HttpClient Send Method Guaranteed Completion

[Daniel Fuchs]

Hi Eliot,

Unless the server keeps the connection open, and fails to send all the
body bytes it has promised to send, the send operation should eventually
terminate. The behavior you describe looks indeed like a bug.

Could you please log a ticket with:
https://bugreport.java.com/bugreport/

That said - there is very little information here to work with.
It would be helpful to understand with which version of the protocol
this happened: HTTP or HTTPS? Version 1.1 or Version 2? Was it
with an upgrade request (h2c)?

If you manage to reproduce, it would be helpful if HTTP traces
could be enabled - I'd suggest:
`-Djdk.httpclient.HttpClient.log=headers,requests,errors`
(see https://docs.oracle.com/en/java/javase/17/core/java-networking.html)

Another issue here is that the request timeout set through
`HttpRequestBuilder::timeout` only runs until the response
headers are received. The reception of the body bytes is not
covered by this timeout. This is not well documented, and
we should probably do a better job there.

We have an enhancement request related to this:
https://bugs.openjdk.java.net/browse/JDK-8258397

However - setting up a global timeout for the request
is already possible:

If you wish to set a timeout for the reception of the body
bytes you can do so by making use of the timeout facility
provided by CompletableFuture:
https://docs.oracle.com/en/java/javase/17/docs/api/java.base/java/util/concurrent/CompletableFuture.html#get(long,java.util.concurrent.TimeUnit)

Instead of:

```
   String html = httpClient.send(request,
       HttpResponse.BodyHandlers.ofString()).body();
```

Use:

```
   long timeout = 5000; // ms
   String html;
   CompletableFuture<HttpResponse<String>> cf;
   try {
       cf = httpClient.sendAsync(request,
           HttpResponse.BodyHandlers.ofString());
       html = cf.get(timeout, TimedUnit.MILLISECONDS)
                .body();
   } catch (TimeoutException x) {
       // timeout: cancel request to free up
       //   any related resources
       cf.cancel();
   } catch (CancellationException x) {
       // cancelled
   } catch (InterruptedException x) {
       // interrupted
   } catch (ExecutionException x) {
       // IO etc..
       // unwrap to get exception and rethrow...
   }
```

This offers the possibility to set up a global timeout
You can also cancel the request asynchronously at any
time by calling cf.cancel() (since Java 15 IIRC).

best regards,

-- daniel


On 05/10/2021 23:05, Elliot Barlas wrote:
> 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