search

tatsuhiro-t / spdylay

The experimental SPDY protocol version 2, 3 and 3.1 implementation in C
http://tatsuhiro-t.github.io/spdylay/
MIT License
602 stars 103 forks source link

check_response_header assert(3)s when mod_spdy pushes anything #35

Closed jhcloos closed 12 years ago

jhcloos commented 12 years ago

When I point spdycat at a site using apache+mod_spdy, which pushes associated content, there is an invariable assert(3) in check_response_header() in the next frame (a SYN_HEADERS fram) after the SYN_REPLY frame which contains the requested body.

W/o associated content, it goes:

[ 0.256] NPN select next protocol: the remote server offers: [ 0.386] send SYN_STREAM frame [ 0.501] recv SETTINGS frame [ 0.522] recv SYN_REPLY frame [ 0.523] recv DATA frame (stream_id=1, flags=1, length=44) [ 0.523] send GOAWAY frame (last_good_stream_id=0)

With associated content (in this case pushing four images and one css), it goes:

[ 0.251] NPN select next protocol: the remote server offers: [ 0.375] send SYN_STREAM frame [ 0.490] recv SETTINGS frame [ 0.493] recv SYN_STREAM frame [ 0.494] recv SYN_STREAM frame [ 0.494] recv SYN_STREAM frame [ 0.494] recv SYN_STREAM frame [ 0.605] recv SYN_STREAM frame [ 0.606] recv SYN_REPLY frame [ 0.606] recv DATA frame (stream_id=1, flags=1, length=1356)

and then assert(3)s, so the next fram (I presume a GOAWAY?) isn’t processed or reported.

I see that the lengths, as reported in the verbose output, of the SYN_STREAM frames are not indicative of the sizes of the associated files or of their URIs. I don’t know whether that is relevant.

Gdb tells me that check_response_header() is called with type=SPDYLAY_HEADERS, frame is:

$5 = {ctrl = {hd = {version = 3, type = 8, flags = 0 '\000', length = 120}}, syn_stream = { hd = {version = 3, type = 8, flags = 0 '\000', length = 120}, stream_id = 2, assoc_stream_id = 6550624, pri = 0 '\000', slot = 0 '\000', nv = 0x40aa25 <spdylay::recv_callback(spdylay_session, unsigned char, unsigned long, int, void)+58>}, syn_reply = {hd = {version = 3, type = 8, flags = 0 '\000', length = 120}, stream_id = 2, nv = 0x63f460}, rst_stream = {hd = {version = 3, type = 8, flags = 0 '\000', length = 120}, stream_id = 2, status_code = 6550624}, settings = { hd = {version = 3, type = 8, flags = 0 '\000', length = 120}, niv = 6550624, iv = 0x40aa25 <spdylay::recv_callback(spdylay_session, unsigned char, unsigned long, int, void)+58>}, ping = {hd = {version = 3, type = 8, flags = 0 '\000', length = 120}, unique_id = 2}, goaway = {hd = {version = 3, type = 8, flags = 0 '\000', length = 120}, last_good_stream_id = 2, status_code = 6550624}, headers = {hd = {version = 3, type = 8, flags = 0 '\000', length = 120}, stream_id = 2, nv = 0x63f460}, window_update = {hd = { version = 3, type = 8, flags = 0 '\000', length = 120}, stream_id = 2, delta_window_size = 6550624}, credential = {hd = {version = 3, type = 8, flags = 0 '\000', length = 120}, slot = 2, proof = {data = 0x63f460 "\b\365c", length = 4237861}, certs = 0x14, ncerts = 140737488331984}}

If I add a return in the SYN_HEADERS if clause, it works and reports the headers and data frames of each of the associated URIs.

tatsuhiro-t commented 12 years ago

I did similar fix with you in 9d6257a. I could not find SPDY site which does server-push, so could you check that the change really fixes the problem?

jhcloos commented 12 years ago

Thanks. It works well now. Feel free to use my server for light testing:

:; spdycat -vn https://jhcloos.com/ [ 0.261] NPN select next protocol: the remote server offers: * spdy/3 * spdy/2 * http/1.1 * x-mod-spdy/0.9.3.2-376 NPN selected the protocol: spdy/3 [ 0.390] send SYN_STREAM frame (stream_id=1, assoc_streamid=0, pri=3) :host: jhcloos.com :method: GET :path: / :scheme: https :version: HTTP/1.1 accept: /_ user-agent: spdylay/0.3.5 [ 0.502] recv SETTINGS frame (niv=1) [4(0):100] [ 0.517] recv SYN_STREAM frame (stream_id=2, assoc_stream_id=1, pri=3) :host: jhcloos.com :path: /jhc.ico :scheme: https [ 0.518] recv SYN_STREAM frame (stream_id=4, assoc_stream_id=1, pri=3) :host: jhcloos.com :path: /layout.css :scheme: https [ 0.519] recv SYN_STREAM frame (stream_id=6, assoc_stream_id=1, pri=3) :host: jhcloos.com :path: /lh.png :scheme: https [ 0.519] recv SYN_STREAM frame (stream_id=8, assoc_stream_id=1, pri=3) :host: jhcloos.com :path: /red.png :scheme: https [ 0.631] recv SYN_STREAM frame (stream_id=10, assoc_stream_id=1, pri=3) :host: jhcloos.com :path: /Secure_Site.png :scheme: https [ 0.631] recv SYN_REPLY frame (stream_id=1) :status: 200 :version: HTTP/1.1 content-length: 1734 content-type: text/html; charset=utf-8 date: Sat, 22 Sep 2012 19:08:18 GMT server: Apache/2.2.22 (Debian) x-mod-spdy: 0.9.3.2-376 x-powered-by: PHP/5.4.4-7 [ 0.632] recv DATA frame (stream_id=1, flags=1, length=1734) [ 0.632] recv HEADERS frame (stream_id=2) :status: 200 :version: HTTP/1.1 accept-ranges: bytes content-length: 1078 content-type: image/vnd.microsoft.icon date: Sat, 22 Sep 2012 19:08:18 GMT etag: "6507c-436-3d3e348f22e40" last-modified: Sat, 21 Feb 2004 21:14:03 GMT server: Apache/2.2.22 (Debian) x-mod-spdy: 0.9.3.2-376 [ 0.633] send GOAWAY frame (last_good_stream_id=10) [ 0.634] recv DATA frame (stream_id=2, flags=1, length=1078) [ 0.634] recv HEADERS frame (stream_id=4) :status: 200 :version: HTTP/1.1 accept-ranges: bytes content-length: 1376 content-type: text/css date: Sat, 22 Sep 2012 19:08:18 GMT etag: "648cb-560-4ca1b49819740" last-modified: Thu, 20 Sep 2012 05:20:29 GMT server: Apache/2.2.22 (Debian) x-mod-spdy: 0.9.3.2-376 [ 0.636] recv DATA frame (stream_id=4, flags=1, length=1376) [ 0.636] recv HEADERS frame (stream_id=10) :status: 200 :version: HTTP/1.1 accept-ranges: bytes content-length: 9869 content-type: image/png date: Sat, 22 Sep 2012 19:08:18 GMT etag: "6411b-268d-4ca1b2d226840" last-modified: Thu, 20 Sep 2012 05:12:33 GMT server: Apache/2.2.22 (Debian) x-mod-spdy: 0.9.3.2-376 [ 0.637] recv HEADERS frame (stream_id=6) :status: 200 :version: HTTP/1.1 accept-ranges: bytes content-length: 27983 content-type: image/png date: Sat, 22 Sep 2012 19:08:18 GMT etag: "64079-6d4f-4ca1b2d226840" last-modified: Thu, 20 Sep 2012 05:12:33 GMT server: Apache/2.2.22 (Debian) x-mod-spdy: 0.9.3.2-376 [ 2.127] recv HEADERS frame (stream_id=8) :status: 200 :version: HTTP/1.1 accept-ranges: bytes content-length: 83 content-type: image/png date: Sat, 22 Sep 2012 19:08:18 GMT etag: "64a4c-53-48127f3cf4f40" last-modified: Sat, 06 Mar 2010 20:47:57 GMT server: Apache/2.2.22 (Debian) x-mod-spdy: 0.9.3.2-376 [ 2.127] recv DATA frame (stream_id=8, flags=1, length=83) [ 2.248] recv DATA frame (stream_id=6, flags=0, length=4096) [ 2.286] recv DATA frame (stream_id=6, flags=0, length=4096) [ 2.368] recv DATA frame (stream_id=6, flags=0, length=4096) [ 2.370] recv DATA frame (stream_id=6, flags=0, length=4096) [ 2.404] recv DATA frame (stream_id=6, flags=0, length=4096) [ 2.481] recv DATA frame (stream_id=6, flags=0, length=4096) [ 2.483] recv DATA frame (stream_id=6, flags=1, length=3407) [ 2.489] recv DATA frame (stream_id=10, flags=0, length=4096) [ 2.491] recv DATA frame (stream_id=10, flags=0, length=4096) [ 2.515] recv DATA frame (stream_id=10, flags=1, length=1677)