Can't SPDY/3 Push

‹prev | My Chain | next›

I have sample node-spdy sites available. The older version that still relies on express-spdy is pretty solid. The spdy-v3 branch more or less works... except for SPDY server push.

SPDY server push is a fascinating (and a little scary) feature of SPDY. It allows the server to push resources directly into the browsers cache. In this way, resources can get served without the round-trip request-response typified by old HTTP.

I try to push the stylesheet for my "real world sample site" to the browser when it requests the /real resource:

app.get('/real', function(req, res){
  headers = {
    ':scheme': 'https',
    ':host': 'localhost:3000',
    ':path': '/stylesheets/style.css'
  };

  res.push('/stylesheets/style.css', headers, function(err, stream) {
    fs.createReadStream('public/stylesheets/style.css').pipe(stream);
    // fs.readFile('public/stylesheets/style.css', function (err, data) {
    //   if (err) throw err;
    //   console.log('stream writing: ' + data);
    //   stream.end(data);
    // });
  });

  res.render('real', {
    title: 'Hello (real) World!'
  });
});

I added the colon headers (:scheme, :host, etc) since spdy/3 requires them. Then I create a readable stream from the file system and pipe it back to the push stream.

And it almost works. In the SPDY tab of chrome://net-internals, I see the push stream initiated immediately after the request is send and before the SYN_REPLY reply comes back:

SPDY_SESSION_SYN_STREAM
--> flags = 1
--> :host: localhost:3000
    :method: GET
    :path: /real
    :scheme: https
    :version: HTTP/1.1
    accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
    accept-charset: ISO-8859-1,utf-8;q=0.7,*;q=0.3
    accept-encoding: gzip,deflate,sdch
    accept-language: en-US,en;q=0.8
    referer: https://localhost:3000/
    user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/536.11 (KHTML, like Gecko) Chrome/20.0.1132.11 Safari/536.11
--> id = 1
SPDY_SESSION_PUSHED_SYN_STREAM
--> associated_stream = 1
--> flags = 2
--> :host: localhost:3000
    :path: /stylesheets/style.css
    :scheme: https
    status: 200
    url: https://localhost:3000/stylesheets/style.css
    version: HTTP/1.1
--> id = 2
SPDY_SESSION_SYN_REPLY
--> flags = 0
--> :status: 200
    :version: HTTP/1.1
--> id = 1

I even see the push data come through and my coveted "adopted" push stream:

SPDY_SESSION_PUSHED_SYN_STREAM
--> associated_stream = 1
--> flags = 2
--> :host: localhost:3000
    :path: /stylesheets/style.css
    :scheme: https
    status: 200
    url: https://localhost:3000/stylesheets/style.css
    version: HTTP/1.1
--> id = 2
SPDY_SESSION_SYN_REPLY
--> flags = 0
--> :status: 200
    :version: HTTP/1.1
--> id = 1
SPDY_SESSION_RECV_DATA
--> flags = 0
--> size = 221
--> stream_id = 2
...
SPDY_SESSION_RECV_DATA
--> flags = 0
--> size = 0
--> stream_id = 2
SPDY_STREAM_ADOPTED_PUSH_STREAM

But the page does not actually load (at least not for a minute or so). And I see this in the SPDY tab:

...
SPDY_SESSION_RST_STREAM
--> description = ""
--> status = 2
--> stream_id = 3
SPDY_SESSION_CLOSE
--> description = "bytes_read is <= 0."
--> status = -100
SPDY_SESSION_POOL_REMOVE_SESSION
--> source_dependency = 226371 (SPDY_SESSION)
SPDY_STREAM_ERROR
--> description = "ABANDONED (stream_id=2): /stylesheets/style.css"
--> status = -100
--> stream_id = 2

Back when I was first exploring SPDY server push, I found arcane rules that were needed in order get Chrome to handle the push properly. I try various combinations of those rules and attempt to push different resources, but to no avail. Even if I remove all headers but those explicitly mentioned in version 3 of the SPDY specification:

SPDY_SESSION_PUSHED_SYN_STREAM
--> associated_stream = 1
--> flags = 2
--> :host: localhost:3000
    :path: /images/00-h.jpg
    :scheme: https
--> id = 2

I still end up with an invalid stream:

SPDY_STREAM_ERROR
--> description = "ABANDONED (stream_id=2): /images/00-h.jpg"
--> status = -100
--> stream_id = 2

Looking through the Chromium source code, this error arises when a SPDY session times out and there are still streams open.

But why is that stream still open? Node-spdy sent a DATA FIN packet. Chrome even seemed to acknowledge that it received the DATA FIN by virtue of the zero length DATA packet (Chrome has never logged FIN flags for some reason) and the SPDY_STREAM_ADOPTED_PUSH_STREAM log message.

But, sure enough, after the session times out with the push stream abandoned, Chrome makes another, non-push request for my push resource in a new SPDY session:

SPDY_SESSION_SYN_STREAM
--> flags = 1
--> :host: localhost:3000
    :method: GET
    :path: /images/00-h.jpg
    :scheme: https
    :version: HTTP/1.1
    accept: */*
    accept-charset: ISO-8859-1,utf-8;q=0.7,*;q=0.3
    accept-encoding: gzip,deflate,sdch
    accept-language: en-US,en;q=0.8
    referer: https://localhost:3000/real
    user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/536.11 (KHTML, like Gecko) Chrome/20.0.1132.11 Safari/536.11
--> id = 1

In other words, even though I said that I was going to push that image, Chrome seemed to acknowledge that I was pushing that image and that it received bunches of data without error, this resource is still not in Chrome's browser cache.

I suspect that I am missing a magic header or two somewhere. I will likely have to ask on the mailing list because I have to call it a night with it still broken.


Day #392