分享一次 Java 内存泄漏的排查
由來
前些日子小組內(nèi)安排值班,輪流看顧我們的服務(wù),主要做一些報警郵件處理、Bug 排查、運營 issue 處理的事。工作日還好,無論干什么都要上班的,若是輪到周末,那這一天算是毀了。
不知道是公司網(wǎng)絡(luò)廣了就這樣還是網(wǎng)絡(luò)運維組不給力,網(wǎng)絡(luò)總有問題,不是這邊交換機脫網(wǎng)了就是那邊路由器壞了,還偶發(fā)地各種超時,而我們靈敏地服務(wù)探測服務(wù)總能準(zhǔn)確地抓住偶現(xiàn)的小問題,給美好的工作加點料。好幾次值班組的小伙伴們一起吐槽,商量著怎么避過服務(wù)保活機制,偷偷停了探測服務(wù)而不讓人發(fā)現(xiàn)(雖然也并不敢)。
前些天我就在周末處理了一次探測服務(wù)的鍋。
問題
網(wǎng)絡(luò)問題?
晚上七點多開始,我就開始不停地收到報警郵件,郵件顯示探測的幾個接口有超時情況。多數(shù)執(zhí)行棧都在:
java.io.BufferedReader.readLine(BufferedReader.java:371) java.io.BufferedReader.readLine(BufferReader.java:389) java_io_BufferedReader$readLine.call(Unknown?Source) com.domain.detect.http.HttpClient.getResponse(HttpClient.groovy:122) com.domain.detect.http.HttpClient.this$2$getResponse(HttpClient.groovy)這個線程棧的報錯我見得多了,我們設(shè)置的 HTTP DNS 超時是 1s, connect 超時是 2s, read 超時是 3s,這種報錯都是探測服務(wù)正常發(fā)送了 HTTP 請求,服務(wù)器也在收到請求正常處理后正常響應(yīng)了,但數(shù)據(jù)包在網(wǎng)絡(luò)層層轉(zhuǎn)發(fā)中丟失了,所以請求線程的執(zhí)行棧會停留在獲取接口響應(yīng)的地方。這種情況的典型特征就是能在服務(wù)器上查找到對應(yīng)的日志記錄。而且日志會顯示服務(wù)器響應(yīng)完全正常。與它相對的還有線程棧停留在 Socket connect 處的,這是在建連時就失敗了,服務(wù)端完全無感知。
我注意到其中一個接口報錯更頻繁一些,這個接口需要上傳一個 4M 的文件到服務(wù)器,然后經(jīng)過一連串的業(yè)務(wù)邏輯處理,再返回 2M 的文本數(shù)據(jù),而其他的接口則是簡單的業(yè)務(wù)邏輯,我猜測可能是需要上傳下載的數(shù)據(jù)太多,所以超時導(dǎo)致丟包的概率也更大吧。
根據(jù)這個猜想,群登上服務(wù)器,使用請求的 request_id 在近期服務(wù)日志中搜索一下,果不其然,就是網(wǎng)絡(luò)丟包問題導(dǎo)致的接口超時了。
當(dāng)然這樣 leader 是不會滿意的,這個結(jié)論還得有人接鍋才行。于是趕緊聯(lián)系運維和網(wǎng)絡(luò)組,向他們確認一下當(dāng)時的網(wǎng)絡(luò)狀態(tài)。網(wǎng)絡(luò)組同學(xué)回復(fù)說是我們探測服務(wù)所在機房的交換機老舊,存在未知的轉(zhuǎn)發(fā)瓶頸,正在優(yōu)化,這讓我更放心了,于是在部門群里簡單交待一下,算是完成任務(wù)。
問題爆發(fā)
本以為這次值班就起這么一個小波浪,結(jié)果在晚上八點多,各種接口的報警郵件蜂擁而至,打得準(zhǔn)備收拾東西過周日單休的我措手不及。
這次幾乎所有的接口都在超時,而我們那個大量網(wǎng)絡(luò) I/O 的接口則是每次探測必超時,難道是整個機房故障了么。
我再次通過服務(wù)器和監(jiān)控看到各個接口的指標(biāo)都很正常,自己測試了下接口也完全 OK,既然不影響線上服務(wù),我準(zhǔn)備先通過探測服務(wù)的接口把探測任務(wù)停掉再慢慢排查。
結(jié)果給暫停探測任務(wù)的接口發(fā)請求好久也沒有響應(yīng),這時候我才知道沒這么簡單。
解決
內(nèi)存泄漏
于是趕快登陸探測服務(wù)器,首先是?top free df?三連,結(jié)果還真發(fā)現(xiàn)了些異常。
我們的探測進程 CPU 占用率特別高,達到了 900%。
我們的 Java 進程,并不做大量 CPU 運算,正常情況下,CPU 應(yīng)該在 100~200% 之間,出現(xiàn)這種 CPU 飆升的情況,要么走到了死循環(huán),要么就是在做大量的 GC。
使用?jstat -gc pid [interval]?命令查看了 java 進程的 GC 狀態(tài),果然,FULL GC 達到了每秒一次。
這么多的 FULL GC,應(yīng)該是內(nèi)存泄漏沒跑了,于是 使用?jstack pid > jstack.log?保存了線程棧的現(xiàn)場,使用?jmap -dump:format=b,file=heap.log pid?保存了堆現(xiàn)場,然后重啟了探測服務(wù),報警郵件終于停止了。
jstat
jstat 是一個非常強大的 JVM 監(jiān)控工具,一般用法是:?jstat [-options] pid interval
它支持的查看項有:
-
-class 查看類加載信息
-
-compile 編譯統(tǒng)計信息
-
-gc 垃圾回收信息
-
-gcXXX 各區(qū)域 GC 的詳細信息 如 -gcold
使用它,對定位 JVM 的內(nèi)存問題很有幫助。
排查
問題雖然解決了,但為了防止它再次發(fā)生,還是要把根源揪出來。
分析棧
棧的分析很簡單,看一下線程數(shù)是不是過多,多數(shù)棧都在干嘛。
>?grep?'java.lang.Thread.State'?jstack.log??|?wc?-l >?464才四百多線程,并無異常。
>?grep?-A?1?'java.lang.Thread.State'?jstack.log??|?grep?-v?'java.lang.Thread.State'?|?sort?|?uniq?-c?|sort?-n10?????at?java.lang.Class.forName0(Native?Method)10?????at?java.lang.Object.wait(Native?Method)16?????at?java.lang.ClassLoader.loadClass(ClassLoader.java:404)44?????at?sun.nio.ch.EPollArrayWrapper.epollWait(Native?Method)344?????at?sun.misc.Unsafe.park(Native?Method)線程狀態(tài)好像也無異常,接下來分析堆文件。
下載堆 dump 文件。
堆文件都是一些二進制數(shù)據(jù),在命令行查看非常麻煩,Java 為我們提供的工具都是可視化的,Linux 服務(wù)器上又沒法查看,那么首先要把文件下載到本地。
由于我們設(shè)置的堆內(nèi)存為 4G,所以 dump 出來的堆文件也很大,下載它確實非常費事,不過我們可以先對它進行一次壓縮。
gzip?是個功能很強大的壓縮命令,特別是我們可以設(shè)置?-1 ~ -9?來指定它的壓縮級別,數(shù)據(jù)越大壓縮比率越大,耗時也就越長,推薦使用 -6~7, -9 實在是太慢了,且收益不大,有這個壓縮的時間,多出來的文件也下載好了。
使用 MAT 分析 jvm heap
MAT 是分析 Java 堆內(nèi)存的利器,使用它打開我們的堆文件(將文件后綴改為?.hprof), 它會提示我們要分析的種類,對于這次分析,果斷選擇?memory leak suspect。
從上面的餅圖中可以看出,絕大多數(shù)堆內(nèi)存都被同一個內(nèi)存占用了,再查看堆內(nèi)存詳情,向上層追溯,很快就發(fā)現(xiàn)了罪魁禍?zhǔn)住?/p>
分析代碼
找到內(nèi)存泄漏的對象了,在項目里全局搜索對象名,它是一個 Bean 對象,然后定位到它的一個類型為 Map 的屬性。
這個 Map 根據(jù)類型用 ArrayList 存儲了每次探測接口響應(yīng)的結(jié)果,每次探測完都塞到 ArrayList 里去分析,由于 Bean 對象不會被回收,這個屬性又沒有清除邏輯,所以在服務(wù)十來天沒有上線重啟的情況下,這個 Map 越來越大,直至將內(nèi)存占滿。
內(nèi)存滿了之后,無法再給 HTTP 響應(yīng)結(jié)果分配內(nèi)存了,所以一直卡在 readLine 那。而我們那個大量 I/O 的接口報警次數(shù)特別多,估計跟響應(yīng)太大需要更多內(nèi)存有關(guān)。
給代碼 owner 提了 PR,問題圓滿解決。
小結(jié)
其實還是要反省一下自己的,一開始報警郵件里還有這樣的線程棧:
groovy.json.internal.JsonParserCharArray.decodeValueInternal(JsonParserCharArray.java:166) groovy.json.internal.JsonParserCharArray.decodeJsonObject(JsonParserCharArray.java:132) groovy.json.internal.JsonParserCharArray.decodeValueInternal(JsonParserCharArray.java:186) groovy.json.internal.JsonParserCharArray.decodeJsonObject(JsonParserCharArray.java:132) groovy.json.internal.JsonParserCharArray.decodeValueInternal(JsonParserCharArray.java:186)看到這種報錯線程棧卻沒有細想,要知道 TCP 是能保證消息完整性的,況且消息沒有接收完也不會把值賦給變量,這種很明顯的是內(nèi)部錯誤,如果留意后細查是能提前查出問題所在的,查問題真是差了哪一環(huán)都不行啊。
總結(jié)
以上是生活随笔為你收集整理的分享一次 Java 内存泄漏的排查的全部內(nèi)容,希望文章能夠幫你解決所遇到的問題。
- 上一篇: 面试问红黑树,我脸都绿了。。
- 下一篇: 面试 4 个月,最终入职大厂经验分享!