Почему откат транзакции во время stage3CommitProcessing? - PullRequest
Новая
       22

Почему откат транзакции во время stage3CommitProcessing?

3 голосов
/ 10 августа 2011

В Java-программе, работающей на двух узлах Websphere, следующий сценарий гонки происходит в распределенной транзакции, управляемой Websphere Transaction Manager.Транзакция охватывает источник транзакций JMS (Websphere-MQ) и источник транзакций базы данных (Oracle).Я хотел бы понять,

  • Почему произошло это исключение (исключение в потоке 2, на этапе B6)?Я не ожидал никаких проблем.Поток 2 продолжился только после того, как убедился, что T1 заблокирован в транзакции TX2, поэтому естественно, что поток 1 ожидал снятия блокировки таблицы T1 (в транзакции TX1).Что меня интересует, так это то, почему в Thread 2 возникла исключительная ситуация stage3CommitProcessing?Как я могу получить более подробную информацию об этом, поскольку исключение не затрагивает никакой информации об этом?
  • Как отладить такой сценарий гонки, связанный с транзакцией?Я знаю, что это может быть трудно воспроизвести.Но я думаю, что могут быть какие-то связанные с Websphere журналы, которые я мог бы разрешить, чтобы увидеть, что привело к сбою фиксации во время stage3?Было бы замечательно, если бы кто-то мог указать мне в этом направлении.
  • Как этого можно избежать / разрешить?

Поток 1 (работает в узле Websphere 1) 

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

Поток 2 (работает в узле Websphere 2) 

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***.

Журнал1:

org.springframework.jdbc.BadSqlGrammarException: StatementCallback;плохая грамматика SQL [LOCK TABLE T1 В ЭКСКЛЮЗИВНОМ РЕЖИМЕ];вложенное исключение: java.sql.SQLSyntaxErrorException: ORA-02049: время ожидания: распределенная транзакция ожидает блокировки 

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

Журнал 2: 

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

1 Ответ

1 голос
/ 06 апреля 2014

Предполагая, что это проблема с ресурсами WebSphere MQ, давайте попробуем ответить на ваши вопросы по очереди.

Почему произошло это исключение (исключение в потоке 2, на этапе B6)?
Почему в потоке 2 возникла исключительная ситуация stage3CommitProcessing?
Как я могу получить более подробную информацию об этом?

Скорее всего, соответствующий QMgr не был сконфигурирован с достаточным пространством для журнала, чтобы содержать все сообщения, которые находятся под синхронизацией. Несмотря на то, что вы позаботились о сериализации доступа к базе данных, очередь не сериализуется, и поэтому QMgr должен одновременно управлять до 2000 записями в точке синхронизации. Более подробная информация доступна в журнале ошибок QMgr.

Как отладить такой сценарий гонки, связанный с транзакцией?
Существуют ли журналы, связанные с Websphere, которые я мог бы включить, чтобы увидеть, что привело к сбою фиксации на этапе 3?

Посмотрите в /var/mqm/qmgrs/[QMgr name]/errors/AMQERR01.log подробности о том, был ли WebSphere MQ откатывать транзакцию.

Также распечатайте связанные исключения JMS. Всегда. JMS предоставляет многоуровневое исключение, где нижние уровни содержат информацию об ошибках, связанных с поставщиком. Часто они передают приложению ту же информацию, которую в противном случае вам пришлось бы копать в журналах ошибок QMgr.

Если я правильно понял причину проблемы, самый простой способ проверить это - два экземпляра попытаться прочитать 100 записей в каждой из них в точке синхронизации.

Как этого можно избежать / решить?

Увеличьте размер журналов, чтобы они могли содержать все сообщения, которые могут быть синхронизированы в любой данный момент. Например, если каждое сообщение имеет размер 1 КБ и вам нужно 1000 из них в точке синхронизации для каждого из 10 экземпляров, вам потребуется как минимум около 10 МБ экстентов журнала. Они определяются параметрами основного и дополнительного журнала QMgr и параметрами счета. Помните, что QMgr также поддерживает точки синхронизации, например, при управлении каналами, и поэтому в любом вычисляемом пространстве необходимо учитывать размеры пакета канала и несколько МБ для внутренних транзакций QMgr.

Подробнее см. Раздел в Инфоцентре по расчетам размера файла журнала . Дополнительную информацию смотрите в Циркулярные и линейные журналы в IBM developerWorks.

...