性能工具之Java调试工具BTrace入门

引言

在我们对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方法

  1. @GetMapping(value = "/arg1")

  2. public String arg1(@RequestParam("name") String name) throws InterruptedException {

  3. Thread.sleep(2000);

  4. return "7DGroup," + name;

  5. }

BTrace脚本

  1. /**

  2. * 拦截示例

  3. */

  4. @BTrace

  5. public class PrintArgSimple {

  6. @OnMethod(

  7. //类名

  8. clazz = "com.techstar.monitordemo.controller.UserController",

  9. //方法名

  10. method = "arg1",

  11. //拦截时刻:入口

  12. location = @Location(Kind.ENTRY))

  13. /**

  14. * 拦截类名和方法名

  15. */ public static void anyRead(@ProbeClassName String pcn, @ProbeMethodName String pmn, AnyType[] args) {

  16. BTraceUtils.printArray(args);

  17. BTraceUtils.println(pcn + "," + pmn);

  18. BTraceUtils.println();

  19. }

  20. }

拦截结果:

  1. 192:Btrace apple$ jps -l

  2. 369

  3. 5889 /Users/apple/Downloads/performance/apache-jmeter-4.0/bin/ApacheJMeter.jar

  4. 25922 sun.tools.jps.Jps

  5. 23011 org.jetbrains.idea.maven.server.RemoteMavenServer

  6. 25914 org.jetbrains.jps.cmdline.Launcher

  7. 25915 com.techstar.monitordemo.MonitordemoApplication

  8. 192:Btrace apple$ btrace 25915 PrintArgSimple.java

  9. [zuozewei, ]

  10. com.techstar.monitordemo.controller.UserController,arg1

  11. [zee, ]

  12. com.techstar.monitordemo.controller.UserController,arg1

拦截构造函数

构造函数

  1. @Data

  2. public class User {

  3. private int id;

  4. private String name;

  5. }

control方法

  1. @GetMapping(value = "/arg2")

  2. public User arg2(User user) {

  3. return user;

  4. }

BTrace脚本

  1. /**

  2. * 拦截构造函数

  3. */

  4. @BTrace

  5. public class PrintConstructor {

  6. @OnMethod(clazz = "com.techstar.monitordemo.domain.User", method = "<init>")

  7. public static void anyRead(@ProbeClassName String pcn, @ProbeMethodName String pmn, AnyType[] args) {

  8. BTraceUtils.println(pcn + "," + pmn);

  9. BTraceUtils.printArray(args);

  10. BTraceUtils.println();

  11. }

  12. }

拦截结果

  1. 192:Btrace apple$ btrace 34119 PrintConstructor.java

  2. com.techstar.monitordemo.domain.User,<init>

  3. [1, zuozewei, ]

拦截同名函数,以参数区分

control方法

  1. @GetMapping(value = "/same1")

  2. public String same(@RequestParam("name") String name) {

  3. return "7DGroup," + name;

  4. }

  5. @GetMapping(value = "/same2")

  6. public String same(@RequestParam("id") int id, @RequestParam("name") String name) {

  7. return "7DGroup," + name + "," + id;

  8. }

BTrace脚本

  1. /**

  2. * 拦截同名函数,通过输入的参数区分

  3. */

  4. @BTrace

  5. public class PrintSame {

  6. @OnMethod(clazz = "com.techstar.monitordemo.controller.UserController", method = "same")

  7. public static void anyRead(@ProbeClassName String pcn, @ProbeMethodName String pmn, String name) {

  8. BTraceUtils.println(pcn + "," + pmn + "," + name);

  9. BTraceUtils.println();

  10. }

  11. }

拦截结果

  1. 192:Btrace apple$ jps -l

  2. 369

  3. 5889 /Users/apple/Downloads/performance/apache-jmeter-4.0/bin/ApacheJMeter.jar

  4. 34281 sun.tools.jps.Jps

  5. 34220 org.jetbrains.jps.cmdline.Launcher

  6. 34221 com.techstar.monitordemo.MonitordemoApplication

  7. 192:Btrace apple$ btrace 34221 PrintSame.java

  8. com.techstar.monitordemo.controller.UserController,same,zuozewei

  9. com.techstar.monitordemo.controller.UserController,same,zuozewei

  10. com.techstar.monitordemo.controller.UserController,same,zuozewei

拦截方法返回值

BTrace脚本

  1. /**

  2. * 拦截返回值

  3. */

  4. @BTrace

  5. public class PrintReturn {

  6. @OnMethod(clazz = "com.techstar.monitordemo.controller.UserController", method = "arg1",

  7. //拦截时刻:返回值

  8. location = @Location(Kind.RETURN))

  9. public static void anyRead(@ProbeClassName String pcn, @ProbeMethodName String pmn, @Return AnyType result) {

  10. BTraceUtils.println(pcn + "," + pmn + "," + result);

  11. BTraceUtils.println();

  12. }

  13. }

拦截结果

  1. 192:Btrace apple$ jps -l

  2. 34528 org.jetbrains.jps.cmdline.Launcher

  3. 34529 com.techstar.monitordemo.MonitordemoApplication

  4. 369

  5. 5889 /Users/apple/Downloads/performance/apache-jmeter-4.0/bin/ApacheJMeter.jar

  6. 34533 sun.tools.jps.Jps

  7. 192:Btrace apple$ btrace 34529 PrintReturn.java

  8. com.techstar.monitordemo.controller.UserController,arg1,7DGroup,zuozewei

异常分析

有时候开发人员对异常处理不合理,导致某些重要异常人为被吃掉,并且没有日志或者日志不详细,导致性能分析定位问题困难,我们可以使用BTrace来处理

control方法

  1. @GetMapping(value = "/exception")

  2. public String exception() {

  3. try {

  4. System.out.println("start...");

  5. System.out.println(1 / 0); //模拟异常

  6. System.out.println("end...");

  7. } catch (Exception e) {}

  8. return "successful...";

  9. }

BTrace脚本

  1. /**

  2. * 有时候,有些异常被人为吃掉,日志又没有打印,这个时候可以用该类定位问题

  3. * This example demonstrates printing stack trace

  4. * of an exception and thread local variables. This

  5. * trace script prints exception stack trace whenever

  6. * java.lang.Throwable's constructor returns. This way

  7. * you can trace all exceptions that may be caught and

  8. * "eaten" silently by the traced program. Note that the

  9. * assumption is that the exceptions are thrown soon after

  10. * creation [like in "throw new FooException();"] rather

  11. * that be stored and thrown later.

  12. */

  13. @BTrace

  14. public class PrintOnThrow {

  15. // store current exception in a thread local

  16. // variable (@TLS annotation). Note that we can't

  17. // store it in a global variable!

  18. @TLS

  19. static Throwable currentException;

  20. // introduce probe into every constructor of java.lang.Throwable

  21. // class and store "this" in the thread local variable.

  22. @OnMethod(clazz = "java.lang.Throwable", method = "<init>")

  23. public static void onthrow(@Self Throwable self) {

  24. currentException = self;

  25. }

  26. @OnMethod(clazz = "java.lang.Throwable", method = "<init>")

  27. public static void onthrow1(@Self Throwable self, String s) {

  28. currentException = self;

  29. }

  30. @OnMethod(clazz = "java.lang.Throwable", method = "<init>")

  31. public static void onthrow1(@Self Throwable self, String s, Throwable cause) {

  32. currentException = self;

  33. }

  34. @OnMethod(clazz = "java.lang.Throwable", method = "<init>")

  35. public static void onthrow2(@Self Throwable self, Throwable cause) {

  36. currentException = self;

  37. }

  38. // when any constructor of java.lang.Throwable returns

  39. // print the currentException's stack trace.

  40. @OnMethod(clazz = "java.lang.Throwable", method = "<init>", location = @Location(Kind.RETURN))

  41. public static void onthrowreturn() {

  42. if (currentException != null) {

  43. Threads.jstack(currentException);

  44. BTraceUtils.println("=====================");

  45. currentException = null;

  46. }

  47. }

  48. }

拦截结果

  1. 192:Btrace apple$ jps -l

  2. 369

  3. 5889 /Users/apple/Downloads/performance/apache-jmeter-4.0/bin/ApacheJMeter.jar

  4. 34727 sun.tools.jps.Jps

  5. 34666 org.jetbrains.jps.cmdline.Launcher

  6. 34667 com.techstar.monitordemo.MonitordemoApplication

  7. 192:Btrace apple$ btrace 34667 PrintOnThrow.java

  8. java.lang.ClassNotFoundException: org.apache.catalina.webresources.WarResourceSet

  9. java.net.URLClassLoader.findClass(URLClassLoader.java:381)

  10. java.lang.ClassLoader.loadClass(ClassLoader.java:424)

  11. java.lang.ClassLoader.loadClass(ClassLoader.java:411)

  12. sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:349)

  13. java.lang.ClassLoader.loadClass(ClassLoader.java:357)

  14. org.apache.catalina.webresources.StandardRoot.isPackedWarFile(StandardRoot.java:656)

  15. org.apache.catalina.webresources.CachedResource.validateResource(CachedResource.java:109)

  16. org.apache.catalina.webresources.Cache.getResource(Cache.java:69)

  17. org.apache.catalina.webresources.StandardRoot.getResource(StandardRoot.java:216)

  18. org.apache.catalina.webresources.StandardRoot.getResource(StandardRoot.java:206)

  19. org.apache.catalina.mapper.Mapper.internalMapWrapper(Mapper.java:1027)

  20. org.apache.catalina.mapper.Mapper.internalMap(Mapper.java:842)

  21. org.apache.catalina.mapper.Mapper.map(Mapper.java:698)

  22. org.apache.catalina.connector.CoyoteAdapter.postParseRequest(CoyoteAdapter.java:679)

  23. org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:336)

  24. org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:800)

  25. org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)

  26. org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:800)

  27. org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1471)

  28. org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)

  29. java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

  30. java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

  31. org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)

  32. java.lang.Thread.run(Thread.java:748)

  33. =====================

  34. ...

定位某个超过阈值的函数

BTrace脚本

  1. **

  2. * 探测某个包路径下的方法执行时间是否超过某个阈值的程序,如果超过了该阀值,则打印当前线程的栈信息。

  3. */

  4. import com.sun.btrace.BTraceUtils;

  5. import com.sun.btrace.annotations.*;

  6. import static com.sun.btrace.BTraceUtils.*;

  7. @BTrace

  8. public class PrintDurationTracer {

  9. @OnMethod(clazz = "/com\\.techstar\\.monitordemo\\..*/", method = "/.*/", location = @Location(Kind.RETURN))

  10. public static void trace(@ProbeClassName String pcn, @ProbeMethodName String pmn, @Duration long duration) {

  11. //duration的单位是纳秒

  12. if (duration > 1000 * 1000 * 2) {

  13. BTraceUtils.println(Strings.strcat(Strings.strcat(pcn, "."), pmn));

  14. BTraceUtils.print(" 耗时:");

  15. BTraceUtils.print(duration);

  16. BTraceUtils.println("纳秒,堆栈信息如下");

  17. jstack();

  18. }

  19. }

  20. }

拦截结果

  1. 192:Btrace apple$ btrace 39644 PrintDurationTracer.java

  2. com.techstar.monitordemo.controller.Adder.execute 耗时:1715294657纳秒,堆栈信息如下

  3. com.techstar.monitordemo.controller.Adder.execute(Adder.java:13)

  4. com.techstar.monitordemo.controller.Main.main(Main.java:10)

  5. com.techstar.monitordemo.controller.Adder.execute 耗时:893795666纳秒,堆栈信息如下

  6. com.techstar.monitordemo.controller.Adder.execute(Adder.java:13)

  7. com.techstar.monitordemo.controller.Main.main(Main.java:10)

  8. com.techstar.monitordemo.controller.Adder.execute 耗时:1331363658纳秒,堆栈信息如下

  9. com.techstar.monitordemo.controller.Adder.execute(Adder.java:13)

追踪方法执行时间

BTrace脚本

  1. /**

  2. * 追踪某个方法的执行时间,实现原理同AOP一样。

  3. */

  4. @BTrace

  5. public class PrintExecuteTimeTracer {

  6. @TLS

  7. static long beginTime;

  8. @OnMethod(clazz = "com.techstar.monitordemo.controller.Adder", method = "execute")

  9. public static void traceExecuteBegin() {

  10. beginTime = timeMillis();

  11. }

  12. @OnMethod(clazz = "com.techstar.monitordemo.controller.Adder", method = "execute", location = @Location(Kind.RETURN))

  13. public static void traceExecute(int arg1, int arg2, @Return int result) {

  14. BTraceUtils.println(strcat(strcat("Adder.execute 耗时:", str(timeMillis() - beginTime)), "ms"));

  15. BTraceUtils.println(strcat("返回结果为:", str(result)));

  16. }

  17. }

拦截结果

  1. 192:Btrace apple$ btrace 40863 PrintExecuteTimeTracer.java

  2. Adder.execute 耗时:803ms

  3. 返回结果为:797

  4. Adder.execute 耗时:1266ms

  5. 返回结果为:1261

  6. Adder.execute 耗时:788ms

  7. 返回结果为:784

  8. Adder.execute 耗时:1524ms

  9. 返回结果为:1521

  10. Adder.execute 耗时:1775ms

性能分析

压测的时候经常发现某一个服务变慢了,但是由于这个服务有很多的业务逻辑和方法构成,这个时候就不好定位到底慢在哪个地方。BTrace可以解决这个问题,只需要大概定位问题可能存在的地方,通过包路径模糊匹配,就可以找到问题。

BTrace脚本

  1. /**

  2. *

  3. * Description:

  4. * This script demonstrates new capabilities built into BTrace 1.2

  5. * Shortened syntax - when omitting "public" identifier in the class

  6. * definition one can safely omit all other modifiers when declaring methods

  7. * and variables

  8. * Extended syntax for @ProbeMethodName annotation - you can use

  9. * parameter to request a fully qualified method name instead of

  10. * the short one

  11. * Profiling support - you can use {@linkplain Profiler} instance to gather

  12. * performance data with the smallest overhead possible

  13. */

  14. @BTrace

  15. class Profiling {

  16. @Property

  17. Profiler profiler = BTraceUtils.Profiling.newProfiler();

  18. @OnMethod(clazz = "/com\\.techstar\\..*/", method = "/.*/")

  19. void entry(@ProbeMethodName(fqn = true) String probeMethod) {

  20. BTraceUtils.Profiling.recordEntry(profiler, probeMethod);

  21. }

  22. @OnMethod(clazz = "/com\\.techstar\\..*/", method = "/.*/", location = @Location(value = Kind.RETURN))

  23. void exit(@ProbeMethodName(fqn = true) String probeMethod, @Duration long duration) {

  24. BTraceUtils.Profiling.recordExit(profiler, probeMethod, duration);

  25. }

  26. @OnTimer(5000)

  27. void timer() {

  28. BTraceUtils.Profiling.printSnapshot("Performance profile", profiler);

  29. }

死锁排查

我们怀疑程序是否有死锁,可以通过以下的脚本扫描追踪,非常简单方便。

  1. /**

  2. * This BTrace program demonstrates deadlocks

  3. * built-in function. This example prints

  4. * deadlocks (if any) once every 4 seconds.

  5. */

  6. @BTrace

  7. public class PrintDeadlock {

  8. @OnTimer(4000)

  9. public static void print() {

  10. deadlocks();

  11. }

  12. }

小结

BTrace是一个事后工具,所谓的事后工具就是在服务已经上线或者压测后,但是发现有问题的时候,可以使用BTrace动态跟踪分析。

  1. 比如哪些方法执行太慢,例如监控方法执行时间超过1秒的方法;

  2. 查看哪些方法调用了system.gc( ),调用栈是怎样的;

  3. 查看方法的参数和属性

  4. 哪些方法发生了异常

  5. .....

总之,这里只是将部分经常用的列举了下抛砖引玉,还有很多没有列举,大家可以参考官方的其他Sample去玩下。

评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值