3.6 Using a Speculation for Error Analysis

You can use the speculative tracing facility in DTrace to trace data, and then later decide whether to commit the data to a tracing buffer or to discard the data. When a probe fires, predicates allow you to filter out uninteresting events if you know whether an event is of interest at that time. However, in some situations, you might not know whether a probe event is of interest until some time after the probe fires.

For example, if a program is occasionally failing with an error, you might want to examine the code path leading to the error condition. You can write trace data at one or more probe locations to speculative buffers, and then choose which data to commit to the principal buffer at another probe location. As a result, your trace data contains only the output of interest, no post-processing is required, and the DTrace overhead is minimized.

The speculation() function creates a speculative buffer and returns a speculation identifier, which you use in subsequent calls to the speculate() function. Typically, you assign the speculation identifier to a thread-local variable, and then use that variable as a predicate to other probes and as an argument to speculate().

You call the speculate() function before performing any data-recording actions. DTrace directs all the data that you subsequently record in the clause to a speculative buffer. You can create only one speculation per clause.

If a speculative buffer contains data that you want to retain, use the commit() function to copy its contents to the principal buffer. If the speculative buffer contains data that you want to delete, use the discard() function.

For more information, see Speculative Tracing in the Oracle Linux Dynamic Tracing Guide.

In the following D program, errortrace.d, we use a speculation to display the function calls below initialize() in func.php if an error occurs but not otherwise.

Example 3.7 errortrace.d: Print complete trace after one or more errors occur

/* errortrace.d -- Print complete trace after one or more errors occur */

self int indent;

BEGIN
{
  /* Read the name of the function from the command line */
  topfunc =  $1;
}

php$target:::function-entry
/copyinstr(arg0) == topfunc/
{ /* Initialize and start speculation */
  self->errflag = 0;
  self->spec = speculation();
  self->indent += 2;
  self->func = topfunc;
  speculate(self->spec);
}

php$target:::function-entry
/self->spec/
{ /* Add function call to speculation */
  speculate(self->spec);
  self->func = copyinstr(arg0);
  printf("%*s %s()\n", self->indent, "->", copyinstr(arg0));
  self->indent += 2;
}

php$target:::function-return
/self->spec/
{ /* Add function return to speculation */
  self->indent -= 2;
  speculate(self->spec);
  printf("%*s %s()\n", self->indent, "<-", copyinstr(arg0));
}

php$target:::function-return
/copyinstr(arg0) == topfunc && self->errflag == 1/
{ /* Commit speculation if error flag is set */
  commit(self->spec);
  self->spec = 0;
  self->indent = 0;
}

php$target:::function-return
/copyinstr(arg0) == topfunc && self->errflag == 0/
{ /* Discard speculation if error flag is not set */
  discard(self->spec);
  self->spec = 0;
  self->indent = 0;
}

php$target:::error
/self->spec/
{
  speculate(self->spec);
  self->errflag = 1; /* Set error flag if an error occurs */
  printf("%*s PHP error: \"%s\"", self->indent-2, "", copyinstr(arg0));
  printf(" in %s() at line %d of %s\n", self->func, (int)arg2,
         basename(copyinstr(arg1)));
}

Running the program for several seconds produces output such as the following:

# dtrace -c 'php func.php' -s 'errortrace.d' -x nspec=10 '"initialize"'
-> initialize()
  -> heads()
    -> heads()
      -> heads()
         PHP error: "Division by zero" in heads() at line 6 of func.php
        -> tails()
          -> heads()
             PHP error: "Division by zero" in heads() at line 6 of func.php
            -> heads()
            <- heads()
          <- heads()
        <- tails()
      <- heads()
    <- heads()
  <- heads()
<- initialize()
^C

We pass the name of the top-level function initialize as an argument to dtrace, which requires us to protect the string quotes from being removed by the shell. For more information, see Macro Arguments in the Oracle Linux Dynamic Tracing Guide.

The output shows that two errors occurred before the program returned to the initialize() function.

The -x nspec=10 option creates more speculative buffers so that DTrace does not report speculation errors because of a shortage of available buffers.

The error occurs in heads() or tails() when PHP evaluates $i = @(1/(abs($d)-3)); and the value of $d is 3.