[ Previous | Next | Contents | Glossary | Home | Search ]
AIX Versions 3.2 and 4 Performance Tuning Guide

Detailed Control Flow Analysis with stem

The stem instrumentation package can trace the flow of control through a wide range of software. It is available on AIX Version 4 systems as part of the Performance Toolbox for AIX. To determine whether stem is available on your system, use:

lslpp -lI perfagent.tools

If this package has been installed, stem is available.

Some of the most significant advantages of stem are:

stem builds instrumented versions of the requested programs and libraries, and stores them in a directory called /tmp/EXE. When the user runs the instrumented program, stem creates a corresponding file called stem_out.

Basic stem Analysis

If we want to analyze the control flow of a simple application program, we would use:

stem -p stem_test_pgm

The output of that command would be:

**********************************************************
Make.Stem does not exist, issuing make for stem_samples.o
make stem_samples.o
Target stem_samples.o is up to date.
******************************************************
The instrumented stem_test_pgm is at /tmp/EXE/stem_test_pgm
Assuming AIX 3.2.5 or later, SVC_string=.sc_flih

The instrumentation of stem_test_pgm was successful, even though the program had been stripped. The instrumented form of the program has been placed in the directory /tmp/EXE. We then enter:

/tmp/EXE/stem_test_pgm

We get a file called stem_out in the current working directory. In this case, stem_out contains:

  Seconds.usecs  TID  Routine Names & Seconds.usecs since entering routine.
767549539.847704   1 ->main
767549539.880523   1           ->setPI
767549539.880958   1           <-setPI  0.000435
767549539.881244   1           ->squareit
767549539.881515   1           <-squareit  0.000271
767549539.881793   1           ->printf
767549539.883316   1           <-printf  0.001523
767549539.883671   1           ->setPI
767549539.883944   1           <-setPI  0.000273
767549539.884221   1           ->squareit
767549539.884494   1           <-squareit  0.000273
767549539.884772   1           ->printf
767549539.885981   1           <-printf  0.001209
767549539.886330   1 <-main  0.038626
767549539.886647   1 ->exit

The call graph captures both calls to functions within the module (setPI and squareit) and calls to the printf subroutine in libc.a. The numbers to the right of the subroutine names represent the elapsed seconds and microseconds between the call and the return.

If we perform the same process on the wc command (/usr/bin/wc), the stem_out file (for a wc of a two-word file) contains:

  Seconds.usecs  TID  Routine Names & Seconds.usecs since entering routine.
767548812.962031   1 ->main
767548812.993952   1           ->setlocale
767548812.995065   1           <-setlocale  0.001113
767548812.995337   1           ->catopen
767548812.995554   1           <-catopen  0.000217
767548812.995762   1           ->getopt
767548812.996101   1           <-getopt  0.000339
767548812.996345   1           ->open
767548812.996709   1           <-open  0.000364
767548812.996953   1           ->read
767548812.997209   1           <-read  0.000256
767548812.997417   1           ->read
767548812.997654   1           <-read  0.000237
767548812.997859   1           ->wcp
767548812.998113   1                        ->printf
767548812.998586   1                        <-printf  0.000473
767548812.998834   1           <-wcp  0.000975
767548812.999041   1           ->printf
767548813.000439   1           <-printf  0.001398
767548813.000720   1           ->close
767548813.000993   1           <-close  0.000273
767548813.001284   1           ->exit

This call graph, obtained almost effortlessly, shows the structure of an AIX command. The calls to setlocale and catopen ensure that the command process is running in the same National Language Support (NLS) locale and with the same message catalog as its parent process.

Although stem-instrumented programs can run in multiple processes, the call graph shows only the flow of control within the primary process.


[ Previous | Next | Contents | Glossary | Home | Search ]