13.7.深入理解jstack日志

Posted 2021-09-06 to.to

13.7.深入理解jstack日志

转自：https://blog.csdn.net/iteye_5603/article/details/82652200

在分析线上问题时常使用到jstack 命令将当时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"队列。