Do you also have that feeling when you type in your tracing code that it is too cumbersome and too much hassle to get it right? I mean really trace the information that is useful for finding faults, for instance. And when you log an exception, even when you write out all the information the exception offers, it is barely enough to really understand what went wrong?
That is why I wrote this framework. This framework tries to solve one major problem (and some small one on the side): Getting the runtime information of an executing method into a trace text or an exception.
Note that this post assumes you know about the main classes in System.Diagnostics.
MethodContext
The MethodContext is a class that maintains all running values during the execution of a method. It is created at the beginning of the method and it is Disposed at the end of the method. It collects information about the runtime values of the method parameters, the class reference (this) if it isn't a static method and its return value. This runtime method context information can be formatted into trace texts or added to an exception the code is about to throw.
The MethodContext also maintains its own call stack and provides access to its calling method context.
For tracing purposes a MethodContext derived class, the TraceContext, adds to this a reference to a MethodTracer and method entry and exit trace methods.
Here's a typical usage scenario:
public string Repeat(string value, int numberOfTimes)
{
using(TraceContext ctx = new TraceContext())
{
ctx.Initialize(this);
ctx.AddParameter(value, "value");
ctx.AddParameter(numberOfTimes, "numberOfTimes");
ctx.TraceMethodEntry();
string result = null;
// method impl.
ctx.ReturnValue = result;
return result;
} // Dispose is called on ctx, calling TraceMethodExit()
}
Note that the TraceContext (MethodContext) maintains weak references to all instances.
MethodTracer
The MethodTracer instance is created for each TraceContext. The MethodTracer takes a TraceSource and an optional method-level TraceSwitch in its constructor and uses these to filter and output trace text. It implements 2 versions of the FormatTrace method; one instance and one static. The static FormatTrace method can be used by your code to trace custom texts. The TraceContext is located behind the scenes.
The FormatTrace method takes an object parameter as the object to generate a trace text for (along with some other parameters). The method delegates this task to the TraceManager (discussed next) where a collection of ITraceFormatter instances is checked to see if that specific Type is supported.
If the TraceSwitch allows it the formatted text is output to the TraceSource.
TraceManager
The TraceManager is a global (singleton) class that manages several cached classes. One already discussed are the TraceFormatters. These classes are able to generate trace text for a specific Type of object. TraceFormatters can use other TraceFormatters and thus composing the trace text.
By convention the TraceManager will keep track of a TraceSource for each class Type that creates a TraceContext. It will also keep track of optional method TraceSwitch instances that can be configured to fine tune trace levels at method level.
Exceptions
Exceptions caught in the method that created a TraceContext can keep track of it using the LastError property on the context. When throwing exceptions you can add the context information of the TraceContext to the exception using the AddContextTo method. This method populates the Data dictionary of an exception instance with the context information. Note that only types that are serializable are added, this is because the Data dictionary doesn't allow otherwise (exceptions need to be marshaled across boundaries sometimes and that involves serialization).
The following code sample shows a nice way to add runtime information to an exception before propagating it to a higher level.
public string ReadTextFile(string path)
{
using(TraceContext ctx = new TraceContext())
{
ctx.Initialize(this);
ctx.AddParameter(path, "path");
ctx.TraceMethodEntry();
string result = null;
try
{
// method impl.
}
catch(IOException ioe)
{
ctx.AddContextTo(ioe);
throw;
}
ctx.ReturnValue = result;
return result;
} // Dispose is called on ctx, calling TraceMethodExit()
}
The calling code will receive an exception which Data dictionary is filled with runtime method context information. A nice extension would be to be able to dump all properties of the instances present in the Data dictionary. That way you should be able to generate comprehensive error log messages.
Configuration
The following configuration shows how to set up a Console TraceListener and an EventLog TraceListener for errors, a trace source for several classes, trace switches at class level (trace source) and at method level.
<configuration>
<system.diagnostics>
<sharedListeners>
<!-- Choose your trace output channels -->
<add name="Console" type="System.Diagnostics.ConsoleTraceListener"
initializeData="false" />
<!-- Only Error traces will go to the Event Log -->
<add name="ErrorEventLog" type="System.Diagnostics.EventLogTraceListener"
initializeData="Jacobi.Diagnostics.TestApp">
<filter type="System.Diagnostics.EventTypeFilter" initializeData="Error" />
</add>
</sharedListeners>
<sources>
<!-- Configure a TraceSource for each class-->
<!-- Non-configured classes all create a default TraceSource -->
<source name="Jacobi.Diagnostics.TestApp">
<listeners>
<add name="Console" />
<add name="ErrorEventLog" />
</listeners>
</source>
<source name="Jacobi.Diagnostics.TestApp.TraceAspectTest">
<listeners>
<add name="Console" />
<add name="ErrorEventLog" />
<remove name="Default" />
</listeners>
</source>
</sources>
<switches>
<!-- SourceSwitch settings for classes -->
<!-- You can specify SourceSwitch settings
without configuring the TraceSource (<sources>) -->
<add name="Jacobi.Diagnostics.TestApp" value="Error" />
<add name="Jacobi.Diagnostics.TestApp.TraceAspectTest" value="All" />
<!-- TraceSwitch settings for Methods -->
<add name="Jacobi.Diagnostics.TestApp.TraceAspectTest.WithContext" value="Info" traceFlow="Entry,Exit" />
<add name="Jacobi.Diagnostics.TestApp.TraceAspectTest.ConcatName" value="Verbose" />
</switches>
</system.diagnostics>
</configuration>
Basically this configuration is very similar to the one discussed in my previous post about System.Diagnostics. <sharedListeners> declares all listeners, <sources> lists a TraceSource per class and <switches> configures both class-level switches and method-level switches. Notice that the method level switches extent the dot-syntax with the method name for the name of the switch and carry an extra traceFlow attribute. The traceFlow attribute allows you to filter the output of method entry and exit traces that are done by the TraceMethodEntry and TraceMethodExit methods on TraceContext.
The next post will investigate a way to get rid of all the custom code you have to write to use the TraceContext. Using a static aspect weaver it is possible to have all that code removed from your method and indicate with a code attribute what methods you want to trace in a completely transparent way.
Download the source code here. Note that this source code also contains the projects for the static aspect weaver that will be discussed in the next post.