在公司定位故障問題的時候,一般我們會採用在代碼中關鍵代碼中打印日誌,然後採用在環境容器內換 Jar 包的形式進行問題定位分析。但是這樣定位的問題流程很麻煩:
- 首先你要確保你打印日誌的全面性,萬一某個關鍵信息沒有打印出來你就需要重新打印、換包、重啟服務,一套流程下來浪費很多時間;
- 其次不是所有環境都運行換包和重啟服務
所以最近我一直在找更好的故障問題定位方法,然後我發現阿里開源的 Java 服務診斷工具好像還不錯,它可以查看方法調用入參、返回值,被調用的調用路徑、調用耗時、方法調用次數、成功次數、失敗次數等這些都可以記錄,所以學習記錄一下這個工具。
什麼是 arthas#
官方介紹:
Arthas 是一款線上監控診斷產品,通過全局視角實時查看應用 load、內存、gc、線程的狀態信息,並能在不修改應用代碼的情況下,對業務問題進行診斷,包括查看方法調用的出入參、異常,監測方法執行耗時,類加載信息等,大大提升線上問題排查效率。
運行環境#
- 只支持 JDK 6 + 的環境
- 由 Java 編寫的,支持跨平台:支持 Linux(主要)、Mac、Windows
特性#
- 採用命令行交互模式
- 提供
Tab
鍵自動補全的功能
初步使用#
因為平時公司使用的環境主要是在容器中,所以以下就主要記錄在 Linux 環境下如何使用這個工具
下載使用包#
由於公司環境是內網環境,不支持直接訪問連接 Github 進行安裝包的下載,這裡防止機器的網絡問題無法下載,所以採用的是手動先從 Github 下載拷貝到服務容器內部的方式進行使用
在 Github 中下載完整的安裝包,下載地址 :https://github.com/alibaba/arthas/releases
容器環境下解壓#
# 創建一個專屬於 arthas 的目錄,因為解壓後會產生很多文件
mkdir arthas
# 解壓到剛才創建好的目錄 arthas
unzip -d arthas arthas-bin.zip
卸載#
定位完問題之後也要打掃好戰場,那卸載這個工具的方法也記錄一下
執行完以下三步即可卸載工具
rm -rf arthas
rm -rf ~/.arthas/
rm -rf ~/logs
運行#
首先啟動一個不會停止的 Java 程序服務,官方的安裝包下就附帶了一個給我們練手的 Jar 包:
math-game.jar
(不過一般我們的服務也是一直運行的,這裡就使用官方的包作為記錄)
# 啟動這個 Java 程序,有自己的服務的可以跳過這一步
java -jar math-game.jar
然後再啟動 arthas
# 1、啟動
java -jar arthas-boot.jar
# 2、選擇你要 attach 的 Java 服務, 輸入進程號然後回車(這裡只有一個進程,就是進程 1)
1
# 看到 arthas 標誌就代表 arthas attach 上這個進程 1 服務
常用命令#
help#
# 輸入 help 可以獲取到Arthas相關命令幫助信息。
[arthas@421554]$ help
NAME DESCRIPTION
help Display Arthas Help
auth Authenticates the current session
keymap Display all the available keymap for the specified connection.
sc Search all the classes loaded by JVM
sm Search the method of classes loaded by JVM
classloader Show classloader info
jad Decompile class
getstatic Show the static field of a class
monitor Monitor method execution statistics, e.g. total/success/failure count, average rt, fail rate, etc.
stack Display the stack trace for the specified class and method
thread Display thread info, thread stack
trace Trace the execution time of specified method invocation.
watch Display the input/output parameter, return object, and thrown exception of specified method invocation
tt Time Tunnel
jvm Display the target JVM information
memory Display jvm memory info.
perfcounter Display the perf counter information.
ognl Execute ognl expression.
mc Memory compiler, compiles java files into bytecode and class files in memory.
redefine Redefine classes. @see Instrumentation#redefineClasses(ClassDefinition...)
retransform Retransform classes. @see Instrumentation#retransformClasses(Class...)
dashboard Overview of target jvm's thread, memory, gc, vm, tomcat info.
dump Dump class byte array from JVM
heapdump Heap dump
options View and change various Arthas options
cls Clear the screen
reset Reset all the enhanced classes
version Display Arthas version
session Display current session information
sysprop Display and change the system properties.
sysenv Display the system env.
vmoption Display, and update the vm diagnostic options.
logger Print logger info, and update the logger level
history Display command history
cat Concatenate and print files
base64 Encode and decode using Base64 representation
echo write arguments to the standard output
pwd Return working directory name
mbean Display the mbean information
grep grep command for pipes.
tee tee command for pipes.
profiler Async Profiler. https://github.com/jvm-profiling-tools/async-profiler
vmtool jvm tool
stop Stop/Shutdown Arthas server and exit the console.
jfr Java Flight Recorder Command
dashboard#
儀表板:顯示當前系統的實時數據面板,平時沒有這個 dashboard 的時候我們一般只能通過 Linux 自帶的
top
命令查看系統運行的信息
輸入 dashboard,按 回車/enter
,會展示當前進程的信息,按 ctrl+c
或輸入 q
可以中斷執行。
顯示的信息大概分為 3 大塊:
- 最上面的是線程相關信息
- 中間區域是 JVM 內存相關的信息
- 最下面的是 Java 的運行環境信息
具體每一列的信息可以參考官方文檔
thread#
查看當前線程信息堆棧
當沒有參數時,顯示第一页線程的信息#
thread
默認按照 CPU 增量時間降序排列,只顯示第一页數據。
支持一鍵展示當前最忙的前 N 個線程並打印堆棧#
thread -n N
thread --all, 顯示所有匹配的線程#
# 顯示所有匹配線程信息,有時需要獲取全部 JVM 的線程數據進行分析。
thread --all
thread id, 顯示指定線程的運行堆棧#
[arthas@421554]$ thread 1
"main" Id=1 TIMED_WAITING
at java.lang.Thread.sleep(Native Method)
at java.lang.Thread.sleep(Thread.java:342)
at java.util.concurrent.TimeUnit.sleep(TimeUnit.java:386)
at demo.MathGame.main(MathGame.java:17)
thread -b, 找出當前阻塞其他線程的線程#
thread -b
watch#
觀察指定方法的調用情況
可以觀察到:
方法返回值、入參、方法拋出的異常,還可以通過編寫 OGNL 表達式進行對應變量的查看
觀察函數調用返回時的參數、this 對象和返回值#
# 觀察維度的默認值是{params, target, returnObj},下面觀察的是函數調用返回時的參數、this 對象和返回值,-x 代表的是輸出結果屬性的遍歷深度,即子對象的深度,深度最大值為 4
[arthas@421554]$ watch demo.MathGame primeFactors -x 2
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 28 ms, listenerId: 2
method=demo.MathGame.primeFactors location=AtExit
ts=2023-05-10 00:25:42; [cost=0.106133ms] result=@ArrayList[
@Object[][
@Integer[1],
],
@MathGame[
random=@Random[java.util.Random@254989ff],
illegalArgumentCount=@Integer[85442],
],
@ArrayList[
@Integer[103],
@Integer[1667],
],
]
# 將深度改為 3
[arthas@421554]$ watch demo.MathGame primeFactors -x 3
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 26 ms, listenerId: 3
method=demo.MathGame.primeFactors location=AtExit
ts=2023-05-10 00:26:17; [cost=0.34344ms] result=@ArrayList[
@Object[][
@Integer[1],
],
@MathGame[
random=@Random[
serialVersionUID=@Long[3905348978240129619],
seed=@AtomicLong[97774455668942],
multiplier=@Long[25214903917],
addend=@Long[11],
mask=@Long[281474976710655],
DOUBLE_UNIT=@Double[1.1102230246251565E-16],
BadBound=@String[bound must be positive],
BadRange=@String[bound must be greater than origin],
BadSize=@String[size must be non-negative],
seedUniquifier=@AtomicLong[-3282039941672302964],
nextNextGaussian=@Double[0.0],
haveNextNextGaussian=@Boolean[false],
serialPersistentFields=@ObjectStreamField[][isEmpty=false;size=3],
unsafe=@Unsafe[sun.misc.Unsafe@5d099f62],
seedOffset=@Long[24],
],
illegalArgumentCount=@Integer[85459],
],
@ArrayList[
@Integer[7],
@Integer[21313],
],
]
同時觀察函數調用前和函數返回後#
[arthas@421554]$ watch demo.MathGame primeFactors "{params,target,returnObj}" -x 2 -b -s
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 39 ms, listenerId: 6
method=demo.MathGame.primeFactors location=AtEnter
ts=2023-05-10 00:30:00; [cost=0.036373ms] result=@ArrayList[
@Object[][
@Integer[163405],
],
@MathGame[
random=@Random[java.util.Random@254989ff],
illegalArgumentCount=@Integer[85576],
],
null,
]
method=demo.MathGame.primeFactors location=AtExit
ts=2023-05-10 00:30:00; [cost=1.4721136326180643E10ms] result=@ArrayList[
@Object[][
@Integer[1],
],
@MathGame[
random=@Random[java.util.Random@254989ff],
illegalArgumentCount=@Integer[85576],
],
@ArrayList[
@Integer[5],
@Integer[11],
@Integer[2971],
],
]
觀察當前對象中的屬性#
如果想查看函數運行前後,當前對象中的屬性,可以使用 target 關鍵字,target 代表當前對象,然後使用 target.field_name 訪問當前對象的某個屬性
[arthas@421554]$ watch demo.MathGame primeFactors 'target.illegalArgumentCount'
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 31 ms, listenerId: 7
method=demo.MathGame.primeFactors location=AtExit
ts=2023-05-10 00:33:50; [cost=0.081212ms] result=@Integer[85676]
method=demo.MathGame.primeFactors location=AtExceptionExit
ts=2023-05-10 00:33:51; [cost=0.102672ms] result=@Integer[85677]
trace#
方法內部調用路徑,並輸出路徑上的每個節點上耗時,服務間調用時間過長時使用
[arthas@421554]$ trace demo.MathGame run
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 55 ms, listenerId: 9
`---ts=2023-05-11 00:24:38;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@74a14482
`---[0.54719ms] demo.MathGame:run()
+---[20.76% 0.113574ms ] demo.MathGame:primeFactors() #24
`---[53.28% 0.29155ms ] demo.MathGame:print() #25
- 輸出結果中 #24 表示 在源文件的第 24 行調用了
primeFactors()
函數 - 輸出結果中 #25 表示 在源文件的第 25 行調用了
print()
函數
stack#
輸出當前方法被調用的調用路徑,當我們需要知道這個方法(被很多地方調用過)從那裡開始執行了就可以使用這個命令(適合尋根溯源)
arthas@421554]$ stack demo.MathGame primeFactors
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 38 ms, listenerId: 12
ts=2023-05-11 00:32:43;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@74a14482
@demo.MathGame.primeFactors()
at demo.MathGame.run(MathGame.java:24)
at demo.MathGame.main(MathGame.java:16)
jad#
反編譯指定已加載類的源碼,便於在線上理解業務邏輯,反編譯出來的代碼是帶語法高亮的
jad demo.MathGame