From 43361e0ca5180f608513e6f26d29d93c3a40142c Mon Sep 17 00:00:00 2001 From: Andy Wilkinson Date: Thu, 25 Aug 2016 15:17:25 +0100 Subject: [PATCH] Prevent child applications from reinitializing the logging system Closes gh-6688 --- .../logging/LoggingApplicationListener.java | 10 ++++++ .../logging/log4j2/Log4J2LoggingSystem.java | 33 +++++++++++++++++-- .../logging/logback/LogbackLoggingSystem.java | 26 +++++++++++++-- ...ngApplicationListenerIntegrationTests.java | 28 ++++++++++++++++ .../LoggingApplicationListenerTests.java | 16 +++++++++ .../log4j2/Log4J2LoggingSystemTests.java | 26 +++++++++++++++ .../logback/LogbackLoggingSystemTests.java | 26 +++++++++++++-- 7 files changed, 159 insertions(+), 6 deletions(-) diff --git a/spring-boot/src/main/java/org/springframework/boot/logging/LoggingApplicationListener.java b/spring-boot/src/main/java/org/springframework/boot/logging/LoggingApplicationListener.java index f1517f0785..01ac287e04 100644 --- a/spring-boot/src/main/java/org/springframework/boot/logging/LoggingApplicationListener.java +++ b/spring-boot/src/main/java/org/springframework/boot/logging/LoggingApplicationListener.java @@ -28,6 +28,7 @@ import org.springframework.beans.factory.config.ConfigurableListableBeanFactory; import org.springframework.boot.SpringApplication; import org.springframework.boot.bind.RelaxedPropertyResolver; import org.springframework.boot.context.event.ApplicationEnvironmentPreparedEvent; +import org.springframework.boot.context.event.ApplicationFailedEvent; import org.springframework.boot.context.event.ApplicationPreparedEvent; import org.springframework.boot.context.event.ApplicationStartedEvent; import org.springframework.context.ApplicationContext; @@ -214,6 +215,9 @@ public class LoggingApplicationListener implements GenericApplicationListener { .getApplicationContext().getParent() == null) { onContextClosedEvent(); } + else if (event instanceof ApplicationFailedEvent) { + onApplicationFailedEvent(); + } } private void onApplicationStartedEvent(ApplicationStartedEvent event) { @@ -245,6 +249,12 @@ public class LoggingApplicationListener implements GenericApplicationListener { } } + private void onApplicationFailedEvent() { + if (this.loggingSystem != null) { + this.loggingSystem.cleanUp(); + } + } + /** * Initialize the logging system according to preferences expressed through the * {@link Environment} and the classpath. diff --git a/spring-boot/src/main/java/org/springframework/boot/logging/log4j2/Log4J2LoggingSystem.java b/spring-boot/src/main/java/org/springframework/boot/logging/log4j2/Log4J2LoggingSystem.java index cf2aac58f4..955fa748a0 100644 --- a/spring-boot/src/main/java/org/springframework/boot/logging/log4j2/Log4J2LoggingSystem.java +++ b/spring-boot/src/main/java/org/springframework/boot/logging/log4j2/Log4J2LoggingSystem.java @@ -129,15 +129,24 @@ public class Log4J2LoggingSystem extends Slf4JLoggingSystem { @Override public void beforeInitialize() { + LoggerContext loggerContext = getLoggerContext(); + if (isAlreadyInitialized(loggerContext)) { + return; + } super.beforeInitialize(); - getLoggerContext().getConfiguration().addFilter(FILTER); + loggerContext.getConfiguration().addFilter(FILTER); } @Override public void initialize(LoggingInitializationContext initializationContext, String configLocation, LogFile logFile) { - getLoggerContext().getConfiguration().removeFilter(FILTER); + LoggerContext loggerContext = getLoggerContext(); + if (isAlreadyInitialized(loggerContext)) { + return; + } + loggerContext.getConfiguration().removeFilter(FILTER); super.initialize(initializationContext, configLocation, logFile); + markAsInitialized(loggerContext); } @Override @@ -204,6 +213,13 @@ public class Log4J2LoggingSystem extends Slf4JLoggingSystem { return new ShutdownHandler(); } + @Override + public void cleanUp() { + super.cleanUp(); + LoggerContext loggerContext = getLoggerContext(); + markAsUninitialized(loggerContext); + } + private LoggerConfig getLoggerConfig(String name) { name = (StringUtils.hasText(name) ? name : LogManager.ROOT_LOGGER_NAME); return getLoggerContext().getConfiguration().getLoggers().get(name); @@ -213,6 +229,18 @@ public class Log4J2LoggingSystem extends Slf4JLoggingSystem { return (LoggerContext) LogManager.getContext(false); } + private boolean isAlreadyInitialized(LoggerContext loggerContext) { + return LoggingSystem.class.getName().equals(loggerContext.getExternalContext()); + } + + private void markAsInitialized(LoggerContext loggerContext) { + loggerContext.setExternalContext(LoggingSystem.class.getName()); + } + + private void markAsUninitialized(LoggerContext loggerContext) { + loggerContext.setExternalContext(null); + } + private final class ShutdownHandler implements Runnable { @Override @@ -221,4 +249,5 @@ public class Log4J2LoggingSystem extends Slf4JLoggingSystem { } } + } diff --git a/spring-boot/src/main/java/org/springframework/boot/logging/logback/LogbackLoggingSystem.java b/spring-boot/src/main/java/org/springframework/boot/logging/logback/LogbackLoggingSystem.java index 4e2903dc00..b681bc9729 100644 --- a/spring-boot/src/main/java/org/springframework/boot/logging/logback/LogbackLoggingSystem.java +++ b/spring-boot/src/main/java/org/springframework/boot/logging/logback/LogbackLoggingSystem.java @@ -94,16 +94,25 @@ public class LogbackLoggingSystem extends Slf4JLoggingSystem { @Override public void beforeInitialize() { + LoggerContext loggerContext = getLoggerContext(); + if (isAlreadyInitialized(loggerContext)) { + return; + } super.beforeInitialize(); - getLogger(null).getLoggerContext().getTurboFilterList().add(FILTER); + loggerContext.getTurboFilterList().add(FILTER); configureJBossLoggingToUseSlf4j(); } @Override public void initialize(LoggingInitializationContext initializationContext, String configLocation, LogFile logFile) { - getLogger(null).getLoggerContext().getTurboFilterList().remove(FILTER); + LoggerContext loggerContext = getLoggerContext(); + if (isAlreadyInitialized(loggerContext)) { + return; + } + loggerContext.getTurboFilterList().remove(FILTER); super.initialize(initializationContext, configLocation, logFile); + markAsInitialized(loggerContext); if (StringUtils.hasText(System.getProperty(CONFIGURATION_FILE_PROPERTY))) { getLogger(LogbackLoggingSystem.class.getName()).warn( "Ignoring '" + CONFIGURATION_FILE_PROPERTY + "' system property. " @@ -184,6 +193,7 @@ public class LogbackLoggingSystem extends Slf4JLoggingSystem { @Override public void cleanUp() { + markAsUninitialized(getLoggerContext()); super.cleanUp(); getLoggerContext().getStatusManager().clear(); } @@ -243,6 +253,18 @@ public class LogbackLoggingSystem extends Slf4JLoggingSystem { return "unknown location"; } + private boolean isAlreadyInitialized(LoggerContext loggerContext) { + return loggerContext.getObject(LoggingSystem.class.getName()) != null; + } + + private void markAsInitialized(LoggerContext loggerContext) { + loggerContext.putObject(LoggingSystem.class.getName(), new Object()); + } + + private void markAsUninitialized(LoggerContext loggerContext) { + loggerContext.removeObject(LoggingSystem.class.getName()); + } + private final class ShutdownHandler implements Runnable { @Override diff --git a/spring-boot/src/test/java/org/springframework/boot/logging/LoggingApplicationListenerIntegrationTests.java b/spring-boot/src/test/java/org/springframework/boot/logging/LoggingApplicationListenerIntegrationTests.java index d0f24c6fd1..19bc4ba6e6 100644 --- a/spring-boot/src/test/java/org/springframework/boot/logging/LoggingApplicationListenerIntegrationTests.java +++ b/spring-boot/src/test/java/org/springframework/boot/logging/LoggingApplicationListenerIntegrationTests.java @@ -16,9 +16,15 @@ package org.springframework.boot.logging; +import org.junit.Rule; import org.junit.Test; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; import org.springframework.boot.builder.SpringApplicationBuilder; +import org.springframework.boot.context.event.ApplicationStartedEvent; +import org.springframework.boot.testutil.InternalOutputCapture; +import org.springframework.context.ApplicationListener; import org.springframework.context.ConfigurableApplicationContext; import org.springframework.stereotype.Component; @@ -31,6 +37,9 @@ import static org.assertj.core.api.Assertions.assertThat; */ public class LoggingApplicationListenerIntegrationTests { + @Rule + public InternalOutputCapture outputCapture = new InternalOutputCapture(); + @Test public void loggingSystemRegisteredInTheContext() { ConfigurableApplicationContext context = new SpringApplicationBuilder( @@ -44,6 +53,21 @@ public class LoggingApplicationListenerIntegrationTests { } } + @Test + public void loggingPerformedDuringChildApplicationStartIsNotLost() { + new SpringApplicationBuilder(Config.class).web(false).child(Config.class) + .web(false).listeners(new ApplicationListener() { + + private final Logger logger = LoggerFactory.getLogger(getClass()); + + @Override + public void onApplicationEvent(ApplicationStartedEvent event) { + this.logger.info("Child application started"); + } + }).run(); + assertThat(this.outputCapture.toString()).contains("Child application started"); + } + @Component static class SampleService { @@ -55,4 +79,8 @@ public class LoggingApplicationListenerIntegrationTests { } + static class Config { + + } + } diff --git a/spring-boot/src/test/java/org/springframework/boot/logging/LoggingApplicationListenerTests.java b/spring-boot/src/test/java/org/springframework/boot/logging/LoggingApplicationListenerTests.java index 371d0296bb..6378cbee5d 100644 --- a/spring-boot/src/test/java/org/springframework/boot/logging/LoggingApplicationListenerTests.java +++ b/spring-boot/src/test/java/org/springframework/boot/logging/LoggingApplicationListenerTests.java @@ -37,6 +37,7 @@ import org.slf4j.bridge.SLF4JBridgeHandler; import org.springframework.boot.ApplicationPid; import org.springframework.boot.SpringApplication; +import org.springframework.boot.context.event.ApplicationFailedEvent; import org.springframework.boot.context.event.ApplicationStartedEvent; import org.springframework.boot.logging.java.JavaLoggingSystem; import org.springframework.boot.testutil.InternalOutputCapture; @@ -464,6 +465,21 @@ public class LoggingApplicationListenerTests { .isEqualTo("target/" + new ApplicationPid().toString() + ".log"); } + @Test + public void applicationFailedEventCleansUpLoggingSystem() { + System.setProperty(LoggingSystem.SYSTEM_PROPERTY, + TestCleanupLoggingSystem.class.getName()); + this.initializer.onApplicationEvent( + new ApplicationStartedEvent(this.springApplication, new String[0])); + TestCleanupLoggingSystem loggingSystem = (TestCleanupLoggingSystem) ReflectionTestUtils + .getField(this.initializer, "loggingSystem"); + assertThat(loggingSystem.cleanedUp).isFalse(); + this.initializer + .onApplicationEvent(new ApplicationFailedEvent(this.springApplication, + new String[0], new GenericApplicationContext(), new Exception())); + assertThat(loggingSystem.cleanedUp).isTrue(); + } + private boolean bridgeHandlerInstalled() { Logger rootLogger = LogManager.getLogManager().getLogger(""); Handler[] handlers = rootLogger.getHandlers(); diff --git a/spring-boot/src/test/java/org/springframework/boot/logging/log4j2/Log4J2LoggingSystemTests.java b/spring-boot/src/test/java/org/springframework/boot/logging/log4j2/Log4J2LoggingSystemTests.java index d81b926e84..a9eff17d1b 100644 --- a/spring-boot/src/test/java/org/springframework/boot/logging/log4j2/Log4J2LoggingSystemTests.java +++ b/spring-boot/src/test/java/org/springframework/boot/logging/log4j2/Log4J2LoggingSystemTests.java @@ -16,6 +16,8 @@ package org.springframework.boot.logging.log4j2; +import java.beans.PropertyChangeEvent; +import java.beans.PropertyChangeListener; import java.io.File; import java.io.FileReader; import java.util.ArrayList; @@ -25,6 +27,7 @@ import java.util.List; import com.fasterxml.jackson.databind.ObjectMapper; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.core.LoggerContext; import org.apache.logging.log4j.core.config.Configuration; import org.hamcrest.Matcher; import org.hamcrest.Matchers; @@ -43,6 +46,10 @@ import org.springframework.util.StringUtils; import static org.assertj.core.api.Assertions.assertThat; import static org.hamcrest.Matchers.containsString; import static org.hamcrest.Matchers.not; +import static org.mockito.Matchers.any; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.times; +import static org.mockito.Mockito.verify; /** * Tests for {@link Log4J2LoggingSystem}. @@ -62,6 +69,7 @@ public class Log4J2LoggingSystemTests extends AbstractLoggingSystemTests { @Before public void setup() { + this.loggingSystem.cleanUp(); this.logger = LogManager.getLogger(getClass()); } @@ -223,6 +231,24 @@ public class Log4J2LoggingSystemTests extends AbstractLoggingSystemTests { } } + @Test + public void initializationIsOnlyPerformedOnceUntilCleanedUp() throws Exception { + LoggerContext loggerContext = (LoggerContext) LogManager.getContext(false); + PropertyChangeListener listener = mock(PropertyChangeListener.class); + loggerContext.addPropertyChangeListener(listener); + this.loggingSystem.beforeInitialize(); + this.loggingSystem.initialize(null, null, null); + this.loggingSystem.beforeInitialize(); + this.loggingSystem.initialize(null, null, null); + this.loggingSystem.beforeInitialize(); + this.loggingSystem.initialize(null, null, null); + verify(listener, times(2)).propertyChange(any(PropertyChangeEvent.class)); + this.loggingSystem.cleanUp(); + this.loggingSystem.beforeInitialize(); + this.loggingSystem.initialize(null, null, null); + verify(listener, times(4)).propertyChange(any(PropertyChangeEvent.class)); + } + private static class TestLog4J2LoggingSystem extends Log4J2LoggingSystem { private List availableClasses = new ArrayList(); diff --git a/spring-boot/src/test/java/org/springframework/boot/logging/logback/LogbackLoggingSystemTests.java b/spring-boot/src/test/java/org/springframework/boot/logging/logback/LogbackLoggingSystemTests.java index f86188ef84..39b4d9810a 100644 --- a/spring-boot/src/test/java/org/springframework/boot/logging/logback/LogbackLoggingSystemTests.java +++ b/spring-boot/src/test/java/org/springframework/boot/logging/logback/LogbackLoggingSystemTests.java @@ -23,6 +23,7 @@ import java.util.logging.LogManager; import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.LoggerContext; +import ch.qos.logback.classic.spi.LoggerContextListener; import org.apache.commons.logging.Log; import org.apache.commons.logging.impl.SLF4JLogFactory; import org.hamcrest.Matcher; @@ -48,6 +49,9 @@ import org.springframework.util.StringUtils; import static org.assertj.core.api.Assertions.assertThat; import static org.hamcrest.Matchers.containsString; import static org.hamcrest.Matchers.not; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.times; +import static org.mockito.Mockito.verify; /** * Tests for {@link LogbackLoggingSystem}. @@ -72,6 +76,7 @@ public class LogbackLoggingSystemTests extends AbstractLoggingSystemTests { @Before public void setup() { + this.loggingSystem.cleanUp(); this.logger = new SLF4JLogFactory().getInstance(getClass().getName()); this.environment = new MockEnvironment(); this.initializationContext = new LoggingInitializationContext(this.environment); @@ -304,17 +309,34 @@ public class LogbackLoggingSystemTests extends AbstractLoggingSystemTests { } @Test - public void reinitializeShouldSetSystemProperty() throws Exception { + public void initializeShouldSetSystemProperty() throws Exception { // gh-5491 this.loggingSystem.beforeInitialize(); this.logger.info("Hidden"); - this.loggingSystem.initialize(this.initializationContext, null, null); LogFile logFile = getLogFile(tmpDir() + "/example.log", null, false); this.loggingSystem.initialize(this.initializationContext, "classpath:logback-nondefault.xml", logFile); assertThat(System.getProperty("LOG_FILE")).endsWith("example.log"); } + @Test + public void initializationIsOnlyPerformedOnceUntilCleanedUp() throws Exception { + LoggerContext loggerContext = (LoggerContext) StaticLoggerBinder.getSingleton() + .getLoggerFactory(); + LoggerContextListener listener = mock(LoggerContextListener.class); + loggerContext.addListener(listener); + this.loggingSystem.beforeInitialize(); + this.loggingSystem.initialize(this.initializationContext, null, null); + this.loggingSystem.beforeInitialize(); + this.loggingSystem.initialize(this.initializationContext, null, null); + verify(listener, times(1)).onReset(loggerContext); + this.loggingSystem.cleanUp(); + loggerContext.addListener(listener); + this.loggingSystem.beforeInitialize(); + this.loggingSystem.initialize(this.initializationContext, null, null); + verify(listener, times(2)).onReset(loggerContext); + } + private String getLineWithText(File file, String outputSearch) throws Exception { return getLineWithText(FileCopyUtils.copyToString(new FileReader(file)), outputSearch);