fix: Log4Net integration filters SDK-internal log events to prevent infinite loops#5238
fix: Log4Net integration filters SDK-internal log events to prevent infinite loops#5238jamescrosswell wants to merge 7 commits into
Conversation
…nfinite loops Adds a logger-name filter (analogous to Serilog/MEL IsFromSentry checks) and an AsyncLocal re-entrance guard so that SDK diagnostic logs routed through a user-supplied Log4NetDiagnosticLogger are not captured as Sentry events, breaking the 429 → DiagnosticLogger.Log → SentryAppender → CaptureEvent → 429 cycle. Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>
Codecov Report✅ All modified and coverable lines are covered by tests. Additional details and impacted files@@ Coverage Diff @@
## main #5238 +/- ##
==========================================
- Coverage 74.12% 73.58% -0.55%
==========================================
Files 508 494 -14
Lines 18282 17893 -389
Branches 3574 3486 -88
==========================================
- Hits 13551 13166 -385
Misses 3861 3861
+ Partials 870 866 -4 ☔ View full report in Codecov by Sentry. 🚀 New features to boost your workflow:
|
The AsyncLocal re-entrance guard already prevents infinite loops from SDK-internal log events re-entering the appender. The IsSentryLogger name-based filter was redundant and silently dropped events from any user logger named "Sentry" or prefixed with "Sentry." — a valid naming choice that would have caused silent data loss. Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>
| public void Append_IsLoggingRateLimited_DoesNotCaptureEvent() | ||
| { | ||
| _ = _fixture.Hub.IsEnabled.Returns(true); | ||
| var capturedEvents = 0; | ||
| _fixture.Hub.When(h => h.CaptureEvent(Arg.Any<SentryEvent>())) | ||
| .Do(_ => | ||
| { | ||
| capturedEvents++; | ||
| // Simulate 429 - the transport will set IsLoggingRateLimited before logging the 429 | ||
| _fixture.IsLoggingRateLimited = true; | ||
| try | ||
| { | ||
| var sut = _fixture.GetSut(); | ||
| var reentrantEvt = new LoggingEvent(null, null, "app-logger", Level.Error, "429", null); | ||
| sut.DoAppend(reentrantEvt); | ||
| } | ||
| finally | ||
| { | ||
| _fixture.IsLoggingRateLimited = false; | ||
| } | ||
| }); | ||
|
|
||
| var sut = _fixture.GetSut(); | ||
| var evt = new LoggingEvent(null, null, "app-logger", Level.Error, "original", null); | ||
| sut.DoAppend(evt); | ||
|
|
||
| Assert.Equal(1, capturedEvents); | ||
| } | ||
| } |
There was a problem hiding this comment.
Append_IsLoggingRateLimited_DoesNotCaptureEvent doesn't isolate the rate-limit guard from the re-entrancy guard
The rate-limit test triggers DoAppend from inside the CaptureEvent callback, so IsReentrant.Value is already true when the inner call hits the guard — both conditions fire simultaneously and the test can't prove the _isLoggingRateLimited() check independently blocks capture. A bug that removed only that check would leave this test green.
Evidence
SentryAppender.AppendsetsIsReentrant.Value = truebefore callingAppendCore, and resets it infinally.AppendCorecalls_hub.CaptureEvent, which executes the.Do()callback synchronously while still inside thetryblock.- At that point
IsReentrant.ValueistrueAND_fixture.IsLoggingRateLimitedis set totrue, so the guardif (IsReentrant.Value || _isLoggingRateLimited())is satisfied by either condition alone. - Removing the
_isLoggingRateLimited()branch from the productionifwould not cause this test to fail. - A proper isolation test would call
sut.DoAppendfrom outside any active appender frame (e.g., directly before the outer call, withIsLoggingRateLimited = truealready set).
Identified by Warden code-review · UQV-B4J
By default,
SentryOptions.DiagnosticLoggeris eithernull(whenDebugis off) or aConsoleDiagnosticLogger/DebugDiagnosticLoggerthat writes toConsole.ErrororDebug.WriteLine. Neither of those has anything to do with log4net, so_options.LogWarning(...)inLogRateLimitednever touchesSentryAppenderat all. No loop possible.The problem occurs when the user does something like:
At that point
_options.LogWarning(...)→Log4NetDiagnosticLogger.Log→ log4net →SentryAppender.Append→CaptureEvent→ background worker → 429 → repeat. The user has literally wired the SDK's own error output back into the SDK's event pipeline.Solution
I've tried to add this:
sentry-dotnet/src/Sentry/Http/HttpTransportBase.cs
Lines 595 to 613 in a62bd4b
And then this:
sentry-dotnet/src/Sentry.Log4Net/SentryAppender.cs
Lines 81 to 94 in 99d2647
But ultimately I don't think there's any good solution to this problem. See this comment in my discussion with the AI overlords.
Aside (consistency)
Added an
AsyncLocal<bool>re-entrance guard toSentryAppender.Append(matching the Serilog and NLog pattern) so that synchronous re-entrant log calls are dropped.This doesn't address the original issue which stems from the Background Worker. The background worker is started with
Task.Run(DoWorkAsync)long before any appender call setsIsReentrant = true. So when LogRateLimited → _options.LogWarning fires on the background worker thread,IsReentrant.Valueis always false there.Closes #2953
#skip-changelog