[prev in list] [next in list] [prev in thread] [next in thread] 

List:       activemq-dev
Subject:    [jira] Commented: (AMQ-2512) "Failed to page in more queue
From:       "Dariusz Szablinski (JIRA)" <jira () apache ! org>
Date:       2009-11-26 22:53:52
Message-ID: 323806160.1259276032738.JavaMail.jira () brutus
[Download RAW message or body]


    [ 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.


[prev in list] [next in list] [prev in thread] [next in thread] 

Configure | About | News | Add a list | Sponsored by KoreLogic