-
Bug
-
Resolution: Done
-
Blocker
-
7.0.0.ER4
-
None
The use case is as follow:
Client makes a call to a bean on server-1
bean (server-1) inserts a row into table-1
bean (server-1) calls to a bean on server-2
bean (server-2) inserts a row into table-2
bean (server-2) goes to sleep for 3 minutes
periodic recovery (server-1) flags the remote branchof the transaction (on server-2) as in doubt and rolls it back.
(server-1 log)
11:53:37,991 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids _whenFirstSeen toRecover no RecoveryOnlyEJBXAResource{receiverContext=EJBReceiverContext
, transactionOriginNodeIdentifier='server1'} 1452599607985 === 1452599617991
11:53:37,991 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Have 1 Xids to recover on this pass.
11:53:37,992 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) No record found for < formatId=131077, gtrid_length=35, bqual_length=43, tx_uid=0:ffffc0a80164:-fa2e9db:5694e833:2c, node_name=server1, branch_uid=0:ffffc0a80164:-fa2e9db:5694e833:39, subordinatenodename=server2, eis_name=unknown eis name >
11:53:37,992 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) XAResourceOrphanFilter com.arjuna.ats.internal.jta.recovery.arjunacore.JTATransactionLogXAResourceOrphanFilter voted ABSTAIN
11:53:37,993 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) node name of < formatId=131077, gtrid_length=35, bqual_length=43, tx_uid=0:ffffc0a80164:-fa2e9db:5694e833:2c, node_name=server1, branch_uid=0:ffffc0a80164:-fa2e9db:5694e833:39, subordinatenodename=server2, eis_name=unknown eis name > is server1
11:53:37,993 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) XAResourceOrphanFilter com.arjuna.ats.internal.jta.recovery.arjunacore.JTANodeNameXAResourceOrphanFilter voted ROLLBACK
11:53:37,993 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) subordinate node name of < formatId=131077, gtrid_length=35, bqual_length=43, tx_uid=0:ffffc0a80164:-fa2e9db:5694e833:2c, node_name=server1, branch_uid=0:ffffc0a80164:-fa2e9db:5694e833:39, subordinatenodename=server2, eis_name=unknown eis name > is server2
11:53:37,993 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Checking whether Xid < formatId=131077, gtrid_length=35, bqual_length=43, tx_uid=0:ffffc0a80164:-fa2e9db:5694e833:2c, node_name=server1, branch_uid=0:ffffc0a80164:-fa2e9db:5694e833:39, subordinatenodename=server2, eis_name=unknown eis name > exists in ObjectStore.
11:53:37,993 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Looking for 0:ffffc0a80164:-fa2e9db:5694e833:2c and /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction/SubordinateAtomicAction/JCA
11:53:37,993 INFO [com.arjuna.ats.jta] (Periodic Recovery) ARJUNA016013: Rolling back < formatId=131077, gtrid_length=35, bqual_length=43, tx_uid=0:ffffc0a80164:-fa2e9db:5694e833:2c, node_name=server1, branch_uid=0:ffffc0a80164:-fa2e9db:5694e833:39, subordinatenodename=server2, eis_name=unknown eis name >
(server-2 log)
11:53:37,997 TRACE [com.arjuna.ats.jta] (EJB default - 5) TransactionImple.getStatus: javax.transaction.Status.STATUS_ACTIVE
11:53:37,998 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) BasicAction::phase2Abort() for action-id 0:ffffc0a80164:-41fcd6d0:5694e85a:34
11:53:37,998 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) BasicAction::doAbort (XAResourceRecord < resource:XAResourceWrapperImpl@3de8e444[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@6440856e pad=false overrideRmValue=false productName=PostgreSQL productVersion=9.4.1 jndiName=java:jboss/datasources/testJBossDS], txid:< formatId=131077, gtrid_length=35, bqual_length=43, tx_uid=0:ffffc0a80164:-fa2e9db:5694e833:2c, node_name=server1, branch_uid=0:ffffc0a80164:-41fcd6d0:5694e85a:3e, subordinatenodename=server2, eis_name=java:jboss/datasources/testJBossDS >, heuristic: TwoPhaseOutcome.FINISH_OK, product: PostgreSQL/9.4.1, jndiName: java:jboss/datasources/testJBossDS com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@32ff4c6d >)
11:53:37,998 TRACE [com.arjuna.ats.jta] (EJB default - 5) XAResourceRecord.topLevelAbort for XAResourceRecord < resource:XAResourceWrapperImpl@3de8e444[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@6440856e pad=false overrideRmValue=false productName=PostgreSQL productVersion=9.4.1 jndiName=java:jboss/datasources/testJBossDS], txid:< formatId=131077, gtrid_length=35, bqual_length=43, tx_uid=0:ffffc0a80164:-fa2e9db:5694e833:2c, node_name=server1, branch_uid=0:ffffc0a80164:-41fcd6d0:5694e85a:3e, subordinatenodename=server2, eis_name=java:jboss/datasources/testJBossDS >, heuristic: TwoPhaseOutcome.FINISH_OK, product: PostgreSQL/9.4.1, jndiName: java:jboss/datasources/testJBossDS com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@32ff4c6d >, record id=0:ffffc0a80164:-41fcd6d0:5694e85a:3f
11:53:37,998 TRACE [org.jboss.as.connector.subsystems.datasources.AbstractDataSourceService$MyXaMCF] (EJB default - 5) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
11:53:37,998 TRACE [org.jboss.as.connector.subsystems.datasources.AbstractDataSourceService$MyXaMCF] (EJB default - 5) Owner: Thread[EJB default - 5,5,EJB default]
11:53:37,999 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) BasicAction::doAbort() result for action-id (0:ffffc0a80164:-41fcd6d0:5694e85a:34) on record id: (0:ffffc0a80164:-41fcd6d0:5694e85a:3f) is (TwoPhaseOutcome.FINISH_OK) node id: (server2)
11:53:37,999 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) BasicAction::updateState() for action-id 0:ffffc0a80164:-41fcd6d0:5694e85a:34
11:53:37,999 TRACE [com.arjuna.ats.jta] (EJB default - 5) SynchronizationImple.afterCompletion
bean (server-2) wake up
bean (server-1) updates the row in table-1
at this point the parent transaction gets committed without an error
11:55:31,104 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) BasicAction::removeChildThread () action 0:ffffc0a80164:-fa2e9db:5694e833:2c removing TSThread:1
11:55:31,104 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) BasicAction::removeChildThread () action 0:ffffc0a80164:-fa2e9db:5694e833:2c removing TSThread:1 result = true
11:55:31,104 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) TransactionReaper::remove ( BasicAction: 0:ffffc0a80164:-fa2e9db:5694e833:2c status: ActionStatus.COMMITTED )
client call ends
When I look at the table in the database I see a row in table-1 but no row in table-2. I would expect to see both tables empty.
When I switch to JTS and run the same use case it all works as expected.
- clones
-
WFLY-6011 Remote branch of a transaction gets rolled back incorrectly.
- Closed
- is related to
-
EJBCLIENT-151 Wrong handling of prepare in EJB recovery-only XAResource
- Resolved