可用于追蹤線上 Java服務 運行時信息的神器 BTrace，你們經常用嗎 ？

概述

生產環境中的服務可能會出現各種問題，但總不能讓服務下線來專門排查錯誤，這時候最好有一些手段來獲取程序運行時信息，比如 接口方法參數/返回值、外部調用情況 以及 函數執行時間等信息以便定位問題。傳統的日志記錄方式的確可以，但有時非常麻煩，甚至可能需要重啟服務，因此代價太大，這時可以借助一個牛批的工具：BTrace ！

BTrace 可用于動態跟蹤正在運行的 Java程序，其原理是通過動態地檢測目標應用程序的類并注入跟蹤代碼 ( “字節碼跟蹤” )，因此可以直接用于監控和追蹤線上問題而無需修改業務代碼并重啟應用程序。

BTrace 的使用方式是用戶自己編寫符合 BTrace使用語法的腳本，并結合btrace命令，來獲取應用的一切調用信息，就像下面這樣：

<btrace>/bin/btrace <PID> <trace_script>

• 其中 <PID>為被監控 Java應用的 進程ID
• <trace_script> 為 根據需要監控的信息 而自行編寫的 Java腳本

本文就來實操一波 BTrace工具的使用，實驗環境如下：

• OS：CentOS 7.4 64bit
• BTrace版本：1.3.11.3
• 被追蹤的 Java應用：Spring Boot 2.1.1 應用，這里使用我的文章《Spring Boot應用緩存實踐之：Ehcache加持》一文中的 Spring Boot工程

---

BTrace 安裝部署

• 下載 二進制文件并解壓

這里我解壓到目錄：/home/btrace

• 配置系統環境變量

vim /etc/profileBTRACE_HOME=/home/btrace export BTRACE_HOME export PATH=$PATH:$BTRACE_HOME/bin

• 驗證 BTrace安裝情況

btrace --version

---

編譯 BTrace源碼

• 克隆源碼

git clone git@github.com:btraceio/btrace.git

• 編譯源碼

./gradlew build

編譯源碼

• 構建完成的生成物路徑位于：build/libs目錄下

[

我們取出構建生成的 jar包供下文使用。

---

利用btrace追蹤 Spring Boot應用例析

首先我們得構造一個 Spring Boot的模擬業務 用于下文被追蹤和分析，這里我就使用文章 《Spring Boot應用緩存實踐之：Ehcache加持》中的實驗工程。

我們在此工程里再添加一個 scripts包，用于放置 btrace 腳本文件：

[

由于 btrace腳本中需要用到 btrace相關的組件和函數庫，因此我們還需要在工程的 pom.xml中引入 btrace的依賴，所使用的 jar包就是上文編譯生成的 btrace-1.3.11.3.jar

<dependency><groupId>com.sun.btrace</groupId><artifactId>btrace</artifactId><version>1.3.11.3</version> </dependency>

Talk is cheap ，Show you the code ！接下來就用四五個實驗來說明一切吧：

---

0x01 監控方法耗時情況

btrace 腳本：

@BTrace public class BtraceTest2 {@OnMethod(clazz = "cn.codesheep.springbt_brace.controller.UserController", method = "getUsersByName", location = @Location(Kind.RETURN))public static void getFuncRunTime( @ProbeMethodName String pmn, @Duration long duration) {println( "接口 " + pmn + strcat("的執行時間(ms)為: ", str(duration / 1000000)) ); //單位是納秒，要轉為毫秒} }

接下來開始運行 btrace腳本來攔截方法的參數，首先我們用 jps命令取到需要被監控的 Spring Boot應用的進程 Id為 27887，然后執行：

/home/btrace/bin/btrace 27887 BtraceTest2.java

這里我總共對 /getusersbyname接口發出了 12次 POST請求，情況如下：

12次請求情況

接下來我們再看看利用btrace腳本監控到的 /getuserbyname接口的執行時間：

12次請求所對應的接口調用時間

這樣一對比很明顯，從數據庫取數據還是需要 花費十幾毫秒的，但從緩存讀取數據 幾乎沒有耗時，這就是為什么要讓緩存加持于應用的原因！！！

---

0x02 攔截方法的 參數/返回值

btrace 腳本：

@OnMethod(clazz = "cn.codesheep.springbt_brace.controller.UserController",method = "getUsersByName",location = @Location(Kind.ENTRY) ) public static void getFuncEntry(@ProbeClassName String pcn, @ProbeMethodName String pmn, User user ) {println("類名: " + pcn);println("方法名: " + pmn);// 先打印入參實體整體信息BTraceUtils.print("入參實體為: ");BTraceUtils.printFields(user);// 再打印入參實體每個屬性的信息Field oneFiled = BTraceUtils.field("cn.codesheep.springbt_brace.entity.User", "userName");println("userName字段為: " + BTraceUtils.get(oneFiled, user));oneFiled = BTraceUtils.field("cn.codesheep.springbt_brace.entity.User", "userAge");println("userAge字段為: " + BTraceUtils.get(oneFiled, user));}

接下來開始運行 btrace腳本來攔截方法的參數，首先我們用 jps命令取到需要被監控的java應用的進程 Id為 27887，然后執行：

/home/btrace/bin/btrace -cp springbt_brace/target/classes 27887 BtraceTest4.java

此時正常帶參數 {"userName":"codesheep.cn"} 去請求業務接口：POST /getusersbyname，會得到如下輸出：

成功攔截到了接口入參

很明顯請求參數已經被 btrace給攔截到了

同理，如果想攔截方法的返回值，可以使用如下 btrace腳本：

@OnMethod(clazz = "cn.codesheep.springbt_brace.controller.UserController",method = "getUsersByName",location = @Location(Kind.RETURN) //函數返回的時候執行，如果不填，則在函數開始的時候執行 ) public static void getFuncReturn( @Return List<User> users ) {println("返回值為: ");println(str(users)); }

運行 btrace命令后，繼續請求想要被監控的業務接口，則可以得到類似如下的輸出：

成功攔截到了接口返回值

---

0x03 監控代碼是否到達了某類的某一行

btrace 腳本如下：

@BTrace public class BtraceTest3 {@OnMethod(clazz="cn.codesheep.springbt_brace.service.UserService",method="getUsersByName",location=@Location(value= Kind.LINE, line=28) // 比如攔截第28行, 28行是從數據庫取數據操作)public static void lineTest( @ProbeClassName String pcn, @ProbeMethodName String pmn, int line ) {BTraceUtils.println("ClassName: " + pcn);BTraceUtils.println("MethodName: " + pmn);BTraceUtils.println("執行到的line行數: " + line);} }

執行 btrace追蹤命令

/home/btrace/bin/btrace 28927 BtraceTest3.java

接著用 POSTMAN工具連續發出了對 /getuserbyname接口的 十幾次POST請求，由于只有第一次請求沒有緩存時才會從數據庫讀，因此也才會執行到 UserService類的第 28行 ！

---

0x04 監控指定函數中所有外部調用的耗時情況

btrace腳本如下：

@BTrace public class BtraceTest5 {@OnMethod (clazz = "cn.codesheep.springbt_brace.service.UserService",method = "getUsersByName",location=@Location(value= Kind.CALL, clazz="/.*/", method="/.*/", where = Where.AFTER) )public static void printMethodRunTime(@Self Object self,@TargetInstance Object instance,@TargetMethodOrField String method, @Duration long duration) {if( duration > 5000000 ){ //如果外部調用耗時大于 5ms 則打印出來println( "self: " + self );println( "instance: " + instance );println( method + ",cost:" + duration/1000000 + " ms" );}}}

執行監控命令：

/home/btrace/bin/btrace 28927 BtraceTest5.java

然后再對接口 /getuserbyname發出POST請求，觀察監控結果如下：

[](https://raw.githubusercontent.com/hansonwang99/pic/master/springbt-btrace/發現最耗時的外部調用來源于 MyBatis調用.png)發現最耗時的外部調用來源于 MyBatis調用

我們發現最耗時的外部調用來源于 MyBatis調用。

---

0x05 其他追蹤與監控

除了上面四種典型的追蹤場景之外，其他的 btrace追蹤與監控場景還比如 查看誰調用了System.gc()，調用棧如何，則可以使用如下 btrace腳本進行監控

@BTrace public class BtraceTest {@OnMethod(clazz = "java.lang.System", method = "gc")public static void onSystemGC() {println("entered System.gc()");jstack();} }

很明顯，因為btrace 內置了一系列諸如 jstack等十分有用的監控命令。

當然最后需要說明的是 btrace內置了很多語法和命令，可以應對很多線上 Java應用監控場景，大家可以去研究一下官方文檔

---

后記

由于能力有限，若有錯誤或者不當之處，還請大家批評指正，一起學習交流！

本文轉載自https://www.codesheep.cn/2019/01/17/springbt-btrace/
如有侵權，請聯系作者刪除

總結

以上是生活随笔為你收集整理的利用神器BTrace 追踪线上 Spring Boot应用运行时信息的全部內容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。