Friday, November 13, 2009

Using NUnit with log4net

Those who know me are aware that my obsessive-compulsive nature has latched on to TDD over the past few years. While I don't slavishly pursue 100% code coverage, I'll admit that anything below 80% really starts to get me pacing and much lower than that gives me the shakes for more green bars.

One of the areas I hadn't spent much time on was logging coverage. Partly because I hadn't found a good solution and partly because the types of applications I had been working on didn't really require much in the way of logging. My latest assignment, however, is another integration framework with lots of moving parts that screams logging and lots of it, particularly as I try to refactor a legacy code base I inherited.

Thanks to articles by David Hogue and Robert Prouse, the solution is incredibly simple.

The first step is to create a custom appender. The easiest way I found was to create a class that derives from AppenderSkeleton. I had it write to a static List<string> for the sake of simplicity.

1 namespace Integrations.Framework.Tests

2 {

3 class ListAppender:log4net.Appender.AppenderSkeleton

4 {

5 public static List<string> logTable = new List<string>();

6

7 protected override void Append(log4net.Core.LoggingEvent loggingEvent)

8 {

9 logTable.Add(RenderLoggingEvent(loggingEvent));

10 }

11 }

12 }



The next step was to programatically configure log4net. Something that initially tripped me up here was that I had defined a log4net configuration in an app.config in my test project. This apparently takes precedence over programmatic configuration (or else I just had something mucked up). Anyway, my programatic configuration would not take effect until I deleted the app.config.

1 namespace Integrations.Framework.Tests

2 {

3 [TestFixture]

4 public class DataGathererTests:DataGathererBase

5 {

6 private ListAppender appender;

7 private static ILog log;

8

9 [TestFixtureSetUp]

10 public void OneTimeSetup()

11 {

12 appender = new ListAppender();

13 appender.Layout = new log4net.Layout.SimpleLayout();

14 appender.Threshold = log4net.Core.Level.Fatal;

15 log4net.Config.BasicConfigurator.Configure(appender);

16 log = LogManager.GetLogger(typeof(ListAppender));

17 }



Notice above that I've derived my test class from my base class that implements logging. I want to make sure I'm not creating an artificial layer, so I'm deriving from that base class just as I expect my "real" code to do. Now I can call any of the logging methods, setting log level appropriately and check that messages are getting logged. Once I see that simple tests like log message count are passing, I can move on to more complicated tests that examine actual log messages to make sure the text is as expected, the correct log level, etc. Also, make sure to put a logTable.Clear() call in a TearDown method to make sure tests don't interfere with one another or become dependent upon one another for system state.

19 [Test]

20 public void TestLogging()

21 {

22 this.LogDebug("Debug");

23 Assert.AreEqual(0, ListAppender.logTable.Count());

24

25

26 appender.Threshold = log4net.Core.Level.Debug;

27 this.LogDebug("Debug");

28 Assert.AreEqual(1, ListAppender.logTable.Count());

29 }