來源:zhenbianshu.github.io/
前些日子小組內安排值班,輪流看顧我們的服務,主要做一些報警郵件處理、Bug 排查、運營 issue 處理的事,作業榷訓好,無論干什么都要上班的,若是輪到周末,那這一天算是毀了,
不知道是公司網路廣了就這樣還是網路運維組不給力,網路總有問題,不是這邊交換機脫網了就是那邊路由器壞了,還偶發地各種超時,而我們靈敏地服務探測服務總能準確地抓住偶現的小問題,給美好的作業加點料,好幾次值班組的小伙伴們一起吐槽,商量著怎么避過服務保活機制,偷偷停了探測服務而不讓人發現(雖然也并不敢),
前些天我就在周末處理了一次探測服務的鍋,
問題
網路問題?
晚上七點多開始,我就開始不停地收到報警郵件,郵件顯示探測的幾個介面有超時情況,多數執行堆疊都在:
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)
這個執行緒堆疊的報錯我見得多了,我們設定的 HTTP DNS 超時是 1s, connect 超時是 2s, read 超時是 3s,這種報錯都是探測服務正常發送了 HTTP 請求,服務器也在收到請求正常處理后正常回應了,但資料包在網路層層轉發中丟失了,所以請求執行緒的執行堆疊會停留在獲取介面回應的地方,這種情況的典型特征就是能在服務器上查找到對應的日志記錄,而且日志會顯示服務器回應完全正常,與它相對的還有執行緒堆疊停留在 Socket connect 處的,這是在建連時就失敗了,服務端完全無感知,
我注意到其中一個介面報錯更頻繁一些,這個介面需要上傳一個 4M 的檔案到服務器,然后經過一連串的業務邏輯處理,再回傳 2M 的文本資料,而其他的介面則是簡單的業務邏輯,我猜測可能是需要上傳下載的資料太多,所以超時導致丟包的概率也更大吧,
根據這個猜想,群登上服務器,使用請求的 request_id 在近期服務日志中搜索一下,果不其然,就是網路丟包問題導致的介面超時了,
當然這樣 leader 是不會滿意的,這個結論還得有人接鍋才行,于是趕緊聯系運維和網路組,向他們確認一下當時的網路狀態,網路組同學回復說是我們探測服務所在機房的交換機老舊,存在未知的轉發瓶頸,正在優化,這讓我更放心了,于是在部門群里簡單交待一下,算是完成任務,
問題爆發
本以為這次值班就起這么一個小波浪,結果在晚上八點多,各種介面的報警郵件蜂擁而至,打得準備收拾東西過周日單休的我措手不及,
這次幾乎所有的介面都在超時,而我們那個大量網路 I/O 的介面則是每次探測必超時,難道是整個機房故障了么,
我再次通過服務器和監控看到各個介面的指標都很正常,自己測驗了下介面也完全 OK,既然不影響線上服務,我準備先通過探測服務的介面把探測任務停掉再慢慢排查,
結果給暫停探測任務的介面發請求好久也沒有回應,這時候我才知道沒這么簡單,
解決
記憶體泄漏
于是趕快登陸探測服務器,首先是 top free df 三連,結果還真發現了些例外,

我們的探測行程 CPU 占用率特別高,達到了 900%,另外,JVM 系列面試題和答案全部整理好了,微信搜索?Java技術堆疊,在后臺發送:面試,?可以在線閱讀,
我們的 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 的記憶體問題很有幫助,
排查
問題雖然解決了,但為了防止它再次發生,還是要把根源揪出來,
分析堆疊
堆疊的分析很簡單,看一下執行緒數是不是過多,多數堆疊都在干嘛,
> 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 -n
10 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)
執行緒狀態好像也無例外,接下來分析堆檔案,
下載堆 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,問題圓滿解決,
小結
其實還是要反省一下自己的,一開始報警郵件里還有這樣的執行緒堆疊:
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 是能保證訊息完整性的,況且訊息沒有接收完也不會把值賦給變數,這種很明顯的是內部錯誤,如果留意后細查是能提前查出問題所在的,查問題真是差了哪一環都不行啊,
近期熱文推薦:
1.1,000+ 道 Java面試題及答案整理(2022最新版)
2.勁爆!Java 協程要來了,,,
3.Spring Boot 2.x 教程,太全了!
4.別再寫滿屏的爆爆爆炸類了,試試裝飾器模式,這才是優雅的方式!!
5.《Java開發手冊(嵩山版)》最新發布,速速下載!
覺得不錯,別忘了隨手點贊+轉發哦!
轉載請註明出處,本文鏈接:https://www.uj5u.com/houduan/541801.html
標籤:Java
下一篇:一次JVM GC長暫停的排查程序
