I've been playing with the JVM DTrace provider for the last few days and looking at ways of integrating output from this into the DAVE graphing tool that Jon Haslam and I have been working on.

Anyone who's used DTrace knows how cool it is. Once you get used to the scripting style, i.e. remembering that each clause gets executed in the order they are declared in the script and that the flow control is much more like AWK than C you can get going pretty quickly. Here's a script I put together that will track all the method calls made when a particular method is called

#!/usr/sbin/dtrace -s
#pragma D option quiet
#pragma D option bufsize=100m

self int in; /* This thread */
self string caller[int]; /* Method call stack */

/**
 * Initialise variables
 **/
BEGIN
{
  depth = 0; /* Current depth in method calls */
  max_depth = $2; /* Maximum depth to trace method calls */
  trace_method = $$3; /* The name of the method to trace */
  deepest_call = 0; /* Deepest call made */
}

/**
 * Entering any method where the call depth is greater than we want to
 * trace. To ensure that the returns match up we still need to increase
 * the current call depth
 **/
dvm$1:::method-entry
/self->in && depth >= max_depth/
{
  depth++;
}

/**
 * Entering a constructor. Since we always get as the method name
 * we replace it with the class name to provide proper identification
 **/
dvm$1:::method-entry
/self->in && copyinstr(arg1) == "" && depth < max_depth/
{
  printf("\t\"%s\" -> \"%s\";\n", self->caller[depth], copyinstr(arg0));
  depth++;
  self->caller[depth] = copyinstr(arg0);
}

/**
 * Entering a method which is not a constructor
 **/
dvm$1:::method-entry
/self->in && copyinstr(arg1) != "" && depth < max_depth/
{
  printf("\t\"%s\" -> \"%s\";\n", self->caller[depth], copyinstr(arg1));
  depth++;
  self->caller[depth] = copyinstr(arg1);
}

/**
 * Track the deepest call made
 **/
dvm$1:::method-entry
/self->in && depth > deepest_call/
{
  deepest_call = depth;
}

/**
 * Method call that starts the trace. This is placed last in the list of
 * method-entry clauses so that this is the only one executed when we start
 * the trace
 **/
dvm$1:::method-entry
/self->in == 0 && copyinstr(arg1) == trace_method/
{
  depth = 1;
  self->in = 1;
  self->caller[depth] = copyinstr(arg1);
}

/**
 * Return from the method we're tracing. Terminate the trace
 **/
dvm$1:::method-return
/self->in && copyinstr(arg1) == trace_method/
{
  printf("Trace finished, max call depth was %d\n", deepest_call);
  self->in = 0;
  exit(0);
}

/**
 * Return from a method. Decrease the current call stack depth
 **/
dvm$1:::method-return
/self->in/
{
  depth--;
}


To execute this you need either to be logged in as root or have the dtrace_kernel, dtrace_proc and dtrace_user privileges. The script takes three arguments: the first is the pid of the JVM you want to trace the method in; the second is the maximum call depth you want to go to; and the third is the name of the method to start the trace. The JVM being traced must be started with the argument -Xrundvmti:methods to enable the DTrace provider.

It's amazing how many methods get called in a Java application (many of which you, as the developer, are completely unaware of. To test this I used the DAVE GUI and just tracked the method call to display the next function in the sequence. The maximum call depth was 40. If I let the script generate all the output I got a file of 147MB. I couldn't even vi that and when I tried to put it into DAVE I just kept getting OOM errors or insufficient swap space. Even limiting it to 9 levels of method call generated the following graph (click on the image to see the fullsize version which is rather large).

Also, the impact on performance of using the DTrace provider is quite noticable (well, tracking every method entry and exit when there's 4.6 million of them, as there were for that one button click, would place a greater load on the system).

I'll keep looking into this to see how usable this can be made as a general purpose Java analysis tool. Ideally I'd like to integrate it into NetBeans so you can also look at the source code for the different methods.