重点:学会利用arthas idea
这款插件。arthas命令有很多,大家不需要都记下来,只需要记一下常用的命令是哪些就可以了,至于这些命令下有哪些参数直接看对应的文档就可以了
Arthas中文用户手册:arthas.gitee.io/doc/quick-s…
Arthas在线教程:arthas.aliyun.com/doc/arthas-…
一、使用arthas可以帮助我们解决啥问题
场景 | 如何使用 |
---|---|
获取到Spring Context,然后为所欲为(比如调用方法,查看属性) | 请看增强命令-tt |
线上代码更新后想看看自己修改的类有没有生效 | class反编译:jad --source-only com.demo.Service > /tmp/Service.java |
某个方法执行很慢,到底慢在哪? | trace demo.MathGame run |
如果项目上线后发现有个java文件没有及时提交导致线上没有更新 | 重新加载class文件:retransform /tmp/MathGame.class |
如果想观察某方法在调用前后的入参、出参、返回值和异常信息 | 同时观察方法调用前和方法返回后watch demo.MathGame run "{params,target,returnObj}" -x 3 -b -s |
查看某个静态属性值 | getstatic -c 46fbb2c1 demo.MathGame random |
调用spring bean的findUserById(),入参为1 | vmtool --action getInstances --className org.springframework.context.ApplicationContext --express 'instances[0].getBean("userController").findUserById(1)' |
直接获取 UserController 并调用findUserById(),入参为2 | vmtool --action getInstances --className com.example.demo.arthas.user.UserController --express 'instances[0].findUserById(2)' |
查看方法调用的(入/出)参/返回值/异常信息 | 见增强命令:watch |
如果想看某个方法被调用后,其内部调用链路和耗时 | trace demo.MathGame run |
run()如果执行耗时超过10ms就输出其内部调用链路 | trace demo.MathGame run '#cost > 10' |
设置HelloService中的静态变量name的值 | ognl -x 3 '#field=@com.demo.HelloService@class.getDeclaredField("name"),#field.setAccessible(true),#field.set(null,"matio")' -c 1efbd816 |
查看run()被调用后,内部调用链路耗时情况,日志保存到~/a.log 中 | trace demo.MathGame run >> a.log & |
try-catch了异常又不打印日志,这种问题如何排查 | |
如果应用部署在docker中咋办 | 查看arthas监控docker应用 |
二、arthas idea
插件
在IDEA的Marketplace中直接安装arthas idea
,也可以选择去idea插件库下载,arthas支持的功能见下图:
三、启动arthas
test@ubuntucloudtest1:~/arthas-demo$ java -jar arthas-boot.jar [INFO] JAVA_HOME: /usr/local/jdk1.8.0_111/jre [INFO] arthas-boot version: 3.7.2 [INFO] Found existing java process, please choose one and input the serial number of the process, eg : 1. Then hit ENTER. * [1]: 13954 math-game.jar
- 执行该程序的用户需要和目标进程具有相同的权限。比如以
admin
用户来执行:sudo su admin && java -jar arthas-boot.jar
或sudo -u admin -EH java -jar arthas-boot.jar
。- 如果 attach 不上目标进程,可以查看
~/logs/arthas/
目录下的日志。- 如果下载速度比较慢,可以使用 aliyun 的镜像:
java -jar arthas-boot.jar --repo-mirror aliyun --use-http
java -jar arthas-boot.jar -h
打印更多参数信息。
输入1后会进入该程序的主控制台
1
[INFO] local lastest version: 3.5.4, remote lastest version: 3.7.2, try to download from remote.
[INFO] Start download arthas from remote server: https://arthas.aliyun.com/download/3.7.2?mirror=aliyun
[INFO] File size: 17.84 MB, downloaded size: 9.99 MB, downloading ...
[INFO] Download arthas success.
[INFO] arthas home: /home/shuncom/.arthas/lib/3.7.2/arthas
[INFO] Try to attach process 13954
Picked up JAVA_TOOL_OPTIONS:
^A[INFO] Attach process 13954 success.
[INFO] arthas-client connect 127.0.0.1 3658
,---. ,------. ,--------.,--. ,--. ,---. ,---.
/ O \ | .--. ''--. .--'| '--' | / O \ ' .-'
| .-. || '--'.' | | | .--. || .-. |`. `-.
| | | || |\ \ | | | | | || | | |.-' |
`--' `--'`--' '--' `--' `--' `--'`--' `--'`-----'
wiki https://arthas.aliyun.com/doc
tutorials https://arthas.aliyun.com/doc/arthas-tutorials.html
version 3.7.2
main_class
pid 13954
time 2024-04-23 13:28:20
[arthas@13954]$
执行dashboard,会打印当前进程的信息,按ctrl+c
可以中断执行,如下:
四、退出arthas
用 exit
或者 quit
命令可以退出 Arthas。退出之后,还可以再次用 java -jar arthas-boot.jar
来连接。exit
或者 quit
命令只是退出当前session,arthas server 还在目标进程中运行
想完全退出 Arthas,可以执行 stop
命令。
五、arthas日志
~/.arthas/
和 ~/logs/arthas
六、arthas监控docker应用
- 下载arthas包:
wget https://alibaba.github.io/arthas/arthas-boot.jar
- 拷贝arthas程序包到目标docker容器目录下:
docker cp arthas-boot.jar 容器id:/
- 进入到容器目录:
docker exec -it 容器id /bin/bash
- 进入到第2步映射到容器的路径,查看arthas-boot.jar是否存在
- 启动Artha:
java -jar arthas-boot.jar
七、arthas用户案例
标题 | |
---|---|
执行结果存日志 | 运行 trace demo.MathGame run >> a.log & ,这时候任务已经在后台挂起,使用 jobs 查看当前后台运行的任务,之后可以使用 kill 指定任务 ID 将其结束 |
排查函数调用异常 | watch com.example.demo.arthas.user.UserController * "{params[0],throwExp}" -e |
调试ognl表达式 | watch com.example.demo.arthas.user.UserController * "{loader, clazz, method, target, params, returnObj, throwExp, isBefore, isThrow, isReturn}" |
查找Top N线程 | thread -n 3 |
动态更新应用Logger LEVEL | ognl -c 14db12ff '@com.demo.UserController@logger.setLevel(@ch.qos.logback.classic.Level@DEBUG)' ,也可以使用arthas提供的logger 命令 |
排查logger冲突问题 | 点我 |
热更新代码 | retransform /tmp/MathGame.class ,不允许新增加 field/method |
排查 HTTP 请求返回 401 | trace javax.servlet.Filter * ,监听Filter实现类中的所有方法调用然后输出其内部调用链路和耗时,慎用 |
获取Spring Context | vmtool --action getInstances --className demo.HelloService --express 'instances[0].getHelloMessage()' ,可以利用arthas提供的vmtool 或者tt 命令实现,具体见下 |
理解 Spring Boot 应用的 ClassLoader 结构 | 见classloader |
arthas-boot 支持的参数 | 点我 |
后台异步任务 | watch demo.UserController * '{params, throwExp}' 'throwExp != null' >> a.log & 挂在后台运行,可以使用jobs 查看任务详情,kill 停止后台任务 |
八、arthas命令详解
1. dashboard
dashboard -h
dashboard 间隔5s打印当前进程的信息
dashboard -i 3000 间隔3s打印当前进程的信息
dashboard -n 2 -i 1000
ID | NAME | GROUP | PRIORITY | STATE | %CPU | DELTA_TIME | TIME | INTERRUPTED | DAEMON |
---|---|---|---|---|---|---|---|---|---|
-1 | C1 CompilerThread3 | - | -1 | - | 0.0 | 0.000 | 0:1.396 | false | true |
- ID: Java 级别的线程 ID,这个 ID 不能跟 jstack 中的 nativeID一一对应。
- NAME: 线程名
- GROUP: 线程组名
- PRIORITY: 线程优先级, 1~10 之间的数字,越大表示优先级越高
- STATE: 线程的状态
- CPU%: 线程的 cpu 使用率。比如采样间隔 1000ms,某个线程的增量 cpu 时间为 100ms,则 cpu 使用率=100/1000=10%
- DELTA_TIME: 上次采样之后线程运行增量 CPU 时间,数据格式为
秒
- TIME: 线程运行总 CPU 时间,数据格式为
分:秒
- INTERRUPTED: 线程当前的中断位状态
- DAEMON: 是否是 daemon 线程
Memory | used | total | max | usage | GC | |
---|---|---|---|---|---|---|
heap | 114M | 471M | 6983M | 1.64% | gc.ps_scavenge.count | 0 |
ps_eden_space | 114M | 123M | 2577M | 4.44% | gc.ps_scavenge.time(ms) | 0 |
ps_survivor_space | 0K | 20992K | 20992K | 0.00% | gc.ps_marksweep.count | 0 |
ps_old_gen | 0K | 335872K | 5363200K | 0.00% | gc.ps_marksweep.time(ms) | 0 |
nonheap | 27M | 28M | -1 | 96.87% | ||
code_cache | 5M | 5M | 240M | 2.36% | ||
metaspace | 19M | 19M | -1 | 96.87% | ||
compressed_class_space | 2M | 2M | 1024M | 0.23% | ||
direct | 0K | 0K | - | 200.00% | ||
mapped | 0K | 0K | - | 0.00% |
运行时环境变量
Runtime | |
---|---|
os.name | Linux |
os.version | 4.2.0-27-generic |
java.version | 1.8.0_111 |
java.home | /usr/local/jdk1.8.0_111/jre |
systemload.average | 0.25 |
processors | 10 |
timestamp/uptime | Tue Apr 23 13:33:17 CST 2024/342s |
JVM 内部线程:Java 8 之后支持获取 JVM 内部线程 CPU 时间,这些线程只有名称和 CPU 时间,没有 ID 及状态等信息(显示 ID 为-1)。 通过内部线程可以观测到 JVM 活动,如 GC、JIT 编译等占用 CPU 情况,方便了解 JVM 整体运行状况。
- 当 JVM 堆(heap)/元数据(metaspace)空间不足或 OOM 时,可以看到 GC 线程的 CPU 占用率明显高于其他的线程。
- 当执行
trace/watch/tt/redefine
等命令后,可以看到 JIT 线程活动变得更频繁。因为 JVM 热更新 class 字节码时清除了此 class 相关的 JIT 编译结果,需要重新编译。
JVM 内部线程包括下面几种:
- JIT 编译线程: 如
C1 CompilerThread0
,C2 CompilerThread0
- GC 线程: 如
GC Thread0
,G1 Young RemSet Sampling
- 其它内部线程: 如
VM Periodic Task Thread
,VM Thread
,Service Thread
2. thread 查看当前线程信息,查看线程的堆栈
支持一键展示当前最忙的前 N 个线程并打印堆栈:thread -n 3
- 没有线程 ID,包含
[Internal]
表示为 JVM 内部线程,参考dashboard
命令的介绍。cpuUsage
为采样间隔时间内线程的 CPU 使用率,与dashboard
命令的数据一致。deltaTime
为采样间隔时间内线程的增量 CPU 时间,小于 1ms 时被取整显示为 0ms。time
线程运行总 CPU 时间。
注意:线程栈为第二采样结束时获取,不能表明采样间隔时间内该线程都是在处理相同的任务。建议间隔时间不要太长,可能间隔时间越大越不准确。 可以根据具体情况尝试指定不同的间隔时间,观察输出结果。
默认按照 CPU 增量时间降序排列,只显示第一页数据,避免滚屏:thread
显示所有匹配线程信息,有时需要获取全部 JVM 的线程数据进行分析:thread --all
查看线程 ID 16 的运行堆栈:thread 16
找出当前阻塞其他线程的线程:thread -b
。有时候我们发现应用卡住了,通常是由于某个线程拿住了某个锁,并且其他线程都在等待这把锁造成的。为了排查这类问题,arthas 提供了thread -b
,一键找出那个罪魁祸首。注意,目前只支持找出 synchronized 关键字阻塞住的线程,如果是java.util.concurrent.Lock
,目前还不支持。
统计最近 1000ms 内的线程 CPU 时间:thread -i 1000
列出 1000ms 内最忙的 3 个线程栈:thread -n 3 -i 1000
查看指定状态的线程:thread --state WAITING
3. jvm 查看当前jvm信息
打印出JVM
的各种详细信息:jvm
查找 Java 应用的 classpath:jvm | grep PATH
jvm | grep COUNT
- COUNT: JVM 当前活跃的线程数
- DAEMON-COUNT: JVM 当前活跃的守护线程数
- PEAK-COUNT: 从 JVM 启动开始曾经活着的最大线程数
- STARTED-COUNT: 从 JVM 启动开始总共启动过的线程次数
- DEADLOCK-COUNT: JVM 当前死锁的线程数
- MAX-FILE-DESCRIPTOR-COUNT:JVM 进程最大可以打开的文件描述符数
- OPEN-FILE-DESCRIPTOR-COUNT:JVM 当前打开的文件描述符数
4. vmtool 利用JVMTI接口,实现查询内存对象,强制GC等功能
一般在使用vmtool的时候都是结合arthas idea
一起使用的,因为其命令太过复杂,容易出错
支持的参数如下:
-a, --action <value> Action to execute
-c, --classloader <value> The hash code of the special class's classLoader
--classLoaderClass <value> The class name of the special class's classLoader.
--className <value> The class name
-x, --expand <value> 指定结果的返回层级,默认1
--express <value> The ognl expression, default value is `instances`.
-h, --help this help
--libPath <value> The specify lib path.
-l, --limit <value> Set the limit value of the getInstances action, default value is 10, set to -1 is unlimited
-t, --threadId <value> The id of the thread to be interrupted
package com.example.demo.arthas;
// 省略import...
@Controller
public class WelcomeController {
@Value("${application.message:Hello World}")
private String message = "Hello World";
@GetMapping("/")
public String welcome(Map<String, Object> model) {
model.put("time", new Date());
model.put("message", this.message);
return "welcome";
}
@RequestMapping("/hello")
public String helloWorld(Model model) {
model.addAttribute("name", "jsp");
return "hello";
}
}
在成功安装好arthas idea
插件后,鼠标悬浮到类名、属性名或方法名上的时候点击右键,会出现Arthas Command
,其右侧有很多选项,跟vmtool有关的有2个:
- Vmtool Get Instance Invoke Method Field:调用方法、设置属性
- Vmtool Get Instance Set Field:修改属性,不支持final属性
vmtool -x 3 --action getInstances --className com.example.demo.arthas.WelcomeController --express 'instances[0].message' -c 1efbd816
给controller中的message属性赋个值:vmtool -x 3 --action getInstances --className com.example.demo.arthas.WelcomeController --express '#field=instances[0].getClass().getDeclaredField("message"),#field.setAccessible(true),#field.set(instances[0],"想要设置的属性值")' -c 1efbd816
解释:
-x 3
:返回参数展开层级的,默认1,如果返回体是对象,建议设置3,方便观察返回结果,可取值1-4--action getInstances
:执行的动作,获取实例,固定不变即可--className com.example.demo.arthas.WelcomeController
:指明目标类--express '#field=instances[0].getClass().getDeclaredField("message"),#field.setAccessible(true),#field.set(instances[0]," ")'
:执行动作:instances[0]代表当前类实例对象,也就是当前controller对象,然后通过反射设置message的值-c 1efbd816
:指定加载WelcomeController这个类的classloader的hashcode,这个值需要用户通过sc -d com.example.demo.arthas.WelcomeController | grep classLoaderHash
实时获取
鼠标悬浮到message属性上,右击选择Arthas Command,继续选择Vmtool Get Instance Set Field,会弹出如下窗口:
标题 | 对应生成的命令 | 功能 |
---|---|---|
copy sc command | sc -d com.example.demo.arthas.WelcomeController | 获取类信息,上面有个空的框,需要填入WelcomeController类的classloader的hashcode,就可以直接通过该命令获取 |
在使用下面的2个命令前需要调用上面的命令拿到WelcomeController的classloader的hashcode,然后填充在上面的空格中。假如hashcode是1efbd816,那么下面的2个命令在生成后会额外加上-c 1efbd816 这个选项 | ||
copy instantces command | vmtool -x 1 --action getInstances --className com.example.demo.arthas.WelcomeController --limit 5 | 获取该类的所有实例信息(包括类的属性信息),如果jvm中有很多个该类的实例,只会输出前5个 |
copy invoke command | vmtool -x 3 --action getInstances --className com.example.demo.arthas.WelcomeController --express '#field=instances[0].getClass().getDeclaredField("message"),#field.setAccessible(true),#field.set(instances[0]," ")' | 反射给WelcomeController类的message属性赋值 |
举例说明:
在执行以下命令前,最好通过sc -d
命令获取到指定类的classloader的hashcode,然后-c hascode
拼接到以下命令中
例子 | vmtool命令 |
---|---|
强制gc | vmtool --action forceGc |
查看类信息,包括属性 | vmtool --action getInstances --className demo.MathGame --limit 10 |
调用实例方法 | vmtool --action getInstances --className demo.MathGame --express 'instances[0].primeFactors(3)' -x 3 |
查找String类型的对象,默认只看前10个。limit如果为-1,则返回所有 | vmtool --action getInstances --className java.lang.String -limit 10 |
查找 spring context | vmtool --action getInstances --className org.springframework.context.ApplicationContext |
查找所有的 spring beans 名字 | vmtool --action getInstances --className org.springframework.context.ApplicationContext --express 'instances[0].getBeanDefinitionNames()' |
调用userController.findUserById(),入参为1 | vmtool --action getInstances --className org.springframework.context.ApplicationContext --express 'instances[0].getBean("userController").findUserById(1)' |
直接获取 UserController 并调用findUserById(),入参为2 | vmtool --action getInstances --className com.example.demo.arthas.user.UserController --express 'instances[0].findUserById(2)' |
5. logger 查看logger信息,更新logger level
例子 | 命令 |
---|---|
查看所有logger信息 | logger |
查看指定名字的 logger 信息 | logger -n org.springframework.web |
更新 logger level | logger --name ROOT --level debug |
6. getstatic 查看类的静态属性
例子 | 命令 |
---|---|
查看类MathGame的静态属性random | getstatic -c 46fbb2c1 demo.MathGame random |
-c 46fbb2c1
是通过sc -d demo.MathGame
命令获取到该类的classloader的hashcde的值
7. ognl 执行 ognl 表达式
在 Arthas 里ognl
表达式是很重要的功能,在很多命令里都可以使用ognl
表达式。一些更复杂的用法可以参考:
例子 | 命令 |
---|---|
读取列表第一个元素 | ognl "{1,2,3,4}[0]" |
ognl "{10,20,30}[0].(#this > 5 ? #this*2 : #this+10)" | |
ognl "{1,2,3,4}.size()" | |
ognl "@java.lang.System@out.(print('Hello '), print('world\n'))" | |
ognl "1 in {2, 3}" | |
ognl "new int[9]" | |
执行多行表达式,赋值给临时变量,返回一个 List | ognl '#value1=@System@getProperty("java.home"), #value2=@System@getProperty("java.runtime.name"), {#value1, #value2}' |
获取静态类的静态字段 | ognl -c 目标类所属classloader的hashcode @com.example.demo.arthas.user.UserController@logger |
获取静态类的静态字段,且返回结果展开3层 | ognl -c 目标类所属classloader的hashcode -x 3 @com.example.demo.arthas.user.UserController@logger |
设置HelloService中的静态变量name的值 | ognl -x 3 '#field=@com.demo.HelloService@class.getDeclaredField("name"),#field.setAccessible(true),#field.set(null,"matio")' -c 1efbd816 |
8. 其他不重要的命令:heapdump、vmoption、sysprop、sysenv、
- heapdump:类似 jmap 命令的 heap dump 功能
- vmoption:查看,更新 VM 诊断相关的参数
- sysprop:可以打印所有的系统属性信息,也支持更新
- sysenv:命令可以获取到环境变量。两者用法类似
九、类命令
1. sc 读取class信息
“Search-Class” 的简写,这个命令能搜索出所有已经加载到 JVM 中的 Class 信息
读取指定class的classloader的hashcode:
sc -d demo.Controller | grep classLoaderHash
如果是接口,还会搜索所有的实现类:
sc javax.servlet.Filter
通过
-d
参数,可以打印出类加载的具体信息:sc -d javax.servlet.Filter
支持通配,比如搜索所有的
StringUtils
:sc *StringUtils
打印出类的 Field 信息:
sc -d -f demo.MathGame
2. sm 读取method信息
“Search-Method” 的简写,这个命令能搜索出所有已经加载了 Class 信息的方法信息。sm
命令只能看到由当前类所声明 (declaring) 的方法,父类则无法看到
通过
-d
参数可以打印方法的具体属性:sm -d java.math.RoundingMode
查找构造函数:
sm java.math.RoundingMode <init>
查找指定方法并打印详细信息:
sm -d java.lang.String toString
3. jad 反编译class
jad
命令将 JVM 中实际运行的 class 的 byte code 反编译成 java 代码,便于你理解业务逻辑;如需批量下载指定包的目录的 class 字节码可以参考dump
反编译时只显示源代码:
jad --source-only demo.MathGame
反编译指定函数:
jad demo.MathGame main
反编译时不显示行号:
jad demo.MathGame main --lineNumber false
反编译指定classloader加载的那个类:
jad -c 目标class所属classloader的hashcode org.apache.log4j.Logger
。我们可以通过sc -d org.apache.log4j.Logger | grep classLoaderHash
获取指定类所属classloader的hashcodejad 反编译的结果保存在/tmp/UserController.java本地文件:
jad --source-only com.example.demo.arthas.user.UserController > /tmp/UserController.java
4. retransform 热更新class文件
加载外部的.class
文件,需要保证该class已经被加载了
如果项目上线后发现有个java文件没有及时提交导致线上没有更新,这时我们可以使用该命令热更新该文件,但是有限制如下:
- 不允许新增加 field/method
- 正在跑的函数,没有退出不能生效
重新加载class文件:retransform /tmp/MathGame.class
加载指定的 .class 文件,然后解析出 class name,再 retransform jvm 中已加载的对应的类。每加载一个 .class
文件,则会记录一个 retransform entry。如果多次执行 retransform 加载同一个 class 文件,则会有多条 retransform entry.
查看 retransform entry:retransform -l
[arthas@2377]$ retransform -l
Id ClassName TransformCount LoaderHash LoaderClassName
1 demo.MathGame 1 null null
TransformCount 统计在 ClassFileTransformer#transform 函数里尝试返回 entry 对应的 .class 文件的次数,但并不表明 transform 一定成功。
如果对某个类执行 retransform 之后,想消除影响(就是还原),则需要:
- 删除这个类对应的 retransform entry
- 重新触发 retransform
如果不清除掉所有的 retransform entry,并重新触发 retransform ,则 arthas stop 时,retransform 过的类仍然生效。
5. 其他不重要的命令:mc、redefine、dump、classloader
- redefine:推荐使用retransform命令
- dump:下载bytecode文件到特定目录
- classloader:查看 classloader 的继承树,urls,类加载信息
- mc:编译
.java
文件生成.class
使用指定classloader编译java文件保存到指定位置(-d):mc -c 42a57993 -d /home/demo/test/ /home/demo/Test1.java /home/demo/Test2.java
十、增强命令
1. watch 查看方法调用的(入/出)参/返回值/异常信息
更多关于watch的使用:arthas.gitee.io/doc/watch.h… 或 arthas.aliyun.com/doc/arthas-…
<class-pattern> The full qualified class name you want to watch
<method-pattern> The method name you want to watch
-x, --expand <value> result中对象的显示层级,默认1,最大为4
-n, --limits <value> 最大执行次数
<express> 观察表达式,默认值:`{params, target, returnObj}`
Examples:
params
params[0]
'params[0]+params[1]'
'{params[0], target, returnObj}'
returnObj
throwExp
target
clazz
method
-b, --before 在函数调用之前观察,默认关闭
-e, --exception 在函数异常之后观察,默认关闭
-s, --success 在函数返回之后观察,默认关闭
-f, --finish 在函数结束之后(正常返回和异常返回)观察,默认打开
--exclude-class-pattern <value> exclude class name pattern, use either '.' or '/' as separator
-h, --help this help
--listenerId <value> The special listenerId
-m, --maxMatch <value> The maximum of matched class.
-E, --regex Enable regular expression to match (wildcard matching by default)
-M, --sizeLimit <value> Upper size limit in bytes for the result (10 * 1024 * 1024 by default)
-v, --verbose Enables print verbose information, default value false.
<condition-express> Conditional expression in ognl style, for example:
TRUE : 1==1
TRUE : true
FALSE : false
TRUE : 'params.length>=0'
FALSE : 1==2
'#cost>100'
在 watch 命令的结果里,会打印出location
信息。location
有三种可能值:AtEnter
,AtExit
,AtExceptionExit
。对应函数入口,函数正常 return,函数抛出异常
这里要注意
函数入参
和函数出参
的区别,有可能在中间被修改导致前后不一致,除了-b
事件点params
代表函数入参外,其余事件都代表函数出参
- 观察
primeFactors()
方法调用后的返回值:
watch demo.MathGame primeFactors returnObj
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 157 ms, listenerId: 1
method=demo.MathGame.primeFactors location=AtExceptionExit
ts=2024-04-23 07:55:59; [cost=0.565772ms] result=null
method=demo.MathGame.primeFactors location=AtExit
ts=2024-04-23 07:56:00; [cost=0.068512ms] result=@ArrayList[
@Integer[2],
@Integer[3],
@Integer[3],
@Integer[5],
@Integer[19],
@Integer[37],
]
因为命令中只观察了primeFactors()的返回值,所以result结果就是该方法返回值。我们就截取了2次调用输出如上所示,第一次result=null说明出现异常了(location=AtExceptionExit),二第二次就正常输出了一个ArrayList
- 观察
primeFactors()
方法出参、this 对象和返回值
watch demo.MathGame primeFactors -x 2
这里的-x 2
是指result返回对象只显示最多2层(x默认为1,最大为4)
method=demo.MathGame.primeFactors location=AtExceptionExit
ts=2024-04-23 12:05:56; [cost=0.025534ms] result=@ArrayList[
@Object[][
@Integer[-109004],
],
@MathGame[
random=@Random[java.util.Random@5afa04c],
illegalArgumentCount=@Integer[339],
],
null,
]
method=demo.MathGame.primeFactors location=AtExceptionExit
ts=2024-04-23 12:05:54; [cost=0.044902ms] result=@ArrayList[
@Object[][
@Integer[-163380],
],
@MathGame[
random=@Random[java.util.Random@5afa04c],
illegalArgumentCount=@Integer[338],
],
null,
]
method=demo.MathGame.primeFactors location=AtExit
ts=2024-04-23 12:05:55; [cost=0.026476ms] result=@ArrayList[
@Object[][
@Integer[1],
],
@MathGame[
random=@Random[java.util.Random@5afa04c],
illegalArgumentCount=@Integer[338],
],
@ArrayList[
@Integer[2],
@Integer[2],
@Integer[7],
@Integer[5011],
],
]
这里我们截取了3次结果,通过location知道只有第三次正常执行完成了。而且每个result中返回了3个对象,他们其实依次代表着{params, target, returnObj}
,也就是方法出参、this对象和返回值
- 观察
primeFactors()
方法入参
watch demo.MathGame primeFactors "{params,returnObj}" -x 2 -b
这里的-x 2
是指result返回对象只显示最多2层(x默认为1,最大为4)
-b
指的是在primeFactors()
方法调用之前观察
method=demo.MathGame.primeFactors location=AtEnter
ts=2024-04-23 12:13:06; [cost=0.010306ms] result=@ArrayList[
@Object[][
@Integer[-7315],
],
null,
]
method=demo.MathGame.primeFactors location=AtEnter
ts=2024-04-23 12:13:07; [cost=0.006734ms] result=@ArrayList[
@Object[][
@Integer[165981],
],
null,
]
method=demo.MathGame.primeFactors location=AtEnter
ts=2024-04-23 12:13:08; [cost=0.009809ms] result=@ArrayList[
@Object[][
@Integer[-140341],
],
null,
]
result中第一个元素就是指方法调用前参数,第二个参数就是返回值,因为这里观察的是方法调用前,所以获取不到返回值
- 同时观察方法调用前和方法返回后
watch demo.MathGame primeFactors "{params,target,returnObj}" -x 2 -b -s -n 2
这里的-x 2
是指result返回对象只显示最多2层(x默认为1,最大为4)
-b
指的是在primeFactors()
方法调用之前观察
-s
指的是在primeFactors()
方法调用之后观察
-n 2
表示只执行两次
[arthas@2091]$ watch demo.MathGame primeFactors "{params,target,returnObj}" -x 2 -b -s -n 2
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 29 ms, listenerId: 5
method=demo.MathGame.primeFactors location=AtEnter
ts=2024-04-23 12:20:01; [cost=0.019763ms] result=@ArrayList[
@Object[][
@Integer[-12188],
],
@MathGame[
random=@Random[java.util.Random@5afa04c],
illegalArgumentCount=@Integer[748],
],
null,
]
method=demo.MathGame.primeFactors location=AtEnter
ts=2024-04-23 12:20:02; [cost=0.008146ms] result=@ArrayList[
@Object[][
@Integer[-204858],
],
@MathGame[
random=@Random[java.util.Random@5afa04c],
illegalArgumentCount=@Integer[749],
],
null,
]
Command execution times exceed limit: 2, so command will exit. You can set it with -n option.
这里输出结果中,第一次输出的是方法调用前的观察表达式的结果,第二次输出的是方法返回后的表达式的结果 结果的输出顺序和事件发生的先后顺序一致,和命令中 -s -b
的顺序无关
- 当条件表达式满足时才会观察第一个出参和返回结果
watch demo.MathGame primeFactors "{params[0],target}" "params[0]<0"
method=demo.MathGame.primeFactors location=AtExceptionExit
ts=2024-04-23 12:31:58; [cost=0.0762ms] result=@ArrayList[
@Integer[-69352],
@MathGame[demo.MathGame@77cd7a0],
]
method=demo.MathGame.primeFactors location=AtExceptionExit
ts=2024-04-23 12:32:00; [cost=0.022681ms] result=@ArrayList[
@Integer[-137631],
@MathGame[demo.MathGame@77cd7a0],
]
params
代表出参,params[0]
代表第一个出参,"params[0]<0"
条件表达式代表当第一个出参小于0的时候才会有观察结果打印出来
只有满足条件的调用,才会有响应。
watch-express
单个值可以不加'{}',多个值需要加'{a,b,c}'。
condition-express
不能加'{}',可以使用逗号分隔子表达式,取表达式最后一个值来判断。
根据参数类型进行过滤(防止方法重载):watch demo.MathGame primeFactors '{params, params[0].class.name}' 'params[0].class.name == "java.lang.Integer"'
。前面是被观察的对象,后面是条件表达式
根据参数个数进行过滤:watch demo.MathGame primeFactors '{params, params.length}' 'params.length==1'
。前面是被观察的对象,后面是条件表达式
观察异常信息的例子:watch demo.MathGame primeFactors "{params[0],throwExp}" -e -x 2
-e
表示抛出异常时才触发- express 中,表示异常信息的变量是
throwExp
根据异常类型或者 message 进行过滤:watch demo.MathGame primeFactors '{params, throwExp}' '#msg=throwExp.toString(), #msg.contains("IllegalArgumentException")' -e -x 2
按照耗时进行过滤:watch demo.MathGame primeFactors '{params, returnObj}' '#cost>200' -x 2
。#cost>200
(单位是ms
) 表示只有当耗时大于 200ms 时才会输出,这样可以过滤掉执行时间小于 200ms 的调用
观察当前对象中的属性:watch demo.MathGame primeFactors 'target'
。如果想查看方法运行前后,当前对象中的属性,可以使用target
关键字,代表当前对象 ,然后使用target.field_name
访问当前对象的某个属性,比如:watch demo.MathGame primeFactors 'target.illegalArgumentCount'
2. monitor 监控某方法的调用次数、成功次数、失败次数等
监控的维度说明
监控项 | 说明 |
---|---|
timestamp | 时间戳 |
class | Java 类 |
method | 方法(构造方法、普通方法) |
total | 调用次数 |
success | 成功次数 |
fail | 失败次数 |
rt | 平均 RT |
fail-rate | 失败率 |
例子 | 命令 |
---|---|
间隔5s输出一次统计结果 | monitor -c 5 demo.MathGame primeFactors |
计算条件表达式过滤统计结果(方法执行完毕之后) | monitor -c 5 demo.MathGame primeFactors "params[0] <= 2" |
计算条件表达式过滤统计结果(方法执行完毕之前) | monitor -b -c 5 demo.MathGame primeFactors "params[0] <= 2" |
3. trace 输出方法内部调用路径,并输出方法路径上的每个节点上耗时
更多关于trace的使用:arthas.gitee.io/doc/trace.h…
当执行trace demo.MathGame run
命令时,如果run()被调用了,那么就会打印run()的内部调用链路和耗时
run()如下:
public void run() throws InterruptedException {
try {
int number = random.nextInt() / 10000;
List<Integer> primeFactors = primeFactors(number);
print(number, primeFactors);
} catch (Exception e) {
System.out.println(String.format("illegalArgumentCount:%3d, ", illegalArgumentCount) + e.getMessage());
}
}
run()执行了2次,就会打印2次内部调用链路和耗时:
`---ts=2024-04-26 11:25:05;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=jdk.internal.loader.ClassLoaders$AppClassLoader@46fbb2c1
`---[0.213813ms] demo.MathGame:run()
+---[1.99% 0.00425ms ] demo.MathGame:primeFactors() #24
`---[89.85% 0.192109ms ] demo.MathGame:print() #25
`---ts=2024-04-26 11:25:06;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=jdk.internal.loader.ClassLoaders$AppClassLoader@46fbb2c1
`---[0.236956ms] demo.MathGame:run()
`---[7.69% 0.018218ms ] demo.MathGame:primeFactors() #24 [throws Exception]
默认情况下,trace 不会包含 jdk 里的函数调用,如果希望 trace jdk 里的函数,需要显式设置--skipJDKMethod false
如果我们只想在run()调用耗时超过10ms的时候才输出其内部调用链路,可以这样写:
trace demo.MathGame run '#cost > 10'
使用 Arthas 的异步后台任务将结果存日志文件:运行 trace demo.MathGame run >> a.log &
,这时候任务已经在后台挂起,使用 jobs
查看当前后台运行的任务,之后可以使用 kill 指定任务 ID 将其结束。
使用 cat a.log
可以看到运行命令的输出已经重定向到了 a.log
文件中。
4. stack 输出当前方法被调用的调用路径
跟trace相反,更多关于stack的可以参考:arthas.gitee.io/doc/stack.h…
5. tt
记录下指定方法每次调用的入参和返回信息,并能对这些不同的时间下调用进行观测
记录下MathGame#primeFactors()的每次调用环境现场:tt -t -n 100 demo.MathGame primeFactors
[arthas@2238]$ tt -t -n 100 demo.MathGame primeFactors
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 141 ms, listenerId: 1
INDEX TIMESTAMP COST(ms) IS-RET IS-EXP OBJECT CLASS METHOD
-------------------------------------------------------------------------------------------------------------------------------------------------
1000 2024-04-28 11:12:39 0.602247 false true 0x61a52fbd MathGame primeFactors
1001 2024-04-28 11:12:40 0.06738 true false 0x61a52fbd MathGame primeFactors
1002 2024-04-28 11:12:41 0.077271 true false 0x61a52fbd MathGame primeFactors
1003 2024-04-28 11:12:42 0.025394 true false 0x61a52fbd MathGame primeFactors
1004 2024-04-28 11:12:43 0.029007 false true 0x61a52fbd MathGame
- -t:希望记录下类
*Test
的- -n 100:最多记录100次,防止遇到调用量非常大的方法,瞬间就能将JVM内存撑爆
表格字段 | 字段解释 |
---|---|
INDEX | 时间片段记录编号,每一个编号代表着一次调用,后续 tt 还有很多命令都是基于此编号指定记录操作,非常重要。 |
TIMESTAMP | 方法执行的本机时间,记录了这个时间片段所发生的本机时间 |
COST(ms) | 方法执行的耗时 |
IS-RET | 方法是否以正常返回的形式结束 |
IS-EXP | 方法是否以抛异常的形式结束 |
OBJECT | 执行对象的hashCode() ,注意,曾经有人误认为是对象在 JVM 中的内存地址,但很遗憾他不是。但他能帮助你简单的标记当前执行方法的类实体 |
CLASS | 执行的类名 |
METHOD | 执行的方法名 |
当print()存在重载方法时,可以通过以下方式确定目标方法:
- 只有一个参数:
tt -t *Test print params.length==1
- 第二个参数是Integer类型:
tt -t *Test print 'params[1] instanceof Integer'
- 指定参数值:
tt -t *Test print params[0].mobile=="13989838402"
如何现场还原
- 筛选出primeFactors()的调用信息:
tt -s 'method.name=="primeFactors"'
- 然后执行
tt -i 1003
可以查看INDEX=1003
本次的调用详情- 最后执行
tt -i 1003 -p
发起一次调用
通过tt获取到spring中任意bean,然后调用其某方法
- 记录invokeHandlerMethod()的每次执行情况:
tt -t org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter invokeHandlerMethod
- 当invokeHandlerMethod()被触发后会输出其执行情况
- 获取到spring context:
tt -i 1000 -w 'target.getApplicationContext()'
(-i 1000是指上面的invokeHandlerMethod()被触发后的INDEX)- 从spring context里获取任意bean:
tt -i 1000 -w 'target.getApplicationContext().getBean("helloWorldService").getHelloMessage()'
另外,在Dubbo里通过SpringExtensionFactory
获取spring context:ognl '#context=@com.alibaba.dubbo.config.spring.extension.SpringExtensionFactory@contexts.iterator.next, #context.getBean("userServiceImpl").findUser(1)'
参考:# Alibaba Arthas实践--获取到Spring Context,然后为所欲为
6. profiler 使用async-profiler生成火焰图
7. jfr
Java Flight Recorder (JFR) 是一种用于收集有关正在运行的 Java 应用程序的诊断和分析数据的工具。它集成到 Java 虚拟机 (JVM) 中,几乎不会造成性能开销,因此即使在负载较重的生产环境中也可以使用。