One problem which often arises during programming is building a base set of functionality which can be extended by the user, while still being modular enough to make it easy to replace only certain parts of an implementation. I guess everybody of us has faced this problem at least once, and came up with different solutions. There is a really powerful and elegant technique for solving this kind of problem, which is what I want to show today.
We’re going to describe the problem and its solution with the help of a very common task: logging. We’re not concerned about how log messages are dispatched to the different logger implementations, but rather how new logger-classes with completely different functionality are implemented.
Let’s start by looking at the base class for loggers:
class Logger
{
public:
virtual ~Logger(void) {}
virtual void Log(size_t channel, size_t type, size_t verbosity, const SourceInfo& SourceInfo, const char* format, va_list args) = 0;
};
As you can see, it’s nothing more than a very simple base class with one virtual function. The arguments are the log-channel (e.g. “TextureManager”, “SoundEngine”, “Memory”, etc), the type of log (e.g. INFO, WARNING, ERROR, FATAL, ASSERT), the verbosity level, a wrapper around source-code information (file name, function name, line number), and last but not least the message itself in terms of a format string and a variable number of arguments. Nothing spectacular so far.
One possible logger implementation could be the following:
class IdeLogger : public Logger
{
public:
virtual void Log(/*arguments omitted for brevity*/)
{
// format message
// do additional filtering based on channel, verbosity, etc.
// output to IDE/debugger
}
};
The IdeLogger outputs all log messages to e.g. the MSVC output window by using OutputDebugString(). In order to do that, it formats the message in a certain kind of way, applies additional filtering based on the channel, verbosity, etc., and finally outputs the message.
We might want another logger which logs to the console, and one which writes into a file, so we whip up the corresponding source code:
class ConsoleLogger : public Logger
{
public:
virtual void Log(/*arguments omitted for brevity*/)
{
// format message
// do additional filtering based on channel, verbosity, etc.
// output to console
}
};
class FileLogger : public Logger
{
public:
virtual void Log(/*arguments omitted for brevity*/)
{
// format message
// do additional filtering based on channel, verbosity, etc.
// write to file
}
};
Based on experience, this is where the problems begin. Sooner or later, you will want different things:
- A logger which writes to the console, but only filters based on the channel, not the verbosity level.
- You don’t want to filter any messages going into the log-file, because they are a useful tool for post-mortem debugging.
- You want to format your messages slightly different in one of the existing loggers, e.g. I like being able to click on log messages in Visual Studio’s output window because they are formatted like this:
“C:/MyFilename.cpp(20): [TextureManager] (WARNING) Whatever.” - You want a logger sending messages over a TCP socket, but you don’t want to copy existing code.
- One of your clients wants to replace only the filtering mechanism in one of the existing loggers without copy-pasting code.
- One of your clients wants to build a logger which filters only messages of a certain type – again, no copy-pasting of existing code desired.
- A bunch of other things which makes your life as engine programmer harder.
No matter how you twist and turn things around, you’re either going to add a bunch of new virtual functions which can be overridden, copy-paste existing code, dive into the realms of multiple-inheritance galore, whip up some macro mess, or just move things around between the different classes, touching tons of code in the process.
For the Molecule Engine, I really didn’t want to go down that route. I wanted to have a mechanism which makes it easy to define new loggers based on existing functionality without copying any code, and without having to write a new logger implementation each and every time. What I wanted was a mechanism where parts of the implementation could essentially be assembled by writing only a few lines of code.
So how can this goal be achieved? Let’s try by breaking up the thing a logger does into smaller pieces, hopefully finding some orthogonal functionality (called aspects) along the way. A logger essentially:
- Filters the incoming message based on certain criteria.
- Formats the message in a certain way.
- Writes the formatted message to a certain output.
If you think about it, these aspects are completely orthogonal to each other, which means that you can exchange the algorithm for filtering messages with any other without having to touch either the formatting or writing stage, and vice versa.
What we now would like to have is some mechanism for exchanging those aspects with very little amount of code. And here is the solution (in a mix of C++ and pseudo-code):
template <class FilterPolicy, class FormatPolicy, class WritePolicy>
class LoggerImpl : public Logger
{
public:
virtual void Log(/*arguments omitted for brevity*/)
{
Criteria criteria = { channel, type, verbosity, sourceInfo, format, args };
if (m_filter.Filter(criteria))
{
Buffer buffer;
m_formatter.Format(buffer, criteria);
m_writer.Write(buffer);
}
}
private:
FilterPolicy m_filter;
FormatPolicy m_formatter;
WritePolicy m_writer;
};
The above is a very generic logger which passes on the task of filtering, formatting and writing messages to certain policies, which are handed down to the implementation via template parameters. Each policy does only a very small amount of work, but by combining them you can come up with several different logger implementations with only a single line of code. Let’s rewrite our IdeLogger, ConsoleLogger, and FileLogger in terms of policies.
Filter policies first:
struct NoFilterPolicy
{
bool Filter(const Criteria& criteria)
{
// no filter at all
return true;
}
};
struct VerbosityFilterPolicy
{
bool Filter(const Criteria& criteria)
{
// filter based on verbosity
}
};
struct ChannelFilterPolicy
{
bool Filter(const Criteria& criteria)
{
// filter based on channel
}
};
As you can see, each policy takes care of filtering messages based on certain criteria, nothing more.
Now the format policies:
struct SimpleFormatPolicy
{
void Format(const Buffer& buffer, const Criteria& criteria)
{
// simple format, e.g. "[TextureManager] the log message";
}
};
struct ExtendedFormatPolicy
{
void Format(const Buffer& buffer, const Criteria& criteria)
{
// extended format, e.g. "filename.cpp(10): [TextureManager] (INFO) the log message";
}
};
And lastly, the writer policies:
struct IdeWriterPolicy
{
void Write(const Buffer& buffer)
{
// output to the IDE
}
};
struct ConsoleWriterPolicy
{
void Write(const Buffer& buffer)
{
// output to the console
}
};
struct FileWriterPolicy
{
void Write(const Buffer& buffer)
{
// write into a file
}
};
By dissecting the problem into different aspects, we can now implement very small functions called policies, which can be assembled together in any way we wish by using just a single line of code. Examples:
typedef LoggerImpl<NoFilterPolicy, ExtendedFormatPolicy, IdeWriterPolicy> IdeLogger; typedef LoggerImpl<VerbosityFilterPolicy, SimpleFormatPolicy, ConsoleWriterPolicy> ConsoleLogger; typedef LoggerImpl<NoFilterPolicy, SimpleFormatPolicy, FileWriterPolicy> FileLogger;
Take a moment to consider the beauty of this approach. With only 3 filter policies, 2 format policies, and 3 writer policies we are able to come up with 3*2*3 = 18 different implementations, just by using a simple typedef!
Additionally, each part can be replaced separately, so if you e.g. add a NetworkWriterPolicy you can combine it with any other filter or format policy, without having to resort to copy-pasting. And this approach solved our original problems where clients want to replace parts of the implementation, slightly change existing functionality, and more. All of this is now possible with only a very small amount of code.
The possibilities of this approach are pretty much endless. You can assemble the pieces of policies in any way you want, you can even combine small policies into larger ones, like in the following example:
template <class Policy1, class Policy2>
struct CompositeFilterPolicy
{
bool Filter(const Criteria& criteria)
{
return (m_policy1.Filter(criteria) && m_policy2.Filter(criteria));
}
private:
Policy1 m_policy1;
Policy2 m_policy2;
};
typedef LoggerImpl<CompositeFilterPolicy<VerbosityFilterPolicy, ChannelFilterPolicy>, ExtendedFormatPolicy, IdeWriterPolicy> FilteredIdeLogger;
Last but not least, if any combination of policies does not exactly do what you want, you can still implement your own logger by deriving from the Logger base class.
This policy-based design allows us to somewhat emulate aspect-oriented programming, and is used in several places in the Molecule Engine, making development so much easier.
Molecular Musings 
Very nicely explained!
I see one further nice thing about this pattern is that you don’t need any virtual functions at all in your Policy classes.
I wonder if this approach is extensible to situations where you don’t only want to modularly change parts of an entities implementation, but also have different interfaces. Let’s say I want to introduce a new policy, but its virtual function (in your case, Filter) needs some additional parameters. Is there some clever way of parameter packing or whatever to avoid having to reimplement the LoggerImpl class to provide this additional parameter?
Cheers!
Exactly! Not forcing every policy to override virtual functions from a certain interface reduces the amount of code that has to be written, and improves performance – we will see even more benefits when we discuss the memory arenas.
If you want to enhance the class’ interface, you can publicly derive from the policies instead of using composition. That way, you can call functions from LoggerImpl which never even were in the original interface!
>> If you want to enhance the class’ interface, you can publicly derive from the
>> policies instead of using composition. That way, you can call functions from
>> LoggerImpl which never even were in the original interface!
But still you would have to adapt the LoggerImpl class (or derive from it) in order to let it call those new functions, right?
Ah, that’s what you mean. Yes, in this case I see no other reasonable solution other than the one you were talking about, because the original LoggerImpl class doesn’t know about the additional parameters your particular Filter-policy needs.
Pingback: Memory system – Part 5 | Molecular Musings
Hello Stefan!
I’ve been following your blog for some months now and I really like the stuff you post in it!
I’m trying to implement a simple 3D engine as a hobby, at home, and I wanted to add this Logger implementation.
I had no problems under Windows and VisualStudio 2012, but I’m having a lot of trouble under Linux (Clang 3.2, GCC 4.7). The problems are related to va_list. I’m storing the va_list in a Criteria struct like this:
struct Criteria
{
uint32_t channel;
unit32_t type;
uint32_t verbosity;
const SourceInfo& source_info;
const char* format;
va_list args;
};
When compiling this line:
Criteria criteria = { channel, type, verbosity, source_info, format, args };
in Logger::Log(…) I get the following error (Clang 3.2):
error: cannot initialize
a member subobject of type 'unsigned int' with an lvalue of type '__va_list_tag *'
Criteria criteria = { channel, type, verbosity, source_info, format, args };
I was wondering if there is another (portable, safe) way to store the va_list or its information to forward it to the pertinent FormatPolicy. Or if you’ve got any ideas to solve that.
Thank you!
I don’t put va_list in a struct, but rather pass all parameters individually. In the above code I simply omitted the arguments for brevity.
If you want to store va_list in a struct, I think you have to use va_copy(). But I’d recommend against it, ellipsis and va_list are already unsafe enough :).
Indeed! I think I learned it the hard way! 😉
What I ended up doing is passing the format and va_list as function paramenters to FormatPolicy::Format(Criteria&, const char* format, va_list args); This way I don’t need to store the data.
Now I’m trying to figure out the problems with macros… but that’s another story! 😉
Thank you!
Hello Stefan,
I recently started refactoring and overdoing a little logging and debugging framework I did once and just came accross your article. I always wanted to get started with policy based design and overdoing my old logging class based on your approach seems to be a good start for me.
Currently I´m kinda stuck with an architectural problem related to filtering.
If I understood correctly the Criteria struct takes care of storing all related data for filtering (in addition to the formatting data) like the verbose mode, log level, channel etc.
Now in case of the VerbosityFilter, i would implement the filter method like this for example:
struct FilterCriteria {FilterCriteria() : channel(UNDEFINED), loglevel(UNDEFINED), verbosity(UNDEFINED) {}
uint32_t channel;
uint32_t loglevel;
uint32_t verbosity;
};
struct LogLevelFilter {
bool filter(const FilterCriteria& criteria) {
if(criteria.loglevel == UNDEFINED || criteria.verbosity == UNDEFINED) {
return false;
} else if(criteria.loglevel >= criteria.verbosity) {
return true;
} else {
return false;
}
}
};
The verbosity level would be somewhere defined in the code and every time I log something I pass the defined verbosity level to the log() method from the logger. So if if have some static variable or define called VERBOSITY, I would always pass VERBOSITY to log und depending on VERBOSITY and the log level for each log, the log message is displayed or not.
Now coming to the Channelfilter I´m not sure how i should define the channel i want to filter within my Filter.
I dont want to add a channel() method within my logger since only Loggers with the Channerfilter policy are interested in the channel.
I also dont want to do something like this
struct LogSettings {
static uint32_t verbosity;
static uint32_t channel;
};
struct ChannelFilter {
bool filter(const FilterCriteria& criteria) {
if(criteria.channel == UNDEFINED) {
return false;
} else if(criteria.channel == LogSettings::channel) {
return true;
} else {
return false;
}
}
};
because all loggers would be bound to the LogSettings struct and I cannot tell Logger a to only filter by Channel “A” and Logger b to only filter by Channel “B”. This problem does not came into play with verbosity since the verbosity level can be shared by all loggers.
I hope i could state a clear question.
Regards Christian
The solution is quite simple: in your case, why not pass the channel value which is to be filtered against explicitly in the constructor?
For example, you could take each of the policies by const-ref. in the Logger constructor. This allows you to pass whatever values you want to each of the policies, e.g.:
SomeLoggerClass myLogger(SomeOutputPolicy(arg1, arg2), ChannelFilter(channelToBeShown), OtherPolicy(arg1, arg2, arg3));
That’s how I do it in order to pass arguments to policies in all policy-based classes.
Thanks for the quick answer.
I actually already thought about that but somehow discarded the idea because I was still a little focused on my old design. Thanks for clarification 🙂
Alexandrescu should probably appear somewhere around the top of this entry.
Pingback: Using runtime-compiled C++ code as a scripting language: under the hood | Molecular Musings
Great article! But I have a few questions:
1. How size_t i_channel trnasforms to “Texture”; “Mesh” or something else? Is it compile time hashes or different format policies. Maybe. template with parameter
template
struct FormatPolicy { …}
and partial specializations for different channels?
2. About logging system itself. You wrote a wonderful article about Singletonitis. What about log system? Is it global object, singleton or there is tricky solution?
I changed the implementation a bit since this was posted. In its current form, the argument is simply a const char* that only accepts string literals.
The log dispatch takes care of registering loggers, and forwards messages to the registered instances. The dispatch itself is nothing more than a namespace. Loggers use an intrusive linked list so that instances can be added/removed in O(1) without any need for a Singleton, pre-main constructors, or similar.
Hi Stefan,
Sorry for bothering you, but can you post some pseudo code or explain how the log dispatch system / log macro is implemented? I’m really curious and I’m not sure if the way I’ve implemented mine is optimal 🙂
The log dispatch is a namespace that offers functions for logging messages, warnings, errors, etc. It simply forwards the message in question to all registered loggers. Loggers themselves are stored in an intrusive linked list, so there is no need for a singleton, a global std::vector, or similar.
The log macros #define to either a call to any of the functions offered by the log dispatch namespace, or “nothing” (with a bit of extra magic to suppress warnings about unused function arguments and the likes). This ensures that certain logs do not generate *any* instructions in the final executable if I don’t want to.
There are also additional log macros for e.g. logging a message every N-th time, logging only once, etc.
Thanks 🙂 I actually implemented my own IntrusiveListNode container form Doom 3’s source code. Works really well, but the trade-off is that I can’t store it as a POD now, like you do.