HttpClient Send Method Guaranteed Completion

[Michael McMahon]

I think we should at least clarify the behavior of 
HttpRequest.Builder.timeout() ie. that it is specifically related to the 
response headers, and maybe consider adding a timeout variant that sets 
the timeout for the entire response, including the body.

- Michael.

On 06/10/2021 10:42, Daniel Fuchs wrote:
> 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
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.openjdk.java.net/pipermail/net-dev/attachments/20211007/2d660b71/attachment-0001.htm>