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

不知道是公司網絡廣了就這樣還是網絡運維組不給力，網絡總有問題，不是這邊交換機脫網了，就是那邊路由器壞了，還偶發(fā)地各種超時，而我們靈敏地服務探測服務總能準確地抓住偶現的小問題，給美好的工作加點料。

[[257200]]

好幾次值班組的小伙伴們一起吐槽，商量著怎么避過服務保活機制，偷偷停了探測服務而不讓人發(fā)現(雖然也并不敢)。

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

一、問題

網絡問題?

晚上七點多開始，我就開始不停地收到報警郵件，郵件顯示探測的幾個接口有超時情況。 多數執(zhí)行棧都在：

這個線程棧的報錯我見得多了，我們設置的HTTP DNS超時是1s，connect超時是2s，read超時是3s，這種報錯都是探測服務正常發(fā)送了HTTP請求，服務器也在收到請求正常處理后正常響應了，但數據包在網絡層層轉發(fā)中丟失了，所以請求線程的執(zhí)行棧會停留在獲取接口響應的地方。

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

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

根據這個猜想，群登上服務器，使用請求的request_id在近期服務日志中搜索一下，果不其然，就是網絡丟包問題導致的接口超時了。

當然這樣leader是不會滿意的，這個結論還得有人接鍋才行。于是趕緊聯系運維和網絡組，向他們確認一下當時的網絡狀態(tài)。網絡組同學回復說是我們探測服務所在機房的交換機老舊，存在未知的轉發(fā)瓶頸，正在優(yōu)化，這讓我更放心了，于是在部門群里簡單交待一下，算是完成任務。

問題爆發(fā)

本以為這次值班就起這么一個小波浪，結果在晚上八點多，各種接口的報警郵件蜂擁而至，打得準備收拾東西過周日單休的我措手不及。

這次幾乎所有的接口都在超時，而我們那個大量網絡I/O的接口則是每次探測必超時，難道是整個機房故障了么?

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

結果給暫停探測任務的接口發(fā)請求好久也沒有響應，這時候我才知道沒這么簡單。

二、解決

內存泄漏

于是趕快登陸探測服務器，首先是top free df三連，結果還真發(fā)現了些異常。

我們的探測進程CPU占用率特別高，達到了900%。

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

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

這么多的FULL GC，應該是內存泄漏沒跑了，于是使用jstack pid > jstack.log保存了線程棧的現場，使用jmap -dump:format=b,file=heap.log pid保存了堆現場，然后重啟了探測服務，報警郵件終于停止了。

jstat

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

它支持的查看項有：

class查看類加載信息

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

gc垃圾回收信息

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

使用它，對定位JVM的內存問題很有幫助。

三、排查

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

分析棧

棧的分析很簡單，看一下線程數是不是過多，多數棧都在干嘛。

才四百多線程，并無異常。

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

下載堆dump文件

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

由于我們設置的堆內存為4G，所以dump出來的堆文件也很大，下載它確實非常費事，不過我們可以先對它進行一次壓縮。

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

使用MAT分析jvm heap

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

從上面的餅圖中可以看出，絕大多數堆內存都被同一個內存占用了，再查看堆內存詳情，向上層追溯，很快就發(fā)現了罪魁禍首。

分析代碼

找到內存泄漏的對象了，在項目里全局搜索對象名，它是一個Bean對象，然后定位到它的一個類型為Map的屬性。

這個Map根據類型用ArrayList存儲了每次探測接口響應的結果，每次探測完都塞到ArrayList里去分析，由于Bean對象不會被回收，這個屬性又沒有清除邏輯，所以在服務十來天沒有上線重啟的情況下，這個Map越來越大，直至將內存占滿。

內存滿了之后，無法再給HTTP響應結果分配內存了，所以一直卡在readLine那。而我們那個大量I/O的接口報警次數特別多，估計跟響應太大需要更多內存有關。

給代碼owner提了PR，問題圓滿解決。

四、小結

其實還是要反省一下自己的，一開始報警郵件里還有這樣的線程棧：

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