Add try catch on shutdown#6378
Conversation
a7a5677 to
ab5b1c0
Compare
Datadog ReportBranch report: ✅ 0 Failed, 449800 Passed, 2721 Skipped, 19h 5m 11.23s Total Time |
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 (6378) - mean (69ms) : 66, 71
. : milestone, 69,
master - mean (69ms) : 66, 72
. : milestone, 69,
section CallTarget+Inlining+NGEN
This PR (6378) - mean (976ms) : 953, 1000
. : milestone, 976,
master - mean (983ms) : 961, 1006
. : milestone, 983,
gantt
title Execution time (ms) FakeDbCommand (.NET Core 3.1)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6378) - mean (108ms) : 106, 110
. : milestone, 108,
master - mean (108ms) : 105, 111
. : milestone, 108,
section CallTarget+Inlining+NGEN
This PR (6378) - mean (676ms) : 661, 691
. : milestone, 676,
master - mean (681ms) : 663, 699
. : milestone, 681,
gantt
title Execution time (ms) FakeDbCommand (.NET 6)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6378) - mean (91ms) : 89, 93
. : milestone, 91,
master - mean (91ms) : 88, 93
. : milestone, 91,
section CallTarget+Inlining+NGEN
This PR (6378) - mean (629ms) : 609, 650
. : milestone, 629,
master - mean (632ms) : 619, 645
. : milestone, 632,
gantt
title Execution time (ms) HttpMessageHandler (.NET Framework 4.6.2)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6378) - mean (191ms) : 187, 195
. : milestone, 191,
master - mean (190ms) : 185, 195
. : milestone, 190,
section CallTarget+Inlining+NGEN
This PR (6378) - mean (1,093ms) : 1058, 1129
. : milestone, 1093,
master - mean (1,090ms) : 1058, 1122
. : milestone, 1090,
gantt
title Execution time (ms) HttpMessageHandler (.NET Core 3.1)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6378) - mean (276ms) : 270, 281
. : milestone, 276,
master - mean (275ms) : 270, 281
. : milestone, 275,
section CallTarget+Inlining+NGEN
This PR (6378) - mean (865ms) : 837, 892
. : milestone, 865,
master - mean (869ms) : 844, 894
. : milestone, 869,
gantt
title Execution time (ms) HttpMessageHandler (.NET 6)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (6378) - mean (265ms) : 261, 269
. : milestone, 265,
master - mean (265ms) : 261, 269
. : milestone, 265,
section CallTarget+Inlining+NGEN
This PR (6378) - mean (848ms) : 815, 881
. : milestone, 848,
master - mean (847ms) : 817, 878
. : milestone, 847,
|
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 (6378) (11.205M) : 0, 11205049
master (10.950M) : 0, 10950268
benchmarks/2.9.0 (11.033M) : 0, 11032866
section Automatic
This PR (6378) (7.283M) : 0, 7282813
master (7.144M) : 0, 7144062
benchmarks/2.9.0 (7.786M) : 0, 7785853
section Trace stats
master (7.592M) : 0, 7592116
section Manual
master (11.151M) : 0, 11151368
section Manual + Automatic
This PR (6378) (6.803M) : 0, 6802716
master (6.721M) : 0, 6721227
section DD_TRACE_ENABLED=0
master (10.133M) : 0, 10132646
gantt
title Throughput Linux arm64 (Total requests)
dateFormat X
axisFormat %s
section Baseline
This PR (6378) (9.386M) : 0, 9386094
master (9.581M) : 0, 9581060
benchmarks/2.9.0 (9.495M) : 0, 9494821
section Automatic
This PR (6378) (6.289M) : 0, 6289038
master (6.411M) : 0, 6411077
section Trace stats
master (6.557M) : 0, 6557433
section Manual
master (9.539M) : 0, 9539314
section Manual + Automatic
This PR (6378) (5.945M) : 0, 5944959
master (5.854M) : 0, 5854294
section DD_TRACE_ENABLED=0
master (8.891M) : 0, 8890821
gantt
title Throughput Windows x64 (Total requests)
dateFormat X
axisFormat %s
section Baseline
This PR (6378) (10.027M) : 0, 10026994
master (10.194M) : 0, 10193580
benchmarks/2.9.0 (10.020M) : 0, 10019592
section Automatic
This PR (6378) (6.447M) : 0, 6447038
master (6.769M) : 0, 6768819
benchmarks/2.9.0 (7.255M) : 0, 7255257
section Trace stats
master (7.357M) : 0, 7356753
section Manual
master (10.447M) : 0, 10447376
section Manual + Automatic
This PR (6378) (6.147M) : 0, 6146600
master (5.985M) : 0, 5985300
section DD_TRACE_ENABLED=0
master (9.475M) : 0, 9475300
|
Benchmarks Report for tracer 🐌Benchmarks for #6378 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 - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.HttpClientBenchmark - Same speed ✔️ Same allocations ✔️Raw results
Benchmarks.Trace.ILoggerBenchmark - Faster 🎉 Same allocations ✔️
|
| Benchmark | base/diff | Base Median (ns) | Diff Median (ns) | Modality |
|---|---|---|---|---|
| Benchmarks.Trace.ILoggerBenchmark.EnrichedLog‑net6.0 | 1.116 | 1,628.44 | 1,459.79 |
Raw results
| Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
|---|---|---|---|---|---|---|---|---|---|
| master | EnrichedLog |
net6.0 | 1.63μs | 0.737ns | 2.66ns | 0.0228 | 0 | 0 | 1.64 KB |
| master | EnrichedLog |
netcoreapp3.1 | 2.32μs | 4.1ns | 15.9ns | 0.0219 | 0 | 0 | 1.64 KB |
| master | EnrichedLog |
net472 | 2.61μs | 1.97ns | 7.37ns | 0.249 | 0 | 0 | 1.57 KB |
| #6378 | EnrichedLog |
net6.0 | 1.46μs | 0.799ns | 2.99ns | 0.0234 | 0 | 0 | 1.64 KB |
| #6378 | EnrichedLog |
netcoreapp3.1 | 2.28μs | 0.758ns | 2.83ns | 0.0216 | 0 | 0 | 1.64 KB |
| #6378 | EnrichedLog |
net472 | 2.65μs | 1.24ns | 4.64ns | 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 | 119μs | 73.5ns | 265ns | 0 | 0 | 0 | 4.28 KB |
| master | EnrichedLog |
netcoreapp3.1 | 125μs | 148ns | 573ns | 0 | 0 | 0 | 4.28 KB |
| master | EnrichedLog |
net472 | 153μs | 104ns | 401ns | 0.687 | 0.229 | 0 | 4.46 KB |
| #6378 | EnrichedLog |
net6.0 | 119μs | 94.8ns | 355ns | 0.0604 | 0 | 0 | 4.28 KB |
| #6378 | EnrichedLog |
netcoreapp3.1 | 125μs | 195ns | 756ns | 0 | 0 | 0 | 4.28 KB |
| #6378 | EnrichedLog |
net472 | 153μs | 160ns | 619ns | 0.687 | 0.229 | 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.07μs | 1.91ns | 7.39ns | 0.0308 | 0 | 0 | 2.2 KB |
| master | EnrichedLog |
netcoreapp3.1 | 4.16μs | 3.72ns | 14.4ns | 0.0292 | 0 | 0 | 2.2 KB |
| master | EnrichedLog |
net472 | 4.93μs | 1.72ns | 6.42ns | 0.321 | 0 | 0 | 2.02 KB |
| #6378 | EnrichedLog |
net6.0 | 2.96μs | 1.33ns | 5.13ns | 0.0312 | 0 | 0 | 2.2 KB |
| #6378 | EnrichedLog |
netcoreapp3.1 | 4.16μs | 1.66ns | 6.42ns | 0.0289 | 0 | 0 | 2.2 KB |
| #6378 | EnrichedLog |
net472 | 4.86μs | 1.39ns | 5.38ns | 0.319 | 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.34μs | 0.734ns | 2.84ns | 0.0161 | 0 | 0 | 1.14 KB |
| master | SendReceive |
netcoreapp3.1 | 1.78μs | 0.893ns | 3.46ns | 0.0151 | 0 | 0 | 1.14 KB |
| master | SendReceive |
net472 | 2.09μs | 1.32ns | 5.12ns | 0.184 | 0 | 0 | 1.16 KB |
| #6378 | SendReceive |
net6.0 | 1.34μs | 0.558ns | 2.01ns | 0.0164 | 0 | 0 | 1.14 KB |
| #6378 | SendReceive |
netcoreapp3.1 | 1.71μs | 0.689ns | 2.67ns | 0.0153 | 0 | 0 | 1.14 KB |
| #6378 | SendReceive |
net472 | 2.21μs | 1.25ns | 4.69ns | 0.184 | 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.6μs | 2.99ns | 11.6ns | 0.0223 | 0 | 0 | 1.6 KB |
| master | EnrichedLog |
netcoreapp3.1 | 3.88μs | 3.83ns | 14.3ns | 0.0214 | 0 | 0 | 1.65 KB |
| master | EnrichedLog |
net472 | 4.43μs | 1.31ns | 5.09ns | 0.322 | 0 | 0 | 2.04 KB |
| #6378 | EnrichedLog |
net6.0 | 2.83μs | 1.05ns | 4.06ns | 0.0226 | 0 | 0 | 1.6 KB |
| #6378 | EnrichedLog |
netcoreapp3.1 | 3.85μs | 2.26ns | 8.75ns | 0.0212 | 0 | 0 | 1.65 KB |
| #6378 | EnrichedLog |
net472 | 4.4μs | 0.725ns | 2.71ns | 0.322 | 0 | 0 | 2.04 KB |
Benchmarks.Trace.SpanBenchmark - Same speed ✔️ Same allocations ✔️
Raw results
| Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
|---|---|---|---|---|---|---|---|---|---|
| master | StartFinishSpan |
net6.0 | 402ns | 0.756ns | 2.93ns | 0.00813 | 0 | 0 | 576 B |
| master | StartFinishSpan |
netcoreapp3.1 | 552ns | 0.799ns | 3.1ns | 0.00773 | 0 | 0 | 576 B |
| master | StartFinishSpan |
net472 | 603ns | 1.43ns | 5.53ns | 0.0917 | 0 | 0 | 578 B |
| master | StartFinishScope |
net6.0 | 538ns | 1.08ns | 4.17ns | 0.00966 | 0 | 0 | 696 B |
| master | StartFinishScope |
netcoreapp3.1 | 690ns | 1.15ns | 4.45ns | 0.00942 | 0 | 0 | 696 B |
| master | StartFinishScope |
net472 | 855ns | 1.8ns | 6.98ns | 0.104 | 0 | 0 | 658 B |
| #6378 | StartFinishSpan |
net6.0 | 448ns | 0.627ns | 2.35ns | 0.00804 | 0 | 0 | 576 B |
| #6378 | StartFinishSpan |
netcoreapp3.1 | 600ns | 1.71ns | 6.41ns | 0.0077 | 0 | 0 | 576 B |
| #6378 | StartFinishSpan |
net472 | 672ns | 1.04ns | 4.02ns | 0.0916 | 0 | 0 | 578 B |
| #6378 | StartFinishScope |
net6.0 | 487ns | 0.983ns | 3.81ns | 0.00978 | 0 | 0 | 696 B |
| #6378 | StartFinishScope |
netcoreapp3.1 | 703ns | 1.02ns | 3.93ns | 0.00942 | 0 | 0 | 696 B |
| #6378 | StartFinishScope |
net472 | 879ns | 1.49ns | 5.78ns | 0.104 | 0 | 0 | 658 B |
Benchmarks.Trace.TraceAnnotationsBenchmark - Same speed ✔️ Same allocations ✔️
Raw results
| Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated |
|---|---|---|---|---|---|---|---|---|---|
| master | RunOnMethodBegin |
net6.0 | 600ns | 0.881ns | 3.41ns | 0.00974 | 0 | 0 | 696 B |
| master | RunOnMethodBegin |
netcoreapp3.1 | 903ns | 1.62ns | 6.26ns | 0.0095 | 0 | 0 | 696 B |
| master | RunOnMethodBegin |
net472 | 1.08μs | 1.23ns | 4.6ns | 0.104 | 0 | 0 | 658 B |
| #6378 | RunOnMethodBegin |
net6.0 | 627ns | 0.598ns | 2.32ns | 0.00977 | 0 | 0 | 696 B |
| #6378 | RunOnMethodBegin |
netcoreapp3.1 | 840ns | 1.2ns | 4.66ns | 0.0093 | 0 | 0 | 696 B |
| #6378 | RunOnMethodBegin |
net472 | 1.13μs | 2.67ns | 10.3ns | 0.104 | 0 | 0 | 658 B |
## Summary of changes Add a big try-catch around `RunShutdownTasks()` ## Reason for change We spotted a crash where the app was shutting down but the machine was out of disk space, so writing logs in `DatadogLogging.CloseAndFlush()` threw an exception. ## Implementation details Added a big `try-catch` around the whole method. I added it just around `DatadogLogging.CloseAndFlush()` initially, but why bother being picky? 🤷♂️ ## Test coverage meh
Summary of changes
Add a big try-catch around
RunShutdownTasks()Reason for change
We spotted a crash where the app was shutting down but the machine was out of disk space, so writing logs in
DatadogLogging.CloseAndFlush()threw an exception.Implementation details
Added a big
try-catcharound the whole method. I added it just aroundDatadogLogging.CloseAndFlush()initially, but why bother being picky? 🤷♂️Test coverage
meh