JVM - jstack工具 — Bob的城堡

jstack是JDK中自带的Java工具之一，用于生成虚拟机当前时刻的线程快照，含有正在执行的方法堆栈的集合信息，生成线程快照的主要目的是定位线程出现长时间停顿的原因，如线程间死锁、死循环、请求外部资源导致的长时间等待等问题。

命令和参数

通过 jstack -h命令可以查看可选参数，主要有三个：

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

$ jstack -h
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

使用范例

jstack -l 11467 > ./stack.txt
cat stack.txt

2021-09-30 15:42:55
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.291-b10 mixed mode):

"Attach Listener" #13 daemon prio=9 os_prio=31 tid=0x00007fee4799c000 nid=0xd07 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"DestroyJavaVM" #12 prio=5 os_prio=31 tid=0x00007fee46a4f800 nid=0x2503 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"JPS thread pool" #11 daemon prio=5 os_prio=31 tid=0x00007fee46972800 nid=0x4203 waiting on condition [0x0000700009448000]
   java.lang.Thread.State: TIMED_WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x000000079442b8c8> (a java.util.concurrent.SynchronousQueue$TransferStack)
	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
	at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
	at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

   Locked ownable synchronizers:
	- None

"JPS event loop" #9 prio=5 os_prio=31 tid=0x00007fee47140000 nid=0x3b03 runnable [0x0000700009345000]
   java.lang.Thread.State: RUNNABLE
	at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method)
	at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:198)
	at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:117)
	at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
	- locked <0x0000000794552b18> (a io.netty.channel.nio.SelectedSelectionKeySet)
	- locked <0x0000000794566018> (a java.util.Collections$UnmodifiableSet)
	- locked <0x0000000794553b40> (a sun.nio.ch.KQueueSelectorImpl)
	at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
	at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:101)
	at io.netty.channel.nio.SelectedSelectionKeySetSelector.select(SelectedSelectionKeySetSelector.java:68)
	at io.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:810)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:457)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at java.lang.Thread.run(Thread.java:748)

   Locked ownable synchronizers:
	- None

"Service Thread" #8 daemon prio=9 os_prio=31 tid=0x00007fee46814000 nid=0x4603 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"C1 CompilerThread2" #7 daemon prio=9 os_prio=31 tid=0x00007fee4800d000 nid=0x3903 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"C2 CompilerThread1" #6 daemon prio=9 os_prio=31 tid=0x00007fee46813800 nid=0x4803 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"C2 CompilerThread0" #5 daemon prio=9 os_prio=31 tid=0x00007fee47864800 nid=0x3703 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"Signal Dispatcher" #4 daemon prio=9 os_prio=31 tid=0x00007fee46806800 nid=0x4c0b runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"Finalizer" #3 daemon prio=8 os_prio=31 tid=0x00007fee4800c000 nid=0x5103 in Object.wait() [0x0000700008c30000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00000007944245c8> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144)
	- locked <0x00000007944245c8> (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=0x00007fee48009000 nid=0x2f03 in Object.wait() [0x0000700008b2d000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00000007944247f8> (a java.lang.ref.Reference$Lock)
	at java.lang.Object.wait(Object.java:502)
	at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
	- locked <0x00000007944247f8> (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=0x00007fee47836000 nid=0x2e03 runnable
"GC task thread#0 (ParallelGC)" os_prio=31 tid=0x00007fee47806800 nid=0x1d07 runnable
"GC task thread#1 (ParallelGC)" os_prio=31 tid=0x00007fee48001000 nid=0x1f03 runnable
"GC task thread#2 (ParallelGC)" os_prio=31 tid=0x00007fee48002000 nid=0x2b03 runnable
"GC task thread#3 (ParallelGC)" os_prio=31 tid=0x00007fee48002800 nid=0x2c03 runnable
"VM Periodic Task Thread" os_prio=31 tid=0x00007fee4681a800 nid=0x4503 waiting on condition
JNI global references: 444

知识回顾

线程状态

New：创建后尚未启动的线程处于这种状态，不会出现在Dump中。
RUNNABLE：包括Running和Ready。线程开启start（）方法，会进入该状态，在虚拟机内执行的。
Waiting：无限的等待另一个线程的特定操作。
Timed Waiting：有时限的等待另一个线程的特定操作。
Blocked：在程序等待进入同步区域的时候，线程将进入阻塞状态，在等待监视器锁。
Terminated：已终止线程的线程状态，线程已经结束执行。

Dump文件的线程状态一般其实就以下3种：

RUNNABLE，线程处于执行中
BLOCKED，线程被阻塞
WAITING，线程正在等待

Monitor 监视锁

因为Java程序一般都是多线程运行的，Java多线程跟监视锁环环相扣，所以我们分析线程状态时，也需要回顾一下Monitor监视锁知识。 Monitor的工作原理图如下：

线程状态

线程想要获取monitor,首先会进入Entry Set队列，它是Waiting Thread，线程状态是Waiting for monitor entry。
当某个线程成功获取对象的monitor后,进入Owner区域，它就是Active Thread。
如果线程调用了wait()方法，则会进入Wait Set队列，它会释放monitor锁，它也是Waiting Thread，线程状态in Object.wait()
如果其他线程调用 notify() / notifyAll() ，会唤醒Wait Set中的某个线程，该线程再次尝试获取monitor锁，成功即进入Owner区域。

案例分析

死锁问题

排查Java死锁步骤：

jps
jstack -l pid
分析堆栈信息

CPU过高问题

分析CPU过高步骤：

top
top -Hp pid
jstack pid
jstack -l pid >/tmp/log.txt
分析堆栈信息

参考资料

文档信息

本文作者：Bob.Zhu
本文链接：https://adolphor.github.io/2021/07/29/01-jvm-jstack/
版权声明：自由转载-非商用-非衍生-保持署名（创意共享3.0许可证）

Bob的城堡

JVM - jstack工具

命令和参数

使用范例

知识回顾

线程状态

Monitor 监视锁

案例分析

死锁问题

CPU过高问题

参考资料

文档信息

Search

Table of Contents