Experiences Getting SystemTap work on OLPC Machine

[William Cohen]

Experiences Getting SystemTap work on OLPC Machine

Right now the stock Systemtap does not allow cross compiling of
systemtap scripts between different subarchitectures. The stock
systemtap assumes that the host and target systems are the same
subarchitecture. If the host systemtap is a i686 machine and the
target system is a i586 (olpc machine), the generated kernel module
for the target system has runtime test that determines the module was
built on a different architecture and the systemtap instrumentation
module will fail when trying to initialize the module.  Chris Ball
made a hack that disables the runtime test. There is a systemtap
bugzilla entry that describes the problem in more detail:

http://sources.redhat.com/bugzilla/show_bug.cgi?id=4186


Setup of SystemTap on Host Machine


The existing systemtap-0.5.12-1.fc6 was modified to include the
translate.diff patch in the systemtap bugzilla. This is a very
temporary solution to work around the existing runtime architecture
check. There is no way that this patch will be included in the
upstream systemtap; unsupported instructions may be compiled into the
target code. The systemtap rpm including the translate.diff patch was
built locally on an FC6 machine with:

rpmbuild -ba systemtap.spec --define "fedora 6" --define "dist olpc"

Once built the systemtap and systemtap-runtime rpms were installed on
the host system with:

rpm -ivh systemtap-0.5.12-1olpc.i386.rpm \
systemtap-runtime-0.5.12-1olpc.i386.rpm

The host machine needs the files to map the probe points to kernel
executables and the host machines to be able to build modules for the
target (olpc machine) kernel. The kernel rpms for the olpc machine are
installed on the host machine:

rpm -ivh kernel-debuginfo-2.6.21-20070312.1.olpc.3eca75102a57502.i586.rpm \
kernel-debuginfo-common-2.6.21-20070312.1.olpc.3eca75102a57502.i586.rpm \
kernel-devel-2.6.21-20070312.1.olpc.3eca75102a57502.i586.rpm \
kernel-2.6.21-20070319.olpc1p.3eca75102a57502.i586.rpm

You will need to adjust the /boot/grub/grub.conf to boot the correct
kernel. The installation of the kernel will assume that you will want
to boot the olpc kernel.

At this point modules for the olpc machine can be built on the host
machine with something like the following command:

stap -r 2.6.21-20070319.olpc1p.3eca75102a57502  -k idle1.stp  -m idle1

The "-r 2.6.21-20070319.olpc1p.3eca75102a57502" indicates that the
modules should be used to instrument the kernel for the olpc rather
than the kernel currently running on the host system. The "-k"
idicates that the resulting temporary files should be kept after
systemtap is complete; systemtap normally erases the temporary files.
The "-m idle1" renames the resulting module as "idle1.ko". Systemtap
prints a line listing the directory holding the temporary data and it
looks like the following:

Keeping temporary directory "/tmp/stapXYktsn"

The "/tmp/stapXYktsn/idle1.ko" kernel module can be copied over to the
olpc machine.


Setup of SystemTap on OLPC Machine

To run systemtap kernel modules on olpc machine the hacked systemtap-runtime
module needs to be installed on the olpc machine:

rpm -Uvh systemtap-runtime-0.5.12-1olpc.i386.rpm

The instrumentation needs to be run as root with:

staprun idle1.ko

This particular script attempts to determine the amount of the time
spent in the power saving halted mode. It will run until control-c is
typed on the command line. When control-c is pressed, the script
prints out information about how long it ran, the number of entries
and exits from halt state, and some statistics about the time spent in
halted state. Below is the output of idle1.stp running on a idle
machine running the 314 build and the q2b76 rom:

Starting halt watch
Ran for 60544934 us
entered default_halt 9609
exited default_halt 9609
percent halted: 17
count: 9609
avg_time: 1081
min_time: 3
max_time: 3429
usec                distribution
value |-------------------------------------------------- count
     0 |                                                      0
     1 |                                                      0
     2 |                                                     18
     4 |@                                                   219
     8 |@                                                   295
    16 |                                                     56
    32 |@                                                   279
    64 |                                                    149
   128 |                                                    147
   256 |@                                                   275
   512 |@@@                                                 542
  1024 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@  7605
  2048 |                                                     24
  4096 |                                                      0
  8192 |                                                      0

This data show that the script was run for about 1 minute
(60,544,934us).  There were about 9600 halt entries and exits. The
time actually spent halted is surprisingly small, 17% for the unloaded
machine. The average time spent halted is slightly over
1millisecond. One can see the distribution on the histogram.


The idle1.stp script is a quick and dirty script to look at time spent
in halted state. It won't work on SMP kernels, it has a line based
probe that is fail if the process.c file changes, and doesn't work for
kernels that use alternative idle functions. The script idle1.stp is
below:

# idle1.stp

# This is a simple script to determine how much time is spent with the
# processor actually in the halted mode.

# FIXME the following will NOT work for SMP kernel with multiple processors
# It does not keep track of data by a per processor basis

global entries_halt
global entries_halt_t
global exits_halt
global halt_state

global start_wall_time
global stats_halt

probe begin
{
	printf("Starting halt watch\n");
	start_wall_time = gettimeofday_us();
}

#FIXME The following should not probe based on line number.
# However the safe_halt() is a define rather than a function, so no
# debug information exists for safe_halt()
probe kernel.function("*@arch/i386/kernel/process.c:114")
{
	entries_halt_t = gettimeofday_us();
	++entries_halt;
	halt_state=1;
}

#interrupt is going to get it out of halted state
probe kernel.function("irq_enter")
{
	if (halt_state) {
		halt_state=0;
		exit_halt_t = gettimeofday_us();
		++exits_halt;
		stats_halt <<< exit_halt_t - entries_halt_t;
	}
}

probe end
{
	stop_wall_time = gettimeofday_us();
	runtime= stop_wall_time - start_wall_time;
	printf("Ran for %d us\n", runtime);
	printf("entered default_halt %d\n", entries_halt);
	printf("exited default_halt %d\n", exits_halt);
	/* print out some statistics on how much time spent halted */
	if (@count(stats_halt)){
		printf("percent halted: %d\n", @sum(stats_halt)*100/runtime);
		printf("count: %d\n", @count(stats_halt));
		printf("avg_time: %d\n", @avg(stats_halt));
		printf("min_time: %d\n", @min(stats_halt));
		printf("max_time: %d\n", @max(stats_halt));
		printf("usec                distribution\n");
		print (@hist_log(stats_halt));
	}
}