03)阿里 Arthas(阿尔萨斯)开源的 Java 诊断工具使用-排查web项目请求后响应超时或响应慢;trace、stack、profiler指令使用
阿里 Arthas(阿尔萨斯)开源的 Java 诊断工具使用-排查web项目请求后响应超时或响应慢、controller到service到dao层执行慢的方法、代码排查
当一个HTTP接口执行特别慢,且涉及Controller -> Service -> DAO 多层调用和SQL执行时,使用 Arthas(阿里巴巴开源的Java诊断工具)可以非常高效地定位性能瓶颈。以下是系统性的排查步骤,帮助你精准定位到“哪个方法的哪一段代码最慢”。
总体思路
- 定位慢请求的调用链路耗时分布(哪个方法耗时最长)
- 深入分析耗时方法内部的子方法或代码段(如SQL执行、循环、远程调用等)
- 重点分析SQL执行时间(DAO层)
模拟服务响应慢场景
在服务的dao层加了一个sleep休眠10S
现在请求后需要10.2才有响应
trace排查问题(具体情况具体分析)
Arthas 怎么附加到selfServiceMachine应用进程步骤在以下文章
01)阿里 Arthas(阿尔萨斯)开源的 Java 诊断工具下载、入门教程,windwos/linux系统使用Arthas备注
选择需要附加的进程成功后如下图所示
步骤一:使用 trace 命令定位整体调用链路耗时
trace 命令可以统计方法调用路径中每个节点的耗时,非常适合分析性能瓶颈。
先使用trace 跟踪controller层 请求入口方法
trace com.bsoft.selfServiceMachine.controller.MachineController getReportRecordByTjbhOrZjm
跟踪上了方法
前端调用下selfServiceMachine/machineController/getReportRecordByTjbhOrZjm服务触发
Arthas 跟踪getReportRecordByTjbhOrZjm方法执行输出的内容
源码内容,可以看到Arthas 跟踪输出的内容和源码对应的,已经明确显示了107行 machineService.getReportRecordByTjbhOrZjm方法执行了 约10S
检测到service层执行了约10S,使用trace 跟踪service层方法
由于已经代码,service层就一个调用dao的代码,这里基本锁定在dao层了
trace com.bsoft.selfServiceMachine.service.impl.MachineServiceImpl getReportRecordByTjbhOrZjm
检测到dao层执行了约10S,使用trace 跟踪dao层方法
trace com.bsoft.selfServiceMachine.dao.MachineDao getReportRecordByTjbhOrZjm
输出dao层执行了约10S,显示dao层调用的方法执行最慢的也是4ms,并没有显示sleep方法执行了10S,
原因是因为 sleep 是 JDK 阻塞调用,不产生子方法,trace 不会展开它,不过看到这个输出至少告诉了我们正常的业务方法都不卡,我们看下代码是不是有Thread.sleep、Lock、I/O 阻塞、无限循环 这类“不产生方法调用但耗时”的问题
使用 stack 实时抓取调用栈
stack com.bsoft.selfServiceMachine.dao.MachineDao getReportRecordByTjbhOrZjm
stack就是打印方法执行的栈信息
从servlet入口方法直到调用到MachineDao getReportRecordByTjbhOrZjm方法的中间过程,但是没有调用时间之类的显示,只能用来看栈链信息
profiler 火焰图排查问题(不支持windwos)
Arthas 的 profiler 命令底层依赖的是 Async-Profiler,这是一个由 Alibaba 开源的高性能采样分析器。
对于 Thread.sleep、Lock、I/O 阻塞、无限循环 这类“不产生方法调用但耗时”的问题,一定要用 profiler 火焰图,它是 Arthas 中最强大的性能分析工具。
找了一台linux服务器使用tomcat容器启动selfServiceMachine项目,端口8089
由于服务器有多个tomcat启动,无法区分的话就先使用tomcat端口号查询出进程PID在选择即可
# 启动
profiler start
调用几次接口后停止
# 停止,停止后会打印出分析内容的存储位置
profiler stop
不过看不懂…