From 73b9a17e110bcb6a04c3257d68e6aec9a4710165 Mon Sep 17 00:00:00 2001 From: Jan Friedrich Date: Sat, 12 Sep 2026 00:55:18 +0200 Subject: [PATCH 1/3] keep the log when a roll cannot rename it #319 - A failed rename was reported, then the file reopened without appending, which destroyed it. A backup agent holding a read handle is enough. It appends now, and only that rename is retried, once per MaxFileSize of growth, so the backups are never rotated twice and a retry that succeeds keeps the generation it recovers. - The footer, close and open paths released the file lock even when acquiring it had failed. Only what was taken is released now. audit da18b6fd-f036, da18b6fd-f032 --- CLAUDE.md | 12 + .../3.5.0/319-lock-level-underflow.xml | 13 + .../3.5.0/319-rollover-keeps-events.xml | 15 + .../Appender/LockingStreamTest.cs | 143 +++++++ .../RollingFileAppenderRollFailureTest.cs | 349 ++++++++++++++++++ src/log4net/Appender/FileAppender.cs | 86 +++-- src/log4net/Appender/RollingFileAppender.cs | 144 +++++++- 7 files changed, 715 insertions(+), 47 deletions(-) create mode 100644 src/changelog/3.5.0/319-lock-level-underflow.xml create mode 100644 src/changelog/3.5.0/319-rollover-keeps-events.xml create mode 100644 src/log4net.Tests/Appender/LockingStreamTest.cs create mode 100644 src/log4net.Tests/Appender/RollingFileAppenderRollFailureTest.cs diff --git a/CLAUDE.md b/CLAUDE.md index 0e7bcaa2..3c3ecc5e 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -26,6 +26,8 @@ almost always be doing. Omit the type wherever the target is known, including `return new(…);` and `=> new(…);`, where the enclosing member's return type supplies it. It cannot be omitted when the target type is an interface or abstract class, as in `Func f = () => new MailKitSmtpTransport();`. +- `x?.Method() ?? false` rather than `x is not null && x.Method()`, and merge nested guards + into one condition. - Expression-bodied members whenever the body fits on one line, including constructors (`resharper_constructor_or_destructor_body = expression_body`). - Braces on `if`/`else` bodies even for a single statement. @@ -149,6 +151,13 @@ almost always be doing. the assertion is about control characters, use `Contains.Substring(x).Using(StringComparison.Ordinal)`, negated with the `!` operator that `Constraint` defines, or assert the whole value with `Is.EqualTo`, which is ordinal. +- **Order `[TestCase]` attributes shortest to longest by source line**, not by argument length. +- **If no black-box test can reach a defect, extract the sequence into a small private helper + and drive that by reflection.** Do not delete the test and call the defect untestable. The + extraction is usually an improvement anyway: `FileAppender.RunWithBestEffortLock` replaced two + copies of an acquire/release pair, one of which released a lock it had failed to take. +- **A test that passes before the fix is worthless.** Revert the production change and watch + it fail; if it does not, the test is wrong or the defect is not where you think it is. - **Give a `[TestCase]` an explicit `TestName` when an argument holds a control character.** Otherwise the whole fixture can become invisible to `dotnet test --filter`, silently: it is listed by `--list-tests` and runs in a full pass, but every filter reports "No test matches". @@ -206,6 +215,9 @@ Every user-visible change gets an entry in `src/changelog//` `missing attribute: link` otherwise, which is only caught by the Maven site build. - Put anything that has no issue number, such as an external finding identifier, in the description text rather than inventing an `` for it. +- **The description is whitespace-collapsed before the AsciiDoc transform, so block syntax does + not survive.** No bullets, no code blocks: `*` ends up mid-sentence as a literal asterisk. + Write prose. Bullets are fine in commit messages. - Close the description with an attribution in parentheses, crediting both sides: who raised it and who did the work, as in `(reported by @viktorgobbi, fixed by @FreeAndNil)`. `implemented by` reads better than `fixed by` for an `added` or `changed` entry, and once a pull request exists the house diff --git a/src/changelog/3.5.0/319-lock-level-underflow.xml b/src/changelog/3.5.0/319-lock-level-underflow.xml new file mode 100644 index 00000000..82cf7dcd --- /dev/null +++ b/src/changelog/3.5.0/319-lock-level-underflow.xml @@ -0,0 +1,13 @@ + + + + Stop the file lock counter going negative. Writing the footer, + closing the writer and opening the file released the lock even when acquiring it had failed, and a + negative count made every later acquisition fail. The footer and close paths share one helper now, + which releases only what it took; opening keeps its own acquire, because wrapping an unlocked + stream throws. Nothing was lost by this, because the appender reopens the file on the next + event (audit da18b6fd-f032, fixed by @FreeAndNil) + diff --git a/src/changelog/3.5.0/319-rollover-keeps-events.xml b/src/changelog/3.5.0/319-rollover-keeps-events.xml new file mode 100644 index 00000000..9ccb7fdb --- /dev/null +++ b/src/changelog/3.5.0/319-rollover-keeps-events.xml @@ -0,0 +1,15 @@ + + + + Keep the log file when a rollover cannot rename it. The failed rename + was reported and the file then reopened without appending, which destroyed everything it held; a + reader holding the file without `FILE_SHARE_DELETE`, such as a backup or antivirus agent, is enough + to cause it. The file is appended to now. Only the rename that failed is retried, once per + `MaxFileSize` of growth, which is the cadence a working rollover would have had, because a full + retry would shift the numbered backups again and lose the oldest one every time; the file + therefore grows past `MaxFileSize` for as long as the rename keeps failing (audit da18b6fd-f036, + fixed by @FreeAndNil) + diff --git a/src/log4net.Tests/Appender/LockingStreamTest.cs b/src/log4net.Tests/Appender/LockingStreamTest.cs new file mode 100644 index 00000000..abe9d49c --- /dev/null +++ b/src/log4net.Tests/Appender/LockingStreamTest.cs @@ -0,0 +1,143 @@ +#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 System.Reflection; +using System.Text; + +using log4net.Appender; + +using NUnit.Framework; + +namespace log4net.Tests.Appender; + +/// The recursion counter inside the private FileAppender.LockingStream. +[TestFixture] +public sealed class LockingStreamTest +{ + /// Hands out a stream only when told to, so a failed acquisition can be staged. + private sealed class SwitchableLock : FileAppender.LockingModelBase + { + internal bool CanAcquire { get; set; } + + internal int ReleaseCount { get; private set; } + + public override Stream? AcquireLock() => CanAcquire ? Stream.Null : null; + + public override void ReleaseLock() => ReleaseCount++; + + public override void OpenFile(string filename, bool append, Encoding encoding) + { } + + public override void CloseFile() + { } + + public override void ActivateOptions() + { } + + public override void OnClose() + { } + } + + /// + /// An unmatched release drove the counter below zero, after which every later acquisition failed + /// and the model lock was never released. + /// + [Test] + public void AnUnmatchedReleaseDoesNotBreakTheNextAcquisition() + { + SwitchableLock model = new() { CanAcquire = false }; + object stream = NewLockingStream(model); + + // What the footer, close and open paths used to do. + Assert.That(Invoke(stream, "AcquireLock"), Is.False, "the model was set up to refuse"); + Invoke(stream, "ReleaseLock"); + + model.CanAcquire = true; + + Assert.That(Invoke(stream, "AcquireLock"), Is.True, + "the counter went negative, so the stream could never be locked again"); + Invoke(stream, "ReleaseLock"); + Assert.That(model.ReleaseCount, Is.EqualTo(1), "the model lock must be released exactly once"); + } + + /// Nesting still locks and releases the model once. + [Test] + public void NestedAcquisitionsReleaseTheModelOnce() + { + SwitchableLock model = new() { CanAcquire = true }; + object stream = NewLockingStream(model); + + Assert.That(Invoke(stream, "AcquireLock"), Is.True); + Assert.That(Invoke(stream, "AcquireLock"), Is.True); + Invoke(stream, "ReleaseLock"); + Assert.That(model.ReleaseCount, Is.EqualTo(0), "still held by the outer acquisition"); + + Invoke(stream, "ReleaseLock"); + Assert.That(model.ReleaseCount, Is.EqualTo(1)); + } + + /// + /// The footer, close and open paths run through one helper. The work has to happen either way, + /// because closing is what releases the OS handle, but only a lock that was taken may be released. + /// + [Test] + public void RunWithBestEffortLockRunsTheWorkButReleasesOnlyWhatItTook() + { + SwitchableLock model = new() { CanAcquire = false }; + FileAppender appender = new(); + SetStream(appender, NewLockingStream(model)); + + bool ran = false; + RunWithBestEffortLock(appender, () => ran = true); + Assert.That(ran, Is.True, "the work must run even without the lock, or the file is never closed"); + Assert.That(model.ReleaseCount, Is.EqualTo(0), "released a lock it never took"); + + model.CanAcquire = true; + ran = false; + + RunWithBestEffortLock(appender, () => ran = true); + Assert.That(ran, Is.True); + Assert.That(model.ReleaseCount, Is.EqualTo(1), "the counter went negative, so nothing locked again"); + } + + + private static void SetStream(FileAppender appender, object stream) + => typeof(FileAppender).GetField("_stream", BindingFlags.Instance | BindingFlags.NonPublic)! + .SetValue(appender, stream); + + private static void RunWithBestEffortLock(FileAppender appender, Action action) + => typeof(FileAppender).GetMethod("RunWithBestEffortLock", BindingFlags.Instance | BindingFlags.NonPublic)! + .Invoke(appender, [action]); + + private static object NewLockingStream(FileAppender.LockingModelBase model) + { + Type type = typeof(FileAppender).GetNestedType("LockingStream", BindingFlags.NonPublic) + ?? throw new InvalidOperationException("FileAppender.LockingStream is gone"); + return Activator.CreateInstance(type, BindingFlags.Instance | BindingFlags.NonPublic | BindingFlags.Public, + null, [model], null) + ?? throw new InvalidOperationException("could not construct a LockingStream"); + } + + private static void Invoke(object target, string method) => Invoke(target, method); + + private static T Invoke(object target, string method) + => (T)target.GetType().GetMethod(method)!.Invoke(target, null)!; +} diff --git a/src/log4net.Tests/Appender/RollingFileAppenderRollFailureTest.cs b/src/log4net.Tests/Appender/RollingFileAppenderRollFailureTest.cs new file mode 100644 index 00000000..13d92610 --- /dev/null +++ b/src/log4net.Tests/Appender/RollingFileAppenderRollFailureTest.cs @@ -0,0 +1,349 @@ +#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 log4net.Tests.Integration; +using log4net.Util; + +using NUnit.Framework; + +namespace log4net.Tests.Appender; + +/// +/// What does when a roll cannot complete. Every test here blocks +/// the base rename with , which leaves the archive shift working, so the +/// state under test is the reported one: a reader holding the log file and nothing else. +/// +[TestFixture] +public sealed class RollingFileAppenderRollFailureTest +{ + private const string Marker = "must survive the failed roll"; + + private string _directory = string.Empty; + private readonly Internal.RecordingErrorHandler _errors = new(); + + [SetUp] + public void SetUp() + { + _directory = Path.Combine(Path.GetTempPath(), Guid.NewGuid().ToString("N")); + Directory.CreateDirectory(_directory); + _errors.Messages.Clear(); + } + + [TearDown] + public void TearDown() + { + if (Directory.Exists(_directory)) + { + Directory.Delete(_directory, true); + } + } + + /// + /// A failed rename leaves the file in place, and reopening it without appending destroyed it. + /// The archive it shifted on the way must not be shifted a second time. + /// + [Test] + [NonParallelizable] + public void AFailedRollKeepsTheEventsItCouldNotMove() + { + string file = Path.Combine(_directory, "roll-failure.log"); + RollingFileAppender appender = new() + { + File = file, + Layout = new PatternLayout("%message%newline"), + RollingStyle = RollingFileAppender.RollingMode.Size, + MaxSizeRollBackups = 3, + MaximumFileSize = "200", + AppendToFile = true, + LockingModel = new FileAppender.MinimalLock(), + ErrorHandler = _errors + }; + appender.ActivateOptions(); + + try + { + // Two ordinary rolls, so there is an archive to rotate. + appender.DoAppend(CreateEvent(new string('a', 200))); + appender.DoAppend(CreateEvent(new string('a', 200))); + appender.DoAppend(CreateEvent(new string('a', 200))); + + BlockRename(file + ".1"); + + // The file is already over the limit, so this event rolls first and the roll is the one that + // fails. What it writes afterwards is the content the failed roll used to destroy. + LogLog.ExecuteWithoutEmittingInternalMessages(() => appender.DoAppend(CreateEvent(Marker))); + Assert.That(_errors.Messages, Is.Not.Empty, "the roll never failed, so nothing was exercised"); + + // That first attempt shifts the archive before failing on the base file, which is + // unavoidable. What must not happen is a second shift. + string[] afterFirstFailure = Backups(file); + Assert.That(afterFirstFailure, Is.Not.Empty, "the fixture needs an archive for the roll to shift"); + string[] contentAfterFirstFailure = Array.ConvertAll(afterFirstFailure, File.ReadAllText); + + // Events well under MaxFileSize, so a retry per MaxFileSize of growth is measurably rarer + // than a retry per event. At 200 bytes each the two cadences would be the same thing. + LogLog.ExecuteWithoutEmittingInternalMessages(() => + { + for (int i = 0; i < 20; i++) + { + appender.DoAppend(CreateEvent(new string('b', 50))); + } + }); + + Assert.That(Backups(file), Is.EqualTo(afterFirstFailure), + "the archive was rotated again while the rename kept failing"); + Assert.That(Array.ConvertAll(afterFirstFailure, File.ReadAllText), Is.EqualTo(contentAfterFirstFailure), + "the backup contents were rewritten while the rename kept failing"); + // Only the base rename is retried, and only once the file has grown another MaxFileSize, + // so the attempts are far fewer than the 20 events above. + Assert.That(BaseRenameAttempts(file), Is.LessThan(20), + "the rename was retried per event instead of per MaxFileSize of growth"); + } + finally + { + LogLog.ExecuteWithoutEmittingInternalMessages(appender.Close); + } + + Assert.That(File.ReadAllText(file), Does.Contain(Marker), + "the roll could not rename the file, so reopening it must not have truncated it"); + } + + /// + /// The same failure with a dated name, where the file being rolled is not the configured one. + /// Testing the base file's existence instead of the one the rename could not move passes here + /// and truncates anyway. + /// + [Test] + [NonParallelizable] + public void AFailedRollKeepsTheEventsWhenTheFileNameIsDated() + { + string file = Path.Combine(_directory, "roll-failure.log"); + RollingFileAppender appender = new() + { + File = file, + Layout = new PatternLayout("%message%newline"), + RollingStyle = RollingFileAppender.RollingMode.Composite, + DatePattern = "'.'yyyy-MM-dd", + StaticLogFileName = false, + MaxSizeRollBackups = 3, + MaximumFileSize = "200", + AppendToFile = true, + LockingModel = new FileAppender.MinimalLock(), + ErrorHandler = _errors + }; + appender.ActivateOptions(); + + // The file that is written and rolled, which is not the configured name. + string dated = appender.File!; + Assert.That(dated, Is.Not.EqualTo(file), "the fixture needs a name the configured one does not match"); + + try + { + appender.DoAppend(CreateEvent(new string('a', 200))); + + BlockRename(dated + ".1"); + + // Rolls first, fails on the dated name, and keeps what the rename could not move. + LogLog.ExecuteWithoutEmittingInternalMessages( + () => appender.DoAppend(CreateEvent(new string('b', 200)))); + Assert.That(_errors.Messages, Is.Not.Empty, "the roll never failed, so nothing was exercised"); + + // Written into the file the failed rename left behind, so a truncating reopen destroys it. + appender.DoAppend(CreateEvent(Marker)); + + // Grow past the retry threshold, so the base rename is attempted and fails again. + LogLog.ExecuteWithoutEmittingInternalMessages(() => + { + for (int i = 0; i < 20; i++) + { + appender.DoAppend(CreateEvent(new string('b', 200))); + } + }); + } + finally + { + LogLog.ExecuteWithoutEmittingInternalMessages(appender.Close); + } + + Assert.That(File.ReadAllText(dated), Does.Contain(Marker), + "the roll could not rename the dated file, so reopening it must not have truncated it"); + } + + /// + /// A retry that succeeds moves the kept file into the archive, and the next roll has to shift + /// that generation rather than overwrite it. + /// + [Test] + [NonParallelizable] + public void ASuccessfulRetryKeepsTheBackupItRecovered() + { + string file = Path.Combine(_directory, "roll-failure.log"); + RollingFileAppender appender = new() + { + File = file, + Layout = new PatternLayout("%message%newline"), + RollingStyle = RollingFileAppender.RollingMode.Size, + // Far more than the run needs, so nothing may be discarded as too old. + MaxSizeRollBackups = 10, + MaximumFileSize = "200", + AppendToFile = true, + LockingModel = new FileAppender.MinimalLock(), + ErrorHandler = _errors + }; + appender.ActivateOptions(); + + try + { + appender.DoAppend(CreateEvent(new string('a', 200))); + + BlockRename(file + ".1"); + + // Rolls first, fails, and is then written into the file the rename could not move. + LogLog.ExecuteWithoutEmittingInternalMessages(() => appender.DoAppend(CreateEvent(Marker))); + Assert.That(_errors.Messages, Is.Not.Empty, "the roll never failed, so nothing was exercised"); + + // The obstruction is gone, so the next retry succeeds. + UnblockRename(file + ".1"); + + LogLog.ExecuteWithoutEmittingInternalMessages(() => + { + for (int i = 0; i < 20 && !ArchiveHolds(file, Marker); i++) + { + appender.DoAppend(CreateEvent(new string('b', 200))); + } + }); + Assert.That(ArchiveHolds(file, Marker), Is.True, + "the retry never moved the kept file into the archive, so nothing was recovered"); + + // One ordinary roll on top of the recovered generation. + LogLog.ExecuteWithoutEmittingInternalMessages(() => + { + for (int i = 0; i < 2; i++) + { + appender.DoAppend(CreateEvent(new string('c', 200))); + } + }); + } + finally + { + LogLog.ExecuteWithoutEmittingInternalMessages(appender.Close); + } + + Assert.That(ArchiveHolds(file, Marker), Is.True, + "the roll after the retry overwrote the backup the retry had just recovered"); + } + + /// + /// A failed base rename leaves the numbered files one slot higher than the backup count says, + /// and the time roll has to take that top one with it. + /// + [Test] + [NonParallelizable] + public void ATimeRollAfterAFailedRenameTakesEveryBackupWithIt() + { + string file = Path.Combine(_directory, "roll-failure.log"); + MockDateTime clock = new(new DateTime(2026, 1, 1, 12, 0, 0, DateTimeKind.Local)); + RollingFileAppender appender = new() + { + File = file, + Layout = new PatternLayout("%message%newline"), + RollingStyle = RollingFileAppender.RollingMode.Composite, + DatePattern = "'.'yyyy-MM-dd", + StaticLogFileName = true, + MaxSizeRollBackups = 5, + MaximumFileSize = "200", + AppendToFile = true, + LockingModel = new FileAppender.MinimalLock(), + DateTimeStrategy = clock, + ErrorHandler = _errors + }; + appender.ActivateOptions(); + + try + { + // Two ordinary rolls, so the marker ends up in the second backup. + appender.DoAppend(CreateEvent(Marker + new string('a', 200))); + appender.DoAppend(CreateEvent(new string('a', 200))); + appender.DoAppend(CreateEvent(new string('a', 200))); + + BlockRename(file + ".1"); + + LogLog.ExecuteWithoutEmittingInternalMessages( + () => appender.DoAppend(CreateEvent(new string('b', 200)))); + Assert.That(_errors.Messages, Is.Not.Empty, "the base rename never failed, so nothing was exercised"); + Assert.That(File.ReadAllText(file + ".3"), Does.Contain(Marker), + "the fixture needs the archive shifted a slot beyond the backup count"); + + // A day later, so the time roll moves the whole group under the dated name. + clock.Now = clock.Now.AddDays(1); + LogLog.ExecuteWithoutEmittingInternalMessages(() => appender.DoAppend(CreateEvent("after midnight"))); + } + finally + { + LogLog.ExecuteWithoutEmittingInternalMessages(appender.Close); + } + + Assert.That(File.Exists(file + ".3"), Is.False, + "the backup stayed under the old base name instead of moving with the group"); + } + + /// + /// Blocks one rename by occupying its target with a directory. + /// throws when the destination exists, and the appender's own delete of the target skips it, + /// because is false for a directory. Only that rename fails, so the + /// archive shift still goes through, which is the reported shape: a reader holding the log file + /// without FILE_SHARE_DELETE. + /// + private static void BlockRename(string target) + { + if (File.Exists(target)) + { + File.Delete(target); + } + + Directory.CreateDirectory(target); + } + + private static void UnblockRename(string target) => Directory.Delete(target, true); + + /// The numbered backups, excluding the log file itself: a `.*` pattern matches it too. + private string[] Backups(string file) + => Array.FindAll(Directory.GetFiles(_directory, "roll-failure.log.*"), + f => !string.Equals(f, file, StringComparison.Ordinal)); + + /// + /// How often the base rename itself was attempted. A failed attempt can report twice, once for + /// the delete of the target and once for the move, so counting messages counts the wrong thing. + /// + private int BaseRenameAttempts(string file) + => _errors.Messages.FindAll(m => m.IndexOf($"[{file}] ->", StringComparison.Ordinal) >= 0).Count; + + /// Whether any numbered backup holds . + private bool ArchiveHolds(string file, string content) + => Array.Exists(Backups(file), + f => File.ReadAllText(f).IndexOf(content, StringComparison.Ordinal) >= 0); + + private static LoggingEvent CreateEvent(string message) + => new(new LoggingEventData { Level = Level.Info, Message = message, LoggerName = "RollFailure" }); +} diff --git a/src/log4net/Appender/FileAppender.cs b/src/log4net/Appender/FileAppender.cs index 5887fbfe..28f74a17 100644 --- a/src/log4net/Appender/FileAppender.cs +++ b/src/log4net/Appender/FileAppender.cs @@ -194,6 +194,12 @@ public void ReleaseLock() { lock (_syncRoot) { + if (_lockLevel == 0) + { + // Unmatched release: going negative would strand the model lock. + return; + } + _lockLevel--; if (_lockLevel == 0) { @@ -1094,7 +1100,7 @@ protected override void PrepareWriter() /// protected override void Append(LoggingEvent loggingEvent) { - if (_stream is not null && _stream.AcquireLock()) + if (_stream?.AcquireLock() ?? false) { try { @@ -1120,7 +1126,7 @@ protected override void Append(LoggingEvent loggingEvent) /// protected override void Append(LoggingEvent[] loggingEvents) { - if (_stream is not null && _stream.AcquireLock()) + if (_stream?.AcquireLock() ?? false) { try { @@ -1143,19 +1149,8 @@ protected override void Append(LoggingEvent[] loggingEvents) /// protected override void WriteFooter() { - if (_stream is not null) - { - //WriteFooter can be called even before a file is opened - _stream.AcquireLock(); - try - { - base.WriteFooter(); - } - finally - { - _stream.ReleaseLock(); - } - } + //WriteFooter can be called even before a file is opened + RunWithBestEffortLock(base.WriteFooter); } /// @@ -1168,18 +1163,15 @@ protected override void WriteFooter() /// protected override void WriteHeader() { - if (_stream is not null) + if (_stream?.AcquireLock() ?? false) { - if (_stream.AcquireLock()) + try { - try - { - base.WriteHeader(); - } - finally - { - _stream.ReleaseLock(); - } + base.WriteHeader(); + } + finally + { + _stream.ReleaseLock(); } } } @@ -1194,18 +1186,8 @@ protected override void WriteHeader() /// protected override void CloseWriter() { - if (_stream is not null) - { - _stream.AcquireLock(); - try - { - base.CloseWriter(); - } - finally - { - _stream.ReleaseLock(); - } - } + // An already closed writer cannot take the lock. + RunWithBestEffortLock(base.CloseWriter); } /// @@ -1242,6 +1224,28 @@ protected virtual void SafeOpenFile(string fileName, bool append) } } + /// + /// Runs under the file lock if it can be taken, releasing only what it + /// took. It runs unlocked too, because closing has to happen: that is what frees the handle. + /// and deliberately skip their work + /// instead when the lock is refused, so they keep their own acquire. + /// + private void RunWithBestEffortLock(Action action) + { + bool locked = _stream?.AcquireLock() ?? false; + try + { + action(); + } + finally + { + if (locked) + { + _stream!.ReleaseLock(); + } + } + } + /// /// Sets and opens the file where the log output will go. The specified file must be writable. /// @@ -1289,9 +1293,9 @@ protected virtual void OpenFile(string fileName, bool append) LockingModel.OpenFile(fileName, append, Encoding); _stream = new LockingStream(LockingModel); - if (_stream is not null) + // Wrapping an unlocked stream throws, so say why instead of trying. + if (_stream.AcquireLock()) { - _stream.AcquireLock(); try { SetQWForFiles(_stream); @@ -1301,6 +1305,10 @@ protected virtual void OpenFile(string fileName, bool append) _stream.ReleaseLock(); } } + else + { + ErrorHandler.Error($"Could not acquire the lock on {fileName} to open it."); + } WriteHeader(); } diff --git a/src/log4net/Appender/RollingFileAppender.cs b/src/log4net/Appender/RollingFileAppender.cs index a15e8f97..1339bb61 100644 --- a/src/log4net/Appender/RollingFileAppender.cs +++ b/src/log4net/Appender/RollingFileAppender.cs @@ -128,6 +128,16 @@ namespace log4net.Appender; // ReSharper disable GrammarMistakeInComment public partial class RollingFileAppender : FileAppender { + /// A base rename that failed, kept whole so its parts cannot drift apart. + /// The file that could not be moved. + /// Where it was heading. + /// + /// Whether the caller undid a increment, which a successful + /// retry has to put back. The time roll does not touch the counter, the size roll does. + /// + /// The size the file must reach before the rename is attempted again. + private sealed record PendingRename(string From, string To, bool WasBackupCountReverted, long RetryAtCount = 0); + /// /// Style of rolling to use /// @@ -556,9 +566,17 @@ protected virtual void AdjustFileBeforeAppend() } } - if (_rollSize && (File is not null) && ((CountingQuietTextWriter)QuietWriter!).Count >= MaxFileSize) + if (_rollSize && (File is not null) + && ((CountingQuietTextWriter)QuietWriter!).Count >= MaxFileSize) { - RollOverSize(); + if (_pendingRename is null) + { + RollOverSize(); + } + else if (((CountingQuietTextWriter)QuietWriter).Count >= _pendingRename.RetryAtCount) + { + RetryFailedRoll(); + } } } finally @@ -623,7 +641,10 @@ protected override void OpenFile(string fileName, bool append) base.OpenFile(fileName, append); // Set the file size onto the counting writer - ((CountingQuietTextWriter)QuietWriter!).Count = currentCount; + if (QuietWriter is CountingQuietTextWriter countingWriter) + { + countingWriter.Count = currentCount; + } } } @@ -1001,6 +1022,8 @@ public static RollPoint ComputeCheckPeriod(string datePattern) /// public override void ActivateOptions() { + _pendingRename = null; + if (_rollDate && DatePattern is not null) { _now = DateTimeStrategy.Now; @@ -1081,6 +1104,15 @@ private string CombinePath(string path1, string path2) /// protected void RollOverTime(bool fileIsOpen) { + if (_pendingRename is { WasBackupCountReverted: true }) + { + // The failed size rename left the numbered files a slot higher than the count says, and the + // group move below walks the count. Without this the top backup stays behind. + CurrentSizeRollBackups++; + } + + // A time roll that renames successfully proves the obstruction is gone. + _pendingRename = null; if (StaticLogFileName) { // Compute filename, but only if datePattern is specified @@ -1114,7 +1146,10 @@ protected void RollOverTime(bool fileIsOpen) RollFile(from, to); } - RollFile(File!, _scheduledFilename!); + if (!TryRollFile(File!, _scheduledFilename!)) + { + RecordFailedBaseRename(File!, _scheduledFilename!, wasBackupCountReverted: false); + } } //We've cleared out the old date and are ready for the new @@ -1126,7 +1161,15 @@ protected void RollOverTime(bool fileIsOpen) if (fileIsOpen) { // This will also close the file. This is OK since multiple close operations are safe. - SafeOpenFile(_baseFileName!, false); + // A failed rename leaves the file in place; appending keeps what it holds. + SafeOpenFile(_baseFileName!, ShouldAppendAfterFailedRoll()); + // Its own threshold, or the one from a size failure would fire a retry immediately. + ScheduleRollRetry(); + } + else + { + // The startup roll, with no file open to grow, so nothing can trigger a retry. As before. + _pendingRename = null; } } @@ -1159,6 +1202,7 @@ protected void RollFile(string fromFile, string toFile) } catch (Exception e) when (!e.IsFatal()) { + _rollFailures++; ErrorHandler.Error($"Exception while rolling file [{fromFile}] -> [{toFile}]", e, ErrorCode.GenericFailure); } } @@ -1287,6 +1331,7 @@ protected void RollOverSize() LogLog.Debug(_declaringType, $"curSizeRollBackups [{CurrentSizeRollBackups}]"); LogLog.Debug(_declaringType, $"countDirection [{CountDirection}]"); + _pendingRename = null; if (File is not null) { RollOverRenameFiles(File); @@ -1298,7 +1343,72 @@ protected void RollOverSize() } // This will also close the file. This is OK since multiple close operations are safe. - SafeOpenFile(_baseFileName!, false); + // A failed rename leaves the file in place; appending keeps what it holds. + SafeOpenFile(_baseFileName!, ShouldAppendAfterFailedRoll()); + + if (_pendingRename is not null) + { + ScheduleRollRetry(); + // The failing rename already reported, and OnlyOnceErrorHandler silences the handler after + // the first report, so this one goes through LogLog to survive. + LogLog.Error(_declaringType, + $"Rolling {_pendingRename.From} failed, so it is kept and appended to. Only that rename is " + + "retried, once per MaxFileSize of growth, so the backups are left alone."); + } + } + + /// Remembers the base rename to retry, without touching the archive again. + private void RecordFailedBaseRename(string fromFile, string toFile, bool wasBackupCountReverted) + => _pendingRename = new(fromFile, toFile, wasBackupCountReverted); + + /// + /// Schedules the next attempt at the failed base rename, one of growth + /// away: the cadence a working roll would have had. + /// + private void ScheduleRollRetry() + { + // A refused lock leaves no writer, and then the threshold simply stays where it was. + if (_pendingRename is not null && QuietWriter is CountingQuietTextWriter countingWriter) + { + _pendingRename = _pendingRename with { RetryAtCount = countingWriter.Count + MaxFileSize }; + } + } + + /// + /// Retries only the base rename, never the archive shift, so the backups are not rotated twice. + /// When the shift succeeded the target slot is still free. When it failed too, the target may be + /// occupied and deletes it, which is what that call has always done. + /// + private void RetryFailedRoll() + { + CloseFile(); + PendingRename pending = _pendingRename!; + if (TryRollFile(pending.From, pending.To)) + { + if (pending.WasBackupCountReverted) + { + // The slot the failed rename left empty is filled now, so the backup it gave up is real + // again. Without this the next roll shifts nothing and overwrites what was just recovered. + CurrentSizeRollBackups++; + } + + _pendingRename = null; + } + + SafeOpenFile(_baseFileName!, ShouldAppendAfterFailedRoll()); + ScheduleRollRetry(); + } + + /// Whether a rename failed and left the file, so it must be appended to. + private bool ShouldAppendAfterFailedRoll() + => _pendingRename is not null && FileExists(_pendingRename.From); + + /// Renames as does, reporting whether it worked. + private bool TryRollFile(string fromFile, string toFile) + { + int failuresBefore = _rollFailures; + RollFile(fromFile, toFile); + return _rollFailures == failuresBefore; } /// @@ -1353,7 +1463,11 @@ protected virtual void RollOverRenameFiles(string baseFileName) CurrentSizeRollBackups++; // Rename fileName to fileName.1 - RollFile(baseFileName, CombinePath(baseFileName, ".1")); + if (!TryRollFile(baseFileName, CombinePath(baseFileName, ".1"))) + { + CurrentSizeRollBackups--; + RecordFailedBaseRename(baseFileName, CombinePath(baseFileName, ".1"), wasBackupCountReverted: true); + } } else { @@ -1402,7 +1516,12 @@ protected virtual void RollOverRenameFiles(string baseFileName) if (StaticLogFileName) { CurrentSizeRollBackups++; - RollFile(baseFileName, CombinePath(baseFileName, "." + CurrentSizeRollBackups)); + if (!TryRollFile(baseFileName, CombinePath(baseFileName, "." + CurrentSizeRollBackups))) + { + CurrentSizeRollBackups--; + RecordFailedBaseRename(baseFileName, CombinePath(baseFileName, "." + (CurrentSizeRollBackups + 1)), + wasBackupCountReverted: true); + } } } } @@ -1526,6 +1645,15 @@ protected static DateTime NextCheckDate(DateTime currentDateTime, RollPoint roll /// private bool _rollDate = true; + /// + /// The base rename waiting to be retried, or null when none is. A + /// override that renames itself bypasses it. + /// + private PendingRename? _pendingRename; + + /// How many renames have failed, so one call can be told apart. + private int _rollFailures; + /// /// Cache flag set if we are rolling by size. /// From 18bc141dc498d3e33bb620db012c9e250fec1866 Mon Sep 17 00:00:00 2001 From: Jan Friedrich Date: Mon, 14 Sep 2026 22:10:32 +0200 Subject: [PATCH 2/3] name the file lock mutex after the resolved path #319 - InterProcessLock named its mutex before the path was resolved, so a relative and an absolute spelling of one file took two mutexes and excluded nothing. - A name over 255 characters throws on Unix, out of ActivateOptions, so a deep log path took the appender down. Those are hashed now. Windows has no limit, measured, so its names are left alone and keep excluding older versions. - Both mutexes take their name from one helper, which carries why there is no ACL, no Global\ prefix and no user component. audit da18b6fd-f031, da18b6fd-f010 --- src/changelog/3.5.0/319-mutex-name-length.xml | 14 ++ .../3.5.0/319-mutex-resolved-path.xml | 15 ++ .../Appender/FileAppenderMutexNameTest.cs | 222 ++++++++++++++++++ src/log4net/Appender/FileAppender.cs | 54 ++++- src/log4net/Appender/RollingFileAppender.cs | 6 +- src/log4net/Util/SystemInfo.cs | 6 + 6 files changed, 303 insertions(+), 14 deletions(-) create mode 100644 src/changelog/3.5.0/319-mutex-name-length.xml create mode 100644 src/changelog/3.5.0/319-mutex-resolved-path.xml create mode 100644 src/log4net.Tests/Appender/FileAppenderMutexNameTest.cs diff --git a/src/changelog/3.5.0/319-mutex-name-length.xml b/src/changelog/3.5.0/319-mutex-name-length.xml new file mode 100644 index 00000000..c9ac89d8 --- /dev/null +++ b/src/changelog/3.5.0/319-mutex-name-length.xml @@ -0,0 +1,14 @@ + + + + Keep logging to a deep path on Unix. Both the rolling lock and the + inter-process file lock name their mutex after the log file, and Unix rejects a name longer than + 255 characters, throwing out of `ActivateOptions` and taking the appender with it before anything + was written. Such a name is replaced by a hash of the path now. Windows enforces no + length limit at all, and names are left alone there, so the only ones that change are the ones + that used to throw and exclusion against an older version is nowhere affected (audit + da18b6fd-f010, da18b6fd-f031, fixed by @FreeAndNil) + diff --git a/src/changelog/3.5.0/319-mutex-resolved-path.xml b/src/changelog/3.5.0/319-mutex-resolved-path.xml new file mode 100644 index 00000000..a4d6d87d --- /dev/null +++ b/src/changelog/3.5.0/319-mutex-resolved-path.xml @@ -0,0 +1,15 @@ + + + + Let two processes that spell the log path differently share one + inter-process file lock. `InterProcessLock` named its mutex after the configured path before that + path was resolved, so a relative and an absolute spelling of one file took two different mutexes + and excluded nothing. The name comes from the resolved path now. That resolves a relative path and + nothing else: symbolic links, hard links, 8.3 short names, letter case and UNC versus mapped-drive + spellings still produce different names. The name is also unprefixed, which on Windows makes it + per-session, so a service and an interactive process have never coordinated through it (audit + da18b6fd-f031, fixed by @FreeAndNil) + diff --git a/src/log4net.Tests/Appender/FileAppenderMutexNameTest.cs b/src/log4net.Tests/Appender/FileAppenderMutexNameTest.cs new file mode 100644 index 00000000..6eb3baa0 --- /dev/null +++ b/src/log4net.Tests/Appender/FileAppenderMutexNameTest.cs @@ -0,0 +1,222 @@ +#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 System.Reflection; +using System.Text; +using System.Threading; + +using log4net.Appender; +using log4net.Core; +using log4net.Layout; +using log4net.Util; + +using NUnit.Framework; + +namespace log4net.Tests.Appender; + +/// The mutex name the file lock and the rolling lock derive from the log file path. +[TestFixture] +public sealed class FileAppenderMutexNameTest +{ + /// Records what the appender had resolved by the time the locking model was activated. + private sealed class RecordingLock : FileAppender.LockingModelBase + { + internal string? FileAtActivation { get; private set; } + + public override void ActivateOptions() => FileAtActivation = CurrentAppender?.File; + + public override Stream? AcquireLock() => Stream.Null; + + public override void ReleaseLock() + { } + + public override void OpenFile(string filename, bool append, Encoding encoding) + { } + + public override void CloseFile() + { } + + public override void OnClose() + { } + } + + private string _directory = string.Empty; + + [SetUp] + public void SetUp() + { + _directory = Path.Combine(Path.GetTempPath(), Guid.NewGuid().ToString("N")); + Directory.CreateDirectory(_directory); + } + + [TearDown] + public void TearDown() + { + if (Directory.Exists(_directory)) + { + Directory.Delete(_directory, true); + } + } + + /// + /// The model was activated before the path was resolved, so a relative and an absolute spelling + /// of one file never shared a mutex. + /// + [Test] + [NonParallelizable] + public void TheLockingModelIsActivatedAfterThePathIsResolved() + { + RecordingLock model = new(); + FileAppender appender = new() + { + File = "mutex-name-test.log", + Layout = new PatternLayout("%message%newline"), + LockingModel = model, + ErrorHandler = new Internal.RecordingErrorHandler() + }; + + try + { + LogLog.ExecuteWithoutEmittingInternalMessages(appender.ActivateOptions); + + Assert.That(model.FileAtActivation, Is.Not.Null, "the locking model was never activated"); + Assert.That(Path.IsPathRooted(model.FileAtActivation!), Is.True, + "the locking model named its mutex after an unresolved path"); + Assert.That(model.FileAtActivation, Does.EndWith("mutex-name-test.log")); + } + finally + { + LogLog.ExecuteWithoutEmittingInternalMessages(appender.Close); + string written = appender.File!; + if (File.Exists(written)) + { + File.Delete(written); + } + } + } + + /// A name past the Unix limit took the appender down before anything was logged. + [Test] + [NonParallelizable] + public void ADeepPathStillActivates() + { + // Over the 255 character mutex name limit once "_rolling" is added, under the 260 Windows + // still enforces on net462. + string leaf = new('d', 250 - _directory.Length - "roll.log".Length - 2); + string directory = Path.Combine(_directory, leaf); + Directory.CreateDirectory(directory); + string file = Path.Combine(directory, "roll.log"); + Assert.That(file, Has.Length.EqualTo(250), "the fixture must exceed the mutex name limit"); + + RollingFileAppender appender = new() + { + File = file, + Layout = new PatternLayout("%message%newline"), + RollingStyle = RollingFileAppender.RollingMode.Size, + MaximumFileSize = "10KB", + LockingModel = new FileAppender.MinimalLock(), + ErrorHandler = new Internal.RecordingErrorHandler() + }; + + try + { + appender.ActivateOptions(); + appender.DoAppend(new LoggingEvent(new LoggingEventData + { + Level = Level.Info, + Message = "deep", + LoggerName = "MutexName" + })); + } + finally + { + LogLog.ExecuteWithoutEmittingInternalMessages(appender.Close); + } + + Assert.That(File.ReadAllText(file), Does.Contain("deep")); + } + + /// A name that fits is left alone, so no existing deployment's mutex changes. + [Test] + public void AShortPathKeepsTheNameEarlierVersionsComputed() + => Assert.That(MutexNameForPath("/var/log/app.log", "_rolling"), Is.EqualTo("_var_log_app.log_rolling")); + + /// Under a limit, a long name is hashed below it and stays distinct. + [Test] + public void ALongPathIsHashedWhereThePlatformHasALimit() + { + string deep = "/" + new string('d', 4000) + "/app.log"; + string name = MutexNameForPath(deep, "_rolling", 255); + + Assert.That(name, Has.Length.LessThanOrEqualTo(255)); + Assert.That(name, Does.EndWith("_rolling")); + Assert.That(MutexNameForPath(deep + "x", "_rolling", 255), Is.Not.EqualTo(name), + "two different paths collapsed onto one mutex"); + + // The defect itself: this threw before the cap existed. + using Mutex mutex = new(false, name); + Assert.That(mutex.WaitOne(0), Is.True); + mutex.ReleaseMutex(); + } + + /// With no limit, which is Windows, the name is left as earlier versions computed it. + [Test] + public void ALongPathIsLeftAloneWhereThePlatformHasNoLimit() + { + string deep = "/" + new string('d', 4000) + "/app.log"; + + Assert.That(MutexNameForPath(deep, "_rolling", null), + Is.EqualTo("_" + new string('d', 4000) + "_app.log_rolling")); + } + + /// + /// Which limit the platform gets, expected from this fixture's own check rather than the one + /// under test. On Windows nothing else would notice a wrong gate. + /// + [Test] + public void ThePlatformDecidesWhetherALongNameIsHashed() + { + string deep = "/" + new string('d', 4000) + "/app.log"; + string name = MutexNameForPath(deep, "_rolling"); + + if (Environment.OSVersion.Platform is PlatformID.Unix or PlatformID.MacOSX) + { + Assert.That(name, Has.Length.LessThanOrEqualTo(255), "Unix rejects a longer name"); + } + else + { + Assert.That(name, Has.Length.EqualTo(deep.Length + "_rolling".Length), + "Windows has no limit, so the name must be left as earlier versions computed it"); + } + } + + private static string MutexNameForPath(string path, string suffix) + => (string)typeof(FileAppender) + .GetMethod("MutexNameForPath", BindingFlags.NonPublic | BindingFlags.Static, + null, [typeof(string), typeof(string)], null)! + .Invoke(null, [path, suffix])!; + + private static string MutexNameForPath(string path, string suffix, int? maxLength) + => (string)typeof(FileAppender) + .GetMethod("MutexNameForPath", BindingFlags.NonPublic | BindingFlags.Static, + null, [typeof(string), typeof(string), typeof(int?)], null)! + .Invoke(null, [path, suffix, maxLength])!; +} diff --git a/src/log4net/Appender/FileAppender.cs b/src/log4net/Appender/FileAppender.cs index 28f74a17..70228545 100644 --- a/src/log4net/Appender/FileAppender.cs +++ b/src/log4net/Appender/FileAppender.cs @@ -22,6 +22,7 @@ using System.Diagnostics.CodeAnalysis; using System.IO; using System.Runtime.Serialization; +using System.Security.Cryptography; using System.Text; using System.Threading; using log4net.Util; @@ -759,12 +760,9 @@ public override void ActivateOptions() { if (CurrentAppender.File is not null) { - string mutexFriendlyFilename = CurrentAppender.File - .Replace("\\", "_") - .Replace(":", "_") - .Replace("/", "_"); - - _mutex = new Mutex(false, mutexFriendlyFilename); + // No ACL, Global\ prefix or user name here: without a shared ACL a global mutex + // throws for whichever process starts second, and a user name splits one session. + _mutex = new Mutex(false, MutexNameForPath(CurrentAppender.File, string.Empty)); } else { @@ -1025,16 +1023,20 @@ public override void ActivateOptions() SecurityContext ??= SecurityContextProvider.DefaultProvider.CreateSecurityContext(this); - LockingModel.CurrentAppender = this; - LockingModel.ActivateOptions(); - if (_fileName is not null) { using (SecurityContext.Impersonate(this)) { + // Before the locking model activates, which names its mutex after this path. _fileName = ConvertToFullPath(_fileName.Trim()); } + } + + LockingModel.CurrentAppender = this; + LockingModel.ActivateOptions(); + if (_fileName is not null) + { SafeOpenFile(_fileName, AppendToFile); } else @@ -1366,6 +1368,40 @@ protected virtual void SetQWForFiles(TextWriter writer) /// protected static string ConvertToFullPath(string path) => SystemInfo.ConvertToFullPath(path); + /// + /// Names the mutex that serialises between processes, with + /// telling one mutex over the same file from another. + /// + /// + /// The flattened path, as earlier versions computed it. Only a name the platform rejects is + /// hashed: Unix stops at , Windows has no limit. Unprefixed, so + /// on Windows it coordinates one session. + /// + internal static string MutexNameForPath(string path, string suffix) + => MutexNameForPath(path, suffix, SystemInfo.IsWindows ? null : MaxMutexNameLength); + + /// Takes the limit rather than deciding it, so both branches are testable anywhere. + private static string MutexNameForPath(string path, string suffix, int? maxLength) + { + string name = path.EnsureNotNull() + .Replace("\\", "_") + .Replace(":", "_") + .Replace("/", "_") + suffix; + + if (maxLength is null || name.Length <= maxLength) + { + return name; + } + + // TODO use SHA256.HashData and Convert.ToHexString on .net10 + using SHA256 sha256 = SHA256.Create(); + byte[] hash = sha256.ComputeHash(Encoding.UTF8.GetBytes(path)); + return "log4net_" + BitConverter.ToString(hash).Replace("-", "") + suffix; + } + + /// The longest mutex name Unix accepts. Windows has no limit. Both measured. + private const int MaxMutexNameLength = 255; + /// /// The name of the log file. /// diff --git a/src/log4net/Appender/RollingFileAppender.cs b/src/log4net/Appender/RollingFileAppender.cs index 1339bb61..0b31c616 100644 --- a/src/log4net/Appender/RollingFileAppender.cs +++ b/src/log4net/Appender/RollingFileAppender.cs @@ -1059,11 +1059,7 @@ public override void ActivateOptions() } // initialize the mutex that is used to lock rolling - _mutexForRolling = new Mutex(false, _baseFileName - .Replace("\\", "_") - .Replace(":", "_") - .Replace("/", "_") + "_rolling" - ); + _mutexForRolling = new Mutex(false, MutexNameForPath(_baseFileName, "_rolling")); if (_rollDate && File is not null && _scheduledFilename is null) { diff --git a/src/log4net/Util/SystemInfo.cs b/src/log4net/Util/SystemInfo.cs index f71876d7..5da9adb7 100644 --- a/src/log4net/Util/SystemInfo.cs +++ b/src/log4net/Util/SystemInfo.cs @@ -47,6 +47,12 @@ public static class SystemInfo /// Is the mono runtime used /// internal static bool IsMono { get; } = Type.GetType("Mono.Runtime") is not null; + + /// + /// Is the runtime on Windows + /// + /// Not RuntimeInformation.IsOSPlatform, which throws below net471. + internal static bool IsWindows { get; } = Environment.OSVersion.Platform == PlatformID.Win32NT; /// /// Initialize default values for private static fields. From 2f3d444e2ff87dbc255db8688086161e9c880f12 Mon Sep 17 00:00:00 2001 From: Jan Friedrich Date: Mon, 14 Sep 2026 22:10:46 +0200 Subject: [PATCH 3/3] drop the pre-Vista event log size branch Windows 7 SP1 is the floor for the net462 build this file compiles into, so the version test could not fail and the 32766 constant behind it was dead. The surviving constant keeps its measured value and loses the superseded lore. --- src/log4net/Appender/EventLogAppender.cs | 67 ++---------------------- 1 file changed, 5 insertions(+), 62 deletions(-) diff --git a/src/log4net/Appender/EventLogAppender.cs b/src/log4net/Appender/EventLogAppender.cs index fa0a23d5..524dcf9c 100644 --- a/src/log4net/Appender/EventLogAppender.cs +++ b/src/log4net/Appender/EventLogAppender.cs @@ -433,7 +433,7 @@ private static string PrepareEventText(string rendered, int maxSize) private int GetMaxMessageSize() { string machineName = MachineName == "." ? Environment.MachineName : MachineName; - int budget = _maxEventlogMessageSize + int budget = MaxEventlogMessageSize - LogName.Length - ApplicationName.Length - machineName.Length @@ -519,47 +519,14 @@ public class Level2EventLogEntryType : LevelMappingEntry private static readonly Type _declaringType = typeof(EventLogAppender); /// - /// The maximum size supported by default. + /// The maximum size the operating system supports for an event log message. /// /// - /// http://msdn.microsoft.com/en-us/library/xzwc042w(v=vs.100).aspx - /// The 32766 documented max size is two bytes shy of 32K (I'm assuming 32766 - /// may leave space for a two byte null terminator of #0#0). The 32766 max - /// length is what the .NET 4.0 source code checks for, but this is WRONG! - /// Strings with a length > 31839 on Windows Vista or higher can CORRUPT - /// the event log! See: System.Diagnostics.EventLogInternal.InternalWriteEvent() - /// for the use of the 32766 max size. - /// - private const int MaxEventlogMessageSizeDefault = 32766; - - /// - /// The maximum size supported by a windows operating system that is vista - /// or newer. - /// - /// - /// See ReportEvent API: - /// http://msdn.microsoft.com/en-us/library/aa363679(VS.85).aspx - /// ReportEvent's lpStrings parameter: - /// "A pointer to a buffer containing an array of - /// null-terminated strings that are merged into the message before Event Viewer - /// displays the string to the user. This parameter must be a valid pointer - /// (or NULL), even if wNumStrings is zero. Each string is limited to 31,839 characters." - /// - /// Going beyond the size of 31839 will (at some point) corrupt the event log on Windows - /// Vista or higher! It may succeed for a while...but you will eventually run into the - /// error: "System.ComponentModel.Win32Exception : A device attached to the system is - /// not functioning", and the event log will then be corrupt (I was able to corrupt - /// an event log using a length of 31877 on Windows 7). - /// - /// The max size for Windows Vista or higher is documented here: - /// http://msdn.microsoft.com/en-us/library/xzwc042w(v=vs.100).aspx. - /// Going over this size may succeed a few times but the buffer will overrun and - /// eventually corrupt the log (based on testing). - /// /// Measured on Windows 11 build 26200: a record is stored while message plus log name plus - /// source stays within 31736 characters, and one character more stores nothing at all. + /// source stays within this, and one character more stores nothing. The 32766 that .NET itself + /// checks for is wrong and corrupts the log. /// - private const int MaxEventlogMessageSizeVistaOrNewer = 31736; + private const int MaxEventlogMessageSize = 31736; /// /// Held back from the computed limit. Crossing it discards the record silently, consumes the @@ -567,29 +534,5 @@ public class Level2EventLogEntryType : LevelMappingEntry /// private const int MaxEventlogMessageSizeMargin = 1024; - /// - /// The maximum size that the operating system supports for - /// a event log message. - /// - /// - /// Used to determine the maximum string length that can be written - /// to the operating system event log and eventually truncate a string - /// that exceeds the limits. - /// - private static readonly int _maxEventlogMessageSize = GetMaxEventLogMessageSize(); - - /// - /// This method determines the maximum event log message size allowed for - /// the current environment. - /// - /// - private static int GetMaxEventLogMessageSize() - { - if (Environment.OSVersion.Platform == PlatformID.Win32NT && Environment.OSVersion.Version.Major >= 6) - { - return MaxEventlogMessageSizeVistaOrNewer; - } - return MaxEventlogMessageSizeDefault; - } } #endif // NET462_OR_GREATER \ No newline at end of file