FUSE Message Broker
  1. FUSE Message Broker
  2. MB-913

Exceptions in KahaDB code when running the Stomp benchmark against ActiveMQ 5.5.0-fuse-00-27

    Details

    • Type: Bug Bug
    • Status: Resolved Resolved
    • Priority: Major Major
    • Resolution: Done
    • Affects Version/s: None
    • Component/s: broker
    • Labels:
      None
    • Environment:
      ActiveMQ 5.5.0-fuse-00-27
      Linux Ubuntu 11.04
      Quad core x86_64
    • Similar Issues:
      Show 10 results 

      Description

      When running the Stomp benchmark from https://github.com/chirino/stomp-benchmark according to the instructions on that page, I start seeing exceptions in the broker's log about 5 minutes into the benchmark.
      Please find my broker's configuration file attached. I am also attaching the broker's log file. Here are some of the stack traces from it:

       
      
      2011-06-30 16:02:09,903 [127.0.0.1:50524] ERROR FilePendingMessageCursor       - Caught an IO Exception getting the DiskList 98_PendingCursor:loadq-3
      java.lang.NullPointerException
      	at org.apache.kahadb.index.ListIndex.loadNode(ListIndex.java:203)
      	at org.apache.kahadb.index.ListIndex.load(ListIndex.java:75)
      	at org.apache.activemq.store.kahadb.plist.PListStore$1.execute(PListStore.java:219)
      	at org.apache.kahadb.page.Transaction.execute(Transaction.java:729)
      	at org.apache.activemq.store.kahadb.plist.PListStore.getPList(PListStore.java:216)
      	at org.apache.activemq.broker.region.cursors.FilePendingMessageCursor.getDiskList(FilePendingMessageCursor.java:454)
      	at org.apache.activemq.broker.region.cursors.FilePendingMessageCursor.flushToDisk(FilePendingMessageCursor.java:432)
      	at org.apache.activemq.broker.region.cursors.FilePendingMessageCursor.tryAddMessageLast(FilePendingMessageCursor.java:217)
      	at org.apache.activemq.broker.region.cursors.FilePendingMessageCursor.addMessageLast(FilePendingMessageCursor.java:193)
      	at org.apache.activemq.broker.region.Queue.sendMessage(Queue.java:1629)
      	at org.apache.activemq.broker.region.Queue.doMessageSend(Queue.java:720)
      	at org.apache.activemq.broker.region.Queue.send(Queue.java:652)
      	at org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:379)
      	at org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:523)
      	at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129)
      	at org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)
      	at org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:304)
      	at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129)
      	at org.apache.activemq.broker.UserIDBroker.send(UserIDBroker.java:56)
      	at org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:135)
      	at org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:468)
      	at org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:681)
      	at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:316)
      	at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:180)
      	at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:69)
      	at org.apache.activemq.transport.stomp.StompTransportFilter.sendToActiveMQ(StompTransportFilter.java:81)
      	at org.apache.activemq.transport.stomp.ProtocolConverter.sendToActiveMQ(ProtocolConverter.java:140)
      	at org.apache.activemq.transport.stomp.ProtocolConverter.onStompSend(ProtocolConverter.java:257)
      	at org.apache.activemq.transport.stomp.ProtocolConverter.onStompCommand(ProtocolConverter.java:178)
      	at org.apache.activemq.transport.stomp.StompTransportFilter.onCommand(StompTransportFilter.java:70)
      	at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
      	at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:221)
      	at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:203)
      	at java.lang.Thread.run(Thread.java:662)
      2011-06-30 16:02:09,912 [127.0.0.1:50524] ERROR FilePendingMessageCursor       - Caught an Exception adding a message: ActiveMQBytesMessage {commandId = 19796,
       responseRequired = false, messageId = ID:bigmacli-40948-1309463846336-2:105:-1:1:19794, originalDestination = null, originalTransactionId = null, producerId = ID:bigmacli-
      40948-1309463846336-2:105:-1:1, destination = queue://loadq-3, transactionId = null, expiration = 0, timestamp = 1309464129898, arrival = 0, brokerInTime = 1309464129898, 
      brokerOutTime = 0, correlationId = null, replyTo = null, persistent = false, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, 
      userID = null, content = org.apache.activemq.util.ByteSequence@665e2517, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, 
      readOnlyProperties = true, readOnlyBody = true, droppable = false} ActiveMQBytesMessage{ bytesOut = null, dataOut = null, dataIn = null } first to FilePendingMessageCursor 
      
      java.lang.RuntimeException: java.lang.NullPointerException
      	at org.apache.activemq.broker.region.cursors.FilePendingMessageCursor.getDiskList(FilePendingMessageCursor.java:457)
      	at org.apache.activemq.broker.region.cursors.FilePendingMessageCursor.flushToDisk(FilePendingMessageCursor.java:432)
      	at org.apache.activemq.broker.region.cursors.FilePendingMessageCursor.tryAddMessageLast(FilePendingMessageCursor.java:217)
      	at org.apache.activemq.broker.region.cursors.FilePendingMessageCursor.addMessageLast(FilePendingMessageCursor.java:193)
      	at org.apache.activemq.broker.region.Queue.sendMessage(Queue.java:1629)
      	at org.apache.activemq.broker.region.Queue.doMessageSend(Queue.java:720)
      	at org.apache.activemq.broker.region.Queue.send(Queue.java:652)
      	at org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:379)
      	at org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:523)
      	at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129)
      	at org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)
      	at org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:304)
      	at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129)
      	at org.apache.activemq.broker.UserIDBroker.send(UserIDBroker.java:56)
      	at org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:135)
      	at org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:468)
      	at org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:681)
      	at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:316)
      	at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:180)
      	at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:69)
      	at org.apache.activemq.transport.stomp.StompTransportFilter.sendToActiveMQ(StompTransportFilter.java:81)
      	at org.apache.activemq.transport.stomp.ProtocolConverter.sendToActiveMQ(ProtocolConverter.java:140)
      	at org.apache.activemq.transport.stomp.ProtocolConverter.onStompSend(ProtocolConverter.java:257)
      	at org.apache.activemq.transport.stomp.ProtocolConverter.onStompCommand(ProtocolConverter.java:178)
      	at org.apache.activemq.transport.stomp.StompTransportFilter.onCommand(StompTransportFilter.java:70)
      	at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
      	at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:221)
      	at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:203)
      	at java.lang.Thread.run(Thread.java:662)
      Caused by: java.lang.NullPointerException
      	at org.apache.kahadb.index.ListIndex.loadNode(ListIndex.java:203)
      	at org.apache.kahadb.index.ListIndex.load(ListIndex.java:75)
      	at org.apache.activemq.store.kahadb.plist.PListStore$1.execute(PListStore.java:219)
      	at org.apache.kahadb.page.Transaction.execute(Transaction.java:729)
      	at org.apache.activemq.store.kahadb.plist.PListStore.getPList(PListStore.java:216)
      	at org.apache.activemq.broker.region.cursors.FilePendingMessageCursor.getDiskList(FilePendingMessageCursor.java:454)
      	... 28 more
      
      
       
      
      2011-06-30 16:02:44,121 [Queue:loadq-9  ] ERROR Queue                          - Failed to page in more queue messages 
      java.util.NoSuchElementException: Chunk stream does not exist, page: 63122 is marked free
      	at org.apache.kahadb.index.ListNode$ListIterator.nextFromNextListNode(ListNode.java:149)
      	at org.apache.kahadb.index.ListNode$ListIterator.hasNext(ListNode.java:160)
      	at org.apache.activemq.store.kahadb.plist.PList$PListIterator.hasNext(PList.java:203)
      	at org.apache.activemq.broker.region.cursors.FilePendingMessageCursor$DiskIterator.hasNext(FilePendingMessageCursor.java:496)
      	at org.apache.activemq.broker.region.cursors.FilePendingMessageCursor.hasNext(FilePendingMessageCursor.java:288)
      	at org.apache.activemq.broker.region.Queue.doPageInForDispatch(Queue.java:1725)
      	at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1944)
      	at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1452)
      	at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:98)
      	at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:36)
      Caused by: java.io.EOFException: Chunk stream does not exist, page: 63122 is marked free
      	at org.apache.kahadb.page.Transaction$2.readPage(Transaction.java:456)
      	at org.apache.kahadb.page.Transaction$2.<init>(Transaction.java:433)
      	at org.apache.kahadb.page.Transaction.openInputStream(Transaction.java:430)
      	at org.apache.kahadb.page.Transaction.load(Transaction.java:406)
      	at org.apache.kahadb.page.Transaction.load(Transaction.java:363)
      	at org.apache.kahadb.index.ListIndex.loadNode(ListIndex.java:201)
      	at org.apache.kahadb.index.ListNode$ListIterator.nextFromNextListNode(ListNode.java:147)
      	... 9 more
      
      
       
      
      2011-06-30 16:02:49,401 [Queue:loadq-4  ] ERROR Queue                          - Failed to page in more queue messages 
      java.util.NoSuchElementException: Could not locate data file /lab/activemq-5.5.0-fuse-00-27/data/broker/tmp_storage/db-3.log
      	at org.apache.activemq.store.kahadb.plist.PList$PListIterator.next(PList.java:213)
      	at org.apache.activemq.store.kahadb.plist.PList$PListIterator.next(PList.java:192)
      	at org.apache.activemq.broker.region.cursors.FilePendingMessageCursor$DiskIterator.next(FilePendingMessageCursor.java:501)
      	at org.apache.activemq.broker.region.cursors.FilePendingMessageCursor$DiskIterator.next(FilePendingMessageCursor.java:485)
      	at org.apache.activemq.broker.region.cursors.FilePendingMessageCursor.next(FilePendingMessageCursor.java:296)
      	at org.apache.activemq.broker.region.Queue.doPageInForDispatch(Queue.java:1726)
      	at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1944)
      	at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1452)
      	at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:98)
      	at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:36)
      Caused by: java.io.IOException: Could not locate data file /lab/activemq-5.5.0-fuse-00-27/data/broker/tmp_storage/db-3.log
      	at org.apache.kahadb.journal.Journal.getDataFile(Journal.java:350)
      	at org.apache.kahadb.journal.Journal.read(Journal.java:597)
      	at org.apache.activemq.store.kahadb.plist.PListStore.getPayload(PListStore.java:367)
      	at org.apache.activemq.store.kahadb.plist.PList$PListIterator.next(PList.java:211)
      	... 9 more
      
      
      1. activemq.log
        821 kB
        Stan Livitski
      2. activemq.xml
        4 kB
        Stan Livitski

        Activity

        Hide
        Gary Tully
        added a comment - - edited

        I am actively working on a resolution but the root cause is elusive b/c it is very time sensitive and has multiple failure modes. Once I have a fix we can determine an appropriate delivery route.

        Show
        Gary Tully
        added a comment - - edited I am actively working on a resolution but the root cause is elusive b/c it is very time sensitive and has multiple failure modes. Once I have a fix we can determine an appropriate delivery route.
        Show
        Gary Tully
        added a comment - There is a new 5.6-SNAPSHOT with the fix for this issue: http://repo.fusesource.com/nexus/content/repositories/snapshots/org/apache/activemq/apache-activemq/5.6-fuse-SNAPSHOT/apache-activemq-5.6-fuse-20110803.145933-4-bin.tar.gz
        Hide
        Gary Tully
        added a comment -

        merged to 5.5 branch

        Show
        Gary Tully
        added a comment - merged to 5.5 branch

          People

          • Assignee:
            Gary Tully
            Reporter:
            Stan Livitski
          • Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: