NUnit and log4net

A lot of people just run headlong into an automation project and immediately start either recording or writing scripts. In my experience, that is a bit rash as there are some infrastructure bits that need taking care of first.

The very first thing is to figure out where the scripts will be stored in version control. Everything should be in version control for automation. (If anyone has a recommendation around solutions for automation consultants who don’t always have access to client repos but write code, ping me.) This should be an obvious first step, but it often isn’t. Sadly.

The next step is to figure out your logging strategy. The reason for this is two-fold. First, it gives you a means of debugging your script in a clean manner and second, it allows you to create a record of test execution details for latter reference.

I’m currently helping a client do a proof-of-concept script for their custom widget toolkit with Selenium 2 and C# and went down the rabbit hole of getting the logging (log4net) figured out yesterday with NUnit. Here is what was necessary from the myriad of posts that all contributed only part of the answer. Hopefully it will take you a lot less time to get wired up than it did me.

Assumption Alert – You have already installed NUnit and got a bare-bones ‘hello world’ test working

  1. Download the latest log4net release
  2. Add a log4net reference to the VS project
  3. Add the log4net bits to the script
    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    13
    14
    15
    16
    17
    18
    19
    20
    21
    22
    23
    24
    25
    26
    27
    28
    29
    30
    31
    32
    33
    34
    35
    36
    37
    38
    39
    40
    41
    42
    43
    44
    45
    46
    
    using System;
    using System.Text;
    using System.Text.RegularExpressions;
    using System.Threading;
    using NUnit.Framework;
     
    using OpenQA.Selenium;
    using OpenQA.Selenium.IE;
    using OpenQA.Selenium.Internal;
     
    using log4net;
    using log4net.Config;
     
    namespace Selenium2Tests
    {
        [TestFixture]
        public class NowWithLoggingTests
        {
            IWebDriver driver;
     
            private static readonly ILog log = LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);
     
            [SetUp] 
            public void SetupTest()
            {
                verificationErrors = new StringBuilder();
     
                driver = new InternetExplorerDriver();
                driver.Navigate().GoToUrl("http://localhost:8080");
            }
     
            [TearDown]
            public void TeardownTest()
            {
                driver.Quit();
     
                Assert.AreEqual("", verificationErrors.ToString());
            }
     
            [Test]
            public void TheNewTest()
            {
                Assert.AreEqual(1, 1);
            }
        }
    }

    Lines 11-12 and 21 are the important ones. The first two add the log4net functionality to the class and the third does some reflection trickiness to determine the class name in a safe-to-copy-and-paste-this-line-without-change manner. Also notice that there is not a BasicConfigurator.Configure() or similar call. We’re doing a bit of configuration magic to omit that.

  4. Next we need to configure log4net. And of course there a tonne of different ways to do this, but this way I feel is the cleanest. In your project, add a new Application Configuration File and rename log4net.config. You can put whatever config you like in there; here is the one I am currently using.

    <?xml version="1.0" encoding="utf-8" ?>
    <log4net>
      <appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender" >
        <layout type="log4net.Layout.PatternLayout">
          <conversionPattern value="%date [%thread] %-5level %logger [%ndc] - %message%newline" />
        </layout>
      </appender>
      <appender name="RollingFile" type="log4net.Appender.RollingFileAppender">
        <file value="example.log" />
        <appendToFile value="true" />
        <maximumFileSize value="100KB" />
        <maxSizeRollBackups value="2" />
     
        <layout type="log4net.Layout.PatternLayout">
          <conversionPattern value="%level %thread %logger - %message%newline" />
        </layout>
      </appender>
      <root>
        <level value="DEBUG" />
        <appender-ref ref="ConsoleAppender" />
      </root>
    </log4net>

    As things stand right now though, log4net will never find this file as it expects it by default in an app.config or web.config. To tell log4net where it’s config can be found we add

    [assembly: log4net.Config.XmlConfigurator(ConfigFile = "log4net.config", Watch = true)]

    to our AssemblyInfo.cs file. You also need to remember to change the properties of this file to have:

    • Build Action: Content
    • Copy to Output Directory: Copy if newer

You have now integrated log4net into your project and you can send log messages to it using log.Debug, log.Info, log.Error, etc. and everything is rainbows and lollipops until you run the script with NUnit and don’t see anything being logged below the Error level. WTF?

  1. NUnit will be default capture log4net messages as pass they along to the user if they are Error or higher — regardless of what log4net says. So we need another Application Configuration File, this time called, well, actually it is complicated. Depending on how the script is run, the file needs to be named one of five different ways. Here is a trick though, if you run your NUnit scripts from the NUnit GUI you can specify the config file you want — so go ahead and called it nunit.config. Just remember this bit of naming silliness when your logging “doesn’t work” sometime later.

    Here is my nunit.config — note the DefaultLogThreshold is now DEUBG.

    <?xml version="1.0" encoding="utf-8" ?>
    <configuration>
      <configSections>
        <sectionGroup name="NUnit">
          <section name="TestCaseBuilder"
          type="System.Configuration.NameValueSectionHandler"/>
          <section name="TestRunner"
          type="System.Configuration.NameValueSectionHandler"/>
        </sectionGroup>
      </configSections>
     
      <NUnit>
        <TestCaseBuilder>
          <add key="OldStyleTestCases" value="false" />
        </TestCaseBuilder>
        <TestRunner>
          <add key="ApartmentState" value="MTA" />
          <add key="ThreadPriority" value="Normal" />
        <add key="DefaultLogThreshold" value="DEBUG" />
      </TestRunner>
      </NUnit>
    </configuration>

    Don’t forget too that the properties of this file need to be set in the same manner as the log4net.config file above.

Now you are really integrated with log4net and NUnit with your messages actually showing up. If only it didn’t take me all day to get it working properly…

Comments 1

  1. Alex wrote:

    What exactly does can mean in: if you run your NUnit scripts from the NUnit GUI you can specify the config file you want?

    I run the NUint GUI programmatically but the nunit.config file isn’t loaded by default and I don’t know the way how to tell NUnit GUI to load it.

    Posted 09 Oct 2010 at 6:45 pm

Post a Comment

Your email is never published nor shared. Required fields are marked *