Skip to content

Close the logger on exit#3374

Merged
kevingosse merged 4 commits into
masterfrom
kevin/nlog_wouldnt_have_failed
Oct 24, 2022
Merged

Close the logger on exit#3374
kevingosse merged 4 commits into
masterfrom
kevin/nlog_wouldnt_have_failed

Conversation

@kevingosse

@kevingosse kevingosse commented Oct 20, 2022

Copy link
Copy Markdown
Contributor

Summary of changes

Make sure to close the logger when the appdomain unloads.

Reason for change

Serilog doesn't automatically flush the logger on exit. Because of that, the underlying FileStream might be flushed during finalization, which would cause a crash if an I/O error happens at that moment.

Implementation details

Test coverage

"Testing the logger stuff is a nightmare" Andrew Lock, 2022

@kevingosse kevingosse added the area:tracer The core tracer library (Datadog.Trace, does not include OpenTracing, native code, or integrations) label Oct 20, 2022
@kevingosse
kevingosse requested a review from a team as a code owner October 20, 2022 11:50
andrewlock
andrewlock requested changes Oct 20, 2022
View reviewed changes
Comment thread tracer/src/Datadog.Trace/Logging/Internal/DatadogLogging.cs Outdated
andrewlock
andrewlock reviewed Oct 20, 2022
View reviewed changes
Comment thread tracer/src/Datadog.Trace/LifetimeManager.cs
@andrewlock

This comment has been minimized.

Sign in to view
@andrewlock

This comment has been minimized.

Sign in to view
@andrewlock

andrewlock commented Oct 21, 2022

Copy link
Copy Markdown
Member

Benchmarks Report 🐌

Benchmarks for #3374 compared to master:

  • 1 benchmarks are slower, with geometric mean 1.149
  • 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.AgentWriterBenchmark - Slower ⚠️ Same allocations ✔️

Slower ⚠️ in #3374

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.AgentWriterBenchmark.WriteAndFlushEnrichedTraces‑netcoreapp3.1 1.149 568,859.18 653,678.96

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master WriteAndFlushEnrichedTraces net472 797μs 677ns 2.53μs 0.398 0 0 3.22 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 569μs 607ns 2.27μs 0 0 0 2.63 KB
#3374 WriteAndFlushEnrichedTraces net472 796μs 428ns 1.6μs 0.393 0 0 3.22 KB
#3374 WriteAndFlushEnrichedTraces netcoreapp3.1 656μs 1.86μs 7.19μs 0 0 0 2.62 KB
Benchmarks.Trace.AppSecBodyBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master AllCycleSimpleBody net472 196ns 0.0355ns 0.123ns 0.0701 0 0 441 B
master AllCycleSimpleBody netcoreapp3.1 255ns 0.115ns 0.397ns 0.00592 0 0 440 B
master AllCycleMoreComplexBody net472 197ns 0.147ns 0.549ns 0.0662 0 0 417 B
master AllCycleMoreComplexBody netcoreapp3.1 251ns 0.133ns 0.499ns 0.00566 0 0 416 B
master BodyExtractorSimpleBody net472 290ns 0.329ns 1.23ns 0.0574 0 0 361 B
master BodyExtractorSimpleBody netcoreapp3.1 232ns 0.101ns 0.379ns 0.0037 0 0 272 B
master BodyExtractorMoreComplexBody net472 16μs 13.3ns 51.4ns 1.21 0.0159 0 7.62 KB
master BodyExtractorMoreComplexBody netcoreapp3.1 13μs 6.22ns 23.3ns 0.0907 0 0 6.75 KB
#3374 AllCycleSimpleBody net472 199ns 0.184ns 0.687ns 0.0701 0 0 441 B
#3374 AllCycleSimpleBody netcoreapp3.1 261ns 0.398ns 1.54ns 0.00607 0 0 440 B
#3374 AllCycleMoreComplexBody net472 196ns 0.0451ns 0.156ns 0.0663 0 0 417 B
#3374 AllCycleMoreComplexBody netcoreapp3.1 249ns 0.15ns 0.58ns 0.00589 0 0 416 B
#3374 BodyExtractorSimpleBody net472 281ns 0.177ns 0.662ns 0.0573 0 0 361 B
#3374 BodyExtractorSimpleBody netcoreapp3.1 242ns 0.118ns 0.441ns 0.00365 0 0 272 B
#3374 BodyExtractorMoreComplexBody net472 16μs 39.3ns 147ns 1.2 0.0159 0 7.62 KB
#3374 BodyExtractorMoreComplexBody netcoreapp3.1 12.4μs 4.17ns 15ns 0.0886 0 0 6.75 KB
Benchmarks.Trace.AspNetCoreBenchmark - Unknown 🤷 Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendRequest net472 0ns 0ns 0ns 0 0 0 0 b
master SendRequest netcoreapp3.1 181μs 195ns 753ns 0.179 0 0 20.67 KB
#3374 SendRequest net472 0ns 0ns 0ns 0 0 0 0 b
#3374 SendRequest netcoreapp3.1 179μs 173ns 670ns 0.269 0 0 20.66 KB
Benchmarks.Trace.DbCommandBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master ExecuteNonQuery net472 1.84μs 0.949ns 3.55ns 0.158 0.000917 0 995 B
master ExecuteNonQuery netcoreapp3.1 1.41μs 0.869ns 3.13ns 0.0135 0 0 984 B
#3374 ExecuteNonQuery net472 1.78μs 0.621ns 2.32ns 0.157 0.00089 0 995 B
#3374 ExecuteNonQuery netcoreapp3.1 1.44μs 0.659ns 2.55ns 0.0129 0 0 984 B
Benchmarks.Trace.ElasticsearchBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master CallElasticsearch net472 2.46μs 1.05ns 3.78ns 0.19 0 0 1.2 KB
master CallElasticsearch netcoreapp3.1 1.59μs 1.37ns 5.3ns 0.0151 0 0 1.14 KB
master CallElasticsearchAsync net472 2.71μs 0.822ns 3.18ns 0.212 0 0 1.34 KB
master CallElasticsearchAsync netcoreapp3.1 1.62μs 0.639ns 2.39ns 0.017 0 0 1.26 KB
#3374 CallElasticsearch net472 2.56μs 0.582ns 2.18ns 0.191 0 0 1.2 KB
#3374 CallElasticsearch netcoreapp3.1 1.55μs 1.19ns 4.44ns 0.0156 0 0 1.14 KB
#3374 CallElasticsearchAsync net472 2.65μs 1.23ns 4.77ns 0.213 0 0 1.34 KB
#3374 CallElasticsearchAsync netcoreapp3.1 1.64μs 0.898ns 3.36ns 0.0172 0 0 1.26 KB
Benchmarks.Trace.GraphQLBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master ExecuteAsync net472 2.64μs 1.5ns 5.81ns 0.233 0 0 1.47 KB
master ExecuteAsync netcoreapp3.1 1.69μs 0.786ns 3.04ns 0.0185 0 0 1.39 KB
#3374 ExecuteAsync net472 2.79μs 1.73ns 6.69ns 0.232 0 0 1.47 KB
#3374 ExecuteAsync netcoreapp3.1 1.75μs 0.404ns 1.51ns 0.0191 0 0 1.39 KB
Benchmarks.Trace.HttpClientBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendAsync net472 5.88μs 3.27ns 12.7ns 0.445 0 0 2.82 KB
master SendAsync netcoreapp3.1 3.67μs 1.26ns 4.88ns 0.0348 0 0 2.65 KB
#3374 SendAsync net472 5.93μs 2.06ns 7.97ns 0.448 0 0 2.82 KB
#3374 SendAsync netcoreapp3.1 3.69μs 1.51ns 5.85ns 0.0352 0 0 2.65 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 net472 3.14μs 1.99ns 7.7ns 0.298 0 0 1.88 KB
master EnrichedLog netcoreapp3.1 2.55μs 0.799ns 2.99ns 0.0254 0 0 1.91 KB
#3374 EnrichedLog net472 3.25μs 5.58ns 21.6ns 0.298 0 0 1.88 KB
#3374 EnrichedLog netcoreapp3.1 2.56μs 0.569ns 2.13ns 0.0259 0 0 1.91 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 net472 151μs 103ns 386ns 0.749 0.225 0 4.72 KB
master EnrichedLog netcoreapp3.1 119μs 108ns 390ns 0 0 0 4.55 KB
#3374 EnrichedLog net472 150μs 107ns 414ns 0.749 0.225 0 4.72 KB
#3374 EnrichedLog netcoreapp3.1 121μs 126ns 489ns 0.0602 0 0 4.55 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 net472 5.74μs 1.33ns 5.17ns 0.579 0.0029 0 3.65 KB
master EnrichedLog netcoreapp3.1 4.57μs 3.18ns 12.3ns 0.0526 0 0 3.98 KB
#3374 EnrichedLog net472 5.7μs 1.95ns 7.03ns 0.578 0.00285 0 3.65 KB
#3374 EnrichedLog netcoreapp3.1 4.34μs 4.02ns 15ns 0.0544 0 0 3.98 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 net472 2.3μs 1.1ns 4.11ns 0.225 0 0 1.42 KB
master SendReceive netcoreapp3.1 1.71μs 0.834ns 3.23ns 0.0188 0 0 1.37 KB
#3374 SendReceive net472 2.26μs 2.92ns 11.3ns 0.225 0 0 1.42 KB
#3374 SendReceive netcoreapp3.1 1.81μs 0.743ns 2.88ns 0.0182 0 0 1.37 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 net472 5.05μs 1.53ns 5.74ns 0.364 0 0 2.3 KB
master EnrichedLog netcoreapp3.1 4.32μs 2.62ns 9.79ns 0.0238 0 0 1.86 KB
#3374 EnrichedLog net472 5.01μs 2.24ns 8.66ns 0.364 0 0 2.3 KB
#3374 EnrichedLog netcoreapp3.1 4.25μs 0.85ns 3.18ns 0.0253 0 0 1.86 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 net472 1.17μs 0.276ns 1.03ns 0.136 0 0 859 B
master StartFinishSpan netcoreapp3.1 986ns 0.393ns 1.52ns 0.0109 0 0 808 B
master StartFinishScope net472 1.36μs 0.725ns 2.71ns 0.149 0 0 939 B
master StartFinishScope netcoreapp3.1 1.09μs 1.05ns 3.78ns 0.0124 0 0 928 B
#3374 StartFinishSpan net472 1.25μs 0.523ns 2.03ns 0.136 0 0 859 B
#3374 StartFinishSpan netcoreapp3.1 1μs 0.331ns 1.28ns 0.011 0 0 808 B
#3374 StartFinishScope net472 1.39μs 0.295ns 1.1ns 0.149 0 0 939 B
#3374 StartFinishScope netcoreapp3.1 1.18μs 0.34ns 1.27ns 0.0123 0 0 928 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 net472 1.52μs 0.772ns 2.99ns 0.149 0 0 939 B
master RunOnMethodBegin netcoreapp3.1 1.13μs 0.306ns 1.15ns 0.0124 0 0 928 B
#3374 RunOnMethodBegin net472 1.47μs 0.744ns 2.88ns 0.149 0 0 939 B
#3374 RunOnMethodBegin netcoreapp3.1 1.23μs 0.494ns 1.85ns 0.0123 0 0 928 B

@andrewlock

andrewlock commented Oct 21, 2022

Copy link
Copy Markdown
Member

Code Coverage Report 📊

✔️ Merging #3374 into master will not change line coverage
✔️ Merging #3374 into master will not change branch coverage
⛔ Merging #3374 into master will will increase complexity by 3

master #3374 Change
Lines 19594 / 27074 19565 / 27079
Lines % 72% 72% 0% ✔️
Branches 11593 / 16760 11591 / 16762
Branches % 69% 69% 0% ✔️
Complexity 18141 18144 3 ⛔

View the full report for further details:

Datadog.Trace Breakdown ✔️

master #3374 Change
Lines % 72% 72% 0% ✔️
Branches % 69% 69% 0% ✔️
Complexity 18141 18144 3 ⛔

The following classes have significant coverage changes.

File Line coverage change Branch coverage change Complexity change
Datadog.Trace.Ci.GitInfo -17% ⛔ -11% ⛔ 0 ✔️
Datadog.Trace.Logging.DatadogLogging -6% ⛔ 0% ✔️ 1 ⛔
Datadog.Trace.Logging.DatadogSerilogLogger -3% ⚠️ -8% ⛔ 2 ⛔
Datadog.Trace.Propagators.SpanContextPropagator 8% ✔️ 6% ✔️ 0 ✔️

View the full reports for further details:

@kevingosse
kevingosse merged commit 1950af4 into master Oct 24, 2022
@kevingosse
kevingosse deleted the kevin/nlog_wouldnt_have_failed branch October 24, 2022 12:49
@github-actions github-actions Bot added this to the vNext milestone Oct 24, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

@andrewlock andrewlock andrewlock approved these changes
@pierotibou pierotibou pierotibou approved these changes

Assignees

No one assigned

Labels

area:tracer The core tracer library (Datadog.Trace, does not include OpenTracing, native code, or integrations)

Projects

None yet

Milestone

2.18.0

Development

Successfully merging this pull request may close these issues.

3 participants

@kevingosse @andrewlock @pierotibou