Logback logging system left in uninitialized state after executing JMX reloadDefaultConfiguration operation

[vpavic]

Issue can be reproduced using spring-boot-sample-logback and the following patch (Logback 1.1.6 is required to avoid NPE on reloadDefaultConfiguration, see qos-ch/logback#302):

diff --git spring-boot-samples/spring-boot-sample-logback/pom.xml spring-boot-samples/spring-boot-sample-logback/pom.xml
index 34efcd6..836a052 100644
--- spring-boot-samples/spring-boot-sample-logback/pom.xml
+++ spring-boot-samples/spring-boot-sample-logback/pom.xml
@@ -17,6 +17,7 @@
        </organization>
        <properties>
                <main.basedir>${basedir}/../..</main.basedir>
+               <logback.version>1.1.6</logback.version>
        </properties>
        <dependencies>
                <dependency>
diff --git spring-boot-samples/spring-boot-sample-logback/src/main/java/sample/logback/SampleLogbackApplication.java spring-boot-samples/spring-boot-sample-logback/src/main/java/sample/logback/SampleLogbackApplication.java
index 058fe1a..8569507 100644
--- spring-boot-samples/spring-boot-sample-logback/src/main/java/sample/logback/SampleLogbackApplication.java
+++ spring-boot-samples/spring-boot-sample-logback/src/main/java/sample/logback/SampleLogbackApplication.java
@@ -16,21 +16,22 @@

 package sample.logback;

-import javax.annotation.PostConstruct;
-
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;

 import org.springframework.boot.SpringApplication;
 import org.springframework.boot.autoconfigure.SpringBootApplication;
+import org.springframework.scheduling.annotation.EnableScheduling;
+import org.springframework.scheduling.annotation.Scheduled;

+@EnableScheduling
 @SpringBootApplication
 public class SampleLogbackApplication {

        private static final Logger logger = LoggerFactory
                        .getLogger(SampleLogbackApplication.class);

-       @PostConstruct
+       @Scheduled(fixedDelay = 5000)
        public void logSomething() {
                logger.debug("Sample Debug Message");
                logger.trace("Sample Trace Message");
diff --git spring-boot-samples/spring-boot-sample-logback/src/main/resources/logback-spring.xml spring-boot-samples/spring-boot-sample-logback/src/main/resources/logback-spring.xml
index e279b82..638b4c4 100644
--- spring-boot-samples/spring-boot-sample-logback/src/main/resources/logback-spring.xml
+++ spring-boot-samples/spring-boot-sample-logback/src/main/resources/logback-spring.xml
@@ -1,5 +1,6 @@
 <?xml version="1.0" encoding="UTF-8"?>
 <configuration>
+       <jmxConfigurator/>
        <include resource="org/springframework/boot/logging/logback/base.xml" />
        <logger name="sample.logback" level="DEBUG" />
        <springProfile name="staging">

Start the sample app, execute reloadDefaultConfiguration operation via JMX. The following output is logged:

21:33:08,445 |-INFO in ch.qos.logback.classic.jmx.JMXConfigurator(default) - Resetting context: default
21:33:08,445 |-INFO in ch.qos.logback.classic.jmx.JMXConfigurator(default) - onReset() method called JMXActivator [ch.qos.logback.classic:Name=default,Type=ch.qos.logback.classic.jmx.JMXConfigurator]

After that no further events are logged.

The problem is that there's no LoggerContextListener that would've notified logging system of reset operation and trigger the re-initialization.

[vpavic]

Any feedback on this issue?

[philwebb]

Supporting JXM logback reloading isn't something we've looked at. It would be a nice addition but it's not very high on the list at the moment.

[philwebb]

Mind you, you make some compelling points in your comments on #5321

[vpavic]

I'll try to take a more detailed look at this and come up with PR.

[philwebb]

Thanks!

[vpavic]

The cleanest way to fix this is to provide customized JMXConfigurator which hooks into LogbackLoggingSystem for reloadDefaultConfiguration and reloadByFileName operations. This is the approach I took in #4486.

Fixing this without adding without automatically registering JMXConfigurator would require replacing the default JMXConfiguratorAction with a custom one that registers previously mentioned customized JMXConfigurator (instead of the original one) when <jmxConfigurator/> is used in Logback configuration.