JUL bridge and System.Logger are inconsistent on handling of OFF and ALL

[agentgt]

When logging with either the System.Logger or the JUL the expectation of passing Level.OFF (which does not have an SLF4J analog) is inconsistent when they should be same. Ideally they should both NOOP.

That is when passing making a logging request with Level.OFF it should be off.

This can be clearly seen in java.util.logging.Handler.isLoggable(LogRecord)

    public boolean isLoggable(LogRecord record) {
        final int levelValue = getLevel().intValue();
        if (record == null) return false;
        if (record.getLevel().intValue() < levelValue || levelValue == offValue) {
            return false;
        }
        final Filter filter = getFilter();
        if (filter == null) {
            return true;
        }
        return filter.isLoggable(record);
    }

N.B. the levelValue == offValue. All JUL handlers inherit isLoggable including the SLF4J bridge.

However here it is turned into ERROR here:

https://github.com/qos-ch/slf4j/blob/448bca173cb461087ce4958f5a6ecbb9f74ee519/jul-to-slf4j/src/main/java/org/slf4j/bridge/SLF4JBridgeHandler.java#L247

Worse is in the System.Logger it is reported as an error:

https://github.com/qos-ch/slf4j/blob/448bca173cb461087ce4958f5a6ecbb9f74ee519/slf4j-jdk-platform-logging/src/main/java/org/slf4j/jdk/platform/logging/SLF4JPlatformLogger.java#L94

It clearly was the intention of the System.Logger to follow JUL behavior as it is documented:

            /**
             * A marker to indicate that all levels are disabled.
             * This level {@linkplain #getSeverity() severity} is
             * {@link Integer#MAX_VALUE}.
             */
            OFF(Integer.MAX_VALUE);  // typically mapped to/from j.u.l.Level.OFF

[ceki]

@agentgt Can you create a LogRecord with the Level.OFF as the level? I don't think that is possible or is it?

[agentgt]

@agentgt Can you create a LogRecord with the Level.OFF as the level? I don't think that is possible or is it?

Oh it is possible that is how I found it and why I filed the bug 😄 .

I have a massive combinatorics of a test in my logging implementation: https://github.com/jstachio/rainbowgum/blob/main/test/rainbowgum-test-jdk/src/test/java/io/jstach/rainbowgum/test/jdk/JDKSetupTest.java

The issue is the actual j.u.l.Logger

    public boolean isLoggable(Level level) {
        int levelValue = config.levelValue;
        if (level.intValue() < levelValue || levelValue == offValue) {
            return false;
        }
        return true;
    }
...
    public void log(Level level, String msg) {
        if (!isLoggable(level)) {
            return;
        }
        LogRecord lr = new LogRecord(level, msg);
        doLog(lr);
    }

isLoggable will report true for Level.OFF because it is Integer.MAX. This isLoggable I don't think you can override.

I guess one could argue it is a JDK bug.

On a completely separate note I'm trying to write API unit/integration tests that use the facades that I can give you (logback) and log4j2 since I'm doing it anyway for my project. The logback and log4j code coverage could be improved. I have a PR I will put in logback later that turns on jacoco. Good news is I think logback has higher coverage than log4j 😄 but both seem to be below 60% but there is a solid chance jacoco is not catching things.

[agentgt]

@ceki

I forgot to mention the level ALL is also broken and perhaps the bigger bug.

I can put in an integration test module as a PR if you like but basically it is:

// given our backing implementation as trace.
// and jul has been set to not discard any events (ALL)
// and we have output like %level %msg
var jul = java.util.logging.Logger.getLogger(name);
var sl = System.getLogger(name);

// when we log with ALL
jul.log(java.util.logging.Level.ALL, "hello");
sl.log(System.Logger.Level.ALL, "hello");

// we expect

assertEquals(output, "TRACE hello");

// what we get is both discard events.

// Now same given

// when we log with OFF
jul.log(java.util.logging.Level.OFF, "hello");
sl.log(System.Logger.Level.OFF, "hello");

// we expect both to discard the events per JDK description

// sl reports an error
// jul get output as "ERROR hello"

[ceki]

@agentgt Adam I do not consider these as bugs. SLF4J does not support logging backend configuration and the levels ALL and OFF can only be used during configuration or testing. I suggest that you modify your tests.

[agentgt]

@ceki

I think out of the box JUL will not discard any events and is set to ALL. The issue is actually one of security and other libraries.

Other libraries may use System.Logger or JUL and pass these levels and the System.Logger defaults to a JUL like backend (and possibly JUL itself... I can't remember how it does that detection).

If a library switches from JUL to System.Logger which is probably happening now they will get wildly different results.

If you are OK with that (I'm not) then I will have to strongly recommend consumers of my logging library not to use the SLF4J jul/system logger bridge.

[agentgt]

That is a third party library that is not your own very easily could have originally done:

var level = levelDeterminedFromSomeConfigInLibraryOrCondition;
// level gets set to OFF
jul.log(level, "hello");

Application uses SLF4J bridge notices no issues.

Third party library switches to System.Logger in modernizing to Java 9 or greater:

var level = levelDeterminedFromSomeConfigInLibraryOrCondition;
// level gets set to OFF
systemLogger.log(level, "hello");

Application is now getting errors (not error log message but slf4j report errors) reported and can do jack squat about it other than writing their own System.Logger facade.

[agentgt]

If you think JUL and System.Logger do not have a strong relationship in levels and behavior I suggest you examine the javadoc: https://docs.oracle.com/en/java/javase/21/docs/api/java.base/java/lang/System.Logger.Level.html

System logger levels are mapped to java.util.logging levels of corresponding severity.

https://docs.oracle.com/en/java/javase/21/docs/api/java.base/java/lang/System.Logger.Level.html#OFF

A marker to indicate that all levels are disabled. This level [severity](https://docs.oracle.com/en/java/javase/21/docs/api/java.base/java/lang/System.Logger.Level.html#getSeverity()) is Integer.MAX_VALUE.

https://docs.oracle.com/en/java/javase/21/docs/api/java.logging/java/util/logging/Level.html#OFF

OFF is a special level that can be used to turn off logging. This level is initialized to Integer.MAX_VALUE.

emphasis on off.

[ceki]

@ceki

I forgot to mention the level ALL is also broken and perhaps the bigger bug.

I can put in an integration test module as a PR if you like but basically it is:

// given our backing implementation as trace.
// and jul has been set to not discard any events (ALL)
// and we have output like %level %msg
var jul = java.util.logging.Logger.getLogger(name);
var sl = System.getLogger(name);
... cut

My initial premise regarding Level.OFF and Level.ON being unusable in regular log statement was incorrect as your examples clearly show. However, I think passing Level.OFF or Level.ON to a logger.log() method is quite bad practice.

[agentgt]

My initial premise regarding Level.OFF and Level.ON being unusable in regular log statement was incorrect as your examples clearly show. However, I think passing Level.OFF or Level.ON to a logger.log() method is quite bad practice

I obviously agree with that. My concern is one of safety and consistency. A third party library may have different opinions on OFF.

I think at minimum if we do go with the bad practice both System.Logger and JUL would report it as bad for OFF (my feeling is to just discard) but the ship may have sailed on this if you feel it could be breaking change since it has been out in the wild for some time.

Perhaps documentation or a flag is the least dangerous resort?

[agentgt]

@ceki is this commit related to this issue?

https://github.com/qos-ch/slf4j/commit/f7b34c2e60ebf242003675490dcbbeae52fb8f52

It appears to be but just wanted to make sure.