Uploaded image for project: 'WildFly'
  1. WildFly
  2. WFLY-851

OOME while paging leads to endless NPE and queues stop working

    Details

    • Type: Bug
    • Status: Closed (View Workflow)
    • Priority: Major
    • Resolution: Out of Date
    • Affects Version/s: None
    • Fix Version/s: None
    • Component/s: JMS
    • Labels:
    • Steps to Reproduce:
      Hide

      I wrote the long story above because this happens in a scenario I didn't figure out yet - I will try to reproduce again and update here

      Show
      I wrote the long story above because this happens in a scenario I didn't figure out yet - I will try to reproduce again and update here

      Description

      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

        Gliffy Diagrams

          Attachments

            Activity

              People

              • Assignee:
                ataylor Andy Taylor
                Reporter:
                NewWay Noa Drach
              • Votes:
                0 Vote for this issue
                Watchers:
                3 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: