Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Console.WriteLine calls during dotnet test are not emitted to the console on Windows #799

Closed
livarcocc opened this issue May 10, 2017 · 73 comments · Fixed by #4998
Closed
Labels
needs-attention needs-triage This item should be discussed in the next triage meeting.

Comments

@livarcocc
Copy link

From @jonsequitur on December 15, 2016 19:10

Steps to reproduce

  • Add a Console.WriteLine call in a test, .e.g GivenThatIWantToMigrateTestApps.ItMigratesRootProjectAndReferences
  • On Windows, dotnet test --test-case-filter "FullyQualifiedName=Microsoft.DotNet.Migration.Tests.GivenThatIWantToMigrateTestApps.ItMigratesRootProjectAndR eferences"

Expected behavior

The string passed to Console.WriteLine appears in console output.

Actual behavior

C:\dev\github\cli\test\dotnet-migrate.Tests [rel/1.0.0 ↓ +0 ~2 -0 !]> dotnet test --test-case-filter "FullyQualifiedName=Microsoft.DotNet.Migration.Tests.GivenThatIWantToMigrateTestApps.ItMigratesRootProjectAndR
eferences"
Build started, please wait...
Build completed.

Test run for C:\dev\github\cli\test\dotnet-migrate.Tests\bin\Debug\netcoreapp1.0\dotnet-migrate.Tests.dll(.NETCoreApp,Version=v1.0)
Microsoft (R) Test Execution Command Line Tool Version 15.0.0.0
Copyright (c) Microsoft Corporation.  All rights reserved.

Starting test execution, please wait...
Passed   Microsoft.DotNet.Migration.Tests.GivenThatIWantToMigrateTestApps.ItMigratesRootProjectAndReferences(projectName: "ProjectB", expectedProjects: "ProjectB,ProjectC,ProjectD,ProjectE")
Passed   Microsoft.DotNet.Migration.Tests.GivenThatIWantToMigrateTestApps.ItMigratesRootProjectAndReferences(projectName: "ProjectA", expectedProjects: "ProjectA,ProjectB,ProjectC,ProjectD,ProjectE")
Passed   Microsoft.DotNet.Migration.Tests.GivenThatIWantToMigrateTestApps.ItMigratesRootProjectAndReferences(projectName: "ProjectC", expectedProjects: "ProjectC,ProjectD,ProjectE")
Passed   Microsoft.DotNet.Migration.Tests.GivenThatIWantToMigrateTestApps.ItMigratesRootProjectAndReferences(projectName: "ProjectE", expectedProjects: "ProjectE")
Passed   Microsoft.DotNet.Migration.Tests.GivenThatIWantToMigrateTestApps.ItMigratesRootProjectAndReferences(projectName: "ProjectD", expectedProjects: "ProjectD")

Total tests: 5. Passed: 5. Failed: 0. Skipped: 0.
Test Run Successful.
Test execution time: 32.2825 Seconds

Environment data

dotnet --info output:

.NET Command Line Tools (1.0.0-preview5-004253)

Product Information:
Version: 1.0.0-preview5-004253
Commit SHA-1 hash: 0caae96daf

Runtime Environment:
OS Name: Windows
OS Version: 10.0.14393
OS Platform: Windows
RID: win10-x64
Base Path: C:\dev\github\cli\artifacts\win10-x64\stage2\sdk\1.0.0-preview5-004253

Copied from original issue: dotnet/cli#5033

@livarcocc
Copy link
Author

From @krwq on January 5, 2017 23:46

@jonsequitur You should probably be using Xunit's ITestOutputHelper. making Console.WriteLine forward to that might be slightly harder

@livarcocc
Copy link
Author

From @jonsequitur on January 6, 2017 4:35

The issue that I was seeing was that this works on OS X but not on Windows.

@livarcocc
Copy link
Author

I am seeing that too on windows. None of the Console.WriteLine from my tests gets printed out. We should not ask users to use special APIs to print to the console.

@codito @Faizan2304 Can you guys take a look?

I think we should move this bug to the vstest repo.

@codito
Copy link
Contributor

codito commented May 11, 2017

I think this should be handled by adapters at some level. MSTest for instance captures and sends the console outputs to the runner, I think we are including them in trx logger, but not in the console. We can start showing them in console. cc: @Faizan2304

There were a few requests to capture console output in xunit:
https://xunit.github.io/docs/capturing-output.html suggests to use IOutputHelper
xunit/xunit#1141

@Faizan2304
Copy link
Contributor

Fixed!!

@zwcloud
Copy link

zwcloud commented Jul 29, 2017

@Faizan2304 Is it fixed in Visual Studio Community 2017 Version 15.2 (26430.15) Release? I still cannot get the output in the output window or the test explorer. I'm using xunit.

@rogusdev
Copy link

rogusdev commented Aug 4, 2017

I also still do not see test output and would love to, please.

From dotnet test output:

Test ...Tests\bin\Debug\netcoreapp2.0\~.dll(.NETCoreApp,Version=v2.0)
Microsoft (R) Test Execution Command Line Tool Version 15.3.0-preview-20170703-02

and in csproj:

    <PackageReference Include="Microsoft.NET.Test.Sdk" Version="15.3.0-preview-20170628-02" />
    <PackageReference Include="xunit" Version="2.2.0" />
    <PackageReference Include="xunit.runner.visualstudio" Version="2.2.0" />

(I am using preview version of VS and latest dotnet core from github)

@Faizan2304
Copy link
Contributor

Sorry for the late reply. I missed this thread.
@zwcloud: We have fixed it in vstest.console of version v15.3.0-preview-20170517-02 and it is part of Visual studio 2017 Update3 preview3. Please see below answer to see test output with xunit.

@rogusdev : How are you writing output from test method? Is it Console.WriteLine ?
If yes then it seems xunit doesn't support that.
There were a few requests to capture console output in xunit:
https://xunit.github.io/docs/capturing-output.html suggests to use IOutputHelper
xunit/xunit#1141

@zwcloud
Copy link

zwcloud commented Aug 8, 2017

@Faizan2304

Is it Console.WriteLine ?
If yes then it seems xunit doesn't support that.

Yes. But @bradwilson said in xunit#1141

There is no way to see that output with dotnet test because of limitations in the VSTest runner.

We do not capture stdout (users are free to use that if they so choose). Our output capture system pushes that information into the test result rather than to stdout. The TRX report may or may not generate reports which include "output" results (I don't personally know, since I have no knowledge of this format), but today there's no simple way today to get this output from dotnet test directly on the console.

Visual Studio's UI, on the other hand, offers ready access to "output", which is where this information is captured.

So.. could you fix or change the behaviour of VSTest runner to remove the limitaion?

@Faizan2304
Copy link
Contributor

@zwcloud:
We display what adapter sends in TestResult.Message Code here And here

Its the responsibility of adapter to fill console.WriteLine message in TestResult.Message.

But as you can see, @bradwilson said in xunit#1141 that they are not capturing console output to test result

Users will use ITestOutputHelper to write output. That's what ends up in ITestResultMessage.Output. We do not capture any device like console, debug, or tracing.

In this case you have to follow this article. xunit is suggesting to use IOutputHelper to log your message.

@evil-shrike
Copy link

Why the issue is closed if there is still no console output in tests?

It's kinda strange to have console test runner which doesn't show console output.

@ValorMorgan
Copy link

Bumping this in case anyone else comes along hoping to find an answer.

dotnet test -v n

I learned that running the above will show the "Standard Output Messages:" that you would expect from Console.Write*. It does flood the terminal with information at build but at least is a solution for the time. "-v" is a Verbosity argument. "n" represents "normal". Refer here for more information.

I use this with a .NET Core Unit / Integration test projects running NUnit.

@zwcloud
Copy link

zwcloud commented Mar 15, 2018

@Faizan2304 Apparently you guys think you have done quite well in handling the console output. But that's far from the truth. We don't want to use IOutputHelper to log your message, just implement a simple way today to get this output from dotnet test directly on the console.

@mattiasw2
Copy link

mattiasw2 commented Apr 7, 2018

I solved the problem by letting my xUnit test classes inherit from a base class, that rewires console to ITestOutputHelper. Has some drawbacks since everything is first copied at the end, i.e. not during debugging. Someone can probably improve it.

using System;
using System.Diagnostics;
using System.IO;
using Xunit;
using Xunit.Abstractions;

namespace MyStd.Test
{
    public class MakeConsoleWork : IDisposable
    {
        private readonly ITestOutputHelper _output;
        private readonly TextWriter _originalOut;
        private readonly TextWriter _textWriter;

        public MakeConsoleWork(ITestOutputHelper output)
        {
            _output = output;
            _originalOut = Console.Out;
            _textWriter = new StringWriter();
            Console.SetOut(_textWriter);
        }

        public void Dispose()
        {
            _output.WriteLine(_textWriter.ToString());
            Console.SetOut(_originalOut);
        }
    }

    public class ConsoleWriterTest : MakeConsoleWork
    {
        public ConsoleWriterTest(ITestOutputHelper output) : base(output)
        {
        }

        [Fact]
        public void Test1()
        {
            Console.WriteLine("nunit console visible in test runner");
        }
    }
}

@alexsandro-xpt
Copy link

@mattiasw2 nice job! but, it's a bug in dotnet test?

@mattiasw2
Copy link

@alexsandro-xpt Sorry, you are correct, it is related to Xunit, and the reason I ended up here is @Faizan2304

Also, since I did the above, I realized it only works if you do not run tests in parallel. The core problem is actually Console.SetOut, since you would actually want to have a Console.SetOut that only changes the Console in the current thread, something that is hard in dotnet (but easy in Clojure). So. you can delete my comments as not relevant.

@dhowe
Copy link

dhowe commented May 17, 2018

Why is this closed?

@JoshuaKGoldberg
Copy link

@Faizan2304 this is not working for me using dotnet test. No System.Console.WriteLine output shows up during unit tests.

Could you please re-open the issue? This is still broken for many.

@roblframpton
Copy link

roblframpton commented Sep 21, 2018

Could this be re-opened? It is clearly not fixed for a very large number of users. The ITestOutputHelper is not a good solution for a variety of reasons - for example, how am I supposed to log the output of the actual library I am testing (i.e. not in the test class itself)? I'm supposed to pass this XUnit object into my actual library?

BTW, if anyone is having trouble getting the ITestOutputHelper to work, note that it will not output anything if your test passes. It needs to fail for output to be shown. Hope that helps.

@adamralph
Copy link
Contributor

I'm also experiencing this problem on Windows. On Linux, it works just fine.

Interestingly, on Appveyor Windows builds, I also see the console output. It's only locally that I see nothing.

@devedse
Copy link

devedse commented Nov 6, 2018

How does appveyor do this?

@wizofaus
Copy link

wizofaus commented Nov 21, 2018

using (var writer = new System.IO.StreamWriter(System.Console.OpenStandardOutput()))
       writer.WriteLine("This will show up!");

Works on Linux/Mac, but not on Windows...

@danvln
Copy link

danvln commented Nov 21, 2018

Any final solution to this problem for Windows?

Edit:

This is what I ended up doing:

public class Client : ClientWConsole {
        public Client(ITestOutputHelper output) : base(output) { }

        [Fact]
        public void Execute() {

            Debug.WriteLine("Hello world - D "); // for debug results 
            this.output.WriteLine("Hello world - C"); // for test  output results 
        }
    }
public class ClientWConsole {
         protected readonly ITestOutputHelper output;

        public ClientWConsole(ITestOutputHelper output) {
            this.output = output;
        }

    }

@olfek
Copy link

olfek commented Jan 10, 2023

On Ubuntu 22.04.1 LTS

dotnet test --no-build --verbosity normal shows logging from Console.WriteLine

However, on Windows, I don't see anything.

@olfek
Copy link

olfek commented Jan 10, 2023

@Faizan2304 Why have you closed this? It isn't fixed! 😡

@moh-hassan
Copy link

@olfek ,
In Nunit suit test, Console.WriteLine is working fine on Windows and Ubuntu.
What testing suit are using?

@bradwilson
Copy link

@olfek is correct, this is still broken on Windows for xUnit.net.

Windows:

image

Linux (WSL):

image

@bradwilson
Copy link

This was closed prematurely @Faizan2304

@bradwilson
Copy link

Note that unlike other test frameworks, xUnit.net v2 does not touch or capture Console output. It appears that VSTest on Windows is capturing (and throwing away) Console output, whereas on Linux it is not (or some similar disparity).

@Evangelink Evangelink reopened this Jan 12, 2023
@Evangelink Evangelink added the needs-triage This item should be discussed in the next triage meeting. label Jan 12, 2023
@IngmarPaetzold
Copy link

Really annoying, I envy the Linux version. xUnit states on its website https://xunit.net/docs/capturing-output that this funcitonality was intentionally removed due to "many tests [...] running in parallel". Hell! When I want to create and fine tune one test, I just let this one test run, and need some helpful output which I then remove when it's done.
Granted, the described workaround with ITestOutputHelper works, but it clutters the code and complicates the command line call. Just gimme Console.WriteLine() for developing. It's then my responsibility how many tests run in parallel and whether outputs interfere, isn't it?
image

@SimonCropp
Copy link
Contributor

@IngmarPaetzold u might find this useful https://github.com/SimonCropp/XunitContext/

@IngmarPaetzold
Copy link

IngmarPaetzold commented Feb 6, 2023

Thanks Simon, good to know, in case one has several kinds of output. Currently, the solution provided by xUnit works for me, thus, adding an ITestOutputHelper.
My point is rather that I felt the Principle of least surprise being violated by xUnit not showing Console.WriteLine() output in the first place. Practically: I tried to set up a unit test, needed some values printed temporarily, and was surprised as it did not work. Then googleing, finding that I am not the only one, tried one workaround (did not work), until, eventually, found a solution.
Still, requiring to add an ITestOutputHelper to the class and -l "console;verbosity=detailed" to the command call just does not feel right. In my opinion, an option to switch off console output in case the executed code prints too much stuff, locally, globally, whatever, would be the better option. Just my opinion.

@peabnuts123
Copy link

This is absurd behaviour from one of the largest development toolkits there is. This is not an issue of whether a test framework should swallow logs, the issue is about the fact that 2/3 major platforms don't and one platform does. On my team we just discovered that our Mac developers see logs in the tests (e.g. stack traces) and our Windows developers don't (and have been working in a totally different way). This is not something that is up to personal preference / should be a setting / can be worked around, it is broken and needs to be fixed because it's not consistent.
Reading the commentary about this on various issues, it seems like there has been some finger pointing for a few years (this issue was opened in 2016). The team at xUnit seems to think that since they aren't doing anything with Console output, its vstest's burden to fix. The team here seem to be suggesting that test runner developers should be implementing it themselves (like Nunit has done).

@bradwilson

Note that unlike other test frameworks, xUnit.net v2 does not touch or capture Console output. It appears that VSTest on Windows is capturing (and throwing away) Console output, whereas on Linux it is not (or some similar disparity).

@codito

I think this should be handled by adapters at some level. MSTest for instance captures and sends the console outputs to the runner, I think we are including them in trx logger, but not in the console. We can start showing them in console. cc: @Faizan2304

@Faizan2304

@rogusdev : How are you writing output from test method? Is it Console.WriteLine ?
If yes then it seems xunit doesn't support that.
There were a few requests to capture console output in xunit:
https://xunit.github.io/docs/capturing-output.html suggests to use IOutputHelper
xunit/xunit#1141

Its the responsibility of adapter to fill console.WriteLine message in TestResult.Message.

But as you can see, @bradwilson said in xunit/xunit#1141 (comment) that they are not capturing console output to test result

Can we at least get some agreement here about whose backlog this should be on? Pointing fingers is just harming users and has been doing so now for 6 years.

cc: @Evangelink

@bradwilson
Copy link

@peabnuts123 For sure, lobbing insults is not going to get you results.

@emmenlau
Copy link

@bradwilson What results? There have been no results in 6 years.

@Evangelink
Copy link
Member

@peabnuts123 I was on a long leave and I am just back. I will read all this thread and try to give some information/ask for plan about this.

@Evangelink Evangelink self-assigned this Apr 12, 2023
@kodeo
Copy link

kodeo commented May 3, 2023

Thank you for making this point @peabnuts123, it's unbelievable that such a major framework should be broken in such fundamental way for so long, and on Windows of all platforms. I was mortified when I found out our Mac developers had been having a completely different experience with this all this time.

@chhh
Copy link

chhh commented May 4, 2023

Wow, on a leave for 6 years... And the issue didn't get assigned to anyone else...

@jacobjmarks
Copy link

It would be great if this discrepancy could be resolved. I'm surprised it's been outstanding for so long. This is making it harder for me to debug issues during testing for libraries that I do not govern, and as such cannot modify their methods of outputting to the console; I can see their logs in Linux, but not Windows.

@daniellopezgarcia
Copy link

We also want the Console.WriteLine to simply flow through the console. its unexpected behavior not to have this output and have the framework eat it somewhere. All we see is "Test passed" but we need to see the actual test log.

@ReenigneArcher
Copy link

I am on Windows, and when I first setup xunit a few days ago (using the ITestOutputHelper, I did not need to pass extra args to dotnet test... not sure what changed, but now nothing is output unless I add the --logger "console;verbosity=detailed" arg.

Kind of weird how it changed. Unfortunately I cannot pinpoint what could have possibly affected it.

Is there a way to make --logger "console;verbosity=detailed" the default?

@Evangelink Evangelink removed their assignment Sep 18, 2023
@kodeo
Copy link

kodeo commented Jan 24, 2024

Hello. Is there any update on this egregious seven year old bug affecting users running on Windows, a platform I understand the project owner has some interest in?

@pluma9
Copy link

pluma9 commented Feb 4, 2024

Console log debugging is a real pain now.

It's not always possible to inject IOutputHelper into a class.

@SimonCropp
Copy link
Contributor

@pluma9 this should work without needing to pass in ioutputhelper https://github.com/SimonCropp/XunitContext/

@HassanJbara
Copy link

it's amazing that after an hour of pulling my hair out as to why this wasn't working, I'm back to using linux on windows to debug a windows application. Microsoft will be Microsoft.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
needs-attention needs-triage This item should be discussed in the next triage meeting.
Projects
None yet
Development

Successfully merging a pull request may close this issue.