Add rate limit for the log written by `TraceRateLimiter` #5229

andrewlock · 2024-02-22T16:20:30Z

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

datadog-ddstaging · 2024-02-22T16:38:41Z

Datadog Report

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

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

andrewlock · 2024-02-22T16:59:51Z

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 (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 · 2024-02-22T17:36:23Z

Benchmarks Report 🐌

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 ✔️ Same allocations ✔️

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 ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`WriteAndFlushEnrichedTraces`	net6.0	444μs	285ns	1.1μs	0	2.7 KB
master	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	607μs	294ns	1.14μs	0	2.7 KB
master	`WriteAndFlushEnrichedTraces`	net472	815μs	261ns	978ns	0.403	3.3 KB
#5229	`WriteAndFlushEnrichedTraces`	net6.0	464μs	318ns	1.19μs	0	2.7 KB
#5229	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	606μs	143ns	553ns	0	2.7 KB
#5229	`WriteAndFlushEnrichedTraces`	net472	815μs	411ns	1.59μs	0.406	3.3 KB

Benchmarks.Trace.Asm.AppSecBodyBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Allocated
master	`AllCycleSimpleBody`	net6.0	40.8μs	50.1ns	194ns	0.0204	0	2.36 KB
master	`AllCycleSimpleBody`	netcoreapp3.1	43.1μs	11ns	41.2ns	0.0216	0	2.34 KB
master	`AllCycleSimpleBody`	net472	46.9μs	18.4ns	71.1ns	0.372	0	2.41 KB
master	`AllCycleMoreComplexBody`	net6.0	213μs	34.9ns	126ns	0.107	0	9.84 KB
master	`AllCycleMoreComplexBody`	netcoreapp3.1	226μs	453ns	1.75μs	0.112	0	9.73 KB
master	`AllCycleMoreComplexBody`	net472	240μs	83.7ns	324ns	1.56	0	9.91 KB
master	`ObjectExtractorSimpleBody`	net6.0	149ns	0.121ns	0.452ns	0.00392	0	280 B
master	`ObjectExtractorSimpleBody`	netcoreapp3.1	198ns	0.0475ns	0.171ns	0.00369	0	272 B
master	`ObjectExtractorSimpleBody`	net472	176ns	0.0914ns	0.342ns	0.0446	0	281 B
master	`ObjectExtractorMoreComplexBody`	net6.0	3.01μs	2.21ns	8.56ns	0.0528	0	3.78 KB
master	`ObjectExtractorMoreComplexBody`	netcoreapp3.1	3.97μs	1.85ns	7.17ns	0.0503	0	3.69 KB
master	`ObjectExtractorMoreComplexBody`	net472	3.78μs	1.57ns	5.86ns	0.602	0.00565	3.8 KB
#5229	`AllCycleSimpleBody`	net6.0	40.7μs	58.3ns	226ns	0.0205	0	2.36 KB
#5229	`AllCycleSimpleBody`	netcoreapp3.1	44.2μs	103ns	398ns	0.0219	0	2.34 KB
#5229	`AllCycleSimpleBody`	net472	47μs	20.7ns	80.3ns	0.376	0	2.41 KB
#5229	`AllCycleMoreComplexBody`	net6.0	214μs	258ns	1μs	0.106	0	9.84 KB
#5229	`AllCycleMoreComplexBody`	netcoreapp3.1	224μs	116ns	448ns	0.112	0	9.73 KB
#5229	`AllCycleMoreComplexBody`	net472	239μs	60.3ns	217ns	1.56	0	9.91 KB
#5229	`ObjectExtractorSimpleBody`	net6.0	154ns	0.0813ns	0.315ns	0.00397	0	280 B
#5229	`ObjectExtractorSimpleBody`	netcoreapp3.1	209ns	0.0853ns	0.33ns	0.00368	0	272 B
#5229	`ObjectExtractorSimpleBody`	net472	173ns	0.128ns	0.477ns	0.0446	0	281 B
#5229	`ObjectExtractorMoreComplexBody`	net6.0	2.98μs	1.52ns	5.67ns	0.0538	0	3.78 KB
#5229	`ObjectExtractorMoreComplexBody`	netcoreapp3.1	3.94μs	1.67ns	6.25ns	0.0496	0	3.69 KB
#5229	`ObjectExtractorMoreComplexBody`	net472	3.82μs	2.55ns	9.86ns	0.601	0.00571	3.8 KB

Benchmarks.Trace.Asm.AppSecEncoderBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Allocated
master	`EncodeArgs`	net6.0	53μs	46.1ns	179ns	0.423	0	30.94 KB
master	`EncodeArgs`	netcoreapp3.1	69.3μs	63.5ns	238ns	0.413	0	31.47 KB
master	`EncodeArgs`	net472	85.2μs	43.1ns	161ns	5.12	0.0853	32.27 KB
master	`EncodeLegacyArgs`	net6.0	128μs	177ns	637ns	0.439	0	33.89 KB
master	`EncodeLegacyArgs`	netcoreapp3.1	158μs	158ns	592ns	0.465	0	34.08 KB
master	`EncodeLegacyArgs`	net472	212μs	241ns	933ns	5.51	0.424	34.99 KB
#5229	`EncodeArgs`	net6.0	52.8μs	68.4ns	265ns	0.423	0	30.94 KB
#5229	`EncodeArgs`	netcoreapp3.1	70.9μs	81ns	314ns	0.42	0	31.47 KB
#5229	`EncodeArgs`	net472	84.1μs	34.9ns	130ns	5.09	0.0848	32.27 KB
#5229	`EncodeLegacyArgs`	net6.0	127μs	267ns	1.04μs	0.434	0	33.89 KB
#5229	`EncodeLegacyArgs`	netcoreapp3.1	158μs	312ns	1.17μs	0.396	0	34.09 KB
#5229	`EncodeLegacyArgs`	net472	210μs	153ns	571ns	5.5	0.423	34.99 KB

Benchmarks.Trace.Asm.AppSecWafBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`RunWafRealisticBenchmark`	net6.0	190μs	103ns	400ns	0.0948	6.51 KB
master	`RunWafRealisticBenchmark`	netcoreapp3.1	204μs	232ns	900ns	0	6.49 KB
master	`RunWafRealisticBenchmark`	net472	225μs	181ns	701ns	1.01	6.59 KB
master	`RunWafRealisticBenchmarkWithAttack`	net6.0	127μs	83.2ns	322ns	0.0632	4.15 KB
master	`RunWafRealisticBenchmarkWithAttack`	netcoreapp3.1	134μs	410ns	1.59μs	0	4.15 KB
master	`RunWafRealisticBenchmarkWithAttack`	net472	149μs	47.5ns	184ns	0.597	4.19 KB
#5229	`RunWafRealisticBenchmark`	net6.0	190μs	82.1ns	318ns	0	6.51 KB
#5229	`RunWafRealisticBenchmark`	netcoreapp3.1	205μs	230ns	891ns	0	6.49 KB
#5229	`RunWafRealisticBenchmark`	net472	222μs	72.8ns	262ns	1.01	6.59 KB
#5229	`RunWafRealisticBenchmarkWithAttack`	net6.0	125μs	56.6ns	219ns	0.063	4.15 KB
#5229	`RunWafRealisticBenchmarkWithAttack`	netcoreapp3.1	134μs	100ns	374ns	0	4.14 KB
#5229	`RunWafRealisticBenchmarkWithAttack`	net472	146μs	114ns	441ns	0.656	4.19 KB

Benchmarks.Trace.AspNetCoreBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`SendRequest`	net6.0	173μs	235ns	911ns	0.26	18.26 KB
master	`SendRequest`	netcoreapp3.1	192μs	261ns	1.01μs	0.19	20.42 KB
master	`SendRequest`	net472	0.000211ns	0.000101ns	0.000365ns	0	0 b
#5229	`SendRequest`	net6.0	173μs	159ns	616ns	0.173	18.26 KB
#5229	`SendRequest`	netcoreapp3.1	193μs	228ns	883ns	0.193	20.42 KB
#5229	`SendRequest`	net472	0.000272ns	0.000126ns	0.000489ns	0	0 b

Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark - Same speed ✔️ Fewer allocations 🎉

Fewer allocations 🎉 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 ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`ExecuteNonQuery`	net6.0	1.14μs	0.541ns	2.02ns	0.0108	776 B
master	`ExecuteNonQuery`	netcoreapp3.1	1.47μs	1.43ns	5.53ns	0.0103	776 B
master	`ExecuteNonQuery`	net472	1.76μs	1.41ns	5.08ns	0.117	738 B
#5229	`ExecuteNonQuery`	net6.0	1.08μs	0.453ns	1.76ns	0.0108	776 B
#5229	`ExecuteNonQuery`	netcoreapp3.1	1.53μs	0.715ns	2.77ns	0.0101	776 B
#5229	`ExecuteNonQuery`	net472	1.84μs	8.35ns	30.1ns	0.117	738 B

Benchmarks.Trace.ElasticsearchBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`CallElasticsearch`	net6.0	1.33μs	1.41ns	5.46ns	0.0133	944 B
master	`CallElasticsearch`	netcoreapp3.1	1.59μs	1.87ns	6.98ns	0.0124	944 B
master	`CallElasticsearch`	net472	2.59μs	1.22ns	4.73ns	0.152	963 B
master	`CallElasticsearchAsync`	net6.0	1.33μs	0.698ns	2.7ns	0.0126	920 B
master	`CallElasticsearchAsync`	netcoreapp3.1	1.63μs	1.73ns	6.49ns	0.0137	992 B
master	`CallElasticsearchAsync`	net472	2.62μs	0.66ns	2.38ns	0.161	1.02 KB
#5229	`CallElasticsearch`	net6.0	1.23μs	0.805ns	3.01ns	0.0129	944 B
#5229	`CallElasticsearch`	netcoreapp3.1	1.52μs	0.494ns	1.85ns	0.0128	944 B
#5229	`CallElasticsearch`	net472	2.53μs	0.853ns	3.19ns	0.152	963 B
#5229	`CallElasticsearchAsync`	net6.0	1.31μs	0.873ns	3.27ns	0.0125	920 B
#5229	`CallElasticsearchAsync`	netcoreapp3.1	1.62μs	0.598ns	2.24ns	0.013	992 B
#5229	`CallElasticsearchAsync`	net472	2.52μs	0.883ns	3.42ns	0.162	1.02 KB

Benchmarks.Trace.GraphQLBenchmark - Slower ⚠️ Same allocations ✔️

Slower ⚠️ 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	Allocated
master	`ExecuteAsync`	net6.0	1.33μs	0.617ns	2.39ns	0.0126	920 B
master	`ExecuteAsync`	netcoreapp3.1	1.62μs	0.998ns	3.74ns	0.0122	920 B
master	`ExecuteAsync`	net472	1.75μs	0.689ns	2.67ns	0.14	883 B
#5229	`ExecuteAsync`	net6.0	1.33μs	0.785ns	2.94ns	0.0129	920 B
#5229	`ExecuteAsync`	netcoreapp3.1	1.59μs	2.04ns	7.9ns	0.0119	920 B
#5229	`ExecuteAsync`	net472	1.95μs	0.382ns	1.48ns	0.14	883 B

Benchmarks.Trace.HttpClientBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Allocated
master	`SendAsync`	net6.0	4.14μs	0.869ns	3.37ns	0.029	0	2.1 KB
master	`SendAsync`	netcoreapp3.1	4.82μs	1.36ns	4.9ns	0.0357	0	2.64 KB
master	`SendAsync`	net472	7.79μs	1.75ns	6.78ns	0.525	0.00389	3.31 KB
#5229	`SendAsync`	net6.0	4.06μs	1.54ns	5.75ns	0.0282	0	2.1 KB
#5229	`SendAsync`	netcoreapp3.1	5.03μs	1.75ns	6.56ns	0.035	0	2.64 KB
#5229	`SendAsync`	net472	7.78μs	3.82ns	14.8ns	0.524	0	3.31 KB

Benchmarks.Trace.Iast.StringAspectsBenchmark - Same speed ✔️ More allocations ⚠️

More allocations ⚠️ 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 🎉 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	Allocated
master	`StringConcatBenchmark`	net6.0	59.2μs	756ns	7.41μs	43.44 KB
master	`StringConcatBenchmark`	netcoreapp3.1	58μs	705ns	6.76μs	42.64 KB
master	`StringConcatBenchmark`	net472	38.6μs	148ns	534ns	57.9 KB
master	`StringConcatAspectBenchmark`	net6.0	264μs	1.32μs	5.62μs	202.79 KB
master	`StringConcatAspectBenchmark`	netcoreapp3.1	287μs	1.13μs	4.66μs	212.17 KB
master	`StringConcatAspectBenchmark`	net472	225μs	1.78μs	16.5μs	221.18 KB
#5229	`StringConcatBenchmark`	net6.0	52μs	251ns	1.07μs	43.44 KB
#5229	`StringConcatBenchmark`	netcoreapp3.1	60.6μs	658ns	6.38μs	42.64 KB
#5229	`StringConcatBenchmark`	net472	38μs	98.9ns	342ns	60.49 KB
#5229	`StringConcatAspectBenchmark`	net6.0	256μs	3.2μs	29.2μs	201.35 KB
#5229	`StringConcatAspectBenchmark`	netcoreapp3.1	279μs	1.58μs	10.6μs	212.23 KB
#5229	`StringConcatAspectBenchmark`	net472	232μs	2.58μs	23.3μs	221.18 KB

Benchmarks.Trace.ILoggerBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`EnrichedLog`	net6.0	1.53μs	0.496ns	1.85ns	0.0225	1.58 KB
master	`EnrichedLog`	netcoreapp3.1	2.2μs	1.44ns	5.56ns	0.0217	1.58 KB
master	`EnrichedLog`	net472	2.55μs	3.15ns	12.2ns	0.239	1.51 KB
#5229	`EnrichedLog`	net6.0	1.44μs	0.876ns	3.28ns	0.022	1.58 KB
#5229	`EnrichedLog`	netcoreapp3.1	2.22μs	0.897ns	3.36ns	0.0214	1.58 KB
#5229	`EnrichedLog`	net472	2.59μs	2.47ns	8.91ns	0.239	1.51 KB

Benchmarks.Trace.Log4netBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Allocated
master	`EnrichedLog`	net6.0	116μs	208ns	805ns	0	0	4.22 KB
master	`EnrichedLog`	netcoreapp3.1	121μs	167ns	623ns	0	0	4.22 KB
master	`EnrichedLog`	net472	149μs	163ns	631ns	0.67	0.223	4.4 KB
#5229	`EnrichedLog`	net6.0	113μs	105ns	394ns	0	0	4.22 KB
#5229	`EnrichedLog`	netcoreapp3.1	119μs	58.3ns	218ns	0.0595	0	4.22 KB
#5229	`EnrichedLog`	net472	148μs	99.6ns	373ns	0.661	0.22	4.4 KB

Benchmarks.Trace.NLogBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`EnrichedLog`	net6.0	2.97μs	1.47ns	5.7ns	0.0296	2.14 KB
master	`EnrichedLog`	netcoreapp3.1	4.06μs	2.15ns	8.03ns	0.0283	2.14 KB
master	`EnrichedLog`	net472	4.89μs	4.34ns	16.8ns	0.308	1.95 KB
#5229	`EnrichedLog`	net6.0	3.04μs	0.779ns	2.92ns	0.0304	2.14 KB
#5229	`EnrichedLog`	netcoreapp3.1	4.14μs	3.03ns	11.7ns	0.029	2.14 KB
#5229	`EnrichedLog`	net472	4.93μs	4.26ns	16.5ns	0.31	1.95 KB

Benchmarks.Trace.RedisBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`SendReceive`	net6.0	1.4μs	0.813ns	3.15ns	0.0155	1.11 KB
master	`SendReceive`	netcoreapp3.1	1.78μs	0.766ns	2.76ns	0.0142	1.11 KB
master	`SendReceive`	net472	2.17μs	1.76ns	6.59ns	0.178	1.12 KB
#5229	`SendReceive`	net6.0	1.29μs	0.594ns	2.22ns	0.0155	1.11 KB
#5229	`SendReceive`	netcoreapp3.1	1.8μs	1.29ns	4.99ns	0.0143	1.11 KB
#5229	`SendReceive`	net472	2.12μs	2.13ns	8.25ns	0.178	1.12 KB

Benchmarks.Trace.SerilogBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`EnrichedLog`	net6.0	2.78μs	0.897ns	3.48ns	0.021	1.54 KB
master	`EnrichedLog`	netcoreapp3.1	3.93μs	3.42ns	13.3ns	0.0216	1.58 KB
master	`EnrichedLog`	net472	4.39μs	2.22ns	8.58ns	0.313	1.97 KB
#5229	`EnrichedLog`	net6.0	2.78μs	0.591ns	2.21ns	0.021	1.54 KB
#5229	`EnrichedLog`	netcoreapp3.1	3.87μs	0.79ns	2.85ns	0.0215	1.58 KB
#5229	`EnrichedLog`	net472	4.25μs	1.69ns	6.1ns	0.312	1.97 KB

Benchmarks.Trace.SpanBenchmark - Slower ⚠️ Same allocations ✔️

Slower ⚠️ 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 🎉 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	Allocated
master	`StartFinishSpan`	net6.0	447ns	0.75ns	2.9ns	0.00767	544 B
master	`StartFinishSpan`	netcoreapp3.1	675ns	1.55ns	5.6ns	0.00743	544 B
master	`StartFinishSpan`	net472	720ns	1.24ns	4.8ns	0.0867	546 B
master	`StartFinishScope`	net6.0	669ns	0.926ns	3.59ns	0.00928	664 B
master	`StartFinishScope`	netcoreapp3.1	799ns	0.698ns	2.42ns	0.00885	664 B
master	`StartFinishScope`	net472	930ns	2.31ns	8.94ns	0.0991	626 B
#5229	`StartFinishSpan`	net6.0	527ns	0.695ns	2.6ns	0.00771	544 B
#5229	`StartFinishSpan`	netcoreapp3.1	686ns	1.33ns	5.15ns	0.00727	544 B
#5229	`StartFinishSpan`	net472	731ns	1.52ns	5.89ns	0.0864	546 B
#5229	`StartFinishScope`	net6.0	593ns	1.01ns	3.93ns	0.00938	664 B
#5229	`StartFinishScope`	netcoreapp3.1	787ns	3.13ns	12.1ns	0.00897	664 B
#5229	`StartFinishScope`	net472	888ns	2.75ns	10.6ns	0.0992	626 B

Benchmarks.Trace.TraceAnnotationsBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`RunOnMethodBegin`	net6.0	673ns	1.19ns	4.62ns	0.00935	664 B
master	`RunOnMethodBegin`	netcoreapp3.1	1E+03ns	1.84ns	7.13ns	0.00898	664 B
master	`RunOnMethodBegin`	net472	1.14μs	1.98ns	7.67ns	0.0994	626 B
#5229	`RunOnMethodBegin`	net6.0	730ns	1.36ns	5.26ns	0.00911	664 B
#5229	`RunOnMethodBegin`	netcoreapp3.1	969ns	3.63ns	14.1ns	0.00864	664 B
#5229	`RunOnMethodBegin`	net472	1.07μs	1.46ns	5.67ns	0.0993	626 B

andrewlock · 2024-02-22T20:33:27Z

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

tracer/src/Datadog.Trace/Sampling/TracerRateLimiter.cs

Co-authored-by: Lucas Pimentel <lucas.pimentel@datadoghq.com>

andrewlock added the area:tracer The core tracer library (Datadog.Trace, does not include OpenTracing, native code, or integrations) label Feb 22, 2024

andrewlock requested a review from a team as a code owner February 22, 2024 16:20

andrewlock force-pushed the andrew/rate-limit-logs branch from 5c0862d to d381d47 Compare February 27, 2024 16:31

Add rate limit for trace rate log

9d7d00f

andrewlock force-pushed the andrew/rate-limit-logs branch from d381d47 to 9d7d00f Compare March 5, 2024 15:45

lucaspimentel reviewed Mar 5, 2024

View reviewed changes

tracer/src/Datadog.Trace/Sampling/TracerRateLimiter.cs Outdated Show resolved Hide resolved

lucaspimentel approved these changes Mar 5, 2024

View reviewed changes

Update tracer/src/Datadog.Trace/Sampling/TracerRateLimiter.cs

e9292ef

Co-authored-by: Lucas Pimentel <lucas.pimentel@datadoghq.com>

zacharycmontoya approved these changes Mar 12, 2024

View reviewed changes

andrewlock merged commit 6299d0a into master Mar 26, 2024
54 of 56 checks passed

andrewlock deleted the andrew/rate-limit-logs branch March 26, 2024 13:42

github-actions bot added this to the vNext milestone Mar 26, 2024

andrewlock modified the milestones: vNext, vNext-v2 Apr 17, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add rate limit for the log written by `TraceRateLimiter` #5229

Add rate limit for the log written by `TraceRateLimiter` #5229

andrewlock commented Feb 22, 2024

datadog-ddstaging bot commented Feb 22, 2024 •

edited

Loading

andrewlock commented Feb 22, 2024 •

edited

Loading

andrewlock commented Feb 22, 2024

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Fewer allocations 🎉 in #5229

Raw results

Raw results

Raw results

Slower ⚠️ in #5229

Raw results

Raw results

More allocations ⚠️ in #5229

Fewer allocations 🎉 in #5229

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Slower ⚠️ in #5229

Faster 🎉 in #5229

Raw results

Raw results

andrewlock commented Feb 22, 2024 •

edited

Loading

Add rate limit for the log written by TraceRateLimiter #5229

Add rate limit for the log written by TraceRateLimiter #5229

Conversation

andrewlock commented Feb 22, 2024

Summary of changes

Reason for change

Implementation details

Test coverage

datadog-ddstaging bot commented Feb 22, 2024 • edited Loading

Datadog Report

andrewlock commented Feb 22, 2024 • edited Loading

Execution-Time Benchmarks Report ⏱️

andrewlock commented Feb 22, 2024

Benchmarks Report 🐌

Benchmark details

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Fewer allocations 🎉 in #5229

Raw results

Raw results

Raw results

Slower ⚠️ in #5229

Raw results

Raw results

More allocations ⚠️ in #5229

Fewer allocations 🎉 in #5229

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Slower ⚠️ in #5229

Faster 🎉 in #5229

Raw results

Raw results

andrewlock commented Feb 22, 2024 • edited Loading

Throughput/Crank Report:zap:

Add rate limit for the log written by `TraceRateLimiter` #5229

Add rate limit for the log written by `TraceRateLimiter` #5229

datadog-ddstaging bot commented Feb 22, 2024 •

edited

Loading

andrewlock commented Feb 22, 2024 •

edited

Loading

andrewlock commented Feb 22, 2024 •

edited

Loading