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.
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

Reply via email to