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

[ASM] Fix benchmarks AppSecBodyBenchmarks: have a trace context to avoid null reference exceptions #6274

Merged
merged 1 commit into from
Nov 13, 2024

Conversation

anna-git
Copy link
Contributor

@anna-git anna-git commented Nov 13, 2024

Summary of changes

Not having a trace context generates a crash at

var samplingPriority = localRootSpan.Context.TraceContext.GetOrMakeSamplingDecision();

which in turn generates a huge amount of error logs saturating the server's disk

Reason for change

Fix benchmark creating a trace context.
https://datadoghq.atlassian.net/browse/APPSEC-55826

Implementation details

Test coverage

Other details

Would be nice to monitor error logs in benchmarks in CI

@github-actions github-actions bot added area:asm area:tests unit tests, integration tests labels Nov 13, 2024
@datadog-ddstaging
Copy link

datadog-ddstaging bot commented Nov 13, 2024

Datadog Report

Branch report: anna/asm/fix-benchmarks
Commit report: a1051a1
Test service: dd-trace-dotnet

❌ 6 Failed (0 Known Flaky), 369417 Passed, 2092 Skipped, 15h 19m 27.15s Total Time

❌ Failed Tests (6)

This report shows up to 5 failed tests.

  • AllCycleMoreComplexBody - Benchmarks.Trace.Asm.AppSecBodyBenchmark - Details

  • AllCycleMoreComplexBody - Benchmarks.Trace.Asm.AppSecBodyBenchmark - Details

  • AllCycleMoreComplexBody - Benchmarks.Trace.Asm.AppSecBodyBenchmark - Details

  • AllCycleSimpleBody - Benchmarks.Trace.Asm.AppSecBodyBenchmark - Details

  • AllCycleSimpleBody - Benchmarks.Trace.Asm.AppSecBodyBenchmark - Details

@andrewlock
Copy link
Member

Benchmarks Report for tracer 🐌

Benchmarks for #6274 compared to master:

  • 2 benchmarks are faster, with geometric mean 1.133
  • 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 ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartStopWithChild net6.0 8.05μs 43.6ns 235ns 0.0158 0.00792 0 5.61 KB
master StartStopWithChild netcoreapp3.1 10.1μs 54.9ns 296ns 0.021 0.0105 0 5.8 KB
master StartStopWithChild net472 16.4μs 43.9ns 170ns 1.03 0.303 0.0901 6.22 KB
#6274 StartStopWithChild net6.0 7.91μs 43.7ns 255ns 0.0151 0.00757 0 5.61 KB
#6274 StartStopWithChild netcoreapp3.1 9.94μs 51.1ns 240ns 0.0201 0.0101 0 5.8 KB
#6274 StartStopWithChild net472 16.4μs 47.7ns 185ns 1.05 0.315 0.116 6.21 KB
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 486μs 222ns 799ns 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 646μs 247ns 955ns 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces net472 843μs 580ns 2.25μs 0.419 0 0 3.3 KB
#6274 WriteAndFlushEnrichedTraces net6.0 488μs 376ns 1.46μs 0 0 0 2.7 KB
#6274 WriteAndFlushEnrichedTraces netcoreapp3.1 673μs 225ns 841ns 0 0 0 2.7 KB
#6274 WriteAndFlushEnrichedTraces net472 837μs 580ns 2.25μs 0.422 0 0 3.3 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 198μs 1.16μs 10.9μs 0.2 0 0 18.73 KB
master SendRequest netcoreapp3.1 229μs 1.42μs 14μs 0.206 0 0 20.89 KB
master SendRequest net472 8.3E‑05ns 6.89E‑05ns 0.000248ns 0 0 0 0 b
#6274 SendRequest net6.0 202μs 1.16μs 9.38μs 0.196 0 0 18.73 KB
#6274 SendRequest netcoreapp3.1 223μs 1.26μs 9.15μs 0.211 0 0 20.89 KB
#6274 SendRequest net472 0.000698ns 0.000208ns 0.000777ns 0 0 0 0 b
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master WriteAndFlushEnrichedTraces net6.0 602μs 3.43μs 30.9μs 0.558 0 0 41.82 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 676μs 3.26μs 12.6μs 0.349 0 0 41.78 KB
master WriteAndFlushEnrichedTraces net472 867μs 3.74μs 14.5μs 8.25 2.6 0.434 53.27 KB
#6274 WriteAndFlushEnrichedTraces net6.0 575μs 2.99μs 14.3μs 0.556 0 0 41.78 KB
#6274 WriteAndFlushEnrichedTraces netcoreapp3.1 692μs 3.11μs 11.6μs 0.342 0 0 41.76 KB
#6274 WriteAndFlushEnrichedTraces net472 865μs 3.96μs 15.8μs 8.25 2.6 0.434 53.31 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.23μs 1.52ns 5.87ns 0.0145 0 0 1.02 KB
master ExecuteNonQuery netcoreapp3.1 1.77μs 0.875ns 3.27ns 0.0133 0 0 1.02 KB
master ExecuteNonQuery net472 2.11μs 1.33ns 4.97ns 0.156 0.00106 0 987 B
#6274 ExecuteNonQuery net6.0 1.18μs 0.772ns 2.78ns 0.0143 0 0 1.02 KB
#6274 ExecuteNonQuery netcoreapp3.1 1.78μs 1.39ns 5.37ns 0.0133 0 0 1.02 KB
#6274 ExecuteNonQuery net472 2.06μs 2.21ns 8.26ns 0.156 0.00104 0 987 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.23μs 0.403ns 1.51ns 0.0136 0 0 976 B
master CallElasticsearch netcoreapp3.1 1.55μs 0.864ns 3.35ns 0.0131 0 0 976 B
master CallElasticsearch net472 2.48μs 2.6ns 10.1ns 0.157 0 0 995 B
master CallElasticsearchAsync net6.0 1.24μs 0.543ns 2.1ns 0.013 0 0 952 B
master CallElasticsearchAsync netcoreapp3.1 1.6μs 0.683ns 2.55ns 0.0137 0 0 1.02 KB
master CallElasticsearchAsync net472 2.61μs 2.81ns 10.9ns 0.167 0 0 1.05 KB
#6274 CallElasticsearch net6.0 1.37μs 0.931ns 3.61ns 0.0135 0 0 976 B
#6274 CallElasticsearch netcoreapp3.1 1.61μs 3.9ns 14.6ns 0.0128 0 0 976 B
#6274 CallElasticsearch net472 2.65μs 2.33ns 9.02ns 0.158 0 0 995 B
#6274 CallElasticsearchAsync net6.0 1.34μs 0.806ns 3.02ns 0.0134 0 0 952 B
#6274 CallElasticsearchAsync netcoreapp3.1 1.66μs 0.57ns 2.05ns 0.0141 0 0 1.02 KB
#6274 CallElasticsearchAsync net472 2.58μs 2.41ns 9.33ns 0.166 0 0 1.05 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.29μs 0.685ns 2.56ns 0.0135 0 0 952 B
master ExecuteAsync netcoreapp3.1 1.67μs 1.73ns 6.47ns 0.0125 0 0 952 B
master ExecuteAsync net472 1.84μs 0.699ns 2.61ns 0.145 0 0 915 B
#6274 ExecuteAsync net6.0 1.32μs 0.992ns 3.84ns 0.0132 0 0 952 B
#6274 ExecuteAsync netcoreapp3.1 1.67μs 0.717ns 2.68ns 0.0127 0 0 952 B
#6274 ExecuteAsync net472 1.81μs 0.41ns 1.54ns 0.145 0 0 915 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 4.46μs 1.22ns 4.57ns 0.0313 0 0 2.31 KB
master SendAsync netcoreapp3.1 5.2μs 1.63ns 6.3ns 0.039 0 0 2.85 KB
master SendAsync net472 7.52μs 2.64ns 10.2ns 0.495 0 0 3.12 KB
#6274 SendAsync net6.0 4.34μs 1.58ns 5.7ns 0.0324 0 0 2.31 KB
#6274 SendAsync netcoreapp3.1 5.08μs 2.58ns 9.64ns 0.0378 0 0 2.85 KB
#6274 SendAsync net472 7.39μs 1.56ns 5.85ns 0.494 0 0 3.12 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.48μs 1ns 3.76ns 0.0231 0 0 1.64 KB
master EnrichedLog netcoreapp3.1 2.32μs 1.88ns 7.05ns 0.022 0 0 1.64 KB
master EnrichedLog net472 2.64μs 2ns 7.74ns 0.249 0 0 1.57 KB
#6274 EnrichedLog net6.0 1.62μs 0.827ns 3.2ns 0.0234 0 0 1.64 KB
#6274 EnrichedLog netcoreapp3.1 2.19μs 1.35ns 5.07ns 0.0219 0 0 1.64 KB
#6274 EnrichedLog net472 2.6μs 1.62ns 6.29ns 0.249 0 0 1.57 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 119μs 95.3ns 369ns 0.0594 0 0 4.28 KB
master EnrichedLog netcoreapp3.1 122μs 175ns 632ns 0 0 0 4.28 KB
master EnrichedLog net472 154μs 177ns 685ns 0.688 0.229 0 4.46 KB
#6274 EnrichedLog net6.0 122μs 249ns 965ns 0.061 0 0 4.28 KB
#6274 EnrichedLog netcoreapp3.1 124μs 204ns 791ns 0 0 0 4.28 KB
#6274 EnrichedLog net472 153μs 175ns 677ns 0.691 0.23 0 4.46 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 3.04μs 13.8ns 55.2ns 0.0302 0 0 2.2 KB
master EnrichedLog netcoreapp3.1 4.23μs 3.92ns 15.2ns 0.0295 0 0 2.2 KB
master EnrichedLog net472 4.91μs 1.62ns 6.27ns 0.32 0 0 2.02 KB
#6274 EnrichedLog net6.0 2.93μs 0.624ns 2.33ns 0.0309 0 0 2.2 KB
#6274 EnrichedLog netcoreapp3.1 4.25μs 1.12ns 4.32ns 0.0293 0 0 2.2 KB
#6274 EnrichedLog net472 4.84μs 1.33ns 5.15ns 0.319 0 0 2.02 KB
Benchmarks.Trace.RedisBenchmark - Faster 🎉 Same allocations ✔️

Faster 🎉 in #6274

Benchmark base/diff Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.RedisBenchmark.SendReceive‑net6.0 1.119 1,446.27 1,292.41

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendReceive net6.0 1.45μs 0.771ns 2.99ns 0.0159 0 0 1.14 KB
master SendReceive netcoreapp3.1 1.78μs 0.775ns 3ns 0.0151 0 0 1.14 KB
master SendReceive net472 2.17μs 4.16ns 16.1ns 0.183 0 0 1.16 KB
#6274 SendReceive net6.0 1.29μs 0.738ns 2.86ns 0.0162 0 0 1.14 KB
#6274 SendReceive netcoreapp3.1 1.75μs 0.795ns 3.08ns 0.0158 0 0 1.14 KB
#6274 SendReceive net472 2.11μs 1.16ns 4.51ns 0.183 0 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.8μs 1.58ns 5.9ns 0.0224 0 0 1.6 KB
master EnrichedLog netcoreapp3.1 3.9μs 2.96ns 11.5ns 0.0214 0 0 1.65 KB
master EnrichedLog net472 4.39μs 2.57ns 9.96ns 0.323 0 0 2.04 KB
#6274 EnrichedLog net6.0 2.8μs 0.977ns 3.65ns 0.021 0 0 1.6 KB
#6274 EnrichedLog netcoreapp3.1 3.92μs 1.73ns 6.71ns 0.0216 0 0 1.65 KB
#6274 EnrichedLog net472 4.37μs 3.51ns 13.6ns 0.323 0 0 2.04 KB
Benchmarks.Trace.SpanBenchmark - Faster 🎉 Same allocations ✔️

Faster 🎉 in #6274

Benchmark base/diff Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.SpanBenchmark.StartFinishSpan‑netcoreapp3.1 1.147 639.46 557.41

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartFinishSpan net6.0 406ns 0.284ns 1.1ns 0.00803 0 0 576 B
master StartFinishSpan netcoreapp3.1 640ns 0.846ns 3.28ns 0.00779 0 0 576 B
master StartFinishSpan net472 733ns 0.76ns 2.63ns 0.0916 0 0 578 B
master StartFinishScope net6.0 492ns 0.575ns 2.07ns 0.00976 0 0 696 B
master StartFinishScope netcoreapp3.1 736ns 0.596ns 2.31ns 0.00911 0 0 696 B
master StartFinishScope net472 873ns 1.52ns 5.48ns 0.104 0 0 658 B
#6274 StartFinishSpan net6.0 406ns 0.165ns 0.616ns 0.00816 0 0 576 B
#6274 StartFinishSpan netcoreapp3.1 558ns 0.268ns 1ns 0.00776 0 0 576 B
#6274 StartFinishSpan net472 713ns 0.42ns 1.63ns 0.0916 0 0 578 B
#6274 StartFinishScope net6.0 490ns 0.531ns 2.06ns 0.00978 0 0 696 B
#6274 StartFinishScope netcoreapp3.1 743ns 0.575ns 2.23ns 0.00927 0 0 696 B
#6274 StartFinishScope net472 921ns 0.484ns 1.88ns 0.104 0 0 658 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 600ns 0.444ns 1.72ns 0.00965 0 0 696 B
master RunOnMethodBegin netcoreapp3.1 954ns 1.8ns 6.98ns 0.00911 0 0 696 B
master RunOnMethodBegin net472 1.12μs 0.714ns 2.76ns 0.104 0 0 658 B
#6274 RunOnMethodBegin net6.0 662ns 1.54ns 5.98ns 0.00966 0 0 696 B
#6274 RunOnMethodBegin netcoreapp3.1 881ns 1.07ns 4.13ns 0.00926 0 0 696 B
#6274 RunOnMethodBegin net472 1.2μs 1.19ns 4.6ns 0.104 0 0 658 B

@anna-git anna-git marked this pull request as ready for review November 13, 2024 12:40
@anna-git anna-git requested a review from a team as a code owner November 13, 2024 12:40
Copy link
Member

@andrewlock andrewlock left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If it works, :shipit:

@anna-git
Copy link
Contributor Author

If it works, :shipit:

Checked the logs of this run and no null ref exception 🥳

@andrewlock
Copy link
Member

Throughput/Crank Report ⚡

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 (6274) (11.293M)   : 0, 11292952
    master (11.082M)   : 0, 11082495
    benchmarks/2.9.0 (11.033M)   : 0, 11032866

    section Automatic
    This PR (6274) (7.231M)   : 0, 7231371
    master (7.157M)   : 0, 7156676
    benchmarks/2.9.0 (7.786M)   : 0, 7785853

    section Trace stats
    master (7.487M)   : 0, 7486935

    section Manual
    master (11.095M)   : 0, 11094549

    section Manual + Automatic
    This PR (6274) (6.728M)   : 0, 6727801
    master (6.662M)   : 0, 6661600

    section DD_TRACE_ENABLED=0
    master (10.306M)   : 0, 10305980

Loading
gantt
    title Throughput Linux arm64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (6274) (9.585M)   : 0, 9584642
    master (9.147M)   : 0, 9147171
    benchmarks/2.9.0 (9.495M)   : 0, 9494821

    section Automatic
    This PR (6274) (6.384M)   : 0, 6383880
    master (6.241M)   : 0, 6240685

    section Trace stats
    master (6.456M)   : 0, 6455873

    section Manual
    master (9.565M)   : 0, 9564721

    section Manual + Automatic
    This PR (6274) (5.836M)   : 0, 5835885
    master (6.070M)   : 0, 6069625

    section DD_TRACE_ENABLED=0
    master (8.975M)   : 0, 8975239

Loading
gantt
    title Throughput Windows x64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (6274) (9.498M)   : 0, 9497856
    master (9.861M)   : 0, 9860504
    benchmarks/2.9.0 (10.020M)   : 0, 10019592

    section Automatic
    This PR (6274) (6.379M)   : 0, 6378624
    master (6.281M)   : 0, 6280856
    benchmarks/2.9.0 (7.255M)   : 0, 7255257

    section Trace stats
    master (6.858M)   : 0, 6857519

    section Manual
    master (9.497M)   : 0, 9496807

    section Manual + Automatic
    This PR (6274) (5.930M)   : 0, 5930399
    master (5.679M)   : 0, 5679163

    section DD_TRACE_ENABLED=0
    master (8.903M)   : 0, 8902951

Loading

@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 (6274) - mean (69ms)  : 67, 72
     .   : milestone, 69,
    master - mean (69ms)  : 67, 71
     .   : milestone, 69,

    section CallTarget+Inlining+NGEN
    This PR (6274) - mean (1,112ms)  : 1094, 1131
     .   : milestone, 1112,
    master - mean (1,107ms)  : 1086, 1127
     .   : milestone, 1107,

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

    section CallTarget+Inlining+NGEN
    This PR (6274) - mean (778ms)  : 763, 793
     .   : milestone, 778,
    master - mean (778ms)  : 764, 792
     .   : milestone, 778,

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

    section CallTarget+Inlining+NGEN
    This PR (6274) - mean (733ms)  : 718, 749
     .   : milestone, 733,
    master - mean (730ms)  : 715, 745
     .   : milestone, 730,

Loading

@anna-git anna-git merged commit 973a84e into master Nov 13, 2024
76 of 78 checks passed
@anna-git anna-git deleted the anna/asm/fix-benchmarks branch November 13, 2024 13:32
@github-actions github-actions bot added this to the vNext-v3 milestone Nov 13, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area:asm area:tests unit tests, integration tests
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants