diff --git a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/SystemStatusListener.java b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/SystemStatusListener.java index 89a257e88e..386a367143 100644 --- a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/SystemStatusListener.java +++ b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/SystemStatusListener.java @@ -17,34 +17,73 @@ package org.springframework.boot.logging.logback; import java.io.PrintStream; +import java.util.List; import ch.qos.logback.classic.LoggerContext; -import ch.qos.logback.core.status.OnPrintStreamStatusListenerBase; +import ch.qos.logback.core.BasicStatusManager; +import ch.qos.logback.core.status.OnConsoleStatusListener; import ch.qos.logback.core.status.Status; import ch.qos.logback.core.status.StatusListener; +import ch.qos.logback.core.status.StatusManager; +import ch.qos.logback.core.util.StatusPrinter2; /** * {@link StatusListener} used to print appropriate status messages to {@link System#out} - * or {@link System#err}. + * or {@link System#err}. Note that this class extends {@link OnConsoleStatusListener} so + * that {@link BasicStatusManager#add(StatusListener)} does not add the same listener + * twice. It also implement a version of retrospectivePrint that can filter status + * messages by level. * * @author Dmytro Nosan * @author Phillip Webb */ -final class SystemStatusListener extends OnPrintStreamStatusListenerBase { +final class SystemStatusListener extends OnConsoleStatusListener { + + static final long RETROSPECTIVE_THRESHOLD = 300; + + private static final StatusPrinter2 PRINTER = new StatusPrinter2(); private final boolean debug; private SystemStatusListener(boolean debug) { this.debug = debug; + setResetResistant(false); + setRetrospective(0); + } + + @Override + public void start() { + super.start(); + retrospectivePrint(); + } + + private void retrospectivePrint() { + if (this.context == null) { + return; + } + long now = System.currentTimeMillis(); + List statusList = this.context.getStatusManager().getCopyOfStatusList(); + statusList.stream().filter((status) -> isPrintable(status, now)).forEach(this::print); + } + + private void print(Status status) { + StringBuilder sb = new StringBuilder(); + PRINTER.buildStr(sb, "", status); + getPrintStream().print(sb); } @Override public void addStatusEvent(Status status) { - if (this.debug || status.getLevel() >= Status.WARN) { + if (isPrintable(status, 0)) { super.addStatusEvent(status); } } + private boolean isPrintable(Status status, long now) { + boolean timstampInRange = (now == 0 || (now - status.getTimestamp()) < RETROSPECTIVE_THRESHOLD); + return timstampInRange && (this.debug || status.getLevel() >= Status.WARN); + } + @Override protected PrintStream getPrintStream() { return (!this.debug) ? System.err : System.out; @@ -57,9 +96,20 @@ final class SystemStatusListener extends OnPrintStreamStatusListenerBase { static void addTo(LoggerContext loggerContext, boolean debug) { SystemStatusListener listener = new SystemStatusListener(debug); listener.setContext(loggerContext); - if (loggerContext.getStatusManager().add(listener)) { + StatusManager statusManager = loggerContext.getStatusManager(); + if (statusManager.add(listener)) { listener.start(); } } + @Override + public boolean equals(Object obj) { + return (obj != null) && (obj.getClass() == getClass()); + } + + @Override + public int hashCode() { + return getClass().hashCode(); + } + } diff --git a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/logback/LogbackLoggingSystemTests.java b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/logback/LogbackLoggingSystemTests.java index db6f34ce9f..5bd3ff185b 100644 --- a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/logback/LogbackLoggingSystemTests.java +++ b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/logback/LogbackLoggingSystemTests.java @@ -40,6 +40,10 @@ import ch.qos.logback.core.encoder.LayoutWrappingEncoder; import ch.qos.logback.core.joran.spi.JoranException; import ch.qos.logback.core.rolling.RollingFileAppender; import ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy; +import ch.qos.logback.core.status.ErrorStatus; +import ch.qos.logback.core.status.InfoStatus; +import ch.qos.logback.core.status.StatusManager; +import ch.qos.logback.core.status.WarnStatus; import ch.qos.logback.core.util.DynamicClassLoadingException; import org.junit.jupiter.api.AfterEach; import org.junit.jupiter.api.BeforeEach; @@ -645,13 +649,20 @@ class LogbackLoggingSystemTests extends AbstractLoggingSystemTests { System.setProperty("logback.debug", "true"); try { this.loggingSystem.beforeInitialize(); + LoggerContext loggerContext = this.logger.getLoggerContext(); + StatusManager statusManager = loggerContext.getStatusManager(); + statusManager.add(new InfoStatus("INFO STATUS MESSAGE", getClass())); + statusManager.add(new WarnStatus("WARN STATUS MESSAGE", getClass())); + statusManager.add(new ErrorStatus("ERROR STATUS MESSAGE", getClass())); File file = new File(tmpDir(), "logback-test.log"); LogFile logFile = getLogFile(file.getPath(), null); initialize(this.initializationContext, null, logFile); assertThat(output).contains("LevelChangePropagator") .contains("SizeAndTimeBasedFileNamingAndTriggeringPolicy") - .contains("DebugLogbackConfigurator"); - LoggerContext loggerContext = this.logger.getLoggerContext(); + .contains("DebugLogbackConfigurator") + .contains("INFO STATUS MESSAGE") + .contains("WARN STATUS MESSAGE") + .contains("ERROR STATUS MESSAGE"); assertThat(loggerContext.getStatusManager().getCopyOfStatusListenerList()).allSatisfy((listener) -> { assertThat(listener).isInstanceOf(SystemStatusListener.class); assertThat(listener).hasFieldOrPropertyWithValue("debug", true); @@ -663,7 +674,7 @@ class LogbackLoggingSystemTests extends AbstractLoggingSystemTests { } @Test - void logbackErrorStatusListenerShouldBeRegistered(CapturedOutput output) { + void logbackSystemStatusListenerShouldBeRegistered(CapturedOutput output) { this.loggingSystem.beforeInitialize(); initialize(this.initializationContext, null, getLogFile(tmpDir() + "/tmp.log", null)); LoggerContext loggerContext = this.logger.getLoggerContext(); @@ -680,7 +691,40 @@ class LogbackLoggingSystemTests extends AbstractLoggingSystemTests { } @Test - void logbackErrorStatusListenerShouldBeRegisteredWhenUsingCustomLogbackXml(CapturedOutput output) { + void logbackSystemStatusListenerShouldBeRegisteredOnlyOnce() { + this.loggingSystem.beforeInitialize(); + initialize(this.initializationContext, null, getLogFile(tmpDir() + "/tmp.log", null)); + LoggerContext loggerContext = this.logger.getLoggerContext(); + SystemStatusListener.addTo(loggerContext); + SystemStatusListener.addTo(loggerContext, true); + assertThat(loggerContext.getStatusManager().getCopyOfStatusListenerList()).satisfiesOnlyOnce((listener) -> { + assertThat(listener).isInstanceOf(SystemStatusListener.class); + assertThat(listener).hasFieldOrPropertyWithValue("debug", false); + }); + } + + @Test + void logbackSystemStatusListenerShouldBeRegisteredAndFilterStatusByLevelIfDebugDisabled(CapturedOutput output) { + this.loggingSystem.beforeInitialize(); + LoggerContext loggerContext = this.logger.getLoggerContext(); + StatusManager statusManager = loggerContext.getStatusManager(); + statusManager.add(new InfoStatus("INFO STATUS MESSAGE", getClass())); + statusManager.add(new WarnStatus("WARN STATUS MESSAGE", getClass())); + statusManager.add(new ErrorStatus("ERROR STATUS MESSAGE", getClass())); + initialize(this.initializationContext, null, getLogFile(tmpDir() + "/tmp.log", null)); + assertThat(statusManager.getCopyOfStatusListenerList()).allSatisfy((listener) -> { + assertThat(listener).isInstanceOf(SystemStatusListener.class); + assertThat(listener).hasFieldOrPropertyWithValue("debug", false); + }); + this.logger.info("Hello world"); + assertThat(output).doesNotContain("INFO STATUS MESSAGE"); + assertThat(output).contains("WARN STATUS MESSAGE"); + assertThat(output).contains("ERROR STATUS MESSAGE"); + assertThat(output).contains("Hello world"); + } + + @Test + void logbackSystemStatusListenerShouldBeRegisteredWhenUsingCustomLogbackXml(CapturedOutput output) { this.loggingSystem.beforeInitialize(); initialize(this.initializationContext, "classpath:logback-include-defaults.xml", null); LoggerContext loggerContext = this.logger.getLoggerContext(); diff --git a/spring-boot-tests/spring-boot-smoke-tests/spring-boot-smoke-test-structured-logging/src/test/java/smoketest/structuredlogging/SampleStructuredLoggingApplicationTests.java b/spring-boot-tests/spring-boot-smoke-tests/spring-boot-smoke-test-structured-logging/src/test/java/smoketest/structuredlogging/SampleStructuredLoggingApplicationTests.java index a6f8b8fbd1..2e0159d2da 100644 --- a/spring-boot-tests/spring-boot-smoke-tests/spring-boot-smoke-test-structured-logging/src/test/java/smoketest/structuredlogging/SampleStructuredLoggingApplicationTests.java +++ b/spring-boot-tests/spring-boot-smoke-tests/spring-boot-smoke-test-structured-logging/src/test/java/smoketest/structuredlogging/SampleStructuredLoggingApplicationTests.java @@ -36,11 +36,12 @@ import static org.assertj.core.api.Assertions.assertThat; class SampleStructuredLoggingApplicationTests { @AfterEach - void reset() { + void reset(CapturedOutput output) { LoggingSystem.get(getClass().getClassLoader()).cleanUp(); for (LoggingSystemProperty property : LoggingSystemProperty.values()) { System.getProperties().remove(property.getEnvironmentVariableName()); } + assertThat(output).doesNotContain("-INFO in ch.qos.logback.classic.LoggerContext"); } @Test