changeset 16969:c35ff69c2852

8178147: Race conditions in timeout handling code in http/2 incubator client Summary: Timeout handling code (in particular cancel(IOException)) is modified to take into account cancellation arising before exchange implementation is established or response completable future is created. TimeoutEvent::compareTo method is modified to be consistent with TimeoutEvent::equals. Reviewed-by: prappo, chegar, michaelm
author dfuchs
date Tue, 11 Apr 2017 16:32:38 +0100
parents cd268728d178
children 23255bc8606d
files src/jdk.incubator.httpclient/share/classes/jdk/incubator/http/Exchange.java src/jdk.incubator.httpclient/share/classes/jdk/incubator/http/Http1Exchange.java src/jdk.incubator.httpclient/share/classes/jdk/incubator/http/HttpClientImpl.java src/jdk.incubator.httpclient/share/classes/jdk/incubator/http/MultiExchange.java src/jdk.incubator.httpclient/share/classes/jdk/incubator/http/PlainHttpConnection.java src/jdk.incubator.httpclient/share/classes/jdk/incubator/http/Stream.java src/jdk.incubator.httpclient/share/classes/jdk/incubator/http/TimeoutEvent.java test/ProblemList.txt test/java/net/httpclient/SmallTimeout.java test/java/net/httpclient/TimeoutOrdering.java
diffstat 10 files changed, 409 insertions(+), 48 deletions(-) [+]
line wrap: on
line diff
--- a/src/jdk.incubator.httpclient/share/classes/jdk/incubator/http/Exchange.java	Tue Apr 11 10:12:27 2017 +0800
+++ b/src/jdk.incubator.httpclient/share/classes/jdk/incubator/http/Exchange.java	Tue Apr 11 16:32:38 2017 +0100
@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2015, 2016, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2015, 2017, Oracle and/or its affiliates. All rights reserved.
  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
  *
  * This code is free software; you can redistribute it and/or modify it
@@ -26,6 +26,7 @@
 package jdk.incubator.http;
 
 import java.io.IOException;
+import java.io.UncheckedIOException;
 import java.net.InetSocketAddress;
 import java.net.ProxySelector;
 import java.net.SocketPermission;
@@ -64,6 +65,9 @@
     final HttpRequestImpl request;
     final HttpClientImpl client;
     volatile ExchangeImpl<T> exchImpl;
+    // used to record possible cancellation raised before the exchImpl
+    // has been established.
+    private volatile IOException failed;
     final List<SocketPermission> permissions = new LinkedList<>();
     final AccessControlContext acc;
     final MultiExchange<?,T> multi;
@@ -143,14 +147,80 @@
     }
 
     public void cancel() {
+        // cancel can be called concurrently before or at the same time
+        // that the exchange impl is being established.
+        // In that case we won't be able to propagate the cancellation
+        // right away
         if (exchImpl != null) {
             exchImpl.cancel();
+        } else {
+            // no impl - can't cancel impl yet.
+            // call cancel(IOException) instead which takes care
+            // of race conditions between impl/cancel.
+            cancel(new IOException("Request cancelled"));
         }
     }
 
     public void cancel(IOException cause) {
-        if (exchImpl != null) {
-            exchImpl.cancel(cause);
+        // If the impl is non null, propagate the exception right away.
+        // Otherwise record it so that it can be propagated once the
+        // exchange impl has been established.
+        ExchangeImpl<?> impl = exchImpl;
+        if (impl != null) {
+            // propagate the exception to the impl
+            impl.cancel(cause);
+        } else {
+            try {
+                // no impl yet. record the exception
+                failed = cause;
+                // now call checkCancelled to recheck the impl.
+                // if the failed state is set and the impl is not null, reset
+                // the failed state and propagate the exception to the impl.
+                checkCancelled(false);
+            } catch (IOException x) {
+                // should not happen - we passed 'false' above
+                throw new UncheckedIOException(x);
+            }
+        }
+    }
+
+    // This method will raise an exception if one was reported and if
+    // it is possible to do so. If the exception can be raised, then
+    // the failed state will be reset. Otherwise, the failed state
+    // will persist until the exception can be raised and the failed state
+    // can be cleared.
+    // Takes care of possible race conditions.
+    private void checkCancelled(boolean throwIfNoImpl) throws IOException {
+        ExchangeImpl<?> impl = null;
+        IOException cause = null;
+        if (failed != null) {
+            synchronized(this) {
+                cause = failed;
+                impl = exchImpl;
+                if (throwIfNoImpl || impl != null) {
+                    // The exception will be raised by one of the two methods
+                    // below: reset the failed state.
+                    failed = null;
+                }
+            }
+        }
+        if (cause == null) return;
+        if (impl != null) {
+            // The exception is raised by propagating it to the impl.
+            impl.cancel(cause);
+        } else if (throwIfNoImpl) {
+            // The exception is raised by throwing it immediately
+            throw cause;
+        } else {
+            Log.logTrace("Exchange: request [{0}/timeout={1}ms] no impl is set."
+                         + "\n\tCan''t cancel yet with {2}",
+                         request.uri(),
+                         request.duration() == null ? -1 :
+                         // calling duration.toMillis() can throw an exception.
+                         // this is just debugging, we don't care if it overflows.
+                         (request.duration().getSeconds() * 1000
+                          + request.duration().getNano() / 1000000),
+                         cause);
         }
     }
 
@@ -191,10 +261,26 @@
         }
     }
 
+    // get/set the exchange impl, solving race condition issues with
+    // potential concurrent calls to cancel() or cancel(IOException)
+    private void establishExchange(HttpConnection connection)
+        throws IOException, InterruptedException
+    {
+        // check if we have been cancelled first.
+        checkCancelled(true);
+        // not yet cancelled: create/get a new impl
+        exchImpl = ExchangeImpl.get(this, connection);
+        // recheck for cancelled, in case of race conditions
+        checkCancelled(true);
+        // now we're good to go. because exchImpl is no longer null
+        // cancel() will be able to propagate directly to the impl
+        // after this point.
+    }
+
     private Response responseImpl0(HttpConnection connection)
         throws IOException, InterruptedException
     {
-        exchImpl = ExchangeImpl.get(this, connection);
+        establishExchange(connection);
         exchImpl.setClientForRequest(requestProcessor);
         if (request.expectContinue()) {
             Log.logTrace("Sending Expect: 100-Continue");
@@ -257,7 +343,7 @@
 
     CompletableFuture<Response> responseAsyncImpl0(HttpConnection connection) {
         try {
-            exchImpl = ExchangeImpl.get(this, connection);
+            establishExchange(connection);
         } catch (IOException | InterruptedException e) {
             return MinimalFuture.failedFuture(e);
         }
--- a/src/jdk.incubator.httpclient/share/classes/jdk/incubator/http/Http1Exchange.java	Tue Apr 11 10:12:27 2017 +0800
+++ b/src/jdk.incubator.httpclient/share/classes/jdk/incubator/http/Http1Exchange.java	Tue Apr 11 16:32:38 2017 +0100
@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2015, 2016, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2015, 2017, Oracle and/or its affiliates. All rights reserved.
  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
  *
  * This code is free software; you can redistribute it and/or modify it
@@ -46,9 +46,12 @@
 class Http1Exchange<T> extends ExchangeImpl<T> {
 
     final HttpRequestImpl request;        // main request
-    final List<CompletableFuture<?>> operations; // used for cancel
+    private final List<CompletableFuture<?>> operations; // used for cancel
     final Http1Request requestAction;
-    volatile Http1Response<T> response;
+    private volatile Http1Response<T> response;
+    // use to record possible cancellation raised before any operation
+    // has been initiated.
+    private IOException failed;
     final HttpConnection connection;
     final HttpClientImpl client;
     final Executor executor;
@@ -70,7 +73,7 @@
         this.request = exchange.request();
         this.client = exchange.client();
         this.executor = exchange.executor();
-        this.operations = Collections.synchronizedList(new LinkedList<>());
+        this.operations = new LinkedList<>();
         this.buffer = exchange.getBuffer();
         if (connection != null) {
             this.connection = connection;
@@ -186,9 +189,22 @@
         }
         connection.close();
         int count = 0;
-        for (CompletableFuture<?> cf : operations) {
-            cf.completeExceptionally(cause);
-            count++;
+        if (operations.isEmpty()) {
+            failed = cause;
+            Log.logTrace("Http1Exchange: request [{0}/timeout={1}ms] no pending operation."
+                         + "\n\tCan''t cancel yet with {2}",
+                         request.uri(),
+                         request.duration() == null ? -1 :
+                         // calling duration.toMillis() can throw an exception.
+                         // this is just debugging, we don't care if it overflows.
+                         (request.duration().getSeconds() * 1000
+                          + request.duration().getNano() / 1000000),
+                         cause);
+        } else {
+            for (CompletableFuture<?> cf : operations) {
+                cf.completeExceptionally(cause);
+                count++;
+            }
         }
         Log.logError("Http1Exchange.cancel: count=" + count);
     }
@@ -206,8 +222,24 @@
         CompletableFuture<Response> cf =
             connection.whenReceivingResponse()
                       .thenCompose((v) -> getResponseAsyncImpl(executor));
-
-        operations.add(cf);
+        IOException cause;
+        synchronized(this) {
+            operations.add(cf);
+            cause = failed;
+            failed = null;
+        }
+        if (cause != null) {
+            Log.logTrace("Http1Exchange: request [{0}/timeout={1}ms]"
+                         + "\n\tCompleting exceptionally with {2}\n",
+                         request.uri(),
+                         request.duration() == null ? -1 :
+                         // calling duration.toMillis() can throw an exception.
+                         // this is just debugging, we don't care if it overflows.
+                         (request.duration().getSeconds() * 1000
+                          + request.duration().getNano() / 1000000),
+                         cause);
+            cf.completeExceptionally(cause);
+        }
         return cf;
     }
 }
--- a/src/jdk.incubator.httpclient/share/classes/jdk/incubator/http/HttpClientImpl.java	Tue Apr 11 10:12:27 2017 +0800
+++ b/src/jdk.incubator.httpclient/share/classes/jdk/incubator/http/HttpClientImpl.java	Tue Apr 11 16:32:38 2017 +0100
@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2015, 2016, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2015, 2017, Oracle and/or its affiliates. All rights reserved.
  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
  *
  * This code is free software; you can redistribute it and/or modify it
@@ -582,12 +582,14 @@
     // Timers are implemented through timed Selector.select() calls.
 
     synchronized void registerTimer(TimeoutEvent event) {
+        Log.logTrace("Registering timer {0}", event);
         timeouts.add(event);
         selmgr.wakeupSelector();
     }
 
     synchronized void cancelTimer(TimeoutEvent event) {
-        timeouts.stream().filter(e -> e == event).forEach(timeouts::remove);
+        Log.logTrace("Canceling timer {0}", event);
+        timeouts.remove(event);
     }
 
     /**
@@ -595,23 +597,61 @@
      * returns the amount of time, in milliseconds, until the next earliest
      * event. A return value of 0 means that there are no events.
      */
-    private synchronized long purgeTimeoutsAndReturnNextDeadline() {
-        if (timeouts.isEmpty())
-            return 0L;
+    private long purgeTimeoutsAndReturnNextDeadline() {
+        long diff = 0L;
+        List<TimeoutEvent> toHandle = null;
+        int remaining = 0;
+        // enter critical section to retrieve the timeout event to handle
+        synchronized(this) {
+            if (timeouts.isEmpty()) return 0L;
 
-        Instant now = Instant.now();
-        Iterator<TimeoutEvent> itr = timeouts.iterator();
-        while (itr.hasNext()) {
-            TimeoutEvent event = itr.next();
-            long diff = now.until(event.deadline(), ChronoUnit.MILLIS);
-            if (diff <= 0) {
-                itr.remove();
-                event.handle();  // TODO: release lock.
-            } else {
-                return diff;
+            Instant now = Instant.now();
+            Iterator<TimeoutEvent> itr = timeouts.iterator();
+            while (itr.hasNext()) {
+                TimeoutEvent event = itr.next();
+                diff = now.until(event.deadline(), ChronoUnit.MILLIS);
+                if (diff <= 0) {
+                    itr.remove();
+                    toHandle = (toHandle == null) ? new ArrayList<>() : toHandle;
+                    toHandle.add(event);
+                } else {
+                    break;
+                }
             }
+            remaining = timeouts.size();
         }
-        return 0L;
+
+        // can be useful for debugging
+        if (toHandle != null && Log.trace()) {
+            Log.logTrace("purgeTimeoutsAndReturnNextDeadline: handling "
+                    + (toHandle == null ? 0 : toHandle.size()) + " events, "
+                    + "remaining " + remaining
+                    + ", next deadline: " + (diff < 0 ? 0L : diff));
+        }
+
+        // handle timeout events out of critical section
+        if (toHandle != null) {
+            Throwable failed = null;
+            for (TimeoutEvent event : toHandle) {
+                try {
+                   Log.logTrace("Firing timer {0}", event);
+                   event.handle();
+                } catch (Error | RuntimeException e) {
+                    // Not expected. Handle remaining events then throw...
+                    // If e is an OOME or SOE it might simply trigger a new
+                    // error from here - but in this case there's not much we
+                    // could do anyway. Just let it flow...
+                    if (failed == null) failed = e;
+                    else failed.addSuppressed(e);
+                    Log.logTrace("Failed to handle event {0}: {1}", event, e);
+                }
+            }
+            if (failed instanceof Error) throw (Error) failed;
+            if (failed instanceof RuntimeException) throw (RuntimeException) failed;
+        }
+
+        // return time to wait until next event. 0L if there's no more events.
+        return diff < 0 ? 0L : diff;
     }
 
     // used for the connection window
--- a/src/jdk.incubator.httpclient/share/classes/jdk/incubator/http/MultiExchange.java	Tue Apr 11 10:12:27 2017 +0800
+++ b/src/jdk.incubator.httpclient/share/classes/jdk/incubator/http/MultiExchange.java	Tue Apr 11 16:32:38 2017 +0100
@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2015, 2016, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2015, 2017, Oracle and/or its affiliates. All rights reserved.
  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
  *
  * This code is free software; you can redistribute it and/or modify it
@@ -357,9 +357,5 @@
         public void handle() {
             cancel(new HttpTimeoutException("request timed out"));
         }
-        @Override
-        public String toString() {
-            return "[deadline = " + deadline() + "]";
-        }
     }
 }
--- a/src/jdk.incubator.httpclient/share/classes/jdk/incubator/http/PlainHttpConnection.java	Tue Apr 11 10:12:27 2017 +0800
+++ b/src/jdk.incubator.httpclient/share/classes/jdk/incubator/http/PlainHttpConnection.java	Tue Apr 11 16:32:38 2017 +0100
@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2015, 2016, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2015, 2017, Oracle and/or its affiliates. All rights reserved.
  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
  *
  * This code is free software; you can redistribute it and/or modify it
@@ -54,7 +54,7 @@
  */
 class PlainHttpConnection extends HttpConnection implements AsyncConnection {
 
-    protected SocketChannel chan;
+    protected final SocketChannel chan;
     private volatile boolean connected;
     private boolean closed;
 
@@ -100,6 +100,7 @@
                 chan.finishConnect();
             } catch (IOException e) {
                 cf.completeExceptionally(e);
+                return;
             }
             connected = true;
             cf.complete(null);
--- a/src/jdk.incubator.httpclient/share/classes/jdk/incubator/http/Stream.java	Tue Apr 11 10:12:27 2017 +0800
+++ b/src/jdk.incubator.httpclient/share/classes/jdk/incubator/http/Stream.java	Tue Apr 11 16:32:38 2017 +0100
@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2015, 2016, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2015, 2017, Oracle and/or its affiliates. All rights reserved.
  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
  *
  * This code is free software; you can redistribute it and/or modify it
@@ -670,11 +670,21 @@
 
     @Override
     CompletableFuture<Response> getResponseAsync(Executor executor) {
-        CompletableFuture<Response> cf;
+        CompletableFuture<Response> cf = null;
+        // The code below deals with race condition that can be caused when
+        // completeResponse() is being called before getResponseAsync()
         synchronized (response_cfs) {
             if (!response_cfs.isEmpty()) {
+                // This CompletableFuture was created by completeResponse().
+                // it will be already completed.
                 cf = response_cfs.remove(0);
+                // if we find a cf here it should be already completed.
+                // finding a non completed cf should not happen. just assert it.
+                assert cf.isDone() : "Removing uncompleted response: could cause code to hang!";
             } else {
+                // getResponseAsync() is called first. Create a CompletableFuture
+                // that will be completed by completeResponse() when
+                // completeResponse() is called.
                 cf = new MinimalFuture<>();
                 response_cfs.add(cf);
             }
@@ -708,7 +718,7 @@
                     cf.complete(resp);
                     response_cfs.remove(cf);
                     return;
-                }
+                } // else we found the previous response: just leave it alone.
             }
             cf = MinimalFuture.completedFuture(resp);
             Log.logTrace("Created completed future (streamid={0}): {1}",
@@ -742,10 +752,13 @@
      */
     void completeResponseExceptionally(Throwable t) {
         synchronized (response_cfs) {
-            for (CompletableFuture<Response> cf : response_cfs) {
+            // use index to avoid ConcurrentModificationException
+            // caused by removing the CF from within the loop.
+            for (int i = 0; i < response_cfs.size(); i++) {
+                CompletableFuture<Response> cf = response_cfs.get(i);
                 if (!cf.isDone()) {
                     cf.completeExceptionally(t);
-                    response_cfs.remove(cf);
+                    response_cfs.remove(i);
                     return;
                 }
             }
--- a/src/jdk.incubator.httpclient/share/classes/jdk/incubator/http/TimeoutEvent.java	Tue Apr 11 10:12:27 2017 +0800
+++ b/src/jdk.incubator.httpclient/share/classes/jdk/incubator/http/TimeoutEvent.java	Tue Apr 11 16:32:38 2017 +0100
@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2015, 2016, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2015, 2017, Oracle and/or its affiliates. All rights reserved.
  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
  *
  * This code is free software; you can redistribute it and/or modify it
@@ -27,10 +27,11 @@
 
 import java.time.Duration;
 import java.time.Instant;
+import java.util.concurrent.atomic.AtomicLong;
 
 /**
  * Timeout event notified by selector thread. Executes the given handler if
- * the timer not cancelled first.
+ * the timer not canceled first.
  *
  * Register with {@link HttpClientImpl#registerTimer(TimeoutEvent)}.
  *
@@ -38,6 +39,10 @@
  */
 abstract class TimeoutEvent implements Comparable<TimeoutEvent> {
 
+    private static final AtomicLong COUNTER = new AtomicLong();
+    // we use id in compareTo to make compareTo consistent with equals
+    // see TimeoutEvent::compareTo below;
+    private final long id = COUNTER.incrementAndGet();
     private final Instant deadline;
 
     TimeoutEvent(Duration duration) {
@@ -52,6 +57,24 @@
 
     @Override
     public int compareTo(TimeoutEvent other) {
-        return this.deadline.compareTo(other.deadline);
+        if (other == this) return 0;
+        // if two events have the same deadline, but are not equals, then the
+        // smaller is the one that was created before (has the smaller id).
+        // This is arbitrary and we don't really care which is smaller or
+        // greater, but we need a total order, so two events with the
+        // same deadline cannot compare == 0 if they are not equals.
+        final int compareDeadline = this.deadline.compareTo(other.deadline);
+        if (compareDeadline == 0 && !this.equals(other)) {
+            long diff = this.id - other.id; // should take care of wrap around
+            if (diff < 0) return -1;
+            else if (diff > 0) return 1;
+            else assert false : "Different events with same id and deadline";
+        }
+        return compareDeadline;
+    }
+
+    @Override
+    public String toString() {
+        return "TimeoutEvent[id=" + id + ", deadline=" + deadline + "]";
     }
 }
--- a/test/ProblemList.txt	Tue Apr 11 10:12:27 2017 +0800
+++ b/test/ProblemList.txt	Tue Apr 11 16:32:38 2017 +0100
@@ -170,8 +170,6 @@
 
 java/net/DatagramSocket/SendDatagramToBadAddress.java           7143960 macosx-all
 
-java/net/httpclient/TimeoutOrdering.java                        8170940 solaris-all,windows-all
-
 ############################################################################
 
 # jdk_nio
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/test/java/net/httpclient/SmallTimeout.java	Tue Apr 11 16:32:38 2017 +0100
@@ -0,0 +1,165 @@
+/*
+ * Copyright (c) 2015, 2017, Oracle and/or its affiliates. All rights reserved.
+ * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
+ *
+ * This code is free software; you can redistribute it and/or modify it
+ * under the terms of the GNU General Public License version 2 only, as
+ * published by the Free Software Foundation.
+ *
+ * This code is distributed in the hope that it will be useful, but WITHOUT
+ * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+ * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
+ * version 2 for more details (a copy is included in the LICENSE file that
+ * accompanied this code).
+ *
+ * You should have received a copy of the GNU General Public License version
+ * 2 along with this work; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
+ *
+ * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
+ * or visit www.oracle.com if you need additional information or have any
+ * questions.
+ */
+
+import java.io.IOException;
+import java.net.ServerSocket;
+import java.net.URI;
+import jdk.incubator.http.HttpClient;
+import jdk.incubator.http.HttpRequest;
+import jdk.incubator.http.HttpResponse;
+import jdk.incubator.http.HttpTimeoutException;
+import java.time.Duration;
+import java.util.concurrent.CompletableFuture;
+import java.util.concurrent.ExecutorService;
+import java.util.concurrent.Executors;
+import java.util.concurrent.LinkedBlockingQueue;
+import static java.lang.System.out;
+import static jdk.incubator.http.HttpResponse.BodyHandler.discard;
+
+/**
+ * @test
+ * @bug 8178147
+ * @summary Ensures that small timeouts do not cause hangs due to race conditions
+ * @run main/othervm SmallTimeout
+ */
+
+// To enable logging use. Not enabled by default as it changes the dynamics
+// of the test.
+// @run main/othervm -Djdk.httpclient.HttpClient.log=all,frames:all SmallTimeout
+
+public class SmallTimeout {
+
+    static int[] TIMEOUTS = {2, 1, 3, 2, 100, 1};
+
+    // A queue for placing timed out requests so that their order can be checked.
+    static LinkedBlockingQueue<HttpRequest> queue = new LinkedBlockingQueue<>();
+
+    static volatile boolean error;
+
+    public static void main(String[] args) throws Exception {
+        HttpClient client = HttpClient.newHttpClient();
+
+        try (ServerSocket ss = new ServerSocket(0, 20)) {
+            int port = ss.getLocalPort();
+            URI uri = new URI("http://127.0.0.1:" + port + "/");
+
+            HttpRequest[] requests = new HttpRequest[TIMEOUTS.length];
+
+            out.println("--- TESTING Async");
+            for (int i = 0; i < TIMEOUTS.length; i++) {
+                requests[i] = HttpRequest.newBuilder(uri)
+                                         .timeout(Duration.ofMillis(TIMEOUTS[i]))
+                                         .GET()
+                                         .build();
+
+                final HttpRequest req = requests[i];
+                CompletableFuture<HttpResponse<Object>> response = client
+                    .sendAsync(req, discard(null))
+                    .whenComplete((HttpResponse<Object> r, Throwable t) -> {
+                        if (r != null) {
+                            out.println("Unexpected response: " + r);
+                            error = true;
+                        }
+                        if (t != null) {
+                            if (!(t.getCause() instanceof HttpTimeoutException)) {
+                                out.println("Wrong exception type:" + t.toString());
+                                Throwable c = t.getCause() == null ? t : t.getCause();
+                                c.printStackTrace();
+                                error = true;
+                            } else {
+                                out.println("Caught expected timeout: " + t.getCause());
+                            }
+                        }
+                        if (t == null && r == null) {
+                            out.println("Both response and throwable are null!");
+                            error = true;
+                        }
+                        queue.add(req);
+                    });
+            }
+            System.out.println("All requests submitted. Waiting ...");
+
+            checkReturn(requests);
+
+            if (error)
+                throw new RuntimeException("Failed. Check output");
+
+            // Repeat blocking in separate threads. Use queue to wait.
+            out.println("--- TESTING Sync");
+
+            // For running blocking response tasks
+            ExecutorService executor = Executors.newCachedThreadPool();
+
+            for (int i = 0; i < TIMEOUTS.length; i++) {
+                requests[i] = HttpRequest.newBuilder(uri)
+                                         .timeout(Duration.ofMillis(TIMEOUTS[i]))
+                                         .GET()
+                                         .build();
+
+                final HttpRequest req = requests[i];
+                executor.execute(() -> {
+                    try {
+                        client.send(req, discard(null));
+                    } catch (HttpTimeoutException e) {
+                        out.println("Caught expected timeout: " + e);
+                        queue.offer(req);
+                    } catch (IOException | InterruptedException ee) {
+                        Throwable c = ee.getCause() == null ? ee : ee.getCause();
+                        c.printStackTrace();
+                        error = true;
+                    }
+                });
+            }
+            System.out.println("All requests submitted. Waiting ...");
+
+            checkReturn(requests);
+
+            executor.shutdownNow();
+
+            if (error)
+                throw new RuntimeException("Failed. Check output");
+
+        } finally {
+            ((ExecutorService) client.executor()).shutdownNow();
+        }
+    }
+
+    static void checkReturn(HttpRequest[] requests) throws InterruptedException {
+        // wait for exceptions and check order
+        for (int j = 0; j < TIMEOUTS.length; j++) {
+            HttpRequest req = queue.take();
+            out.println("Got request from queue " + req + ", order: " + getRequest(req, requests));
+        }
+        out.println("Return ok");
+    }
+
+    /** Returns the index of the request in the array. */
+    static String getRequest(HttpRequest req, HttpRequest[] requests) {
+        for (int i=0; i<requests.length; i++) {
+            if (req == requests[i]) {
+                return "r" + i;
+            }
+        }
+        throw new AssertionError("Unknown request: " + req);
+    }
+}
--- a/test/java/net/httpclient/TimeoutOrdering.java	Tue Apr 11 10:12:27 2017 +0800
+++ b/test/java/net/httpclient/TimeoutOrdering.java	Tue Apr 11 16:32:38 2017 +0100
@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2015, 2016, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2015, 2017, Oracle and/or its affiliates. All rights reserved.
  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
  *
  * This code is free software; you can redistribute it and/or modify it
@@ -43,6 +43,9 @@
  * @run main/othervm TimeoutOrdering
  */
 
+// To enable logging use
+// @run main/othervm -Djdk.httpclient.HttpClient.log=all,frames:all TimeoutOrdering
+
 public class TimeoutOrdering {
 
     // The assumption is that 5 secs is sufficiently large enough, without being
@@ -81,6 +84,8 @@
                         if (t != null) {
                             if (!(t.getCause() instanceof HttpTimeoutException)) {
                                 out.println("Wrong exception type:" + t.toString());
+                                Throwable c = t.getCause() == null ? t : t.getCause();
+                                c.printStackTrace();
                                 error = true;
                             } else {
                                 out.println("Caught expected timeout: " + t.getCause());
@@ -116,6 +121,8 @@
                         out.println("Caught expected timeout: " + e);
                         queue.offer(req);
                     } catch (IOException | InterruptedException ee) {
+                        Throwable c = ee.getCause() == null ? ee : ee.getCause();
+                        c.printStackTrace();
                         error = true;
                     }
                 });