2012/04/11

Building a Log system for the engine

This is the first in a series of tutorials about programming different pieces of a game engine. I'll be using my own engine, Revolution Engine as a framework for these tutorials, but the code is intended to be easy to adapt to different projects. In this first tutorial we will design and implement a simple but powerful log system for Revolution Engine. The log system is one of the first things you should write for your engine (and for most big projects, in fact).
Let's dive in.

Part I: The design

Requisites:
 - We want our logger to be easy to use. A tool like a logger, which is intended to ease the work of the team, must be easy to use. If a tool is not easy to use, people just won't want to use it.
 - Our engine is intended to be multiplatform, and so has to be the logger. We want our logger to work for as many of our platforms as possible.
 - Easy to activate/deactivate/filter. More on this later.
 - Flexible output. Sometimes we prefer logging to a file, other times, we prefer logging to the terminal, etc...
 - And finally, if possible, we want our logger to be lightweight, not consuming to much cpu-time.

Part II: Defining the interface

In order to keep our tool simple to use, we have to keep it's interface small, simple, and compact.
If you think of it, there are actually two parts in the use of our logger: Configuration and common use.
Configuration is about choosing which logs you want to use, enabling/disabling log, choosing log output method, etc. Common use is all about logging concrete messages.
This is what my log class declaration looks like:


class SLog
{
public:
// Singleton life cycle
static  void init ();
static  void end ();
static  SLog* get ();

public:
// Common use interface
template < class T >
void log ( T _msg, ELogChannel _out );
void newLine (ELogChannel _out);

// Extra management
void enableGlobalLog ();
void disableGlobalLog ();
void enableChannel (ELogChannel _channel);

void disableChannel (ELogChannel _channel);
void flush ();
void setBufferCapacity (unsigned _capacity);

private:
typedef char* messageT; // Channel, message text

bool mEnableGlobal;
bool mEnableChannel[eMaxLogChannel];
rtl::vector mBuffer;
unsigned mBufferCapacity;

private:
// Singleton instantiation
SLog();
~SLog();
static SLog * sInstance;
};

Even though you can see the common use interface is really small, we'll create a couple of wrapping functions to avoid dealing with the singleton every time we want to log something. This has an extra advantage: We can simply define them out as inline void functions for non-debug versions.
#ifdef REV_LOG
template<class T>
void revLog ( T _msg, ELogChannel _channel = eCommon )
{
codeTools::SLog * logger = codeTools::SLog::get();
logger->log(_msg, _channel);
}
template<class T>
void revLogN ( T _msg, ELogChannel _channel = eCommon )
{
codeTools::SLog * logger = codeTools::SLog::get();
logger->log(_msg, _channel);
logger->newLine(_channel);
}
#else // ! REV_LOG
template<class T>
void revLog ( T _msg, ELogChannel _channel = eCommon )
{
_msg; _channel; // Unused variables
}
template<class T>
void revLogN ( T _msg, ELogChannel _channel = eCommon )
{
_msg; _channel; // Unused variables
}
#endif // ! REV_LOG
Notice that we have templatized some parts of the interface. This increases the flexibility of the log system, allowing us to define specific log formats for custom types (e.g. vectors, enemy weapons).

Part III: Log cache

Imagine we set our logger to write logs to a text file. If we wrote a few logs per frame, it would mean we have to access the file in the hard drive a few times per frame, or even many times per frame, thus seriously hurting our engine's performance. Because of this, we're going set an intermediate layer, a log cache, that stores a number of logs, and eventually writes them all at once, saving us a lot of execution time.
The strategy is simple. As you can see in the private part of our SLog declaration, we have a vector of char arrays (a vector of log messages), and a buffer size. The buffer size is the minimun amount of log messages that must be stored so that the system flushes itself, and actually writes them down somewhere. Of course we have direct access to the flush mechanism, so we can flush the system whenever we want. This is useful, for example, when an error raises. If we didn't flush the system, the engine might crash before we got the message saved in the log.

Part IV: Putting it all together

We have now designed our log system and written it's interface. We have also written some wrapper code to provide an easy way to use the system. Only a few more pieces of code need to be written now. For the sake of clarity, I'm not going to write here the code that deals with singleton creation and destruction, and I'm going to omit some error checking code and assertions. To see the real code I use in Revolution engine, you can get an updated version of the code here.
Let's start with the actual log function:
template<class T>
void SLog::log( T _msg, ELogChannel _channel )
{
if(mEnableGlobal && mEnableChannel[_channel])
{
mBuffer.push_back(makeString(_msg));
if(mBuffer.size() >= mBufferCapacity)
flush();
}
}
As you can see, we have a generic, templatized version of the log function, that calls "makeString". That is a useful template function defined in Revolution engine, that  converts different input types into strings. This way, our log system can log all any type supported by the engine. We can add specialized versions of this function for types that we preffer to log in different ways (e.g. for const char * we could simply make a copy of the string and push it into the buffer).

The other important part of the code, is "flush()":

void SLog::flush()
{
for(unsigned i = 0; i < mBuffer.size(); ++i)
{
char * message = mBuffer[i];
#if defined(WIN32) || defined(_linux)
std::cout << message;
#endif // win32 || linux
delete[] message;
}
mBuffer.clear();
}
It's a pretty simple method. On one side, it writes our cached logs to the actual output system (which depends on the platform we're compiling for), and on the other side, it cleans the buffer and deletes old messages.

 

Part V: Some ideas to improve the logger.

There are a few things we can do to improve our logger:
 - First, we could create a platformLogger class that abstracts the flush function from the real writting. This class would have different implementations for different platforms.
- Second, we could use that abstraction layer to let the user select different output methods for each log channel. For example we may want to write error logs to the terminal, but prefer profiling logs in a separate text file.
- Third, we could use a custom allocator for our log messages, storing them in a custom pool. We could use a fixed size pool where we store the messages one after another, separated by '\0' characters. Every time the pool gets filled, we flush our messages and start again. This would probably greatly increase the performance of our log system.

More ideas and suggestions are welcome, I hope you find this code useful.

No comments:

Post a Comment