1 2 Previous Next 16 Replies Latest reply on Jun 11, 2009 1:24 AM by Yong Hao Gao

    Cannot find session during shutdown

    Philip Dodds Newbie

      During the shutdown of a system with several MDB's we appear to be getting:

      2009-05-20 12:30:52,499 ERROR [org.jboss.messaging.util.ExceptionUtil] (WorkManager(2)-44) ConnectionEndpoint[fe-oz919yuf-1-mj809yuf-bruz48-x21o4c5] sendTransaction [ur4-b6b39yuf-1-mj809yuf-bruz48-x21o4c5]
      javax.jms.IllegalStateException: Cannot find session with id ie-qz919yuf-1-mj809yuf-bruz48-x21o4c5
       at org.jboss.jms.server.endpoint.ServerConnectionEndpoint.processTransaction(ServerConnectionEndpoint.java:835)
       at org.jboss.jms.server.endpoint.ServerConnectionEndpoint.sendTransaction(ServerConnectionEndpoint.java:497)
       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)
      


      This seems to lead to

      2009-05-20 12:36:34,251 WARN [com.arjuna.ats.jta.logging.loggerI18N] (Thread-13) [com.arjuna.ats.internal.jta.resources.arjunacore.norecoveryxa] [com.arjuna.ats.internal.jta.resources.arjunacore.norecoveryxa] Could not find new XAResource to use for recovering non-serializable XAResource < 131075, 30, 28, 4945455110253551021015755589956555058529749525010299575855555753455110253551021015755589956555058529749525010299575855555754 >


      When the server restarts, what causes problems with the session not being found in a XA environment?

      Thanks in advance

      Philip

        • 1. Re: Cannot find session during shutdown
          Clebert Suconic Master

          Regarding the non-serializable error, look at this thread:

          http://www.jboss.org/index.html?module=bb&op=viewtopic&t=152893


          I'm not sure why you're getting this error though. Maybe some missing dependency between JCA and JBossMessaging and the shutdown order is not being respected?

          • 2. Re: Cannot find session during shutdown
            Clebert Suconic Master

             

            I'm not sure why you're getting this error though.




            I was referring to this error:

            2009-05-20 12:30:52,499 ERROR [org.jboss.messaging.util.ExceptionUtil] (WorkManager(2)-44) Connectio
            nEndpoint[fe-oz919yuf-1-mj809yuf-bruz48-x21o4c5] sendTransaction [ur4-b6b39yuf-1-mj809yuf-bruz48-x21
            o4c5]
            javax.jms.IllegalStateException: Cannot find session with id ie-qz919yuf-1-mj809yuf-bruz48-x21o4c5
            ...
            


            • 3. Re: Cannot find session during shutdown
              Philip Dodds Newbie

              Hi Clebert

              We have put in the recovery settings into the jbossjta-properties.xml and also moved it to the top during testing.

              It worries me a little that the session isn't found - I could only find references to that problem occurring in a clustered environment (see https://jira.jboss.org/jira/browse/JBESB-2218) though we are seeing this:

              2009-05-20 12:30:52,499 ERROR [org.jboss.messaging.util.ExceptionUtil] (WorkManager(2)-44) ConnectionEndpoint[fe-oz919yuf-1-mj809yuf-bruz48-x21o4c5] sendTransaction [ur4-b6b39yuf-1-mj809yuf-bruz48-x21o4c5]
              javax.jms.IllegalStateException: Cannot find session with id ie-qz919yuf-1-mj809yuf-bruz48-x21o4c5
               at org.jboss.jms.server.endpoint.ServerConnectionEndpoint.processTransaction(ServerConnectionEndpoint.java:835)
               at org.jboss.jms.server.endpoint.ServerConnectionEndpoint.sendTransaction(ServerConnectionEndpoint.java:497)
               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.GeneratedMethodAccessor345.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.prepare(ResourceManager.java:337)
               at org.jboss.jms.tx.MessagingXAResource.prepare(MessagingXAResource.java:240)
               at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelPrepare(XAResourceRecord.java:271)
               at com.arjuna.ats.arjuna.coordinator.BasicAction.doPrepare(BasicAction.java:2893)
               at com.arjuna.ats.arjuna.coordinator.BasicAction.doPrepare(BasicAction.java:2850)
               at com.arjuna.ats.arjuna.coordinator.BasicAction.prepare(BasicAction.java:2402)
               at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1790)
               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)
              2009-05-20 12:30:52,502 WARN [com.arjuna.ats.jta.logging.loggerI18N] (WorkManager(2)-44) [com.arjuna.ats.internal.jta.resources.arjunacore.preparefailed] [com.arjuna.ats.internal.jta.resources.arjunacore.preparefailed] XAResourceRecord.prepare - prepare failed with exception XAException.XA_RETRY
              2009-05-20 12:30:52,503 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] (WorkManager(2)-44) [com.arjuna.ats.arjuna.coordinator.BasicAction_50] - Prepare phase of action -3f57fe97:c872:4a142fc9:7795 received heuristic decision: TwoPhaseOutcome.HEURISTIC_HAZARD
              2009-05-20 12:30:52,503 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] (WorkManager(2)-44) [com.arjuna.ats.arjuna.coordinator.BasicAction_36] - BasicAction.End() - prepare phase of action-id -3f57fe97:c872:4a142fc9:7795 failed.
              2009-05-20 12:30:52,503 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] (WorkManager(2)-44) [com.arjuna.ats.arjuna.coordinator.BasicAction_37] - Received heuristic: TwoPhaseOutcome.HEURISTIC_HAZARD .
              2009-05-20 12:30:52,503 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] (WorkManager(2)-44) [com.arjuna.ats.arjuna.coordinator.BasicAction_38] - Action Aborting
              2009-05-20 12:30:52,504 ERROR [org.jboss.resource.adapter.jms.inflow.JmsServerSession] (WorkManager(2)-44) org.jboss.resource.adapter.jms.inflow.JmsServerSession@8e4361 failed to commit/rollback
              javax.transaction.HeuristicMixedException
               at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1422)
               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)
              


              The HeuristicMixedException worries me - and noticed that this ticket - https://cloud.prod.atl2.jboss.com:8443/jira/browse/JBESB-2483 seemed to indicate a possible problem in JBM? I wondered if you have seen it or had any advice on what to look at? I'm not saying there might not be a problem in the code - it is an MDB that communicates to an Oracle database and XA is in place across all sides of the transaction - also JBM is running on the same Oracle database (if that helps)

              Thanks again for the quick response

              P

              • 4. Re: Cannot find session during shutdown
                Yong Hao Gao Master

                Hi Phillip, please give some details of your application server deployment and the version of JBM.

                The possible reason of the "Cannot find session with id" is that the session has been closed before the 'commit' request arrives.

                How did you shutdown your application servers? and in what order? I'm asking these question because this might provide a clue to what has actually happened.


                • 5. Re: Cannot find session during shutdown
                  Philip Dodds Newbie

                  We are running on a JBoss 5.0.1GA base, though we needed the startDelivery and stopDelivery methods to exist on the MDB container therefore we upgraded the EJB 3.0 container to 1.1.4(?).

                  Judging from the log its a JBoss 1.4.1.GA server, this is just what came with the server.

                  2009-05-20 12:29:01,038 INFO [org.jboss.jms.server.ServerPeer] (main) JBoss Messaging 1.4.1.GA server [0] started
                  


                  The shutdown we are seeing just being initiated by a control+C on the terminal. If we don't have messages processing the shutdown is clean.

                  Thanks again

                  P

                  • 6. Re: Cannot find session during shutdown
                    Yong Hao Gao Master

                    Hi Phillp,

                    How many JBoss AS server instances are you running? Is the JBM running in one instance, and the MDB is running in another? Are they on the same machine or separate machines? If there are multiple instances, which one do you shut down first, which one second?

                    Thanks.

                    • 7. Re: Cannot find session during shutdown
                      Philip Dodds Newbie

                      This is just a single JBoss instance, and the only one on the network while we are testing. The persistence if using Oracle 11g to a database on a second server.

                      Thanks again

                      P

                      • 8. Re: Cannot find session during shutdown
                        Yong Hao Gao Master

                        ok, this is probably a service shutdown sequence issue between MDB and Transaction Service. You can ask AS guy for how to make sure the Transaction Service is shutdown before MDB services.

                        Or you may not kill the process while there is live transactions.

                        • 9. Re: Cannot find session during shutdown
                          Philip Dodds Newbie

                          We have continued to work on this one - and have upgraded to the latest JBoss 5.1.0GA release.

                          This appears to have resolved the problem with the XA transaction - however we are using the stopDelivery method on the EJB3 MDB MBean and are getting a "session cannot be found" during the stopDelivery processing.

                          I'm not certain if it is a problem in the MDB container or the JBoss Messaging configuration, I have opened a discussion over on the EJB3 forum, see:

                          http://www.jboss.org/index.html?module=bb&op=viewtopic&t=155887

                          I really didn't want to cross post stuff but I was wondering if any JBM guys could spot something in the trace, it looks like it rolls back ok - and we are trying to work out whether this is a problem that we need to look into or just the way things are when you stop delivery.

                          Thanks again for all the help

                          • 10. Re: Cannot find session during shutdown
                            Yong Hao Gao Master

                            Hi,

                            I think 'session cannot be found' can happen as I explained. To further verify my reasoning, you can try to find in the server's server.log if there is something like:

                            "A problem has been detected with the connection to remote client xxxxxxxxx, jmsClientID=xxxxxxxx. It is possible the client has exited without closing its connection(s) or the network has failed. All associated connection resources will be cleaned up."

                            If not, then I think the connection is probably shared by two or more threads, and one of the thread closed the connection without waiting for other threads finish their work with it. That should be viewed as an application level issue from JBM angle.

                            • 11. Re: Cannot find session during shutdown
                              Yong Hao Gao Master

                              Sorry, actually the second case I supposed (shared connection) is unlikely to happen. As if it happened, there wouldn't be error messages like you have got. It should be detected by other clients before reaching that point.

                              • 12. Re: Cannot find session during shutdown
                                Tim Fox Master

                                I'm not familiar with this stopDelivery method - I guess this is something added by the EJB team.

                                Like Howard says, perhaps it is doing something illegal, but without seeing the code for it, it would be hard to tell.

                                • 13. Re: Cannot find session during shutdown
                                  Philip Dodds Newbie

                                  Thanks for all the help and insight - I'll jump back over to EJB3 and see if maybe it is a configuration issue in the deployment or a problem in the EJB3 container (since stopDelivery was only recently added).

                                  Thanks again

                                  P

                                  • 14. Re: Cannot find session during shutdown
                                    Philip Dodds Newbie

                                    We are still looking into this - I had a quick question around the way in which a JBMActivation stops, it looks like you stop delivery and then start a teardown. As I'm following it when I choose stopDelivery on the MDB it then requested deactiveEndpoint in the reosource adapter which finally gets to call stop on the JBMActivation which sets deliveryActive to false then calls teardown on the JBMMessageHandler which releases the endpoint and closes the session.

                                    If the message is currently being consumed shouldn't this be waiting for that transaction? I'm wondering if this is causing the session can not be found when the in-flight transaction completes?

                                    All help is greatly appreciated :)

                                    1 2 Previous Next