JVM性能調優(4) —— 性能調優工具

前序文章:

JVM性能調優(1) —— JVM內存模型和類加載運行機制

JVM性能調優(2) —— 垃圾回收器和回收策略

JVM性能調優(3) —— 內存分配和垃圾回收調優

一、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對象分別由哪幾個對象分配出來的)等。

更詳細的一些使用方式可以參考這篇文章://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日誌,下載地址為 //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 下載地址://www.eclipse.org/mat/downloads.php

MAT 主要功能:

  • 找出內存泄漏的原因
  • 找出重複引用的類和jar
  • 分析集合的使用
  • 分析類加載器

7、性能調優工具

1)在線工具地址

線程 Dump 分析(FastThread)://fastthread.io/

線程 Dump 分析(PerfMa)://thread.console.perfma.com/

內存 Dump 分析(PerfMa)://memory.console.perfma.com/

JVM 參數分析(PerfMa)://opts.console.perfma.com/

GC 日誌分析(GCEasy)://www.gceasy.io/

GC 日誌分析(GCViewer)://github.com/chewiebug/GCViewer

Java 診斷(Arthas)://alibaba.github.io/arthas/

MAT://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.068

View 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 官方文檔://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://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。

參考

本文是學習、參考了如下課程,再通過自己的總結和實踐總結而來。如果想了解更多深入的細節,建議閱讀原著。

從 0 開始帶你成為JVM實戰高手

極客時間:Java性能調優實戰