I am about to give up on SPDY server push with node-spdy. Before I do, I feel compelled to give it one more try.
I took a step back last night (I think) when I concentrated on fiddling with relative URLs in the SYN_STREAM that initiated the push stream. It seemed a reasonable thing to try given that all URLs that show up in other streams are root relative (e.g. /style.css instead of https://localhost:8081/style.css).
The magical thing that goes missing when using relative URLs is the SPDY_STREAM_ADOPTED_PUSH_STREAM that I saw two nights ago:
t=1306724141170 [st=88] SPDY_STREAM_ADOPTED_PUSH_STREAMTo my still-in-training eye, that SPDY_STREAM_ADOPTED_PUSH_STREAM seems a good thing.
First up tonight, I fiddle with the point at which I send the data FIN on the push stream. The other night, I sent the push stream FIN immediately after sending the push stream DATA and before sending the FIN on the SYN_REPLY. Tonight, I try sending the push stream FIN after sending all of the data in the original reply (i.e. the homepage):
Response.prototype.end = function(data, encoding) {
this.writable = false;
this._write(data, encoding, true);
if (this.push_stream) {
this.push_stream.end();
}
};Loading that up in the browser and checking the SPDY log in Chrome's about:net-internals, I find:t=1306892767809 [st= 48] SPDY_SESSION_PUSHED_SYN_STREAMBack to where I was the other night. I have my desired SPDY_STREAM_ADOPTED_PUSH_STREAM, but then the SPDY session just hangs.
--> associated_stream = 1
--> flags = 2
--> cache-control: public, max-age=0
content-length: 20
content-type: text/css; charset=UTF-8
etag: 347-1306200491000
last-modified: Tue, 24 May 2011 01:28:11 GMT
url: https://localhost:8081/style.css
--> id = 2
t=1306892767809 [st= 48] SPDY_SESSION_RECV_DATA
--> flags = 0
--> size = 20
--> stream_id = 2
t=1306892767810 [st= 49] SPDY_SESSION_RECV_DATA
--> flags = 0
--> size = 698
--> stream_id = 1
t=1306892767810 [st= 49] SPDY_SESSION_RECV_DATA
--> flags = 0
--> size = 0
--> stream_id = 1
t=1306892767810 [st= 49] SPDY_SESSION_RECV_DATA
--> flags = 0
--> size = 0
--> stream_id = 2
t=1306892767879 [st=118] SPDY_STREAM_ADOPTED_PUSH_STREAM
Checking the packet specifics out with Wireshark, I see the SYN_REPLY returned:
+----------------------------------+That will contain headers for the homepage. Next is the push stream's SYN_STREAM:
80 02 00 02 |1| 1 | 2 |
+----------------------------------+
00 00 00 a4 | Flags (8) | Length (24 bits) |
+----------------------------------+
00 00 00 01 |X| Stream-ID (31bits) |
+----------------------------------+
00 00 78 bb | Unused | |
df a2 51 b2 +---------------- |
62 e0 64 e0 | Name/value header block |
42 c4 10 03 | ... |
57 76 6a 6a
81 6e 62 4e 66 59 2a 03 1f 6a 90 33 30 9b 59 5a
30 f0 a2 c4 2d 83 20 c4 1d 3a 0a 50 97 d8 1a 30
f0 a2 04 2e 83 2c 30 38 75 14 8c 4c 14 80 c1 a3
00 cc 0b 86 0a 06 86 56 46 16 56 40 86 bb 6f 08
03 0b 28 56 18 84 95 80 66 eb 02 b3 84 19 30 c3
98 58 02 f3 8e 81 12 03 0f 72 e4 31 48 c0 c3 cf
5a 01 e6 df d0 10 37 5d a0 93 50 d2 3b 03 6b 52
65 09 90 62 83 78 95 81 0d 68 a2 82 bf 37 03 3b
d4 d3 0c 1c b0 b0 00 00 00 00 ff ff
+----------------------------------+Then comes the data for the push stream (ID = 2):
80 02 00 01 |1| 1 | 1 |
+----------------------------------+
02 00 00 51 | Flags (8) | Length (24 bits) |
+----------------------------------+
00 00 00 02 |X| Stream-ID (31bits) |
+----------------------------------+
00 00 00 01 |X|Associated-To-Stream-ID (31bits)|
+----------------------------------+
00 00 62 60 | Pri | Unused | |
+------------------ |
| Name/value header block |
23 c2 37 cc | ... |
a0 40 52 c8
28 29 29 28
b6 d2 d7 07 25 b7 1c 50 a1 62 65 61 60 61 a8 5f
5c 52 99 93 aa 97 5c 5c 8c 11 56 4c 46 06 68 ee
17 07 bb 1f a8 16 dd f9 90 10 10 34 36 31 47 0d
00 d2 02 12 00 00 00 ff ff
+----------------------------------+The data in that frame is uncompressed. Checking it out in hex+text view, I see that it is my dummy stylesheet:
00 00 00 02 |C| Stream-ID (31bits) |
+----------------------------------+
00 00 00 14 | Flags (8) | Length (24 bits) |
+----------------------------------+
68 31 20 7b | Data |
20 63 6f 6c +----------------------------------+
6f 72 3a 20
6f 72 61 6e
67 65 20 7d
0000 00 00 00 02 00 00 00 14 68 31 20 7b 20 63 6f 6c ........h1 { col
0010 6f 72 3a 20 6f 72 61 6e 67 65 20 7d or: orange }The next frame through is the data frame for the SYN_REPLY, the homepage:0000 00 00 00 01 00 00 02 ba 3c 21 44 4f 43 54 59 50 ........<!DOCTYPThen, the data FIN for the SYN_REPLY:
0010 45 20 68 74 6d 6c 3e 0a 3c 68 74 6d 6c 3e 0a 20 E html>.<html>.
...
+----------------------------------+Which is followed by the data FIN for the push stream (ID = 2):
00 00 00 01 |C| Stream-ID (31bits) |
+----------------------------------+
01 00 00 00 | Flags (8) | Length (24 bits) |
+----------------------------------+
| Data |
+----------------------------------+
+----------------------------------+Everything looks just as I would expect and as was shown in the SPDY log in Chrome.
00 00 00 02 |C| Stream-ID (31bits) |
+----------------------------------+
01 00 00 00 | Flags (8) | Length (24 bits) |
+----------------------------------+
| Data |
+----------------------------------+
If I escape/stop the blocked SPDY session, then I see the following RST_STREAM coming from the client:
+-------------------------------+A status code of 0x05 means:
80 02 00 03 |1| 1 | 3 |
+-------------------------------+
00 00 00 08 | Flags (8) | 8 |
+-------------------------------+
00 00 00 02 |X| Stream-ID (31bits) |
+-------------------------------+
00 00 00 05 | Status code |
+-------------------------------+
5 - CANCEL. Used by the creator of a stream to indicate that the stream is no longer needed.Next up is the new SYN_STREAM from the client requesting the next resource:
+----------------------------------+The rest of the SPDY session is just normal SPDY as if I had never send the push stream. So fiddling with the order of data FIN seems to have no effect on things.
80 02 00 01 |1| 1 | 1 |
+----------------------------------+
01 00 00 2f | Flags (8) | Length (24 bits) |
+----------------------------------+
00 00 00 03 |X| Stream-ID (31bits) |
+----------------------------------+
00 00 00 00 |X|Associated-To-Stream-ID (31bits)|
+----------------------------------+
80 00 62 e0 | Pri | Unused | |
82 c7 14 33 +------------------ |
30 cc 07 26 | Name/value header block |
b4 89 09 54 | ... |
2c 41 c8 a3
9f 96 58 96 09 8c 23 3d 60 b2 1f 14
a1 09 00 00 00 ff ff
Next I try sending a RST_STREAM from the server in addition to the data FIN:
Response.prototype.end = function(data, encoding) {
this.writable = false;
this._write(data, encoding, true);
if (this.push_stream) {
this.push_stream.end();
this.push_stream.reset();
}
};Reloading the page kinda-sorta works in that I see the homepage. Unfortunately, checking out the SPDY log in Chrome's about:net-internals shows that the RST_STREAM prevented the pushed stream from being "adopted". More importantly, the client ignores the pushed stylesheet and asks for it again:t=1306896650130 [st= 41] SPDY_SESSION_PUSHED_SYN_STREAMUnfortunately, I do not see anything in the dump that give me hope. I do see the server-generated RST_STREAM:
--> associated_stream = 1
--> flags = 2
--> cache-control: public, max-age=0
content-length: 20
content-type: text/css; charset=UTF-8
etag: 347-1306200491000
last-modified: Tue, 24 May 2011 01:28:11 GMT
url: https://localhost:8081/style.css
--> id = 2
t=1306896650130 [st= 41] SPDY_SESSION_RECV_DATA
--> flags = 0
--> size = 20
--> stream_id = 2
t=1306896650130 [st= 41] SPDY_SESSION_RECV_DATA
--> flags = 0
--> size = 698
--> stream_id = 1
t=1306896650130 [st= 41] SPDY_SESSION_RECV_DATA
--> flags = 0
--> size = 0
--> stream_id = 1
t=1306896650140 [st= 51] SPDY_SESSION_RECV_DATA
--> flags = 0
--> size = 0
--> stream_id = 2
t=1306896650140 [st= 51] SPDY_SESSION_RST_STREAM
--> status = 5
--> stream_id = 2
t=1306896650172 [st= 83] SPDY_SESSION_SYN_STREAM
--> flags = 1
--> accept: text/css,*/*;q=0.1
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
cache-control: no-cache
host: localhost:8081
method: GET
pragma: no-cache
referer: https://localhost:8081/
scheme: https
url: /style.css
user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/535.1 (KHTML, like Gecko) Chrome/13.0.772.0 Safari/535.1
version: HTTP/1.1
--> id = 3
t=1306896650177 [st= 88] SPDY_SESSION_SYN_REPLY
--> flags = 0
--> accept-ranges: bytes
cache-control: public, max-age=0
connection: keep-alive
content-length: 347
content-type: text/css; charset=UTF-8
etag: "347-1306200491000"
last-modified: Tue, 24 May 2011 01:28:11 GMT
status: 200 OK
version: HTTP/1.1
--> id = 3
t=1306896650177 [st= 88] SPDY_SESSION_RECV_DATA
But the very next SPDY frame is the client initiating the SYN_STREAM to request the stylesheet:
+-------------------------------+
80 02 00 03 |1| 1 | 3 |
+-------------------------------+
00 00 00 08 | Flags (8) | 8 |
+-------------------------------+
00 00 00 02 |X| Stream-ID (31bits) |
+-------------------------------+
00 00 00 05 | Status code |
+-------------------------------+
There are no stray frames floating about that might give some indication of what to try next.
+----------------------------------+
80 02 00 01 |1| 1 | 1 |
+----------------------------------+
01 00 00 40 | Flags (8) | Length (24 bits) |
+----------------------------------+
00 00 00 03 |X| Stream-ID (31bits) |
+----------------------------------+
00 00 00 00 |X|Associated-To-Stream-ID (31bits)|
+----------------------------------+
40 00 62 e0 | Pri | Unused | |
85 c7 94 10 +------------------ |
38 a6 92 8b | Name/value header block |
8b e1 81 6f | ... |
38 1c 02 9f
1d 5a 8c 32 88 83 43 df 4a 5f 1f 55
bf 3e d6 e8 e1 d2 2f 2e a9 cc 49 d5 03 06 c7 a0
88 27 00 00 00 00 ff ff
So, for now, I will shut down my direct effort to get SPDY server push working. I will keep working it in the background (along with ruby zlib), but will pick back up tomorrow by taking a closer look at compression in SPDY.
Day #35
