近期线上项目遇到比较棘手的问题:【定时任务在运行一段时间后突然停止运行】,排查了若干天仍旧没有发现具体问题,头疼哟~~进入正题!
一、什么是Jstack
Jstack( Stack Trace for Java),用于生成虚拟机当前的线程快照信息,包含每一条线程的堆栈信息。该命令通常用于定位线程停顿原因,当出现线程停顿时,可通过stack查看每个线程的堆栈信息,进而分析停顿原因。jstack用于打印出给定的java进程ID或core file或远程调试服务的Java堆栈信息。 如果java程序崩溃生成core文件,jstack工具可以用来获得core文件的java stack和native stack的信息,从而可以轻松地知道java程序是如何崩溃和在程序何处发生问题。另外,jstack工具还可以附属到正在运行的java程序中,看到当时运行的java程序的java stack和native stack的信息, 如果现在运行的java程序呈现hung的状态,jstack是非常有用的。
二、Jstack命令使用方法
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实战运用
Windows系统下我们可以使用[tasklist]命令或者直接打开任务管理器来查看我们当前运行的Java程序的PID,获取到PID后我们就可以开始使用我们的Jstack命令来监控一下我们的Java程序线程的堆栈使用情况,下面是小编使用命令的状况:
Windows系统下使用Jstack,(篇幅原因不再演示如何获取PID,相信高级Java工程师的你一定会的~):
jstack [PID]
C:\Users\sunshine>jstack 13236
2019-08-02 16:00:20
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.144-b01 mixed mode):
"DestroyJavaVM" #13 prio=5 os_prio=0 tid=0x0000000002ade000 nid=0x119c waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Thread-2" #12 prio=5 os_prio=0 tid=0x0000000014a9d000 nid=0xce0 waiting for monitor entry [0x00000000154cf000]
java.lang.Thread.State: BLOCKED (on object monitor)
at com.sunshine.vm.DeadLock.run(DeadLock.java:88)
- waiting to lock <0x00000000ffc0fe70> (a java.lang.Object)
- locked <0x00000000ffc0fe60> (a java.lang.Object)
at java.lang.Thread.run(Thread.java:748)
"Thread-1" #11 prio=5 os_prio=0 tid=0x0000000014a9c000 nid=0x9d0 waiting for monitor entry [0x00000000153cf000]
java.lang.Thread.State: BLOCKED (on object monitor)
at com.sunshine.vm.DeadLock.run(DeadLock.java:75)
- waiting to lock <0x00000000ffc0fe60> (a java.lang.Object)
- locked <0x00000000ffc0fe70> (a java.lang.Object)
at java.lang.Thread.run(Thread.java:748)
"Service Thread" #8 daemon prio=9 os_prio=0 tid=0x00000000141e7800 nid=0x3210 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C1 CompilerThread1" #7 daemon prio=9 os_prio=2 tid=0x00000000141e3800 nid=0x36d4 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread0" #6 daemon prio=9 os_prio=2 tid=0x000000001319f000 nid=0x3070 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Attach Listener" #5 daemon prio=5 os_prio=2 tid=0x000000001319e800 nid=0x7f0 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Signal Dispatcher" #4 daemon prio=9 os_prio=2 tid=0x0000000013148000 nid=0x1f08 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Finalizer" #3 daemon prio=8 os_prio=1 tid=0x0000000013128800 nid=0x2b6c in Object.wait() [0x0000000013e6f000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000000ffc00b90> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
- locked <0x00000000ffc00b90> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)
"Reference Handler" #2 daemon prio=10 os_prio=2 tid=0x000000000305d000 nid=0x7fc in Object.wait() [0x0000000013d6e000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000000ffc08660> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:502)
at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
- locked <0x00000000ffc08660> (a java.lang.ref.Reference$Lock)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)
"VM Thread" os_prio=2 tid=0x0000000013106800 nid=0x34c0 runnable
"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x0000000002f86800 nid=0x2bdc runnable
"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x0000000002f88800 nid=0x2f98 runnable
"VM Periodic Task Thread" os_prio=2 tid=0x00000000141ff000 nid=0x2c88 waiting on condition
JNI global references: 25
Found one Java-level deadlock:
=============================
"Thread-2":
waiting to lock monitor 0x0000000003064c78 (object 0x00000000ffc0fe70, a java.lang.Object),
which is held by "Thread-1"
"Thread-1":
waiting to lock monitor 0x0000000003063b48 (object 0x00000000ffc0fe60, a java.lang.Object),
which is held by "Thread-2"
Java stack information for the threads listed above:
===================================================
"Thread-2":
at com.sunshine.vm.DeadLock.run(DeadLock.java:88)
- waiting to lock <0x00000000ffc0fe70> (a java.lang.Object)
- locked <0x00000000ffc0fe60> (a java.lang.Object)
at java.lang.Thread.run(Thread.java:748)
"Thread-1":
at com.sunshine.vm.DeadLock.run(DeadLock.java:75)
- waiting to lock <0x00000000ffc0fe60> (a java.lang.Object)
- locked <0x00000000ffc0fe70> (a java.lang.Object)
at java.lang.Thread.run(Thread.java:748)
Found 1 deadlock.
jstack -F [PID] (注意F必须大写)
C:\Users\sunshine>jstack -F 13236
Attaching to process ID 13236, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.144-b01
Deadlock Detection:
Found one Java-level deadlock:
=============================
"Thread-1":
waiting to lock Monitor@0x0000000003063b48 (Object@0x00000000ffc0fe60, a java/lang/Object),
which is held by "Thread-2"
"Thread-2":
waiting to lock Monitor@0x0000000003064c78 (Object@0x00000000ffc0fe70, a java/lang/Object),
which is held by "Thread-1"
Found a total of 1 deadlock.
Thread 1: (state = BLOCKED)
Thread 14: (state = BLOCKED)
- com.sunshine.vm.DeadLock.run() @bci=116, line=88 (Interpreted frame)
- java.lang.Thread.run() @bci=11, line=748 (Interpreted frame)
Thread 13: (state = BLOCKED)
- com.sunshine.vm.DeadLock.run() @bci=59, line=75 (Interpreted frame)
- java.lang.Thread.run() @bci=11, line=748 (Interpreted frame)
Thread 8: (state = BLOCKED)
Thread 7: (state = BLOCKED)
Thread 6: (state = BLOCKED)
- java.lang.Object.wait(long) @bci=0 (Interpreted frame)
- java.lang.ref.ReferenceQueue.remove(long) @bci=59, line=143 (Interpreted frame)
- java.lang.ref.ReferenceQueue.remove() @bci=2, line=164 (Interpreted frame)
- java.lang.ref.Finalizer$FinalizerThread.run() @bci=36, line=209 (Interpreted frame)
Thread 5: (state = BLOCKED)
- java.lang.Object.wait(long) @bci=0 (Interpreted frame)
- java.lang.Object.wait() @bci=2, line=502 (Interpreted frame)
- java.lang.ref.Reference.tryHandlePending(boolean) @bci=54, line=191 (Interpreted frame)
- java.lang.ref.Reference$ReferenceHandler.run() @bci=1, line=153 (Interpreted frame)
jstack -l [PID]
C:\Users\sunshine>jstack -l 13236
2019-08-02 16:10:21
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.144-b01 mixed mode):
"DestroyJavaVM" #13 prio=5 os_prio=0 tid=0x0000000002ade000 nid=0x119c waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"Thread-2" #12 prio=5 os_prio=0 tid=0x0000000014a9d000 nid=0xce0 waiting for monitor entry [0x00000000154cf000]
java.lang.Thread.State: BLOCKED (on object monitor)
at com.sunshine.vm.DeadLock.run(DeadLock.java:88)
- waiting to lock <0x00000000ffc0fe70> (a java.lang.Object)
- locked <0x00000000ffc0fe60> (a java.lang.Object)
at java.lang.Thread.run(Thread.java:748)
Locked ownable synchronizers:
- None
"Thread-1" #11 prio=5 os_prio=0 tid=0x0000000014a9c000 nid=0x9d0 waiting for monitor entry [0x00000000153cf000]
java.lang.Thread.State: BLOCKED (on object monitor)
at com.sunshine.vm.DeadLock.run(DeadLock.java:75)
- waiting to lock <0x00000000ffc0fe60> (a java.lang.Object)
- locked <0x00000000ffc0fe70> (a java.lang.Object)
at java.lang.Thread.run(Thread.java:748)
Locked ownable synchronizers:
- None
"Service Thread" #8 daemon prio=9 os_prio=0 tid=0x00000000141e7800 nid=0x3210 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"C1 CompilerThread1" #7 daemon prio=9 os_prio=2 tid=0x00000000141e3800 nid=0x36d4 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"C2 CompilerThread0" #6 daemon prio=9 os_prio=2 tid=0x000000001319f000 nid=0x3070 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"Attach Listener" #5 daemon prio=5 os_prio=2 tid=0x000000001319e800 nid=0x7f0 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"Signal Dispatcher" #4 daemon prio=9 os_prio=2 tid=0x0000000013148000 nid=0x1f08 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
Locked ownable synchronizers:
- None
"Finalizer" #3 daemon prio=8 os_prio=1 tid=0x0000000013128800 nid=0x2b6c in Object.wait() [0x0000000013e6f000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000000ffc00b90> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
- locked <0x00000000ffc00b90> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)
Locked ownable synchronizers:
- None
"Reference Handler" #2 daemon prio=10 os_prio=2 tid=0x000000000305d000 nid=0x7fc in Object.wait() [0x0000000013d6e000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000000ffc08660> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:502)
at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
- locked <0x00000000ffc08660> (a java.lang.ref.Reference$Lock)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)
Locked ownable synchronizers:
- None
"VM Thread" os_prio=2 tid=0x0000000013106800 nid=0x34c0 runnable
"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x0000000002f86800 nid=0x2bdc runnable
"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x0000000002f88800 nid=0x2f98 runnable
"VM Periodic Task Thread" os_prio=2 tid=0x00000000141ff000 nid=0x2c88 waiting on condition
JNI global references: 25
Found one Java-level deadlock:
=============================
"Thread-2":
waiting to lock monitor 0x0000000003064c78 (object 0x00000000ffc0fe70, a java.lang.Object),
which is held by "Thread-1"
"Thread-1":
waiting to lock monitor 0x0000000003063b48 (object 0x00000000ffc0fe60, a java.lang.Object),
which is held by "Thread-2"
Java stack information for the threads listed above:
===================================================
"Thread-2":
at com.sunshine.vm.DeadLock.run(DeadLock.java:88)
- waiting to lock <0x00000000ffc0fe70> (a java.lang.Object)
- locked <0x00000000ffc0fe60> (a java.lang.Object)
at java.lang.Thread.run(Thread.java:748)
"Thread-1":
at com.sunshine.vm.DeadLock.run(DeadLock.java:75)
- waiting to lock <0x00000000ffc0fe60> (a java.lang.Object)
- locked <0x00000000ffc0fe70> (a java.lang.Object)
at java.lang.Thread.run(Thread.java:748)
Found 1 deadlock.
以上是小编写的一个死锁测试程序,从上面我们可以清晰的看出发生死锁的线程,便于我们处理问题,当然你还可以使用以下命令直接导出文件:
C:\Users\sunshine>jstack 13236 >C:\Users\sunshine\Desktop\log\test.log
C:\Users\sunshine>jstack -l 13236 >C:\Users\sunshine\Desktop\log\test.log
C:\Users\sunshine>jstack -F 13236 >C:\Users\sunshine\Desktop\log\test.log
Linux系统下操作与Windows系统下一致,如有错误之处,欢迎交流指正,限于篇幅原因先写到这里,请续看:浅析Java堆栈跟踪工具:Jstack【下】!