Stop Logging Debug Values, Use Visual Studio’s Trace Points instead!

nearly every company I’ve worked for had a “let’s clean our logs project”.  The trigger for this activity was often  frustrated log uses such as tech supporters , customer service staff and other developers (usually the new ones)   overwhelmed  by the clutter and junk included in the logs.
Some of the log trash  is generated during development,  is not uncommon to see something like

[26/04/2016:14:23:48]  INFO: In nameVerify method (remove after Q4-2014  release)

Or even worse
[26/04/2016:14:23:48]  WARNING:  secstr = DvVP1$XFJ2T
where secstr stands from secret or security ,  and warnign logging was used because it stands out in the logs.

Often these log entries are created during the infant days of the software components.  While some of  them  are an  indication the should  me more unit test  cases,   Other are used sed to extract and examine  internal data  dynamically created by the component on each run.

For this late use, you can use trace points.
trace points are a kind of breakpoints only the debugger can be instructed no to halt the program. The expression is evaluated and the  result  can be printed to the output windows:

consider this simple TraceMe class:

#include  <vector>
#include  <string>

class TraceMe
{
	public: 
	TraceMe() 
	{
		val = 5;
	}
	TraceMe(std::string str) 
	{
		secStruct.secStringVec.push_back(str);
		val = 10;
	}
private:
	int  val;
	struct  InternalStruct
	{
		std::vector<std::string>  secStringVec;
	};
	InternalStruct  secStruct;
};

int main(int argc, char* argv[])
{
	TraceMe  trace;
	return 0;
}

 

Suppose we need to examine the content of the val member after it has been   initialized.  The first step is writing an expression that would evaluate to its contend.  This can be done without typing in a single character :

I placed a breakpoint (the plain vanilla type)  at line 28.  After I debug the program and the breakpoint is hit ,  I right click on the trace variable and select Quick Watch:

image

After expanding the structure,  Select the variable, the content of the expression edit box is what the QuickWatch  tool is using to evaluate val :

image

You can remove the breakpoint, we won’t need it anymore. Go to the next line (line 29)  and create another breakpoint :

image

right click on it and select, when hit:

image

In the dialog make sure  Print Message  and Continue execution checkboxes are both  is ticked.

now we can use the expression we extracted earlier: paste it into the edit box and enclose it with curly braces :   {(trace).valthe cause tell the debugger to evaluate the the expression and output the result.

Write  some text that will the value some context for example C++ Island -Debug the value of val is  {(trace).val}.

image

Now run the program and search the output window for you message:

image

This method works the same way  even when the value you are interested in is buried deep inside other data structure(s). Getting  the secString from the the vector inside internal structure is just as easy:

image

The expression turns out to be

((((trace).secStruct).secStringVec)._Myfirst)[0]

Conclusion

When printing a variable value during development, consider trace points However  if the variable values  serves as  an indication the program is running as it should (a virtual green LED)  , it might be a hint that an  an assertion or  a test case is a better  tool for the job.