SPDY v3 WINDOW_UPDATEs and Firefox

‹prev | My Chain | next›

As of yesterday, it seems that my spdy-v3 branch of node-spdy still has a few kinks to work out. Nearly all of the work in this branch has been adding flow control from version 3 of the SPDY specification. And it is the flow control in that branch the continues to vex me.

I originally got it working with Chrome, then I moved on to spdylay. When I then moved on to sandbox versions of Firefox, things did not go so well. Last night it even seemed that things no longer worked in Chrome—at least not all the time.

Today, I am the beneficiary of some research by Patrick McManus into the issue. He found that the underlying TCP/IP connection was actually resetting halfway through. So first up tonight, I hunt through the code for places that might drop the TCP/IP connection itself. I find that, upon an error the connection is reset, so I add a debug statement to see if this is the cause:

function Server(options, requestListener) {
    // ...
    this.on('secureConnection', function secureConnection(socket) {
      // ...
      connection.on('error', function(e) {
        console.log('[secureConnection] error ' + e);
        socket.destroy(e.errno === 'EPIPE' ? undefined : e);
      });
    });
  }

And, sure enought, when I connect with Firefox, I see that error:

...
[secureConnection] error Stream 7 not found
[secureConnection] error Stream 7 not found
settings.initial_window_size: 268435456
...

The error is followed by another SETTINGS frame, which again sets the initial receive window for each SPDY stream to Firefox's 256mb.

The next question is, where is the "Stream 7 not found" message emitted from and, more importantly, why?

The where is easily ack'd. I find it in the Server class during the parsing of frames:

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;
          return self.emit('error', 'Stream ' + frame.id + ' not found');
        }
      }
      // ...
    }
  });
  // ...
}

I am not quite sure why I seemingly ignore a RST_STREAM like that, but, since I am seeing no RST_STREAMs, I set that aside for now. Instead, I know that Firefox is sending me a frame other than a RST_STREAM and that the stream is not available in the active list of streams. Rather than speculate as to the cause, I add a debug statement to show the frame contents:

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

I also add debugging to fire when a data frame is zero length, which should be at the end of the data:

Stream.prototype._writeData = function _writeData(fin, buffer) {
  // Buffer the data if the agreed up receive window is exhausted...

  if (buffer.length == 0) {
    console.log('sending ' + this.id + ': ' + buffer.length + ' (' + fin + ')');
  }

  // Send the data over the wire...
};

Now when I point Firefox at the server, I see:

Express server listening on port 3000 in development mode
settings.initial_window_size: 268435456
sending 1: 0 (false)
[secureConnection] finish
sending 1: 0 (true)
sending 3: 0 (false)
[secureConnection] finish
sending 3: 0 (true)
sending 5: 0 (false)
[secureConnection] finish
sending 5: 0 (true)
sending 7: 0 (false)
[secureConnection] finish
sending 7: 0 (true)
sending 9: 0 (false)
[secureConnection] finish
sending 9: 0 (true)
{ type: 'WINDOW_UPDATE', id: 7, delta: 65660 }
[secureConnection] error Stream 7 not found
settings.initial_window_size: 268435456
...

Aha! All of the data for stream #7 has been sent, including the DATA FIN, which closes stream #7. Then Firefox is sending a WINDOW_UPDATE. I believe that Firefox is mistaken in this case.

By virtue of the initial SETTINGS frame, Firefox tells my node-spdy server that its initial receive window is 256mb. That is, each SPDY stream in the session can receive 256mb before there is any danger of the SPDY stream's resources being exhausted. Since the images that are transferred on stream #7 and #9 are ~200kb, both easily fit in Firefox's receive window for each stream. In other words, node-spdy need never wait for a WINDOW_UPDATE to tell it that it can resume sending data over the stream—it can send the entire image without delay.

This also means that Firefox should not be sending a WINDOW_UPDATE frame—not during the initial transmission and certainly not after all data has been sent. Firefox told me that each stream's receive window was 256mb. Unless I send it more than 256mb in a stream (at most I send 200kb), a WINDOW_UPDATE is inappropriate.

Unless I am missing something (which I have proved time and again is much better than 50-50 odds), I believe that node-spdy is correct. That both Chrome (which no longer fails) and spdylay both work with the current implementation would seem to corroborate that.

But, as always, I am more than happy to be disabused of incorrect notions...


Day #386