Arthas在线诊断方法耗时

wen java案例 2

本文目录导读:

Arthas在线诊断方法耗时

  1. 核心命令:trace (最常用)
  2. 聚合统计:monitor (适合稳定复现的慢问题)
  3. 查看出入参和耗时:watch (精准定位)
  4. 生成火焰图:async-profiler (终极诊断)
  5. 跟踪多线程或异步调用
  6. 常见耗时问题类型与对应命令选择
  7. 总结建议

Arthas(阿尔萨斯)是Alibaba开源的Java诊断工具,在线诊断方法耗时,通常指的是使用Arthas的TraceMonitorWatch等命令来监控某个方法执行所花费的时间。

以下是几种通过Arthas诊断方法耗时的常用命令及场景:

核心命令:trace (最常用)

trace 命令会跟踪方法内部的所有调用路径,并统计每个子调用(子方法)的耗时。

场景:你的API响应很慢,想知道“是方法A慢,还是它内部的某个子方法B慢?”

用法

# 跟踪 com.example.service.UserService 类中的 getUser 方法
trace com.example.service.UserService getUser

输出示例

`---ts=2023-01-01 12:00:00;thread_name=http-nio-8080-exec-1;id=123;is_daemon=true;priority=5;
    `---[6.123ms] com.example.service.UserService:getUser()
        +---[0.021ms] com.example.service.UserService:validateInput() #1
        +---[5.001ms] com.example.service.UserService:queryFromDB()   #2  <-- 这一步最耗时,5ms
        `---[0.101ms] com.example.service.UserService:buildResponse() #3

解读:一眼看出 queryFromDB 方法消耗了绝大部分时间(5/6 ms)。

进阶

  • 条件过滤:只跟踪耗时超过X毫秒的调用。
    trace com.example.service.UserService getUser '#cost > 10'
  • 追踪到JDK或框架内部:默认只追踪到方法第一层子调用,如果想看内部细节(如JdbcTemplate到底执行了哪个SQL):
    trace --skipJDKMethod false com.example.service.UserService getUser

聚合统计:monitor (适合稳定复现的慢问题)

monitor 用于统计一段时间内方法的调用次数、成功/失败次数、平均耗时最大/最小耗时

场景:你不是想看某一次调用,而是想看“这个接口过去30秒的平均耗时是多少?”

用法

# 监控 UserService 的 getUser 方法,每5秒输出一次统计
monitor -c 5 com.example.service.UserService getUser

输出:会显示调用次数、总耗时、平均耗时、成功/失败率等,这是定位系统整体性能瓶颈的好方法。


查看出入参和耗时:watch (精准定位)

watch 可以查看方法的入参、出参、异常和耗时,比 trace 更轻量,适合观察某个特定方法的具体行为。

场景:想知道“这个方法返回了什么,以及这次调用花了多久?”

用法

# 查看方法入参、出参、耗时(exp条件中的 #cost 就是耗时,单位ms)
watch com.example.service.UserService getUser "{params, returnObj, #cost}" -x 2

-x 2 代表展开深度为2,防止打印大对象时内容被截断。


生成火焰图:async-profiler (终极诊断)

场景trace 打印的东西太多,或者不知道哪个路径慢,想看“整个请求链路上,CPU都在忙什么”。

用法(需安装 profiler 插件或使用新版Arthas):

# 启动CPU采样,30秒后停止
profiler start
# 采样一段时间后
profiler stop

生成的HTML火焰图可以直观看到每个栈帧的CPU消耗比例,是诊断CPU密集型或锁争用导致的耗时问题的利器。


跟踪多线程或异步调用

场景:业务使用了线程池(CompletableFutureExecutorService),主线程调用子线程后返回时间不准确。

用法(Arthas 3.3.0+):

# 开启父子线程关联,使得trace能跟踪到子线程里的调用
options unsafe true
trace com.example.service.AsyncService doAsyncTask '#cost > 1'

常见耗时问题类型与对应命令选择

问题现象 推荐命令 说明
接口整体慢,想快速定位瓶颈 trace 直接跟踪方法内部所有子调用耗时
方法总是慢,但想统计平均值 monitor 聚合统计,看平均/最大耗时
不知道哪里慢,想全局观察 async-profiler 火焰图,直观展示热点
只关心特定参数的慢调用 trace + 条件 '#cost > 100'
调用链非常深(几十层) stacktrace + 深度限制 trace -n 1 限制采样次数防刷屏
怀疑有死锁或长时间等待 thread -b 查看当前阻塞的线程

总结建议

  • 第一步:使用 trace com.your.service.YourMethod 直接看方法内部子调用耗时。
  • 第二步trace 显示最耗时的子调用是 JdbcTemplate.query(),可以使用 trace --skipJDKMethod false 进一步跟踪到SQL执行的具体耗时。
  • 第三步:如果是定时任务或循环执行,使用 monitor -c 10 聚合看平均耗时。

注意:在生产环境使用 trace 时,建议加上 -n 1'#cost > 100' 限制,避免打印过多日志拖慢业务。

抱歉,评论功能暂时关闭!