Separate report logging from context initialization and events

See gh-32109
pull/32643/head
Andy Wilkinson 2 years ago
parent 73fd760137
commit 8e35f2ae92

@ -0,0 +1,86 @@
/*
* Copyright 2012-2022 the original author or authors.
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* https://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package org.springframework.boot.autoconfigure.logging;
import java.util.function.Supplier;
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.springframework.boot.autoconfigure.condition.ConditionEvaluationReport;
import org.springframework.boot.logging.LogLevel;
import org.springframework.util.Assert;
/**
* Logs the {@link ConditionEvaluationReport}.
*
* @author Greg Turnquist
* @author Dave Syer
* @author Phillip Webb
* @author Andy Wilkinson
* @author Madhura Bhave
*/
class ConditionEvaluationReportLogger {
private final Log logger = LogFactory.getLog(getClass());
private final Supplier<ConditionEvaluationReport> reportSupplier;
private final LogLevel logLevel;
ConditionEvaluationReportLogger(LogLevel logLevel, Supplier<ConditionEvaluationReport> reportSupplier) {
Assert.isTrue(isInfoOrDebug(logLevel), "LogLevel must be INFO or DEBUG");
this.logLevel = logLevel;
this.reportSupplier = reportSupplier;
}
private boolean isInfoOrDebug(LogLevel logLevelForReport) {
return LogLevel.INFO.equals(logLevelForReport) || LogLevel.DEBUG.equals(logLevelForReport);
}
void logReport(boolean isCrashReport) {
ConditionEvaluationReport report = this.reportSupplier.get();
if (report == null) {
this.logger.info("Unable to provide the condition evaluation report");
return;
}
if (!report.getConditionAndOutcomesBySource().isEmpty()) {
if (this.logLevel.equals(LogLevel.INFO)) {
if (this.logger.isInfoEnabled()) {
this.logger.info(new ConditionEvaluationReportMessage(report));
}
else if (isCrashReport) {
logMessage("info");
}
}
else {
if (this.logger.isDebugEnabled()) {
this.logger.debug(new ConditionEvaluationReportMessage(report));
}
else if (isCrashReport) {
logMessage("debug");
}
}
}
}
private void logMessage(String logLevel) {
this.logger.info(String.format("%n%nError starting ApplicationContext. To display the "
+ "condition evaluation report re-run your application with '" + logLevel + "' enabled."));
}
}

@ -16,8 +16,7 @@
package org.springframework.boot.autoconfigure.logging; package org.springframework.boot.autoconfigure.logging;
import org.apache.commons.logging.Log; import java.util.function.Supplier;
import org.apache.commons.logging.LogFactory;
import org.springframework.boot.autoconfigure.condition.ConditionEvaluationReport; import org.springframework.boot.autoconfigure.condition.ConditionEvaluationReport;
import org.springframework.boot.context.event.ApplicationFailedEvent; import org.springframework.boot.context.event.ApplicationFailedEvent;
@ -51,12 +50,6 @@ import org.springframework.util.Assert;
public class ConditionEvaluationReportLoggingListener public class ConditionEvaluationReportLoggingListener
implements ApplicationContextInitializer<ConfigurableApplicationContext> { implements ApplicationContextInitializer<ConfigurableApplicationContext> {
private final Log logger = LogFactory.getLog(getClass());
private ConfigurableApplicationContext applicationContext;
private ConditionEvaluationReport report;
private final LogLevel logLevelForReport; private final LogLevel logLevelForReport;
public ConditionEvaluationReportLoggingListener() { public ConditionEvaluationReportLoggingListener() {
@ -84,72 +77,37 @@ public class ConditionEvaluationReportLoggingListener
return new ConditionEvaluationReportLoggingListener(logLevelForReport); return new ConditionEvaluationReportLoggingListener(logLevelForReport);
} }
public LogLevel getLogLevelForReport() {
return this.logLevelForReport;
}
@Override @Override
public void initialize(ConfigurableApplicationContext applicationContext) { public void initialize(ConfigurableApplicationContext applicationContext) {
this.applicationContext = applicationContext; applicationContext.addApplicationListener(new ConditionEvaluationReportListener(applicationContext));
applicationContext.addApplicationListener(new ConditionEvaluationReportListener());
if (applicationContext instanceof GenericApplicationContext) {
// Get the report early in case the context fails to load
this.report = ConditionEvaluationReport.get(this.applicationContext.getBeanFactory());
}
} }
protected void onApplicationEvent(ApplicationEvent event) { private final class ConditionEvaluationReportListener implements GenericApplicationListener {
ConfigurableApplicationContext initializerApplicationContext = this.applicationContext;
if (event instanceof ContextRefreshedEvent contextRefreshedEvent) {
if (contextRefreshedEvent.getApplicationContext() == initializerApplicationContext) {
logAutoConfigurationReport();
}
}
else if (event instanceof ApplicationFailedEvent applicationFailedEvent
&& applicationFailedEvent.getApplicationContext() == initializerApplicationContext) {
logAutoConfigurationReport(true);
}
}
private void logAutoConfigurationReport() { private final ConfigurableApplicationContext context;
logAutoConfigurationReport(!this.applicationContext.isActive());
}
public void logAutoConfigurationReport(boolean isCrashReport) { private final ConditionEvaluationReportLogger logger;
if (this.report == null) {
if (this.applicationContext == null) { private ConditionEvaluationReportListener(ConfigurableApplicationContext context) {
this.logger.info("Unable to provide the conditions report due to missing ApplicationContext"); this.context = context;
return; Supplier<ConditionEvaluationReport> reportSupplier;
} if (context instanceof GenericApplicationContext) {
this.report = ConditionEvaluationReport.get(this.applicationContext.getBeanFactory()); // Get the report early when the context allows early access to the bean
} // factory in case the context subsequently fails to load
if (!this.report.getConditionAndOutcomesBySource().isEmpty()) { ConditionEvaluationReport report = getReport();
if (getLogLevelForReport().equals(LogLevel.INFO)) { reportSupplier = () -> report;
if (this.logger.isInfoEnabled()) {
this.logger.info(new ConditionEvaluationReportMessage(this.report));
}
else if (isCrashReport) {
logMessage("info");
}
} }
else { else {
if (this.logger.isDebugEnabled()) { reportSupplier = this::getReport;
this.logger.debug(new ConditionEvaluationReportMessage(this.report));
}
else if (isCrashReport) {
logMessage("debug");
}
}
} }
this.logger = new ConditionEvaluationReportLogger(
ConditionEvaluationReportLoggingListener.this.logLevelForReport, reportSupplier);
} }
private void logMessage(String logLevel) { private ConditionEvaluationReport getReport() {
this.logger.info(String.format("%n%nError starting ApplicationContext. To display the " return ConditionEvaluationReport.get(this.context.getBeanFactory());
+ "conditions report re-run your application with '" + logLevel + "' enabled."));
} }
private class ConditionEvaluationReportListener implements GenericApplicationListener {
@Override @Override
public int getOrder() { public int getOrder() {
return Ordered.LOWEST_PRECEDENCE; return Ordered.LOWEST_PRECEDENCE;
@ -172,7 +130,15 @@ public class ConditionEvaluationReportLoggingListener
@Override @Override
public void onApplicationEvent(ApplicationEvent event) { public void onApplicationEvent(ApplicationEvent event) {
ConditionEvaluationReportLoggingListener.this.onApplicationEvent(event); if (event instanceof ContextRefreshedEvent contextRefreshedEvent) {
if (contextRefreshedEvent.getApplicationContext() == this.context) {
this.logger.logReport(false);
}
}
else if (event instanceof ApplicationFailedEvent applicationFailedEvent
&& applicationFailedEvent.getApplicationContext() == this.context) {
this.logger.logReport(false);
}
} }
} }

@ -0,0 +1,124 @@
/*
* Copyright 2012-2022 the original author or authors.
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* https://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package org.springframework.boot.autoconfigure.logging;
import java.util.Arrays;
import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.LoggerContext;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.extension.ExtendWith;
import org.slf4j.LoggerFactory;
import org.springframework.boot.autoconfigure.condition.ConditionEvaluationReport;
import org.springframework.boot.autoconfigure.logging.ConditionEvaluationReportLoggingListenerTests.Config;
import org.springframework.boot.logging.LogLevel;
import org.springframework.boot.test.system.CapturedOutput;
import org.springframework.boot.test.system.OutputCaptureExtension;
import org.springframework.context.annotation.AnnotationConfigApplicationContext;
import static org.assertj.core.api.Assertions.assertThat;
import static org.assertj.core.api.Assertions.assertThatIllegalArgumentException;
/**
* Tests for {@link ConditionEvaluationReportLogger}.
*
* @author Andy Wilkinson
*/
@ExtendWith(OutputCaptureExtension.class)
class ConditionEvaluationReportLoggerTests {
@Test
void noErrorIfNotInitialized(CapturedOutput output) {
new ConditionEvaluationReportLogger(LogLevel.INFO, () -> null).logReport(true);
assertThat(output).contains("Unable to provide the condition evaluation report");
}
@Test
void supportsOnlyInfoAndDebugLogLevels() {
assertThatIllegalArgumentException()
.isThrownBy(() -> new ConditionEvaluationReportLogger(LogLevel.TRACE, () -> null))
.withMessageContaining("LogLevel must be INFO or DEBUG");
}
@Test
void loggerWithInfoLevelShouldLogAtInfo(CapturedOutput output) {
try (AnnotationConfigApplicationContext context = new AnnotationConfigApplicationContext()) {
ConditionEvaluationReportLogger logger = new ConditionEvaluationReportLogger(LogLevel.INFO,
() -> ConditionEvaluationReport.get(context.getBeanFactory()));
context.register(Config.class);
context.refresh();
logger.logReport(false);
assertThat(output).contains("CONDITIONS EVALUATION REPORT");
}
}
@Test
void loggerWithDebugLevelShouldLogAtDebug(CapturedOutput output) {
try (AnnotationConfigApplicationContext context = new AnnotationConfigApplicationContext()) {
ConditionEvaluationReportLogger logger = new ConditionEvaluationReportLogger(LogLevel.DEBUG,
() -> ConditionEvaluationReport.get(context.getBeanFactory()));
context.register(Config.class);
context.refresh();
logger.logReport(false);
assertThat(output).doesNotContain("CONDITIONS EVALUATION REPORT");
withDebugLogging(() -> logger.logReport(false));
assertThat(output).contains("CONDITIONS EVALUATION REPORT");
}
}
@Test
void logsInfoOnErrorIfDebugDisabled(CapturedOutput output) {
try (AnnotationConfigApplicationContext context = new AnnotationConfigApplicationContext()) {
ConditionEvaluationReportLogger logger = new ConditionEvaluationReportLogger(LogLevel.DEBUG,
() -> ConditionEvaluationReport.get(context.getBeanFactory()));
context.register(Config.class);
context.refresh();
logger.logReport(true);
assertThat(output).contains("Error starting ApplicationContext. To display the condition "
+ "evaluation report re-run your application with 'debug' enabled.");
}
}
@Test
void logsOutput(CapturedOutput output) {
try (AnnotationConfigApplicationContext context = new AnnotationConfigApplicationContext()) {
ConditionEvaluationReportLogger logger = new ConditionEvaluationReportLogger(LogLevel.DEBUG,
() -> ConditionEvaluationReport.get(context.getBeanFactory()));
context.register(Config.class);
ConditionEvaluationReport.get(context.getBeanFactory()).recordExclusions(Arrays.asList("com.foo.Bar"));
context.refresh();
withDebugLogging(() -> logger.logReport(false));
assertThat(output).contains("not a servlet web application (OnWebApplicationCondition)");
}
}
private void withDebugLogging(Runnable runnable) {
Logger logger = ((LoggerContext) LoggerFactory.getILoggerFactory())
.getLogger(ConditionEvaluationReportLogger.class);
Level currentLevel = logger.getLevel();
logger.setLevel(Level.DEBUG);
try {
runnable.run();
}
finally {
logger.setLevel(currentLevel);
}
}
}

@ -16,8 +16,6 @@
package org.springframework.boot.autoconfigure.logging; package org.springframework.boot.autoconfigure.logging;
import java.util.Arrays;
import ch.qos.logback.classic.Level; import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.LoggerContext; import ch.qos.logback.classic.LoggerContext;
@ -31,7 +29,6 @@ import org.springframework.boot.autoconfigure.context.PropertyPlaceholderAutoCon
import org.springframework.boot.autoconfigure.http.HttpMessageConvertersAutoConfiguration; import org.springframework.boot.autoconfigure.http.HttpMessageConvertersAutoConfiguration;
import org.springframework.boot.autoconfigure.web.servlet.WebMvcAutoConfiguration; import org.springframework.boot.autoconfigure.web.servlet.WebMvcAutoConfiguration;
import org.springframework.boot.context.event.ApplicationFailedEvent; import org.springframework.boot.context.event.ApplicationFailedEvent;
import org.springframework.boot.logging.LogLevel;
import org.springframework.boot.test.system.CapturedOutput; import org.springframework.boot.test.system.CapturedOutput;
import org.springframework.boot.test.system.OutputCaptureExtension; import org.springframework.boot.test.system.OutputCaptureExtension;
import org.springframework.boot.web.servlet.context.AnnotationConfigServletWebApplicationContext; import org.springframework.boot.web.servlet.context.AnnotationConfigServletWebApplicationContext;
@ -39,12 +36,10 @@ import org.springframework.context.annotation.AnnotationConfigApplicationContext
import org.springframework.context.annotation.Bean; import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration; import org.springframework.context.annotation.Configuration;
import org.springframework.context.annotation.Import; import org.springframework.context.annotation.Import;
import org.springframework.context.event.ContextRefreshedEvent;
import org.springframework.mock.web.MockServletContext; import org.springframework.mock.web.MockServletContext;
import static org.assertj.core.api.Assertions.assertThat; import static org.assertj.core.api.Assertions.assertThat;
import static org.assertj.core.api.Assertions.assertThatExceptionOfType; import static org.assertj.core.api.Assertions.assertThatExceptionOfType;
import static org.assertj.core.api.Assertions.assertThatIllegalArgumentException;
/** /**
* Tests for {@link ConditionEvaluationReportLoggingListener}. * Tests for {@link ConditionEvaluationReportLoggingListener}.
@ -63,44 +58,21 @@ class ConditionEvaluationReportLoggingListenerTests {
AnnotationConfigApplicationContext context = new AnnotationConfigApplicationContext(); AnnotationConfigApplicationContext context = new AnnotationConfigApplicationContext();
this.initializer.initialize(context); this.initializer.initialize(context);
context.register(Config.class); context.register(Config.class);
context.refresh(); withDebugLogging(() -> context.refresh());
withDebugLogging(() -> this.initializer.onApplicationEvent(new ContextRefreshedEvent(context)));
assertThat(output).contains("CONDITIONS EVALUATION REPORT"); assertThat(output).contains("CONDITIONS EVALUATION REPORT");
} }
@Test @Test
void logsDebugOnError(CapturedOutput output) { void logsDebugOnApplicationFailedEvent(CapturedOutput output) {
AnnotationConfigApplicationContext context = new AnnotationConfigApplicationContext(); AnnotationConfigApplicationContext context = new AnnotationConfigApplicationContext();
this.initializer.initialize(context); this.initializer.initialize(context);
context.register(ErrorConfig.class); context.register(ErrorConfig.class);
assertThatExceptionOfType(Exception.class).isThrownBy(context::refresh) assertThatExceptionOfType(Exception.class).isThrownBy(context::refresh)
.satisfies((ex) -> withDebugLogging(() -> this.initializer.onApplicationEvent( .satisfies((ex) -> withDebugLogging(() -> context.publishEvent(
new ApplicationFailedEvent(new SpringApplication(), new String[0], context, ex)))); new ApplicationFailedEvent(new SpringApplication(), new String[0], context, ex))));
assertThat(output).contains("CONDITIONS EVALUATION REPORT"); assertThat(output).contains("CONDITIONS EVALUATION REPORT");
} }
@Test
void logsInfoOnErrorIfDebugDisabled(CapturedOutput output) {
AnnotationConfigApplicationContext context = new AnnotationConfigApplicationContext();
this.initializer.initialize(context);
context.register(ErrorConfig.class);
assertThatExceptionOfType(Exception.class).isThrownBy(context::refresh).satisfies((ex) -> this.initializer
.onApplicationEvent(new ApplicationFailedEvent(new SpringApplication(), new String[0], context, ex)));
assertThat(output).contains("Error starting ApplicationContext. To display the conditions report re-run"
+ " your application with 'debug' enabled.");
}
@Test
void logsOutput(CapturedOutput output) {
AnnotationConfigApplicationContext context = new AnnotationConfigApplicationContext();
this.initializer.initialize(context);
context.register(Config.class);
ConditionEvaluationReport.get(context.getBeanFactory()).recordExclusions(Arrays.asList("com.foo.Bar"));
context.refresh();
withDebugLogging(() -> this.initializer.onApplicationEvent(new ContextRefreshedEvent(context)));
assertThat(output).contains("not a servlet web application (OnWebApplicationCondition)");
}
@Test @Test
void canBeUsedInApplicationContext() { void canBeUsedInApplicationContext() {
AnnotationConfigApplicationContext context = new AnnotationConfigApplicationContext(); AnnotationConfigApplicationContext context = new AnnotationConfigApplicationContext();
@ -120,35 +92,9 @@ class ConditionEvaluationReportLoggingListenerTests {
assertThat(context.getBean(ConditionEvaluationReport.class)).isNotNull(); assertThat(context.getBean(ConditionEvaluationReport.class)).isNotNull();
} }
@Test
void listenerWithInfoLevelShouldLogAtInfo(CapturedOutput output) {
AnnotationConfigApplicationContext context = new AnnotationConfigApplicationContext();
ConditionEvaluationReportLoggingListener initializer = ConditionEvaluationReportLoggingListener
.forLogLevel(LogLevel.INFO);
initializer.initialize(context);
context.register(Config.class);
context.refresh();
initializer.onApplicationEvent(new ContextRefreshedEvent(context));
assertThat(output).contains("CONDITIONS EVALUATION REPORT");
}
@Test
void listenerSupportsOnlyInfoAndDebug() {
assertThatIllegalArgumentException()
.isThrownBy(() -> ConditionEvaluationReportLoggingListener.forLogLevel(LogLevel.TRACE))
.withMessageContaining("LogLevel must be INFO or DEBUG");
}
@Test
void noErrorIfNotInitialized(CapturedOutput output) {
this.initializer.onApplicationEvent(new ApplicationFailedEvent(new SpringApplication(), new String[0], null,
new RuntimeException("Planned")));
assertThat(output).contains("Unable to provide the conditions report");
}
private void withDebugLogging(Runnable runnable) { private void withDebugLogging(Runnable runnable) {
Logger logger = ((LoggerContext) LoggerFactory.getILoggerFactory()) Logger logger = ((LoggerContext) LoggerFactory.getILoggerFactory())
.getLogger(ConditionEvaluationReportLoggingListener.class); .getLogger(ConditionEvaluationReportLogger.class);
Level currentLevel = logger.getLevel(); Level currentLevel = logger.getLevel();
logger.setLevel(Level.DEBUG); logger.setLevel(Level.DEBUG);
try { try {

@ -3,6 +3,7 @@
"-//Checkstyle//DTD SuppressionFilter Configuration 1.2//EN" "-//Checkstyle//DTD SuppressionFilter Configuration 1.2//EN"
"https://checkstyle.org/dtds/suppressions_1_2.dtd"> "https://checkstyle.org/dtds/suppressions_1_2.dtd">
<suppressions> <suppressions>
<suppress files="ConditionEvaluationReportLoggerTests\.java" checks="IllegalImport" />
<suppress files="ConditionEvaluationReportLoggingListenerTests\.java" checks="IllegalImport" /> <suppress files="ConditionEvaluationReportLoggingListenerTests\.java" checks="IllegalImport" />
<suppress files="LoggingApplicationListenerTests\.java" checks="IllegalImport" /> <suppress files="LoggingApplicationListenerTests\.java" checks="IllegalImport" />
<suppress files="LogbackInitializer\.java" checks="IllegalImport" /> <suppress files="LogbackInitializer\.java" checks="IllegalImport" />

Loading…
Cancel
Save