Arthas - Java 线上问题定位处理的终极利器

古城微笑少年丶 2022-11-20 08:08 191阅读 0赞

![Arthas logo][]

# 前言 #

在使用 **Arthas** 之前，当遇到 Java 线上问题时，如 CPU 飙升、负载突高、内存溢出等问题，你需要查命令，查网络，然后 jps、jstack、jmap、jhat、jstat、hprof 等一通操作。最终焦头烂额，还不一定能查出问题所在。而现在，大多数的常见问题你都可以使用 **Arthas** 轻松定位，迅速解决，及时止损，准时下班。

# 1、Arthas 介绍 #

**Arthas** 是 `Alibaba` 在 2018 年 9 月开源的 **Java 诊断**工具。支持 `JDK6+`， 采用命令行交互模式，提供 `Tab` 自动不全，可以方便的定位和诊断线上程序运行问题。截至本篇文章编写时，已经收获 `Star` 17000+。

**Arthas** 官方文档十分详细，本文也参考了官方文档内容，同时在开源在的 `Github` 的项目里的 `Issues` 里不仅有问题反馈，更有大量的使用案例，也可以进行学习参考。

开源地址：*https://github.com/alibaba/arthas*

官方文档：*https://alibaba.github.io/arthas*

# 2、Arthas 使用场景 #

得益于 **Arthas** 强大且丰富的功能，让 **Arthas** 能做的事情超乎想象。下面仅仅列举几项常见的使用情况，更多的使用场景可以在熟悉了 **Arthas** 之后自行探索。

1.  是否有一个全局视角来查看系统的运行状况？
2.  为什么 CPU 又升高了，到底是哪里占用了 CPU ？
3.  运行的多线程有死锁吗？有阻塞吗？
4.  程序运行耗时很长，是哪里耗时比较长呢？如何监测呢？
5.  这个类从哪个 jar 包加载的？为什么会报各种类相关的 Exception？
6.  我改的代码为什么没有执行到？难道是我没 commit？分支搞错了？
7.  遇到问题无法在线上 debug，难道只能通过加日志再重新发布吗？
8.  有什么办法可以监控到 JVM 的实时运行状态？

# 3、Arthas 怎么用 #

前文已经提到，**Arthas** 是一款命令行交互模式的 Java 诊断工具，由于是 Java 编写，所以可以直接下载相应 的 jar 包运行。

## 3.1 安装 ##

可以在官方 Github 上进行下载，如果速度较慢，可以尝试国内的码云 Gitee 下载。

# github下载
    wget https://alibaba.github.io/arthas/arthas-boot.jar
    # 或者 Gitee 下载
    wget https://arthas.gitee.io/arthas-boot.jar
    # 打印帮助信息
    java -jar arthas-boot.jar -h

*  1
 *  2
 *  3
 *  4
 *  5
 *  6

## 3.2 运行 ##

**Arthas** 只是一个 java 程序，所以可以直接用 `java -jar` 运行。运行时或者运行之后要选择要监测的 Java 进程。

# 运行方式1，先运行，在选择 Java 进程 PID
    java -jar arthas-boot.jar
    # 选择进程(输入[]内编号(不是PID)回车)
    [INFO] arthas-boot version: 3.1.4
    [INFO] Found existing java process, please choose one and hit RETURN.
    * [1]: 11616 com.Arthas
      [2]: 8676
      [3]: 16200 org.jetbrains.jps.cmdline.Launcher
      [4]: 21032 org.jetbrains.idea.maven.server.RemoteMavenServer
    
    # 运行方式2，运行时选择 Java 进程 PID
    java -jar arthas-boot.jar [PID]

*  1
 *  2
 *  3
 *  4
 *  5
 *  6
 *  7
 *  8
 *  9
 *  10
 *  11
 *  12

查看 PID 的方式可以通过 `ps` 命令，也可以通过 JDK 提供的 `jps`命令。

# 查看运行的 java 进程信息
    $ jps -mlvV 
    # 筛选 java 进程信息
    $ jps -mlvV | grep [xxx]

*  1
 *  2
 *  3
 *  4

`jps` 筛选想要的进程方式。

![jps 筛选进程][jps]

在出现 **Arthas** Logo 之后就可以使用命令进行问题诊断了。下面会详细介绍。

![Arthas 启动][Arthas]

更多的启动方式可以参考 help 帮助命令。

# 其他用法
    EXAMPLES:
      java -jar arthas-boot.jar <pid>
      java -jar arthas-boot.jar --target-ip 0.0.0.0
      java -jar arthas-boot.jar --telnet-port 9999 --http-port -1
      java -jar arthas-boot.jar --tunnel-server 'ws://192.168.10.11:7777/ws'
      java -jar arthas-boot.jar --tunnel-server 'ws://192.168.10.11:7777/ws'
    --agent-id bvDOe8XbTM2pQWjF4cfw
      java -jar arthas-boot.jar --stat-url 'http://192.168.10.11:8080/api/stat'
      java -jar arthas-boot.jar -c 'sysprop; thread' <pid>
      java -jar arthas-boot.jar -f batch.as <pid>
      java -jar arthas-boot.jar --use-version 3.1.4
      java -jar arthas-boot.jar --versions
      java -jar arthas-boot.jar --session-timeout 3600
      java -jar arthas-boot.jar --attach-only
      java -jar arthas-boot.jar --repo-mirror aliyun --use-http

*  1
 *  2
 *  3
 *  4
 *  5
 *  6
 *  7
 *  8
 *  9
 *  10
 *  11
 *  12
 *  13
 *  14
 *  15
 *  16

## 3.3 web console ##

**Arthas** 目前支持 `Web Console`，在成功启动连接进程之后就已经自动启动，可以直接访问 http://127.0.0.1:8563/ 访问，页面上的操作模式和控制台完全一样。

![1570979937637][]

## 3.4 常用命令 ##

下面列举一些 [**Arthas**][Arthas 1] 的常用命令，看到这里你可能还不知道怎么使用，别急，后面会一一介绍。

<table> 
 <thead> 
  <tr> 
   <th>命令</th> 
   <th>介绍</th> 
  </tr> 
 </thead> 
 <tbody> 
  <tr> 
   <td><a href="https://alibaba.github.io/arthas/dashboard.html" rel="nofollow">dashboard</a></td> 
   <td>当前系统的实时数据面板</td> 
  </tr> 
  <tr> 
   <td><a href="https://alibaba.github.io/arthas/thread.html" rel="nofollow"><strong>thread</strong></a></td> 
   <td>查看当前 JVM 的线程堆栈信息</td> 
  </tr> 
  <tr> 
   <td><a href="https://alibaba.github.io/arthas/watch.html" rel="nofollow"><strong>watch</strong></a></td> 
   <td>方法执行数据观测</td> 
  </tr> 
  <tr> 
   <td><strong><a href="https://alibaba.github.io/arthas/trace.html" rel="nofollow">trace</a></strong></td> 
   <td>方法内部调用路径，并输出方法路径上的每个节点上耗时</td> 
  </tr> 
  <tr> 
   <td><a href="https://alibaba.github.io/arthas/stack.html" rel="nofollow"><strong>stack</strong></a></td> 
   <td>输出当前方法被调用的调用路径</td> 
  </tr> 
  <tr> 
   <td><a href="https://alibaba.github.io/arthas/tt.html" rel="nofollow"><strong>tt</strong></a></td> 
   <td>方法执行数据的时空隧道，记录下指定方法每次调用的入参和返回信息，并能对这些不同的时间下调用进行观测</td> 
  </tr> 
  <tr> 
   <td><a href="https://alibaba.github.io/arthas/monitor.html" rel="nofollow">monitor</a></td> 
   <td>方法执行监控</td> 
  </tr> 
  <tr> 
   <td><a href="https://alibaba.github.io/arthas/jvm.html" rel="nofollow">jvm</a></td> 
   <td>查看当前 JVM 信息</td> 
  </tr> 
  <tr> 
   <td><a href="https://alibaba.github.io/arthas/vmoption.html" rel="nofollow">vmoption</a></td> 
   <td>查看，更新 JVM 诊断相关的参数</td> 
  </tr> 
  <tr> 
   <td><a href="https://alibaba.github.io/arthas/sc.html" rel="nofollow">sc</a></td> 
   <td>查看 JVM 已加载的类信息</td> 
  </tr> 
  <tr> 
   <td><a href="https://alibaba.github.io/arthas/sm.html" rel="nofollow">sm</a></td> 
   <td>查看已加载类的方法信息</td> 
  </tr> 
  <tr> 
   <td><a href="https://alibaba.github.io/arthas/jad.html" rel="nofollow">jad</a></td> 
   <td>反编译指定已加载类的源码</td> 
  </tr> 
  <tr> 
   <td><a href="https://alibaba.github.io/arthas/classloader.html" rel="nofollow">classloader</a></td> 
   <td>查看 classloader 的继承树，urls，类加载信息</td> 
  </tr> 
  <tr> 
   <td><a href="https://alibaba.github.io/arthas/heapdump.html" rel="nofollow">heapdump</a></td> 
   <td>类似 jmap 命令的 heap dump 功能</td> 
  </tr> 
 </tbody> 
</table>

## 3.5 退出 ##

使用 shutdown 退出时 **Arthas** 同时自动重置所有增强过的类 。

# 4、Arthas 常用操作 #

上面已经了解了什么是 **Arthas**，以及 **Arthas** 的启动方式，下面会依据一些情况，详细说一说 **Arthas** 的使用方式。在使用命令的过程中如果有问题，每个命令都可以是 `-h` 查看帮助信息。

首先编写一个有各种情况的测试类运行起来，再使用 **Arthas** 进行问题定位，

import java.util.HashSet;
    import java.util.concurrent.ExecutorService;
    import java.util.concurrent.Executors;
    import lombok.extern.slf4j.Slf4j;
    
    /**
     * <p>
     * Arthas Demo
     * 公众号：未读代码
     *
     * @Author niujinpeng
     */
    @Slf4j
    public class Arthas {
    
        private static HashSet hashSet = new HashSet();
        /** 线程池，大小1*/
        private static ExecutorService executorService = Executors.newFixedThreadPool(1);
    
        public static void main(String[] args) {
            // 模拟 CPU 过高，这里注释掉了，测试时可以打开
            // cpu();
            // 模拟线程阻塞
            thread();
            // 模拟线程死锁
            deadThread();
            // 不断的向 hashSet 集合增加数据
            addHashSetThread();
        }
    
        /**
         * 不断的向 hashSet 集合添加数据
         */
        public static void addHashSetThread() {
            // 初始化常量
            new Thread(() -> {
                int count = 0;
                while (true) {
                    try {
                        hashSet.add("count" + count);
                        Thread.sleep(10000);
                        count++;
                    } catch (InterruptedException e) {
                        e.printStackTrace();
                    }
                }
            }).start();
        }
    
        public static void cpu() {
            cpuHigh();
            cpuNormal();
        }
    
        /**
         * 极度消耗CPU的线程
         */
        private static void cpuHigh() {
            Thread thread = new Thread(() -> {
                while (true) {
                    log.info("cpu start 100");
                }
            });
            // 添加到线程
            executorService.submit(thread);
        }
    
        /**
         * 普通消耗CPU的线程
         */
        private static void cpuNormal() {
            for (int i = 0; i < 10; i++) {
                new Thread(() -> {
                    while (true) {
                        log.info("cpu start");
                        try {
                            Thread.sleep(3000);
                        } catch (InterruptedException e) {
                            e.printStackTrace();
                        }
                    }
                }).start();
            }
        }
    
        /**
         * 模拟线程阻塞,向已经满了的线程池提交线程
         */
        private static void thread() {
            Thread thread = new Thread(() -> {
                while (true) {
                    log.debug("thread start");
                    try {
                        Thread.sleep(3000);
                    } catch (InterruptedException e) {
                        e.printStackTrace();
                    }
                }
            });
            // 添加到线程
            executorService.submit(thread);
        }
    
        /**
         * 死锁
         */
        private static void deadThread() {
            /** 创建资源 */
            Object resourceA = new Object();
            Object resourceB = new Object();
            // 创建线程
            Thread threadA = new Thread(() -> {
                synchronized (resourceA) {
                    log.info(Thread.currentThread() + " get ResourceA");
                    try {
                        Thread.sleep(1000);
                    } catch (InterruptedException e) {
                        e.printStackTrace();
                    }
                    log.info(Thread.currentThread() + "waiting get resourceB");
                    synchronized (resourceB) {
                        log.info(Thread.currentThread() + " get resourceB");
                    }
                }
            });
    
            Thread threadB = new Thread(() -> {
                synchronized (resourceB) {
                    log.info(Thread.currentThread() + " get ResourceB");
                    try {
                        Thread.sleep(1000);
                    } catch (InterruptedException e) {
                        e.printStackTrace();
                    }
                    log.info(Thread.currentThread() + "waiting get resourceA");
                    synchronized (resourceA) {
                        log.info(Thread.currentThread() + " get resourceA");
                    }
                }
            });
            threadA.start();
            threadB.start();
        }
    }

## 4.1 全局监控 ##

使用 **dashboard** 命令可以概览程序的 线程、内存、GC、运行环境信息。

![dashboard][]

## 4.2 CPU 为什么起飞了 ##

上面的代码例子有一个 `CPU` 空转的死循环，非常的消耗 `CPU性能`，那么怎么找出来呢？

使用 **thread**查看**所有**线程信息，同时会列出每个线程的 `CPU` 使用率，可以看到图里 ID 为12 的线程 CPU 使用100%。  
![format_png][]

使用命令 **thread 12** 查看 CPU 消耗较高的 12 号线程信息，可以看到 CPU 使用较高的方法和行数（这里的行数可能和上面代码里的行数有区别，因为上面的代码在我写文章时候重新排过版了）。

![format_png 1][]

上面是先通过观察总体的线程信息，然后查看具体的线程运行情况。如果只是为了寻找 CPU 使用较高的线程，可以直接使用命令 **thread -n \[显示的线程个数\]** ，就可以排列出 CPU 使用率 **Top N** 的线程。

![format_png 2][]

定位到的 CPU 使用最高的方法。

![format_png 3][]

## 4.3 线程池线程状态 ##

定位线程问题之前，先回顾一下线程的几种常见状态：

*  **RUNNABLE** 运行中
 *  **TIMED\_WAITIN** 调用了以下方法的线程会进入**TIMED\_WAITING**：
    
    1.  Thread\#sleep()
    2.  Object\#wait() 并加了超时参数
    3.  Thread\#join() 并加了超时参数
    4.  LockSupport\#parkNanos()
    5.  LockSupport\#parkUntil()
 *  **WAITING** 当线程调用以下方法时会进入WAITING状态：
    
    1.  Object\#wait() 而且不加超时参数
    2.  Thread\#join() 而且不加超时参数
    3.  LockSupport\#park()
 *  **BLOCKED** 阻塞，等待锁

上面的模拟代码里，定义了线程池大小为1 的线程池，然后在 `cpuHigh` 方法里提交了一个线程，在 `thread`方法再次提交了一个线程，后面的这个线程因为线程池已满，会阻塞下来。

使用 **thread | grep pool** 命令查看线程池里线程信息。

![format_png 4][]

可以看到线程池有 **WAITING** 的线程。

![format_png 5][]

## 4.4 线程死锁 ##

上面的模拟代码里 `deadThread`方法实现了一个死锁，使用 **thread -b** 命令查看直接定位到死锁信息。

/**
     * 死锁
     */
    private static void deadThread() {
        /** 创建资源 */
        Object resourceA = new Object();
        Object resourceB = new Object();
        // 创建线程
        Thread threadA = new Thread(() -> {
            synchronized (resourceA) {
                log.info(Thread.currentThread() + " get ResourceA");
                try {
                    Thread.sleep(1000);
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
                log.info(Thread.currentThread() + "waiting get resourceB");
                synchronized (resourceB) {
                    log.info(Thread.currentThread() + " get resourceB");
                }
            }
        });
    
        Thread threadB = new Thread(() -> {
            synchronized (resourceB) {
                log.info(Thread.currentThread() + " get ResourceB");
                try {
                    Thread.sleep(1000);
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
                log.info(Thread.currentThread() + "waiting get resourceA");
                synchronized (resourceA) {
                    log.info(Thread.currentThread() + " get resourceA");
                }
            }
        });
        threadA.start();
        threadB.start();
    }

*  1
 *  2
 *  3
 *  4
 *  5
 *  6
 *  7
 *  8
 *  9
 *  10
 *  11
 *  12
 *  13
 *  14
 *  15
 *  16
 *  17
 *  18
 *  19
 *  20
 *  21
 *  22
 *  23
 *  24
 *  25
 *  26
 *  27
 *  28
 *  29
 *  30
 *  31
 *  32
 *  33
 *  34
 *  35
 *  36
 *  37
 *  38
 *  39
 *  40

检查到的死锁信息。

![format_png 6][]

## 4.5 反编译 ##

上面的代码放到了包 `com`下，假设这是一个线程环境，当怀疑当前运行的代码不是自己想要的代码时，可以直接反编译出代码，也可以选择性的查看类的字段或方法信息。

如果怀疑不是自己的代码，可以使用 **jad** 命令直接反编译 class。

![jad][]

`jad` 命令还提供了一些其他参数：

# 反编译只显示源码
    jad --source-only com.Arthas
    # 反编译某个类的某个方法
    jad --source-only com.Arthas mysql

*  1
 *  2
 *  3
 *  4

## 4.6 查看字段信息 ##

使用 \*\*sc -d -f \*\* 命令查看类的字段信息。

[arthas@20252]$ sc -d -f com.Arthas
    sc -d -f com.Arthas
     class-info        com.Arthas
     code-source       /C:/Users/Niu/Desktop/arthas/target/classes/
     name              com.Arthas
     isInterface       false
     isAnnotation      false
     isEnum            false
     isAnonymousClass  false
     isArray           false
     isLocalClass      false
     isMemberClass     false
     isPrimitive       false
     isSynthetic       false
     simple-name       Arthas
     modifier          public
     annotation
     interfaces
     super-class       +-java.lang.Object
     class-loader      +-sun.misc.Launcher$AppClassLoader@18b4aac2
                         +-sun.misc.Launcher$ExtClassLoader@2ef1e4fa
     classLoaderHash   18b4aac2
     fields            modifierfinal,private,static
                       type    org.slf4j.Logger
                       name    log
                       value   Logger[com.Arthas]
    
                       modifierprivate,static
                       type    java.util.HashSet
                       name    hashSet
                       value   [count1, count2]
    
                       modifierprivate,static
                       type    java.util.concurrent.ExecutorService
                       name    executorService
                       value   java.util.concurrent.ThreadPoolExecutor@71c03156[Ru
                               nning, pool size = 1, active threads = 1, queued ta
                               sks = 0, completed tasks = 0]
    
    
    Affect(row-cnt:1) cost in 9 ms.

*  1
 *  2
 *  3
 *  4
 *  5
 *  6
 *  7
 *  8
 *  9
 *  10
 *  11
 *  12
 *  13
 *  14
 *  15
 *  16
 *  17
 *  18
 *  19
 *  20
 *  21
 *  22
 *  23
 *  24
 *  25
 *  26
 *  27
 *  28
 *  29
 *  30
 *  31
 *  32
 *  33
 *  34
 *  35
 *  36
 *  37
 *  38
 *  39
 *  40
 *  41

## 4.7 查看方法信息 ##

使用 **sm** 命令查看类的方法信息。

[arthas@22180]$ sm com.Arthas
    com.Arthas <init>()V
    com.Arthas start()V
    com.Arthas thread()V
    com.Arthas deadThread()V
    com.Arthas lambda$cpuHigh$1()V
    com.Arthas cpuHigh()V
    com.Arthas lambda$thread$3()V
    com.Arthas addHashSetThread()V
    com.Arthas cpuNormal()V
    com.Arthas cpu()V
    com.Arthas lambda$addHashSetThread$0()V
    com.Arthas lambda$deadThread$4(Ljava/lang/Object;Ljava/lang/Object;)V
    com.Arthas lambda$deadThread$5(Ljava/lang/Object;Ljava/lang/Object;)V
    com.Arthas lambda$cpuNormal$2()V
    Affect(row-cnt:16) cost in 6 ms.

*  1
 *  2
 *  3
 *  4
 *  5
 *  6
 *  7
 *  8
 *  9
 *  10
 *  11
 *  12
 *  13
 *  14
 *  15
 *  16

## 4.8 对变量的值很是好奇 ##

使用 **ognl** 命令，ognl 表达式可以轻松操作想要的信息。

代码还是上面的示例代码，我们查看变量 `hashSet` 中的数据：

![format_png 7][]

查看静态变量 `hashSet` 信息。

[arthas@19856]$ ognl '@com.Arthas@hashSet'
    @HashSet[
        @String[count1],
        @String[count2],
        @String[count29],
        @String[count28],
        @String[count0],
        @String[count27],
        @String[count5],
        @String[count26],
        @String[count6],
        @String[count25],
        @String[count3],
        @String[count24],

*  1
 *  2
 *  3
 *  4
 *  5
 *  6
 *  7
 *  8
 *  9
 *  10
 *  11
 *  12
 *  13
 *  14

查看静态变量 hashSet 大小。

[arthas@19856]$ ognl '@com.Arthas@hashSet.size()'
    	@Integer[57]

*  1
 *  2

甚至可以进行操作。

[arthas@19856]$ ognl  '@com.Arthas@hashSet.add("test")'
    	@Boolean[true]
    [arthas@19856]$
    # 查看添加的字符
    [arthas@19856]$ ognl  '@com.Arthas@hashSet' | grep test
        @String[test],
    [arthas@19856]$

*  1
 *  2
 *  3
 *  4
 *  5
 *  6
 *  7

`ognl` 可以做很多事情，可以参考 [ognl 表达式特殊用法( https://github.com/alibaba/arthas/issues/71 )][ognl _ https_github.com_alibaba_arthas_issues_71]。

## 4.9 程序有没有问题 ##

### 4.9.1 运行较慢、耗时较长 ###

使用 **trace** 命令可以跟踪统计方法耗时

这次换一个模拟代码。一个最基础的 Springboot 项目（当然，不想 Springboot 的话，你也可以直接在 UserController 里 main 方法启动）控制层 `getUser` 方法调用了 `userService.get(uid);`，这个方法中分别进行`check`、`service`、`redis`、`mysql`操作。

@RestController
    @Slf4j
    public class UserController {
    
        @Autowired
        private UserServiceImpl userService;
    
        @GetMapping(value = "/user")
        public HashMap<String, Object> getUser(Integer uid) throws Exception {
            // 模拟用户查询
            userService.get(uid);
            HashMap<String, Object> hashMap = new HashMap<>();
            hashMap.put("uid", uid);
            hashMap.put("name", "name" + uid);
            return hashMap;
        }
    }

*  1
 *  2
 *  3
 *  4
 *  5
 *  6
 *  7
 *  8
 *  9
 *  10
 *  11
 *  12
 *  13
 *  14
 *  15
 *  16
 *  17

模拟代码 Service:

@Service
    @Slf4j
    public class UserServiceImpl {
    
        public void get(Integer uid) throws Exception {
            check(uid);
            service(uid);
            redis(uid);
            mysql(uid);
        }
    
        public void service(Integer uid) throws Exception {
            int count = 0;
            for (int i = 0; i < 10; i++) {
                count += i;
            }
            log.info("service  end {}", count);
        }
    
        public void redis(Integer uid) throws Exception {
            int count = 0;
            for (int i = 0; i < 10000; i++) {
                count += i;
            }
            log.info("redis  end {}", count);
        }
    
        public void mysql(Integer uid) throws Exception {
            long count = 0;
            for (int i = 0; i < 10000000; i++) {
                count += i;
            }
            log.info("mysql end {}", count);
        }
    
     	 public boolean check(Integer uid) throws Exception {
             if (uid == null || uid < 0) {
                 log.error("uid不正确，uid:{}", uid);
                 throw new Exception("uid不正确");
             }
             return true;
         }
    }

*  1
 *  2
 *  3
 *  4
 *  5
 *  6
 *  7
 *  8
 *  9
 *  10
 *  11
 *  12
 *  13
 *  14
 *  15
 *  16
 *  17
 *  18
 *  19
 *  20
 *  21
 *  22
 *  23
 *  24
 *  25
 *  26
 *  27
 *  28
 *  29
 *  30
 *  31
 *  32
 *  33
 *  34
 *  35
 *  36
 *  37
 *  38
 *  39
 *  40
 *  41
 *  42
 *  43
 *  44

运行 Springboot 之后，使用 \*\*trace== \*\* 命令开始检测耗时情况。

[arthas@6592]$ trace com.UserController getUser

*  1

访问接口 `/getUser` ，可以看到耗时信息，看到 `com.UserServiceImpl:get()`方法耗时较高。  
![format_png 8][]

继续跟踪耗时高的方法，然后再次访问。

[arthas@6592]$ trace com.UserServiceImpl get

*  1

![format_png 9][]

很清楚的看到是 `com.UserServiceImpl`的 `mysql`方法耗时是最高的。

Affect(class-cnt:1 , method-cnt:1) cost in 31 ms.
    `---ts=2019-10-16 14:40:10;thread_name=http-nio-8080-exec-8;id=1f;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@23a918c7
        `---[6.792201ms] com.UserServiceImpl:get()
            +---[0.008ms] com.UserServiceImpl:check() #17
            +---[0.076ms] com.UserServiceImpl:service() #18
            +---[0.1089ms] com.UserServiceImpl:redis() #19
            `---[6.528899ms] com.UserServiceImpl:mysql() #20

*  1
 *  2
 *  3
 *  4
 *  5
 *  6
 *  7

### 4.9.2 统计方法耗时 ###

使用 **monitor** 命令监控统计方法的执行情况。

每5秒统计一次 `com.UserServiceImpl` 类的 `get` 方法执行情况。

monitor -c 5 com.UserServiceImpl get

*  1

![format_png 10][]

## 4.10 想观察方法信息 ##

下面的示例用到了文章的前两个模拟代码。

### 4.10.1 观察方法的入参出参信息 ###

使用 **watch** 命令轻松查看输入输出参数以及异常等信息。

USAGE:
       watch [-b] [-e] [-x <value>] [-f] [-h] [-n <value>] [-E] [-M <value>] [-s] class-pattern method-pattern express [condition-express]
    
     SUMMARY:
       Display the input/output parameter, return object, and thrown exception of specified method invocation
       The express may be one of the following expression (evaluated dynamically):
               target : the object
                clazz : the object's class
               method : the constructor or method
               params : the parameters array of method
         params[0..n] : the element of parameters array
            returnObj : the returned object of method
             throwExp : the throw exception of method
             isReturn : the method ended by return
              isThrow : the method ended by throwing exception
                #cost : the execution time in ms of method invocation
     Examples:
       watch -b org.apache.commons.lang.StringUtils isBlank params
       watch -f org.apache.commons.lang.StringUtils isBlank returnObj
       watch org.apache.commons.lang.StringUtils isBlank '{params, target, returnObj}' -x 2
       watch -bf *StringUtils isBlank params
       watch *StringUtils isBlank params[0]
       watch *StringUtils isBlank params[0] params[0].length==1
       watch *StringUtils isBlank params '#cost>100'
       watch -E -b org\.apache\.commons\.lang\.StringUtils isBlank params[0]
    
     WIKI:
       https://alibaba.github.io/arthas/watch

*  1
 *  2
 *  3
 *  4
 *  5
 *  6
 *  7
 *  8
 *  9
 *  10
 *  11
 *  12
 *  13
 *  14
 *  15
 *  16
 *  17
 *  18
 *  19
 *  20
 *  21
 *  22
 *  23
 *  24
 *  25
 *  26
 *  27
 *  28

常用操作：

# 查看入参和出参
    $ watch com.Arthas addHashSet '{params[0],returnObj}'
    # 查看入参和出参大小
    $ watch com.Arthas addHashSet '{params[0],returnObj.size}'
    # 查看入参和出参中是否包含 'count10'
    $ watch com.Arthas addHashSet '{params[0],returnObj.contains("count10")}'
    # 查看入参和出参，出参 toString
    $ watch com.Arthas addHashSet '{params[0],returnObj.toString()}'

*  1
 *  2
 *  3
 *  4
 *  5
 *  6
 *  7
 *  8

查看入参出参。

![format_png 11][]

查看返回的异常信息。

### 4.10.2 观察方法的调用路径 ###

使用 **stack**命令查看方法的调用信息。

# 观察 类com.UserServiceImpl的 mysql 方法调用路径
    stack com.UserServiceImpl mysql

*  1
 *  2

![format_png 12][]

### 4.10.3 方法调用时空隧道 ###

使用 **tt** 命令记录方法执行的详细情况。

> **tt** 命令方法执行数据的时空隧道，记录下指定方法每次调用的入参和返回信息，并能对这些不同的时间下调用进行观测 。

常用操作：

开始记录方法调用信息：tt -t com.UserServiceImpl check

![format_png 13][]

可以看到记录中 INDEX=1001 的记录的 IS-EXP = true ，说明这次调用出现异常。

查看记录的方法调用信息： tt -l

![format_png 14][]

查看调用记录的详细信息（-i 指定 INDEX）： tt -i 1001

![format_png 15][]

可以看到 INDEX=1001 的记录的异常信息。

重新发起调用，使用指定记录，使用 -p 重新调用。

tt -i 1001 -p

*  1

![format_png 16][]

文中代码已经上传到 [Github][]。

https://github.com/niumoo/lab-notes/

[Arthas logo]: /images/20221120/d0f48a927e044ff18ff5bbd0c028cbfc.png
[jps]: /images/20221120/33e80f62b62e4d07a0bb378278ef5767.png
[Arthas]: /images/20221120/ed0198d9695b44a594bcd7f4b82def62.png
[1570979937637]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly93d3cuY29kaW5nbWUubmV0L2Fzc2V0cy9hcnRoYXMvMTU3MDk3OTkzNzYzNy5wbmc?x-oss-process=image/format,png
[Arthas 1]: https://www.codingme.net/2019/11/arthas/
[dashboard]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly93d3cuY29kaW5nbWUubmV0L2Fzc2V0cy9hcnRoYXMvMTU3MTIxMjQ3MDM3My5wbmc?x-oss-process=image/format,png
[format_png]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly93d3cuY29kaW5nbWUubmV0L2Fzc2V0cy9hcnRoYXMvMTU3MDk4MzQ0MDQ1Ny5wbmc?x-oss-process=image/format,png
[format_png 1]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly93d3cuY29kaW5nbWUubmV0L2Fzc2V0cy9hcnRoYXMvMTU3MDk4MzQwMTI1NC5wbmc?x-oss-process=image/format,png
[format_png 2]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly93d3cuY29kaW5nbWUubmV0L2Fzc2V0cy9hcnRoYXMvMTU3MDk4MzA2MTA0Ny5wbmc?x-oss-process=image/format,png
[format_png 3]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly93d3cuY29kaW5nbWUubmV0L2Fzc2V0cy9hcnRoYXMvMTU3MTAxNjY3NTA4My5wbmc?x-oss-process=image/format,png
[format_png 4]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly93d3cuY29kaW5nbWUubmV0L2Fzc2V0cy9hcnRoYXMvMTU3MTAyMDg3MTUzNy5wbmc?x-oss-process=image/format,png
[format_png 5]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly93d3cuY29kaW5nbWUubmV0L2Fzc2V0cy9hcnRoYXMvMTU3MTAyMTgzODMyMy5wbmc?x-oss-process=image/format,png
[format_png 6]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly93d3cuY29kaW5nbWUubmV0L2Fzc2V0cy9hcnRoYXMvMTU3MTIwNjYzODE0Mi5wbmc?x-oss-process=image/format,png
[jad]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly93d3cuY29kaW5nbWUubmV0L2Fzc2V0cy9hcnRoYXMvaW1hZ2UtMjAxOTExMDYwMTIwMDU3NDcucG5n?x-oss-process=image/format,png
[format_png 7]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly93d3cuY29kaW5nbWUubmV0L2Fzc2V0cy9hcnRoYXMvMTU3MTE5Njc4NjY3OC5wbmc?x-oss-process=image/format,png
[ognl _ https_github.com_alibaba_arthas_issues_71]: https://github.com/alibaba/arthas/issues/71
[format_png 8]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly93d3cuY29kaW5nbWUubmV0L2Fzc2V0cy9hcnRoYXMvMTU3MTIwODE1Mzc5My5wbmc?x-oss-process=image/format,png
[format_png 9]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly93d3cuY29kaW5nbWUubmV0L2Fzc2V0cy9hcnRoYXMvMTU3MTIwODI0NTU5Ny5wbmc?x-oss-process=image/format,png
[format_png 10]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly93d3cuY29kaW5nbWUubmV0L2Fzc2V0cy9hcnRoYXMvMTU3MTIxMDE1ODAxOC5wbmc?x-oss-process=image/format,png
[format_png 11]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly93d3cuY29kaW5nbWUubmV0L2Fzc2V0cy9hcnRoYXMvMTU3MTE5NjQ4MzQ2OS5wbmc?x-oss-process=image/format,png
[format_png 12]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly93d3cuY29kaW5nbWUubmV0L2Fzc2V0cy9hcnRoYXMvMTU3MTIxMDcwNjYwMi5wbmc?x-oss-process=image/format,png
[format_png 13]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly93d3cuY29kaW5nbWUubmV0L2Fzc2V0cy9hcnRoYXMvMTU3MTIxMjAwNzI0OS5wbmc?x-oss-process=image/format,png
[format_png 14]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly93d3cuY29kaW5nbWUubmV0L2Fzc2V0cy9hcnRoYXMvMTU3MTIxMjA4MDA3MS5wbmc?x-oss-process=image/format,png
[format_png 15]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly93d3cuY29kaW5nbWUubmV0L2Fzc2V0cy9hcnRoYXMvMTU3MTIxMjE1MTA2NC5wbmc?x-oss-process=image/format,png
[format_png 16]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly93d3cuY29kaW5nbWUubmV0L2Fzc2V0cy9hcnRoYXMvMTU3MTIxMjIyNzA1OC5wbmc?x-oss-process=image/format,png
[Github]: https://github.com/niumoo/lab-notes/