Repository navigation
file locking: keep the log on a failed roll, fix the mutex name #319
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Merged
+1,374
−252
Merged
Changes from 3 commits
Commits
Show all changes
15 commits
Select commit
Hold shift + click to select a range
73b9a17
keep the log when a roll cannot rename it #319
FreeAndNil 18bc141
name the file lock mutex after the resolved path #319
FreeAndNil 2f3d444
drop the pre-Vista event log size branch
FreeAndNil a952525
answer the review on the file locking work #319
FreeAndNil 6dc58e5
Merge remote-tracking branch 'origin/master' into Feature/319-file-lo…
FreeAndNil 03af5dc
give the temp folder tests their own folder #319
FreeAndNil dc354f9
bump PeanutButter.Utils to 3.0.437
FreeAndNil 0e1e7cf
document the overrides in the two locking fakes
FreeAndNil 1b7a8ae
cap the mutex name by UTF-8 bytes, not characters #319
FreeAndNil 1865b50
retry a pending rename outside the size roll path #319
FreeAndNil 5b594a8
retry a pending rename every tenth of MaxFileSize #319
FreeAndNil ef16930
the changelog attribution does not repeat the pull request link
FreeAndNil c907f7f
compute the retry threshold once #319
FreeAndNil 51a751e
keep the startup roll from rolling twice #319
FreeAndNil 2c7cd96
assert the deadline, not the wall clock #319
FreeAndNil File filter
Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
There are no files selected for viewing
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,13 @@ | ||
| <?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="319" link="https://github.com/apache/logging-log4net/pull/319"/> | ||
| <description format="asciidoc">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)</description> | ||
| </entry> | ||
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,14 @@ | ||
| <?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="319" link="https://github.com/apache/logging-log4net/pull/319"/> | ||
| <description format="asciidoc">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)</description> | ||
|
FreeAndNil marked this conversation as resolved.
Outdated
|
||
| </entry> | ||
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -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="319" link="https://github.com/apache/logging-log4net/pull/319"/> | ||
| <description format="asciidoc">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)</description> | ||
|
FreeAndNil marked this conversation as resolved.
Outdated
|
||
| </entry> | ||
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -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="319" link="https://github.com/apache/logging-log4net/pull/319"/> | ||
| <description format="asciidoc">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)</description> | ||
|
FreeAndNil marked this conversation as resolved.
Outdated
|
||
| </entry> | ||
222 changes: 222 additions & 0 deletions
222
src/log4net.Tests/Appender/FileAppenderMutexNameTest.cs
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -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; | ||
|
|
||
| /// <summary>The mutex name the file lock and the rolling lock derive from the log file path.</summary> | ||
| [TestFixture] | ||
| public sealed class FileAppenderMutexNameTest | ||
| { | ||
| /// <summary>Records what the appender had resolved by the time the locking model was activated.</summary> | ||
| 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() | ||
| { } | ||
|
Copilot marked this conversation as resolved.
|
||
| } | ||
|
|
||
| private string _directory = string.Empty; | ||
|
|
||
| [SetUp] | ||
| public void SetUp() | ||
| { | ||
| _directory = Path.Combine(Path.GetTempPath(), Guid.NewGuid().ToString("N")); | ||
|
FreeAndNil marked this conversation as resolved.
Outdated
|
||
| Directory.CreateDirectory(_directory); | ||
| } | ||
|
|
||
| [TearDown] | ||
| public void TearDown() | ||
| { | ||
| if (Directory.Exists(_directory)) | ||
| { | ||
| Directory.Delete(_directory, true); | ||
| } | ||
| } | ||
|
|
||
| /// <summary> | ||
| /// The model was activated before the path was resolved, so a relative and an absolute spelling | ||
| /// of one file never shared a mutex. | ||
| /// </summary> | ||
| [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); | ||
| } | ||
| } | ||
| } | ||
|
|
||
| /// <summary>A name past the Unix limit took the appender down before anything was logged.</summary> | ||
| [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")); | ||
| } | ||
|
|
||
| /// <summary>A name that fits is left alone, so no existing deployment's mutex changes.</summary> | ||
| [Test] | ||
| public void AShortPathKeepsTheNameEarlierVersionsComputed() | ||
| => Assert.That(MutexNameForPath("/var/log/app.log", "_rolling"), Is.EqualTo("_var_log_app.log_rolling")); | ||
|
|
||
| /// <summary>Under a limit, a long name is hashed below it and stays distinct.</summary> | ||
| [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(); | ||
| } | ||
|
|
||
| /// <summary>With no limit, which is Windows, the name is left as earlier versions computed it.</summary> | ||
| [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")); | ||
| } | ||
|
|
||
| /// <summary> | ||
| /// 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. | ||
| /// </summary> | ||
| [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])!; | ||
| } | ||
Oops, something went wrong.
Oops, something went wrong.
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
Uh oh!
There was an error while loading. Please reload this page.