Use of `Skip` causes failure with diagnostic verbosity logger

[mthalman]

When running dotnet test with verbosity set to diagnostic, it will cause a non-zero exit code if a test has set Fact.Skip to a non-empty value. This is a regression that was introduced by version 2.5.0-pre.27 of xunit.runner.visualstudio.

Repro:

1. Create a new C# xUnit test project with VS.
2. Upgrade xunit.runner.visualstudio package to version 2.5.0-pre.27 or higher.
3. In the generated test method, change [Fact] to [Fact(Skip = "foo")]
4. dotnet test --logger:'console;verbosity=detailed'

Output:

Starting test execution, please wait...
A total of 1 test files matched the specified pattern.
C:\Users\mthalman\source\repos\TestProject1\TestProject1\bin\Debug\net8.0\TestProject1.dll
[xUnit.net 00:00:00.00] xUnit.net VSTest Adapter v2.5.0-pre.27+4e86b435fe (64-bit .NET 8.0.0-preview.5.23280.8)
[xUnit.net 00:00:00.08]   Discovering: TestProject1
[xUnit.net 00:00:00.11]   Discovered:  TestProject1
[xUnit.net 00:00:00.11]   Starting:    TestProject1
[xUnit.net 00:00:00.14]     TestProject1.UnitTest1.Test1 [SKIP]
[xUnit.net 00:00:00.14]       foo
[xUnit.net 00:00:00.15]   Finished:    TestProject1
  Skipped TestProject1.UnitTest1.Test1 [1 ms]
  Error Message:
   foo

Test Run Successful.
Total tests: 1
    Skipped: 1
 Total time: 0.6572 Seconds

Changing verbosity to normal will cause it to succeed.

[bradwilson]

The test doesn't fail:

Test Run Successful.

I cannot repro your non-zero exit code problem either. My prompt shows non-zero exit codes and you can see dotnet test does not return a non-zero exit code (I added an invocation of false to show the error code on my prompt):

Skip reasons are reported as messages so they can be filtered in Test Explorer, per https://github.com/xunit/visualstudio.xunit/issues/110

[mthalman]

Ok, try this:

repro.zip

It's targeting net8.0 but you can still repro with earlier versions.

To repro that, run:

dotnet build build.proj

MSBuild version 17.7.0-preview-23281-03+4ce2ff1f8 for .NET
    Determining projects to restore...
    All projects are up-to-date for restore.
  C:\Program Files\dotnet\sdk\8.0.100-preview.5.23303.2\Sdks\Microsoft.NET.Sdk\targets\Microsoft.NET.RuntimeIdentifierInference.targets(314,5): message NETSDK1057: You are using a preview version o
  f .NET. See: https://aka.ms/dotnet-support-policy [C:\Users\mthalman\source\repos\TestProject1\TestProject1\TestProject1.csproj]
    TestProject1 -> C:\Users\mthalman\source\repos\TestProject1\TestProject1\bin\Debug\net8.0\TestProject1.dll
  Test run for C:\Users\mthalman\source\repos\TestProject1\TestProject1\bin\Debug\net8.0\TestProject1.dll (.NETCoreApp,Version=v8.0)
  Microsoft (R) Test Execution Command Line Tool Version 17.7.0-preview.23272.5+6bce41dc77697d2c1f42ede74ee02458ff18e4c1 (x64)
  Copyright (c) Microsoft Corporation.  All rights reserved.

  Starting test execution, please wait...
  A total of 1 test files matched the specified pattern.
  C:\Users\mthalman\source\repos\TestProject1\TestProject1\bin\Debug\net8.0\TestProject1.dll
  [xUnit.net 00:00:00.00] xUnit.net VSTest Adapter v2.5.0-pre.27+4e86b435fe (64-bit .NET 8.0.0-preview.5.23280.8)
  [xUnit.net 00:00:00.51]   Discovering: TestProject1
  [xUnit.net 00:00:00.55]   Discovered:  TestProject1
  [xUnit.net 00:00:00.55]   Starting:    TestProject1
  [xUnit.net 00:00:00.61]     TestProject1.UnitTest1.Test1 [SKIP]
  [xUnit.net 00:00:00.61]       foo
  [xUnit.net 00:00:00.62]   Finished:    TestProject1
    Skipped TestProject1.UnitTest1.Test1 [1 ms]
EXEC : error Message:  [C:\Users\mthalman\source\repos\TestProject1\build.proj]
     foo

  Results File: C:\Users\mthalman\source\repos\TestProject1\TestProject1\TestResults\mthalman_CPC-mthal-VUXNE_2023-11-06_14_12_55.trx

  Test Run Successful.
  Total tests: 1
      Skipped: 1
   Total time: 2.9472 Seconds
C:\Users\mthalman\source\repos\TestProject1\build.proj(3,2): error MSB3073: The command "dotnet test TestProject1 --logger:trx --logger:console;verbosity=detailed" exited with code -1.

Build FAILED.

EXEC : error Message:  [C:\Users\mthalman\source\repos\TestProject1\build.proj]
C:\Users\mthalman\source\repos\TestProject1\build.proj(3,2): error MSB3073: The command "dotnet test TestProject1 --logger:trx --logger:console;verbosity=detailed" exited with code -1.
    0 Warning(s)
    2 Error(s)

Time Elapsed 00:00:06.55

[bradwilson]

This isn't dotnet test failing, this is MSBuild trying to parse the output in the hopes of "finding" errors that it thinks aren't being reported as failure codes.

Disable this by adding IgnoreStandardErrorWarningFormat="true' to your <Exec>.

[bradwilson]

This is your hint that it's Exec doing this:

[mthalman]

Thanks for educating me. Using IgnoreStandardErrorWarningFormat works.

[bradwilson]

Here's another example of this unnecessary and counterproductive parsing:

using Xunit.Abstractions;

namespace TestProject1
{
    public class UnitTest1
    {
        readonly ITestOutputHelper helper;

        public UnitTest1(ITestOutputHelper helper)
        {
            this.helper = helper;
        }

        [Fact]
        public void Test1()
        {
            helper.WriteLine("error: isn't really what's happening here");
        }
    }
}

That's not even a skipped test, that's a passing test with output that "looks suspicious".

[mthalman]

That's a very "helpful" feature. 😉