Example: Logging

This example demonstrates the use of slightly more advanced logging facilities in CENA by example.

The program instantiates various logging mechanisms and uses with no specific purpose.

Logs will be written

To disk by using the RotatingFileSink
To the terminal by using the TerminalOutputSink

Available loggers and sinks

We will begin with a brief overview over the 3 big logging classes we will implement in this example.

Filtering logger using stdout

Filtering loggers use a severity to indicate what the minimum log level is an then output the log messages to the terminals standard output facilities.

This tends to be the most common logging facility used.

#include "logging/FilteringMessageLogger.hpp"

Sinked Logger

Sinked loggers build on the previous FilteringMessageLogger, but instead of using <iostream> and stdout, they will direct logmessages to one or more “sinks”. The later define how printing text actually works.

Note

SinkedLoggers can have any number of sinks and they can be added and removed at runtime.

#include "logging/SinkedLogger.hpp"

The simplest conceivable sink is of course again the standard output facilities of the terminal. But they might also be a UART, a file, etc.

#include "logging/TerminalOutputSink.hpp"

Rotating file sinks Logger use files to output the log messages. They will use multiple files in succession, ensuring that logs always use a known fixed size of data on disks.

#include "logging/RotatingFileSink.hpp"

Log Decorators

A recurring use case is having a class that MAY produce logging output in a software, but the use of a logger spamming the command line during testing is commonly not desired. Obviously, we want to pass this log to our class using dependency injection.

The OptionalLoggingDecorator is an decorator pattern that allows you to turn any class into having an ILogger interface. Any CENA log facility can be attached to this class. Here’s an example.

#include "logging/OptionalLoggingDecorator.hpp"

namespace cena = semodia::controlengine::native::osal::logging;

class MyClass : public cena::OptionalLoggingDecorator
{
private:
    unsigned data;

public:
    MyClass()
    :   data(0)
    {
        this->setLogPrefix("MyClass: ");
        return;
    };

    virtual ~MyClass()
    {
        this->info("Destructor called... bye");
        return;
    };

    virtual unsigned increment()
    {
        this->data++;
        this->info("Data is now " + std::to_string(this->data));
        return this->data;
    }
};

MyClass now effectively acts as a logger and will add an additional prefix to any log messages it outputs. The last line, when printed to a terminal, would read

[info] MyClass: Destructor called... bye

Usage examples

Let’s see the different logging mechanisms in action.

int main([[maybe_unused]] int argc, [[maybe_unused]] char** argv)
{

To avoid addressing each class with its full namespace, we use a shortcut here.

using namespace cena;

Simple logging

Simple logging is achieved by instantiating a FilteringMessageLogger and issuing calls to its logging methods. Here we instruct the logger to write a message with the LogLevel::info severity. This logger writes only to the terminal.

FilteringMessageLogger log;
log.info("Hello world");

Sinked Logging

When using sinked logging, we can distribute log messages to multiple output channels, each having its own minimum severity.

First, we create a SinkedLogger object and set its minimum severity to LogLevel::info. This way, this instance does not log any messages having a severity lower than LogLevel::info, i.e. messages with a severity of LogLevel::debug won’t be forwarded at all

Since we intend to share the logger around in our software by dependency injection, we will make the sink shared.

auto logger = std::make_shared<SinkedLogger>(LogLevel::info);

Now we create the sinks and register them in the previously created SinkedLogger instance.

The TerminalOutputSink is straight forward as it does no configuration parameters.

auto stdoutSink = std::make_shared<TerminalOutputSink>();
logger->addSink(stdoutSink, "StdOut", LogLevel::debug);

The RotatingFileSink requires some configuration parameters. Here we set the maximum file size per log file to 1024 bytes, the maximum count of log files to 3, and specify, that the log files should be created in the current working directory with the prefix controlEngine_ and the file ending .log. As the initialization of this logger might fail due to system I/O errors, we need to check, if the creation was successful. If it wasn’t, we cannot register the sink.

std::error_code error;
auto optFileSink = RotatingFileSink::create(error, 512, 3, "./controlEngine_", ".log");
if (!error && optFileSink)
{
    logger->addSink(*optFileSink, "RotatingFileSink", LogLevel::warning);
}

Now we issue a log message to the logger with the LogLevel::info severity. As we registered the TerminalOutputSink with the minimum severity of LogLevel::debug, but not the RotatingFileSink, this message is only forwarded to the former.

logger->info("Logger with multiple sinks says hello");

However, if we send a log message with a severity of LogLevel::debug, the log message is filtered at the level of the Logger itself rather than the sinks, and the message is not forwarded to any sink. Both registered sinks will write these messages.

logger->debug("You can't see me!");

Next up, we issue log messages with a severity of LogLevel::warning. These log messages are forwarded to both logging sinks.

for (std::uintmax_t i = 0; i < 5; i++)
{
    logger->warning("Hello World " + std::to_string(i));
}

Decorating classes as loggers

Let us create a MyClass-instance to show how we can now attach a logger, any logger, to the class. As a matter of fact, let’s create two instances - one with and one without an attached logger.

MyClass thatWillBeSilent;
(void) thatWillBeSilent.increment();

MyClass thisWillSayGoodbye;
thisWillSayGoodbye.assignLoggingFacility(logger);
(void) thisWillSayGoodbye.increment();

Note that both classes will work just fine… but the instance without logger will not output any messages.

    return 0;
}

Source Code

Here’s the complete source code from this example:

#include "logging/FilteringMessageLogger.hpp"

#include "logging/SinkedLogger.hpp"

#include "logging/TerminalOutputSink.hpp"

#include "logging/RotatingFileSink.hpp"

#include "logging/OptionalLoggingDecorator.hpp"

namespace cena = semodia::controlengine::native::osal::logging;

class MyClass : public cena::OptionalLoggingDecorator
{
private:
    unsigned data;

public:
    MyClass()
    :   data(0)
    {
        this->setLogPrefix("MyClass: ");
        return;
    };

    virtual ~MyClass()
    {
        this->info("Destructor called... bye");
        return;
    };

    virtual unsigned increment()
    {
        this->data++;
        this->info("Data is now " + std::to_string(this->data));
        return this->data;
    }
};

int main([[maybe_unused]] int argc, [[maybe_unused]] char** argv)
{
    using namespace cena;

    FilteringMessageLogger log;
    log.info("Hello world");

    auto logger = std::make_shared<SinkedLogger>(LogLevel::info);

    auto stdoutSink = std::make_shared<TerminalOutputSink>();
    logger->addSink(stdoutSink, "StdOut", LogLevel::debug);

    std::error_code error;
    auto optFileSink = RotatingFileSink::create(error, 512, 3, "./controlEngine_", ".log");
    if (!error && optFileSink)
    {
        logger->addSink(*optFileSink, "RotatingFileSink", LogLevel::warning);
    }

    logger->info("Logger with multiple sinks says hello");

    logger->debug("You can't see me!");

    for (std::uintmax_t i = 0; i < 5; i++)
    {
        logger->warning("Hello World " + std::to_string(i));
    }

    MyClass thatWillBeSilent;
    (void) thatWillBeSilent.increment();

    MyClass thisWillSayGoodbye;
    thisWillSayGoodbye.assignLoggingFacility(logger);
    (void) thisWillSayGoodbye.increment();

    return 0;
}