Unit Test Your Enterprise Library Logging Logic
Most enterprise applications need to perform logging in some form or other, and the Enterprise Library Logging Application Block provides an excellent platform for implementation. With the Logging Application Block (henceforth LAB) you don't have to think about how to log, but you still need to implement when and what to log.
These decisions can be complex in themselves, so it might be nice to be able to unit test your logging logic. How do you test logging today? Click on the right sequence of UI elements in your application and then carefully examine the Windows Event Log? With the LAB, there's a better way.
Logging with the LAB is easy enough in itself:
public class MyClass
{
public void DoSomething()
{
// Imagine that something interesting happens
// here...
LogEntry le = new LogEntry();
le.Message = "Something interesting happened.";
le.Categories.Add("General");
Logger.Write(le);
}
}
If you imagine that the code is a bit more complex, you may want to test that the DoSomething method logs the expected information.
Unit testing is all about automation, so you need to be able to automate the validation of log entries. One could consider using the Windows API to open the Windows Event Log and search through all the entries, carefully filtering the relevant and most recent ones out, but that is, at best, a rather error-prone approach. However, the LAB, like the rest of Enterprise Library, uses a configurable provider model, so you can configure the destination of event log entries.
It even ships with a lot of other logging destinations than the default Windows Event Log, for example a text file. Logging to a text file sounds more automatable, but you would still need to write some helper classes to clean and parse the log file for each test case.
Since the provider model is extensible, why not go all the way? I'll write a custom trace listener that I'll use to configure the LAB. Instead of writing the log entries to some external data store, this trace listener will just add a log entry to an in-memory list of log entries. After I exercise the code in DoSomething, I can retrieve the list of log entries and validate it.
Here's the custom trace listener in all its gory detail (excluding namespace imports):
[ConfigurationElementType(typeof(CustomTraceListenerData))]
public class StubTraceListener : CustomTraceListener
{
private readonly static List<LogEntry> logEntries_ =
new List<LogEntry>();
private readonly static List<string> logMessages_ =
new List<string>();
public override void Write(string message)
{
StubTraceListener.logMessages_.Add(message);
}
public override void WriteLine(string message)
{
StubTraceListener.logMessages_.Add(message);
}
public override void TraceData(TraceEventCache eventCache,
string source, TraceEventType eventType, int id,
object data)
{
LogEntry le = data as LogEntry;
if (le != null)
{
StubTraceListener.logEntries_.Add(le);
if (this.Formatter != null)
{
this.Write(this.Formatter.Format(le));
return;
}
}
base.TraceData(eventCache, source, eventType, id, data);
}
internal static IList<string> GetLogMessages()
{
return new ReadOnlyCollection<string>
(StubTraceListener.logMessages_);
}
internal static IList<LogEntry> GetLogEntries()
{
return new ReadOnlyCollection<LogEntry>
(StubTraceListener.logEntries_);
}
internal static void Reset()
{
StubTraceListener.logEntries_.Clear();
StubTraceListener.logMessages_.Clear();
}
}
To create a custom trace listener, you must first derive a class from CustomTraceListener and set the ConfigurationElementType attribute. That's just a bit of Enterprise Library infrastructure, so I will leave it at that. CustomTraceListener is an abstract class, so to derive from that, I need to at least implement the Write and WriteLine methods. As you can see, I just add the messages to a static list of messages.
The real fun happens in the TraceData method, though. This is a virtual method that you don't have to override, but it's really the core of any trace listener. The base implementation of this method uses a pre-defined formatter to format the data parameter into a string, with which it then calls the Write or WriteLine methods. If you want to change this behavior, this is the place to do it. In this method, I cast the data parameter to a LogEntry instance and add that LogEntry to another static list. This is the same LogEntry instance that was originally created by the logging application (such as in the DoSomething method above), so keeping this instance around allows for very rich testing.
If there's a formatter configured for the StubTraceListener, I use that formatter to format a text string from the LogEntry, whereafter I return from the method to prevent the base implementation from also calling the Write method.
The GetLogMessages, GetLogEntries, and Reset methods enable me to use StubTraceListener in a unit test:
[TestInitialize]
public void TestInitialize()
{
StubTraceListener.Reset();
}
[TestMethod]
public void ValidateLogging()
{
MyClass mc = new MyClass();
mc.DoSomething();
IList<LogEntry> logEntries =
StubTraceListener.GetLogEntries();
Assert.AreEqual<int>(1, logEntries.Count);
LogEntry le = logEntries[0];
Assert.AreEqual<string>("Something interesting happened.",
le.Message);
Assert.AreEqual<int>(1, le.Categories.Count);
Assert.IsTrue(le.Categories.Contains("General"));
}
Since test cases should be independent, I make sure to call the Reset method before each test. This clears out all the log entries from the StubTraceListener.
In the test method, it's simply a matter of exercising the code that generates log entries, and then subsequently retrieve the log entries from the StubTraceListener and validate that everything is as expected.
This test suite is going to fail until you create a configuration for the LAB. The easiest way to do this is to add an empty app.config file to the test project, and then use the Enterprise Library Configuration application to configure the LAB. The default LAB configuration uses a Windows Event Log trace listener, so you'll need to remove that and add the StubTraceListener instead.
Once that is done, you have a working unit test suite, and you can unit test logging logic of arbitrary complexity without having to manually check anything.
Most of Enterprise Library uses a similar provider model, so this principle of stubbing out a provider for an application block can be used in many other ways, for other application blocks.
Comments
Anonymous
August 08, 2006
The comment has been removedAnonymous
August 08, 2006
The comment has been removedAnonymous
February 10, 2007
Hello, How did you get VSTS to copy your configuration file to its TestResults folder each time the test run. VSTS does not copy my config file so every time I run, I get a configurationErrorException. It's frustrating. Maybe I am forgetting something? TIA, AnAnonymous
February 10, 2007
Hello An Phu Thank you for asking. I don't really do anything to copy my configuration file to the TestResults folder. When you add an App.config file to your project, Visual Studio will automatically deploy it and rename it to <output_name>.exe|dll.config. However, as far as I've been able to tell, VSTS only does this if the file is called "App.config", i.e. if it's called "myProject.config", it doesn't get copied unless you specify it as a deployment item. Could it be that your configuration file has another name than "App.config"?Anonymous
February 14, 2007
You were right. I see my mistake. The file was named "Web.config". It looks like the configuration file has to be "App.config". Thank you for your help.Anonymous
February 14, 2007
Hello An Phu I'm happy I was able to help :)Anonymous
July 09, 2007
I have built the StubTraceListener seperately. Referenced the dll. But, I am not getting the app.config file just right. I seems like it is not being used by Enterprise Library logging. This is my simplified (template) config file. <configuration> <configSections> <section name="loggingConfiguration" type="Microsoft.Practices.EnterpriseLibrary.Logging.Configuration.LoggingSettings, Microsoft.Practices.EnterpriseLibrary.Logging, Version=2.0.0.0, Culture=neutral, PublicKeyToken=null" /> </configSections> <loggingConfiguration name="Logging Application Block" tracingEnabled="true" defaultCategory="General" logWarningsWhenNoCategoriesMatch="true"> <listeners> <add listenerDataType="Microsoft.Practices.EnterpriseLibrary.Logging.Configuration.CustomTraceListenerData, Microsoft.Practices.EnterpriseLibrary.Logging, Version=2.0.0.0, Culture=neutral, PublicKeyToken=null" traceOutputOptions="None" type="TestingTraceListener.StubTraceListener, LoggingTraceListener, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null" name="CustomTraceListener" initializeData="" /> </listeners> <formatters> <add template="Timestamp: {timestamp}, Message: {message}, Category: {category} 
 )}" type="Microsoft.Practices.EnterpriseLibrary.Logging.Formatters.TextFormatter, Microsoft.Practices.EnterpriseLibrary.Logging, Version=2.0.0.0, Culture=neutral, PublicKeyToken=null" name="Text Formatter" /> </formatters> <categorySources> <add switchValue="All" name="General"> <listeners> <add name="CustomTraceListener" /> </listeners> </add> </categorySources> <specialSources> <allEvents switchValue="All" name="All Events"> <listeners> <add name="CustomTraceListener" /> </listeners> </allEvents> <notProcessed switchValue="All" name="Unprocessed Category" /> <errors switchValue="All" name="Logging Errors & Warnings" /> </specialSources> </loggingConfiguration> </configuration>Anonymous
July 09, 2007
Hi phuhn Thank you for writing. How does your problem manifest itself? Are you getting an exception?Anonymous
July 10, 2007
The problem was nothing was showing up in the generic lists. I removed the WMI stuff place in the app.config file produced by Enterprise Library Configuration application and then data started showing up. PS I added the following (taken from MockTraceListener) (Note: I use prefix _, not postfix): public static int GetEntriesCount { get { return _logEntries.Count; } } public static LogEntry LastEntry { get { return _logEntries.Count > 0 ? _logEntries[_logEntries.Count - 1] : null; } } public static string LastMessage { get { return _logEntries.Count > 0 ? _logEntries[_logEntries.Count - 1].Message : null; } }Anonymous
July 10, 2007
Hi phuhn Okay, so your issue is solved now?Anonymous
July 10, 2007
Can Enterprise Library and StubTraceListener be used to extend the Trace.Write and Trace.Warn? i.e. StubTraceListener.Reset( ); Trace.Write( "method name", "message" ); Assert.AreEqual( 1, StubTraceListener.GetLogEntries().Count );Anonymous
July 10, 2007
Hi phuhn I don't see why not. According to the documentation, Trace.Write writes to each configured TraceListener's Write method. Since StubTracelistener derives from TraceListener, you'd just need to add it to the Listeners property of the Trace class.Anonymous
September 20, 2007
One of the nice things about the Enterprise Library Logging Application Block (LAB) is that it's so darnedAnonymous
April 01, 2008
How do I create a new eventlog other than the application log. I changed the Source to my custom eventlog name and it didn't work. any ideas?Anonymous
April 01, 2008
Hi Sandra Thank you for your question. Before you can write to a custom event log, you have to create it. This requires Administrator privileges, and should usually be done at deployment time. If you are using the Enterprise Library Logging Application Block, this post may be of some help to you: http://blogs.msdn.com/ploeh/archive/2007/09/20/InstallingEventSourcesForTheLoggingApplicationBlock.aspx HTHAnonymous
May 17, 2008
Thank you for writing this post, it really helped a lot to think upfront of a strategy to unit test a logging mechanism within our system using LAP. Your solution proved to be more than inspirational in this situation.Anonymous
October 03, 2008
Lots of applications write to the Windows Event Log. When TDD'ing, event logging is part of an application's