8130448: thread dump improvements, comment additions, new diagnostics inspired by 8077392
Reviewed-by: dholmes, coleenp
--- a/hotspot/src/cpu/x86/vm/macroAssembler_x86.cpp Tue Jul 14 11:40:49 2015 +0200
+++ b/hotspot/src/cpu/x86/vm/macroAssembler_x86.cpp Tue Jul 14 09:33:20 2015 -0700
@@ -1781,6 +1781,7 @@
cmpxchgptr(scrReg, Address(boxReg, OM_OFFSET_NO_MONITOR_VALUE_TAG(owner)));
} else
if ((EmitSync & 128) == 0) { // avoid ST-before-CAS
+ // register juggle because we need tmpReg for cmpxchgptr below
movptr(scrReg, boxReg);
movptr(boxReg, tmpReg); // consider: LEA box, [tmp-2]
@@ -1814,7 +1815,10 @@
}
cmpxchgptr(scrReg, Address(boxReg, OM_OFFSET_NO_MONITOR_VALUE_TAG(owner)));
movptr(Address(scrReg, 0), 3); // box->_displaced_header = 3
+ // If we weren't able to swing _owner from NULL to the BasicLock
+ // then take the slow path.
jccb (Assembler::notZero, DONE_LABEL);
+ // update _owner from BasicLock to thread
get_thread (scrReg); // beware: clobbers ICCs
movptr(Address(boxReg, OM_OFFSET_NO_MONITOR_VALUE_TAG(owner)), scrReg);
xorptr(boxReg, boxReg); // set icc.ZFlag = 1 to indicate success
@@ -2083,6 +2087,9 @@
xorptr(boxReg, boxReg); // box is really EAX
if (os::is_MP()) { lock(); }
cmpxchgptr(rsp, Address(tmpReg, OM_OFFSET_NO_MONITOR_VALUE_TAG(owner)));
+ // There's no successor so we tried to regrab the lock with the
+ // placeholder value. If that didn't work, then another thread
+ // grabbed the lock so we're done (and exit was a success).
jccb (Assembler::notEqual, LSuccess);
// Since we're low on registers we installed rsp as a placeholding in _owner.
// Now install Self over rsp. This is safe as we're transitioning from
@@ -2190,6 +2197,9 @@
movptr(boxReg, (int32_t)NULL_WORD);
if (os::is_MP()) { lock(); }
cmpxchgptr(r15_thread, Address(tmpReg, OM_OFFSET_NO_MONITOR_VALUE_TAG(owner)));
+ // There's no successor so we tried to regrab the lock.
+ // If that didn't work, then another thread grabbed the
+ // lock so we're done (and exit was a success).
jccb (Assembler::notEqual, LSuccess);
// Intentional fall-through into slow-path
--- a/hotspot/src/share/vm/oops/markOop.cpp Tue Jul 14 11:40:49 2015 +0200
+++ b/hotspot/src/share/vm/oops/markOop.cpp Tue Jul 14 09:33:20 2015 -0700
@@ -32,26 +32,32 @@
void markOopDesc::print_on(outputStream* st) const {
if (is_marked()) {
st->print(" marked(" INTPTR_FORMAT ")", value());
+ } else if (has_monitor()) {
+ // have to check has_monitor() before is_locked()
+ st->print(" monitor(" INTPTR_FORMAT ")=", value());
+ ObjectMonitor* mon = monitor();
+ if (mon == NULL) {
+ st->print("NULL (this should never be seen!)");
+ } else {
+ st->print("{count=" INTPTR_FORMAT ",waiters=" INTPTR_FORMAT
+ ",recursions=" INTPTR_FORMAT ",owner=" INTPTR_FORMAT "}",
+ mon->count(), mon->waiters(), mon->recursions(),
+ p2i(mon->owner()));
+ }
} else if (is_locked()) {
st->print(" locked(" INTPTR_FORMAT ")->", value());
if (is_neutral()) {
st->print("is_neutral");
- if (has_no_hash()) st->print(" no_hash");
- else st->print(" hash=" INTPTR_FORMAT, hash());
+ if (has_no_hash()) {
+ st->print(" no_hash");
+ } else {
+ st->print(" hash=" INTPTR_FORMAT, hash());
+ }
st->print(" age=%d", age());
} else if (has_bias_pattern()) {
st->print("is_biased");
JavaThread* jt = biased_locker();
st->print(" biased_locker=" INTPTR_FORMAT, p2i(jt));
- } else if (has_monitor()) {
- ObjectMonitor* mon = monitor();
- if (mon == NULL)
- st->print("monitor=NULL");
- else {
- BasicLock * bl = (BasicLock *) mon->owner();
- st->print("monitor={count=" INTPTR_FORMAT ",waiters=" INTPTR_FORMAT ",recursions=" INTPTR_FORMAT ",owner=" INTPTR_FORMAT "}",
- mon->count(), mon->waiters(), mon->recursions(), p2i(bl));
- }
} else {
st->print("??");
}
--- a/hotspot/src/share/vm/runtime/objectMonitor.cpp Tue Jul 14 11:40:49 2015 +0200
+++ b/hotspot/src/share/vm/runtime/objectMonitor.cpp Tue Jul 14 09:33:20 2015 -0700
@@ -1,5 +1,5 @@
/*
- * Copyright (c) 1998, 2014, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 1998, 2015, 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
@@ -103,8 +103,10 @@
// The knob* variables are effectively final. Once set they should
// never be modified hence. Consider using __read_mostly with GCC.
+int ObjectMonitor::Knob_ExitRelease = 0;
int ObjectMonitor::Knob_Verbose = 0;
int ObjectMonitor::Knob_VerifyInUse = 0;
+int ObjectMonitor::Knob_VerifyMatch = 0;
int ObjectMonitor::Knob_SpinLimit = 5000; // derived by an external tool -
static int Knob_LogSpins = 0; // enable jvmstat tally for spins
static int Knob_HandOff = 0;
@@ -251,24 +253,6 @@
// -----------------------------------------------------------------------------
// Enter support
-bool ObjectMonitor::try_enter(Thread* THREAD) {
- if (THREAD != _owner) {
- if (THREAD->is_lock_owned ((address)_owner)) {
- assert(_recursions == 0, "internal state error");
- _owner = THREAD;
- _recursions = 1;
- return true;
- }
- if (Atomic::cmpxchg_ptr (THREAD, &_owner, NULL) != NULL) {
- return false;
- }
- return true;
- } else {
- _recursions++;
- return true;
- }
-}
-
void NOINLINE ObjectMonitor::enter(TRAPS) {
// The following code is ordered to check the most common cases first
// and to reduce RTS->RTO cache line upgrades on SPARC and IA32 processors.
@@ -2272,7 +2256,7 @@
}
inline void ObjectMonitor::AddWaiter(ObjectWaiter* node) {
- assert(node != NULL, "should not dequeue NULL node");
+ assert(node != NULL, "should not add NULL node");
assert(node->_prev == NULL, "node already in list");
assert(node->_next == NULL, "node already in list");
// put node at end of queue (circular doubly linked list)
@@ -2407,8 +2391,8 @@
char * v = kvGet(kvList, Key);
int rslt = v ? ::strtol(v, NULL, 0) : Default;
if (Knob_ReportSettings && v != NULL) {
- ::printf (" SyncKnob: %s %d(%d)\n", Key, rslt, Default) ;
- ::fflush(stdout);
+ tty->print_cr("INFO: SyncKnob: %s %d(%d)", Key, rslt, Default) ;
+ tty->flush();
}
return rslt;
}
@@ -2442,8 +2426,10 @@
#define SETKNOB(x) { Knob_##x = kvGetInt(knobs, #x, Knob_##x); }
SETKNOB(ReportSettings);
+ SETKNOB(ExitRelease);
SETKNOB(Verbose);
SETKNOB(VerifyInUse);
+ SETKNOB(VerifyMatch);
SETKNOB(FixedSpin);
SETKNOB(SpinLimit);
SETKNOB(SpinBase);
@@ -2477,7 +2463,9 @@
if (os::is_MP()) {
BackOffMask = (1 << Knob_SpinBackOff) - 1;
- if (Knob_ReportSettings) ::printf("BackOffMask=%X\n", BackOffMask);
+ if (Knob_ReportSettings) {
+ tty->print_cr("INFO: BackOffMask=0x%X", BackOffMask);
+ }
// CONSIDER: BackOffMask = ROUNDUP_NEXT_POWER2 (ncpus-1)
} else {
Knob_SpinLimit = 0;
--- a/hotspot/src/share/vm/runtime/objectMonitor.hpp Tue Jul 14 11:40:49 2015 +0200
+++ b/hotspot/src/share/vm/runtime/objectMonitor.hpp Tue Jul 14 09:33:20 2015 -0700
@@ -1,5 +1,5 @@
/*
- * Copyright (c) 1998, 2014, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 1998, 2015, 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
@@ -196,8 +196,10 @@
static PerfCounter * _sync_Deflations;
static PerfLongVariable * _sync_MonExtant;
+ static int Knob_ExitRelease;
static int Knob_Verbose;
static int Knob_VerifyInUse;
+ static int Knob_VerifyMatch;
static int Knob_SpinLimit;
void* operator new (size_t size) throw() {
@@ -317,7 +319,6 @@
void print();
#endif
- bool try_enter(TRAPS);
void enter(TRAPS);
void exit(bool not_suspended, TRAPS);
void wait(jlong millis, bool interruptable, TRAPS);
@@ -354,14 +355,14 @@
#undef TEVENT
#define TEVENT(nom) { if (SyncVerbose) FEVENT(nom); }
-#define FEVENT(nom) \
- { \
- static volatile int ctr = 0; \
- int v = ++ctr; \
- if ((v & (v - 1)) == 0) { \
- ::printf(#nom " : %d\n", v); \
- ::fflush(stdout); \
- } \
+#define FEVENT(nom) \
+ { \
+ static volatile int ctr = 0; \
+ int v = ++ctr; \
+ if ((v & (v - 1)) == 0) { \
+ tty->print_cr("INFO: " #nom " : %d", v); \
+ tty->flush(); \
+ } \
}
#undef TEVENT
--- a/hotspot/src/share/vm/runtime/synchronizer.cpp Tue Jul 14 11:40:49 2015 +0200
+++ b/hotspot/src/share/vm/runtime/synchronizer.cpp Tue Jul 14 09:33:20 2015 -0700
@@ -40,6 +40,7 @@
#include "runtime/stubRoutines.hpp"
#include "runtime/synchronizer.hpp"
#include "runtime/thread.inline.hpp"
+#include "runtime/vframe.hpp"
#include "utilities/dtrace.hpp"
#include "utilities/events.hpp"
#include "utilities/preserveException.hpp"
@@ -927,8 +928,9 @@
if (ForceMonitorScavenge == 0 && Atomic::xchg (1, &ForceMonitorScavenge) == 0) {
if (ObjectMonitor::Knob_Verbose) {
- ::printf ("Monitor scavenge - Induced STW @%s (%d)\n", Whence, ForceMonitorScavenge) ;
- ::fflush(stdout);
+ tty->print_cr("INFO: Monitor scavenge - Induced STW @%s (%d)",
+ Whence, ForceMonitorScavenge) ;
+ tty->flush();
}
// Induce a 'null' safepoint to scavenge monitors
// Must VM_Operation instance be heap allocated as the op will be enqueue and posted
@@ -937,8 +939,9 @@
VMThread::execute(new VM_ForceAsyncSafepoint());
if (ObjectMonitor::Knob_Verbose) {
- ::printf ("Monitor scavenge - STW posted @%s (%d)\n", Whence, ForceMonitorScavenge) ;
- ::fflush(stdout);
+ tty->print_cr("INFO: Monitor scavenge - STW posted @%s (%d)",
+ Whence, ForceMonitorScavenge) ;
+ tty->flush();
}
}
}
@@ -1603,10 +1606,11 @@
// Consider: audit gFreeList to ensure that gMonitorFreeCount and list agree.
if (ObjectMonitor::Knob_Verbose) {
- ::printf("Deflate: InCirc=%d InUse=%d Scavenged=%d ForceMonitorScavenge=%d : pop=%d free=%d\n",
- nInCirculation, nInuse, nScavenged, ForceMonitorScavenge,
- gMonitorPopulation, gMonitorFreeCount);
- ::fflush(stdout);
+ tty->print_cr("INFO: Deflate: InCirc=%d InUse=%d Scavenged=%d "
+ "ForceMonitorScavenge=%d : pop=%d free=%d",
+ nInCirculation, nInuse, nScavenged, ForceMonitorScavenge,
+ gMonitorPopulation, gMonitorFreeCount);
+ tty->flush();
}
ForceMonitorScavenge = 0; // Reset
@@ -1643,6 +1647,14 @@
ReleaseJavaMonitorsClosure(Thread* thread) : THREAD(thread) {}
void do_monitor(ObjectMonitor* mid) {
if (mid->owner() == THREAD) {
+ if (ObjectMonitor::Knob_VerifyMatch != 0) {
+ Handle obj((oop) mid->object());
+ tty->print("INFO: unexpected locked object:");
+ javaVFrame::print_locked_object_class_name(tty, obj, "locked");
+ fatal(err_msg("exiting JavaThread=" INTPTR_FORMAT
+ " unexpectedly owns ObjectMonitor=" INTPTR_FORMAT,
+ THREAD, mid));
+ }
(void)mid->complete_exit(CHECK);
}
}
--- a/hotspot/src/share/vm/runtime/thread.cpp Tue Jul 14 11:40:49 2015 +0200
+++ b/hotspot/src/share/vm/runtime/thread.cpp Tue Jul 14 09:33:20 2015 -0700
@@ -1802,14 +1802,25 @@
assert(!this->has_pending_exception(), "ensure_join should have cleared");
// 6282335 JNI DetachCurrentThread spec states that all Java monitors
- // held by this thread must be released. A detach operation must only
- // get here if there are no Java frames on the stack. Therefore, any
- // owned monitors at this point MUST be JNI-acquired monitors which are
- // pre-inflated and in the monitor cache.
+ // held by this thread must be released. The spec does not distinguish
+ // between JNI-acquired and regular Java monitors. We can only see
+ // regular Java monitors here if monitor enter-exit matching is broken.
+ //
+ // Optionally release any monitors for regular JavaThread exits. This
+ // is provided as a work around for any bugs in monitor enter-exit
+ // matching. This can be expensive so it is not enabled by default.
+ // ObjectMonitor::Knob_ExitRelease is a superset of the
+ // JNIDetachReleasesMonitors option.
//
- // ensure_join() ignores IllegalThreadStateExceptions, and so does this.
- if (exit_type == jni_detach && JNIDetachReleasesMonitors) {
- assert(!this->has_last_Java_frame(), "detaching with Java frames?");
+ // ensure_join() ignores IllegalThreadStateExceptions, and so does
+ // ObjectSynchronizer::release_monitors_owned_by_thread().
+ if ((exit_type == jni_detach && JNIDetachReleasesMonitors) ||
+ ObjectMonitor::Knob_ExitRelease) {
+ // Sanity check even though JNI DetachCurrentThread() would have
+ // returned JNI_ERR if there was a Java frame. JavaThread exit
+ // should be done executing Java code by the time we get here.
+ assert(!this->has_last_Java_frame(),
+ "should not have a Java frame when detaching or exiting");
ObjectSynchronizer::release_monitors_owned_by_thread(this);
assert(!this->has_pending_exception(), "release_monitors should have cleared");
}
--- a/hotspot/src/share/vm/runtime/vframe.cpp Tue Jul 14 11:40:49 2015 +0200
+++ b/hotspot/src/share/vm/runtime/vframe.cpp Tue Jul 14 09:33:20 2015 -0700
@@ -144,7 +144,7 @@
return result;
}
-static void print_locked_object_class_name(outputStream* st, Handle obj, const char* lock_state) {
+void javaVFrame::print_locked_object_class_name(outputStream* st, Handle obj, const char* lock_state) {
if (obj.not_null()) {
st->print("\t- %s <" INTPTR_FORMAT "> ", lock_state, (address)obj());
if (obj->klass() == SystemDictionary::Class_klass()) {
@@ -160,17 +160,29 @@
void javaVFrame::print_lock_info_on(outputStream* st, int frame_count) {
ResourceMark rm;
- // If this is the first frame, and java.lang.Object.wait(...) then print out the receiver.
+ // If this is the first frame and it is java.lang.Object.wait(...)
+ // then print out the receiver. Locals are not always available,
+ // e.g., compiled native frames have no scope so there are no locals.
if (frame_count == 0) {
if (method()->name() == vmSymbols::wait_name() &&
method()->method_holder()->name() == vmSymbols::java_lang_Object()) {
+ const char *wait_state = "waiting on"; // assume we are waiting
+ // If earlier in the output we reported java.lang.Thread.State ==
+ // "WAITING (on object monitor)" and now we report "waiting on", then
+ // we are still waiting for notification or timeout. Otherwise if
+ // we earlier reported java.lang.Thread.State == "BLOCKED (on object
+ // monitor)", then we are actually waiting to re-lock the monitor.
+ // At this level we can't distinguish the two cases to report
+ // "waited on" rather than "waiting on" for the second case.
StackValueCollection* locs = locals();
if (!locs->is_empty()) {
StackValue* sv = locs->at(0);
if (sv->type() == T_OBJECT) {
Handle o = locs->at(0)->get_obj();
- print_locked_object_class_name(st, o, "waiting on");
+ print_locked_object_class_name(st, o, wait_state);
}
+ } else {
+ st->print_cr("\t- %s <no object reference available>", wait_state);
}
} else if (thread()->current_park_blocker() != NULL) {
oop obj = thread()->current_park_blocker();
@@ -179,8 +191,8 @@
}
}
-
- // Print out all monitors that we have locked or are trying to lock
+ // Print out all monitors that we have locked, or are trying to lock,
+ // including re-locking after being notified or timing out in a wait().
GrowableArray<MonitorInfo*>* mons = monitors();
if (!mons->is_empty()) {
bool found_first_monitor = false;
@@ -202,14 +214,14 @@
if (monitor->owner() != NULL) {
// the monitor is associated with an object, i.e., it is locked
- // First, assume we have the monitor locked. If we haven't found an
- // owned monitor before and this is the first frame, then we need to
- // see if we have completed the lock or we are blocked trying to
- // acquire it - we can only be blocked if the monitor is inflated
-
markOop mark = NULL;
const char *lock_state = "locked"; // assume we have the monitor locked
if (!found_first_monitor && frame_count == 0) {
+ // If this is the first frame and we haven't found an owned
+ // monitor before, then we need to see if we have completed
+ // the lock or if we are blocked trying to acquire it. Only
+ // an inflated monitor that is first on the monitor list in
+ // the first frame can block us on a monitor enter.
mark = monitor->owner()->mark();
if (mark->has_monitor() &&
( // we have marked ourself as pending on this monitor
@@ -219,13 +231,33 @@
)) {
lock_state = "waiting to lock";
} else {
- mark = NULL; // Disable printing below
+ // We own the monitor which is not as interesting so
+ // disable the extra printing below.
+ mark = NULL;
+ }
+ } else if (frame_count != 0) {
+ // This is not the first frame so we either own this monitor
+ // or we owned the monitor before and called wait(). Because
+ // wait() could have been called on any monitor in a lower
+ // numbered frame on the stack, we have to check all the
+ // monitors on the list for this frame.
+ mark = monitor->owner()->mark();
+ if (mark->has_monitor() &&
+ ( // we have marked ourself as pending on this monitor
+ mark->monitor() == thread()->current_pending_monitor() ||
+ // we are not the owner of this monitor
+ !mark->monitor()->is_entered(thread())
+ )) {
+ lock_state = "waiting to re-lock in wait()";
+ } else {
+ // We own the monitor which is not as interesting so
+ // disable the extra printing below.
+ mark = NULL;
}
}
print_locked_object_class_name(st, monitor->owner(), lock_state);
- if (Verbose && mark != NULL) {
- // match with format above, replacing "-" with " ".
- st->print("\t lockbits=");
+ if (ObjectMonitor::Knob_Verbose && mark != NULL) {
+ st->print("\t- lockbits=");
mark->print_on(st);
st->cr();
}
--- a/hotspot/src/share/vm/runtime/vframe.hpp Tue Jul 14 11:40:49 2015 +0200
+++ b/hotspot/src/share/vm/runtime/vframe.hpp Tue Jul 14 09:33:20 2015 -0700
@@ -1,5 +1,5 @@
/*
- * Copyright (c) 1997, 2014, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 1997, 2015, 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
@@ -135,7 +135,8 @@
// Return an array of monitors locked by this frame in the youngest to oldest order
GrowableArray<MonitorInfo*>* locked_monitors();
- // printing used during stack dumps
+ // printing used during stack dumps and diagnostics
+ static void print_locked_object_class_name(outputStream* st, Handle obj, const char* lock_state);
void print_lock_info_on(outputStream* st, int frame_count);
void print_lock_info(int frame_count) { print_lock_info_on(tty, frame_count); }