Behavior of transaction timeout defined on XAResource
Hi,
if you don't mind this time I'm just curious.
I'm now playing with tests of transaction timeout. I'm interested how the behavior of transaction timeout is expected to work when is defined for XAResource. I have following case when working with Narayana under JBoss EAP.
- two XA resources enlisted
- prepare phase of 2PC starts
- transaction timeout is hit
As I understood from my other question on the forum (https://developer.jboss.org/message/956043#956043) when timeout is hit during prepare phase global transaction will be aborted.
That's happens. Transaction reaper found the transaction being timeouted and start aborting it. But meanwhile timeout of underlaying transaction of one of the XAResources is hit. This is messaging broker and it removes record about the transaction (as timeouted) from its internal log. Now Narayana calls XAResource.rollback on all participants. As transaction was already removed from the messaging broker there is returned on the rollback call XAException.XAER_NOTA [1]. This is because transaction timeout of the TM global transaction is set down through the XAResource.setTransactionTimeout, in time when XAResource is enlisted, to messaging broker.
This is probably correct behavior. Even that it seems to me a bit strange that TM does not rollback transaction without the all the noise of XAER_NOTA XAExceptions. Do you have some though of this?
Thank you
Ondra
[1]
DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread Status <== INACTIVE DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread backing off TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) ReaperThread.run () TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) TransactionReaper::check () TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) TransactionReaper::check - comparing 1463584113886 WARN [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check timeout for TX 0:ffff7f000001:-3efe60f9:573c8562:16 in state RUN TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) Reaper scheduling TX for cancellation 0:ffff7f000001:-3efe60f9:573c8562:16 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) TransactionReaper::check - comparing 1463584114387 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) Thread Thread[Transaction Reaper,5,main] sleeping for 500 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) Thread Thread[Transaction Reaper Worker 0,5,main] performing cancellations TRACE [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) Reaper Worker Thread[Transaction Reaper Worker 0,5,main] attempting to cancel 0:ffff7f000001:-3efe60f9:573c8562:16 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) Thread Thread[Transaction Reaper Worker 0,5,main] waiting for cancelled TXs TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) ReaperThread.run () TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) TransactionReaper::check () TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) TransactionReaper::check - comparing 9223372036854775807 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) Thread Thread[Transaction Reaper,5,main] sleeping for 9223370573270661419 TRACE [org.apache.activemq.artemis.core.server] (Thread-2 (ActiveMQ-scheduled-threads-570329958)) TransactionImpl::TransactionImpl [xid=XidImpl (795339106 bq:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-63.1.-97.7.87.60.-123.98.0.0.0.34.0.0.0.2.0.0.0.0 formatID:131077 gtxid:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-63.1.-97.7.87.60.-123.98.0.0.0.22.49 base64:AAAAAAAAAAAAAP__fwAAAcEBnwdXPIViAAAAIgAAAAIAAAAAAAAAAAAAAAAAAP__fwAAAcEBnwdXPIViAAAAFjEHAgIA, id=47, xid=XidImpl (795339106 bq:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-63.1.-97.7.87.60.-123.98.0.0.0.34.0.0.0.2.0.0.0.0 formatID:131077 gtxid:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-63.1.-97.7.87.60.-123.98.0.0.0.22.49 base64:AAAAAAAAAAAAAP__fwAAAcEBnwdXPIViAAAAIgAAAAIAAAAAAAAAAAAAAAAAAP__fwAAAcEBnwdXPIViAAAAFjEHAgIA, state=ACTIVE, createTime=1463584108057(Wed May 18 17:08:28 CEST 2016), timeoutSeconds=6, nr operations = 1]@183aa614 marking rollbackOnly for ActiveMQException[errorType=GENERIC_EXCEPTION message=TX Timeout], msg=TX Timeout DEBUG [org.apache.activemq.artemis.core.server] (Thread-2 (ActiveMQ-scheduled-threads-570329958)) Marking Transaction 47 as rollback only WARN [org.apache.activemq.artemis.core.server] (Thread-2 (ActiveMQ-scheduled-threads-570329958)) AMQ222103: transaction with xid XidImpl (795339106 bq:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-63.1.-97.7.87.60.-123.98.0.0.0.34.0.0.0.2.0.0.0.0 formatID:131077 gtxid:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-63.1.-97.7.87.60.-123.98.0.0.0.22.49 base64:AAAAAAAAAAAAAP__fwAAAcEBnwdXPIViAAAAIgAAAAIAAAAAAAAAAAAAAAAAAP__fwAAAcEBnwdXPIViAAAAFjEHAgIA timed out TRACE [org.apache.activemq.artemis.core.server] (Thread-2 (ActiveMQ-scheduled-threads-570329958)) TransactionImpl::rollback::TransactionImpl [xid=XidImpl (795339106 bq:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-63.1.-97.7.87.60.-123.98.0.0.0.34.0.0.0.2.0.0.0.0 formatID:131077 gtxid:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-63.1.-97.7.87.60.-123.98.0.0.0.22.49 base64:AAAAAAAAAAAAAP__fwAAAcEBnwdXPIViAAAAIgAAAAIAAAAAAAAAAAAAAAAAAP__fwAAAcEBnwdXPIViAAAAFjEHAgIA, id=47, xid=XidImpl (795339106 bq:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-63.1.-97.7.87.60.-123.98.0.0.0.34.0.0.0.2.0.0.0.0 formatID:131077 gtxid:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-63.1.-97.7.87.60.-123.98.0.0.0.22.49 base64:AAAAAAAAAAAAAP__fwAAAcEBnwdXPIViAAAAIgAAAAIAAAAAAAAAAAAAAAAAAP__fwAAAcEBnwdXPIViAAAAFjEHAgIA, state=ROLLBACK_ONLY, createTime=1463584108057(Wed May 18 17:08:28 CEST 2016), timeoutSeconds=6, nr operations = 1]@183aa614 TRACE [org.apache.activemq.artemis.core.server] (Thread-2 (ActiveMQ-scheduled-threads-570329958)) TransactionImpl::internalRollback TransactionImpl [xid=XidImpl (795339106 bq:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-63.1.-97.7.87.60.-123.98.0.0.0.34.0.0.0.2.0.0.0.0 formatID:131077 gtxid:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-63.1.-97.7.87.60.-123.98.0.0.0.22.49 base64:AAAAAAAAAAAAAP__fwAAAcEBnwdXPIViAAAAIgAAAAIAAAAAAAAAAAAAAAAAAP__fwAAAcEBnwdXPIViAAAAFjEHAgIA, id=47, xid=XidImpl (795339106 bq:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-63.1.-97.7.87.60.-123.98.0.0.0.34.0.0.0.2.0.0.0.0 formatID:131077 gtxid:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-63.1.-97.7.87.60.-123.98.0.0.0.22.49 base64:AAAAAAAAAAAAAP__fwAAAcEBnwdXPIViAAAAIgAAAAIAAAAAAAAAAAAAAAAAAP__fwAAAcEBnwdXPIViAAAAFjEHAgIA, state=ROLLBACK_ONLY, createTime=1463584108057(Wed May 18 17:08:28 CEST 2016), timeoutSeconds=6, nr operations = 1]@183aa614 TRACE [org.apache.activemq.artemis.journal] (activemq-buffer-timeout) Clearing reuse buffers queue with 0 elements INFO [org.jboss.as.test.jbossts.common.TestXAResourceCommon] (default task-8) TestXAResourceCommon.prepare(Xid=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-3efe60f9:573c8562:16, node_name=1, branch_uid=0:ffff7f000001:-3efe60f9:573c8562:1c, subordinatenodename=null, eis_name=java:/TestXAResource-674 >)[return 0][id=674] INFO [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (default task-8) logPrepared(xid=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-3efe60f9:573c8562:16, node_name=1, branch_uid=0:ffff7f000001:-3efe60f9:573c8562:1c, subordinatenodename=null, eis_name=java:/TestXAResource-674 >) INFO [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (default task-8) Using file /home/ochaloup/Transactions/eap-tests-transactions/jbossts/target/jbossas-jbossts/standalone/data/tx-object-store/TestXAResourceStateStore/TestXAResource.ser for saving state of the org.jboss.as.test.jbossts.common.TestXAResource XA resource INFO [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (default task-8) logging xids: [< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-3efe60f9:573c8562:16, node_name=1, branch_uid=0:ffff7f000001:-3efe60f9:573c8562:1c, subordinatenodename=null, eis_name=java:/TestXAResource-674 >][number: 1] records to /home/ochaloup/Transactions/eap-tests-transactions/jbossts/target/jbossas-jbossts/standalone/data/tx-object-store/TestXAResourceStateStore/TestXAResource.ser TRACE [com.arjuna.ats.arjuna] (default task-8) BasicAction::doPrepare() result for action-id (0:ffff7f000001:-3efe60f9:573c8562:16) on record id: (0:ffff7f000001:-3efe60f9:573c8562:1d) is (TwoPhaseOutcome.PREPARE_OK) node id: (1) TRACE [com.arjuna.ats.arjuna] (default task-8) RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/XAResourceRecord for 0:ffff7f000001:-3efe60f9:573c8562:1d TRACE [com.arjuna.ats.jta] (default task-8) XAResourceRecord.topLevelPrepare for XAResourceRecord < resource:org.jboss.activemq.artemis.wildfly.integration.WildFlyActiveMQXAResourceWrapper@49bc405, txid:< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-3efe60f9:573c8562:16, node_name=1, branch_uid=0:ffff7f000001:-3efe60f9:573c8562:22, subordinatenodename=null, eis_name=java:/JmsXA NodeId:53dcb340-1d0a-11e6-bcaf-a1901dc9466f >, heuristic: TwoPhaseOutcome.FINISH_OK, product: ActiveMQ Artemis/1.1.0.SP16-redhat-1, jndiName: java:/JmsXA NodeId:53dcb340-1d0a-11e6-bcaf-a1901dc9466f com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@4f8ea62b >, record id=0:ffff7f000001:-3efe60f9:573c8562:23 TRACE [org.apache.activemq.artemis.ra] (default task-8) prepare(< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-3efe60f9:573c8562:16, node_name=1, branch_uid=0:ffff7f000001:-3efe60f9:573c8562:22, subordinatenodename=null, eis_name=java:/JmsXA NodeId:53dcb340-1d0a-11e6-bcaf-a1901dc9466f >) TRACE [org.apache.activemq.artemis.core.client] (default task-8) Calling prepare:: xid=XidImpl (1238632546 bq:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-63.1.-97.7.87.60.-123.98.0.0.0.34.0.0.0.2.0.0.0.0 formatID:131077 gtxid:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-63.1.-97.7.87.60.-123.98.0.0.0.22.49 base64:AAAAAAAAAAAAAP__fwAAAcEBnwdXPIViAAAAIgAAAAIAAAAAAAAAAAAAAAAAAP__fwAAAcEBnwdXPIViAAAAFjEHAgIA,clientXID=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-3efe60f9:573c8562:16, node_name=1, branch_uid=0:ffff7f000001:-3efe60f9:573c8562:22, subordinatenodename=null, eis_name=java:/JmsXA NodeId:53dcb340-1d0a-11e6-bcaf-a1901dc9466f > TRACE [org.apache.activemq.artemis.core.server] (Thread-2 (ActiveMQ-remoting-threads-ActiveMQServerImpl::serverUUID=53dcb340-1d0a-11e6-bcaf-a1901dc9466f-967442496-1911047462)) InVMConnection [serverID=0, id=60164771-1d0a-11e6-89ad-d3670c2a2b30]::Sending inVM packet TRACE [org.apache.activemq.artemis.core.client] (Thread-2 (ActiveMQ-remoting-threads-ActiveMQServerImpl::serverUUID=53dcb340-1d0a-11e6-bcaf-a1901dc9466f-967442496-1911047462)) handling packet PACKET(SessionXAPrepareMessage)[type=54, channelID=11, packetObject=SessionXAPrepareMessage] TRACE [org.apache.activemq.artemis.core.server] (Thread-2 (ActiveMQ-remoting-threads-ActiveMQServerImpl::serverUUID=53dcb340-1d0a-11e6-bcaf-a1901dc9466f-967442496-1911047462)) ServerSessionPacketHandler::handlePacket,PACKET(SessionXAPrepareMessage)[type=54, channelID=11, packetObject=SessionXAPrepareMessage] TRACE [org.apache.activemq.artemis.core.server] (Thread-2 (ActiveMQ-remoting-threads-ActiveMQServerImpl::serverUUID=53dcb340-1d0a-11e6-bcaf-a1901dc9466f-967442496-1911047462)) xaprepare into , xid=XidImpl (689514392 bq:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-63.1.-97.7.87.60.-123.98.0.0.0.34.0.0.0.2.0.0.0.0 formatID:131077 gtxid:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-63.1.-97.7.87.60.-123.98.0.0.0.22.49 base64:AAAAAAAAAAAAAP__fwAAAcEBnwdXPIViAAAAIgAAAAIAAAAAAAAAAAAAAAAAAP__fwAAAcEBnwdXPIViAAAAFjEHAgIA, tx= null DEBUG [org.apache.activemq.artemis.core.server] (Thread-2 (ActiveMQ-remoting-threads-ActiveMQServerImpl::serverUUID=53dcb340-1d0a-11e6-bcaf-a1901dc9466f-967442496-1911047462)) Sending exception to client: org.apache.activemq.artemis.core.exception.ActiveMQXAException: Cannot find xid in resource manager: XidImpl (689514392 bq:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-63.1.-97.7.87.60.-123.98.0.0.0.34.0.0.0.2.0.0.0.0 formatID:131077 gtxid:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-63.1.-97.7.87.60.-123.98.0.0.0.22.49 base64:AAAAAAAAAAAAAP__fwAAAcEBnwdXPIViAAAAIgAAAAIAAAAAAAAAAAAAAAAAAP__fwAAAcEBnwdXPIViAAAAFjEHAgIA at org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.xaPrepare(ServerSessionImpl.java:1125) at org.apache.activemq.artemis.core.protocol.core.ServerSessionPacketHandler.handlePacket(ServerSessionPacketHandler.java:363) at org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl.handlePacket(ChannelImpl.java:626) at org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl.doBufferReceived(RemotingConnectionImpl.java:349) at org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl.bufferReceived(RemotingConnectionImpl.java:331) at org.apache.activemq.artemis.core.remoting.server.impl.RemotingServiceImpl$DelegatingBufferHandler.bufferReceived(RemotingServiceImpl.java:616) at org.apache.activemq.artemis.core.remoting.impl.invm.InVMConnection$1.run(InVMConnection.java:171) at org.apache.activemq.artemis.utils.OrderedExecutorFactory$OrderedExecutor$ExecutorTask.run(OrderedExecutorFactory.java:100) 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) TRACE [org.apache.activemq.artemis.core.server] (Thread-2 (ActiveMQ-remoting-threads-ActiveMQServerImpl::serverUUID=53dcb340-1d0a-11e6-bcaf-a1901dc9466f-967442496-1911047462)) ServerSessionPacketHandler::scheduling response::PACKET(SessionXAResponseMessage)[type=55, channelID=0, packetObject=SessionXAResponseMessage] TRACE [org.apache.activemq.artemis.core.client] (Thread-2 (ActiveMQ-remoting-threads-ActiveMQServerImpl::serverUUID=53dcb340-1d0a-11e6-bcaf-a1901dc9466f-967442496-1911047462)) Sending packet nonblocking PACKET(SessionXAResponseMessage)[type=55, channelID=11, packetObject=SessionXAResponseMessage] on channeID=11 TRACE [org.apache.activemq.artemis.core.client] (Thread-2 (ActiveMQ-remoting-threads-ActiveMQServerImpl::serverUUID=53dcb340-1d0a-11e6-bcaf-a1901dc9466f-967442496-1911047462)) Writing buffer for channelID=11 TRACE [org.apache.activemq.artemis.core.server] (Thread-2 (ActiveMQ-remoting-threads-ActiveMQServerImpl::serverUUID=53dcb340-1d0a-11e6-bcaf-a1901dc9466f-967442496-1911047462)) InVMConnection [serverID=0, id=60164771-1d0a-11e6-89ad-d3670c2a2b30]::packet sent done TRACE [org.apache.activemq.artemis.core.server] (pool-5-thread-30) InVMConnection [serverID=0, id=60164771-1d0a-11e6-89ad-d3670c2a2b30]::Sending inVM packet TRACE [org.apache.activemq.artemis.logs] (pool-5-thread-30) Reading string with utfSize=341 TRACE [org.apache.activemq.artemis.core.client] (pool-5-thread-30) handling packet PACKET(SessionXAResponseMessage)[type=55, channelID=11, packetObject=SessionXAResponseMessage] TRACE [org.apache.activemq.artemis.core.server] (pool-5-thread-30) InVMConnection [serverID=0, id=60164771-1d0a-11e6-89ad-d3670c2a2b30]::packet sent done WARN [com.arjuna.ats.jta] (default task-8) ARJUNA016041: prepare on < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-3efe60f9:573c8562:16, node_name=1, branch_uid=0:ffff7f000001:-3efe60f9:573c8562:22, subordinatenodename=null, eis_name=java:/JmsXA NodeId:53dcb340-1d0a-11e6-bcaf-a1901dc9466f > (org.jboss.activemq.artemis.wildfly.integration.WildFlyActiveMQXAResourceWrapper@49bc405) failed with exception XAException.XAER_NOTA: javax.transaction.xa.XAException at org.apache.activemq.artemis.core.protocol.core.impl.ActiveMQSessionContext.xaPrepare(ActiveMQSessionContext.java:457) at org.apache.activemq.artemis.core.client.impl.ClientSessionImpl.prepare(ClientSessionImpl.java:1238) at org.apache.activemq.artemis.ra.ActiveMQRAXAResource.prepare(ActiveMQRAXAResource.java:132) at org.apache.activemq.artemis.service.extensions.xa.ActiveMQXAResourceWrapperImpl.prepare(ActiveMQXAResourceWrapperImpl.java:101) at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelPrepare(XAResourceRecord.java:218) at com.arjuna.ats.arjuna.coordinator.BasicAction.doPrepare(BasicAction.java:2644) at com.arjuna.ats.arjuna.coordinator.BasicAction.doPrepare(BasicAction.java:2594) at com.arjuna.ats.arjuna.coordinator.BasicAction.prepare(BasicAction.java:2137) at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1501) at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:96) at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162) at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1200) 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.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:91) at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:279) at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:327) at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:239) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.as.ejb3.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:79) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:43) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.as.ejb3.deployment.processors.EjbSuspendInterceptor.processInvocation(EjbSuspendInterceptor.java:53) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:66) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.as.ejb3.component.interceptors.EjbExceptionTransformingInterceptorFactories$1.processInvocation(EjbExceptionTransformingInterceptorFactories.java:75) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:64) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356) at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:636) at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:61) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356) at org.jboss.invocation.PrivilegedWithCombinerInterceptor.processInvocation(PrivilegedWithCombinerInterceptor.java:80) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:195) at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.invokeMethod(MethodInvocationMessageHandler.java:327) at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.access$100(MethodInvocationMessageHandler.java:67) at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler$1.run(MethodInvocationMessageHandler.java:200) at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.processMessage(MethodInvocationMessageHandler.java:262) 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) TRACE [com.arjuna.ats.arjuna] (default task-8) BasicAction::doPrepare() result for action-id (0:ffff7f000001:-3efe60f9:573c8562:16) on record id: (0:ffff7f000001:-3efe60f9:573c8562:23) is (TwoPhaseOutcome.PREPARE_NOTOK) node id: (1) TRACE [com.arjuna.ats.arjuna] (default task-8) RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/XAResourceRecord for 0:ffff7f000001:-3efe60f9:573c8562:23 WARN [com.arjuna.ats.arjuna] (default task-8) ARJUNA012073: BasicAction.End() - prepare phase of action-id 0:ffff7f000001:-3efe60f9:573c8562:16 failed. WARN [com.arjuna.ats.arjuna] (default task-8) ARJUNA012075: Action Aborting TRACE [com.arjuna.ats.arjuna] (default task-8) BasicAction::phase2Abort() for action-id 0:ffff7f000001:-3efe60f9:573c8562:16
