microsoft / vstest

Visual Studio Test Platform is the runner and engine that powers test explorer and vstest.console.
MIT License
902 stars 323 forks source link

Improve output of `dotnet test` #3842

Open Socolin opened 2 years ago

Socolin commented 2 years ago

Hello,

When running dotnet test there are a lots of output and the console output is kind of useless du to the noise.

Would it be possible to improve the output to get something similar with jest for example:

image

Anton-V-K commented 2 years ago

Running C# tests is also possible with vstest.console.exe. Have you tried it? It produces the output similar to the one you're refferring to on the picture: image

Socolin commented 2 years ago

The request here is to improve the default output from dotnet test, nunit console or vstest.console.exe might have better output, but I don't want to add in my build pipeline a linux and windows binary that need to be upgraded manually later.

dotnet test is simple and I think it should get readable output in scenario where lots of tests are running.

And when runnning test locally I can just Rider test runner

MFDeAngelo commented 11 months ago

I'd like to add that I would really appreciate this feature as well. Honestly, it doesn't even need to be that big of a change. If we could avoid outputting the entire test results on a single line, that would be a huge advantage. A simple change such as changing Passed! - Failed: 0, Passed: 7, Skipped: 0, Total: 7, Duration: 6 s - IntegrationTests.dll (net6.0) to

Passed!  
Failed:     0, 
Passed:     7,
Skipped:     0, 
Total:     7, 
Duration: 6 s 
IntegrationTests.dll (net6.0)

would be an enormous improvement.

nohwnd commented 11 months ago

dotnet test is internally using vstest.console to run tests, and you can change to the same output by setting the console logger to detailed mode dotnet test --logger:"console;verbosity=detailed". But this is not the default for dotnet test because internally there are multiple instances of vstest.console being run, and so outputing just 1 summary line per instance (per test assembly) is more desirable.

The change could be done, but in order to do that we would have redesign how tests are being run.

We are also working on a reporter that is using msbuild in a more standard way. This is implemented in net9 https://github.com/microsoft/vstest/pull/2702#issue-787468151 and can be enabled by providing /p:VsTestUseMSBuildOutput=true build property. We hope to integrate this better with the new msbuild logger, which should give better summaries, and experience that integrates well with the other msbuild related tools.

juwens commented 8 months ago

it's a little bit ridiculous, that one needs to do parameter gymnastics with --logger:"console;verbosity=detailed" (which is one of the awkwardest parameter syntax i've seen) for a what the majority of coders and console users would call a default behavior. (at least if you look at other languages. rust, mocha, etc.)

I mean we are not talking of "crazy" improvements like grouping by class.

Like this python example: image

But it would be nice to make "dotnet test" work like a tool from the 2020s. Not like a tool from the 2000s and .NET 1.0.

kzu commented 5 months ago

I came across this issue and decided to do something about it 🤷

now you can run: dotnet tool install -g dotnet-trx, and after running tests with dotnet test -l trx (shorthand for --logger trx), you can simply run trx and get the following:

image

You can add --output to get the actual unit tests console output if desired.

Since it's a post-run renderer, no in-progress is provided. It just scans the current dir by default (unless -p|--path is provided) recursively (unless -r|--recursive false is provided) for all *.trx files and renders them nicely.

timheuer commented 4 months ago

@kzu this is cool -- some of my output is not emitting though is it only in detailed verbosity? (https://github.com/timheuer/xunitplay)

kzu commented 4 months ago

Just cloned, run dotnet test -l trx; trx (with latest version) and got:

image

kzu commented 4 months ago

Added skipped tests reason:

image

GH PR reporting (when running in CI, detected automatically):

image

With fully collapsible details:

image

kzu commented 4 months ago

I need to stop now and go back to what I was actually working on 🙄

image

PureKrome commented 4 months ago

@kzu - loving this! ❤️

how did u wire up GH with trx, please? Link-example?

🧝🏻 🪄 EDIT: Side Quest

Here's what I do with GH actions + testing + code coverage. Could this work with your dotnet-trx?

      - run: dotnet test --configuration Debug --verbosity minimal --no-build --collect:"XPlat Code Coverage" --results-directory "./.codecoverage"

      - name: Code coverage
        uses: codecov/codecov-action@v4
        with:
          token: ${{ secrets.CODECOV_TOKEN }}
          directory: "./.codecoverage"
          fail_ci_if_error: true

could i just add the --logger trx to my dotnet test command and I can get the best of both worlds?

timheuer commented 4 months ago

Just cloned, run dotnet test -l trx; trx (with latest version) and got:

Yeah if you just run dotnet test with a console logger you'll see (notice 'Standard Output Messages'):

NUnit Adapter 4.5.0.0: Test execution started
Running all tests in D:\source\repos\xunitplay\TestProject3\bin\Debug\net8.0\TestProject3.dll
  Failed MSTest_Failed_Test [21 ms]
  Error Message:
   Assert.IsTrue failed.
  Stack Trace:
     at TestProject2.UnitTest1.MSTest_Failed_Test() in D:\source\repos\xunitplay\TestProject2\UnitTest1.cs:line 10
   at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
   at System.Reflection.MethodBaseInvoker.InvokeWithNoArgs(Object obj, BindingFlags invokeAttr)

  Standard Output Messages:
 This MSTest failed

  Passed MSTest_Passing_Test [< 1 ms]
  Standard Output Messages:
 This MSTest passed

Test Run Failed.
Total tests: 2
     Passed: 1
     Failed: 1
 Total time: 1.6229 Seconds
   NUnit3TestExecutor discovered 2 of 2 NUnit test cases using Current Discovery mode, Non-Explicit run
[xUnit.net 00:00:00.38]   Discovering: TestProject1
[xUnit.net 00:00:00.41]   Discovered:  TestProject1
[xUnit.net 00:00:00.41]   Starting:    TestProject1
This nUnit test failed.

This nUnit test passed.

NUnit Adapter 4.5.0.0: Test execution complete
  Failed NUnit_Failed_Test [25 ms]
  Stack Trace:
     at TestProject3.Tests.NUnit_Failed_Test() in D:\source\repos\xunitplay\TestProject3\UnitTest1.cs:line 14

1)    at TestProject3.Tests.NUnit_Failed_Test() in D:\source\repos\xunitplay\TestProject3\UnitTest1.cs:line 14

  Standard Output Messages:
 This nUnit test failed.

  Passed NUnit_Passing_Test [< 1 ms]
  Standard Output Messages:
 This nUnit test passed.

Test Run Failed.
Total tests: 2
     Passed: 1
     Failed: 1
 Total time: 1.8018 Seconds
[xUnit.net 00:00:00.56]     TestProject1.UnitTest1.Failed_XUnit_Test [FAIL]
[xUnit.net 00:00:00.56]       Assert.True() Failure
[xUnit.net 00:00:00.56]       Expected: True
[xUnit.net 00:00:00.56]       Actual:   False
[xUnit.net 00:00:00.57]       Stack Trace:
[xUnit.net 00:00:00.57]         D:\source\repos\xunitplay\TestProject1\UnitTest1.cs(18,0): at TestProject1.UnitTest1.Failed_XUnit_Test()
[xUnit.net 00:00:00.57]            at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
[xUnit.net 00:00:00.57]            at System.Reflection.MethodBaseInvoker.InvokeWithNoArgs(Object obj, BindingFlags invokeAttr)
[xUnit.net 00:00:00.57]       Output:
[xUnit.net 00:00:00.57]         This xUnit test failed
[xUnit.net 00:00:00.57]   Finished:    TestProject1
  Passed TestProject1.UnitTest1.Passed_XUnit_Test [114 ms]
  Standard Output Messages:
 This xUnit test passed

  Failed TestProject1.UnitTest1.Failed_XUnit_Test [< 1 ms]
  Error Message:
   Assert.True() Failure
Expected: True
Actual:   False
  Stack Trace:
     at TestProject1.UnitTest1.Failed_XUnit_Test() in D:\source\repos\xunitplay\TestProject1\UnitTest1.cs:line 18
   at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
   at System.Reflection.MethodBaseInvoker.InvokeWithNoArgs(Object obj, BindingFlags invokeAttr)
  Standard Output Messages:
 This xUnit test failed

Test Run Failed.
Total tests: 2
     Passed: 1
     Failed: 1
 Total time: 1.9220 Seconds
kzu commented 4 months ago

could i just add the --logger trx to my dotnet test command and I can get the best of both worlds?

That is indeed how it should Just Work :)

The GH integration uses the github CLI. See https://github.com/devlooped/dotnet-trx/blob/main/src/dotnet-trx/TrxCommand.cs#L221-L256

kzu commented 4 months ago

@timheuer I'm just reading from the trx, so whatever all the various test frameworks emit and the logger collects, is what ends up in there. I only use xunit though. Did you find that bumping the verbosity causes additional text to show?

timheuer commented 4 months ago

@timheuer I'm just reading from the trx, so whatever all the various test frameworks emit and the logger collects, is what ends up in there. I only use xunit though. Did you find that bumping the verbosity causes additional text to show?

Bumping to detailed didn't change anything in the output of trx -- full output:

dotnet test -l "trx;verbosity=detailed"

  Determining projects to restore...
  All projects are up-to-date for restore.
C:\Program Files\dotnet\sdk\8.0.400-preview.0.24324.5\Sdks\Microsoft.NET.Sdk\targets\Microsoft.NET.RuntimeIdentifierInf
erence.targets(311,5): message NETSDK1057: You are using a preview version of .NET. See: https://aka.ms/dotnet-support-
policy [D:\source\repos\xunitplay\TestProject3\TestProject3.csproj]
C:\Program Files\dotnet\sdk\8.0.400-preview.0.24324.5\Sdks\Microsoft.NET.Sdk\targets\Microsoft.NET.RuntimeIdentifierInf
erence.targets(311,5): message NETSDK1057: You are using a preview version of .NET. See: https://aka.ms/dotnet-support-
policy [D:\source\repos\xunitplay\TestProject1\TestProject1.csproj]
C:\Program Files\dotnet\sdk\8.0.400-preview.0.24324.5\Sdks\Microsoft.NET.Sdk\targets\Microsoft.NET.RuntimeIdentifierInf
erence.targets(311,5): message NETSDK1057: You are using a preview version of .NET. See: https://aka.ms/dotnet-support-
policy [D:\source\repos\xunitplay\TestProject2\TestProject2.csproj]
  TestProject3 -> D:\source\repos\xunitplay\TestProject3\bin\Debug\net8.0\TestProject3.dll
  TestProject1 -> D:\source\repos\xunitplay\TestProject1\bin\Debug\net8.0\TestProject1.dll
Test run for D:\source\repos\xunitplay\TestProject1\bin\Debug\net8.0\TestProject1.dll (.NETCoreApp,Version=v8.0)
  TestProject2 -> D:\source\repos\xunitplay\TestProject2\bin\Debug\net8.0\TestProject2.dll
Test run for D:\source\repos\xunitplay\TestProject3\bin\Debug\net8.0\TestProject3.dll (.NETCoreApp,Version=v8.0)
Test run for D:\source\repos\xunitplay\TestProject2\bin\Debug\net8.0\TestProject2.dll (.NETCoreApp,Version=v8.0)
VSTest version 17.11.0-preview-24320-06 (x64)
VSTest version 17.11.0-preview-24320-06 (x64)

VSTest version 17.11.0-preview-24320-06 (x64)

Starting test execution, please wait...
Starting test execution, please wait...
Starting test execution, please wait...
A total of 1 test files matched the specified pattern.
A total of 1 test files matched the specified pattern.
A total of 1 test files matched the specified pattern.
  Failed MSTest_Failed_Test [26 ms]
  Error Message:
   Assert.IsTrue failed.
  Stack Trace:
     at TestProject2.UnitTest1.MSTest_Failed_Test() in D:\source\repos\xunitplay\TestProject2\UnitTest1.cs:line 10
   at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
   at System.Reflection.MethodBaseInvoker.InvokeWithNoArgs(Object obj, BindingFlags invokeAttr)

  Standard Output Messages:
 This MSTest failed

Results File: D:\source\repos\xunitplay\TestProject2\TestResults\timheuer_GRIMSEL_2024-07-08_07_38_46.trxThis nUnit test failed.

This nUnit test passed.

Failed!  - Failed:     1, Passed:     1, Skipped:     0, Total:     2, Duration: 45 ms - TestProject2.dll (net8.0)
  Failed NUnit_Failed_Test [32 ms]
  Stack Trace:
     at TestProject3.Tests.NUnit_Failed_Test() in D:\source\repos\xunitplay\TestProject3\UnitTest1.cs:line 14

1)    at TestProject3.Tests.NUnit_Failed_Test() in D:\source\repos\xunitplay\TestProject3\UnitTest1.cs:line 14

  Standard Output Messages:
 This nUnit test failed.

Results File: D:\source\repos\xunitplay\TestProject3\TestResults\timheuer_GRIMSEL_2024-07-08_07_38_46.trx

Failed!  - Failed:     1, Passed:     1, Skipped:     0, Total:     2, Duration: 34 ms - TestProject3.dll (net8.0)
[xUnit.net 00:00:00.78]     TestProject1.UnitTest1.Failed_XUnit_Test [FAIL]
  Failed TestProject1.UnitTest1.Failed_XUnit_Test [< 1 ms]
  Error Message:
   Assert.True() Failure
Expected: True
Actual:   False
  Stack Trace:
     at TestProject1.UnitTest1.Failed_XUnit_Test() in D:\source\repos\xunitplay\TestProject1\UnitTest1.cs:line 18
   at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
   at System.Reflection.MethodBaseInvoker.InvokeWithNoArgs(Object obj, BindingFlags invokeAttr)
  Standard Output Messages:
 This xUnit test failed

Results File: D:\source\repos\xunitplay\TestProject1\TestResults\timheuer_GRIMSEL_2024-07-08_07_38_46.trx

Failed!  - Failed:     1, Passed:     1, Skipped:     0, Total:     2, Duration: 11 ms - TestProject1.dll (net8.0)
[NuGet Manager] [Info]     [CredentialProvider]VstsCredentialProvider - Acquired bearer token using 'MSAL Silent'
[NuGet Manager] [Info]     [CredentialProvider]VstsCredentialProvider - Attempting to exchange the bearer token for an Azure DevOps session token.

Workload updates are available. Run `dotnet workload list` for more information.

trx:

❌ MSTest_Failed_Test
     Assert.IsTrue failed.
        at TestProject2.UnitTest1.MSTest_Failed_Test() in TestProject2\UnitTest1.cs:line 10

✅ MSTest_Passing_Test
❌ NUnit_Failed_Test
✅ NUnit_Passing_Test
❌ TestProject1.UnitTest1.Failed_XUnit_Test
     Assert.True() Failure
     Expected: True
     Actual:   False
        at TestProject1.UnitTest1.Failed_XUnit_Test() in TestProject1\UnitTest1.cs:line 18

✅ TestProject1.UnitTest1.Passed_XUnit_Test

👉 Run 6 tests in ~ 219 milliseconds ❌
   ✅ 3 passed
   ❌ 3 failed
kzu commented 4 months ago

@timheuer got latest from your repo, run dotnet test -l trx; trx and still got proper output:

image

❯ dotnet --version
9.0.100-preview.2.24074.1