Repository navigation
HTTP/2 max local stream count exceeded #6208
Description
Jetty version
9.4.39.v20210325
Java version
1.8
OS type/version
MAC and linux
Description
When the header size reaches some value (In my demo, it's 2237B) and multiple requests send concurrently, some requests will not be sent to remote server and cause an TimeoutException and then an "java.lang.IllegalStateException: Max local stream count 100 exceeded". When the header size is smaller, it's ok. Please refer to this demo project to reproduce it.
https://github.com/qingdaoheze/jetty-gzip-decode
Activity
sbordet commentedon Apr 24, 2021
Cannot reproduce.
I see Jetty's client sending requests, and Tomcat server replying to some but then stopping to reply, so the client times out.
I suggest you change the server to Jetty (SpringBoot supports Jetty too) and see if you still have problems.
qingdaoheze commentedon Apr 24, 2021
Maybe your computer is stronger than mine, I increase the thread size, please try it again and please use the client code provided in the repo directly. Its path is "jetty9-client-sample/src/main/java/org/sample/jetty/client/http2/HttpClientWithHttp2Transport.java". The problem must be reproduced.
And please refer to the log on my side. https://github.com/qingdaoheze/jetty-gzip-decode/blob/master/detail.log.tar.gz
@sbordet
sbordet commentedon Apr 24, 2021
As I said, I cannot reproduce.
Your logs show nothing wrong in Jetty.
The
IllegalStateExceptionyou mention in your first comment is not present in your logs, and I was not able to reproduce it with your code.The timeouts you see are only due to the (bad) load test that overwhelms the client and the server and eventually the client times out.
qingdaoheze commentedon Apr 25, 2021
I only uploaded the first part of the log because the whole log is too big. I have re-run and uploaded more logs, please check again. In my case, this question certainly comes up.
https://github.com/qingdaoheze/jetty-gzip-decode/blob/master/detail.log.tar.gz
The first timeout is between 09:05:45.244 and 09:05:50.220. At 09:06:26.269, the first java.lang.IllegalStateException: Max local stream count 100 exceeded.
@sbordet
RoySunnySean007 commentedon Apr 25, 2021
Dear @sbordet,
We also encountered similar issues. Is there any difference between Jetty server and tomcat server regarding HTTP2.0 implementation?
Really appreciate ur great help in advance~
Thanks,
Roy
lsc1943 commentedon Apr 25, 2021
@sbordet
We also met similar issues, we ran some load tests using Jetty HTTP2 client as a middleware and send requests to Tomcat 9 server. We observed some abnormal timeout errors, and we have checked that the timeout was not happened at server side, it seems the Jetty client tried to send request but not succeed, the http exchange got snd = "IDLE" like below:
HttpExchange@625d06a5{req=HttpRequest[POST /xx HTTP/2.0]@871420d[PENDING/null] res=HttpResponse[null 0 null]@48ced718[PENDING/null]} associated true to HttpChannelOverHTTP2@1384fef4(exchange=HttpExchange@625d06a5{req=HttpRequest[POST /xx HTTP/2.0]@871420d[PENDING/null] res=HttpResponse[null 0 null]@48ced718[PENDING/null]})[send=HttpSenderOverHTTP2@11e7b7a3(req=QUEUED,snd=IDLE,failure=null),recv=HttpReceiverOverHTTP2@1b05f314(rsp=IDLE,failure=null)]
And another issue is that if many timeout happened, we encountered another kind of exception like "jetty http2 request failed(java.lang.IllegalStateException: Max local stream count 100 exceeded)", I doubt that if any miscount of the local stream count once the timeout occurred.
Thank you!
sbordet commentedon Apr 25, 2021
@RoySunnySean007
Yes the implementations are completely different.
They should be interoperable, because they both implement the same specification, but there could be gray areas that make them differ in behavior.
sbordet commentedon Apr 25, 2021
@lsc1943 if you use Jetty's low-level
HTTP2Client, it is the application responsibility to control that the maximum number of streams is not exceeded.If you use Jetty's high-level
HttpClient, then it controls that the maximum number of streams is not exceeded.The line of logging that you chose is perfectly normal, and the states that you see are correct.
You should not look at just one log line, but rather report all the DEBUG logs in their entirety and attach them to this issue for analysis.
I need evidence that there is a Jetty issue.
So far, either I cannot reproduce, or it's a bad assumption, or it's a badly written load test.
Take into account that Jetty's HTTP/2 implementation has been quite battle tested; you may have found an issue, but chances are that either it's a bug in your code, or in the server's code.
To be able to tell, I need hard evidence -- saying it or just picking one log line is not enough to help you.
lsc1943 commentedon Apr 26, 2021
@sbordet, thank you for your help. We are using the high-level HttpClient and we checked the debug log but didn't observe any abnormals, it seems the HEADER frames were sent to server but got no response util timeout.
But we do noticed that a lot of evict actions for the hpack like below, and it seems the size reached the limit, anyway we could configure this size to a larger value?
HdrTbl[1f2a7b19] evict {D,17,x-user-id: 36329177,445117b}
HdrTbl[1f2a7b19] entries=36, size=4096, max=4096
sbordet commentedon Apr 26, 2021
They are not relevant.
There is some evidence that I am investigating in @qingdaoheze logs.
@qingdaoheze would be great if you can turn on full DEBUG logging (not only
org.eclipse.jetty.client).Stay tuned for updates.
qingdaoheze commentedon Apr 26, 2021
@sbordet I have rerun the demo with full DEBUG logging in (org.eclipse.jetty). Please refer to it:
https://github.com/qingdaoheze/jetty-gzip-decode/blob/master/detail.log.tar.gz
sbordet commentedon Apr 26, 2021
@qingdaoheze we have reproduced the issue and found the bug, it's a quite particular combination of many things that must go wrong. I'll write a report when we have a test case and the fix.
Thanks for the reproducer!
qingdaoheze commentedon Apr 26, 2021
Do you know what workaround can I use before you fix it? @sbordet BTW, when will you fix it?
sbordet commentedon Apr 27, 2021
@qingdaoheze
There is no workaround.
The fix is underway.
[-]Header size is bigger will cause TimeoutException[/-][+]HTTP/2 max local stream count exceeded[/+]Fixes #6208 - HTTP/2 max local stream count exceeded
sbordet commentedon Apr 28, 2021
FTR, here is what is happening.
The big HEADERS frames, load test being written as it is and the server being overwhelmed caused a connection to TCP congest.
At that point, a HEADERS frame is sent by the client, queued into the
HTTP2Flusher, but not sent over the wire because of TCP congestion.The corresponding request times out and the failure arrives at
HttpChannelOverHTTP2.exchangeTerminated(), where it finds thatstream=nullbecause the HEADERS frame has not been written yet (thestreamfield is assigned by the HEADERS write callback, which is not completed yet because the frame has not been written yet).This causes a
release()at the connection pool level, which decrements the pool counter, without the corresponding decrement of the stream counter. From this point the 2 counters are out of sync and later, for an unrelated request, may cause theIllegalStateException: max local stream count exceeded.@qingdaoheze can you build Jetty from branch
jetty-9.4.x-6208-max_streams_exceeded_tcp_congestedand verify if it fixes the problem for you?Issue #6208 - HTTP/2 max local stream count exceeded
qingdaoheze commentedon Apr 29, 2021
@sbordet I have verified it, it worked fine. Thank you! I will do more verification, if I have any other found, I will tell you.
Fixes #6208 - HTTP/2 max local stream count exceeded (#6220)
Fixes #6208 - HTTP/2 max local stream count exceeded (#6220)
Fixes #6208 - HTTP/2 max local stream count exceeded (#6220)