OProfile manual

You must have the source tree available to uninstall OProfile; a make uninstall will remove all installed files except your configuration file in the directory ~/.oprofile.

Before getting into detail about usage, it's probably a good idea to have a quick stroll through an example session (this example is for Intel P6 generation processors, but the process is similar).

First we need to start the profiler running in the background. We need to specify the correct vmlinux file (to allow kernel profiling), and we need to specify what event to count and the counter value. Here I've started with :

opcontrol --setup --vmlinux=/boot/2.4.0ac12/vmlinux --ctr0-event=CPU_CLK_UNHALTED --ctr0-count=600000

opcontrol --start

Here we've enabled counter 0 to count "CPU_CLK_UNHALTED" (number of cycles CPU is not halted) events with a count value of 600,000. This event is useful as profiles resulting generally correspond to time-spent profiles for functions etc.

In this section we describe the configuration and control of the profiling system with opcontrol in more depth.

The opcontrol script provides the following options :

The opcontrol script options used with the --setup option :

This section describes the OProfile Qt-based interface.

The oprof_start application provides a convenient way to start the profiler. Note that oprof_start is just a wrapper around the opcontrol script, so it does not provide more services than the script itself.

It can often be useful to split up profiling data into several different time periods. For example, you may want to collect data on an application's startup separately from the normal runtime data. You can use the simple command opcontrol --save to do this. For example :

opcontrol --save=blah

will create a sub-directory in /var/lib/oprofile/samples containing the samples up to that point (the current session's sample files are moved into this directory). You can then pass this name as, for example, a parameter to op_time to only get data up to the point you named the session.

All post profile tools accept the following options

Oprofpp can be used in three major modes; list symbol mode, detailed symbol mode, or gprof mode. The first gives sorted histogram output of sample counts against functions as shown in the walkthrough. The second can show individual sample counts against instructions inside a function, useful for detailed profiling, whilst the third mode is handy if you're used to gprof style output. Note that only flat gprof profiles are supported, however.

Some interesting options of the post-processor :

op_merge is used to merge samples wich belongs to the same binary image. Its main purpose is to merge samples files created by profiling with --separate-samples. So you can create one samples file containing all samples for a shared library : op_merge/usr/lib/ld-2.1.2.so will create a samples file named }usr}lib}ld-2.1.2.so ready to use with oprofpp or other post-profiling tools. Additionally you can merge a subset of samples files inside one sample file by specifying explicitly the sample files to merge. This allows you to use post-profile tools on shared libs for a subset of applications.

The options allowed are :

You can get a quick look at an overall summary of relative binary profiles using op_time. This utility displays the relative amount of samples for each application profiled sorted by decreasing order of samples count. So with op_time [--option] [image_name[,image_names]] you can get :

/lib/libc-2.1.2.so 19 32.7586%
/usr/X11R6/bin/XF86_SVGA 13 22.4138%
...
/usr/bin/grep 1 1.72414%
/usr/X11R6/lib/libXt.so.6.0 1 1.72414%

If you don't specify any image_name on command line op_time report information about all profiled binary image. You can use shell wildcards like : op_time /usr/bin/*

Options allowed are :

This is an example of how the latency of delivery of profiling interrupts can impact the reliability of the profiling data. This is pretty much a worst-case-scenario example: these problems are fairly rare.

double fun(double a, double b, double c)
{
 double result = 0;
 for (int i = 0 ; i < 10000; ++i) {
  result += a;
  result *= b;
  result /= c;
 }
 return result;
}

Here the last instruction of the loop is very costly, and you would expect the result reflecting that - but (cutting the instructions inside the loop):

$ op_to_source -a -w 10

 /* 9349 0.3788% */
 8048394:       fadd   %st(3),%st
 /* 22858 0.9261% */
 8048396:       fmul   %st(2),%st
 /* 687682 27.86% */
 8048398:       fdiv   %st(1),%st
 /* 1747822 70.81% */
 804839a:       decl   %eax
 /* 17 0.0006887% */
 804839b:       jns    8048394

The problem comes from the x86 hardware; when the counter overflows the IRQ line is asserted but the hardware have features that can delay the NMI interrupt: x86 hardware is synchronous (e.g. can not interrupt during an instruction but interrupt at the end of instruction), there is also a latency when the IRQ line is asserted the hardware can take some cycles to get account; the multiple execution unit and the out of order model of modern x86 family also causes problems. The following shows the same function at source level

$op_to_source -a -w 10 show

double fun(double a, double b, double c)
/* fun(double, double, double) 2468162 100% */
/* 165 0.006685% */
{
        /* 3 0.0001215% */
        double result = 0;
        for (int i = 0 ; i < 10000; ++i) {
                /* 9349 0.3788% */
                result += a;
                /* 22858 0.9261% */
                result *= b;
                /* 687682 27.86% */
                result /= c;
        /* 1747918 70.82% */
        }
        return result;
/* 187 0.007576% */
}

So the conclusion: don't trust samples coming at the end of a loop, particularly if the last instruction generated by the compiler is costly, this case can occur also for each branch in your program. Always bear in mind that samples can be often delayed by a few cycles from its real position. That's a hardware problem and OProfile can do nothing about it.

OProfile uses non-maskable interrupts (NMI) on the P6 generation, Pentium 4, Athlon and Duron processors. These interrupts can occur even in section of the Linux where interrupts are disabled, allowing collection of samples in virtually all executable code. The RTC, timer interrupt mode, and Itanium 2 collection mechanisms use maskable interrupts. Thus, the RTC and Itanium 2 data collection mechanism have "sample shadows", or blind spots: regions where no samples will be collected. Typically, the samples will be attributed to the code immediately after the interrupts are re-enabled.

Often the assembler can not generate debug information automatically. Such example of commonly used assembler is gas and nasm. This means than you can not get a source report unless you manually define the neccessary debug information; read your assembler documentation for how you might do that. The only debugging info needed currently by OProfile is the linenr/filename-VMA association. When profiling assembly without debugging info you can always get report for symbol, and optionally for VMA, through oprofpp -l or oprofpp -L but this works only for symbol with the right attributes. For gas you can get this by

.globl foo
	.type	foo,@function

while for nasm you must use

	  GLOBAL foo:function		; [1]

Note than OProfile does not need the global attribute, but only the function attribute. Users of gas and nasm must find the right way to not declare the foo symbol global if necessary.

Some post-profile tools need only symbol information like basic use of oprofpp, whilst others need debugging information, like op_to_source. The notions of debugging information and symbol information are orthogonal. gcc always creates symbol information even without -g. You should be aware that strip by default remove debug and symbol information. You must use strip -d to strip only debug information. Profiling binaries without symbol information leads to a lot of (no symbol) reported by oprofpp.

Note that the post-profile tools do not use dynamic symbols for shared libraries in the absence of symbol information. These symbol are never stripped but using them has a risk of a misleading profile. Dynamic symbols don't provide enough information to create accurate profiling report, because the symbol size information is lost, and we don't know if a sample is from an exported function or from a static function which come immediately after this exported symbol.

In short, if you want to profile already installed binaries on your system, reinstall them with the proper information, at least with symbol information for basic oprofpp and op_time -l or with full debug information to get annotated source. Unfortunately debug information can be very voluminous. The neeeded debug information for annotated source, line numbers, is only generated at -g2 level.