Click here to Skip to main content
15,860,972 members
Articles / Programming Languages / C++
Article

Debug tracing in stream-like way

Rate me:
Please Sign up or sign in to vote.
4.74/5 (19 votes)
24 May 2007CPOL6 min read 85.7K   447   24   29
Tracing in the debug window using std::ostream

Introduction

This article is the "second edition", replacing an older one, responding to some requests from the former, and perfecting certain design aspects.

The original idea came while writing a small program for certain math calculations that didn't want to work as expected. There was a need to trace some values at certain execution points, typically to track the execution flow.

On console apps, this is typically done with std::cout, but this may not be a good choice if you want to preserve the console from debugging dirtiness, or you are using Windows applications, with no console.

The good old C runtime <crtdbg.h> header provides some printf-like macros named _RPTx. But, if we want something that can support a universal C++ style interface, potentially good for every type, something is missing.

The Win32 OutputDebugString can help with this, but it is just a LPCTSTR output function. So, the idea is to write an STL-like stream using that API for output.

Contents

A bit inside the streams

The most intuitive way to come to this solution is a class having an overridden operator<<, that calls the Win32 API after converting the input data into a string.
In fact, by doing this, will result in re-inventing the most of the STL formatting utilities.

STL streams are -in fact- all re-interpretations of the common std::basic_ostream base class, providing to it a convenient override of the std::basic_streambuff class.

The stream takes care of data formatting through the selected locale, providing utilities while the streambuff provides the space for the stream to write to. The stream also takes care of output towards media (in this case, the debugger; more generally, the standard output or an open file).

Thus, the proper way to handle this task is provide an override of the basic_streambuff flushing the content of a supplied buffer into the debug output.

Things to arrange

If we want to be able to use such functions in a pure Win32 context, we must be prepared to operate with TCHARs. For that reason, the std::ostream and wostream are not suitable, as they are a pre-defined character type.

We need another typedef. Within the GE_::dbg namespace I placed a ostream_t typedef, aliasing basic_ostream<TCHAR>.

An inner report_h namespace is then used to contain implementation details. In it, class globals declare as members an ostream_t stream object and a streambuff object, where streambuff is a class derived from std::basic_streambuf<TCHAR>.

To provide trace indentation, a depth member is also present.

Regardless of the streambuff implementation, the globals constructor initialize the stream, passing the streambuff object address. In addition, the in-line global function provides access to a lazy static instance of globals.

Outside the inner namespace, GE_::dbg::out() returns the reference to the static hidden stream, making it globally available.

The streambuff implementation

The streambuff class derives from std::basic_sreambuff<TCHAR> and its constructor calls the inherited pubsetbuff, setting a supplied TCHAR[] buffer, keeping one character as guardian, to be used as a string terminator.

The key components of this implementation are the setbuf, overflow and sync virtual functions overrides.

The setbuf override simply calls the base setp function to tell it to use the supplied buffer from the first up to the second-last character (thus leaving the last one to be always null).

The sync function is called by the stream when the buffer is required to be flushed. It happens when the std::flush or the std::endl manipulator are encountered. It just gets the currently running pbase() and pptr() (the beginning of the stream output and its last output character), calculates the string size, forces the one-past last output character to be '\0', and calls OutputDebugString, thus causing the buffer content to be printed out. After that, it calls pbump(-sz) to rewind the buffer, allowing the stream to overwrite it.

The overflow function is called by the stream when sending to the output more characters than the buffer can contain. It just calls sync, thus flushing the buffer, that places the "pending" character in the just cleaned buffer, and increments the writing position.

Simple sample

The above described code is all what is required for a snipset like this

C++
int n = 5;
double d = 6.75;
dbg::out() << "n = " << n << "; d = " << d << std::endl;

to trace a line like

C++
n = 5; d = 6.75

RAII indentation

The dbg::trace class is an RAII class (a class whose destructors "undo" to resources what the constructor has done) that helps to track the entry/exit from function calls.

It takes name and address parameters, and increments / decrements on construction / destruction the globals.depth member.

Its constructor writes the passed name[address] preceded by a > sign in a depth wide field. Similarly, the destructor writes <name[address], with the same indentation.

The generic operator<< outputs the parameter to the stream, preceeding it by an indented ".". This "effect" can also be obtained with the dbg::dpeth manipulator, inside a normal "<<" chain.

Thus this function:

C++
void function(int n)
{
    dbg::trace trc("function", function);
    trc << "hallo with n = " << n << std::endl;
    if(n) function(n-1);
}

If called with n = 3, will trace as:

C++
>function[xxxxxxxx]
 .hallo with n = 3
 >function[xxxxxxxx]
  .hallo with n = 2
  >function[xxxxxxxx]
   .hallo with n = 1
   >function[xxxxxxxx]
    .hallo with n = 0
   <function[xxxxxxxx]
  <function[xxxxxxxx]
 <function[xxxxxxxx]
<function[xxxxxxxx]

RAII object tracking

The dbg::track class is similar to the dbg::trace, but it uses the "C:" and "D:" strings instead of the "<" and ">" signs, and doesn't increment/decrement the depth (while writing coherently with it).

It can be used to track objects creation / destructions, like in this snipset:

C++
class myobject
{
private:
   dbg::track trk;
public:
   myobject() :trk("myobject", &trk) {}
};

An with the following code:

C++
int main()
{
    dbg::trace trc("main", 0);
    trc << "creating two objects on stack" << std::endl;
    myobject m1, m2;
    trc << "creating a static object" << std::endl;
    static myobject m3;
    trc << "Bye" << std::endl;
}

will trace as

C++
>main[00000000]
 .creating two object on stack
 C:myobject[xxxxxxxx]
 C:myobject[yyyyyyyy]
 .creating a static object
 C:myobject[zzzzzzzz]
 .Bye

 D:myobject[yyyyyyyy]
 D:myobject[xxxxxxxx]
<main[00000000]
D:myobject[zzzzzzzz]

(Note how the static object is destroyed after that main returns)

Other stuff

One of the problems of inserting tracing code is making it disappear from release versions (to avoid the trace string literals and possibly lengthy function calls).

In the previous article I proposed the use of a "fake stream", whose operation is implemented as "do nothing", letting to the compiler optimization process to remove the fake calls.

Here I use a more traditional approach. The DBG macro just is defined as its own parameter if the _DEBUG symbol is defined, or as "nothing" if such a symbol is not defined.

It is possible to place calls like in this snipset:

C++
void myfunc()
{
        DBG(dbg::trace trc("myfunc", myfunc);)
        ...
        DBG(trc << "some code" << a_variable << std::endl;)
        ...
}

or inserting some dummy variables in tracked objects, like

C++
class myclass
{
        DBG(dbg::trackedobj<myclass> trk;)
public:
        ...     
};

Conclusion

I hope this new version can be more flexible and usable than its predecessor. Some "fetaures" of the old article (like the stackval manipulator, are not present here, mainly because they are not required if using RAII wrappers.

In any case, I've placed the old article text and embedded code in this subpage, for the benefits of whoever would like to see the history.

Compilers compatibility

The code presented here is compiled in C++ 8.0 (VSC++ express). The code itself is not particularly sensible to the compiler, but the different version of the STL that is provided with the compiler can make the difference.

A particular case, is the use of UNICODE: when TCHAR id defined as char, (no unicode), the wchar_t* type is treated by std::ostream as a void* (the hex representation of the address is printed).

When UNCODE is defined, the C++8 STL treats both char* and wcahr_t* as strings by std::wostream. This allows you to write debug string literals as C++ strings (const char[]) even in unicode environment.

Unfortunately, this is not guaranted to always work: the old C++ compiler provided STL implementations may not represent char* as a "string literal" in std::wostream when TCHAR is defined as wchar_t. Moral: unless you know exactly with which STL version provider you're working, always use the _T(.) macro. (Exactly what I didn't use in my sample snipsets in this article.)

License

This article, along with any associated source code and files, is licensed under The Code Project Open License (CPOL)


Written By
Architect
Italy Italy
Born and living in Milan (Italy), I'm an engineer in electronics actually working in the ICT department of an important oil/gas & energy company as responsible for planning and engineering of ICT infrastructures.
Interested in programming since the '70s, today I still define architectures for the ICT, deploying dedicated specific client application for engineering purposes, working with C++, MFC, STL, and recently also C# and D.

Comments and Discussions

 
Generalshifting and multithreading Pin
owillebo28-May-07 1:58
owillebo28-May-07 1:58 
GeneralRe: shifting and multithreading Pin
Emilio Garavaglia28-May-07 4:46
Emilio Garavaglia28-May-07 4:46 
GeneralArticle updated Pin
Emilio Garavaglia17-Feb-07 5:03
Emilio Garavaglia17-Feb-07 5:03 
GeneralVS6 Pin
Malcolm Pirie23-Nov-06 0:55
Malcolm Pirie23-Nov-06 0:55 
GeneralGreat article by the way! Pin
wtwhite22-Aug-06 19:41
wtwhite22-Aug-06 19:41 
Generalostream::endl() Pin
wtwhite22-Aug-06 19:51
wtwhite22-Aug-06 19:51 
GeneralRe: ostream::endl() Pin
Emilio Garavaglia22-Aug-06 21:33
Emilio Garavaglia22-Aug-06 21:33 
GeneralRe: ostream::endl() Pin
wtwhite22-Aug-06 22:12
wtwhite22-Aug-06 22:12 
Questiondbg::stackval Pin
depaolim22-Aug-06 0:32
depaolim22-Aug-06 0:32 
AnswerRe: dbg::stackval Pin
wtwhite22-Aug-06 6:57
wtwhite22-Aug-06 6:57 
GeneralRe: dbg::stackval Pin
depaolim22-Aug-06 21:52
depaolim22-Aug-06 21:52 
GeneralRe: dbg::stackval Pin
wtwhite22-Aug-06 21:58
wtwhite22-Aug-06 21:58 
GeneralRe: dbg::stackval Pin
depaolim22-Aug-06 22:34
depaolim22-Aug-06 22:34 
AnswerRe: dbg::stackval Pin
Emilio Garavaglia22-Aug-06 21:53
Emilio Garavaglia22-Aug-06 21:53 
GeneralRe: dbg::stackval Pin
depaolim22-Aug-06 22:14
depaolim22-Aug-06 22:14 
Generalrelease mode Pin
Goran Mitrovic21-Aug-06 1:21
Goran Mitrovic21-Aug-06 1:21 
GeneralNo trace statement should have side effects Pin
wtwhite22-Aug-06 7:13
wtwhite22-Aug-06 7:13 
GeneralRe: No trace statement should have side effects Pin
Goran Mitrovic22-Aug-06 9:30
Goran Mitrovic22-Aug-06 9:30 
GeneralRe: No trace statement should have side effects Pin
wtwhite22-Aug-06 19:31
wtwhite22-Aug-06 19:31 
GeneralRe: No trace statement should have side effects Pin
Goran Mitrovic22-Aug-06 21:06
Goran Mitrovic22-Aug-06 21:06 
GeneralRe: No trace statement should have side effects Pin
wtwhite22-Aug-06 21:09
wtwhite22-Aug-06 21:09 
GeneralRe: No trace statement should have side effects Pin
Emilio Garavaglia22-Aug-06 21:09
Emilio Garavaglia22-Aug-06 21:09 
GeneralRe: No trace statement should have side effects Pin
wtwhite22-Aug-06 21:13
wtwhite22-Aug-06 21:13 
QuestionPossible Overflow? Pin
Robin17-Aug-06 22:34
Robin17-Aug-06 22:34 
AnswerRe: Possible Overflow? Pin
Emilio Garavaglia18-Aug-06 6:55
Emilio Garavaglia18-Aug-06 6:55 

General General    News News    Suggestion Suggestion    Question Question    Bug Bug    Answer Answer    Joke Joke    Praise Praise    Rant Rant    Admin Admin   

Use Ctrl+Left/Right to switch messages, Ctrl+Up/Down to switch threads, Ctrl+Shift+Left/Right to switch pages.