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

[Profiler] Make LibrariesInfoCache standalone

Open gleocadie opened this issue 1 year ago • 5 comments

Summary of changes

Reason for change

Implementation details

Test coverage

Other details

gleocadie avatar Sep 10 '24 20:09 gleocadie

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 (6019) - mean (71ms)  : 68, 73
     .   : milestone, 71,
    master - mean (71ms)  : 68, 73
     .   : milestone, 71,

    section CallTarget+Inlining+NGEN
    This PR (6019) - mean (1,118ms)  : 1090, 1146
     .   : milestone, 1118,
    master - mean (1,126ms)  : 1103, 1149
     .   : milestone, 1126,


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

    section CallTarget+Inlining+NGEN
    This PR (6019) - mean (780ms)  : 765, 796
     .   : milestone, 780,
    master - mean (790ms)  : 769, 811
     .   : milestone, 790,


gantt
    title Execution time (ms) FakeDbCommand (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6019) - mean (93ms)  : 90, 96
     .   : milestone, 93,
    master - mean (94ms)  : 90, 99
     .   : milestone, 94,

    section CallTarget+Inlining+NGEN
    This PR (6019) - mean (734ms)  : 716, 752
     .   : milestone, 734,
    master - mean (747ms)  : 729, 764
     .   : milestone, 747,


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

    section CallTarget+Inlining+NGEN
    This PR (6019) - mean (1,224ms)  : 1193, 1255
     .   : milestone, 1224,
    master - mean (1,222ms)  : 1198, 1246
     .   : milestone, 1222,


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

    section CallTarget+Inlining+NGEN
    This PR (6019) - mean (945ms)  : 926, 964
     .   : milestone, 945,
    master - mean (948ms)  : 926, 970
     .   : milestone, 948,


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

    section CallTarget+Inlining+NGEN
    This PR (6019) - mean (930ms)  : 912, 948
     .   : milestone, 930,
    master - mean (932ms)  : 914, 949
     .   : milestone, 932,

andrewlock avatar Sep 10 '24 20:09 andrewlock

Datadog Report

Branch report: gleocadie/ensure-dl-iterate-phdr-cache-works-even-if-walltime-profiler-is-disabled Commit report: df0ab5f Test service: dd-trace-dotnet

:white_check_mark: 0 Failed, 369260 Passed, 2432 Skipped, 16h 54m 40.75s Total Time :snowflake: 1 New Flaky

New Flaky Tests (1)

  • SsiAndProfilingSsiEnabled_AllTriggered - Datadog.Profiler.IntegrationTests.SingleStepInstrumentation.SingleStepInstrumentationTest - Last Failure

    Expand for error 
    xit code of "Samples.BuggyBits" should be 0 instead of 134 (= 0x86)
xpected: True
ctual:   False

datadog-ddstaging[bot] avatar Sep 10 '24 20:09 datadog-ddstaging[bot]

Benchmarks Report for tracer :snail:

Benchmarks for #6019 compared to master:

  • 1 benchmarks are faster, with geometric mean 1.140
  • 1 benchmarks are slower, with geometric mean 1.114
  • 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.09μs 44.2ns 242ns 0.0113 0.00378 0 5.61 KB
master StartStopWithChild netcoreapp3.1 10μs 48.7ns 218ns 0.0293 0.0147 0 5.81 KB
master StartStopWithChild net472 16.5μs 49.8ns 186ns 1.06 0.332 0.0891 6.23 KB
#6019 StartStopWithChild net6.0 8.08μs 45.6ns 329ns 0.017 0.00849 0 5.6 KB
#6019 StartStopWithChild netcoreapp3.1 10.1μs 52.7ns 247ns 0.0243 0.00972 0 5.8 KB
#6019 StartStopWithChild net472 16.4μs 40.7ns 158ns 1.05 0.319 0.0899 6.2 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 470μs 181ns 702ns 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 654μs 566ns 2.19μs 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces net472 834μs 414ns 1.6μs 0.419 0 0 3.3 KB
#6019 WriteAndFlushEnrichedTraces net6.0 473μs 355ns 1.38μs 0 0 0 2.7 KB
#6019 WriteAndFlushEnrichedTraces netcoreapp3.1 661μs 240ns 866ns 0 0 0 2.7 KB
#6019 WriteAndFlushEnrichedTraces net472 840μs 404ns 1.57μs 0.419 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 217μs 1.31μs 13μs 0.192 0 0 18.73 KB
master SendRequest netcoreapp3.1 250μs 2.23μs 22.3μs 0.214 0 0 20.89 KB
master SendRequest net472 0.00132ns 0.000548ns 0.00212ns 0 0 0 0 b
#6019 SendRequest net6.0 198μs 1.14μs 8.91μs 0.189 0 0 18.73 KB
#6019 SendRequest netcoreapp3.1 219μs 1.24μs 8.58μs 0.213 0 0 20.89 KB
#6019 SendRequest net472 0.000319ns 0.000231ns 0.000863ns 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 580μs 2.93μs 12.8μs 0.595 0 0 41.53 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 702μs 3.76μs 19.5μs 0.343 0 0 41.84 KB
master WriteAndFlushEnrichedTraces net472 905μs 4.64μs 20.8μs 8.04 2.23 0.446 53.29 KB
#6019 WriteAndFlushEnrichedTraces net6.0 557μs 2.54μs 10.1μs 0.539 0 0 41.55 KB
#6019 WriteAndFlushEnrichedTraces netcoreapp3.1 675μs 3.67μs 19.8μs 0.319 0 0 41.81 KB
#6019 WriteAndFlushEnrichedTraces net472 861μs 3.51μs 13.1μs 8.3 2.62 0.437 53.26 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.35μs 1.74ns 6.74ns 0.0147 0 0 1.02 KB
master ExecuteNonQuery netcoreapp3.1 1.75μs 3.41ns 13.2ns 0.0137 0 0 1.02 KB
master ExecuteNonQuery net472 2.04μs 1.85ns 6.92ns 0.156 0.00102 0 987 B
#6019 ExecuteNonQuery net6.0 1.23μs 0.94ns 3.64ns 0.0141 0 0 1.02 KB
#6019 ExecuteNonQuery netcoreapp3.1 1.68μs 1.33ns 5.13ns 0.0134 0 0 1.02 KB
#6019 ExecuteNonQuery net472 2.13μs 1.24ns 4.65ns 0.156 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.504ns 1.95ns 0.0139 0 0 976 B
master CallElasticsearch netcoreapp3.1 1.6μs 5.24ns 20.3ns 0.0127 0 0 976 B
master CallElasticsearch net472 2.58μs 2.31ns 8.95ns 0.158 0 0 995 B
master CallElasticsearchAsync net6.0 1.29μs 0.5ns 1.94ns 0.013 0 0 952 B
master CallElasticsearchAsync netcoreapp3.1 1.51μs 0.927ns 3.59ns 0.0136 0 0 1.02 KB
master CallElasticsearchAsync net472 2.52μs 1.74ns 6.75ns 0.166 0 0 1.05 KB
#6019 CallElasticsearch net6.0 1.23μs 0.384ns 1.33ns 0.0137 0 0 976 B
#6019 CallElasticsearch netcoreapp3.1 1.53μs 1.62ns 6.26ns 0.013 0 0 976 B
#6019 CallElasticsearch net472 2.46μs 1.42ns 5.31ns 0.157 0 0 995 B
#6019 CallElasticsearchAsync net6.0 1.28μs 0.599ns 2.32ns 0.0134 0 0 952 B
#6019 CallElasticsearchAsync netcoreapp3.1 1.64μs 1.41ns 5.27ns 0.0139 0 0 1.02 KB
#6019 CallElasticsearchAsync net472 2.63μs 1.54ns 5.98ns 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.3μs 0.46ns 1.78ns 0.0131 0 0 952 B
master ExecuteAsync netcoreapp3.1 1.64μs 0.741ns 2.77ns 0.0126 0 0 952 B
master ExecuteAsync net472 1.73μs 1.66ns 6.42ns 0.145 0 0 915 B
#6019 ExecuteAsync net6.0 1.24μs 0.981ns 3.67ns 0.0131 0 0 952 B
#6019 ExecuteAsync netcoreapp3.1 1.61μs 1.49ns 5.78ns 0.0128 0 0 952 B
#6019 ExecuteAsync net472 1.91μs 8.22ns 33.9ns 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.47ns 5.51ns 0.0323 0 0 2.31 KB
master SendAsync netcoreapp3.1 5.24μs 4.57ns 17.7ns 0.0367 0 0 2.85 KB
master SendAsync net472 7.48μs 2.97ns 11.5ns 0.494 0 0 3.12 KB
#6019 SendAsync net6.0 4.48μs 7.4ns 28.7ns 0.0301 0 0 2.31 KB
#6019 SendAsync netcoreapp3.1 5.5μs 6.98ns 26.1ns 0.0378 0 0 2.85 KB
#6019 SendAsync net472 7.77μs 12.5ns 48.5ns 0.494 0 0 3.12 KB
Benchmarks.Trace.ILoggerBenchmark - Slower :warning: Same allocations :heavy_check_mark:

Slower :warning: in #6019

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.ILoggerBenchmark.EnrichedLog‑net6.0 1.114 1,425.41 1,588.01

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net6.0 1.43μs 0.535ns 1.93ns 0.0228 0 0 1.64 KB
master EnrichedLog netcoreapp3.1 2.2μs 1.7ns 6.38ns 0.0221 0 0 1.64 KB
master EnrichedLog net472 2.55μs 1.2ns 4.67ns 0.249 0 0 1.57 KB
#6019 EnrichedLog net6.0 1.59μs 0.824ns 3.08ns 0.0229 0 0 1.64 KB
#6019 EnrichedLog netcoreapp3.1 2.2μs 1.16ns 4.36ns 0.0223 0 0 1.64 KB
#6019 EnrichedLog net472 2.69μs 0.728ns 2.82ns 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 120μs 371ns 1.44μs 0.0597 0 0 4.28 KB
master EnrichedLog netcoreapp3.1 122μs 133ns 515ns 0.0611 0 0 4.28 KB
master EnrichedLog net472 150μs 88.9ns 333ns 0.671 0.224 0 4.46 KB
#6019 EnrichedLog net6.0 119μs 207ns 801ns 0.0597 0 0 4.28 KB
#6019 EnrichedLog netcoreapp3.1 121μs 274ns 1.06μs 0.0602 0 0 4.28 KB
#6019 EnrichedLog net472 154μs 255ns 989ns 0.692 0.231 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.16μs 2.52ns 9.42ns 0.03 0 0 2.2 KB
master EnrichedLog netcoreapp3.1 4.28μs 10.2ns 39.5ns 0.0296 0 0 2.2 KB
master EnrichedLog net472 4.7μs 1.11ns 4.31ns 0.32 0 0 2.02 KB
#6019 EnrichedLog net6.0 3.21μs 4.41ns 17.1ns 0.0292 0 0 2.2 KB
#6019 EnrichedLog netcoreapp3.1 4.17μs 6.43ns 24.9ns 0.0293 0 0 2.2 KB
#6019 EnrichedLog net472 4.89μs 4.9ns 19ns 0.319 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.29μs 0.676ns 2.62ns 0.0161 0 0 1.14 KB
master SendReceive netcoreapp3.1 1.83μs 0.718ns 2.78ns 0.0155 0 0 1.14 KB
master SendReceive net472 2.15μs 0.811ns 3.14ns 0.183 0 0 1.16 KB
#6019 SendReceive net6.0 1.39μs 0.784ns 2.94ns 0.0162 0 0 1.14 KB
#6019 SendReceive netcoreapp3.1 1.68μs 1.82ns 7.05ns 0.0152 0 0 1.14 KB
#6019 SendReceive net472 2.13μs 0.792ns 2.96ns 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.77μs 1.03ns 4ns 0.0222 0 0 1.6 KB
master EnrichedLog netcoreapp3.1 3.97μs 1.24ns 4.65ns 0.0218 0 0 1.65 KB
master EnrichedLog net472 4.32μs 1.43ns 4.94ns 0.322 0 0 2.04 KB
#6019 EnrichedLog net6.0 2.72μs 0.741ns 2.87ns 0.0219 0 0 1.6 KB
#6019 EnrichedLog netcoreapp3.1 3.75μs 1.44ns 5.58ns 0.0209 0 0 1.65 KB
#6019 EnrichedLog net472 4.32μs 2.13ns 7.98ns 0.322 0 0 2.04 KB
Benchmarks.Trace.SpanBenchmark - Faster :tada: Same allocations :heavy_check_mark:

Faster :tada: in #6019

Benchmark base/diff Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.SpanBenchmark.StartFinishScope‑net6.0 1.140 563.78 494.74

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartFinishSpan net6.0 418ns 0.335ns 1.3ns 0.00799 0 0 576 B
master StartFinishSpan netcoreapp3.1 629ns 1.07ns 4.13ns 0.00769 0 0 576 B
master StartFinishSpan net472 655ns 0.857ns 3.21ns 0.0918 0 0 578 B
master StartFinishScope net6.0 564ns 0.451ns 1.75ns 0.00984 0 0 696 B
master StartFinishScope netcoreapp3.1 723ns 1.95ns 7.54ns 0.00931 0 0 696 B
master StartFinishScope net472 858ns 1.79ns 6.69ns 0.104 0 0 658 B
#6019 StartFinishSpan net6.0 410ns 0.19ns 0.712ns 0.00809 0 0 576 B
#6019 StartFinishSpan netcoreapp3.1 653ns 0.658ns 2.55ns 0.00756 0 0 576 B
#6019 StartFinishSpan net472 666ns 0.614ns 2.38ns 0.0917 0 0 578 B
#6019 StartFinishScope net6.0 494ns 0.262ns 1.01ns 0.00987 0 0 696 B
#6019 StartFinishScope netcoreapp3.1 662ns 0.595ns 2.3ns 0.00934 0 0 696 B
#6019 StartFinishScope net472 841ns 0.938ns 3.63ns 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 603ns 0.284ns 1.1ns 0.00963 0 0 696 B
master RunOnMethodBegin netcoreapp3.1 900ns 1.39ns 5.4ns 0.00958 0 0 696 B
master RunOnMethodBegin net472 1.16μs 1.47ns 5.71ns 0.104 0 0 658 B
#6019 RunOnMethodBegin net6.0 623ns 0.459ns 1.78ns 0.0098 0 0 696 B
#6019 RunOnMethodBegin netcoreapp3.1 928ns 0.539ns 2.09ns 0.00923 0 0 696 B
#6019 RunOnMethodBegin net472 1.19μs 1.2ns 4.65ns 0.104 0 0 658 B

andrewlock avatar Sep 10 '24 21:09 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 (6019) (11.007M)   : 0, 11007468
    master (11.117M)   : 0, 11117260
    benchmarks/2.9.0 (11.038M)   : 0, 11038036

    section Automatic
    This PR (6019) (7.229M)   : 0, 7229077
    master (7.226M)   : 0, 7225635
    benchmarks/2.9.0 (7.724M)   : 0, 7723503

    section Trace stats
    master (7.449M)   : 0, 7449286

    section Manual
    master (10.953M)   : 0, 10953495

    section Manual + Automatic
    This PR (6019) (6.721M)   : 0, 6721062
    master (6.666M)   : 0, 6665540

    section DD_TRACE_ENABLED=0
    master (10.150M)   : 0, 10149876


gantt
    title Throughput Linux arm64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (6019) (9.615M)   : 0, 9614608
    master (9.513M)   : 0, 9512712
    benchmarks/2.9.0 (9.579M)   : 0, 9578713

    section Automatic
    This PR (6019) (6.523M)   : 0, 6523463
    master (6.446M)   : 0, 6446446

    section Trace stats
    master (6.488M)   : 0, 6487585

    section Manual
    master (9.490M)   : 0, 9490394

    section Manual + Automatic
    This PR (6019) (5.973M)   : 0, 5973436
    master (6.008M)   : 0, 6008073

    section DD_TRACE_ENABLED=0
    master (8.952M)   : 0, 8951696


gantt
    title Throughput Windows x64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (6019) (9.734M)   : 0, 9733503
    master (9.705M)   : 0, 9704662
    benchmarks/2.9.0 (9.814M)   : 0, 9814080

    section Automatic
    This PR (6019) (6.431M)   : 0, 6431249
    master (6.564M)   : 0, 6564332
    benchmarks/2.9.0 (7.108M)   : 0, 7108110

    section Trace stats
    master (7.046M)   : 0, 7046369

    section Manual
    master (9.762M)   : 0, 9761737

    section Manual + Automatic
    This PR (6019) (5.945M)   : 0, 5944883
    master (6.099M)   : 0, 6099190

    section DD_TRACE_ENABLED=0
    master (9.212M)   : 0, 9212142

andrewlock avatar Sep 11 '24 11:09 andrewlock

Snapshots difference summary

The following differences have been observed in committed snapshots. It is meant to help the reviewer. The diff is simplistic, so please check some files anyway while we improve it.

github-actions[bot] avatar Oct 23 '24 15:10 github-actions[bot]