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

init macro benchmarks

Open faydef opened this issue 1 year ago • 3 comments

Summary of changes

Adds macrobenchmarks

Reason for change

Being able to compare impact of commits on main

Implementation details

https://datadoghq.atlassian.net/wiki/spaces/APMINT/pages/2680356865/How+to+use+Benchmarking+Platform

Test coverage

Other details

faydef avatar Aug 14 '24 12:08 faydef

Datadog Report

Branch report: fayssal/add-macrobenchmarks Commit report: 505f85e Test service: dd-trace-dotnet

:white_check_mark: 0 Failed, 342409 Passed, 1769 Skipped, 14h 48m 36.27s Total Time :hourglass: 7 Performance Regressions

:hourglass: Performance Regressions vs Default Branch (7)

This report shows up to 5 performance regressions.

  • ExecuteNonQuery - Benchmarks.Trace.DbCommandBenchmark 1.6µs (+349ns, +28%) - Details
  • WriteAndFlushEnrichedTraces - Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark 687µs (+119.16µs, +21%) - Details
  • WriteAndFlushEnrichedTraces - Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark 819.83µs (+124.52µs, +18%) - Details
  • WriteAndFlushEnrichedTraces - Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark 1.03ms (+163.15µs, +19%) - Details
  • WriteAndFlushEnrichedTraces - Benchmarks.Trace.AgentWriterBenchmark 704.12µs (+66.78µs, +10%) - Details

datadog-ddstaging[bot] avatar Aug 14 '24 12:08 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 (5897) - mean (73ms)  : 64, 82
     .   : milestone, 73,
    master - mean (74ms)  : 64, 84
     .   : milestone, 74,

    section CallTarget+Inlining+NGEN
    This PR (5897) - mean (1,109ms)  : 1088, 1130
     .   : milestone, 1109,
    master - mean (1,110ms)  : 1090, 1130
     .   : milestone, 1110,


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

    section CallTarget+Inlining+NGEN
    This PR (5897) - mean (804ms)  : 786, 821
     .   : milestone, 804,
    master - mean (803ms)  : 788, 817
     .   : milestone, 803,


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

    section CallTarget+Inlining+NGEN
    This PR (5897) - mean (757ms)  : 736, 778
     .   : milestone, 757,
    master - mean (754ms)  : 732, 776
     .   : milestone, 754,


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

    section CallTarget+Inlining+NGEN
    This PR (5897) - mean (1,206ms)  : 1174, 1238
     .   : milestone, 1206,
    master - mean (1,195ms)  : 1171, 1219
     .   : milestone, 1195,


gantt
    title Execution time (ms) HttpMessageHandler (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5897) - mean (276ms)  : 270, 282
     .   : milestone, 276,
    master - mean (275ms)  : 270, 281
     .   : milestone, 275,

    section CallTarget+Inlining+NGEN
    This PR (5897) - mean (979ms)  : 955, 1003
     .   : milestone, 979,
    master - mean (976ms)  : 958, 994
     .   : milestone, 976,


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

    section CallTarget+Inlining+NGEN
    This PR (5897) - mean (982ms)  : 911, 1053
     .   : milestone, 982,
    master - mean (958ms)  : 932, 985
     .   : milestone, 958,

andrewlock avatar Aug 14 '24 12:08 andrewlock

Benchmarks Report for tracer :snail:

Benchmarks for #5897 compared to master:

  • 8 benchmarks are slower, with geometric mean 1.379
  • 2 benchmarks have fewer 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.65μs 42.9ns 291ns 0.0155 0.00777 0 5.43 KB
master StartStopWithChild netcoreapp3.1 9.94μs 56.1ns 384ns 0.0248 0.00991 0 5.61 KB
master StartStopWithChild net472 16.1μs 62.7ns 243ns 1.02 0.307 0.0945 6.06 KB
#5897 StartStopWithChild net6.0 7.97μs 45.1ns 315ns 0.0153 0.00763 0 5.42 KB
#5897 StartStopWithChild netcoreapp3.1 10.2μs 56.6ns 375ns 0.0206 0.0103 0 5.61 KB
#5897 StartStopWithChild net472 17.3μs 85.5ns 392ns 1.01 0.293 0.0776 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 484μs 235ns 908ns 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 634μs 551ns 2.13μs 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces net472 854μs 795ns 2.97μs 0.431 0 0 3.3 KB
#5897 WriteAndFlushEnrichedTraces net6.0 514μs 2.73μs 14.5μs 0 0 0 2.7 KB
#5897 WriteAndFlushEnrichedTraces netcoreapp3.1 704μs 4.06μs 31.7μs 0 0 0 2.7 KB
#5897 WriteAndFlushEnrichedTraces net472 923μs 5.23μs 35.1μs 0.428 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 198μs 1.15μs 10.8μs 0.2 0 0 18.45 KB
master SendRequest netcoreapp3.1 224μs 1.31μs 11.7μs 0.216 0 0 20.61 KB
master SendRequest net472 0.000252ns 0.000252ns 0.000907ns 0 0 0 0 b
#5897 SendRequest net6.0 189μs 906ns 3.51μs 0.202 0 0 18.45 KB
#5897 SendRequest netcoreapp3.1 201μs 418ns 1.56μs 0.201 0 0 20.61 KB
#5897 SendRequest net472 0.0638ns 0.0143ns 0.0729ns 0 0 0 0 b
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark - Slower :warning: Fewer allocations :tada:

Slower :warning: in #5897

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark.WriteAndFlushEnrichedTraces‑net6.0 1.211 566,626.05 686,236.33
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark.WriteAndFlushEnrichedTraces‑net472 1.205 858,383.84 1,034,596.33

Fewer allocations :tada: in #5897

Benchmark Base Allocated Diff Allocated Change Change %
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark.WriteAndFlushEnrichedTraces‑netcoreapp3.1 41.52 KB 41.08 KB -441 B -1.06%
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark.WriteAndFlushEnrichedTraces‑net6.0 41.74 KB 41.15 KB -597 B -1.43%

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master WriteAndFlushEnrichedTraces net6.0 567μs 2.89μs 15μs 0.551 0 0 41.74 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 753μs 4.22μs 26.7μs 0.374 0 0 41.52 KB
master WriteAndFlushEnrichedTraces net472 859μs 4.41μs 19.7μs 8.08 2.55 0.425 53.29 KB
#5897 WriteAndFlushEnrichedTraces net6.0 687μs 2.49μs 9.65μs 0.334 0 0 41.15 KB
#5897 WriteAndFlushEnrichedTraces netcoreapp3.1 820μs 3.42μs 13.3μs 0.417 0 0 41.08 KB
#5897 WriteAndFlushEnrichedTraces net472 1.03ms 3.08μs 11.9μs 8.26 2.58 0.517 53.33 KB
Benchmarks.Trace.DbCommandBenchmark - Slower :warning: Same allocations :heavy_check_mark:

Slower :warning: in #5897

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.DbCommandBenchmark.ExecuteNonQuery‑net6.0 1.236 1,295.73 1,601.79 bimodal

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master ExecuteNonQuery net6.0 1.3μs 1.66ns 6.42ns 0.0142 0 0 1.02 KB
master ExecuteNonQuery netcoreapp3.1 1.69μs 1.14ns 4.41ns 0.0134 0 0 1.02 KB
master ExecuteNonQuery net472 1.99μs 2.31ns 8.65ns 0.156 0 0 987 B
#5897 ExecuteNonQuery net6.0 1.6μs 16.4ns 164ns 0.0139 0 0 1.02 KB
#5897 ExecuteNonQuery netcoreapp3.1 1.69μs 1.04ns 3.91ns 0.0135 0 0 1.02 KB
#5897 ExecuteNonQuery net472 1.98μs 1.46ns 5.67ns 0.156 0 0 987 B
Benchmarks.Trace.ElasticsearchBenchmark - Slower :warning: Same allocations :heavy_check_mark:

Slower :warning: in #5897

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.ElasticsearchBenchmark.CallElasticsearch‑net6.0 1.891 1,201.60 2,272.35
Benchmarks.Trace.ElasticsearchBenchmark.CallElasticsearch‑netcoreapp3.1 1.762 1,534.57 2,704.24 several?
Benchmarks.Trace.ElasticsearchBenchmark.CallElasticsearchAsync‑net6.0 1.601 1,436.42 2,299.18 bimodal

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master CallElasticsearch net6.0 1.2μs 0.946ns 3.66ns 0.0135 0 0 976 B
master CallElasticsearch netcoreapp3.1 1.53μs 0.6ns 2.33ns 0.0131 0 0 976 B
master CallElasticsearch net472 2.52μs 1.82ns 7.03ns 0.158 0 0 995 B
master CallElasticsearchAsync net6.0 1.43μs 1.56ns 5.85ns 0.0134 0 0 952 B
master CallElasticsearchAsync netcoreapp3.1 1.66μs 0.849ns 3.18ns 0.0133 0 0 1.02 KB
master CallElasticsearchAsync net472 2.8μs 1.91ns 7.16ns 0.166 0 0 1.05 KB
#5897 CallElasticsearch net6.0 2.28μs 20.5ns 205ns 0.0139 0 0 976 B
#5897 CallElasticsearch netcoreapp3.1 2.71μs 20.2ns 201ns 0.013 0 0 976 B
#5897 CallElasticsearch net472 2.46μs 1.71ns 6.61ns 0.158 0 0 995 B
#5897 CallElasticsearchAsync net6.0 2.3μs 20.4ns 204ns 0.0131 0 0 952 B
#5897 CallElasticsearchAsync netcoreapp3.1 1.62μs 0.475ns 1.84ns 0.0141 0 0 1.02 KB
#5897 CallElasticsearchAsync net472 2.67μs 2.89ns 10.8ns 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.19μs 2.04ns 7.9ns 0.013 0 0 952 B
master ExecuteAsync netcoreapp3.1 1.6μs 0.514ns 1.99ns 0.0128 0 0 952 B
master ExecuteAsync net472 1.69μs 1.21ns 4.54ns 0.145 0 0 915 B
#5897 ExecuteAsync net6.0 1.25μs 0.767ns 2.97ns 0.0132 0 0 952 B
#5897 ExecuteAsync netcoreapp3.1 1.59μs 1.11ns 4.31ns 0.0127 0 0 952 B
#5897 ExecuteAsync net472 1.72μs 0.324ns 1.12ns 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.25μs 1.38ns 5.36ns 0.03 0 0 2.22 KB
master SendAsync netcoreapp3.1 5.05μs 1.23ns 4.76ns 0.0354 0 0 2.76 KB
master SendAsync net472 7.74μs 2.1ns 8.15ns 0.498 0 0 3.15 KB
#5897 SendAsync net6.0 4.2μs 1.43ns 5.35ns 0.0316 0 0 2.22 KB
#5897 SendAsync netcoreapp3.1 5.01μs 1.32ns 4.95ns 0.0375 0 0 2.76 KB
#5897 SendAsync net472 7.65μs 2.8ns 10.8ns 0.497 0 0 3.15 KB
Benchmarks.Trace.ILoggerBenchmark - Slower :warning: Same allocations :heavy_check_mark:

Slower :warning: in #5897

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.ILoggerBenchmark.EnrichedLog‑netcoreapp3.1 1.159 2,113.88 2,449.00

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net6.0 1.47μs 1.11ns 4.16ns 0.0233 0 0 1.64 KB
master EnrichedLog netcoreapp3.1 2.13μs 8.79ns 34.1ns 0.0221 0 0 1.64 KB
master EnrichedLog net472 2.64μs 4.31ns 16.7ns 0.25 0 0 1.57 KB
#5897 EnrichedLog net6.0 1.49μs 1.35ns 5.06ns 0.023 0 0 1.64 KB
#5897 EnrichedLog netcoreapp3.1 2.45μs 1.49ns 5.59ns 0.0218 0 0 1.64 KB
#5897 EnrichedLog net472 2.56μs 0.792ns 2.75ns 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 117μs 210ns 812ns 0 0 0 4.28 KB
master EnrichedLog netcoreapp3.1 123μs 605ns 2.64μs 0 0 0 4.28 KB
master EnrichedLog net472 153μs 161ns 603ns 0.678 0.226 0 4.46 KB
#5897 EnrichedLog net6.0 117μs 147ns 569ns 0.0588 0 0 4.28 KB
#5897 EnrichedLog netcoreapp3.1 120μs 280ns 1.05μs 0 0 0 4.28 KB
#5897 EnrichedLog net472 150μs 174ns 673ns 0.682 0.227 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.93μs 0.982ns 3.8ns 0.0312 0 0 2.2 KB
master EnrichedLog netcoreapp3.1 4.1μs 1.8ns 6.99ns 0.029 0 0 2.2 KB
master EnrichedLog net472 4.82μs 0.791ns 3.06ns 0.321 0 0 2.02 KB
#5897 EnrichedLog net6.0 2.87μs 0.806ns 3.12ns 0.0299 0 0 2.2 KB
#5897 EnrichedLog netcoreapp3.1 4.31μs 2.96ns 11.5ns 0.0301 0 0 2.2 KB
#5897 EnrichedLog net472 4.93μs 3.8ns 14.7ns 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.42μs 1.23ns 4.78ns 0.0162 0 0 1.14 KB
master SendReceive netcoreapp3.1 1.75μs 1.32ns 5.11ns 0.0154 0 0 1.14 KB
master SendReceive net472 2.14μs 2.49ns 9.64ns 0.183 0.0011 0 1.16 KB
#5897 SendReceive net6.0 1.32μs 0.988ns 3.7ns 0.0158 0 0 1.14 KB
#5897 SendReceive netcoreapp3.1 1.84μs 0.88ns 3.29ns 0.0153 0 0 1.14 KB
#5897 SendReceive net472 2.11μs 5.32ns 20.6ns 0.183 0.00104 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.72μs 0.756ns 2.83ns 0.0218 0 0 1.6 KB
master EnrichedLog netcoreapp3.1 3.85μs 4.56ns 17.7ns 0.021 0 0 1.65 KB
master EnrichedLog net472 4.37μs 2.79ns 10.8ns 0.324 0 0 2.04 KB
#5897 EnrichedLog net6.0 2.68μs 0.896ns 3.23ns 0.0215 0 0 1.6 KB
#5897 EnrichedLog netcoreapp3.1 3.93μs 1.59ns 6.18ns 0.0214 0 0 1.65 KB
#5897 EnrichedLog net472 4.54μs 1.98ns 7.66ns 0.323 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 397ns 0.302ns 1.13ns 0.00803 0 0 576 B
master StartFinishSpan netcoreapp3.1 559ns 0.165ns 0.637ns 0.0077 0 0 576 B
master StartFinishSpan net472 646ns 0.326ns 1.26ns 0.0918 0 0 578 B
master StartFinishScope net6.0 559ns 0.528ns 2.04ns 0.00981 0 0 696 B
master StartFinishScope netcoreapp3.1 761ns 0.27ns 1.05ns 0.00938 0 0 696 B
master StartFinishScope net472 922ns 1.27ns 4.76ns 0.105 0 0 658 B
#5897 StartFinishSpan net6.0 401ns 0.823ns 3.19ns 0.00801 0 0 576 B
#5897 StartFinishSpan netcoreapp3.1 611ns 2.38ns 9.2ns 0.00779 0 0 576 B
#5897 StartFinishSpan net472 624ns 1.73ns 6.46ns 0.0916 0 0 578 B
#5897 StartFinishScope net6.0 560ns 0.206ns 0.798ns 0.0096 0 0 696 B
#5897 StartFinishScope netcoreapp3.1 785ns 0.561ns 2.17ns 0.00943 0 0 696 B
#5897 StartFinishScope net472 837ns 0.482ns 1.87ns 0.105 0 0 658 B
Benchmarks.Trace.TraceAnnotationsBenchmark - Slower :warning: Same allocations :heavy_check_mark:

Slower :warning: in #5897

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.TraceAnnotationsBenchmark.RunOnMethodBegin‑netcoreapp3.1 1.174 874.11 1,026.06

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master RunOnMethodBegin net6.0 605ns 0.258ns 1ns 0.00986 0 0 696 B
master RunOnMethodBegin netcoreapp3.1 873ns 1.23ns 4.76ns 0.00915 0 0 696 B
master RunOnMethodBegin net472 1.1μs 0.27ns 1.04ns 0.104 0 0 658 B
#5897 RunOnMethodBegin net6.0 673ns 0.682ns 2.64ns 0.00974 0 0 696 B
#5897 RunOnMethodBegin netcoreapp3.1 1.02μs 0.875ns 3.39ns 0.00964 0 0 696 B
#5897 RunOnMethodBegin net472 1.09μs 0.348ns 1.35ns 0.104 0 0 658 B

andrewlock avatar Aug 14 '24 18:08 andrewlock

We have the macrobenchmarks now so no longer needed

bouwkast avatar Oct 03 '25 22:10 bouwkast