2017-07-21 3 views
0

J'utilise Log4net pour enregistrer l'activité et après analyse de la trace de la pile de perfmon je vois qu'il ya une impasse comme scénario illustré ci-dessousLog4net provoquant fil à bloquer

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 

J'initialiser le enregistreur

Que peut-on faire pour éviter ce scénario?
private static readonly ILog logger = LogManager.GetLogger(typeof(Program)); 

J'ai passé en revue une option pour ajouter par journal de fil. Mais, ce sera une surpuissance car j'aurai 100 journaux par jour.

Ce qui suit est la configuration 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> 

+0

Bien sûr que vous utilisez NLog et non pas log4net, puisque log4net fait partie de votre stacktrace? –

+0

@RolfKristensen oui, j'utilise Log4Net. Changé le titre – user2526236

+0

Quelle est la configuration de l'appender? – Peter

Répondre

0

Juste une supposition sur ce qui se passe, pour une raison quelconque les journaux \ logfile.txt est verrouillé lorsque vous voulez écrire à la fichier. Un deuxième message de journal attendra jusqu'à ce que les premiers messages de journal soient terminés (votre stacktrace). Le verrouillage minimal ne vous aidera pas ici car vous devez toujours verrouiller le fichier. Lorsque vous souhaitez accéder au fichier journal, vous devez d'abord le copier, puis ouvrir la version copiée du fichier journal avec l'outil d'inspection. De cette façon, vous êtes sûr que vous ne bloquez pas le processus qui veut se connecter au fichier journal.

+0

Va ajouter un verrou/moniteur pour chaque enregistreur .InfoFormat ("Message à enregistrer") aide. Cela entraînera-t-il des problèmes de performance. – user2526236

+0

Vous obtiendrez la même condition de relance si le fichier est verrouillé – Peter

+0

Comment puis-je résoudre cette condition de course? toutes les suggestions – user2526236