org.jboss.cache.lock.TimeoutException reports lock is unlocked -------------------------------------------------------------- Key: JBCACHE-1568 URL: https://jira.jboss.org/jira/browse/JBCACHE-1568 Project: JBoss Cache Issue Type: Bug Security Level: Public (Everyone can see) Components: Locking Affects Versions: 1.4.1.SP13 Reporter: Dennis Reed Assignee: Manik Surtani Priority: Minor During an INVALIDATION_SYNC cluster call, the following exception is reported. There is a lock TimeoutException, but it reports that the lock is not locked. This appears to be a race condition between the time the lock is checked and when the log is printed. [WARN ] [org.jboss.cache.TreeCache] replication failure with method_call _evict; id:8; Args: ( arg[0] = /path/to/data) exception org.jboss.cache.lock.TimeoutException: failure acquiring lock: fqn=/path/to/data, caller=Thread[IncomingMessageHandler (channel= CustomCache),5,JGroups threads], lock=<unlocked> (org.jboss.cache.lock.LockStrategyReadCommitted@7c72d14f) at org.jboss.cache.Node.acquire(Node.java:533) at org.jboss.cache.interceptors.PessimisticLockInterceptor.acquireNodeLock(PessimisticLockInterceptor.java:410) at org.jboss.cache.interceptors.PessimisticLockInterceptor.lock(PessimisticLockInterceptor.java:322) at org.jboss.cache.interceptors.PessimisticLockInterceptor.invoke(PessimisticLockInterceptor.java:196) at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68) at org.jboss.cache.interceptors.UnlockInterceptor.invoke(UnlockInterceptor.java:32) at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68) at org.jboss.cache.interceptors.InvalidationInterceptor.invoke(InvalidationInterceptor.java:60) at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68) at org.jboss.cache.interceptors.TxInterceptor.handleNonTxMethod(TxInterceptor.java:379) at org.jboss.cache.interceptors.TxInterceptor.invoke(TxInterceptor.java:174) at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68) at org.jboss.cache.interceptors.CacheMgmtInterceptor.invoke(CacheMgmtInterceptor.java:179) at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:5934) at org.jboss.cache.TreeCache._replicate(TreeCache.java:5211) at sun.reflect.GeneratedMethodAccessor228.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:585) at org.jgroups.blocks.MethodCall.invoke(MethodCall.java:330) at org.jgroups.blocks.RpcDispatcher.handle(RpcDispatcher.java:281) at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:654) at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:544) at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:367) at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:779) at org.jgroups.JChannel.up(JChannel.java:1090) at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:382) at org.jgroups.stack.ProtocolStack.receiveUpEvent(ProtocolStack.java:398) at org.jgroups.stack.Protocol.passUp(Protocol.java:520) at org.jgroups.protocols.pbcast.STATE_TRANSFER.up(STATE_TRANSFER.java:158) at org.jgroups.stack.Protocol.receiveUpEvent(Protocol.java:470) at org.jgroups.stack.Protocol.passUp(Protocol.java:520) at org.jgroups.protocols.pbcast.GMS.up(GMS.java:763) at org.jgroups.stack.Protocol.receiveUpEvent(Protocol.java:470) at org.jgroups.protocols.pbcast.GMS.receiveUpEvent(GMS.java:783) at org.jgroups.stack.Protocol.passUp(Protocol.java:520) at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:262) at org.jgroups.stack.Protocol.receiveUpEvent(Protocol.java:470) at org.jgroups.stack.Protocol.passUp(Protocol.java:520) at org.jgroups.protocols.pbcast.NAKACK.handleMessage(NAKACK.java:685) at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:517) at org.jgroups.stack.Protocol.receiveUpEvent(Protocol.java:470) at org.jgroups.stack.Protocol.passUp(Protocol.java:520) at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:170) at org.jgroups.stack.Protocol.receiveUpEvent(Protocol.java:470) at org.jgroups.stack.Protocol.passUp(Protocol.java:520) at org.jgroups.protocols.FD.up(FD.java:300) at org.jgroups.stack.Protocol.receiveUpEvent(Protocol.java:470) at org.jgroups.stack.Protocol.passUp(Protocol.java:520) at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:301) at org.jgroups.stack.Protocol.receiveUpEvent(Protocol.java:470) at org.jgroups.stack.Protocol.passUp(Protocol.java:520) at org.jgroups.protocols.MERGE2.up(MERGE2.java:162) at org.jgroups.stack.Protocol.receiveUpEvent(Protocol.java:470) at org.jgroups.stack.Protocol.passUp(Protocol.java:520) at org.jgroups.protocols.TP.access$900(TP.java:47) at org.jgroups.protocols.TP$IncomingMessageHandler.run(TP.java:1343) at java.lang.Thread.run(Thread.java:595) Caused by: org.jboss.cache.lock.TimeoutException: read lock for /path/to/data could not be acquired by Thread[IncomingMessageHandler (channel=CustomCache),5,JGroups threads] after 0 ms. Locks: Read lock owners: [] Write lock owner: null , lock info: <unlocked> (org.jboss.cache.lock.LockStrategyReadCommitted@7c72d14f) at org.jboss.cache.lock.IdentityLock.acquireReadLock(IdentityLock.java:262) at org.jboss.cache.Node.acquireReadLock(Node.java:545) at org.jboss.cache.Node.acquire(Node.java:507) ... 60 more -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: https://jira.jboss.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira