Uploaded image for project: 'Log4net'
  1. Log4net
  2. LOG4NET-485

RollingFileAppender cannot be used by multiple process

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 1.2.13, 1.2.14, 1.3.0
    • Fix Version/s: 1.2.14
    • Component/s: Appenders
    • Labels:
      None

      Description

      RollingFileAppender doesn't acquire lock when rolling takes place.
      As a consequence running multiple instances of the same program rewrites the same log file instead of making a roll for everyone.

      There is FileAppender.InterProcessLock but it only protects writes and not rolls.

        Issue Links

          Activity

          Hide
          nachbarslumpi Dominik Psenner added a comment -

          Fix committed as svn revision 1711836. Would you please check if this solves this issue? If not please reopen this issue.

          Show
          nachbarslumpi Dominik Psenner added a comment - Fix committed as svn revision 1711836. Would you please check if this solves this issue? If not please reopen this issue.
          Hide
          nachbarslumpi Dominik Psenner added a comment -

          It's great to hear that it looks great. Obviously it should also work. You wouldn't have the chance to test it, have you?

          I gotta note further that this fix introduces a performance penalty for the non-inter-process usage of the rolling file appender. This might not be always the wanted behaviour, but I did not want to introduce yet another configuration option allowing users to choose if locking should take place or not. Worst case users configure it wrong and suffer on the collateral damage that will happen. Anyway, this configuration option could be a great way to improve this appender further. Let me know what you think about this.

          Show
          nachbarslumpi Dominik Psenner added a comment - It's great to hear that it looks great. Obviously it should also work. You wouldn't have the chance to test it, have you? I gotta note further that this fix introduces a performance penalty for the non-inter-process usage of the rolling file appender. This might not be always the wanted behaviour, but I did not want to introduce yet another configuration option allowing users to choose if locking should take place or not. Worst case users configure it wrong and suffer on the collateral damage that will happen. Anyway, this configuration option could be a great way to improve this appender further. Let me know what you think about this.
          Hide
          _nn_ NN added a comment -

          Let's discuss mutex modes in #487 ( https://issues.apache.org/jira/browse/LOG4NET-487 )

          Show
          _nn_ NN added a comment - Let's discuss mutex modes in #487 ( https://issues.apache.org/jira/browse/LOG4NET-487 )
          Hide
          _nn_ NN added a comment -

          Actually I think the mutex mode should be a non-locking by default same with previous versions to not impact program's performance.
          In case anybody needs to log from multiple processes he can turn on the mutex locking.

          Show
          _nn_ NN added a comment - Actually I think the mutex mode should be a non-locking by default same with previous versions to not impact program's performance. In case anybody needs to log from multiple processes he can turn on the mutex locking.
          Hide
          _nn_ NN added a comment -

          Hello,
          Can you merge these changes into 1.3 branch ?
          Thanks

          Show
          _nn_ NN added a comment - Hello, Can you merge these changes into 1.3 branch ? Thanks
          Hide
          miroslav.vanicky@vande.cz Miroslav Vanický added a comment -

          Hi,

          please how to unsubscribe from these emails?
          Thank You,

          Mirek Vanicky

          Show
          miroslav.vanicky@vande.cz Miroslav Vanický added a comment - Hi, please how to unsubscribe from these emails? Thank You, Mirek Vanicky
          Hide
          Christoph.Herzog Christoph Herzog added a comment -

          Tested with 1.2.15, definitly not fixed.

          The whole part which is reponsible for rolling/creating of files needs to be garded by locks!

          Worst case, when logging from multiple processes, is that the call to Log is stuck

          mscorlib.dll!System.Threading.WaitHandle.WaitOne() Unknown
          log4net.dll!log4net.Appender.RollingFileAppender.AdjustFileBeforeAppend() Unknown
          log4net.dll!log4net.Appender.RollingFileAppender.Append(log4net.Core.LoggingEvent loggingEvent) Unknown
          log4net.dll!log4net.Appender.AppenderSkeleton.DoAppend(log4net.Core.LoggingEvent loggingEvent) Unknown
          log4net.dll!log4net.Util.AppenderAttachedImpl.AppendLoopOnAppenders(log4net.Core.LoggingEvent loggingEvent) Unknown
          log4net.dll!log4net.Repository.Hierarchy.Logger.CallAppenders(log4net.Core.LoggingEvent loggingEvent) Unknown
          log4net.dll!log4net.Repository.Hierarchy.Logger.ForcedLog(System.Type callerStackBoundaryDeclaringType, log4net.Core.Level level, object message, System.Exception exception) Unknown
          log4net.dll!log4net.Repository.Hierarchy.Logger.Log(System.Type callerStackBoundaryDeclaringType, log4net.Core.Level level, object message, System.Exception exception) Unknown
          log4net.dll!log4net.Core.LogImpl.WarnFormat(string format, object arg0, object arg1, object arg2) Unknown

          The normal logging, will also generate errors, in this case the file is not rolled, but instead the logfile is rewritten

          log4net:ERROR RollingFileAppender: INTERNAL ERROR. Append is False but OutputFile [C:\Temp\log\myLog.txt] already exists.
          log4net:WARN Cannot RollFile [C:\Temp\log\myLog.1.txt] -> [C:\Temp\log\myLog.2.txt]. Source does not exist
          log4net:ERROR RollingFileAppender: INTERNAL ERROR. Append is False but OutputFile [C:\Temp\log\myLog.txt] already exists.
          log4net:WARN Cannot RollFile [C:\Temp\log\myLog.2.txt] -> [C:\Temp\log\myLog.3.txt]. Source does not exist
          log4net:WARN Cannot RollFile [C:\Temp\log\myLog.1.txt] -> [C:\Temp\log\myLog.2.txt]. Source does not exist
          log4net:ERROR RollingFileAppender: INTERNAL ERROR. Append is False but OutputFile [C:\Temp\log\myLog.txt] already exists.

          Show
          Christoph.Herzog Christoph Herzog added a comment - Tested with 1.2.15, definitly not fixed. The whole part which is reponsible for rolling/creating of files needs to be garded by locks! Worst case, when logging from multiple processes, is that the call to Log is stuck mscorlib.dll!System.Threading.WaitHandle.WaitOne() Unknown log4net.dll!log4net.Appender.RollingFileAppender.AdjustFileBeforeAppend() Unknown log4net.dll!log4net.Appender.RollingFileAppender.Append(log4net.Core.LoggingEvent loggingEvent) Unknown log4net.dll!log4net.Appender.AppenderSkeleton.DoAppend(log4net.Core.LoggingEvent loggingEvent) Unknown log4net.dll!log4net.Util.AppenderAttachedImpl.AppendLoopOnAppenders(log4net.Core.LoggingEvent loggingEvent) Unknown log4net.dll!log4net.Repository.Hierarchy.Logger.CallAppenders(log4net.Core.LoggingEvent loggingEvent) Unknown log4net.dll!log4net.Repository.Hierarchy.Logger.ForcedLog(System.Type callerStackBoundaryDeclaringType, log4net.Core.Level level, object message, System.Exception exception) Unknown log4net.dll!log4net.Repository.Hierarchy.Logger.Log(System.Type callerStackBoundaryDeclaringType, log4net.Core.Level level, object message, System.Exception exception) Unknown log4net.dll!log4net.Core.LogImpl.WarnFormat(string format, object arg0, object arg1, object arg2) Unknown The normal logging, will also generate errors, in this case the file is not rolled, but instead the logfile is rewritten log4net:ERROR RollingFileAppender: INTERNAL ERROR. Append is False but OutputFile [C:\Temp\log\myLog.txt] already exists. log4net:WARN Cannot RollFile [C:\Temp\log\myLog.1.txt] -> [C:\Temp\log\myLog.2.txt] . Source does not exist log4net:ERROR RollingFileAppender: INTERNAL ERROR. Append is False but OutputFile [C:\Temp\log\myLog.txt] already exists. log4net:WARN Cannot RollFile [C:\Temp\log\myLog.2.txt] -> [C:\Temp\log\myLog.3.txt] . Source does not exist log4net:WARN Cannot RollFile [C:\Temp\log\myLog.1.txt] -> [C:\Temp\log\myLog.2.txt] . Source does not exist log4net:ERROR RollingFileAppender: INTERNAL ERROR. Append is False but OutputFile [C:\Temp\log\myLog.txt] already exists.
          Hide
          blake.raymond Blake Raymond added a comment - - edited

          We have two processes sharing a log file using RollingFileAppender running under different users. One is a Windows service running as Local System and the other is IIS running as Network Service, with default permissions for those users on Windows Server 2012. We are finding that if the Local System process is the one to create the named mutex for rolling, the Network Service process is unable to open it and receives an access denied error during ActivateOptions for the RollingFileAppender. The reverse order works - if the Network Service process creates the mutex, the Local System process is able to open it.

          System.UnauthorizedAccessException: Access to the path 'C__ProgramData_*********************.log' is denied.
             at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath)
             at System.Threading.Mutex.MutexTryCodeHelper.MutexTryCode(Object userData)
             at System.Runtime.CompilerServices.RuntimeHelpers.ExecuteCodeWithGuaranteedCleanup(TryCode code, CleanupCode backoutCode, Object userData)
             at System.Threading.Mutex.CreateMutexWithGuaranteedCleanup(Boolean initiallyOwned, String name, Boolean& createdNew, SECURITY_ATTRIBUTES secAttrs)
             at System.Threading.Mutex..ctor(Boolean initiallyOwned, String name, Boolean& createdNew, MutexSecurity mutexSecurity)
             at System.Threading.Mutex..ctor(Boolean initiallyOwned, String name, Boolean& createdNew)
             at log4net.Appender.RollingFileAppender.ActivateOptions()
          

          <call stack truncated>

          Show
          blake.raymond Blake Raymond added a comment - - edited We have two processes sharing a log file using RollingFileAppender running under different users. One is a Windows service running as Local System and the other is IIS running as Network Service, with default permissions for those users on Windows Server 2012. We are finding that if the Local System process is the one to create the named mutex for rolling, the Network Service process is unable to open it and receives an access denied error during ActivateOptions for the RollingFileAppender. The reverse order works - if the Network Service process creates the mutex, the Local System process is able to open it. System.UnauthorizedAccessException: Access to the path 'C__ProgramData_*********************.log' is denied. at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath) at System.Threading.Mutex.MutexTryCodeHelper.MutexTryCode(Object userData) at System.Runtime.CompilerServices.RuntimeHelpers.ExecuteCodeWithGuaranteedCleanup(TryCode code, CleanupCode backoutCode, Object userData) at System.Threading.Mutex.CreateMutexWithGuaranteedCleanup(Boolean initiallyOwned, String name, Boolean& createdNew, SECURITY_ATTRIBUTES secAttrs) at System.Threading.Mutex..ctor(Boolean initiallyOwned, String name, Boolean& createdNew, MutexSecurity mutexSecurity) at System.Threading.Mutex..ctor(Boolean initiallyOwned, String name, Boolean& createdNew) at log4net.Appender.RollingFileAppender.ActivateOptions() <call stack truncated>

            People

            • Assignee:
              nachbarslumpi Dominik Psenner
              Reporter:
              _nn_ NN
            • Votes:
              0 Vote for this issue
              Watchers:
              5 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development