Initialize log4Net as early as possible with NUnit

Question

I'm wondering what is the best way to initialize log4Net in a NUnit project. Of course I want to call the init code (ie. XmlConfigurator.Configure()) as soon as I can to get as many early log output as I can. But since my project is run through NUnit, I have little control on its entry point.

According to NUnit documentation, it should call some constructors first, then a method marked with the [SetUp] attribute in a class marked with [TestFixtureSetup].

So, First, I created a static helper class which I can call several times without trouble.

  public static class LoggingFacility
  {
    private static bool _loggerIsUp = false;

    public static void InitLogger()
    {
      if (_loggerIsUp == false)
        XmlConfigurator.ConfigureAndWatch(f);

      _loggerIsUp = true;
    }
  }

Then, I made all my [TestFixtureSetup] inherit a single one that does pretty much nothing else than calling LoggingFacility.initLogger(). But that still leaves all constructors that are run earlier, in an order I can only assume random. And moreover, it will probably do some static initializations before I am even able to execute some code.

In fact, as I can see in my log, the first 4 seconds or so of execution are completely unrecorded.

Does it mean I will have to call my InitLogger() in every constructor and forbid the use of any static initializer? That's tough job!

Does somebody know a magic trick with this?

Just wondering for which purposes you are using log4net in tests, to log test progress/results or to instantiate a logger as dependency of some classes? — sll, Mar 07 '12 at 21:22
@sll: I use two logging outputs: first one is for test outputs to be a little more verbose than NUnit itself, and the second one (the one I need to be ready fast) is for debugging the test app — PPC, Mar 08 '12 at 14:16

k.m · Answer 1 · 2012-03-07T21:06:11.637

For single initialization point you should use class marked with [SetUpFixture] attribute and method marked with [SetUp], for example:

[SetUpFixture]
public class TestsInitializer
{
    [SetUp]
    public void InitializeLogger()
    {
        LoggingFacility.InitLogger();
    }
}

Now, this method ([SetUp] InitializeLogger) will run before any test is run, same as one marked with [TearDown] will run once all tests are run. But here's the catch - what does any and all mean in this context? Tests from classes declared in the same namespace as class marked with [SetUpFixture].

For example, assuming hierarchy like this:

- Tests
--- Business
----- TestsInitializer.cs // SetUpFixture class
----- FirstBusinessTests.cs
----- SecondBusinesTests.cs
--- ComplexLogic
----- VeryComplexLogicTests.cs

First and SecondBusinessTests will run after SetUp from TestsInitializer, however VeryComplexLogicTests might run in random order.

According to linked documentation, if you declare SetUpFixture class outside of any namespace, setup and teardown will apply for entire assembly:

Only one SetUpFixture should be created in a given namespace. A SetUpFixture outside of any namespace provides SetUp and TearDown for the entire assembly.

thanks for the namespace tips, that is much appreciated. Still, my problem is that NUnit runs lots of code *before* even wondering about [SetUpFixture]: contructors and static initializers, and I'd like to log this code too — PPC, Mar 08 '12 at 14:14
@PPC: what kind of code is run *before*? You mean NUnit's initialization or your code, like test classes constructors and such? I'm pretty sure `SetUpFixture` is as soon as it gets in terms of hooking up your custom code to NUnit. *Maybe* you can work your ways with config file, but to be honest I have never seen anybody doing such stuff before. — k.m, Mar 08 '12 at 23:12
Yes, I mean constructors and such. My first logging entry starts at about 5 seconds uptime and I don't see most of my constructors logging in there. — PPC, Mar 12 '12 at 14:31

score 1 · Accepted Answer · answered Mar 12 '12 at 14:39

A work mate provided me with the following workaround, that does the job:

In all my classes that require logging, I had the following logger initialization

private static readonly ILog Log = LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);

I simply changed it to a singleton initializer

private static readonly ILog Log = LoggingFacility.GetLoggerWithInit(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);

/*** ... ***/

public static class LoggingFacility
{
  private static bool _loggerIsUp = false;

  public static ILog GetLoggerWithInit(Type declaringType)
  {
    if (_loggerIsUp == false)
      XmlConfigurator.Configure(_log4NetCfgFile);
    _loggerIsUp = true;
    return LogManager.GetLogger(declaringType);
  }
}

Because I have this code in every class, this static initializer has to be called very early by NUnit wile instantiating my test classes.

Next step is to make that thread safe :(

Initialize log4Net as early as possible with NUnit

2 Answers2

Linked