使用jstack命令，排查线程死锁问题

心已赠人 2023-02-20 02:11 19阅读 0赞

# 概述 #

使用`jstack`命令，排查线程死锁问题。

# jstack是什么？ #

> `jstack`是`java虚拟机`自带的一种`堆栈跟踪工具`。`jstack`用于打印出给定的`java进程ID`或`core file`或`远程调试服务`的Java堆栈信息

# jstack有什么作用 #

> `jstack`主要用于生成java虚拟机当前时刻的线程快照。线程快照是当前java虚拟机内每一条线程正在执行的方法堆栈的集合，生成线程快照的主要目的是定位线程出现长时间停顿的原因，如线程间死锁、死循环、请求外部资源导致的长时间等待等。 线程出现停顿的时候通过`jstack`来查看各个线程的调用堆栈，就可以知道没有响应的线程到底在后台做什么事情，或者等待什么资源。如果现在运行的java程序呈现`hung`的状态，`jstack`是非常有用的。

# 如何使用？ #

使用`jstack -help`查看官方文档

Usage:
        jstack [-l] <pid>
            (to connect to running process)
        jstack -F [-m] [-l] <pid>
            (to connect to a hung process)
        jstack [-m] [-l] <executable> <core>
            (to connect to a core file)
        jstack [-m] [-l] [server_id@]<remote server IP or hostname>
            (to connect to a remote debug server)
    
    Options:
        -F  to force a thread dump. Use when jstack <pid> does not respond (process is hung)
        -m  to print both java and native frames (mixed mode)
        -l  long listing. Prints additional information about locks
        -h or -help to print this help message

## 参数解释 ##

-F：当正常输出的请求不被响应时（jstack <pid>无响应），强制输出线程堆栈。
    
    -m：如果调用到本地方法的话，可以显示C/C++的堆栈 
    
    -l：除堆栈外，会打印出额外的锁信息，在发生死锁时可以用jstack -l pid来观察锁持有情况

# 实战使用 #

## 1. 模拟死锁情形 ##

import java.util.concurrent.TimeUnit;
    import java.util.concurrent.locks.ReentrantLock;
    
    /** * <pre> * 程序目的：模拟线程死锁 * </pre> * created at 2020-06-21 17:54 * @author lerry */
    public class DeathLockDemo { 
    	public static void main(String[] args) { 
    		deathLock();
    	}
    
    	/** * 一个模拟死锁的方法。 */
    	public static void deathLock() { 
    		ReentrantLock lock1 = new ReentrantLock();
    		ReentrantLock lock2 = new ReentrantLock();
    
    		Thread t1 = new Thread(() -> { 
    			try { 
    				lock1.lock();
    				TimeUnit.SECONDS.sleep(1);
    				lock2.lock();
    			}
    			catch (InterruptedException e) { 
    				e.printStackTrace();
    			}
    		});
    		Thread t2 = new Thread(() -> { 
    			try { 
    				lock2.lock();
    				TimeUnit.SECONDS.sleep(1);
    				lock1.lock();
    			}
    			catch (InterruptedException e) { 
    				e.printStackTrace();
    			}
    		});
    		t1.setName("mythread1");
    		t2.setName("mythread2");
    
    		System.out.println("启动两个线程");
    		t1.start();
    		t2.start();
    	}
    }

## 2. 查找该程序的pid ##

1）方法1 使用`ps`命令

ps -ef | grep 'DeathLockDemo'

输出结果为：  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2xpbWVuZ2h1YTkxMTI_size_16_color_FFFFFF_t_70_pic_center]  
图：DeathLockDemo的进程信息  
可以查到，该程序的进程编号为`15019`  
2)方法2 使用`jps`命令

jps

输出结果为：

➜  ~ jps
    14736 KotlinCompileDaemon
    10720 Launcher
    10721 Bootstrap
    15462 Jps
    3608 
    15017 Launcher
    15019 DeathLockDemo
    13471

同样可以查看到该程序的进程编号为`15019`

## 3. 使用jstack ##

jstack -l 15019

输出结果如下：

2020-06-21 18:25:09
    Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.251-b08 mixed mode):
    
    "Attach Listener" #16 daemon prio=9 os_prio=31 tid=0x00007faae8835800 nid=0x5c03 waiting on condition [0x0000000000000000]
       java.lang.Thread.State: RUNNABLE
    
       Locked ownable synchronizers:
    	- None
    
    "DestroyJavaVM" #15 prio=5 os_prio=31 tid=0x00007faae684e800 nid=0x1603 waiting on condition [0x0000000000000000]
       java.lang.Thread.State: RUNNABLE
    
       Locked ownable synchronizers:
    	- None
    
    "mythread2" #14 prio=5 os_prio=31 tid=0x00007faae684e000 nid=0xa803 waiting on condition [0x000070001022c000]
       java.lang.Thread.State: WAITING (parking)
    	at sun.misc.Unsafe.park(Native Method)
    	- parking to wait for  <0x000000076aea4848> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
    	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    	at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
    	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
    	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199)
    	at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:209)
    	at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)
    	at com.hua.jvm.DeathLockDemo.lambda$deathLock$1(DeathLockDemo.java:39)
    	at com.hua.jvm.DeathLockDemo$$Lambda$2/240650537.run(Unknown Source)
    	at java.lang.Thread.run(Thread.java:748)
    
       Locked ownable synchronizers:
    	- <0x000000076aea4878> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
    
    "mythread1" #13 prio=5 os_prio=31 tid=0x00007faae684d000 nid=0xa903 waiting on condition [0x0000700010129000]
       java.lang.Thread.State: WAITING (parking)
    	at sun.misc.Unsafe.park(Native Method)
    	- parking to wait for  <0x000000076aea4878> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
    	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    	at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
    	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
    	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199)
    	at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:209)
    	at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)
    	at com.hua.jvm.DeathLockDemo.lambda$deathLock$0(DeathLockDemo.java:29)
    	at com.hua.jvm.DeathLockDemo$$Lambda$1/1809787067.run(Unknown Source)
    	at java.lang.Thread.run(Thread.java:748)
    
       Locked ownable synchronizers:
    	- <0x000000076aea4848> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
    
    "Service Thread" #12 daemon prio=9 os_prio=31 tid=0x00007faae580c800 nid=0x5703 runnable [0x0000000000000000]
       java.lang.Thread.State: RUNNABLE
    
       Locked ownable synchronizers:
    	- None
    
    "C1 CompilerThread3" #11 daemon prio=9 os_prio=31 tid=0x00007faae802b800 nid=0x5503 waiting on condition [0x0000000000000000]
       java.lang.Thread.State: RUNNABLE
    
       Locked ownable synchronizers:
    	- None
    
    "C2 CompilerThread2" #10 daemon prio=9 os_prio=31 tid=0x00007faae580b800 nid=0x3f03 waiting on condition [0x0000000000000000]
       java.lang.Thread.State: RUNNABLE
    
       Locked ownable synchronizers:
    	- None
    
    "C2 CompilerThread1" #9 daemon prio=9 os_prio=31 tid=0x00007faae800f800 nid=0x4003 waiting on condition [0x0000000000000000]
       java.lang.Thread.State: RUNNABLE
    
       Locked ownable synchronizers:
    	- None
    
    "C2 CompilerThread0" #8 daemon prio=9 os_prio=31 tid=0x00007faae8828800 nid=0x4103 waiting on condition [0x0000000000000000]
       java.lang.Thread.State: RUNNABLE
    
       Locked ownable synchronizers:
    	- None
    
    "JDWP Command Reader" #7 daemon prio=10 os_prio=31 tid=0x00007faae802b000 nid=0x4203 runnable [0x0000000000000000]
       java.lang.Thread.State: RUNNABLE
    
       Locked ownable synchronizers:
    	- None
    
    "JDWP Event Helper Thread" #6 daemon prio=10 os_prio=31 tid=0x00007faae6010800 nid=0x4303 runnable [0x0000000000000000]
       java.lang.Thread.State: RUNNABLE
    
       Locked ownable synchronizers:
    	- None
    
    "JDWP Transport Listener: dt_socket" #5 daemon prio=10 os_prio=31 tid=0x00007faae8824800 nid=0x4507 runnable [0x0000000000000000]
       java.lang.Thread.State: RUNNABLE
    
       Locked ownable synchronizers:
    	- None
    
    "Signal Dispatcher" #4 daemon prio=9 os_prio=31 tid=0x00007faae6819800 nid=0x4607 runnable [0x0000000000000000]
       java.lang.Thread.State: RUNNABLE
    
       Locked ownable synchronizers:
    	- None
    
    "Finalizer" #3 daemon prio=8 os_prio=31 tid=0x00007faae6810800 nid=0x5003 in Object.wait() [0x000070000f608000]
       java.lang.Thread.State: WAITING (on object monitor)
    	at java.lang.Object.wait(Native Method)
    	- waiting on <0x000000076ab08ee0> (a java.lang.ref.ReferenceQueue$Lock)
    	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144)
    	- locked <0x000000076ab08ee0> (a java.lang.ref.ReferenceQueue$Lock)
    	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:165)
    	at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:216)
    
       Locked ownable synchronizers:
    	- None
    
    "Reference Handler" #2 daemon prio=10 os_prio=31 tid=0x00007faae7815800 nid=0x5103 in Object.wait() [0x000070000f505000]
       java.lang.Thread.State: WAITING (on object monitor)
    	at java.lang.Object.wait(Native Method)
    	- waiting on <0x000000076ab06c00> (a java.lang.ref.Reference$Lock)
    	at java.lang.Object.wait(Object.java:502)
    	at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
    	- locked <0x000000076ab06c00> (a java.lang.ref.Reference$Lock)
    	at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)
    
       Locked ownable synchronizers:
    	- None
    
    "VM Thread" os_prio=31 tid=0x00007faae680e000 nid=0x5203 runnable 
    
    "GC task thread#0 (ParallelGC)" os_prio=31 tid=0x00007faae8803800 nid=0x1e07 runnable 
    
    "GC task thread#1 (ParallelGC)" os_prio=31 tid=0x00007faae9000000 nid=0x1f03 runnable 
    
    "GC task thread#2 (ParallelGC)" os_prio=31 tid=0x00007faae6804000 nid=0x2a03 runnable 
    
    "GC task thread#3 (ParallelGC)" os_prio=31 tid=0x00007faae780c800 nid=0x2c03 runnable 
    
    "GC task thread#4 (ParallelGC)" os_prio=31 tid=0x00007faae780d000 nid=0x2e03 runnable 
    
    "GC task thread#5 (ParallelGC)" os_prio=31 tid=0x00007faae780d800 nid=0x5403 runnable 
    
    "GC task thread#6 (ParallelGC)" os_prio=31 tid=0x00007faae780e800 nid=0x3003 runnable 
    
    "GC task thread#7 (ParallelGC)" os_prio=31 tid=0x00007faae780f000 nid=0x3203 runnable 
    
    "VM Periodic Task Thread" os_prio=31 tid=0x00007faae7880800 nid=0x5903 waiting on condition 
    
    JNI global references: 2537
    
    
    Found one Java-level deadlock:
    =============================
    "mythread2":
      waiting for ownable synchronizer 0x000000076aea4848, (a java.util.concurrent.locks.ReentrantLock$NonfairSync),
      which is held by "mythread1"
    "mythread1":
      waiting for ownable synchronizer 0x000000076aea4878, (a java.util.concurrent.locks.ReentrantLock$NonfairSync),
      which is held by "mythread2"
    
    Java stack information for the threads listed above:
    ===================================================
    "mythread2":
    	at sun.misc.Unsafe.park(Native Method)
    	- parking to wait for  <0x000000076aea4848> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
    	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    	at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
    	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
    	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199)
    	at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:209)
    	at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)
    	at com.hua.jvm.DeathLockDemo.lambda$deathLock$1(DeathLockDemo.java:39)
    	at com.hua.jvm.DeathLockDemo$$Lambda$2/240650537.run(Unknown Source)
    	at java.lang.Thread.run(Thread.java:748)
    "mythread1":
    	at sun.misc.Unsafe.park(Native Method)
    	- parking to wait for  <0x000000076aea4878> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
    	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    	at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
    	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
    	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199)
    	at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:209)
    	at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)
    	at com.hua.jvm.DeathLockDemo.lambda$deathLock$0(DeathLockDemo.java:29)
    	at com.hua.jvm.DeathLockDemo$$Lambda$1/1809787067.run(Unknown Source)
    	at java.lang.Thread.run(Thread.java:748)
    
    Found 1 deadlock.

## 4. 结果分析 ##

![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2xpbWVuZ2h1YTkxMTI_size_16_color_FFFFFF_t_70_pic_center 1]  
图：截取的部分jstack输出结果  
根据输出，可以发现：  
`线程mythread2`在等待正在由`mythread1`持有的锁`0x000000076aea4848`。  
而`线程mythread1`同时又在等待正在由`mythread2`持有的锁`0x000000076aea4878`。造成了死锁问题。

# jstack日志分析工具 #

可以把`jstack`输出到文本中，然后使用分析工具查看

~ jstack -l 15019 > ~/Temp/jstack15019.txt

![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2xpbWVuZ2h1YTkxMTI_size_16_color_FFFFFF_t_70]  
图：fastthread.io的在线分析结果

# 参考 #

[jvm 性能调优工具之 jstack - 简书][jvm _ jstack -]

# 环境说明 #

*  java -version

java version "1.8.0_251"
    Java(TM) SE Runtime Environment (build 1.8.0_251-b08)
    Java HotSpot(TM) 64-Bit Server VM (build 25.251-b08, mixed mode)

*  OS：`macOS High Sierra 10.13.4`

[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2xpbWVuZ2h1YTkxMTI_size_16_color_FFFFFF_t_70_pic_center]: https://img-blog.csdnimg.cn/20200621183336686.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2xpbWVuZ2h1YTkxMTI=,size_16,color_FFFFFF,t_70#pic_center
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2xpbWVuZ2h1YTkxMTI_size_16_color_FFFFFF_t_70_pic_center 1]: https://img-blog.csdnimg.cn/20200621183355225.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2xpbWVuZ2h1YTkxMTI=,size_16,color_FFFFFF,t_70#pic_center
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2xpbWVuZ2h1YTkxMTI_size_16_color_FFFFFF_t_70]: https://img-blog.csdnimg.cn/2020062118552413.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2xpbWVuZ2h1YTkxMTI=,size_16,color_FFFFFF,t_70
[jvm _ jstack -]: https://www.jianshu.com/p/025cb069cb69