2

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?

PAA
  • 1
  • 46
  • 174
  • 282
badera
  • 1,495
  • 2
  • 24
  • 49
  • Which version of servlet API are you using? – D.B. Sep 22 '17 at 16:18
  • I think the best thing you can do now is to create a simple web application (start from nothing, build a new app) and try to recreate your issue. If you can recreate it you will know where the problem is. I don't have all the details of your environment or the details of how you're building and running the code. Generally on stackoverflow we ask that question authors provide a [Minimal, Complete, and Verifiable Example](http://stackoverflow.com/help/mcve) so I think that is what you need to work on now. – D.B. Sep 22 '17 at 16:50
  • I made a minimal example with a EJB and deployed it to Wildfly 10.1. -> Exactly my problem. I updated the question showing all files from this example. Here I provide it for download: http://pubstore.webhop.org/misc/issues/java/logging1.zip – badera Sep 22 '17 at 20:00
  • Do you notice how the pattern of your output does not match the pattern you specified in the log4j2.xml? I bet Wildfly has a default logging implementation that you need to disable before the logs will be handled by your application's configuration. In fact when I search for this I find [this answer](https://stackoverflow.com/a/35489152/3284624) and although it is for Wildfly 9 it may still work with version 10. – D.B. Sep 22 '17 at 23:21

1 Answers1

4

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.

D.B.
  • 4,523
  • 2
  • 19
  • 39
  • I adjusted my `pom.xml` file; however, the behaviour is still the same. Just to understand you correctly: Your defined `blah` logger in log4j2.xml does also affect the behaviour of your `LoggerFactory.getLogger(Main.class)` logger, just because it is in package `blah`? – badera Sep 22 '17 at 13:52
  • Can you please update your question to provide more details about your POM file - anything log4j or slf4j related would be helpful. Regarding the configuration yes the logger obtained by that call is the blah logger because loggers are hierarchical - it does not find a blah.Main so it looks for blah. If it didn't find blah it would use root. – D.B. Sep 22 '17 at 14:00
  • Thank you very much, D.B. for your amazing help!! – badera Sep 25 '17 at 07:35