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

Thu Jul 20 06:49:18 UTC 2023

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?

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/b58e6d4f/attachment-0001.htm>