OOME while paging leads to endless NPE and queues stop working -------------------------------------------------------------- Key: WFLY-851 URL: https://issues.jboss.org/browse/WFLY-851 Project: WildFly Issue Type: Bug Components: JMS Environment: Win2008 R2, 64bit, 8GB RAM, 4 CPUs Reporter: Noa Drach Assignee: Andy Taylor Priority: Major Labels: OOME, jms, npe, paging I am working with jboss 7.1.1 Final that was changed to include a fix to JIRA https://issues.jboss.org/browse/AS7-4330 In my system there are 60000 messages that are sent to 1 persistent queue and later on they pass in 4 non durable queues. the 60000 messages where sent successfully within 1 hour and I saw the load of the system and CPU usage drop, but than after 3 hours I got the following out of memory exception: 21:26:33,515 ERROR [org.hornetq.utils.OrderedExecutorFactory] (Thread-19 (HornetQ-server-HornetQServerImpl::serverUUID=b554c910-cb6a-11e1-a8a0-005056b044a0-32482279)) Caught unexpected Throwable: java.lang.OutOfMemoryError INFO | jvm 1 | 2012/07/11 21:26:33 | at sun.misc.Unsafe.allocateMemory(Native Method) [rt.jar:1.6.0_16] INFO | jvm 1 | 2012/07/11 21:26:33 | at java.nio.DirectByteBuffer.<init>(DirectByteBuffer.java:99) [rt.jar:1.6.0_16] INFO | jvm 1 | 2012/07/11 21:26:33 | at java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:288) [rt.jar:1.6.0_16] INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.core.journal.impl.NIOSequentialFileFactory.allocateDirectBuffer(NIOSequentialFileFactory.java:130) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.core.persistence.impl.journal.JournalStorageManager.allocateDirectBuffer(JournalStorageManager.java:1655) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.core.paging.impl.PageImpl.read(PageImpl.java:119) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.core.paging.cursor.impl.PageCursorProviderImpl.getPageCache(PageCursorProviderImpl.java:189) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.core.paging.cursor.impl.PageCursorProviderImpl.getPageCache(PageCursorProviderImpl.java:140) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.core.paging.cursor.impl.PageSubscriptionImpl.internalGetNext(PageSubscriptionImpl.java:345) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.core.paging.cursor.impl.PageSubscriptionImpl.access$1500(PageSubscriptionImpl.java:65) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.core.paging.cursor.impl.PageSubscriptionImpl$CursorIterator.moveNext(PageSubscriptionImpl.java:1177) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.core.paging.cursor.impl.PageSubscriptionImpl$CursorIterator.next(PageSubscriptionImpl.java:1134) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.core.paging.cursor.impl.PageSubscriptionImpl$CursorIterator.hasNext(PageSubscriptionImpl.java:1289) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.core.server.impl.QueueImpl.depage(QueueImpl.java:1861) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.core.server.impl.QueueImpl.access$1200(QueueImpl.java:77) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.core.server.impl.QueueImpl$DepageRunner.run(QueueImpl.java:2469) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.utils.OrderedExecutorFactory$OrderedExecutor$1.run(OrderedExecutorFactory.java:100) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [rt.jar:1.6.0_16] INFO | jvm 1 | 2012/07/11 21:26:33 | at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [rt.jar:1.6.0_16] INFO | jvm 1 | 2012/07/11 21:26:33 | at java.lang.Thread.run(Thread.java:619) [rt.jar:1.6.0_16] and than the system keeps throwing the next NPE: INFO | jvm 1 | 2012/07/11 21:26:33 | 21:26:33,562 ERROR [org.hornetq.utils.OrderedExecutorFactory] (Thread-19 (HornetQ-server-HornetQServerImpl::serverUUID=b554c910-cb6a-11e1-a8a0-005056b044a0-32482279)) Caught unexpected Throwable: java.lang.RuntimeException INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.core.paging.cursor.impl.PageSubscriptionImpl$CursorIterator.next(PageSubscriptionImpl.java:1138) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.core.paging.cursor.impl.PageSubscriptionImpl$CursorIterator.hasNext(PageSubscriptionImpl.java:1289) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.core.server.impl.QueueImpl.deliver(QueueImpl.java:1797) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.core.server.impl.QueueImpl.doPoll(QueueImpl.java:1625) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.core.server.impl.QueueImpl.access$1300(QueueImpl.java:77) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.core.server.impl.QueueImpl$ConcurrentPoller.run(QueueImpl.java:2482) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.utils.OrderedExecutorFactory$OrderedExecutor$1.run(OrderedExecutorFactory.java:100) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [rt.jar:1.6.0_16] INFO | jvm 1 | 2012/07/11 21:26:33 | at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [rt.jar:1.6.0_16] INFO | jvm 1 | 2012/07/11 21:26:33 | at java.lang.Thread.run(Thread.java:619) [rt.jar:1.6.0_16] INFO | jvm 1 | 2012/07/11 21:26:33 | Caused by: java.lang.NullPointerException INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.core.paging.cursor.impl.PageCacheImpl.getNumberOfMessages(PageCacheImpl.java:110) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.core.paging.cursor.impl.PageSubscriptionImpl.internalGetNext(PageSubscriptionImpl.java:352) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.core.paging.cursor.impl.PageSubscriptionImpl.access$1500(PageSubscriptionImpl.java:65) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.core.paging.cursor.impl.PageSubscriptionImpl$CursorIterator.moveNext(PageSubscriptionImpl.java:1177) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | at org.hornetq.core.paging.cursor.impl.PageSubscriptionImpl$CursorIterator.next(PageSubscriptionImpl.java:1134) [hornetq-core-2.2.13.Final.jar:] INFO | jvm 1 | 2012/07/11 21:26:33 | ... 9 more I restarted JBOSS and than it won't start with the following error: INFO | jvm 1 | 2012/07/11 23:14:17 | 23:14:17,218 INFO [org.jboss.as] JBAS015899: JBoss AS 7.1.1.Final "Brontes" starting INFO | jvm 1 | 2012/07/11 23:14:18 | 23:14:18,421 ERROR [org.jboss.as.server] JBAS015956: Caught exception during boot: org.jboss.as.controller.persistence.ConfigurationPersistenceException: JBAS014676: Failed to parse configuration INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.as.controller.persistence.XmlConfigurationPersister.load(XmlConfigurationPersister.java:141) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final] INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.as.server.ServerService.boot(ServerService.java:266) [jboss-as-server-7.1.1.Final.jar:7.1.1.Final] INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.as.controller.AbstractControllerService$1.run(AbstractControllerService.java:155) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final] INFO | jvm 1 | 2012/07/11 23:14:18 | at java.lang.Thread.run(Thread.java:619) [rt.jar:1.6.0_16] INFO | jvm 1 | 2012/07/11 23:14:18 | Caused by: javax.xml.stream.XMLStreamException: Failed to load module org.jboss.as.cmp INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.as.controller.parsing.ExtensionXml.parseExtensions(ExtensionXml.java:154) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final] INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.as.server.parsing.StandaloneXml.readServerElement_1_1(StandaloneXml.java:305) [jboss-as-server-7.1.1.Final.jar:7.1.1.Final] INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.as.server.parsing.StandaloneXml.readElement(StandaloneXml.java:127) [jboss-as-server-7.1.1.Final.jar:7.1.1.Final] INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.as.server.parsing.StandaloneXml.readElement(StandaloneXml.java:100) [jboss-as-server-7.1.1.Final.jar:7.1.1.Final] INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.staxmapper.XMLMapperImpl.processNested(XMLMapperImpl.java:110) [staxmapper-1.1.0.Final.jar:1.1.0.Final] INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.staxmapper.XMLMapperImpl.parseDocument(XMLMapperImpl.java:69) [staxmapper-1.1.0.Final.jar:1.1.0.Final] INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.as.controller.persistence.XmlConfigurationPersister.load(XmlConfigurationPersister.java:133) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final] INFO | jvm 1 | 2012/07/11 23:14:18 | ... 3 more INFO | jvm 1 | 2012/07/11 23:14:18 | Caused by: java.util.concurrent.ExecutionException: javax.xml.stream.XMLStreamException: JBAS014674: Failed to load module INFO | jvm 1 | 2012/07/11 23:14:18 | at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222) [rt.jar:1.6.0_16] INFO | jvm 1 | 2012/07/11 23:14:18 | at java.util.concurrent.FutureTask.get(FutureTask.java:83) [rt.jar:1.6.0_16] INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.as.controller.parsing.ExtensionXml.parseExtensions(ExtensionXml.java:146) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final] INFO | jvm 1 | 2012/07/11 23:14:18 | ... 9 more INFO | jvm 1 | 2012/07/11 23:14:18 | Caused by: javax.xml.stream.XMLStreamException: JBAS014674: Failed to load module INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.as.controller.parsing.ExtensionXml.loadModule(ExtensionXml.java:195) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final] INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.as.controller.parsing.ExtensionXml.access$000(ExtensionXml.java:68) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final] INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.as.controller.parsing.ExtensionXml$1.call(ExtensionXml.java:126) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final] INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.as.controller.parsing.ExtensionXml$1.call(ExtensionXml.java:123) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final] INFO | jvm 1 | 2012/07/11 23:14:18 | at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) [rt.jar:1.6.0_16] INFO | jvm 1 | 2012/07/11 23:14:18 | at java.util.concurrent.FutureTask.run(FutureTask.java:138) [rt.jar:1.6.0_16] INFO | jvm 1 | 2012/07/11 23:14:18 | at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [rt.jar:1.6.0_16] INFO | jvm 1 | 2012/07/11 23:14:18 | at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [rt.jar:1.6.0_16] INFO | jvm 1 | 2012/07/11 23:14:18 | at java.lang.Thread.run(Thread.java:619) [rt.jar:1.6.0_16] INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.threads.JBossThread.run(JBossThread.java:122) [jboss-threads-2.0.0.GA.jar:2.0.0.GA] INFO | jvm 1 | 2012/07/11 23:14:18 | Caused by: org.jboss.modules.ModuleLoadException: Error loading module from C:\Program Files (x86)\CA\Cloud Insight\JBOSS7\modules\org\jboss\as\cmp\main\module.xml INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.modules.ModuleXmlParser.parseModuleXml(ModuleXmlParser.java:292) [jboss-modules.jar:1.1.1.GA] INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.modules.ModuleXmlParser.parseModuleXml(ModuleXmlParser.java:242) [jboss-modules.jar:1.1.1.GA] INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.modules.LocalModuleLoader.parseModuleInfoFile(LocalModuleLoader.java:138) [jboss-modules.jar:1.1.1.GA] INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.modules.LocalModuleLoader.findModule(LocalModuleLoader.java:122) [jboss-modules.jar:1.1.1.GA] INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.modules.ModuleLoader.loadModuleLocal(ModuleLoader.java:275) [jboss-modules.jar:1.1.1.GA] INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.modules.ModuleLoader.preloadModule(ModuleLoader.java:222) [jboss-modules.jar:1.1.1.GA] INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.modules.LocalModuleLoader.preloadModule(LocalModuleLoader.java:94) [jboss-modules.jar:1.1.1.GA] INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.modules.ModuleLoader.loadModule(ModuleLoader.java:204) [jboss-modules.jar:1.1.1.GA] INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.as.controller.parsing.ExtensionXml.loadModule(ExtensionXml.java:177) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final] INFO | jvm 1 | 2012/07/11 23:14:18 | ... 9 more INFO | jvm 1 | 2012/07/11 23:14:18 | Caused by: javax.xml.stream.XMLStreamException: ParseError at [row,col]:[30,13] INFO | jvm 1 | 2012/07/11 23:14:18 | Message: The string "--" is not permitted within comments. INFO | jvm 1 | 2012/07/11 23:14:18 | at com.sun.org.apache.xerces.internal.impl.XMLStreamReaderImpl.next(XMLStreamReaderImpl.java:588) [rt.jar:1.6.0_16] INFO | jvm 1 | 2012/07/11 23:14:18 | at com.sun.org.apache.xerces.internal.impl.XMLStreamReaderImpl.nextTag(XMLStreamReaderImpl.java:1219) [rt.jar:1.6.0_16] INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.modules.ModuleXmlParser.parseDocument(ModuleXmlParser.java:539) [jboss-modules.jar:1.1.1.GA] INFO | jvm 1 | 2012/07/11 23:14:18 | at org.jboss.modules.ModuleXmlParser.parseModuleXml(ModuleXmlParser.java:287) [jboss-modules.jar:1.1.1.GA] INFO | jvm 1 | 2012/07/11 23:14:18 | ... 17 more INFO | jvm 1 | 2012/07/11 23:14:18 | INFO | jvm 1 | 2012/07/11 23:14:18 | 23:14:18,578 FATAL [org.jboss.as.server] JBAS015957: Server boot has failed in an unrecoverable manner; exiting. See previous messages for details. INFO | jvm 1 | 2012/07/11 23:14:18 | 23:14:18,656 INFO [org.jboss.as] JBAS015950: JBoss AS 7.1.1.Final "Brontes" stopped in 65ms I looked in the standalone.xml and didn't find any -- at line 30