Logging variables

Logging variables from applications with debug information is simple. In general, it is easy to log a variable using the log() probe directive and the variable's "target name." The variable must be logged from a probe in a scope where the variable is visible or you must specify the variable scope in the target expression.

From a probed function you can log parameters, local variables, function-static variables, file-static variables and globals within the same file using the target expression for the variable.

You can log global and static variables from any scope using the target expression modifiers -file or -unit (see examples below).

In most case, the target expression is just the variable name preceded by a dollar sign, for example:

$var
$structvar.field
$structptr->field

For global and file-static variables you may need to use target expression modifiers to locate the variable scope, for example:

$(global-var, "-file file.c")
$(file-static, "-file file.c")
$(powerada-global-var, "-unit sec/pkg")
$(gnat-global-var, "-file pkg.adb")

You can use the apcgen tool generate probes for logging functions, lines, and parameters. Version 4.4.6d of apcgen supports logging locals and globals.

If you don't have debug information in the application, you can still log parameters using positional notation ($1, $2, $3, ...). You can even cast the positional parameters to local types you declare in the probe.

C Example

For this C program:

int global = 1234;

static int file_local = 5678;

void p1(int param)
{
  static int func_static = 9876;

  int func_local = param * 10;

  {
     int block_local = param * 100;

     printf("b = %d\n", block_local);
     global += block_local;
  }
}

The following probe:

probe thread
{
   on_entry
   {
      // This probe not in any scope so we have to use the "-file" modifier to specify the scope. 
      log ("\"global\" = ", $(global, "-file main.c"));
      log ("\"file_local\" = ", $(file_local, "-file main.c"));
   }

   probe "p1"
   {
      // all target expressions are in the scope containing the variable so no modifiers needed.
      on_entry
      {
         log ("\"global\" = ", $global);
         log ("\"file_local\" = ", $file_local);
         log ("\"func_static\" = ", $func_static);
         log ("\"param\" = ", $param);
      }
      on_line(17)
      {
         log ("\"func_local\" = ", $func_local);
         log ("\"block_local\" = ", $block_local);
      }
   }
}

Produces the following output:

"global" = 1234
"file_local" = 5678
"global" = 1234
"file_local" = 5678
"func_static" = 9876
"param" = 1234
"func_local" = 12340
"block_local" = 123400

C++ Example

For this C++ program:

class Rectangle {
    int width, height;
    static int count = 0;
  public:
    void set_values (int,int);
    int area (void);
};

Class static data is not part of the object; it is a global and is referenced using a qualified name, in any function probe like:

probe thread
{
  probe "MyFunction"
  {
    on_entry
    {
      log($("Rectangle::count"));
    }
  }
}

If you're unsure of the full name of a static data item you can use:

  apinfo -d myprog.exe

A class object is always called $this within a method. You can access class member data in a class method like:

probe thread
{
  probe "Rectangle::area"
  {
    on_entry
    {
      log($this->width);  // log one data member
      log(*$this);        // log the whole object
    }
  }
}

If you're unsure of the full method name in class "Class", you can use

  apcgen -L <dll-or-exe> | grep "Class::"

to list all the methods.

Static class methods do not have a $this argument. The arguments of a static class member can be logged like C parameters above.

Ada Example

For an Ada program:

package Pkg is

  function P1(Param : in Integer) return Integer;

  PkgGlobal : Integer := 53;

end Pkg;

with Text_Io;

package body Pkg is

  PkgLocal : Integer := 27;

  function P1(Param : in Integer) return Integer is
    PLocal : Integer := Param * 5;
  begin
    Text_Io.Put_Line("PkgGlobal = " & Integer'Image(PkgGlobal));
    Text_Io.Put_Line("PkgLocal = " & Integer'Image(PkgLocal));
    Text_Io.Put_Line("Param = " & Integer'Image(Param));
    Text_Io.Put_Line("PLocal = " & Integer'Image(PLocal));
    declare
       PBlock : Integer := Param * 3;
    begin
       Text_Io.Put_Line("PBlock = " & Integer'Image(PBlock));
       PLocal := PLocal + PBlock;
    end;
    return PLocal;
  end P1;

The following probe:

probe thread
{
   probe "pkg.p1"
   {
      on_entry
      {
#ifdef _AIX
         // Must specify the PowerAda unit name to access global
         log ("\"PkgGlobal\" = ", $(PkgGlobal, "-unit lib/pkg"));
#else
         log ("\"PkgGlobal\" = ", $PkgGlobal);
#endif
         log ("\"PkgLocal\" = ", $PkgLocal);
         log ("\"Param\" = ", $Param);
      }
      on_line(18)
      {
         log ("\"PLocal\" = ", $PLocal);
         log ("\"PBlock\" = ", $PBlock);
      }
      on_exit
      {
         log ("\"Return\" = ", $return);
      }
   }
}

Produces the following output:

"PkgGlobal" = 53
"PkgLocal" = 27
"Param" = 1234
"PLocal" = 6170
"PBlock" = 3702
"Return" = 9872