Exceptions that escape SpringMVC DispatcherServlet should be logged w…

…ith trace & span IDs

without this change any exception that is not caught by a filter, get caught and logged by server's internals (e.g. Tomcat's Valve). To make the Valve log the exception together with the tracing information we would have to allow the tracing context remain in the thread after TraceFilter gets executed. That is problematic cause we're polluting the ThreadLocal and would have to assume that some component will eventually clear the context.

with this change we're trying to solve the issue from a different angle. Whenever an uncaught exception is thrown, we are already catching it in the `catch(...) {}` clause. It's enough to just log it at the error level and that way, regardless of the underlying server implementation (Tomcat, Undertow) we will log the uncaught exception and rethrow it.

fixes #714

spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/TraceFilter.java

@@ -165,6 +165,9 @@ public void doFilter(ServletRequest servletRequest, ServletResponse servletRespo
 		} catch (Throwable e) {
 			exception = e;
 			errorParser().parseErrorTags(tracer().getCurrentSpan(), e);
+			if (log.isErrorEnabled()) {
+				log.error("Uncaught exception thrown", e);
+			}
 			throw e;
 		} finally {
 			if (isAsyncStarted(request) || request.isAsyncStarted()) {

spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/TraceFilterWebIntegrationTests.java

@@ -16,18 +16,20 @@
 
 package org.springframework.cloud.sleuth.instrument.web;
 
-import static org.assertj.core.api.Assertions.fail;
-import static org.springframework.cloud.sleuth.assertions.SleuthAssertions.then;
-
 import java.io.IOException;
+import java.util.Arrays;
+import java.util.List;
+import java.util.stream.Collectors;
 
 import org.junit.After;
 import org.junit.Before;
+import org.junit.Rule;
 import org.junit.Test;
 import org.junit.runner.RunWith;
 import org.springframework.beans.factory.annotation.Autowired;
 import org.springframework.boot.autoconfigure.EnableAutoConfiguration;
 import org.springframework.boot.test.context.SpringBootTest;
+import org.springframework.boot.test.rule.OutputCapture;
 import org.springframework.cloud.sleuth.Sampler;
 import org.springframework.cloud.sleuth.Span;
 import org.springframework.cloud.sleuth.Tracer;
@@ -49,6 +51,9 @@
 import org.springframework.web.client.HttpClientErrorException;
 import org.springframework.web.client.RestTemplate;
 
+import static org.assertj.core.api.Assertions.fail;
+import static org.springframework.cloud.sleuth.assertions.SleuthAssertions.then;
+
 /**
  * @author Marcin Grzejszczak
  */
@@ -61,6 +66,7 @@ public class TraceFilterWebIntegrationTests {
 	@Autowired ArrayListSpanAccumulator accumulator;
 	@Autowired RestTemplate restTemplate;
 	@Autowired Environment environment;
+	@Rule  public OutputCapture capture = new OutputCapture();
 
 	@Before
 	@After
@@ -82,7 +88,15 @@ public void should_not_create_a_span_for_error_controller() {
 		then(new ListOfSpans(this.accumulator.getSpans()))
 				.hasASpanWithTagEqualTo(Span.SPAN_ERROR_TAG_NAME,
 						"Request processing failed; nested exception is java.lang.RuntimeException: Throwing exception")
-				.hasRpcTagsInProperOrder();
+				.hasRpcTagsInProperOrder();// issue#714
+		Span span = this.accumulator.getSpans().get(0);
+		String hex = Span.idToHex(span.getTraceId());
+		String[] split = capture.toString().split("\n");
+		List<String> list = Arrays.stream(split).filter(s -> s.contains(
+				"Uncaught exception thrown"))
+				.filter(s -> s.contains("[bootstrap," + hex + "," + hex + ",true]"))
+				.collect(Collectors.toList());
+		then(list).isNotEmpty();
 	}
 
 	@Test