[Profiler] Enable ETW support by default for .NET Framework #6724

chrisnas · 2025-02-27T12:51:17Z

Summary of changes

Enable ETW support by default

Reason for change

We won't need to enable an internal environment variable to make allocation/lock contention profiling work for .NET Framework

Implementation details

DD_INTERNAL_PROFILING_ETW_ENABLED is enabled by default in configuration

Test coverage

Updated

Other details

gleocadie

LGTM

andrewlock · 2025-02-27T13:26:24Z

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 (6724) - mean (71ms)  : 66, 76
     .   : milestone, 71,
    master - mean (70ms)  : 65, 74
     .   : milestone, 70,

    section CallTarget+Inlining+NGEN
    This PR (6724) - mean (1,008ms)  : 987, 1030
     .   : milestone, 1008,
    master - mean (1,003ms)  : 977, 1029
     .   : milestone, 1003,

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

    section CallTarget+Inlining+NGEN
    This PR (6724) - mean (686ms)  : 666, 707
     .   : milestone, 686,
    master - mean (688ms)  : 664, 711
     .   : milestone, 688,

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

    section CallTarget+Inlining+NGEN
    This PR (6724) - mean (645ms)  : 622, 667
     .   : milestone, 645,
    master - mean (640ms)  : 626, 654
     .   : milestone, 640,

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

    section CallTarget+Inlining+NGEN
    This PR (6724) - mean (1,112ms)  : 1083, 1142
     .   : milestone, 1112,
    master - mean (1,107ms)  : 1081, 1133
     .   : milestone, 1107,

gantt
    title Execution time (ms) HttpMessageHandler (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6724) - mean (270ms)  : 265, 274
     .   : milestone, 270,
    master - mean (271ms)  : 266, 275
     .   : milestone, 271,

    section CallTarget+Inlining+NGEN
    This PR (6724) - mean (879ms)  : 846, 912
     .   : milestone, 879,
    master - mean (877ms)  : 842, 913
     .   : milestone, 877,

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

    section CallTarget+Inlining+NGEN
    This PR (6724) - mean (858ms)  : 826, 889
     .   : milestone, 858,
    master - mean (855ms)  : 817, 892
     .   : milestone, 855,

datadog-datadog-prod-us1 · 2025-02-27T13:26:56Z

Datadog Report

All test runs 1fb82cc 🔗

✅ 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	242993	2905	21h 30m 35.83s	Link
`exploration_tests`	0	0	0	22085	3	2m 10.74s	Link

andrewlock · 2025-02-27T13:49:04Z

Benchmarks Report for tracer 🐌

Benchmarks for #6724 compared to master:

2 benchmarks are slower, with geometric mean 1.133
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.19μs	46.8ns	338ns	0.0119	0.00398	0	5.6 KB
master	`StartStopWithChild`	netcoreapp3.1	10.7μs	60.3ns	435ns	0.015	0.00499	0	5.81 KB
master	`StartStopWithChild`	net472	16.2μs	47.8ns	185ns	1.04	0.299	0.0969	6.2 KB
#6724	`StartStopWithChild`	net6.0	8.44μs	48.6ns	406ns	0.0156	0.00782	0	5.61 KB
#6724	`StartStopWithChild`	netcoreapp3.1	10.8μs	62ns	460ns	0.0259	0.0103	0	5.8 KB
#6724	`StartStopWithChild`	net472	16.4μs	55.5ns	215ns	1.04	0.299	0.0968	6.21 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`WriteAndFlushEnrichedTraces`	net6.0	483μs	358ns	1.39μs	0	2.7 KB
master	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	644μs	635ns	2.46μs	0	2.7 KB
master	`WriteAndFlushEnrichedTraces`	net472	849μs	397ns	1.54μs	0.422	3.3 KB
#6724	`WriteAndFlushEnrichedTraces`	net6.0	500μs	701ns	2.72μs	0	2.7 KB
#6724	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	650μs	485ns	1.81μs	0	2.7 KB
#6724	`WriteAndFlushEnrichedTraces`	net472	829μs	442ns	1.65μs	0.411	3.3 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`SendRequest`	net6.0	133μs	411ns	1.59μs	0.199	14.47 KB
master	`SendRequest`	netcoreapp3.1	151μs	212ns	794ns	0.227	17.27 KB
master	`SendRequest`	net472	0.000146ns	9.84E‑05ns	0.000368ns	0	0 b
#6724	`SendRequest`	net6.0	133μs	315ns	1.22μs	0.193	14.47 KB
#6724	`SendRequest`	netcoreapp3.1	152μs	228ns	881ns	0.223	17.27 KB
#6724	`SendRequest`	net472	0.000346ns	0.000151ns	0.000583ns	0	0 b

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

More allocations ⚠️ in #6724

Benchmark	Base Allocated	Diff Allocated	Change	Change %
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark.WriteAndFlushEnrichedTraces‑net6.0	41.47 KB	41.7 KB	229 B	0.55%

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Gen 2	Allocated
master	`WriteAndFlushEnrichedTraces`	net6.0	549μs	2.62μs	10.5μs	0.543	0	0	41.47 KB
master	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	683μs	3.34μs	13.8μs	0.324	0	0	41.84 KB
master	`WriteAndFlushEnrichedTraces`	net472	878μs	3.73μs	13.9μs	8.19	2.59	0.431	53.32 KB
#6724	`WriteAndFlushEnrichedTraces`	net6.0	549μs	2.3μs	8.3μs	0.595	0	0	41.7 KB
#6724	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	685μs	3.51μs	20.7μs	0.329	0	0	41.86 KB
#6724	`WriteAndFlushEnrichedTraces`	net472	846μs	2.39μs	9.25μs	8.22	2.47	0.411	53.36 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.33μs	1.28ns	4.97ns	0.014	0	1.02 KB
master	`ExecuteNonQuery`	netcoreapp3.1	1.82μs	1.88ns	7.28ns	0.0133	0	1.02 KB
master	`ExecuteNonQuery`	net472	2.12μs	1.29ns	4.81ns	0.156	0.00106	987 B
#6724	`ExecuteNonQuery`	net6.0	1.3μs	1.8ns	6.99ns	0.0142	0	1.02 KB
#6724	`ExecuteNonQuery`	netcoreapp3.1	1.72μs	1.17ns	4.55ns	0.014	0	1.02 KB
#6724	`ExecuteNonQuery`	net472	2.09μs	1.61ns	6.04ns	0.156	0.00105	987 B

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`CallElasticsearch`	net6.0	1.26μs	0.7ns	2.62ns	0.0139	976 B
master	`CallElasticsearch`	netcoreapp3.1	1.55μs	3.3ns	12.3ns	0.0131	976 B
master	`CallElasticsearch`	net472	2.47μs	0.758ns	2.73ns	0.158	995 B
master	`CallElasticsearchAsync`	net6.0	1.24μs	1.08ns	4.18ns	0.0131	952 B
master	`CallElasticsearchAsync`	netcoreapp3.1	1.64μs	1.06ns	3.95ns	0.0131	1.02 KB
master	`CallElasticsearchAsync`	net472	2.64μs	1ns	3.62ns	0.166	1.05 KB
#6724	`CallElasticsearch`	net6.0	1.22μs	0.541ns	2.09ns	0.0134	976 B
#6724	`CallElasticsearch`	netcoreapp3.1	1.6μs	0.601ns	2.17ns	0.0128	976 B
#6724	`CallElasticsearch`	net472	2.43μs	1.96ns	7.59ns	0.158	995 B
#6724	`CallElasticsearchAsync`	net6.0	1.27μs	0.943ns	3.65ns	0.0135	952 B
#6724	`CallElasticsearchAsync`	netcoreapp3.1	1.63μs	6.86ns	26.6ns	0.0135	1.02 KB
#6724	`CallElasticsearchAsync`	net472	2.6μs	2.09ns	8.1ns	0.166	1.05 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`ExecuteAsync`	net6.0	1.34μs	1.58ns	5.9ns	0.0133	952 B
master	`ExecuteAsync`	netcoreapp3.1	1.69μs	1.57ns	6.08ns	0.0128	952 B
master	`ExecuteAsync`	net472	1.85μs	0.672ns	2.6ns	0.145	915 B
#6724	`ExecuteAsync`	net6.0	1.35μs	2.51ns	9.72ns	0.0133	952 B
#6724	`ExecuteAsync`	netcoreapp3.1	1.61μs	1.35ns	5.05ns	0.0129	952 B
#6724	`ExecuteAsync`	net472	1.87μs	0.689ns	2.58ns	0.145	915 B

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`SendAsync`	net6.0	4.36μs	1.04ns	3.75ns	0.0325	2.31 KB
master	`SendAsync`	netcoreapp3.1	5.22μs	2.2ns	7.94ns	0.0393	2.85 KB
master	`SendAsync`	net472	7.45μs	2.36ns	9.15ns	0.492	3.12 KB
#6724	`SendAsync`	net6.0	4.43μs	0.971ns	3.5ns	0.0332	2.31 KB
#6724	`SendAsync`	netcoreapp3.1	5.17μs	2.63ns	10.2ns	0.0367	2.85 KB
#6724	`SendAsync`	net472	7.51μs	1.92ns	7.43ns	0.495	3.12 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`EnrichedLog`	net6.0	1.47μs	0.781ns	3.03ns	0.0234	1.64 KB
master	`EnrichedLog`	netcoreapp3.1	2.14μs	5.9ns	22.9ns	0.0223	1.64 KB
master	`EnrichedLog`	net472	2.63μs	2.01ns	7.8ns	0.25	1.57 KB
#6724	`EnrichedLog`	net6.0	1.46μs	0.905ns	3.39ns	0.0233	1.64 KB
#6724	`EnrichedLog`	netcoreapp3.1	2.21μs	0.898ns	3.36ns	0.0222	1.64 KB
#6724	`EnrichedLog`	net472	2.64μs	1.42ns	5.31ns	0.249	1.57 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	114μs	158ns	612ns	0.0563	0	4.28 KB
master	`EnrichedLog`	netcoreapp3.1	118μs	179ns	692ns	0	0	4.28 KB
master	`EnrichedLog`	net472	149μs	211ns	817ns	0.668	0.223	4.46 KB
#6724	`EnrichedLog`	net6.0	114μs	175ns	676ns	0.0569	0	4.28 KB
#6724	`EnrichedLog`	netcoreapp3.1	117μs	200ns	749ns	0.0585	0	4.28 KB
#6724	`EnrichedLog`	net472	148μs	150ns	581ns	0.668	0.223	4.46 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`EnrichedLog`	net6.0	2.9μs	0.691ns	2.59ns	0.0318	2.2 KB
master	`EnrichedLog`	netcoreapp3.1	4.16μs	3.18ns	11.5ns	0.029	2.2 KB
master	`EnrichedLog`	net472	5.01μs	1.69ns	6.54ns	0.32	2.02 KB
#6724	`EnrichedLog`	net6.0	3.17μs	0.989ns	3.83ns	0.0313	2.2 KB
#6724	`EnrichedLog`	netcoreapp3.1	4.16μs	2.86ns	11.1ns	0.0288	2.2 KB
#6724	`EnrichedLog`	net472	4.76μs	1.97ns	7.62ns	0.319	2.02 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`SendReceive`	net6.0	1.36μs	0.605ns	2.34ns	0.0156	1.14 KB
master	`SendReceive`	netcoreapp3.1	1.74μs	0.624ns	2.41ns	0.0155	1.14 KB
master	`SendReceive`	net472	2.11μs	1.34ns	5.2ns	0.183	1.16 KB
#6724	`SendReceive`	net6.0	1.48μs	1.23ns	4.75ns	0.0162	1.14 KB
#6724	`SendReceive`	netcoreapp3.1	1.78μs	1.54ns	5.97ns	0.015	1.14 KB
#6724	`SendReceive`	net472	2.04μs	1.49ns	5.75ns	0.183	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.74μs	0.565ns	2.19ns	0.022	1.6 KB
master	`EnrichedLog`	netcoreapp3.1	3.9μs	2.99ns	11.6ns	0.0216	1.65 KB
master	`EnrichedLog`	net472	4.46μs	2.17ns	8.11ns	0.324	2.04 KB
#6724	`EnrichedLog`	net6.0	2.75μs	1.04ns	4.01ns	0.0219	1.6 KB
#6724	`EnrichedLog`	netcoreapp3.1	4.01μs	1.79ns	6.68ns	0.022	1.65 KB
#6724	`EnrichedLog`	net472	4.32μs	4.38ns	17ns	0.323	2.04 KB

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

Slower ⚠️ in #6724

Benchmark	diff/base	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.SpanBenchmark.StartFinishScope‑net6.0	1.123	481.86	541.13

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`StartFinishSpan`	net6.0	392ns	0.434ns	1.68ns	0.00798	576 B
master	`StartFinishSpan`	netcoreapp3.1	606ns	1.38ns	5.36ns	0.0079	576 B
master	`StartFinishSpan`	net472	589ns	0.892ns	3.46ns	0.0916	578 B
master	`StartFinishScope`	net6.0	481ns	0.798ns	3.09ns	0.00986	696 B
master	`StartFinishScope`	netcoreapp3.1	725ns	1.74ns	6.72ns	0.00921	696 B
master	`StartFinishScope`	net472	842ns	1.98ns	7.67ns	0.104	658 B
#6724	`StartFinishSpan`	net6.0	428ns	0.189ns	0.73ns	0.00812	576 B
#6724	`StartFinishSpan`	netcoreapp3.1	601ns	0.278ns	1.08ns	0.00767	576 B
#6724	`StartFinishSpan`	net472	654ns	0.486ns	1.88ns	0.0915	578 B
#6724	`StartFinishScope`	net6.0	541ns	0.242ns	0.938ns	0.00964	696 B
#6724	`StartFinishScope`	netcoreapp3.1	737ns	0.783ns	3.03ns	0.0095	696 B
#6724	`StartFinishScope`	net472	836ns	0.29ns	1.09ns	0.104	658 B

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

Slower ⚠️ in #6724

Benchmark	diff/base	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.TraceAnnotationsBenchmark.RunOnMethodBegin‑net6.0	1.143	614.88	702.68

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`RunOnMethodBegin`	net6.0	615ns	1.18ns	4.58ns	0.00981	696 B
master	`RunOnMethodBegin`	netcoreapp3.1	922ns	1.49ns	5.78ns	0.00937	696 B
master	`RunOnMethodBegin`	net472	1.06μs	2.1ns	8.12ns	0.104	658 B
#6724	`RunOnMethodBegin`	net6.0	703ns	0.55ns	2.13ns	0.00981	696 B
#6724	`RunOnMethodBegin`	netcoreapp3.1	943ns	0.449ns	1.74ns	0.00945	696 B
#6724	`RunOnMethodBegin`	net472	1.16μs	0.182ns	0.654ns	0.104	658 B

…ault

enable ETW support by default

c0c22c5

chrisnas requested a review from a team as a code owner February 27, 2025 12:51

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

gleocadie approved these changes Feb 27, 2025

View reviewed changes

chrisnas added 5 commits February 28, 2025 09:57

Merge remote-tracking branch 'origin' into chrisnas/enable_etw_by_def…

2fa78f2

…ault

Fix tests to avoid errors in logs

0eecc7d

Fix tests for default ETW support

233508d

Merge remote-tracking branch 'origin' into chrisnas/enable_etw_by_def…

78c0f0f

…ault

Fix test for linux

1fb82cc

chrisnas merged commit 918aa1f into master Mar 3, 2025
150 of 154 checks passed

chrisnas deleted the chrisnas/enable_etw_by_default branch March 3, 2025 21:41

github-actions bot added this to the vNext-v3 milestone Mar 3, 2025

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[Profiler] Enable ETW support by default for .NET Framework #6724

[Profiler] Enable ETW support by default for .NET Framework #6724

chrisnas commented Feb 27, 2025

gleocadie left a comment

andrewlock commented Feb 27, 2025 •

edited

Loading

datadog-datadog-prod-us1 bot commented Feb 27, 2025 •

edited

Loading

andrewlock commented Feb 27, 2025 •

edited

Loading

Raw results

Raw results

Raw results

More allocations ⚠️ in #6724

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Slower ⚠️ in #6724

Raw results

Slower ⚠️ in #6724

Raw results

[Profiler] Enable ETW support by default for .NET Framework #6724

[Profiler] Enable ETW support by default for .NET Framework #6724

Conversation

chrisnas commented Feb 27, 2025

Summary of changes

Reason for change

Implementation details

Test coverage

Other details

gleocadie left a comment

Choose a reason for hiding this comment

andrewlock commented Feb 27, 2025 • edited Loading

Execution-Time Benchmarks Report ⏱️

datadog-datadog-prod-us1 bot commented Feb 27, 2025 • edited Loading

Datadog Report

andrewlock commented Feb 27, 2025 • edited Loading

Benchmarks Report for tracer 🐌

Benchmark details

Raw results

Raw results

Raw results

More allocations ⚠️ in #6724

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Slower ⚠️ in #6724

Raw results

Slower ⚠️ in #6724

Raw results

andrewlock commented Feb 27, 2025 •

edited

Loading

datadog-datadog-prod-us1 bot commented Feb 27, 2025 •

edited

Loading

andrewlock commented Feb 27, 2025 •

edited

Loading