Troubleshooting Deadlock Conditions With Monitor Locks In Java Virtual Machines

By 01

Tuesday, October 14, 2008

Introduction

In this article, I wanted to present a brief tutorial regarding troubleshooting deadlock conditions in JVMs. Before one can troubleshoot a deadlock condition, one needs to understand what it is; to this end, I have written a simple Java program called DeadLock.java, which is guaranteed to very quickly hit a deadlock condition between two threads shortly after starting. I present two mechanisms for troubleshooting deadlock conditions within a Sun JVM: thread dumps and jdb. There are several variations on using thread dump information to troubleshoot deadlocks that will be presented here.  I briefly touched on jdb and thread dumps in this article; we're going to use similar techniques here to troubleshoot deadlock conditions.

The Problem

Deadlocks can occur in the real world as easily as they can in the computer world; however, one would like to think that in the real world rational, sentient beings are capable of reasoning their way out of the deadlock. But, that is often wishful thinking. A deadlock occurs when two or more parties, actions, or entities are all waiting on an event(s) to be completed by one of the same parties, actions, or entities. But, since they are all waiting for something, none of the needed events ever occur or finish.

As an example, I will use DeadLock.java to create a deadlock condition between two Java threads. This program can be easily compiled with the following:

javac DeadLock.java

The DeadLock.java program defines three classes: DeadLock, Thread1, and Thread2.  The DeadLock class code looks like:

public class DeadLock
{
   private Object lock1 = new Object ();
   private Object lock2 = new Object ();
   private int x = 0;

   public void instanceMethod1 ()
   {
      synchronized (lock1)
      {
         synchronized (lock2)
         {
           x=x+1;
         }
      }
   }
   public void instanceMethod2 ()
   {
      synchronized (lock2)
      {
         synchronized (lock1)
         {
           x=x-1;
         }
      }
   }
   static public void main(String [] str)
   {
      DeadLock dl = new DeadLock();
      Thread1 t1 = new Thread1(dl);
      Thread2 t2 = new Thread2(dl);
      t1.start();
      t2.start();
      try {
        t1.join();
        t2.join();
      }
      catch(InterruptedException e)
      {
        e.printStackTrace();
      }
   }
}

The DeadLock class defines three instance variables: object1, object2, and x.  The object1 & object2 variables are simple Objects--these are used as Monitor locks.  A Monitor lock is the built-in Java language thread synchronization primitive; an in-depth discussion about this locking mechanisms is beyond the scope of this discussion--for more information about Monitor locks see this article.  The integer x is manipulated by instance methods, which are called by different threads.

The instance method instanceMethod1() attempts to lock object1, then lock object2, and increment x by one.  It then releases object2 and object1.  Note, I said that the method attempts to lock object1 & object2.  If for some reason object1 and object2 are already locked by something else, then the code will wait for the lock before proceeding. 

Likewise, the instanceMethod2() instance method will attempt to lock object2, lock object1, decrement x by one, release object2, and release object1.  The same rules about locking an object apply here.

Finally, in the main() method, the entry point to the program, an instance of DeadLock is created.  Then, an instance of a Thread1 object and a Thread2 object are created.  Each object is given a copy of the DeadLock object, d1, that was just created.  Then, Thread.start() of each object is called.  This results in the creation of two new Java threads.  The first thread will be running Thread1.run(); the second thread will be running thread2.run().

This brings us to the Thread1 class.  This class extends the java.lang.Thread class, which will create one new Java thread for each instance that is created as described in the last paragraph.  The Thread1 code looks like:

class Thread1 extends Thread
{
    private DeadLock dl;
    public Thread1(DeadLock lock)
    {
      super();
      dl = lock;
    }
    public void run()
    {
        System.out.println("Hello from a thread1!");
        while(true) dl.instanceMethod1();
    }
}

The Thread1 constructor takes a single DeadLock object as an argument; this is how our Thread1,t1, and Thread2, t2, objects are communicating.  The run Thread1.run() method announces itself to the world and then enters an infinite loop making repeated calls to DeadLock.instanceMethod1().  In a very similar fashion, Thread2 looks like:

class Thread2 extends Thread
{
    private DeadLock dl;
    public Thread2(DeadLock lock)
    {
      super();
      dl = lock;
    }
    public void run()
    {
        System.out.println("Hello from a thread2!");
        while(true) dl.instanceMethod2();

    }
}

The only major difference between Thread2 and Thread1 is that in Thread2.run(), the infinite loop repeatedly calls DeadLock.instanceMethod2().  The net result is this program creates two Java threads that both go into infinite loops calling DeadLock.instanceMethod1() & DeadLock.instanceMethod2(), respectively.  Meanwhile, the Java thread running the DeadLock.main() method will be waiting for these two threads to complete, which, of course, will never happen.

This program can be run with the following start script:

#!/bin/bash
. ./env.linux
export CLASSPATH=.
java -Xdebug -Xrunjdwp:transport=dt_socket,server=y,suspend=n,address=5002 DeadLock > out &
exit 0

The env.linux script sets up the environment for use with my JDK.  I also use this script to setup my environment for compiling from the command line without Ant.  When this program runs, it will very quickly encounter a deadlock scenerio.  There isn't really output to view; we need to look at the state of the individual threads using a debugger.  To do this, we are going to look at a JVM running DeadLock after the program has become deadlocked using jdb.  To attach jdb to this program, run the following:

jdb -connect com.sun.jdi.SocketAttach:hostname=localhost,port=5002

This should give you a command prompt where you can attach to the running program.  We can generate a list of running threads and look at which threads each program has locked as follows:

> threads
Group system:
  (java.lang.ref.Reference$ReferenceHandler)0x148 Reference Handler cond. waiting
  (java.lang.ref.Finalizer$FinalizerThread)0x149  Finalizer         cond. waiting
  (java.lang.Thread)0x14a                         Signal Dispatcher running
Group main:
  (java.lang.Thread)0x14c                         main              cond. waiting
  (Thread1)0x14d                                  Thread-0          waiting in a monitor
  (Thread2)0x14e                                  Thread-1          waiting in a monitor
> thread 0x14c
main[1] suspend
All threads suspended.
main[1] threadlocks
Monitor information for thread main:
  No monitors owned
   Waiting for monitor: instance of Thread1(name='Thread-0', id=333)
main[1] thread 0x14d
Thread-0[1] threadlocks
Monitor information for thread Thread-0:
  Owned monitor: instance of java.lang.Object(id=335)
   Waiting for monitor: instance of java.lang.Object(id=336)
Thread-0[1] thread 0x14e
Thread-1[1] threadlocks
Monitor information for thread Thread-1:
  Owned monitor: instance of java.lang.Object(id=336)
   Waiting for monitor: instance of java.lang.Object(id=335)
Thread-1[1] quit

The initial comand 'threads' generated a list of all the threads running in the JVM.  The only threads we are interested in are those in the main thread group: main, Thread-0, and Thread-1.  These are the thread running our DeadLock.main() method, Thread1.run(), and Thread2.run(), respectively.  From the states listed for each of these threads, we can see that the main thread is in a conditional wait state and the other two are each waiting to acquire a monitor lock.  The main thread is waiting for one of the Thread objects it created to end.  The other two threads are each waiting on a monitor that is currently locked by the other thread.  Corresponding to this information, the "threadlocks" command is called for each of the three threads in question.

We can see from the output that Thread-0 currently owns java.lang.Object(id=335) and is waiting to lock java.lang.Object(id=336).  At the same time, Thread-1 currently owns java.lang.Object(id=336) and is waiting to lock java.lang.Object(id=335).  Neither of these threads are going to get out of their current situation anytime soon.  In fact, neither ever will.  This is a classic deadlock scenerio.

If you as a Middleware Administrator come across this scenerio between threads in a web container, you need to pass it along to the developers.  Ideally, you'll have a couple of thread dumps showing line numbers to assist the developer.

Troubleshooting

In the introduction, I mentioned I would present to methods for troubleshooting deadlock conditions in a JVM: thread dumps and jdb.  The basic idea behind using jdb was outlined in the previous section in order to present the example.  Of course, this assumes that you had the remote debugging interface enabled.  If you do, then fire up your favorite Java debugger (I like jdb and jswat)--just get a dump of the currently running threads and the locks each thread owns or is waiting to acquire.  Some debuggers have a nice graphical tool for presenting this information.  If you are using a command line JVM such as jdb, it might be easier to draw things out on paper--to each their own.

For jdb, the following commands will be useful when troubleshooting deadlocks or any concurrency locking issues in Java:

threads -- Thread dump
thread tid -- switch to thread context tid (tid comes from the threads command)
suspend -- suspend all threads(needed before threadlock information can be run)
threadlocks -- print all Monitor locks that the current thread is interacting with
resume -- allow all threads to continue execution normally

The second option for troubleshooting locking conditions is to look at thread dumps.  The format of thread dumps are vendor specific; although, they all tend to look similar.  Thread dumps are generated in IBM & Sun JVMs on Solaris by issuing a "kill -QUIT pid" command.  For this article, a Sun Java 1.5 JVM is being used.  An IBM JVM's thread dump includes a monitor lock section that includes all of the information we just extracted with jdb.  If you are using an IBM JVM, I'd recommend this approach--it certainly seems much easier.  Sometimes, both vendors JVMs will report that deadlock conditions have been detected; however, this information isn't always reported. So, we cannot necessarily rely on that.  I'm going to present a technique that should work in every situation.

Full thread dump Java HotSpot(TM) Client VM (1.5.0_16-b02 mixed mode):

...

"Thread-1" prio=1 tid=0x08b52b30 nid=0x1d35 waiting for monitor entry [0xa9d20000..0xa9d20120]
        at DeadLock.instanceMethod2(DeadLock.java:51)
        - waiting to lock <0xaa6fd0d8> (a java.lang.Object)
        - locked <0xaa6fd0e0> (a java.lang.Object)
        at Thread2.run(DeadLock.java:26)

"Thread-0" prio=1 tid=0x08b525f0 nid=0x1d34 waiting for monitor entry [0xa9da0000..0xa9da0fa0]
        at DeadLock.instanceMethod1(DeadLock.java:41)
        - waiting to lock <0xaa6fd0e0> (a java.lang.Object)
        - locked <0xaa6fd0d8> (a java.lang.Object)
        at Thread1.run(DeadLock.java:12)

...

"main" prio=1 tid=0x08a13068 nid=0x1d2a in Object.wait() [0xbfa38000..0xbfa38578]
        at java.lang.Object.wait(Native Method)
        - waiting on <0xaa6fea58> (a Thread1)
        at java.lang.Thread.join(Thread.java:1095)
        - locked <0xaa6fea58> (a Thread1)
        at java.lang.Thread.join(Thread.java:1148)
        at DeadLock.main(DeadLock.java:65)

As we know, the DeadLock program running in a JVM has three Java threads that are of interest to us.  These three threads are listed above: main, Thread-0, and Thread-1.  The stack trace information tells us all the important information we need to identify each thread's state at the moment the thread dump was generated.  Note, every thread is suspended for a few milliseconds while the thread dump is generated.  First, let's look at the main thread running the main() method; you can see that the thread is waiting in a Thread.join() method call on line 65 of DeadLock.java.  This is the t1.join() method call in the main() method.  Next, let's look at Thread-0.  Thread-0  is running the Thread.run() method.  We can see that it is currently in a "waiting for monitor entry" state on line 41 of DeadLock.java.  This corresponds to the "syncronizes(lock2)" call; so, we can summerize that instanceMethod1() was able to acquire the lock1 object (from the code).  Likewise, we can see that Thread-1 is running the Thread2.run() method.  It is currently in a "waiting for monitor entry" state on line 51 of DeadLock.java in the instanceMethod2() method.  This corresponds to the "syncronized(lock1)" call; so, we can once again surmize from the code that Thread-1 has acquired lock2 and is attempting to lock lock1--this is the exact opposite state of Thread-0.  So, we can see our deadlock condition: Thread-0 is waiting on a lock that is owned by Thread-1 and Thread-1 is waiting on a lock that is owned by Thread-0--our deadlock scenerio.

Now, if you look at the Thread-0 & Thread-1 entries, you'll notice that it conveniently tells you which Monitors the thread has acquired and where in the stack it aquired them.  It also reports what Monitors the thread is waiting to acquire.  This is very helpful information, if it is present.  It may not always be there though.  But, if it is there, then by all means use it.

Again, these thread dump snippets were captured from a Sun Java 1.5 JVM running on Linux.  At the bottom of the thread dump, the following information was printed:

Found one Java-level deadlock:
=============================
"Thread-1":
  waiting to lock monitor 0x08a72a44 (object 0xaa6fd0d8, a java.lang.Object),
  which is held by "Thread-0"
"Thread-0":
  waiting to lock monitor 0x08a72a04 (object 0xaa6fd0e0, a java.lang.Object),
  which is held by "Thread-1"

Java stack information for the threads listed above:
===================================================
"Thread-1":
        at DeadLock.instanceMethod2(DeadLock.java:51)
        - waiting to lock <0xaa6fd0d8> (a java.lang.Object)
        - locked <0xaa6fd0e0> (a java.lang.Object)
        at Thread2.run(DeadLock.java:26)
"Thread-0":
        at DeadLock.instanceMethod1(DeadLock.java:41)
        - waiting to lock <0xaa6fd0e0> (a java.lang.Object)
        - locked <0xaa6fd0d8> (a java.lang.Object)
        at Thread1.run(DeadLock.java:12)

Found 1 deadlock.

That is certainly a helpful bit of information.  And, it is far easier to use this information to diagnose a deadlock than anything I've presented thus far.  But, again, you aren't always this lucky.

Closing Thoughts

Whenever you are troubleshooting unresponsive JVMs, be mindful that you may be looking at a locking issue.  There are five approachs to troubleshooting deadlock situations that I've presented here:

  1. Java debugger (jdb, JSwat, etc)
  2. Thread dumps -- using information present in each Thread's stack dump
  3. Thread dumps -- consolidated Monitor information for each thread (always available in an IBM JVM)
  4. Thread dumps -- per-thread, stack-trace, in-line, lock information
  5. Thread dumps -- information printed about detected deadlocks (not always present) 

The exact information and format presented by a thread dump is vendor specific.  Likewise, the way a Java debugger presents information is debugger-vendor specific.  As a Middleware Administrator, the most likely scenerio upon finding a deadlock is contacting a development team or the vendor that supports the product. 

As always, I hope you have found this useful.


Reference
[1]http://en.wikipedia.org/wiki/Deadlock
[2]http://www.artima.com/insidejvm/ed2/threadsynch2.html
[3]http://www.cs.drexel.edu/~shartley/conProgJava/monitors.html
[4]http://www.ibm.com/developerworks/java
[5]http://java.sun.com
[6]http://java.sun.com/j2se/1.5.0/docs/tooldocs/solaris/jdb.html
[7]http://code.google.com/p/jswat/

 

©2008 www.thinkmiddleware.com

All copyrights & trademarks belong to their respective owners.

The comments and opinions herein are that of the author.

Please direct all comments to 01.

While the information presented on this web site is believed to be correct, the author is not responsible for any damage, loss of data, or other issues that may arise from using the information posted here.

Made with CityDesk
Last Modified: Sunday, 09-Nov-2008 10:48:57 MST