Arthas 监控相关命令 watch/stack/trace/minitor/tt
前面我们学习了 sm/sc/jad/mc/redefine等命令，适用于类相关的命令，今天我们来看下其他的命令，包括 watch/stack/trace/minitor/tt 特别是stack, watch，trace这三个，是日常我们项目工作时候必须的几个功能
1.演示代码
现在我们的TestController 有一段下面的代码，我们来演示一下 watch
@GetMapping("/print")
private String getScore(Integer score) {
log.debug("debug ===========");
log.info("info ===========");
log.error("error ===========");
//输入分数超过 100， 就取100，否则返回真正的分数
if (score > 100) {
return "10";
}
return String.valueOf(score);
}
2.watch 查看方法信息
watch 命令主要用于查看线上的方法，入参，返回值等信息
- 1、查看方法入参、返回值
- 2、过滤无用的输出
- 3、查看类中的成员变量
- 4、无法查看方法中的局部变量
我们查看方法入参和返回值信息
执行 watch com.jzj.jvmtest.font.TestController getScore '{params,returnObj}' -x 3 什么意思？
- watch 监控类 com.jzj.jvmtest.font.TestController
- TestController 的方法getScore
- 方法的 {params,returnObj} 参数，返回值
- -x 3 输出对象 深度遍历3层
执行后等待，然后另开一个窗口，去访问该 TestController的 getScore方法，看是否能够监控到输入输出信息
[arthas@13016]$ watch com.jzj.jvmtest.font.TestController getScore '{params,returnObj}' -x 3
Press Q or Ctrl+C to abort.
我们执行该方法 3次， 分别是
- curl 127.0.0.1:8078/print?score=44
- curl 127.0.0.1:8078/print?score=55
- curl 127.0.0.1:8078/print?score=66 执行日志如下
PS C:\Users\jzj> curl 127.0.0.1:8078/print?score=44
StatusCode : 200
Content : 44
PS C:\Users\jzj> curl 127.0.0.1:8078/print?score=55
StatusCode : 200
Content : 55
PS C:\Users\jzj> curl 127.0.0.1:8078/print?score=66
StatusCode : 200
Content : 66
watch检测的返回之信息如下
- 第一次 输入是@Integer[44], 返回是 @String[44]
- 第二次 输入是@Integer[55], 返回是 @String[55],
- 第三次 输入是@Integer[66], 返回是 @String[66],
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 32 ms, listenerId: 4
method=com.jzj.jvmtest.font.TestController.getScore location=AtExit
ts=2023-05-07 12:56:03; [cost=0.3413ms] result=@ArrayList[
@Object[][
@Integer[44],
],
@String[44],
]
method=com.jzj.jvmtest.font.TestController.getScore location=AtExit
ts=2023-05-07 12:56:05; [cost=0.2543ms] result=@ArrayList[
@Object[][
@Integer[55],
],
@String[55],
]
method=com.jzj.jvmtest.font.TestController.getScore location=AtExit
ts=2023-05-07 12:56:07; [cost=0.2831ms] result=@ArrayList[
@Object[][
@Integer[66],
],
@String[66],
]
我们还可以过滤 不需要的请求，输入参数是55的不监控
执行命令，过滤参数
watch com.jzj.jvmtest.font.TestController getScore '{params,returnObj}' "params[0]==55" -x 3
[arthas@13016]$ watch com.jzj.jvmtest.font.TestController getScore '{params,returnObj}' "params[0]==55" -x 3
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 33 ms, listenerId: 7
method=com.jzj.jvmtest.font.TestController.getScore location=AtExit
ts=2023-05-07 13:08:15; [cost=0.2861ms] result=@ArrayList[
@Object[][
@Integer[55],
],
@String[55],
]
method=com.jzj.jvmtest.font.TestController.getScore location=AtExit
ts=2023-05-07 13:08:30; [cost=0.2492ms] result=@ArrayList[
@Object[][
@Integer[55],
],
@String[55],
连续访问3次 PS C:\Users\jzj> curl 127.0.0.1:8078/print?score=“55” PS C:\Users\jzj> curl 127.0.0.1:8078/print?score=“55” PS C:\Users\jzj> curl 127.0.0.1:8078/print?score=“66”
可以看到监控结果， 只输出了 监控输入参数 55的 请求, 66的被过滤掉
3.trace 追踪方法耗时
神器，我们可以用trace 命令，查该方法的调用链路及耗时信息,trace可以统计整个调用链路上的所有性能开销和追踪调用链路。监控整个调用路径的耗时，找出真正的性能瓶颈，耗时方法，进而解决问题
还是之前的例子，我们用trace 来追踪 TestController getScore方法的耗时信息
执行 trace com.jzj.jvmtest.font.TestController getScore
[arthas@13016]$ trace com.jzj.jvmtest.font.TestController getScore
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 51 ms, listenerId: 8
`---ts=2023-05-07 13:11:54;thread_name=http-nio-8078-exec-4;id=2d;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@7e22550a
`---[0.3982ms] com.jzj.jvmtest.font.TestController:getScore()
+---[7.38% 0.0294ms ] org.slf4j.Logger:debug() #19
+---[41.99% 0.1672ms ] org.slf4j.Logger:info() #20
`---[20.77% 0.0827ms ] org.slf4j.Logger:error() #21
`---ts=2023-05-07 13:11:56;thread_name=http-nio-8078-exec-5;id=2e;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@7e22550a
`---[0.2815ms] com.jzj.jvmtest.font.TestController:getScore()
+---[3.37% 0.0095ms ] org.slf4j.Logger:debug() #19
+---[52.18% 0.1469ms ] org.slf4j.Logger:info() #20
`---[29.24% 0.0823ms ] org.slf4j.Logger:error() #21
可以看到执行结果，把所有的方法调用耗时全都打印出来了
- 链路 7.38%的耗时 花费时间0.0294ms 19行Logger:debug() 方法
- 链路 41.99%的耗时 花费时间0.1672ms 20行Logger:info() 方法
- 链路 20.77%的耗时 花费时间0.0827ms 21行Logger:error() 方法
4.stack 获取调用堆栈
神器，用于线上环境，我们看下调用链路，到底某个方法走到了没有走到, 命令 stack 类， 方法
执行 stack com.jzj.jvmtest.font.TestController getScore
然后访问请求 curl 127.0.0.1:8078/print?score=“66” 监控此方法的调用堆栈
[arthas@13016]$ stack com.jzj.jvmtest.font.TestController getScore
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 33 ms, listenerId: 9
ts=2023-05-07 13:13:28;thread_name=http-nio-8078-exec-8;id=31;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@7e22550a
@com.jzj.jvmtest.font.TestController.getScore()
at jdk.internal.reflect.GeneratedMethodAccessor26.invoke(null:-1)
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:568)
5.minitor 监控类方法的 成功率，失败次数等
minitor 适用于监控类 方法的 成功率，失败率，等信息
| 监控项 | 说明 |
|---|---|
| timestamp | 时间戳 |
| class | Java类 |
| method | 方法（构造方法、普通方法） |
| total | 方法调用次数 |
| success | 方法成功次数 |
| fail | 方法失败次数 |
| rt | 方法平均RT |
| fail-rate | 方法失败率 |
monitor -c 5 com.jzj.jvmtest.font.TestController getScore 表示每 5 秒，打印一次 TestController 的方法getScore的监控信息
**执行 minitor **
[arthas@13016]$ monitor -c 5 com.jzj.jvmtest.font.TestController getScore
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 37 ms, listenerId: 10
timestamp class method total success fail avg-rt(ms) fail-rate
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
2023-05-07 13:23:49 com.jzj.jvmtest.font.TestController getScore 1 1 0 0.32 0.00%
timestamp class method total success fail avg-rt(ms) fail-rate
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
2023-05-07 13:23:54 com.jzj.jvmtest.font.TestController getScore 1 1 0 0.22 0.00%
timestamp class method total success fail avg-rt(ms) fail-rate
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
2023-05-07 13:23:59 com.jzj.jvmtest.font.TestController getScore 3 3 0 0.24 0.00%
timestamp class method total success fail avg-rt(ms) fail-rate
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
2023-05-07 13:24:04 com.jzj.jvmtest.font.TestController getScore 2 2 0 0.27 0.00%
timestamp class method total success fail avg-rt(ms) fail-rate
监控结果如下 ，每5秒一次监控统计信息
至此我们已经学会了大部分Arthas的监控命令，watch查看类方法输入输出信息，trace链路追踪排查最耗时的方法调用，stack打印类方法调用堆栈信息，minitor监控方法调用信息
