阿里排查神器，太強了！

程式設計師大彬發表於2023-01-10
阿里

本文已經收錄到Github倉庫，該倉庫包含計算機基礎、Java基礎、多執行緒、JVM、資料庫、Redis、Spring、Mybatis、SpringMVC、SpringBoot、分散式、微服務、設計模式、架構等核心知識點，歡迎star~

Github地址：https://github.com/Tyson0314/...

Gitee地址：https://gitee.com/tysondai/Ja...

簡介

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

使用場景

  1. 這個類從哪個 jar 包載入的？為什麼會報各種類相關的 Exception？
  2. 我改的程式碼為什麼沒有執行到？難道是我沒 commit？分支搞錯了？
  3. 遇到問題無法線上上 debug，難道只能透過加日誌再重新發布嗎？
  4. 線上遇到某個使用者的資料處理有問題，但線上同樣無法 debug，線下無法重現！
  5. 是否有一個全域性視角來檢視系統的執行狀況？
  6. 有什麼辦法可以監控到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

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

常用命令

查詢arthas版本

[arthas@79952]$ version
3.1.4

1、stack

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

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

引數名稱引數說明
class-pattern類名錶達式匹配
method-pattern方法名錶達式匹配
[arthas@79952]$ stack com.baomidou.mybatisplus.extension.service.IService getOne
Press 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 getOrderInfo

ClassLoader:
@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.String
java.lang.String <init>([BII)V
java.lang.String <init>([BLjava/nio/charset/Charset;)V
java.lang.String <init>([BLjava/lang/String;)V
java.lang.String <init>([BIILjava/nio/charset/Charset;)V
java.lang.String <init>([BIILjava/lang/String;)V
... ... ... ...

檢視String中toString的詳細資訊

sm -d java.lang.String toString
declaring-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 2

Press 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 -b

Press 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 getOrderInfo

Press 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:<init>() #472
        +---[0.00992ms] java.util.HashMap:<init>() #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:<init>() #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:<init>() #472
        +---[0.01408ms] cn.test.mobile.controller.order.OrderController:getUserInfo() #478
        +---[0.0128ms] com.baomidou.mybatisplus.core.conditions.query.QueryWrapper:<init>() #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 76
kill 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 debug
update logger level success.

如果執行這個命令時出錯：update logger level fail.

指定classLoaderHash重試一下試試

logger -c 18b4aac2 --name ROOT --level debug
update logger level success.

8、dashboard

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

dashboard
ID        NAME                          GROUP               PRIORITY STATE     %CPU      TIME      INTERRUPT DAEMON
17        Abandoned connection cleanup  main                5        TIMED_WAI 0         0:0       false     true
1009      AsyncAppender-Worker-arthas-c system              5        WAITING   0         0:0       false     true
5         Attach Listener               system              5        RUNNABLE  0         0:0       false     true
23        ContainerBackgroundProcessor[ main                5        TIMED_WAI 0         0:0       false     true
55        DestroyJavaVM                 main                5        RUNNABLE  0         0:11      false     false
3         Finalizer                     system              8        WAITING   0         0:0       false     true
18        HikariPool-1 housekeeper      main                5        TIMED_WAI 0         0:0       false     true
39        NioBlockingSelector.BlockPoll main                5        RUNNABLE  0         0:0       false     true
2         Reference Handler             system              10       WAITING   0         0:0       false     true
4         Signal Dispatcher             system              9        RUNNABLE  0         0:0       false     true
69        System Clock                  main                5        TIMED_WAI 0         0:34      false     true
25        Thread-2                      main                5        TIMED_WAI 0         0:0       false     false
37        Timer-0                       main                5        TIMED_WAI 0         0:0       false     true
Memory                    used    total    max     usage    GC
heap                      216M    415M     3614M   5.99%    gc.ps_scavenge.count          96
ps_eden_space             36M     78M      1276M   2.90%    gc.ps_scavenge.time(ms)       3054
ps_survivor_space         17M     38M      38M     46.53%   gc.ps_marksweep.count         4
ps_old_gen                161M    298M     2711M   5.97%    gc.ps_marksweep.time(ms)      804
nonheap                   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 classLoaderHash
classLoaderHash   18b4aac2

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

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

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

redefine -c 18b4aac2 OrderController.class
redefine 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]: 3068
2 #選擇第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關閉這個應用就可以啟動了

最後給大家分享一個Github倉庫，上面有大彬整理的300多本經典的計算機書籍PDF，包括C語言、C++、Java、Python、前端、資料庫、作業系統、計算機網路、資料結構和演算法、機器學習、程式設計人生等，可以star一下，下次找書直接在上面搜尋，倉庫持續更新中~

Github地址：https://github.com/Tyson0314/...

相關文章