Table of Contents
Potential Transaction Timeouts in a JEE7 / RAC 12.1.0.2 env
- JTA Transaction Timeout triggering an OracleXAResource.rollback operation on our TM side [ Wildfly 8.2 ]
- JTA Transaction Timeout occuring on the RM side [ ORA-24756 ]
- DISTRIBUTED LOCK TIMEOUT occuring on the RM side [ ORA-2049 ]
- HTTPSession Object Timeout
Rule of Thumb
- JTA transaction timeout < DISTRIBUTED_LOCK_TIMEOUT < HTTP Session Timeout
- In a working JTA env we only want to see JTA timeouts triggered by our TM [ see 1. ]
Overview Bean Managed Transaction with JTA
- Each JTA transaction is associated with an Execution Thread
- Only a single Transaction can be active within an Execution Thread
- If one Transaction is active the user can’t start an new one until the TX was committed suspended or rolled back
- The setTransactionTimeout() method causing the transaction to roll back after reaching the timeout limit
- Do not invoke the getRollbackOnly and setRollbackOnly methods of the EJBContext interface in bean-managed transactions [ BMT ]
- For bean-managed transactions, invoke the getStatus and rollback methods of the UserTransaction interface
- If a session times out within Oracle, then the Oracle database Process Monitor (PMON) will delete the transaction branch if not prepared or cause the transaction to become in-doubt if prepared.
- We can track the Transaction Timeout at RM side using Event 10246
alter system set event=”10246 trace name context forever, level 1″ scope=spfile sid=’*’; - If the PMON terminates the transaction branch you should get error: ORA-24756: transaction does not exist
- If the Transaction can’t get a database lock you should get error: ORA-02049: timeout: distributed transaction waiting for lock
- During this JPA test we use OnePhaseCommit [ means no 2PC / no prepare call ]
- We always want that our TM is controlling the Transaction
- If runnig with correct timeout settings we should not see any ORA-2049 or ORA-24756 errors
How to track the XA transaction at database level
- FORMATID, GLOBALID, BRANCHID build our XA Xid
- TIGHTLY COUPLED means we serialize using a DX lock [ can lead to a performance problem ] and can use RAC ClusterWide Transaction Feature
- PREPARECOUNT=0 this Tx is not yet prepared
- STATE ACTIVE means this transaction is active
SQL> select FORMATID, GLOBALID, BRANCHID, BRANCHES, REFCOUNT, PREPARECOUNT, STATE, FLAGS, COUPLING from v$global_transaction; FORMATID GLOBALID ---------- ---------------------------------------------------------------- BRANCHID -------------------------------------------------------------------------------------------------------------------------------- BRANCHES REFCOUNT PREPARECOUNT STATE FLAGS COUPLING ---------- ---------- ------------ -------------------------------------- ---------- --------------- 131077 00000000000000000000FFFFC0A805C935ABDAA855FBBB600000046931 00000000000000000000FFFFC0A805C935ABDAA855FBBB600000046C0000000200000000 1 1 0 ACTIVE 0 TIGHTLY COUPLED
TEST 1: Testing global JTA Timeout
- The service routine will run 60 seconds before committing the data
- The JPA timeout will rollback the transaction after the JTA timeout [ 30 seconds ]
- The Transaction Reaper Wildfly Thread will rollback the transaction after 30 second
- Later on the commit fails as we don’t run inside a transaction anymore
Setup HTTP Session Timeout : 1800 seconds JTA Timeout : 30 seconds ut.setTransactionTimeout() : not active Service routine sleep : 60 seconds Setup and verify JTA Transaction Timeout : 30 seconds: $ $WILDFLY_HOME/bin/jboss-cli.sh --connect --controller=localhost:9990 '/subsystem=transactions/:write-attribute(name=default-timeout,value=30)'; { "outcome" => "success", "result" => 30, "response-headers" => {"process-state" => "reload-required"} } $ $WILDFLY_HOME/bin/jboss-cli.sh --connect --controller=localhost:9990 '/subsystem=transactions/:read-attribute(name=default-timeout)' { "outcome" => "success", "result" => 30 } -> Restart Wildfly -> Run test test case Wildfly Logs: 10:18:52,211 INFO [stdout] (default task-15) +++ HttpSessionListenerImpl:: sessionCreated().... 10:18:55,489 INFO [org.eclipse.persistence.connection] (default task-36) Connected: jdbc:oracle:thin:@ract2-scan.grid12c.example.com:1521/banka User: SCOTT Database: Oracle Version: Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production Driver: Oracle JDBC driver Version: 12.1.0.2.0 ... 2015-09-17 10:18:55,500 INFO [org.eclipse.persistence.connection] (default task-17) vfs:/usr/local/wildfly-8.2.0.Final/standalone/deployments/WFJPA2EL-1.0.war/WEB-INF/classes/_jpaELPU login successful 10:19:27,365 WARN [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a805c9:6a216e79:55fa71c5:72 in state RUN 10:19:27,367 WARN [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012095: Abort of action id 0:ffffc0a805c9:6a216e79:55fa71c5:72 invoked while multiple threads active within it. 10:19:27,368 WARN [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012108: CheckedAction::check - atomic action 0:ffffc0a805c9:6a216e79:55fa71c5:72 aborting with 1 threads active! 10:19:27,383 WARN [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012121: TransactionReaper::doCancellations worker Thread[Transaction Reaper Worker 0,5,main] successfully canceled TX 0:ffffc0a805c9:6a216e79:55fa71c5:72 10:19:57,381 WARN [com.arjuna.ats.arjuna] (default task-17) ARJUNA012077: Abort called on already aborted atomic action 0:ffffc0a805c9:6a216e79:55fa71c5:72 -> JPA connection returned at 10:18:55 About 32 seconds later the global JTA timeout kicks in and terminates the transaction a Stack : 10:19:57.382 Error in top level function: timeoutTest() 10:19:57.384 ARJUNA016102: The transaction is not active! Uid is 0:ffffc0a805c9:6a216e79:55fa71c5:72 10:19:57.385 javax.transaction.RollbackException: ARJUNA016102: The transaction is not active! Uid is 0:ffffc0a805c9:6a216e79:55fa71c5:72 at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1156) 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.tm.usertx.client.ServerVMClientUserTransaction.commit(ServerVMClientUserTransaction.java:173) at com.hhu.wfjpa2el.JPATestBean.timeoutTest(JPATestBean.java:456)
TEST 2: Overriding global JTA Timeout with ut.setTransactionTimeout()
- This test is similar to TEST 1
- it only overrides the JTA transaction timeout with setTransactionTimeout()
Setup HTTP Session Timeout : 1800 seconds JTA Timeout : 30 seconds ut.setTransactionTimeout() : 15 seconds Service routine sleep : 60 seconds Java Code ... ut = (UserTransaction)new InitialContext().lookup("java:comp/UserTransaction"); ut.setTransactionTimeout(getTxTimeout()); ut.begin(); ... Wildfly Log : 2015-09-17 10:58:58,426 INFO [org.eclipse.persistence.connection] (default task-36) Connected: jdbc:oracle:thin:@ract2-scan.grid12c.example.com:1521/banka User: SCOTT Database: Oracle Version: Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production Driver: Oracle JDBC driver Version: 12.1.0.2.0 2015-09-17 10:58:58,431 INFO [org.eclipse.persistence.connection] (default task-36) vfs:/usr/local/wildfly-8.2.0.Final/standalone/deployments/WFJPA2EL-1.0.war/WEB-INF/classes/_jpaELPU login successful 2015-09-17 10:59:15,094 WARN [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a805c9:6a216e79:55fa71c5:11a in state RUN 2015-09-17 10:59:15,096 WARN [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012095: Abort of action id 0:ffffc0a805c9:6a216e79:55fa71c5:11a invoked while multiple threads active within it. 2015-09-17 10:59:15,097 WARN [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012108: CheckedAction::check - atomic action 0:ffffc0a805c9:6a216e79:55fa71c5:11a aborting with 1 threads active! 2015-09-17 10:59:15,115 WARN [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012121: TransactionReaper::doCancellations worker Thread[Transaction Reaper Worker 0,5,main] successfully canceled TX 0:ffffc0a805c9:6a216e79:55fa71c5:11a -> JPA connection returned at 10:58:58, -> About 17 seconds later the Timeout value set by ut.setTransactionTimeout() kicks in and terminates the transaction a -> As in TEST 1 the commit fail with a similar stack
TEST 3 : Stop all TM Threads and let the RM [ Resource Manager ] terminate the transaction
- In this test set a breakpoint at OracleXAResource.commit to stop all WildFly Threads
- This will avoid that any WildFly Thread is running a ROLLBACK
- You may read following article to setup a XA Breakpoints with Netbeans
- As no client ROLLBACK operation can terminate the transaction PMON takes over control and terminates the TX
Setup HTTP Session Timeout : 1800 seconds JTA Timeout : 30 seconds ut.setTransactionTimeout() : 20 seconds Service routine sleep : not active PMON Tracing Enable PMON tracing for our RAC 12.1.0.2 database SQL> alter system set event="10246 trace name context forever, level 1" scope=spfile sid='*'; SQL> startup force SQL> show parameter event SQL> NAME TYPE VALUE ------------------------------------ ----------- ------------------------------ even t string 10246 trace name context forever, level 1 PMON trace *** 2015-09-18 11:47:04.143 bno=1 timeout=20 dtime=1442569601 ctime=1442569623 ser=1 evt=1 ksuprog() called at ktur.c:3906 [claim lock 0x74cb0100 for dead session/txn in procp 0x76b29430.18437][hist x424224a1] deleted branch 0x72558fc0 in first attempt PMON last posted from location=FILE:/ade/b/2502491802/oracle/rdbms/src/hdir/ksa2.h LINE:294 ID:ksasnr, process=47, post_num=41 -> timeout=20 translates to our JTA timing set with ut.setTransactionTimeout(20); -> The RM ( Oracle Database ) has terminated this Transaction -> The transaction timeout was to 20 [ timeout=20 ] Errors : XA Failure : XAException.XAER_NOTA: oracle.jdbc.xa.OracleXAException ORacle Failure : java.sql.SQLException: ORA-24756: transaction does not exist Java Stack : Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP, Advanced Analytics and Real Application Testing options jndiName=java:jboss/datasources/xa_rac12g_banka]) failed with exception XAException.XAER_NOTA: oracle.jdbc.xa.OracleXAException at oracle.jdbc.driver.T4CXAResource.kputxrec(T4CXAResource.java:965) at oracle.jdbc.driver.T4CXAResource.doCommit(T4CXAResource.java:454) at oracle.jdbc.xa.client.OracleXAResource.commit(OracleXAResource.java:583) at org.jboss.jca.adapters.jdbc.xa.XAManagedConnection.commit(XAManagedConnection.java:338) at org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.commit(XAResourceWrapperImpl.java:107) at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelOnePhaseCommit(XAResourceRecord.java:679) [jbossjta-4.16.6.Final.jar:] at com.arjuna.ats.arjuna.coordinator.BasicAction.onePhaseCommit(BasicAction.java:2317) [jbossjta-4.16.6.Final.jar:] at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1475) [jbossjta-4.16.6.Final.jar:] at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:96) [jbossjta-4.16.6.Final.jar:] at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162) [jbossjta-4.16.6.Final.jar:] at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1166) [jbossjta-4.16.6.Final.jar:] at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126) [jbossjta-4.16.6.Final.jar:] at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75) at org.jboss.tm.usertx.client.ServerVMClientUserTransaction.commit(ServerVMClientUserTransaction.java:173) at com.hhu.wfjpa2el.JPATestBean.timeoutTest(JPATestBean.java:466) [classes:] Caused by: java.sql.SQLException: ORA-24756: transaction does not exist at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:450) at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:392) at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:385) at oracle.jdbc.driver.T4CTTIfun.processError(T4CTTIfun.java:1018) at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:522) at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:257) at oracle.jdbc.driver.T4CTTIOtxen.doOTXEN(T4CTTIOtxen.java:166) at oracle.jdbc.driver.T4CXAResource.doTransaction(T4CXAResource.java:757) at oracle.jdbc.driver.T4CXAResource.doCommit(T4CXAResource.java:428)
TEST 4 : Understand and Testing DISTRIBUTED_LOCK_TIMEOUT
- DISTRIBUTED_LOCK_TIMEOUT default value is 60 seconds
- If a DML can get the lock within DISTRIBUTED_LOCK_TIMEOUT ORA-2049 is thrown
If the locking transaction runs for longer than the database DISTRIBUTED_LOCK_TIMEOUT (e.g. a single phase trans action with no timeout) a deadlock type situation occurs and the XA / Oracle distributed transactions can fail with “ORA-02049: timeout: distributed transaction waiting for lock”. If the ordering of timeouts is correct, then this error should never be received within a XA distributed transaction since the TM timeout should be exceeded before the DISTRIBUTED_LOCK_TIMEOUT is reached Setup HTTP Session Timeout : 1800 seconds JTA Timeout : 30 seconds ut.setTransactionTimeout() : 120 seconds DISTRIBUTED_LOCK_TIMEOUT : 60 seconds As ut.setTransactionTimeout() < DISTRIBUTED_LOCK_TIMEOUT the database will throw ORA-2049 errors Prepare test SQL> show parameter dist NAME TYPE VALUE ------------------------------------ ----------- ------------------------------ distributed_lock_timeout integer 60 Note PMON runs only every 60 seconds so we can see a delay between 60 and 120 seconds untill we hot ORA-2049 Lock the records SQL> select * from emp2 for update; EMPNO ENAME JOB SAL ---------- ---------- --------- ---------- 9997 Helmut Progr. 63206 Our JPA code will start a BMT and update the same record resulting in a ORA-2049 error UPDATE EMP2 SET SAL = ? WHERE (EMPNO = ?) Call flow ut.begin() JPA update gets blocked untill we hit ORA-2049 error Verify the Transation status before getting ORA-2049 SQL> select FORMATID, GLOBALID, BRANCHID, BRANCHES, REFCOUNT, PREPARECOUNT, STATE, FLAGS, COUPLING from v$global_transaction; FORMATID GLOBALID ---------- ---------------------------------------------------------------- BRANCHID -------------------------------------------------------------------------------------------------------------------------------- BRANCHES REFCOUNT PREPARECOUNT STATE FLAGS COUPLING ---------- ---------- ------------ -------------------------------------- ---------- --------------- 131077 00000000000000000000FFFFC0A805C935ABDAA855FBBB60000003C931 00000000000000000000FFFFC0A805C935ABDAA855FBBB60000003CC0000000200000000 1 1 0 ACTIVE 0 TIGHTLY COUPLED Error Stacks 12:06:04.535 Error in top level function: timeoutTest() 12:06:04.536 Exception [EclipseLink-4002] (Eclipse Persistence Services - 2.5.2.v20140319-9ad6abd): org.eclipse.persistence.exceptions.DatabaseException Internal Exception: java.sql.SQLSyntaxErrorException: ORA-02049: timeout: distributed transaction waiting for lock Error Code: 2049 Call: UPDATE EMP2 SET SAL = ? WHERE (EMPNO = ?) bind => [2 parameters bound] Query: UpdateObjectQuery(com.hhu.wfjpa2el.Emp2[ empno=9997 ]) 12:06:04.539 javax.persistence.PersistenceException: Exception [EclipseLink-4002] (Eclipse Persistence Services - 2.5.2.v20140319-9ad6abd): org.eclipse.persistence.exceptions.DatabaseException Internal Exception: java.sql.SQLSyntaxErrorException: ORA-02049: timeout: distributed transaction waiting for lock Error Code: 2049 Call: UPDATE EMP2 SET SAL = ? WHERE (EMPNO = ?) bind => [2 parameters bound] Query: UpdateObjectQuery(com.hhu.wfjpa2el.Emp2[ empno=9997 ]) at org.eclipse.persistence.internal.jpa.EntityManagerImpl.flush(EntityManagerImpl.java:868) at com.hhu.wfjpa2el.JPATestBean.timeoutTest(JPATestBean.java:472) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) 2015-09-18 12:27:05,295 WARN [com.arjuna.ats.jta] (Periodic Recovery) ARJUNA016037: Could not find new XAResource to use for recovering non-serializable XAResource XAResourceRecord < resource:null, txid:< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffffc0a805c9:35abdaa8:55fbbb60:49, node_name=1, branch_uid=0:ffffc0a805c9:35abdaa8:55fbbb60:4c, subordinatenodename=null, eis_name=java:jboss/datasources/xa_rac12g_banka >, heuristic: TwoPhaseOutcome.FINISH_OK, product: Oracle/Oracle Database 12c12:27:05,295 WARN [com.arjuna.ats.jta] (Periodic Recovery) ARJUNA016037: Could not find new XAResource to use for recovering non-serializable XAResource XAResourceRecord < resource:null, txid:< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffffc0a805c9:35abdaa8:55fbbb60:49, node_name=1, branch_uid=0:ffffc0a805c9:35abdaa8:55fbbb60:4c, subordinatenodename=null, eis_name=java:jboss/datasources/xa_rac12g_banka >, heuristic: TwoPhaseOutcome.FINISH_OK, product: Oracle/Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production As we don't rollback the Transaction in our sample this is done by the Transaction Reaper Wildfly thread "Transaction Reaper Worker 1" oracle.jdbc.xa.client.OracleXAResource.rollback(OracleXAResource.java:945) org.jboss.jca.adapters.jdbc.xa.XAManagedConnection.rollback(XAManagedConnection.java:346) org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.rollback(XAResourceWrapperImpl.java:196) com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelAbort(XAResourceRecord.java:355) com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:2939) com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:2918) com.arjuna.ats.arjuna.coordinator.BasicAction.Abort(BasicAction.java:1632) com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.cancel(TwoPhaseCoordinator.java:116) com.arjuna.ats.arjuna.AtomicAction.cancel(AtomicAction.java:215) com.arjuna.ats.arjuna.coordinator.TransactionReaper.doCancellations(TransactionReaper.java:377) com.arjuna.ats.internal.arjuna.coordinator.ReaperWorkerThread.run(ReaperWorkerThread.java:78)
TEST 5 : Testing HTTP session Timeout
- In this test the service routine runs 5 seconds longer [ see sleep 20 s ] compared to our HTTP session limit
- When returned from our service routine the HTTP session object was already deleted
- Again The XA transaction will be rolled back by the Wildfly Transaction Reaper Worker Thread
Setup : HTTP Session Timeout : 15 seconds JTA Timeout : 30 seconds ut.setTransactionTimeout() : not active Service routine duration/sleep : 20 seconds Java Code : HttpSession session; ... session.setMaxInactiveInterval(getSessTimeout()); Wildfly Log reports : 15:55:35,839 SEVERE [javax.enterprise.resource.webcontainer.jsf.application] (default task-5) Error Rendering View[/index.xhtml]: java.lang.IllegalStateException: UT000010: Session not found Iu250lTlBLzIu_FlPHWNxq5_ at io.undertow.server.session.InMemorySessionManager$SessionImpl.getAttribute(InMemorySessionManager.java:353) [undertow-core-1.1.0.Final.jar:1.1.0.Final] at io.undertow.servlet.spec.HttpSessionImpl.getAttribute(HttpSessionImpl.java:121) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final] at com.sun.faces.context.SessionMap.get(SessionMap.java:118) [jsf-impl-2.2.8-jbossorg-1.jar:] at com.sun.faces.application.view.FaceletViewHandlingStrategy.getResponseEncoding(FaceletViewHandlingStrategy.java:1271) [jsf-impl-2.2.8-jbossorg-1.jar:] at com.sun.faces.application.view.FaceletViewHandlingStrategy.createResponseWriter(FaceletViewHandlingStrategy.java:1182) [jsf-impl-2.2.8-jbossorg-1.jar:] at com.sun.faces.application.view.FaceletViewHandlingStrategy.renderView(FaceletViewHandlingStrategy.java:403) [jsf-impl-2.2.8-jbossorg-1.jar:] at com.sun.faces.application.view.MultiViewHandler.renderView(MultiViewHandler.java:133) [jsf-impl-2.2.8-jbossorg-1.jar:] at javax.faces.application.ViewHandlerWrapper.renderView(ViewHandlerWrapper.java:337) [jboss-jsf-api_2.2_spec-2.2.8.jar:2.2.8] at javax.faces.application.ViewHandlerWrapper.renderView(ViewHandlerWrapper.java:337) [jboss-jsf-api_2.2_spec-2.2.8.jar:2.2.8] at com.sun.faces.lifecycle.RenderResponsePhase.execute(RenderResponsePhase.java:120) [jsf-impl-2.2.8-jbossorg-1.jar:] at com.sun.faces.lifecycle.Phase.doPhase(Phase.java:101) [jsf-impl-2.2.8-jbossorg-1.jar:] at com.sun.faces.lifecycle.LifecycleImpl.render(LifecycleImpl.java:219) [jsf-impl-2.2.8-jbossorg-1.jar:] at javax.faces.webapp.FacesServlet.service(FacesServlet.java:647) [jboss-jsf-api_2.2_spec-2.2.8.jar:2.2.8] at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final] Which Thread is rolling back the transaction ? Setting a breakpoint on OracleXAResource.rollback shows that the Transaction Reaper is rolling back the Transaction "Transaction Reaper Worker 2" oracle.jdbc.xa.client.OracleXAResource.rollback(OracleXAResource.java:945) org.jboss.jca.adapters.jdbc.xa.XAManagedConnection.rollback(XAManagedConnection.java:346) org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.rollback(XAResourceWrapperImpl.java:196) com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelAbort(XAResourceRecord.java:355) com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:2939) com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:2918) com.arjuna.ats.arjuna.coordinator.BasicAction.Abort(BasicAction.java:1632) com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.cancel(TwoPhaseCoordinator.java:116) com.arjuna.ats.arjuna.AtomicAction.cancel(AtomicAction.java:215) com.arjuna.ats.arjuna.coordinator.TransactionReaper.doCancellations(TransactionReaper.java:377) com.arjuna.ats.internal.arjuna.coordinator.ReaperWorkerThread.run(ReaperWorkerThread.java:78)
JAVA Test CODE
public String timeoutTest()
{
EntityManager em;
String methodName = "timeoutTest()";
UserTransaction ut =null;
cleanall();
try
{
setRunTimeInfo("Calling " + methodName + " in progress .. ");
setRunTimeInfo("Requesting Entity Manager.. ");
HttpSession session = (HttpSession) FacesContext.getCurrentInstance().getExternalContext().getSession(true);
if ( session == null)
{
throw new IllegalArgumentException(methodName+ ": Could not get HTTP session : ");
}
/*
HTTP session object is not thread safe. We need to syncronoise on session id.
For datails read : http://yet-another-dev.blogspot.de/2009/08/synchronizing-httpsession.html
*/
final Object lock = session.getId().intern();
Emp2 e = null;
long eno = -1;
synchronized(lock)
{
if ( getTestMode() == 4)
{
setSessTimeout(15);
setTxTimeout(100);
session.setMaxInactiveInterval(getSessTimeout());
setRunTimeInfo("HTTP SessionTimeout() set to: "
+ getSessTimeout() + " seconds");
}
if ( getTestMode() == 3)
{
setTxTimeout(100);
//setSessTimeout(15);
setRunTimeInfo("ut.setTransactionTimeout() set to: "
+ getTxTimeout() + " seconds");
}
if ( getTestMode() == 2)
{
setTxTimeout(20);
//setSessTimeout(15);
setRunTimeInfo("Overriding global JTA Timeout : 30 seconds with ut.setTransactionTimeout() set to: "
+ getTxTimeout() + " seconds");
}
if ( getTestMode() == 1)
{
setTxTimeout(15);
setRunTimeInfo("Overriding global JTA Timeout : 30 seconds with ut.setTransactionTimeout() set to: "
+ getTxTimeout() + " seconds");
}
if ( getTestMode() == 0)
{
setRunTimeInfo("Testing global JTA Timeout : 30 seconds");
}
// startAndSuspendSimple(session);
trackSession(session, methodName );
em=getEntityManager();
eno= getEmpno();
setRunTimeInfo("Inside " + methodName + " - Empno: " + eno + " - Thread: " + Thread.currentThread().getName());
e = em.find(Emp2.class, eno );
checkEntity(e,em);
e.setSal(e.getSal().add(increaseSalStep1) );
ut = (UserTransaction)new InitialContext().lookup("java:comp/UserTransaction");
String tx_status_before = returnTXStatus(ut);
if ( getTestMode() == 1 || getTestMode() == 2 || getTestMode() == 3 )
{
ut.setTransactionTimeout(getTxTimeout());
setRunTimeInfo("JTA Transation started with ut.setTransactionTimeout() set to : " + getTxTimeout() + " seconds");
}
ut.begin();
em.joinTransaction();
e.setSal(e.getSal().add(increaseSalStep1) );
em.merge(e);
// Update database record
em.flush();
int sleep_time = 20;
sleep(sleep_time*1000);
ut.commit();
setRunTimeInfo("Commit Called ");
String tx_status_after = returnTXStatus(ut);
setRunTimeInfo(methodName + ": em.flush() // but NO ut.commit - Before " + tx_status_before
+ " - After " + tx_status_after);
checkEntity(e,em);
setRunTimeInfo("Closing Entity Manager.. !");
closeEntityManager();
}
} catch ( Throwable t1)
{
// ut.rollback() operation is missing here !
setRunTimeInfo("FATAL ERROR in : " + methodName );
// Use Throwable as we don't want to loose any important imformation
// Note: Throwable is super class of Exception class
genericException("Error in top level function: " + methodName , (Exception)t1);
}
closeEntityManager();
setRunTimeInfo("Leaving " + methodName + " - Entity manager closed !\n");
return "index";
}