activemq-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Jeremy Levy <jel...@gmail.com>
Subject Unable to catch some exceptions in ActiveMQ MDB
Date Thu, 21 Jun 2012 22:45:41 GMT
We are using JBoss 5.1 w/ MDB backed by ActiveMQ RAR.  When a message on a
queue is consumed and performs some database operations which then result
in a deadlock, the deadlock is essentially hosing the entire instance of
JBoss until it is restarted. By hosed, any subsequent messages consumed on
that queue all fail with the follow exception:

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

The deadlock exception never references my code, which in turn make it very
difficult for me to catch and handle.

See sample exception at the bottom of this message...

On subsequent messages to the queue I'm able to catch the GenericJDBCException:
Cannot open connection, but I'm not even sure what to do with it, maybe I
can get a new EntityManager that isn't hosed, but I'm getting via Injection
to begin with... The only way I know to fix this error is to restart.

I assume that the initial Deadlock is happening as part of ending the
transaction in the Queue which is why it's not happening in my code, but
does any idea of a way I can handle this gracefully?

Thanks.

----

    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@10015060context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@4643d6d5xaResource=org.jboss.resource.adapter.jdbc.xa.XAManagedConnection@2c9e906txSync=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

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message