logging-log4net-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Hendrik Dev <hendrikde...@gmail.com>
Subject AsynchronousBufferingForwardingAppender with flooding prevention/message throttling
Date Sun, 04 Nov 2012 14:25:53 GMT
Hi everybody,

i just wrote a first sketch for an Asynchronous Buffering Forwarding
Appender with flooding prevention.
I need three things in my project:
1) async logging (so that the ILog.Debug/Info/Error() call will not
block) if, for example the underlying ADO Appender does currently slow
inserts into database because of database locks
2) Flooding detection/prevention: If a log4net enabled application
gets wild and issue, for example, 10000 logging events per minute i
want to suppress further messages, issue a message that now messages
will be discarded, and if the flooding is over the appender should
automatically resume with normal logging behavior (sometimes this is
also called message throttling)
3) All the capabilities of the BufferingForwardingAppender

The appender is always async, flooding prevention can be configured
with two parameters
  <maxEventsPeriod value="100"/> <!-- set to 0 to disable flood protection -->
  <periodInSeconds value="5"/>

Note regarding async behavior: If one of the attached appenders will
block for a while this cause that logmessage delivery to the other
appenders will also be delayed - but although its async from the
perspective of the log4net enabled application which is using this
appender.


So here is the code i want to share with you, asking for
comments/feedback/review.
You also can use the code (without any warranty etc) for your own projects:
(build upon .NET 4 and log4net 1.2.11)

using System;
using System.Diagnostics;
using System.Threading.Tasks;
using log4net.Appender;
using log4net.Core;
using log4net.Util;

namespace Dev.Log4net
{

    public class AsynchronousBufferingForwardingAppender :
BufferingForwardingAppender
    {

        private readonly Object _lock = new Object();
        private Stopwatch _watch = new Stopwatch();
        private int _countLastPeriod = 0;
        private int _currentCount = 0;
        private bool _isFlodding = false;
        private bool _floodMessageSend = false;

        private int c_MaxEventsPeriod = 0;
        private int c_PeriodInSeconds = 5;

        public AsynchronousBufferingForwardingAppender()
        {

        }


        public int MaxEventsPeriod
        {

            get { return this.c_MaxEventsPeriod; }

            set { this.c_MaxEventsPeriod = value; }

        }

        public int PeriodInSeconds
        {

            get { return this.c_PeriodInSeconds; }

            set { this.c_PeriodInSeconds = value; }

        }

        public override void ActivateOptions()
        {

            if (c_MaxEventsPeriod > 0)
            {

                _countLastPeriod = 0;
                _currentCount = 0;
                _isFlodding = false;
                _watch.Restart();


            }

            base.ActivateOptions();


        }


        override protected void SendBuffer(LoggingEvent[] events)
        {


            if (events == null || events.Length == 0)
                return;


            if (c_MaxEventsPeriod > 0)
            { //flodding detection enabled


                double elapsed = _watch.Elapsed.TotalSeconds;

                if (elapsed > 0)
                {

                    if (elapsed >= c_PeriodInSeconds)
                    { //period end, check flodding



                        if (_currentCount > c_MaxEventsPeriod)
                        {
                            //flodding
                            _isFlodding = true;


                        }
                        else
                        {


                            if (_isFlodding)
                            {
                                LogLog.Warn(GetType(), "Flooding stop
detected, resume to normal logging operation");
                            }

                            _isFlodding = false;
                            _floodMessageSend = false;
                        }


                        _countLastPeriod = _currentCount;
                        _currentCount = 0;
                        _watch.Restart();

                    }
                    else
                    {//period not ended, just count
                        _currentCount += events.Length;
                    }


                    if (_isFlodding)
                    {

                        //emmit warning message
                        if (!_floodMessageSend)
                        {
                            string floddingMessage = "Log Flodding
detected! Messages gets discarded! Received " + _countLastPeriod + "
messages within " + c_PeriodInSeconds + " secs.";
                            LogLog.Error(GetType(), floddingMessage);

                            LoggingEvent floddingErrorLoggingEvent =
new LoggingEvent(GetType(), events[0].Repository,
"Dev.Log4net.AsynchronousBufferingForwardingAppender.FloodingDetection",
Level.Fatal, floddingMessage, null);//null = Message, Exception

                            base.SendBuffer(new LoggingEvent[] {
floddingErrorLoggingEvent });

                            _floodMessageSend = true;

                        }
                        return;

                    }//endif isflodding
                }
            }

            Task logTask = Task.Factory.StartNew(() =>
             {
                 _SendBuffer(events);
             });

        }

        protected void _SendBuffer(LoggingEvent[] events)
        {
            lock (_lock)
            {
                base.SendBuffer(events);
            }
        }



    }
}




  <appender name="AsynchronousBufferingForwardingAppender"
type="Dev.Log4net.AsynchronousBufferingForwardingAppender,
Dev.AsynchronousBufferingForwardingAppender">
    <bufferSize value="1" />
    <lossy value="false" />
    <maxEventsPeriod value="100"/>
    <periodInSeconds value="5"/>
    <evaluator type="log4net.Core.LevelEvaluator">
      <threshold value="ALL" />
    </evaluator>

    <appender-ref ref="UdpAppender" />
    <appender-ref ref="TraceAppender" />
  </appender>


PS: Sorry for cross posting, but i think its relevant for either
developers and users

-H. Dev

Mime
View raw message