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

Regression in Microsoft.Extensions.DependencyInjection.TimeToFirstService #57146

Closed
performanceautofiler bot opened this issue Aug 10, 2021 · 4 comments
Closed

Regression in Microsoft.Extensions.DependencyInjection.TimeToFirstService #57146

performanceautofiler bot opened this issue Aug 10, 2021 · 4 comments
Assignees
@eerhardt
Labels
arch-x64 area-Extensions-DependencyInjection os-linux Linux OS (any supported distro) os-windows tenet-performance Performance related issue tenet-performance-benchmarks Issue from performance benchmark
Milestone
6.0.0

Comments

@performanceautofiler
Copy link

Run Information

Architecture x86
OS Windows 10.0.18362
Baseline 4803ce2c8f7bd335a2e81aa3c312c61707f70b0e
Compare 3c903d622ca8d9269b8c5384e32e357882001450
Diff Diff

Regressions in Microsoft.Extensions.DependencyInjection.TimeToFirstService

Benchmark Baseline Test Test/Base Test Quality Edge Detector Baseline IR Compare IR IR Ratio Baseline ETL Compare ETL
BuildProvider - Duration of single invocation 975.92 ns 1.66 μs 1.70 0.01 True
Transient - Duration of single invocation 3.02 μs 3.64 μs 1.21 0.05 False
Scoped - Duration of single invocation 3.45 μs 3.90 μs 1.13 0.04 False
Singleton - Duration of single invocation 3.06 μs 3.54 μs 1.16 0.04 False
Transient - Duration of single invocation 3.00 μs 3.49 μs 1.16 0.06 False
BuildProvider - Duration of single invocation 977.34 ns 1.65 μs 1.69 0.01 True
Scoped - Duration of single invocation 3.48 μs 4.11 μs 1.18 0.07 False
Singleton - Duration of single invocation 3.09 μs 3.51 μs 1.14 0.07 False
Transient - Duration of single invocation 3.02 μs 3.56 μs 1.18 0.03 True
Transient - Duration of single invocation 3.03 μs 3.56 μs 1.17 0.03 False
BuildProvider - Duration of single invocation 975.34 ns 1.67 μs 1.71 0.01 True
Scoped - Duration of single invocation 3.43 μs 3.91 μs 1.14 0.03 False
Singleton - Duration of single invocation 3.12 μs 3.57 μs 1.14 0.03 False
Singleton - Duration of single invocation 3.08 μs 3.55 μs 1.15 0.03 False
Scoped - Duration of single invocation 3.50 μs 4.01 μs 1.15 0.03 False
BuildProvider - Duration of single invocation 972.36 ns 1.66 μs 1.71 0.01 True

graph
graph
graph
graph
graph
graph
graph
graph
graph
graph
graph
graph
graph
graph
graph
graph
Historical Data in Reporting System

Repro

git clone https://github.com/dotnet/performance.git
py .\performance\scripts\benchmarks_ci.py -f netcoreapp5.0 --filter 'Microsoft.Extensions.DependencyInjection.TimeToFirstService*'

Payloads

Baseline
Compare

Histogram

Microsoft.Extensions.DependencyInjection.TimeToFirstService.BuildProvider(Mode: "Expressions")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.Transient(Mode: "Dynamic")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.Scoped(Mode: "ILEmit")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.Singleton(Mode: "ILEmit")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.Transient(Mode: "ILEmit")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.BuildProvider(Mode: "ILEmit")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.Scoped(Mode: "Expressions")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.Singleton(Mode: "Dynamic")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.Transient(Mode: "Runtime")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.Transient(Mode: "Expressions")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.BuildProvider(Mode: "Dynamic")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.Scoped(Mode: "Dynamic")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.Singleton(Mode: "Runtime")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.Singleton(Mode: "Expressions")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.Scoped(Mode: "Runtime")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.BuildProvider(Mode: "Runtime")

Docs

Profiling workflow for dotnet/runtime repository
Benchmarking workflow for dotnet/runtime repository
@DrewScoggins DrewScoggins transferred this issue from dotnet/perf-autofiling-issues Aug 10, 2021
@DrewScoggins DrewScoggins changed the title [Perf] Changes at 8/7/2021 3:21:54 PM Regression in Microsoft.Extensions.DependencyInjection.TimeToFirstService Aug 10, 2021
@DrewScoggins DrewScoggins added arch-x64 os-linux Linux OS (any supported distro) os-windows tenet-performance Performance related issue tenet-performance-benchmarks Issue from performance benchmark labels Aug 10, 2021
@DrewScoggins
Copy link
Member

#56809

@dotnet-issue-labeler dotnet-issue-labeler bot added area-Extensions-DependencyInjection untriaged New issue has not been triaged by the area owner labels Aug 10, 2021
@ghost
Copy link

ghost commented Aug 10, 2021

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

Issue Details

Run Information

Architecture x86
OS Windows 10.0.18362
Baseline 4803ce2c8f7bd335a2e81aa3c312c61707f70b0e
Compare 3c903d622ca8d9269b8c5384e32e357882001450
Diff Diff

Regressions in Microsoft.Extensions.DependencyInjection.TimeToFirstService

Benchmark Baseline Test Test/Base Test Quality Edge Detector Baseline IR Compare IR IR Ratio Baseline ETL Compare ETL
BuildProvider - Duration of single invocation 975.92 ns 1.66 μs 1.70 0.01 True
Transient - Duration of single invocation 3.02 μs 3.64 μs 1.21 0.05 False
Scoped - Duration of single invocation 3.45 μs 3.90 μs 1.13 0.04 False
Singleton - Duration of single invocation 3.06 μs 3.54 μs 1.16 0.04 False
Transient - Duration of single invocation 3.00 μs 3.49 μs 1.16 0.06 False
BuildProvider - Duration of single invocation 977.34 ns 1.65 μs 1.69 0.01 True
Scoped - Duration of single invocation 3.48 μs 4.11 μs 1.18 0.07 False
Singleton - Duration of single invocation 3.09 μs 3.51 μs 1.14 0.07 False
Transient - Duration of single invocation 3.02 μs 3.56 μs 1.18 0.03 True
Transient - Duration of single invocation 3.03 μs 3.56 μs 1.17 0.03 False
BuildProvider - Duration of single invocation 975.34 ns 1.67 μs 1.71 0.01 True
Scoped - Duration of single invocation 3.43 μs 3.91 μs 1.14 0.03 False
Singleton - Duration of single invocation 3.12 μs 3.57 μs 1.14 0.03 False
Singleton - Duration of single invocation 3.08 μs 3.55 μs 1.15 0.03 False
Scoped - Duration of single invocation 3.50 μs 4.01 μs 1.15 0.03 False
BuildProvider - Duration of single invocation 972.36 ns 1.66 μs 1.71 0.01 True

graph
graph
graph
graph
graph
graph
graph
graph
graph
graph
graph
graph
graph
graph
graph
graph
Historical Data in Reporting System

Repro

git clone https://github.com/dotnet/performance.git
py .\performance\scripts\benchmarks_ci.py -f netcoreapp5.0 --filter 'Microsoft.Extensions.DependencyInjection.TimeToFirstService*'

Payloads

Baseline
Compare

Histogram

Microsoft.Extensions.DependencyInjection.TimeToFirstService.BuildProvider(Mode: "Expressions")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.Transient(Mode: "Dynamic")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.Scoped(Mode: "ILEmit")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.Singleton(Mode: "ILEmit")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.Transient(Mode: "ILEmit")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.BuildProvider(Mode: "ILEmit")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.Scoped(Mode: "Expressions")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.Singleton(Mode: "Dynamic")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.Transient(Mode: "Runtime")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.Transient(Mode: "Expressions")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.BuildProvider(Mode: "Dynamic")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.Scoped(Mode: "Dynamic")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.Singleton(Mode: "Runtime")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.Singleton(Mode: "Expressions")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.Scoped(Mode: "Runtime")

Microsoft.Extensions.DependencyInjection.TimeToFirstService.BuildProvider(Mode: "Runtime")

Docs

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

Author: performanceautofiler[bot]
Assignees: eerhardt
Labels:

os-linux, os-windows, tenet-performance, tenet-performance-benchmarks, arch-x64, untriaged, area-Extensions-DependencyInjection
Milestone: -

eerhardt added a commit to eerhardt/performance that referenced this issue Aug 10, 2021
@eerhardt
Fix TimeToFirstService tests to dispose the ServiceProvider correctly
c6839bc 
Contributes to dotnet/runtime#57146
@eerhardt eerhardt mentioned this issue Aug 10, 2021
Merged
@eerhardt
Copy link
Member

The majority of the regression here occurred because we depend on the ServiceProvider being disposed in order to remove it from the list maintained in the EventSource. See #56809 for more details. However, the perf test isn't disposing of all the ServiceProviders it creates. I'm fixing that in dotnet/performance#1915.

However, even with that fixed, we still have a ~5-10% regression here. After profiling, I see that creating WeakReference instances adds about 7%. So I created a change locally that didn't use WeakReference, and instead just holds directly onto the ServiceProvider. This gets back a lot of the regression. On my machine, the numbers I see are:

Method Toolchain Mean Error Ratio
BuildProvider \After56809\corerun.exe 5.139 us 0.1980 us 1.20
BuildProvider \Before56809\corerun.exe 4.278 us 0.2091 us 1.00
BuildProvider \NoWeakRef\corerun.exe 4.415 us 0.0825 us 1.02
Transient \After56809\corerun.exe 11.717 us 0.7768 us 1.12
Transient \Before56809\corerun.exe 10.494 us 0.3826 us 1.00
Transient \NoWeakRef\corerun.exe 11.355 us 0.6039 us 1.08
Scoped \After56809\corerun.exe 13.006 us 0.5993 us 1.12
Scoped \Before56809\corerun.exe 11.546 us 0.1159 us 1.00
Scoped \NoWeakRef\corerun.exe 11.900 us 0.3847 us 1.02
Singleton \After56809\corerun.exe 11.363 us 0.4158 us 1.05
Singleton \Before56809\corerun.exe 10.874 us 0.7197 us 1.00
Singleton \NoWeakRef\corerun.exe 10.835 us 0.5034 us 1.00
BuildProvider \After56809\corerun.exe 5.050 us 0.0864 us 1.20
BuildProvider \Before56809\corerun.exe 4.200 us 0.0847 us 1.00
BuildProvider \NoWeakRef\corerun.exe 4.517 us 0.1331 us 1.07
Transient \After56809\corerun.exe 11.853 us 0.7914 us 1.07
Transient \Before56809\corerun.exe 11.110 us 1.1999 us 1.00
Transient \NoWeakRef\corerun.exe 10.575 us 0.3055 us 0.94
Scoped \After56809\corerun.exe 12.695 us 0.6120 us 1.05
Scoped \Before56809\corerun.exe 12.161 us 0.6388 us 1.00
Scoped \NoWeakRef\corerun.exe 12.179 us 0.5881 us 1.00
Singleton \After56809\corerun.exe 11.023 us 0.2195 us 1.01
Singleton \Before56809\corerun.exe 10.850 us 0.4884 us 1.00
Singleton \NoWeakRef\corerun.exe 10.538 us 0.2047 us 0.97
BuildProvider \After56809\corerun.exe 4.961 us 0.1474 us 1.15
BuildProvider \Before56809\corerun.exe 4.305 us 0.1628 us 1.00
BuildProvider \NoWeakRef\corerun.exe 4.425 us 0.1084 us 1.03
Transient \After56809\corerun.exe 11.000 us 0.2074 us 1.04
Transient \Before56809\corerun.exe 10.553 us 0.2841 us 1.00
Transient \NoWeakRef\corerun.exe 10.500 us 0.1829 us 0.99
Scoped \After56809\corerun.exe 12.489 us 0.3466 us 1.07
Scoped \Before56809\corerun.exe 11.682 us 0.2885 us 1.00
Scoped \NoWeakRef\corerun.exe 12.061 us 0.5816 us 1.04
Singleton \After56809\corerun.exe 11.106 us 0.2300 us 1.04
Singleton \Before56809\corerun.exe 10.658 us 0.3677 us 1.00
Singleton \NoWeakRef\corerun.exe 10.442 us 0.1849 us 0.98
BuildProvider \After56809\corerun.exe 4.900 us 0.0489 us 1.10
BuildProvider \Before56809\corerun.exe 4.411 us 0.2507 us 1.00
BuildProvider \NoWeakRef\corerun.exe 4.526 us 0.1116 us 1.03
Transient \After56809\corerun.exe 11.085 us 0.1683 us 1.03
Transient \Before56809\corerun.exe 10.768 us 0.5229 us 1.00
Transient \NoWeakRef\corerun.exe 11.480 us 0.7388 us 1.07
Scoped \After56809\corerun.exe 12.479 us 0.4183 us 1.07
Scoped \Before56809\corerun.exe 11.728 us 0.3154 us 1.00
Scoped \NoWeakRef\corerun.exe 11.978 us 0.2930 us 1.02
Singleton \After56809\corerun.exe 11.083 us 0.2103 us 1.00
Singleton \Before56809\corerun.exe 10.930 us 0.4578 us 1.00
Singleton \NoWeakRef\corerun.exe 10.612 us 0.2456 us 0.98

@davidfowl - do you think using WeakReference is an acceptable tradeoff here? Or should we instead remove the WeakReference usage?

My initial thoughts are that typical apps don't create many ServiceProviders, so using WeakReference is acceptable here.

@maryamariyan maryamariyan removed the untriaged New issue has not been triaged by the area owner label Aug 11, 2021
@maryamariyan maryamariyan added this to the 6.0.0 milestone Aug 11, 2021
billwert pushed a commit to dotnet/performance that referenced this issue Aug 11, 2021
@eerhardt
Fix TimeToFirstService tests to dispose the ServiceProvider correctly (…
5522aa9 
…#1915)

* Fix TimeToFirstService tests to dispose the ServiceProvider correctly

Contributes to dotnet/runtime#57146

* Move Dispose into the Benchmarck, as IterationCleanup shouldn't be used in a micro benchmark.
@eerhardt
Copy link
Member

Consulting with @davidfowl offline, we both agree that we should keep the WeakReference as it is currently in the code. Thus the regression noted in my comment above is acceptable.

The major regression part of the test was addressed with dotnet/performance#1915 (disposing the ServiceProviders properly).

Closing.

@eerhardt eerhardt mentioned this issue Aug 26, 2021
Closed
@ghost ghost locked as resolved and limited conversation to collaborators Sep 11, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees

@eerhardt eerhardt

Labels
arch-x64 area-Extensions-DependencyInjection os-linux Linux OS (any supported distro) os-windows tenet-performance Performance related issue tenet-performance-benchmarks Issue from performance benchmark
Projects
None yet
Milestone
6.0.0
Development

No branches or pull requests
3 participants
@maryamariyan @eerhardt @DrewScoggins