Uploaded image for project: 'JDK'
  1. JDK
  2. JDK-8304701

Request with timeout aborts later in-flight request on HTTP/1.1 cxn

XMLWordPrintable

    • b26
    • generic
    • generic
    • Verified

        ADDITIONAL SYSTEM INFORMATION :
        macOS 12.6.3 (21G419)
        openjdk version "20" 2023-03-21
        OpenJDK Runtime Environment (build 20+36-2344)
        OpenJDK 64-Bit Server VM (build 20+36-2344, mixed mode, sharing)

        A DESCRIPTION OF THE PROBLEM :
        This was originally encountered and reported as https://github.com/SeleniumHQ/selenium/issues/11798, until it was determined to be a JDK issue.

        When an java.net.http.HttpRequest is sent with a specific timeout over a persistent HTTP/1.1 connection, the ResponseTimerEvent appears to be unconditionally handle()'d once its deadline elapses (regardless of whether
        the request has completed), forcing the connection to be promptly and unnecessarily closed. If there is another request in-flight on the connection at this moment, then it will fail with a "java.io.IOException: connection closed locally" error.

        This issue is readily reproducible by sending requests in a tight loop to a server with non-trivial latency or that returns a large response having a non-trivial transfer time. This issue does appear to arise with HTTP/2 connections or if the connection is idle at the moment the timer elapses.

        STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
        javac JavaExample.java && java JavaExample

        EXPECTED VERSUS ACTUAL BEHAVIOR :
        EXPECTED -
        The process should run to completion with a few successful requests over ~15 seconds.
        ACTUAL -
        The process sends a few successful requests, but at ~10 seconds throws an exception like:
        ```
        Exception in thread "main" java.io.IOException: fixed content-length: 28490775, bytes received: 17112264
        at java.net.http/jdk.internal.net.http.HttpClientImpl.send(HttpClientImpl.java:586)
        at java.net.http/jdk.internal.net.http.HttpClientFacade.send(HttpClientFacade.java:123)
        at example.JavaExample.main(JavaExample.java:28)
        Caused by: java.io.IOException: fixed content-length: 28490775, bytes received: 17112264
        at java.net.http/jdk.internal.net.http.common.Utils.wrapWithExtraDetail(Utils.java:351)
        at java.net.http/jdk.internal.net.http.Http1Response$BodyReader.onReadError(Http1Response.java:760)
        at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.checkForErrors(Http1AsyncReceiver.java:302)
        at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.flush(Http1AsyncReceiver.java:268)
        at java.net.http/jdk.internal.net.http.common.SequentialScheduler$LockingRestartableTask.run(SequentialScheduler.java:205)
        at java.net.http/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:149)
        at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:230)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
        at java.base/java.lang.Thread.run(Thread.java:833)
        Caused by: java.io.IOException: connection closed locally
        at java.net.http/jdk.internal.net.http.SocketTube.signalClosed(SocketTube.java:159)
        at java.net.http/jdk.internal.net.http.PlainHttpConnection.close(PlainHttpConnection.java:372)
        at java.net.http/jdk.internal.net.http.AsyncSSLConnection.close(AsyncSSLConnection.java:111)
        at java.net.http/jdk.internal.net.http.Http1Exchange.cancelImpl(Http1Exchange.java:492)
        at java.net.http/jdk.internal.net.http.Http1Exchange.cancel(Http1Exchange.java:427)
        at java.net.http/jdk.internal.net.http.Exchange.cancel(Exchange.java:238)
        at java.net.http/jdk.internal.net.http.MultiExchange.cancel(MultiExchange.java:260)
        at java.net.http/jdk.internal.net.http.ResponseTimerEvent.handle(ResponseTimerEvent.java:71)
        at java.net.http/jdk.internal.net.http.HttpClientImpl.purgeTimeoutsAndReturnNextDeadline(HttpClientImpl.java:1270)
        at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.run(HttpClientImpl.java:899)
        ```

        ---------- BEGIN SOURCE ----------
        import java.net.URI;
        import java.net.http.HttpClient;
        import java.net.http.HttpRequest;
        import java.net.http.HttpResponse;
        import java.time.Duration;
        import java.time.Instant;

        import static java.net.http.HttpClient.Redirect.ALWAYS;
        import static java.net.http.HttpClient.Version.HTTP_1_1;

        public class JavaExample {

            public static void main(String[] args) throws Exception {
                int timeoutSeconds = 10;

                HttpClient client = HttpClient.newBuilder()
                        .followRedirects(ALWAYS)
                        .build();

                for (Instant start = Instant.now(), now = start; now.isBefore(start.plusSeconds(timeoutSeconds * 3 / 2)); now = Instant.now()) {
                    HttpRequest request = HttpRequest.newBuilder().uri(URI.create("https://github.com/SeleniumHQ/selenium/releases/download/selenium-4.8.0/selenium-java-4.8.1.zip"))
                            .GET()
                            .version(HTTP_1_1)
                            .timeout(Duration.ofSeconds(timeoutSeconds))
                            .build();
                    HttpResponse<Void> response = client.send(request, HttpResponse.BodyHandlers.discarding());
                    System.out.println(now + " -> " + response.headers().firstValue("date"));
                }
            }
        }
        ---------- END SOURCE ----------

        CUSTOMER SUBMITTED WORKAROUND :
        Use HTTP/2 if available
        Add "Connection: close" header to request if possible (requires jdk.httpclient.allowRestrictedHeaders customization)
        Avoid using request timeouts if feasible


        FREQUENCY : often


              ccleary Conor Cleary (Inactive)
              webbuggrp Webbug Group
              Votes:
              0 Vote for this issue
              Watchers:
              12 Start watching this issue

                Created:
                Updated:
                Resolved: