引言
在我们对Java应用做问题分析的时候,往往采用log进行问题定位和分析,但是如果我们的log缺乏相关的信息呢?远程调试会影响应用的正常工作,修改代码重新部署应用,实时性和灵活性难以保证,有没有不影响正常应用运行,又灵活并无侵入性的方法呢?
答案是有,它就是Java中的神器-BTrace
BTrace是什么?
BTrace使用Java的Attach技术,可以让我们无缝的将我们BTrace脚本挂到JVM上,通过脚本你可以获取到任何你想拿到的数据,在侵入性和安全性都非常可靠,特别是定位线上问题的神器。
BTrace原理
BTrace是基于动态字节码修改技术(Hotswap)向目标程序的字节码注入追踪代码。
安装配置
关于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; }
1.
2.
3.
4.
BTrace脚本
/** * 拦截示例
/@BTracepublic 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(); }}
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
拦截结果:
192:Btrace apple btrace 25915 PrintArgSimple.java [zuozewei, ]com.techstar.monitordemo.controller.UserController,arg1[zee, ]com.techstar.monitordemo.controller.UserController,arg1
1.
拦截构造函数
构造函数
@Datapublic class User { private int id; private String name;}
1.
control方法
@GetMapping(value = “/arg2”) public User arg2(User user) { return user; }
1.
BTrace脚本
/** * 拦截构造函数 */@BTracepublic class PrintConstructor { @OnMethod(clazz = “com.techstar.monitordemo.domain.User”, method = “”) public static void anyRead(@ProbeClassName String pcn, @ProbeMethodName String pmn, AnyType[] args) { BTraceUtils.println(pcn + “,” + pmn); BTraceUtils.printArray(args); BTraceUtils.println(); }}
1.
拦截结果
192:Btrace apple$ btrace 34119 PrintConstructor.java com.techstar.monitordemo.domain.User,[1, zuozewei, ]
1.
拦截同名函数,以参数区分
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; }
1.
BTrace脚本
/** * 拦截同名函数,通过输入的参数区分 */@BTracepublic 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(); }}
1.
拦截结果
192:Btrace apple btrace 34221 PrintSame.java com.techstar.monitordemo.controller.UserController,same,zuozeweicom.techstar.monitordemo.controller.UserController,same,zuozeweicom.techstar.monitordemo.controller.UserController,same,zuozewei
1.
拦截方法返回值
BTrace脚本
/** * 拦截返回值 */@BTracepublic 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(); }}
1.
拦截结果
192:Btrace apple btrace 34529 PrintReturn.java com.techstar.monitordemo.controller.UserController,arg1,7DGroup,zuozewei
1.
异常分析
有时候开发人员对异常处理不合理,导致某些重要异常人为被吃掉,并且没有日志或者日志不详细,导致性能分析定位问题困难,我们可以使用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…”; }
1.
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. */@BTracepublic 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 = “”) public static void onthrow(@Self Throwable self) { currentException = self; } @OnMethod(clazz = “java.lang.Throwable”, method = “”) public static void onthrow1(@Self Throwable self, String s) { currentException = self; } @OnMethod(clazz = “java.lang.Throwable”, method = “”) public static void onthrow1(@Self Throwable self, String s, Throwable cause) { currentException = self; } @OnMethod(clazz = “java.lang.Throwable”, method = “”) 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 = “”, location = @Location(Kind.RETURN)) public static void onthrowreturn() { if (currentException != null) { Threads.jstack(currentException); BTraceUtils.println(“=====================”); currentException = null; } }}
1.
拦截结果
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.LauncherConnectionHandler.process(AbstractProtocol.java:800) org.apache.tomcat.util.net.NioEndpointWorker.run(ThreadPoolExecutor.java:624) org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) java.lang.Thread.run(Thread.java:748)=====================…
1.
定位某个超过阈值的函数
BTrace脚本
** * 探测某个包路径下的方法执行时间是否超过某个阈值的程序,如果超过了该阀值,则打印当前线程的栈信息。 /import com.sun.btrace.BTraceUtils;import com.sun.btrace.annotations.;import static com.sun.btrace.BTraceUtils.;@BTracepublic 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(); } }}
1.
拦截结果
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)
1.
追踪方法执行时间
BTrace脚本
/** * 追踪某个方法的执行时间,实现原理同AOP一样。 */@BTracepublic 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))); }}
1.
拦截结果
192:Btrace apple$ btrace 40863 PrintExecuteTimeTracer.java Adder.execute 耗时:803ms返回结果为:797Adder.execute 耗时:1266ms返回结果为:1261Adder.execute 耗时:788ms返回结果为:784Adder.execute 耗时:1524ms返回结果为:1521Adder.execute 耗时:1775ms
1.
性能分析
压测的时候经常发现某一个服务变慢了,但是由于这个服务有很多的业务逻辑和方法构成,这个时候就不好定位到底慢在哪个地方。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 /@BTraceclass 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); }
1.
死锁排查
我们怀疑程序是否有死锁,可以通过以下的脚本扫描追踪,非常简单方便。
/** * This BTrace program demonstrates deadlocks * built-in function. This example prints * deadlocks (if any) once every 4 seconds. */@BTracepublic class PrintDeadlock { @OnTimer(4000) public static void print() { deadlocks(); }}
1.
小结
BTrace是一个事后工具,所谓的事后工具就是在服务已经上线或者压测后,但是发现有问题的时候,可以使用BTrace动态跟踪分析。
比如哪些方法执行太慢,例如监控方法执行时间超过1秒的方法;
查看哪些方法调用了system.gc( ),调用栈是怎样的;
查看方法的参数和属性
哪些方法发生了异常
…..
总之,这里只是将部分经常用的列举了下抛砖引玉,还有很多没有列举,大家可以参考官方的其他Sample去玩下。