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


概述

背景

是不是在實際開發工作當中經常碰到自己寫的代碼在開發、測試環境行雲流水穩得一筆,可一到線上就經常不是缺這個就是少那個反正就是一頓報錯抽風似的,線上調試代碼又很麻煩,讓人頭疼得抓狂;而且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

image-20220126134413467

# 查看阻塞線程
thread -b
# jad反編譯查看代碼
jad --source-only cn.itxs.controller.ThreadController

image-20220126135921777

image-20220126140105959

線上修復熱部署

准備一個有問題的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


免責聲明!

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



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM