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

Thu Jul 20 07:31:59 UTC 2023

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/20230720/c7470292/attachment.htm>