I have not investigated into the deep details to find a way to work around
all this messy trouble since it would require me to disassemble several
implementations built on different machines and with different compilers
(different msbuild versions for all the supported .NET versions, different
mono versions, ..). This is such time consuming that it might be even
better to be automated.
Thus my conclusion is the same: *exceptional design patterns are never a
good deal!*
However, the issue might be solveable with a better log4net configuration
only. I can imagine that spawning a remoting appender for every thread
should suffice since then cross thread locking would no longer occur.
2014-10-21 15:46 GMT+02:00 <piers.willi...@gmail.com>:
> 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 <calin.pa...@codemart.ro>
> *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
>
--
Dominik Psenner
