“卡死”醇王,說的比較口語化,換個視角就有思路了:卡死就是線程阻塞了搁吓。
說一下背景原茅,項目都是 Java 應(yīng)用,容器是 tomcat堕仔,應(yīng)用發(fā)布就是 tomcat shutdown擂橘,然后 tomcat start,一般看啟動日志 catalina.out 能看到啟動時 spring ApplicationContext 啟動過程中的各種日志摩骨,中間件的加載也會輸出日志通贞。所以啟動卡死,看到的現(xiàn)象就是:打印了幾行日志恼五,就不往下繼續(xù)打印了昌罩,應(yīng)用一直處于不可用狀態(tài),直到發(fā)布超時灾馒。
從線程角度考慮茎用,此時就是線程阻塞住了,就需要知道各個線程是在做什么睬罗,找出可疑的線程轨功,順藤摸瓜,看它在干什么傅物。
一個實例
一直卡住夯辖,馬上現(xiàn)場定位, 執(zhí)行ps -ef | grep java
找出 tomcat 進(jìn)程的 pid董饰,然后執(zhí)行 jstack [pid]
蒿褂,因為 tomcat 是應(yīng)用程序以 nobody
的身份啟動的圆米,所以提示權(quán)限不足,聯(lián)系運(yùn)維開通權(quán)限之后以 root 身份執(zhí)行即可啄栓。
tomcat 發(fā)布啟動的時候卡住娄帖,那就是主線程阻塞了,直接定位到以下線程堆棧:
"main" prio=10 tid=0x00007f99e0012800 nid=0x5246 waiting on condition [0x00007f99e74c5000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000e5a16058> (a java.util.concurrent.CountDownLatch$Sync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:994)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1303)
at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:236)
at com.xyz.client.http.domain.PollFuture.get(PollFuture.java:54)
at com.xyz.client.http.PollWorker.get(PollWorker.java:107)
- locked <0x00000000e2901da8> (a com.xyz.client.http.PollWorker)
at com.xyz.client.http.ProjectManager.load(ProjectManager.java:200)
可以看到線程此刻處于 waiting 狀態(tài)昙楚,在等待什么呢近速?waiting on condition [0x00007f99e74c5000]
條件等待,繼續(xù)看堆棧堪旧,跟 CountDownLatch 有關(guān)削葱,繼續(xù)往棧下層看,com.xyz.client.http.domain.PollFuture.get
就是內(nèi)部中間件的代碼了淳梦,證明在 get 的時候阻塞在了 CountDownLatch.await()
方法上了析砸。
到這一步,基本可以拿著堆棧找中間件相關(guān)的同事定位了爆袍,一般還可以找到此時中間件相關(guān)的一些日志首繁,注意 ERROR
級別的日志,幫助他們更快找到問題陨囊。
作為思考弦疮,想想為什么阻塞在 await 了?了解 CountDownLatch
的原理就可以想到蜘醋,一定是某個地方?jīng)]有執(zhí)行 latch.countDown()
操作胁塞,或者執(zhí)行的次數(shù)不夠√煤看 PollFuture
相關(guān)的代碼闲先,有如下聲明,this.latch = new CountDownLatch(1);
這就更好定位了无蜂,證明 countdown 一次沒執(zhí)行成功伺糠,搜索執(zhí)行 countdown 操作的地方,只有一處斥季,如下:
public void setResult(Object result) {
this.result = result;
if(result == null) {
// no changes
return;
}
// do something
latch.countDown();
}
于是可以知道训桶,這里 result == null
成立,往上層繼續(xù)排查就是了酣倾。
最終定位下來舵揭,某個極端條件下,setResult()
前一步的請求出錯躁锡,返回 error 信息午绳,于是處理出來的 result 為空。
另一個例子
上面的例子是啟動完全阻塞映之,永遠(yuǎn)不會繼續(xù)拦焚。這個例子的現(xiàn)象是 tomcat 啟動超時蜡坊,表現(xiàn)就是斷斷續(xù)續(xù)輸出日志,部分機(jī)器啟動能成功赎败,部分不成功秕衙,其實也不是完全不會啟動,只是超過了timeout = 50000ms
的啟動超時時長僵刮,發(fā)布系統(tǒng)就提示啟動失敗据忘。
一樣的思路,重新發(fā)布超時的機(jī)器搞糕,然后登錄上去勇吊,jstack [pid]
輸出若干線程信息,但是只看到有些線程 waiting 窍仰,多執(zhí)行幾次命令萧福,又發(fā)現(xiàn)有時會繼續(xù)執(zhí)行。
聯(lián)系架構(gòu)的同事辈赋,也是一樣的操作,執(zhí)行若干次命令之后膏燕,觀察幾次輸出的差異钥屈,看到有個線程會 sleep,這個線程此時的動作是:去遠(yuǎn)程拿一批服務(wù)注冊項信息坝辫。順著堆棧信息進(jìn)一步定位發(fā)現(xiàn)篷就,這個是 RPC 框架調(diào)用內(nèi)部另一個組件的接口拿注冊項信息,該接口的處理是:獲取超時就 sleep 3s近忙,然后再獲取竭业,重試 n 次。多番定位之后及舍,升級組件解決問題未辆。
由此可以看出,定位線程阻塞問題锯玛,一次輸出甚至多次輸出可能還不夠咐柜,對引入的組件代碼不熟悉,可能也無法確認(rèn)問題攘残。熟悉代碼的人大致知道哪些地方拙友,哪些后臺線程可能阻塞。還有賴于平時多積累歼郭,遇到問題多請教遗契。
總結(jié)
記得兩年前,同事遇到過一次定時任務(wù)發(fā)布的時候啟動卡死的問題病曾,當(dāng)時直覺可能跟線程死鎖有關(guān)牍蜂,不過我們都沒有想到怎么入手排查漾根。當(dāng)時所有排查問題的思路都局限于“看代碼”、設(shè)置斷點捷兰、加日志立叛,差別無非是,測試環(huán)境可以調(diào)試贡茅,就靠斷點秘蛇,生產(chǎn)環(huán)境要求嚴(yán)格、不能影響服務(wù)顶考,所以只能靠日志和代碼赁还,總的來說,都局限在自己維護(hù)的業(yè)務(wù)代碼中驹沿,進(jìn)了斷點艘策,什么都好說,這類不知道怎么加斷點的問題渊季,就束手無策朋蔫。
從線程阻塞類問題可以認(rèn)識到,有時候要從整個運(yùn)行時體系去考慮却汉,甚至要從部署結(jié)構(gòu)考慮驯妄,轉(zhuǎn)換視角能發(fā)現(xiàn)更多問題,也會有更多方法合砂。