JVM进程诊断利器——arthas介绍

图片看不到的话可以看我的CSDN的博客
https://blog.csdn.net/u013332124/article/details/84888074

Arthas 是Alibaba开源的Java诊断工具,采用命令行交互模式,提供了丰富的功能,是排查jvm相关问题的利器。

在逛github时,发现了这款利器,深入了解之后,简直惊为天人。下面先列举一下它能做的一些事情:

  1. 提供性能看板,包括线程、cpu、内存等信息,并且会定时的刷新。
  2. 根据各种条件查看线程快照。比如找出cpu占用率最高的n个线程等
  3. 输出jvm的各种信息,如gc算法、jdk版本、ClassPath等
  4. 查看/设置sysprop和sysenv
  5. 查看某个类的静态属性,也可以通过ognl语法执行一些语句
  6. 查看已加载的类的详细信息,比如这个类从哪个jar包加载的。也可以查看类的方法的信息
  7. dump某个类的字节码到指定目录
  8. 直接反编译指定的类
  9. 查看类加载器的一些信息
  10. 可以让jvm重新加载某个类
  11. 监控方法的执行,同时可以获取到执行的入参、出参以及抛出的异常
  12. 追踪方法执行的调用栈,以及各个方法的调用时间

下面我会对如何使用这些功能做一个简单的介绍,也会加上一些自己对这些命令的理解。有一些命令不会介绍的太详细,因为官方文档已经写的很棒了,我没必要再这复述。想深入了解的朋友也可以直接去看arthas的官方文档,中文的,很容易阅读。

https://alibaba.github.io/arthas/install-detail.html

一、安装和使用arthas

官方文档:

https://alibaba.github.io/arthas/install-detail.html

安装

直接通过`java -jar启动:

wget https://alibaba.github.io/arthas/arthas-boot.jar
# 启动后会自动下载响应的lib到 ~/.arthas 目录下
java -jar arthas-boot.jar

或者直接下载arthas的压缩包,然后解压:

unzip arthas-packaging-bin.zip
# 执行
./as.sh

启动asthas进程后,它会列出所有的jvm进程,并让我们选择要attach哪个进程。attach目标进程后,就进入athas的交互命令行了,这时候就可以开始输入arthas对应的命令使用了

卸载

 rm -rf ~/.arthas/

二、athas的各个命令

1. dashboard

进入当前系统的实时数据面板,按 ctrl+c 退出。这个面板会实时刷新,其中包括线程信息、内存信息、gc信息、还有一些运行时的数据。

另外,当运行在Ali-tomcat时,会显示当前tomcat的实时信息,如HTTP请求的qps, rt, 错误数, 线程池信息等等

下面是arthas上面的一张demo图

在这里插入图片描述

2. thread

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

3. jvm

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

4. sysprop和sysenv

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

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

5. getstatic

通过该命令可以查看类的静态属性。不过查看类的静态属性ognl命令也可以做到,官方也比较推荐使用ognl表达式来做

不过使用getstatic可以使用通配符来查看变量,好像用ognl不行。(也可能是我对ognl表达式了解还不够)

# 查看CommonConstants类下的所有静态属性
getstatic *.CommonConstants *

6. ognl

通过ognl表达式来执行一些语句。

# 调用静态函数
ognl '@java.lang.System@out.println("hello")'
# 输出
null

# 获取静态类的静态字段
ognl '@demo.MathGame@random'
# 输出
@Random[
    serialVersionUID=@Long[3905348978240129619],
    seed=@AtomicLong[125451474443703],
    multiplier=@Long[25214903917],
    addend=@Long[11],
    mask=@Long[281474976710655],
    DOUBLE_UNIT=@Double[1.1102230246251565E-16],
    BadBound=@String[bound must be positive],
    BadRange=@String[bound must be greater than origin],
    BadSize=@String[size must be non-negative],
    seedUniquifier=@AtomicLong[-3282039941672302964],
    nextNextGaussian=@Double[0.0],
    haveNextNextGaussian=@Boolean[false],
    serialPersistentFields=@ObjectStreamField[][isEmpty=false;size=3],
    unsafe=@Unsafe[sun.misc.Unsafe@28ea5898],
    seedOffset=@Long[24],
]

# 执行多行表达式,赋值给临时变量,返回一个List
ognl '#value1=@System@getProperty("java.home"),#value2=@System@getProperty("java.runtime.name"), {#value1, #value2}'
# 输出
@ArrayList[
    @String[/opt/java/8.0.181-zulu/jre],
    @String[OpenJDK Runtime Environment],
]

ognl表达式在arthas中用的还是比较多的,语法也比较简单。在后面的monitor、watch、trace、stack等命令中都会排上用场。

关于ognl,这个userCase上有丰富的案例:

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

7. sc 和 sm

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

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

8. dump

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

9. jad

反编译已加载的类。让它变成可读的形式。

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

10. classloader

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

11. redefine

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

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

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

大体就是作者遇到项目中的日志一直输出[] [] [] No credential found,想要找到是哪个类输出的。由于大多数日志框架输出日志时都用到了StringBuilder,因此作者对StringBuilder的toString方法做了以下修改:

    @Override
    public String toString() {
        // Create a copy, don't share the array
        String result = new String(value, 0, count);
        if(result.contains("No credential found")) {
            System.err.println(result);
            new Throwable().printStackTrace();
        }
        return result;
    }

改完类之后再用redefine把修改后的StringBuilder加载进去,这样,当后面继续输出[] [] [] No credential found就可以知道到底是从哪里输出的了。

12. monitor

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

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

13. watch

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

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

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

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

相关参数:

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

14. trace

方法内部调用路径,并输出方法路径上的每个节点上耗时。但是该命令只能输出一级调用的方法耗时,往下的就不会输出了。比如我定义了一个类Test

public class Test{
    
    public void a(){
        b();
    }
    
    public void b(){
        c();
    }
    
    public void c(){
        //...
    }
}

当我要观察Test a时,trace命令只会输出b()的耗时,而不会输出c()的耗时。因为对方法a来说,只有b()是一级调用。

trace命令也可以使用条件表达式,来过滤一些不想要的输出

# 方法耗时大于100时才输出,且只输出1.其他条件过滤的语法可以看watch命令的demo
trace *.Common* test '#cost>100' -n 1

友情提醒下,trace 在执行的过程中本身是会有一定的性能开销,在统计的报告中并未像 JProfiler 一样预先减去其自身的统计开销。所以这统计出来有些许的不准,渲染路径上调用的类、方法越多,性能偏差越大。但还是能让你看清一些事情的。

这里存在一个统计不准确的问题,就是所有方法耗时加起来可能会小于该监测方法的总耗时,这个是由于 Arthas 本身的逻辑会有一定的耗时

15. stack

输出当前方法被调用的调用路径。用法和trace差不多

# 方法耗时大于100时才输出,且只输出1.其他条件过滤的语法可以看watch命令的demo
stack *.Common* test '#cost>100' -n 1

16. tt

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

在这里插入图片描述

从上图中我们可以看到,通过-i参数我们可以直接查看之前某次调用的详细信息。

# 指定第一个参数的mobile字段等于13989838402
tt -t *.CommonTest test params[0].mobile=="13989838402"
# 把之前记录的那些调用都输出来
tt -l
# 

replay某次调用:

# replay时间片的index=1002这次调用
tt -i 1002 -p

使用tt进行方法replay时,要注意2点

  1. ThreadLocal 信息丢失

    很多框架偷偷的将一些环境变量信息塞到了发起调用线程的 ThreadLocal 中,由于调用线程发生了变化,这些 ThreadLocal 线程信息无法通过 Arthas 保存,所以这些信息将会丢失。

    一些常见的 CASE 比如:鹰眼的 TraceId 等。

  2. 引用的对象

    需要强调的是,tt 命令是将当前环境的对象引用保存起来,但仅仅也只能保存一个引用而已。如果方法内部对入参进行了变更,或者返回的对象经过了后续的处理,那么在 tt 查看的时候将无法看到当时最准确的值。这也是为什么 watch 命令存在的意义。

17. options

options用来打开关闭某些功能:

名称 默认值 描述
unsafe false 是否支持对系统级别的类进行增强,打开该开关可能导致把JVM搞挂,请慎重选择!
dump false 是否支持被增强了的类dump到外部文件中,如果打开开关,class文件会被dump到/${application dir}/arthas-class-dump/目录下,具体位置详见控制台输出
batch-re-transform true 是否支持批量对匹配到的类执行retransform操作
json-format false 是否支持json化的输出
disable-sub-class false 是否禁用子类匹配,默认在匹配目标类的时候会默认匹配到其子类,如果想精确匹配,可以关闭此开关
debug-for-asm false 打印ASM相关的调试信息
save-result false 是否打开执行结果存日志功能,打开之后所有命令的运行结果都将保存到/home/admin/logs/arthas/arthas.log
job-timeout 1d 异步后台任务的默认超时时间,超过这个时间,任务自动停止;比如设置 1d, 2h, 3m, 25s,分别代表天、小时、分、秒
$ options save-result true                                                                                         
 NAME         BEFORE-VALUE  AFTER-VALUE                                                                            
----------------------------------------                                                                           
 save-result  false         true

18. help

通过help命令可以查看某个命令的使用详情

help tt
help stack
...

三、遇到的一些问题

在使用arthas的过程中,会遇到一些问题,这里做个记录。

1. attach错进程

在我们要去sc、jad某个类,发现arthas提示类没加载,但是我们很确定类已经加载了。这时候就要检查arthas attach的进程是不是我们目标的进程。在进入arthas交互界面时会输出一些信息,里面就有真正attach的进程id:

在这里插入图片描述

在上图我们可以看到,明明我选择的是要attach 37179这个进程,但实际arthas attach的是26792这个进程。这是由于我们之前用arthas attach过26792这个进程,并且没有执行 shutdown命令导致的。也就是说执行exit或者quit只会退出交互界面,不会关闭attach的arthas进程。

解决办法

再次进入arthas交互界面,执行 shutdown 命令,之后重新attach新的进程即可。

四、总结

在以前,我们排查线上jvm进程时,用的命令无非就是jps、jstack、jmap、jstat、jhat这些jvm命令。但是这些命令能做的事都比较有限。有了arthas,我们可以在线上进行更加丰富的操作,对我们排查问题有很大的帮助。

另外,想学习arthas的话,建议不要只看文档,最好自己手动把所有命令都试一遍,印象会比较深刻,下次遇到类似的问题也可以及时想到这个工具。

©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 202,607评论 5 476
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 85,047评论 2 379
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 149,496评论 0 335
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 54,405评论 1 273
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 63,400评论 5 364
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 48,479评论 1 281
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 37,883评论 3 395
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 36,535评论 0 256
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 40,743评论 1 295
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,544评论 2 319
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,612评论 1 329
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,309评论 4 318
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 38,881评论 3 306
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,891评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,136评论 1 259
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 42,783评论 2 349
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,316评论 2 342

推荐阅读更多精彩内容