4

I am trying to set up a Wildfly Swarm based project to log with log4j 2 through slf4j. I have already tried a few things reaching some kind of compromise, that I will base my question on (maybe it's of help to others). Yet my solution is nothing I am fully satisfied with, so I am curious to see if someone can give hints on how to improve my project setup.

First of all, my pom.xml:

<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/maven-v4_0_0.xsd">
<modelVersion>4.0.0</modelVersion>
<groupId>test</groupId>
<artifactId>BasicWildflySwarm</artifactId>
<packaging>war</packaging>
<version>0.0.1-SNAPSHOT</version>
<name>BasicWildflySwarm Maven Webapp</name>
<url>http://maven.apache.org</url>

<properties>
    <version.wildfly.swarm>2017.9.5</version.wildfly.swarm>
    <maven.compiler.source>1.8</maven.compiler.source>
    <maven.compiler.target>1.8</maven.compiler.target>
    <failOnMissingWebXml>false</failOnMissingWebXml>
    <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
</properties>

<dependencyManagement>
    <dependencies>
        <dependency>
            <groupId>org.wildfly.swarm</groupId>
            <artifactId>bom</artifactId>
            <version>${version.wildfly.swarm}</version>
            <scope>import</scope>
            <type>pom</type>
        </dependency>
    </dependencies>
</dependencyManagement>

<build>
    <finalName>BasicwildflySwarm</finalName>
    <plugins>
        <plugin>
            <groupId>org.wildfly.swarm</groupId>
            <artifactId>wildfly-swarm-plugin</artifactId>
            <version>${version.wildfly.swarm}</version>
            <executions>
                <execution>
                    <goals>
                        <goal>package</goal>
                    </goals>
                </execution>
            </executions>
            <configuration>
                <jvmArguments>
                    <jvmArgument>-Dlog4j.configurationFile=file://D:/Daten/Java/workspace/BasicWildflySwarm/src/main/webapp/log4j2.xml</jvmArgument>
                    <jvmArgument>-Dorg.apache.logging.log4j.simplelog.StatusLogger.level=TRACE</jvmArgument>
                </jvmArguments>
            </configuration>
        </plugin>
    </plugins>
</build>

<dependencies>
    <dependency>
        <groupId>javax</groupId>
        <artifactId>javaee-api</artifactId>
        <version>7.0</version>
        <scope>provided</scope>
    </dependency>

    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-api</artifactId>
        <version>2.9.0</version>
    </dependency>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-core</artifactId>
        <version>2.9.0</version>
    </dependency>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-slf4j-impl</artifactId>
        <version>2.9.0</version>
    </dependency>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-web</artifactId>
        <version>2.9.0</version>
    </dependency>
</dependencies>

So, I do two things regarding logging:

  • adding the dependencies to log4j2 and the slf4j bridge (seems like slf4j itself is not necessary)
  • setting a jvm argument to point to the log4j2.xml (dirty way, but will suit the example)

Next thing I did is disabling the logging subsystem of wildfly swarm by placing a jboss-deploayment-structure.xml under WEB-INF with the following content:

<jboss-deployment-structure xmlns="urn:jboss:deployment-structure:1.2">
<deployment> 
    <exclude-subsystems>
        <subsystem name="logging"/>
    </exclude-subsystems>
</deployment>

Finally, I created a simple WebListener to test my logging setup:

package main;

import javax.servlet.ServletContextEvent;
import javax.servlet.ServletContextListener;
import javax.servlet.annotation.WebListener;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

@WebListener
public class MyWebListener implements ServletContextListener {

    private static final Logger LOG = LoggerFactory.getLogger(MyWebListener.class);

    public void contextDestroyed(ServletContextEvent arg0) {
        // TODO Auto-generated method stub
    }

    public void contextInitialized(ServletContextEvent sce) {
        LOG.info("Hello world!");
    }
}

Note: of course, there's also a log4j2.xml, but it's not doing anything special, just prints to a file, so quoting it here would not add anything, I think.

Result

Good news is, that my message is written to the log-file. On the downside, the output from the container is written on the console (well, didn't expect it to be in the log-file with these settings, but that's what I'd like to have) and with log4j 2 in version 2.9.0, there's an ugly error message during startup:

ERROR StatusLogger Log4j2 could not find a logging implementation. Please add log4j-core to the classpath. Using SimpleLogger to log to the console...

With other versions of log4j 2, including 2.9.1, it's been even worse:

DEBUG StatusLogger Using ShutdownCallbackRegistry class org.apache.logging.log4j.core.util.DefaultShutdownCallbackRegistry
DEBUG StatusLogger Took 0,000534 seconds to load 0 plugins from org.wildfly.swarm.container.runtime.ExtensionPreventionClassLoaderWrapper@3833da6f
DEBUG StatusLogger Took 0,000890 seconds to load 0 plugins from package org.apache.logging.log4j.core
DEBUG StatusLogger PluginManager 'Converter' found 0 plugins
ERROR StatusLogger Unrecognized format specifier [d]
ERROR StatusLogger Unrecognized conversion specifier [d] starting at position 16 in conversion pattern.
ERROR StatusLogger Unrecognized format specifier [thread]
ERROR StatusLogger Unrecognized conversion specifier [thread] starting at position 25 in conversion pattern.
ERROR StatusLogger Unrecognized format specifier [level]
ERROR StatusLogger Unrecognized conversion specifier [level] starting at position 35 in conversion pattern.
ERROR StatusLogger Unrecognized format specifier [logger]
ERROR StatusLogger Unrecognized conversion specifier [logger] starting at position 47 in conversion pattern.
ERROR StatusLogger Unrecognized format specifier [msg]
ERROR StatusLogger Unrecognized conversion specifier [msg] starting at position 54 in conversion pattern.
ERROR StatusLogger Unrecognized format specifier [n]
ERROR StatusLogger Unrecognized conversion specifier [n] starting at position 56 in conversion pattern.
DEBUG StatusLogger Jansi is not installed, cannot find org.fusesource.jansi.WindowsAnsiOutputStream
DEBUG StatusLogger Starting OutputStreamManager SYSTEM_OUT.false.false-1
DEBUG StatusLogger Starting LoggerContext[name=4aa298b7, org.apache.logging.log4j.core.LoggerContext@5d0c5251]...
DEBUG StatusLogger Reconfiguration started for context[name=4aa298b7] at URI null (org.apache.logging.log4j.core.LoggerContext@5d0c5251) with optional ClassLoader: null
DEBUG StatusLogger PluginManager 'ConfigurationFactory' found 0 plugins
DEBUG StatusLogger Using configurationFactory org.apache.logging.log4j.core.config.ConfigurationFactory$Factory@225be644
ERROR StatusLogger Reconfiguration failed: No configuration found for '4aa298b7' at 'null' in 'null'
DEBUG StatusLogger Shutdown hook enabled. Registering a new one.
DEBUG StatusLogger LoggerContext[name=4aa298b7, org.apache.logging.log4j.core.LoggerContext@5d0c5251] started OK.

Later crashing with:

2017-10-01 14:08:07,162 ERROR [org.jboss.msc.service.fail] (ServerService Thread Pool -- 3) MSC000001: Failed to start service jboss.undertow.deployment.default-server.default-host./: org.jboss.msc.service.StartException in service jboss.undertow.deployment.default-server.default-host./: java.util.ServiceConfigurationError: org.apache.logging.log4j.spi.Provider: Provider org.apache.logging.log4j.core.impl.Log4jProvider not a subtype
at org.wildfly.extension.undertow.deployment.UndertowDeploymentService$1.run(UndertowDeploymentService.java:85)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
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:748)
at org.jboss.threads.JBossThread.run(JBossThread.java:320)
Caused by: java.util.ServiceConfigurationError: org.apache.logging.log4j.spi.Provider: Provider org.apache.logging.log4j.core.impl.Log4jProvider not a subtype
at java.util.ServiceLoader.fail(ServiceLoader.java:239)
at java.util.ServiceLoader.access$300(ServiceLoader.java:185)
at java.util.ServiceLoader$LazyIterator.nextService(ServiceLoader.java:376)
at java.util.ServiceLoader$LazyIterator.next(ServiceLoader.java:404)
at java.util.ServiceLoader$1.next(ServiceLoader.java:480)
at org.apache.logging.log4j.util.ProviderUtil.loadProviders(ProviderUtil.java:101)
at org.apache.logging.log4j.util.ProviderUtil.<init>(ProviderUtil.java:67)
at org.apache.logging.log4j.util.ProviderUtil.lazyInit(ProviderUtil.java:142)
at org.apache.logging.log4j.util.ProviderUtil.hasProviders(ProviderUtil.java:126)
at org.apache.logging.log4j.LogManager.<clinit>(LogManager.java:89)
at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getContext(AbstractLoggerAdapter.java:122)
at org.apache.logging.slf4j.Log4jLoggerFactory.getContext(Log4jLoggerFactory.java:43)
at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getLogger(AbstractLoggerAdapter.java:46)
at org.apache.logging.slf4j.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:29)
at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:358)
at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:383)
at main.MyWebListener.<clinit>(MyWebListener.java:17)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at org.jboss.as.ee.component.ConstructorComponentFactory.create(ConstructorComponentFactory.java:24)
at org.jboss.as.ee.component.ComponentInstantiatorInterceptor.processInvocation(ComponentInstantiatorInterceptor.java:67)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
at org.jboss.as.ee.component.AroundConstructInterceptorFactory$1.processInvocation(AroundConstructInterceptorFactory.java:26)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
at org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:45)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:64)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
at org.jboss.invocation.PrivilegedWithCombinerInterceptor.processInvocation(PrivilegedWithCombinerInterceptor.java:80)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
at org.jboss.as.ee.component.BasicComponent.constructComponentInstance(BasicComponent.java:161)
at org.jboss.as.ee.component.BasicComponent.constructComponentInstance(BasicComponent.java:134)
at org.jboss.as.ee.component.BasicComponent.createInstance(BasicComponent.java:88)
at org.jboss.as.ee.component.ComponentRegistry$ComponentManagedReferenceFactory.getReference(ComponentRegistry.java:149)
at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$6.createInstance(UndertowDeploymentInfoService.java:1379)
at io.undertow.servlet.core.ManagedListener.start(ManagedListener.java:48)
at io.undertow.servlet.core.ApplicationListeners.start(ApplicationListeners.java:159)
at io.undertow.servlet.core.DeploymentManagerImpl$1.call(DeploymentManagerImpl.java:175)
at io.undertow.servlet.core.DeploymentManagerImpl$1.call(DeploymentManagerImpl.java:171)
at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:42)
at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44)
at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44)
at io.undertow.servlet.core.DeploymentManagerImpl.deploy(DeploymentManagerImpl.java:234)
at org.wildfly.extension.undertow.deployment.UndertowDeploymentService.startContext(UndertowDeploymentService.java:100)
at org.wildfly.extension.undertow.deployment.UndertowDeploymentService$1.run(UndertowDeploymentService.java:82)
... 6 more

Seems like my solution is rather fragile...

Some additional notes to the problem

As a measure of keeping the answers / discussions focused, I'd like to add some notes:

  • I'd like to have the containers messages log-messages to be logged by log4j 2 to avoid to have two logging configurations. As log4j 2 is already established in my company, I'd like to keep that one. For the same reason, I don't want to have log4j 2 messages routed to wildfly swarms logging system through slf4j.
  • One of our libraries, that I have to use in my final project, we already log against slf4j, so I don't want to have to log against log4j 2 directly. Well, at least this problem seems to be adressed by my solution already.
  • I tried to add my own log4j 2 container module, but it either had no effect or led to a java.lang.ClassNotFoundException: org.xml.sax.SAXException.
  • My own research on the web led me to the impression, that rerouting the containers log-messages to log4j 2 seems to be a problem in Wildfly already, so it's not a problem of Wildfly Swarm. Seems like they have questioned the need of that feature, but I think that with Wildfly Swarm, the matter needs to be re-evaluated.

Having said all this, I'm curious to see if someone can help me improving on my project setup... Thank you in advance!

@Benjamin: Sorry for the long delay, but I was pretty busy the last weeks. I have no special settings in my log4j2.xml, I really don't believe that its content is the root of your difficulties. As I prefer to be able to config my log4j2.xml without recompiling the project, I usually place it outside my jar-file. The location of the file is then up to you as you can set its path with the system property log4j.configurationFile. If you check the pom.xml I posted above, you'll see it in the configuration part of the wildfly-swarm-plugin. However, I suggest you rather do that in your project-stages.yml or project-defaults.yml, which have to go to src/main/resources of your project. That's how I did it for my real application and it still seems to work even after upgrading to Thorntail. Just keep case that your path starts with file:... - hope that helps.

TheDentist
  • 103
  • 1
  • 7
  • This may not currently be possible because WildFly uses the jboss-logmanager as it's log manager. You can file a feature request https://issues.jboss.org/browse/SWARM though. – James R. Perkins Oct 03 '17 at 16:09
  • The respective feature request ended up here [SWARM-1570](https://issues.jboss.org/browse/SWARM-1570). – user667 Feb 09 '18 at 11:09
  • @TheDentist, I am having the same issue, but could not get it resolved using your approach. I think the issue is with the log4j2.xml. What is its content and where to place it? Can you place it in a resources folder or webapp/WEB-INF? – Benjamin May 25 '18 at 09:16
  • @Benjamin: I updated my post to reply to your question as the answer was too long to post it down here. See last paragraph. – TheDentist Jul 13 '18 at 12:01
  • @TheDentist, thanks for your reply! I eventually figured out my problem maybe was not with the logging, since the error message (related to logging) went away when removing some depencies on seleniumhq and serenity bdd, which is really strange. – Benjamin Jul 14 '18 at 14:34

0 Answers0