# HG changeset patch # User dholmes # Date 1547588431 18000 # Node ID d193d58ae79dba7ca94793f015efb00f16d9cef5 # Parent 9e968a576dd27a1994880016c8dbf5d99ac9a574 8213397: Stack dump should show more clearly when a thread is blocked on a class initialization monitor Reviewed-by: rehn, coleenp diff -r 9e968a576dd2 -r d193d58ae79d src/hotspot/share/oops/instanceKlass.cpp --- a/src/hotspot/share/oops/instanceKlass.cpp Tue Jan 15 15:56:41 2019 -0500 +++ b/src/hotspot/share/oops/instanceKlass.cpp Tue Jan 15 16:40:31 2019 -0500 @@ -918,25 +918,28 @@ bool wait = false; + assert(THREAD->is_Java_thread(), "non-JavaThread in initialize_impl"); + JavaThread* jt = (JavaThread*)THREAD; + // refer to the JVM book page 47 for description of steps // Step 1 { Handle h_init_lock(THREAD, init_lock()); ObjectLocker ol(h_init_lock, THREAD, h_init_lock() != NULL); - Thread *self = THREAD; // it's passed the current thread - // Step 2 // If we were to use wait() instead of waitInterruptibly() then // we might end up throwing IE from link/symbol resolution sites // that aren't expected to throw. This would wreak havoc. See 6320309. - while(is_being_initialized() && !is_reentrant_initialization(self)) { - wait = true; - ol.waitUninterruptibly(CHECK); + while (is_being_initialized() && !is_reentrant_initialization(jt)) { + wait = true; + jt->set_class_to_be_initialized(this); + ol.waitUninterruptibly(jt); + jt->set_class_to_be_initialized(NULL); } // Step 3 - if (is_being_initialized() && is_reentrant_initialization(self)) { + if (is_being_initialized() && is_reentrant_initialization(jt)) { DTRACE_CLASSINIT_PROBE_WAIT(recursive, -1, wait); return; } @@ -966,7 +969,7 @@ // Step 6 set_init_state(being_initialized); - set_init_thread(self); + set_init_thread(jt); } // Step 7 @@ -1006,8 +1009,6 @@ // Step 8 { - assert(THREAD->is_Java_thread(), "non-JavaThread in initialize_impl"); - JavaThread* jt = (JavaThread*)THREAD; DTRACE_CLASSINIT_PROBE_WAIT(clinit, -1, wait); // Timer includes any side effects of class initialization (resolution, // etc), but not recursive entry into call_class_initializer(). @@ -1033,14 +1034,14 @@ CLEAR_PENDING_EXCEPTION; // JVMTI has already reported the pending exception // JVMTI internal flag reset is needed in order to report ExceptionInInitializerError - JvmtiExport::clear_detected_exception((JavaThread*)THREAD); + JvmtiExport::clear_detected_exception(jt); { EXCEPTION_MARK; set_initialization_state_and_notify(initialization_error, THREAD); CLEAR_PENDING_EXCEPTION; // ignore any exception thrown, class initialization error is thrown below // JVMTI has already reported the pending exception // JVMTI internal flag reset is needed in order to report ExceptionInInitializerError - JvmtiExport::clear_detected_exception((JavaThread*)THREAD); + JvmtiExport::clear_detected_exception(jt); } DTRACE_CLASSINIT_PROBE_WAIT(error, -1, wait); if (e->is_a(SystemDictionary::Error_klass())) { diff -r 9e968a576dd2 -r d193d58ae79d src/hotspot/share/runtime/thread.cpp --- a/src/hotspot/share/runtime/thread.cpp Tue Jan 15 15:56:41 2019 -0500 +++ b/src/hotspot/share/runtime/thread.cpp Tue Jan 15 16:40:31 2019 -0500 @@ -1671,6 +1671,8 @@ SafepointMechanism::initialize_header(this); } + _class_to_be_initialized = NULL; + pd_initialize(); } diff -r 9e968a576dd2 -r d193d58ae79d src/hotspot/share/runtime/thread.hpp --- a/src/hotspot/share/runtime/thread.hpp Tue Jan 15 15:56:41 2019 -0500 +++ b/src/hotspot/share/runtime/thread.hpp Tue Jan 15 16:40:31 2019 -0500 @@ -2088,6 +2088,16 @@ bool is_attaching_via_jni() const { return _jni_attach_state == _attaching_via_jni; } bool has_attached_via_jni() const { return is_attaching_via_jni() || _jni_attach_state == _attached_via_jni; } inline void set_done_attaching_via_jni(); + + // Stack dump assistance: + // Track the class we want to initialize but for which we have to wait + // on its init_lock() because it is already being initialized. + void set_class_to_be_initialized(InstanceKlass* k); + InstanceKlass* class_to_be_initialized() const; + +private: + InstanceKlass* _class_to_be_initialized; + }; // Inline implementation of JavaThread::current diff -r 9e968a576dd2 -r d193d58ae79d src/hotspot/share/runtime/thread.inline.hpp --- a/src/hotspot/share/runtime/thread.inline.hpp Tue Jan 15 15:56:41 2019 -0500 +++ b/src/hotspot/share/runtime/thread.inline.hpp Tue Jan 15 16:40:31 2019 -0500 @@ -233,4 +233,16 @@ OrderAccess::release_store((volatile jint *) &_terminated, (jint) _thread_terminated); } +// Allow tracking of class initialization monitor use +inline void JavaThread::set_class_to_be_initialized(InstanceKlass* k) { + assert((k == NULL && _class_to_be_initialized != NULL) || + (k != NULL && _class_to_be_initialized == NULL), "incorrect usage"); + assert(this == Thread::current(), "Only the current thread can set this field"); + _class_to_be_initialized = k; +} + +inline InstanceKlass* JavaThread::class_to_be_initialized() const { + return _class_to_be_initialized; +} + #endif // SHARE_RUNTIME_THREAD_INLINE_HPP diff -r 9e968a576dd2 -r d193d58ae79d src/hotspot/share/runtime/vframe.cpp --- a/src/hotspot/share/runtime/vframe.cpp Tue Jan 15 15:56:41 2019 -0500 +++ b/src/hotspot/share/runtime/vframe.cpp Tue Jan 15 16:40:31 2019 -0500 @@ -190,6 +190,14 @@ Klass* k = obj->klass(); st->print_cr("\t- %s <" INTPTR_FORMAT "> (a %s)", "parking to wait for ", p2i(obj), k->external_name()); } + else if (thread()->osthread()->get_state() == OBJECT_WAIT) { + // We are waiting on an Object monitor but Object.wait() isn't the + // top-frame, so we should be waiting on a Class initialization monitor. + InstanceKlass* k = thread()->class_to_be_initialized(); + if (k != NULL) { + st->print_cr("\t- waiting on the Class initialization monitor for %s", k->external_name()); + } + } } // Print out all monitors that we have locked, or are trying to lock, diff -r 9e968a576dd2 -r d193d58ae79d test/hotspot/jtreg/runtime/Thread/TestThreadDumpClassInitMonitor.java --- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/test/hotspot/jtreg/runtime/Thread/TestThreadDumpClassInitMonitor.java Tue Jan 15 16:40:31 2019 -0500 @@ -0,0 +1,195 @@ +/* + * Copyright (c) 2019, 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. + */ + +/* + * @test + * @bug 8213397 + * @summary Check that the thread dump shows when a thread is blocked + * on a class initialization monitor + * + * @library /test/lib + * @run main/othervm TestThreadDumpClassInitMonitor + */ + +import jdk.test.lib.process.OutputAnalyzer; +import jdk.test.lib.JDKToolFinder; + +import java.io.IOException; +import java.util.List; + +public class TestThreadDumpClassInitMonitor { + // jstack tends to be closely bound to the VM that we are running + // so use getTestJDKTool() instead of getCompileJDKTool() or even + // getJDKTool() which can fall back to "compile.jdk". + final static String JSTACK = JDKToolFinder.getTestJDKTool("jstack"); + final static String PID = "" + ProcessHandle.current().pid(); + + final static Thread current = Thread.currentThread(); + + /* + * This is the output we're looking for: + * + * "TestThread" #22 prio=5 os_prio=0 cpu=1.19ms elapsed=0.80s tid=0x00007f8f9405d800 nid=0x568b in Object.wait() [0x00007f8fd94d0000] + * java.lang.Thread.State: RUNNABLE + * Thread: 0x00007f8f9405d800 [0x568b] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 + * JavaThread state: _thread_blocked + * at TestThreadDumpClassInitMonitor$Target$1.run(TestThreadDumpClassInitMonitor.java:69) + * - waiting on the Class initialization monitor for TestThreadDumpClassInitMonitor$Target + * + */ + final static String TEST_THREAD = "TestThread"; + final static String TEST_THREAD_ENTRY = "\"" + TEST_THREAD; + final static String IN_OBJECT_WAIT = "in Object.wait()"; + final static String THREAD_STATE = "java.lang.Thread.State: RUNNABLE"; + final static String THREAD_INFO = "Thread:"; // the details are not important + final static String JAVATHREAD_STATE = "JavaThread state: _thread_blocked"; + final static String CURRENT_METHOD = "at TestThreadDumpClassInitMonitor$Target$1.run"; + final static String WAIT_INFO = "- waiting on the Class initialization monitor for TestThreadDumpClassInitMonitor$Target"; + + volatile static boolean ready = false; + + static List stackDump; // jstack output as lines + + static class Target { + + static int field; + + // The main thread will initialize this class and so + // execute the actual test logic here. + static { + if (Thread.currentThread() != current) { + throw new Error("Initialization logic error"); + } + System.out.println("Initializing Target class in main thread"); + + Thread t = new Thread() { + public void run() { + System.out.println("Test thread about to access Target"); + ready = true; // tell main thread we're close + // This will block until the main thread completes + // static initialization of target + Target.field = 42; + System.out.println("Test thread done"); + } + }; + t.setName(TEST_THREAD); + t.start(); + + // We want to run jstack once the test thread is blocked but + // there's no programmatic way to detect that. So we check the flag + // that will be set just before it should block, then by the time + // we can exec jstack it should be ready. + try { + while (!ready) { + Thread.sleep(200); + } + } + catch (InterruptedException ie) { + throw new Error("Shouldn't happen"); + } + + // Now run jstack + try { + ProcessBuilder pb = new ProcessBuilder(JSTACK, PID); + OutputAnalyzer output = new OutputAnalyzer(pb.start()); + output.shouldHaveExitValue(0); + stackDump = output.asLines(); + } + catch (IOException ioe) { + throw new Error("Launching jstack failed", ioe); + } + } + } + + + public static void main(String[] args) throws Throwable { + // Implicitly run the main test logic + Target.field = 21; + + // Now check the output of jstack + try { + int foundLines = 0; + parseStack: for (String line : stackDump) { + switch(foundLines) { + case 0: { + if (!line.startsWith(TEST_THREAD_ENTRY)) { + continue; + } + foundLines++; + if (!line.contains(IN_OBJECT_WAIT)) { + throw new Error("Unexpected initial stack line: " + line); + } + continue; + } + case 1: { + if (!line.trim().equals(THREAD_STATE)) { + throw new Error("Unexpected thread state line: " + line); + } + foundLines++; + continue; + } + case 2: { + if (!line.startsWith(THREAD_INFO)) { + throw new Error("Unexpected thread info line: " + line); + } + foundLines++; + continue; + } + case 3: { + if (!line.trim().equals(JAVATHREAD_STATE)) { + throw new Error("Unexpected JavaThread state line: " + line); + } + foundLines++; + continue; + } + case 4: { + if (!line.trim().startsWith(CURRENT_METHOD)) { + throw new Error("Unexpected current method line: " + line); + } + foundLines++; + continue; + } + case 5: { + if (!line.trim().equals(WAIT_INFO)) { + throw new Error("Unexpected monitor information line: " + line); + } + break parseStack; + } + default: throw new Error("Logic error in case statement"); + } + } + + if (foundLines == 0) { + throw new Error("Unexpected stack content - did not find line starting with " + + TEST_THREAD_ENTRY); + } + } + catch (Error e) { + // Dump the full stack trace on error so we can check the content + for (String line : stackDump) { + System.out.println(line); + } + throw e; + } + } +}