[slf4j-user] jul-to-slf4j bridge not working properly with JUL Logger#isLoggable()

[Robert Elliot]

Take this with a pinch of salt, but my understanding is that SLF4JBridgeHandler.install() simply adds a new handler to the root logger which sends events to SLF4J. Unless the root JUL logger (and any others with configured levels) is set to a low enough level they won't reach the handler.

This is why the jul-to-slf4j bridge is quite inefficient - all JUL logging events have to be constructed and sent to the handler and only then are they filtered by SLF4J. See [1] for details.

Logback has a LevelChangePropagator[2] which reacts to changes in the enabled Logback level and changes the appropriate JUL Logger's level to keep it in synch, which might you a pattern to copy in Log4J2 if Log4J2 exposes the necessary extension points to listen for logger level changes.

Rob

[1]http://www.slf4j.org/legacy.html#jul-to-slf4j
[2]http://logback.qos.ch/manual/configuration.html#LevelChangePropagator



On 10 Sep 2013, at 16:55, Guus der Kinderen <guus.der.kinderen at gmail.com> wrote:

> Hello,
> 
> Today, I've ran into a snag using the jul-to-slf4j SLF4JBridgeHandler (distribution version 1.7.5). Although I worked around the issue, I wonder if I'm doing something wrong, or if I hit a bug in the implementation.
> 
> The problem popped up during a refactoring of a project. In this project, I switched from using version 1.x of the Jersey framework to version 2.x. Both versions use JUL, which is why the SLF4JBridge was already in place (and doing its magic without incident), using the following two lines in a ContextListener
> 
> SLF4JBridgeHandler.removeHandlersForRootLogger();
> SLF4JBridgeHandler.install();
> 
> After the move was complete, I noticed that a lot less information was logged. When looking into the source code of the newly added framework, I noticed the following:
> 
> A log statement that was generated using the snippet below got logged just fine:
> 
> LOGGER.info(LocalizationMessages.INIT_MSG(Version.getBuildId()));
> 
> However, in the same method, a different log statement was generated conditionally based on the 'isLoggable' method response:
> 
> if (LOGGER.isLoggable(Level.CONFIG)) {
>   final StringBuilder sb;
>   /* lots of string generation */
>   LOGGER.log(Level.CONFIG, sb.toString());
> }
> 
> The condition in the if statement evaluated to false, no matter what.
> 
> I remedied the problem by adding this last line to my jul-to-slf4j bridge invocation:
> 
> SLF4JBridgeHandler.removeHandlersForRootLogger();
> SLF4JBridgeHandler.install();
> java.util.logging.LogManager.getLogManager().getLogger( "" ).setLevel( Level.ALL );
> 
> Immediately, all of the missing log statements popped up in my log files again. Changing the desired log level in my log configuration (which happens to be log4j2) also has the desired effect (as in: lower level JUL statements do not get logged).
> 
> I'm not familiar enough with all of the implementations involved to evaluate a) why my fix was needed, and b) if this fix is a proper work-around, rather than something that's likely to fail in upcoming releases of either product. I would love to get some feedback.
> 
> Kind regards,
> 
>   Guus
> 
> _______________________________________________
> slf4j-user mailing list
> slf4j-user at qos.ch
> http://mailman.qos.ch/mailman/listinfo/slf4j-user

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.qos.ch/pipermail/slf4j-user/attachments/20130910/0226afe9/attachment.html>