Producing readable log4net output

As a follow up to log4net configuration made easy, a common question people ask is what tool to use for reading log4net output.

Unless you're using an AdoNetAppender, there aren't many popular choices for combing through log4net file output.  This really should be as simple as setting fixed width columns or column delimiters into our FileAppender's layout pattern, but unfortunately it isn't that simple: log4net's base appender (AppenderSkeleton) outputs Exceptions over multiple lines making it unsuitable for delimited output.

Here are a few options for producing friendly log4net output that can be easily imported or understood by common tools, such as Excel, LogParser, etc.

Format Exceptions using an IObjectRenderer

log4net is just so darn extensible!  Object renderers are one of those great hidden gems in log4net that allow you to log an object and leave the formatting to log4net configuration.  Any object reference pushed through log4net (including derived classes) will use the supplied object render to customize the output. 

public class ExceptionRenderer : IObjectRenderer
{
        public void RenderObject(RendererMap rendererMap, object obj, TextWriter writer)
        {
            Exception ex = obj as Exception;
            if (ex != null)
            {
                // format exception to taste
                writer.Write(ex.StackTrace);
            }
        }
}

The object renderer appears in your config thusly:

<log4net>
    <!-- appenders -->
    <appender ... />
    <root ... />
    <renderer 
	renderingClass="MyNamespace.ExceptionRenderer,MyAssembly"
	renderedClass= "System.Exception" />
</log4net>

This option can be combined with the other approaches defined below, or on it's own.

try
{
    // perform work
}
catch(Exception ex)
{
    // format using IObjectRenderer
    log.Warn(ex);
}

By logging just the Exception object, the IObjectRenderer will do its formatting. Coincidentally, because the exception is the message it isn't subject to the same delimited friendly problems, though this may not be a suitable solution for you if it means having to rewrite all of your exception blocks.

Redirect Exceptions using a Custom Appender

As previously mentioned, the culprit behind our messy exceptions is the AppenderSkeleton.  Technically, it's how the RollingFileAppender leverages the AppenderSkeleton RenderLoggingEvent method: it appends content to the log based on our LayoutPattern, and then dumps the Exception stack trace as its own line.  We can correct this behaviour by creating a new appender that handles our exception details before it gets rendered into the logger as an exception.

public class CustomRollingFileAppender : RollingFileAppender
{
    public override Append(LoggingEvent loggingEvent)
    {
        string exceptionString = loggingEvent.GetExceptionString();
            
        if (String.IsNullOrEmpty(exceptionString))
        {
            // business as usual
            base.Append(loggingEvent);
        }
        else
        {
            // move our formatted exception details into the message
            LoggingEventData data = loggingEvent.GetLoggingEventData(FixFlags.All);
            data.ExceptionString = null;
            data.Message = String.Format("{0}:{1}", data.Message, exceptionString);

            LoggingEvent newLoggingEvent = new LoggingEvent(data);

            base.Append(newLoggingEvent);
        }
    }
}

The key advantage to this approach is that you won't have to change your existing logging code.

Move Exception details to a Custom Property

Though the previous approach solves our problem, we're coupling our message to our exception.  There may be some cases where you would want to separate exception details, such as importing into a database where the message is limited and the stack trace is a blob.  To accommodate, we can write our exceptionString to a custom property, which can be further customized using our layout configuration.

This code example shows the exception being logged to a custom property:

   LoggingEventData data = loggingEvent.GetLoggingEventData(FixFlags.All);
   data.ExceptionString = null;
   data.Properties["exception"] = exceptionString;

And our configuration:

<appender name="RollingLogFileAppender" type="log4net.Appender.CustomAppender">
  <file value="..\logs\log.txt" />
  <layout type="log4net.Layout.PatternLayout">
    <conversionPattern value="%date %-5level [%t] - %message %property{exception} %newline" />
  </layout>
</appender>

Putting it all together

The final piece is defining our layout of file so that it can be consumed by Excel or Log Parser. In the example below, I've customized my Header and Conversion pattern to use a pipe-delimited format, perfect for importing into Excel or a database table.

<log4net>
    <appender type="Example.CustomAppender,Example" name="CustomAppender">
        <!-- derived from Rolling File Appender -->
        <file value="..\logs\log.txt" />
        <appendtofile value="false" />
              <layout type="log4net.Layout.PatternLayout">
                <header value="Date|Level|Thread|Logger|Message|Exception&#13;&#10;" />
                <conversionpattern value="%date|%-5level|%t|%logger|%message|%property{exception}%newline" />
              </layout>
    </appender>
    <renderer renderedclass="System.Exception" renderingclass="Example.ExceptionRenderer,Example" />
    </appender>
        <root>
        <level value="DEBUG" />
        <appender-ref ref="CustomAppender" />
    </root>
</log4net>

Here's a Log Parser query that uses pipe-delimited format (we use a Tab delimited format with a pipe as the delimiter):

logparser.exe -i:TSV -iSeparator:"|" "select Level, count(*) as Count from log.txt group by Level"