/*
* Copyright (c) 2018, 2023, 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.io.PrintStream;
import java.lang.management.LockInfo;
import java.lang.management.ManagementFactory;
import java.lang.management.MonitorInfo;
import java.lang.management.ThreadInfo;
import java.net.http.HttpClient;
import java.time.Duration;
import java.util.Arrays;
import java.util.Objects;
import java.util.concurrent.ConcurrentLinkedQueue;
import java.util.function.Predicate;
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<Tracker> TRACKERS
= new ConcurrentLinkedQueue<Tracker>();
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) {
return diagnose(warnings, (t) -> t.getOutstandingHttpOperations() > 0);
}
public StringBuilder diagnose(Tracker tracker) {
return diagnose(tracker, new StringBuilder(), (t) -> t.getOutstandingHttpOperations() > 0);
}
public StringBuilder diagnose(HttpClient client) {
return diagnose(getTracker(client));
}
public StringBuilder diagnose(Tracker tracker, StringBuilder warnings, Predicate<Tracker> hasOutstanding) {
checkOutstandingOperations(warnings, tracker, hasOutstanding);
return warnings;
}
public StringBuilder diagnose(StringBuilder warnings, Predicate<Tracker> hasOutstanding) {
for (Tracker tracker : TRACKERS) {
diagnose(tracker, warnings, hasOutstanding);
}
return warnings;
}
public boolean hasOutstandingOperations() {
return TRACKERS.stream().anyMatch(t -> t.getOutstandingOperations() > 0);
}
public boolean hasOutstandingSubscribers() {
return TRACKERS.stream().anyMatch(t -> t.getOutstandingSubscribers() > 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(Tracker tracker, long graceDelayMs) {
Predicate<Tracker> hasOperations = (t) -> t.getOutstandingOperations() > 0;
Predicate<Tracker> hasSubscribers = (t) -> t.getOutstandingSubscribers() > 0;
return check(tracker, graceDelayMs,
hasOperations.or(hasSubscribers)
.or(Tracker::isFacadeReferenced)
.or(Tracker::isSelectorAlive),
"outstanding operations or unreleased resources", true);
}
public AssertionError checkFinished(Tracker tracker, long graceDelayMs) {
Predicate<Tracker> hasOperations = (t) -> t.getOutstandingOperations() > 0;
Predicate<Tracker> hasSubscribers = (t) -> t.getOutstandingSubscribers() > 0;
return check(tracker, graceDelayMs,
hasOperations.or(hasSubscribers),
"outstanding operations or unreleased resources", false);
}
public AssertionError check(long graceDelayMs) {
Predicate<Tracker> hasOperations = (t) -> t.getOutstandingOperations() > 0;
Predicate<Tracker> hasSubscribers = (t) -> t.getOutstandingSubscribers() > 0;
return check(graceDelayMs,
hasOperations.or(hasSubscribers)
.or(Tracker::isFacadeReferenced)
.or(Tracker::isSelectorAlive),
"outstanding operations or unreleased resources", true);
}
// This method is copied from ThreadInfo::toString, but removes the
// limit on the stack trace depth (8 frames max) that ThreadInfo::toString
// forcefully implement. We want to print all frames for better diagnosis.
private static String toString(ThreadInfo info) {
StringBuilder sb = new StringBuilder("\"" + info.getThreadName() + "\"" +
(info.isDaemon() ? " daemon" : "") +
" prio=" + info.getPriority() +
" Id=" + info.getThreadId() + " " +
info.getThreadState());
if (info.getLockName() != null) {
sb.append(" on " + info.getLockName());
}
if (info.getLockOwnerName() != null) {
sb.append(" owned by \"" + info.getLockOwnerName() +
"\" Id=" + info.getLockOwnerId());
}
if (info.isSuspended()) {
sb.append(" (suspended)");
}
if (info.isInNative()) {
sb.append(" (in native)");
}
sb.append('\n');
int i = 0;
var stackTrace = info.getStackTrace();
for (; i < stackTrace.length ; i++) {
StackTraceElement ste = stackTrace[i];
sb.append("\tat " + ste.toString());
sb.append('\n');
if (i == 0 && info.getLockInfo() != null) {
Thread.State ts = info.getThreadState();
switch (ts) {
case BLOCKED:
sb.append("\t- blocked on " + info.getLockInfo());
sb.append('\n');
break;
case WAITING:
sb.append("\t- waiting on " + info.getLockInfo());
sb.append('\n');
break;
case TIMED_WAITING:
sb.append("\t- waiting on " + info.getLockInfo());
sb.append('\n');
break;
default:
}
}
for (MonitorInfo mi : info.getLockedMonitors()) {
if (mi.getLockedStackDepth() == i) {
sb.append("\t- locked " + mi);
sb.append('\n');
}
}
}
if (i < stackTrace.length) {
sb.append("\t...");
sb.append('\n');
}
LockInfo[] locks = info.getLockedSynchronizers();
if (locks.length > 0) {
sb.append("\n\tNumber of locked synchronizers = " + locks.length);
sb.append('\n');
for (LockInfo li : locks) {
sb.append("\t- " + li);
sb.append('\n');
}
}
sb.append('\n');
return sb.toString();
}
private void printThreads(String why, PrintStream out) {
out.println(why);
Arrays.stream(ManagementFactory.getThreadMXBean()
.dumpAllThreads(true, true))
.map(ReferenceTracker::toString)
.forEach(out::println);
}
public Tracker getTracker(HttpClient client) {
return OperationTrackers.getTracker(Objects.requireNonNull(client));
}
public AssertionError check(Tracker tracker,
long graceDelayMs,
Predicate<Tracker> hasOutstanding,
String description,
boolean printThreads) {
AssertionError fail = null;
graceDelayMs = Math.max(graceDelayMs, 100);
long delay = Math.min(graceDelayMs, 10);
var count = delay > 0 ? graceDelayMs / delay : 1;
long waitStart = System.nanoTime();
long waited = 0;
long toWait = Math.min(graceDelayMs, Math.max(delay, 1));
int i = 0;
for (i = 0; i < count; i++) {
if (hasOutstanding.test(tracker)) {
System.gc();
try {
if (i == 0) {
System.out.println("Waiting for HTTP operations to terminate...");
System.out.println("\tgracedelay: " + graceDelayMs
+ " ms, iterations: " + count + ", wait/iteration: " + toWait + "ms");
}
waited += toWait;
Thread.sleep(toWait);
} catch (InterruptedException x) {
// OK
}
} else {
System.out.println("No outstanding HTTP operations remaining after "
+ i + "/" + count + " iterations and " + waited + "/" + graceDelayMs
+ " ms, (wait/iteration " + toWait + " ms)");
break;
}
}
long duration = Duration.ofNanos(System.nanoTime() - waitStart).toMillis();
if (hasOutstanding.test(tracker)) {
if (i == 0 && waited == 0) {
// we found nothing and didn't wait expecting success, but then found
// something. Respin to make sure we wait.
return check(tracker, graceDelayMs, hasOutstanding, description, printThreads);
}
StringBuilder warnings = diagnose(tracker, new StringBuilder(), hasOutstanding);
if (hasOutstanding.test(tracker)) {
fail = new AssertionError(warnings.toString());
}
} else {
System.out.println("PASSED: No " + description + " found in "
+ tracker.getName() + " in " + duration + " ms");
}
if (fail != null) {
if (printThreads && tracker.isSelectorAlive()) {
var msg = "Selector manager threads are still alive for " + tracker.getName() + ": ";
printThreads(msg, System.out);
printThreads(msg, System.err);
}
System.out.println("AssertionError: Found some " + description + " in "
+ tracker.getName() + " after " + i + " iterations and " + duration
+ " ms, waited " + waited + " ms");
}
return fail;
}
public AssertionError check(long graceDelayMs,
Predicate<Tracker> hasOutstanding,
String description,
boolean printThreads) {
AssertionError fail = null;
graceDelayMs = Math.max(graceDelayMs, 100);
long waitStart = System.nanoTime();
long delay = Math.min(graceDelayMs, 10);
long toWait = Math.min(graceDelayMs, Math.max(delay, 1));
long waited = 0;
var count = delay > 0 ? graceDelayMs / delay : 1;
int i = 0;
for (i = 0; i < count; i++) {
if (TRACKERS.stream().anyMatch(hasOutstanding)) {
System.gc();
try {
if (i == 0) {
System.out.println("Waiting for HTTP operations to terminate...");
System.out.println("\tgracedelay: " + graceDelayMs
+ " ms, iterations: " + count + ", wait/iteration: " + toWait + "ms");
}
waited += toWait;
Thread.sleep(toWait);
} catch (InterruptedException x) {
// OK
}
} else {
System.out.println("No outstanding HTTP operations remaining after "
+ i + "/" + count + " iterations and " + waited + "/" + graceDelayMs
+ " ms, (wait/iteration " + toWait + " ms)");
break;
}
}
long duration = Duration.ofNanos(System.nanoTime() - waitStart).toMillis();
if (TRACKERS.stream().anyMatch(hasOutstanding)) {
if (i == 0 && waited == 0) {
// we found nothing and didn't wait expecting success, but then found
// something. Respin to make sure we wait.
return check(graceDelayMs, hasOutstanding, description, printThreads);
}
StringBuilder warnings = diagnose(new StringBuilder(), hasOutstanding);
addSummary(warnings);
if (TRACKERS.stream().anyMatch(hasOutstanding)) {
fail = new AssertionError(warnings.toString());
}
} else {
System.out.println("PASSED: No " + description + " found in "
+ getTrackedClientCount() + " clients in " + duration + " ms");
}
if (fail != null) {
Predicate<Tracker> isAlive = Tracker::isSelectorAlive;
if (printThreads && TRACKERS.stream().anyMatch(isAlive)) {
printThreads("Some selector manager threads are still alive: ", System.out);
printThreads("Some selector manager threads are still alive: ", System.err);
}
System.out.println("AssertionError: Found some " + description + " in "
+ getTrackedClientCount() + " clients after " + i + " iterations and " + duration
+ " ms, waited " + waited + " ms");
}
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.substring(pos));
System.err.println(warning.substring(pos));
}
private static void checkOutstandingOperations(StringBuilder warning,
Tracker tracker,
Predicate<Tracker> hasOutsanding) {
if (hasOutsanding.test(tracker)) {
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 Requests: " + tracker.getOutstandingHttpRequests());
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\tPending TCP connections: " + tracker.getOutstandingTcpConnections());
warning.append("\n\tPending Subscribers: " + tracker.getOutstandingSubscribers());
warning.append("\n\tTotal pending operations: " + tracker.getOutstandingOperations());
warning.append("\n\tFacade referenced: " + tracker.isFacadeReferenced());
warning.append("\n\tSelector alive: " + tracker.isSelectorAlive());
System.out.println(warning.substring(pos));
System.err.println(warning.substring(pos));
}
}
private boolean isSelectorManager(Thread t) {
String name = t.getName();
if (name == null) return false;
return name.contains("SelectorManager");
}
// This is a slightly more permissive check than the default checks,
// it only verifies that all CFs returned by send/sendAsync have been
// completed, and that all opened channels have been closed, and that
// the selector manager thread has exited.
// It doesn't check that all refcounts have reached 0.
// This is typically useful to only check that resources have been released.
public AssertionError checkShutdown(long graceDelayMs) {
Predicate<Tracker> isAlive = Tracker::isSelectorAlive;
Predicate<Tracker> hasPendingRequests = (t) -> t.getOutstandingHttpRequests() > 0;
Predicate<Tracker> hasPendingConnections = (t) -> t.getOutstandingTcpConnections() > 0;
Predicate<Tracker> hasPendingSubscribers = (t) -> t.getOutstandingSubscribers() > 0;
AssertionError failed = check(graceDelayMs,
isAlive.or(hasPendingRequests)
.or(hasPendingConnections)
.or(hasPendingSubscribers),
"outstanding unclosed resources", true);
return failed;
}
}