The Logger Template

Now, let's look at the logger template body (Listing Eight), and at the implementation of the support functions that are used by the print operation.

Listing Eight: Logger template body.

template< typename log_policy >
class logger
{
    unsigned log_line_number;
    std::string get_time();
    std::string get_logline_header();
    std::stringstream log_stream;
    log_policy* policy;
    std::mutex write_mutex;

    //Core printing functionality
    void print_impl();
    template<typename First, typename...Rest>
    void print_impl(First parm1, Rest...parm);
public:
    logger( const std::string& name );

    template< severity_type severity , typename...Args >
    void print( Args...args );

    ~logger();
};

Lines 4-9 provide a private function and visible attributes such as log_line_number just to keep track of the current line number; for each print invocation the number will be increased by one. Get_time and get_logline_header are support functions used to format the log message header, and they are implemented in Listing Nine.

Listing Nine: get_time and get_logline_header implementation.

template< typename log_policy >
std::string logger< log_policy >::get_time()
{
    std::string time_str;
    time_t raw_time;
    time( & raw_time );
    time_str = ctime( &raw_time );
    //without the newline character
    return time_str.substr( 0 , time_str.size() - 1 );
}

template< typename log_policy >
std::string logger< log_policy >::get_logline_header()
{
    std::stringstream header;
    header.str("");
    header.fill('0');
    header.width(7);
    header << log_line_number++ <<" < "<<get_time()<<" - ";
    header.fill('0');
    header.width(7);
    header <<clock()<<" > ~ ";
    return header.str();
}

Going back to Listing Eight, at line 10-13, the declaration of print_impl is visible, followed at line 15 by the logger-constructor declaration. Lisiting Ten shows the constructor and destructor bodies.

Listing Ten: The logger constructor and destructor.

template< typename log_policy >
logger< log_policy >::logger( const std::string& name )
{
   log_line_number = 0;
   policy = new log_policy;
   if( !policy )
    {
       throw std::runtime_error("LOGGER: Unable to create the logger instance"); 
    }
    policy->open_ostream( name );
}

template< typename log_policy >
logger< log_policy >::~logger()
{
    if( policy )
    {
       policy->close_ostream();
       delete policy;
    }
}

Note that if the allocation at line 5 fails and it is not possible to create a log_policy object, then a std::runtime_error is thrown. As previously explained, no exception handling is performed here — after all, if this small logger is not able to allocate the amount of memory required by log_policy, then something very weird is happening.

Conclusion

The simple logger described in this article can be used easily in any project to track code behavior during runtime, I think that its Achilles' heel is actually the need to lock the writing mutex in the print function. From one perspective, this is unavoidable because not all operating systems are able to provide atomic stream operations, but it introduces a source of inefficiency.

I think that a good logger should always provide a near constant execution time in any circumstance, which is problematic when threads might have to wait for mutexes to be released. However, in practice, unless numerous threads are logging, the operations are fast enough that there is no significant delay.

The source code for this article was tested with g++ 4.7.2 and requires the C++11 multithread functionality support to work properly; refer to http://tehsausage.com/mingw-std-thread-gcc-4-7 if you get into trouble when compiling this project.

Filip Janiszewski has been a Fault Coordinator at Nokia Siemens Networks since 2011.