Deprecates ExceptionLoggingFilter and disables it by default (#1633)

`ExceptionLoggingFilter` logs "Uncaught exception thrown" to error level when there is a synchronous exception not otherwise swallowed. This is a cure worse than the disease. This disables it by default and the 3.x should end the years of problems it caused.
spring-cloud · May 15, 2020 · f982149 · f982149
1 parent 0290437
commit f982149
Show file tree

Hide file tree

Showing 7 changed files with 66 additions and 29 deletions.
diff --git a/...ore/src/main/java/org/springframework/cloud/sleuth/autoconfig/TraceAutoConfiguration.java b/...ore/src/main/java/org/springframework/cloud/sleuth/autoconfig/TraceAutoConfiguration.java
@@ -54,6 +54,7 @@
 import org.springframework.cloud.sleuth.LocalServiceName;
 import org.springframework.cloud.sleuth.SpanAdjuster;
 import org.springframework.cloud.sleuth.SpanNamer;
+import org.springframework.cloud.sleuth.log.SleuthLogAutoConfiguration;
 import org.springframework.cloud.sleuth.sampler.SamplerAutoConfiguration;
 import org.springframework.context.annotation.Bean;
 import org.springframework.context.annotation.Configuration;
@@ -73,7 +74,7 @@
 @Configuration(proxyBeanMethods = false)
 @ConditionalOnProperty(value = "spring.sleuth.enabled", matchIfMissing = true)
 @EnableConfigurationProperties(SleuthProperties.class)
-@Import(SamplerAutoConfiguration.class)
+@Import({ SleuthLogAutoConfiguration.class, SamplerAutoConfiguration.class })
 public class TraceAutoConfiguration {
 
 	/**
@@ -92,18 +93,12 @@ public class TraceAutoConfiguration {
 	@Autowired(required = false)
 	List<FinishedSpanHandler> finishedSpanHandlers = new ArrayList<>();
 
-	@Autowired(required = false)
-	List<CurrentTraceContext.ScopeDecorator> scopeDecorators = new ArrayList<>();
-
 	@Autowired(required = false)
 	ExtraFieldPropagation.FactoryBuilder extraFieldPropagationFactoryBuilder;
 
 	@Autowired(required = false)
 	List<TracingCustomizer> tracingCustomizers = new ArrayList<>();
 
-	@Autowired(required = false)
-	List<CurrentTraceContextCustomizer> currentTraceContextCustomizers = new ArrayList<>();
-
 	@Autowired(required = false)
 	List<ExtraFieldCustomizer> extraFieldCustomizers = new ArrayList<>();
 
@@ -186,11 +181,20 @@ Propagation.Factory sleuthPropagation(SleuthProperties sleuthProperties) {
 	}
 
 	@Bean
-	CurrentTraceContext sleuthCurrentTraceContext(CurrentTraceContext.Builder builder) {
-		for (CurrentTraceContext.ScopeDecorator scopeDecorator : this.scopeDecorators) {
+	CurrentTraceContext sleuthCurrentTraceContext(CurrentTraceContext.Builder builder,
+			@Nullable List<CurrentTraceContext.ScopeDecorator> scopeDecorators,
+			@Nullable List<CurrentTraceContextCustomizer> currentTraceContextCustomizers) {
+		if (scopeDecorators == null) {
+			scopeDecorators = Collections.emptyList();
+		}
+		if (currentTraceContextCustomizers == null) {
+			currentTraceContextCustomizers = Collections.emptyList();
+		}
+
+		for (CurrentTraceContext.ScopeDecorator scopeDecorator : scopeDecorators) {
 			builder.addScopeDecorator(scopeDecorator);
 		}
-		for (CurrentTraceContextCustomizer customizer : this.currentTraceContextCustomizers) {
+		for (CurrentTraceContextCustomizer customizer : currentTraceContextCustomizers) {
 			customizer.customize(builder);
 		}
 		return builder.build();

diff --git a/...src/main/java/org/springframework/cloud/sleuth/instrument/web/ExceptionLoggingFilter.java b/...src/main/java/org/springframework/cloud/sleuth/instrument/web/ExceptionLoggingFilter.java
@@ -29,11 +29,9 @@
 import org.apache.commons.logging.LogFactory;
 
 /**
- * Filter running after {@link brave.servlet.TracingFilter} that logs uncaught exceptions.
- *
- * @author Marcin Grzejszczak
- * @since 2.0.0
+ * @deprecated Since 2.2.3 this is disabled by default and will be removed in 3.0
  */
+@Deprecated
 class ExceptionLoggingFilter implements Filter {
 
 	private static final Log log = LogFactory.getLog(ExceptionLoggingFilter.class);

diff --git a/...ava/org/springframework/cloud/sleuth/instrument/web/TraceWebServletAutoConfiguration.java b/...ava/org/springframework/cloud/sleuth/instrument/web/TraceWebServletAutoConfiguration.java
@@ -83,10 +83,8 @@ public FilterRegistrationBean traceWebFilter(BeanFactory beanFactory,
 		return filterRegistrationBean;
 	}
 
-	// TODO: Rename to exception-logging-filter for 3.0
 	@Bean
-	@ConditionalOnProperty(value = "spring.sleuth.web.exception-logging-filter-enabled",
-			matchIfMissing = true)
+	@ConditionalOnProperty("spring.sleuth.web.exception-logging-filter-enabled")
 	public FilterRegistrationBean exceptionThrowingFilter(
 			SleuthWebProperties webProperties) {
 		FilterRegistrationBean filterRegistrationBean = new FilterRegistrationBean(

diff --git a/...h-core/src/main/java/org/springframework/cloud/sleuth/log/SleuthLogAutoConfiguration.java b/...h-core/src/main/java/org/springframework/cloud/sleuth/log/SleuthLogAutoConfiguration.java
@@ -19,28 +19,29 @@
 import brave.propagation.CurrentTraceContext;
 import org.slf4j.MDC;
 
-import org.springframework.boot.autoconfigure.AutoConfigureBefore;
 import org.springframework.boot.autoconfigure.condition.ConditionalOnClass;
 import org.springframework.boot.autoconfigure.condition.ConditionalOnProperty;
 import org.springframework.boot.context.properties.EnableConfigurationProperties;
 import org.springframework.cloud.sleuth.autoconfig.SleuthProperties;
-import org.springframework.cloud.sleuth.autoconfig.TraceAutoConfiguration;
 import org.springframework.context.annotation.Bean;
 import org.springframework.context.annotation.Configuration;
 
 /**
- * {@link org.springframework.boot.autoconfigure.EnableAutoConfiguration
- * Auto-configuration} adds a {@link Slf4jScopeDecorator} that prints tracing information
- * in the logs.
+ * {@link Configuration} that adds a {@link Slf4jScopeDecorator} that prints tracing
+ * information in the logs.
  * <p>
  *
  * @author Spencer Gibb
  * @author Marcin Grzejszczak
  * @since 2.0.0
+ * @deprecated Do not use this type directly as it was removed in 3.x
  */
 @Configuration(proxyBeanMethods = false)
 @ConditionalOnProperty(value = "spring.sleuth.enabled", matchIfMissing = true)
-@AutoConfigureBefore(TraceAutoConfiguration.class)
+// This is not auto-configuration, but it was in the past. Leaving the name as
+// SleuthLogAutoConfiguration because some may have imported this directly.
+// A less precise name is better than rev-locking code.
+@Deprecated
 public class SleuthLogAutoConfiguration {
 
 	/**
@@ -49,7 +50,7 @@ public class SleuthLogAutoConfiguration {
 	@Configuration(proxyBeanMethods = false)
 	@ConditionalOnClass(MDC.class)
 	@EnableConfigurationProperties(SleuthSlf4jProperties.class)
-	protected static class Slf4jConfiguration {
+	public static class Slf4jConfiguration {
 
 		@Bean
 		@ConditionalOnProperty(value = "spring.sleuth.log.slf4j.enabled",

diff --git a/spring-cloud-sleuth-core/src/main/resources/META-INF/spring.factories b/spring-cloud-sleuth-core/src/main/resources/META-INF/spring.factories
@@ -2,7 +2,6 @@
 org.springframework.boot.autoconfigure.EnableAutoConfiguration=\
 org.springframework.cloud.sleuth.annotation.SleuthAnnotationAutoConfiguration,\
 org.springframework.cloud.sleuth.autoconfig.TraceAutoConfiguration,\
-org.springframework.cloud.sleuth.log.SleuthLogAutoConfiguration,\
 org.springframework.cloud.sleuth.propagation.SleuthTagPropagationAutoConfiguration,\
 org.springframework.cloud.sleuth.instrument.web.TraceHttpAutoConfiguration,\
 org.springframework.cloud.sleuth.instrument.web.TraceWebAutoConfiguration,\

diff --git a/.../java/org/springframework/cloud/sleuth/instrument/web/TraceFilterWebIntegrationTests.java b/.../java/org/springframework/cloud/sleuth/instrument/web/TraceFilterWebIntegrationTests.java
@@ -22,15 +22,22 @@
 import java.util.regex.Pattern;
 import java.util.stream.Collectors;
 
+import brave.Span.Kind;
+import brave.handler.FinishedSpanHandler;
+import brave.handler.MutableSpan;
 import brave.http.HttpRequest;
 import brave.http.HttpRequestParser;
 import brave.propagation.CurrentTraceContext;
+import brave.propagation.CurrentTraceContext.Scope;
+import brave.propagation.TraceContext;
 import brave.sampler.Sampler;
 import brave.sampler.SamplerFunction;
 import org.assertj.core.api.BDDAssertions;
 import org.junit.jupiter.api.AfterEach;
 import org.junit.jupiter.api.Test;
 import org.junit.jupiter.api.extension.ExtendWith;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 import zipkin2.Span;
 
 import org.springframework.beans.factory.annotation.Autowired;
@@ -64,6 +71,9 @@
 		properties = "spring.sleuth.http.legacy.enabled=true")
 public class TraceFilterWebIntegrationTests {
 
+	private static final Logger log = LoggerFactory
+			.getLogger(TraceFilterWebIntegrationTests.class);
+
 	@Autowired
 	CurrentTraceContext currentTraceContext;
 
@@ -92,7 +102,8 @@ public void should_tag_url() {
 	}
 
 	@Test
-	public void should_not_create_a_span_for_error_controller(CapturedOutput capture) {
+	public void exception_logging_span_handler_logs_synchronous_exceptions(
+			CapturedOutput capture) {
 		try {
 			new RestTemplate().getForObject("http://localhost:" + port() + "/",
 					String.class);
@@ -107,7 +118,7 @@ public void should_not_create_a_span_for_error_controller(CapturedOutput capture
 				.containsEntry("mvc.controller.class", "ExceptionThrowingController")
 				.containsEntry("error",
 						"Request processing failed; nested exception is java.lang.RuntimeException: Throwing exception");
-		// issue#714
+		// Trace IDs in logs: issue#714
 		String hex = fromFirstTraceFilterFlow.traceId();
 		String[] split = capture.toString().split("\n");
 		List<String> list = Arrays.stream(split)
@@ -162,6 +173,32 @@ BlockingQueueSpanReporter reporter() {
 			return new BlockingQueueSpanReporter();
 		}
 
+		@Bean
+		FinishedSpanHandler uncaughtExceptionThrown(
+				CurrentTraceContext currentTraceContext) {
+			return new FinishedSpanHandler() {
+				@Override
+				public boolean handle(TraceContext context, MutableSpan span) {
+					if (span.kind() != Kind.SERVER || span.error() == null
+							|| !log.isErrorEnabled()) {
+						return true; // don't add overhead as we only log server errors
+					}
+
+					// In TracingFilter, the exception is raised in scope. This is is more
+					// explicit to ensure it works in other tech such as WebFlux.
+					try (Scope scope = currentTraceContext.maybeScope(context)) {
+						log.error("Uncaught exception thrown", span.error());
+					}
+					return true;
+				}
+
+				@Override
+				public String toString() {
+					return "UncaughtExceptionThrown";
+				}
+			};
+		}
+
 		@Bean
 		Sampler alwaysSampler() {
 			return Sampler.ALWAYS_SAMPLE;

diff --git a/...rg/springframework/cloud/sleuth/instrument/web/TraceWebServletAutoConfigurationTests.java b/...rg/springframework/cloud/sleuth/instrument/web/TraceWebServletAutoConfigurationTests.java
@@ -37,9 +37,9 @@ public class TraceWebServletAutoConfigurationTests {
 					TraceWebServletAutoConfiguration.class));
 
 	@Test
-	public void shouldCreateExceptionLoggingFilterBeanByDefault() {
+	public void shouldNotCreateExceptionLoggingFilterBeanByDefault() {
 		this.contextRunner.run((context) -> {
-			assertThat(context).hasBean(EXCEPTION_LOGGING_FILTER_BEAN_NAME);
+			assertThat(context).doesNotHaveBean(EXCEPTION_LOGGING_FILTER_BEAN_NAME);
 		});
 	}