Nlog: The process cannot access the file because it is being used by another process.

[DumboJet]

Type (choose one):

• Bug

NLog version:
4.5.6

Platform:
.Net 4.5

Current NLog config (xml or C#, if relevant)

  <nlog autoReload="true" throwExceptions="true" internalLogFile="F:\webapplogs\Nloglog.log" internalLogLevel="Warn" xmlns="http://www.nlog-project.org/schemas/NLog.xsd" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
    <variable name="acdatasource" value="Data Source=..........." />
    <variable name="aclogDirectory" value="F:\webapplogs\/logs" />
    <variable name="message_one_line" value="${replace:inner=${message}:searchFor=\\r\\n|\\r|\\n:replaceWith=\xB6:regex=true}" />
    <!--Pilcrow = "\xB6";-->
    <variable name="exception_one_line" value="${replace:inner=${exception:format=tostring}:searchFor=\\r\\n|\\r|\\n:replaceWith=\xB6:regex=true}" />
    <!--Pilcrow = "\xB6";-->
    <variable name="exception_and_message_with_level" value="${longdate} =&gt; (${uppercase:${level}}) | ${callsite} : ${message_one_line} | ${exception_one_line}" />
    <targets>
      <target name="logfile" type="File" fileName="${aclogDirectory}/${shortdate}.${logger}.Worker.Tracing.log" layout="${exception_and_message_with_level}" />
      <target name="console" type="Console" layout="${message}" />
      <target name="database" type="Database" connectionString="${acdatasource}" commandText="exec dbo.Errors_Insert @ErrDate,@ErrUser,@LogLevel,@ErrOrganization,@ErrMessage,@ErrInnerException,@ErrCallsite">
        <parameter name="@ErrDate" layout="${date:format=yyyy-MM-dd HH\:mm\:ss}" />
        <parameter name="@ErrUser" layout="Worker" />
        <parameter name="@LogLevel" layout="${level}" />
        <parameter name="@ErrOrganization" layout="Worker" />
        <parameter name="@ErrMessage" layout="${message}" />
        <parameter name="@ErrInnerException" layout="${exception:format=ToString}" />
        <parameter name="@ErrCallsite" layout="${callsite}" />
      </target>
    </targets>
    <rules>
      <logger name="*" minLevel="Trace" appendTo="logfile" />
      <logger name="*" minLevel="Error" appendTo="database" />
    </rules>
  </nlog>

We use NLog 4.5.6 and we spawn many (10+) instances of the same executable, all of which write on the same log files.
This used to work since yesterday, but today I get this:

The process cannot access the file because it is being used by another process. (Exception from HRESULT: 0x80070020) ---> System.IO.FileLoadException: The process cannot access the file because it is being used by another process. (Exception from HRESULT: 0x80070020)   at System.Runtime.InteropServices.Marshal.ThrowExceptionForHRInternal(Int32 errorCode, IntPtr errorInfo)   at NLog.Internal.FileAppenders.BaseFileAppender.WindowsCreateFile(String fileName, Boolean allowFileSharedWriting)   at NLog.Internal.FileAppenders.BaseFileAppender.TryCreateFileStream(Boolean allowFileSharedWriting)   at NLog.Internal.FileAppenders.BaseFileAppender.CreateFileStream(Boolean allowFileSharedWriting)   at NLog.Internal.FileAppenders.RetryingMultiProcessFileAppender.Write(Byte[] bytes, Int32 offset, Int32 count)   at NLog.Targets.FileTarget.WriteToFile(String fileName, LogEventInfo logEvent, ArraySegment`1 bytes, Boolean justData)   at NLog.Targets.FileTarget.ProcessLogEvent(LogEventInfo logEvent, String fileName, ArraySegment`1 bytesToWrite)   at NLog.Targets.FileTarget.Write(LogEventInfo logEvent)   at NLog.Targets.Target.Write(AsyncLogEventInfo logEvent)   at NLog.Targets.Target.WriteAsyncThreadSafe(AsyncLogEventInfo logEvent)   at NLog.Targets.Target.WriteAsyncLogEvent(AsyncLogEventInfo logEvent)   at NLog.LoggerImpl.WriteToTargetWithFilterChain(TargetWithFilterChain targetListHead, LogEventInfo logEvent, AsyncContinuation onException)   at NLog.LoggerImpl.Write(Type loggerType, TargetWithFilterChain targets, LogEventInfo logEvent, LogFactory factory)   at NLog.Logger.WriteToTargets(LogLevel level, IFormatProvider formatProvider, String message)   at NLog.Logger.Info(String message)

Not sure why this appeared all of the sudden. :^)
Maybe there are more EXE instances logging at the same time.

Any insights on how the write synchronization works in NLog, that might help us identify the problem?
Is there a "lock file" or something like that?
Hm... I see now in the main log that it tries to open the file and it retries with a delay when it fails.

[snakefoot]

Well first of all then you should not use throwExceptions="true". It is only for unit-testing and for local testing. It causes all kinds of unexpected behavior, which is unwanted in a production environment.

When using keepFileOpen="false" with concurrentWrites="true", then it uses the standard exclusiv-file-lock in the operating system. This means only one process can write to the file, while the others get the error cannot access the file because it is being used by another process, which is perfectly normal (will automatically retry). The retry mechanism controlled by concurrentWriteAttempts. See also https://github.com/nlog/NLog/wiki/File-target

When running full NetFramework on Windows, then one can configure keepFileOpen="true" AND concurrentWrites="true". Then it will activate a special mode where it performs atomic file-writes, without using exclusive-file-locks (faster and without any exceptions).

[DumboJet]

Thank you! :)
This information has helped me fix the problem. :)