Uploaded image for project: 'Application Server 3  4  5 and 6'
  1. Application Server 3 4 5 and 6
  2. JBAS-6412

Database Exception kills delivery to message driven beans

    Details

    • Type: Bug
    • Status: Closed (View Workflow)
    • Priority: Major
    • Resolution: Done
    • Affects Version/s: JBossAS-4.0.4.GA, JBossAS-4.0.5.GA
    • Fix Version/s: None
    • Component/s: JMS (JBossMQ)
    • Labels:

      Description

      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.

        Gliffy Diagrams

          Attachments

            Activity

              People

              • Assignee:
                adrian.brock Adrian Brock
                Reporter:
                b.eckenfels Bernd Eckenfels
              • Votes:
                1 Vote for this issue
                Watchers:
                3 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: