In this article, I want to discuss the importance of providing a logging component in your software project. From a very general point of view, any software can be developed in a way that allows the running code to provide a trace of its execution in a log file, then depending on the life phase of the product (development or production), it may be released with a different level of logging set. Having a logger becomes crucial when debugging is not possible or is inconvenient. Under some circumstances, debugging is not possible  for example, because the application runs on specific hardware or the problem is completely unclear. In those cases, collection and analysis of logs is crucial to pinpointing a problem.

At Nokia Siemens Networks, I developed the firmware running on NSN's Base Transceiver Station (BTS). A BTS is very complex hardware driven by impressive firmware. When something does not work (especially in a real network), there is no way to check where the problem traces back other than reading the BTS logs, a common logging platform every subsystem shares with all the other components, which provides prints on different severity levels.

A logger should be effective, efficient, and able to provide clear data. Most importantly, it has to guarantee proper functioning even when the whole system crashes. It makes no sense to write logs if the logger stops running at every crash. The logging platform, like the captain of a sinking ship, must "survive" until the end.

In this article, I develop a small logger that provides two levels of logging and three types of log severity (Error, Warning, and Debug). The code has been used in different projects of different sizes, is thread-safe, computationally lightweight, and easily customizable to work with different log output (to allowing remote logging for example).

Dr. Dobb's has previously published another implementation of a good C/C++ logger (see Logging In C++ and Logging In C++: Part 2). There are few important differences between what you'll see here and that solution. First and most important, the logger discussed here will flush the log messages immediately and will not buffer them, which is crucial when a serious destabilizing event occurs. (The implementation provided in Logging In C++: Part 2 provides the ability to enable or disable a single log print at runtime. The way this feature is implemented is very clever and I encourage you all to take a look at both articles.) Another difference in my implementation is that I use only C++ and STL functionalities (no Boost libraries). To understand the code presented, I expect that you'll be familiar with the variadic template concept of the new C++ standard.

First Look

What a logger should print depends on the kind of application it's written for. In my projects, I've used it to provide at least: the sequential numbering for the logged lines, date, and execution time elapsed since the beginning of the logging period (expressed in ms, it is also very useful to check the execution time for single operations), and some information about the severity of the logged item.

Making a call to the log function should be easy. The logger should be as little invasive as possible, both for the programmer than for the code. If you take a look at Listing One, you'll see how to invoke the logger function just by using the proper c-style macro:

Listing One: logger.hpp.

#ifndef LOGGER_HPP #define LOGGER_HPP #include "log.hpp" static logging::logger< logging::file_log_policy > log_inst( "execution.log" ); #ifdef LOGGING_LEVEL_1 #define LOG log_inst.print< logging::severity_type::debug > #define LOG_ERR log_inst.print< logging::severity_type::error > #define LOG_WARN log_inst.print< logging::severity_type::warning > #else #define LOG(...) #define LOG_ERR(...) #define LOG_WARN(...) #endif #ifdef LOGGING_LEVEL_2 #define ELOG log_inst.print< logging::severity_type::debug > #define ELOG_ERR log_inst.print< logging::severity_type::error > #define ELOG_WARN log_inst.print< logging::severity_type::warning > #else #define ELOG(...) #define ELOG_ERR(...) #define ELOG_WARN(...) #endif #endif

Line 4 shows a static instantiation of the logger class. The logger is a template that needs to be parameterized with a logging policy. In this case, I'm using a file logging policy, which means that all the output of the logger will be directed to a file on the physical disk.

Lines 6-8 and 15-17 are where the logging macros are defined. As you can see, there are two logging levels (the second level may be enabled to have a more verbose output), and three severity levels. The preferred logging level may be enabled or disabled by toggling the LOGGING_LEVEL_x definition. When those macro definitions are absent, a log invocation attempt will be resolved by the preprocessor in the usage of the definitions visible at lines 10-12 and 19-21, which do no logging.

Listing Two shows an example of the logger usage and the relative output:

Listing Two: Example.

#define LOGGING_LEVEL_1 #include "logger.hpp" int main() { LOG("Starting the application.."); for( short i = 0 ; i < 3 ; i++ ) { LOG("The value of 'i' is ", i , ". " , 3 - i - 1 , " more iterations left "); } LOG_WARN("Loop over"); LOG_ERR("All good things come to an end.. :("); return 0; }

Output:

0000000 < Wed Jan 09 12:33:18 2013 - 0000005 > ~ <DEBUG> :Starting the application.. 0000001 < Wed Jan 09 12:33:18 2013 - 0000005 > ~ <DEBUG> :The value of 'i' is 0. 2 more iterations left 0000002 < Wed Jan 09 12:33:18 2013 - 0000005 > ~ <DEBUG> :The value of 'i' is 1. 1 more iteration left 0000003 < Wed Jan 09 12:33:18 2013 - 0000005 > ~ <DEBUG> :The value of 'i' is 2. 0 more iterations left 0000004 < Wed Jan 09 12:33:18 2013 - 0000005 > ~ <WARNING> :Loop over 0000005 < Wed Jan 09 12:33:18 2013 - 0000005 > ~ <ERROR> :All good things come to an end.. :(

The Logging Policy

Listing Three shows the policy interface and the implementation for the file policy, which uses a C++ ofstream to direct the log messages to the disk.

Listing Three: Log policy.

class log_policy_interface { public: virtual void open_ostream(const std::string& name) = 0; virtual void close_ostream() = 0; virtual void write(const std::string& msg) = 0; }; class file_log_policy : public log_policy_interface { std::unique_ptr< std::ofstream > out_stream; public: file_log_policy() : out_stream( new std::ofstream ) {} void open_ostream(const std::string& name); void close_ostream(); void write(const std::string& msg); ~file_log_policy(); };

A logging policy should use a pure abstract class to describe how the interface for the policy works (line 5). This logger "policy" provides functionality related to the log writing, as the logger does not know where its output will be directed: Whether to disk, RAM, or even tunneled by a socket to a remote computer, it just calls a "write" function in the provided policy.