[
https://issues.apache.org/jira/browse/LOG4NET-583?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16974560#comment-16974560
]
Emmo Emminghaus commented on LOG4NET-583:
-----------------------------------------
Same Experience... same result:
Deadlock in FileAppender.FileOpen().
My suggestion:
Use a different name for the {color:#172b4d}File Rolling{color} mutex...
Then you have the same behavior when using the MinimalLock… IT WORKS PERFECT!
PS: I hope such a simple solution does not need another 2 years.
> RolingFileAppender+InterProcessLock is locked after rolling log files
> ---------------------------------------------------------------------
>
> Key: LOG4NET-583
> URL: https://issues.apache.org/jira/browse/LOG4NET-583
> Project: Log4net
> Issue Type: Bug
> Components: Appenders
> Affects Versions: 2.0.8
> Environment: Windows Server 2008 R2 Standart, IIS 7.5
> Reporter: Eugene Panov
> Priority: Major
>
> We are using log4net for logging http requests to HttpHandlers.
> RollingFileAppender is locked after rolling log files by date or by size.
> Here is the dump of locked thread:
> [[HelperMethodFrame_1OBJ] (System.Threading.WaitHandle.WaitOneNative)]
> System.Threading.WaitHandle.WaitOneNative(Microsoft.Win32.SafeHandles.SafeWaitHandle,
> UInt32, Boolean, Boolean)
> mscorlib_ni!System.Threading.WaitHandle.WaitOne(Int64, Boolean)+23
> log4net.Appender.RollingFileAppender.AdjustFileBeforeAppend()+47
> log4net.Appender.RollingFileAppender.Append(log4net.Core.LoggingEvent)+18
> log4net.Appender.AppenderSkeleton.DoAppend(log4net.Core.LoggingEvent)+c5
> log4net.Util.AppenderAttachedImpl.AppendLoopOnAppenders(log4net.Core.LoggingEvent)+9a
> log4net.Repository.Hierarchy.Logger.CallAppenders(log4net.Core.LoggingEvent)+8a
> log4net.Repository.Hierarchy.Logger.Log(System.Type, log4net.Core.Level,
> System.Object, System.Exception)+6f
> log4net.Core.LogImpl.ErrorFormat(System.String, System.Object, System.Object,
> System.Object)+10e
> FileManager.SaveReceivedDeviceLog(System.Web.HttpPostedFile,
> System.String)+1e1
> upload_log_file.ProcessRequest(System.Web.HttpContext)+110
> System_Web_ni!System.Web.HttpApplication+CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()+257
> System_Web_ni!System.Web.HttpApplication.ExecuteStep(IExecutionStep, Boolean
> ByRef)+ab
> System_Web_ni!System.Web.HttpApplication+PipelineStepManager.ResumeSteps(System.Exception)+511
> System_Web_ni!System.Web.HttpApplication.BeginProcessRequestNotification(System.Web.HttpContext,
> System.AsyncCallback)+72
> System_Web_ni!System.Web.HttpRuntime.ProcessRequestNotificationPrivate(System.Web.Hosting.IIS7WorkerRequest,
> System.Web.HttpContext)+269
> System_Web_ni!System.Web.Hosting.PipelineRuntime.ProcessRequestNotificationHelper(IntPtr,
> IntPtr, IntPtr, Int32)+411
> System_Web_ni!System.Web.Hosting.PipelineRuntime.ProcessRequestNotification(IntPtr,
> IntPtr, IntPtr, Int32)+2b
> System_Web_ni!DomainNeutralILStubClass.IL_STUB(Int64, Int64, Int64, Int32)+24
> System_Web_ni!DomainNeutralILStubClass.IL_STUB(IntPtr,
> System.Web.RequestNotificationStatus ByRef)+4b
> [[NDirectMethodFrameStandalone]
> (System.Web.Hosting.UnsafeIISMethods.MgdIndicateCompletion)]
> System.Web.Hosting.UnsafeIISMethods.MgdIndicateCompletion(IntPtr,
> System.Web.RequestNotificationStatusByRef)
> System_Web_ni!System.Web.Hosting.PipelineRuntime.ProcessRequestNotificationHelper(IntPtr,
> IntPtr, IntPtr, Int32)+540
> System_Web_ni!System.Web.Hosting.PipelineRuntime.ProcessRequestNotification(IntPtr,
> IntPtr, IntPtr, Int32)+2b
> System_Web_ni!DomainNeutralILStubClass.IL_STUB(Int64, Int64, Int64, Int32)+24
> I found that there are two places with mutex instanciation in the code:
> *In FileAppender.cs:*
> public override void ActivateOptions()
> {
> if (m_mutex == null)
> {
> string mutexFriendlyFilename =
> CurrentAppender.File
> .Replace("\\", "_")
> .Replace(":", "_")
> .Replace("/", "_");
> {color:red}m_mutex = new Mutex(false,
> mutexFriendlyFilename);
> {color} }
> else
> {
>
> CurrentAppender.ErrorHandler.Error("Programming error, mutex already
> initialized!");
> }
> }
> and
> *in RollingFileAppender.cs:*
> // initialize the mutex that is used to lock rolling
> {color:red}m_mutexForRolling = new Mutex(false, m_baseFileName.Replace("\\",
> "_").Replace(":", "_").Replace("/", "_") + "_MutexForRolling");{color}
> It looks like these mutexes are used for differnt purposes but they have the
> same name.
> Suppose they should have different names.
> But really locking is caused by the following code:
> protected override void WriteHeader()
> {
> if (m_stream != null)
> {
> if (m_stream.AcquireLock())
> {
> try
> {
> base.WriteHeader();
> }
> finally
> {
> m_stream.ReleaseLock();
> }
> }
> }
> }
> public bool AcquireLock()
> {
> bool ret = false;
> lock (this)
> {
> if (m_lockLevel == 0)
> {
> // If lock is already acquired,
> nop
> m_realStream =
> m_lockingModel.AcquireLock();
> }
> if (m_realStream != null)
> {
> m_lockLevel++;
> ret = true;
> }
> }
> return ret;
> }
> m_realStream = m_lockingModel.AcquireLock(); - this line executes th
> following function:
> public override Stream AcquireLock()
> {
> if (m_mutex != null)
> {
> // TODO: add timeout?
> m_mutex.WaitOne();
> // increment recursive watch
> m_recursiveWatch++;
>
> // should always be true (and fast) for
> FileStream
> if (m_stream != null)
> {
>
> if (m_stream.CanSeek)
> {
> m_stream.Seek(0,
> SeekOrigin.End);
> }
> }
> else
> {
> // this can happen when the
> file appender cannot open a file for writing
> }
> }
> else
> {
>
> CurrentAppender.ErrorHandler.Error("Programming error, no mutex available to
> acquire lock! From here on things will be dangerous!");
> }
> return m_stream;
> }
> if m_stream == null then m_mutex.WaitOne(); is executed
> but m_lockLevel is not incremented
> if (m_realStream != null)
> {
> m_lockLevel++;
> ret = true;
> }
> And mutex will not be released:
> public void ReleaseLock()
> {
> lock (this)
> {
> m_lockLevel--;
> if (m_lockLevel == 0)
> {
> // If already unlocked, nop
> m_lockingModel.ReleaseLock();
> m_realStream = null;
> }
> }
> }
> It cause locking of any other threads that try to append to the log.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
