Attachment 893362 Details for Bug 1095413 – server.log with error

server.log with error

server.log (text/x-log), 137.36 KB, created by Ondrej Chaloupka on 2014-05-07 16:02:40 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Ondrej Chaloupka

Created: 2014-05-07 16:02:40 UTC

Size: 137.36 KB

patch

obsolete

>17:31:14,385 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 35) JBAS010280: Activating Infinispan subsystem.
>17:31:14,471 INFO  [org.jboss.as.jacorb] (ServerService Thread Pool -- 36) JBAS016300: Activating JacORB Subsystem
>17:31:14,494 INFO  [org.jboss.as.connector.logging] (MSC service thread 1-6) JBAS010408: Starting JCA Subsystem (IronJacamar 1.0.26.Final-redhat-1)
>17:31:14,497 INFO  [org.jboss.as.naming] (ServerService Thread Pool -- 47) JBAS011800: Activating Naming Subsystem
>17:31:14,553 INFO  [org.jboss.as.security] (ServerService Thread Pool -- 52) JBAS013171: Activating Security Subsystem
>17:31:14,555 INFO  [org.jboss.as.jsf] (ServerService Thread Pool -- 43) JBAS012605: Activated the following JSF Implementations: [main, 1.2]
>17:31:14,564 INFO  [org.jboss.as.security] (MSC service thread 1-1) JBAS013170: Current PicketBox version=4.0.19.SP5-redhat-1
>17:31:14,594 WARN  [org.jboss.as.txn] (ServerService Thread Pool -- 54) JBAS010153: Node identifier property is set to the default value. Please make sure it is unique.
>17:31:14,620 INFO  [org.jboss.as.webservices] (ServerService Thread Pool -- 56) JBAS015537: Activating WebServices Extension
>17:31:14,682 INFO  [org.jboss.as.mail.extension] (MSC service thread 1-6) JBAS015400: Bound mail session [java:jboss/mail/Default]
>17:31:14,683 INFO  [org.jboss.as.naming] (MSC service thread 1-2) JBAS011802: Starting Naming Service
>17:31:14,717 INFO  [org.jboss.jaxr] (MSC service thread 1-8) JBAS014000: Started JAXR subsystem, binding JAXR connection factory into JNDI as: java:jboss/jaxr/ConnectionFactory
>17:31:14,716 INFO  [org.jboss.as.connector.subsystems.datasources] (ServerService Thread Pool -- 31) JBAS010403: Deploying JDBC-compliant driver class org.h2.Driver (version 1.3)
>17:31:15,019 INFO  [com.arjuna.ats.jbossatx] (MSC service thread 1-1) ARJUNA032010: JBossTS Recovery Service (tag: f389d3924787dbdae73e40b9bd68ea676fe40690) - JBoss Inc.
>17:31:15,055 INFO  [com.arjuna.ats.arjuna] (MSC service thread 1-1) ARJUNA012324: Start RecoveryActivators
>17:31:15,057 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-1) Expiry scan interval set to 43200 seconds
>17:31:15,057 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) Loading class com.arjuna.ats.internal.arjuna.recovery.ExpiredTransactionStatusManagerScanner
>17:31:15,068 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-1) Expiry scan interval set to  43200  seconds
>17:31:15,069 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-1) ExpiredTransactionStatusManagerScanner created, with expiry time of 43200  seconds
>17:31:15,070 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) Loading class com.arjuna.ats.internal.arjuna.objectstore.ShadowNoFileLockStore
>17:31:15,078 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) FileSystemStore.createHierarchy(/home/ochaloup/tmp/jbossas-testsuite-cmr/jboss-eap-6.3-src/testsuite/integration/basic/target/jbossas/standalone/data/tx-object-store/ShadowNoFileLockStore/defaultStore/)
>17:31:15,087 INFO  [org.apache.coyote.http11.Http11Protocol] (MSC service thread 1-8) JBWEB003001: Coyote HTTP/1.1 initializing on : http-localhost.localdomain/127.0.0.1:8080
>17:31:15,088 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-1) ExpiredEntryMonitor - constructed
>17:31:15,095 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221000: live server is starting with configuration HornetQ Configuration (clustered=false,backup=false,sharedStore=true,journalDirectory=/home/ochaloup/tmp/jbossas-testsuite-cmr/jboss-eap-6.3-src/testsuite/integration/basic/target/jbossas/standalone/data/messagingjournal,bindingsDirectory=/home/ochaloup/tmp/jbossas-testsuite-cmr/jboss-eap-6.3-src/testsuite/integration/basic/target/jbossas/standalone/data/messagingbindings,largeMessagesDirectory=/home/ochaloup/tmp/jbossas-testsuite-cmr/jboss-eap-6.3-src/testsuite/integration/basic/target/jbossas/standalone/data/messaginglargemessages,pagingDirectory=/home/ochaloup/tmp/jbossas-testsuite-cmr/jboss-eap-6.3-src/testsuite/integration/basic/target/jbossas/standalone/data/messagingpaging)
>17:31:15,098 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221006: Waiting to obtain live lock
>17:31:15,109 INFO  [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) ARJUNA012296: ExpiredEntryMonitor running at Wed, 7 May 2014 17:31:15
>17:31:15,110 DEBUG [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) ExpiredTransactionStatusManagerScanner - scanning to remove items from before Wed, 7 May 2014 05:31:15
>17:31:15,111 TRACE [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) InputObjectState::InputObjectState()
>17:31:15,112 INFO  [org.apache.coyote.http11.Http11Protocol] (MSC service thread 1-8) JBWEB003000: Coyote HTTP/1.1 starting on: http-localhost.localdomain/127.0.0.1:8080
>17:31:15,126 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)
>17:31:15,127 TRACE [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) OutputObjectState::OutputObjectState()
>17:31:15,134 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) Loading class com.arjuna.ats.internal.jta.recovery.arjunacore.CommitMarkableResourceRecordRecoveryModule
>17:31:15,142 DEBUG [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor)   
>17:31:15,205 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) Loading class com.arjuna.ats.internal.arjuna.coordinator.CheckedActionFactoryImple
>17:31:15,206 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) StateManager::StateManager( 2, 0 )
>17:31:15,206 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) BasicAction::BasicAction()
>17:31:15,208 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) InputObjectState::InputObjectState()
>17:31:15,208 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) FileSystemStore.allObjUids(/Recovery/TransactionStatusManager, InputObjectState Uid   : 0:0:0:0:0
>InputObjectState Type  : null
>InputObjectState Size  : 0
>InputObjectState Buffer: , -1)
>17:31:15,209 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) OutputObjectState::OutputObjectState()
>17:31:15,209 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) Loading class com.arjuna.ats.internal.arjuna.recovery.AtomicActionRecoveryModule
>17:31:15,222 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) StateManager::StateManager( 2, 0 )
>17:31:15,222 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) BasicAction::BasicAction()
>17:31:15,222 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-1) AtomicActionRecoveryModule created
>17:31:15,223 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) InputObjectState::InputObjectState()
>17:31:15,223 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) FileSystemStore.allObjUids(/Recovery/TransactionStatusManager, InputObjectState Uid   : 0:0:0:0:0
>InputObjectState Type  : null
>InputObjectState Size  : 0
>InputObjectState Buffer: , -1)
>17:31:15,223 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) OutputObjectState::OutputObjectState()
>17:31:15,223 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) Loading class com.arjuna.ats.internal.txoj.recovery.TORecoveryModule
>17:31:15,241 DEBUG [com.arjuna.ats.txoj] (MSC service thread 1-1) TORecoveryModule created
>17:31:15,241 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) Loading class com.arjuna.ats.internal.arjuna.objectstore.ShadowNoFileLockStore
>17:31:15,241 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) FileSystemStore.createHierarchy(/home/ochaloup/tmp/jbossas-testsuite-cmr/jboss-eap-6.3-src/testsuite/integration/basic/target/jbossas/standalone/data/tx-object-store/ShadowNoFileLockStore/defaultStore/)
>17:31:15,241 INFO  [org.jboss.as.jacorb] (MSC service thread 1-3) JBAS016330: CORBA ORB Service started
>17:31:15,241 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) Loading class com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule
>17:31:15,243 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) InputObjectState::InputObjectState()
>17:31:15,243 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) Loading class com.arjuna.ats.internal.jta.recovery.arjunacore.JTATransactionLogXAResourceOrphanFilter
>17:31:15,243 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) Loading class com.arjuna.ats.internal.jta.recovery.arjunacore.JTANodeNameXAResourceOrphanFilter
>17:31:15,244 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-1) Loading class com.arjuna.ats.internal.jta.recovery.arjunacore.SubordinateJTAXAResourceOrphanFilter
>17:31:15,255 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221013: Using NIO Journal
>17:31:15,255 INFO  [com.arjuna.ats.arjuna] (MSC service thread 1-1) ARJUNA012343: RecoveryManagerImple is ready. Socket listener is turned off.
>17:31:15,256 INFO  [com.arjuna.ats.jbossatx] (MSC service thread 1-1) ARJUNA032013: Starting transaction recovery manager
>17:31:15,266 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) ObjectStoreDir: /home/ochaloup/tmp/jbossas-testsuite-cmr/jboss-eap-6.3-src/testsuite/integration/basic/target/jbossas/standalone/data/tx-object-store
>17:31:15,266 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) StateManager::StateManager( 2, 0 )
>17:31:15,266 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) BasicAction::BasicAction()
>17:31:15,281 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread Status <== SCANNING
>17:31:15,281 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread scanning
>17:31:15,281 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) Periodic recovery first pass at Wed, 7 May 2014 17:31:15
>17:31:15,281 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) CommitMarkableResourceRecordRecoveryModule::periodicWorkFirstPass
>17:31:15,288 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) StateManager::StateManager( 0:0:0:0:0 )
>17:31:15,288 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) BasicAction::BasicAction(0:0:0:0:0)
>17:31:15,286 WARN  [com.arjuna.ats.arjuna] (Periodic Recovery) Could not lookup CommitMarkableResource: java:jboss/datasources/ExampleDS
>17:31:15,297 TRACE [com.arjuna.ats.jts] (MSC service thread 1-5) ArjunaTransactionImple::ArjunaTransactionImple ( 0:0:0:0:0 )
>17:31:15,292 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) Could not lookup CommitMarkableResource: java:jboss/datasources/ExampleDS: javax.naming.NameNotFoundException: Error looking up datasources/ExampleDS, service service jboss.naming.context.java.jboss.datasources.ExampleDS is not started
>	at org.jboss.as.naming.ServiceBasedNamingStore.lookup(ServiceBasedNamingStore.java:132)
>	at org.jboss.as.naming.ServiceBasedNamingStore.lookup(ServiceBasedNamingStore.java:80)
>	at org.jboss.as.naming.NamingContext.lookup(NamingContext.java:197)
>	at org.jboss.as.naming.NamingContext.lookup(NamingContext.java:174)
>	at org.jboss.as.naming.InitialContext$DefaultInitialContext.lookup(InitialContext.java:243)
>	at org.jboss.as.naming.NamingContext.lookup(NamingContext.java:183)
>	at org.jboss.as.naming.NamingContext.lookup(NamingContext.java:179)
>	at javax.naming.InitialContext.lookup(InitialContext.java:411) [rt.jar:1.7.0_51]
>	at javax.naming.InitialContext.lookup(InitialContext.java:411) [rt.jar:1.7.0_51]
>	at com.arjuna.ats.internal.jta.recovery.arjunacore.CommitMarkableResourceRecordRecoveryModule.periodicWorkFirstPass(CommitMarkableResourceRecordRecoveryModule.java:207) [jbossjts-jacorb-4.17.19.Final-redhat-1.jar:4.17.19.Final-redhat-1]
>	at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal(PeriodicRecovery.java:743) [jbossjts-jacorb-4.17.19.Final-redhat-1.jar:4.17.19.Final-redhat-1]
>	at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run(PeriodicRecovery.java:371) [jbossjts-jacorb-4.17.19.Final-redhat-1.jar:4.17.19.Final-redhat-1]
>
>17:31:15,299 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState()
>17:31:15,299 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)
>17:31:15,300 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState()
>17:31:15,300 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) processing /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction transactions
>17:31:15,300 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState()
>17:31:15,300 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)
>17:31:15,301 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState()
>17:31:15,301 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
>17:31:15,302 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState()
>17:31:15,302 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) AtomicActionRecoveryModule first pass
>17:31:15,302 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)
>17:31:15,302 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState()
>17:31:15,302 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) processing /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction transactions
>17:31:15,302 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
>17:31:15,302 DEBUG [com.arjuna.ats.txoj] (Periodic Recovery) TORecoveryModule - first pass
>17:31:15,302 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState()
>17:31:15,302 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.allTypes(InputObjectState Uid   : 0:0:0:0:0
>InputObjectState Type  : null
>InputObjectState Size  : 0
>InputObjectState Buffer: )
>17:31:15,303 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState()
>17:31:15,303 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.allTypes(OutputObjectState Uid   : 0:ffff7f000001:67f9ad09:536a51c3:a
>OutputObjectState Type  : null
>OutputObjectState Size  : 20
>OutputObjectState Buffer: , EISNAME)
>17:31:15,307 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState()
>17:31:15,307 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.allObjUids(EISNAME, InputObjectState Uid   : 0:0:0:0:0
>InputObjectState Type  : null
>InputObjectState Size  : 0
>InputObjectState Buffer: , 2)
>17:31:15,308 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState()
>17:31:15,308 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) ShadowingStore.genPathName(0:ffff7f000001:1258154c:536a3d63:1c, EISNAME, StateType.OS_SHADOW)
>17:31:15,308 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.genPathName(0:ffff7f000001:1258154c:536a3d63:1c, EISNAME, 10)
>17:31:15,308 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) ShadowingStore.genPathName(0:ffff7f000001:1258154c:536a3d63:1c, EISNAME, StateType.OS_ORIGINAL)
>17:31:15,309 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.genPathName(0:ffff7f000001:1258154c:536a3d63:1c, EISNAME, 11)
>17:31:15,309 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) ShadowingStore.currentState(0:ffff7f000001:1258154c:536a3d63:1c, EISNAME) - returning StateStatus.OS_COMMITTED
>17:31:15,309 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
>17:31:15,312 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) Loading class com.arjuna.ats.jbossatx.jta.TransactionManagerDelegate
>17:31:15,317 INFO  [com.arjuna.ats.jbossatx] (MSC service thread 1-5) ARJUNA032017: JBossTS Transaction Service (JTA version - tag: f389d3924787dbdae73e40b9bd68ea676fe40690) - JBoss Inc.
>17:31:15,324 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) TransactionReaper::instantiate()
>17:31:15,329 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Local XARecoveryModule - first pass
>17:31:15,329 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState()
>17:31:15,331 TRACE [com.arjuna.ats.arjuna] (MSC service thread 1-5) TransactionReaper::TransactionReaper ( 9223372036854775807 )
>17:31:15,335 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)
>17:31:15,335 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState()
>17:31:15,350 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) xarecovery of RecoveryOnlyEJBXAResource{receiverContext=EJBReceiverContext{clientContext=org.jboss.ejb.client.EJBClientContext@3f7fd343, receiver=org.jboss.as.ejb3.remote.LocalEjbReceiver@f8f516e}, transactionOriginNodeIdentifier='1'}
>17:31:15,349 INFO  [org.jboss.ws.common.management] (MSC service thread 1-4) JBWS022052: Starting JBoss Web Services - Stack CXF Server 4.3.0.Final-redhat-2
>17:31:15,366 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Found 0 xids in doubt
>17:31:15,368 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) ReaperThread.run ()
>17:31:15,368 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) Thread Thread[Transaction Reaper,5,main] sleeping for 9223370637378100439
>17:31:15,372 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-5) registering bean jboss.jta:type=ObjectStore
>17:31:15,372 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ReaperWorkerThread.run ()
>17:31:15,373 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) Thread Thread[Transaction Reaper Worker 0,5,main] waiting for cancelled TXs
>17:31:15,373 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids new recoveryXids RecoveryOnlyEJBXAResource{receiverContext=EJBReceiverContext{clientContext=org.jboss.ejb.client.EJBClientContext@3f7fd343, receiver=org.jboss.as.ejb3.remote.LocalEjbReceiver@f8f516e}, transactionOriginNodeIdentifier='1'} 1399476675367
>17:31:15,376 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
>17:31:15,415 DEBUG [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (MSC service thread 1-1) start: CachedConnectionManagerImpl@60e7e2d1[debug=false error=false transactionManager=org.jboss.jca.core.tx.jbossts.TransactionManagerDelegator@17dc390b transactionSynchronizationRegistry=com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionSynchronizationRegistryImple@7b250d69 userTransactionRegistry=org.jboss.jca.core.tx.jbossts.UserTransactionRegistryImpl@3d93a7a8 currentObjects=null objectToConnectionManagerMap={} connectionStackTraces={}]
>17:31:15,461 INFO  [org.jboss.as.jacorb] (MSC service thread 1-6) JBAS016328: CORBA Naming Service started
>17:31:15,487 TRACE [org.jboss.jca.core.connectionmanager.TxConnectionManager] (MSC service thread 1-2) connectable=false
>17:31:15,495 INFO  [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-6) JBAS010400: Bound data source [java:jboss/datasources/MaskedDS]
>17:31:15,540 INFO  [org.jboss.as.server.deployment.scanner] (MSC service thread 1-4) JBAS015012: Started FileSystemDeploymentService for directory /home/ochaloup/tmp/jbossas-testsuite-cmr/jboss-eap-6.3-src/testsuite/integration/basic/target/jbossas/standalone/deployments
>17:31:15,543 INFO  [org.jboss.as.remoting] (MSC service thread 1-1) JBAS017100: Listening on 127.0.0.1:4447
>17:31:15,543 INFO  [org.jboss.as.remoting] (MSC service thread 1-7) JBAS017100: Listening on 127.0.0.1:9999
>17:31:15,545 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-6) JBAS015876: Starting deployment of "postgresql-9.3-1100.jdbc4.jar" (runtime-name: "postgresql-9.3-1100.jdbc4.jar")
>17:31:15,603 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221034: Waiting to obtain live lock
>17:31:15,604 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221035: Live Server Obtained live lock
>17:31:16,169 INFO  [org.jboss.as.connector.deployers.jdbc] (MSC service thread 1-2) JBAS010404: Deploying non-JDBC-compliant driver class org.postgresql.Driver (version 9.3)
>17:31:16,184 TRACE [org.jboss.jca.core.connectionmanager.TxConnectionManager] (MSC service thread 1-7) connectable=true
>17:31:16,186 INFO  [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-4) JBAS010400: Bound data source [java:jboss/datasources/ExampleDS]
>17:31:16,497 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221020: Started Netty Acceptor version 3.6.7.Final-redhat-1-3c0a3ac 127.0.0.1:5445 for CORE protocol
>17:31:16,501 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221020: Started Netty Acceptor version 3.6.7.Final-redhat-1-3c0a3ac 127.0.0.1:5455 for CORE protocol
>17:31:16,504 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221007: Server is now live
>17:31:16,504 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 58) HQ221001: HornetQ Server version 2.3.18.Final (2.3.18, 123) [7bb985fe-d5f0-11e3-8778-9dadac5c51b7] 
>17:31:16,522 INFO  [org.jboss.as.messaging] (ServerService Thread Pool -- 58) JBAS011601: Bound messaging object to jndi name java:/ConnectionFactory
>17:31:16,524 INFO  [org.jboss.as.messaging] (ServerService Thread Pool -- 60) JBAS011601: Bound messaging object to jndi name java:jboss/exported/jms/RemoteConnectionFactory
>17:31:16,525 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 61) HQ221003: trying to deploy queue jms.queue.DLQ
>17:31:16,534 INFO  [org.jboss.as.messaging] (ServerService Thread Pool -- 61) JBAS011601: Bound messaging object to jndi name java:/jms/queue/DLQ
>17:31:16,534 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 59) HQ221003: trying to deploy queue jms.queue.ExpiryQueue
>17:31:16,535 INFO  [org.jboss.as.messaging] (ServerService Thread Pool -- 59) JBAS011601: Bound messaging object to jndi name java:/jms/queue/ExpiryQueue
>17:31:16,579 TRACE [org.jboss.jca.core.connectionmanager.TxConnectionManager] (MSC service thread 1-2) connectable=false
>17:31:16,579 INFO  [org.jboss.as.connector.deployment] (MSC service thread 1-2) JBAS010406: Registered connection factory java:/JmsXA
>17:31:16,610 INFO  [org.hornetq.ra] (MSC service thread 1-2) HornetQ resource adaptor started
>17:31:16,611 INFO  [org.jboss.as.connector.services.resourceadapters.ResourceAdapterActivatorService$ResourceAdapterActivator] (MSC service thread 1-2) IJ020002: Deployed: file://RaActivatorhornetq-ra
>17:31:16,613 INFO  [org.jboss.as.connector.deployment] (MSC service thread 1-1) JBAS010401: Bound JCA ConnectionFactory [java:/JmsXA]
>17:31:16,664 INFO  [org.jboss.as.server] (ServerService Thread Pool -- 32) JBAS018559: Deployed "postgresql-9.3-1100.jdbc4.jar" (runtime-name : "postgresql-9.3-1100.jdbc4.jar")
>17:31:16,771 INFO  [org.jboss.as] (Controller Boot Thread) JBAS015961: Http management interface listening on http://127.0.0.1:9990/management
>17:31:16,773 INFO  [org.jboss.as] (Controller Boot Thread) JBAS015951: Admin console listening on http://127.0.0.1:9990
>17:31:16,773 INFO  [org.jboss.as] (Controller Boot Thread) JBAS015874: JBoss EAP 6.3.0.Beta1 (AS 7.4.0.Final-redhat-11) started in 4832ms - Started 228 of 265 services (69 services are lazy, passive or on-demand)
>17:31:18,207 INFO  [org.jboss.as.repository] (management-handler-thread - 1) JBAS014900: Content added at location /home/ochaloup/tmp/jbossas-testsuite-cmr/jboss-eap-6.3-src/testsuite/integration/basic/target/jbossas/standalone/data/content/09/8843a033061706ae6f0d963607b345fa716a52/content
>17:31:18,219 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-2) JBAS015876: Starting deployment of "arquillian-service" (runtime-name: "arquillian-service")
>17:31:18,340 WARN  [org.jboss.as.dependency.private] (MSC service thread 1-3) JBAS018567: Deployment "deployment.arquillian-service" is using a private module ("org.jboss.as.jmx:main") which may be changed or removed in future versions without notice.
>17:31:18,340 WARN  [org.jboss.as.dependency.private] (MSC service thread 1-3) JBAS018567: Deployment "deployment.arquillian-service" is using a private module ("org.jboss.as.server:main") which may be changed or removed in future versions without notice.
>17:31:18,344 WARN  [org.jboss.as.dependency.private] (MSC service thread 1-3) JBAS018567: Deployment "deployment.arquillian-service" is using a private module ("org.jboss.as.osgi:main") which may be changed or removed in future versions without notice.
>17:31:18,345 WARN  [org.jboss.as.dependency.private] (MSC service thread 1-3) JBAS018567: Deployment "deployment.arquillian-service" is using a private module ("org.jboss.jandex:main") which may be changed or removed in future versions without notice.
>17:31:18,345 WARN  [org.jboss.as.dependency.private] (MSC service thread 1-3) JBAS018567: Deployment "deployment.arquillian-service" is using a private module ("org.jboss.osgi.framework:main") which may be changed or removed in future versions without notice.
>17:31:18,354 WARN  [org.jboss.weld.deployer] (MSC service thread 1-4) JBAS016012: Deployment deployment "arquillian-service" contains CDI annotations but beans.xml was not found.
>17:31:18,505 INFO  [org.jboss.as.server] (management-handler-thread - 1) JBAS018559: Deployed "arquillian-service" (runtime-name : "arquillian-service")
>17:31:20,726 INFO  [org.jboss.as.repository] (management-handler-thread - 2) JBAS014900: Content added at location /home/ochaloup/tmp/jbossas-testsuite-cmr/jboss-eap-6.3-src/testsuite/integration/basic/target/jbossas/standalone/data/content/1b/cb4723be079c9891a82c2f954d5bba795f66be/content
>17:31:20,730 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-2) JBAS015876: Starting deployment of "ejb-remote-client-api-usertx-test.ear" (runtime-name: "ejb-remote-client-api-usertx-test.ear")
>17:31:20,740 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-5) JBAS015876: Starting deployment of "null" (runtime-name: "ejb.jar")
>17:31:20,771 INFO  [org.jboss.as.jpa] (MSC service thread 1-1) JBAS011401: Read persistence.xml for ejb-client-tx-pu
>17:31:20,835 INFO  [org.jboss.as.ejb3.deployment.processors.EjbJndiBindingsDeploymentUnitProcessor] (MSC service thread 1-2) JNDI bindings for session bean named BatchCreationBean in deployment unit subdeployment "ejb.jar" of deployment "ejb-remote-client-api-usertx-test.ear" are as follows:
>
>	java:global/ejb-remote-client-api-usertx-test/ejb/BatchCreationBean!org.jboss.as.test.integration.ejb.remote.client.api.tx.RemoteBatch
>	java:app/ejb/BatchCreationBean!org.jboss.as.test.integration.ejb.remote.client.api.tx.RemoteBatch
>	java:module/BatchCreationBean!org.jboss.as.test.integration.ejb.remote.client.api.tx.RemoteBatch
>	java:jboss/exported/ejb-remote-client-api-usertx-test/ejb/BatchCreationBean!org.jboss.as.test.integration.ejb.remote.client.api.tx.RemoteBatch
>	java:global/ejb-remote-client-api-usertx-test/ejb/BatchCreationBean
>	java:app/ejb/BatchCreationBean
>	java:module/BatchCreationBean
>
>17:31:20,836 INFO  [org.jboss.as.ejb3.deployment.processors.EjbJndiBindingsDeploymentUnitProcessor] (MSC service thread 1-2) JNDI bindings for session bean named CMTBean in deployment unit subdeployment "ejb.jar" of deployment "ejb-remote-client-api-usertx-test.ear" are as follows:
>
>	java:global/ejb-remote-client-api-usertx-test/ejb/CMTBean!org.jboss.as.test.integration.ejb.remote.client.api.tx.CMTRemote
>	java:app/ejb/CMTBean!org.jboss.as.test.integration.ejb.remote.client.api.tx.CMTRemote
>	java:module/CMTBean!org.jboss.as.test.integration.ejb.remote.client.api.tx.CMTRemote
>	java:jboss/exported/ejb-remote-client-api-usertx-test/ejb/CMTBean!org.jboss.as.test.integration.ejb.remote.client.api.tx.CMTRemote
>	java:global/ejb-remote-client-api-usertx-test/ejb/CMTBean
>	java:app/ejb/CMTBean
>	java:module/CMTBean
>
>17:31:20,837 INFO  [org.jboss.as.ejb3.deployment.processors.EjbJndiBindingsDeploymentUnitProcessor] (MSC service thread 1-2) JNDI bindings for session bean named BatchFetchingBean in deployment unit subdeployment "ejb.jar" of deployment "ejb-remote-client-api-usertx-test.ear" are as follows:
>
>	java:global/ejb-remote-client-api-usertx-test/ejb/BatchFetchingBean!org.jboss.as.test.integration.ejb.remote.client.api.tx.BatchRetriever
>	java:app/ejb/BatchFetchingBean!org.jboss.as.test.integration.ejb.remote.client.api.tx.BatchRetriever
>	java:module/BatchFetchingBean!org.jboss.as.test.integration.ejb.remote.client.api.tx.BatchRetriever
>	java:jboss/exported/ejb-remote-client-api-usertx-test/ejb/BatchFetchingBean!org.jboss.as.test.integration.ejb.remote.client.api.tx.BatchRetriever
>	java:global/ejb-remote-client-api-usertx-test/ejb/BatchFetchingBean
>	java:app/ejb/BatchFetchingBean
>	java:module/BatchFetchingBean
>
>17:31:20,936 INFO  [org.jboss.as.jpa] (ServerService Thread Pool -- 21) JBAS011402: Starting Persistence Unit Service 'ejb-remote-client-api-usertx-test.ear/ejb.jar#ejb-client-tx-pu'
>17:31:20,937 INFO  [org.jboss.as.arquillian] (MSC service thread 1-1) Arquillian deployment detected: ArquillianConfig[service=jboss.arquillian.config."ejb.jar",unit=ejb.jar,tests=[org.jboss.as.test.integration.ejb.remote.client.api.tx.EJBClientUserTransactionTestCase, org.jboss.as.test.integration.ejb.remote.client.api.tx.EJBClientXidTransactionTestCase]]
>17:31:21,051 INFO  [org.hibernate.annotations.common.Version] (ServerService Thread Pool -- 21) HCANN000001: Hibernate Commons Annotations {4.0.1.Final-redhat-2}
>17:31:21,056 INFO  [org.hibernate.Version] (ServerService Thread Pool -- 21) HHH000412: Hibernate Core {4.2.12.Final-redhat-1}
>17:31:21,058 INFO  [org.hibernate.cfg.Environment] (ServerService Thread Pool -- 21) HHH000206: hibernate.properties not found
>17:31:21,060 INFO  [org.hibernate.cfg.Environment] (ServerService Thread Pool -- 21) HHH000021: Bytecode provider name : javassist
>17:31:21,077 INFO  [org.hibernate.ejb.Ejb3Configuration] (ServerService Thread Pool -- 21) HHH000204: Processing PersistenceUnitInfo [
>	name: ejb-client-tx-pu
>	...]
>17:31:21,149 INFO  [org.hibernate.service.jdbc.connections.internal.ConnectionProviderInitiator] (ServerService Thread Pool -- 21) HHH000130: Instantiating explicit connection provider: org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider
>17:31:21,169 TRACE [org.jboss.jca.core.connectionmanager.TxConnectionManager] (ServerService Thread Pool -- 21) Subject: null
>17:31:21,173 TRACE [org.jboss.jca.core.connectionmanager.TxConnectionManager] (ServerService Thread Pool -- 21) getManagedConnection interleaving=false , tx=null
>17:31:21,179 DEBUG [org.jboss.jca.core.connectionmanager.pool.idle.IdleRemover] (ServerService Thread Pool -- 21) Register pool: SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] (interval=1800000)
>17:31:21,179 DEBUG [org.jboss.jca.core.connectionmanager.pool.idle.IdleRemover] (ServerService Thread Pool -- 21) About to notify thread: old next: 1399477581179, new next: 1399477581179
>17:31:21,179 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 21) TransactionSynchronizationRegistryImple.getTransactionKey
>17:31:21,179 TRACE [org.jboss.jca.core.connectionmanager.pool.idle.IdleRemover] (IdleRemover) Result of await: true
>17:31:21,180 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 21) TransactionSynchronizationRegistryImple.getTransactionKey
>17:31:21,180 DEBUG [org.jboss.jca.core.connectionmanager.pool.idle.IdleRemover] (IdleRemover) Notifying pools, interval: 900000
>17:31:21,181 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 21) getConnection(null, WrappedConnectionRequestInfo@36592c9b[userName=crashrec])
>ManagedConnectionPool: 236ea9f9
>Method: getConnection(null, WrappedConnectionRequestInfo@36592c9b[userName=crashrec])
>ManagedConnectionFactory:
>  Class: org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory
>  Object: 46216f19
>ConnectionListenerFactory:
>  Class: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl
>  Object: 3d04f647
>Pool:
>  Name: ExampleDS
>PoolConfiguration:
>  MinSize: 0
>  MaxSize: 20
>  BlockingTimeout: 30000
>  IdleTimeoutMinutes: 30
>  BackgroundValidation: false
>  BackgroundValidationMillis: 0
>  StrictMin: false
>  UseFastFail: false
>Available (0):
>InUse (0):
>Statistics:
>  ActiveCount: 0
>  AvailableCount: 0
>  AverageBlockingTime: 0
>  AverageCreationTime: 0
>  CreatedCount: 0
>  DestroyedCount: 0
>  InUseCount: 0
>  MaxCreationTime: 0
>  MaxUsedCount: 0
>  MaxWaitCount: 0
>  MaxWaitTime: 0
>  TimedOut: 0
>  TotalBlockingTime: 0
>  TotalCreationTime: 0
>17:31:21,181 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Using properties: {user=crashrec, password=--hidden--}
>17:31:21,181 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Checking driver for URL: jdbc:postgresql://localhost:5432/crashrec
>17:31:21,182 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Driver not yet registered for url: jdbc:postgresql://localhost:5432/crashrec
>17:31:21,183 DEBUG [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Driver loaded and instance created:org.postgresql.Driver@7834a169
>17:31:21,236 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 21) supplying new ManagedConnection: org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476681236 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:21,237 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 21) Got connection from pool: org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476681236 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:21,237 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (ServerService Thread Pool -- 21) No transaction, no need to enlist: org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476681236 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:21,241 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (ServerService Thread Pool -- 21) registering connection from connection manager: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl@3d04f647, connection : org.jboss.jca.adapters.jdbc.jdk6.WrappedConnectionJDK6@303a6c18, key: null
>17:31:21,241 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
>17:31:21,242 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
>17:31:21,242 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Owner: Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup]
>17:31:21,491 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
>17:31:21,491 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
>17:31:21,491 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Owner: Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup]
>17:31:21,497 INFO  [org.hibernate.dialect.Dialect] (ServerService Thread Pool -- 21) HHH000400: Using dialect: org.hibernate.dialect.PostgreSQL82Dialect
>17:31:21,503 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
>17:31:21,503 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
>17:31:21,503 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Owner: Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup]
>17:31:21,504 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
>17:31:21,505 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
>17:31:21,505 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Owner: Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup]
>17:31:21,505 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
>17:31:21,505 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Lock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
>17:31:21,506 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Owner: Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup]
>17:31:21,506 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 2, QueueLength: 0
>17:31:21,506 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Owner: Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup]
>17:31:21,507 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
>17:31:21,508 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Owner: Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup]
>17:31:21,508 INFO  [org.hibernate.engine.jdbc.internal.LobCreatorBuilder] (ServerService Thread Pool -- 21) HHH000424: Disabling contextual LOB creation as createClob() method threw error : java.lang.reflect.InvocationTargetException
>17:31:21,509 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (ServerService Thread Pool -- 21) connectionClosed called mc=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5
>17:31:21,509 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (ServerService Thread Pool -- 21) unregistering connection from connection manager: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl@3d04f647, connection: org.jboss.jca.adapters.jdbc.jdk6.WrappedConnectionJDK6@303a6c18, key: null
>17:31:21,509 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (ServerService Thread Pool -- 21) unregisterConnection: 0 handles left
>17:31:21,510 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (ServerService Thread Pool -- 21) delisting org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476681236 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:21,510 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (ServerService Thread Pool -- 21) delisted org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476681236 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:21,510 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (ServerService Thread Pool -- 21) isManagedConnectionFree=true mc=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5
>17:31:21,510 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 21) returnConnection(7d2614f3, false)
>ManagedConnectionPool: 236ea9f9
>Method: returnConnection(7d2614f3, false)
>ManagedConnectionFactory:
>  Class: org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory
>  Object: 46216f19
>ConnectionListenerFactory:
>  Class: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl
>  Object: 3d04f647
>Pool:
>  Name: ExampleDS
>PoolConfiguration:
>  MinSize: 0
>  MaxSize: 20
>  BlockingTimeout: 30000
>  IdleTimeoutMinutes: 30
>  BackgroundValidation: false
>  BackgroundValidationMillis: 0
>  StrictMin: false
>  UseFastFail: false
>Available (0):
>InUse (1):
>  7d2614f3 (NORMAL)
>Statistics:
>  ActiveCount: 0
>  AvailableCount: 0
>  AverageBlockingTime: 0
>  AverageCreationTime: 0
>  CreatedCount: 0
>  DestroyedCount: 0
>  InUseCount: 0
>  MaxCreationTime: 0
>  MaxUsedCount: 0
>  MaxWaitCount: 0
>  MaxWaitTime: 0
>  TimedOut: 0
>  TotalBlockingTime: 0
>  TotalCreationTime: 0
>17:31:21,510 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 21) Returning connection to pool org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476681510 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:21,583 INFO  [org.hibernate.engine.transaction.internal.TransactionFactoryInitiator] (ServerService Thread Pool -- 21) HHH000268: Transaction strategy: org.hibernate.engine.transaction.internal.jta.CMTTransactionFactory
>17:31:21,587 INFO  [org.hibernate.hql.internal.ast.ASTQueryTranslatorFactory] (ServerService Thread Pool -- 21) HHH000397: Using ASTQueryTranslatorFactory
>17:31:21,628 INFO  [org.hibernate.validator.internal.util.Version] (ServerService Thread Pool -- 21) HV000001: Hibernate Validator 4.3.1.Final-redhat-1
>17:31:21,904 INFO  [org.hibernate.tool.hbm2ddl.SchemaExport] (ServerService Thread Pool -- 21) HHH000227: Running hbm2ddl schema export
>17:31:21,905 TRACE [org.jboss.jca.core.connectionmanager.TxConnectionManager] (ServerService Thread Pool -- 21) Subject: null
>17:31:21,905 TRACE [org.jboss.jca.core.connectionmanager.TxConnectionManager] (ServerService Thread Pool -- 21) getManagedConnection interleaving=false , tx=null
>17:31:21,905 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 21) TransactionSynchronizationRegistryImple.getTransactionKey
>17:31:21,905 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 21) getConnection(null, WrappedConnectionRequestInfo@36592c9b[userName=crashrec])
>ManagedConnectionPool: 236ea9f9
>Method: getConnection(null, WrappedConnectionRequestInfo@36592c9b[userName=crashrec])
>ManagedConnectionFactory:
>  Class: org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory
>  Object: 46216f19
>ConnectionListenerFactory:
>  Class: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl
>  Object: 3d04f647
>Pool:
>  Name: ExampleDS
>PoolConfiguration:
>  MinSize: 0
>  MaxSize: 20
>  BlockingTimeout: 30000
>  IdleTimeoutMinutes: 30
>  BackgroundValidation: false
>  BackgroundValidationMillis: 0
>  StrictMin: false
>  UseFastFail: false
>Available (1):
>  7d2614f3 (NORMAL)
>InUse (0):
>Statistics:
>  ActiveCount: 0
>  AvailableCount: 0
>  AverageBlockingTime: 0
>  AverageCreationTime: 0
>  CreatedCount: 0
>  DestroyedCount: 0
>  InUseCount: 0
>  MaxCreationTime: 0
>  MaxUsedCount: 0
>  MaxWaitCount: 0
>  MaxWaitTime: 0
>  TimedOut: 0
>  TotalBlockingTime: 0
>  TotalCreationTime: 0
>17:31:21,906 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 21) supplying ManagedConnection from pool: org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476681510 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:21,906 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 21) Got connection from pool: org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476681510 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:21,906 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (ServerService Thread Pool -- 21) No transaction, no need to enlist: org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476681510 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:21,906 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (ServerService Thread Pool -- 21) registering connection from connection manager: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl@3d04f647, connection : org.jboss.jca.adapters.jdbc.jdk6.WrappedConnectionJDK6@38a9ade0, key: null
>17:31:21,906 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
>17:31:21,906 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
>17:31:21,906 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Owner: Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup]
>17:31:21,906 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
>17:31:21,909 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
>17:31:21,909 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Owner: Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup]
>17:31:21,909 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
>17:31:21,910 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
>17:31:21,910 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Owner: Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup]
>17:31:21,910 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
>17:31:21,910 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
>17:31:21,910 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Owner: Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup]
>17:31:21,911 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
>17:31:21,911 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
>17:31:21,911 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Owner: Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup]
>17:31:21,911 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
>17:31:21,911 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
>17:31:21,911 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Owner: Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup]
>17:31:21,911 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
>17:31:22,220 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
>17:31:22,220 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Owner: Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup]
>17:31:22,220 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
>17:31:22,221 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
>17:31:22,221 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Owner: Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup]
>17:31:22,221 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
>17:31:22,221 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
>17:31:22,221 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Owner: Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup]
>17:31:22,221 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
>17:31:22,221 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
>17:31:22,221 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Owner: Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup]
>17:31:22,221 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (ServerService Thread Pool -- 21) connectionClosed called mc=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5
>17:31:22,222 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (ServerService Thread Pool -- 21) unregistering connection from connection manager: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl@3d04f647, connection: org.jboss.jca.adapters.jdbc.jdk6.WrappedConnectionJDK6@38a9ade0, key: null
>17:31:22,222 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (ServerService Thread Pool -- 21) unregisterConnection: 0 handles left
>17:31:22,222 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (ServerService Thread Pool -- 21) delisting org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476681510 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:22,222 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (ServerService Thread Pool -- 21) delisted org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476681510 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:22,222 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (ServerService Thread Pool -- 21) isManagedConnectionFree=true mc=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5
>17:31:22,222 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 21) returnConnection(7d2614f3, false)
>ManagedConnectionPool: 236ea9f9
>Method: returnConnection(7d2614f3, false)
>ManagedConnectionFactory:
>  Class: org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory
>  Object: 46216f19
>ConnectionListenerFactory:
>  Class: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl
>  Object: 3d04f647
>Pool:
>  Name: ExampleDS
>PoolConfiguration:
>  MinSize: 0
>  MaxSize: 20
>  BlockingTimeout: 30000
>  IdleTimeoutMinutes: 30
>  BackgroundValidation: false
>  BackgroundValidationMillis: 0
>  StrictMin: false
>  UseFastFail: false
>Available (0):
>InUse (1):
>  7d2614f3 (NORMAL)
>Statistics:
>  ActiveCount: 0
>  AvailableCount: 0
>  AverageBlockingTime: 0
>  AverageCreationTime: 0
>  CreatedCount: 0
>  DestroyedCount: 0
>  InUseCount: 0
>  MaxCreationTime: 0
>  MaxUsedCount: 0
>  MaxWaitCount: 0
>  MaxWaitTime: 0
>  TimedOut: 0
>  TotalBlockingTime: 0
>  TotalCreationTime: 0
>17:31:22,222 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 21) Returning connection to pool org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476682222 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:22,222 INFO  [org.hibernate.tool.hbm2ddl.SchemaExport] (ServerService Thread Pool -- 21) HHH000230: Schema export complete
>17:31:22,388 INFO  [org.jboss.as.server] (management-handler-thread - 2) JBAS018559: Deployed "ejb-remote-client-api-usertx-test.ear" (runtime-name : "ejb-remote-client-api-usertx-test.ear")
>17:31:22,699 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (EJB default - 1) new stack for key: org.jboss.as.connector.deployers.ra.processors.CachedConnectionManagerSetupProcessor$CachedConnectionManagerSetupAction@10cd3ba4
>17:31:22,700 TRACE [com.arjuna.ats.jta] (EJB default - 1) BaseTransaction.begin
>17:31:22,701 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) StateManager::StateManager( 2, 0 )
>17:31:22,701 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::BasicAction()
>17:31:22,701 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::Begin() for action-id 0:ffff7f000001:67f9ad09:536a51c3:d
>17:31:22,701 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::actionInitialise() for action-id 0:ffff7f000001:67f9ad09:536a51c3:d
>17:31:22,702 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ActionHierarchy::ActionHierarchy(5)
>17:31:22,702 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ActionHierarchy::add(0:ffff7f000001:67f9ad09:536a51c3:d, 1)
>17:31:22,702 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::addChildThread () action 0:ffff7f000001:67f9ad09:536a51c3:d adding Thread[EJB default - 1,5,EJB default]
>17:31:22,703 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::addChildThread () action 0:ffff7f000001:67f9ad09:536a51c3:d adding Thread[EJB default - 1,5,EJB default] result = true
>17:31:22,703 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:d status: ActionStatus.RUNNING, 300 )
>17:31:22,703 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:d status: ActionStatus.RUNNING, 300 )
>17:31:22,703 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) ReaperThread.run ()
>17:31:22,704 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) TransactionReaper::check ()
>17:31:22,704 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) TransactionReaper::check - comparing 1399476982703
>17:31:22,704 TRACE [com.arjuna.ats.arjuna] (Transaction Reaper) Thread Thread[Transaction Reaper,5,main] sleeping for 299999
>17:31:22,704 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (EJB default - 1) user tx started, key: org.jboss.as.connector.deployers.ra.processors.CachedConnectionManagerSetupProcessor$CachedConnectionManagerSetupAction@10cd3ba4
>17:31:22,706 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImpleManager.suspend
>17:31:22,706 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::removeChildThread () action 0:ffff7f000001:67f9ad09:536a51c3:d removing TSThread:1
>17:31:22,706 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::removeChildThread () action 0:ffff7f000001:67f9ad09:536a51c3:d removing TSThread:1 result = true
>17:31:22,706 TRACE [com.arjuna.ats.jta] (EJB default - 1) BaseTransaction.begin
>17:31:22,706 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) StateManager::StateManager( 2, 0 )
>17:31:22,706 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::BasicAction()
>17:31:22,706 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::Begin() for action-id 0:ffff7f000001:67f9ad09:536a51c3:e
>17:31:22,706 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::actionInitialise() for action-id 0:ffff7f000001:67f9ad09:536a51c3:e
>17:31:22,706 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ActionHierarchy::ActionHierarchy(5)
>17:31:22,706 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ActionHierarchy::add(0:ffff7f000001:67f9ad09:536a51c3:e, 1)
>17:31:22,707 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::addChildThread () action 0:ffff7f000001:67f9ad09:536a51c3:e adding Thread[EJB default - 1,5,EJB default]
>17:31:22,707 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::addChildThread () action 0:ffff7f000001:67f9ad09:536a51c3:e adding Thread[EJB default - 1,5,EJB default] result = true
>17:31:22,707 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:e status: ActionStatus.RUNNING, 300 )
>17:31:22,707 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:e status: ActionStatus.RUNNING, 300 )
>17:31:22,710 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,710 TRACE [com.arjuna.ats.jta] (EJB default - 1) BaseTransaction.commit
>17:31:22,710 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.commitAndDisassociate
>17:31:22,710 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::End() for action-id 0:ffff7f000001:67f9ad09:536a51c3:e
>17:31:22,711 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::End() result for action-id (0:ffff7f000001:67f9ad09:536a51c3:e) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)
>17:31:22,711 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::removeChildThread () action 0:ffff7f000001:67f9ad09:536a51c3:e removing TSThread:1
>17:31:22,711 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::removeChildThread () action 0:ffff7f000001:67f9ad09:536a51c3:e removing TSThread:1 result = true
>17:31:22,711 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:e status: ActionStatus.COMMITTED )
>17:31:22,711 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImpleManager.resume
>17:31:22,711 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::addChildThread () action 0:ffff7f000001:67f9ad09:536a51c3:d adding Thread[EJB default - 1,5,EJB default]
>17:31:22,711 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::addChildThread () action 0:ffff7f000001:67f9ad09:536a51c3:d adding Thread[EJB default - 1,5,EJB default] result = true
>17:31:22,712 INFO  [org.jboss.as.test.integration.ejb.remote.client.api.tx.BatchCreationBean] (EJB default - 1) Persisting new batch Simple Batch
>17:31:22,713 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,713 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,713 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionSynchronizationRegistryImple.getResource
>17:31:22,713 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,742 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,743 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionSynchronizationRegistryImple.getRollbackOnly
>17:31:22,743 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,743 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,743 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,745 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionSynchronizationRegistryImple.registerInterposedSynchronization
>17:31:22,745 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,745 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,745 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,747 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionSynchronizationRegistryImple.registerInterposedSynchronization
>17:31:22,748 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,748 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionSynchronizationRegistryImple.putResource
>17:31:22,748 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,752 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,759 TRACE [com.arjuna.ats.jta] (EJB default - 1) TransactionImpleManager.suspend
>17:31:22,759 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::removeChildThread () action 0:ffff7f000001:67f9ad09:536a51c3:d removing TSThread:1
>17:31:22,759 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) BasicAction::removeChildThread () action 0:ffff7f000001:67f9ad09:536a51c3:d removing TSThread:1 result = true
>17:31:22,759 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (EJB default - 1) popped object: org.jboss.as.connector.deployers.ra.processors.CachedConnectionManagerSetupProcessor$CachedConnectionManagerSetupAction@10cd3ba4
>17:31:22,811 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImpleManager.resume
>17:31:22,811 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::addChildThread () action 0:ffff7f000001:67f9ad09:536a51c3:d adding Thread[EJB default - 2,5,EJB default]
>17:31:22,812 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::addChildThread () action 0:ffff7f000001:67f9ad09:536a51c3:d adding Thread[EJB default - 2,5,EJB default] result = true
>17:31:22,812 TRACE [com.arjuna.ats.jta] (EJB default - 2) BaseTransaction.commit
>17:31:22,813 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImple.commitAndDisassociate
>17:31:22,813 TRACE [com.arjuna.ats.jta] (EJB default - 2) SynchronizationImple.beforeCompletion
>17:31:22,813 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,827 TRACE [org.jboss.jca.core.connectionmanager.TxConnectionManager] (EJB default - 2) Subject: null
>17:31:22,827 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,827 TRACE [org.jboss.jca.core.connectionmanager.TxConnectionManager] (EJB default - 2) getManagedConnection interleaving=false , tx=TransactionImple < ac, BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:d status: ActionStatus.RUNNING >
>17:31:22,827 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionSynchronizationRegistryImple.getTransactionKey
>17:31:22,827 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionSynchronizationRegistryImple.getTransactionKey
>17:31:22,828 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionSynchronizationRegistryImple.getResource
>17:31:22,828 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,828 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionSynchronizationRegistryImple.getTransactionKey
>17:31:22,828 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionSynchronizationRegistryImple.getResource
>17:31:22,828 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,828 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionSynchronizationRegistryImple.putResource
>17:31:22,828 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,828 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionSynchronizationRegistryImple.getResource
>17:31:22,828 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,828 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (EJB default - 2) getConnection(null, WrappedConnectionRequestInfo@36592c9b[userName=crashrec])
>ManagedConnectionPool: 236ea9f9
>Method: getConnection(null, WrappedConnectionRequestInfo@36592c9b[userName=crashrec])
>ManagedConnectionFactory:
>  Class: org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory
>  Object: 46216f19
>ConnectionListenerFactory:
>  Class: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl
>  Object: 3d04f647
>Pool:
>  Name: ExampleDS
>PoolConfiguration:
>  MinSize: 0
>  MaxSize: 20
>  BlockingTimeout: 30000
>  IdleTimeoutMinutes: 30
>  BackgroundValidation: false
>  BackgroundValidationMillis: 0
>  StrictMin: false
>  UseFastFail: false
>Available (1):
>  7d2614f3 (NORMAL)
>InUse (0):
>Statistics:
>  ActiveCount: 0
>  AvailableCount: 0
>  AverageBlockingTime: 0
>  AverageCreationTime: 0
>  CreatedCount: 0
>  DestroyedCount: 0
>  InUseCount: 0
>  MaxCreationTime: 0
>  MaxUsedCount: 0
>  MaxWaitCount: 0
>  MaxWaitTime: 0
>  TimedOut: 0
>  TotalBlockingTime: 0
>  TotalCreationTime: 0
>17:31:22,829 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (EJB default - 2) supplying ManagedConnection from pool: org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476682222 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:22,829 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (EJB default - 2) Got connection from pool tracked by transaction=org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476682222 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null] tx=TransactionImple < ac, BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:d status: ActionStatus.RUNNING >
>17:31:22,829 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionSynchronizationRegistryImple.getTransactionKey
>17:31:22,829 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionSynchronizationRegistryImple.getResource
>17:31:22,829 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,829 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionSynchronizationRegistryImple.getResource
>17:31:22,829 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,829 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionSynchronizationRegistryImple.putResource
>17:31:22,829 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,829 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (EJB default - 2) Using connection from pool tracked by transaction=org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476682222 trackByTx=true pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null] tx=TransactionImple < ac, BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:d status: ActionStatus.RUNNING >
>17:31:22,829 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,829 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (EJB default - 2) Pre-enlist: org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476682222 trackByTx=true pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null] threadTx=TransactionImple < ac, BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:d status: ActionStatus.RUNNING >
>17:31:22,831 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionSynchronizationRegistryImple.registerInterposedSynchronization
>17:31:22,831 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,831 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (EJB default - 2) Get synchronizer org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476682222 trackByTx=true pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null] threadTx=TransactionImple < ac, BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:d status: ActionStatus.RUNNING >
>17:31:22,832 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (EJB default - 2) Enlisting resource org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476682222 trackByTx=true pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=TxSync@1262352757{tx=TransactionImple < ac, BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:d status: ActionStatus.RUNNING > wasTrackByTx=true enlisted=false}]
>17:31:22,832 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImple.enlistResource ( LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] )
>17:31:22,832 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,832 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) InputObjectState::InputObjectState()
>17:31:22,832 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) FileSystemStore.allObjUids(EISNAME, InputObjectState Uid   : 0:0:0:0:0
>InputObjectState Type  : null
>InputObjectState Size  : 0
>InputObjectState Buffer: , -1)
>17:31:22,832 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) OutputObjectState::OutputObjectState()
>17:31:22,833 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) FileSystemStore.read_committed(0:ffff7f000001:1258154c:536a3d63:1c, EISNAME)
>17:31:22,833 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) ShadowingStore.read_state(0:ffff7f000001:1258154c:536a3d63:1c, EISNAME, StateType.OS_ORIGINAL)
>17:31:22,833 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) ShadowingStore.genPathName(0:ffff7f000001:1258154c:536a3d63:1c, EISNAME, StateType.OS_SHADOW)
>17:31:22,833 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) FileSystemStore.genPathName(0:ffff7f000001:1258154c:536a3d63:1c, EISNAME, 10)
>17:31:22,833 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) ShadowingStore.genPathName(0:ffff7f000001:1258154c:536a3d63:1c, EISNAME, StateType.OS_ORIGINAL)
>17:31:22,833 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) FileSystemStore.genPathName(0:ffff7f000001:1258154c:536a3d63:1c, EISNAME, 11)
>17:31:22,833 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) ShadowingStore.currentState(0:ffff7f000001:1258154c:536a3d63:1c, EISNAME) - returning StateStatus.OS_COMMITTED
>17:31:22,833 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) ShadowingStore.genPathName(0:ffff7f000001:1258154c:536a3d63:1c, EISNAME, StateType.OS_ORIGINAL)
>17:31:22,833 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) FileSystemStore.genPathName(0:ffff7f000001:1258154c:536a3d63:1c, EISNAME, 11)
>17:31:22,834 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) FileSystemStore.openAndLock(/home/ochaloup/tmp/jbossas-testsuite-cmr/jboss-eap-6.3-src/testsuite/integration/basic/target/jbossas/standalone/data/tx-object-store/ShadowNoFileLockStore/defaultStore/EISNAME/0_ffff7f000001_1258154c_536a3d63_1c, FileLock.F_RDLCK, false)
>17:31:22,834 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) InputObjectState::InputObjectState(0:ffff7f000001:1258154c:536a3d63:1c, EISNAME)
>17:31:22,834 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) FileSystemStore.closeAndUnlock(/home/ochaloup/tmp/jbossas-testsuite-cmr/jboss-eap-6.3-src/testsuite/integration/basic/target/jbossas/standalone/data/tx-object-store/ShadowNoFileLockStore/defaultStore/EISNAME/0_ffff7f000001_1258154c_536a3d63_1c, java.io.FileInputStream@759f41f1, null)
>17:31:22,836 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) StateManager::StateManager( 1, 0 )
>17:31:22,836 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) AbstractRecord::AbstractRecord (0:ffff7f000001:67f9ad09:536a51c3:14, 1)
>17:31:22,837 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) CommitMarkableResourceRecord.CommitMarkableResourceRecord ( TransactionImple < ac, BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:d status: ActionStatus.RUNNING >, LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS], < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:67f9ad09:536a51c3:d, node_name=1, branch_uid=0:ffff7f000001:67f9ad09:536a51c3:13, subordinatenodename=null, eis_name=java:jboss/datasources/ExampleDS >, BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:d status: ActionStatus.RUNNING ), record id=-80000000:-80000000:-80000000:-80000000:-80000000
>17:31:22,837 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImple.registerSynchronization
>17:31:22,837 WARN  [com.arjuna.ats.arjuna] (EJB default - 2) Could not register synchronization for CommitMarkableResourceRecord: java.lang.IllegalStateException: ARJUNA016082: Synchronizations are not allowed! Transaction status isActionStatus.RUNNING
>	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.registerSynchronizationImple(TransactionImple.java:384)
>	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.registerSynchronization(TransactionImple.java:361)
>	at com.arjuna.ats.internal.jta.resources.arjunacore.CommitMarkableResourceRecord.<init>(CommitMarkableResourceRecord.java:262)
>	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.createRecord(TransactionImple.java:784)
>	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(TransactionImple.java:644)
>	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(TransactionImple.java:407)
>	at org.jboss.jca.core.connectionmanager.listener.TxConnectionListener$TransactionSynchronization.enlist(TxConnectionListener.java:692)
>	at org.jboss.jca.core.connectionmanager.listener.TxConnectionListener.enlist(TxConnectionListener.java:338)
>	at org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.managedConnectionReconnected(TxConnectionManagerImpl.java:483)
>	at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.reconnectManagedConnection(AbstractConnectionManager.java:623)
>	at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:491)
>	at org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:143)
>	at org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider.getConnection(InjectedDataSourceConnectionProvider.java:70)
>	at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:301)
>	at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:214)
>	at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.getConnection(LogicalConnectionImpl.java:157)
>	at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:56)
>	at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$1.doPrepare(StatementPreparerImpl.java:96)
>	at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:183)
>	at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareStatement(StatementPreparerImpl.java:89)
>	at org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.buildBatchStatement(AbstractBatchImpl.java:146)
>	at org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.getBatchStatement(AbstractBatchImpl.java:135)
>	at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3057)
>	at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3521)
>	at org.hibernate.action.internal.EntityInsertAction.execute(EntityInsertAction.java:88)
>	at org.hibernate.engine.spi.ActionQueue.execute(ActionQueue.java:395)
>	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:387)
>	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:303)
>	at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:349)
>	at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:56)
>	at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1159)
>	at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:404)
>	at org.hibernate.engine.transaction.synchronization.internal.SynchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:105)
>	at org.hibernate.engine.transaction.synchronization.internal.RegisteredSynchronization.beforeCompletion(RegisteredSynchronization.java:53)
>	at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:76)
>	at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:273)
>	at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:93)
>	at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
>	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1189)
>	at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
>	at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
>	at org.jboss.as.ejb3.remote.protocol.versionone.UserTransactionCommitTask.manageTransaction(UserTransactionCommitTask.java:48)
>	at org.jboss.as.ejb3.remote.protocol.versionone.UserTransactionManagementTask.run(UserTransactionManagementTask.java:61)
>	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0_51]
>	at java.util.concurrent.FutureTask.run(FutureTask.java:262) [rt.jar:1.7.0_51]
>	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]
>	at org.jboss.threads.JBossThread.run(JBossThread.java:122) [jboss-threads-2.1.1.Final-redhat-1.jar:2.1.1.Final-redhat-1]
>
>17:31:22,844 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImple.setRollbackOnly
>17:31:22,844 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::preventCommit( BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:d status: ActionStatus.RUNNING)
>17:31:22,844 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (EJB default - 2) Failed to enlist resource org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476682222 trackByTx=true pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=TxSync@1262352757{tx=TransactionImple < ac, BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:d status: ActionStatus.ABORT_ONLY > wasTrackByTx=true enlisted=false}]: java.lang.Throwable: Unabled to enlist resource, see the previous warnings.
>	at org.jboss.jca.core.connectionmanager.listener.TxConnectionListener$TransactionSynchronization.<init>(TxConnectionListener.java:630)
>	at org.jboss.jca.core.connectionmanager.listener.TxConnectionListener.enlist(TxConnectionListener.java:316)
>	at org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.managedConnectionReconnected(TxConnectionManagerImpl.java:483)
>	at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.reconnectManagedConnection(AbstractConnectionManager.java:623)
>	at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:491)
>	at org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:143)
>	at org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider.getConnection(InjectedDataSourceConnectionProvider.java:70)
>	at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:301)
>	at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:214)
>	at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.getConnection(LogicalConnectionImpl.java:157)
>	at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:56)
>	at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$1.doPrepare(StatementPreparerImpl.java:96)
>	at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:183)
>	at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareStatement(StatementPreparerImpl.java:89)
>	at org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.buildBatchStatement(AbstractBatchImpl.java:146)
>	at org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.getBatchStatement(AbstractBatchImpl.java:135)
>	at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3057)
>	at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3521)
>	at org.hibernate.action.internal.EntityInsertAction.execute(EntityInsertAction.java:88)
>	at org.hibernate.engine.spi.ActionQueue.execute(ActionQueue.java:395)
>	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:387)
>	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:303)
>	at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:349)
>	at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:56)
>	at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1159)
>	at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:404)
>	at org.hibernate.engine.transaction.synchronization.internal.SynchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:105)
>	at org.hibernate.engine.transaction.synchronization.internal.RegisteredSynchronization.beforeCompletion(RegisteredSynchronization.java:53)
>	at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:76)
>	at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:273)
>	at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:93)
>	at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
>	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1189)
>	at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
>	at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
>	at org.jboss.as.ejb3.remote.protocol.versionone.UserTransactionCommitTask.manageTransaction(UserTransactionCommitTask.java:48)
>	at org.jboss.as.ejb3.remote.protocol.versionone.UserTransactionManagementTask.run(UserTransactionManagementTask.java:61)
>	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0_51]
>	at java.util.concurrent.FutureTask.run(FutureTask.java:262) [rt.jar:1.7.0_51]
>	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]
>	at org.jboss.threads.JBossThread.run(JBossThread.java:122) [jboss-threads-2.1.1.Final-redhat-1.jar:2.1.1.Final-redhat-1]
>
>17:31:22,847 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (EJB default - 2) Check enlisted org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476682222 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null] threadTx=TransactionImple < ac, BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:d status: ActionStatus.ABORT_ONLY >
>17:31:22,847 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (EJB default - 2) Error enlisting resource in transaction=TransactionImple < ac, BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:d status: ActionStatus.ABORT_ONLY > org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476682222 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:22,848 TRACE [org.jboss.jca.core.connectionmanager.TxConnectionManager] (EJB default - 2) Could not enlist in transaction on entering meta-aware object! org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476682222 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]: javax.transaction.SystemException: IJ000356: Failed to enlist: java.lang.Throwable: Unabled to enlist resource, see the previous warnings. tx=TransactionImple < ac, BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:d status: ActionStatus.ABORT_ONLY >
>	at org.jboss.jca.core.connectionmanager.listener.TxConnectionListener$TransactionSynchronization.checkEnlisted(TxConnectionListener.java:657)
>	at org.jboss.jca.core.connectionmanager.listener.TxConnectionListener.enlist(TxConnectionListener.java:356)
>	at org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.managedConnectionReconnected(TxConnectionManagerImpl.java:483)
>	at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.reconnectManagedConnection(AbstractConnectionManager.java:623)
>	at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:491)
>	at org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:143)
>	at org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider.getConnection(InjectedDataSourceConnectionProvider.java:70)
>	at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:301)
>	at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:214)
>	at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.getConnection(LogicalConnectionImpl.java:157)
>	at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:56)
>	at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$1.doPrepare(StatementPreparerImpl.java:96)
>	at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:183)
>	at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareStatement(StatementPreparerImpl.java:89)
>	at org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.buildBatchStatement(AbstractBatchImpl.java:146)
>	at org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.getBatchStatement(AbstractBatchImpl.java:135)
>	at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3057)
>	at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3521)
>	at org.hibernate.action.internal.EntityInsertAction.execute(EntityInsertAction.java:88)
>	at org.hibernate.engine.spi.ActionQueue.execute(ActionQueue.java:395)
>	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:387)
>	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:303)
>	at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:349)
>	at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:56)
>	at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1159)
>	at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:404)
>	at org.hibernate.engine.transaction.synchronization.internal.SynchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:105)
>	at org.hibernate.engine.transaction.synchronization.internal.RegisteredSynchronization.beforeCompletion(RegisteredSynchronization.java:53)
>	at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:76)
>	at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:273)
>	at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:93)
>	at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
>	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1189)
>	at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
>	at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
>	at org.jboss.as.ejb3.remote.protocol.versionone.UserTransactionCommitTask.manageTransaction(UserTransactionCommitTask.java:48)
>	at org.jboss.as.ejb3.remote.protocol.versionone.UserTransactionManagementTask.run(UserTransactionManagementTask.java:61)
>	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0_51]
>	at java.util.concurrent.FutureTask.run(FutureTask.java:262) [rt.jar:1.7.0_51]
>	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]
>	at org.jboss.threads.JBossThread.run(JBossThread.java:122) [jboss-threads-2.1.1.Final-redhat-1.jar:2.1.1.Final-redhat-1]
>
>17:31:22,851 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (EJB default - 2) delisting org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476682222 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:22,851 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (EJB default - 2) delisted org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476682222 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:22,851 TRACE [org.jboss.jca.core.connectionmanager.TxConnectionManager] (EJB default - 2) Disconnected isManagedConnectionFree=true cl=org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476682222 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:22,852 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (EJB default - 2) returnConnection(7d2614f3, false)
>ManagedConnectionPool: 236ea9f9
>Method: returnConnection(7d2614f3, false)
>ManagedConnectionFactory:
>  Class: org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory
>  Object: 46216f19
>ConnectionListenerFactory:
>  Class: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl
>  Object: 3d04f647
>Pool:
>  Name: ExampleDS
>PoolConfiguration:
>  MinSize: 0
>  MaxSize: 20
>  BlockingTimeout: 30000
>  IdleTimeoutMinutes: 30
>  BackgroundValidation: false
>  BackgroundValidationMillis: 0
>  StrictMin: false
>  UseFastFail: false
>Available (0):
>InUse (1):
>  7d2614f3 (NORMAL)
>Statistics:
>  ActiveCount: 0
>  AvailableCount: 0
>  AverageBlockingTime: 0
>  AverageCreationTime: 0
>  CreatedCount: 0
>  DestroyedCount: 0
>  InUseCount: 0
>  MaxCreationTime: 0
>  MaxUsedCount: 0
>  MaxWaitCount: 0
>  MaxWaitTime: 0
>  TimedOut: 0
>  TotalBlockingTime: 0
>  TotalCreationTime: 0
>17:31:22,852 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (EJB default - 2) Returning connection to pool org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476682852 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:22,852 WARN  [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (EJB default - 2) SQL Error: 0, SQLState: null
>17:31:22,852 ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (EJB default - 2) javax.resource.ResourceException: IJ000457: Unchecked throwable in managedConnectionReconnected() cl=org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476682852 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:22,854 TRACE [com.arjuna.ats.jta] (EJB default - 2) BaseTransaction.setRollbackOnly
>17:31:22,854 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImple.setRollbackOnly
>17:31:22,854 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::preventCommit( BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:d status: ActionStatus.ABORT_ONLY)
>17:31:22,855 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImple.getStatus: javax.transaction.Status.STATUS_MARKED_ROLLBACK
>17:31:22,855 TRACE [com.arjuna.ats.jta] (EJB default - 2) BaseTransaction.setRollbackOnly
>17:31:22,855 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImple.setRollbackOnly
>17:31:22,855 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::preventCommit( BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:d status: ActionStatus.ABORT_ONLY)
>17:31:22,855 WARN  [com.arjuna.ats.arjuna] (EJB default - 2) ARJUNA012125: TwoPhaseCoordinator.beforeCompletion - failed for SynchronizationImple< 0:ffff7f000001:67f9ad09:536a51c3:f, org.hibernate.engine.transaction.synchronization.internal.RegisteredSynchronization@7cf99a4d >: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: Could not open connection
>	at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1387)
>	at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1310)
>	at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1316)
>	at org.hibernate.ejb.AbstractEntityManagerImpl$CallbackExceptionMapperImpl.mapManagedFlushFailure(AbstractEntityManagerImpl.java:1510)
>	at org.hibernate.engine.transaction.synchronization.internal.SynchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:110)
>	at org.hibernate.engine.transaction.synchronization.internal.RegisteredSynchronization.beforeCompletion(RegisteredSynchronization.java:53)
>	at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:76)
>	at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:273)
>	at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:93)
>	at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
>	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1189)
>	at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
>	at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
>	at org.jboss.as.ejb3.remote.protocol.versionone.UserTransactionCommitTask.manageTransaction(UserTransactionCommitTask.java:48)
>	at org.jboss.as.ejb3.remote.protocol.versionone.UserTransactionManagementTask.run(UserTransactionManagementTask.java:61)
>	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0_51]
>	at java.util.concurrent.FutureTask.run(FutureTask.java:262) [rt.jar:1.7.0_51]
>	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]
>	at org.jboss.threads.JBossThread.run(JBossThread.java:122) [jboss-threads-2.1.1.Final-redhat-1.jar:2.1.1.Final-redhat-1]
>Caused by: org.hibernate.exception.GenericJDBCException: Could not open connection
>	at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:54)
>	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:124)
>	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:109)
>	at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:221)
>	at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.getConnection(LogicalConnectionImpl.java:157)
>	at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:56)
>	at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$1.doPrepare(StatementPreparerImpl.java:96)
>	at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:183)
>	at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareStatement(StatementPreparerImpl.java:89)
>	at org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.buildBatchStatement(AbstractBatchImpl.java:146)
>	at org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.getBatchStatement(AbstractBatchImpl.java:135)
>	at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3057)
>	at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3521)
>	at org.hibernate.action.internal.EntityInsertAction.execute(EntityInsertAction.java:88)
>	at org.hibernate.engine.spi.ActionQueue.execute(ActionQueue.java:395)
>	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:387)
>	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:303)
>	at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:349)
>	at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:56)
>	at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1159)
>	at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:404)
>	at org.hibernate.engine.transaction.synchronization.internal.SynchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:105)
>	... 16 more
>Caused by: java.sql.SQLException: javax.resource.ResourceException: IJ000457: Unchecked throwable in managedConnectionReconnected() cl=org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476682852 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>	at org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:151)
>	at org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider.getConnection(InjectedDataSourceConnectionProvider.java:70)
>	at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:301)
>	at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:214)
>	... 34 more
>Caused by: javax.resource.ResourceException: IJ000457: Unchecked throwable in managedConnectionReconnected() cl=org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476682852 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>	at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.reconnectManagedConnection(AbstractConnectionManager.java:628)
>	at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:491)
>	at org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:143)
>	... 37 more
>Caused by: javax.resource.ResourceException: IJ000461: Could not enlist in transaction on entering meta-aware object
>	at org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.managedConnectionReconnected(TxConnectionManagerImpl.java:490)
>	at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.reconnectManagedConnection(AbstractConnectionManager.java:623)
>	... 39 more
>Caused by: javax.transaction.SystemException: IJ000356: Failed to enlist: java.lang.Throwable: Unabled to enlist resource, see the previous warnings. tx=TransactionImple < ac, BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:d status: ActionStatus.ABORT_ONLY >
>	at org.jboss.jca.core.connectionmanager.listener.TxConnectionListener$TransactionSynchronization.checkEnlisted(TxConnectionListener.java:657)
>	at org.jboss.jca.core.connectionmanager.listener.TxConnectionListener.enlist(TxConnectionListener.java:356)
>	at org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.managedConnectionReconnected(TxConnectionManagerImpl.java:483)
>	... 40 more
>
>17:31:22,869 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::preventCommit( BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:d status: ActionStatus.ABORT_ONLY)
>17:31:22,870 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::Abort() for action-id 0:ffff7f000001:67f9ad09:536a51c3:d
>17:31:22,870 TRACE [com.arjuna.ats.jta] (EJB default - 2) SynchronizationImple.afterCompletion
>17:31:22,870 TRACE [com.arjuna.ats.jta] (EJB default - 2) SynchronizationImple.afterCompletion
>17:31:22,870 TRACE [com.arjuna.ats.jta] (EJB default - 2) TransactionImple.getStatus: javax.transaction.Status.STATUS_ROLLEDBACK
>17:31:22,872 TRACE [com.arjuna.ats.jta] (EJB default - 2) SynchronizationImple.afterCompletion
>17:31:22,872 WARN  [org.hibernate.engine.transaction.synchronization.internal.SynchronizationCallbackCoordinatorTrackingImpl] (EJB default - 2) HHH000451: Transaction afterCompletion called by a background thread; delaying afterCompletion processing until the original thread can handle it. [status=4]
>17:31:22,873 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::removeChildThread () action 0:ffff7f000001:67f9ad09:536a51c3:d removing TSThread:2
>17:31:22,873 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) BasicAction::removeChildThread () action 0:ffff7f000001:67f9ad09:536a51c3:d removing TSThread:2 result = true
>17:31:22,873 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:d status: ActionStatus.ABORTED )
>17:31:22,954 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 21) BaseTransaction.begin
>17:31:22,955 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 21) StateManager::StateManager( 2, 0 )
>17:31:22,955 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 21) BasicAction::BasicAction()
>17:31:22,955 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 21) BasicAction::Begin() for action-id 0:ffff7f000001:67f9ad09:536a51c3:17
>17:31:22,955 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 21) BasicAction::actionInitialise() for action-id 0:ffff7f000001:67f9ad09:536a51c3:17
>17:31:22,955 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 21) ActionHierarchy::ActionHierarchy(5)
>17:31:22,955 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 21) ActionHierarchy::add(0:ffff7f000001:67f9ad09:536a51c3:17, 1)
>17:31:22,955 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 21) BasicAction::addChildThread () action 0:ffff7f000001:67f9ad09:536a51c3:17 adding Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup]
>17:31:22,955 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 21) BasicAction::addChildThread () action 0:ffff7f000001:67f9ad09:536a51c3:17 adding Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup] result = true
>17:31:22,955 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 21) TransactionReaper::insert ( BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:17 status: ActionStatus.RUNNING, 300 )
>17:31:22,955 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 21) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:17 status: ActionStatus.RUNNING, 300 )
>17:31:22,956 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 21) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
>17:31:22,956 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 21) BaseTransaction.commit
>17:31:22,956 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 21) TransactionImple.commitAndDisassociate
>17:31:22,956 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 21) BasicAction::End() for action-id 0:ffff7f000001:67f9ad09:536a51c3:17
>17:31:22,956 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 21) BasicAction::End() result for action-id (0:ffff7f000001:67f9ad09:536a51c3:17) is (TwoPhaseOutcome.PREPARE_OK) node id: (1)
>17:31:22,956 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 21) BasicAction::removeChildThread () action 0:ffff7f000001:67f9ad09:536a51c3:17 removing TSThread:3
>17:31:22,956 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 21) BasicAction::removeChildThread () action 0:ffff7f000001:67f9ad09:536a51c3:17 removing TSThread:3 result = true
>17:31:22,956 TRACE [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 21) TransactionReaper::remove ( BasicAction: 0:ffff7f000001:67f9ad09:536a51c3:17 status: ActionStatus.COMMITTED )
>17:31:22,961 INFO  [org.jboss.as.jpa] (ServerService Thread Pool -- 21) JBAS011403: Stopping Persistence Unit Service 'ejb-remote-client-api-usertx-test.ear/ejb.jar#ejb-client-tx-pu'
>17:31:22,961 INFO  [org.hibernate.tool.hbm2ddl.SchemaExport] (ServerService Thread Pool -- 21) HHH000227: Running hbm2ddl schema export
>17:31:22,962 TRACE [org.jboss.jca.core.connectionmanager.TxConnectionManager] (ServerService Thread Pool -- 21) Subject: null
>17:31:22,962 TRACE [org.jboss.jca.core.connectionmanager.TxConnectionManager] (ServerService Thread Pool -- 21) getManagedConnection interleaving=false , tx=null
>17:31:22,962 TRACE [com.arjuna.ats.jta] (ServerService Thread Pool -- 21) TransactionSynchronizationRegistryImple.getTransactionKey
>17:31:22,963 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 21) getConnection(null, WrappedConnectionRequestInfo@36592c9b[userName=crashrec])
>ManagedConnectionPool: 236ea9f9
>Method: getConnection(null, WrappedConnectionRequestInfo@36592c9b[userName=crashrec])
>ManagedConnectionFactory:
>  Class: org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory
>  Object: 46216f19
>ConnectionListenerFactory:
>  Class: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl
>  Object: 3d04f647
>Pool:
>  Name: ExampleDS
>PoolConfiguration:
>  MinSize: 0
>  MaxSize: 20
>  BlockingTimeout: 30000
>  IdleTimeoutMinutes: 30
>  BackgroundValidation: false
>  BackgroundValidationMillis: 0
>  StrictMin: false
>  UseFastFail: false
>Available (1):
>  7d2614f3 (NORMAL)
>InUse (0):
>Statistics:
>  ActiveCount: 0
>  AvailableCount: 0
>  AverageBlockingTime: 0
>  AverageCreationTime: 0
>  CreatedCount: 0
>  DestroyedCount: 0
>  InUseCount: 0
>  MaxCreationTime: 0
>  MaxUsedCount: 0
>  MaxWaitCount: 0
>  MaxWaitTime: 0
>  TimedOut: 0
>  TotalBlockingTime: 0
>  TotalCreationTime: 0
>17:31:22,963 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 21) supplying ManagedConnection from pool: org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476682852 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:22,963 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 21) Got connection from pool: org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476682852 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:22,963 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (ServerService Thread Pool -- 21) No transaction, no need to enlist: org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476682852 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:22,963 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (ServerService Thread Pool -- 21) registering connection from connection manager: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl@3d04f647, connection : org.jboss.jca.adapters.jdbc.jdk6.WrappedConnectionJDK6@18072f3e, key: null
>17:31:22,963 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
>17:31:22,963 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
>17:31:22,964 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Owner: Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup]
>17:31:22,964 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
>17:31:22,964 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
>17:31:22,964 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Owner: Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup]
>17:31:22,964 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
>17:31:23,087 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
>17:31:23,087 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Owner: Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup]
>17:31:23,087 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
>17:31:23,087 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
>17:31:23,087 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Owner: Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup]
>17:31:23,088 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
>17:31:23,088 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
>17:31:23,088 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Owner: Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup]
>17:31:23,088 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
>17:31:23,088 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
>17:31:23,088 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 21) Owner: Thread[ServerService Thread Pool -- 21,5,ServerService ThreadGroup]
>17:31:23,088 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (ServerService Thread Pool -- 21) connectionClosed called mc=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5
>17:31:23,088 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (ServerService Thread Pool -- 21) unregistering connection from connection manager: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl@3d04f647, connection: org.jboss.jca.adapters.jdbc.jdk6.WrappedConnectionJDK6@18072f3e, key: null
>17:31:23,088 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (ServerService Thread Pool -- 21) unregisterConnection: 0 handles left
>17:31:23,088 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (ServerService Thread Pool -- 21) delisting org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476682852 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:23,088 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (ServerService Thread Pool -- 21) delisted org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476682852 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:23,088 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (ServerService Thread Pool -- 21) isManagedConnectionFree=true mc=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5
>17:31:23,089 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 21) returnConnection(7d2614f3, false)
>ManagedConnectionPool: 236ea9f9
>Method: returnConnection(7d2614f3, false)
>ManagedConnectionFactory:
>  Class: org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory
>  Object: 46216f19
>ConnectionListenerFactory:
>  Class: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl
>  Object: 3d04f647
>Pool:
>  Name: ExampleDS
>PoolConfiguration:
>  MinSize: 0
>  MaxSize: 20
>  BlockingTimeout: 30000
>  IdleTimeoutMinutes: 30
>  BackgroundValidation: false
>  BackgroundValidationMillis: 0
>  StrictMin: false
>  UseFastFail: false
>Available (0):
>InUse (1):
>  7d2614f3 (NORMAL)
>Statistics:
>  ActiveCount: 0
>  AvailableCount: 0
>  AverageBlockingTime: 0
>  AverageCreationTime: 0
>  CreatedCount: 0
>  DestroyedCount: 0
>  InUseCount: 0
>  MaxCreationTime: 0
>  MaxUsedCount: 0
>  MaxWaitCount: 0
>  MaxWaitTime: 0
>  TimedOut: 0
>  TotalBlockingTime: 0
>  TotalCreationTime: 0
>17:31:23,089 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 21) Returning connection to pool org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476683089 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:23,089 INFO  [org.hibernate.tool.hbm2ddl.SchemaExport] (ServerService Thread Pool -- 21) HHH000230: Schema export complete
>17:31:23,108 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-6) JBAS015877: Stopped deployment null (runtime-name: ejb.jar) in 163ms
>17:31:23,111 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-3) JBAS015877: Stopped deployment ejb-remote-client-api-usertx-test.ear (runtime-name: ejb-remote-client-api-usertx-test.ear) in 167ms
>17:31:23,239 INFO  [org.jboss.as.repository] (management-handler-thread - 4) JBAS014901: Content removed from location /home/ochaloup/tmp/jbossas-testsuite-cmr/jboss-eap-6.3-src/testsuite/integration/basic/target/jbossas/standalone/data/content/1b/cb4723be079c9891a82c2f954d5bba795f66be/content
>17:31:23,240 INFO  [org.jboss.as.server] (management-handler-thread - 4) JBAS018558: Undeployed "ejb-remote-client-api-usertx-test.ear" (runtime-name: "ejb-remote-client-api-usertx-test.ear")
>17:31:23,283 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-5) JBAS015877: Stopped deployment arquillian-service (runtime-name: arquillian-service) in 9ms
>17:31:23,408 INFO  [org.jboss.as.repository] (management-handler-thread - 1) JBAS014901: Content removed from location /home/ochaloup/tmp/jbossas-testsuite-cmr/jboss-eap-6.3-src/testsuite/integration/basic/target/jbossas/standalone/data/content/09/8843a033061706ae6f0d963607b345fa716a52/content
>17:31:23,408 INFO  [org.jboss.as.server] (management-handler-thread - 1) JBAS018558: Undeployed "arquillian-service" (runtime-name: "arquillian-service")
>17:31:23,424 INFO  [org.apache.catalina.core] (MSC service thread 1-4) JBWEB001079: Container org.apache.catalina.core.ContainerBase.[jboss.web].[default-host].[/] has not been started
>17:31:23,448 INFO  [org.jboss.as.connector.deployment] (MSC service thread 1-6) JBAS010410: Unbound JCA ConnectionFactory [java:/JmsXA]
>17:31:23,449 INFO  [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-6) JBAS010409: Unbound data source [java:jboss/datasources/MaskedDS]
>17:31:23,451 INFO  [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-2) JBAS010409: Unbound data source [java:jboss/datasources/ExampleDS]
>17:31:23,459 INFO  [org.jboss.jaxr] (MSC service thread 1-3) JBAS014002: UnBinding JAXR ConnectionFactory: java:jboss/jaxr/ConnectionFactory
>17:31:23,461 INFO  [org.apache.coyote.http11.Http11Protocol] (MSC service thread 1-7) JBWEB003075: Coyote HTTP/1.1 pausing on: http-localhost.localdomain/127.0.0.1:8080
>17:31:23,461 INFO  [org.apache.coyote.http11.Http11Protocol] (MSC service thread 1-7) JBWEB003077: Coyote HTTP/1.1 stopping on : http-localhost.localdomain/127.0.0.1:8080
>17:31:23,464 INFO  [org.jboss.as.messaging] (ServerService Thread Pool -- 21) JBAS011605: Unbound messaging object to jndi name java:jboss/exported/jms/RemoteConnectionFactory
>17:31:23,484 DEBUG [org.jboss.jca.core.connectionmanager.TxConnectionManager] (ServerService Thread Pool -- 5) java:jboss/datasources/ExampleDS: shutdown
>17:31:23,485 DEBUG [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 5) ExampleDS: shutdown
>17:31:23,485 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 5) Shutdown - Pool: ExampleDS MCP: 236ea9f9
>17:31:23,485 DEBUG [org.jboss.jca.core.connectionmanager.pool.idle.IdleRemover] (ServerService Thread Pool -- 5) Unregister pool: SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS]
>17:31:23,485 DEBUG [org.jboss.jca.core.connectionmanager.pool.idle.IdleRemover] (ServerService Thread Pool -- 5) Setting interval to Long.MAX_VALUE
>17:31:23,485 DEBUG [org.jboss.jca.core.connectionmanager.pool.validator.ConnectionValidator] (ServerService Thread Pool -- 5) Unregister pool: SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS]
>17:31:23,485 DEBUG [org.jboss.jca.core.connectionmanager.pool.validator.ConnectionValidator] (ServerService Thread Pool -- 5) Setting interval to Long.MAX_VALUE
>17:31:23,486 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 5) Flushing pool checkedOut=[] inPool=[org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476683089 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]]
>17:31:23,486 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 5) Destroying flushed connection org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7d2614f3[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f299db5 connection handles=0 lastUse=1399476683089 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3530fead pool internal context=SemaphoreArrayListManagedConnectionPool@236ea9f9[pool=ExampleDS] xaResource=LocalXAResourceImpl@23a02b23[connectionListener=7d2614f3 connectionManager=3d04f647 warned=false currentXid=null productName=PostgreSQL productVersion=9.3.4 jndiName=java:jboss/datasources/ExampleDS] txSync=null]
>17:31:23,491 DEBUG [org.jboss.jca.core.connectionmanager.TxConnectionManager] (ServerService Thread Pool -- 16) java:jboss/datasources/MaskedDS: shutdown
>17:31:23,491 DEBUG [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 16) MaskedDS: shutdown
>17:31:23,520 DEBUG [org.jboss.jca.core.connectionmanager.TxConnectionManager] (ServerService Thread Pool -- 27) java:/JmsXA: shutdown
>17:31:23,520 DEBUG [org.jboss.jca.core.connectionmanager.pool.strategy.PoolByCri] (ServerService Thread Pool -- 27) HornetQConnectionDefinition: shutdown
>17:31:23,526 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-2) JBAS015877: Stopped deployment postgresql-9.3-1100.jdbc4.jar (runtime-name: postgresql-9.3-1100.jdbc4.jar) in 97ms
>17:31:23,544 INFO  [org.hornetq.ra] (ServerService Thread Pool -- 27) HQ151003: HornetQ resource adaptor stopped
>17:31:23,546 DEBUG [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (MSC service thread 1-5) stop: CachedConnectionManagerImpl@60e7e2d1[debug=false error=false transactionManager=org.jboss.jca.core.tx.jbossts.TransactionManagerDelegator@17dc390b transactionSynchronizationRegistry=com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionSynchronizationRegistryImple@7b250d69 userTransactionRegistry=org.jboss.jca.core.tx.jbossts.UserTransactionRegistryImpl@3d93a7a8 currentObjects=null objectToConnectionManagerMap={} connectionStackTraces={}]
>17:31:23,549 INFO  [com.arjuna.ats.jbossatx] (MSC service thread 1-5) ARJUNA032018: Destroying TransactionManagerService
>17:31:23,550 INFO  [com.arjuna.ats.jbossatx] (MSC service thread 1-5) ARJUNA032014: Stopping transaction recovery manager
>17:31:23,551 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-5) PeriodicRecovery: Mode <== TERMINATED
>17:31:23,551 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-5) PeriodicRecovery: shutdown waiting for scan to end
>17:31:23,551 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: scan TERMINATED at phase 1
>17:31:23,551 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread Status <== INACTIVE
>17:31:23,551 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread exiting
>17:31:23,551 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-5) PeriodicRecovery: shutdown scan wait complete
>17:31:23,678 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 5) HQ221002: HornetQ Server version 2.3.18.Final (2.3.18, 123) [7bb985fe-d5f0-11e3-8778-9dadac5c51b7] stopped
>17:31:23,695 INFO  [org.jboss.as] (MSC service thread 1-8) JBAS015950: JBoss EAP 6.3.0.Beta1 (AS 7.4.0.Final-redhat-11) stopped in 260ms

Actions: View

Attachments on bug 1095413: 893362 | 893364