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
<source> 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.
Previous Page
