Log4Net guard AppenderAttachedImpl integration against NullReferenceException. - #8489
Closed
NachoEchevarria wants to merge 3 commits into
Closed
Log4Net guard AppenderAttachedImpl integration against NullReferenceException.#8489NachoEchevarria wants to merge 3 commits into
NachoEchevarria wants to merge 3 commits into
Conversation
Execution-Time Benchmarks Report ⏱️Execution-time results for samples comparing This PR (8489) and master. ✅ No regressions detected - check the details below Full Metrics ComparisonFakeDbCommand
HttpMessageHandler
Comparison explanationExecution-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 highlighted 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). Duration chartsFakeDbCommand (.NET Framework 4.8)gantt
title Execution time (ms) FakeDbCommand (.NET Framework 4.8)
dateFormat x
axisFormat %Q
todayMarker off
section Baseline
This PR (8489) - mean (73ms) : 70, 76
master - mean (73ms) : 70, 77
section Bailout
This PR (8489) - mean (80ms) : 76, 85
master - mean (77ms) : 74, 80
section CallTarget+Inlining+NGEN
This PR (8489) - mean (1,086ms) : 1032, 1140
master - mean (1,085ms) : 1036, 1134
FakeDbCommand (.NET Core 3.1)gantt
title Execution time (ms) FakeDbCommand (.NET Core 3.1)
dateFormat x
axisFormat %Q
todayMarker off
section Baseline
This PR (8489) - mean (117ms) : 111, 122
master - mean (114ms) : 110, 119
section Bailout
This PR (8489) - mean (118ms) : 111, 124
master - mean (115ms) : 111, 118
section CallTarget+Inlining+NGEN
This PR (8489) - mean (779ms) : 747, 811
master - mean (794ms) : 765, 824
FakeDbCommand (.NET 6)gantt
title Execution time (ms) FakeDbCommand (.NET 6)
dateFormat x
axisFormat %Q
todayMarker off
section Baseline
This PR (8489) - mean (104ms) : 97, 112
master - mean (105ms) : 101, 110
section Bailout
This PR (8489) - mean (102ms) : 100, 104
master - mean (103ms) : 99, 108
section CallTarget+Inlining+NGEN
This PR (8489) - mean (941ms) : 905, 978
master - mean (947ms) : 900, 993
FakeDbCommand (.NET 8)gantt
title Execution time (ms) FakeDbCommand (.NET 8)
dateFormat x
axisFormat %Q
todayMarker off
section Baseline
This PR (8489) - mean (101ms) : 97, 105
master - mean (101ms) : 96, 106
section Bailout
This PR (8489) - mean (106ms) : 101, 111
master - mean (105ms) : 101, 110
section CallTarget+Inlining+NGEN
This PR (8489) - mean (823ms) : 785, 861
master - mean (826ms) : 784, 869
HttpMessageHandler (.NET Framework 4.8)gantt
title Execution time (ms) HttpMessageHandler (.NET Framework 4.8)
dateFormat x
axisFormat %Q
todayMarker off
section Baseline
This PR (8489) - mean (210ms) : 200, 219
master - mean (203ms) : 195, 212
section Bailout
This PR (8489) - mean (212ms) : 203, 220
master - mean (207ms) : 198, 215
section CallTarget+Inlining+NGEN
This PR (8489) - mean (1,216ms) : 1158, 1274
master - mean (1,202ms) : 1158, 1247
HttpMessageHandler (.NET Core 3.1)gantt
title Execution time (ms) HttpMessageHandler (.NET Core 3.1)
dateFormat x
axisFormat %Q
todayMarker off
section Baseline
This PR (8489) - mean (297ms) : 284, 309
master - mean (294ms) : 280, 307
section Bailout
This PR (8489) - mean (299ms) : 287, 311
master - mean (295ms) : 280, 311
section CallTarget+Inlining+NGEN
This PR (8489) - mean (970ms) : 935, 1005
master - mean (981ms) : 952, 1011
HttpMessageHandler (.NET 6)gantt
title Execution time (ms) HttpMessageHandler (.NET 6)
dateFormat x
axisFormat %Q
todayMarker off
section Baseline
This PR (8489) - mean (291ms) : 277, 305
master - mean (286ms) : 276, 297
section Bailout
This PR (8489) - mean (293ms) : 281, 306
master - mean (286ms) : 276, 297
section CallTarget+Inlining+NGEN
This PR (8489) - mean (1,166ms) : 1119, 1213
master - mean (1,169ms) : 1122, 1216
HttpMessageHandler (.NET 8)gantt
title Execution time (ms) HttpMessageHandler (.NET 8)
dateFormat x
axisFormat %Q
todayMarker off
section Baseline
This PR (8489) - mean (292ms) : 275, 309
master - mean (289ms) : 276, 301
section Bailout
This PR (8489) - mean (292ms) : 276, 308
master - mean (290ms) : 275, 306
section CallTarget+Inlining+NGEN
This PR (8489) - mean (1,090ms) : 986, 1195
master - mean (1,070ms) : 983, 1158
|
||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
BenchmarksBenchmark execution time: 2026-04-22 16:25:01 Comparing candidate commit b1b28de in PR branch Found 0 performance improvements and 1 performance regressions! Performance is the same for 26 metrics, 0 unstable metrics, 60 known flaky benchmarks, 27 flaky benchmarks without significant changes.
|
NachoEchevarria
changed the title
NachoEchevarria
changed the title
NachoEchevarria
marked this pull request as ready for review
April 21, 2026 14:54
bouwkast
approved these changes
Apr 22, 2026
| if (!_loggedNullSettings) | ||
| { | ||
| _loggedNullSettings = true; | ||
| Log.Debug("log4net logs-injection skipped: CurrentTraceSettings was null."); |
Collaborator
There was a problem hiding this comment.
Unsure how valuable this is, if the theory here is correct there will only be an occasional missed injection
Collaborator
There was a problem hiding this comment.
(at least as I understand it)
| /// <param name="loggingEvent">The logging event</param> | ||
| /// <returns>Calltarget state value</returns> | ||
| internal static CallTargetState OnMethodBegin<TTarget, TLoggingEvent>(TTarget instance, TLoggingEvent loggingEvent) | ||
| internal static CallTargetState OnMethodBegin<TTarget, TLoggingEvent>(TTarget instance, TLoggingEvent? loggingEvent) |
Collaborator
There was a problem hiding this comment.
I don't think TLoggingEvent can be null?
Collaborator
Author
There was a problem hiding this comment.
Right! I have modified the code. Thanks!
| var tracer = Tracer.Instance; | ||
|
|
||
| var mutableSettings = tracer.CurrentTraceSettings.Settings; | ||
| var mutableSettings = tracer.CurrentTraceSettings?.Settings; |
Collaborator
There was a problem hiding this comment.
I wonder if this is the case if we'd need to guard this elsewhere for other instrumentations, if so something that we can do later
andrewlock
reviewed
Apr 22, 2026
andrewlock
left a comment
andrewlock
left a comment
Member
There was a problem hiding this comment.
Startup race: TracerManager._perTraceSettings is only populated partway through the constructor.
Wait, what? If this is true, then everything everywhere is doomed 😅
Collaborator
Author
LoggingEvent should never be null and anyway, we were already protected against that before this change. We are calling tracer.CurrentTraceSettings.Settings after calling Tracer.Instance, so it should be safe too... The more I think about it, the most weird this error seems. But it's there. |
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
3 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary of changes
Guards the log4net
AppenderAttachedImpl.AppendLoopOnAppendersCallTarget integration against aNullReferenceException.Reason for change
We have observed the following error in customer installations:
How it can be thrown
Hypothesis - Startup race: the field backing
Tracer.Instance.CurrentTraceSettingsis only assigned partway through theTracerManagerconstructor (line 116), so there's a window — roughly lines 84–115 of the ctor — whereTracer.Instance.CurrentTraceSettingsreturnsnull, and the subsequent.Settingsaccess NREs.Implementation details
tracer.CurrentTraceSettings?.Settings; short-circuit withCallTargetState.GetDefault()ifnullor ifLogsInjectionEnabledisfalse.Log.Debugduring startup ifCurrentTraceSettingsisnull, so the condition stays diagnosable. Bounded naturally by the brief startup window; no flag / atomic needed.#nullable enableon the file, with matching annotations on theOnMethodBegin/OnMethodEndsignatures.new CallTargetState(scope: null, state: null)withCallTargetState.GetDefault()for consistency across the three return paths (same value, clearer intent).Test coverage
Other details