Category

Logging

When disaster strikes: the complete guide to Failover Appenders in Log4net

Log4Net is a cool, stable, fully featured, highly configurable, highly customizable and open source logging framework for .Net.

One of its powerful features is that it can be used to write logs to multiple targets, by using “Appenders”.
An Appender is a Log4Net component that handles log events; It receives a log event each time a new message is logged and it ‘handles’ the event. For example, a simple file appender will write the new log event to a local file.

Although there are a lot of Log4Net Appenders that are included in the Log4net framework, occasionally we won’t find one that fully satisfies our needs. During a project I was working on, I had to implement a failover mechanism for logging, where the app had to start logging to a remote service, and then failback to a local file system if that remote service wasn’t reachable anymore.

Fortunately, Log4Net allows us implement our own Custom Appenders.
The Appender had to start writing logs to a remote service, and fallback to a local disk file after the first failed attempt to send a log message to that service.

Implementing the Appender

To create a custom Appender we have to implement the IAppender interface. Although easy to implement, Log4Net makes it even simpler by providing the AppenderSkeleton abstract class, which implements IAppender and adds common functionalities on top of it.

public class FailoverAppender : AppenderSkeleton
{
    private AppenderSkeleton _primaryAppender;
    private AppenderSkeleton _failOverAppender;

    //Public setters are necessary for configuring
    //the appender using a config file
    public AppenderSkeleton PrimaryAppender 
    { 
        get { return _primaryAppender;} 
        set 
        { 
             _primaryAppender = value; 
             SetAppenderErrorHandler(value); 
        } 
    }

    public AppenderSkeleton FailOverAppender 
    { 
        get { return _failOverAppender; } 
        set 
        { 
            _failOverAppender = value; 
            SetAppenderErrorHandler(value); 
        } 
    }

    public IErrorHandler DefaultErrorHandler { get; set; }

    //Whether to use the failover Appender or not
    public bool LogToFailOverAppender { get; private set; }

    public FailoverAppender()
    {
        //The ErrorHandler property is defined in
        //AppenderSkeleton
        DefaultErrorHandler = ErrorHandler;
        ErrorHandler = new FailOverErrorHandler(this);
    }

    protected override void Append(LoggingEvent loggingEvent)
    {
        if (LogToFailOverAppender)
        {
            _failOverAppender?.DoAppend(loggingEvent);
        }
        else
        {
            try
            {
                _primaryAppender?.DoAppend(loggingEvent);
            }
            catch
            {
                ActivateFailOverMode();
                Append(loggingEvent);
            }
        }
    }

    private void SetAppenderErrorHandler(AppenderSkeleton appender)
        => appender.ErrorHandler = new PropogateErrorHandler();

    internal void ActivateFailOverMode()
    {
        ErrorHandler = DefaultErrorHandler;
        LogToFailOverAppender = true;
    }
}

The FailoverAppender above accepts two appenders; a primary appender and a failover appender.

By default it will propagate Log events only to the primary appender, but in case an exception is thrown from the primary appender during event logging , it will stop sending log events to that appender and instead it starts propagating log events only to the failover appender.

I’ve used AppenderSkeleton to reference both the primary and the failover appenders in order to utilize a functionality in the AppenderSkeleton class – in this case the ability to handle errors (a.k.a Exceptions) that were thrown during an appender attempt to log an event.
We can do so by assigning the ErrorHandler property defined in AppenderSkeleton an object.

I use the LogToFailOverAppender flag to determine whether we are in ‘normal’ mode or in ‘FailOver’ mode.

The actual logging logic exists in the overridden ‘Append’ method:

protected override void Append(LoggingEvent loggingEvent)
{
    if (LogToFailOverAppender)
    {
        _failOverAppender?.DoAppend(loggingEvent);
    }
    else
    {
        try
        {
            _primaryAppender?.DoAppend(loggingEvent);
        }
        catch
        {
            ActivateFailOverMode();
            Append(loggingEvent);
        }
    }
}

If the LogToFailOverAppender flag is active, it logs events using the failover appender, as it means an exception has been thrown already. Otherwise, it logs events using the primary appender, and it will activate the failover mode, if an exception is thrown during that time.

The following are the IErrorHandlers that I defined and used

/*
This is important. 
By default the AppenderSkeleton's ErrorHandler doesn't
propagate exceptions
*/
class PropogateErrorHandler : IErrorHandler
{
    public void Error(string message, Exception e, ErrorCode errorCode)
    {
        throw new AggregateException(message, e);
    }

    public void Error(string message, Exception e)
    {
        throw new AggregateException(message, e);
    }

    public void Error(string message)
    {
        throw new LogException($"Error logging an event: {message}");
    }
}
/*
This is just in case something bad happens. It signals 
the FailoverAppender to use the failback appender.
*/
class FailOverErrorHandler : IErrorHandler
{
    public FailOverAppender FailOverAppender { get; set; }
        
    public FailOverErrorHandler(FailOverAppender failOverAppender)
    {
        FailOverAppender = failOverAppender;
    }

    public void Error(string message, Exception e, ErrorCode errorCode)
        => FailOverAppender.ActivateFailOverMode();

    public void Error(string message, Exception e)
        => FailOverAppender.ActivateFailOverMode();

    public void Error(string message)
        => FailOverAppender.ActivateFailOverMode();
}

Testing the Appender

I’ve created a config file you can use to test the appender. These are the important bits:

<!--This custom appender handles failovers. If the first appender fails, it'll delegate the message to the back appender-->
<appender name="FailoverAppender" type="MoreAppenders.FailoverAppender">
    <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%date [%thread] %-5level %logger - %message%newline"/>
    </layout>

    <!--This is a custom test appender that will always throw an exception -->
    <!--The first and the default appender that will be used.-->
    <PrimaryAppender type="MoreAppenders.ExceptionThrowerAppender" >
        <ThrowExceptionForCount value="1" />
        <layout type="log4net.Layout.PatternLayout">
            <conversionPattern value="%date [%thread] %-5level %logger - %message%newline"/>
        </layout>        
    </PrimaryAppender>

    <!--This appender will be used only if the PrimaryAppender has failed-->
    <FailOverAppender type="log4net.Appender.RollingFileAppender">
        <file value="log.txt"/>
        <rollingStyle value="Size"/>
        <maxSizeRollBackups value="10"/>
        <maximumFileSize value="100mb"/>
        <appendToFile value="true"/>
        <staticLogFileName value="true"/>
        <layout type="log4net.Layout.PatternLayout">
            <conversionPattern value="%date [%thread] %-5level %logger - %message%newline"/>
        </layout>
    </FailOverAppender>
</appender>

In this post I’ll discuss the parts that are relevant to the appender. You can find the full config file here. The rest of the config file are a regular Log4Net configurations, which you can read more about here and here.

Log4Net has a feature that give us an ability to instantiate and assign values to public properties of appenders in the config file using XML. I’m using this feature to instantiate and assign values to both the PrimaryAppender and the FailOverAppender properties.

In this section I’m instantiating the PrimaryAppender:

<PrimaryAppender type="MoreAppenders.ExceptionThrowerAppender" >
    <ThrowExceptionForCount value="1" />
    <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%date [%thread] %-5level %logger - %message%newline"/>
    </layout>        
</PrimaryAppender>

The type attribute’s value is the fully qualified name of the appender’s class.
For our example, I’ve created the ExceptionThrowerAppender appender for testing purposes. It can be configured to throw exceptions once per a certain amount of log events.

In a similar manner, in the following XML I’ve instantiated and configured the FailOverApppender to be a regular RollingFileAppender

<FailOverAppender type="log4net.Appender.RollingFileAppender">
    <file value="log.txt"/>
    <rollingStyle value="Size"/>
    <maxSizeRollBackups value="10"/>
    <maximumFileSize value="100mb"/>
    <appendToFile value="true"/>
    <staticLogFileName value="true"/>
    <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%date [%thread] %-5level %logger - %message%newline"/>
    </layout>
</FailOverAppender>

I used the following code to create log events:

class Program
{
    static void Main(string[] args)
    {
        XmlConfigurator.Configure();

        var logger = LogManager.GetLogger(typeof(Program));

        for (var index = 0; index < int.MaxValue; ++index)
        {
            logger.Debug($"This is a debug message number {index}");
        }

        Console.ReadLine();
    }
}

I started the program in debug mode and placed a breakpoint inside the ‘Append’ method:

First logging message - goes to the primary appender

Notice how OzCode’s Predict the Future feature marks the if-statement with an X and with a red background, telling us that the condition is evaluated to false. That means an exception wasn’t thrown yet from the primary appender.

In order to make figuring out the loggingEvent message value easier, I’ve used OzCode’s Magic Glance feature to view the necessary information in every LoggingEvent object.

Selecting the properties to show

The result:

Magic Glance feature

By continuing the program, the primary appender will handle the logging event, and it will throw an exception

Exception is thrown.

After that exception is propagated by the ErrorHandler, it will be handled by the catch-clause, which activates the FailOverAppender mode (notice how the log event is sent to the FailOverAppender as well) which would send future logging events only to the FailOverAppender

FailOverAppender mode is active

This time the if-statement is marked by a green ‘V’ . This tell us that the condition is evaluated to be true and that it will execute the if-statement body (sends the logging-event to the failover appender).

You can view and download the code by visiting this GitHub Repository.

Summary

Log4Net is a well-known logging framework for .Net. The framework comes with a list of out-of-the-box Appenders that we can use in our programs.
Although these Appenders are usually sufficient for most of us, sometimes you’ll need Appenders that are more customized for your needs.

We saw how we can use Log4Net’s extensibility features to implement our own Log4Net custom Appenders. In this example, we have created a Fail-over mechanism for Appenders that we can use to change the active Appender when it is failing to append log messages.

Log4Net is highly extensible and it has many more extensibility features that I encourage you to explore.

Note: this post is published also at OzCode’s blog.