Skip to content

Feature/315 local syslog newlines - #315

Draft
FreeAndNil wants to merge 23 commits into
masterfrom
Feature/315-local-syslog-newlines
Draft

Feature/315 local syslog newlines#315
FreeAndNil wants to merge 23 commits into
masterfrom
Feature/315-local-syslog-newlines

Conversation

@FreeAndNil

@FreeAndNil FreeAndNil commented Sep 1, 2026

Copy link
Copy Markdown
Contributor

Follow-ups from the second security scan, stacked on #314. One rule, applied to
every sink that had got it wrong: content a sink cannot carry is escaped visibly,
never silently deleted, and never allowed to cost the record or the event.

  • LocalSyslogAppender escapes newlines, which reached syslog(3) unchanged and
    let content forge a second record. NewLineHandling mirrors the remote appender,
    and SyslogNewLineHandling moves out of RemoteSyslogAppender so both can use
    it. Measured: glibc does no escaping of its own, contrary to the old comment.
  • EventLogAppender and OutputDebugStringAppender escape NUL, which ended the
    stored record with no error. Measured on Windows: a 45 character message with a
    NUL at 23 stored as its 23 character prefix.
  • RemoteSyslogAppender escapes characters outside RFC 3164 rather than deleting
    them. "Schönwetter 你好" reached the collector as "Schnwetter ".
  • TelnetAppender and SmtpPickupDirAppender escape unpaired surrogates. Both
    used a writer whose encoding throws: the first disconnected every connected
    client, the second destroyed the whole buffered batch and left a truncated mail.
  • EventLogAppender's size limit is computed rather than guessed. The old constant
    sat above the point where the service silently discards the record, so log4net
    truncated events into oblivion.

Behaviour changes: syslog exception traces are now one escaped record instead of
several lines, Keep restores the old behaviour; RemoteSyslogAppender. SyslogNewLineHandling moves namespace,
configuration binds by value name and is unaffected.

FreeAndNil added a commit that referenced this pull request Sep 1, 2026
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.
FreeAndNil added a commit that referenced this pull request Sep 1, 2026
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.
FreeAndNil added a commit that referenced this pull request Sep 1, 2026
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.
FreeAndNil added a commit that referenced this pull request Sep 1, 2026
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.
FreeAndNil added a commit that referenced this pull request Sep 1, 2026


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.
FreeAndNil added a commit that referenced this pull request Sep 2, 2026
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.
FreeAndNil added a commit that referenced this pull request Sep 2, 2026
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.
FreeAndNil added a commit that referenced this pull request Sep 2, 2026
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.
FreeAndNil added a commit that referenced this pull request Sep 2, 2026
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.
FreeAndNil added a commit that referenced this pull request Sep 2, 2026
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.
@FreeAndNil
FreeAndNil force-pushed the Feature/315-local-syslog-newlines branch from e722104 to 6aca022 Compare September 2, 2026 04:32
FreeAndNil added a commit that referenced this pull request Sep 2, 2026


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.
FreeAndNil added a commit that referenced this pull request Sep 2, 2026
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.
FreeAndNil added a commit that referenced this pull request Sep 2, 2026
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.
FreeAndNil added a commit that referenced this pull request Sep 2, 2026
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.
FreeAndNil added a commit that referenced this pull request Sep 2, 2026
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.
@FreeAndNil
FreeAndNil force-pushed the Feature/315-local-syslog-newlines branch from 6aca022 to 3e5e016 Compare September 2, 2026 19:20
FreeAndNil added a commit that referenced this pull request Sep 2, 2026
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.
FreeAndNil added a commit that referenced this pull request Sep 2, 2026


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.
FreeAndNil added a commit that referenced this pull request Sep 2, 2026
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.
FreeAndNil added a commit that referenced this pull request Sep 2, 2026
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.
@FreeAndNil
FreeAndNil force-pushed the Feature/315-local-syslog-newlines branch from 3e5e016 to 65c603f Compare September 2, 2026 20:44
FreeAndNil added a commit that referenced this pull request Sep 2, 2026
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.
FreeAndNil added a commit that referenced this pull request Sep 2, 2026
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.
FreeAndNil added a commit that referenced this pull request Sep 2, 2026
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.
FreeAndNil added a commit that referenced this pull request Sep 2, 2026


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.
FreeAndNil added a commit that referenced this pull request Sep 2, 2026
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.
FreeAndNil added a commit that referenced this pull request Sep 2, 2026
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.
An appender sends while it holds the appender lock, so a slow sink stalls the
logging call and every thread queued behind it. BackgroundSender hands the work
to one thread with a bounded queue: the caller waits at most the enqueue timeout.

It avoids what the RemoteSyslogAppender pump gets wrong. The queue is bounded,
the whole pump body is guarded so a fault cannot pass unobserved, Close drains
under one deadline and then cancels the send in flight, and drops are counted and
reported. Flush(timeout) can answer honestly because its marker travels in the
queue. Nothing the pump thread calls may throw, the error handler included, since
an escaping exception there would take the process down.

No appender uses it yet.
The next release adds public API, so it is a minor one.

scripts/update-version.ps1 assumes the old version is the released one, so it also
set Log4NetPackageVersion and the examples version to 3.4.1; both belong at 3.4.0.
package-lock.json is not covered by the script at all.
Tests had no access to IsFatal or the EnsureNotNull family and hand-rolled the
checks instead. Linking it needs NotNullAttribute and ValidatedNotNullAttribute
too, or the compiler reports CS0122.
SmtpClient.Timeout defaults to 100 seconds and the appender never set it. The mail
goes out under the appender lock, so a server that accepts the connection and then
stops answering suspended every thread logging through the appender for two minutes.

There is no value meaning "wait forever": SmtpClient rejects a negative timeout and
treats 0 as "do not wait", so SendTimeoutMillis rejects both.
MailKit waits 100 seconds per operation by default and the mail goes out under the
appender lock, so an unresponsive server suspended every thread logging through it.

SendTimeoutMillis is a deadline for the whole send, passed as a CancellationToken:
a per operation timeout still permits a multiple of itself overall. Measured, a
server delaying 2s per step finished in 14.2s against a 3s per operation timeout,
and in 3.1s against a 3s deadline. Disconnect keeps no token, as it runs in the
finally and would otherwise replace the failure that got us there.
The mail went out under the appender lock, so the thread that logged, and every
thread behind it, waited for the SMTP server. It is now handed to a BackgroundSender
holding at most SendQueueSize mails (500), and a logging call waits at most
EnqueueTimeoutMillis (5000) for room.

Behaviour changes: failures reach the error handler after the logging call has
returned, queued mail is lost if the process is killed, and Flush now honours its
timeout. A failed send no longer reports the queue-pressure message as well, which
was wrong: nothing was dropped for lack of room.
Flush(int) returned true unconditionally. For a lossy appender, flushing does
nothing at all and every buffered event stays in the buffer, so the answer was
simply untrue.

The timeout stays unused and is now documented as such: IFlushable already says it
only applies to appenders that send asynchronously.
The appender sends through the connection its pump owns and never touched the one
inherited from UdpAppender, so that socket existed only to bind localPort a second
time and be closed again at shutdown.

Connecting also moved inside the guard, with a message of its own. It sat outside,
so a failure ended the pump unobserved and every later event queued behind a sender
that was no longer running.
The appender's own pump held an unbounded queue, so a syslog server that stopped
accepting datagrams grew it until the process ran out of memory. Shutdown waited
five seconds and then abandoned a drain that had no limit of its own.

It now holds SendQueueSize datagrams (500), a logging call waits at most
EnqueueTimeoutMillis (5000) for room, losses are counted, and Flush honours its
timeout: this appender sends asynchronously, so unlike a buffering one the timeout
means something here.
Retrying after a rolled back transaction was added in 3.4.0 to save the events
around the one the database rejected. A batch that fails outright, a missing table
or permission, then cost one round trip per event: measured 21 for a batch of 20,
so 513 for a full buffer where there had been 1.

It gives up after five consecutive failures. Failures spread through a batch do not
count towards that, so a single rejected event still costs only itself.

SendBuffer contains per-event failures and returns normally, so the retry loop had
no way to tell one from a success. A private flag gives it one.
It is the re-opened 1231d72-f009, which the second scan reports as a prior fix
that was incomplete rather than as a new finding. da18b6f-f004 is the Ext.Mail
batch loss and has nothing to do with it.

The other 19 citations across 3.4.0 and 3.5.0 were checked against both reports
and match.
Flush(bool) only moves the buffer into the queue; Flush(int) waits for the sender.
The test used the first and asserted immediately, so it passed on Linux and failed
on macOS and Windows.

RequiresALayout asserted that nothing was sent without waiting either, which an
asynchronous send makes true regardless.
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.
@FreeAndNil
FreeAndNil force-pushed the Feature/315-local-syslog-newlines branch from 65c603f to fc122b1 Compare September 2, 2026 21:32
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 FreeAndNil added this to the 3.5.0 milestone Sep 2, 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