三個(gè)實(shí)例演示 Java Thread Dump 日志分析

jstack dump 文件里腥沽,值得關(guān)注的線程狀態(tài)有:

  1. 死鎖,Deadlock(重點(diǎn)關(guān)注)
  2. 執(zhí)行中,Runnable
  3. 等待資源襟衰,Waiting on condition(重點(diǎn)關(guān)注)
  4. 等待獲取監(jiān)視器满败,Waiting on monitor entry(重點(diǎn)關(guān)注)
  5. 暫停肤频,Suspended
  6. 對(duì)象等待中,Object.wait() 或 TIMED_WAITING
  7. 阻塞算墨,Blocked(重點(diǎn)關(guān)注)
  8. 停止宵荒,Parked

下面我們先從第一個(gè)例子開(kāi)始分析,然后再列出不同線程狀態(tài)的含義以及注意事項(xiàng)净嘀,最后再補(bǔ)充兩個(gè)實(shí)例报咳。

綜合示范一:Waiting to lock 和 Blocked

實(shí)例如下:

"RMI TCP Connection(267865)-172.16.5.25" daemon prio=10 tid=0x00007fd508371000 nid=0x55ae waiting for monitor entry [0x00007fd4f8684000]
   java.lang.Thread.State: BLOCKED (on object monitor)
at org.apache.log4j.Category.callAppenders(Category.java:201)
   - waiting to lock <0x00000000acf4d0c0> (a org.apache.log4j.Logger)
at org.apache.log4j.Category.forcedLog(Category.java:388)
at org.apache.log4j.Category.log(Category.java:853)
at org.apache.commons.logging.impl.Log4JLogger.warn(Log4JLogger.java:234)
at com.tuan.core.common.lang.cache.remote.SpyMemcachedClient.get(SpyMemcachedClient.java:110)
……

1)線程狀態(tài)是 Blocked,阻塞狀態(tài)挖藏。說(shuō)明線程等待資源超時(shí)暑刃!
2)“ waiting to lock <0x00000000acf4d0c0>”指,線程在等待給這個(gè) 0x00000000acf4d0c0 地址上鎖(英文可描述為:trying to obtain 0x00000000acf4d0c0 lock)膜眠。
3)在 dump 日志里查找字符串 0x00000000acf4d0c0稍走,發(fā)現(xiàn)有大量線程都在等待給這個(gè)地址上鎖。如果能在日志里找到誰(shuí)獲得了這個(gè)鎖(如locked < 0x00000000acf4d0c0 >)柴底,就可以順藤摸瓜了婿脸。
4)“waiting for monitor entry”說(shuō)明此線程通過(guò) synchronized(obj) {……} 申請(qǐng)進(jìn)入了臨界區(qū),從而進(jìn)入了下圖1中的“Entry Set”隊(duì)列柄驻,但該 obj 對(duì)應(yīng)的 monitor 被其他線程擁有狐树,所以本線程在 Entry Set 隊(duì)列中等待。
5)第一行里鸿脓,"RMI TCP Connection(267865)-172.16.5.25"是 Thread Name 抑钟。tid指Java Thread id涯曲。nid指native線程的id。prio是線程優(yōu)先級(jí)在塔。[0x00007fd4f8684000]是線程棧起始地址幻件。

Dump文件中的線程狀態(tài)含義及注意事項(xiàng)

含義如下所示:

  • Deadlock:死鎖線程,一般指多個(gè)線程調(diào)用間蛔溃,進(jìn)入相互資源占用绰沥,導(dǎo)致一直等待無(wú)法釋放的情況。
  • Runnable:一般指該線程正在執(zhí)行狀態(tài)中贺待,該線程占用了資源徽曲,正在處理某個(gè)請(qǐng)求,有可能正在傳遞SQL到數(shù)據(jù)庫(kù)執(zhí)行麸塞,有可能在對(duì)某個(gè)文件操作秃臣,有可能進(jìn)行數(shù)據(jù)類(lèi)型等轉(zhuǎn)換。
  • Waiting on condition:等待資源哪工,或等待某個(gè)條件的發(fā)生奥此。具體原因需結(jié)合 stacktrace來(lái)分析。
  • 如果堆棧信息明確是應(yīng)用代碼雁比,則證明該線程正在等待資源得院。一般是大量讀取某資源,且該資源采用了資源鎖的情況下章贞,線程進(jìn)入等待狀態(tài),等待資源的讀取非洲。
  • 又或者鸭限,正在等待其他線程的執(zhí)行等。
  • 如果發(fā)現(xiàn)有大量的線程都在處在 Wait on condition两踏,從線程 stack看败京,正等待網(wǎng)絡(luò)讀寫(xiě),這可能是一個(gè)網(wǎng)絡(luò)瓶頸的征兆梦染。因?yàn)榫W(wǎng)絡(luò)阻塞導(dǎo)致線程無(wú)法執(zhí)行赡麦。
  • 一種情況是網(wǎng)絡(luò)非常忙,幾乎消耗了所有的帶寬帕识,仍然有大量數(shù)據(jù)等待網(wǎng)絡(luò)讀寫(xiě)泛粹;
  • 另一種情況也可能是網(wǎng)絡(luò)空閑,但由于路由等問(wèn)題肮疗,導(dǎo)致包無(wú)法正常的到達(dá)晶姊。
  • 另外一種出現(xiàn) Wait on condition的常見(jiàn)情況是該線程在 sleep,等待 sleep的時(shí)間到了時(shí)候伪货,將被喚醒们衙。
  • Blocked:線程阻塞钾怔,是指當(dāng)前線程執(zhí)行過(guò)程中,所需要的資源長(zhǎng)時(shí)間等待卻一直未能獲取到蒙挑,被容器的線程管理器標(biāo)識(shí)為阻塞狀態(tài)宗侦,可以理解為等待資源超時(shí)的線程。
  • Waiting for monitor entry 和 in Object.wait():Monitor是 Java中用以實(shí)現(xiàn)線程之間的互斥與協(xié)作的主要手段忆蚀,它可以看成是對(duì)象或者 Class的鎖矾利。每一個(gè)對(duì)象都有,也僅有一個(gè) monitor蜓谋。從下圖1中可以看出梦皮,每個(gè) Monitor在某個(gè)時(shí)刻,只能被一個(gè)線程擁有桃焕,該線程就是 “Active Thread”剑肯,而其它線程都是 “Waiting Thread”,分別在兩個(gè)隊(duì)列 “ Entry Set”和 “Wait Set”里面等候观堂。在 “Entry Set”中等待的線程狀態(tài)是 “Waiting for monitor entry”让网,而在 “Wait Set”中等待的線程狀態(tài)是 “in Object.wait()”。
image.png

圖1 A Java Monitor

綜合示范二:Waiting on condition 和 TIMED_WAITING

實(shí)例如下:

"RMI TCP Connection(idle)" daemon prio=10 tid=0x00007fd50834e800 nid=0x56b2 waiting on condition [0x00007fd4f1a59000]
   java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for  <0x00000000acd84de8> (a java.util.concurrent.SynchronousQueue$TransferStack)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:198)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:424)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:323)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:874)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:945)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
at java.lang.Thread.run(Thread.java:662)

1)“TIMED_WAITING (parking)”中的 timed_waiting 指等待狀態(tài)师痕,但這里指定了時(shí)間溃睹,到達(dá)指定的時(shí)間后自動(dòng)退出等待狀態(tài);parking指線程處于掛起中胰坟。
2)“waiting on condition”需要與堆棧中的“parking to wait for <0x00000000acd84de8> (a java.util.concurrent.SynchronousQueue$TransferStack)”結(jié)合來(lái)看因篇。首先,本線程肯定是在等待某個(gè)條件的發(fā)生笔横,來(lái)把自己?jiǎn)拘丫鹤摇F浯危琒ynchronousQueue 并不是一個(gè)隊(duì)列吹缔,只是線程之間移交信息的機(jī)制商佑,當(dāng)我們把一個(gè)元素放入到 SynchronousQueue 中時(shí)必須有另一個(gè)線程正在等待接受移交的任務(wù),因此這就是本線程在等待的條件厢塘。
3)別的就看不出來(lái)了茶没。

綜合示范三:in Obejct.wait() 和 TIMED_WAITING

實(shí)例如下:

"RMI RenewClean-[172.16.5.19:28475]" daemon prio=10 tid=0x0000000041428800 nid=0xb09 in Object.wait() [0x00007f34f4bd0000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000000aa672478> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
- locked <0x00000000aa672478> (a java.lang.ref.ReferenceQueue$Lock)
at sun.rmi.transport.DGCClient$EndpointEntry$RenewCleanThread.run(DGCClient.java:516)
at java.lang.Thread.run(Thread.java:662)

1)“TIMED_WAITING (on object monitor)”,對(duì)于本例而言晚碾,是因?yàn)楸揪€程調(diào)用了 java.lang.Object.wait(long timeout) 而進(jìn)入等待狀態(tài)抓半。
2)“Wait Set”中等待的線程狀態(tài)就是“ in Object.wait() ”。當(dāng)線程獲得了 Monitor格嘁,進(jìn)入了臨界區(qū)之后琅关,如果發(fā)現(xiàn)線程繼續(xù)運(yùn)行的條件沒(méi)有滿足,它則調(diào)用對(duì)象(一般就是被 synchronized 的對(duì)象)的 wait() 方法,放棄了 Monitor涣易,進(jìn)入 “Wait Set”隊(duì)列画机。只有當(dāng)別的線程在該對(duì)象上調(diào)用了 notify() 或者 notifyAll() ,“ Wait Set”隊(duì)列中線程才得到機(jī)會(huì)去競(jìng)爭(zhēng)新症,但是只有一個(gè)線程獲得對(duì)象的 Monitor步氏,恢復(fù)到運(yùn)行態(tài)。
3)RMI RenewClean 是 DGCClient 的一部分徒爹。DGC 指的是 Distributed GC荚醒,即分布式垃圾回收。
4)請(qǐng)注意隆嗅,是先 locked <0x00000000aa672478>稼病,后 waiting on <0x00000000aa672478>谒撼,之所以先鎖再等同一個(gè)對(duì)象组贺,請(qǐng)看下面它的代碼實(shí)現(xiàn):

static private class  Lock { };
private Lock lock = new Lock();
public Reference<? extends T> remove(long timeout) {
    synchronized (lock) {
        Reference<? extends T> r = reallyPoll();
        if (r != null) return r;
        for (;;) {
            lock.wait(timeout);
            r = reallyPoll();
            ……
       }
}

即儿普,線程的執(zhí)行中,先用 synchronized 獲得了這個(gè)對(duì)象的 Monitor(對(duì)應(yīng)于 locked <0x00000000aa672478> )丽焊;當(dāng)執(zhí)行到 lock.wait(timeout);较剃,線程就放棄了 Monitor 的所有權(quán),進(jìn)入“Wait Set”隊(duì)列(對(duì)應(yīng)于 waiting on <0x00000000aa672478> )技健。

5)從堆棧信息看写穴,是正在清理 remote references to remote objects ,引用的租約到了雌贱,分布式垃圾回收在逐一清理呢啊送。

最后編輯于
?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請(qǐng)聯(lián)系作者
  • 序言:七十年代末,一起剝皮案震驚了整個(gè)濱河市欣孤,隨后出現(xiàn)的幾起案子馋没,更是在濱河造成了極大的恐慌,老刑警劉巖导街,帶你破解...
    沈念sama閱讀 221,198評(píng)論 6 514
  • 序言:濱河連續(xù)發(fā)生了三起死亡事件,死亡現(xiàn)場(chǎng)離奇詭異纤子,居然都是意外死亡搬瑰,警方通過(guò)查閱死者的電腦和手機(jī),發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 94,334評(píng)論 3 398
  • 文/潘曉璐 我一進(jìn)店門(mén)控硼,熙熙樓的掌柜王于貴愁眉苦臉地迎上來(lái)泽论,“玉大人,你說(shuō)我怎么就攤上這事卡乾∫磴玻” “怎么了?”我有些...
    開(kāi)封第一講書(shū)人閱讀 167,643評(píng)論 0 360
  • 文/不壞的土叔 我叫張陵,是天一觀的道長(zhǎng)鹦赎。 經(jīng)常有香客問(wèn)我谍椅,道長(zhǎng),這世上最難降的妖魔是什么古话? 我笑而不...
    開(kāi)封第一講書(shū)人閱讀 59,495評(píng)論 1 296
  • 正文 為了忘掉前任雏吭,我火速辦了婚禮,結(jié)果婚禮上陪踩,老公的妹妹穿的比我還像新娘杖们。我一直安慰自己,他們只是感情好肩狂,可當(dāng)我...
    茶點(diǎn)故事閱讀 68,502評(píng)論 6 397
  • 文/花漫 我一把揭開(kāi)白布摘完。 她就那樣靜靜地躺著,像睡著了一般傻谁。 火紅的嫁衣襯著肌膚如雪孝治。 梳的紋絲不亂的頭發(fā)上,一...
    開(kāi)封第一講書(shū)人閱讀 52,156評(píng)論 1 308
  • 那天栅螟,我揣著相機(jī)與錄音荆秦,去河邊找鬼。 笑死力图,一個(gè)胖子當(dāng)著我的面吹牛步绸,可吹牛的內(nèi)容都是我干的。 我是一名探鬼主播吃媒,決...
    沈念sama閱讀 40,743評(píng)論 3 421
  • 文/蒼蘭香墨 我猛地睜開(kāi)眼瓤介,長(zhǎng)吁一口氣:“原來(lái)是場(chǎng)噩夢(mèng)啊……” “哼!你這毒婦竟也來(lái)了赘那?” 一聲冷哼從身側(cè)響起刑桑,我...
    開(kāi)封第一講書(shū)人閱讀 39,659評(píng)論 0 276
  • 序言:老撾萬(wàn)榮一對(duì)情侶失蹤,失蹤者是張志新(化名)和其女友劉穎募舟,沒(méi)想到半個(gè)月后祠斧,有當(dāng)?shù)厝嗽跇?shù)林里發(fā)現(xiàn)了一具尸體,經(jīng)...
    沈念sama閱讀 46,200評(píng)論 1 319
  • 正文 獨(dú)居荒郊野嶺守林人離奇死亡拱礁,尸身上長(zhǎng)有42處帶血的膿包…… 初始之章·張勛 以下內(nèi)容為張勛視角 年9月15日...
    茶點(diǎn)故事閱讀 38,282評(píng)論 3 340
  • 正文 我和宋清朗相戀三年琢锋,在試婚紗的時(shí)候發(fā)現(xiàn)自己被綠了。 大學(xué)時(shí)的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片呢灶。...
    茶點(diǎn)故事閱讀 40,424評(píng)論 1 352
  • 序言:一個(gè)原本活蹦亂跳的男人離奇死亡吴超,死狀恐怖,靈堂內(nèi)的尸體忽然破棺而出鸯乃,到底是詐尸還是另有隱情鲸阻,我是刑警寧澤,帶...
    沈念sama閱讀 36,107評(píng)論 5 349
  • 正文 年R本政府宣布,位于F島的核電站鸟悴,受9級(jí)特大地震影響陈辱,放射性物質(zhì)發(fā)生泄漏。R本人自食惡果不足惜遣臼,卻給世界環(huán)境...
    茶點(diǎn)故事閱讀 41,789評(píng)論 3 333
  • 文/蒙蒙 一性置、第九天 我趴在偏房一處隱蔽的房頂上張望。 院中可真熱鬧揍堰,春花似錦鹏浅、人聲如沸。這莊子的主人今日做“春日...
    開(kāi)封第一講書(shū)人閱讀 32,264評(píng)論 0 23
  • 文/蒼蘭香墨 我抬頭看了看天上的太陽(yáng)。三九已至蝙眶,卻和暖如春季希,著一層夾襖步出監(jiān)牢的瞬間,已是汗流浹背幽纷。 一陣腳步聲響...
    開(kāi)封第一講書(shū)人閱讀 33,390評(píng)論 1 271
  • 我被黑心中介騙來(lái)泰國(guó)打工式塌, 沒(méi)想到剛下飛機(jī)就差點(diǎn)兒被人妖公主榨干…… 1. 我叫王不留,地道東北人友浸。 一個(gè)月前我還...
    沈念sama閱讀 48,798評(píng)論 3 376
  • 正文 我出身青樓峰尝,卻偏偏與公主長(zhǎng)得像,于是被迫代替她去往敵國(guó)和親收恢。 傳聞我的和親對(duì)象是個(gè)殘疾皇子武学,可洞房花燭夜當(dāng)晚...
    茶點(diǎn)故事閱讀 45,435評(píng)論 2 359