Tracing and Profiling

From Yocto Project
Jump to navigationJump to search

Tracing and Profiling in Yocto

Yocto bundles a large number of tracing and profiling tools; many of them are available however only in 'sdk' images. So, in order to be able to access all of the tools described here, please first build and boot an 'sdk' image e.g. 

$ bitbake poky-image-sdk-live

This page contains basic information and simple examples to help you get started with each of the tracing and profiling tools available in Yocto. There is no overall structure - each tool is simply listed in alphabetical order. If you'd like to see more involved real-world use cases that show how you might use these tools in concert, see Tracing and Profiling End-to-End Examples.


blktrace

blktrace is a tool for tracing and reporting low-level disk I/O. blktrace provides the tracing half of the equation; its output can be piped into the blkparse program, which renders the data in a human-readable form and does some basic analysis: 

$ blktrace /dev/sda -o - | blkparse -i -

systemtap

SystemTap is a system-wide script-based tracing and profiling tool.


For example, this probe from the SystemTap tutorial [1] simply prints a line every time any process on the system open()s a file. For each line, it prints the executable name of the program that opened the file, along with its pid, and the name of the file it opened (or tried to open), which it extracts from the open syscall's argstr. 

probe syscall.open
{
        printf ("%s(%d) open (%s)\n", execname(), pid(), argstr)
}

probe timer.ms(4000) # after 4 seconds
{
        exit ()
}

Normally, to execute this probe, you'd simply install systemtap on the system you want to probe, and directly run the probe on that system e.g. assuming the name of the file containing the above text is trace_open.stp: 

# stap trace_open.stp

What systemtap does under the covers to run this probe is 1) parse and convert the probe to an equivalent 'C' form, 2) compile the 'C' form into a kernel module, 3) insert the module into the kernel, which arms it, and 4) collect the data generated by the probe and display it to the user.

In order to accomplish steps 1 and 2, the 'stap' program needs access to the kernel build system that produced the kernel that the probed system is running. In the case of a typical embedded system (the 'target'), the kernel build system unfortunately isn't typically part of the image running on the target. It is normally available on the 'host' system that produced the target image however; in such cases, steps 1 and 2 are executed on the host system, and steps 3 and 4 are executed on the target system, using only the systemtap 'runtime'.

The systemtap support in Yocto assumes that only steps 3 and 4 are run on the target; it is possible to do everything on the target, but this section assumes only the typical embedded use-case.

So basically what you need to do in order to run a systemtap script on the target is to 1) on the host system, compile the probe into a kernel module that makes sense to the target, 2) copy the module onto the target system and 3) insert the module into the target kernel, which arms it, and 4) collect the data generated by the probe and display it to the user.

Unfortunately, the process detailed below isn't as simple as 'stap script.stp', but I have created a simple script that does simplify usage quite a bit (see the 'crosstap' script below).

The first thing you need to do is get systemtap on the host system (if you've built an -sdk- Yocto image, the systemtap runtime is already installed and ready to go on the target, nothing to do there). The easiest way to do that is to clone the systemtap repo and build it. You also need to download the latest elfutils in order to compile systemtap.

First, get elfutils from [2] and unpack it e.g. 

$ bunzip2 -c elfutils-0.148.tar.bz2 | tar xvf -

Clone the systemtap repo, and check out a working branch using the commit id matching the systemtap SRCREV in meta/conf/distro/include/poky-default-revisions.inc: 

SRCREV_pn-systemtap ??= "4ab3a1863bf4f472acae7a809bf2b38d91658aa8":

$ git clone git://sources.redhat.com/git/systemtap.git
$ cd systemtap
$ git checkout -b yocto 4ab3a1863bf4f472acae7a809bf2b38d91658aa8
$ ./configure --with-elfutils=../elfutils-0.148 --prefix=/home/trz/systemtap-1.4
$ make install

At this point, (in this example) you have an installed systemtap that you can use to cross-compile probes for the target.

Basically, here's the form of the 'stap' invocation you need to make (using the example of the trace_open.stp script) in order to generate a kernel module to run on the host: 

${SYSTEMTAP_HOST_INSTALLDIR}/bin/stap -gv -a ${SYSTEMTAP_TARGET_ARCH}
-B CROSS_COMPILE="${STAGING_BINDIR_TOOLCHAIN}/${STAGING_BINDIR_TOOLPREFIX}-"
-r ${TARGET_KERNEL_BUILDDIR} -I ${SYSTEMTAP_HOST_INSTALLDIR}/share/systemtap/tapset
-R ${SYSTEMTAP_HOST_INSTALLDIR}/share/systemtap/runtime -m trace_open trace_open.stp

Thankfully, the 'crosstap' script below hides all this, but you do still need to fill in the blanks in the script with with the appropriate values for your system:

  • SYSTEMTAP_HOST_INSTALLDIR is the directory we installed systemtap into (/home/trz/systemtap-1.4 above).
  • SYSTEMTAP_TARGET_ARCH is the arch that will be passed on to the compiler. In the case of emenlow (x86) that's "i386".
  • STAGING_BINDIR_TOOLCHAIN is the location of the toolchain binaries used to compile the target. In my case, with my Yocto base directory at "/home/trz/work/dev", it would be "/home/trz/work/dev/build/tmp/sysroots/x86_64-linux/usr/bin/emen-poky-linux".
  • STAGING_BINDIR_TOOLPREFIX is the prefix the binaries in the STAGING_BINDIR_TOOLCHAIN directory have (look there to see). In the case of emenlow (x86), that would be "i586-poky-linux".
  • TARGET_KERNEL_BUILDDIR is the location of the kernel build directory. In my case (emenlow x86), that's "/home/trz/work/dev/build/tmp/work/emenlow-poky-linux/linux-yocto-stable-2.6.34+git0+d1cd5c80ee97e81e130be8c3de3965b770f320d6_0+aae69fdf104b0a9d7b3710f808aac6ab303490f7-r1/linux-emenlow-standard-build.

Once you know all those values, you can then substitute them into the above invocation (or into the 'crosstap' script below) and you should be able to generate a module (trace_open.ko using the example) that you can then copy over to the target machine and run there: 

$ scp trace_open.ko root@192.168.1.7:trace_open.ko
$ ssh -t root@192.168.1.7 staprun trace_open.ko

You should then see the output of the script in your terminal session. If the script doesn't have an automatic termination condition e.g. after 4 secs, Ctrl-C will terminate it, and print out the information the script generates upon termination (if it does).

You should also clean up by removing the module on the target: 

$ ssh -t root@192.168.1.7 trace_open.ko

The following script, 'crosstap', automates all of the above and makes invoking systemtap scripts on the target a bit easier, but is just an example and is unsupported. Usage is basically the following (again using the above example): 

$ crosstap trace_open.stp root@192.168.1.7

Here's example output from running the above on an emenlow system: 

trz@elmorro:~/stap-tests/cross$ ./crosstap ../scripts/tutorial/trace_open.stp root@192.168.1.7
WARNING: kernel release/architecture mismatch with host forces last-pass 4.
Pass 1: parsed user script and 75 library script(s) using 60404virt/20848res/2056shr kb, in 100usr/10sys/104real ms.
Pass 2: analyzed script: 2 probe(s), 8 function(s), 22 embed(s), 0 global(s) using 210076virt/44108res/2956shr kb, in 430usr/60sys/500real ms.
Pass 3: translated to C into "/tmp/stapQL56Ll/trace_open.c" using 207808virt/46548res/5480shr kb, in 380usr/0sys/383real ms.
trace_open.ko
Pass 4: compiled C into "trace_open.ko" in 1270usr/190sys/2040real ms.
copying stap module trace_open.ko
root@192.168.1.7's password: 
trace_open.ko                                                                      100%  259KB 259.0KB/s   00:00    
executing stap module trace_open.ko
root@192.168.1.7's password: 
ls(1853) open ("/etc/ld.so.cache", O_RDONLY)
ls(1853) open ("/lib/librt.so.1", O_RDONLY)
ls(1853) open ("/usr/lib/libcap.so.2", O_RDONLY)
ls(1853) open ("/lib/libc.so.6", O_RDONLY)
ls(1853) open ("/lib/libpthread.so.0", O_RDONLY)
ls(1853) open (".", O_RDONLY|O_CLOEXEC|O_DIRECTORY|O_LARGEFILE|O_NONBLOCK|O_CLOEXEC)
sh(1823) open ("/etc/passwd", O_RDONLY|O_CLOEXEC|O_CLOEXEC)
hald-addon-stor(1656) open ("/dev/sdb", O_RDONLY|O_LARGEFILE)
hald-addon-stor(1656) open ("/dev/sdb", O_RDONLY|O_LARGEFILE)
hald-addon-stor(1656) open ("/dev/sdb", O_RDONLY|O_LARGEFILE)
Connection to 192.168.1.7 closed.
removing stap module trace_open.ko
root@192.168.1.7's password: 
Connection to 192.168.1.7 closed.

The trace_open.stp script is about as simple a script as you can have (aside from a helloworld.stp script). Just to show that that you can in fact run some pretty interesting and non-trivial scripts, here's the iostats.stp script from the systemtap examples dir, which basically aggregates read/write activity over a period of time: 

#! /usr/bin/env stap
global opens, reads, writes, totals 

probe begin { printf("starting probe\n") }

probe syscall.open {
  e=execname();
  opens[e] <<< 1 # statistics array
}

probe syscall.read.return {
  count = $return
  if ( count >= 0 ) {
    e=execname();
    reads[e] <<< count # statistics array
    totals[e] += count
  }
}

probe syscall.write.return {
  count = $return
  if (count >= 0 ) {
    e=execname();
    writes[e] <<< count # statistics array
    totals[e] += count
  }
}

probe end {
  printf("\n%16s %8s %8s %8s %8s %8s %8s %8s\n",
    "", "", "", "read", "read", "", "write", "write")
  printf("%16s %8s %8s %8s %8s %8s %8s %8s\n",
    "name", "open", "read", "KB tot", "B avg", "write", "KB tot", "B avg")
  foreach (name in totals- limit 20) { # sort by total io
    printf("%16s %8d %8d %8d %8d %8d %8d %8d\n",
      name, @count(opens[name]),
      @count(reads[name]),
      (@count(reads[name]) ? @sum(reads[name])>>10 : 0 ),
      (@count(reads[name]) ? @avg(reads[name]) : 0 ),
      @count(writes[name]),
      (@count(writes[name]) ? @sum(writes[name])>>10 : 0 ),
      (@count(writes[name]) ? @avg(writes[name]) : 0 ))
  }
}

And here's the output of the script using 'crosstap' to run the script on an emenlow target - this output was generated following a fresh boot and browser invocation visiting an external website (notice that this script was terminated using Ctrl-C, at which point the results are printed in tabular form: 

trz@elmorro:~/stap-tests/cross$ ./crosstap ../scripts/iostats.stp root@192.168.1.7
WARNING: kernel release/architecture mismatch with host forces last-pass 4.
Pass 1: parsed user script and 75 library script(s) using 60444virt/20892res/2056shr kb, in 140usr/10sys/164real ms.
Pass 2: analyzed script: 5 probe(s), 2 function(s), 22 embed(s), 4 global(s) using 210232virt/44264res/2952shr kb, in 540usr/50sys/589real ms.
Pass 3: translated to C into "/tmp/staprO74T8/iostats.c" using 207964virt/46724res/5496shr kb, in 330usr/10sys/436real ms.
iostats.ko
Pass 4: compiled C into "iostats.ko" in 1830usr/140sys/2471real ms.
copying stap module iostats.ko
root@192.168.1.7's password: 
iostats.ko                                                                         100%  289KB 289.3KB/s   00:00    
executing stap module iostats.ko
root@192.168.1.7's password: 
starting probe
^C
                                       read     read             write    write
            name     open     read   KB tot    B avg    write   KB tot    B avg
            Xorg        0      392      745     1947        0        0        0
            web2      253      406      249      628      168       86      528
 matchbox-deskto        2      213        6       31        1        0        4
 matchbox-window        0       57        3       66        0        0        0
  matchbox-panel        1       12        2      218        0        0        0
        dropbear        0        4        0       16        3        0       37
  connman-applet        0        2        0       48        0        0        0
          stapio        0       63        0        0        1        0       15
Connection to 192.168.1.7 closed.
removing stap module iostats.ko
root@192.168.1.7's password: 
Connection to 192.168.1.7 closed.

The output of the above two scripts should give you some idea of the power these types of open-ended system-wide queries can provide, and give you a good starting point for your own experimentation.

'crosstap' script: 

#!/bin/bash                                                                     
# usage: crosstap <systemtap script> <user@target-addr>                         
#                                                                               
# NOTE: SYSTEMTAP_HOST_INSTALLDIR, SYSTEMTAP_TARGET_ARCH,                       
# STAGING_BINDIR_TOOLCHAIN, STAGING_BINDIR_TOOLPREFIX, and                      
# TARGET_KERNEL_BUILDDIR must be set to the appropriate host/yocto              
# build-tree paths for this script to work correctly.  The values               
# below are only examples.                                                      

# where systemtap was installed on the host                                     
SYSTEMTAP_HOST_INSTALLDIR="/home/trz/systemtap-1.4"

# i386 for 32-bit x86, arm for arm                                              
SYSTEMTAP_TARGET_ARCH="i386"

# where to find compiler executables, passed on to kernel kbuild                
STAGING_BINDIR_TOOLCHAIN="/home/trz/work/dev/build/tmp/sysroots/x86_64-linux/us\
r/bin/emen-poky-linux"
STAGING_BINDIR_TOOLPREFIX="i586-poky-linux"

# pointer to configured/built kernel tree                                       
TARGET_KERNEL_BUILDDIR="/home/trz/work/dev/build/tmp/work/emenlow-poky-linux/li\
nux-yocto-stable-2.6.34+git0+d1cd5c80ee97e81e130be8c3de3965b770f320d6_0+aae69fd\
f104b0a9d7b3710f808aac6ab303490f7-r1/linux-emenlow-standard-build"

script_name=$(basename "$1")
script_base=${script_name%.*}

${SYSTEMTAP_HOST_INSTALLDIR}/bin/stap -gv -a ${SYSTEMTAP_TARGET_ARCH} -B CROSS_\
COMPILE="${STAGING_BINDIR_TOOLCHAIN}/${STAGING_BINDIR_TOOLPREFIX}-" -r ${TARGET\
_KERNEL_BUILDDIR} -I ${SYSTEMTAP_HOST_INSTALLDIR}/share/systemtap/tapset -R ${S\
YSTEMTAP_HOST_INSTALLDIR}/share/systemtap/runtime -m $script_base $1

echo "copying stap module $script_base.ko"
scp $script_base.ko $2:$script_base.ko

echo "executing stap module $script_base.ko"
ssh -t $2 staprun $script_base.ko

echo "removing stap module $script_base.ko"
ssh -t $2 rm $script_base.ko

For many more examples, and documentation, see [3].

Current status:

For all of the below, the host was an x86_64 system, with systemtap installed on the host as: 

SYSTEMTAP_HOST_INSTALLDIR="/home/trz/systemtap-1.4"
  • x86 - has been tested on actual x86 hardware (emenlow) and everything so far seems to work nicely - all the systemtap tutorial scripts and the systemtap iostats.stp example script worked fine.
'crosstap' variables used (machine = 'emenlow'):
SYSTEMTAP_TARGET_ARCH="i386"
STAGING_BINDIR_TOOLCHAIN="/home/trz/work/dev/build/tmp/sysroots/x86_64-linux/us\
r/bin/emen-poky-linux"
STAGING_BINDIR_TOOLPREFIX="i586-poky-linux"
TARGET_KERNEL_BUILDDIR="/home/trz/work/dev/build/tmp/work/emenlow-poky-linux/li\
nux-yocto-stable-2.6.34+git0+d1cd5c80ee97e81e130be8c3de3965b770f320d6_0+aae69fd\
f104b0a9d7b3710f808aac6ab303490f7-r1/linux-emenlow-standard-build"
  • qemuarm - a 'hello, world' script generated on an x86_64 host worked fine on qemuarm, but other scripts from the systemtap tutorial showed integer truncation complilation errors - arm is probably untested wrt the systemtap project and those problems need to be fixed upstream.
'crosstap' variables used (machine = 'emenlow'):
SYSTEMTAP_TARGET_ARCH="arm"
STAGING_BINDIR_TOOLCHAIN="/usr/local/src/yocto/b/build/tmp/sysroots/x86_64-linux/usr/bin/armv5te-poky-linux-gnueabi/"
STAGING_BINDIR_TOOLPREFIX="arm-poky-linux-gnueabi"
TARGET_KERNEL_BUILDDIR="/usr/local/src/yocto/b/build/tmp/work/qemuarm-poky-linux-gnueabi/linux-yocto-stable-2.6.34+git0+582a28e4bc966ea367cbc2dc1f0de89dd4e7c3d8_0+8cc1674d61d0e0e1bf006164074cffd1071a3a52-r1/linux-arm_versatile_926ejs-standard-build"
Retrieved from "https://wiki.yoctoproject.org/wiki/index.php?title=Tracing_and_Profiling&oldid=498"