HTTP/3 Race with Dynamic Table referencing in QPackDecoder

[cowwoc]

Jetty version(s)
12.0.7

Jetty Environment
core

Java version/vendor (use: java -version)
openjdk version "21.0.1" 2023-10-17 LTS
OpenJDK Runtime Environment Zulu21.30+15-CA (build 21.0.1+12-LTS)
OpenJDK 64-Bit Server VM Zulu21.30+15-CA (build 21.0.1+12-LTS, mixed mode, sharing)

OS type/version
Microsoft Windows [Version 10.0.19045.4046]

Description
I have an index.html file that references login/login.js.

If I open a new Incognito tab and hit index.html I sometimes (randomly) get the wrong headers.

Here is what a good request looks like:

14:37:32.330 [main-21] DEBUG o.e.j.h.s.i.HttpStreamOverHTTP3.onRequest() - HTTP3 request #4/2327826b, GET https://licensed.app/login/login.js HTTP/3.0
sec-ch-ua: "Not A(Brand";v="99", "Brave";v="121", "Chromium";v="121"
origin: https://licensed.app
dnt: 1
sec-ch-ua-mobile: ?0
user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/121.0.0.0 Safari/537.36
sec-ch-ua-platform: "Windows"
accept: */*
sec-gpc: 1
sec-fetch-site: same-origin
sec-fetch-mode: cors
sec-fetch-dest: script
referer: https://licensed.app/
accept-encoding: gzip, deflate, br
accept-language: en-US,en;q=0.9

And here is what a bad request looks like:

14:37:47.395 [main-21] DEBUG o.e.j.h.s.i.HttpStreamOverHTTP3.onRequest() - HTTP3 request #56/2f56978, GET https://licensed.app/login/login.js HTTP/3.0
pragma: no-cache
cache-control: no-cache
sec-ch-ua: "Not A(Brand";v="99", "Brave";v="121", "Chromium";v="121"
origin: https://licensed.app
dnt: 1
sec-ch-ua-mobile: ?0
user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/121.0.0.0 Safari/537.36
sec-ch-ua-platform: "Windows"
accept: */*
sec-gpc: 1
sec-gpc: same-origin
sec-gpc: cors
accept: script
referer: https://licensed.app/
accept-encoding: gzip, deflate, br
accept-language: en-US,en;q=0.9

If you diff these two, you will notice that:

sec-fetch-site: same-origin
sec-fetch-mode: cors
sec-fetch-dest: script

is replaced by:

sec-gpc: same-origin
sec-gpc: cors
accept: script

The bad request also contains:

pragma: no-cache
cache-control: no-cache

which the good request does not. The only reason I caught this is that accept: script is invalid.

It's not clear to me whether this is caused by a race condition in Jetty (possibly only in HTTP/3 mode) or it's caused by a race race condition on Chrome.

I know that the initial (non-cached) page load is always okay. If I get the bad headers, it is typically on the second (and subsequent) requests when I hit F5 to reload the page.

Because this is a race condition, the more logs I add the less likely I am to run into this problem. I cannot enable all the DEBUG logs.

How do you suggest figuring out which side is at fault?

[cowwoc]

I got lucky. I managed to reproduce this bug with full DEBUG logs enabled:

debug.log

The text java.lang.IllegalArgumentException: mediaType.value must contain 2 elements indicates the bug occurred.

Do you see any potential problems?

Next, I'm going to try reproducing the problem with the gzip handler disabled.

[cowwoc]

Here is a log of the problem with the gzip handler disabled:

debug.log

I still don't see any obvious problems.

[cowwoc]

It looks increasingly likely this is a Chrome bug. I can't reproduce the problem with Firefox, but both Chrome and Brave do trigger it.

Check out this interesting log:

accept-no-cors.log

15:14:24.490 [main-21] DEBUG o.e.j.h.q.QpackDecoder$InstructionHandler.onInsertNameWithReference() - InsertNameReference: nameIndex=1, dynamic=false, value=/styles.css
15:14:24.490 [main-21] DEBUG o.e.j.h.q.QpackDecoder$InstructionHandler.onInsertNameWithReference() - InsertNameReference: nameIndex=29, dynamic=false, value=text/css,*/*;q=0.1
15:14:24.490 [main-21] DEBUG o.e.j.h.q.QpackDecoder$InstructionHandler.onInsertNameWithReference() - InsertNameReference: nameIndex=6, dynamic=true, value=no-cors
15:14:24.490 [main-21] DEBUG o.e.j.h.q.QpackDecoder$InstructionHandler.onInsertNameWithReference() - InsertNameReference: nameIndex=6, dynamic=true, value=style
[...]
15:14:24.505 [main-21] DEBUG o.e.j.h.s.i.HttpStreamOverHTTP3.onRequest() - HTTP3 request #16/5ccb2c81, GET https://licensed.app/styles.css HTTP/3.0
pragma: no-cache
cache-control: no-cache
sec-ch-ua: "Not A(Brand";v="99", "Brave";v="121", "Chromium";v="121"
dnt: 1
sec-ch-ua-mobile: ?0
user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/121.0.0.0 Safari/537.36
sec-ch-ua-platform: "Windows"
accept: text/css,*/*;q=0.1
sec-gpc: 1
sec-gpc: same-origin
accept: no-cors
accept: style
referer: https://licensed.app/
accept-encoding: gzip, deflate, br
accept-language: en-US,en;q=0.9

Clearly accept: no-cors and style is incorrect.

I'll wait for you guys to confirm whether it's possible Jetty is responsible for this bug. Hopefully it is, because I have no clue how to report this to the Chromium team :)

[sbordet]

These headers are not generated by Jetty. They are sent by the client, so I agree that it seems a Chrome bug.

[cowwoc]

@sbordet Is it possible that the client sends them correctly but Jetty parses them incorrectly? Is it possible for multiple threads to handle the same stream, or is there a dedicated thread per stream?

[sbordet]

There is only 1 reader thread per connection, so I doubt it's a Jetty issue.

[cowwoc]

Thank you for the clarification. I filed a bug report against Chrome: https://issues.chromium.org/issues/325821306

[sbordet]

@lachlan-roberts would it be possible that there is a bug in the qpack decoding, and we emit headers that don't exist, or emit headers with different values?

In the first log file we decode sec-fetch-dest: script; later, the value "script" is associated with the header accept.
I don't think that is possible, because we do not store separately header names from values, right?
Is there any possibility that an index or an instruction comes with the wrong index, so we assign a wrong value to a header?

[cowwoc]

@lachlan-roberts any chance you could reply to the previous question?

[lachlan-roberts]

Sorry for the delay. I have had time to look into this and I do think it is a bug in the Jetty QpackDecoder.

The instruction to insert into the table is supposed to be a relative index to the last entry inserted into the dynamic table but the QpackDecoder is treating it as an absolute index. This was causing the wrong headers to be added to the table.

I am working on a PR with a fix now.

[lachlan-roberts]

@cowwoc I have merged PR #11645 which should fix this issue.

[cowwoc]

Thanks @lachlan-roberts. I'll give it a try in the next official release.