Tips and patterns

Performance tips

If TZ isn't set to a valid value prior to calling one of the readers, there will be many calls made to stat("/etc/timezone"), which slows things down

Filter and search tips

Some search patterns are significantly faster than others. Some patterns instruct the matcher to ignore entire chunks of records so they are not searched. The pid, _procname(), severity and constant string matchers are much faster than other matchers.

Subsystems in traces

A common feature in logging systems is to have a module/subsystem identifier attached to every log message. In a system where all functions are traced and code-flow is easy to understand, this isn't a particularly useful feature. However, it is possible to implement such behavior. For example

#define MY_LOG(level, mod, ...)  do {enum MODULE module = MODULE_##mod; level(module, ## __VA_ARGS__);} while (0);

int filesystem__open_file(const char *filename)
{
    MY_LOG(DEBUG, FILESYSTEM, "Opening file", filename)
    return open(filename, O_RDONLY);
}

enum module is a enum with a value per every module in the system. The trace readers show the symbolic name of the enum value, and the interactive reader can apply searches/filters specifying a specifiy field name, in this case module. For example, a filter that shows all the traces belonging to module FILESYSTEM would look like this: _(module = MODULE_FILESYSTEM)

Field names

Log entries have the notion of field names. Take for example the following log:

int field_value = calculate_some_value()
INFO("The value of the field is:", field_value);

The trace instrumentor associates the name of the variable field_value with the log field name field_value. This allows searching and filtering based on the value of the field. For example, the expression _(field_value = 5) will match every log entry that has a field named field_value and whose value is 5. Only simple expressions are processed as field names. The following examples do not generate a field name from the passed expression:

INFO("The value of the field is:", field_value + other_value);
INFO("The value of the field is:", &field_value);
INFO("The value of the field is:", field_value->member);

Function parameters are considered field names as well as structure members.