摘要：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();
.........
}
synchronized 獲得了這個物件的 Monitor（對應於 locked <0xb3885f60> ）。當執行到 obj.wait()，執行緒即放棄了 Monitor的所有權，進入 “wait set”佇列（對應於 waiting on <0xb3885f60> ）。在堆疊的第一行資訊中，進一步標明瞭執行緒在程式碼級的狀態，例如：
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高，響應很慢
- 一個請求過程中多次dump；
- 對比多次dump檔案的runnable執行緒，如果執行的方法有比較大變化，說明比較正常。如果在執行同一個方法，就有一些問題了；
-
查詢佔用CPU最多的執行緒
- 使用命令：top -H -p pid（pid為被測系統的程式號），找到導致CPU高的執行緒ID，對應thread dump資訊中執行緒的nid，只不過一個是十進位制，一個是十六進位制；
- 在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執行過程中產生的一些比較重要的執行緒羅列如下：
