在JBoss 5.1中的MDB(ActiveMQ)中捕获MySQL死锁

2023年9月6日 337次阅读

我们使用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,但不是我已经通过注入开始……我知道解决这个错误的唯一方法就是重新开始.

我假设最初的死锁是作为结束队列中的事务的一部分发生的,这就是为什么它不会发生在我的代码中,但是我知道一种方法可以优雅地处理这个问题吗？

更新：

>所有DataSource都是MySQL XA
>在transaction-jboss-beans.xml中,我们将transactionTimeout设置为300

最佳答案无法正常处理容器事务异常.

它决定回滚无论原因是什么,你无法控制它.获得有关此类异常和回滚事件的通知的复杂选项可能是编写JCA连接器,该连接器将虚假资源注册到每个MDB事务的分布式事务管理器中.

我建议你调查一下发生了什么,并从源头解决问题.

这是一个死锁场景,它总是涉及多个线程：如果两个代码使用相同的实体但顺序不同,则第一个线程将锁定资源A(行,表或Java监视器)并等待B当第二个线程已经锁定资源B并且现在等待A.

因此,Java监视器和数据库资源之间可能存在分布式死锁,这种情况很难诊断.整个系统一直停留,直到两端的事务超时,必须扫描Java线程转储和数据库会话和锁.

在您的情况下,由于MySQL检测到死锁本身,这意味着只涉及数据库资源.

为了提供帮助,我想你应该减少一次JMS消息(一次事务)的批量更新中运行的SQL查询的数量.在同时消耗并发消息的情况下,处理应用大量行的事务时,更可能发生死锁情况.

但奇怪的是,由于仅使用DB死锁,您的JBoss服务器在回滚后会卡住：

>要么已经耗尽了DataSource池中的JDBC连接数
>或者没有更多的MySQL服务器端连接可用
>或者所有消息bean也处于死锁状态
>事务超时可能太高,无法在合理的时间范围内获得回滚

因此,要么通过缩小相应池的大小来减少MDB并发性,要么减少每个事务的更新次数 – 甚至可能只有每个JMS消息一次更新…