Console output from application is logged as warnings

[ravigneaux-1]

Summary

When writing console output from the application under test, the output is displayed as a warning in the Visual Studio Test Explorer. This holds true both for the standard output stream (Console.Out.Write()) as well as for the standard error stream (Console.Error.Write()).

internal class Program
{
    internal static void Main(string[] args)
    {
        Console.WriteLine("Hello, World!");
        Console.Error.WriteLine("Hello, error stream!");
    }
}

Steps to reproduce

1. Create a .NET console application project ("MyApp")
2. Change the protection level of the Main method from implicit private to internal
3. Write to the standard output and/or standard error stream from within the Main method
4. Create an NUnit test project ("MyApp.Tests")
5. Add a project reference from the test project to the application project
6. Make internals of the application project visible to the test project by editing MyApp.csproj:

   <ItemGroup>
     <InternalsVisibleTo Include="MyApp.Tests"/>
   </ItemGroup>

7. Add invocation of the Main method to the default test case:

   [Test]
   public void Test1()
   {
       Program.Main(new string[] { });
       Assert.Pass();
   }

8. Run the tests in Visual Studio's Test Explorer
9. Observe the reported warning(s) in the Test Explorer

Version information

• NUnit 3.13.3
• NUnit3TestAdapter 4.4.2
• Visual Studio Community 2022 (64-bit), version 17.5.0
• Target framework: .NET 6.0

[OsirisTerje]

This is done by the Test Explorer, not the adapter. They do show this as a warning, as it is regarded as "wrong" to do console output in a test. In your particular case it is the SUT that outputs to the Console, and one can argue that it should be possible to turn that off, but you can't. On the other side, the Console output could have been mocked off, using something like : https://www.nuget.org/packages/WrapThat.System#readme-body-tab and info here https://hermit.no/wrapthat-system-wrappers-for-system-io-to-simplify-unit-testing/

[ravigneaux-1]

@OsirisTerje, thank you very much for pointing out WrapThat and sorry to bother you again 😅 But I have tried the same with MSTest now and it doesn't seem to interpret console output as warnings:

internal class Program
{
    internal static void Main(string[] args)
    {
        Console.WriteLine("Hello, World!");
        Console.Error.WriteLine("Hello, error stream!");
    }
}

[TestClass]
public class UnitTest1
{
    [TestMethod]
    public void TestMethod1()
    {
        Program.Main(new string[] { });
        Assert.IsTrue(true);
    }
}

So, can we really be sure that the issue I observed is not related to NUnit? 😅

[OsirisTerje]

That was weird. I'll check this out! Thanks for checking this with MSTest.

[OsirisTerje]

@Ravigneaux1 Can I bother you with creating a small repro solution containing both a NUnit and a MSTest project ?
You can just add it as a zip here, or add it to the NUnit3-vs-adapter.issues repo.

[ravigneaux-1]

@OsirisTerje, sure thing! I've just created pull request #6. Please let me know if it doesn't meet your requirements.

[OsirisTerje]

This is actually the result of a "feature" in NUnit. NUnit has a configurable console output. MSTest doesn't seem to have the same (or I haven't found it).
The configuration is in the runsettings, and documented here: https://docs.nunit.org/articles/vs-test-adapter/Tips-And-Tricks.html#consoleout

NUnit has the following default setup:

Notice it outputs both in the test results (2) and in the test output console pane (3). MSTest only outputs in (2).
Given the ConsoleOut=2 it will output both standard console output and error stream, and the console output as a Warning.
Given the ConsoleOut=1, it will still output both, but the console out will be output as Information.
This doesnt make much difference in Visual Studio, except one of the warnings disappear from the Warning alert.
But in a console scenario, and thus in CI builds it makes a difference:

Note that the console output is now gone. This was a concern for many, so that is why the default is set to 2.
You can get it out,. but then you need to add a console logger dotnet test -l "console;verbosity=normal -- NUnit.ConsoleOut=1
Adding a logger to the MSTest and running with dotnet test -l "console;verbosity=normal doesn't give any output.
I see this has been reported too: https://learn.microsoft.com/en-us/answers/questions/212062/how-to-view-log-output-while-tests-are-running-in.

If you set the ConsoleOut=0 nothing should come out, but it seems the error message still comes out. That seems to be a bug though. I'll add a separate bug for that. This issue is useful as it is.

[ravigneaux-1]

@OsirisTerje, oh my, silly me was actually aware of the ConsoleOut setting (I'm already using a .runsettings file for test execution in the command line) but I didn't see the connection to the Test Explorer. I wanted to avoid having another .runsettings file for execution in the Test Explorer, but maybe there's no way around that 😕

Anyway, thanks for pointing me in the right direction! <ConsoleOut>1</ConsoleOut> does solve the problem for me.

I never really understood why sending the application's output to the standard error stream is the default, though. Should default to the standard output stream (value 1) in my opinion, not only because of the side effects the standard error stream causes...

[OsirisTerje]

I think the reason is historical. There was something many years ago that only error streams were displayed, so that started it. And in order not to break people who used that to get stuff into their CI logs, we kept it that way, but added the ConsoleOut. The default however, should have been changed, as you point out, so next breaking version I'll get that done :-)

[OsirisTerje]

Bugs and changes created, see #1109 and #1110 , so closing this

[OsirisTerje]

@ravigneaux-1 Fixed in 4.6, beta here : https://www.myget.org/feed/nunit/package/nuget/NUnit3TestAdapter

[ravigneaux-1]

@OsirisTerje, thanks for your time and effort! 🙂 I see that console output from the application under test is not logged as warnings anymore when using the standard output stream (Console.Out), but the standard error stream (Console.Error) still is 🤔 Not sure if that's intended...

Anyway, I'm a bit lost what would be the correct setup for what I have in mind... In my opinion, console output from the application under test should never be forwarded as warnings (it's perfectly valid for an application to write to the error stream) while at the same time it should be possible to emit info, warnings and errors from the test cases, e.g. to point out that there is an issue in the test system (not sure what would be the right way to do it such that each message type is properly displayed in the Test Explorer and the console...) 😵

[OsirisTerje]

Yes, the error stream should be , because it is then an error that is warned.

I am not sure how one can separate between the two (app under test and test itself), since internally in NUnit the streams are just captured and directed into the console and error streams. And Test Explorer does not separate either.
It is interesting though to look into this.
Can you create a new issue containing the essence of your comment, like

In my opinion, console output from the application under test should never be forwarded as warnings (it's perfectly valid for an application to write to the error stream) while at the same time it should be possible to emit info, warnings and errors from the test cases, e.g. to point out that there is an issue in the test system (not sure what would be the right way to do it such that each message type is properly displayed in the Test Explorer and the console...)

NUnit (and any other framework too) executes the test. The SUT is just being called from the test itself. I am not sure if this is possible at all. The test may also invoke methods from other frameworks, and they may also output to the console, and how should the test know what is what?

Perhaps if the application rerouted its own console out to something else (even null), then the only output would be from the test. That means it would be harder to test console output, but if that is wanted, one could reroute to a file, and include that.

Thoughts?

[ravigneaux-1]

@OsirisTerje, done! I've submitted issue #1167 for discussion. Apologies for the late response, I didn't want to throw complaints without substance at you, so I had to evaluate and prepare a few things first...