You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4net-dev@logging.apache.org by "Michael Goldfinger (JIRA)" <ji...@apache.org> on 2013/11/22 15:56:35 UTC

[jira] [Commented] (LOG4NET-407) AsyncAppender - better Implementation

    [ https://issues.apache.org/jira/browse/LOG4NET-407?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13830024#comment-13830024 ] 

Michael Goldfinger commented on LOG4NET-407:
--------------------------------------------

This is my implementation
{code:java}
namespace Goldfinger.Appender
{
	using System;
	using System.Threading.Tasks;

	using log4net.Appender;
	using log4net.Core;
	using log4net.Util;

	/// <summary>
	///     Appender that forwards LoggingEvents asynchronously
	/// </summary>
	/// <remarks>
	///     This appender forwards LoggingEvents to a list of attached appenders.
	///     The events are forwarded asynchronously using the PTL.
	///     This allows the calling thread to be released quickly. This
	///     implementation does guarantee the ordering of events deliverted to
	///     the attached appenders, however it does not guarantee that all events
	///     got logged if the application exits and there are events in the queue.
	///     To force all events to be logged the last command of an application
	///     before exit should be an LogManager.Shutdown() call.
	/// </remarks>
	public sealed class AsyncAppender : IBulkAppender, IOptionHandler, IAppenderAttachable
	{
		#region Static Fields

		/// <summary>
		/// The declaring type.
		/// </summary>
		private static readonly Type DeclaringType = typeof(AsyncAppender);

		#endregion

		#region Fields

		private AppenderAttachedImpl _appenderAttachedImpl;

		private Task _asyncLogTask;

		private bool _closed;

		private IErrorHandler _errorHandler;

		private FixFlags _fixFlags = FixFlags.All;

		private string _name;

		private bool _recursiveGuard;

		#endregion

		#region Constructors and Destructors

		/// <summary>
		///     Initializes a new instance of the <see cref="AsyncAppender"/> class.
		/// </summary>
		public AsyncAppender()
		{
			_errorHandler = new OnlyOnceErrorHandler(GetType().Name);

			// Initialise the task for the async operation.
			// There is no need to do anything now, just make sure the Task got scheduled.
			_asyncLogTask = new Task(() => { });
			_asyncLogTask.Start();
		}

		/// <summary>
		/// Finalizes an instance of the <see cref="AsyncAppender"/> class. 
		/// </summary>
		~AsyncAppender()
		{
			// An appender might be closed then garbage collected. 
			// There is no point in closing twice.
			if (!_closed)
			{
				LogLog.Debug(DeclaringType, "Finalizing appender named [" + _name + "].");
				Close();
			}
		}

		#endregion

		#region Public Properties

		/// <summary>
		///     Gets the known appenders.
		/// </summary>
		public AppenderCollection Appenders
		{
			get
			{
				lock (this)
				{
					return _appenderAttachedImpl == null ? AppenderCollection.EmptyCollection : _appenderAttachedImpl.Appenders;
				}
			}
		}

		/// <summary>
		///     Gets or sets the <see cref="IErrorHandler" /> for this appender.
		/// </summary>
		/// <value>The <see cref="IErrorHandler" /> of the appender</value>
		/// <remarks>
		///     <para>
		///         The <see cref="AppenderSkeleton" /> provides a default
		///         implementation for the <see cref="ErrorHandler" /> property.
		///     </para>
		/// </remarks>
		public IErrorHandler ErrorHandler
		{
			get
			{
				return _errorHandler;
			}

			set
			{
				lock (this)
				{
					if (value == null)
					{
						// We do not throw exception here since the cause is probably a
						// bad config file.
						LogLog.Warn(DeclaringType, "You have tried to set a null error-handler.");
					}
					else
					{
						_errorHandler = value;
					}
				}
			}
		}

		/// <summary>
		///     Gets or sets the fix.
		/// </summary>
		public FixFlags Fix
		{
			get
			{
				return _fixFlags;
			}

			set
			{
				_fixFlags = value;
			}
		}

		/// <summary>
		///     Gets or sets the name.
		/// </summary>
		public string Name
		{
			get
			{
				return _name;
			}

			set
			{
				_name = value;
			}
		}

		#endregion

		#region Public Methods and Operators

		/// <summary>
		///     The activate options.
		/// </summary>
		public void ActivateOptions()
		{
		}

		/// <summary>
		/// Add a new appender.
		/// </summary>
		/// <param name="newAppender">
		/// The new appender.
		/// </param>
		/// <exception cref="ArgumentNullException">
		/// <paramref name="newAppender"/> is null.
		/// </exception>
		public void AddAppender(IAppender newAppender)
		{
			if (newAppender == null)
			{
				throw new ArgumentNullException("newAppender");
			}

			lock (this)
			{
				if (_appenderAttachedImpl == null)
				{
					_appenderAttachedImpl = new AppenderAttachedImpl();
				}

				_appenderAttachedImpl.AddAppender(newAppender);
			}
		}

		/// <summary>
		///     Close the appender.
		/// </summary>
		public void Close()
		{
			// Remove all the attached appenders
			lock (this)
			{
				if (!_closed)
				{
					// Wait till all queued logevents are written to the connected appenders.
					_asyncLogTask.Wait();
					if (_appenderAttachedImpl != null)
					{
						_appenderAttachedImpl.RemoveAllAppenders();
					}

					_closed = true;
				}
			}
		}

		/// <summary>
		/// Performs threshold checks and invokes filters before
		///     delegating actual logging to the subclasses specific
		///     Append method.
		/// </summary>
		/// <param name="loggingEvent">
		/// The event to event.
		/// </param>
		public void DoAppend(LoggingEvent loggingEvent)
		{
			lock (this)
			{
				if (_closed)
				{
					ErrorHandler.Error("Attempted to append to closed appender named [" + _name + "].");
					return;
				}

				// prevent re-entry
				if (_recursiveGuard)
				{
					return;
				}

				try
				{
					_recursiveGuard = true;

					// Makes sure all properties are cached. To speed up the logging the flags could be set to some other value 
					// than the default FixFlags.All. However all Threadbased values such as user properties written to
					// ThreadContext.Properties[string] are lost, if not fixed.
					loggingEvent.Fix = _fixFlags;
					// This is where the magic happens. ContinueWith starts the AsyncAppend Method
					// as soon as the parent tasks has finished. Finished tasks are cleaned up by the GC.
					// This is because AttachToParent is not used. In .Net 4.5 this can be enforced with
					// TaskContinuationOptions.DenyChildAttach. Using ContinueWith also enures that the
					// logging Events maintain there order.
					_asyncLogTask = _asyncLogTask.ContinueWith(t => AsyncAppend(loggingEvent));
				}
				catch (Exception ex)
				{
					ErrorHandler.Error("Failed in DoAppend", ex);
				}
				finally
				{
					_recursiveGuard = false;
				}
			}
		}

		/// <summary>
		/// Performs threshold checks and invokes filters before
		///     delegating actual logging to the subclasses specific
		///     Append method.
		/// </summary>
		/// <param name="loggingEvents">
		/// The events to log.
		/// </param>
		public void DoAppend(LoggingEvent[] loggingEvents)
		{
			lock (this)
			{
				if (_closed)
				{
					ErrorHandler.Error("Attempted to append to closed appender named [" + _name + "].");
					return;
				}

				// prevent re-entry
				if (_recursiveGuard)
				{
					return;
				}

				try
				{
					_recursiveGuard = true;
					// Makes sure all properties are cached. To speed up the logging the flags could be set to some other value 
					// than the default FixFlags.All. However all Threadbased values such as user properties written to
					// ThreadContext.Properties[string] are lost, if not fixed.
					Parallel.ForEach(loggingEvents, item => item.Fix = _fixFlags);
					// This is where the magic happens. ContinueWith starts the AsyncAppend Method
					// as soon as the parent tasks has finished. Finished tasks are cleaned up by the GC.
					// This is because AttachToParent is not used. In .Net 4.5 this can be enforced with
					// TaskContinuationOptions.DenyChildAttach. Using ContinueWith also enures that the
					// logging Events maintain there order.
					_asyncLogTask = _asyncLogTask.ContinueWith(t => AsyncAppend(loggingEvents));
				}
				catch (Exception ex)
				{
					ErrorHandler.Error("Failed in Bulk DoAppend", ex);
				}
				finally
				{
					_recursiveGuard = false;
				}
			}
		}

		/// <summary>
		/// Get the appender by name.
		/// </summary>
		/// <param name="name">
		/// The name of the appender.
		/// </param>
		/// <returns>
		/// The <see cref="IAppender"/> reference.
		/// </returns>
		public IAppender GetAppender(string name)
		{
			lock (this)
			{
				if (_appenderAttachedImpl == null || name == null)
				{
					return null;
				}

				return _appenderAttachedImpl.GetAppender(name);
			}
		}

		/// <summary>
		///     Remove all appenders.
		/// </summary>
		public void RemoveAllAppenders()
		{
			lock (this)
			{
				// Wait till all queued logevents are written to the connected appenders.
				_asyncLogTask.Wait();
				if (_appenderAttachedImpl != null)
				{
					_appenderAttachedImpl.RemoveAllAppenders();
					_appenderAttachedImpl = null;
				}
			}
		}

		/// <summary>
		/// Remove appender method.
		/// </summary>
		/// <param name="appender">
		/// The appender to remove.
		/// </param>
		/// <returns>
		/// The <see cref="IAppender"/> reference.
		/// </returns>
		public IAppender RemoveAppender(IAppender appender)
		{
			lock (this)
			{
				// Wait till all queued logevents are written to the connected appenders.
				_asyncLogTask.Wait();
				if (appender != null && _appenderAttachedImpl != null)
				{
					return _appenderAttachedImpl.RemoveAppender(appender);
				}
			}

			return null;
		}

		/// <summary>
		/// Remove appender by name.
		/// </summary>
		/// <param name="name">
		/// The name of the appender.
		/// </param>
		/// <returns>
		/// The <see cref="IAppender"/> reference.
		/// </returns>
		public IAppender RemoveAppender(string name)
		{
			lock (this)
			{
				// Wait till all queued logevents are written to the connected appenders.
				_asyncLogTask.Wait();
				if (name != null && _appenderAttachedImpl != null)
				{
					return _appenderAttachedImpl.RemoveAppender(name);
				}
			}

			return null;
		}

		#endregion

		#region Methods

		/// <summary>
		/// The async append.
		/// </summary>
		/// <param name="loggingEvent">
		/// The logging event.
		/// </param>
		private void AsyncAppend(LoggingEvent loggingEvent)
		{
			if (_appenderAttachedImpl != null)
			{
				_appenderAttachedImpl.AppendLoopOnAppenders(loggingEvent);
			}
		}

		/// <summary>
		/// The async append.
		/// </summary>
		/// <param name="loggingEvents">
		/// The logging events.
		/// </param>
		private void AsyncAppend(LoggingEvent[] loggingEvents)
		{
			if (_appenderAttachedImpl != null)
			{
				_appenderAttachedImpl.AppendLoopOnAppenders(loggingEvents);
			}
		}

		#endregion
	}
}
{code}

> AsyncAppender - better Implementation
> -------------------------------------
>
>                 Key: LOG4NET-407
>                 URL: https://issues.apache.org/jira/browse/LOG4NET-407
>             Project: Log4net
>          Issue Type: Improvement
>          Components: Appenders
>    Affects Versions: 4.0
>         Environment: .Net 4.0 and newer
>            Reporter: Michael Goldfinger
>            Priority: Minor
>
> I checked out the AsyncAppender and found some drawbacks.
> * logevents are not logged if the appender close
> * order of logevents got lost
> I created an new implementation that waits for all logevents to be computed before close and maintains the order of the events. If the application process got killed the logevents are lost too but in any other case the loss of logevents could be prevented. The drawback of my implementation is that the TLP is requred so .NET 2.0 is not supported.
> I could not find the place to contribute so I created this ticket. I hope it's useful.



--
This message was sent by Atlassian JIRA
(v6.1#6144)