Return-Path: 
 <log4net-dev-return-3929-apmail-logging-log4net-dev-archive=logging.apache.org@logging.apache.org>
X-Original-To: apmail-logging-log4net-dev-archive@www.apache.org
Delivered-To: apmail-logging-log4net-dev-archive@www.apache.org
Received: from mail.apache.org (hermes.apache.org [140.211.11.3])
	by minotaur.apache.org (Postfix) with SMTP id CB5FCDA03
	for <apmail-logging-log4net-dev-archive@www.apache.org>;
 Sun,  4 Nov 2012 14:26:29 +0000 (UTC)
Received: (qmail 99030 invoked by uid 500); 4 Nov 2012 14:26:29 -0000
Delivered-To: apmail-logging-log4net-dev-archive@logging.apache.org
Received: (qmail 98772 invoked by uid 500); 4 Nov 2012 14:26:23 -0000
Mailing-List: contact log4net-dev-help@logging.apache.org; run by ezmlm
Precedence: bulk
list-help: <mailto:log4net-dev-help@logging.apache.org>
list-unsubscribe: <mailto:log4net-dev-unsubscribe@logging.apache.org>
List-Post: <mailto:log4net-dev@logging.apache.org>
Reply-To: "Log4NET Dev" <log4net-dev@logging.apache.org>
List-Id: <log4net-dev.logging.apache.org>
Delivered-To: mailing list log4net-dev@logging.apache.org
Received: (qmail 98735 invoked by uid 99); 4 Nov 2012 14:26:22 -0000
Received: from nike.apache.org (HELO nike.apache.org) (192.87.106.230)
    by apache.org (qpsmtpd/0.29) with ESMTP; Sun, 04 Nov 2012 14:26:22 +0000
X-ASF-Spam-Status: No, hits=-0.5 required=5.0
	tests=FREEMAIL_ENVFROM_END_DIGIT,RCVD_IN_DNSWL_LOW,SPF_PASS
X-Spam-Check-By: apache.org
Received-SPF: pass (nike.apache.org: domain of hendrikdev22@gmail.com
 designates 209.85.216.175 as permitted sender)
Received: from [209.85.216.175] (HELO mail-qc0-f175.google.com)
 (209.85.216.175)
    by apache.org (qpsmtpd/0.29) with ESMTP; Sun, 04 Nov 2012 14:26:14 +0000
Received: by mail-qc0-f175.google.com with SMTP id j3so3720542qcs.34
        for <multiple recipients>; Sun, 04 Nov 2012 06:25:53 -0800 (PST)
DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed;
        d=gmail.com; s=20120113;
        h=mime-version:date:message-id:subject:from:to:content-type;
        bh=wMYbxSfRfF8UKUBDSxJRLkayJP5LTKrYXQyHd+bpVds=;
        b=n1p77ZYe4lFgVuUAfUwQJK7LmbUnFd5zg1SYkKcyCjNdKYbz0uaH15X39UPfRjWPw5
         TDVKpILZMWcleNrCiof6DpsGuUzK7zvKXbjLDmYU2tLUxVBn99a7YUjd4B/xmUt7cy70
         NWWJHnBlO6trPjWL2RII/k4J5OLJuBFv7e20O7LN5IP9gToqAS1IK0zfdNRHbbK8pUjl
         wYytFJ6Z/gEJiDIorCE/2paIaUNGd+P4S38SR3QWFdv224M28n5W2WQvm3qOb0avyCIp
         Lvf7YuKjRs63rPLYTHFfpAkthSwxpu4ubA8KF/iMrbEGAQkw3wdw4RCvNYReuq7EdO/V
         yGsQ==
MIME-Version: 1.0
Received: by 10.224.27.83 with SMTP id h19mr10621787qac.70.1352039153276; Sun,
 04 Nov 2012 06:25:53 -0800 (PST)
Received: by 10.49.104.206 with HTTP; Sun, 4 Nov 2012 06:25:53 -0800 (PST)
Date: Sun, 4 Nov 2012 15:25:53 +0100
Message-ID: 
 <CAPm=oFBXgm5KTtBX=O-n3k1-yGv6E5d9yUP0HeCe8=mtMJKo2Q@mail.gmail.com>
Subject: AsynchronousBufferingForwardingAppender with flooding
 prevention/message throttling
From: Hendrik Dev <hendrikdev22@gmail.com>
To: log4net-user@logging.apache.org, log4net-dev@logging.apache.org
Content-Type: text/plain; charset=ISO-8859-1
X-Virus-Checked: Checked by ClamAV on apache.org

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