Bug 1095413

Summary: [RFE] EAP6-17 CMR synchronization clashes with Hibernate registration of beforeCompletion synchronization
Product: [JBoss] JBoss Enterprise Application Platform 6 Reporter: Ondrej Chaloupka <ochaloup>
Component: Transaction ManagerAssignee: Michael <mmusgrov>
Status: CLOSED CURRENTRELEASE QA Contact: Ondrej Chaloupka <ochaloup>
Severity: urgent Docs Contact: Russell Dickenson <rdickens>
Priority: unspecified    
Version: 6.3.0CC: dosoudil, hhovsepy, jkudrnac, kkhan, tom.jenkinson
Target Milestone: ER5   
Target Release: EAP 6.3.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2014-06-28 15:39:55 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1097673    
Attachments:
Description Flags
server.log with error
none
standalone-full.xml none

Description Ondrej Chaloupka 2014-05-07 16:01:27 UTC 
I wanted to run the JBoss AS testsuite with CMR datasource being configured as the only (main) datasource for the tests. This means that I reconfigured ExampleDS datasource to be CMR.

The tests which runs against the ExampleDS datasource fails with the following errors in log [1].

I tried reconfigured the ExampleDS to be run against the same database account but without the CMR would be configured and the tests pass.
I've checked the existence of 'xids' table in the database and it does exist and is writable under the account.

So it seems to me that there is some trouble in TM and CMR handling. If the error is not on my side of the configuration then I think this is quite bad. The JBoss AS testsuite should work with simple CMR.

Can you, please, look at this?

[1]
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)
Comment 1 Ondrej Chaloupka 2014-05-07 16:02:40 UTC 
Created attachment 893362 [details]
server.log with error
Comment 2 Ondrej Chaloupka 2014-05-07 16:04:16 UTC 
Created attachment 893364 [details]
standalone-full.xml

The file could be used for reproducing the issue but the database account could need to be changed. Respectively it needs to be checked that 'xids' table does exist in DB.
Comment 4 Michael 2014-05-08 10:02:38 UTC 
Hibernate is registering the CMR resource during a beforeCompletion synchronization. The CMR resource then registers its own synchronization. JTA Synchronization ordering prohibits the addition of a synchronization if it would be ordered before any synchronizatons that have already been called.

The fix is to make sure the CMR synchronization is ordered after the hibernate synchronization.
Comment 5 Ondrej Chaloupka 2014-05-09 06:08:40 UTC 
Issue could be quite easily hit by customer using CMR and Hibernate. Proposing as a blocker for GA.
Comment 6 Kabir Khan 2014-05-15 08:07:13 UTC 
Fixed by https://bugzilla.redhat.com/show_bug.cgi?id=1097673
Comment 7 Ondrej Chaloupka 2014-06-02 13:06:42 UTC 
Verified for EAP 6.3.0.ER5
Comment 8 JBoss JIRA Server 2014-09-15 12:49:41 UTC 
Tom Jenkinson <tom.jenkinson> updated the status of jira JBTM-2165 to Closed