dd-trace-dotnet icon indicating copy to clipboard operation
dd-trace-dotnet copied to clipboard
verified publisher icon DataDog

[Profiler] prevent stacksampling loop from sampling if the app is crashing

Open gleocadie opened this issue 1 year ago • 4 comments

Summary of changes

Reason for change

Implementation details

Test coverage

Other details

gleocadie avatar Jun 27 '24 12:06 gleocadie

Datadog Report

Branch report: gleocadie/stop-stacksampling-profiler-if-app-is-crashing Commit report: b6d237e Test service: dd-trace-dotnet

:white_check_mark: 0 Failed, 343701 Passed, 1995 Skipped, 15h 15m 13.98s Total Time :hourglass: 1 Performance Regression

:hourglass: Performance Regressions vs Default Branch (1)

  • StartStopWithChild - Benchmarks.Trace.ActivityBenchmark 18.27µs (+1.92µs, +12%) - Details

datadog-ddstaging[bot] avatar Jun 27 '24 13:06 datadog-ddstaging[bot]

Execution-Time Benchmarks Report :stopwatch:

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 (5746) - mean (74ms)  : 63, 85
     .   : milestone, 74,
    master - mean (72ms)  : 63, 82
     .   : milestone, 72,

    section CallTarget+Inlining+NGEN
    This PR (5746) - mean (1,019ms)  : 998, 1040
     .   : milestone, 1019,
    master - mean (1,013ms)  : 991, 1035
     .   : milestone, 1013,


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

    section CallTarget+Inlining+NGEN
    This PR (5746) - mean (712ms)  : 686, 738
     .   : milestone, 712,
    master - mean (708ms)  : 685, 731
     .   : milestone, 708,


gantt
    title Execution time (ms) FakeDbCommand (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5746) - mean (92ms)  : 89, 95
     .   : milestone, 92,
    master - mean (93ms)  : 90, 97
     .   : milestone, 93,

    section CallTarget+Inlining+NGEN
    This PR (5746) - mean (668ms)  : 641, 696
     .   : milestone, 668,
    master - mean (658ms)  : 634, 682
     .   : milestone, 658,


gantt
    title Execution time (ms) HttpMessageHandler (.NET Framework 4.6.2) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5746) - mean (190ms)  : 187, 194
     .   : milestone, 190,
    master - mean (190ms)  : 187, 194
     .   : milestone, 190,

    section CallTarget+Inlining+NGEN
    This PR (5746) - mean (1,116ms)  : 1092, 1140
     .   : milestone, 1116,
    master - mean (1,108ms)  : 1088, 1128
     .   : milestone, 1108,


gantt
    title Execution time (ms) HttpMessageHandler (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5746) - mean (276ms)  : 272, 280
     .   : milestone, 276,
    master - mean (276ms)  : 272, 279
     .   : milestone, 276,

    section CallTarget+Inlining+NGEN
    This PR (5746) - mean (879ms)  : 847, 910
     .   : milestone, 879,
    master - mean (881ms)  : 860, 903
     .   : milestone, 881,


gantt
    title Execution time (ms) HttpMessageHandler (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5746) - mean (264ms)  : 261, 267
     .   : milestone, 264,
    master - mean (264ms)  : 260, 267
     .   : milestone, 264,

    section CallTarget+Inlining+NGEN
    This PR (5746) - mean (862ms)  : 838, 886
     .   : milestone, 862,
    master - mean (859ms)  : 837, 882
     .   : milestone, 859,

andrewlock avatar Jun 27 '24 13:06 andrewlock

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 (5746) (11.971M)   : 0, 11971308
    master (12.005M)   : 0, 12005408
    benchmarks/2.9.0 (11.959M)   : 0, 11959218

    section Automatic
    This PR (5746) (8.190M)   : 0, 8189594
    master (7.900M)   : 0, 7899864
    benchmarks/2.9.0 (8.424M)   : 0, 8423539

    section Trace stats
    master (8.325M)   : 0, 8324730

    section Manual
    This PR (5746) (10.295M)   : 0, 10294929
    master (10.145M)   : 0, 10144798

    section Manual + Automatic
    This PR (5746) (7.694M)   : 0, 7694338
    master (7.557M)   : 0, 7557199

    section Version Conflict
    master (6.751M)   : 0, 6751170


gantt
    title Throughput Linux arm64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (5746) (9.489M)   : 0, 9489433
    master (9.437M)   : 0, 9437489
    benchmarks/2.9.0 (9.647M)   : 0, 9646678

    section Automatic
    This PR (5746) (6.627M)   : 0, 6626675
    master (6.453M)   : 0, 6452908

    section Trace stats
    master (6.876M)   : 0, 6876442

    section Manual
    This PR (5746) (8.422M)   : 0, 8422226
    master (8.301M)   : 0, 8301349

    section Manual + Automatic
    This PR (5746) (6.211M)   : 0, 6210825
    master (6.254M)   : 0, 6253738

    section Version Conflict
    master (5.472M)   : 0, 5472406


gantt
    title Throughput Windows x64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (5746) (10.098M)   : 0, 10097916
    master (10.198M)   : 0, 10198493
    benchmarks/2.9.0 (10.154M)   : 0, 10153990

    section Automatic
    This PR (5746) (7.004M)   : 0, 7003561
    master (7.162M)   : 0, 7162091
    benchmarks/2.9.0 (7.563M)   : 0, 7562893

    section Trace stats
    master (7.487M)   : 0, 7487136

    section Manual
    This PR (5746) (8.847M)   : 0, 8846746
    master (8.988M)   : 0, 8988317

    section Manual + Automatic
    This PR (5746) (6.726M)   : 0, 6726440
    master (7.057M)   : 0, 7056634

    section Version Conflict
    master (6.243M)   : 0, 6243268

andrewlock avatar Jun 27 '24 13:06 andrewlock

Benchmarks Report for tracer :snail:

Benchmarks for #5746 compared to master:

  • 1 benchmarks are faster, with geometric mean 1.121
  • 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 :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartStopWithChild net6.0 7.8μs 44.1ns 292ns 0.0153 0.00763 0 5.42 KB
master StartStopWithChild netcoreapp3.1 10.2μs 56.6ns 339ns 0.0242 0.00968 0 5.62 KB
master StartStopWithChild net472 16.5μs 65.1ns 252ns 1.01 0.296 0.0821 6.07 KB
#5746 StartStopWithChild net6.0 7.62μs 43.6ns 315ns 0.0143 0.00717 0 5.43 KB
#5746 StartStopWithChild netcoreapp3.1 9.75μs 54.1ns 329ns 0.0143 0.00475 0 5.62 KB
#5746 StartStopWithChild net472 18.3μs 125ns 1.23μs 1.06 0.382 0.108 6.07 KB
Benchmarks.Trace.AgentWriterBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master WriteAndFlushEnrichedTraces net6.0 495μs 218ns 846ns 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 641μs 159ns 596ns 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces net472 820μs 205ns 795ns 0.408 0 0 3.3 KB
#5746 WriteAndFlushEnrichedTraces net6.0 462μs 193ns 748ns 0 0 0 2.7 KB
#5746 WriteAndFlushEnrichedTraces netcoreapp3.1 643μs 164ns 635ns 0 0 0 2.7 KB
#5746 WriteAndFlushEnrichedTraces net472 828μs 259ns 969ns 0.414 0 0 3.3 KB
Benchmarks.Trace.AspNetCoreBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendRequest net6.0 172μs 123ns 474ns 0.258 0 0 18.45 KB
master SendRequest netcoreapp3.1 189μs 213ns 824ns 0.189 0 0 20.61 KB
master SendRequest net472 0.000438ns 0.000248ns 0.00096ns 0 0 0 0 b
#5746 SendRequest net6.0 174μs 378ns 1.46μs 0.175 0 0 18.45 KB
#5746 SendRequest netcoreapp3.1 190μs 156ns 584ns 0.191 0 0 20.61 KB
#5746 SendRequest net472 0ns 0ns 0ns 0 0 0 0 b
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master WriteAndFlushEnrichedTraces net6.0 553μs 277ns 1.07μs 0.541 0 0 41.63 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 655μs 981ns 3.8μs 0.327 0 0 41.71 KB
master WriteAndFlushEnrichedTraces net472 836μs 4.08μs 16.3μs 8.08 2.55 0.425 53.23 KB
#5746 WriteAndFlushEnrichedTraces net6.0 552μs 415ns 1.49μs 0.553 0 0 41.72 KB
#5746 WriteAndFlushEnrichedTraces netcoreapp3.1 656μs 1.58μs 6.11μs 0.331 0 0 41.64 KB
#5746 WriteAndFlushEnrichedTraces net472 879μs 3.81μs 13.7μs 8.25 2.6 0.434 53.23 KB
Benchmarks.Trace.DbCommandBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master ExecuteNonQuery net6.0 1.19μs 0.592ns 2.29ns 0.0144 0 0 1.02 KB
master ExecuteNonQuery netcoreapp3.1 1.76μs 0.639ns 2.47ns 0.0132 0 0 1.02 KB
master ExecuteNonQuery net472 1.99μs 3.31ns 12.4ns 0.157 0 0 987 B
#5746 ExecuteNonQuery net6.0 1.26μs 0.428ns 1.54ns 0.0139 0 0 1.02 KB
#5746 ExecuteNonQuery netcoreapp3.1 1.72μs 2.73ns 10.6ns 0.0136 0 0 1.02 KB
#5746 ExecuteNonQuery net472 2.01μs 1.44ns 5.37ns 0.156 0 0 987 B
Benchmarks.Trace.ElasticsearchBenchmark - Faster :tada: Same allocations :heavy_check_mark:

Faster :tada: in #5746

Benchmark base/diff Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.ElasticsearchBenchmark.CallElasticsearchAsync‑net6.0 1.121 1,342.79 1,198.30

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master CallElasticsearch net6.0 1.3μs 6.71ns 37.9ns 0.0138 0 0 976 B
master CallElasticsearch netcoreapp3.1 1.58μs 2.33ns 9.01ns 0.0134 0 0 976 B
master CallElasticsearch net472 2.52μs 0.964ns 3.61ns 0.157 0 0 995 B
master CallElasticsearchAsync net6.0 1.34μs 0.738ns 2.86ns 0.0135 0 0 952 B
master CallElasticsearchAsync netcoreapp3.1 1.64μs 0.727ns 2.82ns 0.014 0 0 1.02 KB
master CallElasticsearchAsync net472 2.63μs 1.71ns 6.62ns 0.167 0 0 1.05 KB
#5746 CallElasticsearch net6.0 1.23μs 0.573ns 2.14ns 0.0136 0 0 976 B
#5746 CallElasticsearch netcoreapp3.1 1.54μs 0.879ns 3.29ns 0.0129 0 0 976 B
#5746 CallElasticsearch net472 2.49μs 1.05ns 4.06ns 0.157 0 0 995 B
#5746 CallElasticsearchAsync net6.0 1.2μs 1.03ns 3.99ns 0.0133 0 0 952 B
#5746 CallElasticsearchAsync netcoreapp3.1 1.64μs 0.851ns 3.19ns 0.0139 0 0 1.02 KB
#5746 CallElasticsearchAsync net472 2.56μs 1.91ns 7.13ns 0.167 0 0 1.05 KB
Benchmarks.Trace.GraphQLBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master ExecuteAsync net6.0 1.26μs 0.581ns 2.25ns 0.0134 0 0 952 B
master ExecuteAsync netcoreapp3.1 1.6μs 0.768ns 2.97ns 0.0128 0 0 952 B
master ExecuteAsync net472 1.75μs 1.4ns 5.04ns 0.145 0 0 915 B
#5746 ExecuteAsync net6.0 1.14μs 0.379ns 1.37ns 0.0131 0 0 952 B
#5746 ExecuteAsync netcoreapp3.1 1.66μs 1.42ns 5.31ns 0.0125 0 0 952 B
#5746 ExecuteAsync net472 1.85μs 0.822ns 3.07ns 0.145 0 0 915 B
Benchmarks.Trace.HttpClientBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendAsync net6.0 4.01μs 1ns 3.88ns 0.03 0 0 2.22 KB
master SendAsync netcoreapp3.1 5.04μs 2.26ns 8.77ns 0.0376 0 0 2.76 KB
master SendAsync net472 7.56μs 2.53ns 9.46ns 0.498 0 0 3.15 KB
#5746 SendAsync net6.0 4.13μs 1.68ns 6.28ns 0.0311 0 0 2.22 KB
#5746 SendAsync netcoreapp3.1 5.07μs 2.54ns 9.5ns 0.0355 0 0 2.76 KB
#5746 SendAsync net472 7.66μs 2.08ns 8.04ns 0.498 0 0 3.15 KB
Benchmarks.Trace.ILoggerBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net6.0 1.56μs 0.775ns 3ns 0.0232 0 0 1.64 KB
master EnrichedLog netcoreapp3.1 2.12μs 1.87ns 7.25ns 0.0222 0 0 1.64 KB
master EnrichedLog net472 2.5μs 1.71ns 6.4ns 0.249 0 0 1.57 KB
#5746 EnrichedLog net6.0 1.46μs 0.73ns 2.73ns 0.0227 0 0 1.64 KB
#5746 EnrichedLog netcoreapp3.1 2.04μs 0.673ns 2.52ns 0.0215 0 0 1.64 KB
#5746 EnrichedLog net472 2.48μs 1.72ns 6.65ns 0.249 0 0 1.57 KB
Benchmarks.Trace.Log4netBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net6.0 118μs 210ns 812ns 0.0576 0 0 4.28 KB
master EnrichedLog netcoreapp3.1 119μs 91.2ns 353ns 0 0 0 4.28 KB
master EnrichedLog net472 147μs 92.8ns 360ns 0.658 0.219 0 4.46 KB
#5746 EnrichedLog net6.0 114μs 82.9ns 321ns 0 0 0 4.28 KB
#5746 EnrichedLog netcoreapp3.1 119μs 188ns 727ns 0.0591 0 0 4.28 KB
#5746 EnrichedLog net472 147μs 73.8ns 276ns 0.659 0.22 0 4.46 KB
Benchmarks.Trace.NLogBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net6.0 3.07μs 1.48ns 5.73ns 0.0305 0 0 2.2 KB
master EnrichedLog netcoreapp3.1 4.28μs 1.23ns 4.61ns 0.0279 0 0 2.2 KB
master EnrichedLog net472 4.76μs 1.63ns 6.3ns 0.321 0 0 2.02 KB
#5746 EnrichedLog net6.0 2.94μs 0.974ns 3.64ns 0.0312 0 0 2.2 KB
#5746 EnrichedLog netcoreapp3.1 4.23μs 2.14ns 8.01ns 0.0297 0 0 2.2 KB
#5746 EnrichedLog net472 4.8μs 1.57ns 6.09ns 0.32 0 0 2.02 KB
Benchmarks.Trace.RedisBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendReceive net6.0 1.3μs 0.558ns 2.16ns 0.0162 0 0 1.14 KB
master SendReceive netcoreapp3.1 1.78μs 1.44ns 5.59ns 0.0153 0 0 1.14 KB
master SendReceive net472 2.1μs 1.13ns 4.37ns 0.183 0.00105 0 1.16 KB
#5746 SendReceive net6.0 1.38μs 0.437ns 1.58ns 0.0159 0 0 1.14 KB
#5746 SendReceive netcoreapp3.1 1.69μs 0.735ns 2.84ns 0.0154 0 0 1.14 KB
#5746 SendReceive net472 2.14μs 0.519ns 2.01ns 0.183 0.00105 0 1.16 KB
Benchmarks.Trace.SerilogBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net6.0 2.69μs 0.837ns 3.24ns 0.0223 0 0 1.6 KB
master EnrichedLog netcoreapp3.1 3.8μs 0.776ns 2.91ns 0.0209 0 0 1.65 KB
master EnrichedLog net472 4.39μs 0.944ns 3.53ns 0.322 0 0 2.04 KB
#5746 EnrichedLog net6.0 2.83μs 3.05ns 11.4ns 0.0224 0 0 1.6 KB
#5746 EnrichedLog netcoreapp3.1 3.87μs 3.13ns 12.1ns 0.0212 0 0 1.65 KB
#5746 EnrichedLog net472 4.35μs 2.32ns 8.97ns 0.322 0 0 2.04 KB
Benchmarks.Trace.SpanBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartFinishSpan net6.0 420ns 0.265ns 0.956ns 0.00806 0 0 576 B
master StartFinishSpan netcoreapp3.1 577ns 0.494ns 1.91ns 0.00768 0 0 576 B
master StartFinishSpan net472 613ns 0.641ns 2.48ns 0.0916 0 0 578 B
master StartFinishScope net6.0 533ns 0.145ns 0.541ns 0.00987 0 0 696 B
master StartFinishScope netcoreapp3.1 740ns 0.757ns 2.93ns 0.00949 0 0 696 B
master StartFinishScope net472 842ns 0.428ns 1.48ns 0.104 0 0 658 B
#5746 StartFinishSpan net6.0 415ns 0.535ns 2ns 0.00812 0 0 576 B
#5746 StartFinishSpan netcoreapp3.1 620ns 0.389ns 1.51ns 0.00773 0 0 576 B
#5746 StartFinishSpan net472 661ns 0.429ns 1.66ns 0.0916 0 0 578 B
#5746 StartFinishScope net6.0 552ns 0.273ns 1.02ns 0.00976 0 0 696 B
#5746 StartFinishScope netcoreapp3.1 744ns 1.62ns 6.26ns 0.00922 0 0 696 B
#5746 StartFinishScope net472 875ns 0.647ns 2.42ns 0.104 0 0 658 B
Benchmarks.Trace.TraceAnnotationsBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master RunOnMethodBegin net6.0 659ns 0.195ns 0.731ns 0.00995 0 0 696 B
master RunOnMethodBegin netcoreapp3.1 967ns 4.69ns 18.7ns 0.00948 0 0 696 B
master RunOnMethodBegin net472 1.16μs 0.364ns 1.41ns 0.104 0 0 658 B
#5746 RunOnMethodBegin net6.0 667ns 0.247ns 0.958ns 0.00976 0 0 696 B
#5746 RunOnMethodBegin netcoreapp3.1 904ns 0.333ns 1.29ns 0.00947 0 0 696 B
#5746 RunOnMethodBegin net472 1.09μs 0.452ns 1.69ns 0.104 0 0 658 B

andrewlock avatar Jun 27 '24 14:06 andrewlock