Details
-
Bug
-
Resolution: Done
-
Critical
-
7.1.0.ER1
-
None
Description
We have a test with following scenario:
Client makes a call to a bean on server-1
bean (server-1) sends a JMS message to a local queue on server-1
bean (server-1) calls to a bean on server-2
bean (server-2) sends a JMS message to a local queue on server-2
bean (server-2) goes to sleep for 3 minutes (waiting for a quite long time but not enough to hit the time of transaction timeout)
Expected behavior: commit (both messages should be in queues)
But actual behavior is strange for both JTA and JTS.
For JTA it seems that transaction is not propagated from server-1 to server-2.
Log from server-1:
2017-06-20 16:49:13,285 DEBUG [org.jboss.as.test.jbossts.crashrec.txpropagation.jms.JMSClientBean] (default task-22) TX timeout = 2147483647 2017-06-20 16:49:13,286 DEBUG [org.jboss.as.test.jbossts.crashrec.txpropagation.jms.JMSClientBean] (default task-22) Local transaction (delegate=TransactionImple < ac, BasicAction: 0:ffff7f000001:791725c7:594935b3:1f status: ActionStatus.RUNNING >, owner=Local transaction context for provider JBoss JTA transaction provider) 2017-06-20 16:49:13,399 WARN [org.apache.activemq.artemis.core.server] (Thread-1 (ActiveMQ-scheduled-threads)) AMQ222103: transaction with xid XidImpl (2011407065 bq:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.121.23.37.-57.89.73.53.-77.0.0.0.41.0.0.0.1.0.0.0.0 formatID:131077 gtxid:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.121.23.37.-57.89.73.53.-77.0.0.0.31.49 base64:AAAAAAAAAAAAAP__fwAAAXkXJcdZSTWzAAAAKQAAAAEAAAAAAAAAAAAAAAAAAP__fwAAAXkXJcdZSTWzAAAAHzEHAgIA timed out 2017-06-20 16:49:14,671 WARN [com.arjuna.ats.jta] (default task-22) ARJUNA016056: TransactionImple.delistResource - caught exception during delist : XAException.XAER_PROTO: javax.transaction.xa.XAException at org.apache.activemq.artemis.core.protocol.core.impl.ActiveMQSessionContext.xaEnd(ActiveMQSessionContext.java:386) at org.apache.activemq.artemis.core.client.impl.ClientSessionImpl.end(ClientSessionImpl.java:1173) at org.apache.activemq.artemis.ra.ActiveMQRAXAResource.end(ActiveMQRAXAResource.java:112) at org.apache.activemq.artemis.service.extensions.xa.ActiveMQXAResourceWrapperImpl.end(ActiveMQXAResourceWrapperImpl.java:81) at org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.end(XAResourceWrapperImpl.java:118) at org.jboss.jca.core.tx.jbossts.XAResourceWrapperStatImpl.end(XAResourceWrapperStatImpl.java:96) at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.delistResource(TransactionImple.java:897) at org.wildfly.transaction.client.LocalTransaction.delistResource(LocalTransaction.java:162) at org.jboss.jca.core.connectionmanager.listener.TxConnectionListener$TransactionSynchronization.beforeCompletion(TxConnectionListener.java:1063) at org.jboss.jca.core.connectionmanager.transaction.TransactionSynchronizer.invokeBefore(TransactionSynchronizer.java:438) at org.jboss.jca.core.connectionmanager.transaction.TransactionSynchronizer.beforeCompletion(TransactionSynchronizer.java:376) at org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList.beforeCompletion(JCAOrderedLastSynchronizationList.java:130) at org.wildfly.transaction.client.AbstractTransaction.performConsumer(AbstractTransaction.java:206) at org.wildfly.transaction.client.AbstractTransaction.performConsumer(AbstractTransaction.java:217) at org.wildfly.transaction.client.AbstractTransaction$AssociatingSynchronization.beforeCompletion(AbstractTransaction.java:262) at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:76) at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:368) at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:91) at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162) at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1289) at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126) at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:89) at org.wildfly.transaction.client.LocalTransaction.commitAndDissociate(LocalTransaction.java:73) at org.wildfly.transaction.client.ContextTransactionManager.commit(ContextTransactionManager.java:71) at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:92) at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:279) at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:332) at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:240) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:327) at org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:73) at org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:89) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.as.ejb3.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:89) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:47) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.as.ejb3.deployment.processors.EjbSuspendInterceptor.processInvocation(EjbSuspendInterceptor.java:57) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.as.ejb3.component.interceptors.EjbExceptionTransformingInterceptorFactories$1.processInvocation(EjbExceptionTransformingInterceptorFactories.java:80) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:256) at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:609) at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53) at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:198) at org.wildfly.security.auth.server.SecurityIdentity.runAsFunctionEx(SecurityIdentity.java:380) at org.jboss.as.ejb3.remote.AssociationImpl.invokeWithIdentity(AssociationImpl.java:479) at org.jboss.as.ejb3.remote.AssociationImpl.invokeMethod(AssociationImpl.java:474) at org.jboss.as.ejb3.remote.AssociationImpl.lambda$receiveInvocationRequest$0(AssociationImpl.java:182) 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)
Log from server-2:
2017-06-20 16:49:14,031 DEBUG [org.jboss.as.test.jbossts.crashrec.txpropagation.jms.JMSClientBean] (default task-26) TX timeout = -1 2017-06-20 16:49:14,031 DEBUG [org.jboss.as.test.jbossts.crashrec.txpropagation.jms.JMSClientBean] (default task-26) Local transaction (delegate=TransactionImple < jca-subordinate, BasicAction: 0:ffff7f000001:-5a256f6b:594935bf:1f status: ActionStatus.RUNNING >, owner=Local transaction context for provider JBoss JTA transaction provider) 2017-06-20 16:49:14,208 INFO [org.jboss.as.test.jbossts.common.TestXAResourceCommon] (default task-26) TestXAResourceCommon.setTransactionTimeout(seconds=1)[id=646]
For JTS it seems that transaction is propagated from server-1 to server-2 but tx also ends up with timeout (rollback)
Log from server-1:
2017-06-20 16:55:32,368 DEBUG [org.jboss.as.test.jbossts.crashrec.txpropagation.jms.JMSClientBean] (p: default-threadpool; w: Idle) TX timeout = 2147483647 2017-06-20 16:55:32,368 DEBUG [org.jboss.as.test.jbossts.crashrec.txpropagation.jms.JMSClientBean] (p: default-threadpool; w: Idle) Local transaction (delegate=TransactionImple < jts, 0:ffff7f000001:-6ed9e073:5949372b:37 >, owner=Local transaction context for provider JBoss JTS transaction provider) 2017-06-20 16:55:33,397 WARN [com.arjuna.ats.jtax] (p: default-threadpool; w: Idle) ARJUNA024056: TransactionImple.delistResource caught XA exception: XAException.XAER_PROTO: javax.transaction.xa.XAException at org.apache.activemq.artemis.core.protocol.core.impl.ActiveMQSessionContext.xaEnd(ActiveMQSessionContext.java:386) at org.apache.activemq.artemis.core.client.impl.ClientSessionImpl.end(ClientSessionImpl.java:1173) at org.apache.activemq.artemis.ra.ActiveMQRAXAResource.end(ActiveMQRAXAResource.java:112) at org.apache.activemq.artemis.service.extensions.xa.ActiveMQXAResourceWrapperImpl.end(ActiveMQXAResourceWrapperImpl.java:81) at org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.end(XAResourceWrapperImpl.java:118) at org.jboss.jca.core.tx.jbossts.XAResourceWrapperStatImpl.end(XAResourceWrapperStatImpl.java:96) at com.arjuna.ats.internal.jta.transaction.jts.TransactionImple.delistResource(TransactionImple.java:981) at org.wildfly.transaction.client.LocalTransaction.delistResource(LocalTransaction.java:162) at org.jboss.jca.core.connectionmanager.listener.TxConnectionListener$TransactionSynchronization.beforeCompletion(TxConnectionListener.java:1063) at org.jboss.jca.core.connectionmanager.transaction.TransactionSynchronizer.invokeBefore(TransactionSynchronizer.java:438) at org.jboss.jca.core.connectionmanager.transaction.TransactionSynchronizer.beforeCompletion(TransactionSynchronizer.java:376) at org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList.beforeCompletion(JCAOrderedLastSynchronizationList.java:130) at org.wildfly.transaction.client.AbstractTransaction.performConsumer(AbstractTransaction.java:206) at org.wildfly.transaction.client.AbstractTransaction.performConsumer(AbstractTransaction.java:217) at org.wildfly.transaction.client.AbstractTransaction$AssociatingSynchronization.beforeCompletion(AbstractTransaction.java:262) at com.arjuna.ats.internal.jta.resources.jts.orbspecific.SynchronizationImple.before_completion(SynchronizationImple.java:89) at com.arjuna.ArjunaOTS.JTAInterposedSynchronizationPOATie.before_completion(JTAInterposedSynchronizationPOATie.java:41) at com.arjuna.ArjunaOTS.JTAInterposedSynchronizationPOA._invoke(JTAInterposedSynchronizationPOA.java:39) at com.sun.corba.se.impl.protocol.CorbaServerRequestDispatcherImpl.dispatchToServant(CorbaServerRequestDispatcherImpl.java:654) at com.sun.corba.se.impl.protocol.CorbaServerRequestDispatcherImpl.dispatch(CorbaServerRequestDispatcherImpl.java:205) at com.sun.corba.se.impl.protocol.CorbaMessageMediatorImpl.handleRequestRequest(CorbaMessageMediatorImpl.java:1700) at com.sun.corba.se.impl.protocol.SharedCDRClientRequestDispatcherImpl.marshalingComplete(SharedCDRClientRequestDispatcherImpl.java:180) at com.sun.corba.se.impl.protocol.CorbaClientDelegateImpl.invoke(CorbaClientDelegateImpl.java:148) at org.omg.CORBA.portable.ObjectImpl._invoke(ObjectImpl.java:475) at org.omg.CosTransactions._SynchronizationStub.before_completion(_SynchronizationStub.java:19) at com.arjuna.ats.internal.jts.orbspecific.coordinator.ArjunaTransactionImple.doBeforeCompletion(ArjunaTransactionImple.java:1495) at com.arjuna.ats.internal.jts.orbspecific.coordinator.ArjunaTransactionImple.commit(ArjunaTransactionImple.java:354) at com.arjuna.ats.internal.jts.ControlWrapper.commit(ControlWrapper.java:244) at com.arjuna.ats.internal.jts.orbspecific.CurrentImple.commit(CurrentImple.java:247) at com.arjuna.ats.jts.extensions.AtomicTransaction.commit(AtomicTransaction.java:276) at com.arjuna.ats.internal.jta.transaction.jts.TransactionImple.commitAndDisassociate(TransactionImple.java:1397) at com.arjuna.ats.internal.jta.transaction.jts.BaseTransaction.commit(BaseTransaction.java:130) at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:89) at org.wildfly.transaction.client.LocalTransaction.commitAndDissociate(LocalTransaction.java:73) at org.wildfly.transaction.client.ContextTransactionManager.commit(ContextTransactionManager.java:71) at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:92) at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:279) at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:332) at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:240) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:327) at org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:73) at org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:89) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.as.ejb3.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:89) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:47) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.as.ejb3.deployment.processors.EjbSuspendInterceptor.processInvocation(EjbSuspendInterceptor.java:57) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.as.ejb3.component.interceptors.EjbExceptionTransformingInterceptorFactories$1.processInvocation(EjbExceptionTransformingInterceptorFactories.java:80) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:256) at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:609) at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:240) at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53) at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:198) at org.jboss.as.ejb3.iiop.EjbCorbaServant._invoke(EjbCorbaServant.java:371) at com.sun.corba.se.impl.protocol.CorbaServerRequestDispatcherImpl.dispatchToServant(CorbaServerRequestDispatcherImpl.java:654) at com.sun.corba.se.impl.protocol.CorbaServerRequestDispatcherImpl.dispatch(CorbaServerRequestDispatcherImpl.java:205) at com.sun.corba.se.impl.protocol.CorbaMessageMediatorImpl.handleRequestRequest(CorbaMessageMediatorImpl.java:1700) at com.sun.corba.se.impl.protocol.CorbaMessageMediatorImpl.handleRequest(CorbaMessageMediatorImpl.java:1558) at com.sun.corba.se.impl.protocol.CorbaMessageMediatorImpl.handleInput(CorbaMessageMediatorImpl.java:940) at com.sun.corba.se.impl.protocol.giopmsgheaders.RequestMessage_1_2.callback(RequestMessage_1_2.java:198) at com.sun.corba.se.impl.protocol.CorbaMessageMediatorImpl.handleRequest(CorbaMessageMediatorImpl.java:712) at com.sun.corba.se.impl.transport.SocketOrChannelConnectionImpl.dispatch(SocketOrChannelConnectionImpl.java:474) at com.sun.corba.se.impl.transport.SocketOrChannelConnectionImpl.doWork(SocketOrChannelConnectionImpl.java:1237) at com.sun.corba.se.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.performWork(ThreadPoolImpl.java:490) at com.sun.corba.se.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.run(ThreadPoolImpl.java:519)
Log from server-2:
2017-06-20 16:55:32,563 DEBUG [org.jboss.as.test.jbossts.crashrec.txpropagation.jms.JMSClientBean] (p: default-threadpool; w: Idle) TX timeout = 2147483647 2017-06-20 16:55:32,563 DEBUG [org.jboss.as.test.jbossts.crashrec.txpropagation.jms.JMSClientBean] (p: default-threadpool; w: Idle) Local transaction (delegate=TransactionImple < jts, 0:ffff7f000001:-6ed9e073:5949372b:37 >, owner=Local transaction context for provider JBoss JTS transaction provider)
Attachments
Issue Links
- is incorporated by
-
JBEAP-11806 Upgrade Narayana to 5.5.27.Final
-
- Verified
-
