13.7.深入理解jstack日志

古城微笑少年丶 2022-09-04 14:43 132阅读 0赞

## 13.7.深入理解jstack日志 ##

转自：https://blog.csdn.net/iteye\_5603/article/details/82652200

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

**首先要清楚线程的状态**  
线程的状态有：**new、runnable、running、waiting、timed\_waiting、blocked、dead**  
线程状态变迁图：  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3RvdG8xMjk3NDg4NTA0_size_16_color_FFFFFF_t_70_pic_center]  
**各状态说明：**  
**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()"  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3RvdG8xMjk3NDg4NTA0_size_16_color_FFFFFF_t_70_pic_let]  
**最后通过示例来实践一下**  
**示例一**：描述Blocked 和 Waiting to lock  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3RvdG8xMjk3NDg4NTA0_size_16_color_FFFFFF_t_70_pic_left]  
执行后程序输出：  
Thread\[main,5,main\]  
说明主线程先进入同步代码块，获取到thread2对象上的锁。  
通过jstack输出结果：  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3RvdG8xMjk3NDg4NTA0_size_16_color_FFFFFF_t_70_pic_left 1]  
先说明下日志格式：  
"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  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3RvdG8xMjk3NDg4NTA0_size_16_color_FFFFFF_t_70_pic_left 2]  
jstack日志输出结果：  
![在这里插入图片描述][cac6c8b91a5d4bd0b230162402265dc9.png_pic_left]

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

**示例三**：描述Object.wait()  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3RvdG8xMjk3NDg4NTA0_size_16_color_FFFFFF_t_70_pic_left 3]  
程序输出结果：

Thread[thread2,5,main]
    Thread[main,5,main]

说明线程thread2先进入同步代码块，获取到thread2对象上的锁。  
jstack日志输出结果：  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3RvdG8xMjk3NDg4NTA0_size_16_color_FFFFFF_t_70_pic_left 4]  
可以看出：线程thread2的状态是"Waiting", 正在"in Object.wait()"。表明该线程在获取到对象锁后，调用obj.wait()方法，放弃了锁，进入了"Wait Set"队列。

[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3RvdG8xMjk3NDg4NTA0_size_16_color_FFFFFF_t_70_pic_center]: /images/20220829/bb8fec404750444a839a79baccb0f08a.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3RvdG8xMjk3NDg4NTA0_size_16_color_FFFFFF_t_70_pic_let]: /images/20220829/f457c5767f0243afb31cdb335655425c.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3RvdG8xMjk3NDg4NTA0_size_16_color_FFFFFF_t_70_pic_left]: /images/20220829/dc1d9f882e8f4c65a517f29068156051.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3RvdG8xMjk3NDg4NTA0_size_16_color_FFFFFF_t_70_pic_left 1]: /images/20220829/f80f83574143460b81f84d61bae0f051.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3RvdG8xMjk3NDg4NTA0_size_16_color_FFFFFF_t_70_pic_left 2]: /images/20220829/7dbcffc3fd1f40428de7b7f2e8d438ba.png
[cac6c8b91a5d4bd0b230162402265dc9.png_pic_left]: /images/20220829/24b4343a0c374504a7f24133f2c8ee50.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3RvdG8xMjk3NDg4NTA0_size_16_color_FFFFFF_t_70_pic_left 3]: /images/20220829/7a4e4ed9c5ea4f1a857e79b3c43440b3.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3RvdG8xMjk3NDg4NTA0_size_16_color_FFFFFF_t_70_pic_left 4]: /images/20220829/c382355d1a564f1f8ef26aa2da9a3dfb.png