-
Notifications
You must be signed in to change notification settings - Fork 141
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Update dotnet test
tests to take memory dump on hang
#6343
Conversation
Datadog ReportBranch report: ✅ 0 Failed, 451199 Passed, 2725 Skipped, 20h 0m 57.89s Total Time New Flaky Tests (2)
|
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:
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 (6343) - mean (70ms) : 66, 73
. : milestone, 70,
master - mean (69ms) : 65, 74
. : milestone, 69,
section CallTarget+Inlining+NGEN
This PR (6343) - mean (983ms) : 959, 1007
. : milestone, 983,
master - mean (976ms) : 953, 999
. : milestone, 976,
gantt
title Execution time (ms) FakeDbCommand (.NET Core 3.1)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6343) - mean (108ms) : 106, 111
. : milestone, 108,
master - mean (108ms) : 106, 110
. : milestone, 108,
section CallTarget+Inlining+NGEN
This PR (6343) - mean (682ms) : 666, 698
. : milestone, 682,
master - mean (678ms) : 659, 697
. : milestone, 678,
gantt
title Execution time (ms) FakeDbCommand (.NET 6)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6343) - mean (92ms) : 91, 94
. : milestone, 92,
master - mean (92ms) : 89, 94
. : milestone, 92,
section CallTarget+Inlining+NGEN
This PR (6343) - mean (629ms) : 616, 641
. : milestone, 629,
master - mean (633ms) : 614, 651
. : milestone, 633,
gantt
title Execution time (ms) HttpMessageHandler (.NET Framework 4.6.2)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6343) - mean (191ms) : 186, 196
. : milestone, 191,
master - mean (190ms) : 186, 194
. : milestone, 190,
section CallTarget+Inlining+NGEN
This PR (6343) - mean (1,090ms) : 1062, 1117
. : milestone, 1090,
master - mean (1,092ms) : 1068, 1116
. : milestone, 1092,
gantt
title Execution time (ms) HttpMessageHandler (.NET Core 3.1)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6343) - mean (277ms) : 272, 282
. : milestone, 277,
master - mean (276ms) : 272, 280
. : milestone, 276,
section CallTarget+Inlining+NGEN
This PR (6343) - mean (871ms) : 837, 905
. : milestone, 871,
master - mean (870ms) : 835, 905
. : milestone, 870,
gantt
title Execution time (ms) HttpMessageHandler (.NET 6)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6343) - mean (266ms) : 263, 269
. : milestone, 266,
master - mean (265ms) : 261, 269
. : milestone, 265,
section CallTarget+Inlining+NGEN
This PR (6343) - mean (848ms) : 820, 877
. : milestone, 848,
master - mean (850ms) : 811, 888
. : milestone, 850,
|
Throughput/Crank Report ⚡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 (6343) (11.180M) : 0, 11179976
master (10.997M) : 0, 10996550
benchmarks/2.9.0 (11.033M) : 0, 11032866
section Automatic
This PR (6343) (7.325M) : 0, 7325085
master (7.185M) : 0, 7184511
benchmarks/2.9.0 (7.786M) : 0, 7785853
section Trace stats
master (7.538M) : 0, 7538247
section Manual
master (11.069M) : 0, 11069430
section Manual + Automatic
This PR (6343) (6.781M) : 0, 6781346
master (6.738M) : 0, 6737616
section DD_TRACE_ENABLED=0
master (10.302M) : 0, 10301778
gantt
title Throughput Linux arm64 (Total requests)
dateFormat X
axisFormat %s
section Baseline
This PR (6343) (9.433M) : 0, 9432934
master (9.415M) : 0, 9414535
benchmarks/2.9.0 (9.495M) : 0, 9494821
section Automatic
This PR (6343) (6.377M) : 0, 6377106
master (6.358M) : 0, 6358468
section Trace stats
master (6.815M) : 0, 6815014
section Manual
master (9.493M) : 0, 9493123
section Manual + Automatic
This PR (6343) (5.930M) : 0, 5929820
master (5.926M) : 0, 5926110
section DD_TRACE_ENABLED=0
master (8.735M) : 0, 8735109
gantt
title Throughput Windows x64 (Total requests)
dateFormat X
axisFormat %s
section Baseline
This PR (6343) (10.089M) : 0, 10088878
master (10.430M) : 0, 10430317
benchmarks/2.9.0 (10.020M) : 0, 10019592
section Automatic
This PR (6343) (6.772M) : 0, 6771947
master (6.844M) : 0, 6843537
benchmarks/2.9.0 (7.255M) : 0, 7255257
section Trace stats
master (7.470M) : 0, 7470195
section Manual
master (10.484M) : 0, 10483521
section Manual + Automatic
This PR (6343) (6.234M) : 0, 6234264
master (6.451M) : 0, 6451333
section DD_TRACE_ENABLED=0
master (9.895M) : 0, 9894875
|
tracer/test/Datadog.Trace.TestHelpers.AutoInstrumentation/TestHelper.cs
Outdated
Show resolved
Hide resolved
Benchmarks Report for tracer 🐌Benchmarks for #6343 compared to master:
The following thresholds were used for comparing the benchmark speeds:
Allocation changes below 0.5% are ignored. Benchmark detailsBenchmarks.Trace.ActivityBenchmark - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.AgentWriterBenchmark - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.AspNetCoreBenchmark - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.DbCommandBenchmark - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.ElasticsearchBenchmark - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.GraphQLBenchmark - Slower
|
Benchmark | diff/base | Base Median (ns) | Diff Median (ns) | Modality |
---|---|---|---|---|
Benchmarks.Trace.GraphQLBenchmark.ExecuteAsync‑net6.0 | 1.130 | 1,191.82 | 1,346.21 |
Raw results
Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
---|---|---|---|---|---|---|---|---|---|
master | ExecuteAsync |
net6.0 | 1.19μs | 0.582ns | 2.18ns | 0.0132 | 0 | 0 | 952 B |
master | ExecuteAsync |
netcoreapp3.1 | 1.59μs | 1.3ns | 4.85ns | 0.0126 | 0 | 0 | 952 B |
master | ExecuteAsync |
net472 | 1.81μs | 0.76ns | 2.94ns | 0.145 | 0 | 0 | 915 B |
#6343 | ExecuteAsync |
net6.0 | 1.35μs | 0.925ns | 3.46ns | 0.0135 | 0 | 0 | 952 B |
#6343 | ExecuteAsync |
netcoreapp3.1 | 1.71μs | 1.67ns | 6.24ns | 0.0127 | 0 | 0 | 952 B |
#6343 | ExecuteAsync |
net472 | 1.8μs | 1.21ns | 4.69ns | 0.145 | 0 | 0 | 915 B |
Benchmarks.Trace.HttpClientBenchmark - Same speed ✔️ Same allocations ✔️
Raw results
Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
---|---|---|---|---|---|---|---|---|---|
master | SendAsync |
net6.0 | 4.45μs | 1.5ns | 5.8ns | 0.0311 | 0 | 0 | 2.31 KB |
master | SendAsync |
netcoreapp3.1 | 5.18μs | 2.63ns | 10.2ns | 0.0389 | 0 | 0 | 2.85 KB |
master | SendAsync |
net472 | 7.16μs | 1.74ns | 6.72ns | 0.494 | 0 | 0 | 3.12 KB |
#6343 | SendAsync |
net6.0 | 4.29μs | 1.89ns | 7.09ns | 0.0322 | 0 | 0 | 2.31 KB |
#6343 | SendAsync |
netcoreapp3.1 | 5.33μs | 3.2ns | 12.4ns | 0.0371 | 0 | 0 | 2.85 KB |
#6343 | SendAsync |
net472 | 7.41μs | 4.09ns | 14.2ns | 0.493 | 0 | 0 | 3.12 KB |
Benchmarks.Trace.ILoggerBenchmark - Same speed ✔️ Same allocations ✔️
Raw results
Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
---|---|---|---|---|---|---|---|---|---|
master | EnrichedLog |
net6.0 | 1.45μs | 1.41ns | 5.27ns | 0.0226 | 0 | 0 | 1.64 KB |
master | EnrichedLog |
netcoreapp3.1 | 2.3μs | 1.52ns | 5.68ns | 0.0218 | 0 | 0 | 1.64 KB |
master | EnrichedLog |
net472 | 2.62μs | 1.04ns | 4.01ns | 0.249 | 0 | 0 | 1.57 KB |
#6343 | EnrichedLog |
net6.0 | 1.45μs | 0.81ns | 3.03ns | 0.0234 | 0 | 0 | 1.64 KB |
#6343 | EnrichedLog |
netcoreapp3.1 | 2.25μs | 1.08ns | 4.19ns | 0.0225 | 0 | 0 | 1.64 KB |
#6343 | EnrichedLog |
net472 | 2.67μs | 4.91ns | 19ns | 0.249 | 0 | 0 | 1.57 KB |
Benchmarks.Trace.Log4netBenchmark - Same speed ✔️ Same allocations ✔️
Raw results
Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
---|---|---|---|---|---|---|---|---|---|
master | EnrichedLog |
net6.0 | 120μs | 235ns | 911ns | 0.061 | 0 | 0 | 4.28 KB |
master | EnrichedLog |
netcoreapp3.1 | 124μs | 145ns | 560ns | 0 | 0 | 0 | 4.28 KB |
master | EnrichedLog |
net472 | 152μs | 138ns | 534ns | 0.684 | 0.228 | 0 | 4.46 KB |
#6343 | EnrichedLog |
net6.0 | 120μs | 122ns | 457ns | 0 | 0 | 0 | 4.28 KB |
#6343 | EnrichedLog |
netcoreapp3.1 | 124μs | 167ns | 646ns | 0 | 0 | 0 | 4.28 KB |
#6343 | EnrichedLog |
net472 | 151μs | 187ns | 723ns | 0.682 | 0.227 | 0 | 4.46 KB |
Benchmarks.Trace.NLogBenchmark - Same speed ✔️ Same allocations ✔️
Raw results
Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
---|---|---|---|---|---|---|---|---|---|
master | EnrichedLog |
net6.0 | 3.02μs | 1.19ns | 4.59ns | 0.0303 | 0 | 0 | 2.2 KB |
master | EnrichedLog |
netcoreapp3.1 | 4.04μs | 1.3ns | 4.86ns | 0.0303 | 0 | 0 | 2.2 KB |
master | EnrichedLog |
net472 | 4.89μs | 1.19ns | 4.44ns | 0.321 | 0 | 0 | 2.02 KB |
#6343 | EnrichedLog |
net6.0 | 3.23μs | 1.57ns | 6.08ns | 0.0302 | 0 | 0 | 2.2 KB |
#6343 | EnrichedLog |
netcoreapp3.1 | 4.16μs | 2.65ns | 10.3ns | 0.0291 | 0 | 0 | 2.2 KB |
#6343 | EnrichedLog |
net472 | 4.86μs | 2.5ns | 9.67ns | 0.321 | 0 | 0 | 2.02 KB |
Benchmarks.Trace.RedisBenchmark - Same speed ✔️ Same allocations ✔️
Raw results
Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
---|---|---|---|---|---|---|---|---|---|
master | SendReceive |
net6.0 | 1.33μs | 0.984ns | 3.81ns | 0.0159 | 0 | 0 | 1.14 KB |
master | SendReceive |
netcoreapp3.1 | 1.76μs | 1.08ns | 4.19ns | 0.0152 | 0 | 0 | 1.14 KB |
master | SendReceive |
net472 | 2.1μs | 1.01ns | 3.78ns | 0.183 | 0 | 0 | 1.16 KB |
#6343 | SendReceive |
net6.0 | 1.38μs | 1.13ns | 4.36ns | 0.0164 | 0 | 0 | 1.14 KB |
#6343 | SendReceive |
netcoreapp3.1 | 1.76μs | 0.834ns | 3.12ns | 0.015 | 0 | 0 | 1.14 KB |
#6343 | SendReceive |
net472 | 2.06μs | 2.48ns | 9.6ns | 0.183 | 0 | 0 | 1.16 KB |
Benchmarks.Trace.SerilogBenchmark - Same speed ✔️ Same allocations ✔️
Raw results
Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
---|---|---|---|---|---|---|---|---|---|
master | EnrichedLog |
net6.0 | 2.66μs | 0.937ns | 3.51ns | 0.0215 | 0 | 0 | 1.6 KB |
master | EnrichedLog |
netcoreapp3.1 | 3.98μs | 2.76ns | 10.7ns | 0.0219 | 0 | 0 | 1.65 KB |
master | EnrichedLog |
net472 | 4.55μs | 2.45ns | 9.51ns | 0.323 | 0 | 0 | 2.04 KB |
#6343 | EnrichedLog |
net6.0 | 2.72μs | 0.921ns | 3.44ns | 0.0218 | 0 | 0 | 1.6 KB |
#6343 | EnrichedLog |
netcoreapp3.1 | 3.82μs | 3.16ns | 12.2ns | 0.0208 | 0 | 0 | 1.65 KB |
#6343 | EnrichedLog |
net472 | 4.35μs | 2.66ns | 9.94ns | 0.323 | 0 | 0 | 2.04 KB |
Benchmarks.Trace.SpanBenchmark - Slower ⚠️ Same allocations ✔️
Slower ⚠️ in #6343
Benchmark
diff/base
Base Median (ns)
Diff Median (ns)
Modality
Benchmarks.Trace.SpanBenchmark.StartFinishScope‑net6.0
1.128
483.73
545.77
Benchmark | diff/base | Base Median (ns) | Diff Median (ns) | Modality |
---|---|---|---|---|
Benchmarks.Trace.SpanBenchmark.StartFinishScope‑net6.0 | 1.128 | 483.73 | 545.77 |
Raw results
Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
---|---|---|---|---|---|---|---|---|---|
master | StartFinishSpan |
net6.0 | 405ns | 0.288ns | 1.11ns | 0.00814 | 0 | 0 | 576 B |
master | StartFinishSpan |
netcoreapp3.1 | 656ns | 0.217ns | 0.813ns | 0.00764 | 0 | 0 | 576 B |
master | StartFinishSpan |
net472 | 639ns | 0.675ns | 2.62ns | 0.0916 | 0 | 0 | 578 B |
master | StartFinishScope |
net6.0 | 484ns | 0.247ns | 0.925ns | 0.00971 | 0 | 0 | 696 B |
master | StartFinishScope |
netcoreapp3.1 | 758ns | 0.341ns | 1.28ns | 0.00944 | 0 | 0 | 696 B |
master | StartFinishScope |
net472 | 895ns | 0.456ns | 1.77ns | 0.104 | 0 | 0 | 658 B |
#6343 | StartFinishSpan |
net6.0 | 418ns | 0.331ns | 1.28ns | 0.00805 | 0 | 0 | 576 B |
#6343 | StartFinishSpan |
netcoreapp3.1 | 599ns | 0.701ns | 2.53ns | 0.00778 | 0 | 0 | 576 B |
#6343 | StartFinishSpan |
net472 | 709ns | 0.377ns | 1.46ns | 0.0918 | 0 | 0 | 578 B |
#6343 | StartFinishScope |
net6.0 | 546ns | 0.783ns | 3.03ns | 0.00983 | 0 | 0 | 696 B |
#6343 | StartFinishScope |
netcoreapp3.1 | 681ns | 0.61ns | 2.36ns | 0.00918 | 0 | 0 | 696 B |
#6343 | StartFinishScope |
net472 | 844ns | 0.399ns | 1.55ns | 0.104 | 0 | 0 | 658 B |
Benchmarks.Trace.TraceAnnotationsBenchmark - Slower ⚠️ Same allocations ✔️
Slower ⚠️ in #6343
Benchmark
diff/base
Base Median (ns)
Diff Median (ns)
Modality
Benchmarks.Trace.TraceAnnotationsBenchmark.RunOnMethodBegin‑net472
1.127
1,047.84
1,181.16
Benchmark | diff/base | Base Median (ns) | Diff Median (ns) | Modality |
---|---|---|---|---|
Benchmarks.Trace.TraceAnnotationsBenchmark.RunOnMethodBegin‑net472 | 1.127 | 1,047.84 | 1,181.16 |
Raw results
Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
---|---|---|---|---|---|---|---|---|---|
master | RunOnMethodBegin |
net6.0 | 646ns | 0.517ns | 1.93ns | 0.00975 | 0 | 0 | 696 B |
master | RunOnMethodBegin |
netcoreapp3.1 | 1μs | 0.992ns | 3.84ns | 0.00904 | 0 | 0 | 696 B |
master | RunOnMethodBegin |
net472 | 1.05μs | 0.503ns | 1.95ns | 0.104 | 0 | 0 | 658 B |
#6343 | RunOnMethodBegin |
net6.0 | 673ns | 0.565ns | 2.11ns | 0.00969 | 0 | 0 | 696 B |
#6343 | RunOnMethodBegin |
netcoreapp3.1 | 993ns | 0.626ns | 2.42ns | 0.0094 | 0 | 0 | 696 B |
#6343 | RunOnMethodBegin |
net472 | 1.18μs | 0.449ns | 1.74ns | 0.104 | 0 | 0 | 658 B |
Summary of changes
Updates
StartDotnetTestSample
to use the existingWaitForProcessResult
that takes a memory dumpReason for change
We've seen some of the CI Vis tests failing recently with hangs. Hopefully this well help diagnose the issue
Implementation details
Use the existing
WaitForProcessResult
- it's mostly the same code anyway and takes a memory dump if the process hasn't exited, and kills it, instead of waiting forever.Test coverage
If the tests pass, that's good enough for now