介绍#
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;
}
}
}