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)運行緩慢。

• 代碼某個位置有阻塞性的操作，導(dǎo)致該功能調(diào)用整體比較耗時，但出現(xiàn)是比較隨機的；

• 某個線程由于某種原因而進入WAITING狀態(tài)，此時該功能整體不可用，但是無法復(fù)現(xiàn)；

• 由于鎖使用不當(dāng)，導(dǎo)致多個線程進入死鎖狀態(tài)，從而導(dǎo)致系統(tǒng)整體比較緩慢。

前兩種情況出現(xiàn)的頻率較高，可能會導(dǎo)致系統(tǒng)不可用，后三種會導(dǎo)致某個功能運行緩慢，但是不至于導(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為進程編號，COMMAND為其中執(zhí)行命令，java即為要找的應(yīng)用

• top: 展示所有進程占用情況

• top -N num: 展示CPU占用最高的num個進程

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進制格式：

root@8d36124607a0:/# printf "%x\n" 10

得到輸出a線程即為0xa。

02 用jstack查看Java線程信息

• jstack?進程號 | grep 線程ID：查看線程堆棧信息，將上一步驟的Java線程進程ID與CPU占用量較高的線程ID（16進制格式）填入其中。

• jstack pid >> stack.txt：將今后曾所有堆棧信息都打印到stack.txt中

root@8d36124607a0:/# jstack 9 | grep 0xa

"VM Thread" os_prio=0 tid=0x00007f871806e000 nid=0xa runnable”

第一個雙引號圈起來的就是線程名，如果是“VM Thread”這就是虛擬機GC回收線程，如果是"main"則是其他線程，后面的runnable是線程狀態(tài)。

03 使用jstat查看GC信息

• jstat -gcutil 進程號?統(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

查看某進程GC持續(xù)變化情況，如果發(fā)現(xiàn)返回中FGC很大且一直增大，確認(rèn)為Full GC! 也可以使用“jmap -heap 進程ID”查看一下進程的堆內(nèi)從是不是要溢出了，特別是老年代內(nèi)從使用情況一般是達(dá)到閾值(具體看垃圾回收器和啟動時配置的閾值)就會進程Full GC。

04 使用Jmap分析內(nèi)存

• jmap -dump:format=b,file=文件名稱 進程ID?：

  生成內(nèi)存dump文件，進行離線分析。

• dump文件界面分析工具：

  IBM HeapAnalyzer，點擊進入找到ha457.jar的下載鏈接進行下載

• java -Xmx4G -jar ha457.jar：

  運行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進制后，使用jstack命令抓取該線程信息，發(fā)現(xiàn)線程名稱是"VM Thread"垃圾回收線程。

進一步確認(rèn)：?使用jstat -gcutil命令查看gc次數(shù)與增長情況。
進一步分析：使用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進行了一個比較耗時的調(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)的。

某個線程由于某種原因而進入WAITING狀態(tài)，此時該功能整體不可用，但是無法復(fù)現(xiàn)。jstack多查詢幾次，每次間隔30秒，對比一直停留在parking 導(dǎo)致的WAITING狀態(tài)的線程。

可以通過給線程命名快速定位到是哪個業(yè)務(wù)代碼。

05 隨機出現(xiàn)大量線程訪問接口緩慢

對于這種情況，比較典型的例子就是，我們某個接口訪問經(jīng)常需要2~3s才能返回。

這是比較麻煩的一種情況，因為一般來說，其消耗的CPU不多，而且占用的內(nèi)存也不高，也就是說，我們通過上述兩種方式進行排查是無法解決這種問題的。

而且由于這樣的接口耗時比較大的問題是不定時出現(xiàn)的，這就導(dǎo)致了我們在通過 jstack命令即使得到了線程訪問的堆棧信息，我們也沒法判斷具體哪個線程是正在執(zhí)行比較耗時操作的線程。

對于不定時出現(xiàn)的接口耗時比較嚴(yán)重的問題，我們的定位思路基本如下：

首先找到該接口，通過壓測工具不斷加大訪問力度，如果說該接口中有某個位置是比較耗時的，由于我們的訪問的頻率非常高，那么大多數(shù)的線程最終都將阻塞于該阻塞點

這樣通過多個線程具有相同的堆棧日志，我們基本上就可以定位到該接口中比較耗時的代碼的位置。

如下是一個代碼中有比較耗時的阻塞操作通過壓測工具得到的線程堆棧日志：

從上面的日志可以看你出，這里有多個線程都阻塞在了UserController的第18行，說明這是一個阻塞點，也就是導(dǎo)致該接口比較緩慢的原因。

04 總結(jié)

1、排查命令總結(jié)

• top：

  查看系統(tǒng)進程CPU與內(nèi)存占用情況，找到占用最多的進程ID

• top -Hp 進程號：

  查看該進程號的所有線程CPU與內(nèi)存占用情況，找到占用最多的線程ID（顯示的PID即為10進制線程編號，printf "%x\n" 進程號轉(zhuǎn)為16進制線程號）

• jstack 進程號 >> stack.txt：

  將進程號所屬進程的堆棧信息輸出到stack.txt中

• jstack 進程號 | grep 16進制線程號：

  查看進程號先所屬線程的堆棧信息，可查看線程名，區(qū)分出普通線程與GC線程（"VM Thread"）。

• jstat -gcutil 進程號?統(tǒng)計間隔毫秒 統(tǒng)計次數(shù)（缺省代表一直統(tǒng)計）：

  如果是因為GC問題，進一步觀察GC情況

• jmap -heap 進程ID：

  查看詳細(xì)進程內(nèi)存使用信息

• jmap -dump:format=b,file=文件名稱 進程ID：

  將進程內(nèi)存信息dump到磁盤上供進一步分析。

• java -Xmx4G -jar ha457.jar：

  使用ha457.jar來分析內(nèi)存泄漏情況。

2、異常情況解決總結(jié)

• GC問題：

  top+top -Hp + jstack排查是"VM Thread"消耗過多資源，可以進一步使用jmap工具進行內(nèi)存溢出排查。

• 業(yè)務(wù)執(zhí)行過慢問題：

  top+top -Hp + jstack排查發(fā)現(xiàn)是普通業(yè)務(wù)線程，可看到具體是哪個接口。

• 死鎖：

  jstack + Java進程打印堆棧信息中包含死鎖信息deadlock

• 線程處于waiting狀態(tài)：

  多打印幾次jstack信息，對比一直停留在waiting狀態(tài)的線程。

最后：?下方這份完整的軟件測試視頻學(xué)習(xí)教程已經(jīng)整理上傳完成，朋友們?nèi)绻枰梢宰孕忻赓M領(lǐng)取【保證100%免費】

?這些資料，對于【軟件測試】的朋友來說應(yīng)該是最全面最完整的備戰(zhàn)倉庫，這個倉庫也陪伴上萬個測試工程師們走過最艱難的路程，希望也能幫助到你！

文章來源地址http://www.zghlxwxcb.cn/news/detail-467508.html

到了這里，關(guān)于Java線上CPU內(nèi)存沖高問題排查步驟的文章就介紹完了。如果您還想了解更多內(nèi)容，請在右上角搜索TOY模板網(wǎng)以前的文章或繼續(xù)瀏覽下面的相關(guān)文章，希望大家以后多多支持TOY模板網(wǎng)！