You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@logging.apache.org by fr...@apache.org on 2026/09/19 19:53:22 UTC
(logging-log4net) branch Feature/322-reconfiguration-file-lock created (now 6ec0058a)
This is an automated email from the ASF dual-hosted git repository.
FreeAndNil pushed a change to branch Feature/322-reconfiguration-file-lock
in repository https://gitbox.apache.org/repos/asf/logging-log4net.git
at 6ec0058a close the outgoing appenders before activating the new ones #321
This branch includes the following new commits:
new 6ec0058a close the outgoing appenders before activating the new ones #321
The 1 revisions listed above as "new" are entirely new to this
repository and will be described in separate emails. The revisions
listed as "add" were already present in the repository and have only
been added to this reference.
(logging-log4net) 01/01: close the outgoing appenders before activating the new ones #321
Posted by fr...@apache.org.
This is an automated email from the ASF dual-hosted git repository.
FreeAndNil pushed a commit to branch Feature/322-reconfiguration-file-lock
in repository https://gitbox.apache.org/repos/asf/logging-log4net.git
commit 6ec0058a48c05d8cc73f63f6da71cc99af6b47da
Author: Jan Friedrich <fr...@apache.org>
AuthorDate: Sat Sep 19 21:53:01 2026 +0200
close the outgoing appenders before activating the new ones #321
- XmlHierarchyConfigurator activated a new appender while the outgoing
one still held its file, so ConfigureAndWatch failed with "Unable to
acquire lock on file"
- regression from 592d18de (#287)
- ParseAppender collects into _pendingActivations, which Configure
drains once every logger has swapped
- the symptom is Windows only: .NET on Linux does not enforce FileShare
within a process, so the test asserts the open/close order instead
---
CLAUDE.md | 4 +
.../3.5.0/321-reconfiguration-appender-overlap.xml | 12 ++
.../Config/XmlConfiguratorReconfigurationTest.cs | 148 +++++++++++++++++++++
.../Hierarchy/XmlHierarchyConfigurator.cs | 46 ++++++-
4 files changed, 203 insertions(+), 7 deletions(-)
diff --git a/CLAUDE.md b/CLAUDE.md
index 0da68f39..793fa4f7 100644
--- a/CLAUDE.md
+++ b/CLAUDE.md
@@ -167,6 +167,10 @@ almost always be doing.
Reproduced with `[TestCase("one", "\x1b[0m")]`; a single argument holding the same escape is
fine, so it takes two arguments and an escape character. `AnsiColorTerminalAppenderTest` names
all ten of its cases for that reason, and a filtered run there is 54 ms against 9 s for the suite.
+- **A test that needs a folder takes `using AutoTempFolder folder = new();` from
+ `PeanutButter.Utils`**, as a local in the test method rather than a fixture field. It creates the
+ folder and deletes it on dispose, so no `[SetUp]`/`[TearDown]` pair and no NUnit1032. Close the
+ repository or appender before the scope ends, or the delete fails on Windows.
- Mark a test `[NonParallelizable]` when it mutates static state (`LogLog.InternalDebugging`, a
static field on a test double, a process-wide native registration).
- Wrap expected internal logging in `LogLog.ExecuteWithoutEmittingInternalMessages(...)` and capture
diff --git a/src/changelog/3.5.0/321-reconfiguration-appender-overlap.xml b/src/changelog/3.5.0/321-reconfiguration-appender-overlap.xml
new file mode 100644
index 00000000..3ba6bd69
--- /dev/null
+++ b/src/changelog/3.5.0/321-reconfiguration-appender-overlap.xml
@@ -0,0 +1,12 @@
+<?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="321" link="https://github.com/apache/logging-log4net/issues/321"/>
+ <issue id="322" link="https://github.com/apache/logging-log4net/pull/322"/>
+ <description format="asciidoc">Stop a reconfiguration from opening a resource the outgoing
+ appender still holds. Since 3.3.1 the new appenders were activated before the old ones were
+ closed, so `ConfigureAndWatch` with a `FileAppender` failed to acquire the lock on its own log
+ file. Activation waits for the swap now (reported by @urs-hart, fixed by @FreeAndNil)</description>
+</entry>
diff --git a/src/log4net.Tests/Config/XmlConfiguratorReconfigurationTest.cs b/src/log4net.Tests/Config/XmlConfiguratorReconfigurationTest.cs
new file mode 100644
index 00000000..b53731c8
--- /dev/null
+++ b/src/log4net.Tests/Config/XmlConfiguratorReconfigurationTest.cs
@@ -0,0 +1,148 @@
+#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.Collections.Generic;
+using System.IO;
+using System.Text;
+
+using log4net.Appender;
+using log4net.Config;
+using log4net.Repository;
+using log4net.Util;
+
+using NUnit.Framework;
+
+using PeanutButter.Utils;
+
+namespace log4net.Tests.Config;
+
+/// <summary>
+/// Reconfiguring must not leave two <see cref="FileAppender"/> instances holding one file.
+/// </summary>
+[TestFixture]
+[NonParallelizable]
+public sealed class XmlConfiguratorReconfigurationTest
+{
+ /// <summary>
+ /// Records every open and close call, so a test can assert their order.
+ /// </summary>
+ /// <remarks>Public because the configurator instantiates it by name.</remarks>
+ public sealed class RecordingLock : FileAppender.LockingModelBase
+ {
+ /// <summary>Open and close calls across all instances, in order.</summary>
+ internal static List<string> Calls { get; } = [];
+
+ private string _tag = "?";
+
+ /// <inheritdoc/>
+ public override void ActivateOptions()
+ { }
+
+ /// <inheritdoc/>
+ public override void OpenFile(string filename, bool append, Encoding encoding)
+ {
+ _tag = CurrentAppender?.Name ?? "?";
+ Calls.Add($"open {_tag}");
+ }
+
+ /// <inheritdoc/>
+ public override void CloseFile() => Calls.Add($"close {_tag}");
+
+ /// <inheritdoc/>
+ public override Stream? AcquireLock() => Stream.Null;
+
+ /// <inheritdoc/>
+ public override void ReleaseLock()
+ { }
+
+ /// <inheritdoc/>
+ public override void OnClose()
+ { }
+ }
+
+ private ILoggerRepository? _repository;
+
+ /// <summary>The call log is static, so it carries over between the tests in this fixture.</summary>
+ [SetUp]
+ public void SetUp() => RecordingLock.Calls.Clear();
+
+ /// <summary>Closes the appenders, in case the test left the repository running.</summary>
+ [TearDown]
+ public void TearDown()
+ {
+ if (_repository is not null)
+ {
+ LogLog.ExecuteWithoutEmittingInternalMessages(_repository.Shutdown);
+ _repository = null;
+ }
+ }
+
+ /// <summary>
+ /// Configuring the live repository again is what the file watcher does on every change. The
+ /// incoming appender used to open the file while the outgoing one still held it.
+ /// </summary>
+ [Test]
+ public void ReconfiguringClosesTheOutgoingAppenderBeforeOpeningTheNewOne()
+ {
+ using AutoTempFolder folder = new();
+ FileInfo configFile = new(Path.Combine(folder.Path, "log.config"));
+ _repository = LogManager.CreateRepository(Guid.NewGuid().ToString());
+
+ LogLog.ExecuteWithoutEmittingInternalMessages(() =>
+ {
+ Write(configFile, folder, "first");
+ XmlConfigurator.Configure(_repository, configFile);
+
+ Write(configFile, folder, "second");
+ XmlConfigurator.Configure(_repository, configFile);
+
+ _repository.Shutdown();
+ _repository = null;
+ });
+
+ Assert.That(RecordingLock.Calls,
+ Is.EqualTo(new[] { "open first", "close first", "open second", "close second" }));
+ }
+
+ /// <summary>Writes a configuration naming its single appender after the pass.</summary>
+ private static void Write(FileInfo configFile, AutoTempFolder folder, string appenderName)
+ {
+ using (StreamWriter writer = configFile.CreateText())
+ {
+ writer.Write($"""
+ <log4net>
+ <appender name="{appenderName}" type="log4net.Appender.FileAppender">
+ <file value="{Path.Combine(folder.Path, "log.log")}" />
+ <lockingModel type="log4net.Tests.Config.XmlConfiguratorReconfigurationTest+RecordingLock, log4net.Tests" />
+ <layout type="log4net.Layout.PatternLayout">
+ <conversionPattern value="%message%newline" />
+ </layout>
+ </appender>
+ <root>
+ <level value="ALL" />
+ <appender-ref ref="{appenderName}" />
+ </root>
+ </log4net>
+ """);
+ }
+
+ configFile.Refresh();
+ }
+}
diff --git a/src/log4net/Repository/Hierarchy/XmlHierarchyConfigurator.cs b/src/log4net/Repository/Hierarchy/XmlHierarchyConfigurator.cs
index 32df0c2d..0d270b4e 100644
--- a/src/log4net/Repository/Hierarchy/XmlHierarchyConfigurator.cs
+++ b/src/log4net/Repository/Hierarchy/XmlHierarchyConfigurator.cs
@@ -149,6 +149,9 @@ public void Configure(XmlElement? element)
// A configuration is about to happen, so we can emit the warning again
hierarchy.EmittedNoAppenderWarning = false;
+ // Activate only after every logger has swapped, so nothing opens what the old appender holds.
+ _deferActivation = true;
+
/* Building Appender objects, placing them in a local namespace
for future reference */
@@ -205,9 +208,24 @@ public void Configure(XmlElement? element)
}
}
+ ActivatePendingAppenders();
+
// Done reading config
}
+ /// <summary>
+ /// Activates the appenders parsed in this pass, in creation order.
+ /// </summary>
+ private void ActivatePendingAppenders()
+ {
+ _deferActivation = false;
+ foreach (IOptionHandler optionHandler in _pendingActivations)
+ {
+ optionHandler.ActivateOptions();
+ }
+ _pendingActivations.Clear();
+ }
+
/// <summary>
/// Parse appenders by IDREF.
/// </summary>
@@ -319,7 +337,14 @@ public void Configure(XmlElement? element)
if (appender is IOptionHandler optionHandler)
{
- optionHandler.ActivateOptions();
+ if (_deferActivation)
+ {
+ _pendingActivations.Add(optionHandler);
+ }
+ else
+ {
+ optionHandler.ActivateOptions();
+ }
}
LogLog.Debug(_declaringType, $"Created Appender [{appenderName}]");
@@ -406,9 +431,8 @@ protected void ParseChildrenOfLoggerElement(XmlElement catElement, Logger log, b
log.EnsureNotNull();
catElement.EnsureNotNull();
- // Phase 1: resolve all new appenders from XML *before* touching the
- // live logger. This avoids the window where the logger has no appenders.
- List<IAppender> newAppenders = new();
+ // Phase 1: resolve from XML before touching the live logger, which keeps its appenders.
+ List<IAppender> newAppenders = [];
foreach (XmlNode currentNode in catElement.ChildNodes)
{
@@ -442,9 +466,7 @@ protected void ParseChildrenOfLoggerElement(XmlElement catElement, Logger log, b
}
}
- // Phase 2: atomic swap — replace all appenders in one writer lock so
- // the logger is never in a zero-appender state for longer than it takes
- // to acquire and release the lock (microseconds, not milliseconds).
+ // Phase 2: swap in one writer lock, closing the outgoing appenders.
log.ReplaceAppenders(newAppenders);
if (log is IOptionHandler optionHandler)
@@ -1052,6 +1074,16 @@ private static Hashtable CreateCaseInsensitiveWrapper(IDictionary dict)
/// </summary>
private readonly Dictionary<string, IAppender> _appenderBag = new(StringComparer.Ordinal);
+ /// <summary>
+ /// Appenders parsed in this pass and not activated yet.
+ /// </summary>
+ private readonly List<IOptionHandler> _pendingActivations = [];
+
+ /// <summary>
+ /// Set by <see cref="Configure"/> alone: defers activation in <see cref="ParseAppender"/>.
+ /// </summary>
+ private bool _deferActivation;
+
/// <summary>
/// The fully qualified type of the XmlHierarchyConfigurator class.
/// </summary>