Uploaded image for project: 'JBoss Transaction Manager'
  1. JBoss Transaction Manager
  2. JBTM-2792

Participant is not rolled-back when RMERR thrown during prepare phase

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Won't Do
    • Icon: Critical Critical
    • None
    • 5.3.5.Final
    • JTA
    • None
    • Hide 
      git clone http://git.app.eng.bos.redhat.com/git/jbossqe-eap-tests-transactions.git
export JBOSS_HOME=... (downloadable at http://download.eng.brq.redhat.com/devel/candidates/JBEAP/)
DS_PROPS="-Dds0.db=oracle -Dds0.jdbc.driver.url=http://www.qa.jboss.com/jdbc-drivers-products/EAP/7.1.0/postgresql94/jdbc4/postgresql-9.4.1209.jar -Dds0.jdbc.xa-class=org.postgresql.xa.PGXADataSource -Dds0.jdbc.url=jdbc:postgresql://gen-vm006.mw.lab.eng.bos.redhat.com:5432/crashrec -Dds0.db.name=crashrec -Dds0.user=crashrec -Dds0.pass=crashrec -Dds0.jdbc.driver.jar=postgresql-driver.jar"

mvn clean verify -am -pl jbossts -DfailIfNoTests=false -Djbossts.noJTS -Dtest=JPAProxyCrashRecoveryTestCase#prepareHalt
      Show
      git clone http: //git.app.eng.bos.redhat.com/git/jbossqe-eap-tests-transactions.git export JBOSS_HOME=... (downloadable at http: //download.eng.brq.redhat.com/devel/candidates/JBEAP/) DS_PROPS= "-Dds0.db=oracle -Dds0.jdbc.driver.url=http: //www.qa.jboss.com/jdbc-drivers-products/EAP/7.1.0/postgresql94/jdbc4/postgresql-9.4.1209.jar -Dds0.jdbc.xa-class=org.postgresql.xa.PGXADataSource -Dds0.jdbc.url=jdbc:postgresql://gen-vm006.mw.lab.eng.bos.redhat.com:5432/crashrec -Dds0.db.name=crashrec -Dds0.user=crashrec -Dds0.pass=crashrec -Dds0.jdbc.driver.jar=postgresql-driver.jar" mvn clean verify -am -pl jbossts -DfailIfNoTests= false -Djbossts.noJTS -Dtest=JPAProxyCrashRecoveryTestCase#prepareHalt

      I do experience trouble - or maybe different behavior against older version of Narayana - with forgetting transaction log when failure is caused by jdbc driver throws XAException.XAER_RMERR during prepare phase of 2PC.

      The test scenario is following

      • prepare db/jms XA
      • stop connection to db/jms
      • prepare test XA
      • commit db/jms XA (connection is down - jdbc driver throws XAException.XAER_RMERR)
      • client gets javax.transaction.TransactionRolledbackException from server side
      • trying to abort transaction
      • rollback of db resource but connection is down
      • rolback test XA    
      • connection is started again
      • expected behaviour: periodic recovery -> rollback db XA

      For current Narayana version (tested with 5.3.5 and 5.4.1.snapshot) the periodic recovery does not rolled back the participant during recovery cycle.

      For Narayana 5.3.3.Final periodic recovery votes for rollback (ROLLBACK)[1].
      Narayan 5.3.5.Final ends with voting for doing nothing (JTATransactionLogXAResourceOrphanFilter.LEAVE_ALONE)[2].
      It seems to me that's caused by fact that directly after transaction commit fails (because of not existing connection) for previous version of Narayana transaction record about participant was removed from txn log [3]. But in current version the transaction record is left in log[4] and orphan filters do not vote for roll-backing in bottom-up phase later on.

      [1]

      2016-11-21 09:01:25,576 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) ShadowingStore.currentState(0:ffff7f000001:-70f14116:5832a97b:26, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction) - returning StateStatus.OS_UNKNOWN2016-11-21 09:01:25,576 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) No record found for < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-70f14116:5832a97b:26, node_name=1, branch_uid=0:ffff7f000001:-70f14116:5832a97b:29, subordinatenodename=null, eis_name=java:jboss/xa-datasources/CrashRecoveryDS >2016-11-21 09:01:25,576 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) XAResourceOrphanFilter com.arjuna.ats.internal.jta.recovery.arjunacore.JTATransactionLogXAResourceOrphanFilter voted ABSTAIN2016-11-21 09:01:25,576 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) node name of < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-70f14116:5832a97b:26, node_name=1, branch_uid=0:ffff7f000001:-70f14116:5832a97b:29, subordinatenodename=null, eis_name=java:jboss/xa-datasources/CrashRecoveryDS > is 12016-11-21 09:01:25,576 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) XAResourceOrphanFilter com.arjuna.ats.internal.jta.recovery.arjunacore.JTANodeNameXAResourceOrphanFilter voted ROLLBACK2016-11-21 09:01:25,576 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) subordinate node name of < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-70f14116:5832a97b:26, node_name=1, branch_uid=0:ffff7f000001:-70f14116:5832a97b:29, subordinatenodename=null, eis_name=java:jboss/xa-datasources/CrashRecoveryDS > is null2016-11-21 09:01:25,576 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) XAResourceOrphanFilter com.arjuna.ats.internal.jta.recovery.arjunacore.SubordinateJTAXAResourceOrphanFilter voted ABSTAIN2016-11-21 09:01:25,577 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) node name of < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-70f14116:5832a97b:26, node_name=1, branch_uid=0:ffff7f000001:-70f14116:5832a97b:29, subordinatenodename=null, eis_name=java:jboss/xa-datasources/CrashRecoveryDS > is 1

      [2]

      2016-11-21 09:18:03,008 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Found record for < formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-359c90f5:5832ad62:27, node_name=1, branch_uid=0:ffff7f000001:-359c90f5:5832ad62:2a, subordinatenodename=null, eis_name=java:jboss/xa-datasources/CrashRecoveryDS >2016-11-21 09:18:03,008 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) XAResourceOrphanFilter com.arjuna.ats.internal.jta.recovery.arjunacore.JTATransactionLogXAResourceOrphanFilter voted LEAVE_ALONE

      [3]

      2016-11-21 09:00:33,981 TRACE [com.arjuna.ats.arjuna] (default task-8) BasicAction::updateState() for action-id 0:ffff7f000001:-70f14116:5832a97b:262016-11-21 09:00:33,981 TRACE [com.arjuna.ats.arjuna] (default task-8) FileSystemStore.remove_committed(0:ffff7f000001:-70f14116:5832a97b:26, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction)2016-11-21 09:00:33,981 TRACE [com.arjuna.ats.arjuna] (default task-8) ShadowingStore.remove_state(0:ffff7f000001:-70f14116:5832a97b:26, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction, StateType.OS_ORIGINAL)

      [4]

      2016-11-21 09:17:11,785 TRACE [com.arjuna.ats.arjuna] (default task-8) Packing action status of ActionStatus.ABORTING2016-11-21 09:17:11,785 TRACE [com.arjuna.ats.arjuna] (default task-8) FileSystemStore.write_committed(0:ffff7f000001:-359c90f5:5832ad62:27, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction)2016-11-21 09:17:11,785 TRACE [com.arjuna.ats.arjuna] (default task-8) ShadowingStore.write_state(0:ffff7f000001:-359c90f5:5832ad62:27, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction, StateType.OS_ORIGINAL)2016-11-21 09:17:11,785 TRACE [com.arjuna.ats.arjuna] (default task-8) ShadowingStore.genPathName(0:ffff7f000001:-359c90f5:5832ad62:27, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction, StateType.OS_ORIGINAL)

        1. JPAProxyCrashRecoveryTestCase_prepareHalt_jta_server-5.3.3.Final.log
          355 kB
        2. JPAProxyCrashRecoveryTestCase_prepareHalt_jta_server-5.3.5.Final.log
          449 kB

              thjenkin@redhat.com Tom Jenkinson
              ochaloup@redhat.com Ondrej Chaloupka (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

                Created:
                Updated:
                Resolved: