Arthas排查jvm相关问题的利器

Java领地

共 4786字,需浏览 10分钟

 ·

2022-07-30 18:17

背景:

一次线上问题的综合排查排查,两个相同的系统的某个模块,数据量更少的系统查询更慢。
先说下整体思路:

  1. 查看系统整理负载,网络有100左右毫秒的延迟,看起来影响不大


  2. 查看正序运行整体情况,一次查询会经历3次FGC,有问题,解决后虽然会快一些但是还是有点慢

  3. 跟踪调用栈,发现有点在获查询结果的时候特别慢

  4. 排查是否有mysql慢查询(定义为1秒以上的查询),结果是没有

  5. 通过arthas发现调用了20多次查询,每次网络延迟100ms,加起来就有2s了,定位出问题。

这样看起来arthas真的很强大,它不仅仅能处理上述问题,还能….

  • 这个类从哪个 jar 包加载的?为什么会报各种类相关的 Exception?

  • 我改的代码为什么没有执行到?难道是我没 commit?分支搞错了?

  • 遇到问题无法在线上 debug,难道只能通过加日志再重新发布吗?

  • 线上遇到某个用户的数据处理有问题,但线上同样无法 debug,线下无法重现!

  • 是否有一个全局视角来查看系统的运行状况?

  • 有什么办法可以监控到JVM的实时运行状态?

  • 代码出现异常,怎么能获取请求参数和返回值。

Arthas到底是什么

Arthas 是Alibaba开源的Java诊断工具,采用命令行交互模式,提供了丰富的功能,是排查jvm相关问题的利器。
在逛github时,发现了这款利器,深入了解之后,简直惊为天人。下面先列举一下它能做的一些事情:

  • 提供性能看板,包括线程、cpu、内存等信息,并且会定时的刷新。

  • 根据各种条件查看线程快照。比如找出cpu占用率最高的n个线程等

  • 输出jvm的各种信息,如gc算法、jdk版本、ClassPath等

  • 查看/设置sysprop和sysenv

  • 查看某个类的静态属性,也可以通过ognl语法执行一些语句

  • 查看已加载的类的详细信息,比如这个类从哪个jar包加载的。也可以查看类的方法的信息

  • dump某个类的字节码到指定目录

  • 直接反编译指定的类

  • 查看类加载器的一些信息

  • 可以让jvm重新加载某个类

  • 监控方法的执行,同时可以获取到执行的入参、出参以及抛出的异常

  • 追踪方法执行的调用栈,以及各个方法的调用时间

Arthas运行原理

Arthas命令列表

athas的各个命令

sc 和 sm

  • 通过sc可以查看已加载类的相关信息,比如该类是从哪个jar包加载的,被哪个类加载器加载的,以及是否是接口等等。

  • sm查看已加载类的方法详情。

dashboard

进入当前系统的实时数据面板,按 ctrl+c 退出。这个面板会实时刷新,其中包括线程信息、内存信息、gc信息、还有一些运行时的数据。
另外,当运行在Ali-tomcat时,会显示当前tomcat的实时信息,如HTTP请求的qps, rt, 错误数, 线程池信息等等。

thread

通过thread命令可以查看当前jvm进程的线程详情。可以查看线程的cpu使用时间占比,通过指定各种参数可以找出最忙的几个线程,以及阻塞其他线程的线程。具体如何使用这里不多做介绍,大家可以去看arthas的官方文档。


1
2
3
当前最忙的前N个线程并打印堆栈
thread -i 5000
thread -i 5000


jvm

通过jvm命令直接输出当前jvm的各种信息。

getstatic

通过getstatic命令可以方便的查看类的静态属性。


1
getstatic demo.MahtGame random


sysprop和sysenv

  • 通过sysprop可以查看所有的系统变量,也可以设置某个系统变量。

  • 同理,通过sysenv可以查看所有的操作系统环境变量,也可以查看设置某个环境变量。

ognl

执行ognl表达式,可执行任意代码


1
Ognl @demo.MathGame@random


动态修改日志级别

  1. 通过ognl获取对应类上的logger对象实现类

  2. sc命令来查看具体从哪个jar包里加载的,sc -d org.apache.log4j.Logger

  3. 通过ognl修改日志级别

更详细的介绍:https://github.com/alibaba/arthas/issues/11

dump

将已加载类的字节码dump到本地磁盘上。

jad

有时我们经常会不确定线上或者测试环境的包是否是我们修改过的,这时候就可以通过jad反编译来看下。


1
反编译指定已加载类的源码,jad demo.MathGame


classloader

将 JVM 中所有的classloader的信息统计出来,并可以展示继承树,urls等。

redafine

该命令可以加载外部的.class文件,然后覆盖 jvm已加载的类。注意,这个命令不一定都能覆盖成功,如果添加了新的field,就不会加载成功。

关于redefine,arthas的github上有个非常经典的userCase:

https://github.com/alibaba/arthas/issues/263

动态更新代码,不用重启jvm

watch

  • 让你能方便的观察到指定方法的调用情况。能观察到的范围为:返回值、抛出异常、入参,通过编写 OGNL 表达式进行对应变量的查看。

  • watch的使用姿势比较丰富,可以在四个不同的场景观察方法的执行。比如方法调用之前、方法调用之后、方法异常之后、方法结束之后。默认观察的是方法结束之后。

  • 如果观察的是方法结束之后的场景,由于入参可能在执行方法时被改变,所以此时输出的可能不是真正的入参。因此,要看真正的入参,要看方法调用之前的,也就是加上-b的参数。

  • 另外,使用-b参数观察的话,则观察不到方法返回的结果以及抛出的异常了。

参数名称参数说明
class-pattern类名表达式匹配
method-pattern方法名表达式匹配
express观察表达式
condition-express条件表达式
[b]在方法调用之前观察
[e]在方法异常之后观察
[s]在方法返回之后观察
[f]在方法结束之后(正常返回和异常返回)观察
[E]开启正则表达式匹配,默认为通配符匹配
[x:]指定输出结果的属性遍历深度,默认为 1
[n:]只执行n次,默认会不断输出,除非用户按下cltr+c


1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
# 观察CommonTest的test方法
# 输出 入参、返回结果、抛出的异常 —— 输出的内容可以动态调整
# 后面跟着的是 条件表达式,表示耗时超过10ms才输出
# -n 表示只执行一次,-x表示 入参和返回结果的展开层次为5层
watch *.CommonTest test "{params,returnObj,throwExp}" '#cost>10' -x 5 -n 1

# 耗时大于10ms并且第一个参数等于1才输出
watch *.CommonTest test "{params,returnObj,throwExp}" '#cost>10 && params[0]==1' -x 5 -n 1
# 第一个参数大于1 并且第二个参数等于hello才输出
watch *.CommonTest test "{params,returnObj,throwExp}" 'params[0]>1 && params[1]=="hello"' -x 5 -n 1
# 第一个参数小于5或者第二个参数等于"world"就输出
watch *.CommonTest test "{params,returnObj,throwExp}" 'params[0]<5 || params[1]=="wolrd"' -x 5 -n 1
# 第一个参数的name字段等于world时才输出。
# 由于在方法执行过程中参数的name属性可能发生改变,因此加上-b才能观察到真正的入参
watch -b *.CommonTest test "{params,returnObj,throwExp}" 'params[0].name=="wolrd"' -x 5 -n 1

# 由于同时指定了-s和-b,所以方法被调用一次,就会输出2次结果(两个场景分开输出),分别是方法被调用前,和返回之后
# 注意,这里如果-n只设置成1,那么只会输出-b对应的输出,-s对应的输出由于没有次数了就无法输出了
watch *.CommonTest test '{params,returnObj,throwExp}' -x 5 -n 2 -s -b


在填写条件表达式时要注意一点,条件表达式中的params默认都是获取的方法执行完后的参数信息,比如入参a的属性name方法执行前是”hello”,在方法执行后变成了”world”,那么条件表达式传入’params[0].name=”hello”‘将不会输出,只有填入’params[0].name=”hello”‘才可以匹配上。这点对于后面的trace、stack命令也是一样的。

查看方法输入参数/返回值/异常信息,watch demo.MathGame primeFactors “{params,returnObj}” -x 2

monitor

monitor命令可以监控方法的执行情况。比如调用成功次数,失败次数,失败率、平均执行时间等等。默认120秒输出一次,也就是说,当我们输入monitor命令之后,每120秒就会输出一次统计结果。

通过-c参数可以修改输出频率,支持通配符和正则表达式。
monitor -c 5 demo.MathGame primeFactors

trace

方法内部调用路径,并输出方法路径上的每个节点上耗时,tt命令会记录每次方法调用的各种信息。它和watch有些相似但是它能记录下各个时间点的调用信息,之后随时查看,甚至replay这次调用。


1
trace demo.MathGame run


tt

timetunnel,记录下指定方法每次调用的入参和返回信息,并能对这些不同的时间下调用进行观测,同时可回放该方法调用
tt -t demo.MathGame primeFactors

直接重放请求参数


1
2
1.使用tt –t 类名次 方法名次
2.tt –play -i 1000



另外介绍几个我经常用的工具,jmap,jstat,jstack,dump这些基本的就不介绍了。

Tprofiler

TProfiler是一个可以在生产环境长期使用的性能分析工具.它同时支持剖析和采样两种方式,记录方法执行的时间和次数,生成方法热点 对象创建热点 线程状态分析等数据,为查找系统性能瓶颈提供数据支持.

TProfiler在JVM启动时把时间采集程序注入到字节码中,整个过程无需修改应用源码.运行时会把数据写到日志文件,一般情况下每小时输出的日志小于50M.

show-busy-java-threads

  • 查找cpu性能消耗过程
    top命令找出消耗CPU高的Java进程及其线程id:
    开启线程显示模式(top -H,或是打开top后按H)
    按CPU使用率排序(top缺省是按CPU使用降序,已经合要求;打开top后按P可以显式指定按CPU使用降序)
    记下Java进程id及其CPU高的线程id

  • 查看消耗CPU高的线程栈:
    用进程id作为参数,jstack出有问题的Java进程
    手动转换线程id成十六进制(可以用printf %x 1234)
    在jstack输出中查找十六进制的线程id(可以用vim的查找功能/0x1234,或是grep 0x1234 -A 20)

  • 查看对应的线程栈,分析问题
    查问题时,会要多次上面的操作以分析确定问题,这个过程太繁琐太慢了。

  • 参考:https://blog.csdn.net/u013332124/article/details/84888074#11_redefine_157

浏览 129
点赞
评论
收藏
分享

手机扫一扫分享

分享
举报
评论
图片
表情
推荐
点赞
评论
收藏
分享

手机扫一扫分享

分享
举报