An Introduction to BTrace

What is BTrace?
BTrace is a safe, dynamic tracing tool for the Java platform. BTrace can be used to dynamically trace a running Java program. BTrace dynamically instruments the classes of the target application to inject tracing code ("bytecode tracing"). Tracing code is expressed in Java programming language.

BTrace is similar to DTrace for OpenSolaris applications and OS. There is also integration with DTrace for the OpenSolaris platform. Whole stack tracing (Tracing both java code and native code) is possible.

BTrace project home: http://kenai.com/projects/btrace


What can BTrace do?
BTrace probes location or event in the target application's code and execute tracing code when probe fires.

• Here's a list of btrace probe points:
• Method entry / exit
• Exception return from a method
• Line number
• Field set / get
• Method call / return
• Exception throw (before)
• Synchronization entry / exit
• Timer

BTrace define probe points by BTrace annotations. When probe fires, BTrace call the user defined tracing code which is annotated by the btrace annotations.
For example:

@OnMethod(clazz="java.lang.Thread", method="start") 

public static void threadStarted() { ... }

This code snippet tells btrace probing for Thread().start() and call threadStart() once Thread().start() is called.

What BTrace cannot do?
BTrace is designed to be safe, which prohibits arbitrary tracing code. The tracing code is written in a "safe" subset of Java language.
In general, BTrace defines safe as:

• Observe, don't "disturb"
• Read, but not "write"
• Bounded tracing actions (trace actions terminate in bounded time)

Here's a complete list of cannot btrace defined: http://kenai.com/projects/btrace/pages/UserGuide.
Let exam a few safety rules btrace defines:

• can not create new objects, new arrays. - Creating new object effectively is executing arbitrary code.
• can not throw exceptions, catch exceptions. - Obviously, the original execution flow is disturbed.
• can not have loops (for, while, do..while) - If tracing code loop forever, the thread which is being traced hangs.
• can not make arbitrary instance or static method calls - only the public static methods of com.sun.btrace.BTraceUtils class may be called from a BTrace program. - BTraceUtils code are verified to be safe and thus trusted.

In short, btrace do not allow you to execute arbitrary tracing code (it's not another AspectJ). BTrace allows to observe the application state silently.

A Simple Example:
Suppose you have a class:

class MyClass { ... }

And you want to trace the instantiation of MyClass. You can write a tracing script as:

//TracingScript.java
import com.sun.btrace.annotations.*;
import static com.sun.btrace.BTraceUtils.*;

@BTrace

public class TracingScript {
     @OnMethod(clazz="MyClass", method="<init>")

     public static void myClassCreated() {
            println("MyClass is created!"); 
     }

}

There are number of ways to inject this script to a running jvm:

• command line: btrace TracingScript.java
• visualvm: connect to the local jvm. In context menu, tracing application..., open TracingScript.java and click start.

How does BTrace work?
BTrace utilizes Sun Attach API to to attach to a target virtual machine and load a BTrace agent into that virtual machine.
Once the BTrace agent is loaded in the target jvm, it opens a server socket (default is 2020) to communicate with BTrace client.
BTrace client asks BTrace agent to attach or detach a tracing script via the server socket.
Attach/detach the tracing script is implemented byte code engineering via ObjectWeb ASM. BTrace agent registers a ClassFileTransformer
and force a retransform on attaching / detaching the tracing script, thus target class byte code gets modified or restored.

How transformer works?
Whenever a class is loaded, redefined or retransformed, jvm will send the original bytecode of the class to transform pipeline.
Each transform takes the bytecode transformed by previous transformer and apply its own transformation to the bytecode.


Now we're going to exam what happens to the byte code of MyClass mentioned before.
Here's the java code for MyClass:

class MyClass { ... }

It's a very simple class with an empty constructor and nothing else.

Before we attach the tracing script, the disassembled byte code is:

// class version 50.0 (50)
// access flags 33
public class blogspot/liulitom/btrace/demo/MyClass {

// compiled from: MyClass.java

// access flags 1
public <init>()V
 L0

  LINENUMBER 18 L0
  ALOAD 0
  INVOKESPECIAL java/lang/Object.<init> ()V

  RETURN
  MAXSTACK = 1
  MAXLOCALS = 1

}

After we attach the tracing script listed before, the disassembled byte code is:

// class version 50.0 (50)
// access flags 33
public class blogspot/liulitom/btrace/demo/MyClass {

// compiled from: MyClass.java

// access flags 1
public <init>()V
 L0

  LINENUMBER 18 L0
  ALOAD 0
  INVOKESPECIAL java/lang/Object.<init> ()V

  INVOKESTATIC blogspot/liulitom/btrace/demo/MyClass.$btrace$TracingScript$1$myClassCreated ()V

  RETURN
  MAXSTACK = 1
  MAXLOCALS = 1

// access flags 10
private static $btrace$TracingScript$1$myClassCreated()V

@Lcom/sun/btrace/annotations/OnMethod;(clazz="blogspot.liulitom.btrace.demo.MyClass", method="<init>")

  TRYCATCHBLOCK L0 L1 L1 java/lang/Throwable
  GETSTATIC TracingScript$1.runtime : Lcom/sun/btrace/BTraceRuntime;

  INVOKESTATIC com/sun/btrace/BTraceRuntime.enter (Lcom/sun/btrace/BTraceRuntime;)Z

  IFNE L0
  RETURN
 L0
  LINENUMBER 9 L0

 FRAME SAME
  LDC "MyClass is created!"
  INVOKESTATIC com/sun/btrace/BTraceUtils.println (Ljava/lang/Object;)V

 L2
  LINENUMBER 10 L2
  INVOKESTATIC com/sun/btrace/BTraceRuntime.leave ()V

  RETURN
 L1
 FRAME SAME1 java/lang/Throwable

  INVOKESTATIC com/sun/btrace/BTraceRuntime.handleException (Ljava/lang/Throwable;)V

  RETURN
  MAXSTACK = 1
  MAXLOCALS = 0

}
A rough translation from the asm to java code is:

class MyClass {
   public MyClass() {
        TracingScript.myClassCreated();
  }

  private static TracingScript {
      public static void myClassCreated() {
            BTraceRuntime.enter();

            try {
                   BTraceUtils.println("MyClass is created!");
            } catch (Throwable t) {

                   BTraceRuntime.handleException(t);
           } finally {
                BTraceRuntime.leave();

           }
     }
 }
}

After we detach the tracing script, the disassembled byte code is:

// class version 50.0 (50)
// access flags 33
public class blogspot/liulitom/btrace/demo/MyClass {

// compiled from: MyClass.java

// access flags 1
public <init>()V
 L0

  LINENUMBER 18 L0
  ALOAD 0
  INVOKESPECIAL java/lang/Object.<init> ()V

  RETURN
  MAXSTACK = 1
  MAXLOCALS = 1

}
The disassembled shows MyClass is restored correctly. (BTrace simply skips the transformation for this class which effectively "restores" the class.)

Demo project is attached.
Run blogspot.liulitom.btrace.demo.DummyApp. Connect with visualvm and invoke blogspot.liulitom.btrace.demo:type=ShowByteCode#getByteCode("blogspot.liulitom.btrace.demo.MyClass") to observe the disassembled byte code.

A Practical BTrace Example: Tracking File leak
Sometime, you may encounter "too many open files" exception. You could use "lsof" to observe what files are left open, but you have no idea in which line of code you opened these files.
The following file leak tracing script helps you to identify where each file is opened thus you can go back to you code and fix the leak quickly.

/*
* Based on BTrace example: FileTracker.java
*/

package com.sun.btrace.samples;

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

import java.io.File;
import java.io.FileInputStream;
import java.io.FileOutputStream;

/**
* This sample prints all files opened for read/write by a Java process. Note
* that if you pass FileDescriptor to File{Input/Output}Stream or
* File{Reader/Writer}, that is not tracked by this script.
*/
@BTrace
public class FileTracker {

 @TLS
 private static String name;

 @OnMethod(clazz = "java.io.FileInputStream", method = "")

 public static void onNewFileInputStream(@Self FileInputStream self, File f) {

  name = str(f);
 }

 @OnMethod(clazz = "java.io.FileInputStream", method = "", type = "void (java.io.File)", location = @Location(Kind.RETURN))

 public static void onNewFileInputStreamReturn() {
  if (name != null) {

   println(strcat("===> opened for read: ", name));
   jstack(); // PRINT THE STACK TRACE, so you know there the file named

      // "name" is opened.
   name = null;
  }

 }

 @OnMethod(clazz = "java.io.FileOutputStream", method = "")

 public static void onNewFileOutputStream(@Self FileOutputStream self,
   File f, boolean b) {

  name = str(f);
 }

 @OnMethod(clazz = "java.io.FileOutputStream", method = "", type = "void (java.io.File, boolean)", location = @Location(Kind.RETURN))

 public static void OnNewFileOutputStreamReturn() {
  if (name != null) {

   println(strcat("===> opened for write: ", name));
   jstack();

   name = null;
  }
 }
}

BTrace Limitations:

• BTrace only works sunjdk 6+.
• BTrace can only attach to local jvm because the limitation of attach api.