Skip to content
Advertisement

slf4j in library seems to ignore my log4j2 configuration

PAA

We use Log4j2 in our java-ee application. We use a library, where logging is programmed against SLF4J. In this library is a class, which logs a lot of stuff I do not want -> so I want to set LogLevel of this Logger to OFF.

My log4j2.xml looks like this:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="trace" shutdownHook="disable">
    <Appenders>
        <Console name="ConsoleAppender" target="SYSTEM_OUT" ignoreExceptions="false" >
            <PatternLayout pattern="%d{ISO8601} %d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
        </Console>
        <JDBC name="DatabaseAppender" tableName="logentry" ignoreExceptions="false" >
            <ConnectionFactory class="xx.xx.xx.xx.LoggingConnectionFactory" method="getDatabaseConnection" />
            <Column name="eventDate" isEventTimestamp="true" />
            <Column name="level" pattern="%level" isUnicode="false"/>
            <Column name="logger" pattern="%logger" isUnicode="false"/>
            <Column name="message" pattern="%message" isUnicode="false"/>
            <Column name="exception" pattern="%throwable{50}" isUnicode="false"/>
        </JDBC>
    </Appenders>
    <Loggers>
        <Logger name="net.rubyeye.xmemcached.transcoders.BaseSerializingTranscoder" level="off" additivity="false">
            <AppenderRef ref="ConsoleAppender"/>
        </Logger>
        <Root level="INFO">
            <AppenderRef ref="DatabaseAppender"/>
            <AppenderRef ref="ConsoleAppender"/>
        </Root>
    </Loggers>
</Configuration>

But BaseSerializingTranscoder still logs errors. If I do a simple test and place the log code found in BaseSerializingTranscoder to a test function, I see that the logger retrieved over org.slf4j.Logger.LoggerFactory (what is done by the library) has not the same configuration as if I retrieve the logger over org.apache.logging.log4j.LogManager (where my configuration is applied correctly):

import net.rubyeye.xmemcached.transcoders.BaseSerializingTranscoder;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.slf4j.LoggerFactory;

org.slf4j.Logger logger1 = LoggerFactory.getLogger(BaseSerializingTranscoder.class);
logger1.error("log test the same way as in library");

Logger logger2 = LogManager.getLogger(BaseSerializingTranscoder.class);
logger2.error("log test");

The output of logger1 is visible, which I wanted to eliminate. What is wrong?

Edit
We use Wildfly 10.1. I was able to create a minimal example which has exactly the same problem.

pom.xml:

<?xml version="1.0" encoding="UTF-8"?>
<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/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>

    <groupId>test</groupId>
    <artifactId>test</artifactId>
    <version>1.0-SNAPSHOT</version>

    <packaging>war</packaging>

    <dependencies>
        <dependency>
            <groupId>org.jboss.spec</groupId>
            <artifactId>jboss-javaee-all-7.0</artifactId>
            <version>1.0.1.Final</version>
        </dependency>

        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-api</artifactId>
            <version>1.7.25</version>
        </dependency>
        <dependency>
            <groupId>org.apache.logging.log4j</groupId>
            <artifactId>log4j-slf4j-impl</artifactId>
            <version>2.9.1</version>
        </dependency>
        <dependency>
            <groupId>org.apache.logging.log4j</groupId>
            <artifactId>log4j-core</artifactId>
            <version>2.9.1</version>
        </dependency>

    </dependencies>

</project>

log4j2.xml:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="warn">

    <Appenders>
        <Console name="consoleAppender" target="SYSTEM_OUT">
            <PatternLayout pattern="%d %p %c [%t] %m%n" />
        </Console>
    </Appenders>

    <Loggers>
        <Logger name="blah" level="off" additivity="false">
            <AppenderRef ref="consoleAppender" />
        </Logger>
        <Root level="info">
            <AppenderRef ref="consoleAppender" />
        </Root>
    </Loggers>
</Configuration>

Service.java:

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

import javax.annotation.PostConstruct;
import javax.ejb.Singleton;
import javax.ejb.Startup;

@Singleton
@Startup
public class Service {

    private static final Logger loggerBlah = LoggerFactory.getLogger("blah");

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

    @PostConstruct
    private void startup() {
        logger.info("test1");
        logger.error("test2");
        loggerBlah.info("test3");
        loggerBlah.error("test4");
    }
}

output:

21:13:11,641 INFO  [Service] (ServerService Thread Pool -- 40) test1
21:13:11,641 ERROR [Service] (ServerService Thread Pool -- 40) test2
21:13:11,641 INFO  [blah] (ServerService Thread Pool -- 40) test3
21:13:11,641 ERROR [blah] (ServerService Thread Pool -- 40) test4

test3 and test4 should not be logged! What is wrong?

Advertisement

Answer

UPDATE #2:

After your updates I was able to duplicate the problem. As per my latest comment I was able to use this answer to guide me in fixing the issue.

I added the following jboss-deployment-structure.xml to the META-INF of the web project: 

<jboss-deployment-structure xmlns="urn:jboss:deployment-structure:1.2">
    <deployment>
        <exclusions>
            <module name="org.apache.log4j" />
        </exclusions>
        <exclude-subsystems>
            <subsystem name="logging"/>
        </exclude-subsystems>
    </deployment>
</jboss-deployment-structure>

I also modified the log4j2.xml slightly so that I would be sure without any doubt that the configuration specified by this file was being used. I changed the PatternLayout to add the string “MY_PATTERN” as a prefix for every message:

<PatternLayout pattern="MY_PATTERN %d %p %c [%t] %m%n" />

Output:

09:30:38,074 INFO  [stdout] (ServerService Thread Pool -- 137) MY_PATTERN 2017-09-24 09:30:38,073 INFO example.Service [ServerService Thread Pool -- 137] test1
09:30:38,077 INFO  [stdout] (ServerService Thread Pool -- 137) MY_PATTERN 2017-09-24 09:30:38,077 ERROR example.Service [ServerService Thread Pool -- 137] test2

The messages test3 and test4 are no longer logged to console.

PREVIOUS Answer and Update:

I suspect your issue has to do with how you have your classpath configured. I highly recommend that you check your dependency hierarchy to make sure you have all the correct logging libraries you need.

Here is a simple example of using the OFF level with SLF4J and log4j2:

package blah;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;


public class Main {

    private static final Logger log = LoggerFactory.getLogger(Main.class);

    public static void main(String[] args) {

        log.trace("trace log");
        log.debug("debug log");
        log.info("info log");
        log.warn("warn log");
        log.error("error log");
    }

}

Here is the log4j2.xml configuration:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="warn">

    <Appenders>
        <Console name="consoleAppender" target="SYSTEM_OUT">
            <PatternLayout pattern="%d %p %c [%t] %m%n" />
        </Console>
    </Appenders>

    <Loggers>
        <Logger name="blah" level="off" additivity="false">
            <AppenderRef ref="consoleAppender" />
        </Logger>
        <Root level="info">
            <AppenderRef ref="consoleAppender" />
        </Root>
    </Loggers>
</Configuration>

Here are the dependencies:

<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-api</artifactId>
    <version>1.7.25</version>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-slf4j-impl</artifactId>
    <version>2.9.1</version>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-core</artifactId>
    <version>2.9.1</version>
</dependency>

When I have the level of the “blah” logger set to off I see no logs on the console at all. When I change it to something like trace I see all of the logs.

UPDATE:

I was able to put together a simple web application using servlet API 3.1.0 and got the logging working (I am able to set level to OFF and not see ERROR level messages) with the dependencies I mentioned in the example above. So it would certainly seem to be a configuration problem of some kind. Just as an FYI I deployed my simple app to Tomcat 8.

User contributions licensed under: CC BY-SA
8 People found this is helpful
Advertisement