Log4Net Singleton Wrapper for Concurrent Logging

• Download source code - 13.4 KB

Introduction

There have been numerous questions, as well as my experiences with companies who use Log4Net (see https://logging.apache.org/log4net/) regarding how the use of Log4Net affects the application it is being used in.

Background

I have seen Log4Net being used at four different companies, in each case, it has been assumed that the effect of logging on the application is relevant or is not a considerative factor.

For most applications, I would agree that there is really no cause for concern, however, being aware of the effects and providing a solution to those effects is a necessary understanding for implementing a logging strategy.

The out-of-the box implementation of Log4Net implementation is (I have seen many questions on this) thread-safe, logging can be accomplished from many threads. However, the logging process, which is actuated by appenders can be a problem. Log4Net passes the log to the Appenders and blocks until all the appenders have received the log message

For applications which do not have extensive logging, or the logging load is not large and concurrent, this does not present a problem. This is not the case otherwise.

Using the Code

The console application "Log4NetWrapper" demo application to show the results of "out-of-the-box" logging verses an application that uses Log4Net for concurrent logging. It shows the average amount of time added to the application for logging for "out-of-box" and for concurrent logging.

Out of the Box logging:

//
// Needed for out-of-box logging
//
private static readonly log4net.ILog _log = log4net.LogManager.GetLogger
                (System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);
...
private static long NormalLogTest()
{
    Stopwatch sw = Stopwatch.StartNew();

    _log.Info("Normal Input 1");
    _log.Info("Normal Input 2");
    _log.Info("Normal Input 3");

    sw.Stop();

    return sw.ElapsedTicks;
}

Concurrent logging:

private static long ConcurrentLogTest()
{
    Stopwatch sw = Stopwatch.StartNew();

    Logger.Instance().Info("Spooled Input 1");
    Logger.Instance().Info("Spooled Input 2");
    Logger.Instance().Info("Spooled Input 3");

    sw.Stop();

    return sw.ElapsedTicks;
}

Executing and Summarizing execution:

long normalTotal = 0;
long concurrentTotal = 0;

for (var i = 0; i < 2; i++)
{
normalTotal += NormalLogTest();
}

for (var i = 0; i < 2; i++)
{
concurrentTotal += ConcurrentLogTest();
}

Console.WriteLine();
Console.WriteLine("Summary of results");

var averageForNormal = normalTotal / 2;
var averageForConcurrent = concurrentTotal / 2;

Console.WriteLine("Application time for normal logging: {0} ticks,
                  {1} milliseconds", averageForNormal, averageForNormal / 10000);
Console.WriteLine("Application time for concurrent logging: {0} ticks,
                  {1} milliseconds", averageForConcurrent, averageForConcurrent / 10000);

Points of Interest

I added a generic class to easily make a concurrent queue (a.k.a. a spooler), please feel free to reuse as needed.