5.6 KiB
方法内部调用路径，并输出方法路径上的每个节点上耗时
trace{{}} 命令能主动搜索 class-pattern{{}} ／method-pattern{{}} 对应的方法调用路径，渲染和统计整个调用链路上的所有性能开销和追踪调用链路。
参数说明
| 参数名称 | 参数说明 |
|---|---|
| class-pattern | 类名表达式匹配 |
| method-pattern | 方法名表达式匹配 |
| condition-express | 条件表达式 |
| [E] | 开启正则表达式匹配，默认为通配符匹配 |
[n:]{{}} |
命令执行次数 |
#cost{{}} |
方法执行耗时 |
这里重点要说明的是观察表达式，观察表达式的构成主要由 ognl 表达式组成，所以你可以这样写"{params,returnObj}"{{}} ，只要是一个合法的 ognl 表达式，都能被正常支持。
观察的维度也比较多，主要体现在参数 advice{{}} 的数据结构上。Advice{{}} 参数最主要是封装了通知节点的所有信息。
请参考表达式核心变量中关于该节点的描述。
- 特殊用法请参考：https://github.com/alibaba/arthas/issues/71
- OGNL 表达式官网：https://commons.apache.org/proper/commons-ognl/language-guide.html
很多时候我们只想看到某个方法的 rt 大于某个时间之后的 trace 结果，现在 Arthas 可以按照方法执行的耗时来进行过滤了，例如trace *StringUtils isBlank '#cost>100'{{}} 表示当执行时间超过 100ms 的时候，才会输出 trace 的结果。
watch/stack/trace 这个三个命令都支持
#cost{{}}
注意事项
trace{{}} 能方便的帮助你定位和发现因 RT 高而导致的性能问题缺陷，但其每次只能跟踪一级方法的调用链路。
3.3.0 版本后，可以使用动态 Trace 功能，不断增加新的匹配类，参考下面的示例。
使用参考
trace 函数
trace demo.MathGame run{{execute T2}}
按 Q{{exec interrupt}} 或者 Ctrl+c{{exec interrupt}} 退出
trace 次数限制
如果方法调用的次数很多，那么可以用-n{{}} 参数指定捕捉结果的次数。比如下面的例子里，捕捉到一次调用就退出命令。
trace demo.MathGame run -n 1{{execute T2}}
包含 jdk 的函数
--skipJDKMethod <value>{{}} skip jdk method trace, default value true.
trace --skipJDKMethod false demo.MathGame run{{execute T2}}
按Q{{execute T2}}或者Ctrl+c{{}} 退出
默认情况下，trace 不会包含 jdk 里的函数调用，如果希望 trace jdk 里的函数，需要显式设置--skipJDKMethod false{{}} 。
据调用耗时过滤
trace demo.MathGame run '#cost > 10'{{execute T2}}
按Q{{execute T2}}或者Ctrl+c{{}} 退出
只会展示耗时大于 10ms 的调用路径，有助于在排查问题的时候，只关注异常情况
- 是不是很眼熟，没错，在 JProfiler 等收费软件中你曾经见识类似的功能，这里你将可以通过命令就能打印出指定调用路径。友情提醒下，
trace{{}} 在执行的过程中本身是会有一定的性能开销，在统计的报告中并未像 JProfiler 一样预先减去其自身的统计开销。所以这统计出来有些许的不准，渲染路径上调用的类、方法越多，性能偏差越大。但还是能让你看清一些事情的。 - [12.033735ms] 的含义，
12.033735{{}} 的含义是：当前节点在当前步骤的耗时，单位为毫秒 - [0,0,0ms,11]xxx:yyy() [throws Exception]，对该方法中相同的方法调用进行了合并，
0,0,0ms,11{{}} 表示方法调用耗时，min,max,total,count{{}} ；throws Exception{{}} 表明该方法调用中存在异常返回 - 这里存在一个统计不准确的问题，就是所有方法耗时加起来可能会小于该监测方法的总耗时，这个是由于 Arthas 本身的逻辑会有一定的耗时
trace 多个类或者多个函数
trace 命令只会 trace 匹配到的函数里的子调用，并不会向下 trace 多层。因为 trace 是代价比较贵的，多层 trace 可能会导致最终要 trace 的类和函数非常多。
可以用正则表匹配路径上的多个类和函数，一定程度上达到多层 trace 的效果。
trace -E com.test.ClassA|org.test.ClassB method1|method2|method3
动态 trace
3.3.0 版本后支持。
打开终端 1，trace run{{}} 函数，可以看到打印出 listenerId: 1{{}} ：
trace demo.MathGame run{{execute T2}}
按Q{{execute T2}}或者Ctrl+c{{}} 退出
现在想要深入子函数primeFactors{{}} ，可以打开一个新终端 2，使用telnet localhost 3658{{}} 连接上 arthas，再 trace primeFactors{{}} 时，指定listenerId{{}} 。
trace demo.MathGame primeFactors --listenerId 1{{execute T2}}
按Q{{execute T2}}或者Ctrl+c{{}} 退出
这时终端 2 打印的结果，说明已经增强了一个函数：Affect(class count: 1 , method count: 1){{}} ，但不再打印更多的结果。
再查看终端 1，可以发现 trace 的结果增加了一层，打印了primeFactors{{}} 函数里的内容：
通过指定listenerId{{}} 的方式动态 trace，可以不断深入。另外 watch{{}} /tt{{}} /monitor{{}} 等命令也支持类似的功能。