Java 监控诊断利器 Arthas monitor/watch/trace 命令使用详解

07-17 1154阅读

3.1.1、监控primeFactors方法调用情况（5秒一个周期，每过5秒将这5秒统计的信息输出）
3.1.2、监控primeFactors方法调用情况（5秒一个周期，每过5秒将这5秒统计的信息输出，一共输出两次）
3.1.3、计算条件表达式过滤统计结果(方法执行完毕之前)
3.1.4、计算条件表达式过滤统计结果(方法执行完毕之后)
3.2、watch 命令

3.2.1、观察函数调用返回时的参数、this 对象和返回值
3.2.2、同时观察函数调用前和函数返回后
3.2.3、条件表达式的例子
3.2.4、观察异常信息的例子
3.2.5、按照耗时进行过滤
3.2.6、观察当前对象中的属性
3.3、trace 命令

3.3.1、指定监控次数查看执行耗时和调用链路情况
3.3.2、包含 jdk 的函数查看执行耗时和调用链路情况
3.3.3、根据调用耗时过滤

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

一、命令介绍

命令	说明
monitor	方法执行监控，可以对指定类的方法进行实时监控 (给定时间内调用次数、成功次数、失败次数、平均 RT等）
watch	方法执行数据观测，可以观察到方法调用的入参、返参等
trace	方法内部调用路径，并输出方法路径上的每个节点上耗时相当于本地链路追踪

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

Java 监控诊断利器 Arthas monitor/watch/trace 命令使用详解

（图片来源网络，侵删）

官网地址：https://arthas.gitee.io/doc

二、测试Demo

Arthas官网提供了一个测试Demo这里我稍微调整了一下，添加了一个内部内用于测试，官网提供了jar包和源码，我比较喜欢直接跑源码，源码在github我这里把代码粘贴过来避免访问不了，将测试Demo运行起来使用arthas-boot.jar连接上准备开始命令使用。

import java.util.ArrayList;
import java.util.List;
import java.util.Random;
import java.util.concurrent.TimeUnit;
public class MathGame {
    private static Random random = new Random();
    private int illegalArgumentCount = 0;
    public static void main(String[] args) throws InterruptedException {
        MathGame game = new MathGame();
        while (true) {
            game.run();
            TimeUnit.SECONDS.sleep(1);
        }
    }
    public void run() throws InterruptedException {
        try {
            int number = random.nextInt()/10000;
            List primeFactors = primeFactors(number);
            print(number, primeFactors);
        } catch (Exception e) {
            System.out.println(String.format("illegalArgumentCount:%3d, ", illegalArgumentCount) + e.getMessage());
        }
    }
    public static void print(int number, List primeFactors) {
        StringBuffer sb = new StringBuffer(number + "=");
        for (int factor : primeFactors) {
            sb.append(factor).append('*');
        }
        if (sb.charAt(sb.length() - 1) == '*') {
            sb.deleteCharAt(sb.length() - 1);
        }
        System.out.println(sb);
    }
    public List primeFactors(int number) {
        System.out.println("当前时间戳："+new DateTimeUtils().getNow());
        if (number = 2");
        }
        List result = new ArrayList();
        int i = 2;
        while (i 
            if (number % i == 0) {
                result.add(i);
                number = number / i;
                i = 2;
            } else {
                i++;
            }
        }
        return result;
    }
    class DateTimeUtils {
        public String getNow() {
            return String.valueOf(System.currentTimeMillis());
        }
    }
}

h3三、命令使用示例/h3 h43.1、monitor 命令/h4 p monitor方法执行监控是一个很简单好用的线上方法调用响应情况观察工具，可以对指定类的方法进行实时监控，当线上某个业务响应慢时可以使用monitor对这个方法进行监控查看平均耗时，但是monitor没有监控整个链路每一步的处理时间的能力有需要可以使用trace命令。/p ulli监控的维度说明 tabletheadtrth监控项/thth说明/th/tr/theadtbodytrtdtimestamp/tdtd时间戳/td/trtrtdclass/tdtdJava 类/td/trtrtdmethod/tdtd方法（构造方法、普通方法）/td/trtrtdtotal/tdtd调用次数/td/trtrtdsuccess/tdtd成功次数/td/trtrtdfail/tdtd失败次数/td/trtrtdrt/tdtd平均 RT/td/trtrtdfail-rate/tdtd失败率/td/tr/tbody/table ulli参数说明/pp方法拥有一个命名参数 [c:]，意思是统计周期（cycle of output），拥有一个整型的参数值 tabletheadtrth参数名称/thth参数说明/th/tr/theadtbodytrtdclass-pattern/tdtd类名表达式匹配（支持通配符*）/td/trtrtdmethod-pattern/tdtd方法名表达式匹配（支持通配符*）/td/trtrtdcondition-express/tdtd条件表达式/td/trtrtd[E]/tdtd开启正则表达式匹配，默认为通配符匹配/td/trtrtd[c:]/tdtd统计周期，默认值为 120 秒/td/trtrtd[b]/tdtd在方法调用之前计算 condition-express/td/trtrtd[m ]/tdtd指定 Class 最大匹配数量，默认值为 50。长格式为[maxMatch ] /pp因为类名支持通配符所以可能会匹配多个类，可以用-m限制/td/trtrtd[n:]]/tdtd指定统计周期次数/td/tr/tbody/table h53.1.1、监控primeFactors方法调用情况（5秒一个周期，每过5秒将这5秒统计的信息输出）/h5 p我这里收集了3次，使用Ctrl+C退出收集/p pre class="brush:python;toolbar:false"[arthas@9336]$ monitor -c 5 demo.MathGame primeFactors Press Ctrl+C to abort. Affect(class count: 1 , method count: 1) cost in 23 ms, listenerId: 1 timestamp class method total success fail avg-rt(ms) fail-rate ----------------------------------------------------------------------------------------------- 2024-01-04 21:12:00 demo.MathGame primeFactors 5 1 4 0.25 80.00% timestamp class method total success fail avg-rt(ms) fail-rate ----------------------------------------------------------------------------------------------- 2024-01-04 21:12:05 demo.MathGame primeFactors 5 1 4 0.03 80.00% timestamp class method total success fail avg-rt(ms) fail-rate ----------------------------------------------------------------------------------------------- 2024-01-04 21:12:10 demo.MathGame primeFactors 5 4 1 0.66 20.00% /pre h53.1.2、监控primeFactors方法调用情况（5秒一个周期，每过5秒将这5秒统计的信息输出，一共输出两次）/h5 pre class="brush:python;toolbar:false"[arthas@9336]$ monitor -c 5 -n 2 demo.MathGame primeFactors Press Ctrl+C to abort. Affect(class count: 1 , method count: 1) cost in 23 ms, listenerId: 2 timestamp class method total success fail avg-rt(ms) fail-rate ----------------------------------------------------------------------------------------------- 2024-01-04 21:28:50 demo.MathGame primeFactors 5 4 1 0.73 20.00% timestamp class method total success fail avg-rt(ms) fail-rate ----------------------------------------------------------------------------------------------- 2024-01-04 21:28:55 demo.MathGame primeFactors 5 5 0 0.11 0.00% Command execution times exceed limit: 2, so command will exit. You can set it with -n option. /pre h53.1.3、计算条件表达式过滤统计结果(方法执行完毕之前)/h5 p这个方法执行完毕之前的意思是，会先判断入参是否小于等于2，如果小于等于2才记录统计，不然不记录，因为入参小于2会抛出异常，所以这里很大概率都是会失败的，默认是在方法执行完毕之后判断表达式。/p pre class="brush:python;toolbar:false"[arthas@9336]$ monitor -c 5 -n 3 -b demo.MathGame primeFactors "params[0] = 2" Press Ctrl+C to abort. Affect(class count: 1 , method count: 1) cost in 23 ms, listenerId: 3 timestamp class method total success fail avg-rt(ms) fail-rate ----------------------------------------------------------------------------------------------- 2024-01-04 21:39:03 demo.MathGame primeFactors 2 0 2 0.08 100.00% timestamp class method total success fail avg-rt(ms) fail-rate ----------------------------------------------------------------------------------------------- 2024-01-04 21:39:08 demo.MathGame primeFactors 3 0 3 0.02 100.00% timestamp class method total success fail avg-rt(ms) fail-rate ----------------------------------------------------------------------------------------------- 2024-01-04 21:39:13 demo.MathGame primeFactors 2 0 2 0.03 100.00% Command execution times exceed limit: 3, so command will exit. You can set it with -n option. /pre h53.1.4、计算条件表达式过滤统计结果(方法执行完毕之后)/h5 p这个好像没有效果，按照我的理解应该是primeFactors方法执行完成后进行条件表达式判断，只取出入参小于等于2的记录做统计，但是这里还是取出了全部数据/p pre class="brush:python;toolbar:false"[arthas@9336]$ monitor -c 5 -n 3 demo.MathGame primeFactors "params[0] = 2" Press Ctrl+C to abort. Affect(class count: 1 , method count: 1) cost in 23 ms, listenerId: 4 timestamp class method total success fail avg-rt(ms) fail-rate ----------------------------------------------------------------------------------------------- 2024-01-04 21:45:51 demo.MathGame primeFactors 5 2 3 0.67 60.00% timestamp class method total success fail avg-rt(ms) fail-rate ----------------------------------------------------------------------------------------------- 2024-01-04 21:45:56 demo.MathGame primeFactors 5 0 5 0.24 100.00% timestamp class method total success fail avg-rt(ms) fail-rate ----------------------------------------------------------------------------------------------- 2024-01-04 21:46:01 demo.MathGame primeFactors 5 4 1 0.31 20.00% Command execution times exceed limit: 3, so command will exit. You can set it with -n option. /pre h43.2、watch 命令/h4 p watch让你能方便的观察到指定函数的调用情况。能观察到的范围为：返回值、抛出异常、入参，通过编写 OGNL 表达式进行对应变量的查看。/p ulli参数说明/ppwatch 的参数比较多，主要是因为它能在 4 个不同的场景观察对象 tabletheadtrth参数名称/thth参数说明/th/tr/theadtbodytrtdclass-pattern/tdtd类名表达式匹配/td/trtrtdmethod-pattern/tdtd函数名表达式匹配/td/trtrtdexpress/tdtd观察表达式，默认值：{params, target, returnObj}/td/trtrtdcondition-express/tdtd条件表达式/td/trtrtd[b]/tdtd在函数调用之前观察/td/trtrtd[e]/tdtd在函数异常之后观察/td/trtrtd[s]/tdtd在函数返回之后观察/td/trtrtd[f]/tdtd在函数结束之后(正常返回和异常返回)观察/td/trtrtd[E]/tdtd开启正则表达式匹配，默认为通配符匹配/td/trtrtd[x:]/tdtd指定输出结果的属性遍历深度，默认为 1，最大值是 4/td/trtrtd[m ]/tdtd指定 Class 最大匹配数量，默认值为 50。长格式为[maxMatch ]/td/trtrtd[n:]/tdtd命令执行次数/td/trtrtd#cost/tdtd方法执行耗时/td/tr/tbody/table p这里重点要说明的是观察表达式，观察表达式的构成主要由 ognl 表达式组成，所以你可以这样写"{params,returnObj}"，只要是一个合法的 ognl 表达式，都能被正常支持。/p ulli特别说明 ulliwatch 命令定义了 4 个观察事件点，即 -b 函数调用前，-e 函数异常后，-s 函数返回后，-f 函数结束后/lili4 个观察事件点 -b、-e、-s 默认关闭，-f 默认打开，当指定观察点被打开后，在相应事件点会对观察表达式进行求值并输出/pp这里要注意函数入参和函数出参的区别，有可能在中间被修改导致前后不一致，除了 -b 事件点 params 代表函数入参外，其余事件都代表函数出参/lili当使用 -b 时，由于观察事件点是在函数调用前，此时返回值或异常均不存在/lili在 watch 命令的结果里，会打印出location信息。location有三种可能值：AtEnter，AtExit，AtExceptionExit。对应函数入口，函数正常 return，函数抛出异常。 h53.2.1、观察函数调用返回时的参数、this 对象和返回值/h5 pre class="brush:python;toolbar:false"[arthas@3764]$ watch demo.MathGame primeFactors -x 2 -n 1 Press Q or Ctrl+C to abort. Affect(class count: 1 , method count: 1) cost in 20 ms, listenerId: 2 method=demo.MathGame.primeFactors location=AtExit ts=2024-01-08 20:58:31; [cost=1.901ms] result=@ArrayList[ @Object[][ @Integer[1], ], @MathGame[ random=@Random[java.util.Random@28c97a5], illegalArgumentCount=@Integer[53], ], @ArrayList[ @Integer[2], @Integer[95539], ], ] Command execution times exceed limit: 1, so command will exit. You can set it with -n option. /pre ulli观察表达式，默认值是{params, target, returnObj}/lili-x表示遍历深度，可以调整来打印具体的参数和结果内容，默认值是 1。/lili-x最大值是 4，防止展开结果占用太多内存。用户可以在ognl表达式里指定更具体的 field。/lili-n 1代表执行一次就退出，-n这个参数在每个Arthas命令中基本都有只是没有写出来而已 h53.2.2、同时观察函数调用前和函数返回后/h5 pre class="brush:python;toolbar:false"[arthas@3764]$ watch demo.MathGame primeFactors "{params,target,returnObj}" -x 2 -b -s -n 2 Press Q or Ctrl+C to abort. Affect(class count: 1 , method count: 1) cost in 18 ms, listenerId: 10 method=demo.MathGame.primeFactors location=AtEnter ts=2024-01-08 21:09:35; [cost=0.0407ms] result=@ArrayList[ @Object[][ @Integer[132070], ], @MathGame[ random=@Random[java.util.Random@28c97a5], illegalArgumentCount=@Integer[402], ], null, ] method=demo.MathGame.primeFactors location=AtExit ts=2024-01-08 21:09:35; [cost=2151892.1309ms] result=@ArrayList[ @Object[][ @Integer[1], ], @MathGame[ random=@Random[java.util.Random@28c97a5], illegalArgumentCount=@Integer[402], ], @ArrayList[ @Integer[2], @Integer[5], @Integer[47], @Integer[281], ], ] Command execution times exceed limit: 2, so command will exit. You can set it with -n option. /pre ulli p参数里-n 2，表示只执行两次/p /lili p这里输出结果中，第一次输出的是函数调用前的观察表达式的结果，第二次输出的是函数返回后的表达式的结果/p /lili p结果的输出顺序和事件发生的先后顺序一致，和命令中 -s -b 的顺序无关/p h53.2.3、条件表达式的例子/h5 pre class="brush:python;toolbar:false"[arthas@3764]$ watch demo.MathGame primeFactors "{params[0],target}" "params[0]0" -n 2 Press Q or Ctrl+C to abort. Affect(class count: 1 , method count: 1) cost in 16 ms, listenerId: 14 method=demo.MathGame.primeFactors location=AtExceptionExit ts=2024-01-08 21:18:02; [cost=0.3214ms] result=@ArrayList[ @Integer[-181424], @MathGame[demo.MathGame@6659c656], ] method=demo.MathGame.primeFactors location=AtExceptionExit ts=2024-01-08 21:18:03; [cost=0.0878ms] result=@ArrayList[ @Integer[-202266], @MathGame[demo.MathGame@6659c656], ] Command execution times exceed limit: 2, so command will exit. You can set it with -n option. /pre ulliparams[0]0 当第一个参数小于0是响应 h53.2.4、观察异常信息的例子/h5 pre class="brush:python;toolbar:false"[arthas@3764]$ watch demo.MathGame primeFactors "{params[0],throwExp}" -e -x 2 -n 1 Press Q or Ctrl+C to abort. Affect(class count: 1 , method count: 1) cost in 17 ms, listenerId: 17 method=demo.MathGame.primeFactors location=AtExceptionExit ts=2024-01-08 21:24:17; [cost=0.3626ms] result=@ArrayList[ @Integer[-212025], java.lang.IllegalArgumentException: number is: -212025, need = 2 at demo.MathGame.primeFactors(MathGame.java:47) at demo.MathGame.run(MathGame.java:24) at demo.MathGame.main(MathGame.java:16) , ] Command execution times exceed limit: 1, so command will exit. You can set it with -n option. /pre ulli-e表示抛出异常时才触发/liliexpress 观察表达式中，表示异常信息的变量是throwExp h53.2.5、按照耗时进行过滤/h5 pre class="brush:python;toolbar:false"[arthas@3764]$ watch demo.MathGame primeFactors '{params, returnObj}' '#cost0.5' -x 2 -n 1 Press Q or Ctrl+C to abort. Affect(class count: 1 , method count: 1) cost in 19 ms, listenerId: 22 method=demo.MathGame.primeFactors location=AtExit ts=2024-01-08 21:30:26; [cost=1.1834ms] result=@ArrayList[ @Object[][ @Integer[1], ], @ArrayList[ @Integer[2], @Integer[63347], ], ] Command execution times exceed limit: 1, so command will exit. You can set it with -n option. /pre ulli#cost>0.5(单位是ms)表示只有当耗时大于 0.5ms 时才会输出，过滤掉执行时间小于 0.5ms 的调用

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

[arthas@3764]$ watch demo.MathGame primeFactors '{params,target.illegalArgumentCount}' -x 2 -n 1                                     
Press Q or Ctrl+C to abort.            
Affect(class count: 1 , method count: 1) cost in 19 ms, listenerId: 26                
method=demo.MathGame.primeFactors location=AtExit                                     
ts=2024-01-08 21:34:00; [cost=0.2875ms] result=@ArrayList[                                
	@Object[][                                 
		@Integer[1],                       
	],                                     
	@Integer[1149],                    
]                                      
Command execution times exceed limit: 1, so command will exit. You can set it with -n option.

可以使用target.field_name访问当前对象的某个属性，target相当于当前对象

3.3、trace 命令

trace 命令能监控方法内部调用路径，并输出方法路径上的每个节点上耗时，方便的帮助定位和发现因 RT 高而导致的性能问题缺陷，trace 命令能主动搜索 class-pattern／method-pattern 对应的方法调用路径，渲染和统计整个调用链路上的所有性能开销和追踪调用链路。

参数说明

参数名称	参数说明
class-pattern	类名表达式匹配（支持通配符*）
method-pattern	方法名表达式匹配（支持通配符*）
condition-express	条件表达式
[E]	开启正则表达式匹配，默认为通配符匹配
[n:]	命令执行次数
#cost	方法执行耗时
[m ]	指定 Class 最大匹配数量，默认值为 50。长格式为[maxMatch ] 因为类名支持通配符所以可能会匹配多个类，可以用-m限制
–skipJDKMethod	是否包含 jdk 的函数，默认false，不显示jdk函数调用