I love it when a plan comes together – systemtap meets java!

With the recent releases of Systemtap 0.9.9 and IcedTea7 1.11 some pieces of the systemtap whole system observability picture come together. On top of the “meta-probes” in hotspot (for garbage collection, monitors, object allocation, threads, etc.) we now also see the java language level tracing coming to life.

Always wondered what really was going on when your “simple” Hello world java program was running…

$ stap -e \
'probe hotspot.method_entry {log(thread_indent(1) . "=> " . class . "." . method . sig)}
probe hotspot.method_return {log(thread_indent(-1) . "<= " . class . "." . method . sig)}' \
-c 'java -XX:+ExtendedDTraceProbes Hello'
[...]
   0 java(26933):=> Hello.main([Ljava/lang/String;)V
   9 java(26933): => java/lang/ClassLoader.checkPackageAccess(Ljava/lang/Class;Ljava/security/ProtectionDomain;)V
  16 java(26933):  => java/lang/System.getSecurityManager()Ljava/lang/SecurityManager;
  23 java(26933):  <= java/lang/System.getSecurityManager()Ljava/lang/SecurityManager;
  30 java(26933):  => java/util/HashSet.add(Ljava/lang/Object;)Z
  37 java(26933):   => java/util/HashMap.put(Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;
  43 java(26933):    => java/lang/Object.hashCode()I
  50 java(26933):    <= java/lang/Object.hashCode()I
  56 java(26933):    => java/util/HashMap.hash(I)I
  63 java(26933):    <= java/util/HashMap.hash(I)I
  69 java(26933):    => java/util/HashMap.indexFor(II)I
  76 java(26933):    <= java/util/HashMap.indexFor(II)I
  83 java(26933):   <= java/util/HashMap.put(Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;
  89 java(26933):  <= java/util/HashSet.add(Ljava/lang/Object;)Z
  96 java(26933): <= java/lang/ClassLoader.checkPackageAccess(Ljava/lang/Class;Ljava/security/ProtectionDomain;)V
[...]
2611 java(26933):     => java/io/BufferedOutputStream.flush()V
2617 java(26933):      => java/io/BufferedOutputStream.flushBuffer()V
2624 java(26933):       <= java/io/BufferedOutputStream.flushBuffer()V
2630 java(26933):   <= java/io/BufferedOutputStream.flush()V
2636 java(26933):  <= java/io/PrintStream.newLine()V
2643 java(26933): <= java/io/PrintStream.println(Ljava/lang/String;)V
2649 java(26933):<= Hello.main([Ljava/lang/String;)V


The needed changes have also been added to IcedTea6 so expect them in a GNU/Linux distro near you soon.

One Comment

  1. […] did I get here?” in combination with any of the SystemTap tapsets for VM level tracing, Java method entry/exit tracing, Native methods (JNI) tracing, or any other basic SystemTap function, statement or process probes […]