activemq-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Dariusz Szablinski (JIRA)" <j...@apache.org>
Subject [jira] Commented: (AMQ-2512) "Failed to page in more queue messages"
Date Thu, 26 Nov 2009 22:53:52 GMT

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


Mime
View raw message