Skip to content

[JENKINS-75310] Setting log level from bottom up in custom log recorders doesn't work correctly #16660

Description

@jenkins-infra-bot

When we create a custom log recorder, if we set the levels from higher to lower, it correctly takes effect. But if we do the other way round, set the level from lower to higher, it doesn't reflect correctly – still partially stays on the lowest level.

 

Why say partially ?

  • the level reflected by LOGGER.getLevel() stays at the lowest. Lets say you changed the level from FINEST to FINE (or INFO), the returned value of LOGGER.getLevel() is still FINEST.
  • however logging statements like LOGGER.log(..) or LOGGER.finest(..) (and others) correctly see the level. Thus there are no log messages seen for lower level logging statements than the currently set level.

 

The level gets correctly set,

  • if we manually set it from the Log Levels page.
  • if we delete the log recorder and recreate it at the desired level.
  • or, restart the Jenkins controller.

 

This particularly causes bug in code like,

if (LOGGER.isLoggable(Level.FINER)) {
    LOGGER.finer("Detailed debug info with parameters.");
} else {
    LOGGER.info("Intermittent issue detected. Monitor if it persists."); 
} 

Once we changed from say FINER to INFO or to any higher level, the code still goes into if block whereas it was expected to go into the else block. Although it goes into the if block, it doesn't log anything – because inside the LOGGER.finer(...) method or LOGGER.log(..) method the level is correctly evaluated.
 

This behavior is quite confusing and appears to be incorrect memory state of loggers (the `log/.xml` file is correct) - as the issues fixes itself upon controller restart.

Steps to Reproduce

Reproduction can be done using this minimal example
https://github.com/gbhat618/minimal/blob/main/src/main/java/io/jenkins/plugins/sample/LogRecorderLevelDebug.java

Run the minimal plugin with,

mvn hpi:run

Verify the correct behavior

  • create a log recorder for class LogRecorderLevelDebug; the periodic work runs every 5s, so you will start seeing info logs. At the beginning the level will be reported null. It is expected.
  • try to change from INFO to FINE and then from FINE to FINEST. You will see all the logs correctly.
  • Also keep noticing that the LogRecorderLevelDebug has appeared in the Log Levels page and it is correctly reflecting the levels as changed in the configure.

Verify the incorrect behavior

  • change the recorder level from FINEST to FINE; notice the level is reported incorrectly as still FINEST; however the actual FINEST log is not coming, only the FINE and INFO are coming. (the actual FINEST log entry would be FINEST level log - which is missing here)
    Feb 21, 2025 8:34:25 AM INFO io.jenkins.plugins.sample.LogRecorderLevelDebug doRun
    Current log level: FINEST
    Feb 21, 2025 8:34:25 AM FINE io.jenkins.plugins.sample.LogRecorderLevelDebug
    FINE level log inside the if block
    Feb 21, 2025 8:34:25 AM INFO io.jenkins.plugins.sample.LogRecorderLevelDebug doRun
    INFO level log inside the if block
    
  • change the recorder from FINE to INFO; notice only the INFO entry from within the if block is coming; while expected was the entry from the else block
    Feb 21, 2025 8:37:45 AM INFO io.jenkins.plugins.sample.LogRecorderLevelDebug doRun
    Current log level: FINEST
    Feb 21, 2025 8:37:45 AM INFO io.jenkins.plugins.sample.LogRecorderLevelDebug doRun
    INFO level log inside the if block
    
  • During this time in the Log Levels Page you will see that the level for LogRecorderLevelDebug is still set as FINEST, and it is not reflecting the recorder's level. It was reflecting when we were changing the level from higher to lower, it is not reflecting when changing from lower to higher.
Description Screenshot
The Log Level that referred in the above notes; find here
Example of Log Level incorrectly showing the FINEST level even when the recorder is changed to higher level INFO

Originally reported by gbhat, imported from: Setting log level from bottom up in custom log recorders doesn't work correctly
  • status: Open
  • priority: Minor
  • component(s): core
  • label(s): core
  • resolution: Unresolved
  • votes: 0
  • watchers: 2
  • imported: 2025-11-24
Raw content of original issue

When we create a custom log recorder, if we set the levels from higher to lower, it correctly takes effect. But if we do the other way round, set the level from lower to higher, it doesn't reflect correctly – still partially stays on the lowest level.

 

Why say partially ?

  • the level reflected by LOGGER.getLevel() stays at the lowest. Lets say you changed the level from FINEST to FINE (or INFO), the returned value of LOGGER.getLevel() is still FINEST.
  • however logging statements like LOGGER.log(..) or LOGGER.finest(..) (and others) correctly see the level. Thus there are no log messages seen for lower level logging statements than the currently set level.

 

The level gets correctly set,

  • if we manually set it from the Log Levels page.
  • if we delete the log recorder and recreate it at the desired level.
  • or, restart the Jenkins controller.

 

This particularly causes bug in code like,

if (LOGGER.isLoggable(Level.FINER)) {
    LOGGER.finer("Detailed debug info with parameters.");
} else {
    LOGGER.info("Intermittent issue detected. Monitor if it persists."); 
} 

Once we changed from say FINER to INFO or to any higher level, the code still goes into if block whereas it was expected to go into the else block. Although it goes into the if block, it doesn't log anything – because inside the LOGGER.finer(...) method or LOGGER.log(..) method the level is correctly evaluated.  

This behavior is quite confusing and appears to be incorrect memory state of loggers (the `log/<my-logger>.xml` file is correct) - as the issues fixes itself upon controller restart.

Steps to Reproduce

Reproduction can be done using this minimal example https://github.com/gbhat618/minimal/blob/main/src/main/java/io/jenkins/plugins/sample/LogRecorderLevelDebug.java

Run the minimal plugin with,

mvn hpi:run

Verify the correct behavior

  • create a log recorder for class LogRecorderLevelDebug; the periodic work runs every 5s, so you will start seeing info logs. At the beginning the level will be reported null. It is expected.
  • try to change from INFO to FINE and then from FINE to FINEST. You will see all the logs correctly.
  • Also keep noticing that the LogRecorderLevelDebug has appeared in the Log Levels page and it is correctly reflecting the levels as changed in the configure.

Verify the incorrect behavior

  • change the recorder level from FINEST to FINE; notice the level is reported incorrectly as still FINEST; however the actual FINEST log is not coming, only the FINE and INFO are coming. (the actual FINEST log entry would be FINEST level log - which is missing here)
    Feb 21, 2025 8:34:25 AM INFO io.jenkins.plugins.sample.LogRecorderLevelDebug doRun
    Current log level: FINEST
    Feb 21, 2025 8:34:25 AM FINE io.jenkins.plugins.sample.LogRecorderLevelDebug
    FINE level log inside the if block
    Feb 21, 2025 8:34:25 AM INFO io.jenkins.plugins.sample.LogRecorderLevelDebug doRun
    INFO level log inside the if block
    
  • change the recorder from FINE to INFO; notice only the INFO entry from within the if block is coming; while expected was the entry from the else block
    Feb 21, 2025 8:37:45 AM INFO io.jenkins.plugins.sample.LogRecorderLevelDebug doRun
    Current log level: FINEST
    Feb 21, 2025 8:37:45 AM INFO io.jenkins.plugins.sample.LogRecorderLevelDebug doRun
    INFO level log inside the if block
    
  • During this time in the Log Levels Page you will see that the level for LogRecorderLevelDebug is still set as FINEST, and it is not reflecting the recorder's level. It was reflecting when we were changing the level from higher to lower, it is not reflecting when changing from lower to higher.
Description Screenshot
The Log Level that referred in the above notes; find here
Example of Log Level incorrectly showing the FINEST level even when the recorder is changed to higher level INFO
  • environment: I am able to demostrate the bug in latest version 2.492.1. But it appears to be existing older versions as well (possibly from quite log).
2 attachments

Metadata

Metadata

Assignees

No one assigned

    Type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions