跳至主要內容

Arthas诊断工具实战：trace、watch、ognl在生产问题定位中的应用

老张2026/4/30大约 10 分钟

Arthas诊断工具实战：trace、watch、ognl在生产问题定位中的应用

适读人群：Java中高级开发工程师 | 阅读时长：约20分钟 | 适用JDK版本：JDK 8 / 11 / 17 / 21

开篇故事

2019年，有一个接口的响应时间从50ms涨到了500ms，但找了半天看不出代码哪里有问题。测试环境重现不了，因为数据量比生产少太多。生产上不能随便debug，数据也不方便脱敏拿下来复现。

这是很多团队的常见困境：生产问题在测试不复现，没有远程调试环境，只能靠猜和加日志，但加日志要重新发布，而且加的位置还不一定对。

那次是我第一次在生产上用Arthas的trace命令。

trace com.example.OrderService queryOrders -n 5

一行命令，Arthas立刻开始追踪queryOrders方法，并实时打印每次调用的耗时明细，包括调用链上每个子方法的耗时：

---[50ms]com.example.OrderService:queryOrders()
  ---[2ms]com.example.dao.OrderDao:findByUserId()
  ---[45ms]com.example.service.ProductService:batchGetProducts()  ← 热点！
    ---[44ms]com.example.client.ProductClient:getProductList()
      ---[43ms]HTTP调用 GET /api/products?ids=1,2,3...200

问题找到了：queryOrders会查出用户的所有订单，然后对每个订单里的商品调用商品服务获取详情。用户订单越多，商品ID列表越长，HTTP请求越慢。这是一个典型的N+1演变成"大请求"问题。

从发现问题到定位根因，用了不到3分钟。

从那以后，Arthas成了我排查生产问题的第一工具。今天把我最常用的那些命令系统地整理出来。

一、Arthas的核心能力

Arthas是阿里巴巴开源的Java诊断工具，能在不重启、不修改代码的情况下，对运行中的Java进程进行动态分析。

Arthas的核心能力来自Java Agent机制（instrumentation API）：它通过字节码增强，在目标方法前后插入探针代码，实时收集调用信息。整个过程对业务代码无侵入。

主要能力：

  • trace：追踪方法调用链路，显示每个子方法的耗时
  • watch：观察方法的入参、出参、异常、耗时
  • stack：查看方法的调用来源（谁在调用这个方法）
  • tt（Time Tunnel）：记录方法的历史调用，可以重放
  • ognl：直接执行OGNL表达式，获取JVM中任意对象的值
  • jad：反编译运行中的类（查看线上实际运行的字节码）
  • redefine/retransform：在线修改class（谨慎使用）
  • classloader：查看ClassLoader层次
  • thread：查看线程状态，找热点线程

二、原理深度解析

2.1 Arthas的字节码增强原理

Arthas使用Java的Instrumentation API，通过retransformClasses()或redefineClasses()动态修改类的字节码：

关键限制：

  • 只能修改方法体，不能修改方法签名、添加字段、修改继承关系
  • 对性能有影响（trace/watch有额外开销），生产使用要控制条数-n
  • JDK 8无法trace Lambda表达式；JDK 11+有改进

2.2 OGNL表达式引擎

OGNL（Object-Graph Navigation Language）是Arthas用于动态表达式求值的引擎。通过OGNL可以：

  • 访问任意对象的字段和方法
  • 调用静态方法
  • 创建对象
  • 执行复杂的条件逻辑

三、核心命令详解与实战案例

3.1 trace命令：方法调用链路追踪

# 基础用法：追踪某个方法
trace com.example.OrderService queryOrders

# 限制追踪次数（生产必须加！避免性能影响）
trace com.example.OrderService queryOrders -n 5

# 过滤：只显示耗时超过100ms的调用
trace com.example.OrderService queryOrders '#cost > 100'

# 追踪多个方法
trace com.example.* *  -n 3   # 慎用！可能影响性能

# 展开更深的调用层次（默认1层）
trace com.example.OrderService queryOrders -n 3 --skipJDKMethod false

# 按条件过滤（只追踪参数满足条件的调用）
trace com.example.OrderService queryOrders 'params[0].id == 12345' -n 3

trace输出解读：

Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 25 ms, listenerId: 1

`---[12.345678ms] com.example.OrderService:queryOrders()
    +---[0.123ms] com.example.dao.OrderMapper:selectByUserId() #45
    +---[10.234ms] com.example.service.ProductService:batchGetProducts() #62
    |   `---[10.100ms] com.example.client.ProductClient:getProducts() #28
    |       `---[10.050ms] okhttp3.Call:execute() #56
    `---[1.900ms] com.example.service.CouponService:getCoupons() #89

# 解读：
# [12.345678ms]：该方法总耗时
# #45：代码行号
# +---：子方法调用（同级）
# `---：最后一个子方法
# 缩进表示调用深度

3.2 watch命令：观察方法入参/出参/异常

# 基础用法：观察方法的返回值
watch com.example.OrderService queryOrders returnObj

# 同时观察参数和返回值
watch com.example.OrderService queryOrders '{params, returnObj}' -x 2

# 观察异常
watch com.example.OrderService queryOrders '{params, throwExp}' -e

# 完整观察（参数+返回值+异常+耗时）
watch com.example.OrderService queryOrders '{params, returnObj, throwExp, #cost}' -x 3

# 条件过滤：只观察特定参数
watch com.example.OrderService queryOrders '{params, returnObj}' \
  'params[0].userId == 12345' -n 3

# 观察时机控制
# -b: 方法执行前（before）
# -f: 方法执行后（finish，默认）
# -e: 方法异常时（exception）
# -s: 方法成功返回时（success）
watch com.example.OrderService queryOrders returnObj -b  # 方法执行前看入参
watch com.example.OrderService queryOrders returnObj -s  # 成功返回时看出参

# 多个时机同时观察
watch com.example.OrderService queryOrders '{params, returnObj}' -b -f -x 2

watch输出解读：

Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 28 ms, listenerId: 2
method=com.example.OrderService.queryOrders location=AtExit
ts=2024-01-15 14:23:45; [cost=12.345ms] result=@ArrayList[
    @Order[
        id=@Long[1001],
        status=@String[PAID],
        amount=@BigDecimal[299.00]
    ],
    ...
]

3.3 stack命令：查看调用来源

# 谁在调用这个方法？
stack com.example.OrderService queryOrders -n 3

# 实际案例：发现某个方法被意外地频繁调用
stack com.example.dao.OrderMapper selectAll -n 5
# 可能发现是某个定时任务每秒调用一次全表查询

stack输出：

ts=2024-01-15 14:24:01;thread_name=http-nio-8080-exec-3;id=2b;
is_daemon=true;priority=5;TCCL=sun.misc.Launcher$AppClassLoader
@610455d6
    com.example.dao.OrderMapper.selectAll(OrderMapper.java)
    com.example.service.OrderService.refreshCache(OrderService.java:89)  ← 调用方
    com.example.scheduler.CacheRefreshTask.run(CacheRefreshTask.java:34) ← 更上层
    java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(...)

3.4 tt命令：时间隧道，记录和重放调用

# 记录最近5次调用（不影响正在执行的请求）
tt -t com.example.OrderService queryOrders -n 5

# 查看记录的调用列表
tt -l

# 输出示例：
# INDEX    TIMESTAMP            COST(ms)  IS-RET  IS-EXP  OBJECT       CLASS                    METHOD
# 1000     2024-01-15 14:25:00  12.345   true    false   0x12345      OrderService             queryOrders
# 1001     2024-01-15 14:25:01  245.678  true    false   0x12345      OrderService             queryOrders

# 查看某次调用的详细信息
tt -i 1001  # 查看INDEX=1001的详细信息

# 重放某次调用（慎用！会实际执行业务代码）
tt -i 1001 -p  # 重放INDEX=1001的调用

3.5 ognl命令：执行任意表达式

# 获取Spring容器中的Bean
ognl '@org.springframework.web.context.ContextLoader@getCurrentWebApplicationContext().getBean("orderService")'

# 调用实例方法
ognl '#service=@org.springframework.web.context.ContextLoader@getCurrentWebApplicationContext().getBean("orderService"), #service.queryOrders(12345L)'

# 获取静态字段的值
ognl '@com.example.config.SystemConfig@MAX_CONNECTIONS'

# 修改静态字段（谨慎！影响运行中的程序）
ognl '@com.example.config.SystemConfig@MAX_CONNECTIONS=200'

# 查看某个对象的内部状态（配合SpringContext）
ognl '#ctx=@org.springframework.web.context.ContextLoader@getCurrentWebApplicationContext(), \
     #pool=#ctx.getBean("dataSource").getPool(), \
     {"activeConnections=" + #pool.getActiveConnections(), \
      "idleConnections=" + #pool.getIdleConnections()}'

# 查看ThreadLocal变量
ognl '@com.example.context.RequestContextHolder@getContext()'

3.6 jad命令：反编译运行中的类

# 反编译一个类（验证热部署是否生效）
jad com.example.OrderService

# 只反编译特定方法
jad com.example.OrderService queryOrders

# 输出到文件
jad --source-only com.example.OrderService > /tmp/OrderService.java

# 实际使用场景：
# 1. 热部署后验证代码是否更新
# 2. 确认线上运行的代码版本（有时候包版本和实际部署版本不一致）
# 3. 排查字节码增强框架（AOP）对类的修改

3.7 monitor命令：方法调用统计

# 每5秒统计一次方法的调用次数、成功率、平均耗时
monitor com.example.OrderService queryOrders -c 5

# 输出示例：
# timestamp          class                    method          total  success  fail  avg-rt(ms)  fail-rate
# 2024-01-15 14:26  OrderService              queryOrders     120    118      2     12.34       1.67%

四、完整的生产排查案例

4.1 案例：接口突然变慢

# Step 1: 找慢方法
trace com.example.OrderController getOrders '#cost > 200' -n 10

# Step 2: 发现某个DAO方法耗时高，查看它的参数
watch com.example.dao.OrderMapper findByCondition '{params, returnObj}' -x 2 -n 5

# Step 3: 发现参数里的查询条件没有走索引（返回了10万条记录）
# 查看SQL（如果用MyBatis，可以找到MappedStatement对象）
ognl '#sqlSession=@org.springframework.web.context.ContextLoader@getCurrentWebApplicationContext().getBean("sqlSessionFactory").openSession(), "check session"'

# Step 4: 在代码上加入trace，确认慢SQL的来源
stack com.example.dao.OrderMapper findByCondition -n 3

4.2 案例：接口偶发异常

# 监控异常
watch com.example.OrderService processOrder '{params, throwExp}' -e -n 10

# 发现某个NPE，查看对象的内部状态
watch com.example.OrderService processOrder '{params[0], params[0]?.user, params[0]?.user?.address}' -e -n 5

# 找到问题：user.address为null
# 用ognl查看当前系统中某个用户对象
ognl '@com.example.UserContextHolder@getUser(12345L)'

4.3 案例：内存占用高，找大对象

# 用ognl遍历集合，找出大的
ognl '#ctx=@org.springframework.web.context.ContextLoader@getCurrentWebApplicationContext(), \
     #cache=#ctx.getBean("localCache"), \
     #cache.size()'

# 配合vmtool获取实例
vmtool --action getInstances --className com.example.cache.LocalCache --limit 5 -x 2

五、踩坑实录

坑一：trace在生产上没有限制条数，性能雪崩

有一次排查问题心急，用了：trace com.example.OrderService *（追踪类的所有方法），没有加-n限制。这个服务的QPS是1000，每个请求调用了几十个方法，每个都被追踪，Arthas的探针开销叠加起来，响应时间从50ms涨到500ms，服务开始超时告警。

立刻ctrl+c停止trace，服务恢复正常。

教训：生产使用Arthas，一定要加-n限制条数，加条件过滤，只追踪最必要的方法，每次操作完立即退出。Arthas不是免费的，它的字节码增强有性能开销。

坑二：ognl修改了静态配置，引发难以察觉的bug

排查问题时，试图通过ognl临时修改某个静态配置值来验证一个假设，修改成功了，验证完忘记改回来，导致生产配置和预期不一致，后续出现了一个诡异的bug，折腾了两天才发现根源是这次ognl修改没有复原。

教训：ognl对静态字段的修改是实时生效的，对运行中的程序有真实影响。诊断完成后必须恢复所有修改，或者重启服务来确保配置恢复正常。

坑三：jad的输出不代表原始源码

用jad反编译了一个类，发现逻辑和源码不一样，以为是有人改了代码偷偷发布。仔细一看，是AOP切面对这个类做了字节码增强，反编译出来是增强后的字节码，不是原始Java代码。

理解jad：它反编译的是运行时JVM中加载的字节码，包含了所有编译期和运行时的字节码修改（AOP、编译器优化等）。

坑四：JDK 17的安全限制导致部分Arthas功能不可用

升级到JDK 17后，Arthas的某些功能（特别是涉及反射的OGNL表达式和redefine命令）开始报错，提示InaccessibleObjectException。

原因：JDK 17的强封装（Strong Encapsulation）对模块的内部API做了更严格的访问限制。

解决方案：启动JVM时加上--add-opens参数：

--add-opens java.base/java.lang=ALL-UNNAMED
--add-opens java.base/java.util=ALL-UNNAMED
--add-opens java.base/java.lang.reflect=ALL-UNNAMED
# 根据实际Arthas的报错信息，添加对应的--add-opens

六、总结

Arthas是Java生产诊断的利器，核心命令可以按用途分三类记忆：

性能定位：trace（找慢方法）、monitor（统计调用频率和成功率）。trace是我用得最多的命令，在不能修改代码的情况下，一分钟内定位耗时热点。

状态观察：watch（看参数和返回值）、tt（记录历史调用）、ognl（查询任意JVM状态）。watch和ognl组合，可以在运行时检查任意变量的值，相当于无侵入的断点调试。

环境分析：jad（看实际运行的代码）、classloader（分析类加载）、thread（查线程状态）。

使用Arthas的黄金法则：生产操作加-n限制条数，操作完立即ctrl+c退出监听，对系统状态的修改（ognl写操作、redefine）要特别谨慎，做好恢复预案。Arthas是观察工具，不是修改工具，在生产上要保持克制。

编辑此页
最近更新:
贡献者: xiaozhangge