You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@activemq.apache.org by "Dariusz Szablinski (JIRA)" <ji...@apache.org> on 2009/11/25 21:27:52 UTC
[jira] Created: (AMQ-2512) "Failed to page in more queue messages"
"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
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.
Re: [jira] Updated: (AMQ-2512) "Failed to page in more queue
messages"
Posted by immilev <i....@gmail.com>.
"> Following exception occurs quite often at the moment when cursor percent
usage is over 100% and suddenly drops down below 100%..."
The same exception is thrown by ActiveMQ 5.3.0 using the KahaDB store for
persistent queues. The MaxPageSize is set to 20,000. In this case, it occurs
when the count of messages to be paged in gets up to 37K. Both
CursorPercentUsage and MemoryPercentUsage in our case is around 10-15%, so
it does not seem related to cursor percent usage near 100%
2010-01-02 20:57:49,440 | DEBUG | outputQueue toPageIn: 2, Inflight: 17,
pagedInMessages.size 38738 | org.apache.activemq.broker.region
.Queue | QueueThread:queue://outputQueue
2010-01-02 20:57:49,440 | ERROR | Failed to page in more queue messages |
org.apache.activemq.broker.region.Queue | QueueThread:queue://outputQueue
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:185)
at
org.apache.activemq.broker.region.cursors.StoreQueueCursor.remove(StoreQueueCursor.java:141)
at org.apache.activemq.broker.region.Queue.doPageIn(Queue.java:1367)
at
org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1503)
at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1178)
at
org.apache.activemq.thread.DeterministicTaskRunner.runTask(DeterministicTaskRunner.java:84)
at
org.apache.activemq.thread.DeterministicTaskRunner$1.run(DeterministicTaskRunner.java:41)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
Cheers!
Ivaylo
JIRA jira@apache.org wrote:
>
>
> [
> https://issues.apache.org/activemq/browse/AMQ-2512?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
> ]
>
> Dariusz Szablinski updated AMQ-2512:
> ------------------------------------
>
> Attachment: jconsole.jpg
>
>> "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: jconsole.jpg
>>
>>
>> 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.
>
>
>
--
View this message in context: http://old.nabble.com/-jira--Created%3A-%28AMQ-2512%29-%22Failed-to-page-in-more-queue-messages%22-tp26519757p26996701.html
Sent from the ActiveMQ - Dev mailing list archive at Nabble.com.
[jira] Updated: (AMQ-2512) "Failed to page in more queue messages"
Posted by "Dariusz Szablinski (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/activemq/browse/AMQ-2512?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Dariusz Szablinski updated AMQ-2512:
------------------------------------
Attachment: activemq.log.3
> "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-cant-startup.log, 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.
[jira] Updated: (AMQ-2512) "Failed to page in more queue messages"
Posted by "Dariusz Szablinski (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/activemq/browse/AMQ-2512?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Dariusz Szablinski updated AMQ-2512:
------------------------------------
Attachment: activemq.xml
> "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
>
>
> 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.
[jira] Commented: (AMQ-2512) "Failed to page in more queue
messages"
Posted by "Gary Tully (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/activemq/browse/AMQ-2512?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=56119#action_56119 ]
Gary Tully commented on AMQ-2512:
---------------------------------
code inspection may get to the bottom of this but a test case would help. Can you attach your test code or describe what consumers and producers are present at the time?
> "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
>
>
> 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.
[jira] Assigned: (AMQ-2512) "Failed to page in more queue messages"
Posted by "Rob Davies (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/activemq/browse/AMQ-2512?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Rob Davies reassigned AMQ-2512:
-------------------------------
Assignee: Rob Davies
> "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
> Assignee: Rob Davies
> Fix For: 5.3.1, 5.4.0
>
> Attachments: activemq-cant-startup.log, 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.
[jira] Commented: (AMQ-2512) "Failed to page in more queue
messages"
Posted by "Dariusz Szablinski (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/activemq/browse/AMQ-2512?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=56134#action_56134 ]
Dariusz Szablinski commented on AMQ-2512:
-----------------------------------------
My test client code attached. Starting from 30000-50000 messages delivery is much slower. Above situation usually happens at the end of processing (between 80 000 and 100 000 message received).
> "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.
[jira] Updated: (AMQ-2512) "Failed to page in more queue messages"
Posted by "Dariusz Szablinski (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/activemq/browse/AMQ-2512?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Dariusz Szablinski updated AMQ-2512:
------------------------------------
Attachment: (was: activemq.log.3)
> "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-cant-startup.log, 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.
[jira] Resolved: (AMQ-2512) "Failed to page in more queue messages"
Posted by "Rob Davies (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/activemq/browse/AMQ-2512?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Rob Davies resolved AMQ-2512.
-----------------------------
Resolution: Fixed
I'm marking this as fixed - please re-open if not the case
> "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
> Assignee: Rob Davies
> Fix For: 5.3.1, 5.4.0
>
> Attachments: activemq-cant-startup.log, 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.
[jira] Commented: (AMQ-2512) "Failed to page in more queue
messages"
Posted by "Rob Davies (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/activemq/browse/AMQ-2512?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=57017#action_57017 ]
Rob Davies commented on AMQ-2512:
---------------------------------
I have a test case that failed - but have made some improvements - plus reduced prefetch to 10 for consumers - would like verification if this is still an issue on the next 5.4-SNAPSHOT build - anyone ?
SVN revision 901300
> "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-cant-startup.log, 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.
[jira] Commented: (AMQ-2512) "Failed to page in more queue
messages"
Posted by "Dariusz Szablinski (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/activemq/browse/AMQ-2512?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=56212#action_56212 ]
Dariusz Szablinski commented on AMQ-2512:
-----------------------------------------
One more observation: using different type of cursor than store based (which is default I guess) seems to improve dispatch behavior - no more exceptions, hangs and slow downs.
<pendingQueuePolicy>
<fileQueueCursor/>
</pendingQueuePolicy>
However I think store based cursor should also work fine and that's why I'm leaving this issue still open.
> "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-cant-startup.log, 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.
[jira] Commented: (AMQ-2512) "Failed to page in more queue
messages"
Posted by "Dariusz Szablinski (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/activemq/browse/AMQ-2512?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=56135#action_56135 ]
Dariusz Szablinski commented on AMQ-2512:
-----------------------------------------
Once I also got following exception when I've killed my client app (during processing) and then shutdown broker and tried to start it up (I had to delete all kahaDB data files to fix this):
2009-11-26 23:38:58,264 | ERROR | Failed to start ActiveMQ JMS Message Broker. Reason: java.lang.NullPointerException | org.apache.activemq.broker.BrokerService | main
java.lang.NullPointerException
at org.apache.kahadb.index.BTreeNode$BTreeIterator.findNextPage(BTreeNode.java:109)
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.Queue.initialize(Queue.java:226)
at org.apache.activemq.broker.region.DestinationFactoryImpl.createDestination(DestinationFactoryImpl.java:83)
at org.apache.activemq.broker.region.AbstractRegion.createDestination(AbstractRegion.java:460)
at org.apache.activemq.broker.jmx.ManagedQueueRegion.createDestination(ManagedQueueRegion.java:56)
at org.apache.activemq.broker.region.AbstractRegion.addDestination(AbstractRegion.java:120)
at org.apache.activemq.broker.region.RegionBroker.addDestination(RegionBroker.java:268)
at org.apache.activemq.broker.BrokerFilter.addDestination(BrokerFilter.java:142)
at org.apache.activemq.broker.BrokerFilter.addDestination(BrokerFilter.java:142)
at org.apache.activemq.advisory.AdvisoryBroker.addDestination(AdvisoryBroker.java:153)
at org.apache.activemq.broker.BrokerFilter.addDestination(BrokerFilter.java:142)
at org.apache.activemq.broker.MutableBrokerFilter.addDestination(MutableBrokerFilter.java:149)
at org.apache.activemq.broker.region.AbstractRegion.start(AbstractRegion.java:94)
at org.apache.activemq.broker.region.RegionBroker.start(RegionBroker.java:178)
at org.apache.activemq.broker.jmx.ManagedRegionBroker.start(ManagedRegionBroker.java:100)
at org.apache.activemq.broker.TransactionBroker.start(TransactionBroker.java:112)
at org.apache.activemq.broker.BrokerFilter.start(BrokerFilter.java:154)
at org.apache.activemq.broker.BrokerFilter.start(BrokerFilter.java:154)
at org.apache.activemq.broker.BrokerService$3.start(BrokerService.java:1690)
at org.apache.activemq.broker.BrokerService.start(BrokerService.java:458)
at org.apache.activemq.xbean.XBeanBrokerService.afterPropertiesSet(XBeanBrokerService.java:56)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1369)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1335)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:473)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory$1.run(AbstractAutowireCapableBeanFactory.java:409)
at java.security.AccessController.doPrivileged(Native Method)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:380)
at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:264)
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:222)
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:261)
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:185)
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:164)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:429)
at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:728)
at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:380)
at org.apache.xbean.spring.context.ResourceXmlApplicationContext.<init>(ResourceXmlApplicationContext.java:64)
at org.apache.xbean.spring.context.ResourceXmlApplicationContext.<init>(ResourceXmlApplicationContext.java:52)
at org.apache.activemq.xbean.XBeanBrokerFactory.createApplicationContext(XBeanBrokerFactory.java:96)
at org.apache.activemq.xbean.XBeanBrokerFactory.createBroker(XBeanBrokerFactory.java:52)
at org.apache.activemq.broker.BrokerFactory.createBroker(BrokerFactory.java:71)
at org.apache.activemq.broker.BrokerFactory.createBroker(BrokerFactory.java:54)
at org.apache.activemq.console.command.StartCommand.startBroker(StartCommand.java:115)
at org.apache.activemq.console.command.StartCommand.runTask(StartCommand.java:74)
at org.apache.activemq.console.command.AbstractCommand.execute(AbstractCommand.java:57)
at org.apache.activemq.console.command.ShellCommand.runTask(ShellCommand.java:136)
at org.apache.activemq.console.command.AbstractCommand.execute(AbstractCommand.java:57)
at org.apache.activemq.console.command.ShellCommand.main(ShellCommand.java:82)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.activemq.console.Main.runTaskClass(Main.java:251)
at org.apache.activemq.console.Main.main(Main.java:107)
Full log file attached. Could it happened because of enableJournalDiskSyncs="false" setting?
> "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.
[jira] Closed: (AMQ-2512) "Failed to page in more queue messages"
Posted by "Dariusz Szablinski (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/activemq/browse/AMQ-2512?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Dariusz Szablinski closed AMQ-2512.
-----------------------------------
works fine
> "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
> Assignee: Rob Davies
> Fix For: 5.3.1, 5.4.0
>
> Attachments: activemq-cant-startup.log, 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.
[jira] Updated: (AMQ-2512) "Failed to page in more queue messages"
Posted by "Dariusz Szablinski (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/activemq/browse/AMQ-2512?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Dariusz Szablinski updated AMQ-2512:
------------------------------------
Attachment: activemq-cant-startup.log
> "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-cant-startup.log, 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.
[jira] Updated: (AMQ-2512) "Failed to page in more queue messages"
Posted by "Dariusz Szablinski (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/activemq/browse/AMQ-2512?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Dariusz Szablinski updated AMQ-2512:
------------------------------------
Attachment: activemq.log
> "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, jconsole.jpg
>
>
> 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.
[jira] Updated: (AMQ-2512) "Failed to page in more queue messages"
Posted by "Dariusz Szablinski (JIRA)" <ji...@apache.org>.
[ 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.
[jira] Updated: (AMQ-2512) "Failed to page in more queue messages"
Posted by "Dariusz Szablinski (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/activemq/browse/AMQ-2512?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Dariusz Szablinski updated AMQ-2512:
------------------------------------
Attachment: jconsole.jpg
> "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: jconsole.jpg
>
>
> 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.