jstack是jdk中自带的用于查看进程内线程栈的工具。当程序出现死锁时,我们可以通过jstack打印线程栈找到问题。
找出代码中的死锁
学习从一段简单的代码开始:
public class Main {
public static void main(String[] args) {
test1();
}
private static void test1() {
final Object lock1 = new Object();
final Object lock2 = new Object();
Thread thread=new Thread(new Runnable() {
public void run() {
synchronized (lock1) {
try {
for(int i=0;i<20;i++) {
Thread.sleep(1000);
System.out.println(Thread.currentThread().getName()+" "+i);
}
synchronized (lock2) {
for(int i=20;i<40;i++) {
Thread.sleep(1000);
System.out.println(Thread.currentThread().getName()+" "+i);
}
}
} catch (InterruptedException e) {
e.printStackTrace();
}
}
}
});
thread.start();
synchronized (lock2) {
try {
for(int i=0;i<20;i++) {
Thread.sleep(1000);
System.out.println(Thread.currentThread().getName()+" "+i);
}
synchronized (lock1) {
for(int i=20;i<40;i++) {
Thread.sleep(1000);
System.out.println(Thread.currentThread().getName()+" "+i);
}
}
} catch (InterruptedException e) {
e.printStackTrace();
}
}
}
}
肉眼都能看出来的死锁,程序运行20s后进入死锁状态。
首先我们先找出这个程序的进程id,建议用jps,而不是ps,原因是jps只会显示当前用户下面的java进程,等于自动帮我们过滤了。
jps -l
Main进程,id 5632,这时出动我们的主角jstack.
jstack 5632
结果如下
2017-05-23 13:57:22
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.45-b02 mixed mode):
"Attach Listener" #12 daemon prio=9 os_prio=31 tid=0x00007ff0f780c800 nid=0x4507 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Thread-0" #11 prio=5 os_prio=31 tid=0x00007ff0f80c0000 nid=0x5a03 waiting for monitor entry [0x0000700002310000]
java.lang.Thread.State: BLOCKED (on object monitor)
at Main$1.run(Main.java:33)
- waiting to lock <0x000000076adb1a98> (a java.lang.Object)
- locked <0x000000076adb1a88> (a java.lang.Object)
at java.lang.Thread.run(Thread.java:745)
"Service Thread" #10 daemon prio=9 os_prio=31 tid=0x00007ff0f980b800 nid=0x5603 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C1 CompilerThread3" #9 daemon prio=9 os_prio=31 tid=0x00007ff0f6803000 nid=0x5403 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread2" #8 daemon prio=9 os_prio=31 tid=0x00007ff0f6802800 nid=0x5203 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread1" #7 daemon prio=9 os_prio=31 tid=0x00007ff0f6801800 nid=0x5003 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread0" #6 daemon prio=9 os_prio=31 tid=0x00007ff0f90de800 nid=0x4e03 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Monitor Ctrl-Break" #5 daemon prio=5 os_prio=31 tid=0x00007ff0f90dc800 nid=0x4c03 runnable [0x0000700001bfb000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:170)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
- locked <0x000000076af12b68> (a java.io.InputStreamReader)
at java.io.InputStreamReader.read(InputStreamReader.java:184)
at java.io.BufferedReader.fill(BufferedReader.java:161)
at java.io.BufferedReader.readLine(BufferedReader.java:324)
- locked <0x000000076af12b68> (a java.io.InputStreamReader)
at java.io.BufferedReader.readLine(BufferedReader.java:389)
at com.intellij.rt.execution.application.AppMainV2$1.run(AppMainV2.java:64)
"Signal Dispatcher" #4 daemon prio=9 os_prio=31 tid=0x00007ff0f8039800 nid=0x4a03 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Finalizer" #3 daemon prio=8 os_prio=31 tid=0x00007ff0f9803000 nid=0x3903 in Object.wait() [0x0000700001972000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x000000076ab06f58> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
- locked <0x000000076ab06f58> (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=31 tid=0x00007ff0f9802000 nid=0x3703 in Object.wait() [0x000070000186f000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x000000076ab06998> (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 <0x000000076ab06998> (a java.lang.ref.Reference$Lock)
"main" #1 prio=5 os_prio=31 tid=0x00007ff0f8002000 nid=0x1c03 waiting for monitor entry [0x0000700000e51000]
java.lang.Thread.State: BLOCKED (on object monitor)
at Main.test1(Main.java:52)
- waiting to lock <0x000000076adb1a88> (a java.lang.Object)
- locked <0x000000076adb1a98> (a java.lang.Object)
at Main.main(Main.java:18)
"VM Thread" os_prio=31 tid=0x00007ff0f801f800 nid=0x3503 runnable
"GC task thread#0 (ParallelGC)" os_prio=31 tid=0x00007ff0f9003800 nid=0x2503 runnable
"GC task thread#1 (ParallelGC)" os_prio=31 tid=0x00007ff0f9004000 nid=0x2703 runnable
"GC task thread#2 (ParallelGC)" os_prio=31 tid=0x00007ff0f7801000 nid=0x2903 runnable
"GC task thread#3 (ParallelGC)" os_prio=31 tid=0x00007ff0f600e800 nid=0x2b03 runnable
"GC task thread#4 (ParallelGC)" os_prio=31 tid=0x00007ff0f600f000 nid=0x2d03 runnable
"GC task thread#5 (ParallelGC)" os_prio=31 tid=0x00007ff0f6010000 nid=0x2f03 runnable
"GC task thread#6 (ParallelGC)" os_prio=31 tid=0x00007ff0f6010800 nid=0x3103 runnable
"GC task thread#7 (ParallelGC)" os_prio=31 tid=0x00007ff0f6011000 nid=0x3303 runnable
"VM Periodic Task Thread" os_prio=31 tid=0x00007ff0f980c000 nid=0x5803 waiting on condition
JNI global references: 26
Found one Java-level deadlock:
=============================
"Thread-0":
waiting to lock monitor 0x00007ff0f8024f38 (object 0x000000076adb1a98, a java.lang.Object),
which is held by "main"
"main":
waiting to lock monitor 0x00007ff0f8023bf8 (object 0x000000076adb1a88, a java.lang.Object),
which is held by "Thread-0"
Java stack information for the threads listed above:
===================================================
"Thread-0":
at Main$1.run(Main.java:33)
- waiting to lock <0x000000076adb1a98> (a java.lang.Object)
- locked <0x000000076adb1a88> (a java.lang.Object)
at java.lang.Thread.run(Thread.java:745)
"main":
at Main.test1(Main.java:52)
- waiting to lock <0x000000076adb1a88> (a java.lang.Object)
- locked <0x000000076adb1a98> (a java.lang.Object)
at Main.main(Main.java:18)
Found 1 deadlock.
jstack直接帮我们找出来了deadlock。真实场景下,如果代码比较复杂,可能需要我们自己分析找出死锁。
如果我们自己分析,该怎么找出死锁呢?重点分析java.lang.Thread.State: BLOCKED
的进程,找到waiting to lock
,看看这个锁的持有者,是不是也被锁着,沿着这个链路找下去,是不是死锁就能找出来 了。比如上面的例子中,main
线程持有0x000000076adb1a98
锁,等待0x000000076adb1a88
锁释放,而Thread-0
持有0x000000076adb1a88
锁,等待0x000000076adb1a98
锁释放,两个线程互相等待,而进入死锁状态。
找出CPU消耗多的代码
如果程序cpu占用很高,我们需要找到问题优化,可以配合top命令,找出最耗cpu的进程,从而找到相应代码解决问题。
先用jps找出程序pid,这里是23034
用top命令找出该进程最耗cpu的线程。下面的top是linux中的,mac里的不一样。
top -Hp 23034
结果如下图
23046线程占了93.8的cpu,就是它.
将23046转成16进制。因为top里的pid是10进制,而jstack里是16进制,叫nid。
可以用printf命令转换printf "%x\n" 23046
得到
5a06
jstack出场
jstack 23034 | grep 5a06
结果如下:
writeFileThread占用了最多的cpu资源。找到后,可以优化代码了.