Geeks With Blogs
The Unstable Mind of a .Net Developer

For those of us who waded through VB5/6, tracing the execution of our applications and apis was time consuming and somewhat frustrating. Writing to the event log was different than writing to a log file. Writing to the console had its own challenges and many of us developed a vast array of methods to accomplish this very important task. The introduction of the System.Diagnostics namespace, and, in particular, the Trace and Debug classes in .Net v1.0/1.1 was a vast improvement. Now, developers had a standard way, a weapon in their arsenal, to implement this critical functionality, delivered out of the box.

The Trace and Debug classes have many similarities. They both share three basic components, listeners, methods to write messages or data to a destination and they both require that your application or api be compiled with specific compilation options. Debug requires the (surprise!) DEBUG switch and Trace, well, it requires the TRACE switch (imagine that). More importantly, developers now are able to use one set of methods to write (using Write or Writeline) trace or debug messages and data to a logging destination, whether that destination was the event log, a log file or even the console. While both classes have their strengths and particular uses, for the remainder of this article I will be focusing on Trace.

One of the best features of the Trace class is its relative simplicity. By simply setting up a few objects in code, or defining them in the application’s .config file, developers have a powerful tool they can harness to track the execution of their application. This could be critically important when troubleshooting issues, especially those issues that appear to occur randomly or cannot be easily replicated. And when configuring Trace through the app.config, where and how much is traced can be changed without touching a line of code.

One important thing to note is that unless Trace is configured otherwise, it implements the DefaultTraceListener, which basically sends tracing data into the ether, never to be heard from again. The good news is that Microsoft delivers three listener classes out of the box that support most needs, the ConsoleTraceListener, the EventLogTraceListener and the TextWriterTraceListener. Microsoft also delivers the TraceListener abstract class so developers can build custom listeners to implement particular behavior or functionality, such as special formatting or writing to a database.

As an example, if a developer wanted to add Trace to their application, tracing all messages with an EventType of Info, writing all trace messages with an EventType of Warning or Error to the console, it would be as simple as adding the following lines to the app.config.

<configuration>
  <system.diagnostics>
    <switches>
      <clear/>
      <add name="traceSwitch" value="Info"/>
    </switches>
    <sharedListeners>
      <add name="consoleTrace" type="System.Diagnostics.ConsoleTraceListener">
        <filter type="System.Diagnostics.EventTypeFilter" initializeData="Warning"/>
      </add>
    </sharedListeners>
  </system.diagnostics>
</configuration>

With this, most of the work is done. However, there is one line that has to be added in code to instantiate the trace switch as a variable within the class or application where tracing is wanted.

private static TraceSwitch appSwitch = new TraceSwitch("traceSwitch", "any old description");

The first parameter is the name and must match the name of the switch specified in the app.config.

EDIT: I have since realized that the above was not wholly accurate.  When adding listeners to Trace, they must be define under <trace><listeners>, not <sharedListeners>.  That is, the above should look like:

<configuration>
  <system.diagnostics>
    <switches>
      <clear/>
      <add name="traceSwitch" value="Info"/>
    </switches>
    <trace>
      <listeners>
        <add name="consoleTrace" type="System.Diagnostics.ConsoleTraceListener">
          <filter type="System.Diagnostics.EventTypeFilter" initializeData="Warning"/>
        </add>
      </listeners>
    </trace>
  </system.diagnostics>
</configuration>

Also, the switch only applies if it is used in conjunction with the WriteIf and WriteLineIf functions. The Trace class itself does not recognize the switch.

At this point, writing trace messages is as simple as calling one of several methods such as TraceError, TraceInformation or Writeline. Minimal formatting can be applied by using the Indent and Unindent methods to indent trace messages to indicate where processes or functionality start and stop, or to make particular messages stand out visually from the rest.

For details on what these methods do and the other methods available, please go to http://msdn.microsoft.com/en-us/library/system.diagnostics.trace_methods.aspx.

I discovered, however, that Trace does have its limitations.  I had been working on an API for a client that downloads transcripts from a secure website and extracts specific information from the transcript. One of the primary requirements of the API was that it had to be implementation agnostic. That is, it had to function correctly whether its implementor was an actual UI, a console application, a windows service, etc. Because of the unreliability of the hosting website and the different types/formats of transcripts that could be encountered, I made very heavy use of Trace, method calls and completions, event triggers, configuration details, transcript details, etc. I also configured the event type (i.e. Info, Verbose) so specific messages would be written most times and some messages would only be written when the trace switch was configured to Verbose. This all worked fine until I hooked the API up to a console application that also used Trace to show progress.

At that point, it was kind of difficult to ignore the fact that, now, all of the trace messages from both the API and console application were being displayed on the console and written to the trace file of the API. Not only was it confused, the tracing had lost significant value. To find important messages from the API meant having to wade through the chatter of the console application and vice versa. Fortunately, the TraceSource class was added by Microsoft to the System.Diagnostics namespace in .Net v2.0.

 

Consider the TraceSource class as Trace on steroids. It implements additional functionality not found in Trace as well as making improvements to existing functionality. Most notably is that while Trace is static, TraceSource must be instantiated. After that, TraceSource and Trace share many similarities. They both have trace switches, they both require listeners and both can be filtered. In fact, changing the base code and app.config to switch from Trace to TraceSource requires very few changes.

<configuration>
  <system.diagnostics>
    <sources>
      <source name="traceSource" switchName="sourceSwitch" switchType="System.Diagnostics.SourceSwitch">
        <listeners>
          <add name="consoleTrace"/>
          <remove name="Default"/>
        </listeners>
      </source>
    </sources>
    <switches>
      <clear/>
      <add name="sourceSwitch" value="Information"/>
      <add name="traceSwitch" value="Info"/>
    </switches>
    <sharedListeners>
      <add name="consoleTrace" type="System.Diagnostics.ConsoleTraceListener">
        <filter type="System.Diagnostics.EventTypeFilter" initializeData="Warning"/>
      </add>
    </sharedListeners>
  </system.diagnostics>
</configuration>

Add the following lines of code to the application and, voila, the change to TraceSource has been made. The second line is an attribute of the application's entry method, such as Main. I've included part of a Main method as an example.

static TraceSource ts = new TraceSource("traceSource"); 
[SwitchAttribute("sourceSwitch", typeof(SourceSwitch))]
static void Main()
{

Well ..., not exactly. Actually, at this point, the application is broken. Trace and TraceSource only share one method that writes messages to the listeners, TraceInformation. Calls to Write, WriteLine, TraceError, etc. will have to be changed to the TraceData, TraceEvent or TraceInformation methods of the TraceSource instance. And, all calls to Indent and Unindent will have to be removed (Unfortunately, that is one of the features not implemented in TraceSource.). The good news, however, is that TraceData and TraceEvent both accept as a parameter a TraceEventType that tells the listeners what type of message is being written. Now, instead of the api or application determining if Write or WriteLine messages should be written, the CLR handles that internally.

At this point, I have made quite a few changes to code considering the amount of tracing I embedded in both the API and console application. And, I still have the same problem. All of the tracing messages are still being written to all of the listeners. Here is where the switch to TraceSource becomes important. Part of the TraceSource implementation includes the SourceFilter class. This class, when added as a filter, tells a listener to only listen to trace messages from a specific TraceSource. The filter can be added via code or by adding a filter segment to the source listener segment in the app.config. Consider the following lines of code.

ts1.Listeners["console"].Filter = new SourceFilter("consoleSource"); 
ts2.Listeners["logfile"].Filter = new SourceFilter("apiSource"); 

These lines tell the console and logfile listeners to only write trace messages that come from a specific source. So, now, API messages are written only to the trace log and progress messages are only written to the console.

EDIT: I may just have been having a bad day when all of my trace messages were being written by both the API and console application trace listeners. I have since discovered that as long as the listener is added to the collection of a specific TraceSource object, it will only write the trace messages from that TraceSource. I even created a separate console application with the following code to double check myself.

namespace ConsoleApplication1 {
    class Program {
        static void Main(string[] args) {
            TraceSource ts1=new TraceSource("TS1");
            TraceSource ts2=new TraceSource("TS2");
            ts1.Switch=new SourceSwitch("SW1", "All");
            ts2.Switch=new SourceSwitch("SW2", "All");
            ts1.Listeners.Add(new TextWriterTraceListener("ts1.log")
                { Filter=new EventTypeFilter(SourceLevels.Information) });
            ts2.Listeners.Add(new TextWriterTraceListener("ts2.log")
                { Filter=new EventTypeFilter(SourceLevels.Verbose) });
            //ts2.Listeners[1].Filter=new SourceFilter("TS1");
            ts1.TraceEvent(TraceEventType.Warning, 0, "This is a test of ts1 Warning");
            ts2.TraceEvent(TraceEventType.Warning, 0, "This is a test of ts2 Warning");
            ts1.TraceInformation("This is a test of ts1 Information");
            ts2.TraceInformation("This is a test of ts2 Information");
            ts1.TraceEvent(TraceEventType.Verbose, 0, "This is a test of ts1 Verbose");
            ts2.TraceEvent(TraceEventType.Verbose, 0, "This is a test of ts2 Verbose");
            ts1.Flush();
            ts1.Close();
            ts2.Flush();
            ts2.Close();
        }
    }
} 

The result was two different log files, each with only the trace messages written by the TraceSource the listener was added to. I even tried to cause one listener to filter to another TraceSource and the result was no trace messages written to the log file. At this point, I 'm not sure that the SourceFilter class has any real purpose. And the example given in the MSDN does not real world usage and also does not give any real indications to its purpose.

Problem solved! I can still trace all of the events, configurations I need to troubleshoot issues and show progress on the console.

So, to wrap it all up, the Trace and TraceSource classes are very powerful tools developers can use to find and fix issues within an application. The Trace class is sufficient in many instances. But, there may be times when switching to TraceSource is absolutely necessary, especially when developing apis and other types of applications that may not be the primary executable. For more information on TraceSource, head on over to the MSDN, http://msdn.microsoft.com/en-us/library/system.diagnostics.tracesource.aspx.

 

Ralph Wheaton
Microsoft Certified Technology Specialist
Microsoft Certified Professional Developer

Posted on Wednesday, September 9, 2009 10:17 AM ASP.Net , System.Diagnostics , VS.Net , TraceSource , TraceEvent | Back to top


Comments on this post: Adventures in System.Diagnostics

# re: Adventures in System.Diagnostics
Requesting Gravatar...
Can you plase explain what the purpose of the [TraceSwitch] attribute on you Main function is?
Left by Burt Harris on Dec 03, 2009 12:05 PM

# re: Adventures in System.Diagnostics
Requesting Gravatar...
static void Main(string[] args)
{
TraceSource ts1 = new TraceSource("TS1");
TraceSource ts2 = new TraceSource("TS2");
ts1.Switch = new SourceSwitch("SW1", "Warning");
ts2.Switch = new SourceSwitch("SW2", "All");
TraceListener tl1 = new TextWriterTraceListener("ts1.log");
ts1.Listeners.Add(tl1);
ts2.Listeners.Add(tl1);
//tl1.Filter = new SourceFilter("TS1"); // uncomment to see how to use the SourceFilter
ts1.TraceEvent(TraceEventType.Warning, 0, "This is a test of ts1 Warning");
ts2.TraceEvent(TraceEventType.Warning, 0, "This is a test of ts2 Warning");
ts1.TraceInformation("This is a test of ts1 Information");
ts2.TraceInformation("This is a test of ts2 Information");
ts1.TraceEvent(TraceEventType.Verbose, 0, "This is a test of ts1 Verbose");
ts2.TraceEvent(TraceEventType.Verbose, 0, "This is a test of ts2 Verbose");
ts1.Flush();
ts1.Close();
ts2.Flush();
ts2.Close();
}
Left by DS on Feb 12, 2010 10:32 AM

# re: Adventures in System.Diagnostics
Requesting Gravatar...
Sorry for the lengthy delay. The purpose of the SwitchAttribute attribute on the Main function is to avoid having to programmatically do so in code. The line:

ts1.Switch=new SourceSwitch("SW1", "All");

accomplishes the same thing. For the most part, if I am using the same switch for an entire application, I use the switch attribute. If I am using it for a specific module, I define the switch in code.
Left by Ralph Wheaton on Mar 26, 2010 10:57 AM

# re: Adventures in System.Diagnostics
Requesting Gravatar...

Any final _solution_ with **full source code** sample application ? _IMHO, better samples for minimize learning curve are real applications with full source code and good patterns_

How save Console.WriteLine output to text file?
How save Trace.WriteLine output to text file?

Left by pregunton on Sep 05, 2014 6:45 AM

Your comment:
 (will show your gravatar)


Copyright © Ralph Wheaton | Powered by: GeeksWithBlogs.net