some random problems using websockify to connect to a tcp address

[j...@meteorage.com]

hello 

we have a specific protocol based on a telnet connection that can send and receive data based on a telnet connection

when a telnet connection is open, a dialog starts between the client and the server so that

1. the client get authenticated 

2. the client sends a past time request to get data from the server

Authentification works well but the result of the past time request ends in different ways :

-either the client browser receives the message :

error: (107, 'Transport endpoint is not connected')

".....

error: (107, 'Transport endpoint is not connected')

Closing socket listening at :8080

Got SIGCHLD, reaping zombies

Reaped child process 10338

Ignoring interrupted syscall"

in that case I can check that all data are received

-or an error 400 happens on the server side, such as :

code 400, message Bad request syntax ('\x....')

If i simulate an error for instance asking for data in a time interval whose the beginning date is higher than the nding date

the client did receive the error message which is :

error sub=548 msg=1403 act=3 txt="Invalid date in client request" G=071

but at the same time on the server side I get the following trace including systematically error 400 :

192.168.0.72: forking handler

jmarie.meteorage.fr - - [03/Jun/2014 10:07:17] "GET / HTTP/1.1" 101 -

jmarie.meteorage.fr - - [03/Jun/2014 10:07:17] 192.168.0.72: Plain non-SSL (ws://) WebSocket connection

jmarie.meteorage.fr - - [03/Jun/2014 10:07:17] 192.168.0.72: Version hybi-13, base64: 'True'

jmarie.meteorage.fr - - [03/Jun/2014 10:07:17] connecting to: testadad:1548

jmarie.meteorage.fr - - [03/Jun/2014 10:07:19] testadad:1548: Target closed connection

jmarie.meteorage.fr - - [03/Jun/2014 10:07:19] testadad:1548: Closed target

jmarie.meteorage.fr - - [03/Jun/2014 10:07:20] code 400, message Bad HTTP/0.9 request type ('\x88\x8fSt\x98oP\x9c\xcc\x0e!\x13\xfd\x1bs\x17\xf4\x00')

jmarie.meteorage.fr - - [03/Jun/2014 10:07:20] "�t�oP�! s � �" 400 -

Closing socket listening at :8080

Got SIGCHLD, reaping zombies

Reaped child process 14115

Ignoring interrupted syscall

is there an explanation about this

thanks for your help

jean-Marie

[Joel Martin]

If you think there is an issue with websockify code, you're going to need to simplify your error cases into simple reproducers (and providing the simplified code would be helpful). It's difficult to tell from the complex case you posted whether the problem lies in your application code or in websockify itself. The only thing apparent from what you posted is that it appears that at times raw data is being sent to websockify without the websocket channel being fully established. I'm not sure how that would happen unless your client isn't actually a browser (since browsers shouldn't ever send raw data like that.

Regards,

Joel Martin (kanaka)

[j...@meteorage.com]

Thanks a lot for your answer

First I confirm that we use a browser

and that the error happens whatever the browser used

We do not know if there is an issue with websockify code

providing a simplified code is not possible using our protocol

but i could code a little java program working as a simple tcp server

and exchanging the same kind of information 

meanwhile and if it is possible, what could be done is to get more information about the websockify server execution

i used option -v  :

./run -v 8080 ourtcpserver:1548

is it possible to log more information passing in transit through the websockify server ?

regarding the message causing error 400,  does this message come inevitably from the browser 

or is it due for instance to our TCP server that would close the socket too quickly after having sent the last message 

 

at the browser level, here is the end of the log :

...

"error sub=548 msg=1403 act=3 txt="Invalid date in client request" G=071

" wswebgl-telnet_obs.js:158

"<< recv_message" util.js:108

">> WebSock.onclose" util.js:108

">> WebSockets.onclose" util.js:109

">> disconnect" util.js:108

"<< disconnect" util.js:108

"<< WebSockets.onclose" util.js:109

"<< WebSock.onclose"

error 400 on the server happens a few tenths of second after this log

best regards

Jean-Marie

_________________________________________________________________________________________________________________

[j...@meteorage.com]

Hello Joel

I coded a simple java program "tcpserver" waiting for one socket connection on localhost

that u can use with your program wstelnet.html to connect with and send messages

once a connection is established, tcpserver waits for a message and transmits it back to wstelnet ;

when you type message "close", tcpserver closes the socket connection

tcpserver is run this way :

java -jar tcpserver.jar 

by default this program listens on port 1510

to listen on a specific port  type :

java  -jar tcpserver.jar -port xxxx

websockify server is run this way :

./run -v 8080 localhost:1510

websockify server and  tcpserver run on the same machine (Red Hat Enterprise Linux Server release 5.9)

I tested this example on windows with 3 browsers (FireFox 29 , Chrome V 35, IE 11) and on linux with FireFox (Red Hat, centOS)

and error 400 is logged systematically by websockify server

here is below an example of execution log :

jmarie.meteorage.fr - - [04/Jun/2014 09:09:38] "GET / HTTP/1.1" 101 -

jmarie.meteorage.fr - - [04/Jun/2014 09:09:38] 192.168.0.72: Plain non-SSL (ws://) WebSocket connection

jmarie.meteorage.fr - - [04/Jun/2014 09:09:38] 192.168.0.72: Version hybi-13, base64: 'False'

jmarie.meteorage.fr - - [04/Jun/2014 09:09:38] connecting to: localhost:1530

jmarie.meteorage.fr - - [04/Jun/2014 09:09:45] localhost:1530: Target closed connection

jmarie.meteorage.fr - - [04/Jun/2014 09:09:45] localhost:1530: Closed target

jmarie.meteorage.fr - - [04/Jun/2014 09:09:45] code 400, message Bad request syntax ('\x88\x80\xb4n\xb9#')

jmarie.meteorage.fr - - [04/Jun/2014 09:09:45] "���n�#" 400 -

Closing socket listening at :8080

Got SIGCHLD, reaping zombies

Reaped child process 22899

the content of the message responsible for error 400, which is above '\x88\x80\xb4n\xb9#', seems to change at every run

thanks in advance for your help

best regards

Jean-Marie

On Tuesday, June 3, 2014 12:15:08 PM UTC+2, j...@meteorage.com wrote:

[j...@meteorage.com]

Hello

I tested the "tcpserver" java example with wstelnet.html on CentOS release 6.5 with python Version 2.6.6 installed

numpy is also installed (version 1.4.1)

so no warning when running websockify 

firefox version 24.6.0 is used and runs on the same machine

error 400 still appears when closing the telnet socket ; see the log below :

[cats@VM-centos6532-JMC websockify-master]$ ./run -v 8080 localhost:1510

WebSocket server settings:

  - Listen on :8080

  - Flash security policy server

  - No SSL/TLS support (no cert file)

  - proxying from :8080 to localhost:1510

127.0.0.1: new handler Process

localhost.localdomain - - [24/Jun/2014 12:15:04] "GET / HTTP/1.1" 101 -

localhost.localdomain - - [24/Jun/2014 12:15:04] 127.0.0.1: Plain non-SSL (ws://) WebSocket connection

localhost.localdomain - - [24/Jun/2014 12:15:04] 127.0.0.1: Version hybi-13, base64: 'False'

localhost.localdomain - - [24/Jun/2014 12:15:04] connecting to: localhost:1510

localhost.localdomain - - [24/Jun/2014 12:15:28] localhost:1510: Target closed connection

localhost.localdomain - - [24/Jun/2014 12:15:28] localhost:1510: Closed target

localhost.localdomain - - [24/Jun/2014 12:15:29] code 400, message Bad request syntax ("\x88\x8fU\xe9$\x80V\x01p\xe1'\x8eA\xf4u\x8aH\xef&\x8c@")

localhost.localdomain - - [24/Jun/2014 12:15:29] "��$�V p�'�u�H�&�@" 400 -

Reaing zombies, active child count is 0

Ignoring interrupted syscall

is it possible to have some help

thanks a lot in advance

Jean-Marie

On Tuesday, June 3, 2014 12:15:08 PM UTC+2, j...@meteorage.com wrote:

[j...@meteorage.com]

I have a question regarding this error :

since this problem occurs each time the tcp server closes the socket connexion,

does websockify manage closing on the tcp server side ? it seems that it doesn't

Jean-Marie

On Tuesday, June 3, 2014 12:15:08 PM UTC+2, j...@meteorage.com wrote:

[Raymond Henick]

Sorry to reply to an old post but for the benefit of anybody else reading.  I'm having a very similar issue while deploying a VDI solution where https was implemented and this 400 bad request is the result.

After much research, it appears that websockify.py parses the data stream for a few reasons... one to identify flash for legacy flash client support and 2 to identify a legit ssl stream.  

If the stream ^x80 or ^x16 it is SSL... and will proceed with 'wrapping' the stream.

So I haven't figured this out yet... 

it works fine when I switch https off on apache but when I turn on https then add --cert and --key to the websockify command line (using the same cert as apache) 

AND websockify/run.js has been modified from ws:// to wss:// so it properly tries to connect via the correct protocol.

but it appears to be the fact that websockify cannot confirm SSL in the data stream so it fails with the following error.

mydesktop.dhcp-dynamic.FibreOp.ns.bellaliant.net - - [21/Sep/2016 16:05:29] code 400, message Bad HTTP/0.9 request type ('\x88\x8f{U\xc9\x8fx\xbd\x9d\xee')

I will update again when I resolve the problem.

Hope this helps.

[j...@meteorage.com]

Hello Raymond

thanks for your answer

I tried disabling https (SSLEngine off) but still have the same problem (which happens frequently but not always)

the tests are being done using ports different from 80 and 443 (for instance 8080 or 9000)

so I am not supposed to use SSL connection. 

may be the execution would be correct bypassing the websockify parsing...

let me know when you solved this problem

thanks in advance

Jean-Marie

[Raymond Henick]

So I've done a bit more research into my problem and it may be able to help yours.  According to the websocket protocol document RFC 6455... there are status codes websockets can return.

https://tools.ietf.org/html/rfc6455

   IANA has added initial values to the registry as follows.

     |Status Code | Meaning         | Contact       | Reference |
    -+------------+-----------------+---------------+-----------|
     | 1000       | Normal Closure  | hy...@ietf.org | RFC 6455  |
    -+------------+-----------------+---------------+-----------|
     | 1001       | Going Away      | hy...@ietf.org | RFC 6455  |
    -+------------+-----------------+---------------+-----------|
     | 1002       | Protocol error  | hy...@ietf.org | RFC 6455  |
    -+------------+-----------------+---------------+-----------|
     | 1003       | Unsupported Data| hy...@ietf.org | RFC 6455  |
    -+------------+-----------------+---------------+-----------|
     | 1004       | ---Reserved---- | hy...@ietf.org | RFC 6455  |
    -+------------+-----------------+---------------+-----------|
     | 1005       | No Status Rcvd  | hy...@ietf.org | RFC 6455  |
    -+------------+-----------------+---------------+-----------|
     | 1006       | Abnormal Closure| hy...@ietf.org | RFC 6455  |
    -+------------+-----------------+---------------+-----------|
     | 1007       | Invalid frame   | hy...@ietf.org | RFC 6455  |
     |            | payload data    |               |           |
    -+------------+-----------------+---------------+-----------|
     | 1008       | Policy Violation| hy...@ietf.org | RFC 6455  |
    -+------------+-----------------+---------------+-----------|
     | 1009       | Message Too Big | hy...@ietf.org | RFC 6455  |
    -+------------+-----------------+---------------+-----------|
     | 1010       | Mandatory Ext.  | hy...@ietf.org | RFC 6455  |
    -+------------+-----------------+---------------+-----------|
     | 1011       | Internal Server | hy...@ietf.org | RFC 6455  |
     |            | Error           |               |           |
    -+------------+-----------------+---------------+-----------|
     | 1015       | TLS handshake   | hy...@ietf.org | RFC 6455  |
    -+------------+-----------------+---------------+-----------|

and also an ascii drawing of what the hell that string means.

      0                   1                   2                   3
      0 1 2 3 4 5 6 7 8 9 0 1 2 3 4 5 6 7 8 9 0 1 2 3 4 5 6 7 8 9 0 1
     +-+-+-+-+-------+-+-------------+-------------------------------+
     |F|R|R|R| opcode|M| Payload len |    Extended payload length    |
     |I|S|S|S|  (4)  |A|     (7)     |             (16/64)           |
     |N|V|V|V|       |S|             |   (if payload len==126/127)   |
     | |1|2|3|       |K|             |                               |
     +-+-+-+-+-------+-+-------------+ - - - - - - - - - - - - - - - +
     |     Extended payload length continued, if payload len == 127  |
     + - - - - - - - - - - - - - - - +-------------------------------+
     |                               |Masking-key, if MASK set to 1  |
     +-------------------------------+-------------------------------+
     | Masking-key (continued)       |          Payload Data         |
     +-------------------------------- - - - - - - - - - - - - - - - +
     :                     Payload Data continued ...                :
     + - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - +
     |                     Payload Data continued ...                |
     +---------------------------------------------------------------+

my string was translated as this after about 30m deciphering the chart above.

\x88 / \x8f  / \xec \x3a \xd2 \xeb  / \xef\xd2\x86\x8a\x9e]\xb7\x9f\xccY\xbe\x84\x9f_\xb6

Fin+Close /  Mask,15 bit payload /  4byte mask key ( ec 3a d2 eb) /

Payload Data Status Code ( ef d2 ) UTF-8 Encoded Text ( 86 8a 9e 5d b7 9f cc 59 be 84 9f 5f b6 )

Mask: 1110110000111010 1101001011101011

Data: 1110111111010010

UMSK: 0000001111101000

Unmasked Payload (hex): 03 e8

Payload Data : 2 bytes (16-bit bigendian unsigned) of Status Code (03e8) = 1000

So, Normal Closure - according to the status code.  Very anti-climactic really.

Your code is \x88\x8f St\x98oP\x9c\xcc\x0e!\x13\xfd\x1bs\x17\xf4\x00

the x88 is FIN+Close the x8f denotes the next 15 bytes are an XOR mask. 

So your first 15 bytes of St\x98oP\x9c\xcc\x0e!\x13\xfd\x1bs\x17\xf4\x00 is your XOR mask and the rest is the payload.  It might be nice to translate all 15 of these just so people have something to google when this happens :P 

--
You received this message because you are subscribed to the Google Groups "noVNC" group.
To unsubscribe from this group and stop receiving emails from it, send an email to novnc+unsubscribe@googlegroups.com.
To post to this group, send email to no...@googlegroups.com.
Visit this group at https://groups.google.com/group/novnc.
For more options, visit https://groups.google.com/d/optout.