Runtime: [Perf -196%] System.Collections.ContainsTrue<Int32> (6)

[DrewScoggins]

Run Information

Architecture | x86
-- | --
OS | Windows 10.0.18362
Changes | diff

Regressions in System.Collections.ContainsTrue<Int32>

Benchmark | Baseline | Test | Test/Base | Modality | Baseline Outlier
-- | -- | -- | -- | -- | --
Array | 41.69 μs | 121.84 μs | 2.92 | | True
ImmutableArray | 43.10 μs | 116.85 μs | 2.71 | | False
List | 40.60 μs | 121.31 μs | 2.99 | | True
Queue | 41.12 μs | 121.74 μs | 2.96 | | True
ICollection | 40.48 μs | 120.94 μs | 2.99 | | True
Span | 38.31 μs | 121.30 μs | 3.17 | | False

Historical Data in Reporting System

Repro

git clone https://github.com/dotnet/performance.git
py .\performance\scripts\benchmarks_ci.py -f netcoreapp5.0 --filter 'System.Collections.ContainsTrue<Int32>*';

Histogram

System.Collections.ContainsTrue.Array(Size: 512)

[ 37830.974 ;  44220.358) | @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
[ 44220.358 ;  50609.743) | 
[ 50609.743 ;  56999.127) | 
[ 56999.127 ;  63388.512) | 
[ 63388.512 ;  69777.896) | 
[ 69777.896 ;  76167.281) | 
[ 76167.281 ;  82556.665) | 
[ 82556.665 ;  88946.050) | 
[ 88946.050 ;  95335.434) | 
[ 95335.434 ; 101724.819) | 
[101724.819 ; 108114.203) | 
[108114.203 ; 115700.072) | 
[115700.072 ; 122089.456) | @@@@@@@@@

System.Collections.ContainsTrue.ImmutableArray(Size: 512)

[ 39931.110 ;  45983.331) | @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
[ 45983.331 ;  52035.551) | 
[ 52035.551 ;  58087.772) | 
[ 58087.772 ;  64139.992) | 
[ 64139.992 ;  70192.213) | 
[ 70192.213 ;  76244.433) | 
[ 76244.433 ;  82296.654) | 
[ 82296.654 ;  88348.874) | 
[ 88348.874 ;  94401.095) | 
[ 94401.095 ; 100453.315) | 
[100453.315 ; 106505.535) | 
[106505.535 ; 114017.398) | 
[114017.398 ; 120282.927) | @@@@@@@@@

System.Collections.ContainsTrue.List(Size: 512)

[ 37081.144 ;  43571.129) | @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
[ 43571.129 ;  50061.114) | 
[ 50061.114 ;  56551.100) | 
[ 56551.100 ;  63041.085) | 
[ 63041.085 ;  69531.070) | 
[ 69531.070 ;  76021.056) | 
[ 76021.056 ;  82511.041) | 
[ 82511.041 ;  89001.026) | 
[ 89001.026 ;  95491.012) | 
[ 95491.012 ; 101980.997) | 
[101980.997 ; 108470.982) | 
[108470.982 ; 115647.215) | 
[115647.215 ; 122137.200) | @@@@@@@@@

System.Collections.ContainsTrue.Queue(Size: 512)

[ 38137.016 ;  44550.932) | @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
[ 44550.932 ;  50964.849) | 
[ 50964.849 ;  57378.765) | 
[ 57378.765 ;  63792.681) | 
[ 63792.681 ;  70206.597) | 
[ 70206.597 ;  76620.514) | 
[ 76620.514 ;  83034.430) | 
[ 83034.430 ;  89448.346) | 
[ 89448.346 ;  95862.262) | 
[ 95862.262 ; 102276.179) | 
[102276.179 ; 108690.095) | 
[108690.095 ; 115921.666) | 
[115921.666 ; 122335.582) | @@@@@@@@@

System.Collections.ContainsTrue.ICollection(Size: 512)

[ 37234.692 ;  43644.541) | @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
[ 43644.541 ;  50054.389) | 
[ 50054.389 ;  56464.238) | 
[ 56464.238 ;  62874.086) | 
[ 62874.086 ;  69283.935) | 
[ 69283.935 ;  75693.783) | 
[ 75693.783 ;  82103.632) | 
[ 82103.632 ;  88513.480) | 
[ 88513.480 ;  94923.329) | 
[ 94923.329 ; 101333.177) | 
[101333.177 ; 107743.026) | 
[107743.026 ; 115217.905) | 
[115217.905 ; 121627.753) | @@@@@@@@@

System.Collections.ContainsTrue.Span(Size: 512)

[ 34357.683 ;  41646.559) | @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
[ 41646.559 ;  48421.977) | 
[ 48421.977 ;  55197.395) | 
[ 55197.395 ;  61972.813) | 
[ 61972.813 ;  68748.231) | 
[ 68748.231 ;  75523.650) | 
[ 75523.650 ;  82299.068) | 
[ 82299.068 ;  89074.486) | 
[ 89074.486 ;  95849.904) | 
[ 95849.904 ; 102625.322) | 
[102625.322 ; 109400.741) | 
[109400.741 ; 118252.968) | 
[118252.968 ; 125394.354) | @@@@@@@@@

Docs

Profiling workflow for dotnet/runtime repository
Benchmarking workflow for dotnet/runtime repository

[msftbot[bot]]

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

[DrewScoggins]

From @adamsitnik

It looks like a 32-bit only regression (both ARM and x86).

System.Collections.ContainsTrue.ICollection(Size: 512)

| Conclusion | Base | Diff | Base/Diff | Modality | Operating System | Bit | Processor Name | Base Runtime | Diff Runtime |
| ---------- | --------:| ---------:| ---------:| --------:| ----------------------- | --- | ------------------------------------------- | --------------- | --------------------- |
| Slower | 65833.64 | 190178.39 | 0.35 | | Windows 10.0.18363.1016 | Arm | Microsoft SQ1 3.0 GHz | .NET Core 3.1.6 | 5.0.100-rc.1.20413.9 |
| Same | 33533.22 | 33973.23 | 0.99 | | Windows 10.0.18363.959 | X64 | Intel Xeon CPU E5-1650 v4 3.60GHz | .NET Core 3.1.6 | 5.0.100-rc.1.20404.3 |
| Same | 35217.30 | 34374.73 | 1.02 | | Windows 10.0.18363.959 | X64 | Intel Xeon CPU E5-1650 v4 3.60GHz | .NET Core 3.1.6 | 5.0.100-rc.1.20418.3 |
| Same | 39272.39 | 39510.22 | 0.99 | | Windows 10.0.19041.450 | X64 | Intel Core i7-5557U CPU 3.10GHz (Broadwell) | .NET Core 3.1.6 | 5.0.100-rc.1.20413.9 |
| Same | 36729.22 | 36526.22 | 1.01 | | Windows 10.0.19041.450 | X64 | Intel Core i7-6700 CPU 3.40GHz (Skylake) | .NET Core 3.1.6 | 5.0.100-rc.1.20419.9 |
| Same | 31012.96 | 31011.54 | 1.00 | | Windows 10.0.19042 | X64 | Intel Core i7-7700 CPU 3.60GHz (Kaby Lake) | .NET Core 3.1.6 | 5.0.100-rc.1.20418.3 |
| Slower | 35646.15 | 115208.04 | 0.31 | | Windows 10.0.18363.959 | X86 | Intel Xeon CPU E5-1650 v4 3.60GHz | .NET Core 3.1.6 | 5.0.100-rc.1.20420.2 |
| Slower | 39809.39 | 128785.22 | 0.31 | | Windows 10.0.19041.450 | X86 | Intel Core i7-5557U CPU 3.10GHz (Broadwell) | .NET Core 3.1.6 | 5.0.100-rc.1.20419.5 |
| Same | 34530.97 | 34085.75 | 1.01 | | ubuntu 18.04 | X64 | Intel Xeon CPU E5-1650 v4 3.60GHz | .NET Core 3.1.6 | 5.0.100-rc.1.20403.23|
| Faster | 43803.26 | 40551.29 | 1.08 | | macOS Mojave 10.14.5 | X64 | Intel Core i7-5557U CPU 3.10GHz (Broadwell) | .NET Core 3.1.6 | 5.0.100-rc.1.20404.2 |
| Faster | 37258.98 | 31843.53 | 1.17 | | ubuntu 18.04 | X64 | Intel Core i7-7700 CPU 3.60GHz (Kaby Lake) | .NET Core 3.1.6 | 5.0.100-rc.1.20418.3 |

[danmosemsft]

@DrewScoggins I think your diff link above is correct, and matches the x axis on the graph -- it was 6pm 5/9 through midnight. But if I zoom on the graph and do the usual selection of points, it gives me a much wider range -- https://github.com/dotnet/runtime/compare/af1db3eccbc238745e1d163458c92c1bfa650fbd...e18250bd8f23f85f670599177118d6b957f9a3dd

Do you get the same result from the graph?

[DrewScoggins]

That's because the linked report was run against the installer repo, and since we don't take a lot of updates to the runtime in that repo there can often be big gaps in what runtime is being tested. Since this was such a big gap, I used this link, Array, to try and get a tighter bound for the test.

[danmosemsft]

Why is that graph tighter?

Also, it show May 9 08:26 3cd02dfcd1 through 14:41 6b5850fa7c which gives me 4 commits -- https://github.com/dotnet/runtime/compare/3cd02dfcd116d0cbb76525331bcaa908cd352884...6b5850fa7cf476b66be9d01a3ed05f4484b01d3a

your diff is e77572ffccc566186f47207f3c5475533c87538e...d2f7c8f52b7b21112a7765d311dc82a413e7116c which strraddles 10 commits.

Am I doing it wrong?

[DrewScoggins]

That graph is tighter because those runs are from the runtime repo and not the installer repo. So we run closer to every commit. The reason your bound is tighter is that you are better at clicking then I am ;)

[danmosemsft]

What is the difference bewteen runtime repo and installer repo runs? If we have the former why do we do the latter, and the results link above is to the latter?

Anyway it's a puzzle as nothing in any of these commit ranges looks suspicions. I also see the perf scenario did not change.

[danmosemsft]

Given it's 32 bit only, and all collections are affected, my suspicion is codegen. But there's almost no code in common between these scenarios!

From https://pvscmdupload.blob.core.windows.net/reports/08_20_2020/report_Daily_ca=x86_cb=master_co=Windows1018362_cr=dotnetcoresdk_cc=CompliationMode=tiered-RunKind=micro_Baseline_bb=release-3.1.1xx_2020-08-20.html it's affecting ContainsFalse<Int32> the same. It's also affecting ContainsTrue<string>.

Seems unlikely, but if we got our diff a bit wrong, this commit could be implicated?
https://github.com/dotnet/runtime/commit/57408d0d892544c52bddcde3dd8aa3190edf53a9

@CarolEidt can you imagine how this would affect this scenario?

[danmosemsft]

@DrewScoggins were there any other scenarios regressed in this range, other than ContainsTrue/ContainsFalse?

[DrewScoggins]

What is the difference bewteen runtime repo and installer repo runs? If we have the former why do we do the latter, and the results link above is to the latter?

On the performance team we have two goals that we try to meet. One, is that we understand the performance of the product in the way that our customers will use it, and the second is that we provide good data for developers to be able to fix regressions and understand improvements they make.

To meet this first goal we run against the installer repo. because this is what we ship to customers. We want to ensure that between what happened in the runtime repo and being ingested into the installer we didn't introduce some kind of regression, or that there is some interaction with other system components that caused this. But, because it can often be many commits between the runtime repo before changes get ingested into installer, we decided we needed finer-grained data. This is why we also do runs on the runtime repo, because they give us the data and tight regression bounds that make investigation simpler.

Hopefully, that explains why we run both. Now, as to why the above results link is for the installer repo, that is because at the time of the 3.1 release we only had runs on the installer repo. So, in order to make an apples to apples comparison we used the installer repo runs to generate these regressions. We can use, and have as seen in this issue, the runtime runs as a supplement to help with investigation. However, going forward I believe are plan will still be to use the installer repo for release signoff, as that gives us the highest fidelity to what we plan to ship to customers.

[danmosemsft]

@DrewScoggins thanks for the detailed explanation, that makes sense. Yes, the fine grained data is very important to us, so it makes sense to run against both.

[danmosemsft]

The only other change in taht range that could even vaguely have affected this is @jkotas 's https://github.com/dotnet/runtime/commit/6b5850fa7cf476b66be9d01a3ed05f4484b01d3a but I see nothing there.

Could you help me @DrewScoggins with my other question: were there any other scenarios regressed in this range, other than ContainsTrue/ContainsFalse?

[DrewScoggins]

You can find the report here, but a few caveats. Because this is just comparing two back-to-back builds we don't get to run many of the filters that reduce noise on the list of regressions. So that report will contain a decent amount of noise, but looking through I can see that many other tests are showing the same pattern as the ContainsTrue/ContainsFalse tests, and regressed over this bound.

[danmosemsft]

Yeesh.. yes, all regressing at the same point. Here's the worst ones:

System.Collections.ContainsFalse<Int32>.Span(Size: 512)
System.Memory.Span<Int32>.IndexOfValue(Size: 512)
System.Collections.ContainsFalse<Int32>.Array(Size: 512)
System.Memory.Span<Int32>.IndexOfAnyFourValues(Size: 512)
System.Collections.ContainsFalse<Int32>.ImmutableArray(Size: 512)
System.Collections.ContainsFalse<Int32>.List(Size: 512)
System.Collections.ContainsFalse<Int32>.ICollection(Size: 512)
System.Collections.ContainsTrue<Int32>.Span(Size: 512)
System.Collections.ContainsFalse<Int32>.Queue(Size: 512)
System.Collections.ContainsTrue<Int32>.List(Size: 512)
System.Collections.ContainsTrue<Int32>.ICollection(Size: 512)
System.Collections.ContainsTrue<Int32>.Queue(Size: 512)
System.Linq.Tests.Perf_Enumerable.Contains_ElementNotFound(input: ICollection)
System.Collections.ContainsTrue<Int32>.Array(Size: 512)
System.Collections.ContainsTrue<Int32>.ImmutableArray(Size: 512)
System.Memory.SequenceReader.TryReadTo
System.Globalization.Tests.StringSearch.IsSuffix_DifferentLastChar(Options: (en-US, OrdinalIgnoreCase, False))
System.Globalization.Tests.StringSearch.IsSuffix_SecondHalf(Options: (en-US, OrdinalIgnoreCase, False))
System.Globalization.Tests.StringSearch.IsPrefix_FirstHalf(Options: (en-US, OrdinalIgnoreCase, False))
System.Text.Json.Tests.Perf_Reader.ReadReturnBytes(IsDataCompact: True, TestCase: LotsOfStrings)
System.Text.Json.Tests.Perf_Reader.ReadMultiSpanSequenceEmptyLoop(IsDataCompact: True, TestCase: LotsOfStrings)
System.Text.Json.Tests.Perf_Reader.ReadSpanEmptyLoop(IsDataCompact: True, TestCase: HelloWorld)
bunch of other Perf_Reader

These are clearly step functions. Do we have issues open for them all? Eg., this one ?

[jkotas]

It was caused by my change. I will have a PR up shortly.

[danmosemsft]

I was looking all over that! What was it? I looked pretty carefully and didn't find it yet

[danmosemsft]

@DrewScoggins one thing worries me here - we had a bunch of scenarios do a clear step function regression of up to 250% in early May - why didn't we know about this until Aug 21st?

[danmosemsft]

aha https://github.com/dotnet/runtime/compare/3cd02dfcd116d0cbb76525331bcaa908cd352884...6b5850fa7cf476b66be9d01a3ed05f4484b01d3a#diff-bc54f7594b794b8bff2eedbf3347aaa6L367

[danmosemsft]

Never mind, subtraction has precedence over comparison operators, but it was clearer before with the parentheses.

[danmosemsft]

@DrewScoggins one thing worries me here - we had a bunch of scenarios do a clear step function regression of up to 250% in early May - why didn't we know about this until Aug 21st?

I would still like to understand this @DrewScoggins @adamsitnik .. not interested in blaming anyone 😁 just making sure we understand and can improve our processes if necessary. thoughts?

[adamsitnik]

we had a bunch of scenarios do a clear step function regression of up to 250% in early May - why didn't we know about this until Aug 21st?

The issue was reported by the bot in June: https://github.com/DrewScoggins/performance-2/issues/910#issuecomment-676413559

We meet once a week with Drew, Tanner, Andy an Kunal and go throught the list of all reported issues. We have most probably not discussed this particular one (human error).

I've confirmed it during my independent verificaiton: https://github.com/DrewScoggins/performance-2/issues/910#issuecomment-677854221 and @DrewScoggins moved it here.

So far this was the only issue like this, all other x86 and x64 issues were already reported (in general the initial results of my verification looks very promissing).

My plan is to send a report when I am done and also a PR to the bot repo that adds all the actual regressions as unit tests to ensure that we don't loose the precision over time. @danmosemsft does it sound good to you?

[danmosemsft]

Sounds good! Again, just interested in ways we can continue to help remove opportunities for error from our processes, as we go along. Thanks!