Thread Dump线程死锁检测工具（JStack）的使用详解-白红宇

Thread Dump线程死锁检测工具（JStack）的使用详解

阅读量：6408 次

发布时间：2019-06-23

本文共 9281 字，大约阅读时间需要 30 分钟。

Thread Dump用来诊断应用的问题，可以用来发现死锁线程等等。通过它可以得到线程，线程运行状态、标识、调用的堆栈，堆栈包含完整的类名，所执行的方法，以及源代码所在的行数等等信息。

接下来，需要考虑如何获得Thread Dump的问题。首先，可以通过jps查看java的进程信息，从而获得java进程的进程号。也可以用top动态观察CPU使用情况分析进程情况。然后通过jdk自带的工具jstack进行分析。jstack <pid> >> filename 可以将pid对应的java进程的线程使用情况写到后面的file中去。

如下列代码：

package thread;/** * Created by zhubo on 2017/8/21. */public class TestJstack {    final static Object resource_1 = new Object();    final static Object resource_2 = new Object();    public static void main(String[] args) {        Thread t1 = new Thread("t1"){            public void run(){                synchronized (resource_1){                    try{                        Thread.sleep(3000);                    }catch (InterruptedException e){                    }                    System.out.println("locked resource_1");                    synchronized(resource_2){                        System.out.println("thread t1 done.");                    }                }            }        };        Thread t2 = new Thread("t2"){            public void run(){                synchronized (resource_2){                    System.out.println("locked resource_2");                    try{                        Thread.sleep(3000);                    }catch (InterruptedException e){                    }                    synchronized (resource_1){                        System.out.println("thread t2 done.");                    }                }            }        };        t1.start();        t2.start();    }}

通过以上的工具使用完毕后可以得到Thread Dump的快照

[root@linux1 ~]# jstack -l 33572017-08-21 17:04:45Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.11-b03 mixed mode):"Attach Listener" #11 daemon prio=9 os_prio=0 tid=0x00007fbb14001000 nid=0xd55 waiting on condition [0x0000000000000000]   java.lang.Thread.State: RUNNABLE   Locked ownable synchronizers:	- None"DestroyJavaVM" #10 prio=5 os_prio=0 tid=0x00007fbb3c008800 nid=0xd1e waiting on condition [0x0000000000000000]   java.lang.Thread.State: RUNNABLE   Locked ownable synchronizers:	- None"t2" #9 prio=5 os_prio=0 tid=0x00007fbb3c162800 nid=0xd28 waiting for monitor entry [0x00007fbb2c4d2000]   java.lang.Thread.State: BLOCKED (on object monitor)	at thread.TestJstack$2.run(TestJstack.java:37)	- waiting to lock <0x00000000f08b9e50> (a java.lang.Object)	- locked <0x00000000f08b9e60> (a java.lang.Object)   Locked ownable synchronizers:	- None"t1" #8 prio=5 os_prio=0 tid=0x00007fbb3c161000 nid=0xd27 waiting for monitor entry [0x00007fbb2c5d3000]   java.lang.Thread.State: BLOCKED (on object monitor)	at thread.TestJstack$1.run(TestJstack.java:21)	- waiting to lock <0x00000000f08b9e60> (a java.lang.Object)	- locked <0x00000000f08b9e50> (a java.lang.Object)   Locked ownable synchronizers:	- None"Service Thread" #7 daemon prio=9 os_prio=0 tid=0x00007fbb3c0cf800 nid=0xd25 runnable [0x0000000000000000]   java.lang.Thread.State: RUNNABLE   Locked ownable synchronizers:	- None"C1 CompilerThread1" #6 daemon prio=9 os_prio=0 tid=0x00007fbb3c0cc000 nid=0xd24 waiting on condition [0x0000000000000000]   java.lang.Thread.State: RUNNABLE   Locked ownable synchronizers:	- None"C2 CompilerThread0" #5 daemon prio=9 os_prio=0 tid=0x00007fbb3c0ca000 nid=0xd23 waiting on condition [0x0000000000000000]   java.lang.Thread.State: RUNNABLE   Locked ownable synchronizers:	- None"Signal Dispatcher" #4 daemon prio=9 os_prio=0 tid=0x00007fbb3c0c7800 nid=0xd22 runnable [0x0000000000000000]   java.lang.Thread.State: RUNNABLE   Locked ownable synchronizers:	- None"Finalizer" #3 daemon prio=8 os_prio=0 tid=0x00007fbb3c098800 nid=0xd21 in Object.wait() [0x00007fbb2cdfc000]   java.lang.Thread.State: WAITING (on object monitor)	at java.lang.Object.wait(Native Method)	- waiting on <0x00000000f08062d8> (a java.lang.ref.ReferenceQueue$Lock)	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:142)	- locked <0x00000000f08062d8> (a java.lang.ref.ReferenceQueue$Lock)	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:158)	at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)   Locked ownable synchronizers:	- None"Reference Handler" #2 daemon prio=10 os_prio=0 tid=0x00007fbb3c094800 nid=0xd20 in Object.wait() [0x00007fbb2cefd000]   java.lang.Thread.State: WAITING (on object monitor)	at java.lang.Object.wait(Native Method)	- waiting on <0x00000000f0805d48> (a java.lang.ref.Reference$Lock)	at java.lang.Object.wait(Object.java:502)	at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:157)	- locked <0x00000000f0805d48> (a java.lang.ref.Reference$Lock)   Locked ownable synchronizers:	- None"VM Thread" os_prio=0 tid=0x00007fbb3c08f800 nid=0xd1f runnable "VM Periodic Task Thread" os_prio=0 tid=0x00007fbb3c0d5000 nid=0xd26 waiting on condition JNI global references: 7Found one Java-level deadlock:============================="t2":  waiting to lock monitor 0x00007fbb200062c8 (object 0x00000000f08b9e50, a java.lang.Object),  which is held by "t1""t1":  waiting to lock monitor 0x00007fbb200038d8 (object 0x00000000f08b9e60, a java.lang.Object),  which is held by "t2"Java stack information for the threads listed above:==================================================="t2":	at thread.TestJstack$2.run(TestJstack.java:37)	- waiting to lock <0x00000000f08b9e50> (a java.lang.Object)	- locked <0x00000000f08b9e60> (a java.lang.Object)"t1":	at thread.TestJstack$1.run(TestJstack.java:21)	- waiting to lock <0x00000000f08b9e60> (a java.lang.Object)	- locked <0x00000000f08b9e50> (a java.lang.Object)Found 1 deadlock.

jstack Dump 日志文件中的线程状态

dump 文件里，值得关注的线程状态有：

死锁，Deadlock（重点关注）

执行中，Runnable

等待资源，Waiting on condition（重点关注）

等待获取监视器，Waiting on monitor entry（重点关注）

暂停，Suspended

对象等待中，Object.wait() 或 TIMED_WAITING

阻塞，Blocked（重点关注）

停止，Parked

综合示范一：Waiting to lock 和 Blocked

实例如下：

"t1" #8 prio=5 os_prio=0 tid=0x00007fbb3c161000 nid=0xd27 waiting for monitor entry [0x00007fbb2c5d3000]   java.lang.Thread.State: BLOCKED (on object monitor)	at thread.TestJstack$1.run(TestJstack.java:21)	- waiting to lock <0x00000000f08b9e60> (a java.lang.Object)	- locked <0x00000000f08b9e50> (a java.lang.Object)   Locked ownable synchronizers:	- None

1）线程状态是 Blocked，阻塞状态。说明线程等待资源超时！

2）“ waiting to lock <0x00000000f08b9e60>”指，线程在等待给这个 0x00000000f08b9e60地址上锁（英文可描述为：trying to obtain 0x00000000f08b9e60 lock）。

3）在 dump 日志里查找字符串 0x00000000f08b9e60，发现有大量线程都在等待给这个地址上锁。如果能在日志里找到谁获得了这个锁（如locked < 0x00000000f08b9e60 >），就可以顺藤摸瓜了。

4）“waiting for monitor entry”说明此线程通过 synchronized(obj) {……} 申请进入了临界区，从而进入了下图1中的“Entry Set”队列，但该 obj 对应的 monitor 被其他线程拥有，所以本线程在 Entry Set 队列中等待。

5）第一行里，"t1"是 Thread Name 。tid指Java Thread id。nid指native线程的id。prio是线程优先级。[0x00007fbb2c5d3000]是线程栈起始地址。

Dump文件中的线程状态含义及注意事项

含义如下所示：

Deadlock：死锁线程，一般指多个线程调用间，进入相互资源占用，导致一直等待无法释放的情况。

Runnable：一般指该线程正在执行状态中，该线程占用了资源，正在处理某个请求，有可能正在传递SQL到数据库执行，有可能在对某个文件操作，有可能进行数据类型等转换。

Waiting on condition：等待资源，或等待某个条件的发生。具体原因需结合 stacktrace来分析。
- 如果堆栈信息明确是应用代码，则证明该线程正在等待资源。一般是大量读取某资源，且该资源采用了资源锁的情况下，线程进入等待状态，等待资源的读取。
- 又或者，正在等待其他线程的执行等。
- 如果发现有大量的线程都在处在 Wait on condition，从线程 stack看，正等待网络读写，这可能是一个网络瓶颈的征兆。因为网络阻塞导致线程无法执行。
  - 一种情况是网络非常忙，几乎消耗了所有的带宽，仍然有大量数据等待网络读写；
  - 另一种情况也可能是网络空闲，但由于路由等问题，导致包无法正常的到达。
- 另外一种出现 Wait on condition的常见情况是该线程在 sleep，等待 sleep的时间到了时候，将被唤醒。

Blocked：线程阻塞，是指当前线程执行过程中，所需要的资源长时间等待却一直未能获取到，被容器的线程管理器标识为阻塞状态，可以理解为等待资源超时的线程。

Waiting for monitor entry 和 in Object.wait()：Monitor是 Java中用以实现线程之间的互斥与协作的主要手段，它可以看成是对象或者 Class的锁。每一个对象都有，也仅有一个 monitor。从下图1中可以看出，每个 Monitor在某个时刻，只能被一个线程拥有，该线程就是 “Active Thread”，而其它线程都是 “Waiting Thread”，分别在两个队列 “ Entry Set”和 “Wait Set”里面等候。在 “Entry Set”中等待的线程状态是 “Waiting for monitor entry”，而在 “Wait Set”中等待的线程状态是 “in Object.wait()”。

图1 A Monitor

综合示范三：in Obejct.wait() 和 TIMED_WAITING

实例如下：

"RMI RenewClean-[172.16.5.19:28475]" daemon prio=10 tid=0x0000000041428800 nid=0xb09 in Object.wait() [0x00007f34f4bd0000]   java.lang.Thread.State: TIMED_WAITING (on object monitor)at java.lang.Object.wait(Native Method)- waiting on <0x00000000aa672478> (a java.lang.ref.ReferenceQueue$Lock)at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)- locked <0x00000000aa672478> (a java.lang.ref.ReferenceQueue$Lock)at sun.rmi.transport.DGCClient$EndpointEntry$RenewCleanThread.run(DGCClient.java:516)at java.lang.Thread.run(Thread.java:662)

1）“TIMED_WAITING (on object monitor)”，对于本例而言，是因为本线程调用了 java.lang.Object.wait(long timeout) 而进入等待状态。

2）“Wait Set”中等待的线程状态就是“ in Object.wait() ”。当线程获得了 Monitor，进入了临界区之后，如果发现线程继续运行的条件没有满足，它则调用对象（一般就是被 synchronized 的对象）的 wait() 方法，放弃了 Monitor，进入 “Wait Set”队列。只有当别的线程在该对象上调用了 notify() 或者 notifyAll() ，“ Wait Set”队列中线程才得到机会去竞争，但是只有一个线程获得对象的 Monitor，恢复到运行态。

3）RMI RenewClean 是 DGCClient 的一部分。指的是 Distributed GC，即分布式垃圾回收。

4）请注意，是先 locked <0x00000000aa672478>，后 waiting on <0x00000000aa672478>，之所以先锁再等同一个对象，请看下面它的代码实现：

static private class  Lock { };private Lock lock = new Lock();public Reference
     remove(long timeout){    synchronized (lock) {        Reference
     r = reallyPoll();        if (r != null) return r;        for (;;) {            lock.wait(timeout);            r = reallyPoll();            ……       }}

即，线程的执行中，先用 synchronized 获得了这个对象的 Monitor（对应于 locked <0x00000000aa672478> ）；当执行到 lock.wait(timeout);，线程就放弃了 Monitor 的所有权，进入“Wait Set”队列（对应于 waiting on <0x00000000aa672478> ）。

5）从堆栈信息看，是正在清理 remote references to remote objects ，引用的租约到了，分布式垃圾回收在逐一清理呢。

转载于:https://my.oschina.net/LucasZhu/blog/1518175

你可能感兴趣的文章

windows下启动mysql服务的命令行启动和手动启动方法