分析代碼運行過程中的性能
相信有一定基礎的小伙伴們對CPU于內存的速度差異、內存與磁盤的速度差異以及磁盤的順序寫和隨機寫速度差異有一定的了解。
了解一些計算機硬件的速度差異,再結合一些代碼的性能分析工具,可以更好的分析代碼的運行時性能,包括操作系統性能數據、JVM 的性能數據、應用的性能數據等。
一、計算機硬件速度差異
1.1 CPU與內存的速度差異
- CPU比內存快多少:CPU的處理速度通常比內存快很多。CPU的時鐘頻率可以達到3-5 GHz(即每秒數十億次的操作),而內存(DRAM)的帶寬大約為幾十GB/s(例如DDR4的帶寬大約是25-30 GB/s)。理論上,CPU每個時鐘周期能完成的操作比內存大得多,因此CPU對內存的訪問時間比內存的讀寫速度慢得多。
- 大致估算:CPU的處理速度比內存快100到1000倍。換句話說,CPU需要等待內存的數據大約是其自身處理速度的數百倍。
1.2 內存與磁盤的速度差異
- 內存比磁盤快多少:內存的訪問速度通常比硬盤快得多。現代的內存(DRAM)可以在毫微秒級別(ns)內完成訪問,而傳統硬盤(HDD)需要等待毫秒級別的響應時間。
- 內存與磁盤速度比:內存的讀取速度通常比磁盤快幾千到幾萬倍。例如,內存的讀取時間可能為幾十納秒(ns),而HDD則可能是幾毫秒(ms)。現代的固態硬盤(SSD)比傳統的HDD要快,但即使是SSD,其速度仍然比內存慢得多,可能只有幾十倍到幾百倍。
1.3 磁盤的順序寫和隨機寫速度
- 順序寫(Sequential Write):順序寫是指數據按順序連續寫入磁盤,這樣磁頭移動的距離較小,通常可以實現最快的寫入速度。SSD的順序寫速度通常可以達到幾GB/s(例如,現代NVMe SSD的順序寫速度可達到3-7GB/s,甚至更高)。而HDD的順序寫速度一般在100-150 MB/s之間。
- 隨機寫(Random Write):隨機寫是指數據以隨機方式分布,磁頭需要不斷移動到不同位置,導致速度下降。SSD的隨機寫速度通常要比順序寫慢一些,但仍比HDD快很多。現代SSD的隨機寫速度可能在幾百MB/s到幾GB/s之間,而傳統HDD的隨機寫速度可能只有幾十MB/s。
- 順序寫與隨機寫速度比
- 對于SSD,順序寫速度通常比隨機寫速度快大約1.5到3倍(視具體設備而定)。
- 對于HDD,順序寫比隨機寫要快3到5倍左右。
了解完計算機硬件的速度差異后,接下來,我們重點介紹如何獲取代碼的運行時性能數據。
二、通過nmon獲取性能數據
nmon是一個經典的Linux性能監控工具,可以通過nmon工具獲取詳細的監控報告。
2.1 安裝nmon
以CentOS7為例,可以在命令行輸入如下命令安裝nmon。
yum install epel-release -y
yum install nmon -y
nmon -v
也可以直接從nmon官方站點:https://nmon.sourceforge.io/pmwiki.php 下載二進制文件,賦予其執行權限即可。
chmod +x nmon_x86_64_linux
./nmon_x86_64_linux
如果安裝成功,輸入nmon -v
或者 ./nmon_x86_64_linux
后,會輸出如下所示的信息。
[root@localhost ~]# nmon -v
nmon: invalid option -- 'v'
Hint for nmon version 16g
Full Help Info : nmon -h
On-screen Stats: nmon
Data Collection: nmon -f [-s <seconds>] [-c <count>] [-t|-T]
Capacity Plan : nmon -x
Interactive-Mode:
Read the Welcome screen & at any time type: "h"for more help
Type "q" to exit nmon
For Data-Collect-Mode
-f Must be the first option on the line (switches off interactive mode)
Saves data to a CSV Spreadsheet format .nmon file inthenlocal directory
Note: -f sets a defaults -s300 -c288 which you can then modify
Further Data Collection Options:
-s <seconds> time between data snapshots
-c <count> of snapshots before exiting
-t Includes Top Processes stats (-T also collects command arguments)
-x Capacity Planning=15 min snapshots for 1 day. (nmon -ft -s 900 -c 96)
---- End of Hints
2.2 運行 nmon
在命令行運行輸入nmon
命令運行nmon,如下所示。
圖片
進入nmon的運行面板后,可以按對應的快捷鍵監控指定的硬件資源,例如:
- CPU:按
c
- 內存:按
m
- 內核 :按
k
- 磁盤 I/O:按
d
- 網絡:按
n
- 進程:按
p
- 退出:按
q
例如,按 d
監控磁盤的性能數據,如下所示。
圖片
通過如下命令,可以采集服務器數據。
nmon -f -s 5 -c 12 -m .
此命令表示每 5 秒采集一次數據,共采集 12 次。執行此命令后,可以通過ps- ef | grep nmon
命令查看運行的進程。
圖片
nmon會把這一段時間之內的數據記錄下來。比如這次生成的文件為localhost_250616_0848.nmon。
圖片
隨后,可以通過nmonchart工具將nmon文件轉換成html文件。首先安裝nmonchart,如下所示。
wget https://sourceforge.net/projects/nmon/files/nmonchart43.tar
tar xvf nmonchart43.tar
隨后,可以通過如下命令將nmon文件轉換成html文件。
./nmonchart localhost_250616_0848.nmon localhost_250616_0848.html
文件轉換成功,會多出一個localhost_250616_0848.html文件,如下所示。
圖片
注意:如果在轉換文件時報如下錯誤。
/usr/bin/env: ksh: No such file or directory
則需要輸入如下命令安裝ksh。
yum install ksh -y
將生成的localhost_250616_0848.html文件下載到本地,使用瀏覽器打開,如下所示。
圖片
隨后,就可以點擊菜單欄來查看具體的監控指標了。
三、通過jvisualvm獲取JVM性能數據
相信不少小伙伴都知道,jvisualvm是獲取JVM性能數據的一款工具,在JDK1.8之前,會集成到JDK中,在JDK9之后,會單獨進行發布。,并且jvisualvm也提供了大量的插件。
3.1 安裝jvisualvm
大家可以到鏈接:https://visualvm.github.io下載jvisualvm,下載完畢后打開界面如下所示。
圖片
也可以在jvisualvm中更新自己想要安裝的插件,點擊Tools—>Plugins—>Available Plugins即可看到在jvisualvm中可以更新插件。
圖片
3.2 監控數據
如果想通過jvisualvm監控遠程應用,則可以在應用上保留對應的JMX端口,具體做法就是在啟動應用時,添加如下JVM參數。
-Dcom.sun.management.jmxremote.port=11000
-Dcom.sun.management.jmxremote.authenticate=false
-Dcom.sun.management.jmxremote.ssl=false
此時,應用對外保留的JMX端口為11000,并且不需要認證。
在jvisualvm中分析性能數據,主要使用的是抽樣器(Sampler),如下所示。
圖片
除此之外,也要關注如下一些指標。
- CPU分析:統計方法的執行次數和執行耗時,分析哪些方法執行時間過長,可能成為熱點等。
- 內存分析:可以通過內存監視和內存快照等方式進行分析,進而檢測內存泄漏問題,優化內存使用情況。
- 線程分析:可以查看線程的狀態變化,以及一些死鎖情況。
四、通過JMC獲取詳細性能數據
JMC的全稱是JDK Misson controll,是一款分析Java應用詳細性能數據的強大工具,也是一個圖形化的界面監控工具,監控信息非常全面,JMC打開性能日志后,主要包括一般信息、內存、代碼、線程、I/O、系統、事件等功能。
4.1 安裝JMC
打開鏈接:https://www.oracle.com/java/technologies/jdk-mission-control.html 下載JMC,找到自己需要的版本后進行下載。下載后,解壓即可使用。
4.2 目標JVM配置
需要在被監控的JVM上開啟如下配置才能進行監控。
-Dcom.sun.management.jmxremote.authenticate=false
-Dcom.sun.management.jmxremote.ssl=false
-Dcom.sun.management.jmxremote.port=7777
-Dcom.sun.management.jmxremote
-XX:+UnlockCommercialFeatures
-XX:+FlightRecorder
如果要在目標JVM上啟動持續不斷的監控記錄,并在JVM正常退出時Dump記錄為文件,可以參考下面的腳本設置JVM參數
for /f "tokens=1-3 delims=/ " %%a in ('date /t') do (set md=%%a-%%b-%%c)
for /f "tokens=1-3 delims=/:." %%a in ("%TIME%") do (set mt=%%a%%b%%c)
set CUR_TIME=%md%-%mt%
rem 啟用黑匣子默認記錄行為。官方文檔注明dumponexitpath支持目錄,但我在7u71版本下測試失敗
set JAVA_OPTS=%JAVA_OPTS% -XX:FlightRecorderOptinotallow=defaultrecording=true,disk=true,dumpnotallow=true,dumpnotallow=%LOG_DIR%\jfr\dump-on-exit-%CUR_TIME%.jfr,maxage=3600s,settings=%JRE_HOME%\lib\jfr\profile.jfc
4.3 連接目標JVM
配置并重啟目標JVM后,打開JMC,點擊 File - Connect... - Create New connection,參考下圖設置,完畢后點擊Test connection確認可以連通,最后點擊Finish結束配置。
圖片
4.4 MBean Server
在左側窗格JVM Browser視圖中,雙擊剛剛創建的JMC連接,點擊MBean Server,即可在右側主窗體查看實時的JVM狀態信息,供6個選項卡,下面依次描述。
4.4.1 總覽
包含JVM概要性的實時圖表,包含3個面板:
面板 | 說明 |
儀表盤(Dashboard) | 以儀表方式顯示系統運行參數,默認顯示堆內存占用、JVM處理器占用、垃圾回收前后的堆內存情況。注意儀表上有有兩個指針,灰色的通常顯示最大值,黑色的顯示當前值。 面板右側的+號按鈕,點擊后可以添加目標JVM支持的任何運行參數到儀表盤中 |
處理器(Processor) | 顯示JVM、操作系統的動態CPU占用曲線 |
內存(Memory) | 默認顯示Java堆內存占用情況,可以選擇查看物理內存占用等項目 |
4.4.2 MBean瀏覽器
以樹形結構顯示目標JVM支持的所有MBean列表和屬性、操作集。
4.4.3 觸發器
包含若干預定義的觸發器,可以在特定條件下,執行預定義的動作。支持的觸發器包括:
觸發器 | 說明 |
CPU Usage - JVM Process (Too High) | 當JVM的進程的CPU占用過高時 |
CPU Usage - JVM Process (Too Low) | 當JVM的進程的CPU占用過低時 |
CPU Usage - Machine (Too High) | 當OS的CPU占用過高時 |
CPU Usage - Machine (Too Low) | 當OS的CPU占用過低時 |
Deadlocked Threads | 當發生JVM線程死鎖時 |
Live Set (Too Large) | 當垃圾回收之后,存活對象占堆大小百分比過大時 |
Thread Count (Too High) | 當JVM線程總數過大時 |
此外,任何MBean屬性均可以作為觸發器使用,中間件(例如Tomcat、Weblogic、ActiveMQ)都有自己的擴展。 雙擊觸發器后,右側即顯示規則詳情(Rule Details),可以定義觸發的閾值(到達時,或者從異常值恢復時)、執行的動作,可用的動作包括:
動作 | 說明 |
Application alert | 在應用程序上顯示一個警告對話框 |
Console output | 在控制臺(stdout)上輸出警告信息 |
Dump Flight Recording | 保存黑匣子記錄內容 |
HPROF Dump | 保存堆鏡像 |
Log to file | 在日志文件中輸出警告信息 |
Send e-mail | 通過電子郵件發送警告信息 |
Start Continuous Flight Recording | 啟動不間斷的黑匣子記錄 |
Start Time Limited Flight Recording | 啟動限制時間長度的黑匣子記錄 |
4.4.4 LiveSet
所謂LiveSet,是指在一次垃圾回收之后,堆內存的占用比率,取值在0-1之間。
如果GC后,可用的內存空間不足,則LiveSet接近100%,這預示可能存在OOM風險。在生產環境下,我們可以監控LiveSet,并在其過大時,把堆內存映像Dump出來供后續分析。
觸發器配置示例:
圖片
圖片
其中Condition面板:
- Current Value為指標的當前值,當發生GC后,自動刷新
- Max trigger value為觸發器激活時的指標值
- Sustained period,指標必須到達Max trigger value至少多長時間,觸發器才可能激活
- Limit period,連續兩次激活觸發器的最小間隔時間
其中Action面板:
- Only live,如果勾選,僅僅GCRoot可達的對象才被Dump出來
- hprof路徑為服務器的路徑
其中Constraints面板:可以指定此觸發器在什么日期、什么時間段啟用。
要分析內存映像,你可以使用如下命令啟動一個Web UI:
jhat -port 7770 -J-Xmx4G default.hprof
4.4.5 系統
顯示JVM和系統的概要信息,包含3個面板:
- 系統信息:例如OS類型、硬件架構、系統內存、JVM的PID、JVM版本、Classpath、JVM啟動時間、JVM參數(Java Options)
- JVM統計:例如已加載的類數量、已運行時間
- 系統屬性:顯示JVM的系統屬性
4.4.6 內存
顯示JVM內存占用情況,分為上下兩個面板。
面板 | 說明 |
GC Table | 顯示垃圾回收器(ParNew:新生代的并行回收器,ConcurrentMarkSweep:并發垃圾回收器…)的工作情況,包括:GC總計時間、GC總次數、最近GC開始結束時間、GC標識符、GC線程數 |
Active Memory Pools | 顯示當前的內存池的大小、已用大小、類型(堆/非堆),可能有以下內存池: Code Cache:代碼緩存 Par Eden Space:并行(-XX:+UseParNewGC)垃圾回收的新生代Eden區 Par Survivor Space:并行垃圾回收的新生代Survivor區 CMS Perm Gen:并發垃圾回收永久代 CMS Old Gen:并發垃圾收集年老代 PS Old Gen:并行(-XX:+UseParallelGC)垃圾收集年老代 關于垃圾回收器內存分代。 |
4.4.7 線程
顯示JVM線程活動情況,分為三個面板。
面板 | 說明 |
Live Thread Graph | 顯示當前存活線程的數量、守護線程的數量、線程數量峰值的實時曲線 |
Live Threads | 顯示當前存活線程的列表,可以進行CPU占用分析、死鎖檢測、線程分配內存量的分析 |
Stack traces for selected threads | 顯示瞬時的線程調用棧 |
4.5 啟動JMC
JMC可以用于事后分析系統性能低下,甚至崩潰的原因。JMC支持兩種方式來啟動黑匣子記錄:通過觸發器自動啟動, 或者在左側面板,雙擊Flight Recorder,手工啟動。手工啟動可以參考下圖設置:
圖片
其中:Time fixed recording表示記錄定長時間,時間到達后,自動停止記錄;Continuous recording表示進行持續不斷的記錄,直到JVM退出或者接收到停止指令,這種記錄方式下可以隨時進行dump操作。
雖然黑匣子在JVM本地記錄數據,但不在Java堆中記錄,因此它并不會影響內存特性和垃圾收集。
黑匣子錄制完成后,會在你選擇的目錄中生成一個.jfr文件,該文件包含錄制期間JVM中發生的各種事件。
4.5.1 工作機制
黑匣子通過JVM內部API來收集數據,并存放在一個線程本地(thread-local)的緩沖中,并最終刷入全局內存緩沖(global in-memory buffer),內存緩沖中的數據,會被刷入磁盤,磁盤文件時經過壓縮的。
每個記錄數據塊,要么在內存中,要么在磁盤中,這意味著——進程被停止或者宕機時,部分數據會丟失,JVM崩潰會也可能導致一部分數據丟失。
可以配置黑匣子不使用磁盤空間,這種場景下,全局內存緩沖被循環使用,舊的數據自動丟棄。
4.5.2 黑匣子記錄模板
在JMC界面上,點擊 Windows - Flight Recording Template Manager,看到類似如下界面。可以導入、導出、編輯JFR的設置文件。
圖片
我們可以導入%JDK_HOME%\jre\lib\jfr下的兩個自帶模板:default.jfc(Continuous)、profile.jfc(Profiling)。這兩個模板的對比如下:
模板 | 特性 |
Continuous | Garbage Collector:正常 Compiler:正常 Method Sampling: 正常 Thread Dump: 最少一次 Exceptions:僅Error Synchronization Threshold: 20 ms File I/O Threshold: 20 ms Socket I/O Threshold: 20 ms Heap Statistics: 禁用 Class Loading:禁用 Allocation Profiling:禁用 未啟用記錄的事件類型:Exception Throw、Object Alloc In New TLAB、Object Alloc Outside TLAB、Class Loading、Compile/Failure、GC/Object Count、GC/Object Count After GC、GC/Phases/Phase Level 3、Profiling/Execution Sample Info、 |
Profiling | Garbage Collector:正常 Compiler:詳細 Method Sampling: 最大化 Thread Dump: 每分鐘 Exceptions:僅Error Synchronization Threshold: 10 ms File I/O Threshold: 10 ms Socket I/O Threshold: 10 ms Heap Statistics: 禁用 Class Loading:禁用 Allocation Profiling:啟用 未啟用記錄的事件類型:Exception Throw、Class Loading、GC/Object Count、GC/Object Count After GC、GC/Phases/Phase Level 3、Profiling/Execution Sample Info、 |
4.7 黑匣子診斷命令
利用診斷命令,可以通過腳本控制黑匣子的行為,命令的示例如下:
rem 獲取進程號為5361的JVM關于JFR.start命令的幫助
jcmd 5361 help JFR.start
rem 檢查進程的JFR運行狀態
jcmd 7648 JFR.check
rem 輸出如下。注意recording=0表示正在運行的記錄的標識符,后續操作需要用到這個標識符
rem 7648:
rem Recording: recording=0 name="HotSpot default" maxage=1h (running)
rem 啟動一個15分鐘的黑匣子記錄,延遲5分鐘啟動,使用JDK自帶的默認設置(default.jfc),保存Dump文件到D盤
jcmd 7648 JFR.start name=SampleRcd delay=300 duratinotallow=900s filename=D:\temp\SampleRcd.jfr
\ settings=D:\JavaEE\jdk\x64\jre\lib\jfr\default.jfc
rem 相對路徑取決于目標JVM
jcmd 1234 JFR.start delay=0s duratinotallow=${jfr_du}s name=$name filename=$PWD/$name.jfr settings=profile
rem 下面的腳本,可以用于定期進行記錄,按記錄時間保存為不同的文件
setlocal
set DUMP_DIR=D:\temp
set SERVICE_NAME=Tomcat7
set JAVA_HOME=D:\JavaEE\jdk\x64\1.7
pushd %JAVA_HOME%\bin
for /f "tokens=1-3 delims=/ " %%a in ('date /t') do (set md=%%a-%%b-%%c)
for /f "tokens=1-3 delims=/:." %%a in ("%TIME%") do (set mt=%%a%%b%%c)
set CUR_TIME=%md%-%mt%
for /F "tokens=1,3" %%a in ('sc queryex %SERVICE_NAME%') do (
if"%%a" == "PID"set"JPID=%%b"
)
rem 啟動飛行記錄,如果目標JVM是以SYSTEM身份啟動的NT Service,可以使用PSTools發起jcmd命令,否則會報錯:insufficient memory or insufficient privileges to attach
rem psexec -s jcmd %JPID% JFR.start ...
jcmd %JPID% JFR.start name=rcd-%CUR_TIME% duratinotallow=900s compress=true filename=%DUMP_DIR%\rcd-%CUR_TIME%.jfr settings=%JAVA_HOME%\jre\lib\jfr\profile.jfc
popd
endlocal
rem 導出JFR的Dump文件
rem 如果目標JVM正在在運行持續不斷的黑匣子記錄,使用該命令,再結合定時任務機制,可以定期保存黑匣子記錄的Dump文件
jcmd 7648 JFR.dump recording=0 filename=F:\temp\dump.jfr
4.7.1 命令列表
命令 | 說明 |
JFR.start | 啟動一個JFR(黑匣子記錄)實例,參數: name 本次記錄的名稱 settings 服務器上的設置模板 defaultrecording 是否啟動默認錄制 delay 錄制延遲時間,默認0s duration 錄制持續時間,默認0s,表示無限 filename 錄制文件的名稱 compress 是否使用GZip壓縮結果,默認否 maxage 數據最大生命周期,默認0s,表示無限制 maxsize 數據最大字節數,默認0,表示無限制 |
JFR.check | 顯示運行中的JFR的狀態,參數: name 記錄名稱 recording 記錄標識符 verbose 打印冗余信息,默認否 |
JFR.stop | 停止運行中的JFR,參數: name 記錄名稱 recording 記錄標識符 discard 是否丟棄錄制數據 filename 拷貝錄制數據到文件 |
JFR.dump | 將錄制中的JFR保存到文件,參數: name 記錄名稱 recording 記錄標識符 filename 拷貝錄制數據到文件 |
4.8 黑匣子分析
打開黑匣子記錄的.jfr文件,即可看到類似下面的界面:左側是記錄的不同視圖,可以點擊切換;右側主面板,頂部是事件的時間軸,拖動滑塊,可以改變聚焦的時間范圍(勾選右邊的同步選擇可以在切換視圖時保持聚集范圍),底部有若干選項卡。
4.8.1 基本信息
包含4個選項卡:
總覽
可以看到聚焦時間范圍內的實時儀表(堆占用、CPU占用、GC停頓時間),以及CPU、堆使用情況的曲線圖。
JVM信息
可以看到JVM的一些基本信息,包括啟動時間、JVM參數等。
系統屬性
可以看到JVM的系統屬性列表
記錄
可以顯示記錄的事件的列表
內存
包含6個選項卡
總覽
Memory Usage:可以顯示聚焦時間范圍內OS總內存、OS已使用內存、提交的堆、使用的堆的大小曲線圖。
GC Configuration:顯示簡單的GC配置
GC Statistics:顯示簡單的GC統計,包括垃圾回收次數、停頓時間
垃圾收集
上面的面板,包含4個選項卡:
Heap:堆的使用情況曲線,紅色小柱形顯示了GC停頓的持續時間(刻度在右邊)
Reference Objects:包含軟引用、弱引用、幻引用、一般引用的數量變化區域圖
Failed Promotions:失敗的晉升列表,所謂晉升是指:年輕代對象向年老代轉移的GC動作,包含對象個數和大小等信息
Failed Evacuations:
下面的面板,左側顯示歷次GC的列表,右側顯示單次GC的詳細信息,如下:
General:顯示GC類型、觸發原因、ID、開始結束時間、暫停時間
GC Phase:GC每個步驟的開始和持續時間
Reference Objects:本次GC涉及的各類引用的數量
Heap:堆在GC前后的大小對比
Perm Gen:永久代在GC前后的大小對比
垃圾回收時間
顯示各代、各次GC所消耗的時間
垃圾回收配置
顯示GC的詳細配置,包括GC基本配置、堆的配置、年輕代的配置
內存分配
顯示聚焦時間范圍內的內存分配統計信息
General:在線程本地分配緩沖(TLAB)內、外(即Eden區域)中分配的對象個數、內存大小。面板下部是內存分配大小按時間的柱形圖
Allocation in new TLAB:在TLAB中分配的內存,按對象類型、或者按執行分配的線程的占比餅圖;Allocation Profile可以剖析分配內存熱點所在的調用棧
Allocation outside TLAB:在Eden區域的內存分配情況,包含的子選項卡同上
示例:
圖片
在Allocation By Class選項卡中:
- 上面板Allocation Pressure,按對象類型,顯示內存占用最大的對象
- 下面板Stack Trace,選中上面板的某個對象類型后,在此顯示分配對象的調用棧。第一行為直接分配對象的代碼
4.8.2 對象統計
顯示對象數量和內存占用的統計信息,包含上下兩部分
上面的面板:顯示占有堆內存百分比大于0.5%的類型的列表
下面的面板:顯示增長數量最快的類型的列表
4.9 代碼
包含6個選項卡:
4.9.1 總覽
顯示占用CPU時間最多的代碼,分為上下兩部分
上面的面板:顯示CPU時間占用最多的包,包括列表和餅圖
下面的面板:顯示CPU占用最多的類,按占比降序排列
4.9.2 熱點方法
顯示熱點方法(CPU占用時間最多),按占比降序排列,點擊左側小箭頭可以向下鉆取(找到哪些代碼調用了這個方法導致的熱點)
4.9.3 調用樹
類似于熱點方法選項卡,但是會顯示所有熱點方法的完整調用棧
4.9.4 異常
包含3個選項卡,顯示異常(包括錯誤)的統計信息
Overview:顯示異常和錯誤的總數、最頻繁發生異常的調用棧
Exceptions、Error:單獨顯示異常或者錯誤的總數、頻繁調用棧,注意,異常默認是不記錄的
4.9.5 編譯
顯示即時編譯的次數、編譯大小、失敗的日志
4.9.6 類加載
顯示按時間的類加載、卸載的數量曲線圖
4.10 線程
4.10.1 總覽
分為上下兩部分:
上面的面板:顯示OS、JVM的CPU占用率的按時間統計的區域圖
下面的面板:顯示守護線程、活動線程數量的曲線圖
4.10.2 熱點線程
顯示CPU占用最多的線程,及選中線程的熱點方法,分為上下兩部分
上面的面板:顯示CPU占用最多的線程,按占比降序排列
下面的面板:顯示上面板選中線程的熱點方法、調用棧
4.10.3 資源爭用
顯示因為鎖爭用導致的線程阻塞的統計信息,分為3個選項卡:
Top Blocking Locks:發生阻塞最多的監視器(鎖)對象的列表,包含了鎖定次數、最長時間
Top Blocked Threads:因為等待鎖被阻塞時間最長的線程的列表
Top Blocking Threads:因為占用鎖導致其他線程等待時間最長的線程的列表
4.10.4 延遲
顯示因為:Java線程休眠、監視器等待、Socket讀取、監視器阻塞等原因導致的線程執行延遲的情況,包括延遲信息的列表和餅圖,已經導致延遲的線程調用棧。延遲相關的事件包括:Java Thread Park(Waiting)、Java Monitor Wait(等待被喚醒)、Java Monitor Blocked(積極進入同步區被阻塞)等。
4.10.5 線程棧Dump
包含定時捕獲的JVM中所有線程的瞬時調用棧鏡像
4.10.6 監視器實例
Lock Instances:監視器對象的列表,包含鎖定次數、總計持續時間
Trace Tree:選中監視器對象的鎖定調用棧,每個調用棧鎖定的次數
Top Threads:占用監視器次數最多的線程列表
4.11 輸入輸出
4.11.1 總覽
分為兩個選項卡
File Overview:
File Reads and Writes:顯示按時間讀寫文件字節數的曲線
File Read、File Write:顯示針對具體文件的讀寫字節數、次數的列表
Socket Overview:
Socket Read and Writes:顯示按時間讀寫Socket字節數的曲線
Socket Read、Socket Writes:顯示針對具體目標主機、端口讀寫字節數、次數的列表
4.11.2 讀文件
按文件、線程、事件統計文件讀操作的列表,以及每個文件讀取按時間的變化、線程調用棧
4.11.3 寫文件
按文件、線程、事件統計文件寫操作的列表,以及每個文件寫入按時間的變化、線程調用棧
4.11.4 讀Socket
按目標主機、線程、事件統計文Socket讀操作的列表,以及每個Socket讀取按時間的變化、線程調用棧
4.11.5 寫Socket
按目標主機、線程、事件統計文Socket寫操作的列表,以及每個Socket寫入按時間的變化、線程調用棧
4.12 系統
包含操作系統和硬件的基本信息
4.13 事件
顯示黑匣子記錄的事件的相關信息,左側面板Event Types可以過濾關注的事件類型。總體來說,事件可以分為三類:持續事件(duration,持續一段時間,例如GC事件);瞬時事件(instant,立即發生和結束,例如內存溢出);樣本事件(sample,通過定期采樣獲取,例如棧dump)。
4.13.1 總覽
Producers:顯示事件生產者的列表,以及制造事件的占比餅圖
Event Types:顯示各類型事件持續總時間、次數,占比餅圖
4.13.2 日志
顯示每一個事件的記錄,按時間排列,為每個事件顯示:開始時間、結束時間、持續時間、產生事件的線程
4.13.3 圖表
以時間軸的形式展示事件歷史
4.13.4 線程
以列表形式展示各線程產生事件的數量、持續時間
4.13.5 調用棧跟蹤
按產生事件持續時間長短,降序排列相關的調用棧
4.13.6 事件統計
可以按單個事件類型進行簡單的統計分析,支持不同的分組方式,支持總數、平均數、次數等指標,選中單個統計結果,可以顯示調用棧。
五、Arthas獲取調用耗時
Arthas是阿里巴巴開源的一款線上監控診斷產品,通過全局視角實時查看應用 load、內存、gc、線程的狀態信息,并能在不修改應用代碼的情況下,對業務問題進行診斷,包括查看方法調用的出入參、異常,監測方法執行耗時,類加載信息等,大大提升線上問題排查效率。
官網為:https://arthas.aliyun.com
啟動Arthas進入某個運行的Java進程界面如下所示。
圖片
有時在生產環境發現某個接口耗時非常高,但是又無法定位到具體的問題原因,可以使用Arthas的trace命令進行分析,trace命令能主動搜索 class-pattern/
method-pattern對應的方法調用路徑,渲染和統計整個調用鏈路上的所有性能開銷和追蹤調用鏈路。
5.1 trace查看方法整體耗時
基礎語法:trace 全路徑類名 方法名
$ trace demo.MathGame run
Press Q or Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 28 ms.
`---ts=2025-06-16 00:45:08;thread_name=main;id=1;is_daemnotallow=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69
`---[0.617465ms] demo.MathGame:run()
`---[0.078946ms] demo.MathGame:primeFactors() #24 [throws Exception]
`---ts=2025-06-16 00:45:09;thread_name=main;id=1;is_daemnotallow=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69
`---[1.276874ms] demo.MathGame:run()
`---[0.03752ms] demo.MathGame:primeFactors() #24 [throws Exception]
提示結果里的 #24
,表示在 run 函數里,在源文件的第24
行調用了primeFactors()
函數。
5.2 trace次數限制
如果方法調用的次數很多,那么可以用-n
參數指定捕捉結果的次數。比如下面的例子里,捕捉到一次調用就退出命令。
基礎語法:trace 全路徑類名 方法名 -n 次數
$ trace demo.MathGame run -n 1
Press Q or Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 20 ms.
`---ts=2025-06-16 00:45:53;thread_name=main;id=1;is_daemnotallow=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69
`---[0.549379ms] demo.MathGame:run()
+---[0.059839ms] demo.MathGame:primeFactors() #24
`---[0.232887ms] demo.MathGame:print() #25
Command execution times exceed limit: 1, so command will exit. You can set it with -n option.
trace命令的具體用法參見:https://arthas.aliyun.com/doc/trace.html。
Arthas的命令參見:https://arthas.aliyun.com/doc/commands.html。
六、通過wrk獲取接口性能數據
wrk與ab類似,也是一款HTTP壓測命令行工具。可以到鏈接:https://github.com/wg/wrk下載wrk。
6.1 安裝wrk
這里以CentOS為例安裝wrk,如下所示。
sudo yum groupinstall 'Development Tools'
sudo yum install -y openssl-devel git
git clone https://github.com/wg/wrk.git wrk
cd wrk
make
# 將可執行文件移動到 /usr/local/bin 位置
sudo cp wrk /usr/local/bin
6.2 壓測測試接口
假設要對 OpenResty程序的 hello 接口進行壓測,我們可以使用以下命令:
wrk -c 100 -d 30s -t 4 --latency http://121.4.xxx.xx/hello
這條命令表示,利用 wrk 發起壓力測試,連接數為 100,線程數為 4,持續 10 秒,并打印響應時間統計信息。
運行后,我們可以看到以下輸出:
Running 30s test @ http://121.4.xxx.xx/hello
4 threads and 100 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 60.74ms 94.62ms 1.82s 88.81%
Req/Sec 710.91 118.29 1.02k 69.08%
Latency Distribution
50% 26.22ms
75% 32.99ms
90% 176.28ms
99% 475.41ms
84967 requests in 30.02s, 15.40MB read
Socket errors: connect 0, read 0, write 0, timeout 2
Requests/sec: 2829.91
Transfer/sec: 525.08KB
我們可以從輸出中看到以下信息:
- 壓測的配置和目標網址
Running 30s test @ http://121.4.xxx.xx/hello
4 threads and 100 connections
- 每個線程的平均、標準差、最大和正負一個標準差占比的響應時間(Latency)
Latency 60.74ms 94.62ms 1.82s 88.81%
這個數據和 QPS 一樣重要,表示系統的響應速度,這個值越小越好。
- 響應時間的分布情況:即有多少比例的請求在某個時間內完成,延時的分布百分比詳細打印也就是下面展示信息
Latency Distribution
50% 26.22ms
75% 32.99ms
90% 176.28ms
99% 475.41ms
- 總的請求數
Requests/sec: 2829.91
這個數據表示服務端每秒鐘處理了多少請求,這個值越大越好。
七、本章總結
本章,主要給大家簡單介紹了幾款獲取性能數據的工具,包含:nmon、jvisualvm、jmc、arthas、ark等,這里也只是簡單的介紹了一些基本用法,起到拋磚引玉的作用,各個工具的詳細用法,還是要小伙伴們深入學習。
希望本章內容能夠為大家帶來實質性幫助,我們一起搞定性能優化。