Repository navigation
Increased variance in some benchmark tests #87324
Description
We have recently noticed a mysterious increase in variance for a number of benchmark tests. For example
MicroBenchmarks.Serializers.Json_FromStream.SystemTextJson_SourceGen_
Zooming in to the recent history we see that the variance changes started around June 3.
One hypothesis is that the variance is caused by Dynamic PGO, but Dynamic PGO was enabled on May 19th and performance improved at that point and remained steady for two weeks afterwards. So, while Dynamic PGO may be involved there is seemingly some other causal factor here too.
Looking at this benchmark across os/isa we see for this particular test the variance was only an issue for win-x64-intel (pink)
I will collate a few more examples here to see if anything obvious jumps out.
Activity
AndyAyersMS commentedon Jun 9, 2023
Looking at secondary counters it seems some aspect of GC may have changed -- fewer Gen0 GCs
If we zoom in like above we see the GC change is well correlated with the perf change (hard to get the x-axis exactly the same here, but it's close).
A plausible commit range here is 7febca6...2f18320
but there does not seem to be any obvious culprit in that range.
AndyAyersMS commentedon Jun 9, 2023
Many of the other tests in #87179 have similar behaviors, though most of those seem to have stabilized as of late.
AndyAyersMS commentedon Jun 9, 2023
System.Collections.ContainsTrue<Int32>.ICollection(Size: 512)'s variance seems to be related to enabling Dynamic PGO
PGO history
NonPGO (until May 19) history
So this is not new behavior.
@EgorBo possibly a case for testing if reservoir size is too small.
this one also seems to have fixed itself lately
AndyAyersMS commentedon Jun 15, 2023
https://pvscmdupload.blob.core.windows.net/reports/allTestHistory/refs/heads/main_arm64_ubuntu%2020.04/MicroBenchmarks.Serializers.Json_ToString(MyEventsListerViewModel).JsonNet_.html
dotnet/perf-autofiling-issues#18835
AndyAyersMS commentedon Jun 17, 2023
The first test in this issue now seems to have calmed down:
Possibly because of the larger reservoir table size for class probes in #87332
EgorBo commentedon Jun 20, 2023
These two are also good examples:
AndyAyersMS commentedon Jun 21, 2023
Another example (from #87179): System.Collections.CtorFromCollection(Int32).SortedSet(Size: 512)
AndyAyersMS commentedon Jun 21, 2023
Some analysis I did for #87179 suggests one idea to try. With the scalable profile mode #84427 and pervasive sparse profiling #80481, during count reconstruction we often compute the difference between counter values; and if that value is negative, we set the count to zero. But zero count has a special meaning with PGO (see eg #48778) and it may be the jit is getting overly hung up here by the zero, and this happens randomly from run to run.
We could validate this by seeing if the PGO counts for the benchmarks above are large enough that we switch from deterministic to randomized counting (currently this happens when the count reaches 8192).
So one idea is to set the diff count for these inconsistent cases to something small or nonzero, say 1% of the larger/smaller value being subtracted, since large counts have a 2% or so margin of error.
AndyAyersMS commentedon Jun 22, 2023
The hottest method in System.Collections.CtorFromCollection(Int32).SortedSet(Size: 512) is
PickPivotAndPartition, and the gathered PGO data for this has counts in the millions:So it certainly seems likely that we could run into the problem noted above, where we subtract two large approximate counts and end up with a negative result.
cincuranet commentedon Jun 22, 2023
JIT: don't set edge weights to zero for inconsistent profiles
JIT: don't set edge weights to zero for inconsistent profiles (#87947)
EgorBo commentedon Jun 27, 2023
BenchE benchmark
cincuranet commentedon Jun 29, 2023
AndyAyersMS commentedon Jul 5, 2023
https://pvscmdupload.blob.core.windows.net/reports/allTestHistory/refs/heads/main_arm64_ubuntu%2020.04/BenchmarksGame.RegexRedux_5.RunBench%28options%3a%20Compiled%29.html
cincuranet commentedon Jul 11, 2023
AndyAyersMS commentedon Aug 1, 2023
Also possibly related (for non-windows): #89340. Looks like the fix (#89350) might have worked on RegexRedux above:
AndyAyersMS commentedon Aug 1, 2023
Back to the intial benchmark above
Non-PGO is more stable (note: different axes)
Linux-x64 (same HW), win-amd-x64 (different HW), win-intel-x86 (same HW) are all stable:
When run locally this benchmark doesn't warm up enough to reliably make it to Tier1 code when PGO is enabled
AndyAyersMS commentedon Aug 2, 2023
So possibly the variance is from using median results in the lab where the iteration to iteration times drop sharply once everything is finally tiered up (note on my machine PGO is quite typically always faster)
Here's the entire set of these tests, locally. "diff" is with PGO, "base" is without.
enchmarkDotNet v0.13.7-nightly.20230717.35, Windows 11 (10.0.22621.1992/22H2/2022Update/SunValley2)
Intel Core i7-8700 CPU 3.20GHz (Coffee Lake), 1 CPU, 12 logical and 6 physical cores
.NET SDK 8.0.100-preview.4.23260.5
[Host] : .NET 6.0.20 (6.0.2023.32017), X64 RyuJIT AVX2
Job-KLSCSY : .NET 8.0.0 (42.42.42.42424), X64 RyuJIT AVX2
Job-DEMYRR : .NET 8.0.0 (42.42.42.42424), X64 RyuJIT AVX2
PowerPlanMode=00000000-0000-0000-0000-000000000000 Arguments=/p:EnableUnsafeBinaryFormatterSerialization=true IterationTime=250.0000 ms
MaxIterationCount=20 MinIterationCount=15 WarmupCount=1
Adding
Gives better numbers with PGO enabled (diff)
BenchmarkDotNet v0.13.7-nightly.20230717.35, Windows 11 (10.0.22621.1992/22H2/2022Update/SunValley2)
Intel Core i7-8700 CPU 3.20GHz (Coffee Lake), 1 CPU, 12 logical and 6 physical cores
.NET SDK 8.0.100-preview.4.23260.5
[Host] : .NET 6.0.20 (6.0.2023.32017), X64 RyuJIT AVX2
Job-VTIKZT : .NET 8.0.0 (42.42.42.42424), X64 RyuJIT AVX2
Job-MABZQL : .NET 8.0.0 (42.42.42.42424), X64 RyuJIT AVX2
PowerPlanMode=00000000-0000-0000-0000-000000000000 Arguments=/p:EnableUnsafeBinaryFormatterSerialization=true IterationTime=250.0000 ms
MaxIterationCount=20 MaxWarmupIterationCount=10 MinIterationCount=15
MinWarmupIterationCount=6 WarmupCount=-1
AndyAyersMS commentedon Aug 4, 2023
It looks like there are a variety of explanations:
BitScanReverseto use__builtin_clz#89350,I am going to close this as I don't see anything actionable right now; we can revisit paritcular cases if they prove problematic.