The log4j-jul artifact should not modify logger levels

[abpicoli1]

Description

Using log4j2 2.23 makes my logs not to show trace and debug events, not mattering what I set in the log4j2 configuration file.

Configuration

Version: 2.23.0

Operating system: Windows WSL Linux 5.15.133.1-microsoft-standard-WSL2 #1 SMP Thu Oct 5 21:02:42 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux

JDK: Azul Zulu 21 community edition

openjdk version "21.0.1" 2023-10-17 LTS
OpenJDK Runtime Environment Zulu21.30+16-SA (build 21.0.1+12-LTS)
OpenJDK 64-Bit Server VM Zulu21.30+16-SA (build 21.0.1+12-LTS, mixed mode, sharing)

Logs

The output using log4j 2.23
My log4j2 xml configuration
The log output with log4j 2.22.1 : notice that the expected application trace events do appear

Reproduction

[An isolated test reproducing the test.
JUnit tests similar to the ones in the code base are extremely appreciated.]
TestLog.java.txt

The output using log4j2 2.22.1 with -Dlog4j2.configurationFile=(the example file)
The output of the junit test with log4j2 2.22.1
The output of the junit test with log4j2 2.23.0

[ppkarwasz]

@abpicoli1,

Please include your configuration file.

[abpicoli1]

@abpicoli1,

Please include your configuration file.

Sorry, malformed opening message. There are links for the gradle output from both situations, using log4j2 2.23 and log4j 2.22.1, and the log4j2.xml configuration file.

[ppkarwasz]

@abpicoli1,

Running the test in a standalone environment I am not able to reproduce it.

Educated guess

You are using the JUL-to-Log4j API bridge. In version 2.22.1 the implementation of the java.util.logging.Logger#setLevel was broken and the changes to the level didn't propagate as required. We fixed it in #2281.

My guess is that something in your code must be calling:

java.util.logging.Logger.getRootLogger().setLevel(java.util.logging.Level.INFO);

which in 2.22.1 is basically a no-op, while in 2.23.0 changes the logging level of all your loggers.

Workarounds

If my guess is right, setting the level to TRACE on a more specific logger than the root logger, should solve the issue:

<Logger name="com.example" level="TRACE"/>

Another workaround would be to set the log4j2.julLoggerAdapter Java system property to org.apache.logging.log4j.jul.ApiLoggerAdapter

Any chance you can set a breakpoint on org.apache.logging.log4j.jul.CoreLogger#setLevel?

[ppkarwasz]

@garydgregory,

Should we introduce in 2.24.0 a kill-switch property to disable the modification of Log4j Core configuration through foreign APIs? As far as I remember, you can mess with the configuration of Log4j Core using log4j-1.2-api or log4j-jul. The log4j-jcl artifact is maybe capable of shutting down the logger context.

[abpicoli1]

In my humble opinion, having external APIs messing with log4j2 configuration are bugs, not features: one of the patterns I did get from log4j2 (at least until version 2.21) is that legacy applications trying to reconfigure logs without using log4j2 api would ultimately fail. If a legacy log4j 1.x app would try a PropertyConfigurator.configure, for example, I wouldn't get all log configuration overriden by a legacy framework.

[ppkarwasz]

I tend to agree with you: only the main application code should be allowed to touch the configuration of the logging backend.

However there are many users that expect their legacy code to work, when they migrate from a logging backend to another, that is why these features were implemented.

[abpicoli1]

Yep, I hear you: what for some is a bug, for others is a feature :)

Well, for the log4 1.x adapter, two versions were created: one that doesn't mess with configuration, and one which does change configuration and is a real drop-in replacement for applications that were using log4j 1.x.

If the opener can't reconfigure logs for an API that doesn't do that since the beginning of time, it is for sure a new app, or a new log4j2 use: it would be easier to simply change the classpath to add a "log4j-jul-fullapi.jar" in their classpath instead of "log4j-jul.jar" than having everyone else that is using log4j2 for years to remove the jar or changing configurations.

[abpicoli1]

Specially if an issue arises like "everyone must change to the latest log4j2 because of CVE whatever"

[ppkarwasz]

For the upcoming 3.x release, I would propose to split log4j-jul as you suggest:

• log4j-jul-core would contain the functionality that depends on log4j-core (i.e. Logger#getLevel/setLevel),
• log4j-jul would only contain the functionality that depends on log4j-api.

[abpicoli1]

But here is the thing: to use the release 3.x there will be massive classpath changes, if I understood well. To use log4j 3 everyone will need to change a lot of things, which makes the whole effort somewhat of a moot point.

I do understand this is an issue with log4j2 2. I'm my humble opinion, this should be dealt with as a log4j patch release 2.23.1 instead of 3.x .

But I can also live without upgrading to 2.23 : the changes made there really aren't "useful" to me. I will just keep a note to the team not to upgrade to it, and keep using 2.22

[abpicoli1]

Or simply keep using only log4j2-jul 2.22. I can live with that :)

[ppkarwasz]

@abpicoli1,

Regarding 2.23.2 (the release process for 2.23.1 already started), let's wait for @garydgregory opinion.

[garydgregory]

@hi All,

After discussing this with @ppkarwasz and looking at code, we are dealing with the following issue:

1. During app startup, some call site (your app, a library, or the JRE) calls JUL's Logger.setLevel()
2. This overrides what your Log4j 2 configuration defines, and you do not want that behavior.

To keep the Log4j configuration pristine, I think we should:

1. Remove auto-detection in our JUL module
2. This will allow org.apache.logging.log4j.jul.ApiLoggerAdapter to kick in instead of org.apache.logging.log4j.jul.CoreLoggerAdapter
3. If you want the old behavior back, you can set the log4j2.julLoggerAdapter Java system property to org.apache.logging.log4j.jul.ApiLoggerAdapter
4. The call to Logger.setLevel() turns into a noop
5. The call to Logger.getLevel() should return the configured level, not the effective level.

@ppkarwasz Check? (Feel free to edit this comment).

[ppkarwasz]

@garydgregory,

Thanks, that sounds the right solution. I am scheduling it for 2.24.0.

As far as I am concerned java.util.Logger#getLevel() could even return null (which is documented as a possible return type).