[Libwebsockets] libwebsocket header corruption

"Andy Green (林安廸)" andy at warmcat.com
Mon Mar 24 11:24:33 CET 2014


On 24/03/14 18:10, the mail apparently from Vinay Kulkarni included:
> Hello Andy,
>
>                      Thanks for the update. Server is rejecting connection
> because it thinks that header is not what is expected
> . I am attaching the logs where it shows the complete header expected by
> our server and it connects successfully. Also attaching the packet capture
> logs
>   for header corruption where connection fails. Please note that custom
> header fields (session key, session secret etc) we have added to websocket
> header can have different values depending upon situation so they may
> appear different in packet trace and  log files I have attached with the
> mail.


Hmm -->

GET /dms/customer/1002uY3SF68GneXJ/camera/00037fb9a805/device HTTP/1.1
Pragma: no-cache
Cache-Control: no-cache
TUpg.ade1.199.20.226
.ConTect.on:
Upg2ade.
Se.-WeTSoc.et-
ey: S/d2zd6j8/Fmd8Zl7rQHXQ=k
Sec-WebSocket-Extensions:
Sec-WebSocket-Version: 13
date: 2004-01-10T15:26:24
sessionKey: acd18363-f7f3-4bbb-a25a-5f80a0ade8f8
sessionSecret: c6ff3c44af93aa48400d543e5d5d2ab45ee1797f
partnerId: 1151e33fef61ac3be7cc2fd7f95ed5887d3e9368
localId: b898e11fefab74973a027cbb7509a34f5c86d9c1
cameraToken: 9e93f745b5e88bba5a646d7c8e6e11258477a48e


I can't really see how we're going to corrupt the packet like that.

There are single-bit errors and such, I have never seen that kind of 
problem caused by lws.

You should compare what lws thinks it was sending, and confirm that's 
what was actually received at the server network layer... it looks like 
you have problems in that area.

-Andy


>
> Thanks,
> Vinay
>
>
> .
>
>
> On Sun, Mar 23, 2014 at 9:51 AM, "Andy Green (林安廸)" <andy at warmcat.com>wrote:
>
>> On 20/03/14 19:24, the mail apparently from Vinay Kulkarni included:
>>
>>   Hello Andy,
>>>
>>>                     We are using libwebsocket as websocket client in our
>>> application on arm linux. When we try to connect to our websocket server
>>> client header gets corrupted while sending so connection fails. Please see
>>> attached logs and let us know if there is any fix for this issue.
>>>
>>
>> Hm "fix for this issue"... we don't really know what the server wants or
>> what it objects to.
>>
>> We're trying to make a ws:// connection it seems but I don't see the
>> upgrade header anywhere...
>>
>> 2014-03-20-11:14:09:500 : parseServerURL : SSL disabled for websock, ws://
>> 121.199.20.226/
>> 2014-03-20-11:14:09:504 : parseServerURL : address: 121.199.20.226 port:
>> 9222
>> 2014-03-20-11:14:09:515 : parseServerURL : path: /dms/customer/
>> 1002uY3SF68GneXJ/camera/00037fb9a805/device
>> 2014-03-20-11:14:09:521 : init_ivWebsocket : IVlibwebsockets client
>> 2014-03-20-11:14:09:527 : ivMsgQManagerThread : ivMsgQManagerThread
>> created!
>> 2014-03-20-11:14:09:534 : ivWebsocketLogger : Initial logging level 1023
>> 2014-03-20-11:14:09:538 : ivWebsocketLogger : Library version: 1.3 91f19d8
>> 2014-03-20-11:14:09:557 : ivWebsocketLogger :  LWS_MAX_HEADER_LEN: 1024
>> 2014-03-20-11:14:09:590 : ivWebsocketLogger :  LWS_MAX_PROTOCOLS: 5
>> 2014-03-20-11:14:09:599 : ivWebsocketLogger :  Configured without
>> extension support
>> 2014-03-20-11:14:09:602 : ivWebsocketLogger :  SPEC_LATEST_SUPPORTED: 13
>> 2014-03-20-11:14:09:609 : ivWebsocketLogger :  AWAITING_TIMEOUT: 10
>> 2014-03-20-11:14:09:621 : ivWebsocketLogger :  SYSTEM_RANDOM_FILEPATH:
>> '/dev/urandom'
>> 2014-03-20-11:14:09:630 : ivWebsocketLogger :  LWS_MAX_ZLIB_CONN_BUFFER:
>> 65536
>> 2014-03-20-11:14:09:637 : ivWebsocketLogger :  static allocation: 5472 +
>> (12 x 1024 fds) = 17760 bytes
>> 2014-03-20-11:14:09:703 : ivWebsocketLogger :   Protocol: ws
>> 2014-03-20-11:14:09:709 : ivWebsocketLogger : libwebsocket_client_connect:
>> direct conn
>> 2014-03-20-11:14:09:718 : ivWebsocketLogger : libwebsocket_client_connect_2
>> 2014-03-20-11:14:09:722 : ivWebsocketLogger :
>> libwebsocket_client_connect_2: address 121.199.20.226
>> 2014-03-20-11:14:09:729 : ivWebsocketLogger : insert_wsi_socket_into_fds:
>> wsi=0xdbc520, sock=43, fds pos=0
>> 2014-03-20-11:14:09:736 : ivWebsocketLogger : nonblocking connect retry
>> 2014-03-20-11:14:10:028 : ivWebsocketLogger : libwebsocket_client_connect_2
>> 2014-03-20-11:14:10:034 : ivWebsocketLogger :
>> libwebsocket_client_connect_2: address 121.199.20.226
>> 2014-03-20-11:14:10:052 : ivWebsocketLogger : connected
>> in video clean up routine
>> 2014-03-20-11:14:10:070 : ivWebsocketLogger : header before callback -
>> length=140
>> GET /dms/customer/1002uY3SF68GneXJ/camera/00037fb9a805/device HTTP/1.1
>> Pragma: no-cache
>> Cache-Control: no-cache
>> XUpg: 121.199.20.226
>> 2014-03-20-11:14:10:087 : callback_ws_handler : LWS_CALLBACK_CLIENT_APPEND_
>> HANDSHAKE_HEADER
>> 2014-03-20-11:14:10:092 : getCustomHeader : header length available = 3806
>> 2014-03-20-11:14:10:098 : ivWebsocketLogger : Sending websocket handshake
>> - length=140
>> GET /dms/customer/1002uY3SF68GneXJ/camera/00037fb9a805/device HTTP/1.1
>> Pragma: no-cache
>> Cache-Control: no-cache
>> XUpg: 121.199.20.226
>> 2014-03-20-11:14:10:446 : ivWebsocketLogger : WSI_TOKEN_NAME_PART 'H'
>> 2014-03-20-11:14:10:469 : ivWebsocketLogger : WSI_TOKEN_NAME_PART 'T'
>> 2014-03-20-11:14:10:472 : ivWebsocketLogger : WSI_TOKEN_NAME_PART 'T'
>> 2014-03-20-11:14:10:483 : ivWebsocketLogger : WSI_TOKEN_NAME_PART 'P'
>> 2014-03-20-11:14:10:488 : ivWebsocketLogger : WSI_TOKEN_NAME_PART '/'
>> 2014-03-20-11:14:10:492 : ivWebsocketLogger : WSI_TOKEN_NAME_PART '1'
>> 2014-03-20-11:14:10:497 : ivWebsocketLogger : WSI_TOKEN_NAME_PART '.'
>> 2014-03-20-11:14:10:501 : ivWebsocketLogger : WSI_TOKEN_NAME_PART '1'
>> 2014-03-20-11:14:10:505 : ivWebsocketLogger : WSI_TOKEN_NAME_PART ' '
>> 2014-03-20-11:14:10:509 : ivWebsocketLogger : known hdr 17
>> 2014-03-20-11:14:10:518 : ivWebsocketLogger : WSI_TOK_(17) '4'
>> 2014-03-20-11:14:10:522 : ivWebsocketLogger : WSI_TOK_(17) '0'
>> 2014-03-20-11:14:10:526 : ivWebsocketLogger : WSI_TOK_(17) '0'
>> 2014-03-20-11:14:10:532 : ivWebsocketLogger : WSI_TOK_(17) ' '
>> 2014-03-20-11:14:10:536 : ivWebsocketLogger : WSI_TOK_(17) 'B'
>> 2014-03-20-11:14:10:565 : ivWebsocketLogger : WSI_TOK_(17) 'a'
>> 2014-03-20-11:14:10:576 : ivWebsocketLogger : WSI_TOK_(17) 'd'
>> 2014-03-20-11:14:10:584 : ivWebsocketLogger : WSI_TOK_(17) ' '
>> 2014-03-20-11:14:10:593 : ivWebsocketLogger : WSI_TOK_(17) 'R'
>> 2014-03-20-11:14:10:596 : ivWebsocketLogger : WSI_TOK_(17) 'e'
>> 2014-03-20-11:14:10:600 : ivWebsocketLogger : WSI_TOK_(17) 'q'
>> 2014-03-20-11:14:10:604 : ivWebsocketLogger : WSI_TOK_(17) 'u'
>> 2014-03-20-11:14:10:609 : ivWebsocketLogger : WSI_TOK_(17) 'e'
>> 2014-03-20-11:14:10:616 : ivWebsocketLogger : WSI_TOK_(17) 's'
>> 2014-03-20-11:14:10:621 : ivWebsocketLogger : WSI_TOK_(17) 't'
>> '014-03-20-11:14:10:627 : ivWebsocketLogger : WSI_TOK_(17)'
>> 2014-03-20-11:14:10:631 : ivWebsocketLogger : *
>> 2014-03-20-11:14:10:638 : ivWebsocketLogger : WSI_TOKEN_SKIPPING_SAW_CR '
>> '
>> 2014-03-20-11:14:10:672 : ivWebsocketLogger : WSI_TOKEN_NAME_PART 'C'
>> 2014-03-20-11:14:10:675 : ivWebsocketLogger : WSI_TOKEN_NAME_PART 'o'
>> 2014-03-20-11:14:10:687 : ivWebsocketLogger : WSI_TOKEN_NAME_PART 'n'
>> 2014-03-20-11:14:10:691 : ivWebsocketLogger : WSI_TOKEN_NAME_PART 't'
>> 2014-03-20-11:14:10:696 : ivWebsocketLogger : WSI_TOKEN_NAME_PART 'e'
>> 2014-03-20-11:14:10:700 : ivWebsocketLogger : WSI_TOKEN_NAME_PART 'n'
>> 2014-03-20-11:14:10:704 : ivWebsocketLogger : WSI_TOKEN_NAME_PART 't'
>> 2014-03-20-11:14:10:710 : ivWebsocketLogger : WSI_TOKEN_NAME_PART '-'
>> 2014-03-20-11:14:10:720 : ivWebsocketLogger : WSI_TOKEN_NAME_PART 'L'
>> 2014-03-20-11:14:10:725 : ivWebsocketLogger : WSI_TOKEN_NAME_PART 'e'
>> 2014-03-20-11:14:10:730 : ivWebsocketLogger : WSI_TOKEN_NAME_PART 'n'
>> 2014-03-20-11:14:10:735 : ivWebsocketLogger : WSI_TOKEN_NAME_PART 'g'
>> 2014-03-20-11:14:10:739 : ivWebsocketLogger : WSI_TOKEN_NAME_PART 't'
>> 2014-03-20-11:14:10:759 : ivWebsocketLogger : WSI_TOKEN_NAME_PART 'h'
>> 2014-03-20-11:14:10:776 : ivWebsocketLogger : WSI_TOKEN_NAME_PART ':'
>> 2014-03-20-11:14:10:783 : ivWebsocketLogger : known hdr 26
>> 2014-03-20-11:14:10:787 : ivWebsocketLogger : WSI_TOK_(26) ' '
>> 2014-03-20-11:14:10:792 : ivWebsocketLogger : WSI_TOK_(26) '0'
>> '014-03-20-11:14:10:797 : ivWebsocketLogger : WSI_TOK_(26)'
>> 2014-03-20-11:14:10:801 : ivWebsocketLogger : *
>> 2014-03-20-11:14:10:806 : ivWebsocketLogger : WSI_TOKEN_SKIPPING_SAW_CR '
>> '
>> '014-03-20-11:14:10:817 : ivWebsocketLogger : WSI_TOKEN_NAME_PART'
>> 2014-03-20-11:14:10:822 : ivWebsocketLogger : WSI_TOKEN_NAME_PART '
>> '
>> 2014-03-20-11:14:10:831 : ivWebsocketLogger : known hdr 10
>> 2014-03-20-11:14:10:834 : ivWebsocketLogger : no ACCEPT
>> 2014-03-20-11:14:10:841 : callback_ws_handler : LWS_CALLBACK_CLIENT_
>> CONNECTION_ERROR
>>
>> This unknown server is returning "Bad Request"... it's not clear from the
>> logs what we're sending it.
>>
>> Can you repeat the same connection action again with tcpdump -S0 -X
>> running on the connection so we can see what is actually sent?
>>
>>
>>                       Also there is no API to get HTTP status code return by
>>> server or to get header contents returned by server to check which error
>>> has occurred. Do you have any plans to add such API?
>>>
>>
>> You should be able to get all the headers in the callback
>>
>> LWS_CALLBACK_CLIENT_FILTER_PRE_ESTABLISH
>>
>> for the selected protocol.  After that the headers are deleted and the
>> connection moves to websocket mode, so you need to grab or interpret any
>> interesting ones there.
>>
>> Use lws_hdr_copy() to get copies of a header in a single buffer.
>>
>> -Andy
>>
>>
>>>
>>> Thanks,
>>> Vinay
>>>
>>>
>>
>




More information about the Libwebsockets mailing list