Sunday, 26 May 2013

Logger - SFINAE solution for implementation selection

Before we continue, a quick recap:
  • We have some reusable code (a lib).
  • We want to add logging to it.
  • We want to allow the client app to replace the logger implementation.
In order to achieve the goal stated in the last point, we defined a minimum interface that the client app's logger will have to implement, and we'll now introduce a mechanism to make our lib decay into that interface, if the client app's logger doesn't implement our optimal interface.

As stated last time, we have this (slightly modified):

template<typename T, typename RESULT, 
    typename ARG1, typename ARG2, typename ARG3>
class DoesDebug
{
    template <typename U, RESULT (U::*)(ARG1, ARG2, ARG3)> struct Check;
    template <typename U> static char checkFn(Check<U, &U::Debug> *);
    template <typename U> static int checkFn(...);
public:
    enum { Exist = sizeof(checkFn<T>(0)) == sizeof(char) };
};


This will be our basic workhorse, and we'll need one for each member function.

We'll put it to work with this:

DoesDebug<Logger, void, std::string const&, char const*, int>::Exist

Upon finding this expression, the compiler will generate DoesDebug like this:
  • typename T = Logger
  • typename RESULT = void
  • typename ARG1 = std::string const&
  • typename ARG2 = char const*
  • typename ARG3 = int
Now, the compiler must calculate DoesDebug<etc...>::Exist. That means, resolving checkFn<Logger>(0).

There are two candidates for this:
char checkFn(Check<U, &U::Debug> *);
int checkFn(...);

The second candidate will always be the last option for the compiler, because of its "..." argument. As for the first, it must instantiate the Check struct, like this:

template <Logger, void (Logger::*)(std::string const&, 
   char const*, int)> struct Check;

The compiler will only be able to instantiate this if &Logger::Debug can be matched with this member function pointer: void (Logger::*)(string const&, char const*, int). So, there must be an overload of Logger::Debug() that has this signature. If that is the case, the compiler successfully instantiates Check, which means sizeof(checkFn<T>(0)) is char, because that's the return type of the first overload of CheckFn; that means Exist is true, because:

Exist = sizeof(char) == sizeof(char)

On the other hand, if there is no Logger::Debug() with the required signature, the compiler can't instantiate struct Check, which means it can't instantiate the first checkFn overload, and it'll go with the second. This means sizeof(checkFn<T>(0)) is int, and Exist is false.

Hence, we have a way to check whether our lib's optimal interface exists. What we need now is a way to use it.

template <bool condition, typename LoggerImpl>
class LoggerBridge
{
public:
...
    void Debug(std::string const& msg);
 

    template <typename LI = LoggerImpl>
    typename std::enable_if<DoesDebug<LI, void, std::string const&, 
        char const*, int>::Exist, void>::type
    Debug(std::string const&, char const*, int);
 

    template <typename LI = LoggerImpl>
    typename std::enable_if<!DoesDebug<LI, void, std::string const&, 
        char const*, int>::Exist, void>::type
    Debug(std::string const&, char const*, int);

...
private:
    LoggerImpl l;
};

We'll use two identical versions of Debug(string const&, char const*, int), but using enable_if with opposed conditions (DoesDebug<> and !DoesDebug<>) ensures only one will be generated by the compiler.

These functions then become:

template <bool condition, typename T> template <typename LI>
typename std::enable_if<DoesDebug<LI, void, std::string const&,  
    char const*, int>::Exist, void>::type
LoggerBridge<condition, T>::Debug(const std::string& msg, char const* file, int line)
{
    l.Debug(msg, file, line);
}
 

template <bool condition, typename T> template <typename LI>
typename std::enable_if<!DoesDebug<LI, void, std::string const&, 
    char const*, int>::Exist, void>::type
LoggerBridge<condition, T>::Debug(const std::string& msg, char const*, int)
{
    l.Debug(msg);
}


So, when DoesDebug is true, i.e., when the method LoggerImpl::Debug(string const&, char const*, int) exists, the compiler will use the first function; otherwise, it uses the second, which logs the message and ignores the remaining arguments. How? The template enable_if only has a type member when the condition is true. So, when the condition is false, type does not exist, which means the compiler excludes it from overload selection.

You'll notice the functions became template functions. My first version didn't work, and after some searching, I arrived here, where Johannes Schaub - litb answer explained why:
That's because when the class template is instantiated (which happens when you create an object of type Y<int> among other cases), it instantiates all its member declarations (not necessarily their definitions/bodies!).
(...)
You need to make the member templates' enable_if depend on a parameter of the member template itself.
So, the problem is that when the Debug() functions weren't templated, the compiler instantiated all of them when LoggerBridge was instantiated. That means both versions of Debug(string const& msg, char const* file, int line) were instantiated, and GCC complained that one could not be overloaded with the other. So, I changed the member functions to templates, in order to do this: "make the member templates' enable_if depend on a parameter of the member template itself".

After getting it to work with GCC, it was time to move over to MSVC. And solve some more problems, obviously. Actually, it was just one problem - warning/error C4519 default template arguments are only allowed on a class template, because of this:
Default template arguments for function templates     No     No
The two Nos refer to VC10 and VC11. So, I gathered, if I can't use default template arguments, I'll have to use them explicitly:

#ifdef _MSC_VER 
    template <typename LI>
#else
    template <typename LI = LoggerImpl>
#endif
    typename std::enable_if<DoesDebug<LI, void, std::string const&,
        char const*, int>::Exist, void>::type
    Debug(std::string const&, char const*, int); 

And, on the call site:

#ifdef _MSC_VER 
    t.Debug<Logger>("String", __FILE__, __LINE__);
#else
    t.Debug("String", __FILE__, __LINE__);
#endif


And there you go. I'm now checking how to hide this from the user, but here I'll probably cop out and use a #define. I'll use macros for creating the logger and calling the methods, anyway; there's no way I'm going to manually write all those __FILE__s and __LINE__s.

A few closing notes.
  • As I said, I'm adapting my Logger bare-bones example for this, and one thing I've already realized is the amount of boilerplate code is huge. It doesn't really bother me that much, because it's work I'll only do once. But it's still a lot more "code" than I expected.
  • All of the above may be obvious to anyone experienced in C++. However, what you read here reflects my first serious contact with templates, the previous contacts being the usual Oh-templates-are-very-useful-look-how-easily-you-can-create-a-container. And this was definitely my first contact with SFINAE. Two weeks ago, all I knew was I needed a way to select function implementations at compile time and that my cursory observation of enable_if, many months ago, showed it could be done. I'm infinitely grateful to all the folks throughout the web (on StackOverflow, on other programming forums, and on their personal sites/blogs) for taking the time to explain these concepts.
  • This solution seems better than what I have here, as far as boilerplate is concerned, but I didn't understand it completely. It's on my study list.

Friday, 24 May 2013

Logger - Automatic selection of implementation on compilation

Ah, redesign. Loads of fun, hey? So... what have I decided to change?

1. I'll reintroduce logging levels to the interface. However, I won't be keeping its state, I'll rely on the Logger implementation. The interface will be basic - a method that returns true or false for a particular logging level, something like:

if (log.IsDebug())
{
    // LET'S DEBUG, PUT ON YOUR RED... SHOES??
}


That way, we'll avoid creating a lovely - and, sometimes, expensive - log string for nothing.

Why had I removed this from the interface, in my previous redesign? Call it the allure of simplicity. Now, I'm reminded - again - that for every problem, there is a solution that is relatively easy, relatively simple, and relatively wrong. That's relativity for you.

2. I'll add a const char * to my Logger class. I'll initialize it with __FILE__, in the ctor. That means adding a second parameter to Logger's ctor, with nullptr as default. Since Logger's typical usage pattern is as a local, ownership is not a concern.

3. I'll add an int parameter to all logging methods. I plan to use it to pass __LINE__.

Points 2 and 3 got me thinking that I might be imposing an unnecessary burden on anyone wanting to use these classes with their own logger implementation. I probably am, by forcing them to implement an interface where they must have two params, instead of just one, even if they don't use it.

E.g.,

// My little lib
log.Debug("My little debug message", __LINE__);


Now, someone comes along and decides to use my little lib code, but supplying his own logger. Alas, his logger falls a little short on the int param department, and only has Debug(string). In order for this to build, he now has to add a useless default int parameter to his implementation. Once again, not earth-shattering, but can we avoid it?

Yes, we can (no relation), and that's what I've been doing all these days, figuring out how. Why all this time? Well...

On my previous post, I've mentioned my puny specialization trick as "template meta-programming" (TMP). I knew I it was a bit of an aggrandizement; I just didn't know how big this "bit" was, i.e., how puny my little trick was, when compared to proper TMP. And these past few days have provided a fantastic eye-opener, even though I've barely scratched the surface, as far as this theme goes.

You see, the obvious way to keep my code from imposing unnecessary requirements on any client app is to allow it to fall back to a "minimum common interface". Something like this:

template <bool condition, typename LoggerImpl>
void LoggerBridge<condition, LoggerImpl>::Debug(
    std::string const& msg, int line)
{
    if (LoggerImpl_has_full_interface)
    {
        l.Debug(msg, file, line);
    }
    else
    {
        l.Debug(msg);
    }
}


And, obviously, I'd like the if (LoggerImpl_has_full_interface) bit to be as automatic as possible.

The solution? SFINAE and definitely more TMP than am I used to. I have a POC ready, and I'm finishing the tests, before I post it here, and include it in my LoggerBridge/Logger.

As a final note, it took me longer because I didn't want just any solution. I chose a solution that I can understand. I've come across many others that worked, but weren't as intuitive as the one I selected.

I've chosen this one, from here:

template<typename T, typename RESULT, typename ARG1, typename ARG2, typename ARG3>
class HasDebug
{
    template <typename U, RESULT (U::*)(ARG1, ARG2, ARG3)> struct Check;
    template <typename U> static char checkFn(Check<U, &U::Debug> *);
    template <typename U> static int checkFn(...);
public:
    enum { value = sizeof(checkFn<T>(0)) == sizeof(char) };
};


I can understand how this works, and I've managed to change it to create versions for const and static members (even though I'm still trying to figure out how the static version works).

With C++11 there are different ways of doing this, but I have to study those more closely. Like I said, this one is intuitive, works for all scenarios I imagined, and I understand it.

Also, this is not a subject where I plan to invest much of my time at this point. I can understand the concepts, and I believe they're extremely useful, but this is probably not the best way to realize their potential in a programming language. C++ should have a simpler way to achieve this.

So, let me get the Logger code ready, and - assuming no further problems - I'll explain the solution on my next post. If you're familiar with SFINAE, it'll all be old news for you.

Tuesday, 14 May 2013

Ever a duh! moment

So, after coming up with a great design I rode off into the sunset.

Of course, after the sunset there's always a sunrise. This particular sunrise caught me merrily peppering logging statements all over my SSH code, basking in the warm light of my brilliant design. Or maybe it was the warm light of the sunrise, I tend to get confused about which is which. And, suddenly (isn't that always the case?), something went click, like a brain cell waking up.

I'm using POCO Logger's poco_* macros. Convenient little buggers, actually. Here, take a look at one of them:

#define poco_debug(logger, msg) \
    if ((logger).debug()) (logger).debug(msg, __FILE__, __LINE__); \
    else (void) 0

Note the __FILE__ and __LINE__. Cool, heh? And now, note how my brilliant design cunningly takes advantage of it:

2013-05-14 13:26:18.228 [Debug] ... [../Logger/logger.h:46] LibClassSupport ctor ID: 11
2013-05-14 13:26:18.250 [Debug] ... [../Logger/logger.h:46] LibClassUtility1 ctor ID: 1
2013-05-14 13:26:18.283 [Debug] ... [../Logger/logger.h:46] LibClassSupport ctor ID: 21
2013-05-14 13:26:18.306 [Debug] ... [../Logger/logger.h:46] LibClassUtility2 ctor ID: 1
2013-05-14 13:26:18.412 [Debug] ... [../Logger/logger.h:46] LibClassMain ctor ID: 1
2013-05-14 13:26:18.474 [Debug] ... [../Logger/logger.h:46] LibClassSupport ctor ID: 12
2013-05-14 13:26:18.508 [Debug] ... [../Logger/logger.h:46] LibClassUtility1 ctor ID: 2
2013-05-14 13:26:18.541 [Debug] ... [../Logger/logger.h:46] LibClassSupport ctor ID: 22
2013-05-14 13:26:18.574 [Debug] ... [../Logger/logger.h:46] LibClassUtility2 ctor ID: 2
2013-05-14 13:26:18.608 [Debug] ... [../Logger/logger.h:46] LibClassMain ctor ID: 2


Yep, looking from this log excerpt, one would get the impression my code spends an awful lot of time in line 46 of logger.h (a definite performance bottleneck, if I ever saw one). One would be forgiven for such an impression, even though one would be wrong; in case you're wondering, this last one would be me.

Ah, well, back to the old drawing board. Still, if it wasn't for mistakes, how would I learn, right?

Hey, if it happens to Wile E. Coyote, super-genius, why wouldn't it happen to me?

Monday, 13 May 2013

Logger wrapper continued

So, we have our logger all figured out, and now we want to use it. We also want to control the inclusion/exclusion of logging code in our build, like this:

#if WANT_LOGGING
    // Logging code
#endif


And, as I said in the previous post, we'd like this to be centralized somewhere, so that we don't have to spread these #ifs all over our code. Since the logging code requires the #include of lib_logger.h, that's a good candidate for this centralization:

#if WANT_LOGGING
#define CREATE_LOGGER(logger_name, config_file) \
    LibLogger::CreateLogger(logger_name, config_file)
#define GET_LOGGER(logger_name) LibLogger LIB_LOGGER(logger_name)
#define LOG_INFORMATION(msg) LIB_LOGGER.Information(msg)
#define LOG_DEBUG(msg) LIB_LOGGER.Debug(msg)
#else
#define CREATE_LOGGER(logger_name, config_file) ((void)0)
#define GET_LOGGER(logger_name) ((void)0)
#define LOG_INFORMATION(msg) ((void)0)
#define LOG_DEBUG(msg) ((void)0)
#endif


So, all we have to do is use CREATE_LOGGER, GET_LOGGER, etc. in our code, and it'll be automatically taken care of with a single #define.

There's a certain comfort in the use of macros, when it comes to code inclusion/exclusion, since the rules are simple. Still, I've always wanted to try some simple template meta-programming (TMP), and this looked like the perfect opportunity.

So, let's change our template class to this:

template <bool condition, typename LoggerImpl>
class LoggerBridge
{
public:
    explicit LoggerBridge(std::string const& loggerName);
 

    static void CreateLogger(std::string const& loggerName, 
        std::string const& configFile);
 

    void Critical(std::string const& msg);
    void Debug(std::string const& msg);
    void Error(std::string const& msg);
    void Fatal(std::string const& msg);
    void Information(std::string const& msg);
    void Notice(std::string const& msg);
    void Trace(std::string const& msg);
    void Warning(std::string const& msg);
private:
    LoggerImpl l;
};


We've added a bool argument to our template. Our goal is that when that argument is true, the compiler generates logging code; and when it's false, it doesn't. In order to achieve that, we'll add a specialization.

template <typename LoggerImpl>
class LoggerBridge<false, LoggerImpl>
{
public:
    explicit LoggerBridge(std::string /*const& loggerName*/) {}
 

    static void CreateLogger(std::string /*const& loggerName*/,  
        std::string const& /*configFile*/) {}
 

    void Critical(std::string const& /*msg*/) {}
    void Debug(std::string const& /*msg*/) {}
    void Error(std::string const& /*msg*/) {}
    void Fatal(std::string const& /*msg*/) {}
    void Information(std::string const& /*msg*/) {}
    void Notice(std::string const& /*msg*/) {}
    void Trace(std::string const& /*msg*/) {}
    void Warning(std::string const& /*msg*/) {}
};


When the bool parameter is false, our class will contain nothing, and it will do - quite unsurprisingly - nothing.

So, if we change lib_logger.h to this

#include "logger.h"
#include "loggerbridge.h"
 
typedef Lib::LoggerBridge<false, Lib::Logger> LibLogger;


and rebuild, running the .o files through nm will show no sign of Logger. You'll still find Logger symbols on the .exe because we didn't exclude Logger.h and Logger.cpp from the build, but if you do it (e.g., commenting their lines on the SOURCES and HEADERS variables, in Qt Creator's .pro file), then this: nm Logger.exe | grep -i 3lib6logger will produce no results.

The funny-looking 3lib6logger identifies Lib::Logger symbols, after mangling occurs. E.g.:

00403c70 T __ZN3Lib6Logger12CreateLoggerERKSsS2_
00403a60 T __ZN3Lib6LoggerC1Ev


You can run these symbols through c++filt, to demangle them

>c++filt __ZN3Lib6Logger12CreateLoggerERKSsS2_

Lib::Logger::CreateLogger(std::basic_string<char, std::char_traits<char>, 
    std::allocator<char> > const&, std::basic_string<char, std::char_traits<char>, 
    std::allocator<char> > const&)
 

>c++filt __ZN3Lib6LoggerC1Ev

Lib::Logger::Logger()


BTW, when running c++filt on valid mangled names (say, a name you got from nm's output or out of the disassembly window in a debugging session), if you're getting no results and if the name has leading underscores, use the -n option.

So, compiling LoggerBridge with false gives us the same result as using macros, and with an amount of TMP small enough not to overwhelm a beginner like me.

Now, we can do something like this in lib_logger.h:

#include "logger.h"
#include "loggerbridge.h"
 
typedef Lib::LoggerBridge<WANT_LOGGING, Lib::Logger> LibLogger;


According to the value we #define for WANT_LOGGING, 1 (true) or 0 (false), we'll instantiate the general LoggerBridge template (with logging functionality) or our specialization (with no functionality).

We could add further complexity to these rules. If we used a char instead of a bool, we could define specializations based on logging level - logging levels 0 and MAX would be the false and true cases above, and the levels in-between would require further specializations, with some methods having empty bodies and others performing actual logging. E.g. (assuming 1 is Fatal and 8 is Trace):

template <typename LoggerImpl>
class LoggerBridge<4, LoggerImpl>
{
public:
    explicit LoggerBridge(std::string /*const& loggerName*/) {}
 

    static void CreateLogger(std::string /*const& loggerName*/, 
        std::string const& /*configFile*/) {}
 

    void Critical(std::string const& msg);
    void Debug(std::string const& /*msg*/) {}
    void Error(std::string const& msg);
    void Fatal(std::string const& msg);
    void Information(std::string const& /*msg*/) {}
    void Notice(std::string const& /*msg*/) {}
    void Trace(std::string const& /*msg*/) {}
    void Warning(std::string const& msg);
private:
    LoggerImpl l;
};


So, we get logging code for Fatal, Critical, Error, and Warning, and all other functions are empty. I don't see much use for this, so I'll stick with the bool version.

You can find the code here.