2 Replies Latest reply on May 19, 2016 2:04 AM by Ondra Chaloupka

    Behavior of transaction timeout defined on XAResource

    Ondra Chaloupka Apprentice

      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.

       

      1. two XA resources enlisted
      2. prepare phase of 2PC starts
      3. 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