diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/TraceFilter.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/TraceFilter.java index da980679f..a9692ebe2 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/TraceFilter.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/TraceFilter.java @@ -86,6 +86,9 @@ public class TraceFilter extends GenericFilterBean { protected static final String TRACE_ERROR_HANDLED_REQUEST_ATTR = TraceFilter.class.getName() + ".ERROR_HANDLED"; + protected static final String TRACE_CLOSE_SPAN_REQUEST_ATTR = TraceFilter.class.getName() + + ".CLOSE_SPAN"; + /** * @deprecated please use {@link SleuthWebProperties#DEFAULT_SKIP_PATTERN} */ @@ -243,6 +246,12 @@ public class TraceFilter extends GenericFilterBean { log.debug( "Won't detach the span " + span + " since error has already been handled"); } + } else if (shouldCloseSpan(request) && this.tracer.isTracing() && stillTracingCurrentSapn(span)) { + if (log.isDebugEnabled()) { + log.debug( + "Will close span " + span + " since some component marked it for closure"); + } + this.tracer.close(span); } else if (this.tracer.isTracing()) { if (log.isDebugEnabled()) { log.debug("Detaching the span " + span + " since the response was unsuccessful"); @@ -252,6 +261,10 @@ public class TraceFilter extends GenericFilterBean { } } + private boolean stillTracingCurrentSapn(Span span) { + return this.tracer.getCurrentSpan().equals(span); + } + private void recordParentSpan(Span parent) { if (parent == null) { return; @@ -287,6 +300,11 @@ public class TraceFilter extends GenericFilterBean { String.valueOf(request.getAttribute(TRACE_ERROR_HANDLED_REQUEST_ATTR))); } + private boolean shouldCloseSpan(HttpServletRequest request) { + return Boolean.valueOf( + String.valueOf(request.getAttribute(TRACE_CLOSE_SPAN_REQUEST_ATTR))); + } + private boolean isSpanContinued(HttpServletRequest request) { return getSpanFromAttribute(request) != null; } diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/TraceWebAspect.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/TraceWebAspect.java index bcf842bd0..7e759d7fc 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/TraceWebAspect.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/TraceWebAspect.java @@ -18,15 +18,21 @@ package org.springframework.cloud.sleuth.instrument.web; import java.lang.reflect.Field; import java.util.concurrent.Callable; +import javax.servlet.http.HttpServletRequest; +import javax.servlet.http.HttpServletResponse; import org.apache.commons.logging.Log; import org.aspectj.lang.ProceedingJoinPoint; import org.aspectj.lang.annotation.Around; import org.aspectj.lang.annotation.Aspect; import org.aspectj.lang.annotation.Pointcut; +import org.springframework.cloud.sleuth.NoOpSpanReporter; +import org.springframework.cloud.sleuth.Span; import org.springframework.cloud.sleuth.SpanNamer; +import org.springframework.cloud.sleuth.SpanReporter; import org.springframework.cloud.sleuth.Tracer; import org.springframework.cloud.sleuth.instrument.async.TraceContinuingCallable; +import org.springframework.cloud.sleuth.util.ExceptionUtils; import org.springframework.web.context.request.async.WebAsyncTask; /** @@ -70,10 +76,19 @@ public class TraceWebAspect { private final Tracer tracer; private final SpanNamer spanNamer; + private final SpanReporter spanReporter; + @Deprecated public TraceWebAspect(Tracer tracer, SpanNamer spanNamer) { this.tracer = tracer; this.spanNamer = spanNamer; + this.spanReporter = new NoOpSpanReporter(); + } + + public TraceWebAspect(Tracer tracer, SpanNamer spanNamer, SpanReporter spanReporter) { + this.tracer = tracer; + this.spanNamer = spanNamer; + this.spanReporter = spanReporter; } @Pointcut("@within(org.springframework.web.bind.annotation.RestController)") @@ -91,6 +106,9 @@ public class TraceWebAspect { @Pointcut("execution(public org.springframework.web.context.request.async.WebAsyncTask *(..))") private void anyPublicMethodReturningWebAsyncTask() { } // NOSONAR + @Pointcut("execution(public * org.springframework.web.servlet.HandlerExceptionResolver.resolveException(..)) && args(request, response, handler, ex)") + private void anyHandlerExceptionResolver(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) { } // NOSONAR + @Pointcut("(anyRestControllerAnnotated() || anyControllerAnnotated()) && anyPublicMethodReturningWebAsyncTask()") private void anyControllerOrRestControllerWithPublicWebAsyncTaskMethod() { } // NOSONAR @@ -129,4 +147,21 @@ public class TraceWebAspect { return webAsyncTask; } + @Around("anyHandlerExceptionResolver(request, response, handler, ex)") + public Object markRequestForSpanClosing(ProceedingJoinPoint pjp, + HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Throwable { + Span currentSpan = this.tracer.getCurrentSpan(); + try { + if (!currentSpan.tags().containsKey(Span.SPAN_ERROR_TAG_NAME)) { + this.tracer.addTag(Span.SPAN_ERROR_TAG_NAME, ExceptionUtils.getExceptionMessage(ex)); + } + return pjp.proceed(); + } finally { + if (log.isDebugEnabled()) { + log.debug("Marking span " + currentSpan + " for closure by Trace Filter"); + } + request.setAttribute(TraceFilter.TRACE_CLOSE_SPAN_REQUEST_ATTR, true); + } + } + } diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/TraceWebAutoConfiguration.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/TraceWebAutoConfiguration.java index 7b761239c..61820cb3f 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/TraceWebAutoConfiguration.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/TraceWebAutoConfiguration.java @@ -75,8 +75,8 @@ public class TraceWebAutoConfiguration { } @Bean - public TraceWebAspect traceWebAspect(Tracer tracer, SpanNamer spanNamer) { - return new TraceWebAspect(tracer, spanNamer); + public TraceWebAspect traceWebAspect(Tracer tracer, SpanNamer spanNamer, SpanReporter spanReporter) { + return new TraceWebAspect(tracer, spanNamer, spanReporter); } @Bean diff --git a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/client/exceptionresolver/Issue585Tests.java b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/client/exceptionresolver/Issue585Tests.java new file mode 100644 index 000000000..87b457eab --- /dev/null +++ b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/client/exceptionresolver/Issue585Tests.java @@ -0,0 +1,171 @@ +package org.springframework.cloud.sleuth.instrument.web.client.exceptionresolver; + +import com.fasterxml.jackson.annotation.JsonInclude; + +import java.time.Instant; +import javax.servlet.http.HttpServletRequest; + +import org.junit.Test; +import org.junit.runner.RunWith; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.springframework.beans.factory.annotation.Autowired; +import org.springframework.boot.autoconfigure.SpringBootApplication; +import org.springframework.boot.context.embedded.LocalServerPort; +import org.springframework.boot.test.context.SpringBootTest; +import org.springframework.boot.test.web.client.TestRestTemplate; +import org.springframework.cloud.sleuth.Sampler; +import org.springframework.cloud.sleuth.Span; +import org.springframework.cloud.sleuth.SpanReporter; +import org.springframework.cloud.sleuth.Tracer; +import org.springframework.cloud.sleuth.assertions.ListOfSpans; +import org.springframework.cloud.sleuth.assertions.SleuthAssertions; +import org.springframework.cloud.sleuth.sampler.AlwaysSampler; +import org.springframework.cloud.sleuth.util.ArrayListSpanAccumulator; +import org.springframework.context.annotation.Bean; +import org.springframework.http.HttpStatus; +import org.springframework.http.ResponseEntity; +import org.springframework.test.context.junit4.SpringRunner; +import org.springframework.web.bind.annotation.ControllerAdvice; +import org.springframework.web.bind.annotation.ExceptionHandler; +import org.springframework.web.bind.annotation.RequestMapping; +import org.springframework.web.bind.annotation.RequestMethod; +import org.springframework.web.bind.annotation.RequestParam; +import org.springframework.web.bind.annotation.RestController; +import org.springframework.web.servlet.mvc.method.annotation.ResponseEntityExceptionHandler; + +import static org.springframework.cloud.sleuth.assertions.SleuthAssertions.then; + +@RunWith(SpringRunner.class) +@SpringBootTest(classes = TestConfig.class, webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT) +public class Issue585Tests { + + TestRestTemplate testRestTemplate = new TestRestTemplate(); + @Autowired ArrayListSpanAccumulator accumulator; + @LocalServerPort int port; + + @Test + public void should_report_span_when_using_custom_exception_resolver() { + ResponseEntity entity = this.testRestTemplate.getForEntity( + "http://localhost:" + this.port + "/sleuthtest?greeting=foo", + String.class); + + then(entity.getStatusCode().value()).isEqualTo(500); + then(new ListOfSpans(this.accumulator.getSpans())) + .hasASpanWithTagEqualTo("custom", "tag") + .hasASpanWithTagKeyEqualTo("error"); + } +} + +@SpringBootApplication +class TestConfig { + + @Bean SpanReporter testSpanReporter() { + return new ArrayListSpanAccumulator(); + } + + @Bean Sampler testSampler() { + return new AlwaysSampler(); + } +} + +@RestController +class TestController { + + private final static Logger logger = LoggerFactory.getLogger(TestController.class); + + @RequestMapping(value = "sleuthtest", method = RequestMethod.GET) + public ResponseEntity testSleuth(@RequestParam String greeting) { + if (greeting.equalsIgnoreCase("hello")) { + return new ResponseEntity<>("Hello World", HttpStatus.OK); + } else { + throw new RuntimeException("This is a test error"); + } + } +} + +@ControllerAdvice +class CustomExceptionHandler extends ResponseEntityExceptionHandler { + + private final static Logger logger = LoggerFactory + .getLogger(CustomExceptionHandler.class); + + @Autowired private Tracer tracer; + + @ExceptionHandler(value = { Exception.class }) + protected ResponseEntity handleDefaultError( + Exception ex, HttpServletRequest request) { + ExceptionResponse exceptionResponse = new ExceptionResponse("ERR-01", + ex.getMessage(), HttpStatus.INTERNAL_SERVER_ERROR, + request.getRequestURI(), Instant.now().toEpochMilli()); + reportErrorSpan(ex.getMessage()); + return new ResponseEntity<>(exceptionResponse, HttpStatus.INTERNAL_SERVER_ERROR); + } + + private void reportErrorSpan(String message) { + Span span = tracer.getCurrentSpan(); + span.logEvent("ERROR: " + message); + tracer.addTag("custom", "tag"); + logger.info("Foo"); + } + +} + +@JsonInclude(JsonInclude.Include.NON_NULL) +class ExceptionResponse { + private String errorCode; + private String errorMessage; + private HttpStatus httpStatus; + private String path; + private Long epochTime; + + ExceptionResponse(String errorCode, String errorMessage, HttpStatus httpStatus, + String path, Long epochTime) { + this.errorCode = errorCode; + this.errorMessage = errorMessage; + this.httpStatus = httpStatus; + this.path = path; + this.epochTime = epochTime; + } + + public String getErrorCode() { + return errorCode; + } + + public void setErrorCode(String errorCode) { + this.errorCode = errorCode; + } + + public String getErrorMessage() { + return errorMessage; + } + + public void setErrorMessage(String errorMessage) { + this.errorMessage = errorMessage; + } + + public HttpStatus getHttpStatus() { + return httpStatus; + } + + public void setHttpStatus(HttpStatus httpStatus) { + this.httpStatus = httpStatus; + } + + public String getPath() { + return path; + } + + public void setPath(String path) { + this.path = path; + } + + public Long getEpochTime() { + return epochTime; + } + + public void setEpochTime(Long epochTime) { + this.epochTime = epochTime; + } + +} \ No newline at end of file