[Profiler] Add gen2 leak scenario #6071

chrisnas · 2024-09-24T12:50:20Z

Summary of changes

Change the LOH fragmentation scenario into a gen2 leak

Reason for change

Simpler to understand and avoid too fast memory increase that leads to OOM/app crash

Implementation details

Remove the large integer array from the controller and create dedicated News request threads

Test coverage

N/A

Other details

…2 increase

datadog-ddstaging · 2024-09-24T13:12:25Z

Datadog Report

Branch report: chrisnas/leaky_app
Commit report: b817a17
Test service: dd-trace-dotnet

✅ 0 Failed, 362114 Passed, 2332 Skipped, 17h 3m 12.17s Total Time
⌛ 1 Performance Regression

⌛ Performance Regressions vs Default Branch (1)

EnrichedLog - Benchmarks.Trace.Log4netBenchmark 151.5µs (+5.52µs, +4%) - Details

andrewlock · 2024-09-24T13:28:42Z

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 (6071) - mean (71ms)  : 67, 74
     .   : milestone, 71,
    master - mean (70ms)  : 67, 73
     .   : milestone, 70,

    section CallTarget+Inlining+NGEN
    This PR (6071) - mean (1,108ms)  : 1085, 1131
     .   : milestone, 1108,
    master - mean (1,105ms)  : 1067, 1143
     .   : milestone, 1105,

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

    section CallTarget+Inlining+NGEN
    This PR (6071) - mean (773ms)  : 756, 791
     .   : milestone, 773,
    master - mean (766ms)  : 751, 782
     .   : milestone, 766,

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

    section CallTarget+Inlining+NGEN
    This PR (6071) - mean (732ms)  : 714, 750
     .   : milestone, 732,
    master - mean (727ms)  : 707, 747
     .   : milestone, 727,

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

    section CallTarget+Inlining+NGEN
    This PR (6071) - mean (1,201ms)  : 1129, 1273
     .   : milestone, 1201,
    master - mean (1,202ms)  : 1165, 1240
     .   : milestone, 1202,

gantt
    title Execution time (ms) HttpMessageHandler (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6071) - mean (276ms)  : 271, 281
     .   : milestone, 276,
    master - mean (276ms)  : 270, 281
     .   : milestone, 276,

    section CallTarget+Inlining+NGEN
    This PR (6071) - mean (939ms)  : 919, 958
     .   : milestone, 939,
    master - mean (938ms)  : 918, 958
     .   : milestone, 938,

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

    section CallTarget+Inlining+NGEN
    This PR (6071) - mean (928ms)  : 910, 947
     .   : milestone, 928,
    master - mean (922ms)  : 906, 939
     .   : milestone, 922,

gleocadie

LGTM

andrewlock · 2024-09-24T17:52:39Z

Benchmarks Report for tracer 🐌

Benchmarks for #6071 compared to master:

2 benchmarks are faster, with geometric mean 1.127
1 benchmarks are slower, with geometric mean 1.174
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	7.84μs	43.1ns	251ns	0.0193	0.00774	0	5.43 KB
master	`StartStopWithChild`	netcoreapp3.1	10.1μs	52.3ns	246ns	0.0193	0.00965	0	5.62 KB
master	`StartStopWithChild`	net472	16.1μs	65.3ns	244ns	1.02	0.308	0.087	6.07 KB
#6071	`StartStopWithChild`	net6.0	7.72μs	41.1ns	214ns	0.0154	0.00772	0	5.43 KB
#6071	`StartStopWithChild`	netcoreapp3.1	10μs	54.7ns	314ns	0.0254	0.0102	0	5.61 KB
#6071	`StartStopWithChild`	net472	16.3μs	55.8ns	216ns	1.04	0.326	0.0978	6.07 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`WriteAndFlushEnrichedTraces`	net6.0	472μs	265ns	990ns	0	2.7 KB
master	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	627μs	317ns	1.19μs	0	2.7 KB
master	`WriteAndFlushEnrichedTraces`	net472	835μs	518ns	1.94μs	0.419	3.3 KB
#6071	`WriteAndFlushEnrichedTraces`	net6.0	478μs	370ns	1.39μs	0	2.7 KB
#6071	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	638μs	220ns	824ns	0	2.7 KB
#6071	`WriteAndFlushEnrichedTraces`	net472	832μs	364ns	1.41μs	0.417	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	210μs	1.2μs	9.83μs	0.194	18.45 KB
master	`SendRequest`	netcoreapp3.1	231μs	1.29μs	11.8μs	0.233	20.61 KB
master	`SendRequest`	net472	0.0038ns	0.0015ns	0.00562ns	0	0 b
#6071	`SendRequest`	net6.0	208μs	1.19μs	8.58μs	0.206	18.45 KB
#6071	`SendRequest`	netcoreapp3.1	229μs	1.21μs	6.41μs	0.236	20.61 KB
#6071	`SendRequest`	net472	0.00154ns	0.000721ns	0.0027ns	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	588μs	3.26μs	19.6μs	0.581	0	0	41.61 KB
master	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	678μs	3.75μs	22.2μs	0.332	0	0	41.61 KB
master	`WriteAndFlushEnrichedTraces`	net472	853μs	3.04μs	11.4μs	8.08	2.55	0.425	53.29 KB
#6071	`WriteAndFlushEnrichedTraces`	net6.0	577μs	2.36μs	9.13μs	0.558	0	0	41.75 KB
#6071	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	706μs	3.26μs	11.7μs	0.355	0	0	41.62 KB
#6071	`WriteAndFlushEnrichedTraces`	net472	871μs	4.24μs	17.5μs	8.19	2.59	0.431	53.27 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`ExecuteNonQuery`	net6.0	1.31μs	0.955ns	3.7ns	0.0144	1.02 KB
master	`ExecuteNonQuery`	netcoreapp3.1	1.73μs	1.2ns	4.49ns	0.013	1.02 KB
master	`ExecuteNonQuery`	net472	2.08μs	2.93ns	11.3ns	0.156	987 B
#6071	`ExecuteNonQuery`	net6.0	1.28μs	1.38ns	5.36ns	0.0142	1.02 KB
#6071	`ExecuteNonQuery`	netcoreapp3.1	1.77μs	1.5ns	5.81ns	0.0133	1.02 KB
#6071	`ExecuteNonQuery`	net472	2.05μs	1.64ns	6.13ns	0.156	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.23μs	0.373ns	1.39ns	0.0136	976 B
master	`CallElasticsearch`	netcoreapp3.1	1.5μs	0.869ns	3.25ns	0.0135	976 B
master	`CallElasticsearch`	net472	2.5μs	1.39ns	5.19ns	0.157	995 B
master	`CallElasticsearchAsync`	net6.0	1.28μs	0.877ns	3.4ns	0.0135	952 B
master	`CallElasticsearchAsync`	netcoreapp3.1	1.68μs	0.299ns	1.08ns	0.0141	1.02 KB
master	`CallElasticsearchAsync`	net472	2.71μs	3.82ns	14.8ns	0.166	1.05 KB
#6071	`CallElasticsearch`	net6.0	1.17μs	0.58ns	2.17ns	0.0136	976 B
#6071	`CallElasticsearch`	netcoreapp3.1	1.53μs	0.358ns	1.39ns	0.0131	976 B
#6071	`CallElasticsearch`	net472	2.49μs	1.37ns	4.96ns	0.158	995 B
#6071	`CallElasticsearchAsync`	net6.0	1.23μs	0.453ns	1.7ns	0.0129	952 B
#6071	`CallElasticsearchAsync`	netcoreapp3.1	1.6μs	3.39ns	13.1ns	0.0134	1.02 KB
#6071	`CallElasticsearchAsync`	net472	2.66μs	2.16ns	8.37ns	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.24μs	1.34ns	5ns	0.0136	952 B
master	`ExecuteAsync`	netcoreapp3.1	1.65μs	0.542ns	2.1ns	0.0124	952 B
master	`ExecuteAsync`	net472	1.76μs	1.44ns	5.56ns	0.145	915 B
#6071	`ExecuteAsync`	net6.0	1.37μs	1.03ns	3.98ns	0.0132	952 B
#6071	`ExecuteAsync`	netcoreapp3.1	1.59μs	2.15ns	8.31ns	0.0127	952 B
#6071	`ExecuteAsync`	net472	1.78μs	0.756ns	2.93ns	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.12μs	1.8ns	6.98ns	0.031	2.22 KB
master	`SendAsync`	netcoreapp3.1	5.05μs	1.96ns	7.33ns	0.0377	2.76 KB
master	`SendAsync`	net472	7.78μs	1.86ns	7.21ns	0.497	3.15 KB
#6071	`SendAsync`	net6.0	4.07μs	2.68ns	10ns	0.0307	2.22 KB
#6071	`SendAsync`	netcoreapp3.1	5.08μs	3.48ns	13.5ns	0.0355	2.76 KB
#6071	`SendAsync`	net472	7.72μs	3.25ns	12.6ns	0.496	3.15 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`EnrichedLog`	net6.0	1.54μs	0.913ns	3.42ns	0.023	1.64 KB
master	`EnrichedLog`	netcoreapp3.1	2.23μs	1.04ns	3.9ns	0.0222	1.64 KB
master	`EnrichedLog`	net472	2.7μs	1.09ns	3.93ns	0.249	1.57 KB
#6071	`EnrichedLog`	net6.0	1.5μs	1.63ns	6.09ns	0.0232	1.64 KB
#6071	`EnrichedLog`	netcoreapp3.1	2.28μs	0.862ns	3.23ns	0.0217	1.64 KB
#6071	`EnrichedLog`	net472	2.64μs	1.34ns	5.21ns	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	117μs	227ns	881ns	0.0585	0	4.28 KB
master	`EnrichedLog`	netcoreapp3.1	120μs	152ns	547ns	0.0595	0	4.28 KB
master	`EnrichedLog`	net472	150μs	194ns	751ns	0.683	0.228	4.46 KB
#6071	`EnrichedLog`	net6.0	117μs	110ns	426ns	0.0584	0	4.28 KB
#6071	`EnrichedLog`	netcoreapp3.1	123μs	498ns	1.93μs	0	0	4.28 KB
#6071	`EnrichedLog`	net472	152μs	188ns	728ns	0.683	0.228	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	3.03μs	0.698ns	2.7ns	0.0303	2.2 KB
master	`EnrichedLog`	netcoreapp3.1	4.1μs	1.99ns	7.71ns	0.0307	2.2 KB
master	`EnrichedLog`	net472	4.83μs	1.33ns	4.97ns	0.319	2.02 KB
#6071	`EnrichedLog`	net6.0	3.12μs	0.994ns	3.72ns	0.0298	2.2 KB
#6071	`EnrichedLog`	netcoreapp3.1	4.22μs	1.81ns	7ns	0.0292	2.2 KB
#6071	`EnrichedLog`	net472	4.77μs	1.93ns	7.49ns	0.32	2.02 KB

Benchmarks.Trace.RedisBenchmark - Faster 🎉 Same allocations ✔️

Faster 🎉 in #6071

Benchmark	base/diff	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.RedisBenchmark.SendReceive‑net6.0	1.131	1,521.05	1,345.43

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Allocated
master	`SendReceive`	net6.0	1.52μs	0.722ns	2.8ns	0.0159	0	1.14 KB
master	`SendReceive`	netcoreapp3.1	1.8μs	1.24ns	4.8ns	0.0153	0	1.14 KB
master	`SendReceive`	net472	2.15μs	1.64ns	6.36ns	0.183	0	1.16 KB
#6071	`SendReceive`	net6.0	1.35μs	0.609ns	2.36ns	0.0161	0	1.14 KB
#6071	`SendReceive`	netcoreapp3.1	1.76μs	1.46ns	5.47ns	0.0159	0	1.14 KB
#6071	`SendReceive`	net472	2.12μs	1.7ns	6.57ns	0.184	0.00106	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.69μs	0.41ns	1.53ns	0.0215	1.6 KB
master	`EnrichedLog`	netcoreapp3.1	3.85μs	1.8ns	6.96ns	0.0212	1.65 KB
master	`EnrichedLog`	net472	4.33μs	2.33ns	9.02ns	0.324	2.04 KB
#6071	`EnrichedLog`	net6.0	2.75μs	0.994ns	3.85ns	0.022	1.6 KB
#6071	`EnrichedLog`	netcoreapp3.1	3.96μs	2.47ns	9.56ns	0.0218	1.65 KB
#6071	`EnrichedLog`	net472	4.39μs	2.34ns	8.42ns	0.322	2.04 KB

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

Slower ⚠️ in #6071

Benchmark	diff/base	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.SpanBenchmark.StartFinishSpan‑netcoreapp3.1	1.174	551.77	647.65

Faster 🎉 in #6071

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`StartFinishSpan`	net6.0	406ns	0.135ns	0.521ns	0.00797	576 B
master	`StartFinishSpan`	netcoreapp3.1	552ns	0.657ns	2.46ns	0.00778	576 B
master	`StartFinishSpan`	net472	692ns	0.818ns	3.17ns	0.0915	578 B
master	`StartFinishScope`	net6.0	548ns	0.142ns	0.548ns	0.00963	696 B
master	`StartFinishScope`	netcoreapp3.1	721ns	0.258ns	0.967ns	0.00974	696 B
master	`StartFinishScope`	net472	861ns	0.779ns	3.02ns	0.104	658 B
#6071	`StartFinishSpan`	net6.0	401ns	0.139ns	0.519ns	0.00809	576 B
#6071	`StartFinishSpan`	netcoreapp3.1	646ns	1.03ns	3.87ns	0.00771	576 B
#6071	`StartFinishSpan`	net472	655ns	0.758ns	2.94ns	0.0916	578 B
#6071	`StartFinishScope`	net6.0	488ns	0.232ns	0.898ns	0.00973	696 B
#6071	`StartFinishScope`	netcoreapp3.1	740ns	1.97ns	7.64ns	0.0093	696 B
#6071	`StartFinishScope`	net472	915ns	1.47ns	5.71ns	0.104	658 B

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`RunOnMethodBegin`	net6.0	635ns	0.341ns	1.32ns	0.00977	696 B
master	`RunOnMethodBegin`	netcoreapp3.1	873ns	1.46ns	5.67ns	0.00958	696 B
master	`RunOnMethodBegin`	net472	1.12μs	0.766ns	2.86ns	0.105	658 B
#6071	`RunOnMethodBegin`	net6.0	600ns	0.312ns	1.21ns	0.00993	696 B
#6071	`RunOnMethodBegin`	netcoreapp3.1	944ns	0.804ns	3.11ns	0.00945	696 B
#6071	`RunOnMethodBegin`	net472	1.12μs	1.08ns	4.19ns	0.105	658 B

chrisnas added 2 commits September 24, 2024 14:47

Update memory leak scenario to avoid LOH fragmentation and show a gen…

ff7f12e

…2 increase

Merge remote-tracking branch 'origin' into chrisnas/leaky_app

b817a17

chrisnas requested a review from a team as a code owner September 24, 2024 12:50

github-actions bot added the area:profiler Issues related to the continous-profiler label Sep 24, 2024

gleocadie approved these changes Sep 24, 2024

View reviewed changes

chrisnas merged commit 16df22d into master Sep 25, 2024
79 of 81 checks passed

chrisnas deleted the chrisnas/leaky_app branch September 25, 2024 08:28

github-actions bot added this to the vNext-v3 milestone Sep 25, 2024

andrewlock added the area:tests unit tests, integration tests label Oct 23, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[Profiler] Add gen2 leak scenario #6071

[Profiler] Add gen2 leak scenario #6071

chrisnas commented Sep 24, 2024

datadog-ddstaging bot commented Sep 24, 2024 •

edited

Loading

andrewlock commented Sep 24, 2024

gleocadie left a comment

andrewlock commented Sep 24, 2024

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Faster 🎉 in #6071

Raw results

Raw results

Slower ⚠️ in #6071

Faster 🎉 in #6071

Raw results

Raw results

[Profiler] Add gen2 leak scenario #6071

[Profiler] Add gen2 leak scenario #6071

Conversation

chrisnas commented Sep 24, 2024

Summary of changes

Reason for change

Implementation details

Test coverage

Other details

datadog-ddstaging bot commented Sep 24, 2024 • edited Loading

Datadog Report

⌛ Performance Regressions vs Default Branch (1)

andrewlock commented Sep 24, 2024

Execution-Time Benchmarks Report ⏱️

gleocadie left a comment

Choose a reason for hiding this comment

andrewlock commented Sep 24, 2024

Benchmarks Report for tracer 🐌

Benchmark details

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Faster 🎉 in #6071

Raw results

Raw results

Slower ⚠️ in #6071

Faster 🎉 in #6071

Raw results

Raw results

datadog-ddstaging bot commented Sep 24, 2024 •

edited

Loading