深入理解jstack日志

在分析线上问题时常使用到jstack <PID>命令将当时Java应用程序的线程堆栈dump出来。
面对jstack 日志，我们如何查看？

 

首先要清楚线程的状态
线程的状态有：new、runnable、running、waiting、timed_waiting、blocked、dead
线程状态变迁图：

 

 

各状态说明：
New: 当线程对象创建时存在的状态，此时线程不可能执行；
Runnable：当调用thread.start()后，线程变成为Runnable状态。只要得到CPU，就可以执行；
Running：线程正在执行；
Waiting：执行thread.join()或在锁对象调用obj.wait()等情况就会进该状态，表明线程正处于等待某个资源或条件发生来唤醒自己；
Timed_Waiting：执行Thread.sleep(long)、thread.join(long)或obj.wait(long)等就会进该状态，与Waiting的区别在于Timed_Waiting的等待有时间限制；
Blocked：如果进入同步方法或同步代码块，没有获取到锁，则会进入该状态；
Dead：线程执行完毕，或者抛出了未捕获的异常之后，会进入dead状态，表示该线程结束

 

其次，对于jstack日志，我们要着重关注如下关键信息
Deadlock：表示有死锁
Waiting on condition：等待某个资源或条件发生来唤醒自己。具体需要结合jstacktrace来分析，比如线程正在sleep，网络读写繁忙而等待
Blocked：阻塞 Waiting on monitor entry：在等待获取锁
in Object.wait()：获取锁后又执行obj.wait()放弃锁 
对于Waiting on monitor entry 和 in Object.wait()的详细描述：Monitor是 Java中用以实现线程之间的互斥与协作的主要手段，它可以看成是对象或者 Class的锁。每一个对象都有，也仅有一个 monitor。从下图中可以看出，每个 Monitor在某个时刻，只能被一个线程拥有，该线程就是 "Active Thread"，而其它线程都是 "Waiting Thread"，分别在两个队列 " Entry Set"和 "Wait Set"里面等候。在 "Entry Set"中等待的线程状态是 "Waiting for monitor entry"，而在 "Wait Set"中等待的线程状态是 "in Object.wait()"

 

 

最后通过示例来实践一下
示例一：描述 Blocked 和 Waiting to lock 

 

执行后程序输出：
Thread[main,5,main]
说明主线程先进入同步代码块，获取到thread2对象上的锁。
通过jstack输出结果：

先说明下日志格式：
"thread2"为线程名称，在平时创建线程或线程池时请务必取一个见明之义的线程名称，方便排查问题；
prio=6：线程优先级，不用关心；
tid=0x0000000006540800：线程id，不用关心；
nid=0x2be4：操作系统映射的线程id, 非常关键，后面再使用jstack时补充；
waiting for monitor entry：表示线程正在等待获取锁
0x0000000006dbf000：线程栈起始地址

 

从jstack日志中，可以看到：主线程获取到thread2对象上的锁，因此正在执行sleep操作，状态为TIMED_WAINTING, 而thread2由于未获取到thread2对象上的锁，因此处于BLOCKED状态。
再细看，thread2 正在"waiting to lock <0x00000000d719d280>"，即试图在地址为0x00000000d719d280所在的对象获取锁，而该锁却被main线程占有（locked <0x00000000d719d280>）。main线程正在"waiting on condition"，说明正在等待某个条件触发，由jstacktrace来看，此线程正在sleep。
经验：如果在jstack日志发现大量的线程在waiting to lock 某个地址，只要能查到哪个线程获取到锁就可以方便定位问题了

 

示例二：描述waiting on condition

]

jstack日志输出结果：

从日志中可以看到，main线程的状态是Waiting，正在"waiting on condition"来唤醒自己。
结合jstackstrace日志来看，"parking to wait for <0x00000000d719ba70> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)"说明在调用ArrayBlockingQueue.put()阻塞了。

 

示例三：描述Object.wait()

程序输出结果：
Thread[thread2,5,main]
Thread[main,5,main]
说明线程thread2先进入同步代码块，获取到thread2对象上的锁。
jstack日志输出结果：

 

可以看出：线程thread2的状态是"Waiting", 正在"in Object.wait()"。表明该线程在获取到对象锁后，调用obj.wait()方法，放弃了锁，进入了"Wait Set"队列。