banner
田野放空

田野放空

认真扮演一个擅长白日做梦的普通人

Arthas使用分享

介紹#

Arthas 是一款線上監控診斷產品,通過全局視角實時查看應用內存、gc、線程的狀態信息,並能在不修改應用代碼的情況下,對業務問題進行診斷,包括查看方法調用的出入參、異常,監測方法執行耗時,類加載信息等,大大提升線上問題排查效率。

解決問題:

  1. 本地開發環境無法訪問生產環境,出現問題難以調試
  2. 某些問題無法在不同的環境中輕鬆復現。
  3. 添加一些日誌以幫助解決問題,涉及到發布。

基礎命令#

下載和安裝:#

機器安裝:
curl -O https://arthas.aliyun.com/arthas-boot.jar

命令列表:#

1. jvm 相關:#

image

  • dashboard - 當前系統的實時數據面板,默認 5s 刷新一次
ID: Java 級別的線程 ID,注意這個 ID 不能跟 jstack 中的 nativeID 一一對應。
NAME: 線程名
GROUP: 線程組名
PRIORITY: 線程優先級, 1~10 之間的數字,越大表示優先級越高。setPriority(1-10)
STATE: 線程的狀態
CPU%: 線程的 cpu 使用率。比如採樣間隔 1000ms,某個線程的增量 cpu 時間為 100ms,則 cpu 使用率=100/1000=10%
DELTA_TIME: 上次採樣之後線程運行增量 CPU 時間,數據格式為秒
TIME: 線程運行總 CPU 時間,數據格式為分:秒
INTERRUPTED: 線程當前的中斷位狀態
DAEMON: 是否是 daemon 線程

C1 C2 CompilerThread:
垃圾回收次數gc.ps_scavenge.count、垃圾回收消耗時間gc.ps_scavenge.time、標記-清除算法的次數gc.ps_marksweep.count、標記-清除算法的消耗時間
  • heapdump - dump java heap, 類似 jmap 命令的 heap dump 功能

    heapdump xx-output/dump.hprof
    生成文件在 arthas-output 目錄,可以通過瀏覽器打開: http://localhost:8563/xx-output/

  • jvm - 查看當前 JVM 的信息

    Thread:
    COUNT: JVM 當前活躍的線程數
    DAEMON-COUNT: JVM 當前活躍的守護線程數
    PEAK-COUNT: 從 JVM 啟動開始曾經活著的最大線程數
    STARTED-COUNT: 從 JVM 啟動開始總共啟動過的線程次數
    DEADLOCK-COUNT: JVM 當前死鎖的線程數
    文件描述符:
    MAX-FILE-DESCRIPTOR-COUNT:JVM 進程最大可以打開的文件描述符數
    OPEN-FILE-DESCRIPTOR-COUNT:JVM 當前打開的文件描述符數

  • logger - 查看和修改 logger

    更新 logger level
    logger --name ROOT --level debug

  • memory - 查看 JVM 的內存信息

  • thread - 查看當前 JVM 的線程堆棧信息

    thread: 默認按照 CPU 增量時間降序排列
    thread -n 3 : 展示當前最忙的前 3 個線程並打印堆棧
    thread id : 顯示指定線程的運行堆棧
    thread -b : 找出當前阻塞其他線程的線程:目前只支持找出 synchronized 關鍵字阻塞住的線程
    thread -i : 指定採樣時間間隔
    thread --state : 查看指定狀態的線程

  • vmoption - 查看和修改 JVM 裡診斷相關的 option

    更新指定的 option
    vmoption PrintGC true

  • vmtool - 從 jvm 裡查詢對象,執行 forceGc

    vmtool --action forceGc

2. class/classloader 相關#

  • classloader - 查看 classloader 的繼承樹,urls,類加載信息,使用 classloader 去 getResource

    按類加載類型查看統計信息
    按類加載實例查看統計信息 -l
    查看 ClassLoader 的繼承樹 -t

  • dump - dump 已加載類的 byte code 到特定目錄

    dump com.xx.xx.controller.ArthasController 生成 ArthasController.class 文件

  • jad - 反編譯指定已加載類的源碼

    默認情況下,反編譯結果裡會帶有 ClassLoader 信息,通過 --source-only 選項,可以只打印源代碼
    jad --source-only com.xx.xx.controller.ArthasController
    jad --source-only com.xx.xx.controller.ArthasController deadLock

  • redefine - 加載外部的.class 文件,redefine 到 JVM 裡

    redefine 命令和 jad/watch/trace/monitor/tt 等命令會衝突。執行完 redefine 之後,如果再執行上面提到的命令,則會把 redefine 的字節碼重置。

  • retransform - 加載外部的.class 文件,retransform 到 JVM 裡

    1. 加載外部.class 文件
      retransform /Users/xx/IdeaProjects/ArthasController.class
    2. 查看 retransform entry
      retransform -l
    3. 刪除 retransform entity:
      retransform -d 1
      retransform --deleteAll
      备注:
    4. 如果不清除掉所有的 retransform entry,並重新觸發 retransform,則 arthas stop 時,retransform 過的類仍然生效。
    5. 若沒有清除 retransform 而停止了 Arthas,則可以再次啟動,重新 jad-mc-retransform,jad 反編譯得到的還是修改前的代碼。
    6. retransform 不允許新增加字段或方法。
  • sc - 查看 JVM 已加載的類信息

    sc -d com.xx.xx.controller.*
    sc -d com.xx.xx.controller.ArthasController

  • sm - 查看已加載類的方法信息

    sm com.xx.xx.controller.ArthasController *

3. monitor/watch/trace 相關#

請注意,這些命令,都通過字節碼增強技術來實現的,會在指定類的方法中插入一些切面來實現數據統計和觀測,因此在線上、預發使用時,請盡量明確需要觀測的類、方法以及條件,診斷結束要執行 stop 或將增強過的類執行 reset 命令。
一定要帶 -n 執行命令,否則在遇到調用量非常大的方法,瞬間就能將你的 JVM 內存撐爆。

  • monitor - 方法執行監控

    監控 ArthasController 中的 flag 方法,每 5s 打印一次,打印 10 次
    monitor com.xx.xx.controller.ArthasController flag -n 10 --cycle 5
    統計接口參數 param [0] <=2 的請求
    monitor -c 5 demo.MathGame primeFactors "params[0] <= 2"

  • stack - 輸出當前方法被調用的調用路徑
    很多時候我們都知道一個方法被執行,但這個方法被執行的路徑非常多,或者你根本就不知道這個方法是從那裡被執行。

stack com.xx.xx.service.impl.WjVideoServiceImpl preprocessingVideo -n 5

  • trace - 方法內部調用路徑,並輸出方法路徑上的每個節點上耗時

    • trace 能方便的幫助你定位和發現因 RT 高而導致的性能問題缺陷,但其每次只能跟蹤一级方法的調用鏈路。
    • 很多時候我們只想看到某個方法的 rt 大於某個時間之後的 trace 結果。可以用 '#cost>100' 表示當執行時間超過 100ms 的時候,才會輸出 trace 的結果。
    • 目前不支持 trace java.lang.Thread getName

    --exclude-class-pattern 排除掉指定的類
    --skipJDKMethod true trace jdk 裡的函數
    '#cost > 10' 執行時間超過 10ms 的時候,才會輸出 trace 的結果。
    跟蹤多級方法實現鏈路調用追蹤
    trace -E com.xx.xx.service.impl.VideoServiceImpl|com.xx.xx.controller.AutoCutController|com.xx.xx.service.impl.WjVideoServiceImpl preprocessing|preprocessingVideo -n 5 '#cost>10'

  • tt (TimeTunnel) - 方法執行數據的時空隧道,記錄下指定方法每次調用的入參和返回信息,並能對這些不同的時間下調用進行觀測

    tt -t com.kscs.capcut.service.impl.WjVideoServiceImpl preprocessingVideo -n 5
    tt -l 檢索調用記錄 tt -s 'method.name=="preprocessingVideo"'
    tt -i 1000 查看調用信息
    tt -i 1004 -p 重做一次調用

  • watch - 觀察到指定函數的調用情況。能觀察到的範圍為:返回值、拋出異常、入參。

    • -f 在函數返回之後觀察
    • -x 輸出結果的屬性遍歷深度

    watch com.xx.xx.service.impl.WjVideoServiceImpl preprocessingVideo '{params,returnObj,throwExp}' -n 5 -x 3

解決問題:#

1. 利用 Arthas 精準定位 Java 應用 CPU 負載過高問題#

查看CPU占比最高線程  
1. thread / thread -n 3
2. thread id

1. 方法被循環調用
2. 內部有死循環

我們使用tt命令監聽一下這個方法的調用情況
tt -t com.xx.xx.controller.ArthasController deadAdd -n 5 
在線上執行這個命令的時候,一定要記得加上 -n 參數,否則線上巨大的流量可能會瞬間撐爆你的JVM內存

反編譯方法,看看
jad --source-only com.xx.xx.controller.ArthasController deadAdd


top --> top -Hp pid --> jstack pid  16 進制

2. 利用 Arthas 分析內存問題#

dashboard 查看GC數據
 gc.ps_scavenge.count      gc.ps_marksweep.count  

使用 vmoption 命令動態打開 GC 日誌
vmoption PrintGC true
vmoption PrintGCDetails true

使用 vmtool 強制 GC
vmtool --action forceGc
https://www.v2ex.com/t/792635

3. 動態修改日誌打印級別#

logger
默認情況下,logger 命令會在 SystemClassloader 下執行,如果應用是傳統的war應用,或者 spring boot fat jar 啟動的應用,那麼需要指定 classloader。
 logger -c 685f4c2e  --name ROOT --level debug

4. 反編譯源碼,查看 jvm 加載的是否為預期的文件內容。#

jad --source-only com.xx.xx.controller.AutoCutController preprocessing

5. 方法內調用路徑及各方法調用耗時。#

    monitor :此命令用於監控方法的執行情況,包括方法的調用次數、成功次數、失敗次數、最大耗時、最小耗時和平均耗時。它通常用於定位性能問題。
[arthas@19702]$ monitor com.xx.xx.service.impl.WjVideoServiceImpl preprocessingVideo  -n 10  --cycle 10
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 49 ms, listenerId: 3
 timestamp         class                     method                    total    success  fail    avg-rt(  fail-ra
                                                                                                 ms)      te
------------------------------------------------------------------------------------------------------------------
 2023-07-17 16:21  com.xx.xx.service.  preprocessingVideo        1        1        0       3755.98  0.00%
 :14               impl.WjVideoServiceImpl

 
 
    trace :此命令用於跟蹤方法的調用路徑和耗時。它會記錄下方法的入參和返回結果,以及方法內部調用的其他方法和它們的執行時間。
 [arthas@19702]$  trace -E com.xx.xx.service.impl.VideoServiceImpl|com.xx.xx.controller.AutoCutController|com.xx.xx.service.impl.WjVideoServiceImpl preprocessing|preprocessingVideo -n 5  --skipJDKMethod false '1==1'
Press Q or Ctrl+C to abort.
Affect(class count: 4 , method count: 4) cost in 157 ms, listenerId: 2
`---ts=2023-07-17 16:20:42;thread_name=http-nio-8183-exec-8;id=2b;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@3576ddc2
    `---[1.069325ms] com.xx.xx.controller.AutoCutController$$EnhancerBySpringCGLIB$$333516af:preprocessing()
        `---[83.17% 0.889312ms ] org.springframework.cglib.proxy.MethodInterceptor:intercept()
            `---[43.36% 0.385619ms ] com.xx.xx.controller.AutoCutController:preprocessing()
                +---[6.45% 0.024868ms ] org.slf4j.MDC:get() #31
                +---[1.90% 0.007333ms ] com.xx.xx.common.vo.ProcessingVO:setTaskId() #31
                +---[70.24% 0.270861ms ] com.xx.xx.service.VideoService:preprocessingVideo() #32
                `---[2.93% 0.011295ms ] com.xx.xx.base.model.Result:success() #33


    tt   :此命令用於記錄方法的歷史調用情況,包括方法的入參、返回結果和異常信息。它不僅可以查看方法的當前調用情況,還可以查看方法的歷史調用情況,還可以重試歷史調用。
[arthas@19702]$ tt -t com.kscs.capcut.controller.AutoCutController preprocessing -n 5
Press Q or Ctrl+C to abort.
Affect(class count: 2 , method count: 2) cost in 39 ms, listenerId: 4
 INDEX  TIMESTAMP         COST(ms  IS-RE  IS-EX  OBJECT       CLASS                     METHOD
                          )        T      P
------------------------------------------------------------------------------------------------------------------
 1000   2023-07-17 16:23  0.20207  true   false  0x5ec8b24c   AutoCutController         preprocessing
        :17               4
 1001   2023-07-17 16:23  1.94166  true   false  0xe637be2a   AutoCutController$$Enhan  preprocessing
        :17               4                                   cerBySpringCGLIB$$333516
                                                              af

6. 代碼熱更新#

1. 反編譯已加載類的源碼
jad --source-only com.kscs.capcut.controller.ArthasController 

2. 修改本地代碼並編譯、測試。通過後找到target目錄下編譯好的.class文件
3. 熱更新
retransform /Users/edy/IdeaProjects/ArthasController.class
2. 查看 retransform entry
    retransform -l 
3. 刪除retransform entity:
    retransform -d 1
    retransform --deleteAll

對服務性能的影響#

Arthas在執行trace/watch/tt/monitor 等命令時,本質上是在method的前後插入代碼,會導致原來JVM裡JIT編譯生成的代碼無效,需要退回原來的代碼,再重新JIT編譯。所以對於並發高的函數調用會調起抖動。
所以要避免一次性trace/watch大量的類。
建議在線上環境時,集群裡選一台負載低的機器來執行分析,如果是只有一台機器,則要小心使用。

用到的 demo#

public class ArthasController {
    public static boolean flag = true;
    private List<ProcessingVO> stringList = new ArrayList<>();

    @RequestMapping(method = RequestMethod.POST, value = "flag")
    public Result<Map<String, String>> flag(Integer param1, Integer param2) {
        flag = !flag;
        return Result.success();
    }

    @RequestMapping(method = RequestMethod.POST, value = "oom")
    public Result<List<ProcessingVO>> oom() {
        stringList.clear();
        for (int i = 0; i < 1000000; i++) {
            if (stringList.size() > 500000) {
                continue;
            }
            ProcessingVO vo = new ProcessingVO();
            vo.setVideoName("videoName" + i);
            vo.setTaskId("taskId" + i);
            stringList.add(vo);
        }
        return Result.success();
    }

    @RequestMapping(method = RequestMethod.POST, value = "deadLock")
    public Result<Map<String, String>> deadLock() {
        Thread thread1 = new Thread(() -> {
            synchronized (String.class) {
                log.info("thread1 get String lock");
                try {
                    Thread.sleep(10000);
                } catch (Exception e) {
                    e.printStackTrace();
                }
                synchronized (Integer.class) {
                    log.info("thread1 get Integer lock");
                }
            }
        });
        Thread thread2 = new Thread(() -> {
            synchronized (Integer.class) {
                log.info("thread2 get Integer lock");
                try {
                    Thread.sleep(100);
                } catch (Exception e) {
                    e.printStackTrace();
                }
                synchronized (String.class) {
                    log.info("thread2 get String lock");
                }
            }
        });
        thread1.setName("deadlock-thread1");
        thread2.setName("deadlock-thread2");
        thread1.start();
        thread2.start();
        return Result.success();
    }

    @RequestMapping(method = RequestMethod.POST, value = "highCPU")
    public Result<Map<String, String>> highCPU() {
        Thread highCpuThread = new Thread(this::deadAdd);
        highCpuThread.setName("HighCpu");
        highCpuThread.start();
        return Result.success();
    }
    //0<-1<-2<-0
    private void deadAdd() {
        ListNode node2 = new ListNode(2, null); //創建節點(數據+引用
        ListNode node1 = new ListNode(1, node2);
        ListNode node = new ListNode(0, node1);
        node2.next = node;
        while (node != null) {
            if (flag) {
                node = node.next;
            } else {
                break;
            }
        }
        System.out.println("stop deadAdd");

    }

    class ListNode {        //類名 :Java類就是一種自定義的數據結構
        int val;            //數據 :節點數據
        ListNode next;      //對象 :引用下個節點對象。在Java中沒有指針的概念,Java中的引用和C語言的指針類似

        ListNode(int val, ListNode next) {  //構造方法 :構造方法和類名相同
            this.val = val;   //把接收的參數賦值給當前類的val變量
            this.next = next;
        }
    }


}
載入中......
此文章數據所有權由區塊鏈加密技術和智能合約保障僅歸創作者所有。