A Simple Wrapper for log4net

Introduction

log4net is a highly flexible logging framework available for .NET. Now firstly, let me say that this article assumes a basic familiarity with the log4net framework, and is in not intended either as an introduction to log4net or a tutorial in how to configure and use log4net.

If you are unfamiliar with log4net, you can find the documentation here, or have a look at this article on CodeProject.

The Problem

One of my main criticisms of log4net is that I find the syntax somewhat clumsy. Take, for example, the following code to add a line of simple debugging logging:

// C#
ILog log = LogManager.GetLogger("MyLog");
if (log.IsDebugEnabled)
{
    using (ThreadContext.Stacks["MyProperty"].Push("MyValue"))
    {
        using(ThreadContext.Stacks["MyOtherProperty"].Push("MyOtherValue"))
        {
            log.Debug("This is a debugging message.");
        }
    }
}

' Visual Basic
Dim log As ILog = LogManager.GetLogger("MyLog")
If log.IsDebugEnabled Then
    Using ThreadContext.Stacks("MyProperty").Push("MyValue")
        Using ThreadContext.Stacks("MyOtherProperty").Push("MyOtherValue")
            log.Debug("This is a debugging message.")
        End Using
    End Using
End If

As you can see, performing what should be a simple logging operation takes up about half-a-dozen lines of code. Clearly for even the smallest application, littering the code with statements like those just shown, simply for logging purposes, is not exactly desirable and would soon become unreadable as the logging code starts to drown out the logic code.

What is needed is a solution whereby a logging operation can be accomplished with a single line of code.

The Solution

My solution is a static class, called Logger, which has two methods (plus overloads): Initialize() to initialize log4net, and Log() which actually performs the logging operation

Firstly, let's look at the Initialize() method. This has two overloads: one takes a single parameter which specifies the config file to be used by log4net. The parameterless overload specifies that log4net should pull its configuration from web.config or app.config:

// C#
private static bool isInitialized;

public static void Initialize()
{
    Initialize(null);
}

public static void Initialize(string configFile)
{
    if (!isInitialized)
    {
        if (!String.IsNullOrEmpty(configFile))
            XmlConfigurator.ConfigureAndWatch(new FileInfo(configFile));
        else
            XmlConfigurator.Configure();
        isInitialized = true;
    }
    else
        throw new LoggingInitializationException(
              "Logging has already been initialized.");
}

' Visual Basic
Private _isInitialized As Boolean

Public Sub Initialize()
    Initialize(Nothing)
End Sub

Public Sub Initialize(ByVal configFile As String)
    If Not _isInitialized Then
        If Not String.IsNullOrEmpty(configFile) Then
            XmlConfigurator.ConfigureAndWatch(New FileInfo(configFile))
        Else
            XmlConfigurator.Configure()
        End If
        _isInitialized = True
    Else
        Throw New LoggingInitializationException("Logging has already been initialized.")
    End If
End Sub

Next, we'll look at the Log() method and its overloads. These methods accept various combinations of the following parameters:

Parameter	Description
logName	The name of the log to write the event to. If omitted, the event is written to all logs.
loggingLevel	The level (debug, info, warning, error or fatal) of the event.
message	The message.
loggingProperties	An object whose properties map to log4net PatternLayout properties (e.g.: %property{Foo} where Foo is the name of the property).
exception	The exception (if any) to be logged.

All of the Log() method overloads ultimately call LogBase() which is where the actual calls to log4net are made. The code for this method is as follows:

// C#
private static void LogBase(ILog log, LoggingLevel loggingLevel, 
        string message, object loggingProperties, Exception exception)
{
    if (ShouldLog(log, loggingLevel))
    {
        PushLoggingProperties(loggingProperties);
        switch (loggingLevel)
        {
            case LoggingLevel.Debug: log.Debug(message, exception); break;
            case LoggingLevel.Info: log.Info(message, exception); break;
            case LoggingLevel.Warning: log.Warn(message, exception); break;
            case LoggingLevel.Error: log.Error(message, exception); break;
            case LoggingLevel.Fatal: log.Fatal(message, exception); break;
        }
        PopLoggingProperties(loggingProperties);
    }
}

' Visual Basic
Private Sub LogBase(ByVal log As ILog, ByVal loggingLevel As LoggingLevel, _
        ByVal message As String, ByVal loggingProperties _
        As Object, ByVal exception As Exception)
    If ShouldLog(log, loggingLevel) Then
        PushLoggingProperties(loggingProperties)
        Select Case loggingLevel
            Case VisualBasic.LoggingLevel.Debug
                log.Debug(message, exception)
            Case VisualBasic.LoggingLevel.Info
                log.Info(message, exception)
            Case VisualBasic.LoggingLevel.Warning
                log.Warn(message, exception)
            Case VisualBasic.LoggingLevel.Error
                log.Error(message, exception)
            Case VisualBasic.LoggingLevel.Fatal
                log.Fatal(message, exception)
        End Select
        PopLoggingProperties(loggingProperties)
    End If
End Sub

As you can see, the first call made by this method is to the ShouldLog() method, which determines whether or not the event should be logged, based on the current logging level:

// C#
private static bool ShouldLog(ILog log, LoggingLevel loggingLevel)
{
    switch (loggingLevel)
    {
        case LoggingLevel.Debug: return log.IsDebugEnabled;
        case LoggingLevel.Info: return log.IsInfoEnabled;
        case LoggingLevel.Warning: return log.IsWarnEnabled;
        case LoggingLevel.Error: return log.IsErrorEnabled;
        case LoggingLevel.Fatal: return log.IsFatalEnabled;
        default: return false;
    }
}

' Visual Basic
Private Function ShouldLog(ByVal log As ILog, _
        ByVal loggingLevel As LoggingLevel) As Boolean
    Select Case loggingLevel
        Case VisualBasic.LoggingLevel.Debug
            Return log.IsDebugEnabled
        Case VisualBasic.LoggingLevel.Info
            Return log.IsInfoEnabled
        Case VisualBasic.LoggingLevel.Warning
            Return log.IsWarnEnabled
        Case VisualBasic.LoggingLevel.Error
            Return log.IsErrorEnabled
        Case VisualBasic.LoggingLevel.Fatal
            Return log.IsFatalEnabled
        Case Else
            Return False
    End Select
End Function

If this method returns true, the next method to be called is PushLoggingProperties(). This takes the loggingProperties parameter and uses Reflection to push the values of each of the properties onto the log4net ThreadContext stack:

// C#
private static void PushLoggingProperties(object loggingProperties)
{
    if (loggingProperties != null)
    {
        Type attrType = loggingProperties.GetType();
        PropertyInfo[] properties = attrType.GetProperties(
                       BindingFlags.Public | BindingFlags.Instance);
        for (int i = 0; i < properties.Length; i++)
        {
            object value = properties[i].GetValue(loggingProperties, null);
            if (value != null)
                ThreadContext.Stacks[properties[i].Name].Push(value.ToString());
        }
    }
}

' Visual Basic
Private Sub PushLoggingProperties(ByVal loggingProperties As Object)
    If Not loggingProperties Is Nothing Then
        Dim attrType As Type = loggingProperties.GetType()
        Dim properties() As PropertyInfo = attrType.GetProperties(
                         BindingFlags.Public Or BindingFlags.Instance)
        For i As Integer = 0 To properties.Length - 1 Step +1
            Dim value As Object = properties(i).GetValue(loggingProperties, Nothing)
            If Not value Is Nothing Then
                ThreadContext.Stacks(properties(i).Name).Push(value.ToString())
            End If
        Next
    End If
End Sub

Next, the code calls the appropriate logging method on the log4net ILog object, based on the current logging level. This is followed by a call to the PopLoggingProperties() which simply performs the reverse of PushLoggingProperties() and pops the properties off the stack.

Some Examples

Here are some examples of the Logger class in action. In these examples, we are using the following PatternLayout:

<layout type="log4net.Layout.PatternLayout">
    <conversionPattern 
     value="%date [%thread] %-5level %logger [%property{User}]: 
            %{property{Environment}  - %message%newline%exception" />
</layout>

// C#
// Initialise log4net
Logger.Initialize();

// Write a debugging event to all logs.
Logger.Log(LoggingLevel.Debug, "Calling method Foo().", 
           new { User = "Joe Bloggs", Environment = "UAT" });

// Write an exception to the log called "ErrorLog".
try
{
    int i = 25;
    int j = 0;
    int foo = i / j;
}
catch (DivideByZeroException ex)
{
    Logger.Log("ErrorLog", LoggingLevel.Error, "Attempted to divide by zero.",
    new { User = "Fred Bloggs", Environment = "Production" }, ex);
}

' Visual Basic
' Initialise log4net
Logger.Initialize()

' Write a debugging event to all logs.
Logger.Log(LoggingLevel.Debug, "Calling method Foo().", _
   New With {.User = "Joe Bloggs", .Environment = "UAT"})

' Write an exception to the log called "ErrorLog".
Try
    Dim i As Integer = 25
    Dim j As Integer = 0
    Dim foo As Integer = CInt(i / j)
Catch ex As DivideByZeroException
    Logger.Log("ErrorLog", LoggingLevel.Error, "Attempted to divide by zero.", _
    New With {.User = "Fred Bloggs", .Environment = "Production"}, ex)
End Try

Summary

With a simple wrapper, it is possible abstract away the code for interacting with the log4net framework, and at the same time improve the readability of our code by reducing logging operations to single lines.

You can download the complete code from here.