JVM效能調優(4) —— 效能調優工具
前序文章:
JVM效能調優(1) —— JVM記憶體模型和類載入執行機制
一、JDK工具
先來看看有哪些常用的工具可以輔助我們進行效能調優和問題排查,後面再通過一個具體的示例結合工具來分析調優。
1、JDK工具
JDK自帶了很多效能監控工具,我們可以用這些工具來監測系統和排查記憶體效能問題。
2、利用 jps 找出程序
jps(Java Virtual Machine Process Status Tool)是JDK 1.5提供的一個顯示當前所有java程序pid的命令,簡單實用,非常適合在linux/unix平臺上簡單察看當前java程序的一些簡單情況。
1)檢視Java程序PID
【jps -l】左邊一列就是Java程序的PID。
2)輸出傳遞給JVM的引數
【jps -vl】
3、利用 jstat 檢視VM統計資訊
使用 jstat 工具可以監測 Java 應用程式的實時執行情況,可以看到VM內的Eden、Survivor、老年代的記憶體使用情況,還有 YoungGC 和 FullGC 的執行次數以及耗時。通過這些指標,我們可以輕鬆的分析出當前系統的執行情況,判斷當前系統的記憶體使用壓力以及GC壓力,還有記憶體分配是否合理。
1)檢視 jstat 有哪些操作
【jstat -options】
- -class:顯示 ClassLoad 的相關資訊;
- -compiler:顯示 JIT 編譯的相關資訊;
- -gc:顯示和 gc 相關的堆資訊;
- -gccapacity:顯示各個代的容量以及使用情況;
- -gcmetacapacity:顯示 Metaspace 的大小;
- -gcnew:顯示新生代資訊;
- -gcnewcapacity:顯示新生代大小和使用情況;
- -gcold:顯示老年代和永久代的資訊;
- -gcoldcapacity :顯示老年代的大小;
- -gcutil:顯示垃圾收集資訊;
- -gccause:顯示垃圾回收的相關資訊(同 -gcutil),同時顯示最後一次或當前正在發生的垃圾回收的誘因;
- -printcompilation:輸出 JIT 編譯的方法資訊
其中 jstat -gc 是最完整、最常用、最實用的命令,基本足夠分析jvm的執行情況了。
2)顯示 ClassLoad 的相關資訊
【jstat -class <pid>】
3)檢視記憶體使用和GC情況
【jstat -gc <pid> [<interval> [<count>]】
- S0C:年輕代中 To Survivor 的容量(單位 KB);
- S1C:年輕代中 From Survivor 的容量(單位 KB);
- S0U:年輕代中 To Survivor 目前已使用空間(單位 KB);
- S1U:年輕代中 From Survivor 目前已使用空間(單位 KB);
- EC:年輕代中 Eden 的容量(單位 KB);
- EU:年輕代中 Eden 目前已使用空間(單位 KB);
- OC:老年代的容量(單位 KB);
- OU:老年代目前已使用空間(單位 KB);
- MC:Metaspace 的容量(單位 KB);
- MU:Metaspace 目前已使用空間(單位 KB);
- CCSC:壓縮類空間大小
- CCSU:壓縮類空間使用大小
- YGC:從應用程式啟動到取樣時年輕代中 gc 次數;
- YGCT:從應用程式啟動到取樣時年輕代中 gc 所用時間 (s);
- FGC:從應用程式啟動到取樣時 old 代(全 gc)gc 次數;
- FGCT:從應用程式啟動到取樣時 old 代(全 gc)gc 所用時間 (s);
- GCT:從應用程式啟動到取樣時 gc 用的總時間 (s)
4)檢視垃圾回收統計
【jstat -gcutil <pid> [<interval> [<count>]】
- S0:Survivor0 區佔用百分比
- S1:Survivor1 區佔用百分比
- E:Eden 區佔用百分比
- O:老年代佔用百分比
- M:元資料區佔用百分比
- YGC:年輕代回收次數
- YGCT:年輕代回收耗時
- FGC:老年代回收次數
- FGCT:老年代回收耗時
- GCT:GC總耗時
4、利用 jmap 檢視物件分佈情況
使用 jmap 可檢視堆記憶體初始化配置資訊以及堆記憶體的使用情況,輸出堆記憶體中的物件資訊,包括產生了哪些物件,物件數量多少等。
1)檢視堆記憶體情況
【jmap -heap <PID>】
這個命令會打印出堆記憶體相關的一些引數設定以及各個區域的情況,要檢視這些資訊一般使用 jstat 命令就足夠了。
2)檢視系統執行時物件分佈
【jmap -histo[:live] <PID>】帶上 live 則只統計活物件
這個命令會按照各種物件佔用記憶體空間的大小降序排列,把佔用記憶體最多的物件放在最上面。通過這個命令可以簡單的瞭解下當前jvm中的物件對記憶體佔用的情況以及當前記憶體裡到底是哪個物件佔用了大量的記憶體空間。
3)生成堆記憶體轉儲快照
【jmap -dump:format=b,file=<path> <pid>】
【jmap -dump:live,format=b,file=<path> <pid>】
jmap -dump 是輸出堆中所有物件;jmap -dump:live 是輸出堆中所有活著的物件,而且 jmap -dump:live 會觸發 FullGC,線上使用要注意。format=b 是以二進位制格式輸出;file 是檔案路徑,格式為 hrpof 字尾。
這個命令會在當前目錄下生成一個 dump.hrpof 檔案,這是個二進位制的格式,無法直接開啟,可以使用MAT等工具來分析。這個命令把這一時刻VM堆記憶體裡所有物件的快照放到檔案裡去了,供你後續去分析。
5、利用 jstack 分析執行緒棧
jstack 是一種執行緒堆疊分析工具,最常用的功能就是使用 jstack pid 命令檢視執行緒的堆疊資訊,通常會結合 top -Hp pid 或 pidstat -p pid -t 一起檢視具體執行緒的狀態,也經常用來排查一些死鎖的異常、CPU佔用高的執行緒等。
1)jstack引數
- -l:長列表. 列印關於鎖的附加資訊,例如屬於 java.util.concurrent 的 ownable synchronizers 列表。
- -F:當 jstack [-l] pid 沒有響應的時候強制列印棧資訊
- -m:列印 java 和 native c/c++ 框架的所有棧資訊.
- -h | -help:列印幫助資訊
2)檢視執行緒堆疊資訊
【jstack <pid> > stack.log】
這個命令可以把程式的執行緒堆疊dump下來。每個執行緒堆疊的資訊中,都可以檢視到執行緒 ID、執行緒狀態(wait、sleep、running 等狀態)以及是否持有鎖等。
- pool-11-thread-6:執行緒名稱
- #1920:執行緒編號
- prio=5:執行緒的優先級別
- os_prio=0:系統級別的執行緒優先順序
- tid=0x00007f87e028c000:執行緒ID
- nid=0x6724:native執行緒的id,通過 printf "%x\n" <pid> 命令轉換執行緒ID
- waiting on condition [0x00007f87b97d2000]:執行緒當前的狀態
二、Linux 命令列工具
1、top 命令
top 命令是我們在 Linux 下最常用的命令之一,它可以實時顯示正在執行程序的 CPU 使用率、記憶體使用率以及系統負載等資訊。其中上半部分顯示的是系統的統計資訊,下半部分顯示的是程序的使用率統計資訊。
② 檢視具體執行緒使用系統資源情況
2、vmstat 命令
vmstat 是 Virtual Meomory Statistics(虛擬記憶體統計)的縮寫,可對作業系統的虛擬記憶體、程序、CPU活動進行監控。
命令格式:【vmstat [ 選項 ] [ <時間間隔> ] [ <次數> ]】
欄位說明:- Procs(程序):
- r:等待執行的程序數
- b:處於非中斷睡眠狀態的程序數
- Memory(記憶體,單位Kb):
- swpd:虛擬記憶體使用情況
- free:空閒的記憶體
- buff:用來作為緩衝的記憶體數
- cache:用作快取的記憶體大小
- Swap(交換區):
- si:從磁碟交換到記憶體的交換頁數量
- so:從記憶體交換到磁碟的交換頁數量
- IO:(現在的Linux版本塊的大小為1024bytes)
- bi:傳送到塊裝置的塊數
- bo:從塊裝置接收到的塊數
- System(系統):
- in:每秒中斷數,包括時鐘中斷。【interrupt】
- cs:每秒上下文切換數。【count/second】
- CPU(以百分比表示):
- us:使用者 CPU 使用時間(user time)
- sy:核心 CPU 系統使用時間 (system time)
- id:空閒時間(包括IO等待時間),中央處理器的空閒時間 。以百分比表示。
- wa:等待IO時間
- 如果 r 經常大於4,id 經常少於40,表示cpu的負荷很重。
- 如果 bi,bo 長期不等於0,表示記憶體不足。
- 如果 disk 經常不等於0,且在 b 中的佇列大於3,表示io效能不好。
- 通過 cs 觀察 Java 程式執行過程中系統的上下文切換頻率。過高說明程式建立了過多的執行緒導致頻繁的上下文切換。
3、pidstat 命令
如果是監視某個應用的上下文切換,可以使用 pidstat 命令監控指定程序的上下文切換。
pidstat 是 Sysstat 中的一個元件,也是一款功能強大的效能監測工具,我們可以通過命令:yum install sysstat 安裝該監控元件。top 和 vmstat 兩個命令都是監測程序的記憶體、CPU 以及 I/O 使用情況,而 pidstat 命令則是深入到執行緒級別。
命令格式:【pidstat [ 選項 ] [ <時間間隔> ] [ <次數> ]】
1)常用的選項:
- -u:預設的引數,顯示各個程序的 cpu 使用情況
- -r:顯示各個程序的記憶體使用情況
- -d:顯示各個程序的 I/O 使用情況
- -p:指定程序號
- -w:顯示每個程序的上下文切換情況
- -t:顯示程序中執行緒的統計資訊
- -T { TASK | CHILD | ALL }
- TASK表示報告獨立的task,CHILD關鍵字表示報告程序下所有執行緒統計資訊。ALL表示報告獨立的task和task下面的所有執行緒。
- 注意:task和子執行緒的全域性的統計資訊和pidstat選項無關。這些統計資訊不會對應到當前的統計間隔,這些統計資訊只有在子執行緒kill或者完成的時候才會被收集。
- -V:版本號
- -h:在一行上顯示了所有活動,這樣其他程式可以容易解析。
- -I:在SMP環境,表示任務的CPU使用率/核心數量
- -l:顯示命令名和所有引數
2)檢視所有程序的 CPU 使用情況
【pidstat】、【pidstat -u -p ALL】
- PID:程序ID
- %usr:程序在使用者空間佔用cpu的百分比
- %system:程序在核心空間佔用cpu的百分比
- %guest:程序在虛擬機器佔用cpu的百分比
- %CPU:程序佔用cpu的百分比
- CPU:處理程序的cpu編號
- Command:當前程序對應的命令
3)顯示每個程序的上下文切換情況
【pidstat -w -p <PID> <時間間隔> <次數>】
- PID:程序id
- Cswch/s:每秒主動任務上下文切換數量
- Nvcswch/s:每秒被動任務上下文切換數量
- Command:命令名
4)顯示程序中執行緒的統計資訊
【pidstat -p <PID> -t】
三、視覺化工具
下面簡單介紹幾款常用的視覺化分析工具,一般我們需要將GC日誌檔案、堆轉儲檔案dump下來,然後就可以通過這些工具來分析。如果是線上分析一般直接使用上面的那些JDK命令列工具就足夠了,這些視覺化工具可以做一些輔助性的分析。
1、jvisualvm — JVM監控
jvisualvm 是 jdk 提供的監控工具,位於 %JAVA_HOME%/bin/jvisualvm.exe,雙擊執行即可。
VisualVM 提供了一個可視介面,用於檢視JVM上執行的基於 Java 技術的應用程式的詳細資訊。VisualVM 能夠監控執行緒,記憶體情況,方法的CPU時間和記憶體中的物件,已被GC的物件,反向檢視分配的堆疊(如100個String物件分別由哪幾個物件分配出來的)等。
更詳細的一些使用方式可以參考這篇文章:https://zhuanlan.zhihu.com/p/30837957
1)外掛安裝
VisualVM 基於NetBeans平臺開發工具,它具備通過外掛擴充套件功能的能力,有了外掛擴充套件支援,VisualVM可以做到:
- 顯示虛擬機器程序以及程序的配置、環境資訊(jps、jinfo)
- 監視應用程式的處理器、垃圾收集、堆、方法區以及執行緒的資訊(jstat、jstack)
- dump以及分析堆轉儲快照(jmap、jhat)
- 方法級的程式執行效能分析,找出被呼叫最多、執行時間最長的方法
- 離執行緒序快照:收集程式的執行時配置、執行緒dump、記憶體dump等資訊建立一個快照,可以將快照發送開發者處進行Bug反饋
- 其他外掛帶來的無限可能性
可以從工具選項中開啟外掛面板安裝所需的外掛:
2)監視面板
在左邊選擇需要監控的程式,右邊就可以可檢視CPU、堆、執行緒等波動情況,也可以直接在這裡進行手動 GC 和堆 Dump 操作。
3)執行緒面板
可看到所有的執行緒,以及執行緒的執行狀態。點選面板的執行緒 Dump 按鈕,可以檢視執行緒瞬時的執行緒棧。(通過 jstack 也可以抓取執行緒棧)
4)GC面板
可以很方便的看到GC趨勢圖。(也可使用 jstat 工具監控)
5)分析堆轉儲快照
通過左上角裝入快照按鈕開啟 dump 的堆轉儲檔案,就可以分析堆轉儲快照了。
3、GCViewer — 離線分析GC日誌
GCViewer 可以離線檢視GC日誌,下載地址為https://github.com/chewiebug/GCViewer。下載下來之後執行 [mvn clean install -Dmaven.test.skip=true] 命令打包編譯,編譯完成後在target目錄下會看到jar包,然後在命令列執行這個jar包就可以啟動 GCViewer。
然後通過 File 開啟GC日誌檔案,就可以看到GC統計圖和GC情況。通過工具,我們可以看到吞吐量、停頓時間以及 GC 的頻率等資訊,從而可以非常直觀地瞭解到 GC 的效能情況。
4、GCeasy — 線上分析GC日誌
GCeasy 是一款線上版的非常直觀的 GC 日誌分析工具,我們可以將日誌檔案壓縮之後,上傳到 GCeasy 官網即可看到非常清楚的 GC 日誌分析結果。
5、FastThread — 分析執行緒棧
執行緒棧使用 jstack 命令 dump 下來後,可以使用 FastThread 線上工具分析執行緒棧資訊,可以直觀的看到有多少執行緒、執行緒池、執行緒的狀態、是否有死鎖等資訊。
6、MAT — 分析堆轉儲檔案
我們使用 jmap 命令 dump 下來的堆轉儲檔案可以使用 MAT 來分析,可以分析建立了哪些物件,然後分析物件的引用鏈,找出問題所在。MAT 下載地址:http://www.eclipse.org/mat/downloads.php
MAT 主要功能:
- 找出記憶體洩漏的原因
- 找出重複引用的類和jar
- 分析集合的使用
- 分析類載入器
7、效能調優工具
1)線上工具地址
執行緒 Dump 分析(FastThread):https://fastthread.io/
執行緒 Dump 分析(PerfMa):https://thread.console.perfma.com/
記憶體 Dump 分析(PerfMa):https://memory.console.perfma.com/
JVM 引數分析(PerfMa):https://opts.console.perfma.com/
GC 日誌分析(GCEasy):https://www.gceasy.io/
GC 日誌分析(GCViewer):https://github.com/chewiebug/GCViewer
Java 診斷(Arthas):https://alibaba.github.io/arthas/
MAT:http://www.eclipse.org/mat/downloads.php
2)調優工具選擇
調優的工具很多,一般對於線上系統,使用 jstat 工具足以分析出JVM的執行情況,如果有GC日誌,也可以使用GCeasy快速分析JVM的執行情況。
遇到CPU負載過高,可以使用 top + pidstat 找出負載高的執行緒,或者直接使用 jstat 觀察是不是在頻繁FullGC。
遇到死鎖、OOM等問題,可以用 jstack 把執行緒棧dump下來分析,還可以結合 FastThread 線上工具,分析執行緒棧、哪些執行緒阻塞等待等。
遇到OOM問題,使用 jmap 把堆轉儲快照dump下來,用MAT來分析建立了哪些大量的物件。
8、JVM監控平臺
系統上線後,如果不部署視覺化的監控平臺,我們一般就通過上面的這些工具來分析JVM的記憶體運轉模型、GC情況等,可以在機器上執行jstat,讓其把監控資訊寫入一個檔案,每天定時檢查—下。
監控平臺則可以通過視覺化的介面看到JVM各個區域的記憶體變化,GC次數和GC耗時等資訊,以及出現效能問題時能及時報警。
一般可以部署 Zabbix、Ganglia、Open-Falcon、Prometheus 之類的視覺化監控平臺,把線上系統接入到這些平臺,就可以直接圖形化看到JVM的表現。
四、利用工具分析JVM執行情況
要想合理地分配記憶體、優化GC,通過前一篇的效能調優過程可以發現,我們至少需要知道如下的一些資訊:新生代物件增長的速率,YoungGC的觸發頻率,YoungGC的耗時,每次YoungGC後存活物件大小,每次YoungGC過後有多少物件進入了老年代,老年代物件增長的速率,FullGC的觸發頻率,FullGC的耗時等。前面我們是通過分析GC日誌或者粗略估算的方式來調優的,現在就利用 jstat 工具來分析下。
1、執行示例程式
1)如下示例程式碼
這段程式碼模擬每秒鐘在新生代建立20M物件,1秒之後就變為垃圾物件了。
1 public class GCMain { 2 static final int _1M = 1024 * 1024; 3 4 public static void main(String[] args) { 5 sleep(20); 6 7 for (int i = 0; i < 100; i++) { 8 loadData(i); 9 } 10 } 11 12 // loadData 每次請求產生20M物件,每次請求耗時1秒 13 public static void loadData(int index) { 14 System.out.println("load data: " + index); 15 byte[] data1 = new byte[_1M * 10]; 16 byte[] data2 = new byte[_1M * 10]; 17 18 sleep(1); 19 } 20 21 public static void sleep(long seconds) { 22 try { 23 Thread.sleep(seconds * 1000); 24 } catch (InterruptedException e) { 25 e.printStackTrace(); 26 } 27 } 28 }
2)設定JVM引數
執行示例程式前設定如下的JVM引數:新生代、老年代各100M,Eden區80M,Survivor區10M,大物件閥值20M。
-Xms200M -Xmx200M -Xmn100M -XX:SurvivorRatio=8 -XX:MaxTenuringThreshold=5 -XX:PretenureSizeThreshold=20M -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFraction=92 -XX:+UseCMSInitiatingOccupancyOnly -XX:+UseCMSCompactAtFullCollection -XX:CMSFullGCsBeforeCompaction=0 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./gc.log
3)估算記憶體運轉模型
我們先根據這段業務程式碼以及JVM引數配置估算下JVM執行情況:
- 這段程式碼每秒將在Eden區產生20M物件,大概3~4秒鐘會佔滿Eden區觸發YoungGC。
- YoungGC 後存活的物件可能超過10M,因為可能在建立 data2 時,Eden區不夠了,而 data1 還是存活的;也有可能為0,在建立 data1 的時候 Eden 區就不夠了。
- 由於 Survivor 區不足以放下YoungGC後存活的物件,那麼每次大概會有10M的物件進入老年代;考慮到有可能YoungGC後沒有存活物件,就估算為2次YoungGC會有10M進入老年代吧。
- YoungGC 3~4 秒觸發一次,那麼大概經過18次左右YoungGC,就是60秒左右,老年代就快滿了,然後存活物件無法放入老年代觸發FullGC。
- 由於CMS後臺回收執行緒在老年代超過92%時會觸發OldGC,所以60秒左右也有可能由於老年代超過92%這個閥值觸發GC。
4)使用 jps 命令找出程式的 PID
將程式執行起來,首先通過 jps -l 命令找到這個程式的PID。
5)使用 jstat 命令檢視GC情況
如下是 jstat 輸出的情況:
1 Mechrevo@hello-world MINGW64 ~/Desktop 2 $ jstat -gc 15488 1000 1000 3 S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT 4 10240.0 10240.0 0.0 0.0 81920.0 4984.1 102400.0 0.0 4480.0 786.6 384.0 76.4 0 0.000 0 0.000 0.000 5 10240.0 10240.0 0.0 0.0 81920.0 4984.1 102400.0 0.0 4480.0 786.6 384.0 76.4 0 0.000 0 0.000 0.000 6 10240.0 10240.0 0.0 0.0 81920.0 4984.1 102400.0 0.0 4480.0 786.6 384.0 76.4 0 0.000 0 0.000 0.000 7 10240.0 10240.0 0.0 0.0 81920.0 4984.1 102400.0 0.0 4480.0 786.6 384.0 76.4 0 0.000 0 0.000 0.000 8 10240.0 10240.0 0.0 0.0 81920.0 4984.1 102400.0 0.0 4480.0 786.6 384.0 76.4 0 0.000 0 0.000 0.000 9 10240.0 10240.0 0.0 0.0 81920.0 25464.1 102400.0 0.0 4480.0 786.6 384.0 76.4 0 0.000 0 0.000 0.000 10 10240.0 10240.0 0.0 0.0 81920.0 45944.2 102400.0 0.0 4480.0 786.6 384.0 76.4 0 0.000 0 0.000 0.000 11 10240.0 10240.0 0.0 0.0 81920.0 66424.2 102400.0 0.0 4480.0 786.6 384.0 76.4 0 0.000 0 0.000 0.000 12 10240.0 10240.0 0.0 713.8 81920.0 11878.4 102400.0 10242.1 4864.0 3043.9 512.0 321.7 1 0.005 0 0.000 0.005 13 10240.0 10240.0 0.0 713.8 81920.0 33961.9 102400.0 10242.1 4864.0 3043.9 512.0 321.7 1 0.005 0 0.000 0.005 14 10240.0 10240.0 0.0 713.8 81920.0 54441.9 102400.0 10242.1 4864.0 3043.9 512.0 321.7 1 0.005 0 0.000 0.005 15 10240.0 10240.0 0.0 713.8 81920.0 74922.0 102400.0 10242.1 4864.0 3043.9 512.0 321.7 1 0.005 0 0.000 0.005 16 10240.0 10240.0 828.5 0.0 81920.0 22891.3 102400.0 10242.1 4864.0 3044.4 512.0 321.7 2 0.005 0 0.000 0.005 17 10240.0 10240.0 828.5 0.0 81920.0 43371.3 102400.0 10242.1 4864.0 3044.4 512.0 321.7 2 0.005 0 0.000 0.005 18 10240.0 10240.0 828.5 0.0 81920.0 63851.3 102400.0 10242.1 4864.0 3044.4 512.0 321.7 2 0.005 0 0.000 0.005 19 10240.0 10240.0 0.0 964.7 81920.0 10240.0 102400.0 20484.1 4864.0 3044.5 512.0 321.7 3 0.010 0 0.000 0.010 20 10240.0 10240.0 0.0 964.7 81920.0 32230.5 102400.0 20484.1 4864.0 3044.5 512.0 321.7 3 0.010 0 0.000 0.010 21 10240.0 10240.0 0.0 964.7 81920.0 52710.5 102400.0 20484.1 4864.0 3044.5 512.0 321.7 3 0.010 0 0.000 0.010 22 10240.0 10240.0 0.0 964.7 81920.0 73190.5 102400.0 20484.1 4864.0 3044.5 512.0 321.7 3 0.010 0 0.000 0.010 23 10240.0 10240.0 759.6 0.0 81920.0 22035.2 102400.0 20484.1 4864.0 3044.5 512.0 321.7 4 0.011 0 0.000 0.011 24 10240.0 10240.0 759.6 0.0 81920.0 42515.2 102400.0 20484.1 4864.0 3044.5 512.0 321.7 4 0.011 0 0.000 0.011 25 10240.0 10240.0 759.6 0.0 81920.0 62995.2 102400.0 20484.1 4864.0 3044.5 512.0 321.7 4 0.011 0 0.000 0.011 26 10240.0 10240.0 0.0 886.2 81920.0 10240.0 102400.0 30724.1 4864.0 3044.5 512.0 321.7 5 0.016 0 0.000 0.016 27 10240.0 10240.0 0.0 886.2 81920.0 32212.1 102400.0 30724.1 4864.0 3044.5 512.0 321.7 5 0.016 0 0.000 0.016 28 10240.0 10240.0 0.0 886.2 81920.0 52692.1 102400.0 30724.1 4864.0 3044.5 512.0 321.7 5 0.016 0 0.000 0.016 29 10240.0 10240.0 0.0 886.2 81920.0 73172.1 102400.0 30724.1 4864.0 3044.5 512.0 321.7 5 0.016 0 0.000 0.016 30 10240.0 10240.0 0.0 0.0 81920.0 22023.2 102400.0 31373.1 4864.0 3044.5 512.0 321.7 6 0.019 0 0.000 0.019 31 10240.0 10240.0 0.0 0.0 81920.0 42503.3 102400.0 31373.1 4864.0 3044.5 512.0 321.7 6 0.019 0 0.000 0.019 32 10240.0 10240.0 0.0 0.0 81920.0 62983.3 102400.0 31373.1 4864.0 3044.5 512.0 321.7 6 0.019 0 0.000 0.019 33 10240.0 10240.0 0.0 0.0 81920.0 10240.0 102400.0 41613.1 4864.0 3044.5 512.0 321.7 7 0.024 0 0.000 0.024 34 10240.0 10240.0 0.0 0.0 81920.0 32204.4 102400.0 41613.1 4864.0 3044.5 512.0 321.7 7 0.024 0 0.000 0.024 35 10240.0 10240.0 0.0 0.0 81920.0 52684.4 102400.0 41613.1 4864.0 3044.5 512.0 321.7 7 0.024 0 0.000 0.024 36 10240.0 10240.0 0.0 0.0 81920.0 73164.4 102400.0 41613.1 4864.0 3044.5 512.0 321.7 7 0.024 0 0.000 0.024 37 10240.0 10240.0 0.0 0.0 81920.0 22018.2 102400.0 41613.1 4864.0 3044.9 512.0 321.7 8 0.025 0 0.000 0.025 38 10240.0 10240.0 0.0 0.0 81920.0 42498.3 102400.0 41613.1 4864.0 3044.9 512.0 321.7 8 0.025 0 0.000 0.025 39 10240.0 10240.0 0.0 0.0 81920.0 62978.3 102400.0 41613.1 4864.0 3044.9 512.0 321.7 8 0.025 0 0.000 0.025 40 10240.0 10240.0 0.0 0.0 81920.0 10240.0 102400.0 51853.2 4864.0 3044.9 512.0 321.7 9 0.030 0 0.000 0.030 41 10240.0 10240.0 0.0 0.0 81920.0 32201.1 102400.0 51853.2 4864.0 3044.9 512.0 321.7 9 0.030 0 0.000 0.030 42 10240.0 10240.0 0.0 0.0 81920.0 52681.2 102400.0 51853.2 4864.0 3044.9 512.0 321.7 9 0.030 0 0.000 0.030 43 10240.0 10240.0 0.0 0.0 81920.0 73161.2 102400.0 51853.2 4864.0 3044.9 512.0 321.7 9 0.030 0 0.000 0.030 44 10240.0 10240.0 0.0 0.0 81920.0 22016.1 102400.0 51853.2 4864.0 3045.6 512.0 321.7 10 0.031 0 0.000 0.031 45 10240.0 10240.0 0.0 0.0 81920.0 42496.2 102400.0 51853.2 4864.0 3045.6 512.0 321.7 10 0.031 0 0.000 0.031 46 10240.0 10240.0 0.0 0.0 81920.0 62976.2 102400.0 51853.2 4864.0 3045.6 512.0 321.7 10 0.031 0 0.000 0.031 47 10240.0 10240.0 0.0 0.0 81920.0 10240.0 102400.0 62093.2 4864.0 3045.9 512.0 321.7 11 0.036 0 0.000 0.036 48 10240.0 10240.0 0.0 0.0 81920.0 32199.8 102400.0 62093.2 4864.0 3045.9 512.0 321.7 11 0.036 0 0.000 0.036 49 10240.0 10240.0 0.0 0.0 81920.0 52679.8 102400.0 62093.2 4864.0 3045.9 512.0 321.7 11 0.036 0 0.000 0.036 50 10240.0 10240.0 0.0 0.0 81920.0 52679.8 102400.0 62093.2 4864.0 3045.9 512.0 321.7 11 0.036 0 0.000 0.036 51 10240.0 10240.0 0.0 0.0 81920.0 22015.3 102400.0 62093.2 4864.0 3045.9 512.0 321.7 12 0.036 0 0.000 0.036 52 10240.0 10240.0 0.0 0.0 81920.0 42495.3 102400.0 62093.2 4864.0 3045.9 512.0 321.7 12 0.036 0 0.000 0.036 53 10240.0 10240.0 0.0 0.0 81920.0 62975.3 102400.0 62093.2 4864.0 3045.9 512.0 321.7 12 0.036 0 0.000 0.036 54 10240.0 10240.0 0.0 0.0 81920.0 0.0 102400.0 72333.2 4864.0 3045.9 512.0 321.7 13 0.041 0 0.000 0.041 55 10240.0 10240.0 0.0 0.0 81920.0 32199.2 102400.0 72333.2 4864.0 3045.9 512.0 321.7 13 0.041 0 0.000 0.041 56 10240.0 10240.0 0.0 0.0 81920.0 52679.3 102400.0 72333.2 4864.0 3045.9 512.0 321.7 13 0.041 0 0.000 0.041 57 10240.0 10240.0 0.0 0.0 81920.0 74797.7 102400.0 72333.2 4864.0 3045.9 512.0 321.7 13 0.041 0 0.000 0.041 58 10240.0 10240.0 4.0 0.0 81920.0 0.0 102400.0 72333.2 4864.0 3048.0 512.0 321.7 14 0.042 0 0.000 0.042 59 10240.0 10240.0 4.0 0.0 81920.0 22014.9 102400.0 72333.2 4864.0 3048.0 512.0 321.7 14 0.042 0 0.000 0.042 60 10240.0 10240.0 4.0 0.0 81920.0 62975.0 102400.0 72333.2 4864.0 3048.0 512.0 321.7 14 0.042 0 0.000 0.042 61 10240.0 10240.0 0.0 2.0 81920.0 10240.0 102400.0 82573.2 4864.0 3048.0 512.0 321.7 15 0.047 0 0.000 0.047 62 10240.0 10240.0 0.0 2.0 81920.0 10240.0 102400.0 82573.2 4864.0 3048.0 512.0 321.7 15 0.047 0 0.000 0.047 63 10240.0 10240.0 0.0 2.0 81920.0 32199.0 102400.0 82573.2 4864.0 3048.0 512.0 321.7 15 0.047 0 0.000 0.047 64 10240.0 10240.0 0.0 2.0 81920.0 73159.1 102400.0 82573.2 4864.0 3048.0 512.0 321.7 15 0.047 0 0.000 0.047 65 10240.0 10240.0 4.0 0.0 81920.0 0.0 102400.0 82573.2 4864.0 3048.0 512.0 321.7 16 0.048 0 0.000 0.048 66 10240.0 10240.0 4.0 0.0 81920.0 22014.7 102400.0 82573.2 4864.0 3048.0 512.0 321.7 16 0.048 0 0.000 0.048 67 10240.0 10240.0 4.0 0.0 81920.0 62974.8 102400.0 82573.2 4864.0 3048.0 512.0 321.7 16 0.048 0 0.000 0.048 68 10240.0 10240.0 0.0 2.0 81920.0 10240.0 102400.0 10892.1 4864.0 3048.7 512.0 321.7 17 0.053 2 0.002 0.055 69 10240.0 10240.0 0.0 2.0 81920.0 10240.0 102400.0 10892.1 4864.0 3048.7 512.0 321.7 17 0.053 2 0.002 0.055 70 10240.0 10240.0 0.0 2.0 81920.0 32198.9 102400.0 10892.1 4864.0 3048.7 512.0 321.7 17 0.053 2 0.002 0.055 71 10240.0 10240.0 0.0 2.0 81920.0 73159.0 102400.0 10892.1 4864.0 3048.7 512.0 321.7 17 0.053 2 0.002 0.055 72 10240.0 10240.0 2.0 0.0 81920.0 22833.9 102400.0 10892.1 4864.0 3049.0 512.0 321.7 18 0.054 2 0.002 0.056 73 10240.0 10240.0 2.0 0.0 81920.0 22833.9 102400.0 10892.1 4864.0 3049.0 512.0 321.7 18 0.054 2 0.002 0.056 74 10240.0 10240.0 2.0 0.0 81920.0 43313.9 102400.0 10892.1 4864.0 3049.0 512.0 321.7 18 0.054 2 0.002 0.056 75 10240.0 10240.0 0.0 4.0 81920.0 0.0 102400.0 21132.1 4864.0 3049.0 512.0 321.7 19 0.056 2 0.002 0.058 76 10240.0 10240.0 0.0 4.0 81920.0 10240.0 102400.0 21132.1 4864.0 3049.0 512.0 321.7 19 0.056 2 0.002 0.058 77 10240.0 10240.0 0.0 4.0 81920.0 32193.5 102400.0 21132.1 4864.0 3049.0 512.0 321.7 19 0.056 2 0.002 0.058 78 10240.0 10240.0 0.0 4.0 81920.0 52673.6 102400.0 21132.1 4864.0 3049.0 512.0 321.7 19 0.056 2 0.002 0.058 79 10240.0 10240.0 2.0 0.0 81920.0 22011.2 102400.0 21132.1 4864.0 3049.0 512.0 321.7 20 0.057 2 0.002 0.058 80 10240.0 10240.0 2.0 0.0 81920.0 22011.2 102400.0 21132.1 4864.0 3049.0 512.0 321.7 20 0.057 2 0.002 0.058 81 10240.0 10240.0 2.0 0.0 81920.0 42491.2 102400.0 21132.1 4864.0 3049.0 512.0 321.7 20 0.057 2 0.002 0.058 82 10240.0 10240.0 0.0 4.0 81920.0 0.0 102400.0 31372.2 4864.0 3049.0 512.0 321.7 21 0.059 2 0.002 0.060 83 10240.0 10240.0 0.0 4.0 81920.0 10240.0 102400.0 31372.2 4864.0 3049.0 512.0 321.7 21 0.059 2 0.002 0.060 84 10240.0 10240.0 0.0 4.0 81920.0 32196.6 102400.0 31372.2 4864.0 3049.0 512.0 321.7 21 0.059 2 0.002 0.060 85 10240.0 10240.0 0.0 4.0 81920.0 52676.6 102400.0 31372.2 4864.0 3049.0 512.0 321.7 21 0.059 2 0.002 0.060 86 10240.0 10240.0 4.0 0.0 81920.0 0.0 102400.0 31372.2 4864.0 3049.0 512.0 321.7 22 0.059 2 0.002 0.061 87 10240.0 10240.0 4.0 0.0 81920.0 22013.2 102400.0 31372.2 4864.0 3049.0 512.0 321.7 22 0.059 2 0.002 0.061 88 10240.0 10240.0 4.0 0.0 81920.0 42493.2 102400.0 31372.2 4864.0 3049.0 512.0 321.7 22 0.059 2 0.002 0.061 89 10240.0 10240.0 0.0 4.0 81920.0 0.0 102400.0 41612.2 4864.0 3049.0 512.0 321.7 23 0.061 2 0.002 0.062 90 10240.0 10240.0 0.0 4.0 81920.0 10240.0 102400.0 41612.2 4864.0 3049.0 512.0 321.7 23 0.061 2 0.002 0.062 91 10240.0 10240.0 0.0 4.0 81920.0 32197.9 102400.0 41612.2 4864.0 3049.0 512.0 321.7 23 0.061 2 0.002 0.062 92 10240.0 10240.0 0.0 4.0 81920.0 52677.9 102400.0 41612.2 4864.0 3049.0 512.0 321.7 23 0.061 2 0.002 0.062 93 10240.0 10240.0 0.0 0.0 81920.0 0.0 102400.0 41612.2 4864.0 3049.0 512.0 321.7 24 0.061 2 0.002 0.063 94 10240.0 10240.0 0.0 0.0 81920.0 42494.1 102400.0 41612.2 4864.0 3049.0 512.0 321.7 24 0.061 2 0.002 0.063 95 10240.0 10240.0 0.0 0.0 81920.0 42494.1 102400.0 41612.2 4864.0 3049.0 512.0 321.7 24 0.061 2 0.002 0.063 96 10240.0 10240.0 0.0 0.0 81920.0 0.0 102400.0 51852.3 4864.0 3049.8 512.0 321.7 25 0.063 2 0.002 0.065 97 10240.0 10240.0 0.0 0.0 81920.0 10240.0 102400.0 51852.3 4864.0 3049.8 512.0 321.7 25 0.063 2 0.002 0.065 98 10240.0 10240.0 0.0 0.0 81920.0 32198.4 102400.0 51852.3 4864.0 3049.8 512.0 321.7 25 0.063 2 0.002 0.065 99 10240.0 10240.0 0.0 0.0 81920.0 52678.5 102400.0 51852.3 4864.0 3049.8 512.0 321.7 25 0.063 2 0.002 0.065 100 10240.0 10240.0 0.0 0.0 81920.0 0.0 102400.0 51852.3 4864.0 3049.8 512.0 321.7 26 0.064 2 0.002 0.065 101 10240.0 10240.0 0.0 0.0 81920.0 22014.4 102400.0 51852.3 4864.0 3049.8 512.0 321.7 26 0.064 2 0.002 0.065 102 10240.0 10240.0 0.0 0.0 81920.0 42494.4 102400.0 51852.3 4864.0 3049.8 512.0 321.7 26 0.064 2 0.002 0.065 103 10240.0 10240.0 0.0 0.0 81920.0 62974.4 102400.0 51852.3 4864.0 3049.8 512.0 321.7 26 0.064 2 0.002 0.065 104 10240.0 10240.0 0.0 0.0 81920.0 10240.0 102400.0 62092.3 4864.0 3049.8 512.0 321.7 27 0.065 2 0.002 0.067 105 10240.0 10240.0 0.0 0.0 81920.0 32198.7 102400.0 62092.3 4864.0 3049.8 512.0 321.7 27 0.065 2 0.002 0.067 106 10240.0 10240.0 0.0 0.0 81920.0 52678.7 102400.0 62092.3 4864.0 3049.8 512.0 321.7 27 0.065 2 0.002 0.067 107 10240.0 10240.0 0.0 0.0 81920.0 73158.7 102400.0 62092.3 4864.0 3049.8 512.0 321.7 27 0.065 2 0.002 0.067 108 10240.0 10240.0 0.0 0.0 81920.0 22014.5 102400.0 62092.3 4864.0 3050.1 512.0 321.7 28 0.066 2 0.002 0.068 109 10240.0 10240.0 0.0 0.0 81920.0 42494.6 102400.0 62092.3 4864.0 3050.1 512.0 321.7 28 0.066 2 0.002 0.068View Code
首先從前面幾行可以看出記憶體各個區域的大小,Survivor0/Survivor1 10M,Eden區80M,老年代100M 等資訊。
2、新生代物件增長的速率
從 EU 這一行可以看出,新生代基本是按照每秒20M左右的物件在增長。
3、YoungGC的觸發頻率和耗時
從 Eden 區的記憶體變化可以看出,基本是每隔3秒或4秒就會觸發一次 YoungGC,比如第一次Eden區增長到66424.2時,經過一次 YoungGC後只剩下11878.4。從 YGC 這列也大致可以看出YoungGC的頻率。
從 YGCT 這列可以看出,每次YoungGC耗時1~5毫秒的樣子,也就是說每隔3~4秒,觸發一次YoungGC,一次YoungGC系統卡頓1~5毫秒。這也可以看出 YoungGC 其實是很快的,就算新生代800M也才10幾毫秒,對系統幾乎沒什麼影響。
4、YoungGC後存活物件大小以及有多少物件進入了老年代
從 S0U、S1U 這兩列的變化可以看出,每次YoungGC後有800K左右的物件進入 Survivor 區。
從 OU 這列的變化可以看出,每次進入老年代的物件在10M左右,所以一次YoungGC後可能有10M的存活物件進入老年代。
5、FullGC的觸發頻率和耗時
從 OU 這列的變化可以看出,在老年代達到 82573.2 時,觸發了 FullGC,回收後老年代大小為 10892.1。從整體的時間線上看,剛好60秒就觸發了一次FullGC。
從 FGCT 可以看出,一次FullGC 耗時2毫秒,
為什麼在老年代82573.2 時就觸發了FullGC呢,我們從GC日誌中來看:
可以看出這一秒內,實際上這次YoungGC導致有10M的物件進入老年代,老年代實際有92815K物件,因而應該是CMS超過了 92% 的閥值之後觸發了老年代GC。
6、使用GCeasy檢視GC日誌
至此,其實已經基本上分析出整個JVM的運轉情況了。這裡總結下:
- 新生代、老年代 100M,Eden區80M,Survivor區10M;
- Eden區每秒產生20M左右物件,每隔3~4秒觸發一次YoungGC;
- YoungGC後存活物件在0~10M左右,由於無法放入Survivor區會進入老年代,每次進入老年代物件10M左右;
- 在經過16次左右YoungGC後,也就是60秒左右老年代會接近佔滿,超過設定的閥值,觸發一次 FullGC。
從上面的分析可以看出,jstat 監控的輸出結果基本是符合前面估算的結果的。但是粗略估算需要熟悉系統核心的業務,而且其它未知因素也比較多,粗略估算一般用於系統剛上線階段來設定JVM引數。而通過 jstat 來監控一般就可以比較準確的摸清JVM的執行情況,然後進行效能調優。
接下來再通過GC日誌來看下是否符合分析的情況,GC日誌就不再一行一行分析了,我們直接通過線上工具 GCeasy 來看看記憶體變化和GC的情況。將輸出的GC日誌直接拷貝到 GCeasy 上,就可以看到分析的結果。
1)GC總體情況
從這張圖可以得到如下資訊:
- 垃圾回收器的吞吐率為 99.937%;
- 平均GC停頓時間:2毫秒
- 最長GC停頓時間:10毫秒
- 80% 的GC耗時 0~1毫秒
- 20% 的GC耗時 9~10毫秒
2)YoungGC頻率
從 Young Gen 這個統計圖可以看出,YoungGC的頻率在3~4秒的樣子。
3)老年代GC頻率
從這張統計圖可以看出,老年代是每兩次YoungGC增長一次,每次增長10M左右,在60秒左右觸發一次OldGC。
4)CMS回收情況
這張圖展示了CMS各個階段的統計情況
7、效能優化
從上面的分析可以看出,這個JVM最大的問題在於 Survivor 區沒起作用,Survivor 區只有10M,而YoungGC後存活物件大於10M,導致無法放進Survivor區而直接進入老年代了,進而觸發FullGC。因此我們可以增大新生代大小或者調整Eden區和Survivor區比例,來讓物件進入Survivor區。
比如改為如下配置:新生代給150M,比例調整為6,這樣Eden區90M,Survivor區各30M,這樣Survivor區足以放下YoungGC後存活的物件,也基本上能避免動態年齡判斷導致物件進入老年代。
-Xms200M -Xmx200M -Xmn150M -XX:SurvivorRatio=6
再看這時的GC情況,首先從 S0U、S1U 的變化可以看出,Survivor 區在起作用了,每次YoungGC後存活物件都進入Survivor區了。
然後從 OU、YGC的變化可以看出,有部分長期存活的物件在YoungGC次數超過設定的GC年齡閥值(設定的5歲)後,進入了老年代。
從 FGC 這列可以看出,Survivor 區合理設定後,再沒有發生過 FullGC 了。
五、使用 MAT 分析OOM問題
對於排查 OOM 問題、分析程式堆記憶體使用情況,最好的方式就是分析堆轉儲,堆轉儲,包含了堆現場全貌和執行緒棧資訊。這節就來看看如何使用MAT分析OOM問題。
1、執行示例程式
準備如下兩個測試類:
1 package com.lyyzoo.test.jvm; 2 3 public class OomService { 4 5 private List<String> data = new ArrayList<>(); 6 7 public void addData() { 8 //往同一個ArrayList中不斷加入大小為10KB的字串 9 data.add(IntStream.rangeClosed(1, 10_000) 10 .mapToObj(__ -> "A") 11 .collect(Collectors.joining(""))); 12 } 13 }
1 package com.lyyzoo.test.jvm; 2 3 public class OomMain { 4 public static void main(String[] args) { 5 OomService service = new OomService(); 6 7 while (true) { 8 service.addData(); 9 } 10 } 11 }
設定如下JVM引數:
-Xms200M -Xmx200M -Xmn100M -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=./dump.hprof -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./gc.log
執行程式後報OOM異常:
2、MAT 分析OOM問題的思路
對於線上執行的程式,如果我們不能通過日誌快速定位出OOM的根源,一般就可以使用MAT來分析OOM的問題。
使用 MAT 分析 OOM 問題,一般可以按照以下思路進行:
- 通過支配樹功能或直方圖功能檢視消耗記憶體最大的型別,來分析記憶體洩露的大概原因;
- 檢視那些消耗記憶體最大的型別、詳細的物件明細列表,以及它們的引用鏈,來定位記憶體洩露的具體點;
- 配合檢視物件屬性的功能,可以脫離原始碼看到物件的各種屬性的值和依賴關係,幫助我們理清程式邏輯和引數;
- 輔助使用檢視執行緒棧來看 OOM 問題是否和過多執行緒有關,甚至可以線上程棧看到 OOM 最後一刻出現異常的執行緒。
如果dump出來的記憶體快照很大,比如有幾個G,務必在啟動MAT之前,先在配置檔案(MemoryAnalyzer.ini)裡給MAT本身設定—下堆記憶體大小(預設為1024m),比如設定為4個G,或者8個G。
3、總覽圖 — 快速分析OOM問題
使用MAT開啟堆轉儲檔案 dump.hprof,開啟後先進入的是概覽資訊介面:
從餅圖可以看出,明顯有物件佔用了大量記憶體,然後再看 Problem Suspect1,已經說明了 main 執行緒通過區域性變數佔據了 99.42% 記憶體的物件,而且是 java.lang.Object[] 陣列佔據了大量記憶體。
點選 Details 進去檢視詳細的說明,從 “Accumulated Objects in Dominator Tree” 支配樹可以看出,main 執行緒引用了 OomService 物件,OomService 引用了一個 ArrayList 物件,然後 ArrayList 儲存了大量 String 物件。這裡基本上就能分析出OOM的根源了。
再點選See stacktrace 看看執行緒棧基本就能定位到問題程式碼了。
4、直方圖 — 定位根源
工具欄的第二個按鈕可以開啟直方圖,直方圖按照型別進行分組,列出了每個類有多少個例項,以及佔用的記憶體。
可以看到,char[] 位元組陣列佔用記憶體最多,物件數量也很多,第二位的 String 物件數量也非常多,有 9791 個,從這大概可以猜出應該是建立了大量的 String 物件。
在 char[] 上點選右鍵,選擇 List objects -> with incoming references,就可以列出所有的 char[] 例項,以及每個 char[] 的整個引用關係鏈:
隨機展開一個 char[],如下圖所示:
右側框中可以看到整個引用鏈,左側的框可以檢視每一個例項的內部屬性。
通過這個引用鏈可以發現是 String 物件引用了 char[] 陣列(String 的內部結構就是一個 char[] 陣列),說明建立了大量的 String 物件;然後 String 物件又被 ArrayList 的 Object[] 陣列引用著,說明是大量 String 物件放入了 ArrayList 中,然後這個 ArrayList 又被 OomService 的 data 變數引用著。到這裡就定位出了引發OOM的類了。
Retained Heap(深堆)代表物件本身和物件關聯的物件佔用的記憶體,Shallow Heap(淺堆)代表物件本身佔用的記憶體。比如,OomService 中的 data 這個 ArrayList 物件本身只有 16 位元組,但是其所有關聯的物件佔用了 130+MB 記憶體。
如果希望看到完整內容的話,可以右鍵選擇 Copy->Value,把值複製到剪貼簿或儲存到檔案中:
5、支配樹 — 定位根源
其實,使用直方圖定位 OomService,已經走了些彎路。可以點選工具欄中第三個按鈕進入支配樹介面。這個介面會按照物件保留的 Retained Heap 倒序直接列出佔用記憶體最大的物件。
可以看到,第一位就是 OomService,整個路徑是 OomSerice -> ArrayList -> Object[] -> String -> char[] 。
6、執行緒棧 — 分析程式碼
可以點選工具欄的第五個按鈕,開啟執行緒檢視來分析 OomService 執行什麼邏輯。可以看到 OomService 是 OomMain 的一個本地變數,然後 OomMain 呼叫了 OomService 的 addData 方法,然後 addData 方法裡應該是通過 Stream 生成一個字串放入 data 中的。
7、OQL—查詢資料
點選工具欄的第四個按鈕,來到 OQL 介面。在這個介面,我們可以使用類似 SQL 的語法,在 dump 中搜索資料。可以看到只建立了一個 OomService 例項,說明只有一個地方呼叫了 OomService 的方法。
然後可通過 List objects 功能搜尋引用OomService 的物件:
可以看到其被 main 執行緒引用著:
六、使用 Arthas 分析高 CPU 問題
Arthas 是阿里開源的 Java 診斷工具,相比 JDK 內建的診斷工具,要更人性化,並且功能強大,可以實現許多問題的一鍵定位,而且可以一鍵反編譯類檢視原始碼,甚至是直接進行生產程式碼熱修復,實現在一個工具內快速定位和修復問題的一站式服務。
Arthas 官方文件:https://alibaba.github.io/arthas/
1、執行示例程式
準備如下導致CPU負載高的程式碼:程式碼中建立了2個執行緒的執行緒池,提交的任務通過BCryptPasswordEncoder 對一個長字串加密,這個是非常消耗CPU的。
1 package com.lyyzoo.test.jvm; 2 3 import java.util.concurrent.ExecutorService; 4 import java.util.concurrent.Executors; 5 import java.util.concurrent.Future; 6 import java.util.stream.Collectors; 7 import java.util.stream.IntStream; 8 9 import org.apache.commons.lang3.RandomUtils; 10 import org.springframework.security.crypto.bcrypt.BCryptPasswordEncoder; 11 12 public class CpuService { 13 private BCryptPasswordEncoder encoder = new BCryptPasswordEncoder(); 14 private ExecutorService executor = Executors.newFixedThreadPool(2); 15 16 public void doTask() throws Exception { 17 while (true) { 18 randomEncode(RandomUtils.nextInt(0, 10000)); 19 } 20 } 21 22 private void randomEncode(Integer size) throws Exception { 23 String payload = IntStream.rangeClosed(1, size).mapToObj(__ -> "A").collect(Collectors.joining()); 24 Future<String> f1 = executor.submit(() -> { 25 return encoder.encode(payload); 26 }); 27 Future<String> f2 = executor.submit(() -> { 28 return encoder.encode(payload); 29 }); 30 31 f1.get(); 32 f2.get(); 33 } 34 }
1 public class CpuMain { 2 private static CpuService service = new CpuService(); 3 4 public static void main(String[] args) throws Exception { 5 service.doTask(); 6 } 7 }
2、啟動 Arthas
首先,下載 Arthas:https://arthas.aliyun.com/arthas-boot.jar
然後把程式先執行起來,再執行 arthas:java -jar arthas-boot.jar
啟動後,直接找到我們要排查的 JVM 程序,然後可以看到 Arthas 附加程序成功:
輸入 help 命令,可以看到所有支援的命令列表。這裡主要會用到 dashboard、thread、jad、watch 等命令,來定位高CPU的問題。
3、dashboard — 展示整體情況
dashboard 命令整體展示了程序所有執行緒、記憶體、GC 等情況,可以明顯看到兩個CPU佔用很高的執行緒,從執行緒名字來看應該是執行緒池的執行緒。
4、thread — 檢視高CPU的執行緒
接下來,檢視最繁忙的執行緒在執行的執行緒棧,可以使用 thread -n 命令。這裡,我們檢視下最忙的 2 個執行緒:從執行緒棧可以看出,應該就是 CpuService 的 randomEncode 方法呼叫BCryptPasswordEncoder 的 encode 方法導致CPU負載高的。
5、watch — 監控引數
如果想要觀察方法的入參和出參,可以用 watch 命令來觀察:
6、jad — 反編譯
前面已經分析出CPU負載高的位置是 CpuService 的randomEncode 了,那麼通過 jad 反編譯來看看原始碼長什麼樣子,方便我們進一步定位問題。
7、redefine — 過載類
如果我們想做線上除錯,又不想在本地改程式碼,列印日誌,再提交到伺服器,再重啟服務測試,那我們可以結合 arthas 的 jad、mc、redefine 來動態重定義類。
① 首先用 jad 把原始檔下載下來
然後修改下原始碼:添加了一行輸出日誌
② 使用 mc 命令反編譯原始檔
反編譯後會生成對應的 class 檔案:
③ 使用 redefine 過載類
就可以看到控制檯已經在輸出我們列印的日誌了:
需要額外說明的是,由於 monitor、trace、watch 等命令是通過位元組碼增強技術來實現的,會在指定類的方法中插入一些切面來實現資料統計和觀測,因此診斷結束要執行 shutdown 來還原類或方法位元組碼,然後退出 Arthas。
參考
本文是學習、參考瞭如下課程,再通過自己的總結和實踐總結而來。如果想了解更多深入的細節,建議閱讀原著。