# HG changeset patch # User dfuchs # Date 1523612957 -3600 # Node ID ba64c30666cc5cfce6ec905b2e94fd3ad1b1ab94 # Parent 56c32f8ea40659ae857891019f36cfb7824485d7 http-client-branch: add test coverage and better diagnosis for HttpClientImpl operations ref count diff -r 56c32f8ea406 -r ba64c30666cc src/java.net.http/share/classes/jdk/internal/net/http/Http1AsyncReceiver.java --- a/src/java.net.http/share/classes/jdk/internal/net/http/Http1AsyncReceiver.java Wed Apr 11 15:21:25 2018 +0100 +++ b/src/java.net.http/share/classes/jdk/internal/net/http/Http1AsyncReceiver.java Fri Apr 13 10:49:17 2018 +0100 @@ -113,6 +113,14 @@ */ public AbstractSubscription subscription(); + /** + * Called to make sure resources are released when the + * when the Http1AsyncReceiver is stopped. + * @param error The Http1AsyncReceiver pending error ref, + * if any. + */ + public void close(Throwable error); + } /** @@ -470,6 +478,10 @@ void stop() { debug.log(Level.DEBUG, "stopping"); scheduler.stop(); + // make sure ref count is handled properly by + // closing the delegate. + Http1AsyncDelegate previous = delegate; + if (previous != null) previous.close(error); delegate = null; owner = null; } diff -r 56c32f8ea406 -r ba64c30666cc src/java.net.http/share/classes/jdk/internal/net/http/Http1Exchange.java --- a/src/java.net.http/share/classes/jdk/internal/net/http/Http1Exchange.java Wed Apr 11 15:21:25 2018 +0100 +++ b/src/java.net.http/share/classes/jdk/internal/net/http/Http1Exchange.java Fri Apr 13 10:49:17 2018 +0100 @@ -214,9 +214,13 @@ this.s = s; } + @Override public AbstractSubscription subscription() { return s; } + + @Override + public void close(Throwable error) {} } @Override diff -r 56c32f8ea406 -r ba64c30666cc src/java.net.http/share/classes/jdk/internal/net/http/Http1Response.java --- a/src/java.net.http/share/classes/jdk/internal/net/http/Http1Response.java Wed Apr 11 15:21:25 2018 +0100 +++ b/src/java.net.http/share/classes/jdk/internal/net/http/Http1Response.java Fri Apr 13 10:49:17 2018 +0100 @@ -117,10 +117,12 @@ // increment the reference count on the HttpClientImpl // to prevent the SelectorManager thread from exiting // until our operation is complete. - debug.log(Level.DEBUG, "incrementing ref count for %s", client); + debug.log(Level.DEBUG, "Operation started: incrementing ref count for %s", client); client.reference(); state = 0x01; } else { + debug.log(Level.DEBUG, "Operation ref count for %s is already %s", + client, ((state & 0x2) == 0x2) ? "released." : "incremented!" ); assert (state & 0x01) == 0 : "reference count already incremented"; } } @@ -131,10 +133,14 @@ // to allow the SelectorManager thread to exit if no // other operation is pending and the facade is no // longer referenced. - debug.log(Level.DEBUG, "decrementing ref count for %s", client); + debug.log(Level.DEBUG, "Operation finished: decrementing ref count for %s", client); client.unreference(); - state |= 0x02; + } else if (state == 0) { + debug.log(Level.DEBUG, "Operation finished: releasing ref count for %s", client); + } else if ((state & 0x02) == 0x02) { + debug.log(Level.DEBUG, "ref count for %s already released", client); } + state |= 0x02; } } @@ -619,6 +625,20 @@ cf.completeExceptionally(t); } } + + @Override + public void close(Throwable error) { + // if there's no error nothing to do: the cf should/will + // be completed. + if (error != null) { + CompletableFuture cf = this.cf; + if (cf != null) { + debug.log(Level.DEBUG, + () -> "close: completing header parser CF with " + error); + cf.completeExceptionally(error); + } + } + } } // Invoked with each new ByteBuffer when reading bodies... @@ -706,6 +726,25 @@ } @Override + public final void close(Throwable error) { + CompletableFuture cf = this.cf; + if (cf != null && !cf.isDone()) { + // we want to make sure dependent actions are triggered + // in order to make sure the client reference count + // is decremented + if (error != null) { + debug.log(Level.DEBUG, + () -> "close: completing body parser CF with " + error); + cf.completeExceptionally(error); + } else { + debug.log(Level.DEBUG, + () -> "close: completing body parser CF"); + cf.complete(State.READING_BODY); + } + } + } + + @Override public String toString() { return super.toString() + "/parser=" + String.valueOf(parser); } diff -r 56c32f8ea406 -r ba64c30666cc src/java.net.http/share/classes/jdk/internal/net/http/Http2Connection.java --- a/src/java.net.http/share/classes/jdk/internal/net/http/Http2Connection.java Wed Apr 11 15:21:25 2018 +0100 +++ b/src/java.net.http/share/classes/jdk/internal/net/http/Http2Connection.java Fri Apr 13 10:49:17 2018 +0100 @@ -741,7 +741,7 @@ // to allow the SelectorManager thread to exit if no // other operation is pending and the facade is no // longer referenced. - client().unreference(); + client().streamUnreference(); } // ## Remove s != null. It is a hack for delayed cancellation,reset if (s != null && !(s instanceof Stream.PushedStream)) { @@ -906,7 +906,7 @@ // increment the reference count on the HttpClientImpl // to prevent the SelectorManager thread from exiting until // the stream is closed. - client().reference(); + client().streamReference(); streams.put(streamid, stream); } diff -r 56c32f8ea406 -r ba64c30666cc src/java.net.http/share/classes/jdk/internal/net/http/HttpClientFacade.java --- a/src/java.net.http/share/classes/jdk/internal/net/http/HttpClientFacade.java Wed Apr 11 15:21:25 2018 +0100 +++ b/src/java.net.http/share/classes/jdk/internal/net/http/HttpClientFacade.java Fri Apr 13 10:49:17 2018 +0100 @@ -41,12 +41,15 @@ import java.net.http.HttpResponse.BodyHandler; import java.net.http.HttpResponse.PushPromiseHandler; import java.net.http.WebSocket; +import jdk.internal.net.http.common.OperationTrackers.Trackable; +import jdk.internal.net.http.common.OperationTrackers.Tracker; /** * An HttpClientFacade is a simple class that wraps an HttpClient implementation * and delegates everything to its implementation delegate. */ -final class HttpClientFacade extends HttpClient { +final class HttpClientFacade extends HttpClient + implements Trackable { final HttpClientImpl impl; @@ -57,6 +60,11 @@ this.impl = impl; } + @Override // for tests + public Tracker getOperationsTracker() { + return impl.getOperationsTracker(); + } + @Override public Optional cookieHandler() { return impl.cookieHandler(); diff -r 56c32f8ea406 -r ba64c30666cc src/java.net.http/share/classes/jdk/internal/net/http/HttpClientImpl.java --- a/src/java.net.http/share/classes/jdk/internal/net/http/HttpClientImpl.java Wed Apr 11 15:21:25 2018 +0100 +++ b/src/java.net.http/share/classes/jdk/internal/net/http/HttpClientImpl.java Fri Apr 13 10:49:17 2018 +0100 @@ -29,6 +29,7 @@ import javax.net.ssl.SSLParameters; import java.io.IOException; import java.lang.System.Logger.Level; +import java.lang.ref.Reference; import java.lang.ref.WeakReference; import java.net.Authenticator; import java.net.CookieHandler; @@ -72,6 +73,8 @@ import jdk.internal.net.http.common.Log; import jdk.internal.net.http.common.Pair; import jdk.internal.net.http.common.Utils; +import jdk.internal.net.http.common.OperationTrackers.Trackable; +import jdk.internal.net.http.common.OperationTrackers.Tracker; import jdk.internal.net.http.websocket.BuilderImpl; import jdk.internal.misc.InnocuousThread; @@ -80,7 +83,7 @@ * the selector manager thread which allows async events to be registered * and delivered when they occur. See AsyncEvent. */ -class HttpClientImpl extends HttpClient { +final class HttpClientImpl extends HttpClient implements Trackable { static final boolean DEBUG = Utils.DEBUG; // Revisit: temporary dev flag. static final boolean DEBUGELAPSED = Utils.TESTING || DEBUG; // Revisit: temporary dev flag. @@ -177,6 +180,7 @@ private final AtomicLong pendingOperationCount = new AtomicLong(); private final AtomicLong pendingWebSocketCount = new AtomicLong(); private final AtomicLong pendingHttpRequestCount = new AtomicLong(); + private final AtomicLong pendingHttp2StreamCount = new AtomicLong(); /** A Set of, deadline first, ordered timeout events. */ private final TreeSet timeouts; @@ -310,11 +314,35 @@ final long unreference() { final long count = pendingOperationCount.decrementAndGet(); final long httpCount = pendingHttpRequestCount.decrementAndGet(); + final long http2Count = pendingHttp2StreamCount.get(); final long webSocketCount = pendingWebSocketCount.get(); if (count == 0 && facade() == null) { selmgr.wakeupSelector(); } - assert httpCount >= 0 : "count of HTTP operations < 0"; + assert httpCount >= 0 : "count of HTTP/1.1 operations < 0"; + assert http2Count >= 0 : "count of HTTP/2 operations < 0"; + assert webSocketCount >= 0 : "count of WS operations < 0"; + assert count >= 0 : "count of pending operations < 0"; + return count; + } + + // Increments the pendingOperationCount. + final long streamReference() { + pendingHttp2StreamCount.incrementAndGet(); + return pendingOperationCount.incrementAndGet(); + } + + // Decrements the pendingOperationCount. + final long streamUnreference() { + final long count = pendingOperationCount.decrementAndGet(); + final long http2Count = pendingHttp2StreamCount.decrementAndGet(); + final long httpCount = pendingHttpRequestCount.get(); + final long webSocketCount = pendingWebSocketCount.get(); + if (count == 0 && facade() == null) { + selmgr.wakeupSelector(); + } + assert httpCount >= 0 : "count of HTTP/1.1 operations < 0"; + assert http2Count >= 0 : "count of HTTP/2 operations < 0"; assert webSocketCount >= 0 : "count of WS operations < 0"; assert count >= 0 : "count of pending operations < 0"; return count; @@ -331,10 +359,12 @@ final long count = pendingOperationCount.decrementAndGet(); final long webSocketCount = pendingWebSocketCount.decrementAndGet(); final long httpCount = pendingHttpRequestCount.get(); + final long http2Count = pendingHttp2StreamCount.get(); if (count == 0 && facade() == null) { selmgr.wakeupSelector(); } - assert httpCount >= 0 : "count of HTTP operations < 0"; + assert httpCount >= 0 : "count of HTTP/1.1 operations < 0"; + assert http2Count >= 0 : "count of HTTP/2 operations < 0"; assert webSocketCount >= 0 : "count of WS operations < 0"; assert count >= 0 : "count of pending operations < 0"; return count; @@ -345,6 +375,59 @@ return pendingOperationCount.get(); } + final static class HttpClientTracker implements Tracker { + final AtomicLong httpCount; + final AtomicLong http2Count; + final AtomicLong websocketCount; + final AtomicLong operationsCount; + final Reference reference; + final String name; + HttpClientTracker(AtomicLong http, + AtomicLong http2, + AtomicLong ws, + AtomicLong ops, + Reference ref, + String name) { + this.httpCount = http; + this.http2Count = http2; + this.websocketCount = ws; + this.operationsCount = ops; + this.reference = ref; + this.name = name; + } + @Override + public long getOutstandingOperations() { + return operationsCount.get(); + } + @Override + public long getOutstandingHttpOperations() { + return httpCount.get(); + } + @Override + public long getOutstandingHttp2Streams() { return http2Count.get(); } + @Override + public long getOutstandingWebSocketOperations() { + return websocketCount.get(); + } + @Override + public boolean isFacadeReferenced() { + return reference.get() != null; + } + @Override + public String getName() { + return name; + } + } + + public Tracker getOperationsTracker() { + return new HttpClientTracker(pendingHttpRequestCount, + pendingHttp2StreamCount, + pendingWebSocketCount, + pendingOperationCount, + facadeRef, + dbgTag); + } + // Called by the SelectorManager thread to figure out whether it's time // to terminate. final boolean isReferenced() { diff -r 56c32f8ea406 -r ba64c30666cc src/java.net.http/share/classes/jdk/internal/net/http/PlainHttpConnection.java --- a/src/java.net.http/share/classes/jdk/internal/net/http/PlainHttpConnection.java Wed Apr 11 15:21:25 2018 +0100 +++ b/src/java.net.http/share/classes/jdk/internal/net/http/PlainHttpConnection.java Fri Apr 13 10:49:17 2018 +0100 @@ -159,6 +159,9 @@ private boolean trySetReceiveBufferSize(int bufsize) { try { chan.setOption(StandardSocketOptions.SO_RCVBUF, bufsize); + debug.log(Level.DEBUG, + "Receive buffer size is %s", + chan.getOption(StandardSocketOptions.SO_RCVBUF)); return true; } catch(IOException x) { debug.log(Level.DEBUG, diff -r 56c32f8ea406 -r ba64c30666cc src/java.net.http/share/classes/jdk/internal/net/http/RawChannelTube.java --- a/src/java.net.http/share/classes/jdk/internal/net/http/RawChannelTube.java Wed Apr 11 15:21:25 2018 +0100 +++ b/src/java.net.http/share/classes/jdk/internal/net/http/RawChannelTube.java Fri Apr 13 10:49:17 2018 +0100 @@ -74,7 +74,7 @@ this.readSubscriber = new ReadSubscriber(); dbgTag = "[WebSocket] RawChannelTube(" + tube.toString() +")"; debug = Utils.getWebSocketLogger(dbgTag::toString, Utils.DEBUG_WS); - connection.client().reference(); + connection.client().webSocketOpen(); connectFlows(); if (Utils.ASSERTIONSENABLED && Utils.DEBUG_WS) { // this is just for debug... @@ -416,7 +416,7 @@ public void close() { if (closed.compareAndSet(false, true)) { debug.log(Level.DEBUG, "close"); - connection.client().unreference(); + connection.client().webSocketClose(); connection.close(); } } diff -r 56c32f8ea406 -r ba64c30666cc src/java.net.http/share/classes/jdk/internal/net/http/ResponseContent.java --- a/src/java.net.http/share/classes/jdk/internal/net/http/ResponseContent.java Wed Apr 11 15:21:25 2018 +0100 +++ b/src/java.net.http/share/classes/jdk/internal/net/http/ResponseContent.java Fri Apr 13 10:49:17 2018 +0100 @@ -165,12 +165,14 @@ boolean hasDemand = sub.demand().tryDecrement(); assert hasDemand; pusher.onNext(Collections.unmodifiableList(out)); + debug.log(Level.DEBUG, "Chunks sent"); } - debug.log(Level.DEBUG, () -> "done!"); + debug.log(Level.DEBUG, "done!"); assert closedExceptionally == null; assert state == ChunkState.DONE; onFinished.run(); pusher.onComplete(); + debug.log(Level.DEBUG, "subscriber completed"); completed = true; onComplete.accept(closedExceptionally); // should be null break; @@ -187,9 +189,12 @@ boolean hasDemand = sub.demand().tryDecrement(); assert hasDemand; pusher.onNext(Collections.unmodifiableList(out)); + debug.log(Level.DEBUG, "Chunk sent"); } assert state == ChunkState.DONE || !b.hasRemaining(); } catch(Throwable t) { + debug.log(Level.DEBUG, + "Error while processing buffer: %s", (Object)t ); closedExceptionally = t; if (!completed) onComplete.accept(t); } @@ -356,7 +361,6 @@ debug.log(Level.DEBUG, "Sending chunk to consumer (%d)", b1.remaining()); out.add(b1); - debug.log(Level.DEBUG, "Chunk sent."); } return false; // we haven't parsed the final chunk yet. } else { diff -r 56c32f8ea406 -r ba64c30666cc src/java.net.http/share/classes/jdk/internal/net/http/SocketTube.java --- a/src/java.net.http/share/classes/jdk/internal/net/http/SocketTube.java Wed Apr 11 15:21:25 2018 +0100 +++ b/src/java.net.http/share/classes/jdk/internal/net/http/SocketTube.java Fri Apr 13 10:49:17 2018 +0100 @@ -679,8 +679,7 @@ * to not require it to be as such. It's a responsibility of the * subscriber to signal demand in a thread-safe manner. * - * https://github.com/reactive-streams/reactive-streams-jvm/blob/dd24d2ab164d7de6c316f6d15546f957bec29eaa/README.md - * (rules 2.7 and 3.4) + * See Reactive Streams specification, rules 2.7 and 3.4. */ @Override public final void request(long n) { @@ -754,8 +753,15 @@ // the selector thread, and that is OK, because we // will just call onError and return. ReadSubscription current = subscription; + Throwable error = errorRef.get(); + if (current == null) { + assert error != null; + debug.log(Level.DEBUG, + "error raised before subscriber subscribed: %s", + (Object)error); + return; + } TubeSubscriber subscriber = current.subscriber; - Throwable error = errorRef.get(); if (error != null) { completed = true; // safe to pause here because we're finished anyway. diff -r 56c32f8ea406 -r ba64c30666cc src/java.net.http/share/classes/jdk/internal/net/http/Stream.java --- a/src/java.net.http/share/classes/jdk/internal/net/http/Stream.java Wed Apr 11 15:21:25 2018 +0100 +++ b/src/java.net.http/share/classes/jdk/internal/net/http/Stream.java Fri Apr 13 10:49:17 2018 +0100 @@ -770,6 +770,7 @@ if (requestBodyCF.isDone()) return; subscription.cancel(); requestBodyCF.completeExceptionally(t); + cancelImpl(t); return; } @@ -825,6 +826,11 @@ sendScheduler.stop(); subscription.cancel(); requestBodyCF.completeExceptionally(ex); + // need to cancel the stream to 1. tell the server + // we don't want to receive any more data and + // 2. ensure that the operation ref count will be + // decremented on the HttpClient. + cancelImpl(ex); } } @@ -983,13 +989,18 @@ CompletableFuture sendBodyImpl() { requestBodyCF.whenComplete((v, t) -> requestSent()); - if (requestPublisher != null) { - final RequestSubscriber subscriber = new RequestSubscriber(requestContentLen); - requestPublisher.subscribe(requestSubscriber = subscriber); - } else { - // there is no request body, therefore the request is complete, - // END_STREAM has already sent with outgoing headers - requestBodyCF.complete(null); + try { + if (requestPublisher != null) { + final RequestSubscriber subscriber = new RequestSubscriber(requestContentLen); + requestPublisher.subscribe(requestSubscriber = subscriber); + } else { + // there is no request body, therefore the request is complete, + // END_STREAM has already sent with outgoing headers + requestBodyCF.complete(null); + } + } catch (Throwable t) { + cancelImpl(t); + requestBodyCF.completeExceptionally(t); } return requestBodyCF; } diff -r 56c32f8ea406 -r ba64c30666cc src/java.net.http/share/classes/jdk/internal/net/http/WindowController.java --- a/src/java.net.http/share/classes/jdk/internal/net/http/WindowController.java Wed Apr 11 15:21:25 2018 +0100 +++ b/src/java.net.http/share/classes/jdk/internal/net/http/WindowController.java Fri Apr 13 10:49:17 2018 +0100 @@ -239,25 +239,30 @@ controllerLock.lock(); try { Integer size = streams.get(streamid); - if (size == null) - throw new InternalError("Expected entry for streamid: " + streamid); - size += amount; - if (size < 0) - return false; - streams.put(streamid, size); - DEBUG_LOGGER.log(Level.DEBUG, - "Stream %s window size is now %s (amount added %d)", - streamid, size, amount); + if (size == null) { + // The stream may have been cancelled. + DEBUG_LOGGER.log(Level.DEBUG, + "WARNING: No entry found for streamid: %s. May be cancelled?", + streamid); + } else { + size += amount; + if (size < 0) + return false; + streams.put(streamid, size); + DEBUG_LOGGER.log(Level.DEBUG, + "Stream %s window size is now %s (amount added %d)", + streamid, size, amount); - Map.Entry,Integer> p = pending.get(streamid); - if (p != null) { - int minAmount = 1; - // only wakes up the pending stream if there is at least - // 1 byte of space in both windows - if (size >= minAmount - && connectionWindowSize >= minAmount) { - pending.remove(streamid); - s = p.getKey(); + Map.Entry, Integer> p = pending.get(streamid); + if (p != null) { + int minAmount = 1; + // only wakes up the pending stream if there is at least + // 1 byte of space in both windows + if (size >= minAmount + && connectionWindowSize >= minAmount) { + pending.remove(streamid); + s = p.getKey(); + } } } } finally { diff -r 56c32f8ea406 -r ba64c30666cc src/java.net.http/share/classes/jdk/internal/net/http/common/OperationTrackers.java --- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/src/java.net.http/share/classes/jdk/internal/net/http/common/OperationTrackers.java Fri Apr 13 10:49:17 2018 +0100 @@ -0,0 +1,85 @@ +/* + * Copyright (c) 2018, 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. Oracle designates this + * particular file as subject to the "Classpath" exception as provided + * by Oracle in the LICENSE file that accompanied this code. + * + * 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. + */ +package jdk.internal.net.http.common; + +import java.net.http.HttpClient; + +/** + * A small class allowing to track how many operations are + * left outstanding on an instance of HttpClient. + */ +public final class OperationTrackers { + private OperationTrackers() { + throw new InternalError("not instantiable"); + } + + /** + * A tracker can return the current value of + * operation counters maintained by an instance + * of {@link Trackable}, such as an HttpClientImpl. + */ + public interface Tracker { + // The total number of outstanding operations + long getOutstandingOperations(); + // The number of outstanding HTTP/1.1 operations. + // A single HTTP/1.1 request may increment this counter + // multiple times, so the value returned will be >= to + // the number of active HTTP/1.1 connections, but will + // still be 0 if there are no active connections. + long getOutstandingHttpOperations(); + // The number of active HTTP/2 streams + long getOutstandingHttp2Streams(); + // The number of active WebSockets + long getOutstandingWebSocketOperations(); + // Whether the facade returned to the + // user is still referenced + boolean isFacadeReferenced(); + // The name of the object being tracked. + String getName(); + } + + /** + * Implemented by objects that maintain operation counters. + */ + public interface Trackable { + Tracker getOperationsTracker(); + } + + /** + * Returns a tracker to track pending operations started on + * an HttpClient instance. May return null if this isn't + * an HttpClientImpl or HttpClientFacade. + * @param client the HttpClient instance to track. + * @return A tracker or null. + */ + public static Tracker getTracker(HttpClient client) { + if (client instanceof Trackable) { + return ((Trackable)client).getOperationsTracker(); + } else { + return null; + } + } + +} diff -r 56c32f8ea406 -r ba64c30666cc test/jdk/java/net/httpclient/DigestEchoClient.java --- a/test/jdk/java/net/httpclient/DigestEchoClient.java Wed Apr 11 15:21:25 2018 +0100 +++ b/test/jdk/java/net/httpclient/DigestEchoClient.java Fri Apr 13 10:49:17 2018 +0100 @@ -63,7 +63,8 @@ * headers directly when connecting with a server. * @bug 8087112 * @library /lib/testlibrary http2/server - * @build jdk.testlibrary.SimpleSSLContext HttpServerAdapters DigestEchoServer DigestEchoClient + * @build jdk.testlibrary.SimpleSSLContext HttpServerAdapters DigestEchoServer + * ReferenceTracker DigestEchoClient * @modules java.net.http/jdk.internal.net.http.common * java.net.http/jdk.internal.net.http.frame * java.net.http/jdk.internal.net.http.hpack @@ -188,6 +189,7 @@ } static final AtomicLong clientCount = new AtomicLong(); + static final ReferenceTracker TRACKER = ReferenceTracker.INSTANCE; public HttpClient newHttpClient(DigestEchoServer server) { clientCount.incrementAndGet(); HttpClient.Builder builder = HttpClient.newBuilder(); @@ -219,7 +221,7 @@ default: break; } - return builder.build(); + return TRACKER.track(builder.build()); } public static List serverVersions(Version clientVersion) { @@ -248,6 +250,7 @@ boolean useSSL = false; EnumSet types = EnumSet.complementOf(EnumSet.of(DigestEchoServer.HttpAuthType.PROXY305)); + Throwable failed = null; if (args != null && args.length >= 1) { useSSL = "SSL".equals(args[0]); if (args.length > 1) { @@ -302,10 +305,14 @@ } } } catch(Throwable t) { - System.out.println("Unexpected exception: exiting: " + t); + out.println(DigestEchoServer.now() + + ": Unexpected exception: " + t); t.printStackTrace(); + failed = t; throw t; } finally { + Thread.sleep(100); + AssertionError trackFailed = TRACKER.check(500); EchoServers.stop(); System.out.println(" ---------------------------------------------------------- "); System.out.println(String.format("DigestEchoClient %s %s", useSSL ? "SSL" : "CLEAR", types)); @@ -316,6 +323,14 @@ System.out.println(String.format("digests: %d requests sent, %d ns / req", digestCount.get(), digests.get())); System.out.println(" ---------------------------------------------------------- "); + if (trackFailed != null) { + if (failed != null) { + failed.addSuppressed(trackFailed); + if (failed instanceof Error) throw (Error) failed; + if (failed instanceof Exception) throw (Exception) failed; + } + throw trackFailed; + } } } @@ -434,6 +449,8 @@ assert t.getCause() != null; t = t.getCause(); } + out.println(DigestEchoServer.now() + + ": Unexpected exception: " + t); throw new RuntimeException("Unexpected exception: " + t, t); } diff -r 56c32f8ea406 -r ba64c30666cc test/jdk/java/net/httpclient/DigestEchoClientSSL.java --- a/test/jdk/java/net/httpclient/DigestEchoClientSSL.java Wed Apr 11 15:21:25 2018 +0100 +++ b/test/jdk/java/net/httpclient/DigestEchoClientSSL.java Fri Apr 13 10:49:17 2018 +0100 @@ -27,7 +27,8 @@ * @summary this test verifies that a client may provides authorization * headers directly when connecting with a server over SSL. * @library /lib/testlibrary http2/server - * @build jdk.testlibrary.SimpleSSLContext DigestEchoServer DigestEchoClient DigestEchoClientSSL + * @build jdk.testlibrary.SimpleSSLContext DigestEchoServer + * DigestEchoClient ReferenceTracker DigestEchoClientSSL * @modules java.net.http/jdk.internal.net.http.common * java.net.http/jdk.internal.net.http.frame * java.net.http/jdk.internal.net.http.hpack diff -r 56c32f8ea406 -r ba64c30666cc test/jdk/java/net/httpclient/ProxyAuthDisabledSchemes.java --- a/test/jdk/java/net/httpclient/ProxyAuthDisabledSchemes.java Wed Apr 11 15:21:25 2018 +0100 +++ b/test/jdk/java/net/httpclient/ProxyAuthDisabledSchemes.java Fri Apr 13 10:49:17 2018 +0100 @@ -30,7 +30,7 @@ * @bug 8087112 * @library /lib/testlibrary http2/server * @build jdk.testlibrary.SimpleSSLContext DigestEchoServer DigestEchoClient - * ProxyAuthDisabledSchemes + * ReferenceTracker ProxyAuthDisabledSchemes * @modules java.net.http/jdk.internal.net.http.common * java.net.http/jdk.internal.net.http.frame * java.net.http/jdk.internal.net.http.hpack diff -r 56c32f8ea406 -r ba64c30666cc test/jdk/java/net/httpclient/ProxyAuthDisabledSchemesSSL.java --- a/test/jdk/java/net/httpclient/ProxyAuthDisabledSchemesSSL.java Wed Apr 11 15:21:25 2018 +0100 +++ b/test/jdk/java/net/httpclient/ProxyAuthDisabledSchemesSSL.java Fri Apr 13 10:49:17 2018 +0100 @@ -30,7 +30,7 @@ * net properties. * @library /lib/testlibrary http2/server * @build jdk.testlibrary.SimpleSSLContext DigestEchoServer DigestEchoClient - * ProxyAuthDisabledSchemesSSL + * ReferenceTracker ProxyAuthDisabledSchemesSSL * @modules java.net.http/jdk.internal.net.http.common * java.net.http/jdk.internal.net.http.frame * java.net.http/jdk.internal.net.http.hpack diff -r 56c32f8ea406 -r ba64c30666cc test/jdk/java/net/httpclient/ReferenceTracker.java --- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/test/jdk/java/net/httpclient/ReferenceTracker.java Fri Apr 13 10:49:17 2018 +0100 @@ -0,0 +1,130 @@ +/* + * Copyright (c) 2018, 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 jdk.internal.net.http.common.OperationTrackers; +import jdk.internal.net.http.common.OperationTrackers.Tracker; + +import java.net.http.HttpClient; +import java.util.concurrent.ConcurrentLinkedQueue; +import java.util.stream.Collectors; + +/** + * A small helper class to help track clients which still + * have pending operations at the end of a test. + */ +public class ReferenceTracker { + private final ConcurrentLinkedQueue TRACKERS + = new ConcurrentLinkedQueue(); + + public static final ReferenceTracker INSTANCE + = new ReferenceTracker(); + + public HttpClient track(HttpClient client) { + Tracker tracker = OperationTrackers.getTracker(client); + assert tracker != null; + TRACKERS.add(tracker); + return client; + } + + public long getTrackedClientCount() { + return TRACKERS.size(); + } + + public StringBuilder diagnose(StringBuilder warnings) { + for (Tracker tracker : TRACKERS) { + checkOutstandingOperations(warnings, tracker); + } + return warnings; + } + + public boolean hasOutstandingOperations() { + return TRACKERS.stream().anyMatch(t -> t.getOutstandingOperations() > 0); + } + + public long getOutstandingOperationsCount() { + return TRACKERS.stream() + .map(Tracker::getOutstandingOperations) + .filter(n -> n > 0) + .collect(Collectors.summingLong(n -> n)); + } + + public long getOutstandingClientCount() { + return TRACKERS.stream() + .map(Tracker::getOutstandingOperations) + .filter(n -> n > 0) + .count(); + } + + public AssertionError check(long graceDelayMs) { + AssertionError fail = null; + if (hasOutstandingOperations()) { + try { + Thread.sleep(graceDelayMs); + } catch (InterruptedException x) { + // OK + } + StringBuilder warnings = diagnose(new StringBuilder()); + addSummary(warnings); + if (hasOutstandingOperations()) { + fail = new AssertionError(warnings.toString()); + } + } else { + System.out.println("PASSED: No outstanding operations found in " + + getTrackedClientCount() + " clients"); + } + return fail; + } + + private void addSummary(StringBuilder warning) { + long activeClients = getOutstandingClientCount(); + long operations = getOutstandingOperationsCount(); + long tracked = getTrackedClientCount(); + if (warning.length() > 0) warning.append("\n"); + int pos = warning.length(); + warning.append("Found ") + .append(activeClients) + .append(" client still active, with ") + .append(operations) + .append(" operations still pending out of ") + .append(tracked) + .append(" tracked clients."); + System.out.println(warning.toString().substring(pos)); + System.err.println(warning.toString().substring(pos)); + } + + private static void checkOutstandingOperations(StringBuilder warning, Tracker tracker) { + if (tracker.getOutstandingOperations() > 0) { + if (warning.length() > 0) warning.append("\n"); + int pos = warning.length(); + warning.append("WARNING: tracker for " + tracker.getName() + " has outstanding operations:"); + warning.append("\n\tPending HTTP/1.1 operations: " + tracker.getOutstandingHttpOperations()); + warning.append("\n\tPending HTTP/2 streams: " + tracker.getOutstandingHttp2Streams()); + warning.append("\n\tPending WebSocket operations: " + tracker.getOutstandingWebSocketOperations()); + warning.append("\n\tTotal pending operations: " + tracker.getOutstandingOperations()); + warning.append("\n\tFacade referenced: " + tracker.isFacadeReferenced()); + System.out.println(warning.toString().substring(pos)); + System.err.println(warning.toString().substring(pos)); + } + } + +} diff -r 56c32f8ea406 -r ba64c30666cc test/jdk/java/net/httpclient/ResponsePublisher.java --- a/test/jdk/java/net/httpclient/ResponsePublisher.java Wed Apr 11 15:21:25 2018 +0100 +++ b/test/jdk/java/net/httpclient/ResponsePublisher.java Fri Apr 13 10:49:17 2018 +0100 @@ -169,11 +169,12 @@ }; } + final ReferenceTracker TRACKER = ReferenceTracker.INSTANCE; HttpClient newHttpClient() { - return HttpClient.newBuilder() + return TRACKER.track(HttpClient.newBuilder() .executor(executor) .sslContext(sslContext) - .build(); + .build()); } @Test(dataProvider = "variants") @@ -438,10 +439,18 @@ @AfterTest public void teardown() throws Exception { - httpTestServer.stop(); - httpsTestServer.stop(); - http2TestServer.stop(); - https2TestServer.stop(); + Thread.sleep(100); + AssertionError fail = TRACKER.check(500); + try { + httpTestServer.stop(); + httpsTestServer.stop(); + http2TestServer.stop(); + https2TestServer.stop(); + } finally { + if (fail != null) { + throw fail; + } + } } static final String WITH_BODY = "Lorem ipsum dolor sit amet, consectetur" + diff -r 56c32f8ea406 -r ba64c30666cc test/jdk/java/net/httpclient/RetryWithCookie.java --- a/test/jdk/java/net/httpclient/RetryWithCookie.java Wed Apr 11 15:21:25 2018 +0100 +++ b/test/jdk/java/net/httpclient/RetryWithCookie.java Fri Apr 13 10:49:17 2018 +0100 @@ -33,7 +33,7 @@ * jdk.httpserver * @library /lib/testlibrary /test/lib http2/server * @build Http2TestServer - * @build jdk.testlibrary.SimpleSSLContext + * @build jdk.testlibrary.SimpleSSLContext ReferenceTracker * @run testng/othervm * -Djdk.httpclient.HttpClient.log=trace,headers,requests * RetryWithCookie @@ -99,6 +99,7 @@ } static final AtomicLong requestCounter = new AtomicLong(); + final ReferenceTracker TRACKER = ReferenceTracker.INSTANCE; @Test(dataProvider = "positive") void test(String uriString) throws Exception { @@ -109,6 +110,7 @@ .cookieHandler(cookieManager) .sslContext(sslContext) .build(); + TRACKER.track(client); assert client.cookieHandler().isPresent(); URI uri = URI.create(uriString); @@ -173,10 +175,16 @@ @AfterTest public void teardown() throws Exception { - httpTestServer.stop(); - httpsTestServer.stop(); - http2TestServer.stop(); - https2TestServer.stop(); + Thread.sleep(100); + AssertionError fail = TRACKER.check(500); + try { + httpTestServer.stop(); + httpsTestServer.stop(); + http2TestServer.stop(); + https2TestServer.stop(); + } finally { + if (fail != null) throw fail; + } } static class CookieRetryHandler implements HttpTestHandler { diff -r 56c32f8ea406 -r ba64c30666cc test/jdk/java/net/httpclient/SmallTimeout.java --- a/test/jdk/java/net/httpclient/SmallTimeout.java Wed Apr 11 15:21:25 2018 +0100 +++ b/test/jdk/java/net/httpclient/SmallTimeout.java Fri Apr 13 10:49:17 2018 +0100 @@ -21,7 +21,6 @@ * questions. */ -import java.io.IOException; import java.net.InetAddress; import java.net.InetSocketAddress; import java.net.ServerSocket; @@ -41,6 +40,7 @@ /** * @test * @bug 8178147 + * @modules java.net.http/jdk.internal.net.http.common * @summary Ensures that small timeouts do not cause hangs due to race conditions * @run main/othervm -Djdk.internal.httpclient.debug=true SmallTimeout */ @@ -78,7 +78,9 @@ public static void main(String[] args) throws Exception { HttpClient client = HttpClient.newHttpClient(); + ReferenceTracker.INSTANCE.track(client); + Throwable failed = null; try (ServerSocket ss = new ServerSocket()) { ss.setReuseAddress(false); ss.bind(new InetSocketAddress(InetAddress.getLoopbackAddress(), 0)); @@ -168,6 +170,24 @@ if (error) throw new RuntimeException("Failed. Check output"); + } catch (Throwable t) { + failed = t; + throw t; + } finally { + try { + Thread.sleep(100); + } catch (InterruptedException t) { + // ignore; + } + AssertionError trackFailed = ReferenceTracker.INSTANCE.check(500); + if (trackFailed != null) { + if (failed != null) { + failed.addSuppressed(trackFailed); + if (failed instanceof Exception) throw (Exception) failed; + if (failed instanceof Error) throw (Exception) failed; + } + throw trackFailed; + } } } diff -r 56c32f8ea406 -r ba64c30666cc test/jdk/java/net/httpclient/ThrowingPublishers.java --- a/test/jdk/java/net/httpclient/ThrowingPublishers.java Wed Apr 11 15:21:25 2018 +0100 +++ b/test/jdk/java/net/httpclient/ThrowingPublishers.java Fri Apr 13 10:49:17 2018 +0100 @@ -26,12 +26,15 @@ * @summary Tests what happens when request publishers * throw unexpected exceptions. * @library /lib/testlibrary http2/server - * @build jdk.testlibrary.SimpleSSLContext HttpServerAdapters ThrowingPublishers + * @build jdk.testlibrary.SimpleSSLContext HttpServerAdapters + * ReferenceTracker ThrowingPublishers * @modules java.base/sun.net.www.http * java.net.http/jdk.internal.net.http.common * java.net.http/jdk.internal.net.http.frame * java.net.http/jdk.internal.net.http.hpack - * @run testng/othervm -Djdk.internal.httpclient.debug=true ThrowingPublishers + * @run testng/othervm -Djdk.internal.httpclient.debug=true + * -Djdk.httpclient.enableAllMethodRetry=true + * ThrowingPublishers */ import com.sun.net.httpserver.HttpServer; @@ -45,10 +48,8 @@ import org.testng.annotations.Test; import javax.net.ssl.SSLContext; -import java.io.BufferedReader; import java.io.IOException; import java.io.InputStream; -import java.io.InputStreamReader; import java.io.OutputStream; import java.io.UncheckedIOException; import java.net.InetAddress; @@ -63,7 +64,9 @@ import java.net.http.HttpResponse.BodyHandlers; import java.nio.ByteBuffer; import java.nio.charset.StandardCharsets; +import java.util.EnumSet; import java.util.List; +import java.util.Set; import java.util.concurrent.CompletableFuture; import java.util.concurrent.CompletionException; import java.util.concurrent.ConcurrentHashMap; @@ -118,6 +121,7 @@ return String.format("[%d s, %d ms, %d ns] ", secs, mill, nan); } + final ReferenceTracker TRACKER = ReferenceTracker.INSTANCE; private volatile HttpClient sharedClient; static class TestExecutor implements Executor { @@ -186,7 +190,7 @@ for (boolean sameClient : List.of(false, true)) { //if (!sameClient) continue; for (String uri: uris()) { - result[i++] = new Object[] {uri, sameClient}; + result[i++] = new Object[] {uri + "/noThrows", sameClient}; } } assert i == uris.length * 2; @@ -218,10 +222,10 @@ private HttpClient makeNewClient() { clientCount.incrementAndGet(); - return HttpClient.newBuilder() + return TRACKER.track(HttpClient.newBuilder() .executor(executor) .sslContext(sslContext) - .build(); + .build()); } HttpClient newHttpClient(boolean share) { @@ -312,7 +316,7 @@ throws Exception { HttpClient client = null; - for (Where where : Where.values()) { + for (Where where : whereValues()) { //if (where == Where.ON_SUBSCRIBE) continue; //if (where == Where.ON_ERROR) continue; if (!sameClient || client == null) @@ -366,6 +370,13 @@ } } + // can be used to reduce the surface of the test when diagnosing + // some failure + Set whereValues() { + //return EnumSet.of(Where.BEFORE_CANCEL, Where.AFTER_CANCEL); + return EnumSet.allOf(Where.class); + } + interface Thrower extends Consumer, BiPredicate { } @@ -620,11 +631,24 @@ @AfterTest public void teardown() throws Exception { + String sharedClientName = + sharedClient == null ? null : sharedClient.toString(); sharedClient = null; - httpTestServer.stop(); - httpsTestServer.stop(); - http2TestServer.stop(); - https2TestServer.stop(); + Thread.sleep(100); + AssertionError fail = TRACKER.check(500); + try { + httpTestServer.stop(); + httpsTestServer.stop(); + http2TestServer.stop(); + https2TestServer.stop(); + } finally { + if (fail != null) { + if (sharedClientName != null) { + System.err.println("Shared client name is: " + sharedClientName); + } + throw fail; + } + } } static class HTTP_FixedLengthHandler implements HttpTestHandler { diff -r 56c32f8ea406 -r ba64c30666cc test/jdk/java/net/httpclient/ThrowingPushPromises.java --- a/test/jdk/java/net/httpclient/ThrowingPushPromises.java Wed Apr 11 15:21:25 2018 +0100 +++ b/test/jdk/java/net/httpclient/ThrowingPushPromises.java Fri Apr 13 10:49:17 2018 +0100 @@ -26,7 +26,8 @@ * @summary Tests what happens when push promise handlers and their * response body handlers and subscribers throw unexpected exceptions. * @library /lib/testlibrary http2/server - * @build jdk.testlibrary.SimpleSSLContext HttpServerAdapters ThrowingPushPromises + * @build jdk.testlibrary.SimpleSSLContext HttpServerAdapters + * ReferenceTracker ThrowingPushPromises * @modules java.base/sun.net.www.http * java.net.http/jdk.internal.net.http.common * java.net.http/jdk.internal.net.http.frame @@ -52,7 +53,6 @@ import java.net.URI; import java.net.URISyntaxException; import java.net.http.HttpClient; -import java.net.http.HttpHeaders; import java.net.http.HttpRequest; import java.net.http.HttpResponse; import java.net.http.HttpResponse.BodyHandler; @@ -112,6 +112,7 @@ return String.format("[%d s, %d ms, %d ns] ", secs, mill, nan); } + final ReferenceTracker TRACKER = ReferenceTracker.INSTANCE; private volatile HttpClient sharedClient; static class TestExecutor implements Executor { @@ -203,10 +204,10 @@ private HttpClient makeNewClient() { clientCount.incrementAndGet(); - return HttpClient.newBuilder() + return TRACKER.track(HttpClient.newBuilder() .executor(executor) .sslContext(sslContext) - .build(); + .build()); } HttpClient newHttpClient(boolean share) { @@ -659,9 +660,22 @@ @AfterTest public void teardown() throws Exception { + String sharedClientName = + sharedClient == null ? null : sharedClient.toString(); sharedClient = null; - http2TestServer.stop(); - https2TestServer.stop(); + Thread.sleep(100); + AssertionError fail = TRACKER.check(500); + try { + http2TestServer.stop(); + https2TestServer.stop(); + } finally { + if (fail != null) { + if (sharedClientName != null) { + System.err.println("Shared client name is: " + sharedClientName); + } + throw fail; + } + } } private static void pushPromiseFor(HttpTestExchange t, URI requestURI, String pushPath, boolean fixed) diff -r 56c32f8ea406 -r ba64c30666cc test/jdk/java/net/httpclient/ThrowingSubscribers.java --- a/test/jdk/java/net/httpclient/ThrowingSubscribers.java Wed Apr 11 15:21:25 2018 +0100 +++ b/test/jdk/java/net/httpclient/ThrowingSubscribers.java Fri Apr 13 10:49:17 2018 +0100 @@ -26,7 +26,8 @@ * @summary Tests what happens when response body handlers and subscribers * throw unexpected exceptions. * @library /lib/testlibrary http2/server - * @build jdk.testlibrary.SimpleSSLContext HttpServerAdapters ThrowingSubscribers + * @build jdk.testlibrary.SimpleSSLContext HttpServerAdapters + * ReferenceTracker ThrowingSubscribers * @modules java.base/sun.net.www.http * java.net.http/jdk.internal.net.http.common * java.net.http/jdk.internal.net.http.frame @@ -117,6 +118,7 @@ return String.format("[%d s, %d ms, %d ns] ", secs, mill, nan); } + final ReferenceTracker TRACKER = ReferenceTracker.INSTANCE; private volatile HttpClient sharedClient; static class TestExecutor implements Executor { @@ -211,10 +213,11 @@ private HttpClient makeNewClient() { clientCount.incrementAndGet(); - return HttpClient.newBuilder() + HttpClient client = HttpClient.newBuilder() .executor(executor) .sslContext(sslContext) .build(); + return TRACKER.track(client); } HttpClient newHttpClient(boolean share) { @@ -677,11 +680,24 @@ @AfterTest public void teardown() throws Exception { + String sharedClientName = + sharedClient == null ? null : sharedClient.toString(); sharedClient = null; - httpTestServer.stop(); - httpsTestServer.stop(); - http2TestServer.stop(); - https2TestServer.stop(); + Thread.sleep(100); + AssertionError fail = TRACKER.check(500); + try { + httpTestServer.stop(); + httpsTestServer.stop(); + http2TestServer.stop(); + https2TestServer.stop(); + } finally { + if (fail != null) { + if (sharedClientName != null) { + System.err.println("Shared client name is: " + sharedClientName); + } + throw fail; + } + } } static class HTTP_FixedLengthHandler implements HttpTestHandler {