大家好我是程序员天天困。这是「Arthas 线上诊断实战」系列第 2 篇。上一篇讲完 watch 命令实战很多读者有疑问入参对了、返回值也对了可我还是不知道代码到底走了哪条分支接口慢又该盯哪一层。答案就是Arthas trace贴一条命令调用树和行号直接告诉你走了哪条分支、哪一层最耗时。点个收藏我们直接上手。一、watch 的盲区只见结果不见过程还是用系列同款计算器接口RequestMapping(path/user/calculate,methodRequestMethod.GET)publicIntegercalculate(RequestParam(x)Integerx,RequestParam(y)Integery,RequestParam(nameop)Stringop){returndoCalculate(x,y,op)1;}publicintdoCalculate(intx,inty,Stringop){if(add.equals(op))returnxy;elseif(sub.equals(op))returnx-y;elseif(mul.equals(op))returnx*y;elseif(div.equals(op))returnx/y;elsethrownewUnsupportedOperationException(NotSupportOpop);}假设请求是x2y2opadd。你用 watch 盯doCalculatewatchcom.ttk.controller.WebController doCalculate\{params,returnObj,throwExp}-n5-x3返回值是4。问题来了22也是 42*2也是 4。watch 只告诉你「结果是 4」不告诉你到底走进了add还是mul。watch 擅长验结果不擅长验路径。线上最常见的「接口慢但不知道慢在哪」就卡在这个盲区上。二、Arthas trace 是什么给方法内部装行车记录仪Arthas trace方法路径追踪Arthas 用来打印某个方法内部调用路径、并统计路径上每个节点耗时的命令。你可以把它理解成「给方法内部装上行车记录仪」走过哪条岔路、每一段花了多少毫秒仪表盘上全有。官方文档对它的定位很直接主动搜索匹配方法的调用路径渲染整条链路上的性能开销。搜索关键词「Arthas trace 官方文档」即可找到最新参数说明。IDEA 里对目标方法右键 → Arthas Command → Trace通常会复制出类似命令trace com.ttk.controller.WebController doCalculate-n5--skipJDKMethodfalse拆开看四个关键点trace启用路径追踪。类全名 方法名被追踪的入口和 watch 一样。-n 5只抓 5 次就退出线上别无限挂着。--skipJDKMethod false是否把 JDK 内部调用也打出来默认跳过。用#cost做耗时过滤#cost是 Arthas 条件表达式里能用的一个变量代表方法执行耗时单位 mswatch / stack / trace 都支持。写法如#cost 100只输出执行超过 100ms 的调用。你可以把它想成「只给超时工单开录像回放」正常的快速调用直接略过噪音少很多。三、Arthas trace 看执行路径代码到底有没有走到先 attach 好进程第 1 篇已讲过此处不重复贴上命令再发请求curlhttp://localhost:8080/user/calculate?x2y2opadd树里的#行号是关键证据它标的是「在被 trace 的那个方法源码的第几行发起了这次调用」。opadd时你会看到执行落到加法对应的那一行。再把op换成mul发一次curlhttp://localhost:8080/user/calculate?x2y2opmul行号对得上分支才算真的走到了。同一个doCalculateopadd和opmul落在两行不同的行号上——这就是 trace 比 watch 多看见的那半边过程。可能有人会问一次 trace 能顺着往下钻十几层吗官方明确说过一次 trace 默认只跟踪匹配方法这一级子调用不会自动无限下钻想看更深要用正则一次匹配多个类方法或用后面说的动态 trace。别指望一条命令把整棵调用树全展开那对线上 JVM 太贵。四、–skipJDKMethodJDK 调用要不要展开默认--skipJDKMethod为true也就是跳过java.*一类调用树更干净。排查业务分支时这样通常够用。当你怀疑慢在字符串拼接、集合操作、或者某个 JDK 工具方法时再打开trace com.ttk.controller.WebController doCalculate\-n3--skipJDKMethodfalse这时树会变「茂盛」StringBuilder、Integer.valueOf之类都会冒出来。信息变多也更容易被噪音淹没。我的习惯是先默认跳过 JDK定位到业务方法后再对可疑节点单独开 false。场景建议原因确认业务 if/else 走到哪--skipJDKMethod true默认树短行号清晰怀疑慢在 JDK/工具方法--skipJDKMethod false能看见 java.* 节点耗时接口整体很慢、调用很深先#cost过滤再决定是否展开 JDK先降噪再放大五、Arthas trace 耗时分析揪出接口最慢那一层路径之外trace 更大的日常价值是找慢点。给控制器加一组串行 sleep 示例RequestMapping(path/user/cost,methodRequestMethod.GET)publicIntegercost()throwsInterruptedException{cost1();cost2();cost3();return1;}publicvoidcost1()throwsInterruptedException{Thread.sleep(100);}publicvoidcost2()throwsInterruptedException{Thread.sleep(200);}publicvoidcost3()throwsInterruptedException{Thread.sleep(300);}预期总耗时大约 600ms。线上等价场景是一个接口串行打了三个下游P99 飙高日志却只有总耗时。trace com.ttk.controller.WebController cost-n5--skipJDKMethodfalse触发请求curlhttp://localhost:8080/user/cost输出里每个子调用都会带耗时Arthas 还会用百分比标出每个子调用占入口耗时的比例占比高的自然就是慢点。一目了然不用猜。请求很频繁时别把所有调用都打出来加上耗时过滤trace com.ttk.controller.WebController cost#cost 200-n5这样只保留总耗时超过 200ms 的样本。可能有人会问trace 出来的毫秒数能不能当性能测试报告别急官方也提醒过——trace 自己有观测开销子节点耗时加总往往小于父节点差值就来自未追踪的 JDK 调用、字节码指令甚至 GC 停顿。六、异常也是一条路径异常对 trace 来说并不是特殊物种只是执行路径的另一种走向。把op改成不支持的值例如curlhttp://localhost:8080/user/calculate?x2y2opadd2再试运行时异常比如除零opdivy0curlhttp://localhost:8080/user/calculate?x2y0opdiv异常现场要用 watch 看对象用 trace 看走到了哪。两者叠在一起比单独翻 error 日志更立体一个告诉你「抛了什么」一个告诉你「从哪条分支抛出来的」。七、动态 trace一层不够就再挖一层Arthas 3.3.0 之后支持动态 trace第一次 trace 入口方法时终端会打印listenerId另开一个 Arthas 连接对可疑子方法再trace ... --listenerId 同一个 id原来的终端里调用树会多长出一层。动态 trace按 listenerId 加深在已有 trace 会话上用同一个listenerId继续增强子方法让调用树多长出一层的能力。你可以把它理解成「行车记录仪先拍主干道发现堵车口再往小巷加一路摄像头」而不是一上来全城监控。这招适合「已经锁定慢在 A还想看 A 里面到底是 B 还是 C」。比一上来用大正则扫半个包要克制线上也更安全。我自己的顺序通常是入口 trace → 看最慢子调用 → 动态加深一层 → 必要时再 watch 该节点的入参。八、watch 和 Arthas trace 怎么搭配维度watchtrace核心问题入参 / 返回值 / 异常对象是什么走了哪条路径、哪段最耗时输出形态观察表达式结果调用树 耗时典型场景结果不对、怀疑多算/少算分支未执行、接口慢常见组合先看结果对不对再看路径与热点实战口诀就一句先 watch 验结果再 trace 验路径和耗时。大部分线上「结果怪」或「延迟高」的问题这两步就能收敛到具体方法甚至具体行号。结语Arthas trace 补上的是 watch 看不见的那半边过程与耗时。会用路径确认分支、会用#cost过滤噪音、知道一次只加深一层你就已经超过很多「只会复制插件命令」的用法。下一篇我会写vmtool聊聊怎么在不重启的前提下直接摸到 JVM 里的对象实例。本文命令参数以 Arthas 官方 trace 文档 为准版本演进时请以官网为准。我是程序员天天困持续分享编程干货。觉得有用的话记得点赞收藏和关注~也欢迎在评论区聊聊你用 Arthas trace 时有没有一次靠行号当场拆穿「假修复」的经历。
Arthas trace 命令怎么用？一行定位最慢那行代码
大家好我是程序员天天困。这是「Arthas 线上诊断实战」系列第 2 篇。上一篇讲完 watch 命令实战很多读者有疑问入参对了、返回值也对了可我还是不知道代码到底走了哪条分支接口慢又该盯哪一层。答案就是Arthas trace贴一条命令调用树和行号直接告诉你走了哪条分支、哪一层最耗时。点个收藏我们直接上手。一、watch 的盲区只见结果不见过程还是用系列同款计算器接口RequestMapping(path/user/calculate,methodRequestMethod.GET)publicIntegercalculate(RequestParam(x)Integerx,RequestParam(y)Integery,RequestParam(nameop)Stringop){returndoCalculate(x,y,op)1;}publicintdoCalculate(intx,inty,Stringop){if(add.equals(op))returnxy;elseif(sub.equals(op))returnx-y;elseif(mul.equals(op))returnx*y;elseif(div.equals(op))returnx/y;elsethrownewUnsupportedOperationException(NotSupportOpop);}假设请求是x2y2opadd。你用 watch 盯doCalculatewatchcom.ttk.controller.WebController doCalculate\{params,returnObj,throwExp}-n5-x3返回值是4。问题来了22也是 42*2也是 4。watch 只告诉你「结果是 4」不告诉你到底走进了add还是mul。watch 擅长验结果不擅长验路径。线上最常见的「接口慢但不知道慢在哪」就卡在这个盲区上。二、Arthas trace 是什么给方法内部装行车记录仪Arthas trace方法路径追踪Arthas 用来打印某个方法内部调用路径、并统计路径上每个节点耗时的命令。你可以把它理解成「给方法内部装上行车记录仪」走过哪条岔路、每一段花了多少毫秒仪表盘上全有。官方文档对它的定位很直接主动搜索匹配方法的调用路径渲染整条链路上的性能开销。搜索关键词「Arthas trace 官方文档」即可找到最新参数说明。IDEA 里对目标方法右键 → Arthas Command → Trace通常会复制出类似命令trace com.ttk.controller.WebController doCalculate-n5--skipJDKMethodfalse拆开看四个关键点trace启用路径追踪。类全名 方法名被追踪的入口和 watch 一样。-n 5只抓 5 次就退出线上别无限挂着。--skipJDKMethod false是否把 JDK 内部调用也打出来默认跳过。用#cost做耗时过滤#cost是 Arthas 条件表达式里能用的一个变量代表方法执行耗时单位 mswatch / stack / trace 都支持。写法如#cost 100只输出执行超过 100ms 的调用。你可以把它想成「只给超时工单开录像回放」正常的快速调用直接略过噪音少很多。三、Arthas trace 看执行路径代码到底有没有走到先 attach 好进程第 1 篇已讲过此处不重复贴上命令再发请求curlhttp://localhost:8080/user/calculate?x2y2opadd树里的#行号是关键证据它标的是「在被 trace 的那个方法源码的第几行发起了这次调用」。opadd时你会看到执行落到加法对应的那一行。再把op换成mul发一次curlhttp://localhost:8080/user/calculate?x2y2opmul行号对得上分支才算真的走到了。同一个doCalculateopadd和opmul落在两行不同的行号上——这就是 trace 比 watch 多看见的那半边过程。可能有人会问一次 trace 能顺着往下钻十几层吗官方明确说过一次 trace 默认只跟踪匹配方法这一级子调用不会自动无限下钻想看更深要用正则一次匹配多个类方法或用后面说的动态 trace。别指望一条命令把整棵调用树全展开那对线上 JVM 太贵。四、–skipJDKMethodJDK 调用要不要展开默认--skipJDKMethod为true也就是跳过java.*一类调用树更干净。排查业务分支时这样通常够用。当你怀疑慢在字符串拼接、集合操作、或者某个 JDK 工具方法时再打开trace com.ttk.controller.WebController doCalculate\-n3--skipJDKMethodfalse这时树会变「茂盛」StringBuilder、Integer.valueOf之类都会冒出来。信息变多也更容易被噪音淹没。我的习惯是先默认跳过 JDK定位到业务方法后再对可疑节点单独开 false。场景建议原因确认业务 if/else 走到哪--skipJDKMethod true默认树短行号清晰怀疑慢在 JDK/工具方法--skipJDKMethod false能看见 java.* 节点耗时接口整体很慢、调用很深先#cost过滤再决定是否展开 JDK先降噪再放大五、Arthas trace 耗时分析揪出接口最慢那一层路径之外trace 更大的日常价值是找慢点。给控制器加一组串行 sleep 示例RequestMapping(path/user/cost,methodRequestMethod.GET)publicIntegercost()throwsInterruptedException{cost1();cost2();cost3();return1;}publicvoidcost1()throwsInterruptedException{Thread.sleep(100);}publicvoidcost2()throwsInterruptedException{Thread.sleep(200);}publicvoidcost3()throwsInterruptedException{Thread.sleep(300);}预期总耗时大约 600ms。线上等价场景是一个接口串行打了三个下游P99 飙高日志却只有总耗时。trace com.ttk.controller.WebController cost-n5--skipJDKMethodfalse触发请求curlhttp://localhost:8080/user/cost输出里每个子调用都会带耗时Arthas 还会用百分比标出每个子调用占入口耗时的比例占比高的自然就是慢点。一目了然不用猜。请求很频繁时别把所有调用都打出来加上耗时过滤trace com.ttk.controller.WebController cost#cost 200-n5这样只保留总耗时超过 200ms 的样本。可能有人会问trace 出来的毫秒数能不能当性能测试报告别急官方也提醒过——trace 自己有观测开销子节点耗时加总往往小于父节点差值就来自未追踪的 JDK 调用、字节码指令甚至 GC 停顿。六、异常也是一条路径异常对 trace 来说并不是特殊物种只是执行路径的另一种走向。把op改成不支持的值例如curlhttp://localhost:8080/user/calculate?x2y2opadd2再试运行时异常比如除零opdivy0curlhttp://localhost:8080/user/calculate?x2y0opdiv异常现场要用 watch 看对象用 trace 看走到了哪。两者叠在一起比单独翻 error 日志更立体一个告诉你「抛了什么」一个告诉你「从哪条分支抛出来的」。七、动态 trace一层不够就再挖一层Arthas 3.3.0 之后支持动态 trace第一次 trace 入口方法时终端会打印listenerId另开一个 Arthas 连接对可疑子方法再trace ... --listenerId 同一个 id原来的终端里调用树会多长出一层。动态 trace按 listenerId 加深在已有 trace 会话上用同一个listenerId继续增强子方法让调用树多长出一层的能力。你可以把它理解成「行车记录仪先拍主干道发现堵车口再往小巷加一路摄像头」而不是一上来全城监控。这招适合「已经锁定慢在 A还想看 A 里面到底是 B 还是 C」。比一上来用大正则扫半个包要克制线上也更安全。我自己的顺序通常是入口 trace → 看最慢子调用 → 动态加深一层 → 必要时再 watch 该节点的入参。八、watch 和 Arthas trace 怎么搭配维度watchtrace核心问题入参 / 返回值 / 异常对象是什么走了哪条路径、哪段最耗时输出形态观察表达式结果调用树 耗时典型场景结果不对、怀疑多算/少算分支未执行、接口慢常见组合先看结果对不对再看路径与热点实战口诀就一句先 watch 验结果再 trace 验路径和耗时。大部分线上「结果怪」或「延迟高」的问题这两步就能收敛到具体方法甚至具体行号。结语Arthas trace 补上的是 watch 看不见的那半边过程与耗时。会用路径确认分支、会用#cost过滤噪音、知道一次只加深一层你就已经超过很多「只会复制插件命令」的用法。下一篇我会写vmtool聊聊怎么在不重启的前提下直接摸到 JVM 里的对象实例。本文命令参数以 Arthas 官方 trace 文档 为准版本演进时请以官网为准。我是程序员天天困持续分享编程干货。觉得有用的话记得点赞收藏和关注~也欢迎在评论区聊聊你用 Arthas trace 时有没有一次靠行号当场拆穿「假修复」的经历。
