2010-12-30

Simple and Easy Tracing in .NET

.NET includes a fairly complete tracing framework built right in, but there isn't much in the way of "getting started" tutorials that provide best practices. So, here's a simple guide to the built-in .NET tracing support, skipping all the hard stuff. :)

Define the TraceSource

One TraceSource should be defined per "component." The "component" is up to you; it's a group of trace statements that can be enabled or disabled together.

A TraceSource needs a name, and that name should be globally unique. Something like "MyCompany.MyProduct.MyComponent" should suffice.

You usually want to define the TraceSource as a static member of a class being traced. The example code below uses a private static TraceSource, but if other classes use the same source, you may prefer internal static:

public class MyComponentClass
{
  private readonly static TraceSource Tracer = new TraceSource("MyCompany.MyProduct.MyComponent");
  ...
}

Use the TraceSource

Add calls to TraceSource methods where you want tracing to take place:

public void Frob(string arg)
{
  Tracer.TraceInformation("Frobbing " + arg);
  ...
}

The TraceSource class provides several tracing methods; the most common are TraceInformation (used for informational message) and TraceEvent (used for any type of message).

The types of messages include (in increasing order of severity): Verbose, Information, Warning, Error, and Critical.

Enable the TraceSource

Defining and using the TraceSource is all the changes that need to be made to the code. However, running the code above will not actually cause any tracing to be done at runtime, because the TraceSource is not enabled.

To enable the TraceSource, you'll need to merge the following with your app.config or web.config (and restart the application):

<configuration>
  <system.diagnostics>
    <sources>
      <source name="MyCompany.MyProduct.MyComponent" switchValue="All" />
    </sources>
  </system.diagnostics>
</configuration>

The switchValue attribute may be set to Off, Critical, Error, Warning, Information, Verbose, or All. This setting interacts with the TraceEvent message types exactly as you'd expect:

VerboseInformationWarningErrorCritical
Off
Critical+
Error++
Warning+++
Information++++
Verbose+++++
All+++++

Tip: you can leave the source element defined in your app.config / web.config when you deploy to production. As long as its switchValue is set to Off, it won't actually trace but it's easy to find and turn on.

Another tip: TraceSource works the same in both Debug and Release builds, so it's great for instrumenting an application heading to production where you want to enable or disable the tracing without recompiling.

Observe the Trace Messages

Simple tracing can be observed in one of two ways:

  • If you run the application in the Visual Studio Debugger, all enabled trace output is written to the Output window.
  • If you're running in production (or for some other reason can't use the debugger), a free Microsoft tool called DebugView may be used to view the traces in real-time (and optionally log them to a file). Tip: uncheck "Options" "Force Carriage Returns" to make the trace output line up correctly.

More Power!

This blog post just scratched the surface of the complexity of the built-in .NET tracing system. It is extensible in many ways:

  • You can add "trace listeners". The simple tracing above just uses the Default trace listener. .NET also includes listeners for logging to the Event Log, a text file, an XML file, or the Console. In addition, you can write your own trace listener (e.g., a rollover log so that the file doesn't get too large).
  • You can add trace switches. Our simple tracing just sets a single switchValue for each TraceSource. It's possible to add trace switches that are shared between multiple trace sources. In addition, you can define your own type of trace switch.
  • You can add trace filters. For example, it's possible to put in a trace filter that sends some messages to one trace listener and other messages to another trace listener. You can also define your own trace filter type, if the built-in ones aren't sufficient.
  • There are additional types of messages that fall under "ActivityTracing": Start, Stop, etc. These can be used in addition to the existing Verbose to Critical hierarchy.
  • There's a Trace.CorrelationManager class that enables "grouping" of traces into logical operations. This is used in conjection with the ActivityTracing messages to relate traces together that would otherwise get intermixed with other traces.

For more information, see this SO answer and the MSDN documentation. Also, check out Essential Diagnostics on CodePlex before writing your own extensions; the most useful things have already been done.

Other TraceSources

Many people aren't aware that a lot of the .NET built-in libraries have already been instrumented with their own TraceSources. Network activity, for example, or tons of tracing for WPF. The two that I've found most useful are System.Net.Sockets for TCP/IP sockets and System.Windows.Data for debugging data binding errors. There are probably many more out there...

2010-12-24

On a Lighter Note: "Wii Me"?

Advances in technology often cause changes in language. Most people these days know what a "tweet" is, even if they don't use the term themselves.

This last Wednesday shortly before church, I asked one of the fellows if I had his email address. He replied, "Wii me." This is the first time I'd heard that term, and - even though the meaning was obvious - I had to pause for a moment before replying "Wii you??"

I don't think the phrase "Wii me" will catch on, but we both had a good laugh over it. :)

2010-12-21

ConditionalWeakTable

I prefer to find bugs as early as possible. Starting unit tests early-on is a big helper towards that goal; unfortunately, I do find myself sometimes banging out code on tight time constraints, and I skip my unit tests. (Oh, how embarassing! I just admitted that right out in public and everything!)

Back in the pre-unit-testing world, when dinosaurs roamed the earth, there was another approach to finding bugs early: static typing. This is why I had (and - to be honest - still have) a preference for statically typed languages. If the compiler finds a bug, then that's one less bug I have to run into at runtime.

That said, dynamic languages are also awesome. I love the ability to do runtime binding with ease, and modify the structure of existing objects after they've been constructed. I do enough work in JavaScript to stand in awe of the language, and I've stated several times that Python is one of the best-designed languages in the world.

.NET 4.0 added the dynamic language runtime, allowing dynamic .NET languages to truly exist for the first time. C# received much of the power of dynamic languages by adding the dynamic keyword. I was one of the ones cheering when this (finally) took place.

Now, I'm still a fan of statically-typed languages. In fact, I wish C# would add something equivalent to the extreme power and flexibility of C++ templates (supporting at least static polymorphism and implicit invokation of type generators). However, there are times when it's wonderful to just side-step the static typing and do something a bit "out of the box," and dynamic is just the ticket. Late binding, for example, or Reflection code that doesn't cause your fingers to fall off, or duck typing, or embedding a scripting engine for your end-users, or using an "expando" object with a runtime-defined structure.

The last of those examples is what ConditionalWeakTable is all about. Most programmers are aware of ExpandoObject; however, many are not aware that ConditionalWeakTable allows them to "attach" additional information to existing, non-dynamic CLR objects.

Somehow I missed that class when the .NET 4.0 changes were announced, but Jeffrey Richter gave an example of it in his ".NET Nuggets" talk last week as part of Wintellect's T.E.N. event. Essentially, you can use ConditionalWeakTable to define a (threadsafe) mapping from an object instance to any type of value you need. This allows you to treat any object as an "expando" object, "attaching" information to it. When the object instance is garbage collected, any attached values are automatically cleaned up as well.

This is a powerful concept, and it was the primary motivation behind my (pre-release) Nito.Weakness library. According to Mr. Richter, ConditionalWeakTable is notified of object collection by the garbage collector rather than using a polling thread, which is good. There are a couple of caveats, though, when using CWT.

Update 2011-01-22: The Nito.Weakness library has been postponed indefinitely. Instead, I've released the ConnectedProperties library on both CodePlex and NuGet. ConnectedProperties is a straightforward wrapper for ConditionalWeakTable.

Caveat 1: Restrictions on TKey

Be careful what type you specify for TKey. I stronly recommend that you only use types that use reference equality. This means that I don't recommend you use string like Mr. Richter did during his demo (and in his example source code). It's well and good for the author of CLR via C# to use TKey = System.String, but mere mortals like you and I should steer clear. string not only uses value equality, but also has a complex interning feature. Remember, ConditionalWeakTable tracks object instances, not object values.

Nito.Weakness contains some code (IsReferenceEquatable) to determine if a type uses reference or value equality, and refuses to track object instances that use value equality. Perhaps this is a bit strong, but I'm planning to add this requirement in any generic ConditionalWeakTable wrappers that I use in my own code.

Caveat 2: IDisposable is ignored on TValue

ConditionalWeakTable will not dispose any IDisposable values attached to object instances. They will (eventally) be finalized, but the standard restrictions on finalizers apply. Mr. Richter does have an example in his downloaded code, using this as an "object-collection callback." However, I don't believe that would be usable in real code, simply because all permissible finalizer actions belong in the original class anyway (specifically, the disposing of unmanaged resources).


Even with these caveats, ConditionalWeakTable promises to be quite useful! It allows better "separation of concerns" in code, with a bit of an "aspect-oriented programming" feel.