VB .NET Tracing


Having hopefully persuaded you that instrumentation and tracing is critically important when building any nontrivial application, I'll now show you how to add the most common type of tracing to your VB .NET software. You need to deal with five basic elements:

  1. Add tracing code to your application with the Trace class.

  2. Activate or deactivate tracing code at compile time with the TRACE flag.

  3. Specify the destination of tracing information with the TraceListener class.

  4. Specify the level of tracing at runtime with the TraceSwitch class.

  5. Control and override tracing behavior at runtime with the application's configuration file.

An important point to make here is that everything I'm about to discuss deals with tracing in non-ASP .NET applications. ASP .NET tracing is done differently, and I cover it in Chapter 9, which deals with debugging ASP .NET applications.

Step 1: Trace Creation

The System.Diagnostics.Trace class is the cornerstone of instrumentation and allows you to write tracing code that sends diagnostic information to all of the current trace listeners. It has several methods for this purpose. I describe these methods in the sections that follow.

The Write and WriteLine Methods

The Write method is used to produce diagnostic information without a linefeed , so that further information can then be appended to the same line. The Write-Line method is used to produce diagnostic information with a linefeed. Both of these methods are overloaded so that you can supply optional parameters. See Listing 6-1 for some examples of using this method.

Listing 6-1. Using Trace.WriteLine
start example
  'This overload takes just a string 'and will produce the trace message Some diagnostic information  Trace.WriteLine("Some diagnostic information")  'This overload takes two strings, a diagnostic message and a user-defined category 'and will produce the trace message Warning: A was supposed to equal B  Trace.WriteLine("A was supposed to equal B", "Warning")  'This overload takes an object and passes its.ToString value 'and will produce a trace message with the value of MyObject.ToString  Trace.WriteLine(MyObject)  'This overload takes an object and a user-defined category 'and will produce the trace message  Information: MyObject.ToString Trace.WriteLine(MyObject, "Information") 
end example
 

The interesting idea here is to find a good use for the user-defined category. One good use is shown in the preceding examples: a message level. In this scheme, you specify different levels of importance so that people looking at the tracing output can easily categorize the information into routine messages, warnings, and errors, or indeed whatever other scheme you devise . Another possibility is to specify the class name as the category, so that you can easily tell which class produced each trace message.

The WriteIf and WriteLineIf Methods

These two Trace class methods are almost identical to their WriteLine and Write siblings, but each also takes a boolean expression that has to evaluate to true for the trace information to be emitted . You would write something like the code shown in Listing 6-2.

Listing 6-2. Using Trace.WriteLineIf
start example
 Trace.WriteLineIf(IsTracingActive, GetStack() & GetDatetime() _     & "Some diagnostic info") 
end example
 

The only caveat with these conditional methods is performance. Even if the boolean expression evaluates to false , the whole statement will be processed ” there is no short-circuit . From the point of view of performance, it is better to write the code shown in Listing 6-3.

Listing 6-3. Trace.WriteLineIf Performance Constraint
start example
 If IsTracingActive = True Then       Trace.WriteLine(GetStack() & GetDatetime() & "Some diagnostic info") End If 
end example
 

The Assert and Fail Methods

These two Trace class methods implement assertions , which are safety checks within your code designed to catch conditions that theoretically shouldn't happen. Assertions are very useful because they can detect many bugs automatically, especially those bugs that result from invalid assumptions. The use of assertions is only bounded by your own imagination , but typically an assertion might be used to

  • Detect an illegal condition that should never occur (e.g., checking that a configuration file setting has a legal value).

  • Check that a component is operating properly (e.g., that a class has its internal flags in a mutually consistent state).

  • Check that procedure parameters supplied by your own code (as opposed to the code of another developer) are really valid.

  • Document an assumption that you make during coding (e.g., that another developer's component always gives an answer within a certain range).

The Assert method therefore tests an expression that you define, which should normally evaluate to true . If instead the condition evaluates to false , the assertion has failed and the Assert method automatically displays one or more messages that should contain your explanation of how and why the condition failed. See Listing 6-4 for some examples of using Trace.Assert .

Listing 6-4. Using Trace.Assert
start example
 Dim VbClassic As Int16, VbNet As Int16  'Does TRUE have the same value when using 'VB.Classic functions and VB .NET functions?  VbClassic = CInt(True) VbNet = Convert.ToInt16(True)  'This overload just shows the call stack leading to the assertion failure  Trace.Assert(VbClassic = VbNet)  'This overload adds an brief explanation of the assertion failure  Trace.Assert (VbClassic = VbNet, "Assertion failed: _                              VbClassic(True) <> VbNet(True)")  'This overload adds a more detailed explanation of the assertion failure  Trace.Assert (VbClassic = VbNet, "Assertion failed: _                              VbClassic(True) <> VbNet(True)", _                              "CInt(True)=" & VbClassic.ToString & _                              " : Convert.ToInt16(True)=" & VbNet.ToString) 
end example
 

The Fail method is simply an assertion that always fails, and it's typically used to signal that the software doesn't understand what it's trying to process. For example, a Select statement that runs out of options should use Trace.Fail to show that the Else clause has been reached. The Fail method is also overloaded, so you can supply just a single message or, as shown in the code in Listing 6-5, a summary message together with a more detailed message.

Listing 6-5. Using Trace.Fail
start example
 Select Case TestNum     Case 1          'Valid value - something happens here     Case 2          'Valid value - something happens here      Case 3          'Valid value - something happens here      Case Else          Trace.Fail("TestNum=" & TestNum.ToString, _                                  "TestNumber must be between 1 and 3") End Select 
end example
 

One major advantage of using assertions is that the complete call stack is added automatically to the generated message. This even includes the line number of the assertion if your application is running as a debug build. Listing 6-6 shows the detailed assertion message produced by the code shown in Listing 6-4 executing as a result of a command button click.

Listing 6-6. Example of an Assertion Message
start example
 ---- DEBUG ASSERTION FAILED ---- ---- Assert Short Message ---- Assertion failed: VbClassic(True) <> VbNet(True) ---- Assert Long Message ---- CInt(True) = -1 : Convert.ToInt16(True) = 1     at TraceDebug.btnTrueIsFalse_Click(Object sender, EventArgs e)    C:\Visual Studio Projects\TraceAndDebug\TraceDebug.vb(117)     at Control.OnClick(EventArgs e)     at Button.OnClick(EventArgs e)     at Button.OnMouseUp(MouseEventArgs mevent)     at Control.WmMouseUp(Message& m, MouseButtons button, Int32 clicks)     at Control.WndProc(Message& m)     at ButtonBase.WndProc(Message& m)     at Button.WndProc(Message& m)     at ControlNativeWindow.OnMessage(Message& m)     at ControlNativeWindow.WndProc(Message& m)     at NativeWindow.Callback(IntPtr hWnd, Int32 msg, IntPtr wparam, IntPtr lparam)     at UnsafeNativeMethods.DispatchMessageW(MSG& msg)     at ComponentManager.System.Windows.Forms.UnsafeNativeMethods+     IMsoComponentManager.FPushMessageLoop(Int32 dwComponentID,     Int32 reason, Int32 pvLoopData)     at ThreadContext.RunMessageLoop(Int32 reason, ApplicationContext context)     at Application.Run(Form mainForm)     at TraceDebug.Main() C:\Visual Studio Projects\TraceAndDebug\TraceDebug.vb(19) 
end example
 

Using Assertions

An assertion really has two uses. During development and unit testing, an assertion failure is shown directly to the developer so that the problem can be investigated and fixed. Therefore, the default output of an assertion failure is to display the call stack and any programmer-defined messages to the developer using a message box. The developer can then choose to stop program execution immediately by clicking Abort, drop into the debugger at the point of assertion failure by clicking Retry, or ignore the failure and continue program execution by clicking Ignore.

During application integration testing and when in production, there is no point in displaying assertion failures to the end user ”these messages would just be confusing. Instead, the application can be told to redirect assertion failures to a log file. I discuss this later when I cover investigating the use of application configuration files.

An important point to remember is that assertions should not take the place of defensive programming. Assertions are intended to detect " impossible " conditions, and they can therefore be sprinkled liberally through your code in an effort to find as many problems and mistaken assumptions as possible. However, adding defensive code to cater to each and every possible assertion failure is counterproductive. Assertions should never normally fail, and adding large amounts of defensive code just makes your application more complex and introduces a strong probability of extra bugs. You should have defensive code for critical areas of your application, but try to use each assertion as a warning beacon , not as a support fixture for some defensive programming. If you are actually seeing regular assertion failures, the solution is to eliminate them by fixing the code rather than trying to defend the code.

Try to document your assertions thoroughly, as it can be very exasperating to hit an assertion failure in somebody else's code and have no idea what that assertion is trying to do. A comment explaining why the assertion check exists can help to stop rogue developers from simply ripping out your carefully constructed code.

Step 2: Trace Activation

Once you've added tracing code to your application with the Trace class, you need a way of activating and deactivating it. At compile time, this can be controlled with a conditional compilation flag called TRACE . When this flag is set to true , any Trace class method is compiled as normal; when it is set to false , any Trace class method is removed from your application. You can set this flag in one of three ways:

  1. From the command line : Use /d:TRACE=True or /d:TRACE=False when compiling your application from the command line.

  2. In Visual Studio : In the Project properties Configuration properties Build window, select or deselect the "Define TRACE constant" check box when compiling your application from VS .NET.

  3. In code : Within your code, define the TRACE constant using the syntax #Const TRACE = True or #Const TRACE = False .

By default, the TRACE flag is set to true in all debug and release builds. Somebody made an assumption that you will normally want tracing code to be permanently enabled. This is a sensible assumption because control of the resulting diagnostic information can be done using trace switches, an option that has its own dedicated section later in this chapter (see "Step 4: Trace Control at Compilation Time").

You can also remove any diagnostic checks that you don't require when tracing is deactivated ”this can be useful for improving performance. To do this, you should use the #If #End If directive with the TRACE constant, as shown in Listing 6-7. If tracing is not active, none of the diagnostic code will be compiled into your program.

Listing 6-7. Determining If Tracing Is Active
start example
 #If TRACE Then 'Some expensive diagnostic code goes here #End If 
end example
 

Step 3: Trace Listening

Once you've instrumented your code so that it's producing tracing information, the next step is to direct that information to the required destinations. You do this with one or more trace listeners.

The TraceListener Class

The System.Diagnostics.TraceListener class is the abstract base class that you need to implement in order to create your own custom trace listeners. The job of atrace listener is to write the information emitted by the Trace class (using Write , WriteLine , and so on) to a specific destination, such as the console, a log file, or a database.

The .NET Framework provides some predefined listeners that handle the most common destinations for diagnostic information. The first is the Default-TraceListener , which writes to the OutputDebugString Win32 API, whereupon the VS .NET debugger redirects the information to the Output window. Other predefined listeners include the TextWriterTraceListener , which writes to a log file or other output stream such as the console, and the EventLogTraceListener , which writes to any of the Windows event logs. Adding an instance of one of these listeners to the Trace.Listeners collection directs tracing information to the specified destination. The following sections look at using these predefined event listeners and also cover how to define and use a custom event listener.

Using the DefaultTraceListener

When you start an application with tracing, the DefaultTraceListener is automatically instantiated and added to the Trace.Listeners collection. As a result, by default all information produced by the Trace class is written to the attached debugger, which in the case of VS .NET shows the information in the Output window. Normally, you don't need to write any code to support this functionality, but Listing 6-8 shows you how to remove the default trace listener, perhaps for performance reasons.

Listing 6-8. Removing the Default Trace Listener
start example
 Option Strict On Class Test     Public Shared Sub Main()        'Remove the default trace listener from the listeners collection        'This method takes either a string containing the listener name        'or the listener object        Trace.Listeners.Remove("DefaultTraceListener")     End Sub End Class 
end example
 

Using the TextWriterTraceListener

One of the most common requirements is to log diagnostic information in a text file. The System.Diagnostics.TextWriterTraceListener class has been created specifically for this purpose. To be more precise, this class can direct tracing information to any type of Stream or Writer , which gives you considerable flexibility in arranging your output. You may, for instance, want a trace listener that writes trace information to the system console. Listing 6-9 shows how you could accomplish this.

Listing 6-9. Sending Trace Information to the System Console
start example
 Option Strict On Class Test     Public Shared Sub Main()        'Create a trace listener that writes trace information to the console        Dim objTraceToConsole As New TextWriterTraceListener(System.Console.Out)        'Add the new trace listener to the collection of listeners        Trace.Listeners.Add(objTraceToConsole)        'Write trace information to all listeners, including the console        Trace.WriteLine("This trace information is for all listeners")        'Write trace information to just the console listener       objTraceToConsole.WriteLine _             ("This trace information is just for the console listener")        'Pause application to see console output       Console.ReadLine()        'Finish and clean up our console listener        objTraceToConsole.Flush()        objTraceToConsole.Close()        objTraceToConsole.Dispose()     End Sub End Class 
end example
 

Notice that you can send trace information to just one specific trace listener if you wish. Although this might be useful when you want to send each category (information, error, and warning) of trace information to a different listener, it subverts the flexibility of tracing where you can add trace listeners at runtime using a configuration file and expect to see the tracing output. I go into more detail about this in the section titled "Step 5: Trace Control at Runtime."

Listing 6-9 also shows the code that you need to run when you're finished with a particular trace listener. The Flush method ensures that all the information is actually written to the console, and the Close and Dispose methods make sure that all of the resources associated with the trace listener are released in a timely manner.

Of course, you might not want to send diagnostics to the console in this manner because the information won't be recorded permanently, but it could be useful when you want an end user to view and report a specific problem.

You might also want to send the diagnostic information to a text file, especially where the tracing database is not available. Listing 6-10 shows an example of doing this.

Listing 6-10. Sending Trace Information to a Text File
start example
 Option Strict On Class Test    Public Shared Sub Main()       'Create a trace listener that writes trace information to a text file       Dim objTextFile As Stream = "TraceListener.txt"       Dim objTraceToText As New TextWriterTraceListener(objTextFile)       'Add the new trace listener to the collection of listeners      Trace.Listeners.Add(objTraceToText)       'Write trace information to all listeners, including the text file      Trace.WriteLine("This trace information is for all listeners")       'Finish and clean up our console listener       objTraceToText.Flush()       objTraceToText.Close()       objTraceToText.Dispose()    End Sub End Class 
end example
 

Notice the necessity in both listings to flush and close the trace listener after you've finished with it. Although the CLR promises to perform garbage collection on an object at some point after it goes out of scope, this cleanup can be delayed for a long time. Any resources used by the object won't be released until the garbage collection has taken place, which would be bad news if some other part of the code wanted to make use of the same resources before the cleanup occurred.

Using the EventLogTraceListener

The System.Diagnostics.EventLogTraceListener class allows you to direct tracing information to any of the Windows event logs. This can be very useful, especially for middle- tier application servers where administrators often expressly monitor these logs. It can also be useful for remote diagnostics because you can easily view another machine's Windows event log using your machine's event viewer if you have the right permissions.

Listing 6-11 shows you how to create a trace listener that writes tracing information to the Application event log, specifying the program and trace listener names as the event source. You can also write to a custom event log for your application by specifying the name of your application's custom log in the EventLog.Log property.

Listing 6-11. Sending Trace Information to the Application Event Log
start example
 Option Strict On Class Test     Public Shared Sub Main()        'Create an event log trace listener, give it a name, and configure it        Dim objTraceToAppLog As New EventLogTraceListener("LogTraceListener")        With objTraceToAppLog             'Write to the Application event log             .EventLog.Log = "Application"             'Specify source of tracing information             .EventLog.Source = "AppName." &.Name          End With          'Add the new trace listener to the collection of listeners         Trace.Listeners.Add(objTraceToAppLog)          'Write trace information to all listeners,          'including the Application event log         Trace.WriteLine("This trace information is for all listeners")          'Finish and clean up our console listener          With objTraceToAppLog               .Flush()               .Close()               .Dispose()          End With     End Sub End Class 
end example
 

It's important to remember that the Windows event log has limited storage available. If you wish to write to the event log, it's better to do this away from the main code path ”in other words, only when an error has occurred. If you insist on writing routine information, anybody monitoring the event log is likely to be drowned in diagnostic information, and the event log may also run out of space rather quickly.

Creating a Custom Trace Listener

You can also create a custom trace listener when you want to send diagnostics to a nonstandard destination or augment the tracing information in some manner. Listing 6-12 shows a custom trace listener derived from the TextWriterTraceListener class. This custom trace listener writes timing information to an XML trace file to record specific performance information produced by your application.

Listing 6-12. Custom Trace Listener for Recording Performance Data
start example
 Option Strict On Imports System.Diagnostics Imports System.Threading Imports System.Text Imports System.IO Imports System Public Class TimerTraceListener : Inherits TextWriterTraceListener     Private msbBuffer As New StringBuilder()  'All of our constructors are here  Public Sub New(ByVal Stream As Stream)         MyBase.New(Stream)         EmitHeader()     End Sub   Public Sub New(ByVal Stream As Stream, ByVal Name As String)     MyBase.New(Stream, Name)     EmitHeader()   End Sub   Public Sub New(ByVal Writer As TextWriter)     MyBase.New(Writer)     EmitHeader()   End Sub   Public Sub New(ByVal Writer As TextWriter, ByVal Name As String)     MyBase.New(Writer, Name)     EmitHeader()   End Sub   Protected Sub EmitHeader()  'Start tracing performance data  MyBase.WriteLine("<trace>")   End Sub   Public Overloads Overrides Sub Write(ByVal Message As String)     If msbBuffer Is Nothing Then         msbBuffer = New StringBuilder()     End If     msbBuffer.Append(Message)   End Sub    Public Overloads Overrides Sub WriteLine(ByVal Message As String)        If Not (msbBuffer Is Nothing) Then            Message = msbBuffer.ToString & Message            msbBuffer = Nothing        End If        EmitMessage(Message)    End Sub    Protected Sub EmitMessage(ByVal Message As String)  'Write performance data  Dim objNow As DateTime = New System.DateTime().Now         Dim objCalledFrom As New StackFrame(4)         MyBase.WriteLine("<entry>")  'Timing data  With objNow             MyBase.WriteLine(CreateTag("time",.ToLongTimeString() & "." _ &.Millisecond.ToString))             MyBase.WriteLine(CreateTag("message", Message))         End With  'Caller data  With objCalledFrom.GetMethod             MyBase.WriteLine(CreateTag("method",.DeclaringType.FullName & "." _ &.Name))         End With  'Thread data  MyBase.WriteLine(CreateTag("thread", Thread.CurrentThread.Name))  'Finish log entry  MyBase.WriteLine("</entry>")    End Sub    Protected Function CreateTag(ByVal TagName As String, _ ByVal TagContents As String) As String  'Return an XML tag  Return "<" & TagName & ">" & TagContents & "</" & TagName & ">"    End Function    Public Overrides Sub Flush()  'Flush any remaining information to file  If Not (msbBuffer Is Nothing) Then             EmitMessage(msbBuffer.ToString)             msbBuffer = Nothing        End If  'Don't forget to chain to MyBase  MyBase.Flush()    End Sub    Public Overrides Sub Close()  'Finish tracing performance data  MyBase.WriteLine("</trace>")        Me.Flush()  'Don't forget to chain to MyBase  MyBase.Close()    End Sub End Class 
end example
 

Using this trace listener is simplicity itself. See the code in Listing 6-13 for an example that writes the trace information to a file called Performance.xml. Notice that as it stands, this listener will hear all trace information emitted from anywhere in your application. You might want to restrict the listener to recording only performance data ”for instance, listening only to procedure entries and exits. To do this, you could establish some special prefix to the trace message, and then this listener can be told to ignore any trace message without this prefix. Alternatively, you can use the custom trace listener directly without adding it to the collection of trace listeners.

Listing 6-13. Using the Custom Trace Listener
start example
 Imports System.IO  'Activate the custom trace listener and its output file stream  Dim objPerformOutput As Stream = File.Create("Performance.xml") Dim objPerformRecorder As New TimerTraceListener(objPerformOutput) Trace.Listeners.Add(objPerformRecorder)  'Add this statement at the start of every monitored procedure  Trace.WriteLine("Entering procedure")  'Add this statement at the end of every monitored procedure  Trace.WriteLine("Leaving procedure")  'Add these statements when closing the custom trace listener  objPerformRecorder.Flush() objPerformRecorder.Close() 
end example
 

To see some example performance diagnostics produced by this custom trace listener, look at the XML in Listing 6-14. This listing shows just two trace entries, the first written upon entering a procedure and the second produced when exiting the same procedure.

Listing 6-14. The XML Produced by the Custom Trace Listener
start example
 <trace>     <entry>          <time>  17:06:01.861  </time>          <message>  Entering procedure  </message>          <method>ConsoleAndText.Module1.Main</method>          <thread></thread>     </entry>     <entry>          <time>  17:06:01.907  </time>          <message>  Leaving procedure  </message>          <method>ConsoleAndText.Module1.Main</method>          <thread></thread>     </entry> </trace> 
end example
 

Step 4: Trace Control at Compilation Time

Once your application is producing and recording tracing information, the next step is to control the tracing process and the amount of diagnostic information produced. This is necessary because if you emit and record all of your diagnostic information all of the time, you'll find that your application is degraded in performance and your support team will suffocate under a huge pile of mostly useless information. Trying to find the significant application issues in a giant haystack of tracing information is almost impossible, especially if your application is large and/or distributed.

You've already seen that you can control the production of all tracing information at build time with the TRACE conditional compilation flag. This is, however, a single on/off decision; either you see all of the tracing information or you see none of it. To control the tracing process at a more granular level, you need to use one or more trace switches.

There are two predefined trace switch classes, both of which are in the System.Diagnostics namespace. The first is the TraceSwitch class, which gives you up to five trace levels to control the production of trace information. The second is the BooleanSwitch class, which gives you just two trace settings (on and off). The major benefit these two switch classes give you is the ability to specify several different tracing levels at runtime without recompiling your application. You can also define a custom trace switch if you want to add to, or extend, the standard trace switch functionality.

Using the BooleanSwitch Class

The BooleanSwitch class has an Enabled boolean property that can be set either in code, from a registry or other setting, or by using an application configuration file. Setting it to 1 or above returns true ; setting it to 0 or not setting it returns false . The code in Listing 6-15 shows a boolean switch being created and set to show all trace messages. Then it shows you how to test the property before writing a trace message.

Listing 6-15. Using the BooleanSwitch Class
start example
  'Create switch for controlling tracing in hypothetical component and set 'the boolean for this switch - setting could come from registry or config file  Private bswTraceOutput As New BooleanSwitch("MyAppTracing", "Test boolean switch") bswTraceOutput.Enabled = True Public Sub Test  'Show whether the BooleanSwitch is enabled or disabled  If bswTraceOutput.Enabled Then         Trace.WriteLine(bswTraceOutput.DisplayName & " is enabled")     Else         Trace.WriteLine(bswTraceOutput.DisplayName & " is disabled")     End If End Sub 
end example
 

Using the TraceSwitch Class

Whereas the BooleanSwitch is either on or off, the TraceSwitch class is more flexible and supports five possible switches, as listed in the TraceLevel enumeration. Table 6-1 shows the supported values.

Table 6-1: TraceLevel Enumeration Values

LEVEL

VALUE

Off

Error

1

Warning

2

Info

3

Verbose

4

You can set the level of a trace switch either in code, from a registry or other setting, or by using an application configuration file. Notice that the higher levels assume the lower levels, so a setting of Warning would also show Error trace messages, and Verbose would show all trace messages. The code in Listing 6-16 shows a trace switch being created and set to show all trace information with a level of Warning or higher. Then it shows you two different ways of testing the trace switch's level before writing a trace message.

Listing 6-16. Creating and Using the TraceSwitch Class
start example
  'Create switch for controlling tracing in hypothetical component and set 'trace level for this switch - setting could come from registry or config file  Private tswTraceControl As New TraceSwitch("SwitchTrace", "Test trace switch") tswTraceControl.Level = TraceLevel.Warning Public Sub Test  'Either check the TraceError, TraceWarning, TraceInfo     'or TraceVerbose properties  If tswTraceControl.TraceError Then         Trace.WriteLine("Trace only shows if traceswitch is set to show errors")     End If  'Or check the Level property against the TraceLevel enumeration  If tswTraceControl.Level = TraceLevel.Warning Then            Trace.WriteLine _             ("Trace shows if traceswitch is set to show warnings or errors")     End If End Sub 
end example
 

Creating a Custom Trace Switch

You can create a custom trace switch by inheriting the TraceSwitch class. For instance, you might want to create custom tracing levels, maybe one for performance data, one for error information, and so on.

To demonstrate the creation of a custom trace switch, I've created one that adds extra information to any trace message and removes the task of checking the trace switch's trace level before writing the message. Before you look at the code for this trace switch, look at Listing 6-17 to see how you would use this switch.

Listing 6-17. Using the Custom Trace Switch
start example
 Private AppTrace As New TraceSwitchCustom("AppTrace", "A custom trace switch")  Public Sub Test()  'Show a trace information message  AppTrace.MessageInfo("Trace information message", _  "This is a verbose version of the trace information")  'Show a trace warning message  AppTrace.MessageWarning("Trace warning message", _          "This is a verbose version of the trace warning")  'Show a trace error message  AppTrace.MessageError("Trace error message", _     "This is a verbose version of the trace error") End Sub 
end example
 

As you can see, this class is designed to avoid having the developer mess around with either trace levels or code dealing with extra trace diagnostics. The code in Listing 6-18 shows how such a trace switch class might be implemented. All trace messages are funneled through to the ControlTraceOutput procedure, where extra trace diagnostics such as the trace originating procedure and the date and time of the trace message are added.

Listing 6-18. Creating the Custom Trace Switch
start example
 Public Class TraceSwitchCustom : Inherits TraceSwitch    Sub New(ByVal DisplayName As String, ByVal Description As String)  'Chain call to base class, then show that tracing has started  MyBase.New(DisplayName, Description)        ControlTraceOutput(TraceLevel.Info, Me.DisplayName & _ " trace listener created - trace level is " & Me.Level.ToString, "", 1)    End Sub    Protected Overrides Sub OnSwitchSettingChanged()  'Show that switch setting has changed  If Me.TraceInfo Then            ControlTraceOutput(TraceLevel.Info, Me.DisplayName & _ " trace level is now " & Me.Level.ToString, "", 1)        End If End Sub    Public Sub MessageError(ByVal Message As String, _                                            ByVal VerboseMessage As String)  'Show trace error message if errors are switched on  If Me.TraceError Then            ControlTraceOutput(TraceLevel.Error, Message, VerboseMessage, 2)        End If    End Sub    Public Sub MessageWarning(ByVal Message As String, _         ByVal VerboseMessage As String)  'Show trace warning message if warnings are switched on  If Me.TraceWarning Then            ControlTraceOutput(TraceLevel.Warning, Message, VerboseMessage, 2)        End If    End Sub    Public Sub MessageInfo(ByVal Message As String, ByVal VerboseMessage As String)  'Show trace information message if information messages are switched on  If Me.TraceInfo Then              ControlTraceOutput(TraceLevel.Info, Message, VerboseMessage, 2)         End If    End Sub    Private Sub ControlTraceOutput(ByVal MessageLevel As TraceLevel, _ ByVal Message As String, _ ByVal VerboseMessage As String, _ ByVal StackDepth As Int16)  'Validate parameters supplied by caller  If Message Is Nothing Then Message = ""           If VerboseMessage Is Nothing Then VerboseMessage = ""  'Add system date/time to the trace message  Dim strDateTime As String = New System.DateTime().Now.ToString  'Add originating module/procedure name to the trace message           '(catch any stackframe error, probably a permission problem)  Dim strTraceSource As String           Try              Dim objStackFrame As New System.Diagnostics.StackFrame(StackDepth)              strTraceSource = objStackFrame.GetMethod.DeclaringType.FullName & _ "." & objStackFrame.GetMethod.Name           Catch              strTraceSource = _              "unknown procedure (stackframe call failed - check permissions)"           Finally              Trace.WriteLine _              (MessageLevel.ToString & " message at " & strDateTime & _              " from " & strTraceSource, Me.DisplayName)           End Try  'Write augmented trace message  Trace.Indent()           Trace.WriteLine(Message)  'Emit verbose trace message if allowed and supplied  If Me.TraceVerbose And VerboseMessage.Length > 0 Then               Trace.Indent()               Trace.WriteLine(VerboseMessage)               Trace.Unindent()           End If  'Finish message  Trace.Unindent()           Trace.Flush()     End Sub End Class 
end example
 

Step 5: Trace Control at Runtime

Once your application is in testing or in production, the next step is to have runtime control over the tracing process and the amount of diagnostic information produced. This is necessary because you usually don't need to produce copious amounts of tracing information unless your testers or your end users are actually seeing a problem. During normal everyday use, you probably want to switch off most of the instrumentation to improve performance and to avoid generating useless information.

Though you can recompile your application to change its tracing behavior, it's much easier to do this with an application configuration file. A configuration file allows you to specify runtime decisions about adding and removing trace listeners, changing the level of trace switches, turning boolean switches on and off, and finally redirecting assertion failures to log files rather than message boxes. Together, these capabilities allow you to increase or decrease the amount of tracing information produced by your application, without actually having to recompile the application.

An application configuration file always resides in the same folder as its application, and it has to be named in the format MyApp .exe.config, where MyApp is replaced by the name of the executable. This text file must be in XML. The following sections discuss the XML formats used to control various aspects of application tracing.

Adding and Removing Trace Listeners

The application configuration file allows you to add and remove trace listeners at runtime. This is important because it affects the performance of your application. You probably want to have all of the trace listeners removed during normal operation in a live environment. Once a problem appears, you can change the configuration file to reinstate one or more of the listeners. The XML in Listing 6-19 shows how to add a TextWriter trace listener and remove the default trace listener using your application's configuration file.

Listing 6-19. XML to Add a Trace Listener at Runtime
start example
 <configuration>      <system.diagnostics>           <trace autoflush="true">                <listeners>                     <add name="MyListener"                               type="System.Diagnostics.TextWriterTraceListener"                               initializeData="C:\MyListener.log"/>                     <remove name="Default"/>                </listeners>           </trace>      </system.diagnostics> </configuration> 
end example
 

After you've played around with this for a while, you may notice a couple of peculiarities . The first oddity is that the documentation is wrong about the format of the type element. If you specify the assembly name System after the trace listener as the documentation shows, you'll encounter an error. It seems as though this functionality was changed after the second beta, but the documentation wasn't updated. If you do want to specify the assembly, you have to identify it completely, with something like System , Version =1.0.3300.0 , Culture =neutral , PublicKeyToken =B77A5C561934e089 . The second oddity is that the autoflush doesn't always seem to work. Although the log file is always created, forcing the trace information to be written to the log file sometimes requires a Trace.Flush and a Trace.Close before you close your application.

Trace Switch Activation

The application configuration file also allows you to change the sensitivity level of your trace switches without recompiling your software. For instance, during development and unit testing, you might want to show all trace messages, whether they're informational messages, warnings, or errors. Once the application has reached system testing, you might want to show just trace warnings and errors. Finally, when your application reaches production, you could show just trace errors. Listing 6-20 shows the XML needed to set a database trace switch to show only trace errors and a component trace switch to show all errors. The numbers refer to the levels discussed earlier in the section on trace switches.

Listing 6-20. XML for Changing the Sensitivity of Two Trace Switches
start example
 <configuration>      <system.diagnostics>           <switches>                <add name="DatabaseSwitch" value="1"/>                <add name="ComponentSwitch" value="4"/>           </switches>      </system.diagnostics> </configuration> 
end example
 

It's important to realize that, unlike the XML shown in Listing 6-19, this doesn't actually create the trace switches ”it just sets the level of trace switches already defined in your code.

Boolean Switch Activation

The boolean switch activation operates in just the same way as the trace switch activation just discussed, but of course you only have two levels with which to play. The XML in Listing 6-21 shows how to disable a boolean switch using the application configuration file.

Listing 6-21. XML to Deactivate a Boolean Switch at Runtime
start example
 <configuration>      <system.diagnostics>           <switches>                <add name="BoolSwitch" value="0"/>           </switches>      </system.diagnostics> </configuration> 
end example
 

Assertion Redirection

As discussed earlier in this chapter, assertions are used to warn the developer and support teams about runtime behavior that should never happen and assumptions that are being violated. These assertions are excellent for catching many bugs automatically and for verifying developer assumptions. Whenever an assertion fails, a message box explaining the failure is shown to the developer.

The question is, what should happen with assertions when the application is promoted into production? First, if you want to keep all of the assertion checks, there's no benefit in showing each assertion failure to the end user via a message box. This is likely to prove confusing to most users and add absolutely nothing to their use of your software. Second, you might want to turn off assertions completely because all of those checks can create a serious drag on application performance. The thinking behind this is that if all of the assumptions and other checks were validated during development and testing, there's no need to waste time on them in production.

If you want to keep your assertion checks in production, you should add the XML in Listing 6-22 to the production version of your application's configuration file to redirect all assertion failures to the specified log file. This will prevent your end users from being assaulted with unfriendly message boxes.

Listing 6-22. XML to Redirect Assertion Failure Messages at Runtime
start example
 <configuration>      <system.diagnostics>           <assert assertuienabled="false" logfilename="c:\log.txt"/>      </system.diagnostics> </configuration> 
end example
 

If you want to turn off the assertion checks entirely once your application reaches production, you should use Debug.Assert (from the Debug class) rather than Trace.Assert . The two methods produce identical results, but all Debug class methods are automatically dropped during compilation of a release build. Please see the section titled "Using the Debug Class" later in this chapter for more details.

Tracing Summary

After such an intensive examination of VB .NET tracing and instrumentation, the following list presents a quick recap of what you've just learned about working with application tracing diagnostics:

  • Categorize your diagnostic information : Decide what tracing information is required and divide the output into error messages, warning messages, informational messages, and extra detail (verbose) messages. These categories match the predefined tracing levels that have already been discussed.

  • Add tracing code : Use the Trace class to add the required tracing code to your application.

  • Add trace listeners : Use predefined or custom TraceListener classes to define the trace message destination(s).

  • Add trace switches : Use the TraceSwitch and BooleanSwitch classes to specify when and which tracing information is shown.

  • Useruntime tracing control : Use your application's configuration file to control trace listeners, trace switches, and assertions at runtime.

I've spent a lot of time discussing the Trace class and its companions, but it also has an important counterpart in the Debug class.




Comprehensive VB .NET Debugging
Comprehensive VB .NET Debugging
ISBN: 1590590503
EAN: 2147483647
Year: 2003
Pages: 160
Authors: Mark Pearce

flylib.com © 2008-2017.
If you may any questions please contact us: flylib@qtcs.net