This is an automated email from the ASF dual-hosted git repository. FreeAndNil pushed a commit to branch Feature/security-audit-hardening in repository https://gitbox.apache.org/repos/asf/logging-log4net.git
commit 86ecb1526ff9fbdb94b823a27f4e8f49cf250952 Author: Jan Friedrich <[email protected]> AuthorDate: Mon Aug 17 22:50:58 2026 +0200 flush TextWriterAppender under the appender lock Flush synchronized on a private object while Append runs under the lock taken by DoAppend, so a flush could run concurrently with a write to the same QuietTextWriter, which is not thread safe. The comment claiming the lock blocked any Append was left over from when it locked on this. All four lock sites in the class now take the inherited LockObj and the private object is gone, so no ordering between two locks remains. Taking LockObj in OnClose is safe because Close already holds it and Monitor is reentrant. Flush also returned true whatever happened. QuietTextWriter routes failing writes to the ErrorHandler but does not override Flush, so a failure from the underlying writer escaped to the caller. It is now reported with ErrorCode.FlushFailure and Flush returns false. The AdoNet test doubles gained the doc comments the rest of the test code has, matching Log4NetTransaction. Co-Authored-By: Claude Opus 5 (1M context) <[email protected]> --- .../3.4.0/309-flush-uses-the-appender-lock.xml | 15 +++ .../Appender/AdoNet/Log4NetCommand.cs | 24 +++++ .../Appender/AdoNet/Log4NetConnection.cs | 17 +++ .../Appender/TextWriterAppenderTest.cs | 116 +++++++++++++++++++++ src/log4net/Appender/TextWriterAppender.cs | 25 +++-- 5 files changed, 189 insertions(+), 8 deletions(-) diff --git a/src/changelog/3.4.0/309-flush-uses-the-appender-lock.xml b/src/changelog/3.4.0/309-flush-uses-the-appender-lock.xml new file mode 100644 index 00000000..90565811 --- /dev/null +++ b/src/changelog/3.4.0/309-flush-uses-the-appender-lock.xml @@ -0,0 +1,15 @@ +<?xml version="1.0" encoding="UTF-8"?> +<entry xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"; + xmlns="https://logging.apache.org/xml/ns"; + xsi:schemaLocation="https://logging.apache.org/xml/ns https://logging.apache.org/xml/ns/log4j-changelog-0.xsd"; + type="fixed"> + <issue id="309" link="https://github.com/apache/logging-log4net/pull/309"/> + <description format="asciidoc"> + make `TextWriterAppender` and the appenders deriving from it, including `FileAppender` and + `RollingFileAppender`, flush under the appender lock. `Flush` synchronized on a private object while + `Append` runs under the lock taken by `DoAppend`, so a flush could run concurrently with a write to + the same `QuietTextWriter`, which is not thread safe, and interleave or lose output. `Flush` also + returned `true` whatever happened and let a failure from the underlying writer escape to its + caller; it now reports through the `ErrorHandler` and returns `false` (audit 1231d72-f020) + </description> +</entry> diff --git a/src/log4net.Tests/Appender/AdoNet/Log4NetCommand.cs b/src/log4net.Tests/Appender/AdoNet/Log4NetCommand.cs index fee95a5d..7a44dea2 100644 --- a/src/log4net.Tests/Appender/AdoNet/Log4NetCommand.cs +++ b/src/log4net.Tests/Appender/AdoNet/Log4NetCommand.cs @@ -27,6 +27,9 @@ namespace log4net.Tests.Appender.AdoNet; internal sealed class Log4NetCommand : IDbCommand { + /// <summary> + /// Initializes a new instance and records it as the <see cref="MostRecentInstance"/>. + /// </summary> public Log4NetCommand() { MostRecentInstance = this; @@ -34,13 +37,16 @@ public Log4NetCommand() Parameters = new Log4NetParameterCollection(); } + /// <inheritdoc/> public void Dispose() { // empty } + /// <inheritdoc/> public IDbTransaction? Transaction { get; set; } + /// <inheritdoc/> public int ExecuteNonQuery() { string? payload = null; @@ -68,6 +74,9 @@ public int ExecuteNonQuery() return 0; } + /// <summary> + /// The number of successful <see cref="ExecuteNonQuery"/> calls on this instance. + /// </summary> public int ExecuteNonQueryCount { get; private set; } /// <summary> @@ -82,43 +91,58 @@ public int ExecuteNonQuery() /// </summary> public static List<string> ExecutedPayloads { get; } = []; + /// <inheritdoc/> public IDbDataParameter CreateParameter() => new Log4NetParameter(); #pragma warning disable CS8766 // Nullability of reference types in return type doesn't match implicitly implemented member (possibly because of nullability attributes). + /// <inheritdoc/> public string? CommandText { get; set; } #pragma warning restore CS8766 + /// <inheritdoc/> public CommandType CommandType { get; set; } + /// <inheritdoc/> public void Prepare() { // empty } + /// <inheritdoc/> public IDataParameterCollection Parameters { get; } + /// <summary> + /// The most recently constructed instance, so that a test can inspect what the appender used. + /// </summary> public static Log4NetCommand? MostRecentInstance { get; private set; } + /// <inheritdoc/> public void Cancel() => throw new NotImplementedException(); + /// <inheritdoc/> public IDataReader ExecuteReader() => throw new NotImplementedException(); + /// <inheritdoc/> public IDataReader ExecuteReader(CommandBehavior behavior) => throw new NotImplementedException(); + /// <inheritdoc/> public object ExecuteScalar() => throw new NotImplementedException(); + /// <inheritdoc/> public IDbConnection? Connection { get => throw new NotImplementedException(); set => throw new NotImplementedException(); } + /// <inheritdoc/> public int CommandTimeout { get => throw new NotImplementedException(); set => throw new NotImplementedException(); } + /// <inheritdoc/> public UpdateRowSource UpdatedRowSource { get => throw new NotImplementedException(); diff --git a/src/log4net.Tests/Appender/AdoNet/Log4NetConnection.cs b/src/log4net.Tests/Appender/AdoNet/Log4NetConnection.cs index 43364c51..f5324ea3 100644 --- a/src/log4net.Tests/Appender/AdoNet/Log4NetConnection.cs +++ b/src/log4net.Tests/Appender/AdoNet/Log4NetConnection.cs @@ -30,20 +30,29 @@ internal sealed class Log4NetConnection : IDbConnection { private bool _open; + /// <summary> + /// Initializes a new instance and records it as the <see cref="MostRecentInstance"/>. + /// </summary> public Log4NetConnection() => MostRecentInstance = this; + /// <inheritdoc/> public void Close() => _open = false; + /// <inheritdoc/> public ConnectionState State => _open ? ConnectionState.Open : ConnectionState.Closed; #pragma warning disable CS8766 // Nullability of reference types in return type doesn't match implicitly implemented member (possibly because of nullability attributes). + /// <inheritdoc/> public string? ConnectionString { get; set; } #pragma warning restore CS8766 + /// <inheritdoc/> public IDbTransaction BeginTransaction() => new Log4NetTransaction(); + /// <inheritdoc/> public IDbCommand CreateCommand() => new Log4NetCommand(); + /// <inheritdoc/> public void Open() { if (FailOnOpen) @@ -58,15 +67,23 @@ public void Open() /// </summary> public static bool FailOnOpen { get; set; } + /// <summary> + /// The most recently constructed instance, so that a test can inspect what the appender used. + /// </summary> public static Log4NetConnection? MostRecentInstance { get; private set; } + /// <inheritdoc/> public IDbTransaction BeginTransaction(IsolationLevel il) => throw new NotImplementedException(); + /// <inheritdoc/> public void ChangeDatabase(string databaseName) => throw new NotImplementedException(); + /// <inheritdoc/> public int ConnectionTimeout => throw new NotImplementedException(); + /// <inheritdoc/> public string Database => throw new NotImplementedException(); + /// <inheritdoc/> public void Dispose() => throw new NotImplementedException(); } diff --git a/src/log4net.Tests/Appender/TextWriterAppenderTest.cs b/src/log4net.Tests/Appender/TextWriterAppenderTest.cs new file mode 100644 index 00000000..e9c387c0 --- /dev/null +++ b/src/log4net.Tests/Appender/TextWriterAppenderTest.cs @@ -0,0 +1,116 @@ +#region Apache License +// +// Licensed to the Apache Software Foundation (ASF) under one or more +// contributor license agreements. See the NOTICE file distributed with +// this work for additional information regarding copyright ownership. +// The ASF licenses this file to you under the Apache License, Version 2.0 +// (the "License"); you may not use this file except in compliance with +// the License. You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. +// +#endregion + +using System; +using System.IO; + +using log4net.Appender; +using log4net.Core; +using log4net.Layout; + +using NUnit.Framework; + +namespace log4net.Tests.Appender; + +/// <summary> +/// Tests for <see cref="TextWriterAppender"/> +/// </summary> +[TestFixture] +public class TextWriterAppenderTest +{ + /// <summary> + /// A writer that accepts everything written to it but cannot be flushed, standing in for a full + /// disk or a broken stream. + /// </summary> + private sealed class UnflushableWriter : StringWriter + { + /// <inheritdoc/> + public override void Flush() => throw new IOException("Simulated failure to flush"); + } + + /// <summary> + /// Swallows what the appender reports, so that the tests observe the return value rather than + /// internal logging. + /// </summary> + private sealed class SilentErrorHandler : IErrorHandler + { + /// <inheritdoc/> + public void Error(string message, Exception? e, ErrorCode errorCode) + { } + + /// <inheritdoc/> + public void Error(string message, Exception e) + { } + + /// <inheritdoc/> + public void Error(string message) + { } + } + + /// <summary> + /// Flush reported success whatever happened. Its contract is to say whether the events were + /// flushed, and a caller such as a shutdown hook relies on that. + /// </summary> + [Test] + public void FlushReportsFailure() + => Assert.That(CreateAppender(new UnflushableWriter()).Flush(1000), Is.False); + + /// <summary> + /// A writer that flushes cleanly still has to report success. + /// </summary> + [Test] + public void FlushReportsSuccess() + => Assert.That(CreateAppender(new StringWriter()).Flush(1000), Is.True); + + /// <summary> + /// A failing flush must not escape to the caller. QuietTextWriter routes failing writes to the + /// ErrorHandler but does not override Flush, so the appender has to catch it. + /// </summary> + [Test] + public void FlushDoesNotThrow() + => Assert.That(() => CreateAppender(new UnflushableWriter()).Flush(1000), Throws.Nothing); + + /// <summary> + /// With ImmediateFlush there is nothing buffered, so the writer is never touched. + /// </summary> + [Test] + public void FlushIsANoOpWhenImmediateFlushIsSet() + { + TextWriterAppender appender = CreateAppender(new UnflushableWriter()); + appender.ImmediateFlush = true; + + Assert.That(appender.Flush(1000), Is.True); + } + + private static TextWriterAppender CreateAppender(TextWriter writer) + { + PatternLayout layout = new("%message%newline"); + layout.ActivateOptions(); + + TextWriterAppender appender = new() + { + Layout = layout, + ImmediateFlush = false, + ErrorHandler = new SilentErrorHandler(), + Writer = writer + }; + appender.ActivateOptions(); + return appender; + } +} diff --git a/src/log4net/Appender/TextWriterAppender.cs b/src/log4net/Appender/TextWriterAppender.cs index 046476c5..7fba8d21 100644 --- a/src/log4net/Appender/TextWriterAppender.cs +++ b/src/log4net/Appender/TextWriterAppender.cs @@ -89,7 +89,7 @@ public class TextWriterAppender : AppenderSkeleton get => QuietWriter; set { - lock (_syncRoot) + lock (LockObj) { Reset(); if (value is not null) @@ -204,7 +204,7 @@ protected override void Append(LoggingEvent[] loggingEvents) /// </remarks> protected override void OnClose() { - lock (_syncRoot) + lock (LockObj) { Reset(); } @@ -222,7 +222,7 @@ public override IErrorHandler ErrorHandler get => base.ErrorHandler; set { - lock (_syncRoot) + lock (LockObj) { if (value is null) { @@ -357,8 +357,6 @@ protected virtual void PrepareWriter() /// </remarks> protected QuietTextWriter? QuietWriter { get; set; } - private readonly object _syncRoot = new(); - /// <summary> /// The fully qualified type of the TextWriterAppender class. /// </summary> @@ -381,10 +379,21 @@ public override bool Flush(int millisecondsTimeout) return true; } - // lock(this) will block any Appends while the buffer is flushed. - lock (_syncRoot) + // Taking the appender lock blocks any Append while the buffer is flushed. QuietTextWriter is + // not thread safe, and Append holds this same lock through DoAppend. + lock (LockObj) { - QuietWriter?.Flush(); + try + { + QuietWriter?.Flush(); + } + catch (Exception e) when (!e.IsFatal()) + { + // QuietTextWriter routes failing writes to the ErrorHandler but does not override Flush, + // so a failure here would otherwise escape to the caller of Flush. + ErrorHandler.Error($"Failed to flush appender [{Name}].", e, ErrorCode.FlushFailure); + return false; + } } return true;
