引言
在我們對Java應用做問題分析的時候,往往采用log進行問題定位和分析,但是如果我們的log缺乏相關的資訊呢?遠程除錯會影回應用的正常作業,修改代碼重新部署應用,實時性和靈活性難以保證,有沒有不影響正常應用運行,又靈活并無侵入性的方法呢?
答案是有,它就是Java中的神器-BTrace
BTrace是什么?
BTrace使用Java的Attach技術,可以讓我們無縫的將我們BTrace腳本掛到JVM上,通過腳本你可以獲取到任何你想拿到的資料,在侵入性和安全性都非常可靠,特別是定位線上問題的神器,
BTrace原理
BTrace是基于動態位元組碼修改技術(Hotswap)向目標程式的位元組碼注入追蹤代碼,
安裝配置
關于BTrace的安裝配置使用,此處就不再重復造輪子,網上有太多的教程,
官網地址:https://github.com/btraceio/btrace
注意事項
生產環境可以使用,但修改的位元組碼不會被還原,使用Btrace時,需要確保追蹤的動作是只讀的(即:追蹤行為不能修改目標程式的狀態)和有限的行為(即:追蹤行為需要在有限的時間內終止),一個追蹤行為需要滿足以下的限制:
-
不能創建新的物件
-
不能創建新的陣列
-
不能拋出例外
-
不能捕獲例外
-
不能對實體或靜態方法呼叫-只有從BTraceUtils中的public static方法中或在當前腳本中宣告的方法,可以被BTrace呼叫
-
不能有外部,內部,嵌套或本地類
-
不能有同步塊或同步方法
-
不能有回圈(for,while,do..while)
-
不能繼承抽象類(父類必須是java.lang.Object)
-
不能實作介面
-
不能有斷言陳述句
-
不能有class保留字
以上的限制可以通過通過unsafe模式繞過,追蹤腳本和引擎都必須設定為unsafe模式,腳本需要使用注解為 @BTrace(unsafe=true),需要修改BTrace安裝目錄下bin中btrace腳本將 -Dcom.sun.btrace.unsafe=false改為 -Dcom.sun.btrace.unsafe=true,
注:關于unsafe的使用,如果你的程式一旦被btrace追蹤過,那么unsafe的設定會一直伴隨該行程的整個生命周期,如果你修改了unsafe的設定,只有通過重啟目標行程,才能獲得想要的結果,所以該用法不是很好使用,如果你的應用不能隨便重啟,那么你在第一次使用btrace最終目標行程之前,先想好到底使用那種模式來啟動引擎,
使用示例
攔截一個普通方法
control方法
-
@GetMapping(value = "/arg1") -
public String arg1(@RequestParam("name") String name) throws InterruptedException { -
Thread.sleep(2000); -
return "7DGroup," + name; -
}
BTrace腳本
-
/** -
* 攔截示例 -
*/ -
@BTrace -
public class PrintArgSimple { -
-
@OnMethod( -
//類名 -
clazz = "com.techstar.monitordemo.controller.UserController", -
//方法名 -
method = "arg1", -
//攔截時刻:入口 -
location = @Location(Kind.ENTRY)) -
-
/** -
* 攔截類名和方法名 -
*/ public static void anyRead(@ProbeClassName String pcn, @ProbeMethodName String pmn, AnyType[] args) { -
BTraceUtils.printArray(args); -
BTraceUtils.println(pcn + "," + pmn); -
BTraceUtils.println(); -
} -
}
攔截結果:
-
192:Btrace apple$ jps -l -
369 -
5889 /Users/apple/Downloads/performance/apache-jmeter-4.0/bin/ApacheJMeter.jar -
25922 sun.tools.jps.Jps -
23011 org.jetbrains.idea.maven.server.RemoteMavenServer -
25914 org.jetbrains.jps.cmdline.Launcher -
25915 com.techstar.monitordemo.MonitordemoApplication -
192:Btrace apple$ btrace 25915 PrintArgSimple.java -
[zuozewei, ] -
com.techstar.monitordemo.controller.UserController,arg1 -
-
[zee, ] -
com.techstar.monitordemo.controller.UserController,arg1
攔截建構式
建構式
-
@Data -
public class User { -
-
private int id; -
private String name; -
-
}
control方法
-
@GetMapping(value = "/arg2") -
public User arg2(User user) { -
return user; -
}
BTrace腳本
-
/** -
* 攔截建構式 -
*/ -
@BTrace -
public class PrintConstructor { -
-
@OnMethod(clazz = "com.techstar.monitordemo.domain.User", method = "<init>") -
public static void anyRead(@ProbeClassName String pcn, @ProbeMethodName String pmn, AnyType[] args) { -
BTraceUtils.println(pcn + "," + pmn); -
BTraceUtils.printArray(args); -
BTraceUtils.println(); -
} -
}
攔截結果
-
192:Btrace apple$ btrace 34119 PrintConstructor.java -
com.techstar.monitordemo.domain.User,<init> -
[1, zuozewei, ]
攔截同名函式,以引數區分
control方法
-
@GetMapping(value = "/same1") -
public String same(@RequestParam("name") String name) { -
return "7DGroup," + name; -
} -
-
@GetMapping(value = "/same2") -
public String same(@RequestParam("id") int id, @RequestParam("name") String name) { -
return "7DGroup," + name + "," + id; -
}
BTrace腳本
-
/** -
* 攔截同名函式,通過輸入的引數區分 -
*/ -
-
@BTrace -
public class PrintSame { -
-
@OnMethod(clazz = "com.techstar.monitordemo.controller.UserController", method = "same") -
public static void anyRead(@ProbeClassName String pcn, @ProbeMethodName String pmn, String name) { -
BTraceUtils.println(pcn + "," + pmn + "," + name); -
BTraceUtils.println(); -
} -
}
攔截結果
-
192:Btrace apple$ jps -l -
369 -
5889 /Users/apple/Downloads/performance/apache-jmeter-4.0/bin/ApacheJMeter.jar -
34281 sun.tools.jps.Jps -
34220 org.jetbrains.jps.cmdline.Launcher -
34221 com.techstar.monitordemo.MonitordemoApplication -
192:Btrace apple$ btrace 34221 PrintSame.java -
com.techstar.monitordemo.controller.UserController,same,zuozewei -
-
com.techstar.monitordemo.controller.UserController,same,zuozewei -
-
com.techstar.monitordemo.controller.UserController,same,zuozewei
攔截方法回傳值
BTrace腳本
-
/** -
* 攔截回傳值 -
*/ -
@BTrace -
public class PrintReturn { -
-
@OnMethod(clazz = "com.techstar.monitordemo.controller.UserController", method = "arg1", -
//攔截時刻:回傳值 -
location = @Location(Kind.RETURN)) -
public static void anyRead(@ProbeClassName String pcn, @ProbeMethodName String pmn, @Return AnyType result) { -
BTraceUtils.println(pcn + "," + pmn + "," + result); -
BTraceUtils.println(); -
} -
}
攔截結果
-
192:Btrace apple$ jps -l -
34528 org.jetbrains.jps.cmdline.Launcher -
34529 com.techstar.monitordemo.MonitordemoApplication -
369 -
5889 /Users/apple/Downloads/performance/apache-jmeter-4.0/bin/ApacheJMeter.jar -
34533 sun.tools.jps.Jps -
192:Btrace apple$ btrace 34529 PrintReturn.java -
com.techstar.monitordemo.controller.UserController,arg1,7DGroup,zuozewei
例外分析
有時候開發人員對例外處理不合理,導致某些重要例外人為被吃掉,并且沒有日志或者日志不詳細,導致性能分析定位問題困難,我們可以使用BTrace來處理
control方法
-
@GetMapping(value = "/exception") -
public String exception() { -
try { -
System.out.println("start..."); -
System.out.println(1 / 0); //模擬例外 -
System.out.println("end..."); -
} catch (Exception e) {} -
return "successful..."; -
}
BTrace腳本
-
/** -
* 有時候,有些例外被人為吃掉,日志又沒有列印,這個時候可以用該類定位問題 -
* This example demonstrates printing stack trace -
* of an exception and thread local variables. This -
* trace script prints exception stack trace whenever -
* java.lang.Throwable's constructor returns. This way -
* you can trace all exceptions that may be caught and -
* "eaten" silently by the traced program. Note that the -
* assumption is that the exceptions are thrown soon after -
* creation [like in "throw new FooException();"] rather -
* that be stored and thrown later. -
*/ -
@BTrace -
public class PrintOnThrow { -
// store current exception in a thread local -
// variable (@TLS annotation). Note that we can't -
// store it in a global variable! -
@TLS -
static Throwable currentException; -
-
// introduce probe into every constructor of java.lang.Throwable -
// class and store "this" in the thread local variable. -
@OnMethod(clazz = "java.lang.Throwable", method = "<init>") -
public static void onthrow(@Self Throwable self) { -
currentException = self; -
} -
-
@OnMethod(clazz = "java.lang.Throwable", method = "<init>") -
public static void onthrow1(@Self Throwable self, String s) { -
currentException = self; -
} -
-
@OnMethod(clazz = "java.lang.Throwable", method = "<init>") -
public static void onthrow1(@Self Throwable self, String s, Throwable cause) { -
currentException = self; -
} -
-
@OnMethod(clazz = "java.lang.Throwable", method = "<init>") -
public static void onthrow2(@Self Throwable self, Throwable cause) { -
currentException = self; -
} -
-
// when any constructor of java.lang.Throwable returns -
// print the currentException's stack trace. -
@OnMethod(clazz = "java.lang.Throwable", method = "<init>", location = @Location(Kind.RETURN)) -
public static void onthrowreturn() { -
if (currentException != null) { -
Threads.jstack(currentException); -
BTraceUtils.println("====================="); -
currentException = null; -
} -
} -
}
攔截結果
-
192:Btrace apple$ jps -l -
369 -
5889 /Users/apple/Downloads/performance/apache-jmeter-4.0/bin/ApacheJMeter.jar -
34727 sun.tools.jps.Jps -
34666 org.jetbrains.jps.cmdline.Launcher -
34667 com.techstar.monitordemo.MonitordemoApplication -
192:Btrace apple$ btrace 34667 PrintOnThrow.java -
java.lang.ClassNotFoundException: org.apache.catalina.webresources.WarResourceSet -
java.net.URLClassLoader.findClass(URLClassLoader.java:381) -
java.lang.ClassLoader.loadClass(ClassLoader.java:424) -
java.lang.ClassLoader.loadClass(ClassLoader.java:411) -
sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:349) -
java.lang.ClassLoader.loadClass(ClassLoader.java:357) -
org.apache.catalina.webresources.StandardRoot.isPackedWarFile(StandardRoot.java:656) -
org.apache.catalina.webresources.CachedResource.validateResource(CachedResource.java:109) -
org.apache.catalina.webresources.Cache.getResource(Cache.java:69) -
org.apache.catalina.webresources.StandardRoot.getResource(StandardRoot.java:216) -
org.apache.catalina.webresources.StandardRoot.getResource(StandardRoot.java:206) -
org.apache.catalina.mapper.Mapper.internalMapWrapper(Mapper.java:1027) -
org.apache.catalina.mapper.Mapper.internalMap(Mapper.java:842) -
org.apache.catalina.mapper.Mapper.map(Mapper.java:698) -
org.apache.catalina.connector.CoyoteAdapter.postParseRequest(CoyoteAdapter.java:679) -
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:336) -
org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:800) -
org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) -
org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:800) -
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1471) -
org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) -
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) -
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) -
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) -
java.lang.Thread.run(Thread.java:748) -
===================== -
...
定位某個超過閾值的函式
BTrace腳本
-
** -
* 探測某個包路徑下的方法執行時間是否超過某個閾值的程式,如果超過了該閥值,則列印當前執行緒的堆疊資訊, -
*/ -
-
import com.sun.btrace.BTraceUtils; -
import com.sun.btrace.annotations.*; -
-
import static com.sun.btrace.BTraceUtils.*; -
-
@BTrace -
public class PrintDurationTracer { -
@OnMethod(clazz = "/com\\.techstar\\.monitordemo\\..*/", method = "/.*/", location = @Location(Kind.RETURN)) -
public static void trace(@ProbeClassName String pcn, @ProbeMethodName String pmn, @Duration long duration) { -
//duration的單位是納秒 -
if (duration > 1000 * 1000 * 2) { -
BTraceUtils.println(Strings.strcat(Strings.strcat(pcn, "."), pmn)); -
BTraceUtils.print(" 耗時:"); -
BTraceUtils.print(duration); -
BTraceUtils.println("納秒,堆疊資訊如下"); -
jstack(); -
} -
} -
}
攔截結果
-
192:Btrace apple$ btrace 39644 PrintDurationTracer.java -
com.techstar.monitordemo.controller.Adder.execute 耗時:1715294657納秒,堆疊資訊如下 -
com.techstar.monitordemo.controller.Adder.execute(Adder.java:13) -
com.techstar.monitordemo.controller.Main.main(Main.java:10) -
com.techstar.monitordemo.controller.Adder.execute 耗時:893795666納秒,堆疊資訊如下 -
com.techstar.monitordemo.controller.Adder.execute(Adder.java:13) -
com.techstar.monitordemo.controller.Main.main(Main.java:10) -
com.techstar.monitordemo.controller.Adder.execute 耗時:1331363658納秒,堆疊資訊如下 -
com.techstar.monitordemo.controller.Adder.execute(Adder.java:13)
追蹤方法執行時間
BTrace腳本
-
/** -
* 追蹤某個方法的執行時間,實作原理同AOP一樣, -
*/ -
@BTrace -
public class PrintExecuteTimeTracer { -
@TLS -
static long beginTime; -
-
@OnMethod(clazz = "com.techstar.monitordemo.controller.Adder", method = "execute") -
public static void traceExecuteBegin() { -
beginTime = timeMillis(); -
} -
-
@OnMethod(clazz = "com.techstar.monitordemo.controller.Adder", method = "execute", location = @Location(Kind.RETURN)) -
public static void traceExecute(int arg1, int arg2, @Return int result) { -
BTraceUtils.println(strcat(strcat("Adder.execute 耗時:", str(timeMillis() - beginTime)), "ms")); -
BTraceUtils.println(strcat("回傳結果為:", str(result))); -
} -
}
攔截結果
-
192:Btrace apple$ btrace 40863 PrintExecuteTimeTracer.java -
Adder.execute 耗時:803ms -
回傳結果為:797 -
Adder.execute 耗時:1266ms -
回傳結果為:1261 -
Adder.execute 耗時:788ms -
回傳結果為:784 -
Adder.execute 耗時:1524ms -
回傳結果為:1521 -
Adder.execute 耗時:1775ms
性能分析
壓測的時候經常發現某一個服務變慢了,但是由于這個服務有很多的業務邏輯和方法構成,這個時候就不好定位到底慢在哪個地方,BTrace可以解決這個問題,只需要大概定位問題可能存在的地方,通過包路徑模糊匹配,就可以找到問題,
BTrace腳本
-
/** -
* -
* Description: -
* This script demonstrates new capabilities built into BTrace 1.2 -
* Shortened syntax - when omitting "public" identifier in the class -
* definition one can safely omit all other modifiers when declaring methods -
* and variables -
* Extended syntax for @ProbeMethodName annotation - you can use -
* parameter to request a fully qualified method name instead of -
* the short one -
* Profiling support - you can use {@linkplain Profiler} instance to gather -
* performance data with the smallest overhead possible -
*/ -
@BTrace -
class Profiling { -
@Property -
Profiler profiler = BTraceUtils.Profiling.newProfiler(); -
-
@OnMethod(clazz = "/com\\.techstar\\..*/", method = "/.*/") -
void entry(@ProbeMethodName(fqn = true) String probeMethod) { -
BTraceUtils.Profiling.recordEntry(profiler, probeMethod); -
} -
-
@OnMethod(clazz = "/com\\.techstar\\..*/", method = "/.*/", location = @Location(value = Kind.RETURN)) -
void exit(@ProbeMethodName(fqn = true) String probeMethod, @Duration long duration) { -
BTraceUtils.Profiling.recordExit(profiler, probeMethod, duration); -
} -
-
@OnTimer(5000) -
void timer() { -
BTraceUtils.Profiling.printSnapshot("Performance profile", profiler); -
}
死鎖排查
我們懷疑程式是否有死鎖,可以通過以下的腳本掃描追蹤,非常簡單方便,
-
/** -
* This BTrace program demonstrates deadlocks -
* built-in function. This example prints -
* deadlocks (if any) once every 4 seconds. -
*/ -
@BTrace -
public class PrintDeadlock { -
@OnTimer(4000) -
public static void print() { -
deadlocks(); -
} -
}
小結
BTrace是一個事后工具,所謂的事后工具就是在服務已經上線或者壓測后,但是發現有問題的時候,可以使用BTrace動態跟蹤分析,
-
比如哪些方法執行太慢,例如監控方法執行時間超過1秒的方法;
-
查看哪些方法呼叫了system.gc( ),呼叫堆疊是怎樣的;
-
查看方法的引數和屬性
-
哪些方法發生了例外
-
.....
總之,這里只是將部分經常用的列舉了下拋磚引玉,還有很多沒有列舉,大家可以參考官方的其他Sample去玩下,
轉載請註明出處,本文鏈接:https://www.uj5u.com/houduan/288606.html
標籤:Java
上一篇:JWT了解一下
