[Profiler] Remove logs in buggybits if needed #6898

chrisnas · 2025-04-25T14:25:07Z

Summary of changes

Allow no logs for BuggyBits if needed

Reason for change

Avoid unneeded logs during our validation

Implementation details

Add the --disableLogs parameter on the command line

Test coverage

Other details

profiler/src/Demos/Samples.BuggyBits/Program.cs

datadog-datadog-prod-us1 · 2025-04-25T14:56:45Z

Datadog Report

All test runs 09bf9ac 🔗

✅ 2 Total Test Services: 0 Failed, 2 Passed

Test Services

Service Name	Failed	Known Flaky	New Flaky	Passed	Skipped	Total Time	Test Service View
`dd-trace-dotnet`	0	0	0	255983	2835	19h 55m 46.37s	Link
`exploration_tests`	0	0	0	22085	3	2m 11.35s	Link

andrewlock · 2025-04-25T15:01:27Z

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

    section CallTarget+Inlining+NGEN
    This PR (6898) - mean (1,012ms)  : 986, 1037
     .   : milestone, 1012,
    master - mean (1,007ms)  : 987, 1027
     .   : milestone, 1007,

gantt
    title Execution time (ms) FakeDbCommand (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6898) - mean (102ms)  : 100, 105
     .   : milestone, 102,
    master - mean (102ms)  : 100, 104
     .   : milestone, 102,

    section CallTarget+Inlining+NGEN
    This PR (6898) - mean (696ms)  : 676, 715
     .   : milestone, 696,
    master - mean (694ms)  : 671, 717
     .   : milestone, 694,

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

    section CallTarget+Inlining+NGEN
    This PR (6898) - mean (654ms)  : 638, 670
     .   : milestone, 654,
    master - mean (657ms)  : 632, 683
     .   : milestone, 657,

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

    section CallTarget+Inlining+NGEN
    This PR (6898) - mean (1,110ms)  : 1074, 1147
     .   : milestone, 1110,
    master - mean (1,104ms)  : 1075, 1133
     .   : milestone, 1104,

gantt
    title Execution time (ms) HttpMessageHandler (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6898) - mean (269ms)  : 265, 273
     .   : milestone, 269,
    master - mean (268ms)  : 264, 272
     .   : milestone, 268,

    section CallTarget+Inlining+NGEN
    This PR (6898) - mean (879ms)  : 847, 910
     .   : milestone, 879,
    master - mean (882ms)  : 854, 910
     .   : milestone, 882,

gantt
    title Execution time (ms) HttpMessageHandler (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6898) - mean (261ms)  : 257, 266
     .   : milestone, 261,
    master - mean (260ms)  : 257, 264
     .   : milestone, 260,

    section CallTarget+Inlining+NGEN
    This PR (6898) - mean (871ms)  : 842, 901
     .   : milestone, 871,
    master - mean (870ms)  : 842, 899
     .   : milestone, 870,

andrewlock · 2025-04-25T15:01:37Z

Benchmarks Report for tracer 🐌

Benchmarks for #6898 compared to master:

1 benchmarks are faster, with geometric mean 1.117
2 benchmarks are slower, with geometric mean 1.185
1 benchmarks have fewer 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 ✔️ Fewer allocations 🎉

Fewer allocations 🎉 in #6898

Benchmark	Base Allocated	Diff Allocated	Change	Change %
Benchmarks.Trace.ActivityBenchmark.StartStopWithChild‑net472	6.13 KB	6.09 KB	-47 B	-0.77%

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Gen 2	Allocated
master	`StartStopWithChild`	net6.0	7.74μs	90.1ns	896ns	0	0	0	5.57 KB
master	`StartStopWithChild`	netcoreapp3.1	10.1μs	148ns	1.48μs	0	0	0	5.73 KB
master	`StartStopWithChild`	net472	15.3μs	87.8ns	697ns	1.04	0.297	0.0741	6.13 KB
#6898	`StartStopWithChild`	net6.0	8.43μs	134ns	1.34μs	0	0	0	5.56 KB
#6898	`StartStopWithChild`	netcoreapp3.1	10.2μs	94.8ns	943ns	0	0	0	5.72 KB
#6898	`StartStopWithChild`	net472	15.4μs	86.6ns	631ns	1.01	0.337	0.0673	6.09 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Allocated
master	`WriteAndFlushEnrichedTraces`	net6.0	513μs	5.69μs	50.6μs	2.7 KB
master	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	664μs	854ns	3.19μs	2.7 KB
master	`WriteAndFlushEnrichedTraces`	net472	841μs	2.7μs	10.1μs	3.31 KB
#6898	`WriteAndFlushEnrichedTraces`	net6.0	521μs	397ns	1.49μs	2.7 KB
#6898	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	690μs	1.64μs	6.13μs	2.7 KB
#6898	`WriteAndFlushEnrichedTraces`	net472	852μs	532ns	2.06μs	3.31 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Allocated
master	`SendRequest`	net6.0	127μs	626ns	2.66μs	14.48 KB
master	`SendRequest`	netcoreapp3.1	141μs	821ns	7.15μs	17.28 KB
master	`SendRequest`	net472	0.00158ns	0.000518ns	0.00201ns	0 b
#6898	`SendRequest`	net6.0	130μs	706ns	4.23μs	14.48 KB
#6898	`SendRequest`	netcoreapp3.1	146μs	471ns	1.7μs	17.28 KB
#6898	`SendRequest`	net472	0.00108ns	0.00058ns	0.00217ns	0 b

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Allocated
master	`WriteAndFlushEnrichedTraces`	net6.0	653μs	7.16μs	70.9μs	0	0	41.81 KB
master	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	745μs	8.26μs	80.5μs	0	0	41.86 KB
master	`WriteAndFlushEnrichedTraces`	net472	871μs	4.95μs	46.7μs	7.35	3.68	53.37 KB
#6898	`WriteAndFlushEnrichedTraces`	net6.0	585μs	3.41μs	30.3μs	0	0	41.65 KB
#6898	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	736μs	8.83μs	86.5μs	0	0	41.73 KB
#6898	`WriteAndFlushEnrichedTraces`	net472	870μs	5.33μs	52.3μs	8.33	4.17	53.42 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Allocated
master	`ExecuteNonQuery`	net6.0	1.3μs	3.03ns	11.3ns	0.0129	0	1.03 KB
master	`ExecuteNonQuery`	netcoreapp3.1	1.78μs	3.2ns	11.1ns	0.00901	0	1.02 KB
master	`ExecuteNonQuery`	net472	2.15μs	1.56ns	5.83ns	0.153	0.0109	995 B
#6898	`ExecuteNonQuery`	net6.0	1.29μs	5.47ns	20.5ns	0.0128	0	1.03 KB
#6898	`ExecuteNonQuery`	netcoreapp3.1	1.75μs	5.04ns	19.5ns	0.00865	0	1.02 KB
#6898	`ExecuteNonQuery`	net472	2.08μs	5.64ns	21.1ns	0.153	0.0102	995 B

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`CallElasticsearch`	net6.0	1.32μs	1.17ns	4.53ns	0.0133	984 B
master	`CallElasticsearch`	netcoreapp3.1	1.6μs	1.34ns	4.83ns	0.00809	984 B
master	`CallElasticsearch`	net472	2.58μs	1.38ns	4.98ns	0.154	1 KB
master	`CallElasticsearchAsync`	net6.0	1.28μs	1.58ns	6.13ns	0.0126	960 B
master	`CallElasticsearchAsync`	netcoreapp3.1	1.73μs	1.34ns	5.17ns	0.00864	1.03 KB
master	`CallElasticsearchAsync`	net472	2.6μs	1.17ns	4.53ns	0.156	1.06 KB
#6898	`CallElasticsearch`	net6.0	1.19μs	1.31ns	5.07ns	0.012	984 B
#6898	`CallElasticsearch`	netcoreapp3.1	1.59μs	0.935ns	3.62ns	0.00799	984 B
#6898	`CallElasticsearch`	net472	2.55μs	2.24ns	8.68ns	0.149	1 KB
#6898	`CallElasticsearchAsync`	net6.0	1.18μs	0.913ns	3.53ns	0.0117	960 B
#6898	`CallElasticsearchAsync`	netcoreapp3.1	1.6μs	1.35ns	5.22ns	0.00807	1.03 KB
#6898	`CallElasticsearchAsync`	net472	2.71μs	1.67ns	6.49ns	0.164	1.06 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`ExecuteAsync`	net6.0	1.35μs	0.862ns	3.23ns	0.0135	960 B
master	`ExecuteAsync`	netcoreapp3.1	1.62μs	1.7ns	6.12ns	0.00819	960 B
master	`ExecuteAsync`	net472	1.81μs	0.999ns	3.74ns	0.145	923 B
#6898	`ExecuteAsync`	net6.0	1.39μs	1.73ns	6.68ns	0.0139	960 B
#6898	`ExecuteAsync`	netcoreapp3.1	1.6μs	3.75ns	13.5ns	0.00797	960 B
#6898	`ExecuteAsync`	net472	1.82μs	0.671ns	2.51ns	0.145	923 B

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`SendAsync`	net6.0	4.4μs	1.76ns	6.09ns	0.0221	2.32 KB
master	`SendAsync`	netcoreapp3.1	5.29μs	9.69ns	37.5ns	0.0263	2.86 KB
master	`SendAsync`	net472	7.45μs	5.2ns	19.5ns	0.49	3.13 KB
#6898	`SendAsync`	net6.0	4.49μs	3.79ns	14.2ns	0.0224	2.32 KB
#6898	`SendAsync`	netcoreapp3.1	5.44μs	8.58ns	32.1ns	0.0274	2.86 KB
#6898	`SendAsync`	net472	7.42μs	4.27ns	15.4ns	0.485	3.13 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`EnrichedLog`	net6.0	1.68μs	1.82ns	7.07ns	0.0168	1.71 KB
master	`EnrichedLog`	netcoreapp3.1	2.34μs	1.83ns	7.09ns	0.0118	1.71 KB
master	`EnrichedLog`	net472	2.65μs	1.81ns	7.02ns	0.25	1.64 KB
#6898	`EnrichedLog`	net6.0	1.55μs	1.11ns	4.15ns	0.0232	1.71 KB
#6898	`EnrichedLog`	netcoreapp3.1	2.27μs	2ns	7.48ns	0.0225	1.71 KB
#6898	`EnrichedLog`	net472	2.56μs	1.82ns	6.8ns	0.255	1.64 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Allocated
master	`EnrichedLog`	net6.0	112μs	295ns	1.14μs	4.32 KB
master	`EnrichedLog`	netcoreapp3.1	115μs	424ns	1.64μs	4.32 KB
master	`EnrichedLog`	net472	149μs	226ns	876ns	4.51 KB
#6898	`EnrichedLog`	net6.0	111μs	169ns	656ns	4.32 KB
#6898	`EnrichedLog`	netcoreapp3.1	115μs	225ns	871ns	4.32 KB
#6898	`EnrichedLog`	net472	151μs	334ns	1.29μs	4.51 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`EnrichedLog`	net6.0	3.26μs	2.4ns	9.29ns	0.0331	2.26 KB
master	`EnrichedLog`	netcoreapp3.1	4.27μs	5.13ns	19.9ns	0.0214	2.26 KB
master	`EnrichedLog`	net472	4.89μs	3.09ns	12ns	0.318	2.09 KB
#6898	`EnrichedLog`	net6.0	3.07μs	2.46ns	9.2ns	0.0306	2.26 KB
#6898	`EnrichedLog`	netcoreapp3.1	4.25μs	4.91ns	19ns	0.0213	2.26 KB
#6898	`EnrichedLog`	net472	5.03μs	8ns	31ns	0.327	2.09 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`SendReceive`	net6.0	1.37μs	1.14ns	4.41ns	0.0138	1.15 KB
master	`SendReceive`	netcoreapp3.1	1.8μs	1.13ns	4.22ns	0.00907	1.15 KB
master	`SendReceive`	net472	2.16μs	1.57ns	6.06ns	0.179	1.16 KB
#6898	`SendReceive`	net6.0	1.43μs	1.3ns	5.02ns	0.0141	1.15 KB
#6898	`SendReceive`	netcoreapp3.1	1.75μs	1.59ns	5.73ns	0.00878	1.15 KB
#6898	`SendReceive`	net472	1.95μs	0.884ns	3.31ns	0.176	1.16 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`EnrichedLog`	net6.0	2.83μs	1.73ns	6.69ns	0.0142	1.64 KB
master	`EnrichedLog`	netcoreapp3.1	3.9μs	2.18ns	7.85ns	0.0194	1.69 KB
master	`EnrichedLog`	net472	4.46μs	2.75ns	10.6ns	0.313	2.08 KB
#6898	`EnrichedLog`	net6.0	2.84μs	2.51ns	9.73ns	0.0143	1.64 KB
#6898	`EnrichedLog`	netcoreapp3.1	3.97μs	2.09ns	7.53ns	0.0197	1.69 KB
#6898	`EnrichedLog`	net472	4.42μs	3.84ns	14.9ns	0.31	2.08 KB

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

Slower ⚠️ in #6898

Benchmark	diff/base	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.SpanBenchmark.StartFinishScope‑net6.0	1.124	491.65	552.75

Faster 🎉 in #6898

Benchmark	base/diff	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.SpanBenchmark.StartFinishScope‑netcoreapp3.1	1.117	751.46	672.51

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`StartFinishSpan`	net6.0	412ns	0.354ns	1.32ns	0.00815	584 B
master	`StartFinishSpan`	netcoreapp3.1	582ns	0.765ns	2.96ns	0.00573	584 B
master	`StartFinishSpan`	net472	658ns	0.658ns	2.37ns	0.0922	586 B
master	`StartFinishScope`	net6.0	492ns	0.316ns	1.18ns	0.00975	704 B
master	`StartFinishScope`	netcoreapp3.1	752ns	0.69ns	2.58ns	0.00755	704 B
master	`StartFinishScope`	net472	838ns	0.778ns	3.01ns	0.105	666 B
#6898	`StartFinishSpan`	net6.0	397ns	0.394ns	1.42ns	0.0079	584 B
#6898	`StartFinishSpan`	netcoreapp3.1	570ns	0.994ns	3.59ns	0.00569	584 B
#6898	`StartFinishSpan`	net472	644ns	0.271ns	1.01ns	0.0904	586 B
#6898	`StartFinishScope`	net6.0	553ns	0.326ns	1.17ns	0.00827	704 B
#6898	`StartFinishScope`	netcoreapp3.1	672ns	0.646ns	2.42ns	0.00672	704 B
#6898	`StartFinishScope`	net472	888ns	0.643ns	2.49ns	0.103	666 B

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

Slower ⚠️ in #6898

Benchmark	diff/base	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.TraceAnnotationsBenchmark.RunOnMethodBegin‑net6.0	1.248	597.07	745.12

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`RunOnMethodBegin`	net6.0	597ns	0.475ns	1.84ns	0.00901	704 B
master	`RunOnMethodBegin`	netcoreapp3.1	1μs	1.28ns	4.78ns	0.00501	704 B
master	`RunOnMethodBegin`	net472	1.14μs	1.45ns	5.62ns	0.102	666 B
#6898	`RunOnMethodBegin`	net6.0	745ns	0.413ns	1.55ns	0.00741	704 B
#6898	`RunOnMethodBegin`	netcoreapp3.1	959ns	1.18ns	4.41ns	0.00937	704 B
#6898	`RunOnMethodBegin`	net472	1.06μs	2.26ns	8.75ns	0.101	666 B

Remove logs in buggybits if needed

c92d756

chrisnas requested a review from a team as a code owner April 25, 2025 14:25

github-actions bot added the area:profiler Issues related to the continous-profiler label Apr 25, 2025

chrisnas requested review from gleocadie and andrewlock April 25, 2025 14:30

andrewlock reviewed Apr 25, 2025

View reviewed changes

profiler/src/Demos/Samples.BuggyBits/Program.cs Show resolved Hide resolved

Remove ASP.NET Core loggers if needed

09bf9ac

gleocadie approved these changes Apr 25, 2025

View reviewed changes

chrisnas merged commit a6de824 into master Apr 28, 2025
132 of 135 checks passed

chrisnas deleted the chrisnas/remove_buggybits_logs branch April 28, 2025 07:59

github-actions bot added this to the vNext-v3 milestone Apr 28, 2025

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

[Profiler] Remove logs in buggybits if needed #6898

[Profiler] Remove logs in buggybits if needed #6898

Uh oh!

chrisnas commented Apr 25, 2025

Uh oh!

Uh oh!

datadog-datadog-prod-us1 bot commented Apr 25, 2025 •

edited

Loading

Uh oh!

andrewlock commented Apr 25, 2025 •

edited

Loading

Uh oh!

andrewlock commented Apr 25, 2025 •

edited

Loading

Fewer allocations 🎉 in #6898

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Slower ⚠️ in #6898

Faster 🎉 in #6898

Raw results

Slower ⚠️ in #6898

Raw results

Uh oh!

Uh oh!

Uh oh!

[Profiler] Remove logs in buggybits if needed #6898

[Profiler] Remove logs in buggybits if needed #6898

Uh oh!

Conversation

chrisnas commented Apr 25, 2025

Summary of changes

Reason for change

Implementation details

Test coverage

Other details

Uh oh!

Uh oh!

datadog-datadog-prod-us1 bot commented Apr 25, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Datadog Report

Uh oh!

andrewlock commented Apr 25, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Execution-Time Benchmarks Report ⏱️

Uh oh!

andrewlock commented Apr 25, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Benchmarks Report for tracer 🐌

Benchmark details

Fewer allocations 🎉 in #6898

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Slower ⚠️ in #6898

Faster 🎉 in #6898

Raw results

Slower ⚠️ in #6898

Raw results

Uh oh!

Uh oh!

Uh oh!

datadog-datadog-prod-us1 bot commented Apr 25, 2025 •

edited

Loading

andrewlock commented Apr 25, 2025 •

edited

Loading

andrewlock commented Apr 25, 2025 •

edited

Loading