Question about domain cache timeout when trying to get the session from an HTTP request.

[Eric Hodges]

I'm running an EAR that works fine in standalone mode, but runs into this timeout when run on a domain.

When my code calls "io.undertow.servlet.spec.HttpServletRequestImpl.getSession(HttpServletRequestImpl.java:426)", the server handling that request throws this exception:

2021-06-17 10:35:24,700 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (non-blocking-thread--p7-t1) ISPN000136: Error executing command GetKeyValueCommand on Cache 'ClearingworksEAR_4.3.1.ear.Clearingworks.war', writing keys []: org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 15 seconds for key SessionCreationMetaDataKey(rUwy9fqCOP6wshNfF5B0IrQgvvdsikIZzT6sZvCR) and requestor GlobalTransaction{id=99, addr=master:server-three, remote=false, xid=null, internalId=-1}. Lock is held by GlobalTransaction{id=98, addr=master:server-three, remote=false, xid=null, internalId=-1}

at org.inf...@11.0.8.Final//org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.get(DefaultLockManager.java:292)

at org.inf...@11.0.8.Final//org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.get(DefaultLockManager.java:222)

at org.inf...@11.0.8.Final//org.infinispan.util.concurrent.locks.impl.InfinispanLock$LockPlaceHolder.checkState(InfinispanLock.java:440)

at org.inf...@11.0.8.Final//org.infinispan.util.concurrent.locks.impl.InfinispanLock$LockPlaceHolder.lambda$toInvocationStage$3(InfinispanLock.java:416)

at java.base/java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:642)

at java.base/java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:478)

at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)

at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630)

at org.jboss.as.cl...@22.0.0.Final//org.jboss.as.clustering.context.ContextReferenceExecutor.execute(ContextReferenceExecutor.java:49)

at org.jboss.as.cl...@22.0.0.Final//org.jboss.as.clustering.context.ContextualExecutor$1.run(ContextualExecutor.java:70)

at java.base/java.lang.Thread.run(Thread.java:832)

I can't figure out why it is timing out. Right now, I only have one server running my EAR.

I've tried editing the full-ha profile in domain.xml to set all of the cache-containers to use '<locking isolation="OPTIMISTIC"/>', but that didn't change anything.

The rest of my configuration is very close to the default for WildFly 22.

How do other people get the session from an HTTP request in domain mode without timing out trying to grab SessionCreationMetaDataKey?

[Paul Ferraro]

Are you able to reproduce the issue on WF24?

[Eric Hodges]

Yes. In domain mode, with EAR deployed to one server (server-three):

2021-06-21 17:11:31,245 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (non-blocking-thread--p6-t17) ISPN000136: Error executing command GetKeyValueCommand on Cache 'ClearingworksEAR_4.3.1.ear.Clearingworks.war', writing keys []: org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 15 seconds for key SessionCreationMetaDataKey(DKu0y-SkXAQ0RRkXfWfSNNulSCH-RR5Q7PeAKybt) and requestor GlobalTransaction{id=116, addr=master:server-three, remote=false, xid=null, internalId=-1}. Lock is held by GlobalTransaction{id=115, addr=master:server-three, remote=false, xid=null, internalId=-1}

at org.inf...@12.1.4.Final//org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.get(DefaultLockManager.java:291)

at org.inf...@12.1.4.Final//org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.get(DefaultLockManager.java:221)

at org.inf...@12.1.4.Final//org.infinispan.util.concurrent.locks.impl.InfinispanLock$LockPlaceHolder.checkState(InfinispanLock.java:439)

at org.inf...@12.1.4.Final//org.infinispan.util.concurrent.locks.impl.InfinispanLock$LockPlaceHolder.lambda$toInvocationStage$3(InfinispanLock.java:415)

at java.base/java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:642)

at java.base/java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:478)

at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)

at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630)

at org.jboss.as.cl...@24.0.0.Final//org.jboss.as.clustering.context.ContextReferenceExecutor.execute(ContextReferenceExecutor.java:49)

at org.jboss.as.cl...@24.0.0.Final//org.jboss.as.clustering.context.ContextualExecutor$1.run(ContextualExecutor.java:70)

at java.base/java.lang.Thread.run(Thread.java:832)

You can see that server-three is unable to acquire the lock held by server-three.

[Paul Ferraro]

Your server log should contain another stack trace from the thread
processing the request, which should provide more context. Can you
paste that?

It might be the case that your session access is to concurrent to
tolerate a transactional cache. In that case, just disable
transactions altogether.
See: https://github.com/wildfly/wildfly/blob/master/docs/src/main/asciidoc/_high-availability/subsystem-support/Distributable_Web_Applications.adoc#session_concurrency

> --
> You received this message because you are subscribed to a topic in the Google Groups "WildFly" group.
> To unsubscribe from this topic, visit https://groups.google.com/d/topic/wildfly/_SIpFghyqek/unsubscribe.
> To unsubscribe from this group and all its topics, send an email to wildfly+u...@googlegroups.com.
> To view this discussion on the web visit https://groups.google.com/d/msgid/wildfly/e2c05914-c3ca-483b-a711-5ae7fe45c623n%40googlegroups.com.

[Eric Hodges]

Thanks for the link, it was very helpful. Disabling transactions makes the lock timeout go away.

Our code has a javax.servlet.ServletRequestListener that we use for monitoring. It keeps track of all of the requests on a session, and never writes to the session. That's the code that tries to get the session from the HTTP request and causes the timeout.

Changing the isolation to READ_COMMITTED also makes the session timeout go away, at least in my simple tests.

--

Eric Hodges

Sr. Product Engineer

eho...@usdataworks.com
O: 281-504-8165

U.S. Dataworks

[Paul Ferraro]

Hmmm. Would you be able to paste the logic within your
ServletRequestListener? Even on a REPEATABLE_READ transactional
cache, I would not expect this to trigger a lock timeout.

[Eric Hodges]

I suspect the problem is due to the way the request is created.

A client makes a call to one of our EJBs. That EJB then issues web requests to all of our servers, including the one that is handling the EJB call. The original EJB call and the new HTTP request are both in the same session.

Thank you very much for your help.