Захват MySQL Deadlock в MDB (ActiveMQ) в JBoss 5.1

Question

Мы используем JBoss 5.1 w/MDB, поддерживаемый ActiveMQ RAR.

Когда сообщение в очереди расходуется и выполняет некоторые операции с базой данных, которые затем приводят к тупиковой ситуации, тупик по существу швыряет весь экземпляр JBoss до его перезапуска. По обливали, все последующие сообщения, потребляемые на этой очереди все завершаться за исключением последующих:

Caused by: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: Cannot open connection 

Исключение тупиковый никогда не ссылается мой код, который, в свою очередь, сделать это очень трудно для меня, чтобы перехватывать и обрабатывать.

Например, вот исключение из исключения тупиковой:

2012-06-18 18:52:19,848 WARN [JDBCExceptionReporter] : SQL Error: 1213, SQLState: 40001 
2012-06-18 18:52:19,848 ERROR [JDBCExceptionReporter] : Deadlock found when trying to get lock; try restarting transaction 
2012-06-18 18:52:19,850 ERROR [AbstractFlushingEventListener] : Could not synchronize database state with session 
org.hibernate.exception.LockAcquisitionException: Could not execute JDBC batch update 
     at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:105) 
     at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66) 
     at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:275) 
     at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:266) 
     at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:168) 
     at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321) 
     at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:50) 
     at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1027) 
     at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:365) 
     at org.hibernate.ejb.AbstractEntityManagerImpl$1.beforeCompletion(AbstractEntityManagerImpl.java:504) 
     at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:101) 
     at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:269) 
     at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:89) 
     at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:177) 
     at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1423) 
     at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:137) 
     at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75) 
     at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.endTransaction(MessageInflowLocalProxy.java:435) 
     at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.finish(MessageInflowLocalProxy.java:314) 
     at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.after(MessageInflowLocalProxy.java:230) 
     at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.invoke(MessageInflowLocalProxy.java:136) 
     at $Proxy677.afterDelivery(Unknown Source) 
     at org.apache.activemq.ra.MessageEndpointProxy$MessageEndpointAlive.afterDelivery(MessageEndpointProxy.java:128) 
     at org.apache.activemq.ra.MessageEndpointProxy.afterDelivery(MessageEndpointProxy.java:69) 
     at org.apache.activemq.ra.ServerSessionImpl.afterDelivery(ServerSessionImpl.java:224) 
     at org.apache.activemq.ActiveMQSession.run(ActiveMQSession.java:897) 
     at org.apache.activemq.ra.ServerSessionImpl.run(ServerSessionImpl.java:169) 
     at org.jboss.resource.work.WorkWrapper.execute(WorkWrapper.java:205) 
     at org.jboss.util.threadpool.BasicTaskWrapper.run(BasicTaskWrapper.java:260) 
     at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) 
     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) 
     at java.lang.Thread.run(Thread.java:619) 
Caused by: java.sql.BatchUpdateException: Deadlock found when trying to get lock; try restarting transaction 
     at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:2013) 
     at com.mysql.jdbc.PreparedStatement.executeBatch(PreparedStatement.java:1449) 
     at com.mysql.jdbc.jdbc2.optional.StatementWrapper.executeBatch(StatementWrapper.java:721) 
     at org.jboss.resource.adapter.jdbc.WrappedStatement.executeBatch(WrappedStatement.java:774) 
     at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:70) 
     at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:268) 
     ... 29 more 
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction 
     at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) 
     at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39) 
     at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27) 
     at java.lang.reflect.Constructor.newInstance(Constructor.java:513) 
     at com.mysql.jdbc.Util.handleNewInstance(Util.java:407) 
     at com.mysql.jdbc.Util.getInstance(Util.java:382) 
     at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1064) 
     at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3603) 
     at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3535) 
     at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1989) 
     at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2150) 
     at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2626) 
     at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2119) 
     at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2415) 
     at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:1976) 
     ... 34 more 
2012-06-18 18:52:19,851 WARN [arjLoggerI18N] : [com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator_2] TwoPhaseCoordinator.beforeCompletion - failed for com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple@480671ab 
javax.persistence.PersistenceException: org.hibernate.exception.LockAcquisitionException: Could not execute JDBC batch update 
     at org.hibernate.ejb.AbstractEntityManagerImpl.throwPersistenceException(AbstractEntityManagerImpl.java:614) 
     at org.hibernate.ejb.AbstractEntityManagerImpl$1.beforeCompletion(AbstractEntityManagerImpl.java:513) 
     at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:101) 
     at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:269) 
     at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:89) 
     at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:177) 
     at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1423) 
     at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:137) 
     at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75) 
     at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.endTransaction(MessageInflowLocalProxy.java:435) 
     at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.finish(MessageInflowLocalProxy.java:314) 
     at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.after(MessageInflowLocalProxy.java:230) 
     at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.invoke(MessageInflowLocalProxy.java:136) 
     at $Proxy677.afterDelivery(Unknown Source) 
     at org.apache.activemq.ra.MessageEndpointProxy$MessageEndpointAlive.afterDelivery(MessageEndpointProxy.java:128) 
     at org.apache.activemq.ra.MessageEndpointProxy.afterDelivery(MessageEndpointProxy.java:69) 
     at org.apache.activemq.ra.ServerSessionImpl.afterDelivery(ServerSessionImpl.java:224) 
     at org.apache.activemq.ActiveMQSession.run(ActiveMQSession.java:897) 
     at org.apache.activemq.ra.ServerSessionImpl.run(ServerSessionImpl.java:169) 
     at org.jboss.resource.work.WorkWrapper.execute(WorkWrapper.java:205) 
     at org.jboss.util.threadpool.BasicTaskWrapper.run(BasicTaskWrapper.java:260) 
     at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) 
     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) 
     at java.lang.Thread.run(Thread.java:619) 
Caused by: org.hibernate.exception.LockAcquisitionException: Could not execute JDBC batch update 
     at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:105) 
     at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66) 
     at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:275) 
     at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:266) 
     at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:168) 
     at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321) 
     at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:50) 
     at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1027) 
     at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:365) 
     at org.hibernate.ejb.AbstractEntityManagerImpl$1.beforeCompletion(AbstractEntityManagerImpl.java:504) 
     ... 22 more 
Caused by: java.sql.BatchUpdateException: Deadlock found when trying to get lock; try restarting transaction 
     at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:2013) 
     at com.mysql.jdbc.PreparedStatement.executeBatch(PreparedStatement.java:1449) 
     at com.mysql.jdbc.jdbc2.optional.StatementWrapper.executeBatch(StatementWrapper.java:721) 
     at org.jboss.resource.adapter.jdbc.WrappedStatement.executeBatch(WrappedStatement.java:774) 
     at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:70) 
     at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:268) 
     ... 29 more 
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction 
     at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) 
     at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39) 
       at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27) 
     at java.lang.reflect.Constructor.newInstance(Constructor.java:513) 
     at com.mysql.jdbc.Util.handleNewInstance(Util.java:407) 
     at com.mysql.jdbc.Util.getInstance(Util.java:382) 
     at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1064) 
     at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3603) 
     at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3535) 
     at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1989) 
     at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2150) 
     at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2626) 
     at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2119) 
     at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2415) 
     at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:1976) 
     ... 34 more 
2012-06-18 18:52:19,912 WARN [TxConnectionManager] : Connection error occured: org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@6acc2da9[state=NORMAL mc=org.jboss.resource.adapter.jdbc.xa.XAManagedConnection@2c9e906 handles=0 lastUse=1340059939649 permit=true trackByTx=true mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@10015060 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@4643d6d5 xaResource=org.jboss.resource.adapter.jdbc.xa.XAManagedConnection@2c9e906 txSync=null] 
com.mysql.jdbc.jdbc2.optional.MysqlXAException: XA_RBDEADLOCK: Transaction branch was rolled back: deadlock was detected 
     at com.mysql.jdbc.jdbc2.optional.MysqlXAConnection.mapXAExceptionFromSQLException(MysqlXAConnection.java:605) 
     at com.mysql.jdbc.jdbc2.optional.MysqlXAConnection.dispatchCommand(MysqlXAConnection.java:584) 
     at com.mysql.jdbc.jdbc2.optional.MysqlXAConnection.end(MysqlXAConnection.java:479) 
     at org.jboss.resource.adapter.jdbc.xa.XAManagedConnection.end(XAManagedConnection.java:246) 
     at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelAbort(XAResourceRecord.java:396) 
     at com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:3270) 
     at com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:3248) 
     at com.arjuna.ats.arjuna.coordinator.BasicAction.Abort(BasicAction.java:1933) 
     at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:97) 
     at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:177) 
     at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1423) 
     at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:137) 
     at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75) 
     at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.endTransaction(MessageInflowLocalProxy.java:435) 
     at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.finish(MessageInflowLocalProxy.java:314) 
     at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.after(MessageInflowLocalProxy.java:230) 
     at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.invoke(MessageInflowLocalProxy.java:136) 
     at $Proxy677.afterDelivery(Unknown Source) 
     at org.apache.activemq.ra.MessageEndpointProxy$MessageEndpointAlive.afterDelivery(MessageEndpointProxy.java:128) 
     at org.apache.activemq.ra.MessageEndpointProxy.afterDelivery(MessageEndpointProxy.java:69) 
     at org.apache.activemq.ra.ServerSessionImpl.afterDelivery(ServerSessionImpl.java:224) 
     at org.apache.activemq.ActiveMQSession.run(ActiveMQSession.java:897) 
     at org.apache.activemq.ra.ServerSessionImpl.run(ServerSessionImpl.java:169) 
     at org.jboss.resource.work.WorkWrapper.execute(WorkWrapper.java:205) 
     at org.jboss.util.threadpool.BasicTaskWrapper.run(BasicTaskWrapper.java:260) 
     at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) 
     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) 
     at java.lang.Thread.run(Thread.java:619) 
2012-06-18 18:52:19,914 INFO [ServerSessionImpl:153] : Endpoint failed to process message. Reason: Endpoint after delivery notification failure 

я могу поймать последующие ошибки (ошибки на последующих сообщений в очереди):

Вызванные: javax.persistence .PersistenceException: org.hibernate.exception.GenericJDBCException: не удается открыть соединение

Но я даже не уверен, что с ним делать, может быть, я могу получить новый EntityManager, который не был взволнован, но я получаю через Инъекция для начала ... Единственная я знаю, чтобы исправить эту ошибку, чтобы перезапустить.

Я предполагаю, что начальный тупик происходит как часть завершения транзакции в очереди, поэтому это не происходит в моем коде, но есть ли какие-либо идеи о том, как я могу справиться с этим изящно?

Update:

• Все DataSources являются MySQL ХА
• В транзакции-JBoss-beans.xml мы имеем transactionTimeout набор 300

Answer 1

Я был в состоянии решить эту проблему изолируя каждую транзакцию, используя следующий метод:

аннотировать MDB с:

@TransactionManagement(value = TransactionManagementType.BEAN) 

Таким образом, говорящее MDB, что сама Bean будет управлять сделку, а не контейнер (за пределами моего кода), затем, вводить необходимые сары ресурсы:

@Resource 
    MessageDrivenContext mc; 
    UserTransaction tx; 

Чтобы создать и управлять своими собственными транзакциями

tx = mc.getUserTransaction(); 
    tx.begin(); 

    //Do work 

    tx.commit(); 

выше шаг можно повторить для каждого блока кода.

Используя очень гранулированные транзакции, я смог проследить, где в моем коде произошло состояние блокировки/гонки. Как только я решил, что мне удалось отменить некоторые из более гранулированных операций управления.

Answer 2

Там нет никакого способа для обработки исключений контейнером транзакции грациозно ,

Он решает откат независимо от причины, и у вас нет контроля над ним. Сложным вариантом получения уведомлений о таких исключениях и событиях отката может быть запись JCA-коннектора, который регистрирует поддельные ресурсы в диспетчере распределенных транзакций для каждой транзакции MDB.

Я бы порекомендовал вам изучить, что происходит, и устранить проблему из своего источника.

Вот сценарий мертвой блокировки, он всегда включает несколько потоков: если два фрагмента кода используют одни и те же объекты, но в другом порядке, первый поток блокирует ресурс A (строка, таблица или монитор Java) и ждать B, когда второй поток уже заблокировал ресурс B и теперь ждет A.

Таким образом, распределенная мертвая блокировка возможна между мониторами Java и ресурсами базы данных, и этот случай является сложным для диагностики. Полная система застревает до тех пор, пока не будут проверены таймауты транзакций на обоих концах, скачки потоков Java и сеансы базы данных и блокировки.

В вашем случае, поскольку MySQL обнаруживает сам dead-lock, это означает, что задействованы только ресурсы базы данных.

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

Но странно, что ваш сервер JBoss застрял после отката из-БД-только тупиковой:

• либо вы исчерпали количество JDBC соединений из DataSource бассейна
• или там не более MySQL соединения на стороне серверов доступны
• или все бобы сообщения находятся в тупиковой ситуации тоже
• тайм-аут транзакции может быть слишком высоким, чтобы получить откаты в разумных сроках

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