Perform LoggingSystem cleanup after web server shutdown

Update `LoggingApplicationListener` so that logging system cleanup is
performed by a `SmartLifecycle` phased after web server shutdown.

Prior to this commit, cleanup occurred on the `ContextClosedEvent` which
was published before Lifecycle beans were stopped. This meant that any
exceptions output during web server shutdown were not logged.

Fixes gh-9457
pull/32234/head
Phillip Webb 2 years ago
parent d69fcf8948
commit 45ad1557c3

@ -45,6 +45,8 @@ import org.springframework.boot.logging.LoggingSystemProperties;
import org.springframework.context.ApplicationContext; import org.springframework.context.ApplicationContext;
import org.springframework.context.ApplicationEvent; import org.springframework.context.ApplicationEvent;
import org.springframework.context.ApplicationListener; import org.springframework.context.ApplicationListener;
import org.springframework.context.ConfigurableApplicationContext;
import org.springframework.context.SmartLifecycle;
import org.springframework.context.event.ContextClosedEvent; import org.springframework.context.event.ContextClosedEvent;
import org.springframework.context.event.GenericApplicationListener; import org.springframework.context.event.GenericApplicationListener;
import org.springframework.core.Ordered; import org.springframework.core.Ordered;
@ -136,6 +138,11 @@ public class LoggingApplicationListener implements GenericApplicationListener {
*/ */
public static final String LOGGER_GROUPS_BEAN_NAME = "springBootLoggerGroups"; public static final String LOGGER_GROUPS_BEAN_NAME = "springBootLoggerGroups";
/**
* The name of the {@link Lifecycle} bean used to handle cleanup.
*/
private static final String LOGGING_LIFECYCLE_BEAN_NAME = "springBootLoggingLifecycle";
private static final Map<String, List<String>> DEFAULT_GROUP_LOGGERS; private static final Map<String, List<String>> DEFAULT_GROUP_LOGGERS;
static { static {
MultiValueMap<String, String> loggers = new LinkedMultiValueMap<>(); MultiValueMap<String, String> loggers = new LinkedMultiValueMap<>();
@ -218,9 +225,8 @@ public class LoggingApplicationListener implements GenericApplicationListener {
else if (event instanceof ApplicationPreparedEvent) { else if (event instanceof ApplicationPreparedEvent) {
onApplicationPreparedEvent((ApplicationPreparedEvent) event); onApplicationPreparedEvent((ApplicationPreparedEvent) event);
} }
else if (event instanceof ContextClosedEvent else if (event instanceof ContextClosedEvent) {
&& ((ContextClosedEvent) event).getApplicationContext().getParent() == null) { onContextClosedEvent((ContextClosedEvent) event);
onContextClosedEvent();
} }
else if (event instanceof ApplicationFailedEvent) { else if (event instanceof ApplicationFailedEvent) {
onApplicationFailedEvent(); onApplicationFailedEvent();
@ -241,7 +247,8 @@ public class LoggingApplicationListener implements GenericApplicationListener {
} }
private void onApplicationPreparedEvent(ApplicationPreparedEvent event) { private void onApplicationPreparedEvent(ApplicationPreparedEvent event) {
ConfigurableListableBeanFactory beanFactory = event.getApplicationContext().getBeanFactory(); ConfigurableApplicationContext applicationContext = event.getApplicationContext();
ConfigurableListableBeanFactory beanFactory = applicationContext.getBeanFactory();
if (!beanFactory.containsBean(LOGGING_SYSTEM_BEAN_NAME)) { if (!beanFactory.containsBean(LOGGING_SYSTEM_BEAN_NAME)) {
beanFactory.registerSingleton(LOGGING_SYSTEM_BEAN_NAME, this.loggingSystem); beanFactory.registerSingleton(LOGGING_SYSTEM_BEAN_NAME, this.loggingSystem);
} }
@ -251,20 +258,29 @@ public class LoggingApplicationListener implements GenericApplicationListener {
if (this.loggerGroups != null && !beanFactory.containsBean(LOGGER_GROUPS_BEAN_NAME)) { if (this.loggerGroups != null && !beanFactory.containsBean(LOGGER_GROUPS_BEAN_NAME)) {
beanFactory.registerSingleton(LOGGER_GROUPS_BEAN_NAME, this.loggerGroups); beanFactory.registerSingleton(LOGGER_GROUPS_BEAN_NAME, this.loggerGroups);
} }
if (!beanFactory.containsBean(LOGGING_LIFECYCLE_BEAN_NAME) && applicationContext.getParent() == null) {
beanFactory.registerSingleton(LOGGING_LIFECYCLE_BEAN_NAME, new Lifecycle());
}
} }
private void onContextClosedEvent() { private void onContextClosedEvent(ContextClosedEvent event) {
if (this.loggingSystem != null) { ApplicationContext applicationContext = event.getApplicationContext();
this.loggingSystem.cleanUp(); if (applicationContext.getParent() != null || applicationContext.containsBean(LOGGING_LIFECYCLE_BEAN_NAME)) {
return;
} }
cleanupLoggingSystem();
} }
private void onApplicationFailedEvent() { void cleanupLoggingSystem() {
if (this.loggingSystem != null) { if (this.loggingSystem != null) {
this.loggingSystem.cleanUp(); this.loggingSystem.cleanUp();
} }
} }
private void onApplicationFailedEvent() {
cleanupLoggingSystem();
}
/** /**
* Initialize the logging system according to preferences expressed through the * Initialize the logging system according to preferences expressed through the
* {@link Environment} and the classpath. * {@link Environment} and the classpath.
@ -438,4 +454,32 @@ public class LoggingApplicationListener implements GenericApplicationListener {
this.parseArgs = parseArgs; this.parseArgs = parseArgs;
} }
private class Lifecycle implements SmartLifecycle {
private volatile boolean running;
@Override
public void start() {
this.running = true;
}
@Override
public void stop() {
this.running = false;
cleanupLoggingSystem();
}
@Override
public boolean isRunning() {
return this.running;
}
@Override
public int getPhase() {
// Shutdown late and always after WebServerStartStopLifecycle
return Integer.MIN_VALUE + 1;
}
}
} }

@ -1,5 +1,5 @@
/* /*
* Copyright 2012-2021 the original author or authors. * Copyright 2012-2022 the original author or authors.
* *
* Licensed under the Apache License, Version 2.0 (the "License"); * Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License. * you may not use this file except in compliance with the License.
@ -46,6 +46,7 @@ import org.slf4j.impl.StaticLoggerBinder;
import org.springframework.boot.DefaultBootstrapContext; import org.springframework.boot.DefaultBootstrapContext;
import org.springframework.boot.SpringApplication; import org.springframework.boot.SpringApplication;
import org.springframework.boot.WebApplicationType;
import org.springframework.boot.context.event.ApplicationFailedEvent; import org.springframework.boot.context.event.ApplicationFailedEvent;
import org.springframework.boot.context.event.ApplicationStartingEvent; import org.springframework.boot.context.event.ApplicationStartingEvent;
import org.springframework.boot.context.properties.bind.BindException; import org.springframework.boot.context.properties.bind.BindException;
@ -66,6 +67,9 @@ import org.springframework.boot.testsupport.system.OutputCaptureExtension;
import org.springframework.context.ApplicationEvent; import org.springframework.context.ApplicationEvent;
import org.springframework.context.ApplicationListener; import org.springframework.context.ApplicationListener;
import org.springframework.context.ConfigurableApplicationContext; import org.springframework.context.ConfigurableApplicationContext;
import org.springframework.context.SmartLifecycle;
import org.springframework.context.annotation.Configuration;
import org.springframework.context.annotation.Import;
import org.springframework.context.event.ContextClosedEvent; import org.springframework.context.event.ContextClosedEvent;
import org.springframework.context.event.SimpleApplicationEventMulticaster; import org.springframework.context.event.SimpleApplicationEventMulticaster;
import org.springframework.context.support.GenericApplicationContext; import org.springframework.context.support.GenericApplicationContext;
@ -95,7 +99,7 @@ class LoggingApplicationListenerTests {
private static final String[] NO_ARGS = {}; private static final String[] NO_ARGS = {};
private final LoggingApplicationListener initializer = new LoggingApplicationListener(); private final LoggingApplicationListener listener = new LoggingApplicationListener();
private final LoggerContext loggerContext = (LoggerContext) StaticLoggerBinder.getSingleton().getLoggerFactory(); private final LoggerContext loggerContext = (LoggerContext) StaticLoggerBinder.getSingleton().getLoggerFactory();
@ -103,7 +107,7 @@ class LoggingApplicationListenerTests {
private final DefaultBootstrapContext bootstrapContext = new DefaultBootstrapContext(); private final DefaultBootstrapContext bootstrapContext = new DefaultBootstrapContext();
private final SpringApplication springApplication = new SpringApplication(); private final SpringApplication springApplication = new SpringApplication(TestConfiguration.class);
private final GenericApplicationContext context = new GenericApplicationContext(); private final GenericApplicationContext context = new GenericApplicationContext();
@ -146,7 +150,7 @@ class LoggingApplicationListenerTests {
@Test @Test
void baseConfigLocation() { void baseConfigLocation() {
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
this.logger.info("Hello world", new RuntimeException("Expected")); this.logger.info("Hello world", new RuntimeException("Expected"));
assertThat(this.output).contains("Hello world"); assertThat(this.output).contains("Hello world");
assertThat(this.output).doesNotContain("???"); assertThat(this.output).doesNotContain("???");
@ -157,7 +161,7 @@ class LoggingApplicationListenerTests {
@Test @Test
void overrideConfigLocation() { void overrideConfigLocation() {
addPropertiesToEnvironment(this.context, "logging.config=classpath:logback-nondefault.xml"); addPropertiesToEnvironment(this.context, "logging.config=classpath:logback-nondefault.xml");
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
this.logger.info("Hello world"); this.logger.info("Hello world");
assertThat(this.output).contains("Hello world").doesNotContain("???").startsWith("null ").endsWith("BOOTBOOT"); assertThat(this.output).contains("Hello world").doesNotContain("???").startsWith("null ").endsWith("BOOTBOOT");
} }
@ -165,7 +169,7 @@ class LoggingApplicationListenerTests {
@Test @Test
void trailingWhitespaceInLoggingConfigShouldBeTrimmed() { void trailingWhitespaceInLoggingConfigShouldBeTrimmed() {
addPropertiesToEnvironment(this.context, "logging.config=classpath:logback-nondefault.xml "); addPropertiesToEnvironment(this.context, "logging.config=classpath:logback-nondefault.xml ");
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
this.logger.info("Hello world"); this.logger.info("Hello world");
assertThat(this.output).contains("Hello world").doesNotContain("???").startsWith("null ").endsWith("BOOTBOOT"); assertThat(this.output).contains("Hello world").doesNotContain("???").startsWith("null ").endsWith("BOOTBOOT");
} }
@ -174,7 +178,7 @@ class LoggingApplicationListenerTests {
void overrideConfigDoesNotExist() { void overrideConfigDoesNotExist() {
addPropertiesToEnvironment(this.context, "logging.config=doesnotexist.xml"); addPropertiesToEnvironment(this.context, "logging.config=doesnotexist.xml");
assertThatIllegalStateException().isThrownBy( assertThatIllegalStateException().isThrownBy(
() -> this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader())); () -> this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader()));
assertThat(this.output) assertThat(this.output)
.contains("Logging system failed to initialize using configuration from 'doesnotexist.xml'") .contains("Logging system failed to initialize using configuration from 'doesnotexist.xml'")
.doesNotContain("JoranException"); .doesNotContain("JoranException");
@ -184,7 +188,7 @@ class LoggingApplicationListenerTests {
void azureDefaultLoggingConfigDoesNotCauseAFailure() { void azureDefaultLoggingConfigDoesNotCauseAFailure() {
addPropertiesToEnvironment(this.context, addPropertiesToEnvironment(this.context,
"logging.config=-Djava.util.logging.config.file=\"d:\\home\\site\\wwwroot\\bin\\apache-tomcat-7.0.52\\conf\\logging.properties\""); "logging.config=-Djava.util.logging.config.file=\"d:\\home\\site\\wwwroot\\bin\\apache-tomcat-7.0.52\\conf\\logging.properties\"");
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
this.logger.info("Hello world"); this.logger.info("Hello world");
assertThat(this.output).contains("Hello world").doesNotContain("???"); assertThat(this.output).contains("Hello world").doesNotContain("???");
assertThat(new File(this.tempDir.toFile(), "/spring.log").exists()).isFalse(); assertThat(new File(this.tempDir.toFile(), "/spring.log").exists()).isFalse();
@ -193,7 +197,7 @@ class LoggingApplicationListenerTests {
@Test @Test
void tomcatNopLoggingConfigDoesNotCauseAFailure() { void tomcatNopLoggingConfigDoesNotCauseAFailure() {
addPropertiesToEnvironment(this.context, "LOGGING_CONFIG=-Dnop"); addPropertiesToEnvironment(this.context, "LOGGING_CONFIG=-Dnop");
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
this.logger.info("Hello world"); this.logger.info("Hello world");
assertThat(this.output).contains("Hello world").doesNotContain("???"); assertThat(this.output).contains("Hello world").doesNotContain("???");
assertThat(new File(this.tempDir.toFile(), "/spring.log").exists()).isFalse(); assertThat(new File(this.tempDir.toFile(), "/spring.log").exists()).isFalse();
@ -203,7 +207,7 @@ class LoggingApplicationListenerTests {
void overrideConfigBroken() { void overrideConfigBroken() {
addPropertiesToEnvironment(this.context, "logging.config=classpath:logback-broken.xml"); addPropertiesToEnvironment(this.context, "logging.config=classpath:logback-broken.xml");
assertThatIllegalStateException().isThrownBy(() -> { assertThatIllegalStateException().isThrownBy(() -> {
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
assertThat(this.output).contains( assertThat(this.output).contains(
"Logging system failed to initialize using configuration from 'classpath:logback-broken.xml'"); "Logging system failed to initialize using configuration from 'classpath:logback-broken.xml'");
assertThat(this.output).contains("ConsolAppender"); assertThat(this.output).contains("ConsolAppender");
@ -214,7 +218,7 @@ class LoggingApplicationListenerTests {
void addLogFileProperty() { void addLogFileProperty() {
addPropertiesToEnvironment(this.context, "logging.config=classpath:logback-nondefault.xml", addPropertiesToEnvironment(this.context, "logging.config=classpath:logback-nondefault.xml",
"logging.file.name=" + this.logFile); "logging.file.name=" + this.logFile);
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
Log logger = LogFactory.getLog(LoggingApplicationListenerTests.class); Log logger = LogFactory.getLog(LoggingApplicationListenerTests.class);
String existingOutput = this.output.toString(); String existingOutput = this.output.toString();
logger.info("Hello world"); logger.info("Hello world");
@ -226,7 +230,7 @@ class LoggingApplicationListenerTests {
void addLogFilePropertyWithDefault() { void addLogFilePropertyWithDefault() {
assertThat(this.logFile).doesNotExist(); assertThat(this.logFile).doesNotExist();
addPropertiesToEnvironment(this.context, "logging.file.name=" + this.logFile); addPropertiesToEnvironment(this.context, "logging.file.name=" + this.logFile);
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
Log logger = LogFactory.getLog(LoggingApplicationListenerTests.class); Log logger = LogFactory.getLog(LoggingApplicationListenerTests.class);
logger.info("Hello world"); logger.info("Hello world");
assertThat(this.logFile).isFile(); assertThat(this.logFile).isFile();
@ -236,7 +240,7 @@ class LoggingApplicationListenerTests {
void addLogPathProperty() { void addLogPathProperty() {
addPropertiesToEnvironment(this.context, "logging.config=classpath:logback-nondefault.xml", addPropertiesToEnvironment(this.context, "logging.config=classpath:logback-nondefault.xml",
"logging.file.path=" + this.tempDir); "logging.file.path=" + this.tempDir);
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
Log logger = LogFactory.getLog(LoggingApplicationListenerTests.class); Log logger = LogFactory.getLog(LoggingApplicationListenerTests.class);
String existingOutput = this.output.toString(); String existingOutput = this.output.toString();
logger.info("Hello world"); logger.info("Hello world");
@ -247,7 +251,7 @@ class LoggingApplicationListenerTests {
@Test @Test
void parseDebugArg() { void parseDebugArg() {
addPropertiesToEnvironment(this.context, "debug"); addPropertiesToEnvironment(this.context, "debug");
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
this.logger.debug("testatdebug"); this.logger.debug("testatdebug");
this.logger.trace("testattrace"); this.logger.trace("testattrace");
assertThat(this.output).contains("testatdebug"); assertThat(this.output).contains("testatdebug");
@ -257,19 +261,19 @@ class LoggingApplicationListenerTests {
@Test @Test
void parseDebugArgExpandGroups() { void parseDebugArgExpandGroups() {
addPropertiesToEnvironment(this.context, "debug"); addPropertiesToEnvironment(this.context, "debug");
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
this.loggerContext.getLogger("org.springframework.boot.actuate.endpoint.web").debug("testdebugwebgroup"); this.loggerContext.getLogger("org.springframework.boot.actuate.endpoint.web").debug("testdebugwebgroup");
this.loggerContext.getLogger("org.hibernate.SQL").debug("testdebugsqlgroup"); this.loggerContext.getLogger("org.hibernate.SQL").debug("testdebugsqlgroup");
assertThat(this.output).contains("testdebugwebgroup"); assertThat(this.output).contains("testdebugwebgroup");
assertThat(this.output).contains("testdebugsqlgroup"); assertThat(this.output).contains("testdebugsqlgroup");
LoggerGroups loggerGroups = (LoggerGroups) ReflectionTestUtils.getField(this.initializer, "loggerGroups"); LoggerGroups loggerGroups = (LoggerGroups) ReflectionTestUtils.getField(this.listener, "loggerGroups");
assertThat(loggerGroups.get("web").getConfiguredLevel()).isEqualTo(LogLevel.DEBUG); assertThat(loggerGroups.get("web").getConfiguredLevel()).isEqualTo(LogLevel.DEBUG);
} }
@Test @Test
void parseTraceArg() { void parseTraceArg() {
addPropertiesToEnvironment(this.context, "trace"); addPropertiesToEnvironment(this.context, "trace");
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
this.logger.debug("testatdebug"); this.logger.debug("testatdebug");
this.logger.trace("testattrace"); this.logger.trace("testattrace");
assertThat(this.output).contains("testatdebug"); assertThat(this.output).contains("testatdebug");
@ -288,7 +292,7 @@ class LoggingApplicationListenerTests {
private void disableDebugTraceArg(String... environment) { private void disableDebugTraceArg(String... environment) {
addPropertiesToEnvironment(this.context, environment); addPropertiesToEnvironment(this.context, environment);
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
this.logger.debug("testatdebug"); this.logger.debug("testatdebug");
this.logger.trace("testattrace"); this.logger.trace("testattrace");
assertThat(this.output).doesNotContain("testatdebug"); assertThat(this.output).doesNotContain("testatdebug");
@ -298,7 +302,7 @@ class LoggingApplicationListenerTests {
@Test @Test
void parseLevels() { void parseLevels() {
addPropertiesToEnvironment(this.context, "logging.level.org.springframework.boot=TRACE"); addPropertiesToEnvironment(this.context, "logging.level.org.springframework.boot=TRACE");
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
this.logger.debug("testatdebug"); this.logger.debug("testatdebug");
this.logger.trace("testattrace"); this.logger.trace("testattrace");
assertThat(this.output).contains("testatdebug"); assertThat(this.output).contains("testatdebug");
@ -308,7 +312,7 @@ class LoggingApplicationListenerTests {
@Test @Test
void parseLevelsCaseInsensitive() { void parseLevelsCaseInsensitive() {
addPropertiesToEnvironment(this.context, "logging.level.org.springframework.boot=TrAcE"); addPropertiesToEnvironment(this.context, "logging.level.org.springframework.boot=TrAcE");
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
this.logger.debug("testatdebug"); this.logger.debug("testatdebug");
this.logger.trace("testattrace"); this.logger.trace("testattrace");
assertThat(this.output).contains("testatdebug"); assertThat(this.output).contains("testatdebug");
@ -318,7 +322,7 @@ class LoggingApplicationListenerTests {
@Test @Test
void parseLevelsTrimsWhitespace() { void parseLevelsTrimsWhitespace() {
addPropertiesToEnvironment(this.context, "logging.level.org.springframework.boot= trace "); addPropertiesToEnvironment(this.context, "logging.level.org.springframework.boot= trace ");
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
this.logger.debug("testatdebug"); this.logger.debug("testatdebug");
this.logger.trace("testattrace"); this.logger.trace("testattrace");
assertThat(this.output).contains("testatdebug"); assertThat(this.output).contains("testatdebug");
@ -328,7 +332,7 @@ class LoggingApplicationListenerTests {
@Test @Test
void parseLevelsWithPlaceholder() { void parseLevelsWithPlaceholder() {
addPropertiesToEnvironment(this.context, "foo=TRACE", "logging.level.org.springframework.boot=${foo}"); addPropertiesToEnvironment(this.context, "foo=TRACE", "logging.level.org.springframework.boot=${foo}");
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
this.logger.debug("testatdebug"); this.logger.debug("testatdebug");
this.logger.trace("testattrace"); this.logger.trace("testattrace");
assertThat(this.output).contains("testatdebug"); assertThat(this.output).contains("testatdebug");
@ -340,13 +344,13 @@ class LoggingApplicationListenerTests {
this.logger.setLevel(Level.INFO); this.logger.setLevel(Level.INFO);
addPropertiesToEnvironment(this.context, "logging.level.org.springframework.boot=GARBAGE"); addPropertiesToEnvironment(this.context, "logging.level.org.springframework.boot=GARBAGE");
assertThatExceptionOfType(BindException.class).isThrownBy( assertThatExceptionOfType(BindException.class).isThrownBy(
() -> this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader())); () -> this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader()));
} }
@Test @Test
void parseLevelsNone() { void parseLevelsNone() {
addPropertiesToEnvironment(this.context, "logging.level.org.springframework.boot=OFF"); addPropertiesToEnvironment(this.context, "logging.level.org.springframework.boot=OFF");
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
this.logger.debug("testatdebug"); this.logger.debug("testatdebug");
this.logger.error("testaterror"); this.logger.error("testaterror");
assertThat(this.output).doesNotContain("testatdebug").doesNotContain("testaterror"); assertThat(this.output).doesNotContain("testatdebug").doesNotContain("testaterror");
@ -355,7 +359,7 @@ class LoggingApplicationListenerTests {
@Test @Test
void parseLevelsMapsFalseToOff() { void parseLevelsMapsFalseToOff() {
addPropertiesToEnvironment(this.context, "logging.level.org.springframework.boot=false"); addPropertiesToEnvironment(this.context, "logging.level.org.springframework.boot=false");
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
this.logger.debug("testatdebug"); this.logger.debug("testatdebug");
this.logger.error("testaterror"); this.logger.error("testaterror");
assertThat(this.output).doesNotContain("testatdebug").doesNotContain("testaterror"); assertThat(this.output).doesNotContain("testatdebug").doesNotContain("testaterror");
@ -363,20 +367,20 @@ class LoggingApplicationListenerTests {
@Test @Test
void parseArgsDisabled() { void parseArgsDisabled() {
this.initializer.setParseArgs(false); this.listener.setParseArgs(false);
addPropertiesToEnvironment(this.context, "debug"); addPropertiesToEnvironment(this.context, "debug");
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
this.logger.debug("testatdebug"); this.logger.debug("testatdebug");
assertThat(this.output).doesNotContain("testatdebug"); assertThat(this.output).doesNotContain("testatdebug");
} }
@Test @Test
void parseArgsDoesntReplace() { void parseArgsDoesntReplace() {
this.initializer.setSpringBootLogging(LogLevel.ERROR); this.listener.setSpringBootLogging(LogLevel.ERROR);
this.initializer.setParseArgs(false); this.listener.setParseArgs(false);
multicastEvent(new ApplicationStartingEvent(this.bootstrapContext, this.springApplication, multicastEvent(new ApplicationStartingEvent(this.bootstrapContext, this.springApplication,
new String[] { "--debug" })); new String[] { "--debug" }));
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
this.logger.debug("testatdebug"); this.logger.debug("testatdebug");
assertThat(this.output).doesNotContain("testatdebug"); assertThat(this.output).doesNotContain("testatdebug");
} }
@ -390,7 +394,7 @@ class LoggingApplicationListenerTests {
@Test @Test
void defaultExceptionConversionWord() { void defaultExceptionConversionWord() {
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
this.logger.info("Hello world", new RuntimeException("Wrapper", new RuntimeException("Expected"))); this.logger.info("Hello world", new RuntimeException("Wrapper", new RuntimeException("Expected")));
assertThat(this.output).contains("Hello world"); assertThat(this.output).contains("Hello world");
assertThat(this.output).doesNotContain("Wrapped by: java.lang.RuntimeException: Wrapper"); assertThat(this.output).doesNotContain("Wrapped by: java.lang.RuntimeException: Wrapper");
@ -399,7 +403,7 @@ class LoggingApplicationListenerTests {
@Test @Test
void overrideExceptionConversionWord() { void overrideExceptionConversionWord() {
addPropertiesToEnvironment(this.context, "logging.exceptionConversionWord=%rEx"); addPropertiesToEnvironment(this.context, "logging.exceptionConversionWord=%rEx");
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
this.logger.info("Hello world", new RuntimeException("Wrapper", new RuntimeException("Expected"))); this.logger.info("Hello world", new RuntimeException("Wrapper", new RuntimeException("Expected")));
assertThat(this.output).contains("Hello world"); assertThat(this.output).contains("Hello world");
assertThat(this.output).contains("Wrapped by: java.lang.RuntimeException: Wrapper"); assertThat(this.output).contains("Wrapped by: java.lang.RuntimeException: Wrapper");
@ -436,8 +440,8 @@ class LoggingApplicationListenerTests {
void closingContextCleansUpLoggingSystem() { void closingContextCleansUpLoggingSystem() {
System.setProperty(LoggingSystem.SYSTEM_PROPERTY, TestCleanupLoggingSystem.class.getName()); System.setProperty(LoggingSystem.SYSTEM_PROPERTY, TestCleanupLoggingSystem.class.getName());
multicastEvent(new ApplicationStartingEvent(this.bootstrapContext, this.springApplication, new String[0])); multicastEvent(new ApplicationStartingEvent(this.bootstrapContext, this.springApplication, new String[0]));
TestCleanupLoggingSystem loggingSystem = (TestCleanupLoggingSystem) ReflectionTestUtils TestCleanupLoggingSystem loggingSystem = (TestCleanupLoggingSystem) ReflectionTestUtils.getField(this.listener,
.getField(this.initializer, "loggingSystem"); "loggingSystem");
assertThat(loggingSystem.cleanedUp).isFalse(); assertThat(loggingSystem.cleanedUp).isFalse();
multicastEvent(new ContextClosedEvent(this.context)); multicastEvent(new ContextClosedEvent(this.context));
assertThat(loggingSystem.cleanedUp).isTrue(); assertThat(loggingSystem.cleanedUp).isTrue();
@ -447,8 +451,8 @@ class LoggingApplicationListenerTests {
void closingChildContextDoesNotCleanUpLoggingSystem() { void closingChildContextDoesNotCleanUpLoggingSystem() {
System.setProperty(LoggingSystem.SYSTEM_PROPERTY, TestCleanupLoggingSystem.class.getName()); System.setProperty(LoggingSystem.SYSTEM_PROPERTY, TestCleanupLoggingSystem.class.getName());
multicastEvent(new ApplicationStartingEvent(this.bootstrapContext, this.springApplication, new String[0])); multicastEvent(new ApplicationStartingEvent(this.bootstrapContext, this.springApplication, new String[0]));
TestCleanupLoggingSystem loggingSystem = (TestCleanupLoggingSystem) ReflectionTestUtils TestCleanupLoggingSystem loggingSystem = (TestCleanupLoggingSystem) ReflectionTestUtils.getField(this.listener,
.getField(this.initializer, "loggingSystem"); "loggingSystem");
assertThat(loggingSystem.cleanedUp).isFalse(); assertThat(loggingSystem.cleanedUp).isFalse();
GenericApplicationContext childContext = new GenericApplicationContext(); GenericApplicationContext childContext = new GenericApplicationContext();
childContext.setParent(this.context); childContext.setParent(this.context);
@ -465,7 +469,7 @@ class LoggingApplicationListenerTests {
"logging.file.name=" + this.logFile, "logging.file.path=path", "logging.pattern.console=console", "logging.file.name=" + this.logFile, "logging.file.path=path", "logging.pattern.console=console",
"logging.pattern.file=file", "logging.pattern.level=level", "logging.pattern.file=file", "logging.pattern.level=level",
"logging.pattern.rolling-file-name=my.log.%d{yyyyMMdd}.%i.gz"); "logging.pattern.rolling-file-name=my.log.%d{yyyyMMdd}.%i.gz");
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
assertThat(System.getProperty(LoggingSystemProperties.CONSOLE_LOG_PATTERN)).isEqualTo("console"); assertThat(System.getProperty(LoggingSystemProperties.CONSOLE_LOG_PATTERN)).isEqualTo("console");
assertThat(System.getProperty(LoggingSystemProperties.FILE_LOG_PATTERN)).isEqualTo("file"); assertThat(System.getProperty(LoggingSystemProperties.FILE_LOG_PATTERN)).isEqualTo("file");
assertThat(System.getProperty(LoggingSystemProperties.EXCEPTION_CONVERSION_WORD)).isEqualTo("conversion"); assertThat(System.getProperty(LoggingSystemProperties.EXCEPTION_CONVERSION_WORD)).isEqualTo("conversion");
@ -479,7 +483,7 @@ class LoggingApplicationListenerTests {
void environmentPropertiesIgnoreUnresolvablePlaceholders() { void environmentPropertiesIgnoreUnresolvablePlaceholders() {
// gh-7719 // gh-7719
addPropertiesToEnvironment(this.context, "logging.pattern.console=console ${doesnotexist}"); addPropertiesToEnvironment(this.context, "logging.pattern.console=console ${doesnotexist}");
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
assertThat(System.getProperty(LoggingSystemProperties.CONSOLE_LOG_PATTERN)) assertThat(System.getProperty(LoggingSystemProperties.CONSOLE_LOG_PATTERN))
.isEqualTo("console ${doesnotexist}"); .isEqualTo("console ${doesnotexist}");
} }
@ -487,7 +491,7 @@ class LoggingApplicationListenerTests {
@Test @Test
void environmentPropertiesResolvePlaceholders() { void environmentPropertiesResolvePlaceholders() {
addPropertiesToEnvironment(this.context, "logging.pattern.console=console ${pid}"); addPropertiesToEnvironment(this.context, "logging.pattern.console=console ${pid}");
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
assertThat(System.getProperty(LoggingSystemProperties.CONSOLE_LOG_PATTERN)) assertThat(System.getProperty(LoggingSystemProperties.CONSOLE_LOG_PATTERN))
.isEqualTo(this.context.getEnvironment().getProperty("logging.pattern.console")); .isEqualTo(this.context.getEnvironment().getProperty("logging.pattern.console"));
} }
@ -495,7 +499,7 @@ class LoggingApplicationListenerTests {
@Test @Test
void logFilePropertiesCanReferenceSystemProperties() { void logFilePropertiesCanReferenceSystemProperties() {
addPropertiesToEnvironment(this.context, "logging.file.name=" + this.tempDir + "${PID}.log"); addPropertiesToEnvironment(this.context, "logging.file.name=" + this.tempDir + "${PID}.log");
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
assertThat(System.getProperty(LoggingSystemProperties.LOG_FILE)) assertThat(System.getProperty(LoggingSystemProperties.LOG_FILE))
.isEqualTo(this.tempDir + new ApplicationPid().toString() + ".log"); .isEqualTo(this.tempDir + new ApplicationPid().toString() + ".log");
} }
@ -504,21 +508,44 @@ class LoggingApplicationListenerTests {
void applicationFailedEventCleansUpLoggingSystem() { void applicationFailedEventCleansUpLoggingSystem() {
System.setProperty(LoggingSystem.SYSTEM_PROPERTY, TestCleanupLoggingSystem.class.getName()); System.setProperty(LoggingSystem.SYSTEM_PROPERTY, TestCleanupLoggingSystem.class.getName());
multicastEvent(new ApplicationStartingEvent(this.bootstrapContext, this.springApplication, new String[0])); multicastEvent(new ApplicationStartingEvent(this.bootstrapContext, this.springApplication, new String[0]));
TestCleanupLoggingSystem loggingSystem = (TestCleanupLoggingSystem) ReflectionTestUtils TestCleanupLoggingSystem loggingSystem = (TestCleanupLoggingSystem) ReflectionTestUtils.getField(this.listener,
.getField(this.initializer, "loggingSystem"); "loggingSystem");
assertThat(loggingSystem.cleanedUp).isFalse(); assertThat(loggingSystem.cleanedUp).isFalse();
multicastEvent(new ApplicationFailedEvent(this.springApplication, new String[0], multicastEvent(new ApplicationFailedEvent(this.springApplication, new String[0],
new GenericApplicationContext(), new Exception())); new GenericApplicationContext(), new Exception()));
assertThat(loggingSystem.cleanedUp).isTrue(); assertThat(loggingSystem.cleanedUp).isTrue();
} }
@Test
void cleanupOccursAfterWebServerShutdown() {
System.setProperty(LoggingSystem.SYSTEM_PROPERTY, TestCleanupLoggingSystem.class.getName());
this.springApplication.setWebApplicationType(WebApplicationType.NONE);
ConfigurableApplicationContext context = this.springApplication.run();
ApplicationListener<?> listener = this.springApplication.getListeners().stream()
.filter(LoggingApplicationListener.class::isInstance).findFirst().get();
TestCleanupLoggingSystem loggingSystem = (TestCleanupLoggingSystem) ReflectionTestUtils.getField(listener,
"loggingSystem");
assertThat(loggingSystem.cleanedUp).isFalse();
WebServerStyleLifecycle lifecycle = context.getBean(WebServerStyleLifecycle.class);
AtomicBoolean called = new AtomicBoolean();
AtomicBoolean cleanupOnStop = new AtomicBoolean();
lifecycle.onStop = () -> {
called.set(true);
cleanupOnStop.set(loggingSystem.cleanedUp);
};
context.close();
assertThat(called).isTrue();
assertThat(cleanupOnStop).isFalse();
assertThat(loggingSystem.cleanedUp).isTrue();
}
@Test @Test
void lowPriorityPropertySourceShouldNotOverrideRootLoggerConfig() { void lowPriorityPropertySourceShouldNotOverrideRootLoggerConfig() {
MutablePropertySources propertySources = this.context.getEnvironment().getPropertySources(); MutablePropertySources propertySources = this.context.getEnvironment().getPropertySources();
propertySources propertySources
.addFirst(new MapPropertySource("test1", Collections.singletonMap("logging.level.ROOT", "DEBUG"))); .addFirst(new MapPropertySource("test1", Collections.singletonMap("logging.level.ROOT", "DEBUG")));
propertySources.addLast(new MapPropertySource("test2", Collections.singletonMap("logging.level.root", "WARN"))); propertySources.addLast(new MapPropertySource("test2", Collections.singletonMap("logging.level.root", "WARN")));
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
this.logger.debug("testatdebug"); this.logger.debug("testatdebug");
assertThat(this.output).contains("testatdebug"); assertThat(this.output).contains("testatdebug");
} }
@ -526,7 +553,7 @@ class LoggingApplicationListenerTests {
@Test @Test
void loggingGroupsDefaultsAreApplied() { void loggingGroupsDefaultsAreApplied() {
addPropertiesToEnvironment(this.context, "logging.level.web=TRACE"); addPropertiesToEnvironment(this.context, "logging.level.web=TRACE");
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
assertTraceEnabled("org.springframework.core", false); assertTraceEnabled("org.springframework.core", false);
assertTraceEnabled("org.springframework.core.codec", true); assertTraceEnabled("org.springframework.core.codec", true);
assertTraceEnabled("org.springframework.http", true); assertTraceEnabled("org.springframework.http", true);
@ -539,7 +566,7 @@ class LoggingApplicationListenerTests {
void loggingGroupsCanBeDefined() { void loggingGroupsCanBeDefined() {
addPropertiesToEnvironment(this.context, "logging.group.foo=com.foo.bar,com.foo.baz", addPropertiesToEnvironment(this.context, "logging.group.foo=com.foo.bar,com.foo.baz",
"logging.level.foo=TRACE"); "logging.level.foo=TRACE");
this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader());
assertTraceEnabled("com.foo", false); assertTraceEnabled("com.foo", false);
assertTraceEnabled("com.foo.bar", true); assertTraceEnabled("com.foo.bar", true);
assertTraceEnabled("com.foo.baz", true); assertTraceEnabled("com.foo.baz", true);
@ -550,7 +577,7 @@ class LoggingApplicationListenerTests {
} }
private void multicastEvent(ApplicationEvent event) { private void multicastEvent(ApplicationEvent event) {
multicastEvent(this.initializer, event); multicastEvent(this.listener, event);
} }
private void multicastEvent(ApplicationListener<?> listener, ApplicationEvent event) { private void multicastEvent(ApplicationListener<?> listener, ApplicationEvent event) {
@ -668,4 +695,39 @@ class LoggingApplicationListenerTests {
} }
@Configuration
@Import(WebServerStyleLifecycle.class)
static class TestConfiguration {
}
static class WebServerStyleLifecycle implements SmartLifecycle {
private volatile boolean running;
Runnable onStop;
@Override
public void start() {
this.running = true;
}
@Override
public void stop() {
this.running = false;
this.onStop.run();
}
@Override
public boolean isRunning() {
return this.running;
}
@Override
public int getPhase() {
return Integer.MAX_VALUE - 1;
}
}
} }

Loading…
Cancel
Save