Systemtap simple userspace example (function tracing, Ubuntu)?

Question

(I've spent quite some time getting this to work, so I thought I'd document it - first, to put it formally as a question):

Is there a simple example of systemtap probing/tracing functions in a user-space application, preferably in C++? My system is Ubuntu 14.04:

$ uname -a
Linux mypc 4.2.0-42-generic #49~14.04.1-Ubuntu SMP Wed Jun 29 20:22:11 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux
$ g++ --version
g++ (Ubuntu 4.8.4-2ubuntu1~14.04.3) 4.8.4 ...
$ stap --version
Systemtap translator/driver (version 2.3/0.158, Debian version 2.3-1ubuntu1.4 (trusty))

Answer 1

OK, so this didn't turn out to be trivial - first of all, I somehow ended up with a (newer) kernel 4.2.0 on Ubuntu 14.04; and apparently the systemtap that comes with Ubuntu 14.04 is too old for that kernel (see below). That means that I had to build systemtap from source - this was my procedure:

cd /path/to/src
git clone git://sourceware.org/git/elfutils.git elfutils_git
git clone git://sourceware.org/git/systemtap.git systemtap_git
cd systemtap_git
./configure --with-elfutils=/path/to/src/elfutils_git --prefix=/path/to/src/systemtap_git/local --enable-docs=no
make
make install
# after this, there are `stap` executables in: 
#  /path/to/src/systemtap_git/stap
#  /path/to/src/systemtap_git/local/bin/stap

This is the thing:

• you shouldn't build elfutils separately, and then systemtap - you should instead pass the elfutils source directory to --with-elfutils of systemtap's configure, which will then configure and build elfutils as well.
• you MUST do make install of systemtap, even if it is in a non-system/private (local) directory! - otherwise, some errors occur (unfortunately, didn't log them)

After building, stap reports version:

$ ./stap --version
Systemtap translator/driver (version 3.2/0.170, commit release-3.1-331-g0efba6fc74c8 + changes) ...

Ok, so I found a basic Fibonacci C++ example for analysis, which I slightly modified, and called /tmp/fibo.cpp:

// based on: http://www.cplusplus.com/articles/LT75fSEw/
#include <iostream>

using namespace std;

class Fibonacci{
public:
  int a, b, c;
  void generate(int);
  void doFibonacciStep(int);
};

void Fibonacci::doFibonacciStep(int istep){
  c = a + b;
  cout << "  istep: " << istep << " c: " << c << endl;
  a = b;
  b = c;
}

void Fibonacci::generate(int n){
  a = 0; b = 1;
  cout << " Start: a "<< a << " b " << b << endl;
  for(int i=1; i<= n-2; i++){
    doFibonacciStep(i);
  }
}

int main()
{
  cout << "Hello world! Fibonacci series" << endl;
  cout << "Enter number of items you need in the series: ";
  int n;
  cin  >> n;
  Fibonacci fibonacci;
  fibonacci.generate(n);
  return 0;
}

First I tried compiling it like this:

cd /tmp
g++ -g fibo.cpp -o fibo.exe

Now, the first thing that we want to do, is to figure out which functions are available for probing in our executable; for that, we can use stap -L (note, here I'm still using the old, Ubuntu 14.04 system stap):

$ stap -L 'process("/tmp/fibo.exe").function("*").call'
process("/tmp/fibo.exe").function("_GLOBAL__sub_I__ZN9Fibonacci15doFibonacciStepEi").call
process("/tmp/fibo.exe").function("__static_initialization_and_destruction_0").call $__initialize_p:int $__priority:int
process("/tmp/fibo.exe").function("doFibonacciStep@/tmp/fibo.cpp:13").call $this:class Fibonacci* const $istep:int
process("/tmp/fibo.exe").function("generate@/tmp/fibo.cpp:20").call $this:class Fibonacci* const $n:int
process("/tmp/fibo.exe").function("main@/tmp/fibo.cpp:28").call

Nice - so I'd like to probe/trace the doFibonacciStep and its input argument, istep. So I try from the command line:

$ sudo stap -e 'probe process("/tmp/fibo.exe").function("Fibonacci::doFibonacciStep").call { printf("stap do step: %d\n", $istep) }' -c /tmp/fibo.exe 
WARNING: "__tracepoint_sched_process_fork" [/tmp/stap51A5tV/stap_ab5b824c79b38b5207910696c49c4e22_1760.ko] undefined!
WARNING: "__tracepoint_sys_exit" [/tmp/stap51A5tV/stap_ab5b824c79b38b5207910696c49c4e22_1760.ko] undefined!
WARNING: "__tracepoint_sys_enter" [/tmp/stap51A5tV/stap_ab5b824c79b38b5207910696c49c4e22_1760.ko] undefined!
WARNING: "__tracepoint_sched_process_exec" [/tmp/stap51A5tV/stap_ab5b824c79b38b5207910696c49c4e22_1760.ko] undefined!
WARNING: "__tracepoint_sched_process_exit" [/tmp/stap51A5tV/stap_ab5b824c79b38b5207910696c49c4e22_1760.ko] undefined!
ERROR: Couldn't insert module '/tmp/stap51A5tV/stap_ab5b824c79b38b5207910696c49c4e22_1760.ko': Unknown symbol in module
WARNING: /usr/bin/staprun exited with status: 1
Pass 5: run failed.  [man error::pass5]
Tip: /usr/share/doc/systemtap/README.Debian should help you get started.
$ sudo stap -e 'probe process("/tmp/fibo.exe").function("Fibonacci::doFibonacciStep").call { printf("stap do step: %d\n", $istep) }' -c /tmp/fibo.exe 
ERROR: Couldn't insert module '/tmp/stapmo60OW/stap_ab5b824c79b38b5207910696c49c4e22_1760.ko': Unknown symbol in module
WARNING: /usr/bin/staprun exited with status: 1
Pass 5: run failed.  [man error::pass5]

Ouch, errors like these - not good. The post "__tracepoint_sched_process_fork undefined" when run systemstap script explains that basically the stap version is too old for the kernel that I have - which required the building from source (above). So let's see now how the new stap -L works:

$ /path/to/src/systemtap_git/stap -L 'process("/tmp/fibo.exe").function("*").call'
process("/tmp/fibo.exe").function("_GLOBAL__sub_I__ZN9Fibonacci15doFibonacciStepEi@/tmp/fibo.cpp:37").call
process("/tmp/fibo.exe").function("__do_global_dtors_aux").call
process("/tmp/fibo.exe").function("__libc_csu_fini").call
process("/tmp/fibo.exe").function("__libc_csu_init").call
process("/tmp/fibo.exe").function("__static_initialization_and_destruction_0@/tmp/fibo.cpp:37").call $__initialize_p:int $__priority:int
process("/tmp/fibo.exe").function("_fini").call
process("/tmp/fibo.exe").function("_init").call
process("/tmp/fibo.exe").function("_start").call
process("/tmp/fibo.exe").function("deregister_tm_clones").call
process("/tmp/fibo.exe").function("doFibonacciStep@/tmp/fibo.cpp:13").call $this:class Fibonacci* const $istep:int
process("/tmp/fibo.exe").function("frame_dummy").call
process("/tmp/fibo.exe").function("generate@/tmp/fibo.cpp:20").call $this:class Fibonacci* const $n:int
process("/tmp/fibo.exe").function("main@/tmp/fibo.cpp:28").call
process("/tmp/fibo.exe").function("register_tm_clones").call

Nice, this is already a bit more verbose than the old version. Anyways, I'd like to probe the doFibonacciStep function, and its input argument, here $istep. So I write this on the command line:

$ sudo /path/to/src/systemtap_git/stap -e 'probe process("/tmp/fibo.exe").function("Fibonacci::doFibonacciStep").call { printf("stap do step: %d\n", $istep) }' -c /tmp/fibo.exe 
semantic error: while processing probe process("/tmp/fibo.exe").function("Fibonacci::doFibonacciStep@/tmp/fibo.cpp:13").call from: process("/tmp/fibo.exe").function("Fibonacci::doFibonacciStep").call

semantic error: No cfa_ops supplied, but needed by DW_OP_call_frame_cfa: identifier '$istep' at <input>:1:107
        source: probe process("/tmp/fibo.exe").function("Fibonacci::doFibonacciStep").call { printf("stap do step: %d\n", $istep) }

Pass 2: analysis failed.  [man error::pass2]

Ouch - a nasty error, and doesn't really tell me anything - there are very few bug reports on this error (and mostly from 2010). So I was about to get stuck here, when for some reason, I remembered that the other day, I compiled some programs with -gdwarf-2 (for reasons I've forgotten by now); so I thought I'd try it - and whaddayaknow, it actually started working now:

$ g++ -gdwarf-2 fibo.cpp -o fibo.exe
$ sudo /path/to/src/systemtap_git/stap -e 'probe process("/tmp/fibo.exe").function("Fibonacci::doFibonacciStep").call { printf("stap do step: %d\n", $istep) }' -c /tmp/fibo.exe 
Hello world! Fibonacci series
Enter number of items you need in the series: 5
 Start: a 0 b 1
  istep: 1 c: 1
  istep: 2 c: 2
  istep: 3 c: 3
stap do step: 1
stap do step: 2
stap do step: 3

Nice! Note that the stap prints are actually printed after the program has finished (that is, they are not interleaved with the actual program output where they occured).

Instead of specifying the probe points and behavior directly on the command line, we could write a script instead - so here is check-do-step.stp - here with some extra stuff:

#!/usr/bin/env stap

global stringone = "Testing String One"
global stringtwo = "Testing String Two"

probe begin {
  printf("begin: %s\n", stringone)
  #exit() # must have; else probe end runs only upon Ctrl-C if we only have `begin` and `end` probes!
}

probe process(
  "/tmp/fibo.exe"
).function(
  "Fibonacci::doFibonacciStep"
).call {
  printf("stap do step: %d\n", $istep)
}

probe end {
  newstr = "We Are " . stringtwo . " And We're Done" # string concat
  printf("%s\n", newstr)
}

... and with this script, our call and results look like this:

$ sudo /path/to/src/systemtap_git/stap check-do-step.stp -c /tmp/fibo.exe
Hello world! Fibonacci series
Enter number of items you need in the series: begin: Testing String One
6
 Start: a 0 b 1
  istep: 1 c: 1
  istep: 2 c: 2
  istep: 3 c: 3
  istep: 4 c: 5
stap do step: 1
stap do step: 2
stap do step: 3
stap do step: 4
We Are Testing String Two And We're Done

Notice again - the begin: Testing ... string does not hit at the very start as we'd otherwise expect, but only after the program already started generating output.

Well, I guess this is it - certainly good enough for me, for a simple example...