8130448: thread dump improvements, comment additions, new diagnostics inspired by 8077392

Reviewed-by: dholmes, coleenp

hotspot/src/cpu/x86/vm/macroAssembler_x86.cpp

@@ -1781,6 +1781,7 @@ void MacroAssembler::fast_lock(Register objReg, Register boxReg, Register tmpReg
        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 @@ void MacroAssembler::fast_lock(Register objReg, Register boxReg, Register tmpReg
        }
        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 @@ void MacroAssembler::fast_unlock(Register objReg, Register boxReg, Register tmpR
        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 @@ void MacroAssembler::fast_unlock(Register objReg, Register boxReg, Register tmpR
       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
 

hotspot/src/share/vm/oops/markOop.cpp

@@ -32,26 +32,32 @@ PRAGMA_FORMAT_MUTE_WARNINGS_FOR_GCC
 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("??");
     }

hotspot/src/share/vm/runtime/objectMonitor.cpp

 /*
- * 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 @@ static volatile int InitDone        = 0;
 // -----------------------------------------------------------------------------
 // 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 @@ void ObjectWaiter::wait_reenter_end(ObjectMonitor * const mon) {
 }
 
 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 @@ static int kvGetInt(char * kvList, const char * Key, int Default) {
   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 @@ void ObjectMonitor::DeferredInitialize() {
 
   #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 @@ void ObjectMonitor::DeferredInitialize() {
 
   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;

hotspot/src/share/vm/runtime/objectMonitor.hpp

 /*
- * 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 @@ class ObjectMonitor {
   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 @@ class ObjectMonitor {
   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 @@ class ObjectMonitor {
 #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

hotspot/src/share/vm/runtime/synchronizer.cpp

@@ -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 @@ static void InduceScavenge(Thread * Self, const char * Whence) {
 
   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 @@ static void InduceScavenge(Thread * Self, const char * Whence) {
     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 @@ void ObjectSynchronizer::deflate_idle_monitors() {
   // 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 @@ class ReleaseJavaMonitorsClosure: public MonitorClosure {
   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);
     }
   }

hotspot/src/share/vm/runtime/thread.cpp

@@ -1802,14 +1802,25 @@ void JavaThread::exit(bool destroy_vm, ExitType exit_type) {
   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.
   //
-  // ensure_join() ignores IllegalThreadStateExceptions, and so does this.
-  if (exit_type == jni_detach && JNIDetachReleasesMonitors) {
-    assert(!this->has_last_Java_frame(), "detaching with Java frames?");
+  // 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
+  // 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");
   }

hotspot/src/share/vm/runtime/vframe.cpp

@@ -144,7 +144,7 @@ GrowableArray<MonitorInfo*>* javaVFrame::locked_monitors() {
   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 @@ static void print_locked_object_class_name(outputStream* st, Handle obj, const c
 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 @@ void javaVFrame::print_lock_info_on(outputStream* st, int frame_count) {
     }
   }
 
-
-  // 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 @@ void javaVFrame::print_lock_info_on(outputStream* st, int frame_count) {
       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 @@ void javaVFrame::print_lock_info_on(outputStream* st, int frame_count) {
               )) {
             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();
         }

hotspot/src/share/vm/runtime/vframe.hpp

 /*
- * 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 @@ class javaVFrame: public vframe {
   // 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); }