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

本文轉載自查看原文 2019-11-06 10:30 839 開發技巧

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 之后自行探索。

是否有一個全局視角來查看系統的運行狀況？
為什么 CPU 又升高了，到底是哪里占用了 CPU ？
運行的多線程有死鎖嗎？有阻塞嗎？
程序運行耗時很長，是哪里耗時比較長呢？如何監測呢？
這個類從哪個 jar 包加載的？為什么會報各種類相關的 Exception？
我改的代碼為什么沒有執行到？難道是我沒 commit？分支搞錯了？
遇到問題無法在線上 debug，難道只能通過加日志再重新發布嗎？
有什么辦法可以監控到 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 篩選想要的進程方式。

jps 篩選進程

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

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

3.3 web console

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

1570979937637

3.4 常用命令

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

命令	介紹
dashboard	當前系統的實時數據面板
thread	查看當前 JVM 的線程堆棧信息
watch	方法執行數據觀測
trace	方法內部調用路徑，並輸出方法路徑上的每個節點上耗時
stack	輸出當前方法被調用的調用路徑
tt	方法執行數據的時空隧道，記錄下指定方法每次調用的入參和返回信息，並能對這些不同的時間下調用進行觀測
monitor	方法執行監控
jvm	查看當前 JVM 信息
vmoption	查看，更新 JVM 診斷相關的參數
sc	查看 JVM 已加載的類信息
sm	查看已加載類的方法信息
jad	反編譯指定已加載類的源碼
classloader	查看 classloader 的繼承樹，urls，類加載信息
heapdump	類似 jmap 命令的 heap dump 功能

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%。

使用命令 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 命令還提供了一些其他參數：

# 反編譯只顯示源碼
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 '@com.Arthas@hashSet.size()'
	@Integer[57]

甚至可以進行操作。

[arthas@19856]$ ognl  '@com.Arthas@hashSet.add("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

<完>

本文作者： 未讀代碼
我的微信：wn8398
個人主頁： https://www.codingme.net
本篇文章是博主原創文章，歡迎轉載，轉載時在明顯位置注明原文鏈接即可。
關注公眾號回復資源可以獲取Java 核心知識整理&面試資料。

免責聲明！

本站轉載的文章為個人學習借鑒使用，本站對版權不負任何法律責任。如果侵犯了您的隱私權益，請聯系本站郵箱yoyou2525@163.com刪除。

猜您在找 Arthas-Java的線上問題定位工具 Arthas線上監控及問題定位 java線上排查利器arthas 利用Arthas定位線上問題實例 Tomcat connectionTimeout問題定位處理線上應用調試利器 --Arthas 記Tomcat進程stop卡住問題定位處理 Arthas線上問題排查 java 線上問題定位工具 Java線上問題排查神器Arthas實戰分析