Intermittent Module Parse Error Starting JBoss 7.1.1

[dabramov]

Hi,

About every maybe ~20-30 times I start JBoss AS 7.1.1 I'll get a parse error trying load one of the core modules. If I try again - without modifications - it will just work. This has happened now on three different servers (all running RHEL5). The actual module which is affected varies.

Anyone else seen this? Or better yet have any ideas how to fix it?

Thanks,

-Dan

My server.log from last night's failed build:

21:38:03,938 INFO  [org.jboss.modules] JBoss Modules version 1.1.1.GA
21:38:04,195 INFO  [org.jboss.msc] JBoss MSC version 1.0.2.GA
21:38:04,297 INFO  [org.jboss.as] JBAS015899: JBoss AS 7.1.1.Final "Brontes" starting
21:38:05,835 ERROR [org.jboss.as.server] JBAS015956: Caught exception during boot: org.jboss.as.controller.persistence.ConfigurationPersistenceException: JBAS014676: Failed to parse configuration
        at org.jboss.as.controller.persistence.XmlConfigurationPersister.load(XmlConfigurationPersister.java:141) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final]
        at org.jboss.as.server.ServerService.boot(ServerService.java:266) [jboss-as-server-7.1.1.Final.jar:7.1.1.Final]
        at org.jboss.as.controller.AbstractControllerService$1.run(AbstractControllerService.java:155) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final]
        at java.lang.Thread.run(Thread.java:619) [rt.jar:1.6.0_10]
Caused by: javax.xml.stream.XMLStreamException: Failed to load module org.jboss.as.jaxr
        at org.jboss.as.controller.parsing.ExtensionXml.parseExtensions(ExtensionXml.java:154) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final]
        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]
        at org.jboss.as.server.parsing.StandaloneXml.readElement(StandaloneXml.java:127) [jboss-as-server-7.1.1.Final.jar:7.1.1.Final]
        at org.jboss.as.server.parsing.StandaloneXml.readElement(StandaloneXml.java:100) [jboss-as-server-7.1.1.Final.jar:7.1.1.Final]
        at org.jboss.staxmapper.XMLMapperImpl.processNested(XMLMapperImpl.java:110) [staxmapper-1.1.0.Final.jar:1.1.0.Final]
        at org.jboss.staxmapper.XMLMapperImpl.parseDocument(XMLMapperImpl.java:69) [staxmapper-1.1.0.Final.jar:1.1.0.Final]
        at org.jboss.as.controller.persistence.XmlConfigurationPersister.load(XmlConfigurationPersister.java:133) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final]
        ... 3 more
Caused by: java.util.concurrent.ExecutionException: javax.xml.stream.XMLStreamException: JBAS014674: Failed to load module
        at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222) [rt.jar:1.6.0_10]
        at java.util.concurrent.FutureTask.get(FutureTask.java:83) [rt.jar:1.6.0_10]
        at org.jboss.as.controller.parsing.ExtensionXml.parseExtensions(ExtensionXml.java:146) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final]
        ... 9 more
Caused by: javax.xml.stream.XMLStreamException: JBAS014674: Failed to load module
        at org.jboss.as.controller.parsing.ExtensionXml.loadModule(ExtensionXml.java:195) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final]
        at org.jboss.as.controller.parsing.ExtensionXml.access$000(ExtensionXml.java:68) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final]
        at org.jboss.as.controller.parsing.ExtensionXml$1.call(ExtensionXml.java:126) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final]
        at org.jboss.as.controller.parsing.ExtensionXml$1.call(ExtensionXml.java:123) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final]
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) [rt.jar:1.6.0_10]
        at java.util.concurrent.FutureTask.run(FutureTask.java:138) [rt.jar:1.6.0_10]
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [rt.jar:1.6.0_10]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [rt.jar:1.6.0_10]
        at java.lang.Thread.run(Thread.java:619) [rt.jar:1.6.0_10]
        at org.jboss.threads.JBossThread.run(JBossThread.java:122) [jboss-threads-2.0.0.GA.jar:2.0.0.GA]
Caused by: org.jboss.modules.ModuleLoadException: Error loading module from /usr/local/litle-tools/jboss-as-7.1.1.Final/modules/org/jboss/as/jaxr/main/module.xml
        at org.jboss.modules.ModuleXmlParser.parseModuleXml(ModuleXmlParser.java:292) [jboss-modules.jar:1.1.1.GA]
        at org.jboss.modules.ModuleXmlParser.parseModuleXml(ModuleXmlParser.java:242) [jboss-modules.jar:1.1.1.GA]
        at org.jboss.modules.LocalModuleLoader.parseModuleInfoFile(LocalModuleLoader.java:138) [jboss-modules.jar:1.1.1.GA]
        at org.jboss.modules.LocalModuleLoader.findModule(LocalModuleLoader.java:122) [jboss-modules.jar:1.1.1.GA]
        at org.jboss.modules.ModuleLoader.loadModuleLocal(ModuleLoader.java:275) [jboss-modules.jar:1.1.1.GA]
        at org.jboss.modules.ModuleLoader.preloadModule(ModuleLoader.java:222) [jboss-modules.jar:1.1.1.GA]
        at org.jboss.modules.LocalModuleLoader.preloadModule(LocalModuleLoader.java:94) [jboss-modules.jar:1.1.1.GA]
        at org.jboss.modules.ModuleLoader.loadModule(ModuleLoader.java:204) [jboss-modules.jar:1.1.1.GA]
        at org.jboss.as.controller.parsing.ExtensionXml.loadModule(ExtensionXml.java:177) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final]
        ... 9 more
Caused by: javax.xml.stream.XMLStreamException: ParseError at [row,col]:[36,35]
Message: Unexpected content of type 'element start' named '{urn:jboss:module:1.1}module'
        at org.jboss.modules.ModuleXmlParser.unexpectedContent(ModuleXmlParser.java:355) [jboss-modules.jar:1.1.1.GA]
        at org.jboss.modules.ModuleXmlParser.parseModuleContents(ModuleXmlParser.java:678) [jboss-modules.jar:1.1.1.GA]
        at org.jboss.modules.ModuleXmlParser.parseDocument(ModuleXmlParser.java:548) [jboss-modules.jar:1.1.1.GA]
        at org.jboss.modules.ModuleXmlParser.parseModuleXml(ModuleXmlParser.java:287) [jboss-modules.jar:1.1.1.GA]
        ... 17 more
21:38:05,867 FATAL [org.jboss.as.server] JBAS015957: Server boot has failed in an unrecoverable manner; exiting. See previous messages for details.
21:38:05,893 INFO  [org.jboss.as] JBAS015950: JBoss AS 7.1.1.Final "Brontes" stopped in 3ms

[jaikiran]

This is actually the first time I'm seeing this being reported. Which OS are you on and what vendor and version of Java runtime are you using (output of java -version from that command prompt). Have you done any changes to any of the configs that are shipped in AS7?

[dabramov]

Hi Jakiran,

We're using RedHat EL5. The Java version is Sun JDK 1.5.0_10. In terms of modifications: Please let me know if there's any more information I can gather to try and understand this better.

1) We've added some packages back in to the module.xml for the JDK, by added the following lines:

     <path name="com/sun/jndi/url/rmi"/>

     <path name="sun/rmi/server"/>

     <path name="sun/security/rsa"/>

2) We've added a new module (com.ibm.db2) to support a DB2 JDBC driver

3) We've made various modifications to our standalone.xml - changing ports, removing OSGI (though this issue definiitely  predates that change), adding topics, datasources, etc.

4) We're specifying -Djboss.server.base.dir to an alternate location, since multiple standalone instances share the same base install. I am, however, 100% certain that I've seen this issue when no other JBoss processes are running/starting.

----

[linuser1@l-dabramov-ws490@release_vap_jboss_upgrade_branch:fevap]uname -a

Linux l-dabramov-ws490 2.6.18-274.18.1.el5 #1 SMP Fri Jan 20 15:11:18 EST 2012 x86_64 x86_64 x86_64 GNU/Linux

[linuser1@l-dabramov-ws490@release_vap_jboss_upgrade_branch:fevap]java -version

java version "1.6.0_10"

Java(TM) SE Runtime Environment (build 1.6.0_10-b33)

Java HotSpot(TM) Server VM (build 11.0-b15, mixed mode)

Thanks,

-Dan

[dabramov]

We hit a a maybe slightly different variation of this again last night. The stack is slighlty different so maybe helpful. The next attempt to start the server - without any changes - started just fine.

I notice that the stacks contains a java.util.concurrent.ExecutionException, so I'm assuming JBoss is loading in parallel. This could introduce the kind of timing issue/randomness that we're seeing. Maybe I'm oversimplifying, but perhaps there is a synchronization issue if module A and B are both trying to read module C at the same time?

Does anyone have a suggestion at least for any debug logging we could turn on to help troubleshoot this?

Here's the new stack:

11:13:16,910 ERROR [org.jboss.as.server] JBAS015956: Caught exception during boot: org.jboss.as.controller.persistence.ConfigurationPersistenceException: JBAS014676: Failed to parse configuration

        at org.jboss.as.controller.persistence.XmlConfigurationPersister.load(XmlConfigurationPersister.java:141) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final]

        at org.jboss.as.server.ServerService.boot(ServerService.java:266) [jboss-as-server-7.1.1.Final.jar:7.1.1.Final]

        at org.jboss.as.controller.AbstractControllerService$1.run(AbstractControllerService.java:155) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final]

        at java.lang.Thread.run(Thread.java:619) [rt.jar:1.6.0_10]

Caused by: javax.xml.stream.XMLStreamException: Failed to load module org.jboss.as.cmp

        at org.jboss.as.controller.parsing.ExtensionXml.parseExtensions(ExtensionXml.java:154) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final]

        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]

        at org.jboss.as.server.parsing.StandaloneXml.readElement(StandaloneXml.java:127) [jboss-as-server-7.1.1.Final.jar:7.1.1.Final]

        at org.jboss.as.server.parsing.StandaloneXml.readElement(StandaloneXml.java:100) [jboss-as-server-7.1.1.Final.jar:7.1.1.Final]

        at org.jboss.staxmapper.XMLMapperImpl.processNested(XMLMapperImpl.java:110) [staxmapper-1.1.0.Final.jar:1.1.0.Final]

        at org.jboss.staxmapper.XMLMapperImpl.parseDocument(XMLMapperImpl.java:69) [staxmapper-1.1.0.Final.jar:1.1.0.Final]

        at org.jboss.as.controller.persistence.XmlConfigurationPersister.load(XmlConfigurationPersister.java:133) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final]

        ... 3 more

Caused by: java.util.concurrent.ExecutionException: javax.xml.stream.XMLStreamException: JBAS014674: Failed to load module

        at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222) [rt.jar:1.6.0_10]

        at java.util.concurrent.FutureTask.get(FutureTask.java:83) [rt.jar:1.6.0_10]

        at org.jboss.as.controller.parsing.ExtensionXml.parseExtensions(ExtensionXml.java:146) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final]

        ... 9 more

Caused by: javax.xml.stream.XMLStreamException: JBAS014674: Failed to load module

        at org.jboss.as.controller.parsing.ExtensionXml.loadModule(ExtensionXml.java:195) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final]

        at org.jboss.as.controller.parsing.ExtensionXml.access$000(ExtensionXml.java:68) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final]

        at org.jboss.as.controller.parsing.ExtensionXml$1.call(ExtensionXml.java:126) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final]

        at org.jboss.as.controller.parsing.ExtensionXml$1.call(ExtensionXml.java:123) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final]

        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) [rt.jar:1.6.0_10]

        at java.util.concurrent.FutureTask.run(FutureTask.java:138) [rt.jar:1.6.0_10]

        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [rt.jar:1.6.0_10]

        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [rt.jar:1.6.0_10]

        at java.lang.Thread.run(Thread.java:619) [rt.jar:1.6.0_10]

        at org.jboss.threads.JBossThread.run(JBossThread.java:122) [jboss-threads-2.0.0.GA.jar:2.0.0.GA]

Caused by: org.jboss.modules.ModuleNotFoundException: org.jboss.as.ejb3:main

        at org.jboss.modules.ModuleLoader$FutureModule.getModule(ModuleLoader.java:511) [jboss-modules.jar:1.1.1.GA]

        at org.jboss.modules.ModuleLoader.loadModuleLocal(ModuleLoader.java:261) [jboss-modules.jar:1.1.1.GA]

        at org.jboss.modules.ModuleLoader.preloadModule(ModuleLoader.java:222) [jboss-modules.jar:1.1.1.GA]

        at org.jboss.modules.LocalModuleLoader.preloadModule(LocalModuleLoader.java:94) [jboss-modules.jar:1.1.1.GA]

        at org.jboss.modules.Module.addPaths(Module.java:841) [jboss-modules.jar:1.1.1.GA]

        at org.jboss.modules.Module.link(Module.java:1181) [jboss-modules.jar:1.1.1.GA]

        at org.jboss.modules.Module.relinkIfNecessary(Module.java:1207) [jboss-modules.jar:1.1.1.GA]

        at org.jboss.modules.ModuleLoader.loadModule(ModuleLoader.java:208) [jboss-modules.jar:1.1.1.GA]

        at org.jboss.as.controller.parsing.ExtensionXml.loadModule(ExtensionXml.java:177) [jboss-as-controller-7.1.1.Final.jar:7.1.1.Final]

        ... 9 more

[meyers79]

Daniel you ever find any resolution to this, we are encountering similiar issue in JBoss 6 EAP. . .

- Matthew

[dabramov]

Hi Matthew,

No, I'm sorry we never did find a resolution. Our only work around was to have our own application start scripts detect the condition and retry. But if you are using EAP, might as well put support to work.

-Dan

[nickarls]

It sounds a bit strange, one would think there would be many reports of this if it was frequent. Perhaps some strange combination of OS version, JRE version and number of processors? One would think concurrent read-only access to a XML file would be allowed.

[jaikiran]

FYI https://issues.jboss.org/browse/MODULES-142

[meyers79]

Thanks for the post Jaikiran, looking at it lead me to look into my JDK version. I have updated from 1.6.0_16 to 1.6.0_37 and have run with out an issue for the past few days. Typically I see the issue multiple times a day. So fingers crossed it holds, but seems thus far the issue is resolved with a JDK change.

- Matthew