Post Failure Logging¶

Post Failure Logging is a tool that retrospectively logs information about the execution of a program using an Undo 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 Undo 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 undo log. Use it as follows:

undo log [OPTIONS ...] RECORDING PROBE_FILE

The two mandatory command line arguments are RECORDING, an Undo recording, and PROBE_FILE, a Post Failure Logging probe file.

Replay options¶

--start TIME¶: Start replaying the recording at TIME. If omitted, the recording is replayed from the beginning.

--end TIME¶: Finish replaying the recording at TIME. If omitted, the recording is replayed until the end.

--standard-streams¶: Display the recorded process’s standard output and standard error along with the requested logging.

Command options¶

--command, -x FILE¶: Execute commands from FILE, as if by the source command, after loading the recording.

--eval-command, -ex COMMAND¶

Execute the UDB command COMMAND after loading the recording.

You can specify multiple --command and --eval-command options. They are executed in the order that they are given on the command line.

--init-command, -ix FILE¶: Execute UDB commands from FILE, as if by the source command, before loading the recording.

--init-eval-command, -iex COMMAND¶

Execute the UDB command COMMAND before loading the recording.

You can specify multiple --init-command and --init-eval-command options. They are executed in the order that they are given on the command line.

Symbol options¶

--enc-symbols SYMBOLS¶: Load encrypted symbols from SYMBOLS.

--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.

$ undo log --symbols '.debug/**/*.debug'

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

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

Other options¶

--dry-run, -n¶: Display the list of symbol files that would be loaded by the --symbols or --enc-symbols options and exit.

--help, -h¶: Display help message and exit.

--sw-watchpoints¶: Use software watchpoints when watching expressions. Software watchpoints are unlimited in number but execution is very slow while any watch expressions are active. By default, hardware watchpoints are used, which are fast but very limited in number.

--version, -v¶: Print version information and exit.

Option files¶

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:

undo log @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, undo log logs the value of the variable i.

A probe entry that triggers when a given code line is reached 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.

A probe entry that triggers when the value of an expression changes has the syntax:

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

In this context, every time the breakpoint is reached, the value of EXPRESSION will be monitored from that point until the expression goes out of scope. EXPRESSION can be any expression that would be also be a valid watchpoint in UDB. For examples, see the watch command. ACTION is the command that will be invoked when the expression changes value.

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:

#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 undo log, 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, undo log logs the value of the variable i.

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

$ undo log 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.