Monospaced

Tracing is probably the simplest way to debug some piece of code you (or someone else) wrote. For large projects, it’s also often faster than trying to load every debug symbol in your favorite debugger.

The principle of tracing is printing out messages at key points in your code. This way you can follow the execution of your program as it runs normally, instead of dealing with breakpoints and debugger controls. While outputting text is quite straightforward in most programming languages, we can still make use of a mini framework. Such framework could provide useful things such as:

1. redirecting output to different streams or files
2. turning output on/off
3. automatically indenting tracing output to enhance the readability

The approach I’m presenting here deals with items 2 and 3 of this list and is designed for C++ development.

The goal

C++ is a functional language and the behavior of your program depends on the interaction of those functions. Therefore, we would like the trace output to easily display this interaction of functions (or methods). An indented tree view fits the bill perfectly:

+- main()
|  +- intialize()
|  |  initializing...
|  /
|  +- functionA()
|  |  doing something..
|  +- functionB()
|  |  +- functionA()
|  |  |  doing something..
|  |  /
|  /
|  +- finalize()
|  |  cleaning up...
|  /
/

Making use of the scope

An object or variable always lives in a well-defined scope. Our goal is to show the entry and exit points of our program’s functions. Every function body forms a scope. Therefore, we can generalize the problem and begin to think of a way to trace scope entry and exit points.

Constructors and destructors

Every time an object becomes in scope, its constructor is called . Similarly, the destructor is called when the object goes out of scope.

#include <iostream>

using std::cout;
using std::endl;

class MyClass
{
public:
    MyClass() { cout << "MyClass::MyClass()" << endl; }
    ~MyClass() { cout << "MyClass::~MyClass()" << endl; }
};

int main (int argc, char const* argv[])
{
    MyClass a;
    cout << "function body" << endl;
    return 0;
}

Running the above code gives us the following output:

MyClass::MyClass()
function body
MyClass::~MyClass()

Generating tracing objects on demand

In every scope we would like to trace, we simply have to keep a tracer instance that will output certain messages in its constructor and destructor. To customize the text displayed, we’ll add a string argument to our tracer’s constructor.

#ifdef DEBUG
#define TRACE_ENTER( msg ) ST::ScopeTrace __trace_enter__( msg );
#else
#define TRACE_ENTER( msg );
#endif

We hide the tracing objects behind macros. This way we can use #define values to turn tracing on or off. In debug mode, the preprocessor inserts the tracer object. In release mode, the macro is ignored and no code is generated.

Scope indentation

The final piece in our little framework is the smart indentation. Scope can be viewed as a stack. When your program executes, the current scope is the top of the stack. All we need to indent our tracing messages is a shared (static) integer variable that will tell the tracers how many indentations they should use. The constructor will increment this value and the destructor will decrease it.

struct ScopeTrace
{
    static int traceLevel;

    ScopeTrace( const string& msg )
    {
        ++traceLevel;
        // print indented line (msg)
    }

    ~ScopeTrace()
    {
        // print indented line
        --traceLevel;
    }
};

Adding visual cues

Now that everything is in place, we can improve the readability by outputting vertical lines and other symbols. Too much symbols will make our output hard to decipher.

Putting it all together

I’ve put together the ideas described here in
smartTrace.h. All you need to do is to #include it and make use of the following macros in your code:

TRACE_ENTER( “some string” )

Insert this on the very first line of any function or method you wish to trace. It will increase the indentation level.

TRACE( “some string” )

This can be used anywhere and will output the string using the current indentation level without modifying it. Use it inside functions.

Example

Compiling this file with DEBUG defined ( g++ -DDEBUG example.cpp ) gives us the following output:

+- main
|  +- ClassA::ClassA
|  /
|  Calling function...
|  +- function1
|  |  +- ClassA::ClassA
|  |  /
|  |  Calling method on a...
|  |  +- ClassA::method1
|  |  |  Processing data...
|  |  /
|  |  +- ClassA::~ClassA
|  |  |  Releasing memory...
|  |  /
|  /
|  +- ClassA::~ClassA
|  |  Releasing memory...
|  /
/

See also

A relatively recent article over at the The Code Project features a similar tracer that lets you save the output to disk. It can also report the time usage of your function, combining the tracer with a simple profiler.