log4net configuration with MSTest and Visual Studio 2013

I use log4net because it gives me easy class level control over logging levels and it has a lot of outbound (appender) types.  Folks that dislike log4net will not find this post useful.

Visual Studio test output can be pretty confounding. There are way to many forum discussions around viewing test logs in Visual Studio. It sort of makes sense because some of the normal logging channels don't make sense in the test environment.  Phones, web apps, console apps, services all log in different environments.  The Visual Studio team changed the location of the logging views in VS2013 (or possibly 2012). Here is my "how did I do that last time" version of configuring log4net logging for unit tests.  

Viewing Test Output

Visual studio has an Output window and an Immediate window buty my output never shows up in either. I've tried routing the console output to the Immediate window via the preferences. My output never shows up there. It seems like unit test output is only available inside TestExplorer.

1. Run a test
2. Highlight the test in Test Explorer
3. Select Output on the bottom of the test results.

You see the Output link only if you have written something to the Console or one of the Diagnostic logs.

Logged text shows up different sections of the test output windows depending on the channel and type

This screen shows messages generated by log4net configured for the ConsoleAppender and Microsoft Diagnostic traces generated using

System.Diagnostics.Debug().  

The TraceAppender puts the output in the Debug Trace section.  The ConsoleAppender puts information in Standard Output.

Note: Debug() and Trace() both show up in the same section.

Configuring Log4Net in Tests

Appender and Level Configuration

This assumes you've added a log4net reference to your test project. 

We need two components to configure log4net. The first is the log4net.properties file that configures the log4net logging levels and appenders.  The second is some piece of bootstrap markup or code to initialize log4net with that file.

Create a log4net configuration file. Name it log4net.properties and put it in the root directory of your testing project. Set the properties to be CopyAlways.

I've provided a simple sample below.  You should be able to find more sophisticated example on the Internet.

Logging Bootstrap

You're supposed to be able to do it inside your assembly.cs file.  That didn't really work for me with unit tests.

MSTest supports running assembly initialization C# code one time when the test assembly in the same way it uses assembly.cs.  I create log4net bootstrap code in a test-less C# Unit Test class. that contains one start-up method marked with the [AssemblyInitialize] attribute. You only need to create one class that will initialize log4net for all your tests.  This example has some extra output I used to understand the various destinations.  It should work for projects almost unmodified.

using log4net.Config;
using log4net;
using Microsoft.VisualStudio.TestTools.UnitTesting;
using System.IO;
using System.Diagnostics;

namespace IOIOLibDotNetTest
{
    [TestClass]
    public class LoggingSetup
    {

        [AssemblyInitialize]
        public static void Configure(TestContext tc)
        {
            //Diag output will go to the "output" logs if you add tehse two lines
            //TextWriterTraceListener writer = new TextWriterTraceListener(System.Console.Out);
            //Debug.Listeners.Add(writer);

            Debug.WriteLine("Diag Called inside Configure before log4net setup");
            XmlConfigurator.Configure(new FileInfo("log4net.properties"));
            // create the first logger AFTER we run the configuration
            ILog LOG = LogManager.GetLogger(typeof(LoggingSetup));
            LOG.Debug("log4net initialized for tests");
            Debug.WriteLine("Diag Called inside Configure after log4net setup");
        }
    }
}

I used Configure() instead of ConfigureAndWatch() because I don't manually change my logging configuration in the middle of a test run.

Sample log4j.properties

This simple properties file configures log4net to write to the Console so that I can see it in Visual Studio 2013.  It also contains Appenders that send traffic to the trace system. This

Note: Unit test performance can be greatly impacted by excessive logging. You should consider using one of the file Appenders if you have a lot of output or if you want log output in specific directories on build servers.

Conclusion 

I hope this saves others from the hassle I had making log4net output visible while running unit tests inside Visual Studio.