4

我们正在使用由 ActiveMQ RAR 支持的带有 MDB 的 JBoss 5.1。

当队列上的消息被消耗并执行一些数据库操作，然后导致死锁时，死锁本质上是占用整个 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，但我是通过注入开始的......我知道解决这个错误的唯一方法是重新开始。

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

更新：

  • 所有数据源都是 MySQL XA
  • 在 transaction-jboss-beans.xml 中，我们将 transactionTimeout 设置为 300
4

2 回答 2

1

我能够通过使用以下方法隔离每个事务来解决此问题：

使用以下命令注释 MDB：

    @TransactionManagement(value = TransactionManagementType.BEAN)

因此告诉 MDB Bean 本身将管理事务而不是容器（在我的代码之外），接下来，注入必要的资源：

    @Resource
    MessageDrivenContext mc;
    UserTransaction tx;

创建和管理我自己的交易

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

    //Do work

    tx.commit();

可以对每个代码块重复上述步骤。

使用非常精细的事务，我能够跟踪我的代码中发生锁定/竞争条件的位置。一旦我解决了这个问题，我就能够退出一些更精细的事务管理。

于 2012-10-12T15:40:11.323 回答
1

没有办法优雅地处理容器事务异常。

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

我建议您调查发生的情况并从源头解决问题。

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

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

在您的情况下，当 MySQL 检测到死锁本身时，这意味着只涉及数据库资源。

为了提供帮助，我想您应该减少在批量更新中针对一条 JMS 消息、一项事务运行的 SQL 查询的数量。在同时消费并发消息的情况下，处理应用大量行的事务，更容易出现死锁情况。

但奇怪的是，您的 JBoss 服务器在回滚后由于仅 DB 的死锁而被卡住：

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

因此，要么通过缩小相应池的大小来减少 MDB 并发，要么减少每个事务的更新数量——甚至可能小到每个 JMS 消息一个更新......

于 2012-06-25T15:52:45.370 回答