使用Thread Dump診斷死鎖和效能瓶頸問題
場景:Java程式在執行的過程中出現了死鎖或者執行的很慢,檢視日誌也沒發現什麼Exception,該如何解決呢?
-
一段死鎖程式:
public class DeadLock { public static Object lockA = new Object(); public static Object lockB = new Object(); public static void main(String[] args) { new ThreadA().start(); new ThreadB
-
執行該程式會出現死鎖:
-
使用JDK提供的一個非常強大的效能診斷工具:Thread Dump來解決。
3.1. 在Linux系統上通過執行
kill -3 PID
來獲取某個java程序的Thread Dump資訊。
3.2. 使用JDK自帶的工具:jps 來獲取執行中的java程序的PID。
3.3. 新開一個命令列視窗,執行jps獲取執行中的java程序的PID。
3.4. 緊接著執行kill -3 1529
命令,我們就會發現在原來發生死鎖的那個命令列視窗中出現瞭如下資訊(Thread Dump資訊):
3.5. 詳細的資訊如下:2018-11-10 11:55:08 Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.144-b01 mixed mode): "DestroyJavaVM" #10 prio=5 os_prio=0 tid=0x00007f4a74008800 nid=0x5fa waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Thread-1" #9 prio=5 os_prio=0 tid=0x00007f4a740ca800 nid=0x604 waiting for monitor entry [0x00007f4a78808000] java.lang.Thread.State: BLOCKED (on object monitor) at ThreadB.run(DeadLock.java:43) - waiting to lock <0x00000000e0e5ddc8> (a java.lang.Object) - locked <0x00000000e0e5ddd8> (a java.lang.Object) "Thread-0" #8 prio=5 os_prio=0 tid=0x00007f4a740c8800 nid=0x603 waiting for monitor entry [0x00007f4a78909000] java.lang.Thread.State: BLOCKED (on object monitor) at ThreadA.run(DeadLock.java:25) - waiting to lock <0x00000000e0e5ddd8> (a java.lang.Object) - locked <0x00000000e0e5ddc8> (a java.lang.Object) "Service Thread" #7 daemon prio=9 os_prio=0 tid=0x00007f4a740b3000 nid=0x601 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C1 CompilerThread1" #6 daemon prio=9 os_prio=0 tid=0x00007f4a740b0000 nid=0x600 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread0" #5 daemon prio=9 os_prio=0 tid=0x00007f4a740ae000 nid=0x5ff waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Signal Dispatcher" #4 daemon prio=9 os_prio=0 tid=0x00007f4a740ac800 nid=0x5fe waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Finalizer" #3 daemon prio=8 os_prio=0 tid=0x00007f4a74079800 nid=0x5fd in Object.wait() [0x00007f4a78f0f000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000e0e08ec8> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143) - locked <0x00000000e0e08ec8> (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=0 tid=0x00007f4a74074800 nid=0x5fc in Object.wait() [0x00007f4a79010000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000e0e06b68> (a java.lang.ref.Reference$Lock) at java.lang.Object.wait(Object.java:502) at java.lang.ref.Reference.tryHandlePending(Reference.java:191) - locked <0x00000000e0e06b68> (a java.lang.ref.Reference$Lock) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153) "VM Thread" os_prio=0 tid=0x00007f4a7406d000 nid=0x5fb runnable "VM Periodic Task Thread" os_prio=0 tid=0x00007f4a740b6800 nid=0x602 waiting on condition JNI global references: 6 Found one Java-level deadlock: ============================= "Thread-1": waiting to lock monitor 0x00007f4a580062c8 (object 0x00000000e0e5ddc8, a java.lang.Object), which is held by "Thread-0" "Thread-0": waiting to lock monitor 0x00007f4a58004e28 (object 0x00000000e0e5ddd8, a java.lang.Object), which is held by "Thread-1" Java stack information for the threads listed above: =================================================== "Thread-1": at ThreadB.run(DeadLock.java:43) - waiting to lock <0x00000000e0e5ddc8> (a java.lang.Object) - locked <0x00000000e0e5ddd8> (a java.lang.Object) "Thread-0": at ThreadA.run(DeadLock.java:25) - waiting to lock <0x00000000e0e5ddd8> (a java.lang.Object) - locked <0x00000000e0e5ddc8> (a java.lang.Object) Found 1 deadlock. Heap def new generation total 9792K, used 1393K [0x00000000e0e00000, 0x00000000e18a0000, 0x00000000eb400000) eden space 8704K, 16% used [0x00000000e0e00000, 0x00000000e0f5c560, 0x00000000e1680000) from space 1088K, 0% used [0x00000000e1680000, 0x00000000e1680000, 0x00000000e1790000) to space 1088K, 0% used [0x00000000e1790000, 0x00000000e1790000, 0x00000000e18a0000) tenured generation total 21888K, used 0K [0x00000000eb400000, 0x00000000ec960000, 0x0000000100000000) the space 21888K, 0% used [0x00000000eb400000, 0x00000000eb400000, 0x00000000eb400200, 0x00000000ec960000) Metaspace used 2485K, capacity 4490K, committed 4864K, reserved 1056768K class space used 269K, capacity 386K, committed 512K, reserved 1048576K
可以看到這裡發現了一個死鎖:
“Thread-1”:
at ThreadB.run(DeadLock.java:43)
- waiting to lock <0x00000000e0e5ddc8> (a java.lang.Object)
- locked <0x00000000e0e5ddd8> (a java.lang.Object)
“Thread-0”:
at ThreadA.run(DeadLock.java:25)
- waiting to lock <0x00000000e0e5ddd8> (a java.lang.Object)
- locked <0x00000000e0e5ddc8> (a java.lang.Object)Found 1 deadlock.
(1). Thread-1在等待鎖住<0x00000000e0e5ddc8>,但是Thread-0已經鎖住了<0x00000000e0e5ddc8>。
(2). 分別發生在DeadLock.java的43行和25行,定位到程式碼對應的位置:13 class ThreadA extends Thread { 14 15 @Override 16 public void run() { 17 synchronized(DeadLock.lockA) { 18 System.out.println(Thread.currentThread().getName() + " get LockA"); 19 try { 20 Thread.sleep(1000); 21 } catch (InterruptedException e) { 22 e.printStackTrace(); 23 } 24 synchronized(DeadLock.lockB) { 25 System.out.println(Thread.currentThread().getName() + " get LockB"); 26 } 27 } 28 } 29 }
31 class ThreadB extends Thread { 32 33 @Override 34 public void run() { 35 synchronized(DeadLock.lockB) { 36 System.out.println(Thread.currentThread().getName() + " get LockB"); 37 try { 38 Thread.sleep(1000); 39 } catch (InterruptedException e) { 40 e.printStackTrace(); 41 } 42 synchronized(DeadLock.lockA) { 43 System.out.println(Thread.currentThread().getName() + " get LockA"); 44 } 45 } 46 } 47 }
發現兩個執行緒分別在持有了各自的鎖的前提下去搶奪對方的鎖,結果陷入死鎖,使用
kill -9 1529
殺掉死鎖程序,修改程式碼,重新部署到伺服器,問題解決。 -
另外,正常執行的java執行緒的狀態是RUNNABLE,陷入阻塞或者有問題的執行緒將處於BLOCKED狀態,根據Threa Dump資訊也可以看出來。