Use case for custom Log4Net MemoryAppender

When developing an enterprise grade desktop or web application, there is always a need to be able to view application logs including activities in one of the views. These activities could include user actions, system warnings or errors, triggered from the client or server.

Server errors or warnings could be polled for, through a WCF or RESTFul API, and stored in an inmemory collection that is bound to some data grid in a view. Log messages generated on the client, either through exceptions, caught and logged somewhere or via actions that require auditing such as changing sensitive system parameters, can also share the same inmemory collection with data retreived from the server.

Log4Net is a popular .NET library used for application logging. The general pattern in using Log4Net is as follows:

1. Get an ILog instance.
2. Call any of the API on the ILog instance to log your message.

Log4Net log messages eventually are persisted to entitities called Appenders. There are FileAppenders, ConsoleAppenders, InMemoryAppenders and many more. An Appender is the destination of a log message.

We can leverage an MemoryAppender to catch application error or warning messages into a collection which can then be bound to a view. The code is as follows:

 public class NotifyingInMemoryLog4NetAppender : MemoryAppender
    {
        private readonly static BindableCollection<LogMessage> LogData = new BindableCollection<LogMessage>();
        private readonly static List<LoggingEvent> CachedEvents = new List<LoggingEvent>();
        private readonly Timer _flushTimer;
        private readonly object _lock  = new object();
        public NotifyingInMemoryLog4NetAppender()
        {
            _flushTimer = new Timer((arg) =>
            {
                lock (_lock)
                {
                    if (CachedEvents.Count > 0)
                    {
                        LogData.AddRange(CachedEvents.Select(Convert));
                        CachedEvents.Clear();
                        
                    }    
                }
            }, null, 5000, 3000);
        }

        public IListExtended Logs
        {
            get { return LogData; }
        }

        private DateTime _lastEventTime = DateTime.Now;
        private readonly TimeSpan _threshold = new TimeSpan(0, 0, 0, 0, 500);

        protected override void Append(LoggingEvent loggingEvent)
        {
            var now = DateTime.Now;
            
            // if we are getting flooded, cache the events and process them later.
            if (now - _lastEventTime < _threshold)
            {
                lock (_lock)
                {
                    CachedEvents.Add(loggingEvent);
                }
            }
            else
            {
                LogData.Add(Convert(loggingEvent));    
            }

            _lastEventTime = DateTime.Now;
        }

        private Severity ConvertFrom(Level level)
        {
            if (level == Level.Error)
                return Severity.Error;
            if (level == Level.Warn)
                return Severity.Warning;
            if (level == Level.Info)
                return Severity.Information;

            return Severity.Trace;
        }

        private LogMessage Convert(LoggingEvent loggingEvent)
        {
            return new LogMessage
            {
                Timestamp = loggingEvent.TimeStamp,
                Message = loggingEvent.RenderedMessage,
                Severity = ConvertFrom(loggingEvent.Level)
            };
            
        }
    }

This custom appender is used as follows:

<log4net debug="true">
    <appender name="InMemory" type="Infrastructure.Dictionary.Facades.NotifyingInMemoryLog4NetAppender, Pidac.Infrastructure.Dictionary ">
       <conversionPattern value="%5level [%thread] (%file:%line) - %message%newline" />
    </appender>
    <appender name="Console" type="log4net.Appender.ConsoleAppender">
      <layout type="log4net.Layout.PatternLayout">
        <!-- Pattern to output the caller's file name and line number -->
        <conversionPattern value="%5level [%thread] (%file:%line) - %message%newline" />
      </layout>
    </appender>
    <appender name="RollingFile" type="log4net.Appender.RollingFileAppender">
      <file value="dosewin.log" />
      <appendToFile value="true" />
      <rollingStyle value="Size" />
      <maxSizeRollBackups value="10" />
      <maximumFileSize value="10MB" />
      <staticLogFileName value="true" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%date [%thread] %-5level %logger [%property{NDC}] - %message%newline" />
      </layout>
    </appender>
    <root>
      <!--ALL,DEBUG,INFO,WARN,ERROR,FATAL-->
      <level value="DEBUG" />
      <appender-ref ref="Console" />
      <appender-ref ref="RollingFile" />
      <appender-ref ref="InMemory" />
    </root>
  </log4net>

When you call any of the ILog API’s the Append(LoggingEvent loggingEvent) method in our custom implementation is called. We add this message to a local queue and then subsequently pass this on to the Static LogData structure which could be bound to a view. Note that since we do not really care about preserving the order in which the messages appear, since most datagrids today provide an ability for data to be sorted prior to presentation, a simple List will suffice for our queue.

And that is it.

Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s