Labs 導(dǎo)讀

作為Java開(kāi)發(fā)者，在日常工作中經(jīng)常會(huì)碰到Java服務(wù)端程序無(wú)法響應(yīng)客戶端的請(qǐng)求，輕則影響用戶體驗(yàn)，重則會(huì)造成重大故障。這種無(wú)法響應(yīng)客戶端的請(qǐng)求就是常說(shuō)的服務(wù)“假死”、“卡住了”。那么，在這種“假死”的背后到底發(fā)生了什么事，本該正常響應(yīng)客戶端請(qǐng)求的進(jìn)程、線程又在做什么呢？本文帶你來(lái)揭曉這一答案。

Part 01、 程序“假死”的跡象  

服務(wù)端程序卡死之后，最常見(jiàn)的現(xiàn)象是無(wú)法響應(yīng)客戶端請(qǐng)求，結(jié)果返回特別慢直至超時(shí)。如果是網(wǎng)頁(yè)服務(wù)，那么用戶會(huì)發(fā)現(xiàn)該頁(yè)面會(huì)無(wú)法訪問(wèn)，或者一直加載不出來(lái)。

如果此時(shí)深入查看Http協(xié)議，其返回狀態(tài)碼一般是504（Gateway Timeout），提示網(wǎng)關(guān)超時(shí)。如果該程序?qū)?yīng)的進(jìn)程還在存活在操作系統(tǒng)中，在排除了網(wǎng)絡(luò)、服務(wù)器問(wèn)題后，可以認(rèn)為該程序已經(jīng)“假死”，無(wú)法再繼續(xù)提供服務(wù)。有些程序在假死后過(guò)一段時(shí)間可以自己恢復(fù)，然而更多的時(shí)候需要人工介入重啟程序才能恢復(fù)正常。

Part 02、如何定位假死問(wèn)題 

接下來(lái)我們看一下當(dāng)碰到程序假死問(wèn)題時(shí)，應(yīng)該從哪些方面著手處理，如何快速定位到根本原因。

2.1 常用的工具

工欲善其事必先利其器，我們首先來(lái)看下一些常用的診斷問(wèn)題的工具。

2.1.1 top命令

top命令是Linux下常用的性能分析工具，能夠?qū)崟r(shí)顯示系統(tǒng)中各個(gè)進(jìn)程的資源占用狀況，操作系統(tǒng)自帶。在終端中輸入top即可看到正在運(yùn)行的所有進(jìn)程占用的CPU、內(nèi)存、運(yùn)行時(shí)間等，也能夠大致知曉當(dāng)前服務(wù)器的運(yùn)行狀態(tài)。

top命令結(jié)果

以上是一張典型的top命令結(jié)果圖，可以看出java進(jìn)程進(jìn)行占用了 44.7%的內(nèi)存，118.8%的CPU（多核的CPU使用率會(huì)超過(guò)100%），但系統(tǒng)1分鐘的平均負(fù)載（load average）只有0.92，運(yùn)行較為穩(wěn)定。

2.1.2 jstat命令

jstat 是用于監(jiān)控虛擬機(jī)各種運(yùn)行狀態(tài)信息的命令行工具，包括了對(duì)Heap size和垃圾回收狀況的監(jiān)控，由JDK提供。當(dāng)需要了解JVM的運(yùn)行狀態(tài)時(shí)它是首選工具。比如需要每秒查看一次JVM的垃圾回收狀態(tài)，可以使用：

jstat命令結(jié)果

上圖是進(jìn)程號(hào)為4417的JVM進(jìn)程的內(nèi)存使用情況，S0和S1是新生代中幸存區(qū)使用比例，E是伊甸園區(qū)空間使用比例，O是老年代空間使用比例；YGC是新生代垃圾回收次數(shù)，YGCT是新生代垃圾回收總時(shí)間；FGC是老年代垃圾回收次數(shù)，F(xiàn)GCT是老年代垃圾回收總時(shí)間，GCT是垃圾回收總時(shí)間。當(dāng)出現(xiàn)內(nèi)存不夠用時(shí)，O會(huì)出現(xiàn)100%，并且FGC和FGCT持續(xù)增加，比較容易辨別。

2.1.3 jmap命令

jmap是JDK提供的一個(gè)可以生成JVM的堆轉(zhuǎn)儲(chǔ)快照dump文件的命令行工具。除此以外，jmap命令還可以查看finalize執(zhí)行隊(duì)列、Java堆和方法區(qū)的詳細(xì)信息，比如空間使用率、當(dāng)前使用的什么垃圾回收器、分代情況等等。當(dāng)出現(xiàn)內(nèi)存問(wèn)題時(shí)，就需要jmap命令將內(nèi)存堆轉(zhuǎn)儲(chǔ)成文件進(jìn)行詳細(xì)的分析了。常用的命令如下：

該命令將堆轉(zhuǎn)儲(chǔ)成名為memory.hprof的文件，后續(xù)可以使用堆內(nèi)存分析工具（如Eclipse Memory Analyzer）等進(jìn)行詳細(xì)分析，在此不再展開(kāi)。

2.1.4 jstack命令

jstack是JDK提供的一個(gè)可以生成JVM當(dāng)前時(shí)刻的線程快照信息的命令行工具，可以探查在命令執(zhí)行那一刻JVM中每個(gè)線程都在做什么。在實(shí)際使用中，可以每隔10秒鐘執(zhí)行一次，連續(xù)執(zhí)行幾次再對(duì)比分析，實(shí)際中的輸出內(nèi)多會(huì)比較多，建議轉(zhuǎn)存到文件中方便分析。常用的命令如下：

jstack命令部分結(jié)果

上圖是jstack命令的部分結(jié)果，顯示名為logback-8的線程此刻正在等待狀態(tài)，未執(zhí)行實(shí)際的任務(wù)。

2.2 診斷三把斧

JVM進(jìn)程假死其實(shí)就是線程不夠用了，忙不過(guò)來(lái)，用以下三把斧依次施行，基本上能夠覆蓋90%以上場(chǎng)景。

2.2.1 看進(jìn)程

首先，使用top命令對(duì)服務(wù)器的負(fù)載和進(jìn)程的資源使用做一個(gè)評(píng)估。尤其關(guān)注top命令中的負(fù)載指標(biāo)和進(jìn)程的CPU、內(nèi)存使用率。負(fù)載代表服務(wù)器的繁忙程度，它綜合了CPU、IO等指標(biāo)，負(fù)載/CPU數(shù) > 1 代表服務(wù)器非常繁忙。當(dāng)系統(tǒng)負(fù)載高時(shí)，而每一個(gè)進(jìn)程的CPU都不高時(shí)，要考慮服務(wù)器是否已經(jīng)過(guò)載，比如運(yùn)行進(jìn)程過(guò)多、IO瓶頸等。當(dāng)某個(gè)進(jìn)程的CPU使用高時(shí)，問(wèn)題大概率出在該進(jìn)程中，即可對(duì)該進(jìn)程進(jìn)行探查。（本文只討論JVM，故進(jìn)程特指JVM進(jìn)程）

2.2.2 看內(nèi)存

使用jstat命令查看JVM的內(nèi)存狀態(tài)。當(dāng)JVM內(nèi)存泄漏導(dǎo)致堆內(nèi)存無(wú)法回收、堆內(nèi)存不夠用從而觸發(fā)頻繁的Full GC時(shí)，JVM會(huì)停頓程序的執(zhí)行進(jìn)行全面的垃圾回收（stop the world），此時(shí)程序?qū)o(wú)法響應(yīng)請(qǐng)求，GC線程會(huì)占用大量的CPU時(shí)間。當(dāng)這種情況發(fā)生時(shí)，會(huì)出現(xiàn)進(jìn)程CPU使用率很高，接近系統(tǒng)極限。堆內(nèi)存中老年代空間使用比例接近或達(dá)到100%，F(xiàn)GC、FGCT在持續(xù)地上升（正常情況下Full GC幾小時(shí)甚至幾天才執(zhí)行一次）。

當(dāng)判斷為進(jìn)程因內(nèi)存問(wèn)題而一直在Full GC時(shí)，可以使用jmap命令將內(nèi)存dump下來(lái)進(jìn)行進(jìn)一步的分析，查找內(nèi)存泄漏的對(duì)象，進(jìn)而進(jìn)一步找到內(nèi)存泄漏點(diǎn)。此外，值得注意的一點(diǎn)是如果堆內(nèi)存本身設(shè)得很小，而程序需要的內(nèi)存又很多，JVM會(huì)嘗試去回收內(nèi)存，也會(huì)出現(xiàn)頻繁的Full GC而導(dǎo)致CPU使用率升高的情況。這就需要具體問(wèn)題具體分析了。

2.2.3 看線程

使用jstack命令查看線程狀態(tài)。當(dāng)操作系統(tǒng)、堆內(nèi)存都無(wú)明顯異常情況下，需要進(jìn)一步探查每一個(gè)線程都在做什么。線程無(wú)法處理更多任務(wù)，要么是線程都很忙（單核 CPU 100%），要么是都在等待（CPU使用率不高），極少數(shù)是處于死鎖狀態(tài)，而這些都可以從jstack的命令結(jié)果中看出來(lái)。

jstack會(huì)顯示每個(gè)線程當(dāng)前所處的程序棧。如果多個(gè)線程處在同一個(gè)程序棧，那么要引起高度注意，可以通過(guò)連續(xù)幾個(gè)間隔10秒左右的jstack結(jié)果查看該線程是否一直處于同一位置，如果是那么大概率是卡在了這里。如果是死循環(huán)，那么CPU使用率會(huì)很高，如果是等待IO，那么CPU使用率會(huì)很低。通過(guò)卡住的程序棧，可以較容易定位到代碼行并進(jìn)行進(jìn)一步的分析了。

Part 03、 案例實(shí)戰(zhàn) 

了解完基本的理論知識(shí)，下面通過(guò)實(shí)際工作中碰到的案例來(lái)使用三把斧進(jìn)行分析。

3.1 案例一：IO等待

系統(tǒng)表現(xiàn)：界面無(wú)響應(yīng)，請(qǐng)求API也無(wú)響應(yīng)。

看進(jìn)程：top命令顯示系統(tǒng)負(fù)載很低，進(jìn)程CPU、內(nèi)存使用也無(wú)異常。

看內(nèi)存：jstat命令顯示堆內(nèi)存表現(xiàn)正常：

jstat顯示堆內(nèi)存狀態(tài)正常

看線程：jstack命令顯示絕大部分線程都卡在同一個(gè)地方：

出現(xiàn)io等待的線程

通過(guò)進(jìn)一步檢查AbstractProvinceServiceImpl.sendPost方法，發(fā)現(xiàn)是使用java原生的HttpUrlConnection來(lái)實(shí)現(xiàn)Http請(qǐng)求的方法，而該方法未設(shè)置超時(shí)時(shí)間，如果被調(diào)用方未返回會(huì)一直等待。

有缺陷的代碼

至此，問(wèn)題原因查明：因代碼缺陷，在發(fā)起http請(qǐng)求時(shí)未設(shè)置超時(shí)時(shí)間，而恰好此時(shí)被調(diào)用方系統(tǒng)故障，無(wú)法及時(shí)返回，從而導(dǎo)致線程都卡在這里等待IO，無(wú)更多的線程來(lái)響應(yīng)其他請(qǐng)求了。

3.2 案例二：死循環(huán)

系統(tǒng)表現(xiàn)：系統(tǒng)響應(yīng)很慢，api請(qǐng)求有一定的錯(cuò)誤率。

看進(jìn)程：top命令顯示系統(tǒng)負(fù)載較高（1核CPU），進(jìn)程CPU達(dá)到190%，系統(tǒng)過(guò)載。

負(fù)載較高，進(jìn)程CPU使用率較高

看內(nèi)存：jstat命令顯示堆內(nèi)存表現(xiàn)正常，無(wú)明顯的內(nèi)存問(wèn)題。

看線程：多次間隔執(zhí)行jstack命令，發(fā)現(xiàn)一部分進(jìn)程一直卡在同一個(gè)地方：

出現(xiàn)死循環(huán)的線程

通過(guò)查看相關(guān)代碼發(fā)現(xiàn)這里有個(gè)死循環(huán)，當(dāng)變量cur一直不為null時(shí)，程序無(wú)法跳出循環(huán)。通過(guò)更進(jìn)一步的分析，最終找數(shù)據(jù)庫(kù)中的一條數(shù)據(jù)其CateParentId是自己，從而觸發(fā)這個(gè)死循環(huán)的bug。

...


while (Objects.nonNull(cur)) { 
    allCateName.insert(0, "/"); 
    allCateName.insert(0, cur.getCateName()); 
    cur = goodsCatePOMap.get(cur.getCateParentId()); 
} 


...

Part 04、  總結(jié) 

對(duì)于Java服務(wù)端假死，可以通過(guò)本文介紹的三把斧，利用一些常用工具來(lái)對(duì)程序內(nèi)部的運(yùn)行狀態(tài)進(jìn)行分析。掌握這個(gè)方法后，基本上可以定位到工作中碰到的90%以上的java程序假死問(wèn)題。下表是對(duì)可能的假死原因做一個(gè)簡(jiǎn)單的歸納總結(jié)：