Running xunit tests from console using .NET 9 Preview 1 SDK elides important informantion

[eiriktsarpalis]

Describe the bug

Not sure if this is an SDK or xunit bug, but I thought I should report it here. Running xunit tests using an SDK <= v8 results in useful test run information being printed in the console. For a passing run:

  Determining projects to restore...
  Restored C:\Users\eitsarpa\source\repos\Solution\TestProj\TestProj.csproj (in 359 ms).
  TestProj -> C:\Users\eitsarpa\source\repos\Solution\TestProj\bin\Debug\net8.0\TestProj.dll
Test run for C:\Users\eitsarpa\source\repos\Solution\TestProj\bin\Debug\net8.0\TestProj.dll (.NETCoreApp,Version=v8.0)
Microsoft (R) Test Execution Command Line Tool Version 17.9.0 (x64)
Copyright (c) Microsoft Corporation.  All rights reserved.

Starting test execution, please wait...
A total of 1 test files matched the specified pattern.

Passed!  - Failed:     0, Passed:     2, Skipped:     0, Total:     2, Duration: 2 ms - TestProj.dll (net8.0)

And for a failing run:

Microsoft (R) Test Execution Command Line Tool Version 17.9.0 (x64)
Copyright (c) Microsoft Corporation.  All rights reserved.

Starting test execution, please wait...
A total of 1 test files matched the specified pattern.
[xUnit.net 00:00:00.14]     TestProj.UnitTest1.Test2 [FAIL]
[xUnit.net 00:00:00.14]     TestProj.UnitTest1.Test1 [FAIL]
  Failed TestProj.UnitTest1.Test2 [2 ms]
  Error Message:
   Assert.True() Failure
Expected: True
Actual:   False
  Stack Trace:
     at TestProj.UnitTest1.Test2() in C:\Users\eitsarpa\source\repos\Solution\TestProj\UnitTest1.cs:line 12
   at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
   at System.Reflection.MethodBaseInvoker.InvokeWithNoArgs(Object obj, BindingFlags invokeAttr)
  Failed TestProj.UnitTest1.Test1 [< 1 ms]
  Error Message:
   Assert.True() Failure
Expected: True
Actual:   False
  Stack Trace:
     at TestProj.UnitTest1.Test1() in C:\Users\eitsarpa\source\repos\Solution\TestProj\UnitTest1.cs:line 9
   at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
   at System.Reflection.MethodBaseInvoker.InvokeWithNoArgs(Object obj, BindingFlags invokeAttr)

Failed!  - Failed:     2, Passed:     0, Skipped:     0, Total:     2, Duration: 2 ms - TestProj.dll (net8.0)

However if I try to run the same project using SDK v9.0.100-preview.1.24101.2 I get the following output:

  Determining projects to restore...
  All projects are up-to-date for restore.
C:\Program Files\dotnet\sdk\9.0.100-preview.1.24101.2\Sdks\Microsoft.NET.Sdk\targets\Microsoft.NET.RuntimeIdentifierInference.targets(313,5): message NETSDK1057: You are usin
g a preview version of .NET. See: https://aka.ms/dotnet-support-policy [C:\Users\eitsarpa\source\repos\Solution\TestProj\TestProj.csproj]
  TestProj -> C:\Users\eitsarpa\source\repos\Solution\TestProj\bin\Debug\net8.0\TestProj.dll

If I try to induce test failures then I get the following output:

C:\Users\eitsarpa\source\repos\Solution\TestProj\UnitTest1.cs(12): error VSTEST1: (TestProj.UnitTest1.Test2) TestProj.UnitTest1.Test2() Assert.True() Failure  Expected: True 
 Actual:   False [C:\Users\eitsarpa\source\repos\Solution\TestProj\TestProj.csproj]
C:\Users\eitsarpa\source\repos\Solution\TestProj\UnitTest1.cs(9): error VSTEST1: (TestProj.UnitTest1.Test1) TestProj.UnitTest1.Test1() Assert.True() Failure  Expected: True   
Actual:   False [C:\Users\eitsarpa\source\repos\Solution\TestProj\TestProj.csproj]

Which arguably is less useful and less readable compared to .NET 8 sdk output. (Note that the terminal logger is disabled in both cases, but that doesn't appear to play a big role for this particular case).

To Reproduce

Any xunit test project should do, for this example I created one using the standard xunit template:

<Project Sdk="Microsoft.NET.Sdk">

  <PropertyGroup>
    <TargetFramework>net8.0</TargetFramework>
    <ImplicitUsings>enable</ImplicitUsings>
    <Nullable>enable</Nullable>
    <IsPackable>false</IsPackable>
    <IsTestProject>true</IsTestProject>
  </PropertyGroup>

  <ItemGroup>
    <PackageReference Include="coverlet.collector" Version="6.0.0" />
    <PackageReference Include="Microsoft.NET.Test.Sdk" Version="17.8.0" />
    <PackageReference Include="xunit" Version="2.5.3" />
    <PackageReference Include="xunit.runner.visualstudio" Version="2.5.3" />
  </ItemGroup>

</Project>

Source file:

namespace TestProj;
using Xunit;

public class UnitTest1
{
    private const bool Pass = false;

    [Fact]
    public void Test1() => Assert.True(Pass);

    [Fact]
    public void Test2() => Assert.True(Pass);
}

Further technical details

$ dotnet --info
.NET SDK:
 Version:           9.0.100-preview.1.24101.2
 Commit:            6bbd460f4d
 Workload version:  9.0.100-manifests.c840f51f

Runtime Environment:
 OS Name:     Windows
 OS Version:  10.0.22621
 OS Platform: Windows
 RID:         win-x64
 Base Path:   C:\Program Files\dotnet\sdk\9.0.100-preview.1.24101.2\

.NET workloads installed:
There are no installed workloads to display.

Host:
  Version:      9.0.0-preview.1.24080.9
  Architecture: x64
  Commit:       1d1bf92fcf

.NET SDKs installed:
  7.0.406 [C:\Program Files\dotnet\sdk]
  8.0.200 [C:\Program Files\dotnet\sdk]
  9.0.100-preview.1.24101.2 [C:\Program Files\dotnet\sdk]

.NET runtimes installed:
  Microsoft.AspNetCore.App 6.0.27 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 7.0.16 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 8.0.2 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 9.0.0-preview.1.24081.5 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.NETCore.App 6.0.27 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 7.0.16 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 8.0.2 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 9.0.0-preview.1.24080.9 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.WindowsDesktop.App 6.0.27 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 7.0.16 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 8.0.2 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 9.0.0-preview.1.24081.3 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]

Other architectures found:
  x86   [C:\Program Files (x86)\dotnet]
    registered at [HKLM\SOFTWARE\dotnet\Setup\InstalledVersions\x86\InstallLocation]

Environment variables:
  Not set

global.json file:
  Not found

Learn more:
  https://aka.ms/dotnet/info

Download .NET:
  https://aka.ms/dotnet/download

[baronfel]

yep! @nohwnd may have more details here, but we hope to have a much more useful experience in preview 2: dotnet/msbuild#9706

[nohwnd]

Yup, this is merged to preview 2, all the additional information including the console output should be in binlog, for both passing and failing tests.

Preview 2 also adds a way to opt out via env variable, or in both p1 and p2 you can opt out by build variable:

-p:VSTestUseMSBuildOutput=false build property
or by MSBUILDENSURESTDOUTFORTASKPROCESSES=1 (after microsoft/vstest#4853).

Feedback is welcomed :) I am tracking it here: microsoft/vstest#4843