I'm developing API where I use NLog for logging incoming requests and their responses. Occasionally I'm getting following error on my server
Application: w3wp.exe
Framework Version: v4.0.30319
Description: The process was terminated due to an unhandled exception.
Exception Info: System.IO.FileLoadException
at System.Runtime.InteropServices.Marshal.ThrowExceptionForHRInternal(Int32, IntPtr)
at NLog.Internal.FileAppenders.BaseFileAppender.WindowsCreateFile(System.String, Boolean)
at NLog.Internal.FileAppenders.BaseFileAppender.TryCreateFileStream(Boolean)
at NLog.Internal.FileAppenders.BaseFileAppender.CreateFileStream(Boolean)
at NLog.Internal.FileAppenders.RetryingMultiProcessFileAppender.Write(Byte[])
at NLog.Targets.FileTarget.WriteToFile(System.String, NLog.LogEventInfo, Byte[], Boolean)
at NLog.Targets.FileTarget.ProcessLogEvent(NLog.LogEventInfo, System.String, Byte[])
at NLog.Targets.FileTarget.FlushCurrentFileWrites(System.String, NLog.LogEventInfo, System.IO.MemoryStream, System.Collections.Generic.List`1<NLog.Common.AsyncContinuation>)
at NLog.Targets.FileTarget.Write(NLog.Common.AsyncLogEventInfo[])
at NLog.Targets.Target.WriteAsyncLogEvents(NLog.Common.AsyncLogEventInfo[])
at NLog.Targets.Wrappers.AsyncTargetWrapper.ProcessPendingEvents(System.Object)
at System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
at System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
at System.Threading.TimerQueueTimer.CallCallback()
at System.Threading.TimerQueueTimer.Fire()
at System.Threading.QueueUserWorkItemCallback.System.Threading.IThreadPoolWorkItem.ExecuteWorkItem()
at System.Threading.ThreadPoolWorkQueue.Dispatch()
My nlog.config
looks like this
<?xml version="1.0" encoding="utf-8" ?>
<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" autoReload="true" throwExceptions="true">
<variable name="logPath" value="${basedir}/App_Data/Logs"/>
<variable name="rowFormatInfo" value="${longdate} | ${level:uppercase=true} | ${message} | Thread: ${threadid}" />
<targets async="true">
<target name="traceFile" xsi:type="AsyncWrapper" overflowAction="Grow">
<target xsi:type="File" fileName="${logPath}/${shortdate}.trace.log" layout="${rowFormatInfo}" />
</target>
</targets>
<rules>
<logger name="*" minlevel="Trace" maxlevel="Debug" writeTo="traceFile" />
</rules>
</nlog>
In my opinion the problem lies with the fact that I'm using async wrapper which can result into mix of several threads trying to access the log file. Is there any workaround to prevent such errors occurring in the peak times where my API has to deal with tens of requests per second? I don't think that switching to sync logging helps as the API runs in several concurrent threads itself.
Thanks for suggestions
Multiple threads within the same application should not give any issues, as they will just write to the async-queue (and not the file). But if you have multiple applications writing to the same file, then you can get issues.
You can also get this issue if you have an external application can monitors the log-file and tries to copy the contents somewhere else (Ex. SPLUNK).
If you don't have multiple applications writing to the same file, then just add these options to the file-target:
<target xsi:type="File"
fileName="${logPath}/${shortdate}.trace.log"
layout="${rowFormatInfo}"
keepFileOpen="true"
concurrentWrites="false" />
If you do have multiple Applications/AppDomains writing to the same file, then upgrade to latest NLog (currently 4.4.10) and use these options on the file-target:
<target xsi:type="File"
fileName="${logPath}/${shortdate}.trace.log"
layout="${rowFormatInfo}"
keepFileOpen="true"
concurrentWrites="true" />