Arthas - Java 線上問題定位處理的終極利器 Hollis 2019-11-09 如下文章來源於未讀代碼 ,做者達西java
轉載:mp.weixin.qq.com/s?subscene=…mysql
在使用 Arthas 以前,當遇到 Java 線上問題時,如 CPU 飆升、負載突高、內存溢出等問題,你須要查命令,查網絡,而後 jps、jstack、jmap、jhat、jstat、hprof 等一通操做。最終焦頭爛額,還不必定能查出問題所在。而如今,大多數的常見問題你均可以使用 Arthas 輕鬆定位,迅速解決,及時止損,準時下班。git
Arthas 是 Alibaba 在 2018 年 9 月開源的 Java 診斷工具。支持 JDK6+, 採用命令行交互模式,提供 Tab 自動不全,能夠方便的定位和診斷線上程序運行問題。截至本篇文章編寫時,已經收穫 Star 17000+。github
Arthas 官方文檔十分詳細,本文也參考了官方文檔內容,同時在開源在的 Github 的項目裏的 Issues 裏不只有問題反饋,更有大量的使用案例,也能夠進行學習參考。web
開源地址:github.com/alibaba/art…redis
官方文檔:alibaba.github.io/arthasspring
得益於 Arthas 強大且豐富的功能,讓 Arthas 能作的事情超乎想象。下面僅僅列舉幾項常見的使用狀況,更多的使用場景能夠在熟悉了 Arthas 以後自行探索。sql
是否有一個全局視角來查看系統的運行情況?express
爲何 CPU 又升高了,究竟是哪裏佔用了 CPU ?apache
運行的多線程有死鎖嗎?有阻塞嗎?
程序運行耗時很長,是哪裏耗時比較長呢?如何監測呢?
這個類從哪一個 jar 包加載的?爲何會報各類類相關的 Exception?
我改的代碼爲何沒有執行到?難道是我沒 commit?分支搞錯了?
遇到問題沒法在線上 debug,難道只能經過加日誌再從新發布嗎?
有什麼辦法能夠監控到 JVM 的實時運行狀態?
前文已經提到,Arthas 是一款命令行交互模式的 Java 診斷工具,因爲是 Java 編寫,因此能夠直接下載相應 的 jar 包運行。
3.1 安裝 能夠在官方 Github 上進行下載,若是速度較慢,能夠嘗試國內的碼雲 Gitee 下載。
wget alibaba.github.io/arthas/arth…
wget arthas.gitee.io/arthas-boot…
java -jar arthas-boot.jar -h 3.2 運行 Arthas 只是一個 java 程序,因此能夠直接用 java -jar 運行。運行時或者運行以後要選擇要監測的 Java 進程。
java -jar arthas-boot.jar
[INFO] arthas-boot version: 3.1.4 [INFO] Found existing java process, please choose one and hit RETURN.
java -jar arthas-boot.jar [PID] 查看 PID 的方式能夠經過 ps 命令,也能夠經過 JDK 提供的 jps命令。
$ jps -mlvV
$ jps -mlvV | grep [xxx] jps 篩選想要的進程方式。
在出現 Arthas Logo 以後就可使用命令進行問題診斷了。下面會詳細介紹。
更多的啓動方式能夠參考 help 幫助命令。
EXAMPLES: java -jar arthas-boot.jar 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' java -jar arthas-boot.jar -f batch.as 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 的經常使用命令,看到這裏你可能還不知道怎麼使用,別急,後面會一一介紹。
命令 介紹 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 同時自動重置全部加強過的類 。
上面已經瞭解了什麼是 Arthas,以及 Arthas 的啓動方式,下面會依據一些狀況,詳細說一說 Arthas 的使用方式。在使用命令的過程當中若是有問題,每一個命令均可以是 -h 查看幫助信息。
首先編寫一個有各類狀況的測試類運行起來,再使用 Arthas 進行問題定位,
import java.util.HashSet; import java.util.concurrent.ExecutorService; import java.util.concurrent.Executors; import lombok.extern.slf4j.Slf4j;
/**
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(); }
/**
public static void cpu() { cpuHigh(); cpuNormal(); }
/**
/**
/**
/**
死鎖 / 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:
Thread#sleep()
Object#wait() 並加了超時參數
Thread#join() 並加了超時參數
LockSupport#parkNanos()
LockSupport#parkUntil()
WAITING 當線程調用如下方法時會進入WAITING狀態:
Object#wait() 並且不加超時參數
Thread#join() 並且不加超時參數
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]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]cpuHigh
thread
addHashSetThread
deadThread
deadThread
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]
[arthas@19856] ognl 能夠作不少事情,能夠參考 ognl 表達式特殊用法( github.com/alibaba/art… )。
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 ] [-f] [-h] [-n ] [-E] [-M ] [-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: alibaba.github.io/arthas/watc… 經常使用操做:
$ watch com.Arthas addHashSet '{params[0],returnObj}'
$ watch com.Arthas addHashSet '{params[0],returnObj.size}'
$ watch com.Arthas addHashSet '{params[0],returnObj.contains("count10")}'
$ watch com.Arthas addHashSet '{params[0],returnObj.toString()}' 查看入參出參。
查看返回的異常信息。
4.10.2 觀察方法的調用路徑 使用 stack命令查看方法的調用信息。
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。