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.

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

Fix crash at shutdown in runtime metrics #5696

Merged
merged 4 commits into from
Jun 17, 2024

Conversation

kevingosse
Copy link
Collaborator

@kevingosse kevingosse commented Jun 14, 2024

Summary of changes

Don't dispose the runtime metrics when shutting down.

Reason for change

Disposing the underlying EventListener can cause a crash if the customer has another EventListener running: dotnet/runtime#103480

Implementation details

Removed the explicit Dispose call in TraceManager.RunShutdownTasksAsync

Test coverage

Added a smoke test. Confirmed that it crashes without the fix.

@andrewlock
Copy link
Member

andrewlock commented Jun 14, 2024

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:

  • Welch test with statistical test for significance of 5%
  • Only results indicating a difference greater than 5% and 5 ms are considered.

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 (5696) - mean (72ms)  : 64, 81
     .   : milestone, 72,
    master - mean (74ms)  : 65, 82
     .   : milestone, 74,

    section CallTarget+Inlining+NGEN
    This PR (5696) - mean (1,003ms)  : 986, 1020
     .   : milestone, 1003,
    master - mean (1,009ms)  : 984, 1033
     .   : milestone, 1009,

Loading
gantt
    title Execution time (ms) FakeDbCommand (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5696) - mean (109ms)  : 107, 111
     .   : milestone, 109,
    master - mean (110ms)  : 106, 113
     .   : milestone, 110,

    section CallTarget+Inlining+NGEN
    This PR (5696) - mean (715ms)  : 693, 736
     .   : milestone, 715,
    master - mean (720ms)  : 697, 742
     .   : milestone, 720,

Loading
gantt
    title Execution time (ms) FakeDbCommand (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5696) - mean (93ms)  : 89, 96
     .   : milestone, 93,
    master - mean (93ms)  : 89, 96
     .   : milestone, 93,

    section CallTarget+Inlining+NGEN
    This PR (5696) - mean (674ms)  : 652, 695
     .   : milestone, 674,
    master - mean (674ms)  : 645, 702
     .   : milestone, 674,

Loading
gantt
    title Execution time (ms) HttpMessageHandler (.NET Framework 4.6.2) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5696) - mean (191ms)  : 188, 194
     .   : milestone, 191,
    master - mean (191ms)  : 188, 195
     .   : milestone, 191,

    section CallTarget+Inlining+NGEN
    This PR (5696) - mean (1,104ms)  : 1083, 1125
     .   : milestone, 1104,
    master - mean (1,107ms)  : 1087, 1127
     .   : milestone, 1107,

Loading
gantt
    title Execution time (ms) HttpMessageHandler (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5696) - mean (277ms)  : 271, 283
     .   : milestone, 277,
    master - mean (277ms)  : 273, 282
     .   : milestone, 277,

    section CallTarget+Inlining+NGEN
    This PR (5696) - mean (901ms)  : 878, 924
     .   : milestone, 901,
    master - mean (902ms)  : 879, 925
     .   : milestone, 902,

Loading
gantt
    title Execution time (ms) HttpMessageHandler (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5696) - mean (265ms)  : 261, 270
     .   : milestone, 265,
    master - mean (266ms)  : 261, 270
     .   : milestone, 266,

    section CallTarget+Inlining+NGEN
    This PR (5696) - mean (883ms)  : 856, 909
     .   : milestone, 883,
    master - mean (881ms)  : 859, 903
     .   : milestone, 881,

Loading

@datadog-ddstaging
Copy link

datadog-ddstaging bot commented Jun 14, 2024

Datadog Report

Branch report: kevin/runtime_metrics_crash
Commit report: 69a3338
Test service: dd-trace-dotnet

✅ 0 Failed, 24255 Passed, 66 Skipped, 44m 32.33s Total Time

@andrewlock
Copy link
Member

andrewlock commented Jun 14, 2024

Benchmarks Report for tracer 🐌

Benchmarks for #5696 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.ActivityBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartStopWithChild net6.0 7.79μs 45.4ns 398ns 0.0157 0.00787 0 5.42 KB
master StartStopWithChild netcoreapp3.1 10.1μs 55.9ns 340ns 0.0196 0.00982 0 5.62 KB
master StartStopWithChild net472 16μs 47.9ns 185ns 1.03 0.315 0.0969 6.06 KB
#5696 StartStopWithChild net6.0 7.87μs 38.6ns 173ns 0.0154 0.00772 0 5.42 KB
#5696 StartStopWithChild netcoreapp3.1 9.77μs 54.1ns 342ns 0.0143 0.00476 0 5.62 KB
#5696 StartStopWithChild net472 16.1μs 34.2ns 128ns 1.01 0.3 0.0973 6.07 KB
Benchmarks.Trace.AgentWriterBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master WriteAndFlushEnrichedTraces net6.0 478μs 170ns 636ns 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 623μs 268ns 1μs 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces net472 816μs 186ns 720ns 0.406 0 0 3.3 KB
#5696 WriteAndFlushEnrichedTraces net6.0 482μs 406ns 1.57μs 0 0 0 2.7 KB
#5696 WriteAndFlushEnrichedTraces netcoreapp3.1 654μs 411ns 1.54μs 0 0 0 2.7 KB
#5696 WriteAndFlushEnrichedTraces net472 835μs 208ns 777ns 0.417 0 0 3.3 KB
Benchmarks.Trace.AspNetCoreBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendRequest net6.0 173μs 195ns 756ns 0.256 0 0 18.44 KB
master SendRequest netcoreapp3.1 192μs 404ns 1.57μs 0.191 0 0 20.6 KB
master SendRequest net472 0.000351ns 0.000221ns 0.000829ns 0 0 0 0 b
#5696 SendRequest net6.0 172μs 167ns 646ns 0.256 0 0 18.44 KB
#5696 SendRequest netcoreapp3.1 189μs 248ns 927ns 0.187 0 0 20.6 KB
#5696 SendRequest net472 0.000537ns 0.000273ns 0.00106ns 0 0 0 0 b
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master WriteAndFlushEnrichedTraces net6.0 556μs 286ns 1.07μs 0.541 0 0 41.67 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 663μs 430ns 1.55μs 0.331 0 0 41.91 KB
master WriteAndFlushEnrichedTraces net472 857μs 3.95μs 15.8μs 8.12 2.44 0.406 53.25 KB
#5696 WriteAndFlushEnrichedTraces net6.0 557μs 1.05μs 4.07μs 0.546 0 0 41.6 KB
#5696 WriteAndFlushEnrichedTraces netcoreapp3.1 667μs 553ns 2.07μs 0.338 0 0 41.94 KB
#5696 WriteAndFlushEnrichedTraces net472 852μs 4.16μs 17.7μs 8.13 2.57 0.428 53.25 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 net6.0 1.08μs 0.37ns 1.43ns 0.0114 0 0 808 B
master ExecuteNonQuery netcoreapp3.1 1.54μs 0.462ns 1.79ns 0.0107 0 0 808 B
master ExecuteNonQuery net472 1.71μs 0.62ns 2.4ns 0.122 0 0 770 B
#5696 ExecuteNonQuery net6.0 1.04μs 0.626ns 2.34ns 0.0114 0 0 808 B
#5696 ExecuteNonQuery netcoreapp3.1 1.52μs 0.892ns 3.45ns 0.0106 0 0 808 B
#5696 ExecuteNonQuery net472 1.78μs 2.36ns 8.51ns 0.122 0 0 770 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 net6.0 1.16μs 0.366ns 1.32ns 0.014 0 0 976 B
master CallElasticsearch netcoreapp3.1 1.47μs 1.84ns 6.38ns 0.0133 0 0 976 B
master CallElasticsearch net472 2.51μs 1.77ns 6.86ns 0.157 0.00125 0 995 B
master CallElasticsearchAsync net6.0 1.3μs 0.553ns 2.07ns 0.0131 0 0 952 B
master CallElasticsearchAsync netcoreapp3.1 1.69μs 0.843ns 3.26ns 0.0136 0 0 1.02 KB
master CallElasticsearchAsync net472 2.68μs 2.42ns 9.37ns 0.167 0 0 1.05 KB
#5696 CallElasticsearch net6.0 1.13μs 1ns 3.75ns 0.0136 0 0 976 B
#5696 CallElasticsearch netcoreapp3.1 1.49μs 0.585ns 2.26ns 0.0134 0 0 976 B
#5696 CallElasticsearch net472 2.52μs 0.655ns 2.27ns 0.157 0 0 995 B
#5696 CallElasticsearchAsync net6.0 1.28μs 0.814ns 3.05ns 0.0135 0 0 952 B
#5696 CallElasticsearchAsync netcoreapp3.1 1.63μs 0.541ns 1.87ns 0.0139 0 0 1.02 KB
#5696 CallElasticsearchAsync net472 2.61μs 1.17ns 4.39ns 0.167 0.00131 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.28μs 5.39ns 21.6ns 0.0133 0 0 952 B
master ExecuteAsync netcoreapp3.1 1.56μs 1.44ns 5.57ns 0.0124 0 0 952 B
master ExecuteAsync net472 1.79μs 1.29ns 4.98ns 0.145 0.00089 0 915 B
#5696 ExecuteAsync net6.0 1.31μs 1.09ns 4.09ns 0.0137 0 0 952 B
#5696 ExecuteAsync netcoreapp3.1 1.58μs 1.11ns 4.01ns 0.0128 0 0 952 B
#5696 ExecuteAsync net472 1.75μs 0.804ns 3.11ns 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.11μs 1.83ns 6.85ns 0.0308 0 0 2.22 KB
master SendAsync netcoreapp3.1 5.18μs 12.4ns 47.9ns 0.0357 0 0 2.76 KB
master SendAsync net472 7.62μs 3.33ns 12.5ns 0.497 0 0 3.15 KB
#5696 SendAsync net6.0 4.24μs 1.6ns 5.98ns 0.0316 0 0 2.22 KB
#5696 SendAsync netcoreapp3.1 4.97μs 1.79ns 6.2ns 0.0372 0 0 2.76 KB
#5696 SendAsync net472 7.62μs 3.56ns 13.8ns 0.498 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.48μs 0.915ns 3.54ns 0.0226 0 0 1.64 KB
master EnrichedLog netcoreapp3.1 2.08μs 0.733ns 2.64ns 0.022 0 0 1.64 KB
master EnrichedLog net472 2.55μs 1.18ns 4.56ns 0.249 0 0 1.57 KB
#5696 EnrichedLog net6.0 1.52μs 0.593ns 2.22ns 0.0228 0 0 1.64 KB
#5696 EnrichedLog netcoreapp3.1 2.18μs 0.48ns 1.8ns 0.0218 0 0 1.64 KB
#5696 EnrichedLog net472 2.47μs 0.9ns 3.24ns 0.25 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 113μs 104ns 402ns 0.0564 0 0 4.28 KB
master EnrichedLog netcoreapp3.1 119μs 145ns 562ns 0.0593 0 0 4.28 KB
master EnrichedLog net472 147μs 222ns 861ns 0.659 0.22 0 4.46 KB
#5696 EnrichedLog net6.0 113μs 112ns 432ns 0.0564 0 0 4.28 KB
#5696 EnrichedLog netcoreapp3.1 117μs 110ns 426ns 0 0 0 4.28 KB
#5696 EnrichedLog net472 146μs 74.2ns 278ns 0.662 0.221 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.05μs 0.974ns 3.77ns 0.0304 0 0 2.2 KB
master EnrichedLog netcoreapp3.1 4.31μs 3.91ns 15.1ns 0.0296 0 0 2.2 KB
master EnrichedLog net472 4.95μs 1.65ns 6.37ns 0.32 0 0 2.02 KB
#5696 EnrichedLog net6.0 3.07μs 1.59ns 6.16ns 0.0307 0 0 2.2 KB
#5696 EnrichedLog netcoreapp3.1 4.08μs 1.37ns 4.93ns 0.0287 0 0 2.2 KB
#5696 EnrichedLog net472 4.91μs 1.94ns 7.52ns 0.318 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.28μs 0.636ns 2.46ns 0.0159 0 0 1.14 KB
master SendReceive netcoreapp3.1 1.66μs 1.02ns 3.94ns 0.0158 0 0 1.14 KB
master SendReceive net472 2.16μs 1.4ns 5.42ns 0.183 0 0 1.16 KB
#5696 SendReceive net6.0 1.28μs 0.69ns 2.67ns 0.0161 0 0 1.14 KB
#5696 SendReceive netcoreapp3.1 1.78μs 1.4ns 5.23ns 0.015 0 0 1.14 KB
#5696 SendReceive net472 2.05μs 1.36ns 5.27ns 0.184 0 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.78μs 1.34ns 5.03ns 0.0222 0 0 1.6 KB
master EnrichedLog netcoreapp3.1 3.88μs 1.6ns 6.18ns 0.0213 0 0 1.65 KB
master EnrichedLog net472 4.45μs 3.01ns 11.2ns 0.322 0 0 2.04 KB
#5696 EnrichedLog net6.0 2.75μs 0.988ns 3.7ns 0.022 0 0 1.6 KB
#5696 EnrichedLog netcoreapp3.1 3.8μs 1.76ns 6.8ns 0.0209 0 0 1.65 KB
#5696 EnrichedLog net472 4.5μs 4.02ns 15.6ns 0.323 0 0 2.04 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 net6.0 403ns 0.0954ns 0.37ns 0.00817 0 0 576 B
master StartFinishSpan netcoreapp3.1 660ns 0.242ns 0.937ns 0.00789 0 0 576 B
master StartFinishSpan net472 600ns 0.648ns 2.51ns 0.0917 0 0 578 B
master StartFinishScope net6.0 527ns 0.196ns 0.76ns 0.00978 0 0 696 B
master StartFinishScope netcoreapp3.1 666ns 0.611ns 2.37ns 0.00944 0 0 696 B
master StartFinishScope net472 853ns 0.267ns 1.03ns 0.104 0 0 658 B
#5696 StartFinishSpan net6.0 397ns 0.133ns 0.499ns 0.00817 0 0 576 B
#5696 StartFinishSpan netcoreapp3.1 620ns 0.555ns 2.15ns 0.00795 0 0 576 B
#5696 StartFinishSpan net472 579ns 0.912ns 3.53ns 0.0916 0 0 578 B
#5696 StartFinishScope net6.0 474ns 0.206ns 0.771ns 0.00979 0 0 696 B
#5696 StartFinishScope netcoreapp3.1 725ns 0.43ns 1.61ns 0.00943 0 0 696 B
#5696 StartFinishScope net472 873ns 0.583ns 2.26ns 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 661ns 0.365ns 1.41ns 0.00979 0 0 696 B
master RunOnMethodBegin netcoreapp3.1 953ns 4.08ns 15.8ns 0.00933 0 0 696 B
master RunOnMethodBegin net472 1.11μs 0.682ns 2.64ns 0.105 0 0 658 B
#5696 RunOnMethodBegin net6.0 641ns 0.286ns 1.11ns 0.00986 0 0 696 B
#5696 RunOnMethodBegin netcoreapp3.1 1μs 1.36ns 5.27ns 0.00951 0 0 696 B
#5696 RunOnMethodBegin net472 1.07μs 1.11ns 4.3ns 0.104 0 0 658 B

@andrewlock
Copy link
Member

andrewlock commented Jun 14, 2024

Throughput/Crank Report:zap:

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 (5696) (11.481M)   : 0, 11481051
    master (11.569M)   : 0, 11568891
    benchmarks/2.9.0 (11.449M)   : 0, 11448607

    section Automatic
    This PR (5696) (7.732M)   : 0, 7731714
    master (7.767M)   : 0, 7767254
    benchmarks/2.9.0 (8.083M)   : 0, 8082807

    section Trace stats
    master (8.118M)   : 0, 8117530

    section Manual
    This PR (5696) (9.929M)   : 0, 9929269
    master (10.019M)   : 0, 10019017

    section Manual + Automatic
    This PR (5696) (7.297M)   : 0, 7296546
    master (7.281M)   : 0, 7281374

    section Version Conflict
    master (6.636M)   : 0, 6636457

Loading
gantt
    title Throughput Linux arm64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (5696) (9.701M)   : 0, 9700696
    master (9.453M)   : 0, 9453044
    benchmarks/2.9.0 (9.581M)   : 0, 9580805

    section Automatic
    This PR (5696) (6.655M)   : 0, 6655388
    master (6.502M)   : 0, 6502006

    section Trace stats
    master (6.976M)   : 0, 6976118

    section Manual
    This PR (5696) (8.027M)   : 0, 8027254
    master (8.257M)   : 0, 8256510

    section Manual + Automatic
    This PR (5696) (6.050M)   : 0, 6049872
    master (6.094M)   : 0, 6093563

    section Version Conflict
    master (5.682M)   : 0, 5681946

Loading
gantt
    title Throughput Windows x64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (5696) (9.989M)   : 0, 9988727
    master (10.169M)   : 0, 10168829
    benchmarks/2.9.0 (10.102M)   : 0, 10101741

    section Automatic
    This PR (5696) (7.068M)   : 0, 7067735
    master (7.240M)   : 0, 7240499
    benchmarks/2.9.0 (7.401M)   : 0, 7400836

    section Trace stats
    master (7.595M)   : 0, 7594699

    section Manual
    This PR (5696) (8.781M)   : 0, 8781044
    master (9.108M)   : 0, 9107531

    section Manual + Automatic
    This PR (5696) (6.747M)   : 0, 6746539
    master (7.001M)   : 0, 7000903

    section Version Conflict
    master (6.374M)   : 0, 6373775

Loading

@kevingosse kevingosse marked this pull request as ready for review June 17, 2024 11:14
@kevingosse kevingosse requested review from a team as code owners June 17, 2024 11:14
Copy link
Member

@andrewlock andrewlock left a comment

Choose a reason for hiding this comment

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

:shipit:

@kevingosse kevingosse merged commit 39797c5 into master Jun 17, 2024
55 of 57 checks passed
@kevingosse kevingosse deleted the kevin/runtime_metrics_crash branch June 17, 2024 11:20
@github-actions github-actions bot added this to the vNext-v2 milestone Jun 17, 2024
@andrewlock andrewlock modified the milestones: vNext-v2, 2.53.1 Jun 17, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants