如何分析Java虚拟机死锁

到目前为止，我认为分析Java代码问题的最有效的工具仍然是java thread dump，原因是：

1.任何操作系统平台下都可以使用。

2.在多数情况下，可以在生产环境中使用。

3.和操作系统提供的工具相比，java thread dump给出的信息是直白的，直接对应到应用代码。

4.它对被分析的系统干扰很小，因此能反应真实的问题。而其它很多profiling或Instrument工具本身对JVM运行有很大的干扰，经常不能暴露出真正的问题，而且这种工具不能用于生产系统。

我觉得在通常情况下分析Java虚拟机死锁比分析内存泄漏要容易的多。因为死锁发生时，JVM通常处于挂起状态(hang住了)，thread dump可以给出静态稳定的信息，查找死锁只需要查找有问题的线程。而内存泄漏的问题却很难界定，一个运行的JVM里有无数对象存在，只有写程序的人才知 道哪些对象是垃圾，而哪些不是，而且对象的引用关系非常复杂，很难得到一份清晰的对象引用图。

Java虚拟机死锁发生时，从操作系统上观察，虚拟机的CPU占用率为零，很快会从top或prstat的输出中消失。这时你就可以收集 thread dump了，Unix/Linux 下是kill -3 <JVM pid>，在Windows下可以在JVM的console窗口上敲Ctrl-Break。根据不同的设置，thread dump会输出到当前控制台上或应用服务器的日志里。

拿到java thread dump后，你要做的就是查找"waiting for monitor entry"的thread，如果大量thread都在等待给同一个地址上锁（因为对于Java，一个对象只有一把锁），这说明很可能死锁发生了。比如：

1. "service-j2ee"  prio= 5  tid= 0x024f1c28  nid= 0x125  waiting  for  monitor entry  
2. [62a3e000..62a3f690]  
3. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: at  
4. com.sun.enterprise.resource.IASNonSharedResourcePool.internalGetResource(IASNonS  
5. haredResourcePool.java: 625 )  
6. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: - waiting to  
7. lock < 0x965d8110 > (a com.sun.enterprise.resource.IASNonSharedResourcePool)  
8. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: at  
9. com.sun.enterprise.resource.IASNonSharedResourcePool.getResource(IASNonSharedRes  
10. ourcePool.java: 520 )  
11. ................ 

为了确定问题，常常需要在隔两分钟后再次收集一次thread dump，如果得到的输出相同，仍然是大量thread都在等待给同一个地址上锁，那么肯定是死锁了。

如何找到当前持有锁的线程是解决问题的关键。方法是搜索thread dump，查找"locked <0x965d8110>"， 找到持有锁的线程。

 

1. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr:  "Thread-20"  daemon prio= 5  tid= 0x01394f18  
2. nid= 0x109  runnable [6716f000..6716fc28]  
3. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: at  
4. java.net.SocketInputStream.socketRead0(Native Method)  
5. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: at  
6. java.net.SocketInputStream.read(SocketInputStream.java: 129 )  
7. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: at oracle.net.ns.Packet.receive(Unknown  
8. Source)  
9. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: at  
10. oracle.net.ns.DataPacket.receive(Unknown Source)  
11. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: at  
12. oracle.net.ns.NetInputStream.getNextPacket(Unknown Source)  
13. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: at  
14. oracle.net.ns.NetInputStream.read(Unknown Source)  
15. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: at  
16. oracle.net.ns.NetInputStream.read(Unknown Source)  
17. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: at  
18. oracle.net.ns.NetInputStream.read(Unknown Source)  
19. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: at  
20. oracle.jdbc.ttc7.MAREngine.unmarshalUB1(MAREngine.java: 929 )  
21. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: at  
22. oracle.jdbc.ttc7.MAREngine.unmarshalSB1(MAREngine.java: 893 )  
23. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: at  
24. oracle.jdbc.ttc7.Ocommoncall.receive(Ocommoncall.java: 106 )  
25. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: at  
26. oracle.jdbc.ttc7.TTC7Protocol.logoff(TTC7Protocol.java: 396 )  
27. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: - locked < 0x954f47a0 > (a  
28. oracle.jdbc.ttc7.TTC7Protocol)  
29. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: at  
30. oracle.jdbc.driver.OracleConnection.close(OracleConnection.java: 1518 )  
31. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: - locked < 0x954f4520 > (a  
32. oracle.jdbc.driver.OracleConnection)  
33. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: at  
34. com.sun.enterprise.resource.JdbcUrlAllocator.destroyResource(JdbcUrlAllocator.java: 122 )  
35. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: at  
36. com.sun.enterprise.resource.IASNonSharedResourcePool.destroyResource(IASNonSharedResourcePool.java: 8  
37. 72 )  
38. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: at  
39. com.sun.enterprise.resource.IASNonSharedResourcePool.resizePool(IASNonSharedResourcePool.java: 1086 )  
40. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: - locked < 0x965d8110 > (a  
41. com.sun.enterprise.resource.IASNonSharedResourcePool)  
42. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: at  
43. com.sun.enterprise.resource.IASNonSharedResourcePool$Resizer.run(IASNonSharedResourcePool.java: 1178 )  
44. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: at  
45. java.util.TimerThread.mainLoop(Timer.java: 432 )  
46. [ 27 /Jun/ 2006 : 10 : 03 : 08 ] WARNING ( 26140 ): CORE3283: stderr: at  
47. java.util.TimerThread.run(Timer.java: 382 ) 

在这个例子里，持有锁的线程在等待Oracle返回结果，却始终等不到响应，因此发生了死锁。

如果持有锁的线程还在等待给另一个对象上锁，那么还是按上面的办法顺藤摸瓜，直到找到死锁的根源为止。

另外，在thread dump里还会经常看到这样的线程，它们是等待一个条件而主动放弃锁的线程。
例如：

1. "Thread-1"  daemon prio= 5  tid= 0x014e97a8  nid= 0x80  in Object.wait() [68c6f000..68c6fc28]  
2. at java.lang.Object.wait(Native Method)  
3. - waiting on < 0x95b07178 > (a java.util.LinkedList)  
4. at com.iplanet.ias.util.collection.BlockingQueue.remove(BlockingQueue.java: 258 )  
5. - locked < 0x95b07178 > (a java.util.LinkedList)  
6. at com.iplanet.ias.util.threadpool.FastThreadPool$ThreadPoolThread.run(FastThreadPool.java: 241 )  
7. at java.lang.Thread.run(Thread.java: 534 ) 

有时也会需要分析这类线程，尤其是线程等待的条件。

其实，Java thread dump并不只用于分析死锁，其它Java应用运行时古怪的行为都可以用thread dump来分析。

最后，在Java SE 5里，增加了jstack的工具，也可以获取thread dump。在Java SE 6里， 通过jconsole的图形化工具也可以方便地查找涉及object monitors 和java.util.concurrent.locks死锁。