阿里开源Java诊断工具 Arthas 使用

Arthas 是阿里开源的 Java 诊断工具,相比 JDK 内置的诊断工具,要更人性化,并且功能强大,可以实现许多问题的一键定位,是我用到的最方便的诊断工具。
下载和安装见官网 https://arthas.aliyun.com/doc/profiler.html
下面记录一些我工作中常用到的指令

1. dashboard : 展示当前进程信息

主要是两部分: 线程信息(按照cpu使用率倒序) 和 内存信息
可以快速发现 当前前几个cpu使用高的线程

image.png

2. thread :查看当前 JVM 的线程堆栈信息

image.png
thread : 获取当前所有线程 (按照cpu使用率倒序) 
thread 4602 threathe : 获取指定线程堆栈信息
thread -n 8 : 当前最忙的前8个线程并打印堆栈
thread -n 8  -i 3000 : 列出3s内最忙的8个线程并打印堆栈(-i 为采样时间)
thread -b :找出当前阻塞其他线程的线程
有时候我们发现应用卡住了, 通常是由于某个线程拿住了某个锁, 并且其他线程都在等待这把锁造成的。 
为了排查这类问题, arthas提供了thread -b, 一键找出那个罪魁祸首。
注意, 目前只支持找出synchronized关键字阻塞住的线程, 如果是java.util.concurrent.Lock, 目前还不支持。

3. heapdump : dump java heap, 类似jmap命令的heap dump功能。

heapdump /tmp/dump.hprof : dump到指定文件

heapdump --live /tmp/dump.hprof : 只dump live对象

下载dump文件后,可以使用MAT查看,MAT官网下载: https://www.eclipse.org/mat/previousReleases.php ,主要要选择和本地一样的jvm版本,不然启动会失败。

使用MAT 分析 OOM 大内存问题,过程如下,是截取别的文章的过程。

image.png
image.png
image.png
image.png
image.png

4. watch: 观察到指定函数的调用情况。能观察到的范围为:返回值、抛出异常、入参

这个用于观察未打印日志的方法特别好用,包括入参 返参 和 异常

watch xxx.xxx.ABTestRecordServiceImpl doABTestWithLayer "{params,returnObj}" -x 3 -n 2 
-x 指定输出结果的属性遍历深度,默认为 1,最大值是4 ,
如果入参和出参是属性深度不一样(通常是不一样的,入参就是一个对象,出差会统一被一个Result包裹),需要分别设置才能观察到
params,returnObj : 指的是入参和返参,固定值
throwExp :观察异常信息 watch demo.MathGame primeFactors "{params,throwExp}" -e -x 2

-b :  在函数调用之前观察入参,因为入参有可能在执行被修改
-e :在函数异常之后观察
-s : 在函数返回之后观察,因为入参有可能在执行被修改
-n :  表示执行次数,即只打印n次,对于频繁调用来说,不设置的话,会打印很多

watch xxx.xxx.ABTestRecordServiceImpl doABTestWithLayer "{params,returnObj}" -x 3 -n 2  '#cost>100'
'#cost>100' : 按照耗时过滤,在很多方法中都可以通用,表示只打印执行超过100ms的方法
image.png

实例应用:生产上一个已废弃的接口突然被调用,报了一个异常,由于是老接口,我们并没有catch捕获,导致我们的日志filter没能打印出入参来,我们想根据入参来定位是哪里在调用,是谁在调用,这时候就可以用 watch 来获取方法的调用入参。
发现是运营突然上线了一个很久都没用的活动导致的,我们直接下线就可以了。

5. trace: 渲染和统计整个调用链路上的所有性能开销和追踪调用链路。

trace命令只会匹配到的函数里的子调用,并不会向下trace多层。因为trace是代价比较贵的,多层trace可能会导致最终要trace的类和函数非常多。

trace xxx.DiscountCXOpenServiceImpl aaaRespCXDTOList  '#cost > 50' -n 1
-n : 打印次数
'#cost>100' : 方法执行耗时
默认情况下,trace不会包含jdk里的函数调用,如果希望trace jdk里的函数,需要显式设置 --skipJDKMethod false。
image.png

6. stack:输出当前方法被调用的调用路径

如果一个方法被很多地方调用了,但是我们又不知道是被哪里调用时,可用这个命令查询

stack xxx.DiscountCacheUtil getStrategyCachaaa  -n 1 
image.png

7. profiler:生成应用热点的火焰图。

profiler start : 启动 
    启动时,默认采样的是cpu,可以通过 --event 来指定跟踪事件(cpu , alloc , lock )
profiler status :查看状态 
profiler stop : 停止
    停止时,默认生成html格式文件,可以通过 --file 指定生成路径和svg类型
image.png
image.png

从上面可以看出来耗时主要是在json parseArray格式化上。 横向长度越长,说明耗时越久

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

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

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

火焰图就是看顶层的哪个函数占据的宽度最大。只要有“平顶”(plateaus),就表示该函数可能存在性能问题。

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

默认生成的是html格式,只是html格式找东西不方便


image.png

8. Arthas线上常用场景

8.1 CPU过高问题

现象描述:运维突然打电话说是生成线上节点cpu高达80%,而且还在增加,但是最新的一个版本并没有什么复杂的功能上线,而且日志在报一个批量插入主键冲突的异常,但是这个批量插入的功能已经上线很久,并且在很多地方都有用到,所以不能定位到是哪里的问题,这时候可以用arthas来查找问题原因

//dashboard 命令用于整体展示进程所有线程、内存、GC 等情况
dashboard    -- 查看发现cpu高 不是GC引起的,占用CPU较多的线程只有一个
thread -n 6    -- 查看最繁忙的线程在执行的线程堆栈信息,然后可以直接定位具体代码行

在这个案例中,我们通过 Arthas 工具排查了高 CPU 的问题:

  • 首先,通过 dashboard + thread 命令,基本可以在几秒钟内一键定位问题,找出消耗 CPU 最多的线程和方法栈;
  • 然后,直接 jad 反编译相关代码,来确认根因;
  • 此外,如果调用入参不明确的话,可以使用 watch 观察方法入参,并根据方法执行时间来过滤慢请求的入参。

8.2 TPS过低问题

现象描述:新上线一个高并发的复杂业务接口,压测的时候发现TPS只有50,明显是太低了,需要找出耗时较长的地方加以优化。

trace xxx.DiscountCXOpenServiceImpl aaaRespCXDTOList  '#cost > 100' -n 1
由于trace命令只会匹配到的函数里的子调用,并不会向下trace多层,而这个业务接口很复杂,所以一层层找下去的话,太过于麻烦,所以用profiler 生成应用热点的火焰图来查找比较好,

profiler start --event alloc
//等待10s
profiler stop --file /app/deploy/logs/profiler.svg
image.png

从上面的图中可以看出最终耗时比较久的竟然是 fastjson 的 parseArray方法,然后找到具体调用的地方后,
发现是因为内部缓存的原因,由于内部缓存用的公共方法,value为Stiring,所以每次getValue后,都需要parseArray 转化为List<Bean> ,之所以使用内部缓存就是因为value值太大,存redis时会造成网卡带宽不够,所以我们需要修改为自定义内部缓存,这样就可以避免 parseArray 方法,从而提高性能了。
private static ConcurrentHashMap<String, ConcurrentHashMap> cache = new ConcurrentHashMap<>();

这里其实还有一个问题,这种大对象频繁反序列化除了影响性能,还会每次都生成新的对象,导致在高并发下,内存也飙升。

8.3 排查线程阻塞问题

  • 1、thread筛选所有阻塞状态的线程。

  • 2、根据线程名称定位具体的业务模块,再选中该业务中的一条线程查看堆栈信息。

  • 3、根据线程堆栈信息定位导致阻塞的具体方法,再利用stack命令查看方法堆栈信息。

  • 4、利用jad工具反编译源码,分析业务逻辑代码并改善。

8.4 排查死锁问题

  • 利用Arthas来检测死锁特别简单,只需要执行一行命令thread -b即可。

8.5 排查方法执行过慢问题

  • 1、通过trace命令排查方法执行速度,trace xx类 xx方法 '#cost>50ms',观测执行时间大于50ms的该方法的调用信息。

  • 2、可以结合正则表达式,同时排查多个类、多个方法,trace -E ClassA|ClassB method1|method2|method3。

8.6 动态修改线上代码

上线之后,发现代码有一处小地方存在逻辑错误需要更改,可以直接线上修改,而不用重启。

  • 1、通过jad将要修改的类反编译为.java文件,输出到指定目录。
  • 2、本地纠正.java文件后,通过mc命令重新编译.java文件。
  • 4、通过retransform命令将刚编译的.class文件再次加载到JVM中。
    这种已经很少使用了,仅限于不能重启的情况下,通常还是直接发版解决的。

参考文章:学会Arthas,让你3年经验掌握5年功力!

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

推荐阅读更多精彩内容