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.Net.Security.Tests.SslStreamTests #68408

Closed
performanceautofiler bot opened this issue Mar 31, 2022 · 13 comments
Closed

Regressions in System.Net.Security.Tests.SslStreamTests #68408

performanceautofiler bot opened this issue Mar 31, 2022 · 13 comments
Assignees
@rzikm
Labels
arch-x64 area-System.Net.Security PGO runtime-coreclr specific to the CoreCLR runtime
Milestone
7.0.0

Comments

@performanceautofiler
Copy link

Run Information

Architecture x64
OS alpine 3.12
Baseline b4e258a377ccfd8fe636f51b50e8f9204d292d8f
Compare 0e35b8d33851efde52e4e7aaadac239f3c2e97d5
Diff Diff

Regressions in System.Net.Security.Tests.SslStreamTests

Benchmark Baseline Test Test/Base Test Quality Edge Detector Baseline IR Compare IR IR Ratio Baseline ETL Compare ETL
HandshakeECDSA256CertAsync - Duration of single invocation 2.14 ms 2.75 ms 1.28 0.01 True
HandshakeRSA2048CertAsync - Duration of single invocation 2.42 ms 2.96 ms 1.23 0.00 True

graph
graph
Test Report

Repro

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

Payloads

Baseline
Compare

Histogram

System.Net.Security.Tests.SslStreamTests.HandshakeECDSA256CertAsync(protocol: Tls13)

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 2.7451470734265735 > 2.2503181640281595.
IsChangePoint: Marked as a change because one of 3/24/2022 7:54:35 AM, 3/31/2022 1:45:25 PM falls between 3/22/2022 11:55:12 PM and 3/31/2022 1:45:25 PM.
IsRegressionStdDev: Marked as regression because -57.985291775661906 (T) = (0 -2737000.43546216) / Math.Sqrt((1622080925.6075373 / (22)) + (1036970535.6862763 / (31))) is less than -2.007583770314729 = MathNet.Numerics.Distributions.StudentT.InvCDF(0, 1, (22) + (31) - 2, .025) and -0.2809551936244573 = (2136687.0981004643 - 2737000.43546216) / 2136687.0981004643 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.

```#### System.Net.Security.Tests.SslStreamTests.HandshakeRSA2048CertAsync(protocol: Tls13)

```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 2.9622326522435896 > 2.558988685171287.
IsChangePoint: Marked as a change because one of 3/24/2022 7:54:35 AM, 3/31/2022 1:45:25 PM falls between 3/22/2022 11:55:12 PM and 3/31/2022 1:45:25 PM.
IsRegressionStdDev: Marked as regression because -65.73768931290239 (T) = (0 -2961577.750771263) / Math.Sqrt((424628717.59201896 / (22)) + (1391852437.844686 / (31))) is less than -2.007583770314729 = MathNet.Numerics.Distributions.StudentT.InvCDF(0, 1, (22) + (31) - 2, .025) and -0.21632557941456396 = (2434856.095188523 - 2961577.750771263) / 2434856.095188523 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
@performanceautofiler performanceautofiler bot added alpine 3.12 PGO untriaged New issue has not been triaged by the area owner labels Mar 31, 2022
@kunalspathak
Copy link
Member

Regression introduced in #66334

@kunalspathak kunalspathak changed the title [Perf] Changes at 3/24/2022 12:14:34 PM Regressions in System.Net.Security.Tests.SslStreamTests Apr 22, 2022
@kunalspathak kunalspathak transferred this issue from dotnet/perf-autofiling-issues Apr 22, 2022
@ghost
Copy link

ghost commented Apr 22, 2022

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

Issue Details

Run Information

Architecture x64
OS alpine 3.12
Baseline b4e258a377ccfd8fe636f51b50e8f9204d292d8f
Compare 0e35b8d33851efde52e4e7aaadac239f3c2e97d5
Diff Diff

Regressions in System.Net.Security.Tests.SslStreamTests

Benchmark Baseline Test Test/Base Test Quality Edge Detector Baseline IR Compare IR IR Ratio Baseline ETL Compare ETL
HandshakeECDSA256CertAsync - Duration of single invocation 2.14 ms 2.75 ms 1.28 0.01 True
HandshakeRSA2048CertAsync - Duration of single invocation 2.42 ms 2.96 ms 1.23 0.00 True

graph
graph
Test Report

Repro

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

Payloads

Baseline
Compare

Histogram

System.Net.Security.Tests.SslStreamTests.HandshakeECDSA256CertAsync(protocol: Tls13)

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 2.7451470734265735 > 2.2503181640281595.
IsChangePoint: Marked as a change because one of 3/24/2022 7:54:35 AM, 3/31/2022 1:45:25 PM falls between 3/22/2022 11:55:12 PM and 3/31/2022 1:45:25 PM.
IsRegressionStdDev: Marked as regression because -57.985291775661906 (T) = (0 -2737000.43546216) / Math.Sqrt((1622080925.6075373 / (22)) + (1036970535.6862763 / (31))) is less than -2.007583770314729 = MathNet.Numerics.Distributions.StudentT.InvCDF(0, 1, (22) + (31) - 2, .025) and -0.2809551936244573 = (2136687.0981004643 - 2737000.43546216) / 2136687.0981004643 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.

```#### System.Net.Security.Tests.SslStreamTests.HandshakeRSA2048CertAsync(protocol: Tls13)

```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 2.9622326522435896 > 2.558988685171287.
IsChangePoint: Marked as a change because one of 3/24/2022 7:54:35 AM, 3/31/2022 1:45:25 PM falls between 3/22/2022 11:55:12 PM and 3/31/2022 1:45:25 PM.
IsRegressionStdDev: Marked as regression because -65.73768931290239 (T) = (0 -2961577.750771263) / Math.Sqrt((424628717.59201896 / (22)) + (1391852437.844686 / (31))) is less than -2.007583770314729 = MathNet.Numerics.Distributions.StudentT.InvCDF(0, 1, (22) + (31) - 2, .025) and -0.21632557941456396 = (2434856.095188523 - 2961577.750771263) / 2434856.095188523 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: -
Labels:

area-System.Net.Security, untriaged, refs/heads/main, RunKind=micro, PGO, Regression, CoreClr, x64, alpine 3.12
Milestone: -

@kunalspathak
Copy link
Member

@rzikm, @wfurt

@wfurt
Copy link
Member

wfurt commented Apr 22, 2022

I actually experienced something similar when looking at memory allocations. #66334 made processing of expired certificates way more expensive as on each round they would be considered expired and we would rebuild the chain over and over.

This is the RS2048 certificate from test.

Certificate:
    Data:
        Version: 3 (0x2)
        Serial Number:
            9b:91:c6:45:a4:ba:77:e6
        Signature Algorithm: sha256WithRSAEncryption
        Issuer: CN = localhost
        Validity
            Not Before: Feb  1 00:23:54 2020 GMT
            Not After : Jan 31 00:23:54 2021 GMT
        Subject: CN = localhost
        Subject Public Key Info:
            Public Key Algorithm: rsaEncryption
                RSA Public-Key: (2048 bit)

I'm not sure how much we care about that, but something to consider. The expiration did not matter before is it is form of regression. I think we can get perf back by re-generating the certificates with updated time.

@rzikm
Copy link
Member

rzikm commented Apr 25, 2022 •
edited
Loading

I think we can get perf back by re-generating the certificates with updated time.

I agree the perf hit should occur only on an expired cert chain. And if there is still a hit with unexpired certs, we can improve it slightly by moving the calculation of the expiration timestamp to SslStreamCertificateContext so that it is calculated only once per instance.

@wfurt wfurt mentioned this issue Apr 27, 2022
Merged
@rzikm rzikm self-assigned this Apr 28, 2022
@rzikm
Copy link
Member

rzikm commented Apr 29, 2022

@wfurt how did you generate those certs? The ec256.pfx contains a key with ECDH_P256 listed as "Private key parameters", but I was unable to replicate that, all my attempts had ECDSA_P256. I assume that makes a difference.

@wfurt
Copy link
Member

wfurt commented Apr 29, 2022

I don't remember the exact details but I did not do anything's special besides setting key size (as far as I remember)
It may be also OpenSSL difference. If you want to be exact, you can perhaps extract existing keys and simple resign with updated expiration.

@rzikm
Copy link
Member

rzikm commented May 2, 2022

I tried that before, but I did not copy extensions from the original cert, which apparently affects the key params... anyway, it works now, I put up dotnet/performance#2405

@antonfirsov antonfirsov added this to the 7.0.0 milestone May 12, 2022
@ghost ghost removed the untriaged New issue has not been triaged by the area owner label May 12, 2022
@antonfirsov
Copy link
Member

Triage: this is expected because of new functionality, but we should take a look.

@dakersnar
Copy link
Contributor

This regression appears on a variety of configs, here is some more data to help this effort:

System.Net.Security.Tests.SslStreamTests.HandshakeRSA2048CertAsync(protocol: Tls12)

Result Ratio Alloc Delta Operating System Bit Processor Name
Same 0.92 +2590 ubuntu 20.04 Arm64 Unknown processor
Slower 0.62 +392 Windows 10 Arm64 Microsoft SQ1 3.0 GHz
Slower 0.64 +701 Windows 11 Arm64 Microsoft SQ1 3.0 GHz
Slower 0.63 +658 Windows 11 Arm64 Unknown processor
Same 0.99 +10650 macOS Monterey 12.3 Arm64 Apple M1 Max
Slower 0.40 +736 Windows 10 X64 Intel Xeon Platinum 8272CL CPU 2.60GHz
Slower 0.49 +672 Windows 10 X64 Intel Xeon CPU E5-1650 v4 3.60GHz
Slower 0.50 +693 Windows 10 X64 Intel Core i7-6700 CPU 3.40GHz (Skylake)
Slower 0.50 +680 Windows 11 X64 AMD Ryzen Threadripper PRO 3945WX 12-Cores
Slower 0.50 +682 Windows 11 X64 AMD Ryzen 9 5950X
Slower 0.50 +672 Windows 11 X64 Intel Core i7-8700 CPU 3.20GHz (Coffee Lake)
Slower 0.52 +686 Windows 11 X64 Intel Core i9-9900T CPU 2.10GHz
Slower 0.83 +3277 alpine 3.13 X64 Intel Core i7-7700 CPU 3.60GHz (Kaby Lake)
Faster 1.48 +2257 pop 22.04 X64 Intel Core i7-6600U CPU 2.60GHz (Skylake)
Same 0.90 +3019 ubuntu 18.04 X64 Intel Xeon CPU E5-1650 v4 3.60GHz
Slower 0.79 +2853 ubuntu 18.04 X64 Intel Core i7-2720QM CPU 2.20GHz (Sandy Bridge)
Slower 0.88 +3468 ubuntu 20.04 X64 AMD Ryzen 9 5900X
Same 0.92 +2747 ubuntu 20.04 X64 Intel Core i7-8700 CPU 3.20GHz (Coffee Lake)
Slower 0.51 +384 Windows 10 X86 Intel Xeon CPU E5-1650 v4 3.60GHz
Slower 0.51 +389 Windows 10 X86 Intel Core i7-6700 CPU 3.40GHz (Skylake)
Slower 0.54 +373 Windows 11 X86 AMD Ryzen Threadripper PRO 3945WX 12-Cores
Same 0.94 +10531 macOS Monterey 12.2.1 X64 Intel Core i7-5557U CPU 3.10GHz (Broadwell)
Same 0.95 +11940 macOS Monterey 12.3.1 X64 Intel Core i7-4870HQ CPU 2.50GHz (Haswell)

System.Net.Security.Tests.SslStreamTests.HandshakeECDSA256CertAsync(protocol: Tls12)

Result Ratio Alloc Delta Operating System Bit Processor Name
Slower 0.82 +2945 ubuntu 20.04 Arm64 Unknown processor
Slower 0.65 +644 Windows 10 Arm64 Microsoft SQ1 3.0 GHz
Slower 0.64 +700 Windows 11 Arm64 Microsoft SQ1 3.0 GHz
Slower 0.64 +699 Windows 11 Arm64 Unknown processor
Same 0.98 +10072 macOS Monterey 12.3 Arm64 Apple M1 Max
Slower 0.35 +738 Windows 10 X64 Intel Xeon Platinum 8272CL CPU 2.60GHz
Slower 0.60 +666 Windows 10 X64 Intel Xeon CPU E5-1650 v4 3.60GHz
Slower 0.61 +687 Windows 10 X64 Intel Core i7-6700 CPU 3.40GHz (Skylake)
Slower 0.58 +679 Windows 11 X64 AMD Ryzen Threadripper PRO 3945WX 12-Cores
Slower 0.57 +683 Windows 11 X64 AMD Ryzen 9 5950X
Slower 0.59 +687 Windows 11 X64 Intel Core i7-8700 CPU 3.20GHz (Coffee Lake)
Slower 0.62 +682 Windows 11 X64 Intel Core i9-9900T CPU 2.10GHz
Slower 0.77 +3324 alpine 3.13 X64 Intel Core i7-7700 CPU 3.60GHz (Kaby Lake)
Faster 1.55 +3273 pop 22.04 X64 Intel Core i7-6600U CPU 2.60GHz (Skylake)
Slower 0.84 +3638 ubuntu 18.04 X64 Intel Xeon CPU E5-1650 v4 3.60GHz
Slower 0.82 +2946 ubuntu 18.04 X64 Intel Core i7-2720QM CPU 2.20GHz (Sandy Bridge)
Slower 0.78 +5427 ubuntu 20.04 X64 AMD Ryzen 9 5900X
Slower 0.86 +2243 ubuntu 20.04 X64 Intel Core i7-8700 CPU 3.20GHz (Coffee Lake)
Slower 0.62 +369 Windows 10 X86 Intel Xeon CPU E5-1650 v4 3.60GHz
Slower 0.61 +385 Windows 10 X86 Intel Core i7-6700 CPU 3.40GHz (Skylake)
Slower 0.62 +387 Windows 11 X86 AMD Ryzen Threadripper PRO 3945WX 12-Cores
Same 0.97 +10179 macOS Monterey 12.2.1 X64 Intel Core i7-5557U CPU 3.10GHz (Broadwell)
Same 0.93 +10054 macOS Monterey 12.3.1 X64 Intel Core i7-4870HQ CPU 2.50GHz (Haswell)

System.Net.Security.Tests.SslStreamTests.HandshakeRSA4096CertAsync(protocol: Tls12)

Result Ratio Alloc Delta Operating System Bit Processor Name
Same 1.00 +2600 ubuntu 20.04 Arm64 Unknown processor
Slower 0.70 +733 Windows 10 Arm64 Microsoft SQ1 3.0 GHz
Slower 0.71 +556 Windows 11 Arm64 Microsoft SQ1 3.0 GHz
Slower 0.71 +733 Windows 11 Arm64 Unknown processor
Same 1.01 +6628 macOS Monterey 12.3 Arm64 Apple M1 Max
Slower 0.84 +700 Windows 10 X64 Intel Xeon Platinum 8272CL CPU 2.60GHz
Slower 0.47 +711 Windows 10 X64 Intel Xeon CPU E5-1650 v4 3.60GHz
Slower 0.50 +707 Windows 10 X64 Intel Core i7-6700 CPU 3.40GHz (Skylake)
Slower 0.48 +703 Windows 11 X64 AMD Ryzen Threadripper PRO 3945WX 12-Cores
Slower 0.51 +668 Windows 11 X64 AMD Ryzen 9 5950X
Slower 0.46 +678 Windows 11 X64 Intel Core i7-8700 CPU 3.20GHz (Coffee Lake)
Slower 0.46 +916 Windows 11 X64 Intel Core i9-9900T CPU 2.10GHz
Same 0.90 +1583 alpine 3.13 X64 Intel Core i7-7700 CPU 3.60GHz (Kaby Lake)
Faster 1.30 +4728 pop 22.04 X64 Intel Core i7-6600U CPU 2.60GHz (Skylake)
Same 0.94 +3591 ubuntu 18.04 X64 Intel Xeon CPU E5-1650 v4 3.60GHz
Same 1.00 +2903 ubuntu 18.04 X64 Intel Core i7-2720QM CPU 2.20GHz (Sandy Bridge)
Same 0.92 +4016 ubuntu 20.04 X64 AMD Ryzen 9 5900X
Same 0.93 +2749 ubuntu 20.04 X64 Intel Core i7-8700 CPU 3.20GHz (Coffee Lake)
Slower 0.50 +406 Windows 10 X86 Intel Xeon CPU E5-1650 v4 3.60GHz
Slower 0.50 +400 Windows 10 X86 Intel Core i7-6700 CPU 3.40GHz (Skylake)
Slower 0.52 +380 Windows 11 X86 AMD Ryzen Threadripper PRO 3945WX 12-Cores
Same 0.98 +11512 macOS Monterey 12.2.1 X64 Intel Core i7-5557U CPU 3.10GHz (Broadwell)
Same 0.99 +11512 macOS Monterey 12.3.1 X64 Intel Core i7-4870HQ CPU 2.50GHz (Haswell)

@rzikm
Copy link
Member

rzikm commented May 13, 2022

@dakersnar were these measurements taken before or after merging dotnet/performance#2405?

Preferably, we should compare the old results with the ones after the mentioned PR was merged.

@dakersnar
Copy link
Contributor

dakersnar commented May 13, 2022 •
edited
Loading

@rzikm these results are comparing preview3 and preview4, which is before that change was merged. However, looking at the perf lab data (which runs continuously), it's looking like the regression has not been solved yet, at least on the config I checked (windows 10 x64).

EDIT: actually I just noticed that your commit was merged yesterday, so it's very likely the perf lab has just not run those changes yet. I'll check in on this in the next few days.

image

@rzikm
Copy link
Member

rzikm commented May 16, 2022

looks like updating the certs got the perf back to previous levels:
image

I believe we can close this issue

@rzikm rzikm closed this as completed May 16, 2022
@dakersnar dakersnar mentioned this issue May 16, 2022
Closed
16 tasks
@ghost ghost locked as resolved and limited conversation to collaborators Jun 15, 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

@rzikm rzikm

Labels
arch-x64 area-System.Net.Security PGO runtime-coreclr specific to the CoreCLR runtime
Projects
None yet
Milestone
7.0.0
Development

No branches or pull requests
6 participants
@jeffhandley @antonfirsov @kunalspathak @wfurt @dakersnar @rzikm