Tracing glib

I saw a blog entry where Krishnan Parthasarathi at sun played with static dtrace probes in glib and it seemed like a really nice thing. Also, the systemtap developers at Red Hat continue to kick ass, and I’ve long wanted to play around with their work. This seemed like a great thing to try it out on.

I’m running Fedora 12 here, and it includes systemtap 1.0 and utrace, so it support the same kind of static probes that dtrace does (in fact, the markers are source compatible with dtrace). So, I wrote an initial set of dtrace/systemtap probes and a systemtap tapset (a library for easier using the probes in systemtap) for glib and gobject.

Its kind of limited atm, but it lets you trace memory allocation in glib, gobject lifecycle issues and signal emissions. Already this lets you do some pretty cool things, like this alive.stp:

global alive
probe gobject.object_new {
 alive[type]++
}
probe gobject.object_finalize {
 alive[type]--
}
probe end {
  printf ("Alive objects: \n")
  foreach (a in alive) {
   if (alive[a] > 0)
     printf ("%d\t%s\n", alive[a], a)
  }
}

Which you can run like this:

stap alive.stp -c "gedit /etc/passwd"

Giving something that starts:

Alive objects: 
72   GParamObject
1    GdkDisplayManager
1    GdkDisplayX11
7    GParamPointer
17   GParamDouble
1    GdkScreenX11
...

Another example is signals.stp which is a simple example to look at signal emissions:

probe gobject.signal_emit {
 printf("%s --> %p[%s]::%s\n", thread_indent(1),  object, type, signal);
}
probe gobject.signal_emit_end {
 printf("%s <-- %p[%s]::%s\n", thread_indent(-1),  object, type, signal);
}

Some example output (again from gedit), shows how size allocation works for the main window:

14406 gedit(7492):  --> 0x00000000021c2040[GeditWindow]::realize
 14862 gedit(7492):  <-- 0x00000000021c2040[GeditWindow]::realize
 14872 gedit(7492):  --> 0x00000000021c2040[GeditWindow]::check-resize
 14881 gedit(7492):   --> 0x00000000021c2040[GeditWindow]::size-request
 14890 gedit(7492):    --> 0x00000000021a2950[GtkVBox]::size-request
 14899 gedit(7492):     --> 0x000000000236f090[GtkHPaned]::size-request
 14907 gedit(7492):      --> 0x000000000236f190[GtkVPaned]::size-request
 14915 gedit(7492):       --> 0x0000000002378010[GeditNotebook]::size-request
 14927 gedit(7492):        --> 0x000000000235ac30[GeditTab]::size-request
 14935 gedit(7492):         --> 0x00000000023b79f0[GtkScrolledWindow]::size-request
 14944 gedit(7492):          --> 0x00000000023825c0[GtkHScrollbar]::size-request
 14954 gedit(7492):          <-- 0x00000000023825c0[GtkHScrollbar]::size-request
 14963 gedit(7492):          --> 0x0000000002382730[GtkVScrollbar]::size-request
 14973 gedit(7492):          <-- 0x0000000002382730[GtkVScrollbar]::size-request
 14980 gedit(7492):         <-- 0x00000000023b79f0[GtkScrolledWindow]::size-request
 14987 gedit(7492):        <-- 0x000000000235ac30[GeditTab]::size-request
 14995 gedit(7492):        --> 0x00000000023b9df0[GtkHBox]::size-request
 15002 gedit(7492):        <-- 0x00000000023b9df0[GtkHBox]::size-request
 15009 gedit(7492):       <-- 0x0000000002378010[GeditNotebook]::size-request
 15015 gedit(7492):      <-- 0x000000000236f190[GtkVPaned]::size-request
 15021 gedit(7492):     <-- 0x000000000236f090[GtkHPaned]::size-request
 15028 gedit(7492):    <-- 0x00000000021a2950[GtkVBox]::size-request
 15034 gedit(7492):   <-- 0x00000000021c2040[GeditWindow]::size-request
 15044 gedit(7492):   --> 0x00000000021c2040[GeditWindow]::size-allocate
 15051 gedit(7492):    --> 0x00000000021a2950[GtkVBox]::size-allocate
 15060 gedit(7492):     --> 0x000000000236f090[GtkHPaned]::size-allocate
 15067 gedit(7492):      --> 0x000000000236f190[GtkVPaned]::size-allocate
 15075 gedit(7492):       --> 0x0000000002378010[GeditNotebook]::size-allocate
 15084 gedit(7492):        --> 0x000000000235ac30[GeditTab]::size-allocate
 15092 gedit(7492):         --> 0x00000000023b79f0[GtkScrolledWindow]::size-allocate
 15101 gedit(7492):         <-- 0x00000000023b79f0[GtkScrolledWindow]::size-allocate
 15107 gedit(7492):        <-- 0x000000000235ac30[GeditTab]::size-allocate
 15119 gedit(7492):        --> 0x00000000023b9df0[GtkHBox]::size-allocate
 15128 gedit(7492):        <-- 0x00000000023b9df0[GtkHBox]::size-allocate
 15134 gedit(7492):       <-- 0x0000000002378010[GeditNotebook]::size-allocate
 15140 gedit(7492):      <-- 0x000000000236f190[GtkVPaned]::size-allocate
 15146 gedit(7492):     <-- 0x000000000236f090[GtkHPaned]::size-allocate
 15153 gedit(7492):    <-- 0x00000000021a2950[GtkVBox]::size-allocate
 15159 gedit(7492):   <-- 0x00000000021c2040[GeditWindow]::size-allocate
 15165 gedit(7492):  <-- 0x00000000021c2040[GeditWindow]::check-resize

This is really cool and useful stuff.

Unfortunately the current systemtap static marker implementation is a bit inefficient, so I wouldn’t at the moment enable this for a shipping production glib. However, this can and will be fixed (I even proposed some ideas of how to do this in the systemtap bugzilla).

5 Responses to “Tracing glib”

  1. Andy Wingo says:

    Nobody has replied? Well may I be the first to say, for the Nth time, that you sir are a hacker.

  2. pvanhoof says:

    Wow, this is super useful. Thanks for the tip, Alex.

  3. For a long time ago you wrote about policykit in gio. It’s still not implemented, will it ever be?

  4. alexl says:

    Jean-Philippe:

    I had never had time to work on it. Various other people have expressed interest in doing it, but nothing have ever come out of it.

    I hope it will happen eventually, but its not something I see myself working on short-term, unfortunately.