arthas之profiler火焰图基本使用和实践

profiler火焰图

目标

生成火焰图

介绍

profiler 命令支持生成应用热点的火焰图。本质上是通过不断的采样，然后把收集到的采样结果生成火焰图。

命令基本运行结构是 profiler 命令 [命令参数]

案例

启动profiler

$ profiler start
Started [cpu] profiling

默认情况下，生成的是cpu的火焰图，即event为cpu。可以用--event参数来指定。

显示支持的事件

$ profiler list

获取已采集的sample的数量

$ profiler getSamples
23

查看profiler状态

$ profiler status
[cpu] profiling is running for 4 seconds

可以查看当前profiler在采样哪种event和采样时间。

停止profiler

生成svg格式结果

$ profiler stop
profiler output file: /tmp/demo/arthas-output/20191125-135546.svg
OK

默认情况下，生成的结果保存到应用的工作目录下的arthas-output目录。可以通过 --file参数来指定输出结果路径。比如：

$ profiler stop --file /tmp/output.svg
profiler output file: /tmp/output.svg
OK

生成html格式结果

默认情况下，结果文件是svg格式，如果想生成html格式，可以用--format参数指定：

$ profiler stop --format html
profiler output file: /tmp/test/arthas-output/20191125-143329.html
OK

或者在--file参数里用文件名指名格式。比如--file /tmp/result.html 。

通过浏览器查看arthas-output下面的profiler结果

默认情况下，arthas使用3658端口，则可以打开： http://localhost:3658/arthas-output/ 查看到arthas-output目录下面的profiler结果：

点击可以查看具体的结果：

火焰图的含义

火焰图是基于 perf 结果产生的SVG 图片，用来展示 CPU 的调用栈。

y 轴表示调用栈，每一层都是一个函数。调用栈越深，火焰就越高，顶部就是正在执行的函数，下方都是它的父函数。

x 轴表示抽样数，如果一个函数在 x 轴占据的宽度越宽，就表示它被抽到的次数多，即执行的时间长。注意，x 轴不代表时间，而是所有的调用栈合并后，按字母顺序排列的。

火焰图就是看顶层的哪个函数占据的宽度最大。只要有"平顶"（plateaus），就表示该函数可能存在性能问题。

颜色没有特殊含义，因为火焰图表示的是 CPU 的繁忙程度，所以一般选择暖色调。

小结

profiler	命令作用
profiler start	启动profiler，默认情况下，生成cpu的火焰图
profiler list	显示所有支持的事件
profiler getSamples	获取已采集的sample的数量
profiler status	查看profiler的状态，运行的时间
profiler stop	停止profiler，生成火焰图的结果，指定输出目录和输出格式：svg或html

Arthas实践

需求

1. 哪个Controller处理了请求

我们可以快速定位一个请求是被哪些Filter拦截的，或者请求最终是由哪些Servlet处理的。但有时，我们想知道一个请求是被哪个Spring MVC Controller处理的。如果翻代码的话，会比较难找，并且不一定准确。通过Arthas可以精确定位是哪个Controller处理请求。

2. 每个请求的调用参数和返回值是多少

通过watch来查看请求的参数和返回值

准备场景

将ssm_student.war项目部署到Linux的tomcat服务器下，可以正常访问。

启动之后，访问：http://192.168.254.199:8080/ssm_student ，会返回如下页面。192.168.254.199 是Linux服务器的地址。

那么这个请求是被哪个Controller处理的呢？

步骤

1. trace定位DispatcherServlet
2. jad反编译DispatcherServlet
3. watch定位handler
4. 使用watch得到方法的入参和返回值

实现步骤

第1步：

在浏览器上进行登录操作，检查最耗时的方法
trace *.DispatcherServlet *

可以分步trace，请求最终是被DispatcherServlet#doDispatch()处理了
trace *.FrameworkServlet doService

第2步：

trace结果里把调用的行号打印出来了，我们可以直接在IDE里查看代码（也可以用jad命令反编译）
jad --source-only *.DispatcherServlet doDispatch

第3步：

watch *.DispatcherServlet getHandler 'returnObj'
查看返回的结果，得到使用到了2个控制器的方法

第4步：

watch com.xdr630.controller.* * {params,returnObj} -x 2

结论

通过trace, jad, watch最后得到这个操作由2个控制器来处理，分别是：

com.xdr630.controller.UserController.login()
com.xdr630.controller.StudentController.findAll()

学习总结

命令	说明
dump	将已加载类的字节码文件保存到特定的目录中
classloader	获取类加载器的信息
monitor	监控指定类中方法的执行情况
watch	观察到指定方法的调用情况
trace	对方法内部调用路径进行追踪，并输出方法路径上每个节点上耗时
stack	输出当前方法被调用的路径
tt	记录指定方法每次调用的入参和返回信息
options	全局开关
profiler	生成火焰图