Attachment 902145 Details for Bug 1082652 – server.log from 6.3.0.ER5

server.log from 6.3.0.ER5

org.jboss.as.test.jbossts.crashrec.test.JMSMdbCrashRecoveryTestCase_none_jta_server.log (text/x-log), 153.20 KB, created by Ondrej Chaloupka on 2014-06-04 11:23:22 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Ondrej Chaloupka

Created: 2014-06-04 11:23:22 UTC

Size: 153.20 KB

patch

obsolete

>13:04:29,772 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 35) JBAS010280: Activating Infinispan subsystem.
>13:04:29,777 INFO  [org.jboss.as.jacorb] (ServerService Thread Pool -- 36) JBAS016300: Activating JacORB Subsystem
>13:04:29,814 INFO  [org.jboss.as.connector.logging] (MSC service thread 1-3) JBAS010408: Starting JCA Subsystem (IronJacamar 1.0.26.Final-redhat-1)
>13:04:29,834 INFO  [org.jboss.as.connector.subsystems.datasources] (ServerService Thread Pool -- 31) JBAS010403: Deploying JDBC-compliant driver class org.h2.Driver (version 1.3)
>13:04:29,842 INFO  [org.jboss.as.naming] (ServerService Thread Pool -- 47) JBAS011800: Activating Naming Subsystem
>13:04:29,872 INFO  [org.jboss.as.jsf] (ServerService Thread Pool -- 43) JBAS012605: Activated the following JSF Implementations: [main, 1.2]
>13:04:29,874 INFO  [org.jboss.as.security] (ServerService Thread Pool -- 52) JBAS013171: Activating Security Subsystem
>13:04:29,880 WARN  [org.jboss.as.txn] (ServerService Thread Pool -- 54) JBAS010153: Node identifier property is set to the default value. Please make sure it is unique.
>13:04:29,889 INFO  [org.jboss.as.webservices] (ServerService Thread Pool -- 56) JBAS015537: Activating WebServices Extension
>13:04:29,891 INFO  [org.jboss.as.security] (MSC service thread 1-6) JBAS013170: Current PicketBox version=4.0.19.SP6-redhat-1
>13:04:29,963 INFO  [org.jboss.as.mail.extension] (MSC service thread 1-6) JBAS015400: Bound mail session [java:jboss/mail/Default]
>13:04:29,972 INFO  [org.jboss.as.naming] (MSC service thread 1-8) JBAS011802: Starting Naming Service
>13:04:29,997 INFO  [org.jboss.jaxr] (MSC service thread 1-8) JBAS014000: Started JAXR subsystem, binding JAXR connection factory into JNDI as: java:jboss/jaxr/ConnectionFactory
>13:04:30,255 INFO  [com.arjuna.ats.jbossatx] (MSC service thread 1-5) ARJUNA032010: JBossTS Recovery Service (tag: bea48879928270f8b0933725f6baf1c10cce649c) - JBoss Inc.
>13:04:30,292 INFO  [com.arjuna.ats.arjuna] (MSC service thread 1-5) ARJUNA012324: Start RecoveryActivators
>13:04:30,308 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-5) Expiry scan interval set to 43200 seconds
>13:04:30,308 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) Loading class com.arjuna.ats.internal.arjuna.recovery.ExpiredTransactionStatusManagerScanner
>13:04:30,308 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-5) Expiry scan interval set to  43200  seconds
>13:04:30,309 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-5) ExpiredTransactionStatusManagerScanner created, with expiry time of 43200  seconds
>13:04:30,301 INFO  [org.apache.coyote.http11.Http11Protocol] (MSC service thread 1-6) JBWEB003001: Coyote HTTP/1.1 initializing on : http-/127.0.0.1:8080
>13:04:30,316 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) Loading class com.arjuna.ats.internal.arjuna.objectstore.ShadowNoFileLockStore
>13:04:30,318 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) FileSystemStore.createHierarchy(/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/tx-object-store/ShadowNoFileLockStore/defaultStore/)
>13:04:30,325 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-5) ExpiredEntryMonitor - constructed
>13:04:30,329 INFO  [org.apache.coyote.http11.Http11Protocol] (MSC service thread 1-6) JBWEB003000: Coyote HTTP/1.1 starting on: http-/127.0.0.1:8080
>13:04:30,340 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) Loading class com.arjuna.ats.internal.jta.recovery.arjunacore.CommitMarkableResourceRecordRecoveryModule
>13:04:30,370 INFO  [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) ARJUNA012296: ExpiredEntryMonitor running at Wed, 4 Jun 2014 13:04:30
>13:04:30,370 DEBUG [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) ExpiredTransactionStatusManagerScanner - scanning to remove items from before Wed, 4 Jun 2014 01:04:30
>13:04:30,371 TRACE [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) InputObjectState::InputObjectState()
>13:04:30,386 TRACE [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) FileSystemStore.allObjUids(/Recovery/TransactionStatusManager, InputObjectState Uid   : 0:0:0:0:0
>InputObjectState Type  : null
>InputObjectState Size  : 0
>InputObjectState Buffer: , -1)
>13:04:30,387 TRACE [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) OutputObjectState::OutputObjectState()
>13:04:30,389 DEBUG [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor)   
>13:04:30,393 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) Loading class com.arjuna.ats.internal.arjuna.coordinator.CheckedActionFactoryImple
>13:04:30,394 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) StateManager::StateManager( 2, 0 )
>13:04:30,395 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) BasicAction::BasicAction()
>13:04:30,407 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) InputObjectState::InputObjectState()
>13:04:30,408 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) FileSystemStore.allObjUids(/Recovery/TransactionStatusManager, InputObjectState Uid   : 0:0:0:0:0
>InputObjectState Type  : null
>InputObjectState Size  : 0
>InputObjectState Buffer: , -1)
>13:04:30,408 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) OutputObjectState::OutputObjectState()
>13:04:30,408 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) Loading class com.arjuna.ats.internal.arjuna.recovery.AtomicActionRecoveryModule
>13:04:30,408 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) StateManager::StateManager( 2, 0 )
>13:04:30,408 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) BasicAction::BasicAction()
>13:04:30,408 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-5) AtomicActionRecoveryModule created
>13:04:30,409 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) InputObjectState::InputObjectState()
>13:04:30,409 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) FileSystemStore.allObjUids(/Recovery/TransactionStatusManager, InputObjectState Uid   : 0:0:0:0:0
>InputObjectState Type  : null
>InputObjectState Size  : 0
>InputObjectState Buffer: , -1)
>13:04:30,409 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) OutputObjectState::OutputObjectState()
>13:04:30,409 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) Loading class com.arjuna.ats.internal.txoj.recovery.TORecoveryModule
>13:04:30,422 DEBUG [com.arjuna.ats.txoj] (MSC service thread 1-5) TORecoveryModule created
>13:04:30,422 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) Loading class com.arjuna.ats.internal.arjuna.objectstore.ShadowNoFileLockStore
>13:04:30,423 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) FileSystemStore.createHierarchy(/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/tx-object-store/ShadowNoFileLockStore/defaultStore/)
>13:04:30,423 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) Loading class com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule
>13:04:30,424 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) InputObjectState::InputObjectState()
>13:04:30,425 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) Loading class com.arjuna.ats.internal.jta.recovery.arjunacore.JTATransactionLogXAResourceOrphanFilter
>13:04:30,425 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) Loading class com.arjuna.ats.internal.jta.recovery.arjunacore.JTANodeNameXAResourceOrphanFilter
>13:04:30,425 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) Loading class com.arjuna.ats.internal.jta.recovery.arjunacore.SubordinateJTAXAResourceOrphanFilter
>13:04:30,427 INFO  [com.arjuna.ats.arjuna] (MSC service thread 1-5) ARJUNA012343: RecoveryManagerImple is ready. Socket listener is turned off.
>13:04:30,427 INFO  [com.arjuna.ats.jbossatx] (MSC service thread 1-5) ARJUNA032013: Starting transaction recovery manager
>13:04:30,432 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread Status <== SCANNING
>13:04:30,432 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread scanning
>13:04:30,432 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) Periodic recovery first pass at Wed, 4 Jun 2014 13:04:30
>13:04:30,434 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) CommitMarkableResourceRecordRecoveryModule::periodicWorkFirstPass
>13:04:30,434 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) ObjectStoreDir: /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/tx-object-store
>13:04:30,435 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) StateManager::StateManager( 2, 0 )
>13:04:30,435 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) BasicAction::BasicAction()
>13:04:30,436 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState()
>13:04:30,436 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.allObjUids(/StateManager/BasicAction/TwoPhaseCoordinator/AtomicActionConnectable, InputObjectState Uid   : 0:0:0:0:0
>InputObjectState Type  : null
>InputObjectState Size  : 0
>InputObjectState Buffer: , -1)
>13:04:30,437 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState()
>13:04:30,437 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) processing /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction transactions
>13:04:30,437 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState()
>13:04:30,437 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.allObjUids(/StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction, InputObjectState Uid   : 0:0:0:0:0
>InputObjectState Type  : null
>InputObjectState Size  : 0
>InputObjectState Buffer: , -1)
>13:04:30,437 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState()
>13:04:30,437 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
>13:04:30,437 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState()
>13:04:30,437 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) AtomicActionRecoveryModule first pass
>13:04:30,438 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.allObjUids(/StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction, InputObjectState Uid   : 0:0:0:0:0
>InputObjectState Type  : null
>InputObjectState Size  : 0
>InputObjectState Buffer: , -1)
>13:04:30,438 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState()
>13:04:30,438 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) processing /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction transactions
>13:04:30,438 INFO  [org.jboss.as.jacorb] (MSC service thread 1-2) JBAS016330: CORBA ORB Service started
>13:04:30,438 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
>13:04:30,438 DEBUG [com.arjuna.ats.txoj] (Periodic Recovery) TORecoveryModule - first pass
>13:04:30,442 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState()
>13:04:30,442 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.allTypes(InputObjectState Uid   : 0:0:0:0:0
>InputObjectState Type  : null
>InputObjectState Size  : 0
>InputObjectState Buffer: )
>13:04:30,442 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState()
>13:04:30,442 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
>13:04:30,453 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Local XARecoveryModule - first pass
>13:04:30,453 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState()
>13:04:30,456 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.allObjUids(/StateManager/AbstractRecord/XAResourceRecord, InputObjectState Uid   : 0:0:0:0:0
>InputObjectState Type  : null
>InputObjectState Size  : 0
>InputObjectState Buffer: , -1)
>13:04:30,456 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState()
>13:04:30,459 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) StateManager::StateManager( 0:0:0:0:0 )
>13:04:30,459 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) BasicAction::BasicAction(0:0:0:0:0)
>13:04:30,475 TRACE [com.arjuna.ats.jts] (MSC service thread 1-8) ArjunaTransactionImple::ArjunaTransactionImple ( 0:0:0:0:0 )
>13:04:30,476 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) xarecovery of RecoveryOnlyEJBXAResource{receiverContext=EJBReceiverContext{clientContext=org.jboss.ejb.client.EJBClientContext@54ef1826, receiver=org.jboss.as.ejb3.remote.LocalEjbReceiver@38838efa}, transactionOriginNodeIdentifier='1'}
>13:04:30,499 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Found 0 xids in doubt
>13:04:30,500 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids new recoveryXids RecoveryOnlyEJBXAResource{receiverContext=EJBReceiverContext{clientContext=org.jboss.ejb.client.EJBClientContext@54ef1826, receiver=org.jboss.as.ejb3.remote.LocalEjbReceiver@38838efa}, transactionOriginNodeIdentifier='1'} 1401879870500
>13:04:30,501 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
>13:04:30,508 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) Loading class com.arjuna.ats.jbossatx.jta.TransactionManagerDelegate
>13:04:30,512 INFO  [com.arjuna.ats.jbossatx] (MSC service thread 1-8) ARJUNA032017: JBossTS Transaction Service (JTA version - tag: bea48879928270f8b0933725f6baf1c10cce649c) - JBoss Inc.
>13:04:30,516 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) TransactionReaper::instantiate()
>13:04:30,517 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) TransactionReaper::TransactionReaper ( 9223372036854775807 )
>13:04:30,539 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) ReaperThread.run ()
>13:04:30,539 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) Thread Thread[Transaction Reaper,5,main] sleeping for 9223370634974905268
>13:04:30,547 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-8) registering bean jboss.jta:type=ObjectStore
>13:04:30,549 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ReaperWorkerThread.run ()
>13:04:30,549 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) Thread Thread[Transaction Reaper Worker 0,5,main] waiting for cancelled TXs
>13:04:30,636 INFO  [org.jboss.ws.common.management] (MSC service thread 1-1) JBWS022052: Starting JBoss Web Services - Stack CXF Server 4.3.0.Final-redhat-2
>13:04:30,668 INFO  [org.jboss.as.jacorb] (MSC service thread 1-2) JBAS016328: CORBA Naming Service started
>13:04:30,698 INFO  [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-4) JBAS010400: Bound data source [java:jboss/datasources/ExampleDS]
>13:04:30,720 INFO  [org.jboss.as.remoting] (MSC service thread 1-7) JBAS017100: Listening on 127.0.0.1:9999
>13:04:30,724 INFO  [org.jboss.as.remoting] (MSC service thread 1-5) JBAS017100: Listening on 127.0.0.1:4447
>13:04:30,737 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-7) JBAS015876: Starting deployment of "dsdriver.jar" (runtime-name: "dsdriver.jar")
>13:04:30,747 INFO  [org.jboss.as.server.deployment.scanner] (MSC service thread 1-1) JBAS015012: Started FileSystemDeploymentService for directory /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/deployments
>13:04:30,885 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221000: live server is starting with configuration HornetQ Configuration (clustered=false,backup=false,sharedStore=true,journalDirectory=/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/messagingjournal,bindingsDirectory=/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/messagingbindings,largeMessagesDirectory=/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/messaginglargemessages,pagingDirectory=/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/messagingpaging)
>13:04:30,887 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221006: Waiting to obtain live lock
>13:04:30,925 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221013: Using NIO Journal
>13:04:31,075 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221034: Waiting to obtain live lock
>13:04:31,076 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221035: Live Server Obtained live lock
>13:04:31,191 INFO  [org.jboss.as.connector.deployers.jdbc] (MSC service thread 1-4) JBAS010404: Deploying non-JDBC-compliant driver class org.postgresql.Driver (version 9.3)
>13:04:31,446 TRACE [com.arjuna.ats.jts] (Finalizer) ArjunaTransactionImple.finalize - called for < 0:0:0:0:0 >
>13:04:31,447 TRACE [com.arjuna.ats.arjuna] (Finalizer) BasicAction::finalize()
>13:04:32,170 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221020: Started Netty Acceptor version 3.6.7.Final-redhat-1-3c0a3ac 127.0.0.1:5445 for CORE protocol
>13:04:32,174 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221020: Started Netty Acceptor version 3.6.7.Final-redhat-1-3c0a3ac 127.0.0.1:5455 for CORE protocol
>13:04:32,176 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221007: Server is now live
>13:04:32,177 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221001: HornetQ Server version 2.3.18.Final (2.3.18, 123) [00afa0cd-ebd8-11e3-b3ac-a3cc7d7c32ba] 
>13:04:32,212 INFO  [org.jboss.as.messaging] (ServerService Thread Pool -- 58) JBAS011601: Bound messaging object to jndi name java:jboss/exported/jms/RemoteConnectionFactory
>13:04:32,214 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 61) HQ221003: trying to deploy queue jms.queue.DLQ
>13:04:32,270 INFO  [org.jboss.as.connector.deployment] (MSC service thread 1-8) JBAS010406: Registered connection factory java:/JmsXA
>13:04:32,278 INFO  [org.jboss.as.messaging] (ServerService Thread Pool -- 61) JBAS011601: Bound messaging object to jndi name java:/jms/queue/DLQ
>13:04:32,279 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 59) HQ221003: trying to deploy queue jms.queue.ExpiryQueue
>13:04:32,291 INFO  [org.jboss.as.messaging] (ServerService Thread Pool -- 59) JBAS011601: Bound messaging object to jndi name java:/jms/queue/ExpiryQueue
>13:04:32,292 INFO  [org.jboss.as.messaging] (ServerService Thread Pool -- 60) JBAS011601: Bound messaging object to jndi name java:/ConnectionFactory
>13:04:32,305 INFO  [org.hornetq.ra] (MSC service thread 1-8) HornetQ resource adaptor started
>13:04:32,306 INFO  [org.jboss.as.connector.services.resourceadapters.ResourceAdapterActivatorService$ResourceAdapterActivator] (MSC service thread 1-8) IJ020002: Deployed: file://RaActivatorhornetq-ra
>13:04:32,312 INFO  [org.jboss.as.connector.deployment] (MSC service thread 1-8) JBAS010401: Bound JCA ConnectionFactory [java:/JmsXA]
>13:04:32,402 INFO  [org.jboss.as.server] (ServerService Thread Pool -- 32) JBAS018559: Deployed "dsdriver.jar" (runtime-name : "dsdriver.jar")
>13:04:32,644 INFO  [org.jboss.as] (Controller Boot Thread) JBAS015961: Http management interface listening on http://127.0.0.1:9990/management
>13:04:32,646 INFO  [org.jboss.as] (Controller Boot Thread) JBAS015951: Admin console listening on http://127.0.0.1:9990
>13:04:32,647 INFO  [org.jboss.as] (Controller Boot Thread) JBAS015874: JBoss EAP 6.3.0.Beta2 (AS 7.4.0.Final-redhat-13) started in 5688ms - Started 231 of 268 services (71 services are lazy, passive or on-demand)
>13:04:35,068 INFO  [org.apache.catalina.core] (MSC service thread 1-8) JBWEB001079: Container org.apache.catalina.core.ContainerBase.[jboss.web].[default-host].[/] has not been started
>13:04:35,078 INFO  [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-2) JBAS010409: Unbound data source [java:jboss/datasources/ExampleDS]
>13:04:35,084 INFO  [org.jboss.as.connector.deployment] (MSC service thread 1-1) JBAS010410: Unbound JCA ConnectionFactory [java:/JmsXA]
>13:04:35,094 INFO  [org.jboss.jaxr] (MSC service thread 1-6) JBAS014002: UnBinding JAXR ConnectionFactory: java:jboss/jaxr/ConnectionFactory
>13:04:35,103 INFO  [org.jboss.as.messaging] (ServerService Thread Pool -- 27) JBAS011605: Unbound messaging object to jndi name java:jboss/exported/jms/RemoteConnectionFactory
>13:04:35,100 INFO  [org.apache.coyote.http11.Http11Protocol] (MSC service thread 1-5) JBWEB003075: Coyote HTTP/1.1 pausing on: http-localhost.localdomain/127.0.0.1:8080
>13:04:35,131 INFO  [org.apache.coyote.http11.Http11Protocol] (MSC service thread 1-5) JBWEB003077: Coyote HTTP/1.1 stopping on : http-localhost.localdomain/127.0.0.1:8080
>13:04:35,119 INFO  [org.jboss.as.messaging] (ServerService Thread Pool -- 29) JBAS011605: Unbound messaging object to jndi name java:/jms/queue/DLQ
>13:04:35,136 INFO  [org.jboss.as.messaging] (ServerService Thread Pool -- 28) JBAS011605: Unbound messaging object to jndi name java:/ConnectionFactory
>13:04:35,138 INFO  [org.jboss.as.messaging] (ServerService Thread Pool -- 11) JBAS011605: Unbound messaging object to jndi name java:/jms/queue/ExpiryQueue
>13:04:35,158 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-4) JBAS015877: Stopped deployment dsdriver.jar (runtime-name: dsdriver.jar) in 106ms
>13:04:35,155 INFO  [org.hornetq.ra] (ServerService Thread Pool -- 22) HQ151003: HornetQ resource adaptor stopped
>13:04:35,291 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 22) HQ221002: HornetQ Server version 2.3.18.Final (2.3.18, 123) [00afa0cd-ebd8-11e3-b3ac-a3cc7d7c32ba] stopped
>13:04:35,294 INFO  [com.arjuna.ats.jbossatx] (MSC service thread 1-2) ARJUNA032018: Destroying TransactionManagerService
>13:04:35,295 INFO  [com.arjuna.ats.jbossatx] (MSC service thread 1-4) ARJUNA032014: Stopping transaction recovery manager
>13:04:35,296 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-4) PeriodicRecovery: Mode <== TERMINATED
>13:04:35,296 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-4) PeriodicRecovery: shutdown waiting for scan to end
>13:04:35,296 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: scan TERMINATED at phase 1
>13:04:35,296 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread Status <== INACTIVE
>13:04:35,297 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-4) PeriodicRecovery: shutdown scan wait complete
>13:04:35,297 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread exiting
>13:04:35,308 INFO  [org.jboss.as.mail.extension] (MSC service thread 1-4) JBAS015401: Unbound mail session [java:jboss/mail/Default]
>13:04:35,323 INFO  [org.jboss.as] (MSC service thread 1-6) JBAS015950: JBoss EAP 6.3.0.Beta2 (AS 7.4.0.Final-redhat-13) stopped in 279ms
>13:04:35,327 INFO  [org.jboss.as] (MSC service thread 1-4) JBAS015899: JBoss EAP 6.3.0.Beta2 (AS 7.4.0.Final-redhat-13) starting
>13:04:35,330 DEBUG [org.jboss.as.config] (MSC service thread 1-4) Configured system properties:
>	awt.toolkit = sun.awt.X11.XToolkit
>	catalina.home = /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/tmp
>	file.encoding = UTF-8
>	file.encoding.pkg = sun.io
>	file.separator = /
>	java.awt.graphicsenv = sun.awt.X11GraphicsEnvironment
>	java.awt.printerjob = sun.print.PSPrinterJob
>	java.class.path = /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/jboss-modules.jar:/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/byteman/byteman.jar
>	java.class.version = 51.0
>	java.endorsed.dirs = /opt/jdk1.7.0_60/jre/lib/endorsed
>	java.ext.dirs = /opt/jdk1.7.0_60/jre/lib/ext:/usr/java/packages/lib/ext
>	java.home = /opt/jdk1.7.0_60/jre
>	java.io.tmpdir = /tmp
>	java.library.path = /usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
>	java.naming.factory.url.pkgs = org.jboss.as.naming.interfaces:org.jboss.ejb.client.naming
>	java.net.preferIPv4Stack = true
>	java.net.preferIPv6Addresses = false
>	java.protocol.handler.pkgs = org.jboss.net.protocol|org.jboss.vfs.protocol
>	java.runtime.name = Java(TM) SE Runtime Environment
>	java.runtime.version = 1.7.0_60-b19
>	java.specification.name = Java Platform API Specification
>	java.specification.vendor = Oracle Corporation
>	java.specification.version = 1.7
>	java.util.logging.manager = org.jboss.logmanager.LogManager
>	java.vendor = Oracle Corporation
>	java.vendor.url = http://java.oracle.com/
>	java.vendor.url.bug = http://bugreport.sun.com/bugreport/
>	java.version = 1.7.0_60
>	java.vm.info = mixed mode
>	java.vm.name = Java HotSpot(TM) 64-Bit Server VM
>	java.vm.specification.name = Java Virtual Machine Specification
>	java.vm.specification.vendor = Oracle Corporation
>	java.vm.specification.version = 1.7
>	java.vm.vendor = Oracle Corporation
>	java.vm.version = 24.60-b09
>	javax.management.builder.initial = org.jboss.as.jmx.PluggableMBeanServerBuilder
>	javax.xml.datatype.DatatypeFactory = __redirected.__DatatypeFactory
>	javax.xml.parsers.DocumentBuilderFactory = __redirected.__DocumentBuilderFactory
>	javax.xml.parsers.SAXParserFactory = __redirected.__SAXParserFactory
>	javax.xml.stream.XMLEventFactory = __redirected.__XMLEventFactory
>	javax.xml.stream.XMLInputFactory = __redirected.__XMLInputFactory
>	javax.xml.stream.XMLOutputFactory = __redirected.__XMLOutputFactory
>	javax.xml.transform.TransformerFactory = __redirected.__TransformerFactory
>	javax.xml.validation.SchemaFactory:http://www.w3.org/2001/XMLSchema = __redirected.__SchemaFactory
>	javax.xml.xpath.XPathFactory:http://java.sun.com/jaxp/xpath/dom = __redirected.__XPathFactory
>	jboss.bundles.dir = /home/ochaloup/jboss/jboss-eap-6.3.0.ER5/bundles
>	jboss.dist = /home/ochaloup/jboss/jboss-eap-6.3.0.ER5
>	jboss.home.dir = /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts
>	jboss.host.name = localhost
>	jboss.modules.dir = /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/modules
>	jboss.modules.system.pkgs = org.jboss.byteman
>	jboss.node.name = jbossts
>	jboss.qualified.host.name = localhost.localdomain
>	jboss.server.base.dir = /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone
>	jboss.server.config.dir = /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/configuration
>	jboss.server.data.dir = /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data
>	jboss.server.deploy.dir = /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/content
>	jboss.server.log.dir = /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/log
>	jboss.server.name = localhost
>	jboss.server.persist.config = true
>	jboss.server.temp.dir = /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/tmp
>	jbossas.project.dir = /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/../../..
>	jbossas.ts.dir = /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/../..
>	jbossas.ts.integ.dir = /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/..
>	jbossas.ts.submodule.dir = /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts
>	line.separator = 
>
>	logging.configuration = file:/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/configuration/logging.properties
>	mcast = 230.0.0.4
>	module.path = /home/ochaloup/jboss/jboss-eap-6.3.0.ER5/modules:/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/modules
>	node0 = 127.0.0.1
>	node1 = 127.0.0.1
>	node2 = 127.0.0.1
>	org.apache.xml.security.ignoreLineBreaks = true
>	org.jboss.boot.log.file = /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/log/boot.log
>	org.jboss.byteman.contrib.dtest.rmiregistry.port = 1199
>	org.jboss.byteman.debug = true
>	org.jboss.byteman.verbose = true
>	org.jboss.com.sun.CORBA.ORBUseDynamicStub = true
>	org.jboss.logmanager.nocolor = true
>	org.jboss.resolver.warning = true
>	org.jboss.security.context.ThreadLocal = true
>	org.omg.CORBA.ORBClass = org.jacorb.orb.ORB
>	org.omg.CORBA.ORBSingletonClass = org.jacorb.orb.ORBSingleton
>	org.xml.sax.driver = __redirected.__XMLReaderFactory
>	os.arch = amd64
>	os.name = Linux
>	os.version = 3.14.4-200.fc20.x86_64
>	path.separator = :
>	sun.arch.data.model = 64
>	sun.boot.class.path = /opt/jdk1.7.0_60/jre/lib/resources.jar:/opt/jdk1.7.0_60/jre/lib/rt.jar:/opt/jdk1.7.0_60/jre/lib/sunrsasign.jar:/opt/jdk1.7.0_60/jre/lib/jsse.jar:/opt/jdk1.7.0_60/jre/lib/jce.jar:/opt/jdk1.7.0_60/jre/lib/charsets.jar:/opt/jdk1.7.0_60/jre/lib/jfr.jar:/opt/jdk1.7.0_60/jre/classes
>	sun.boot.library.path = /opt/jdk1.7.0_60/jre/lib/amd64
>	sun.cpu.endian = little
>	sun.cpu.isalist = 
>	sun.io.unicode.encoding = UnicodeLittle
>	sun.java.command = /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/jboss-modules.jar -mp /home/ochaloup/jboss/jboss-eap-6.3.0.ER5/modules:/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/modules -jaxpmodule javax.xml.jaxp-provider org.jboss.as.standalone -server-config standalone-full.xml
>	sun.java.launcher = SUN_STANDARD
>	sun.jnu.encoding = UTF-8
>	sun.management.compiler = HotSpot 64-Bit Tiered Compilers
>	sun.nio.ch.bugLevel = 
>	sun.os.patch.level = unknown
>	ts.timeout.factor = 100
>	user.country = US
>	user.dir = /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/workdir
>	user.home = /home/ochaloup
>	user.language = en
>	user.name = ochaloup
>	user.timezone = Europe/Prague
>13:04:35,330 DEBUG [org.jboss.as.config] (MSC service thread 1-4) VM Arguments: -Xmx1303m -XX:MaxPermSize=256m -Djboss.dist=/home/ochaloup/jboss/jboss-eap-6.3.0.ER5 -Djava.net.preferIPv4Stack=true -Djava.net.preferIPv6Addresses=false -Dts.timeout.factor=100 -Dnode0=127.0.0.1 -Dnode1=127.0.0.1 -Dnode2=127.0.0.1 -Dmcast=230.0.0.4 -Djbossas.ts.submodule.dir=/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts -Djbossas.ts.integ.dir=/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/.. -Djbossas.ts.dir=/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/../.. -Djbossas.project.dir=/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/../../.. -Djboss.dist=/home/ochaloup/jboss/jboss-eap-6.3.0.ER5 -Dorg.jboss.logmanager.nocolor=true -Dorg.jboss.byteman.debug=true -Dorg.jboss.byteman.verbose=true -Dorg.jboss.byteman.contrib.dtest.rmiregistry.port=1199 -Djboss.modules.system.pkgs=org.jboss.byteman -javaagent:/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/byteman/byteman.jar=address:127.0.0.1,port:9091,listener:true,sys:/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/byteman/byteman-dtest.jar -Djboss.node.name=jbossts -ea -Djboss.home.dir=/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts -Dorg.jboss.boot.log.file=/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/log/boot.log -Dlogging.configuration=file:/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/configuration/logging.properties -Djboss.bundles.dir=/home/ochaloup/jboss/jboss-eap-6.3.0.ER5/bundles 
>13:04:35,522 INFO  [org.jboss.as.server] (Controller Boot Thread) JBAS015888: Creating http management service using socket-binding (management-http)
>13:04:35,533 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 35) JBAS010280: Activating Infinispan subsystem.
>13:04:35,535 INFO  [org.jboss.as.jacorb] (ServerService Thread Pool -- 36) JBAS016300: Activating JacORB Subsystem
>13:04:35,540 INFO  [org.jboss.as.connector.logging] (MSC service thread 1-8) JBAS010408: Starting JCA Subsystem (IronJacamar 1.0.26.Final-redhat-1)
>13:04:35,549 INFO  [org.jboss.as.connector.subsystems.datasources] (ServerService Thread Pool -- 31) JBAS010403: Deploying JDBC-compliant driver class org.h2.Driver (version 1.3)
>13:04:35,553 INFO  [org.jboss.as.jacorb] (MSC service thread 1-6) JBAS016330: CORBA ORB Service started
>13:04:35,553 INFO  [org.jboss.as.naming] (ServerService Thread Pool -- 47) JBAS011800: Activating Naming Subsystem
>13:04:35,558 INFO  [org.jboss.as.naming] (MSC service thread 1-7) JBAS011802: Starting Naming Service
>13:04:35,559 INFO  [org.jboss.jaxr] (MSC service thread 1-7) JBAS014000: Started JAXR subsystem, binding JAXR connection factory into JNDI as: java:jboss/jaxr/ConnectionFactory
>13:04:35,559 INFO  [org.jboss.as.mail.extension] (MSC service thread 1-8) JBAS015400: Bound mail session [java:jboss/mail/Default]
>13:04:35,570 INFO  [org.jboss.as.security] (ServerService Thread Pool -- 52) JBAS013171: Activating Security Subsystem
>13:04:35,573 WARN  [org.jboss.as.txn] (ServerService Thread Pool -- 54) JBAS010153: Node identifier property is set to the default value. Please make sure it is unique.
>13:04:35,577 INFO  [org.jboss.as.webservices] (ServerService Thread Pool -- 56) JBAS015537: Activating WebServices Extension
>13:04:35,597 INFO  [org.jboss.as.security] (MSC service thread 1-6) JBAS013170: Current PicketBox version=4.0.19.SP6-redhat-1
>13:04:35,603 INFO  [org.jboss.ws.common.management] (MSC service thread 1-4) JBWS022052: Starting JBoss Web Services - Stack CXF Server 4.3.0.Final-redhat-2
>13:04:35,607 INFO  [com.arjuna.ats.jbossatx] (MSC service thread 1-5) ARJUNA032010: JBossTS Recovery Service (tag: bea48879928270f8b0933725f6baf1c10cce649c) - JBoss Inc.
>13:04:35,608 INFO  [com.arjuna.ats.jbossatx] (MSC service thread 1-5) ARJUNA032013: Starting transaction recovery manager
>13:04:35,608 INFO  [com.arjuna.ats.arjuna] (MSC service thread 1-5) ARJUNA012324: Start RecoveryActivators
>13:04:35,608 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-5) ExpiredEntryMonitor - constructed
>13:04:35,611 INFO  [com.arjuna.ats.arjuna] (MSC service thread 1-5) ARJUNA012310: Recovery manager listening on endpoint 127.0.0.1:4712
>13:04:35,612 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-5) PeriodicRecovery: starting listener worker thread
>13:04:35,612 INFO  [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) ARJUNA012296: ExpiredEntryMonitor running at Wed, 4 Jun 2014 13:04:35
>13:04:35,613 INFO  [com.arjuna.ats.arjuna] (MSC service thread 1-5) ARJUNA012344: RecoveryManagerImple is ready on port 4712
>13:04:35,614 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread Status <== SCANNING
>13:04:35,614 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread scanning
>13:04:35,615 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) Periodic recovery first pass at Wed, 4 Jun 2014 13:04:35
>13:04:35,617 DEBUG [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) ExpiredTransactionStatusManagerScanner - scanning to remove items from before Wed, 4 Jun 2014 01:04:35
>13:04:35,617 TRACE [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) InputObjectState::InputObjectState()
>13:04:35,617 TRACE [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) FileSystemStore.allObjUids(/Recovery/TransactionStatusManager, InputObjectState Uid   : 0:0:0:0:0
>InputObjectState Type  : null
>InputObjectState Size  : 0
>InputObjectState Buffer: , -1)
>13:04:35,617 TRACE [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) OutputObjectState::OutputObjectState()
>13:04:35,617 DEBUG [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor)   
>13:04:35,617 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) ObjectStoreDir: /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/tx-object-store
>13:04:35,618 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) StateManager::StateManager( 2, 0 )
>13:04:35,618 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) BasicAction::BasicAction()
>13:04:35,618 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) StateManager::StateManager( 0:0:0:0:0 )
>13:04:35,618 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) BasicAction::BasicAction(0:0:0:0:0)
>13:04:35,618 TRACE [com.arjuna.ats.jts] (MSC service thread 1-5) ArjunaTransactionImple::ArjunaTransactionImple ( 0:0:0:0:0 )
>13:04:35,618 INFO  [com.arjuna.ats.jbossatx] (MSC service thread 1-5) ARJUNA032017: JBossTS Transaction Service (JTA version - tag: bea48879928270f8b0933725f6baf1c10cce649c) - JBoss Inc.
>13:04:35,618 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-5) registering bean jboss.jta:type=ObjectStore
>13:04:35,619 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) CommitMarkableResourceRecordRecoveryModule::periodicWorkFirstPass
>13:04:35,619 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState()
>13:04:35,619 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.allObjUids(/StateManager/BasicAction/TwoPhaseCoordinator/AtomicActionConnectable, InputObjectState Uid   : 0:0:0:0:0
>InputObjectState Type  : null
>InputObjectState Size  : 0
>InputObjectState Buffer: , -1)
>13:04:35,620 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState()
>13:04:35,620 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) processing /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction transactions
>13:04:35,620 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState()
>13:04:35,620 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.allObjUids(/StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction, InputObjectState Uid   : 0:0:0:0:0
>InputObjectState Type  : null
>InputObjectState Size  : 0
>InputObjectState Buffer: , -1)
>13:04:35,620 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState()
>13:04:35,620 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
>13:04:35,620 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState()
>13:04:35,620 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) AtomicActionRecoveryModule first pass
>13:04:35,620 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.allObjUids(/StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction, InputObjectState Uid   : 0:0:0:0:0
>InputObjectState Type  : null
>InputObjectState Size  : 0
>InputObjectState Buffer: , -1)
>13:04:35,621 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState()
>13:04:35,621 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) processing /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction transactions
>13:04:35,621 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
>13:04:35,621 DEBUG [com.arjuna.ats.txoj] (Periodic Recovery) TORecoveryModule - first pass
>13:04:35,621 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState()
>13:04:35,621 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.allTypes(InputObjectState Uid   : 0:0:0:0:0
>InputObjectState Type  : null
>InputObjectState Size  : 0
>InputObjectState Buffer: )
>13:04:35,621 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState()
>13:04:35,621 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
>13:04:35,621 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
>13:04:35,630 INFO  [org.apache.coyote.http11.Http11Protocol] (MSC service thread 1-1) JBWEB003001: Coyote HTTP/1.1 initializing on : http-/127.0.0.1:8080
>13:04:35,632 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-4) JBAS015876: Starting deployment of "dsdriver.jar" (runtime-name: "dsdriver.jar")
>13:04:35,636 INFO  [org.apache.coyote.http11.Http11Protocol] (MSC service thread 1-1) JBWEB003000: Coyote HTTP/1.1 starting on: http-/127.0.0.1:8080
>13:04:35,641 INFO  [org.jboss.as.jacorb] (MSC service thread 1-6) JBAS016328: CORBA Naming Service started
>13:04:35,641 INFO  [org.jboss.as.server.deployment.scanner] (MSC service thread 1-8) JBAS015012: Started FileSystemDeploymentService for directory /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/deployments
>13:04:35,643 INFO  [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-8) JBAS010400: Bound data source [java:jboss/datasources/ExampleDS]
>13:04:35,643 INFO  [org.jboss.as.remoting] (MSC service thread 1-3) JBAS017100: Listening on 127.0.0.1:9999
>13:04:35,649 INFO  [org.jboss.as.remoting] (MSC service thread 1-5) JBAS017100: Listening on 127.0.0.1:4447
>13:04:35,651 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221000: live server is starting with configuration HornetQ Configuration (clustered=false,backup=false,sharedStore=true,journalDirectory=/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/messagingjournal,bindingsDirectory=/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/messagingbindings,largeMessagesDirectory=/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/messaginglargemessages,pagingDirectory=/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/messagingpaging)
>13:04:35,652 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221006: Waiting to obtain live lock
>13:04:35,652 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221013: Using NIO Journal
>13:04:35,707 INFO  [org.jboss.as.connector.deployers.jdbc] (MSC service thread 1-6) JBAS010404: Deploying non-JDBC-compliant driver class org.postgresql.Driver (version 9.3)
>13:04:35,836 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221034: Waiting to obtain live lock
>13:04:35,837 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221035: Live Server Obtained live lock
>13:04:36,212 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221020: Started Netty Acceptor version 3.6.7.Final-redhat-1-3c0a3ac 127.0.0.1:5445 for CORE protocol
>13:04:36,216 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221020: Started Netty Acceptor version 3.6.7.Final-redhat-1-3c0a3ac 127.0.0.1:5455 for CORE protocol
>13:04:36,217 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221007: Server is now live
>13:04:36,218 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221001: HornetQ Server version 2.3.18.Final (2.3.18, 123) [00afa0cd-ebd8-11e3-b3ac-a3cc7d7c32ba] 
>13:04:36,221 INFO  [org.jboss.as.messaging] (ServerService Thread Pool -- 58) JBAS011601: Bound messaging object to jndi name java:jboss/exported/jms/RemoteConnectionFactory
>13:04:36,228 INFO  [org.jboss.as.messaging] (ServerService Thread Pool -- 61) JBAS011601: Bound messaging object to jndi name java:/ConnectionFactory
>13:04:36,230 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221003: trying to deploy queue jms.queue.DLQ
>13:04:36,233 INFO  [org.jboss.as.messaging] (ServerService Thread Pool -- 60) JBAS011601: Bound messaging object to jndi name java:/jms/queue/DLQ
>13:04:36,234 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 59) HQ221003: trying to deploy queue jms.queue.ExpiryQueue
>13:04:36,237 INFO  [org.jboss.as.connector.deployment] (MSC service thread 1-4) JBAS010406: Registered connection factory java:/JmsXA
>13:04:36,238 INFO  [org.jboss.as.messaging] (ServerService Thread Pool -- 59) JBAS011601: Bound messaging object to jndi name java:/jms/queue/ExpiryQueue
>13:04:36,251 INFO  [org.hornetq.ra] (MSC service thread 1-4) HornetQ resource adaptor started
>13:04:36,252 INFO  [org.jboss.as.connector.services.resourceadapters.ResourceAdapterActivatorService$ResourceAdapterActivator] (MSC service thread 1-4) IJ020002: Deployed: file://RaActivatorhornetq-ra
>13:04:36,254 INFO  [org.jboss.as.connector.deployment] (MSC service thread 1-7) JBAS010401: Bound JCA ConnectionFactory [java:/JmsXA]
>13:04:36,312 TRACE [com.arjuna.ats.jts] (Finalizer) ArjunaTransactionImple.finalize - called for < 0:0:0:0:0 >
>13:04:36,312 TRACE [com.arjuna.ats.arjuna] (Finalizer) BasicAction::finalize()
>13:04:36,360 INFO  [org.jboss.as.server] (ServerService Thread Pool -- 32) JBAS018559: Deployed "dsdriver.jar" (runtime-name : "dsdriver.jar")
>13:04:36,369 INFO  [org.jboss.as] (Controller Boot Thread) JBAS015961: Http management interface listening on http://127.0.0.1:9990/management
>13:04:36,370 INFO  [org.jboss.as] (Controller Boot Thread) JBAS015951: Admin console listening on http://127.0.0.1:9990
>13:04:36,370 INFO  [org.jboss.as] (Controller Boot Thread) JBAS015874: JBoss EAP 6.3.0.Beta2 (AS 7.4.0.Final-redhat-13) started in 1038ms - Started 231 of 268 services (71 services are lazy, passive or on-demand)
>13:04:37,173 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 24) HQ221003: trying to deploy queue jms.queue.queue/crashRecoveryQueue
>13:04:37,193 INFO  [org.jboss.as.messaging] (ServerService Thread Pool -- 24) JBAS011601: Bound messaging object to jndi name java:jboss/queue/crashRecoveryQueue
>13:04:37,355 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 24) HQ221003: trying to deploy queue jms.queue.queue/MDBTriggerQueue
>13:04:37,374 INFO  [org.jboss.as.messaging] (ServerService Thread Pool -- 24) JBAS011601: Bound messaging object to jndi name java:jboss/queue/MDBTriggerQueue
>13:04:37,789 INFO  [org.jboss.as.repository] (management-handler-thread - 2) JBAS014900: Content added at location /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/content/ba/c7d1f4f627bbb61eeab83769c29f9bbe7458fd/content
>13:04:37,808 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-4) JBAS015876: Starting deployment of "crashrecovery-jms.jar" (runtime-name: "crashrecovery-jms.jar")
>13:04:37,937 WARN  [org.jboss.as.dependency.private] (MSC service thread 1-2) JBAS018567: Deployment "deployment.crashrecovery-jms.jar" is using a private module ("org.jboss.jts:main") which may be changed or removed in future versions without notice.
>13:04:38,020 INFO  [org.jboss.as.ejb3.deployment.processors.EjbJndiBindingsDeploymentUnitProcessor] (MSC service thread 1-2) JNDI bindings for session bean named MessageHelper in deployment unit deployment "crashrecovery-jms.jar" are as follows:
>
>	java:global/crashrecovery-jms/MessageHelper!org.jboss.as.test.jbossts.crashrec.jms.MessageHelperRemote
>	java:app/crashrecovery-jms/MessageHelper!org.jboss.as.test.jbossts.crashrec.jms.MessageHelperRemote
>	java:module/MessageHelper!org.jboss.as.test.jbossts.crashrec.jms.MessageHelperRemote
>	java:jboss/exported/crashrecovery-jms/MessageHelper!org.jboss.as.test.jbossts.crashrec.jms.MessageHelperRemote
>	java:global/crashrecovery-jms/MessageHelper
>	java:app/crashrecovery-jms/MessageHelper
>	java:module/MessageHelper
>
>13:04:38,020 INFO  [org.jboss.as.ejb3.deployment.processors.EjbJndiBindingsDeploymentUnitProcessor] (MSC service thread 1-2) JNDI bindings for session bean named CrashHelperTestXAResource in deployment unit deployment "crashrecovery-jms.jar" are as follows:
>
>	java:global/crashrecovery-jms/CrashHelperTestXAResource!org.jboss.as.test.jbossts.crashrec.common.CrashHelperRemote
>	java:app/crashrecovery-jms/CrashHelperTestXAResource!org.jboss.as.test.jbossts.crashrec.common.CrashHelperRemote
>	java:module/CrashHelperTestXAResource!org.jboss.as.test.jbossts.crashrec.common.CrashHelperRemote
>	java:jboss/exported/crashrecovery-jms/CrashHelperTestXAResource!org.jboss.as.test.jbossts.crashrec.common.CrashHelperRemote
>	java:global/crashrecovery-jms/CrashHelperTestXAResource
>	java:app/crashrecovery-jms/CrashHelperTestXAResource
>	java:module/CrashHelperTestXAResource
>
>13:04:38,021 INFO  [org.jboss.as.ejb3.deployment.processors.EjbJndiBindingsDeploymentUnitProcessor] (MSC service thread 1-2) JNDI bindings for session bean named TestXAResourceRecoveryHelper in deployment unit deployment "crashrecovery-jms.jar" are as follows:
>
>	java:global/crashrecovery-jms/TestXAResourceRecoveryHelper!com.arjuna.ats.jta.recovery.XAResourceRecoveryHelper
>	java:app/crashrecovery-jms/TestXAResourceRecoveryHelper!com.arjuna.ats.jta.recovery.XAResourceRecoveryHelper
>	java:module/TestXAResourceRecoveryHelper!com.arjuna.ats.jta.recovery.XAResourceRecoveryHelper
>	java:global/crashrecovery-jms/TestXAResourceRecoveryHelper
>	java:app/crashrecovery-jms/TestXAResourceRecoveryHelper
>	java:module/TestXAResourceRecoveryHelper
>
>13:04:38,022 INFO  [org.jboss.as.ejb3.deployment.processors.EjbJndiBindingsDeploymentUnitProcessor] (MSC service thread 1-2) JNDI bindings for session bean named TransactionStoreBrowserService in deployment unit deployment "crashrecovery-jms.jar" are as follows:
>
>	java:global/crashrecovery-jms/TransactionStoreBrowserService!org.jboss.as.test.jbossts.common.TransactionStoreBrowserService
>	java:app/crashrecovery-jms/TransactionStoreBrowserService!org.jboss.as.test.jbossts.common.TransactionStoreBrowserService
>	java:module/TransactionStoreBrowserService!org.jboss.as.test.jbossts.common.TransactionStoreBrowserService
>	java:global/crashrecovery-jms/TransactionStoreBrowserService
>	java:app/crashrecovery-jms/TransactionStoreBrowserService
>	java:module/TransactionStoreBrowserService
>
>13:04:38,022 INFO  [org.jboss.as.ejb3.deployment.processors.EjbJndiBindingsDeploymentUnitProcessor] (MSC service thread 1-2) JNDI bindings for session bean named JMSCrashHelper in deployment unit deployment "crashrecovery-jms.jar" are as follows:
>
>	java:global/crashrecovery-jms/JMSCrashHelper!org.jboss.as.test.jbossts.crashrec.jms.JMSCrashHelperRemote
>	java:app/crashrecovery-jms/JMSCrashHelper!org.jboss.as.test.jbossts.crashrec.jms.JMSCrashHelperRemote
>	java:module/JMSCrashHelper!org.jboss.as.test.jbossts.crashrec.jms.JMSCrashHelperRemote
>	java:jboss/exported/crashrecovery-jms/JMSCrashHelper!org.jboss.as.test.jbossts.crashrec.jms.JMSCrashHelperRemote
>	java:global/crashrecovery-jms/JMSCrashHelper
>	java:app/crashrecovery-jms/JMSCrashHelper
>	java:module/JMSCrashHelper
>
>13:04:38,231 WARN  [org.jboss.as.ejb3] (MSC service thread 1-8) JBAS014105: ActivationConfigProperty hostName will be ignored since it is not allowed by resource adapter: hornetq-ra
>13:04:38,231 WARN  [org.jboss.as.ejb3] (MSC service thread 1-8) JBAS014105: ActivationConfigProperty MaxDeliveryCnt will be ignored since it is not allowed by resource adapter: hornetq-ra
>13:04:38,231 WARN  [org.jboss.as.ejb3] (MSC service thread 1-8) JBAS014105: ActivationConfigProperty useJndi will be ignored since it is not allowed by resource adapter: hornetq-ra
>13:04:38,232 WARN  [org.jboss.as.ejb3] (MSC service thread 1-8) JBAS014105: ActivationConfigProperty port will be ignored since it is not allowed by resource adapter: hornetq-ra
>13:04:38,232 WARN  [org.jboss.as.ejb3] (MSC service thread 1-8) JBAS014105: ActivationConfigProperty queueManager will be ignored since it is not allowed by resource adapter: hornetq-ra
>13:04:38,232 WARN  [org.jboss.as.ejb3] (MSC service thread 1-8) JBAS014105: ActivationConfigProperty username will be ignored since it is not allowed by resource adapter: hornetq-ra
>13:04:38,232 WARN  [org.jboss.as.ejb3] (MSC service thread 1-8) JBAS014105: ActivationConfigProperty connectionFactory will be ignored since it is not allowed by resource adapter: hornetq-ra
>13:04:38,232 WARN  [org.jboss.as.ejb3] (MSC service thread 1-8) JBAS014105: ActivationConfigProperty channel will be ignored since it is not allowed by resource adapter: hornetq-ra
>13:04:38,233 WARN  [org.jboss.as.ejb3] (MSC service thread 1-8) JBAS014105: ActivationConfigProperty transportType will be ignored since it is not allowed by resource adapter: hornetq-ra
>13:04:38,357 INFO  [org.jboss.as.ejb3] (MSC service thread 1-8) JBAS014142: Started message driven bean 'mdb' with 'hornetq-ra' resource adapter
>13:04:38,375 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 15) BaseTransaction.begin
>13:04:38,375 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 6) BaseTransaction.begin
>13:04:38,377 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 6) StateManager::StateManager( 2, 0 )
>13:04:38,377 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 6) BasicAction::BasicAction()
>13:04:38,377 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 6) BasicAction::Begin() for action-id 0:ffff7f000001:25699049:538efd3e:12
>13:04:38,377 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 6) BasicAction::actionInitialise() for action-id 0:ffff7f000001:25699049:538efd3e:12
>13:04:38,377 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 15) StateManager::StateManager( 2, 0 )
>13:04:38,377 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 15) BasicAction::BasicAction()
>13:04:38,378 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 15) BasicAction::Begin() for action-id 0:ffff7f000001:25699049:538efd3e:13
>13:04:38,378 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 15) BasicAction::actionInitialise() for action-id 0:ffff7f000001:25699049:538efd3e:13
>13:04:38,379 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 15) ActionHierarchy::ActionHierarchy(5)
>13:04:38,379 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 6) ActionHierarchy::ActionHierarchy(5)
>13:04:38,379 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 15) ActionHierarchy::add(0:ffff7f000001:25699049:538efd3e:13, 1)
>13:04:38,380 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 15) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:13 adding Thread[ServerService Thread Pool -- 15,5,ServerService ThreadGroup]
>13:04:38,380 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 6) ActionHierarchy::add(0:ffff7f000001:25699049:538efd3e:12, 1)
>13:04:38,380 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 15) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:13 adding Thread[ServerService Thread Pool -- 15,5,ServerService ThreadGroup] result = true
>13:04:38,380 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 6) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:12 adding Thread[ServerService Thread Pool -- 6,5,ServerService ThreadGroup]
>13:04:38,381 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 15) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:25699049:538efd3e:13 status: ActionStatus.RUNNING, 300 )
>13:04:38,381 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 6) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:12 adding Thread[ServerService Thread Pool -- 6,5,ServerService ThreadGroup] result = true
>13:04:38,381 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 6) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:25699049:538efd3e:12 status: ActionStatus.RUNNING, 300 )
>13:04:38,382 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 15) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:25699049:538efd3e:13 status: ActionStatus.RUNNING, 300 )
>13:04:38,382 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 6) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:25699049:538efd3e:12 status: ActionStatus.RUNNING, 300 )
>13:04:38,382 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) ReaperThread.run ()
>13:04:38,382 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) TransactionReaper::check ()
>13:04:38,382 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) TransactionReaper::check - comparing 1401880178382
>13:04:38,382 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) Thread Thread[Transaction Reaper,5,main] sleeping for 300000
>13:04:38,383 INFO  [org.jboss.as.test.jbossts.common.TransactionStoreBrowserService] (ServerService Thread Pool -- 15) TransactionStoreBrowserService.start
>13:04:38,384 INFO  [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (ServerService Thread Pool -- 6) TestXAResourceRecoveryHelper starting
>13:04:38,386 INFO  [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (ServerService Thread Pool -- 6) Using file /home/ochaloup/Transactions/eap-tests-transactions/integration/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
>13:04:38,389 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 15) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:04:38,389 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 15) BaseTransaction.commit
>13:04:38,389 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 15) TransactionImple.commitAndDisassociate
>13:04:38,389 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 15) BasicAction::End() for action-id 0:ffff7f000001:25699049:538efd3e:13
>13:04:38,390 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 15) BasicAction::End() result for action-id (0:ffff7f000001:25699049:538efd3e:13) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)
>13:04:38,389 INFO  [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (ServerService Thread Pool -- 6) file /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/tx-object-store/TestXAResourceStateStore/TestXAResource.ser does not exists - no data for recovery
>13:04:38,390 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 15) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:13 removing TSThread:1
>13:04:38,390 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 6) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:04:38,390 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 15) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:13 removing TSThread:1 result = true
>13:04:38,390 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 6) BaseTransaction.commit
>13:04:38,390 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 15) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:25699049:538efd3e:13 status: ActionStatus.COMMITTED )
>13:04:38,390 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 6) TransactionImple.commitAndDisassociate
>13:04:38,390 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 6) BasicAction::End() for action-id 0:ffff7f000001:25699049:538efd3e:12
>13:04:38,390 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 6) BasicAction::End() result for action-id (0:ffff7f000001:25699049:538efd3e:12) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)
>13:04:38,391 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 6) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:12 removing TSThread:2
>13:04:38,391 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 6) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:12 removing TSThread:2 result = true
>13:04:38,391 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 6) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:25699049:538efd3e:12 status: ActionStatus.COMMITTED )
>13:04:38,588 INFO  [org.jboss.as.server] (management-handler-thread - 2) JBAS018559: Deployed "crashrecovery-jms.jar" (runtime-name : "crashrecovery-jms.jar")
>13:04:41,103 TRACE [com.arjuna.ats.arjuna] (pool-6-thread-1) InputObjectState::InputObjectState()
>13:04:41,103 TRACE [com.arjuna.ats.arjuna] (pool-6-thread-1) FileSystemStore.allTypes(InputObjectState Uid   : 0:0:0:0:0
>InputObjectState Type  : null
>InputObjectState Size  : 0
>InputObjectState Buffer: )
>13:04:41,103 TRACE [com.arjuna.ats.arjuna] (pool-6-thread-1) OutputObjectState::OutputObjectState()
>13:04:41,235 TRACE [com.arjuna.ats.arjuna] (pool-6-thread-1) InputObjectState::InputObjectState()
>13:04:41,235 TRACE [com.arjuna.ats.arjuna] (pool-6-thread-1) FileSystemStore.allTypes(InputObjectState Uid   : 0:0:0:0:0
>InputObjectState Type  : null
>InputObjectState Size  : 0
>InputObjectState Buffer: )
>13:04:41,236 TRACE [com.arjuna.ats.arjuna] (pool-6-thread-1) OutputObjectState::OutputObjectState()
>13:04:41,245 TRACE [com.arjuna.ats.arjuna] (pool-6-thread-1) InputObjectState::InputObjectState()
>13:04:41,245 TRACE [com.arjuna.ats.arjuna] (pool-6-thread-1) FileSystemStore.allTypes(InputObjectState Uid   : 0:0:0:0:0
>InputObjectState Type  : null
>InputObjectState Size  : 0
>InputObjectState Buffer: )
>13:04:41,246 TRACE [com.arjuna.ats.arjuna] (pool-6-thread-1) OutputObjectState::OutputObjectState()
>13:04:45,622 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) Periodic recovery second pass at Wed, 4 Jun 2014 13:04:45
>13:04:45,622 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState()
>13:04:45,623 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.allObjUids(/StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction, InputObjectState Uid   : 0:0:0:0:0
>InputObjectState Type  : null
>InputObjectState Size  : 0
>InputObjectState Buffer: , -1)
>13:04:45,623 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState()
>13:04:45,624 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.allObjUids(/StateManager/BasicAction/TwoPhaseCoordinator/AtomicActionConnectable, InputObjectState Uid   : 0:0:0:0:0
>InputObjectState Type  : null
>InputObjectState Size  : 40
>InputObjectState Buffer: , -1)
>13:04:45,624 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState()
>13:04:45,624 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
>13:04:45,625 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) AtomicActionRecoveryModule second pass
>13:04:45,625 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
>13:04:45,625 DEBUG [com.arjuna.ats.txoj] (Periodic Recovery) TORecoveryModule - second pass
>13:04:45,625 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
>13:04:45,626 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Local XARecoveryModule - second pass
>13:04:45,626 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Local XARecoveryModule.transactionInitiatedRecovery completed
>13:04:45,627 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Have 0 Xids to recover on this pass.
>13:04:45,627 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids isStale Check RecoveryOnlyEJBXAResource{receiverContext=EJBReceiverContext{clientContext=org.jboss.ejb.client.EJBClientContext@54ef1826, receiver=org.jboss.as.ejb3.remote.LocalEjbReceiver@38838efa}, transactionOriginNodeIdentifier='1'} 1401879870500 1401879885627 false
>13:04:45,627 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Local XARecoveryModule.resourceInitiatedRecovery completed
>13:04:45,628 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
>13:04:45,628 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread Status <== INACTIVE
>13:04:45,628 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread backing off
>13:04:51,596 TRACE [com.arjuna.ats.jta] (EJB default - 1) BaseTransaction.begin
>13:04:51,597 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) StateManager::StateManager( 2, 0 )
>13:04:51,597 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::BasicAction()
>13:04:51,597 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::Begin() for action-id 0:ffff7f000001:25699049:538efd3e:19
>13:04:51,597 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::actionInitialise() for action-id 0:ffff7f000001:25699049:538efd3e:19
>13:04:51,598 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ActionHierarchy::ActionHierarchy(5)
>13:04:51,598 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ActionHierarchy::add(0:ffff7f000001:25699049:538efd3e:19, 1)
>13:04:51,598 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:19 adding Thread[EJB default - 1,5,EJB default]
>13:04:51,598 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:19 adding Thread[EJB default - 1,5,EJB default] result = true
>13:04:51,599 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:25699049:538efd3e:19 status: ActionStatus.RUNNING, 300 )
>13:04:51,599 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:25699049:538efd3e:19 status: ActionStatus.RUNNING, 300 )
>13:04:51,601 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:04:51,602 TRACE [com.arjuna.ats.jta] (EJB default - 1) BaseTransaction.commit
>13:04:51,602 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.commitAndDisassociate
>13:04:51,602 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::End() for action-id 0:ffff7f000001:25699049:538efd3e:19
>13:04:51,602 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::End() result for action-id (0:ffff7f000001:25699049:538efd3e:19) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)
>13:04:51,603 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:19 removing TSThread:3
>13:04:51,603 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:19 removing TSThread:3 result = true
>13:04:51,603 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:25699049:538efd3e:19 status: ActionStatus.COMMITTED )
>13:04:51,606 INFO  [org.jboss.as.test.jbossts.crashrec.common.CrashHelperCommon] (EJB default - 1) wipe out in-doubt txs: wipeOutTxsInDoubt() called
>13:04:51,607 TRACE [com.arjuna.ats.jta] (EJB default - 1) BaseTransaction.begin
>13:04:51,607 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) StateManager::StateManager( 2, 0 )
>13:04:51,607 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::BasicAction()
>13:04:51,607 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::Begin() for action-id 0:ffff7f000001:25699049:538efd3e:1a
>13:04:51,608 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::actionInitialise() for action-id 0:ffff7f000001:25699049:538efd3e:1a
>13:04:51,608 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ActionHierarchy::ActionHierarchy(5)
>13:04:51,608 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ActionHierarchy::add(0:ffff7f000001:25699049:538efd3e:1a, 1)
>13:04:51,608 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:1a adding Thread[EJB default - 1,5,EJB default]
>13:04:51,609 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:1a adding Thread[EJB default - 1,5,EJB default] result = true
>13:04:51,609 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:25699049:538efd3e:1a status: ActionStatus.RUNNING, 300 )
>13:04:51,609 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:25699049:538efd3e:1a status: ActionStatus.RUNNING, 300 )
>13:04:51,612 INFO  [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (EJB default - 1) getXAResources()
>13:04:51,613 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:04:51,613 TRACE [com.arjuna.ats.jta] (EJB default - 1) BaseTransaction.commit
>13:04:51,614 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.commitAndDisassociate
>13:04:51,614 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::End() for action-id 0:ffff7f000001:25699049:538efd3e:1a
>13:04:51,614 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::End() result for action-id (0:ffff7f000001:25699049:538efd3e:1a) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)
>13:04:51,614 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:1a removing TSThread:3
>13:04:51,615 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:1a removing TSThread:3 result = true
>13:04:51,615 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:25699049:538efd3e:1a status: ActionStatus.COMMITTED )
>13:04:51,616 TRACE [com.arjuna.ats.jta] (EJB default - 1) BaseTransaction.begin
>13:04:51,616 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) StateManager::StateManager( 2, 0 )
>13:04:51,616 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::BasicAction()
>13:04:51,616 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::Begin() for action-id 0:ffff7f000001:25699049:538efd3e:1b
>13:04:51,617 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::actionInitialise() for action-id 0:ffff7f000001:25699049:538efd3e:1b
>13:04:51,617 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ActionHierarchy::ActionHierarchy(5)
>13:04:51,617 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ActionHierarchy::add(0:ffff7f000001:25699049:538efd3e:1b, 1)
>13:04:51,617 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:1b adding Thread[EJB default - 1,5,EJB default]
>13:04:51,618 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:1b adding Thread[EJB default - 1,5,EJB default] result = true
>13:04:51,618 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:25699049:538efd3e:1b status: ActionStatus.RUNNING, 300 )
>13:04:51,618 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:25699049:538efd3e:1b status: ActionStatus.RUNNING, 300 )
>13:04:51,618 INFO  [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (EJB default - 1) getXAResources()
>13:04:51,619 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:04:51,619 TRACE [com.arjuna.ats.jta] (EJB default - 1) BaseTransaction.commit
>13:04:51,619 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.commitAndDisassociate
>13:04:51,619 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::End() for action-id 0:ffff7f000001:25699049:538efd3e:1b
>13:04:51,619 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::End() result for action-id (0:ffff7f000001:25699049:538efd3e:1b) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)
>13:04:51,620 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:1b removing TSThread:3
>13:04:51,620 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:1b removing TSThread:3 result = true
>13:04:51,620 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:25699049:538efd3e:1b status: ActionStatus.COMMITTED )
>13:04:51,621 TRACE [com.arjuna.ats.jta] (EJB default - 1) BaseTransaction.begin
>13:04:51,621 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) StateManager::StateManager( 2, 0 )
>13:04:51,621 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::BasicAction()
>13:04:51,621 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::Begin() for action-id 0:ffff7f000001:25699049:538efd3e:1c
>13:04:51,621 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::actionInitialise() for action-id 0:ffff7f000001:25699049:538efd3e:1c
>13:04:51,621 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ActionHierarchy::ActionHierarchy(5)
>13:04:51,622 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ActionHierarchy::add(0:ffff7f000001:25699049:538efd3e:1c, 1)
>13:04:51,622 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:1c adding Thread[EJB default - 1,5,EJB default]
>13:04:51,622 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:1c adding Thread[EJB default - 1,5,EJB default] result = true
>13:04:51,622 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:25699049:538efd3e:1c status: ActionStatus.RUNNING, 300 )
>13:04:51,623 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:25699049:538efd3e:1c status: ActionStatus.RUNNING, 300 )
>13:04:51,623 INFO  [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (EJB default - 1) getXAResources()
>13:04:51,623 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:04:51,623 TRACE [com.arjuna.ats.jta] (EJB default - 1) BaseTransaction.commit
>13:04:51,624 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.commitAndDisassociate
>13:04:51,624 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::End() for action-id 0:ffff7f000001:25699049:538efd3e:1c
>13:04:51,624 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::End() result for action-id (0:ffff7f000001:25699049:538efd3e:1c) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)
>13:04:51,624 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:1c removing TSThread:3
>13:04:51,625 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:1c removing TSThread:3 result = true
>13:04:51,625 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:25699049:538efd3e:1c status: ActionStatus.COMMITTED )
>13:04:51,625 INFO  [org.jboss.as.test.jbossts.common.TestXAResourceRecovered] (EJB default - 1) TestXAResourceRecovered.recover(i=16777216)
>13:04:51,626 INFO  [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (EJB default - 1) recover()
>13:04:51,626 INFO  [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (EJB default - 1) returning 0 Xids
>13:04:51,654 TRACE [com.arjuna.ats.jta] (EJB default - 2) BaseTransaction.begin
>13:04:51,655 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) StateManager::StateManager( 2, 0 )
>13:04:51,655 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::BasicAction()
>13:04:51,655 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::Begin() for action-id 0:ffff7f000001:25699049:538efd3e:1d
>13:04:51,656 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::actionInitialise() for action-id 0:ffff7f000001:25699049:538efd3e:1d
>13:04:51,656 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) ActionHierarchy::ActionHierarchy(5)
>13:04:51,657 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) ActionHierarchy::add(0:ffff7f000001:25699049:538efd3e:1d, 1)
>13:04:51,657 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:1d adding Thread[EJB default - 2,5,EJB default]
>13:04:51,657 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:1d adding Thread[EJB default - 2,5,EJB default] result = true
>13:04:51,658 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:25699049:538efd3e:1d status: ActionStatus.RUNNING, 300 )
>13:04:51,658 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:25699049:538efd3e:1d status: ActionStatus.RUNNING, 300 )
>13:04:51,658 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:04:51,659 TRACE [com.arjuna.ats.jta] (EJB default - 2) BaseTransaction.commit
>13:04:51,659 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImple.commitAndDisassociate
>13:04:51,659 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::End() for action-id 0:ffff7f000001:25699049:538efd3e:1d
>13:04:51,660 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::End() result for action-id (0:ffff7f000001:25699049:538efd3e:1d) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)
>13:04:51,660 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:1d removing TSThread:4
>13:04:51,660 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:1d removing TSThread:4 result = true
>13:04:51,661 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:25699049:538efd3e:1d status: ActionStatus.COMMITTED )
>13:04:51,686 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionSynchronizationRegistryImple.getTransactionKey
>13:04:51,686 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionSynchronizationRegistryImple.getTransactionKey
>13:04:51,747 INFO  [org.jboss.as.test.jbossts.crashrec.common.CrashHelperCommon] (EJB default - 2) There are 0 xids in doubt
>13:04:52,288 TRACE [com.arjuna.ats.jta] (EJB default - 3) BaseTransaction.begin
>13:04:52,289 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) StateManager::StateManager( 2, 0 )
>13:04:52,289 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) BasicAction::BasicAction()
>13:04:52,289 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) BasicAction::Begin() for action-id 0:ffff7f000001:25699049:538efd3e:1e
>13:04:52,289 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) BasicAction::actionInitialise() for action-id 0:ffff7f000001:25699049:538efd3e:1e
>13:04:52,289 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) ActionHierarchy::ActionHierarchy(5)
>13:04:52,289 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) ActionHierarchy::add(0:ffff7f000001:25699049:538efd3e:1e, 1)
>13:04:52,289 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:1e adding Thread[EJB default - 3,5,EJB default]
>13:04:52,290 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:1e adding Thread[EJB default - 3,5,EJB default] result = true
>13:04:52,290 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:25699049:538efd3e:1e status: ActionStatus.RUNNING, 300 )
>13:04:52,290 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:25699049:538efd3e:1e status: ActionStatus.RUNNING, 300 )
>13:04:52,291 TRACE [com.arjuna.ats.jta] (EJB default - 3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:04:52,291 TRACE [com.arjuna.ats.jta] (EJB default - 3) BaseTransaction.commit
>13:04:52,291 TRACE [com.arjuna.ats.jta] (EJB default - 3) TransactionImple.commitAndDisassociate
>13:04:52,291 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) BasicAction::End() for action-id 0:ffff7f000001:25699049:538efd3e:1e
>13:04:52,291 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) BasicAction::End() result for action-id (0:ffff7f000001:25699049:538efd3e:1e) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)
>13:04:52,292 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:1e removing TSThread:5
>13:04:52,292 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:1e removing TSThread:5 result = true
>13:04:52,292 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:25699049:538efd3e:1e status: ActionStatus.COMMITTED )
>13:04:52,293 INFO  [org.jboss.as.test.jbossts.crashrec.jms.MessageHelper] (EJB default - 3) Looking for connection factory java:/JmsXA
>13:04:52,294 TRACE [com.arjuna.ats.jta] (EJB default - 3) TransactionSynchronizationRegistryImple.getTransactionKey
>13:04:52,294 TRACE [com.arjuna.ats.jta] (EJB default - 3) TransactionSynchronizationRegistryImple.getTransactionKey
>13:04:52,298 INFO  [org.jboss.as.test.jbossts.crashrec.jms.MessageHelper] (EJB default - 3) Looking for queue by jndi java:jboss/queue/MDBTriggerQueue or by connection factory lookup on queue queue/MDBTriggerQueue
>13:04:52,305 INFO  [org.jboss.as.test.jbossts.crashrec.jms.MessageHelper] (EJB default - 3) waiting to receive a message from queue/MDBTriggerQueue [queue name on broker: HornetQQueue[queue/MDBTriggerQueue]] ...
>13:04:57,332 INFO  [org.jboss.as.test.jbossts.crashrec.jms.MessageHelper] (EJB default - 4) Looking for connection factory java:/JmsXA
>13:04:57,334 TRACE [com.arjuna.ats.jta] (EJB default - 4) TransactionSynchronizationRegistryImple.getTransactionKey
>13:04:57,336 INFO  [org.jboss.as.test.jbossts.crashrec.jms.MessageHelper] (EJB default - 4) Looking for queue by jndi java:jboss/queue/crashRecoveryQueue or by connection factory lookup on queue queue/crashRecoveryQueue
>13:04:57,341 INFO  [org.jboss.as.test.jbossts.crashrec.jms.MessageHelper] (EJB default - 4) waiting to receive a message from queue/crashRecoveryQueue [queue name on broker: HornetQQueue[queue/crashRecoveryQueue]] ...
>13:05:02,383 TRACE [com.arjuna.ats.jta] (EJB default - 5) BaseTransaction.begin
>13:05:02,384 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) StateManager::StateManager( 2, 0 )
>13:05:02,384 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) BasicAction::BasicAction()
>13:05:02,385 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) BasicAction::Begin() for action-id 0:ffff7f000001:25699049:538efd3e:1f
>13:05:02,385 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) BasicAction::actionInitialise() for action-id 0:ffff7f000001:25699049:538efd3e:1f
>13:05:02,385 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) ActionHierarchy::ActionHierarchy(5)
>13:05:02,386 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) ActionHierarchy::add(0:ffff7f000001:25699049:538efd3e:1f, 1)
>13:05:02,386 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:1f adding Thread[EJB default - 5,5,EJB default]
>13:05:02,386 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:1f adding Thread[EJB default - 5,5,EJB default] result = true
>13:05:02,387 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:25699049:538efd3e:1f status: ActionStatus.RUNNING, 300 )
>13:05:02,387 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:25699049:538efd3e:1f status: ActionStatus.RUNNING, 300 )
>13:05:02,392 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:02,393 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionSynchronizationRegistryImple.getTransactionKey
>13:05:02,394 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionSynchronizationRegistryImple.getResource
>13:05:02,394 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:02,394 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionSynchronizationRegistryImple.putResource
>13:05:02,394 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:02,395 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionSynchronizationRegistryImple.getTransactionKey
>13:05:02,395 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionSynchronizationRegistryImple.getTransactionKey
>13:05:02,395 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionSynchronizationRegistryImple.getResource
>13:05:02,395 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:02,395 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionSynchronizationRegistryImple.getResource
>13:05:02,396 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:02,407 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionSynchronizationRegistryImple.getTransactionKey
>13:05:02,407 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionSynchronizationRegistryImple.getResource
>13:05:02,407 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:02,408 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionSynchronizationRegistryImple.getResource
>13:05:02,408 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:02,409 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionSynchronizationRegistryImple.putResource
>13:05:02,409 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:02,410 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:02,414 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionSynchronizationRegistryImple.registerInterposedSynchronization
>13:05:02,414 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:02,418 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.enlistResource ( XAResourceWrapperImpl@23e9c3df[xaResource=org.hornetq.ra.HornetQRAXAResource@483a77e4 pad=false overrideRmValue=null productName=HornetQ productVersion=2.0 jndiName=java:/JmsXA] )
>13:05:02,419 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:02,419 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) InputObjectState::InputObjectState()
>13:05:02,419 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) FileSystemStore.allObjUids(EISNAME, InputObjectState Uid   : 0:0:0:0:0
>InputObjectState Type  : null
>InputObjectState Size  : 0
>InputObjectState Buffer: , -1)
>13:05:02,420 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) OutputObjectState::OutputObjectState()
>13:05:02,420 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) OutputObjectState::OutputObjectState()
>13:05:02,421 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) FileSystemStore.write_committed(0:ffff7f000001:25699049:538efd3e:23, EISNAME)
>13:05:02,422 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) ShadowingStore.write_state(0:ffff7f000001:25699049:538efd3e:23, EISNAME, StateType.OS_ORIGINAL)
>13:05:02,422 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) ShadowingStore.genPathName(0:ffff7f000001:25699049:538efd3e:23, EISNAME, StateType.OS_ORIGINAL)
>13:05:02,422 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) FileSystemStore.genPathName(0:ffff7f000001:25699049:538efd3e:23, EISNAME, 11)
>13:05:02,424 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) FileSystemStore.openAndLock(/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/tx-object-store/ShadowNoFileLockStore/defaultStore/EISNAME/0_ffff7f000001_25699049_538efd3e_23, FileLock.F_WRLCK, true)
>13:05:02,425 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) FileSystemStore.createHierarchy(/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/tx-object-store/ShadowNoFileLockStore/defaultStore/EISNAME/0_ffff7f000001_25699049_538efd3e_23)
>13:05:02,520 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) FileSystemStore.closeAndUnlock(/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/tx-object-store/ShadowNoFileLockStore/defaultStore/EISNAME/0_ffff7f000001_25699049_538efd3e_23, null, java.io.FileOutputStream@1e673af8)
>13:05:02,530 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) StateManager::StateManager( 1, 0 )
>13:05:02,531 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) AbstractRecord::AbstractRecord (0:ffff7f000001:25699049:538efd3e:25, 1)
>13:05:02,532 TRACE [com.arjuna.ats.jta] (EJB default - 5) XAResourceRecord.XAResourceRecord ( < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:25699049:538efd3e:1f, node_name=1, branch_uid=0:ffff7f000001:25699049:538efd3e:24, subordinatenodename=null, eis_name=java:/JmsXA >, XAResourceWrapperImpl@23e9c3df[xaResource=org.hornetq.ra.HornetQRAXAResource@483a77e4 pad=false overrideRmValue=null productName=HornetQ productVersion=2.0 jndiName=java:/JmsXA] ), record id=0:ffff7f000001:25699049:538efd3e:25
>13:05:02,556 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/XAResourceRecord for 0:ffff7f000001:25699049:538efd3e:25
>13:05:02,558 INFO  [org.jboss.as.test.jbossts.crashrec.jms.MessageHelper] (EJB default - 5) Looking for queue by jndi java:jboss/queue/MDBTriggerQueue or by connection factory lookup on queue queue/MDBTriggerQueue
>13:05:02,585 INFO  [org.jboss.as.test.jbossts.crashrec.jms.MessageHelper] (EJB default - 5) Sending message MDB:none to queue queue/MDBTriggerQueue [queue name on broker: HornetQQueue[queue/MDBTriggerQueue]]
>13:05:02,593 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImpleManager.suspend
>13:05:02,594 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:1f removing TSThread:6
>13:05:02,594 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:1f removing TSThread:6 result = true
>13:05:12,662 TRACE [com.arjuna.ats.jta] (EJB default - 6) TransactionImpleManager.resume
>13:05:12,663 TRACE [com.arjuna.ats.arjuna] (EJB default - 6) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:1f adding Thread[EJB default - 6,5,EJB default]
>13:05:12,664 TRACE [com.arjuna.ats.arjuna] (EJB default - 6) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:1f adding Thread[EJB default - 6,5,EJB default] result = true
>13:05:12,664 TRACE [com.arjuna.ats.jta] (EJB default - 6) BaseTransaction.commit
>13:05:12,664 TRACE [com.arjuna.ats.jta] (EJB default - 6) TransactionImple.commitAndDisassociate
>13:05:12,665 TRACE [com.arjuna.ats.jta] (EJB default - 6) SynchronizationImple.beforeCompletion
>13:05:12,666 TRACE [com.arjuna.ats.arjuna] (EJB default - 6) BasicAction::End() for action-id 0:ffff7f000001:25699049:538efd3e:1f
>13:05:12,666 TRACE [com.arjuna.ats.arjuna] (EJB default - 6) BasicAction::onePhaseCommit() for action-id 0:ffff7f000001:25699049:538efd3e:1f
>13:05:12,667 TRACE [com.arjuna.ats.jta] (EJB default - 6) XAResourceRecord.topLevelOnePhaseCommit for XAResourceRecord < resource:XAResourceWrapperImpl@23e9c3df[xaResource=org.hornetq.ra.HornetQRAXAResource@483a77e4 pad=false overrideRmValue=null productName=HornetQ productVersion=2.0 jndiName=java:/JmsXA], txid:< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:25699049:538efd3e:1f, node_name=1, branch_uid=0:ffff7f000001:25699049:538efd3e:24, subordinatenodename=null, eis_name=java:/JmsXA >, heuristic: TwoPhaseOutcome.FINISH_OK, product: HornetQ/2.0, jndiName: java:/JmsXA com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@6b53108d >, record id=0:ffff7f000001:25699049:538efd3e:25
>13:05:12,742 TRACE [com.arjuna.ats.arjuna] (EJB default - 6) BasicAction::End() result for action-id (0:ffff7f000001:25699049:538efd3e:1f) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)
>13:05:12,744 TRACE [com.arjuna.ats.jta] (EJB default - 6) SynchronizationImple.afterCompletion
>13:05:12,748 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionImpleManager.suspend
>13:05:12,748 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) BaseTransaction.begin
>13:05:12,749 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) StateManager::StateManager( 2, 0 )
>13:05:12,749 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::BasicAction()
>13:05:12,750 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::Begin() for action-id 0:ffff7f000001:25699049:538efd3e:27
>13:05:12,750 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::actionInitialise() for action-id 0:ffff7f000001:25699049:538efd3e:27
>13:05:12,750 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) ActionHierarchy::ActionHierarchy(5)
>13:05:12,750 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) ActionHierarchy::add(0:ffff7f000001:25699049:538efd3e:27, 1)
>13:05:12,751 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:27 adding Thread[Thread-0 (HornetQ-client-global-threads-140932677),5,HornetQ-client-global-threads-140932677]
>13:05:12,751 TRACE [com.arjuna.ats.arjuna] (EJB default - 6) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:1f removing TSThread:7
>13:05:12,751 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:27 adding Thread[Thread-0 (HornetQ-client-global-threads-140932677),5,HornetQ-client-global-threads-140932677] result = true
>13:05:12,751 TRACE [com.arjuna.ats.arjuna] (EJB default - 6) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:1f removing TSThread:7 result = true
>13:05:12,752 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:25699049:538efd3e:27 status: ActionStatus.RUNNING, 300 )
>13:05:12,752 TRACE [com.arjuna.ats.arjuna] (EJB default - 6) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:25699049:538efd3e:1f status: ActionStatus.COMMITTED )
>13:05:12,752 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:25699049:538efd3e:27 status: ActionStatus.RUNNING, 300 )
>13:05:12,753 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionImple.enlistResource ( DelegatingSession [session=ClientSessionImpl [name=05309528-ebd8-11e3-b3ac-a3cc7d7c32ba, username=null, closed=false, factory = ClientSessionFactoryImpl [serverLocator=ServerLocatorImpl [initialConnectors=[TransportConfiguration(name=03eaf5bd-ebd8-11e3-b3ac-a3cc7d7c32ba, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0], discoveryGroupConfiguration=null], connectorConfig=TransportConfiguration(name=03eaf5bd-ebd8-11e3-b3ac-a3cc7d7c32ba, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0, backupConfig=null], metaData=(resource-adapter=inbound,jms-session=,)]@2ae13b5e] )
>13:05:12,754 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:12,755 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) StateManager::StateManager( 1, 0 )
>13:05:12,756 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) AbstractRecord::AbstractRecord (0:ffff7f000001:25699049:538efd3e:29, 1)
>13:05:12,756 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) XAResourceRecord.XAResourceRecord ( < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:25699049:538efd3e:27, node_name=1, branch_uid=0:ffff7f000001:25699049:538efd3e:28, subordinatenodename=null, eis_name=unknown eis name >, DelegatingSession [session=ClientSessionImpl [name=05309528-ebd8-11e3-b3ac-a3cc7d7c32ba, username=null, closed=false, factory = ClientSessionFactoryImpl [serverLocator=ServerLocatorImpl [initialConnectors=[TransportConfiguration(name=03eaf5bd-ebd8-11e3-b3ac-a3cc7d7c32ba, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0], discoveryGroupConfiguration=null], connectorConfig=TransportConfiguration(name=03eaf5bd-ebd8-11e3-b3ac-a3cc7d7c32ba, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0, backupConfig=null], metaData=(resource-adapter=inbound,jms-session=,)]@2ae13b5e] ), record id=0:ffff7f000001:25699049:538efd3e:29
>13:05:12,757 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/XAResourceRecord for 0:ffff7f000001:25699049:538efd3e:29
>13:05:12,763 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionImpleManager.suspend
>13:05:12,763 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:27 removing TSThread:8
>13:05:12,764 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:27 removing TSThread:8 result = true
>13:05:12,764 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) BaseTransaction.begin
>13:05:12,764 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) StateManager::StateManager( 2, 0 )
>13:05:12,765 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::BasicAction()
>13:05:12,765 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::Begin() for action-id 0:ffff7f000001:25699049:538efd3e:2b
>13:05:12,765 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::actionInitialise() for action-id 0:ffff7f000001:25699049:538efd3e:2b
>13:05:12,766 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) ActionHierarchy::ActionHierarchy(5)
>13:05:12,766 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) ActionHierarchy::add(0:ffff7f000001:25699049:538efd3e:2b, 1)
>13:05:12,766 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:2b adding Thread[Thread-0 (HornetQ-client-global-threads-140932677),5,HornetQ-client-global-threads-140932677]
>13:05:12,767 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:2b adding Thread[Thread-0 (HornetQ-client-global-threads-140932677),5,HornetQ-client-global-threads-140932677] result = true
>13:05:12,767 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:25699049:538efd3e:2b status: ActionStatus.RUNNING, 300 )
>13:05:12,767 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:25699049:538efd3e:2b status: ActionStatus.RUNNING, 300 )
>13:05:12,779 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:12,779 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) BaseTransaction.commit
>13:05:12,779 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionImple.commitAndDisassociate
>13:05:12,779 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::End() for action-id 0:ffff7f000001:25699049:538efd3e:2b
>13:05:12,779 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::End() result for action-id (0:ffff7f000001:25699049:538efd3e:2b) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)
>13:05:12,780 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:2b removing TSThread:8
>13:05:12,780 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:2b removing TSThread:8 result = true
>13:05:12,780 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:25699049:538efd3e:2b status: ActionStatus.COMMITTED )
>13:05:12,787 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionImpleManager.resume
>13:05:12,787 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:27 adding Thread[Thread-0 (HornetQ-client-global-threads-140932677),5,HornetQ-client-global-threads-140932677]
>13:05:12,787 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:27 adding Thread[Thread-0 (HornetQ-client-global-threads-140932677),5,HornetQ-client-global-threads-140932677] result = true
>13:05:12,788 INFO  [org.jboss.as.test.jbossts.crashrec.jms.mdb.JMSCrashMessageDrivenBean] (Thread-0 (HornetQ-client-global-threads-140932677)) Receiving message HornetQMessage[ID:139f58cd-ebd8-11e3-b3ac-a3cc7d7c32ba]:PERSISTENT in MDB with text 'MDB:none'
>13:05:12,845 TRACE [com.arjuna.ats.jta] (EJB default - 7) TransactionSynchronizationRegistryImple.getTransactionKey
>13:05:12,847 INFO  [org.jboss.as.test.jbossts.crashrec.common.CrashHelperCommon] (EJB default - 7) There are 0 xids in doubt
>13:05:12,853 INFO  [org.jboss.as.test.jbossts.crashrec.common.CrashBeanCommon] (Thread-0 (HornetQ-client-global-threads-140932677)) CrashBeanCommon.enlistSynchronization
>13:05:12,854 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionImple.registerSynchronization
>13:05:12,855 INFO  [org.jboss.as.test.jbossts.crashrec.common.CrashBeanCommon] (Thread-0 (HornetQ-client-global-threads-140932677)) CrashBeanCommon.enlistXAResource
>13:05:12,855 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionImple.enlistResource ( TestXAResource(TestXAResourceCommon(0, null)) )
>13:05:12,855 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:12,856 INFO  [org.jboss.as.test.jbossts.common.TestXAResourceCommon] (Thread-0 (HornetQ-client-global-threads-140932677)) TestXAResourceCommon.setTransactionTimeout(i=300)
>13:05:12,857 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) StateManager::StateManager( 1, 0 )
>13:05:12,857 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) AbstractRecord::AbstractRecord (0:ffff7f000001:25699049:538efd3e:2e, 1)
>13:05:12,857 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) XAResourceRecord.XAResourceRecord ( < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:25699049:538efd3e:27, node_name=1, branch_uid=0:ffff7f000001:25699049:538efd3e:2d, subordinatenodename=null, eis_name=unknown eis name >, TestXAResource(TestXAResourceCommon(300, null)) ), record id=0:ffff7f000001:25699049:538efd3e:2e
>13:05:12,858 INFO  [org.jboss.as.test.jbossts.common.TestXAResourceCommon] (Thread-0 (HornetQ-client-global-threads-140932677)) TestXAResourceCommon.start(Xid=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:25699049:538efd3e:27, node_name=1, branch_uid=0:ffff7f000001:25699049:538efd3e:2d, subordinatenodename=null, eis_name=unknown eis name >, i=0)
>13:05:12,858 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) RecordList::insert(RecordList: 0:ffff7f000001:25699049:538efd3e:29) : appending /StateManager/AbstractRecord/XAResourceRecord for 0:ffff7f000001:25699049:538efd3e:2e
>13:05:12,859 INFO  [org.jboss.as.test.jbossts.crashrec.common.CrashBeanCommon] (Thread-0 (HornetQ-client-global-threads-140932677)) CrashBeanCommon.beforeEntityUpdate
>13:05:12,859 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:12,859 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionSynchronizationRegistryImple.getTransactionKey
>13:05:12,860 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionSynchronizationRegistryImple.getTransactionKey
>13:05:12,860 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionSynchronizationRegistryImple.getResource
>13:05:12,860 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:12,860 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionSynchronizationRegistryImple.getTransactionKey
>13:05:12,860 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionSynchronizationRegistryImple.getResource
>13:05:12,860 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:12,860 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionSynchronizationRegistryImple.putResource
>13:05:12,860 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:12,861 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionSynchronizationRegistryImple.getResource
>13:05:12,861 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:12,861 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionSynchronizationRegistryImple.getTransactionKey
>13:05:12,861 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionSynchronizationRegistryImple.getResource
>13:05:12,861 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:12,861 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionSynchronizationRegistryImple.getResource
>13:05:12,861 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:12,861 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionSynchronizationRegistryImple.putResource
>13:05:12,861 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:12,862 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:12,862 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionSynchronizationRegistryImple.registerInterposedSynchronization
>13:05:12,862 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:12,862 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionImple.enlistResource ( XAResourceWrapperImpl@23e9c3df[xaResource=org.hornetq.ra.HornetQRAXAResource@483a77e4 pad=false overrideRmValue=null productName=HornetQ productVersion=2.0 jndiName=java:/JmsXA] )
>13:05:12,862 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:12,862 INFO  [org.jboss.as.test.jbossts.common.TestXAResourceCommon] (Thread-0 (HornetQ-client-global-threads-140932677)) TestXAResourceCommon.isSameRM(xaResource=XAResourceWrapperImpl@23e9c3df[xaResource=org.hornetq.ra.HornetQRAXAResource@483a77e4 pad=false overrideRmValue=null productName=HornetQ productVersion=2.0 jndiName=java:/JmsXA]) - returning false
>13:05:12,863 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) StateManager::StateManager( 1, 0 )
>13:05:12,863 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) AbstractRecord::AbstractRecord (0:ffff7f000001:25699049:538efd3e:32, 1)
>13:05:12,863 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) XAResourceRecord.XAResourceRecord ( < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:25699049:538efd3e:27, node_name=1, branch_uid=0:ffff7f000001:25699049:538efd3e:31, subordinatenodename=null, eis_name=java:/JmsXA >, XAResourceWrapperImpl@23e9c3df[xaResource=org.hornetq.ra.HornetQRAXAResource@483a77e4 pad=false overrideRmValue=null productName=HornetQ productVersion=2.0 jndiName=java:/JmsXA] ), record id=0:ffff7f000001:25699049:538efd3e:32
>13:05:12,864 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) RecordList::insert(RecordList: 0:ffff7f000001:25699049:538efd3e:29 0:ffff7f000001:25699049:538efd3e:2e) : appending /StateManager/AbstractRecord/XAResourceRecord for 0:ffff7f000001:25699049:538efd3e:32
>13:05:12,865 INFO  [org.jboss.as.test.jbossts.crashrec.jms.MessageHelper] (Thread-0 (HornetQ-client-global-threads-140932677)) Looking for queue by jndi java:jboss/queue/crashRecoveryQueue or by connection factory lookup on queue queue/crashRecoveryQueue
>13:05:12,868 INFO  [org.jboss.as.test.jbossts.crashrec.jms.MessageHelper] (Thread-0 (HornetQ-client-global-threads-140932677)) Sending message JMSCrashMessageDrivenBean to queue queue/crashRecoveryQueue [queue name on broker: HornetQQueue[queue/crashRecoveryQueue]]
>13:05:12,874 INFO  [org.jboss.as.test.jbossts.crashrec.common.CrashBeanCommon] (Thread-0 (HornetQ-client-global-threads-140932677)) CrashBeanCommon.afterEntityUpdate
>13:05:12,875 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:12,875 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) BaseTransaction.commit
>13:05:12,874 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 62) BaseTransaction.begin
>13:05:12,875 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionImple.commitAndDisassociate
>13:05:12,875 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 62) StateManager::StateManager( 2, 0 )
>13:05:12,875 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) SynchronizationImple.beforeCompletion
>13:05:12,875 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 62) BasicAction::BasicAction()
>13:05:12,876 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) SynchronizationImple.beforeCompletion
>13:05:12,876 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 62) BasicAction::Begin() for action-id 0:ffff7f000001:25699049:538efd3e:34
>13:05:12,876 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::End() for action-id 0:ffff7f000001:25699049:538efd3e:27
>13:05:12,876 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 62) BasicAction::actionInitialise() for action-id 0:ffff7f000001:25699049:538efd3e:34
>13:05:12,876 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::prepare () for action-id 0:ffff7f000001:25699049:538efd3e:27
>13:05:12,876 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 62) ActionHierarchy::ActionHierarchy(5)
>13:05:12,876 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 62) ActionHierarchy::add(0:ffff7f000001:25699049:538efd3e:34, 1)
>13:05:12,876 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) XAResourceRecord.topLevelPrepare for XAResourceRecord < resource:DelegatingSession [session=ClientSessionImpl [name=05309528-ebd8-11e3-b3ac-a3cc7d7c32ba, username=null, closed=false, factory = ClientSessionFactoryImpl [serverLocator=ServerLocatorImpl [initialConnectors=[TransportConfiguration(name=03eaf5bd-ebd8-11e3-b3ac-a3cc7d7c32ba, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0], discoveryGroupConfiguration=null], connectorConfig=TransportConfiguration(name=03eaf5bd-ebd8-11e3-b3ac-a3cc7d7c32ba, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0, backupConfig=null], metaData=(resource-adapter=inbound,jms-session=,)]@2ae13b5e], txid:< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:25699049:538efd3e:27, node_name=1, branch_uid=0:ffff7f000001:25699049:538efd3e:28, subordinatenodename=null, eis_name=unknown eis name >, heuristic: TwoPhaseOutcome.FINISH_OK com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@38622ef6 >, record id=0:ffff7f000001:25699049:538efd3e:29
>13:05:12,876 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 62) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:34 adding Thread[ServerService Thread Pool -- 62,5,ServerService ThreadGroup]
>13:05:12,877 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 62) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:34 adding Thread[ServerService Thread Pool -- 62,5,ServerService ThreadGroup] result = true
>13:05:12,877 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 66) BaseTransaction.begin
>13:05:12,876 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 67) BaseTransaction.begin
>13:05:12,877 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 62) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:25699049:538efd3e:34 status: ActionStatus.RUNNING, 300 )
>13:05:12,877 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) StateManager::StateManager( 2, 0 )
>13:05:12,877 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 62) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:25699049:538efd3e:34 status: ActionStatus.RUNNING, 300 )
>13:05:12,877 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) BasicAction::BasicAction()
>13:05:12,878 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) BasicAction::Begin() for action-id 0:ffff7f000001:25699049:538efd3e:35
>13:05:12,878 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) BasicAction::actionInitialise() for action-id 0:ffff7f000001:25699049:538efd3e:35
>13:05:12,878 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) ActionHierarchy::ActionHierarchy(5)
>13:05:12,878 INFO  [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (ServerService Thread Pool -- 62) TestXAResourceRecoveryHelper stopping
>13:05:12,878 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 62) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:12,878 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 62) BaseTransaction.commit
>13:05:12,878 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 65) BaseTransaction.begin
>13:05:12,878 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 62) TransactionImple.commitAndDisassociate
>13:05:12,879 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) StateManager::StateManager( 2, 0 )
>13:05:12,879 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 62) BasicAction::End() for action-id 0:ffff7f000001:25699049:538efd3e:34
>13:05:12,879 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) BasicAction::BasicAction()
>13:05:12,879 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) BasicAction::Begin() for action-id 0:ffff7f000001:25699049:538efd3e:36
>13:05:12,878 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) ActionHierarchy::add(0:ffff7f000001:25699049:538efd3e:35, 1)
>13:05:12,879 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) StateManager::StateManager( 2, 0 )
>13:05:12,879 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 62) BasicAction::End() result for action-id (0:ffff7f000001:25699049:538efd3e:34) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)
>13:05:12,879 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) BasicAction::BasicAction()
>13:05:12,879 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 62) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:34 removing TSThread:9
>13:05:12,880 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) BasicAction::Begin() for action-id 0:ffff7f000001:25699049:538efd3e:37
>13:05:12,880 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 62) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:34 removing TSThread:9 result = true
>13:05:12,880 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 62) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:25699049:538efd3e:34 status: ActionStatus.COMMITTED )
>13:05:12,880 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:35 adding Thread[ServerService Thread Pool -- 66,5,ServerService ThreadGroup]
>13:05:12,880 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:35 adding Thread[ServerService Thread Pool -- 66,5,ServerService ThreadGroup] result = true
>13:05:12,880 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:25699049:538efd3e:35 status: ActionStatus.RUNNING, 300 )
>13:05:12,879 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 63) BaseTransaction.begin
>13:05:12,881 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) BasicAction::actionInitialise() for action-id 0:ffff7f000001:25699049:538efd3e:36
>13:05:12,881 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:25699049:538efd3e:35 status: ActionStatus.RUNNING, 300 )
>13:05:12,881 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 63) StateManager::StateManager( 2, 0 )
>13:05:12,881 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) ActionHierarchy::ActionHierarchy(5)
>13:05:12,881 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 63) BasicAction::BasicAction()
>13:05:12,881 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) ActionHierarchy::add(0:ffff7f000001:25699049:538efd3e:36, 1)
>13:05:12,881 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 63) BasicAction::Begin() for action-id 0:ffff7f000001:25699049:538efd3e:38
>13:05:12,880 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) BasicAction::actionInitialise() for action-id 0:ffff7f000001:25699049:538efd3e:37
>13:05:12,881 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:36 adding Thread[ServerService Thread Pool -- 65,5,ServerService ThreadGroup]
>13:05:12,882 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 63) BasicAction::actionInitialise() for action-id 0:ffff7f000001:25699049:538efd3e:38
>13:05:12,882 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) ActionHierarchy::ActionHierarchy(5)
>13:05:12,882 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:36 adding Thread[ServerService Thread Pool -- 65,5,ServerService ThreadGroup] result = true
>13:05:12,882 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) ActionHierarchy::add(0:ffff7f000001:25699049:538efd3e:37, 1)
>13:05:12,882 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 63) ActionHierarchy::ActionHierarchy(5)
>13:05:12,882 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:25699049:538efd3e:36 status: ActionStatus.RUNNING, 300 )
>13:05:12,881 INFO  [org.jboss.as.test.jbossts.common.TransactionStoreBrowserService] (ServerService Thread Pool -- 66) TransactionStoreBrowserService.stop
>13:05:12,882 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 63) ActionHierarchy::add(0:ffff7f000001:25699049:538efd3e:38, 1)
>13:05:12,882 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:25699049:538efd3e:36 status: ActionStatus.RUNNING, 300 )
>13:05:12,885 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:37 adding Thread[ServerService Thread Pool -- 67,5,ServerService ThreadGroup]
>13:05:12,885 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 63) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:38 adding Thread[ServerService Thread Pool -- 63,5,ServerService ThreadGroup]
>13:05:12,886 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:37 adding Thread[ServerService Thread Pool -- 67,5,ServerService ThreadGroup] result = true
>13:05:12,886 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 63) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:38 adding Thread[ServerService Thread Pool -- 63,5,ServerService ThreadGroup] result = true
>13:05:12,886 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 63) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:25699049:538efd3e:38 status: ActionStatus.RUNNING, 300 )
>13:05:12,886 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 65) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:12,887 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 65) BaseTransaction.commit
>13:05:12,887 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 65) TransactionImple.commitAndDisassociate
>13:05:12,887 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) BasicAction::End() for action-id 0:ffff7f000001:25699049:538efd3e:36
>13:05:12,887 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) BasicAction::End() result for action-id (0:ffff7f000001:25699049:538efd3e:36) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)
>13:05:12,886 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:25699049:538efd3e:37 status: ActionStatus.RUNNING, 300 )
>13:05:12,887 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 63) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:25699049:538efd3e:38 status: ActionStatus.RUNNING, 300 )
>13:05:12,887 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:36 removing TSThread:b
>13:05:12,888 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:25699049:538efd3e:37 status: ActionStatus.RUNNING, 300 )
>13:05:12,888 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:36 removing TSThread:b result = true
>13:05:12,888 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:25699049:538efd3e:36 status: ActionStatus.COMMITTED )
>13:05:12,888 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 67) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:12,888 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 63) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:12,888 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 63) BaseTransaction.commit
>13:05:12,888 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 67) BaseTransaction.commit
>13:05:12,889 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 63) TransactionImple.commitAndDisassociate
>13:05:12,889 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 67) TransactionImple.commitAndDisassociate
>13:05:12,889 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 63) BasicAction::End() for action-id 0:ffff7f000001:25699049:538efd3e:38
>13:05:12,889 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) BasicAction::End() for action-id 0:ffff7f000001:25699049:538efd3e:37
>13:05:12,889 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 63) BasicAction::End() result for action-id (0:ffff7f000001:25699049:538efd3e:38) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)
>13:05:12,889 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 63) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:38 removing TSThread:d
>13:05:12,889 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) BasicAction::End() result for action-id (0:ffff7f000001:25699049:538efd3e:37) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)
>13:05:12,889 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 63) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:38 removing TSThread:d result = true
>13:05:12,889 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:37 removing TSThread:c
>13:05:12,889 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 63) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:25699049:538efd3e:38 status: ActionStatus.COMMITTED )
>13:05:12,890 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:37 removing TSThread:c result = true
>13:05:12,890 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:25699049:538efd3e:37 status: ActionStatus.COMMITTED )
>13:05:12,891 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 66) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:12,891 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 66) BaseTransaction.commit
>13:05:12,891 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 66) TransactionImple.commitAndDisassociate
>13:05:12,891 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) BasicAction::End() for action-id 0:ffff7f000001:25699049:538efd3e:35
>13:05:12,891 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) BasicAction::End() result for action-id (0:ffff7f000001:25699049:538efd3e:35) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)
>13:05:12,891 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:35 removing TSThread:a
>13:05:12,892 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:35 removing TSThread:a result = true
>13:05:12,892 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:25699049:538efd3e:35 status: ActionStatus.COMMITTED )
>13:05:12,879 WARN  [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) ARJUNA016041: prepare on < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:25699049:538efd3e:27, node_name=1, branch_uid=0:ffff7f000001:25699049:538efd3e:28, subordinatenodename=null, eis_name=unknown eis name > (DelegatingSession [session=ClientSessionImpl [name=05309528-ebd8-11e3-b3ac-a3cc7d7c32ba, username=null, closed=false, factory = ClientSessionFactoryImpl [serverLocator=ServerLocatorImpl [initialConnectors=[TransportConfiguration(name=03eaf5bd-ebd8-11e3-b3ac-a3cc7d7c32ba, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0], discoveryGroupConfiguration=null], connectorConfig=TransportConfiguration(name=03eaf5bd-ebd8-11e3-b3ac-a3cc7d7c32ba, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0, backupConfig=null], metaData=(resource-adapter=inbound,jms-session=,)]@2ae13b5e]) failed with exception -: org.hornetq.api.core.HornetQInterruptedException: java.lang.InterruptedException
>	at org.hornetq.core.protocol.core.impl.ChannelImpl.sendBlocking(ChannelImpl.java:363)
>	at org.hornetq.core.client.impl.ClientSessionImpl.end(ClientSessionImpl.java:1469)
>	at org.hornetq.core.client.impl.DelegatingSession.end(DelegatingSession.java:331)
>	at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelPrepare(XAResourceRecord.java:208) [jbossjts-jacorb-4.17.20.Final-redhat-1.jar:4.17.20.Final-redhat-1]
>	at com.arjuna.ats.arjuna.coordinator.BasicAction.doPrepare(BasicAction.java:2522) [jbossjts-jacorb-4.17.20.Final-redhat-1.jar:4.17.20.Final-redhat-1]
>	at com.arjuna.ats.arjuna.coordinator.BasicAction.doPrepare(BasicAction.java:2489) [jbossjts-jacorb-4.17.20.Final-redhat-1.jar:4.17.20.Final-redhat-1]
>	at com.arjuna.ats.arjuna.coordinator.BasicAction.prepare(BasicAction.java:2066) [jbossjts-jacorb-4.17.20.Final-redhat-1.jar:4.17.20.Final-redhat-1]
>	at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1481) [jbossjts-jacorb-4.17.20.Final-redhat-1.jar:4.17.20.Final-redhat-1]
>	at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:98) [jbossjts-jacorb-4.17.20.Final-redhat-1.jar:4.17.20.Final-redhat-1]
>	at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162) [jbossjts-jacorb-4.17.20.Final-redhat-1.jar:4.17.20.Final-redhat-1]
>	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1189) [jbossjts-jacorb-4.17.20.Final-redhat-1.jar:4.17.20.Final-redhat-1]
>	at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126) [jbossjts-jacorb-4.17.20.Final-redhat-1.jar:4.17.20.Final-redhat-1]
>	at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
>	at org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.afterDelivery(MessageEndpointInvocationHandler.java:72) [jboss-as-ejb3-7.4.0.Final-redhat-13.jar:7.4.0.Final-redhat-13]
>	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_60]
>	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_60]
>	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_60]
>	at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_60]
>	at org.jboss.as.ejb3.inflow.AbstractInvocationHandler.handle(AbstractInvocationHandler.java:60) [jboss-as-ejb3-7.4.0.Final-redhat-13.jar:7.4.0.Final-redhat-13]
>	at org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.doInvoke(MessageEndpointInvocationHandler.java:136) [jboss-as-ejb3-7.4.0.Final-redhat-13.jar:7.4.0.Final-redhat-13]
>	at org.jboss.as.ejb3.inflow.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:73) [jboss-as-ejb3-7.4.0.Final-redhat-13.jar:7.4.0.Final-redhat-13]
>	at com.sun.proxy.$Proxy20.afterDelivery(Unknown Source)
>	at org.hornetq.ra.inflow.HornetQMessageHandler.onMessage(HornetQMessageHandler.java:337)
>	at org.hornetq.core.client.impl.ClientConsumerImpl.callOnMessage(ClientConsumerImpl.java:1117)
>	at org.hornetq.core.client.impl.ClientConsumerImpl.access$500(ClientConsumerImpl.java:57)
>	at org.hornetq.core.client.impl.ClientConsumerImpl$Runner.run(ClientConsumerImpl.java:1252)
>	at org.hornetq.utils.OrderedExecutorFactory$OrderedExecutor$1.run(OrderedExecutorFactory.java:105)
>	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_60]
>	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_60]
>	at java.lang.Thread.run(Thread.java:745) [rt.jar:1.7.0_60]
>Caused by: java.lang.InterruptedException
>	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2164) [rt.jar:1.7.0_60]
>	at org.hornetq.core.protocol.core.impl.ChannelImpl.sendBlocking(ChannelImpl.java:359)
>	... 29 more
>
>13:05:12,895 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::doPrepare() result for action-id (0:ffff7f000001:25699049:538efd3e:27) on record id: (0:ffff7f000001:25699049:538efd3e:29) is (TwoPhaseOutcome.PREPARE_NOTOK) node id: (1)
>13:05:12,895 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) RecordList::insert(RecordList: 0:ffff7f000001:25699049:538efd3e:2e 0:ffff7f000001:25699049:538efd3e:32) : inserting /StateManager/AbstractRecord/XAResourceRecord for 0:ffff7f000001:25699049:538efd3e:29 before /StateManager/AbstractRecord/XAResourceRecord
>13:05:12,895 WARN  [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) ARJUNA012073: BasicAction.End() - prepare phase of action-id 0:ffff7f000001:25699049:538efd3e:27 failed.
>13:05:12,896 WARN  [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) ARJUNA012075: Action Aborting
>13:05:12,896 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::phase2Abort() for action-id 0:ffff7f000001:25699049:538efd3e:27
>13:05:12,896 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::doAbort (XAResourceRecord < resource:DelegatingSession [session=ClientSessionImpl [name=05309528-ebd8-11e3-b3ac-a3cc7d7c32ba, username=null, closed=false, factory = ClientSessionFactoryImpl [serverLocator=ServerLocatorImpl [initialConnectors=[TransportConfiguration(name=03eaf5bd-ebd8-11e3-b3ac-a3cc7d7c32ba, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0], discoveryGroupConfiguration=null], connectorConfig=TransportConfiguration(name=03eaf5bd-ebd8-11e3-b3ac-a3cc7d7c32ba, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0, backupConfig=null], metaData=(resource-adapter=inbound,jms-session=,)]@2ae13b5e], txid:< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:25699049:538efd3e:27, node_name=1, branch_uid=0:ffff7f000001:25699049:538efd3e:28, subordinatenodename=null, eis_name=unknown eis name >, heuristic: TwoPhaseOutcome.FINISH_OK com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@38622ef6 >)
>13:05:12,896 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) XAResourceRecord.topLevelAbort for XAResourceRecord < resource:DelegatingSession [session=ClientSessionImpl [name=05309528-ebd8-11e3-b3ac-a3cc7d7c32ba, username=null, closed=false, factory = ClientSessionFactoryImpl [serverLocator=ServerLocatorImpl [initialConnectors=[TransportConfiguration(name=03eaf5bd-ebd8-11e3-b3ac-a3cc7d7c32ba, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0], discoveryGroupConfiguration=null], connectorConfig=TransportConfiguration(name=03eaf5bd-ebd8-11e3-b3ac-a3cc7d7c32ba, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0, backupConfig=null], metaData=(resource-adapter=inbound,jms-session=,)]@2ae13b5e], txid:< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:25699049:538efd3e:27, node_name=1, branch_uid=0:ffff7f000001:25699049:538efd3e:28, subordinatenodename=null, eis_name=unknown eis name >, heuristic: TwoPhaseOutcome.FINISH_OK com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@38622ef6 >, record id=0:ffff7f000001:25699049:538efd3e:29
>13:05:12,904 WARN  [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) ARJUNA016045: attempted rollback of < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:25699049:538efd3e:27, node_name=1, branch_uid=0:ffff7f000001:25699049:538efd3e:28, subordinatenodename=null, eis_name=unknown eis name > (DelegatingSession [session=ClientSessionImpl [name=05309528-ebd8-11e3-b3ac-a3cc7d7c32ba, username=null, closed=false, factory = ClientSessionFactoryImpl [serverLocator=ServerLocatorImpl [initialConnectors=[TransportConfiguration(name=03eaf5bd-ebd8-11e3-b3ac-a3cc7d7c32ba, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0], discoveryGroupConfiguration=null], connectorConfig=TransportConfiguration(name=03eaf5bd-ebd8-11e3-b3ac-a3cc7d7c32ba, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0, backupConfig=null], metaData=(resource-adapter=inbound,jms-session=,)]@2ae13b5e]) failed with exception code XAException.XAER_PROTO: javax.transaction.xa.XAException
>	at org.hornetq.core.client.impl.ClientSessionImpl.end(ClientSessionImpl.java:1478)
>	at org.hornetq.core.client.impl.DelegatingSession.end(DelegatingSession.java:331)
>	at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelAbort(XAResourceRecord.java:312) [jbossjts-jacorb-4.17.20.Final-redhat-1.jar:4.17.20.Final-redhat-1]
>	at com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:2875) [jbossjts-jacorb-4.17.20.Final-redhat-1.jar:4.17.20.Final-redhat-1]
>	at com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:2854) [jbossjts-jacorb-4.17.20.Final-redhat-1.jar:4.17.20.Final-redhat-1]
>	at com.arjuna.ats.arjuna.coordinator.BasicAction.phase2Abort(BasicAction.java:1924) [jbossjts-jacorb-4.17.20.Final-redhat-1.jar:4.17.20.Final-redhat-1]
>	at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1494) [jbossjts-jacorb-4.17.20.Final-redhat-1.jar:4.17.20.Final-redhat-1]
>	at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:98) [jbossjts-jacorb-4.17.20.Final-redhat-1.jar:4.17.20.Final-redhat-1]
>	at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162) [jbossjts-jacorb-4.17.20.Final-redhat-1.jar:4.17.20.Final-redhat-1]
>	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1189) [jbossjts-jacorb-4.17.20.Final-redhat-1.jar:4.17.20.Final-redhat-1]
>	at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126) [jbossjts-jacorb-4.17.20.Final-redhat-1.jar:4.17.20.Final-redhat-1]
>	at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
>	at org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.afterDelivery(MessageEndpointInvocationHandler.java:72) [jboss-as-ejb3-7.4.0.Final-redhat-13.jar:7.4.0.Final-redhat-13]
>	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_60]
>	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_60]
>	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_60]
>	at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_60]
>	at org.jboss.as.ejb3.inflow.AbstractInvocationHandler.handle(AbstractInvocationHandler.java:60) [jboss-as-ejb3-7.4.0.Final-redhat-13.jar:7.4.0.Final-redhat-13]
>	at org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.doInvoke(MessageEndpointInvocationHandler.java:136) [jboss-as-ejb3-7.4.0.Final-redhat-13.jar:7.4.0.Final-redhat-13]
>	at org.jboss.as.ejb3.inflow.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:73) [jboss-as-ejb3-7.4.0.Final-redhat-13.jar:7.4.0.Final-redhat-13]
>	at com.sun.proxy.$Proxy20.afterDelivery(Unknown Source)
>	at org.hornetq.ra.inflow.HornetQMessageHandler.onMessage(HornetQMessageHandler.java:337)
>	at org.hornetq.core.client.impl.ClientConsumerImpl.callOnMessage(ClientConsumerImpl.java:1117)
>	at org.hornetq.core.client.impl.ClientConsumerImpl.access$500(ClientConsumerImpl.java:57)
>	at org.hornetq.core.client.impl.ClientConsumerImpl$Runner.run(ClientConsumerImpl.java:1252)
>	at org.hornetq.utils.OrderedExecutorFactory$OrderedExecutor$1.run(OrderedExecutorFactory.java:105)
>	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_60]
>	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_60]
>	at java.lang.Thread.run(Thread.java:745) [rt.jar:1.7.0_60]
>
>13:05:12,914 WARN  [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) ARJUNA012091: Top-level abort of action 0:ffff7f000001:25699049:538efd3e:27 received TwoPhaseOutcome.FINISH_ERROR from com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord
>13:05:12,915 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::doAbort() result for action-id (0:ffff7f000001:25699049:538efd3e:27) on record id: (0:ffff7f000001:25699049:538efd3e:29) is (TwoPhaseOutcome.FINISH_ERROR) node id: (1)
>13:05:12,917 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::doAbort (XAResourceRecord < resource:TestXAResource(TestXAResourceCommon(300, < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:25699049:538efd3e:27, node_name=1, branch_uid=0:ffff7f000001:25699049:538efd3e:2d, subordinatenodename=null, eis_name=unknown eis name >)), txid:< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:25699049:538efd3e:27, node_name=1, branch_uid=0:ffff7f000001:25699049:538efd3e:2d, subordinatenodename=null, eis_name=unknown eis name >, heuristic: TwoPhaseOutcome.FINISH_OK com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@28455c84 >)
>13:05:12,917 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) XAResourceRecord.topLevelAbort for XAResourceRecord < resource:TestXAResource(TestXAResourceCommon(300, < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:25699049:538efd3e:27, node_name=1, branch_uid=0:ffff7f000001:25699049:538efd3e:2d, subordinatenodename=null, eis_name=unknown eis name >)), txid:< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:25699049:538efd3e:27, node_name=1, branch_uid=0:ffff7f000001:25699049:538efd3e:2d, subordinatenodename=null, eis_name=unknown eis name >, heuristic: TwoPhaseOutcome.FINISH_OK com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@28455c84 >, record id=0:ffff7f000001:25699049:538efd3e:2e
>13:05:12,917 INFO  [org.jboss.as.test.jbossts.common.TestXAResourceCommon] (Thread-0 (HornetQ-client-global-threads-140932677)) TestXAResourceCommon.end(Xid=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:25699049:538efd3e:27, node_name=1, branch_uid=0:ffff7f000001:25699049:538efd3e:2d, subordinatenodename=null, eis_name=unknown eis name >, b=536870912)
>13:05:12,918 INFO  [org.jboss.as.test.jbossts.common.TestXAResourceCommon] (Thread-0 (HornetQ-client-global-threads-140932677)) TestXAResourceCommon.rollback(Xid=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:25699049:538efd3e:27, node_name=1, branch_uid=0:ffff7f000001:25699049:538efd3e:2d, subordinatenodename=null, eis_name=unknown eis name >)
>13:05:12,919 INFO  [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (Thread-0 (HornetQ-client-global-threads-140932677)) removeLog(xid=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:25699049:538efd3e:27, node_name=1, branch_uid=0:ffff7f000001:25699049:538efd3e:2d, subordinatenodename=null, eis_name=unknown eis name >
>13:05:12,920 INFO  [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (Thread-0 (HornetQ-client-global-threads-140932677)) no log present for < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:25699049:538efd3e:27, node_name=1, branch_uid=0:ffff7f000001:25699049:538efd3e:2d, subordinatenodename=null, eis_name=unknown eis name >
>13:05:12,921 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::doAbort() result for action-id (0:ffff7f000001:25699049:538efd3e:27) on record id: (0:ffff7f000001:25699049:538efd3e:2e) is (TwoPhaseOutcome.FINISH_OK) node id: (1)
>13:05:12,921 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::doAbort (XAResourceRecord < resource:XAResourceWrapperImpl@23e9c3df[xaResource=org.hornetq.ra.HornetQRAXAResource@483a77e4 pad=false overrideRmValue=null productName=HornetQ productVersion=2.0 jndiName=java:/JmsXA], txid:< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:25699049:538efd3e:27, node_name=1, branch_uid=0:ffff7f000001:25699049:538efd3e:31, subordinatenodename=null, eis_name=java:/JmsXA >, heuristic: TwoPhaseOutcome.FINISH_OK, product: HornetQ/2.0, jndiName: java:/JmsXA com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@3f83c17c >)
>13:05:12,922 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) XAResourceRecord.topLevelAbort for XAResourceRecord < resource:XAResourceWrapperImpl@23e9c3df[xaResource=org.hornetq.ra.HornetQRAXAResource@483a77e4 pad=false overrideRmValue=null productName=HornetQ productVersion=2.0 jndiName=java:/JmsXA], txid:< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:25699049:538efd3e:27, node_name=1, branch_uid=0:ffff7f000001:25699049:538efd3e:31, subordinatenodename=null, eis_name=java:/JmsXA >, heuristic: TwoPhaseOutcome.FINISH_OK, product: HornetQ/2.0, jndiName: java:/JmsXA com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@3f83c17c >, record id=0:ffff7f000001:25699049:538efd3e:32
>13:05:12,935 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::doAbort() result for action-id (0:ffff7f000001:25699049:538efd3e:27) on record id: (0:ffff7f000001:25699049:538efd3e:32) is (TwoPhaseOutcome.FINISH_OK) node id: (1)
>13:05:12,936 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::updateState() for action-id 0:ffff7f000001:25699049:538efd3e:27
>13:05:12,936 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::End() result for action-id (0:ffff7f000001:25699049:538efd3e:27) is (TwoPhaseOutcome.FINISH_OK) node id: (1)
>13:05:12,937 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) SynchronizationImple.afterCompletion
>13:05:12,937 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-140932677)) SynchronizationImple.afterCompletion
>13:05:12,938 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:27 removing TSThread:8
>13:05:12,938 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:27 removing TSThread:8 result = true
>13:05:12,938 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-140932677)) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:25699049:538efd3e:27 status: ActionStatus.ABORTED )
>13:05:12,941 WARN  [org.hornetq.ra] (Thread-0 (HornetQ-client-global-threads-140932677)) HQ152006: Unable to call after delivery: javax.resource.spi.LocalTransactionException: javax.transaction.RollbackException: ARJUNA016053: Could not commit transaction.
>	at org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.afterDelivery(MessageEndpointInvocationHandler.java:88)
>	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_60]
>	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_60]
>	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_60]
>	at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_60]
>	at org.jboss.as.ejb3.inflow.AbstractInvocationHandler.handle(AbstractInvocationHandler.java:60)
>	at org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.doInvoke(MessageEndpointInvocationHandler.java:136)
>	at org.jboss.as.ejb3.inflow.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:73)
>	at com.sun.proxy.$Proxy20.afterDelivery(Unknown Source)
>	at org.hornetq.ra.inflow.HornetQMessageHandler.onMessage(HornetQMessageHandler.java:337) [hornetq-ra-2.3.18.Final-redhat-1.jar:2.3.18.Final-redhat-1]
>	at org.hornetq.core.client.impl.ClientConsumerImpl.callOnMessage(ClientConsumerImpl.java:1117) [hornetq-core-client-2.3.18.Final-redhat-1.jar:2.3.18.Final-redhat-1]
>	at org.hornetq.core.client.impl.ClientConsumerImpl.access$500(ClientConsumerImpl.java:57) [hornetq-core-client-2.3.18.Final-redhat-1.jar:2.3.18.Final-redhat-1]
>	at org.hornetq.core.client.impl.ClientConsumerImpl$Runner.run(ClientConsumerImpl.java:1252) [hornetq-core-client-2.3.18.Final-redhat-1.jar:2.3.18.Final-redhat-1]
>	at org.hornetq.utils.OrderedExecutorFactory$OrderedExecutor$1.run(OrderedExecutorFactory.java:105) [hornetq-core-client-2.3.18.Final-redhat-1.jar:2.3.18.Final-redhat-1]
>	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_60]
>	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_60]
>	at java.lang.Thread.run(Thread.java:745) [rt.jar:1.7.0_60]
>Caused by: javax.transaction.RollbackException: ARJUNA016053: Could not commit transaction.
>	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1201) [jbossjts-jacorb-4.17.20.Final-redhat-1.jar:4.17.20.Final-redhat-1]
>	at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126) [jbossjts-jacorb-4.17.20.Final-redhat-1.jar:4.17.20.Final-redhat-1]
>	at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
>	at org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.afterDelivery(MessageEndpointInvocationHandler.java:72)
>	... 16 more
>
>13:05:12,952 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 64) BaseTransaction.begin
>13:05:12,953 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) StateManager::StateManager( 2, 0 )
>13:05:12,953 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) BasicAction::BasicAction()
>13:05:12,953 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) BasicAction::Begin() for action-id 0:ffff7f000001:25699049:538efd3e:39
>13:05:12,953 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) BasicAction::actionInitialise() for action-id 0:ffff7f000001:25699049:538efd3e:39
>13:05:12,954 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) ActionHierarchy::ActionHierarchy(5)
>13:05:12,954 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) ActionHierarchy::add(0:ffff7f000001:25699049:538efd3e:39, 1)
>13:05:12,954 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:39 adding Thread[ServerService Thread Pool -- 64,5,ServerService ThreadGroup]
>13:05:12,955 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) BasicAction::addChildThread () action 0:ffff7f000001:25699049:538efd3e:39 adding Thread[ServerService Thread Pool -- 64,5,ServerService ThreadGroup] result = true
>13:05:12,955 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:25699049:538efd3e:39 status: ActionStatus.RUNNING, 300 )
>13:05:12,955 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:25699049:538efd3e:39 status: ActionStatus.RUNNING, 300 )
>13:05:12,956 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 64) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>13:05:12,956 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 64) BaseTransaction.commit
>13:05:12,956 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 64) TransactionImple.commitAndDisassociate
>13:05:12,956 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) BasicAction::End() for action-id 0:ffff7f000001:25699049:538efd3e:39
>13:05:12,957 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) BasicAction::End() result for action-id (0:ffff7f000001:25699049:538efd3e:39) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)
>13:05:12,957 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:39 removing TSThread:e
>13:05:12,957 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) BasicAction::removeChildThread () action 0:ffff7f000001:25699049:538efd3e:39 removing TSThread:e result = true
>13:05:12,958 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:25699049:538efd3e:39 status: ActionStatus.COMMITTED )
>13:05:12,995 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-1) JBAS015877: Stopped deployment crashrecovery-jms.jar (runtime-name: crashrecovery-jms.jar) in 131ms
>13:05:13,160 INFO  [org.jboss.as.repository] (management-handler-thread - 3) JBAS014901: Content removed from location /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/content/ba/c7d1f4f627bbb61eeab83769c29f9bbe7458fd/content
>13:05:13,161 INFO  [org.jboss.as.server] (management-handler-thread - 3) JBAS018558: Undeployed "crashrecovery-jms.jar" (runtime-name: "crashrecovery-jms.jar")
>13:05:16,224 INFO  [org.apache.coyote.http11.Http11Protocol] (MSC service thread 1-7) JBWEB003075: Coyote HTTP/1.1 pausing on: http-localhost.localdomain/127.0.0.1:8080
>13:05:16,228 INFO  [org.apache.coyote.http11.Http11Protocol] (MSC service thread 1-7) JBWEB003077: Coyote HTTP/1.1 stopping on : http-localhost.localdomain/127.0.0.1:8080
>13:05:16,255 INFO  [org.jboss.as.connector.deployment] (MSC service thread 1-4) JBAS010410: Unbound JCA ConnectionFactory [java:/JmsXA]
>13:05:16,251 INFO  [org.jboss.as.messaging] (ServerService Thread Pool -- 64) JBAS011605: Unbound messaging object to jndi name java:jboss/exported/jms/RemoteConnectionFactory
>13:05:16,253 INFO  [org.apache.catalina.core] (MSC service thread 1-3) JBWEB001079: Container org.apache.catalina.core.ContainerBase.[jboss.web].[default-host].[/] has not been started
>13:05:16,285 INFO  [org.jboss.jaxr] (MSC service thread 1-7) JBAS014002: UnBinding JAXR ConnectionFactory: java:jboss/jaxr/ConnectionFactory
>13:05:16,270 INFO  [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-5) JBAS010409: Unbound data source [java:jboss/datasources/ExampleDS]
>13:05:16,356 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-6) JBAS015877: Stopped deployment dsdriver.jar (runtime-name: dsdriver.jar) in 106ms
>13:05:16,373 INFO  [org.hornetq.ra] (ServerService Thread Pool -- 68) HQ151003: HornetQ resource adaptor stopped
>13:05:16,527 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 68) HQ221002: HornetQ Server version 2.3.18.Final (2.3.18, 123) [00afa0cd-ebd8-11e3-b3ac-a3cc7d7c32ba] stopped
>13:05:16,545 INFO  [com.arjuna.ats.jbossatx] (MSC service thread 1-2) ARJUNA032018: Destroying TransactionManagerService
>13:05:16,556 INFO  [com.arjuna.ats.jbossatx] (MSC service thread 1-4) ARJUNA032014: Stopping transaction recovery manager
>13:05:16,567 DEBUG [com.arjuna.ats.arjuna] (Listener:4712) Recovery listener existing com.arjuna.ats.internal.arjuna.recovery.WorkerService
>13:05:16,567 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-4) PeriodicRecovery: Mode <== TERMINATED
>13:05:16,568 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-4) PeriodicRecovery: shutdown scan wait complete
>13:05:16,568 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread exiting
>13:05:16,576 INFO  [org.jboss.as] (MSC service thread 1-2) JBAS015950: JBoss EAP 6.3.0.Beta2 (AS 7.4.0.Final-redhat-13) stopped in 280ms

Actions: View

Attachments on bug 1082652: 880787 | 880788 | 880789 | 902145