Fixed not clearing trace attribute on closed span

due to this Zuul spans have been improperly closed and the span remained in the main thread. After sending enough requests the traces started to be reused by the worker threads.

fixes #634

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

@@ -257,7 +257,8 @@ public class TraceFilter extends GenericFilterBean {
 					log.debug("Closing the span " + span + " since the response was successful");
 				}
 				tracer().close(span);
-			} else if (errorAlreadyHandled(request) && tracer().isTracing()) {
+				clearTraceAttribute(request);
+			} else if (errorAlreadyHandled(request) && tracer().isTracing() && !shouldCloseSpan(request)) {
 				if (log.isDebugEnabled()) {
 					log.debug(
 							"Won't detach the span " + span + " since error has already been handled");
@@ -268,11 +269,13 @@ public class TraceFilter extends GenericFilterBean {
 							"Will close span " + span + " since some component marked it for closure");
 				}
 				tracer().close(span);
+				clearTraceAttribute(request);
 			} else if (tracer().isTracing()) {
 				if (log.isDebugEnabled()) {
 					log.debug("Detaching the span " + span + " since the response was unsuccessful");
 				}
 				tracer().detach(span);
+				clearTraceAttribute(request);
 			}
 		}
 	}
@@ -311,6 +314,10 @@ public class TraceFilter extends GenericFilterBean {
 		return (Span) request.getAttribute(TRACE_REQUEST_ATTR);
 	}
 
+	private void clearTraceAttribute(HttpServletRequest request) {
+		request.setAttribute(TRACE_REQUEST_ATTR, null);
+	}
+
 	private boolean errorAlreadyHandled(HttpServletRequest request) {
 		return Boolean.valueOf(
 				String.valueOf(request.getAttribute(TRACE_ERROR_HANDLED_REQUEST_ATTR)));

spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/zuul/TracePreZuulFilter.java

@@ -28,6 +28,7 @@ import org.springframework.cloud.sleuth.Span;
 import org.springframework.cloud.sleuth.Tracer;
 import org.springframework.cloud.sleuth.instrument.web.HttpSpanInjector;
 import org.springframework.cloud.sleuth.instrument.web.HttpTraceKeysInjector;
+import org.springframework.cloud.sleuth.instrument.web.TraceFilter;
 import org.springframework.cloud.sleuth.instrument.web.TraceRequestAttributes;
 
 import java.lang.invoke.MethodHandles;
@@ -44,6 +45,11 @@ public class TracePreZuulFilter extends ZuulFilter {
 
 	private static final Log log = LogFactory.getLog(MethodHandles.lookup().lookupClass());
 
+	private static final String TRACE_REQUEST_ATTR = TraceFilter.class.getName()
+			+ ".TRACE";
+	private static final String TRACE_CLOSE_SPAN_REQUEST_ATTR = TraceFilter.class.getName()
+			+ ".CLOSE_SPAN";
+
 	private static final String ZUUL_COMPONENT = "zuul";
 
 	private final Tracer tracer;
@@ -94,6 +100,11 @@ public class TracePreZuulFilter extends ZuulFilter {
 		if (log.isDebugEnabled()) {
 			log.debug("New Zuul Span is " + newSpan + "");
 		}
+		if (log.isDebugEnabled()) {
+			log.debug("Setting attributes for TraceFilter to pick up later");
+		}
+		RequestContext.getCurrentContext().getRequest().setAttribute(TRACE_REQUEST_ATTR, this.tracer.getCurrentSpan());
+		RequestContext.getCurrentContext().getRequest().setAttribute(TRACE_CLOSE_SPAN_REQUEST_ATTR, true);
 		ZuulFilterResult result = super.runFilter();
 		if (log.isDebugEnabled()) {
 			log.debug("Result of Zuul filter is [" + result.getStatus() + "]");

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

@@ -3,6 +3,8 @@ package org.springframework.cloud.sleuth.instrument.web.multiple;
 import java.util.Arrays;
 import java.util.List;
 
+import org.apache.commons.logging.Log;
+import org.apache.commons.logging.LogFactory;
 import org.springframework.beans.factory.annotation.Autowired;
 import org.springframework.integration.annotation.Aggregator;
 import org.springframework.integration.annotation.Gateway;
@@ -21,6 +23,8 @@ import org.springframework.web.bind.annotation.RestController;
 @IntegrationComponentScan
 public class DemoApplication {
 
+	private static final Log log = LogFactory.getLog(DemoApplication.class);
+
 	@Autowired
 	Sender sender;
 
@@ -42,7 +46,7 @@ public class DemoApplication {
 
 	@ServiceActivator(inputChannel="counts")
 	public void report(int count) {
-		System.err.println("Count: " + count);
+		log.info("Count: " + count);
 	}
 
 }

spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/zuul/issues/issue634/Issue634Tests.java

@@ -0,0 +1,106 @@
+package org.springframework.cloud.sleuth.instrument.zuul.issues.issue634;
+
+import java.util.HashSet;
+import java.util.Map;
+import java.util.concurrent.ConcurrentHashMap;
+
+import com.netflix.zuul.ZuulFilter;
+import org.junit.After;
+import org.junit.Before;
+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.context.embedded.LocalServerPort;
+import org.springframework.boot.test.context.SpringBootTest;
+import org.springframework.boot.test.web.client.TestRestTemplate;
+import org.springframework.cloud.netflix.zuul.EnableZuulProxy;
+import org.springframework.cloud.sleuth.Tracer;
+import org.springframework.cloud.sleuth.trace.TestSpanContextHolder;
+import org.springframework.cloud.sleuth.util.ExceptionUtils;
+import org.springframework.context.annotation.Bean;
+import org.springframework.context.annotation.Configuration;
+import org.springframework.test.annotation.DirtiesContext;
+import org.springframework.test.context.junit4.SpringRunner;
+
+import static org.assertj.core.api.BDDAssertions.then;
+
+@RunWith(SpringRunner.class)
+@SpringBootTest(classes = TestZuulApplication.class,
+		webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT,
+		properties = {"feign.hystrix.enabled=false",
+				"zuul.routes.dp.path:/display/**",
+				"zuul.routes.dp.path.url: http://localhost:9987/unknown"})
+@DirtiesContext
+public class Issue634Tests {
+
+	@LocalServerPort int port;
+	@Autowired Tracer tracer;
+	@Autowired TraceCheckingSpanFilter filter;
+
+	@Before
+	public void setup() {
+		TestSpanContextHolder.removeCurrentSpan();
+		ExceptionUtils.setFail(true);
+	}
+
+	@After
+	public void close() {
+		TestSpanContextHolder.removeCurrentSpan();
+	}
+
+	@Test
+	public void should_reuse_custom_feign_client() {
+		for (int i = 0; i < 15; i++) {
+			new TestRestTemplate()
+					.getForEntity("http://localhost:" + this.port + "/display/ddd",
+							String.class);
+
+			then(this.tracer.getCurrentSpan()).isNull();
+			then(ExceptionUtils.getLastException()).isNull();
+		}
+		then(new HashSet<>(this.filter.counter.values()))
+				.describedAs("trace id should not be reused from thread").hasSize(1);
+	}
+}
+
+@EnableZuulProxy
+@EnableAutoConfiguration
+@Configuration
+class TestZuulApplication {
+
+	@Bean
+	TraceCheckingSpanFilter traceCheckingSpanFilter(Tracer tracer) {
+		return new TraceCheckingSpanFilter(tracer);
+	}
+
+}
+
+class TraceCheckingSpanFilter extends ZuulFilter {
+
+	private final Tracer tracer;
+	final Map<Long, Integer> counter = new ConcurrentHashMap<>();
+
+	TraceCheckingSpanFilter(Tracer tracer) {
+		this.tracer = tracer;
+	}
+
+	@Override public String filterType() {
+		return "post";
+	}
+
+	@Override public int filterOrder() {
+		return -1;
+	}
+
+	@Override public boolean shouldFilter() {
+		return true;
+	}
+
+	@Override public Object run() {
+		long trace = this.tracer.getCurrentSpan().getTraceId();
+		Integer integer = this.counter.getOrDefault(trace, 0);
+		counter.put(trace, integer + 1);
+		return null;
+	}
+}