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

[SSI] Bail out on known-faulty .NET 6 version

Open andrewlock opened this issue 1 year ago • 4 comments

Summary of changes

  • Bails out of SSI by default on .NET 6 < 6.0.12
  • Tweak log message to write correct reason for the bail out

Reason for change

There's a known crashing bug in early versions of .NET 6: https://github.com/dotnet/runtime/pull/78670

We want to bail out of these cases by default in SSI. (Other major versions are unaffected we believe)

Implementation details

Check if we're in .NET 6 and build version is < 13, if so, bail out by default.

Test coverage

Manually tested locally to confirm we bail out in SSI if we're running 6.0.12, but not otherwise

Other details

andrewlock avatar Jul 02 '24 10:07 andrewlock

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 (5761) - mean (76ms)  : 66, 87
     .   : milestone, 76,
    master - mean (75ms)  : 64, 87
     .   : milestone, 75,

    section CallTarget+Inlining+NGEN
    This PR (5761) - mean (1,045ms)  : 1026, 1064
     .   : milestone, 1045,
    master - mean (1,048ms)  : 1030, 1067
     .   : milestone, 1048,


gantt
    title Execution time (ms) FakeDbCommand (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5761) - mean (111ms)  : 108, 114
     .   : milestone, 111,
    master - mean (112ms)  : 108, 116
     .   : milestone, 112,

    section CallTarget+Inlining+NGEN
    This PR (5761) - mean (734ms)  : 712, 755
     .   : milestone, 734,
    master - mean (735ms)  : 713, 756
     .   : milestone, 735,


gantt
    title Execution time (ms) FakeDbCommand (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5761) - mean (94ms)  : 91, 97
     .   : milestone, 94,
    master - mean (95ms)  : 92, 98
     .   : milestone, 95,

    section CallTarget+Inlining+NGEN
    This PR (5761) - mean (686ms)  : 666, 707
     .   : milestone, 686,
    master - mean (688ms)  : 661, 716
     .   : milestone, 688,


gantt
    title Execution time (ms) HttpMessageHandler (.NET Framework 4.6.2) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5761) - mean (193ms)  : 189, 197
     .   : milestone, 193,
    master - mean (192ms)  : 187, 196
     .   : milestone, 192,

    section CallTarget+Inlining+NGEN
    This PR (5761) - mean (1,156ms)  : 1126, 1185
     .   : milestone, 1156,
    master - mean (1,160ms)  : 1140, 1180
     .   : milestone, 1160,


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

    section CallTarget+Inlining+NGEN
    This PR (5761) - mean (938ms)  : 916, 961
     .   : milestone, 938,
    master - mean (949ms)  : 930, 967
     .   : milestone, 949,


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

    section CallTarget+Inlining+NGEN
    This PR (5761) - mean (919ms)  : 886, 953
     .   : milestone, 919,
    master - mean (922ms)  : 902, 941
     .   : milestone, 922,

andrewlock avatar Jul 02 '24 11:07 andrewlock

Datadog Report

Branch report: andrew/single-step/bail-out-in-early-net6 Commit report: ffcc470 Test service: dd-trace-dotnet

:white_check_mark: 0 Failed, 346790 Passed, 2052 Skipped, 15h 23m 12.92s Total Time

datadog-ddstaging[bot] avatar Jul 02 '24 11:07 datadog-ddstaging[bot]

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 (5761) (11.583M)   : 0, 11582891
    master (11.579M)   : 0, 11579356
    benchmarks/2.9.0 (11.793M)   : 0, 11792634

    section Automatic
    This PR (5761) (7.833M)   : 0, 7832965
    master (7.775M)   : 0, 7774636
    benchmarks/2.9.0 (8.209M)   : 0, 8209122

    section Trace stats
    master (8.206M)   : 0, 8205782

    section Manual
    This PR (5761) (10.006M)   : 0, 10005562
    master (10.090M)   : 0, 10090249

    section Manual + Automatic
    This PR (5761) (7.348M)   : 0, 7347672
    master (7.416M)   : 0, 7415620

    section Version Conflict
    master (6.677M)   : 0, 6676535


gantt
    title Throughput Linux arm64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (5761) (9.523M)   : 0, 9523192

    section Automatic
    This PR (5761) (6.568M)   : 0, 6567793

    section Manual
    This PR (5761) (7.969M)   : 0, 7968674

    section Manual + Automatic
    This PR (5761) (6.075M)   : 0, 6075471


gantt
    title Throughput Windows x64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (5761) (10.279M)   : 0, 10279308
    master (10.110M)   : 0, 10109641
    benchmarks/2.9.0 (10.296M)   : 0, 10295769

    section Automatic
    This PR (5761) (7.247M)   : 0, 7246767
    master (7.224M)   : 0, 7223553
    benchmarks/2.9.0 (7.267M)   : 0, 7266503

    section Trace stats
    master (7.632M)   : 0, 7631517

    section Manual
    This PR (5761) (9.056M)   : 0, 9055705
    master (8.931M)   : 0, 8930758

    section Manual + Automatic
    This PR (5761) (6.983M)   : 0, 6982838
    master (6.943M)   : 0, 6943118

    section Version Conflict
    master (6.220M)   : 0, 6220018

andrewlock avatar Jul 02 '24 11:07 andrewlock

Benchmarks Report for tracer :snail:

Benchmarks for #5761 compared to master:

  • 1 benchmarks are faster, with geometric mean 1.125
  • 3 benchmarks are slower, with geometric mean 1.177
  • 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.59μs 42.9ns 300ns 0.0155 0.00775 0 5.43 KB
master StartStopWithChild netcoreapp3.1 9.66μs 50.7ns 243ns 0.019 0.00476 0 5.62 KB
master StartStopWithChild net472 16μs 58.1ns 225ns 1.03 0.321 0.094 6.08 KB
#5761 StartStopWithChild net6.0 7.63μs 35.1ns 131ns 0.0146 0.00728 0 5.42 KB
#5761 StartStopWithChild netcoreapp3.1 9.77μs 54.2ns 351ns 0.0146 0.00485 0 5.62 KB
#5761 StartStopWithChild net472 16μs 40.2ns 156ns 1.03 0.307 0.105 6.08 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 473μs 300ns 1.16μs 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 645μs 241ns 902ns 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces net472 833μs 599ns 2.32μs 0.419 0 0 3.3 KB
#5761 WriteAndFlushEnrichedTraces net6.0 479μs 137ns 530ns 0 0 0 2.7 KB
#5761 WriteAndFlushEnrichedTraces netcoreapp3.1 634μs 181ns 700ns 0 0 0 2.7 KB
#5761 WriteAndFlushEnrichedTraces net472 846μs 618ns 2.39μs 0.422 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 173μs 260ns 1.01μs 0.261 0 0 18.45 KB
master SendRequest netcoreapp3.1 192μs 355ns 1.37μs 0.193 0 0 20.61 KB
master SendRequest net472 0.00151ns 0.000154ns 0.000576ns 0 0 0 0 b
#5761 SendRequest net6.0 169μs 189ns 733ns 0.253 0 0 18.45 KB
#5761 SendRequest netcoreapp3.1 191μs 329ns 1.27μs 0.189 0 0 20.61 KB
#5761 SendRequest net472 6.96E‑05ns 6.96E‑05ns 0.000251ns 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 560μs 238ns 922ns 0.563 0 0 41.69 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 666μs 1.33μs 5.13μs 0.336 0 0 41.76 KB
master WriteAndFlushEnrichedTraces net472 836μs 2.08μs 7.79μs 8.28 2.48 0.414 53.24 KB
#5761 WriteAndFlushEnrichedTraces net6.0 542μs 1.44μs 5.58μs 0.546 0 0 41.62 KB
#5761 WriteAndFlushEnrichedTraces netcoreapp3.1 657μs 1.22μs 4.72μs 0.329 0 0 41.86 KB
#5761 WriteAndFlushEnrichedTraces net472 846μs 4.25μs 18.5μs 8.08 2.55 0.425 53.25 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.16μs 0.356ns 1.38ns 0.0144 0 0 1.02 KB
master ExecuteNonQuery netcoreapp3.1 1.65μs 0.901ns 3.49ns 0.0132 0 0 1.02 KB
master ExecuteNonQuery net472 1.96μs 0.471ns 1.76ns 0.157 0 0 987 B
#5761 ExecuteNonQuery net6.0 1.21μs 2.24ns 8.69ns 0.0142 0 0 1.02 KB
#5761 ExecuteNonQuery netcoreapp3.1 1.67μs 0.439ns 1.64ns 0.0134 0 0 1.02 KB
#5761 ExecuteNonQuery net472 1.94μs 1.05ns 3.93ns 0.157 0 0 987 B
Benchmarks.Trace.ElasticsearchBenchmark - Slower :warning: Same allocations :heavy_check_mark:

Slower :warning: in #5761

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.ElasticsearchBenchmark.CallElasticsearch‑net6.0 1.298 1,099.54 1,427.43 several?

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master CallElasticsearch net6.0 1.1μs 0.326ns 1.26ns 0.0138 0 0 976 B
master CallElasticsearch netcoreapp3.1 1.53μs 0.711ns 2.66ns 0.0129 0 0 976 B
master CallElasticsearch net472 2.54μs 0.929ns 3.48ns 0.157 0 0 995 B
master CallElasticsearchAsync net6.0 1.25μs 0.999ns 3.74ns 0.0131 0 0 952 B
master CallElasticsearchAsync netcoreapp3.1 1.63μs 0.691ns 2.68ns 0.0131 0 0 1.02 KB
master CallElasticsearchAsync net472 2.67μs 1.16ns 4.51ns 0.167 0 0 1.05 KB
#5761 CallElasticsearch net6.0 1.43μs 19.1ns 189ns 0.0136 0 0 976 B
#5761 CallElasticsearch netcoreapp3.1 1.48μs 0.803ns 3.11ns 0.0133 0 0 976 B
#5761 CallElasticsearch net472 2.47μs 1.55ns 6.01ns 0.157 0 0 995 B
#5761 CallElasticsearchAsync net6.0 1.23μs 0.673ns 2.52ns 0.013 0 0 952 B
#5761 CallElasticsearchAsync netcoreapp3.1 1.6μs 0.911ns 3.53ns 0.0136 0 0 1.02 KB
#5761 CallElasticsearchAsync net472 2.56μs 2.16ns 8.38ns 0.166 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.37μs 0.692ns 2.49ns 0.0131 0 0 952 B
master ExecuteAsync netcoreapp3.1 1.56μs 1ns 3.6ns 0.0126 0 0 952 B
master ExecuteAsync net472 1.83μs 0.835ns 3.12ns 0.145 0 0 915 B
#5761 ExecuteAsync net6.0 1.27μs 0.453ns 1.75ns 0.0134 0 0 952 B
#5761 ExecuteAsync netcoreapp3.1 1.6μs 1.46ns 5.48ns 0.0127 0 0 952 B
#5761 ExecuteAsync net472 1.8μs 0.904ns 3.5ns 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.17μs 1.36ns 5.08ns 0.0311 0 0 2.22 KB
master SendAsync netcoreapp3.1 5.11μs 2.17ns 8.39ns 0.0356 0 0 2.76 KB
master SendAsync net472 7.9μs 1.23ns 4.75ns 0.496 0 0 3.15 KB
#5761 SendAsync net6.0 4.34μs 1.84ns 7.13ns 0.0301 0 0 2.22 KB
#5761 SendAsync netcoreapp3.1 5.06μs 1.27ns 4.74ns 0.0379 0 0 2.76 KB
#5761 SendAsync net472 7.83μs 3.14ns 12.1ns 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.42μs 0.433ns 1.56ns 0.0228 0 0 1.64 KB
master EnrichedLog netcoreapp3.1 2.26μs 0.907ns 3.4ns 0.0214 0 0 1.64 KB
master EnrichedLog net472 2.5μs 2.17ns 8.39ns 0.249 0 0 1.57 KB
#5761 EnrichedLog net6.0 1.47μs 0.65ns 2.52ns 0.0229 0 0 1.64 KB
#5761 EnrichedLog netcoreapp3.1 2.24μs 0.779ns 2.81ns 0.0214 0 0 1.64 KB
#5761 EnrichedLog net472 2.7μs 1.68ns 6.3ns 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 116μs 240ns 930ns 0.0578 0 0 4.28 KB
master EnrichedLog netcoreapp3.1 120μs 233ns 903ns 0 0 0 4.28 KB
master EnrichedLog net472 149μs 223ns 866ns 0.677 0.226 0 4.46 KB
#5761 EnrichedLog net6.0 114μs 147ns 568ns 0 0 0 4.28 KB
#5761 EnrichedLog netcoreapp3.1 118μs 200ns 773ns 0 0 0 4.28 KB
#5761 EnrichedLog net472 149μs 138ns 536ns 0.665 0.222 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.18μs 1.21ns 4.69ns 0.0302 0 0 2.2 KB
master EnrichedLog netcoreapp3.1 4.11μs 1.88ns 7.27ns 0.0296 0 0 2.2 KB
master EnrichedLog net472 4.98μs 1.39ns 5.4ns 0.319 0 0 2.02 KB
#5761 EnrichedLog net6.0 3.21μs 7.78ns 30.1ns 0.0303 0 0 2.2 KB
#5761 EnrichedLog netcoreapp3.1 4.13μs 1.66ns 6.44ns 0.0289 0 0 2.2 KB
#5761 EnrichedLog net472 4.88μs 0.546ns 2.04ns 0.32 0 0 2.02 KB
Benchmarks.Trace.RedisBenchmark - Slower :warning: Same allocations :heavy_check_mark:

Slower :warning: in #5761

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.RedisBenchmark.SendReceive‑net6.0 1.122 1,265.16 1,419.08

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendReceive net6.0 1.27μs 0.478ns 1.79ns 0.0164 0 0 1.14 KB
master SendReceive netcoreapp3.1 1.73μs 0.663ns 2.48ns 0.0156 0 0 1.14 KB
master SendReceive net472 2.11μs 1.39ns 5.22ns 0.183 0 0 1.16 KB
#5761 SendReceive net6.0 1.42μs 0.555ns 2.15ns 0.0162 0 0 1.14 KB
#5761 SendReceive netcoreapp3.1 1.7μs 1.3ns 5.05ns 0.0152 0 0 1.14 KB
#5761 SendReceive net472 2.15μs 1.3ns 5.05ns 0.183 0 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.7μs 0.658ns 2.28ns 0.0217 0 0 1.6 KB
master EnrichedLog netcoreapp3.1 3.78μs 0.902ns 3.49ns 0.0208 0 0 1.65 KB
master EnrichedLog net472 4.27μs 2.28ns 8.54ns 0.323 0 0 2.04 KB
#5761 EnrichedLog net6.0 2.88μs 1.14ns 4.43ns 0.0217 0 0 1.6 KB
#5761 EnrichedLog netcoreapp3.1 3.76μs 1.03ns 3.85ns 0.0226 0 0 1.65 KB
#5761 EnrichedLog net472 4.37μs 3.43ns 13.3ns 0.322 0 0 2.04 KB
Benchmarks.Trace.SpanBenchmark - Slower :warning: Same allocations :heavy_check_mark:

Slower :warning: in #5761

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.SpanBenchmark.StartFinishSpan‑netcoreapp3.1 1.120 547.69 613.48

Faster :tada: in #5761

Benchmark base/diff Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.SpanBenchmark.StartFinishSpan‑net472 1.125 712.55 633.40

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartFinishSpan net6.0 393ns 0.0869ns 0.325ns 0.00799 0 0 576 B
master StartFinishSpan netcoreapp3.1 548ns 0.131ns 0.472ns 0.00775 0 0 576 B
master StartFinishSpan net472 713ns 0.868ns 3.36ns 0.0915 0 0 578 B
master StartFinishScope net6.0 478ns 0.119ns 0.462ns 0.00982 0 0 696 B
master StartFinishScope netcoreapp3.1 698ns 0.676ns 2.44ns 0.00963 0 0 696 B
master StartFinishScope net472 875ns 0.381ns 1.48ns 0.104 0 0 658 B
#5761 StartFinishSpan net6.0 391ns 0.105ns 0.377ns 0.0081 0 0 576 B
#5761 StartFinishSpan netcoreapp3.1 613ns 0.33ns 1.14ns 0.00767 0 0 576 B
#5761 StartFinishSpan net472 633ns 0.227ns 0.817ns 0.0918 0 0 578 B
#5761 StartFinishScope net6.0 471ns 0.256ns 0.992ns 0.00966 0 0 696 B
#5761 StartFinishScope netcoreapp3.1 736ns 0.255ns 0.956ns 0.00914 0 0 696 B
#5761 StartFinishScope net472 897ns 0.504ns 1.95ns 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 652ns 0.244ns 0.945ns 0.0098 0 0 696 B
master RunOnMethodBegin netcoreapp3.1 864ns 0.517ns 1.93ns 0.00924 0 0 696 B
master RunOnMethodBegin net472 1.06μs 0.552ns 2.14ns 0.104 0 0 658 B
#5761 RunOnMethodBegin net6.0 606ns 0.179ns 0.67ns 0.00974 0 0 696 B
#5761 RunOnMethodBegin netcoreapp3.1 918ns 1.18ns 4.58ns 0.00967 0 0 696 B
#5761 RunOnMethodBegin net472 1.14μs 0.258ns 0.966ns 0.104 0 0 658 B

andrewlock avatar Jul 02 '24 15:07 andrewlock