詳解JAVA線程問題診斷工具Thread Dump

摘要：Thread Dump是非常有用的診斷Java應用問題的工具。

本文分享自華為雲社區《調試排錯 - Java 線程分析之線程Dump分析》，作者：龍哥手記。

Thread Dump是非常有用的診斷Java應用問題的工具。每一個Java虛擬機都有及時生成所有線程在某一點狀態的thread-dump的能力，雖然各個 Java虛擬機列印的thread dump略有不同，但是 大多都提供了當前活動線程的快照，及JVM中所有Java線程的堆棧跟蹤信息，堆棧信息一般包含完整的類名及所執行的方法，如果可能的話還有源代碼的行數。

Thread Dump特點

• 能在各種操作系統下使用；
• 能在各種Java應用伺服器下使用；
• 能在生產環境下使用而不影響系統的性能；
• 能將問題直接定位到應用程式的代碼行上；

Thread Dump抓取

一般當伺服器掛起，崩潰或者性能低下時，就需要抓取伺服器的線程堆棧（Thread Dump）用於後續的分析。在實際運行中，往往一次 dump的信息，還不足以確認問題。為了反映線程狀態的動態變化，需要接連多次做thread dump，每次間隔10-20s，建議至少產生三次 dump信息，如果每次 dump都指向同一個問題，我們才確定問題的典型性。

• 操作系統命令獲取ThreadDump

ps –ef | grep java
kill -3 <pid>

註意：

一定要謹慎, 一步不慎就可能讓伺服器進程被殺死。kill -9 命令會殺死進程。

• JVM 自帶的工具獲取線程堆棧

jps 或 ps –ef | grep java （獲取PID）
jstack [-l ] <pid> | tee -a jstack.log（獲取ThreadDump）

Thread Dump分析

Thread Dump信息

• 頭部信息：時間，JVM信息

2011-11-02 19:05:06  
Full thread dump Java HotSpot(TM) Server VM (16.3-b01 mixed mode): 

• 線程INFO信息塊：

1. "Timer-0" daemon prio=10 tid=0xac190c00 nid=0xaef in Object.wait() [0xae77d000] 
# 線程名稱：Timer-0；線程類型：daemon；優先順序: 10，預設是5；
# JVM線程id：tid=0xac190c00，JVM內部線程的唯一標識（通過java.lang.Thread.getId()獲取，通常用自增方式實現）。
# 對應系統線程id（NativeThread ID）：nid=0xaef，和top命令查看的線程pid對應，不過一個是10進位，一個是16進位。（通過命令：top -H -p pid，可以查看該進程的所有線程信息）
# 線程狀態：in Object.wait()；
# 起始棧地址：[0xae77d000]，對象的記憶體地址，通過JVM記憶體查看工具，能夠看出線程是在哪兒個對象上等待；
2.  java.lang.Thread.State: TIMED_WAITING (on object monitor)
3.  at java.lang.Object.wait(Native Method)
4.  -waiting on <0xb3885f60> (a java.util.TaskQueue)     # 繼續wait 
5.  at java.util.TimerThread.mainLoop(Timer.java:509)
6.  -locked <0xb3885f60> (a java.util.TaskQueue)         # 已經locked
7.  at java.util.TimerThread.run(Timer.java:462)
Java thread statck trace：是上面2-7行的信息。到目前為止這是最重要的數據，Java stack trace提供了大部分信息來精確定位問題根源。

• Java thread statck trace詳解：

堆棧信息應該逆向解讀：程式先執行的是第7行，然後是第6行，依次類推。

- locked <0xb3885f60> (a java.util.ArrayList)
- waiting on <0xb3885f60> (a java.util.ArrayList) 

也就是說對象先上鎖，鎖住對象0xb3885f60，然後釋放該對象鎖，進入waiting狀態。為啥會出現這樣的情況呢？看看下麵的java代碼示例，就會明白：

synchronized(obj) {  
   .........  
   obj.wait();  
   .........  
}

在堆棧的第一行信息中，進一步標明瞭線程在代碼級的狀態，例如：

java.lang.Thread.State: TIMED_WAITING (parking)

|blocked|

> This thread tried to enter asynchronized block, but the lock was taken by another thread. This thread isblocked until the lock gets released.

|blocked (on thin lock)|

> This is the same state asblocked, but the lock in question is a thin lock.

|waiting|

> This thread calledObject.wait() on an object. The thread will remain there until some otherthread sends a notification to that object.

|sleeping|

> This thread calledjava.lang.Thread.sleep().

|parked|

> This thread calledjava.util.concurrent.locks.LockSupport.park().

|suspended|

> The thread's execution wassuspended by java.lang.Thread.suspend() or a JVMTI agent call.

Thread狀態分析

線程的狀態是一個很重要的東西，因此thread dump中會顯示這些狀態，通過對這些狀態的分析，能夠得出線程的運行狀況，進而發現可能存在的問題。線程的狀態在Thread.State這個枚舉類型中定義：

public enum State   
{  
       /** 
        * Thread state for a thread which has not yet started. 
        */  
       NEW,  
         
       /** 
        * Thread state for a runnable thread.  A thread in the runnable 
        * state is executing in the Java virtual machine but it may 
        * be waiting for other resources from the operating system 
        * such as processor. 
        */  
       RUNNABLE,  
         
       /** 
        * Thread state for a thread blocked waiting for a monitor lock. 
        * A thread in the blocked state is waiting for a monitor lock 
        * to enter a synchronized block/method or  
        * reenter a synchronized block/method after calling 
        * {@link Object#wait() Object.wait}. 
        */  
       BLOCKED,  
     
       /** 
        * Thread state for a waiting thread. 
        * A thread is in the waiting state due to calling one of the  
        * following methods: 
        * <ul> 
        *   <li>{@link Object#wait() Object.wait} with no timeout</li> 
        *   <li>{@link #join() Thread.join} with no timeout</li> 
        *   <li>{@link LockSupport#park() LockSupport.park}</li> 
        * </ul> 
        *  
        * <p>A thread in the waiting state is waiting for another thread to 
        * perform a particular action.   
        * 
        * For example, a thread that has called <tt>Object.wait()</tt> 
        * on an object is waiting for another thread to call  
        * <tt>Object.notify()</tt> or <tt>Object.notifyAll()</tt> on  
        * that object. A thread that has called <tt>Thread.join()</tt>  
        * is waiting for a specified thread to terminate. 
        */  
       WAITING,  
         
       /** 
        * Thread state for a waiting thread with a specified waiting time. 
        * A thread is in the timed waiting state due to calling one of  
        * the following methods with a specified positive waiting time: 
        * <ul> 
        *   <li>{@link #sleep Thread.sleep}</li> 
        *   <li>{@link Object#wait(long) Object.wait} with timeout</li> 
        *   <li>{@link #join(long) Thread.join} with timeout</li> 
        *   <li>{@link LockSupport#parkNanos LockSupport.parkNanos}</li>  
        *   <li>{@link LockSupport#parkUntil LockSupport.parkUntil}</li> 
        * </ul> 
        */  
       TIMED_WAITING,  
  
       /** 
        * Thread state for a terminated thread. 
        * The thread has completed execution. 
        */  
       TERMINATED;  
}

• NEW：

每一個線程，在堆記憶體中都有一個對應的Thread對象。Thread t = new Thread();當剛剛在堆記憶體中創建Thread對象，還沒有調用t.start()方法之前，線程就處在NEW狀態。在這個狀態上，線程與普通的java對象沒有什麼區別，就僅僅是一個堆記憶體中的對象。

• RUNNABLE：

該狀態表示線程具備所有運行條件，在運行隊列中準備操作系統的調度，或者正在運行。 這個狀態的線程比較正常，但如果線程長時間停留在在這個狀態就不正常了，這說明線程運行的時間很長（存在性能問題），或者是線程一直得不得執行的機會（存線上程饑餓的問題）。

• BLOCKED：

線程正在等待獲取java對象的監視器(也叫內置鎖)，即線程正在等待進入由synchronized保護的方法或者代碼塊。synchronized用來保證原子性，任意時刻最多只能由一個線程進入該臨界區域，其他線程只能排隊等待。

• WAITING：

處在該線程的狀態，正在等待某個事件的發生，只有特定的條件滿足，才能獲得執行機會。而產生這個特定的事件，通常都是另一個線程。也就是說，如果不發生特定的事件，那麼處在該狀態的線程一直等待，不能獲取執行的機會。比如：

A線程調用了obj對象的obj.wait()方法，如果沒有線程調用obj.notify或obj.notifyAll，那麼A線程就沒有辦法恢復運行； 如果A線程調用了LockSupport.park()，沒有別的線程調用LockSupport.unpark(A)，那麼A沒有辦法恢復運行。 TIMED_WAITING：

J.U.C中很多與線程相關類，都提供了限時版本和不限時版本的API。TIMED_WAITING意味著線程調用了限時版本的API，正在等待時間流逝。當等待時間過去後，線程一樣可以恢復運行。如果線程進入了WAITING狀態，一定要特定的事件發生才能恢復運行；而處在TIMED_WAITING的線程，如果特定的事件發生或者是時間流逝完畢，都會恢復運行。

• TERMINATED：

線程執行完畢，執行完run方法正常返回，或者拋出了運行時異常而結束，線程都會停留在這個狀態。這個時候線程只剩下Thread對象了，沒有什麼用了。

關鍵狀態分析

• Wait on condition：The thread is either sleeping or waiting to be notified by another thread.

該狀態說明它在等待另一個條件的發生，來把自己喚醒，或者乾脆它是調用了 sleep(n)。

此時線程狀態大致為以下幾種：

java.lang.Thread.State: WAITING (parking)：一直等那個條件發生；
java.lang.Thread.State: TIMED_WAITING (parking或sleeping)：定時的，那個條件不到來，也將定時喚醒自己。

• Waiting for Monitor Entry 和 in Object.wait()：The thread is waiting to get the lock for an object (some other thread may be holding the lock). This happens if two or more threads try to execute synchronized code. Note that the lock is always for an object and not for individual methods.

在多線程的JAVA程式中，實現線程之間的同步，就要說說 Monitor。Monitor是Java中用以實現線程之間的互斥與協作的主要手段，它可以看成是對象或者Class的鎖。每一個對象都有，也僅有一個 Monitor 。下麵這個圖，描述了線程和 Monitor之間關係，以及線程的狀態轉換圖：

如上圖，每個Monitor在某個時刻，只能被一個線程擁有，該線程就是 “ActiveThread”，而其它線程都是 “Waiting Thread”，分別在兩個隊列“Entry Set”和“Wait Set”里等候。在“Entry Set”中等待的線程狀態是“Waiting for monitor entry”，而在“Wait Set”中等待的線程狀態是“in Object.wait()”。

先看“Entry Set”裡面的線程。我們稱被 synchronized保護起來的代碼段為臨界區。當一個線程申請進入臨界區時，它就進入了“Entry Set”隊列。對應的 code就像：

synchronized(obj) {
   .........
}

• 該 monitor不被其它線程擁有， Entry Set裡面也沒有其它等待線程。本線程即成為相應類或者對象的 Monitor的 Owner，執行臨界區的代碼。
• 該 monitor被其它線程擁有，本線程在 Entry Set隊列中等待。

在第一種情況下，線程將處於 “Runnable”的狀態，而第二種情況下，線程 DUMP會顯示處於 “waiting for monitor entry”。如下：

"Thread-0" prio=10 tid=0x08222eb0 nid=0x9 waiting for monitor entry [0xf927b000..0xf927bdb8] 
at testthread.WaitThread.run(WaitThread.java:39) 
- waiting to lock <0xef63bf08> (a java.lang.Object) 
- locked <0xef63beb8> (a java.util.ArrayList) 
at java.lang.Thread.run(Thread.java:595) 

再看“Wait Set”裡面的線程。當線程獲得了 Monitor，進入了臨界區之後，如果發現線程繼續運行的條件沒有滿足，它則調用對象（一般就是被 synchronized 的對象）的 wait() 方法，放棄 Monitor，進入 “Wait Set”隊列。只有當別的線程在該對象上調用了 notify() 或者 notifyAll()，“Wait Set”隊列中線程才得到機會去競爭，但是只有一個線程獲得對象的Monitor，恢復到運行態。在 “Wait Set”中的線程， DUMP中表現為： in Object.wait()。如下：

"Thread-1" prio=10 tid=0x08223250 nid=0xa in Object.wait() [0xef47a000..0xef47aa38] 
 at java.lang.Object.wait(Native Method) 
 - waiting on <0xef63beb8> (a java.util.ArrayList) 
 at java.lang.Object.wait(Object.java:474) 
 at testthread.MyWaitThread.run(MyWaitThread.java:40) 
 - locked <0xef63beb8> (a java.util.ArrayList) 
 at java.lang.Thread.run(Thread.java:595) 
綜上，一般CPU很忙時，則關註runnable的線程，CPU很閑時，則關註waiting for monitor entry的線程。

• JDK 5.0 的 Lock

上面提到如果 synchronized和 monitor機制運用不當，可能會造成多線程程式的性能問題。在 JDK 5.0中，引入了 Lock機制，從而使開發者能更靈活的開發高性能的併發多線程程式，可以替代以往 JDK中的 synchronized和 Monitor的 機制。但是，要註意的是，因為 Lock類只是一個普通類，JVM無從得知 Lock對象的占用情況，所以線上程 DUMP中，也不會包含關於 Lock的信息， 關於死鎖等問題，就不如用 synchronized的編程方式容易識別。

關鍵狀態示例

• 顯示BLOCKED狀態

package jstack;  

public class BlockedState  
{  
    private static Object object = new Object();  
    
    public static void main(String[] args)  
    {  
        Runnable task = new Runnable() {  

            @Override  
            public void run()  
            {  
                synchronized (object)  
                {  
                    long begin = System.currentTimeMillis();  
  
                    long end = System.currentTimeMillis();  

                    // 讓線程運行5分鐘,會一直持有object的監視器  
                    while ((end - begin) <= 5 * 60 * 1000)  
                    {  
  
                    }  
                }  
            }  
        };  

        new Thread(task, "t1").start();  
        new Thread(task, "t2").start();  
    }  
} 

Full thread dump Java HotSpot(TM) Server VM (20.12-b01 mixed mode):  
  
"DestroyJavaVM" prio=6 tid=0x00856c00 nid=0x1314 waiting on condition [0x00000000]  
java.lang.Thread.State: RUNNABLE  

"t2" prio=6 tid=0x27d7a800 nid=0x1350 waiting for monitor entry [0x2833f000]  
java.lang.Thread.State: BLOCKED (on object monitor)  
     at jstack.BlockedState$1.run(BlockedState.java:17)  
     - waiting to lock <0x1cfcdc00> (a java.lang.Object)  
     at java.lang.Thread.run(Thread.java:662)  

"t1" prio=6 tid=0x27d79400 nid=0x1338 runnable [0x282ef000]  
 java.lang.Thread.State: RUNNABLE  
     at jstack.BlockedState$1.run(BlockedState.java:22)  
     - locked <0x1cfcdc00> (a java.lang.Object)  
     at java.lang.Thread.run(Thread.java:662)

• 顯示WAITING狀態

package jstack;  
  
public class WaitingState  
{  
    private static Object object = new Object();  

    public static void main(String[] args)  
    {  
        Runnable task = new Runnable() {  

            @Override  
            public void run()  
            {  
                synchronized (object)  
                {  
                    long begin = System.currentTimeMillis();  
                    long end = System.currentTimeMillis();  

                    // 讓線程運行5分鐘,會一直持有object的監視器  
                    while ((end - begin) <= 5 * 60 * 1000)  
                    {  
                        try  
                        {  
                            // 進入等待的同時,會進入釋放監視器  
                            object.wait();  
                        } catch (InterruptedException e)  
                        {  
                            e.printStackTrace();  
                        }  
                    }  
                }  
            }  
        };  

        new Thread(task, "t1").start();  
        new Thread(task, "t2").start();  
    }  
}  
Full thread dump Java HotSpot(TM) Server VM (20.12-b01 mixed mode):  

"DestroyJavaVM" prio=6 tid=0x00856c00 nid=0x1734 waiting on condition [0x00000000]  
java.lang.Thread.State: RUNNABLE  

"t2" prio=6 tid=0x27d7e000 nid=0x17f4 in Object.wait() [0x2833f000]  
java.lang.Thread.State: WAITING (on object monitor)  
     at java.lang.Object.wait(Native Method)  
     - waiting on <0x1cfcdc00> (a java.lang.Object)  
     at java.lang.Object.wait(Object.java:485)  
     at jstack.WaitingState$1.run(WaitingState.java:26)  
     - locked <0x1cfcdc00> (a java.lang.Object)  
     at java.lang.Thread.run(Thread.java:662)  

"t1" prio=6 tid=0x27d7d400 nid=0x17f0 in Object.wait() [0x282ef000]  
java.lang.Thread.State: WAITING (on object monitor)  
     at java.lang.Object.wait(Native Method)  
     - waiting on <0x1cfcdc00> (a java.lang.Object)  
     at java.lang.Object.wait(Object.java:485)  
     at jstack.WaitingState$1.run(WaitingState.java:26)  
     - locked <0x1cfcdc00> (a java.lang.Object)  
     at java.lang.Thread.run(Thread.java:662)  

• 顯示TIMED_WAITING狀態

package jstack;  

import java.util.concurrent.TimeUnit;  
import java.util.concurrent.locks.Condition;  
import java.util.concurrent.locks.Lock;  
import java.util.concurrent.locks.ReentrantLock;  
  
public class TimedWaitingState  
{  
    // java的顯示鎖,類似java對象內置的監視器  
    private static Lock lock = new ReentrantLock();  
  
    // 鎖關聯的條件隊列(類似於object.wait)  
    private static Condition condition = lock.newCondition();  

    public static void main(String[] args)  
    {  
        Runnable task = new Runnable() {  

            @Override  
            public void run()  
            {  
                // 加鎖,進入臨界區  
                lock.lock();  
  
                try  
                {  
                    condition.await(5, TimeUnit.MINUTES);  
                } catch (InterruptedException e)  
                {  
                    e.printStackTrace();  
                }  
  
                // 解鎖,退出臨界區  
                lock.unlock();  
            }  
        };  
  
        new Thread(task, "t1").start();  
        new Thread(task, "t2").start();  
    }  
} 
Full thread dump Java HotSpot(TM) Server VM (20.12-b01 mixed mode):  

"DestroyJavaVM" prio=6 tid=0x00856c00 nid=0x169c waiting on condition [0x00000000]  
java.lang.Thread.State: RUNNABLE  

"t2" prio=6 tid=0x27d7d800 nid=0xc30 waiting on condition [0x2833f000]  
java.lang.Thread.State: TIMED_WAITING (parking)  
     at sun.misc.Unsafe.park(Native Method)  
     - parking to wait for  <0x1cfce5b8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)  
     at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:196)  
     at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2116)  
     at jstack.TimedWaitingState$1.run(TimedWaitingState.java:28)  
     at java.lang.Thread.run(Thread.java:662)  

"t1" prio=6 tid=0x280d0c00 nid=0x16e0 waiting on condition [0x282ef000]  
java.lang.Thread.State: TIMED_WAITING (parking)  
     at sun.misc.Unsafe.park(Native Method)  
     - parking to wait for  <0x1cfce5b8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)  
     at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:196)  
     at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2116)  
     at jstack.TimedWaitingState$1.run(TimedWaitingState.java:28)  
     at java.lang.Thread.run(Thread.java:662)  

案例分析

問題場景

• CPU飆高，load高，響應很慢

  1. 一個請求過程中多次dump；
  2. 對比多次dump文件的runnable線程，如果執行的方法有比較大變化，說明比較正常。如果在執行同一個方法，就有一些問題了；

• 查找占用CPU最多的線程

  1. 使用命令：top -H -p pid（pid為被測系統的進程號），找到導致CPU高的線程ID，對應thread dump信息中線程的nid，只不過一個是十進位，一個是十六進位；
  2. 在thread dump中，根據top命令查找的線程id，查找對應的線程堆棧信息；

• CPU使用率不高但是響應很慢

進行dump，查看是否有很多thread struck在了i/o、資料庫等地方，定位瓶頸原因；

• 請求無法響應

多次dump，對比是否所有的runnable線程都一直在執行相同的方法，如果是的，恭喜你，鎖住了！

死鎖

死鎖經常表現為程式的停頓，或者不再響應用戶的請求。從操作系統上觀察，對應進程的CPU占用率為零，很快會從top或prstat的輸出中消失。

比如在下麵這個示例中，是個較為典型的死鎖情況：

"Thread-1" prio=5 tid=0x00acc490 nid=0xe50 waiting for monitor entry [0x02d3f000 
..0x02d3fd68] 
at deadlockthreads.TestThread.run(TestThread.java:31) 
- waiting to lock <0x22c19f18> (a java.lang.Object) 
- locked <0x22c19f20> (a java.lang.Object) 

"Thread-0" prio=5 tid=0x00accdb0 nid=0xdec waiting for monitor entry [0x02cff000 
..0x02cff9e8] 
at deadlockthreads.TestThread.run(TestThread.java:31) 
- waiting to lock <0x22c19f20> (a java.lang.Object) 
- locked <0x22c19f18> (a java.lang.Object) 

Found one Java-level deadlock: 
============================= 
"Thread-1": 
waiting to lock monitor 0x0003f334 (object 0x22c19f18, a java.lang.Object), 
which is held by "Thread-0" 

"Thread-0": 
waiting to lock monitor 0x0003f314 (object 0x22c19f20, a java.lang.Object), 
which is held by "Thread-1"

熱鎖

熱鎖，也往往是導致系統性能瓶頸的主要因素。其表現特征為：由於多個線程對臨界區，或者鎖的競爭，可能出現：

• 頻繁的線程的上下文切換：從操作系統對線程的調度來看，當線程在等待資源而阻塞的時候，操作系統會將之切換出來，放到等待的隊列，當線程獲得資源之後，調度演算法會將這個線程切換進去，放到執行隊列中。
• 大量的系統調用：因為線程的上下文切換，以及熱鎖的競爭，或者臨界區的頻繁的進出，都可能導致大量的系統調用。
• 大部分CPU開銷用在“系統態”：線程上下文切換，和系統調用，都會導致 CPU在 “系統態 ”運行，換而言之，雖然系統很忙碌，但是CPU用在 “用戶態 ”的比例較小，應用程式得不到充分的 CPU資源。
• 隨著CPU數目的增多，系統的性能反而下降。因為CPU數目多，同時運行的線程就越多，可能就會造成更頻繁的線程上下文切換和系統態的CPU開銷，從而導致更糟糕的性能。

上面的描述，都是一個 scalability（可擴展性）很差的系統的表現。從整體的性能指標看，由於線程熱鎖的存在，程式的響應時間會變長，吞吐量會降低。

那麼，怎麼去瞭解 “熱鎖 ”出現在什麼地方呢？

一個重要的方法是 結合操作系統的各種工具觀察系統資源使用狀況，以及收集Java線程的DUMP信息，看線程都阻塞在什麼方法上，瞭解原因，才能找到對應的解決方法。

JVM重要線程

JVM運行過程中產生的一些比較重要的線程羅列如下：

點擊關註，第一時間瞭解華為雲新鮮技術~