How to log with slf4j from within a jboss module?

Question

How can I log to console / server.log from within a jboss module?

Say that I have a class:

public class MyClass {

    private static final Logger logger = LoggerFactory.getLogger(MyClass.class);

    private boolean done = false;

    public void doSomething() {
        logger.info("Look ma, I'm logging!");
        done = true;
    }

    public boolean isDone() {
        return done;
    }
}

If I want to log from a deployed artifact (e.g., MyWebProject.war), all I have to do is:

Compile against slf4j-api

<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-api</artifactId>
    <version>1.7.7</version>
    <scope>provided</scope>
</dependency>

Deploy

./jboss-cli.sh -c "deploy  MyWebProject.war"

Profit

2015-10-19 11:04:02,445 INFO  [com.myCompany.MyClass] (default task-13) Look ma, I'm logging!

But for the life of mine, I can't manage to do the same from within a jboss module.

Example: If MyWebProject.war uses MyModule.jar, and MyModule.jar is deployed as a jboss module:

${jbossHome}/modules/com/mycompany/mymodule/main
                                            |____ MyModule.jar
                                            |____ module.xml

Module.xml

<?xml version="1.0" encoding="UTF-8"?>
<module xmlns="urn:jboss:module:1.1" name="com.mycompany.mymodule">
  <resources>
    <resource-root path="MyModule.jar" />
  </resources>
  <dependencies>
    <module name="org.slf4j" />
  </dependencies>
</module>

If I move MyClass into MyModule.jar and use it from MyWebProject.war I can see the side effects (e.g., isDone() == true) but nothing is written to server.log.

What am I missing? Do I need any other module dependencies but slf4j?

That's all you should have to do. How are you invoking the `doSomething()`? — James R. Perkins, Oct 19 '15 at 22:17
Hi James. Original user case is `MyClass myClass = new MyClass(); myClass.doSomething()` from a Servlet in `MyWebProject.war` (with a proper dependency declaration to module `com.mycompany.mymodule` on `jboss-deployment-structure.xml`. I have also tried to create a main class for the module and run it with `java -jar jboss-modules.jar -mp modules com.mycompany.mymodule`. In both cases I can see that `isDone==true`, but nothing is written to `server.log`. — Anthony Accioly, Oct 20 '15 at 08:10
Hmm... ..odd. It seems to work for me `10:44:03,226 INFO [org.jboss.example.Slf4jLogTest] (default task-3) Look ma, I'm logging!`. I tested this on WildFly 10.0.0.CR3, but not much has changed with logging so I doubt that's it. — James R. Perkins, Oct 20 '15 at 17:45
Hi James. Good to know that. I'm using Wildfly 9.0.1 Final, let me try to isolate this example and I'll provide the repos. — Anthony Accioly, Oct 21 '15 at 06:18
@James, please have a look at my answer. Can you try to reproduce the same issue with the latest version of Wildfly? If so, and if it is still a unknown bug I will be happy to raise a ticket. Cheers — Anthony Accioly, Oct 28 '15 at 19:15

Anthony Accioly · Accepted Answer · 2015-10-28T19:46:22.603

For further reference, my problem had nothing to do with logging. The above recipe works as expected. In fact I've suffered because of a red herring: my original module.xml was never really used. I was actually loading a old class with the same name in another module. This old version of the class had no logging and should not be there to begin with.

Anyway, I think that the root cause of my problem (besides my lack of attention) was a small bug in jboss-cli.

I was deploying mymodule with the following command:

module add --name=com.mycompany.mymodule \
            --resources=MyModule.jar \
            --dependencies=org.slf4j \
            --main-class=com.mycompany.mymodule.Main

This command was generating a module.xml like this:

<?xml version="1.0" ?>

<module xmlns="urn:jboss:module:1.1" name="com.mycompany.mymodule">

    <main-class value="com.mycompany.mymodule.Main"/>

    <resources>
        <resource-root path="MyModule.jar"/>
    </resources>

    <dependencies>
        <module name="org.slf4j"/>
    </dependencies>
</module>

When I've finally managed to get my web project to try to load mymodule it failed with a stack trace such as:

18:45:59,999 ERROR [org.jboss.msc.service.fail] (MSC service thread 1-7) MSC000001: Failed to start service jboss.module.service."deployment.MyWebProject.war".main: org.jboss.msc.service.StartException in service jboss.module.service."deployment.MyWebProject.war".main: WFLYSRV0179: Failed to load module: deployment.MyWebProject.war.war:main
    at org.jboss.as.server.moduleservice.ModuleLoadService.start(ModuleLoadService.java:91)
    at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1948)
    at org.jboss.msc.service.ServiceControllerImpl$StartTask.run(ServiceControllerImpl.java:1881)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
Caused by: org.jboss.modules.ModuleLoadException: Error loading module from C:\opt\server\wildfly-9.0.1.Final\modules\com\mycompany\mymodule\main\module.xml
    at org.jboss.modules.ModuleXmlParser.parseModuleXml(ModuleXmlParser.java:150)
    at org.jboss.modules.ModuleXmlParser.parseModuleXml(ModuleXmlParser.java:127)
    at org.jboss.modules.LocalModuleFinder$1.run(LocalModuleFinder.java:150)
    at org.jboss.modules.LocalModuleFinder$1.run(LocalModuleFinder.java:144)
    at java.security.AccessController.doPrivileged(Native Method)
    at org.jboss.modules.LocalModuleFinder.findModule(LocalModuleFinder.java:144)
    at org.jboss.modules.ModuleLoader.findModule(ModuleLoader.java:452)
    at org.jboss.modules.ModuleLoader.loadModuleLocal(ModuleLoader.java:355)
    at org.jboss.modules.ModuleLoader.preloadModule(ModuleLoader.java:302)
    at org.jboss.modules.ModuleLoader.preloadExportedModule(ModuleLoader.java:313)
    at org.jboss.modules.ModuleLoader.preloadModule(ModuleLoader.java:326)
    at org.jboss.as.server.moduleservice.ServiceModuleLoader.preloadModule(ServiceModuleLoader.java:149)
    at org.jboss.modules.ModuleLoader.loadModule(ModuleLoader.java:234)
    at org.jboss.as.server.moduleservice.ModuleLoadService.start(ModuleLoadService.java:74)
    ... 5 more
Caused by: org.jboss.modules.xml.XmlPullParserException: Unexpected content of type 'element start' named 'main-class', text is: '<main-class value="com.mycompany.mymodule.Main"/>' (position: START_TAG seen ...n-class value="com.mycompany.mymodule.Main"/>... @5:54) 
    at org.jboss.modules.ModuleXmlParser.unexpectedContent(ModuleXmlParser.java:179)
    at org.jboss.modules.ModuleXmlParser.parseMainClass(ModuleXmlParser.java:620)
    at org.jboss.modules.ModuleXmlParser.parseModuleContents(ModuleXmlParser.java:445)
    at org.jboss.modules.ModuleXmlParser.parseDocument(ModuleXmlParser.java:261)
    at org.jboss.modules.ModuleXmlParser.parseModuleXml(ModuleXmlParser.java:148)
    ... 18 more

Taking a look at module-1_1.xsd I've found out that the main-class element was expecting a name attribute instead of a value attribute. So I've manually changed the module.xml to:

<main-class name="com.mycompany.mymodule.Main"/>

After I've restarted WildFly and redeployed my web project everything worked as expected.

How to log with slf4j from within a jboss module?

Module.xml

1 Answers1