1. 背景說明

前段時間升級了urs新的遠程cookie校驗模式。功能上線后，發現涉及用戶cookie 校驗的接口，有時會報接口超時。通過日志埋點方式，確認了與urs提供的jar包內的新驗證方法有關。通過反編譯，看到相關方法執行過程中涉及參數校驗、參數組裝、遠程訪問校驗、本地校驗等步驟，究竟哪個步驟出了問題？

一種方式是讓urs幫忙提供一個新的jar包，在關鍵步驟處加日志，記錄執行時間，另一種方法，就是使用一些在線分析工具。顯然第二種方式更方便快捷。本文主要介紹兩款在線問題排的工具：Btrace 和 Greys 。

2. 工具簡介

Btrace 和 Greys 都比較適合對生成環境的問題進行排查，都屬于“事后工具” ，即服務已經上線了，無法再通過打印日志等方式埋點分析。這時可以使用這些工具，來跟蹤代碼執行耗時、堆棧情況等。

原理

都是基于動態字節碼修改技術(Hotswap)來實現運行時 java 程序的跟蹤和替換。
利用了Java SE 6 新特性Instrumentation 。

使用場景

• 分析哪些方法慢，查詢具體的故障點；
• 查看方法的參數、返回值；
• 查看對象屬性等；

Btrace 和 Greys

Btrace 和 Greys 都屬于工具，本文以實例，介紹如何使用，不再對其本身進行介紹，如果想進一步了解，可以直接去下面的鏈接：

類型	介紹
Btrace	https://github.com/btraceio/btrace/wiki
Greys介紹	https://yq.aliyun.com/articles/2390

3. 實例-使用工具排查問題

urs新提供了遠程cookie的校驗jar包，其中關鍵的方法為遠程調用方法
CookieDecoder.requestDecode(**)，我們主要對這個方法進行跟蹤。

3.1 使用Btrace

由于我們的tomcat 在 appuser 用戶下，為了有相應權限，我們的操作都在 appuser 用戶下進行。
大體步驟分為：

• 下載解壓 btrace 工具；
• 編寫監控腳本；
• 設置jdk/btrace 環境變量，上傳腳本，編譯
• 獲取tomcat 進程號
• 啟動監控
• 查看詳情

具體操作：

（1）下載btrace工具 btrace-bin-1.3.9.tgz 并解壓縮

（2） 編寫一個監控腳本（java代碼 UrsInterfaceCalls.java），

即需要監控的具體類和方法

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35

@BTrace // 備注1 public class UrsInterfaceCalls{ /** * 備注2 * 本代碼用于監控 CookieDecoder 中 requestDecode 方法的執行時間，如果執行時間大于 500ms，則打印花費的時間和堆棧 * @param duration */ @OnMethod( clazz="com.netease.urs.CookieDecoder", method="requestDecode", location=@Location(Kind.RETURN)) // 備注2 public static void requestDecode( @Duration long duration ) { // 備注3 //備注4 if(duration /1000000 > 500){ println("==CookieDecoder requestDecode spend: " + duration /1000000 + " ms"); jstack(); } } /** * 本代碼用于監控 CustomHttpComponent 中 execute 方法的執行時間，如果執行時間大于 500ms，則打印花費的時間和堆棧 * @param duration */ @OnMethod( clazz="com.netease.urs.http.CustomHttpComponent", method="execute", location=@Location(Kind.RETURN)) public static void execute( @Duration long duration ) { if(duration /1000000 > 500){ println("==ursCookieHttp doExecute spend: " + duration /1000000 + " ms"); jstack(); } } }

簡要說明

本監控類，寫了兩個監控方法:
一個是監聽CookieDecoder.requestDecode()的執行時間，如果大于 500ms，則打印日志，并打印相關堆棧；
另一個監聽CustomHttpComponent.execute()的執行時間。

備注1： 添加注釋 @BTrace ，代表本腳本將使用btrace相關功能；

備注2： 攔截方法定義 ，@OnMethod 可以指定 clazz 、 method、location。由此組成了在什么時機（location 決定）監控某個類/某些類（clazz 決定）下的某個方法/某些方法(method 決定)。

1	@OnMethod(clazz="com.netease.urs.CookieDecoder",method="requestDecode",location=@Location(Kind.RETURN))

意思是監控CookieDecoder.requestDecode() ，在執行結束后（location=@Location(Kind.RETURN) 執行相關操作。

備注3： @Duration 代表方法執行時間，納秒。

備注4： 只打印 耗時超過500ms的信息及堆棧，防止記錄打印大多。

方法注解說明

• @OnMethod:指定使用當前注解的方法應該在什么情況下觸發：
  • claszz屬性指定要匹配的類的全限定類名,可以用正則表達式;
  • method屬性指定要匹配的方法名稱,可以用正則表達式;
  • type屬性void(java.lang.String)可以用于匹配:public void funcName(String param) 中的方法入參；
  • location屬性用@Location來表明,匹配了clazz,method情況,在方法執行的何時去執行腳本(前,后,異常,行,某個方法調用)
• @OnTimer:指定一個定時任務
• @OnExit:當腳本運行Sys.exit(code)時觸發
• @OnError:當腳本運行拋出異常時觸發
• @OnEvent:腳本運行時Ctrl+C可以發送事件
• @OnLowMemory:讓你指定一個閥值,內存低于閥值觸發
• @OnProbe:可以用一個xml文件來描述你想在什么時候觸發該方法

方法參數注解說明

• @Self:目標對象本身
• @Retrun:目標程序方法返回值(Kind.RETURN)
• @ProbeClassName:目標類名
• @ProbeMethodName:目標方法名
• @targetInstance:@Location指定的clazz,method的目標(Kind.CALL)
• @targetMethodOrField:@Location指定的clazz,method的目標的方法或字段(Kind.CALL)
• @Duration:目標方法執行時間,單位是納秒,需要與 Kind.RETURN 或者 Kind.ERROR 一起使用

（3）設置jdk/btrace 環境變量

1 2 3 4 5 6 7

export JAVA_HOME=/home/jdk1.8.0 export JRE_HOME=/home/jdk1.8.0/jre export CLASSPATH=.:${JAVA_HOME}/lib:${JRE_HOME}/lib export PATH=$JAVA_HOME/bin:$PATH export BTRACE_HOME=/home/appuser/bTrace export PATH=$BTRACE_HOME/bin:$PATH

 上傳監控腳本 UrsInterfaceCalls.java 到服務器；

可以用 btracec 進行預編譯，以保證代碼無誤

（4）獲取tomcat的執行進程號 ps aux |grep “/fa.163.com”

（5）進入UrsInterfaceCalls.java所在目錄，啟動btrace監控，監聽指定進程號19504（即jvm的進程號）

1	sh btrace -p 2021 19054 UrsInterfaceCalls.java

-p 2021 ：指定一個端口號，防止多個執行導致端口沖突；
19054 ：要監聽的進程號
UrsInterfaceCalls.java ：監聽腳本

（6）查看結果
如果方法執行超過500ms，會打印日志，同時打印堆棧；

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16

==CookieDecoder requestDecode spend: 525 ms com.netease.urs.CookieDecoder.requestDecode(CookieDecoder.java:64) com.netease.urs.ntescode.validate_cookie_online(ntescode.java:49) com.netease.common.util.CookieUtil.getUserInfoFromUrsRemoteCookie(CookieUtil.java:317) com.netease.lottery.service.util.CookieUtilServiceImpl.getUserInfoFromUrsRemoteCookie(CookieUtilServiceImpl.java:88) com.netease.lottery.service.util.CookieUtilServiceImpl$$FastClassByCGLIB$$1bd66cf1.invoke(<generated>) org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) ....... org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1708) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) java.lang.Thread.run(Thread.java:745)

如果要定位具體耗時，需要對各個關鍵方法，都添加監控腳本。

3.2 使用Greys

使用greys，無需編寫 腳步，它是命令交互式的，直接輸入命令指定監控的類、方法。
但是每次只能監控一個方法，不能像 Btrace，可以同時監控多個方法。

使用過程大體步驟：

• 下載解壓 Greys工具，安裝；
• 設置jdk 環境變量
• 獲取tomcat 進程號
• 啟動監控
• 查看詳情

具體步驟：
（1）下載***版本的Greys、解壓后，執行安裝命令

1	sh ./install-local.sh

（2）設置環境變量

1 2 3 4

export JAVA_HOME=/home/jdk1.8.0 export JRE_HOME=/home/jdk1.8.0/jre export CLASSPATH=.:${JAVA_HOME}/lib:${JRE_HOME}/lib export PATH=$JAVA_HOME/bin:$PATH

（3）查詢 jvm的進程號，進入greys安裝目錄，啟動Greys

1	./greys.sh 10437

10437 為 jvm的進程號

（4）啟動后，就可以通過交互式命令方式，對指定的類、方法進行分析。

使用help 可以看到各種命令。

（5）使用 trace命令 跟蹤指定類、方法的執行時間、參數、返回值情況；
使用 help trace，查詢使用方式

例如：跟蹤CookieDecoder類中 requestDecode()方法耗時超過500ms 的方法執行情況：

1	trace -n 2 com.netease.urs.CookieDecoder requestDecode '#cost>500'

-n 2 ：代表只打印2次就退出（防止刷屏，影響性能）；
com.netease.urs.CookieDecoder ：監聽的類名
requestDecode :監聽的方法名
‘#cost>500’ : 打印條件為 耗時超過 500ms

執行后，會顯示：

1 2 3

ga?>trace -n 2 com.netease.urs.CookieDecoder requestDecode '#cost>10' Press Ctrl+D to abort. Affect(class-cnt:1 , method-cnt:2) cost in 262 ms.

代表動態修改了一個類，對兩個方法（例如方法重載）進行監控，修改花費262毫秒。

如果出現滿足條件的情況，則我們會看到打印結果：

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31

`---+Tracing for : thread_name="http-nio-8003-exec-8" thread_id=0x7a;is_daemon=true;priority=5; `---+[5283,5283ms]com.netease.urs.CookieDecoder:requestDecode() +---[1,0ms]java.lang.System:nanoTime() +---[2,1ms]org.apache.http.client.methods.HttpPost:<init>(@39) +---[2,0ms]java.lang.StringBuffer:<init>(@41) +---[2,0ms]java.lang.StringBuffer:append(@42) +---[2,0ms]java.net.URLEncoder:encode(@43) +---[2,0ms]java.lang.StringBuffer:append(@43) +---[2,0ms]java.lang.StringBuffer:append(@44) +---[2,0ms]java.lang.StringBuffer:append(@45) +---[2,0ms]java.lang.StringBuffer:append(@46) +---[2,0ms]java.lang.StringBuffer:append(@47) +---[2,0ms]java.lang.StringBuffer:append(@48) +---[2,0ms]java.lang.Integer:<init>(@49) +---[2,0ms]java.lang.Integer:<init>(@49) +---[2,0ms]java.lang.reflect.Method:invoke(@49) +---[2,0ms]java.lang.StringBuffer:append(@49) +---[2,0ms]java.lang.StringBuffer:toString(@50) +---[2,0ms]org.apache.http.entity.StringEntity:<init>(@50) +---[2,0ms]org.apache.http.entity.StringEntity:setContentType(@51) +---[2,0ms]org.apache.http.client.methods.HttpPost:setEntity(@52) +---[2,0ms]org.apache.http.client.methods.HttpPost:getParams(@53) +---[2,0ms]org.apache.http.params.HttpParams:setIntParameter(@55) +---[2,0ms]org.apache.http.params.HttpParams:setIntParameter(@58) +---[5282,5280ms]com.netease.urs.http.CustomHttpComponent:execute(@60) +---[5283,0ms]org.apache.http.HttpResponse:getEntity(@61) +---[5283,0ms]org.apache.http.util.EntityUtils:toString(@62) +---[5283,0ms]com.netease.urs.util.LogUtil:debug(@63) +---[5283,0ms]org.apache.http.client.methods.HttpPost:releaseConnection(@71) +---[5283,0ms]java.lang.System:nanoTime(@64) `---[5283,0ms]com.netease.urs.CookieDecoder:$btrace$com$netease$fa$trace$UrsInterfaceCalls$2$requestDecode(@64)

可以看到，主要耗時在

1	+---[5282,5280ms]com.netease.urs.http.CustomHttpComponent:execute(@60)

 只要一層一層跟蹤下去，就可以最終定位問題。

（6）退出前可以使用 reset 恢復增強類（即被動態修改的代碼）

（7）***，使用shutdown 關閉greys 并退出

4.總結說明

（1） 相比兩個工具，btrace 需要手寫腳步，每次更新都要重新上傳再執行，而greys 支持命令式交互，無需手寫腳本；

（2）btrace 腳步中，可以寫多個監聽類和方法，但是greys 命令同時只能輸入一個。（但是greys 可以支持多個用戶操作，所如果想同時監控多個方法，只能開多窗口）

（3）btrace 要確保監控腳本的正確性，使用前***預編譯，防止動態增強后影響在線功能；

（4）監控時，設置合適的條件，例如在 greys實例中，花費時間大于 N ms才輸出，且只打印2個。

（5）greys 中只能顯示1層的方法調用情況，無法直接跟蹤到***層；只能自己一層一層往下跟進。

【編輯推薦】

1. Java 虛擬機 OpenJ9 和 Hotspot 的 Benchmark 測試
2. WordPress 核心 JavaScript 框架選擇討論話題持續進行
3. 10 個最終編譯成 JavaScript 的腳本語言
4. 【分享】Java反序列化漏洞從理解到實踐
5. Java開發者的福音：使用 Visual Studio Code 調試 Java 應用程序

【責任編輯：張燕妮 TEL：（010）68476606】