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

Use of Skip causes failure with diagnostic verbosity logger #391

Closed
mthalman opened this issue Nov 6, 2023 · 9 comments
Closed

Use of Skip causes failure with diagnostic verbosity logger #391

mthalman opened this issue Nov 6, 2023 · 9 comments

Comments

@mthalman
Copy link

mthalman commented Nov 6, 2023

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
Copy link
Member

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):

image

Skip reasons are reported as messages so they can be filtered in Test Explorer, per #110

@mthalman
Copy link
Author

mthalman commented Nov 6, 2023

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
Copy link
Member

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
Copy link
Member

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

image

@mthalman
Copy link
Author

mthalman commented Nov 6, 2023

Thanks for educating me. Using IgnoreStandardErrorWarningFormat works.

@mthalman mthalman closed this as not planned Won't fix, can't repro, duplicate, stale Nov 6, 2023
@bradwilson
Copy link
Member

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");
        }
    }
}

image

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

@mthalman
Copy link
Author

mthalman commented Nov 6, 2023

That's a very "helpful" feature. 😉

@brumlemann
Copy link

brumlemann commented Dec 5, 2024

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>.

Not necessarily relevant. I just ran

dotnet vstest **/bin/**/*Tests.dll --settings:test.runsettings --logger:"console;verbosity=detailed"

pointing directly at my test assemblies (no .csproj | *sln as argument). Wathcing it in Process Explorer it is clear that MSBuild is not part of the stack (needed to be sure ;-))

image
image

However dotnet vstest **/bin/**/*Tests.dll --settings:test.runsettings --logger:"console;verbosity=normal" works like a charm

M

@bradwilson
Copy link
Member

bradwilson commented Dec 5, 2024

@brumlemann You should open an issue against VSTest.

https://github.com/microsoft/vstest/

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

3 participants