Why does NLog miss some messages when logging a large number of messages?

Question

I try to test NLog performance (latest version) with settings:

<?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">
    <variable name="basePath" value="c:\logs\" />
    <variable name="msgFormat" value="${message}" />
    <targets async="true">
        <target name="file"
                xsi:type="File"
                fileName="${basePath}/${logger}/${date:format=yyyy}/${date:format=MMMM}/log-${date:format=yyMMdd}-${level}.log"
                layout="${msgFormat}"
                concurrentWrites="true" />
    </targets>
    <rules>
        <logger name="*" minlevel="Debug" writeTo="file"/>
    </rules>
</nlog>

and run this code:

var msg = "this is example string for logging test. it's not very long, but not very short";
var count = 20000;
Parallel.For(0, count, x => nlog.Info(msg));

NLog writes to file, but when file size reaches 1MB it stops writing. I try to use simple for loop, but it doesn't helped me. And i try to use internal logging, but there is no errors, by the way i see there this strings:

2013-04-01 11:36:18.2458 Trace Opening c:\logs/NLogTest/2013/April/log-130401-Info.log with concurrentWrite=False

It's very strange, because concurrentWrites default value is true, furthermore I've set this value in config.

Answer 1

The problem lies in the default value of the AsyncWrappers QueueLimit, which is 10000.

The value determines how big the queue of messages to write are allowed to be, the problem arises because all 20000 messages are queued before anything is written to the file, which causes NLog to discard the last 10000 messages.

Unfortunately this cannot be changed when using the async attribute, you have to define the AsyncWrapper manually to be able to control the QueueLimit, which is done 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">
    <variable name="basePath" value="c:\logs\" />
    <variable name="msgFormat" value="${message}" />
    <targets async>
        <target name="asyncWrapper" xsi:Type="AsyncWrapper" queueLimit="20000">
            <target name="file"
                xsi:type="File"
                fileName="${basePath}/${logger}/${date:format=yyyy}/${date:format=MMMM}/log-${date:format=yyMMdd}-${level}.log"
                layout="${msgFormat}"
                concurrentWrites="true" />
       </target>
    </targets>
    <rules>
        <logger name="*" minlevel="Debug" writeTo="file"/>
    </rules>
</nlog>

Where QueueLimit is set to 20000.

You could also changed the OverflowAction if you need to do something other the discard messages not put in the queue, see AsyncWrapper documentation for more information. The options are Block, Discard or Grow.