學會 Arthas,讓你 3 年經驗掌握 5 年功力

簡介

Arthas 是Alibaba開源的Java診斷工具,動態跟蹤Java程式碼;實時監控JVM狀態,可以在不中斷程式執行的情況下輕鬆完成JVM相關問題排查工作 。支援JDK 6+,支援Linux/Mac/Windows。這個工具真的很好用,而且入門超簡單,十分推薦。

使用場景

這個類從哪個 jar 包載入的?為什麼會報各種類相關的 Exception?

我改的程式碼為什麼沒有執行到?難道是我沒 commit?分支搞錯了?

遇到問題無法在線上 debug,難道只能透過加日誌再重新發布嗎?

線上遇到某個使用者的資料處理有問題,但線上同樣無法 debug,線下無法重現!

是否有一個全域性視角來檢視系統的執行狀況?

有什麼辦法可以監控到JVM的實時執行狀態?接下來,圍繞這6個問題,學習下Arthas的基本用法。

安裝

執行下面命令下載

wget https://alibaba。github。io/arthas/arthas-boot。jar複製程式碼

用java -jar的方式啟動

java -jar arthas-boot。jar[INFO] Found existing java process, please choose one and hit RETURN。* [1]: 79952 cn。test。MobileApplication [2]: 93872 org。jetbrains。jps。cmdline。Launcher複製程式碼

然後輸入數字,選擇你想要監聽的應用,回車即可

常用命令

當前版本v3。1。4

[arthas@79952]$ version3。1。4複製程式碼

1、stack

輸出當前方法被呼叫的呼叫路徑

很多時候我們都知道一個方法被執行,但是有很多地方呼叫了它,你並不知道是誰呼叫了它,此時你需要的是 stack 命令。

引數名稱引數說明

class-pattern

類名錶達式匹配

method-pattern

方法名錶達式匹配

[arthas@79952]$ stack com。baomidou。mybatisplus。extension。service。IService getOnePress Q or Ctrl+C to abort。Affect(class-cnt:202 , method-cnt:209) cost in 10761 ms。ts=2019-11-13 11:49:13;thread_name=http-nio-8801-exec-6;id=2d;is_daemon=true;priority=5;TCCL=org。springframework。boot。web。embedded。tomcat。TomcatEmbeddedWebappClassLoader@a6c54c3 @com。baomidou。mybatisplus。extension。service。impl。ServiceImpl。getOne() at com。baomidou。mybatisplus。extension。service。IService。getOne(IService。java:230) …… …… at cn。test。mobile。controller。order。OrderController。getOrderInfo(OrderController。java:500)

可以看到OrderController。java的第500行呼叫了這個getOne介面。

注意這個命令需要呼叫後才會觸發日誌,相似的還有watch、trace等

2、jad

反編譯指定已載入類的原始碼

有時候,版本釋出後,程式碼竟然沒有執行,程式碼是最新的嗎,這時可以使用jad反編譯相應的class。

jad cn。test。mobile。controller。order。OrderController

僅編譯指定的方法

jad cn。test。mobile。controller。order。OrderController getOrderInfoClassLoader:@RequestMapping(value={“getOrderInfo”}, method={RequestMethod。POST})public Object getOrderInfo(HttpServletRequest request, @RequestBody Map map) { ResponseVo responseVo = new ResponseVo(); 。。。 。。。 。。。 。。。

3、sc

“Search-Class” 的簡寫 ,檢視JVM已載入的類資訊 有的時候,你只記得類的部分關鍵詞,你可以用sc獲取完整名稱 當你碰到這個錯的時候“ClassNotFoundException”或者“ClassDefNotFoundException”,你可以用這個命令驗證下

引數名稱引數說明

class-pattern

類名錶達式匹配

method-pattern

方法名錶達式匹配

[d]輸出當前類的詳細資訊,包括這個類所載入的原始檔案來源、類的宣告、載入的ClassLoader等詳細資訊。如果一個類被多個ClassLoader所載入,則會出現多次

模糊搜尋

sc *OrderController*cn。test。mobile。controller。order。OrderController

列印類的詳細資訊 sc -d

sc -d cn。test。mobile。controller。order。OrderController class-info cn。test。mobile。controller。order。OrderController code-source /F:/IDEA-WORKSPACE-TEST-qyb/trunk/BE/mobile/target/classes/ name cn。test。mobile。controller。order。OrderController isInterface false isAnnotation false isEnum false isAnonymousClass false isArray false isLocalClass false isMemberClass false isPrimitive false isSynthetic false simple-name OrderController modifier public annotation org。springframework。web。bind。annotation。RestController,org。springframework。web。bind。annotation。Requ estMapping interfaces super-class +-cn。test。mobile。controller。BaseController +-java。lang。Object class-loader +-sun。misc。Launcher$AppClassLoader@18b4aac2 +-sun。misc。Launcher$ExtClassLoader@480bdb19 classLoaderHash 18b4aac2

與之相應的還有sm( “Search-Method” ),檢視已載入類的方法資訊

檢視String裡的方法

sm java。lang。Stringjava。lang。String ([BII)Vjava。lang。String ([BLjava/nio/charset/Charset;)Vjava。lang。String ([BLjava/lang/String;)Vjava。lang。String ([BIILjava/nio/charset/Charset;)Vjava。lang。String ([BIILjava/lang/String;)V。。。 。。。 。。。 。。。

檢視String中toString的詳細資訊

sm -d java。lang。String toStringdeclaring-class java。lang。String method-name toString modifier public annotation parameters return java。lang。String exceptions classLoaderHash null複製程式碼

4、watch

可以監測一個方法的入參和返回值

有些問題線上會出現,本地重現不了,這時這個命令就有用了

引數名稱引數說明

class-pattern

類名錶達式匹配

method-pattern

方法名錶達式匹配

express

觀察表示式

condition-express

條件表示式

[b]在

方法呼叫之前

觀察

[e]在

方法異常之後

觀察

[s]在

方法返回之後

觀察

[f]在

方法結束之後

(正常返回和異常返回)觀察,

預設選項

[E]開啟正則表示式匹配,預設為萬用字元匹配

[x:]指定輸出結果的屬性遍歷深度,預設為 1

觀察getOrderInfo的出參和返回值,出參就是方法結束後的入參

watch cn。test。mobile。controller。order。OrderController getOrderInfo “{params,returnObj}” -x 2Press Q or Ctrl+C to abort。Affect(class-cnt:1 , method-cnt:1) cost in 456 ms。ts=2019-11-13 15:30:18; [cost=18。48307ms] result=@ArrayList[ @Object[][ # 這個就是出參,params @RequestFacade[org。apache。catalina。connector。RequestFacade@1d81dbd7], @LinkedHashMap[isEmpty=false;size=2], # 把遍歷深度x改為3就可以檢視map裡的值了 ], @ResponseVo[ # 這個就是返回值 returnObj log=@Logger[Logger[cn。test。db。common。vo。ResponseVo]], success=@Boolean[true], message=@String[Ok], count=@Integer[0], code=@Integer[1000], data=@HashMap[isEmpty=false;size=1], ],]複製程式碼

觀察getOrderInfo的入參和返回值

watch cn。test。mobile。controller。order。OrderController getOrderInfo “{params,returnObj}” -x 3 -bPress Q or Ctrl+C to abort。Affect(class-cnt:1 , method-cnt:1) cost in 93 ms。ts=2019-11-13 15:37:38; [cost=0。012479ms] result=@ArrayList[ @Object[][ @RequestFacade[ request=@Request[org。apache。catalina。connector。Request@d04e652], sm=@StringManager[org。apache。tomcat。util。res。StringManager@7ae7a97b], ], @LinkedHashMap[ @String[payNo]:@String[190911173713755288], @String[catalogId]:@String[6], ], ], null,# -b是方法呼叫之前觀察,所以還沒有返回值]

如果需要捕捉異常的話,使用throwExp,如{params,returnObj,throwExp}

5、trace

輸出方法內部呼叫路徑,和路徑上每個節點的耗時

可以透過這個命令,檢視哪些方法耗效能,從而找出導致效能缺陷的程式碼,這個耗時還包含了arthas執行的時間哦。

引數名稱引數說明

class-pattern

類名錶達式匹配

method-pattern

方法名錶達式匹配

condition-express

條件表示式

[E]開啟正則表示式匹配,預設為萬用字元匹配

[n:]命令執行次數

#cost方法執行耗時

輸出getOrderInfo的呼叫路徑

trace -j cn。test。mobile。controller。order。OrderController getOrderInfoPress Q or Ctrl+C to abort。Affect(class-cnt:1 , method-cnt:1) cost in 92 ms。——-ts=2019-11-13 15:46:59;thread_name=http-nio-8801-exec-4;id=2b;is_daemon=true;priority=5;TCCL=org。springframework。boot。web。embedded。tomcat。TomcatEmbeddedWebappClassLoader@a6c54c3 ——-[15。509011ms] cn。test。mobile。controller。order。OrderController:getOrderInfo() +——-[0。03584ms] cn。test。db。common。vo。ResponseVo:() #472 +——-[0。00992ms] java。util。HashMap:() #473 +——-[0。02176ms] cn。test。mobile。controller。order。OrderController:getUserInfo() #478 +——-[0。024ms] java。util。Map:get() #483 +——-[0。00896ms] java。lang。Object:toString() #483 +——-[0。00864ms] java。lang。Integer:parseInt() #483 +——-[0。019199ms] com。baomidou。mybatisplus。core。conditions。query。QueryWrapper:() #500 +——-[0。135679ms] com。baomidou。mybatisplus。core。conditions。query。QueryWrapper:allEq() #500 +——-[12。476072ms] cn。test。db。service。IOrderMediaService:getOne() #500 +——-[0。0128ms] java。util。HashMap:put() #501 +——-[0。443517ms] cn。test。db。common。vo。ResponseVo:setSuccess() #503 `——-[0。03488ms] java。util。Map:put() #504

輸出getOrderInfo的呼叫路徑,且cost大於10ms,-j是指過濾掉jdk中的方法,可以看到輸出少了很多

trace -j cn。test。mobile。controller。order。OrderController getOrderInfo ‘#cost > 10’Press Q or Ctrl+C to abort。Affect(class-cnt:1 , method-cnt:1) cost in 96 ms。——-ts=2019-11-13 15:53:42;thread_name=http-nio-8801-exec-2;id=29;is_daemon=true;priority=5;TCCL=org。springframework。boot。web。embedded。tomcat。TomcatEmbeddedWebappClassLoader@a6c54c3 ——-[13。803743ms] cn。test。mobile。controller。order。OrderController:getOrderInfo() +——-[0。01312ms] cn。test。db。common。vo。ResponseVo:() #472 +——-[0。01408ms] cn。test。mobile。controller。order。OrderController:getUserInfo() #478 +——-[0。0128ms] com。baomidou。mybatisplus。core。conditions。query。QueryWrapper:() #500 +——-[0。303998ms] com。baomidou。mybatisplus。core。conditions。query。QueryWrapper:allEq() #500 +——-[12。675431ms] cn。test。db。service。IOrderMediaService:getOne() #500 `——-[0。409917ms] cn。test。db。common。vo。ResponseVo:setSuccess() #503

6、jobs

執行後臺非同步任務

線上有些問題是偶然發生的,這時就需要使用非同步任務,把資訊寫入檔案。

使用 & 指定命令去後臺執行,使用 > 將結果重寫到日誌檔案,以trace為例

trace -j cn。test。mobile。controller。order。OrderController getOrderInfo > test。out &

jobs——列出所有job

jobs[76]* Running trace -j cn。test。mobile。controller。order。OrderController getOrderInfo >> test。out & execution count : 0 start time : Wed Nov 13 16:13:23 CST 2019 timeout date : Thu Nov 14 16:13:23 CST 2019 session : f4fba846-e90b-4234-959e-e78ad0a5db8c (current)複製程式碼

job id是76, * 表示此job是當前session建立,狀態是Running,execution count是執行次數,timeout date是超時時間

非同步執行時間,預設為1天,如果要修改,使用options命令,

options job-timeout 2d

options可選引數 1d, 2h, 3m, 25s,分別代表天、小時、分、秒

kill——強制終止任務

kill 76kill job 76 success

最多同時支援8個命令使用重定向將結果寫日誌

請勿同時開啟過多的後臺非同步命令,以免對目標JVM效能造成影響

7、logger

檢視logger資訊,更新logger level

檢視

logger name ROOT class ch。qos。logback。classic。Logger classLoader sun。misc。Launcher$AppClassLoader@18b4aac2 classLoaderHash 18b4aac2 #改日誌級別時要用到它 level INFO effectiveLevel INFO 。。。 。。。 。。。 。。。

更新日誌級別

logger ——name ROOT ——level debugupdate logger level success。

如果執行這個命令時出錯:update logger level fail。

指定classLoaderHash重試一下試試

logger -c 18b4aac2 ——name ROOT ——level debugupdate logger level success。

8、dashboard

檢視當前系統的實時資料面板 這個命令可以全域性地檢視jvm執行狀態,比如記憶體和cpu佔用情況

dashboardID NAME GROUP PRIORITY STATE %CPU TIME INTERRUPT DAEMON17 Abandoned connection cleanup main 5 TIMED_WAI 0 0:0 false true1009 AsyncAppender-Worker-arthas-c system 5 WAITING 0 0:0 false true5 Attach Listener system 5 RUNNABLE 0 0:0 false true23 ContainerBackgroundProcessor[ main 5 TIMED_WAI 0 0:0 false true55 DestroyJavaVM main 5 RUNNABLE 0 0:11 false false3 Finalizer system 8 WAITING 0 0:0 false true18 HikariPool-1 housekeeper main 5 TIMED_WAI 0 0:0 false true39 NioBlockingSelector。BlockPoll main 5 RUNNABLE 0 0:0 false true2 Reference Handler system 10 WAITING 0 0:0 false true4 Signal Dispatcher system 9 RUNNABLE 0 0:0 false true69 System Clock main 5 TIMED_WAI 0 0:34 false true25 Thread-2 main 5 TIMED_WAI 0 0:0 false false37 Timer-0 main 5 TIMED_WAI 0 0:0 false trueMemory used total max usage GCheap 216M 415M 3614M 5。99% gc。ps_scavenge。count 96ps_eden_space 36M 78M 1276M 2。90% gc。ps_scavenge。time(ms) 3054ps_survivor_space 17M 38M 38M 46。53% gc。ps_marksweep。count 4ps_old_gen 161M 298M 2711M 5。97% gc。ps_marksweep。time(ms) 804nonheap 175M 180M -1 97。09%code_cache 35M 35M 240M 14。85%

ID: Java級別的執行緒ID,注意這個ID不能跟jstack中的nativeID一一對應 我們可以透過 thread id 檢視執行緒的堆疊 資訊

thread 2“Reference Handler” Id=2 WAITING on java。lang。ref。Reference$Lock@66ad4272 at java。lang。Object。wait(Native Method) - waiting on java。lang。ref。Reference$Lock@66ad4272 at java。lang。Object。wait(Object。java:502) at java。lang。ref。Reference。tryHandlePending(Reference。java:191) at java。lang。ref。Reference$ReferenceHandler。run(Reference。java:153)

NAME: 執行緒名

GROUP: 執行緒組名

PRIORITY: 執行緒優先順序, 1~10之間的數字,越大表示優先順序越高

STATE: 執行緒的狀態

CPU%: 執行緒消耗的cpu佔比,取樣100ms,將所有執行緒在這100ms內的cpu使用量求和,再算出每個執行緒的cpu使用佔比。

TIME: 執行緒執行總時間,資料格式為分:秒

INTERRUPTED: 執行緒當前的中斷位狀態

DAEMON: 是否是daemon執行緒

9、redefine

redefine jvm已載入的類 ,可以在不重啟專案的情況下,熱更新類。

這個功能真的很強大,但是命令不一定會成功

下面我們來模擬:假設我想修改OrderController裡的某幾行程式碼,然後熱更新至jvm:

a。 反編譯OrderController,預設情況下,反編譯結果裡會帶有ClassLoader資訊,透過——source-only選項,可以只打印原始碼。方便和mc/redefine命令結合使用

jad ——source-only cn。test。mobile。controller。order。OrderController > OrderController。java

生成的OrderController。java在哪呢,執行pwd就知道在哪個目錄了

b。 查詢載入OrderController的ClassLoader

sc -d cn。test。mobile。controller。order。OrderController | grep classLoaderHashclassLoaderHash 18b4aac2

c。 修改儲存好OrderController。java之後,使用mc(Memory Compiler)命令來編譯成位元組碼,並且透過-c引數指定ClassLoader

mc -c 18b4aac2 OrderController。java -d 。/

d。 熱更新剛才修改後的程式碼

redefine -c 18b4aac2 OrderController。classredefine success, size: 1

然後程式碼就更新成功了。

其他

如果java -jar選擇啟動某個應用的時候,報下面的錯

java -jar arthas-boot。jar[INFO] arthas-boot version: 3。1。4[INFO] Process 11544 already using port 3658[INFO] Process 11544 already using port 8563[INFO] Found existing java process, please choose one and hit RETURN。* [1]: 11544 [2]: 119504 cn。test。MobileApplication [3]: 136340 org。jetbrains。jps。cmdline。Launcher [4]: 30682 #選擇第2個啟動[ERROR] Target process 119504 is not the process using port 3658, you will connect to an unexpected process。[ERROR] 1。 Try to restart arthas-boot, select process 11544, shutdown it first with running the ‘shutdown’ command。[ERROR] 2。 Or try to use different telnet port, for example: java -jar arthas-boot。jar ——telnet-port 9998 ——http-port -1複製程式碼

注意提示[ERROR] 1,只需要進入11544這個應用,然後執行shutdown關閉這個應用就可以啟動了