Skip to content

report an unexpected Telnet send failure instead of dropping the client - #331

Merged
FreeAndNil merged 2 commits into
masterfrom
Feature/331-telnet-send-failure
Sep 28, 2026
Merged

FreeAndNil merged 2 commits into
masterfrom
Feature/331-telnet-send-failure

Conversation

@FreeAndNil

Copy link
Copy Markdown
Contributor

Every throw from a Telnet write was read as a dead client, so a bug in what we write dropped every
client, one per event. That was f013.

Only SocketException, IOException and ObjectDisposedException disconnect now. The rest is
rethrown after the loop and reported by BackgroundSender.

Commit 2, test-only:

  • AdoNetAppenderTest twice, XmlConfiguratorTest, LogLogTest, StringFormatTest once each
  • ten provoked log4net:ERROR off stderr, two left, asserted by LogLogTest
  • CLAUDE.md gets the ReflectionExtensions convention from one home for the reflection in the tests #326

#331

SocketHandler.Send read every non-fatal exception as a hung up connection, so a
defect in what we write cost every client in turn. That is how f013 became a
mass disconnect.

* Only SocketException, IOException and ObjectDisposedException disconnect.
  Anything else is raised after the loop and reported by BackgroundSender.
* SocketHandler is protected, so a subclass calling Send sees exceptions it
  did not before.
Five tests provoked log4net:ERROR or WARN on purpose and let it reach stderr.

* AdoNetAppenderTest twice, XmlConfiguratorTest, LogLogTest and
  StringFormatTest once each.
* Ten messages down to two. The two left are LogLogTest.EmitInternalMessages,
  which asserts the console output itself.
@FreeAndNil FreeAndNil added this to the 3.5.0 milestone Sep 27, 2026
@FreeAndNil
FreeAndNil merged commit 408bbdd into master Sep 28, 2026
3 checks passed
@FreeAndNil
FreeAndNil deleted the Feature/331-telnet-send-failure branch September 28, 2026 06:40
@FreeAndNil

Copy link
Copy Markdown
Contributor Author

Implementation plan for #331, kept here for the record. Revised after the merge so that it describes the change as it landed.

Plan

PR #331: stop reading every exception as a hung-up client

The defect

TelnetAppender.SocketHandler.Send, src/log4net/Appender/TelnetAppender.cs:455:

try
{
  client.Send(message);
}
catch (Exception e) when (!e.IsFatal())
{
  // The client has closed the connection, remove it from our list
  client.Dispose();
  RemoveClient(client);
}

Any non-fatal exception is read as "this client hung up", and the client is disconnected with
nothing written anywhere. That is how f013 turned into a mass disconnect: a lone surrogate threw
while encoding, and every connected client was dropped in turn. f013 itself is fixed at the source,
SocketClient.Send escapes through ContentEscape.EscapeUnpairedSurrogates, but the catch that
misread it is untouched.

The agent instructions already name this: "A catch of Exception always carries when (!e.IsFatal()). The filter is not a licence to widen: a catch that handles one expected exception
keeps naming that type."

Two commits: the fix, and a test-only pass over the provoked internal logging.

Why it is safe to narrow now, and was not before

Since #318 nothing calls Send on the logging thread. The path is
Append -> _sender.TryEnqueue -> BackgroundSender<string> pump -> SendToClients ->
_handler.Send. The pump wraps the callback, BackgroundSender.cs:261-264:

catch (Exception e) when (!e.IsFatal())
{
  CountLost();
  Report($"[{_name}] Failed to send a logging event.", e);
}

So an exception that escapes Send is counted, reported through the appender's ErrorHandler, and
the pump carries on. The old reason to swallow everything, that a throw would reach the
application, no longer holds.

Commit 1: the change

SocketHandler.Send: two catch clauses in the loop over the clients.

  • catch (Exception e) when (e is SocketException or IOException or ObjectDisposedException)
    disconnects, as before: the socket operations, what a StreamWriter over a NetworkStream
    wraps a SocketException in, and a client disposed concurrently by Dispose or a second
    failure. Only these mean the client is gone.
  • catch (Exception e) when (!e.IsFatal()) is our own bug. It captures the first one as an
    ExceptionDispatchInfo and the loop goes on, so the remaining clients are still served; after
    the loop failure?.Throw() raises it with its stack intact, and the pump reports it.

The comment in the SocketClient constructor, which said that Send reads a throw as a hung up
client, now says the escaping keeps a future gap costing one character rather than failing the
write.

SocketHandler is protected, so a subclass calling Send sees those exceptions where it saw
none. Say so in the commit message and the changelog.

Commit 1: the test

src/log4net.Tests/Appender/TelnetAppenderTest.cs, NUnit 4, real sockets. One new test,
AnUnexpectedSendFailureKeepsTheClientConnected: an unexpected exception from a send leaves
the client connected and still serves the others.
No black-box route reaches it, since the three
narrowed types are the only ones a real socket raises, so drive the handler directly through
ReflectionExtensions:

  • Construct SocketHandler on the loopback address and a free port with
    NonPublicNestedType("SocketHandler").Construct<IDisposable>(...), connect two TcpClients and
    wait, with a bounded poll over the private _clients list, until both are registered.
  • Replace the first client's _writer with a StreamWriter over an UnflushableStream, a
    MemoryStream whose Flush throws NotSupportedException while armed. The first client fails
    and the second shows that the loop ran to the end.
  • handler.Invoke("Send", [payload]) must throw with that inner exception, the second client
    must receive the payload, read with a bounded loop and a receive timeout, and the client list
    must still hold two. Disarm the stream in a finally, or disposing the writer throws and hides
    whichever assertion failed.

Revert to fail, in place, not with git stash: with the wide catch back, the first client is
dropped and the throw never comes; with a rethrow inside the loop instead of after it, the second
client never receives. Each half of the change fails the test on its own.

The thing to note, not silently accept

OnlyOnceErrorHandler sets IsEnabled = false after the first error, OnlyOnceErrorHandler.cs:115.
So under the default handler a genuine bug on this path is reported once and every later one is as
silent as today. That is project-wide, not specific to this change, and fixing it is not part of
#331.

Commit 2: the internal logging that reaches the console

Unrelated to the catch, but test hygiene on the same rule, and small. Measured on net10.0, the
suite emits ten log4net:ERROR or WARN lines that tests provoke on purpose and let reach stderr.
Wrap each in LogLog.ExecuteWithoutEmittingInternalMessages, with a one line comment saying the
message is provoked:

  • AdoNetAppenderTest.NoBufferingTest and BufferingTest: no CommandText and no Layout, both
    warned about on purpose. The activation, the configuration and the logging calls go inside the
    wrapper, the assertions on the command stay outside.
  • XmlConfiguratorTest.ConfigureWithUnkownConfigFile and LogLogTest.LogReceivedAdapter: the
    LogReceivedAdapter is fed either way, so the wrapper only keeps the message off the console.
  • StringFormatTest.TestFormatString: the deliberately broken format call.

Ten messages down to two. The two left are LogLogTest.EmitInternalMessages, which asserts the
console output itself; a comment there says so. Do not wrap a message a test does not intend to
provoke, find out why it is there instead.

Also in this commit: the agent instructions get the ReflectionExtensions convention from #326,
replacing the sentence that pointed at the old BindingFlags pattern.

Changelog

src/changelog/3.5.0/331-telnet-unexpected-send-failure.xml, type="fixed", both id and link
on <issue>. Prose, no bullets. Name what it means: an unexpected failure while writing to a
Telnet client is now reported instead of silently disconnecting that client, only the three
exception types disconnect, anything else is raised once the remaining clients have been served,
and a SocketHandler subclass calling Send sees those exceptions where it saw none. Close with
(fixed by @FreeAndNil); there is no finding id, this came out of the #318 review.

Verification

dotnet build src/log4net.sln                                    # 0 warnings
dotnet test src/log4net.Tests/log4net.Tests.csproj

House rules

Branch Feature/331-telnet-send-failure off local master, not from origin/master. Leave the
work unstaged, write the commit messages to .git/plans/331/commit-1.txt and commit-2.txt and
stop. The maintainer commits.

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.

2 participants