Introducing this.Log

One of my favorite creations over the past year has been this.Log(). It works everywhere including static methods and in razor views. Everything about how to create it and set it up is in this gist.

How It Looks

public class SomeClass {
 
  public void SomeMethod() {
    this.Log().Info(() => "Here is a log message with params which can " + 
      "be in Razor Views as well: '{0}'".FormatWith(typeof(SomeClass).Name));

    this.Log().Debug("I don't have to be delayed execution or have parameters either");
  }

  public static void StaticMethod() {
    "SomeClass".Log().Error("This is crazy, right?!");
  } 
}

Why It’s Awesome

• It does no logging if you don’t have a logging engine set up.
• It works everywhere in your code base (where you can write C#). This means in your razor views as well!
• It uses deferred execution, which means you don’t have to mock it to use it with testing (your tests won’t fail on logging lines).
• You can mock it easily and use that as a means of testing.
• You have no references to your actual logging engine anywhere in your codebase, so swapping it out (or upgrading) becomes a localized event to one class where you provide the adapter.

Some Internals

This uses the awesome static logging gateway that JP Boodhoo showed me a long time ago at a developer bootcamp, except it takes the concept further. One thing that always bothered me about the static logging gateway is that it would construct an object every time you called the logger if you were using anything but log4net or NLog. Internally, it likely continued to reuse the same object, but at the codebase level, it appeared as that was not so.

/// <summary>
/// Logger type initialization
/// </summary>
public static class Log
{
    private static Type _logType = typeof(NullLog);
    private static ILog _logger;
 
    /// <summary>
    /// Sets up logging to be with a certain type
    /// </summary>
    /// <typeparam name="T">The type of ILog for the application to use</typeparam>
    public static void InitializeWith<T>() where T : ILog, new()
    {
        _logType = typeof(T);
    }
 
    /// <summary>
    /// Sets up logging to be with a certain instance. The other method is preferred.
    /// </summary>
    /// <param name="loggerType">Type of the logger.</param>
    /// <remarks>This is mostly geared towards testing</remarks>
    public static void InitializeWith(ILog loggerType)
    {
        _logType = loggerType.GetType();
        _logger = loggerType;
    }
 
    /// <summary>
    /// Initializes a new instance of a logger for an object.
    /// This should be done only once per object name.
    /// </summary>
    /// <param name="objectName">Name of the object.</param>
    /// <returns>ILog instance for an object if log type has been intialized; otherwise null</returns>
    public static ILog GetLoggerFor(string objectName)
    {
        var logger = _logger;
 
        if (_logger == null)
        {
            logger = Activator.CreateInstance(_logType) as ILog;
            if (logger != null)
            {
                logger.InitializeFor(objectName);
            }
        }
 
        return logger;
    }
}

You see how when it calls InitializeFor, that’s when you get something like the following in the actual implemented method:

_logger = LogManager.GetLogger(loggerName);

So we take the idea a step further by implementing the following in the root namespace of our project:

/// <summary>
/// Extensions to help make logging awesome
/// </summary>
public static class LogExtensions
{
    /// <summary>
    /// Concurrent dictionary that ensures only one instance of a logger for a type.
    /// </summary>
    private static readonly Lazy<ConcurrentDictionary<string,ILog>> _dictionary = 
      new Lazy<ConcurrentDictionary<string, ILog>>(()=>new ConcurrentDictionary<string, ILog>());
 
    /// <summary>
    /// Gets the logger for <see cref="T"/>.
    /// </summary>
    /// <typeparam name="T"></typeparam>
    /// <param name="type">The type to get the logger for.</param>
    /// <returns>Instance of a logger for the object.</returns>
    public static ILog Log<T>(this T type)
    {
        string objectName = typeof(T).FullName;
        return Log(objectName);
   }
 
    /// <summary>
    /// Gets the logger for the specified object name.
    /// </summary>
    /// <param name="objectName">Either use the fully qualified object name
    /// or the short. If used with Log&lt;T&gt;() you must use the fully qualified object name"/></param>
    /// <returns>Instance of a logger for the object.</returns>
    public static ILog Log(this string objectName)
    {
        return _dictionary.Value.GetOrAdd(objectName, Infrastructure.Logging.Log.GetLoggerFor);
    }
}

You can see I’m using a concurrent dictionary which really speeds up the operation of going and getting a logger. I get the initial performance hit the first time I add the object, but from there it’s really fast. I do take a hit with a reflection call every time, but this is acceptable for me since I’ve been doing that with most logging engines for awhile.

Conclusion

If you are interested in the details, see this gist. Also take a look at the follow up with samples and more details here.

Extensions are awesome if used sparingly. Is this.Log perfect? Probably not, but it does have a lot of benefits in use. Feel free to take my work and make it better. Find a way to get me away from the reflection call every time. I’ve been using it for almost a year now and have improved it a little here and there.

If there is enough interest, I can create a NuGet package with this as well.