Uploaded image for project: 'WildFly'
  1. WildFly
  2. WFLY-6224

IllegalStateException "not in a valid state to be invoking cache operations on" in two cluster test

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Done
    • Icon: Major Major
    • 14.0.0.Beta2
    • 10.0.0.Final, 11.0.0.CR1, 13.0.0.Final
    • Clustering, EJB
    • None

      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:

      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)
      

      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-2clusters-ejbremote-shutdown-repl-async/21/console-perf19/). 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.

              pferraro@redhat.com Paul Ferraro
              lthon@redhat.com Ladislav Thon
              Votes:
              0 Vote for this issue
              Watchers:
              10 Start watching this issue

                Created:
                Updated:
                Resolved: