Regressions from "make SIP not on by default"

[performanceautofiler]

Run Information

Architecture	arm64
OS	ubuntu 20.04
Baseline	7f317997e9d0baeb21ce7a1889d3330a13ffd0a1
Compare	6274ea7365b7124d4451aab3e73712763e71183b
Diff	Diff

Regressions in System.IO.Tests.StreamReaderReadToEndTests

Benchmark	Baseline	Test	Test/Base	Test Quality	Edge Detector	Baseline IR	Compare IR	IR Ratio	Baseline ETL	Compare ETL
ReadToEndAsync - Duration of single invocation	67.94 ms	75.94 ms	1.12	0.08	False

Test Report

Repro

git clone https://github.com/dotnet/performance.git
py .\performance\scripts\benchmarks_ci.py -f net6.0 --filter 'System.IO.Tests.StreamReaderReadToEndTests*'

Payloads

Baseline
Compare

Histogram

System.IO.Tests.StreamReaderReadToEndTests.ReadToEndAsync(LineLengthRange: [ 0, 1024])

Description of detection logic

IsRegressionChecked: Marked as regression because the three check build points were 0.05 greater than the baseline.
IsImprovementBase: Marked as not an improvement because the compare was not 5% less than the baseline, or the value was too small.
IsRegressionBase: Marked as regression because the compare was 5% greater than the baseline, and the value was not too small.
IsRegressionChecked: Marked as regression because the three check build points were 0.05 greater than the baseline.
IsRegressionWindowed: Marked as regression because 75.93536301666667 > 70.84351980125.
IsChangePoint: Marked as a change because one of 6/22/2022 5:33:38 PM, 8/6/2022 1:07:13 AM, 8/11/2022 10:02:44 AM falls between 8/2/2022 9:32:02 PM and 8/11/2022 10:02:44 AM.
IsRegressionStdDev: Marked as regression because -24.83915370249787 (T) = (0 -76684335.4223952) / Math.Sqrt((1825236129188.6467 / (23)) + (2631504391413.2695 / (27))) is less than -2.010634757623041 = MathNet.Numerics.Distributions.StudentT.InvCDF(0, 1, (23) + (27) - 2, .025) and -0.15768388595046612 = (66239442.695046976 - 76684335.4223952) / 66239442.695046976 is less than -0.05.
IsImprovementBase: Marked as not an improvement because the compare was not 5% less than the baseline, or the value was too small.
IsChangeEdgeDetector: Marked not as a regression because Edge Detector said so.

Docs

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

[kunalspathak]

#73434

[dotnet-issue-labeler]

I couldn't figure out the best area label to add to this issue. If you have write-permissions please help me learn by adding exactly one area label.

[kunalspathak]

@Maoni0

[ghost]

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

Issue Details

---

Run Information

Architecture	arm64
OS	ubuntu 20.04
Baseline	7f317997e9d0baeb21ce7a1889d3330a13ffd0a1
Compare	6274ea7365b7124d4451aab3e73712763e71183b
Diff	Diff

Regressions in System.IO.Tests.StreamReaderReadToEndTests

Benchmark	Baseline	Test	Test/Base	Test Quality	Edge Detector	Baseline IR	Compare IR	IR Ratio	Baseline ETL	Compare ETL
ReadToEndAsync - Duration of single invocation	67.94 ms	75.94 ms	1.12	0.08	False

Test Report

Repro

git clone https://github.com/dotnet/performance.git
py .\performance\scripts\benchmarks_ci.py -f net6.0 --filter 'System.IO.Tests.StreamReaderReadToEndTests*'

Payloads

Baseline
Compare

Histogram

System.IO.Tests.StreamReaderReadToEndTests.ReadToEndAsync(LineLengthRange: [ 0, 1024])

Description of detection logic

IsRegressionChecked: Marked as regression because the three check build points were 0.05 greater than the baseline.
IsImprovementBase: Marked as not an improvement because the compare was not 5% less than the baseline, or the value was too small.
IsRegressionBase: Marked as regression because the compare was 5% greater than the baseline, and the value was not too small.
IsRegressionChecked: Marked as regression because the three check build points were 0.05 greater than the baseline.
IsRegressionWindowed: Marked as regression because 75.93536301666667 > 70.84351980125.
IsChangePoint: Marked as a change because one of 6/22/2022 5:33:38 PM, 8/6/2022 1:07:13 AM, 8/11/2022 10:02:44 AM falls between 8/2/2022 9:32:02 PM and 8/11/2022 10:02:44 AM.
IsRegressionStdDev: Marked as regression because -24.83915370249787 (T) = (0 -76684335.4223952) / Math.Sqrt((1825236129188.6467 / (23)) + (2631504391413.2695 / (27))) is less than -2.010634757623041 = MathNet.Numerics.Distributions.StudentT.InvCDF(0, 1, (23) + (27) - 2, .025) and -0.15768388595046612 = (66239442.695046976 - 76684335.4223952) / 66239442.695046976 is less than -0.05.
IsImprovementBase: Marked as not an improvement because the compare was not 5% less than the baseline, or the value was too small.
IsChangeEdgeDetector: Marked not as a regression because Edge Detector said so.

Docs

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

Author:	performanceautofiler[bot]
Assignees:	-
Labels:	os-linux, tenet-performance, tenet-performance-benchmarks, area-GC-coreclr, arm64
Milestone:	-

[mangod9]

from the chart this appears to be bimodel behavior from the test? Would be surprised in disabling SIP has caused this regression?

[kunalspathak]

We see the improvements from #71029 and the spike comes from one of 638a4c1...667c170 so definitely it is sensitive to GC.

[mangod9]

Hmm interesting. Ok we can look if reverting the SIP change makes things better.

[Maoni0]

you don't need to revert the change, you can set the GCEnableSpecialRegions env var to turn it on as I mentioned in the PR -

set COMPlus_GCEnableSpecialRegions=1

[mrsharm]

I was able to repro this issue locally and proved that after we set COMPLUS_GCEnableSpecialRegions=1, the regression dissapears:

Without COMPlus_GCEnableSpecialRegions=1:

Method	LineLengthRange	Mean	Error	StdDev	Median	Min	Max	Gen 0	Gen 1	Gen 2	Allocated
ReadToEndAsync	[ 0, 0]	75.48 ms	3.021 ms	3.358 ms	75.21 ms	66.71 ms	82.37 ms	11750.0000	11500.0000	2250.0000	192.46 MB
ReadToEndAsync	[ 0, 1024]	80.63 ms	6.050 ms	6.967 ms	80.92 ms	65.84 ms	95.74 ms	11750.0000	11500.0000	2250.0000	192.46 MB
ReadToEndAsync	[ 1, 1]	76.86 ms	4.302 ms	4.954 ms	76.77 ms	67.28 ms	85.89 ms	11750.0000	11500.0000	2250.0000	192.45 MB
ReadToEndAsync	[ 1, 8]	80.90 ms	5.925 ms	6.586 ms	80.13 ms	65.31 ms	96.45 ms	11750.0000	11500.0000	2250.0000	192.46 MB
ReadToEndAsync	[ 9, 32]	80.02 ms	4.404 ms	5.071 ms	78.75 ms	71.35 ms	89.76 ms	11750.0000	11500.0000	2250.0000	192.45 MB
ReadToEndAsync	[ 33, 128]	80.75 ms	5.678 ms	6.538 ms	80.18 ms	69.92 ms	95.18 ms	11750.0000	11500.0000	2250.0000	192.46 MB
ReadToEndAsync	[ 129, 1024]	78.22 ms	4.076 ms	4.694 ms	78.02 ms	71.16 ms	87.93 ms	11750.0000	11500.0000	2250.0000	192.46 MB
ReadToEndAsync	[1025, 2048]	79.14 ms	3.996 ms	4.442 ms	78.13 ms	71.42 ms	87.40 ms	11750.0000	11500.0000	2250.0000	192.46 MB

With COMPlus_GCEnableSpecialRegions=1:

Method	LineLengthRange	Mean	Error	StdDev	Median	Min	Max	Gen 0	Gen 1	Gen 2	Allocated
ReadToEndAsync	[ 0, 0]	67.57 ms	3.646 ms	4.199 ms	66.26 ms	60.61 ms	75.92 ms	11500.0000	11250.0000	2000.0000	192.45 MB
ReadToEndAsync	[ 0, 1024]	69.11 ms	4.242 ms	4.885 ms	67.26 ms	61.92 ms	80.70 ms	11500.0000	11250.0000	2000.0000	192.46 MB
ReadToEndAsync	[ 1, 1]	65.02 ms	4.357 ms	4.842 ms	62.98 ms	58.59 ms	74.84 ms	11500.0000	11250.0000	2000.0000	192.45 MB
ReadToEndAsync	[ 1, 8]	67.07 ms	2.870 ms	3.306 ms	66.56 ms	60.95 ms	73.38 ms	11500.0000	11250.0000	2000.0000	192.46 MB
ReadToEndAsync	[ 9, 32]	65.12 ms	2.226 ms	2.186 ms	66.39 ms	61.19 ms	67.05 ms	11500.0000	11250.0000	2000.0000	192.46 MB
ReadToEndAsync	[ 33, 128]	65.82 ms	3.204 ms	3.428 ms	66.40 ms	60.80 ms	73.95 ms	11500.0000	11250.0000	2000.0000	192.46 MB
ReadToEndAsync	[ 129, 1024]	64.79 ms	2.608 ms	2.791 ms	65.71 ms	61.11 ms	71.32 ms	11500.0000	11250.0000	2000.0000	192.45 MB
ReadToEndAsync	[1025, 2048]	67.52 ms	3.188 ms	3.672 ms	66.55 ms	61.56 ms	74.67 ms	11500.0000	11250.0000	2000.0000	192.46 MB

@kunalspathak: Should we close this issue as this issue is by design?

[Maoni0]

so when regions was enabled did we see the same degree of improvement with these tests? if so it would be fine to close.

[mrsharm]

Yes, comparing net6.0 (w/o regions enabled by default) and the results above, I observe a definite improvement:

Method	LineLengthRange	Mean	Error	StdDev	Median	Min	Max	Gen 0	Gen 1	Gen 2	Allocated
ReadToEndAsync	[ 0, 0]	71.74 ms	4.641 ms	5.345 ms	71.55 ms	64.63 ms	82.03 ms	10500.0000	5750.0000	1750.0000	192.45 MB
ReadToEndAsync	[ 0, 1024]	72.18 ms	3.466 ms	3.853 ms	72.76 ms	64.72 ms	79.73 ms	10500.0000	5750.0000	1750.0000	192.45 MB
ReadToEndAsync	[ 1, 1]	72.81 ms	4.448 ms	5.123 ms	72.95 ms	65.06 ms	83.10 ms	10500.0000	5750.0000	1750.0000	192.45 MB
ReadToEndAsync	[ 1, 8]	72.76 ms	5.199 ms	5.987 ms	72.60 ms	63.89 ms	83.93 ms	10500.0000	5750.0000	1750.0000	192.45 MB
ReadToEndAsync	[ 9, 32]	72.28 ms	4.439 ms	5.113 ms	72.61 ms	64.83 ms	81.65 ms	10500.0000	5750.0000	1750.0000	192.45 MB
ReadToEndAsync	[ 33, 128]	72.80 ms	3.808 ms	4.385 ms	72.28 ms	65.41 ms	82.49 ms	10500.0000	5750.0000	1750.0000	192.45 MB
ReadToEndAsync	[ 129, 1024]	70.84 ms	2.889 ms	3.211 ms	72.08 ms	64.56 ms	75.34 ms	10500.0000	5750.0000	1750.0000	192.45 MB
ReadToEndAsync	[1025, 2048]	72.26 ms	4.173 ms	4.806 ms	72.45 ms	64.21 ms	80.71 ms	10500.0000	5750.0000	1750.0000	192.45 MB

Repro: py .\scripts\benchmarks_ci.py -f net6.0 --filter 'System.IO.Tests.StreamReaderReadToEndTests.ReadToEndAsync'

Closing this issue.