Log4net in Asp.Net redux: Implement IFixingRequired on your Active Property Values

A while back I noted that the built-in contexts in log4net were broken in the face of ASP.Net's thread agility (and pointed this out to the log4net community).

The workaround I suggested, which was also suggested on the log4net developers list, was to leverage log4net's support for deferred evaluation of logging properties. These are known as Active Property Values, but that's just a fancy/short way of saying 'any object you like, who's ToString() method results in the value that you actually want logged'. This was a pretty neat workaround, eg:

      log4net.GlobalContext.Properties["requestUrl"] = new HttpContextRequestUrlProvider();

    private class HttpContextRequestUrlProvider
    {
        public override string ToString()
        {
            HttpContext context = HttpContext.Current;
            if (context == null) return null;
            return context.Request.RawUrl;
        }
    }

However in one of my logging databases, I recently noticed logging entries attributed to me that had clearly come from someone else, which made me worry for a few hours whether this pattern was broken, or broken when using an appender that buffers (like the AdoNetAppender).

Digging through the source code showed that BufferingAppenderSkeleton does indeed attempt to 'fix' logging entries when they go into the buffer, to guard against exactly these kind of multithreading logging mishaps:

 // Because we are caching the LoggingEvent beyond the
// lifetime of the Append() method we must fix any
// volatile data in the event.
loggingEvent.Fix = this.Fix;

This causes all kinds of intrinsic log4net values (like thread ID, UserName), and the message itself to be 'fixed': i.e. fully evaluated (and rendered via the layout) now, rather than later. Otherwise all the logging events in the buffer would end up being written out with the values in-play at the time the appender flushed (ie potentially another thread/users's context).

This fixing also 'fixes' properties from the log4net contexts (ThreadContext, LogicalThreadContext and GlobalContext) if they implement IFixingRequired. And that's what I missed - one obscure interface:

 // Fix any IFixingRequired objects
IFixingRequired fixingRequired = val as IFixingRequired;
if (fixingRequired != null)
{
 val = fixingRequired.GetFixedObject();
}

But I've missed that for the last couple of years. So… actually I'd rather not think about the implications of that. Meanwhile, if anyone who does any log4net dev would actually like to update the Active Property Value doco, that'd be good, thanks.

Better still, 18 months later, can we have our Adaptive Context now please?