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

[Profiler] Cache snapshot result for Walltime profiler #4500

Draft
wants to merge 1 commit into
base: master
Choose a base branch
from

Conversation

gleocadie
Copy link
Collaborator

Summary of changes

Reason for change

Implementation details

Test coverage

Other details

@github-actions github-actions bot added the area:profiler Issues related to the continous-profiler label Aug 10, 2023
@datadog-ddstaging
Copy link

datadog-ddstaging bot commented Aug 10, 2023

Datadog Report

Branch report: gleocadie/cache-stackwalk-result-for-wallclock-profiler
Commit report: 69486da

dd-trace-dotnet: 0 Failed, 0 New Flaky, 151912 Passed, 320 Skipped, 22m 6.96s Wall Time

@andrewlock
Copy link
Member

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 (4500) - mean (73ms)  : 60, 86
     .   : milestone, 73,
    master - mean (68ms)  : 64, 73
     .   : milestone, 68,

    section CallTarget+Inlining+NGEN
    This PR (4500) - mean (1,048ms)  : 1024, 1072
     .   : milestone, 1048,
    master - mean (1,048ms)  : 1022, 1074
     .   : milestone, 1048,

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

    section CallTarget+Inlining+NGEN
    This PR (4500) - mean (743ms)  : 717, 769
     .   : milestone, 743,
    master - mean (745ms)  : 726, 764
     .   : milestone, 745,

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

    section CallTarget+Inlining+NGEN
    This PR (4500) - mean (709ms)  : 684, 734
     .   : milestone, 709,
    master - mean (708ms)  : 692, 724
     .   : milestone, 708,

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

    section CallTarget+Inlining+NGEN
    This PR (4500) - mean (1,143ms)  : 1112, 1175
     .   : milestone, 1143,
    master - mean (1,154ms)  : 1126, 1182
     .   : milestone, 1154,

Loading
gantt
    title Execution time (ms) HttpMessageHandler (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4500) - mean (274ms)  : 266, 282
     .   : milestone, 274,
    master - mean (274ms)  : 268, 279
     .   : milestone, 274,

    section CallTarget+Inlining+NGEN
    This PR (4500) - mean (1,104ms)  : 1067, 1141
     .   : milestone, 1104,
    master - mean (1,106ms)  : 1079, 1133
     .   : milestone, 1106,

Loading
gantt
    title Execution time (ms) HttpMessageHandler (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4500) - mean (260ms)  : 252, 267
     .   : milestone, 260,
    master - mean (263ms)  : 257, 269
     .   : milestone, 263,

    section CallTarget+Inlining+NGEN
    This PR (4500) - mean (1,052ms)  : 1030, 1074
     .   : milestone, 1052,
    master - mean (1,058ms)  : 1042, 1074
     .   : milestone, 1058,

Loading

@andrewlock
Copy link
Member

Benchmarks Report 🐌

Benchmarks for #4500 compared to master:

  • 1 benchmarks are faster, with geometric mean 1.332
  • 1 benchmarks are slower, with geometric mean 1.237
  • 1 benchmarks have more 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.AgentWriterBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master WriteAndFlushEnrichedTraces net6.0 476μs 80.1ns 310ns 0 0 0 2.62 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 623μs 612ns 2.29μs 0 0 0 2.63 KB
master WriteAndFlushEnrichedTraces net472 795μs 300ns 1.16μs 0.396 0 0 3.22 KB
#4500 WriteAndFlushEnrichedTraces net6.0 480μs 178ns 690ns 0 0 0 2.62 KB
#4500 WriteAndFlushEnrichedTraces netcoreapp3.1 632μs 174ns 674ns 0 0 0 2.63 KB
#4500 WriteAndFlushEnrichedTraces net472 789μs 300ns 1.16μs 0.393 0 0 3.22 KB
Benchmarks.Trace.AppSecBodyBenchmark - Faster 🎉 Same allocations ✔️

Faster 🎉 in #4500

Benchmark base/diff Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.AppSecBodyBenchmark.ObjectExtractorSimpleBody‑netcoreapp3.1 1.332 233.03 174.89

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master AllCycleSimpleBody net6.0 39.1μs 40.1ns 155ns 0.0195 0 0 1.65 KB
master AllCycleSimpleBody netcoreapp3.1 41.8μs 43.8ns 158ns 0.0207 0 0 1.63 KB
master AllCycleSimpleBody net472 42.9μs 28ns 108ns 0.252 0 0 1.69 KB
master AllCycleMoreComplexBody net6.0 223μs 332ns 1.28μs 0.11 0 0 9.22 KB
master AllCycleMoreComplexBody netcoreapp3.1 229μs 131ns 509ns 0.115 0 0 9.12 KB
master AllCycleMoreComplexBody net472 239μs 72ns 279ns 1.42 0 0 9.28 KB
master ObjectExtractorSimpleBody net6.0 119ns 0.0694ns 0.26ns 0.00393 0 0 280 B
master ObjectExtractorSimpleBody netcoreapp3.1 233ns 0.147ns 0.569ns 0.00371 0 0 272 B
master ObjectExtractorSimpleBody net472 141ns 0.094ns 0.364ns 0.0446 0 0 281 B
master ObjectExtractorMoreComplexBody net6.0 2.97μs 0.786ns 2.94ns 0.055 0 0 3.88 KB
master ObjectExtractorMoreComplexBody netcoreapp3.1 4.04μs 1.57ns 5.87ns 0.0505 0 0 3.78 KB
master ObjectExtractorMoreComplexBody net472 4.1μs 2.19ns 8.48ns 0.618 0.00614 0 3.89 KB
#4500 AllCycleSimpleBody net6.0 39μs 19.9ns 77ns 0.0193 0 0 1.65 KB
#4500 AllCycleSimpleBody netcoreapp3.1 41.6μs 161ns 623ns 0.0206 0 0 1.63 KB
#4500 AllCycleSimpleBody net472 41.6μs 16.1ns 62.2ns 0.25 0 0 1.69 KB
#4500 AllCycleMoreComplexBody net6.0 221μs 116ns 448ns 0.112 0 0 9.22 KB
#4500 AllCycleMoreComplexBody netcoreapp3.1 227μs 207ns 748ns 0.114 0 0 9.12 KB
#4500 AllCycleMoreComplexBody net472 239μs 87ns 337ns 1.43 0 0 9.28 KB
#4500 ObjectExtractorSimpleBody net6.0 119ns 0.0462ns 0.173ns 0.00394 0 0 280 B
#4500 ObjectExtractorSimpleBody netcoreapp3.1 175ns 0.0787ns 0.295ns 0.00371 0 0 272 B
#4500 ObjectExtractorSimpleBody net472 142ns 0.0983ns 0.381ns 0.0446 0 0 281 B
#4500 ObjectExtractorMoreComplexBody net6.0 3.12μs 0.7ns 2.53ns 0.0547 0 0 3.88 KB
#4500 ObjectExtractorMoreComplexBody netcoreapp3.1 4.03μs 1.33ns 4.98ns 0.0523 0 0 3.78 KB
#4500 ObjectExtractorMoreComplexBody net472 4.1μs 2.78ns 10.8ns 0.617 0.00613 0 3.89 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 170μs 148ns 573ns 0.254 0 0 18.08 KB
master SendRequest netcoreapp3.1 189μs 332ns 1.24μs 0.19 0 0 20.14 KB
master SendRequest net472 0.000172ns 0.000156ns 0.000584ns 0 0 0 0 b
#4500 SendRequest net6.0 169μs 131ns 507ns 0.167 0 0 18.08 KB
#4500 SendRequest netcoreapp3.1 188μs 327ns 1.27μs 0.187 0 0 20.14 KB
#4500 SendRequest net472 4.45E‑05ns 2.81E‑05ns 0.000109ns 0 0 0 0 b
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark - Same speed ✔️ More allocations ⚠️

More allocations ⚠️ in #4500

Benchmark Base Allocated Diff Allocated Change Change %
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark.WriteAndFlushEnrichedTraces‑net6.0 41.51 KB 41.89 KB 385 B 0.93%

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master WriteAndFlushEnrichedTraces net6.0 502μs 251ns 869ns 0.521 0 0 41.51 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 625μs 1.43μs 5.55μs 0.311 0 0 41.72 KB
master WriteAndFlushEnrichedTraces net472 782μs 2.77μs 10.7μs 8.2 2.34 0.391 53.21 KB
#4500 WriteAndFlushEnrichedTraces net6.0 530μs 2.1μs 8.14μs 0.494 0 0 41.89 KB
#4500 WriteAndFlushEnrichedTraces netcoreapp3.1 611μs 968ns 3.62μs 0.311 0 0 41.89 KB
#4500 WriteAndFlushEnrichedTraces net472 800μs 2.68μs 10.4μs 8.2 2.34 0.391 53.22 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.15μs 0.401ns 1.55ns 0.0104 0 0 768 B
master ExecuteNonQuery netcoreapp3.1 1.34μs 0.551ns 2.06ns 0.0103 0 0 768 B
master ExecuteNonQuery net472 1.55μs 0.759ns 2.94ns 0.116 0.000773 0 730 B
#4500 ExecuteNonQuery net6.0 1.08μs 0.365ns 1.41ns 0.0109 0 0 768 B
#4500 ExecuteNonQuery netcoreapp3.1 1.46μs 0.25ns 0.937ns 0.0102 0 0 768 B
#4500 ExecuteNonQuery net472 1.65μs 0.589ns 2.28ns 0.116 0 0 730 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.1μs 3.03ns 11.7ns 0.0137 0 0 992 B
master CallElasticsearch netcoreapp3.1 1.48μs 0.677ns 2.53ns 0.0133 0 0 992 B
master CallElasticsearch net472 2.32μs 1.1ns 4.25ns 0.159 0.00116 0 1 KB
master CallElasticsearchAsync net6.0 1.26μs 0.704ns 2.54ns 0.0133 0 0 968 B
master CallElasticsearchAsync netcoreapp3.1 1.53μs 0.682ns 2.64ns 0.0138 0 0 1.04 KB
master CallElasticsearchAsync net472 2.59μs 0.68ns 2.54ns 0.167 0.00131 0 1.06 KB
#4500 CallElasticsearch net6.0 1.2μs 0.37ns 1.43ns 0.0138 0 0 992 B
#4500 CallElasticsearch netcoreapp3.1 1.49μs 0.573ns 2.06ns 0.0135 0 0 992 B
#4500 CallElasticsearch net472 2.38μs 0.536ns 2.08ns 0.159 0 0 1 KB
#4500 CallElasticsearchAsync net6.0 1.32μs 0.459ns 1.78ns 0.0133 0 0 968 B
#4500 CallElasticsearchAsync netcoreapp3.1 1.47μs 0.592ns 2.21ns 0.0142 0 0 1.04 KB
#4500 CallElasticsearchAsync net472 2.45μs 0.697ns 2.7ns 0.168 0.00122 0 1.06 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.19μs 0.304ns 1.1ns 0.0131 0 0 912 B
master ExecuteAsync netcoreapp3.1 1.45μs 0.301ns 1.04ns 0.0123 0 0 912 B
master ExecuteAsync net472 1.59μs 0.463ns 1.79ns 0.139 0 0 875 B
#4500 ExecuteAsync net6.0 1.19μs 0.393ns 1.42ns 0.0126 0 0 912 B
#4500 ExecuteAsync netcoreapp3.1 1.55μs 0.509ns 1.97ns 0.0124 0 0 912 B
#4500 ExecuteAsync net472 1.69μs 0.627ns 2.17ns 0.139 0.000841 0 875 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 3.77μs 1.21ns 4.7ns 0.0263 0 0 1.94 KB
master SendAsync netcoreapp3.1 4.49μs 1.37ns 5.14ns 0.0337 0 0 2.48 KB
master SendAsync net472 7.03μs 4.01ns 15.5ns 0.483 0 0 3.05 KB
#4500 SendAsync net6.0 3.85μs 1.19ns 4.59ns 0.027 0 0 1.94 KB
#4500 SendAsync netcoreapp3.1 4.44μs 1.12ns 4.05ns 0.0335 0 0 2.48 KB
#4500 SendAsync net472 7.12μs 1.51ns 5.84ns 0.483 0 0 3.05 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.25μs 0.315ns 1.14ns 0.0225 0 0 1.62 KB
master EnrichedLog netcoreapp3.1 1.94μs 1.95ns 7.05ns 0.0223 0 0 1.62 KB
master EnrichedLog net472 2.33μs 0.894ns 3.34ns 0.245 0 0 1.54 KB
#4500 EnrichedLog net6.0 1.39μs 0.773ns 2.89ns 0.023 0 0 1.62 KB
#4500 EnrichedLog netcoreapp3.1 1.94μs 0.807ns 3.02ns 0.0218 0 0 1.62 KB
#4500 EnrichedLog net472 2.28μs 1.07ns 4.14ns 0.244 0 0 1.54 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 115μs 66.1ns 256ns 0.0574 0 0 4.21 KB
master EnrichedLog netcoreapp3.1 120μs 324ns 1.25μs 0 0 0 4.21 KB
master EnrichedLog net472 148μs 321ns 1.24μs 0.666 0.222 0 4.38 KB
#4500 EnrichedLog net6.0 113μs 83.6ns 324ns 0.0562 0 0 4.21 KB
#4500 EnrichedLog netcoreapp3.1 118μs 227ns 880ns 0 0 0 4.21 KB
#4500 EnrichedLog net472 149μs 90ns 337ns 0.672 0.224 0 4.38 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 2.91μs 0.929ns 3.48ns 0.0307 0 0 2.18 KB
master EnrichedLog netcoreapp3.1 3.87μs 8.57ns 30.9ns 0.0285 0 0 2.18 KB
master EnrichedLog net472 4.44μs 1.59ns 6.16ns 0.316 0 0 1.99 KB
#4500 EnrichedLog net6.0 2.91μs 1.27ns 4.91ns 0.0307 0 0 2.18 KB
#4500 EnrichedLog netcoreapp3.1 3.84μs 1.67ns 6.25ns 0.0287 0 0 2.18 KB
#4500 EnrichedLog net472 4.5μs 2.73ns 10.6ns 0.315 0 0 1.99 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.3μs 0.496ns 1.86ns 0.0164 0 0 1.16 KB
master SendReceive netcoreapp3.1 1.59μs 0.71ns 2.56ns 0.0151 0 0 1.16 KB
master SendReceive net472 2.12μs 0.938ns 3.63ns 0.184 0 0 1.16 KB
#4500 SendReceive net6.0 1.34μs 1.43ns 5.53ns 0.0159 0 0 1.16 KB
#4500 SendReceive netcoreapp3.1 1.66μs 0.549ns 1.98ns 0.0157 0 0 1.16 KB
#4500 SendReceive net472 1.97μs 2.03ns 7.61ns 0.185 0.000978 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.54μs 0.659ns 2.47ns 0.0216 0 0 1.53 KB
master EnrichedLog netcoreapp3.1 3.58μs 2.41ns 9.02ns 0.0215 0 0 1.58 KB
master EnrichedLog net472 3.88μs 1.46ns 5.65ns 0.31 0 0 1.96 KB
#4500 EnrichedLog net6.0 2.6μs 1.72ns 5.97ns 0.0207 0 0 1.53 KB
#4500 EnrichedLog netcoreapp3.1 3.71μs 1.91ns 7.39ns 0.02 0 0 1.58 KB
#4500 EnrichedLog net472 3.95μs 0.893ns 3.22ns 0.31 0 0 1.96 KB
Benchmarks.Trace.SpanBenchmark - Slower ⚠️ Same allocations ✔️

Slower ⚠️ in #4500

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.SpanBenchmark.StartFinishScope‑net6.0 1.237 489.90 606.11

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartFinishSpan net6.0 496ns 0.497ns 1.86ns 0.00744 0 0 536 B
master StartFinishSpan netcoreapp3.1 546ns 0.223ns 0.865ns 0.00721 0 0 536 B
master StartFinishSpan net472 666ns 0.101ns 0.392ns 0.0854 0 0 538 B
master StartFinishScope net6.0 490ns 0.162ns 0.605ns 0.0091 0 0 656 B
master StartFinishScope netcoreapp3.1 744ns 0.234ns 0.876ns 0.00892 0 0 656 B
master StartFinishScope net472 863ns 0.328ns 1.27ns 0.098 0 0 618 B
#4500 StartFinishSpan net6.0 465ns 0.0931ns 0.348ns 0.0075 0 0 536 B
#4500 StartFinishSpan netcoreapp3.1 558ns 0.363ns 1.36ns 0.00726 0 0 536 B
#4500 StartFinishSpan net472 650ns 0.323ns 1.25ns 0.0853 0 0 538 B
#4500 StartFinishScope net6.0 606ns 0.419ns 1.57ns 0.00906 0 0 656 B
#4500 StartFinishScope netcoreapp3.1 721ns 0.365ns 1.36ns 0.00866 0 0 656 B
#4500 StartFinishScope net472 852ns 0.639ns 2.47ns 0.0979 0 0 618 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 598ns 0.118ns 0.426ns 0.0093 0 0 656 B
master RunOnMethodBegin netcoreapp3.1 795ns 0.635ns 2.46ns 0.00886 0 0 656 B
master RunOnMethodBegin net472 1μs 0.382ns 1.48ns 0.0979 0 0 618 B
#4500 RunOnMethodBegin net6.0 613ns 0.379ns 1.42ns 0.00909 0 0 656 B
#4500 RunOnMethodBegin netcoreapp3.1 780ns 0.287ns 1.08ns 0.00894 0 0 656 B
#4500 RunOnMethodBegin net472 1.03μs 0.235ns 0.91ns 0.0982 0 0 618 B

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area:profiler Issues related to the continous-profiler
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants