Posted by: rmn on: 18/11/2009
The RAII design pattern can be utilized to create simple and intuitive logging facilities, like the one we will present now. Through the useful macro LOG_FUNC, the proposed ScopeLogger will easily create function call graphs at run time, to allow easy debugging and tracking of program execution.
Here’s the implementation:
// ---- header ----
#include <string>
// Following macro is not entirely portable, but works in MSVS & GCC
#define LOG_FUNC ScopeLogger s##__LINE__(__FUNCTION__)
struct ScopeLogger {
ScopeLogger (const std::string &str);
~ScopeLogger ();
private:
std::string indent (unsigned ind) const;
static unsigned indent_;
const std::string msg_;
};
// ---- source ----
#include <iostream>
unsigned ScopeLogger::indent_ = 0;
ScopeLogger::ScopeLogger (const std::string &str)
: msg_(str) {
std::cout << indent(indent_++) << "[+] " << msg_ << std::endl;
}
ScopeLogger::~ScopeLogger () {
std::cout << indent(--indent_) << "[-] " << msg_ << std::endl;
}
std::string ScopeLogger::indent (unsigned ind) const {
return std::string(ind<<1, ' ');
}
Note that, as commented above, the macro LOG_FUNC is not entirely portable; The usage of the non-standard pre-defined macro __FUNCTION__ is not guaranteed to work on every compiler, although Microsoft’s Visual Studio & GCC do support it. (GCC also supports a __PRETTY_FUNCTION__ macro which can be even more useful)
The code can be extended further: extra functionality can be added to the ScopeLogger class if needed, and compile time reliance on _DEBUG can be added (to disable output in a release build, for example).
Here’s an example of the generated call graph:
antrikot:~/work/sandbox/log> ./scopelogger.out
[+] main
[+] run
[-] run
[+] work
[+] attempt
[-] attempt
[-] work
[+] attempt
[-] attempt
[+] run
[-] run
[-] main
Generated by the following code:
#include "scopelogger.h"
bool run () {
LOG_FUNC;
static unsigned num = 1;
return num--;
}
void attempt () {
LOG_FUNC;
}
bool work () {
LOG_FUNC;
static bool state = true;
if (state)
attempt();
return state -= state;
}
int main () {
LOG_FUNC;
while (run())
if (!work())
attempt();
return 0;
}
This example only illustrates how easy using this facility actually is, whilst the generated output is just priceless for debugging or understanding execution flow.
Hi Roman!
I love the scoped logger. Your logger helped us in finding bugs in our software. It’s awesome.
I know that the logger in this post is only a demo, but I would suggest another feature. The current logger prints to std::cout. I would like to be able to instantiate the logger with any object which supports the << operator. This way you can log into std::cerr, log4cpp or stringstream.
Nadav
Nice! As another quibble, I’d suggest branching the LOG_FUNC definition to be null if _DEBUG is not defined. Naturally the overhead of stream outputs can be prohibitively expensive in production builds.
Roman – do you have an actual scenario where the point of leaving a function adds value? (I mean – why should the destructor be instrumented?)
Very nice code.
I’d say that the exit point is also important – you can log stuff about the return value of the function, maybe special case bools, ints and pointers.
Also interesting is the addition of MT support.
On another subject:
In Python it’s a “standard exercise” to implement a trace function decorator. With little additional work, such a decorator can work & look just like your LOG_FUNC, except maybe making it a little more Pythonic.
It could be interesting to implement the same scopelogger for tracing objects instead of functions
19/11/2009 at 03:10
Very interesting post. I think that such a component with little additional stuffs (like handling different levels, and different output means like standard output, standard error stream, files, being able to plug databases maybe, etc) could be of a great interest and be the ultimate boost.log library everybody wants :p
22/11/2009 at 00:15
Thanks for the kind words
Seems like the proposed boost::logging library has similar features. It looks very promising.
23/11/2009 at 09:43
Indeed, but it’s been in the “proposed” state for a long time. I don’t know when it’ll be reviewed and possibly accepted, and even if it’ll be.
08/01/2010 at 21:42
Vladimir Prus has just volunteered be the review manager for the Boost.Log review. So one step closer.