Multiple Java threads seem to have locked the same object monitor from the thread dumps

[David Holmes]

Hi Kris,

The scenario you outline seems plausible. There are numerous inherent 
races when it comes to this kind of observation of thread state because 
the changes of state are not atomically performed (and can not be). The 
inference logic for "have I locked this monitor" is quite simple and I 
did fix one bug in this area about 6 years ago.

  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);
   }
}

Looking at this now the obvious (and hence undoubtedly wrong :) ) 
solution would seem to be add a check for the owner() against the thread().

David
-----

On 12/07/2012 8:55 PM, Krystal Mok wrote:
> Hi,
>
> Someone sent me a couple of thread dumps, and what's strange in them is
> that there are multiple threads claiming to have locked the same object
> monitor.
> There's at most only one of them actually in the
> (java.lang.Thread.State-level) RUNNABLE state, which is correct. The
> ones that claim to have locked but are in BLOCKED state apparent haven't
> really acquired the lock yet.
> Excerpts of the dumps are available here: [1]
>
> There are two other discussion threads on this topic [2][3].
>
> Reading through the related code [4], the only scenario that could
> result in such thread dump seems to be:
> 1. The VM is going into a safepoint caused by the VM_PrintThreads VM
> operation;
> 2. A thread is (re-)entering a synchronized block with
> ObjectMonitor::enter().
>    It has already set the correct thread state at Java-level and
> OSThread-level, and then it gets blocked in the safepoint callback
> before setting the current pending monitor;
> 3. VM_PrintThreads eventually calls javaVFrame::print_lock_info_on(),
> where it checks if it's the first frame and the monitor matches the
> thread's current pending one.
>    Because the current pending monitor wasn't set yet, this check fails,
> and the lock state message defaults to "locked".
>
> I wonder if such behavior implies we should set the pending monitor
> before the safepoint callback.
>
> And, could there be other scenarios that would produce such thread dumps?
>
> Regards,
> Kris
>
> [1]: https://gist.github.com/3097193#file_thread_dumps.md
> [2]:
> http://stackoverflow.com/questions/9536975/multiple-java-threads-seemingly-locking-same-monitor
> [3]: https://forums.oracle.com/forums/thread.jspa?messageID=9952796
> [4]: https://gist.github.com/3097193#file_notes.md