Java在线诊断工具Arthas介绍

Java在线诊断工具Arthas介绍

21 2019-07-19 20:54:56

![](/img/pic/2019071920274822002_png_320_105_15715)
> Arthas

## Arthas是什么
> Arthas 是Alibaba开源的Java诊断工具，深受开发者喜爱。
当你遇到以下类似问题而束手无策时，Arthas可以帮助你解决：
- 这个类从哪个 jar 包加载的？为什么会报各种类相关的 Exception？
- 遇到问题无法在线上 debug，难道只能通过加日志再重新发布吗？
- 线上遇到某个用户的数据处理有问题，但线上同样无法 debug，线下无法重现！

> ——Arthas中文说明文档

前几天遇到了一个这样的场景：
1. 核心业务上线了新功能，在上线时间节点前后核心方法平均耗时同比增长了约15%
2. 新功能包含一个第三方RPC调用，有可能出现服务不稳定的风险
3. 新功能未增加耗时日志记录，第三方RPC调用也未接入统计上报，导致在服务器日志及RPC链路监控中都没办法了解耗时信息
4. 新功能成了一个监控盲点，上线前后耗时又有变化，于是这个功能成了首要怀疑对象

这是一个典型的线上Debug场景：加打点日志，重新发布。
Arthas作为一个诊断工具，提供了很多更高效的方法。

## Arthas能做什么
Arthas通过JDK提供的`Instrument`（基于`Java Virtual Machine Tool Interface`）和asm库（操作字节码），在低侵入的情况下提供了非常丰富的在线诊断功能，包括JVM信息查询、字节码增强热替换等。
几个比较关键的功能是：
- 查看JVM的一些信息，包括线程信息、加载的类的信息、系统属性和环境变量等
- 反编译已加载类的代码（.class to .java）
- 内存编译器（.java to .class）
- 加载外部.class文件并替换原本已加载的类

通过这几个关键功能，Arthas可以实现无需重启（甚至不需要登录对应的服务器）在线上环境Debug、临时紧急修复等功能。
Arthas功能的确很丰富，但是使用不当也会造成一定的影响。

### 基础命令
`help` 查看命令帮助
`pwd` 当前工作目录，同Linux命令，结合cat命令使用
`cat` 打印文件内容，同Linux命令，可用于查看机器配置内容
`history` 历史命令，同Linux命令
`dashboard` 实时数据，包括线程信息、堆栈信息、系统变量

### 比较重要的命令
**sc 和 sm**
- `sc {Class-Pattern}` Search-Class，搜索JVM已经加载的类，比如`sc *Controller`
- `sm {Class-Pattern}` Search-Method，搜索类中的方法，比如`sm *QuestionController`

**getstatic**
可以用于查看类的静态属性，比如用于查看当前加载的配置信息
```shell
    $ getstatic *ConfigUtil editWhiteList
    @HashSet[
        @Long[174446],
        @Long[175009],
        @Long[174957],
        @Long[21959],
        @Long[10519],
        @Long[23813],
        @Long[10034],
    ]
```

**jad、mc、redefine**
- `jad [--source-only] {Class-Pattern} [{Method}]` 将指定的类反编译为高亮代码，可结合sm命令仅反编译指定方法
- `mc {File}` Memory-Compile，使用内存编译器将.java文件编译为.class文件
- `redefine` 加载外部.class文件，替换JVM中的类

通过这三个方法的结合可以实现在线反编译、修改、编译、替换的热修复操作，但是实际上这个做法十分危险，很可能导致线上代码处于不可控状态。
更合理的方式是在本地修复并编译通过后将生成的.class文件在线上替换。

**thread**
- `thread` 查看当前JVM所有线程信息，ID一栏是JVM级别的。
```shell
$ thread
Threads Total: 160, NEW: 0, RUNNABLE: 16, BLOCKED: 0, WAITING: 109, TIMED_WAITING: 35, TERMINATED: 0
ID       NAME                                                       GROUP                  PRIORITY      STATE              %CPU           TIME          INTERRUPTED         DAEMON
284      as-command-execute-daemon                                  system                 10            RUNNABLE           56             0:0           false               true
34       cluster-ClusterId{value='5d31369656d4890864c2d2ff', descri main                   5             TIMED_WAITING      36             0:0           false               true
36       DubboRegistryFailedRetryTimer-thread-1                     main                   5             TIMED_WAITING      2              0:0           false               true
50       DubboResponseTimeoutScanTimer                              main                   5             TIMED_WAITING      1              0:2           false               true
54       JinJingRocketMQSender-thread-1                             main                   5             TIMED_WAITING      1              0:0           false               true
```
可以看出来在Arthas接入期间诊断用的线程CPU占用率是比较高的。

- `thread {id}` 查看指定线程的状态
```shell
$ thread 284
        "as-command-execute-daemon" Id=284 RUNNABLE
          at sun.management.ThreadImpl.dumpThreads0(Native Method)
          at sun.management.ThreadImpl.getThreadInfo(ThreadImpl.java:440)
          at com.taobao.arthas.core.command.monitor200.ThreadCommand.processThread(ThreadCommand.java:146)
          at com.taobao.arthas.core.command.monitor200.ThreadCommand.process(ThreadCommand.java:77)
          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:370)
          at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
          at java.lang.Thread.run(Thread.java:745)

Number of locked synchronizers = 1
          - java.util.concurrent.ThreadPoolExecutor$Worker@5c49c9aa
```

- `thread -n {n}` 打印最忙的n个线程的信息
```shell
$ thread -n 3
        "as-command-execute-daemon" Id=289 cpuUsage=95% RUNNABLE
          at sun.management.ThreadImpl.dumpThreads0(Native Method)
          at sun.management.ThreadImpl.getThreadInfo(ThreadImpl.java:440)
          at com.taobao.arthas.core.command.monitor200.ThreadCommand.processTopBusyThreads(ThreadCommand.java:133)
          at com.taobao.arthas.core.command.monitor200.ThreadCommand.process(ThreadCommand.java:79)
          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:370)
          at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
          at java.lang.Thread.run(Thread.java:745)
          Number of locked synchronizers = 1
          - java.util.concurrent.ThreadPoolExecutor$Worker@4b3798a4
        "DubboResponseTimeoutScanTimer" Id=50 cpuUsage=2% TIMED_WAITING
          at java.lang.Thread.sleep(Native Method)
          at com.alibaba.dubbo.remoting.exchange.support.DefaultFuture$RemotingInvocationTimeoutScan.run(DefaultFuture.java:300)
          at java.lang.Thread.run(Thread.java:745)
        "Abandoned connection cleanup thread" Id=23 cpuUsage=1% TIMED_WAITING on java.lang.ref.ReferenceQueue$Lock@47459f1b
          at java.lang.Object.wait(Native Method)
          -  waiting on java.lang.ref.ReferenceQueue$Lock@47459f1b
          at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
          at com.mysql.jdbc.AbandonedConnectionCleanupThread.run(AbandonedConnectionCleanupThread.java:40)
```

- `thread -b` 找出阻塞其他线程的线程

### * 非常重要的命令
**monitor**
使用了字节码增强并替换了原本运行中的类，用于查看方法的执行统计信息，包括调用次数、平均耗时、失败率
```shell
$ monitor -c 5 demo.MathGame primeFactors
Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 94 ms.
 timestamp            class          method        total  success  fail  avg-rt(ms)  fail-rate
-----------------------------------------------------------------------------------------------
 2018-12-03 19:06:38  demo.MathGame  primeFactors  5      1        4     1.15        80.00%

timestamp            class          method        total  success  fail  avg-rt(ms)  fail-rate
-----------------------------------------------------------------------------------------------
 2018-12-03 19:06:43  demo.MathGame  primeFactors  5      3        2     42.29       40.00%

timestamp            class          method        total  success  fail  avg-rt(ms)  fail-rate
-----------------------------------------------------------------------------------------------
 2018-12-03 19:06:48  demo.MathGame  primeFactors  5      3        2     67.92       40.00%

timestamp            class          method        total  success  fail  avg-rt(ms)  fail-rate
-----------------------------------------------------------------------------------------------
 2018-12-03 19:06:53  demo.MathGame  primeFactors  5      2        3     0.25        60.00%

timestamp            class          method        total  success  fail  avg-rt(ms)  fail-rate
-----------------------------------------------------------------------------------------------
 2018-12-03 19:06:58  demo.MathGame  primeFactors  1      1        0     0.45        0.00%

timestamp            class          method        total  success  fail  avg-rt(ms)  fail-rate
-----------------------------------------------------------------------------------------------
 2018-12-03 19:07:03  demo.MathGame  primeFactors  2      2        0     3182.72     0.00%
```

**trace**
使用了字节码增强并替换了原本运行中的类，用于查看方法的执行耗时，对当前方法调用的每个方法都进行了打点计时，并标记最耗时的调用，只追踪一级方法
```shell
$ trace demo.MathGame run
Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 42 ms.
`---ts=2018-12-04 00:44:17;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69
    `---[10.611029ms] demo.MathGame:run()
        +---[0.05638ms] java.util.Random:nextInt()
        +---[10.036885ms] demo.MathGame:primeFactors()
        `---[0.170316ms] demo.MathGame:print()
```

**reset**
monitor、trace命令都使用了字节码增强替换，替换后的类逻辑上没有变化，**但是插入的一些切面有些许额外性能开销的，不应当追踪过长的时间，在诊断完成之后应当使用reset方法恢复所有增强过的类**。

**shutdown**
关闭当前的Arthas客户端，同时关闭当前连接，在关闭时会调用reset。
30分钟未进行操作会自动shutdown，超时时间可配置。这应该是考虑到Arthas不应当长时间启用、连接，如果忘记退出需要自动reset。

**quit**
关闭当前的Arthas客户端，不会关闭当前连接，不会调用reset。

## Arthas怎么用
### 方式1：使用jar
**操作流程**
1. 登录目标机器
2. `java -jar arthas-boot.jar`（或者使用`/path/to/java -jar /path/to/arthas-boot.jar --arthas-home /path/to/arthas/lib/`）
3. 选择要连接的进程id，Arthas会进行attach和连接

*attach和连接是两个步骤，attach是在目标进程中创建一个Arthas的守护线程，并监听对应的端口，默认为8563。*

**使用jar操作的一些坑**
- Arthas和服务最好使用对应的JDK版本
- Arthas启动时会访问Maven仓库下载依赖（默认使用阿里云，可配置），考虑到机房隔离问题，最好在需要部署的机器上将`arthas-boot.jar`和其依赖提前下载一起复制过去

### 方式2：使用WebConsole
**操作流程**
1. 进入Arthas控制台（需自己实现）
![](/img/pic/2019071920413947003_png_1481_311_23982)
2. 选择目标服务，使用Arthas提供的WebConsole远程连接
![](/img/pic/2019071921113793105_png_1912_313_33471)

**使用 WebConsole 远程连接时的一些坑**
1. 目标机器Arthas未attach时无法连接，且需要确认attach的具体PID
2. 需要一台Arthas客户端用于提供WebConsole服务
	- 其实也可以直接访问目标机器的8563端口，但考虑到机房的隔离问题，最好使用一个跳板机，通过跳板机连接目标机器
3. 连接到同一台机器的客户端会共用一个连接，因此连接其他服务前应当断开当前连接
4. `quit`命令不会断开连接，需要`shutdown`，而其中一个客户端使用`shutdown`所有共用连接的客户端都会退出

**目前为了使用 WebConsole 做了哪些措施**
1. 修改了目标机器上原有的一个Java Agent，提供了一个Http接口，用于：
	- 唤起目标机器上的Arthas
	- 查找PID并attach到目标进程
2. 开发Arthas控制台，在控制台点击“启用Arthas”后做了一系列操作：
	- 如果本机Arthas未启动，唤起控制台本机的Arthas
	- 调用目标机器Agent的唤起接口，attach到对应的进程
3. 从控制台机器上的Arthas客户端连接目标机器的Arthas监听的端口

**后续可优化的点**
1. 可以集成到其他系统中，比如发布平台、监控平台
2. 可以增加热修复的功能（需非常谨慎）
3. 目前agent提供Http接口用于唤醒Arthas，跨机房的唤醒和连接需要建立机房间的代理或在每个机房都部署控制台
4. 目前使用Http接口唤醒目标机器的Arthas，可以改为监听Zookeeper的方式唤醒

## Arthas相关网站
Github：[alibaba/arthas: Alibaba Java Diagnostic Tool Arthas/Alibaba Java诊断利器Arthas](https://github.com/alibaba/arthas)
中文文档，有在线教程：[arthas/README_CN.md at master · alibaba/arthas](https://github.com/alibaba/arthas/blob/master/README_CN.md)
命令介绍：[进阶使用 — Arthas 3.1.1 文档](https://alibaba.github.io/arthas/advanced-use.html)

## 参考资料
[记录如何使用arthas进行远程访问 · Issue #442 · alibaba/arthas](https://github.com/alibaba/arthas/issues/442)