4:26 p.m.
[
https://issues.jboss.org/browse/WFLY-6011?page=com.atlassian.jira.plugin....
]
Tom Jenkinson commented on WFLY-6011:
-------------------------------------
The reason the unprepared branches are returned is caused by this:
https://github.com/wildfly/wildfly/blob/master/ejb3/src/main/java/org/jbo...
The reason that the unprepared branches are returned is to support the case where a remote
server crashes and we then need some way to roll back transactions that have been
propagated (which do not have a timeout value set). To be able to do that, does JBoss
Remoting know when a remote server it has inflowed transactions for has crashed. If so EJB
can hook into that and rollback the unprepared transactions at that point?
To recap, we should remove the inflight (unprepared) Xids from the
getXidsToRecoverForParentNode() call but find a way to rollback those same inflight
transactions once we detect the connection to the remote server is broken.
Remote branch of a transaction gets rolled back incorrectly.
-------------------------------------------------------------
Key: WFLY-6011
URL: https://issues.jboss.org/browse/WFLY-6011
Project: WildFly
Issue Type: Bug
Components: EJB
Reporter: Jason Greene
Assignee: David Lloyd
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)
{noformat}
11:53:37,991 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids
_whenFirstSeen toRecover no
RecoveryOnlyEJBXAResource{receiverContext=EJBReceiverContext{clientContext=org.jboss.ejb.client.EJBClientContext@322f7790,
receiver=Remoting connection EJB receiver [connection=Remoting connection
<2c1ab3f6>,channel=jboss.ejb,nodename=server2]},
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 >
{noformat}
(server-2 log)
{noformat}
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
{noformat}
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
{noformat}
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 )
{noformat}
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.
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
3763
days inactive
3763
days old
0 comments
1 participants
participants (1)
-
Tom Jenkinson (JIRA)