摘要: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)臨界區的設定,是為了保證其內部的代碼執行的原子性和完整性,但是因為臨界區在任何時間只允許執行緒串行通過,這和我們多執行緒的程式的初衷是相反的,如果在多執行緒的程式中,大量使用 synchronized,或者不適當的使用了它,會造成大量執行緒在臨界區的入口等待,造成系統的性能大幅下降,如果在執行緒 DUMP中發現了這個情況,應該審查原始碼,改行程式,
再看“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(); } }先獲取object的執行緒會執行5分鐘,這5分鐘內會一直持有object的監視器,另一個執行緒無法執行處在BLOCKED狀態:
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)通過thread dump可以看到:t2執行緒確實處在BLOCKED (on object monitor),waiting for monitor entry 等待進入synchronized保護的區域,
- 顯示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)可以發現t1和t2都處在WAITING (on object monitor),進入等待狀態的原因是呼叫了in Object.wait(),通過J.U.C包下的鎖和條件佇列,也是這個效果,大家可以自己實踐下,
- 顯示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)可以看到t1和t2執行緒都處在java.lang.Thread.State: TIMED_WAITING (parking),這個parking代表是呼叫的JUC下的工具類,而不是java默認的監視器,
案例分析
問題場景
-
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)在 JAVA 5中加強了對死鎖的檢測,執行緒 Dump中可以直接報告出 Java級別的死鎖,如下所示:
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運行程序中產生的一些比較重要的執行緒羅列如下:

點擊關注,第一時間了解華為云新鮮技術~
轉載請註明出處,本文鏈接:https://www.uj5u.com/houduan/540776.html
標籤:其他
