Uploaded image for project: 'AMQ Broker'
  1. AMQ Broker
  2. ENTMQBR-2100

AMQ 7.2.1: under heavy load: org.apache.activemq.artemis.core.paging.cursor.NonExistentPage: Invalid messageNumber passed

    XMLWordPrintable

Details

    • Bug
    • Resolution: Done
    • Major
    • AMQ 7.2.4.GA
    • AMQ 7.2.1.GA
    • None
    • None
    • Release Notes
    • +
    • Hide
      While a receiving transaction is committed to a paging operation, if the page is complete, a transaction operation deletes it. Previously, the transaction operation might delete the page before the receiving transaction could access it. This caused the receiving transaction to fail to find a message. In that case, you saw an exception. This issue is now resolved.
      Show
      While a receiving transaction is committed to a paging operation, if the page is complete, a transaction operation deletes it. Previously, the transaction operation might delete the page before the receiving transaction could access it. This caused the receiving transaction to fail to find a message. In that case, you saw an exception. This issue is now resolved.
    • Verified in a release
    • Hide

      1. Download and extract the attached broker.zip file. broker1 is the master and broker2 is the slave.
      2. Create the master/slave setup using attached broker files.
      3. Run master and slave broker.
      4. Run the attached test script (testScript.sh) which produces and consumes messages with high volume.
      5. After a few iterations the following logs appear when the consumer is running:

      [org.apache.activemq.artemis.utils.actors.OrderedExecutor] Invalid messageNumber passed = PagePositionImpl [pageNr=2, messageNr=11127, recordID=6573510] on null: org.apache.activemq.artemis.core.paging.cursor.NonExistentPage: Invalid messageNumber passed = PagePositionImpl [pageNr=2, messageNr=11127, recordID=6573510] on null
      

      6. Incorrect message count is displayed for this particular queue on hawtio console

      Expected
      1. This exception should not appear under high load
      2. Correct message count should be displayed on hawtio console.

      Show
      1. Download and extract the attached broker.zip file. broker1 is the master and broker2 is the slave. 2. Create the master/slave setup using attached broker files. 3. Run master and slave broker. 4. Run the attached test script (testScript.sh) which produces and consumes messages with high volume. 5. After a few iterations the following logs appear when the consumer is running: [org.apache.activemq.artemis.utils.actors.OrderedExecutor] Invalid messageNumber passed = PagePositionImpl [pageNr=2, messageNr=11127, recordID=6573510] on null : org.apache.activemq.artemis.core.paging.cursor.NonExistentPage: Invalid messageNumber passed = PagePositionImpl [pageNr=2, messageNr=11127, recordID=6573510] on null 6. Incorrect message count is displayed for this particular queue on hawtio console Expected 1. This exception should not appear under high load 2. Correct message count should be displayed on hawtio console.

    Description

      When AMQ broker is operated under heavy load. The following message is observed in artemis.log.

      [org.apache.activemq.artemis.utils.actors.OrderedExecutor] Invalid messageNumber passed = PagePositionImpl [pageNr=2, messageNr=11127, recordID=6573510] on null: org.apache.activemq.artemis.core.paging.cursor.NonExistentPage: Invalid messageNumber passed = PagePositionImpl [pageNr=2, messageNr=11127, recordID=6573510] on null
      	at org.apache.activemq.artemis.core.paging.cursor.impl.PageCursorProviderImpl.getMessage(PageCursorProviderImpl.java:119) [artemis-server-2.6.3.redhat-00004.jar:2.6.3.redhat-00004]
      	at org.apache.activemq.artemis.core.paging.cursor.impl.PageSubscriptionImpl.queryMessage(PageSubscriptionImpl.java:574) [artemis-server-2.6.3.redhat-00004.jar:2.6.3.redhat-00004]
      	at org.apache.activemq.artemis.core.paging.cursor.PagedReferenceImpl.getPagedMessage(PagedReferenceImpl.java:101) [artemis-server-2.6.3.redhat-00004.jar:2.6.3.redhat-00004]
      	at org.apache.activemq.artemis.core.paging.cursor.PagedReferenceImpl.getMessage(PagedReferenceImpl.java:88) [artemis-server-2.6.3.redhat-00004.jar:2.6.3.redhat-00004]
      	at org.apache.activemq.artemis.core.server.impl.QueuePendingMessageMetrics.decrementMetrics(QueuePendingMessageMetrics.java:71) [artemis-server-2.6.3.redhat-00004.jar:2.6.3.redhat-00004]
      	at org.apache.activemq.artemis.core.server.impl.QueueImpl.decDelivering(QueueImpl.java:3399) [artemis-server-2.6.3.redhat-00004.jar:2.6.3.redhat-00004]
      	at org.apache.activemq.artemis.core.server.impl.QueueImpl.postAcknowledge(QueueImpl.java:3016) [artemis-server-2.6.3.redhat-00004.jar:2.6.3.redhat-00004]
      	at org.apache.activemq.artemis.core.server.impl.RefsOperation.afterCommit(RefsOperation.java:157) [artemis-server-2.6.3.redhat-00004.jar:2.6.3.redhat-00004]
      	at org.apache.activemq.artemis.core.transaction.impl.TransactionImpl.afterCommit(TransactionImpl.java:546) [artemis-server-2.6.3.redhat-00004.jar:2.6.3.redhat-00004]
      	at org.apache.activemq.artemis.core.transaction.impl.TransactionImpl.access$100(TransactionImpl.java:38) [artemis-server-2.6.3.redhat-00004.jar:2.6.3.redhat-00004]
      	at org.apache.activemq.artemis.core.transaction.impl.TransactionImpl$2.done(TransactionImpl.java:304) [artemis-server-2.6.3.redhat-00004.jar:2.6.3.redhat-00004]
      	at org.apache.activemq.artemis.core.persistence.impl.journal.OperationContextImpl$1.run(OperationContextImpl.java:236) [artemis-server-2.6.3.redhat-00004.jar:2.6.3.redhat-00004]
      	at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:42) [artemis-commons-2.6.3.redhat-00004.jar:2.6.3.redhat-00004]
      	at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:31) [artemis-commons-2.6.3.redhat-00004.jar:2.6.3.redhat-00004]
      	at org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:66) [artemis-commons-2.6.3.redhat-00004.jar:2.6.3.redhat-00004]
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [rt.jar:1.8.0_181]
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [rt.jar:1.8.0_181]
      	at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118) [artemis-commons-2.6.3.redhat-00004.jar:2.6.3.redhat-00004]
      

      As a result of this, incorrect message count is displayed on the hawtio console for this queue. See attachments.

      Attachments

        1. brokers.zip
          7 kB
        2. Incorrect message count.png
          Incorrect message count.png
          153 kB
        3. No messages.png
          No messages.png
          100 kB
        4. testScript.sh
          0.7 kB

        Issue Links

          Activity

            People

              gaohoward Howard Gao
              rhn-support-adongre Avinash Dongre
              Michal Toth Michal Toth
              Votes:
              2 Vote for this issue
              Watchers:
              13 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Time Tracking

                  Estimated:
                  Original Estimate - 0 minutes
                  0m
                  Remaining:
                  Remaining Estimate - 0 minutes
                  0m
                  Logged:
                  Time Spent - 1 day, 5 hours
                  1d 5h