Performance regression for .NET 9.0 / .NET 10.0 vs. .NET 8.0

[ayende]

Description

During benchmarking, we found that there is a significant difference between the performance of our project (RavenDB) between .NET 8.0 and .NET 9.0 or .NET 10.0.

Our results:

v7.1 (.net 8.0)
[OVERALL], RunTime(ms), 50225
[OVERALL], Throughput(ops/sec), 19910.40318566451

v7.1 (.net 9.0)
[OVERALL], RunTime(ms), 99615
[OVERALL], Throughput(ops/sec), 10038.648797871807

That is close to 50%(!) regression in our tests.

We were able to reproduce a similar regression in a much smaller benchmark, where we are observing roughly 10% performance regression between 8.0 and 9.0 (10.0 is a bit better than 9.0, it is still slower than 8.0).

Repro code here: https://gist.github.com/ayende/e94d9ad6e8bba41a36d33ffb9e6de2ad

Configuration

• All tests were run on Windows
• dotnet versions tests:

> dotnet --list-sdks
8.0.413 [C:\Program Files\dotnet\sdk]
9.0.304 [C:\Program Files\dotnet\sdk]
10.0.100-preview.6.25358.103 [C:\Program Files\dotnet\sdk]

Regression?

Significant performance regression

• .NET 8.0 - 955ms - 995ms tested
• .NET 9.0 - 1103ms - 1132ms tested

Full results:

PS C:\Work\tryout>  .\bin\Release\net8.0\ConsoleApp1.exe
955
PS C:\Work\tryout>  .\bin\Release\net8.0\ConsoleApp1.exe
989
PS C:\Work\tryout>  .\bin\Release\net8.0\ConsoleApp1.exe
995
PS C:\Work\tryout>  .\bin\Release\net9.0\ConsoleApp1.exe
1103
PS C:\Work\tryout>  .\bin\Release\net9.0\ConsoleApp1.exe
1119
PS C:\Work\tryout>  .\bin\Release\net9.0\ConsoleApp1.exe
1132

Data

Here is the profiling output comparing those two versions.
Note: Sparrow.Json.JsonOperationContext.ReadObjectInternal(Object, String, UsageMode, IBlittableDocumentModifier)

• .NET 8.0 is 2,201 ms under profiler
• .NET 9.0 is 2,847 ms under profiler

Repro code

https://gist.github.com/ayende/e94d9ad6e8bba41a36d33ffb9e6de2ad

I run the build using dotnet build -c Release and change the <TargetFramework>net9.0</TargetFramework> in the .csproj from net8.0 to net9.0 to test the different frameworks.

@redknightlois @EgorBo

[EgorBo]

Tried to repro on Windows-x64 Ryzen 7950x - I see no difference, if I change your repro to run in a loop, I get these numbers:
net8.0:

1027
631
635
667
640
638
639

net9.0:

1013
616
630
632
641
634
617

net10.0:

1026
597
588
570
564
588
575

[EgorBo]

It looks like the repro is rather measuring performance of Tier0 or R2R coverage

[redknightlois]

Maybe, but that doesn't explain this one though. I could not believe my eyes when I saw that. It is write only YCSB benchmark.

v7.1 (.net 8.0)
[OVERALL], RunTime(ms), 50225
[OVERALL], Throughput(ops/sec), 19910.40318566451

v7.1 (.net 9.0)
[OVERALL], RunTime(ms), 99615
[OVERALL], Throughput(ops/sec), 10038.648797871807

That is full 6 seconds just in this call.

And to be true, we uncovered this as a regression on the unreleased v8.0 which is targetting .Net 9.0. But then I went back and target .Net 9.0 on the current version and the regression is huge there also. Only difference is .Net 9.0 instead of .Net 8.0 for the same benchmark, same setup, fully reproducible over time, etc.

EDIT: I am looking at the processor, could it be processor dependent? Mine is a AMD Ryzen 7 5800X 8-Core Processor. Also is there any environment variable that you think it would allow us to shrink the potential variance surface?

[dotnet-policy-service]

Tagging subscribers to this area: @JulieLeeMSFT, @jakobbotsch
See info in area-owners.md if you want to be subscribed.

[AndyAyersMS]

I have a 5800H which is similar enough perhaps, and I see a regression too. Seems like a fair amount of time is spent in the profiling helper method (which is native, so might not show up well in some profilers).

With defaults:

C:\bugs\r118909\repro\bin\Release\net8.0\ConsoleApp1.exe
1013
1002
1017
1024
1019

C:\bugs\r118909\repro\bin\Release\net9.0\ConsoleApp1.exe
1107
1124
1114
1114
1109

C:\bugs\r118909\repro\bin\Release\net10.0\ConsoleApp1.exe
1087
1066
1054
1068
1076

One thing that can help in this case is to move code a bit more aggressively into Tier1. Here are some examples

Suppress the initial un-instrumented tier:

set DOTNET_TieredPGO_InstrumentOnlyHotCode=0

C:\bugs\r118909\repro\bin\Release\net8.0\ConsoleApp1.exe
1039
970
995
995
988

C:\bugs\r118909\repro\bin\Release\net9.0\ConsoleApp1.exe
1014
1010
1000
1012
1009

C:\bugs\r118909\repro\bin\Release\net10.0\ConsoleApp1.exe
957
954
936
937
951

Accelerate promotion of methods to Tier1:

set DOTNET_TC_CallCountingDelayMs=0

C:\bugs\r118909\repro\bin\Release\net8.0\ConsoleApp1.exe
750
768
788
763
745

C:\bugs\r118909\repro\bin\Release\net9.0\ConsoleApp1.exe
786
786
798
831
809

C:\bugs\r118909\repro\bin\Release\net10.0\ConsoleApp1.exe
787
779
808
796
792

I haven't tried on more modern HW yet but given Egor's results perhaps it is some issue with how the Zen3 handles the counter probe call in a loop or something.

[AndyAyersMS]

I've looked at profiles some on my 5800H and nothing jumps out just yet.

Might be helpful to either look at the YCSB benchmark or the full benchmark, as those regressions are more substantial and perhaps easier to spot.

[AndyAyersMS]

Just to follow up, here's an ETL profile comparison. .NET 8 on the left, .NET 9 on the right.

I was mainly looking for tiering impact.

The elapsed times here weren't too different, so the deltas are pretty small.

And here's my homegrown tool output

[redknightlois]

I will be trying out what you mentioned will be able to have some data for you in 20' or so. Meanwhile have a look at the following methods:

The reason why they are interesting is because they are particularly well suited to look at the assembly generated.

Specially this one: https://github.com/ravendb/ravendb/blob/v7.1/src/Sparrow/Json/BlittableWriter.cs#L200
Look at the FastList implementation and the .get indexer, I noted something strange on a few of profiles, it could be a hint.

[redknightlois]

No change with running with either of the instrumentations. I can clearly see the change in behavior in the startup on the first 10 seconds (closer to final throughput much earlier) but it has no impact on the final throughput.

v7.1 (.net 8.0)
[OVERALL], RunTime(ms), 50225
[OVERALL], Throughput(ops/sec), 19910.40318566451

v7.1 (.net 9.0 + InstrumentOnlyHotCode)

[OVERALL], RunTime(ms), 95716
[OVERALL], Throughput(ops/sec), 10447.57407330018

v7.1 (.net 9.0 + InstrumentOnlyHotCode + CallCountingDelayMs)

[OVERALL], RunTime(ms), 92947
[OVERALL], Throughput(ops/sec), 10758.819542319816

[AndyAyersMS]

No change with running with either of the instrumentations.

Not too surprising on such a long-running test. They can be useful sometimes for short-lived computation like in the gist where there is a benefit to fast tiering up.