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-43575

Signed-off-by: Dmytro Nosan <dimanosan@gmail.com>
This commit is contained in:
Dmytro Nosan 2024-12-19 14:40:56 +02:00 committed by Moritz Halbritter
parent c847ce4a8b
commit c256f41fce
7 changed files with 291 additions and 2 deletions

View File

@ -0,0 +1,80 @@
/*
* Copyright 2012-2025 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.logging.logback;
import ch.qos.logback.core.spi.ContextAwareBase;
import ch.qos.logback.core.spi.LifeCycle;
import ch.qos.logback.core.status.Status;
import ch.qos.logback.core.status.StatusListener;
/**
* Logback {@link StatusListener} that filters {@link Status} by its logging level and
* delegates to the underlying {@code StatusListener}.
*
* @author Dmytro Nosan
*/
final class FilteringStatusListener extends ContextAwareBase implements StatusListener, LifeCycle {
private final StatusListener delegate;
private final int levelThreshold;
/**
* Creates a new {@link FilteringStatusListener}.
* @param delegate the {@link StatusListener} delegate to
* @param levelThreshold the minimum log level accepted for delegation
*/
FilteringStatusListener(StatusListener delegate, int levelThreshold) {
this.delegate = delegate;
this.levelThreshold = levelThreshold;
}
@Override
public void addStatusEvent(Status status) {
if (status.getLevel() >= this.levelThreshold) {
this.delegate.addStatusEvent(status);
}
}
@Override
public boolean isResetResistant() {
return this.delegate.isResetResistant();
}
@Override
public void start() {
if (this.delegate instanceof LifeCycle lifeCycle) {
lifeCycle.start();
}
}
@Override
public void stop() {
if (this.delegate instanceof LifeCycle lifeCycle) {
lifeCycle.stop();
}
}
@Override
public boolean isStarted() {
if (this.delegate instanceof LifeCycle lifeCycle) {
return lifeCycle.isStarted();
}
return true;
}
}

View File

@ -36,6 +36,7 @@ import ch.qos.logback.classic.turbo.TurboFilter;
import ch.qos.logback.core.joran.spi.JoranException;
import ch.qos.logback.core.spi.FilterReply;
import ch.qos.logback.core.status.OnConsoleStatusListener;
import ch.qos.logback.core.status.OnErrorConsoleStatusListener;
import ch.qos.logback.core.status.Status;
import ch.qos.logback.core.status.StatusUtil;
import ch.qos.logback.core.util.StatusListenerConfigHelper;
@ -234,6 +235,9 @@ public class LogbackLoggingSystem extends AbstractLoggingSystem implements BeanF
if (debug) {
StatusListenerConfigHelper.addOnConsoleListenerInstance(loggerContext, new OnConsoleStatusListener());
}
else {
addOnErrorConsoleStatusListener(loggerContext);
}
Environment environment = initializationContext.getEnvironment();
// Apply system properties directly in case the same JVM runs multiple apps
new LogbackLoggingSystemProperties(environment, getDefaultValueResolver(environment),
@ -487,6 +491,14 @@ public class LogbackLoggingSystem extends AbstractLoggingSystem implements BeanF
}
}
private void addOnErrorConsoleStatusListener(LoggerContext context) {
FilteringStatusListener listener = new FilteringStatusListener(new OnErrorConsoleStatusListener(),
Status.ERROR);
listener.setContext(context);
context.getStatusManager().add(listener);
listener.start();
}
void setStatusPrinterStream(PrintStream stream) {
this.statusPrinter.setPrintStream(stream);
}

View File

@ -0,0 +1,121 @@
/*
* Copyright 2012-2025 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.logging.logback;
import java.util.ArrayList;
import java.util.List;
import ch.qos.logback.core.spi.LifeCycle;
import ch.qos.logback.core.status.ErrorStatus;
import ch.qos.logback.core.status.InfoStatus;
import ch.qos.logback.core.status.Status;
import ch.qos.logback.core.status.StatusListener;
import ch.qos.logback.core.status.WarnStatus;
import org.junit.jupiter.api.Test;
import static org.assertj.core.api.Assertions.assertThat;
/**
* Tests for {@link FilteringStatusListener}.
*
* @author Dmytro Nosan
*/
class FilteringStatusListenerTests {
private final DelegateStatusListener delegate = new DelegateStatusListener();
@Test
void shouldFilterOutInfoStatus() {
FilteringStatusListener listener = createListener(Status.WARN);
InfoStatus info = new InfoStatus("info", getClass());
WarnStatus warn = new WarnStatus("warn", getClass());
ErrorStatus error = new ErrorStatus("error", getClass());
listener.addStatusEvent(info);
listener.addStatusEvent(warn);
listener.addStatusEvent(error);
assertThat(this.delegate.getStatuses()).containsExactly(warn, error);
}
@Test
void shouldStartUnderlyingStatusListener() {
FilteringStatusListener listener = createListener(Status.INFO);
assertThat(this.delegate.isStarted()).isFalse();
listener.start();
assertThat(this.delegate.isStarted()).isTrue();
}
@Test
void shouldStopUnderlyingStatusListener() {
FilteringStatusListener listener = createListener();
this.delegate.start();
assertThat(this.delegate.isStarted()).isTrue();
listener.stop();
assertThat(this.delegate.isStarted()).isFalse();
}
@Test
void shouldUseResetResistantValueFromUnderlyingStatusListener() {
FilteringStatusListener listener = createListener();
assertThat(listener.isResetResistant()).isEqualTo(this.delegate.isResetResistant());
}
private FilteringStatusListener createListener() {
return new FilteringStatusListener(this.delegate, Status.INFO);
}
private FilteringStatusListener createListener(int levelThreshold) {
return new FilteringStatusListener(this.delegate, levelThreshold);
}
private static final class DelegateStatusListener implements StatusListener, LifeCycle {
private final List<Status> statuses = new ArrayList<>();
private boolean started = false;
@Override
public void addStatusEvent(Status status) {
this.statuses.add(status);
}
List<Status> getStatuses() {
return this.statuses;
}
@Override
public boolean isResetResistant() {
return true;
}
@Override
public void start() {
this.started = true;
}
@Override
public void stop() {
this.started = false;
}
@Override
public boolean isStarted() {
return this.started;
}
}
}

View File

@ -1,5 +1,5 @@
/*
* Copyright 2012-2024 the original author or authors.
* Copyright 2012-2025 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.
@ -32,12 +32,18 @@ import java.util.stream.Stream;
import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.LoggerContext;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.classic.spi.LoggerContextListener;
import ch.qos.logback.core.AppenderBase;
import ch.qos.logback.core.ConsoleAppender;
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.OnConsoleStatusListener;
import ch.qos.logback.core.status.OnErrorConsoleStatusListener;
import ch.qos.logback.core.status.Status;
import ch.qos.logback.core.status.StatusListener;
import ch.qos.logback.core.util.DynamicClassLoadingException;
import org.junit.jupiter.api.AfterEach;
import org.junit.jupiter.api.BeforeEach;
@ -649,12 +655,41 @@ class LogbackLoggingSystemTests extends AbstractLoggingSystemTests {
assertThat(output).contains("LevelChangePropagator")
.contains("SizeAndTimeBasedFileNamingAndTriggeringPolicy")
.contains("DebugLogbackConfigurator");
LoggerContext loggerContext = this.logger.getLoggerContext();
List<StatusListener> statusListeners = loggerContext.getStatusManager().getCopyOfStatusListenerList();
assertThat(statusListeners).hasSize(1);
StatusListener statusListener = statusListeners.get(0);
assertThat(statusListener).isInstanceOf(OnConsoleStatusListener.class);
}
finally {
System.clearProperty("logback.debug");
}
}
@Test
void logbackErrorStatusListenerShouldBeRegistered(CapturedOutput output) {
this.loggingSystem.beforeInitialize();
initialize(this.initializationContext, null, getLogFile(tmpDir() + "/tmp.log", null));
LoggerContext loggerContext = this.logger.getLoggerContext();
List<StatusListener> statusListeners = loggerContext.getStatusManager().getCopyOfStatusListenerList();
assertThat(statusListeners).hasSize(1);
StatusListener statusListener = statusListeners.get(0);
assertThat(statusListener).isInstanceOf(FilteringStatusListener.class);
assertThat(statusListener).hasFieldOrPropertyWithValue("levelThreshold", Status.ERROR);
assertThat(statusListener).extracting("delegate").isInstanceOf(OnErrorConsoleStatusListener.class);
AppenderBase<ILoggingEvent> appender = new AppenderBase<>() {
@Override
protected void append(ILoggingEvent eventObject) {
throw new IllegalStateException("Fail to append");
}
};
this.logger.addAppender(appender);
appender.setContext(loggerContext);
appender.start();
this.logger.info("Hello world");
assertThat(output).contains("Fail to append").contains("Hello world");
}
@Test
void testRollingFileNameProperty() {
String rollingFile = "my.log.%d{yyyyMMdd}.%i.gz";

View File

@ -0,0 +1,32 @@
/*
* Copyright 2012-2025 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 smoketest.structuredlogging;
import java.util.Objects;
import org.springframework.boot.json.JsonWriter.Members;
import org.springframework.boot.logging.structured.StructuredLoggingJsonMembersCustomizer;
public class DuplicateJsonMembersCustomizer implements StructuredLoggingJsonMembersCustomizer<Object> {
@Override
public void customize(Members<Object> members) {
members.add("test").as(Objects::toString);
members.add("test").as(Objects::toString);
}
}

View File

@ -7,3 +7,6 @@ logging.structured.json.customizer=smoketest.structuredlogging.SampleJsonMembers
#---
spring.config.activate.on-profile=custom
logging.structured.format.console=smoketest.structuredlogging.CustomStructuredLogFormatter
#---
spring.config.activate.on-profile=on-error
logging.structured.json.customizer=smoketest.structuredlogging.DuplicateJsonMembersCustomizer

View File

@ -1,5 +1,5 @@
/*
* Copyright 2012-2024 the original author or authors.
* Copyright 2012-2025 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.
@ -65,4 +65,10 @@ class SampleStructuredLoggingApplicationTests {
assertThat(output).contains("epoch=").contains("msg=\"Starting SampleStructuredLoggingApplication");
}
@Test
void shouldCaptureCustomizerError(CapturedOutput output) {
SampleStructuredLoggingApplication.main(new String[] { "--spring.profiles.active=on-error" });
assertThat(output).contains("The name 'test' has already been written");
}
}