Search code examples
javamavenlog4j2

Log4j v2 creates logfile but does not write anything to it and ignores my log levels


The problem is that my Log4J logger does not write to a file although it creates it (and the dir too!) and that the levels enabled are only FATAL, ERROR although I told it to enable ALL. Here is my src/resources/log4j.properties (which with maven is placed in target/classes/resources/log4j.properties, I am sure it is found and read because I changed the logfilename etc.):

og4j.rootLogger=all, stdout, rollingfile

log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %-5p %c{1}:%L - %m%n


log4j.appender.rollingfile=org.apache.log4j.RollingFileAppender
#log4j.appender.rollingfile=org.apache.log4j.FileAppender
log4j.appender.rollingfile.ImmediateFlush=true
log4j.appender.rollingfile.File=var/log/app.log
log4j.appender.rollingfile.MaxFileSize=20MB
log4j.appender.rollingfile.layout=org.apache.log4j.PatternLayout
log4j.appender.rollingfile.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %-5p %c{1}:%L - %m%n

And here is a simplified java code to demonstrate the problem:

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.apache.log4j.PropertyConfigurator;

public class Main {
    private static final org.apache.logging.log4j.Logger logger = org.apache.logging.log4j.LogManager.getLogger(Main.class.getName());
    static{
        org.apache.log4j.PropertyConfigurator.configure(
            Main.class.getClassLoader().getResource("resources/log4j.properties")
        );
    }
    public static void main(String []args){
if(logger.isDebugEnabled()){ System.out.println("debug enabled"); }
if(logger.isInfoEnabled()){ System.out.println("info enabled"); }
if(logger.isFatalEnabled()){ System.out.println("fatal enabled"); }
if(logger.isErrorEnabled()){ System.out.println("error enabled"); }
        logger.info("xxit");
        logger.error("xxit2");
        logger.warn("xxit3");
        logger.debug("xxit4");
        logger.fatal("xxit5");
    }
}

The STDOUT is:

fatal enabled
error enabled
21:11:17.131 [main] ERROR Main - xxit2
21:11:17.136 [main] ERROR Main - xxit5

The output dir and file are created but the file is empty. I have no idea where the remaining messages go. I guess ignored because they are not logged.

My pom.xml file has explicit dependencies for latest log4j and slf4j-relog4j. At some point I also added log4j-slf4j-impl. The output still the same.

I have read that other dependencies may implicitly use older versions of Log4j or slf4j which may clash with the latest I am requesting.

Indeed, running mvn dependency:tree I get:

...
[INFO] +- org.jxls:jxls-jexcel:jar:1.0.9:compile
[INFO] |  +- org.jxls:jxls:jar:2.6.0:compile
[INFO] |  |  +- org.apache.commons:commons-jexl3:jar:3.1:compile
[INFO] |  |  |  \- commons-logging:commons-logging:jar:1.2:compile
[INFO] |  |  +- commons-beanutils:commons-beanutils:jar:1.9.3:compile
[INFO] |  |  |  \- commons-collections:commons-collections:jar:3.2.2:compile
[INFO] |  |  \- ch.qos.logback:logback-core:jar:1.2.3:compile
[INFO] |  +- net.sourceforge.jexcelapi:jxl:jar:2.6.10:compile
[INFO] |  |  \- log4j:log4j:jar:1.2.14:compile
[INFO] |  \- org.slf4j:jcl-over-slf4j:jar:1.7.26:compile
...
[INFO] +- org.apache.logging.log4j:log4j-api:jar:2.23.1:compile
[INFO] +- org.apache.logging.log4j:log4j-core:jar:2.23.1:compile
[INFO] +- org.apache.logging.log4j:log4j-slf4j-impl:jar:2.23.1:compile
[INFO] +- org.slf4j:slf4j-api:jar:2.0.13:compile
[INFO] +- org.slf4j:slf4j-reload4j:jar:2.0.13:compile
[INFO] |  \- ch.qos.reload4j:reload4j:jar:1.2.22:compile
[INFO] +- org.slf4j:slf4j-jdk14:jar:2.0.13:compile

There are two versions of slf4j and log4j active in the project. The last part is from me, the first part from jxls. I have no idea how this is possible and how it affects my desired versions.

Could the static logger I think I am creating is not created but re-used from other packages? Then it makes sense that the log levels are not what I set in my properties file. But it does not make sense, to me, why the output file is created but remains empty.

Perhaps I am overthinking what is wrong here. Can anybody shed some light?

My aim is to use the latest log4j and re-use the same logger throughtout my app which btw is a JavaFX app with a number of controllers. Ideally every part of the app should be using the same logger object.


Solution

  • There are two main problems in your project:

    1. You are logging using Log4j API (version 2), but you configuration is for Log4j 1 and org.apache.log4j.PropertyConfigurator is a version 1 class.
    2. You have a dependency problem: your classpath contains many different implementations and replacements of logging APIs.

    Log4j 2 configuration

    If you want to configure Log4j 2 Core (the standard implementation of Log4j API), add a log4j2.xml file to the root of you classpath (you want it to end up in target/classes):

    <Configuration xmlns="https://logging.apache.org/xml/ns"
                   xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
                   xsi:schemaLocation="https://logging.apache.org/xml/ns
                       https://logging.apache.org/xml/ns/log4j-config-2.xsd">
      <Appenders>
        <Console name="stdout">
          <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss} %-5p %c{1}:%L - %m%n"/>
        </Console>
        <RollingFile name="rollingfile"
                     fileName="var/log/app.log"
                     filePattern="var/log/app.log.%i">
          <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss} %-5p %c{1}:%L - %m%n"/>
          <SizeBasedTriggeringPolicy size="20 MB"/>
        </RollingFile>
      </Appenders>
      <Loggers>
        <Root level="ALL">
          <AppenderRef ref="stdout"/>
          <AppenderRef ref="rollingfile"/>
        </Root>
      </Loggers>
    </Configuration>
    

    Since both Log4j 1 and Log4j 2 use convention over configuration to find configuration files, you also should remove the org.apache.log4j.PropertyConfigurator method call.

    This should solve your immediate problem of logging from your application, but libraries might use other logging backends.

    Dependency problem

    On your runtime classpath you have:

    • 3 implementations of SLF4J: slf4j-jdk14, slf4j-reload4j and log4j-slf4j-impl. You want only the last one, which forwards SLF4J API calls to Log4j API calls (which end up in Log4j Core as per previous section),

    • a transitive dependency on Log4j 1, which reached EOL 9 years ago. Looking at the source code of the (15 years old) net.sourceforge.jexcelapi:jxl library, it does not require Log4j 1.

    • you have two versions of commons-logging classes: the jcl-over-slf4j library contains the same classes as commons-logging. Which one is used is random. You should remove jcl-over-slf4j and bump the requirement for commons-logging to 1.3.2 to have a direct binding to Log4j API:

      <dependencyManagement>
        <dependencies>
          <dependency>
            <groupId>commons-logging</groupId>
            <artifactId>commons-logging</artifactId>
            <version>1.3.2</version>
          </dependency>
        </dependencies>
      </dependencyManagement>
      <dependencies>
        <dependency>
          <groupId>org.jxls</groupId>
          <artifactId>jxls-jexcel</artifactId>
          <version>1.0.9</version>
          <exclusions>
            <exclusion>
              <groupId>log4j</groupId>
              <artifactId>log4j</artifactId>
            </exclusion>
            <exclusion>
              <groupId>org.slf4j</groupId>
              <artifactId>jcl-over-slf4j</artifactId>
            </exclusion>
          </exclusions>
        </dependency>
      </dependencies>