Arthas 简单使用

西瓜猿 6/28/2022 Arthas

Arthas 简单使用

注意：启动的时候必须要有 java 进程，同时启动arthas的账户要与将要诊断的进程具有相同的权限。

# 一、启动Arthas

在放有 arthas-boot.jar的目录运行命令

java -jar arthas-boot.jar

启动后会列出当前找到的所有的 java进程，通过输入数字后回车，选择我我们要诊断的进程。如下图，我要诊断math-game 进程，则输入 1 后回车。

启动成功 Arthas 会 attach 到目标进程上，并输出日志，可以看到命令行变为arthas@目标进程ID开头的。

# 二、查看 dashboard

输入dashboard按回车，会展示当前进程的实时信息，按ctrl+c可以中断执行。

展示信息基本如下图，注意：Java 8 之后才支持获取 JVM 内部线程 CPU 时间，这些线程只有名称和 CPU 时间，没有 ID 及状态等信息（显示 ID 为-1）。

# 三、thread命令查看线程信息

通过thread 空格线程 ID 可以打印线程的栈，还可以通过管道操作，筛选想要的信息。

如打印线程 1 的栈，并查找 main( 命令如下：

thread 1 | grep 'main('

参数 -n ，当前最忙的前 N 个线程并打印堆栈

// 找出当前最忙的 3 个并打印堆栈
thread -n 3

1
2

参数 -b ，找出当前阻塞其他线程的线程（可以用于排查应用卡住，一键找出罪魁祸首，但是目前只支持synchronized阻塞）

// 找出当前阻塞其他线程的线程
thread -b

1
2

参数 --state ，查看指定状态的线程

// 查看当前处于 WAITING 状态的线程
thread --state WAITING

1
2

参数--all ，显示所有线程，有时需要获取全部 JVM 的线程数据进行分析，就需要使用他啦。

// 显示所有线程
thread --all

1
2

参数 -i ，指定采样时间间隔（单位为毫秒，默认值为 200）

// 统计最近 1000ms 内的线程 CPU 时间
thread -i 1000
// 列出 1000ms 内最忙的 3 个线程栈
thread -n 3 -i 1000

1
2
3
4

不带任何参数时，默认按照 CPU 增量时间降序排列，只显示第一页数据

// 默认按照 CPU 增量时间降序排列，只显示第一页数据
thread

1
2

# 四、watch数据观测

watch 可以方便的观察到指定方法的调用情况。能观察到的范围为：返回值、抛出异常、入参，可以通过编写 OGNL 表达式进行对应变量的查看。 watch 命令定义了 4 个观察事件点，即-b函数调用前，-e函数异常后，-s 函数返回后，-f 函数结束后，只有-f默认打开，当指定观察点被打开后，在相应事件点会对观察表达式进行求值并输出。

# watch用例 1

例：观察 demo.MathGame 类中的 primeFactors 方法，在方法结束之后，观察入参和this 对象已及返回值，结果属性遍历深度为 2，命令如下

watch demo.MathGame primeFactors -x 2

结果如下

$ watch demo.MathGame primeFactors -x 2
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 32 ms, listenerId: 5
method=demo.MathGame.primeFactors location=AtExceptionExit
ts=2021-08-31 15:22:57; [cost=0.220625ms] result=@ArrayList[
    @Object[][
        @Integer[-179173],
    ],
    @MathGame[
        random=@Random[java.util.Random@31cefde0],
        illegalArgumentCount=@Integer[44],
    ],
    null,
]
method=demo.MathGame.primeFactors location=AtExit
ts=2021-08-31 15:22:58; [cost=1.020982ms] result=@ArrayList[
    @Object[][
        @Integer[1],
    ],
    @MathGame[
        random=@Random[java.util.Random@31cefde0],
        illegalArgumentCount=@Integer[44],
    ],
    @ArrayList[
        @Integer[2],
        @Integer[2],
        @Integer[26947],
    ],
]

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29

在上述的结果里，表示方法被执行了两次，第一次结果是location=AtExceptionExit，说明方法抛出异常了，因此returnObj是 null。在第二次结果里是location=AtExit，说明方法正常返回，因此可以看到returnObj结果是一个 ArrayList 注：location的值有三种：AtEnter（方法入口），AtExit（方法正常 return），AtExceptionExit（方法抛出异常）。

# watch用例 2

例：观察 demo.MathGame 类中的 primeFactors 方法调用入口的参数和返回值，结果属性遍历深度为 2，命令如下

watch demo.MathGame primeFactors "{params,returnObj}" -x 2 -b

结果如下

$ watch demo.MathGame primeFactors "{params,returnObj}" -x 2 -b
Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 50 ms.
ts=2018-12-03 19:23:23; [cost=0.0353ms] result=@ArrayList[
    @Object[][
        @Integer[-1077465243],
    ],
    null,
]

1
2
3
4
5
6
7
8
9

对比前一个例子，返回值为空（事件点为方法执行前，因此获取不到返回值）

# watch用例 3

例：观察 demo.MathGame 类中的 primeFactors 方法，同时观察方法调用前和方法返回后，表达式只执行两次，结果属性遍历深度为 2，命令如下

watch demo.MathGame primeFactors "{params,returnObj}" -x 2 -b -s -n 2

结果如下

$ watch demo.MathGame primeFactors "{params,returnObj}" -x 2 -b -s -n 2
Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 46 ms.
ts=2018-12-03 19:29:54; [cost=0.01696ms] result=@ArrayList[
    @Object[][
        @Integer[1],
    ],
    null,
]
ts=2018-12-03 19:29:54; [cost=4.277392ms] result=@ArrayList[
    @Object[][
        @Integer[1],
    ],
    @ArrayList[
        @Integer[2],
        @Integer[2],
        @Integer[2],
        @Integer[5],
        @Integer[5],
        @Integer[73],
        @Integer[241],
        @Integer[439],
    ],
]

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24

参数里-n 2，表示只执行两次输出结果中，第一次输出的是方法调用前的观察表达式的结果，第二次输出的是方法返回后的表达式的结果结果的输出顺序和事件发生的先后顺序一致，和命令中 -s -b 的顺序无关

# 五、通过 jad 来反编译指定类

将 JVM 中实际运行的类的字节码反编译成 java 代码，便于检查代码或理解业务逻辑。反编译出来的 java 代码可能会存在语法错误，但不影响进行阅读理解。例1：反编译 demo.MathGame 类得到运行中源码

jad demo.MathGame

例2：反编译 demo.MathGame 类中的 main 方法

jad demo.MathGame main

反编译方法

反编译如果要只显示源码，可以加上参数--source-only，不显示行数可以加上参数--lineNumber 指定为 false

反编译时指定 ClassLoader当有多个 ClassLoader 都加载了这个类时，jad 命令会输出对应 ClassLoader 实例的 hashcode，然后你只需要重新执行 jad 命令，并使用参数-c <hashcode> 就可以反编译指定 ClassLoader 加载的那个类了；

# 六、stack 输出当前方法调用路径

很多时候我们都知道一个方法被执行，但这个方法被执行的路径非常多，或者你根本就不知道这个方法是从那里被执行了，这个时候可以通过 stack 命令查看调用。例1：查看 demo.MathGame 类下 primeFactors 方法被调用路径

stack demo.MathGame primeFactors

结果如下

$ stack demo.MathGame primeFactors
Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 36 ms.
ts=2018-12-04 01:32:19;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69
    @demo.MathGame.run()
        at demo.MathGame.main(MathGame.java:16)

1
2
3
4
5
6

显示 demo.MathGame 类的main 方法，调用 run 方法，run 方法调用了该方法。

例 2：根据条件表达式过滤

// 根据第一个参数值小于 0 只显示两个
stack demo.MathGame primeFactors 'params[0]<0' -n 2

// 根据执行时间过滤，显示大于 5 ms 的
stack demo.MathGame primeFactors '#cost>5'

1
2
3
4
5

# 七、trace 显示内部调用路径，并输出方法路径上的每个节点上耗时

trace 可以帮助发现整个调用过程中耗时高的部分。

注意：trace 在执行的过程中本身是会有一定的性能开销。例：获取 demo.MathGame 类下 run 方法的耗时分部，只捕捉一次（如果不指定会一直捕捉）

trace demo.MathGame run -n 1

结果

$ trace demo.MathGame run
Press Q or Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 28 ms.
`---ts=2019-12-04 00:45:08;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69
    `---[0.617465ms] demo.MathGame:run()
        `---[0.078946ms] demo.MathGame:primeFactors() #24 [throws Exception]

`---ts=2019-12-04 00:45:09;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69
    `---[1.276874ms] demo.MathGame:run()
        `---[0.03752ms] demo.MathGame:primeFactors() #24 [throws Exception]

1
2
3
4
5
6
7
8
9
10

结果里的#24，表示在 run 方法里，在源文件的第24行调用了primeFactors()方法。 [0.078946ms] 的含义，0.078946的含义是：当前节点在当前步骤的耗时，单位为毫秒。 [0,0,0ms,11]类路径:方法名() [throws Exception]，对该方法中相同的方法调用进行了合并，0,0,0ms,11 表示方法调用耗时，min,max,total,count；throws Exception 表明该方法调用中存在异常返回。默认情况下，trace 不会包含jdk里的函数调用，如果希望 trace jdk 里的函数，需要显式设置--skipJDKMethod为 false。 trace的统计的报告中并未预先减去其自身的统计开销。所以这统计出来有些许的不准，渲染路径上调用的类、方法越多，性能偏差越大。

# 八、tt-方法执行数据的时空隧道

tt(TimeTunnel)方法执行数据的时空隧道，记录下指定方法每次调用的入参和返回信息，并能对这些不同的时间下调用进行观测 watch 虽然很方便和灵活，但需要提前想清楚观察表达式的拼写，这对排查问题而言要求太高，因为有时候我们并不清楚问题出自于哪里，只能靠蛛丝马迹进行猜测，这个时候如果能记录下当时方法调用的所有入参和返回值、抛出的异常会对整个问题的思考与判断非常有帮助。 注意:如果方法调用量特别大，一定要用-n指定次数，防止将JVM 内存撑爆

# tt 参数解析

tt的参数	说明
-t	记录某个方法在一个时间段中的调用
-l	显示所有已经记录的列表
-n 次数	只记录多少次
-s 表达式	搜索表达式
-i 索引号	查看指定索引号的详细调用信息
-p	重新调用指定的索引号时间碎片

-t

tt 命令有很多个主参数，-t 就是其中之一。这个参数表名记录下指定方法。
-n 3

当你执行一个调用量不高的方法时可能你还能有足够的时间用 CTRL+C 中断 tt 命令记录的过程，注意:如果遇到调用量非常大的方法，瞬间就能将你的 JVM 内存撑爆。

此时你可以通过 -n 参数指定你需要记录的次数，当达到记录次数时 Arthas 会主动中断tt命令的记录过程，避免人工操作无法停止的情况。

例1:记录demo.MathGame类下的primeFactors方法调用情况

tt -t demo.MathGame primeFactors

返回结果如下

# 返回结果表格字段说明

表格字段	字段解释
INDEX	时间片段记录编号，每一个编号代表着一次调用，后续tt还有很多命令都是基于此编号指定记录操作，非常重要。
TIMESTAMP	方法执行的本机时间，记录了这个时间片段所发生的本机时间
COST(ms)	方法执行的耗时
IS-RET	方法是否以正常返回的形式结束
IS-EXP	方法是否以抛异常的形式结束
OBJECT	执行对象的`hashCode()`，注意，曾经有人误认为是对象在JVM中的内存地址，但很遗憾他不是。但他能帮助你简单的标记当前执行方法的类实体
CLASS	执行的类名
METHOD	执行的方法名

条件表达式

不知道大家是否有在使用过程中遇到以下困惑
- Arthas 似乎很难区分出重载的方法
- 我只需要观察特定参数，但是 tt 却全部都给我记录了下来
条件表达式也是用 OGNL 来编写，核心的判断对象依然是 Advice 对象。除了 tt 命令之外，watch、trace、stack 命令也都支持条件表达式。
解决方法重载

tt -t *Test print params.length==1

通过制定参数个数的形式解决不同的方法签名，如果参数个数一样，你还可以这样写

tt -t *Test print 'params[1] instanceof Integer'
解决指定参数

tt -t *Test print params[0].mobile=="13989838402"

# 检索调用记录

当你用 tt 记录了一大片的时间片段之后，你希望能从中筛选出自己需要的时间片段，这个时候你就需要对现有记录进行检索。

tt -l

需要筛选出 primeFactors 方法的调用信息

tt -s 'method.name=="primeFactors"'

# 查看调用信息

对于具体一个时间片的信息而言，你可以通过 -i 参数后边跟着对应的 INDEX 编号查看到他的详细信息。

tt -i 1002

# 重做一次调用

当你稍稍做了一些调整之后，你可能需要前端系统重新触发一次你的调用，此时得求爷爷告奶奶的需要前端配合联调的同学再次发起一次调用。而有些场景下，这个调用不是这么好触发的。

tt 命令由于保存了当时调用的所有现场信息，所以我们可以自己主动对一个 INDEX 编号的时间片自主发起一次调用，从而解放你的沟通成本。此时你需要 -p 参数。通过 --replay-times 指定调用次数，通过 --replay-interval 指定多次调用间隔(单位ms, 默认1000ms)

tt -i 1002 -p

tt 重做调用需要注意
1. ThreadLocal 信息丢失
  
  很多框架偷偷的将一些环境变量信息塞到了发起调用线程的 ThreadLocal 中，由于调用线程发生了变化，这些 ThreadLocal 线程信息无法通过 Arthas 保存，所以这些信息将会丢失。
  
  一些常见的 CASE 比如：鹰眼的 TraceId 等。
2. 引用的对象
  
  tt 命令是将当前环境的对象引用保存起来，但仅仅也只能保存一个引用而已。如果方法内部对入参进行了变更，或者返回的对象经过了后续的处理，那么在 tt 查看的时候将无法看到当时最准确的值。这也是为什么 watch 命令存在的意义。

# 九、退出arthas

注意：monitor、watch、trace命令都会都通过字节码增强技术来实现的，会在指定类的方法中插入一些切面来实现数据统计和观测，因此请尽量明确需要观测的类、方法以及条件，诊断结束要执行 stop 或将增强过的类执行 reset 命令。

如果只是退出当前的连接，可以用quit或者exit命令。Attach 到目标进程上的 arthas 还会继续运行，端口会保持开放，下次连接时可以直接连接上。

如果想完全退出 arthas，可以执行stop命令。

# 十、卸载arthas

在 Linux/Unix/Mac 平台，删除下面文件即可

rm -rf ~/.arthas/
rm -rf ~/logs/arthas

1
2

# 十一、arthas开启执行结果保存日志

默认该功能是关闭的，如果需要开启，需执行命令开启

options save-result true

显示结果如下，则说明开启成功

注意：执行结果保存在{user.home}/logs/arthas-cache/result.log目录，如果开启，防止占用空间过大，建议定期清理该日志记录

# 十二、arthas常见异常

例 1

当我们连接目标线程时出现如下图

这种一般都是上次我们连接了其他进程，但是没有正常退出，可以换一个端口继续启动，或者继续连接上次的进程，然后执行 stop 命令结束连接。再次启动arthas，选择想要的进程即可正常连接。

Arthas安装 Arthas命令列表

西瓜空间站