Logging and Tracing

When you write an application you should use tracing and logging. Tracing means, that you monitor when a function is entered and exited or when a specific statement is executed. Logging means that you output debug messages whereever you like to know what's going on or to signal a user that something is going wrong or right :). Both can be done with this library.

Severity levels

There are different severity levels for debug outputs:

CRITICAL:
- The highest severity level and lowest debug output threshold.
- Should be used when encountering an exception that causes the application to terminate.
ERROR:
- Should be used when an error occurred that can be handled but is worth investigation.
WARNING:
- Should be used when an unexpected but easyly manageable situation occurs.
- Typically, a "normal" user is not interested in WARNINGS.
NOTICE:
- This is the lowest severity level in release mode.
DEBUG:
- Debug outputs. Log messages of this level are only shown in debug mode.
TRACE:
- Trace outputs (created by the MIRA_TRACE macro).
- Log messages of this level are only shown in debug mode.

When a specific severity level for a logger is selected (by using setSeverityLevel, see below), all logging outputs with a lower or equal severity are outputted.

When the program is built in release mode, all DEBUG and TRACE messages will be completely optimized away by the compiler so it won't slow down the application. Messages of different debug levels can be logged by the macro MIRA_LOG(level)

MIRA_LOG(DEBUG) << "This is a debug message";

The macro uses an underlying stream to collect messages and data for the log entry.

int i=5;

MIRA_LOG(NOTICE) << "We have set i initially to '" << i << "'";

This stream is implemented in a thread safe way. This means that first all data is collected and finally the complete stream is serialized as a log entry.

In addition to specifying the maximum log level by compiling the application in debug or release mode, the application log level can be set at runtime.

MIRA_LOGGER.setSeverityLevel(NOTICE);

When setSeverityLevel is called multiple times, always the latest selected severity level will be active.

Again all the MIRA_LOG calls with a higher debug level are optimized out, but in contrast to the release mode optimization this time a single 'if' statement remains. NOTE: Never put important equations or function calls you rely on into the stream of the log macro - if the application log level is below the one of the log call, the statement is never evaluated/called.

MIRA_LOGGER.setSeverityLevel(NOTICE);
// A nice little endless loop since i will never be incremented (DEBUG > NOTICE)
int i=0;
while(i<10)
    MIRA_LOG(DEBUG) << "Now we are at " << i++;

Setting up logging

To use logging in your application all you need to do is include the error/Logging.h header and to register one or more Log Sinks at the logging core class.

#include <error/LogTxtStreamSink.h>
int main()
{
    MIRA_LOGGER.registerSink(LogTxtStreamSink(std::cout));
}

Using different Log Sinks

Log Sinks can be used to output log messages to different destinations e.g files, console or network. You can even add your own custom sink. For console or simple file output the LogTxtStreamSink class can be used. For a more advanced file output with support for log file rotation and daily log files the LogFileSink class should be used.

Formatting the output

The format of the log messages can be adapted to the user's needs. Each Log Sink can have its own output format. The LogSimpleFormatter class acts as a default formatter. The LogCustomizableFormatter class supports user defined formats but you can add your own format class.

LogCustomizableFormatter formatter;
formatter << "[level="
        << LogCustomizableFormatter::Severity() << "] at "
        << LogCustomizableFormatter::Uptime("%f") << " micro-seconds after startup. (\""
        << LogCustomizableFormatter::Message() << "\") in "
        << LogCustomizableFormatter::Function();
LogTxtStreamSink txtSink(std::cout);
txtSink.setFormatter(formatter);

Filtering the output

Each Log Sink can have its own filter that filters out only specific messages. You can add your own filter class or use the LogCustomizableFilter class.

LogCustomizableFilter filter;
filter << (LogCustomizableFilter::Severity<LogCustomizableFilter::EQUAL>(WARNING) |
        LogCustomizableFilter::Severity<LogCustomizableFilter::EQUAL>(CRITICAL));
LogTxtStreamSink txtSink(std::cout);
txtSink.setFilter(filter);

Tracing functions or code blocks

For tracing functions or instructions you can use the two macros MIRA_TRACE and MIRA_LOGTIMER. MIRA_TRACE can be used to trace the program flow of your code. It will create a message at TRACE severity level containing file, line number and function. You can also add more messages and data in the same way as for the MIRA_LOG macro.

MIRA_TRACE;
some code;
MIRA_TRACE << "Before testing";
if (x==y)
    return;
MIRA_TRACE << "We reached here because " << x << " != " << y;

The MIRA_LOGTIMER(level, name, text) macro can be used to trace execution time of your code. A variable with name "name" will be created that logs the text upon construction and destruction at the given level. Additionally the time passed between construction and destruction is logged.

{
    MIRA_LOGTIMER(NOTICE, MyTimer, "Watch it");
    runLengthyOperation1();
    MIRA_PEEKLOGTIMER(MyTimer);
    runLengthyOperation2();
}   // MyTimer gets destroyed here and logs the time consumed since its start

If the timer should end before going out of scope use the MIRA_ENDLOGTIMER(name) macro. Additionally you can have a peek on the timer during its runtime via the MIRA_PEEKLOGTIMER(name) macro.