Injectable logging with NLog and Ninject

Question

I have been using NLog for logging purposes in my web applications, but it was not injectable. More precisely, each class using logging declared the logger like this:

private static Logger logger = LogManager.GetCurrentClassLogger();

Since my logging is very simple, I have defined some extension methods to easily log any message and/or exception information:

public static class NLogExtensions
{
 public static void LogEx(this Logger logger, LogLevel level, String message)
 {
 logger.Log(level, message);
 }
 public static void LogEx(this Logger logger, LogLevel level, String format, params object[] parameters)
 {
 logger.Log(level, format, parameters);
 }
 public static void LogEx(this Logger logger, LogLevel level, IList<String> list)
 {
 String output = String.Join("; ", list);
 LogEx(logger, level, output);
 }
 public static void LogEx(this Logger logger, LogLevel level, String message, Exception exc)
 {
 try
 {
 GlobalDiagnosticsContext.Set("FullExceptionInfo", exc.ToString());
 logger.Log(level, message, exc);
 }
 finally
 {
 GlobalDiagnosticsContext.Remove("FullExceptionInfo");
 }
 }
 public static void LogEx(this Logger logger, LogLevel level, String format, Exception exc, params object[] parameters)
 {
 try
 {
 GlobalDiagnosticsContext.Set("FullExceptionInfo", exc.ToString());
 logger.Log(level, format, parameters);
 }
 finally
 {
 GlobalDiagnosticsContext.Remove("FullExceptionInfo");
 }
 }
}

It is clear that everything is static and I cannot replace logging while automatic testing takes place, for example. So, I thought about injecting the logging mechanism.

First, I have read this article, but it looks quite complicated for my needs, so I thought of giving a try on my own.

The service

public class LoggingService : ILoggingService
{
 private static Logger logger = LogManager.GetCurrentClassLogger();
 public void Log(LogLevel level, String message)
 {
 logger.Log(level, message);
 }
 public void Log(LogLevel level, String format, params object[] parameters)
 {
 logger.Log(level, format, parameters);
 }
 public void Log(LogLevel level, IList<String> list)
 {
 String output = String.Join("; ", list);
 Log(level, output);
 }
 public void Log(LogLevel level, String message, Exception exc)
 {
 try
 {
 GlobalDiagnosticsContext.Set("FullExceptionInfo", exc.ToString());
 logger.Log(level, message, exc);
 }
 finally
 {
 GlobalDiagnosticsContext.Remove("FullExceptionInfo");
 }
 }
 public void Log(LogLevel level, String format, Exception exc, params object[] parameters)
 {
 try
 {
 GlobalDiagnosticsContext.Set("FullExceptionInfo", exc.ToString());
 logger.Log(level, format, parameters);
 }
 finally
 {
 GlobalDiagnosticsContext.Remove("FullExceptionInfo");
 }
 }
}

The configuration

 <targets>
 <target name="database" type="Database">
 <connectionString>
 Data Source=dbinstance;Initial Catalog=database;User Id=userid;Password=userpass;Application Name=TheLogger
 </connectionString>
 <commandText>
 insert into dbo.nlog
 (log_date, log_level_id, log_level, logger, log_message, machine_name, log_user_name, call_site, thread, exception, stack_trace, full_exception_info)
 values(@timestamp, dbo.func_get_nlog_level_id(@level), @level, NULL /*@logger*/, @message, @machinename, @username, NULL /*@call_site */, @threadid, @log_exception, @stacktrace, @FullExceptionInfo);
 </commandText>
 <parameter name="@timestamp" layout="${longdate}"/>
 <parameter name="@level" layout="${level}"/>
 <parameter name="@logger" layout="${logger}"/>
 <parameter name="@message" layout="${message}"/>
 <parameter name="@machinename" layout="${machinename}"/>
 <parameter name="@username" layout="${windows-identity:domain=true}"/>
 <parameter name="@call_site" layout="${callsite:filename=true}"/>
 <parameter name="@threadid" layout="${threadid}"/>
 <parameter name="@log_exception" layout="${exception}"/>
 <parameter name="@stacktrace" layout="${stacktrace}"/>
 <parameter name="@FullExceptionInfo" layout="${gdc:FullExceptionInfo}"/>
 </target>
 </targets>

It is clear that I do not have class information anymore, since the logger is defined in a single place, but my custom field FullExceptionInfo gets me relevant information for exceptions.

Is this a good approach or it can lead to trouble in the future?

• Mathieu Guindon: You know Ninject has a logging extension that supports NLog, right? The only downside of it is that it requires a Ninject dependency, but then you get a constructor-injected ILogger automagically.. by merely specifying an ILogger constructor parameter anywhere you need one.
• Alexei: Yes, I know of its existence, but I felt like reinventing the wheel :). I don't mind Ninject dependency, because it seems very flexible and has a lot of community support.

Answer 1

Your implementation looks all right. It should be able to injected by any DI tool as you work with abstractions.

But I got couple of improvement notes:

1. Logger type:

    private static Logger logger = LogManager.GetCurrentClassLogger();
   

This would generate yournamespace.LoggingService as the logger.

I believe key part of your log file is to identify where the log has been originated/written. Therefore create a logger base on the caller's type (where the logger file being used)

2. self explanatory methods: Instead of having overload methods think of having self explanatory method and consumers of your logger would have better understanding what method would appropriate for the given situation. e.g Info, Debug, Exception, LogException, LogExceptionWithParameters etc.

Think about given meaning full names for the following methods in your implementation.

void Log(LogLevel level, String format, params object[] parameters)
void Log(LogLevel level, IList<String> list)
void Log(LogLevel level, String message, Exception exc)
void Log(LogLevel level, String format, Exception exc, params object[] parameters)

As a side note; If I'm were you I would implement a Logger factory to create loggers base on the caller's type.

Eg.

Factory

public interface ILoggerFactory
{
 ILogger Create<T>() where T : class;
}
public class LoggerFactory:ILoggerFactory
{
 public ILogger Create<T>() where T : class
 {
 return new Loger(typeof(T));
 }
}

Logger

public interface ILogger
{
 string Name { get; }
 void Debug(string message);
}
public class Loger:ILogger
{
 private readonly NLog.Logger _logger;
 public Loger(Type type)
 {
 if(type==null)
 throw new ArgumentNullException("type");
 _logger = LogManager.GetCurrentClassLogger();
 }
 public string Name {
 get { return _logger.Name; }
 }
 public void Debug(string message)
 {
 _logger.Debug(message);
 }
}

Usage

 var logger = loggerFactory.Create<CallerClass>();
 logger.Debug("some debug message");

• Alexei: Thanks for taking the time to review. I know about defining a static logger for each class to have the origin of the log message, but the stacktrace and FullExceptionInfo usually provide all the required information. I do not see a major advantage of creating a method for each level (Debug, Info etc.). but having appropriate names for logging of exceptions, formatted information is a very good idea.
• Marshal: @RSF I see that object of type System.Type is passed to the constructor of Loger, but the object doesn't seem to be used anywhere?

Answer 2

Well I would not recommend doing an abstraction layer over your logging, and also by setting the Logger thru DI, you are not allowing the GetCurrentClassLogger to work the right way.

This is HUGELY important because that way you can say that this class X should output the log thru email, and this other class Y can output the log to file. All thru just configuration.

Therefore just use the logger in each class and write messages to it. That is the best approach and it should be the only pattern you SHOULD use.