Skip to content

Commit 0cd39cb

Browse files
authored
Fixes after AVSS scanning #298
Fixes for https://github.com/apache/tooling-agents/blob/main/ASVS/reports/logging-log4net/f57d7b3/issues.md --- ## Issue: FINDING-001 - Filter chain modification methods lack synchronization, creating potential race with FilterEvent under active logging **Labels:** bug, security, priority:low **Description:** ### Summary The `AddFilter` and `ClearFilters` methods in `AppenderSkeleton.cs` lack proper synchronization, creating a race condition with `FilterEvent` during active logging operations. This can lead to inconsistent filter chain state, potentially causing filters to be skipped, `NullReferenceException`, or lost filter entries. ### Details **CWE:** CWE-362 (Concurrent Execution using Shared Resource with Improper Synchronization) **ASVS:** 15.4.1 (L3) **Data Flow:** - `AddFilter` (no lock) → modifies `FilterHead`/`_tailFilter`/`filter.Next` - `FilterEvent` (under `LockObj` in `DoAppend`) reads `FilterHead` and traverses `f.Next` **Attack Vector:** In-process code within the trust boundary calling `AddFilter`/`ClearFilters` concurrently with active logging—for example, during dynamic reconfiguration while the appender is receiving log events. **Impact:** Inconsistent filter chain state during traversal in `FilterEvent`, resulting in: - Filters being skipped during evaluation - `NullReferenceException` during chain traversal - Lost filter entries ### Remediation Add `lock(LockObj)` to both `AddFilter` and `ClearFilters` methods to synchronize with the `DoAppend` hot path and ensure thread-safe filter chain modifications. ### Acceptance Criteria - [x] Fixed: `AddFilter` method wrapped with `lock(LockObj)` - [x] Fixed: `ClearFilters` method wrapped with `lock(LockObj)` - [x] Test added: Concurrent filter modification during active logging ### References - File: `src/log4net/Appender/AppenderSkeleton.cs` - Source Report: 15.4.1.md ### Priority **Low** - Requires in-process code with concurrent reconfiguration during active logging. Limited to availability/integrity impact within the logging subsystem. --- ## Issue: FINDING-002 - InterProcessLock Mutex Not Released When Underlying File Stream Is Null **Labels:** bug, security, priority:low **Description:** ### Summary When `InterProcessLock.AcquireLock()` is called and the underlying `_stream` is null (due to a prior file open failure), the named Mutex is acquired but never released. This causes a resource leak that blocks other processes attempting to use InterProcessLock on the same file, potentially leading to deadlock or resource exhaustion. ### Details **CWE:** CWE-772 (Missing Release of Resource after Effective Lifetime) **ASVS:** 1.4.3 (L2) **Data Flow:** 1. `InterProcessLock.AcquireLock()` called with `_stream == null` 2. `_mutex.WaitOne()` acquires the named Mutex 3. `_recursiveWatch` is incremented 4. Method returns null without releasing the mutex 5. Caller (`FileAppender.Append`) does not enter try/finally block 6. `ReleaseLock()` is never called 7. Named system Mutex remains held indefinitely **Attack Vector:** Not directly exploitable by external attackers. Requires environmental file open failure (e.g., permissions, disk full, file locked by another process). **Impact:** - Named Mutex remains held indefinitely - Other processes using InterProcessLock on the same file are blocked - Potential deadlock across processes - Resource exhaustion if multiple locks are leaked ### Remediation Release the named Mutex immediately when `AcquireLock()` detects that `_stream` is null: 1. Decrement `_recursiveWatch` 2. Call `_mutex.ReleaseMutex()` 3. Return null Ensure all code paths that acquire the mutex properly release it, even in error conditions. ### Acceptance Criteria - [x] Fixed: Mutex released when `_stream` is null in `AcquireLock()` - [x] Fixed: `_recursiveWatch` properly decremented in error path - [x] Test added: Verify mutex released when file stream is null ### References - File: `src/log4net/Appender/FileAppender.cs` - Source Report: 1.4.3.md ### Priority **Low** - Requires environmental file system failure. Impact limited to inter-process synchronization and resource exhaustion within logging subsystem. --- ## Issue: FINDING-003 - Finalizer path lacks exception protection, risking process termination **Labels:** bug, security, priority:low **Description:** ### Summary The `~AppenderSkeleton()` finalizer calls `Close()` which in turn calls `OnClose()` without exception protection. An unhandled exception on the finalizer thread will terminate the entire process in .NET Framework 2.0+ and .NET Core/5+. ### Details **CWE:** CWE-755 (Improper Handling of Exceptional Conditions) **ASVS:** 16.5.4 (L3) **Data Flow:** GC finalizer thread → `~AppenderSkeleton()` → `Close()` → `OnClose()` (subclass implementation) → unhandled exception → **process termination** **Attack Vector:** If a subclass implementation of `OnClose()` throws an unhandled exception during finalization (e.g., due to resource cleanup failure, network timeout, or malformed state), the finalizer thread will propagate the exception and terminate the entire application process. **Impact:** - Complete application/service termination - Denial of service - Loss of in-flight data - Ungraceful shutdown without proper cleanup ### Remediation 1. Wrap the finalizer's call to `Close()` in a try-catch block: ```csharp catch (Exception ex) when (!ex.IsFatal()) { // Log if possible, otherwise suppress } ``` 2. Consider protecting `Close()` itself with exception handling 3. Ensure `_isClosed` is set in a finally block to prevent repeated finalization attempts ### Acceptance Criteria - [x] Fixed: Finalizer wrapped with try-catch for non-fatal exceptions - [x] Fixed: `_isClosed` flag set in finally block - [x] Code review: Verify fatal exceptions (OutOfMemoryException, StackOverflowException) are not caught ### References - File: `src/log4net/Appender/AppenderSkeleton.cs` - Source Report: 16.5.4.md ### Priority **Low** - Requires specific failure conditions during finalization. However, impact is severe (process termination) when triggered. Recommend prioritizing fix despite low likelihood.
2 parents e633f77 + 2a0a190 commit 0cd39cb

7 files changed

Lines changed: 195 additions & 15 deletions
Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,11 @@
1+
<?xml version="1.0" encoding="UTF-8"?>
2+
<entry xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
3+
xmlns="https://logging.apache.org/xml/ns"
4+
xsi:schemaLocation="https://logging.apache.org/xml/ns https://logging.apache.org/xml/ns/log4j-changelog-0.xsd"
5+
type="fixed">
6+
<issue id="f57d7b3-001" link="https://github.com/apache/tooling-agents/blob/main/ASVS/reports/logging-log4net/f57d7b3/issues.md#issue-finding-001---filter-chain-modification-methods-lack-synchronization-creating-potential-race-with-filterevent-under-active-logging"/>
7+
<issue id="298" link="https://github.com/apache/logging-log4net/pull/298"/>
8+
<description format="asciidoc">
9+
fix race condition in `AppenderSkeleton.AddFilter` and `ClearFilters` under concurrent logging (CWE-362)
10+
</description>
11+
</entry>
Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,11 @@
1+
<?xml version="1.0" encoding="UTF-8"?>
2+
<entry xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
3+
xmlns="https://logging.apache.org/xml/ns"
4+
xsi:schemaLocation="https://logging.apache.org/xml/ns https://logging.apache.org/xml/ns/log4j-changelog-0.xsd"
5+
type="fixed">
6+
<issue id="f57d7b3-003" link="https://github.com/apache/tooling-agents/blob/main/ASVS/reports/logging-log4net/f57d7b3/issues.md#issue-finding-003---finalizer-path-lacks-exception-protection-risking-process-termination"/>
7+
<issue id="298" link="https://github.com/apache/logging-log4net/pull/298"/>
8+
<description format="asciidoc">
9+
fix unhandled exception in `AppenderSkeleton` finalizer that could terminate the process when `OnClose()` throws (CWE-755)
10+
</description>
11+
</entry>
Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,11 @@
1+
<?xml version="1.0" encoding="UTF-8"?>
2+
<entry xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
3+
xmlns="https://logging.apache.org/xml/ns"
4+
xsi:schemaLocation="https://logging.apache.org/xml/ns https://logging.apache.org/xml/ns/log4j-changelog-0.xsd"
5+
type="fixed">
6+
<issue id="f57d7b3-002" link="https://github.com/apache/tooling-agents/blob/main/ASVS/reports/logging-log4net/f57d7b3/issues.md#issue-finding-002---interprocesslock-mutex-not-released-when-underlying-file-stream-is-null"/>
7+
<issue id="298" link="https://github.com/apache/logging-log4net/pull/298"/>
8+
<description format="asciidoc">
9+
fix mutex leak in `InterProcessLock.AcquireLock` when the underlying file stream is null (CWE-772)
10+
</description>
11+
</entry>
Lines changed: 88 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,88 @@
1+
#region Apache License
2+
//
3+
// Licensed to the Apache Software Foundation (ASF) under one or more
4+
// contributor license agreements. See the NOTICE file distributed with
5+
// this work for additional information regarding copyright ownership.
6+
// The ASF licenses this file to you under the Apache License, Version 2.0
7+
// (the "License"); you may not use this file except in compliance with
8+
// the License. You may obtain a copy of the License at
9+
//
10+
// http://www.apache.org/licenses/LICENSE-2.0
11+
//
12+
// Unless required by applicable law or agreed to in writing, software
13+
// distributed under the License is distributed on an "AS IS" BASIS,
14+
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
15+
// See the License for the specific language governing permissions and
16+
// limitations under the License.
17+
//
18+
#endregion
19+
20+
using log4net.Filter;
21+
using log4net.Appender;
22+
using NUnit.Framework;
23+
24+
namespace log4net.Tests.Appender;
25+
26+
/// <summary>
27+
/// Unit tests for <see cref="AppenderSkeleton"/> filter chain management.
28+
/// </summary>
29+
[TestFixture]
30+
public sealed class AppenderSkeletonTest
31+
{
32+
private CountingAppender _appender = null!;
33+
34+
[SetUp]
35+
public void SetUp() => _appender = new CountingAppender();
36+
37+
[TearDown]
38+
public void TearDown() => _appender.Close();
39+
40+
/// <summary>
41+
/// Verifies that <see cref="AppenderSkeleton.AddFilter"/> sets <see cref="AppenderSkeleton.FilterHead"/> when the chain is empty.
42+
/// </summary>
43+
[Test]
44+
public void AddFilter_FirstFilter_SetsFilterHead()
45+
{
46+
DenyAllFilter filter = new();
47+
_appender.AddFilter(filter);
48+
Assert.That(_appender.FilterHead, Is.SameAs(filter));
49+
}
50+
51+
/// <summary>
52+
/// Verifies that a second <see cref="AppenderSkeleton.AddFilter"/> call appends the filter via <see cref="Filter.IFilter.Next"/>.
53+
/// </summary>
54+
[Test]
55+
public void AddFilter_SecondFilter_LinksToChain()
56+
{
57+
DenyAllFilter first = new();
58+
DenyAllFilter second = new();
59+
_appender.AddFilter(first);
60+
_appender.AddFilter(second);
61+
Assert.That(_appender.FilterHead, Is.SameAs(first));
62+
Assert.That(_appender.FilterHead!.Next, Is.SameAs(second));
63+
}
64+
65+
/// <summary>
66+
/// Verifies that <see cref="AppenderSkeleton.ClearFilters"/> resets <see cref="AppenderSkeleton.FilterHead"/> to null.
67+
/// </summary>
68+
[Test]
69+
public void ClearFilters_ResetsFilterHead()
70+
{
71+
_appender.AddFilter(new DenyAllFilter());
72+
_appender.ClearFilters();
73+
Assert.That(_appender.FilterHead, Is.Null);
74+
}
75+
76+
/// <summary>
77+
/// Verifies that filters can be added again after <see cref="AppenderSkeleton.ClearFilters"/>.
78+
/// </summary>
79+
[Test]
80+
public void ClearFilters_AllowsAddingFiltersAgain()
81+
{
82+
_appender.AddFilter(new DenyAllFilter());
83+
_appender.ClearFilters();
84+
DenyAllFilter filter = new();
85+
_appender.AddFilter(filter);
86+
Assert.That(_appender.FilterHead, Is.SameAs(filter));
87+
}
88+
}

src/log4net.Tests/Appender/FileAppenderTest.cs

Lines changed: 32 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -29,6 +29,8 @@
2929
using log4net.Core;
3030
using System.IO;
3131
using System.Linq;
32+
using System.Text;
33+
using System.Threading.Tasks;
3234

3335
namespace log4net.Tests.Appender;
3436

@@ -151,4 +153,34 @@ public void FilenameWithGlobalContextPatternStringTest()
151153
logs.Refresh();
152154
Assert.That(logs.GetFiles().Any(file => file.Name.StartsWith("file_custom_log_issue_193")));
153155
}
156+
157+
/// <summary>
158+
/// Verifies that <see cref="FileAppender.InterProcessLock"/> releases the mutex
159+
/// when the underlying file stream is null.
160+
/// </summary>
161+
[Test]
162+
public void InterProcessLock_AcquireLock_ReleasesMutexWhenStreamIsNull()
163+
{
164+
string tempFile = Path.GetTempFileName();
165+
FileAppender appender = new() { File = "log4net_ipl_test" };
166+
FileAppender.InterProcessLock lockingModel = new() { CurrentAppender = appender };
167+
lockingModel.ActivateOptions();
168+
lockingModel.OpenFile(tempFile, false, Encoding.UTF8);
169+
lockingModel.CloseFile(); // sets _stream to null; mutex remains alive
170+
try
171+
{
172+
Stream? stream = lockingModel.AcquireLock();
173+
Assert.That(stream, Is.Null);
174+
175+
// if the mutex was released, a second thread can acquire the lock without blocking
176+
Task task = Task.Run(lockingModel.AcquireLock);
177+
Assert.That(task.Wait(TimeSpan.FromSeconds(2)), Is.True,
178+
"Mutex was not released by AcquireLock when stream is null");
179+
}
180+
finally
181+
{
182+
lockingModel.OnClose();
183+
File.Delete(tempFile);
184+
}
185+
}
154186
}

src/log4net/Appender/AppenderSkeleton.cs

Lines changed: 39 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -65,13 +65,21 @@ public abstract class AppenderSkeleton : IAppender, IBulkAppender, IOptionHandle
6565
/// </remarks>
6666
~AppenderSkeleton()
6767
{
68-
// An appender might be closed then garbage collected.
68+
// An appender might be closed then garbage collected.
6969
// There is no point in closing twice.
70-
if (!_isClosed)
70+
if (_isClosed)
71+
{
72+
return;
73+
}
74+
LogLog.Debug(_declaringType, $"Finalizing appender named [{Name}].");
75+
try
7176
{
72-
LogLog.Debug(_declaringType, $"Finalizing appender named [{Name}].");
7377
Close();
7478
}
79+
catch (Exception ex) when (!ex.IsFatal())
80+
{
81+
LogLog.Warn(_declaringType, $"Exception during finalization of {GetType().FullName} [{Name}].", ex);
82+
}
7583
}
7684

7785
/// <summary>
@@ -111,6 +119,7 @@ public virtual IErrorHandler ErrorHandler
111119
{
112120
lock (LockObj)
113121
{
122+
// ReSharper disable once ConditionIsAlwaysTrueOrFalseAccordingToNullableAPIContract
114123
if (value is null)
115124
{
116125
// We do not throw exception here since the cause is probably a
@@ -198,8 +207,14 @@ public void Close()
198207
{
199208
if (!_isClosed)
200209
{
201-
OnClose();
202-
_isClosed = true;
210+
try
211+
{
212+
OnClose();
213+
}
214+
finally
215+
{
216+
_isClosed = true;
217+
}
203218
}
204219
}
205220
}
@@ -248,7 +263,7 @@ public void Close()
248263
public void DoAppend(LoggingEvent loggingEvent)
249264
{
250265
// This lock is absolutely critical for correct formatting
251-
// of the message in a multi-threaded environment. Without
266+
// of the message in a multithreaded environment. Without
252267
// this, the message may be broken up into elements from
253268
// multiple thread contexts (like get the wrong thread ID).
254269

@@ -332,7 +347,7 @@ public void DoAppend(LoggingEvent[] loggingEvents)
332347
loggingEvents.EnsureNotNull();
333348

334349
// This lock is absolutely critical for correct formatting
335-
// of the message in a multi-threaded environment. Without
350+
// of the message in a multithreaded environment. Without
336351
// this, the message may be broken up into elements from
337352
// multiple thread contexts (like get the wrong thread ID).
338353
lock (LockObj)
@@ -456,14 +471,17 @@ protected virtual bool FilterEvent(LoggingEvent loggingEvent)
456471
public virtual void AddFilter(IFilter filter)
457472
{
458473
filter.EnsureNotNull();
459-
if (FilterHead is null)
460-
{
461-
FilterHead = _tailFilter = filter;
462-
}
463-
else
474+
lock (LockObj)
464475
{
465-
_tailFilter!.Next = filter;
466-
_tailFilter = filter;
476+
if (FilterHead is null)
477+
{
478+
FilterHead = _tailFilter = filter;
479+
}
480+
else
481+
{
482+
_tailFilter!.Next = filter;
483+
_tailFilter = filter;
484+
}
467485
}
468486
}
469487

@@ -475,7 +493,13 @@ public virtual void AddFilter(IFilter filter)
475493
/// Clears the filter list for this appender.
476494
/// </para>
477495
/// </remarks>
478-
public virtual void ClearFilters() => FilterHead = _tailFilter = null;
496+
public virtual void ClearFilters()
497+
{
498+
lock (LockObj)
499+
{
500+
FilterHead = _tailFilter = null;
501+
}
502+
}
479503

480504
/// <summary>
481505
/// Checks if the message level is below this appender's threshold.

src/log4net/Appender/FileAppender.cs

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -657,6 +657,9 @@ public override void CloseFile()
657657
else
658658
{
659659
// this can happen when the file appender cannot open a file for writing
660+
_recursiveWatch--;
661+
_mutex.ReleaseMutex();
662+
return null;
660663
}
661664
}
662665
else

0 commit comments

Comments
 (0)