0

Application cannot overwrite jul and log4j2 logging frameworks, but can ovewrite: log4j, jcl with log4j

The application uses slf4j bridge with logback as a logging framework. The application also depends and invokes modules which use different logging frameworks:

  1. jul,
  2. log4j (v1),
  3. jcl with log4j
  4. log4j2.

Each module has its own logging configuration file, depending on the logging framework. The config file is defined in the resorces of each module.

I try to force all the modules, do not use their own logging frameworks and configuration, but only slf4j bridge with logback.

Here is java code:

new Slf4jLoggingExample().doLog();
new JulLoggingExample().doLog();
new Log4jLoggingExample().doLog();
new Log4jV2LoggingExample().doLog();
new JclLog4jLoggingExample().doLog();

Here is the maven configuration WITHOUT multiple bridging libraries, like log4j-over-slf4j, jul-to-slf4j, jcl-over-slf4j. Note, artifact ids are just custom components: jul, log4j,log4j-v2, jcl-log4j to highlight a logging framework, used in that component:

  <dependencies>
    <!-- https://mvnrepository.com/artifact/org.slf4j/slf4j-api -->
    <dependency>
      <groupId>org.slf4j</groupId>
      <artifactId>slf4j-api</artifactId>
      <version>1.7.30</version>
    </dependency>
    <dependency>
      <groupId>ch.qos.logback</groupId>
      <artifactId>logback-classic</artifactId>
      <version>1.2.3</version>
    </dependency>
    <dependency>
      <groupId>com.savdev.example.logging</groupId>
      <artifactId>jul</artifactId>
      <version>1.0.0</version>
    </dependency>
    <dependency>
      <groupId>com.savdev.example.logging</groupId>
      <artifactId>log4j</artifactId>
      <version>1.0.0</version>
    </dependency>
    <dependency>
      <groupId>com.savdev.example.logging</groupId>
      <artifactId>log4j-v2</artifactId>
      <version>1.0.0</version>
    </dependency>
    <dependency>
      <groupId>com.savdev.example.logging</groupId>
      <artifactId>jcl-log4j</artifactId>
      <version>1.0.0</version>
    </dependency>
  </dependencies>

Here is the output, which just shows that each set of log statemens have different format, according to the chosen and configured logging framework:

12:18:08.316 [main] INFO  c.s.e.logging.Slf4jLoggingExample - This is an info message, (originally, slf4j with logback)
12:18:08.318 [main] ERROR c.s.e.logging.Slf4jLoggingExample - This is an error message, (originally, slf4j with logback)
12:18:08.318 [main] WARN  c.s.e.logging.Slf4jLoggingExample - This is a warning message, (originally, slf4j with logback)
12:18:08.318 [main] DEBUG c.s.e.logging.Slf4jLoggingExample - Here is a debug message, (originally, slf4j with logback)
Feb 24, 2021 12:18:08 PM com.savdev.example.logging.jul.JulLoggingExample doLog
INFO: This is an info message (originally, JUL)
Feb 24, 2021 12:18:08 PM com.savdev.example.logging.jul.JulLoggingExample doLog
SEVERE: This is an error message (originally, JUL)
Feb 24, 2021 12:18:08 PM com.savdev.example.logging.jul.JulLoggingExample doLog
WARNING: This is a warning message (originally, JUL)
Feb 24, 2021 12:18:08 PM com.savdev.example.logging.jul.JulLoggingExample doLog
FINE: Here is a debug message (originally, JUL)
[main] INFO  com.savdev.example.logging.log4j.Log4jLoggingExample  - This is an info message, (originally, log4j)
[main] ERROR com.savdev.example.logging.log4j.Log4jLoggingExample  - This is an error message, (originally, log4j)
[main] WARN  com.savdev.example.logging.log4j.Log4jLoggingExample  - This is a warning message, (originally, log4j)
[main] DEBUG com.savdev.example.logging.log4j.Log4jLoggingExample  - Here is a debug message, (originally, log4j)
[INFO ] 2021-02-24 12:18:08.722 [main] Log4jV2LoggingExample - This is an info message, (originally, log4j2)
[ERROR] 2021-02-24 12:18:08.724 [main] Log4jV2LoggingExample - This is an error message, (originally, log4j2)
[WARN ] 2021-02-24 12:18:08.724 [main] Log4jV2LoggingExample - This is a warning message, (originally, log4j2)
[DEBUG] 2021-02-24 12:18:08.724 [main] Log4jV2LoggingExample - Here is a debug message, (originally, log4j2)
[main] INFO  com.savdev.example.logging.jcl.logback.JclLog4jLoggingExample  - This is an info message (originally, jcl with log4j)
[main] ERROR com.savdev.example.logging.jcl.logback.JclLog4jLoggingExample  - This is an error message (originally, jcl with log4j)
[main] WARN  com.savdev.example.logging.jcl.logback.JclLog4jLoggingExample  - This is a warning message (originally, jcl with log4j)
[main] DEBUG com.savdev.example.logging.jcl.logback.JclLog4jLoggingExample  - Here is a debug message (originally, jcl with log4j)

5 groups of messages with different format. I am adding multiple bridging libraries:

<!-- https://mvnrepository.com/artifact/org.slf4j/jul-to-slf4j -->
<dependency>
  <groupId>org.slf4j</groupId>
  <artifactId>jul-to-slf4j</artifactId>
  <version>1.7.30</version>
</dependency>
<!-- https://mvnrepository.com/artifact/org.slf4j/log4j-over-slf4j -->
<dependency>
  <groupId>org.slf4j</groupId>
    <artifactId>log4j-over-slf4j</artifactId>
  <version>1.7.30</version>
</dependency>
<!-- https://mvnrepository.com/artifact/org.slf4j/jcl-over-slf4j -->
<dependency>
  <groupId>org.slf4j</groupId>
  <artifactId>jcl-over-slf4j</artifactId>
  <version>1.7.30</version>
</dependency>

Here is the new output:

12:44:40.385 [main] INFO  c.s.e.logging.Slf4jLoggingExample - This is an info message, (originally, slf4j with logback)
12:44:40.387 [main] ERROR c.s.e.logging.Slf4jLoggingExample - This is an error message, (originally, slf4j with logback)
12:44:40.387 [main] WARN  c.s.e.logging.Slf4jLoggingExample - This is a warning message, (originally, slf4j with logback)
12:44:40.387 [main] DEBUG c.s.e.logging.Slf4jLoggingExample - Here is a debug message, (originally, slf4j with logback)
12:44:40.399 [main] INFO  c.s.e.l.log4j.Log4jLoggingExample - This is an info message, (originally, log4j)
12:44:40.400 [main] ERROR c.s.e.l.log4j.Log4jLoggingExample - This is an error message, (originally, log4j)
12:44:40.400 [main] WARN  c.s.e.l.log4j.Log4jLoggingExample - This is a warning message, (originally, log4j)
12:44:40.400 [main] DEBUG c.s.e.l.log4j.Log4jLoggingExample - Here is a debug message, (originally, log4j)
Feb 24, 2021 12:44:40 PM com.savdev.example.logging.jul.JulLoggingExample doLog
INFO: This is an info message (originally, JUL)
Feb 24, 2021 12:44:40 PM com.savdev.example.logging.jul.JulLoggingExample doLog
SEVERE: This is an error message (originally, JUL)
Feb 24, 2021 12:44:40 PM com.savdev.example.logging.jul.JulLoggingExample doLog
WARNING: This is a warning message (originally, JUL)
Feb 24, 2021 12:44:40 PM com.savdev.example.logging.jul.JulLoggingExample doLog
FINE: Here is a debug message (originally, JUL)
[INFO ] 2021-02-24 12:44:40.793 [main] Log4jV2LoggingExample - This is an info message, (originally, log4j2)
[ERROR] 2021-02-24 12:44:40.795 [main] Log4jV2LoggingExample - This is an error message, (originally, log4j2)
[WARN ] 2021-02-24 12:44:40.795 [main] Log4jV2LoggingExample - This is a warning message, (originally, log4j2)
[DEBUG] 2021-02-24 12:44:40.796 [main] Log4jV2LoggingExample - Here is a debug message, (originally, log4j2)
12:44:40.798 [main] INFO  c.s.e.l.j.l.JclLog4jLoggingExample - This is an info message (originally, jcl with log4j)
12:44:40.798 [main] ERROR c.s.e.l.j.l.JclLog4jLoggingExample - This is an error message (originally, jcl with log4j)
12:44:40.798 [main] WARN  c.s.e.l.j.l.JclLog4jLoggingExample - This is a warning message (originally, jcl with log4j)
12:44:40.798 [main] DEBUG c.s.e.l.j.l.JclLog4jLoggingExample - Here is a debug message (originally, jcl with log4j)

What I can see, only the components with log4j and jcl with log4j changed their logging format and now use as expected the logging format of the main application.

But log4j2 and jul - still use their own logging format and are not affected by this setup.

I have read but JUL to SLF4J Bridge it did not help. Here is the full code of all modules: logging github repo

What do I miss, can you please help.

Alexandr
  • 9,213
  • 12
  • 62
  • 102

1 Answers1

1

The reason why Log4j 2 is still using its own configuration is because you are only using SLF4J's log4j-over-slf4j which is for Log4j 1 (despite not being that clearly documented). For Log4j 2 to SLF4J, you will have to add Log4j 2 to SLF4J Adapter (dependency information) as well.

For jul-to-slf4j you have to follow the steps described in the SLF4JBridgeHandler documentation:

  • Either specify it in the logging.properties file of your JRE. Though if you have no control over the environment your application is running, this is likely not an option.
  • Or programmatically install it:
    static {
      // Verify that it is not installed yet; other dependency might have already
      // installed it which would cause duplicate handler
      // Unfortunately SLF4J provides no built-in method for this procedure, so
      // race condition between different classes could happen
      if (!SLF4JBridgeHandler.isInstalled()) {
        // Remove default handler logging to System.err
        SLF4JBridgeHandler.removeHandlersForRootLogger();
        // Install the SLF4J handler
        SLF4JBridgeHandler.install();
      }
    }
    

Additionally you should configure the LevelChangePropagator for Logback. Otherwise, because the SLF4J class is only a handler, lowering the SLF4J log level (e.g. for debugging) would have no effect on java.util.logging.

Note however, that redirecting java.util.logging in general is a pain, especially if your project has multiple entry points. You will have to perform the SLF4J bridge initialization check in every one of these entry points.

As a side note: The situation for the java.util.logging to Log4j 2 bridge (Log4j JDK Logging Adapter) it is not much better. That library instead implements LogManager which therefore integrates more tightly into java.util.logging, but has the disadvantage that it has to be specified using a System property (or the logging.properties file) and must be specified before java.util.logging.LogManager is loaded (which might not be in your control), afterwards a custom LogManager implementation cannot be specified anymore.
There is also a JUL Handler class called Log4jBridgeHandler, but that only exists on the not yet released 3.0.0 branch and has not been backported yet, see backport pull request.

Marcono1234
  • 5,856
  • 1
  • 25
  • 43
  • log4j2 is redirected now successfully. Thank you very much. With JUL I still could not get it work. I removed and then installed slf4jbridgehandler, added `LevelChangePropagator` in the logback.xml, as you offered. Still no changes. Everything is commited and pushed to the repo, you can have a look. I could solve all issues with similar redirections to log4j2. For JUL I had to set explicitely the system property. – Alexandr Feb 25 '21 at 05:13
  • 1
    The reason for this is that your code manually overwrites the JUL `LogManager` config, I have created a [GitHub issue in your repository](https://github.com/AlexandrSokolov/logging/issues/1) describing it in more detail. – Marcono1234 Feb 26 '21 at 19:29
  • 1
    sorry for late feedback. You are right. It was the reason. Actually, if I change code, another issue appears, so the final conclusion: never-never use JUL in the projects:) It is always a headache to redirect logging messages with it. – Alexandr Apr 06 '21 at 12:49