[java.net.http.HttpClient] Error on idle/closed stream when sending requests

Jaikiran Pai jai.forums2013 at gmail.com
Mon Jul 24 05:18:56 UTC 2023


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 <jai.forums2013 at gmail.com> 
> 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
>>>     <jai.forums2013 at gmail.com> 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:?]
>>>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.openjdk.org/pipermail/net-dev/attachments/20230724/51c3f49c/attachment-0001.htm>


More information about the net-dev mailing list