1. 程式人生 > >如何排查java應用中CPU使用率高或記憶體佔用高的問題

如何排查java應用中CPU使用率高或記憶體佔用高的問題

如何排查java應用中CPU使用率高或記憶體佔用高的問題?這類問題的排查步驟基本通用的。現在通過一個具體的例子來說明。

問題描述

最近有個線上專案每天0點過後CPU使用率會上升至200%到300%。

排查過程

本節內容是對排查過程的覆盤,過程記錄會比較詳細。如果想知道具體的命令操作,可以直接看總結部分內容。

1)當CPU再次暴漲的時候,首先我們可以通過top -c檢視CPU使用率高的程序的PID。

如何排查java應用中CPU使用率高或記憶體佔用高的問題

2)然後使用top -p PID -H檢視CPU使用率高的執行緒資訊。如果CPU使用率高的執行緒是比較固定的,那麼我們記下對應執行緒的PID。 執行top -p 14639 -H得出下圖結果:

如何排查java應用中CPU使用率高或記憶體佔用高的問題

記下4個執行緒的PID: 14643、14644、14641、14642

3)接下來通過jstack PID > xxx.log輸出java應用當前堆疊資訊到檔案。

4)第2步中,我們記下了CPU使用率高的執行緒PID,現在將4個執行緒的PID轉成16進位制: 3933、3934、3931、3932。接著在jstack輸出的堆疊檔案裡,搜尋nid等於3933、3934、3931、3932的執行緒資訊。如下圖:

如何排查java應用中CPU使用率高或記憶體佔用高的問題

從圖中可以看出,對應的是GC執行緒。GC消耗大,那就有可能是由於記憶體不足,頻繁執行Full GC導致的。

再使用jstat -gc PID檢視jvm的GC情況,連續執行4次jstat -gc 14639命令,發現FGC的數值變化比較快。這就說明Full GC確實執行很頻繁。如下圖:

如何排查java應用中CPU使用率高或記憶體佔用高的問題

5)從第1步的截圖中,可以看到CPU高的時候整個專案的記憶體佔用1.3G左右。既然是記憶體問題,那麼就需要使用jmap -histo:live PID > xxx.log分析下jvm記憶體存活物件的統計情況。如下圖:

如何排查java應用中CPU使用率高或記憶體佔用高的問題

從圖中可以看出,byte物件([B)記憶體佔用特別高,而且出現了一個具體的類:ByteArrayRow。這是一個jdbc做查詢時候封裝資料用的一個類,這個類裡包含有byte陣列。通過這個統計結果初步懷疑是做資料庫查詢時候,查詢了太多內容到了記憶體,導致了記憶體不足。

由於統計中沒有出現具體的業務類,所以就以為只是請求量比較大,導致的記憶體消耗過大。當時暫時將jvm的堆記憶體增大到2G。

6)應用jvm堆記憶體調大之後,到了0點還是出現了CPU高漲的問題。

如何排查java應用中CPU使用率高或記憶體佔用高的問題

記憶體佔用了2G多,按照目前專案的請求量來說,2G記憶體不可能被佔滿了,所以說明並不是請求量大導致的結果,而是由於某塊程式碼查詢資料量過大導致的問題。

7)再次執行jmap -histo:live PID > xxx.log將記憶體物件統計情況輸出到檔案。結果如下圖:

如何排查java應用中CPU使用率高或記憶體佔用高的問題

這次的輸出結果出現了業務類MiniProgram_User_Info,那就可以針對這個業務類去排查異常程式碼的位置了。不過,除非比較清楚這個類具體使用的地方,否則即使出現了具體的類名還是比較難定位異常程式碼的位置。

這時候,我們可以使用jmap -dump:live,format=b,file=xxx.hprof PID命令來輸出記憶體物件的明細,來定位具體方法位置。這個命令是將記憶體裡的所有資訊都輸出出來,輸出的檔案大小和記憶體大小基本一致。而且這個命令會導致應用暫時掛起,所以謹慎使用。

8)這次將記憶體明細輸出之後,dump檔案大小為2G。用jdk自帶的jhat命令可以分析。之前分析其他dump檔案用jhat還是比較方便的。不過,分析這次的dump檔案,給了10G執行記憶體給jhat命令才勉強打開了檔案:jhat -J-mx10G -port 7170。而且記憶體物件比較多,查詢問題不方便。

最後找到了一款神器: jprofiler。用jprofier分析dump檔案需要的執行記憶體比較少,而且問題定位很方便。很快就定位出了記憶體中的大物件,佔用了1G多記憶體的物件:

如何排查java應用中CPU使用率高或記憶體佔用高的問題

如何排查java應用中CPU使用率高或記憶體佔用高的問題

如上圖,至此問題已經定位完成了。最後排查程式碼,最終發現凌晨時候,會將資料庫裡100多萬條資料查詢出來。記憶體不足導致頻繁GC,結果就是CPU使用率暴漲。

總結

一、在排查問題的過程中針對CPU的問題,使用以下命令組合來排查問題

1、檢視問題程序,得到程序PID:

top -c

2、檢視程序裡的執行緒明細,並手動記下CPU異常的執行緒PID:

top -p PID -H

3、使用jdk提供jstack命令打印出專案堆疊:

jstack pid > xxx.log

執行緒PID轉成16進位制,與堆疊中的nid對應,定位問題程式碼位置。

二、針對記憶體問題,使用以下命令組合來排查問題:

1、檢視記憶體中的存活物件統計,找出業務相關的類名:

jmap -histo:live PID > xxx.log

2、通過簡單的統計還是沒法定位問題的話,就輸出記憶體明細來分析。這個命令會將記憶體裡的所有資訊都輸出,輸出的檔案大小和記憶體大小基本一致。而且會導致應用暫時掛起,所以謹慎使用。

jmap -dump:live,format=b,file=xxx.hprof PID

3、 最後對dump出來的檔案進行分析。檔案大小不是很大的話,使用jdk自帶的jhat命令即可:

jhat -J-mx2G -port 7170

4、dump檔案太大的話,可以使用jprofiler工具來分析。jprofiler工具的使用,這裡不做詳細介紹,有興趣可以搜尋一下。

三、需要分析GC情況,可以使用以下命令:

jstat -gc PID

這裡簡單介紹一下java8裡面這個命令得出的列表各個列的含義:

S0C:第一個倖存區的大小
S1C:第二個倖存區的大小
S0U:第一個倖存區的使用大小
S1U:第二個倖存區的使用大小
EC:伊甸園區的大小
EU:伊甸園區的使用大小
OC:老年代大小
OU:老年代使用大小
MC:方法區大小
MU:方法區使用大小
CCSC:壓縮類空間大小
CCSU:壓縮類空間使用大小
YGC:年輕代垃圾回收次數
YGCT:年輕代垃圾回收消耗時間
FGC:老年代垃圾回收次數
FGCT:老年代垃圾回收消耗時間
GCT:垃圾回收消耗總時間

一般會比較關注YGC和FGC的次數。

內容補充

1、jstack輸出的堆疊檔案可以上傳到下面這個網站,這個網站可以對堆疊內容進行統計彙總,方便我們做分析:

http://fastthread.io/index.jsp

2、排查過程小節中的第5步,jmap命令執行完後沒有輸出業務類,而第7步在卻有。這個是因為第5步操作的時候只有1G多的記憶體,程式碼還沒執行到業務物件的封裝,記憶體就不夠了,後續的程式碼無法被執行到。第7步操作的時候記憶體調整到2G,所以有部分業務物件