The Debug and Trace Classes

The Debug and Trace Classes

Visual Basic .NET provides two classes, Trace and Debug, that contain methods for debugging your code. Both Trace and Debug are found in the System.Diagnostics namespace and have the same properties and methods. They do not derive from each other, however, or from any base class except Object. The difference between the two is that Debug is active when you define #DEBUG statements, and Trace is active when you define #Trace statements. Debug methods are enabled in the debug build of your code, and Trace methods are by default enabled in release builds.

Debug.WriteLine

Let's say you want to add a line to your code to see whether a denominator is 0. We never expect this to happen because we would receive a divide-by-zero error. Asserting that the denominator is not 0 will never execute unless, of course, we're wrong. Using Debug.WriteLine statements assist in finding any unexpected problems or conditions. You should use the Debug.WriteLine statement liberally in your code to ensure that it's behaving as you think it should. Here's an example:

Debug.WriteLine(iDenominator <> 0, "The denominator is 0.")

When you run the code, the Debug.WriteLine statement writes to the Debug window and tells you that the statement is false—the denominator is not 0.

'Errors.exe': Loaded 'c:\winnt\assembly\gac\accessibility\  1.0.2411.0__b03f5f7f11d50a3a\accessibility.dll',  No symbols loaded. 'Errors.exe': Loaded 'c:\winnt\assembly\gac\microsoft.visualbasic\  7.0.0.0__b03f5f7f11d50a3a\microsoft.visualbasic.dll',  No symbols loaded. 'Errors.exe': Loaded 'c:\winnt\assembly\gac\system.xml\  1.0.2411.0__b77a5c561934e089\system.xml.dll',  No symbols loaded. The denominator is 0.: False The program '[452] Errors.exe' has exited with code 0 (0x0).

When you run the Debug.WriteLine statement under the debugger, the assertion statement will be evaluated. However, in the release build, the comparison will not be made, so there is no additional overhead.

	Note: Use Debug.Write to write a partial line and Debug.WriteLine to have a carriage return and line feed (CrLf) appended to the output. Debug.Flush will ensure all text is printed.

Debug.Assert

Another handy method of the Debug class is the Assert method. This method is a bit more verbose than the WriteLine method and will provide the call stack in the output.

Private Sub procedure3()         Dim iNumerator As Integer = 32         Dim iDenominator As Integer = 0         Dim iResult As Integer = 0         Debug.Assert(iDenominator <> 0, "The denominator is 0.")

In this example, our assertion fails, and we are told so in no uncertain terms, as you can see in Figure 7-19.

Figure 7-19

A failed assertion.

An assert statement tests a condition that you specify as an argument to the Assert method. If the condition evaluates to True, no action occurs. If the condition evaluates to False, the assertion fails. If you are running your program under the debugger, it enters break mode. The Assert method can be used from either the Debug class or the Trace class.

When you are ready to build your program for final release, bring up the properties page of your program by right-clicking the program icon in the Solution Explorer and then selecting Properties. Be sure to clear the Define DEBUG Constant check box on the Build page of the Configuration Properties. If you don't do this, the Debug.Assert statements will show up to a startled and disoriented user. Both the DEBUG and TRACE check boxes are checked by default in the debug build, meaning that they are given the value of 1, which is True.

When you modify the configuration for the release version, the DEBUG statement is unchecked by default. This will ensure that any Debug class methods such as Assert or WriteLine will be stripped out of the binary. The property page is shown in Figure 7-20.

During development, you can easily include a #Const Debug = False statement in your code to turn off any debugging messages as you work. You can then toggle debug messages on and off by changing the Debug constant.

Figure 7-20

A project property page.

When using the Debug.Assert method, be sure that any code inside the Assert statement does not change the results of the program if the statement is removed. Otherwise, you might accidentally introduce a bug that shows up only in the release version of your program. You want to be especially careful about Assert statements that contain function or procedure calls. For example, consider the following line:

Debug.Assert (aFunction(iInteger) <> 0 )

While this Debug.Assert statement might appear safe at first glance, imagine that the function aFunction updates a counter each time it is called. When you build the release version, this call to aFunction is eliminated, so the counter will not be updated. This is known as a side effect because eliminating a call to a function has side effects that result in bugs that appear only in the release version. To avoid such problems, do not place function calls in a Debug.Assert statement. To modify the code to eliminate any unwanted side effects, you should use a temporary variable instead, as shown here:

iTempInteger = aFunction(iInteger) Debug.Assert (iTempInteger <> 0)

Tracing

You want to use the Debug class while developing your application and include Trace statements in your deployed application. Placing Trace statements in your code permits you to print out information as your program executes and see what's going on in an application that has been deployed. A programmer needs to exercise care to place Trace statements strategically for use during run time. If you don't think through what exactly you would like to see in a running application, you could end up adding code that turns out to be useless for diagnosing problems after deployment. You must always consider what tracing information is likely to be needed in a deployed application.

The need for wise planning in your use of Trace statements contrasts with the use of debugging messages during testing, where you can place debugging statements almost anywhere in an application under development. Other than placing your Trace statements wisely because their presence will incur a slight performance cost, there are no general guidelines for what "strategic" placement of trace statements means. Applications that use tracing vary widely. Wisdom will come with experimentation and practice.

Adding a Tracing Class to Our Code

Developing a generalized class that will handle the output of Trace statements for us might make some sense. If we create this class, we won't have to write all the tracing code, check for levels, and so on for each line we want to trace in our application. Instead we will write and include a class called ErrorTrace, which will permit our application to create an instance of the ErrorTrace class and then pass in the information we want to trace. We can leave the determination of the details to the class.

	The ErrorTrace class is on the companion disc as a class library project named Errors. (The library is a file named Errors.dll.) You can easily import this error tracing assembly to any new .NET program you write. When we discuss assemblies in Chapter 8, "Assemblies in Detail," you'll see how to strongly name and sign the new file so that it can be placed in the global assembly cache. This procedure gives it visibility (scope) to any program on the machine so that no matter which subdirectory you use to write a new Visual Basic .NET program, the Errors.dll file will always be available.

The following ErrorTrace class allows you to trace simple errors inside a program. Of course, this class could be greatly expanded; this example is just to get you thinking.

Imports System.IO Imports System.Diagnostics Public Class ErrorTrace     Private m_errorFile As StreamWriter     Private m_fileListener As TextWriterTraceListener     Private m_sAppName As String = ""     Private m_tsTraceSwitch As TraceSwitch     Public Sub New(ByVal sApplication As String)         Dim sEnv As String = _             Environment.GetEnvironmentVariable("demoSwitch")         m_tsTraceSwitch = New TraceSwitch("demoSwitch", _             "demoSwitch")         m_tsTraceSwitch.Level = CInt(sEnv)         If m_tsTraceSwitch.Level = TraceLevel.Off Then Exit Sub         m_errorFile = File.AppendText("C:\ErrorFile.txt")         m_fileListener = New TextWriterTraceListener(m_errorFile)         Trace.Listeners.Add(m_fileListener)         m_sAppName = sApplication         Trace.WriteLine(Date.Now & " Application: " & _             m_sAppName & " started")         Trace.WriteLine("Application Version: " & _             Environment.Version.ToString)         Trace.WriteLine("Current Directory: " & _             Environment.CommandLine)         Trace.WriteLine("Machine Name: " & _             Environment.MachineName)         Trace.WriteLine("Operating System: " & _             Environment.OSVersion.ToString)         Trace.WriteLine("User: " & Environment.UserName.ToString)         Trace.WriteLine( _             "------------------------------------------")     End Sub     Public Sub writeError(ByVal eException As System.Exception)                Trace.WriteLineIf(m_tsTraceSwitch.TraceInfo, _             "Error: " & eException.Message)         Trace.WriteLineIf(m_tsTraceSwitch.TraceVerbose, _             "Stack Trace: ")         Trace.WriteLineIf(m_tsTraceSwitch.TraceVerbose, _             eException.StackTrace)         Trace.WriteLineIf(m_tsTraceSwitch.TraceVerbose, _             "------------------------------------")            End Sub     Public Sub writeText(ByVal sMessageToWrite As String)         Trace.WriteLineIf(m_tsTraceSwitch.TraceInfo, _             sMessageToWrite)     End Sub     Public Sub dispose()         If m_tsTraceSwitch.Level = _             System.Diagnostics.TraceLevel.Off Then             Exit Sub         End If         Trace.WriteLine(Date.Now & "  Application: " & _             m_sAppName & " ended")         m_errorFile.Flush()         m_errorFile.Close()     End Sub End Class

Examining the ErrorTrace.vb Code

The ErrorTrace class includes four class-scoped variables that are visible to the entire class. The class will create a file that will log each Trace statement automatically, provided that a Trace variable is set to the level of output. More on this in a moment. First, let's take a look at our class module.

Imports System.IO Imports System.Diagnostics

We import the System.IO namespace because we will be opening a file in which to write the information. Remember, the ErrorTrace class will be used in an application that we have deployed, so we could easily turn tracing on, create the file, and have the user send it to us via e-mail. (Or you could send the file to yourself through a firewall because it will be a simple text file.) The System.Diagnostics namespace is where the Trace class lives.

The four private member variables have class visibility. We will create an m_errorFile file to write our output to. We will then build a listener and a TraceSwitch object that will dictate how many entries should be written to the file. Also, because this class is meant to be generalized, m_sAppName will hold the name of the application that instantiates our class.

Public Class ErrorTrace     Private m_errorFile As StreamWriter     Private m_fileListener As TextWriterTraceListener     Private m_sAppName As String = ""     Private m_tsTraceSwitch As TraceSwitch

The ErrorTrace.vb Class Constructor

When we instantiate the class from an application, the constructor takes the name of the application. When we write information to a file, the class writes the name of the application being reported on to the file.

For the Trace object to provide the flexibility we want, we use a TraceSwitch object that can hold a value from 0 through 4. The Trace object will be set to one of these levels at run time, and the value will dictate what, if anything, will be printed to our file. Table 7-2 lists the values and the related outputs.

Table 7-2  TraceSwitch Levels

Enumerated value	Integer value	Type of message displayed (or written to a specified output target)
Off	0	None
Error	1	Only error messages
Warning	2	Warning messages and error messages
Info	3	Informational messages, warning messages, and error messages
Verbose	4	Verbose messages, informational messages, warning messages, and error messages

You can set the TraceSwitch level in three ways. The first way is through the registry. This approach is probably not a good idea because to use our class, we would have to write code to add keys to the client's registry. We really don't want users to have to go into the registry and set keys. The other two methods for setting the TraceSwitch level are by means of an environment variable. I'll discuss these operations after we wrap up our discussion of the class.

The TraceSwitch constructor takes two parameters: a name of the switch and a description of the switch. If the switch (in this case demoSwitch) can't be found, the Trace class is disabled. I've noticed that getting TraceSwitch to read the demoSwitch environment variable is erratic, but you can easily grab the value from the environment using Environment.GetEnvironmentVariable and passing in the variable you want, in this case our demoSwitch value. By using this approach you are guaranteed a foolproof method of reading the value, if any.

We then create the new switch that will be used when we print our information. This switch is assigned to the member variable m_tsTraceSwitch. Next we convert the value of demoSwitch that we've retrieved from the environment and assign it to the level property of our switch. Finally, if the variable is not set, it will evaluate to TraceLevel.Off and we will simply exit the constructor. We don't need to build a file if we are not tracing. Our code can lay dormant until the environment variable is set and we need to perform remote diagnostics.

Public Sub New(ByVal sApplication As String)     Dim sEnv As String = _         Environment.GetEnvironmentVariable("demoSwitch")         m_tsTraceSwitch = New TraceSwitch("demoSwitch", _             "demoSwitch")         m_tsTraceSwitch.Level = CInt(sEnv)         If m_tsTraceSwitch.Level = TraceLevel.Off Then Exit Sub

If we get past this If statement, we know that some level is set for our m_tsTraceSwitch. We create a file in the root directory and assign it to m_errorFile. Of course, you could enhance the program to create the file right in the directory of the application or on a remote drive.

Once the file is created, we create a TextWriterTraceListener object. This object initializes a new instance of the TextWriterTraceListener class with TextWriter as the recipient of the output. Once that instance is created, we add it to the Listeners collection of the Trace object. Other listeners permit us to send the output to a stream or to the console. Here we instruct the trace to be sent to the file ErrorFile.txt.

m_errorFile = File.AppendText("C:\ErrorFile.txt") m_fileListener = New TextWriterTraceListener(m_errorFile) Trace.Listeners.Add(m_fileListener)

If any trace level is set, we send some specifics to our log file about the time the application started, its version, where it's located on the user's machine, the current version of the operating system, and the current user. The WriteLine method of the Trace object sends each piece of information to its own line in the file.

m_sAppName = sApplication     Trace.WriteLine(Date.Now & " Application: " & _         m_sAppName & " started")     Trace.WriteLine("Application Version: " & _         Environment.Version.ToString)     Trace.WriteLine("Current Directory: " & _         Environment.CommandLine)     Trace.WriteLine("Machine Name: " & Environment.MachineName)     Trace.WriteLine("Operating System: " & _         Environment.OSVersion.ToString)     Trace.WriteLine("User: " & Environment.UserName.ToString)     Trace.WriteLine( _         "------------------------------------------")     End Sub

Now our class is set up and waiting for any information to be sent from an error. Of course, you should be sure that you place the writeError procedure in a Catch statement in the running application because it takes an exception as a parameter. Unless TraceLevel is set to at least TraceInfo (a value of 3), the error message will not be printed. If the TraceLevel is verbose (a value of 4), the stack trace will be printed as well.

Public Sub writeError(ByVal eException As System.Exception)            Trace.WriteLineIf(m_tsTraceSwitch.TraceInfo, _         "Error: " & eException.Message)     Trace.WriteLineIf(m_tsTraceSwitch.TraceVerbose, _         "Stack Trace: ")     Trace.WriteLineIf(m_tsTraceSwitch.TraceVerbose, _         eException.StackTrace)     Trace.WriteLineIf(m_tsTraceSwitch.TraceVerbose, _         "------------------------------------")        End Sub

I've also added a simple procedure that will write a line of text to the file. With this procedure you can easily add information such as "Entering procedure3" to see where the program is at any particular time.

Public Sub writeText(ByVal sMessageToWrite As String)     Trace.WriteLineIf(m_tsTraceSwitch.TraceInfo, _         sMessageToWrite) End Sub

Finally, when the application that instantiated our class is closed, the dispose method is called. With this call, we can log the time the application stopped running and be sure that all entries are flushed to the file. Being good .NET citizens, we then close the file.

Public Sub dispose()     If m_tsTraceSwitch.Level = _         System.Diagnostics.TraceLevel.Off Then         Exit Sub     End If     Trace.WriteLine(Date.Now & "  Application: " & _         m_sAppName & " ended")     m_errorFile.Flush()     m_errorFile.Close() End Sub End Class

Setting the Trace Level

Sending any information to the ErrorFile.txt file is predicated on having a trace level set. As I mentioned, you can set the level in several ways. First, you can add an entry to the registry such as this:

HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\COMPlus\Switches\  <switch name>

If any of the entries in this key, for example Switches, are not present, you have to add them. Next you add the name of the switch (demoSwitch in our case) and a value from 0 through 4. As you can see, asking a user to do this over the phone is a dangerous proposition. You could write a helper program (or add an option to your application's menus) that would add these registry settings programmatically, but setting the trace level by using an environment variable is easier.

To start, simply bring up a command prompt and type SET demoSwitch=3. This command will add the variable to the environment. Another, more user friendly, way is to right-click My Computer on the desktop and select Properties from the shortcut menu. Click the Advanced tab, and then click Environment Variables. Under the System Variables box, click New. In the New System Variable dialog box, shown in Figure 7-21, you can add your variable and a value.

Figure 7-21

You can add a new environment variable and its value in the New System Variable dialog box.

When you click OK, the variable and value are added to the environment, as you can see in Figure 7-22.

Figure 7-22

The environment variable and its value are added to the environment.

You can display a command prompt and type set to see the effects of your work in these dialog boxes. This command shows you all the environment variables. You can see in Figure 7-23 that demoSwitch is set to 3.

Figure 7-23

The set command lists environment variables and their values.

Adding the Errors.vb Class to a Program

I'll use the code that generated a divide-by-zero error, presented earlier in the chapter, to demonstrate our new class. The first operation we perform is importing the Errors.ErrorTrace namespace. (You'll also need to add a reference to Errors.dll.) This namespace contains the ErrorTrace class located in the Errors files we added to the project earlier.

Imports Errors.ErrorTrace

We also want to import the following two statements.

Imports System.Text Imports CtrlChrs = Microsoft.VisualBasic.ControlChars

Remember the discussion about aliasing an imports statement? We want to add a carriage return and line feed after each line. If we imported only the Microsoft.VisualBasic.ControlChars namespace, for each carriage return and line feed we would need to write the statement

Microsoft.VisualBasic.ControlCharsCtrlChrs.CrLf

Instead of the statement

CtrlChrs.CrLf

If an Imports statement does not include an alias name such as CtrlChrs, elements defined within the imported namespace can sometimes be used in the module without qualification. However, if an alias name is specified, it must be used as a qualifier for names contained within that namespace.

Next we dimension and create a new instance of our Errors.ErrorTrace class and pass in the name of the current application. I've used "Test Error Program" in this example. Be sure that the new ErrorTrace object is dimensioned with class scope so that its methods can be seen throughout the class.

Dim sErrorMessage As New StringBuilder() Dim etErrorTracing As _     New Errors.ErrorTrace("Test Error Program")

We want to be sure that any text is flushed to our file and that the file closes properly. One way to be sure these operations occur is to explicitly dispose of our etErrorTracing object.

Form overrides dispose to clean up the component list. Protected Overloads Overrides Sub Dispose(ByVal disposing _     As Boolean)     If disposing Then         If Not (components Is Nothing) Then             components.Dispose()         End If     End If

    etErrorTracing.dispose()    MyBase.Dispose(disposing) End Sub

Let's add a line in a subroutine named procedure1 that will write the error to our trace file. We simply need to call the writeError method of our etErrorTracing object and pass in the error object for it to trace.

Private Sub procedure1()     Try         sErrorMessage.Append("In procedure1, calling " & _             "procedure2" & CtrlChrs.CrLf)         procedure2()     Catch e As Exception

        etErrorTracing.writeError(e)

        sErrorMessage.Append("Catch block in procedure1: " & _             e.ToString & CtrlChrs.CrLf)     Finally         sErrorMessage.Append("Finally in procedure1" & _             CtrlChrs.CrLf)         MessageBox.Show(sErrorMessage.ToString, _             "Error Stack Example", MessageBoxButtons.OK, _             MessageBoxIcon.Information)     End Try End Sub Private Sub procedure2()     sErrorMessage.Append("In procedure2, calling procedure3" & _         CtrlChrs.CrLf)     procedure3()     sErrorMessage.Append("In procedure2, returned from " & _         "procedure3 - never gets here" & CtrlChrs.CrLf) End Sub

Now we can check the writeText method by passing it some text. As you can see, with our new class handling the heavy lifting involved in creating files, adding a listener, determining the levels to print, and cleaning up when the application exits, we can simply add lines to the application.

Private Sub procedure3()     Dim iNumerator As Integer = 32     Dim iDenominator As Integer = 0     Dim iResult As Integer = 0     etErrorTracing.writeText("In procedure3 - just " & _         "before the error.")     sErrorMessage.Append("In procedure3,generating error" & _         CtrlChrs.CrLf)     iResult = iNumerator / iDenominator     sErrorMessage.Append("In procedure3, after error – " & _         "never gets here" & CtrlChrs.CrLf) End Sub

When your application is deployed and starts behaving badly, you can set an environmental variable and automatically generate a trace file for your evaluation. Because our demoSwitch variable is currently set to 3, we see only informational messages, warning messages, and error messages. If we add a call to procedure1 in the form's Load event and run the program, the output will look like the data shown in Figure 7-24.

Figure 7-24

The error log receives informational messages, warning messages, and error messages when demoSwitch is set to 3.

We can see when the application started and stopped, as well as all sorts of helpful information about the application—where it's located on the drive, machine name, operating system, and the current user. The log shows that the first error occurred in procedure3, where an OverFlowException error was thrown. We might want to check the call stack and any other information that can be seen in the Verbose mode. Of course, we would have to change the environment variable demoSwitch from 3 (Info) to 4 (Verbose).

You can use the Advanced tab of the properties sheet for My Computer and edit the value of demoSwitch, changing it from 3 to 4, or you can bring up a command prompt and type Set demoSwitch=4. Either technique will change the environment. Unfortunately, you will have to restart Visual Studio .NET to see the change. Also, when the environment variable is read by the .NET common language runtime, the runtime performs some optimizations and reads the variable only once. If the value changes, you have to stop your application and restart it. This situation applies only if you are using an environment variable to hold the switch value. When you change the value of demoSwitch to Verbose, the stack trace information is now printed to our file. You can see the results in Figure 7-25.

As I mentioned earlier, the first parameter of the Trace.WriteLineIf method is a Boolean that determines whether the line is printed. Because the value of demoSwitch is now 4, the complete verbose information such as the stack trace is now printed.

Trace.WriteLineIf(m_tsTraceSwitch.TraceVerbose, _     "Stack Trace: ") Trace.WriteLineIf(m_tsTraceSwitch.TraceVerbose, _     eException.StackTrace)

Figure 7-25

The error log receives verbose messages when demoSwitch is set to 4.

When you deploy your Visual Basic .NET application, the trace switch is disabled so that users need not observe a lot of irrelevant trace messages appearing on a screen or, in our case, filling up a log file as the application runs. However, if a problem arises in the field, you can stop the application, enable the switches, and restart the application. Once you've done this, the tracing messages will be written to the file.

If the TraceSwitch constructor in our class cannot find initial switch settings in the environment, the level of the new switch is set to TraceLevel.Off. Also, when your application executes the code that creates an instance of a switch for the first time, it checks the configuration system for trace level information about the named switch. The tracing system examines the configuration system only once for any particular switch: when your application creates the switch for the first time. In a deployed application, you can customize the tracing code by reconfiguring switch objects when the application isn't running. If you are using the registry, making these modifications involves changing the tracing levels and then restarting your application. If you are using the environment to store the values, you usually have to reboot to flush the old value and insert the new.