vstest console does not show console output from a test logger for "quiet" verbosity level

[NikolayPianikov]

Description

The test logger produces a console output
vstest console does not show this output for default verbosity level (quiet)

Steps to reproduce

Install .NET Core sdk-2.1.300-rc1 or 2.1.200
Run tests from sample
Messages like ##teamcity[testStarted should be in the stdOut

Expected behavior

Test Logger console output should be visible for any verbosity level

Actual behavior

Test Logger console output is not visible for quiet verbosity level

Diagnostic logs

quiet.txt
normal.txt

Environment

Windows 10
dotnet --version
2.1.300-rc1-008673
2.1.200

[dtretyakov]

@smadala, @pvlakshm could you please take a look? It looks like a breaking change on which our customers complains: https://youtrack.jetbrains.com/issue/TW-54720

[smadala]

@dtretyakov @NikolayPianikov Thanks for reporting the issue.
Looks like there is behavior difference between how the dotnet cli executing VSTestTask(Additional property -property:VSTestVerbosity=quiet).

2.2.100-preview1

"dotnet.exe" exec C:\Users\samadala\src\vstest\tools\dotnet\sdk\2.2.100-preview1-008636\MSBuild.dll -maxcpucount -verbosity:m -restore -target:VSTest -verbosity:quiet -nodereuse:false -nologo C:\Users\samadala\src\tmp\core-cc\core-cc.csproj -property:VSTestVerbosity=quiet -distributedlogger:Microsoft.DotNet.Tools.MSBuild.MSBuildLogger,C:\Users\samadala\src\vstest\tools\dotnet\sdk\2.2.100-preview1-008636\dotnet.dll*Microsoft.DotNet.Tools.MSBuild.MSBuildForwardingLogger,C:\Users\samadala\src\vstest\tools\dotnet\sdk\2.2.100-preview1-008636\dotnet.dll

2.1.200-preview-007474

"dotnet.exe" exec "C:\Program Files\dotnet\sdk\2.1.200-preview-007474\MSBuild.dll" /m /v:m /restore /t:VSTest /v:quiet /nologo C:\Users\samadala\src\tmp\core-cc\core-cc.csproj "/Logger:Microsoft.DotNet.Tools.MSBuild.MSBuildLogger,C:\Program Files\dotnet\sdk\2.1.200-preview-007474\dotnet.dll"

To fix the issue, We will make verbosity value minimal by default same as dotnet cli 2.1.

Now the results at least report the build as 'Failed' but I still don't get any test results.

@dtretyakov I'm not sure making verbosity value to minimal fixes this.

[NikolayPianikov]

@smadala Test Logger console output should be visible for ANY verbosity level
It is a breaking change:

• it is working as expected for SDK 2.1.104
• it is not working for SDK 2.1.200

See the attached sample

[smadala]

@NikolayPianikov Thanks for repro, We will look into it. @mayankbansal018 Already working on default verbosity level to minimal.

[martincostello]

I’ve also found this problem, which lead to this issue in the CLI: dotnet/cli#9229

[peterhuene]

@smadala The issue of the CLI passing the wrong default verbosity (VSTestVerbosity=quiet instead of not defining the property) to VSTest has been corrected for 2.1 RTM.

[mayankbansal018]

@peterhuene , we also made change to set default verbosity to minimal instead of quite, in PR https://github.com/dotnet/cli/pull/9211, I hope the changes we made would still be relevant?

[peterhuene]

That change affects the MSBuild verbosity as well, which is likely undesirable. The fix we took for RTM restores the previous behavior of being quiet for MSBuild and "unspecified" for VSTest (i.e. whatever default VSTest uses). Users that specify a --verbosity option on the command line will have it still passed through to VSTest through the VSTestVerbosity property.

[mayankbansal018]

I'll revert my fix then, thanks for the update @peterhuene , will close this issue as well.

[NikolayPianikov]

@mayankbansal018 Does quiet mode show stdOut messages from loggers?

[mayankbansal018]

@NikolayPianikov quite mode does not show any messages from logger, quiet mode only shows passed, & failed count.
Minimal mode: stacks for failed + passed failed count
Normal mode: stacks for failed + Passed tests names + passed, failed count
Detailed mode: messages from stdout + Normal mode

usage https://github.com/Microsoft/vstest-docs/blob/f2ef4a7dbbda6b315175ac20c9fabe4b4e199c09/docs/report.md#syntax

[NikolayPianikov]

I think it is a breaking change. Some CI are using stdOut for integration and obviously
the integration will be broken in the quiet mode. Moreover there are no way to notify about it from the logger side.
Is the any way to show messages in the stdOut from loggers?

[mayankbansal018]

@NikolayPianikov we never used to show messages printed via Console.WriteLine(stdout) in CLI, it was always in detailed mode, the above change restores the behavior back to "minimal" as default, where we only show stack trace for failed messages + passed failed count

[martincostello]

As a user of dotnet test directly, from an interactive perspective I want stdout and stacks for failed tests only to keep the terminal uncluttered, but in CI want all tests output so tools like TeamCity can display the total passed/fail count on a per-test basis, rather than in aggregate, as well as stdout and stacks for failed tests.

[mayankbansal018]

@martincostello for users who need complete data, they can simply pass -verbosity:detailed as input to dotnet cli.

[martincostello]

That wasn’t required for 2.1.1xx and earlier versions, and also that would increase the MSBuild verbosity, which I don’t want to do. As mentioned above, this is a breaking change for CI integrations that parse the output, like TeamCity.

[NikolayPianikov]

@mayankbansal018 vstest shows stdOut from loggers in all modes (including quiet) for SDK 2.1.104 and for previous versions. I've attached the sample for 2.1.104
Users often want to minimize output but they want have CI integration
Also it will be great to have the same behaviour for dotnet test, dotnet msbuild /t:vstest, dotnet vstest

[NikolayPianikov]

@mayankbansal018 may be there is some API to make possible to write down to stdOut without any filtrations?

[mayankbansal018]

@NikolayPianikov, so far when I mean logger I was only referring to Console logger, I hope you also meant the same.
I went through your sample, & I think the confusion arises because of usage of flag "VSTestDiag", which prints diagnostics information of testplatform to a file(Note: this has nothing to do with what is printed to console, but the information Testplatform needs to diagnose in case of unwarranted errors), rather than what we are talking about i.e. messages print on console.
Also in your run_quiet if you were passing dotnet test -v:quiet, this would lead for console verbosity quiet, but since you are not using it, it would lead to default console verbosity to minimal.

Further I tried out SDK 2.1.104, & below are my observations:
default: Minimal

• We only output stdout for failed test
• Print stack trace for failed

Quiet:

• No stdout message for any test(pass or failed)
• Only test summary i.e. failed + passed count

Normal:

• stdout for all Tests(failed or passed)
• Print stack trace for failed

[NikolayPianikov]

@mayankbansal018 it is not so important for us which information about tests is appeared in the stdOut because of we are skipping it from all loggers excepted our.
I've attached sample.zip.
Our messages like ##teamcity[testStarted are not in the stdOut for 2.1.300-rc1-008673
I would like to make sure that our messages will be in the stdOut for any verbosity level after fixes.

Can I rely on this?

[mayankbansal018]

@NikolayPianikov , as per @peterhuene comment , the behavior is restored as before where msbuild verbosity is set to quite, & vstest to unspecified(default:minimal).

Which means that messages your were receiving in logger earlier should be restored.

[NikolayPianikov]

@mayankbansal018 thank you

[NikolayPianikov]

@mayankbansal018 another one issue:
Integration of XUnit and TeamCity is broken: #1590

[mayankbansal018]

@NikolayPianikov , please create a new issue, & if possible also attach a sample repro.