Test duration reported by dotnet test is inaccurate for xUnit async tests
Closed this issue · 4 comments
Description
When running a series of asynchronous xUnit tests with dotnet test, the time elapsed reported at the end of dotnet test is wrong. It appears to be failing to measure the time taken by the first test, and only measuring the time elapsed starting with the second test to run.
Reproduction Steps
Clone https://github.com/rmunn/dotnet-test-xunit-timing-repro and run dotnet test. Note the time elapsed is the time taken by the second test to run.
Then try adding a third and fourth test, each waiting for a different number of seconds. Note that the time elapsed is the total time taken up by all tests, minus the time the first test spends waiting.
Expected behavior
The time elapsed reported by dotnet test would include all tests.
Actual behavior
The first test to run asynchronously does not have its time recorded in the time elapsed that dotnet test reports.
Further details
Originally reported at dotnet/runtime#98205, but once I observed that this behavior does not happen for MSUnit and NUnit tests I decided the source of the bug was more likely somewhere in xUnit's Visual Studio support.
This is a bug in VSTest.
If you run with verbosity turned to normal, then it reports the right time. Compare:
I can definitely vouch for the fact that when you use first party runners, we always report the right time. You should open this bug against VSTest and get them to explain their inconsistency when running in different verbosity levels.
Also, you're using quite old versions of our NuGet packages. You should probably upgrade before reporting the bug to them, as that's likely the first thing they'll tell you to do. 😄
I used dotnet new xunit to create a template, and those are the versions it came with. I'll update to the latest versions in my repro repo, then reopen the bug against the .NET test runner.
I've reopened dotnet/runtime#98205 since it does appear that the bug is somewhere in the dotnet test code. Closing this one. If someone manages to prove that the bug is in xUnit after all, I'll reopen.