ACCU Home page ACCU Conference Page
Search Contact us ACCU at Flickr ACCU at GitHib ACCU at Google+ ACCU at Facebook ACCU at Linked-in ACCU at Twitter Skip Navigation

pinC++ Trivial Logger

Overload Journal #77 - Feb 2007 + Programming Topics   Author: Seweryn Habdank-Wojewódzki
When a fully functional logging subsystem isn't the answer what does one do? Seweryn Habdank-Wojewódzki rolls his own.

Sometimes there is a need to track some results of the program, but we do not want to put them in the output of the program - especially when the program is working either as a server or if we want to observe some results, but not show them in the GUI. There are times we want to debug the program but there are a lot of iterations to perform (such as work on huge data containers, or making many calculations and we would like to observe all iterations).

Of course debuggers support conditional stops, but if we do not exactly know what the conditions are or if there is a problem to set a "stop condition" for the debugger, using a debugger can be problematic. The solution is to equip the application with the logger.

For logging, there are specially designed libraries.

They are equipped with

  • sinks (appenders),
  • filters which need to be configured in runtime but they have to be compiled as library.

These loggers are large (with a potential performance hit), because of existence of parsers for configuration files e.g. written in XML or in the style of UNIX configuration files.

As a simple case, let's consider simple code shown in listing 1 and 2.

 // cont is a huge container e.g. std::list<double>
 // filled with values
 for ( std::list<double>::const_iterator
	 pos = cont.begin();
	 pos != cont.end(); ++pos )
 {
	 // operate on *pos
	 // and we want to observe
	 // if there are any somehow critical values
	 // inside cont
 }
  
Listing 1

 // Let assume that Editbox is a edit box widget
 // where user can put value e.g. for currency like:
 // 120 (by default e.g. in Euro), 120.11EUR,
 // E120, 120.1E and so on.

 // Let assume for simplification that we have
 // a standard string as a result from Editbox.

 std::string val_str = Editbox.get_text();

 // we want to log what users put in the edit box
 // to have an overview about typical
 // errors in writing, or what is a preferable style,
 // maybe string uses UTF-8, and we do NOT expect
 // signs form extended set like "€".

 // let assume that currency is a class
 // that contains information about currency
 // and it has overloaded operator>> and operator<<

 currency value =
 boost::lexical_cast<currency>(val_str);

 // and we want to observe what are the result
 // from currency parser.
  
Listing 2

Why we do not sometimes need big loggers? What do we have to do if we do not need all of that, but only need simple functionality like Log ( variable )? Do we need one logging stream? What if we do not separate levels of logging? And even then sometimes the big loggers' licences do not fit our project. If the code is simple then it has greater possibility to be portable. The solution for this can be the usage of a lightweight logger.

A typical and very rough solution for that problem is to write in every place where we need logger/debugger functionality preprocessor directives such as in listing 3:

 std::string val_str = Editbox.get_text();

 #if defined (DEBUG)
   std::cout << str << std::endl;
 #elif defined (FILEDEBUG)
   file_stream << str <<std::endl;
 #endif

 currency value =
 boost::lexical_cast<currency>(val_str);

 #if defined (DEBUG)
   std::cout << value << std::endl;
 #elif defined (FILEDEBUG)
   file_stream << value <<std::endl;
 #endif
  
Listing 3

It can be seen that there are a lot of lines which are not needed; especially all of the compiler directives. In this simple example, we have 5 lines of code for 1 line of logging functionality. Even if we prepare macro to use Log ( ) instead of file_stream << str <<std::endl; there is still a problem with compiler directives.

In this paper, the author will present a very easy to use logger which solves the problem of compiler directives. The design is based on pointers to the output streams e.g. to the file or to the standard output stream (generally console output). There will be some examples of usage, and some possible extensions. Also, the author compares such a simple construction with other existing (free) logging libraries. In fact, the comparison is more a presentation, because they have much larger functionality - however they are really not lightweight.

In the end, the motivation for preparing ones own logger is that licences of existent loggers may not be suitable for the project and we do not want to extend too much our project.

Construction of the C++ Trivial Logger

We can describe some needs for such a logger.

Assumptions:

  • Activate the logger at compilation time by using a flag. If flag is not set then logger has to be cleaned up from the code or set to the stream which ignores all input;
  • Flag has to switch logger style;
  • Usage as simple as possible;
  • Debugger-like style for debugging purpose;
  • Implement some basic configuration procedure.

The proposed construction of the header file logger.hpp is as shown in listing 4. We can observe that the usage of the std::auto_ptr helps with destroying/closing a file stream and also other streams based on the construction of the proper class [Josuttis99]. The definitions of the Log(name) construct is a very useful function like macro.

Three flags are defined; FTLOG (File Trivial Logger), TLOG (standard stream Trivial Logger) and ETLOG (standard Error stream Trivial Logger), each with different functionality.

 // Copyright (c) 2005, 2006
 // Seweryn Habdank-Wojewodzki
 // Distributed under the Boost Software License,
 // Version 1.0.
 // ( copy at http://www.boost.org/LICENSE_1_0.txt )
 #ifndef LOGGER_HPP_INCLUDED
 #define LOGGER_HPP_INCLUDED

 #include <ostream>
 #include <memory>

 class logger_t
 {
 public:
   static bool is_activated;
   static std::auto_ptr < std::ostream >
	  outstream_helper_ptr;
   static std::ostream * outstream;
   logger_t ();private:
   logger_t ( const logger_t & );
   logger_t & operator= ( const logger_t & );
 };
 extern logger_t & logger();
 #define LOG(name)do {if (logger().is_activated ){\
	 *logger().outstream << __FILE__ \
	 << " [" << __LINE__ << "] : " << #name \
	 << " = " << (name)
	 << std::endl;} }while(false)
 namespace logger_n {
   template < typename T1, typename T2, \
	  typename T3, typename T4 >
   void put_debug_info ( logger_t & log, \
	   T1 const & t1, T2 const & t2, \
	   T3 const & t3, T4 const & t4 )
   {
	 if ( log.is_activated )
	   {
	   *(log.outstream) << t1 << " (" \
		 << t2 << ") : ";
	   *(log.outstream) << t3 << " = " \
		 << t4 << std::endl;
	   }
   }
 }
 #define LOG_FN(name) logger_n::put_debug_info ( \
	logger(), __FILE__, __LINE__, #name, (name) )
 // place for user defined logger formating data
 #define LOG_ON() do { \
   logger().is_activated = true; } while(false)
 #define LOG_OFF() do { \
   logger().is_activated = false; } while(false)
 #if defined(CLEANLOG)
 #undef LOG
 #undef LOG_ON
 #undef LOG_OFF
 #undef LOG_FN
 #define LOG(name) do{}while(false)
 #define LOG_FN(name) do{}while(false)
 #define LOG_ON() do{}while(false)
 #define LOG_OFF() do{}while(false)
 #endif
 #endif // LOGGER_HPP_INCLUDED
  
Listing 4

 // Copyright (c) 2005, 2006
 // Seweryn Habdank-Wojewodzki
 // Distributed under the Boost Software License,
 // Version 1.0.
 // (copy at http://www.boost.org/LICENSE_1_0.txt)
 #include "logger.hpp"
 #if !defined(CLEANLOG)

 #if defined (FTLOG)
 #include <fstream>
 #else
 #include <iostream>
 // http://www.msobczak.com/prog/bin/nullstream.zip
 #include "nullstream.h"
 #endif
 logger_t::logger_t()
 {}
 bool logger_t::is_activated = true;

 #if defined(TLOG)
 std::auto_ptr < std::ostream >
	 logger_t::outstream_helper_ptr
	 = std::auto_ptr < std::ostream > (
	 new NullStream );
 std::ostream * logger_t::outstream = &std::cout;

 #elif defined (ETLOG)
 std::auto_ptr < std::ostream >
	 logger_t::outstream_helper_ptr
	 = std::auto_ptr < std::ostream > (
	 new NullStream );
 std::ostream * logger_t::outstream = &std::cerr;

 #elif defined (FTLOG)
 std::auto_ptr < std::ostream >
	 logger_t::outstream_helper_ptr
	 = std::auto_ptr < std::ostream > (
		 new std::ofstream ( "_logger.out" ));
 std::ostream * logger_t::outstream
	 = outstream_helper_ptr.get();

 // here is a place for user defined output stream
 // and compiler flag

 #else
 std::auto_ptr < std::ostream >
	 logger_t::outstream_helper_ptr
	 = std::auto_ptr < std::ostream > (
	 new NullStream );
 std::ostream * logger_t::outstream
	 = outstream_helper_ptr.get();
 #endif
 logger_t & logger()
 {
	 static logger_t * ans = new logger_t ();
	 return *ans;
 }

 #endif // !CLEANLOG
  
Listing 5

FTLOG forces the logger to put information to the file logger stream (listing 5). TLOG indicates that the logger sends information to the standard output. The logger will put information into the standard error stream if ETLOG is enabled. An interesting event occurs when no flag is chosen, the stream is set to a safe null stream. If a flag is set to CLEANLOG, then all macros are cleaned up.

The code uses the NullStream class defined by Maciej Sobczak [Sobczak (1)].

We can easily observe that such a construction of compiler directives leads to usage that we do not need any more as the Log(name) macro is defined every time. However it is empty do{}while(false) if CLEANLOG flag is set. If there is none of ...TFLAG set, it leads to the creation of the null output stream.

In every file where we need to use the functionality, we need to include logger.hpp and add o the makefile, logger.cpp.

To highlight the problem with the creation of the pointer to the stream in logger.cpp, a simple test case file is created (foo.cpp, listing 6), which has to be included to the example project. In listing 6, the logger is used before it starts in main(). This can lead to a problem when other cpp files in the project use it before the pointer is constructed. The problem is called "static initialization order fiasco". Happily, a solution exists. It is simple in concept, but tricky to perform and of course the author tries to do his best to solve the problem in the code using remarks from the Marshall Cline - Parashift.com website [Parashift].

 #include "logger.hpp"
 struct Foo
 {
	 Foo()
	 {
		 LOG ( "Creation of the Foo object" );
	 }
	 ~Foo()
	 {
		 LOG ( "Destruction of the Foo object" );
	 }
 };
 Foo foo;     #include <string>
  
Listing 6

Usage and results

So, what functionality do we have thanks to the Trivial Logger?

The first observation of the code is that we can easily write Log (var); to log values of the variable which has name var. The result in the logger stream are the contents of __FILE__ [__LINE__] and the actual value stored in var (var = value) - in other words:

     __FILE__ [__LINE__] :  var = value
    

The code uses a natively defined operator << for the considered type, so dependent on that, the operator logs can change. A complete example of usage is shown in listing 6 and 7.

 #include <string>
 #include <utility>

 #include "logger.hpp"

 template < typename T, typename U >
 std::ostream & operator<< ( std::ostream & os,
	std::pair < T, U > const & p )
 {
	 os << "( " << p.first << ", "
		<< p.second << " )";
	 return os;
 }

 int main ()
 {
	 double const a = 1.0;
	 std::string const str = "test";
	 std::pair < std::string, double > p (
		"PI", 3.1415 );
	 std::pair < unsigned long, std::string > q (
		10, "EUR" );
	 LOG ("Trivial logger in main()!");
	 LOG (a);
	 LOG (str);
	 LOG (p);
	 if ( 1 ) LOG (q); else LOG(str);
	 LOG_OFF();
	 LOG ("Trivial logger in main()!");
	 LOG_ON();
	 LOG_FN ("Trivial logger in main()!");
 }
  
Listing 7

After running the example program with the flag FTLOG, new file _logger.out is created and it contains:

 foo.cpp [7] : "Creation of the Foo object"
	= Creation of the Foo object
 main.cpp [20] : "Trivial logger in main()!"
	= Trivial logger in main()!
 main.cpp [21] : a = 1
 main.cpp [22] : str = test
 main.cpp [23] : p = ( PI, 3.1415 )
 main.cpp [24] : q = ( 10, EUR )
 main.cpp (30) : "Trivial logger in main()!"
	= Trivial logger in main()!
 foo.cpp [12] : "Destruction of the Foo object"
	= Destruction of the Foo object
    

If TLOG is set, the same content is written in the console output, respectively for ETLOG flag, standard error output is chosen.

As we can see, we have information stored in the logger output even if the object foo is created before main(). What is very important for debugging and logging static is the construction of the objects. A similar method is presented for the destruction of the foo object.

Also in log file is the highlighted effect of the switching on and off the logger by using LOG_OFF() and switching on by using LOG_ON() - in main() the function LOG() is seen twice; one is put into the logger results.

At the very end of the main.cpp file is the macro LOG_FN() which is more less equivalent to the LOG() macro, but the difference is presented as a change of brackets. This macro also shows how to prepare other formatting functions and macros for Trivial Logger.

Configuration and simple code changes

There is not much configuration opportunity at this stage of the Trivial Logger construction. However, for the user there is available the pointer to the stream instead of the static variable. The pointer gives the opportunity to be changed at runtime. It is also possible to switch off and then switch on the logger, and also it's possible to change formatting style.

In the construction of the logger_t class static fields are used; the class can be redesigned not to use static variables. There has to be some small changes in logger.hpp file - mostly remove the static keywords. There is a larger change to be done in logger.cpp file - the construction of the fields has to be moved to the constructor of the logger_t class - of course with respect to the creation of non static fields of the class. The basic functionality of the logger remains similar - extended functionality in that we can define many different loggers (see in the Further extensions section).

Further extensions

There are many extensions possible. The first one is that the logger is somehow a singleton, so the code can be redesigned to use a singleton design pattern, but it will not be "trivial" [Alexandrescu01].

Other propositions can be to define different streams for different purposes e.g. one for logger other for debugging purpose, another for collecting data from UI to prepare some statistics about usage of the UI. This can be solved by defining in parallel similar macros (with different names) or by using this functionality in the more general concept, what will be not trivial at all if we consider native system logging mechanisms, threads and so on. Static pointers have to be changed to the normal ones.

An interesting extension is that, in fact, Trivial Logger defines pointer to the stream and we could implement other streams to use with a user-defined compiling flag. Interesting examples of such a stream objects are implemented in streamed socket implementation [Sobczak (2)], also FASTreams [Sobczak (3)] and the Boost iostreams Library [Boost].

The last extension concerns the used file name which is fixed as _logger.out. Another possibility is to use function std::tmpnam from the C standard library to generate a temporary file for logging [Dinkumware]. This approach can be useful if we combine the functionality of Trivial Logger and use it in a multi-threaded application but with the separation of the log files for every critical thread. This approach can be treated as second extension, too.

With respect to multi-threaded and or Real-Time systems, logging information can be extended by using time stamps, which informs about a time of the logged value.

Also very simple is EzLogger [Axter]. It is a set of seven (in fact six) headers which are easy to include to the project. It supports levels of verbosity and works on streams, but the overhead is quite heavy for such a simple logger. It also supports changing formatting policy, but it seems to force the user to generate their own policy classes. There is no way to clean up its functionality, so it can not be used just only for debugging purpose.

Some not trivial loggers

More or less all extensions will lead to the construction of a really big logger. As examples of design we can compare: log4cxx, log4cpp and log4cplus [Apache (1)] [Sourceforge (1)] [Sourceforge (2)]. As we can read, all of them are based on Java Log4j project design [Apache (2)].

  • log4cxx is equipped with loggers and they give possible different levels of logging such as (shown with the relation): DEBUG < INFO < WARN < ERROR < FATAL. Additionally, it has different appenders, so the programmer can chose: console output, files, GUI components, remote socket servers, NT Event Loggers, and remote UNIX Syslog daemons.

    The usage is very simple e.g.:

     LOG4CXX_INFO(logger, "Exiting application.");
        

    log4cxx is distributed under the Apache Software License.

  • log4cpp is smaller than log4cxx. However it has extended levels of logging: NOTSET < DEBUG < INFO < NOTICE < WARN < ERROR < CRIT < ALERT < FATAL = EMERG. Unfortunately the documentation is not good enough, so we need to look to the programmers documentation to recognize that appenders are: files, files with set maximal size (logs will rotation of the file contents), standard streams, strings (logging into memory), remote and local Syslog and the default system debugger on Win32 systems.

    The usage is different:

      file_appender.log(log4cpp::Priority::WARN,
            "This will be a logged warning");
        

    log4cpp is released under the GNU Lesser General Public License (LGPL).

  • log4cplus is even smaller than log4cpp. It has some levels: TRACE < DEBUG < INFO < WARN, ERROR < FATAL. Possible appenders are: console output, file, file with set maximal size (similar to log4cpp), file with set time of rotation (file is rolled over at a user chosen frequency), socket, Syslog and NT Event Log and at last NULL.

    The usage of log4cplus is as simply as in log4cxx:

     LOG4CPLUS_WARN(logger, "Hello, World!")
        

    log4cplus is released under the Apache Software License.

To summarize. All of none trivial loggers are: multi-threaded, equipped with many appenders, and they separate logging levels. They contain hierarchical loggers and filters. All support NDC (Nested Diagnostic Context), which is a design technique for loggers in multi-clients and multi-threaded applications to separate events from clients. They can be configured from pure text and/or XML files. They can change configuration in runtime.

The design is copied from Java design style which is very good kind of OO programming, but it is far from modern C++ design. The best documentation is prepared for log4cxx library, other libraries have only documentation of the API, and simple examples of usage.

Acknowledgement

Author would like to give thanks, in alphabetical order, to: Wiktor Adamski, Jedrzej Dudkiewicz, Alan Griffiths, Paul Johnson, Mateusz Loskot, Roger Orr, Ric Parkin and Piotr Wyderski for all remarks which helped improve the code and clarify all problems.

Reference

[Josuttis99] N. M. Josuttis, The C++ Standard Library: A Tutorial and Reference, Addison Wesley Professional, 1999.

[Sobczak (1)] http://www.msobczak.com/prog/bin/nullstream.zip

[Parashift] http://www.parashift.com/c++-faq-lite/ctors.html#faq-10.12

[Alexandrescu01] A. Alexandrescu, Modern C++ Design: Generic Programming and Design Patterns Applied, Addison Wesley Professional, 2001.

[Sobczak (2)] http://www.msobczak.com/prog/bin/sockets.zip

[Sobczak (3)] http://www.msobczak.com/prog/fastreams/

[Boost] http://www.boost.org/libs/iostreams/doc/index.html

[Dinkumware] http://www.dinkumware.com/manuals/?manual=compleat&page=stdio.html#tmpnam

[Axter] http://axter.com/ezlogger/

[Apache (1)] http://logging.apache.org/log4cxx/

[Sourceforge (1)] http://log4cpp.sourceforge.net/

[Sourceforge (2)] http://log4cplus.sourceforge.net/

[Apache (2)] http://logging.apache.org/log4j/docs/index.html

Overload Journal #77 - Feb 2007 + Programming Topics