Uploaded image for project: 'logback'
  1. logback
  2. LOGBACK-1612

jul LevelChangePropagator is inconsistent with SLF4JBridgeHandler

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Minor
    • Resolution: Not a bug
    • Affects Version/s: None
    • Fix Version/s: 1.3.0, 1.4.0
    • Component/s: logback-classic
    • Labels:
    • Environment:

      Description

       

      LevelChangePropagator is inconsistent with jul-to-slf4j for intermediate values FINER, CONFIG, and any other custom jul Level that you construct. When you logger.finer(), it becomes DEBUG, but when you set the level to DEBUG, then logger.finer() messages disappear. This violates Logback’s Basic selection rule: “A log request of level p issued to a logger having an effective level q, is enabled if p >= q.”

      When I configured the level for the logger com.sun.mail.util to ALL in my logback.xml, I observed log messages with level DEBUG. But when I configured the logger's level to DEBUG in logback.xml, the logger became disabled! The library I was observing used java.util.logging and conditionally did

      if (logger.isLoggable(Level.FINER))
        logger.finer("")

      Current implementations

      jul-to-slf4j's SLF4JBridgeHandler.callPlainSLF4JLogger: given jul level x, it maps to a slf4j level y

      • x ≤ FINEST = 300 → TRACE
      • FINEST < x ≤ FINE = 500 → DEBUG
        • including FINER = 400
      • FINE < x ≤ INFO = 800 → INFO
        • including CONFIG = 700
      • INFO < x ≤ WARNING = 900 → WARN
      • WARNING < x → ERROR
        • including SEVERE = 1000 -> TRACE

      LevelChangePropagator's JULHelper.asJULLevel: given slf4j level y, it maps to a jul level x.

      • slf4j ALL → jul ALL
      • TRACE → FINEST
      • DEBUG → FINE
      • INFO → INFO
      • WARN → WARNING
      • ERROR → SEVERE
      • OFF → OFF

      The problem is that these x values are all at the top of the jul-to-slf4j intervals, but java.util.logging.Logger.isLoggable will reject any message whose level is less than this x. So jul-to-slf4j will log a FINER message as DEBUG, but if you set the slf4j level to DEBUG, then FINER messages are rejected.

      Proposed implementation:

      I think the correct behavior is for LevelChangePropagator to return the minimum value in each jul-to-slf4j interval rather than the maximum value, so that any jul message that is converted to a given logback level will be enabled when the logback logger is set to that level.

      • slf4j TRACE → jul ALL = Integer.MIN_VALUE
      • DEBUG → FINEST + 1 = 301
      • INFO → FINE + 1 = 501
      • WARN → INFO + 1 = 801
      • ERROR → WARNING + 1 = 901
      • OFF → OFF (this is special-cased in java.util.logging.Logger.isLoggable)

       

        Attachments

          Activity

            People

            Assignee:
            ceki Ceki Gülcü
            Reporter:
            yonathan@gmail.com Yonathan Randolph
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved: