Skip to content

.NET 11 preview: ThreadPool work item that enqueues another work item and keeps running is 2x slower than .NET 10 #132952

Description

@wholroyd

Description

I thought at first this was the warm-up regression I filed as #132943 showing up in another benchmark. Working through that question showed a separate problem though. A thread-pool work item that queues another work item and then keeps running for a moment got much slower on .NET 11 preview, while the same pattern with the work item exiting immediately got faster. Just for giggles, I tested the other benchmark filing and found that the slowdown survives every setting that removed the warm-up regression, and I even extended it to a 10 second run. The warm-up regression is visible in these numbers too, as the exit scenario's step down to final speed will show later on.

I hit this benchmarking a message-passing library and reduced it to something reproducible below, which has no dependencies. It models a request/reply server where a client awaits a reply, a server work item queues the reply delivery as a second work item, and then does a little tail work before it exits (updating a counter, flushing a log, the kind of thing most servers do after replying). The tail work means two pool workers are briefly busy per request.

using System.Diagnostics;

int warmup = args.Length > 1 ? int.Parse(args[1]) : 20_000;

string mode = args.Length > 0 ? args[0] : "exit";
// "spaced" means no housekeeping, but the client busy-waits between requests
// so the pool parks before each one instead of briefly running two requests
int gap = mode == "spaced" ? 20_000 : 0;
bool housekeeping = mode == "housekeeping";
string label = mode switch
{
    "housekeeping" => "reply, then housekeeping",
    "spaced"       => "spaced lone requests    ",
    _              => "reply, then exit        ",
};
int requests = gap > 0 ? 50_000 : 200_000;
await Measure(label, housekeeping, gap, requests);

async Task Measure(string label, bool housekeeping, int gap, int requests)
{
    for (int i = 0; i < warmup; i++) { await RoundTrip(housekeeping); if (gap > 0) Thread.SpinWait(gap); }

    // Time only the awaited round trip
    // The inter-request gap sits outside the measured window.
    long ticks = 0;
    for (int i = 0; i < requests; i++)
    {
        long t0 = Stopwatch.GetTimestamp();
        await RoundTrip(housekeeping);
        ticks += Stopwatch.GetTimestamp() - t0;
        if (gap > 0) Thread.SpinWait(gap);
    }
    var elapsed = new TimeSpan((long)(ticks * (10_000_000.0 / Stopwatch.Frequency)));

    Console.WriteLine(
        $"{Environment.Version} | {label} | warmup {warmup,7:N0} | {elapsed.TotalNanoseconds / requests,5:F0} ns/request");
}

static Task RoundTrip(bool housekeeping)
{
    var reply = new TaskCompletionSource(
        TaskCreationOptions.RunContinuationsAsynchronously);

    ThreadPool.UnsafeQueueUserWorkItem(static state =>
    {
        // Hand the response to the outbound dispatcher, which generates a second work
        // item, and then wakes another worker to deliver the reply.
        ThreadPool.UnsafeQueueUserWorkItem(
            static s => s.SetResult(), state.reply, preferLocal: false);

        // Post-reply housekeeping where this work item stays alive a moment
        // longer while the reply is delivered elsewhere.
        if (state.housekeeping)
            Thread.SpinWait(200);
    }, (reply, housekeeping), preferLocal: false);

    return reply.Task;
}

Create a new project file for the above Program.cs file...

<Project Sdk="Microsoft.NET.Sdk">
  <PropertyGroup>
    <OutputType>Exe</OutputType>
    <TargetFrameworks>net10.0;net11.0</TargetFrameworks>
    <Nullable>enable</Nullable>
    <ImplicitUsings>enable</ImplicitUsings>
  </PropertyGroup>
</Project>

Execute it, each scenario in its own process. Mixing them in one process changes how the pool warms up, and the numbers stop being comparable:

dotnet run -c Release -f net10.0 -- exit
dotnet run -c Release -f net10.0 -- housekeeping
dotnet run -c Release -f net11.0 -- exit
dotnet run -c Release -f net11.0 -- housekeeping

Configuration

.NET 10.0.7 vs .NET 11.0.0-preview.7.26381.103 (SDK 11.0.100-preview.7.26381.103). The effect was also present, slightly larger, on preview 6. macOS 26.5.2, Apple M5, 10 cores, ARM64.

Regression?

Yes, from .NET 10. The reply-then-exit scenario improved on the preview. Only the reply-then-keep-running scenario regressed. Preview 6 measured somewhat worse than preview 7 on the regressed scenario, so the area seems to be under active tuning.

Data

Every number below is the output from the above program, 200,000 timed requests after a 20,000-request warmup. Similar to what I did in the other bug.

Default settings first...

default
                          .NET 10             .NET 11 preview 7
reply, then exit          1,622 ns/request    1,278 ns/request
reply, then housekeeping  2,475 ns/request    3,409 ns/request

Without the tail work the preview is faster than .NET 10, and with it the preview is slower, 1.4x in this run and up to 2x in other runs. Interestingly enough, there is a somewhat steady signal here in what the tail work adds on top of the exit scenario - which is about 850 ns on .NET 10 here, about 2,100 ns on the preview.

The two tiering settings matter a lot in the separate warm-up report I filed as #132943. Seeing if it's also related here, they barely move this one...

DOTNET_TieredCompilation=0
                          .NET 10             .NET 11 preview 7
reply, then exit          1,762 ns/request      711 ns/request
reply, then housekeeping  2,067 ns/request    3,983 ns/request
DOTNET_TieredPGO=0
                          .NET 10             .NET 11 preview 7
reply, then exit          1,729 ns/request    1,101 ns/request
reply, then housekeeping  2,173 ns/request    3,595 ns/request

With tiering off entirely the preview posts its fastest exit number from my testing and its worst housekeeping gap, so this is not codegen warming up.

Then the same three configurations with runtime-async enabled...

dotnet build -c Release -f net11.0 -p:Features=runtime-async=on --no-incremental
dotnet run -c Release -f net11.0 --no-build -- exit
dotnet run -c Release -f net11.0 --no-build -- housekeeping
.NET 11 preview 7, runtime-async on
                          default             TieredCompilation=0   TieredPGO=0
reply, then exit          1,500 ns/request      823 ns/request        966 ns/request
reply, then housekeeping  4,953 ns/request    3,358 ns/request      3,326 ns/request

Runtime-async does not help this pattern, but it does not hurt it either. The default column reading worst bugged me, so I re-ran both compilation modes five times each. A short 200k-request run of either mode wanders between 3.4 and 6.0 us, and 10-second chunked runs of both settle at the same 3.3 to 3.5 us, so the 4,953 above was an unlucky draw rather than a runtime-async cost. The two tiering columns read better for a related reason. Tiering off means there is no early elevated window to sample, and PGO off makes that window much shorter, so those short runs land near steady state while a default run spends most of its calls inside the window. The exit row has the same shape, with its default number well above the roughly 370 ns that a 10-second run works down to.

Here is what the tail work adds on top of the exit scenario in each of those runs...

                             .NET 10          .NET 11 preview 7
default                      +853 ns          +2,131 ns
DOTNET_TieredCompilation=0   +305 ns          +3,272 ns
DOTNET_TieredPGO=0           +444 ns          +2,494 ns

No combination of settings brings the two runtimes close. .NET 10 stays in the hundreds of nanoseconds and the preview stays in the thousands. And it is not warmup either. The second argument sets the warmup count, and the regression holds through 500k iterations, which is more than a second of continuous work before measurement begins (these runs are from an earlier sitting):

warmup  20,000:   net10 2,784   net11 3,943
warmup 200,000:   net10 2,970   net11 3,286
warmup 500,000:   net10 2,292   net11 3,190

Letting it run longer does not change it. I also ran the same round trip chunked the way the #132943 report does, no warmup, a per-request average printed every 20,000 requests, for 10 seconds per scenario:

housekeeping, per-request average over 10 seconds
                             .NET 10             .NET 11 preview 7
first chunk                  2,583 ns/request    4,099 ns/request
at ~1 s                      2,042 ns/request    3,276 ns/request
at ~2 s                      1,969 ns/request    3,169 ns/request
at ~5 s                      2,037 ns/request    3,219 ns/request
at ~10 s                     2,285 ns/request    3,342 ns/request
requests completed in 10 s   4,900,000           2,860,000

The preview eases from about 4.3 us in its first few chunks to about 3.4 by the end and never gets near .NET 10's 2.0 to 2.3. There is no step down like the one in #132943. The exit scenario in the same probe does step down, on both runtimes: .NET 10 settles near 1,150 ns/request after the first second, and the preview drops to about 330 around the two-second mark and holds it for the remaining 18 million requests. So the recompile window from #132943 comes and goes in this test, and the housekeeping scenario performance problem never disappears.

.NET 10:  ReplyThenExit    725 ns   ReplyThenHousekeeping  2,566 ns   ratio 3.57
.NET 11:  ReplyThenExit    382 ns   ReplyThenHousekeeping  3,137 ns   ratio 8.29

Sampled-thread-time traces (dotnet-trace collect --profile dotnet-sampled-thread-time) of this workload show the preview spending its extra time in Thread.SpinWaitInternal and PortableThreadPool+WorkerThread.MaybeAddWorkingWorker, neither of which is hot on .NET 10. The parking path changed too as the workers on the preview block in LowLevelLifoSemaphore.Block / WaitSubsystem+ThreadWaitInfo.Wait, where .NET 10 parked in LowLevelLifoSemaphore.WaitNative.

One measurement note for anyone reproducing this. BenchmarkDotNet's in-process toolchain inflates the preview's numbers for this pattern by a further ~1.5x while leaving .NET 10 unchanged, so like we found in the other bug... measure out of process. Benchmarks.cs is attached this time!

Metadata

Metadata

Assignees

No one assigned

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions