[wildfly-dev] Misleading error message on extension add failure

Wed May 8 10:15:27 EDT 2013


----- Original Message -----
> From: "Brian Stansberry" <brian.stansberry at redhat.com>
> To: wildfly-dev at lists.jboss.org
> Sent: Wednesday, May 8, 2013 4:01:20 PM
> Subject: Re: [wildfly-dev] Misleading error message on extension add failure
> 
> 1. This is because it is a post-boot error that did not affect the
> runtime and thus hasn't had any negative effect on the operation of the
> process. A post-boot management operation has a caller; the failure
> response is sent to the caller to deal with. The caller should be
> looking at the response, not the log.
> 
> The rationale for this is analogous to not logging an ERROR for every
> EJB invocation failure.
> 
> 2. This is because the detail information might be useful, so we do log it.
+1, I dont deny this. I would make this a "WARN" not "DEBUG" - since its not a "failed EJB invocation" - it is a parse/model change failure.
> 
> 3. This is a mistake in ExtensionAddHandler L103 -- when it creates the
> OperationFailedException it should pass the cause into the constructor.
> 
Roger.
> On 5/8/13 3:18 AM, Bartosz Baranowski wrote:
> >
> > Im not sure what is a general policy about logging such things but... it
> > seems odd. If Im wrong, please ignore.
> >
> > Ive been playing with extension test cases and here is what I found out:
> >
> > 1. If Extension Add handler fails, no error/warn message is displayed.
> > 2. Above is false IF level is set to debug:
> >
> > :59,685 DEBUG org.jboss.as.controller.management-operation JBAS014616:
> > Operation ("add") failed - address: ([("extension" => "jmxrmiconnector")])
> > - failure description: "org.jboss.modules.ModuleLoadException: Error
> > loading module from
> > /home/baranowb/redhat/git/jboss-as/testsuite/integration/basic/../../../build/target/wildfly-8.0.0.Alpha1-SNAPSHOT/modules/jmxrmiconnector/main/module.xml"
> >
> > 3. Above message is cryptic at best - "Error loading module" - what error,
> > where, why?
> >
> > Full stack trace for #2
> >
> > 15:06:26,373 ERROR stderr org.jboss.modules.ModuleLoadException: Error
> > loading module from
> > /home/baranowb/redhat/git/jboss-as/testsuite/integration/basic/../../../build/target/wildfly-8.0.0.Alpha1-SNAPSHOT/modules/jmxrmiconnector/main/module.xml
> > 15:06:26,373 ERROR stderr at
> > org.jboss.modules.ModuleXmlParser.parseModuleXml(ModuleXmlParser.java:292)
> > 15:06:26,374 ERROR stderr at
> > org.jboss.modules.ModuleXmlParser.parseModuleXml(ModuleXmlParser.java:256)
> > 15:06:26,374 ERROR stderr at
> > org.jboss.modules.LocalModuleFinder$1.run(LocalModuleFinder.java:144)
> > 15:06:26,374 ERROR stderr at
> > org.jboss.modules.LocalModuleFinder$1.run(LocalModuleFinder.java:138)
> > 15:06:26,374 ERROR stderr at
> > java.security.AccessController.doPrivileged(Native Method)
> > 15:06:26,375 ERROR stderr at
> > org.jboss.modules.LocalModuleFinder.findModule(LocalModuleFinder.java:138)
> > 15:06:26,375 ERROR stderr at
> > org.jboss.modules.ModuleLoader.findModule(ModuleLoader.java:389)
> > 15:06:26,375 ERROR stderr at
> > org.jboss.modules.ModuleLoader.loadModuleLocal(ModuleLoader.java:293)
> > 15:06:26,376 ERROR stderr at
> > org.jboss.modules.ModuleLoader.preloadModule(ModuleLoader.java:240)
> > 15:06:26,376 ERROR stderr at
> > org.jboss.modules.ModuleLoader.loadModule(ModuleLoader.java:222)
> > 15:06:26,376 ERROR stderr at
> > org.jboss.modules.Module.loadServiceFromCallerModuleLoader(Module.java:322)
> > 15:06:26,377 ERROR stderr at
> > org.jboss.as.controller.extension.ExtensionAddHandler.initializeExtension(ExtensionAddHandler.java:84)
> > 15:06:26,377 ERROR stderr at
> > org.jboss.as.controller.extension.ExtensionAddHandler.execute(ExtensionAddHandler.java:70)
> > 15:06:26,378 ERROR stderr at
> > org.jboss.as.controller.AbstractOperationContext.executeStep(AbstractOperationContext.java:439)
> > 15:06:26,378 ERROR stderr at
> > org.jboss.as.controller.AbstractOperationContext.doCompleteStep(AbstractOperationContext.java:321)
> > 15:06:26,379 ERROR stderr at
> > org.jboss.as.controller.AbstractOperationContext.completeStepInternal(AbstractOperationContext.java:228)
> > 15:06:26,380 ERROR stderr at
> > org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:223)
> > 15:06:26,380 ERROR stderr at
> > org.jboss.as.controller.ModelControllerImpl.internalExecute(ModelControllerImpl.java:235)
> > 15:06:26,381 ERROR stderr at
> > org.jboss.as.controller.ModelControllerImpl.execute(ModelControllerImpl.java:124)
> > 15:06:26,381 ERROR stderr at
> > org.jboss.as.controller.remote.ModelControllerClientOperationHandler$ExecuteRequestHandler.doExecute(ModelControllerClientOperationHandler.java:148)
> > 15:06:26,382 ERROR stderr at
> > org.jboss.as.controller.remote.ModelControllerClientOperationHandler$ExecuteRequestHandler.access$300(ModelControllerClientOperationHandler.java:97)
> > 15:06:26,382 ERROR stderr at
> > org.jboss.as.controller.remote.ModelControllerClientOperationHandler$ExecuteRequestHandler$1.execute(ModelControllerClientOperationHandler.java:114)
> > 15:06:26,382 ERROR stderr at
> > org.jboss.as.protocol.mgmt.AbstractMessageHandler$2$1.doExecute(AbstractMessageHandler.java:296)
> > 15:06:26,383 ERROR stderr at
> > org.jboss.as.protocol.mgmt.AbstractMessageHandler$AsyncTaskRunner.run(AbstractMessageHandler.java:518)
> > 15:06:26,383 ERROR stderr at
> > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> > 15:06:26,383 ERROR stderr at
> > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> > 15:06:26,384 ERROR stderr at java.lang.Thread.run(Thread.java:722)
> > 15:06:26,384 ERROR stderr at
> > org.jboss.threads.JBossThread.run(JBossThread.java:122)
> > 15:06:26,385 ERROR stderr Caused by: javax.xml.stream.XMLStreamException:
> > ParseError at [row,col]:[21,52]
> > 15:06:26,385 ERROR stderr Message: Failed to add resource root
> > 'service-loader-resources' at path 'service-loader-resources'
> > 15:06:26,385 ERROR stderr at
> > org.jboss.modules.ModuleXmlParser.parseResourceRoot(ModuleXmlParser.java:756)
> > 15:06:26,386 ERROR stderr at
> > org.jboss.modules.ModuleXmlParser.parseResources(ModuleXmlParser.java:712)
> > 15:06:26,386 ERROR stderr at
> > org.jboss.modules.ModuleXmlParser.parseModuleContents(ModuleXmlParser.java:538)
> > 15:06:26,386 ERROR stderr at
> > org.jboss.modules.ModuleXmlParser.parseDocument(ModuleXmlParser.java:369)
> > 15:06:26,387 ERROR stderr at
> > org.jboss.modules.ModuleXmlParser.parseModuleXml(ModuleXmlParser.java:287)
> > 15:06:26,387 ERROR stderr ... 27 more
> >
> >
> >
> > Here is link to commit:
> > https://github.com/wildfly/wildfly/commit/3973d7cd2edcf913461dc65902ff471689452bb7#commitcomment-3131977
> > _______________________________________________
> > wildfly-dev mailing list
> > wildfly-dev at lists.jboss.org
> > https://lists.jboss.org/mailman/listinfo/wildfly-dev
> >
> 
> 
> --
> Brian Stansberry
> Principal Software Engineer
> JBoss by Red Hat
> _______________________________________________
> wildfly-dev mailing list
> wildfly-dev at lists.jboss.org
> https://lists.jboss.org/mailman/listinfo/wildfly-dev
>