Performance regression in v0.50.0

[PhilippNaused]

<Project Sdk="Microsoft.NET.Sdk">
  <PropertyGroup>
    <ImplicitUsings>enable</ImplicitUsings>
    <Nullable>enable</Nullable>
    <OutputType>Exe</OutputType>
    <TargetFramework>net8.0</TargetFramework>
    <PublishAot>true</PublishAot>
    <TrimmerSingleWarn>false</TrimmerSingleWarn>
  </PropertyGroup>
  <ItemGroup>
    <PackageReference Include="TUnit" Version="0.50.0" />
  </ItemGroup>
</Project>

class Tests
{
    [Test]
    [MethodDataSource(nameof(Ints))]
    public async Task Test1(int i)
    {
        await Assert.That(i).IsGreaterThan(0);
    }

    public static IEnumerable<int> Ints() => Enumerable.Range(1, 10000);
}

Build with dotnet publish --use-current-runtime and then run the output executable.

In v0.25.21 the test duration was about 190ms, in v0.50.0 it takes about 350ms.

I also get performance differences without AOT, but using it makes it more noticeable.

[thomhurst]

@PhilippNaused Is it any better on v0.52?

[PhilippNaused]

@thomhurst in 0.52.8 it's down to 320ms.
So there is a slight improvement,

[PhilippNaused]

Tested 0.52.49. It's 430ms now.

[PhilippNaused]

Don't know if this helps, but the difference becomes far more noticeable when I add await Task.Delay(100); before the assert.
v0.25.21: ~350ms
v0.52.60: ~3s

[PhilippNaused]

Also, the title of the PR suggests that this only affects MethodDataSource, but I get the same numbers for MatrixDataSource.

[Test, MatrixDataSource]
public async Task Test1([MatrixRange<int>(1, 10000)] int i)
{
    await Task.Delay(100);
    await Assert.That(i).IsGreaterThan(0);
}

TUnit	time
0.25.21	350ms
0.50.0	39s
0.52.8	20s
0.52.49	2s
0.52.60	2s

[thomhurst]

@PhilippNaused How about v0.53.0?

[PhilippNaused]

@thomhurst
In the test with Task.Delay it's much better now (600ms). But not as good as in v0.25.21 (350ms).
Without the delay, there is no difference between v0.52.64 and v0.53.0.

[thomhurst]

Glad to hear that! This is a tricky one because I have no idea how to even track down what regressed. 0.50 was essentially a rewrite so it could be absolutely anything

[PhilippNaused]

I've used dotTrace to see if there is an obvious difference between v0.25 and v0.53. (Without AOT)

In v0.25, the test execution is very evenly split between 29 threads. The only time loss is lock contention and GC.

But in v0.53, 85% of the test execution is done by the thread that runs ExecuteParallelTestsAsync.
On this "main" thread, calls to ExecuteTestWhenReadyAsync make up 97% of it's runtime while the tests are executed.
The other 28 worker threads spend ~95% of that time idling.

Every single call to my Test1(int) method is started on this "main" thread. Without the Task.Delay, the other workers are not executing any test code. When I add the delay, they only execute the continuation.

Then I added a second identical method (Test2) and noticed that they are also started synchronously on the thread that calls ExecuteParallelTestsAsync.

The other threads don't perform any test work unless the tests actually need to await something. Since the asserts are synchronous, that never happens unless you have I/O in your tests.

Lastly, I ran the same analysis on my real unit test project and it had the same issue. Almost all of my unit tests are purely CPU-bound, so they ran on the same thread.
The only part of the process that was properly parallelized were the calls to GetTestsAsync in AotTestDataCollector.CollectTestsAsync.
Which is ironic, since that parts used to be synchronous in v0.25.

[thomhurst]

Interesting... I'm out today so won't be able to look any further today. But thank you so much for looking into this. If you wanna dig anymore into the root cause, go for it 🤣

[PhilippNaused]

ExecuteParallelTestsAsync doesn't execute tests in parallel, so the issue is likely in your EnumerableAsyncProcessor library.

And I think I found where it is:
https://github.com/thomhurst/EnumerableAsyncProcessor/blob/6d672d21a11fb987c649a511d9421dfe5fad6d26/EnumerableAsyncProcessor/RunnableProcessors/ParallelAsyncProcessor_1.cs#L16-L17

ProcessInParallel has an isIOBound parameter with default value true. Because of that, the tasks are scheduled synchronously.

I would recommend changing the default value to false. Assuming that unit tests are I/O bound seems like a bad idea. And even if they do, the extra overhead of a Task.Run call isn't so bad compared the tests themselves.

Also, even when a method is I/O-bound it will still block the thread until it hits the first await that needs to schedule a continuation on the thread pool.