介紹#
Arthas 是一款線上監控診斷產品,通過全局視角實時查看應用內存、gc、線程的狀態信息,並能在不修改應用代碼的情況下,對業務問題進行診斷,包括查看方法調用的出入參、異常,監測方法執行耗時,類加載信息等,大大提升線上問題排查效率。
解決問題:
- 本地開發環境無法訪問生產環境,出現問題難以調試
- 某些問題無法在不同的環境中輕鬆復現。
- 添加一些日誌以幫助解決問題,涉及到發布。
基礎命令#
下載和安裝:#
機器安裝:
curl -O https://arthas.aliyun.com/arthas-boot.jar
命令列表:#
1. jvm 相關:#
- 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 裡
- 加載外部.class 文件
retransform /Users/xx/IdeaProjects/ArthasController.class - 查看 retransform entry
retransform -l - 刪除 retransform entity:
retransform -d 1
retransform --deleteAll
备注: - 如果不清除掉所有的 retransform entry,並重新觸發 retransform,則 arthas stop 時,retransform 過的類仍然生效。
- 若沒有清除 retransform 而停止了 Arthas,則可以再次啟動,重新 jad-mc-retransform,jad 反編譯得到的還是修改前的代碼。
- retransform 不允許新增加字段或方法。
- 加載外部.class 文件
-
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;
}
}
}