Skip to content

Prevent the ANSI appender and %aspnet-request dropping events - #316

Draft
FreeAndNil wants to merge 15 commits into
masterfrom
Feature/316-content-loss
Draft

Prevent the ANSI appender and %aspnet-request dropping events#316
FreeAndNil wants to merge 15 commits into
masterfrom
Feature/316-content-loss

Conversation

@FreeAndNil

@FreeAndNil FreeAndNil commented Sep 3, 2026

Copy link
Copy Markdown
Contributor

Both findings let content the application logged make log4net discard the whole
event. That is worse than log injection: the sender chooses what is not
recorded.

  • f029 AnsiColorTerminalAppender. The branch meant for a one-character
    message read message[0] without checking there was one, so an event that
    rendered to nothing threw and AppenderSkeleton swallowed it. The reset codes
    now go at one computed offset, leaving no short-message branch to get wrong.
  • f019 %aspnet-request. Reading HttpRequest.Params runs ASP.NET request
    validation on first access, so a request carrying <script> threw inside the
    layout and the event was discarded. The converter reads through
    HttpRequest.Unvalidated, which keeps the content instead of degrading the
    field to NOT AVAILABLE. The try now also covers the body parse and
    ServerVariables, two further paths that could throw there.

Two changelog-only commits ride along: every 3.5.0 entry now credits the fixer
per CLAUDE.md, and the Ext.Mail and remote-syslog entries cite the findings
behind them. Those touch entries owned by #313, #314 and #315.

Tests: f029 pins all ten line-break branches. f019 adds five, net462 only, so
they run on the Windows leg alone; verified there at 384 passed on net462, 368
on net10.0, 50 on Ext.Mail, 0 warnings.

LocalSyslogAppender needs the same option, so nesting it in one of the two
appenders no longer fits.

Breaking for code naming RemoteSyslogAppender.SyslogNewLineHandling. Configuration
binds the value by name and is unaffected.
A newline in logged content ends the record for a syslog daemon that writes the
message through to a line oriented log, so content could forge a second entry that
looks authentic.

The code claimed syslog(3) escapes control characters itself. It does not: glibc
formats the buffer and hands it over, and the escaping seen on a mainstream Linux
is the daemon's. Measured with LOG_PERROR, an embedded newline comes out as two
lines.

NewLineHandling mirrors the option RemoteSyslogAppender has had all along, which
already escaped by default. Keep restores the previous behaviour. The remote
appender's habit of dropping non-ASCII is deliberately not copied.
OutputDebugStringW takes a null terminated string, so a NUL in logged content
ended the record there and dropped whatever the layout rendered after it.

The escape LocalSyslogAppender already had is now shared by both, since
EventLogAppender is the same shape and will want it too. Its tests moved onto the
shared helper with it.

The appender level test only runs on Windows: Append refuses to run elsewhere.
ReportEventW takes a null terminated string, so a NUL in logged content ended the
stored record there and dropped whatever the layout rendered after it. WriteEntry
raises nothing, so the record simply stored short and no ErrorHandler call fired.

Measured on Windows 11 build 26200: a 45 character message with a NUL at 23 stored
as its 23 character prefix.

Escaping happens before the size limit is applied, since it doubles each NUL, and
PrepareEventText exists so that ordering can be tested without an event log.


RFC 3164 allows only visible ASCII and space in the message, and everything else
fell through the loop unwritten. "Schoenwetter <CJK>" reached the collector as
"Schnwetter ", and a tab vanished from between its neighbours, with no marker and
no error.

Such characters are now written as a \uXXXX escape, which stays inside the allowed
range. Encoding still cannot make the message body non-ASCII, which the appender
page now says.
Does.Not.Contain is culture sensitive, and a culture sensitive comparison treats
NUL as ignorable: it reports a match in a string that contains none. Both new
escape tests therefore failed on Windows against correctly escaped output.

ContainsConstraint has no comparison knob at all, so these use
Contains.Substring(x).Using(StringComparison.Ordinal), negated with the ! operator
Constraint defines. The EventLog test asserts the whole value instead, which is
ordinal and pins the length too.

This is the shape f018 reports in StringMatchFilter, which is still open.
The limit is a whole record budget, and the log name, the source and the machine
name are spent from it one character for one. The fixed 31837 sat above the real
ceiling, so log4net truncated to a size the service then discarded: the event was
lost whole rather than shortened, with no exception and no record.

Measured on Windows 11 build 26200 over five source name lengths and two log names
with no residual: stored while message + logName + applicationName stays within
31736. One character more and nothing is stored.

ApplicationName defaults to the app domain name, so the consumer's assembly name
came out of the budget invisibly. A 1024 margin is held back because crossing the
line is not one lost message: the write still consumes log space, and a log given
about thirty of them was later found reporting a negative record count.

Truncation is now reported through the error handler. There is no channel where
the service records a dropped write, so that is the only signal available.
The helper held only the NUL escape. It now also escapes unpaired surrogates,
which f013 needs and f011 will, so the name no longer fitted.
The default writer encoding threw on an unpaired surrogate, and Send reads a throw
as a client that hung up, so one event reached nobody and disconnected everybody.
Escaped as \uXXXX now; the non-throwing encoding stays as belt and braces.
Four appenders have needed the same two escapes. New ones belong in ContentEscape,
and escaping comes before any length limit, not after.
File.CreateText throws on an unpaired surrogate, which abandoned the whole buffered
batch and left a truncated mail for the pickup service to send. Reverting the fix
leaves the test with a file that exists and is empty.

Writing under the final name stays as it was, with a note why.
FreeAndNil added a commit that referenced this pull request Sep 3, 2026
#316

- Reading HttpRequest.Params validates the query string, form and cookies on
  first access, so a request carrying <script> threw inside the layout and
  AppenderSkeleton discarded the whole event: a sender could suppress the log
  record of their own request.
- The converter now reads through HttpRequest.Unvalidated, so the content is
  kept rather than replaced by the not-available marker.
- The try now also covers the body parse and ServerVariables, which throw on an
  oversized body or a lost client. Verified on Windows: with no worker request
  behind it, ServerVariables is empty rather than throwing.
- Five tests, net462 only, so they run on the Windows leg alone. Reverting the
  fix fails exactly the two that assert the content survives.

audit da18b6f-f019
FreeAndNil added a commit that referenced this pull request Sep 3, 2026
- Logging an empty message threw IndexOutOfRangeException: the branch meant for
  a one-character message read message[0] without checking there was one.
- AppenderSkeleton caught it, so the event simply disappeared.
- The reset codes now go at one computed offset, leaving no short-message branch
  to get wrong.
- All ten line-break cases are pinned by test. They carry explicit names because
  dotnet test --filter cannot see them otherwise; CLAUDE.md records why.

audit da18b6f-f029
FreeAndNil added a commit that referenced this pull request Sep 3, 2026
#316

- Reading HttpRequest.Params validates the query string, form and cookies on
  first access, so a request carrying <script> threw inside the layout and
  AppenderSkeleton discarded the whole event: a sender could suppress the log
  record of their own request.
- The converter now reads through HttpRequest.Unvalidated, so the content is
  kept rather than replaced by the not-available marker.
- The try now also covers the body parse and ServerVariables, which throw on an
  oversized body or a lost client. Verified on Windows: with no worker request
  behind it, ServerVariables is empty rather than throwing.
- Five tests, net462 only, so they run on the Windows leg alone. Reverting the
  fix fails exactly the two that assert the content survives.

audit da18b6f-f019
@FreeAndNil
FreeAndNil force-pushed the Feature/316-content-loss branch from 411f7b5 to 5b392b3 Compare September 3, 2026 21:22
- Logging an empty message threw IndexOutOfRangeException: the branch meant for
  a one-character message read message[0] without checking there was one.
- AppenderSkeleton caught it, so the event simply disappeared.
- The reset codes now go at one computed offset, leaving no short-message branch
  to get wrong.
- All ten line-break cases are pinned by test. They carry explicit names because
  dotnet test --filter cannot see them otherwise; CLAUDE.md records why.

audit da18b6f-f029
#316

- Reading HttpRequest.Params validates the query string, form and cookies on
  first access, so a request carrying <script> threw inside the layout and
  AppenderSkeleton discarded the whole event: a sender could suppress the log
  record of their own request.
- The converter now reads through HttpRequest.Unvalidated, so the content is
  kept rather than replaced by the not-available marker.
- The try now also covers the body parse and ServerVariables, which throw on an
  oversized body or a lost client. Verified on Windows: with no worker request
  behind it, ServerVariables is empty rather than throwing.
- Five tests, net462 only, so they run on the Windows leg alone. Reverting the
  fix fails exactly the two that assert the content survives.

audit da18b6f-f019
CLAUDE.md wants the description to close with both sides, who raised it and who
did the work. Eleven entries named only the audit finding. Nothing but the
attribution changed.
The Ext.Mail send rework answers f004 and the remote syslog queue and pump work
answers f034, but neither pair named the finding. The other five 314 and 315
entries stay unattributed: they are our own, not audit findings.
@FreeAndNil
FreeAndNil force-pushed the Feature/316-content-loss branch from 5b392b3 to 4c1120c Compare September 3, 2026 21:27
@FreeAndNil FreeAndNil added this to the 3.5.0 milestone Sep 3, 2026
@FreeAndNil FreeAndNil changed the title Feature/316 content loss Prevent the ANSI appender and %aspnet-request dropping events (#316) Sep 3, 2026
@FreeAndNil FreeAndNil changed the title Prevent the ANSI appender and %aspnet-request dropping events (#316) Prevent the ANSI appender and %aspnet-request dropping events Sep 3, 2026
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.

1 participant