Arthas – Java 線上問題定位處理的終極利器

• 2019 年 11 月 6 日
• 筆記

前言

在使用 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

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]

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

# 查看運行的 java 進程資訊  $ jps -mlvV  # 篩選 java 進程資訊  $ jps -mlvV | grep [xxx]

jps 篩選想要的進程方式。

在出現 Arthas Logo 之後就可以使用命令進行問題診斷了。下面會詳細介紹。

更多的啟動方式可以參考 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

3.3 web console

Arthas 目前支援 Web Console，在成功啟動連接進程之後就已經自動啟動，可以直接訪問 http://127.0.0.1:8563/ 訪問，頁面上的操作模式和控制台完全一樣。

3.4 常用命令

下面列舉一些 Arthas 的常用命令，看到這裡你可能還不知道怎麼使用，別急，後面會一一介紹。

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、運行環境資訊。

4.2 CPU 為什麼起飛了

上面的程式碼例子有一個 CPU 空轉的死循環，非常的消耗 CPU性能，那麼怎麼找出來呢？

使用 thread查看所有執行緒資訊，同時會列出每個執行緒的 CPU 使用率，可以看到圖裡 ID 為12 的執行緒 CPU 使用100%。

使用命令 thread 12 查看 CPU 消耗較高的 12 號執行緒資訊，可以看到 CPU 使用較高的方法和行數（這裡的行數可能和上面程式碼里的行數有區別，因為上面的程式碼在我寫文章時候重新排過版了）。

上面是先通過觀察總體的執行緒資訊，然後查看具體的執行緒運行情況。如果只是為了尋找 CPU 使用較高的執行緒，可以直接使用命令 thread -n [顯示的執行緒個數] ，就可以排列出 CPU 使用率 Top N 的執行緒。

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

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 命令查看執行緒池裡執行緒資訊。

可以看到執行緒池有 WAITING 的執行緒。

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();  }

檢查到的死鎖資訊。

4.5 反編譯

上面的程式碼放到了包 com下，假設這是一個執行緒環境，當懷疑當前運行的程式碼不是自己想要的程式碼時，可以直接反編譯出程式碼，也可以選擇性的查看類的欄位或方法資訊。

如果懷疑不是自己的程式碼，可以使用 jad 命令直接反編譯 class。

jad 命令還提供了一些其他參數：

# 反編譯只顯示源碼  jad --source-only com.Arthas  # 反編譯某個類的某個方法  jad --source-only com.Arthas mysql

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.

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.

4.8 對變數的值很是好奇

使用 ognl 命令，ognl 表達式可以輕鬆操作想要的資訊。

程式碼還是上面的示例程式碼，我們查看變數 hashSet 中的數據：

查看靜態變數 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],

查看靜態變數 hashSet 大小。

[arthas@19856]$ ognl '@[email protected]()'      @Integer[57]

甚至可以進行操作。

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

ognl 可以做很多事情，可以參考 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;      }  }

模擬程式碼 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;       }  }  

運行 Springboot 之後，使用 trace== 命令開始檢測耗時情況。

[arthas@6592]$ trace com.UserController getUser

訪問介面 /getUser ，可以看到耗時資訊，看到 com.UserServiceImpl:get()方法耗時較高。

繼續跟蹤耗時高的方法，然後再次訪問。

[arthas@6592]$ trace com.UserServiceImpl get

很清楚的看到是 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

4.9.2 統計方法耗時

使用 monitor 命令監控統計方法的執行情況。

每5秒統計一次 com.UserServiceImpl 類的 get 方法執行情況。

monitor -c 5 com.UserServiceImpl get

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

常用操作：

# 查看入參和出參  $ 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()}'

查看入參出參。

查看返回的異常資訊。

4.10.2 觀察方法的調用路徑

使用 stack命令查看方法的調用資訊。

# 觀察 類com.UserServiceImpl的 mysql 方法調用路徑  stack com.UserServiceImpl mysql

4.10.3 方法調用時空隧道

使用 tt 命令記錄方法執行的詳細情況。

tt 命令方法執行數據的時空隧道，記錄下指定方法每次調用的入參和返回資訊，並能對這些不同的時間下調用進行觀測 。

常用操作：

開始記錄方法調用資訊：tt -t com.UserServiceImpl check

可以看到記錄中 INDEX=1001 的記錄的 IS-EXP = true ，說明這次調用出現異常。

查看記錄的方法調用資訊： tt -l

查看調用記錄的詳細資訊（-i 指定 INDEX）： tt -i 1001

可以看到 INDEX=1001 的記錄的異常資訊。

重新發起調用，使用指定記錄，使用 -p 重新調用。

tt -i 1001 -p

文中程式碼已經上傳到 Github。

https://github.com/niumoo/lab-notes/tree/master/src/main/java/net/codingme/arthas

<完>