Btrace、DTrace实战之Btrace

Btrace及Dtrace实战之BTRACE

 

最早接触的是btrace，那会在2010年就听说了，后来又听说了Dtrace，今天放假回来就总结总结这两个线上调试利器。

源码下载地址是：http://kenai.com/projects/btrace/downloads 看主页上的最近更新时间都是2年前了，release的更新更是在三年前，好东西虽然不常更新，但确经久待用。在iteye上搜索可下btrace，发现几篇老东家同事写的：

http://www.iteye.com/topic/1005918

http://www.iteye.com/topic/586630

都写的很好，从实现原理到代码级别的解读，我这里就不做重复的事情了，只写点自己的感受！

 

 

tips:

源码是通过，Mercurial管理的

下载代码：hg clone https://hg.kenai.com/hg/btrace~hg  

 

它干什么的？

对于程序员来说最头大的问题之一就是线上出了故障了，但是我们无法debug来找出问题原因，同时在上线的时候日志级别限定了我们不可能把所有的细节都打印到log上，这个时候故障都等在哪里，能办的手段无非看源码，通过仔细看代码来找出问题，并编译重新上线解决，这种手段能解决一部分代码，但是对于一些隐藏较深的bug就无能为力了，例如OOM或是频繁的full gc，一般是一个很多的对象没有被释放或是一个对象被频繁的创建调用，若是大对象的问题还好说，通过jmap+MAT都可以找出，若是后者的话，就够你头大的了，笔者之前遇见一个OOM问题就是一个对象被频繁创建，最后查找时是一个开源软件包中的问题，这种方式指望通过看源码是很难解决的，那么还好有btrace脚本。

 

开始搞吧

即然上面提到了对象的调用创建，就先看看如何通过Btrace来查找一个类都被谁调用了，五步骤即可：

 

1）需要一个开始的类：

 

package com.zhaming.trace.btrace;

import java.util.Random;

public class StartObject {

    public static void main(String[] args) throws InterruptedException {

        Random random = new Random();

        ActionObject actionObject = new ActionObject();
        while (true) {
            int sleepTime = random.nextInt(1000);
            actionObject.work(sleepTime);
            Thread.sleep(1000);
        }
    }
}

 

 

2）一个被执行的类：ActionObject

 

package com.zhaming.trace.btrace;

public class ActionObject {

    private static int totalTimes = 0;

    public int work(int sleepTime) throws InterruptedException {
        System.out.println("sleep " + sleepTime);
        totalTimes += sleepTime;
        Thread.sleep(sleepTime);

        return totalTimes;
    }

}

 

 

3）查看的具体脚本：

 

package com.zhaming.trace.btrace;

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

@BTrace
public class TraceObject {

    @OnMethod(clazz = "com.zhaming.trace.btrace.ActionObject", method = "work", location = @Location(value = Kind.CALL, clazz = "/.*/", method = "/.*/"))
    public static void checkWhoCallMe() {
        println("check who ActionObject.work method:");
        jstack();
    }
}

 

 

4)通过jps命令获取进程ID：

 

inter12@inter12-VirtualBox:~/install/soft/btrace/bin$ jps 
10617 Jps
10600 StartObject
1876 org.eclipse.equinox.launcher_1.2.0.v20110502.jar

 

 

5）执行btrace脚本

 

inter12@inter12-VirtualBox:~/workspace/Light/target/classes$ btrace -cp /home/inter12/workspace/Light/target/classes  10600  /home/inter12/workspace/Light/src/main/java/com/zhaming/trace/btrace/TraceObject.java
check who ActionObject.work method:
com.zhaming.trace.btrace.ActionObject.work(ActionObject.java:9)
com.zhaming.trace.btrace.StartObject.main(StartObject.java:14)
check who ActionObject.work method:
com.zhaming.trace.btrace.ActionObject.work(ActionObject.java:9)
com.zhaming.trace.btrace.StartObject.main(StartObject.java:14)

 

 

在终端我们看到StartObject类中执行科ActionObject.work方法，如此即可找到我们想要的执行对象。

 

回到开头

现在再回过头来看看我们上面干了什么，第一到第二步都可以忽略，是为了准备测试的数据，直接看第三步骤，我们主要加了两个标注

 

@BTrace   //这里告诉btrace这是一个调试脚本 
public class TraceObject {  
		
    // // 这里说我们查看哪个类的哪个方法，最好的办法是写类名的全路径，比较存在重复类名的情况，个人实际试过，若是重复的话，会执行第一个被加载的类
    @OnMethod(clazz = "com.zhaming.trace.btrace.ActionObject", method = "work", location = @Location(value = Kind.CALL, clazz = "/.*/", method = "/.*/")) 
    public static void checkWhoCallMe() {
    
        // 对这些类的这些方法做什么操作，这里是简单的执行了jstatck命令，获取是谁调用了我那么执行的方法
        println("check who ActionObject.work method:");
        jstack();
    }
}

 

最后的命令是： btrace -cp /home/inter12/workspace/Light/target/classes  10600  /home/inter12/workspace/Light/src/main/java/com/zhaming/trace/btrace/TraceObject.java(-cp后面跟的是你代码中依赖的类)

简缩后就是 btrace -cp 【指定的类路径】 【PID】 XXX.JAVA 如此就搞定了btrace，相当的简单！还有点需要注意的话，若你下载btrace是1.2版本之前的话，那么TraceObject中的类必须是静态的static，1.2版本以后没有这个要求！

 

若是想知道 ActionObject类中totalTimes的值的话，可以写下面的脚本

 

package com.zhaming.trace.btrace;

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

@BTrace
public class TraceObjectValue {

    @OnMethod(clazz = "com.zhaming.trace.btrace.ActionObject", method = "work", location = @Location(Kind.RETURN))
    public static void getMethodValueAndReturn(@Self com.zhaming.trace.btrace.ActionObject instance ,int sleepTime,@Return int totalTime) {
        println("call ActionObject work method:");
        println(strcat("sleepTime", str(sleepTime)));
        println(strcat("return total timeL", str(get(field("com.zhaming.trace.btrace.ActionObject", "totalTimes"), instance))));
    }

}

 

 

执行脚本：

 

inter12@inter12-VirtualBox:~/workspace/Light/target/classes$ btrace -cp /home/inter12/workspace/Light/target/classes  11939 /home/inter12/workspace/Light/src/main/java/com/zhaming/trace/btrace/TraceObjectValue.java
call ActionObject work method:
sleepTime45
return total timeL11267
call ActionObject work method:
sleepTime513
return total timeL11780
call ActionObject work method:
sleepTime845

 

 

若是得到一个方法的执行时间的话，可以参见如下:

 

package com.zhaming.trace.btrace;

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

@BTrace
public class TraceObjectCost {

    @TLS
    static long startTime;

    @OnMethod(clazz = "com.zhaming.trace.btrace.ActionObject", method = "work", location = @Location(Kind.RETURN))
    public static void start() {
        startTime = timeMillis();
    }

    @OnMethod(clazz = "com.zhaming.trace.btrace.ActionObject", method = "work", location = @Location(Kind.RETURN))
    public static void getMethodExecuteCost(int sleepTime,@Return int totalTime) {
        String str = str(timeMillis() - startTime);
        String strcat = strcat("execute work method cost:", str);
        String strcat2 = strcat(strcat, " ms");
        println(strcat2);
    }
}

 

 

执行脚本：

 

inter12@inter12-VirtualBox:~/workspace/Light/target/classes$ btrace -cp /home/inter12/workspace/Light/target/classes  13191 /home/inter12/workspace/Light/src/main/java/com/zhaming/trace/btrace/TraceObjectCost.java 
execute work method cost:1357295586155 ms
execute work method cost:1410 ms
execute work method cost:1005 ms
execute work method cost:1335 ms
execute work method cost:1448 ms

 

 

 

若是期望的到一个method哪几行被执行了的话，可以试试下面的脚本：

 

package com.zhaming.trace.btrace;

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

@BTrace
public class TraceObjectMethodLineCall {
    
    @OnMethod(clazz="com.zhaming.trace.btrace.ActionObject",method="work",location=@Location(value=Kind.CALL, clazz="/.*/", method="/.*/"))
    public static void lineCall(@Self com.zhaming.trace.btrace.ActionObject self, @TargetMethodOrField String method, @ProbeMethodName String probeMethod){
        println(Strings.strcat(method, Strings.strcat(" in ", probeMethod)));
    }
}

 

 

 

TargetMethodOrField :目标对象

ProbeMethodName ：调用对象

执行脚本：

 

inter12@inter12-VirtualBox:~/workspace/Light/target/classes$ btrace -cp /home/inter12/workspace/Light/target/classes  13544 /home/inter12/workspace/Light/src/main/java/com/zhaming/trace/btrace/TraceObjectMethodLineCall.java 
append in work
toString in work
println in work
sleep in work