Debugging with Visual Studio 2005/2008: Logging and Tracing

by Patrick Mancier

Whenever you write C++ programs, inevitably you're going to have to debug the program. In this article, discover how to use logging to make your programs much easier to debug--without needing a debugger.



Trace and Logging messages

TRACE Macro

Tracing is a feature in Visual Studio that allows the programmer to put a log message onto the main output window. The mechanism is fairly simple to use. It is only active with debug builds, in a release build none of the trace messages will be displayed.

The TRACE macro contains a format specified string argument that can contain any number of variable arguments. For a simple message it is very simple.

void TRACETest()
{
    TRACE(_T("Hello World!"));
}

To add variables to this use the following format:

void TRACETest2()
{
    char *pszPlanet[] = {"Earth","Mars"};
    int iNumberPlanets = 2;

    TRACE(_T("Hello World! We are visiting %d planets.  First stop:%s, Second stop:%s"),iNumberPlanets,pszPlanet[0],pszPlanet[1]));
}

If you are debugging MFC it is better to use the TRACEn where n = 0,1,2,3 and stands for the number of arguments that are being passed into the string that you are using. However, be forewarned that TRACEn is now an obsolete macro and MSDN recommends using ATLTRACE instead.

ATLTRACE Macro

ATLTRACE is a macro used for debugging in MFC or ATL. This macro has two versions. The first version has this signature: ATLTRACE(exp) where exp is basically a formatted string and a number of variable arguments. This is the same behavior as the older TRACE macro. The second version has this signature:
ATLTRACE(DWORD category,UINT level,LPCSTR lpszFormat,...).

NOTE: In order to get the information that applies to this version, you need to refer to ATLTRACE2. ATLTRACE. actually calls this second version and was designed this way to keep the backwards compatibility.

DWORD category - Defines the type or method to report.

Referring to the MSDN document you can see that ATLTRACE has a much higher level of tracing than just the normal TRACE macro. There are a set of ATL and MFC categories that can be set to track.

You can even declare a custom category by declaring a global instance of the CTraceCateogry class and making it a macro.

CTraceCategory MY_CUSTOMCONTROL(_T("MyCustomControlName"), 1);

The first parameter is the name of your category, the second parameter is the log level you want this to appear in and can range from 0 . 4.

UINT level - Defines the level of tracing requested and is set to 0,1,2,3,4. This level will suppress or add logging messages as requested. The messages that are displayed are dependent on whether or not the message being requested exists at this log level.

LPCSTR lpszFormat, ... is the formatted string and the list of variables that are used for the formatted string.

Report Macros

Visual Studio provides a built in debug reporting mechanism for logging. The basic idea here is to configure the mechanism to its desired behavior and use it to track program progress and to report errors. These are _RPT, _RPTF, _RPTW, _RPTFW. The .W. versions of these macros are simply for Unicode implementations.

To use these reporting macros you must include the crtdbg.h header file. There are two basic macros, RPTn, _RPTFn, n=0,1,2,3,4,5. Both essentially do the same thing. The n is for the number of arguments that string contains. The only difference between these two macros is the _RPTF provides the file name and line number where the macro is executed. This may or may not be useful but generally if used in conjunction with the ASSERT macros this function probably does not need to be used because an assert will provide this information by default.

The basic idea is to send a message string to the macro that will be sent to the debug report. Each macro is called with a reportType and the message string and its parameters. The following example illustrates how to use it.

#include 

void ReportMacroTest()
{
    int iCount = 21;
    char pszName[] = "Harry";

    _RPT1(_CRT_WARN,"Reporting that iCount == %d",iCount);
    _RPT2(_CRT_WARN,"Reporting that %s is %d years old" ,pszName,iCount);
}

This reporting mechanism can be configured in different ways. The two functions that are used to configure the mechanism are _CrtSetReportMode and _CrtSetReportFile.

Below is a rehash of the MSDN documentation.

_CrtSetReportMode has two parameters:
int reportType - This is set to any of the three reports types:

  • _CRT_WARN for warnings and information only
  • _CRT_ERROR for errors that require immediate attention
  • _CRT_ASSERT for assertion failures
int reportMode. - Set this to tell the reporting mechanism how you want the messages to be reported. You can use any combination of these flags to apply to the report.
  • _CRTDBG_MODE_DEBUG - Write the message to the debugger window, usually the Output window in Visual Studio
  • _CRTDBG_MODE_FILE - Write the message to a file. This requires an already establish open file handle
  • _CRTDBG_MODE_WNDW - Display it in a message box with Abort, Retry and Ignore buttons
  • _CRTDBG_REPORT_MODE - Returns the current setting for reportMode for each of the above report types

The thing to keep in mind with this mechanism is that each report type (warn, error, assert) has a separate reporting mode. In other words for each report type to have a separate value you would need to call _CrtSetReportMode three times with the reportMode flags.

For example, let's say you only want error messages to go to a file and the trace window but you want all warnings to go to just the trace window. You also want all asserts to be put in a message box in addition to the error file and the output window. This is how you would accomplish this.

#include 
void AssignReportingLevels()
{
    _CrtSetReportMode( _CRT_WARN, _CRTDBG_MODE_DEBUG);
    _CrtSetReportMode( _CRT_ERROR, , _CRTDBG_MODE_DEBUG | _CRTDBG_MODE_FILE );
    _CrtSetReportMode( _CRT_ASSERT, _CRTDBG_MODE_DEBUG |_CRTDBG_MODE_FILE | _CRTDBG_MODE_WNDW );
}

_CrtSetReportFile is fairly simple to understand once you understand how to use _CrtSetReportMode. It has two parameters:
int ireportType - Report to apply the file to
_HFILE reportFile - A file handle to an open file to report messages to

Referring to our previous example, let's say we want the error file and the assert file to be separate. We obviously need to open two file handles, one for the error report and one for the assert report. Assuming that we have done that, here is the code below to assign them:

#include 
extern _HFILE fileErrorReport;
extern _HFILE fileAssertReport;
void AssignReportFiles()
{
    _CrtSetReportFile(_CRT_ERROR,fileErrorReport);
    _CrtSetReportFile(_CRT_ASSERT,fileAssertReport);
}
Prev: Part 4: Setting Up Code for the Debugger
Next: Part 6: Remote Debugging



Related articles

Debugging with Visual Studio Part 1: Debugging Concepts

Debugging with Visual Studio Part 2: Setting up the Debugger

Debugging with Visual Studio Part 3: Using Breakpoints Effectively

Debugging with Visual Studio Part 4: Setting Up Code for the Debugger

Debugging with Visual Studio Part 6: Remote Debugging

Main debugging page

Learn about another debugger, GDB

bug prevention, debugging strategies, tips, and gotchas

hunting segmentation faults and pointer errors

Finding Memory Leaks using Valgrind

Skip Stepping Into Functions with Visual Studio's NoStepInto Option