5 Replies Latest reply on Mar 14, 2003 9:40 AM by John Peng

    Problem: MDB stops reacting

    Ed Letifov Newbie

      Hello, All.

      Setup:
      Our system is centered around Jboss 3.0.4+Jetty running on AS400. In short, it handles HTTP requests :) Current (test environment) average load on the system is somewhere around 30 requests per minute, peak values so far were around 200. Production systems certainly as usual has to handle more.

      The basic workflow/design of the system can be described as follows:
      - requests are picked up by the servlets
      - each type of request is handled by separate servlet (actually the same class, but different config parameters through web.xml)
      - servlet parses the request, composes an object message and submits it to the core via request JMS queue with one of the properties set to specific constant reflecting the request type
      - servlet goes to timed-synchronous waiting cycle on response queue, if no response arrives from core in 10 sec, a specific (timeout) response is sent to the client
      - core "interface" is a set of MDB that call the rest (Session and Entity beans) or respond back directly through response queue. Instances of each different MDB class handle request messages only of a certain type specified via message selector in descriptor.

      Problem:
      After a certain time (~couple of days) one (or several, no system visible) MDBs stop responding to messages. In the logs it is visible that message was submitted to the queue, after that nothing happens, clients eventually receive timeout response. If we restart Jboss or stop/destroy/create/start the jar with MDB through JMX console everything starts working again.

      Polite request:
      Please respond if you had the same problem with simular setups or under different versions/operating systems and have a clue what direction to look for the solution.

      Ed.
      PS. Jboss Group paid support IS an option, if you are sure this can help us please mention it.

        • 1. Re: Problem: MDB stops reacting
          David Mann Newbie

          We seem to have the same trouble using Jboss 3.0.4 on AIX 4.3.3/JDK 1.3.1 R3.

          All messages fire on server restart. Can you share your descriptor settings, the transaction settings for your onMessage...

          David

          • 2. Re: Problem: MDB stops reacting
            John Peng Newbie

            Yes, I ran into the same problem. The version I am using is 3.0.2. Maybe the newer version behaves better.

            Best,

            John

            • 3. Re: Problem: MDB stops reacting
              Ed Letifov Newbie

              Are you using JDK from IBM as well? What platform are you running on? The reason I am asking this is that there is an opinion that for us its rather Jboss on AS400 issue.
              Though I have to admit I've seen this on Windows box as well.

              • 4. Re: Problem: MDB stops reacting
                Ed Letifov Newbie

                >Yes, I ran into the same problem. The version I am using
                >is 3.0.2. Maybe the newer version behaves better.

                Are you using JVM from IBM as well? What platform are you running on? Hopefully it is not "Jboss on AS400" or "Jboss on IBM JVM" issue. I think I've seen this on Windows box as well, but unfortunately I am not sure.

                Also it looks like JbossMQ hasn't changed from 3.0.2 to 3.0.6

                I do have the thread dumps both from AS400 and Windows. Anyone is willing to take a look? Or maybe direct me where to send them?

                I've noticed that in our case problems seem to start after the following message appears in the logs: "WARNING: NACK issued. The message consumer was not waiting for a message."

                Also we've made some more detailed research of logs and Jboss source. After we enable tracing here is what we've got:

                2003-03-06 16:34:21,068 TRACE [1046964853752:TracingInterceptor] CALLED : receive
                2003-03-06 16:34:21,082 TRACE [1046964853752:TracingInterceptor] ARG : -2147473121
                2003-03-06 16:34:21,090 TRACE [1046964853752:TracingInterceptor] ARG : -1
                2003-03-06 16:34:21,090 TRACE [1046964853752:ServerSecurityInterceptor] Checking receive authorize on SpyDistributedConnection:ID:78/ca35b8c9ad1c166f21560d812148ea9e subId=-2147473121
                2003-03-06 16:34:21,092 TRACE [1046964853752:TracingInterceptor] EXCEPTION : receive:
                javax.jms.JMSException: The provided subscription does not exist
                java/lang/Throwable.(Ljava/lang/String;)V+4 (Throwable.java:90)
                javax/jms/JMSException.(Ljava/lang/String;Ljava/lang/String;)V+0 (JMSException.java:0)
                javax/jms/JMSException.(Ljava/lang/String;)V+0 (JMSException.java:0)
                org/jboss/mq/server/ClientConsumer.getSubscription(I)Lorg/jboss/mq/Subscription;+0 (ClientConsumer.java:0)
                org/jboss/mq/server/JMSDestinationManager.getSubscription(Lorg/jboss/mq/ConnectionToken;I)Lorg/jboss/mq/Subscription;+0 (JMSDestinationManager.java:0)
                org/jboss/mq/server/JMSServerInterceptorSupport.getSubscription(Lorg/jboss/mq/ConnectionToken;I)Lorg/jboss/mq/Subscription;+0 (JMSServerInterceptorSupport.java:0)
                org/jboss/mq/security/ServerSecurityInterceptor.receive(Lorg/jboss/mq/ConnectionToken;IJ)Lorg/jboss/mq/SpyMessage;+0 (ServerSecurityInterceptor.java:0)
                org/jboss/mq/server/TracingInterceptor.receive(Lorg/jboss/mq/ConnectionToken;IJ)Lorg/jboss/mq/SpyMessage;+0 (TracingInterceptor.java:0)
                org/jboss/mq/server/JMSServerInvoker.receive(Lorg/jboss/mq/ConnectionToken;IJ)Lorg/jboss/mq/SpyMessage;+0 (JMSServerInvoker.java:0)
                org/jboss/mq/il/jvm/JVMServerIL.receive(Lorg/jboss/mq/ConnectionToken;IJ)Lorg/jboss/mq/SpyMessage;+0 (JVMServerIL.java:0)
                org/jboss/mq/Connection.receive(Lorg/jboss/mq/Subscription;J)Lorg/jboss/mq/SpyMessage;+0 (Connection.java:0)
                org/jboss/mq/SpyMessageConsumer.receiveNoWait()Ljavax/jms/Message;+0 (SpyMessageConsumer.java:0)
                com/vocognition/talkface/jms/JMSModel.checkNoWaitForReplyTo(Lcom/vocognition/talkface/talkman/TalkmanMessage;)Lcom/vocognition/talkface/talkman/ModelMessage;+0 (JMSModel.java:73)
                com/vocognition/talkface/talkman/LUTHandler.service(Lcom/vocognition/talkface/talkman/TalkmanRequest;Lcom/vocognition/talkface/talkman/TalkmanResponse;)V+0 (LUTHandler.java:27)
                com/vocognition/talkface/protocol/tfshttp/JMSServlet.doGet(Ljavax/servlet/http/HttpServletRequest;Ljavax/servlet/http/HttpServletResponse;)V+0 (JMSServlet.java:112)
                javax/servlet/http/HttpServlet.service(Ljavax/servlet/http/HttpServletRequest;Ljavax/servlet/http/HttpServletResponse;)V+0 (HttpServlet.java:0)
                javax/servlet/http/HttpServlet.service(Ljavax/servlet/ServletRequest;Ljavax/servlet/ServletResponse;)V+0 (HttpServlet.java:0)
                org/mortbay/jetty/servlet/ServletHolder.handle(Ljavax/servlet/ServletRequest;Ljavax/servlet/ServletResponse;)V+0 (ServletHolder.java:334)
                org/mortbay/jetty/servlet/WebApplicationHandler.dispatch(Ljava/lang/String;Ljavax/servlet/http/HttpServletRequest;Ljavax/servlet/http/HttpServletResponse;Lorg/mortbay/jetty/servlet/ServletHolder;)V+0 (WebApplicationHandler.java:201)
                org/mortbay/jetty/servlet/ServletHandler.handle(Ljava/lang/String;Ljava/lang/String;Lorg/mortbay/http/HttpRequest;Lorg/mortbay/http/HttpResponse;)V+0 (ServletHandler.java:518)
                org/mortbay/http/HttpContext.handle(Ljava/lang/String;Ljava/lang/String;Lorg/mortbay/http/HttpRequest;Lorg/mortbay/http/HttpResponse;)Z+0 (HttpContext.java:1665)
                org/mortbay/jetty/servlet/WebApplicationContext.handle(Ljava/lang/String;Ljava/lang/String;Lorg/mortbay/http/HttpRequest;Lorg/mortbay/http/HttpResponse;)Z+0 (WebApplicationContext.java:540)
                org/mortbay/http/HttpContext.handle(Lorg/mortbay/http/HttpRequest;Lorg/mortbay/http/HttpResponse;)Z+0 (HttpContext.java:1576)
                org/mortbay/http/HttpServer.service(Lorg/mortbay/http/HttpRequest;Lorg/mortbay/http/HttpResponse;)Lorg/mortbay/http/HttpContext;+0 (HttpServer.java:840)
                org/jboss/jetty/Jetty.service(Lorg/mortbay/http/HttpRequest;Lorg/mortbay/http/HttpResponse;)Lorg/mortbay/http/HttpContext;+0 (Jetty.java:543)
                org/mortbay/http/HttpConnection.service(Lorg/mortbay/http/HttpRequest;Lorg/mortbay/http/HttpResponse;)Lorg/mortbay/http/HttpContext;+0 (HttpConnection.java:804)
                org/mortbay/http/HttpConnection.handleNext()Z+0 (HttpConnection.java:871)
                org/mortbay/http/HttpConnection.handle()V+0 (HttpConnection.java:822)
                org/mortbay/http/SocketListener.handleConnection(Ljava/net/Socket;)V+0 (SocketListener.java:176)
                org/mortbay/util/ThreadedServer.handle(Ljava/lang/Object;)V+0 (ThreadedServer.java:287)
                org/mortbay/util/ThreadPool$JobRunner.run()V+0 (ThreadPool.java:658)
                java/lang/Thread.run()V+11 (Thread.java:484)
                2003-03-06 16:34:21,097 TRACE [1046964853752:TracingInterceptor] RETURN : receive


                We've added some more trace statements. The subscription is definitely added, but there is no evidence that it is removed. So it looks like it magically dissappears :(

                I am worried about one thing - in JbossMQ ClientConsumer source all operations on subsriptions HashMap are done in blocks synchronized on subscriptions object itself by making clones, operating on them and then setting subscriptions reference to the new object (as in the following code snippets). I am not sure why is it done like this, and I suspect that it actually breaks the idea of synchronization because as it looks right after the reference is changed another thread may acquire a lock on a new object, while the first thread is still holding a lock on the old one. Please take a look:
                ===
                public void addSubscription(Subscription req) throws JMSException
                {
                if( log.isTraceEnabled() )
                log.trace("Adding subscription for: " + req);
                req.connectionToken = connectionToken;
                req.clientConsumer = this;

                JMSDestination jmsdest = (JMSDestination) server.getJMSDestination(req.destination);
                if (jmsdest == null)
                {
                throw new JMSException("The destination " + req.destination + " does not exist !");
                }

                jmsdest.addSubscriber(req);

                synchronized (subscriptions)
                {
                HashMap subscriptionsClone = (HashMap) subscriptions.clone();
                subscriptionsClone.put(new Integer(req.subscriptionId), req);
                subscriptions = subscriptionsClone;
                }
                }
                ===

                public void close()
                {
                boolean trace = log.isTraceEnabled();
                if( trace )
                log.trace("" + this +"->close()");

                synchronized (messages)
                {
                closed = true;
                if (enqueued)
                {
                if( trace )
                log.trace("" + this +"->close(): Cancelling work in progress.");
                threadPool.cancelWork(this);
                enqueued = false;
                }
                }

                synchronized (subscriptions)
                {
                Iterator i = subscriptions.keySet().iterator();
                while (i.hasNext())
                {
                Integer subscriptionId = (Integer) i.next();
                try
                {
                removeSubscription(subscriptionId.intValue());
                }
                catch(JMSException ignore)
                {
                }
                }
                }

                // Nack the removed subscriptions, the connection is gone
                HashMap removedSubsClone = (HashMap) ((HashMap) removedSubscriptions).clone();
                Iterator i = removedSubsClone.values().iterator();
                while (i.hasNext())
                {
                Subscription removed = (Subscription) i.next();
                JMSDestination queue = (JMSDestination) server.getJMSDestination(removed.destination);
                if (queue == null)
                log.warn("The subscription was registered with a destination that does not exist: " + removed);
                try
                {
                queue.nackMessages(removed);
                }
                catch (JMSException e)
                {
                log.warn("Unable to nack removed subscription: " + removed, e);
                }
                }
                }





                • 5. Re: Problem: MDB stops reacting
                  John Peng Newbie

                  I am using Sun's HotSpot JVM version 1.4.0 and running JBoss 3.0.2 on Windows 2000 Server (SP2). Unfortunately, I bundled everything in one big jar file and deployed it, if I stop/destroy/create/start this jar file through JMX console, my entire application will be down. Is there any way to restart this MDB via JMX console without bothering other EJBs in my jar file. Please let me know if you have idea how to do this. I appreciate it.