昔年浅巷

昔年浅巷

JAVA线上排查利器arthas（阿尔萨斯）之使用篇

技术
31
2024-10-19

前言

Arthas 是一款线上监控诊断产品，通过全局视角实时查看应用 load、内存、gc、线程的状态信息，并能在不修改应用代码的情况下，对业务问题进行诊断，包括查看方法调用的出入参、异常，监测方法执行耗时，类加载信息等，大大提升线上问题排查效率。

简单的使用

从github上下载资源包

https://github.com/alibaba/arthas/releases

用 arthas-boot .jar 启动

PS C:\Users\39242\Desktop\arthas> java -jar C:\Users\39242\Desktop\arthas\arthas-boot.jar
[INFO] JAVA_HOME: C:\Program Files\Java\jdk-17
[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]: 21348 org.hzaw.qbittorrentmanagerservice.QbittorrentManagerServiceApplication
  [2]: 3896
  [3]: 6536 org.jetbrains.jps.cmdline.Launcher
  [4]: 26476 org.jetbrains.idea.maven.server.RemoteMavenServer36

选择指定的应用后，arthas会自动连接应用会话即可开始调试。

常用命令

trace

方法内部调用路径，并输出方法路径上的每个节点上耗时

trace 命令能主动搜索 class-pattern／method-pattern 对应的方法调用路径，渲染和统计整个调用链路上的所有性能开销和追踪调用链路。

参数说明

参数名称参数说明
class-pattern类名表达式匹配
method-pattern方法名表达式匹配
condition-express条件表达式
[E]开启正则表达式匹配，默认为通配符匹配
[n:]命令执行次数
#cost方法执行耗时
[m <arg>]指定 Class 最大匹配数量，默认值为 50。长格式为[maxMatch <arg>]

最简单的使用方式，先试用sc命令搜索指定的类路径，然后再使用trace直接监控方法的节点耗时。

[arthas@21348]$ sc *UserInfoController*
org.hzaw.qbittorrentmanagerservice.controller.UserInfoController
Affect(row-cnt:1) cost in 20 ms.
[arthas@21348]$ trace org.hzaw.qbittorrentmanagerservice.controller.UserInfoController batchInsertOneByOne
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 78 ms, listenerId: 1
`---ts=2024-03-13 22:31:59;thread_name=http-nio-7758-exec-1;id=52;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@664212ab
    `---[271.3667ms] org.hzaw.qbittorrentmanagerservice.controller.UserInfoController:batchInsertOneByOne()
        +---[99.88% 271.0498ms ] org.hzaw.qbittorrentmanagerservice.service.UserInfoService:batchInsertOneByOne() #34
        `---[0.04% 0.1067ms ] org.hzaw.utils.entity.response.AppResult:success() #35

`---ts=2024-03-13 22:32:52;thread_name=http-nio-7758-exec-3;id=54;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@664212ab
    `---[9401.6336ms] org.hzaw.qbittorrentmanagerservice.controller.UserInfoController:batchInsertOneByOne()
        +---[100.00% 9401.5842ms ] org.hzaw.qbittorrentmanagerservice.service.UserInfoService:batchInsertOneByOne() #34
        `---[0.00% 0.0061ms ] org.hzaw.utils.entity.response.AppResult:success() #35

使用 --skipJDKMethod <value> 命令输出JDK内部的方法的耗时

[arthas@21348]$ sc *UserInfoService*
org.hzaw.qbittorrentmanagerservice.service.UserInfoService
org.hzaw.qbittorrentmanagerservice.service.impl.UserInfoServiceImpl
org.hzaw.qbittorrentmanagerservice.service.impl.UserInfoServiceImpl$$SpringCGLIB$$0
Affect(row-cnt:3) cost in 18 ms.
yOnehas@21348]$  trace --skipJDKMethod false org.hzaw.qbittorrentmanagerservice.service.UserInfoService batchInsertOneB
Press Q or Ctrl+C to abort.
Affect(class count: 3 , method count: 2) cost in 76 ms, listenerId: 2
`---ts=2024-03-13 22:33:50;thread_name=http-nio-7758-exec-4;id=55;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@664212ab
    `---[7896.0368ms] org.hzaw.qbittorrentmanagerservice.service.impl.UserInfoServiceImpl$$SpringCGLIB$$0:batchInsertOneByOne()
        `---[100.00% 7895.9968ms ] org.springframework.cglib.proxy.MethodInterceptor:intercept()
            `---[100.00% 7895.9508ms ] org.hzaw.qbittorrentmanagerservice.service.impl.UserInfoServiceImpl:batchInsertOneByOne()
                +---[0.00% 0.0106ms ] com.google.common.collect.Lists:newArrayList() #91
                +---[0.00% 0.0164ms ] cn.hutool.core.date.DateUtil:timer() #92
                +---[0.00% 0.0872ms ] cn.hutool.core.util.IdUtil:getSnowflake() #93
                +---[0.00% min=0.0024ms,max=0.0067ms,total=0.0091ms,count=2] org.hzaw.qbittorrentmanagerservice.pojo.request.DebugParamsDTO:getLoopIndex() #94
                +---[0.00% 0.0056ms ] java.util.ArrayList:clear() #95
                +---[0.00% min=0.001ms,max=0.013ms,total=0.1608ms,count=101] org.hzaw.qbittorrentmanagerservice.pojo.request.DebugParamsDTO:getIndexNum() #96
                +---[0.00% min=8.0E-4ms,max=0.0072ms,total=0.1389ms,count=100] org.hzaw.qbittorrentmanagerservice.entity.UserInfo:<init>() #97
                +---[0.01% min=7.0E-4ms,max=0.0447ms,total=0.406ms,count=300] cn.hutool.core.util.RandomUtil:randomChinese() #98
                +---[0.00% min=0.0013ms,max=0.0796ms,total=0.305ms,count=100] java.lang.String:format() #98
                +---[0.00% min=9.0E-4ms,max=0.0439ms,total=0.1964ms,count=100] org.hzaw.qbittorrentmanagerservice.entity.UserInfo:setNickName() #98
                +---[0.00% min=8.0E-4ms,max=0.0313ms,total=0.3734ms,count=300] cn.hutool.core.util.RandomUtil:randomChinese() #99
                +---[0.00% min=0.0013ms,max=0.0088ms,total=0.2041ms,count=100] java.lang.String:format() #99
                +---[0.00% min=9.0E-4ms,max=0.0087ms,total=0.1515ms,count=100] org.hzaw.qbittorrentmanagerservice.entity.UserInfo:setName() #99
                +---[0.00% min=9.0E-4ms,max=0.0239ms,total=0.1631ms,count=100] org.hzaw.qbittorrentmanagerservice.entity.UserInfo:setSex() #100
                +---[0.00% min=8.0E-4ms,max=0.0162ms,total=0.1364ms,count=100] cn.hutool.core.util.RandomUtil:randomInt() #101
                +---[0.00% min=9.0E-4ms,max=0.0234ms,total=0.1637ms,count=100] org.hzaw.qbittorrentmanagerservice.entity.UserInfo:setAge() #101
                +---[0.00% min=9.0E-4ms,max=0.0232ms,total=0.1596ms,count=100] org.hzaw.qbittorrentmanagerservice.entity.UserInfo:setRemark() #102
                +---[0.00% min=0.0011ms,max=0.0209ms,total=0.244ms,count=100] java.time.LocalDateTime:now() #103
                +---[0.00% min=9.0E-4ms,max=0.0058ms,total=0.1427ms,count=100] org.hzaw.qbittorrentmanagerservice.entity.UserInfo:setCreateTime() #103
                +---[0.00% min=9.0E-4ms,max=0.0256ms,total=0.1742ms,count=100] org.hzaw.qbittorrentmanagerservice.entity.UserInfo:setCreateUser() #104
                +---[0.00% min=0.001ms,max=0.0294ms,total=0.2374ms,count=100] java.time.LocalDateTime:now() #105
                +---[0.00% min=9.0E-4ms,max=0.0052ms,total=0.1442ms,count=100] org.hzaw.qbittorrentmanagerservice.entity.UserInfo:setUpdateTime() #105
                +---[0.00% min=9.0E-4ms,max=0.0238ms,total=0.1714ms,count=100] org.hzaw.qbittorrentmanagerservice.entity.UserInfo:setUpdateUser() #106
                +---[0.00% min=9.0E-4ms,max=0.0055ms,total=0.1418ms,count=100] org.hzaw.qbittorrentmanagerservice.entity.UserInfo:setStatus() #107
                +---[0.00% min=9.0E-4ms,max=0.0096ms,total=0.1438ms,count=100] org.hzaw.qbittorrentmanagerservice.entity.UserInfo:setIdType() #108
                +---[0.00% min=0.0012ms,max=0.0125ms,total=0.1971ms,count=100] cn.hutool.core.lang.Snowflake:nextIdStr() #109
                +---[0.00% min=0.0015ms,max=0.0246ms,total=0.2375ms,count=100] cn.hutool.core.util.RandomUtil:randomString() #109
                +---[0.00% min=9.0E-4ms,max=0.0426ms,total=0.191ms,count=100] org.hzaw.qbittorrentmanagerservice.entity.UserInfo:setIdno() #109
                +---[0.00% min=8.0E-4ms,max=0.0059ms,total=0.1267ms,count=100] java.util.ArrayList:add() #110
                +---[0.00% 0.0057ms ] com.baomidou.mybatisplus.core.batch.MybatisBatch:<init>() #113
                +---[0.00% 0.0048ms ] com.baomidou.mybatisplus.core.batch.MybatisBatch$Method:<init>() #114
                +---[0.00% 0.0074ms ] com.baomidou.mybatisplus.core.batch.MybatisBatch$Method:insert() #115
                +---[99.87% 7885.5157ms ] com.baomidou.mybatisplus.core.batch.MybatisBatch:execute() #115
                +---[0.00% 0.0093ms ] cn.hutool.core.date.TimeInterval:interval() #117
                `---[0.00% 0.2491ms ] org.slf4j.Logger:info() #117

一些简单的指令实例

# 观测方法内部调用顺序及耗时
trace org.hzaw.qbittorrentmanagerservice.service.UserInfoService helloUser

# 观测方法内部调用顺序及耗时,只观测3次
trace org.hzaw.qbittorrentmanagerservice.service.UserInfoService helloUser -n 3

# 观测方法内部调用顺序及耗时,包含jdk内部方法
trace org.hzaw.qbittorrentmanagerservice.service.UserInfoService helloUser --skipJDKMethod false

# 限制观测范围，第一个参数长度大于10
trace org.hzaw.qbittorrentmanagerservice.service.UserInfoService helloUser params[0].length>=10

# 限制观测范围，执行耗时大于100ms
trace org.hzaw.qbittorrentmanagerservice.service.UserInfoService helloUser '#cost>100'

# trace 同时多个类的多个方法
trace -E com.test.ClassA|org.test.ClassB method1|method2|method3

thread

查看当前线程信息，查看线程的堆栈

参数说明

参数名称参数说明
id线程 id
[n:]指定最忙的前 N 个线程并打印堆栈
[b]找出当前阻塞其他线程的线程
[i <value>]指定 cpu 使用率统计的采样间隔，单位为毫秒，默认值为 200
[--all]显示所有匹配的线程

sc 命令

“Search-Class” 的简写，这个命令能搜索出所有已经加载到 JVM 中的 Class 信息，这个命令支持的参数有 [d]、[E]、[f] 和 [x:]。

参数说明

参数名称参数说明
class-pattern类名表达式匹配
method-pattern方法名表达式匹配
[d]输出当前类的详细信息，包括这个类所加载的原始文件来源、类的声明、加载的 ClassLoader 等详细信息。 如果一个类被多个 ClassLoader 所加载，则会出现多次
[E]开启正则表达式匹配，默认为通配符匹配
[f]输出当前类的成员变量信息（需要配合参数-d 一起使用）
[x:]指定输出静态变量时属性的遍历深度，默认为 0，即直接使用 toString 输出
[c:]指定 class 的 ClassLoader 的 hashcode
[classLoaderClass:]指定执行表达式的 ClassLoader 的 class name
[n:]具有详细信息的匹配类的最大数量（默认为 100）
[cs <arg>]指定 class 的 ClassLoader#toString() 返回值。长格式[classLoaderStr <arg>]

使用参考

  • 模糊匹配

    [arthas@7464]$ sc *UserInfoController*
org.hzaw.qbittorrentmanagerservice.controller.UserInfoController
Affect(row-cnt:1) cost in 23 ms.

  • 打印类的详细信息

    [arthas@7464]$ sc -d *UserInfoController*
 class-info        org.hzaw.qbittorrentmanagerservice.controller.UserInfoController
 code-source       /C:/Users/86156/Desktop/idea-project/common-base/qbittorrent-manager-service/target/classes/
 name              org.hzaw.qbittorrentmanagerservice.controller.UserInfoController
 isInterface       false
 isAnnotation      false
 isEnum            false
 isAnonymousClass  false
 isArray           false
 isLocalClass      false
 isMemberClass     false
 isPrimitive       false
 isSynthetic       false
 simple-name       UserInfoController
 modifier          public
 annotation        org.springframework.web.bind.annotation.RestController,org.springframework.web.bind.annotation.Requ
                   estMapping
 interfaces
 super-class       +-java.lang.Object
 class-loader      +-jdk.internal.loader.ClassLoaders$AppClassLoader@63947c6b
                     +-jdk.internal.loader.ClassLoaders$PlatformClassLoader@cdcf812
 classLoaderHash   63947c6b

Affect(row-cnt:1) cost in 26 ms.

  • 打印出类的 Field 信息

    [arthas@7464]$ sc -d -f org.hzaw.qbittorrentmanagerservice.controller.UserInfoController
 class-info        org.hzaw.qbittorrentmanagerservice.controller.UserInfoController
 code-source       /C:/Users/86156/Desktop/idea-project/common-base/qbittorrent-manager-service/target/classes/
 name              org.hzaw.qbittorrentmanagerservice.controller.UserInfoController
 isInterface       false
 isAnnotation      false
 isEnum            false
 isAnonymousClass  false
 isArray           false
 isLocalClass      false
 isMemberClass     false
 isPrimitive       false
 isSynthetic       false
 simple-name       UserInfoController
 modifier          public
 annotation        org.springframework.web.bind.annotation.RestController,org.springframework.web.bind.annotation.Requ
                   estMapping
 interfaces
 super-class       +-java.lang.Object
 class-loader      +-jdk.internal.loader.ClassLoaders$AppClassLoader@63947c6b
                     +-jdk.internal.loader.ClassLoaders$PlatformClassLoader@cdcf812
 classLoaderHash   63947c6b
 fields            name       userInfoService
                   type       org.hzaw.qbittorrentmanagerservice.service.UserInfoService
                   modifier
                   annotation jakarta.annotation.Resource


Affect(row-cnt:1) cost in 12 ms.

profiler 命令

profiler 命令支持生成应用热点的火焰图。本质上是通过不断的采样，然后把收集到的采样结果生成火焰图。

参数说明

参数名称参数说明
action要执行的操作
actionArg属性名模式
[i:]采样间隔（单位：ns）（默认值：10'000'000，即 10 ms）
[f:]将输出转储到指定路径
[d:]运行评测指定秒
[e:]要跟踪哪个事件（cpu, alloc, lock, cache-misses 等），默认是 cpu

参考资料

arthas Java 应用诊断利器

arthas 常用命令

#Java 3
DOCKER魔法
Spring事务简单回顾