Spdylay and SPDY/3

‹prev | My Chain | next›

I had all but given up trying to test out my flow control implementation in node-spdy. Flow control is new in version 3 of the SPDY protocol. I think my implementation—even the race condition handling—is sound. But, since Chrome currently has no way to adjust its own data transfer window, I cannot use it to test my solution.

While chatting on the spdy-dev mailing list, however, Tatsuhiro Tsujikawa, the maintainer of spdylay said that he had added support for different receive window sizes. That sounds perfect, so I grab a copy of the spdylay repository and run the configure steps:

git clone https://github.com/tatsuhiro-t/spdylay.git
autoreconf -i
automake # there was no visible output from this command
autoconf # there was no visible output from this command
./configure --prefix=$HOME/local

The --prefix=$HOME/local option is my preference. I do not like installing unsigned code with root privileges, so I use the standard --prefix switch to signify that the resultant executable and shared libraries will be installed in $HOME/local (instead of the default /usr/local).

I do not have to worry about the prerequisites. I have been playing with SPDY for so long that I already have all the important development libraries needed.

The result of the configure command confirms that everything is in order:

configure: summary of build options:

    version:        0.1.0 shared 0:0:0
    Host type:      x86_64-unknown-linux-gnu
    Install prefix: /home/chris/local
    C compiler:     gcc
    CFlags:         -g -O2  
    Library types:  Shared=yes, Static=yes
    CUnit:          no
    OpenSSL:        yes
    Examples:       yes

So I build and install spdylay:

make
make install

With that, I have the desired spdycat command installed:

➜  spdylay git:(master) which spdycat
/home/chris/local/bin/spdycat

More importantly, it is not crashy:

➜  spdylay git:(master) spdycat --help
Usage: spdycat [-Onv3] [-t=seconds] [-w=window_bits] [--cert=CERT]
               [--key=KEY] URI...

OPTIONS:
    -v, --verbose      Print debug information such as reception/
                       transmission of frames and name/value pairs.
    -n, --null-out     Discard downloaded data.
    -O, --remote-name  Save download data in the current directory.
                       The filename is dereived from URI. If URI
                       ends with '/', 'index.html' is used as a
                       filename. Not implemented yet.
    -3, --spdy3        Only use SPDY/3.
    -t, --timeout=N    Timeout each request after N seconds.
    -w, --window-bits=N  Sets the initial window size to 2**N.
    --cert=CERT        Use the specified client certificate file.
                       The file must be in PEM format.
    --key=KEY          Use the client private key file. The file
                       must be in PEM format.

So, it is time to fire it up against my spdy/3 express.js site:

➜  spdylay git:(master) spdycat -v3 https://localhost:3000
[  0.004] NPN select next protocol: the remote server offers:
          * spdy/3
          * spdy/2
          * http/1.1
          * http/1.0
          NPN selected the protocol: spdy/3
[  0.013] send SYN_STREAM frame <version=3, flags=1, length=102>
          (stream_id=1, assoc_stream_id=0, pri=3)
          :host: localhost:3000
          :method: GET
          :path: /
          :scheme: https
          :version: HTTP/1.1
          accept: */*
          user-agent: spdylay/0.1.0
[  0.021] send GOAWAY frame <version=3, flags=0, length=8>
          (last_good_stream_id=0)

Hrm... that does not seem right. It looks to have successfully connected and determined that the server was spdy/3 capable. But immediately after sending the usual SYN_STREAM, it told the server to GOAWAY. There is no explanation that I can see for this seemingly rude behavior.

So I downgrade my SPDY server to spdy/2 and try again:

➜  spdylay git:(master) spdycat -v https://localhost:3000         
[  0.003] NPN select next protocol: the remote server offers:
          * spdy/2
          * http/1.1
          * http/1.0
          NPN selected the protocol: spdy/2
[  0.009] send SYN_STREAM frame <version=2, flags=1, length=111>
          (stream_id=1, assoc_stream_id=0, pri=3)
          :host: localhost:3000
          :method: GET
          :path: /
          :scheme: https
          :version: HTTP/1.1
          accept: */*
          user-agent: spdylay/0.1.0
[  0.011] recv SETTINGS frame <version=2, flags=0, length=12>
          (niv=1)
          [4(1):100]
[  0.047] recv SYN_REPLY frame <version=2, flags=0, length=80>
          (stream_id=1)
          x-powered-by: Express
          content-type: text/html
          content-length: 629
          :status: 200 OK
          :version: HTTP/1.1
<!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.0 Transitional//EN" "http://www.w3.org/TR/xhtml1/DTD/xhtml1-transitional.dtd"><html><head><title>Express w/ SPDY 3</title><link rel="stylesheet" href="/stylesheets/style.css"/><script src="/main.js"></script></head><body><h1>Express w/ SPDY 3</h1><p>Welcome to Express w/ SPDY 3</p><p><Here>is a huge image (830kb)</Here><br/><jammed>into a height=200</jammed><br/>&lt;img&gt; tag:
</p><img src="images/pipelining.jpg" height="200"/><p><And>another image (956kb)</And><br/><Also>jammed into a small</Also><br/>&lt;img&gt; tag:
</p><img src="images/tube.jpg" height="200"/></body></html>[  0.047] recv DATA frame (stream_id=1, flags=0, length=629)
[  0.047] recv DATA frame (stream_id=1, flags=1, length=0)
[  0.047] send GOAWAY frame <version=2, flags=0, length=4>
          (last_good_stream_id=0)

Hrm... it would be nice if spdycat followed the Javascript and image links in there in order to get a better feel for real SPDY conversations. Still, it works so my problems is not spdycat but something in the spdy/3 conversation.

Since I spdycat is being unhelpful here, I am forced to inspect the SPDY conversation with Wireshark. What I find is that node-spdy is sending back a SETTINGS frame, which ought to be perfectly OK:

It ought to be OK because both Chrome and Firefox not only accept this frame, but seem to process it. spdycat on the other hand, not so much.

Update: Figured out my problem. I had encoded the wrong number of entries in the SETTINGS frame (I advertised 2 but only sent 1). I could ask for a more helpful error message, but the problem is solved and I have my spdy/3 conversation:

➜  spdylay git:(master) spdycat -vvv https://localhost:3000 
[  0.007] NPN select next protocol: the remote server offers:
          * spdy/3
          * spdy/2
          * http/1.1
          * http/1.0
          NPN selected the protocol: spdy/3
[  0.017] send SYN_STREAM frame <version=3, flags=1, length=102>
          (stream_id=1, assoc_stream_id=0, pri=3)
          :host: localhost:3000
          :method: GET
          :path: /
          :scheme: https
          :version: HTTP/1.1
          accept: */*
          user-agent: spdylay/0.1.0
[  0.019] recv SETTINGS frame <version=3, flags=0, length=12>
          (niv=1)
          [4(1):100]
[  0.093] recv SYN_REPLY frame <version=3, flags=0, length=34>
          (stream_id=1)
          :status: 200
          :version: HTTP/1.1
<!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.0 Transitional//EN" "http://www.w3.org/TR/xhtml1/DTD/xhtml1-transitional.dtd"><html><head><title>Express w/ SPDY 3</title><link rel="stylesheet" href="/stylesheets/style.css"/><script src="/main.js"></script></head><body><h1>Express w/ SPDY 3</h1><p>Welcome to Express w/ SPDY 3</p><p><Here>is a huge image (830kb)</Here><br/><jammed>into a height=200</jammed><br/>&lt;img&gt; tag:
</p><img src="images/pipelining.jpg" height="200"/><p><And>another image (956kb)</And><br/><Also>jammed into a small</Also><br/>&lt;img&gt; tag:
</p><img src="images/tube.jpg" height="200"/></body></html>[  0.093] recv DATA frame (stream_id=1, flags=0, length=629)
[  0.094] recv DATA frame (stream_id=1, flags=1, length=0)
[  0.094] send GOAWAY frame <version=3, flags=0, length=8>
          (last_good_stream_id=0)

With that, I can try out my update receive window code by way of the -w switch. I use that switch to specify a 16kb receive window (2¹⁴ == 16kb):

➜  spdylay git:(master) spdycat -v -w14 -n https://localhost:3000/images/pipelining.jpg
[  0.003] NPN select next protocol: the remote server offers:
          * spdy/3
          * spdy/2
          * http/1.1
          * http/1.0
          NPN selected the protocol: spdy/3
[  0.008] send SETTINGS frame <version=3, flags=0, length=12>
          (niv=1)
          [7(0):16384]
[  0.008] send SYN_STREAM frame <version=3, flags=1, length=118>
          (stream_id=1, assoc_stream_id=0, pri=3)
          :host: localhost:3000
          :method: GET
          :path: /images/pipelining.jpg
          :scheme: https
          :version: HTTP/1.1
          accept: */*
          user-agent: spdylay/0.1.0
[  0.009] recv SETTINGS frame <version=3, flags=0, length=12>
          (niv=1)
          [4(1):100]
[  0.017] recv SYN_REPLY frame <version=3, flags=0, length=34>
          (stream_id=1)
          :status: 200
          :version: HTTP/1.1
[  0.017] recv DATA frame (stream_id=1, flags=0, length=1300)
[  0.017] recv DATA frame (stream_id=1, flags=0, length=1300)
[  0.017] recv DATA frame (stream_id=1, flags=0, length=1300)
[  0.017] recv DATA frame (stream_id=1, flags=0, length=1300)
[  0.017] recv DATA frame (stream_id=1, flags=0, length=1300)
....
          (stream_id=1, delta_window_size=9100)
[  0.227] recv DATA frame (stream_id=1, flags=0, length=1300)
[  0.265] recv DATA frame (stream_id=1, flags=0, length=1300)
[  0.265] recv DATA frame (stream_id=1, flags=0, length=1300)
[  0.265] recv DATA frame (stream_id=1, flags=0, length=1300)
[  0.265] recv DATA frame (stream_id=1, flags=0, length=1300)
[  0.265] recv DATA frame (stream_id=1, flags=0, length=1300)

It actually seems to work right up until the end when the server seemingly fails to send more data. At first glance, my implementation in node-spdy seems to be at fault, but I will investigate further tomorrow.


Day #380