1
votes

NLog didn't log every log messages with asynchronous rolling file logger configurations.

Following is my NLog.config xml.

<?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"
      xsi:schemaLocation="http://www.nlog-project.org/schemas/NLog.xsd NLog.xsd"
      autoReload="true"
      throwExceptions="false"
      internalLogLevel="Off" internalLogFile="c:\temp\nlog-internal.log" >

  <targets async="true">
      <target name="logfile" xsi:type="File" fileName="logs/log.txt" 
              maxArchiveFiles="10" 
              archiveAboveSize="1048576" 
              archiveNumbering="Sequence" 
              concurrentWrites="true" 
              archiveFileName="logs/log.{####}.txt"/>
    </target>
  </targets>

  <rules>
    <logger name="*" minlevel="Debug" writeTo="logfile" />
  </rules>
</nlog>

And the following is my code.

    private static Logger log = LogManager.GetCurrentClassLogger();
    Stopwatch sw = new Stopwatch();

    public Form1()
    {
        InitializeComponent();
        LogManager.ReconfigExistingLoggers();
    }

    private void button1_Click(object sender, EventArgs e)
    {
        string toLog;
        sw.Start();
        for (int i = 0; i < 100000; i++)
        {
            toLog = "Message:" + i.ToString();
            log.Debug(toLog);
        }
        sw.Stop();
        string s = "STOP :" + sw.Elapsed.ToString();
        log.Debug(s);
    }

I only get one file as the result and some log entries are missing. Following is the resulting log.txt file.

2015-10-16 12:04:08.9865|DEBUG|NLogAsync.Form1|Message:11591
2015-10-16 12:04:08.9865|DEBUG|NLogAsync.Form1|Message:11592
2015-10-16 12:04:08.9865|DEBUG|NLogAsync.Form1|Message:11593
2015-10-16 12:04:08.9865|DEBUG|NLogAsync.Form1|Message:11594
2015-10-16 12:04:09.0802|DEBUG|NLogAsync.Form1|Message:80436
2015-10-16 12:04:09.0802|DEBUG|NLogAsync.Form1|Message:80437
2015-10-16 12:04:09.0802|DEBUG|NLogAsync.Form1|Message:80438
2015-10-16 12:04:09.0802|DEBUG|NLogAsync.Form1|Message:80439

However when i remove the async attribute, the code is running properly.

1

1 Answers

4
votes

<targets async="true"> is just a shorthand for wrapping all your targets with AsyncWrapper target. I.e. your configuration is equivalent to:

<targets>
  <target name="logfile" xsi:type="AsyncWrapper">
    <target xsi:type="File" fileName="logs/log.txt"
            maxArchiveFiles="10"
            archiveAboveSize="1048576"
            archiveNumbering="Sequence"
            concurrentWrites="true"
            archiveFileName="logs/log.{####}.txt"/>
  </target>
</targets>

This async wrapper will use default settings. Most important for you are queueLimit which is 10000 by default, and overflowAction which is Discard by default. What does it mean? After writer thread has more than 10000 log messages in queue all new log messages just discarded. So simplest way to make sure all your log messages will be processed is changing default overflowAction value to Grow. But you need to specify AsyncWrapper manually for that:

<targets>
  <target name="logfile" xsi:type="AsyncWrapper" overflowAction="Grow">
    <target xsi:type="File" fileName="logs/log.txt"
            maxArchiveFiles="10"
            archiveAboveSize="1048576"
            archiveNumbering="Sequence"
            concurrentWrites="true"
            archiveFileName="logs/log.{####}.txt"/>
  </target>
</targets>