Skip to content

Commit 8e15317

Browse files
philwebbphilwebb
committed
Merge pull request #43931 from nosan
* pr/43931: Refine `SystemStatusListener` superfluous output fix Fix SystemStatusListener to prevent superfluous output Closes gh-43931
2 parents fc01b01 + c884529 commit 8e15317

File tree

3 files changed

+105
-10
lines changed

3 files changed

+105
-10
lines changed

‎spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/SystemStatusListener.java‎

Lines changed: 55 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -17,34 +17,73 @@
1717
package org.springframework.boot.logging.logback;
1818

1919
import java.io.PrintStream;
20+
import java.util.List;
2021

2122
import ch.qos.logback.classic.LoggerContext;
22-
import ch.qos.logback.core.status.OnPrintStreamStatusListenerBase;
23+
import ch.qos.logback.core.BasicStatusManager;
24+
import ch.qos.logback.core.status.OnConsoleStatusListener;
2325
import ch.qos.logback.core.status.Status;
2426
import ch.qos.logback.core.status.StatusListener;
27+
import ch.qos.logback.core.status.StatusManager;
28+
import ch.qos.logback.core.util.StatusPrinter2;
2529

2630
/**
2731
* {@link StatusListener} used to print appropriate status messages to {@link System#out}
28-
* or {@link System#err}.
32+
* or {@link System#err}. Note that this class extends {@link OnConsoleStatusListener} so
33+
* that {@link BasicStatusManager#add(StatusListener)} does not add the same listener
34+
* twice. It also implement a version of retrospectivePrint that can filter status
35+
* messages by level.
2936
*
3037
* @author Dmytro Nosan
3138
* @author Phillip Webb
3239
*/
33-
final class SystemStatusListener extends OnPrintStreamStatusListenerBase {
40+
final class SystemStatusListener extends OnConsoleStatusListener {
41+
42+
static final long RETROSPECTIVE_THRESHOLD = 300;
43+
44+
private static final StatusPrinter2 PRINTER = new StatusPrinter2();
3445

3546
private final boolean debug;
3647

3748
private SystemStatusListener(boolean debug) {
3849
this.debug = debug;
50+
setResetResistant(false);
51+
setRetrospective(0);
52+
}
53+
54+
@Override
55+
public void start() {
56+
super.start();
57+
retrospectivePrint();
58+
}
59+
60+
private void retrospectivePrint() {
61+
if (this.context == null) {
62+
return;
63+
}
64+
long now = System.currentTimeMillis();
65+
List<Status> statusList = this.context.getStatusManager().getCopyOfStatusList();
66+
statusList.stream().filter((status) -> isPrintable(status, now)).forEach(this::print);
67+
}
68+
69+
private void print(Status status) {
70+
StringBuilder sb = new StringBuilder();
71+
PRINTER.buildStr(sb, "", status);
72+
getPrintStream().print(sb);
3973
}
4074

4175
@Override
4276
public void addStatusEvent(Status status) {
43-
if (this.debug || status.getLevel() >= Status.WARN) {
77+
if (isPrintable(status, 0)) {
4478
super.addStatusEvent(status);
4579
}
4680
}
4781

82+
private boolean isPrintable(Status status, long now) {
83+
boolean timstampInRange = (now == 0 || (now - status.getTimestamp()) < RETROSPECTIVE_THRESHOLD);
84+
return timstampInRange && (this.debug || status.getLevel() >= Status.WARN);
85+
}
86+
4887
@Override
4988
protected PrintStream getPrintStream() {
5089
return (!this.debug) ? System.err : System.out;
@@ -57,9 +96,20 @@ static void addTo(LoggerContext loggerContext) {
5796
static void addTo(LoggerContext loggerContext, boolean debug) {
5897
SystemStatusListener listener = new SystemStatusListener(debug);
5998
listener.setContext(loggerContext);
60-
if (loggerContext.getStatusManager().add(listener)) {
99+
StatusManager statusManager = loggerContext.getStatusManager();
100+
if (statusManager.add(listener)) {
61101
listener.start();
62102
}
63103
}
64104

105+
@Override
106+
public boolean equals(Object obj) {
107+
return (obj != null) && (obj.getClass() == getClass());
108+
}
109+
110+
@Override
111+
public int hashCode() {
112+
return getClass().hashCode();
113+
}
114+
65115
}

‎spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/logback/LogbackLoggingSystemTests.java‎

Lines changed: 48 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -40,6 +40,10 @@
4040
import ch.qos.logback.core.joran.spi.JoranException;
4141
import ch.qos.logback.core.rolling.RollingFileAppender;
4242
import ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy;
43+
import ch.qos.logback.core.status.ErrorStatus;
44+
import ch.qos.logback.core.status.InfoStatus;
45+
import ch.qos.logback.core.status.StatusManager;
46+
import ch.qos.logback.core.status.WarnStatus;
4347
import ch.qos.logback.core.util.DynamicClassLoadingException;
4448
import org.junit.jupiter.api.AfterEach;
4549
import org.junit.jupiter.api.BeforeEach;
@@ -645,13 +649,20 @@ void logbackDebugPropertyIsHonored(CapturedOutput output) {
645649
System.setProperty("logback.debug", "true");
646650
try {
647651
this.loggingSystem.beforeInitialize();
652+
LoggerContext loggerContext = this.logger.getLoggerContext();
653+
StatusManager statusManager = loggerContext.getStatusManager();
654+
statusManager.add(new InfoStatus("INFO STATUS MESSAGE", getClass()));
655+
statusManager.add(new WarnStatus("WARN STATUS MESSAGE", getClass()));
656+
statusManager.add(new ErrorStatus("ERROR STATUS MESSAGE", getClass()));
648657
File file = new File(tmpDir(), "logback-test.log");
649658
LogFile logFile = getLogFile(file.getPath(), null);
650659
initialize(this.initializationContext, null, logFile);
651660
assertThat(output).contains("LevelChangePropagator")
652661
.contains("SizeAndTimeBasedFileNamingAndTriggeringPolicy")
653-
.contains("DebugLogbackConfigurator");
654-
LoggerContext loggerContext = this.logger.getLoggerContext();
662+
.contains("DebugLogbackConfigurator")
663+
.contains("INFO STATUS MESSAGE")
664+
.contains("WARN STATUS MESSAGE")
665+
.contains("ERROR STATUS MESSAGE");
655666
assertThat(loggerContext.getStatusManager().getCopyOfStatusListenerList()).allSatisfy((listener) -> {
656667
assertThat(listener).isInstanceOf(SystemStatusListener.class);
657668
assertThat(listener).hasFieldOrPropertyWithValue("debug", true);
@@ -663,7 +674,7 @@ void logbackDebugPropertyIsHonored(CapturedOutput output) {
663674
}
664675

665676
@Test
666-
void logbackErrorStatusListenerShouldBeRegistered(CapturedOutput output) {
677+
void logbackSystemStatusListenerShouldBeRegistered(CapturedOutput output) {
667678
this.loggingSystem.beforeInitialize();
668679
initialize(this.initializationContext, null, getLogFile(tmpDir() + "/tmp.log", null));
669680
LoggerContext loggerContext = this.logger.getLoggerContext();
@@ -680,7 +691,40 @@ void logbackErrorStatusListenerShouldBeRegistered(CapturedOutput output) {
680691
}
681692

682693
@Test
683-
void logbackErrorStatusListenerShouldBeRegisteredWhenUsingCustomLogbackXml(CapturedOutput output) {
694+
void logbackSystemStatusListenerShouldBeRegisteredOnlyOnce() {
695+
this.loggingSystem.beforeInitialize();
696+
initialize(this.initializationContext, null, getLogFile(tmpDir() + "/tmp.log", null));
697+
LoggerContext loggerContext = this.logger.getLoggerContext();
698+
SystemStatusListener.addTo(loggerContext);
699+
SystemStatusListener.addTo(loggerContext, true);
700+
assertThat(loggerContext.getStatusManager().getCopyOfStatusListenerList()).satisfiesOnlyOnce((listener) -> {
701+
assertThat(listener).isInstanceOf(SystemStatusListener.class);
702+
assertThat(listener).hasFieldOrPropertyWithValue("debug", false);
703+
});
704+
}
705+
706+
@Test
707+
void logbackSystemStatusListenerShouldBeRegisteredAndFilterStatusByLevelIfDebugDisabled(CapturedOutput output) {
708+
this.loggingSystem.beforeInitialize();
709+
LoggerContext loggerContext = this.logger.getLoggerContext();
710+
StatusManager statusManager = loggerContext.getStatusManager();
711+
statusManager.add(new InfoStatus("INFO STATUS MESSAGE", getClass()));
712+
statusManager.add(new WarnStatus("WARN STATUS MESSAGE", getClass()));
713+
statusManager.add(new ErrorStatus("ERROR STATUS MESSAGE", getClass()));
714+
initialize(this.initializationContext, null, getLogFile(tmpDir() + "/tmp.log", null));
715+
assertThat(statusManager.getCopyOfStatusListenerList()).allSatisfy((listener) -> {
716+
assertThat(listener).isInstanceOf(SystemStatusListener.class);
717+
assertThat(listener).hasFieldOrPropertyWithValue("debug", false);
718+
});
719+
this.logger.info("Hello world");
720+
assertThat(output).doesNotContain("INFO STATUS MESSAGE");
721+
assertThat(output).contains("WARN STATUS MESSAGE");
722+
assertThat(output).contains("ERROR STATUS MESSAGE");
723+
assertThat(output).contains("Hello world");
724+
}
725+
726+
@Test
727+
void logbackSystemStatusListenerShouldBeRegisteredWhenUsingCustomLogbackXml(CapturedOutput output) {
684728
this.loggingSystem.beforeInitialize();
685729
initialize(this.initializationContext, "classpath:logback-include-defaults.xml", null);
686730
LoggerContext loggerContext = this.logger.getLoggerContext();

‎spring-boot-tests/spring-boot-smoke-tests/spring-boot-smoke-test-structured-logging/src/test/java/smoketest/structuredlogging/SampleStructuredLoggingApplicationTests.java‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -36,11 +36,12 @@
3636
class SampleStructuredLoggingApplicationTests {
3737

3838
@AfterEach
39-
void reset() {
39+
void reset(CapturedOutput output) {
4040
LoggingSystem.get(getClass().getClassLoader()).cleanUp();
4141
for (LoggingSystemProperty property : LoggingSystemProperty.values()) {
4242
System.getProperties().remove(property.getEnvironmentVariableName());
4343
}
44+
assertThat(output).doesNotContain("-INFO in ch.qos.logback.classic.LoggerContext");
4445
}
4546

4647
@Test

0 commit comments

Comments
 (0)