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

Appenders Deadlock

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Resolved
    • Blocker
    • Resolution: Information Provided
    • 1.2.15
    • 2.1.0
    • Appenders
    • None
    • Win10

    Description

      Hi,
      I have struggled with a deadlock using log4net when multiple threads are logging.

      This situation is hadr to reproduce but it happends from time to time

      Threads call stacks:

      log4net.dll!log4net.Appender.AppenderSkeleton.DoAppend	Normal
       	 	 	 	 	 	log4net.dll!log4net.Appender.AppenderSkeleton.DoAppend(log4net.Core.LoggingEvent loggingEvent)	 
       	 	 	 	 	 	log4net.dll!log4net.Util.AppenderAttachedImpl.AppendLoopOnAppenders(log4net.Core.LoggingEvent loggingEvent)	 
       	 	 	 	 	 	log4net.dll!log4net.Repository.Hierarchy.Logger.CallAppenders(log4net.Core.LoggingEvent loggingEvent)	 
       	 	 	 	 	 	log4net.dll!log4net.Repository.Hierarchy.Logger.ForcedLog(System.Type callerStackBoundaryDeclaringType, log4net.Core.Level level, object message, System.Exception exception)	 
       	 	 	 	 	 	log4net.dll!log4net.Repository.Hierarchy.Logger.Log(System.Type callerStackBoundaryDeclaringType, log4net.Core.Level level, object message, System.Exception exception)	 
       	 	 	 	 	 	MT.Spectra.BaseFramework.dll!MT.Spectra.BaseFramework.ILogExtensions.Log(log4net.Core.ILoggerWrapper logger, log4net.Core.Level level, System.Func<MT.Spectra.BaseFramework.MessageFormatter, string> formatter, System.Func<string> contextProvider, System.Exception exception)	 
       	 	 	 	 	 	MT.Spectra.MtRpc.dll!MT.Spectra.MtRpc.ReconnectableRpcChannel.ConnectInnerChannel(MT.Spectra.MtRpc.IRpcChannel innerChannel)	 
       	 	 	 	 	 	MT.Spectra.MtRpc.dll!MT.Spectra.MtRpc.ReconnectableRpcChannel.ReconnectableRpcChannel(MT.Spectra.MtRpc.IRpcChannel innerChannel, System.TimeSpan reconnectionTimeout, MT.Spectra.MtRpc.ReconnectableRpcChannel.ChannelStrategy strategy)	 
       	 	 	 	 	 	MT.Spectra.MtRpc.dll!MT.Spectra.MtRpc.ReconnectableRpcChannel.CreateClientChannel(MT.Spectra.MtRpc.IRpcChannel innerChannel, System.TimeSpan reconnectionTimeout, System.TimeSpan reconnectionInterval)	 
       	 	 	 	 	 	MT.SWF.MtRpc.Autofac.dll!MT.SWF.MtRpc.Autofac.RpcClientContextModule.ClientSideChannelFactory(Autofac.IComponentContext c, System.Collections.Generic.IEnumerable<Autofac.Core.Parameter> p)	 
       	 	 	 	 	 	Autofac.dll!Autofac.Builder.RegistrationBuilder.ForDelegate.AnonymousMethod__0(Autofac.IComponentContext c, System.Collections.Generic.IEnumerable<Autofac.Core.Parameter> p)	 
       	 	 	 	 	 	Autofac.dll!Autofac.Core.Activators.Delegate.DelegateActivator.ActivateInstance(Autofac.IComponentContext context, System.Collections.Generic.IEnumerable<Autofac.Core.Parameter> parameters)	 
       	 	 	 	 	 	Autofac.dll!Autofac.Core.Resolving.InstanceLookup.Activate(System.Collections.Generic.IEnumerable<Autofac.Core.Parameter> parameters)	 
       	 	 	 	 	 	Autofac.dll!Autofac.Core.Resolving.InstanceLookup.Execute.AnonymousMethod__0()	 
       	 	 	 	 	 	Autofac.dll!Autofac.Core.Lifetime.LifetimeScope.GetOrCreateAndShare(System.Guid id, System.Func<object> creator)	 
       	 	 	 	 	 	Autofac.dll!Autofac.Core.Resolving.InstanceLookup.Execute()	 
       	 	 	 	 	 	Autofac.dll!Autofac.Core.Resolving.ResolveOperation.GetOrCreateInstance(Autofac.Core.ISharingLifetimeScope currentOperationScope, Autofac.Core.IComponentRegistration registration, System.Collections.Generic.IEnumerable<Autofac.Core.Parameter> parameters)	 
       	 	 	 	 	 	Autofac.dll!Autofac.Core.Resolving.ResolveOperation.Execute(Autofac.Core.IComponentRegistration registration, System.Collections.Generic.IEnumerable<Autofac.Core.Parameter> parameters)	 
       	 	 	 	 	 	Autofac.dll!Autofac.Core.Lifetime.LifetimeScope.ResolveComponent(Autofac.Core.IComponentRegistration registration, System.Collections.Generic.IEnumerable<Autofac.Core.Parameter> parameters)	 
       	 	 	 	 	 	Autofac.dll!Autofac.ResolutionExtensions.TryResolveService(Autofac.IComponentContext context, Autofac.Core.Service service, System.Collections.Generic.IEnumerable<Autofac.Core.Parameter> parameters, out object instance)	 
       	 	 	 	 	 	Autofac.dll!Autofac.ResolutionExtensions.ResolveService(Autofac.IComponentContext context, Autofac.Core.Service service, System.Collections.Generic.IEnumerable<Autofac.Core.Parameter> parameters)	 
       	 	 	 	 	 	Autofac.dll!Autofac.ResolutionExtensions.Resolve<MT.Spectra.MtRpc.IRpcChannel>(Autofac.IComponentContext context, System.Collections.Generic.IEnumerable<Autofac.Core.Parameter> parameters)	 
       	 	 	 	 	 	MT.SWF.MtRpc.Autofac.dll!MT.SWF.MtRpc.GenericRpcClient.CreateContext(MT.Spectra.MtRpc.IRpcPort rpcPort)	 
       	 	 	 	 	 	MT.Spectra.MtRpc.dll!MT.Spectra.MtRpc.RpcClient<MT.SWF.MtRpc.GenericRpcContext>.Connect(System.TimeSpan connectionTimeout)	 
       	 	 	 	 	 	MT.SWF.MtRpc.Autofac.dll!MT.SWF.MtRpc.Autofac.OwnedRpcClient.Connect()	 
       	 	 	 	 	 	MT.SWF.IND.FormPlus.DeviceGateway.dll!MT.SWF.IND.Devices.DiscoveredDevice.Probe() Line 170	 
       	 	 	 	 	 	MT.SWF.IND.FormPlus.DeviceGateway.dll!MT.SWF.IND.Managers.SyncPlusDeviceManager.ProcessDiscoveredDevice(System.Collections.Generic.IEnumerable<MT.SWF.IND.Devices.DiscoveredDevice> discoveredDevices) Line 476	 
       	 	 	 	 	 	MT.SWF.IND.FormPlus.DeviceGateway.dll!MT.SWF.IND.Managers.SyncPlusDeviceManager.AutoDiscoveryLoop(object context) Line 426	 
       	 	 	 	 	 	mscorlib.dll!System.Threading.ThreadHelper.ThreadStart_Context(object state)	 
       	 	 	 	 	 	mscorlib.dll!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state, bool preserveSyncCtx)	 
       	 	 	 	 	 	mscorlib.dll!System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state, bool preserveSyncCtx)	 
       	 	 	 	 	 	mscorlib.dll!System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state)	 
       	 	 	 	 	 	mscorlib.dll!System.Threading.ThreadHelper.ThreadStart(object obj)	 
       	 	 	 	 	 	[Native to Managed Transition]	 
      
      log4net.dll!log4net.Appender.AppenderSkeleton.DoAppend	Normal
       	 	 	 	 	 	log4net.dll!log4net.Appender.AppenderSkeleton.DoAppend(log4net.Core.LoggingEvent loggingEvent)	 
       	 	 	 	 	 	log4net.dll!log4net.Util.AppenderAttachedImpl.AppendLoopOnAppenders(log4net.Core.LoggingEvent loggingEvent)	 
       	 	 	 	 	 	log4net.dll!log4net.Repository.Hierarchy.Logger.CallAppenders(log4net.Core.LoggingEvent loggingEvent)	 
       	 	 	 	 	 	log4net.dll!log4net.Repository.Hierarchy.Logger.ForcedLog(System.Type callerStackBoundaryDeclaringType, log4net.Core.Level level, object message, System.Exception exception)	 
       	 	 	 	 	 	log4net.dll!log4net.Repository.Hierarchy.Logger.Log(System.Type callerStackBoundaryDeclaringType, log4net.Core.Level level, object message, System.Exception exception)	 
       	 	 	 	 	 	log4net.dll!log4net.Core.LogImpl.DebugFormat(System.IFormatProvider provider, string format, object[] args)	 
       	 	 	 	 	 	MT.Backbone.Data.NHibernate.dll!MT.SWF.DataAccess.TransactionService.CreateTransactionScope(MT.SWF.DataAccess.TransactionType transactionType, System.Data.IsolationLevel isolationLevel)	 
       	 	 	 	 	 	MT.Backbone.Data.NHibernate.dll!MT.SWF.DataAccess.TransactionService.CreateTransactionScope()	 
       	 	 	 	 	 	MT.SWF.IND.FormPlus.BusinessLogic.dll!MT.SWF.IND.Security.ClientSessionManager.Renew() Line 164	 
       	 	 	 	 	 	MT.Backbone.dll!MT.SWF.ServiceModel.Dispatcher.ClientSessionServerInspector.BeforeCall(string operationName, object[] inputs)	 
       	 	 	 	 	 	System.ServiceModel.dll!System.ServiceModel.Dispatcher.DispatchOperationRuntime.InspectInputsCore(ref System.ServiceModel.Dispatcher.MessageRpc rpc)	 
       	 	 	 	 	 	System.ServiceModel.dll!System.ServiceModel.Dispatcher.DispatchOperationRuntime.InvokeBegin(ref System.ServiceModel.Dispatcher.MessageRpc rpc)	 
       	 	 	 	 	 	System.ServiceModel.dll!System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage5(ref System.ServiceModel.Dispatcher.MessageRpc rpc)	 
       	 	 	 	 	 	System.ServiceModel.dll!System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage41(ref System.ServiceModel.Dispatcher.MessageRpc rpc)	 
       	 	 	 	 	 	System.ServiceModel.dll!System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage4(ref System.ServiceModel.Dispatcher.MessageRpc rpc)	 
       	 	 	 	 	 	System.ServiceModel.dll!System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage31(ref System.ServiceModel.Dispatcher.MessageRpc rpc)	 
       	 	 	 	 	 	System.ServiceModel.dll!System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage3(ref System.ServiceModel.Dispatcher.MessageRpc rpc)	 
       	 	 	 	 	 	System.ServiceModel.dll!System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage2(ref System.ServiceModel.Dispatcher.MessageRpc rpc)	 
       	 	 	 	 	 	System.ServiceModel.dll!System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage11(ref System.ServiceModel.Dispatcher.MessageRpc rpc)	 
       	 	 	 	 	 	System.ServiceModel.dll!System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage1(ref System.ServiceModel.Dispatcher.MessageRpc rpc)	 
       	 	 	 	 	 	System.ServiceModel.dll!System.ServiceModel.Dispatcher.MessageRpc.Process(bool isOperationContextSet)	 
       	 	 	 	 	 	System.ServiceModel.dll!System.ServiceModel.Dispatcher.ChannelHandler.DispatchAndReleasePump(System.ServiceModel.Channels.RequestContext request, bool cleanThread, System.ServiceModel.OperationContext currentOperationContext)	 
       	 	 	 	 	 	System.ServiceModel.dll!System.ServiceModel.Dispatcher.ChannelHandler.HandleRequest(System.ServiceModel.Channels.RequestContext request, System.ServiceModel.OperationContext currentOperationContext)	 
       	 	 	 	 	 	System.ServiceModel.dll!System.ServiceModel.Dispatcher.ChannelHandler.AsyncMessagePump(System.IAsyncResult result)	 
       	 	 	 	 	 	System.ServiceModel.dll!System.ServiceModel.Dispatcher.ChannelHandler.OnAsyncReceiveComplete(System.IAsyncResult result)	 
       	 	 	 	 	 	System.ServiceModel.Internals.dll!System.Runtime.Fx.AsyncThunk.UnhandledExceptionFrame(System.IAsyncResult result)	 
       	 	 	 	 	 	System.ServiceModel.Internals.dll!System.Runtime.AsyncResult.Complete(bool completedSynchronously)	 
       	 	 	 	 	 	System.ServiceModel.dll!System.ServiceModel.Channels.TransportDuplexSessionChannel.TryReceiveAsyncResult.OnReceive(System.IAsyncResult result)	 
       	 	 	 	 	 	System.ServiceModel.Internals.dll!System.Runtime.Fx.AsyncThunk.UnhandledExceptionFrame(System.IAsyncResult result)	 
       	 	 	 	 	 	System.ServiceModel.Internals.dll!System.Runtime.AsyncResult.Complete(bool completedSynchronously)	 
       	 	 	 	 	 	System.ServiceModel.dll!System.ServiceModel.Channels.SynchronizedMessageSource.ReceiveAsyncResult.OnReceiveComplete(object state)	 
       	 	 	 	 	 	System.ServiceModel.dll!System.ServiceModel.Channels.SessionConnectionReader.OnAsyncReadComplete(object state)	 
       	 	 	 	 	 	System.ServiceModel.dll!System.ServiceModel.Channels.SocketConnection.FinishRead()	 
       	 	 	 	 	 	System.ServiceModel.dll!System.ServiceModel.Channels.SocketConnection.OnReceiveAsync(object sender, System.Net.Sockets.SocketAsyncEventArgs eventArgs)	 
       	 	 	 	 	 	System.ServiceModel.dll!System.ServiceModel.Channels.SocketConnection.OnReceiveAsyncCompleted(object sender, System.Net.Sockets.SocketAsyncEventArgs e)	 
       	 	 	 	 	 	System.dll!System.Net.Sockets.SocketAsyncEventArgs.OnCompleted(System.Net.Sockets.SocketAsyncEventArgs e)	 
       	 	 	 	 	 	System.dll!System.Net.Sockets.SocketAsyncEventArgs.FinishOperationSuccess(System.Net.Sockets.SocketError socketError, int bytesTransferred, System.Net.Sockets.SocketFlags flags)	 
       	 	 	 	 	 	System.dll!System.Net.Sockets.SocketAsyncEventArgs.CompletionPortCallback(uint errorCode, uint numBytes, System.Threading.NativeOverlapped* nativeOverlapped)	 
       	 	 	 	 	 	mscorlib.dll!System.Threading._IOCompletionCallback.PerformIOCompletionCallback(uint errorCode, uint numBytes, System.Threading.NativeOverlapped* pOVERLAP)	 
       	 	 	 	 	 	[Native to Managed Transition]	 
      
      
      
      log4net.dll!log4net.Appender.ColoredConsoleAppender.Append	Normal
       	 	 	 	 	 	[Managed to Native Transition]	 
       	 	 	 	 	 	mscorlib.dll!System.IO.__ConsoleStream.WriteFileNative(Microsoft.Win32.SafeHandles.SafeFileHandle hFile, byte[] bytes, int offset, int count, bool useFileAPIs)	 
       	 	 	 	 	 	mscorlib.dll!System.IO.__ConsoleStream.Write(byte[] buffer, int offset, int count)	 
       	 	 	 	 	 	mscorlib.dll!System.IO.StreamWriter.Flush(bool flushStream, bool flushEncoder)	 
       	 	 	 	 	 	mscorlib.dll!System.IO.StreamWriter.Write(char[] buffer, int index, int count)	 
       	 	 	 	 	 	log4net.dll!log4net.Appender.ColoredConsoleAppender.Append(log4net.Core.LoggingEvent loggingEvent)	 
       	 	 	 	 	 	log4net.dll!log4net.Appender.AppenderSkeleton.DoAppend(log4net.Core.LoggingEvent loggingEvent)	 
       	 	 	 	 	 	log4net.dll!log4net.Util.AppenderAttachedImpl.AppendLoopOnAppenders(log4net.Core.LoggingEvent loggingEvent)	 
       	 	 	 	 	 	log4net.dll!log4net.Repository.Hierarchy.Logger.CallAppenders(log4net.Core.LoggingEvent loggingEvent)	 
       	 	 	 	 	 	log4net.dll!log4net.Repository.Hierarchy.Logger.ForcedLog(System.Type callerStackBoundaryDeclaringType, log4net.Core.Level level, object message, System.Exception exception)	 
       	 	 	 	 	 	log4net.dll!log4net.Repository.Hierarchy.Logger.Log(System.Type callerStackBoundaryDeclaringType, log4net.Core.Level level, object message, System.Exception exception)	 
       	 	 	 	 	 	log4net.dll!log4net.Core.LogImpl.Info(object message)	 
       	 	 	 	 	 	MT.SWF.IND.FormPlus.BusinessLogic.dll!MT.SWF.IND.Notifications.InterruptionMailerJob.NotifyInterruptedBatches() Line 113	 
       	 	 	 	 	 	MT.SWF.IND.FormPlus.BusinessLogic.dll!MT.SWF.IND.Notifications.InterruptionMailerJob.StartPeriodicalChecks.AnonymousMethod__12_0(object state) Line 88	 
       	 	 	 	 	 	MT.SWF.BaseFramework.dll!MT.SWF.Threading.ThreadFactory.CreateSynchronousTimer.AnonymousMethod__0(object sender, MT.SWF.Threading.TimerEventArgs e)	 
       	 	 	 	 	 	MT.SWF.BaseFramework.dll!MT.SWF.Threading.WrappedTimer..ctor.AnonymousMethod__1()	 
       	 	 	 	 	 	MT.SWF.BaseFramework.dll!MT.SWF.Threading.WrappedTimer.SynchronousWorkerWrapper(System.Action worker)	 
       	 	 	 	 	 	MT.SWF.BaseFramework.dll!MT.SWF.Threading.WrappedTimer..ctor.AnonymousMethod__0(object x)	 
       	 	 	 	 	 	mscorlib.dll!System.Threading.TimerQueueTimer.CallCallbackInContext(object state)	 
       	 	 	 	 	 	mscorlib.dll!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state, bool preserveSyncCtx)	 
       	 	 	 	 	 	mscorlib.dll!System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state, bool preserveSyncCtx)	 
       	 	 	 	 	 	mscorlib.dll!System.Threading.TimerQueueTimer.CallCallback()	 
       	 	 	 	 	 	mscorlib.dll!System.Threading.TimerQueueTimer.Fire()	 
       	 	 	 	 	 	mscorlib.dll!System.Threading.TimerQueue.FireNextTimers()	 
       	 	 	 	 	 	mscorlib.dll!System.Threading.TimerQueue.AppDomainTimerCallback()	 
       	 	 	 	 	 	[Native to Managed Transition]	 
      
      

      Im also attaching configurtation file.
      Could someone help me to confirmat, that is a bug?
      Also if additional information are needed, fell free to ask

      Attachments

        1. LoggingConfiguration.log4net.config
          6 kB
          Michal
        2. screenshot-1.png
          30 kB
          Paul Mendoza
        3. screenshot-2.png
          29 kB
          Paul Mendoza

        Activity

          People

            nachbarslumpi Dominik Psenner
            mbenedyk Michal
            Votes:
            1 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: