1 2 Previous Next 20 Replies Latest reply on Sep 9, 2003 4:16 AM by stephanenicoll

    MDB receiving messages before end of startup

    dbxbdxdob

      Hi,


      here at Solidus, we have an application that:
      - runs in JBoss 3.0.7
      - pulls messages from a queue hosted in MQSeries
      We've configured JBoss in such a way that it is deprived from its JMS message provider feature.


      What we've noticed so far is that:

      1. when JBoss starts and the queue is not empty, messages are processed before we can read in the log "[Server] JBoss (MX MicroKernel) [3.0.7 (CVSTag=JBoss_3_0_7 Date=200304081816)] Started in xxm:xxs:xxxms"
      The number of messages that can be processed may vary (from a dozen to a hundred)

      2. usually, after the "Started" sentence is printed, the processing of messages is stalled:
      - the other functions do not seem to be impacted (the jmx-console is still available, I can run test-cases) but messages sit in the queue
      - when trying to shutdown JBoss, the shutdown process hangs with:
      16:33:18,420 DEBUG [ServiceController] service context has 0 depending services
      16:33:18,421 INFO [JMSContainerInvoker] Stopping
      16:33:18,421 DEBUG [JMSContainerInvoker] Stop requested
      16:33:18,422 DEBUG [JMSContainerInvoker] Unset exception listener



      Did somebody experience a similar behavior?
      Is the hanging related to the premature processing of messages?
      We would of course gratefully appreciate any hints or directions in which we could dig in.

      --
      Dominique

        • 1. Re: MDB receiving messages before end of startup

          Try getting a thread dump

          ctrl-break on windows
          kill -3 {jboss-pid} on unix

          It is probably stuck in some socket i/o?

          Regards,
          Adrian

          • 2. Re: MDB receiving messages before end of startup
            dbxbdxdob

            Please find the dump enclosed.

            Regards,

            --
            Dominique

            • 3. Re: MDB receiving messages before end of startup
              dbxbdxdob

              Please find enclosed the dump.
              Please also accept my apologies if you receive it twice.

              Regards,

              --
              Dominique

              • 4. Re: MDB receiving messages before end of startup
                dbxbdxdob

                After putting in TRACE mode the following classes:

                * org.jboss.ejb.MessageDrivenContainer
                * org.jboss.ejb.plugins.jms.JMSContainerInvoker
                * org.jboss.jms.asf.StdServerSession
                * org.jboss.jms.asf.StdServerSessionPool

                what I've noticed so far is that:

                1. the processing of messages seems to be stalled in
                org.jboss.jms.asf.StdServerSessionPool.getServerSession():
                the last trace being: "Begin wait for server session"
                sessionPool.size() being equal to 0 2. The following methods are called the same number of times and are
                fully processed (in the log, the traces at the begin and at the
                end of them show up):

                * org.jboss.ejb.plugins.jms.JMSContainerInvoker.onMessage(javax.jms.Message)
                * org.jboss.jms.asf.StdServerSession.onMessage(javax.jms.Message)
                * org.jboss.jms.asf.StdServerSessionPool.recycle(org.jboss.jms.asf.StdServerSession)

                2. Let us call N this number.
                N vary between tests.

                3. org.jboss.jms.asf.StdServerSession.run() is called N+15 times and
                successfully exit.

                4. org.jboss.jms.asf.StdServerSessionPool.getServerSession() is
                called n+15+1 times but do no exit (cf. it stalls)

                5. If in conf/standardJboss.xml, in the configuration of the
                "Standard Message Driven Bean" container, if I change the
                parameter from 15 to 7,the preceeding figures evolve
                from n+15 (resp. n+15+1) to n+7 (resp n+7+1)


                Who originates the calls to getServerSession() not balanced with the recycling of the session, what's where I'm starting to be lost.
                In our deployment schema, MQ is alive before JBoss is up and running. Could MQ be the originator?
                Hope it helps.

                Regards,

                --
                Dominique

                • 5. Re: MDB receiving messages before end of startup

                  This is the thread deliverying the messages.

                  3XMTHREADINFO "MQQueueAgent (WQ_dobQ)" (TID:0x112FDBC0, sys_thread_t:0x8C23AB8, state:CW, native ID:0xC8032) prio=5
                  4XESTACKTRACE at java.lang.Object.wait(Native Method)
                  4XESTACKTRACE at java.lang.Object.wait(Object.java:429)
                  4XESTACKTRACE at org.jboss.jms.asf.StdServerSessionPool.getServerSession(StdServerSessionPool.java:208)
                  4XESTACKTRACE at com.ibm.mq.jms.MQConnectionConsumer.deliverNow(MQConnectionConsumer.java:592)
                  4XESTACKTRACE at com.ibm.mq.jms.MQConnectionConsumer.deliver(MQConnectionConsumer.java:554)
                  4XESTACKTRACE at com.ibm.mq.jms.MQQueueAgent.deliver(MQQueueAgent.java:723)
                  4XESTACKTRACE at com.ibm.mq.jms.MQQueueAgentThread.processMessage(MQQueueAgentThread.java:763)
                  4XESTACKTRACE at com.ibm.mq.jms.MQQueueAgentThread.run(MQQueueAgentThread.java:933)
                  4XESTACKTRACE at java.lang.Thread.run(Thread.java:513)

                  The recycling to the pool is done at the end
                  of
                  org.jboss.jms.asf.StdServerSession.onMessage(javax.jms.Message)

                  Do the 15 messages get to the MDB?
                  Are the sessions recycled?

                  It does 15+1 getServerSession()s because
                  it is reading ahead one message. When there
                  is something in the pool to process it, the
                  +1 invocation will return with a session.

                  It sounds to me like there is a silent failure
                  somewhere near the start of the delivery process?
                  And the session is not being recycled.

                  Regards,
                  Adrian

                  • 6. Re: MDB receiving messages before end of startup
                    dbxbdxdob

                    We might have an explanation:
                    What happens is that when MQ initiates a JMS session, it is trying to publish many messages in it.
                    The connection it obtains from the session pool being recycled at the end of the onMessage, I don't know what happens to the messages after the first one.

                    According to the javadoc of the javax.jms.ServerSession http://java.sun.com/j2ee/sdk_1.3/techdocs/api/javax/jms/ServerSession.html, "When |run| returns, the |ServerSession|'s run object can return the |ServerSession| to the |ServerSessionPool|, and the cycle starts again."

                    The little patch enclosed moves the recycling of the ServerSession from the end of the onMessage to the end of the run.

                    With it, the freezes during the processing of the messages and at shutdwon disappear.
                    Our QA team hasn't noticed any side effects yet with MQ but we haven't tested it in a configuration where JBoss plays the role of the JMS Provider.

                    One problem still subsists: when JBoss is started after the queue has been loaded, the processing of the first messages fail because the JNDI lookup of some beans fail (they are said not have been bound yet).
                    As usual, hints, workaround, ... are more than appreciated!

                    Regards,

                    --
                    Dominique

                    • 7. Re: MDB receiving messages before end of startup
                      dbxbdxdob

                      We might have an explanation.
                      What happens is that when MQ initiates a JMS session, it is trying to publish many messages in it.
                      The connection it obtains from the session pool being recycled at the end of the onMessage, I don't know what happens to the messages after the first one.

                      According to the javadoc of the javax.jms.ServerSession http://java.sun.com/j2ee/sdk_1.3/techdocs/api/javax/jms/ServerSession.html, "When |run| returns, the |ServerSession|'s run object can return the |ServerSession| to the |ServerSessionPool|, and the cycle starts again."

                      The little patch enclosed moves the recycling of the ServerSession from the end of the onMessage to the end of the run.

                      With it, the freezes during the processing of the messages and at shutdwon disappear.
                      Our QA team hasn't noticed any side effects yet *with MQ* but we haven't tested it in a configuration where JBoss plays the role of the JMS Provider.

                      One problem still subsists: when JBoss is started after the queue has been loaded, the processing of the first messages fail because the JNDI lookup of some beans fail (they are said not have been bound yet).
                      As usual, hints, workaround, ... are more than appreciated!

                      Regards,

                      --
                      Dominique

                      • 8. Re: MDB receiving messages before end of startup

                        Thanks for the patch, using "-u 5" would have
                        been better so the diff had some context.

                        I will look further into this, a simple testcase
                        will speed up my testing/investigation.

                        For the beans not available, you can
                        add a
                        jboss.j2ee:service=EJB,jndiName=whatever
                        to the mdb in jboss.xml

                        It will wait for the other bean to deploy before
                        starting.

                        Regards,
                        Adrian

                        • 9. Re: MDB receiving messages before end of startup

                          I've applied your patch.

                          It will be available in the next jboss releases.

                          Thanks,
                          Adrian

                          • 10. Re: MDB receiving messages before end of startup
                            dbxbdxdob

                            Adding the <depends> in the MDB solved the last problem.

                            Thanks for your help all over this issue.

                            Do you still need a test case?

                            Regards,

                            --
                            Dominique

                            • 11. Re: MDB receiving messages before end of startup

                              I tried to reproduce it with jbossmq, but couldn't.

                              We can't really add mqseries to the testsuite.

                              Regards,
                              Adrian

                              • 12. Re: MDB receiving messages before end of startup

                                Is this depends entry in JBoss.xml could be generated through Xdoclet?

                                We generate JBoss.xml on the fly using Xdoclet and we need this feature.

                                Thanks

                                • 13. Re: MDB receiving messages before end of startup
                                  dbxbdxdob

                                  With xdoclet-1.1.2, if you create in your directory src/resources/xdoclet/<name
                                  of the package containing your MDB> a file called jboss-<class name of your
                                  MDB>.xml, xdoclet will take this file as a template to generate the xml block
                                  for this specific MDB.

                                  cf. xdoclet/ejb/vendor/jboss_xml.j in your xdoclet.jar

                                  What I did -but I doubt that it is elegant and/or the most maintainable way-,
                                  was to copy the block I found in xdoclet/ejb/vendor/jboss_xml.j and added the
                                  parameter I needed.
                                  (cf. file enclosed).

                                  I hope it helps and that members of this forum will provide a cleaner way to do it.

                                  --
                                  Dominique

                                  • 14. Re: MDB receiving messages before end of startup

                                    Ok I succeeded this xdoclet stuff. Now I have in my jboss.xml for my bean the following:

                                    </message-driven>
                                    <message-driven>
                                    <ejb-name>ejb/kp/v0.0.1/ParcelCreator</ejb-name>
                                    <destination-jndi-name>queue/kp/v0.0.1/parcelInstruction</destination-jndi-name>
                                    <configuration-name>KPServer Message Driven Bean</configuration-name>
                                    jboss.j2ee:service=EJB,jndiName=ejb/debug/LogWriterLocal
                                    jboss.j2ee:service=EJB,jndiName=ejb/kp/ParcelFacadeLocal
                                    </message-driven>


                                    Those 2 EJBs are in separates JARs in the EAR I am deploying. At the end of the deployment of my ear, I got this:

                                    2003-05-28 16:04:02,136 INFO [org.jboss.deployment.EARDeployer] Started J2EE application: file:/var/jboss-3.2.1/server/default/deploy/kpserver.ear
                                    2003-05-28 16:04:02,136 INFO [org.jboss.deployment.MainDeployer] Deployed package: file:/var/jboss-3.2.1/server/default/deploy/kpserver.ear
                                    2003-05-28 16:04:02,137 ERROR [org.jboss.deployment.scanner.URLDeploymentScanner] MBeanException: Exception in MBean operation 'checkIncompleteDeployments()'
                                    Cause: Incomplete Deployment listing:
                                    Packages waiting for a deployer:

                                    Incompletely deployed packages:

                                    MBeans waiting for classes:

                                    MBeans waiting for other MBeans:
                                    [ObjectName: jboss.j2ee:jndiName=local/ejb/kp/v0.0.1/ParcelCreator,service=EJB
                                    state: NOTYETINSTALLED
                                    I Depend On: jboss.j2ee:service=EJB,jndiName=ejb/debug/LogWriterLocal
                                    jboss.j2ee:service=EJB,jndiName=ejb/kp/ParcelFacadeLocal

                                    Depends On Me: ]


                                    My MDB does not start and msgs are not pooled (they are JMS msgs waiting for that particular MDB in the queue).

                                    Any idea?

                                    1 2 Previous Next