13 Replies Latest reply on May 18, 2011 10:40 AM by Christian Strempfer

    Calling stopDelivery causes a

    Philip Dodds Newbie

      I am currently running a JBoss 5.0.1GA with an updated EJB3 container (1.1.4). I upgraded the container so that I could use the stopDelivery/startDelivery functionality on the MDB's.

      When we call stopDelivery and startDelivery through JMX they do seem to function as expected, however on the stopDelivery we get

      15:28:07,069 ERROR [ExceptionUtil] ConnectionEndpoint[s73-tbaaa1vf-1-j8ot91vf-maz9g4-b1r27p4] sendTransaction [hc3-17yaa1vf-1-j8ot91vf-maz9g4-b1r27p4]
      javax.jms.IllegalStateException: Cannot find session with id v73-vbaaa1vf-1-j8ot91vf-maz9g4-b1r27p4
       at org.jboss.jms.server.endpoint.ServerConnectionEndpoint.processTransaction(ServerConnectionEndpoint.java:835)
       at org.jboss.jms.server.endpoint.ServerConnectionEndpoint.sendTransaction(ServerConnectionEndpoint.java:489)
       at org.jboss.jms.server.endpoint.advised.ConnectionAdvised.org$jboss$jms$server$endpoint$advised$ConnectionAdvised$sendTransaction$aop(ConnectionAdvised.java:101)
       at org.jboss.jms.server.endpoint.advised.ConnectionAdvised$sendTransaction_N3268650789275322226.invokeTarget(ConnectionAdvised$sendTransaction_N3268650789275322226.java)
       at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:111)
       at org.jboss.jms.server.container.SecurityAspect.handleSendTransaction(SecurityAspect.java:195)
       at sun.reflect.GeneratedMethodAccessor502.invoke(Unknown Source)
       at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
       at java.lang.reflect.Method.invoke(Method.java:585)
       at org.jboss.aop.advice.PerInstanceAdvice.invoke(PerInstanceAdvice.java:122)
       at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
       at org.jboss.jms.server.container.ServerLogInterceptor.invoke(ServerLogInterceptor.java:105)
       at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
       at org.jboss.jms.server.endpoint.advised.ConnectionAdvised.sendTransaction(ConnectionAdvised.java)
       at org.jboss.jms.wireformat.ConnectionSendTransactionRequest.serverInvoke(ConnectionSendTransactionRequest.java:82)
       at org.jboss.jms.server.remoting.JMSServerInvocationHandler.invoke(JMSServerInvocationHandler.java:143)
       at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:908)
       at org.jboss.remoting.transport.local.LocalClientInvoker.invoke(LocalClientInvoker.java:106)
       at org.jboss.remoting.Client.invoke(Client.java:1708)
       at org.jboss.remoting.Client.invoke(Client.java:612)
       at org.jboss.remoting.Client.invoke(Client.java:600)
       at org.jboss.jms.client.delegate.DelegateSupport.doInvoke(DelegateSupport.java:189)
       at org.jboss.jms.client.delegate.DelegateSupport.doInvoke(DelegateSupport.java:160)
       at org.jboss.jms.client.delegate.ClientConnectionDelegate.org$jboss$jms$client$delegate$ClientConnectionDelegate$sendTransaction$aop(ClientConnectionDelegate.java:221)
       at org.jboss.jms.client.delegate.ClientConnectionDelegate$sendTransaction_N3268650789275322226.invokeTarget(ClientConnectionDelegate$sendTransaction_N3268650789275322226.java)
       at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:111)
       at org.jboss.jms.client.container.FailoverValveInterceptor.invoke(FailoverValveInterceptor.java:92)
       at org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:86)
       at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
       at org.jboss.jms.client.container.ClosedInterceptor.invoke(ClosedInterceptor.java:170)
       at org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:86)
       at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
       at org.jboss.jms.client.delegate.ClientConnectionDelegate.sendTransaction(ClientConnectionDelegate.java)
       at org.jboss.jms.tx.ResourceManager.sendTransactionXA(ResourceManager.java:662)
       at org.jboss.jms.tx.ResourceManager.commit(ResourceManager.java:367)
       at org.jboss.jms.tx.MessagingXAResource.commit(MessagingXAResource.java:254)
       at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelOnePhaseCommit(XAResourceRecord.java:800)
       at com.arjuna.ats.arjuna.coordinator.BasicAction.onePhaseCommit(BasicAction.java:2639)
       at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1784)
       at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:88)
       at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:177)
       at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1414)
       at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:135)
       at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
       at org.jboss.resource.adapter.jms.inflow.JmsServerSession$XATransactionDemarcationStrategy.end(JmsServerSession.java:657)
       at org.jboss.resource.adapter.jms.inflow.JmsServerSession.run(JmsServerSession.java:243)
       at org.jboss.resource.work.WorkWrapper.execute(WorkWrapper.java:213)
       at org.jboss.util.threadpool.BasicTaskWrapper.run(BasicTaskWrapper.java:260)
       at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
       at java.lang.Thread.run(Thread.java:613)
      15:28:07,070 ERROR [JmsServerSession] org.jboss.resource.adapter.jms.inflow.JmsServerSession@458998 failed to commit/rollback
      javax.transaction.RollbackException: [com.arjuna.ats.internal.jta.transaction.arjunacore.commitwhenaborted] [com.arjuna.ats.internal.jta.transaction.arjunacore.commitwhenaborted] Could not commit transaction.
       at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1426)
       at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:135)
       at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
       at org.jboss.resource.adapter.jms.inflow.JmsServerSession$XATransactionDemarcationStrategy.end(JmsServerSession.java:657)
       at org.jboss.resource.adapter.jms.inflow.JmsServerSession.run(JmsServerSession.java:243)
       at org.jboss.resource.work.WorkWrapper.execute(WorkWrapper.java:213)
       at org.jboss.util.threadpool.BasicTaskWrapper.run(BasicTaskWrapper.java:260)
       at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
       at java.lang.Thread.run(Thread.java:613)
      15:28:14,263 ERROR [ExceptionUtil] ConnectionEndpoint[s73-tbaaa1vf-1-j8ot91vf-maz9g4-b1r27p4] sendTransaction [gd3-vq3ba1vf-1-j8ot91vf-maz9g4-b1r27p4]
      javax.jms.IllegalStateException: Cannot find session with id v73-vbaaa1vf-1-j8ot91vf-maz9g4-b1r27p4
       at org.jboss.jms.server.endpoint.ServerConnectionEndpoint.processTransaction(ServerConnectionEndpoint.java:835)
       at org.jboss.jms.server.endpoint.ServerConnectionEndpoint.sendTransaction(ServerConnectionEndpoint.java:489)
       at org.jboss.jms.server.endpoint.advised.ConnectionAdvised.org$jboss$jms$server$endpoint$advised$ConnectionAdvised$sendTransaction$aop(ConnectionAdvised.java:101)
       at org.jboss.jms.server.endpoint.advised.ConnectionAdvised$sendTransaction_N3268650789275322226.invokeTarget(ConnectionAdvised$sendTransaction_N3268650789275322226.java)
       at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:111)
       at org.jboss.jms.server.container.SecurityAspect.handleSendTransaction(SecurityAspect.java:195)
       at sun.reflect.GeneratedMethodAccessor502.invoke(Unknown Source)
       at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
       at java.lang.reflect.Method.invoke(Method.java:585)
       at org.jboss.aop.advice.PerInstanceAdvice.invoke(PerInstanceAdvice.java:122)
       at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
       at org.jboss.jms.server.container.ServerLogInterceptor.invoke(ServerLogInterceptor.java:105)
       at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
       at org.jboss.jms.server.endpoint.advised.ConnectionAdvised.sendTransaction(ConnectionAdvised.java)
       at org.jboss.jms.wireformat.ConnectionSendTransactionRequest.serverInvoke(ConnectionSendTransactionRequest.java:82)
       at org.jboss.jms.server.remoting.JMSServerInvocationHandler.invoke(JMSServerInvocationHandler.java:143)
       at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:908)
       at org.jboss.remoting.transport.local.LocalClientInvoker.invoke(LocalClientInvoker.java:106)
       at org.jboss.remoting.Client.invoke(Client.java:1708)
       at org.jboss.remoting.Client.invoke(Client.java:612)
       at org.jboss.remoting.Client.invoke(Client.java:600)
       at org.jboss.jms.client.delegate.DelegateSupport.doInvoke(DelegateSupport.java:189)
       at org.jboss.jms.client.delegate.DelegateSupport.doInvoke(DelegateSupport.java:160)
       at org.jboss.jms.client.delegate.ClientConnectionDelegate.org$jboss$jms$client$delegate$ClientConnectionDelegate$sendTransaction$aop(ClientConnectionDelegate.java:221)
       at org.jboss.jms.client.delegate.ClientConnectionDelegate$sendTransaction_N3268650789275322226.invokeTarget(ClientConnectionDelegate$sendTransaction_N3268650789275322226.java)
       at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:111)
       at org.jboss.jms.client.container.FailoverValveInterceptor.invoke(FailoverValveInterceptor.java:92)
       at org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:86)
       at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
       at org.jboss.jms.client.container.ClosedInterceptor.invoke(ClosedInterceptor.java:170)
       at org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:86)
       at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
       at org.jboss.jms.client.delegate.ClientConnectionDelegate.sendTransaction(ClientConnectionDelegate.java)
       at org.jboss.jms.tx.ResourceManager.sendTransactionXA(ResourceManager.java:662)
       at org.jboss.jms.tx.ResourceManager.commit(ResourceManager.java:367)
       at org.jboss.jms.tx.MessagingXAResource.commit(MessagingXAResource.java:254)
       at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelOnePhaseCommit(XAResourceRecord.java:800)
       at com.arjuna.ats.arjuna.coordinator.BasicAction.onePhaseCommit(BasicAction.java:2639)
       at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1784)
       at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:88)
       at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:177)
       at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1414)
       at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:135)
       at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
       at org.jboss.resource.adapter.jms.inflow.JmsServerSession$XATransactionDemarcationStrategy.end(JmsServerSession.java:657)
       at org.jboss.resource.adapter.jms.inflow.JmsServerSession.run(JmsServerSession.java:243)
       at org.jboss.resource.work.WorkWrapper.execute(WorkWrapper.java:213)
       at org.jboss.util.threadpool.BasicTaskWrapper.run(BasicTaskWrapper.java:260)
       at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
       at java.lang.Thread.run(Thread.java:613)
      15:28:14,264 ERROR [JmsServerSession] org.jboss.resource.adapter.jms.inflow.JmsServerSession@458998 failed to commit/rollback
      javax.transaction.RollbackException: [com.arjuna.ats.internal.jta.transaction.arjunacore.commitwhenaborted] [com.arjuna.ats.internal.jta.transaction.arjunacore.commitwhenaborted] Could not commit transaction.
       at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1426)
       at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:135)
       at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
       at org.jboss.resource.adapter.jms.inflow.JmsServerSession$XATransactionDemarcationStrategy.end(JmsServerSession.java:657)
       at org.jboss.resource.adapter.jms.inflow.JmsServerSession.run(JmsServerSession.java:243)
       at org.jboss.resource.work.WorkWrapper.execute(WorkWrapper.java:213)
       at org.jboss.util.threadpool.BasicTaskWrapper.run(BasicTaskWrapper.java:260)
       at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
       at java.lang.Thread.run(Thread.java:613)
      


      I had assumed that stopDelivery would simply allow the current transactions to complete then it would simply not deliver more messages, however this error seems to imply that it is terminating the current transactions, however it does seem to be after the MDB itself has finished processing.

      I'm not sure if this is just a standard way to shut things down - however from the log it doesn't look at clean as I would expect.

      Can anyone help me just get my head around how the container is stopping delivery, and can't these errors be safely ignored or is there a problem in the way we are stopping the delivery of messages to the MDB?

      Any help is greatly appreciated - thanks in advance

      P

        • 1. Re: Calling stopDelivery causes an exception
          Philip Dodds Newbie

          We have upgraded to JBoss 5.1.0GA and the problem is the same, is it a known issue, or an exception we can safely ignore?

          • 2. Re: Calling stopDelivery causes a
            jaikiran pai Master

            On which MBean are you calling the stopDelivery method? I could not find any EJB3 related classes in the exception stacktrace. Maybe the MBean is JBoss Messaging related?

            • 3. Re: Calling stopDelivery causes a
              Philip Dodds Newbie

              We are calling the stopDelivery method on the EJB3 MDB MBean - I believe this one is the container registered when deploying the MDB. The stopDelivery functionality was only re-introduced recently (I believe maybe 1.1.2/1.1.3?) and we have been keen to make use of it.

              Thanks for the reply and the continuing help :)

              Cheers

              P

              • 4. Re: Calling stopDelivery causes a
                Philip Dodds Newbie

                I posted back to the JBM forum (I'm sorry I keep jumping between them)

                http://www.jboss.org/index.html?module=bb&op=viewtopic&t=155777&start=10&postdays=postDays&postorder=postOrder&highlight=highlight

                The MDB in question is an EJB3 deployed one and it is the EJB3 container, the MBean is listed as org.jboss.ejb3.mdb.MessagingDelegateWrapper. We are calling the stopDelivery method on this to try and pause message consumption and that is when we get the exception. I have checked the MDB and there is no funky threading stuff going on it there.

                Since stopDelivery is new I'm wondering if there is a threading problem in the container, though this occurs where we have MaxMessages and JMS Sessions both a 1 (and it also occurs where JMS sessions is set to a higher value).

                Once again thanks for all the help

                P

                • 5. Re: Calling stopDelivery causes a
                  jaikiran pai Master

                  I just tried to reproduce this against AS-5.1.0.GA with the MDB tutorial http://www.jboss.org/jbossejb3/docs/ and it worked fine for me - I mean i don't see any exceptions when i call a stopDelivery on the MBean corresponding to a MDB. Can you provide more details like when do you call this method and does the queue have any messages when you call this method?

                  • 6. Re: Calling stopDelivery causes a
                    jaikiran pai Master

                     

                    "jaikiran" wrote:
                    Can you provide more details like when do you call this method and does the queue have any messages when you call this method?


                    Bad question :) You already have provided those details:

                    I had assumed that stopDelivery would simply allow the current transactions to complete then it would simply not deliver more messages, however this error seems to imply that it is terminating the current transactions, however it does seem to be after the MDB itself has finished processing.


                    I'll have to look more into it to understand what's going on.


                    • 7. Re: Calling stopDelivery causes a
                      jaikiran pai Master

                      By the way, is this all the log that you see on the console/log file? I am failing to see any EJB3 classes in that call hierarchy? Maybe the stopDelivery() invocation from the EJB3 MBean went off successfully?

                      • 8. Re: Calling stopDelivery causes a
                        Philip Dodds Newbie

                        Its been a while :) but I finally got a little time to dig into this one a little more, in the end the bit that seems to bite me is the MessageInflowLocalProxy, when requesting the stopDelivery - messages are continuing to pass through the MDB. The flow of the requests to stop finally make it to the MessageInflowProxy which will request a release of the proxy - due to a small stack of debugging I was sure I had a transaction in flight and I get to the release method.

                         protected void release(Object proxy) throws Throwable
                         {
                         // We are now released
                         released.set(true);
                        
                         if (trace)
                         log.trace("MessageEndpoint " + getProxyString(proxy) + " release " + Thread.currentThread());
                        
                         // Tidyup any outstanding delivery
                         if (oldClassLoader != null)
                         {
                         try
                         {
                         finish("release", proxy, false);
                         }
                         catch (Throwable t)
                         {
                         log.warn("Error in release ", t);
                         }
                         }
                         }
                        


                        What I don't understand is that the oldClassLoader is null which means that the finish didn't get called - looking at that method that means that the finish doesn't get called and the transaction manager didn't get tidied up.

                        So I continued to dig around to see where the oldClassLoader gets set - it looks like it is done in the before and after, which would imply that the TransactionDemarcationStrategy in the JmsServerSession needs to be TraditionalXATransactionDemarcationStrategy (since that it checked for) in the onMessage. I appear to have an XATransactionDemarcationStrategy in place so before and after aren't called.

                        It looked like in the MessageInflowLocalProxy you look for the oldClassLoader in the delivery method too - if it is null you start a transaction.

                        try
                         {
                         // Check for starting a transaction
                         if (oldClassLoader == null)
                         {
                         boolean isTransacted = messageEndpointFactory.isDeliveryTransacted(methodInfo.getAdvisedMethod());
                         startTransaction("delivery", proxy, container, method, args, isTransacted);
                         }
                         return container.localInvoke(methodInfo, args);
                         }
                        


                        when you try to release how do you perform the check to ensure that the transaction has completed (when the oldClassLoader is null)?

                        All this code is pretty new to me so excuse any things that I got patently wrong :) Any advice or help would be greatly appreciated.

                        Cheers

                        P

                        • 9. Re: Calling stopDelivery causes a
                          Philip Dodds Newbie

                          I still haven't been able to make much progress on this issue.

                          I've tried various things to see what is going on - from what I can tell while the a transaction is in flight the session is closed in JBoss Messaging, it is as though it doesn't realize that the consumer is active, the session id is that of the consumer that is feeding the MDB.

                          I did discover that some of the comments in my last post aren't quite true - I was looking at a release of the JCA provider that isn't in 5.1.0. It appears that there was a feature added, which added all the traditional stuff into the JCA layer (see https://jira.jboss.org/jira/browse/JBAS-7084).

                          I was wondering if this issue might have any bearing on my problem, since it would imply that maxmessages isn't quite being maintained, and thus maybe this is where my rogue transaction that keeps running and is ultimately cut off in its prime :)

                          Any help or guidance would be greatly appreciated.

                          Cheers

                          P

                          • 10. Re: Calling stopDelivery causes a
                            Philip Dodds Newbie

                            After a chat with the very friendly Andy Taylor in the JBoss Messaging room on IRC I have put together a modified version of the EJB3 MDB example, basically you need to run it then while it is consuming messages through JMX execute the stopDelivery (if you don't get an error the first time it is worth trying again).

                            The source is available here - http://www.fiveclouds.com/stuff/stopdelivery-mdb.zip

                            Also I posted to the JCA forum - http://www.jboss.org/index.html?module=bb&op=viewtopic&p=4244714#4244714

                            I'm posting here (not in an attempt to cross post) to allow anyone who stumbles upon this thread to follow it since I'm still not sure if it is a problem in the EJB3 container or JCA.

                            Thanks again for the help - hopefully I'm getting closer to working out what is wrong :)

                            Cheers

                            P

                            • 11. Re: Calling stopDelivery causes a
                              jaikiran pai Master

                              Please open a JIRA in EJBTHREE https://jira.jboss.org/jira/browse/EJBTHREE and attach the source and the logs and any other relevant data. If it turns out to be lower level issue (like JCA) we can then decide about moving the issue to JCA.

                              • 12. Re: Calling stopDelivery causes a
                                Philip Dodds Newbie

                                Thanks for the quick response - I have opened a JIRA

                                https://jira.jboss.org/jira/browse/EJBTHREE-1870

                                Cheers

                                P

                                • 13. Re: Calling stopDelivery causes a
                                  Christian Strempfer Newbie

                                  Did you find a workaround? I'm experiencing exactly the same problem. It doesn't look like someone will fix it.