java-使用Arthas全链路统计方法调用链和执行耗时

java-使用Arthas全链路统计方法调用链和执行耗时

环境

• Springboot v1.5.6.RELEASE
• arthas 3.6.2

引言

在使用JMH框架对方法做完基准测试后，发现执行效果不理想。由于顶层方法调用的业务函数比较多，

需要优化的点不好定位。不知道是哪个方法有性能开销，想优化没有数据支持无从下手。

亟需一个能够全链路统计方法调用链和执行耗时工具。Arthas(阿尔萨斯)监控诊断产品中的trace命令完美解决了我的问题。

且Arthas是个非侵入式的，不会污染你的业务代码。

文档

• Arthas简介
• Arthas的treac命令

排查过程

运行Springboot应用

本地部署的、debug的、服务器上部署的，都可以。只要在相同的宿主机上运行Arthas即可。
这里使用bebug运行的应用。

运行Arthas

Arthas需要单独启动。

cd xxx/arthas-boot.jar  --定位到jar目录
java -jar arthas-boot.jar  --启动

启动后会打印java已启动的所有进程，选择需要监控的应用序号后回车即可；

[INFO] arthas-boot version: 3.6.2
[INFO] Process 2672 already using port 3658
[INFO] Process 2672 already using port 8563
[INFO] Found existing java process, please choose one and input the serial number of the process, eg : 1. Then hit ENTER.
* [1]: 2672 xxx.StartApplication
  [2]: 17056 xxx
  [3]: 19232 xxx

执行trace命令

选择应用后，将附加到该进程中，测试执行trace命令，附加到我们需要跟踪的类、方法上，进行统计；

语法：trace 类名 方法名

trace默认使用通配符匹配，如:监听testController下的所有方法

trace com.controller.testController

监听com.controller包下的所有方法

trace com.controller. *

注：trace监听的方法越多性能开销越大

[arthas@2672]$ trace com.controller.* * --trace命令
Press Q or Ctrl+C to abort.
Affect(class count: 2 , method count: 4) cost in 66 ms, listenerId: 6  -- 监听到2个类的4个方法
`---ts=2023-03-21 15:11:21;thread_name=http-nio-8080-exec-10;id=73;is_daemon=true;priority=5;TCCL=org.springframework.boot.context.embedded.tomcat.TomcatEmbeddedWebappClassLoader@3d67f2e
    `---[151.9948ms] xxx.test.getXxx()
        `---[99.96% 151.9402ms ] org.springframework.cglib.proxy.MethodInterceptor:intercept()
            `---[99.96% 151.8739ms ] xxx.test.getXxx()
                +---[74.63% 113.3481ms ] xxx.test.getXxx() #143
                |   `---[99.99% 113.3338ms ] xxx.test.getXxx()
                |       +---[76.14% 86.2936ms ] xxx.test.getXxx() #86
                |       |   `---[99.98% 86.273ms ] xxx.test.getXxx()
                |       |       `---[99.97% 86.246ms ] xxx.test.getXxx() #82
                |       +---[0.01% 0.0127ms ] xxx.test.getXxx() #88
                |       +---[0.01% 0.0082ms ] xxx.test.getXxx() #88
                |       `---[22.13% 25.0795ms ] xxx.test.getXxx() #91
                |           `---[32.16% 8.0653ms ] xxx.test.getXxx()
                |               `---[99.87% 8.0552ms ] xxx.test.getXxx() #93
                |                   `---[99.82% 8.0408ms ] xxx.test.getXxx()
                |                       +---[0.36% 0.0292ms ] xxx.test.getXxx() #99
                |                       +---[2.47% 0.1985ms ] xxx.test.getXxx() #100
                |                       +---[0.19% 0.0155ms ] xxx.test.getXxx() #106
                |                       +---[0.11% 0.0092ms ] xxx.test.getXxx() #112
                |                       +---[0.19% 0.0155ms ] xxx.test.getXxx() #113
                |                       +---[0.16% 0.0132ms ] xxx.test.getXxx() #115
                |                       +---[94.97% 7.636ms ] xxx.test.getXxx() #117
                |                       `---[0.23% 0.0187ms ] org.apache.commons.collections.CollectionUtils:isNotEmpty() #118
                +---[0.01% 0.011ms ] xxx.test.getXxx() #144
                +---[11.69% 17.7584ms ] xxx.test.getXxx() #144
                +---[0.01% 0.0127ms ] xxx.test.getXxx() #145
                +---[13.57% 20.6134ms ] xxx.test.getXxx() #145
                +---[0.01% min=0.0038ms,max=0.0107ms,total=0.0145ms,count=2] xxx.test.getXxx() #147
                +---[0.01% 0.0077ms ] xxx.test.getXxx() #147
                +---[0.00% 0.0049ms ] xxx.test.getXxx() #147
                `---[0.01% 0.0142ms ] xxx.test.getXxx() #147

总结

Arthas监控诊断产品功能比较多，可以帮助我们不停服务在线诊断问题。使用jmh配合Arthas可以进行吞吐量、平均执行时间等基础测试和性能监控分析，帮助开发人员科学定位性能瓶颈和优化点。