Mailing-List: contact dev-help@activemq.apache.org; run by ezmlm
Precedence: bulk
Reply-To: dev@activemq.apache.org
Message-ID: <1488738663.1259273272951.JavaMail.jira@brutus>
Date: Thu, 26 Nov 2009 14:07:52 -0800 (PST)
From: "Dariusz Szablinski (JIRA)" <jira@apache.org>
To: dev@activemq.apache.org
Subject: [jira] Updated: (AMQ-2512) "Failed to page in more queue messages"
In-Reply-To: <471040936.1259180872724.JavaMail.jira@brutus>
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 7bit


     [ https://issues.apache.org/activemq/browse/AMQ-2512?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Dariusz Szablinski updated AMQ-2512:
------------------------------------

    Attachment: KahaDbNPE.java

> "Failed to page in more queue messages"
> ---------------------------------------
>
>                 Key: AMQ-2512
>                 URL: https://issues.apache.org/activemq/browse/AMQ-2512
>             Project: ActiveMQ
>          Issue Type: Bug
>    Affects Versions: 5.3.1
>            Reporter: Dariusz Szablinski
>             Fix For: 5.3.1, 5.4.0
>
>         Attachments: activemq.log, activemq.xml, jconsole.jpg, KahaDbNPE.java
>
>
> Following exception occurs quite often at the moment when cursor percent usage is over 100% and suddenly drops down below 100%:
> 2009-11-25 21:16:00,287 | INFO  | Slow KahaDB access: cleanup took 547 | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
> 2009-11-25 21:16:27,832 | INFO  | Slow KahaDB access: Journal append took: 0 ms, Index update took 891 ms | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Transport: tcp:///192.168.1.4:57697
> 2009-11-25 21:16:30,324 | INFO  | Slow KahaDB access: Journal append took: 0 ms, Index update took 1172 ms | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Transport: tcp:///192.168.1.4:57697
> 2009-11-25 21:16:31,283 | ERROR | Failed to page in more queue messages  | org.apache.activemq.broker.region.Queue | Queue:dee.q
> java.lang.NullPointerException
> 	at org.apache.kahadb.index.BTreeIndex.loadNode(BTreeIndex.java:260)
> 	at org.apache.kahadb.index.BTreeNode$BTreeIterator.findNextPage(BTreeNode.java:103)
> 	at org.apache.kahadb.index.BTreeNode$BTreeIterator.hasNext(BTreeNode.java:120)
> 	at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore$2.execute(KahaDBStore.java:194)
> 	at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore$2.execute(KahaDBStore.java:190)
> 	at org.apache.kahadb.page.Transaction.execute(Transaction.java:751)
> 	at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore.getMessageCount(KahaDBStore.java:189)
> 	at org.apache.activemq.broker.region.cursors.QueueStorePrefetch.getStoreSize(QueueStorePrefetch.java:63)
> 	at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.remove(AbstractStoreCursor.java:189)
> 	at org.apache.activemq.broker.region.cursors.StoreQueueCursor.remove(StoreQueueCursor.java:141)
> 	at org.apache.activemq.broker.region.Queue.doPageIn(Queue.java:1370)
> 	at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1505)
> 	at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1176)
> 	at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:98)
> 	at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:36)
> Additional side effect is that broker stops dispatching messages out of the queue (see queue size and consumer count on screenshot from jconsole)
> Sometimes this exception is also followed by:
> 2009-11-25 20:45:00,783 | WARN  | Async error occurred: java.lang.ClassCastException: java.lang.String cannot be cast to org.apache.kahadb.journal.Location | org.apache.activemq.broker.TransportConnection.Service | ActiveMQ Transport: tcp:///192.168.1.4:57516
> java.lang.ClassCastException: java.lang.String cannot be cast to org.apache.kahadb.journal.Location
> 	at org.apache.kahadb.journal.Location.compareTo(Location.java:29)
> 	at java.util.Arrays.binarySearch0(Arrays.java:2001)
> 	at java.util.Arrays.binarySearch(Arrays.java:1943)
> 	at org.apache.kahadb.index.BTreeNode.remove(BTreeNode.java:234)
> 	at org.apache.kahadb.index.BTreeNode.remove(BTreeNode.java:240)
> 	at org.apache.kahadb.index.BTreeNode.remove(BTreeNode.java:240)
> 	at org.apache.kahadb.index.BTreeIndex.remove(BTreeIndex.java:194)
> 	at org.apache.activemq.store.kahadb.MessageDatabase.updateIndex(MessageDatabase.java:873)
> 	at org.apache.activemq.store.kahadb.MessageDatabase.access$700(MessageDatabase.java:82)
> 	at org.apache.activemq.store.kahadb.MessageDatabase$13.execute(MessageDatabase.java:757)
> 	at org.apache.kahadb.page.Transaction.execute(Transaction.java:728)
> 	at org.apache.activemq.store.kahadb.MessageDatabase.process(MessageDatabase.java:755)
> 	at org.apache.activemq.store.kahadb.MessageDatabase$11.visit(MessageDatabase.java:700)
> 	at org.apache.activemq.store.kahadb.data.KahaRemoveMessageCommand.visit(KahaRemoveMessageCommand.java:220)
> 	at org.apache.activemq.store.kahadb.MessageDatabase.process(MessageDatabase.java:692)
> 	at org.apache.activemq.store.kahadb.MessageDatabase.store(MessageDatabase.java:644)
> 	at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore.removeMessage(KahaDBStore.java:153)
> 	at org.apache.activemq.broker.region.Queue.acknowledge(Queue.java:602)
> 	at org.apache.activemq.broker.region.Queue.removeMessage(Queue.java:1235)
> 	at org.apache.activemq.broker.region.QueueSubscription.acknowledge(QueueSubscription.java:60)
> 	at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:250)
> 	at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:369)
> 	at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:470)
> 	at org.apache.activemq.broker.TransactionBroker.acknowledge(TransactionBroker.java:194)
> 	at org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:74)
> 	at org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:74)
> 	at org.apache.activemq.broker.MutableBrokerFilter.acknowledge(MutableBrokerFilter.java:85)
> 	at org.apache.activemq.broker.TransportConnection.processMessageAck(TransportConnection.java:449)
> 	at org.apache.activemq.command.MessageAck.visit(MessageAck.java:205)
> 	at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:297)
> 	at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:175)
> 	at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68)
> 	at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
> 	at org.apache.activemq.transport.InactivityMonitor.onCommand(InactivityMonitor.java:210)
> 	at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:84)
> 	at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:203)
> 	at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:185)
> 	at java.lang.Thread.run(Thread.java:619)
> I'm using latest 5.3.1-SNAPSHOT

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.