Logger

Quick start to logging

First log

#include "zupply.hpp" // as usual, include the header
using namespace zz;
...
int main(int argc, char** argv)
{
    auto logger = log::get_logger("default");
    logger->info("Welcome to zupply logger!");
}

Output

[15/09/14 19:26:56.983][T129][default][INFO] Welcome to zupply logger!

Log more in one line

Loggers support three logging styles for convenience.

c++ stream style

logger->info() << "This is " << "style " << 1;

[15-09-14 20:35:32.443][T1][default][INFO] This is style 1

c++ stream style variant

logger->info("This is ") << "style " << 2;

[15-09-14 20:35:32.443][T1][default][INFO] This is style 2

python style

logger->info("Style {}, python style formatter. With placeholder {}, {}", 3, 2.33f, -1.2f);

[15-09-14 20:35:32.443][T1][default][INFO] Style 3, python style formatter. With placeholder 2.33, -1.2

Note

You can chain(<<) or format({}) any type as long as std::stringstream support << it.
Logger will take care of new line characters, so don't bother add one by hand(life saver!).

Control importance levels

Zupply logger support six logging levels which is sufficient for most scenarios:

trace: verbose information that is useful but may slow down execution or messy.
debug: debug information
info: normal message
warn: detected warning information, but program could continue
error: error detected, but allowed to continue
fatal: fatal error, need to abort program

For example:

logger->warn("Some warning here");
logger->info("Normal info");
logger->debug("By default, debug msg appear in debug mode only");
logger->trace("By default, trace msg will not be logged");

Okay, now I only want fatal and error message in this logger, turn off others:

logger->set_level_mask(0x30); // show fatal and error msg only

logger->set_level_mask(log::level_mask_from_string("fatal error")); // use whitespaces to separate levels

Log to file

logger->attach_sink(log::new_simple_file_sink("simple.log", false));
logger->info("Now msg goes to console and simple.log simultaneously!");

Now create a log file with maximum 4M size, and backup all the old contents.

logger->attach_sink(log::new_rotate_file_sink("rotate.txt", 4*1024*1024, true));
logger->info("When file exceed 4M, the content will be cleared, backups will be renamed");

The old backups will be "rotate_yr_month_day-hr_min_sec.txt". In such case, file sizes are controlled, to avoid huge size log file.

Create a new logger for different purposes

auto logger2 = get_logger("test", true); // tell it to create one if not exist
logger2->info("New logger here");
logger2->attach_sink(log::new_simple_file_sink("test.log"));

// you can always get the logger from anywhere
{
    // another code block
    auto l2 = get_logger("test");
    l2->debug("Again! The attached sink is still valid");
    get_logger("test")->info("This is okay, but if you have lots of call, please use the previous version");
}

Note: though you can conveniently get logger at any time, try use a variable to keep the shared_ptr of logger if you call logger frequently. Because get_logger() involves synchronization, which is not free. However, don't be scared, it won't be slow, just a simple performance tip.

Advanced controls

I just showed some simple how-to examples. Actually, the zupply logging module has more than that.

Sinks

Sinks are the direct handler of outputs. Sinks control the flow of files, stdout/stderr, streams.

Each sink has its own level mask for finer control and formatter for message format control.

Currently supported sinks:

Simplefile sink: basic file sink, no size limit. Filename is the name of the logger.

auto sinkPtr = log::new_simple_file_sink("filename.log", truncateOrNot); // false to keep old content, true to truncate

Rotatefile sink: have size limit, automatically rewrite and backup if set. Filename is the name of the logger.

auto sinkPtr = log::new_rotate_file_sink("rotate.txt", maxSizeInByte, backupOldFile);

Ostream sink: log to c++ streams.

std::ostream oss;
auto sinkPtr = log::new_ostream_sink(oss, "streamsink1", autoFlushOrNot);

Stdout sink: derived from ostream sink, but it's unique standard output.

auto sinkPtr = log::new_stdout_sink();

Stderr sink: similar to stdout sink, used for warning/errors.

auto sinkPtr = log::new_stderr_sink();

And asynchronous version of these sinks: TBD. (vc++12 has known bug that will cause deadlock if background thread ends later than main thread, vc14 is good, so I will add these sinks as long as visual studio 2015 become popular).

Control the log level for specific sink

auto sinkPtr = get_sink("simple.txt");
sinkPtr->set_level_mask(0); // now this sink won't produce any msg

Control the log format

auto sinkPtr = get_sink("stdout");
// I want date time only, and add some stuff to stdout
sinkPtr->set_format("[%datetime]{:)} %msg");

Specifiers for formatter:

Specifier	Description
%datetime	current timestamp for this log message
%logger	the logger's name which you called
%thread	thread id, OS dependent
%level	level for this message, e.g. INFO, DEBUG, etc...
%lvl	abbrev for level, e.g. T for trace, D for debug, etc...
%msg	the real message input by user, you should always put it somewhere!
%%	use %% to skip %, e.g. use %% to display %

Change the date time format

Date time format is stored in shared configuration class. To set it, simply use:

// only hour-minute-second
log::LogConfig::instance().set_datetime_format("%H:%M:%S");

Refer to DateTime class for details.

Remove some sinks

You can detach a sink from a specific logger by this:

logger->detach_sink("nameofsink");

or remove it permanently from every logger

log::drop_sink("nameofsink");

Remove all sinks in one logger:

logger->detach_all_sinks();

Remove some loggers

You can remove a logger in storage by this:

log::drop_logger("nameoflogger");

Or remove all loggers

log::drop_all_loggers();

Get the status of all loggers and sinks

Dump the information to a stream:

log::dump_loggers(std::cout); // dump to cout

It will print out the current status of every logger

{
default: <|DEBUG|INFO|WARN|ERROR|FATAL|>
{
StdoutSink->stdout <|DEBUG|INFO|>
StderrSink->stderr <|WARN|ERROR|FATAL|>
SimpleFileSink->log.txt <|DEBUG|INFO|WARN|ERROR|FATAL|>
}
}

Console(stdout and stderr)

By default, stdout and stderr sinks are added to loggers. One can detach it as normal one:

logger->detach_sink("stdout");

or detach them together, which is more practical:

logger->detach_sink("console"); // this is equivalent to call detach stdout/stderr at the same time

Attach them back to one logger:

logger->attach_sink("console"); // back to logger

Config everything in a more "human" way

Zupply log support config from external ini/cfg file. Thus, you can config everything in one step:

log::config_from_file("config_for_my_log.txt");

An example of config file:

# use '#' to comment, or ';' is okay. In appliance to Microsoft ini file.
# key-value pair use '=' or ':', e.g. "a = 1 \n b : 2.5".

[global]
# global settings, for every logger and sink
datetime_format = %y-%m-%d %H:%M:%S.%frac  
format = [%datetime][T%thread][%logger][%level] %msg
levels = info warn error fatal # global default levels
# sink_list is the default sinks that should be added to
# every logger created after config from this file
sink_list = stdout stderr simplefile1 # stdout and stderr are standard, simplefile1 need to be specified later

[loggers]
; In this section, we config for every logger
default.levels = error fatal # default logger only shows error and fatal msg
default.sink_list = rotatefile1 # default logger only log to rotatefile1

myownlogger.levels = debug trace info
myownlogger.sink_list = simplefile1

[sinks]
# here we specify the sinks
simplefile1.filename = simple.txt # filename required
simplefile1.type = simplefile # type required
simplefile1.format = [%datetime] %msg # control its own format

rotatefile1.filename = rotate.log
rotatefile1.type = rotatefile

simplefile2.filename = "simple_not_used.txt"
simplefile2.type = simplefile

After config_from_file(), all the changes will take effect at runtime.

#####Some notes:

Hierarchical "[a]\n[b]\n[c] is equivalent to a.b.c. So you can use global.levels = xxx instead of [global] levels = xxx (Check zupply config parser for more details)
Specific config will overwrite global setting if set, otherwise they have default values
In the previous example, simplefilesink2 is not used by any logger, but it is actually stored, one can get_sink("simple_not_used.txt") later and the settings are kept.
If you use some sink in "sink_list" somewhere, you must specify it in [sinks] section, otherwise program will throw an exception because it doesn't have enough information.

I hate external file, how?

Use previously introduced functions, OR, use std::stringstream instead.

std::stringstream ss;
ss << "global.levels = info error \n" // don't forget \n
   << "global.sink_list = stdout stderr \n"
   ...
   << "\n";
log::config_from_stringstream(ss);

This may become messy, but good for brain saver.

Story behind the logging module

Logging system is the fundamental module in each project as long as you want to log something, whatever it is. The more you use it, the stronger feeling you have that basic fprintf() or iostream is not enough.

What a logger should do

Filter logging levels. For instance, You don't want debug messages in release mode.
Formatting. Process various kind of data type internally, like int, float, etc...
Attributing. Add timestamps, logging level, application name, etc.
Buffering. Using internal buffering techniques to speed up.
Work as an agent. Should be able to control files, streams without specific instructions.

Principles in designing zupply logger in c++

Simple. Users should only care about what to log, loggers take care of the rest.
Convenient. Loggers should support formatting, as well as chain input.
Highly configurable. Easy to config by built-in functions and more importantly, configuration file, such that you can control log output without touching the code.
Hit the point. Loggers should support a basic feature which allow user to log message into multiple outputs simultaneously.
Always available. Treat loggers as resources, when you need it, go get it.
Flexible. We can have multiple loggers
Thread-safe. Either using lock or lock-free mechanics to synchronize among threads.
Concrete. Fulfill the useful functions only, ignore those complicated features, keep it light-weight.

Design

diagram So, the figure shows the basic structure of the logging system.

So what should we expect from this structure:

User log messages from different threads, which is common in multi-threaded program.
We have a logger storage to store multiple loggers, one can retrieve them by get_logger("name").
Each logger may have multiple sinks which directly control the I/O streams and files.
Multiple loggers may link to the same sink, for example, if you want all loggers show message on console, they should all linked to stdout and stderr.
Loggers could reject certain levels of messages.
Sinks have independent levels for finer control of levels.
Each sink have its own formatter for the final message.
All sinks(synchronized/async) are derived from a common interface(polymorphism), so loggers have unified control over them.

Asynchronous sink

Synchronous sinks use mutex to avoid corrupted output. It's not the biggest problem. In fact, using synchronous sinks require each thread to wait for the I/O operation, which is relatively slow.

Alternatively, use a async sink, which has a lock-free queue to store messages, and a background thread to "dump" the message to iostreams. The front-end thread just throw their logs into the queue, and go ahead, leave the background worker to finish its job. It is considered a partial wait-free mechanism, cause "wait" did occur when the queue is full if the worker can't catch up with tons of logs inserted into the buffer.

When logging thousands of message per second to screen, you will notice the performance gap between sync/async sinks. In other situations, they won't make too much difference.

Provide feedback

Saved searches

Use saved searches to filter your results more quickly