Java 诊断利器 Arthas monitor/watch/trace命令

一、监控相关命令介绍

二、监控相关命令

2.1、运行Demo

2.2、monitor 命令

2.2.1、方法监控

2.3、watch 命令 （重要）

2.3.1、观察函数调用返回时的参数、this 对象和返回值

2.3.2、查看函数调用的入参和返回值

2.3.3、深度遍历 x 说明

2.3.4、查看方法调用前和函数返回后的值

2.4、trace 命令（重要）

2.4.1、查看方法耗时情况

2.4.2、据调用耗时过滤（重要）

2.4.3、包含 JDK 函数

2.4.4、trace 多个类或者多个函数

2.5、stack 命令（重要）

2.5.1、查看方法被调用的调用情况

2.5.2、根据条件表达式来过滤

---

一、监控相关命令介绍

        stack、trace、watch 线上使用比较多，本篇会详细介绍这几个命令。

命令	说明
monitor	方法执行监控
stack	输出当前方法被调用的调用路径
trace	方法内部调用路径，并输出方法路径上的每个节点上耗时
watch	方法执行数据观测

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

watch/stack/trace这个三个命令都支持#cost

二、监控相关命令

2.1、运行Demo

        在官方提供的 arthas（ arthas-bin.zip）程序中，提供一个 math-game.jar 的 demo ，本章就通过该demo进行演示。

        运行 math-game.jar

java -jar math-game.jar 

        启动 arthas 连接到该 java 程序

        math-game 的源代码如下： 

https://github.com/alibaba/arthas/blob/master/math-game/src/main/java/demo/MathGame.java

public List<Integer> primeFactors(int number) {
    if (number < 2) {
        illegalArgumentCount++;
        throw new IllegalArgumentException("number is: " + number + ", need >= 2");
    }

    List<Integer> result = new ArrayList<Integer>();
    int i = 2;
    while (i <= number) {
        if (number % i == 0) {
            result.add(i);
            number = number / i;
            i = 2;
        } else {
            i++;
        }
    }

    return result;
}

2.2、monitor 命令

        对匹配 class-pattern／method-pattern／condition-express的类、方法的调用进行监控。

        monitor 命令是一个非实时返回命令，实时返回命令是输入之后立即返回，而非实时返回的命令，则是不断的等待目标 Java 进程返回信息，直到用户输入 Ctrl+C 为止。

        服务端是以任务的形式在后台跑任务，植入的代码随着任务的中止而不会被执行，所以任务关闭后，不会对原有性能产生太大影响。

参数：

        方法拥有一个命名参数 [c:]，意思是统计周期（cycle of output），拥有一个整型的参数值

参数名称	参数说明
class-pattern	类名表达式匹配
method-pattern	方法名表达式匹配
condition-express	条件表达式
[E]	开启正则表达式匹配，默认为通配符匹配
[c:]	统计周期，默认值为120秒
[b]	在方法调用之前计算condition-express

使用说明：

        2.2.1、方法监控

        查看 MathGame 类中 primeFactors方法的运行情况，默认值为120秒输出一次结果，可以通过 -c 指定统计周期，按 Q 或者 Ctrl+C 来终止。

monitor demo.MathGame primeFactors

         每隔 5s 统计一次方法运行情况。

monitor demo.MathGame primeFactors -c 5 

数据说明：

监控项	说明
timestamp	时间戳
class	Java类
method	方法（构造方法、普通方法）
total	调用次数
success	成功次数
fail	失败次数
rt	平均RT
fail-rate	失败率

2.3、watch 命令 （重要）

        函数执行数据观测，让你能方便的观察到指定函数的调用情况。能观察到的范围为：返回值、抛出异常、入参，通过编写 OGNL 表达式进行对应变量的查看。

参数：

        watch 的参数比较多，主要是因为它能在 4 个不同的场景观察对象 —— 函数调用之前，函数异常之后，函数返回之后，函数结束之后。

参数名称	参数说明
class-pattern	类名表达式匹配
method-pattern	函数名表达式匹配
express	观察表达式，默认值：{params, target, returnObj}
condition-express	条件表达式
[b]	在函数调用之前观察
[e]	在函数异常之后观察
[s]	在函数返回之后观察
[f]	在函数结束之后(正常返回和异常返回)观察
[E]	开启正则表达式匹配，默认为通配符匹配
[x:]	指定输出结果的属性遍历深度，默认为 1

        观察表达式的构成主要由 ognl 表达式组成，所以你可以这样写"{params,returnObj}"，只要是一个合法的 ognl 表达式，都能被正常支持。

        OGNL 表达式官网：

        https://commons.apache.org/proper/commons-ognl/language-guide.html

使用说明：

        2.3.1、观察函数调用返回时的参数、this 对象和返回值

        查看 demo.MathGame 类中 primeFactors 方法出参和返回值

watch demo.MathGame primeFactors

• 观察表达式，默认值是{params, target, returnObj}，params 是入参，target 是 this 对象，returnObj 是返回值
• 函数被执行了两次，第一次结果是location=AtExit，说明函数正常返回，因此可以看到returnObj结果是一个 ArrayList
• 第二次结果里是location=AtExceptionExit，说明函数抛出异常了，因此 returnObj 是 null
• ts 是时间戳，表示当前方法执行时间，cost 是指当前方法耗时
• 默认深度遍历x=1，只显示最外层对象属性，入参 Object 表示入参是个对象，返回值为 ArrayList 表示返回是个对象数组

        2.3.2、查看函数调用的入参和返回值

        查看 demo.MathGame 类中 primeFactors 方法出参和返回值，结果属性遍历深度为2。

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

• 函数被执行了两次，第一次结果是location=AtExit，说明函数正常返回，因此可以看到returnObj结果是一个 ArrayList
• 第二次结果里是location=AtExceptionExit，说明函数抛出异常了，因此returnObj是 null
• 深度遍历x=2，不但显示对象属性，而且显示对象的值，入参 Object 表示入参是个Integer类型的对象，对象值为1，返回值为 ArrayList 数组，值为 2，2，5，347。

        2.3.3、深度遍历 x 说明

        在查看方法执行信息时，通过深度遍历参数 x 来查看参数和返回值显示的信息，x 值不同，显示的结果也不一样。

• -x：表示遍历深度，可以调整来打印具体的参数和结果内容，默认值是 1。
• -x：最大值是 4，防止展开结果占用太多内存。用户可以在ognl表达式里指定更具体的 field。

        我们分别执行三条命令，查看 深度遍历 x = 1，x = 2，x = 3 的不同结果。其中 -n 表示执行几次结束，这里我们设置为1次。

watch demo.MathGame primeFactors -x 1 -n 1

watch demo.MathGame primeFactors -x 2 -n 1

watch demo.MathGame primeFactors -x 3 -n 1

• 如果对象里面的对象属性越多，层级越深

        2.3.4、查看方法调用前和函数返回后的值

        查看 demo.MathGame 类中 primeFactors() 方法调用前和方法执行后返回的值。

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

watch demo.MathGame primeFactors -b -s -n 2 -x 2

        2.3.5、观察当前对象中的属性

        查看 demo.MathGame 类中的属性值，遍历深度为2。 

watch demo.MathGame primeFactors "target" -x 2

        观察当前对象中的属性

        如果想查看函数运行前后，当前对象中的属性，可以使用 target 关键字，target 代表this 对象。查看 demo.MathGame 类中 primeFactors() 方法运行前的对象中属性值，遍历深度为2。 

watch demo.MathGame primeFactors "target" -b -x 2

        使用 target.field_name 可以访问当前对象的某个属性值，查看 demo.MathGame 类中 primeFactors() 方法运行时 illegalArgumentCount 属性的值，遍历深度为2

watch demo.MathGame primeFactors "target.illegalArgumentCount" -x 2

        2.3.6、条件表达式

        打印入参小于0的执行执行情况，只有满足条件的调用，才会有响应。使用 -v 参数打印更多信息。params[0] 时入参第一个参数，params[0] < 0 表示只显示第一个入参值小于0的信息。

     当命令执行之后，没有输出结果。有两种可能：

1. 匹配到的函数没有被执行
2. 条件表达式结果是 false

     但用户区分不出是哪种情况，使用 -v选项，则会打印Condition express的具体值和执行结果，方便确认。

watch demo.MathGame primeFactors "{params[0],target}" "params[0]<0" -v

         按照方法执行耗时进行过滤

watch demo.MathGame primeFactors '{params, returnObj}' '#cost > 1' -x 2

#cost>1(单位是ms)表示只有当耗时大于 1ms 时才会输出，过滤掉执行时间小于 1ms 的调用。

        查看方法执行异常时的信息

watch demo.MathGame primeFactors "{params[0],throwExp}" -e -x 2

2.4、trace 命令（重要）

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

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

        trace 能方便的帮助你定位和发现因 RT 高而导致的性能问题缺陷，但其每次只能跟踪一级方法的调用链路。

参数：

参数名称	参数说明
class-pattern	类名表达式匹配
method-pattern	方法名表达式匹配
condition-express	条件表达式
[E]	开启正则表达式匹配，默认为通配符匹配
[n:]	命令执行次数
#cost	方法执行耗时

使用说明：

        2.4.1、查看方法耗时情况

        查看 demo.MathGame 类中 run() 方法执行耗时情况

        使用用 -n 参数指定捕捉结果的次数。

        2.4.2、据调用耗时过滤（重要）

        过滤 demo.MathGame 类中 run() 方法执行耗时情况，'#cost > 1' 表示只显示方法执行耗时大于 1ms 的执行情况，根据耗时进行过滤，有助于在排查问题的时候，只关注异常情况。

trace demo.MathGame run '#cost > 1'

        2.4.3、包含 JDK 函数

        trace 包含 jdk 里的函数调用情况

trace --skipJDKMethod false demo.MathGame run

        默认情况下，trace 不会包含 jdk 里的函数调用，如果希望 trace jdk 里的函数，需要显式设置--skipJDKMethod false。 

        2.4.4、trace 多个类或者多个函数

        trace 命令只会 trace 匹配到的函数里的子调用，并不会向下 trace 多层。因为 trace 是代价比较贵的，多层 trace 可能会导致最终要 trace 的类和函数非常多。

        可以用正则表匹配路径上的多个类和函数，一定程度上达到多层 trace 的效果。

        trace -E com.test.ClassA|org.test.ClassB method1|method2|method3

 trace -E demo.MathGame run|primeFactors

        查看  demo.MathGame 类中，run() 方法调用链上 run() 和 primeFactors() 方法执行耗时。

2.5、stack 命令（重要）

        输出当前方法被调用的调用路径

        很多时候我们都知道一个方法被执行，但这个方法被执行的路径非常多，或者你根本就不知道这个方法是从那里被执行了，此时你需要的是 stack 命令。

参数：

参数名称	参数说明
class-pattern	类名表达式匹配
method-pattern	方法名表达式匹配
condition-express	条件表达式
[E]	开启正则表达式匹配，默认为通配符匹配
[n:]	执行次数限制

使用说明

        2.5.1、查看方法被调用的调用情况

        查看 demo.MathGame 类中 primeFactors() 方法调用情况

stack demo.MathGame primeFactors

         输出结果中，demo.MathGame.primeFactors 被 demo.MathGame.run() 方法调用，demo.MathGame.run() 方法被 demo.MathGame.main() 方法调用。

        2.5.2、根据条件表达式来过滤

        查看 demo.MathGame 类中 primeFactors() 方法第一个入参小于0的调用情况

stack demo.MathGame primeFactors 'params[0] < 0' -n 2

        根据执行时间来过滤

        查看 demo.MathGame 类中 primeFactors() 方法执行耗时超过 1ms 的调用情况