Logging strategy setup

Question

I finally set up my logging infrastructure to work as desired, however I feel like I had to do quite a lot things just to fulfill a few requirements. Now I'm worried if my approach has major drawbacks, e.g. in performance or stability, so I need your help!

Requirements

• Logging to multiple output sources, depending on configuration and environment (e.g. Console or Windows Service)
• Pre-evaluation of logging conditions for formatting, which means: If the message won't be logged, nothing gets formatted or converted to improve performance and memory usage
• Abstraction of logging implementation for use within domain & infrastructure layer (application is split up according to the Onion Architecture)
• Ability to inject logging abstraction into classes (DI)

Framework I've chosen log4net as the framework behind because of it's straight-forward configuration and variety of listeners (appenders)

Implementation

Basically, everytime I need to have logging abilities in a class, I request a custom ILogger interface via the constructor. This interface will be served using dependency injection with Ninject as my IoC container. The interface, among with extension methods etc. is implemented in a "Core" library every other project can reference to (library for cross cutting concerns).

The actual logger (log4net adapter) is implemented in a infrastructure project called "Infrastructure.Logging". The adapter itself requests a implementation of the log4net facade ILog via constructor, which will also be served by Ninject. It routes the calls to ILogger forward to log4net with the appropriate log4net level.

Everything gets hooked up at the start of the application. More than 4 appenders will be registered, which can be activated/deactivated using log4net property filters. Also, the ILog interface is bound to a log4net logging instance using a method binding to LogManager.

MyApp.Core

ILogger

public enum EventSeverity
{
    Informational,
    Warning,
    Error,
    Fatal,
    Debug,
    Verbose
}

public interface ILogger {

    bool IsDebugEnabled             { get; }
    bool IsVerboseEnabled           { get; }
    bool IsInformationalEnabled     { get; }
    bool IsWarningEnabled           { get; }
    bool IsFatalEnabled             { get; }
    bool IsErrorEnabled             { get; }

    void Write(string message, EventSeverity severity);
    void Write(string message, Exception exception, EventSeverity severity);

}

LoggerExtensions

public static class LoggerExtensions
{

    public static void Informational(this ILogger logger, string message)
    {
        if (logger.IsInformationalEnabled)
            logger.Write(message, EventSeverity.Informational);
    }

    public static void Informational(this ILogger logger, string format, params object[] args)
    {
        if (logger.IsInformationalEnabled)
            logger.Write(String.Format(format, args), EventSeverity.Informational);
    }

    public static void Warning(this ILogger logger, string message)
    {
        if (logger.IsWarningEnabled)
            logger.Write(message, EventSeverity.Warning);
    }

    // ... error, fatal, verbose

MyApp.Infrastructure.Logging

Log4NetLoggingAdapter

public sealed class Log4NetLoggingAdapter : ILogger
{

    private readonly ILog _internalLogger;

    public bool IsDebugEnabled
    {
        get { return _internalLogger.IsDebugEnabled; }
    }

    public bool IsVerboseEnabled
    {
        get { return _internalLogger.Logger.IsEnabledFor(Level.Verbose); }
    }

    // ... isWarningEnabled, isInfoEnabled..

    public Log4NetLoggingAdapter(ILog internalLogger)
    {
        if (internalLogger == null)
            throw new ArgumentNullException("internalLogger");
        _internalLogger = internalLogger;
    }

    public void Write(string message, EventSeverity severity)
    {
        Write(message, null, severity);
    }

    public void Write(string message, Exception exception, EventSeverity severity)
    {
        var level = GetLevelFromSeverity(severity);
        _internalLogger.Logger.Log(MethodBase.GetCurrentMethod().DeclaringType, 
            level, message, exception);
    }

    private static Level GetLevelFromSeverity(EventSeverity severity)
    {
        switch (severity)
        {
            case EventSeverity.Informational:
                return Level.Info;
            case EventSeverity.Warning:
                return Level.Warn;
    // ... etc..
    }

MyApp.Server

log4net configuration

    <root>
        <level value="INFO"/>
        <appender-ref ref="ColoredConsoleAppender" />
        <appender-ref ref="RollingFileAppender" />
        <appender-ref ref="EventLogAppender" />
        <appender-ref ref="DebugAppender" />
    </root>

    <appender name="DebugAppender" type="log4net.Appender.DebugAppender">
        <immediateFlush value="true" />
        <filter type="log4net.Filter.PropertyFilter">
            <key value="DebugEnabled" />
            <stringToMatch value="True" />
            <acceptOnMatch value="true" />
        </filter>
        <filter type="log4net.Filter.DenyAllFilter" />
        <layout type="log4net.Layout.PatternLayout">
            <conversionPattern value="%date [%thread] %-5level [%property{NDC}] - %message%newline%exception" />
        </layout>
    </appender>

    <appender name="RollingFileAppender" type="log4net.Appender.RollingFileAppender">

        <filter type="log4net.Filter.PropertyFilter">
            <key value="ApplicationMode" />
            <stringToMatch value="Service" />
            <acceptOnMatch value="true" />
        </filter>

        <filter type="log4net.Filter.DenyAllFilter" />

        <file value="app.log" />
        <appendToFile value="true" />
        <rollingStyle value="Size" />
        <maxSizeRollBackups value="3" />
        <maximumFileSize value="1000KB" />
        <staticLogFileName value="true" />
        <layout type="log4net.Layout.PatternLayout">
            <conversionPattern value="%date [%thread] %-5level %logger [%property{NDC}] - %message%newline%exception" />
        </layout>
    </appender>

    <appender name="EventLogAppender" type="log4net.Appender.EventLogAppender" >

        <filter type="log4net.Filter.PropertyFilter">
            <key value="ApplicationMode" />
            <stringToMatch value="Service" />
            <acceptOnMatch value="true" />
        </filter>

        <filter type="log4net.Filter.LevelRangeFilter">
            <acceptOnMatch value="true" />
            <levelMin value="ERROR" />
            <levelMax value="FATAL" />
        </filter>

        <filter type="log4net.Filter.DenyAllFilter" />

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

    <appender name="ColoredConsoleAppender" type="log4net.Appender.ColoredConsoleAppender">

        <filter type="log4net.Filter.PropertyFilter">
            <key value="ApplicationMode" />
            <stringToMatch value="Console" />
            <acceptOnMatch value="true" />
        </filter>

        <filter type="log4net.Filter.DenyAllFilter" />

        <mapping>
            <level value="INFO" />
            <foreColor value="White, HighIntensity" />
            <backColor value="Green" />
        </mapping>
        <mapping>
            <level value="DEBUG" />
            <foreColor value="White, HighIntensity" />
            <backColor value="Blue" />
        </mapping>
        <mapping>
            <level value="WARN" />
            <foreColor value="Yellow, HighIntensity" />
            <backColor value="Purple" />
        </mapping>
        <mapping>
            <level value="ERROR" />
            <foreColor value="Yellow, HighIntensity" />
            <backColor value="Red" />
        </mapping>
        <layout  type="log4net.Layout.PatternLayout">
            <conversionPattern value="[%date] %message%newline%exception" />
        </layout>
    </appender>

Program (pseudo code)

internal static class Program {

    private static IKernel _kernel;
    private static ILogger _logger;

    internal static void Main() {

        // setup kernel
        _kernel = new StandardKernel();
        _kernel.Bind<ILog>().ToMethod(context => {
            return LogManager.GetLogger(context.Request.ParentRequest.ParentRequest.Target.Member.DeclaringType) };
        _kernel.Bind<ILogger>().To<Log4NetLoggerAdapter>();

        // init log4net
        XmlConfigurator.Configure();

        // load server configuration
        if(serverConfiguration.IsDebug) {
           if(!Debugger.IsAttached())
                Debugger.Launch();

            ThreadContext.Properties["DebugEnabled"] = "True";

        }

        if(!Environment.UserInteractive) {
                    ThreadContext.Properties["ApplicationMode"] = "Service";
                    // setup service controller
        } else {
                    ThreadContext.Properties["ApplicationMode"] = "Console";
                    Start();
        }

Answer 1

Using extension methods and the interface makes me think you should use an abstract class to encapsulate the logging framework you use. I put the Write method and the overloads protected but you could put it public back if you need. Also, as you'll see it, I added brackets to your one line's if. I believe that even if it adds some lines of code, it gives a much better readability to your code.

public abstract class Logger
{
    public abstract bool IsDebugEnabled { get; }
    public abstract bool IsVerboseEnabled { get; }
    public abstract bool IsInformationalEnabled { get; }
    public abstract bool IsWarningEnabled { get; }
    public abstract bool IsFatalEnabled { get; }
    public abstract bool IsErrorEnabled { get; }

    protected abstract void Write(string message, EventSeverity severity);
    protected abstract void Write(string message, Exception exception, EventSeverity severity);

    public void LogInformational(string message)
    {
       if (IsInformationalEnabled)
       {
          Write(message, EventSeverity.Informational);
       }
    }

    public void LogInformational(string format, params object[] args)
    {
       if (IsInformationalEnabled)
       {
          Write(String.Format(format, args), EventSeverity.Informational);
       }
    }

    public void Warning(string message)
    {
       if (IsWarningEnabled)
       {
          Write(message, EventSeverity.Warning);
       }
    }

    //etc..
}

Edit :

I think you should keep your interface as clear as possible. Your contract should define the minimum you need, which is both Write methods. The other methods, as you mentioned, might not be supported by your logging framework, which means they wouldn't comply to the interface. Also, these methods have a little problem, let me give you an example. If IsInformationalEnabled = false and you call LogInformational, you have no feedback that the information wasn't logged, which is a problem. I think your Write method should deal with this, to keep it as simple as possible. Look at the following approach, I think it is an okay way to abstract your logger.

public abstract class Logger
{
    protected abstract bool IsDebugEnabled { get; }
    protected abstract bool IsVerboseEnabled { get; }
    protected abstract bool IsInformationalEnabled { get; }
    protected abstract bool IsWarningEnabled { get; }
    protected abstract bool IsFatalEnabled { get; }
    protected abstract bool IsErrorEnabled { get; }

    public void Write(string message, EventSeverity severity)
    {
       ValidateSeverityEnabled(severity);
       WriteToLog(message,severity);
    } 

    public void Write(string message, Exception exception, EventSeverity severity)
    {
       ValidateSeverityEnabled(severity);
       WriteToLog(message, exception, severity);
    }

    protected abstract void WriteToLog(string message, EventSeverity severity);
    protected abstract void WriteToLog(string message, Exception exception, EventSeverity severity);

    private void ValidateSeverityEnabled(EventSeverity severity)
    {
       switch (severity)
       { 
          case EventSeverity.Informational:
             if (!IsInformationalEnabled)
                throw new InvalidOperationException("Informational log disabled");
             break;
          case EventSeverity.Warning:
             if (!IsWarningEnabled)
                throw new InvalidOperationException("Warning log disabled");
             break;
          case EventSeverity.Error:
             if (!IsErrorEnabled)
                throw new InvalidOperationException("Error log disabled");
             break;
          case EventSeverity.Fatal:
             if (!IsFatalEnabled)
                throw new InvalidOperationException("Fatal log disabled");
             break;
          case EventSeverity.Debug:
             if (!IsDebugEnabled)
                throw new InvalidOperationException("Debug log disabled");
             break;
          case EventSeverity.Verbose:
             if (!IsVerboseEnabled)
                throw new InvalidOperationException("Verbose log disabled");
             break;
       }
    }
}

Answer 2

Your design is quite good. Reading the code you wrote I have a few notes.

What's the point of LoggerExtensions? I am not sure that it is a good idea to define an ILogger interface and then put almost all the methods you're supposed to used to interact with it in LoggerExtensions.

I think that you want ILogger to cover two different concerns. The first is what the client of your library should use, the other is what you need from your logging backend.

I'd rename your ILogger in ILoggerAdapter and I'd introduce a new Logger class implemented as follows:

public class Logger
{
    private readonly ILoggerAdapter backend;

    public Logger(ILoggerAdapter backend)
    {
        this.backend = backend;
    }

    public void Informational(this ILogger logger, string message)
    {
        if (logger.IsInformationalEnabled)
            logger.Write(message, EventSeverity.Informational);
    }

    /* all the other methods you had in LoggerExtensions */
}

If you do this now you have different classes to cover different concerns with a very lightweight API.

I appreciate your use of dependency injection instead of using singletons. I think it is quite good.