Login
[x]
Log in using an account from:
Fedora Account System
Red Hat Associate
Red Hat Customer
Or login using a Red Hat Bugzilla account
Forgot Password
Login:
Hide Forgot
Create an Account
Red Hat Bugzilla – Attachment 880788 Details for
Bug 1082652
Transaction started in MDB can't be committed when previous transaction was started on client with jboss ejb remoting
[?]
New
Simple Search
Advanced Search
My Links
Browse
Requests
Reports
Current State
Search
Tabular reports
Graphical reports
Duplicates
Other Reports
User Changes
Plotly Reports
Bug Status
Bug Severity
Non-Defaults
|
Product Dashboard
Help
Page Help!
Bug Writing Guidelines
What's new
Browser Support Policy
5.0.4.rh83 Release notes
FAQ
Guides index
User guide
Web Services
Contact
Legal
This site requires JavaScript to be enabled to function correctly, please enable it.
jta requires_new server.log
org.jboss.as.test.jbossts.crashrec.test.JMSMdbCrashRecoveryTestCase_none_jta_server.requires_new.log (text/x-log), 174.30 KB, created by
Ondrej Chaloupka
on 2014-03-31 14:50:56 UTC
(
hide
)
Description:
jta requires_new server.log
Filename:
MIME Type:
Creator:
Ondrej Chaloupka
Created:
2014-03-31 14:50:56 UTC
Size:
174.30 KB
patch
obsolete
>16:42:53,755 INFO [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 36) JBAS010280: Activating Infinispan subsystem. >16:42:53,771 INFO [org.jboss.as.jacorb] (ServerService Thread Pool -- 37) JBAS016300: Activating JacORB Subsystem >16:42:53,804 INFO [org.jboss.as.connector.logging] (MSC service thread 1-7) JBAS010408: Starting JCA Subsystem (IronJacamar 1.0.24.Final) >16:42:53,810 INFO [org.jboss.as.naming] (ServerService Thread Pool -- 48) JBAS011800: Activating Naming Subsystem >16:42:53,821 INFO [org.jboss.as.jsf] (ServerService Thread Pool -- 44) JBAS012605: Activated the following JSF Implementations: [main, 1.2] >16:42:53,829 INFO [org.jboss.as.security] (ServerService Thread Pool -- 54) JBAS013171: Activating Security Subsystem >16:42:53,841 WARN [org.jboss.as.txn] (ServerService Thread Pool -- 56) JBAS010153: Node identifier property is set to the default value. Please make sure it is unique. >16:42:53,845 INFO [org.jboss.as.security] (MSC service thread 1-3) JBAS013170: Current PicketBox version=4.0.19.SP5 >16:42:53,882 INFO [org.jboss.as.connector.subsystems.datasources] (ServerService Thread Pool -- 32) JBAS010403: Deploying JDBC-compliant driver class org.h2.Driver (version 1.3) >16:42:53,889 INFO [org.jboss.as.webservices] (ServerService Thread Pool -- 58) JBAS015537: Activating WebServices Extension >16:42:53,927 INFO [org.jboss.as.naming] (MSC service thread 1-3) JBAS011802: Starting Naming Service >16:42:53,928 INFO [org.jboss.as.mail.extension] (MSC service thread 1-6) JBAS015400: Bound mail session [java:jboss/mail/Default] >16:42:53,977 INFO [org.jboss.jaxr] (MSC service thread 1-4) JBAS014000: Started JAXR subsystem, binding JAXR connection factory into JNDI as: java:jboss/jaxr/ConnectionFactory >16:42:54,299 INFO [com.arjuna.ats.jbossatx] (MSC service thread 1-8) ARJUNA032010: JBossTS Recovery Service (tag: 430b320d1e2bb4b97bd2226c29c36953d5939c4c) - JBoss Inc. >16:42:54,383 INFO [com.arjuna.ats.arjuna] (MSC service thread 1-8) ARJUNA012324: Start RecoveryActivators >16:42:54,384 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-8) Expiry scan interval set to 43200 seconds >16:42:54,384 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) Loading class com.arjuna.ats.internal.arjuna.recovery.ExpiredTransactionStatusManagerScanner >16:42:54,385 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-8) Expiry scan interval set to 43200 seconds >16:42:54,385 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-8) ExpiredTransactionStatusManagerScanner created, with expiry time of 43200 seconds >16:42:54,386 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) Loading class com.arjuna.ats.internal.arjuna.objectstore.ShadowNoFileLockStore >16:42:54,388 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) FileSystemStore.createHierarchy(/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/tx-object-store/ShadowNoFileLockStore/defaultStore/) >16:42:54,390 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-8) ExpiredEntryMonitor - constructed >16:42:54,399 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) Loading class com.arjuna.ats.internal.jta.recovery.arjunacore.CommitMarkableResourceRecordRecoveryModule >16:42:54,399 INFO [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) ARJUNA012296: ExpiredEntryMonitor running at Mon, 31 Mar 2014 16:42:54 >16:42:54,461 DEBUG [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) ExpiredTransactionStatusManagerScanner - scanning to remove items from before Mon, 31 Mar 2014 04:42:54 >16:42:54,461 TRACE [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) InputObjectState::InputObjectState() >16:42:54,396 INFO [org.apache.coyote.http11.Http11NioProtocol] (MSC service thread 1-3) JBWEB003001: Coyote HTTP/1.1 initializing on : http-localhost.localdomain/127.0.0.1:8080 >16:42:54,458 INFO [org.jboss.as.jacorb] (MSC service thread 1-7) JBAS016330: CORBA ORB Service started >16:42:54,473 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) >16:42:54,474 TRACE [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) OutputObjectState::OutputObjectState() >16:42:54,482 DEBUG [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) >16:42:54,491 INFO [org.apache.coyote.http11.Http11NioProtocol] (MSC service thread 1-3) JBWEB003000: Coyote HTTP/1.1 starting on: http-localhost.localdomain/127.0.0.1:8080 >16:42:54,502 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) Loading class com.arjuna.ats.internal.arjuna.coordinator.CheckedActionFactoryImple >16:42:54,503 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) StateManager::StateManager( 2, 0 ) >16:42:54,503 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) BasicAction::BasicAction() >16:42:54,509 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) InputObjectState::InputObjectState() >16:42:54,510 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) FileSystemStore.allObjUids(/Recovery/TransactionStatusManager, InputObjectState Uid : 0:0:0:0:0 >InputObjectState Type : null >InputObjectState Size : 0 >InputObjectState Buffer: , -1) >16:42:54,510 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) OutputObjectState::OutputObjectState() >16:42:54,510 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) Loading class com.arjuna.ats.internal.arjuna.recovery.AtomicActionRecoveryModule >16:42:54,511 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) StateManager::StateManager( 2, 0 ) >16:42:54,511 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) BasicAction::BasicAction() >16:42:54,511 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-8) AtomicActionRecoveryModule created >16:42:54,511 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) InputObjectState::InputObjectState() >16:42:54,511 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) FileSystemStore.allObjUids(/Recovery/TransactionStatusManager, InputObjectState Uid : 0:0:0:0:0 >InputObjectState Type : null >InputObjectState Size : 0 >InputObjectState Buffer: , -1) >16:42:54,511 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) OutputObjectState::OutputObjectState() >16:42:54,512 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) Loading class com.arjuna.ats.internal.txoj.recovery.TORecoveryModule >16:42:54,519 DEBUG [com.arjuna.ats.txoj] (MSC service thread 1-8) TORecoveryModule created >16:42:54,519 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) Loading class com.arjuna.ats.internal.arjuna.objectstore.ShadowNoFileLockStore >16:42:54,520 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) FileSystemStore.createHierarchy(/home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/tx-object-store/ShadowNoFileLockStore/defaultStore/) >16:42:54,520 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) Loading class com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule >16:42:54,527 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) InputObjectState::InputObjectState() >16:42:54,528 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) Loading class com.arjuna.ats.internal.jta.recovery.arjunacore.JTATransactionLogXAResourceOrphanFilter >16:42:54,528 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) Loading class com.arjuna.ats.internal.jta.recovery.arjunacore.JTANodeNameXAResourceOrphanFilter >16:42:54,528 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-8) Loading class com.arjuna.ats.internal.jta.recovery.arjunacore.SubordinateJTAXAResourceOrphanFilter >16:42:54,530 INFO [com.arjuna.ats.arjuna] (MSC service thread 1-8) ARJUNA012343: RecoveryManagerImple is ready. Socket listener is turned off. >16:42:54,530 INFO [com.arjuna.ats.jbossatx] (MSC service thread 1-8) ARJUNA032013: Starting transaction recovery manager >16:42:54,534 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread Status <== SCANNING >16:42:54,534 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread scanning >16:42:54,534 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) Periodic recovery first pass at Mon, 31 Mar 2014 16:42:54 >16:42:54,535 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) ObjectStoreDir: /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/tx-object-store >16:42:54,535 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) StateManager::StateManager( 2, 0 ) >16:42:54,535 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) BasicAction::BasicAction() >16:42:54,538 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) CommitMarkableResourceRecordRecoveryModule::periodicWorkFirstPass >16:42:54,538 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState() >16:42:54,539 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) >16:42:54,539 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState() >16:42:54,539 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) processing /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction transactions >16:42:54,539 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState() >16:42:54,539 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) >16:42:54,539 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState() >16:42:54,539 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) >16:42:54,539 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState() >16:42:54,540 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) AtomicActionRecoveryModule first pass >16:42:54,540 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) >16:42:54,540 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState() >16:42:54,540 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) processing /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction transactions >16:42:54,540 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) >16:42:54,540 DEBUG [com.arjuna.ats.txoj] (Periodic Recovery) TORecoveryModule - first pass >16:42:54,540 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState() >16:42:54,540 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.allTypes(InputObjectState Uid : 0:0:0:0:0 >InputObjectState Type : null >InputObjectState Size : 0 >InputObjectState Buffer: ) >16:42:54,540 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState() >16:42:54,541 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) >16:42:54,543 INFO [org.jboss.ws.common.management] (MSC service thread 1-5) JBWS022052: Starting JBoss Web Services - Stack CXF Server 4.3.0.Final >16:42:54,545 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Local XARecoveryModule - first pass >16:42:54,545 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState() >16:42:54,548 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) >16:42:54,548 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState() >16:42:54,557 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 60) 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) >16:42:54,558 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221006: Waiting to obtain live lock >16:42:54,562 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) StateManager::StateManager( 0:0:0:0:0 ) >16:42:54,562 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) BasicAction::BasicAction(0:0:0:0:0) >16:42:54,565 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) xarecovery of RecoveryOnlyEJBXAResource{receiverContext=EJBReceiverContext{clientContext=org.jboss.ejb.client.EJBClientContext@3db31a82, receiver=org.jboss.as.ejb3.remote.LocalEjbReceiver@70d5ca2}, transactionOriginNodeIdentifier='1'} >16:42:54,577 TRACE [com.arjuna.ats.jts] (MSC service thread 1-1) ArjunaTransactionImple::ArjunaTransactionImple ( 0:0:0:0:0 ) >16:42:54,583 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 >16:42:54,585 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) Loading class com.arjuna.ats.jbossatx.jta.TransactionManagerDelegate >16:42:54,590 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Found 0 xids in doubt >16:42:54,591 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids new recoveryXids RecoveryOnlyEJBXAResource{receiverContext=EJBReceiverContext{clientContext=org.jboss.ejb.client.EJBClientContext@3db31a82, receiver=org.jboss.as.ejb3.remote.LocalEjbReceiver@70d5ca2}, transactionOriginNodeIdentifier='1'} 1396276974591 >16:42:54,592 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) >16:42:54,592 INFO [org.jboss.as.remoting] (MSC service thread 1-3) JBAS017100: Listening on 127.0.0.1:9999 >16:42:54,593 INFO [org.jboss.as.server.deployment] (MSC service thread 1-2) JBAS015876: Starting deployment of "dsdriver.jar" (runtime-name: "dsdriver.jar") >16:42:54,595 INFO [com.arjuna.ats.jbossatx] (MSC service thread 1-1) ARJUNA032017: JBossTS Transaction Service (JTA version - tag: 430b320d1e2bb4b97bd2226c29c36953d5939c4c) - JBoss Inc. >16:42:54,597 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) TransactionReaper::instantiate() >16:42:54,598 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) TransactionReaper::TransactionReaper ( 9223372036854775807 ) >16:42:54,598 INFO [org.jboss.as.remoting] (MSC service thread 1-4) JBAS017100: Listening on 127.0.0.1:4447 >16:42:54,601 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) ReaperThread.run () >16:42:54,601 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ReaperWorkerThread.run () >16:42:54,602 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) Thread Thread[Transaction Reaper Worker 0,5,main] waiting for cancelled TXs >16:42:54,602 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) Thread Thread[Transaction Reaper,5,main] sleeping for 9223370640577801205 >16:42:54,604 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-1) registering bean jboss.jta:type=ObjectStore >16:42:54,655 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221013: Using NIO Journal >16:42:54,692 INFO [org.jboss.as.jacorb] (MSC service thread 1-6) JBAS016328: CORBA Naming Service started >16:42:54,720 INFO [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-1) JBAS010400: Bound data source [java:jboss/datasources/ExampleDS] >16:42:54,834 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221034: Waiting to obtain live lock >16:42:54,834 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221035: Live Server Obtained live lock >16:42:55,044 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) >16:42:55,544 TRACE [com.arjuna.ats.jts] (Finalizer) ArjunaTransactionImple.finalize - called for < 0:0:0:0:0 > >16:42:55,545 TRACE [com.arjuna.ats.arjuna] (Finalizer) BasicAction::finalize() >16:42:56,248 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221020: Started Netty Acceptor version 3.6.7.Final-99b1b26 127.0.0.1:5455 for CORE protocol >16:42:56,250 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221020: Started Netty Acceptor version 3.6.7.Final-99b1b26 127.0.0.1:5445 for CORE protocol >16:42:56,252 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221007: Server is now live >16:42:56,252 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221001: HornetQ Server version 2.3.18.Final (2.3.18, 123) [be3d1309-b8e2-11e3-b69d-9962638eac79] >16:42:56,255 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221003: trying to deploy queue jms.queue.DLQ >16:42:56,333 INFO [org.jboss.as.connector.deployment] (MSC service thread 1-4) JBAS010406: Registered connection factory java:/JmsXA >16:42:56,336 INFO [org.jboss.as.messaging] (ServerService Thread Pool -- 60) JBAS011601: Bound messaging object to jndi name java:/jms/queue/DLQ >16:42:56,346 INFO [org.jboss.as.messaging] (ServerService Thread Pool -- 62) JBAS011601: Bound messaging object to jndi name java:jboss/exported/jms/RemoteConnectionFactory >16:42:56,351 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 63) HQ221003: trying to deploy queue jms.queue.ExpiryQueue >16:42:56,356 INFO [org.jboss.as.messaging] (ServerService Thread Pool -- 63) JBAS011601: Bound messaging object to jndi name java:/jms/queue/ExpiryQueue >16:42:56,357 INFO [org.jboss.as.messaging] (ServerService Thread Pool -- 61) JBAS011601: Bound messaging object to jndi name java:/ConnectionFactory >16:42:56,367 INFO [org.hornetq.ra] (MSC service thread 1-4) HornetQ resource adaptor started >16:42:56,367 INFO [org.jboss.as.connector.services.resourceadapters.ResourceAdapterActivatorService$ResourceAdapterActivator] (MSC service thread 1-4) IJ020002: Deployed: file://RaActivatorhornetq-ra >16:42:56,369 INFO [org.jboss.as.connector.deployment] (MSC service thread 1-4) JBAS010401: Bound JCA ConnectionFactory [java:/JmsXA] >16:42:56,405 INFO [org.jboss.as.server] (ServerService Thread Pool -- 33) JBAS018559: Deployed "dsdriver.jar" (runtime-name : "dsdriver.jar") >16:42:56,548 INFO [org.jboss.as] (Controller Boot Thread) JBAS015961: Http management interface listening on http://127.0.0.1:9990/management >16:42:56,550 INFO [org.jboss.as] (Controller Boot Thread) JBAS015951: Admin console listening on http://127.0.0.1:9990 >16:42:56,551 INFO [org.jboss.as] (Controller Boot Thread) JBAS015874: JBoss EAP 6.3.0.Alpha2 (AS 7.4.0.Final-redhat-6) started in 4652ms - Started 231 of 268 services (71 services are lazy, passive or on-demand) >16:42:58,643 INFO [org.apache.catalina.core] (MSC service thread 1-6) JBWEB001079: Container org.apache.catalina.core.ContainerBase.[jboss.web].[default-host].[/] has not been started >16:42:58,646 INFO [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-3) JBAS010409: Unbound data source [java:jboss/datasources/ExampleDS] >16:42:58,649 INFO [org.jboss.as.connector.deployment] (MSC service thread 1-3) JBAS010410: Unbound JCA ConnectionFactory [java:/JmsXA] >16:42:58,651 INFO [org.jboss.jaxr] (MSC service thread 1-1) JBAS014002: UnBinding JAXR ConnectionFactory: java:jboss/jaxr/ConnectionFactory >16:42:58,658 INFO [org.jboss.as.messaging] (ServerService Thread Pool -- 11) JBAS011605: Unbound messaging object to jndi name java:/jms/queue/ExpiryQueue >16:42:58,669 INFO [org.jboss.as.server.deployment] (MSC service thread 1-4) JBAS015877: Stopped deployment dsdriver.jar (runtime-name: dsdriver.jar) in 32ms >16:42:58,670 INFO [org.jboss.as.messaging] (ServerService Thread Pool -- 30) JBAS011605: Unbound messaging object to jndi name java:/ConnectionFactory >16:42:58,674 INFO [org.apache.coyote.http11.Http11NioProtocol] (MSC service thread 1-2) JBWEB003075: Coyote HTTP/1.1 pausing on: http-localhost.localdomain/127.0.0.1:8080 >16:42:58,674 INFO [org.apache.coyote.http11.Http11NioProtocol] (MSC service thread 1-2) JBWEB003077: Coyote HTTP/1.1 stopping on : http-localhost.localdomain/127.0.0.1:8080 >16:42:58,677 INFO [org.jboss.as.messaging] (ServerService Thread Pool -- 29) JBAS011605: Unbound messaging object to jndi name java:jboss/exported/jms/RemoteConnectionFactory >16:42:58,680 INFO [org.jboss.as.messaging] (ServerService Thread Pool -- 16) JBAS011605: Unbound messaging object to jndi name java:/jms/queue/DLQ >16:42:58,692 INFO [org.hornetq.ra] (ServerService Thread Pool -- 12) HQ151003: HornetQ resource adaptor stopped >16:42:58,696 INFO [com.arjuna.ats.jbossatx] (MSC service thread 1-7) ARJUNA032018: Destroying TransactionManagerService >16:42:58,697 INFO [com.arjuna.ats.jbossatx] (MSC service thread 1-8) ARJUNA032014: Stopping transaction recovery manager >16:42:58,698 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-8) PeriodicRecovery: Mode <== TERMINATED >16:42:58,698 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-8) PeriodicRecovery: shutdown waiting for scan to end >16:42:58,698 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: scan TERMINATED at phase 1 >16:42:58,698 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread Status <== INACTIVE >16:42:58,698 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread exiting >16:42:58,698 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-8) PeriodicRecovery: shutdown scan wait complete >16:42:58,801 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 12) HQ221002: HornetQ Server version 2.3.18.Final (2.3.18, 123) [be3d1309-b8e2-11e3-b69d-9962638eac79] stopped >16:42:58,810 INFO [org.jboss.as.mail.extension] (MSC service thread 1-4) JBAS015401: Unbound mail session [java:jboss/mail/Default] >16:42:58,817 INFO [org.jboss.as] (MSC service thread 1-3) JBAS015950: JBoss EAP 6.3.0.Alpha2 (AS 7.4.0.Final-redhat-6) stopped in 182ms >16:42:58,818 INFO [org.jboss.as] (MSC service thread 1-8) JBAS015899: JBoss EAP 6.3.0.Alpha2 (AS 7.4.0.Final-redhat-6) starting >16:42:58,818 DEBUG [org.jboss.as.config] (MSC service thread 1-8) 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 = /usr/lib/jvm/java-1.7.0-openjdk-1.7.0.60-2.4.5.1.fc20.x86_64/jre/lib/endorsed > java.ext.dirs = /usr/lib/jvm/java-1.7.0-openjdk-1.7.0.60-2.4.5.1.fc20.x86_64/jre/lib/ext:/usr/java/packages/lib/ext > java.home = /usr/lib/jvm/java-1.7.0-openjdk-1.7.0.60-2.4.5.1.fc20.x86_64/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 = OpenJDK Runtime Environment > java.runtime.version = 1.7.0_51-mockbuild_2014_01_31_16_21-b00 > 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_51 > java.vm.info = mixed mode > java.vm.name = OpenJDK 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.51-b03 > 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.DR6/bundles > jboss.dist = /home/ochaloup/jboss/jboss-eap-6.3.0.DR6 > 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.DR6/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.13.6-200.fc20.x86_64 > path.separator = : > sun.arch.data.model = 64 > sun.boot.class.path = /usr/lib/jvm/java-1.7.0-openjdk-1.7.0.60-2.4.5.1.fc20.x86_64/jre/lib/resources.jar:/usr/lib/jvm/java-1.7.0-openjdk-1.7.0.60-2.4.5.1.fc20.x86_64/jre/lib/rt.jar:/usr/lib/jvm/java-1.7.0-openjdk-1.7.0.60-2.4.5.1.fc20.x86_64/jre/lib/sunrsasign.jar:/usr/lib/jvm/java-1.7.0-openjdk-1.7.0.60-2.4.5.1.fc20.x86_64/jre/lib/jsse.jar:/usr/lib/jvm/java-1.7.0-openjdk-1.7.0.60-2.4.5.1.fc20.x86_64/jre/lib/jce.jar:/usr/lib/jvm/java-1.7.0-openjdk-1.7.0.60-2.4.5.1.fc20.x86_64/jre/lib/charsets.jar:/usr/lib/jvm/java-1.7.0-openjdk-1.7.0.60-2.4.5.1.fc20.x86_64/jre/lib/netx.jar:/usr/lib/jvm/java-1.7.0-openjdk-1.7.0.60-2.4.5.1.fc20.x86_64/jre/lib/plugin.jar:/usr/lib/jvm/java-1.7.0-openjdk-1.7.0.60-2.4.5.1.fc20.x86_64/jre/lib/rhino.jar:/usr/lib/jvm/java-1.7.0-openjdk-1.7.0.60-2.4.5.1.fc20.x86_64/jre/lib/jfr.jar:/usr/lib/jvm/java-1.7.0-openjdk-1.7.0.60-2.4.5.1.fc20.x86_64/jre/classes > sun.boot.library.path = /usr/lib/jvm/java-1.7.0-openjdk-1.7.0.60-2.4.5.1.fc20.x86_64/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.DR6/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 >16:42:58,819 DEBUG [org.jboss.as.config] (MSC service thread 1-8) VM Arguments: -Xmx1303m -XX:MaxPermSize=256m -Djboss.dist=/home/ochaloup/jboss/jboss-eap-6.3.0.DR6 -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.DR6 -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.DR6/bundles >16:42:58,939 INFO [org.jboss.as.server] (Controller Boot Thread) JBAS015888: Creating http management service using socket-binding (management-http) >16:42:58,949 INFO [org.jboss.as.jacorb] (ServerService Thread Pool -- 37) JBAS016300: Activating JacORB Subsystem >16:42:58,949 INFO [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 36) JBAS010280: Activating Infinispan subsystem. >16:42:58,951 INFO [org.jboss.as.connector.subsystems.datasources] (ServerService Thread Pool -- 32) JBAS010403: Deploying JDBC-compliant driver class org.h2.Driver (version 1.3) >16:42:58,953 INFO [org.jboss.as.connector.logging] (MSC service thread 1-4) JBAS010408: Starting JCA Subsystem (IronJacamar 1.0.24.Final) >16:42:58,974 INFO [org.jboss.as.jacorb] (MSC service thread 1-2) JBAS016330: CORBA ORB Service started >16:42:58,979 INFO [org.jboss.as.naming] (ServerService Thread Pool -- 48) JBAS011800: Activating Naming Subsystem >16:42:58,981 INFO [org.jboss.jaxr] (MSC service thread 1-3) JBAS014000: Started JAXR subsystem, binding JAXR connection factory into JNDI as: java:jboss/jaxr/ConnectionFactory >16:42:58,982 INFO [org.jboss.as.naming] (MSC service thread 1-3) JBAS011802: Starting Naming Service >16:42:58,983 INFO [org.jboss.as.mail.extension] (MSC service thread 1-3) JBAS015400: Bound mail session [java:jboss/mail/Default] >16:42:58,989 INFO [org.jboss.as.security] (ServerService Thread Pool -- 54) JBAS013171: Activating Security Subsystem >16:42:58,990 INFO [org.jboss.as.security] (MSC service thread 1-4) JBAS013170: Current PicketBox version=4.0.19.SP5 >16:42:58,996 WARN [org.jboss.as.txn] (ServerService Thread Pool -- 56) JBAS010153: Node identifier property is set to the default value. Please make sure it is unique. >16:42:59,006 INFO [org.jboss.as.webservices] (ServerService Thread Pool -- 58) JBAS015537: Activating WebServices Extension >16:42:59,021 INFO [com.arjuna.ats.jbossatx] (MSC service thread 1-5) ARJUNA032010: JBossTS Recovery Service (tag: 430b320d1e2bb4b97bd2226c29c36953d5939c4c) - JBoss Inc. >16:42:59,021 INFO [com.arjuna.ats.jbossatx] (MSC service thread 1-5) ARJUNA032013: Starting transaction recovery manager >16:42:59,021 INFO [com.arjuna.ats.arjuna] (MSC service thread 1-5) ARJUNA012324: Start RecoveryActivators >16:42:59,022 INFO [org.jboss.ws.common.management] (MSC service thread 1-1) JBWS022052: Starting JBoss Web Services - Stack CXF Server 4.3.0.Final >16:42:59,028 INFO [org.apache.coyote.http11.Http11NioProtocol] (MSC service thread 1-8) JBWEB003001: Coyote HTTP/1.1 initializing on : http-localhost.localdomain/127.0.0.1:8080 >16:42:59,030 INFO [org.apache.coyote.http11.Http11NioProtocol] (MSC service thread 1-8) JBWEB003000: Coyote HTTP/1.1 starting on: http-localhost.localdomain/127.0.0.1:8080 >16:42:59,034 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-5) ExpiredEntryMonitor - constructed >16:42:59,034 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 60) 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) >16:42:59,035 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221006: Waiting to obtain live lock >16:42:59,035 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221013: Using NIO Journal >16:42:59,042 INFO [com.arjuna.ats.arjuna] (MSC service thread 1-5) ARJUNA012310: Recovery manager listening on endpoint 127.0.0.1:4712 >16:42:59,042 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-5) PeriodicRecovery: starting listener worker thread >16:42:59,043 INFO [com.arjuna.ats.arjuna] (MSC service thread 1-5) ARJUNA012344: RecoveryManagerImple is ready on port 4712 >16:42:59,046 INFO [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) ARJUNA012296: ExpiredEntryMonitor running at Mon, 31 Mar 2014 16:42:59 >16:42:59,051 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread Status <== SCANNING >16:42:59,052 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread scanning >16:42:59,056 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) Periodic recovery first pass at Mon, 31 Mar 2014 16:42:59 >16:42:59,057 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-3) ObjectStoreDir: /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/tx-object-store >16:42:59,056 DEBUG [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) ExpiredTransactionStatusManagerScanner - scanning to remove items from before Mon, 31 Mar 2014 04:42:59 >16:42:59,057 TRACE [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) InputObjectState::InputObjectState() >16:42:59,057 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-3) StateManager::StateManager( 2, 0 ) >16:42:59,057 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) >16:42:59,057 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-3) BasicAction::BasicAction() >16:42:59,057 TRACE [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) OutputObjectState::OutputObjectState() >16:42:59,057 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-3) StateManager::StateManager( 0:0:0:0:0 ) >16:42:59,057 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-3) BasicAction::BasicAction(0:0:0:0:0) >16:42:59,057 DEBUG [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) >16:42:59,057 TRACE [com.arjuna.ats.jts] (MSC service thread 1-3) ArjunaTransactionImple::ArjunaTransactionImple ( 0:0:0:0:0 ) >16:42:59,057 INFO [com.arjuna.ats.jbossatx] (MSC service thread 1-3) ARJUNA032017: JBossTS Transaction Service (JTA version - tag: 430b320d1e2bb4b97bd2226c29c36953d5939c4c) - JBoss Inc. >16:42:59,058 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-3) registering bean jboss.jta:type=ObjectStore >16:42:59,060 INFO [org.jboss.as.server.deployment] (MSC service thread 1-4) JBAS015876: Starting deployment of "dsdriver.jar" (runtime-name: "dsdriver.jar") >16:42:59,060 INFO [org.jboss.as.jacorb] (MSC service thread 1-6) JBAS016328: CORBA Naming Service started >16:42:59,059 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) CommitMarkableResourceRecordRecoveryModule::periodicWorkFirstPass >16:42:59,061 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState() >16:42:59,061 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) >16:42:59,061 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState() >16:42:59,062 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) processing /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction transactions >16:42:59,062 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState() >16:42:59,062 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) >16:42:59,062 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState() >16:42:59,062 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) >16:42:59,062 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState() >16:42:59,062 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) AtomicActionRecoveryModule first pass >16:42:59,062 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) >16:42:59,063 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState() >16:42:59,063 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) processing /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction transactions >16:42:59,063 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) >16:42:59,063 DEBUG [com.arjuna.ats.txoj] (Periodic Recovery) TORecoveryModule - first pass >16:42:59,063 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState() >16:42:59,063 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.allTypes(InputObjectState Uid : 0:0:0:0:0 >InputObjectState Type : null >InputObjectState Size : 0 >InputObjectState Buffer: ) >16:42:59,064 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState() >16:42:59,064 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) >16:42:59,064 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) >16:42:59,064 INFO [org.jboss.as.remoting] (MSC service thread 1-4) JBAS017100: Listening on 127.0.0.1:4447 >16:42:59,066 INFO [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-3) JBAS010400: Bound data source [java:jboss/datasources/ExampleDS] >16:42:59,077 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 >16:42:59,077 INFO [org.jboss.as.remoting] (MSC service thread 1-7) JBAS017100: Listening on 127.0.0.1:9999 >16:42:59,098 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221034: Waiting to obtain live lock >16:42:59,099 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221035: Live Server Obtained live lock >16:42:59,144 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) >16:42:59,328 TRACE [com.arjuna.ats.jts] (Finalizer) ArjunaTransactionImple.finalize - called for < 0:0:0:0:0 > >16:42:59,328 TRACE [com.arjuna.ats.arjuna] (Finalizer) BasicAction::finalize() >16:42:59,446 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221020: Started Netty Acceptor version 3.6.7.Final-99b1b26 127.0.0.1:5445 for CORE protocol >16:42:59,447 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221020: Started Netty Acceptor version 3.6.7.Final-99b1b26 127.0.0.1:5455 for CORE protocol >16:42:59,448 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221007: Server is now live >16:42:59,448 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221001: HornetQ Server version 2.3.18.Final (2.3.18, 123) [be3d1309-b8e2-11e3-b69d-9962638eac79] >16:42:59,450 INFO [org.jboss.as.messaging] (ServerService Thread Pool -- 60) JBAS011601: Bound messaging object to jndi name java:/ConnectionFactory >16:42:59,452 INFO [org.jboss.as.connector.deployment] (MSC service thread 1-2) JBAS010406: Registered connection factory java:/JmsXA >16:42:59,454 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 61) HQ221003: trying to deploy queue jms.queue.ExpiryQueue >16:42:59,467 INFO [org.jboss.as.messaging] (ServerService Thread Pool -- 61) JBAS011601: Bound messaging object to jndi name java:/jms/queue/ExpiryQueue >16:42:59,468 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 62) HQ221003: trying to deploy queue jms.queue.DLQ >16:42:59,468 INFO [org.jboss.as.messaging] (ServerService Thread Pool -- 62) JBAS011601: Bound messaging object to jndi name java:/jms/queue/DLQ >16:42:59,471 INFO [org.hornetq.ra] (MSC service thread 1-2) HornetQ resource adaptor started >16:42:59,470 INFO [org.jboss.as.messaging] (ServerService Thread Pool -- 63) JBAS011601: Bound messaging object to jndi name java:jboss/exported/jms/RemoteConnectionFactory >16:42:59,471 INFO [org.jboss.as.connector.services.resourceadapters.ResourceAdapterActivatorService$ResourceAdapterActivator] (MSC service thread 1-2) IJ020002: Deployed: file://RaActivatorhornetq-ra >16:42:59,472 INFO [org.jboss.as.connector.deployment] (MSC service thread 1-2) JBAS010401: Bound JCA ConnectionFactory [java:/JmsXA] >16:42:59,500 INFO [org.jboss.as.server] (ServerService Thread Pool -- 33) JBAS018559: Deployed "dsdriver.jar" (runtime-name : "dsdriver.jar") >16:42:59,507 INFO [org.jboss.as] (Controller Boot Thread) JBAS015961: Http management interface listening on http://127.0.0.1:9990/management >16:42:59,508 INFO [org.jboss.as] (Controller Boot Thread) JBAS015951: Admin console listening on http://127.0.0.1:9990 >16:42:59,509 INFO [org.jboss.as] (Controller Boot Thread) JBAS015874: JBoss EAP 6.3.0.Alpha2 (AS 7.4.0.Final-redhat-6) started in 688ms - Started 231 of 268 services (71 services are lazy, passive or on-demand) >16:43:00,705 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 29) HQ221003: trying to deploy queue jms.queue.queue/crashRecoveryQueue >16:43:00,731 INFO [org.jboss.as.messaging] (ServerService Thread Pool -- 29) JBAS011601: Bound messaging object to jndi name java:jboss/queue/crashRecoveryQueue >16:43:00,883 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 29) HQ221003: trying to deploy queue jms.queue.queue/MDBTriggerQueue >16:43:00,904 INFO [org.jboss.as.messaging] (ServerService Thread Pool -- 29) JBAS011601: Bound messaging object to jndi name java:jboss/queue/MDBTriggerQueue >16:43:01,200 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/20/dd7b85ab034a6bea8e7a9026c14250807151b2/content >16:43:01,208 INFO [org.jboss.as.server.deployment] (MSC service thread 1-2) JBAS015876: Starting deployment of "crashrecovery-jms.jar" (runtime-name: "crashrecovery-jms.jar") >16:43:01,275 WARN [org.jboss.as.dependency.private] (MSC service thread 1-5) 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. >16:43:01,316 INFO [org.jboss.as.ejb3.deployment.processors.EjbJndiBindingsDeploymentUnitProcessor] (MSC service thread 1-8) 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 > >16:43:01,317 INFO [org.jboss.as.ejb3.deployment.processors.EjbJndiBindingsDeploymentUnitProcessor] (MSC service thread 1-8) 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 > >16:43:01,317 INFO [org.jboss.as.ejb3.deployment.processors.EjbJndiBindingsDeploymentUnitProcessor] (MSC service thread 1-8) 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 > >16:43:01,317 INFO [org.jboss.as.ejb3.deployment.processors.EjbJndiBindingsDeploymentUnitProcessor] (MSC service thread 1-8) 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 > >16:43:01,318 INFO [org.jboss.as.ejb3.deployment.processors.EjbJndiBindingsDeploymentUnitProcessor] (MSC service thread 1-8) 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 > >16:43:01,416 WARN [org.jboss.as.ejb3] (MSC service thread 1-2) JBAS014105: ActivationConfigProperty hostName will be ignored since it is not allowed by resource adapter: hornetq-ra >16:43:01,417 WARN [org.jboss.as.ejb3] (MSC service thread 1-2) JBAS014105: ActivationConfigProperty MaxDeliveryCnt will be ignored since it is not allowed by resource adapter: hornetq-ra >16:43:01,417 WARN [org.jboss.as.ejb3] (MSC service thread 1-2) JBAS014105: ActivationConfigProperty useJndi will be ignored since it is not allowed by resource adapter: hornetq-ra >16:43:01,418 WARN [org.jboss.as.ejb3] (MSC service thread 1-2) JBAS014105: ActivationConfigProperty port will be ignored since it is not allowed by resource adapter: hornetq-ra >16:43:01,418 WARN [org.jboss.as.ejb3] (MSC service thread 1-2) JBAS014105: ActivationConfigProperty queueManager will be ignored since it is not allowed by resource adapter: hornetq-ra >16:43:01,419 WARN [org.jboss.as.ejb3] (MSC service thread 1-2) JBAS014105: ActivationConfigProperty username will be ignored since it is not allowed by resource adapter: hornetq-ra >16:43:01,419 WARN [org.jboss.as.ejb3] (MSC service thread 1-2) JBAS014105: ActivationConfigProperty connectionFactory will be ignored since it is not allowed by resource adapter: hornetq-ra >16:43:01,419 WARN [org.jboss.as.ejb3] (MSC service thread 1-2) JBAS014105: ActivationConfigProperty channel will be ignored since it is not allowed by resource adapter: hornetq-ra >16:43:01,420 WARN [org.jboss.as.ejb3] (MSC service thread 1-2) JBAS014105: ActivationConfigProperty transportType will be ignored since it is not allowed by resource adapter: hornetq-ra >16:43:01,441 INFO [org.jboss.as.ejb3] (MSC service thread 1-2) JBAS014142: Started message driven bean 'mdb' with 'hornetq-ra' resource adapter >16:43:01,455 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 29) BaseTransaction.begin >16:43:01,455 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 28) BaseTransaction.begin >16:43:01,456 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 28) StateManager::StateManager( 2, 0 ) >16:43:01,456 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 29) StateManager::StateManager( 2, 0 ) >16:43:01,456 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 28) BasicAction::BasicAction() >16:43:01,456 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 29) BasicAction::BasicAction() >16:43:01,456 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 28) BasicAction::Begin() for action-id 0:ffff7f000001:-7751a77e:53397eee:12 >16:43:01,456 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 29) BasicAction::Begin() for action-id 0:ffff7f000001:-7751a77e:53397eee:13 >16:43:01,456 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 28) BasicAction::actionInitialise() for action-id 0:ffff7f000001:-7751a77e:53397eee:12 >16:43:01,456 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 29) BasicAction::actionInitialise() for action-id 0:ffff7f000001:-7751a77e:53397eee:13 >16:43:01,458 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 28) ActionHierarchy::ActionHierarchy(5) >16:43:01,458 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 29) ActionHierarchy::ActionHierarchy(5) >16:43:01,458 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 29) ActionHierarchy::add(0:ffff7f000001:-7751a77e:53397eee:13, 1) >16:43:01,459 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 28) ActionHierarchy::add(0:ffff7f000001:-7751a77e:53397eee:12, 1) >16:43:01,459 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 29) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:13 adding Thread[ServerService Thread Pool -- 29,5,ServerService ThreadGroup] >16:43:01,459 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 28) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:12 adding Thread[ServerService Thread Pool -- 28,5,ServerService ThreadGroup] >16:43:01,459 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 29) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:13 adding Thread[ServerService Thread Pool -- 29,5,ServerService ThreadGroup] result = true >16:43:01,459 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 28) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:12 adding Thread[ServerService Thread Pool -- 28,5,ServerService ThreadGroup] result = true >16:43:01,460 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 29) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:13 status: ActionStatus.RUNNING, 300 ) >16:43:01,460 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 28) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:12 status: ActionStatus.RUNNING, 300 ) >16:43:01,460 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 29) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:13 status: ActionStatus.RUNNING, 300 ) >16:43:01,460 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 28) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:12 status: ActionStatus.RUNNING, 300 ) >16:43:01,460 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) ReaperThread.run () >16:43:01,461 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) TransactionReaper::check () >16:43:01,461 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) TransactionReaper::check - comparing 1396277281460 >16:43:01,461 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) Thread Thread[Transaction Reaper,5,main] sleeping for 299999 >16:43:01,462 INFO [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (ServerService Thread Pool -- 29) TestXAResourceRecoveryHelper starting >16:43:01,464 INFO [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (ServerService Thread Pool -- 29) 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 >16:43:01,464 INFO [org.jboss.as.test.jbossts.common.TransactionStoreBrowserService] (ServerService Thread Pool -- 28) TransactionStoreBrowserService.start >16:43:01,465 INFO [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (ServerService Thread Pool -- 29) 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 >16:43:01,466 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 29) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:01,466 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 29) BaseTransaction.commit >16:43:01,466 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 29) TransactionImple.commitAndDisassociate >16:43:01,467 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 29) BasicAction::End() for action-id 0:ffff7f000001:-7751a77e:53397eee:13 >16:43:01,467 INFO [stdout] (ServerService Thread Pool -- 28) registering bean jboss.jta:type=com.arjuna.ats.arjuna.tools.osb.api.mbeans.RecoveryStoreBean,name=store1 >16:43:01,467 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 29) BasicAction::End() result for action-id (0:ffff7f000001:-7751a77e:53397eee:13) is (TwoPhaseOutcome.PREPARE_OK) node id: (1) >16:43:01,467 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 29) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:13 removing TSThread:1 >16:43:01,467 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 29) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:13 removing TSThread:1 result = true >16:43:01,467 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 29) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:13 status: ActionStatus.COMMITTED ) >16:43:01,468 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 28) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:01,468 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 28) BaseTransaction.commit >16:43:01,468 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 28) TransactionImple.commitAndDisassociate >16:43:01,468 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 28) BasicAction::End() for action-id 0:ffff7f000001:-7751a77e:53397eee:12 >16:43:01,468 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 28) BasicAction::End() result for action-id (0:ffff7f000001:-7751a77e:53397eee:12) is (TwoPhaseOutcome.PREPARE_OK) node id: (1) >16:43:01,468 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 28) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:12 removing TSThread:2 >16:43:01,468 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 28) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:12 removing TSThread:2 result = true >16:43:01,468 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 28) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:12 status: ActionStatus.COMMITTED ) >16:43:01,596 INFO [org.jboss.as.server] (management-handler-thread - 2) JBAS018559: Deployed "crashrecovery-jms.jar" (runtime-name : "crashrecovery-jms.jar") >16:43:03,421 TRACE [com.arjuna.ats.arjuna] (pool-5-thread-1) InputObjectState::InputObjectState() >16:43:03,421 TRACE [com.arjuna.ats.arjuna] (pool-5-thread-1) FileSystemStore.allTypes(InputObjectState Uid : 0:0:0:0:0 >InputObjectState Type : null >InputObjectState Size : 0 >InputObjectState Buffer: ) >16:43:03,421 TRACE [com.arjuna.ats.arjuna] (pool-5-thread-1) OutputObjectState::OutputObjectState() >16:43:03,455 TRACE [com.arjuna.ats.arjuna] (pool-5-thread-1) InputObjectState::InputObjectState() >16:43:03,455 TRACE [com.arjuna.ats.arjuna] (pool-5-thread-1) FileSystemStore.allTypes(InputObjectState Uid : 0:0:0:0:0 >InputObjectState Type : null >InputObjectState Size : 0 >InputObjectState Buffer: ) >16:43:03,455 TRACE [com.arjuna.ats.arjuna] (pool-5-thread-1) OutputObjectState::OutputObjectState() >16:43:09,064 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) Periodic recovery second pass at Mon, 31 Mar 2014 16:43:09 >16:43:09,064 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState() >16:43:09,065 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) >16:43:09,065 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState() >16:43:09,065 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) >16:43:09,065 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState() >16:43:09,065 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) >16:43:09,065 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) AtomicActionRecoveryModule second pass >16:43:09,066 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) >16:43:09,066 DEBUG [com.arjuna.ats.txoj] (Periodic Recovery) TORecoveryModule - second pass >16:43:09,066 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) >16:43:09,066 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Local XARecoveryModule - second pass >16:43:09,066 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Local XARecoveryModule.transactionInitiatedRecovery completed >16:43:09,066 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Have 0 Xids to recover on this pass. >16:43:09,067 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids isStale Check RecoveryOnlyEJBXAResource{receiverContext=EJBReceiverContext{clientContext=org.jboss.ejb.client.EJBClientContext@3db31a82, receiver=org.jboss.as.ejb3.remote.LocalEjbReceiver@70d5ca2}, transactionOriginNodeIdentifier='1'} 1396276974591 1396276989067 false >16:43:09,067 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Local XARecoveryModule.resourceInitiatedRecovery completed >16:43:09,067 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) >16:43:09,067 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread Status <== INACTIVE >16:43:09,067 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread backing off >16:43:13,690 TRACE [com.arjuna.ats.jta] (EJB default - 1) BaseTransaction.begin >16:43:13,690 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) StateManager::StateManager( 2, 0 ) >16:43:13,690 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::BasicAction() >16:43:13,690 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::Begin() for action-id 0:ffff7f000001:-7751a77e:53397eee:18 >16:43:13,690 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::actionInitialise() for action-id 0:ffff7f000001:-7751a77e:53397eee:18 >16:43:13,690 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ActionHierarchy::ActionHierarchy(5) >16:43:13,691 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ActionHierarchy::add(0:ffff7f000001:-7751a77e:53397eee:18, 1) >16:43:13,691 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:18 adding Thread[EJB default - 1,5,EJB default] >16:43:13,691 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:18 adding Thread[EJB default - 1,5,EJB default] result = true >16:43:13,691 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:18 status: ActionStatus.RUNNING, 300 ) >16:43:13,691 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:18 status: ActionStatus.RUNNING, 300 ) >16:43:13,692 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:13,692 TRACE [com.arjuna.ats.jta] (EJB default - 1) BaseTransaction.commit >16:43:13,692 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.commitAndDisassociate >16:43:13,692 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::End() for action-id 0:ffff7f000001:-7751a77e:53397eee:18 >16:43:13,692 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::End() result for action-id (0:ffff7f000001:-7751a77e:53397eee:18) is (TwoPhaseOutcome.PREPARE_OK) node id: (1) >16:43:13,693 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:18 removing TSThread:3 >16:43:13,693 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:18 removing TSThread:3 result = true >16:43:13,693 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:18 status: ActionStatus.COMMITTED ) >16:43:13,694 INFO [org.jboss.as.test.jbossts.crashrec.common.CrashHelperCommon] (EJB default - 1) wipe out in-doubt txs: wipeOutTxsInDoubt() called >16:43:13,694 TRACE [com.arjuna.ats.jta] (EJB default - 1) BaseTransaction.begin >16:43:13,694 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) StateManager::StateManager( 2, 0 ) >16:43:13,694 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::BasicAction() >16:43:13,694 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::Begin() for action-id 0:ffff7f000001:-7751a77e:53397eee:19 >16:43:13,694 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::actionInitialise() for action-id 0:ffff7f000001:-7751a77e:53397eee:19 >16:43:13,694 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ActionHierarchy::ActionHierarchy(5) >16:43:13,694 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ActionHierarchy::add(0:ffff7f000001:-7751a77e:53397eee:19, 1) >16:43:13,694 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:19 adding Thread[EJB default - 1,5,EJB default] >16:43:13,694 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:19 adding Thread[EJB default - 1,5,EJB default] result = true >16:43:13,695 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:19 status: ActionStatus.RUNNING, 300 ) >16:43:13,695 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:19 status: ActionStatus.RUNNING, 300 ) >16:43:13,696 INFO [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (EJB default - 1) getXAResources() >16:43:13,696 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:13,696 TRACE [com.arjuna.ats.jta] (EJB default - 1) BaseTransaction.commit >16:43:13,696 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.commitAndDisassociate >16:43:13,696 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::End() for action-id 0:ffff7f000001:-7751a77e:53397eee:19 >16:43:13,696 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::End() result for action-id (0:ffff7f000001:-7751a77e:53397eee:19) is (TwoPhaseOutcome.PREPARE_OK) node id: (1) >16:43:13,696 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:19 removing TSThread:3 >16:43:13,696 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:19 removing TSThread:3 result = true >16:43:13,696 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:19 status: ActionStatus.COMMITTED ) >16:43:13,697 TRACE [com.arjuna.ats.jta] (EJB default - 1) BaseTransaction.begin >16:43:13,697 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) StateManager::StateManager( 2, 0 ) >16:43:13,697 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::BasicAction() >16:43:13,697 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::Begin() for action-id 0:ffff7f000001:-7751a77e:53397eee:1a >16:43:13,697 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::actionInitialise() for action-id 0:ffff7f000001:-7751a77e:53397eee:1a >16:43:13,697 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ActionHierarchy::ActionHierarchy(5) >16:43:13,697 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ActionHierarchy::add(0:ffff7f000001:-7751a77e:53397eee:1a, 1) >16:43:13,697 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:1a adding Thread[EJB default - 1,5,EJB default] >16:43:13,697 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:1a adding Thread[EJB default - 1,5,EJB default] result = true >16:43:13,697 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:1a status: ActionStatus.RUNNING, 300 ) >16:43:13,697 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:1a status: ActionStatus.RUNNING, 300 ) >16:43:13,697 INFO [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (EJB default - 1) getXAResources() >16:43:13,698 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:13,698 TRACE [com.arjuna.ats.jta] (EJB default - 1) BaseTransaction.commit >16:43:13,698 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.commitAndDisassociate >16:43:13,698 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::End() for action-id 0:ffff7f000001:-7751a77e:53397eee:1a >16:43:13,698 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::End() result for action-id (0:ffff7f000001:-7751a77e:53397eee:1a) is (TwoPhaseOutcome.PREPARE_OK) node id: (1) >16:43:13,698 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:1a removing TSThread:3 >16:43:13,698 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:1a removing TSThread:3 result = true >16:43:13,698 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:1a status: ActionStatus.COMMITTED ) >16:43:13,698 TRACE [com.arjuna.ats.jta] (EJB default - 1) BaseTransaction.begin >16:43:13,698 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) StateManager::StateManager( 2, 0 ) >16:43:13,698 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::BasicAction() >16:43:13,698 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::Begin() for action-id 0:ffff7f000001:-7751a77e:53397eee:1b >16:43:13,698 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::actionInitialise() for action-id 0:ffff7f000001:-7751a77e:53397eee:1b >16:43:13,698 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ActionHierarchy::ActionHierarchy(5) >16:43:13,698 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ActionHierarchy::add(0:ffff7f000001:-7751a77e:53397eee:1b, 1) >16:43:13,699 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:1b adding Thread[EJB default - 1,5,EJB default] >16:43:13,699 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:1b adding Thread[EJB default - 1,5,EJB default] result = true >16:43:13,699 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:1b status: ActionStatus.RUNNING, 300 ) >16:43:13,699 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:1b status: ActionStatus.RUNNING, 300 ) >16:43:13,699 INFO [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (EJB default - 1) getXAResources() >16:43:13,699 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:13,699 TRACE [com.arjuna.ats.jta] (EJB default - 1) BaseTransaction.commit >16:43:13,699 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.commitAndDisassociate >16:43:13,699 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::End() for action-id 0:ffff7f000001:-7751a77e:53397eee:1b >16:43:13,699 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::End() result for action-id (0:ffff7f000001:-7751a77e:53397eee:1b) is (TwoPhaseOutcome.PREPARE_OK) node id: (1) >16:43:13,699 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:1b removing TSThread:3 >16:43:13,699 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:1b removing TSThread:3 result = true >16:43:13,699 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:1b status: ActionStatus.COMMITTED ) >16:43:13,699 INFO [org.jboss.as.test.jbossts.common.TestXAResourceRecovered] (EJB default - 1) TestXAResourceRecovered.recover(i=16777216) >16:43:13,700 INFO [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (EJB default - 1) recover() >16:43:13,700 INFO [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (EJB default - 1) returning 0 Xids >16:43:13,708 TRACE [com.arjuna.ats.jta] (EJB default - 2) BaseTransaction.begin >16:43:13,709 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) StateManager::StateManager( 2, 0 ) >16:43:13,709 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::BasicAction() >16:43:13,709 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::Begin() for action-id 0:ffff7f000001:-7751a77e:53397eee:1c >16:43:13,709 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::actionInitialise() for action-id 0:ffff7f000001:-7751a77e:53397eee:1c >16:43:13,709 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) ActionHierarchy::ActionHierarchy(5) >16:43:13,709 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) ActionHierarchy::add(0:ffff7f000001:-7751a77e:53397eee:1c, 1) >16:43:13,709 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:1c adding Thread[EJB default - 2,5,EJB default] >16:43:13,709 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:1c adding Thread[EJB default - 2,5,EJB default] result = true >16:43:13,709 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:1c status: ActionStatus.RUNNING, 300 ) >16:43:13,709 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:1c status: ActionStatus.RUNNING, 300 ) >16:43:13,709 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:13,709 TRACE [com.arjuna.ats.jta] (EJB default - 2) BaseTransaction.commit >16:43:13,709 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImple.commitAndDisassociate >16:43:13,709 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::End() for action-id 0:ffff7f000001:-7751a77e:53397eee:1c >16:43:13,710 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::End() result for action-id (0:ffff7f000001:-7751a77e:53397eee:1c) is (TwoPhaseOutcome.PREPARE_OK) node id: (1) >16:43:13,710 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:1c removing TSThread:4 >16:43:13,710 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:1c removing TSThread:4 result = true >16:43:13,710 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:1c status: ActionStatus.COMMITTED ) >16:43:13,716 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionSynchronizationRegistryImple.getTransactionKey >16:43:13,716 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionSynchronizationRegistryImple.getTransactionKey >16:43:13,732 INFO [org.jboss.as.test.jbossts.crashrec.common.CrashHelperCommon] (EJB default - 2) There are 0 xids in doubt >16:43:13,738 INFO [stdout] (Thread-0) TransformListener() : handling connection on port 9091 >16:43:13,884 INFO [stdout] (Thread-0) TransformListener() : handling connection on port 9091 >16:43:13,951 INFO [stdout] (Thread-0) retransforming org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,015 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : possible trigger for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_prepare_remotetrace_entry in class org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,036 INFO [stdout] (Thread-0) RuleTriggerMethodAdapter.injectTriggerPoint : inserting trigger into org.jboss.as.test.jbossts.common.TestXAResource.prepare(javax.transaction.xa.Xid) int for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_prepare_remotetrace_entry >16:43:14,040 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : inserted trigger for org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_prepare_remotetrace_entry in class org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,044 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : possible trigger for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_start_remotetrace_entry in class org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,045 INFO [stdout] (Thread-0) RuleTriggerMethodAdapter.injectTriggerPoint : inserting trigger into org.jboss.as.test.jbossts.common.TestXAResource.start(javax.transaction.xa.Xid,int) void for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_start_remotetrace_entry >16:43:14,047 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : inserted trigger for org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_start_remotetrace_entry in class org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,049 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : possible trigger for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_end_remotetrace_entry in class org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,052 INFO [stdout] (Thread-0) RuleTriggerMethodAdapter.injectTriggerPoint : inserting trigger into org.jboss.as.test.jbossts.common.TestXAResource.end(javax.transaction.xa.Xid,int) void for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_end_remotetrace_entry >16:43:14,054 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : inserted trigger for org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_end_remotetrace_entry in class org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,057 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : possible trigger for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_toString_remotetrace_entry in class org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,059 INFO [stdout] (Thread-0) RuleTriggerMethodAdapter.injectTriggerPoint : inserting trigger into org.jboss.as.test.jbossts.common.TestXAResource.toString() java.lang.String for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_toString_remotetrace_entry >16:43:14,062 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : inserted trigger for org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_toString_remotetrace_entry in class org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,066 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : possible trigger for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_isSameRM_remotetrace_entry in class org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,068 INFO [stdout] (Thread-0) RuleTriggerMethodAdapter.injectTriggerPoint : inserting trigger into org.jboss.as.test.jbossts.common.TestXAResource.isSameRM(javax.transaction.xa.XAResource) boolean for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_isSameRM_remotetrace_entry >16:43:14,072 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : inserted trigger for org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_isSameRM_remotetrace_entry in class org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,075 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : possible trigger for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_checkHeuristicType_remotetrace_entry in class org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,077 INFO [stdout] (Thread-0) RuleTriggerMethodAdapter.injectTriggerPoint : inserting trigger into org.jboss.as.test.jbossts.common.TestXAResource.checkHeuristicType(javax.transaction.xa.Xid,boolean) void for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_checkHeuristicType_remotetrace_entry >16:43:14,081 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : inserted trigger for org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_checkHeuristicType_remotetrace_entry in class org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,085 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : possible trigger for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_getTransactionTimeout_remotetrace_entry in class org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,087 INFO [stdout] (Thread-0) RuleTriggerMethodAdapter.injectTriggerPoint : inserting trigger into org.jboss.as.test.jbossts.common.TestXAResource.getTransactionTimeout() int for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_getTransactionTimeout_remotetrace_entry >16:43:14,091 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : inserted trigger for org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_getTransactionTimeout_remotetrace_entry in class org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,095 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : possible trigger for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_setTransactionTimeout_remotetrace_entry in class org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,097 INFO [stdout] (Thread-0) RuleTriggerMethodAdapter.injectTriggerPoint : inserting trigger into org.jboss.as.test.jbossts.common.TestXAResource.setTransactionTimeout(int) boolean for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_setTransactionTimeout_remotetrace_entry >16:43:14,101 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : inserted trigger for org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_setTransactionTimeout_remotetrace_entry in class org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,104 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : possible trigger for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_recover_remotetrace_entry in class org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,107 INFO [stdout] (Thread-0) RuleTriggerMethodAdapter.injectTriggerPoint : inserting trigger into org.jboss.as.test.jbossts.common.TestXAResource.recover(int) javax.transaction.xa.Xid for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_recover_remotetrace_entry >16:43:14,110 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : inserted trigger for org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_recover_remotetrace_entry in class org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,114 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : possible trigger for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_rollback_remotetrace_entry in class org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,117 INFO [stdout] (Thread-0) RuleTriggerMethodAdapter.injectTriggerPoint : inserting trigger into org.jboss.as.test.jbossts.common.TestXAResource.rollback(javax.transaction.xa.Xid) void for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_rollback_remotetrace_entry >16:43:14,119 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : inserted trigger for org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_rollback_remotetrace_entry in class org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,123 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : possible trigger for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_commit_remotetrace_entry in class org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,126 INFO [stdout] (Thread-0) RuleTriggerMethodAdapter.injectTriggerPoint : inserting trigger into org.jboss.as.test.jbossts.common.TestXAResource.commit(javax.transaction.xa.Xid,boolean) void for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_commit_remotetrace_entry >16:43:14,129 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : inserted trigger for org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_commit_remotetrace_entry in class org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,133 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : possible trigger for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_forget_remotetrace_entry in class org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,136 INFO [stdout] (Thread-0) RuleTriggerMethodAdapter.injectTriggerPoint : inserting trigger into org.jboss.as.test.jbossts.common.TestXAResource.forget(javax.transaction.xa.Xid) void for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_forget_remotetrace_entry >16:43:14,140 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : inserted trigger for org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.common.TestXAResource_forget_remotetrace_entry in class org.jboss.as.test.jbossts.common.TestXAResource >16:43:14,166 INFO [stdout] (Thread-0) TransformListener() : handling connection on port 9091 >16:43:14,184 INFO [stdout] (Thread-0) retransforming org.jboss.as.test.jbossts.crashrec.common.CrashBeanCommon >16:43:14,187 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : possible trigger for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.crashrec.common.CrashBeanCommon_beforeEntityUpdate_injectionatENTRY in class org.jboss.as.test.jbossts.crashrec.common.CrashBeanCommon >16:43:14,188 INFO [stdout] (Thread-0) RuleTriggerMethodAdapter.injectTriggerPoint : inserting trigger into org.jboss.as.test.jbossts.crashrec.common.CrashBeanCommon.beforeEntityUpdate() void for rule org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.crashrec.common.CrashBeanCommon_beforeEntityUpdate_injectionatENTRY >16:43:14,190 INFO [stdout] (Thread-0) org.jboss.byteman.agent.Transformer : inserted trigger for org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.crashrec.common.CrashBeanCommon_beforeEntityUpdate_injectionatENTRY in class org.jboss.as.test.jbossts.crashrec.common.CrashBeanCommon >16:43:14,211 TRACE [com.arjuna.ats.jta] (EJB default - 3) BaseTransaction.begin >16:43:14,211 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) StateManager::StateManager( 2, 0 ) >16:43:14,211 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) BasicAction::BasicAction() >16:43:14,211 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) BasicAction::Begin() for action-id 0:ffff7f000001:-7751a77e:53397eee:1d >16:43:14,211 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) BasicAction::actionInitialise() for action-id 0:ffff7f000001:-7751a77e:53397eee:1d >16:43:14,212 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) ActionHierarchy::ActionHierarchy(5) >16:43:14,212 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) ActionHierarchy::add(0:ffff7f000001:-7751a77e:53397eee:1d, 1) >16:43:14,212 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:1d adding Thread[EJB default - 3,5,EJB default] >16:43:14,212 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:1d adding Thread[EJB default - 3,5,EJB default] result = true >16:43:14,212 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:1d status: ActionStatus.RUNNING, 300 ) >16:43:14,212 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:1d status: ActionStatus.RUNNING, 300 ) >16:43:14,212 TRACE [com.arjuna.ats.jta] (EJB default - 3) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:14,212 TRACE [com.arjuna.ats.jta] (EJB default - 3) BaseTransaction.commit >16:43:14,212 TRACE [com.arjuna.ats.jta] (EJB default - 3) TransactionImple.commitAndDisassociate >16:43:14,212 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) BasicAction::End() for action-id 0:ffff7f000001:-7751a77e:53397eee:1d >16:43:14,213 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) BasicAction::End() result for action-id (0:ffff7f000001:-7751a77e:53397eee:1d) is (TwoPhaseOutcome.PREPARE_OK) node id: (1) >16:43:14,213 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:1d removing TSThread:5 >16:43:14,213 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:1d removing TSThread:5 result = true >16:43:14,213 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:1d status: ActionStatus.COMMITTED ) >16:43:14,214 INFO [org.jboss.as.test.jbossts.crashrec.jms.MessageHelper] (EJB default - 3) Looking for connection factory java:/JmsXA >16:43:14,214 INFO [org.jboss.as.test.jbossts.crashrec.jms.MessageHelper] (EJB default - 3) Looking for queue java:jboss/queue/MDBTriggerQueue >16:43:14,215 TRACE [com.arjuna.ats.jta] (EJB default - 3) TransactionSynchronizationRegistryImple.getTransactionKey >16:43:14,215 TRACE [com.arjuna.ats.jta] (EJB default - 3) TransactionSynchronizationRegistryImple.getTransactionKey >16:43:14,221 INFO [org.jboss.as.test.jbossts.crashrec.jms.MessageHelper] (EJB default - 3) waiting to receive a message from java:jboss/queue/MDBTriggerQueue ... >16:43:19,240 INFO [org.jboss.as.test.jbossts.crashrec.jms.MessageHelper] (EJB default - 4) Looking for connection factory java:/JmsXA >16:43:19,242 INFO [org.jboss.as.test.jbossts.crashrec.jms.MessageHelper] (EJB default - 4) Looking for queue java:jboss/queue/crashRecoveryQueue >16:43:19,243 TRACE [com.arjuna.ats.jta] (EJB default - 4) TransactionSynchronizationRegistryImple.getTransactionKey >16:43:19,246 INFO [org.jboss.as.test.jbossts.crashrec.jms.MessageHelper] (EJB default - 4) waiting to receive a message from java:jboss/queue/crashRecoveryQueue ... >16:43:24,270 TRACE [com.arjuna.ats.jta] (EJB default - 5) BaseTransaction.begin >16:43:24,300 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) StateManager::StateManager( 2, 0 ) >16:43:24,300 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) BasicAction::BasicAction() >16:43:24,300 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) BasicAction::Begin() for action-id 0:ffff7f000001:-7751a77e:53397eee:1e >16:43:24,301 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) BasicAction::actionInitialise() for action-id 0:ffff7f000001:-7751a77e:53397eee:1e >16:43:24,301 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) ActionHierarchy::ActionHierarchy(5) >16:43:24,301 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) ActionHierarchy::add(0:ffff7f000001:-7751a77e:53397eee:1e, 1) >16:43:24,301 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:1e adding Thread[EJB default - 5,5,EJB default] >16:43:24,301 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:1e adding Thread[EJB default - 5,5,EJB default] result = true >16:43:24,301 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:1e status: ActionStatus.RUNNING, 300 ) >16:43:24,301 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:1e status: ActionStatus.RUNNING, 300 ) >16:43:24,304 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:24,304 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionSynchronizationRegistryImple.getTransactionKey >16:43:24,305 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionSynchronizationRegistryImple.getResource >16:43:24,305 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:24,305 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionSynchronizationRegistryImple.putResource >16:43:24,305 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:24,305 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionSynchronizationRegistryImple.getTransactionKey >16:43:24,305 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionSynchronizationRegistryImple.getTransactionKey >16:43:24,306 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionSynchronizationRegistryImple.getResource >16:43:24,306 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:24,306 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionSynchronizationRegistryImple.getResource >16:43:24,306 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:24,312 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionSynchronizationRegistryImple.getTransactionKey >16:43:24,312 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionSynchronizationRegistryImple.getResource >16:43:24,312 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:24,312 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionSynchronizationRegistryImple.getResource >16:43:24,312 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:24,312 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionSynchronizationRegistryImple.putResource >16:43:24,312 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:24,312 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:24,315 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionSynchronizationRegistryImple.registerInterposedSynchronization >16:43:24,315 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:24,316 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.enlistResource ( XAResourceWrapperImpl@b7d8a0b[xaResource=org.hornetq.ra.HornetQRAXAResource@5ef1de11 pad=false overrideRmValue=null productName=HornetQ productVersion=2.0 jndiName=java:/JmsXA] ) >16:43:24,317 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:24,317 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) InputObjectState::InputObjectState() >16:43:24,317 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) >16:43:24,317 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) OutputObjectState::OutputObjectState() >16:43:24,318 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) OutputObjectState::OutputObjectState() >16:43:24,318 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) FileSystemStore.write_committed(0:ffff7f000001:-7751a77e:53397eee:22, EISNAME) >16:43:24,318 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) ShadowingStore.write_state(0:ffff7f000001:-7751a77e:53397eee:22, EISNAME, StateType.OS_ORIGINAL) >16:43:24,318 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) ShadowingStore.genPathName(0:ffff7f000001:-7751a77e:53397eee:22, EISNAME, StateType.OS_ORIGINAL) >16:43:24,318 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) FileSystemStore.genPathName(0:ffff7f000001:-7751a77e:53397eee:22, EISNAME, 11) >16:43:24,319 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_-7751a77e_53397eee_22, FileLock.F_WRLCK, true) >16:43:24,320 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_-7751a77e_53397eee_22) >16:43:24,408 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_-7751a77e_53397eee_22, null, java.io.FileOutputStream@3fd45ee0) >16:43:24,415 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) StateManager::StateManager( 1, 0 ) >16:43:24,416 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) AbstractRecord::AbstractRecord (0:ffff7f000001:-7751a77e:53397eee:24, 1) >16:43:24,416 TRACE [com.arjuna.ats.jta] (EJB default - 5) XAResourceRecord.XAResourceRecord ( < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-7751a77e:53397eee:1e, node_name=1, branch_uid=0:ffff7f000001:-7751a77e:53397eee:23, subordinatenodename=null, eis_name=java:/JmsXA >, XAResourceWrapperImpl@b7d8a0b[xaResource=org.hornetq.ra.HornetQRAXAResource@5ef1de11 pad=false overrideRmValue=null productName=HornetQ productVersion=2.0 jndiName=java:/JmsXA] ), record id=0:ffff7f000001:-7751a77e:53397eee:24 >16:43:24,423 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/XAResourceRecord for 0:ffff7f000001:-7751a77e:53397eee:24 >16:43:24,441 INFO [org.jboss.as.test.jbossts.crashrec.jms.MessageHelper] (EJB default - 5) Sending message MDB:none to queue queue/MDBTriggerQueue >16:43:24,447 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImpleManager.suspend >16:43:24,447 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:1e removing TSThread:6 >16:43:24,448 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:1e removing TSThread:6 result = true >16:43:34,468 TRACE [com.arjuna.ats.jta] (EJB default - 6) TransactionImpleManager.resume >16:43:34,469 TRACE [com.arjuna.ats.arjuna] (EJB default - 6) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:1e adding Thread[EJB default - 6,5,EJB default] >16:43:34,469 TRACE [com.arjuna.ats.arjuna] (EJB default - 6) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:1e adding Thread[EJB default - 6,5,EJB default] result = true >16:43:34,469 TRACE [com.arjuna.ats.jta] (EJB default - 6) BaseTransaction.commit >16:43:34,470 TRACE [com.arjuna.ats.jta] (EJB default - 6) TransactionImple.commitAndDisassociate >16:43:34,470 TRACE [com.arjuna.ats.jta] (EJB default - 6) SynchronizationImple.beforeCompletion >16:43:34,470 TRACE [com.arjuna.ats.arjuna] (EJB default - 6) BasicAction::End() for action-id 0:ffff7f000001:-7751a77e:53397eee:1e >16:43:34,471 TRACE [com.arjuna.ats.arjuna] (EJB default - 6) BasicAction::onePhaseCommit() for action-id 0:ffff7f000001:-7751a77e:53397eee:1e >16:43:34,471 TRACE [com.arjuna.ats.jta] (EJB default - 6) XAResourceRecord.topLevelOnePhaseCommit for XAResourceRecord < resource:XAResourceWrapperImpl@b7d8a0b[xaResource=org.hornetq.ra.HornetQRAXAResource@5ef1de11 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:-7751a77e:53397eee:1e, node_name=1, branch_uid=0:ffff7f000001:-7751a77e:53397eee:23, 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@4f40528c >, record id=0:ffff7f000001:-7751a77e:53397eee:24 >16:43:34,530 TRACE [com.arjuna.ats.arjuna] (EJB default - 6) BasicAction::End() result for action-id (0:ffff7f000001:-7751a77e:53397eee:1e) is (TwoPhaseOutcome.PREPARE_OK) node id: (1) >16:43:34,532 TRACE [com.arjuna.ats.jta] (EJB default - 6) SynchronizationImple.afterCompletion >16:43:34,533 TRACE [com.arjuna.ats.arjuna] (EJB default - 6) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:1e removing TSThread:7 >16:43:34,533 TRACE [com.arjuna.ats.arjuna] (EJB default - 6) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:1e removing TSThread:7 result = true >16:43:34,534 TRACE [com.arjuna.ats.arjuna] (EJB default - 6) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:1e status: ActionStatus.COMMITTED ) >16:43:34,536 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionImpleManager.suspend >16:43:34,537 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) BaseTransaction.begin >16:43:34,538 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) StateManager::StateManager( 2, 0 ) >16:43:34,538 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::BasicAction() >16:43:34,538 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::Begin() for action-id 0:ffff7f000001:-7751a77e:53397eee:26 >16:43:34,538 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::actionInitialise() for action-id 0:ffff7f000001:-7751a77e:53397eee:26 >16:43:34,538 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) ActionHierarchy::ActionHierarchy(5) >16:43:34,539 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) ActionHierarchy::add(0:ffff7f000001:-7751a77e:53397eee:26, 1) >16:43:34,539 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:26 adding Thread[Thread-0 (HornetQ-client-global-threads-635027840),5,HornetQ-client-global-threads-635027840] >16:43:34,539 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:26 adding Thread[Thread-0 (HornetQ-client-global-threads-635027840),5,HornetQ-client-global-threads-635027840] result = true >16:43:34,539 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:26 status: ActionStatus.RUNNING, 300 ) >16:43:34,539 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:26 status: ActionStatus.RUNNING, 300 ) >16:43:34,541 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionImpleManager.suspend >16:43:34,541 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:26 removing TSThread:8 >16:43:34,542 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:26 removing TSThread:8 result = true >16:43:34,542 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) BaseTransaction.begin >16:43:34,542 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) StateManager::StateManager( 2, 0 ) >16:43:34,542 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::BasicAction() >16:43:34,542 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::Begin() for action-id 0:ffff7f000001:-7751a77e:53397eee:27 >16:43:34,543 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::actionInitialise() for action-id 0:ffff7f000001:-7751a77e:53397eee:27 >16:43:34,543 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) ActionHierarchy::ActionHierarchy(5) >16:43:34,543 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) ActionHierarchy::add(0:ffff7f000001:-7751a77e:53397eee:27, 1) >16:43:34,543 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:27 adding Thread[Thread-0 (HornetQ-client-global-threads-635027840),5,HornetQ-client-global-threads-635027840] >16:43:34,543 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:27 adding Thread[Thread-0 (HornetQ-client-global-threads-635027840),5,HornetQ-client-global-threads-635027840] result = true >16:43:34,544 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:27 status: ActionStatus.RUNNING, 300 ) >16:43:34,544 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:27 status: ActionStatus.RUNNING, 300 ) >16:43:34,545 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:34,545 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) BaseTransaction.commit >16:43:34,546 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionImple.commitAndDisassociate >16:43:34,546 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::End() for action-id 0:ffff7f000001:-7751a77e:53397eee:27 >16:43:34,546 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::End() result for action-id (0:ffff7f000001:-7751a77e:53397eee:27) is (TwoPhaseOutcome.PREPARE_OK) node id: (1) >16:43:34,546 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:27 removing TSThread:8 >16:43:34,546 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:27 removing TSThread:8 result = true >16:43:34,547 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:27 status: ActionStatus.COMMITTED ) >16:43:34,547 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionImpleManager.resume >16:43:34,547 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:26 adding Thread[Thread-0 (HornetQ-client-global-threads-635027840),5,HornetQ-client-global-threads-635027840] >16:43:34,547 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:26 adding Thread[Thread-0 (HornetQ-client-global-threads-635027840),5,HornetQ-client-global-threads-635027840] result = true >16:43:34,548 INFO [org.jboss.as.test.jbossts.crashrec.jms.mdb.JMSCrashMessageDrivenBean] (Thread-0 (HornetQ-client-global-threads-635027840)) Receiving message HornetQMessage[ID:d015dcc9-b8e2-11e3-b69d-9962638eac79]:PERSISTENT in MDB with text 'MDB:none' >16:43:34,549 INFO [stdout] (Thread-0) TransformListener() : handling connection on port 9091 >16:43:34,549 INFO [stdout] (Thread-0 (HornetQ-client-global-threads-635027840)) Rule.execute called for org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.crashrec.common.CrashBeanCommon_beforeEntityUpdate_injectionatENTRY_12 >16:43:34,568 INFO [stdout] (Thread-0 (HornetQ-client-global-threads-635027840)) HelperManager.install for helper class org.jboss.byteman.contrib.dtest.BytemanTestHelper >16:43:34,570 INFO [stdout] (Thread-0 (HornetQ-client-global-threads-635027840)) calling activated() for helper class org.jboss.byteman.contrib.dtest.BytemanTestHelper >16:43:34,571 INFO [stdout] (Thread-0 (HornetQ-client-global-threads-635027840)) Default helper activated >16:43:34,571 INFO [stdout] (Thread-0 (HornetQ-client-global-threads-635027840)) calling installed(org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.crashrec.common.CrashBeanCommon_beforeEntityUpdate_injectionatENTRY) for helper classorg.jboss.byteman.contrib.dtest.BytemanTestHelper >16:43:34,572 INFO [stdout] (Thread-0 (HornetQ-client-global-threads-635027840)) Installed rule using default helper : org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.crashrec.common.CrashBeanCommon_beforeEntityUpdate_injectionatENTRY >16:43:34,574 INFO [stdout] (Thread-0) retransforming org.jboss.as.test.jbossts.common.TestXAResource >16:43:34,575 INFO [stdout] (Thread-0) retransforming org.jboss.as.test.jbossts.crashrec.common.CrashBeanCommon >16:43:34,609 INFO [stdout] (Thread-0) HelperManager.uninstall for helper class org.jboss.byteman.contrib.dtest.BytemanTestHelper >16:43:34,609 INFO [stdout] (Thread-0) calling uninstalled(org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.crashrec.common.CrashBeanCommon_beforeEntityUpdate_injectionatENTRY) for helper class org.jboss.byteman.contrib.dtest.BytemanTestHelper >16:43:34,610 INFO [stdout] (Thread-0) Uninstalled rule using default helper : org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.crashrec.common.CrashBeanCommon_beforeEntityUpdate_injectionatENTRY >16:43:34,610 INFO [stdout] (Thread-0) calling deactivated() for helper classorg.jboss.byteman.contrib.dtest.BytemanTestHelper >16:43:34,610 INFO [stdout] (Thread-0) Default helper deactivated >16:43:34,614 TRACE [com.arjuna.ats.jta] (EJB default - 7) TransactionSynchronizationRegistryImple.getTransactionKey >16:43:34,615 INFO [org.jboss.as.test.jbossts.crashrec.common.CrashHelperCommon] (EJB default - 7) There are 0 xids in doubt >16:43:34,617 INFO [stdout] (Thread-0 (HornetQ-client-global-threads-635027840)) org.jboss.byteman.contrib.dtest.Instrumentor_org.jboss.as.test.jbossts.crashrec.common.CrashBeanCommon_beforeEntityUpdate_injectionatENTRY execute() >16:43:34,617 INFO [org.jboss.as.test.jbossts.crashrec.common.CrashBeanCommon] (Thread-0 (HornetQ-client-global-threads-635027840)) CrashBeanCommon.enlistSynchronization >16:43:34,619 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionImple.registerSynchronization >16:43:34,619 INFO [org.jboss.as.test.jbossts.crashrec.common.CrashBeanCommon] (Thread-0 (HornetQ-client-global-threads-635027840)) CrashBeanCommon.enlistXAResource >16:43:34,619 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionImple.enlistResource ( TestXAResource(TestXAResourceCommon(0, null)) ) >16:43:34,619 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:34,619 INFO [org.jboss.as.test.jbossts.common.TestXAResourceCommon] (Thread-0 (HornetQ-client-global-threads-635027840)) TestXAResourceCommon.setTransactionTimeout(i=300) >16:43:34,620 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) StateManager::StateManager( 1, 0 ) >16:43:34,620 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) AbstractRecord::AbstractRecord (0:ffff7f000001:-7751a77e:53397eee:2a, 1) >16:43:34,620 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) XAResourceRecord.XAResourceRecord ( < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-7751a77e:53397eee:26, node_name=1, branch_uid=0:ffff7f000001:-7751a77e:53397eee:29, subordinatenodename=null, eis_name=unknown eis name >, TestXAResource(TestXAResourceCommon(300, null)) ), record id=0:ffff7f000001:-7751a77e:53397eee:2a >16:43:34,620 INFO [org.jboss.as.test.jbossts.common.TestXAResourceCommon] (Thread-0 (HornetQ-client-global-threads-635027840)) TestXAResourceCommon.start(Xid=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-7751a77e:53397eee:26, node_name=1, branch_uid=0:ffff7f000001:-7751a77e:53397eee:29, subordinatenodename=null, eis_name=unknown eis name >, i=0) >16:43:34,620 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/XAResourceRecord for 0:ffff7f000001:-7751a77e:53397eee:2a >16:43:34,620 INFO [org.jboss.as.test.jbossts.crashrec.common.CrashBeanCommon] (Thread-0 (HornetQ-client-global-threads-635027840)) CrashBeanCommon.beforeEntityUpdate >16:43:34,621 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:34,621 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionSynchronizationRegistryImple.getTransactionKey >16:43:34,621 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionSynchronizationRegistryImple.getTransactionKey >16:43:34,621 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionSynchronizationRegistryImple.getResource >16:43:34,621 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:34,621 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionSynchronizationRegistryImple.getTransactionKey >16:43:34,621 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionSynchronizationRegistryImple.getResource >16:43:34,622 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:34,622 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionSynchronizationRegistryImple.putResource >16:43:34,622 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:34,622 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionSynchronizationRegistryImple.getResource >16:43:34,622 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:34,622 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionSynchronizationRegistryImple.getTransactionKey >16:43:34,622 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionSynchronizationRegistryImple.getResource >16:43:34,622 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:34,622 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionSynchronizationRegistryImple.getResource >16:43:34,622 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:34,622 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionSynchronizationRegistryImple.putResource >16:43:34,622 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:34,623 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:34,623 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionSynchronizationRegistryImple.registerInterposedSynchronization >16:43:34,623 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:34,623 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionImple.enlistResource ( XAResourceWrapperImpl@b7d8a0b[xaResource=org.hornetq.ra.HornetQRAXAResource@5ef1de11 pad=false overrideRmValue=null productName=HornetQ productVersion=2.0 jndiName=java:/JmsXA] ) >16:43:34,623 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:34,623 INFO [org.jboss.as.test.jbossts.common.TestXAResourceCommon] (Thread-0 (HornetQ-client-global-threads-635027840)) TestXAResourceCommon.isSameRM(xaResource=XAResourceWrapperImpl@b7d8a0b[xaResource=org.hornetq.ra.HornetQRAXAResource@5ef1de11 pad=false overrideRmValue=null productName=HornetQ productVersion=2.0 jndiName=java:/JmsXA]) - returning false >16:43:34,624 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) StateManager::StateManager( 1, 0 ) >16:43:34,624 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) AbstractRecord::AbstractRecord (0:ffff7f000001:-7751a77e:53397eee:2e, 1) >16:43:34,624 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) XAResourceRecord.XAResourceRecord ( < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-7751a77e:53397eee:26, node_name=1, branch_uid=0:ffff7f000001:-7751a77e:53397eee:2d, subordinatenodename=null, eis_name=java:/JmsXA >, XAResourceWrapperImpl@b7d8a0b[xaResource=org.hornetq.ra.HornetQRAXAResource@5ef1de11 pad=false overrideRmValue=null productName=HornetQ productVersion=2.0 jndiName=java:/JmsXA] ), record id=0:ffff7f000001:-7751a77e:53397eee:2e >16:43:34,624 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) RecordList::insert(RecordList: 0:ffff7f000001:-7751a77e:53397eee:2a) : appending /StateManager/AbstractRecord/XAResourceRecord for 0:ffff7f000001:-7751a77e:53397eee:2e >16:43:34,625 INFO [org.jboss.as.test.jbossts.crashrec.jms.MessageHelper] (Thread-0 (HornetQ-client-global-threads-635027840)) Sending message JMSCrashMessageDrivenBean to queue queue/crashRecoveryQueue >16:43:34,626 INFO [org.jboss.as.test.jbossts.crashrec.common.CrashBeanCommon] (Thread-0 (HornetQ-client-global-threads-635027840)) CrashBeanCommon.afterEntityUpdate >16:43:34,627 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:34,627 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) BaseTransaction.commit >16:43:34,627 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionImple.commitAndDisassociate >16:43:34,627 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) SynchronizationImple.beforeCompletion >16:43:34,627 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) SynchronizationImple.beforeCompletion >16:43:34,627 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::End() for action-id 0:ffff7f000001:-7751a77e:53397eee:26 >16:43:34,627 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::prepare () for action-id 0:ffff7f000001:-7751a77e:53397eee:26 >16:43:34,628 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) XAResourceRecord.topLevelPrepare for XAResourceRecord < resource:TestXAResource(TestXAResourceCommon(300, < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-7751a77e:53397eee:26, node_name=1, branch_uid=0:ffff7f000001:-7751a77e:53397eee:29, subordinatenodename=null, eis_name=unknown eis name >)), txid:< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-7751a77e:53397eee:26, node_name=1, branch_uid=0:ffff7f000001:-7751a77e:53397eee:29, subordinatenodename=null, eis_name=unknown eis name >, heuristic: TwoPhaseOutcome.FINISH_OK com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@153df5e5 >, record id=0:ffff7f000001:-7751a77e:53397eee:2a >16:43:34,628 INFO [org.jboss.as.test.jbossts.common.TestXAResourceCommon] (Thread-0 (HornetQ-client-global-threads-635027840)) TestXAResourceCommon.end(Xid=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-7751a77e:53397eee:26, node_name=1, branch_uid=0:ffff7f000001:-7751a77e:53397eee:29, subordinatenodename=null, eis_name=unknown eis name >, b=67108864) >16:43:34,628 INFO [org.jboss.as.test.jbossts.common.TestXAResourceCommon] (Thread-0 (HornetQ-client-global-threads-635027840)) TestXAResourceCommon.prepare(Xid=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-7751a77e:53397eee:26, node_name=1, branch_uid=0:ffff7f000001:-7751a77e:53397eee:29, subordinatenodename=null, eis_name=unknown eis name >) returning 0 >16:43:34,629 INFO [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (Thread-0 (HornetQ-client-global-threads-635027840)) logPrepared(xid=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-7751a77e:53397eee:26, node_name=1, branch_uid=0:ffff7f000001:-7751a77e:53397eee:29, subordinatenodename=null, eis_name=unknown eis name >) >16:43:34,629 INFO [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (Thread-0 (HornetQ-client-global-threads-635027840)) 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 >16:43:34,630 INFO [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (Thread-0 (HornetQ-client-global-threads-635027840)) logging 1 records to /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/tx-object-store/TestXAResourceStateStore/TestXAResource.ser >16:43:34,636 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::doPrepare() result for action-id (0:ffff7f000001:-7751a77e:53397eee:26) on record id: (0:ffff7f000001:-7751a77e:53397eee:2a) is (TwoPhaseOutcome.PREPARE_OK) node id: (1) >16:43:34,636 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/XAResourceRecord for 0:ffff7f000001:-7751a77e:53397eee:2a >16:43:34,636 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 67) BaseTransaction.begin >16:43:34,636 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) XAResourceRecord.topLevelPrepare for XAResourceRecord < resource:XAResourceWrapperImpl@b7d8a0b[xaResource=org.hornetq.ra.HornetQRAXAResource@5ef1de11 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:-7751a77e:53397eee:26, node_name=1, branch_uid=0:ffff7f000001:-7751a77e:53397eee:2d, 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@2ca43057 >, record id=0:ffff7f000001:-7751a77e:53397eee:2e >16:43:34,636 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 68) BaseTransaction.begin >16:43:34,636 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) StateManager::StateManager( 2, 0 ) >16:43:34,636 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) BasicAction::BasicAction() >16:43:34,636 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) BasicAction::Begin() for action-id 0:ffff7f000001:-7751a77e:53397eee:30 >16:43:34,636 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 68) StateManager::StateManager( 2, 0 ) >16:43:34,636 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) BasicAction::actionInitialise() for action-id 0:ffff7f000001:-7751a77e:53397eee:30 >16:43:34,637 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 68) BasicAction::BasicAction() >16:43:34,637 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) ActionHierarchy::ActionHierarchy(5) >16:43:34,637 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 68) BasicAction::Begin() for action-id 0:ffff7f000001:-7751a77e:53397eee:31 >16:43:34,637 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) ActionHierarchy::add(0:ffff7f000001:-7751a77e:53397eee:30, 1) >16:43:34,637 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 68) BasicAction::actionInitialise() for action-id 0:ffff7f000001:-7751a77e:53397eee:31 >16:43:34,637 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:30 adding Thread[ServerService Thread Pool -- 67,5,ServerService ThreadGroup] >16:43:34,637 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 68) ActionHierarchy::ActionHierarchy(5) >16:43:34,637 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:30 adding Thread[ServerService Thread Pool -- 67,5,ServerService ThreadGroup] result = true >16:43:34,637 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 68) ActionHierarchy::add(0:ffff7f000001:-7751a77e:53397eee:31, 1) >16:43:34,637 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:30 status: ActionStatus.RUNNING, 300 ) >16:43:34,637 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 68) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:31 adding Thread[ServerService Thread Pool -- 68,5,ServerService ThreadGroup] >16:43:34,637 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:30 status: ActionStatus.RUNNING, 300 ) >16:43:34,637 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 68) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:31 adding Thread[ServerService Thread Pool -- 68,5,ServerService ThreadGroup] result = true >16:43:34,637 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 64) BaseTransaction.begin >16:43:34,639 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) StateManager::StateManager( 2, 0 ) >16:43:34,637 INFO [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (ServerService Thread Pool -- 67) TestXAResourceRecoveryHelper stopping >16:43:34,637 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 68) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:31 status: ActionStatus.RUNNING, 300 ) >16:43:34,639 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 68) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:31 status: ActionStatus.RUNNING, 300 ) >16:43:34,639 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 67) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:34,639 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 67) BaseTransaction.commit >16:43:34,639 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 68) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:34,640 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 68) BaseTransaction.commit >16:43:34,640 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 68) TransactionImple.commitAndDisassociate >16:43:34,639 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) BasicAction::BasicAction() >16:43:34,640 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 67) TransactionImple.commitAndDisassociate >16:43:34,640 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) BasicAction::End() for action-id 0:ffff7f000001:-7751a77e:53397eee:30 >16:43:34,640 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) BasicAction::End() result for action-id (0:ffff7f000001:-7751a77e:53397eee:30) is (TwoPhaseOutcome.PREPARE_OK) node id: (1) >16:43:34,641 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:30 removing TSThread:9 >16:43:34,641 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:30 removing TSThread:9 result = true >16:43:34,641 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 67) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:30 status: ActionStatus.COMMITTED ) >16:43:34,640 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) BasicAction::Begin() for action-id 0:ffff7f000001:-7751a77e:53397eee:32 >16:43:34,641 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) BasicAction::actionInitialise() for action-id 0:ffff7f000001:-7751a77e:53397eee:32 >16:43:34,640 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 68) BasicAction::End() for action-id 0:ffff7f000001:-7751a77e:53397eee:31 >16:43:34,641 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 68) BasicAction::End() result for action-id (0:ffff7f000001:-7751a77e:53397eee:31) is (TwoPhaseOutcome.PREPARE_OK) node id: (1) >16:43:34,642 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 68) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:31 removing TSThread:a >16:43:34,642 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 65) BaseTransaction.begin >16:43:34,642 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 68) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:31 removing TSThread:a result = true >16:43:34,642 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) StateManager::StateManager( 2, 0 ) >16:43:34,642 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 68) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:31 status: ActionStatus.COMMITTED ) >16:43:34,642 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) BasicAction::BasicAction() >16:43:34,642 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) BasicAction::Begin() for action-id 0:ffff7f000001:-7751a77e:53397eee:33 >16:43:34,642 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) BasicAction::actionInitialise() for action-id 0:ffff7f000001:-7751a77e:53397eee:33 >16:43:34,642 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) ActionHierarchy::ActionHierarchy(5) >16:43:34,642 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 69) BaseTransaction.begin >16:43:34,642 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) ActionHierarchy::add(0:ffff7f000001:-7751a77e:53397eee:33, 1) >16:43:34,642 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:33 adding Thread[ServerService Thread Pool -- 65,5,ServerService ThreadGroup] >16:43:34,643 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:33 adding Thread[ServerService Thread Pool -- 65,5,ServerService ThreadGroup] result = true >16:43:34,643 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:33 status: ActionStatus.RUNNING, 300 ) >16:43:34,643 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:33 status: ActionStatus.RUNNING, 300 ) >16:43:34,643 INFO [org.jboss.as.test.jbossts.common.TransactionStoreBrowserService] (ServerService Thread Pool -- 65) TransactionStoreBrowserService.stop >16:43:34,643 INFO [stdout] (ServerService Thread Pool -- 65) unregistering bean jboss.jta:type=com.arjuna.ats.arjuna.tools.osb.api.mbeans.RecoveryStoreBean,name=store1 >16:43:34,644 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 65) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:34,644 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 65) BaseTransaction.commit >16:43:34,644 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 65) TransactionImple.commitAndDisassociate >16:43:34,644 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) BasicAction::End() for action-id 0:ffff7f000001:-7751a77e:53397eee:33 >16:43:34,644 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) BasicAction::End() result for action-id (0:ffff7f000001:-7751a77e:53397eee:33) is (TwoPhaseOutcome.PREPARE_OK) node id: (1) >16:43:34,641 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) ActionHierarchy::ActionHierarchy(5) >16:43:34,644 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) ActionHierarchy::add(0:ffff7f000001:-7751a77e:53397eee:32, 1) >16:43:34,644 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 69) StateManager::StateManager( 2, 0 ) >16:43:34,644 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:33 removing TSThread:b >16:43:34,645 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 69) BasicAction::BasicAction() >16:43:34,645 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:33 removing TSThread:b result = true >16:43:34,645 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 69) BasicAction::Begin() for action-id 0:ffff7f000001:-7751a77e:53397eee:34 >16:43:34,645 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 65) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:33 status: ActionStatus.COMMITTED ) >16:43:34,645 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 69) BasicAction::actionInitialise() for action-id 0:ffff7f000001:-7751a77e:53397eee:34 >16:43:34,645 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 69) ActionHierarchy::ActionHierarchy(5) >16:43:34,645 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 69) ActionHierarchy::add(0:ffff7f000001:-7751a77e:53397eee:34, 1) >16:43:34,644 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:32 adding Thread[ServerService Thread Pool -- 64,5,ServerService ThreadGroup] >16:43:34,645 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 69) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:34 adding Thread[ServerService Thread Pool -- 69,5,ServerService ThreadGroup] >16:43:34,646 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:32 adding Thread[ServerService Thread Pool -- 64,5,ServerService ThreadGroup] result = true >16:43:34,646 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 69) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:34 adding Thread[ServerService Thread Pool -- 69,5,ServerService ThreadGroup] result = true >16:43:34,646 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:32 status: ActionStatus.RUNNING, 300 ) >16:43:34,647 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 69) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:34 status: ActionStatus.RUNNING, 300 ) >16:43:34,647 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:32 status: ActionStatus.RUNNING, 300 ) >16:43:34,647 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 69) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:34 status: ActionStatus.RUNNING, 300 ) >16:43:34,647 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 64) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:34,647 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 64) BaseTransaction.commit >16:43:34,647 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 69) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:34,648 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 69) BaseTransaction.commit >16:43:34,648 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 69) TransactionImple.commitAndDisassociate >16:43:34,648 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 69) BasicAction::End() for action-id 0:ffff7f000001:-7751a77e:53397eee:34 >16:43:34,648 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 69) BasicAction::End() result for action-id (0:ffff7f000001:-7751a77e:53397eee:34) is (TwoPhaseOutcome.PREPARE_OK) node id: (1) >16:43:34,648 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 69) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:34 removing TSThread:d >16:43:34,648 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 69) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:34 removing TSThread:d result = true >16:43:34,648 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 69) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:34 status: ActionStatus.COMMITTED ) >16:43:34,647 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 64) TransactionImple.commitAndDisassociate >16:43:34,649 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) BasicAction::End() for action-id 0:ffff7f000001:-7751a77e:53397eee:32 >16:43:34,649 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) BasicAction::End() result for action-id (0:ffff7f000001:-7751a77e:53397eee:32) is (TwoPhaseOutcome.PREPARE_OK) node id: (1) >16:43:34,649 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:32 removing TSThread:c >16:43:34,649 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:32 removing TSThread:c result = true >16:43:34,649 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 64) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:32 status: ActionStatus.COMMITTED ) >16:43:34,642 WARN [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) ARJUNA016041: prepare on < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-7751a77e:53397eee:26, node_name=1, branch_uid=0:ffff7f000001:-7751a77e:53397eee:2d, subordinatenodename=null, eis_name=java:/JmsXA > (XAResourceWrapperImpl@b7d8a0b[xaResource=org.hornetq.ra.HornetQRAXAResource@5ef1de11 pad=false overrideRmValue=null productName=HornetQ productVersion=2.0 jndiName=java:/JmsXA]) 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.prepare(ClientSessionImpl.java:1576) > at org.hornetq.ra.HornetQRAXAResource.prepare(HornetQRAXAResource.java:130) > at org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.prepare(XAResourceWrapperImpl.java:169) > at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelPrepare(XAResourceRecord.java:213) [jbossjts-jacorb-4.17.18.Final.jar:4.17.18.Final] > at com.arjuna.ats.arjuna.coordinator.BasicAction.doPrepare(BasicAction.java:2522) [jbossjts-jacorb-4.17.18.Final.jar:4.17.18.Final] > at com.arjuna.ats.arjuna.coordinator.BasicAction.doPrepare(BasicAction.java:2489) [jbossjts-jacorb-4.17.18.Final.jar:4.17.18.Final] > at com.arjuna.ats.arjuna.coordinator.BasicAction.prepare(BasicAction.java:2066) [jbossjts-jacorb-4.17.18.Final.jar:4.17.18.Final] > at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1481) [jbossjts-jacorb-4.17.18.Final.jar:4.17.18.Final] > at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:98) [jbossjts-jacorb-4.17.18.Final.jar:4.17.18.Final] > at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162) [jbossjts-jacorb-4.17.18.Final.jar:4.17.18.Final] > at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1189) [jbossjts-jacorb-4.17.18.Final.jar:4.17.18.Final] > at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126) [jbossjts-jacorb-4.17.18.Final.jar:4.17.18.Final] > at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75) > at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:92) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:276) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.as.ejb3.tx.CMTTxInterceptor.requiresNew(CMTTxInterceptor.java:368) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:240) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [jboss-as-ee-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:55) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ejb3.component.messagedriven.MessageDrivenComponentDescription$5$1.processInvocation(MessageDrivenComponentDescription.java:203) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45) [jboss-as-ee-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:185) [jboss-as-ee-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:182) [jboss-as-ee-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:73) [jboss-as-ee-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at javax.jms.MessageListener$$$view1.onMessage(Unknown Source) [jboss-jms-api_1.1_spec-1.0.1.Final-redhat-2.jar:1.0.1.Final-redhat-2] > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_51] > at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_51] > at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_51] > at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_51] > at org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.doInvoke(MessageEndpointInvocationHandler.java:140) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.as.ejb3.inflow.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:73) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at com.sun.proxy.$Proxy20.onMessage(Unknown Source) > at org.hornetq.ra.inflow.HornetQMessageHandler.onMessage(HornetQMessageHandler.java:328) > 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_51] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_51] > at java.lang.Thread.run(Thread.java:744) [rt.jar:1.7.0_51] >Caused by: java.lang.InterruptedException > at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) [rt.jar:1.7.0_51] > at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2188) [rt.jar:1.7.0_51] > at org.hornetq.core.protocol.core.impl.ChannelImpl.sendBlocking(ChannelImpl.java:359) > ... 54 more > >16:43:34,652 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::doPrepare() result for action-id (0:ffff7f000001:-7751a77e:53397eee:26) on record id: (0:ffff7f000001:-7751a77e:53397eee:2e) is (TwoPhaseOutcome.PREPARE_NOTOK) node id: (1) >16:43:34,652 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/XAResourceRecord for 0:ffff7f000001:-7751a77e:53397eee:2e >16:43:34,652 WARN [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) ARJUNA012073: BasicAction.End() - prepare phase of action-id 0:ffff7f000001:-7751a77e:53397eee:26 failed. >16:43:34,652 WARN [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) ARJUNA012075: Action Aborting >16:43:34,652 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::phase2Abort() for action-id 0:ffff7f000001:-7751a77e:53397eee:26 >16:43:34,653 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::doAbort (XAResourceRecord < resource:TestXAResource(TestXAResourceCommon(300, < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-7751a77e:53397eee:26, node_name=1, branch_uid=0:ffff7f000001:-7751a77e:53397eee:29, subordinatenodename=null, eis_name=unknown eis name >)), txid:< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-7751a77e:53397eee:26, node_name=1, branch_uid=0:ffff7f000001:-7751a77e:53397eee:29, subordinatenodename=null, eis_name=unknown eis name >, heuristic: TwoPhaseOutcome.FINISH_OK com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@153df5e5 >) >16:43:34,653 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) XAResourceRecord.topLevelAbort for XAResourceRecord < resource:TestXAResource(TestXAResourceCommon(300, < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-7751a77e:53397eee:26, node_name=1, branch_uid=0:ffff7f000001:-7751a77e:53397eee:29, subordinatenodename=null, eis_name=unknown eis name >)), txid:< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-7751a77e:53397eee:26, node_name=1, branch_uid=0:ffff7f000001:-7751a77e:53397eee:29, subordinatenodename=null, eis_name=unknown eis name >, heuristic: TwoPhaseOutcome.FINISH_OK com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@153df5e5 >, record id=0:ffff7f000001:-7751a77e:53397eee:2a >16:43:34,653 INFO [org.jboss.as.test.jbossts.common.TestXAResourceCommon] (Thread-0 (HornetQ-client-global-threads-635027840)) TestXAResourceCommon.rollback(Xid=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-7751a77e:53397eee:26, node_name=1, branch_uid=0:ffff7f000001:-7751a77e:53397eee:29, subordinatenodename=null, eis_name=unknown eis name >) >16:43:34,653 INFO [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (Thread-0 (HornetQ-client-global-threads-635027840)) removeLog(xid=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-7751a77e:53397eee:26, node_name=1, branch_uid=0:ffff7f000001:-7751a77e:53397eee:29, subordinatenodename=null, eis_name=unknown eis name > >16:43:34,654 INFO [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (Thread-0 (HornetQ-client-global-threads-635027840)) 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 >16:43:34,654 INFO [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (Thread-0 (HornetQ-client-global-threads-635027840)) logging 0 records to /home/ochaloup/Transactions/eap-tests-transactions/integration/jbossts/target/jbossas-jbossts/standalone/data/tx-object-store/TestXAResourceStateStore/TestXAResource.ser >16:43:34,655 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::doAbort() result for action-id (0:ffff7f000001:-7751a77e:53397eee:26) on record id: (0:ffff7f000001:-7751a77e:53397eee:2a) is (TwoPhaseOutcome.FINISH_OK) node id: (1) >16:43:34,655 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::doAbort (XAResourceRecord < resource:XAResourceWrapperImpl@b7d8a0b[xaResource=org.hornetq.ra.HornetQRAXAResource@5ef1de11 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:-7751a77e:53397eee:26, node_name=1, branch_uid=0:ffff7f000001:-7751a77e:53397eee:2d, 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@2ca43057 >) >16:43:34,655 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) XAResourceRecord.topLevelAbort for XAResourceRecord < resource:XAResourceWrapperImpl@b7d8a0b[xaResource=org.hornetq.ra.HornetQRAXAResource@5ef1de11 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:-7751a77e:53397eee:26, node_name=1, branch_uid=0:ffff7f000001:-7751a77e:53397eee:2d, 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@2ca43057 >, record id=0:ffff7f000001:-7751a77e:53397eee:2e >16:43:34,673 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::doAbort() result for action-id (0:ffff7f000001:-7751a77e:53397eee:26) on record id: (0:ffff7f000001:-7751a77e:53397eee:2e) is (TwoPhaseOutcome.FINISH_OK) node id: (1) >16:43:34,674 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::updateState() for action-id 0:ffff7f000001:-7751a77e:53397eee:26 >16:43:34,674 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::End() result for action-id (0:ffff7f000001:-7751a77e:53397eee:26) is (TwoPhaseOutcome.FINISH_OK) node id: (1) >16:43:34,674 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) SynchronizationImple.afterCompletion >16:43:34,674 TRACE [com.arjuna.ats.jta] (Thread-0 (HornetQ-client-global-threads-635027840)) SynchronizationImple.afterCompletion >16:43:34,674 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:26 removing TSThread:8 >16:43:34,674 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:26 removing TSThread:8 result = true >16:43:34,674 TRACE [com.arjuna.ats.arjuna] (Thread-0 (HornetQ-client-global-threads-635027840)) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:26 status: ActionStatus.ABORTED ) >16:43:34,675 ERROR [org.jboss.as.ejb3.invocation] (Thread-0 (HornetQ-client-global-threads-635027840)) JBAS014134: EJB Invocation failed on component mdb for method public abstract void javax.jms.MessageListener.onMessage(javax.jms.Message): javax.ejb.EJBTransactionRolledbackException: Transaction rolled back > at org.jboss.as.ejb3.tx.CMTTxInterceptor.handleEndTransactionException(CMTTxInterceptor.java:138) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:118) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:276) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.as.ejb3.tx.CMTTxInterceptor.requiresNew(CMTTxInterceptor.java:368) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:240) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [jboss-as-ee-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:55) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ejb3.component.messagedriven.MessageDrivenComponentDescription$5$1.processInvocation(MessageDrivenComponentDescription.java:203) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45) [jboss-as-ee-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:185) [jboss-as-ee-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:182) [jboss-as-ee-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:73) [jboss-as-ee-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at javax.jms.MessageListener$$$view1.onMessage(Unknown Source) [jboss-jms-api_1.1_spec-1.0.1.Final-redhat-2.jar:1.0.1.Final-redhat-2] > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_51] > at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_51] > at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_51] > at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_51] > at org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.doInvoke(MessageEndpointInvocationHandler.java:140) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.as.ejb3.inflow.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:73) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at com.sun.proxy.$Proxy20.onMessage(Unknown Source) > at org.hornetq.ra.inflow.HornetQMessageHandler.onMessage(HornetQMessageHandler.java:328) > 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_51] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_51] > at java.lang.Thread.run(Thread.java:744) [rt.jar:1.7.0_51] >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.18.Final.jar:4.17.18.Final] > at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126) [jbossjts-jacorb-4.17.18.Final.jar:4.17.18.Final] > at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75) > at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:92) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > ... 40 more > >16:43:34,678 ERROR [org.hornetq.ra] (Thread-0 (HornetQ-client-global-threads-635027840)) HQ154004: Failed to deliver message: javax.ejb.EJBTransactionRolledbackException: Transaction rolled back > at org.jboss.as.ejb3.tx.CMTTxInterceptor.handleEndTransactionException(CMTTxInterceptor.java:138) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:118) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:276) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.as.ejb3.tx.CMTTxInterceptor.requiresNew(CMTTxInterceptor.java:368) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:240) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [jboss-as-ee-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:55) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ejb3.component.messagedriven.MessageDrivenComponentDescription$5$1.processInvocation(MessageDrivenComponentDescription.java:203) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45) [jboss-as-ee-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:185) [jboss-as-ee-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:182) [jboss-as-ee-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1] > at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:73) [jboss-as-ee-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at javax.jms.MessageListener$$$view1.onMessage(Unknown Source) [jboss-jms-api_1.1_spec-1.0.1.Final-redhat-2.jar:1.0.1.Final-redhat-2] > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_51] > at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_51] > at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_51] > at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_51] > at org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.doInvoke(MessageEndpointInvocationHandler.java:140) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at org.jboss.as.ejb3.inflow.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:73) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > at com.sun.proxy.$Proxy20.onMessage(Unknown Source) > at org.hornetq.ra.inflow.HornetQMessageHandler.onMessage(HornetQMessageHandler.java:328) > 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_51] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_51] > at java.lang.Thread.run(Thread.java:744) [rt.jar:1.7.0_51] >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.18.Final.jar:4.17.18.Final] > at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126) [jbossjts-jacorb-4.17.18.Final.jar:4.17.18.Final] > at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75) > at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:92) [jboss-as-ejb3-7.4.0.Final-redhat-6.jar:7.4.0.Final-redhat-6] > ... 40 more > >16:43:34,704 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 66) BaseTransaction.begin >16:43:34,704 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) StateManager::StateManager( 2, 0 ) >16:43:34,705 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) BasicAction::BasicAction() >16:43:34,705 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) BasicAction::Begin() for action-id 0:ffff7f000001:-7751a77e:53397eee:35 >16:43:34,705 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) BasicAction::actionInitialise() for action-id 0:ffff7f000001:-7751a77e:53397eee:35 >16:43:34,705 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) ActionHierarchy::ActionHierarchy(5) >16:43:34,705 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) ActionHierarchy::add(0:ffff7f000001:-7751a77e:53397eee:35, 1) >16:43:34,705 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:35 adding Thread[ServerService Thread Pool -- 66,5,ServerService ThreadGroup] >16:43:34,705 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) BasicAction::addChildThread () action 0:ffff7f000001:-7751a77e:53397eee:35 adding Thread[ServerService Thread Pool -- 66,5,ServerService ThreadGroup] result = true >16:43:34,705 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:35 status: ActionStatus.RUNNING, 300 ) >16:43:34,705 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:35 status: ActionStatus.RUNNING, 300 ) >16:43:34,705 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 66) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE >16:43:34,705 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 66) BaseTransaction.commit >16:43:34,706 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 66) TransactionImple.commitAndDisassociate >16:43:34,706 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) BasicAction::End() for action-id 0:ffff7f000001:-7751a77e:53397eee:35 >16:43:34,706 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) BasicAction::End() result for action-id (0:ffff7f000001:-7751a77e:53397eee:35) is (TwoPhaseOutcome.PREPARE_OK) node id: (1) >16:43:34,706 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:35 removing TSThread:e >16:43:34,706 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) BasicAction::removeChildThread () action 0:ffff7f000001:-7751a77e:53397eee:35 removing TSThread:e result = true >16:43:34,706 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 66) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:-7751a77e:53397eee:35 status: ActionStatus.COMMITTED ) >16:43:34,718 INFO [org.jboss.as.server.deployment] (MSC service thread 1-3) JBAS015877: Stopped deployment crashrecovery-jms.jar (runtime-name: crashrecovery-jms.jar) in 90ms >16:43:34,864 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/20/dd7b85ab034a6bea8e7a9026c14250807151b2/content >16:43:34,865 INFO [org.jboss.as.server] (management-handler-thread - 3) JBAS018558: Undeployed "crashrecovery-jms.jar" (runtime-name: "crashrecovery-jms.jar") >16:43:34,875 INFO [org.jboss.as.messaging] (ServerService Thread Pool -- 66) JBAS011605: Unbound messaging object to jndi name java:jboss/queue/MDBTriggerQueue >16:43:35,031 INFO [org.jboss.as.messaging] (ServerService Thread Pool -- 66) JBAS011605: Unbound messaging object to jndi name java:jboss/queue/crashRecoveryQueue >16:43:35,180 INFO [org.apache.coyote.http11.Http11NioProtocol] (MSC service thread 1-5) JBWEB003075: Coyote HTTP/1.1 pausing on: http-localhost.localdomain/127.0.0.1:8080 >16:43:35,180 INFO [org.apache.coyote.http11.Http11NioProtocol] (MSC service thread 1-5) JBWEB003077: Coyote HTTP/1.1 stopping on : http-localhost.localdomain/127.0.0.1:8080 >16:43:35,187 INFO [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-8) JBAS010409: Unbound data source [java:jboss/datasources/ExampleDS] >16:43:35,191 INFO [org.jboss.jaxr] (MSC service thread 1-2) JBAS014002: UnBinding JAXR ConnectionFactory: java:jboss/jaxr/ConnectionFactory >16:43:35,189 INFO [org.jboss.as.connector.deployment] (MSC service thread 1-7) JBAS010410: Unbound JCA ConnectionFactory [java:/JmsXA] >16:43:35,205 INFO [org.apache.catalina.core] (MSC service thread 1-1) JBWEB001079: Container org.apache.catalina.core.ContainerBase.[jboss.web].[default-host].[/] has not been started >16:43:35,198 INFO [org.jboss.as.messaging] (ServerService Thread Pool -- 66) JBAS011605: Unbound messaging object to jndi name java:jboss/exported/jms/RemoteConnectionFactory >16:43:35,245 INFO [org.jboss.as.server.deployment] (MSC service thread 1-3) JBAS015877: Stopped deployment dsdriver.jar (runtime-name: dsdriver.jar) in 67ms >16:43:35,252 INFO [org.hornetq.ra] (ServerService Thread Pool -- 64) HQ151003: HornetQ resource adaptor stopped >16:43:35,256 INFO [com.arjuna.ats.jbossatx] (MSC service thread 1-3) ARJUNA032018: Destroying TransactionManagerService >16:43:35,260 INFO [com.arjuna.ats.jbossatx] (MSC service thread 1-5) ARJUNA032014: Stopping transaction recovery manager >16:43:35,262 DEBUG [com.arjuna.ats.arjuna] (Listener:4712) Recovery listener existing com.arjuna.ats.internal.arjuna.recovery.WorkerService >16:43:35,263 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-5) PeriodicRecovery: Mode <== TERMINATED >16:43:35,263 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-5) PeriodicRecovery: shutdown scan wait complete >16:43:35,263 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread exiting >16:43:35,344 INFO [org.hornetq.core.server] (ServerService Thread Pool -- 64) HQ221002: HornetQ Server version 2.3.18.Final (2.3.18, 123) [be3d1309-b8e2-11e3-b69d-9962638eac79] stopped >16:43:35,359 INFO [org.jboss.as] (MSC service thread 1-8) JBAS015950: JBoss EAP 6.3.0.Alpha2 (AS 7.4.0.Final-redhat-6) stopped in 165ms
<b>You cannot view the attachment while viewing its details because your browser does not support IFRAMEs. <a href="attachment.cgi?id=880788">View the attachment on a separate page</a>.</b>
View Attachment As Raw
Actions:
View
Attachments on
bug 1082652
:
880787
| 880788 |
880789
|
902145