Tracing in Enterprise Library is available out of the box. Now a lot of articles will explain how to start using tracing, but in practise we encountered something not so straight forward.
Quick intro
For us, tracing is the ability to write messages to a destination (usually a file) concerning the execution of some parts of the application. Especially Windows NT Services should have tracing as they don't contain a Graphical UI.
In Enterprise Library you can turn tracing on or off in the Client Settings of the Logging and Instrumentation Application Block node. In your code tracing is performed by this type of statement:
//Prepare the trace capabilities
using (new Tracer("MyService Tracer"))
{
...
}
Now you need define for the log Category "MyService Tracer" a certain destination (sink), usually a flat file. With this destination you also define how you would like to format your message, this is the Text Formatter.
When you run this code, the output will be simmilar to:
Timestamp: 8/29/2005 10:10:58 AM
Message: Start Trace: Activity 'f8cee722-0101-4d33-b222-1f2e0d331df8' in method 'Execute' at 22731642092 ticks
Category: MyService Tracer
Priority: 5
EventId: 1
Severity: Information
Title:TracerEnter
Machine: PCLEL05
Application Domain: myservice.exe
Process Id: 5588
Process Name: c:\program files\myservice\myservice.exe
Win32 Thread Id: 5784
Thread Name:
Extended Properties: TracerActivityId - f8cee722-0101-4d33-b222-1f2e0d331df8
----------------------------------------
Timestamp: 8/29/2005 10:11:09 AM
Message: End Trace: Activity 'f8cee722-0101-4d33-b222-1f2e0d331df8' in method 'Execute' at 22770949331 ticks (elapsed time: 10.981071 seconds)
Category: MyService Tracer
Priority: 5
EventId: 1
Severity: Information
Title:TracerExit
Machine: PCLEL05
Application Domain: myservice.exe
Process Id: 5588
Process Name: c:\program files\\myservice\myservice.exe
Win32 Thread Id: 5784
Thread Name:
Extended Properties: TracerActivityId - f8cee722-0101-4d33-b222-1f2e0d331df8
So, out of the box, you get quite a lot of information there. At the start of the scope of the using block, the header message will be written and at the end, the footer.
Adding custom info to the trace file
Now, when you would like to add your own messages in between, you would expect that the Tracer object contains a method like Write or so, but this is not the case. To achieve this, you need to actually fall back on the logging system of Enterprise Library. So, what we did is, we created a Log Category which also writes to the same destination. This time however we've used a different Text Formatter because otherwise the file would be unreadable and too large at the end. This formatter (we call short-formatter) is like this: "[{timestamp}] {message}".
So, now we can use the Logger.Write method in the tracing block like this:
//Prepare the trace capabilities
using (new Tracer("MyService Tracer"))
{
...
Logger.Write("Step 1/4: starting up engine...", "MyService Logger"))
...
}
Note: if you were happy with the standard formatter, both the log and trace could use the same category).
This will output into:
Timestamp: 8/29/2005 10:10:58 AM
Message: Start Trace: Activity 'f8cee722-0101-4d33-b222-1f2e0d331df8' in method 'Execute' at 22731642092 ticks
----------------------------------------
[8/29/2005 10:11:03 AM] Step 1/4: Starting up engine...
----------------------------------------
Timestamp: 8/29/2005 10:11:09 AM
Message: End Trace: Activity 'f8cee722-0101-4d33-b222-1f2e0d331df8' in method 'Execute' at 22770949331 ticks (elapsed
The problem
We're in fact mixing tracing & logging, although it is what the guys from Patterns & Practices advice to do.
Now, suppose if you want to disable tracing and only use it when you need to resolve some problem. As said above, you can turn off tracing in the Client Settings. The header and footer messages (from the Tracer object) will not be written anymore as expected. However all the log messages in the scope of the Tracing block will still be written to the destination. So, you will end up with :
[8/29/2005 10:11:03 AM] Step 1/4: Starting up engine...
----------------------------------------
[8/29/2005 10:12:24 AM] Step 2/4: do something...
----------------------------------------
Now, this is not what we want because the file will grow unmonitored and could cause problems after a long period. So, one solution is to apply filters. These filters can also be set on the Client Settings node of the Logging and Instrumentation Application Block. So, to turn off tracing, you could filter out the "MyService Tracer" and "MyService Logger" Categories.
Improvement
To further improve the tracing, we found a Rolling File Sink from Hisham Baz. This allows to manage the size of the Flat Files for your logging/tracing.
- Erik
In one of our projects, we have been using Enterprise Library v1.1. Most of the Application Blocks where sufficient as they came out of the box, however we found some room for improvements and this post will explain one in the area of the Exception Handling Application Block.
Our Exception handling strategy is based on firstly, logging each exception in every layer (DB, Bus, UI, Interfacing) where the exception occured and secondly, replacing it with a custom exception. The reason we replace the original exception with a custom one, is to avoid that this exception will get logged within each layer it passes. So here's the detail:
We created a seperate assembly with Exception types called Error from here we derive for example UserInterfaceError, InterfaceLogicError, BusinessLogicError and DataAccessError.
Now in every try catch statement we use :
catch(EX.Error){}
catch(Exception ex)
{
bool rethrow = Microsoft.Practices.EnterpriseLibrary.
ExceptionHandling.ExceptionPolicy.HandleException(ex,
EX.ExceptionPolicies.DataPumpService);
if(rethrow)
throw;
}
Now, first thing to notice in this code, is the fact that we ignore all Error exceptions, because as said before they are already logged by the layer where the exception occured. Secondly we apply the default boilerplate code for the catch statement within the Exception Handling Application Block. (Note the the EX.ExceptionPolicies.DataPumpService is a constant for one of the exception policies.)
Improvement
As mentioned above, besides logging we replace the original exception with a new one that is defined in the specific policy. Now with the default Replace Handler will can set the message of the new exception to a constant text like :
"The system has stored the necessary information of the occured error with following identifier: {handlingInstanceID}"
Because we run this application in multiple languages, we can't use this fixed text, so we went looking for a different solution. We found a new Handler called Localized Replace Handler from Tim Shakarian. This was exactly what we were looking for because now we could fill the message with a string from a specific recource file.
Tim did a good job by also making the designer so it fits nicely into the Enterprise Library Configuration tool as you can see on his post.