Arthas 深入学习
一、序言
近期在做双十一大促稳定性保障，基于去年双十一团队压测过程中出现的 CPU 飙高和内存负载过大问题，提前整理下。本文主要讲述系统负载过高时排查思路、如何使用故障诊断工具 Arthas 来分析、定位问题。
二、CPU 高的问题
2.1、CPU 飙高的可能原因
1、慢 sql 会导致数据库 CPU 飙升
2、内存泄漏频繁的 GC 会导致 CPU 占用率飙升，比如经典的 ThreadLoad 弱引用没有调用 remove 方法导致的内存泄漏。
3、while 的无限循环和死锁导致也会导致 CPU 飙升，之前团队遇到的“parallelStream 和 lettuce 混合使用 case”
4、文件解析、序列化和反序列化也会导致 CPU 飙升。之前团队遇到的“反序列化导致 JVM Crash 的 case”
5、线程池设置不合理，频繁的线程上下文切换，导致 CPU 升高
频繁的 GC：GC 是 JVM 用于垃圾收集的操作，它需要计算内存和调用寄存器，需要大量的占用 CPU 资源。
2.2、CPU 飙高的排查思路
查看监控大盘，首先检查线程数，JVM，GC 情况，系统负载等参数。
使用这些参数来证明问题的原因。
最后使用 Arthas 工具 或 jstack 命令打印堆栈信息，分析线程使用情况。
2.3、通过 Arthas 工具排查了高 CPU 的问题
2.3.1、首先通过 dashboard 查看系统的实时数据面板
通过 dashboard 命令找出消耗 CPU 最多的线程和方法栈
如上图，通过 dashboard 命令查看实时数据面板(dashboard 的详细参数信息会在下面 Part 4 重点讲解)，重点关注下当前占用 CPU 比较多的 Top5 线程，同时看下目前的内存和 GC 情况，确认 CPU 飙高跟内存和 GC 是否有直接关联。
2.3.2、thread 命令：查看 Top5 的线程堆栈
thread -n 5 当前最忙的前 5 个线程并打印堆栈，从中可以看到当前最忙的线程正在运行的方法栈，如果连续多次打印出来的栈都一样，那说明栈顶的方法占用 cpu 时间过长，一般来说是有问题的。
命令执行结果说明：
没有线程 ID，包含
[Internal]表示为 JVM 内部线程。cpuUsage为采样间隔时间内线程的 CPU 使用率。deltaTime为采样间隔时间内线程的增量 CPU 时间，小于 1ms 时被取整显示为 0ms。time线程运行总 CPU 时间。Gang Worker 表示 G1 收集器的主线程
2.3.3、线程死锁排查
为了进行死锁排查，可以先执行 JVM 命令查看 DEADLOCK-COUNT 数值，该参数标识当前 JVM 死锁的线程数
然后再查看当前指定状态的线程，命令和执行结果如下，如果当前 BLOCKED 数量很大，那大概率是有问题的。
还可以使用 thread -b 命令找出当前阻塞其他线程的线程 （即当前占用锁的线程）
如果 thread 命令输出结果变动较大不易观察，则可以使用 profiler 生成火焰图进行深入分析，详见 Part 10 火焰图部分
2.3.4、分析出占用 CPU 较高的线程后，直接 jad 反编译相关代码来确认根因；
当我们找到占用大量 CPU 资源的线程后。我们希望分析出代码中哪些逻辑可能会执行这个操作，需要从方法栈上找出自己服务相关的类，并重点关注。
使用 jad 命令直接对自己服务中的类反编译：
--lineNumber 参数默认值为 true，显示指定为 false 则不打印行号。
2.4、CPU 高-常用的黑屏命令
这里补充下 CPU 高时常用的黑屏排查命令
> top
> ps -aux | grep 2838
> top -Hp 2838
> printf "%x\n” 4808
> jstack 2838 | grep 12c8 -A30
三、内存占用过大问题
通过 Dashboard 可以看到内存中各区使用情况和 GC 情况
3.1、内存高的可能原因
内存泄漏导致的内存溢出，比如 ThreadLoad 弱引用导致的内存泄漏。各种连接（线程池，连接池）问题
线程池队列设置问题：Executors.newFixedThreadPool(8) 创建的线程池的任务队列是无边界的，当调用量很大时会有堆积，导致内存一直被消耗
死循环等
注意：
当内存过大时需要重点关注下 GC 情况，Java 内存不够或者溢出会导致 GC overhead limit exceeded
具体的 GC 和 STW 时间可以登陆服务器上的下载 gc.log 进行查看
3.2、CPU 高-常用的黑屏命令
这里补充下内存过高的查询黑屏命令 特别注意：如果是线上环境，dump 之前必须先将流量切走，否则大内存 dump 是直接卡死服务。
> jmap -histo:live <pid> | head -20
> jmap -dump:format=b,file=filename <pid>
3.3、arthas 类似的操作命令
四、 JVM 的实时运行状态/实时数据面板
命令：dashboard
4.1、参数说明
4.2、命令执行
4.3、执行结果数据说明
ID: Java 级别的线程 ID，注意这个 ID 不能跟 jstack 命令中的 nativeID 一一对应。
NAME: 线程名
GROUP: 线程组名
PRIORITY: 线程优先级, 1~10 之间的数字，越大表示优先级越高
STATE: 线程的状态
CPU%: 线程的 cpu 使用率。比如采样间隔 1000ms，某个线程的增量 cpu 时间为 100ms，则 cpu 使用率=100/1000=10%
DELTA_TIME: 上次采样之后线程运行增量 CPU 时间，数据格式为秒
TIME: 线程运行总 CPU 时间，数据格式为分:秒
INTERRUPTED: 线程当前的中断位状态
DAEMON: 是否是 daemon 线程
usage:内存使用的百分比
4.4、JVM 内部线程
Java 8 之后支持获取 JVM 内部线程 CPU 时间，这些线程只有名称和 CPU 时间，没有 ID 及状态等信息（显示 ID 为-1）。通过内部线程可以观测到 JVM 活动，如 GC、JIT 编译等占用 CPU 情况，方便了解 JVM 整体运行状况。
当 JVM 堆(heap)/元数据(metaspace)空间不足或 OOM 时，可以看到 GC 线程的 CPU 占用率明显高于其他的线程。
当执行 trace/watch/tt/redefine 等命令后，可以看到 JIT 线程活动变得更频繁。因为 JVM 热更新 class 字节码时清除了此 class 相关的 JIT 编译结果，需要重新编译。
JVM 内部线程包括下面几种：
JIT 编译线程: 如 C1 CompilerThread0, C2 CompilerThread0
GC 线程: 如 GC Thread0, G1 Young RemSet Sampling , Gang Worker
其它内部线程: 如 VM Periodic Task Thread, VM Thread, Service Thread
五、接口 RT 过大/链路耗时分析
5.1、解决的问题
通过监控系统发现一个接口的 RT 比较大，怎么进行耗时分析？
想知道业务逻辑内部又调用了哪些方法以及方法耗时情况该如何分析？
5.2、trace 命令:查看方法调用链路及耗时
-n参数标识指定捕捉结果的次数。比如上面的例子就是捕捉到 5 次调用就退出命令。
如果方法的 QPS 很高，你只想输出耗时比较久的那次调用，可以添加条件表达式，如下
其中'#cost>1000'表示耗时超过 1000 毫秒的那次调用才输出。
如果你想连 jdk 里的方法调用也进行 trace，则需要显式设置 --skipJDKMethod false，默认是 true
5.3、针对特定入参的长耗时接口分析
如果我们发现接口的平均 RT 不高，但是个别 RT 很高，有可能特定入参有关系，可以使用 watch 观察方法入参，并根据方法执行时间来过滤慢请求的入参。
可以使用 watch 命令来观察方法入参
如上命令，表示需要监控耗时超过 100 毫秒的 doTask 方法的入参，并且输出入参，展开 2 层入参参数：
六、如何实现线上远程 debug
6.1、解决的问题
生产环境执行有问题不能 debug，线下又不能重现，该如何排查问题呢？可以使用 watch 配合 stack 快速定位问题。
6.2、watch 命令：查看参数 &返回值
6.3、watch 命令 + 条件断点
当监控一个方法时可能有很多地方调用，只想找到自己的调用怎么办呢？(类似条件断点) 可以加一个"params[0]" 然后获取里面的属性和自己特定的入参值进行比较例如
对于简单的业务逻辑基本就可以定位到问题了，如果是复杂的业务逻辑还需要再借助 stack 命令来查看该方法的调用栈，并配合 watch 命令查看各方法的入参。
6.4、stack 命令:输出当前方法被调用的调用路径（查看方法调用栈）
对于一个方法被执行但方法被执行的路径非常多的情况，有时根本不知道这个方法是从哪里被执行了，这时就需要 stack 命令。
如上图，可以查看到 doAddBidding 方法的调用方是谁，对于入参是特定条件的 stack 命令
七、如何判断静态常量值、确认 ark 配置是否生效
7.1、读取运行代码里面的静态常量值
7.2、确认 ark 当前的生效值
case：自己之前在线上预案开启后发现没有起到预期的效果，一度怀疑修改 ark 配置没有生效，那么到底如何确定动态更新的配置值是否生效呢？
7.2.1、命令解析
classloader -l 命令。记录下 springboot 的类加载器哈希值，如：28627a48（红框便是其哈希值 ）。提示：在使用 arthas 过程中 classloader -l 这个命令很有用，因为很多命令需要指定类加载器
ognl -c 28627a48 "@com.poizon.fusion.webmvc.utils.SpringContextUtils@applicationContext.getBean('assignSellerConfig').spuStatusList"
第二步是一个 ognl 表达式，其中 com.poizon.fusion.webmvc.utils.SpringContextUtils@applicationContext 指的是程序中的 applicationContext 的一个静态实例也就是说我们有这么一块代码(实际上我们引用的 fusion-webmvc 就有 ，第二步中的 assignSellerConfig 和 spuStatusList 是 Spring 容器的类名和对应的变量名
八、monitor 命令
8.1、解决的问题
压测环境，观察一个接口的平均 RT、失误率
验证一个接口的 RT、错误率飙升是否跟入参有关系
8.2、monitor 命令：统计一段时间内某个方法执行执行的次数，成功及失败率
这里以监听自己服务方法为例，每隔 10 秒监听一次，其中 -n 3 表示，表示执行次数，共监听 3 次；--cycle 20 每次监控间隔时间为 20 秒。
8.3、monitor 命令+过滤条件
也可以添加过滤条件，比如想要只监控 skuId=123456 的新增出价方法的执行，那么上面的命令修改如下：
其中条件表达式 'params[0].skuId==123456' 是一段 ognl 表达式。
（具体 ognl 的用法参考https://arthas.aliyun.com/doc/ognl.html）。
十、火焰图
火焰图是软件性能分析的利器。可以查看 CPU 耗时情况，了解系统瓶颈在哪里。
10.1、解决的问题
性能分析与优化
不确定哪个接口有问题，用于先锁定有问题的接口
火焰图可以观测运行程序，每一段代码所占用的 cpu 的时间和比例,从而可以分析并找到项目中占用 cpu 时间最长的代码片段，优化热点代码，达到优化内存的效果。
10.2、火焰图
y 轴表示调用栈，每一层都是一个函数。调用栈越深，火焰就越高，顶部就是正在执行的函数，下方都是它的父函数。
x 轴表示抽样数，如果一个函数在 x 轴占据的宽度越宽，就表示它被抽到的次数多，即执行的时间长。注意，x 轴不代表时间，而是所有的调用栈合并后，按字母顺序排列的。
火焰图里，X 轴越长,代表使用的越多,Y 轴是调用堆栈信息。当前收集的是什么类型的数据，比如 cpu 那么 x 轴长度越大,占用的 cpu 资源就越多~。
火焰图就是看顶层的哪个函数占据的宽度最大。只要有"平顶"（plateaus），就表示该函数可能存在性能问题。
颜色没有特殊含义，因为火焰图表示的是 CPU 的繁忙程度，所以一般选择暖色调。
10.3、启动火焰图
如果 thread 命令输出结果变动较大，不易观察，则可以使用
profiler -e cpu start --duration 120 解释：CPU使用情况该命令表示从现在开始后台运行火焰图制作，运行时间 120s,到时间后在相应目录可以保存到 html 文件中，下载下来在浏览器查看，其中异常宽的栈就是有问题的方法栈
拓展
十一、备注
arthas 是通过 java agent 的方式实现，会一定程度的影响我们系统的性能，所以不使用 arthas 的时候，记得使用 stop 命令结束 arthas。
（注：如果 arthas 意外退出，植入的代码并不会被删除（测试环境验证了下），需要使用 arthas 重新连接目标进程，再执行 stop）
版权声明: 本文为 InfoQ 作者【Monin】的原创文章。
原文链接:【http://xie.infoq.cn/article/1db184a9136ea561400f0cb22】。文章转载请联系作者。
道术器用 2022-08-16 加入
还未添加个人简介
评论