You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@logging.apache.org by "omtslug (via GitHub)" <gi...@apache.org> on 2026/04/17 17:20:10 UTC
[I] Log messages not getting to appender during concurrent logging (logging-log4net)
omtslug opened a new issue, #292:
URL: https://github.com/apache/logging-log4net/issues/292
Hi
I'm looking into going to log4net 3.3 but we have some logging concurrency test that bails out and I'm uncertain about the real cause.
What happens is that we don't get expected log count in the appender when doing concurrent logging.
Rather hard to reproduce, see attached repro which sets up an ILoggerRepository and Hierarchy and then runs the concurrent logging.
(put them on disk and run script.ps1), (all of this on windows 11 and windows server)
The result I get:
```
3.3.0 on net472: OK=17, NOK=3
3.3.0 on net10.0-windows: OK=19, NOK=1
3.0.4 on net472: OK=13, NOK=7
3.0.4 on net10.0-windows: OK=20, NOK=0
2.0.14 on net472: OK=20, NOK=0
2.0.14 on net10.0-windows: OK=20, NOK=0
2.0.17 on net472: OK=20, NOK=0
2.0.17 on net10.0-windows: OK=20, NOK=0
(not ok should be 0)
```
Please have a look at the LoggingConcurrencyTests ctor if that code is correct for log4net 2 and 3 versions.
Please try to reproduce it with attached code.
The actual test just does massive parallel logging, including a GetLogger call.
If the GetLogger call is done outside the loop all is good ('alt b') so it's related to the GetLogger.
It's possible to argue that the test is somewhat theoretic and maybe aggressive but I think that this problem seen on v3, not v2, is a bit worrying.
(hmm, working on getting the repro code into this..)
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@logging.apache.org.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [I] Log messages not getting to appender during concurrent GetLogger (logging-log4net)
Posted by "FreeAndNil (via GitHub)" <gi...@apache.org>.
FreeAndNil commented on issue #292:
URL: https://github.com/apache/logging-log4net/issues/292#issuecomment-4276702044
Hi @omtslug,
thanks for the detailed report and the reproduction test - both are very helpful.
I will take a closer look tomorrow.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@logging.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [I] Log messages not getting to appender during concurrent GetLogger (logging-log4net)
Posted by "FreeAndNil (via GitHub)" <gi...@apache.org>.
FreeAndNil commented on issue #292:
URL: https://github.com/apache/logging-log4net/issues/292#issuecomment-4329261890
Hi Stefan,
Thanks for the thoughtful write-up.
**a)** Noted - and not entirely wrong. But as you say, let's not go down that path here.
**b)** The double-checked locking approach you are proposing looks promising. The fast path stays lock-free via `TryGetValue`, and the lock is only taken on first creation - which is exactly the right trade-off. We will evaluate this and work on it.
For some background: the switch from `Hashtable` to `ConcurrentDictionary` for the loggers collection was introduced in #126. The intent was sound - `Hashtable` was clearly no longer the right way to hold that data - but as your bug demonstrates, `ConcurrentDictionary` alone is not sufficient when the value needs to be initialized atomically.
**c)** A 2.x release with the vulnerability fix is unfortunately not something we can provide. The 2.x line still targets legacy frameworks including .NET Compact Framework, and we no longer have any environment where we could build, test, or validate changes against those targets. Shipping a fix we cannot test would be irresponsible, so 2.x will not receive this fix.
For most users, migrating to 3.x should be straightforward - outside of dropping support for those legacy frameworks, there are very few breaking changes. If you are on a modern framework, the upgrade path should be smooth.
Thanks again for the detailed investigation and the concrete proposal.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@logging.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [I] Log messages not getting to appender during concurrent GetLogger (logging-log4net)
Posted by "FreeAndNil (via GitHub)" <gi...@apache.org>.
FreeAndNil commented on issue #292:
URL: https://github.com/apache/logging-log4net/issues/292#issuecomment-4412749555
@omtslug can you test #294?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@logging.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [I] Log messages not getting to appender during concurrent GetLogger (logging-log4net)
Posted by "FreeAndNil (via GitHub)" <gi...@apache.org>.
FreeAndNil commented on issue #292:
URL: https://github.com/apache/logging-log4net/issues/292#issuecomment-4439894653
@omtslug can you test?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@logging.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [I] Log messages not getting to appender during concurrent GetLogger (logging-log4net)
Posted by "gdziadkiewicz (via GitHub)" <gi...@apache.org>.
gdziadkiewicz closed issue #292: Log messages not getting to appender during concurrent GetLogger
URL: https://github.com/apache/logging-log4net/issues/292
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@logging.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [I] Log messages not getting to appender during concurrent GetLogger (logging-log4net)
Posted by "omtslug (via GitHub)" <gi...@apache.org>.
omtslug commented on issue #292:
URL: https://github.com/apache/logging-log4net/issues/292#issuecomment-4325632050
Many thanks for looking into this issue.
Some thoughts/questions I have
( you could very well ignore my 'a' rant, but i had to add it.. )
a, How come classic locks are on the not-use list and should be avoided (this is not only a log4net trend).
Lock free solutions are great and cool but very hard to reason about, see e.g. this bug.
Again, never mind about this, it's a subject on its own which we shouldnt pursue here.
b, In this specific bug we have a race issue when doing concurrent creation of a logger.
It must be very seldom we actually instantiate a new logger, the ConcurrentDictionary _loggers.TryGetValue is lock free and
will in all cases except the first return the available logger without locking.
What I'm proposing is something like this (simplified/naive):
```
if (!_loggers.TryGetValue(key, out object? node))
{
lock (_loggers)
{
if (!_loggers.TryGetValue(key, out node))
{
Logger newLogger = CreateLogger(key.Name);
RegisterLogger(newLogger);
node = _loggers.GetOrAdd(key, newLogger);
}
}
}
```
The exact implementation is not that important, what I want to emphasize is that if we handle the fast path lock free, ConcurrentDictionary, it shouldn't be an issue that we take a lock when we need to create/adjust loggers?
(if needed we could create a logger name specific lock but I'm uncertain how 'slim/narrow' we can be e.g. in RegisterLogger, UpdateParents etc.)
I see in the v2 code that we take a lock in the GetLogger call and that will happen both when returning an existing and when needing to create a new logger.
With the change to ConcurrentDictionary the improvement is good and real, (but keep a lock for the creation).
c, The background for all this is related to the vulnerability raised some weeks ago for all log4net versions before 3.3.
We were quite happy with the v2 version.
Is it possible to do a release on v2 major with the vulnerability fixed? (drop the feature is my suggestion, do what's easiest)
(maybe not realistic, related to when a fix for this can be available and if there could be other similar issues in v3)
All good and thanks for a great component
/Stefan
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@logging.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [I] Log messages not getting to appender during concurrent GetLogger (logging-log4net)
Posted by "omtslug (via GitHub)" <gi...@apache.org>.
omtslug commented on issue #292:
URL: https://github.com/apache/logging-log4net/issues/292#issuecomment-4440216764
> [@omtslug](https://github.com/omtslug) can you test?
Very sorry but i'm fully booked with other stuff, can try to test it when i have time (will probably be several weeks), and it will more or less just be with the test repro we already have.
Many thanks for the feedback and fix.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@logging.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [I] Log messages not getting to appender during concurrent GetLogger (logging-log4net)
Posted by "gdziadkiewicz (via GitHub)" <gi...@apache.org>.
gdziadkiewicz commented on issue #292:
URL: https://github.com/apache/logging-log4net/issues/292#issuecomment-4341641838
b) I'm reluctant to go for ` lock (_loggers)` for creating a log due to two reasons:
1. Even with the proposed lock in `GetLogger` it is still possible to get an unregistered logger for a brief moment by intervening `GetLogger` and `Hierarchy.Exists` calls. This is due to the fact that the biggest crime of `GetLogger` is, IMO, inserting a not-yet-registered logger into the dict making it accessible for others.
2. The users are allowed to use as many loggers with mix of same and different names as they want and making creation of x independent loggers at the same time sequential would slow them down, especially if they start it up all at once.
I'm reviewing my lockless solution with Copilot in https://github.com/gdziadkiewicz/logging-log4net/pull/4 (please take a look if interested) and, given no major issues from testing or review, expect to create the real PR to main repo today. Expect an explanation in description of the PR why I believe this will handle both the problem highlighted in this issue and the dotted loggers. I also added the repro as test to prevent regression in future.
Logger name specific locks you mentioned would not suffer from those issues. I will investigate that alternative too.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@logging.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [I] Log messages not getting to appender during concurrent logging (logging-log4net)
Posted by "omtslug (via GitHub)" <gi...@apache.org>.
omtslug commented on issue #292:
URL: https://github.com/apache/logging-log4net/issues/292#issuecomment-4269993824
'' Failed to upload ''
Here's Log4NetConcurrencyRepro.csproj
```
<Project Sdk="Microsoft.NET.Sdk">
<PropertyGroup>
<TargetFrameworks>net472;net10.0-windows</TargetFrameworks>
<IsPackable>false</IsPackable>
<IsTestProject>true</IsTestProject>
<Log4NetVersion Condition="'$(Log4NetVersion)' == ''">3.3.0</Log4NetVersion>
</PropertyGroup>
<ItemGroup>
<PackageReference Include="log4net" Version="$(Log4NetVersion)" />
<PackageReference Include="Microsoft.NET.Test.Sdk" Version="17.10.0" />
<PackageReference Include="xunit" Version="2.9.0" />
<PackageReference Include="xunit.runner.visualstudio" Version="2.8.1">
<PrivateAssets>all</PrivateAssets>
<IncludeAssets>runtime; build; native; contentfiles; analyzers; buildtransitive</IncludeAssets>
</PackageReference>
</ItemGroup>
</Project>
```
Here's LoggingConcurrencyTests.cs
```
using System;
using System.Collections.Generic;
using System.Linq;
using System.Threading;
using System.Threading.Tasks;
using log4net;
using log4net.Appender;
using log4net.Core;
using log4net.Layout;
using log4net.Repository;
using log4net.Repository.Hierarchy;
using Xunit;
namespace Log4NetConcurrencyRepro
{
public class LoggingConcurrencyTests : IDisposable
{
private readonly TestMemoryAppender _memoryAppender;
private readonly ILoggerRepository _repository;
public LoggingConcurrencyTests()
{
_repository = LogManager.CreateRepository(Guid.NewGuid().ToString());
_memoryAppender = new TestMemoryAppender();
_memoryAppender.Layout = new PatternLayout("%message");
_memoryAppender.ActivateOptions();
var hierarchy = (Hierarchy)_repository;
hierarchy.Root.AddAppender(_memoryAppender);
hierarchy.Root.Level = Level.All;
hierarchy.Configured = true;
}
[Fact]
public void Logging_DuringHighConcurrency_ShouldNotLoseMessages()
{
const int messageCount = 400;
const int loggerCount = 20;
// alt b: var loggers = Enumerable.Range(0, loggerCount).Select(i => LogManager.GetLogger(_repository.Name, "ConcurrencyTest-" + i)).ToArray();
Parallel.For(0, messageCount, i =>
{
// alt b: var logger = loggers[i % loggerCount];
var logger = LogManager.GetLogger(_repository.Name, "ConcurrencyTest-" + (i % loggerCount));
logger.Info("High concurrency message " + i);
});
Assert.Equal(messageCount, _memoryAppender.GetAppendCount());
var events = _memoryAppender.GetEvents();
Assert.Equal(messageCount, events.Length);
for (var i = 0; i < messageCount; i++)
{
var expectedMessage = "High concurrency message " + i;
Assert.Contains(events, e => e.RenderedMessage == expectedMessage);
}
}
public void Dispose()
{
_memoryAppender.Clear();
_repository.Shutdown();
}
private sealed class TestMemoryAppender : AppenderSkeleton
{
private readonly List<LoggingEvent> _events = new List<LoggingEvent>();
private readonly object _lock = new object();
private int _appendCount;
protected override void Append(LoggingEvent loggingEvent)
{
Interlocked.Increment(ref _appendCount);
if (loggingEvent == null)
return;
loggingEvent.Fix = FixFlags.All;
lock (_lock)
{
_events.Add(loggingEvent);
}
}
public int GetAppendCount()
{
return Volatile.Read(ref _appendCount);
}
public LoggingEvent[] GetEvents()
{
lock (_lock)
{
return _events.ToArray();
}
}
public void Clear()
{
lock (_lock)
{
_events.Clear();
_appendCount = 0;
}
}
}
}
}
```
Here's script.ps1
```
function BuildAndTest([string]$tfm, [string]$l4n) {
""
"************************************************************"
"*** Running $l4n on $tfm"
"*** "
remove-item .\bin,.\obj -rec -ea 0
dotnet build .\Log4NetConcurrencyRepro.csproj -c Release -f $tfm -p Log4NetVersion=$l4n
1..20 |
%{ $testok = 0; $testnok = 0 } `
{ dotnet vstest .\bin\Release\$tfm\Log4NetConcurrencyRepro.dll; if (!$lastexitcode) { $testok++ } else { $testnok++ } } `
{ "***`n***`n*** Completed $l4n on $tfm. Outcome: OK=$testok, NOK=$testnok`n***"
$script:result += "$l4n on $tfm : `tOK=$testok, NOK=$testnok"
}
""
}
$result = @()
BuildAndTest 'net472' '3.3.0'
BuildAndTest 'net472' '2.0.14'
BuildAndTest 'net10.0-windows' '3.3.0'
BuildAndTest 'net10.0-windows' '2.0.14'
BuildAndTest 'net472' '3.0.4'
BuildAndTest 'net472' '2.0.17'
BuildAndTest 'net10.0-windows' '3.0.4'
BuildAndTest 'net10.0-windows' '2.0.17'
""
"************************************************************"
"*** Overall results:"
$result
""
```
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@logging.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [I] Log messages not getting to appender during concurrent logging (logging-log4net)
Posted by "omtslug (via GitHub)" <gi...@apache.org>.
omtslug commented on issue #292:
URL: https://github.com/apache/logging-log4net/issues/292#issuecomment-4273116348
I'm looking into this code in v3 Hierarchy.cs, (don't know if it's the stuff used but i think so)
```
private Logger? TryCreateLogger(LoggerKey key, ILoggerFactory factory)
{
if (!_loggers.TryGetValue(key, out object? node))
{
Logger newLogger = CreateLogger(key.Name);
node = _loggers.GetOrAdd(key, newLogger);
if (node == newLogger)
{
RegisterLogger(newLogger);
}
}
if (node is Logger logger)
{
return logger;
}
[snip]
```
Imagine that we have parallel GetLogger calls being made for the same logger.
Isn't there a risk that a 'not ready' logger is returned?
Two threads wants the same logger:
a, neither of them gets it from _loggers.
b, both does CreateLogger
c, one of these gets into _loggers and the second GetOrAdd will return the one already in _loggers.
d, the issue is now that this 'second' thread returns the Logger from _loggers but the RegisterLogger hasn't been done yet,
it's the work for the first thread which in some cases is delayed.
Thoughts/discussion welcome.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@logging.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [I] Log messages not getting to appender during concurrent GetLogger (logging-log4net)
Posted by "gdziadkiewicz (via GitHub)" <gi...@apache.org>.
gdziadkiewicz commented on issue #292:
URL: https://github.com/apache/logging-log4net/issues/292#issuecomment-4299328534
@omtslug The bug reproduces for me (thanks for great repro), digging into root cause.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@logging.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [I] Log messages not getting to appender during concurrent GetLogger (logging-log4net)
Posted by "gdziadkiewicz (via GitHub)" <gi...@apache.org>.
gdziadkiewicz commented on issue #292:
URL: https://github.com/apache/logging-log4net/issues/292#issuecomment-4324605123
Hi, I spent some time on it. Log4net 2.x avoids the issue by heavy lock usage. The locks got removed in version 3 and opened this bag of challenges. I drafted a solution that does not reintroduce the locking, but instead introduces a bool carried with each logger for tracking its readiness (only one thread wins the competition for creating the missing logger, rest wait until it is done, similar to 2.x behavior, but none of the global locking). Immediately the imaginary friend noted that there are two open questions:
1. What to do with the `OnLoggerCreation` event? Is completing the callback a requirement to be "ready"? User can register whatever they want for callback. I'm tempted to recreate 2.x behavior there.
2. I only addressed dot-less loggers. I should extend the tests to also tests dotted loggers that are more connected in the hierarchy . I will do that and make sure the fix also addresses them
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@logging.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org