Skip to content

Commit 11461d0

Browse files
nosannosan
committed
Logback StructuredLogFormatter exceptions are not visible to the user
Before this commit, any exceptions thrown in Logback encoders were just swallowed. This commit adds the FilteringStatusListener that delegates to OnErrorConsoleStatusListener to print any errors that happened in logback encoders. See gh-43384
1 parent 60e0de7 commit 11461d0

File tree

7 files changed

+289
-0
lines changed

7 files changed

+289
-0
lines changed

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

Lines changed: 80 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,80 @@
1+
/*
2+
* Copyright 2012-2024 the original author or authors.
3+
*
4+
* Licensed under the Apache License, Version 2.0 (the "License");
5+
* you may not use this file except in compliance with the License.
6+
* You may obtain a copy of the License at
7+
*
8+
* https://www.apache.org/licenses/LICENSE-2.0
9+
*
10+
* Unless required by applicable law or agreed to in writing, software
11+
* distributed under the License is distributed on an "AS IS" BASIS,
12+
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13+
* See the License for the specific language governing permissions and
14+
* limitations under the License.
15+
*/
16+
17+
package org.springframework.boot.logging.logback;
18+
19+
import ch.qos.logback.core.spi.ContextAwareBase;
20+
import ch.qos.logback.core.spi.LifeCycle;
21+
import ch.qos.logback.core.status.Status;
22+
import ch.qos.logback.core.status.StatusListener;
23+
24+
/**
25+
* Logback {@link StatusListener} that filters {@link Status} by its logging level and
26+
* delegates to the underlying {@code StatusListener}.
27+
*
28+
* @author Dmytro Nosan
29+
*/
30+
final class FilteringStatusListener extends ContextAwareBase implements StatusListener, LifeCycle {
31+
32+
private final StatusListener delegate;
33+
34+
private final int levelThreshold;
35+
36+
/**
37+
* Creates a new {@link FilteringStatusListener}.
38+
* @param delegate the {@link StatusListener} delegate to
39+
* @param levelThreshold the minimum log level accepted for delegation
40+
*/
41+
FilteringStatusListener(StatusListener delegate, int levelThreshold) {
42+
this.delegate = delegate;
43+
this.levelThreshold = levelThreshold;
44+
}
45+
46+
@Override
47+
public void addStatusEvent(Status status) {
48+
if (status.getLevel() >= this.levelThreshold) {
49+
this.delegate.addStatusEvent(status);
50+
}
51+
}
52+
53+
@Override
54+
public boolean isResetResistant() {
55+
return this.delegate.isResetResistant();
56+
}
57+
58+
@Override
59+
public void start() {
60+
if (this.delegate instanceof LifeCycle lifeCycle) {
61+
lifeCycle.start();
62+
}
63+
}
64+
65+
@Override
66+
public void stop() {
67+
if (this.delegate instanceof LifeCycle lifeCycle) {
68+
lifeCycle.stop();
69+
}
70+
}
71+
72+
@Override
73+
public boolean isStarted() {
74+
if (this.delegate instanceof LifeCycle lifeCycle) {
75+
return lifeCycle.isStarted();
76+
}
77+
return true;
78+
}
79+
80+
}

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

Lines changed: 12 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -36,6 +36,7 @@
3636
import ch.qos.logback.core.joran.spi.JoranException;
3737
import ch.qos.logback.core.spi.FilterReply;
3838
import ch.qos.logback.core.status.OnConsoleStatusListener;
39+
import ch.qos.logback.core.status.OnErrorConsoleStatusListener;
3940
import ch.qos.logback.core.status.Status;
4041
import ch.qos.logback.core.status.StatusUtil;
4142
import ch.qos.logback.core.util.StatusListenerConfigHelper;
@@ -234,6 +235,9 @@ protected void loadDefaults(LoggingInitializationContext initializationContext,
234235
if (debug) {
235236
StatusListenerConfigHelper.addOnConsoleListenerInstance(loggerContext, new OnConsoleStatusListener());
236237
}
238+
else {
239+
addOnErrorConsoleStatusListener(loggerContext);
240+
}
237241
Environment environment = initializationContext.getEnvironment();
238242
// Apply system properties directly in case the same JVM runs multiple apps
239243
new LogbackLoggingSystemProperties(environment, getDefaultValueResolver(environment),
@@ -487,6 +491,14 @@ private void withLoggingSuppressed(Runnable action) {
487491
}
488492
}
489493

494+
private void addOnErrorConsoleStatusListener(LoggerContext context) {
495+
FilteringStatusListener listener = new FilteringStatusListener(new OnErrorConsoleStatusListener(),
496+
Status.ERROR);
497+
listener.setContext(context);
498+
context.getStatusManager().add(listener);
499+
listener.start();
500+
}
501+
490502
void setStatusPrinterStream(PrintStream stream) {
491503
this.statusPrinter.setPrintStream(stream);
492504
}

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

Lines changed: 121 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,121 @@
1+
/*
2+
* Copyright 2012-2024 the original author or authors.
3+
*
4+
* Licensed under the Apache License, Version 2.0 (the "License");
5+
* you may not use this file except in compliance with the License.
6+
* You may obtain a copy of the License at
7+
*
8+
* https://www.apache.org/licenses/LICENSE-2.0
9+
*
10+
* Unless required by applicable law or agreed to in writing, software
11+
* distributed under the License is distributed on an "AS IS" BASIS,
12+
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13+
* See the License for the specific language governing permissions and
14+
* limitations under the License.
15+
*/
16+
17+
package org.springframework.boot.logging.logback;
18+
19+
import java.util.ArrayList;
20+
import java.util.List;
21+
22+
import ch.qos.logback.core.spi.LifeCycle;
23+
import ch.qos.logback.core.status.ErrorStatus;
24+
import ch.qos.logback.core.status.InfoStatus;
25+
import ch.qos.logback.core.status.Status;
26+
import ch.qos.logback.core.status.StatusListener;
27+
import ch.qos.logback.core.status.WarnStatus;
28+
import org.junit.jupiter.api.Test;
29+
30+
import static org.assertj.core.api.Assertions.assertThat;
31+
32+
/**
33+
* Tests for {@link FilteringStatusListener}.
34+
*
35+
* @author Dmytro Nosan
36+
*/
37+
class FilteringStatusListenerTests {
38+
39+
private final DelegateStatusListener delegate = new DelegateStatusListener();
40+
41+
@Test
42+
void shouldFilterOutInfoStatus() {
43+
FilteringStatusListener listener = createListener(Status.WARN);
44+
InfoStatus info = new InfoStatus("info", getClass());
45+
WarnStatus warn = new WarnStatus("warn", getClass());
46+
ErrorStatus error = new ErrorStatus("error", getClass());
47+
listener.addStatusEvent(info);
48+
listener.addStatusEvent(warn);
49+
listener.addStatusEvent(error);
50+
assertThat(this.delegate.getStatuses()).containsExactly(warn, error);
51+
}
52+
53+
@Test
54+
void shouldStartUnderlyingStatusListener() {
55+
FilteringStatusListener listener = createListener(Status.INFO);
56+
assertThat(this.delegate.isStarted()).isFalse();
57+
listener.start();
58+
assertThat(this.delegate.isStarted()).isTrue();
59+
}
60+
61+
@Test
62+
void shouldStopUnderlyingStatusListener() {
63+
FilteringStatusListener listener = createListener();
64+
this.delegate.start();
65+
assertThat(this.delegate.isStarted()).isTrue();
66+
listener.stop();
67+
assertThat(this.delegate.isStarted()).isFalse();
68+
}
69+
70+
@Test
71+
void shouldUseResetResistantValueFromUnderlyingStatusListener() {
72+
FilteringStatusListener listener = createListener();
73+
assertThat(listener.isResetResistant()).isEqualTo(this.delegate.isResetResistant());
74+
}
75+
76+
private FilteringStatusListener createListener() {
77+
return new FilteringStatusListener(this.delegate, Status.INFO);
78+
}
79+
80+
private FilteringStatusListener createListener(int levelThreshold) {
81+
return new FilteringStatusListener(this.delegate, levelThreshold);
82+
}
83+
84+
private static final class DelegateStatusListener implements StatusListener, LifeCycle {
85+
86+
private final List<Status> statuses = new ArrayList<>();
87+
88+
private boolean started = false;
89+
90+
@Override
91+
public void addStatusEvent(Status status) {
92+
this.statuses.add(status);
93+
}
94+
95+
List<Status> getStatuses() {
96+
return this.statuses;
97+
}
98+
99+
@Override
100+
public boolean isResetResistant() {
101+
return true;
102+
}
103+
104+
@Override
105+
public void start() {
106+
this.started = true;
107+
}
108+
109+
@Override
110+
public void stop() {
111+
this.started = false;
112+
}
113+
114+
@Override
115+
public boolean isStarted() {
116+
return this.started;
117+
}
118+
119+
}
120+
121+
}

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

Lines changed: 35 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -32,12 +32,18 @@
3232
import ch.qos.logback.classic.Level;
3333
import ch.qos.logback.classic.Logger;
3434
import ch.qos.logback.classic.LoggerContext;
35+
import ch.qos.logback.classic.spi.ILoggingEvent;
3536
import ch.qos.logback.classic.spi.LoggerContextListener;
37+
import ch.qos.logback.core.AppenderBase;
3638
import ch.qos.logback.core.ConsoleAppender;
3739
import ch.qos.logback.core.encoder.LayoutWrappingEncoder;
3840
import ch.qos.logback.core.joran.spi.JoranException;
3941
import ch.qos.logback.core.rolling.RollingFileAppender;
4042
import ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy;
43+
import ch.qos.logback.core.status.OnConsoleStatusListener;
44+
import ch.qos.logback.core.status.OnErrorConsoleStatusListener;
45+
import ch.qos.logback.core.status.Status;
46+
import ch.qos.logback.core.status.StatusListener;
4147
import ch.qos.logback.core.util.DynamicClassLoadingException;
4248
import org.junit.jupiter.api.AfterEach;
4349
import org.junit.jupiter.api.BeforeEach;
@@ -649,12 +655,41 @@ void logbackDebugPropertyIsHonored(CapturedOutput output) {
649655
assertThat(output).contains("LevelChangePropagator")
650656
.contains("SizeAndTimeBasedFileNamingAndTriggeringPolicy")
651657
.contains("DebugLogbackConfigurator");
658+
LoggerContext loggerContext = this.logger.getLoggerContext();
659+
List<StatusListener> statusListeners = loggerContext.getStatusManager().getCopyOfStatusListenerList();
660+
assertThat(statusListeners).hasSize(1);
661+
StatusListener statusListener = statusListeners.get(0);
662+
assertThat(statusListener).isInstanceOf(OnConsoleStatusListener.class);
652663
}
653664
finally {
654665
System.clearProperty("logback.debug");
655666
}
656667
}
657668

669+
@Test
670+
void logbackErrorStatusListenerShouldBeRegistered(CapturedOutput output) {
671+
this.loggingSystem.beforeInitialize();
672+
initialize(this.initializationContext, null, getLogFile(tmpDir() + "/tmp.log", null));
673+
LoggerContext loggerContext = this.logger.getLoggerContext();
674+
List<StatusListener> statusListeners = loggerContext.getStatusManager().getCopyOfStatusListenerList();
675+
assertThat(statusListeners).hasSize(1);
676+
StatusListener statusListener = statusListeners.get(0);
677+
assertThat(statusListener).isInstanceOf(FilteringStatusListener.class);
678+
assertThat(statusListener).hasFieldOrPropertyWithValue("levelThreshold", Status.ERROR);
679+
assertThat(statusListener).extracting("delegate").isInstanceOf(OnErrorConsoleStatusListener.class);
680+
AppenderBase<ILoggingEvent> appender = new AppenderBase<>() {
681+
@Override
682+
protected void append(ILoggingEvent eventObject) {
683+
throw new IllegalStateException("Fail to append");
684+
}
685+
};
686+
this.logger.addAppender(appender);
687+
appender.setContext(loggerContext);
688+
appender.start();
689+
this.logger.info("Hello world");
690+
assertThat(output).contains("Fail to append").contains("Hello world");
691+
}
692+
658693
@Test
659694
void testRollingFileNameProperty() {
660695
String rollingFile = "my.log.%d{yyyyMMdd}.%i.gz";

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

Lines changed: 32 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,32 @@
1+
/*
2+
* Copyright 2012-2024 the original author or authors.
3+
*
4+
* Licensed under the Apache License, Version 2.0 (the "License");
5+
* you may not use this file except in compliance with the License.
6+
* You may obtain a copy of the License at
7+
*
8+
* https://www.apache.org/licenses/LICENSE-2.0
9+
*
10+
* Unless required by applicable law or agreed to in writing, software
11+
* distributed under the License is distributed on an "AS IS" BASIS,
12+
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13+
* See the License for the specific language governing permissions and
14+
* limitations under the License.
15+
*/
16+
17+
package smoketest.structuredlogging;
18+
19+
import java.util.Objects;
20+
21+
import org.springframework.boot.json.JsonWriter.Members;
22+
import org.springframework.boot.logging.structured.StructuredLoggingJsonMembersCustomizer;
23+
24+
public class DuplicateJsonMembersCustomizer implements StructuredLoggingJsonMembersCustomizer<Object> {
25+
26+
@Override
27+
public void customize(Members<Object> members) {
28+
members.add("test").as(Objects::toString);
29+
members.add("test").as(Objects::toString);
30+
}
31+
32+
}

‎spring-boot-tests/spring-boot-smoke-tests/spring-boot-smoke-test-structured-logging/src/main/resources/application.properties‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -7,3 +7,6 @@ logging.structured.json.customizer=smoketest.structuredlogging.SampleJsonMembers
77
#---
88
spring.config.activate.on-profile=custom
99
logging.structured.format.console=smoketest.structuredlogging.CustomStructuredLogFormatter
10+
#---
11+
spring.config.activate.on-profile=on-error
12+
logging.structured.json.customizer=smoketest.structuredlogging.DuplicateJsonMembersCustomizer

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

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -65,4 +65,10 @@ void custom(CapturedOutput output) {
6565
assertThat(output).contains("epoch=").contains("msg=\"Starting SampleStructuredLoggingApplication");
6666
}
6767

68+
@Test
69+
void shouldCaptureCustomizerError(CapturedOutput output) {
70+
SampleStructuredLoggingApplication.main(new String[] { "--spring.profiles.active=on-error" });
71+
assertThat(output).contains("The name 'test' has already been written");
72+
}
73+
6874
}

0 commit comments

Comments
 (0)