Debug logging with STL stream operators

• Download demo - 14.9 KB
• Download source - 3.54 KB

Introduction

There are so many different ways to output debug log messages in a C++ program. Some use printf, others std::cout or std::cerr. On Windows, one can send strings to the debugger by calling the OutputDebugString API function, or by using TRACE macros from the MFC library. Wouldn’t it be nice if we can do it always the same way, e.g., using the STL stream operator<<, with configurable destinations?

I’d like to write the following code:

debuglogger << "This is a debug message: " << variable1 << std::endl;

The debug logger should call, for example, OutputDebugString with the generated stream content as a string.

OutputDebugString("This is a debug message: 42\n");

While browsing Josuttis' book about the STL [1], I stumbled over the stream buffer classes (Chapter 13.13), which should simplify this task. A stream buffer only implements the data for a stream, so you don’t have to implement all those stream operators or stream manipulators.

Building a STL like debug logger

The stream buffer class

To build a stream buffer, you have to derive from std::basic_streambuf and overwrite two virtual functions:

virtual int overflow (int c)
virtual int sync()

The overflow function is called whenever a new character is inserted into a full buffer. The sync() function is called to flush the buffer to the output destination. To make the output destination configurable, we use a functor and define a base class which only holds the parameter and return types for the function call operator. To keep this generic, we use a template parameter for the character type (char or wchar_t). The first argument holds the context used for the output. The second parameter holds a line of the debug message. The function call operator is called for each line of the debug message.

template<class charT>
struct basic_log_function 
{
    typedef void result_type;                           
    typedef const charT * const first_argument_type;    
    typedef const charT * const second_argument_type;   
};

Now, we define the buffer for the debug logger stream. There are three template parameters which make the buffer generic to the used character type and the output destination. The charT parameter specifies the character type to be used for the stream. The logfunction parameter specifies the type of the output functor, and the traits type defines the character helper class for basic_strings.

template
<
    class charT,                                    // character type
    class logfunction,                              // logfunctor type
    class traits = std::char_traits<charT>          // character traits
>
class basic_debuglog_buf : public std::basic_streambuf<charT, traits>
{
    typedef std::basic_string<charT, traits> string_type;   
public:
    virtual ~basic_debuglog_buf();
    void setContext(const string_type &context);
protected:
    virtual int_type overflow (int_type c);
    virtual int sync();
private:
    string_type buffer_, context_;
    logfunction func_;
    void sendToDebugLog();
};

The setContext function sets the context string for the debug message. The private sendToDebugLog function executes the logfunction’s function call operator, passing the context string and the current line of the debug message.

The stream class

To make a stream using your own buffer, a pointer to an instance of this buffer must be passed to the constructor of the basic_ostream class from which our stream class is derived. The template parameters are the same as for the basic_debuglog_buf class.

template
<
    class charT,                                // character type 
    class logfunction,                          // logfunction type
    class traits = std::char_traits<charT>      // character traits 
>
class basic_debuglog_stream : public std::basic_ostream<charT, traits>
{
    typedef std::basic_string<charT, traits> string_type;
    typedef basic_debuglog_buf<charT, logfunction, traits> buffer_type;
    typedef std::basic_ostream<charT, traits> stream_type;                  
    typedef std::basic_ostringstream<charT, traits> stringstream_type;      public:
    basic_debuglog_stream(const char *file = 0, int line = -1);
    basic_debuglog_stream(const string_type &context, const char *file = 0, int line = -1);
    virtual ~basic_debuglog_stream();
    void setContext(const string_type &context);
    const string_type getContext() const;
    basic_debuglog_stream &get() {return *this;}
private:
    basic_debuglog_stream(const basic_debuglog_stream &);
    basic_debuglog_stream &operator=(const basic_debuglog_stream &);
    void buildContext();
    const char *file_;    
    const int line_;
    string_type context_;
    buffer_type buf_;
};

The setContext function builds a context string from the filename and line number (if specified) and the given context message, and passes it to the stream buffer. The context string is formatted like this:

[[<filename>][(<linenumber>)] : ][<context message> : ]<message text>

Each part can be omitted by using the default values of the stream constructor. A full context string looks like this:

c:\projects\testlogger\main.cpp(20) : main() : Hello debuglog!

The getContext function retrieves the context message from the stream. The get function simply returns a reference to the stream object. This is helpful to use the stream operators on a temporary stream object.

e.g. logstream().get() << "Hello world!" << std::endl;

As you have noticed, in the private section of the stream, copying of a stream object is forbidden. These three classes are the base for our debug logger; now, let’s see how to use them.

Using the code

First of all, we need a functor which defines the destination of the debug messages.

The log_to_win32_debugger class

Let’s start with a class for using OutputDebugString from the Windows API. This function sends a given string to the debugger. If used from Visual Studio, the message is displayed in the output window. If it’s formatted correctly, we can click on the message in the output window, and the position where the message is outputted will be shown to us automatically. To remain generic, we do this as a template with the character type as the parameter. The function call operator simply concatenates the context and the output string, and passes the result to OutputDebugString. It’s not really necessary to derive the class from basic_log_function; this is only a helper to define the function call operator the right way. It’s sufficient to declare the function call operator as:

void operator()(const char * const context, const char * const output);

Here comes the debug log stream:

template<class charT>
class log_to_win32_debugger : public basic_log_function<charT>
{
    typedef std::basic_string<charT> string_type;
public:
    result_type operator()(first_argument_type context,               
                           second_argument_type output)
    {
        string_type s(context);
        s += output;
        OutputDebugString(s.c_str());
    }
};

Now, we are ready to define a concrete type for debug logging:

typedef 
basic_debuglog_stream<TCHAR, log_to_win32_debugger<TCHAR> > DebugLogger;

The TCHAR macro holds char for multi-byte character builds, and wchar_t for Unicode builds.

Use the class in the following way:

DebugLogger(__FILE__, __LINE__, _T("main()")).get() << 
            _T("Hello debug log!") << std::endl;
DebugLogger(_T("main()")).get() << _T("Only a context message!\n");
DebugLogger().get() << _T("Without a context!\n");

This should produce the following output on the debugger:

c:\projects\testlogger\main.cpp(20) : main() : Hello debuglog!
main() : Only a context message!
Without a context!

Simple, isn’t it? It’s also possible to use the stream modifiers from the STL.

DebugLogger("In hex") << std::hex << std::showbase << 12345 << std::endl;

This should output:

In hex: 0x3039

To get rid of the typing pain, we define a few simple macros. (Macros huh? Well, I know macros are evil, but sometimes they are useful.)

We use the prefix RAW if the filename and the line number are omitted, and the prefix CTX if a context message is used:

#define RAWLOG() DebugLogger().get()
#define CTXRAWLOG(text) DebugLogger(text).get()
#define CTXLOG(text) DebugLogger(text, __FILE__, __LINE__).get()
#define LOG() DebugLogger(__FILE__, __LINE__).get()

Now, it’s much easier to type:

CTXLOG(_T("main()")) << _T("Hello debug log!") << std::endl;
CTXRAWLOG(_T("main()")) << _T("Only a context message!\n");
RAWLOG() << _T("Without a context!\n");

To catch the debug output from OutputDebugString without using Visual Studio, use the free tool DebugView from Mark Russinovich (at www.sysinternals.com, now owned by Microsoft).

Logging to a file

It’s also easy to log to a file. Just implement another functor for our debug log stream.

template<class charT>
class log_to_file : public basic_log_function<charT>
{
public:
    result_type operator()(second_argument_type context,               
                           second_argument_type output)
    {    
        std::basic_ofstream<charT> fs(GetLogfilename(),std::ios_base::app);
        if (!fs)
            throw std::invalid_argument("Logging file not found!");
        else
            fs << context << output;
    }
private:
    const std::basic_string<charT> GetLogfilename()
    { 
        return std::basic_string<charT>(_T("c:\temp\debug.log"));
    }
};

typedef 
basic_debuglog_stream<TCHAR, log_to_file<TCHAR> > FileDebugLogger;

Maybe, you want a more sophisticated GetLogFilename implementation, but hey, this is just a sample.

Logging to std::cerr

It’s even simpler to direct the output to std::cerr (but therefore, we won’t need those classes, but now, we can do it in an interchangeable way).

template<class charT>
class log_to_cerr : public basic_log_function<charT>
{
public:
    result_type operator()(first_argument_type context,  
                            second_argument_type output)
    {
        std::cerr << context << output;
    }
};

typedef basic_debuglog_stream<TCHAR, log_to_cerr<TCHAR> > ErrDebugLogger;

Stateful functors

As you may have noticed, you cannot pass in more information to the functors. They are instantiated in the constructor of the stream buffer class, and there is no access to them. To overcome this limitation, I suggest using the Monostate pattern, where many instances of the same class share the same state.

template<class charT>
class MonoStateFunctor 
{
public:
    void operator()(const charT * const context, 
                    const charT * const message)
    {
        std::basic_ofstream<charT> fs(filename_.c_str(),
                                      std::ios_base::app);
        if (!fs)
            throw std::invalid_argument("cannot open filestream");
        else
            fs << context << message;        
    }
    
    void setFilename(const std::string &filename)
    {
        filename_ = filename;
    }
    const std::string getFilename() const
    {
        return filename_;
    }
private:
    static std::string filename_;        
};

typedef MonoStateFunctor<TCHAR> functor;
typedef basic_debuglog_stream<TCHAR, functor> logger;

Using this logger:

std::string functor::filename_ = "";

int main(int, char **)
{
    // The filename must be set once
    functor f;
    f.setFilename("c:\\temp\\test.log");

    logger(__FILE__, __LINE__, _T("main()")).get() << "This is a test!\n";
}

It’s clear that you have to protect the filename_ variable in the multithreaded context, e.g., with a mutex.

Using MFC classes and your own classes

If you want to use the logger with classes from MFC or with your own classes, you have to define the stream operator<< for them as shown in the following code fragment for CString and COleDateTime.

typedef std::basic_ostream<TCHAR> stream_type;

stream_type &operator<<(stream_type &log, const CString &text)
{
    log << text.operator LPCTSTR();
    return log;
}

stream_type &operator<<(stream_type &log, const COleDateTime &dateTime)
{
    log << dateTime.Format();
    return log;
}

int main(int, char **)
{
    CTXLOG(_T("main()")) << CString("MFC String: ") 
                         << COleDateTime::GetCurrentTime() 
                         << _T("\n");
}

Compiler issues

I’ve tested this code with Visual Studio 2008, Visual Studio 6, and GCC (Open Suse 10.3). On Visual Studio 6, I had to replace the clear() function of std::basic_string with resize(0) and set the debug level to 3 instead of 4 to make it compile without too much warnings within the STL. For my version of GCC, I have to fully qualify the typedefs from base classes or types within the template parameters:

E.g.:

virtual typename traits::int_type::int_type overflow (
                     typename traits::int_type int_type c);

Bibliography

[1] Nicolai M. Josuttis, The C++ Standard Library, A Tutorial and Reference

You must Sign In to use this message board.

FAQ  Noise Tolerance Very HighHighMediumLowVery Low  Search Messages    Layout Expand All MessagesThread ViewNo Javascript (slow)No Javascript Preview    Per page 102550

Msgs 1 to 4 of 4 (Total in Forum: 4) (Refresh) FirstPrevNext

Usage of __FUNCTION__ cristianadam 14:23 16 Aug '08   Instead of: DebugLogger(__FILE__, __LINE__, _T("main()")).get() << _T("Hello debug log!") << std::endl; You could have used: DebugLogger(__FILE__, __LINE__, __FUNCTION__).get() << _T("Hello debug log!") << std::endl; Cheers! Sign In·View Thread·PermaLink Re: Usage of __FUNCTION__ Johann Anhofer 23:11 16 Aug '08   Indeed, i can do this. But then I loose portability because __FUNCTION__ is Microsoft specific. Sign In·View Thread·PermaLink Re: Usage of __FUNCTION__ cristianadam 9:51 17 Aug '08   It's not Microsoft specific, at least that's my conclusion after reading: http://gcc.gnu.org/onlinedocs/gcc-3.2.3/gcc/Function-Names.html[^] http://www.devx.com/cplus/10MinuteSolution/31491/1954[^] Sign In·View Thread·PermaLink Re: Usage of __FUNCTION__ Johann Anhofer 9:19 20 Aug '08   Sorry, you're right! The MSDN Library for VS2008 states __FUNCTION__ as Microsoft specific, but it seems that other compiler vendors have also implemented this feature. Definitly it's not in the C++ Standard (2003) but only in the C99 Standard. Sign In·View Thread·PermaLink

Last Visit: Friday, November 21, 2008 12:51 PM     Last Update:Friday, November 21, 2008 12:51 PM