SystemTap and Erlang: a tutorial

As mentioned in my previous posting, DTrace and Erlang: a status report, it’s also possible to use Linux’s SystemTap to watch the inner workings of the Erlang virtual machine.  This is possible via a DTrace compatibility layer built in to SystemTap.

In theory, any Linux system that supports user-space SystemTap should work just fine.

In practice, I highly recommend that you use a CentOS 5 machine.  Why?

  * CentOS 5 is what I use for my Linux + SystemTap testing
  * CentOS 6 ought to work, but I've noticed strange problems when trying to run some SystemTap scripts ... and have seen incorrect/weird behavior from other scripts.
  * Fedora Core 16 ought to work as well as CentOS 5, but I haven't tried it yet.

I owe many, many thanks to Andreas Schultz at Travelping GmbH for doing almost all the research and actual work to get the SystemTap stuff working.

First, Read the README File

As with any piece of open source software, it’s a good idea to read the README file.  In Erlang’s case, there are several README files.  I recommend that you quickly skim the following two files (though careful reading would be even better):

  * [README.dtrace.md](https://github.com/slfritchie/otp/blob/dtrace-review3/README.dtrace.md), the introduction to DTrace and Erlang
  * [README.systemtap.md](https://github.com/slfritchie/otp/blob/dtrace-experiment+michal2/README.systemtap.md), the introduction to SystemTap and Erlang

Please note that the newest, most up-to-date copies of these files can be found in the Erlang/OTP distribution, using the instructions below in the section “Build Erlang/OTP With SystemTap Enabled”.

Installing SystemTap on a CentOS 5 Machine

I started with a a CentOS 5.6 32-bit machine, freshly installed via the installer CD. Using a 64-bit machine is fine.  My 32-bit machine is actually a virtual machine, running inside VMware Fusion.

First, edit the /etc/yum.repos.d/CentOS-Debuginfo.repo file to change the “enabled=0” line to be “enabled=1” instead.

Next, run the following “yum” commands:

<code> yum -y install kernel kernel-devel kernel-headers yum -y install kernel-debuginfo kernel-debuginfo-common systemtap systemtap-sdt-devel systemtap-runtime systemtap-testsuite yum -y install make gcc gcc-c++ kernel-devel m4 ncurses-devel openssl-</code>devel




<span style="font-family: Georgia, 'Times New Roman', 'Bitstream Charter', Times, serif; font-size: 13px; line-height: 19px; white-space: normal;" class="Apple-style-span">Those three commands take care of the following:</span>





  * Upgrade your kernel
  * Install the kernel & user packages required for SystemTap
  * Install the minimum packages needed to build the Erlang/OTP package.

We also need to install Git.  This recipe comes from http://www.webtatic.com/packages/git17/

rpm -Uvh http://repo.webtatic.com/yum/centos/5/latest.rpm
yum install --enablerepo=webtatic git

When that’s done, reboot your machine.  The default kernel in your GRUB boot loader config should be the latest stable kernel for CentOS 5.

Now you’re ready for the next step … skip down to the section “Build Erlang/OTP With SystemTap Enabled”.

Installing SystemTap on a CentOS 6 Machine

Setting up CentOS 6 is slightly easier than CentOS 5.

So, I’ve had a more difficult time using SystemTap on CentOS 6.  There seem to be two (or three?) main variations of the SystemTap kernel & user-space packaging.  Whichever one that CentOS 6 uses doesn’t work well.  Or, doesn’t work very well for me.  If you have a different experience, please contact me!

OK, here’s the packages to install via “yum”:

yum install kernel kernel-devel kernel-headers
yum install systemtap systemtap-sdt-devel systemtap-runtime systemtap-testsuite
yum install make gcc gcc-c++ kernel-devel m4 ncurses-devel openssl-devel
yum install git

Reboot your machine, then you’re ready for the next phase.

Build Erlang/OTP With SystemTap Enabled

First, please make certain that the kernel that’s currently running supports user-space SystemTap

See the “How Do I Try It?” section of the status report for instructions on how to compile the Erlang/OTP distribution.  Both the R14B04 and the still-under-development R15A releases are supported.

Checking to See If User-Space SystemTap Works

Please run the following command to make certain that user-space SystemTap is installed correctly on your system.

    grep CONFIG_UTRACE /boot/config-`uname -r`

The output should be:

    CONFIG_UTRACE=y

If not, you’re using the wrong kernel.

Next, check to see if your Erlang build has been compiled successfully with SystemTap via the DTrace compatibility mode:

    PATH=/path/to/beam:$PATH stap -L 'process("beam").mark("*")'

You should see output that looks like this:

process("beam").mark("aio_pool__add")
process("beam").mark("aio_pool__get")
process("beam").mark("bif__entry")
process("beam").mark("bif__return")
process("beam").mark("copy__object")
process("beam").mark("copy__struct")
[...]

Congratulations!

Running Your First SystemTap Script on CentOS 5

You will need two windows/login sessions:

  1. One window/login session to run an Erlang shell
  2. One window/login session as the superuser (i.e., "root") to run the SystemTap scripts.

Using the first window, start an Erlang shell with SMP support disabled, e.g. /path/to/your/erlang/installation/bin/erl -smp disabled

On my machine, I have close to a dozen different versions of Erlang installed.  To keep my SystemTap/DTrace builds separate from everything else, I used “./configure –prefix=/usr/local/erlang/R15A.dtrace”.  Therefore, my startup command is “/usr/local/erlang/R15A.dtrace/bin/erl -smp disabled”.

Your paths are probably different.  For the rest of this little tutorial, I assume that you know what the top-level path is.

Using your second window, use “ps axw | grep beam” to find the full path to the BEAM virtual machine.  This path is NOT THE SAME as the path used to start Erlang via the “erl” command.  On my system, the result is:

[root@localhost ~]# ps axw | grep beam
 9606 pts/2    S+     0:00 /usr/local/erlang/R15A.dtrace-review3/lib/erlang/erts-5.9/bin/beam -- -root /usr/local/erlang/R15A.dtrace-review3/lib/erlang -progname erl -- -home /home/fritchie -- -smp disable

The directory that contains the “beam” executable is what’s necessary for the “env PATH” commands that we will use later.  In my case, that directory is “/usr/local/erlang/R15A.dtrace-review3/lib/erlang/erts-5.9/bin”. Your directory name is probably different.

In the second window/login session, start a SystemTap script from the examples directory: 

cd /usr/local/erlang/R15A.dtrace/lib/erlang/lib/dtrace-0.8/example
env PATH=/usr/local/erlang/R15A.dtrace-review3/lib/erlang/erts-5.9/bin:$PATH stap ./garbage-collection.systemtap




<span style="font-family: Georgia, 'Times New Roman', 'Bitstream Charter', Times, serif; font-size: 13px; line-height: 19px; white-space: normal;" class="Apple-style-span">Then, back in the first window, start typing commands at the Erlang shell prompt.  For example:</span><span style="font-family: Georgia, 'Times New Roman', 'Bitstream Charter', Times, serif; font-size: 13px; line-height: 19px; white-space: normal;" class="Apple-style-span"> </span>




Erlang R15A (erts-5.9) [source] [rq:1] [async-threads:0] [hipe] [kernel-poll:false] [dtrace]

Eshell V5.9  (abort with ^G)
1> "this is a test of the SystemTap system".

Over in the second window, you should see output that looks like this:

GC minor start pid <0.24.0> need 3 words
GC minor end pid <0.24.0> reclaimed 3 words
GC minor start pid <0.22.0> need 14 words
GC minor end pid <0.22.0> reclaimed 14 words
GC minor start pid <0.24.0> need 8 words
GC minor end pid <0.24.0> reclaimed 8 words

Congratulations, go have fun exploring Erlang and SystemTap!

 WARNING: Erlang SMP Support Uses a Different Executable Name!

All of the SystemTap scripts in the “examples” directory contain the name of the Erlang virtual machine executable, “beam”.  We started Erlang using the “-smp disabled” flag because we wanted to make certain that we were using “beam”, the executable that does NOT support SMP, i.e., symmetric multi-processing, i.e., multi-CPU and multi-core systems.

The executable that supports SMP is called “beam.smp”.  If you use the SMP version of Erlang, then you must also change the name of the executable in your SystemTap scripts!

Running Your First SystemTap Script on CentOS 6

So, all of the directions given in the CentOS 5 section are exactly the same for CentOS 6 also.

Why is there a separate CentOS 6 section?  Because things don’t work correctly for me, and I’m hoping that someone else will notice and then email me with a fix.  (Hint, hint, …. :-)

Here’s what I see when I run the same garbage collection script on my CentOS 6 machine:

[root@localhost ~]# env PATH=/usr/local/erlang/R15A.dtrace-review3/lib/erlang/erts-5.9/bin:$PATH stap ./garbage-collection.systemtap
semantic error: no match while resolving probe point process("beam").mark("gc_major-start")
semantic error: no match while resolving probe point process("beam").mark("gc_minor-start")
semantic error: no match while resolving probe point process("beam").mark("gc_major-end")
Pass 2: analysis failed.  Try again with another '--vp 01' option.

Actually, I know how to fix that one.  The problem comes from the DTrace convention of using underscore characters and hyphen characters in probe names.  With DTrace, if a probe definition file uses a name has two underscores, e.g., “gc_major__start”, then the DTrace probe name is “gc_major-start”.

The version of SystemTap that CentOS 5 uses seems to be aware of the double-underscore-becomes-a-hyphen convention.  The CentOS 6 version of SystemTap does not.

So, we fix our file with a bit of editing, so it now looks like this:

[... comments at top of file omitted ...]
probe process("beam").mark("gc_major__start")
{
    printf("GC major start pid %s need %d words\n", user_string($arg1), $arg2);
}

probe process("beam").mark("gc_minor__start")
{
    printf("GC minor start pid %s need %d words\n", user_string($arg1), $arg2);
}

probe process("beam").mark("gc_major__end")
{
    printf("GC major end pid %s reclaimed %d words\n", user_string($arg1), $arg2);
}

probe process("beam").mark("gc_minor__start")
{
    printf("GC minor end pid %s reclaimed %d words\n", user_string($arg1), $arg2);
}

Now we try to run again.  This time we see garbage instead of the Erlang PID strings that we ought to see:

[root@localhost ~]# env PATH=/usr/local/erlang/R15A.dtrace-review3/lib/erlang/erts-5.9/bin:$PATH stap /tmp/garbage-collection.systemtap
GC minor start pid ???? need 8 words
GC minor end pid ???? reclaimed 8 words
GC minor start pid ???? need 14 words
GC minor end pid ???? reclaimed 14 words
GC minor start pid need 16 words
GC minor end pid reclaimed 16 words
^C

Other SystemTap scripts in the examples director have bigger problems, such as the following (after changing the probe name hyphens to double-underscores):

[root@localhost ~]# env PATH=/usr/local/erlang/R15A.dtrace-review3/lib/erlang/erts-5.9/bin:$PATH stap /tmp/messages.systemtap
semantic error: failed to retrieve location attribute for local 'arg4' (dieoffset: 0x193897): identifier '$arg4' at /tmp/messages.systemtap:79:9
        source:     if ($arg4 == 0 && $arg5 == 0 && $arg6 == 0) {
                        ^
Pass 2: analysis failed.  Try again with another '--vp 01' option.

[root@localhost ~]# env PATH=/usr/local/erlang/R15A.dtrace-review3/lib/erlang/erts-5.9/bin:$PATH stap -L 'process("beam").mark("*")' | grep message
process("beam").mark("message__queued") $arg1:char* $arg3:int $arg4:Sint $arg5:Sint $arg6:Sint
process("beam").mark("message__receive")
process("beam").mark("message__send") $arg1:char* $arg2:char* $arg4:Sint $arg5:Sint $arg6:Sint
process("beam").mark("message__send__remote") $arg1:char* $arg2:char* $arg3:char* $arg5:Sint $arg6:Sint $arg7:Sint

So, the probe is there, it’s named correctly, and it’s got the proper number of arguments but … SystemTap doesn’t like it.  Perhaps there’s a different version of SystemTap syntax also?  Hrm, I don’t know the answer, but I’ll try to find out in the next week….

Conclusion

I hope you’ve enjoyed this little tutorial.  Now go have some fun and explore Erlang and SystemTap!

 UPDATE 1, Saturday Nov 19, 2011:

It’s quite possible that despite the number 6 being greater than the number 5, CentOS 6 is using a version of SystemTap 1.2, and CentOS 5 is using a version of SystemTap 1.3.  If that’s true, then it’s probably better for CentOS 6 users to roll their own SystemTap support.  Many thanks to Andreas Schultz for pointing this out.

Another tip from Andreas: Newer versions of SystemTap are available using the CentOS continuous release (CR) repository.  Beware that packages there may not be 100% stable.

UPDATE 2, Tuesday Nov 29, 2011:

There appears to be an additional problem, this time with CentOS 5 and its SystemTap version 1.3: probes defined by shared libraries do not work correctly.  To demonstrate, run this little demo in two different windows/login sessions.

In window number #1, run this command using a DTrace-enabled Erlang build. Depending on where your Erlang package was installed, you must change the directory paths to match your environment.

/usr/local/erlang/R15A.dtrace-review-20111127/bin/erl -eval '{dtrace:init(), [{dtrace:p(42), io:format("."), timer:sleep(1000)} || _ <- lists:seq(1,2000)]}.'

This 1-liner will load the “dtrace.so” shared library into the Erlang virtual machine and then try to fire a probe within that library once per second.

In window/login session #2, as root/superuser, run the following two commands. Also, note the output from the first command should match what I show here.

# env PATH=/home/local/erlang/R15A.dtrace-review-20111127/lib/erlang/lib/dtrace-0.8/priv/lib:/usr/local/erlang/R15A.dtrace-review-20111127/lib/erlang/erts-5.9.pre/bin:$PATH stap -l 'process("dtrace.so").mark("*")'
process("dtrace.so").mark("user_trace__i4s4")
process("dtrace.so").mark("user_trace__s1")

# env PATH=/home/local/erlang/R15A.dtrace-review-20111127/lib/erlang/lib/dtrace-0.8/priv/lib:/usr/local/erlang/R15A.dtrace-review-20111127/lib/erlang/erts-5.9.pre/bin:$PATH stap -e 'probe process("dtrace.so").mark("*") {printf("Shared lib probe fired");}'

If the probe is working correctly, then you should see the “Shared lib probe fired” message printed once per second. Unfortunately, on my CentOS 5 machine, the probe does nothing.  :-(