Post Failure Logging

Post Failure Logging is a tool that retrospectively logs information about the execution of a failed program using a LiveRecorder recording of the program together with a probe file describing the information to log and the conditions under which to log it.

Post Failure Logging enables debugging of applications in settings with Personally Identifiable Information (PII) and Intellectual Property (IP) concerns. Two features of Post Failure Logging make this possible:

  • The ability to load LiveRecorder recordings containing encrypted symbols.

  • A straightforward probe file syntax.

These features allow an engineer to diagnose a failure at a customer site, without complete knowledge of the system being debugged, or access to necessary systems. In such situations the on-site engineer’s lack of specific system knowledge might make a traditional debugging session with UDB impractical. However, provided with probe files written by an experienced engineer off-site, it may be possible to gain some useful insights into why the application is failing.

Usage

The Post Failure Logging functionality is implemented as the program postfailurelog. Use it as follows:

postfailurelog [OPTIONS ...] RECORDING PROBE_FILE

The two mandatory command line arguments are RECORDING, a LiveRecorder Recording, and PROBE_FILE, a Post Failure Logging probe file.

Options

--help, -h

Display help message and exit.

--start TIME

Begin replaying the recording at TIME.

--end TIME

Finish replaying the recording at TIME.

--symbols SYMBOLS

Load symbols from SYMBOLS. This can be specified multiple times, to allow multiple symbol files to be loaded. SYMBOLS can also include wildcards, including recursive wildcards. For example, the following loads every file under the .debug directory with the extension .debug, including those in subdirectories.

$ postfailurelog --symbols '.debug/**/*.debug'

Arguments passed to this option may require quoting to avoid expansion by the shell.

Symbol files will be matched against object files in the recording using the GNU Build ID embedded in the file.

--enc-symbols SYMBOLS

Load encrypted symbols from SYMBOLS.

--dry-run, -n

Display the list of symbol files that would be loaded and exit.

Options and values can be specified in a file, one per line, for example:

--symbols
.debug/**/*.debug
--symbols
.libdebug/**/*.debug

To include such options, pass the filename prefixed with an @ character:

postfailurelog @OPTSFILE

Option files can be mixed with options specified on the command line.

Probe files

Probe files contains rules (probe entries) that specify the events of interest in the recording, and what action to take for each event. For example:

hello.c:12 => log i

This probe entry specifies that when line 12 of hello.c is reached, postfailurelog logs the value of the variable i.

A probe entry has the syntax:

BREAKPOINT => ACTION [ARG, ARG, ..., ARG]

BREAKPOINT can be anything that would also be a valid breakpoint in UDB. For details on breakpoint syntax, see the breakpoint documentation. ACTION is the command that will be invoked when the breakpoint is hit.

Actions

In all cases ARGS is a comma-separated list of expressions. These expressions can be any kind of expression that would be valid in UDB’s current working language, this therefore includes variables, strings, floating-point and integer expressions, etc.

backtrace

Print a backtrace.

call FUNCTION[, ARGS...]

Call FUNCTION passing ARGS. Note: since a recording may not be modified, any side-effects performed by this function will be discarded once the function exits.

fail [MESSAGE]

Print MESSAGE followed by a backtrace, and then exit.

log [ARGS...]

Evaluate and print ARGS.

printf FORMAT[, ARGS...]

Evaluate and print ARGS using FORMAT as a printf() format string.

Examples

Take a simple program, hello.c:

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
#include <stdio.h>

int f(int x, double y)
{
    printf("in function f! x: %d, y: %f\n", x, y);
}

int main(int argc, char *argv[])
{
    int i;
    for (i = 0; i < 5; i++) {
        f(42, 3.14);
    }
    printf("Hello world\n");
}

After it has been compiled, the program can be recorded using live-record:

$ gcc -O0 -g -o hello hello.c
$ live-record ./hello

A probe file must also be supplied to postfailurelog, for example:

hello.c:12 => log i

This probe file contains a single probe entry, which specifies that when line 12 of hello.c is reached, postfailurelog logs the value of the variable i.

Running postfailurelog with this recording and probe file as arguments produces the following output:

$ postfailurelog hello.undo example.probe
[22,425:0x5578242aa1b4  hello.c:12] i = 0
[42,875:0x5578242aa1b4  hello.c:12] i = 1
[43,496:0x5578242aa1b4  hello.c:12] i = 2
[44,117:0x5578242aa1b4  hello.c:12] i = 3
[44,738:0x5578242aa1b4  hello.c:12] i = 4

Each line has the format:

[BBCOUNT:PC BREAKPOINT] OUTPUT

where BBCOUNT is the bbcount, PC is the address of the program counter, BREAKPOINT is the breakpoint, and OUTPUT is the output of the probe entry.

The same output can be produced using the printf action:

hello.c:12 => printf "i = %d", i

printf is a more powerful variant of log and supports the usual kinds of printf() format specifiers, for example:

hello.c:12 => printf "Program invoked with %s: argc = %d", argv[0], argc
hello.c:12 => printf "The value of pi is %.2f", 3.1415926

Since a breakpoint in Post Failure Logging can be any valid UDB breakpoint, conditional breakpoints may also be used, for example:

hello.c:12 if i % 2 == 0 => log i

This probe entry logs the value of i only when it is even.