log4Net 导致线程被阻塞

Question

我正在使用 log4Net 记录活动，在分析来自 perfmon 的堆栈跟踪后，我看到有如下所示的死锁场景

    ntdll!NtWaitForMultipleObjects+a
    KERNELBASE!WaitForMultipleObjectsEx+e1
    clr!WaitForMultipleObjectsEx_SO_TOLERANT+62 
    clr!Thread::DoAppropriateWaitWorker+1e4 
    clr!Thread::DoAppropriateWait+7d 
    clr!CLREventBase::WaitEx+c4
    clr!AwareLock::EnterEpilogHelper+ca
    [[GCFrame]] 
    clr!AwareLock::EnterEpilog+62 
    clr!AwareLock::Contention+2a7f4a
    clr!JITutil_MonContention+af
    [[GCFrame]] 
    [[HelperMethodFrame] (System.Threading.Monitor.Enter)] System.Threading.Monitor.Enter(System.Object) 
    log4net.Appender.AppenderSkeleton.DoAppend(log4net.Core.LoggingEvent)+47 
    log4net.Util.AppenderAttachedImpl.AppendLoopOnAppenders(log4net.Core.LoggingEvent)+a8
    log4net.Repository.Hierarchy.Logger.CallAppenders(log4net.Core.LoggingEvent)+74 
    log4net.Repository.Hierarchy.Logger.Log(System.Type, log4net.Core.Level, System.Object, System.Exception)+6a
    log4net.Core.LogImpl.InfoFormat(System.String, System.Object)+cc
    Archival.Logic.Status(Archival.ProcessArgs)+240 
    Archival.Logic.Product(Archival.ProcessArgs)+221 
    Archival.Logic.Number(Archival.ProcessArgs, System.Collections.Generic.IEnumerable`1<LenderProduct>)+2e9 
    Archival.Logic+<>c__DisplayClass3_0.<ArchiveDealsPerAsset>b__1(System.String)+b5
    mscorlib_ni!System.Threading.Tasks.Parallel+<>c__DisplayClass42_0`2[[System.__Canon, mscorlib],[System.__Canon, mscorlib]].<PartitionerForEachWorker>b__1()+2bd
    mscorlib_ni!System.Threading.Tasks.Task.InnerInvokeWithArg(System.Threading.Tasks.Task)+20 
    mscorlib_ni!System.Threading.Tasks.Task+<>c__DisplayClass176_0.<ExecuteSelfReplicating>b__0(System.Object)+114 
    mscorlib_ni!System.Threading.Tasks.Task.Execute()+46 
    mscorlib_ni!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)+162 
    mscorlib_ni!System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)+14 
    mscorlib_ni!System.Threading.Tasks.Task.ExecuteWithThreadLocal(System.Threading.Tasks.Task ByRef)+21c
    mscorlib_ni!System.Threading.Tasks.Task.ExecuteEntry(Boolean)+73 
    mscorlib_ni!System.Threading.ThreadPoolWorkQueue.Dispatch()+152 
    clr!CallDescrWorkerInternal+83 
    clr!CallDescrWorkerWithHandler+4e 
    clr!MethodDescCallSite::CallTargetWorker+f8
    clr!QueueUserWorkItemManagedCallback+2a
    clr!ManagedThreadBase_DispatchInner+39 
    clr!ManagedThreadBase_DispatchMiddle+6c
    clr!ManagedThreadBase_DispatchOuter+75 
    [[DebuggerU2MCatchHandlerFrame]] 
    clr!ManagedThreadBase_FullTransitionWithAD+2f 
    clr!ManagedPerAppDomainTPCount::DispatchWorkItem+a0
    clr!ThreadpoolMgr::ExecuteWorkRequest+64 
    clr!ThreadpoolMgr::WorkerThreadStart+f5
    clr!Thread::intermediateThreadProc+86 
    kernel32!BaseThreadInitThunk+22 
    ntdll!RtlUserThreadStart+34 

我初始化记录器

private static readonly ILog logger = LogManager.GetLogger(typeof(Program));

可以做些什么来避免这种情况。 我已经查看了添加每个线程日志的选项。但是，这将是一个过度杀伤，因为我每天将有 100 个日志。

以下是log4Net的配置：

<log4net>
<appender name="ColoredConsoleAppender" type="log4net.Appender.ColoredConsoleAppender">
  <mapping>
    <level value="ERROR"/>
    <foreColor value="White"/>
    <backColor value="Red"/>
  </mapping>
  <mapping>
    <level value="WARN"/>
    <foreColor value="White"/>
    <backColor value="Yellow"/>
  </mapping>
  <layout type="log4net.Layout.PatternLayout">
    <conversionPattern value="%date [%thread] - %message%newline"/>
  </layout>
  <filter type="log4net.Filter.LevelRangeFilter">
    <levelMin value="INFO"/>
  </filter>
</appender>
<appender name="RollingLogFileAppender" type="log4net.Appender.RollingFileAppender">
  <file value="Logs\logfile.txt"/>
  <appendToFile value="true"/>
  <rollingStyle value="Date"/>
  <datePattern value="yyyyMMdd"/>
  <maxSizeRollBackups value="3"/>
  <layout type="log4net.Layout.PatternLayout">
    <conversionPattern value="%date [%thread] %-5level - %message%newline"/>
  </layout>
  <filter type="log4net.Filter.LevelRangeFilter">
    <levelMin value="INFO"/>
  </filter>
</appender>
<root>
  <level value="ALL"/>
  <appender-ref ref="ColoredConsoleAppender"/>
  <appender-ref ref="RollingLogFileAppender"/>
</root>

Answer 1

只是猜测发生了什么，由于某种原因，当您要写入文件时，Logs\logfile.txt 被锁定。第二条日志消息将等到第一条日志消息完成（您的堆栈跟踪）。最小锁定在这里对您没有帮助，因为您仍然需要锁定文件。当您要访问日志文件时，您需要先复制它，然后使用检查工具打开复制的日志文件版本。这样您就可以确定您不会阻止想要记录到日志文件的进程。