前些日子小組內(nèi)安排值班，輪流看顧我們的服務(wù)，主要做一些報(bào)警郵件處理、Bug排查、運(yùn)營(yíng)issue處理的事。工作日還好，無(wú)論干什么都要上班的，若是輪到周末，那這一天算是毀了。

不知道是公司網(wǎng)絡(luò)廣了就這樣還是網(wǎng)絡(luò)運(yùn)維組不給力，網(wǎng)絡(luò)總有問(wèn)題，不是這邊交換機(jī)脫網(wǎng)了，就是那邊路由器壞了，還偶發(fā)地各種超時(shí)，而我們靈敏地服務(wù)探測(cè)服務(wù)總能準(zhǔn)確地抓住偶現(xiàn)的小問(wèn)題，給美好的工作加點(diǎn)料。

[[257200]]

好幾次值班組的小伙伴們一起吐槽，商量著怎么避過(guò)服務(wù)?；顧C(jī)制，偷偷停了探測(cè)服務(wù)而不讓人發(fā)現(xiàn)(雖然也并不敢)。

前些天我就在周末處理了一次探測(cè)服務(wù)的鍋。本文會(huì)持續(xù)修訂，大家可以繼續(xù)關(guān)注。

一、問(wèn)題

網(wǎng)絡(luò)問(wèn)題?

晚上七點(diǎn)多開(kāi)始，我就開(kāi)始不停地收到報(bào)警郵件，郵件顯示探測(cè)的幾個(gè)接口有超時(shí)情況。 多數(shù)執(zhí)行棧都在：

這個(gè)線程棧的報(bào)錯(cuò)我見(jiàn)得多了，我們?cè)O(shè)置的HTTP DNS超時(shí)是1s，connect超時(shí)是2s，read超時(shí)是3s，這種報(bào)錯(cuò)都是探測(cè)服務(wù)正常發(fā)送了HTTP請(qǐng)求，服務(wù)器也在收到請(qǐng)求正常處理后正常響應(yīng)了，但數(shù)據(jù)包在網(wǎng)絡(luò)層層轉(zhuǎn)發(fā)中丟失了，所以請(qǐng)求線程的執(zhí)行棧會(huì)停留在獲取接口響應(yīng)的地方。

這種情況的典型特征就是能在服務(wù)器上查找到對(duì)應(yīng)的日志記錄。而且日志會(huì)顯示服務(wù)器響應(yīng)完全正常。與它相對(duì)的還有線程棧停留在Socket connect處的，這是在建連時(shí)就失敗了，服務(wù)端完全無(wú)感知。

我注意到其中一個(gè)接口報(bào)錯(cuò)更頻繁一些，這個(gè)接口需要上傳一個(gè)4M的文件到服務(wù)器，然后經(jīng)過(guò)一連串的業(yè)務(wù)邏輯處理，再返回2M的文本數(shù)據(jù)，而其他的接口則是簡(jiǎn)單的業(yè)務(wù)邏輯，我猜測(cè)可能是需要上傳下載的數(shù)據(jù)太多，所以超時(shí)導(dǎo)致丟包的概率也更大吧。

根據(jù)這個(gè)猜想，群登上服務(wù)器，使用請(qǐng)求的request_id在近期服務(wù)日志中搜索一下，果不其然，就是網(wǎng)絡(luò)丟包問(wèn)題導(dǎo)致的接口超時(shí)了。

當(dāng)然這樣leader是不會(huì)滿意的，這個(gè)結(jié)論還得有人接鍋才行。于是趕緊聯(lián)系運(yùn)維和網(wǎng)絡(luò)組，向他們確認(rèn)一下當(dāng)時(shí)的網(wǎng)絡(luò)狀態(tài)。網(wǎng)絡(luò)組同學(xué)回復(fù)說(shuō)是我們探測(cè)服務(wù)所在機(jī)房的交換機(jī)老舊，存在未知的轉(zhuǎn)發(fā)瓶頸，正在優(yōu)化，這讓我更放心了，于是在部門(mén)群里簡(jiǎn)單交待一下，算是完成任務(wù)。

問(wèn)題爆發(fā)

本以為這次值班就起這么一個(gè)小波浪，結(jié)果在晚上八點(diǎn)多，各種接口的報(bào)警郵件蜂擁而至，打得準(zhǔn)備收拾東西過(guò)周日單休的我措手不及。

這次幾乎所有的接口都在超時(shí)，而我們那個(gè)大量網(wǎng)絡(luò)I/O的接口則是每次探測(cè)必超時(shí)，難道是整個(gè)機(jī)房故障了么?

我再次通過(guò)服務(wù)器和監(jiān)控看到各個(gè)接口的指標(biāo)都很正常，自己測(cè)試了下接口也完全OK，既然不影響線上服務(wù)，我準(zhǔn)備先通過(guò)探測(cè)服務(wù)的接口把探測(cè)任務(wù)停掉再慢慢排查。

結(jié)果給暫停探測(cè)任務(wù)的接口發(fā)請(qǐng)求好久也沒(méi)有響應(yīng)，這時(shí)候我才知道沒(méi)這么簡(jiǎn)單。

二、解決

內(nèi)存泄漏

于是趕快登陸探測(cè)服務(wù)器，首先是top free df三連，結(jié)果還真發(fā)現(xiàn)了些異常。

我們的探測(cè)進(jìn)程CPU占用率特別高，達(dá)到了900%。

我們的Java進(jìn)程，并不做大量CPU運(yùn)算，正常情況下，CPU應(yīng)該在100~200%之間，出現(xiàn)這種CPU飆升的情況，要么走到了死循環(huán)，要么就是在做大量的GC。

使用jstat -gc pid [interval]命令查看了java進(jìn)程的GC狀態(tài)，果然，F(xiàn)ULL GC達(dá)到了每秒一次。

這么多的FULL GC，應(yīng)該是內(nèi)存泄漏沒(méi)跑了，于是使用jstack pid > jstack.log保存了線程棧的現(xiàn)場(chǎng)，使用jmap -dump:format=b,file=heap.log pid保存了堆現(xiàn)場(chǎng)，然后重啟了探測(cè)服務(wù)，報(bào)警郵件終于停止了。

jstat

jstat是一個(gè)非常強(qiáng)大的JVM監(jiān)控工具，一般用法是：jstat [-options] pid interval

它支持的查看項(xiàng)有：

class查看類(lèi)加載信息

compile編譯統(tǒng)計(jì)信息

gc垃圾回收信息

gcXXX各區(qū)域GC的詳細(xì)信息，如-gcold

使用它，對(duì)定位JVM的內(nèi)存問(wèn)題很有幫助。

三、排查

問(wèn)題雖然解決了，但為了防止它再次發(fā)生，還是要把根源揪出來(lái)。

分析棧

棧的分析很簡(jiǎn)單，看一下線程數(shù)是不是過(guò)多，多數(shù)棧都在干嘛。

才四百多線程，并無(wú)異常。

線程狀態(tài)好像也無(wú)異常，接下來(lái)分析堆文件。

下載堆dump文件

堆文件都是一些二進(jìn)制數(shù)據(jù)，在命令行查看非常麻煩，Java為我們提供的工具都是可視化的，Linux服務(wù)器上又沒(méi)法查看，那么首先要把文件下載到本地。

由于我們?cè)O(shè)置的堆內(nèi)存為4G，所以dump出來(lái)的堆文件也很大，下載它確實(shí)非常費(fèi)事，不過(guò)我們可以先對(duì)它進(jìn)行一次壓縮。

gzip是個(gè)功能很強(qiáng)大的壓縮命令，特別是我們可以設(shè)置-1~-9來(lái)指定它的壓縮級(jí)別，數(shù)據(jù)越大壓縮比率越大，耗時(shí)也就越長(zhǎng)，推薦使用-6~7，-9實(shí)在是太慢了，且收益不大，有這個(gè)壓縮的時(shí)間，多出來(lái)的文件也下載好了。

使用MAT分析jvm heap

MAT是分析Java堆內(nèi)存的利器，使用它打開(kāi)我們的堆文件(將文件后綴改為 .hprof), 它會(huì)提示我們要分析的種類(lèi)，對(duì)于這次分析，果斷選擇memory leak suspect。

從上面的餅圖中可以看出，絕大多數(shù)堆內(nèi)存都被同一個(gè)內(nèi)存占用了，再查看堆內(nèi)存詳情，向上層追溯，很快就發(fā)現(xiàn)了罪魁禍?zhǔn)住?/p>

分析代碼

找到內(nèi)存泄漏的對(duì)象了，在項(xiàng)目里全局搜索對(duì)象名，它是一個(gè)Bean對(duì)象，然后定位到它的一個(gè)類(lèi)型為Map的屬性。

這個(gè)Map根據(jù)類(lèi)型用ArrayList存儲(chǔ)了每次探測(cè)接口響應(yīng)的結(jié)果，每次探測(cè)完都塞到ArrayList里去分析，由于Bean對(duì)象不會(huì)被回收，這個(gè)屬性又沒(méi)有清除邏輯，所以在服務(wù)十來(lái)天沒(méi)有上線重啟的情況下，這個(gè)Map越來(lái)越大，直至將內(nèi)存占滿。

內(nèi)存滿了之后，無(wú)法再給HTTP響應(yīng)結(jié)果分配內(nèi)存了，所以一直卡在readLine那。而我們那個(gè)大量I/O的接口報(bào)警次數(shù)特別多，估計(jì)跟響應(yīng)太大需要更多內(nèi)存有關(guān)。

給代碼owner提了PR，問(wèn)題圓滿解決。

四、小結(jié)

其實(shí)還是要反省一下自己的，一開(kāi)始報(bào)警郵件里還有這樣的線程棧：

看到這種報(bào)錯(cuò)線程棧卻沒(méi)有細(xì)想，要知道TCP是能保證消息完整性的，況且消息沒(méi)有接收完也不會(huì)把值賦給變量，這種很明顯的是內(nèi)部錯(cuò)誤，如果留意后細(xì)查是能提前查出問(wèn)題所在的，查問(wèn)題真是差了哪一環(huán)都不行啊。