-
Notifications
You must be signed in to change notification settings - Fork 145
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.
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
[Profiler] Improve EtwEventsManager cleanup #6189
Conversation
Execution-Time Benchmarks Report ⏱️Execution-time results for samples comparing the following branches/commits: Execution-time benchmarks measure the whole time it takes to execute a program. And are intended to measure the one-off costs. Cases where the execution time results for the PR are worse than latest master results are shown in red. The following thresholds were used for comparing the execution times:
Note that these results are based on a single point-in-time result for each branch. For full results, see the dashboard. Graphs show the p99 interval based on the mean and StdDev of the test run, as well as the mean value of the run (shown as a diamond below the graph). gantt
title Execution time (ms) FakeDbCommand (.NET Framework 4.6.2)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6189) - mean (71ms) : 68, 73
. : milestone, 71,
master - mean (71ms) : 68, 75
. : milestone, 71,
section CallTarget+Inlining+NGEN
This PR (6189) - mean (1,115ms) : 1086, 1144
. : milestone, 1115,
master - mean (1,118ms) : 1096, 1140
. : milestone, 1118,
gantt
title Execution time (ms) FakeDbCommand (.NET Core 3.1)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6189) - mean (111ms) : 108, 114
. : milestone, 111,
master - mean (110ms) : 107, 114
. : milestone, 110,
section CallTarget+Inlining+NGEN
This PR (6189) - mean (777ms) : 763, 790
. : milestone, 777,
master - mean (778ms) : 762, 793
. : milestone, 778,
gantt
title Execution time (ms) FakeDbCommand (.NET 6)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6189) - mean (94ms) : 90, 98
. : milestone, 94,
master - mean (94ms) : 90, 97
. : milestone, 94,
section CallTarget+Inlining+NGEN
This PR (6189) - mean (734ms) : 718, 751
. : milestone, 734,
master - mean (733ms) : 718, 749
. : milestone, 733,
gantt
title Execution time (ms) HttpMessageHandler (.NET Framework 4.6.2)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6189) - mean (190ms) : 186, 194
. : milestone, 190,
master - mean (190ms) : 188, 193
. : milestone, 190,
section CallTarget+Inlining+NGEN
This PR (6189) - mean (1,201ms) : 1176, 1226
. : milestone, 1201,
master - mean (1,201ms) : 1175, 1228
. : milestone, 1201,
gantt
title Execution time (ms) HttpMessageHandler (.NET Core 3.1)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6189) - mean (276ms) : 272, 281
. : milestone, 276,
master - mean (276ms) : 271, 280
. : milestone, 276,
section CallTarget+Inlining+NGEN
This PR (6189) - mean (947ms) : 927, 968
. : milestone, 947,
master - mean (949ms) : 927, 971
. : milestone, 949,
gantt
title Execution time (ms) HttpMessageHandler (.NET 6)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6189) - mean (264ms) : 258, 271
. : milestone, 264,
master - mean (265ms) : 261, 268
. : milestone, 265,
section CallTarget+Inlining+NGEN
This PR (6189) - mean (935ms) : 918, 952
. : milestone, 935,
master - mean (924ms) : 905, 943
. : milestone, 924,
|
Datadog ReportBranch report: ✅ 0 Failed, 365605 Passed, 2410 Skipped, 17h 14m 13.75s Total Time |
Benchmarks Report for tracer 🐌Benchmarks for #6189 compared to master:
The following thresholds were used for comparing the benchmark speeds:
Allocation changes below 0.5% are ignored. Benchmark detailsBenchmarks.Trace.ActivityBenchmark - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.AgentWriterBenchmark - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.AspNetCoreBenchmark - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.DbCommandBenchmark - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.ElasticsearchBenchmark - Faster 🎉 Same allocations ✔️
|
Benchmark | base/diff | Base Median (ns) | Diff Median (ns) | Modality |
---|---|---|---|---|
Benchmarks.Trace.ElasticsearchBenchmark.CallElasticsearch‑net6.0 | 1.128 | 1,251.65 | 1,110.10 |
Raw results
Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
---|---|---|---|---|---|---|---|---|---|
master | CallElasticsearch |
net6.0 | 1.25μs | 0.447ns | 1.67ns | 0.0138 | 0 | 0 | 976 B |
master | CallElasticsearch |
netcoreapp3.1 | 1.5μs | 0.832ns | 2.88ns | 0.0132 | 0 | 0 | 976 B |
master | CallElasticsearch |
net472 | 2.51μs | 1.42ns | 5.3ns | 0.158 | 0 | 0 | 995 B |
master | CallElasticsearchAsync |
net6.0 | 1.36μs | 0.515ns | 1.93ns | 0.0131 | 0 | 0 | 952 B |
master | CallElasticsearchAsync |
netcoreapp3.1 | 1.58μs | 0.55ns | 2.06ns | 0.0135 | 0 | 0 | 1.02 KB |
master | CallElasticsearchAsync |
net472 | 2.54μs | 1.6ns | 5.99ns | 0.166 | 0 | 0 | 1.05 KB |
#6189 | CallElasticsearch |
net6.0 | 1.11μs | 0.869ns | 3.25ns | 0.014 | 0 | 0 | 976 B |
#6189 | CallElasticsearch |
netcoreapp3.1 | 1.47μs | 0.679ns | 2.54ns | 0.0133 | 0 | 0 | 976 B |
#6189 | CallElasticsearch |
net472 | 2.46μs | 2ns | 7.49ns | 0.157 | 0 | 0 | 995 B |
#6189 | CallElasticsearchAsync |
net6.0 | 1.3μs | 0.52ns | 1.94ns | 0.013 | 0 | 0 | 952 B |
#6189 | CallElasticsearchAsync |
netcoreapp3.1 | 1.62μs | 0.951ns | 3.68ns | 0.0138 | 0 | 0 | 1.02 KB |
#6189 | CallElasticsearchAsync |
net472 | 2.63μs | 2.55ns | 9.88ns | 0.166 | 0 | 0 | 1.05 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 |
net6.0 | 1.2μs | 0.484ns | 1.68ns | 0.0132 | 0 | 0 | 952 B |
master | ExecuteAsync |
netcoreapp3.1 | 1.61μs | 0.434ns | 1.62ns | 0.0129 | 0 | 0 | 952 B |
master | ExecuteAsync |
net472 | 1.8μs | 0.733ns | 2.64ns | 0.145 | 0 | 0 | 915 B |
#6189 | ExecuteAsync |
net6.0 | 1.16μs | 0.768ns | 2.87ns | 0.0134 | 0 | 0 | 952 B |
#6189 | ExecuteAsync |
netcoreapp3.1 | 1.62μs | 1.03ns | 3.86ns | 0.0122 | 0 | 0 | 952 B |
#6189 | ExecuteAsync |
net472 | 1.77μs | 0.383ns | 1.43ns | 0.145 | 0 | 0 | 915 B |
Benchmarks.Trace.HttpClientBenchmark - Same speed ✔️ Same allocations ✔️
Raw results
Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
---|---|---|---|---|---|---|---|---|---|
master | SendAsync |
net6.0 | 4.15μs | 2.37ns | 8.88ns | 0.031 | 0 | 0 | 2.22 KB |
master | SendAsync |
netcoreapp3.1 | 5.09μs | 2.33ns | 8.71ns | 0.0381 | 0 | 0 | 2.76 KB |
master | SendAsync |
net472 | 7.76μs | 1.9ns | 7.35ns | 0.498 | 0 | 0 | 3.15 KB |
#6189 | SendAsync |
net6.0 | 4.16μs | 1.68ns | 6.51ns | 0.0312 | 0 | 0 | 2.22 KB |
#6189 | SendAsync |
netcoreapp3.1 | 5.17μs | 1.48ns | 5.32ns | 0.0361 | 0 | 0 | 2.76 KB |
#6189 | SendAsync |
net472 | 7.89μs | 1.46ns | 5.67ns | 0.499 | 0 | 0 | 3.15 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 |
net6.0 | 1.55μs | 0.725ns | 2.62ns | 0.0231 | 0 | 0 | 1.64 KB |
master | EnrichedLog |
netcoreapp3.1 | 2.08μs | 0.824ns | 3.08ns | 0.022 | 0 | 0 | 1.64 KB |
master | EnrichedLog |
net472 | 2.49μs | 1.36ns | 5.07ns | 0.249 | 0 | 0 | 1.57 KB |
#6189 | EnrichedLog |
net6.0 | 1.47μs | 3.04ns | 11.8ns | 0.0226 | 0 | 0 | 1.64 KB |
#6189 | EnrichedLog |
netcoreapp3.1 | 2.11μs | 1.3ns | 4.68ns | 0.0222 | 0 | 0 | 1.64 KB |
#6189 | EnrichedLog |
net472 | 2.57μs | 1.01ns | 3.93ns | 0.249 | 0 | 0 | 1.57 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 |
net6.0 | 116μs | 153ns | 573ns | 0.0583 | 0 | 0 | 4.28 KB |
master | EnrichedLog |
netcoreapp3.1 | 122μs | 86.3ns | 311ns | 0.0606 | 0 | 0 | 4.28 KB |
master | EnrichedLog |
net472 | 153μs | 148ns | 572ns | 0.69 | 0.23 | 0 | 4.46 KB |
#6189 | EnrichedLog |
net6.0 | 119μs | 174ns | 651ns | 0 | 0 | 0 | 4.28 KB |
#6189 | EnrichedLog |
netcoreapp3.1 | 123μs | 259ns | 1μs | 0 | 0 | 0 | 4.28 KB |
#6189 | EnrichedLog |
net472 | 153μs | 117ns | 437ns | 0.685 | 0.228 | 0 | 4.46 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 |
net6.0 | 3.06μs | 0.767ns | 2.87ns | 0.0307 | 0 | 0 | 2.2 KB |
master | EnrichedLog |
netcoreapp3.1 | 4.22μs | 1.49ns | 5.77ns | 0.0294 | 0 | 0 | 2.2 KB |
master | EnrichedLog |
net472 | 4.89μs | 2.67ns | 10.4ns | 0.32 | 0 | 0 | 2.02 KB |
#6189 | EnrichedLog |
net6.0 | 3.08μs | 1.3ns | 5.04ns | 0.0308 | 0 | 0 | 2.2 KB |
#6189 | EnrichedLog |
netcoreapp3.1 | 4.23μs | 1.61ns | 6.22ns | 0.0294 | 0 | 0 | 2.2 KB |
#6189 | EnrichedLog |
net472 | 4.88μs | 3ns | 11.2ns | 0.32 | 0 | 0 | 2.02 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 |
net6.0 | 1.39μs | 0.816ns | 3.16ns | 0.016 | 0 | 0 | 1.14 KB |
master | SendReceive |
netcoreapp3.1 | 1.79μs | 0.844ns | 2.92ns | 0.0156 | 0 | 0 | 1.14 KB |
master | SendReceive |
net472 | 2.18μs | 1.04ns | 4.05ns | 0.183 | 0.00109 | 0 | 1.16 KB |
#6189 | SendReceive |
net6.0 | 1.3μs | 1.1ns | 4.25ns | 0.0163 | 0 | 0 | 1.14 KB |
#6189 | SendReceive |
netcoreapp3.1 | 1.72μs | 1.25ns | 4.85ns | 0.0154 | 0 | 0 | 1.14 KB |
#6189 | SendReceive |
net472 | 2.01μs | 0.806ns | 3.02ns | 0.183 | 0.00101 | 0 | 1.16 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 |
net6.0 | 2.76μs | 0.913ns | 3.42ns | 0.022 | 0 | 0 | 1.6 KB |
master | EnrichedLog |
netcoreapp3.1 | 3.89μs | 2.25ns | 8.44ns | 0.0215 | 0 | 0 | 1.65 KB |
master | EnrichedLog |
net472 | 4.46μs | 4.67ns | 18.1ns | 0.322 | 0 | 0 | 2.04 KB |
#6189 | EnrichedLog |
net6.0 | 2.7μs | 0.799ns | 2.99ns | 0.0214 | 0 | 0 | 1.6 KB |
#6189 | EnrichedLog |
netcoreapp3.1 | 3.88μs | 2.1ns | 7.85ns | 0.0214 | 0 | 0 | 1.65 KB |
#6189 | EnrichedLog |
net472 | 4.43μs | 4.45ns | 17.2ns | 0.323 | 0 | 0 | 2.04 KB |
Benchmarks.Trace.SpanBenchmark - Slower ⚠️ Same allocations ✔️
Slower ⚠️ in #6189
Benchmark
diff/base
Base Median (ns)
Diff Median (ns)
Modality
Benchmarks.Trace.SpanBenchmark.StartFinishScope‑net6.0
1.247
492.91
614.45
Faster 🎉 in #6189
Benchmark
base/diff
Base Median (ns)
Diff Median (ns)
Modality
Benchmarks.Trace.SpanBenchmark.StartFinishSpan‑net6.0
1.221
490.44
401.74
Benchmark | diff/base | Base Median (ns) | Diff Median (ns) | Modality |
---|---|---|---|---|
Benchmarks.Trace.SpanBenchmark.StartFinishScope‑net6.0 | 1.247 | 492.91 | 614.45 |
Benchmark | base/diff | Base Median (ns) | Diff Median (ns) | Modality |
---|---|---|---|---|
Benchmarks.Trace.SpanBenchmark.StartFinishSpan‑net6.0 | 1.221 | 490.44 | 401.74 |
Raw results
Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
---|---|---|---|---|---|---|---|---|---|
master | StartFinishSpan |
net6.0 | 490ns | 0.31ns | 1.2ns | 0.00809 | 0 | 0 | 576 B |
master | StartFinishSpan |
netcoreapp3.1 | 603ns | 0.916ns | 3.3ns | 0.00775 | 0 | 0 | 576 B |
master | StartFinishSpan |
net472 | 683ns | 0.282ns | 1.09ns | 0.0916 | 0 | 0 | 578 B |
master | StartFinishScope |
net6.0 | 493ns | 0.255ns | 0.987ns | 0.00968 | 0 | 0 | 696 B |
master | StartFinishScope |
netcoreapp3.1 | 754ns | 4.12ns | 22.5ns | 0.0093 | 0 | 0 | 696 B |
master | StartFinishScope |
net472 | 902ns | 0.969ns | 3.75ns | 0.104 | 0 | 0 | 658 B |
#6189 | StartFinishSpan |
net6.0 | 402ns | 0.145ns | 0.56ns | 0.00808 | 0 | 0 | 576 B |
#6189 | StartFinishSpan |
netcoreapp3.1 | 562ns | 0.212ns | 0.82ns | 0.00784 | 0 | 0 | 576 B |
#6189 | StartFinishSpan |
net472 | 701ns | 0.256ns | 0.99ns | 0.0915 | 0 | 0 | 578 B |
#6189 | StartFinishScope |
net6.0 | 615ns | 0.159ns | 0.595ns | 0.00984 | 0 | 0 | 696 B |
#6189 | StartFinishScope |
netcoreapp3.1 | 771ns | 0.557ns | 2.16ns | 0.00923 | 0 | 0 | 696 B |
#6189 | StartFinishScope |
net472 | 901ns | 0.705ns | 2.64ns | 0.104 | 0 | 0 | 658 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 |
net6.0 | 647ns | 0.516ns | 2ns | 0.00971 | 0 | 0 | 696 B |
master | RunOnMethodBegin |
netcoreapp3.1 | 960ns | 0.623ns | 2.41ns | 0.00958 | 0 | 0 | 696 B |
master | RunOnMethodBegin |
net472 | 1.09μs | 0.976ns | 3.78ns | 0.104 | 0 | 0 | 658 B |
#6189 | RunOnMethodBegin |
net6.0 | 612ns | 0.315ns | 1.22ns | 0.0098 | 0 | 0 | 696 B |
#6189 | RunOnMethodBegin |
netcoreapp3.1 | 883ns | 0.448ns | 1.73ns | 0.00927 | 0 | 0 | 696 B |
#6189 | RunOnMethodBegin |
net472 | 1.07μs | 0.388ns | 1.45ns | 0.104 | 0 | 0 | 658 B |
Throughput/Crank Report ⚡Throughput results for AspNetCoreSimpleController comparing the following branches/commits: Cases where throughput results for the PR are worse than latest master (5% drop or greater), results are shown in red. Note that these results are based on a single point-in-time result for each branch. For full results, see one of the many, many dashboards! gantt
title Throughput Linux x64 (Total requests)
dateFormat X
axisFormat %s
section Baseline
This PR (6189) (11.119M) : 0, 11119369
master (11.292M) : 0, 11291882
benchmarks/2.9.0 (11.081M) : 0, 11080577
section Automatic
This PR (6189) (7.417M) : 0, 7417071
master (7.471M) : 0, 7470618
benchmarks/2.9.0 (7.732M) : 0, 7732233
section Trace stats
master (7.854M) : 0, 7853541
section Manual
master (11.178M) : 0, 11177916
section Manual + Automatic
This PR (6189) (6.915M) : 0, 6915329
master (6.983M) : 0, 6983283
section DD_TRACE_ENABLED=0
master (10.353M) : 0, 10352817
gantt
title Throughput Linux arm64 (Total requests)
dateFormat X
axisFormat %s
section Baseline
This PR (6189) (9.470M) : 0, 9470162
master (9.759M) : 0, 9758573
benchmarks/2.9.0 (9.798M) : 0, 9798067
section Automatic
This PR (6189) (6.585M) : 0, 6584972
master (6.447M) : 0, 6446582
section Trace stats
master (6.536M) : 0, 6536083
section Manual
master (9.551M) : 0, 9551044
section Manual + Automatic
This PR (6189) (6.102M) : 0, 6101835
master (6.282M) : 0, 6282382
section DD_TRACE_ENABLED=0
master (8.955M) : 0, 8955266
gantt
title Throughput Windows x64 (Total requests)
dateFormat X
axisFormat %s
section Baseline
This PR (6189) (9.832M) : 0, 9831829
master (9.819M) : 0, 9818915
benchmarks/2.9.0 (10.067M) : 0, 10067315
section Automatic
This PR (6189) (6.290M) : 0, 6290305
master (6.429M) : 0, 6429392
benchmarks/2.9.0 (7.552M) : 0, 7552193
section Trace stats
master (7.215M) : 0, 7214864
section Manual
master (9.879M) : 0, 9879197
section Manual + Automatic
This PR (6189) (6.234M) : 0, 6233538
master (5.890M) : 0, 5889975
section DD_TRACE_ENABLED=0
master (9.240M) : 0, 9240298
|
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
one comment, LGTM otherwise
Summary of changes
Avoid closing already closed named pipe server
Reason for change
One test was failing in x86
Implementation details
Test coverage
Other details