HttpClient Send Method Guaranteed Completion

[Elliot Barlas]

Hello net-dev!

I'm emailing about a surprising observation in the HttpClient send method related to guaranteed completion.

Despite explicit timeout configurations, a call to send can block indefinitely. The stacktrace below was obtained from a thread dump on a running OpenJDK 16.0.2 JVM. The thread was stuck in that state for over a week. An application restart was required to recover. The related Java source code is also included below.

My sense is that this is due to a missed notification from the async I/O subsystem. Unfortunately, I'm not an expert on HttpClient internals, and the asynchronous nature of the code makes it challenging to debug.

Is this the intended behavior? That is, are there scenarios in which send should never return? Did I miss a socket timeout option?

-----

HttpClient httpClient = HttpClient.newBuilder()
        .version(HttpClient.Version.HTTP_1_1)
        .connectTimeout(Duration.ofSeconds(5))
        .build();
...
HttpRequest request = HttpRequest.newBuilder()
        .timeout(Duration.ofSeconds(5))
        .uri(URI.create("http://" + ip + ":" + port + "/frontend"))
        .build();
...
String html = httpClient.send(request, HttpResponse.BodyHandlers.ofString()).body();

-----

"pool-1-thread-70" #164 prio=5 os_prio=0 cpu=100038.29ms elapsed=1891832.58s tid=0x00007fe0211d4050 nid=0x29e waiting on condition  [0x00007fdf025ac000]
   java.lang.Thread.State: WAITING (parking)
        at jdk.internal.misc.Unsafe.park(java.base at 16.0.2/Native Method)
        - parking to wait for  <0x00000000e7fc9be0> (a java.util.concurrent.CompletableFuture$Signaller)
        at java.util.concurrent.locks.LockSupport.park(java.base at 16.0.2/LockSupport.java:211)
        at java.util.concurrent.CompletableFuture$Signaller.block(java.base at 16.0.2/CompletableFuture.java:1860)
        at java.util.concurrent.ForkJoinPool.managedBlock(java.base at 16.0.2/ForkJoinPool.java:3137)
        at java.util.concurrent.CompletableFuture.waitingGet(java.base at 16.0.2/CompletableFuture.java:1894)
        at java.util.concurrent.CompletableFuture.get(java.base at 16.0.2/CompletableFuture.java:2068)
        at jdk.internal.net.http.HttpClientImpl.send(java.net.http at 16.0.2/HttpClientImpl.java:535)
        at jdk.internal.net.http.HttpClientFacade.send(java.net.http at 16.0.2/HttpClientFacade.java:119)
        at com.logmein.haproxy.ProxyFrontendConnectionCounter.countCurrentConnections(ProxyFrontendConnectionCounter.java:89)
        at com.logmein.haproxy.ProxyFrontendConnectionCounter.doRun(ProxyFrontendConnectionCounter.java:74)
        at com.logmein.haproxy.ProxyFrontendConnectionCounter.run(ProxyFrontendConnectionCounter.java:59)
        at com.logmein.haproxy.ProxyFrontendConnectionCounter$$Lambda$712/0x00000008010a0a88.run(Unknown Source)
        at java.util.concurrent.Executors$RunnableAdapter.call(java.base at 16.0.2/Executors.java:515)
        at java.util.concurrent.FutureTask.runAndReset(java.base at 16.0.2/FutureTask.java:305)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(java.base at 16.0.2/ScheduledThreadPoolExecutor.java:305)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base at 16.0.2/ThreadPoolExecutor.java:1130)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base at 16.0.2/ThreadPoolExecutor.java:630)
        at java.lang.Thread.run(java.base at 16.0.2/Thread.java:831)


Elliot Barlas
elliot.barlas at logmein.com
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.openjdk.java.net/pipermail/net-dev/attachments/20211005/4ec6237e/attachment-0001.htm>