Note: You can find the source code for the bit flag logger generator on Github.

The logging system I wrote for Metric Panda Engine uses bit masks to support arbitrary composition of logging categories like so:

  Log(INFO, "One");                  // Outputs: [INFO ][         ][    ] One
  Log(ERROR|CATEGORY1, "Two");       // Outputs: [ERROR][CATEGORY1][    ] Two
  Log(CATEGORY1|CAT2, "Three");      // Outputs: [     ][CATEGORY1][CAT2] Three

The Log macro takes a bit mask that is used to filter log messages based on a verbosity mask. The log message, in this case a simple printf, is prepended with a prefix that is generated from the bit mask.

Category labels used in the log prefix are resolved at compile time, when building in optimized mode, and the only branch is on the verbosity bit-mask.

Why bit masks

Other than the fact that, in my opinion, the API is quite comfortable, using bit masks makes pinpoint filtering much easier.

For example, in Metric Panda Engine I use three log categories, with labels along these lines:

• Severity: VERBOSE, INFO, WARN, ERROR
• Subsystem: AUDIO, RENDER, NET, INPUT, …
• Subcategory: INIT, SHUTDOWN, DRAW, SAMPLE, …

When investigating a particular subsystem, it is quite easy to filter only events related to it, for example by setting the verbosity mask to RENDER|INIT messages of any severity coming from the initialization part of the rendering subsystem are shown.

Name collisions

In order to keep category labels short and easy to type, while also avoiding name collisions, the Log macro looks like this:

enum
{
  LOG_VERBOSE        = 1 <<  0,
  LOG_INFO           = 1 <<  1,
  LOG_WARN           = 1 <<  2,
};

#define Log(Flags, ...) \
{ \
  enum { \
    VERBOSE    = LOG_VERBOSE, \
    INFO       = LOG_INFO, \
    WARN       = LOG_WARN, \
  }; \
  ... \
}

As you can see, the short labels are “aliases” to longer equivalents with the LOG_ prefix. The shorter labels are confined to the scope of the macro so they don’t leak out causing collisions.

Unfortunately collisions can still occur if macros in the outer scope have the same name as the short labels, like the following example:

#define INIT(X) 
// ...
  Log(INFO|RENDER|INIT, "Setting up XYZ"); // This won't compile

Fortunately the collision is detected at compile time, so it can be easily fixed by changing the conflicting log label. In Metric Panda Engine I removed all external includes so I have the luxury of using concise names without fear of collisions.

Filtering log entries

Filtering is done by wrapping the actual logging function in an if statement like so:

#define Log(Flags, ...) \
  ... \
  if ((Flags) & GlobalVerbosity) { \
    DoTheLogging(...); \
  } \
}

The GlobalVerbosity variable is an integer that can be set to the desired bit mask. Since the GlobalVerbosity is set outside the macro, the longer version of the log labels are used, like so:

int GlobalVerbosity;

int main()
{
  GlobalVerbosity = LOG_INFO | LOG_RENDER | LOG_INIT;
  // ...
}

Printing label strings

In order to print the labels I’m using simple lookup functions that look like this:

static inline const char* LOG_PrioritiesLabel(int Flags)
{
  switch (Flags & LOG_PRIORITIES_MASK)
  {
    case LOG_VERBOSE:     return "[VERBOSE]";
    case LOG_INFO:        return "[INFO   ]";
    case LOG_WARN:        return "[WARN   ]";
    case LOG_ERROR:       return "[ERROR  ]";
    case LOG_FATAL:       return "[FATAL  ]";
  }
  return "[       ]";
}

As I mentioned earlier, this function is trivially collapsed by the compiler since the Flags variable is known at compile time, so there is no cost to this approach.

The LOG_PRIORITIES_MASK is an integer that masks only the bits that, in this case, make up the priorities labels.

Generating the logger code

None of the code I showed is written by hand, it is all generated by the Metareflect system that I talked about in previous posts.

I extracted the relevant bits into a standalone logger generator, loggen that is up on Github.

Give it a try!