Java在線問題排查利器之Btrace&Greys
1. 背景說明
前段時間升級了urs新的遠程cookie校驗?zāi)Ｊ?。功能上線后，發(fā)現(xiàn)涉及用戶cookie 校驗的接口，有時會報接口超時。通過日志埋點方式，確認了與urs提供的jar包內(nèi)的新驗證方法有關(guān)。通過反編譯，看到相關(guān)方法執(zhí)行過程中涉及參數(shù)校驗、參數(shù)組裝、遠程訪問校驗、本地校驗等步驟，究竟哪個步驟出了問題？
一種方式是讓urs幫忙提供一個新的jar包，在關(guān)鍵步驟處加日志，記錄執(zhí)行時間，另一種方法，就是使用一些在線分析工具。顯然第二種方式更方便快捷。本文主要介紹兩款在線問題排的工具：Btrace 和 Greys 。
2. 工具簡介
Btrace 和 Greys 都比較適合對生成環(huán)境的問題進行排查，都屬于“事后工具” ，即服務(wù)已經(jīng)上線了，無法再通過打印日志等方式埋點分析。這時可以使用這些工具，來跟蹤代碼執(zhí)行耗時、堆棧情況等。
原理
都是基于動態(tài)字節(jié)碼修改技術(shù)(Hotswap)來實現(xiàn)運行時 java 程序的跟蹤和替換。
利用了Java SE 6 新特性Instrumentation 。
使用場景
- 分析哪些方法慢，查詢具體的故障點；
- 查看方法的參數(shù)、返回值；
- 查看對象屬性等；
Btrace 和 Greys
Btrace 和 Greys 都屬于工具，本文以實例，介紹如何使用，不再對其本身進行介紹，如果想進一步了解，可以直接去下面的鏈接：
| 類型 | 介紹 |
|---|---|
| Btrace | https://github.com/btraceio/btrace/wiki |
| Greys介紹 | https://yq.aliyun.com/articles/2390 |
3. 實例-使用工具排查問題
urs新提供了遠程cookie的校驗jar包，其中關(guān)鍵的方法為遠程調(diào)用方法
CookieDecoder.requestDecode(**)，我們主要對這個方法進行跟蹤。
3.1 使用Btrace
由于我們的tomcat 在 appuser 用戶下，為了有相應(yīng)權(quán)限，我們的操作都在 appuser 用戶下進行。
大體步驟分為：
- 下載解壓 btrace 工具；
- 編寫監(jiān)控腳本；
- 設(shè)置jdk/btrace 環(huán)境變量，上傳腳本，編譯
- 獲取tomcat 進程號
- 啟動監(jiān)控
- 查看詳情
具體操作：
（1）下載btrace工具 btrace-bin-1.3.9.tgz 并解壓縮
（2） 編寫一個監(jiān)控腳本（java代碼 UrsInterfaceCalls.java），
即需要監(jiān)控的具體類和方法
1 |
@BTrace // 備注1 |
簡要說明
本監(jiān)控類，寫了兩個監(jiān)控方法:
一個是監(jiān)聽CookieDecoder.requestDecode()的執(zhí)行時間，如果大于 500ms，則打印日志，并打印相關(guān)堆棧；
另一個監(jiān)聽CustomHttpComponent.execute()的執(zhí)行時間。
備注1： 添加注釋 @BTrace ，代表本腳本將使用btrace相關(guān)功能；
備注2： 攔截方法定義 ，@OnMethod 可以指定 clazz 、 method、location。由此組成了在什么時機（location 決定）監(jiān)控某個類/某些類（clazz 決定）下的某個方法/某些方法(method 決定)。
1 |
@OnMethod(clazz="com.netease.urs.CookieDecoder",method="requestDecode",location=@Location(Kind.RETURN)) |
意思是監(jiān)控CookieDecoder.requestDecode() ，在執(zhí)行結(jié)束后（location=@Location(Kind.RETURN) 執(zhí)行相關(guān)操作。
備注3： @Duration 代表方法執(zhí)行時間，納秒。
備注4： 只打印 耗時超過500ms的信息及堆棧，防止記錄打印大多。
方法注解說明
- @OnMethod:指定使用當(dāng)前注解的方法應(yīng)該在什么情況下觸發(fā)：
- claszz屬性指定要匹配的類的全限定類名,可以用正則表達式;
- method屬性指定要匹配的方法名稱,可以用正則表達式;
- type屬性void(java.lang.String)可以用于匹配:public void funcName(String param) 中的方法入?yún)ⅲ?/li>
- location屬性用@Location來表明,匹配了clazz,method情況,在方法執(zhí)行的何時去執(zhí)行腳本(前,后,異常,行,某個方法調(diào)用)
- @OnTimer:指定一個定時任務(wù)
- @OnExit:當(dāng)腳本運行Sys.exit(code)時觸發(fā)
- @OnError:當(dāng)腳本運行拋出異常時觸發(fā)
- @OnEvent:腳本運行時Ctrl+C可以發(fā)送事件
- @OnLowMemory:讓你指定一個閥值,內(nèi)存低于閥值觸發(fā)
- @OnProbe:可以用一個xml文件來描述你想在什么時候觸發(fā)該方法
方法參數(shù)注解說明
- @Self:目標對象本身
- @Retrun:目標程序方法返回值(Kind.RETURN)
- @ProbeClassName:目標類名
- @ProbeMethodName:目標方法名
- @targetInstance:@Location指定的clazz,method的目標(Kind.CALL)
- @targetMethodOrField:@Location指定的clazz,method的目標的方法或字段(Kind.CALL)
- @Duration:目標方法執(zhí)行時間,單位是納秒,需要與 Kind.RETURN 或者 Kind.ERROR 一起使用
（3）設(shè)置jdk/btrace 環(huán)境變量
1 |
export JAVA_HOME=/home/jdk1.8.0 |
上傳監(jiān)控腳本 UrsInterfaceCalls.java 到服務(wù)器；
可以用 btracec 進行預(yù)編譯，以保證代碼無誤
（4）獲取tomcat的執(zhí)行進程號 ps aux |grep “/fa.163.com”
（5）進入UrsInterfaceCalls.java所在目錄，啟動btrace監(jiān)控，監(jiān)聽指定進程號19504（即jvm的進程號）
1 |
sh btrace -p 2021 19054 UrsInterfaceCalls.java |
-p 2021 ：指定一個端口號，防止多個執(zhí)行導(dǎo)致端口沖突；
19054 ：要監(jiān)聽的進程號
UrsInterfaceCalls.java ：監(jiān)聽腳本
（6）查看結(jié)果
如果方法執(zhí)行超過500ms，會打印日志，同時打印堆棧；
1 |
|
如果要定位具體耗時，需要對各個關(guān)鍵方法，都添加監(jiān)控腳本。
3.2 使用Greys
使用greys，無需編寫 腳步，它是命令交互式的，直接輸入命令指定監(jiān)控的類、方法。
但是每次只能監(jiān)控一個方法，不能像 Btrace，可以同時監(jiān)控多個方法。
使用過程大體步驟：
- 下載解壓 Greys工具，安裝；
- 設(shè)置jdk 環(huán)境變量
- 獲取tomcat 進程號
- 啟動監(jiān)控
- 查看詳情
具體步驟：
（1）下載***版本的Greys、解壓后，執(zhí)行安裝命令
1 |
sh ./install-local.sh |
（2）設(shè)置環(huán)境變量
1 |
export JAVA_HOME=/home/jdk1.8.0 |
（3）查詢 jvm的進程號，進入greys安裝目錄，啟動Greys
1 |
./greys.sh 10437 |
10437 為 jvm的進程號
（4）啟動后，就可以通過交互式命令方式，對指定的類、方法進行分析。
使用help 可以看到各種命令。
（5）使用 trace命令 跟蹤指定類、方法的執(zhí)行時間、參數(shù)、返回值情況；
使用 help trace，查詢使用方式
例如：跟蹤CookieDecoder類中 requestDecode()方法耗時超過500ms 的方法執(zhí)行情況：
1 |
trace -n 2 com.netease.urs.CookieDecoder requestDecode '#cost>500' |
-n 2 ：代表只打印2次就退出（防止刷屏，影響性能）；
com.netease.urs.CookieDecoder ：監(jiān)聽的類名
requestDecode :監(jiān)聽的方法名
‘#cost>500’ : 打印條件為 耗時超過 500ms
執(zhí)行后，會顯示：
1 |
ga?>trace -n 2 com.netease.urs.CookieDecoder requestDecode '#cost>10' |
代表動態(tài)修改了一個類，對兩個方法（例如方法重載）進行監(jiān)控，修改花費262毫秒。
如果出現(xiàn)滿足條件的情況，則我們會看到打印結(jié)果：
1 |
`---+Tracing for : thread_name="http-nio-8003-exec-8" thread_id=0x7a;is_daemon=true;priority=5; |
可以看到，主要耗時在
1 |
+---[5282,5280ms]com.netease.urs.http.CustomHttpComponent:execute(@60) |
只要一層一層跟蹤下去，就可以最終定位問題。
（6）退出前可以使用 reset 恢復(fù)增強類（即被動態(tài)修改的代碼）
（7）***，使用shutdown 關(guān)閉greys 并退出
4.總結(jié)說明
（1） 相比兩個工具，btrace 需要手寫腳步，每次更新都要重新上傳再執(zhí)行，而greys 支持命令式交互，無需手寫腳本；
（2）btrace 腳步中，可以寫多個監(jiān)聽類和方法，但是greys 命令同時只能輸入一個。（但是greys 可以支持多個用戶操作，所如果想同時監(jiān)控多個方法，只能開多窗口）
（3）btrace 要確保監(jiān)控腳本的正確性，使用前***預(yù)編譯，防止動態(tài)增強后影響在線功能；
（4）監(jiān)控時，設(shè)置合適的條件，例如在 greys實例中，花費時間大于 N ms才輸出，且只打印2個。
（5）greys 中只能顯示1層的方法調(diào)用情況，無法直接跟蹤到***層；只能自己一層一層往下跟進。
【編輯推薦】
【責(zé)任編輯：張燕妮 TEL：（010）68476606】
