Database Exception kills delivery to message driven beans --------------------------------------------------------- Key: JBAS-6412 URL: https://jira.jboss.org/jira/browse/JBAS-6412 Project: JBoss Application Server Issue Type: Bug Security Level: Public (Everyone can see) Components: JMS (JBoss Messaging) Affects Versions: JBossAS-4.0.5.GA, JBossAS-4.0.4.GA Environment: JBoss 405GA on Windows, Linux, HP/UX or AIX with JAva 5 or Java 6 Reporter: Bernd Eckenfels Assignee: Clebert Suconic 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. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: https://jira.jboss.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira