開發導致的內存泄露問題,運維小夥伴兒這樣排查不背鍋

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

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

好幾次值班組的小夥伴們一起吐槽,商量着怎麼避過服務保活機制,偷偷停了探測服務而不讓人發現(雖然也並不敢)。

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

 

一、問題

網絡問題?

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

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

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

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

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

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

問題爆發

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

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

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

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

二、解決

內存泄漏

於是趕快登陸探測服務器,首先是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的內存問題很有幫助。

 

三、排查

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

分析棧

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

才四百多線程,並無異常。

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

下載堆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,問題圓滿解決。

 

四、小結

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

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

 

作者:枕邊書

來源://zhenbianshu.github.io


 

關注微信公眾號:大數據學習與分享,獲取更對技術乾貨