Technical Articles
Brief introduction to BTrace – a very useful dynamic tracing tool
What’s BTrace
For the issue tracking of the dev environment of java program, we can debug and get information from IDE debugger in the local environment, but if this happens in the production / on-line environment, generally we can only get the information from the output log. Actually, in this scenario, we can use BTrace, a very useful and powerful tool to do dynamic tracing for on-line java program.
BTrace can get much more detail information inner the program based on trace script without original program stop and restart, etc. but just run the trace script independently.
Configuration
Download and config runtime
- Download BTrace distribution file from the release page
- Set the environment variable BTRACE_HOME to point to the directory containing the downloaded distribution folder
- Set the system environment PATH with $BTRACE_HOME/bin for convenience, you can verify the configuration via command “btrace –version“
Script environment configuration
Add BTrace related jar files in the pom.xml when creating BTrace script
<!--btrace start-->
<dependency>
<groupId>com.sun.tools.btrace</groupId>
<artifactId>btrace-agent</artifactId>
<version>1.3.11.3</version>
<scope>system</scope>
<systemPath>/Users/i075496/soft/btrace-bin-1.3.11.3/build/btrace-agent.jar</systemPath>
</dependency>
<dependency>
<groupId>com.sun.tools.btrace</groupId>
<artifactId>btrace-boot</artifactId>
<version>1.3.11.3</version>
<scope>system</scope>
<systemPath>/Users/i075496/soft/btrace-bin-1.3.11.3/build/btrace-boot.jar</systemPath>
</dependency>
<dependency>
<groupId>com.sun.tools.btrace</groupId>
<artifactId>btrace-client</artifactId>
<version>1.3.11.3</version>
<scope>system</scope>
<systemPath>/Users/i075496/soft/btrace-bin-1.3.11.3/build/btrace-client.jar</systemPath>
</dependency>
<!--btrace end-->
Running
- Get the running program process id (PID) via command “jps”
- Run the tracing via command: “btrace <PID> <your trace script file name here>”
Demo
Sample code of the java program to test BTrace
package com.sap.olingo.demo8.controller;
import java.util.Random;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RequestParam;
import org.springframework.web.bind.annotation.RestController;
@RestController
public class HelloController {
//This is just a sample to demo method info, performance profiling and exception trace for BTrace
@GetMapping(path="btracetest")
public String btraceTest(@RequestParam String str1, @RequestParam int int2) {
Random rd = new Random();
try {
Thread.sleep(rd.nextInt(2000) + 1000);
} catch (InterruptedException e) {
e.printStackTrace();
}
return str1 + " : " + int2;
}
}
Get the method detail information via BTrace
BTrace script
import com.sun.btrace.BTraceUtils;
import com.sun.btrace.annotations.*;
@BTrace
public class BTraceTest {
@OnMethod(clazz = "com.sap.olingo.demo8.controller.HelloController", method = "btraceTest", location = @Location(Kind.RETURN))
public static void methodDetail(@Self Object self, String str1, int int2, @Return String result, @Duration long time) {
BTraceUtils.println();
BTraceUtils.println();
BTraceUtils.println("Invoke info from method detail trace: ");
BTraceUtils.println("parameter: str1=" + str1 + ", int2=" + int2);
BTraceUtils.println("return: result=" + result);
BTraceUtils.println("cost time(ns): " + time);
BTraceUtils.println();
}
}
Tracing result
Get the performance profiling information via BTrace
BTrace script
import com.sun.btrace.BTraceUtils;
import com.sun.btrace.annotations.*;
@BTrace
public class BTraceTest {
@OnMethod(clazz = "com.sap.olingo.demo8.controller.HelloController", method="/.*/", location = @Location(Kind.RETURN))
public static void onProfiling(@ProbeClassName String className, @ProbeMethodName String methodName, @Duration long time) {
if(time / 1000000000L >= 2){
BTraceUtils.println();
BTraceUtils.println();
BTraceUtils.println("Invoke info from profiling trace: ");
BTraceUtils.println("className: " + className + ", methodName: " + methodName + ", duration: " + ((double)time) / 1000000000);
BTraceUtils.println();
}
}
}
Tracing result
Get the exception information via BTrace
BTrace script
import com.sun.btrace.BTraceUtils;
import com.sun.btrace.annotations.*;
@BTrace
public class BTraceTest {
@OnMethod(clazz="java.lang.Throwable",method="<init>",location=@Location(Kind.RETURN))
public static void excepionDetail(@Self Throwable self){
BTraceUtils.println();
BTraceUtils.println();
BTraceUtils.println("Invoke info from exception trace: ");
BTraceUtils.Threads.jstack(self);
BTraceUtils.println();
}
}
Tracing result
More Scenario
- Please refer here.
Note
- There’re some limitations in trace script for security
- Need to verify locally before do the trace in the production environment
- Please refer to the sample scripts
Conclusion
- BTrace is a very powerful and useful tool for Java.
- BTrace can be used to dynamically trace a running Java program.
- Please use it carefully and cautiously validate in the local before using it in the production environment.
Citations:
- BTrace: https://github.com/btraceio
- BTrace sample scripts: https://github.com/btraceio/btrace/tree/master/samples
Great post!
Dear George Liu,
Do you know how we can save the log/traces results to a file when use this command: “btrace <PID> <your trace script file name here>”
Because it is printed on the console and when I execute many traces the console rewrites the existing ones.
Thanks in advance.
Hi Gabriela Michelon
Sorry for my late response, you can try this way to store the log and view it:
btrace <PID> <you trace script file> > trace.log &
I've tried and seems it works.
Thanks,
Best regards,
George
SAP IBSO(Innovative Business Solutions) Chengdu, China
Thank you so much!
It works.
Best Regards,
Gabriela
Dear George Liu,
Have you ever got the time of executing method is 0?
I am really sure that duration of my method not 0, but I don't know what reason for that btrace result .