4 Replies Latest reply on Jun 11, 2008 6:40 PM by ajassal

    Lock timeout exceptions

    ajassal

      Am trying to understand some intermittent lock timeout exceptions we are seeing. These could be related to the LRU eviction policy thread not able to acquire a lock as it seems to timeout after 0ms and not 15000ms as it is specified in the

      15000

      attribute.

      If these are more informational i.e. eviction will occur in the next go around, can we log them differently. Or what can we do to set a timeout, etc. for these?

      Version: 1.4.1GA on Linux

      Here is the trace:

      ....
      at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:358)
      at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:775) at org.jgroups.JChannel.up(JChannel.java:1091)
      at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:377)
      at org.jgroups.stack.ProtocolStack.receiveUpEvent(ProtocolStack.java:393)
      at org.jgroups.stack.Protocol.passUp(Protocol.java:538)
      at org.jgroups.protocols.pbcast.STATE_TRANSFER.up(STATE_TRANSFER.java:158)
      at org.jgroups.stack.Protocol.receiveUpEvent(Protocol.java:488)
      at org.jgroups.stack.Protocol.passUp(Protocol.java:538)
      at org.jgroups.protocols.pbcast.GMS.up(GMS.java:771)
      at org.jgroups.stack.UpHandler.run(Protocol.java:60)
      Caused by: org.jboss.cache.lock.TimeoutException: read lock for /user/name-id could not be acquired by Thread[UpHandler (GMS),5,JGroups threads] after 0 ms. Locks: Read lock owners: []
      Write lock owner: null
      , lock info: (activeReaders=0, activeWriter=null, waitingReaders=0, waitingWriters=0, waitingUpgrader=0)
      at org.jboss.cache.lock.IdentityLock.acquireReadLock(IdentityLock.java:261)
      at org.jboss.cache.Node.acquireReadLock(Node.java:512)
      at org.jboss.cache.Node.acquire(Node.java:474)

        • 1. Re: Lock timeout exceptions
          brian.stansberry

          Please post the entire stack trace.

          It's not eviction, as eviction isn't handled by the JGroups UpHandler thread.

          • 2. Re: Lock timeout exceptions
            ajassal

            Brian,

            Thanks. Here you go:

            INFO 2008-06-11 18:50:34,071 UpHandler (GMS) U- org.jboss.cache.interceptors.TxInterceptor - There was a problem handling this request
            org.jboss.cache.lock.TimeoutException: failure acquiring lock: fqn=/user/id, caller=Thread[UpHandler (GMS),5,JGroups threads], lock= (activeReaders=0, activeWriter=null, waitingReaders=0, waitingWriters=0, waitingUpgrader=0)
            at org.jboss.cache.Node.acquire(Node.java:500)
            at org.jboss.cache.interceptors.PessimisticLockInterceptor.acquireNodeLock(PessimisticLockInterceptor.java:342)
            at org.jboss.cache.interceptors.PessimisticLockInterceptor.lock(PessimisticLockInterceptor.java:287)
            at org.jboss.cache.interceptors.PessimisticLockInterceptor.invoke(PessimisticLockInterceptor.java:178)
            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:364)
            at org.jboss.cache.interceptors.TxInterceptor.invoke(TxInterceptor.java:160)
            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:5710)
            at org.jboss.cache.TreeCache._replicate(TreeCache.java:5056)
            at sun.reflect.GeneratedMethodAccessor34.invoke(Unknown Source)
            at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
            at java.lang.reflect.Method.invoke(Method.java:597)
            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:650)
            at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:535)
            at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:358)
            at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:775)
            at org.jgroups.JChannel.up(JChannel.java:1091)
            at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:377)
            at org.jgroups.stack.ProtocolStack.receiveUpEvent(ProtocolStack.java:393)
            at org.jgroups.stack.Protocol.passUp(Protocol.java:538)
            at org.jgroups.protocols.pbcast.STATE_TRANSFER.up(STATE_TRANSFER.java:158)
            at org.jgroups.stack.Protocol.receiveUpEvent(Protocol.java:488)
            at org.jgroups.stack.Protocol.passUp(Protocol.java:538)
            at org.jgroups.protocols.pbcast.GMS.up(GMS.java:771)
            at org.jgroups.stack.UpHandler.run(Protocol.java:60)
            Caused by: org.jboss.cache.lock.TimeoutException: read lock for /user/id could not be acquired by Thread[UpHandler (GMS),5,JGroups threads] after 0 ms. Locks: Read lock owners: []
            Write lock owner: null
            , lock info: (activeReaders=0, activeWriter=null, waitingReaders=0, waitingWriters=0, waitingUpgrader=0)
            at org.jboss.cache.lock.IdentityLock.acquireReadLock(IdentityLock.java:261)
            at org.jboss.cache.Node.acquireReadLock(Node.java:512)
            at org.jboss.cache.Node.acquire(Node.java:474)
            ... 32 more
            WARN 2008-06-11 18:50:34,072 UpHandler (GMS) U- org.jboss.cache.TreeCache - replication failure with method_call _evict; id:8(/user/id/655382) exception: org.jboss.cache.lock.TimeoutException: failure acquiring lock: fqn=/user/id, caller=Thread[UpHandler (GMS),5,JGroups threads], lock= (activeReaders=0, activeWriter=null, waitingReaders=0, waitingWriters=0, waitingUpgrader=0)

            • 3. Re: Lock timeout exceptions
              brian.stansberry

              I see where you got the idea about eviction from. :-) I assume your cache is configured for INVALIDATION_SYNC or INVALIDATION_ASYNC. Seems in 1.x the cluster wide invalidation was implemented by telling the other nodes to do an evict. And that means the call uses the 0 ms timeout meant for regular evictions.

              Note sure what advice I can give you here, other than to try JBC 2.x (2.1.1.GA is latest stable release). JBC 2.x handles invalidation differently. Perhaps someone else on this forum knows a workaround.

              • 4. Re: Lock timeout exceptions
                ajassal

                You are right. We are using INVALIDATION_SYNC.

                I think for now I will switch over to using REPL_[A]SYNC instead and plan to upgrade to 2.x later.

                Thanks