iagnostics, also known as “program tracing,” is a crucial?and often overlooked and underappreciated?component of application development. I have long been an ardent believer in diagnostic support, and have written diagnostic systems from scratch for a diverse assortment of software and hardware products, including integrated circuit design tools, laser printers, and user interfaces. As Microsoft’s .NET Framework Developer’s Guide puts it, diagnostics is:

“?a way to monitor the execution of your application while it is running. You can add tracing and debugging instrumentation to your .NET application when you develop it, and you can use that instrumentation both while you are developing the application and after you have deployed it.? [Y]ou can record information about errors and application execution to logs, text files, or other devices for later analysis.”

What You’ll Cover
Despite a plethora of diagnostic information on MSDN and elsewhere, you’ll get some material from this article that’s difficult or impossible to find anywhere else, such as:

• A practical example of multi-module instrumentation: You’ll see how to design a library that you could use both with diagnostic-aware or with diagnostic-unaware programs.
• A sandbox: You’ll find the sandbox a good place to exercise all combinations of diagnostic levels, output options, and output channels (listeners).
• Output examples: You can see at a glance the differences in output for every pre-defined listener.
• Comparison charts: The charts let you compare the output of each pre-defined listener: always, never, or on-demand.
• A customized listener: This listener lets you review a diagnostic log quickly and effectively. It functions as both a tutorial, giving you a step-by-step guide to learning and using diagnostics, and a reference?a summary of the salient details, pitfalls, and features you need to know.

The .NET framework has included diagnostic capabilities from its early days. Prior to .NET 2.0, the prescribed technique was to use the Trace or Debug classes. (These two classes have identical functionality; the only difference is that the framework compiles Trace functionality into release builds by default, but does not compile Debug functionality by default.) Both classes provide static methods, including WriteLine, WriteLineIf, Assert, Fail, and others that interact with BooleanSwitch or TraceSwitch classes to provide diagnostic logging capabilities. Microsoft’s Introduction to Instrumentation and Tracing covers this older diagnostic capability thoroughly, so I won’t cover it here.

Both this reference and the earlier link are good starting points for tracing. An easy point of confusion, however, is that both of them focus primarily (but not entirely) on the old-style, pre-.NET 2.0 tracing. They hyperlink to TraceSources?a new style available from .NET 2.0 onward. Interestingly, I could not find an overview section in the MSDN documentation for the new-style tracing.

New-style tracing still relies in part on the old-style components. For example, to turn on automatic flushing, you need to set the static Trace.AutoFlush property, as discussed later. See the “Tracing References” sidebar for more links to pre-.NET 2.0 tracing. If you plan to follow along using the downloadable code for this article, you should also take a look at the sidebar “The Demo Projects and Their Library Components.”

Using Diagnostics in Your Applications

	?
Figure 1. Demo Application: You can use this simple UI to explore many of the diagnostic capabilities built into the .NET framework.

Figure 1 shows the demo application’s simple user interface. When you launch the application, the text box initially contains a dump of the tracing settings specified in the application’s configuration file. The check box represents the collection of settings you might activate in a typical application. The Go button begins a processing run, which generates some diagnostic output. The only action you will see on-screen is a message that you have pressed the button, plus another dump of the tracing settings. The code is in the event handlers attached to the button and the check box.

Instead of first discussing all the details about the diagnostic system mechanisms, I’ll start with the sample application itself. Figure 2 shows diagnostic output from the application rendered by a myriad of choices that determine the quantity and type of output desired. The application records output to a log file (diagnostic.log) in the same directory as the executable.

	?
Figure 2. File Tail Viewer: The diagnostic output in this file includes: (1) The start of a session; (2) The instantiation of a tracing object; (3) Entering an event handler method; (4) Entering a general method; (5) A constant message; (6) A message showing a parameter value.

You can see two groups of properties in Figure 2; the properties in this first group are a function of the TraceListener you choose. The.NET framework has five built-in TraceListeners to pick from, but I ended up designing my own because none of the standard TraceListeners meets all these goals:

• Strict adherence to one line per log event
• Date, time, source, process, and thread information attached to each record and always aligned vertically
• Indentation to visually show nesting of method calls such that all trace sources honor the same indentation
• Full control over what fields the output will include

The goals in this second group are a function of the mechanism for viewing the diagnostic output after it has been recorded by your application:

• On-the-fly color-coding capability
• Dynamic output, so every diagnostic record is displayed as soon as it is recorded
• Multiple logs are available if needed, via separate tabs in the diagnostic viewer

The screen shot in Figure 2 shows a popular, general purpose file-tail viewer called BareTail a graphical implementation of the common Unix/Linux tail program. BareTail waits for more output to be written to a file by some external application, and then displays it immediately, which fulfills one of the goals listed above. While any good tail program will work, BareTail is nice because it includes a multiple-tabbed interface, provides all the color-coding you see in the figure (you simply need to specify the textual patterns you want to match and assign foreground/background colors for those matches)?and it’s free.

A Walk Through the Code
The TraceSourceDemoApp.cs file contains a static constructor, an instance constructor, three event handlers, and three support methods. First, you need a TraceSource as a handle into diagnostics. A TraceSource is the standard top-level, tracing .NET component that connects to the named section of your app.config file via the specified name. This demo uses a customized StructuredTraceSource, which adds some features to the standard TraceSource, providing a better quality of output, as you will see later. The first argument to the constructor is a reference to a TraceSource defined in your application’s app.config file. The second (optional) argument is an options value?a bitwise combination of TraceOptions flags to be used in logging.

The class (or static) constructor selects options for the single TraceListener used in this application. It then instantiates the StructuredTraceSource with some standard options at the TraceSource level, which find their way internally to the TraceListener attached to the TraceSource. The order of these is important. The act of instantiating a StructuredTraceSource will itself write some diagnostic output. Therefore, you must adjust any TraceListener options before you create the StructuredTraceSource.

A static constructor is a handy tool for your coding toolkit if you are not familiar with it. Less well known than a “regular” or instance constructor, a static constructor runs once and only once?upon your first access to the class?no matter how many instances of the class you create. One common use is to set up class properties or variables before any objects are instantiated. The StructuredTraceSource named tracer in the following code is such a class (or static) variable. So if you were to define a class containing a static StructuredTraceSource then instantiate multiple copies of your class, all will share the same StructuredTraceSource?and they should?for efficiency. Instantiating the StructuredTraceSource within this static constructor guarantees it will be available when any instances of the class (in this case, TraceSourceDemoForm) are instantiated.

Here is the static constructor for the demo application:

   static TraceSourceDemoForm()   {      AlignedTextWriterTraceListener.EventTypeLength = 0;      tracer = new StructuredTraceSource("DemoMain",         (TraceOptions.DateTime |          TraceOptions.ProcessId | TraceOptions.ThreadId));   }   

The instance constructor (shown next) begins with the standard InitializeComponent call common to GUI applications. The second line is optional; it serves to let you see what all the TraceSource settings are before the tracing actually gets started, dumping that info into the TextBox on the form.

All methods that send output to your collection of Listeners have the “Trace” prefix. The standard TraceSource class includes TraceEvent, TraceInformation, and TraceData. The StructuredTraceSource class inherits those and adds TraceEnter, TraceLeave, and others discussed later in this article (see Table 1):

   public TraceSourceDemoForm()   {      InitializeComponent();      AddOutputToTextBox(tracer.Dump());   }   

The form Load event handler invokes the StructuredTraceSource’s TraceEnter and TraceLeave methods; these trace execution entering or leaving the event handler. These, in fact, led to the naming of the class; “structured” is intended to invoke the image of successive levels of hierarchy shown by indentation in the diagnostic log. The StructuredTraceSource is optimized for recording the flow of an application and these two methods are key. They write Enter and Leave events in the output as well as automatically indenting (on an Enter) and exdenting (on a Leave):

   private void Form1_Load(object sender, EventArgs e)   {      tracer.TraceEnter();      tracer.TraceInformation("constructor processing here...");      tracer.TraceLeave();      // Not needed since StructuredTraceSource sets Trace.AutoFlush.      // tracer.Flush();   }   

Note the final comment in the method as well. To ensure that trace output reaches your trace file, you need to periodically flush, or ultimately, close the TraceSource. The StructuredTraceSource sets the static Trace.AutoFlush property which causes every trace event call to be flushed immediately. Whether you use a regular TraceSource or a StructuredTraceSource, be sure to consider how you wish to handle the issue (e.g. you could turn it off).

You are not required to mark any particular event (Enter, Leave, etc.) in any particular methods of your code. In fact, if you use TraceEnter and TraceLeave in every method, you may get more verbose output than you need. If you do use them, however, the call to TraceEnter, by convention, should be the very first line of your method and TraceLeave should be the last line (or the penultimate line when the method has a return statement). Between the TraceEnter and TraceLeave methods you’d typically have one or more calls to the TraceInformation method (this is the same method available from a regular TraceSource object because StructuredTraceSource derives from TraceSource). Table 1 lists the methods available to emit diagnostic information from a TraceSource or a StructuredTraceSource.

TraceEvent is the main workhorse method for diagnostics. You specify a TraceEventType (see Table 2), an event ID, and a message to log. An event ID is completely arbitrary unless you care to output diagnostics to your system event log, viewable with the standard Event Viewer tool. There event IDs have significance; for example, 6005 is the event ID of a boot, and 6006 is the event ID of a clean shutdown (see Event Log Entries). Your events will be comingled with other application events in the application log, so you may want to give some thought to what you assign. Note that TraceInformation is just shorthand for one type of TraceEvent call, which always uses a TraceEventType of Information and an event ID of 0.

The methods added by StructuredTraceSource are also shorthand for calls to TraceEvent. Each of these uses a TraceEventType of Information but the event ID is unique to each (shown in Table 1). Using properties, you may change these event IDs to any value you choose (such as 0 to be consistent with TraceInformation calls).

If you have multiple return statements in a method, you should place a TraceLeave call just before each of them, so no matter which exit route is taken the initial TraceEnter will always be balanced with a terminating TraceLeave. That is vital for keeping the indentation of the log correct. If possible, consider writing each method with just a single exit point, at the bottom of the method. Sometimes it is not convenient to do so, but often code can be rearranged easily to do this. Then you only need use a single TraceLeave call just before the return at the bottom.

A note on nomenclature about events: There are conventional events that you, as a .NET developer probably think of first, i.e. those that are processed by event handlers, as in a form load event or a button click event. Then there are trace events?events signifying something “newsworthy” enough that you want to log them. Each such trace event has a TraceEventType (see Table 2).

The StructuredTraceSource adds methods that generate output with the TraceEventType of Information, subdividing this single event type into sub-event types (see Table 3).

EnterEventHandler and LeaveEventHandler form a nexus for confusion about the term “event”: they are sub-events of tracing events, but they both refer to conventional events! The code examples you’ll see later in this article should disambiguate these for you.

The next two methods are representative samples of conventional event handlers for explicit user actions, clicking a button and checking a box. Each implements the same pattern: a call to TraceEnterEventHandler, some processing, one or more calls to TraceInformation, and a call to TraceLeaveEventHandler. Both TraceEnterEventHandler and TraceLeaveEventHandler are akin to the TraceEnter and TraceLeave that you just saw above, but they output additional information in the diagnostic log, indicating the object name and display name of the object acted upon by the user (extracted from the sender parameter to the event).

The name of the TraceEnterEventHandler method provides a good clue as to its intended purpose: it is a trace output method because it begins with “Trace”, it is a method that indicates entering a method due to the second word, and it should be used to instrument a conventional event handler, as the final chunk indicates. The same concepts apply to the TraceLeaveEventHandler method name.

   private void goButton_Click(object sender, EventArgs e)   {      AddOutputToTextBox("Go button pressed.");      tracer.TraceEnterEventHandler(sender);      tracer.TraceInformation("running with checkbox "         + (colorizeCheckBox.Checked ? "CHECKED" : "UNCHECKED"));      ProcessLevel1();      tracer.TraceLeaveEventHandler(sender);   }      private void colorizeCheckBox_CheckedChanged(object sender, EventArgs e)   {      tracer.TraceEnterEventHandler(sender);      tracer.TraceInformation("checkbox changed from checked={0} to checked={1}",         colorizeCheckBox.Checked, !colorizeCheckBox.Checked);      tracer.TraceLeaveEventHandler(sender);   }   

The next two methods are more representative of real methods, in that they do not do all the work themselves, but break it down and pass it along to subordinate methods. Again you will observe that each method has a TraceEnter/TraceLeave bracket, possibly some TraceInformation calls, and then calls to other methods. So ProcessLevel1 calls ProcessLevel2 which in turn calls an external method called SomeCalc, discussed next. As mentioned, each TraceEnter call not only outputs a trace event of type Information and sub-type Enter, it also increases the indentation level of the log. As you get deeper into your method stack, then, the diagnostic output gets indented correspondingly, providing a visual analog of your program structure’s hierarchy.

One additional minor observation: in both of these methods you see the TraceInformation call is passed a single string. But look back at the colorizeCheckBox_CheckedChanged method and you will see that it also has a “built-in” formatting handler: it implicitly calls the String.Format method if you provide a format string and corresponding arguments:

   private void ProcessLevel1()   {      tracer.TraceEnter();      tracer.TraceInformation("processing here at level1...");      ProcessLevel2("abc");      ProcessLevel2("xyz");      tracer.TraceInformation("Finished processing.");      tracer.TraceLeave();   }      private void ProcessLevel2(string parm)   {      tracer.TraceEnter();      tracer.TraceInformation("processing here at level2 with parm=" + parm);      if ("abc".Equals(parm)) { TraceSourceDemoLibrary.SomeLibClass.SomeCalc(); }      tracer.TraceLeave();   }   

Connecting Diagnostics Between Your Application and External Libraries
The SomeCalc method called inside ProcessLevel2 is a static method defined in the SomeLibClass shown next. (Whether it is a static or an instance method is unimportant.) This small class is contained in a separate library defined in a separate Visual Studio project called TraceSourceDemoLibrary, which generates a DLL referenced in the current project. (The TraceSourceDemoLibrary could just as easily have been in a separate solution.) The point is that the coupling between the current project and the library is minimal. Here is the entire class:

   public class SomeLibClass   {      private static StructuredTraceSource tracer         = new StructuredTraceSource("DemoSecond");         public static void SomeCalc()      {         tracer.TraceEnter();         tracer.TraceInformation("stuff in a library module");         tracer.TraceLeave();      }   }

There are three ways the SomeLibClass differs from the TraceSourceDemoApp project:

1. Both classes define a static StructuredTraceSource, but where the TraceSourceDemoApp project referenced the “DemoMain” TraceSource, the TraceSourceDemoLibrary references the “DemoSecond” TraceSource.
2. The SomeLibClass code declares and initializes the tracer variable in one statement, while the main application initialized it inside a static constructor. Why the difference? In this case the application doesn’t have to execute any statements before instantiating the StructuredTraceSource.
3. This library uses a different form of the StructuredTraceSource constructor, one that does not include TraceOptions. The main application included some settings of the listener both before instantiating the StructuredTraceSource and during instantiation, while this one does not. That’s because by the time the SomeCalc method gets called (and therefore this class is first accessed, triggering static initialization), the demo application has already output a number of diagnostic lines. If this library class were to set trace output options in mid-stream, nothing would prevent those options from being different than those used by the main program?which is generally undesirable: all diagnostic output from an entire application should be consistent for ease of interpreting the results. Figure 3 clarifies this point. The figure shows diagnostic output from multiple sessions of this TraceSourceDemoApp, highlighting the point where the main application connects to a TraceSource and where the library connects to a TraceSource.

	?
Figure 3. Diagnostic Output from an AlignedTextWriterTraceListener: All columns are aligned, irrespective of indentation and irrespective of source library.

In Figure 3, you can see that the library trace output integrates seamlessly in terms of indentation, because the constructor does not specify any output options; instead it just continues with those already established by the main application. This provides two subtle but important advantages:

1. The library needs to know nothing a priori about the application that will reference it.
2. The library does not affect output from the main application because it does not set any output options.

When you design library tracing this way, an application designer does not have to worry about side effects from any libraries used, and the library designer doesn’t have to worry about which applications the library code might plug into.

The application and the library are connected, of course, but only by very loose coupling?the single argument to the StructuredTraceSource constructor that references a TraceSource from the app.config file (see Listing 1).

The element in Listing 1 contains three children: , , and . Though they all appear as children of the element, switches and shared listeners are subordinate to sources. A source has a name attribute you use to reference the source in your code; a switchName attribute, with which you reference a particular switch from the element; and a child element, with which you reference one or more listeners from the element. The first element shown has the name “DemoMain,” which is the name passed in the StructuredTraceSource constructor of the demo application. Similarly, the second element has the name “DemoSecond,” which is used in the StructuredTraceSource constructor of the library class. You can see this both by reviewing the code discussed earlier, and by observing the highlighted CREATE entries in Figure 3.

So, putting all this together, when you create an instrumented library, the name of its TraceSource needs to be part of its advertised API. Anyone (including yourself) who wishes to be a consumer of that library would then need only add a element to the main applications app.config file to enable diagnostic output from that library.

This does not imply that there is a one-to-one mapping between libraries and TraceSources. The main demo application uses a single TraceSource. But if you have a large program and you want to be able to see diagnostic output from one portion of code but not from another, simply create two TraceSources. Or more, if you want even finer resolution over what will reach your diagnostic streams. Similarly, you may have zero or more TraceSources associated with each library that you create. This is the first component of controlling what you log: create a separate TraceSource for each “channel” of output that you want to control.

To turn on output for a particular TraceSource, you set the value of the associated TraceSwitch in the app.config file. Note that app.config is relevant primarily within the confines of Visual Studio. Once you have compiled your program and you run it independent of Visual Studio, the app.config file gets a new name, which is your executable with a “.config” suffix appended; in this case, TraceSourceDemoApp.exe.config. Everything discussed about app.config in this article also applies to your xxx.exe.config file, with the further advantage that no recompilation is required.

The demo application works exclusively with the TraceEventType of Information, but in the next section you will see others in play. Take a look at the hierarchy of Table 4 (ignoring the ActivityTracing level). If you set the TraceSwitch to All, as you have seen, the application outputs Information events. If you set the TraceSwitch level to Verbose or Information, the application will still output all the Information event messages. But in this demo application Warning, Error, and Critical are just synonyms for Off because an Information event does not rise to the urgency required by any of those levels.

This is the second component of controlling what you log: set each TraceSwitch to an appropriate level. You could, for example, set all your switches to Error as a default, but then set the switch for the new module that you are debugging to Verbose.

Controlling Trace Format
You have seen techniques for controlling the flow of trace information, but you also have substantial control over the format of that information with TraceListener objects. The app.config file code in Listing 1 adds a single TraceListener for each TraceSource. Both TraceListeners are of the same type?AlignedTextWriterTraceListener?a custom listener described in detail later. Both TraceSources use not only the same type of TraceListener, but by design they reference the same instance of AlignedTextWriterTraceListener. That’s important for seamless integration among the collection of TraceSources. You could create a local TraceListener connection for a TraceSource by modifying the child in the element. Instead of referencing a TraceListener from the collection, you would explicitly define it in the element. But each must reference its own file.

I find AlignedTextWriterTraceListener the most useful type for my development style, but you may prefer any of the several standard types, or create one of your own. The point is that you have great flexibility as to how the information is presented. This is the third component of controlling what you log: select (or create) a TraceListener that produces output most comfortable to your working style. Table 5 enumerates the available TraceListeners.

Footnotes to Table 5:

• ¹ The DelimitedListTraceListener emits standard comma-separated values (CSV file), wrapping string arguments in quotes. (It will use whatever delimiter you specify, not just commas.) So the natural question to ask is: what are the fields in the file? I was unable to find the answer to this in the MSDN library so I found it through experimentation. The fifth field was always empty in my trials so I could not say what it is for, but here’s the list: Name, Level, EventId, Message, ?Reserved (empty) field, ProcessId, LogicalOperationStack, ThreadId, DateTime, TimeStamp, and CallStack. Note that an event may or may not be contained entirely on one line. If you include the CallStack, for example, though contained within quotes that field will include embedded line breaks.
• ² Through no fault of the XmlWriterTraceListener, it cannot create an output file that is legitimate XML at any instant. Why? A valid XML file consists of a single root element containing zero or more child elements. If the trace listener emitted the opening tag of the root, and then began emitting children, it would always be missing the closing tag of the root, so it would not be balanced and hence not valid. If instead?as it actually does?it ignored the root and simply emitted a list of children, one element per event, then the file would be balanced but not valid because it would violate the rule of only one root (each child would in fact be considered a root in this case). So if you need to legitimize the XML you must wrap it in a root element. Alternatively, you can view it in an XML editor that is more forgiving.
• ³ I list the DefaultTraceListener for completeness, but in practice its use seems to be rare. One important reason for this is that the Fail method pops up a message box that may not be expected or desired. If you use libraries written by others, you have no way of knowing whether that would occur. In every example and tutorial I have seen, the first thing they tell you to do is take out the default listener, either in the configuration file or in code.

Depending on what type of TraceListener you choose, some information fits more naturally than others. For example, I did not design the AlignedTextWriterTraceListener to handle the call stack as that is, by its nature, a voluminous multi-line construct, and one of the main strengths of AlignedTextWriterTraceListener is “one event = one line of output.” Table 6 shows all the possible attributes for each standard TraceListener plus the AlignedTextWriterTraceListener. The shaded rows indicate those attributes that may be enabled or disabled via the TraceOutputOptions property of the listener.

The EventLogTraceListener does not use the TraceOutputOptions property at all, because according to Microsoft “it can cause a large volume of data to be written to the log.” Thus, Table 6 shows that all entries for this listener are either “always” or “never.”

Footnotes to Table 6:

• ¹ Indent applies globally: any connected TraceSources will both honor and affect the current indentation.
• ² Indent applies locally: the indentation of each TraceSource is independent of any others in different executables (DLLs).
• ³ The item is not selectable in the standard TraceOutputOptions but may be suppressed by setting the appropriate length property.

Your choice of TraceListener may be driven by what attributes you need to see in your diagnostic output; Table 6 can help you determine which TraceListeners will meet your needs. You could take the minimalist approach and show only the logging message that you pass in, or you could add any or all of the attributes listed in the table. This is the fourth component of controlling what you log: pick and choose the attributes you want in your output.

You can enable or disable the shaded entries in Table 6 for any TraceListener by combining elements of the TraceOptions enumeration into the TraceOutputOptions property of a TraceListener. Several other entries in the table are marked to indicate that you may enable or disable them solely for the AlignedTextWriterTraceListener?via a different mechanism. This custom listener provides properties that specify the output column width for each attribute. These properties are named with a “Length” suffix, as in ProcessIdLength. Setting this property to zero turns off the attribute. I felt it was useful to give length properties to all the fields where it made sense, so some of them have dual controls as a side effect?in other words you can turn off ProcessID either by omitting it from the TraceOutputOptions or by setting ProcessIdLength to zero. Conversely, to turn it on you must include it in TraceOutputOptions and ProcessIdLength must be a positive number. Table 7 summarizes the default settings for all the attributes of Table 6. The DateStamp attribute in Table 7 is unique in that it does not have a length property but instead has a format property, which defaults to MM/dd/yy hh:mm:ss.fff tt. See Standard DateTime Format Strings for how to specify date formatting.

A Guide to Controlling Trace Output
As a summary to the vital concepts you have been reading about, Table 8 collects reference links that you may need. Don’t remember the difference between a TraceSwitch and a TraceSource? Check this table. Need to know how to define something in the configuration file? Check this table!

Interested in designing your own TraceListeners? Take a look at the source code for the AlignedTextWriterTraceListener referenced in this project, or the TextBoxTraceListener discussed in the next section. A couple other tutorials specifically on customization are also available: CLR Inside Out: Customized Tracing and Custom Trace Listener.

Build a Trace Output Comparison Sandbox

	?
Figure 4. Diagnostic Sandbox: This is the UI for the TraceSourceGuiApp that lets you experiment with any combination of source levels, trace options, and trace listeners.

It helps when you can actually compare the output of each TraceListener, using identical diagnostic output. The next application provides a sandbox tool so you may do this yourself. You’ll also see snapshots of each TraceListener’s output. Figure 4 shows the UI for the tool. The top half enumerates all source levels, trace options, and trace listeners. The bottom half contains a large TextBox used for user feedback; it’s initially loaded with a dump of the main TraceSource used by the application. You can get a current snapshot at any time by pressing the Dump button.

All the radio buttons and check boxes are populated dynamically. The first two group boxes will probably not change much over time, but they may when a new release of the framework comes out. The third group box?the trace listeners?is populated based on the contents of the app.config file and/or any TraceListeners that you create programmatically. Each TraceListener gets a check box in the trace listener group, but its configuration will also be listed in the output area. This configuration reflects the initial configuration from the app.config file, plus any changes you have made programmatically before the form actually opens.

Given the preliminaries you learned in the earlier parts of this article, the user interface of this tool should be reasonably evident. If you want to refresh yourself:

• Source Levels?see Table 4
• Trace Options?see Table 6 (the shaded rows)
• Trace Listeners?see Table 5 (except for the TextBox).

	?
Figure 5. TraceListener Output: Each TraceListener includes a specification for where its output goes. The file names are detailed in the application’s configuration file. If you want to change one, you can edit the configuration file without needing to recompile the application.

All the TraceListeners except the TextBox type are detailed in Table 5. The TextBox TraceListener exists in the sandbox project only; it allows you to send diagnostic output directly to the text box of this application.

Working with the application is simple: select a source level, any number of trace options, and any number of trace listeners, then press Go. The application then exercises each of the common trace event types (see Table 2) for all TraceListeners you have selected. The output of each trace listener goes to a different destination, as shown in Figure 5. Note that output from the Console TraceListener will not be available unless you are running inside Visual Studio, because the application is a graphical rather than a console application.

Table 9 shows the output from each TraceListener responding to the same trace events with the same output settings. You can reproduce equivalent results by selecting All for the source level; DateTime, ProcessId, and ThreadId for trace options (my preferred combination); and all the trace listeners listed. The more expansive formats have linked figures showing more complete samples. Note that there is no requirement for all TraceListeners to use either the same source level or the same output options; the TraceSourceGuiApp just happens to work that way for easier “apples to apples” comparisons.

TextWriter and Console output sample (see Figure 6):

DelimitedList output sample:

AlignedText and TextBox output sample:

XmlWriter output sample (see Figure 7):

Event Log output sample:

? Figure 6: Full TextWriter and Console Output Sample: Selected trace options are output one per line.

? Figure 7: Full XmlWriter Output Sample: Your diagnostic message maps to the element, and your selected trace options are emitted as XML attributes of the element.

	?
Figure 8: Application configuration file: The highlighted items are: (1) the two TraceSource names, which you use to reference the TraceSources from your code; (2) the output files passed to constructors of a couple TraceListeners; and (3) a filter that acts as a single-listener-specific switch.

For brevity, this article won’t walk through the TraceSourceGuiApp code, but it will discuss the key points. First, take a look at the configuration file (see Figure 8). For educational purposes, the application uses two TraceSources. The previous application used one in the main program and another in an external library. Here, the main program uses both. Each uses the same set of seven listeners: six are defined in the configuration file as shown here and the remaining TextBox listener is defined programmatically.

Most TraceListeners have a variety of constructors, but the configuration file does not support all of them?it supports only those that take string arguments. As the configuration sample shows, you pass the string arguments to the constructors in the initializeData attribute. Typically, this will be a file name. That means that you can’t initialize a constructor that uses a Stream, a TextBox, or any other object, in the configuration file. That does not necessarily prevent you from instantiating all your listeners in the configuration file. You could define a listener here using some dummy string arguments, and then update it during your program initialization to configure it completely.

Another new feature introduced here is the child attached to most of the listeners. It is not strictly necessary, because it’s manipulated in the code, but including it here illustrates where it would be used. The combination of the source level of the switch and the source level of the filter determines the trace listener’s ultimate output.

The earlier discussion of the TraceSourceDemoApp application mentioned that you should generally use shared listeners rather than private listeners if you want seamless integration for your separate modules. I stated that shared listeners use the same instance of a listener. That is only partly true. (I suspect it is a bug and should have been completely true.) Using a shared listener lets all consumers write to a single file. That’s true. Using a shared listener lets you set the TraceOutputOptions once and everyone gets access to them. That’s true. But then there’s the common indentation issue. When different TraceSources are in the same file, such as in this TraceSourceGuiApp, they have common indentation. When they are in different modules, such as in the TraceSourceDemoApp, they do not have common indentation. As I was designing my custom AlignedTextWriterTraceListener I discovered the indentation was corrupted, so I had to build in a fix to make the indentation global. Table 10 summarizes the differences between shared and local (or private) TraceListeners.

The configuration file connects to your program by the names of the elements as you have seen. In the TraceSourceGuiApp constructor you see where these TraceSources are initialized with names corresponding to the configuration names. This application is again using StructuredTraceSources instead of TraceSources to take advantage of the extra program flow tracing methods they offer. The constructor also builds a list of its TraceSources so that when a user chooses the settings, they may be applied to both TraceSources. The final statement sets up the TraceListener that is used to channel output into the output pane of the application. This TraceListener is defined in InitializeTextBoxListening, specifying the TextBox it will send output to and a name to reference it. The second line programmatically turns the listener off via its Filter property, the programmatic corollary to how you saw it done in the configuration file. The final line adds this listener to both TraceSources?just as in the configuration file, all the other listeners were added to both TraceSources.

   public TraceSourceGuiForm()   {      InitializeComponent();      AlignedTextWriterTraceListener.SourceNameLength = 16;      tracer = new StructuredTraceSource("TraceSource_Main");      tracer2 = new StructuredTraceSource("TraceSource_Secondary");      sources = new TraceSource[] { tracer, tracer2 };      InitializeTextBoxListening();   }      private void InitializeTextBoxListening()   {      TextBoxTraceListener l = new TextBoxTraceListener(         diagTextBox, "TextBox");      l.Filter = new EventTypeFilter(SourceLevels.Off);      foreach (TraceSource source in sources)          { source.Listeners.Add(l); }   }   

Pressing the Go button invokes the event handler shown below is invoked. This method first sets the source level for both TraceSources based on the user’s selected settings. Next, it sets the TraceOutputOptions of each listener to the set of options the user chose. That method walks through the list of listeners, setting each one either on or off depending on the checked choices. The ExerciseTraces method simply invokes a series of TraceEvents. Finally, the method flushes the output so all listeners will write to their respective media for you to view.

   private void goButton_Click(object sender, EventArgs e)   {      // Set the user's selected level.      foreach (TraceSource source in sources)      { source.Switch.Level = GetSourceLevel(sourceLevelGroupBox); }         // Set the user's selected output options.      SetSelectedOptionsForListeners(         BuildTraceOptionsList(traceOptionsGroupBox));         ExerciseTraces();         foreach (TraceSource source in sources)          { source.Flush(); }   }

Troubleshooting Tracing
There is an old adage “If it doesn’t work, try plugging it in!” Which is to say, start with checking the obvious possibilities first. With the .NET diagnostic components, there is nothing that is quite “obvious” (unless you are a hard-core geek). And to exacerbate the situation, components are designed to fail silently rather than verbosely, which is both a blessing and a curse. It’s useful because it lets you design tracing into independent libraries, or even use libraries that others have written and instrumented, and connect up the diagnostic plumbing in them to your main application?or ignore it. If the components complained when they did not connect, they would likely interfere with your application by, for example, throwing an unexpected exception.

The StructuredTraceSource application includes a Dump method that can help troubleshooting diagnostic connections. You saw the output of this in the TraceSourceGuiApp application, which includes a button to invoke Dump on demand.

	?
Figure 9: Diagnostic Data Flow: Use this figure with the troubleshooting steps to determine the cause of unexplained output or lack of output from your diagnostic instrumentation.

Figure 9 presents a visual guide to the plumbing of the diagnostic components. Plumbing is an apt metaphor; for you really are dealing with data flowing from your program (entering at the upper left of the diagram) and flowing down to files or event logs (lower right). As the figure shows, there are six valves and connections between your program and your output, each of which must be set in the correct position to get the output you expect. The first six steps below correspond to those six hurdles. The remaining steps discuss other pieces of the diagnostic puzzle that you will inevitably need to consider.

In Figure 9, the green callouts indicate “valves” that must be opened properly. Yellow callouts indicate required connections. For instance, the first connection indicates that the constructor for a TraceSource in your program must match a value specified in your app.config file; that value is specified with XPath notation because the configuration file is XML.

Step 1: Are you compiling with tracing enabled? In Visual Studio, this is controlled with a checkbox on the build properties page to define or omit the TRACE constant. This is an on/off valve, the first one at the upper left of Figure 9.

Step 2: Is your TraceSource in code connecting to the TraceSource in your configuration file? The two pieces are coupled together by matching the constructor’s name parameter (in code) to the name attribute of a element (in app.config). This is the key element that allows you to use “plug ‘n play” with libraries from diverse sources. If a foreign library references a TraceSource that does not exist in your configuration file, it never outputs any diagnostics. That is, as explained above, both good and bad.

Step 3: Is your TraceSource coupled to your TraceSwitch? This connection is typically internal to the configuration file. In XML terms, //sources/source/[@switchName] must match some //switches/add/[@name]. If they do not match, your diagnostic output is spilling on the floor rather than traversing your pipes.

Step 4: Is the TraceSwitch spigot (//switches/add/[@value]) open far enough? While not having the continuous range of a real spigot, a TraceSwitch has many settings (see Table 4) between fully open (All) and fully closed (Off). If you are, for instance, outputting Information-level events but your switch is open only far enough for Warning-level events to flow, you will get no output.

Step 5: If you are using a shared listener, is your TraceSource coupled to your TraceListener? That is, //sources/source/listeners/add/[@name] must match an instance of //sharedListeners/add/[@name].

Step 6: Is the TraceListener spigot (//sharedListeners/add/filter/[@initializeData] or //sources/source/listeners/add/filter/[@initializeData]) open far enough? Remember that you have several switches in series, and all must be open far enough for your data to flow. TraceListeners have the same range of opening individually as the main TraceSwitch does, from Off to All, and only data with enough “water pressure” to push through both switches will make it through.

Step 7: Are you looking at the right destination bucket (//sharedListeners/add/[@initializeData] or //sources/source/listeners/add/[@initializeData])? This XML attribute typically specifies either a file name or an event log, depending upon the type of TraceListener.

Step 8: Did you flush your output through the pipes? To actually write data to your file or event log you need to call the TraceSource.Flush method. Alternately, set the static Trace.AutoFlush property to true to automatically flush after every event. The latter is not the best strategy for performance, but it certainly gives you timely output. (StructuredTraceSource defaults to the Trace.AutoFlush property, while the base TraceSource defaults to false.)

Step 9: Are you getting the tracing attributes from TraceOptions that you want? Ensure that you set the correct options for each listener. Does the selected listener actually support the options you set? Are your TraceOptions not showing up on your first few lines of output? Make sure that you set them before any output can occur. Using the custom AlignedTextWriterTraceListener, for instance, just instantiating one will output an Information event. So you must set the TraceOptions in the constructor, not as an afterthought. Are you using old-style Trace.WriteXxx calls? TraceOutputOptions do not work with the static WriteXxx methods of Trace or Debug (see this forum thread).

Step 10: Are you using AlignedTextWriterTraceListener and not getting all the columns you want? Any tracing attributes that has a length property must have a positive value to be seen.

Step 11: Are you getting an empty output file? That indicates that your couplings are correct but your switches are not open enough (or open at all). Even if you turn off tracing in a given pipe using either a filter or a switch?or even the TRACE compilation constant?your application will still create an empty tracing file if the connections are set up properly.

Step 12: Did you modify your application’s configuration file after you started execution? Trace configuration data from the file is captured when the application is started. If the configuration data is changed after the application is started, you must call the Refresh method to update the trace configuration data.

Even More Tracing Options
There are varying opinions as to how useful or complete the .NET framework tracing capabilities are; I think they are quite reasonable, but you may want to consider alternatives. TracerX is a very recent one that looks quite interesting and easy to use; it is a fine effort by a single developer. Log4Net is under the auspices of the Apache organization web site and has a team of developers. If you are a multi-lingual designer, it has the advantage that there are flavors of it for other languages as well (Log4Java, Log4Perl, etc.). I have not used either of these, but both appear to be excellent alternative tools.

Whatever technology you elect to use, diagnostic tracing is an important tool to include in your arsenal of software techniques when developing commercial or complex systems. It is useful not only during program development but even more so once your application is deployed. Ongoing maintenance costs are one of the largest segments of software’s true cost, and well-instrumented diagnostics can reduce maintenance costs significantly. You want to have enough tracing statements in your code to be able to see what is going on, but not too many to degrade performance. If you segment your diagnostic statements into multiple “channels” (i.e. different TraceSources) then you can selectively “light up” a small section of code to minimize performance impact. Furthermore, you can adjust your output volume by merely restarting your application; no recompilation is necessary.