[logback-dev] IllegalMonitorStateException in AppenderAttachableImpl.appendLoopOnAppenders()

[Ceki Gulcu]

Any luck reproducing this issue?

Ceki Gulcu wrote:
> Hello Zoltan,
> 
> Looking at this exception and related code in AppenderAttachableImpl,
> moving the r.lock(); statement outside of the try block will not
> change anything because I believe that r.lock() does not throw
> exceptions. However, looking at ReentrantReadWriteLock.ReadLock class'
> lock() method, one is directed to the ReentrantReadWriteLock.Sync
> class and its acquireShared() method. If this method fails to acquire
> the lock due to a RuntimeException, then the subsequent r.unlock()
> call will fail with an IllegalMonitorStateException. In any case,
> r.lock() will not throw an exception since the exception is absorbed
> by the sync.acquireShared method.
> 
> It would be quite helpful if you were able to reproduce the problem.
> 
> We could place the r.unlock() invocation within a try/catch block
> (absorbing the IllegalMonitorStateException you got). However, this is
> may only obfuscate the real cause of the problem, that is an
> OutOfMemoryException or such. We could also imagine that there is a
> bug in ReentrantReadWriteLock. Given its complexity, it's not such an
> outlandish hypothesis.
> 
> Otherwise, the only remaining possibility is a bug in logback. But we
> all know that is impossible.
> 
> More seriously, I think this bug will be hard to nail down.
> 
> Szel, Zoltan (IDEAS) wrote:
>> Hi,
>>
>>  
>>
>> We have hit the exception mentioned in the subject in one of our 
>> applications. We are using JDK 6 and Logback 0.9.14.  Here is the 
>> stacktrace:
>>
>> Caused by: java.lang.IllegalMonitorStateException
>>  at 
>> java.util.concurrent.locks.ReentrantReadWriteLock$Sync.tryReleaseShared(ReentrantReadWriteLock.java:363) 
>>
>>  at 
>> java.util.concurrent.locks.AbstractQueuedSynchronizer.releaseShared(AbstractQueuedSynchronizer.java:1253) 
>>
>>  at 
>> java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.unlock(ReentrantReadWriteLock.java:745) 
>>
>>  at 
>> ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:64) 
>>
>>  at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:270)
>>  at ch.qos.logback.classic.Logger.callAppenders(Logger.java:257)
>>  at 
>> ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:439)
>>  at ch.qos.logback.classic.Logger.filterAndLog_1(Logger.java:411)
>>  at ch.qos.logback.classic.Logger.debug(Logger.java:504)
>>
>>  
>>
>> I have checked the code and it seems to me this can only happen if the 
>> readLock.lock() method throws an exception:
>>
>> *public* *int* appendLoopOnAppenders(E e) {
>>
>> 56 
>> <http://logback.qos.ch/xref/ch/qos/logback/core/spi/AppenderAttachableImpl.html#56>      
>> *int* size = 0;
>>
>> 57 
>> <http://logback.qos.ch/xref/ch/qos/logback/core/spi/AppenderAttachableImpl.html#57>      
>> *try* {
>>
>> 58 
>> <http://logback.qos.ch/xref/ch/qos/logback/core/spi/AppenderAttachableImpl.html#58>        
>> r.lock();
>>
>> 59 
>> <http://logback.qos.ch/xref/ch/qos/logback/core/spi/AppenderAttachableImpl.html#59>        
>> *for* (Appender<E> appender : appenderList) {
>>
>> 60 
>> <http://logback.qos.ch/xref/ch/qos/logback/core/spi/AppenderAttachableImpl.html#60>          
>> appender.doAppend(e);
>>
>> 61 
>> <http://logback.qos.ch/xref/ch/qos/logback/core/spi/AppenderAttachableImpl.html#61>          
>> size++;
>>
>> 62 
>> <http://logback.qos.ch/xref/ch/qos/logback/core/spi/AppenderAttachableImpl.html#62>        
>> }
>>
>> 63 
>> <http://logback.qos.ch/xref/ch/qos/logback/core/spi/AppenderAttachableImpl.html#63>      
>> } *finally* {
>>
>> 64 
>> <http://logback.qos.ch/xref/ch/qos/logback/core/spi/AppenderAttachableImpl.html#64>        
>> r.unlock();
>>
>> 65 
>> <http://logback.qos.ch/xref/ch/qos/logback/core/spi/AppenderAttachableImpl.html#65>      
>> }
>>
>> 66 
>> <http://logback.qos.ch/xref/ch/qos/logback/core/spi/AppenderAttachableImpl.html#66>      
>> *return* size;
>>
>> 67 
>> <http://logback.qos.ch/xref/ch/qos/logback/core/spi/AppenderAttachableImpl.html#67>    
>> }
>>
>>  
>>
>> if r.lock() in line 58 throws an exception for some reason than in the 
>> finally block the unlock will throw also an exception which will hide 
>> the original one. I cannot see any other reason why the unlock would 
>> throw this exception in this scenario. I am not yet able to reproduce 
>> it, but I thought this exception worth a mail. The only suggestion I 
>> have for now is to move the r.lock() call out of the try block, 
>> because if that is the bad guy, than we would have the original 
>> exception propagated.
>>
>>  
>>
>> If I have more information on this issue I will update this thread.
>>
>>  
>>
>> Regards,
>>
>> Zoltan Szel
>> *Morgan Stanley | IDEAS PRACTICE AREAS
>> *Lechner Odon fasor 8 | Floor 07
>> Budapest, 1095
>> Phone: +36 1 881-3978
>> Zoli.Szel at MorganStanley.com <mailto:Zoli.Szel at MorganStanley.com>
>>
>> ------------------------------------------------------------------------
>>
>> NOTICE: If received in error, please destroy and notify sender. Sender 
>> does not intend to waive confidentiality or privilege. Use of this 
>> email is prohibited when received in error.
>>
>>
>> ------------------------------------------------------------------------
>>
>> _______________________________________________
>> logback-dev mailing list
>> logback-dev at qos.ch
>> http://qos.ch/mailman/listinfo/logback-dev
> 

-- 
Ceki Gülcü
Logback: The reliable, generic, fast and flexible logging framework for Java.
http://logback.qos.ch