Capturing context data using log4net

It was a little bit of trial and error to get this working, so I thought I would post the code.

The problem we were trying to solve was this: we wanted to track which batch job was logging the given message. In our situation, each job is a separate class. Each job had its own unique ID number. So, we needed to use some context to determine which job logged the message.

Here is the solution we came up with. First we created a custom attribute to hold the metadata we needed:

[AttributeUsage(AttributeTargets.Class)]
public class BatchJobAttribute : Attribute
{
  public int ProcessorId { get; private set; }
  public BatchJobAttribute(int processorId)
  {
    ProcessorId = processorId;
  }
}

For each processor class, we add this attribute:

[Processor(123)]
class SampleProcessor
{
 ...
}

Note: It would be very nice to use an enum instead of magic numbers. This would be a fairly simple change.

Then we created a context class. The ToString() method on this class is called each time a message is logged. In this method, the code walks up the stack trace looking for a class that has the custom attribute. Please note, this is using reflection and is called every time a message is logged, so be careful in performance critical situations. This particular situation was for off-line processing, so performance was not as critical.

class ProcessorContext
{
  private const string UnknownValue = "-1";

  public override string ToString()
  {
    StackTrace stackTrace = new StackTrace(false);
    foreach (var frame in stackTrace.GetFrames())
    {
      var type = frame.GetMethod().ReflectedType;
      var attributes = type.GetCustomAttributes(typeof(BatchJobAttribute), false);
      if (attributes.Length > 0)
      {
         var procAtt = (ProcessorAttribute)attributes[0];
         return procAtt.ProcessorId.ToString();
      }
    }
    return UnknownValue;
  }
}

Finally, when configuring log4net at application start, we add the context class as a thread context property. This is what causes log4net to call the ToString() method on each call.

log4net.Config.XmlConfigurator.Configure();
log4net.ThreadContext.Properties["ProcessorContext"] = new  ProcessorContext();

In the configuration of the adapter, we add a pattern layout to display this property:

<layout type="log4net.Layout.PatternLayout">
  <param name="ConversionPattern" value="%d{yyyy-MM-dd HH:mm:ss} %-5p %c{1} %property{ProcessorContext} %m%n" />
</layout>

And there you go. Hopefully this will be helpful to someone else. Please keep in mind there are other solutions that may work better in your specific scenario. One good option would be the context stacks described in this article. Another option would be to simply use the class name which is already part of the metadata captured by log4net.

Good luck!