簡(jiǎn)明的 Arthas 入門教程
Arthas是一款強(qiáng)大的開(kāi)源Java診斷程序,它可以非常方便的啟動(dòng)并以界面式的方式和Java程序進(jìn)行交互,支持監(jiān)控程序的內(nèi)存使用情況、線程信息、gc情況、甚至可以反編譯并修改現(xiàn)上代碼等。
如下圖,arthas的運(yùn)行原理大致是以下幾個(gè)步驟:
- 啟動(dòng)arthas選擇目標(biāo)Java程序后,artahs會(huì)向目標(biāo)程序注入一個(gè)代理。
- 代理會(huì)創(chuàng)建一個(gè)集HTTP和Telnet的服務(wù)器與客戶端建立連接。
- 客戶端與服務(wù)端建立連接。
- 后續(xù)客戶端需要監(jiān)控或者調(diào)整程序都可以通過(guò)服務(wù)端Java Instrumentation機(jī)制和應(yīng)用程序產(chǎn)生交互。
為了讓讀者可以快速了并熟練掌握Arhtas的基本使用,筆者就以幾個(gè)比較常見(jiàn)的例子來(lái)演示一下Arthas的日常使用的常規(guī)套路。
詳解Arthas配置與使用
快速開(kāi)始
在介紹幾個(gè)典型的案例之前,我們需要先下載一下Arthas,并了解Arthas的一些簡(jiǎn)單的使用方式(注意:筆者為了方便演示所用的環(huán)境都是基于win 10,對(duì)于Linux環(huán)境而言操作也差不多),Arthas的官方地址如下:
https://arthas.aliyun.com/
考慮到方便筆者一般是使用命令行的方式下載:
curl -O https://arthas.aliyun.com/arthas-boot.jar
完成后我們通過(guò)下面這個(gè)命令就可以將Arthas啟動(dòng)了。
java -jar arthas-boot.jar
可以看到剛剛進(jìn)入界面時(shí),Arthas就會(huì)分別為每個(gè)服務(wù)器中正在運(yùn)行的Java程序標(biāo)上序號(hào),我們只需輸入對(duì)應(yīng)序號(hào)并點(diǎn)擊回車即可進(jìn)行對(duì)目標(biāo)程序的監(jiān)控,為了演示筆者任意選擇一個(gè)2,并點(diǎn)擊回車。
隨后我們就進(jìn)入的交互界面,如下圖:
Arthas最常用的監(jiān)控指令就是dashboard,對(duì)于dashboard的使用說(shuō)明,我們可以像使用Linux一下在dashboard命令后面追加一個(gè)--help。
如下圖所示,可以看出dashboard的用法大抵是這樣的:
- 默認(rèn)參數(shù)都不加,每隔5s刷新一次面板。
- -i 指定刷新面板間隔。
- -n 指定刷新次數(shù)。
所以假如我們希望每10s刷新一次,重復(fù)執(zhí)行3次的指令就是:
dashboard -i 10000 -n 3
此時(shí)面板就會(huì)每隔10s刷新一次界面,監(jiān)控界面如下圖所示,從圖中不難看出dashboard大抵范圍3個(gè)板塊:
- 線程信息版塊,對(duì)應(yīng)的列名分別是:id、線程名、所屬線程組、優(yōu)先級(jí)、線程運(yùn)行狀態(tài)、cpu使用率、延遲時(shí)間、運(yùn)行時(shí)間、是否被打斷。
- 內(nèi)存使用版塊,大體都是記錄著各代內(nèi)存和gc情況。
- 服務(wù)器運(yùn)行參數(shù)版塊,這一版塊記錄著程序當(dāng)前運(yùn)行服務(wù)器的內(nèi)核版本信息、jdk版本等。
在Arthas中,如果我們希望退出dashboard直接按ctrl+c即可,如果我們希望退出當(dāng)前Java程序的交互界面,輸入exit即可。
定位CPU 100%問(wèn)題
CPU 100%問(wèn)題算是生產(chǎn)環(huán)境下最難排查的問(wèn)題了,在沒(méi)有Arthas之前,我們常規(guī)的排查思路大致為:
- 使用top確定是否為java進(jìn)程。
- 如果是,則使用jps定位Java進(jìn)程號(hào)。
- 找到最吃資源的線程號(hào)。
- 將線程號(hào)轉(zhuǎn)為十六進(jìn)制。
- 通過(guò)jstack導(dǎo)出日志并使用全局搜索十六進(jìn)制線程號(hào)定位到問(wèn)題代碼段。
如上所述,是不是很繁瑣呢?有了Arthas之后,問(wèn)題的定位就會(huì)簡(jiǎn)單快速許多,為了演示這個(gè)例子,筆者使用Spring Boot項(xiàng)目編寫(xiě)了一段模擬CPU 100%問(wèn)題的代碼段,可以看到筆者使用:
/**
* 一個(gè)線程數(shù)只有1的線程池
*/
private static ExecutorService threadPool = Executors.newCachedThreadPool();
@RequestMapping("cpu-100")
public static void cpu() {
loopThread();
cpuHigh();
}
/**
* 極度消耗CPU的線程
*/
private static void cpuHigh() {
// 添加到線程
threadPool.submit(() -> {
while (true) {
log.info("cpu working");
}
});
}
/**
* 無(wú)限循環(huán)的線程
*/
private static void loopThread() {
for (int i = 0; i < 10; i++) {
new Thread(() -> {
while (true) {
log.info("死循環(huán)線程工作中");
try {
Thread.sleep(3000);
} catch (InterruptedException e) {
e.printStackTrace();
}
}
}, "thread" + i).start();
}
}
完成編寫(xiě)后,我們將項(xiàng)目啟動(dòng)并請(qǐng)求該地址,不久后你就會(huì)發(fā)現(xiàn)CPU直接飆升接近100%,此時(shí)我們的arthas就派上用場(chǎng)了,首先我們自然是將arthas啟動(dòng)。
java -jar arthas-boot.jar
此時(shí)控制臺(tái)會(huì)出現(xiàn)下面幾個(gè)選項(xiàng),它通過(guò)不同序號(hào)標(biāo)明不同的Java程序,我們看到我們的目標(biāo)程序ArthasExampleApplication,序號(hào)為1,所以我們輸入1按回車。
F:\github>java -jar arthas-boot.jar
[INFO] JAVA_HOME: D:\myinstall\jdk8\jre8
[INFO] arthas-boot version: 3.6.9
[INFO] Found existing java process, please choose one and input the serial number of the process, eg : 1. Then hit ENTER.
* [1]: 18720 com.example.arthasExample.ArthasExampleApplication
[2]: 19300 org.jetbrains.jps.cmdline.Launcher
[3]: 7876 org.jetbrains.idea.maven.server.RemoteMavenServer
[4]: 14488
進(jìn)入控制臺(tái),我們直接鍵入thread命令可以看到,有一個(gè)名為 pool-1-thread-1的線程CPU使用率非常高,所以我們需要定位它所工作的代碼段。
由控制臺(tái)可知,它的序號(hào)為59,所以我們直接鍵入:
thread 59
很快的,我們直接定位到了問(wèn)題代碼段,在TestController的42行。
知道了代碼的位置之后,我們根據(jù)類的包路徑com.example.arthasExample.TestController直接通過(guò)Arthas反編譯查看源碼,命令如下:
jad --source-only com.example.arthasExample.TestController
最終我們定位到了問(wèn)題代碼,即時(shí)修復(fù)即可。
定位線程死鎖問(wèn)題
對(duì)于線程死鎖問(wèn)題,我們也給出下面這樣一段示例代碼,線程1先取鎖1再取鎖2,線程2反之,兩者取鎖順序構(gòu)成環(huán)路造成死鎖。
//兩把鎖
private Object lock1 = new Object();
private Object lock2 = new Object();
@RequestMapping("dead-lock")
public void deadLock() {
//線程1先取得鎖1,休眠后取鎖2
new Thread(() -> {
synchronized (lock1) {
try {
log.info("t1 successfully acquired the lock1......");
TimeUnit.SECONDS.sleep(5);
} catch (InterruptedException e) {
e.printStackTrace();
}
synchronized (lock2) {
log.info("t1 successfully acquired the lock1......");
}
}
}, "t1").start();
//線程2先取得鎖2,休眠后取鎖1
new Thread(() -> {
synchronized (lock2) {
try {
log.info("t2 successfully acquired the lock2......");
TimeUnit.SECONDS.sleep(5);
} catch (InterruptedException e) {
e.printStackTrace();
}
synchronized (lock1) {
log.info("t2 successfully acquired the lock1......");
}
}
}, "t2").start();
}
了解代碼流程之后,我們直接調(diào)用這個(gè)接口,打開(kāi)Arthas查看鍵入thread線程信息可以看到我們的t1和t2兩個(gè)線程處于等待狀態(tài),大概率存在問(wèn)題。
隨后我們直接鍵入thread -b,發(fā)現(xiàn)t2線程被鎖住了,由此斷定這兩個(gè)線程看定存在死鎖,
由上述結(jié)果我們可知兩個(gè)線程的id分別是65和66,所以使用thread id號(hào)的命令直接定位到問(wèn)題代碼段并解決問(wèn)題即可。
反編譯查看代碼
上文我們其實(shí)已經(jīng)用到了jad這個(gè)反編譯命令,對(duì)于筆者來(lái)說(shuō),jad有兩種比較常見(jiàn)的用法,除了上述那種反編譯類的指令jad --source-only 類的包路徑,還有一種定位方法代碼段的命令jad --source-only 類的包路徑 方法名。
例如筆者想定位TestController的deadLock代碼,我們就可以鍵入:
jad --source-only com.example.arthasExample.TestController deadLock
如下圖,我們可以直接看到的方法的代碼:
定位字段信息(不常用)
我們希望看到某個(gè)類下所有字段的詳情,我們就可以使用這條命令
sc -d -f 類的包路徑
例如筆者想查看TestController的字段詳情,就可以鍵入這條命令
sc -d -f com.example.arthasExample.TestController
可以看到這條指令不僅可以查看字段的定義和注解,還可以查看線程池的使用情況以及集合內(nèi)部的value。
查看方法列表(不常用)
這條命令筆者不是很常用,為了教程的完整性筆者也演示一下,假如我們希望查看某個(gè)類的方法,可以使用:
sm 類的包路徑
以筆者為例,查看TestController的方法為:
sm com.example.arthasExample.TestController
輸出結(jié)果如下:
靜態(tài)變量監(jiān)控(常用)
Arthas提供了對(duì)靜態(tài)變量的分析,以下面這段代碼為例,如果筆者希望看到list 內(nèi)部詳情,我們就可以使用ognl。
private static List<String> list = new ArrayList<>();
@RequestMapping("add")
public void add() {
for (int i = 0; i < 10; i++) {
list.add("val" + i);
}
}
在我們執(zhí)行完接口完成添加操作之后,我們可以直接使用ognl進(jìn)行監(jiān)控。例如我們希望查看上述list的內(nèi)容,我們就可以使用命令:
ognl '@類的包路徑@變量名'
所以如果筆者查看list的命令為:
ognl '@com.example.arthasExample.TestController@list'
輸出結(jié)果如下:
當(dāng)然ognl還有一些比較特殊的用法,例如查看集合的長(zhǎng)度,添加元素到集合中等操作,具體可以參考GitHub這個(gè)issue:
https://github.com/alibaba/arthas/issues/71
運(yùn)行耗時(shí)性能問(wèn)題排查
對(duì)于統(tǒng)計(jì)耗時(shí)的操作我們經(jīng)常會(huì)用打日志的方式來(lái)監(jiān)控,在環(huán)境復(fù)雜的生產(chǎn)環(huán)境,我們常因?yàn)榍啡笨紤]而忘記對(duì)某些方法進(jìn)行監(jiān)控。 同樣的Arthas也為我們提供了一些便捷的命令來(lái)完成對(duì)方法耗時(shí)的監(jiān)控與統(tǒng)計(jì):
筆者這里給出一段UserServiceImpl 模擬用戶查詢時(shí)進(jìn)行參數(shù)校驗(yàn)、其他service調(diào)用、redis調(diào)用、MySQL調(diào)用。
@Service
@Slf4j
public class UserServiceImpl {
public JSONObject queryUser(Integer uid) throws Exception {
check(uid);
service(uid);
redis(uid);
return mysql(uid);
}
public void service(Integer uid) throws Exception {
log.info("調(diào)用其他service。。。。。");
TimeUnit.SECONDS.sleep(RandomUtil.randomLong(1, 2));
}
public void redis(Integer uid) throws Exception {
log.info("查看redis緩存數(shù)據(jù)。。。。。");
TimeUnit.MILLISECONDS.sleep(RandomUtil.randomInt(100, 200));
}
public JSONObject mysql(Integer uid) throws Exception {
log.info("查詢MySQL數(shù)據(jù)......");
TimeUnit.SECONDS.sleep(RandomUtil.randomInt(3, 4));
JSONObject jsonObject = new JSONObject();
jsonObject.putOnce("name", "xiaoming");
jsonObject.putOnce("age", 18);
return jsonObject;
}
public boolean check(Integer uid) throws Exception {
if (uid == null || uid < 0) {
log.error("非法用戶id,uid:{}", uid);
throw new Exception("非法用戶id");
}
return true;
}
}
對(duì)應(yīng)的controller代碼如下,假如我們?cè)谏a(chǎn)環(huán)境下發(fā)現(xiàn)這個(gè)接口非常耗時(shí),我們又沒(méi)有日志,那么我們?nèi)绾卫肁rthas排查耗時(shí)問(wèn)題呢?
@Autowired
private UserServiceImpl userService;
@GetMapping(value = "/user")
public JSONObject queryUser(Integer uid) throws Exception {
return userService.queryUser(uid);
}
我們可以用trace命令,我們首先用trace追蹤一下TestController 的queryUser耗時(shí)的調(diào)用:
trace com.example.arthasExample.TestController queryUser
可以發(fā)現(xiàn)TestController 并無(wú)異常,所有的耗時(shí)都在UserServiceImpl:
所以我們?cè)賹?duì)UserServiceImpl 的queryUser進(jìn)行追鐘。
trace com.example.arthasExample.UserServiceImpl queryUser
完成命令鍵入后,控制臺(tái)就會(huì)阻塞監(jiān)控這個(gè)方法,然后我們調(diào)用一下這個(gè)接口,可以發(fā)現(xiàn)原來(lái)是MySQL查詢非常耗時(shí),由此我們就可以進(jìn)一步去推斷問(wèn)題了。
方法耗時(shí)統(tǒng)計(jì)
有時(shí)候我們希望監(jiān)控某個(gè)方法單位時(shí)間內(nèi)請(qǐng)求的耗時(shí)和調(diào)用情況,我們就可以使用monitor命令,例如我們希望每5s查看TestController 的queryUser的情況,我們就可以鍵入:
monitor -c 5 com.example.arthasExample.TestController queryUser
可以看到控制臺(tái)會(huì)每5s輸入請(qǐng)求次數(shù)、成功和失敗次數(shù)以及平均耗時(shí)等信息。
定位出入?yún)㈠e(cuò)誤問(wèn)題
有時(shí)候我們希望定位某個(gè)日志沒(méi)有打到的方法的出入?yún)⒃斍?,例如上面的mysql()的出入?yún)ⅲ覀兺耆梢酝ㄟ^(guò)Arthas的watch方法做到,對(duì)應(yīng)命令為:
watch com.example.arthasExample.UserServiceImpl mysql '{params[0],returnObj}'
可以看到,我們的入?yún)?,出參是一個(gè)對(duì)象。
更進(jìn)一步,假如我們希望可以打印出對(duì)象的內(nèi)容,那么我們就可以使用toString方法做到:
watch com.example.arthasExample.UserServiceImpl mysql '{params[0],returnObj.toString()}'
除此之外watch 還支持很多的騷操作,具體可以參考官方文檔:https://arthas.aliyun.com/doc/watch.html
監(jiān)控方法調(diào)用路徑
還是以上文mysql方法為例,如果我們希望快速定位到它的調(diào)用路徑,我們可以使用stack方法:
stack com.example.arthasExample.UserServiceImpl mysql
可以看到詳細(xì)的調(diào)用路徑直接輸出到控制臺(tái)。
獲取方法調(diào)用的過(guò)程
我們希望查看方法調(diào)用時(shí)出現(xiàn)異常的原因,出參和入?yún)r(shí),可以使用tt這條指令,例如我們想查看check方法為何會(huì)報(bào)錯(cuò),我們就可以使用tt:
tt -t com.example.arthasExample.UserServiceImpl check
從輸出結(jié)果來(lái)看,第二次拋出異常了,我們可以基于1001這個(gè)索引去定位問(wèn)題。
tt -i 1001
最終可以得出,入?yún)?1:
如果我們想重新發(fā)起調(diào)用,可以直接使用:
tt -i 1001 -p
oom問(wèn)題
以下面這段代碼為例,筆者將堆內(nèi)存改為100m,命令為-Xms100m -Xmx100m,啟動(dòng)后直接重現(xiàn)oom問(wèn)題:
final ThreadPoolExecutor poolExecutor = new ThreadPoolExecutor(100, 100, 1, TimeUnit.MINUTES,
new LinkedBlockingQueue<>());// 創(chuàng)建線程池,通過(guò)線程池,保證創(chuàng)建的線程存活
@RequestMapping(value = "/oom")
public String oom(HttpServletRequest request) {
poolExecutor.execute(() -> {
Byte[] c = new Byte[4* 1024* 1024];
localVariable.set(c);// 為線程添加變量
});
return "success";
}
然后通過(guò)arthas發(fā)現(xiàn)老年代內(nèi)存幾乎已滿,gc也十分頻繁。
由此我們可以直接使用Arthas的heapdump 導(dǎo)出文件到mat中進(jìn)行進(jìn)一步分析。
heapdump D://heap.hprof
導(dǎo)出的結(jié)果如下,后續(xù)我們就可以點(diǎn)擊detail推斷到問(wèn)題的源頭了。
最終我們很快速的定位到了問(wèn)題代碼:
線上替換代碼
有時(shí)候我們測(cè)試難免會(huì)遺漏一些情況,如下所示,我們業(yè)務(wù)要求id小于1才拋出異常,但是我們因?yàn)榇中亩鴮⑴袛鄺l件寫(xiě)成id<2,結(jié)果懵懵懂懂的就將這段代碼部到了生產(chǎn)環(huán)境,導(dǎo)致業(yè)務(wù)查詢出了問(wèn)題。
@GetMapping(value={"/user/{id}"})
public JSONObject findUserById(@PathVariable Integer id) {
log.info("id: {}",id);
if (id != null && id < 2) {
throw new IllegalArgumentException("id < 1");
}
return new JSONObject().putOnce("name","user"+id).putOnce("age",18);
}
對(duì)于生產(chǎn)環(huán)境,我們肯定是無(wú)法立刻重啟替換jar包的,對(duì)于這類問(wèn)題,我們完全可以使用arthas實(shí)現(xiàn)在線熱更新。
首先第一步,我們將生產(chǎn)環(huán)境的字節(jié)碼反編譯并導(dǎo)出到本地,如下所示:
jad --source-only com.example.arthasExample.TestController > d://TestController.java
然后我們修改一下對(duì)應(yīng)的代碼段:
然后我們需要找到這個(gè)類對(duì)應(yīng)類加載器的hash碼:
sc -d *TestController | grep classLoaderHash
找到對(duì)應(yīng)hash碼之后,我們就可以基于這個(gè)類加載器將修改后的Java文件編譯成字節(jié)碼文件:
mc -c 18b4aac2 d://TestController.java -d d://
最后我們將代碼熱更新到正在運(yùn)行的程序:
redefine d://com/example/arthasExample/TestController.class
此時(shí)我們傳1作為參數(shù)就不會(huì)報(bào)錯(cuò)了,說(shuō)明代碼熱更新成功了。
獲取spring上下文進(jìn)行進(jìn)一步分析操作
有時(shí)候我們希望在線上獲取Spring容器分析定位問(wèn)題,我們完全可以通過(guò)arthas攔截到這個(gè)類并進(jìn)行進(jìn)一步調(diào)用和分析。
讀過(guò)Spring MVC源碼的讀者可能都知道,每當(dāng)又HTTP請(qǐng)求發(fā)送到web容器時(shí)請(qǐng)求進(jìn)行映射轉(zhuǎn)發(fā)處理時(shí)都會(huì)經(jīng)過(guò)RequestMappingHandlerAdapter,從下面的類圖不難看出它繼承了WebApplicationObjectSupport,而該類有一個(gè)方法getWebApplicationContext可以讓我們獲取到spring容器的上下文,進(jìn)而去分析管理spring容器。
所以我們可以使用arthas的tt指令追蹤這個(gè)類的調(diào)用:
tt -t org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter invokeHandlerMethod
然后我們隨便調(diào)用一個(gè)接口,得到調(diào)用記錄:
我們就以索引為1000的調(diào)用記錄,通過(guò)-w指定ognl獲取到spring上下文并獲取到testController然后完成一個(gè)方法調(diào)用。
tt -i 1000 -w 'target.getApplicationContext().getBean("testController").findUserById(3)'
如下圖,可以看到,我們成功的完成了調(diào)用并得到了返回結(jié)果。
小結(jié)
自此我們對(duì)Arthas的常見(jiàn)操作都已演示完成,更多關(guān)于Arthas的使用讀者可以參考Arthas官網(wǎng),希望對(duì)你有幫助:https://arthas.aliyun.com/doc/