1. Arthas与trace命令初探
相信不少Java开发者都遇到过这样的场景:线上某个接口突然变慢,监控告警频频亮起,但翻遍日志却找不到明显异常。这时候如果贸然加日志再发布,不仅流程繁琐,还可能错过问题复现的最佳时机。去年双十一大促期间,我就遇到过订单查询接口RT(响应时间)从50ms飙升到2秒的情况,最终正是靠Arthas的trace命令在5分钟内锁定了罪魁祸首——一个循环内的第三方服务调用。
Arthas作为阿里开源的Java诊断神器,最让人称道的正是它的零侵入性。不同于传统的加日志或远程调试方案,它通过动态字节码增强技术实现运行时诊断,就像给JVM装了个X光机。其中trace命令堪称性能分析的"狙击枪",能精准绘制方法调用链路的时间消耗热力图。
2. 环境准备与快速上手
2.1 安装Arthas
推荐使用官方一键安装脚本(需要JDK 6+环境):
curl -O https://arthas.aliyun.com/arthas-boot.jar java -jar arthas-boot.jar启动后会列出当前机器所有Java进程,输入序号即可attach。我曾遇到过无法attach的情况,通常是权限问题,可以尝试用sudo或者确认目标进程与当前用户一致。
2.2 基础trace命令
假设我们要分析OrderController的create方法:
trace com.example.OrderController create -n 5这里-n 5表示只捕获5次调用。第一次执行可能会遇到类加载的短暂停顿,属于正常现象。去年排查问题时我发现,对于高频接口设置适当的捕获次数很重要——太少可能抓不到异常调用,太多又会导致输出泛滥。
3. 高级过滤技巧
3.1 耗时阈值过滤
当方法调用链复杂时,可以使用#cost过滤低耗时调用:
trace com.example.OrderService processOrder '#cost > 100' -n 3这个命令只会显示耗时超过100ms的方法调用。有次我用这个参数发现了一个有趣的现象:某个SQL查询大部分时间在10ms内,但偶尔会突然跳到200ms,最终确认是数据库连接池竞争导致。
3.2 忽略JDK方法
默认会跳过JDK内部方法,如需展示需显式关闭:
trace --skipJDKMethod false java.lang.String substring不过实践中我发现,除非怀疑是基础库问题,否则不建议开启,因为会大幅增加输出噪音。
4. 实战案例解析
4.1 典型调用链分析
假设我们得到如下trace结果:
`---ts=2023-08-20 14:30:45;thread_name=http-nio-8080-exec-1;id=1e;is_daemon=true;priority=5 `---[2034.12ms] com.example.OrderService:createOrder() +---[1.2% 24.56ms] com.example.UserService:getUserInfo() #12 +---[0.3% 6.78ms] com.example.InventoryService:checkStock() #15 `---[98.5% 2002.78ms] com.example.PaymentService:processPayment() #18这个树状结构清晰展示了:
- 总耗时2034ms中,支付服务占了98.5%
- 用户服务和库存检查耗时可以忽略
- 调用点行号(#12/#15/#18)可直接定位代码位置
4.2 多层调用展开
对于复杂链路,可以配合-E参数展开子调用:
trace -E 'com.example.*Service' com.example.OrderController create这会把所有Service层调用都展开显示。记得某次排查时,用这个参数发现了一个深达8层的循环调用。
5. 常见问题排查
5.1 时间统计误差
需要注意trace的时间包含:
- 方法实际执行时间
- Arthas自身的采集开销(通常<5%)
- JVM停顿(GC等)
如果发现各子方法耗时之和小于父方法,可能是遇到了JIT优化或异步调用。
5.2 高频调用优化
对于QPS>100的接口,建议:
- 先用
-n限制捕获次数 - 添加
#cost过滤 - 通过
--exclude-class-pattern排除已知类
6. 性能优化建议
根据trace结果优化时,我的经验是:
- 优先处理"帕累托热点"(消耗80%时间的20%代码)
- 对于数据库访问,看是否缺少索引或N+1查询
- 远程调用考虑缓存或批量处理
- 同步阻塞操作评估是否改异步
记得把常用trace命令保存成脚本,比如我的~/scripts/trace_order.sh:
#!/bin/bash arthas-trace -n 10 '#cost > 50' com.example.OrderService *