1. 程式人生 > >使用Thread Dump診斷死鎖和效能瓶頸問題

使用Thread Dump診斷死鎖和效能瓶頸問題

場景:Java程式在執行的過程中出現了死鎖或者執行的很慢,檢視日誌也沒發現什麼Exception,該如何解決呢?

  1. 一段死鎖程式:

    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
    ().start(); } } class ThreadA extends Thread { @Override public void run() { synchronized(DeadLock.lockA) { System.out.println(Thread.currentThread().getName() + " get LockA"); try { Thread.sleep(1000); } catch (InterruptedException
    e) { e.printStackTrace(); } synchronized(DeadLock.lockB) { System.out.println(Thread.currentThread().getName() + " get LockB"); } } } } class ThreadB extends Thread { @Override public void run() { synchronized
    (DeadLock.lockB) { System.out.println(Thread.currentThread().getName() + " get LockB"); try { Thread.sleep(1000); } catch (InterruptedException e) { e.printStackTrace(); } synchronized(DeadLock.lockA) { System.out.println(Thread.currentThread().getName() + " get LockA"); } } } }
  2. 執行該程式會出現死鎖:
    在這裡插入圖片描述

  3. 使用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資訊):
    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殺掉死鎖程序,修改程式碼,重新部署到伺服器,問題解決。

  4. 另外,正常執行的java執行緒的狀態是RUNNABLE,陷入阻塞或者有問題的執行緒將處於BLOCKED狀態,根據Threa Dump資訊也可以看出來。