C++ Trace Logging

In my last post I made mention of a Gnu interface for retrieving backtrace info at run-time. I also suggested that I thought it would be useful for logging. In this post I'll expand on the concept and offer a mechanism for introducing trace logging with appropriate indentation calculated from the backtrace.

Let me start by saying, I rarely use macros. While effective they are often referred to as a 6' chainsaw, useful when necessary but dangerous more often. I sometimes make an exception when I used them for tracelogging because I want to postpone the evaluation of __FILE__ and the __LINE__ preprocessor directives.

I sometimes define a macro as follows:

#define LOG(S) { std::ostringstream s; s<< S; printf("(%s:%d) %s\n",__FILE__,__LINE__,s.str().c_str()); }

This macro allows us a pretty flexible logging mechanism that includes the file and line number as part of the log entry. A couple simple uses include:

{

  LOG("Class01::Method01() entry");

   .

   .

   .

  LOG("Class01::Method01() exit");

}

  for(int i=0; i<10; ++i)

  {

    LOG("iteration " << i);

  }

Back to the backtrace, a pretty simple implementation follows:

#include <execinfo.h>

  int stackDepth()

  {

    static const int Deep = 1024;

    void *array[Deep];

    const size_t size = backtrace (array, Deep);

    return (size-4);

  }

The above function will return the depth of the stack, capp'ed at a depth of 1024. The stack depth can be useful in defining an indentation mechanism to add to our logging:

  std::string indent()

  {

    const int n = stackDepth();

    std::string in=std::string(n,' ')+std::string(n,' ');

    return in;

  }

Revisiting our macro and adding our trace log indentation function gives us a nice logging mechanism that is easier to trace through.

#define LOG(S) { std::ostringstream s; s<< S; printf("%s(%s:%d) %s\n",indent().c_str(),__FILE__,__LINE__,s.str().c_str()); }

That's it, hope you find it useful.

Cheers.