Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Is there any way to set dynamic table size limit to mitigate TooSmallTableSize decode error? #65

Closed
swamp-agr opened this issue Feb 12, 2019 · 29 comments

Comments

@swamp-agr
Copy link

swamp-agr commented Feb 12, 2019

Hi, @lucasdicioccio!

I am trying to invoke GET query with http2-client and constantly receive:

*** Exception: ExceptionInLinkedThread ThreadId 313 TooSmallTableSize

Could you please advise how to tweak the dynamic table size limit?

Upd. Length of :path value is equal to 193.

Thanks,
@swamp-agr

@lucasdicioccio
Copy link
Member

Hi Andrey, what type of server are you communicating with? can you get queries with :path = "/" to return an answer (even if 404)?

There's a cURL-like utility to help exercising the library: http2-client-exe . If you can reproduce and post a trace with http2-client-exe --verbose that would be great.

If i remember correctly that could happen if the remote is changing settings too low. That error seems to come from HPACK in the http2 library directly. I'll try to dig a bit further, but won't have time before the week-end.

@swamp-agr
Copy link
Author

swamp-agr commented Feb 12, 2019

Hi Lucas,

Thank you for quick response!
As you suggested, I tried to invoke GET on :path = "/" and received the same error.
To be honest, I do not have information about type of server, I guess there is a python under the hood.

I will try to reproduce the issue with http2-client-exe as you suggested. BTW, curl invokation worked just fine.

Yes, exactly, the error came from HPACK and to be precisely either from decodeHeader or from decodeTokenHeader.

Please expect update shortly.

Thanks and Regards,
Andrey

@swamp-agr
Copy link
Author

Issue reproduced with http2-client-exe:

(2019-02-12 21:11:18.212667 UTC,[(SettingsMaxFrameSize,1048576),(SettingsMaxConcurrentStreams,100),(SettingsMaxHeaderBlockSize,1048576),(SettingsInitialWindowSize,10485760),(SettingsEnablePush,1)])
(">>> ",0,[(0,SettingsFrame [(SettingsMaxFrameSize,1048576),(SettingsMaxConcurrentStreams,100),(SettingsMaxHeaderBlockSize,1048576),(SettingsInitialWindowSize,10485760),(SettingsEnablePush,1)])])
("<<< ",0,(FrameHeader {payloadLength = 18, flags = 0, streamId = 0},Right (SettingsFrame [(SettingsMaxConcurrentStreams,128),(SettingsInitialWindowSize,65536),(SettingsMaxFrameSize,16777215)])))
(">>> ",0,[(1,SettingsFrame [])])
("<<< ",0,(FrameHeader {payloadLength = 4, flags = 0, streamId = 0},Right (WindowUpdateFrame 2147418112)))
(">>> ",1,[(5,HeadersFrame Nothing "\130\135\EOT\255\r`r!\142\227BX\152\169c\252=\169\129\159\131\214H\ESCv1\150W\219\141\182H\212m\200\225\ESCvF\202\247\193\r$\SOH\NUL>\tR`\SI\196\150\217\NUL>\a!\164\131\224u\214i \248A\146X\141$\r6\239\199\179\212X\141$\SI8\NUL\252Vi q\231]o\226\146\200a\196i y\151\196\211\223\b4\144$\168O\194{\196I\199UE\162#I\STXJ\132\196I\199UE\163\226b\158\EOT\149\t\138b\159\226\146\200a\192j\211\223A\138\FS\136^\164\DC1j\a\SUB\230?@\133M\131\&5\ENQ\179\128")])
(2019-02-12 21:11:18.328342 UTC,"stream started (1,1)")
("<<< ",0,(FrameHeader {payloadLength = 0, flags = 1, streamId = 0},Right (SettingsFrame [])))
("<<< ",1,(FrameHeader {payloadLength = 55, flags = 4, streamId = 1},Right (HeadersFrame Nothing " H\ETX403v\137\170cU\229\128\174\SYN\151\aa\150\223i~\148\b\148\194X\212\DLE\STX\250\130\r\192\134\224^S\SYN\141\255_\135I|\165\137\211M\US\\\ETX169")))
http2-client-exe: ExceptionInLinkedThread ThreadId 13 TooSmallTableSize

@swamp-agr
Copy link
Author

OK, I will try to clone http2-client and to add printDynamicTable into some dispatch* functions for further investigation.

@lucasdicioccio
Copy link
Member

Thanks @swamp-agr ! we've narrowed that down to the library and not you "using it wrong".
I'll need some time to get back into the library code and try simulating what happens from your trace.

I don't see settings changes for SETTINGS_HEADER_TABLE_SIZE exchanged, so it feels like the server not honoring the default 4K size (or maybe some bug in http2 -- Kazu might be able to help). I'll have a look this WE but in the meantime you don't have an easy way out: I've not exposed ways to increase that settings yet (at the time I was unsure if it's more about shooting-oneself-in-the-foot than making users a good service). But you can try playing with http2-client library locally and try increasing the HPACK buffer size to a value higher than 4K (e.g., 64K) where I call newDynamicTableForDecoding in src/Network/HTTP2/Client/Dispatch.hs.

@lucasdicioccio
Copy link
Member

lucasdicioccio commented Feb 12, 2019

Alternatively, the issue is within the HPACK code itself: HPACK has its own "protocol-like" within HTTP2 HEADERS frame, but so far I've always treated this part as a black-box and Kazu is probably your man (time to step up my game I guess :-)).

@swamp-agr
Copy link
Author

swamp-agr commented Feb 12, 2019

@lucasdicioccio, many thanks for clarification. I will share with you my findings.
I am starting to like HTTP/2 :)

@swamp-agr
Copy link
Author

swamp-agr commented Feb 13, 2019

I think, I have a clue. Analysing why curl works, I tested the same query by nghttp cli utility from nghttp2 package and it shown that PRIORITY frames sent to server before further negotiation.

Note. nghttp always sends these PRIORITY requests.

[  0.039] Connected
The negotiated protocol: h2
[  0.062] recv SETTINGS frame <length=18, flags=0x00, stream_id=0>
          (niv=3)
          [SETTINGS_MAX_CONCURRENT_STREAMS(0x03):128]
          [SETTINGS_INITIAL_WINDOW_SIZE(0x04):65536]
          [SETTINGS_MAX_FRAME_SIZE(0x05):16777215]
[  0.062] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=0>
          (window_size_increment=2147418112)
[  0.062] send SETTINGS frame <length=12, flags=0x00, stream_id=0>
          (niv=2)
          [SETTINGS_MAX_CONCURRENT_STREAMS(0x03):100]
          [SETTINGS_INITIAL_WINDOW_SIZE(0x04):65535]
[  0.062] send SETTINGS frame <length=0, flags=0x01, stream_id=0>
          ; ACK
          (niv=0)
[  0.062] send PRIORITY frame <length=5, flags=0x00, stream_id=3>
          (dep_stream_id=0, weight=201, exclusive=0)
[  0.062] send PRIORITY frame <length=5, flags=0x00, stream_id=5>
          (dep_stream_id=0, weight=101, exclusive=0)
[  0.062] send PRIORITY frame <length=5, flags=0x00, stream_id=7>
          (dep_stream_id=0, weight=1, exclusive=0)
[  0.062] send PRIORITY frame <length=5, flags=0x00, stream_id=9>
          (dep_stream_id=7, weight=1, exclusive=0)
[  0.062] send PRIORITY frame <length=5, flags=0x00, stream_id=11>
          (dep_stream_id=3, weight=1, exclusive=0)
[  0.062] send HEADERS frame <length=179, flags=0x25, stream_id=13>
          ; END_STREAM | END_HEADERS | PRIORITY
          (padlen=0, dep_stream_id=11, weight=16, exclusive=0)
          ; Open new stream
          :method: GET
          :path: ...
          :scheme: https
          :authority: ...
          accept: */*
          accept-encoding: gzip, deflate
          user-agent: nghttp2/1.36.0
[  0.069] recv SETTINGS frame <length=0, flags=0x01, stream_id=0>
          ; ACK
          (niv=0)
[  0.088] recv (stream_id=13) :status: 200
[  0.088] recv (stream_id=13) server: nginx/1.14.0
[  0.088] recv (stream_id=13) date: Tue, 12 Feb 2019 23:14:58 GMT
[  0.088] recv (stream_id=13) content-type: text/xml
[  0.088] recv (stream_id=13) content-length: 855
[  0.088] recv (stream_id=13) accept-encoding: gzip
[  0.088] recv (stream_id=13) access-control-allow-credentials: true
[  0.088] recv (stream_id=13) cache-control: no-store, no-cache, must-revalidate, max-age=0
[  0.088] recv (stream_id=13) p3p: policyref=/w3c/w3c.p3p, CP=NON CUR ADM DEV PSA PSD OUR IND UNI NAV INT STA
[  0.088] recv (stream_id=13) pragma: no-cache
[  0.088] recv (stream_id=13) content-encoding: gzip
[  0.088] recv (stream_id=13) set-cookie: ...; Domain=...; HttpOnly; Max-Age=157766400; Path=/
[  0.088] recv (stream_id=13) set-cookie: ...; Domain=...; Max-Age=157766400; Path=/
[  0.088] recv (stream_id=13) set-cookie: ...; Domain=...; HttpOnly; Max-Age=157766400; Path=/
[  0.088] recv HEADERS frame <length=458, flags=0x04, stream_id=13>
          ; END_HEADERS
          (padlen=0)
          ; First response header
<?xml version='1.0' encoding='UTF-8' standalone='yes'?>
    let go = delayException . forever $ do
            HPACK.printDynamicTable $ _dispatchHPACKDynamicTable dh -- !!!
            frame <- getNextFrame
  • After that output of client changed accordingly:
(2019-02-13 14:57:11.820714 UTC,[(SettingsMaxFrameSize,16384),(SettingsMaxConcurrentStreams,100),(SettingsMaxHeaderBlockSize,1048576),(SettingsInitialWindowSize,2147418112),(SettingsEnablePush,1),(SettingsHeaderTableSize,65536)])
(">>> ",0,[(0,SettingsFrame [(SettingsMaxFrameSize,16384),(SettingsMaxConcurrentStreams,100),(SettingsMaxHeaderBlockSize,1048576),(SettingsInitialWindowSize,2147418112),(SettingsEnablePush,1),(SettingsHeaderTableSize,65536)])])
      Table size: 0/655360
("<<< ",0,(FrameHeader {payloadLength = 18, flags = 0, streamId = 0},Right (SettingsFrame [(SettingsMaxConcurrentStreams,128),(SettingsInitialWindowSize,65536),(SettingsMaxFrameSize,16777215)])))
(">>> ",0,[(1,SettingsFrame [])])
      Table size: 0/655360
("<<< ",0,(FrameHeader {payloadLength = 4, flags = 0, streamId = 0},Right (WindowUpdateFrame 2147418112)))
      Table size: 0/655360
(">>> ",1,[(5,HeadersFrame Nothing "\130\EOT\255\r`r!\142\227BX\152\169c\252=\169\129\159\131\214H\ESCv1\150W\219\141\182H\212m\200\225\ESCvF\202\247\193\r$\SOH\NUL>\tR`\SI\196\150\217\NUL>\a!\164\131\224u\214i \248A\146X\141$\r6\239\199\179\212X\141$\SI8\NUL\252Vi q\231]o\226\146\200a\196i y\151\196\211\223\b4\144$\168O\194{\196I\199UE\162#I\STXJ\132\196I\199UE\163\226b\158\EOT\149\t\138b\159\226\146\200a\192j\211\223\135A\138\FS\136^\164\DC1j\a\SUB\230?S\131\249c\231\144@\133M\131\&5\ENQ\179\128")])
(2019-02-13 14:57:11.908085 UTC,"stream started (1,1)")
("<<< ",0,(FrameHeader {payloadLength = 0, flags = 1, streamId = 0},Right (SettingsFrame [])))
      Table size: 0/655360
("<<< ",1,(FrameHeader {payloadLength = 55, flags = 4, streamId = 1},Right (HeadersFrame Nothing " H\ETX403v\137\170cU\229\128\174\SYN\151\aa\150\228Y>\148\v*a,j\b\SOH}@\181q\183n\EOT*b\209\191_\135I|\165\137\211M\US\\\ETX169")))
http2-client-exe: ExceptionInLinkedThread ThreadId 13 TooSmallTableSize
  • Looks like dynamic table was not populated and still empty.

@lucasdicioccio, could you please suggest further steps?

Thanks,
@swamp-agr

@swamp-agr
Copy link
Author

I added some printers to http2 decoder and started to understand what is going on. Will come back soon with a summary.

@swamp-agr
Copy link
Author

Separate issue created for http2.
Please do not close this one, I have to be sure that no changes required in high-level logic.

@swamp-agr
Copy link
Author

After some research it was determined that 1st bit of failing bytestring is a priority flag E (0x2) of PRIORITY Frame Payload.

 +-+-------------------------------------------------------------+
 |E|                  Stream Dependency (31)                     |
 +-+-------------+-----------------------------------------------+
 |   Weight (8)  |
 +-+-------------+

Let me analyse how to handle Priority Frame on http2-client side.

@lucasdicioccio
Copy link
Member

lucasdicioccio commented Feb 16, 2019

I'll have a bit more time late today or tomorrow to setup a proper "lab-like example". Thanks a lot for these investigations!

At the moment I think two broad things can occur:

  • a problem in the framing that leads the client to decode a PRIORITY(or something else) as a HEADERS frame
  • a problem with the HPACK decoding of a valid HEADERS+CONTINUATION frames

Further, the semantics of PRIORITY is likely not the culprit: they should just be ignored and help sequencing streams -- which we don't do yet.

One thing interesting is that http2-client sees a payloadLength of 55bytes for the HEADERS frame (FrameHeader {payloadLength = 55, flags = 4, streamId = 1} whereas curl with nghttp2 sees 458bytes (maybe after HPACK-deflating?) [ 0.088] recv HEADERS frame <length=458, flags=0x04, stream_id=13>. Maybe there's more data to wait for and concatenate before calling the decodeHeader function.

Tomorrow I'll try to decode the 55bytes in your headers payload using HPACK decoder in a GHCi session. Also, encoding the 458bytes of the headers seen by curl. These will give us a lot of insights

@swamp-agr
Copy link
Author

swamp-agr commented Feb 16, 2019

Hi Lucas,

Thank you for explanation!

  • I think I made 2 different tests (1st for http2-client and 2nd for nghttp), since I was able to decode the message:
    Do not allow update max dynamic table size to 0 kazu-yamamoto/http2#16 (comment) (please also review the thread for more details of HPACK decoding).

  • it was: Entry 42 (Token {ix = 4, shouldBeIndexed = True, isPseudo = True, tokenKey = ":status"}) "403")`.

  • Meanwhile, issue reproduced with both tests.

  • I found part where http2-client received frames from server and analyzed it:

  • 1st 9 octets from server contained Frame Header and successfully decoded as HeadersFrame without priority (it should have either priority or exclusive flag).

  • after that it received payload as: HeadersFrame Nothing " H\ETX403v\137\170cU\229\128\174\SYN\151\aa\150\228Y>\148\v*a,j\b\SOH}@\181q\183n\EOT*b\209\191_\135I|\165\137\211M\US\\\ETX169"

  • Corresponding [Word8] is: [32,72,3,52,48,51,118,137,170,99,85,229,128,174,22,151,7,97,150,228,89,62,148,11,42,97,44,106,8,1,125,65,10,227,45,220,19,202,98,209,191,95,135,73,124,165,137,211,77,31,92,3,49,54,57] :: [Word8].

  • As you may notice, 1st byte of payload is 32, i.e. 0x20 (priority flag or exclusive flag) and it was not decoded during decodeHeader according to http2 logic.

Actually here I am a bit stucked.

  1. I will try again to reproduce expected behaviour of Frame Header decoding.
  2. And after that try to understand how Frame Payload should be decoded.

Hope, it might help.

Thanks,
Andrey

@swamp-agr
Copy link
Author

Here is the same test for nghttp (i.e. with status = 403):

[  0.062] Connected
The negotiated protocol: h2
[  0.105] recv SETTINGS frame <length=18, flags=0x00, stream_id=0>
          (niv=3)
          [SETTINGS_MAX_CONCURRENT_STREAMS(0x03):128]
          [SETTINGS_INITIAL_WINDOW_SIZE(0x04):65536]
          [SETTINGS_MAX_FRAME_SIZE(0x05):16777215]
[  0.105] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=0>
          (window_size_increment=2147418112)
[  0.105] send SETTINGS frame <length=12, flags=0x00, stream_id=0>
          (niv=2)
          [SETTINGS_MAX_CONCURRENT_STREAMS(0x03):100]
          [SETTINGS_INITIAL_WINDOW_SIZE(0x04):65535]
[  0.105] send SETTINGS frame <length=0, flags=0x01, stream_id=0>
          ; ACK
          (niv=0)
[  0.105] send PRIORITY frame <length=5, flags=0x00, stream_id=3>
          (dep_stream_id=0, weight=201, exclusive=0)
[  0.105] send PRIORITY frame <length=5, flags=0x00, stream_id=5>
          (dep_stream_id=0, weight=101, exclusive=0)
[  0.105] send PRIORITY frame <length=5, flags=0x00, stream_id=7>
          (dep_stream_id=0, weight=1, exclusive=0)
[  0.105] send PRIORITY frame <length=5, flags=0x00, stream_id=9>
          (dep_stream_id=7, weight=1, exclusive=0)
[  0.105] send PRIORITY frame <length=5, flags=0x00, stream_id=11>
          (dep_stream_id=3, weight=1, exclusive=0)
[  0.105] send HEADERS frame <length=180, flags=0x25, stream_id=13>
          ; END_STREAM | END_HEADERS | PRIORITY
          (padlen=0, dep_stream_id=11, weight=16, exclusive=0)
          ; Open new stream
          :method: GET
          :path: ...
          :scheme: https
          :authority: ...
          accept: */*
          accept-encoding: gzip, deflate
          user-agent: nghttp2/1.36.0
[  0.121] recv SETTINGS frame <length=0, flags=0x01, stream_id=0>
          ; ACK
          (niv=0)
[  0.121] recv (stream_id=13) :status: 403
[  0.121] recv (stream_id=13) server: nginx/1.14.0
[  0.121] recv (stream_id=13) date: Sat, 16 Feb 2019 19:32:48 GMT
[  0.121] recv (stream_id=13) content-type: text/html
[  0.121] recv (stream_id=13) content-length: 169
[  0.121] recv HEADERS frame <length=55, flags=0x04, stream_id=13>
          ; END_HEADERS
          (padlen=0)
          ; First response header
<html>
<head><title>403 Forbidden</title></head>
<body bgcolor="white">
<center><h1>403 Forbidden</h1></center>
<hr><center>nginx/1.14.0</center>
</body>
</html>
[  0.121] recv DATA frame <length=169, flags=0x01, stream_id=13>
          ; END_STREAM
[  0.122] send GOAWAY frame <length=8, flags=0x00, stream_id=0>
          (last_stream_id=0, error_code=NO_ERROR(0x00), opaque_data(0)=[])

Here are also length=55, flags=0x04.

@swamp-agr
Copy link
Author

For test of Frame Header decoding let me prepare you proper test case!

@swamp-agr
Copy link
Author

swamp-agr commented Feb 16, 2019

Frame Payload:

decodeHeader :: DynamicTable
             -> ByteString -- ^ An HPACK format
             -> IO HeaderList
decodeHeader dyntbl inp = decodeHPACK dyntbl inp decodeSimple

decodeHPACK :: DynamicTable
            -> ByteString
            -> (DynamicTable -> ReadBuffer -> IO a)
            -> IO a
decodeHPACK dyntbl inp dec = withReadBuffer inp chkChange
  where
    chkChange rbuf = do
        more <- hasOneByte rbuf
        if more then do
            w <- getByte rbuf
            if isTableSizeUpdate w then do
                tableSizeUpdate dyntbl w rbuf
                chkChange rbuf
              else do
                rewindOneByte rbuf
                dec dyntbl rbuf
          else
            throwIO HeaderBlockTruncated
  • decodeSimple might return correct header, i.e. :status: 403.
  • decodeHPACK has recursion inside.
  • dynamic table created with default parameters:
numOfEntries: 0
maxNumOfEntries: 128
size: 0
maxSize: 4096
  • Since 1st byte is 32, isTableSizeUpdate is equal to True and maxNumOfEntries of empty dynamic table reduced from 128 to 0:
numOfEntries: 0
maxNumOfEntries: 0
size: 0
maxSize: 0
  • After that next iteration of decodeHPACK entered.
  • Since 2nd byte is 72, isTableSizeUpdate is equal to False and decodeHeader started.
  • 1st Entry decoded to Entry 42 (Token {ix = 4, shouldBeIndexed = True, isPseudo = True, tokenKey = ":status"}) "403")`.
  • Decoded entry tried to insert into dynamic table with maxNumOfEntries == 0, TooSmallTableSize exception thrown.

Let me analyze HPACK RFC to try to determine what is the correct approach for HPACK decoding.

@swamp-agr
Copy link
Author

swamp-agr commented Feb 16, 2019

6.3.  Dynamic Table Size Update

     0   1   2   3   4   5   6   7
   +---+---+---+---+---+---+---+---+
   | 0 | 0 | 1 |   Max size (5+)   |
   +---+---------------------------+

               Figure 12: Maximum Dynamic Table Size Change

   A dynamic table size update starts with the '001' 3-bit pattern,
   followed by the new maximum size, represented as an integer with a
   5-bit prefix (see Section 5.1).

I am wondering, how does it relate to

isTableSizeUpdate :: Word8 -> Bool
isTableSizeUpdate w = w .&. 0xe0 == 0x20

where 0xe0 == 224 and 0x20 == 32?

 +---+---+---+---+---+---+---+---+
 | 0 | 0 | 0 | 0 | 1 | 1 | 1 | 1 | -- 224
 +---+---+---+---+---+---+---+---+
 | 0 | 0 | 0 | 0 | 1 | 0 | 0 | 0 | -- 32
 +---+---+---+---+---+---+---+---+
 and the result of "bitwise AND" would be 32:
 +---+---+---+---+---+---+---+---+
 | 0 | 0 | 0 | 0 | 1 | 0 | 0 | 0 | -- 32
 +---+---+---+---+---+---+---+---+
 001 - pattern:
 +---+---+---+---+---+---+---+---+
 | 0 | 0 | 1 | 0 | 0 | 0 | 0 | 0 | -- 4
 +---+---+---+---+---+---+---+---+

@lucasdicioccio
Copy link
Member

That's a lot of information. I think you're doing great progress and you're definitely ahead of me in this debug session

If I understand well, the problem is indeed inside http2. The server sets no HTTP2HeadersFlags 0x20 for the HEADERS frame. Thus, we we expect to decode the whole ByteString " H\ETX403v\137\170cU\229\128\174\SYN\151\aa\150\228Y>\148\v*a,j\b\SOH}@\181q\183n\EOT*b\209\191_\135I|\165\137\211M\US\\\ETX169" as a valid headers-block-fragment.

I'll try to debug that on my own as well but please keep scratching because you probably already know more about HPACK than myself :-). I barely know that there's an hpack tests suite at https://github.com/http2jp/hpack-test-case but I've not been using it.

@swamp-agr
Copy link
Author

swamp-agr commented Feb 17, 2019

Hi Lucas,

I don't know yet what is causing the issue, so I will step back and try to decode Frame Header (9 bytes) and compare with result of http2-client by going step-by-step with http2 decoder.

According to RFC 7540,

    +-----------------------------------------------+
    |                 Length (24)                   |
    +---------------+---------------+---------------+
    |   Type (8)    |   Flags (8)   |
    +-+-------------+---------------+-------------------------------+
    |R|                 Stream Identifier (31)                      |
    +=+=============================================================+
    |                   Frame Payload (0...)                      ...
    +---------------------------------------------------------------+

                          Figure 1: Frame Layout

and its Paylaod:

    +---------------+
    |Pad Length? (8)|
    +-+-------------+-----------------------------------------------+
    |E|                 Stream Dependency? (31)                     |
    +-+-------------+-----------------------------------------------+
    |  Weight? (8)  |
    +-+-------------+-----------------------------------------------+
    |                   Header Block Fragment (*)                 ...
    +---------------------------------------------------------------+
    |                           Padding (*)                       ...
    +---------------------------------------------------------------+

                      Figure 7: HEADERS Frame Payload

Only Header Block Fragment (*) part should be decoded with HPACK decoder. I will check if frame decoded correctly.

@lucasdicioccio
Copy link
Member

lucasdicioccio commented Feb 17, 2019

At the moment, my suspicions are on the http2 decodeHeader function: the HTTP frame decoding code path is shared with the DATA,PUSH_PROMISE,PING, etc. and all other frames. Hence my assumption is that the actual HPACK binary to decode as an HeaderBlockFragment is the one you gave.

I'm debugging with

dtbl <- newDynamicTableForDecoding 4096 4096
bstr = " H\ETX403v\137\170cU\229\128\174\SYN\151\aa\150\228Y>\148\v*a,j\b\SOH}@\181q\183n\EOT*b\209\191_\135I|\165\137\211M\US\\\ETX169"

In a binary run with +RTS -xc the stack trace when crash occurs is in:

*** Exception (reporting due to +RTS -xc): (THUNK_STATIC), stack trace:
  Network.HPACK.Table.Dynamic.insertFront,
  called from Network.HPACK.Table.Dynamic.insertEntry,
  called from Network.HPACK.HeaderBlock.Decode.incrementalIndexing,
  called from Network.HPACK.HeaderBlock.Decode.toTokenHeader,
  called from Network.HPACK.HeaderBlock.Decode.decodeSimple.go,
  called from Network.HPACK.HeaderBlock.Decode.decodeSimple,
  called from Network.HPACK.HeaderBlock.Decode.decodeHPACK.chkChange,
  called from Network.HPACK.Buffer.withReadBuffer.\,
  called from Network.HPACK.Buffer.withReadBuffer,
  called from Network.HPACK.HeaderBlock.Decode.decodeHPACK,
  called from Network.HPACK.HeaderBlock.Decode.decodeHeader,
  called from HPACK.DecodeSpec.spec.\,
  called from Network.HPACK.Table.Dynamic.withDynamicTableForDecoding,

In GHCi, when stepping through the debugger and adding a few traceShow calls, it looks like the problem surfaces when the DynamicTable 's maxNumOfEntries is 0 in insertFront.
This value is set in renewDynamicTable upon tableSizeUpdate in decodeHPACK.

That's about where I am at the moment.

@lucasdicioccio
Copy link
Member

OK, I got it and it's related to your comment about dynamic table update at
#65 (comment) .

By adding a special case

renewDynamicTable 0  _ = return ()

I then properly decode the bytestring as

[(":status","403"),("server","nginx/1.14.0"),("date","Wed, 13 Feb 2019 14:57:11 GMT"),("content-type","text/html"),("content-length","169")]

@lucasdicioccio
Copy link
Member

So now we need Kazu's lights to help us understand whether this is something unclear in RFC 7541, in nginx's implementation, or in http2 implementation :-)

That was an epic bug-chase.

@lucasdicioccio
Copy link
Member

@swamp-agr , for now you can try this patch:

 -- | Renewing 'DynamicTable' with necessary entries copied.
 renewDynamicTable :: Size -> DynamicTable -> IO ()
+renewDynamicTable 0  _ = return ()
 renewDynamicTable maxsiz dyntbl@DynamicTable{..} = do

in Network/HPACK/Table/Dynamic.hs and see if there are more troubles down the road (because HPACK is inherently stateful, we cannot conclude anything from a simple workaround).

We can have a quick chat if you want to help continuing debugging this issue on the http2 side. I would love some summary and would like to spend some time reading HPACK spec and Nginx/nghttp2 implementations for how they handle this. Given that I lack time these weeks we can synchronize to see how to follow up, write a nice http2 bug report and repro case etc.

@lucasdicioccio
Copy link
Member

lucasdicioccio commented Feb 17, 2019

Lets use this comment as a summary.

problem

http2-client is thrown an exception when receiving an HEADERS frame with HeadersBlockFragement binary data " H\ETX403v\137\170cU\229\128\174\SYN\151\aa\150\228Y>\148\va,j\b\SOH}@\181q\183n\EOTb\209\191_\135I|\165\137\211M\US\\ETX169"

This binary header-block-fragment seems correct because nginx emits it and nghttp2 handle it and can decode headers.

The http2-client parsing of the outtermost HTTP2 framing decodes flags=0x04 like nghttp does. Which means the binary data does not contain a 5bytes optional info for streams priority,exclusive,and weight info.

analysis

The error seems to occur in http2 within the decoding functions.

In decodeHPACK the code attemps to tableSizeUpdate with Word w = 0x20, as shown in the debugging snippet below:

ghci> :break Network.HPACK.HeaderBlock.Decode 176
Breakpoint 2 activated at /Users/lucasdicioccio/code/open-source/http2/Network/HPACK/HeaderBlock/Decode.hs:176:15-21
ghci> :trace withDynamicTableForDecoding 4096 4096 (\dtbl1 -> printDynamicTable dtbl1 >> decodeHeader dtbl1 bstr)
      Table size: 0/4096
Stopped in Network.HPACK.HeaderBlock.Decode.tableSizeUpdate.w', /Users/lucasdicioccio/code/open-source/http2/Network/HPACK/HeaderBlock/Decode.hs:176:15-21
_result :: Word8 = _
w :: Word8 = GHC.Word.W8# 32
[/Users/lucasdicioccio/code/open-source/http2/Network/HPACK/HeaderBlock/Decode.hs:176:15-21] ghci> :list
175  tableSizeUpdate dyntbl w rbuf = do
176      let !w' = mask5 w --here w = 32 (0x20)
                   ^^^^^^^

Then, the following happens:

In renewDynamicTable we get to update using maxsiz=0

writeIORef maxDynamicTableSize maxsiz

At tha point maxNumOfEntries is 0 and was 128 before.

The rest of the bytestring gets consumed, which leads to decoding with toTokenHeader and incrementalIndexing for entry e :: Entry = Entry 42 (Token 4 True ....). The code attemps to insertEntry (which calls insertFront). In insertFront, maxNumOfEntries is read to value 0, which means the adj call enters the pattern | maxN == 0 = throwIO TooSmallTableSize.

@swamp-agr
Copy link
Author

Cool, I think it's better to reopen issue I previously created. I will rename it to address it to http2 package.

@swamp-agr
Copy link
Author

I tested patch and it works fine for all cases.

@swamp-agr
Copy link
Author

Lucas, many thanks for your suggestion! 🥇

Right now I am unblocked with further tests.

I think this issue might be closed. We will move on http2 to understand what is the best way to handle dynamic table.

Thank you,
Andrey

@lucasdicioccio
Copy link
Member

Thanks for reporting the issue and the willingness to get to the bottom of it. You rock! :-)
The current workardound seems pretty aweful and may lead to unwanted effects if a server implementation (I'm not sure any does that) actually often resets the dynamic-token headers table, but at least it unblocks you. Hence, thanks again and we should carry on with Kazu to help fixing http2 properly. On my end I won't have much more time on this issue before next week-end, but I'll surely read a bit the RFC and nghttp's implementation during commute time this week. Best!

@swamp-agr
Copy link
Author

Yeah, sure, I will follow http2 issue and support Kazu with more details.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants