BTrace使用

清疚 2021-09-15 08:54 332阅读 0赞

一、背景

在生产环境中可能经常遇到各种问题，定位问题需要获取程序运行时的数据信息，如方法参数、返回值、全局变量、堆栈信息等。为了获取这些数据信息，我们可以通过改写代码，增加日志信息的打印，再发布到生产环境。通过这种方式，一方面将增大定位问题的成本和周期，对于紧急问题无法做到及时响应；另一方面重新部署后环境可能已被破坏，很难重新问题的场景（特别是OOM、gc这类问题短时间内无法重现）。

对于程序员来说最头大的问题之一就是线上出了故障了，但是我们无法debug来找出问题原因，同时在上线的时候日志级别限定了我们不可能把所有的细节都打印到log上，这个时候故障都等在哪里，能办的手段无非看源码，通过仔细看代码来找出问题，并编译重新上线解决，这种手段能解决一部分代码，但是对于一些隐藏较深的bug就无能为力了，例如OOM或是频繁的full gc，一般是一个很多的对象没有被释放或是一个对象被频繁的创建调用。在一个复杂的项目中，一个OOM问题可能是一个对象被频繁创建，这种方式指望通过看源码是很难解决的，但是BTrace可以迅速帮助我们定位到问题所在地。

二、介绍：

Btrace (Byte Trace)是sun推出的一款java 动态、安全追踪（监控）工具，可以不停机的情况下监控线上情况，并且做到最少的侵入，占用最少的系统资源。 它可以动态地跟踪java运行程序。通过hotswap技术，动态将跟踪字节码注入到运行类中，对运行代码侵入较小，对性能上的影响可以忽略不计。

BTrace在使用上有很多限制条件，具体限制条件参考用户文档中的BTrace Restrictions。用户文档地址: http://kenai.com/projects/btrace/pages/UserGuide：

1.  不能创建对象
2.  不能抛出或者捕获异常
3.  不能用synchronized关键字
4.  不能对目标程序中的instace或者static变量
5.  不能调用目标程序的instance或者static方法
6.  脚本的field、method都必须是static的
7.  脚本不能包括outer,inner,nested class
8.  脚本中不能有循环,不能继承任何类,任何接口与assert语句

Btrace可以做什么？

1.  接口性能变慢，分析每个方法的耗时情况；
2.  当在Map中插入大量数据，分析其扩容情况；
3.  分析哪个方法调用了System.gc()，调用栈如何；
4.  执行某个方法抛出异常时，分析运行时参数；
5.  ....

根据官方声明，不当地使用btrace可能导致jvm崩溃，如BTrace使用错误的.class文件，Hotspot JVM自身存在的hotswap bug等。可以先在本地验证BTrace脚本的正确性，再传到生产环境中定位问题。

1、BTrace有两种用法：一种做为jvisualvm中插件的方式使用（见：https://blog.csdn.net/liuxiao723846/article/details/80171461），另一种为单独使用btrace二进制分发包的方式（本文重点介绍）。

2、BTrace官网（[https://kenai.com/projects/btrace/][https_kenai.com_projects_btrace]）已经关闭了，单独使用BTrace可以访问： github: https://github.com/btraceio/btrace

3、**btrace代码自动生成**：https://btrace.org/btrace/

4、一个简单的例子，介绍如何在本地运行btrace程序：

1）下载btrace：https://github.com/btraceio/btrace/releases/ 或者 https://download.csdn.net/download/liuxiao723846/10389507

2）配置环境变量：

3）编写测试代码：

package test;
    
    import java.io.BufferedReader;
    import java.io.IOException;
    import java.io.InputStreamReader;
    
    public class BTraceTest {
    	public int add(int a, int b) {  
            return a + b;  
        }  
        public void run(){  
            int a = (int) (Math.random() * 1000);  
            int b = (int) (Math.random() * 1000);  
            System.out.println(add(a, b));  
        }  
        public static void main(String[] args) throws IOException {  
            BufferedReader bReader = new BufferedReader(new InputStreamReader(System.in));  
            BTraceTest bTraceTest=new BTraceTest();  
            bReader.readLine();  
            for (int i = 0; i < 10; i++) {  
                bTraceTest.run();  
            }  
        }  
    }

4）编写btrace脚本：

/* BTrace Script Template */
    import com.sun.btrace.annotations.*;
    import static com.sun.btrace.BTraceUtils.*;
    
    @BTrace
    public class TracingScript {
    	/* put your code here */
    
        @OnMethod(
            clazz="test.BTraceTest",
            method="add",
            location=@Location(Kind.RETURN)
        )
        public static void func(int a,int b,@Return int result){
            println("调用堆栈");    
            jstack();
            println(strcat("方法参数A：",str(a)));
            println(strcat("方法参数B：",str(b)));
            println(strcat("方法结果：",str(result)));
            
        }
    }

5）先运行测试代码，然后jps找到pid，接下来在控制台启动btrace脚本：

![20180503154046353][]

三、说明：

1、BTrace主要包含btracec和btrace两个命令编译和启动BTrace脚本:   
1.）btrace   
功能: 用于运行BTrace跟踪程序。   
命令格式:   
btrace \[-I <include-path>\] \[-p <port>\] \[-cp <classpath>\] <pid> <btrace-script> \[<args>\]   
示例:   
btrace -cp build/  1200 AllCalls1.java   
参数含义:   
include-path指定头文件的路径，用于脚本预处理功能，可选；   
port指定BTrace agent的服务端监听端口号，用来监听clients，默认为2020，可选；   
classpath用来指定类加载路径，默认为当前路径，可选；   
pid表示进程号，可通过jps命令获取；   
btrace-script即为BTrace脚本；btrace脚本如果以.java结尾，会先编译再提交执行。可使用btracec命令对脚本进行预编译。   
args是BTrace脚本可选参数，在脚本中可通过"$"和"$length"获取参数信息。   
2） btracec   
功能: 用于预编译BTrace脚本，用于在编译时期验证脚本正确性。   
btracec \[-I <include-path>\] \[-cp <classpath>\] \[-d <directory>\] <one-or-more-BTrace-.java-files>   
参数意义同btrace命令一致，directory表示编译结果输出目录。   
3） btracer   
功能: btracer命令同时启动应用程序和BTrace脚本，即在应用程序启动过程中使用BTrace脚本。而btrace命令针对已运行程序执行BTrace脚本。   
命令格式:   
btracer <pre-compiled-btrace.class> <application-main-class> <application-args>   
参数说明:   
pre-compiled-btrace.class表示经过btracec编译后的BTrace脚本。   
application-main-class表示应用程序代码；   
application-args表示应用程序参数。   
该命令的等价写法为:   
java -javaagent:btrace-agent.jar=script=<pre-compiled-btrace-script1>\[,<pre-compiled-btrace-script1>\]\* <MainClass> <AppArguments>

2、Btrace的一些概念：

1）方法上的注解   
@ OnMethod  用来指定trace的目标类和方法以及具体位置, 被注解的方法在匹配的方法执行到指定的位置会被调用。  
1、"clazz"属性用来指定目标类名, 可以指定全限定类名, 比如"java.awt.Component", 也可以是正则表达式(表达式必须写在"//"中, 比如"/java\\\\.awt\\\\..+/")。  
2、"method"属性用来指定被trace的方法. 表达式可以参考自带的例子(NewComponent.java 和Classload.java, 关于方法的注解可以参考MultiClass.java)。  
3、有时候被trace的类和方法可能也使用了注解. 用法参考自带例子WebServiceTracker.java。  
4、针对注解也是可以使用正则表达式, 比如像这个"@/com\\\\.acme\\\\..+/ "，也可以通过指定超类来匹配多个类, 比如"+java.lang.Runnable"可以匹配所有实现了java.lang.Runnable接口的类. 具体参考自带例子SubtypeTracer.java。  
@OnTimer定时触发Trace，时间可以指定，单位为毫秒，具体参考自带例子 Histogram.java。  
@OnError 当trace代码抛异常或者错误时，该注解的方法会被执行. 如果同一个trace脚本中其他方法抛异常, 该注解方法也会被执行。  
@OnExit 当trace方法调用内置exit(int)方法(用来结束整个trace程序)时, 该注解的方法会被执行. 参考自带例子ProbeExit.java。  
@OnEvent 用来截获"外部"btrace client触发的事件, 比如按Ctrl-C 中断btrace执行时，并且选择2，或者输入事件名称，将执行使用了该注解的方法, 该注解的value值为具体事件名称。具体参考例子HistoOnEvent.java  
@OnLowMemory 当内存超过某个设定值将触发该注解的方法, 具体参考MemAlerter.java

@OnProbe 使用外部文件XML来定义trace方法以及具体的位置，具体参考示例SocketTracker1.java和java.net.socket.xml。

2）参数上的注解

@Self 用来指定被trace方法的this，可参考例子AWTEventTracer.java 和 AllCalls1.java  
@Return 用来指定被trace方法的返回值，可参考例子Classload.java  
@ProbeClassName (since 1.1) 用来指定被trace的类名, 可参考例子AllMethods.java  
@ProbeMethodName (since 1.1) 用来指定被trace的方法名, 可参考例子WebServiceTracker.java。  
@TargetInstance (since 1.1) 用来指定被trace方法内部被调用到的实例, 可参考例子AllCalls2.java

@TargetMethodOrField (since 1.1) 用来指定被trace方法内部被调用的方法名, 可参考例子AllCalls1.java 和AllCalls2.java。

3）非注解的方法参数

未使用注解的方法参数一般都是用来做方法签名匹配用的, 他们一般和被trace方法中参数出现的顺序一致. 不过他们也可以与注解方法交错使用, 如果一个参数类型声明为\*AnyType\[\]\*, 则表明它按顺序"通吃"方法所有参数. 未注解方法需要与\*Location\*结合使用:   
Kind.ENTRY-被trace方法参数  
Kind.RETURN- 被trace方法返回值  
Kind.THROW - 抛异常  
Kind.ARRAY\_SET, Kind.ARRAY\_GET - 数组索引  
Kind.CATCH - 捕获异常  
Kind.FIELD\_SET - 属性值  
Kind.LINE - 行号  
Kind.NEW - 类名

Kind.ERROR - 抛异常

4）属性上的注解

@Export 该注解的静态属性主要用来与jvmstat计数器做关联， 使用该注解之后，btrace程序就可以向jvmstat客户端(可以用来统计jvm堆中的内存使用量)暴露trace程序的执行次数， 具体可参考例子ThreadCounter.java。  
@Property 使用了该注解的trace脚本将作为MBean的一个属性，一旦使用该注解， trace脚本就会创建一个MBean并向MBean服务器注册， 这样JMX客户端比如VisualVM， jconsole就可以看到这些BTrace MBean， 如果这些被注解的属性与被trace程序的属性关联， 那么就可以通过VisualVM 和jconsole来查看这些属性了， 具体可参考例子ThreadCounterBean.java 和HistogramBean.java。

@TLS 用来将一个脚本变量与一个ThreadLocal变量关联， 因为ThreadLocal变量是跟线程相关的， 一般用来检查在同一个线程调用中是否执行到了被trace的方法， 具体可参考例子OnThrow.java 和 WebServiceTracker.java。

5）类上的注解

@com.sun.btrace.annotations.DTrace 用来指定btrace脚本与内置在其脚本中的D语言脚本关联， 具体参考例子DTraceInline.java。  
@com.sun.btrace.annotations.DTraceRef 用来指定btrace脚本与另一个D语言脚本文件关联， 具体参考例子DTraceRefDemo.java。  
@com.sun.btrace.annotations.BTrace 用来指定该java类为一个btrace脚本文件。

3、实战：

下载的btrace下sample文件中有很多实例可以参考。下面是一些典型的实例。

1）示例代码定义了Counter计数器，有一个add()方法，每次增加随机值，总数保存在totalCount属性中。

package com.learnworld;  
    import java.util.Random;  
      
    public class BTraceTest {  
      
        public static void main(String[] args) throws Exception {  
            Random random = new Random();  
      
            // 计数器  
            Counter counter = new Counter();  
            while (true) {  
                // 每次增加随机值  
                counter.add(random.nextInt(10));  
                Thread.sleep(1000);  
            }  
        }  
    }

package com.learnworld;  
    public class Counter {  
        // 总数  
        private static int totalCount = 0;  
      
        public int add(int num) throws Exception {  
            totalCount += num;  
            sleep();  
            return totalCount;  
        }  
          
        public void sleep() throws Exception {  
            Thread.sleep(1000);  
        }  
      
    }

常见的使用场景

2）获取add()方法参数值和返回值。

import com.sun.btrace.annotations.*;  
    import static com.sun.btrace.BTraceUtils.*;  
      
    @BTrace  
    public class TracingScript {  
       @OnMethod(  
          clazz="com.learnworld.Counter",  
          method="add",  
          location=@Location(Kind.RETURN)  
       )  
       public static void traceExecute(int num,@Return int result){  
         println("====== ");  
         println(strcat("parameter num: ",str(num)));  
         println(strcat("return value:",str(result)));  
       }  
    }

3）定时获取Counter属性值totalCount

import com.sun.btrace.annotations.*;  
    import static com.sun.btrace.BTraceUtils.*;  
      
    @BTrace  
    public class TracingScript {  
       private static Object totalCount = 0;  
         
       @OnMethod(  
          clazz="com.learnworld.Counter",  
          method="add",  
          location=@Location(Kind.RETURN)  
       )   
       public static void traceExecute(@Self com.learnworld.Counter counter){  
         totalCount = get(field("com.learnworld.Counter","totalCount"), counter);  
       }   
          
       @OnTimer(1000)  
       public static void print(){  
         println("====== ");  
         println(strcat("totalCount: ",str(totalCount)));  
       }

4）获取add方法执行时间

import com.sun.btrace.annotations.*;  
    import static com.sun.btrace.BTraceUtils.*;  
      
    @BTrace  
    public class TracingScript {  
       @TLS private static long startTime = 0;  
         
       @OnMethod(  
          clazz="com.learnworld.Counter",  
          method="add"  
       )   
       public static void startExecute(){  
         startTime = timeNanos();  
       }   
          
       @OnMethod(  
          clazz="com.learnworld.Counter",  
          method="add",  
          location=@Location(Kind.RETURN)  
       )   
       public static void endExecute(@Duration long duration){  
         long time = timeNanos() - startTime;  
         println(strcat("execute time(nanos): ", str(time)));  
         println(strcat("duration(nanos): ", str(duration)));  
       }   
    }

5）add方法调用sleep次数：

import com.sun.btrace.annotations.*;  
    import static com.sun.btrace.BTraceUtils.*;  
      
    @BTrace  
    public class TracingScript {  
       private static long count;   
           
       @OnMethod(  
          clazz="/.*/",  
          method="add",  
          location=@Location(value=Kind.CALL, clazz="/.*/", method="sleep")  
       )  
       public static void traceExecute(@ProbeClassName String pcm, @ProbeMethodName String pmn,  
       @TargetInstance Object instance,  @TargetMethodOrField String method){  
         println("====== ");  
         println(strcat("ProbeClassName: ",pcm));  
         println(strcat("ProbeMethodName: ",pmn));  
         println(strcat("TargetInstance: ",str(classOf(instance))));  
         println(strcat("TargetMethodOrField : ",str(method)));  
         count++;  
       }  
         
       @OnEvent  
       public static void getCount(){  
           println(strcat("count: ", str(count)));  
       }  
    }

还有一些其他的使用常见，例如：

1）看谁调用了gc：

import com.sun.btrace.annotations.\*;
    import static com.sun.btrace.BTraceUtils.\*;
    
    @OnMethod$clazz = "java.lang.System", method = "gc"$
    public static void onSystemGC {
        println$"entered System.gc\($"\);
        jstack;// print the stack info.
    }

2）监控代码是否到达了某类的某一行

import com.sun.btrace.annotations.\*;
    import static com.sun.btrace.BTraceUtils.\*;
    
    @OnMethod$clazz = "java.net.ServerSocket", location = @Location\(value = Kind.LINE, line = 363$\)
    public static void onBind4 {
       println$"socket bind reach line:363"$;
    }

这里是监控代码是否到达了 Stock类的 363 行。

3）按照父类、接口监控方法的执行

import com.sun.btrace.annotations.\*;
    import static com.sun.btrace.BTraceUtils.\*;
    
    @BTrace
    public class InterfaceMonitor{
        //监控某一个方法的执行时间
        @OnMethod$clazz = "+com.joson.btrace.service.BtraceService",method = "getCount",location=@Location\(Kind.RETURN$\)
        public static void printMethodRunTime$@ProbeClassName String probeClassName,@Duration long duration${
            println$probeClassName + ",cost time:" + duration / 1000000 + " ms"$;
        }
    }

这里是监控 BtraceService 接口的所有实现类中 对 getCount 方法的调用情况。

4）监控指定函数中所有外部调用的耗时情况.PS:这里最好只监控一个函数 太多的话 性能没法看

import com.sun.btrace.annotations.\*;
    import static com.sun.btrace.BTraceUtils.\*;
    @BTrace
    public class CheckOnlineStatus{
        //监控某一个方法的执行时间
        @OnMethod$clazz = "com.joson.btrace.service.impl.BtraceServiceImpl",method = "getCount",
        location=@Location\(value=Kind.CALL,clazz="/.\*/",method="/.\*/",where = Where.AFTER$\)
        public static void printMethodRunTime$@Self Object self,@TargetInstance Object instance,@TargetMethodOrField String methon,@Duration long duration${
            if$ duration > 5000000 ${//如果耗时大于 5 毫秒则打印出来 这个条件建议加 否则打印的调用函数太多 具体数值可以自己调控
                println$methon + ",cost:" + duration / 1000000 + " ms"$;
            }
        }
    }

这里是监控 BtraceServiceImpl 类中 getCount 方法内的外部方法调用情况并打印出响应时间大于 5 MS 的外部调用方法名 。通过注入 @TargetInstance 和 @TargetMethodOrField 参数，告诉脚本实际匹配到的外部函数调用的类及方法名\$或属性名\$

5）正则表达式定位监控

import com.sun.btrace.annotations.\*;
    import static com.sun.btrace.BTraceUtils.\*;
    
    @BTrace
    public class ServiceMonitor{
        //监控某一个方法的执行时间
        @OnMethod$clazz = "/com.joson.btrace.service.\*/",method = "/.\*/",location=@Location\(Kind.RETURN$\)
        public static void printMethodRunTime$@ProbeClassName String probeClassName,@ProbeMethodName String probeMethod,@Duration long duration${
            println$ probeClassName + "." + probeMethod + " cost time: " + duration / 1000000 + " ms."$;
        }
    }

通过正则表达式可以实现批量定位，正则表达式需要写在两个 "/" 中间。PS:建议正则表达式的范围要尽可能的小，不然会非常慢。这里是监控 com.joson.btrace.service 包下的所有类与方法，并打印其调用时间 以 MS 为单位。通过在函数里注入 @ProbeClassName,@ProbeMethodName 参数，告诉脚本实际匹配到的类和方法名。

其他：

1、btrace监控map扩容情况：[https://yq.aliyun.com/articles/7569][https_yq.aliyun.com_articles_7569]

2、BTrace注解：[https://github.com/btraceio/btrace/wiki/BTrace-Annotations?spm=5176.100239.blogcont7569.22.IB84VP][https_github.com_btraceio_btrace_wiki_BTrace-Annotations_spm_5176.100239.blogcont7569.22.IB84VP]

3、参考：

[https://github.com/btraceio/btrace/tree/master/samples][https_github.com_btraceio_btrace_tree_master_samples]

[https_kenai.com_projects_btrace]: https://kenai.com/projects/btrace/?spm=a2c4e.11153940.blogcont7569.10.3d5955c8oyeWo6
[20180503154046353]: /images/20210511/4abdf8ef9dee4e59a2dac0b0427ddc58.png
[https_yq.aliyun.com_articles_7569]: https://yq.aliyun.com/articles/7569
[https_github.com_btraceio_btrace_wiki_BTrace-Annotations_spm_5176.100239.blogcont7569.22.IB84VP]: https://github.com/btraceio/btrace/wiki/BTrace-Annotations?spm=5176.100239.blogcont7569.22.IB84VP
[https_github.com_btraceio_btrace_tree_master_samples]: https://github.com/btraceio/btrace/tree/master/samples