Hello Nicolas,
It's good to hear that the workaround is functional. I expect this to be
fixed in JDK 22 and likely be backported in one of the 21 update releases.
-Jaikiran
On 22/07/23 5:35 pm, Nicolas Henneaux wrote:
Hi Jaikiran,
Great news you nailed down the issue and already working on a fix!
I have set the idle timeout to 60s and there was not a single
occurrence of those errors for 2 days. This is effectively the trigger
of those errors. I would prefer to avoid using a non-default idle
timeout but I can live with it for some time. Once you'll manage to
get a fix on that, could you indicate the schedule delivery for it?
Thanks a lot for the help,
Best regards,
Nicolas
On Fri, 21 Jul 2023 at 12:35, Jaikiran Pai <[email protected]>
wrote:
Hello Nicolas,
I have been able to reproduce this issue in a test case and I
realize what's going on. I'll be working on a fix.
I'm just curious if you were able to workaround this issue with
the use of a non-default idle timeout using the system properties
I noted.
-Jaikiran
On 20/07/23 1:01 pm, Jaikiran Pai wrote:
On 20/07/23 12:19 pm, Nicolas Henneaux wrote:
Hi Jaikiran!
Thanks for your quick feedback!
It happens on a regular and consistent basis mostly when
execution health checks between microservices. On about 100
microservices deployed on 100 VM, it happens ~400 times every hours.
I haven't find a consistent pattern for now. I cannot attachÂ
the whole stacktrace as it is a closed source code. I can
provide some details. A ScheduleExecutor is launching a check on
healthiness HTTP call every 29s (was 30s but I desync it to
avoid idle timeout of 30s alignment with HttpClient). This is
the biggest source of those errors but not the only one, there
are regular HTTP calls received on a Jetty server and calling
another service that are failing.
I have already tried to enable full debug without much help for
now. Is there something in particular you are willing to check?
Thank you for these additional details. I don't have any specific
log message in mind for now. I'll look into the code and try to
reproduce this in a test case.
From the stacktrace it appears that this affects HTTP2 connection
in your application. One workaround would be to increase the idle
connection timeout for these connections, to reduce the chances
of this issue. There are system properties that control this
value. If you want to configure this only for HTTP2 connections,
then jdk.httpclient.keepalive.timeout.h2 is the system property
to set, the value represents number of seconds (and defaults to
30). More details about this and other system properties
applicable for HttpClient are available here
https://docs.oracle.com/en/java/javase/20/docs/api/java.net.http/module-summary.html
-Jaikiran
Best regards,
Nicolas
On Thu, 20 Jul 2023 at 08:11, Jaikiran Pai
<[email protected]> wrote:
Hello Nicolas,
This looks like it will need to be investigated. I've opened
https://bugs.openjdk.org/browse/JDK-8312433 to tracking
this. It would help further if you could attach the complete
exception logs along with timestamps, if any.
Is this consistently reproducible? Perhaps you could launch
your application passing it the
-Djdk.internal.httpclient.debug=true system property? That
will generate very verbose logs, so you might want to use
that sparingly and remove that system property when you have
collected the logs for this issue.
-Jaikiran
On 20/07/23 11:00 am, Nicolas Henneaux wrote:
Hi all,
Since I updated Java from 19.0.2 to 20.0.1, I got some
errors with connection idle shutdown or closed stream usage
when trying to send HTTP requests with
java.net.http.HttpClient.
The two following errors are happening. I suspect those are
linked even if they don't trigger together.
1. java.net.http.HttpConnectTimeoutException: HTTP
connection idle, no active streams. Shutting down.
at
jdk.internal.net.http.HttpClientImpl.send(HttpClientImpl.java:890)
~[java.net.http:?]
2. java.io.IOException: Stream 9 cancelled
at jdk.internal.net.http.Stream.cancel(Stream.java:1229)
~[java.net.http:?]
The detailed stacks are copied below.
Error 1. is caused by an idle connection trying to be used
to send the request from what I understood from the code.
Error 2. despite saying it is a cancelled streamed is
actually happening when the stream is closed if I haven't
missed something in the code.
I suspect either the idle connections are not always
properly discarded to create a new one or there is a race
condition when discarding the idle connections.
I was not able so far to find where this could happen and I
hope you could help me to find where the problem lies.
Thank you in advance for your help,
Best regards,
Nicolas Henneaux
Detailed stacks
1. Caused by: java.net.http.HttpConnectTimeoutException:
HTTP connection idle, no active streams. Shutting down.
at
jdk.internal.net.http.HttpClientImpl.send(HttpClientImpl.java:890)
~[java.net.http:?]
at
jdk.internal.net.http.HttpClientFacade.send(HttpClientFacade.java:133)
~[java.net.http:?]
(...)
Caused by: java.net.http.HttpConnectTimeoutException: HTTP
connection idle, no active streams. Shutting down.
at
jdk.internal.net.http.Http2Connection$IdleConnectionTimeoutEvent.handle(Http2Connection.java:204)
~[java.net.http:?]
at
jdk.internal.net.http.HttpClientImpl.purgeTimeoutsAndReturnNextDeadline(HttpClientImpl.java:1689)
~[java.net.http:?]
at
jdk.internal.net.http.HttpClientImpl$SelectorManager.run(HttpClientImpl.java:1299)
~[java.net.http:?]
2. Caused by: java.io.IOException: Stream 9 cancelled
at jdk.internal.net.http.Stream.cancel(Stream.java:1229)
~[java.net.http:?]
at
jdk.internal.net.http.Http2Connection.putStream(Http2Connection.java:1237)
~[java.net.http:?]
at
jdk.internal.net.http.Stream.registerStream(Stream.java:851)
~[java.net.http:?]
at
jdk.internal.net.http.Http2Connection.registerNewStream(Http2Connection.java:1337)
~[java.net.http:?]
at
jdk.internal.net.http.Http2Connection.sendFrame(Http2Connection.java:1361)
~[java.net.http:?]
at
jdk.internal.net.http.Stream.sendHeadersAsync(Stream.java:823)
~[java.net.http:?]
at
jdk.internal.net.http.Exchange.lambda$responseAsyncImpl0$8(Exchange.java:550)
~[java.net.http:?]
at
jdk.internal.net.http.Exchange.checkFor407(Exchange.java:430)
~[java.net.http:?]
at
jdk.internal.net.http.Exchange.lambda$responseAsyncImpl0$9(Exchange.java:554)
~[java.net.http:?]
at
java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934)
~[?:?]
at
java.util.concurrent.CompletableFuture.uniHandleStage(CompletableFuture.java:950)
~[?:?]
at
java.util.concurrent.CompletableFuture.handle(CompletableFuture.java:2372)
~[?:?]
at
jdk.internal.net.http.Exchange.responseAsyncImpl0(Exchange.java:554)
~[java.net.http:?]
at
jdk.internal.net.http.Exchange.responseAsyncImpl(Exchange.java:406)
~[java.net.http:?]
at
jdk.internal.net.http.Exchange.responseAsync(Exchange.java:398)
~[java.net.http:?]
at
jdk.internal.net.http.MultiExchange.responseAsyncImpl(MultiExchange.java:409)
~[java.net.http:?]
at
jdk.internal.net.http.MultiExchange.lambda$responseAsync0$2(MultiExchange.java:342)
~[java.net.http:?]
at
java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1150)
~[?:?]
at
java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)
~[?:?]
at
java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1773)
~[?:?]
at
jdk.internal.net.http.HttpClientImpl$DelegatingExecutor.execute(HttpClientImpl.java:177)
~[java.net.http:?]
at
java.util.concurrent.CompletableFuture.completeAsync(CompletableFuture.java:2719)
~[?:?]
at
jdk.internal.net.http.MultiExchange.responseAsync(MultiExchange.java:295)
~[java.net.http:?]
at
jdk.internal.net.http.HttpClientImpl.sendAsync(HttpClientImpl.java:983)
~[java.net.http:?]
at
jdk.internal.net.http.HttpClientImpl.send(HttpClientImpl.java:875)
~[java.net.http:?]
at
jdk.internal.net.http.HttpClientFacade.send(HttpClientFacade.java:133)
~[java.net.http:?]
