Performance degradation on upgrade from .NET 8 to .NET 9/10 with concurrent requests

[leondeklerkfenetre]

Description

When doing concurrent requests after the API has started, the response times increase significantly compared to older .NET versions. On our front-end we are doing some initial calls with some of the calls being sequential, and some blocks of concurrent calls. Overall, the response time is 6-8 times slower. If the calls are all executed in sequence, there are no performance issues.

Performance issues only occur when running from Visual Studio (26) with the Diagnostic tools enabled. When running without a debugger (Ctrl + f5 or the performance analyzer) the issue is not noticeable.

You can clone my minimal example from here: https://github.com/leondeklerkfenetre/dotnet-performance-degradation
The README contains steps on how to run

Configuration

.NET 10.0.100
Windows 11 Business 26200.7171
x64
Visual Studio 26

Regression?

The performance is good on .NET 6/7/8 but degrades on .NET 9/10 (10 improves slightly over 9)

Data

Version	Avg Response
.NET 8	49ms
.NET 9	437ms
.NET 10	340ms

Analysis

The only pointer I can give is that the issue is mostly noticeable with the diagnostic tools and debugger enabled. When using the performance analyzer or after creating a release build. Also, the performance on .NET 6/7/8 is nearly identical.

[dotnet-policy-service]

Tagging subscribers to this area: @dotnet/ncl
See info in area-owners.md if you want to be subscribed.

[ManickaP]

When running without a debugger (Ctrl + f5 or the performance analyzer) the issue is not noticeable.

This is likely an issue with VS itself. As you state, it doesn't manifest outside of a debugger. I'd recommend filing this issue directly with Visual Studio.

As it is now, there's nothing we (networking team) can do about it.

[leondeklerkfenetre]

@ManickaP
I would like to re-open this issue. I've opened a ticket with VS, and after collecting multiple traces using PerfView they indicate that there is nothing in the traces to indicate it is an issue from the VS side. They have asked me to re-open the issue here to investigate more from the .NET side.

They indicated to add the following code to the startup of the API:

builder.Logging.AddSimpleConsole(options =>
{
    options.TimestampFormat = "HH:mm:ss:fff ";
    options.IncludeScopes = true;
});

For both .NET 8 and .NET 10 I have re-tested with this enabled and collected the console output into files, and added them to my example repo:
https://github.com/leondeklerkfenetre/dotnet-performance-degradation/blob/main/.net8-log.txt
https://github.com/leondeklerkfenetre/dotnet-performance-degradation/blob/main/.net10-log.txt

What I can see from those logs (please correct me if my understanding is incorrect), is that for example the connection id for the getAdministrator call first appears in .NET 8 with Connection id "0HNHM7BCOAIB3" accepted. at 10:19:12:104 and last appears with Connection id "0HNHM7BCOAIB3" stopped. at 10:19:12:247 so a total of 143 ms. For .net 10 this is Connection id "0HNHM7EEM9R5K" accepted. at 10:24:40:694 and Connection id "0HNHM7EEM9R5K" stopped. at 10:24:41:551, so a difference of 857 ms.

If you want me to collect more information, please ask me and I can try to provide it.

Also, on recommendation of the VS team, I've added per request timing and total time data to my testing setup.
please note that all calls simply return a return Ok(new { Success = true }); without performing any logic (or authorization)

.NET 8 request timings overview

Request	Time
Login	223.6642 ms
CheckBrowser	27.162199999999984 ms
IsAuthenticated	73.18989999999997 ms
getGenericFrontEndSettings	7.314300000000003 ms
GetGlobalTabsSettings	2.4370999999999867 ms
getLocalizedResourcesGeneric	9.02520000000004 ms
getGeneralApplicationData	11.77520000000004 ms
getGlobalResources	42.10900000000004 ms
getLocalizedResourcesResource	44.563600000000065 ms
isCIDRValid	48.964200000000005 ms
getIsAdministrator	48.92660000000001 ms
getCanViewAllOrganizations	62.17629999999997 ms
getCanLinkUsersFromOtherOrganizations	62.21289999999999 ms
topBarData	69.54880000000003 ms
getGUISettings	84.19079999999997 ms
getOrganizationGUISettings	93.68880000000001 ms
Avg	56.93431875000001 ms
Total	411.58990000000006 ms

.NET 10 request timings

Request	Time
Login	132.31640000000002 ms
CheckBrowser	10.201199999999972 ms
IsAuthenticated	33.80459999999999 ms
getGenericFrontEndSettings	5.668999999999983 ms
GetGlobalTabsSettings	2.081100000000049 ms
getLocalizedResourcesGeneric	9.348299999999995 ms
getGeneralApplicationData	12.223299999999995 ms
topBarData	347.3136999999999 ms
getCanViewAllOrganizations	351.02359999999993 ms
getCanLinkUsersFromOtherOrganizations	350.7796 ms
isCIDRValid	389.444 ms
getGlobalResources	391.27609999999993 ms
getLocalizedResourcesResource	393.7992 ms
getIsAdministrator	390.0144 ms
getGUISettings	390.09670000000006 ms
getOrganizationGUISettings	420.07039999999995 ms
Avg	226.84135 ms
Total	605.8034 ms

[MihaZupan]

The VS ticket for reference: https://developercommunity.visualstudio.com/t/Performance-degradation-on-upgrade-from/11007946?sort=active

I tried simplifying this down further.
For the server:

var builder = WebApplication.CreateBuilder(args);
builder.Logging.AddFilter("Microsoft.AspNetCore.Server.Kestrel", LogLevel.Debug);
var app = builder.Build();

app.MapGet("/test", () => "Hello");
app.Run("https://localhost:7241");

And the test client sending 3 batches of 16 concurrent requests:

Client code

using System.Diagnostics;
using System.Net.Security;
using System.Net.Sockets;

while (true)
{
    Console.WriteLine("Waiting ...");
    Console.ReadLine();

    // 3 batches of 16 concurrent requests
    await TestAsync();
    await TestAsync();
    await TestAsync();
}

async Task TestAsync()
{
    Stopwatch stopwatch = Stopwatch.StartNew();

    TimeSpan[][] timings = await Task.WhenAll(
    [
        MakeRequest(), MakeRequest(), MakeRequest(), MakeRequest(),
        MakeRequest(), MakeRequest(), MakeRequest(), MakeRequest(),
        MakeRequest(), MakeRequest(), MakeRequest(), MakeRequest(),
        MakeRequest(), MakeRequest(), MakeRequest(), MakeRequest(),
    ]);

    stopwatch.Stop();

    int avgTcp = (int)timings.Average(t => t[0].TotalMilliseconds);
    int maxTcp = (int)timings.Max(t => t[0].TotalMilliseconds);

    int avgTls = (int)timings.Average(t => t[1].TotalMilliseconds);
    int maxTls = (int)timings.Max(t => t[1].TotalMilliseconds);

    int avgHttp = (int)timings.Average(t => t[2].TotalMilliseconds);
    int maxHttp = (int)timings.Max(t => t[2].TotalMilliseconds);

    Console.WriteLine($"Total: {(int)stopwatch.ElapsedMilliseconds} ms. TCP: avg={avgTcp} max={maxTcp}, TLS: avg={avgTls} max={maxTls}, HTTP: avg={avgHttp} max={maxHttp}");

    Task<TimeSpan[]> MakeRequest() => Task.Run(async () =>
    {
        Stopwatch stopwatch = Stopwatch.StartNew();
        List<TimeSpan> timings = [];

        // TCP Connect
        using Socket socket = new Socket(SocketType.Stream, ProtocolType.Tcp) { NoDelay = true };
        await socket.ConnectAsync("127.0.0.1", 7241);
        timings.Add(stopwatch.Elapsed); stopwatch.Restart();

        using var stream = new NetworkStream(socket, ownsSocket: true);
        using var sslStream = new SslStream(stream);

        // TLS Handshake
        await sslStream.AuthenticateAsClientAsync(new SslClientAuthenticationOptions
        {
            TargetHost = "localhost",
            RemoteCertificateValidationCallback = (_, _, _, _) => true
        });
        timings.Add(stopwatch.Elapsed); stopwatch.Restart();

        // HTTP Request/Response
        await sslStream.WriteAsync("GET /test HTTP/1.1\r\nHost: localhost\r\nContent-Length: 0\r\n\r\n"u8.ToArray());
        byte[] buffer = new byte[1024];
        int bytesRead = await sslStream.ReadAsync(buffer);
        timings.Add(stopwatch.Elapsed); stopwatch.Restart();

        return timings.ToArray();
    });
}

I'm seeing results along the lines of:

.NET 8
// Run 1
Total: 355 ms. TCP: avg=1 max=2, TLS: avg=157 max=181, HTTP: avg=185 max=203
Total: 436 ms. TCP: avg=1 max=2, TLS: avg=233 max=376, HTTP: avg=63 max=287
Total: 326 ms. TCP: avg=0 max=2, TLS: avg=162 max=302, HTTP: avg=26 max=46

// Run 2
Total: 390 ms. TCP: avg=1 max=1, TLS: avg=194 max=214, HTTP: avg=181 max=197
Total: 417 ms. TCP: avg=0 max=2, TLS: avg=246 max=398, HTTP: avg=46 max=106
Total: 350 ms. TCP: avg=0 max=2, TLS: avg=175 max=330, HTTP: avg=33 max=185

// Run 3
Total: 388 ms. TCP: avg=1 max=1, TLS: avg=191 max=192, HTTP: avg=181 max=196
Total: 428 ms. TCP: avg=0 max=0, TLS: avg=231 max=348, HTTP: avg=42 max=90
Total: 388 ms. TCP: avg=1 max=3, TLS: avg=178 max=369, HTTP: avg=33 max=115

.NET 9
// Run 1
Total: 467 ms. TCP: avg=0 max=2, TLS: avg=262 max=263, HTTP: avg=158 max=202
Total: 1119 ms. TCP: avg=1 max=4, TLS: avg=468 max=1010, HTTP: avg=240 max=678
Total: 781 ms. TCP: avg=0 max=2, TLS: avg=358 max=774, HTTP: avg=54 max=209

// Run 2
Total: 618 ms. TCP: avg=1 max=2, TLS: avg=370 max=371, HTTP: avg=197 max=247
Total: 676 ms. TCP: avg=0 max=2, TLS: avg=383 max=668, HTTP: avg=68 max=169
Total: 917 ms. TCP: avg=0 max=1, TLS: avg=446 max=851, HTTP: avg=78 max=162

// Run 3
Total: 451 ms. TCP: avg=1 max=2, TLS: avg=320 max=321, HTTP: avg=119 max=129
Total: 817 ms. TCP: avg=0 max=2, TLS: avg=439 max=741, HTTP: avg=129 max=448
Total: 1121 ms. TCP: avg=0 max=1, TLS: avg=541 max=1110, HTTP: avg=120 max=713

But if I comment out the debug-level Kestrel logs (builder.Logging.AddFilter ...) I instead see

Total: 233 ms. TCP: avg=0 max=1, TLS: avg=147 max=148, HTTP: avg=83 max=84
Total: 18 ms. TCP: avg=0 max=2, TLS: avg=14 max=17, HTTP: avg=1 max=2
Total: 8 ms. TCP: avg=0 max=2, TLS: avg=5 max=7, HTTP: avg=1 max=2

[MihaZupan]

@leondeklerkfenetre do you see this issue persist if you avoid debug-level Kestrel logs?

[MihaZupan]

cc: @dotnet/area-extensions-logging, @JamesNK in case you're aware of anything changing around logging infra / Kestrel around .NET 9 that might explain the new delays when running under VS

TL;DR; sending a couple HTTP requests to Kestrel in parallel is noticeably slower in .NET 9 than .NET 8 when running under the debugger.

[leondeklerkfenetre]

@leondeklerkfenetre do you see this issue persist if you avoid debug-level Kestrel logs?

Yes, I see the same behavior, without the builder.Logging.AddFilter line everything is much faster.