Skip to content

Instantly share code, notes, and snippets.

@rednaxelafx
Created July 12, 2012 10:14
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save rednaxelafx/3097193 to your computer and use it in GitHub Desktop.
Save rednaxelafx/3097193 to your computer and use it in GitHub Desktop.
Multiple Java threads look as if they've locked the same monitor, but actually haven't

vframe.cpp

void javaVFrame::print_lock_info_on(outputStream* st, int frame_count) {
  // If this is the first frame, and java.lang.Object.wait(...) then print out the receiver.
  if (frame_count == 0) {
    if (method()->name() == vmSymbols::wait_name() &&
        instanceKlass::cast(method()->method_holder())->name() == vmSymbols::java_lang_Object()) {
      // ...
  }


  // Print out all monitors that we have locked or are trying to lock
  GrowableArray<MonitorInfo*>* mons = monitors();
  if (!mons->is_empty()) {
    bool found_first_monitor = false;
    for (int index = (mons->length()-1); index >= 0; index--) {
      MonitorInfo* monitor = mons->at(index);
      // ...
      if (monitor->owner() != NULL) {

        // 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

        const char *lock_state = "locked"; // assume we have the monitor locked
        if (!found_first_monitor && frame_count == 0) {
          markOop mark = monitor->owner()->mark();
          if (mark->has_monitor() &&
              mark->monitor() == thread()->current_pending_monitor()) {
            lock_state = "waiting to lock";
          }
        }

        found_first_monitor = true;
        print_locked_object_class_name(st, monitor->owner(), lock_state);
      }
    }
  }
}

objectMonitor.cpp

void ATTR ObjectMonitor::enter(TRAPS) {
  // ...
  { // Change java thread status to indicate blocked on monitor enter.

    // 1. Sets Java-level java.lang.Thread.State to BLOCKED.
    JavaThreadBlockedOnMonitorEnterState jtbmes(jt, this);

    // 2. Sets OSThread-level thread state to MONITOR_WAIT.
    OSThreadContendState osts(Self->osthread());

    // 3. Sets Thread-level thread state, transitioning from _thread_in_vm to _thread_blocked.
    //    Also does a safepoint check here.
    ThreadBlockInVM tbivm(jt);

    // 4. Sets current thread's pending monitor to this monitor
    Self->set_current_pending_monitor(this);

    // ...
  }
}

interfaceSupport.hpp

class ThreadBlockInVM : public ThreadStateTransition {
 public:
  ThreadBlockInVM(JavaThread *thread)
  : ThreadStateTransition(thread) {
    // Once we are blocked vm expects stack to be walkable
    thread->frame_anchor()->make_walkable(thread);
    trans_and_fence(_thread_in_vm, _thread_blocked);
  }
  ~ThreadBlockInVM() {
    trans_and_fence(_thread_blocked, _thread_in_vm);
    // We don't need to clear_walkable because it will happen automagically when we return to java
  }
};

interfaceSupport.hpp

  // transition_and_fence must be used on any thread state transition
  // where there might not be a Java call stub on the stack, in
  // particular on Windows where the Structured Exception Handler is
  // set up in the call stub. os::write_memory_serialize_page() can
  // fault and we can't recover from it on Windows without a SEH in
  // place.
  static inline void transition_and_fence(JavaThread *thread, JavaThreadState from, JavaThreadState to) {
    assert(thread->thread_state() == from, "coming from wrong thread state");
    assert((from & 1) == 0 && (to & 1) == 0, "odd numbers are transitions states");
    // Change to transition state (assumes total store ordering!  -Urs)
    thread->set_thread_state((JavaThreadState)(from + 1));

    // Make sure new state is seen by VM thread
    if (os::is_MP()) {
      if (UseMembar) {
        // Force a fence between the write above and read below
        OrderAccess::fence();
      } else {
        // Must use this rather than serialization page in particular on Windows
        InterfaceSupport::serialize_memory(thread);
      }
    }

    if (SafepointSynchronize::do_call_back()) {
      SafepointSynchronize::block(thread);
    }
    thread->set_thread_state(to);

    CHECK_UNHANDLED_OOPS_ONLY(thread->clear_unhandled_oops();)
  }

  void trans_and_fence(JavaThreadState from, JavaThreadState to) { transition_and_fence(_thread, from, to); }
2012-07-05 14:26:29
Full thread dump Java HotSpot(TM) Server VM (16.3-b01 mixed mode):


"httpSSLWorkerThread-10080-221" daemon prio=3 tid=0x09197400 nid=0x1c1 waiting for monitor entry [0x23d5b000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at casinomodule.util.TimeUtilImpl.synchronizeWithDatabase(TimeUtilImpl.java:93)
	- locked <0x75b432d8> (a casinomodule.util.TimeUtilImpl)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:58)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:42)
	...

   Locked ownable synchronizers:
	- None
	
	
	
"httpSSLWorkerThread-10080-134" daemon prio=3 tid=0x0b38a800 nid=0x16a waiting for monitor entry [0x258e2000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at casinomodule.util.TimeUtilImpl.synchronizeWithDatabase(TimeUtilImpl.java:93)
	- locked <0x75b432d8> (a casinomodule.util.TimeUtilImpl)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:58)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:42)
	...

   Locked ownable synchronizers:
	- None


"httpSSLWorkerThread-10080-107" daemon prio=3 tid=0x0912f800 nid=0x14c waiting for monitor entry [0x26260000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at casinomodule.util.TimeUtilImpl.synchronizeWithDatabase(TimeUtilImpl.java:93)
	- locked <0x75b432d8> (a casinomodule.util.TimeUtilImpl)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:58)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:42)
	...

   Locked ownable synchronizers:
	- None



"httpSSLWorkerThread-10080-99" daemon prio=3 tid=0x0b310000 nid=0x144 waiting for monitor entry [0x264e8000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at casinomodule.util.TimeUtilImpl.synchronizeWithDatabase(TimeUtilImpl.java:93)
	- waiting to lock <0x75b432d8> (a casinomodule.util.TimeUtilImpl)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:58)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:42)
	...

   Locked ownable synchronizers:
	- None


"httpSSLWorkerThread-10080-45" daemon prio=3 tid=0x0a647000 nid=0x10e waiting for monitor entry [0x275fe000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at casinomodule.util.TimeUtilImpl.synchronizeWithDatabase(TimeUtilImpl.java:93)
	- waiting to lock <0x75b432d8> (a casinomodule.util.TimeUtilImpl)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:58)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:42)
	...

   Locked ownable synchronizers:
	- None

2012-07-05 14:28:16
Full thread dump Java HotSpot(TM) Server VM (16.3-b01 mixed mode):


"httpSSLWorkerThread-10080-221" daemon prio=3 tid=0x09197400 nid=0x1c1 waiting for monitor entry [0x23d5b000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at casinomodule.util.TimeUtilImpl.synchronizeWithDatabase(TimeUtilImpl.java:93)
	- waiting to lock <0x75b432d8> (a casinomodule.util.TimeUtilImpl)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:58)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:42)
	...

   Locked ownable synchronizers:
	- None
	
	
"httpSSLWorkerThread-10080-134" daemon prio=3 tid=0x0b38a800 nid=0x16a waiting for monitor entry [0x258e2000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at casinomodule.util.TimeUtilImpl.synchronizeWithDatabase(TimeUtilImpl.java:93)
	- locked <0x75b432d8> (a casinomodule.util.TimeUtilImpl)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:58)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:42)
	...

   Locked ownable synchronizers:
	- None	
	

"httpSSLWorkerThread-10080-107" daemon prio=3 tid=0x0912f800 nid=0x14c waiting for monitor entry [0x26260000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at casinomodule.util.TimeUtilImpl.synchronizeWithDatabase(TimeUtilImpl.java:93)
	- waiting to lock <0x75b432d8> (a casinomodule.util.TimeUtilImpl)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:58)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:42)
	...

   Locked ownable synchronizers:
	- None


"httpSSLWorkerThread-10080-99" daemon prio=3 tid=0x0b310000 nid=0x144 waiting for monitor entry [0x264e8000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at casinomodule.util.TimeUtilImpl.synchronizeWithDatabase(TimeUtilImpl.java:93)
	- waiting to lock <0x75b432d8> (a casinomodule.util.TimeUtilImpl)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:58)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:42)
	...

   Locked ownable synchronizers:
	- None


"httpSSLWorkerThread-10080-45" daemon prio=3 tid=0x0a647000 nid=0x10e runnable [0x275fe000]
   java.lang.Thread.State: RUNNABLE
	at casinomodule.util.TimeUtilImpl.synchronizeWithDatabase(TimeUtilImpl.java:93)
	- locked <0x75b432d8> (a casinomodule.util.TimeUtilImpl)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:58)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:42)
	...

   Locked ownable synchronizers:
	- None

2012-07-06 13:21:08
Full thread dump Java HotSpot(TM) Server VM (16.3-b01 mixed mode):


"httpSSLWorkerThread-10080-221" daemon prio=3 tid=0x09197400 nid=0x1c1 runnable [0x23d5b000]
   java.lang.Thread.State: RUNNABLE
	at casinomodule.util.TimeUtilImpl.synchronizeWithDatabase(TimeUtilImpl.java:93)
	- locked <0x75b395d8> (a casinomodule.util.TimeUtilImpl)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:58)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:42)
	...

   Locked ownable synchronizers:
	- None

	
"httpSSLWorkerThread-10080-134" daemon prio=3 tid=0x0b38a800 nid=0x16a waiting for monitor entry [0x258e2000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at casinomodule.util.TimeUtilImpl.synchronizeWithDatabase(TimeUtilImpl.java:93)
	- locked <0x75b395d8> (a casinomodule.util.TimeUtilImpl)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:58)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:42)
	...

   Locked ownable synchronizers:
	- None	
	
	
"httpSSLWorkerThread-10080-107" daemon prio=3 tid=0x0912f800 nid=0x14c waiting for monitor entry [0x26260000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at casinomodule.util.TimeUtilImpl.synchronizeWithDatabase(TimeUtilImpl.java:93)
	- waiting to lock <0x75b395d8> (a casinomodule.util.TimeUtilImpl)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:58)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:42)
	...

   Locked ownable synchronizers:
	- None


"httpSSLWorkerThread-10080-99" daemon prio=3 tid=0x0b310000 nid=0x144 waiting for monitor entry [0x264e8000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at casinomodule.util.TimeUtilImpl.synchronizeWithDatabase(TimeUtilImpl.java:93)
	- waiting to lock <0x75b395d8> (a casinomodule.util.TimeUtilImpl)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:58)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:42)
	...

   Locked ownable synchronizers:
	- None


"httpSSLWorkerThread-10080-45" daemon prio=3 tid=0x0a647000 nid=0x10e waiting for monitor entry [0x275fe000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at casinomodule.util.TimeUtilImpl.synchronizeWithDatabase(TimeUtilImpl.java:93)
	- waiting to lock <0x75b395d8> (a casinomodule.util.TimeUtilImpl)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:58)
	at casinomodule.util.TimeUtilImpl.getTime(TimeUtilImpl.java:42)
	...

   Locked ownable synchronizers:
	- None
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment