Log per class pattern.

Rookie Moves

Awhile ago, I had originally created a single logger for each service and shared it statically across the application.

public static class Log
{
  private readonly static Lazy<Log> instance = new Lazy<Log>(() => new Log(), true);
  public static Log Instance
  {
    get { return instance.Value; }
  }
}

It always had felt strange doing this since it violated encapsulation. I was referencing a static instance inside my objects without ensuring the existence of the log instance itself, while also making assumptions about the instance's state. Essentially reaching outside the class every time to the singleton, which is a global state instance in my case.

Best Practices

As I researched more on best practices with logging, logger per class appeared to be the best pattern since it offered the most fine grain control with respect to filtering and configuration.

When using logging in your class, you should separate the concern of how the log gets created from the use of the log. This can be achieved by having a factory accessor.

public class Log
{
  // Set your factory property to the actual log implementation you wish to use.
  public static Func<Type, Log> Factory { get; set; }

  // Instance based properties and methods.
}

You can also use the abstract factory pattern if you have to wrap your logging implementations.

public abstract class LogBase
{
  // Set your factory property to the actual log implementation you wish to use.
  public static Func<Type, LogBase> Factory { get; set; }

  // Abstract properties and methods.
}

Then just call the factory by passing in the class type it is for.

public class SomeObject
{
  private static readonly LogBase log = Log.Factory(typeof(SomeObject));
}

The Difference

It may not seem like much of a change but subtle differences are happening:

• Calling class can now communicate it's state to the log's creation.
• Log creation is no longer the responsibility, implicitly or otherwise, of the class.

In my case, this was very liberating since we had several log implementations in our large codebase. I no longer needed to worry about which log implementation was being used by messing with the singleton construction, and could leverage filtering when I need to isolate a single component or service that was causing trouble. Something that I couldn't do before.

More Reading & Resources

• C&C Inc: Logging Best Practices
• beefycode: Log4Net Recommended Practices pt 1: Your Code
• JayWay: A nice, basic log4net setup
• Stack Overflow: Why do loggers recommend using a logger per class?
• Stack Overflow: log4net: Configure to ignore messages from a specific class
• Rolf Engelhard: Logging Anti-Patterns, Part I

Creating XML based templates in log4net.

Motivation

I decided to use log4net for a recent project I had been working on. There is a concept of loggers and appenders. Loggers are composed of appenders and a log threshold. Appenders are consumers of logging information and provide specific implementations (eg. file, email, event log, database). You can configure the loggers and appenders either in the application configuration or at runtime.

Configuring logging in the application configuration provides the most flexibility. It is great being able to change settings on the fly, especially when it is running in a production environment and redeploying the build is out of the question. Although this approach comes at the expense of having a lot of information in your application configuration for the loggers and appenders. No big deal though if you just have to configure once.

Why Templates?

I had quite a bit of projects with a lot of redundant logging configuration information in each one's application configuration file. Much of the information had a standard form that we wanted uniform across our different projects too (eg. log file name conventions, event log setup, email format). Also, if we updated the logging appender configuration for a new standard, we would need to do it to every project's application configuration file. This is where templates came into play.

Writing the Code

To cut down the amount of configuration information needed to start a new project with logging and make the configuration more uniform where needed, we offloaded it into the code and left the rest in the application configuration file like so.

<log4net xsi:noNamespaceSchemaLocation="log4net.xsd" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">

<logger name="LoggerTemplate">
  <appender name="SmtpAppenderTemplate" type="log4net.Appender.SmtpAppender">
    <to value="peter@initech.com" />
    <from value="system@initech.com" />
    <smtpHost value="mail.initech.com" />
    <username value="peter" />
    <password value="abc123" />
  </appender>
</logger>

<root>
  <level value="INFO" />
</root>

</log4net>

We don't use the logger directly but rather as a template for our root logger. Now we just need to craft a method to consume the template and create the root appenders at runtime.

/// <summary>
/// Get appenders matching the logger template name and use them to populate the root appenders at runtime.
/// </summary>
/// <param name="loggerTemplateName">The logger template name found in the application configuration.</param>
public static void ConfigureRootFromTemplate(string loggerTemplateName)
{
  ILog logTemplate = LogManager.GetLogger(loggerTemplateName);

  if (logTemplate == null)
  {
    throw new ArgumentException(
      String.Format(
        "Logger template {0} not found in log4net configuration. Make sure there is an " +
        "logger in the log4net configuration with the name {0}.",
        loggerTemplateName),
        "loggerTemplateName");
  }

  IAppender[] appenderTemplates = logTemplate.Logger.Repository.GetAppenders();
  var smtpAppenderTemplate = appenderTemplates.FirstOrDefault(a => a is SmtpAppender) as SmtpAppender;

  if (smtpAppenderTemplate == null)
  {
    throw new ArgumentException(
      String.Format(
        "SmtpAppender template not found in log4net configuration. Make sure there is an " +
        "SmtpAppender in the log4net {0} logger.",
        loggerTemplateName),
        "loggerTemplateName");
  }

  // Can repeat the above pattern with other appenders as well.
  // Create appenders using the template information from above.
  
  AddAppendersToRootAndConfigure(
    new AppenderCollection 
 {
      // Put your created appenders here.
    });
}

private static void AddAppendersToRootAndConfigure(AppenderCollection appenders)
{
  // Get the log repository.
  var hierarchy = (Hierarchy)log4net.LogManager.GetRepository();
  // Get the root logger.
  Logger rootLogger = hierarchy.Root;
  foreach (var appender in appenders)
  {
    // Add all the appenders and activate.
    rootLogger.AddAppender(appender);
    ((AppenderSkeleton)appender).ActivateOptions();
  }
  // Flag root logger as configured with new appender information.
  rootLogger.Hierarchy.Configured = true;
}

Then just call the configuration method at the application's startup.

class Program
{
  /// 

  /// The main entry point for the application.
  /// 
  static void Main()
  {
    // Other startup configuration code.

    log4net.Config.XmlConfigurator.Configure(); // Load the application configuration information.
    Log.ConfigureRootFromTemplate("LoggerTemplate");

    // More startup configuration code.
  }

Considerations

I don't recommend using this approach in all cases. It definitely cuts down the amount of application configuration needed but at the cost of information hiding, since it has been moved to code. Also, it may not be obvious to an uninitiated developer what your application configuration is doing, especially since this template approach is not encoded into the structure of log4net's XML. Although, if you have many projects and need to effect changes to logging across them, this may be a good solution for you.

More Reading & Resources

• C&C Inc: Logging Best Practices
• beefycode: Log4Net Recommended Practices pt 1: Your Code
• JayWay: A nice, basic log4net setup
• Stack Overflow: Why do loggers recommend using a logger per class?
• Stack Overflow: log4net: Configure to ignore messages from a specific class
• Stack Overflow: Best way to dynamically set an appender file path

Using type converters for JSON.NET.

Motivation

I had these flyweights that added a lot of overhead to the serialization process. They weren't really needed in the serialized payload either. In fact, I could recreate the flyweight in memory from just a single property on the object.

public class FlyweightObject
{
   public string Key { get; private set; }
   public string AProperty { get; private set; }
   public string AnotherProperty { get; private set; }
   public string YetAnotherProperty { get; private set; }
   // ... Lots of properties.

   // Overridden GetHashCode and Equals methods to make equality by Key.
}

public class FlyweightObjectFactory
{
   public static FlyweightObjectFactory Instance { get; private set; }

   // Singleton initialization code.

   public FlyweightObject GetObject(string key)
   {
      // Get from dictionary, or create object and add to dictionary.
      // Return object from dictionary.
   }
}

Nothing out of the ordinary here. Although, these flyweights were also used as keys in a dictionary I was serializing. This was a problem too because only scalars can be used when serializing dictionaries with JSON.NET. It does mention that I can use a type converter though.

Serializing

Let focus on serializing this object to a scalar first. The JSON.NET serialization guide mentions that I can override the Object.ToString method. So let's do that.

public class FlyweightObject
{
   public string Key { get; private set; }
   public string AProperty { get; private set; }
   public string AnotherProperty { get; private set; }
   public string YetAnotherProperty { get; private set; }
   // ... Lots of properties.

   // Overridden GetHashCode and Equals methods to make equality by Key.

   public override string ToString()
   {
      return this.Key;
   }
}

I'm done right? Who needs type converters? Well this doesn't help us when I need to deserialize. This is where type converters come into play.

Implementing a Type Converter

First we have to provide the concrete implementation of our type converter class for the flyweight.

internal class FlyweightObjectConverter
   : TypeConverter
{      
   /// <summary>
   /// Returns whether this converter can convert an object of the given type to the type of this converter, using the specified context.
   /// </summary>
   /// <returns>
   /// true if this converter can perform the conversion; otherwise, false.
   /// </returns>
   /// <param name="context">An  that provides a format context. </param>
   /// <param name="sourceType">A <see cref="T:System.Type"/> that represents the type you want to convert from. </param>
   public override bool CanConvertFrom(ITypeDescriptorContext context, Type sourceType)
   {
      return sourceType == typeof(string) || base.CanConvertFrom(context, sourceType);
   }

   /// <summary>
   /// Converts the given object to the type of this converter, using the specified context and culture information.
   /// </summary>
   /// <returns>
   /// An <see cref="T:System.Object"/> that represents the converted value.
   /// </returns>
   /// <param name="context">An <see cref="T:System.ComponentModel.ITypeDescriptorContext"/> that provides a format context. </param>
   /// <param name="culture">The <see cref="T:System.Globalization.CultureInfo"/> to use as the current culture. </param>
   /// <param name="value">The <see cref="T:System.Object"/> to convert. </param><exception cref="T:System.NotSupportedException">The conversion cannot be performed. </exception>
   public override object ConvertFrom(ITypeDescriptorContext context, CultureInfo culture, object value)
   {
      return FlyweightObjectFactory.Instance.GetObject((string)value);
   }
}

Then attribute the convertible class with the implementation.

[TypeConverter(typeof(FlyweightObjectConverter))]
public class FlyweightObject
{
   public string Key { get; private set; }
   public string AProperty { get; private set; }
   public string AnotherProperty { get; private set; }
   public string YetAnotherProperty { get; private set; }
   // ... Lots of properties.

   // Overridden GetHashCode and Equals methods to make equality by Key.
}

Good to go. Now I can deserialize the flyweights. The JSON.NET secret sauce can be found in the static method Newtonsoft.Json.Utilities.ConvertUtils.TryConvertInternal. This method is used by the internal reader class for its own deserialization method and consequently for the final Newtonsoft.Json.JsonSerializer class, which is the lynchpin for all the serialization helper methods in the JSON.NET ecosystem.

Considerations

Instead of overriding the Object.ToString method, I could implement the TypeConverter.CanConvertTo and TypeConverter.ConvertTo methods. It is really up to you. In my case, I already had the Object.ToString method overridden since the key property uniquely identifies the object without having to create an implicitly structured string (ie. comma delimited properties as a single string; "Prop1|Prop2|Prop3").

If you only need a type conversion for JSON, you can also use JSON.NET's own custom type converters. Although this doesn't work in the case of dictionary keys.

Lastly, if you have a complex type as your dictionary key, you may want to consider just serializing it as a collection and then deserializing it using a JSON.NET custom converter.

More Reading & Resources

• MSDN: Type Conversion in the .NET Framework
• MSDN: How to: Implement a Type Converter
• JSON.NET: Add support for IReadOnlyList and IReadOnlyDictionary - Provides JsonConverter implementations for read only collections.