Add more info when GenerateDumpIfDbgRequested fails (take 3) #6325

kevingosse · 2024-11-20T12:10:12Z

Summary of changes

Enable createdump diagnostics during the GenerateDumpIfDbgRequested test.

Reason for change

Thanks to the added information from #6197, I have good confidence that createdump is crashing before resuming the parent process. I hope that enabling diagnostic messages will give more insight as to why/where it crashes.

Implementation details

Setting COMPlus_CreateDumpDiagnostics=1

datadog-ddstaging · 2024-11-20T12:34:34Z

Datadog Report

Branch report: kevin/createdump_diag
Commit report: 9443269
Test service: dd-trace-dotnet

✅ 0 Failed, 457543 Passed, 3200 Skipped, 21h 20m 9.6s Total Time

andrewlock · 2024-11-20T12:39:23Z

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 (6325) - mean (72ms)  : 64, 80
     .   : milestone, 72,
    master - mean (72ms)  : 64, 80
     .   : milestone, 72,

    section CallTarget+Inlining+NGEN
    This PR (6325) - mean (1,110ms)  : 1093, 1128
     .   : milestone, 1110,
    master - mean (1,107ms)  : 1085, 1128
     .   : milestone, 1107,

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

    section CallTarget+Inlining+NGEN
    This PR (6325) - mean (770ms)  : 752, 787
     .   : milestone, 770,
    master - mean (771ms)  : 757, 785
     .   : milestone, 771,

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

    section CallTarget+Inlining+NGEN
    This PR (6325) - mean (723ms)  : 709, 737
     .   : milestone, 723,
    master - mean (726ms)  : 707, 745
     .   : milestone, 726,

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

    section CallTarget+Inlining+NGEN
    This PR (6325) - mean (1,211ms)  : 1191, 1231
     .   : milestone, 1211,
    master - mean (1,213ms)  : 1190, 1236
     .   : milestone, 1213,

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

    section CallTarget+Inlining+NGEN
    This PR (6325) - mean (946ms)  : 925, 967
     .   : milestone, 946,
    master - mean (948ms)  : 929, 967
     .   : milestone, 948,

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

    section CallTarget+Inlining+NGEN
    This PR (6325) - mean (939ms)  : 920, 958
     .   : milestone, 939,
    master - mean (931ms)  : 913, 950
     .   : milestone, 931,

gleocadie

LGTM

andrewlock · 2024-11-21T04:52:30Z

Benchmarks Report for tracer 🐌

Benchmarks for #6325 compared to master:

1 benchmarks are faster, with geometric mean 1.158
1 benchmarks are slower, with geometric mean 1.139
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	8.01μs	40.6ns	177ns	0.012	0.00399	0	5.61 KB
master	`StartStopWithChild`	netcoreapp3.1	10.1μs	52.5ns	241ns	0.0262	0.0157	0.00523	5.8 KB
master	`StartStopWithChild`	net472	16.4μs	51.6ns	193ns	1.03	0.301	0.0977	6.21 KB
#6325	`StartStopWithChild`	net6.0	7.93μs	44.8ns	323ns	0.0152	0.00762	0	5.61 KB
#6325	`StartStopWithChild`	netcoreapp3.1	10.1μs	54.3ns	317ns	0.0247	0.00986	0	5.8 KB
#6325	`StartStopWithChild`	net472	16.4μs	62.8ns	243ns	1.05	0.33	0.0989	6.22 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`WriteAndFlushEnrichedTraces`	net6.0	501μs	250ns	968ns	0	2.7 KB
master	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	645μs	335ns	1.3μs	0	2.7 KB
master	`WriteAndFlushEnrichedTraces`	net472	873μs	454ns	1.7μs	0.434	3.3 KB
#6325	`WriteAndFlushEnrichedTraces`	net6.0	508μs	345ns	1.34μs	0	2.7 KB
#6325	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	647μs	234ns	875ns	0	2.7 KB
#6325	`WriteAndFlushEnrichedTraces`	net472	876μs	775ns	3μs	0.437	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	200μs	1.16μs	9.1μs	0.2	18.73 KB
master	`SendRequest`	netcoreapp3.1	222μs	1.25μs	9.29μs	0.222	20.89 KB
master	`SendRequest`	net472	0ns	0ns	0ns	0	0 b
#6325	`SendRequest`	net6.0	216μs	1.26μs	12.1μs	0.235	18.73 KB
#6325	`SendRequest`	netcoreapp3.1	236μs	1.52μs	15.1μs	0.225	20.89 KB
#6325	`SendRequest`	net472	0.000112ns	7.83E‑05ns	0.000293ns	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	577μs	2.92μs	16.8μs	0.553	0	0	41.76 KB
master	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	675μs	3μs	11.6μs	0.336	0	0	41.83 KB
master	`WriteAndFlushEnrichedTraces`	net472	868μs	3.23μs	12.5μs	8.3	2.62	0.437	53.28 KB
#6325	`WriteAndFlushEnrichedTraces`	net6.0	577μs	2.98μs	14.9μs	0.561	0	0	41.81 KB
#6325	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	680μs	3.6μs	18μs	0.338	0	0	41.66 KB
#6325	`WriteAndFlushEnrichedTraces`	net472	874μs	3.84μs	16.3μs	8.19	2.59	0.431	53.3 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.03ns	3.84ns	0.014	0	1.02 KB
master	`ExecuteNonQuery`	netcoreapp3.1	1.77μs	3.27ns	12.7ns	0.0131	0	1.02 KB
master	`ExecuteNonQuery`	net472	2.09μs	1.04ns	3.75ns	0.156	0.00104	987 B
#6325	`ExecuteNonQuery`	net6.0	1.41μs	1.5ns	5.8ns	0.0147	0	1.02 KB
#6325	`ExecuteNonQuery`	netcoreapp3.1	1.83μs	1.58ns	6.13ns	0.0136	0	1.02 KB
#6325	`ExecuteNonQuery`	net472	2.08μs	1.34ns	5.18ns	0.156	0.00103	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.28μs	0.482ns	1.87ns	0.0135	976 B
master	`CallElasticsearch`	netcoreapp3.1	1.54μs	1.03ns	3.99ns	0.0129	976 B
master	`CallElasticsearch`	net472	2.51μs	1.16ns	4.5ns	0.157	995 B
master	`CallElasticsearchAsync`	net6.0	1.28μs	0.633ns	2.45ns	0.0135	952 B
master	`CallElasticsearchAsync`	netcoreapp3.1	1.65μs	0.898ns	3.36ns	0.014	1.02 KB
master	`CallElasticsearchAsync`	net472	2.56μs	0.795ns	2.98ns	0.167	1.05 KB
#6325	`CallElasticsearch`	net6.0	1.28μs	0.636ns	2.38ns	0.0133	976 B
#6325	`CallElasticsearch`	netcoreapp3.1	1.52μs	0.793ns	2.86ns	0.0126	976 B
#6325	`CallElasticsearch`	net472	2.61μs	1.73ns	6.47ns	0.157	995 B
#6325	`CallElasticsearchAsync`	net6.0	1.33μs	0.436ns	1.63ns	0.0133	952 B
#6325	`CallElasticsearchAsync`	netcoreapp3.1	1.67μs	1.59ns	5.95ns	0.0142	1.02 KB
#6325	`CallElasticsearchAsync`	net472	2.73μs	1.08ns	3.88ns	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.51μs	0.534ns	2.07ns	0.0134	952 B
master	`ExecuteAsync`	netcoreapp3.1	1.59μs	0.857ns	3.2ns	0.0127	952 B
master	`ExecuteAsync`	net472	1.8μs	0.547ns	2.12ns	0.145	915 B
#6325	`ExecuteAsync`	net6.0	1.36μs	0.89ns	3.45ns	0.0135	952 B
#6325	`ExecuteAsync`	netcoreapp3.1	1.68μs	1.8ns	6.97ns	0.0127	952 B
#6325	`ExecuteAsync`	net472	1.85μs	0.542ns	2.1ns	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.3μs	3.14ns	12.2ns	0.0325	2.31 KB
master	`SendAsync`	netcoreapp3.1	5.23μs	5.65ns	21.9ns	0.0368	2.85 KB
master	`SendAsync`	net472	7.23μs	8.75ns	33.9ns	0.494	3.12 KB
#6325	`SendAsync`	net6.0	4.28μs	2.45ns	9.49ns	0.0321	2.31 KB
#6325	`SendAsync`	netcoreapp3.1	5.35μs	2.7ns	10.5ns	0.0377	2.85 KB
#6325	`SendAsync`	net472	7.36μs	3.32ns	12.9ns	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.58μs	0.613ns	2.3ns	0.0232	1.64 KB
master	`EnrichedLog`	netcoreapp3.1	2.19μs	1.32ns	4.76ns	0.0221	1.64 KB
master	`EnrichedLog`	net472	2.7μs	5.51ns	21.3ns	0.25	1.57 KB
#6325	`EnrichedLog`	net6.0	1.44μs	1.24ns	4.65ns	0.0228	1.64 KB
#6325	`EnrichedLog`	netcoreapp3.1	2.17μs	0.655ns	2.36ns	0.0229	1.64 KB
#6325	`EnrichedLog`	net472	2.56μs	1.56ns	5.85ns	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	119μs	237ns	918ns	0.06	0	4.28 KB
master	`EnrichedLog`	netcoreapp3.1	124μs	114ns	443ns	0	0	4.28 KB
master	`EnrichedLog`	net472	152μs	187ns	725ns	0.687	0.229	4.46 KB
#6325	`EnrichedLog`	net6.0	120μs	125ns	485ns	0	0	4.28 KB
#6325	`EnrichedLog`	netcoreapp3.1	125μs	171ns	662ns	0	0	4.28 KB
#6325	`EnrichedLog`	net472	150μs	102ns	394ns	0.673	0.224	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.07μs	2.25ns	8.73ns	0.0306	2.2 KB
master	`EnrichedLog`	netcoreapp3.1	4.01μs	1.44ns	5.57ns	0.03	2.2 KB
master	`EnrichedLog`	net472	4.88μs	5.97ns	23.1ns	0.32	2.02 KB
#6325	`EnrichedLog`	net6.0	3.1μs	1.2ns	4.5ns	0.031	2.2 KB
#6325	`EnrichedLog`	netcoreapp3.1	4.17μs	1.87ns	7.24ns	0.0293	2.2 KB
#6325	`EnrichedLog`	net472	4.88μs	3.96ns	15.3ns	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.32μs	0.646ns	2.5ns	0.0158	1.14 KB
master	`SendReceive`	netcoreapp3.1	1.73μs	1.12ns	4.34ns	0.0148	1.14 KB
master	`SendReceive`	net472	1.99μs	1.25ns	4.84ns	0.183	1.16 KB
#6325	`SendReceive`	net6.0	1.28μs	0.647ns	2.33ns	0.0162	1.14 KB
#6325	`SendReceive`	netcoreapp3.1	1.78μs	1.03ns	3.86ns	0.0151	1.14 KB
#6325	`SendReceive`	net472	2.09μs	1.69ns	6.53ns	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.95μs	0.924ns	3.46ns	0.022	1.6 KB
master	`EnrichedLog`	netcoreapp3.1	3.85μs	2.7ns	10.5ns	0.021	1.65 KB
master	`EnrichedLog`	net472	4.3μs	1.44ns	5.4ns	0.323	2.04 KB
#6325	`EnrichedLog`	net6.0	2.73μs	0.998ns	3.86ns	0.0219	1.6 KB
#6325	`EnrichedLog`	netcoreapp3.1	3.88μs	1.48ns	5.74ns	0.0214	1.65 KB
#6325	`EnrichedLog`	net472	4.34μs	1.55ns	5.79ns	0.323	2.04 KB

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

Slower ⚠️ in #6325

Benchmark	diff/base	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.SpanBenchmark.StartFinishScope‑netcoreapp3.1	1.139	671.42	764.55

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`StartFinishSpan`	net6.0	493ns	0.527ns	2.04ns	0.00801	576 B
master	`StartFinishSpan`	netcoreapp3.1	552ns	0.94ns	3.64ns	0.00779	576 B
master	`StartFinishSpan`	net472	636ns	1.38ns	5.33ns	0.0917	578 B
master	`StartFinishScope`	net6.0	488ns	0.365ns	1.42ns	0.00966	696 B
master	`StartFinishScope`	netcoreapp3.1	671ns	0.68ns	2.63ns	0.00929	696 B
master	`StartFinishScope`	net472	971ns	3.45ns	13.4ns	0.104	658 B
#6325	`StartFinishSpan`	net6.0	455ns	0.273ns	1.06ns	0.00798	576 B
#6325	`StartFinishSpan`	netcoreapp3.1	550ns	0.325ns	1.26ns	0.00781	576 B
#6325	`StartFinishSpan`	net472	581ns	1.05ns	4.06ns	0.0917	578 B
#6325	`StartFinishScope`	net6.0	501ns	0.289ns	1.12ns	0.00965	696 B
#6325	`StartFinishScope`	netcoreapp3.1	764ns	0.659ns	2.55ns	0.00945	696 B
#6325	`StartFinishScope`	net472	910ns	1.77ns	6.84ns	0.104	658 B

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

Faster 🎉 in #6325

Benchmark	base/diff	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.TraceAnnotationsBenchmark.RunOnMethodBegin‑net6.0	1.158	677.49	584.88

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`RunOnMethodBegin`	net6.0	678ns	1.39ns	5.37ns	0.00992	696 B
master	`RunOnMethodBegin`	netcoreapp3.1	966ns	0.736ns	2.85ns	0.00918	696 B
master	`RunOnMethodBegin`	net472	1.1μs	2.28ns	8.83ns	0.104	658 B
#6325	`RunOnMethodBegin`	net6.0	585ns	0.538ns	2.08ns	0.00991	696 B
#6325	`RunOnMethodBegin`	netcoreapp3.1	909ns	1.04ns	4.04ns	0.00944	696 B
#6325	`RunOnMethodBegin`	net472	1.13μs	1.81ns	7.01ns	0.104	658 B

kevingosse requested a review from a team as a code owner November 20, 2024 12:10

andrewlock approved these changes Nov 20, 2024

View reviewed changes

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

Enable createdump diagnostics

9443269

kevingosse force-pushed the kevin/createdump_diag branch from 0651826 to 9443269 Compare November 20, 2024 13:51

gleocadie approved these changes Nov 20, 2024

View reviewed changes

kevingosse merged commit 6ea05b0 into master Nov 21, 2024
69 of 72 checks passed

kevingosse deleted the kevin/createdump_diag branch November 21, 2024 10:27

github-actions bot added this to the vNext-v3 milestone Nov 21, 2024

andrewlock added area:tests unit tests, integration tests and removed area:profiler Issues related to the continous-profiler labels Dec 18, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add more info when GenerateDumpIfDbgRequested fails (take 3) #6325

Add more info when GenerateDumpIfDbgRequested fails (take 3) #6325

kevingosse commented Nov 20, 2024

datadog-ddstaging bot commented Nov 20, 2024 •

edited

Loading

andrewlock commented Nov 20, 2024 •

edited

Loading

gleocadie left a comment

andrewlock commented Nov 21, 2024

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 #6325

Raw results

Faster 🎉 in #6325

Raw results

Add more info when GenerateDumpIfDbgRequested fails (take 3) #6325

Add more info when GenerateDumpIfDbgRequested fails (take 3) #6325

Conversation

kevingosse commented Nov 20, 2024

Summary of changes

Reason for change

Implementation details

datadog-ddstaging bot commented Nov 20, 2024 • edited Loading

Datadog Report

andrewlock commented Nov 20, 2024 • edited Loading

Execution-Time Benchmarks Report ⏱️

gleocadie left a comment

Choose a reason for hiding this comment

andrewlock commented Nov 21, 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

Raw results

Raw results

Slower ⚠️ in #6325

Raw results

Faster 🎉 in #6325

Raw results

datadog-ddstaging bot commented Nov 20, 2024 •

edited

Loading

andrewlock commented Nov 20, 2024 •

edited

Loading