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.

StubTraceListener.cs