Database Exception kills delivery to message driven beans

When a JDBC Exception (while sending over JVMIL) is thrown in the Persistence Manager (especially in the attached stacktrace) the JBoss Message Driven Bean (CMP) attached to the queue will stop processing messages.

This was quite hard to track down, since JDBC Exceptions (in our case Oracle 10.2) happen quite seldom. We saw sometimes XA Resource timeouts, sometimes other Exceptions. I have now enhanced the log4jdbc fake driver to randomly return JDBC Exceptions in the update Statement for JMS. This helps to trigger the problem reliable on every repeat. Here is a stacktrace of a sample Exception which kills the MDB:

2009-01-23T18:07:29.200+0100 org.jboss.mq.server.BasicQueue JMS SessionPool Worker-1
Caught unusual exception in internalAddMessage.
org.jboss.mq.SpyJMSException: Could not update message: 78 msg=25 hard STORED PERSISTENT queue=QUEUE.MCorrelatorReceiver priority=3 lateClone=false hashCode=2069264; - nested throwable: (java.sql.SQLException: this is a FAKE ERROR 1301)
at org.jboss.mq.pm.jdbc2.PersistenceManager.update(PersistenceManager.java:1350)
at org.jboss.mq.server.BasicQueue.updateRedeliveryFlags(BasicQueue.java:1212)
at org.jboss.mq.server.BasicQueue.internalAddMessage(BasicQueue.java:1131)
at org.jboss.mq.server.BasicQueue.access$000(BasicQueue.java:76)
at org.jboss.mq.server.BasicQueue$AddMessagePostCommitTask.run(BasicQueue.java:1399)
at org.jboss.mq.pm.Tx.commit(Tx.java:217)
at org.jboss.mq.pm.TxManager.commitTx(TxManager.java:159)
at org.jboss.mq.server.JMSDestinationManager.transact(JMSDestinationManager.java:518)
at org.jboss.mq.server.JMSServerInterceptorSupport.transact(JMSServerInterceptorSupport.java:126)
at org.jboss.mq.security.ServerSecurityInterceptor.transact(ServerSecurityInterceptor.java:197)
at org.jboss.mq.server.TracingInterceptor.transact(TracingInterceptor.java:352)
at org.jboss.mq.server.JMSServerInvoker.transact(JMSServerInvoker.java:132)
at org.jboss.mq.il.jvm.JVMServerIL.transact(JVMServerIL.java:175)
at org.jboss.mq.Connection.send(Connection.java:1110)
at org.jboss.mq.SpyXAResourceManager.commit(SpyXAResourceManager.java:185)
at org.jboss.mq.SpyXAResource.commit(SpyXAResource.java:88)
at org.jboss.tm.TransactionImpl$Resource.commit(TransactionImpl.java:2253)
at org.jboss.tm.TransactionImpl.commitResources(TransactionImpl.java:1784)
at org.jboss.tm.TransactionImpl.commit(TransactionImpl.java:358)
at org.jboss.tm.TxManager.commit(TxManager.java:240)
at org.jboss.jms.asf.StdServerSession.onMessage(StdServerSession.java:351)
at org.jboss.mq.SpyMessageConsumer.sessionConsumerProcessMessage(SpyMessageConsumer.java:906)
at org.jboss.mq.SpyMessageConsumer.addMessage(SpyMessageConsumer.java:170)
at org.jboss.mq.SpySession.run(SpySession.java:323)
at org.jboss.jms.asf.StdServerSession.run(StdServerSession.java:194)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:748)
at java.lang.Thread.run(Thread.java:595)
Caused by: java.sql.SQLException: this is a FAKE ERROR 1301
at net.sf.log4jdbc.PreparedStatementSpy.executeUpdate(PreparedStatementSpy.java:1002)
at org.jboss.resource.adapter.jdbc.WrappedPreparedStatement.executeUpdate(WrappedPreparedStatement.java:251)
at org.jboss.mq.pm.jdbc2.PersistenceManager.update(PersistenceManager.java:1329)
... 26 more

In this above case, it happend in the deliver path, but the same stuck problem also happens in this case (Thread is calling a Session Bean which is sending a JMS Message):

2009-01-23T18:07:20.091+0100 org.jboss.mq.server.BasicQueue SeeHFWorker0-PORT_01
Caught unusual exception in internalAddMessage.
org.jboss.mq.SpyJMSException: Could not update message: 37 msg=12 hard STORED PERSISTENT queue=QUEUE.MRestartPointReceiver priority=4 lateClone=false hashCode=3819916; - nested throwable: (java.sql.SQLException: this is a FAKE ERROR 1001)
at org.jboss.mq.pm.jdbc2.PersistenceManager.update(PersistenceManager.java:1350)
at org.jboss.mq.server.BasicQueue.updateRedeliveryFlags(BasicQueue.java:1212)
at org.jboss.mq.server.BasicQueue.internalAddMessage(BasicQueue.java:1131)
at org.jboss.mq.server.BasicQueue.access$000(BasicQueue.java:76)
at org.jboss.mq.server.BasicQueue$AddMessagePostCommitTask.run(BasicQueue.java:1399)
at org.jboss.mq.pm.TxManager.addPostCommitTask(TxManager.java:174)
at org.jboss.mq.server.BasicQueue.performOrPrepareAddMessage(BasicQueue.java:419)
at org.jboss.mq.server.BasicQueue.addMessage(BasicQueue.java:391)
at org.jboss.mq.server.PersistentQueue.addMessage(PersistentQueue.java:76)
at org.jboss.mq.server.JMSQueue.addMessage(JMSQueue.java:180)
at org.jboss.mq.server.JMSDestinationManager.addMessage(JMSDestinationManager.java:439)
at org.jboss.mq.server.JMSDestinationManager.addMessage(JMSDestinationManager.java:422)
at org.jboss.mq.server.JMSServerInterceptorSupport.addMessage(JMSServerInterceptorSupport.java:106)
at org.jboss.mq.security.ServerSecurityInterceptor.addMessage(ServerSecurityInterceptor.java:168)
at org.jboss.mq.server.TracingInterceptor.addMessage(TracingInterceptor.java:226)
at org.jboss.mq.server.JMSServerInvoker.addMessage(JMSServerInvoker.java:112)
at org.jboss.mq.il.jvm.JVMServerIL.addMessage(JVMServerIL.java:101)
at org.jboss.mq.Connection.sendToServer(Connection.java:918)
at org.jboss.mq.SpySession.sendMessage(SpySession.java:924)
at org.jboss.mq.SpyMessageProducer.send(SpyMessageProducer.java:272)
at org.jboss.mq.SpyMessageProducer.send(SpyMessageProducer.java:206)
at com.seeburger.engine.managers.impl.RestartPointManager.createRestartPoint(RestartPointManager.java:977)
...
at com.seeburger.engine.BusinessProcessEngineBase.createRestartPoint(BusinessProcessEngineBase.java:493)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.jboss.invocation.Invocation.performCall(Invocation.java:359)
at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:237)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:158)
at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:169)
at org.jboss.ws.server.ServiceEndpointInterceptor.invoke(ServiceEndpointInterceptor.java:39)
at org.jboss.ejb.plugins.CallValidationInterceptor.invoke(CallValidationInterceptor.java:63)
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:121)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:350)
at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:181)
at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:168)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:205)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:136)
at org.jboss.ejb.SessionContainer.internalInvoke(SessionContainer.java:648)
at org.jboss.ejb.Container.invoke(Container.java:954)
at sun.reflect.GeneratedMethodAccessor116.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
at org.jboss.invocation.local.LocalInvoker$MBeanServerAction.invoke(LocalInvoker.java:169)
at org.jboss.invocation.local.LocalInvoker.invoke(LocalInvoker.java:118)
at org.jboss.invocation.InvokerInterceptor.invokeLocal(InvokerInterceptor.java:209)
at org.jboss.invocation.InvokerInterceptor.invoke(InvokerInterceptor.java:195)
at org.jboss.proxy.TransactionInterceptor.invoke(TransactionInterceptor.java:61)
at org.jboss.proxy.SecurityInterceptor.invoke(SecurityInterceptor.java:70)
at org.jboss.proxy.ejb.StatelessSessionInterceptor.invoke(StatelessSessionInterceptor.java:112)
at org.jboss.proxy.ClientContainer.invoke(ClientContainer.java:100)
at $Proxy476.createRestartPoint(Unknown Source)
...
at com.seeburger.hotfolder.service.FolderWorker.run(FolderWorker.java:387)
at java.lang.Thread.run(Thread.java:595)
Caused by: java.sql.SQLException: this is a FAKE ERROR 1001
at net.sf.log4jdbc.StatementSpy._reportSql(StatementSpy.java:311)
at net.sf.log4jdbc.StatementSpy.reportSql(StatementSpy.java:300)
at net.sf.log4jdbc.PreparedStatementSpy.executeUpdate(PreparedStatementSpy.java:1002)
at org.jboss.resource.adapter.jdbc.WrappedPreparedStatement.executeUpdate(WrappedPreparedStatement.java:251)
at org.jboss.mq.pm.jdbc2.PersistenceManager.update(PersistenceManager.java:1329)
... 67 more

Note that in this case the dequeueing was broken (i.e. if i sent new messages to the Queue they will stay there).

We have been investing quitew some time understanding the relationships between the various components, but the only thing we found out is, that the "addInternalMessage" in basic queue "thinks" there is no receiver in the receivers list.