Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Regressions in System.Text.Json.Serialization.Tests.ColdStartSerialization<SimpleStructWithProperties> #71392

Closed
Tracked by #71123
performanceautofiler bot opened this issue Jun 28, 2022 · 9 comments
Closed
Tracked by #71123

Regressions in System.Text.Json.Serialization.Tests.ColdStartSerialization<SimpleStructWithProperties> #71392

performanceautofiler bot opened this issue Jun 28, 2022 · 9 comments
Assignees
@krwq
Labels
arch-x64 area-System.Text.Json runtime-coreclr specific to the CoreCLR runtime tenet-performance Performance related issue tenet-performance-benchmarks Issue from performance benchmark
Milestone
7.0.0

Comments

@performanceautofiler
Copy link

Run Information

Architecture x64
OS Windows 10.0.18362
Baseline d3f7e0145437ca3afe7d8a0bab38cc95040cfc28
Compare d17741d0c44b13cb4df864e0184cf1e499edcd57
Diff Diff

Regressions in System.Memory.Span<Int32>

Benchmark Baseline Test Test/Base Test Quality Edge Detector Baseline IR Compare IR IR Ratio Baseline ETL Compare ETL
IndexOfValue - Duration of single invocation 25.58 ns 28.36 ns 1.11 0.19 False

graph
Test Report

Repro

git clone https://github.com/dotnet/performance.git
py .\performance\scripts\benchmarks_ci.py -f net6.0 --filter 'System.Memory.Span&lt;Int32&gt;*'

Payloads

Baseline
Compare

Histogram

System.Memory.Span<Int32>.IndexOfValue(Size: 512)

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 28.357586329517822 > 27.01071444906912.
IsChangePoint: Marked as a change because one of 5/11/2022 9:09:01 PM, 5/23/2022 3:43:39 PM, 6/7/2022 9:37:06 AM, 6/22/2022 6:53:40 PM, 6/28/2022 4:38:49 AM falls between 6/19/2022 1:08:59 PM and 6/28/2022 4:38:49 AM.
IsRegressionStdDev: Marked as regression because -8.340375833370718 (T) = (0 -27.81521136381532) / Math.Sqrt((0.20749195724468672 / (39)) + (1.0174994203384329 / (22))) is less than -2.000995378087428 = MathNet.Numerics.Distributions.StudentT.InvCDF(0, 1, (39) + (22) - 2, .025) and -0.07306854638199406 = (25.92118784731724 - 27.81521136381532) / 25.92118784731724 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

### Run Information
Architecture x64
OS Windows 10.0.18362
Baseline d3f7e0145437ca3afe7d8a0bab38cc95040cfc28
Compare d17741d0c44b13cb4df864e0184cf1e499edcd57
Diff Diff

Regressions in System.Text.RegularExpressions.Tests.Perf_Regex_Industry_RustLang_Sherlock

Benchmark Baseline Test Test/Base Test Quality Edge Detector Baseline IR Compare IR IR Ratio Baseline ETL Compare ETL
Count - Duration of single invocation 146.77 μs 154.41 μs 1.05 0.01 False
Count - Duration of single invocation 121.60 μs 128.65 μs 1.06 0.01 False

graph
graph
Test Report

Repro

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

Payloads

Baseline
Compare

Histogram

System.Text.RegularExpressions.Tests.Perf_Regex_Industry_RustLang_Sherlock.Count(Pattern: "Sherlock|Holmes|Watson", Options: Compiled)

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 154.41371699669963 > 153.917664135514.
IsChangePoint: Marked as a change because one of 5/11/2022 9:09:01 PM, 5/20/2022 10:18:01 PM, 5/24/2022 7:55:26 PM, 6/22/2022 6:53:40 PM, 6/28/2022 4:38:49 AM falls between 6/19/2022 1:08:59 PM and 6/28/2022 4:38:49 AM.
IsRegressionStdDev: Marked as regression because -41.38176055194858 (T) = (0 -154744.75350745063) / Math.Sqrt((335214.6012950986 / (39)) + (614664.0370221194 / (18))) is less than -2.0040447832881556 = MathNet.Numerics.Distributions.StudentT.InvCDF(0, 1, (39) + (18) - 2, .025) and -0.05852307268354455 = (146189.30611984216 - 154744.75350745063) / 146189.30611984216 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.

```#### System.Text.RegularExpressions.Tests.Perf_Regex_Industry_RustLang_Sherlock.Count(Pattern: "(?i)Sherlock", Options: Compiled)

```log

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 128.6538695355191 > 127.36861077425374.
IsChangePoint: Marked as a change because one of 5/11/2022 9:09:01 PM, 5/20/2022 10:18:01 PM, 5/24/2022 7:55:26 PM, 6/22/2022 6:53:40 PM, 6/28/2022 4:38:49 AM falls between 6/19/2022 1:08:59 PM and 6/28/2022 4:38:49 AM.
IsRegressionStdDev: Marked as regression because -44.25999063994772 (T) = (0 -128410.12367141017) / Math.Sqrt((404381.85721397464 / (39)) + (319470.3509335992 / (18))) is less than -2.0040447832881556 = MathNet.Numerics.Distributions.StudentT.InvCDF(0, 1, (39) + (18) - 2, .025) and -0.06134123207895987 = (120988.53770137607 - 128410.12367141017) / 120988.53770137607 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

Run Information

Architecture x64
OS Windows 10.0.18362
Baseline d3f7e0145437ca3afe7d8a0bab38cc95040cfc28
Compare d17741d0c44b13cb4df864e0184cf1e499edcd57
Diff Diff

Regressions in System.Text.Json.Serialization.Tests.ColdStartSerialization<SimpleStructWithProperties>

Benchmark Baseline Test Test/Base Test Quality Edge Detector Baseline IR Compare IR IR Ratio Baseline ETL Compare ETL
NewCustomConverter - Duration of single invocation 23.18 μs 28.44 μs 1.23 0.06 False

graph
Test Report

Repro

git clone https://github.com/dotnet/performance.git
py .\performance\scripts\benchmarks_ci.py -f net6.0 --filter 'System.Text.Json.Serialization.Tests.ColdStartSerialization&lt;SimpleStructWithProperties&gt;*'

Payloads

Baseline
Compare

Histogram

System.Text.Json.Serialization.Tests.ColdStartSerialization<SimpleStructWithProperties>.NewCustomConverter

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 28.4422445750452 > 24.447789203980097.
IsChangePoint: Marked as a change because one of 5/9/2022 6:32:22 AM, 6/22/2022 6:53:40 PM, 6/28/2022 4:38:49 AM falls between 6/19/2022 1:08:59 PM and 6/28/2022 4:38:49 AM.
IsRegressionStdDev: Marked as regression because -33.26584895387854 (T) = (0 -29011.512395410962) / Math.Sqrt((287389.13213915617 / (39)) + (480583.35621665104 / (23))) is less than -2.0002978220134566 = MathNet.Numerics.Distributions.StudentT.InvCDF(0, 1, (39) + (23) - 2, .025) and -0.23880750049422977 = (23418.90276240388 - 29011.512395410962) / 23418.90276240388 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
@performanceautofiler performanceautofiler bot added CoreClr untriaged New issue has not been triaged by the area owner labels Jun 28, 2022
@dakersnar dakersnar removed the untriaged New issue has not been triaged by the area owner label Jun 28, 2022
@dakersnar
Copy link
Contributor

Only the last test is worth looking at, the rest are noise.

Could be related to #70435

@dakersnar dakersnar transferred this issue from dotnet/perf-autofiling-issues Jun 28, 2022
@ghost ghost added the untriaged New issue has not been triaged by the area owner label Jun 28, 2022
@dotnet-issue-labeler
Copy link

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.

@dakersnar dakersnar changed the title [Perf] Changes at 6/22/2022 10:05:16 PM Regressions in System.Text.Json.Serialization.Tests.ColdStartSerialization<SimpleStructWithProperties> Jun 28, 2022
@dakersnar dakersnar added tenet-performance Performance related issue tenet-performance-benchmarks Issue from performance benchmark labels Jun 28, 2022
@ghost
Copy link

ghost commented Jun 28, 2022

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

Issue Details

Run Information

Architecture x64
OS Windows 10.0.18362
Baseline d3f7e0145437ca3afe7d8a0bab38cc95040cfc28
Compare d17741d0c44b13cb4df864e0184cf1e499edcd57
Diff Diff

Regressions in System.Memory.Span<Int32>

Benchmark Baseline Test Test/Base Test Quality Edge Detector Baseline IR Compare IR IR Ratio Baseline ETL Compare ETL
IndexOfValue - Duration of single invocation 25.58 ns 28.36 ns 1.11 0.19 False

graph
Test Report

Repro

git clone https://github.com/dotnet/performance.git
py .\performance\scripts\benchmarks_ci.py -f net6.0 --filter 'System.Memory.Span&lt;Int32&gt;*'

Payloads

Baseline
Compare

Histogram

System.Memory.Span<Int32>.IndexOfValue(Size: 512)

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 28.357586329517822 > 27.01071444906912.
IsChangePoint: Marked as a change because one of 5/11/2022 9:09:01 PM, 5/23/2022 3:43:39 PM, 6/7/2022 9:37:06 AM, 6/22/2022 6:53:40 PM, 6/28/2022 4:38:49 AM falls between 6/19/2022 1:08:59 PM and 6/28/2022 4:38:49 AM.
IsRegressionStdDev: Marked as regression because -8.340375833370718 (T) = (0 -27.81521136381532) / Math.Sqrt((0.20749195724468672 / (39)) + (1.0174994203384329 / (22))) is less than -2.000995378087428 = MathNet.Numerics.Distributions.StudentT.InvCDF(0, 1, (39) + (22) - 2, .025) and -0.07306854638199406 = (25.92118784731724 - 27.81521136381532) / 25.92118784731724 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

### Run Information
Architecture x64
OS Windows 10.0.18362
Baseline d3f7e0145437ca3afe7d8a0bab38cc95040cfc28
Compare d17741d0c44b13cb4df864e0184cf1e499edcd57
Diff Diff

Regressions in System.Text.RegularExpressions.Tests.Perf_Regex_Industry_RustLang_Sherlock

Benchmark Baseline Test Test/Base Test Quality Edge Detector Baseline IR Compare IR IR Ratio Baseline ETL Compare ETL
Count - Duration of single invocation 146.77 μs 154.41 μs 1.05 0.01 False
Count - Duration of single invocation 121.60 μs 128.65 μs 1.06 0.01 False

graph
graph
Test Report

Repro

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

Payloads

Baseline
Compare

Histogram

System.Text.RegularExpressions.Tests.Perf_Regex_Industry_RustLang_Sherlock.Count(Pattern: "Sherlock|Holmes|Watson", Options: Compiled)

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 154.41371699669963 > 153.917664135514.
IsChangePoint: Marked as a change because one of 5/11/2022 9:09:01 PM, 5/20/2022 10:18:01 PM, 5/24/2022 7:55:26 PM, 6/22/2022 6:53:40 PM, 6/28/2022 4:38:49 AM falls between 6/19/2022 1:08:59 PM and 6/28/2022 4:38:49 AM.
IsRegressionStdDev: Marked as regression because -41.38176055194858 (T) = (0 -154744.75350745063) / Math.Sqrt((335214.6012950986 / (39)) + (614664.0370221194 / (18))) is less than -2.0040447832881556 = MathNet.Numerics.Distributions.StudentT.InvCDF(0, 1, (39) + (18) - 2, .025) and -0.05852307268354455 = (146189.30611984216 - 154744.75350745063) / 146189.30611984216 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.

```#### System.Text.RegularExpressions.Tests.Perf_Regex_Industry_RustLang_Sherlock.Count(Pattern: "(?i)Sherlock", Options: Compiled)

```log

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 128.6538695355191 > 127.36861077425374.
IsChangePoint: Marked as a change because one of 5/11/2022 9:09:01 PM, 5/20/2022 10:18:01 PM, 5/24/2022 7:55:26 PM, 6/22/2022 6:53:40 PM, 6/28/2022 4:38:49 AM falls between 6/19/2022 1:08:59 PM and 6/28/2022 4:38:49 AM.
IsRegressionStdDev: Marked as regression because -44.25999063994772 (T) = (0 -128410.12367141017) / Math.Sqrt((404381.85721397464 / (39)) + (319470.3509335992 / (18))) is less than -2.0040447832881556 = MathNet.Numerics.Distributions.StudentT.InvCDF(0, 1, (39) + (18) - 2, .025) and -0.06134123207895987 = (120988.53770137607 - 128410.12367141017) / 120988.53770137607 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

Run Information

Architecture x64
OS Windows 10.0.18362
Baseline d3f7e0145437ca3afe7d8a0bab38cc95040cfc28
Compare d17741d0c44b13cb4df864e0184cf1e499edcd57
Diff Diff

Regressions in System.Text.Json.Serialization.Tests.ColdStartSerialization<SimpleStructWithProperties>

Benchmark Baseline Test Test/Base Test Quality Edge Detector Baseline IR Compare IR IR Ratio Baseline ETL Compare ETL
NewCustomConverter - Duration of single invocation 23.18 μs 28.44 μs 1.23 0.06 False

graph
Test Report

Repro

git clone https://github.com/dotnet/performance.git
py .\performance\scripts\benchmarks_ci.py -f net6.0 --filter 'System.Text.Json.Serialization.Tests.ColdStartSerialization&lt;SimpleStructWithProperties&gt;*'

Payloads

Baseline
Compare

Histogram

System.Text.Json.Serialization.Tests.ColdStartSerialization<SimpleStructWithProperties>.NewCustomConverter

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 28.4422445750452 > 24.447789203980097.
IsChangePoint: Marked as a change because one of 5/9/2022 6:32:22 AM, 6/22/2022 6:53:40 PM, 6/28/2022 4:38:49 AM falls between 6/19/2022 1:08:59 PM and 6/28/2022 4:38:49 AM.
IsRegressionStdDev: Marked as regression because -33.26584895387854 (T) = (0 -29011.512395410962) / Math.Sqrt((287389.13213915617 / (39)) + (480583.35621665104 / (23))) is less than -2.0002978220134566 = MathNet.Numerics.Distributions.StudentT.InvCDF(0, 1, (39) + (23) - 2, .025) and -0.23880750049422977 = (23418.90276240388 - 29011.512395410962) / 23418.90276240388 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: dakersnar
Labels:

area-System.Text.Json, tenet-performance, tenet-performance-benchmarks, untriaged, refs/heads/main, RunKind=micro, Windows 10.0.18362, Regression, CoreClr, x64
Milestone: -

@eiriktsarpalis
Copy link
Member

It very clearly correlates with #70435

image

@krwq could you take a look?

@krwq krwq mentioned this issue Jun 29, 2022
Closed
16 tasks
@krwq
Copy link
Member

krwq commented Jun 29, 2022

I suspect this is related to double lookup in the JsonTypeInfo cache which we can't easily fix without making braking change (which we should eventually do). I've added this issue to our backlog #71123 but for now I prefer to prioritize other issues than this since we're talking about 5 microseconds regression in the app startup here.

@eiriktsarpalis
Copy link
Member

I would recommend profiling the benchmark, so that at least we have concrete evidence as to what contributes to the regression.

Instructions can be found here: https://github.com/dotnet/performance/blob/ef3edbc52d92c6b30ba1c316082f46865e5ff1d6/docs/benchmarking-workflow-dotnet-runtime.md#profiling

@eiriktsarpalis eiriktsarpalis added this to the 7.0.0 milestone Jun 29, 2022
@eiriktsarpalis eiriktsarpalis removed the untriaged New issue has not been triaged by the area owner label Jun 29, 2022
@eiriktsarpalis eiriktsarpalis assigned krwq and unassigned dakersnar Jun 29, 2022
@krwq krwq mentioned this issue Jul 5, 2022
Closed
@dakersnar
Copy link
Contributor

Same regression on Arm64: dotnet/perf-autofiling-issues#6465

@krwq krwq removed their assignment Jul 11, 2022
@eiriktsarpalis eiriktsarpalis mentioned this issue Jul 11, 2022
Closed
13 tasks
@dakersnar dakersnar mentioned this issue Jul 21, 2022
Closed
@dakersnar
Copy link
Contributor

Same regression for x86 dotnet/perf-autofiling-issues#6389

@eiriktsarpalis eiriktsarpalis mentioned this issue Aug 5, 2022
Closed
@eiriktsarpalis
Copy link
Member

Closing in favor of #73388.

@ghost ghost locked as resolved and limited conversation to collaborators Sep 4, 2022
@jeffhandley jeffhandley added runtime-coreclr specific to the CoreCLR runtime arch-x64 and removed CoreClr labels Dec 28, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees

@krwq krwq

Labels
arch-x64 area-System.Text.Json runtime-coreclr specific to the CoreCLR runtime tenet-performance Performance related issue tenet-performance-benchmarks Issue from performance benchmark
Projects
None yet
Milestone
7.0.0
Development

No branches or pull requests
5 participants
@krwq @jeffhandley @eiriktsarpalis @danmoseley @dakersnar