Log4j fails to honor lastModifiedTime

[feujun]

Description

When using a monitorInterval setting on a remote/http log4j.xml the reconfigure-thread does not update the lastModifiedTime of the configuration source and reconfigures the loggers every time.

Configuration

Version: 2.23 and 2.24

Operating system: Windows 10

JDK: AdoptOpenJDK 21

Logs

log.txt

Reproduction

I don't really have a completely isolated test. The problem does not occur when using a file-based log-config, so you need something like a webserver.

My test-setup looks like this:

Main

public static void main(String[] args) throws Exception {
  System.setProperty("log4j2.debug", "true");
  System.setProperty("log4j2.Configuration.allowedProtocols","http,https,file,jar");
		
    Configurator.reconfigure(URI.create("http://sfs00053/configs/t7/client/testlog.xml"));

    new Thread(() -> {
      while (true) {
      try {
        LogManager.getLogger().error("hello");
        TimeUnit.SECONDS.sleep(5);
      } catch (InterruptedException e) {
        throw new RuntimeException(e);
      }
    }
  }).start();
}

Log-Config

<?xml version="1.0" encoding="UTF-8" ?>
<Configuration monitorInterval="10">
  <Appenders>

    <Console name="STDOUT" target="SYSTEM_OUT">
      <PatternLayout pattern="%d | %-5p | %c | %m%n" />
    </Console>
  </Appenders>
  <Loggers>

    <Root level="DEBUG">
      <AppenderRef ref="STDOUT" />
    </Root>
  </Loggers>
</Configuration>

Steps to reproduce

1. Change the log4j.xml-location in the main to your own location
2. Start the main. log4j2 should configure itself with the given log-config and log every 5 seconds
3. Change the file on the webserver so the lastModified of the log-config is newer than the one log4j2 knows (e.g. by touch testlog.xml)
4. log4j2 will now reconfigure every 10 seconds and not only once because it doesn't honor the new lastModified

See also the attached log. I changed the file on the webserver after the first watchmonitor run. After that it reconfigured itself every time.

I hope I filled out this issue correctly. If something's missing please let me know :)

[ppkarwasz]

@feujun,

Nice catch! Effectively, if the configuration location is an http or https URI, reconfiguration will occur every monitorInterval seconds after the first change to the file.

This will be fixed in 2.24.1.

[feujun]

That sounds great, thank you very much :)