Using NLog with Dependency Injection

In my last post I blogged about using Dependency Injection to break tight coupling between application components. This lets you to treat infrastructure pieces, such as data access or logging, as swappable entities, allowing your application to change with the times as new technology stacks replace obsolete or deprecated ones.

In this blog post I will share how I took an open-source logging framework, called NLog, and made it injectable by an DI (Ioc) container, such as Ninject. There’s no reason you couldn’t apply this same technique with other logging frameworks, such as Log4Net, or DI containers, such as StructureMap.

Before I set out, I searched for an existing solution and found Ninject.Extensions.Logging.nlog2 in the NuGet online gallery. However, when I applied the solution I ran into a security exception that stopped me in my tracks. (The author as promised to fix it in the next version but has not set a timeline.) In addition, I found some shortcomings in how NLog records exception details and ended up building a thin wrapper that provides richer information on exceptions, such as the assembly, class and method in which the exception occurred.

My first order of business was to create an ILoggingService interface, so as to decouple consumers from the actual logging framework.

public interface ILoggingService
{
    bool IsDebugEnabled { get; }
    bool IsErrorEnabled { get; }
    bool IsFatalEnabled { get; }
    bool IsInfoEnabled { get; }
    bool IsTraceEnabled { get; }
    bool IsWarnEnabled { get; }
    void Debug(Exception exception);
    void Debug(string format, params object[] args);
    void Debug(Exception exception, string format, params object[] args);
    void Error(Exception exception);
    void Error(string format, params object[] args);
    void Error(Exception exception, string format, params object[] args);
    void Fatal(Exception exception);
    void Fatal(string format, params object[] args);
    void Fatal(Exception exception, string format, params object[] args);
    void Info(Exception exception);
    void Info(string format, params object[] args);
    void Info(Exception exception, string format, params object[] args);
    void Trace(Exception exception);
    void Trace(string format, params object[] args);
    void Trace(Exception exception, string format, params object[] args);
    void Warn(Exception exception);
    void Warn(string format, params object[] args);
    void Warn(Exception exception, string format, params object[] args);
}

I then implemented the interface in a LoggingService class, placing it in a separate assembly than ILoggingService, so that consumers could reference the interface without referencing the implementation assembly, which included some custom layout renderers for UTC dates and web variables (borrowed from here). I also had to call an overload of the Log method that accepts the custom logger type so that NLog would ignore the logger when analyzing the call stack.

public class LoggingService : NLog.Logger, ILoggingService
{
    private const string _loggerName = "NLogLogger";
    public static ILoggingService GetLoggingService()
    {
        ConfigurationItemFactory.Default.LayoutRenderers
            .RegisterDefinition("utc_date", typeof(UtcDateRenderer));
        ConfigurationItemFactory.Default.LayoutRenderers
            .RegisterDefinition("web_variables", typeof(WebVariablesRenderer));
        ILoggingService logger = (ILoggingService)LogManager.GetLogger("NLogLogger", typeof(LoggingService));
        return logger;
    }
    public void Debug(Exception exception, string format, params object[] args)
    {
        if (!base.IsDebugEnabled) return;
        var logEvent = GetLogEvent(_loggerName, LogLevel.Debug, exception, format, args);
        base.Log(typeof(LoggingService), logEvent);
    }
    public void Error(Exception exception, string format, params object[] args)
    {
        if (!base.IsErrorEnabled) return;
        var logEvent = GetLogEvent(_loggerName, LogLevel.Error, exception, format, args);
        base.Log(typeof(LoggingService), logEvent);
    }
    public void Fatal(Exception exception, string format, params object[] args)
    {
        if (!base.IsFatalEnabled) return;
        var logEvent = GetLogEvent(_loggerName, LogLevel.Fatal, exception, format, args);
        base.Log(typeof(LoggingService), logEvent);
    }
    public void Info(Exception exception, string format, params object[] args)
    {
        if (!base.IsInfoEnabled) return;
        var logEvent = GetLogEvent(_loggerName, LogLevel.Info, exception, format, args);
        base.Log(typeof(LoggingService), logEvent);
    }
    public void Trace(Exception exception, string format, params object[] args)
    {
        if (!base.IsTraceEnabled) return;
        var logEvent = GetLogEvent(_loggerName, LogLevel.Trace, exception, format, args);
        base.Log(typeof(LoggingService), logEvent);
    }
    public void Warn(Exception exception, string format, params object[] args)
    {
        if (!base.IsWarnEnabled) return;
        var logEvent = GetLogEvent(_loggerName, LogLevel.Warn, exception, format, args);
        base.Log(typeof(LoggingService), logEvent);
    }
    public void Debug(Exception exception)
    {
        this.Debug(exception, string.Empty);
    }
    public void Error(Exception exception)
    {
        this.Error(exception, string.Empty);
    }
    public void Fatal(Exception exception)
    {
        this.Fatal(exception, string.Empty);
    }
    public void Info(Exception exception)
    {
        this.Info(exception, string.Empty);
    }
    public void Trace(Exception exception)
    {
        this.Trace(exception, string.Empty);
    }
    public void Warn(Exception exception)
    {
        this.Warn(exception, string.Empty);
    }
    private LogEventInfo GetLogEvent(string loggerName, LogLevel level, Exception exception, string format, object[] args)
    {
        string assemblyProp = string.Empty;
        string classProp = string.Empty;
        string methodProp = string.Empty;
        string messageProp = string.Empty;
        string innerMessageProp = string.Empty;
        var logEvent = new LogEventInfo
            (level, loggerName, string.Format(format, args));
        if (exception != null)
        {
            assemblyProp = exception.Source;
            classProp = exception.TargetSite.DeclaringType.FullName;
            methodProp = exception.TargetSite.Name;
            messageProp = exception.Message;
            if (exception.InnerException != null)
            {
                innerMessageProp = exception.InnerException.Message;
            }
        }
        logEvent.Properties["error-source"] = assemblyProp;
        logEvent.Properties["error-class"] = classProp;
        logEvent.Properties["error-method"] = methodProp;
        logEvent.Properties["error-message"] = messageProp;
        logEvent.Properties["inner-error-message"] = innerMessageProp;
            
        return logEvent;
    }
}

The Visual Studio solution includes a DependencyResolution project in the solution with a NinjectModule class that binds ILoggingService to the concrete LoggingService implementation. It turns out that the NLog.config file needs to be placed in the same directory as this assembly’s dll, by setting the “Copy to Output Directory” property of the file to “Copy Always.” While I could have created a custom exception renderer, I simply used the convenient Event-context layout renderer.

<?xml version="1.0" encoding="utf-8" ?>
<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
      xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
  <!-- make sure to set 'Copy To Output Directory' option for this file -->
  <!-- go to http://nlog-project.org/wiki/Configuration_file for more information -->
  <targets>
    <target name="console"
            xsi:type="ColoredConsole"
            layout="Server-Date: ${longdate}; UTC-Date: ${utc_date}; Level: ${level}; Log-Message: ${message}; Error-Source: ${event-context:item=error-source}; Error-Class: ${event-context:item=error-class}; Error-Method: ${event-context:item=error-method}; Error-Message: ${event-context:item=error-message}; Inner-Error-Message: ${event-context:item=inner-error-message}" />
    <target name="debug"
            xsi:type="Debugger"
            layout="Server-Date: ${longdate}; UTC-Date: ${utc_date}; Level: ${level}; Log-Message: ${message}; Error-Source: ${event-context:item=error-source}; Error-Class: ${event-context:item=error-class}; Error-Method: ${event-context:item=error-method}; Error-Message: ${event-context:item=error-message}; Inner-Error-Message: ${event-context:item=inner-error-message}" />
  </targets>
  <rules>
    <logger name="*" 
            minlevel="Trace" 
            writeTo="console,debug" />
  </rules>
</nlog>

I created a simple console app to test the logger by newing up a widget and calling a method that throws an exception.

class Program
{
    static void Main(string[] args)
    {
        IKernel kernel = new StandardKernel(new LoggingModule());
        var provider = kernel.Get<WidgetProvider>();
        var widget = new Widget();
        provider.UseWidget(widget);
        Console.WriteLine("Press Enter to Exit");
        Console.ReadLine();
    }
}

The UseWidget method catches an exception thrown by the Widget.Foo method, calling ILoggingService.Error and passing the exception.

public class WidgetProvider
{
    private readonly ILoggingService _logger;
    public WidgetProvider(ILoggingService logger)
    {
        _logger = logger;
    }
    public void UseWidget(Widget widget)
    {
        try
        {
            widget.Foo();
        }
        catch (Exception ex)
        {
            _logger.Error(ex);
        }
    }
}

Here is the exception thrown by Widget.Foo:

public class Widget
{
    public void Foo()
    {
        throw new Exception("Never divide by zero",
            new DivideByZeroException());
    }
}

Running the console app produces the following output from the “console” logging target:

The Debug window shows the output of the “debug” logging target:

Application components can log messages or exceptions using the injected ILoggingService interface. You can download the code for this blog post here. Enjoy.

Reference: Using NLog with Dependency Injection from our NCG partner Tony Sneed at the Tony Sneed’s Blog blog.