Red Hat Bugzilla – Bug 947420
Unable to acquire lock after [0 milliseconds] with session passivation on
Last modified: 2014-05-26 21:29:46 EDT
During soak test (cache: REPL_ASYNC) this TimeoutException were sometimes logged: [JBossINF] ^[[0m^[[31m09:30:02,227 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) ISPN000136: Execution error: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [0 milliseconds] on key [XiC7zdePhT9GUivFKtXL6+SO] for requestor [Thread[ContainerBackgroundProcessor[StandardEngine[jboss.web]],5,main]]! Lock held by [XY] [JBossINF] at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:213) [JBossINF] at org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLockNoCheck(LockManagerImpl.java:196) [JBossINF] at org.infinispan.interceptors.locking.AbstractLockingInterceptor.lockKey(AbstractLockingInterceptor.java:114) [JBossINF] at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.visitEvictCommand(AbstractTxLockingInterceptor.java:79) [JBossINF] at org.infinispan.commands.write.EvictCommand.acceptVisitor(EvictCommand.java:49) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132) [JBossINF] at org.infinispan.commands.AbstractVisitor.visitEvictCommand(AbstractVisitor.java:87) [JBossINF] at org.infinispan.commands.write.EvictCommand.acceptVisitor(EvictCommand.java:49) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132) [JBossINF] at org.infinispan.commands.AbstractVisitor.visitEvictCommand(AbstractVisitor.java:87) [JBossINF] at org.infinispan.commands.write.EvictCommand.acceptVisitor(EvictCommand.java:49) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132) [JBossINF] at org.infinispan.commands.AbstractVisitor.visitEvictCommand(AbstractVisitor.java:87) [JBossINF] at org.infinispan.commands.write.EvictCommand.acceptVisitor(EvictCommand.java:49) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [JBossINF] at org.infinispan.statetransfer.StateTransferInterceptor.visitEvictCommand(StateTransferInterceptor.java:179) [JBossINF] at org.infinispan.commands.write.EvictCommand.acceptVisitor(EvictCommand.java:49) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [JBossINF] at org.infinispan.interceptors.CacheMgmtInterceptor.visitEvictCommand(CacheMgmtInterceptor.java:84) [JBossINF] at org.infinispan.commands.write.EvictCommand.acceptVisitor(EvictCommand.java:49) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [JBossINF] at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128) [JBossINF] at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:92) [JBossINF] at org.infinispan.commands.AbstractVisitor.visitEvictCommand(AbstractVisitor.java:87) [JBossINF] at org.infinispan.commands.write.EvictCommand.acceptVisitor(EvictCommand.java:49) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [JBossINF] at org.infinispan.interceptors.BatchingInterceptor.visitEvictCommand(BatchingInterceptor.java:66) [JBossINF] at org.infinispan.commands.write.EvictCommand.acceptVisitor(EvictCommand.java:49) [JBossINF] at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343) [JBossINF] at org.infinispan.CacheImpl.evict(CacheImpl.java:430) [JBossINF] at org.infinispan.CacheImpl.evict(CacheImpl.java:423) [JBossINF] at org.infinispan.AbstractDelegatingCache.evict(AbstractDelegatingCache.java:60) [JBossINF] at org.infinispan.AbstractDelegatingCache.evict(AbstractDelegatingCache.java:60) [JBossINF] at org.jboss.as.clustering.web.infinispan.DistributedCacheManager$4.invoke(DistributedCacheManager.java:307) [JBossINF] at org.jboss.as.clustering.web.infinispan.DistributedCacheManager$4.invoke(DistributedCacheManager.java:304) [JBossINF] at org.jboss.as.clustering.infinispan.invoker.SimpleCacheInvoker.invoke(SimpleCacheInvoker.java:34) [JBossINF] at org.jboss.as.clustering.infinispan.invoker.BatchCacheInvoker.invoke(BatchCacheInvoker.java:48) [JBossINF] at org.jboss.as.clustering.infinispan.invoker.RetryingCacheInvoker.invoke(RetryingCacheInvoker.java:81) [JBossINF] at org.jboss.as.clustering.web.infinispan.DistributedCacheManager$ForceSynchronousCacheInvoker.invoke(DistributedCacheManager.java:542) [JBossINF] at org.jboss.as.clustering.web.infinispan.DistributedCacheManager.evictSession(DistributedCacheManager.java:311) [JBossINF] at org.jboss.as.web.session.DistributableSessionManager.processSessionPassivation(DistributableSessionManager.java:519) [jboss-as-web-7.2.0.Final-redhat-3.jar:7.2.0.Final-redhat-3] [JBossINF] at org.jboss.as.web.session.DistributableSessionManager.access$600(DistributableSessionManager.java:84) [jboss-as-web-7.2.0.Final-redhat-3.jar:7.2.0.Final-redhat-3] [JBossINF] at org.jboss.as.web.session.DistributableSessionManager$PassivationCheck.passivate(DistributableSessionManager.java:1569) [jboss-as-web-7.2.0.Final-redhat-3.jar:7.2.0.Final-redhat-3] [JBossINF] at org.jboss.as.web.session.DistributableSessionManager$PassivationCheck.access$300(DistributableSessionManager.java:1541) [jboss-as-web-7.2.0.Final-redhat-3.jar:7.2.0.Final-redhat-3] [JBossINF] at org.jboss.as.web.session.DistributableSessionManager.processExpirationPassivation(DistributableSessionManager.java:1305) [jboss-as-web-7.2.0.Final-redhat-3.jar:7.2.0.Final-redhat-3] [JBossINF] at org.jboss.as.web.session.AbstractSessionManager.processExpires(AbstractSessionManager.java:137) [jboss-as-web-7.2.0.Final-redhat-3.jar:7.2.0.Final-redhat-3] [JBossINF] at org.apache.catalina.session.ManagerBase.backgroundProcess(ManagerBase.java:367) [jbossweb-7.2.0.Final-redhat-1.jar:7.2.0.Final-redhat-1] [JBossINF] at org.apache.catalina.core.ContainerBase.backgroundProcess(ContainerBase.java:1302) [jbossweb-7.2.0.Final-redhat-1.jar:7.2.0.Final-redhat-1] [JBossINF] at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1588) [jbossweb-7.2.0.Final-redhat-1.jar:7.2.0.Final-redhat-1] [JBossINF] at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1600) [jbossweb-7.2.0.Final-redhat-1.jar:7.2.0.Final-redhat-1] [JBossINF] at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1600) [jbossweb-7.2.0.Final-redhat-1.jar:7.2.0.Final-redhat-1] [JBossINF] at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1574) [jbossweb-7.2.0.Final-redhat-1.jar:7.2.0.Final-redhat-1] [JBossINF] at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_43] [JBossINF] where XY was one either [null] or [GlobalTransaction:<perf19/web>:4995270:remote] No failover occured during this test and only a few of these TO were seen during 24hrs run.
Seen again during the same test in EAP 6.1.0.ER4 testing cycle.
Link to job: https://jenkins.mw.lab.eng.bos.redhat.com/hudson/view/EAP6/view/EAP6-Clustering/view/EAP6-Clustering-Soak/job/eap-6x-clustering-soak-http-repl-async-web/24/ Link to the server.log: https://jenkins.mw.lab.eng.bos.redhat.com/hudson/view/EAP6/view/EAP6-Clustering/view/EAP6-Clustering-Soak/job/eap-6x-clustering-soak-http-repl-async-web/24/console-perf18/
Occured in ER5 runs as well. Link to job: https://jenkins.mw.lab.eng.bos.redhat.com/hudson/job/eap-6x-clustering-soak-http-repl-async-web/25/
I suppose that this issue have been fixed with the Infinispan upgrade. Moving onto QA.
Verified during 6.1.0.ER8 testing (where we have the upgraded Infinispan 5.2.6.Final).
Details inside vpn: https://post-office.corp.redhat.com/mailman/private/eap-pm-list/2013-July/msg00105.html