Regressions in System.Text.Tests.Perf_StringBuilder

[performanceautofiler]

Run Information

Architecture	arm64
OS	Windows 10.0.19041
Baseline	11bf8a782d27dd0f614dd0da03b27ab025933320
Compare	8471eecd98e5493e3fbc8bcc34662310ef8762eb
Diff	Diff

Regressions in System.Text.Tests.Perf_StringBuilder

Benchmark	Baseline	Test	Test/Base	Test Quality	Edge Detector	Baseline IR	Compare IR	IR Ratio	Baseline ETL	Compare ETL
Append_Span - Duration of single invocation	27.39 ns	43.81 ns	1.60	0.10	True

Test Report

Repro

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

Payloads

Baseline
Compare

Histogram

System.Text.Tests.Perf_StringBuilder.Append_Span

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 43.806113539524524 > 28.626101433626996.
IsChangePoint: Marked as a change because one of 1/28/2022 4:34:00 PM, 2/2/2022 11:04:24 PM falls between 1/25/2022 5:49:56 AM and 2/2/2022 11:04:24 PM.
IsRegressionStdDev: Marked as regression because -38.4072881703715 (T) = (0 -46.3456689212713) / Math.Sqrt((0.7290073887378425 / (26)) + (4.322788422199066 / (19))) is less than -2.016692199226234 = MathNet.Numerics.Distributions.StudentT.InvCDF(0, 1, (26) + (19) - 2, .025) and -0.7209753526364372 = (26.929885341049392 - 46.3456689212713) / 26.929885341049392 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 as regression because Edge Detector said so.

Docs

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

[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.

[EgorBo]

Most likely inliner + #64357

[EgorBo]

hmm or likely #64405 since it touched Append directly (we just didn't expect from it any regressions at all and blamed #64357 🙂)

[stephentoub]

hmm or likely #64405 since it touched Append directly

Certainly seems likely it was #64405... now I just need to figure out why :)

[ghost]

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

Issue Details

---

Run Information

Architecture	arm64
OS	Windows 10.0.19041
Baseline	11bf8a782d27dd0f614dd0da03b27ab025933320
Compare	8471eecd98e5493e3fbc8bcc34662310ef8762eb
Diff	Diff

Regressions in System.Text.Tests.Perf_StringBuilder

Benchmark	Baseline	Test	Test/Base	Test Quality	Edge Detector	Baseline IR	Compare IR	IR Ratio	Baseline ETL	Compare ETL
Append_Span - Duration of single invocation	27.39 ns	43.81 ns	1.60	0.10	True

Test Report

Repro

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

Payloads

Baseline
Compare

Histogram

System.Text.Tests.Perf_StringBuilder.Append_Span

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 43.806113539524524 > 28.626101433626996.
IsChangePoint: Marked as a change because one of 1/28/2022 4:34:00 PM, 2/2/2022 11:04:24 PM falls between 1/25/2022 5:49:56 AM and 2/2/2022 11:04:24 PM.
IsRegressionStdDev: Marked as regression because -38.4072881703715 (T) = (0 -46.3456689212713) / Math.Sqrt((0.7290073887378425 / (26)) + (4.322788422199066 / (19))) is less than -2.016692199226234 = MathNet.Numerics.Distributions.StudentT.InvCDF(0, 1, (26) + (19) - 2, .025) and -0.7209753526364372 = (26.929885341049392 - 46.3456689212713) / 26.929885341049392 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 as regression because Edge Detector said so.

Docs

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

Author:	performanceautofiler[bot]
Assignees:	EgorBo
Labels:	area-System.Runtime, untriaged, refs/heads/main, Regression, RunKind=micro, CoreClr, arm64, Windows 10.0.19041
Milestone:	-

[danmoseley]

Why doesn't the regression show on the graph here (?)

[EgorBo]

Why doesn't the regression show on the graph here (?)

@DrewScoggins promised to fix it 🙂

[stephentoub]

Turns out the perf test is buggy: it was trying to append 100 chars 16 times, but it was actually appending an empty span 16 times. Since appending an empty span is rare, my change included moving the 0-length check into the non-inlined helper; this regression comes then from making a non-inlined method call 16 more times than it was previously. This is not something that needs to be fixed.

[DrewScoggins]

Why doesn't the regression show on the graph here (?)

@DrewScoggins promised to fix it 🙂

The issue that caused this has been fixed, but it is not easy to go back and regenerate the image for the graph. So I am just going to leave it as is for now.