[jira] [Resolved] (LOG4NET-298) Loggers are not fully re-entrant and can deadlock

["Dominik Psenner (JIRA)" <ji...@apache.org>]

     [ https://issues.apache.org/jira/browse/LOG4NET-298?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Dominik Psenner resolved LOG4NET-298.
-------------------------------------

       Resolution: Won't Fix
    Fix Version/s:     (was: 1.2 Maintenance Release)

The same snippet without log4net deadlocks too:

	class Program
	{
		static void Main(string[] args)
		{
			Console.WriteLine("Nasty thing {0}", new NastyThing());
		}

		private class NastyThing
		{
			public override string ToString()
			{
				Console.WriteLine("This message goes missing");

				var t = Task.Factory.StartNew(DoLoggingInOtherThread);
				t.Wait(); // this deadlock deep in log4net

				return "NastyThing.ToString()";
			}
		}

		public static void DoLoggingInOtherThread()
		{
			Console.WriteLine("This message deadlocks");
		}
	}

It may not be obvious at the first glance, but the t.Wait() does most often deadlock even trivial appenders.
                
> Loggers are not fully re-entrant and can deadlock
> -------------------------------------------------
>
>                 Key: LOG4NET-298
>                 URL: https://issues.apache.org/jira/browse/LOG4NET-298
>             Project: Log4net
>          Issue Type: Bug
>          Components: Appenders
>    Affects Versions: 1.2.10
>            Reporter: Tanguy Fautre
>
> Log4net internal locking seems to be too aggressive and coarse. It can deadlock in cases where a logging thread waits on another thread that also logs. While this is a similar issue to LOG4NET-225, there is no custom appender needed to reproduce it.
> For example, the following program will deadlock in .\log4net-1.2.10\src\Appender\AppenderSkeleton.cs (AppenderSkeleton.DoAppend(), line 296)
>  
> using System.Threading.Tasks;
> using log4net;
> using log4net.Appender;
> using log4net.Core;
> using log4net.Layout;
> using log4net.Repository.Hierarchy;
> namespace HelloWorldCSharp
> {
>     public class Program
>     {
>         private static readonly ILog Log = LogManager.GetLogger("My.Logger");
>  
>         private static void InitLogger()
>         {
>             var appender = new ConsoleAppender { Name = "Unit Testing Console Appender", Layout = new PatternLayout("%message%n"), Threshold = Level.All };
>             appender.ActivateOptions();
>  
>             var root = ((Hierarchy)LogManager.GetRepository()).Root;
>             root.Level = Level.Debug;
>             root.AddAppender(appender);
>             root.Repository.Configured = true;
>         }
>         public static void Main()
>         {
>             InitLogger();
>  
>             Log.WarnFormat("Nasty thing {0}", new NastyThing());
>         }
>         private class NastyThing
>         {
>             public override string ToString()
>             {
>                 Log.Warn("This message goes missing");
>                 var t = Task.Factory.StartNew(DoLoggingInOtherThread);
>                 t.Wait(); // this deadlock deep in log4net
>                 return "NastyThing.ToString()";
>             }
>         }
>         public static void DoLoggingInOtherThread()
>         {
>             Log.Warn("This message deadlocks");
>         }
>     }
> }
> Current behaviour:
> - prints nothing
> - deadlocks
> Expected behaviour:
> - prints "This message goes missing"
> - prints "This message deadlocks"
> - prints "Nasty thing NastyThing.ToString()"
> - exits cleanly
> Having looked at the code from SkeletonAppender, I understand this may not be a trivial issue to fix. I feel however that this is a reasonable user expectation (especially given the fact that the use case above is read-only and makes no attempt to modify the log tree).
> Cheers,
> Tanguy

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira