ASPLes / nopoll

OpenSource WebSocket toolkit
http://www.aspl.es/nopoll
GNU Lesser General Public License v2.1
124 stars 74 forks source link

Unable to determine final noPollMsg from single websocket fragment through nopoll_comm_get_msg #55

Open veeg opened 6 years ago

veeg commented 6 years ago

I have a websocket client (through the browser implementation of WebSocket) that will upload small files in the range of 10-100kb. My server is using a nopoll listening socket with GLib event loop to receive complete messages through nopoll_comm_get_msg() on socket activity. When my client sends a message of some significant size, the TCP segments exchanged may be broken into anything between 2 and 12 packets. However, as exemplified by this wireshark TCP dump it is only sent as a single websocket fragment.

TCP segments: [4 Reassembled TCP Segments (32401 bytes): #62(8192), #63(8192), #65(8192), #66(7825)]

Hex dump of websocket fragment header: 82 fe 7e 89 56 41 bd 0f

Wireshark text interpretation of fragment header:

WebSocket
    1... .... = Fin: True
    .000 .... = Reserved: 0x0
    .... 0010 = Opcode: Binary (2)
    1... .... = Mask: True
    .111 1110 = Payload length: 126 Extended Payload Length (16 bits)
    Extended Payload length (16 bits): 32393
    Masking-Key: 5641bd0f

This is my nopoll/server log of received noPollMsg objects:

TRACE - WebSocket traffic
TRACE - nopoll_conn.c:2892 === START: conn-id=6 (errno=13, session: 12, conn->handshake_ok: 1, conn->pending_ssl_accept: 0) ===
TRACE - nopoll_conn.c:3096 Received 2 bytes for websocket header
TRACE - nopoll.c:745   byte (header[0]) = 1 0 0 0  0 0 1 0
TRACE - nopoll.c:745   byte (header[1]) = 1 1 1 1  1 1 1 0
TRACE - nopoll_conn.c:3134 interim payload size received: 126
TRACE - nopoll_conn.c:3173 Received (2) bytes in header (size 4) for payload size indication, which finally is: 32393
TRACE - nopoll_conn.c:3264 Received mask value = 1727240496
TRACE - nopoll.c:745   byte (mask[0]) = 0 1 1 0  0 1 1 0
TRACE - nopoll.c:745   byte (mask[1]) = 1 1 1 1  0 0 1 1
TRACE - nopoll.c:745   byte (mask[2]) = 1 0 0 1  1 0 0 1
TRACE - nopoll.c:745   byte (mask[3]) = 0 0 1 1  0 0 0 0
TRACE - nopoll_conn.c:3280 Detected incoming websocket frame: fin(1), op_code(2), is_masked(1), payload size(32393), mask=1727240496
WARN - nopoll_conn.c:3311 Received fewer bytes than expected (bytes: 28952 < payload size: 32393)
TRACE - nopoll_conn.c:3345 Unmasking (payload size 28952, mask: 1727240496, msg: 0x25d77f0, desp: 0)
DEBUG - Nopoll message size: 28952, is_fragment: 1, is_final: 1, opcode: 2
ERROR - Client provided message is incorrectly formatted - unable to parse successfully.

TRACE - WebSocket traffic
TRACE - nopoll_conn.c:2892 === START: conn-id=6 (errno=0, session: 12, conn->handshake_ok: 1, conn->pending_ssl_accept: 0) ===
WARN - nopoll_conn.c:2982 Reading bytes (previously read 28952) from a previous unfinished frame (pending: 3441) over conn-id=6
TRACE - nopoll_conn.c:3018 Reusing mask value = 1727240496 from previous frame (-810745263)
TRACE - nopoll.c:745   byte (mask[0]) = 0 1 1 0  0 1 1 0
TRACE - nopoll.c:745   byte (mask[1]) = 1 1 1 1  0 0 1 1
TRACE - nopoll.c:745   byte (mask[2]) = 1 0 0 1  1 0 0 1
TRACE - nopoll.c:745   byte (mask[3]) = 0 0 1 1  0 0 0 0
TRACE - nopoll_conn.c:3345 Unmasking (payload size 3441, mask: 1727240496, msg: 0x25b29c0, desp: 28952)
DEBUG - Nopoll message size: 3441, is_fragment: 1, is_final: 1, opcode: 0
ERROR - Client provided message is incorrectly formatted - unable to parse successfully.

NOTE: The wireshark dump and log here is not the same occurrence. Only included the wireshark dump for sake of argument.

In this case, nopoll was able to read 28952 out of 32393 payload bytes from the socket in the first noPollMsg, and was able to read the remaining 3441 bytes in the next noPollMsg, however; the is_final flag is incorrectly set in the first noPollMsg while there are pending payload bytes left to complete the websocket message.

This has been taken into account here: https://github.com/ASPLes/nopoll/blob/e80b74aa653b1395759bce7f256ce7e94645f39f/src/nopoll_conn.c#L3518 Hhowever, this was commented out in commit 4bc7339708bd7f64afcf2e773b5aed76bb5741fc, which is seemingly unrelated to the commit itself. After reverting the change and commenting in the clearing of this flag, I successfully received two noPollMsg objects for this fragment, where the first noPollMsg had is_final cleared.

xiaowenhuyuehu commented 6 years ago

i have the same question:

(proc 3215): (debug) nopoll_conn.c:3069 === START: conn-id=2 (errno=0, session: 3, conn->handshake_ok: 1, conn->pending_ssl_accept: 0) === (proc 3215): (debug) nopoll_conn.c:3275 Received 2 bytes for websocket header (proc 3215): (debug) nopoll.c:744 byte (header[0]) = 1 0 0 0 0 0 1 0 (proc 3215): (debug) nopoll.c:744 byte (header[1]) = 0 1 1 1 1 1 1 0 (proc 3215): (debug) nopoll_conn.c:3313 interim payload size received: 126 (proc 3215): (debug) nopoll_conn.c:3352 Received (2) bytes in header (size 4) for payload size indication, which finally is: 647 (proc 3215): (debug) nopoll_conn.c:3447 Detected incoming websocket frame: fin(1), op_code(2), is_masked(0), payload size(647), mask=0 (proc 3215): (debug) nopoll_conn.c:3503 Received fewer bytes than expected (bytes: 142 < payload size: 647)