Better systemtap java integration - added hotspot tapset

Tue Apr 28 08:38:26 PDT 2009

Hi,

IcedTea contained some support for trace markers since a while. But it
wasn't very convenient to use with systemtap. Systemtap 0.9.7 contains
an important bugfix that makes shared library probeing (libjvm.so)
better. I wrote a hotspot.stp tapset that takes advantage of the markers
(which are the same as dtrace uses) inside libjvm.so and that exposes
the various arguments and some convenient aggregates to make tracing
hotspot with systemtap very easy and powerful.

2009-04-28  Mark Wielaard  <mjw at redhat.com>

   * tapset/hotspot.stp.in: New systemtap tapset for hotspot.
   * configure.ac: Add check for abs-install-dir when
   --enable-systemtap is given.
   * Makefile.am (icedtea.stamp): Install tapsets.
   (icedtea-debug.stamp): Likewise.
   * .hgignore: Add tapset/hotspot.stp.

When configuring with --enable-systemtap this will now install a
tapset/hotspot.stp in the j2sdk-image directory. If you are going to
install in some other permanent location, such as distributions, then
there is a new --with-abs-install-dir option that can be used (for most
distros this should be set to /usr/lib/jvm/java-1.6.0-openjdk-1.6.0.0/).
The probes are placed in both client and server libjvm.so, so you can
use either.

The tapset makes available the following probes:

hotspot.gc_begin
hotspot.gc_end
hotspot.mem_pool_gc_begin
hotspot.mem_pool_gc_end
hotspot.object_alloc (*)
hotspot.vm_init_begin
hotspot.vm_init_end
hotspot.vm_shutdown
hotspot.thread_start
hotspot.thread_stop
hotspot.class_loaded
hotspot.class_unloaded
hotspot.method_compile_begin
hotspot.method_compile_end
hotspot.monitor_wait (*)
hotspot.monitor_waited (*)
hotspot.monitor_notify (*)
hotspot.monitor_notifyAll (*)
hotspot.monitor_contended_enter (*)
hotspot.monitor_contended_entered (*)
hotspot.monitor_contended_exit (*)

The are all documented in the hotspot.stp tapset. Each probe makes at
least its name and a full probestr variable available that can be used
to quickly get all arguments of each probe. Variables that aren't used
are optimized away and will not be evaluated, making the tapset both
convenient and efficient. probes marked with a (*) are only triggered
when java has been started with -XX:+ExtendedDTraceProbes.

Some examples from a trace of HelloWorld (lots of output trimmed):
stap -I j2sdk-image/tapset -e 'probe hotspot.* {log(probestr)}' \
  -c 'j2sdk-image/bin/java HelloWorld'

vm_init_begin
class_loaded(class='java/lang/Object',classloader_id=0x0,is_shared=0)
class_loaded(class='java/io/Serializable',classloader_id=0x0,is_shared=0)
class_loaded(class='java/lang/Comparable',classloader_id=0x0,is_shared=0)
class_loaded(class='java/lang/CharSequence',classloader_id=0x0,is_shared=0)
class_loaded(class='java/lang/String',classloader_id=0x0,is_shared=0)
thread_start(thread_name='Reference Handler',id=2,native_id=22685,is_daemon=1)
thread_start(thread_name='Finalizer',id=3,native_id=22686,is_daemon=1)
vm_init_end
thread_start(thread_name='Signal Dispatcher',id=4,native_id=22687,is_daemon=1)
thread_start(thread_name='CompilerThread0',id=5,native_id=22688,is_daemon=1)
thread_start(thread_name='Low Memory Detector',id=6,native_id=22689,is_daemon=1)
method_compile_begin(compiler='C1',class='java/lang/String',method='hashCode',sig='()I')
method_compile_end(compiler='C1',class='java/lang/String',method='hashCode',sig='()I')
method_compile_begin(compiler='C1',class='java/lang/String',method='indexOf',sig='(II)I')
method_compile_end(compiler='C1',class='java/lang/String',method='indexOf',sig='(II)I')
thread_stop(thread_name='Signal Dispatcher',id=4,native_id=22687,is_daemon=1)
vm_shutdown

And with -XX:+ExtendedDTraceProbes added you will also get information like:

object_alloc(thread_id=1,class='[Ljava/security/cert/Certificate;',size=0x21)
object_alloc(thread_id=7,class='java/util/Collections$EmptyList',size=0x1f)
monitor_wait(thread_id=2,id=0x817feb4,class='java/lang/ref/Reference$Lock',timeout=0)
monitor_wait(thread_id=3,id=0x8180b34,class='java/lang/ref/ReferenceQueue$Lock',timeout=0)

And on larger programs you can see the various garbage collectors and
monitor contention in play:

gc_begin(is_full=0)
gc_end
mem_pool_gc_begin(manager='Copy',pool='Code Cache',initial=163840,used=785856,committed=786432,max=33554432)
mem_pool_gc_begin(manager='Copy',pool='Eden Space',initial=917504,used=917504,committed=917504,max=33030144)
mem_pool_gc_begin(manager='Copy',pool='Survivor Space',initial=65536,used=65536,committed=65536,max=4128768)
mem_pool_gc_begin(manager='Copy',pool='Tenured Gen',initial=4194304,used=784640,committed=4194304,max=495583232)
mem_pool_gc_begin(manager='Copy',pool='Perm Gen',initial=12582912,used=8340016,committed=12582912,max=67108864)
mem_pool_gc_end(manager='Copy',pool='Code Cache',initial=163840,used=785856,committed=786432,max=33554432)
mem_pool_gc_end(manager='Copy',pool='Eden Space',initial=917504,used=0,committed=917504,max=33030144)
mem_pool_gc_end(manager='Copy',pool='Survivor Space',initial=65536,used=65536,committed=65536,max=4128768)
mem_pool_gc_end(manager='Copy',pool='Tenured Gen',initial=4194304,used=1016496,committed=4194304,max=495583232)
mem_pool_gc_end(manager='Copy',pool='Perm Gen',initial=12582912,used=8340016,committed=12582912,max=67108864)
monitor_notifyAll(thread_id=1,id=0x9da26bc,class='java/lang/Object')
monitor_contended_exit(thread_id=1,id=0x9da26bc,class='java/lang/Object')
monitor_waited(thread_id=11,id=0x9da26bc,class='java/lang/Object')
monitor_wait(thread_id=11,id=0x9da26bc,class='java/lang/Object',timeout=0)
monitor_contended_enter(thread_id=12,id=0x9e3a7b0,class='java/awt/Component$AWTTreeLock')
monitor_contended_exit(thread_id=1,id=0x9e3a7b0,class='java/awt/Component$AWTTreeLock')
monitor_contended_exit(thread_id=1,id=0x9e3a7b0,class='java/awt/Component$AWTTreeLock')
monitor_contended_entered(thread_id=12,id=0x9e3a7b0,class='java/awt/Component$AWTTreeLock')
monitor_notifyAll(thread_id=1,id=0x9da26bc,class='java/lang/Object')

I'll write a followup post with some issues that could be improved to
make this even more useful and enable even more probes.

Feedback on the installation appreciated. Is the current location OK, or
should it go into a shared/system systemtap tapset directory (so it is
automagically picked up instead of needed -I)? Does this setup work for
distro packagers?

Cheers,

Mark
-------------- next part --------------
A non-text attachment was scrubbed...
Name: tapset.patch
Type: text/x-patch
Size: 2285 bytes
Desc: not available
Url : http://mail.openjdk.java.net/pipermail/distro-pkg-dev/attachments/20090428/a0f7eb1d/tapset.patch 
-------------- next part --------------
A non-text attachment was scrubbed...
Name: hotspot.stp.in
Type: text/x-csrc
Size: 14963 bytes
Desc: not available
Url : http://mail.openjdk.java.net/pipermail/distro-pkg-dev/attachments/20090428/a0f7eb1d/hotspot.stp.in 