btrace didn't print out anything when the specified method is invoked

Question

I'm learning how to use btrace. In order to do that, I created a spring-boot project which contained the following code.

@Controller
public class MainController {
    private static Logger logger = LoggerFactory.getLogger(MainController.class);
    @ResponseBody
    @GetMapping("/testFile")
    public Map<String, Object> testFile() throws IOException {
        File file = new File("/tmp/a");
        if (file.exists()) {
            file.delete();
        }
        file.createNewFile();
        return ImmutableMap.of("success", true);
    }
}

Then I started the project using mvn spring-boot:run, after which I wrote a btrace script, as follows.

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

@BTrace
public class HelloWorld {

    @OnMethod(clazz = "java.io.File", method = "createNewFile")
    public static void onNewFileCreated(String fileName) {
        BTraceUtils.println("New file is being created");
        BTraceUtils.println(fileName);
    }
}

As you can see, this script should print something when java.io.File#createNewFile is called, which is exactly what the above controller does. Then I attached btrace to the running spring-boot project using the following code.

btrace 30716 HelloWorld.java

30716 is the PID of the running spring-boot project. Then I tried accessing http://localhost:8080/testFile, and I got the following extra output from the running spring-boot project.

objc[30857]: Class JavaLaunchHelper is implemented in both /Library/Java/JavaVirtualMachines/jdk1.8.0_151.jdk/Contents/Home/bin/java (0x10e2744c0) and /Library/Java/JavaVirtualMachines/jdk1.8.0_151.jdk/Contents/Home/jre/lib/libinstrument.dylib (0x1145e24e0). One of the two will be used. Which one is undefined.
2019-01-04 11:24:49.003  INFO 30857 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
2019-01-04 11:24:49.003  INFO 30857 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2019-01-04 11:24:49.019  INFO 30857 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 16 ms

I was expecting it to output New file is being created, but it didn't. Why? Did I do something wrong?

Answer 1

Your trace method, onNewFileCreated(String fileName), cannot be used to intercept java.io.File.createNewFile() as the signatures don't agree (createNewFile() doesn't take any arguments, while onNewFileCreated() has one). If there are arguments in the trace method (unless they have a BTrace annotation), BTrace will attempt to "bind" them to the arguments in the intercepted method. If it can't do so, it will not successfully intercept that method.

Try

@OnMethod(clazz = "java.io.File", method = "createNewFile")
public static void onNewFileCreated() {
    BTraceUtils.println("method createNewFile called");
}

or

@OnMethod(clazz = "java.io.File", method = "createNewFile")
public static void onNewFileCreated(@ProbeMethodName String methodName) {
    BTraceUtils.println("method " + methodName + " called");
}

Update 1:

First, what version of the JDK are you using? BTrace doesn't appear to support JDK > 8 (https://github.com/btraceio/btrace/issues/292).

Second, can you try running this tracing script:

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

@BTrace
public class TracingScript {
    @OnMethod(clazz = "java.io.File", method = "createNewFile")
    public static void onNewFileCreated(@ProbeMethodName String methodName) {
        BTraceUtils.println("method " + methodName + " called");
    }
}

against a simple test application:

import java.io.File;

public class FileCreator {

    public static void main(String[] args) throws Exception{
        for(int i = 0; i < 250; i++) {
            File file = new File("C://Temp//file" + i);
            if (file.exists()) {
                file.delete();
            }
            file.createNewFile();
            Thread.sleep(10000);
        }
    }
}

This works for me with BTrace 1.3.11.3 (and via the BTrace Workbench JVisualVM Plugin 0.6.8, which is where I usually use BTrace).