Arthas - Java 線上問題定位處理的終極利器
前言
在使用 Arthas 之前,當遇到 Java 線上問題時,如 CPU 飆升、負載突高、記憶體溢位等問題,你需要查命令,查網路,然後 jps、jstack、jmap、jhat、jstat、hprof 等一通操作。最終焦頭爛額,還不一定能查出問題所在。而現在,大多數的常見問題你都可以使用 Arthas 輕鬆定位,迅速解決,及時止損,準時下班。
1、Arthas 介紹
Arthas 是 Alibaba
在 2018 年 9 月開源的 Java 診斷工具。支援 JDK6+
, 採用命令列互動模式,提供 Tab
自動不全,可以方便的定位和診斷線上程式執行問題。截至本篇文章編寫時,已經收穫 Star
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
篩選想要的程序方式。
在出現 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 的常用命令,看到這裡你可能還不知道怎麼使用,別急,後面會一一介紹。
命令 | 介紹 |
---|---|
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、執行環境資訊。
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 --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
<完>
本文作者:未讀程式碼我的微信:wn8398
個人主頁:https://www.codingme.net
本篇文章是博主原創文章,歡迎轉載,轉載時在明顯位置註明原文連結即可。
關注公眾號回覆資源可以獲取Java 核心知識整理&面試資料。