Skip to content

Low hanging fruit startup optimization#3195

Merged
tonyredondo merged 4 commits into
masterfrom
tony/loader-initialization-optimization
Sep 12, 2022
Merged

Low hanging fruit startup optimization#3195
tonyredondo merged 4 commits into
masterfrom
tony/loader-initialization-optimization

Conversation

@tonyredondo

Copy link
Copy Markdown
Member

Summary of changes

This PR contains a simple optimization to avoid the reflection Invoke call at startup.

@tonyredondo tonyredondo self-assigned this Sep 9, 2022
@tonyredondo
tonyredondo marked this pull request as ready for review September 9, 2022 08:12
@tonyredondo
tonyredondo requested a review from a team as a code owner September 9, 2022 08:12
@tonyredondo tonyredondo added type:enhancement Improvement to an existing feature type:performance Performance, speed, latency, resource usage (CPU, memory) labels Sep 9, 2022
@andrewlock

This comment has been minimized.

// this way we avoid the reflection invoke call.
if (assembly.GetType(loaderHelperTypeName, throwOnError: false) is { } loaderHelperType)
{
Activator.CreateInstance(loaderHelperType);

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Are you sure Activator.CreateInstance is faster than invoking a method through reflection? 🤔

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is not exactly the same case, but very similar, and also one thing to take in consideration is that on startup time in the tracer we have NGEN disabled and instrumenting through the JITCompilationStart to inject the loader. So less internal calls the better. And I think calling by reflection will result in more checks and internals calls, althought I'm not 100% sure of this.

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

BenchmarkDotNet=v0.12.1, OS=Windows 10.0.22000
AMD Ryzen 9 5950X, 1 CPU, 32 logical and 16 physical cores
.NET Core SDK=7.0.100-preview.7.22377.5
  [Host]     : .NET Core 3.1.28 (CoreCLR 4.700.22.36202, CoreFX 4.700.22.36301), X64 RyuJIT
  DefaultJob : .NET Core 3.1.28 (CoreCLR 4.700.22.36202, CoreFX 4.700.22.36301), X64 RyuJIT


|                    Method |     Mean |    Error |   StdDev |   Median |  Gen 0 | Gen 1 | Gen 2 | Allocated |
|-------------------------- |---------:|---------:|---------:|---------:|-------:|------:|------:|----------:|
| ReflectionInvokeBenchmark | 74.25 ns | 0.646 ns | 0.605 ns | 74.37 ns |      - |     - |     - |         - |
|        ActivatorBenchmark | 30.30 ns | 0.760 ns | 2.194 ns | 30.90 ns | 0.0000 |     - |     - |      24 B |
AMD Ryzen 9 5950X, 1 CPU, 32 logical and 16 physical cores
  [Host]     : .NET Framework 4.8 (4.8.4515.0), X64 RyuJIT
  DefaultJob : .NET Framework 4.8 (4.8.4515.0), X64 RyuJIT


|                    Method |      Mean |    Error |   StdDev |  Gen 0 | Gen 1 | Gen 2 | Allocated |
|-------------------------- |----------:|---------:|---------:|-------:|------:|------:|----------:|
| ReflectionInvokeBenchmark | 103.12 ns | 0.835 ns | 0.740 ns |      - |     - |     - |         - |
|        ActivatorBenchmark |  56.75 ns | 0.299 ns | 0.280 ns | 0.0038 |     - |     - |      24 B |

@andrewlock

This comment has been minimized.

@andrewlock

This comment has been minimized.

@andrewlock

This comment has been minimized.

@andrewlock andrewlock left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM, but what happened to those public API tests? 😬

Comment on lines +3 to +9
namespace Datadog.Trace
{
public sealed class AgentProcessManagerLoader
{
public AgentProcessManagerLoader() { }
}
public static class CorrelationIdentifier

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Um.... :wat:

I guess we need to sort the namespaces in here or something 😬

@tonyredondo tonyredondo Sep 9, 2022

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I didn't do anything, just updated the snapshot I guess it is because the sorting indeed.

@andrewlock

Copy link
Copy Markdown
Member

Benchmarks Report 🐌

Benchmarks for #3195 compared to master:

  • All benchmarks have the same speed
  • All benchmarks have the same allocations

The following thresholds were used for comparing the benchmark speeds:

  • Mann–Whitney U test with statistical test for significance of 5%
  • Only results indicating a difference greater than 10% and 0.3 ns are considered.

Allocation changes below 0.5% are ignored.

Benchmark details

Benchmarks.Trace.AgentWriterBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master WriteAndFlushEnrichedTraces net472 720μs 425ns 1.59μs 0.361 0 0 3.18 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 470μs 203ns 731ns 0 0 0 2.58 KB
#3195 WriteAndFlushEnrichedTraces net472 720μs 515ns 1.99μs 0.359 0 0 3.18 KB
#3195 WriteAndFlushEnrichedTraces netcoreapp3.1 473μs 249ns 933ns 0 0 0 2.59 KB
Benchmarks.Trace.AppSecBodyBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master AllCycleSimpleBody net472 186ns 0.115ns 0.429ns 0.0676 0 0 425 B
master AllCycleSimpleBody netcoreapp3.1 242ns 0.658ns 2.55ns 0.00583 0 0 424 B
master AllCycleMoreComplexBody net472 203ns 0.173ns 0.668ns 0.0637 0 0 401 B
master AllCycleMoreComplexBody netcoreapp3.1 233ns 0.238ns 0.892ns 0.00547 0 0 400 B
master BodyExtractorSimpleBody net472 260ns 0.162ns 0.607ns 0.0573 0 0 361 B
master BodyExtractorSimpleBody netcoreapp3.1 235ns 0.213ns 0.825ns 0.00377 0 0 272 B
master BodyExtractorMoreComplexBody net472 14.4μs 9.15ns 35.4ns 1.21 0.0216 0 7.62 KB
master BodyExtractorMoreComplexBody netcoreapp3.1 11.8μs 17.9ns 69.2ns 0.0874 0 0 6.75 KB
#3195 AllCycleSimpleBody net472 186ns 0.157ns 0.588ns 0.0675 0 0 425 B
#3195 AllCycleSimpleBody netcoreapp3.1 234ns 0.291ns 1.13ns 0.0059 0 0 424 B
#3195 AllCycleMoreComplexBody net472 185ns 0.0913ns 0.329ns 0.0638 0 0 401 B
#3195 AllCycleMoreComplexBody netcoreapp3.1 243ns 0.338ns 1.31ns 0.00557 0 0 400 B
#3195 BodyExtractorSimpleBody net472 256ns 0.252ns 0.942ns 0.0573 0 0 361 B
#3195 BodyExtractorSimpleBody netcoreapp3.1 235ns 0.496ns 1.92ns 0.00364 0 0 272 B
#3195 BodyExtractorMoreComplexBody net472 14.6μs 9.95ns 38.5ns 1.21 0.0217 0 7.62 KB
#3195 BodyExtractorMoreComplexBody netcoreapp3.1 11.9μs 16.2ns 62.8ns 0.0884 0 0 6.75 KB
Benchmarks.Trace.AspNetCoreBenchmark - Unknown 🤷 Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendRequest net472 0ns 0ns 0ns 0 0 0 0 b
master SendRequest netcoreapp3.1 182μs 188ns 704ns 0.182 0 0 20.57 KB
#3195 SendRequest net472 0ns 0ns 0ns 0 0 0 0 b
#3195 SendRequest netcoreapp3.1 182μs 244ns 945ns 0.184 0 0 20.56 KB
Benchmarks.Trace.DbCommandBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master ExecuteNonQuery net472 1.83μs 1.08ns 4.06ns 0.15 0.000915 0 947 B
master ExecuteNonQuery netcoreapp3.1 1.45μs 0.569ns 2.13ns 0.0123 0 0 936 B
#3195 ExecuteNonQuery net472 1.89μs 0.958ns 3.58ns 0.15 0 0 947 B
#3195 ExecuteNonQuery netcoreapp3.1 1.41μs 1.05ns 4.06ns 0.0127 0 0 936 B
Benchmarks.Trace.ElasticsearchBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master CallElasticsearch net472 2.56μs 1.78ns 6.66ns 0.183 0 0 1.16 KB
master CallElasticsearch netcoreapp3.1 1.59μs 0.795ns 2.97ns 0.0143 0 0 1.1 KB
master CallElasticsearchAsync net472 2.82μs 3.96ns 14.3ns 0.205 0 0 1.29 KB
master CallElasticsearchAsync netcoreapp3.1 1.69μs 0.436ns 1.57ns 0.016 0 0 1.22 KB
#3195 CallElasticsearch net472 2.64μs 1.76ns 6.81ns 0.183 0 0 1.16 KB
#3195 CallElasticsearch netcoreapp3.1 1.57μs 1.13ns 4.39ns 0.015 0 0 1.1 KB
#3195 CallElasticsearchAsync net472 2.75μs 2.63ns 9.85ns 0.204 0 0 1.29 KB
#3195 CallElasticsearchAsync netcoreapp3.1 1.66μs 0.699ns 2.62ns 0.0165 0 0 1.22 KB
Benchmarks.Trace.GraphQLBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master ExecuteAsync net472 2.84μs 8.68ns 32.5ns 0.225 0 0 1.42 KB
master ExecuteAsync netcoreapp3.1 1.69μs 3.49ns 13.5ns 0.0186 0 0 1.34 KB
#3195 ExecuteAsync net472 2.72μs 5.91ns 21.3ns 0.226 0 0 1.42 KB
#3195 ExecuteAsync netcoreapp3.1 1.73μs 4.85ns 18.8ns 0.018 0 0 1.34 KB
Benchmarks.Trace.HttpClientBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendAsync net472 5.75μs 14.3ns 55.4ns 0.438 0 0 2.77 KB
master SendAsync netcoreapp3.1 3.62μs 7.02ns 26.3ns 0.0343 0 0 2.6 KB
#3195 SendAsync net472 5.72μs 12.2ns 47.4ns 0.439 0 0 2.77 KB
#3195 SendAsync netcoreapp3.1 3.69μs 7.68ns 28.7ns 0.0348 0 0 2.6 KB
Benchmarks.Trace.ILoggerBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net472 3.13μs 2.25ns 8.43ns 0.288 0 0 1.81 KB
master EnrichedLog netcoreapp3.1 2.51μs 1.04ns 4.04ns 0.0252 0 0 1.85 KB
#3195 EnrichedLog net472 3.21μs 4.6ns 17.8ns 0.287 0.0016 0 1.81 KB
#3195 EnrichedLog netcoreapp3.1 2.51μs 1.28ns 4.77ns 0.025 0 0 1.85 KB
Benchmarks.Trace.Log4netBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net472 153μs 181ns 702ns 0.686 0.229 0 4.65 KB
master EnrichedLog netcoreapp3.1 118μs 114ns 426ns 0 0 0 4.49 KB
#3195 EnrichedLog net472 153μs 220ns 850ns 0.689 0.23 0 4.66 KB
#3195 EnrichedLog netcoreapp3.1 116μs 154ns 598ns 0.0583 0 0 4.49 KB
Benchmarks.Trace.NLogBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net472 5.67μs 7.05ns 26.4ns 0.569 0.00282 0 3.59 KB
master EnrichedLog netcoreapp3.1 4.25μs 8.69ns 32.5ns 0.0522 0 0 3.91 KB
#3195 EnrichedLog net472 5.56μs 13ns 50.5ns 0.568 0.0028 0 3.59 KB
#3195 EnrichedLog netcoreapp3.1 4.55μs 17.1ns 63.8ns 0.0531 0 0 3.91 KB
Benchmarks.Trace.RedisBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendReceive net472 2.25μs 1.6ns 5.97ns 0.218 0 0 1.37 KB
master SendReceive netcoreapp3.1 1.74μs 0.793ns 2.97ns 0.0174 0 0 1.32 KB
#3195 SendReceive net472 2.38μs 2.7ns 10.5ns 0.217 0 0 1.37 KB
#3195 SendReceive netcoreapp3.1 1.81μs 1.14ns 4.26ns 0.0171 0 0 1.32 KB
Benchmarks.Trace.SerilogBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net472 4.98μs 3.47ns 13ns 0.353 0 0 2.23 KB
master EnrichedLog netcoreapp3.1 4.23μs 1.47ns 5.7ns 0.0233 0 0 1.8 KB
#3195 EnrichedLog net472 5.3μs 27.2ns 131ns 0.352 0 0 2.23 KB
#3195 EnrichedLog netcoreapp3.1 4.57μs 25.9ns 190ns 0.0231 0 0 1.8 KB
Benchmarks.Trace.SpanBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartFinishSpan net472 1.14μs 0.683ns 2.56ns 0.128 0 0 810 B
master StartFinishSpan netcoreapp3.1 921ns 0.327ns 1.22ns 0.0101 0 0 760 B
master StartFinishScope net472 1.41μs 0.824ns 3.19ns 0.141 0 0 891 B
master StartFinishScope netcoreapp3.1 1.11μs 4.28ns 16.6ns 0.0121 0 0 880 B
#3195 StartFinishSpan net472 1.21μs 2.69ns 10.4ns 0.128 0 0 810 B
#3195 StartFinishSpan netcoreapp3.1 912ns 0.473ns 1.83ns 0.0105 0 0 760 B
#3195 StartFinishScope net472 1.39μs 1.33ns 5.15ns 0.141 0 0 891 B
#3195 StartFinishScope netcoreapp3.1 1.1μs 0.967ns 3.74ns 0.0122 0 0 880 B
Benchmarks.Trace.TraceAnnotationsBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master RunOnMethodBegin net472 1.5μs 0.94ns 3.64ns 0.141 0 0 891 B
master RunOnMethodBegin netcoreapp3.1 1.16μs 1.65ns 6.18ns 0.012 0 0 880 B
#3195 RunOnMethodBegin net472 1.51μs 1.7ns 6.36ns 0.141 0 0 891 B
#3195 RunOnMethodBegin netcoreapp3.1 1.15μs 0.485ns 1.82ns 0.0116 0 0 880 B

@tonyredondo
tonyredondo merged commit 6f42550 into master Sep 12, 2022
@tonyredondo
tonyredondo deleted the tony/loader-initialization-optimization branch September 12, 2022 12:45
@github-actions github-actions Bot added this to the vNext milestone Sep 12, 2022
@andrewlock

Copy link
Copy Markdown
Member

Code Coverage Report 📊

✔️ Merging #3195 into master will will increase line coverage by 1%
✔️ Merging #3195 into master will will increase branch coverage by 1%
⛔ Merging #3195 into master will will increase complexity by 96

master #3195 Change
Lines 17696 / 24369 18022 / 24525
Lines % 73% 73% 1% ✔️
Branches 10398 / 14968 10617 / 15054
Branches % 69% 71% 1% ✔️
Complexity 16169 16265 96

View the full report for further details:

Datadog.Trace Breakdown ✔️

master #3195 Change
Lines % 73% 73% 1% ✔️
Branches % 69% 71% 1% ✔️
Complexity 16169 16265 96

The following classes have significant coverage changes.

File Line coverage change Branch coverage change Complexity change
Datadog.Trace.Agent.Transports.HttpStreamRequestFactory -12% 0% ✔️ 0 ✔️
Datadog.Trace.Debugger.Sink.AgentBatchUploadApi -8% 0% ✔️ 2
Datadog.Trace.TracerManagerFactory 3% ✔️ 6% ✔️ 2
Datadog.Trace.Logging.DatadogSerilogLogger 4% ✔️ 6% ✔️ 0 ✔️
Datadog.Trace.Ci.CIVisibility 5% ✔️ 6% ✔️ 0 ✔️
Datadog.Trace.Propagators.SpanContextPropagator 8% ✔️ 6% ✔️ 0 ✔️
Datadog.Trace.Agent.StatsAggregator 11% ✔️ 15% ✔️ -2 ✔️
Datadog.Trace.Processors.ObfuscatorTraceProcessor 12% ✔️ 15% ✔️ 0 ✔️
Datadog.Trace.Telemetry.Transports.JsonTelemetryTransport 12% ✔️ 17% ✔️ 0 ✔️
Datadog.Trace.Agent.DiscoveryService.DiscoveryService 21% ✔️ 46% ✔️ 29
...And 7 more

The following classes were added in #3195:

File Line coverage Branch coverage Complexity
Datadog.Trace.Agent.DiscoveryService.AgentConfiguration 100% 100% 1
Datadog.Trace.AgentProcessManagerLoader 0% 100% 1
Datadog.Trace.ClrProfiler.AutoInstrumentation.Process.EnvironmentVariablesScrubber 100% 100% 11
Datadog.Trace.ClrProfiler.AutoInstrumentation.Process.ProcessStartCommon 85% 80% 11
Datadog.Trace.ClrProfiler.AutoInstrumentation.Process.ProcessStartIntegration 80% 50% 3
...And 3 more

View the full reports for further details:

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

type:enhancement Improvement to an existing feature type:performance Performance, speed, latency, resource usage (CPU, memory)

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants