如何排查java應(yīng)用中CPU使用率高或內(nèi)存占用高的問題？這類問題的排查步驟基本通用的。現(xiàn)在通過一個(gè)具體的例子來說明喉悴。
問題描述
最近有個(gè)線上項(xiàng)目每天0點(diǎn)過后CPU使用率會上升至200%到300%祸挪。
排查過程
本節(jié)內(nèi)容是對排查過程的復(fù)盤，過程記錄會比較詳細(xì)原环。如果想知道具體的命令操作挠唆，可以直接看總結(jié)部分內(nèi)容。
1）當(dāng)CPU再次暴漲的時(shí)候嘱吗，首先我們可以通過top -c查看CPU使用率高的進(jìn)程的PID玄组。
2）然后使用top -p PID -H查看CPU使用率高的線程信息。如果CPU使用率高的線程是比較固定的谒麦，那么我們記下對應(yīng)線程的PID俄讹。
執(zhí)行top -p 14639 -H得出下圖結(jié)果：
記下4個(gè)線程的PID: 14643、14644绕德、14641患膛、14642
3）接下來通過jstack PID > xxx.log輸出java應(yīng)用當(dāng)前堆棧信息到文件。
4）第2步中耻蛇，我們記下了CPU使用率高的線程PID踪蹬，現(xiàn)在將4個(gè)線程的PID轉(zhuǎn)成16進(jìn)制: 3933部服、3934歼疮、3931、3932暇仲。接著在jstack輸出的堆棧文件里夺蛇，搜索nid等于3933枝缔、3934、3931、3932的線程信息愿卸。如下圖：
從圖中可以看出灵临，對應(yīng)的是GC線程。GC消耗大趴荸，那就有可能是由于內(nèi)存不足儒溉，頻繁執(zhí)行Full GC導(dǎo)致的。
再使用
jstat -gc PID查看jvm的GC情況发钝，連續(xù)執(zhí)行4次jstat -gc 14639命令顿涣，發(fā)現(xiàn)FGC的數(shù)值變化比較快。這就說明Full GC確實(shí)執(zhí)行很頻繁酝豪。如下圖：
5）從第1步的截圖中涛碑，可以看到CPU高的時(shí)候整個(gè)項(xiàng)目的內(nèi)存占用1.3G左右。既然是內(nèi)存問題孵淘，那么就需要使用jmap -histo:live PID > xxx.log分析下jvm內(nèi)存存活對象的統(tǒng)計(jì)情況蒲障。如下圖：
從圖中可以看出，byte對象（[B）內(nèi)存占用特別高瘫证，而且出現(xiàn)了一個(gè)具體的類：ByteArrayRow揉阎。這是一個(gè)jdbc做查詢時(shí)候封裝數(shù)據(jù)用的一個(gè)類，這個(gè)類里包含有byte數(shù)組背捌。通過這個(gè)統(tǒng)計(jì)結(jié)果初步懷疑是做數(shù)據(jù)庫查詢時(shí)候毙籽，查詢了太多內(nèi)容到了內(nèi)存，導(dǎo)致了內(nèi)存不足毡庆。由于統(tǒng)計(jì)中沒有出現(xiàn)具體的業(yè)務(wù)類坑赡，所以就以為只是請求量比較大，導(dǎo)致的內(nèi)存消耗過大么抗。當(dāng)時(shí)暫時(shí)將jvm的堆內(nèi)存增大到2G垮衷。
6）應(yīng)用jvm堆內(nèi)存調(diào)大之后，到了0點(diǎn)還是出現(xiàn)了CPU高漲的問題乖坠。
內(nèi)存占用了2G多搀突，按照目前項(xiàng)目的請求量來說，2G內(nèi)存不可能被占滿了熊泵，所以說明并不是請求量大導(dǎo)致的結(jié)果仰迁，而是由于某塊代碼查詢數(shù)據(jù)量過大導(dǎo)致的問題。
7）再次運(yùn)行jmap -histo:live PID > xxx.log將內(nèi)存對象統(tǒng)計(jì)情況輸出到文件顽分。結(jié)果如下圖：
這次的輸出結(jié)果出現(xiàn)了業(yè)務(wù)類MiniProgram_User_Info徐许，那就可以針對這個(gè)業(yè)務(wù)類去排查異常代碼的位置了。不過卒蘸，除非比較清楚這個(gè)類具體使用的地方雌隅，否則即使出現(xiàn)了具體的類名還是比較難定位異常代碼的位置翻默。
這時(shí)候，我們可以使用
jmap -dump:live,format=b,file=xxx.hprof PID命令來輸出內(nèi)存對象的明細(xì)恰起，來定位具體方法位置修械。這個(gè)命令是將內(nèi)存里的所有信息都輸出出來，輸出的文件大小和內(nèi)存大小基本一致检盼。而且這個(gè)命令會導(dǎo)致應(yīng)用暫時(shí)掛起肯污，所以謹(jǐn)慎使用。
8）這次將內(nèi)存明細(xì)輸出之后吨枉，dump文件大小為2G蹦渣。用jdk自帶的jhat命令可以分析。之前分析其他dump文件用jhat還是比較方便的貌亭。不過柬唯，分析這次的dump文件，給了10G運(yùn)行內(nèi)存給jhat命令才勉強(qiáng)打開了文件：jhat -J-mx10G -port 7170圃庭。而且內(nèi)存對象比較多锄奢，查找問題不方便。最后找到了一款神器: jprofiler冤议。用jprofier分析dump文件需要的運(yùn)行內(nèi)存比較少斟薇，而且問題定位很方便师坎。很快就定位出了內(nèi)存中的大對象恕酸，占用了1G多內(nèi)存的對象：
大對象對應(yīng)的線程堆棧：
如上圖，至此問題已經(jīng)定位完成了胯陋。最后排查代碼蕊温，最終發(fā)現(xiàn)凌晨時(shí)候，會將數(shù)據(jù)庫里100多萬條數(shù)據(jù)查詢出來遏乔。內(nèi)存不足導(dǎo)致頻繁GC义矛，結(jié)果就是CPU使用率暴漲。
總結(jié)
一盟萨、在排查問題的過程中針對CPU的問題凉翻，使用以下命令組合來排查問題
1、查看問題進(jìn)程捻激，得到進(jìn)程PID：
top -c
2制轰、查看進(jìn)程里的線程明細(xì)，并手動(dòng)記下CPU異常的線程PID：
top -p PID -H
3胞谭、使用jdk提供jstack命令打印出項(xiàng)目堆棧：
jstack pid > xxx.log
線程PID轉(zhuǎn)成16進(jìn)制垃杖，與堆棧中的nid對應(yīng)，定位問題代碼位置丈屹。
二调俘、針對內(nèi)存問題，使用以下命令組合來排查問題：
1、查看內(nèi)存中的存活對象統(tǒng)計(jì)彩库，找出業(yè)務(wù)相關(guān)的類名：
jmap -histo:live PID > xxx.log
2肤无、通過簡單的統(tǒng)計(jì)還是沒法定位問題的話，就輸出內(nèi)存明細(xì)來分析侧巨。這個(gè)命令會將內(nèi)存里的所有信息都輸出舅锄，輸出的文件大小和內(nèi)存大小基本一致。而且會導(dǎo)致應(yīng)用暫時(shí)掛起司忱，所以謹(jǐn)慎使用皇忿。
jmap -dump:live,format=b,file=xxx.hprof PID
3、 最后對dump出來的文件進(jìn)行分析坦仍。文件大小不是很大的話鳍烁，使用jdk自帶的jhat命令即可：
jhat -J-mx2G -port 7170
4、dump文件太大的話繁扎，可以使用jprofiler工具來分析幔荒。jprofiler工具的使用，這里不做詳細(xì)介紹梳玫，有興趣可以搜索一下爹梁。
三、需要分析GC情況提澎，可以使用以下命令：
jstat -gc PID
這里簡單介紹一下java8里面這個(gè)命令得出的列表各個(gè)列的含義：
S0C：第一個(gè)幸存區(qū)的大小
S1C：第二個(gè)幸存區(qū)的大小
S0U：第一個(gè)幸存區(qū)的使用大小
S1U：第二個(gè)幸存區(qū)的使用大小
EC：伊甸園區(qū)的大小
EU：伊甸園區(qū)的使用大小
OC：老年代大小
OU：老年代使用大小
MC：方法區(qū)大小
MU：方法區(qū)使用大小
CCSC：壓縮類空間大小
CCSU：壓縮類空間使用大小
YGC：年輕代垃圾回收次數(shù)
YGCT：年輕代垃圾回收消耗時(shí)間
FGC：老年代垃圾回收次數(shù)
FGCT：老年代垃圾回收消耗時(shí)間
GCT：垃圾回收消耗總時(shí)間
一般會比較關(guān)注YGC和FGC的次數(shù)姚垃。
內(nèi)容補(bǔ)充
1、jstack輸出的堆棧文件可以上傳到下面這個(gè)網(wǎng)站盼忌，這個(gè)網(wǎng)站可以對堆棧內(nèi)容進(jìn)行統(tǒng)計(jì)匯總积糯，方便我們做分析：http://fastthread.io/index.jsp
2、排查過程小節(jié)中的第5步谦纱，jmap命令執(zhí)行完后沒有輸出業(yè)務(wù)類看成，而第7步在卻有。這個(gè)是因?yàn)榈?步操作的時(shí)候只有1G多的內(nèi)存跨嘉，代碼還沒執(zhí)行到業(yè)務(wù)對象的封裝川慌，內(nèi)存就不夠了，后續(xù)的代碼無法被執(zhí)行到祠乃。第7步操作的時(shí)候內(nèi)存調(diào)整到2G梦重，所以有部分業(yè)務(wù)對象已經(jīng)被創(chuàng)建了。
