IllegalStateException "not in a valid state to be invoking cache operations on" in two cluster test --------------------------------------------------------------------------------------------------- Key: WFLY-6224 URL: https://issues.jboss.org/browse/WFLY-6224 Project: WildFly Issue Type: Bug Components: Clustering, EJB Affects Versions: 10.0.0.Final, 11.0.0.CR1, 13.0.0.Final Reporter: Ladislav Thon Assignee: Paul Ferraro During a 2clusters test eap-7x-failover-ejb-2clusters-ejbremote-shutdown-repl-async (where 2clusters test = standalone EJB client -> 2-node "forwarder" cluster -> 2-node "target" cluster -> back to "forwarder" -> back to standalone client), I'm seeing {{IllegalStateException: Transaction is not in a valid state to be invoking cache operations on}}: {code} 05:12:09,813 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (default task-40) ISPN000136: Error executing command GetKeyValueCommand, writing keys []: java.lang.IllegalStateException: Transaction DummyTransaction{xid=DummyXid{id=352}, status=3} is not in a valid state to be invoking cache operations on. at org.infinispan.interceptors.TxInterceptor.enlist(TxInterceptor.java:394) at org.infinispan.interceptors.TxInterceptor.enlistIfNeeded(TxInterceptor.java:350) at org.infinispan.interceptors.TxInterceptor.enlistReadAndInvokeNext(TxInterceptor.java:344) at org.infinispan.interceptors.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:330) at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99) at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:113) at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:85) at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99) at org.infinispan.statetransfer.StateTransferInterceptor.visitReadCommand(StateTransferInterceptor.java:176) at org.infinispan.statetransfer.StateTransferInterceptor.visitGetKeyValueCommand(StateTransferInterceptor.java:153) at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99) at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:107) at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:76) at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:85) at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40) at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:336) at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:411) at org.infinispan.cache.impl.DecoratedCache.get(DecoratedCache.java:443) at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:286) at org.wildfly.clustering.ejb.infinispan.bean.InfinispanBeanFactory.findValue(InfinispanBeanFactory.java:85) at org.wildfly.clustering.ejb.infinispan.bean.InfinispanBeanFactory.findValue(InfinispanBeanFactory.java:49) at org.wildfly.clustering.ejb.infinispan.InfinispanBeanManager.findBean(InfinispanBeanManager.java:238) at org.jboss.as.ejb3.cache.distributable.DistributableCache.release(DistributableCache.java:137) at org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor.releaseInstance(StatefulSessionSynchronizationInterceptor.java:168) at org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization.afterCompletion(StatefulSessionSynchronizationInterceptor.java:250) at org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList.afterCompletion(JCAOrderedLastSynchronizationList.java:147) at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.afterCompletion(SynchronizationImple.java:96) at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.afterCompletion(TwoPhaseCoordinator.java:545) at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.afterCompletion(TwoPhaseCoordinator.java:476) at com.arjuna.ats.internal.jta.transaction.arjunacore.subordinate.SubordinateAtomicAction.doOnePhaseCommit(SubordinateAtomicAction.java:247) at com.arjuna.ats.internal.jta.transaction.arjunacore.subordinate.TransactionImple.doOnePhaseCommit(TransactionImple.java:283) at org.jboss.as.ejb3.remote.protocol.versionone.XidTransactionCommitTask.manageTransaction(XidTransactionCommitTask.java:85) at org.jboss.as.ejb3.remote.protocol.versionone.XidTransactionManagementTask.run(XidTransactionManagementTask.java:68) at org.jboss.as.ejb3.remote.protocol.versionone.TransactionRequestHandler.processMessage(TransactionRequestHandler.java:139) at org.jboss.as.ejb3.remote.protocol.versionone.VersionOneProtocolChannelReceiver.processMessage(VersionOneProtocolChannelReceiver.java:213) at org.jboss.as.ejb3.remote.protocol.versiontwo.VersionTwoProtocolChannelReceiver.processMessage(VersionTwoProtocolChannelReceiver.java:76) at org.jboss.as.ejb3.remote.protocol.versionone.VersionOneProtocolChannelReceiver.handleMessage(VersionOneProtocolChannelReceiver.java:159) at org.jboss.remoting3.remote.RemoteConnectionChannel$5.run(RemoteConnectionChannel.java:456) at org.jboss.remoting3.EndpointImpl$TrackingExecutor$1.run(EndpointImpl.java:717) 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) {code} The difference from WFLY-4678 is the circumstances. In the following text, I'm refering to the nodes by their real names: {{perf17}} is the standalone EJB client, the "forwarder" cluster is {{perf20}} and {{perf21}}, and the "target" cluster is {{perf18}} and {{perf19}}. The stack trace above is the first occurence of the exception, it appears on perf19 (https://jenkins.mw.lab.eng.bos.redhat.com/hudson/job/eap-7x-failover-ejb-...). At that time, perf18 is just shutting down gracefully, but the perf19 log clearly shows that both Infinispan and JGroups have already figured out that perf18 went away. Still, the absence of graceful shutdown for transactions might be an explanation... except that there's no reason why the cache on perf19 would be in an invalid state if it's perf18 who is going down. So maybe perf19 had to reach out to perf18 for some reason and the exception actually comes from perf18... but the cache is REPL, so perf19 should have all data locally already and it shouldn't really have to reach out to perf18. So, not really sure why it happens.