Java線上問題排查神器Arthas實戰分析

itxiaoshen 發表於 2022-01-29
Java

概述

背景

是不是在實際開發工作當中經常碰到自己寫的程式碼在開發、測試環境行雲流水穩得一筆,可一到線上就經常不是缺這個就是少那個反正就是一頓報錯抽風似的,線上除錯程式碼又很麻煩,讓人頭疼得抓狂;而且debug不一定是最高效的方法,遇到線上問題不能debug了怎麼辦。原先我們Java中我們常用分析問題一般是使用JDK自帶或第三方的分析工具如jstat、jmap、jstack、 jconsole、visualvm、Java Mission Control、MAT等。但此刻的你沒有看錯,還有一款神器Arthas工具著實讓人吃驚,可幫助程式設計師解決很多繁瑣的問題,使得加班解決線上問題成為過去的可能性大大提高。

定義

Arthas是一個Java診斷工具,由阿里巴巴中介軟體團隊開源,目前已在Java開發人員中被廣泛採用。Arthas能夠分析,診斷,定位Java應用問題,例如:JVM資訊,執行緒資訊,搜尋類中的方法,跟蹤程式碼執行,觀測方法的入參和返回引數等等。並能在不修改應用程式碼的情況下,對業務問題進行診斷,包括檢視方法的出入參,異常,監測方法執行耗時,類載入資訊等,大大提升線上問題排查效率。簡單的話:就是再不重啟應用的情況下達到排查問題的目的。

特性

  • 儀表盤實時檢視系統的執行狀態。

  • OGNL表示式檢視引數和返回值/例外,檢視方法引數、返回值和異常。

  • 通過jad/sc/redefine實現線上熱插拔。

  • 快速解決類衝突問題,定位類載入路徑。

  • 快速定位應用熱點和生成火焰圖。

  • 支援線上診斷WebConsole。

  • Arthas對應用程式沒有侵入(但對宿主機jvm有侵入),程式碼或專案中不需要引入jar包或依賴,因為是通過attach的機制實現的,我們的應用的程式和arthas都是獨立的程式,arthas是通過和jvm底層互動來獲取執行在其上的應用程式實時資料的,靈活檢視執行時的值,這個和hickwall,jprofiler等監控軟體的區別(JPofiler也有這樣的功能,但是是收費的)動態增加aop代理和監控日誌功能,無需重啟服務,而且關閉arthas客戶端後會還原所有增強過的類,原則上是不會影響現有業務邏輯的。

  • 對應用程式所在的伺服器效能的影響,個別命令使用不當的話,可能會撐爆jvm記憶體或導致應用程式響應變慢,命令的輸出太多,介面呼叫太頻繁會記錄過多的資料變數到記憶體裡,比如tt指令,建議加 -n 引數 限制輸出次數,sc * 萬用字元的使用不當,範圍過大,使用非同步任務時,請勿同時開啟過多的後臺非同步命令,以免對目標JVM效能造成影響,一把雙刃劍(它甚至可以修改jdk裡的原生類),所以線上上執行肯定是需要許可權和流程控制的。

使用場景

在日常開發中,當我們發現應用的某個介面響應比較慢,這個時候想想要分析一下原因,找到程式碼中耗時的部分,比較容易想到的是在介面鏈路的 IO 操作上下游列印時間日誌,再根據幾個時間點的日誌算出耗時長的 IO 操作。這種方式沒有問題,但是加日誌需要釋出,既繁瑣又低效,這個時候可以引入一些線上 debug 的工具,arthas 就是很好的一種,除了分析耗時,還可以列印呼叫棧、方法入參及返回,類載入情況,執行緒池狀態,系統引數等等,其實現原理是解析 JVM 在作業系統中的檔案,大部分操作是隻讀的,對服務程式沒有侵入性,因此可以放心使用。

實戰

CPU佔用高示例

建立一個springboot專案並打包成arthas-demo-1.0.jar,啟動arthas-demo-1.0.jar

程式碼示例如下

package cn.itxs;

import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import java.util.UUID;
import java.util.concurrent.TimeUnit;

@SpringBootApplication
public class App 
{
    public static void main(String[] args) {
        SpringApplication.run(App.class,args);
        new Thread( () -> {
            while (true) {
                String str = UUID.randomUUID().toString().replaceAll("-", "");
            }
        },"cpu demo thread").start();

        new Thread( () -> {
            while (true) {
                String str = UUID.randomUUID().toString().replaceAll("-", "");
                try {
                    TimeUnit.MILLISECONDS.sleep(10);
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
            }
        },"cpu with sleep thread").start();
    }
}

安裝與使用

推薦方式

# 下載`arthas-boot.jar`這種也是官方推薦的方式
curl -O https://arthas.aliyun.com/arthas-boot.jar
# 啟動arthas-boot.jar,必須啟動至少一個 java程式,否則會自動退出。執行此命令會自動發現 java程式,輸入需要 attach 程式對應的序列號,例如,輸入1按回車則會監聽該程式。
java -jar arthas-boot.jar
# 比如輸入JVM (jvm實時執行狀態,記憶體使用情況等)

image-20220125102432593

CPU佔用高示例

package cn.itxs.controller;

import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.ResponseBody;
import org.springframework.web.bind.annotation.RestController;

import java.util.concurrent.TimeUnit;

@RestController
@RequestMapping("/thread")
public class ThreadController {
    private Object obj1 = new Object();
    private Object obj2 = new Object();

    @RequestMapping("/test")
    @ResponseBody
    public String test(){
        new Thread(() -> {
            synchronized (obj1){
                try {
                    TimeUnit.SECONDS.sleep(10);
                } catch (InterruptedException e) {
                    synchronized (obj2){
                        System.out.printf("thread 1執行到此");
                    }
                }
            }
        },"thread 1").start();

        new Thread(() -> {
            synchronized (obj2) {
                synchronized (obj1){
                    System.out.printf("thread 2執行到此");
                }
            }
        },"thread 2").start();
        return "thread test";
    }
}

SpringBoot啟動類

package cn.itxs;

import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;

@SpringBootApplication
public class App 
{
    public static void main(String[] args) {
        SpringApplication.run(App.class,args);
    }
}
# 訪問頁面http://192.168.50.100:8080/cpu/test
# 儀表盤命令,通過上面我們可以發現執行緒ID為29也即是執行緒名稱為“cpu demo thread”佔用的cpu較高
dashboard

image-20220126123754249

  • 第一部分時顯示JVM中執行的所有執行緒:所線上程組,優先順序,執行緒的狀態,CPU的佔有率,是否是後臺程式等。
  • 第二部分顯示的JVM記憶體的使用情況和GC的資訊。
  • 第三部分是作業系統的一些資訊和 Java版本號。
# 當前最忙的前N個執行緒 thread -b, ##找出當前阻塞其他執行緒的執行緒 thread -n 5 -i 1000 #間隔一定時間後展示,本例中可以看到最忙CPU執行緒為id=45,程式碼行數為19
thread -n 5 
# jad檢視反編譯的程式碼
jad cn.itxs.controller.CpuController

image-20220126123948798

image-20220126124323603

執行緒死鎖示例

package cn.itxs.controller;

import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.ResponseBody;
import org.springframework.web.bind.annotation.RestController;
import java.util.concurrent.TimeUnit;

@RestController
@RequestMapping("/thread")
public class ThreadController {
    private Object obj1 = new Object();
    private Object obj2 = new Object();

    @RequestMapping("/test")
    @ResponseBody
    public String test(){
        new Thread(() -> {
            synchronized (obj1){
                try {
                    TimeUnit.SECONDS.sleep(10);
                } catch (InterruptedException e) {
                }
                synchronized (obj2){
                    System.out.println("thread 1執行到此");
                }
            }
        },"thread 1").start();
        try {
            TimeUnit.SECONDS.sleep(2);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
        new Thread(() -> {
            synchronized (obj2) {
                synchronized (obj1){
                    System.out.println("thread 2執行到此");
                }
            }
        },"thread 2").start();
        return "thread test";
    }
}
# 啟動SpringBoot演示程式,訪問頁面http://192.168.50.100:8080/thread/test
# 執行arthas,檢視執行緒
thread

[外鏈圖片轉存失敗,源站可能有防盜鏈機制,建議將圖片儲存下來直接上傳(img-y9YWfijN-1643387195000)(image-20220126134413467.png)]

# 檢視阻塞執行緒
thread -b
# jad反編譯檢視程式碼
jad --source-only cn.itxs.controller.ThreadController

image-20220126135921777

[外鏈圖片轉存失敗,源站可能有防盜鏈機制,建議將圖片儲存下來直接上傳(img-yc6DFvFU-1643387195006)(image-20220126140105959.png)]

線上修復熱部署

準備一個有問題的java類

package cn.itxs.controller;

import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.ResponseBody;
import org.springframework.web.bind.annotation.RestController;

import java.util.UUID;
import java.util.concurrent.TimeUnit;

@RestController
@RequestMapping("/hot")
public class HotController {

    @RequestMapping("/test")
    @ResponseBody
    public String test(){
        boolean flag = true;
        if (flag) {
            System.out.println("開始處理邏輯");
            throw new RuntimeException("出異常了");
        }
        System.out.println("結束流程");
        return "hot test";
    }
}

啟動Spring Boot程式,訪問頁面http://192.168.50.94:8080/hot/test發現報錯,當我們分析到這段程式出異常後,我們分析異常後進行線上程式碼修改不停機不重新發包的情況下的熱更新,操作流程如下:

# 第一步:`jad命令` 將需要更改的檔案先進行反編譯,儲存下來 ,編譯器修改,-c 指定這個類的classloader的雜湊值,–source-only只顯示原始碼,最後是檔案反編譯之後的存放路徑
jad --source-only cn.itxs.controller.HotController > /home/commons/arthas/data/HotController.java
# 我們將HotController.java中的throw new RuntimeException("出異常了")程式碼刪掉,修改完後需要將類重新載入到JVM
# 第二步:`SC命令` 查詢當前類是哪個classLoader載入的,首先,使用sc命令找到要修改的類.sc全稱-search class, -d表示detail,主要是為了獲取classLoader的hash值
sc -d *HotController | grep classLoader
classLoaderHash   6267c3bb #類載入器  編號    
# 第三步:`MC命令` 用指定的classloader重新將類在記憶體中編譯
mc -c 6267c3bb /home/commons/arthas/data/HotController.java -d /home/commons/arthas/class
# 第四步:`redefine命令` 將編譯後的類載入到JVM,引數是編譯後的.class檔案地址
redefine /home/commons/arthas/class/cn/itxs/controller/HotController.class  

以上操作後再次訪問一下頁面http://192.168.50.94:8080/hot/test,發現異常沒有了程式已經是我們修改正確後的,class檔案替換成功,功能確實很強大。

image-20220126152459248

上面我們是手工一步步執行,當然我們可以使用shell指令碼串起來簡單操作。

此外還可以安裝Alibaba Cloud Toolkit熱部署元件(一鍵retransform),熱部署元件支援一鍵將編輯器中修改的 Java 原始碼快速編譯,並更新到遠端應用服務中,免去手動 dump、mc 的過程。此外,也可以一鍵還原 retransform 的類檔案。

image-20220126154240294

由於Arthas命令還是較複雜,Arthas-idea外掛(部分命令視覺化)是一個幫助生成命令的IDEA外掛,使用文件:https://www.yuque.com/arthas-idea-plugin;

安裝基於Arthas實現的簡單好用的熱部署外掛ArthasHotSwap可以一鍵生成熱部署命令,提高我們線上維護的效率。

image-20220126154348013

線上問題常見定位

watch(方法執行資料觀測)

package cn.itxs.controller;

import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.ResponseBody;
import org.springframework.web.bind.annotation.RestController;

import java.util.ArrayList;
import java.util.List;
import java.util.Random;

@RestController
@RequestMapping("/watch")
public class WatchController {
    private static Random random = new Random();
    private int illegalArgumentCount = 0;

    @RequestMapping("/test")
    @ResponseBody
    public String test(){
        String res = null;
        try {
            int number = random.nextInt() / 10000;
            List<Integer> idStrs = this.getIdStr(number);
            res = printList(number, idStrs);
        }
        catch (Exception e) {
            System.out.println(String.format("illegalArgumentCount:%3d, ", this.illegalArgumentCount) + e.getMessage());
        }
        return res;
    }

    private List<Integer> getIdStr(int number) {
        if (number < 5) {
            ++this.illegalArgumentCount;
            throw new IllegalArgumentException("number is: " + number + ", need >= 5");
        }
        ArrayList<Integer> result = new ArrayList<Integer>();
        int count = 2;
        while (count <= number) {
            if (number % count == 0) {
                result.add(count);
                number /= count;
                count = 2;
                continue;
            }
            ++count;
        }
        return result;
    }

    private String printList(int number, List<Integer> primeFactors) {
        StringBuffer sb = new StringBuffer(number + "=");
        for (int factor : primeFactors) {
            sb.append(factor).append('*');
        }
        if (sb.charAt(sb.length() - 1) == '*') {
            sb.deleteCharAt(sb.length() - 1);
        }
        System.out.println(sb);
        return sb.toString();
    }
}

啟動Spring Boot程式,通過Jmeter每秒訪問一次http://192.168.50.100:8080/watch/test

image-20220127093907292

# Arthas中的**watch**命令可以讓我們能方便的觀察到指定方法的呼叫情況,可以觀察到返回值,入參,以及變數等。
# watch 全路徑類名 方法名 觀察表示式 -x 3  ,觀察表示式匹配ognl表示式,觀察的維度也比較多。
# 比如:watch cn.itxs.controller.WatchController printList "{params,returnObj}" -x 3
# 檢視printList方法的入參和出參,-x表示的是遍歷結果深度預設1,只會列印物件的堆地址,看不到具體的屬性值,-x 2會列印結果的屬性值的資訊 -x 3會輸出入參屬性值和結果屬性值
# -n 1只抓緊一次,由於我們這裡是模擬一直請求的
watch cn.itxs.controller.WatchController printList '{params}' -n 1
# -x 表示的是遍歷結果深度預設3
watch cn.itxs.controller.WatchController printList '{params}' -n 1 -x 3
# params[0]代表第一個引數
watch cn.itxs.controller.WatchController printList '{params[0]}' -n 1 -x 3

image-20220127094326927

# 方法的返回值
watch cn.itxs.controller.WatchController getIdStr '{returnObj}' -n 1 -x 3
# 方法引數和返回值
watch cn.itxs.controller.WatchController getIdStr '{params,returnObj}' -n 1 -x 3

image-20220127094944423

# 觀察方法執行前後當前物件屬性值
watch cn.itxs.controller.WatchController getIdStr 'target.illegalArgumentCount'

image-20220127095305635

# 觀察異常資訊,觀察表示式裡增加throwExp就好了。如果增加-e 引數就能過濾掉非異常的監聽了。

image-20220127095616406

# 在觀察表示式後面,我們可以增加條件表示式,例如按時間過濾:#cost>0.5,單位是毫秒,那麼控制檯輸出來的都是耗時在0.5毫秒以上的方法呼叫
watch cn.itxs.controller.WatchController getIdStr '{params}' '#cost>0.5'

image-20220127101715104

# 按條件過濾觀察params[1].size>4:這裡支援ognl表示式。下面例子的意思是:第二個引數(也就是List primeFactors),的size大於4的時候才觀察入參。watch cn.itxs.controller.WatchController printList '{params}' 'params[1].size>4' -x 3

image-20220127102139872

monitor(方法執行監控)

monitor結果包括如下

  • timestamp:時間戳
  • class:Java類
  • method:方法(構造方法、普通方法)
  • total:呼叫次數
  • success:成功次數
  • fail:失敗次數
  • rt:平均RT
  • fail-rate:失敗率
# -c :統計週期,預設值為10秒
monitor -c 10 cn.itxs.controller.WatchController getIdStr
# 在方法呼叫之前計算condition-express,方法後可帶表示式
monitor -b -c 10 cn.itxs.controller.WatchController getIdStr

image-20220127134451812

image-20220127145246950

trace

# trace:方法內部呼叫路徑,並輸出方法路徑上的每個節點上耗時
trace cn.itxs.controller.WatchController test -n 2
#包含jdk的函式--skipJDKMethod <value>  skip jdk method trace, default value true.預設情況下,trace不會包含jdk裡的函式呼叫,如果希望trace jdk裡的函式,需要顯式設定--skipJDKMethod false。
trace --skipJDKMethod false cn.itxs.controller.WatchController test -n 2
# 呼叫耗時過濾,只會展示耗時大於10ms的呼叫路徑,有助於在排查問題的時候,只關注異常情況
trace cn.itxs.controller.WatchController test '#cost > 1'

image-20220127151509432

stack

# 輸出當前方法被呼叫的呼叫路徑,getIdStr是從test方法呼叫進來的
stack cn.itxs.controller.WatchController getIdStr -n 1
# 輸出當前方法被呼叫的呼叫路徑,條件表達過濾,第0個引數小於0,也可以根據執行時間來過濾,'#cost>1'
stack cn.itxs.controller.WatchController getIdStr 'params[0]<0' -n 1

image-20220127153509867

image-20220127153830484

tt

tt(TimeTunnel):方法執行資料的時空隧道,記錄下指定方法每次呼叫的入參和返回資訊,並能對這些不同的時間下呼叫進行觀測。對於一個最基本的使用來說,就是記錄下當前方法的每次呼叫環境現場。

# 記錄指定方法的每次呼叫環境現場
tt -t cn.itxs.controller.WatchController getIdStr 
# 列出所有呼叫記錄
tt -l cn.itxs.controller.WatchController getIdStr

image-20220127173744410

# 篩選呼叫記錄
tt -s 'method.name=="getIdStr"'
# 檢視呼叫資訊
tt -i 1001

image-20220127173952423

# 重新發起一次呼叫
tt -i 1001 -p

image-20220127174134029

Web Console

# 啟動時指定Linux的ip
java -jar arthas-boot.jar --target-ip 192.168.50.94

image-20220127180139880

profiler

profiler 命令支援生成應用熱點的火焰圖。本質上是通過不斷的取樣,然後把收集到的取樣結果生成火焰圖。一般分析效能可以先通過Arthas profiler命令生成jfr檔案;在本地通過jprofiler來分析jfr檔案,定位誰在呼叫我。

# 啟動profiler 預設情況下,生成的是cpu的火焰圖,即event為cpu。可以用--event引數來指定
profiler start
# 獲取已採集的sample的數量
profiler getSamples
# 檢視profiler狀態
profiler status
# 停止profiler 生成html格式結果,預設情況下,結果檔案是html格式,也可以用--format引數指定;或者在--file引數裡用檔名指名格式。比如--file /tmp/result.html
profiler stop --format html

image-20220128135703780

通過瀏覽器檢視arthas-output下面的profiler結果,http://192.168.50.100:3658/arthas-output/

# profiler支援的events
profiler list

image-20220128140054680

# 可以用--event引數指定要取樣的事件,比如對alloc事件進入取樣:
profiler start --event alloc
# 使用execute來執行復雜的命令
profiler execute 'start,framebuf=5000000'
# 生成 jfr格式結果;注意,jfr只支援在 start時配置。如果是在stop時指定,則不會生效。
profiler start --file /tmp/test.jfr
# 配置 include/exclude 來過濾資料
profiler start --include 'java/*' --include 'demo/*' --exclude '*Unsafe.park*'
# profiler執行 300 秒自動結束,可以用 -d/--duration 引數指定
profiler start --duration 300

image-20220128141024676

其他功能

  • 提供Http API可以提供結構化的資料,支援更復雜的互動功能,比如特定應用場景的一系列診斷操作。Http API介面地址為:http://ip:port/api,必須使用POST方式提交請求引數。如POST http://127.0.0.1:8563/api
{
  "action": "exec",
  "requestId": "req112",
  "sessionId": "94766d3c-8b39-42d3-8596-98aee3ccbefb",
  "consumerId": "955dbd1325334a84972b0f3ac19de4f7_2",
  "command": "version",
  "execTimeout": "10000"
}
  • docker使用,很多時候,應用在docker裡出現arthas無法工作的問題,是因為應用沒有安裝 JDK ,而是安裝了 JRE 。如果只安裝了 JRE,則會缺少很多JAVA的命令列工具和類庫,Arthas也沒辦法正常工作,可以使用公開的JDK映象和包管理軟體來安裝這兩種方式在Docker裡使用JDK。

    # 選擇需要監控應用的程式編號,回車後Arthas會attach到目標程式上,並輸出日誌:
    docker exec -it arthas-demo /bin/sh -c "java -jar /opt/arthas/arthas-boot.jar"
    # 甚至我們可以直接把arthas放到容器映象檔案中:
    
  • Arthas Spring Boot Starter:應用啟動後,spring會啟動arthas,並且attach自身程式。

            <dependency>
                <groupId>com.taobao.arthas</groupId>
                <artifactId>arthas-spring-boot-starter</artifactId>
                <version>${arthas.version}</version>
            </dependency>
    
  • 非spring boot應用使用方式

        <dependency>
            <groupId>com.taobao.arthas</groupId>
            <artifactId>arthas-agent-attach</artifactId>
            <version>${arthas.version}</version>
        </dependency>
        <dependency>
            <groupId>com.taobao.arthas</groupId>
            <artifactId>arthas-packaging</artifactId>
            <version>${arthas.version}</version>
        </dependency>
import com.taobao.arthas.agent.attach.ArthasAgent;
 
public class ArthasAttachExample {
	
	public static void main(String[] args) {
		ArthasAgent.attach();
	}
}

**本人部落格網站 **IT小神 www.itxiaoshen.com