java 性能调优神器 -- 黑暗骑士 Arthas

2021-01-01 22:53:18   最后更新: 2021-01-01 22:53:18   访问数量:70




在 java 开发过程中,总不会是一帆风顺的,你是否也遇到过下面的问题呢:

  1. 接口耗时很高,如何短时间定位到底执行慢在哪里?
  2. 类方法执行的代码与你预期不符,你想要知道这个类从哪个 jar 包加载的?
  3. 线上环境如何 debug,看代码具体的执行路径呢?
  4. 如何以一个全局视角查看系统运行状况呢?
  5. 能否在线上观察 jvm 实时的运行状态呢?
  6. 你是否想动态热替换一个类

 

这一系列问题对于任何一个 java 开发工程师来说都是非常有价值的,作为国内 java 使用大厂,阿里开源了一套工具,可以十分方便快捷地解决上述问题,他就是 java 工具中的暗黑骑士 -- Arthas。

 

2.1 下载

Arthas 在 github 上的开源地址:

https://github.com/alibaba/arthas

 

可以直接在 github 的 release 页面下载:

https://github.com/alibaba/arthas/releases

 

也可以从官网下载:

curl -O https://arthas.aliyun.com/arthas-boot.jar

 

2.2 安装

通过 java 执行下载的 jar 文件即可:

 

java -jar arthas-boot.jar

 

执行上述命令后,Arthas 会在 home 目录下创建 .arthas 目录存放必要的文件,以及在 home 目录下的 logs/arthas 目录下存放具体执行过程中所产生的日志文件。

 

2.3 启动

 

执行上面的命令后,会出现选择界面,只要选择你的 java 进程序号或名称,回车后就会出现一个控制台界面:

 

 

 

接下来就可以在这个控制台中通过各个命令来实现对 java 进程的操作了。

 

2.4 相关文档

 

事实上,Arthas 拥有十分详尽的官方中英文文档:

 

https://arthas.aliyun.com/doc/arthas-tutorials.html?language=cn&id=arthas-basics

 

因此,本文只介绍主页君自己的使用体验和基本功能的使用,具体参数敬请参看官方文档。

 

 

3.1 基本命令

 

Arthas 实际上是一系列工具的集合,具体他的具有下面这些命令和功能:

 

命令 介绍
dashboard 当前系统的实时数据面板
thread 查看当前线程信息,查看线程的堆栈
jvm 查看当前 JVM 信息
sysprop 查看当前 JVM 的系统属性
sysenv 查看当前 JVM 的环境属性
vmoption 查看,更新 VM 诊断相关的参数
perfcounter 查看当前 JVM 的 Perf Counter 信息
logger 查看 logger 信息,更新 logger level
mbean 查看 Mbean 的信息
getstatic 查看类的静态属性,推荐直接使用 ognl 命令,更加灵活
ognl 执行 ognl 表达式
sc 查看JVM已加载的类信息
sm 查看已加载类的方法信息
dump dump 已加载类的 bytecode 到特定目录
heapdump dump java heap, 类似 jmap 命令的 heap dump 功能
jad 反编译指定已加载类的源码
classloader 查看classloader的继承树,urls,类加载信息
mc 内存编译器,编译 `.java` 文件生成 `.class`
redefine 加载外部的`.class`文件,redefine jvm已加载的类
monitor 对匹配 `class-pattern`/`method-pattern`/`condition-express`的类、方法的调用进行监控
watch 方法执行数据观测,可以观察方法的返回值、抛出异常、入参等信息
trace 显示方法内部调用路径,并输出方法路径上的每个节点上耗时
stack 输出当前方法被调用的调用路径
tt 记录指定方法每次调用的入参和返回信息,并能对这些不同的时间下调用进行观测
profiler 使用 async-profiler 生成火焰图
options 用于查看和操作全局控制开关

3.2 Arthas 实现的类 linux 命令

 

下面的几个命令与同名的 linux 命令的功能是基本一致的,也可以在 Arthas 控制台中使用:

 

  1. cat
  2. echo
  3. grep
  4. tee
  5. pwd

 

 

执行 dashboard 命令,可以打开一个类似于 top 命令的仪表盘:

 

 

 

如图所示,包括线程的执行状态、内存、GC、运行时信息、系统信息等你所需要的基本信息都一应俱全,其中的很多信息都可以成为 jvm 性能优化的重要依据。

 

 

5.1 基本介绍

 

trace 命令是我最常用的功能之一,他不仅可以看到你的程序执行路径,还可以清楚的知道执行路径上每一步的耗时情况,无论是日常问题的排查,还是在压测中快速找到系统瓶颈,亦或是某个 case 的追踪调试,trace 命令都可以发挥其巨大的优势。

 

你可以通过包名.类名 方法名作为参数,快速定位和打印对应方法的执行路径与耗时:

 

trace demo.MathGame runMethod

 

会显示:

 

Press Q or Ctrl+C to abort.

Affect(class-cnt:1 , method-cnt:1) cost in 28 ms.

---ts=2019-12-04 00:45:08;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69

---[0.617465ms] demo.MathGame:run()

---[0.078946ms] demo.MathGame:primeFactors() #24 [throws Exception]

---ts=2019-12-04 00:45:09;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69

---[1.276874ms] demo.MathGame:run()

---[0.03752ms] demo.MathGame:primeFactors() #24 [throws Exception]

 

当然,如果你只关心执行路径,而不关心耗时情况,你可以通过 stack 命令来查看,stack 命令与 trace 命令的用法基本上是一样的。

 

 

5.2.1 打印限制

 

trace 支持以下可选参数,用来对打印的结果进行限制:

 

  1. -n 指定最多执行的次数
  2. #cost 对方法耗时进行限制

 

例如:

 

trace demo.MathGame runMethod -n 1 # 只打印一次 trace 的结果

 

trace demo.MathGame runMethod '#cost > 100' # 只打印耗时 100ms 以上的 trace 结果

 

5.2.2 监控多个类或函数

 

trace -E com.test.ClassA|org.test.ClassB method1|method2|method3

 

5.2.3 包含 jdk 函数

 

默认情况下,trace不会包含jdk里的函数调用,如果希望trace jdk里的函数,需要显式设置--skipJDKMethod false:

 

trace --skipJDKMethod false demo.MathGame runMethod

 

如果你需要 trace 系统级别的类,那么你需要通过 options 打开 unsafe 开关:

 

options unsafe true

 

5.2.4 缺点

 

trace 最大的缺点是他每次只能跟踪一级方法的调用链路,因此通常你需要反复执行 trace 命令层层深入进去。

 

 

我们常常想要在一个方法调用前、返回后或发生异常时观察方法的入参和出参,这个功能 arthas 也同样支持,那就是 watch 命令。

 

6.1 watch 参数

 

参数 说明
-b 方法调用前打印监测信息
-e 方法抛出异常后打印监测信息
-s 方法返回后打印监测信息
-f 方法结束(包括抛出异常和正常返回)后打印监测信息
-x 指定输出结果的遍历深度,默认为 1
-n 指定最多打印监测信息的次数

例如,我们想要在方法调用前和返回后打印参数和返回值就可以执行:

 

watch demo.MathGame primeFactors "{params,target,returnObj}" -x 2 -b -s -n 2

 

由于 -x 参数指定了 2,因此结果中的对象会遍历打印两层:

 

Press Ctrl+C to abort.

Affect(class-cnt:1 , method-cnt:1) cost in 46 ms.

ts=2018-12-03 19:29:54; [cost=0.01696ms] result=@ArrayList[

@Object[][ @Integer[1544665400],

],

@MathGame[

random=@Random[java.util.Random@522b408a],

illegalArgumentCount=@Integer[13038],

],

null,

]

ts=2018-12-03 19:29:54; [cost=4.277392ms] result=@ArrayList[

@Object[][ @Integer[1544665400],

],

@MathGame[

random=@Random[java.util.Random@522b408a],

illegalArgumentCount=@Integer[13038],

],

@ArrayList[

@Integer[2],

@Integer[2],

@Integer[2],

@Integer[5],

@Integer[5],

@Integer[73],

@Integer[241],

@Integer[439],

],

]

 

6.2 OGNL 表达式

 

从上面的例子可以看出,需要打印的内容是通过一个表达式指定的,例如上面所写的“{params,target,returnObj}”,这就是 ognl 表达式,具体可以参看 apache 的文档:

 

https://commons.apache.org/proper/commons-ognl/language-guide.html

 

你也可以在 arthas 控制台中直接通过 ognl 执行 ognl 表达式,从而观察你所需要的信息,比如下面的例子查看了类的静态变量:

 

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],

]

 

 

Arthas 中最强大的运行监控命令就是 tt 了,他是“时空隧道” TimeTunnel 的缩写。

 

当你对某个方法开启 tt 后,Arthas 会记录下此后的每一次调用,在这之后,你可以非常方便的查看当时的运行情况,包括出参,入参,运行耗时,是否异常等等,甚至可以重放当时的调用,可谓是非常强大。

 

7.1 记录现场

 

tt -t demo.MathGame primeFactors

Press Ctrl+C to abort.

Affect(class-cnt:1 , method-cnt:1) cost in 66 ms.

INDEX   TIMESTAMP COST(ms)  IS-RET  IS-EXP   OBJECT  CLASS   METHOD

---------------------------------------------------------------------------------------------------------------------

1000 2018-12-04 11:15:38  1.096236  false   true  0x4b67cf4d  MathGame    primeFactors

1001 2018-12-04 11:15:39  0.191848  false   true  0x4b67cf4d  MathGame    primeFactors

1002 2018-12-04 11:15:40  0.069523  false   true  0x4b67cf4d  MathGame    primeFactors

1003 2018-12-04 11:15:41  0.186073  false   true  0x4b67cf4d  MathGame    primeFactors

1004 2018-12-04 11:15:42  17.76437  true false 0x4b67cf4d  MathGame    primeFactors

 

他记录的信息包括:

 

表格字段 字段解释
INDEX 时间片段记录编号,每一个编号代表着一次调用,后续tt还有很多命令都是基于此编号指定记录操作,非常重要。
TIMESTAMP 方法执行的本机时间,记录了这个时间片段所发生的本机时间
IS-RET 方法是否以正常返回的形式结束
COST(ms) 方法执行的耗时
IS-EXP 方法是否以抛异常的形式结束
OBJECT 执行对象的`hashCode()`,注意,曾经有人误认为是对象在JVM中的内存地址,但很遗憾他不是。但他能帮助你简单的标记当前执行方法的类实体
CLASS 执行的类名
METHOD 执行的方法名

7.2 重做一次调用

 

tt 的 -p 参数表示重新以当时的现场信息调用方法,通过 -i 参数指定已记录的上下文环境的序号,同时,你可以通过 --replay-times 指定 调用次数,通过 --replay-interval 指定多次调用间隔(单位ms, 默认1000ms)

 

tt -i 1004 -p

RE-INDEX    1004

GMT-REPLAY  2018-12-04 11:26:00

OBJECT  0x4b67cf4d

CLASS   demo.MathGame

METHOD  primeFactors

PARAMETERS[0]  @Integer[946738738]

IS-RETURN   true

IS-EXCEPTION   false

COST(ms)  0.186073

RETURN-OBJ  @ArrayList[

@Integer[2],

@Integer[11],

@Integer[17],

@Integer[2531387],

]

Time fragment[1004] successfully replayed.

Affect(row-cnt:1) cost in 14 ms.

 

除此以外,tt 还支持对结果进行筛选,以及指定更细粒度的记录过滤条件,可以参看官方文档获得更多信息。

 

 

很多诡异的线上问题是因为 java 类加载机制引发的,加载了错误包的类,或使用了错误的类加载器加载了某个类,通过 sc 命令,我们可以快速发现和定位这样的问题,例如,我们可以打印类的详细信息:

 

sc -d demo.MathGame

class-info demo.MathGame

code-source    /private/tmp/arthas-demo.jar

name   demo.MathGame

isInterface    false

isAnnotation   false

isEnum false

isAnonymousClass  false

isArray    false

isLocalClass   false

isMemberClass  false

isPrimitive    false

isSynthetic    false

simple-name    MathGame

modifier   public

annotation

interfaces

super-class    +-java.lang.Object

class-loader   +-sun.misc.Launcher$AppClassLoader@3d4eac69

+-sun.misc.Launcher$ExtClassLoader@66350f69

classLoaderHash   3d4eac69

Affect(row-cnt:1) cost in 875 ms.

 

这些信息一目了然,让我们对于类的实际执行情况了如指掌。

 

 

既然通过 sc 命令可以查看类的加载情况,那么是否有办法,让我们能够热替换某个已加载的类呢?这当然也是有的,Arthas 提供了 redefine 命令实现相应的功能。

 

下面的指令就实现了 Test.class 的加载:

 

redefine --classLoaderClass sun.misc.Launcher$AppClassLoader /tmp/Test.class /tmp/Test\$Inner.class

 

需要注意的是:

 

  1. redefine 加载的类不允许新增 field 或 method
  2. 正在执行中的函数无法 redefine

 

 

redefine 命令看起来很好用,可仔细想想,你需要把 .java 文件编译成 .class 文件,再上传到服务器,想想还是挺繁琐的,而绝大部分场景下,我们其实是要即快速地修复线上存在的问题,此时,将线上正在运行的 java 项目中的某个类反编译为 .java 文件,再进行编辑,再编译回 .class 文件,再用 redefine 命令热加载回去,再通过 sc 命令查看类的加载情况,确定执行成功,才是最常见的一系列操作,此时,就需要使用编译与反编译工具 -- jad 与 mc

 

10.1 反编译工具 -- jad

 

jad 用来反编译指定的已加载的类的源码,例如:

 

jad --source-only demo.MathGame

 

执行结果就是类的源码:

 

/*

* Decompiled with CFR 0_132.

*/

package demo;

import java.io.PrintStream;

import java.util.ArrayList;

import java.util.Iterator;

import java.util.List;

import java.util.Random;

import java.util.concurrent.TimeUnit;

public class MathGame {

private static Random random = new Random();

public int illegalArgumentCount = 0;

...

 

当然,你也可以在类后面加空格传入方法名来只反编译一个方法。

 

10.2 内存编译器 -- mc

 

mc 工具编译 .java 文件为 .class 文件,你也可以通过 -c 参数指定 ClassLoader:

 

mc /tmp/Test.java -d /tmp/output

 

10.3 jad、mc、redefine 结合实现动态代码修改

 

  1. 反编译 jad --source-only com.example.demo.arthas.user.UserController > /tmp/UserController.java
  2. 修改反编译后的 UserController.java
  3. 编译 mc /tmp/UserController.java -d /tmp
  4. 热加载 redefine /tmp/com/example/demo/arthas/user/UserController.class

 

 

thread 命令可以指定的线程信息。

 

例如下面的命令显示了 CPU 使用率 Top N 的线程:

 

thread -n 3

 

打印出了:

 

"C1 CompilerThread0" [Internal] cpuUsage=1.63% deltaTime=3ms time=1170ms

"arthas-command-execute" Id=23 cpuUsage=0.11% deltaTime=0ms time=401ms RUNNABLE

at java.management@11.0.7/sun.management.ThreadImpl.dumpThreads0(Native Method)

at java.management@11.0.7/sun.management.ThreadImpl.getThreadInfo(ThreadImpl.java:466)

at com.taobao.arthas.core.command.monitor200.ThreadCommand.processTopBusyThreads(ThreadCommand.java:199)

at com.taobao.arthas.core.command.monitor200.ThreadCommand.process(ThreadCommand.java:122)

at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl.process(AnnotatedCommandImpl.java:82)

at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl.access$100(AnnotatedCommandImpl.java:18)

at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl$ProcessHandler.handle(AnnotatedCommandImpl.java:111)

at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl$ProcessHandler.handle(AnnotatedCommandImpl.java:108)

at com.taobao.arthas.core.shell.system.impl.ProcessImpl$CommandProcessTask.run(ProcessImpl.java:385)

at java.base@11.0.7/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)

at java.base@11.0.7/java.util.concurrent.FutureTask.run(FutureTask.java:264)

at java.base@11.0.7/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)

at java.base@11.0.7/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)

at java.base@11.0.7/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)

at java.base@11.0.7/java.lang.Thread.run(Thread.java:834)

"VM Periodic Task Thread" [Internal] cpuUsage=0.07% deltaTime=0ms time=584ms

 

除此以外,我们还可以通过 -b 参数查看当前阻塞其他线程的线程,或是通过传入 id 查看线程堆栈信息,亦或是通过 -state 参数指定某状态的线程。

 

 

介绍了这么多 Arthas 的常用工具,基本上已经能够覆盖绝大多数问题排查的场景,同时,官方文档还有着更多的命令、参数和用法,可以说,掌握了阿里 Arthas 这套工具的使用,绝对极大的有助于线上问题的发现、排查和解决。

 

 

欢迎关注微信公众号,以技术为主,涉及历史、人文等多领域的学习与感悟,每周三到七篇推文,全部原创,只有干货没有鸡汤

 

 

 

 






技术帖      调试      java      阿里      编译      性能      arthas      trace      反编译     


京ICP备15018585号