如何排查java應用中CPU使用率高或內存佔用高的問題

如何排查java應用中CPU使用率高或內存佔用高的問題？這類問題的排查步驟基本通用的。如今經過一個具體的例子來講明。

問題描述

最近有個線上項目天天0點事後CPU使用率會上升至200%到300%。

排查過程

本節內容是對排查過程的覆盤，過程記錄會比較詳細。若是想知道具體的命令操做，能夠直接看總結部分內容。

1）當CPU再次暴漲的時候，首先咱們能夠經過top -c查看CPU使用率高的進程的PID。

2）而後使用top -p PID -H查看CPU使用率高的線程信息。若是CPU使用率高的線程是比較固定的，那麼咱們記下對應線程的PID。 執行top -p 14639 -H得出下圖結果：

記下4個線程的PID: 1464三、1464四、1464一、14642

3）接下來經過jstack PID > xxx.log輸出java應用當前堆棧信息到文件。

4）第2步中，咱們記下了CPU使用率高的線程PID，如今將4個線程的PID轉成16進制: 393三、393四、393一、3932。接着在jstack輸出的堆棧文件裏，搜索nid等於393三、393四、393一、3932的線程信息。以下圖：

從圖中能夠看出，對應的是GC線程。GC消耗大，那就有多是因爲內存不足，頻繁執行Full GC致使的。
再使用jstat -gc PID查看jvm的GC狀況，連續執行4次jstat -gc 14639命令，發現FGC的數值變化比較快。這就說明Full GC確實執行很頻繁。以下圖：

5）從第1步的截圖中，能夠看到CPU高的時候整個項目的內存佔用1.3G左右。既然是內存問題，那麼就須要使用jmap -histo:live PID > xxx.log分析下jvm內存存活對象的統計狀況。以下圖：

從圖中能夠看出，byte對象（[B）內存佔用特別高，並且出現了一個具體的類：ByteArrayRow。這是一個jdbc作查詢時候封裝數據用的一個類，這個類裏包含有byte數組。經過這個統計結果初步懷疑是作數據庫查詢時候，查詢了太多內容到了內存，致使了內存不足。因爲統計中沒有出現具體的業務類，因此就覺得只是請求量比較大，致使的內存消耗過大。當時暫時將jvm的堆內存增大到2G。

6）應用jvm堆內存調大以後，到了0點仍是出現了CPU高漲的問題。

內存佔用了2G多，按照目前項目的請求量來講，2G內存不可能被佔滿了，因此說明並非請求量大致使的結果，而是因爲某塊代碼查詢數據量過大致使的問題。

7）再次運行jmap -histo:live PID > xxx.log將內存對象統計狀況輸出到文件。結果以下圖：

此次的輸出結果出現了業務類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多內存的對象：

大對象對應的線程堆棧：

如上圖，至此問題已經定位完成了。最後排查代碼，最終發現凌晨時候，會將數據庫裏100多萬條數據查詢出來。內存不足致使頻繁GC，結果就是CPU使用率暴漲。

總結

1、在排查問題的過程當中針對CPU的問題，使用如下命令組合來排查問題
一、查看問題進程，獲得進程PID：
top -c

二、查看進程裏的線程明細，並手動記下CPU異常的線程PID：
top -p PID -H

三、使用jdk提供jstack命令打印出項目堆棧：
jstack pid > xxx.log

線程PID轉成16進制，與堆棧中的nid對應，定位問題代碼位置。

2、針對內存問題，使用如下命令組合來排查問題：
一、查看內存中的存活對象統計，找出業務相關的類名：
jmap -histo:live PID > xxx.log

二、經過簡單的統計仍是無法定位問題的話，就輸出內存明細來分析。這個命令會將內存裏的全部信息都輸出，輸出的文件大小和內存大小基本一致。並且會致使應用暫時掛起，因此謹慎使用。
jmap -dump:live,format=b,file=xxx.hprof PID

三、 最後對dump出來的文件進行分析。文件大小不是很大的話，使用jdk自帶的jhat命令便可：
jhat -J-mx2G -port 7170

四、dump文件太大的話，可使用jprofiler工具來分析。jprofiler工具的使用，這裏不作詳細介紹，有興趣能夠搜索一下。

3、須要分析GC狀況，可使用如下命令：
jstat -gc PID

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

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

通常會比較關注YGC和FGC的次數。

內容補充

一、jstack輸出的堆棧文件能夠上傳到下面這個網站，這個網站能夠對堆棧內容進行統計彙總，方便咱們作分析：http://fastthread.io/index.jsp

二、排查過程小節中的第5步，jmap命令執行完後沒有輸出業務類，而第7步在卻有。這個是由於第5步操做的時候只有1G多的內存，代碼還沒執行到業務對象的封裝，內存就不夠了，後續的代碼沒法被執行到。第7步操做的時候內存調整到2G，因此有部分業務對象已經被建立了。