JVM程序診斷利器——arthas介紹
文章目錄
Arthas
是Alibaba開源的Java診斷工具,採用命令列互動模式,提供了豐富的功能,是排查jvm相關問題的利器。
在逛github時,發現了這款利器,深入瞭解之後,簡直驚為天人。下面先列舉一下它能做的一些事情:
- 提供效能看板,包括執行緒、cpu、記憶體等資訊,並且會定時的重新整理。
- 根據各種條件檢視執行緒快照。比如找出cpu佔用率最高的n個執行緒等
- 輸出jvm的各種資訊,如gc演算法、jdk版本、ClassPath等
- 檢視/設定sysprop和sysenv
- 檢視某個類的靜態屬性,也可以通過ognl語法執行一些語句
- 檢視已載入的類的詳細資訊,比如這個類從哪個jar包載入的。也可以檢視類的方法的資訊
- dump某個類的位元組碼到指定目錄
- 直接反編譯指定的類
- 檢視類載入器的一些資訊
- 可以讓jvm重新載入某個類
- 監控方法的執行,同時可以獲取到執行的入參、出參以及丟擲的異常
- 追蹤方法執行的呼叫棧,以及各個方法的呼叫時間
下面我會對如何使用這些功能做一個簡單的介紹,也會加上一些自己對這些命令的理解。有一些命令不會介紹的太詳細,因為官方文件已經寫的很棒了,我沒必要再這複述。想深入瞭解的朋友也可以直接去看arthas的官方文件,中文的,很容易閱讀。
https://alibaba.github.io/arthas/install-detail.html
一、安裝和使用arthas
官方文件:
https://alibaba.github.io/arthas/install-detail.html
安裝
直接通過`java -jar啟動:
wget https://alibaba.github.io/arthas/arthas-boot.jar
# 啟動後會自動下載響應的lib到 ~/.arthas 目錄下
java -jar arthas-boot.jar
或者直接下載arthas的壓縮包,然後解壓:
unzip arthas-packaging-bin.zip
# 執行
./as.sh
啟動asthas程序後,它會列出所有的jvm程序,並讓我們選擇要attach哪個程序。attach目標程序後,就進入athas的互動命令行了,這時候就可以開始輸入arthas對應的命令使用了
解除安裝
rm -rf ~/.arthas/
二、athas的各個命令
1. dashboard
進入當前系統的實時資料面板,按 ctrl+c 退出。這個面板會實時重新整理,其中包括執行緒資訊、記憶體資訊、gc資訊、還有一些執行時的資料。
另外,當執行在Ali-tomcat時,會顯示當前tomcat的實時資訊,如HTTP請求的qps, rt, 錯誤數, 執行緒池資訊等等。
下面是arthas上面的一張demo圖
2. thread
通過thread命令可以檢視當前jvm程序的執行緒詳情。可以檢視執行緒的cpu使用時間佔比,通過指定各種引數可以找出最忙的幾個執行緒,以及阻塞其他執行緒的執行緒。具體如何使用這裡不多做介紹,大家可以去看arthas的官方文件。
3. jvm
通過jvm命令直接輸出當前jvm的各種資訊。
4. sysprop和sysenv
通過sysprop可以檢視所有的系統變數,也可以設定某個系統變數。
同理,通過sysenv可以檢視所有的作業系統環境變數,也可以檢視設定某個環境變數。
5. getstatic
通過該命令可以檢視類的靜態屬性。不過檢視類的靜態屬性ognl命令也可以做到,官方也比較推薦使用ognl表示式來做。
不過使用getstatic可以使用萬用字元來檢視變數,好像用ognl不行。(也可能是我對ognl表示式瞭解還不夠)
# 檢視CommonConstants類下的所有靜態屬性
getstatic *.CommonConstants *
6. ognl
通過ognl表示式來執行一些語句。
# 呼叫靜態函式
ognl '@[email protected]("hello")'
# 輸出
null
# 獲取靜態類的靜態欄位
ognl '@[email protected]'
# 輸出
@Random[
serialVersionUID=@Long[3905348978240129619],
seed=@AtomicLong[125451474443703],
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[[email protected]],
seedOffset=@Long[24],
]
# 執行多行表示式,賦值給臨時變數,返回一個List
ognl '#[email protected]@getProperty("java.home"),#[email protected]@getProperty("java.runtime.name"), {#value1, #value2}'
# 輸出
@ArrayList[
@String[/opt/java/8.0.181-zulu/jre],
@String[OpenJDK Runtime Environment],
]
ognl表示式在arthas中用的還是比較多的,語法也比較簡單。在後面的monitor、watch、trace、stack等命令中都會排上用場。
關於ognl,這個userCase上有豐富的案例:
https://github.com/alibaba/arthas/issues/11
7. sc 和 sm
通過sc可以檢視已載入類的相關資訊,比如該類是從哪個jar包載入的,被哪個類載入器載入的,以及是否是介面等等。
sm檢視已載入類的方法詳情。
8. dump
將已載入類的位元組碼dump到本地磁碟上。
9. jad
反編譯已載入的類。讓它變成可讀的形式。
有時我們經常會不確定線上或者測試環境的包是否是我們修改過的,這時候就可以通過jad反編譯來看下。
10. classloader
將 JVM 中所有的classloader的資訊統計出來,並可以展示繼承樹,urls等。
11. redefine
該命令可以載入外部的.class
檔案,然後覆蓋 jvm已載入的類。注意,這個命令不一定都能覆蓋成功,如果添加了新的field,就不會載入成功。
關於redefine,arthas的github上有個非常經典的userCase:
https://github.com/alibaba/arthas/issues/263
大體就是作者遇到專案中的日誌一直輸出[] [] [] No credential found
,想要找到是哪個類輸出的。由於大多數日誌框架輸出日誌時都用到了StringBuilder,因此作者對StringBuilder的toString方法做了以下修改:
@Override
public String toString() {
// Create a copy, don't share the array
String result = new String(value, 0, count);
if(result.contains("No credential found")) {
System.err.println(result);
new Throwable().printStackTrace();
}
return result;
}
改完類之後再用redefine把修改後的StringBuilder載入進去,這樣,當後面繼續輸出[] [] [] No credential found
就可以知道到底是從哪裡輸出的了。
12. monitor
monitor命令可以監控方法的執行情況。比如呼叫成功次數,失敗次數,失敗率、平均執行時間等等。預設120秒輸出一次,也就是說,當我們輸入monitor命令之後,每120秒就會輸出一次統計結果。
通過-c引數可以修改輸出頻率,支援萬用字元和正則表示式。
13. watch
讓你能方便的觀察到指定方法的呼叫情況。能觀察到的範圍為:返回值
、丟擲異常
、入參
,通過編寫 OGNL 表示式進行對應變數的檢視。
watch的使用姿勢比較豐富,可以在四個不同的場景觀察方法的執行。比如方法呼叫之前、方法呼叫之後、方法異常之後、方法結束之後。預設觀察的是方法結束之後。
如果觀察的是方法結束之後的場景,由於入參可能在執行方法時被改變,所以此時輸出的可能不是真正的入參。因此,要看真正的入參,要看方法呼叫之前的,也就是加上-b的引數。
另外,使用-b引數觀察的話,則觀察不到方法返回的結果以及丟擲的異常了。
相關引數:
引數名稱 | 引數說明 |
---|---|
class-pattern | 類名錶達式匹配 |
method-pattern | 方法名錶達式匹配 |
express | 觀察表示式 |
condition-express | 條件表示式 |
[b] | 在方法呼叫之前觀察 |
[e] | 在方法異常之後觀察 |
[s] | 在方法返回之後觀察 |
[f] | 在方法結束之後(正常返回和異常返回)觀察 |
[E] | 開啟正則表示式匹配,預設為萬用字元匹配 |
[x:] | 指定輸出結果的屬性遍歷深度,預設為 1 |
[n:] | 只執行n次,預設會不斷輸出,除非使用者按下cltr+c |
# 觀察CommonTest的test方法
# 輸出 入參、返回結果、丟擲的異常 —— 輸出的內容可以動態調整
# 後面跟著的是 條件表示式,表示耗時超過10ms才輸出
# -n 表示只執行一次,-x表示 入參和返回結果的展開層次為5層
watch *.CommonTest test "{params,returnObj,throwExp}" '#cost>10' -x 5 -n 1
# 耗時大於10ms並且第一個引數等於1才輸出
watch *.CommonTest test "{params,returnObj,throwExp}" '#cost>10 && params[0]==1' -x 5 -n 1
# 第一個引數大於1 並且第二個引數等於hello才輸出
watch *.CommonTest test "{params,returnObj,throwExp}" 'params[0]>1 && params[1]=="hello"' -x 5 -n 1
# 第一個引數小於5或者第二個引數等於"world"就輸出
watch *.CommonTest test "{params,returnObj,throwExp}" 'params[0]<5 || params[1]=="wolrd"' -x 5 -n 1
# 第一個引數的name欄位等於world時才輸出。
# 由於在方法執行過程中引數的name屬性可能發生改變,因此加上-b才能觀察到真正的入參
watch -b *.CommonTest test "{params,returnObj,throwExp}" 'params[0].name=="wolrd"' -x 5 -n 1
# 由於同時指定了-s和-b,所以方法被呼叫一次,就會輸出2次結果(兩個場景分開輸出),分別是方法被呼叫前,和返回之後
# 注意,這裡如果-n只設置成1,那麼只會輸出-b對應的輸出,-s對應的輸出由於沒有次數了就無法輸出了
watch *.CommonTest test '{params,returnObj,throwExp}' -x 5 -n 2 -s -b
在填寫條件表示式時要注意一點,條件表示式中的params預設都是獲取的方法執行完後的引數資訊,比如入參a的屬性name方法執行前是"hello",在方法執行後變成了"world",那麼條件表示式傳入'params[0].name="hello"'
將不會輸出,只有填入'params[0].name="hello"'
才可以匹配上。這點對於後面的trace、stack命令也是一樣的。
14. trace
方法內部呼叫路徑,並輸出方法路徑上的每個節點上耗時。但是該命令只能輸出一級呼叫的方法耗時,往下的就不會輸出了。比如我定義了一個類Test
public class Test{
public void a(){
b();
}
public void b(){
c();
}
public void c(){
//...
}
}
當我要觀察Test a
時,trace命令只會輸出b()
的耗時,而不會輸出c()
的耗時。因為對方法a來說,只有b()
是一級呼叫。
trace命令也可以使用條件表示式,來過濾一些不想要的輸出
# 方法耗時大於100時才輸出,且只輸出1.其他條件過濾的語法可以看watch命令的demo
trace *.Common* test '#cost>100' -n 1
友情提醒下,
trace
在執行的過程中本身是會有一定的效能開銷,在統計的報告中並未像 JProfiler 一樣預先減去其自身的統計開銷。所以這統計出來有些許的不準,渲染路徑上呼叫的類、方法越多,效能偏差越大。但還是能讓你看清一些事情的。這裡存在一個統計不準確的問題,就是所有方法耗時加起來可能會小於該監測方法的總耗時,這個是由於 Arthas 本身的邏輯會有一定的耗時
15. stack
輸出當前方法被呼叫的呼叫路徑。用法和trace差不多
# 方法耗時大於100時才輸出,且只輸出1.其他條件過濾的語法可以看watch命令的demo
stack *.Common* test '#cost>100' -n 1
16. tt
tt命令會記錄每次方法呼叫的各種資訊。它和watch有些相似但是它能記錄下各個時間點的呼叫資訊,之後隨時檢視,甚至replay這次呼叫。
從上圖中我們可以看到,通過-i
引數我們可以直接檢視之前某次呼叫的詳細資訊。
# 指定第一個引數的mobile欄位等於13989838402
tt -t *.CommonTest test params[0].mobile=="13989838402"
# 把之前記錄的那些呼叫都輸出來
tt -l
#
replay某次呼叫:
# replay時間片的index=1002這次呼叫
tt -i 1002 -p
使用tt進行方法replay時,要注意2點
ThreadLocal 資訊丟失
很多框架偷偷的將一些環境變數資訊塞到了發起呼叫執行緒的 ThreadLocal 中,由於呼叫執行緒發生了變化,這些 ThreadLocal 執行緒資訊無法通過 Arthas 儲存,所以這些資訊將會丟失。
一些常見的 CASE 比如:鷹眼的 TraceId 等。
引用的物件
需要強調的是,
tt
命令是將當前環境的物件引用儲存起來,但僅僅也只能儲存一個引用而已。如果方法內部對入參進行了變更,或者返回的物件經過了後續的處理,那麼在tt
檢視的時候將無法看到當時最準確的值。這也是為什麼watch
命令存在的意義。
17. options
options用來開啟關閉某些功能:
名稱 | 預設值 | 描述 |
---|---|---|
unsafe | false | 是否支援對系統級別的類進行增強,開啟該開關可能導致把JVM搞掛,請慎重選擇! |
dump | false | 是否支援被增強了的類dump到外部檔案中,如果開啟開關,class檔案會被dump到/${application dir}/arthas-class-dump/ 目錄下,具體位置詳見控制檯輸出 |
batch-re-transform | true | 是否支援批量對匹配到的類執行retransform操作 |
json-format | false | 是否支援json化的輸出 |
disable-sub-class | false | 是否禁用子類匹配,預設在匹配目標類的時候會預設匹配到其子類,如果想精確匹配,可以關閉此開關 |
debug-for-asm | false | 列印ASM相關的除錯資訊 |
save-result | false | 是否開啟執行結果存日誌功能,開啟之後所有命令的執行結果都將儲存到/home/admin/logs/arthas/arthas.log 中 |
job-timeout | 1d | 非同步後臺任務的預設超時時間,超過這個時間,任務自動停止;比如設定 1d, 2h, 3m, 25s,分別代表天、小時、分、秒 |
$ options save-result true
NAME BEFORE-VALUE AFTER-VALUE
----------------------------------------
save-result false true
18. help
通過help命令可以檢視某個命令的使用詳情
help tt
help stack
...
三、遇到的一些問題
在使用arthas的過程中,會遇到一些問題,這裡做個記錄。
1. attach錯程序
在我們要去sc、jad某個類,發現arthas提示類沒載入,但是我們很確定類已經載入了。這時候就要檢查arthas attach的程序是不是我們目標的程序。在進入arthas互動介面時會輸出一些資訊,裡面就有真正attach的程序id:
在上圖我們可以看到,明明我選擇的是要attach 37179這個程序,但實際arthas attach的是26792這個程序。這是由於我們之前用arthas attach過26792這個程序,並且沒有執行 shutdown命令導致的。也就是說執行exit或者quit只會退出互動介面,不會關閉attach的arthas程序。
解決辦法
再次進入arthas互動介面,執行 shutdown
命令,之後重新attach新的程序即可。
四、總結
在以前,我們排查線上jvm程序時,用的命令無非就是jps、jstack、jmap、jstat、jhat
這些jvm命令。但是這些命令能做的事都比較有限。有了arthas,我們可以在線上進行更加豐富的操作,對我們排查問題有很大的幫助。
另外,想學習arthas的話,建議不要只看文件,最好自己手動把所有命令都試一遍,印象會比較深刻,下次遇到類似的問題也可以及時想到這個工具。