Simple STL Logging System

Published May 14, 2009 by Brook Jensen, posted by Myopic Rhino
Do you see issues with this article? Let us know.
Advertisement

A Brief Introduction
I thought I would start off my first article with something simple, yet something that might prove useful to the average programmer. In this article, I will explain how to use Boost and a couple of its libraries to implement a simple logging system that works directly with the STL clog output stream, so that you can simply use: std::clog << "Your text here"; and make use of these features.
A Note on Boost
Boost is a third party library and not included with C++. If you are running Windows and Visual C++ you can download an installer at http://www.boostpro.com/products/free. I am currently using version 1.36.0. If you don't understand please go to http://www.boost.org to find instructions. Note: even with the installer you must still configure your C++ directories to find the include and lib files for Boost.
Boost IOStreams
The first Boost library we will be dealing with is the IOStreams library. This nice little library allows speedy development of streams (like cout, cin, clog, cerr). The first step of our custom logger is to create our own stream class, called CLogger which will handle all the features we will add. For now, let's just make our class print to the screen. Firstly, include these headers in your project. #include //Sink stuff #include //IOStream stuff Making a simple output stream is easy. You just need to make a class that declares the type of characters used (in our case, char's), the type of stream (ours is output or a "sink") and any read/write functions that the class uses. Observe the basic class below: class CLogger { public: //Sink information typedef char char_type; //Defines char as the character input type typedef boost::iostreams::sink_tag category; //Declares that this class is a "sink" i.e. Output stream //Writes n characters from s std::streamsize write(const char* s, std::streamsize n) {} }; Very simple implementation. Now, let's put a simple body in the write function that uses cout to output to the screen. //Writes n characters from s std::streamsize write(const char* s, std::streamsize n) { //Write data std::cout.write(s, n); return n; } Basically, just print the char buffer s to the screen. We have to return the amount of chars written, so we'll just assume cout printed all of them and return n, the amount of chars we were told to print. In order to test our stream, we have to use the Boost iostream library to "transform" our little class into something like cout. This is accomplished with a simple typedef line:

typedef boost::iostreams::stream logstream; Now, to use our stream in programming - just initiate an instance of the stream class and do cout-like things: logstream mylogger; //Remember to pass argument to the "something" variable mylogger.open(CLogger()); //This is used to "open" the stream given an instance of our logging class mylogger << "This is some text" << std::endl << "And another line" << std::endl; See, just like any other stream. Every call to << just sends the data to our write function.
Sinks and Sources
I said earlier that in our class we were using the characteristics of a sink. In Boost, streams are classified in three ways. They are either a sink, a source or both. A "source" means that the stream is a "source" of input, or a read stream. Such examples of read streams you probably know are cin and ifstream. Both these streams read data via a read function and optionally reading operators such as >>. A sink is a stream that outputs data, like a sink outputs water. Some streams from the STL like this are cout and ofstream. Both these streams take data and put them somewhere else, such as a screen or a file, via functions such as write and the output operators <<. A mix is simply a stream that has both characteristics. Now by putting the typedef boost::iostreams::sink_tag category, we defined a class called category that is the same type as sink_tag. When Boost uses our class, it looks for the class called category inside and checks out some of its members to deduce what the stream is built for. In the case of sink_tag, it tells Boost that our class has a function called write that writes data outbound, and it knows to generate all the << operators for different types to accommodate a sink type system. If you wish to make a source, consult the Boost documentation to learn how.
Customizing
Now that we have a working log stream, we can customize it to do as we please with the incoming data. First of all, let's add a time entry in front of every log entry. For this we will use Boost's POSIX time extension (I like Boost). Add the following header to your headers (wherever you put them) #include //Date time stuff Now, let's modify our write function to use a handy function to get a string with the POSIX time+date in it for logging. //Writes n characters from s with the date std::streamsize write(const char* s, std::streamsize n) { //Get current universal time from the POSIX second clock boost::posix_time::ptime t(boost::posix_time::second_clock::universal_time()); //Format that time as a simple string std::string time = boost::posix_time::to_simple_string(t); //Write the time out std::cout << "[" << time.c_str() << "] "; //Write incoming data std::cout.write(s, n); return n; } As seen, we use one of the Boost time functions to get the current time, then convert it into a string. This string is then outputting before our log string in [] brackets. The result looks like this: [2009-Jan-05 23:49:42] Creating worker thread 9

Now that we have a basic framework, let's integrate this into the std::clog stream. This task is actually incredibly easy. One simply must redirect the clog stream into an instance of the logstream we defined in the typedef. This simple code at the beginning of the program does that very easily:

//Setup logging logstream logger; mylogger.open(CLogger()); std::clog.rdbuf( logger.rdbuf() ); std::clog << "Logging system engaged" << std::endl; The rdbuf line simply does a redirect. As long as logger is not destroyed via deconstructor, the program will run without error. Now every instance of clog anywhere in your program will redirect into logger, regardless of what thread it's in. Useful no?
Extras
I thought I'd include another little idea I used in my logging system. My program has multiple threads running in it, and I thought it would be cool if the logger would show what thread was calling it. To do this I used yet another Boost feature (Yes, Boost is awesome isn't it?) called thread_specific_ptr. This little class does a very simple task. It's like a normal pointer except for the interesting concept that it is thread independent. So it has different values in different threads as you set it. Basically I will use it to hold a string and call it thread_name. This way each thread can set thread_name to whatever it wants to be called, and then the logging class will output it. I just put a global instance right above my logging class. Make sure to add the following header first though: #include //Thread specific storage And here is the variable: //Thread's name static boost::thread_specific_ptr thread_name; Now that we have the variable, it can be set to a string by use of the following code (for those familiar with Boost, it is basically an instance of shared_pointer). //Set thread name thread_name.reset( new std::string("Main Thread") ); Basically the .reset function changes the value of the pointer to a different pointer. In this case we make a new string class and initialize it to "Main String". So for each thread you create you must initialize the value in this way, otherwise it will cause a runtime error because there is no value set and when the logger tries to read it, it will be very unhappy. Now, let's change our logging write function: //Writes n characters from s with the date and thread std::streamsize write(const char* s, std::streamsize n) { //Get current universal time from the POSIX second clock boost::posix_time::ptime t(boost::posix_time::second_clock::universal_time()); //Format that time as a simple string std::string time = boost::posix_time::to_simple_string(t); //Write time and thread name std::cout << '[' << time << "] report from thread " << *thread_name << " - "; //Write incoming data std::cout.write(s, n); return n; } As seen, we just use the * operator to dereference thread_name into a string (just like normal pointers). Now the output looks like this: [2009-Jan-05 23:49:42] report from thread Main Thread - Creating worker thread 9

One might notice running this example with a few threads that the threads will actually overwrite each other. One thread will start writing a message but the CPU switches to a new thread and that starts writing and so on, causing a jumble if more than one thread is writing. This is solved by a friendly (yes, Boost) class called a "mutex." Basically a mutex just sections off an area of code such that only one thread can be inside at a time, and others must wait to enter until the first one is done - almost like a gate. I won't go into detail on this, as it is not the topic of the article, but it is used like this:

boost::mutex mymutex; //... boost::mutex::scoped_lock lock(mymutex); //Locks down so none can enter until unlocked //Do code here lock.unlock(); //Thread is done here, allow another thread to "lock in" Basically I made a static mutex variable in the CLogger class in the example and then create instances of scoped_lock using that mutex to lock it down. I use scoped_lock here because it was designed to be exception safe, so if an exception is thrown or something else happens it will automatically be destroyed and unlock the mutex.
Source
I've included for download 3 cpp files that demonstrate what is done here. Written in either STL or Boost they are platform independent. Just do whatever you would do for console applications and compile them. Each runs on its own:
  • Logging1.cpp - Basic write function and hooking into std::clog
  • Logging2.cpp - Adds support for posting the timestamp into logs
  • Logging3.cpp - Adds a thread name to the loggings
Source Download: http://brwarner.co.cc/articles/STLLogSource.zip
Conclusion
So now you have the tools to do anything you want. I have provided a few examples you can use to build your own framework. With Boost IOStreams you have unlimited possibilities in regards to what you can do with log data, and all from the comfort of your friendly std::clog class. If you edit it, your other files don't even need to recompile because they will only be exposed to clog, and don't even know the logger exists. You can also add more data to your logging, or manipulate log data, or even redirect to some other output like a file or a text box control or whatever you see fit. I also encourage you to continue to look into the Boost library for some very neat functions, such as their networking library (very nice platform -independent interface for sockets/TCP/ports) and other thread functions that they offer. For a complete documentation of all the Boost libraries, visit their documentation at http://www.boost.org/doc/libs/1_36_0 (for version 1.36.0).

Well, until next time,

Brook "Brwarner" Jensen - Hobbyist Programmer (Brwarner's Server)

Cancel Save
0 Likes 0 Comments

Comments

Nobody has left a comment. You can be the first!
You must log in to join the conversation.
Don't have a GameDev.net account? Sign up!

With programs becoming larger and larger with more and more code, having a detailed logging system can make the difference between hours of searching for code, and knowing the exact place to go to fix a bug in minutes. This article explores the use of the very handy IOStream library included with boost to outfit the familiar clog class with the tools to include as much usefull details as possible, without even changing your code.

Advertisement
Advertisement