I'll gladly defer to an expert here, but it's my understanding that the pattern
that log4net is currently using within Logger.CallAppenders() does indeed have
the problem described in the link you sent.
I'd imagine you'd have to abort a lot of threads for this relatively small race
to occur frequently however.
Successfully managing the semantics around atomic lock hold/release in the face
of thread aborts is a bit of a minefield actually, especially as the low-level
details (what op codes the JITer spits out on what architectures) do actually
matter. Anyway, my understanding is it was realized that the typical locking
pattern (and that used by log4net):
EnterLock()
try{
}finally{
ReleaseLock()
}
had a race condition in that the thread could be killed (for various reasons)
prior to the try block being entered*. In CLR 4 Microsoft introduced some
additional approaches to lock acquisition to remove this, so for example
var x = new object();
lock(x){
// something within lock
}
…now compiles down to something quite different to what it did before, using
the Monitor.TryEnter() overloads:
var x = new object();
bool wasHeld;
try{
Monitor.TryEnter(x, out wasHeld);
// do stuff
}finally{
if(wasHeld)
Monitor.Exit(x);
}
see
http://www.danielmoth.com/Blog/NET-4-MonitorEnter-Replaced-By-MonitorEnter.aspx
Unfortunately the TryEnter(ref bool) type overloads were never implemented for
ReaderWriterLockSlim (vote here
https://connect.microsoft.com/VisualStudio/feedback/details/612135/readerwriterlockslim-tryenter-methods-with-ref-bool-locktaken).
So even if log4net's ReaderWriterLock wrapper were to be re-written in this
style, it's going to have to mess about with critical sections etc … to achieve
the same thing, and then still just hope that the implementation is 'right’.
Nasty.
I'd have to say, however, that having to abort threads is generally a bad place
to be in (good excerpt from C# in a nutshell here :
http://www.albahari.com/threading/part4.aspx#_Aborting_Threads ). I don't know
exactly what you're attempting to do, but if possible I'd have thought you
would benefit from either:
Passing a cancellation token into long-running synchronous code, and just check
it from time to time
Refactor to use an async structure (like Task), and allow the framework to deal
with the mopup if you cancel the token
In the meantime, you might want to just consider recycling your process
periodically.
( * depending on what the JIT actually spits out of course. See
http://joeduffyblog.com/2007/01/29/monitorenter-thread-aborts-and-orphaned-locks/
for some gory details on this)
--
Piers, longtime log4net lurker
From: Calin Pavel
Sent: Friday, October 17, 2014 5:55 PM
To: log4net-user@logging.apache.org
Hello everybody,
I do have an .NET application (Windows Service) that collects data from a lot
of sources (DBs, log files, machines event logs, ...) and uses Log4Net to log
details of the actions / execution. As expected, I'm using a high number of
threads to collect data, threads that are writing logs in some files
(RollingFileAppenderer).
Lately it happens that the entire application is BLOCKED because all threads
were trying to acquire a read lock, like in the stack trace:
000000001ac3d998 00000000774715fa [HelperMethodFrame: 000000001ac3d998]
System.Threading.Thread.SleepInternal(Int32)
000000001ac3da90 000007fef747b5e9 System.Threading.Thread.Sleep(Int32)
000000001ac3dac0 000007fef5fb9631
System.Threading.ReaderWriterLockSlim.EnterMyLockSpin()
000000001ac3db90 000007fef5cd297e
System.Threading.ReaderWriterLockSlim.TryEnterReadLockCore(TimeoutTracker)
000000001ac3dbf0 000007fef5cd28fa
System.Threading.ReaderWriterLockSlim.TryEnterReadLock(TimeoutTracker)
000000001ac3dc40 000007fe98fb4efd
log4net.Repository.Hierarchy.Logger.CallAppenders(log4net.Core.LoggingEvent)
000000001ac3dcc0 000007fe98fb4907
log4net.Repository.Hierarchy.Logger.Log(System.Type, log4net.Core.Level,
System.Object, System.Exception)
000000001ac3dd30 000007fe98fb47f9 log4net.Core.LogImpl.Info(System.Object)
....
Did you encountered this before or did anybody else reported similar problems?
May be it's important to mention:
- I'm using Log4Net 1.2.13, .NET 4.5 on Windows 2008 R2
- that my threads have a timeout, and if they do not finish the job in the
given interval they are aborted.
In relation with this, I found a possible explanation of application hanging
here:
http://chabster.blogspot.ro/2013/07/a-story-of-orphaned-readerwriterlockslim.html
Could it be that the acquire of read lock in Logger.CallAppenderers method to
generate our problems?
Thank you in advance,
Calin Pavel
