org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 15 seconds for key z9cE_AvnxXmZAI6CvysLEGRiprt8R6gJL_9qowuf and requestor GlobalTransaction:<node-1>:21:local. Lock is held by GlobalTransaction:<node-1>:17:local

There are no available Samebug tips for this exception. Do you have an idea how to solve this issue? A short tip would help users who saw this issue last week.

  • GitHub comment 8296#149359072
    via GitHub by wildfly-ci
    ,
  • jmx monitoring for JDG 6.3.2
    via by Unknown author,
  • GitHub comment 8296#149359565
    via GitHub by wildfly-ci
    ,
  • Seen regularly in these scenarios of failover tests: ejb-ejbservlet-jvmkill-dist-sync ejb-ejbservlet-shutdown-dist-async The error is present in EAP 7.0.0.DR5, EAP 7.0.0.DR6. We did not see it in EAP 7.0.0.DR4. This error happens every time for the specified scenarios and is seen on one of the nodes in a 4-nodes cluster - usually it is the second node to fail, perf19. When the affected server is restarting after failover, it logs these error messages, ending up with *Operation ("deploy") failed*: {code} [JBossINF] [0m[0m03:49:26,594 INFO [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 64) WFLYCLINF0002: Started clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war cache from web container [JBossINF] [0m[0m03:49:26,666 INFO [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 62) WFLYCLINF0002: Started clusterbench-ee7.ear.clusterbench-ee7-web-default.war cache from web container [JBossINF] [0m[0m03:49:26,667 INFO [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 63) WFLYCLINF0002: Started dist cache from web container [JBossINF] [0m[0m03:49:27,364 INFO [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 65) WFLYCLINF0002: Started dist cache from ejb container [JBossINF] [0m[0m03:49:27,409 INFO [org.infinispan.configuration.cache.EvictionConfigurationBuilder] (ServerService Thread Pool -- 65) ISPN000152: Passivation configured without an eviction policy being selected. Only manually evicted entities will be passivated. [JBossINF] [0m[0m03:49:27,410 INFO [org.infinispan.configuration.cache.EvictionConfigurationBuilder] (ServerService Thread Pool -- 65) ISPN000152: Passivation configured without an eviction policy being selected. Only manually evicted entities will be passivated. [JBossINF] [0m[0m03:49:27,487 INFO [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 65) WFLYCLINF0002: Started clusterbench-ee7.ear/clusterbench-ee7-ejb.jar cache from ejb container [JBossINF] [0m[0m03:49:28,506 INFO [javax.enterprise.resource.webcontainer.jsf.config] (ServerService Thread Pool -- 67) Initializing Mojarra 2.2.11-jbossorg-1 20150505-1501 for context '/clusterbench' [JBossINF] [0m[0m03:49:28,506 INFO [javax.enterprise.resource.webcontainer.jsf.config] (ServerService Thread Pool -- 69) Initializing Mojarra 2.2.11-jbossorg-1 20150505-1501 for context '/clusterbench-passivating' [JBossINF] [0m[0m03:49:29,435 INFO [org.wildfly.extension.undertow] (ServerService Thread Pool -- 69) WFLYUT0021: Registered web context: /clusterbench-passivating [JBossINF] [0m[31m03:49:44,489 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (ServerService Thread Pool -- 67) ISPN000136: Execution error: org.infinispan.util.concurrent.TimeoutException: Could not acquire lock on 1tlWOZAPqztbiLjjrJHTL_6OK7fRTPBhVvyB4BLF on behalf of transaction GlobalTransaction:<perf19>:203:local. Waiting to complete tx: RemoteTransaction{modifications=[ReplaceCommand{key=1tlWOZAPqztbiLjjrJHTL_6OK7fRTPBhVvyB4BLF, oldValue=null, newValue=[B@2b5a5fb2, metadata=EmbeddedMetadata{version=null}, flags=[IGNORE_RETURN_VALUES], successful=true, valueMatcher=MATCH_ALWAYS}], lookedUpEntries={}, lockedKeys=null, backupKeyLocks=[1tlWOZAPqztbiLjjrJHTL_6OK7fRTPBhVvyB4BLF], lookedUpEntriesTopology=15, isMarkedForRollback=false, tx=GlobalTransaction:<perf21>:3605:remote, state=null}. [JBossINF] at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.newTimeoutException(AbstractTxLockingInterceptor.java:219) [JBossINF] at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.waitForTransactionsToComplete(AbstractTxLockingInterceptor.java:207) [JBossINF] at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockKeyAndCheckOwnership(AbstractTxLockingInterceptor.java:171) [JBossINF] at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitDataReadCommand(PessimisticLockingInterceptor.java:68) [JBossINF] at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitGetKeyValueCommand(AbstractLockingInterceptor.java:70) [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:111) [JBossINF] at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:86) [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97) [JBossINF] at org.infinispan.interceptors.TxInterceptor.enlistReadAndInvokeNext(TxInterceptor.java:346) [JBossINF] at org.infinispan.interceptors.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:318) [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:111) [JBossINF] at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:86) [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97) [JBossINF] at org.infinispan.statetransfer.StateTransferInterceptor.handleTopologyAffectedCommand(StateTransferInterceptor.java:364) [JBossINF] at org.infinispan.statetransfer.StateTransferInterceptor.handleDefault(StateTransferInterceptor.java:349) [JBossINF] at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:86) [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97) [JBossINF] at org.infinispan.interceptors.CacheMgmtInterceptor.visitDataReadCommand(CacheMgmtInterceptor.java:103) [JBossINF] at org.infinispan.interceptors.CacheMgmtInterceptor.visitGetKeyValueCommand(CacheMgmtInterceptor.java:91) [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97) [JBossINF] at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:102) [JBossINF] at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:71) [JBossINF] at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:86) [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40) [JBossINF] at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:336) [JBossINF] at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:430) [JBossINF] at org.infinispan.cache.impl.DecoratedCache.get(DecoratedCache.java:427) [JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:287) [JBossINF] at org.wildfly.clustering.web.infinispan.session.coarse.CoarseSessionFactory.findValue(CoarseSessionFactory.java:120) [JBossINF] at org.wildfly.clustering.web.infinispan.session.coarse.CoarseSessionFactory.findValue(CoarseSessionFactory.java:56) [JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionManager.schedule(InfinispanSessionManager.java:363) [JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionManager.start(InfinispanSessionManager.java:156) [JBossINF] at org.wildfly.clustering.web.undertow.session.DistributableSessionManager.start(DistributableSessionManager.java:69) [JBossINF] at io.undertow.servlet.core.DeploymentManagerImpl.start(DeploymentManagerImpl.java:485) [JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentService.startContext(UndertowDeploymentService.java:101) [JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentService$1.run(UndertowDeploymentService.java:82) [JBossINF] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [JBossINF] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [JBossINF] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [JBossINF] at java.lang.Thread.run(Thread.java:745) [JBossINF] at org.jboss.threads.JBossThread.run(JBossThread.java:320) [JBossINF] [JBossINF] [0m[31m03:49:44,492 ERROR [org.jboss.msc.service.fail] (ServerService Thread Pool -- 67) MSC000001: Failed to start service jboss.undertow.deployment.default-server.default-host./clusterbench: org.jboss.msc.service.StartException in service jboss.undertow.deployment.default-server.default-host./clusterbench: org.infinispan.util.concurrent.TimeoutException: Could not acquire lock on 1tlWOZAPqztbiLjjrJHTL_6OK7fRTPBhVvyB4BLF on behalf of transaction GlobalTransaction:<perf19>:203:local. Waiting to complete tx: RemoteTransaction{modifications=[ReplaceCommand{key=1tlWOZAPqztbiLjjrJHTL_6OK7fRTPBhVvyB4BLF, oldValue=null, newValue=[B@2b5a5fb2, metadata=EmbeddedMetadata{version=null}, flags=[IGNORE_RETURN_VALUES], successful=true, valueMatcher=MATCH_ALWAYS}], lookedUpEntries={}, lockedKeys=null, backupKeyLocks=[1tlWOZAPqztbiLjjrJHTL_6OK7fRTPBhVvyB4BLF], lookedUpEntriesTopology=15, isMarkedForRollback=false, tx=GlobalTransaction:<perf21>:3605:remote, state=null}. [JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentService$1.run(UndertowDeploymentService.java:85) [JBossINF] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [JBossINF] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [JBossINF] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [JBossINF] at java.lang.Thread.run(Thread.java:745) [JBossINF] at org.jboss.threads.JBossThread.run(JBossThread.java:320) [JBossINF] Caused by: org.infinispan.util.concurrent.TimeoutException: Could not acquire lock on 1tlWOZAPqztbiLjjrJHTL_6OK7fRTPBhVvyB4BLF on behalf of transaction GlobalTransaction:<perf19>:203:local. Waiting to complete tx: RemoteTransaction{modifications=[ReplaceCommand{key=1tlWOZAPqztbiLjjrJHTL_6OK7fRTPBhVvyB4BLF, oldValue=null, newValue=[B@2b5a5fb2, metadata=EmbeddedMetadata{version=null}, flags=[IGNORE_RETURN_VALUES], successful=true, valueMatcher=MATCH_ALWAYS}], lookedUpEntries={}, lockedKeys=null, backupKeyLocks=[1tlWOZAPqztbiLjjrJHTL_6OK7fRTPBhVvyB4BLF], lookedUpEntriesTopology=15, isMarkedForRollback=false, tx=GlobalTransaction:<perf21>:3605:remote, state=null}. [JBossINF] at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.newTimeoutException(AbstractTxLockingInterceptor.java:219) [JBossINF] at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.waitForTransactionsToComplete(AbstractTxLockingInterceptor.java:207) [JBossINF] at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockKeyAndCheckOwnership(AbstractTxLockingInterceptor.java:171) [JBossINF] at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitDataReadCommand(PessimisticLockingInterceptor.java:68) [JBossINF] at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitGetKeyValueCommand(AbstractLockingInterceptor.java:70) [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:111) [JBossINF] at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:86) [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97) [JBossINF] at org.infinispan.interceptors.TxInterceptor.enlistReadAndInvokeNext(TxInterceptor.java:346) [JBossINF] at org.infinispan.interceptors.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:318) [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:111) [JBossINF] at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:86) [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97) [JBossINF] at org.infinispan.statetransfer.StateTransferInterceptor.handleTopologyAffectedCommand(StateTransferInterceptor.java:364) [JBossINF] at org.infinispan.statetransfer.StateTransferInterceptor.handleDefault(StateTransferInterceptor.java:349) [JBossINF] at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:86) [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97) [JBossINF] at org.infinispan.interceptors.CacheMgmtInterceptor.visitDataReadCommand(CacheMgmtInterceptor.java:103) [JBossINF] at org.infinispan.interceptors.CacheMgmtInterceptor.visitGetKeyValueCommand(CacheMgmtInterceptor.java:91) [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40) [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97) [JBossINF] at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:102) [JBossINF] at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:71) [JBossINF] at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:86) [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40) [JBossINF] at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:336) [JBossINF] at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:430) [JBossINF] at org.infinispan.cache.impl.DecoratedCache.get(DecoratedCache.java:427) [JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:287) [JBossINF] at org.wildfly.clustering.web.infinispan.session.coarse.CoarseSessionFactory.findValue(CoarseSessionFactory.java:120) [JBossINF] at org.wildfly.clustering.web.infinispan.session.coarse.CoarseSessionFactory.findValue(CoarseSessionFactory.java:56) [JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionManager.schedule(InfinispanSessionManager.java:363) [JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionManager.start(InfinispanSessionManager.java:156) [JBossINF] at org.wildfly.clustering.web.undertow.session.DistributableSessionManager.start(DistributableSessionManager.java:69) [JBossINF] at io.undertow.servlet.core.DeploymentManagerImpl.start(DeploymentManagerImpl.java:485) [JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentService.startContext(UndertowDeploymentService.java:101) [JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentService$1.run(UndertowDeploymentService.java:82) [JBossINF] ... 6 more [JBossINF] [JBossINF] [0m[31m03:49:44,503 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0013: Operation ("deploy") failed - address: ([("deployment" => "clusterbench-ee7.ear")]) - failure description: {"WFLYCTL0080: Failed services" => {"jboss.undertow.deployment.default-server.default-host./clusterbench" => "org.jboss.msc.service.StartException in service jboss.undertow.deployment.default-server.default-host./clusterbench: org.infinispan.util.concurrent.TimeoutException: Could not acquire lock on 1tlWOZAPqztbiLjjrJHTL_6OK7fRTPBhVvyB4BLF on behalf of transaction GlobalTransaction:<perf19>:203:local. Waiting to complete tx: RemoteTransaction{modifications=[ReplaceCommand{key=1tlWOZAPqztbiLjjrJHTL_6OK7fRTPBhVvyB4BLF, oldValue=null, newValue=[B@2b5a5fb2, metadata=EmbeddedMetadata{version=null}, flags=[IGNORE_RETURN_VALUES], successful=true, valueMatcher=MATCH_ALWAYS}], lookedUpEntries={}, lockedKeys=null, backupKeyLocks=[1tlWOZAPqztbiLjjrJHTL_6OK7fRTPBhVvyB4BLF], lookedUpEntriesTopology=15, isMarkedForRollback=false, tx=GlobalTransaction:<perf21>:3605:remote, state=null}. [JBossINF] Caused by: org.infinispan.util.concurrent.TimeoutException: Could not acquire lock on 1tlWOZAPqztbiLjjrJHTL_6OK7fRTPBhVvyB4BLF on behalf of transaction GlobalTransaction:<perf19>:203:local. Waiting to complete tx: RemoteTransaction{modifications=[ReplaceCommand{key=1tlWOZAPqztbiLjjrJHTL_6OK7fRTPBhVvyB4BLF, oldValue=null, newValue=[B@2b5a5fb2, metadata=EmbeddedMetadata{version=null}, flags=[IGNORE_RETURN_VALUES], successful=true, valueMatcher=MATCH_ALWAYS}], lookedUpEntries={}, lockedKeys=null, backupKeyLocks=[1tlWOZAPqztbiLjjrJHTL_6OK7fRTPBhVvyB4BLF], lookedUpEntriesTopology=15, isMarkedForRollback=false, tx=GlobalTransaction:<perf21>:3605:remote, state=null}."}} {code} Server log (failover-ejb-ejbservlet-jvmkill-dist-sync): http://jenkins.mw.lab.eng.bos.redhat.com/hudson/job/mvinkler_eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync/1/console-perf19/ Server log (failover-ejb-ejbservlet-shutdown-dist-async): http://jenkins.mw.lab.eng.bos.redhat.com/hudson/job/mvinkler_eap-7x-failover-ejb-ejbservlet-shutdown-dist-async/1/console-perf20/
    via by Michal Vinkler,
  • GitHub comment 8761#196427507
    via GitHub by wildfly-ci
    ,
  • GitHub comment 8761#196428895
    via GitHub by wildfly-ci
    ,
    • org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 15 seconds for key z9cE_AvnxXmZAI6CvysLEGRiprt8R6gJL_9qowuf and requestor GlobalTransaction:<node-1>:21:local. Lock is held by GlobalTransaction:<node-1>:17:local at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.lock(DefaultLockManager.java:236)
    No Bugmate found.