Logging Lines

You can use Aprobe to trace the execution of all or part of your program down to the line level. There are several options for doing this:

• a simple custom probe
• a probe generated by apcgen
• the trace predefined probe

Custom Probe

A simple custom probe may be all you need to do a quick trace of a function or two. Given the example program:

#include <stdio.h>

void func1() 
{
   printf("func1\n");
}

void func2() 
{
   printf("func2\n");
}

void func3() 
{
   printf("func3\n");
}

int main(int argc, char **argv)
{
   func1() ;
   func2() ;
   func3(); 

   return 0;
}

you can write a custom probe to log the lines in function "func1" like this:

// Trace all lines in fucntions

probe thread 
{
   probe "func1"
   {
      on_line(all) ap_LogLine;
   }
}

which you would compile, run, and format as follows:

apc -x main.exe my.apc
aprobe -u my.ual main.exe
apformat main.exe

would produce output like:

=======================================
PID: 20197 - Switched to thread #0 whose entry point is extern:"_start()"

@:5 at 15:34:55.997723000 
@:6 at 15:34:55.997730000
@:7 at 15:34:55.997751000

Using apcegen

Aprobe include a tool called apcgen which helps you generate probes for functions. One of the options you can specify for apcgen is to generate function and line tracing probes.

Given the previous example program, you can generate a function and line tracing probe as follows:

apcgen -qlines -x main.exe > mytrace.apc

The probe will trace all functions unless you specify a -p option to limit it. See apcgen for more information.

You compile, run and format this generated probe as you do custom probes:

apc -x main.exe my trace.apc
aprobe -u mytrace.ual main.exe
apformat main.exe

which produces output like:

=======================================
PID: 16134 - Switched to thread #0 whose entry point is extern:"_start()"

[Enter : extern:"main()"
Called from ==> extern:"__libc_start_main()" + 0x00f2 in "libc.so"
 at 15:31:53.384758000
  @:20 at 15:31:53.384774000
  @:22 at 15:31:53.384778000
  [Enter : extern:"func1()"
  Called from ==> extern:"main()" at line 22 (main.c)
   at 15:31:53.384778000
    @:5 at 15:31:53.384782000
    @:6 at 15:31:53.384783000
    @:7 at 15:31:53.384803000
  ]Leave : extern:"func1()"
   at 15:31:53.384805000
  @:23 at 15:31:53.384806000
  [Enter : extern:"func2()"
  Called from ==> extern:"main()" at line 23 (main.c)
   at 15:31:53.384807000
    @:10 at 15:31:53.384812000
    @:11 at 15:31:53.384813000
    @:12 at 15:31:53.384823000
  ]Leave : extern:"func2()"
   at 15:31:53.384825000
  @:24 at 15:31:53.384826000
  [Enter : extern:"func3()"
  Called from ==> extern:"main()" at line 24 (main.c)
   at 15:31:53.384827000
    @:15 at 15:31:53.384832000
    @:16 at 15:31:53.384834000
    @:17 at 15:31:53.384843000
  ]Leave : extern:"func3()"
   at 15:31:53.384845000
  @:26 at 15:31:53.384846000
  @:27 at 15:31:53.384851000
]Leave : extern:"main()"
 at 15:31:53.384852000

Trace Predefined Probe

Aprobe also includes a predefined probe, trace.ual, which provides a very comprehensive tracing facility. The trace.ual predefined probe is also integrated into RootCause for flashier displays.

The trace.ual predefined probe is controlled by a configuration file in which you select which functions you want to trace. For the example program above we might create a configuration file, main.exe.trace.cfg, like:

TRACE "func1"
TRACE "func2"
TRACE "func3"
TRACE "main"

The trace.ual predefined probe does not need to be compiled, so you can just run and format the trace data as follows:

aprobe -u trace main.exe
apformat main.exe

The output will be very similar to the apcgen output.