14 Replies Latest reply on Oct 29, 2003 4:18 PM by dguy

    Infinite loop in MessageCache

    dguy

      I'm still trying to create a simple test case, but in my application we have persistent transactional queue. An object message is sent to the queue and an MDB processes the message and writes to a table using a different data source (if we remove the MDB, the problem doesn't happen).

      After about 20,000 messages, we end up in an infinite loop in MessageCache.ValidateSoftReferenceDepth(). The currentMem is > highMemoryMark (and maxMemoryMark). The number of messages to soften hits a certain level and none of the counts change. It stays in the loop forever.

      The net effect is the thread hangs forever, of course.

      Has anyone else seen this behavior?

        • 1. Re: Infinite loop in MessageCache
          genman


          Does the rest of the application hang? If not, you can simply change the limits through the JMX console (or JMX directly) and it should work. I'll take a look at the code and see if there is an easy fix. If you have a stack trace, please post it.

          • 2. Re: Infinite loop in MessageCache
            dguy

            I'll post a stack trace on Monday. The rest of the application does not hang, so I can change the limit.

            I've debugged it more and found that the real problem is that somehow there is a message that is set NOT_STORED. There should be no way that can happen since the PersistenceManager.add() immediately stores persistent messages and sets the stored flag. I've used trace and see no message that the store has failed. No uncaught exception is thrown.

            So, the infinite loop seems to be a secondary problem, not the main problem.

            Again, I'll post more info on Monday. Thanks for the quick response.

            • 3. Re: Infinite loop in MessageCache
              dguy

              Here is the stack trace:

              validateSoftReferenceDepth() : 328, org.jboss.mq.server.MessageCache
              addInternal() : 127, org.jboss.mq.server.MessageCache
              add() : 97, org.jboss.mq.server.MessageCache
              addMessage() : 144, org.jboss.mq.server.JMSQueue
              addMessage() : 407, org.jboss.mq.server.JMSDestinationManager
              addMessage() : 383, org.jboss.mq.server.JMSDestinationManager
              addMessage() : 136, org.jboss.mq.server.JMSServerInterceptorSupport
              addMessage() : 162, org.jboss.mq.security.ServerSecurityInterceptor
              addMessage() : 270, org.jboss.mq.server.TracingInterceptor
              addMessage() : 136, org.jboss.mq.server.JMSServerInvoker
              addMessage() : 137, org.jboss.mq.il.jvm.JMSServIL
              sendToServer() : 1243, org.jboss.mq.Connection
              sendMessage() : 729, org.jboss.mq.SpySession
              internalSend() : 118, org.jboss.mq.SpyQueueSender
              send() : 68, org.jboss.mq.SpyQueueSender
              sendEventToQueue() : 259, com.telegea.event.APEventHandler

              The infinite loop happens when a message is being softened and it has
              MessageReference.stored == NOT_STORED. From MessageCache.validateSoftReferenceDepth() calls
              messageToSoften.makeSoft(); calls
              MessageCache.saveToStorage(), line 387, calls
              PersistenceManager.saveToStorage()

              In saveToStorage there is a test "if (messageRef.isPersistent())". Since the message is persistant, it returns without storing the message.

              Back up the stack in makeSoft, the method returns if the message is not stored (note the comment about a HACK) and then in MessageCache, line

              329, the stored flag is tested:
              if (messageToSoften.stored == MessageReference.STORED) since this evaluates to false, the method does not return and will loop forever.

              • 4. Re: Infinite loop in MessageCache
                genman


                Might I ask the persistence manager you are using? If it is JDBC, I can understand it doesn't need to mark the message reference as stored, as it's already stored. But obvioiusly the message cache needs to know what to do. I'll see if there is an easy work around.

                • 5. Re: Infinite loop in MessageCache
                  dguy

                  Sorry, I meant to post that. It is JDBC Persistence Manager. We're using


                  <depends optional-attribute-name="ConnectionManager">jboss.jca:service=LocalTxCM,name=ds/tx/default


                  We seem to be working around the problem by increasing the HighWaterMark and MaxMemoryMark but we're still running tests to make sure.

                  • 6. Re: Infinite loop in MessageCache

                    An addMessage will be NOT_STORED if memory is tight
                    and it hasn't got to the persistenceMangager.storeMessage() yet,
                    or whatever it is called.

                    In other words there is a small window where the cache
                    could know about the persistent message before it is actually
                    persisted.

                    I can imagine that if some error occurs that stops the message
                    being persisted and it is not removed from the cache,
                    under tight memory, it would continually try to soften the message
                    that should have been removed from the cache.

                    If you can reproduce this, try enabling TRACE logging
                    for org.jboss.mq.server. This should show the missing
                    exception handling that causes the problem.

                    Regards,
                    Adrian

                    • 7. Re: Infinite loop in MessageCache
                      dguy

                      I'm still trying to produce a trace log of reasonable length. My first attempt filled up my hard drive!

                      • 8. Re: Infinite loop in MessageCache
                        genman


                        You might want to just turn on tracing for org.jboss.mq.pm.jdbc2.PersistenceManager and see if that alone produces anything interesting.

                        Also, if you use the rollover appender for logging I think you can have it remove (delete) the old logs as time goes on.

                        • 9. Re: Infinite loop in MessageCache

                          No,

                          Change the logging to put the TRACE logging
                          for org.jboss.mq.server
                          into a different appender that rolls over and deletes
                          the previous log.

                          Filter the main log with
                          INFO

                          One of the options on RollingFileAppender is
                          MaxBackupIndex

                          Regards,
                          Adrian

                          • 10. Re: Infinite loop in MessageCache
                            dguy

                            I've attached the log. It traces org.jboss.mq.server and org.jboss.mq.pm.jdbc2. I've removed a million lines of infinite loop.

                            Messages 9, 10, 11, and 12 are never stored by PersistenceManager. You'll see msg=9 as the infinite loop cause. There is no error or problem reported that I can see. PersistenceManager never tries to store those messages.

                            The application that reproduces this problem creates an entity bean, then sends a message to the queue. There is an associated MDB that doesn't do anything. The problem only happens when the client creates multiple threads (usually 10). Having the entity bean seems to cause the problem to happen more quickly.

                            • 11. Re: Infinite loop in MessageCache
                              dguy

                              The client does not send a message directly to the queue; it calls a session EJB that sends the message.

                              • 12. Re: Infinite loop in MessageCache
                                dguy

                                Since the problem happens when a message needs to be softened before it is stored, I tried this change in MessageCache.validateSoftReferenceDepth() at line 329:

                                // Soften unless it was removed
                                if (messageToSoften.messageCache != null && messageToSoften.stored != MessageReference.REMOVED)
                                {
                                messageToSoften.makeSoft();
                                if (messageToSoften.stored == MessageReference.STORED)
                                {
                                softenedSize++;
                                return true;
                                } else if (messageToSoften.isPersistent()) // message not yet stored -- added by dguy
                                return false; // dguy
                                }

                                It works in my testing. I'm trying to verify if the message is getting stored later. I'm not sure if this is a fix or a hack yet.

                                • 13. Re: Infinite loop in MessageCache

                                  That looks like a good solution,
                                  I think the isPersistent() is really just a safety check that shouldn't
                                  be necessary.

                                  It looks like the softener is stuck in a cpu loop trying too hard
                                  to soften messages that can't be softened yet.

                                  This means the rest of the server doesn't get enough time
                                  to persist those same messages.

                                  Returning false means the softener thread will wait
                                  one second before trying again giving the server
                                  the chance to persist the message.

                                  I'll apply your patch.

                                  Regards,
                                  Adrian

                                  • 14. Re: Infinite loop in MessageCache
                                    dguy

                                    Thanks!