一次 Java 記憶體洩漏的排查

一、由來

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

不知道是公司網路廣了就這樣還是網路運維組不給力，網路總有問題，不是這邊交換機脫網了就是那邊路由器壞了，還偶發地各種超時，而我們靈敏地服務探測服務總能準確地抓住偶現的小問題，給美好的工作加點料。好幾次值班組的小夥伴們一起吐槽，商量著怎麼避過服務保活機制，偷偷停了探測服務而不讓人發現（雖然也並不敢）。

前些天我就在週末處理了一次探測服務的鍋。

二、問題

1、網路問題？

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

這個執行緒棧的報錯我見得多了，我們設定的 HTTP DNS 超時是 1s， connect 超時是 2s， read 超時是 3s，這種報錯都是探測服務正常傳送了 HTTP 請求，伺服器也在收到請求正常處理後正常響應了，但資料包在網路層層轉發中丟失了，所以請求執行緒的執行棧會停留在獲取介面響應的地方。這種情況的典型特徵就是能在伺服器上查詢到對應的日誌記錄。而且日誌會顯示伺服器響應完全正常。與它相對的還有執行緒棧停留在 Socket connect 處的，這是在建連時就失敗了，服務端完全無感知。

我注意到其中一個介面報錯更頻繁一些，這個介面需要上傳一個 4M 的檔案到伺服器，然後經過一連串的業務邏輯處理，再返回 2M 的文字資料，而其他的介面則是簡單的業務邏輯，我猜測可能是需要上傳下載的資料太多，所以超時導致丟包的機率也更大吧。

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

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

2、問題爆發

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

這次幾乎所有的介面都在超時，而我們那個大量網路 I/O 的介面則是每次探測必超時，難道是整個機房故障了麼。

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

結果給暫停探測任務的介面發請求好久也沒有響應，這時候我才知道沒這麼簡單。

三、解決

1、記憶體洩漏

於是趕快登陸探測伺服器，首先是 top free df 三連，結果還真發現了些異常。

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

我們的 Java 程式，並不做大量 CPU 運算，正常情況下，CPU 應該在 100~200% 之間，出現這種 CPU 飆升的情況，要麼走到了死迴圈，要麼就是在做大量的 GC。

使用 jstat -gc pid [interval] 命令檢視了 java 程式的 GC 狀態，果然，FULL GC 達到了每秒一次。

這麼多的 FULL GC，應該是記憶體洩漏沒跑了，於是 使用 jstack pid > jstack.log 儲存了執行緒棧的現場，使用 jmap -dump:format=b,file=heap.log pid 儲存了堆現場，然後重啟了探測服務，報警郵件終於停止了。

jstat

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

它支援的檢視項有：

-class 檢視類載入資訊

-compile 編譯統計資訊

-gc 垃圾回收資訊

-gcXXX 各區域 GC 的詳細資訊 如 -gcold

使用它，對定位 JVM 的記憶體問題很有幫助。

四、排查

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

1、分析棧

棧的分析很簡單，看一下執行緒數是不是過多，多數棧都在幹嘛。

才四百多執行緒，並無異常。

執行緒狀態好像也無異常，接下來分析堆檔案。

2、下載堆 dump 檔案。

堆檔案都是一些二進位制資料，在命令列檢視非常麻煩，Java 為我們提供的工具都是視覺化的，Linux 伺服器上又沒法檢視，那麼首先要把檔案下載到本地。

由於我們設定的堆記憶體為 4G，所以 dump 出來的堆檔案也很大，下載它確實非常費事，不過我們可以先對它進行一次壓縮。

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

3、使用 MAT 分析 jvm heap

MAT 是分析 Java 堆記憶體的利器，使用它開啟我們的堆檔案（將檔案字尾改為 .hprof）, 它會提示我們要分析的種類，對於這次分析，果斷選擇 memory leak suspect。

從上面的餅圖中可以看出，絕大多數堆記憶體都被同一個記憶體佔用了，再檢視堆記憶體詳情，向上層追溯，很快就發現了罪魁禍首。

4、分析程式碼

找到記憶體洩漏的物件了，在專案裡全域性搜尋物件名，它是一個 Bean 物件，然後定位到它的一個型別為 Map 的屬性。

這個 Map 根據型別用 ArrayList 儲存了每次探測介面響應的結果，每次探測完都塞到 ArrayList 裡去分析，由於 Bean 物件不會被回收，這個屬性又沒有清除邏輯，所以在服務十來天沒有上線重啟的情況下，這個 Map 越來越大，直至將記憶體佔滿。

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

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

五、小結

其實還是要反省一下自己的，一開始報警郵件裡還有這樣的執行緒棧：

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