一次 Java 內存泄漏的排查

1、由來

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

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

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

2、問題

一、網絡問題？

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

這個線程棧的報錯我見得多了，咱們設置的 HTTP DNS 超時是 1s， connect 超時是 2s， read 超時是 3s，這種報錯都是探測服務正常發送了 HTTP 請求，服務器也在收到請求正常處理後正常響應了，但數據包在網絡層層轉發中丟失了，因此請求線程的執行棧會停留在獲取接口響應的地方。這種狀況的典型特徵就是能在服務器上查找到對應的日誌記錄。並且日誌會顯示服務器響應徹底正常。與它相對的還有線程棧停留在 Socket connect 處的，這是在建連時就失敗了，服務端徹底無感知。

我注意到其中一個接口報錯更頻繁一些，這個接口須要上傳一個 4M 的文件到服務器，而後通過一連串的業務邏輯處理，再返回 2M 的文本數據，而其餘的接口則是簡單的業務邏輯，我猜想多是須要上傳下載的數據太多，因此超時致使丟包的機率也更大吧。

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

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

二、問題爆發

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

此次幾乎全部的接口都在超時，而咱們那個大量網絡 I/O 的接口則是每次探測必超時，難道是整個機房故障了麼。

我再次經過服務器和監控看到各個接口的指標都很正常，本身測試了下接口也徹底 OK，既然不影響線上服務，我準備先經過探測服務的接口把探測任務停掉再慢慢排查。

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

3、解決

一、內存泄漏

因而趕快登錄探測服務器，首先是 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 的內存問題頗有幫助。

4、排查

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

一、分析棧

棧的分析很簡單，看一下線程數是否是過多，多數棧都在幹嗎。

才四百多線程，並沒有異常。

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

二、下載堆 dump 文件。

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

因爲咱們設置的堆內存爲 4G，因此 dump 出來的堆文件也很大，下載它確實很是費事，不過咱們能夠先對它進行一次壓縮。

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

三、使用 MAT 分析 jvm heap

MAT 是分析 Java 堆內存的利器，使用它打開咱們的堆文件（將文件後綴改成 .hprof）, 它會提示咱們要分析的種類，對於此次分析，果斷選擇 memory leak suspect。

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

四、分析代碼

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

這個 Map 根據類型用 ArrayList 存儲了每次探測接口響應的結果，每次探測完都塞到 ArrayList 裏去分析，因爲 Bean 對象不會被回收，這個屬性又沒有清除邏輯，因此在服務十來天沒有上線重啓的狀況下，這個 Map 愈來愈大，直至將內存佔滿。

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

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

5、小結

其實仍是要檢討一下本身的，一開始報警郵件裏還有這樣的線程棧：

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