Nlog: Write console messages in UnitTests output window with async logging

[AFract]

Hello,

This is more a remark rather and not a bug report, as I found how to fix it.
Additionally I hope it will be useful for anybody who will encounter the same problem, as I took a few time to figure this.
My remark is related to unit testing with Resharper (but it could also concern other UT tools)

When I call directly Console.WriteLine, the message appears as expected in Resharper Unit test output window, everything is fine.
But if I use Logger.Info (or another method), message are not displayed, even with a Console or ColoredConsole target.
```c#

[TestFixture]
public class DALTests
{
    private static readonly Logger Logger = LogManager.GetCurrentClassLogger();
    [Test]
    public void MessageTest()
    {
        Console.WriteLine("This message is displayed as expected in R#");
        Logger.Info("This message does not appear in R# unit test");
    }
}

Nlog configuration :
```xml
  <targets async="true">
    ........ Various targets (file system, etc) .......
    <target name="console" xsi:type="Console"/>
  </targets>
  <logger name="*" minlevel="Debug" writeTo="....,console" />

I also tried ColoredConsole.

I am using this setup to run unit tests :

• VS 2010, .Net 4.0 test project
• Resharper 2016.3.2 unit test runner
• NLog 4.4.4
  (- NUnit 3.6.1)

I noticed it's ok if I remove the "async=true", or if I force flushing (which is not very neat to do after each test), so it works.

But is there a way to easily have async logging and console target at the same time ? Maybe using an async wrapper ?

Thank you for your advice

[304NotModified]

Thanks for the report!

Why you need async logging inside a unit test? And why to console?

[AFract]

Hello,
Good question :)
In fact some of the tests may trigger a lot of disk writes through their logger, and to get accurate measurements of performance of what they do without to be affected by logging times, I enabled async writes.
Along them, I have some test which are writing only a few messages, which I would like to be able to see in unit test output console.
I understand this is not a good setup, especially for a simple unit test project. If course I can simply just disable async logging as it fixes my problem.
But I was wondering why it was behaving like this for console and if it can be considered as a potential improvement for a future release to make messages visibles even when async logging is enabled.
Thank you

[304NotModified]

OK

I don't think we could solve this, without an flush.

Another option would be to log to a memorytarget, which is really fast.
https://github.com/nlog/nlog/wiki/Memory-target

[snakefoot]

@AFract Instead of using async=true then I recommend doing this (Much faster and will not discard messages):

 <targets>  
    <default-wrapper xsi:type="AsyncWrapper" overflowAction="Block" timeToSleepBetweenBatches="0" />  
    <target name="console" xsi:type="Console"/>
  </targets>  

Also update from NLog 4.4.4 to NLog 4.4.5 (Fixes a bug with missing flush on shutdown).

If it still doesn't work, then you can consider have two targets-groups. One that is async (with filetargets) and one sync (with console):

 <targets>  
    <default-wrapper xsi:type="AsyncWrapper" overflowAction="Block" timeToSleepBetweenBatches="0" />  
    <target name="file" xsi:type="File"/>
  </targets>
 <targets>  
    <target name="console" xsi:type="Console"/>
  </targets>

If this also doesn't work, then put a flush-statement in you unit-test-cleanup-method.

[AFract]

Hello,
Thank you very much for your advices.
I was not aware it was possible to have two distincts sections, I thought it was supposed to be unique with all different targets inside. I'll also migrate to 4.4.5 ASAP, thanks for the notification.
And thank you very much for NLog, I'm very glad to use it since a lot of years on all my projects.

[304NotModified]

I assume your question has been answered, if not, let us know!