一次 Java 內(nèi)存泄漏的排查

來源:https://zhenbianshu.github.io/2018/12/troubleshooting_java_memory_leak.html

一寇壳、由來

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

不知道是公司網(wǎng)絡(luò)廣了就這樣還是網(wǎng)絡(luò)運(yùn)維組不給力,網(wǎng)絡(luò)總有問題歇由,不是這邊交換機(jī)脫網(wǎng)了就是那邊路由器壞了卵牍,還偶發(fā)地各種超時(shí),而我們靈敏地服務(wù)探測(cè)服務(wù)總能準(zhǔn)確地抓住偶現(xiàn)的小問題沦泌,給美好的工作加點(diǎn)料糊昙。好幾次值班組的小伙伴們一起吐槽,商量著怎么避過服務(wù)毙磺活機(jī)制释牺,偷偷停了探測(cè)服務(wù)而不讓人發(fā)現(xiàn)(雖然也并不敢)。

前些天我就在周末處理了一次探測(cè)服務(wù)的鍋回挽。

二没咙、問題

1、網(wǎng)絡(luò)問題千劈?

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

這個(gè)線程棧的報(bào)錯(cuò)我見得多了涡驮,我們?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ù)端完全無感知合敦。

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

根據(jù)這個(gè)猜想,群登上服務(wù)器蒜魄,使用請(qǐng)求的 request_id 在近期服務(wù)日志中搜索一下扔亥,果不其然,就是網(wǎng)絡(luò)丟包問題導(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ù)說是我們探測(cè)服務(wù)所在機(jī)房的交換機(jī)老舊,存在未知的轉(zhuǎn)發(fā)瓶頸秕脓,正在優(yōu)化驹闰,這讓我更放心了,于是在部門群里簡單交待一下撒会,算是完成任務(wù)嘹朗。

2、問題爆發(fā)

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

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

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

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

三甫何、解決

1出吹、內(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)存泄漏沒跑了女气,于是 使用?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 查看類加載信息

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

-gc 垃圾回收信息

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

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

四赃阀、排查

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

1观游、分析棧

棧的分析很簡單搂捧,看一下線程數(shù)是不是過多,多數(shù)棧都在干嘛懂缕。

才四百多線程允跑,并無異常。

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

2、下載堆 dump 文件拌屏。

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

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

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

3兆衅、使用 MAT 分析 jvm heap

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

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

4及志、分析代碼

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

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

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

給代碼 owner 提了 PR,問題圓滿解決叁征。

五纳账、小結(jié)

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

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

擴(kuò)展閱讀

一次畢生難忘的 Java 內(nèi)存泄漏排查經(jīng)歷

深入分析 ThreadLocal 內(nèi)存泄漏問題

深入了解Java之虛擬機(jī)內(nèi)存

從面試題看問題之JVM和內(nèi)存

排查Java線上服務(wù)故障的方法和實(shí)例分析

?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請(qǐng)聯(lián)系作者
  • 序言:七十年代末官扣,一起剝皮案震驚了整個(gè)濱河市翅敌,隨后出現(xiàn)的幾起案子,更是在濱河造成了極大的恐慌醇锚,老刑警劉巖,帶你破解...
    沈念sama閱讀 218,122評(píng)論 6 505
  • 序言:濱河連續(xù)發(fā)生了三起死亡事件坯临,死亡現(xiàn)場(chǎng)離奇詭異焊唬,居然都是意外死亡,警方通過查閱死者的電腦和手機(jī)看靠,發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 93,070評(píng)論 3 395
  • 文/潘曉璐 我一進(jìn)店門赶促,熙熙樓的掌柜王于貴愁眉苦臉地迎上來,“玉大人挟炬,你說我怎么就攤上這事鸥滨∴露撸” “怎么了?”我有些...
    開封第一講書人閱讀 164,491評(píng)論 0 354
  • 文/不壞的土叔 我叫張陵婿滓,是天一觀的道長老速。 經(jīng)常有香客問我,道長凸主,這世上最難降的妖魔是什么橘券? 我笑而不...
    開封第一講書人閱讀 58,636評(píng)論 1 293
  • 正文 為了忘掉前任,我火速辦了婚禮卿吐,結(jié)果婚禮上旁舰,老公的妹妹穿的比我還像新娘。我一直安慰自己嗡官,他們只是感情好箭窜,可當(dāng)我...
    茶點(diǎn)故事閱讀 67,676評(píng)論 6 392
  • 文/花漫 我一把揭開白布。 她就那樣靜靜地躺著衍腥,像睡著了一般磺樱。 火紅的嫁衣襯著肌膚如雪。 梳的紋絲不亂的頭發(fā)上紧阔,一...
    開封第一講書人閱讀 51,541評(píng)論 1 305
  • 那天坊罢,我揣著相機(jī)與錄音,去河邊找鬼擅耽。 笑死活孩,一個(gè)胖子當(dāng)著我的面吹牛,可吹牛的內(nèi)容都是我干的乖仇。 我是一名探鬼主播憾儒,決...
    沈念sama閱讀 40,292評(píng)論 3 418
  • 文/蒼蘭香墨 我猛地睜開眼,長吁一口氣:“原來是場(chǎng)噩夢(mèng)啊……” “哼乃沙!你這毒婦竟也來了起趾?” 一聲冷哼從身側(cè)響起,我...
    開封第一講書人閱讀 39,211評(píng)論 0 276
  • 序言:老撾萬榮一對(duì)情侶失蹤警儒,失蹤者是張志新(化名)和其女友劉穎训裆,沒想到半個(gè)月后,有當(dāng)?shù)厝嗽跇淞掷锇l(fā)現(xiàn)了一具尸體蜀铲,經(jīng)...
    沈念sama閱讀 45,655評(píng)論 1 314
  • 正文 獨(dú)居荒郊野嶺守林人離奇死亡边琉,尸身上長有42處帶血的膿包…… 初始之章·張勛 以下內(nèi)容為張勛視角 年9月15日...
    茶點(diǎn)故事閱讀 37,846評(píng)論 3 336
  • 正文 我和宋清朗相戀三年,在試婚紗的時(shí)候發(fā)現(xiàn)自己被綠了记劝。 大學(xué)時(shí)的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片变姨。...
    茶點(diǎn)故事閱讀 39,965評(píng)論 1 348
  • 序言:一個(gè)原本活蹦亂跳的男人離奇死亡,死狀恐怖厌丑,靈堂內(nèi)的尸體忽然破棺而出定欧,到底是詐尸還是另有隱情渔呵,我是刑警寧澤,帶...
    沈念sama閱讀 35,684評(píng)論 5 347
  • 正文 年R本政府宣布砍鸠,位于F島的核電站扩氢,受9級(jí)特大地震影響,放射性物質(zhì)發(fā)生泄漏睦番。R本人自食惡果不足惜类茂,卻給世界環(huán)境...
    茶點(diǎn)故事閱讀 41,295評(píng)論 3 329
  • 文/蒙蒙 一、第九天 我趴在偏房一處隱蔽的房頂上張望托嚣。 院中可真熱鬧巩检,春花似錦、人聲如沸示启。這莊子的主人今日做“春日...
    開封第一講書人閱讀 31,894評(píng)論 0 22
  • 文/蒼蘭香墨 我抬頭看了看天上的太陽夫嗓。三九已至迟螺,卻和暖如春,著一層夾襖步出監(jiān)牢的瞬間舍咖,已是汗流浹背矩父。 一陣腳步聲響...
    開封第一講書人閱讀 33,012評(píng)論 1 269
  • 我被黑心中介騙來泰國打工, 沒想到剛下飛機(jī)就差點(diǎn)兒被人妖公主榨干…… 1. 我叫王不留排霉,地道東北人窍株。 一個(gè)月前我還...
    沈念sama閱讀 48,126評(píng)論 3 370
  • 正文 我出身青樓,卻偏偏與公主長得像攻柠,于是被迫代替她去往敵國和親球订。 傳聞我的和親對(duì)象是個(gè)殘疾皇子,可洞房花燭夜當(dāng)晚...
    茶點(diǎn)故事閱讀 44,914評(píng)論 2 355

推薦閱讀更多精彩內(nèi)容

  • 在一個(gè)方法內(nèi)部定義的變量都存儲(chǔ)在棧中瑰钮,當(dāng)這個(gè)函數(shù)運(yùn)行結(jié)束后冒滩,其對(duì)應(yīng)的棧就會(huì)被回收,此時(shí)浪谴,在其方法體中定義的變量將不...
    Y了個(gè)J閱讀 4,418評(píng)論 1 14
  • 前些日子小組內(nèi)安排值班苟耻,輪流看顧我們的服務(wù)篇恒,主要做一些報(bào)警郵件處理、Bug 排查梁呈、運(yùn)營 issue 處理的事婚度。工作...
    C語言學(xué)習(xí)圈1閱讀 332評(píng)論 0 0
  • 《深入理解Java虛擬機(jī)》筆記_第一遍 先取看完這本書(JVM)后必須掌握的部分蘸秘。 第一部分 走近 Java 從傳...
    xiaogmail閱讀 5,093評(píng)論 1 34
  • 第二部分 自動(dòng)內(nèi)存管理機(jī)制 第二章 java內(nèi)存異常與內(nèi)存溢出異常 運(yùn)行數(shù)據(jù)區(qū)域 程序計(jì)數(shù)器:當(dāng)前線程所執(zhí)行的字節(jié)...
    小明oh閱讀 1,164評(píng)論 0 2
  • 今日體驗(yàn) 今天晚上官卡,突博的老師開會(huì)蝗茁,學(xué)習(xí)如何銷售他們的產(chǎn)品,老師講的確實(shí)有點(diǎn)干貨寻咒,從中又學(xué)到了不少哮翘,現(xiàn)在要想的是如...
    劉大大暢閱讀 265評(píng)論 0 0