Fix Node-Spdy's Flow Control for Firefox

‹prev | My Chain | next›

With much, much help from Patrick McManus, I think I finally understand what Firefox SPDY sandboxes are doing with respect to SPDY version 3 flow control. I also have a better understanding of Chrome flow control thanks to this exercise. I even think I have a solution to node-spdy's woes holding a spdy/3 conversation with Firefox.

At the outset of a SPDY conversation, Firefox specifies an initial receive window of 256mb for flow control. That is much higher than the 64kb default in the specification. I remain skeptical that Firefox's large window does little more than disable flow control, but it is definitely throwing real world stuff at node-spdy, so I must support it.

As I found last night, Firefox is sending additional WINDOW_UPDATE frames after node-spdy has sent the DATA FIN packet. Currently node-spdy handles this situation by closing the stream, forcing Firefox to open a new SPDY session to require any remaining resources (but giving up on in-transit resources).

Instead, I add code to RST_STREAM in response to a WINDOW_UPDATE on a closed stream. More specifically, I mark the stream as invalid (0x02):

function Connection(socket, pool, options) {
  // ...
  this.parser.on('frame', function (frame) {
    // ...
    if (frame.type === 'SYN_STREAM') { /* ... */ }
    else {
      if (frame.id) {
        // Load created one
        stream = self.streams[frame.id];

        // Fail if not found
        if (stream === undefined) {
          if (frame.type === 'RST_STREAM') return;
          console.log("frame not found: ", frame);
          //return self.emit('error', 'Stream ' + frame.id + ' not found');
          self.write(self.framer.rstFrame(frame.id, 2));
          return;
        }
      }
      // ...
    }
  });
  // ...
}

Now, when I point my sandbox version of Firefox at my nody-spdy site, I finally see the complete web page with no broken images:

Hooray!

The debugging code that I had added to node-spdy shows that Firefox in fact sends 26 WINDOW_UPDATE frames for the two large resources on that page:

➜  express-spdy-test  node app
Express server listening on port 3000 in development mode
settings.initial_window_size: 268435456
...
sending 7: 0 (false)
[secureConnection] finish
sending 7: 0 (true)
sending 9: 0 (false)
[secureConnection] finish
sending 9: 0 (true)
frame not found:  { type: 'WINDOW_UPDATE', id: 7, delta: 65660 }
frame not found:  { type: 'WINDOW_UPDATE', id: 7, delta: 66320 }
frame not found:  { type: 'WINDOW_UPDATE', id: 7, delta: 65660 }
frame not found:  { type: 'WINDOW_UPDATE', id: 9, delta: 65660 }
frame not found:  { type: 'WINDOW_UPDATE', id: 9, delta: 66320 }
frame not found:  { type: 'WINDOW_UPDATE', id: 9, delta: 65660 }
frame not found:  { type: 'WINDOW_UPDATE', id: 7, delta: 66320 }
frame not found:  { type: 'WINDOW_UPDATE', id: 9, delta: 66320 }
frame not found:  { type: 'WINDOW_UPDATE', id: 7, delta: 66320 }
frame not found:  { type: 'WINDOW_UPDATE', id: 9, delta: 66320 }
frame not found:  { type: 'WINDOW_UPDATE', id: 7, delta: 65660 }
frame not found:  { type: 'WINDOW_UPDATE', id: 9, delta: 65660 }
frame not found:  { type: 'WINDOW_UPDATE', id: 7, delta: 66320 }
frame not found:  { type: 'WINDOW_UPDATE', id: 9, delta: 66320 }
frame not found:  { type: 'WINDOW_UPDATE', id: 7, delta: 65660 }
frame not found:  { type: 'WINDOW_UPDATE', id: 9, delta: 65660 }
frame not found:  { type: 'WINDOW_UPDATE', id: 7, delta: 66320 }
frame not found:  { type: 'WINDOW_UPDATE', id: 9, delta: 66320 }
frame not found:  { type: 'WINDOW_UPDATE', id: 7, delta: 66320 }
frame not found:  { type: 'WINDOW_UPDATE', id: 9, delta: 66320 }
frame not found:  { type: 'WINDOW_UPDATE', id: 7, delta: 65660 }
frame not found:  { type: 'WINDOW_UPDATE', id: 9, delta: 65660 }
frame not found:  { type: 'WINDOW_UPDATE', id: 7, delta: 66320 }
frame not found:  { type: 'WINDOW_UPDATE', id: 9, delta: 66320 }
frame not found:  { type: 'WINDOW_UPDATE', id: 9, delta: 65660 }
frame not found:  { type: 'WINDOW_UPDATE', id: 9, delta: 66320 }
...

Looking through Firefox's HTTP log, it seems that Firefox is sending those WINDOW_UPDATE frames as it receives DATA frames. Where node-spdy sees the WINDOW_UPDATE frames after the DATA FIN, Firefox sees them before.

I have the feeling that my simple flow control buffer in node-spdy may be too simple. I will investigate that another night. Before calling it a night tonight, I make the localhost network interface (lo) a little more realistic with traffic control:

sudo tc qdisc add dev lo root netem delay 50ms

The hope is that perhaps the unrealistic testing on the loopback interface is somehow producing these weird results.

It is not.

I see the exact same number of WINDOW_UPDATE frames from Firefox even with a more realistic RTT in effect. Ah well, even eliminating the obvious solution is helpful sometimes.

I will pick back up tomorrow investigating the apparent discrepancy between when node-spdy sends DATA frames and when Firefox receives them.

UPDATE: I have updated the code on https://test.spdybook.com:3000/ to use this recent version of node-spdy in case anyone is interested in trying it. The certificate for that site is invalid, but is pulled from node-spdy if you want to decrypt the packets: https://github.com/indutny/node-spdy/tree/master/keys.

Day #387