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

[ASM] Fix DefaultInterpolatedStringHandler implicit flaky tests

Open e-n-0 opened this issue 11 months ago • 3 comments

Summary of changes

Reason for change

Implementation details

Test coverage

Other details

e-n-0 avatar Jan 13 '25 15:01 e-n-0

Datadog Report

Branch report: flavien/asm/iast/try-fix-interpolatedstring-flaky Commit report: f4854a0 Test service: dd-trace-dotnet

:white_check_mark: 0 Failed, 256788 Passed, 2041 Skipped, 22h 14m 6.96s Total Time

datadog-ddstaging[bot] avatar Jan 13 '25 15:01 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 (6540) - mean (68ms)  : 66, 70
     .   : milestone, 68,
    master - mean (68ms)  : 66, 71
     .   : milestone, 68,

    section CallTarget+Inlining+NGEN
    This PR (6540) - mean (977ms)  : 951, 1003
     .   : milestone, 977,
    master - mean (979ms)  : 948, 1010
     .   : milestone, 979,


gantt
    title Execution time (ms) FakeDbCommand (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6540) - mean (107ms)  : 104, 109
     .   : milestone, 107,
    master - mean (107ms)  : 105, 109
     .   : milestone, 107,

    section CallTarget+Inlining+NGEN
    This PR (6540) - mean (675ms)  : 659, 690
     .   : milestone, 675,
    master - mean (678ms)  : 664, 693
     .   : milestone, 678,


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

    section CallTarget+Inlining+NGEN
    This PR (6540) - mean (627ms)  : 615, 640
     .   : milestone, 627,
    master - mean (635ms)  : 620, 649
     .   : milestone, 635,


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

    section CallTarget+Inlining+NGEN
    This PR (6540) - mean (1,100ms)  : 1070, 1130
     .   : milestone, 1100,
    master - mean (1,103ms)  : 1066, 1140
     .   : milestone, 1103,


gantt
    title Execution time (ms) HttpMessageHandler (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6540) - mean (280ms)  : 275, 284
     .   : milestone, 280,
    master - mean (277ms)  : 274, 281
     .   : milestone, 277,

    section CallTarget+Inlining+NGEN
    This PR (6540) - mean (871ms)  : 843, 899
     .   : milestone, 871,
    master - mean (870ms)  : 843, 897
     .   : milestone, 870,


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

    section CallTarget+Inlining+NGEN
    This PR (6540) - mean (848ms)  : 817, 878
     .   : milestone, 848,
    master - mean (852ms)  : 825, 878
     .   : milestone, 852,

andrewlock avatar Jan 13 '25 16:01 andrewlock

Benchmarks Report for tracer :snail:

Benchmarks for #6540 compared to master:

  • 1 benchmarks are faster, with geometric mean 1.113
  • 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 8.3μs 48.2ns 449ns 0.0137 0.00686 0 5.61 KB
master StartStopWithChild netcoreapp3.1 10.2μs 57ns 369ns 0.0205 0.0102 0 5.8 KB
master StartStopWithChild net472 16.2μs 40.1ns 155ns 1.05 0.306 0.0965 6.2 KB
#6540 StartStopWithChild net6.0 7.98μs 43.7ns 262ns 0.012 0.00399 0 5.61 KB
#6540 StartStopWithChild netcoreapp3.1 10.3μs 58.2ns 399ns 0.0206 0.0103 0 5.81 KB
#6540 StartStopWithChild net472 16.6μs 50.9ns 197ns 1.03 0.3 0.0833 6.21 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 501μs 243ns 940ns 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 669μs 684ns 2.56μs 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces net472 857μs 919ns 3.56μs 0.422 0 0 3.3 KB
#6540 WriteAndFlushEnrichedTraces net6.0 487μs 289ns 1.08μs 0 0 0 2.7 KB
#6540 WriteAndFlushEnrichedTraces netcoreapp3.1 660μs 699ns 2.42μs 0 0 0 2.7 KB
#6540 WriteAndFlushEnrichedTraces net472 851μs 503ns 1.95μ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 164μs 1.34μs 13.3μs 0.145 0 0 14.48 KB
master SendRequest netcoreapp3.1 182μs 1.19μs 11.7μs 0.179 0 0 17.27 KB
master SendRequest net472 0.00798ns 0.00243ns 0.00908ns 0 0 0 0 b
#6540 SendRequest net6.0 155μs 1μs 9.87μs 0.155 0 0 14.47 KB
#6540 SendRequest netcoreapp3.1 172μs 1μs 9.65μs 0.163 0 0 17.27 KB
#6540 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 610μs 3.3μs 29.5μs 0.581 0 0 41.78 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 728μs 5.77μs 57.4μs 0.332 0 0 41.74 KB
master WriteAndFlushEnrichedTraces net472 874μs 3.54μs 13.2μs 8.08 2.55 0.425 53.34 KB
#6540 WriteAndFlushEnrichedTraces net6.0 568μs 2.99μs 17.7μs 0.548 0 0 41.65 KB
#6540 WriteAndFlushEnrichedTraces netcoreapp3.1 676μs 3.59μs 19.4μs 0.329 0 0 41.88 KB
#6540 WriteAndFlushEnrichedTraces net472 834μs 4.25μs 18.5μs 8.22 2.47 0.411 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.31μs 1.55ns 5.99ns 0.0144 0 0 1.02 KB
master ExecuteNonQuery netcoreapp3.1 1.79μs 1.04ns 3.89ns 0.0133 0 0 1.02 KB
master ExecuteNonQuery net472 2.04μs 1.89ns 6.83ns 0.157 0.00102 0 987 B
#6540 ExecuteNonQuery net6.0 1.26μs 1.62ns 6.28ns 0.0145 0 0 1.02 KB
#6540 ExecuteNonQuery netcoreapp3.1 1.79μs 1.88ns 7.26ns 0.0134 0 0 1.02 KB
#6540 ExecuteNonQuery net472 2.14μs 2.8ns 10.9ns 0.157 0.00107 0 987 B
Benchmarks.Trace.ElasticsearchBenchmark - 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 CallElasticsearch net6.0 1.26μs 0.915ns 3.43ns 0.0133 0 0 976 B
master CallElasticsearch netcoreapp3.1 1.63μs 0.725ns 2.71ns 0.013 0 0 976 B
master CallElasticsearch net472 2.64μs 3.75ns 14.5ns 0.158 0 0 995 B
master CallElasticsearchAsync net6.0 1.34μs 0.935ns 3.62ns 0.0134 0 0 952 B
master CallElasticsearchAsync netcoreapp3.1 1.64μs 0.983ns 3.55ns 0.0135 0 0 1.02 KB
master CallElasticsearchAsync net472 2.68μs 3.01ns 11.7ns 0.167 0 0 1.05 KB
#6540 CallElasticsearch net6.0 1.25μs 0.67ns 2.59ns 0.0138 0 0 976 B
#6540 CallElasticsearch netcoreapp3.1 1.6μs 1.1ns 4.13ns 0.0128 0 0 976 B
#6540 CallElasticsearch net472 2.5μs 2.41ns 9.32ns 0.158 0 0 995 B
#6540 CallElasticsearchAsync net6.0 1.22μs 0.813ns 2.82ns 0.0133 0 0 952 B
#6540 CallElasticsearchAsync netcoreapp3.1 1.66μs 3.36ns 13ns 0.0138 0 0 1.02 KB
#6540 CallElasticsearchAsync net472 2.7μs 1.6ns 6.2ns 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.3μs 1.03ns 3.85ns 0.0131 0 0 952 B
master ExecuteAsync netcoreapp3.1 1.56μs 1.28ns 4.62ns 0.0125 0 0 952 B
master ExecuteAsync net472 1.85μs 0.853ns 3.19ns 0.145 0 0 915 B
#6540 ExecuteAsync net6.0 1.33μs 0.523ns 1.96ns 0.0134 0 0 952 B
#6540 ExecuteAsync netcoreapp3.1 1.61μs 0.365ns 1.37ns 0.0127 0 0 952 B
#6540 ExecuteAsync net472 1.78μs 0.473ns 1.83ns 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.28μs 1.45ns 5.41ns 0.0323 0 0 2.31 KB
master SendAsync netcoreapp3.1 5.25μs 0.952ns 3.69ns 0.0368 0 0 2.85 KB
master SendAsync net472 7.29μs 2.21ns 8.27ns 0.495 0 0 3.12 KB
#6540 SendAsync net6.0 4.38μs 1.25ns 4.85ns 0.0308 0 0 2.31 KB
#6540 SendAsync netcoreapp3.1 5.35μs 1.93ns 7.47ns 0.0374 0 0 2.85 KB
#6540 SendAsync net472 7.53μs 2.44ns 9.14ns 0.496 0 0 3.12 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.52μs 0.698ns 2.7ns 0.0228 0 0 1.64 KB
master EnrichedLog netcoreapp3.1 2.28μs 1.05ns 3.93ns 0.0216 0 0 1.64 KB
master EnrichedLog net472 2.73μs 2.24ns 8.37ns 0.249 0 0 1.57 KB
#6540 EnrichedLog net6.0 1.45μs 1.01ns 3.51ns 0.0232 0 0 1.64 KB
#6540 EnrichedLog netcoreapp3.1 2.26μs 6.55ns 25.4ns 0.022 0 0 1.64 KB
#6540 EnrichedLog net472 2.6μs 1.63ns 5.64ns 0.25 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 119μs 180ns 699ns 0.0585 0 0 4.28 KB
master EnrichedLog netcoreapp3.1 120μs 132ns 510ns 0 0 0 4.28 KB
master EnrichedLog net472 151μs 167ns 645ns 0.68 0.227 0 4.46 KB
#6540 EnrichedLog net6.0 117μs 392ns 1.52μs 0.0581 0 0 4.28 KB
#6540 EnrichedLog netcoreapp3.1 121μs 216ns 837ns 0.0596 0 0 4.28 KB
#6540 EnrichedLog net472 149μs 208ns 806ns 0.67 0.223 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 2.9μs 0.932ns 3.61ns 0.0306 0 0 2.2 KB
master EnrichedLog netcoreapp3.1 4.25μs 2.47ns 9.57ns 0.0297 0 0 2.2 KB
master EnrichedLog net472 4.99μs 1.77ns 6.86ns 0.319 0 0 2.02 KB
#6540 EnrichedLog net6.0 3.01μs 1.5ns 5.79ns 0.0308 0 0 2.2 KB
#6540 EnrichedLog netcoreapp3.1 4.21μs 1.14ns 4.28ns 0.0294 0 0 2.2 KB
#6540 EnrichedLog net472 4.91μs 1.16ns 4.48ns 0.321 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.38μs 1.35ns 5.03ns 0.0161 0 0 1.14 KB
master SendReceive netcoreapp3.1 1.76μs 0.909ns 3.52ns 0.015 0 0 1.14 KB
master SendReceive net472 2.06μs 1.62ns 6.29ns 0.183 0 0 1.16 KB
#6540 SendReceive net6.0 1.42μs 0.964ns 3.73ns 0.0156 0 0 1.14 KB
#6540 SendReceive netcoreapp3.1 1.82μs 6.61ns 25.6ns 0.0155 0 0 1.14 KB
#6540 SendReceive net472 2.16μs 1.31ns 5.07ns 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.65μs 0.845ns 3.16ns 0.0225 0 0 1.6 KB
master EnrichedLog netcoreapp3.1 3.9μs 1.33ns 5.15ns 0.0215 0 0 1.65 KB
master EnrichedLog net472 4.36μs 4.27ns 16ns 0.323 0 0 2.04 KB
#6540 EnrichedLog net6.0 2.76μs 0.783ns 3.03ns 0.0227 0 0 1.6 KB
#6540 EnrichedLog netcoreapp3.1 4μs 2.15ns 8.34ns 0.022 0 0 1.65 KB
#6540 EnrichedLog net472 4.34μs 3.53ns 13.2ns 0.322 0 0 2.04 KB
Benchmarks.Trace.SpanBenchmark - Faster :tada: Same allocations :heavy_check_mark:

Faster :tada: in #6540

Benchmark base/diff Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.SpanBenchmark.StartFinishSpan‑net472 1.113 712.20 639.60

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartFinishSpan net6.0 396ns 0.259ns 1ns 0.00804 0 0 576 B
master StartFinishSpan netcoreapp3.1 621ns 1.21ns 4.7ns 0.00773 0 0 576 B
master StartFinishSpan net472 712ns 0.333ns 1.29ns 0.0916 0 0 578 B
master StartFinishScope net6.0 466ns 0.212ns 0.766ns 0.00978 0 0 696 B
master StartFinishScope netcoreapp3.1 718ns 2.25ns 8.73ns 0.0094 0 0 696 B
master StartFinishScope net472 817ns 0.954ns 3.7ns 0.104 0 0 658 B
#6540 StartFinishSpan net6.0 401ns 0.274ns 1.06ns 0.00806 0 0 576 B
#6540 StartFinishSpan netcoreapp3.1 624ns 0.269ns 0.97ns 0.00781 0 0 576 B
#6540 StartFinishSpan net472 639ns 0.38ns 1.42ns 0.0917 0 0 578 B
#6540 StartFinishScope net6.0 494ns 0.281ns 1.09ns 0.00968 0 0 696 B
#6540 StartFinishScope netcoreapp3.1 780ns 0.408ns 1.58ns 0.00938 0 0 696 B
#6540 StartFinishScope net472 908ns 0.442ns 1.71ns 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 609ns 0.354ns 1.37ns 0.00974 0 0 696 B
master RunOnMethodBegin netcoreapp3.1 970ns 0.624ns 2.34ns 0.00962 0 0 696 B
master RunOnMethodBegin net472 1.12μs 0.636ns 2.46ns 0.104 0 0 658 B
#6540 RunOnMethodBegin net6.0 637ns 0.945ns 3.66ns 0.00961 0 0 696 B
#6540 RunOnMethodBegin netcoreapp3.1 925ns 0.469ns 1.75ns 0.00939 0 0 696 B
#6540 RunOnMethodBegin net472 1.14μs 0.672ns 2.6ns 0.105 0 0 658 B

andrewlock avatar Jan 14 '25 14:01 andrewlock