Skip to content

stop stale context reaching logical stacks and fixed events - #323

Merged
FreeAndNil merged 5 commits into
masterfrom
Feature/323-event-and-context-state
Sep 23, 2026
Merged

FreeAndNil merged 5 commits into
masterfrom
Feature/323-event-and-context-state

Conversation

@FreeAndNil

Copy link
Copy Markdown
Contributor

Fixed

  • Logical stack brought back old frames, audit da18b6f-f044
    • Dispose used the copy of the stack made at Push time
    • after Clear, or after two Pop calls, the old frames came back
    • it now cuts the stack that is in use and never adds to it
    • known limit: disposing a frame of another flow cuts this flow, so frames can be lost, but
      nothing is added
  • A second Fix opened the event cache again, audit da18b6f-f039
    • the cache was opened before we knew if there was anything to fix
    • another thread could then write its own identity, thread name or location into the event
    • before the fix: one hit after 56000 to 63000 calls, five runs of five. After: none in 2000000

Deprecated

  • log4net.Util.TwoArgAction, the old callback of the stack, now unused, to be removed in v4

Documented, not changed

  • %property in a PatternString-typed setting, audit da18b6f-f021
    • a path built from such a value is the operator's choice, see the model and the FAQ on path
      traversal
    • cleaning the value in the converter would change it everywhere, and in the wrong place
  • AspNetTraceAppender belongs to one request, audit da18b6f-f006
    • behind a buffering appender, a flush writes into the request that caused it
    • dropping older events instead would lose them, which is worse

Speed of the stack change

1M calls, best of 5, Release on net10.0:

case before after
push and dispose, depth 1 405 to 438 ns, 1272 B 412 to 458 ns, 1272 B
push and dispose, depth 3 1386 to 1433 ns, 3976 B 1414 to 1440 ns, 3976 B
dispose after Clear 548 ns, 1656 B 361 ns, 1016 B

The normal cases are the same within noise and use the same memory. The fixed case is 34 percent
faster.

@FreeAndNil FreeAndNil added this to the 3.5.0 milestone Sep 20, 2026
FreeAndNil added a commit that referenced this pull request Sep 21, 2026
- context value into a PatternString-typed config value: the operator's choice
- trustworthiness of that value: the deployer's responsibility
- comment at the converter, note in our FAQ, where the next reader looks

audit da18b6f-f021, no code change.
FreeAndNil added a commit that referenced this pull request Sep 21, 2026
- writes to HttpContext.Current of the appending thread
- behind a buffering appender a flush hits the triggering request
- a timestamp filter would drop foreign events, so documented not enforced

audit da18b6f-f006, no code change.
FreeAndNil added a commit that referenced this pull request Sep 21, 2026
- Dispose rebuilt the stack from the copy taken at Push time
- after Clear, or after a Pop below its depth, the earlier frames came back
- now trims the stack registered in the flow, never grows it
- the stack holds its owning stacks instead of a register callback
- residual: a foreign frame trims the current flow, loss not injection

1M ops, best of 5, Release on net10.0:

| case                 | before                  | after                   |
|----------------------|-------------------------|-------------------------|
| push/dispose depth 1 | 405 to 438 ns, 1272 B   | 412 to 458 ns, 1272 B   |
| push/dispose depth 3 | 1386 to 1433 ns, 3976 B | 1414 to 1440 ns, 3976 B |
| dispose after Clear  | 548 ns, 1656 B          | 361 ns, 1016 B          |

audit da18b6f-f044.
FreeAndNil added a commit that referenced this pull request Sep 21, 2026
- existed for the logical stack's register callback, now an owner reference
- unused in the tree, public so it stays for now
- marked obsolete, removal in version 4
@FreeAndNil
FreeAndNil force-pushed the Feature/323-event-and-context-state branch from e123b49 to 4ef6dea Compare September 21, 2026 18:21
FreeAndNil added a commit that referenced this pull request Sep 21, 2026
- the cache was unlocked before the fields to fix were determined
- a redundant Fix reopened it with nothing to do
- a reader then cached its own identity, thread name or location
- measured: a hit after 56000 to 63000 calls, five runs of five

audit da18b6f-f039.
- context value into a PatternString-typed config value: the operator's choice
- trustworthiness of that value: the deployer's responsibility
- comment at the converter, note in our FAQ, where the next reader looks

audit da18b6f-f021, no code change.
- writes to HttpContext.Current of the appending thread
- behind a buffering appender a flush hits the triggering request
- a timestamp filter would drop foreign events, so documented not enforced

audit da18b6f-f006, no code change.
- Dispose rebuilt the stack from the copy taken at Push time
- after Clear, or after a Pop below its depth, the earlier frames came back
- now trims the stack registered in the flow, never grows it
- the stack holds its owning stacks instead of a register callback
- residual: a foreign frame trims the current flow, loss not injection

1M ops, best of 5, Release on net10.0:

| case                 | before                  | after                   |
|----------------------|-------------------------|-------------------------|
| push/dispose depth 1 | 405 to 438 ns, 1272 B   | 412 to 458 ns, 1272 B   |
| push/dispose depth 3 | 1386 to 1433 ns, 3976 B | 1414 to 1440 ns, 3976 B |
| dispose after Clear  | 548 ns, 1656 B          | 361 ns, 1016 B          |

audit da18b6f-f044.
- existed for the logical stack's register callback, now an owner reference
- unused in the tree, public so it stays for now
- marked obsolete, removal in version 4
- the cache was unlocked before the fields to fix were determined
- a redundant Fix reopened it with nothing to do
- a reader then cached its own identity, thread name or location
- measured: a hit after 56000 to 63000 calls, five runs of five

audit da18b6f-f039.
@FreeAndNil
FreeAndNil force-pushed the Feature/323-event-and-context-state branch from 4ef6dea to e725966 Compare September 22, 2026 19:05
@FreeAndNil
FreeAndNil marked this pull request as ready for review September 22, 2026 19:07
@gdziadkiewicz
gdziadkiewicz requested a lite review from Copilot September 23, 2026 15:26

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Warning

Copilot couldn't run its full agentic review because it didn't start before the timeout. Make sure your repository has a runner available, or add a copilot-code-review.yml file specifying one with the runs-on attribute. See the docs for more details.

Copilot review overview

Review effort: Lite
Findings: 2 Medium severity

Open (2)
What changed in this PR

Fixes two concurrency/context bugs in log4net: (1) disposed LogicalThreadContext.Stacks frames resurrecting removed frames, and (2) redundant LoggingEvent.Fix reopening the event cache and allowing cross-thread contamination.

Changes:

  • Rework LogicalThreadContextStack ownership/registration so Dispose trims the currently-registered stack rather than restoring a stale copy, plus new regression tests.
  • Change LoggingEvent.FixVolatileData to only unlock the cache when there is actual work to do and make _cacheUpdatable volatile, plus a new multithreaded regression test.
  • Documentation/changelog updates for %property path traversal considerations, AspNetTraceAppender constraints, and deprecation of TwoArgAction.
File Description
src/​site/​antora/​modules/​ROOT/​pages/​manual/​faq.adoc Adds security note about %property expansion and path traversal risk.
src/​site/​antora/​modules/​ROOT/​pages/​manual/​configuration/​appenders.adoc Documents AspNetTraceAppender request/thread affinity constraint.
src/​log4net/​Util/​PatternStringConverters/​PropertyPatternConverter.cs Adds in-code comment referencing path-traversal guidance for %property.
src/​log4net/​Util/​LogicalThreadContextStacks.cs Changes stack creation to pass owner; adds owner APIs for current-stack lookup/registration.
src/​log4net/​Util/​LogicalThreadContextStack.cs Replaces callback delegate with owner reference; fixes Dispose to trim current flow.
src/​log4net/​Core/​LoggingEvent.cs Prevents redundant Fix from reopening cache; makes cache flag volatile.
src/​log4net/​Appender/​AspNetTraceAppender.cs Adds remarks warning not to wrap in buffering appenders.
src/​log4net.Tests/​Core/​FixingTest.cs Adds regression test for cross-thread identity caching via redundant Fix.
src/​log4net.Tests/​Context/​LogicalThreadContextTest.cs Adds regression tests for stack dispose not resurrecting frames across clear/pop/flows.
src/​changelog/​3.5.0/​323-logical-stack-dispose.xml Changelog entry for logical stack dispose fix.
src/​changelog/​3.5.0/​323-logging-event-fix-cache.xml Changelog entry for logging-event cache reopening fix.
src/​changelog/​3.5.0/​323-deprecate-twoargaction.xml Changelog entry for TwoArgAction deprecation.

💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.

Comment thread src/log4net.Tests/Core/FixingTest.cs
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants