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.

4

0 回答 0