DTrace and Scala

DTrace is one of my favorite technologies ever, it absolutely redefined my view on software and how it can be debugged. In a lot of situations you are basically forced to debug your software by vomiting print-statements just all over the place. To make things worse you have to take them out when you are actually shipping your software, leaving you blind to errors to come. In other cases you probably are missing some print-statements to trace down a very nasty bug, or the bug is hidden in some 3rd-party lib that would take hours to recompile with your new print statement (don't start thinking about libs that you don't have the code of…). In most cases this can become a very unpleasant situation (to put it mildly). DTrace takes a lot of the hassle away by providing you with a mechanism that can modify your program while it's running without stopping it.
Pretty amazing, huh? Wait, it gets better. You can even trace into the runtime of some high level languages (if they provide the probes). This is also true for the JVM, and that means we can instrument a running Scala program.

In this post I will walk you through a very basic script that shows what methods from Predef get called by your program. DTrace is a tool that reaches deep down into the lower levels of your machine. Sounds scary? Nah not really, one of the design goals of DTrace is safety. Your scripts run in a managed environment that keeps it from doing harmful things.

OK, enough sweet-talk. Time to get our hands dirty by writing a very simple Scala program:

import scala.annotation.tailrec

object Main {
  @tailrec
  def sayHallo() {
    println("HALLO!")
    Thread.sleep(1000)
    sayHallo()
  }
                                                                                
  def main(args: Array[String]) {
    sayHallo()
  }
}

This just prints out "HALLO!" in 1 second intervals (not exactly rocket science, but I put a little sugar on top of it by replacing the while loop with a tail recursive function for fun and profit).

What's that? When running my program DTrace is not showing me ANY probes!!?!?! FFFFUUUUUUUU! That's because we have to enable them first, we can instruct a running JVM to do this by using jinfo. Since I only got one JVM running on this box I will fetch the PID with pgrep.

jinfo -flag +ExtendedDTraceProbes $(pgrep java)

The JVM probes are now armed and "dangerous" (just kiddin') and you will have access to the hotspot provider.

Now lets write the DTrace script. Keep in mind: this script is running in kernel space, so we have to copy in some information from userspace, we do this by using copyin and we have to NULL-terminate the strings ourselves. Yep, this is what it feels like to program low-level stuff, it's not as pretty as FP but aaaaaaaaaanyway, here is the little bugger.

#!/usr/sbin/dtrace -s                                                           

#pragma D option quiet

hotspot$$target:::method-entry
{
  this->class = (char *) copyin(arg1, arg2 + 1); 
  this->class[arg2] = '\0';
  self->tracefunc = stringof(this->class);
}

hotspot$$target:::method-entry
/self->tracefunc == "scala/Predef$"/
{
  this->method = (char *) copyin(arg3, arg4 + 1); 
  this->method[arg4] = '\0';
  printf("%s %Y\n", stringof(this->method), walltimestamp);
  self->tracefunc = 0;
}

hotspot$$target:::method-entry
/self->tracefunc/
{
  self->tracefunc = 0;
}

This thing will fire whenever a function from Predef is called and will give us the function name (in our test case this is just println) and the time when this function was being called. I run this on OpenIndiana build151-beta by issuing pfexec dtrace ./tracescript.d -p $(pgrep java) after I enabled the hotspot provider on the JVM. (pfexec is kind of like sudo, just use whatever gives you the permission to run dtrace on your box)
The output will look like this:

println 2011 Jul  6 21:27:34
println 2011 Jul  6 21:27:35
println 2011 Jul  6 21:27:36
println 2011 Jul  6 21:27:37
println 2011 Jul  6 21:27:38
println 2011 Jul  6 21:27:39
println 2011 Jul  6 21:27:40
println 2011 Jul  6 21:27:41
println 2011 Jul  6 21:27:42
println 2011 Jul  6 21:27:43
println 2011 Jul  6 21:27:44
println 2011 Jul  6 21:27:45
println 2011 Jul  6 21:27:46
println 2011 Jul  6 21:27:47
println 2011 Jul  6 21:27:48
println 2011 Jul  6 21:27:49
println 2011 Jul  6 21:27:50
println 2011 Jul  6 21:27:51
println 2011 Jul  6 21:27:52
println 2011 Jul  6 21:27:53
println 2011 Jul  6 21:27:54
println 2011 Jul  6 21:27:55

WTF IS THIS I DON'T EVEN!?!?!? TL;DR

OK, this is not even the tip of the iceberg but I think I will wrap it up because there is a lot of ground to cover when it comes to DTrace. If you are hungry for more you should check out the "DTrace Review" by @bcantrill, this stuff will blow your mind (seriously, WATCH IT!) or buy the book by @brendangregg. I will make sure to dig deeper on the topic, so stay tuned. Tell me what you think, good tool or best tool? :P