[
https://issues.apache.org/jira/browse/LOG4NET-573?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16147792#comment-16147792
]
Dominik Psenner commented on LOG4NET-573:
-----------------------------------------
Hi Michal.
There's a lot going on in these stacktraces. There is NHibernate, ServiceModel
Rpc, AppDomain Timers, Autofac, Mailer jobs and a lot more pieces that all add
up to a great deal of complexity without explanation how these pieces are
supposed to fit together. The log4net configuration is complicated too,
complicated enough that I couldn't understand it while reading it. With this
information it is impossible to say if there is actually a deadlock or where it
could be. It may be that a deadlock is not actually caused by log4net but
rather a consequence of a bad configuration of the logging framework or even a
design flaw of the application and an implication of how all the pieces work
together.
Would you please explain the application in simple words? What does it do? Who
logs what and where are these log events sinked to? Are there multiple
processes involved? Are there multiple threads in multiple processes involved?
How do all those processes interact? Please try to work away as much complexity
as you can. I hope that you'll find the cause of the symptoms you experience
while doing so because I'm afraid that this task is not an easy one and it will
take days if not weeks to work out without having the entire application at
hands.
Cheers
> Appenders Deadlock
> ------------------
>
> Key: LOG4NET-573
> URL: https://issues.apache.org/jira/browse/LOG4NET-573
> Project: Log4net
> Issue Type: Bug
> Components: Appenders
> Affects Versions: 1.2.15
> Environment: Win10
> Reporter: Michal
> Priority: Blocker
> Attachments: LoggingConfiguration.log4net.config
>
>
> 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:
> {code:java}
> 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]
>
> {code}
> {code:java}
> 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]
>
> {code}
> {code:java}
> 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]
>
> {code}
> 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
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)
