[
https://issues.apache.org/jira/browse/LOG4NET-573?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16246231#comment-16246231
]
Paul Mendoza edited comment on LOG4NET-573 at 11/10/17 12:18 AM:
-----------------------------------------------------------------
I'm having a similar locking issue with log4net version 2.0.8. It happens once
every 30 minutes or so of program runtime. It just freezes when trying to write
out a log message.
In the app that is getting stuck/freezing:
.NET 4.7.1
Debugging with Visual Studio 2017 on Windows 10
Two appenders: Console and log4net.Appender.RollingFileAppender
I'm using a custom log layout although when it gets stuck it doesn't get stuck
in my layout code. I basically just followed this guy's template:
https://github.com/Litee/log4net.Layout.Json/blob/master/src/log4net.Layout.Json/JsonLayout.cs
I'll post more if I can get it to happen again. But I've seen it happen about
10 times now over the last week.
UPDATE:
Just hit it again. This time no threading in this program. Here is the thread
stack and you can see where it was stuck. This callstack is much cleaner than
the one in the original post.
!https://i.imgur.com/ETYMVfu.png!
Here is the full stack trace.
!https://i.imgur.com/kU9swXO.png!
was (Author: pauldev):
I'm having a similar locking issue with log4net version 2.0.8. It happens once
every 30 minutes or so of program runtime. It just freezes when trying to write
out a log message.
In the app that is getting stuck/freezing:
.NET 4.7.1
Debugging with Visual Studio 2017 on Windows 10
Two appenders: Console and log4net.Appender.RollingFileAppender
I'm using a custom log layout although when it gets stuck it doesn't get stuck
in my layout code. I basically just followed this guy's template:
https://github.com/Litee/log4net.Layout.Json/blob/master/src/log4net.Layout.Json/JsonLayout.cs
I'll post more if I can get it to happen again. But I've seen it happen about
10 times now over the last week.
UPDATE:
Just hit it again. This time no threading in this program. Here is the thread
stack and you can see where it was stuck.
!https://i.imgur.com/ETYMVfu.png!
Here is the full stack trace.
!https://i.imgur.com/kU9swXO.png!
> 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)
