From faa9c6909dda635eb008b9dada6e06fca47c17d6 Mon Sep 17 00:00:00 2001 From: Alan Bateman Date: Sat, 6 Jan 2024 18:24:28 +0000 Subject: [PATCH] 8322846: Running with -Djdk.tracePinnedThreads set can hang Reviewed-by: jpai --- .../java/lang/PinnedThreadPrinter.java | 65 ++++++++++------- .../classes/java/lang/VirtualThread.java | 10 ++- .../Thread/virtual/TracePinnedThreads.java | 69 +++++++++++++++++-- 3 files changed, 116 insertions(+), 28 deletions(-) diff --git a/src/java.base/share/classes/java/lang/PinnedThreadPrinter.java b/src/java.base/share/classes/java/lang/PinnedThreadPrinter.java index 02e0683a1b9..a9b40d028f5 100644 --- a/src/java.base/share/classes/java/lang/PinnedThreadPrinter.java +++ b/src/java.base/share/classes/java/lang/PinnedThreadPrinter.java @@ -1,5 +1,5 @@ /* - * Copyright (c) 2020, 2022, Oracle and/or its affiliates. All rights reserved. + * Copyright (c) 2020, 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 @@ -34,6 +34,10 @@ import java.util.Objects; import java.util.Set; import java.util.stream.Collectors; import static java.lang.StackWalker.Option.*; +import jdk.internal.access.JavaIOPrintStreamAccess; +import jdk.internal.access.SharedSecrets; +import jdk.internal.misc.InternalLock; +import jdk.internal.vm.Continuation; /** * Helper class to print the virtual thread stack trace when pinned. @@ -42,7 +46,8 @@ import static java.lang.StackWalker.Option.*; * code in that Class. This is used to avoid printing the same stack trace many times. */ class PinnedThreadPrinter { - static final StackWalker STACK_WALKER; + private static final JavaIOPrintStreamAccess JIOPSA = SharedSecrets.getJavaIOPrintStreamAccess(); + private static final StackWalker STACK_WALKER; static { var options = Set.of(SHOW_REFLECT_FRAMES, RETAIN_CLASS_REFERENCE); PrivilegedAction pa = () -> @@ -86,45 +91,59 @@ class PinnedThreadPrinter { } /** - * Prints the continuation stack trace. + * Returns true if the frame is native, a class initializer, or holds monitors. + */ + private static boolean isInterestingFrame(LiveStackFrame f) { + return f.isNativeMethod() + || "".equals(f.getMethodName()) + || (f.getMonitors().length > 0); + } + + /** + * Prints the current thread's stack trace. * * @param printAll true to print all stack frames, false to only print the * frames that are native or holding a monitor */ - static void printStackTrace(PrintStream out, boolean printAll) { + static void printStackTrace(PrintStream out, Continuation.Pinned reason, boolean printAll) { List stack = STACK_WALKER.walk(s -> s.map(f -> (LiveStackFrame) f) .filter(f -> f.getDeclaringClass() != PinnedThreadPrinter.class) .collect(Collectors.toList()) ); + Object lockObj = JIOPSA.lock(out); + if (lockObj instanceof InternalLock lock && lock.tryLock()) { + try { + // find the closest frame that is causing the thread to be pinned + stack.stream() + .filter(f -> isInterestingFrame(f)) + .map(LiveStackFrame::getDeclaringClass) + .findFirst() + .ifPresentOrElse(klass -> { + // print the stack trace if not already seen + int hash = hash(stack); + if (HASHES.get(klass).add(hash)) { + printStackTrace(out, reason, stack, printAll); + } + }, () -> printStackTrace(out, reason, stack, true)); // not found - // find the closest frame that is causing the thread to be pinned - stack.stream() - .filter(f -> (f.isNativeMethod() || f.getMonitors().length > 0)) - .map(LiveStackFrame::getDeclaringClass) - .findFirst() - .ifPresentOrElse(klass -> { - int hash = hash(stack); - Hashes hashes = HASHES.get(klass); - synchronized (hashes) { - // print the stack trace if not already seen - if (hashes.add(hash)) { - printStackTrace(stack, out, printAll); - } - } - }, () -> printStackTrace(stack, out, true)); // not found + } finally { + lock.unlock(); + } + } } - private static void printStackTrace(List stack, - PrintStream out, + private static void printStackTrace(PrintStream out, + Continuation.Pinned reason, + List stack, boolean printAll) { - out.println(Thread.currentThread()); + out.format("%s reason:%s%n", Thread.currentThread(), reason); for (LiveStackFrame frame : stack) { var ste = frame.toStackTraceElement(); int monitorCount = frame.getMonitors().length; if (monitorCount > 0) { out.format(" %s <== monitors:%d%n", ste, monitorCount); - } else if (frame.isNativeMethod() || printAll) { + } else if (printAll || isInterestingFrame(frame)) { out.format(" %s%n", ste); } } diff --git a/src/java.base/share/classes/java/lang/VirtualThread.java b/src/java.base/share/classes/java/lang/VirtualThread.java index 36a673fde60..6f82516d864 100644 --- a/src/java.base/share/classes/java/lang/VirtualThread.java +++ b/src/java.base/share/classes/java/lang/VirtualThread.java @@ -191,7 +191,15 @@ final class VirtualThread extends BaseVirtualThread { protected void onPinned(Continuation.Pinned reason) { if (TRACE_PINNING_MODE > 0) { boolean printAll = (TRACE_PINNING_MODE == 1); - PinnedThreadPrinter.printStackTrace(System.out, printAll); + VirtualThread vthread = (VirtualThread) Thread.currentThread(); + int oldState = vthread.state(); + try { + // avoid printing when in transition states + vthread.setState(RUNNING); + PinnedThreadPrinter.printStackTrace(System.out, reason, printAll); + } finally { + vthread.setState(oldState); + } } } private static Runnable wrap(VirtualThread vthread, Runnable task) { diff --git a/test/jdk/java/lang/Thread/virtual/TracePinnedThreads.java b/test/jdk/java/lang/Thread/virtual/TracePinnedThreads.java index 01fbdc76d49..5db29c631a3 100644 --- a/test/jdk/java/lang/Thread/virtual/TracePinnedThreads.java +++ b/test/jdk/java/lang/Thread/virtual/TracePinnedThreads.java @@ -1,5 +1,5 @@ /* - * Copyright (c) 2020, 2023, Oracle and/or its affiliates. All rights reserved. + * Copyright (c) 2020, 2024, 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 @@ -23,7 +23,7 @@ /** * @test - * @bug 8284161 8289284 + * @bug 8284161 8289284 8322846 * @summary Basic test of debugging option to trace pinned threads * @requires vm.continuations * @library /test/lib @@ -34,6 +34,7 @@ import java.io.ByteArrayOutputStream; import java.io.PrintStream; import java.time.Duration; +import java.util.concurrent.Executors; import java.util.concurrent.locks.LockSupport; import jdk.test.lib.thread.VThreadRunner; @@ -67,8 +68,8 @@ class TracePinnedThreads { park(); } }); + assertContains(output, "reason:MONITOR"); assertContains(output, "<== monitors:1"); - assertDoesNotContain(output, "(Native Method)"); } /** @@ -78,8 +79,68 @@ class TracePinnedThreads { void testPinnedCausedByNativeMethod() throws Exception { System.loadLibrary("TracePinnedThreads"); String output = run(() -> invokePark()); + assertContains(output, "reason:NATIVE"); assertContains(output, "(Native Method)"); - assertDoesNotContain(output, "<== monitors"); + } + + /** + * Test parking in class initializer. + */ + @Test + void testPinnedCausedByClassInitializer() throws Exception { + class C { + static { + park(); + } + } + String output = run(C::new); + assertContains(output, "reason:NATIVE"); + assertContains(output, ""); + } + + /** + * Test contention writing to System.out when pinned. The test creates four threads + * that write to System.out when pinned, this is enough to potentially deadlock + * without the changes in JDK-8322846. + */ + @Test + void testContention() throws Exception { + // use several classes to avoid duplicate stack traces + class C1 { + synchronized void print() { + System.out.println("hello"); + } + } + class C2 { + synchronized void print() { + System.out.println("hello"); + } + } + class C3 { + synchronized void print() { + System.out.println("hello"); + } + } + class C4 { + synchronized void print() { + System.out.println("hello"); + } + } + + try (var executor = Executors.newVirtualThreadPerTaskExecutor()) { + executor.submit(() -> { + new C1().print(); + }); + executor.submit(() -> { + new C2().print(); + }); + executor.submit(() -> { + new C3().print(); + }); + executor.submit(() -> { + new C4().print(); + }); + } } /**