title: Why did transaction rollback during stage3CommitProcessing?
body: <p>In a Java program running in two Websphere nodes the following race scenario happens in a distributed transaction managed by Websphere Transaction Manager.  The transaction spans across a JMS (Websphere-MQ) Transaction Source and a Database (Oracle) Transaction Source.  I would like to understand</p>
  
  <ul>
  <li>Why this (Exception in Thread 2, at step B6) exception happened? 
  I expected no issues to happen.  Thread 2 had proceeded only after making sure T1 is locked in Transaction TX2, so it is natural that Thread 1 was waiting for T1 table lock (within Transaction TX1) to be released.  What I'm wondering about is that why did Thread 2 encounter a stage3CommitProcessing exception?  How could I get more details about it, as the exception doesn't breathe any informtaion about it?</li>
  <li>How to debug such transaction related race scenario?  I know it might be difficult to reproduce.  But I think there could be some Websphere related logs that I could enable to see what made the commit fail during stage3?  It would be great if someone could point me in that direction.</li>
  <li>How it could be avoided/resolved?</li>
  </ul>
  
  <hr>
  
  <p><strong>Thread 1 (Running in Websphere node 1)</strong></p>
  
  <pre><code>A1: Start TX1
  A2: Read messages (maximum of 1000 at a time) from Queue Q1
  A3: LOCK TABLE T1 IN EXCLUSIVE MODE
          Got exception "ORA-02049": distributed transaction waiting for lock.  
  Refer Log 1 for stack trace
  </code></pre>
  
  <hr>
  
  <p><strong>Thread 2 (Running in Websphere node 2)</strong></p>
  
  <pre><code>B1: Start TX2
  B2: Read messages (maximum of 1000 at a time) from Queue Q1
  B3: LOCK TABLE T1 IN EXCLUSIVE MODE
  B4: Batch execute
      MERGE INTO T1 the messages read
  B5: Batch insert messages into T2
  B6: Commit TX2
      Got JTA transaction unexpectedly rolled back (maybe due to a timeout). Refer Log 2 for stack trace.  This was while ***stage3CommitProcessing***.
  </code></pre>
  
  <hr>
  
  <p><em><strong>Log 1:</em></strong></p>
  
  <p>org.springframework.jdbc.BadSqlGrammarException: StatementCallback; bad SQL grammar [LOCK TABLE T1 IN EXCLUSIVE MODE]; nested exception is java.sql.SQLSyntaxErrorException: ORA-02049: timeout: distributed transaction waiting for lock</p>
  
  <pre><code>at org.springframework.jdbc.support.SQLExceptionSubclassTranslator.doTranslate(SQLExceptionSubclassTranslator.java:94)
  at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72)
  at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:80)
  at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:406)
  at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:518)
  at org.springframework.jdbc.core.simple.SimpleJdbcTemplate.update(SimpleJdbcTemplate.java:248)
  at com.test.OracleTableLock.processMessage(OracleTableLock.java:52)
  at sun.reflect.GeneratedMethodAccessor833.invoke(Unknown Source)
  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
  at java.lang.reflect.Method.invoke(Method.java:600)
  at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:309)
  at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
  at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:110)
  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
  at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
  at $Proxy153.receiveMessage(Unknown Source)
  at com.test.BatchProcessor.processMessage(BatchProcessor.java:343)
  at sun.reflect.GeneratedMethodAccessor779.invoke(Unknown Source)
  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
  at java.lang.reflect.Method.invoke(Method.java:600)
  at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:309)
  at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
  at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:110)
  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
  at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
  at $Proxy155.receiveMessage(Unknown Source)
  at sun.reflect.GeneratedMethodAccessor778.invoke(Unknown Source)
  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
  at java.lang.reflect.Method.invoke(Method.java:600)
  at org.springframework.util.MethodInvoker.invoke(MethodInvoker.java:273)
  at org.springframework.scheduling.support.MethodInvokingRunnable.run(MethodInvokingRunnable.java:65)
  at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:51)
  at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:453)
  at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:329)
  at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:162)
  at org.springframework.scheduling.commonj.TimerManagerTaskScheduler$TimerScheduledFuture.timerExpired(TimerManagerTaskScheduler.java:112)
  at com.ibm.ws.asynchbeans.timer.TimerImpl.callListenerMethod(TimerImpl.java:298)
  at com.ibm.ws.asynchbeans.timer.GenericTimer.run(GenericTimer.java:216)
  at com.ibm.ws.asynchbeans.J2EEContext$RunProxy.run(J2EEContext.java:264)
  at java.security.AccessController.doPrivileged(AccessController.java:224)
  at javax.security.auth.Subject.doAs(Subject.java:495)
  at com.ibm.websphere.security.auth.WSSubject.doAs(WSSubject.java:131)
  at com.ibm.websphere.security.auth.WSSubject.doAs(WSSubject.java:89)
  at com.ibm.ws.asynchbeans.J2EEContext$DoAsProxy.run(J2EEContext.java:335)
  at java.security.AccessController.doPrivileged(AccessController.java:251)
  at com.ibm.ws.asynchbeans.J2EEContext.run(J2EEContext.java:1146)
  at com.ibm.ws.asynchbeans.timer.TimerImpl.runListenerAsCJWork(TimerImpl.java:425)
  at com.ibm.ws.asynchbeans.am._Alarm.fireAlarm(_Alarm.java:333)
  at com.ibm.ws.asynchbeans.am._Alarm.run(_Alarm.java:230)
  at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1550)
  Caused by: java.sql.SQLSyntaxErrorException: ORA-02049: timeout: distributed transaction waiting for lock
  
  at oracle.jdbc.driver.SQLStateMapping.newSQLException(SQLStateMapping.java:91)
  at oracle.jdbc.driver.DatabaseError.newSQLException(DatabaseError.java:133)
  at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:206)
  at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:455)
  at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:413)
  at oracle.jdbc.driver.T4C8Oall.receive(T4C8Oall.java:1034)
  at oracle.jdbc.driver.T4CStatement.doOall8(T4CStatement.java:183)
  at oracle.jdbc.driver.T4CStatement.executeForRows(T4CStatement.java:942)
  at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1222)
  at oracle.jdbc.driver.OracleStatement.executeUpdateInternal(OracleStatement.java:1706)
  at oracle.jdbc.driver.OracleStatement.executeUpdate(OracleStatement.java:1674)
  at oracle.jdbc.driver.OracleStatementWrapper.executeUpdate(OracleStatementWrapper.java:275)
  at com.ibm.ws.rsadapter.jdbc.WSJdbcStatement.pmiExecuteUpdate(WSJdbcStatement.java:1683)
  at com.ibm.ws.rsadapter.jdbc.WSJdbcStatement.executeUpdate(WSJdbcStatement.java:1041)
  at org.springframework.jdbc.core.JdbcTemplate$1UpdateStatementCallback.doInStatement(JdbcTemplate.java:508)
  at org.springframework.jdbc.core.JdbcTemplate$1UpdateStatementCallback.doInStatement(JdbcTemplate.java:1)
  at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:395)
  ... 50 more
  </code></pre>
  
  <hr>
  
  <p><em><strong>Log 2:</em></strong></p>
  
  <pre><code>org.springframework.transaction.UnexpectedRollbackException: JTA transaction unexpectedly rolled back (maybe due to a timeout); nested exception is javax.transaction.RollbackException
      at org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:1012)
      at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:754)
      at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:723)
      at com.test.BatchProcessor.processMessage(BatchProcessor.java:359)
      at sun.reflect.GeneratedMethodAccessor1541.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
      at java.lang.reflect.Method.invoke(Method.java:600)
      at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:309)
      at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
      at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
      at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:110)
      at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
      at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
      at $Proxy204.receiveMessage(Unknown Source)
      at sun.reflect.GeneratedMethodAccessor1540.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
      at java.lang.reflect.Method.invoke(Method.java:600)
      at org.springframework.util.MethodInvoker.invoke(MethodInvoker.java:273)
      at org.springframework.scheduling.support.MethodInvokingRunnable.run(MethodInvokingRunnable.java:65)
      at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:51)
      at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:453)
      at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:329)
      at java.util.concurrent.FutureTask.runAndReset(FutureTask.java)
      at org.springframework.scheduling.commonj.TimerManagerTaskScheduler$TimerScheduledFuture.timerExpired(TimerManagerTaskScheduler.java:112)
      at com.ibm.ws.asynchbeans.timer.TimerImpl.callListenerMethod(TimerImpl.java:298)
      at com.ibm.ws.asynchbeans.timer.GenericTimer.run(GenericTimer.java:216)
      at com.ibm.ws.asynchbeans.J2EEContext$RunProxy.run(J2EEContext.java:264)
      at java.security.AccessController.doPrivileged(AccessController.java:224)
      at javax.security.auth.Subject.doAs(Subject.java:495)
      at com.ibm.websphere.security.auth.WSSubject.doAs(WSSubject.java:131)
      at com.ibm.websphere.security.auth.WSSubject.doAs(WSSubject.java:89)
      at com.ibm.ws.asynchbeans.J2EEContext$DoAsProxy.run(J2EEContext.java:335)
      at java.security.AccessController.doPrivileged(AccessController.java:251)
      at com.ibm.ws.asynchbeans.J2EEContext.run(J2EEContext.java:1146)
      at com.ibm.ws.asynchbeans.timer.TimerImpl.runListenerAsCJWork(TimerImpl.java:425)
      at com.ibm.ws.asynchbeans.am._Alarm.fireAlarm(_Alarm.java:333)
      at com.ibm.ws.asynchbeans.am._Alarm.run(_Alarm.java:230)
      at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1550)
  Caused by: javax.transaction.RollbackException
      at com.ibm.tx.jta.TransactionImpl.stage3CommitProcessing(TransactionImpl.java:1217)
      at com.ibm.tx.jta.TransactionImpl.processCommit(TransactionImpl.java:991)
      at com.ibm.tx.jta.TransactionImpl.commit(TransactionImpl.java:913)
      at com.ibm.ws.tx.jta.TranManagerImpl.commit(TranManagerImpl.java:377)
      at com.ibm.tx.jta.TranManagerSet.commit(TranManagerSet.java:161)
      at com.ibm.ws.tx.jta.UserTransactionImpl.commit(UserTransactionImpl.java:293)
      at org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:1009)
      ... 37 more
  </code></pre>