In the last blog entry, I talked about the need for a tool in Java that can be configured easily to log method calls without redeploying a binary, attaching a debugger, or obtaining root in order to trace system calls. In this blog, I'll dive into some of how the tool was implemented.

A caveat: I knocked this tool together in my spare time one afternoon while working on a bunch of other things, so it's a bit rough around the edges. I'm also not a particularly experienced C programmer, so apologies if my code is a bit rough.

However, it's already proven useful to me, and hopefully either the tool itself or the approach will be useful to others. I found a general lack of detailed information about using JVMTI when doing research.

OnLoad: Config, capabilities, events, and callbacks

The main entrypoint to a native JVMTI agent is the Agent_OnLoad function. I want to do three main things when my agent is loaded:

1. Load the configuration file so we know which breakpoints to set.
2. Let JVMTI know which capabilities the agent needs, and ensure the JVM supports them.
3. Let JVMTI know I'm interested in receiving events when classes are about to be loaded and when breakpoints occur, and register callback functions for these.

The configuration file's implementation is a bit out of scope for this blog. I wrote a quick, dirty, and exceptionally rough yaml parser in C (yes, I know... I must have been bored). You can look at config.c if you're truly interested in the sordid details of this. But ignoring that, here are the more interesting parts of OnLoad:

`JNIEXPORT jint JNICALL Agent_OnLoad(JavaVM *vm, char *options, void *reserved) { char *option = strtok(options, ","); // ... // Load the config file using options fromoption`. Also parse out an option for // a log file to write to. // ..

fprintf(stderr, "mlogagent: Loaded agent\n");

// Get a JVMTI env object, which is used to make function calls into JVMTI jvmtiEnv env; assert(JVMTI_ERROR_NONE == (vm)->GetEnv(vm, (void **)&env, JVMTI_VERSION));

// Let JVMTI know we are going to be registering breakpoints and accessing local // variables. If these capabilities are not supported by the JVM, then the AddCapabilities // function will return an error code, and our agent will terminate the VM. jvmtiCapabilities capabilities = { 0 }; capabilities.can_generate_breakpoint_events = 1; capabilities.can_access_local_variables = 1; assert(JVMTI_ERROR_NONE == (*env)->AddCapabilities(env, &capabilities));

// Register callbacks for ClassPrepare and Breakpoint events. We'll dig into these callback // functions soon. jvmtiEventCallbacks callbacks = { 0 }; callbacks.ClassPrepare = &ClassPrepareCallback; callbacks.Breakpoint = &BreakpointCallback; assert(JVMTI_ERROR_NONE == (*env)->SetEventCallbacks(env, &callbacks, sizeof(callbacks)));

// Tell JVMTI to enable breakpoint and class prepare events so our callbacks will be invoked. assert(JVMTI_ERROR_NONE == (env)->SetEventNotificationMode(env, JVMTI_ENABLE, JVMTI_EVENT_BREAKPOINT, NULL)); assert(JVMTI_ERROR_NONE == (env)->SetEventNotificationMode(env, JVMTI_ENABLE, JVMTI_EVENT_CLASS_PREPARE, NULL));

return JNI_OK; }``

Registering method breakpoints

The next step is to attach breakpoints to methods we're interested in. We do this when the ClassPrepare event is fired, which happens just before the JVM loads a class. In our case, the implementation of this is a bit complicated by the fact that we have a config file that drives setting the breakpoints, but at the core, we just need to find the class we're interested in, find the method we care about, then attach a breakpoint to it. Here's a simplified version of the code:

`void JNICALL ClassPrepareCallback(jvmtiEnv jvmti_env, JNIEnv jni, jthread thread, jclass klass) { // Avoid re-entrancy, and return early if we already attached. if (in_prepare || attached) { return; }

in_prepare = true;

jclass clazz = (jni)->FindClass(jni, classConfig->name); // In case we don't find the class, don't throw an exception (jni)->ExceptionClear(jni); if (clazz != NULL) { attachMethodBreakpoint(jvmti_env, jni, clazz); (*jni)->DeleteLocalRef(jni, clazz); attached = true; }

in_prepare = false; }

void attachMethodBreakpoint(jvmtiEnv jvmti_env, JNIEnv jni, jclass clazz) { // Look for the method. Here, // methodName is something like "someMethod" // methodSignature is something like "(Lfrodo/Test$RealFile;)Ljava/lang/String;" jmethodID mid = (jni)->GetMethodID(jni, clazz, methodName, methodSignature); if (mid != NULL) { // Actually set the method breakpoint assert(JVMTI_ERROR_NONE == (jvmti_env)->SetBreakpoint(jvmti_env, mid, 0)); } else { fprintf(stderr, "mlogagent: Can't find the method\n"); } }`

The last part is to handle the method breakpoint callback when it happens. In the real program, we keep track of methodIDs we've registered breakpoints for, so that when we get this event we can quickly determine which method triggered the breakpoint, and look up information about how to display it in the config. In the real code, this is one of the more complex parts of the implementation, since it uses a bunch of JNI in order to generate a string to represent the method parameter we're interested in. For this simplified example, I'm just going to show what the callback looks like, how to extract a parameter, and how to print the first few frames of the stack trace.

`// Called when a breakpoint is hit. void JNICALL BreakpointCallback(jvmtiEnv jvmti_env, JNIEnv jni, jthread thread, jmethodID method, jlocation location) { // Get hold of the parameter. In this example, we just get the first parameter. // Which parameter is first depends on whether this is a static or instance method. // For instance methods, the first parameter is a synthetic parameter representing // the current instance of the class. So here, we get the first "real" parameter. int parameterPos = 1;

jobject the_parameter; assert(JVMTI_ERROR_NONE == (*jvmti_env)->GetLocalObject(jvmti_env, thread, 0, parameterPos, &the_parameter));

// TODO: something that displays the parameter... See the full code for details.

// Show a simplified stack trace. jvmtiFrameInfo frames[8]; jint count; jvmtiError err;

err = (jvmti_env)->GetStackTrace(jvmti_env, thread, 0, 8, frames, &count); if (err == JVMTI_ERROR_NONE && count >= 1) { char methodName; // fout is the output log file fprintf(fout, " trace: "); for (int i = 0; i < count; i++) { err = (*jvmti_env)->GetMethodName(jvmti_env, frames[i].method, &methodName, NULL, NULL); if (err == JVMTI_ERROR_NONE) { fprintf(fout, "<- %s", methodName); } } fprintf(fout, "\n"); }

fflush(fout); }`

Compiling and running the agent

To compile the agent, you need to add to your compiler's include path header files from the java runtime you're compiling for. The location of these vary from system to system. On my system, I use a command something like this:

gcc -shared \
  -I/usr/local/java-runtime/impl/8/include \
  -I/usr/local/java-runtime/impl/8/include/darwin \
  mlogagent.c \
  -o /tmp/libmlogagent.dylib

To use the agent in a running java program, we pass the -agentpath argument to java with the path of the agent, and any options we want to pass in:

java -agentpath:/tmp/libmlogagent.dylib=config=test.conf,file=/tmp/out.txt \
   -cp classes frodo.Test

Summing up

So we've seen how to write a fairly basic JVMTI agent that can log method calls. It's pretty efficient - in an example application which makes thousands of method calls a second, there's no perceptible performance impact when the agent is enabled. You can find full source for the tool on github.

I'd like to experiment more with this tool, perhaps making it more flexible and customizable. Some of the things I want to poke around with are:

• Rewriting it in Rust. This has advantages like me not having to reinvent a configuration file parser from scratch because I'm too lazy to pull in third party C libraries, as well as likely making it easier to maintain and extend the code in future.
• Looking into whether it'd be easier to do the same thing with a java-based agent or JDI, and seeing whether the performance characteristics of these are different.
• Adding much more flexibility around logging various bits of context when a breakpoint is hit. For example, it'd be useful to have the option to log fields, and all of the parameters instead of just one.

You can find the code for this tool in github.