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

Add rate limit for the log written by `TraceRateLimiter`

Open andrewlock opened this issue 1 year ago • 4 comments

Summary of changes

Add a rate limit for the TraceRateLimiter log file written when a trace is dropped

Reason for change

We potentially spam customers logs with the warning. The log is expected to be written precisely when the service is under load, so we expect to see it a lot if it's triggered. This could cause customer log files to rapidly fill up.

Implementation details

  • Add a boolean that is set when we write the log
  • Add a method that is called when the interval is reset
  • Add an extra log to describe how many traces were filtered

At worst, this means we write two logs per interval, instead of an unbounded number.

Test coverage

I'll check in the unit test logs to make sure they're not there any more, I think this is good enough

andrewlock avatar Feb 22 '24 16:02 andrewlock

Datadog Report

Branch report: andrew/rate-limit-logs Commit report: e9292ef Test service: dd-trace-dotnet

:white_check_mark: 0 Failed, 327914 Passed, 1559 Skipped, 54m 16.85s Wall Time

datadog-ddstaging[bot] avatar Feb 22 '24 16:02 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 (5229) - mean (73ms)  : 67, 78
     .   : milestone, 73,
    master - mean (74ms)  : 65, 83
     .   : milestone, 74,

    section CallTarget+Inlining+NGEN
    This PR (5229) - mean (987ms)  : 965, 1009
     .   : milestone, 987,
    master - mean (985ms)  : 961, 1008
     .   : milestone, 985,


gantt
    title Execution time (ms) FakeDbCommand (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5229) - mean (111ms)  : 108, 114
     .   : milestone, 111,
    master - mean (118ms)  : 96, 140
     .   : milestone, 118,

    section CallTarget+Inlining+NGEN
    This PR (5229) - mean (718ms)  : 703, 733
     .   : milestone, 718,
    master - mean (713ms)  : 691, 735
     .   : milestone, 713,


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

    section CallTarget+Inlining+NGEN
    This PR (5229) - mean (673ms)  : 647, 699
     .   : milestone, 673,
    master - mean (671ms)  : 647, 694
     .   : milestone, 671,


gantt
    title Execution time (ms) HttpMessageHandler (.NET Framework 4.6.2) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5229) - mean (188ms)  : 184, 192
     .   : milestone, 188,
    master - mean (188ms)  : 182, 193
     .   : milestone, 188,

    section CallTarget+Inlining+NGEN
    This PR (5229) - mean (1,069ms)  : 1050, 1088
     .   : milestone, 1069,
    master - mean (1,063ms)  : 1038, 1089
     .   : milestone, 1063,


gantt
    title Execution time (ms) HttpMessageHandler (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5229) - mean (272ms)  : 267, 276
     .   : milestone, 272,
    master - mean (269ms)  : 262, 276
     .   : milestone, 269,

    section CallTarget+Inlining+NGEN
    This PR (5229) - mean (870ms)  : 844, 896
     .   : milestone, 870,
    master - mean (861ms)  : 839, 884
     .   : milestone, 861,


gantt
    title Execution time (ms) HttpMessageHandler (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5229) - mean (261ms)  : 257, 265
     .   : milestone, 261,
    master - mean (258ms)  : 250, 265
     .   : milestone, 258,

    section CallTarget+Inlining+NGEN
    This PR (5229) - mean (853ms)  : 826, 880
     .   : milestone, 853,
    master - mean (855ms)  : 834, 876
     .   : milestone, 855,

andrewlock avatar Feb 22 '24 16:02 andrewlock

Benchmarks Report :snail:

Benchmarks for #5229 compared to master:

  • 1 benchmarks are faster, with geometric mean 1.128
  • 2 benchmarks are slower, with geometric mean 1.146
  • 2 benchmarks have fewer allocations
  • 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.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.52μs 47.9ns 346ns 0.0249 0.0125 0 7.49 KB
master StartStopWithChild netcoreapp3.1 10.5μs 56.9ns 327ns 0.0355 0.0152 0 7.58 KB
master StartStopWithChild net472 16.7μs 67.1ns 260ns 1.33 0.352 0.0922 7.96 KB
#5229 StartStopWithChild net6.0 8.69μs 47.8ns 299ns 0.0425 0.0212 0 7.49 KB
#5229 StartStopWithChild netcoreapp3.1 10.7μs 59.8ns 378ns 0.0277 0.0111 0 7.59 KB
#5229 StartStopWithChild net472 16.8μs 64.6ns 242ns 1.33 0.336 0.109 7.95 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 444μs 285ns 1.1μs 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 607μs 294ns 1.14μs 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces net472 815μs 261ns 978ns 0.403 0 0 3.3 KB
#5229 WriteAndFlushEnrichedTraces net6.0 464μs 318ns 1.19μs 0 0 0 2.7 KB
#5229 WriteAndFlushEnrichedTraces netcoreapp3.1 606μs 143ns 553ns 0 0 0 2.7 KB
#5229 WriteAndFlushEnrichedTraces net472 815μs 411ns 1.59μs 0.406 0 0 3.3 KB
Benchmarks.Trace.Asm.AppSecBodyBenchmark - 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 AllCycleSimpleBody net6.0 40.8μs 50.1ns 194ns 0.0204 0 0 2.36 KB
master AllCycleSimpleBody netcoreapp3.1 43.1μs 11ns 41.2ns 0.0216 0 0 2.34 KB
master AllCycleSimpleBody net472 46.9μs 18.4ns 71.1ns 0.372 0 0 2.41 KB
master AllCycleMoreComplexBody net6.0 213μs 34.9ns 126ns 0.107 0 0 9.84 KB
master AllCycleMoreComplexBody netcoreapp3.1 226μs 453ns 1.75μs 0.112 0 0 9.73 KB
master AllCycleMoreComplexBody net472 240μs 83.7ns 324ns 1.56 0 0 9.91 KB
master ObjectExtractorSimpleBody net6.0 149ns 0.121ns 0.452ns 0.00392 0 0 280 B
master ObjectExtractorSimpleBody netcoreapp3.1 198ns 0.0475ns 0.171ns 0.00369 0 0 272 B
master ObjectExtractorSimpleBody net472 176ns 0.0914ns 0.342ns 0.0446 0 0 281 B
master ObjectExtractorMoreComplexBody net6.0 3.01μs 2.21ns 8.56ns 0.0528 0 0 3.78 KB
master ObjectExtractorMoreComplexBody netcoreapp3.1 3.97μs 1.85ns 7.17ns 0.0503 0 0 3.69 KB
master ObjectExtractorMoreComplexBody net472 3.78μs 1.57ns 5.86ns 0.602 0.00565 0 3.8 KB
#5229 AllCycleSimpleBody net6.0 40.7μs 58.3ns 226ns 0.0205 0 0 2.36 KB
#5229 AllCycleSimpleBody netcoreapp3.1 44.2μs 103ns 398ns 0.0219 0 0 2.34 KB
#5229 AllCycleSimpleBody net472 47μs 20.7ns 80.3ns 0.376 0 0 2.41 KB
#5229 AllCycleMoreComplexBody net6.0 214μs 258ns 1μs 0.106 0 0 9.84 KB
#5229 AllCycleMoreComplexBody netcoreapp3.1 224μs 116ns 448ns 0.112 0 0 9.73 KB
#5229 AllCycleMoreComplexBody net472 239μs 60.3ns 217ns 1.56 0 0 9.91 KB
#5229 ObjectExtractorSimpleBody net6.0 154ns 0.0813ns 0.315ns 0.00397 0 0 280 B
#5229 ObjectExtractorSimpleBody netcoreapp3.1 209ns 0.0853ns 0.33ns 0.00368 0 0 272 B
#5229 ObjectExtractorSimpleBody net472 173ns 0.128ns 0.477ns 0.0446 0 0 281 B
#5229 ObjectExtractorMoreComplexBody net6.0 2.98μs 1.52ns 5.67ns 0.0538 0 0 3.78 KB
#5229 ObjectExtractorMoreComplexBody netcoreapp3.1 3.94μs 1.67ns 6.25ns 0.0496 0 0 3.69 KB
#5229 ObjectExtractorMoreComplexBody net472 3.82μs 2.55ns 9.86ns 0.601 0.00571 0 3.8 KB
Benchmarks.Trace.Asm.AppSecEncoderBenchmark - 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 EncodeArgs net6.0 53μs 46.1ns 179ns 0.423 0 0 30.94 KB
master EncodeArgs netcoreapp3.1 69.3μs 63.5ns 238ns 0.413 0 0 31.47 KB
master EncodeArgs net472 85.2μs 43.1ns 161ns 5.12 0.0853 0 32.27 KB
master EncodeLegacyArgs net6.0 128μs 177ns 637ns 0.439 0 0 33.89 KB
master EncodeLegacyArgs netcoreapp3.1 158μs 158ns 592ns 0.465 0 0 34.08 KB
master EncodeLegacyArgs net472 212μs 241ns 933ns 5.51 0.424 0 34.99 KB
#5229 EncodeArgs net6.0 52.8μs 68.4ns 265ns 0.423 0 0 30.94 KB
#5229 EncodeArgs netcoreapp3.1 70.9μs 81ns 314ns 0.42 0 0 31.47 KB
#5229 EncodeArgs net472 84.1μs 34.9ns 130ns 5.09 0.0848 0 32.27 KB
#5229 EncodeLegacyArgs net6.0 127μs 267ns 1.04μs 0.434 0 0 33.89 KB
#5229 EncodeLegacyArgs netcoreapp3.1 158μs 312ns 1.17μs 0.396 0 0 34.09 KB
#5229 EncodeLegacyArgs net472 210μs 153ns 571ns 5.5 0.423 0 34.99 KB
Benchmarks.Trace.Asm.AppSecWafBenchmark - 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 RunWafRealisticBenchmark net6.0 190μs 103ns 400ns 0.0948 0 0 6.51 KB
master RunWafRealisticBenchmark netcoreapp3.1 204μs 232ns 900ns 0 0 0 6.49 KB
master RunWafRealisticBenchmark net472 225μs 181ns 701ns 1.01 0 0 6.59 KB
master RunWafRealisticBenchmarkWithAttack net6.0 127μs 83.2ns 322ns 0.0632 0 0 4.15 KB
master RunWafRealisticBenchmarkWithAttack netcoreapp3.1 134μs 410ns 1.59μs 0 0 0 4.15 KB
master RunWafRealisticBenchmarkWithAttack net472 149μs 47.5ns 184ns 0.597 0 0 4.19 KB
#5229 RunWafRealisticBenchmark net6.0 190μs 82.1ns 318ns 0 0 0 6.51 KB
#5229 RunWafRealisticBenchmark netcoreapp3.1 205μs 230ns 891ns 0 0 0 6.49 KB
#5229 RunWafRealisticBenchmark net472 222μs 72.8ns 262ns 1.01 0 0 6.59 KB
#5229 RunWafRealisticBenchmarkWithAttack net6.0 125μs 56.6ns 219ns 0.063 0 0 4.15 KB
#5229 RunWafRealisticBenchmarkWithAttack netcoreapp3.1 134μs 100ns 374ns 0 0 0 4.14 KB
#5229 RunWafRealisticBenchmarkWithAttack net472 146μs 114ns 441ns 0.656 0 0 4.19 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 173μs 235ns 911ns 0.26 0 0 18.26 KB
master SendRequest netcoreapp3.1 192μs 261ns 1.01μs 0.19 0 0 20.42 KB
master SendRequest net472 0.000211ns 0.000101ns 0.000365ns 0 0 0 0 b
#5229 SendRequest net6.0 173μs 159ns 616ns 0.173 0 0 18.26 KB
#5229 SendRequest netcoreapp3.1 193μs 228ns 883ns 0.193 0 0 20.42 KB
#5229 SendRequest net472 0.000272ns 0.000126ns 0.000489ns 0 0 0 0 b
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark - Same speed :heavy_check_mark: Fewer allocations :tada:

Fewer allocations :tada: in #5229

Benchmark Base Allocated Diff Allocated Change Change %
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark.WriteAndFlushEnrichedTraces‑net6.0 41.84 KB 41.52 KB -322 B -0.77%

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master WriteAndFlushEnrichedTraces net6.0 558μs 595ns 2.23μs 0.543 0 0 41.84 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 656μs 633ns 2.45μs 0.327 0 0 41.8 KB
master WriteAndFlushEnrichedTraces net472 841μs 3.92μs 15.2μs 8.58 2.45 0.408 53.24 KB
#5229 WriteAndFlushEnrichedTraces net6.0 565μs 525ns 2.03μs 0.551 0 0 41.52 KB
#5229 WriteAndFlushEnrichedTraces netcoreapp3.1 661μs 2.25μs 8.12μs 0.326 0 0 41.73 KB
#5229 WriteAndFlushEnrichedTraces net472 827μs 2.78μs 10.8μs 8.45 2.53 0.422 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.14μs 0.541ns 2.02ns 0.0108 0 0 776 B
master ExecuteNonQuery netcoreapp3.1 1.47μs 1.43ns 5.53ns 0.0103 0 0 776 B
master ExecuteNonQuery net472 1.76μs 1.41ns 5.08ns 0.117 0 0 738 B
#5229 ExecuteNonQuery net6.0 1.08μs 0.453ns 1.76ns 0.0108 0 0 776 B
#5229 ExecuteNonQuery netcoreapp3.1 1.53μs 0.715ns 2.77ns 0.0101 0 0 776 B
#5229 ExecuteNonQuery net472 1.84μs 8.35ns 30.1ns 0.117 0 0 738 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.33μs 1.41ns 5.46ns 0.0133 0 0 944 B
master CallElasticsearch netcoreapp3.1 1.59μs 1.87ns 6.98ns 0.0124 0 0 944 B
master CallElasticsearch net472 2.59μs 1.22ns 4.73ns 0.152 0 0 963 B
master CallElasticsearchAsync net6.0 1.33μs 0.698ns 2.7ns 0.0126 0 0 920 B
master CallElasticsearchAsync netcoreapp3.1 1.63μs 1.73ns 6.49ns 0.0137 0 0 992 B
master CallElasticsearchAsync net472 2.62μs 0.66ns 2.38ns 0.161 0 0 1.02 KB
#5229 CallElasticsearch net6.0 1.23μs 0.805ns 3.01ns 0.0129 0 0 944 B
#5229 CallElasticsearch netcoreapp3.1 1.52μs 0.494ns 1.85ns 0.0128 0 0 944 B
#5229 CallElasticsearch net472 2.53μs 0.853ns 3.19ns 0.152 0 0 963 B
#5229 CallElasticsearchAsync net6.0 1.31μs 0.873ns 3.27ns 0.0125 0 0 920 B
#5229 CallElasticsearchAsync netcoreapp3.1 1.62μs 0.598ns 2.24ns 0.013 0 0 992 B
#5229 CallElasticsearchAsync net472 2.52μs 0.883ns 3.42ns 0.162 0 0 1.02 KB
Benchmarks.Trace.GraphQLBenchmark - Slower :warning: Same allocations :heavy_check_mark:

Slower :warning: in #5229

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.GraphQLBenchmark.ExecuteAsync‑net472 1.115 1,746.16 1,947.67

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master ExecuteAsync net6.0 1.33μs 0.617ns 2.39ns 0.0126 0 0 920 B
master ExecuteAsync netcoreapp3.1 1.62μs 0.998ns 3.74ns 0.0122 0 0 920 B
master ExecuteAsync net472 1.75μs 0.689ns 2.67ns 0.14 0 0 883 B
#5229 ExecuteAsync net6.0 1.33μs 0.785ns 2.94ns 0.0129 0 0 920 B
#5229 ExecuteAsync netcoreapp3.1 1.59μs 2.04ns 7.9ns 0.0119 0 0 920 B
#5229 ExecuteAsync net472 1.95μs 0.382ns 1.48ns 0.14 0 0 883 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.14μs 0.869ns 3.37ns 0.029 0 0 2.1 KB
master SendAsync netcoreapp3.1 4.82μs 1.36ns 4.9ns 0.0357 0 0 2.64 KB
master SendAsync net472 7.79μs 1.75ns 6.78ns 0.525 0.00389 0 3.31 KB
#5229 SendAsync net6.0 4.06μs 1.54ns 5.75ns 0.0282 0 0 2.1 KB
#5229 SendAsync netcoreapp3.1 5.03μs 1.75ns 6.56ns 0.035 0 0 2.64 KB
#5229 SendAsync net472 7.78μs 3.82ns 14.8ns 0.524 0 0 3.31 KB
Benchmarks.Trace.Iast.StringAspectsBenchmark - Same speed :heavy_check_mark: More allocations :warning:

More allocations :warning: in #5229

Benchmark Base Allocated Diff Allocated Change Change %
Benchmarks.Trace.Iast.StringAspectsBenchmark.StringConcatBenchmark‑net472 57.9 KB 60.49 KB 2.59 KB 4.48%

Fewer allocations :tada: in #5229

Benchmark Base Allocated Diff Allocated Change Change %
Benchmarks.Trace.Iast.StringAspectsBenchmark.StringConcatAspectBenchmark‑net6.0 202.79 KB 201.35 KB -1.44 KB -0.71%

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StringConcatBenchmark net6.0 59.2μs 756ns 7.41μs 0 0 0 43.44 KB
master StringConcatBenchmark netcoreapp3.1 58μs 705ns 6.76μs 0 0 0 42.64 KB
master StringConcatBenchmark net472 38.6μs 148ns 534ns 0 0 0 57.9 KB
master StringConcatAspectBenchmark net6.0 264μs 1.32μs 5.62μs 0 0 0 202.79 KB
master StringConcatAspectBenchmark netcoreapp3.1 287μs 1.13μs 4.66μs 0 0 0 212.17 KB
master StringConcatAspectBenchmark net472 225μs 1.78μs 16.5μs 0 0 0 221.18 KB
#5229 StringConcatBenchmark net6.0 52μs 251ns 1.07μs 0 0 0 43.44 KB
#5229 StringConcatBenchmark netcoreapp3.1 60.6μs 658ns 6.38μs 0 0 0 42.64 KB
#5229 StringConcatBenchmark net472 38μs 98.9ns 342ns 0 0 0 60.49 KB
#5229 StringConcatAspectBenchmark net6.0 256μs 3.2μs 29.2μs 0 0 0 201.35 KB
#5229 StringConcatAspectBenchmark netcoreapp3.1 279μs 1.58μs 10.6μs 0 0 0 212.23 KB
#5229 StringConcatAspectBenchmark net472 232μs 2.58μs 23.3μs 0 0 0 221.18 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.53μs 0.496ns 1.85ns 0.0225 0 0 1.58 KB
master EnrichedLog netcoreapp3.1 2.2μs 1.44ns 5.56ns 0.0217 0 0 1.58 KB
master EnrichedLog net472 2.55μs 3.15ns 12.2ns 0.239 0 0 1.51 KB
#5229 EnrichedLog net6.0 1.44μs 0.876ns 3.28ns 0.022 0 0 1.58 KB
#5229 EnrichedLog netcoreapp3.1 2.22μs 0.897ns 3.36ns 0.0214 0 0 1.58 KB
#5229 EnrichedLog net472 2.59μs 2.47ns 8.91ns 0.239 0 0 1.51 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 116μs 208ns 805ns 0 0 0 4.22 KB
master EnrichedLog netcoreapp3.1 121μs 167ns 623ns 0 0 0 4.22 KB
master EnrichedLog net472 149μs 163ns 631ns 0.67 0.223 0 4.4 KB
#5229 EnrichedLog net6.0 113μs 105ns 394ns 0 0 0 4.22 KB
#5229 EnrichedLog netcoreapp3.1 119μs 58.3ns 218ns 0.0595 0 0 4.22 KB
#5229 EnrichedLog net472 148μs 99.6ns 373ns 0.661 0.22 0 4.4 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.97μs 1.47ns 5.7ns 0.0296 0 0 2.14 KB
master EnrichedLog netcoreapp3.1 4.06μs 2.15ns 8.03ns 0.0283 0 0 2.14 KB
master EnrichedLog net472 4.89μs 4.34ns 16.8ns 0.308 0 0 1.95 KB
#5229 EnrichedLog net6.0 3.04μs 0.779ns 2.92ns 0.0304 0 0 2.14 KB
#5229 EnrichedLog netcoreapp3.1 4.14μs 3.03ns 11.7ns 0.029 0 0 2.14 KB
#5229 EnrichedLog net472 4.93μs 4.26ns 16.5ns 0.31 0 0 1.95 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.4μs 0.813ns 3.15ns 0.0155 0 0 1.11 KB
master SendReceive netcoreapp3.1 1.78μs 0.766ns 2.76ns 0.0142 0 0 1.11 KB
master SendReceive net472 2.17μs 1.76ns 6.59ns 0.178 0 0 1.12 KB
#5229 SendReceive net6.0 1.29μs 0.594ns 2.22ns 0.0155 0 0 1.11 KB
#5229 SendReceive netcoreapp3.1 1.8μs 1.29ns 4.99ns 0.0143 0 0 1.11 KB
#5229 SendReceive net472 2.12μs 2.13ns 8.25ns 0.178 0 0 1.12 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.78μs 0.897ns 3.48ns 0.021 0 0 1.54 KB
master EnrichedLog netcoreapp3.1 3.93μs 3.42ns 13.3ns 0.0216 0 0 1.58 KB
master EnrichedLog net472 4.39μs 2.22ns 8.58ns 0.313 0 0 1.97 KB
#5229 EnrichedLog net6.0 2.78μs 0.591ns 2.21ns 0.021 0 0 1.54 KB
#5229 EnrichedLog netcoreapp3.1 3.87μs 0.79ns 2.85ns 0.0215 0 0 1.58 KB
#5229 EnrichedLog net472 4.25μs 1.69ns 6.1ns 0.312 0 0 1.97 KB
Benchmarks.Trace.SpanBenchmark - Slower :warning: Same allocations :heavy_check_mark:

Slower :warning: in #5229

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.SpanBenchmark.StartFinishSpan‑net6.0 1.178 447.51 527.02

Faster :tada: in #5229

Benchmark base/diff Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.SpanBenchmark.StartFinishScope‑net6.0 1.128 669.41 593.49

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartFinishSpan net6.0 447ns 0.75ns 2.9ns 0.00767 0 0 544 B
master StartFinishSpan netcoreapp3.1 675ns 1.55ns 5.6ns 0.00743 0 0 544 B
master StartFinishSpan net472 720ns 1.24ns 4.8ns 0.0867 0 0 546 B
master StartFinishScope net6.0 669ns 0.926ns 3.59ns 0.00928 0 0 664 B
master StartFinishScope netcoreapp3.1 799ns 0.698ns 2.42ns 0.00885 0 0 664 B
master StartFinishScope net472 930ns 2.31ns 8.94ns 0.0991 0 0 626 B
#5229 StartFinishSpan net6.0 527ns 0.695ns 2.6ns 0.00771 0 0 544 B
#5229 StartFinishSpan netcoreapp3.1 686ns 1.33ns 5.15ns 0.00727 0 0 544 B
#5229 StartFinishSpan net472 731ns 1.52ns 5.89ns 0.0864 0 0 546 B
#5229 StartFinishScope net6.0 593ns 1.01ns 3.93ns 0.00938 0 0 664 B
#5229 StartFinishScope netcoreapp3.1 787ns 3.13ns 12.1ns 0.00897 0 0 664 B
#5229 StartFinishScope net472 888ns 2.75ns 10.6ns 0.0992 0 0 626 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 673ns 1.19ns 4.62ns 0.00935 0 0 664 B
master RunOnMethodBegin netcoreapp3.1 1E+03ns 1.84ns 7.13ns 0.00898 0 0 664 B
master RunOnMethodBegin net472 1.14μs 1.98ns 7.67ns 0.0994 0 0 626 B
#5229 RunOnMethodBegin net6.0 730ns 1.36ns 5.26ns 0.00911 0 0 664 B
#5229 RunOnMethodBegin netcoreapp3.1 969ns 3.63ns 14.1ns 0.00864 0 0 664 B
#5229 RunOnMethodBegin net472 1.07μs 1.46ns 5.67ns 0.0993 0 0 626 B

andrewlock avatar Feb 22 '24 17:02 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 (5229) (10.953M)   : 0, 10953098
    master (11.301M)   : 0, 11301171
    benchmarks/2.9.0 (11.048M)   : 0, 11047662

    section Automatic
    This PR (5229) (7.682M)   : 0, 7682451
    master (7.786M)   : 0, 7786387
    benchmarks/2.9.0 (7.876M)   : 0, 7876321

    section Trace stats
    This PR (5229) (8.088M)   : 0, 8088370
    master (8.162M)   : 0, 8161989

    section Manual
    This PR (5229) (9.672M)   : 0, 9672310
    master (9.926M)   : 0, 9926297

    section Manual + Automatic
    This PR (5229) (7.326M)   : 0, 7325838
    master (7.412M)   : 0, 7411648

    section Version Conflict
    This PR (5229) (6.525M)   : 0, 6524714
    master (6.730M)   : 0, 6730224


gantt
    title Throughput Linux arm64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (5229) (9.432M)   : 0, 9432101
    master (9.529M)   : 0, 9529282
    benchmarks/2.9.0 (9.382M)   : 0, 9381950

    section Automatic
    This PR (5229) (6.652M)   : 0, 6651729
    master (6.506M)   : 0, 6505611

    section Trace stats
    This PR (5229) (6.844M)   : 0, 6843619
    master (6.940M)   : 0, 6940301

    section Manual
    This PR (5229) (8.143M)   : 0, 8142761
    master (8.383M)   : 0, 8383218

    section Manual + Automatic
    This PR (5229) (6.071M)   : 0, 6071105
    master (6.263M)   : 0, 6262794

    section Version Conflict
    This PR (5229) (5.683M)   : 0, 5682586
    master (5.698M)   : 0, 5698114


gantt
    title Throughput Windows x64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (5229) (9.856M)   : 0, 9856410
    master (10.221M)   : 0, 10221490
    benchmarks/2.9.0 (10.272M)   : 0, 10271759

    section Automatic
    This PR (5229) (7.062M)   : 0, 7061503
    master (7.341M)   : 0, 7340809
    benchmarks/2.9.0 (7.644M)   : 0, 7644353

    section Trace stats
    This PR (5229) (7.347M)   : 0, 7346971
    master (7.697M)   : 0, 7697428

    section Manual
    This PR (5229) (8.673M)   : crit ,0, 8673034
    master (9.139M)   : 0, 9138836

    section Manual + Automatic
    This PR (5229) (6.967M)   : 0, 6966905
    master (7.059M)   : 0, 7058587

    section Version Conflict
    This PR (5229) (6.162M)   : crit ,0, 6162233
    master (6.504M)   : 0, 6503694


gantt
    title Throughput Linux x64 (ASM) (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    master (7.461M)   : 0, 7461396

    section No attack
    master (1.854M)   : 0, 1853890

    section Attack
    master (1.450M)   : 0, 1449724

    section Blocking
    master (3.161M)   : 0, 3160542

    section IAST default
    master (6.464M)   : 0, 6464188

    section IAST full
    master (5.600M)   : 0, 5600403

    section Base vuln
    master (0.918M)   : 0, 917723

    section IAST vuln
    master (0.859M)   : 0, 859223

andrewlock avatar Feb 22 '24 20:02 andrewlock