Received WebSocket frames are malformed if fragmented

[repomaa]

I've been writing issues starting from NodeJS over to Meteor over to SockJS over to this project now all concerning the same issue and being directed to another project. Hopefully I'm at the end of the rainbow now writing this here. The issue is as follows:

I'm sending websockets over to a meteor app (which uses SockJS which uses faye-websocket apparently). One of the frames is fragmented over two TCP packets. This results in the websocket being closed due to an unknown opcode (13). Here's the wireshark dump of the communication:

http://p.jreinert.com/yM9/

[repomaa]

i uploaded a screencast with the wireshark frames inspected for those who can't/don't want to install/use wireshark:

http://p.jreinert.com/WFJtv/

[jcoglan]

Thanks for the TCP dump. I've extracted the data portion of the transcript and reproduced it below. This contains the frame number, which peer sent the packet, the packet length, and its data:

1:    client    1     81

2:    server    19    81 11 7b 22 73 65 72 76   65 72 5f 69 64 22 3a 22
                      30 22 7d

3:    client    52    af f0 e2 92 e9 8b c0 e4   8c 82 91 fb 86 9e c0 a8
                      cb c1 c0 be cb 83 97 e2   99 9f 90 e6 cb ca b9 b0
                      d8 d2 bf be cb 9d 91 f5   cb ca c0 f1 86 9e 8c f7
                      8a 84 c0 ef

4:    server    33    88 1f 03 ea 55 6e 72 65   63 6f 67 6e 69 7a 65 64
                      20 66 72 61 6d 65 20 6f   70 63 6f 64 65 3a 20 31
                      33

5:    client    1     88  

6:    client    36    9f 8b 3a 1e 89 88 d0 4b   e7 f9 5f 7d e6 ec 54 77
                      f3 ee 5e 3e ef f9 5b 73   ec ab 55 6e ea e4 5e 7b
                      b3 ab 0b 2d

Stepping through it:

Frame 1: the client sends 81, which signifies the header fields final=true, rsv=0, opcode=1. The opcode 1 means it's a UTF-8 text frame.

Frame 2: the server sends 81 (a final text frame header), then 11 which is a length header of 17 (decimal), followed by 17 bytes which represent {"server_id":"0"} in UTF-8.

Frame 3: the client sends af. We already saw the opcode header so this is the mask/length header. af signifies the frame is masked and the length is 47. f0 e2 92 e9 is the frame mask, and the remaining 47 bytes in the packet are the payload. The payload is the text {"version":"1","support":["1"],"msg":"connect"} in UTF-8, XORed with the mask bytes.

Frame 4: the server sends 88 which means final=true, rsv=0, opcode=8. Opcode 8 means closing. The length header is 1f so the frame is not masked and has length 31. The next 2 bytes 03 ea are a big-endian 1002, the closing code for a protocol error, and the remaining 29 bytes spell Unrecognized frame opcode: 13.

Frame 5: the client sends 88 to begin a final closing frame.

Frame 6: the client sends 9f, indicating a masked frame with length 31. 8b 3a 1e 89 is the mask and the remaining 31 bytes are the closing code and message sent by the server -- peers must echo closing messages to acknowledge them.

This transcript looks fine to me and I'm not sure why the server is returning an error after the client's first message. So, I got out the example server from this repo. Add this line to the upgradeHandler function to log incoming data:

socket.on('data', function(data) { console.log('parse', data) });

With the example server running, I made this script. It opens a TCP connection to the server, and performs a WebSocket handshake. Then it sends the data from frames 1 and 3 at a controllable delay.

var net       = require('net'),
    websocket = require('websocket-driver');


var INTERVAL = parseInt(process.argv[2], 10);


var CHUNKS = [
  '81',

  'af f0 e2 92 e9 8b c0 e4 8c 82 91 fb 86 9e c0 a8',
  'cb c1 c0 be cb 83 97 e2 99 9f 90 e6 cb ca b9 b0',
  'd8 d2 bf be cb 9d 91 f5 cb ca c0 f1 86 9e 8c f7',
  '8a 84 c0 ef'
];


var socket = net.connect(7000, 'localhost'),
    driver = websocket.client('ws://localhost:7000/');

socket.on('error', function() {});
socket.pipe(driver.io).pipe(socket);

driver.on('open', function() {
  console.log('open');

  var i = 0;

  setInterval(function() {
    var chunk = CHUNKS[i++];
    if (chunk === undefined) return;
    var buf = new Buffer(chunk.replace(/ /g, ''), 'hex');
    socket.write(buf);
  }, INTERVAL);
});

driver.on('close', function(close) {
  console.log('close', close.code, close.reason);
});

driver.messages.on('data', function(message) {
  console.log('message', message);
});

driver.start();

If you run this script with interval 500, you see the data arriving in distinct chunks at the server:

parse <Buffer 81>
parse <Buffer af f0 e2 92 e9 8b c0 e4 8c 82 91 fb 86 9e c0 a8>
parse <Buffer cb c1 c0 be cb 83 97 e2 99 9f 90 e6 cb ca b9 b0>
parse <Buffer d8 d2 bf be cb 9d 91 f5 cb ca c0 f1 86 9e 8c f7>
parse <Buffer 8a 84 c0 ef>

The server processes this data as a text frame as described about and echoes it to the client, which prints

message {"version":"1","support":["1"],"msg":"connect"}

If you leave the server running, you'll see data like this on the server:

parse <Buffer 8a 81 bf 27 b0 d2 31>
parse <Buffer 8a 81 32 1f 6f 17 32>
parse <Buffer 8a 81 50 44 d4 cf 33>
etc

8a denotes a 'pong' frame; the server is sending 'ping' frames to the client, and the driver on the client send is producing responses. 81 in the second byte means the frame is masked and has length 1, so you see four bytes of mask and one byte of data in each frame.

The final chunk of our test input also begins 8a but that is a coincidence; the random masking on that frame happens to produce an 8a byte in the middle of the text payload.

If we increase the interval to 1000 we see (with line numbers):

1 parse <Buffer 81>
2 parse <Buffer af f0 e2 92 e9 8b c0 e4 8c 82 91 fb 86 9e c0 a8>
3 parse <Buffer cb c1 c0 be cb 83 97 e2 99 9f 90 e6 cb ca b9 b0>
4 parse <Buffer d8 d2 bf be cb 9d 91 f5 cb ca c0 f1 86 9e 8c f7>
5 parse <Buffer 8a 81 a9 fa 51 6c 98>
6 parse <Buffer 88 cf 9b 58 bd 19 98 b2 f2 77 fe 78 d2 6b bb 35 d2 6b fe 78 cf 7c e8 3d cf 6f fe 3c 9d 7b f2 2c ce 39 fa 2a d8 39 f4 36 87 39 e9 3d ce 7c e9 2e d8 7d ... >
7 parse <Buffer 8a 84 c0 ef>

Lines 1 to 4 are as before. On line 5, the client sends a pong frame 8a 81 a9 fa 51 6c 98 but it had not yet finished sending the previous text frame: the server was expecting 4 more bytes of text i.e. the data from line 7. So it tries to interpret 8a 81 a9 fa as text and 51 6c 98 as the beginning of a new frame, which is invalid. You usually see Could not decode a text frame as UTF-8 or One or more reserved bits are on in this situation but you might also see an invalid opcode as well.

I mention all this to demonstrate that if frames are somehow interleaved into the parser, then they won't make sense and the parser will spit them out. However the transcript you gave looks valid to me -- parsing it 'by hand' it looks fine, the frame contents are of the correct sizes and arrive in packets all together. And when we replay it without interleaving other things, it works fine.

So I wonder if there's some way the server you're talking to could be interleaving inputs, or delaying or chopping the input up in some way. faye-websocket and websocket-driver just take input as they are fed it from the I/O device they're connected to, and they don't fragment message buffers -- they construct one contiguous frame buffer for each message and emit to I/O, so they shouldn't be creating space within a text frame for other data to be inserted.

Is any of that helpful and does it sound like what might be happening in your system?

[repomaa]

wow thanks @jcoglan for taking so much time to look into this. With "the server you're talking to" I'm not sure what you mean. I though it'd be faye-websocket-node...

[jcoglan]

What I mean is that the only way I can find to trigger this error is to deliberately insert data into the middle of frames. The websocket-driver parser is designed to handle streaming input when it's split into arbitrary chunks.

The server is most likely using a construction like in the docs to set up the WebSocket on the server side. Code like this has access to the socket object, and the program might be routing other data to that stream besides that which is arriving via TCP. Or, the TCP stream might be being piped through a transform that re-orders it, perhaps.

[glasser]

@jreinert What version of Meteor are you using?

Do you observe this in production or in development? If in production, does your app run behind a proxy?

[repomaa]

i'm using the latest version (1.2) and it's happening in development.

[jcoglan]

@glasser @jreinert did you get anywhere with this?

[glasser]

I didn't have a chance to look into it and I'm not sure if I will soon, especially if there's isn't an easy reproduction.

[repomaa]

haven't gotten anywhere no..