NLog FileTarget wrapped with BufferingTargetWrapper fails to write log if there is a delay

[Nick Blair]

I have written up the issue on Stack Overflow in detail, so just bringing it to your attention:

http://stackoverflow.com/questions/14226353/nlog-filetarget-wrapped-with-bufferingtargetwrapper-fails-to-write-log-if-there

Thanks

[Kim Christensen]

Thanks, I'll look into to this issue

[Kim Christensen]

Have you tried to enable the internal NLog logging, as described here https://github.com/NLog/NLog/wiki/Logging-troubleshooting? Could help locating the error

Den onsdag den 9. januar 2013 14.04.56 UTC+1 skrev Nick Blair:

[Kim Christensen]

I can't seem to reproduce the error following the steps described on StackOverflow. Could you post a sample project able to reproduce the error when modifying FileTarget?

Den onsdag den 9. januar 2013 14.04.56 UTC+1 skrev Nick Blair:

[Nick Blair]

I have created a github repo to highlight the problem: https://github.com/blair55/NLog

The only changes made are:

1. Added a 'ConsoleApp' project to the NLog.netfx40 solution in the src folder that you should set as your Start Up project. This is just to apply the Buffer Wrapper Target through the NLog settings in the app.config file, and to write some log lines in the Main method.
   
2. Inserted a new line at line 725 of src\Targets\FileTarget.cs inside the Write method. The line contains a Thread.Sleep to mimic a blocking call that can be expected in other targets e.g. MailTarget.

If you now run the start up Console App project the log does not get written. If you comment out the Thread.Sleep, the log will be written.

As mentioned, the reason I spotted this was because I am writing to a BufferTarget that wraps a MailTarget. When the BufferTarget flushes, sometimes the MailTarget will hang when connecting to the mail server, this therefore causes the Log not to be written.

Hope that's all clear!

[Kim Christensen]

Thanks, I'll take a look and return with my findings

[Kim Christensen]

I have finally figured out why nothing is being logged, unfortunately there is not much that can be done about this.

According to the MSDN documentation for AppDomain.ProcessExit, which is the event handled by NLog:

The total execution time of all ProcessExit event handlers is limited, just as the total execution time of all finalizers is limited at process shutdown. The default is two seconds. An unmanaged host can change this execution time by calling the ICLRPolicyManager::SetTimeout method with the OPR_ProcessExit enumeration value.

So it seems the only way to handle this from managed code, is to manually call LogManager.Flush() before allowing the application to exit.

[Nick Blair]

Thanks Kim, makes sense now.

Although, I am still making the call below to flush the BufferMailWrapper before the program exits.

var target = LogManager.Configuration.FindTargetByName("buffermailwrapper") as BufferingTargetWrapper;

if (target != null)

{

    target.Flush(e => { });

}

Would have thought this would achieved the same as LogManger.Flush()? I'll change it and see what happens anyhow.

Thanks for your all your help!