c# - NLog がトレースでハングする (マルチスレッドの問題?)

Question

症状は、アプリケーションのハングです (IIS 7 でホストされています)。

NLog.dll!NLog.Targets.Target.WriteAsyncLogEvent(NLog.Common.AsyncLogEventInfo logEvent) + 0x54 bytes     
NLog.dll!NLog.LoggerImpl.WriteToTargetWithFilterChain(NLog.Internal.TargetWithFilterChain targetListHead, NLog.LogEventInfo logEvent, NLog.Common.AsyncContinuation onException) + 0x8b bytes    
NLog.dll!NLog.LoggerImpl.Write(System.Type loggerType, NLog.Internal.TargetWithFilterChain targets, NLog.LogEventInfo logEvent, NLog.LogFactory factory) + 0xee bytes    
NLog.dll!NLog.Logger.WriteToTargets(NLog.LogLevel level, string message, object[] args) + 0x14 bytes     
NLog.dll!NLog.Logger.Trace<System.__Canon,long>(string message, System.__Canon argument1, long argument2) + 0x90 bytes
... <my app code> ...

と一つ

mscorlib.dll!System.Collections.Generic.Dictionary<NLog.Layouts.Layout,string>.FindEntry(NLog.Layouts.Layout key) + 0xd0 bytes   
mscorlib.dll!System.Collections.Generic.Dictionary<System.__Canon,System.__Canon>.TryGetValue(System.__Canon key, out System.__Canon value) + 0x14 bytes     
NLog.dll!NLog.Layouts.SimpleLayout.GetFormattedMessage(NLog.LogEventInfo logEvent) + 0x81 bytes  
NLog.dll!NLog.Targets.FileTarget.GetBytesToWrite(NLog.LogEventInfo logEvent) + 0x1c bytes    
NLog.dll!NLog.Targets.FileTarget.Write(NLog.Common.AsyncLogEventInfo[] logEvents) + 0x308 bytes  
NLog.dll!NLog.Targets.Target.WriteAsyncLogEvents(NLog.Common.AsyncLogEventInfo[] logEvents) + 0x258 bytes    
NLog.dll!NLog.Targets.Wrappers.AsyncTargetWrapper.ProcessPendingEvents(object state) + 0x1e6 bytes   
mscorlib.dll!System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state, bool ignoreSyncCtx) + 0xdc bytes     
mscorlib.dll!System.Threading._TimerCallback.PerformTimerCallback(object state) + 0x97 bytes     
... <my app code> ...

そして1つ

mscorlib.dll!System.Collections.Generic.Dictionary<NLog.Layouts.Layout,string>.Insert(NLog.Layouts.Layout key, string value, bool add) + 0x1e0 bytes     
NLog.dll!NLog.LogEventInfo.AddCachedLayoutValue(NLog.Layouts.Layout layout, string value) + 0x6c bytes   
NLog.dll!NLog.Layouts.Log4JXmlEventLayout.GetFormattedMessage(NLog.LogEventInfo logEvent) + 0xf5 bytes   
NLog.dll!NLog.Targets.Target.PrecalculateVolatileLayouts(NLog.LogEventInfo logEvent) + 0xb8 bytes    
NLog.dll!NLog.Targets.Wrappers.AsyncTargetWrapper.Write(NLog.Common.AsyncLogEventInfo logEvent) + 0x23 bytes     
NLog.dll!NLog.Targets.Target.WriteAsyncLogEvent(NLog.Common.AsyncLogEventInfo logEvent) + 0x151 bytes    
NLog.dll!NLog.LoggerImpl.WriteToTargetWithFilterChain(NLog.Internal.TargetWithFilterChain targetListHead, NLog.LogEventInfo logEvent, NLog.Common.AsyncContinuation onException) + 0x8b bytes    
NLog.dll!NLog.LoggerImpl.Write(System.Type loggerType, NLog.Internal.TargetWithFilterChain targets, NLog.LogEventInfo logEvent, NLog.LogFactory factory) + 0xee bytes    
NLog.dll!NLog.Logger.WriteToTargets(NLog.LogLevel level, string message, object[] args) + 0x14 bytes     
NLog.dll!NLog.Logger.Debug<Werp.Controller.Common.Interfaces.EntityEventAction,System.__Canon>(string message, Werp.Controller.Common.Interfaces.EntityEventAction argument1, System.__Canon argument2) + 0x8d bytes     
... <my app code> ...

この状況は、1 週間に 1 回程度の頻度で発生しますが、これを再現するための正確なシナリオはありません。

どうすればこれを修正できますか? NLogのバグですか、それとも私の誤用または設定ミスですか?

score 1 · Accepted Answer

私は最近同じ問題に遭遇しました - 多くのスレッドがブロックしていWriteAsyncLogEventます。Dictionaryしかし、スレッドはありませんでした。AsyncRequestQueue.Enqueueスレッドリストに表示されていないスレッドが 1 つありました。

私の場合、問題はoverflowActiononAsyncWrapperが... に設定されていることでしたBlock! Discardオーバーロードされたロガーに対処するには、これをに設定する方がはるかに賢明な方法です。

NLog 自体に問題がないために、ログメッセージが蓄積されることがあります。場合によっては、他の理由 (ディスクのブロック、大量のスワッピング、ウイルス対策の混乱、完全な GC) でプロセスが停止することがあります。スレッドリストには、NLog がたまたま同じオーバーロードされたリソースに依存しているため、NLog でスタックしているスレッドが多数含まれています。