1 Arthas介绍
Arthas 是一款线上监控诊断产品,通过全局视角实时查看应用 load、内存、gc、线程的状态信息,并能在不修改应用代码的情况下,对业务问题进行诊断,包括查看方法调用的出入参、异常,监测方法执行耗时,类加载信息等,大大提升线上问题排查效率。
Arthas 用户文档:https://arthas.aliyun.com/doc/
对于如何使用Arthas官方文档做得非常详细,本篇主要内容概要:
- 对Arthas命令按作用对象进行了分类
- 对于典型故障场景,分享如何使用Arthas查找问题原因并使用Arthas救火。
- 分享如何使用arthas获取Spring context容器并获取项目中的bean。
- 最后分享实例即将OOM时,如何使用Arthas清理无用的全局对象,以避免OOM。
2 常用命令归类
arthas有40多个工具命令,下面列出的是处理问题常用的工具
看板 | dashboard |
线程栈 | thread |
方法相关 | watch、trace、stack、tt、monitor、sm |
类相关 | getstatic、sc、jad、classloader、dump |
日志调整 | logger |
jvm相关 | jvm、sysenv、sysprop、jvmoption、perfcounter、heapdump、mbean |
手动运行静态方法 | ognl |
热更新代码 | mc、redefine/retransform |
2.1 线程(thread)
参数名称 | 参数说明和用途 | 示例 |
id | 查看指定线程的堆栈 | thread 1 |
[-n:] | 指定最忙的前N个线程并打印堆栈 | thread -n 5 |
[-b] | 找出当前阻塞其他线程的线程 | thread -b |
[-i <value>] | 指定cpu使用率统计的采样间隔,单位为毫秒,默认值为200 | thread -i 2000 |
[--all] | 显示所有匹配的线程 | thread --all |
thread命令局限性:
-
不能一次打印全部线程的stack,对于waitting状态的异常线程需要逐一查看堆栈。解决办法是使用jdk的jstack命令。
2.2 方法相关
命令 | 公共参数 | 可选常用参数 | 主要用途和场景 |
watch | class-pattern: 类名 method-pattern: 方法名 <condition-express>: 条件表达式(ognl) [-n, --limits <value>]: 执行次数,默认100 [-E, --regex]: 使用正则表达式 [--exclude-class-pattern <value>]: 排除类 [--listenerId <value>]:追加另一个监控ID [-v, --verbose]: 打印verbose信息,默认false | [-b, --before]: 在方法调用之前观察 [-e, --exception]: 在方法异常之后观察 [-s, --success]: 在方法返回之后观察 [-f , --finish]: 在方法结束之后(正常返回和异常返回)观察,默认开启 <express>: 观察表达式,即要观察的内容(ognl) [-x, --expand <value>] 观察结果展开级别,默认1 [-M, --sizeLimite <value>] 结果大小,默认10M | 用于方法执行数据观测,入参、返回值、异常、当前调用对象等
|
trace | [--skipJDKMethod <value>]跳过sdk方法,默认true | 方法内部调用路径,并输出方法路径上的每个节点上耗时
| |
stack | 输出当前方法被调用的调用路径
| ||
monitor | [-b, --before]: 在方法调用之前执行条件表达式 [-c, --cycle <value>] 监控周期,默认60秒 | 方法执行监控,耗时、调用次数、异常次数统计
| |
tt | 保存记录: [-t, --time-tunnel]开启tt记录 [-M, --sizeLimite <value>] 结果大小,默认10M 查看记录: [-l, --list]列出当前所有记录 [-s, --search-express <value>] 搜索表达式(ognl) [-i, --index <value>]使用指定索引号的记录 [-w, --watch-express <value>] 查看表达式(ognl) [-x, --expand <value>] 观察结果展开级别,默认1 [-p, --play] 重新执行指定索引号的记录 [--replay-interval <value>] 执行时长 [--replay-times <value>] 执行次数 删除记录: [-d <value>] [--delete-all] 删除tt记录 | 作用:保存方法每次调用的入参和返回信息,并能观测分析对这些信息。结合其它命令还可做线上debug
tt -t com.xxx.Class1 method1 -n 1
tt -l
tt -i 1000 -w 'params'
tt -i 1000 -p
tt --delete-all |
ognl表达式内置对象和变量:target、params、returnObj、throwExp、isThrow、#cost
2.3 类相关常用命令
命令 | 公共参数 | 可选常用参数 | 主要用途 |
sc | class-pattern: 类名 [-c <value>]: 指定类加载器的hash值 [--classLoaderClass <value>]: classloader类名 [-n, --limits <value>]: 执行次数,默认100 [-E, --regex]: 使用正则表达式 | [-d, --detail]: 详细信息 [-f, --field]: 显示类所有的成员变量 [-x, --expand <value>] 观察结果展开级别,默认0 | 查看JVM已加载的类信息
|
getstatic | <field-pattern> 静态变量名 <express> 观察表达式,即要观察的内容(ognl) [-x, --expand <value>] 观察结果展开级别,默认1 |
| |
jad | [--source-only] 只展示反编译代码 <method-name>只反编译指定方法 | 反编译指定已加载类的源码
|
2.4 其它常用命令
命令 | 公共参数 | 可选常用参数 | 主要用途 |
logger | [-c <value>]: 指定类加载器的hash值 [--classLoaderClass <value>]: classloader类名 | [-n, --name] logger名称,根logger为root [-l, --level] 设置日志级别 |
|
ognl | <express> 观察表达式,即要观察的内容(ognl) [-x, --expand <value>] 观察结果展开级别,默认1 | 执行OGNL表达式
|
3 典型业务故障分析
-
cpu负载高问题如何定位原因?
-
接口耗时飙升如何定位原因?
-
接口异常如何定位数据不正确的原因?
3.1 CPU负载高问题定位
3.1.1 问题定位思路
在流量不大的情况下,cpu负载高可能是因为循环次数非常大甚至死循环
-
找到耗CPU高的进程
-
找到进程内耗CPU高的线程
-
找到线程内耗CPU高的代码行
通常做法
#找到占CPU大的进程
top
#找到占CPU高的线程
top -p 进程号 -H
#将线程ID转换为16进制
printf "%x\n" tid
jstack pid | grep 16进制tid #打印线程堆栈
3.1.2 Arthas如何定位?
#查看占用CPU比较大的前10个线程
thread -n 10
#查看指定id号的线程堆栈,找到问题代码行
thread id
#查看源码,如果没有源码,反编译指定方法
jad com.xx.yy.zz.Class1 method 1
3.1.3 跳出死循环
问题:在不能立马上线的情况下,如何立马解决死循环?
-
如果循环内有sleep/wait/await等阻塞方法,可通过循环内watch某个方法,在ognl表达式中获取线程实例并执行interrupt方法
watch com.xx.arthas.Demo1 run '@java.lang.Thread@currentThread().interrupt()' -n 1
-
使用ognl表达式修改对象属性值以满足循环终止条件
-
使用ognl表达式修改对象属性值以便往循环外抛出异常
-
没法终止线程,可通过循环内watch某个方法,在ognl表达式中使线程休眠让出CPU
watch com.xx.arthas.Demo1 run '@java.lang.Thread@sleep(20000)' -b &
3.2 接口耗时飙升问题定位
3.2.1 根因典型场景
-
CPU负载高(定位方法上面提过)
-
网络流量大、延迟
-
磁盘负载
-
远程方法调用耗时
-
数据库访问耗时
-
粗粒度的线程同步块
-
程序执行步骤多,时间复杂度高
-
数据量大处理速度慢
-
与高耗时的任务共用线程池资源
-
连接池小或者连接对象放回连接池时间延迟
3.2.2 问题定位思路
-
排除硬件环境因素,如CPU、磁盘、网络、内存。(top\free\dstat命令)
-
排除数据库(mysql/redis/ES等)性能问题(数据库监控)
-
排除第三方接口耗时
-
排查内部接口耗时
-
检查代码逻辑
痛点,上面排查过程,耗时也非常长,如果每步平均要2分钟,定位一个问题也要10分钟左右,如果有一个很快排除其它因素而定位到问题原因或者方向的工具就太好了,而使用arthas可以勉强做到。
3.2.3 Arthas使用
-
启动arthas
-
执行dashboard命令查看有无占CPU高的线程、内存、gc情况
-
从问题方法开始,逐层从耗时高的方法节点使用trace命令,最终找到耗时高的外部接口或内部方法
#查看jvm实时状况
dashboard
#追踪耗时100ms以上的请求,在方法中哪一步执行比较耗时
trace com.xx.Class1 method1 '#cost>100'
#重复第一步逐层追踪,也可以用下面正则表达式同时追踪多个方法
trace -E com.xx.Class1|com.yy.Class2|...|Classn method1|method2|...|methodn '#cost>100'
辅助命令:
stack: 查看问题方法的调用栈,用于回溯问题方法被调用的源头,定位方法参数的传输路径
watch: 查看问题方法执行的参数、返回值,用于定位数据量大造成方法处理时间长、网络传输慢
jad: 反编译源代码查看代码逻辑
技巧:
trace的过程借助源代码分析进行,避免不必要的trace操作,以免耽误更多时间
3.1.4 内部接口耗时飙升
典型原因
-
数据量大,造成循环次数过多
-
粗粒度的线程同步块,锁竞争
-
wait/sleep等阻塞方法时间长
问题分析思路
-
查看方法入参和调用者对象信息
-
查看代码源码
Arthas使用
以上原因都可以用下面命令排查
#查看jvm实时状况
dashboard
#追踪耗时100ms以上的请求,在方法中哪一步执行比较耗时
trace com.xx.Class1 method1 '#cost>100'
#重复第一步逐层追踪,也可以用下面正则表达式同时追踪多个方法
trace -E com.xx.Class1|com.yy.Class2|...|Classn method1|method2|...|methodn '#cost>100'
3.1.6 Mysql查询超时
典型原因
-
SQL中没有使用索引
-
请求数据量大
-
连接池连接获取延迟
分析思路
-
查看SQL
-
查看mysql返回数据量大小
-
连接获取耗时高时查看连接池信息
-
连接获取耗时高时查看追踪方法耗时点
Arthas使用
#查看SQL
watch java.sql.Statement execute* '{params, target}' -x 3 '#cost>50'
#追踪耗时超过20ms时,获取连接的执行步骤中哪一步耗时高
trace javax.sql.DataSource getConnection '#cost>20'
3.3 流程逻辑异常分析
3.3.1 不能定位到抛出异常的代码点在哪里
原因:没有异常栈信息,不能定位问题
Arthas使用
trace com.xx.Class1 method1
-
通过trace命令就可以看到方法内部执行了哪些行的代码
-
结合源代码查看哪一步没有执行,那么异常就在上一步中抛出
-
找到异常点,分析异常原因
3.3.2 异常原因定位
异常发生,堆栈也有。如果找不到异常点,看上一节。由于参数不正确造成异常,那么如何找到造成参数不正确的原因呢?
典型原因
-
源头传入的参数就不正确
-
方法在执行流程中更改了数据
-
全局状态在某个异常时被更改,而异常点不明且不能复现。正常流程获取不到正确的状态而抛异常。
-
jar包冲突
-
jar包版本问题
Arthas使用
#查看源头方法参数
watch com.xx.Class1 method1 params -x 3
#查看哪个地方修改了方法
stack com.xx.Class2 setMethod2
sc -d com.xx.Class1
4 其他场景技巧
4.1 获取SpingContext
获取方法
-
从dubbo中获取
ognl '#c = @org.apache.dubbo.config.spring.extension.SpringExtensionFactory@CONTEXTS.iterator().next(),#c.getBean("beanName")' -c 6bb489f8
-
Spring mvc使用tt命令获取(需要触发一条http请求)
tt -t org.springframework.web.servlet.DispatcherServlet doService -n 1
tt -i 1000 -w '#c=target.webApplicationContext, #c.getBean("beanName")'
适用场景
-
查看某个bean是否被正确初始化,比如查看参数是否正确
-
想要手动触发某个bean的方法来处理线上问题
-
想要复现线上问题
4.2 查看异常调用栈
无异常堆栈时,如何查看调用堆栈?
watch demo.MathGame primeFactors "{params, throwExp, @java.lang.Thread@currentThread().getStackTrace()}" -x 2 -e
4.3 调整日志级别
logger -n com.xx -l info -c 6bb489f8
注意,
1. 建议指定-c参数,即类加载器的hash值
2. 生产上修改日志级别后,别忘了调整回来
4.4 OOM
典型原因
-
jvm内存设置太小
-
创建对象的速度大于垃圾回收的速度
-
代码问题,有大量本应该释放引用的对象没被释放,这样的对象随着时间的增长而增长,而GC不掉,最终OOM。
处理方式
针对第3个问题,dump出jvm内存数据进行分析,找到那些无用的对象的持有者,比如是一个静态Map实例,可使用ognl表达式清除map中的数据,以便可以GC掉,如
ognl '@com.xx.Class1@staticMap.clear()'
也可以用watch命令在后台按照一定条件清理,如
watch com.xx.Class1 method '@com.xx.Class1@staticMap.size()>1000&& @com.xx.Class1@staticMap.clear()' &
5. 总结
- mc、redefine:mc组合rdefine可以对代码进行热更新,不满足生产运行管理规范要求。
- JVM内存不足,arthas挂上去可能导致系统崩溃;
- 用完Arthas一定要执行stop清除arthas在应用中加载的类和对象,session掉了也要重新连接后stop;