Should NLog flush all queued messages in the AsyncTargetWrapper when Flush() is called?

Question

I want to shut down my application and write any pending log messages. So I call LogManager.Flush() during my shutdown process. However, I don't see all the messages written out. Instead, if I wait for a few seconds (using Thread.Sleep()) I see the messages.

After examining NLog's code on GitHUB, I find the AsyncTargetWrapper.FlushAsync() method is only scheduling the lazy writer thread to write all pending messages on the next batch. It is not writing log messages synchronously.

Is this the expected behaviour? I'm expecting LogManager.Flush() to be synchronous, ie: to block until all pending messages are written (or the timeout is exceeded).

---

Code I use on shutdown:

LogManager.Flush(ex => { }, TimeSpan.FromSeconds(15));

And then the code to initialise Nlog (this is a Silverlight app, so I'm not using any config files).

    public static void InitialiseNLog(LogLevel forLevel)
    {
        var config = new LoggingConfiguration();

        // Add targets.
        // We need an async target wrapping a custom web service call back to the server.
        var serverTarget = new RemoteServiceTarget();
        var asyncWrapper = new AsyncTargetWrapper(serverTarget, 10000, AsyncTargetWrapperOverflowAction.Discard);
        asyncWrapper.TimeToSleepBetweenBatches = (int)TimeSpan.FromSeconds(2).TotalMilliseconds;
        asyncWrapper.BatchSize = 200;

        // Add rules.
        var rule = new LoggingRule("Company.Application.SilverlightApp.*", forLevel, asyncWrapper);
        config.LoggingRules.Add(rule);

        // Activate the configuration.
        LogManager.Configuration = config;
        LogManager.GlobalThreshold = forLevel;
    }

Answer 1

The comment by ligos is on the right track. The AsyncTargetWrapper.CloseTarget() method was modified as a result of NLog issue 134, where a nested BufferingTargetWrapper wasn't getting flushed on domain unload.

LogManager.Shutdown() does indeed force the AsyncTargetWrapper to effectively flush synchronously but it would have to be used after LogManager.Flush() because targets such as the BufferingTargetWrapper don't actually flush on close. It may be better to set LogManager.Configuration = null as this performs a flush and then closes the targets in one hit and the configuration will be reloaded (if using configuration file) next time it needs to be used.

I've tested both and I have gone with the latter as I am wanting my logging back up and running after I've put things right, but given the question is in Silverlight I would recommend:

LogManager.Flush();
LogManager.Shutdown();

Edit

LogManager sets the config to null on domain unload or process exit so we shouldn't be seeing this problem unless running an old NLog version. The NLog issue was fixed in Oct 2012. Have tested without explicit shutdown or setting config to null and can confirm that calling LogManager.Flush() is enough.

Answer 2

Flagrantly stolen from: Buffering log messages in NLog and manually flushes them to target

LogManager.Configuration.AllTargets
.OfType<BufferingTargetWrapper>()
.ToList()
.ForEach(b => b.Flush(e =>
    {
        //do nothing here
    }));