Java線上CPU內(nèi)存沖高問題排查解決步驟
01 引言
作為一名從事Java開發(fā)快一年的程序員，在線上經(jīng)常碰到某個模塊的Pod發(fā)出CPU與內(nèi)存告警的問題，而這些問題會導(dǎo)致系統(tǒng)響應(yīng)緩慢甚至是服務(wù)不可用。一般情況下可以通過重啟或者調(diào)高Pod的資源量或者增加Pod數(shù)量暫時解決問題，但這是治標(biāo)不治本的，只有找到問題發(fā)生的原因才能從根本上解決問題。那么在該如何快速定位到導(dǎo)致告警的原因呢？下面將匯總一下大致的處理思路。
一般來說導(dǎo)致Java程序CPU與內(nèi)存沖高的原因有兩種：
- 代碼中某個位置讀取數(shù)據(jù)量較大，導(dǎo)致系統(tǒng)內(nèi)存耗盡，從而導(dǎo)致Full GC次數(shù)過多，系統(tǒng)緩慢。
- 代碼中有比較耗CPU的操作，導(dǎo)致CPU過高，系統(tǒng)運(yùn)行緩慢。
- 代碼某個位置有阻塞性的操作，導(dǎo)致該功能調(diào)用整體比較耗時，但出現(xiàn)是比較隨機(jī)的；
- 某個線程由于某種原因而進(jìn)入WAITING狀態(tài)，此時該功能整體不可用，但是無法復(fù)現(xiàn)；
- 由于鎖使用不當(dāng)，導(dǎo)致多個線程進(jìn)入死鎖狀態(tài)，從而導(dǎo)致系統(tǒng)整體比較緩慢。
前兩種情況出現(xiàn)的頻率較高，可能會導(dǎo)致系統(tǒng)不可用，后三種會導(dǎo)致某個功能運(yùn)行緩慢，但是不至于導(dǎo)致系統(tǒng)不可用。
對于第一種情況，本人曾經(jīng)遇到過某個查全量數(shù)據(jù)的接口在某段時間被頻繁調(diào)用導(dǎo)致內(nèi)存耗盡、瘋狂GC的情況：記一次GC導(dǎo)致的CPU與內(nèi)存沖高的問題解決。下面將總結(jié)一些具體的排查步驟。
02 分析工具
01 top命令查看CPU占用情況
PID為進(jìn)程編號，COMMAND為其中執(zhí)行命令，java即為要找的應(yīng)用
- top: 展示所有進(jìn)程占用情況
- top -N num: 展示CPU占用最高的num個進(jìn)程
root@8d36124607a0:/# top top - 14:01:23 up 1 day, 17:54, 1 user, load average: 0.00, 0.01, 0.05Tasks: 101 total, 1 running, 100 sleeping, 0 stopped, 0 zombie%Cpu(s): 0.8 us, 1.2 sy, 0.0 ni, 98.0 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 stKiB Mem : 3782864 total, 1477524 free, 329656 used, 1975684 buff/cacheKiB Swap: 0 total, 0 free, 0 used. 3181392 avail Mem PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 9 root 20 0 1031064 52580 19248 S 90.3 10.4 26:30.37 javacatalina.sh
root@8d36124607a0:/# top -Hp 9 top - 08:31:16 up 30 min, 0 users, load average: 0.75, 0.59, 0.35Threads: 11 total, 1 running, 10 sleeping, 0 stopped, 0 zombie%Cpu(s): 3.5 us, 0.6 sy, 0.0 ni, 95.9 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 stKiB Mem: 2046460 total, 1924856 used, 121604 free, 14396 buffersKiB Swap: 1048572 total, 0 used, 1048572 free. 1192532 cached Mem PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 10 root 20 0 2557160 289824 15872 R 79.3 14.2 0:41.49 java 11 root 20 0 2557160 289824 15872 S 1.2 14.2 0:06.78 java
可以看到占用CPU消耗最高的PID為10，該ID即為線程ID，使用如下命令將其轉(zhuǎn)化為16進(jìn)制格式：
root@8d36124607a0:/# printf "%x\n" 10
得到輸出a線程即為0xa。
02 用jstack查看Java線程信息
jstack 進(jìn)程號 | grep 線程ID：查看線程堆棧信息，將上一步驟的Java線程進(jìn)程ID與CPU占用量較高的線程ID（16進(jìn)制格式）填入其中。
jstack pid >> stack.txt：將今后曾所有堆棧信息都打印到stack.txt中
root@8d36124607a0:/# jstack 9 | grep 0xa "VM Thread" os_prio=0 tid=0x00007f871806e000 nid=0xa runnable”
第一個雙引號圈起來的就是線程名，如果是“VM Thread”這就是虛擬機(jī)GC回收線程，如果是"main"則是其他線程，后面的runnable是線程狀態(tài)。
03 使用jstat查看GC信息
jstat -gcutil 進(jìn)程號 統(tǒng)計間隔毫秒 統(tǒng)計次數(shù)（缺省代表一直統(tǒng)計）
root@8d36124607a0:/# jstat -gcutil 9 1000 10 S0 S1 E O M CCS YGC YGCT FGC FGCT GCT 0.00 0.00 0.00 75.07 59.09 59.60 3259 0.919 6517 7.715 8.635 0.00 0.00 0.00 0.08 59.09 59.60 3306 0.930 6611 7.822 8.752 0.00 0.00 0.00 0.08 59.09 59.60 3351 0.943 6701 7.924 8.867 0.00 0.00 0.00 0.08 59.09 59.60 3397 0.955 6793 8.029 8.984
查看某進(jìn)程GC持續(xù)變化情況，如果發(fā)現(xiàn)返回中FGC很大且一直增大，確認(rèn)為Full GC! 也可以使用“jmap -heap 進(jìn)程ID”查看一下進(jìn)程的堆內(nèi)從是不是要溢出了，特別是老年代內(nèi)從使用情況一般是達(dá)到閾值(具體看垃圾回收器和啟動時配置的閾值)就會進(jìn)程Full GC。
04 使用Jmap分析內(nèi)存
- jmap -dump:format=b,file=文件名稱 進(jìn)程ID ：
生成內(nèi)存dump文件，進(jìn)行離線分析。
- dump文件界面分析工具：
IBM HeapAnalyzer，點(diǎn)擊進(jìn)入找到ha457.jar的下載鏈接進(jìn)行下載
- java -Xmx4G -jar ha457.jar：
運(yùn)行jar文件，如果dump文件過大可以使用-Xmx設(shè)置最大堆內(nèi)存大小，防止內(nèi)存溢出。
通過ha457.jar的GUI界面可以很清晰的看到各種類型的數(shù)據(jù)內(nèi)存占用情況、對象之間的引用關(guān)系以及可能存在內(nèi)存泄漏的對象。
03 原因分析
01 Full GC次數(shù)過多
相對來說，這種情況是最容易出現(xiàn)的，尤其是新功能上線時。對于Full GC較多的情況，其主要有如下兩個特征：
- 線上多個線程的CPU都超過了100%，通過jstack命令可以看到這些線程主要是垃圾回收線程
- 通過jstat命令監(jiān)控GC情況，可以看到Full GC次數(shù)非常多，并且次數(shù)在不斷增加。
初步排查：使用top與top -Hp命令找到CPU占用最高的Java線程，將其轉(zhuǎn)為16進(jìn)制后，使用jstack命令抓取該線程信息，發(fā)現(xiàn)線程名稱是"VM Thread"垃圾回收線程。
進(jìn)一步確認(rèn)： 使用jstat -gcutil命令查看gc次數(shù)與增長情況。
進(jìn)一步分析：使用jmap -dump命令dump內(nèi)存，然后使用使用ha457.jar離線分析。
- 生成大量的對象，導(dǎo)致內(nèi)存溢出
- 內(nèi)存占用不高，但是Full GC次數(shù)還是比較多，此時可能是代碼中手動調(diào)用 System.gc()導(dǎo)致GC次數(shù)過多。
02 某個業(yè)務(wù)邏輯執(zhí)行時間過長
如果是Full GC次數(shù)過多，那么通過 jstack得到的線程信息會是類似于VM Thread之類的線程，而如果是代碼中有比較耗時的計算，那么我們得到的就是一個線程的具體堆棧信息。
如下是一個代碼中有比較耗時的計算，導(dǎo)致CPU過高的線程信息：
這里可以看到，在請求UserController的時候，由于該Controller進(jìn)行了一個比較耗時的調(diào)用，導(dǎo)致該線程的CPU一直處于100%。我們可以根據(jù)堆棧信息，直接定位到UserController的34行，查看代碼中具體是什么原因?qū)е掠嬎懔咳绱酥摺?/p>
03 死鎖
如果有死鎖，會直接提示。關(guān)鍵字：deadlock。使用jstack打印線程信息會打印出業(yè)務(wù)死鎖的位置。
04 程一直處于WAITTING狀態(tài)
對于這種情況，這是比較罕見的一種情況，但是也是有可能出現(xiàn)的，而且由于其具有一定的 “不可復(fù)現(xiàn)性”，因在排查的時候是非常難以發(fā)現(xiàn)的。
某個線程由于某種原因而進(jìn)入WAITING狀態(tài)，此時該功能整體不可用，但是無法復(fù)現(xiàn)。jstack多查詢幾次，每次間隔30秒，對比一直停留在parking 導(dǎo)致的WAITING狀態(tài)的線程。
可以通過給線程命名快速定位到是哪個業(yè)務(wù)代碼。
05 隨機(jī)出現(xiàn)大量線程訪問接口緩慢
對于這種情況，比較典型的例子就是，我們某個接口訪問經(jīng)常需要2~3s才能返回。
這是比較麻煩的一種情況，因?yàn)橐话銇碚f，其消耗的CPU不多，而且占用的內(nèi)存也不高，也就是說，我們通過上述兩種方式進(jìn)行排查是無法解決這種問題的。
而且由于這樣的接口耗時比較大的問題是不定時出現(xiàn)的，這就導(dǎo)致了我們在通過 jstack命令即使得到了線程訪問的堆棧信息，我們也沒法判斷具體哪個線程是正在執(zhí)行比較耗時操作的線程。
對于不定時出現(xiàn)的接口耗時比較嚴(yán)重的問題，我們的定位思路基本如下：
首先找到該接口，通過壓測工具不斷加大訪問力度，如果說該接口中有某個位置是比較耗時的，由于我們的訪問的頻率非常高，那么大多數(shù)的線程最終都將阻塞于該阻塞點(diǎn)
這樣通過多個線程具有相同的堆棧日志，我們基本上就可以定位到該接口中比較耗時的代碼的位置。
如下是一個代碼中有比較耗時的阻塞操作通過壓測工具得到的線程堆棧日志：
從上面的日志可以看你出，這里有多個線程都阻塞在了UserController的第18行，說明這是一個阻塞點(diǎn)，也就是導(dǎo)致該接口比較緩慢的原因。
04 總結(jié)
1、排查命令總結(jié)
- top：
查看系統(tǒng)進(jìn)程CPU與內(nèi)存占用情況，找到占用最多的進(jìn)程ID
- top -Hp 進(jìn)程號：
查看該進(jìn)程號的所有線程CPU與內(nèi)存占用情況，找到占用最多的線程ID（顯示的PID即為10進(jìn)制線程編號，printf "%x\n" 進(jìn)程號轉(zhuǎn)為16進(jìn)制線程號）
- jstack 進(jìn)程號 >> stack.txt：
將進(jìn)程號所屬進(jìn)程的堆棧信息輸出到stack.txt中
- jstack 進(jìn)程號 | grep 16進(jìn)制線程號：
查看進(jìn)程號先所屬線程的堆棧信息，可查看線程名，區(qū)分出普通線程與GC線程（"VM Thread"）。
- jstat -gcutil 進(jìn)程號 統(tǒng)計間隔毫秒 統(tǒng)計次數(shù)（缺省代表一直統(tǒng)計）：
如果是因?yàn)镚C問題，進(jìn)一步觀察GC情況
- jmap -heap 進(jìn)程ID：
查看詳細(xì)進(jìn)程內(nèi)存使用信息
- jmap -dump:format=b,file=文件名稱 進(jìn)程ID：
將進(jìn)程內(nèi)存信息dump到磁盤上供進(jìn)一步分析。
- java -Xmx4G -jar ha457.jar：
使用ha457.jar來分析內(nèi)存泄漏情況。
2、異常情況解決總結(jié)
- GC問題：
top+top -Hp + jstack排查是"VM Thread"消耗過多資源，可以進(jìn)一步使用jmap工具進(jìn)行內(nèi)存溢出排查。
- 業(yè)務(wù)執(zhí)行過慢問題：
top+top -Hp + jstack排查發(fā)現(xiàn)是普通業(yè)務(wù)線程，可看到具體是哪個接口。
- 死鎖：
jstack + Java進(jìn)程打印堆棧信息中包含死鎖信息deadlock
- 線程處于waiting狀態(tài)：
多打印幾次jstack信息，對比一直停留在waiting狀態(tài)的線程。
總結(jié)
到此這篇關(guān)于Java線上CPU內(nèi)存沖高問題排查解決的文章就介紹到這了,更多相關(guān)Java線上CPU內(nèi)存沖高內(nèi)容請搜索腳本之家以前的文章或繼續(xù)瀏覽下面的相關(guān)文章希望大家以后多多支持腳本之家！
相關(guān)文章
這篇文章主要介紹了Mybatis-plus4條件構(gòu)造器使用方式,具有很好的參考價值,希望對大家有所幫助,如有錯誤或未考慮完全的地方,望不吝賜教2024-02-02
zookeeper+Springboot實(shí)現(xiàn)服務(wù)器動態(tài)上下線監(jiān)聽教程詳解
這篇文章主要介紹了zookeeper+Springboot實(shí)現(xiàn)服務(wù)器動態(tài)上下線監(jiān)聽,主要介紹了什么是服務(wù)器動態(tài)上下線監(jiān)聽及為什么要實(shí)現(xiàn)對服務(wù)器上下線的監(jiān)聽，本文通過實(shí)例代碼給大家介紹的非常詳細(xì)，需要的朋友可以參考下2022-06-06
這篇文章主要為大家詳細(xì)介紹了java簡單實(shí)現(xiàn)計算器，文中示例代碼介紹的非常詳細(xì)，具有一定的參考價值，感興趣的小伙伴們可以參考一下2020-12-12
Mybatis支持對Executor、StatementHandler、PameterHandler和ResultSetHandler 接口進(jìn)行攔截，也就是說會對這4種對象進(jìn)行代理,下面這篇文章主要給大家介紹了關(guān)于MyBatis自定義SQL攔截器的相關(guān)資料,需要的朋友可以參考下2021-10-10
SpringMVC請求的路徑變量里面寫正則表達(dá)式的方法
這篇文章主要介紹了SpringMVC請求的路徑變量里面寫正則表達(dá)式的相關(guān)知識，本文給大家介紹的非常詳細(xì)，具有一定的參考借鑒價值,需要的朋友可以參考下2019-09-09
Java基本語法就是指java中的規(guī)則，也是一種語言規(guī)則，規(guī)范，同時也能讓您在后面的學(xué)習(xí)中避免不必要的一些錯誤和麻煩，是您學(xué)好java必修的第一門課程2023-05-05
這篇文章主要給大家介紹了關(guān)于Java中如何用Stream分組并求各組數(shù)量的相關(guān)資料,文中通過實(shí)例代碼,對大家學(xué)習(xí)或者Java具有一定的參考借鑒價值,需要的朋友可以參考下2023-07-07
springboot jar包啟動腳本,適用于快速啟動,刪除,重啟,以及查看狀態(tài),下面這篇文章主要給大家介紹了關(guān)于SpringBoot為何可以使用Jar包啟動的相關(guān)資料,文中通過實(shí)例代碼介紹的非常詳細(xì),需要的朋友可以參考下2022-03-03
Listener是由Java編寫的WEB組件，主要完成對內(nèi)置對象狀態(tài)的變化 （創(chuàng)建、銷毀）和屬性的變化進(jìn)行監(jiān)聽，做進(jìn)一步的處理，主要對session和application內(nèi)置對象監(jiān)聽，這篇文章主要介紹了Java中監(jiān)聽器Listener,需要的朋友可以參考下2023-08-08
這篇文章主要為大家詳細(xì)介紹了Java實(shí)現(xiàn)微信發(fā)紅包，文中示例代碼介紹的非常詳細(xì)，具有一定的參考價值，感興趣的小伙伴們可以參考一下2019-12-12