How to fix "Unable to acquire lock after 15 seconds" errors in Wildfly

Question

I have a web application that is <distributable/>, but also deployed to stand alone instances of Wildfly for local development work. Sometimes we have calls to the backend that can stall for a few seconds, which often leads to exceptions like the one shown below.

How can I fix this given that I have no control over long running backend requests?

14:55:04,808 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (default task-6) ISPN000136: Error executing command LockControlCommand, writing keys []: org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 15 seconds for key LA6Q5r9L1q-VF2tyKE9Pc_bO9yYtzXu8dYt8l-BQ and requestor GlobalTransaction:<null>:37:local. Lock is held by GlobalTransaction:<null>:36:local
    at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.lock(DefaultLockManager.java:236)
    at org.infinispan.interceptors.locking.AbstractLockingInterceptor.lockAllAndRecord(AbstractLockingInterceptor.java:199)
    at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.checkPendingAndLockAllKeys(AbstractTxLockingInterceptor.java:199)
    at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockAllOrRegisterBackupLock(AbstractTxLockingInterceptor.java:165)
    at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitLockControlCommand(PessimisticLockingInterceptor.java:184)
    at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:110)
    at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)
    at org.infinispan.interceptors.TxInterceptor.invokeNextInterceptorAndVerifyTransaction(TxInterceptor.java:157)
    at org.infinispan.interceptors.TxInterceptor.visitLockControlCommand(TxInterceptor.java:215)
    at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:110)
    at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)
    at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:107)
    at org.infinispan.interceptors.InvocationContextInterceptor.visitLockControlCommand(InvocationContextInterceptor.java:81)
    at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:110)
    at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:336)
    at org.infinispan.cache.impl.CacheImpl.lock(CacheImpl.java:828)
    at org.infinispan.cache.impl.CacheImpl.lock(CacheImpl.java:810)
    at org.infinispan.cache.impl.AbstractDelegatingAdvancedCache.lock(AbstractDelegatingAdvancedCache.java:177)
    at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.getValue(InfinispanSessionMetaDataFactory.java:84)
    at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:69)
    at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:39)
    at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:61)
    at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:40)
    at org.wildfly.clustering.web.infinispan.session.InfinispanSessionManager.findSession(InfinispanSessionManager.java:234)
    at org.wildfly.clustering.web.undertow.session.DistributableSessionManager.getSession(DistributableSessionManager.java:140)
    at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:726)
    at io.undertow.servlet.spec.HttpServletRequestImpl.getSession(HttpServletRequestImpl.java:370)
    at au.com.agic.settings.listener.SessionInvalidatorListener.clearSession(SessionInvalidatorListener.java:57)
    at au.com.agic.settings.listener.SessionInvalidatorListener.requestInitialized(SessionInvalidatorListener.java:52)
    at io.undertow.servlet.core.ApplicationListeners.requestInitialized(ApplicationListeners.java:245)
    at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:283)
    at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:263)
    at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
    at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:174)
    at io.undertow.server.Connectors.executeRootHandler(Connectors.java:202)
    at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:793)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)

Epicycle

Answer 1

I believe the answer is to update the infinispan configuration like this, which increases the lock timeout to 60 seconds.

<cache-container name="web" default-cache="passivation"
    module="org.wildfly.clustering.web.infinispan">
    <local-cache name="passivation">
        <locking isolation="REPEATABLE_READ" striping="false" acquire-timeout="60000" />
        <transaction mode="BATCH" />
        <file-store passivation="true" purge="false" />
    </local-cache>
    <local-cache name="persistent">
        <locking isolation="REPEATABLE_READ" striping="false" acquire-timeout="60000" />
        <transaction mode="BATCH" />
        <file-store passivation="false" purge="false" />
    </local-cache>
</cache-container>

Epicycle

I found that setting locking="OPTIMISTIC" on the <transaction mode="batch" /> element helps as well. – Spandau

@Epicycle Could you help to explain why setting the timeout to 60 seconds could resolve the problem? what would happen when timeout after 60 seconds? – Combination

I would think that increasing the timeout is a short term solution that will make the problem bigger finally – Gracielagracile

this maybe also can help access.redhat.com/solutions/2776221 – Phalan

Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 60 seconds for key i369vnLfx8pZ9Oj5 and requestor CommandInvocation. It is not working for 60 seconds also :( – Bifacial

Answer 2

For a standalone I had the same error

I was using this:

<cache-container name="web" default-cache="dist" module="org.wildfly.clustering.web.infinispan">
    <transport lock-timeout="60000"/>
    <distributed-cache name="dist" mode="ASYNC" l1-lifespan="0" owners="2">  <!-- IN 7.1+ REMOVE mode="..." IF PRESENT -->
        <locking isolation="REPEATABLE_READ"/>                               <!-- REMOVE THIS LINE -->
        <transaction mode="BATCH"/>                                          <!-- REMOVE THIS LINE -->
        <file-store/>
    </distributed-cache>
</cache-container>

But changed it to:

<cache-container name="web" default-cache="passivation" module="org.wildfly.clustering.web.infinispan">
  <local-cache name="passivation">
      <file-store passivation="true" purge="false"/>
  </local-cache>
  <local-cache name="persistent">
      <file-store passivation="false" purge="false"/>
  </local-cache>
</cache-container>

And then it worked.

Icky

Answer 3

Trigert the same issue when useing server side events. In researching the issue saw that there are/were bugs with async servlets, SSE are implicitly asnyc.

Found RedHat bug with solution that solved the issue: https://access.redhat.com/solutions/2776221

its the same solution as yun_jay , just "official"

Amieva