From ad97be2fa6de9339050b1414977cf7d28d887e82 Mon Sep 17 00:00:00 2001 From: Dave Syer Date: Thu, 4 Feb 2016 16:41:41 +0000 Subject: [PATCH] Remove remaining public accesses of SpanContextHolder Hystrix is complex and the stacks get very deep. It turns out that it is also rather stateful, so order of tests affects the outcomes. Long story short: if you set the concurrency strategy it infects other tests (like the TraecCommandTests), which then have to assert slightly more carefully. --- .../sleuth/instrument/TraceCallable.java | 1 - .../sleuth/instrument/TraceDelegate.java | 4 -- .../sleuth/instrument/TraceRunnable.java | 1 - .../SleuthHystrixAutoConfiguration.java | 3 +- .../SleuthHystrixConcurrencyStrategy.java | 68 ++++++++++++++++--- .../instrument/hystrix/TraceCommand.java | 7 -- .../cloud/sleuth/trace/DefaultTracer.java | 2 + .../cloud/sleuth/AdhocTestSuite.java | 4 +- .../cloud/sleuth/assertions/SpanAssert.java | 23 +++++-- .../DefaultTestAutoConfiguration.java | 3 +- ...> HystrixAnnotationsIntegrationTests.java} | 46 +++++++------ .../instrument/hystrix/TraceCommandTests.java | 5 -- 12 files changed, 109 insertions(+), 58 deletions(-) rename spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/hystrix/{SpanPassingForHystrixViaAnnotationsIntegrationTests.java => HystrixAnnotationsIntegrationTests.java} (65%) diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/TraceCallable.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/TraceCallable.java index fc4efceed..90e27405a 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/TraceCallable.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/TraceCallable.java @@ -42,7 +42,6 @@ public class TraceCallable extends TraceDelegate> implements Call @Override public V call() throws Exception { - ensureThatThreadIsNotPollutedByPreviousTraces(); Span span = startSpan(); try { return this.getDelegate().call(); diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/TraceDelegate.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/TraceDelegate.java index 76e60bb32..2a38f52ee 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/TraceDelegate.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/TraceDelegate.java @@ -18,7 +18,6 @@ package org.springframework.cloud.sleuth.instrument; import org.springframework.cloud.sleuth.Span; import org.springframework.cloud.sleuth.Tracer; -import org.springframework.cloud.sleuth.trace.SpanContextHolder; import lombok.Getter; @@ -56,7 +55,4 @@ public abstract class TraceDelegate { return this.name == null ? Thread.currentThread().getName() : this.name; } - protected void ensureThatThreadIsNotPollutedByPreviousTraces() { - SpanContextHolder.removeCurrentSpan(); - } } diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/TraceRunnable.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/TraceRunnable.java index e40e5dda1..08f384b3f 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/TraceRunnable.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/TraceRunnable.java @@ -39,7 +39,6 @@ public class TraceRunnable extends TraceDelegate implements Runnable { @Override public void run() { - ensureThatThreadIsNotPollutedByPreviousTraces(); Span span = startSpan(); try { this.getDelegate().run(); diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/hystrix/SleuthHystrixAutoConfiguration.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/hystrix/SleuthHystrixAutoConfiguration.java index 13a073a3b..4017f602f 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/hystrix/SleuthHystrixAutoConfiguration.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/hystrix/SleuthHystrixAutoConfiguration.java @@ -13,7 +13,8 @@ import com.netflix.hystrix.HystrixCommand; @ConditionalOnProperty(value = "spring.sleuth.hystrix.strategy.enabled", matchIfMissing = true) public class SleuthHystrixAutoConfiguration { - @Bean SleuthHystrixConcurrencyStrategy sleuthHystrixConcurrencyStrategy(Tracer tracer) { + @Bean + SleuthHystrixConcurrencyStrategy sleuthHystrixConcurrencyStrategy(Tracer tracer) { return new SleuthHystrixConcurrencyStrategy(tracer); } } diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/hystrix/SleuthHystrixConcurrencyStrategy.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/hystrix/SleuthHystrixConcurrencyStrategy.java index f6e07a736..91acd1732 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/hystrix/SleuthHystrixConcurrencyStrategy.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/hystrix/SleuthHystrixConcurrencyStrategy.java @@ -1,12 +1,16 @@ package org.springframework.cloud.sleuth.instrument.hystrix; +import java.util.concurrent.Callable; + +import javax.annotation.PreDestroy; + +import org.springframework.cloud.sleuth.Span; +import org.springframework.cloud.sleuth.Tracer; + import com.netflix.hystrix.strategy.HystrixPlugins; import com.netflix.hystrix.strategy.concurrency.HystrixConcurrencyStrategy; -import lombok.extern.slf4j.Slf4j; -import org.springframework.cloud.sleuth.Tracer; -import org.springframework.cloud.sleuth.instrument.TraceCallable; -import java.util.concurrent.Callable; +import lombok.extern.slf4j.Slf4j; @Slf4j public class SleuthHystrixConcurrencyStrategy extends HystrixConcurrencyStrategy { @@ -17,14 +21,62 @@ public class SleuthHystrixConcurrencyStrategy extends HystrixConcurrencyStrategy this.tracer = tracer; try { HystrixPlugins.getInstance().registerConcurrencyStrategy(this); - } catch (Exception e) { - HystrixConcurrencyStrategy concurrencyStrategy = HystrixPlugins.getInstance().getConcurrencyStrategy(); - log.debug("Failed to register Sleuth Hystrix Concurrency Strategy. Will use the current one which is [" + concurrencyStrategy + "]", e); } + catch (Exception e) { + HystrixConcurrencyStrategy concurrencyStrategy = HystrixPlugins.getInstance() + .getConcurrencyStrategy(); + log.debug( + "Failed to register Sleuth Hystrix Concurrency Strategy. Will use the current one which is [" + + concurrencyStrategy + "]", + e); + } + } + + @PreDestroy + public void close() { + HystrixPlugins.reset(); } @Override public Callable wrapCallable(Callable callable) { - return new TraceCallable<>(this.tracer, callable); + return new HystrixTraceCallable(this.tracer, callable); + } + + private static class HystrixTraceCallable implements Callable { + + private Tracer tracer; + private Callable callable; + private Span parent; + + public HystrixTraceCallable(Tracer tracer, Callable callable) { + this.tracer = tracer; + this.callable = callable; + this.parent = tracer.getCurrentSpan(); + } + + @Override + public S call() throws Exception { + Span span = this.parent; + boolean created = false; + if (span != null) { + span = this.tracer.continueSpan(span); + } + else { + span = this.tracer.startTrace(Thread.currentThread().getName()); + created = true; + } + try { + return this.callable.call(); + } + finally { + if (created) { + this.tracer.close(span); + } + else { + this.tracer.detach(span); + } + } + } + } } diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/hystrix/TraceCommand.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/hystrix/TraceCommand.java index 531948a8b..d5339f18a 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/hystrix/TraceCommand.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/hystrix/TraceCommand.java @@ -18,7 +18,6 @@ package org.springframework.cloud.sleuth.instrument.hystrix; import org.springframework.cloud.sleuth.Span; import org.springframework.cloud.sleuth.Tracer; -import org.springframework.cloud.sleuth.trace.SpanContextHolder; import com.netflix.hystrix.HystrixCommand; @@ -45,7 +44,6 @@ public abstract class TraceCommand extends HystrixCommand { @Override protected R run() throws Exception { - enforceThatHystrixThreadIsNotPollutedByPreviousTraces(); Span span = this.tracer.joinTrace(getCommandKey().name(), this.parentSpan); try { return doRun(); @@ -55,10 +53,5 @@ public abstract class TraceCommand extends HystrixCommand { } } - // TODO: Do more analysis why this is not removed properly - private void enforceThatHystrixThreadIsNotPollutedByPreviousTraces() { - SpanContextHolder.removeCurrentSpan(); - } - public abstract R doRun() throws Exception; } diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/trace/DefaultTracer.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/trace/DefaultTracer.java index b679bf78c..88c0b65b1 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/trace/DefaultTracer.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/trace/DefaultTracer.java @@ -157,6 +157,8 @@ public class DefaultTracer implements Tracer { public Span continueSpan(Span span) { if (span != null) { this.publisher.publishEvent(new SpanContinuedEvent(this, span)); + } else { + return null; } Span newSpan = createSpan(span, SpanContextHolder.getCurrentSpan()); SpanContextHolder.setCurrentSpan(newSpan); diff --git a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/AdhocTestSuite.java b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/AdhocTestSuite.java index 73e52487b..fa2ed644e 100644 --- a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/AdhocTestSuite.java +++ b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/AdhocTestSuite.java @@ -20,7 +20,7 @@ import org.junit.Ignore; import org.junit.runner.RunWith; import org.junit.runners.Suite; import org.junit.runners.Suite.SuiteClasses; -import org.springframework.cloud.sleuth.instrument.hystrix.SpanPassingForHystrixViaAnnotationsIntegrationTests; +import org.springframework.cloud.sleuth.instrument.hystrix.HystrixAnnotationsIntegrationTests; import org.springframework.cloud.sleuth.instrument.hystrix.TraceCommandTests; /** @@ -29,7 +29,7 @@ import org.springframework.cloud.sleuth.instrument.hystrix.TraceCommandTests; * @author Dave Syer */ @RunWith(Suite.class) -@SuiteClasses({ SpanPassingForHystrixViaAnnotationsIntegrationTests.class, +@SuiteClasses({ HystrixAnnotationsIntegrationTests.class, TraceCommandTests.class }) @Ignore public class AdhocTestSuite { diff --git a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/assertions/SpanAssert.java b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/assertions/SpanAssert.java index add1bdb64..11f1dd188 100644 --- a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/assertions/SpanAssert.java +++ b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/assertions/SpanAssert.java @@ -1,10 +1,11 @@ package org.springframework.cloud.sleuth.assertions; -import lombok.extern.slf4j.Slf4j; +import java.util.Objects; + import org.assertj.core.api.AbstractAssert; import org.springframework.cloud.sleuth.Span; -import java.util.Objects; +import lombok.extern.slf4j.Slf4j; @Slf4j public class SpanAssert extends AbstractAssert { @@ -19,8 +20,8 @@ public class SpanAssert extends AbstractAssert { public SpanAssert hasTraceIdEqualTo(long traceId) { isNotNull(); - if (!Objects.equals(actual.getTraceId(), traceId)) { - String message = String.format("Expected span's traceId to be <%s> but was <%s>", traceId, actual.getTraceId()); + if (!Objects.equals(this.actual.getTraceId(), traceId)) { + String message = String.format("Expected span's traceId to be <%s> but was <%s>", traceId, this.actual.getTraceId()); log.error(message); failWithMessage(message); } @@ -29,8 +30,18 @@ public class SpanAssert extends AbstractAssert { public SpanAssert hasNameNotEqualTo(String name) { isNotNull(); - if (Objects.equals(actual.getName(), name)) { - String message = String.format("Expected span's name not to be <%s> but was <%s>", name, actual.getName()); + if (Objects.equals(this.actual.getName(), name)) { + String message = String.format("Expected span's name not to be <%s> but was <%s>", name, this.actual.getName()); + log.error(message); + failWithMessage(message); + } + return this; + } + + public SpanAssert hasNameEqualTo(String name) { + isNotNull(); + if (!Objects.equals(this.actual.getName(), name)) { + String message = String.format("Expected span's name to be <%s> but it was <%s>", name, this.actual.getName()); log.error(message); failWithMessage(message); } diff --git a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/DefaultTestAutoConfiguration.java b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/DefaultTestAutoConfiguration.java index 07f8c8598..945e20e91 100644 --- a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/DefaultTestAutoConfiguration.java +++ b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/DefaultTestAutoConfiguration.java @@ -8,7 +8,6 @@ import java.lang.annotation.Target; import org.springframework.boot.autoconfigure.EnableAutoConfiguration; import org.springframework.boot.autoconfigure.jmx.JmxAutoConfiguration; import org.springframework.cloud.client.loadbalancer.LoadBalancerAutoConfiguration; -import org.springframework.cloud.netflix.archaius.ArchaiusAutoConfiguration; import org.springframework.cloud.sleuth.instrument.integration.TraceSpringIntegrationAutoConfiguration; import org.springframework.context.annotation.Configuration; import org.springframework.context.annotation.EnableAspectJAutoProxy; @@ -17,7 +16,7 @@ import org.springframework.context.annotation.EnableAspectJAutoProxy; @Retention(RetentionPolicy.RUNTIME) @EnableAutoConfiguration(exclude = { LoadBalancerAutoConfiguration.class, JmxAutoConfiguration.class, TraceSpringIntegrationAutoConfiguration.class, - ArchaiusAutoConfiguration.class, LoadBalancerAutoConfiguration.class }) + LoadBalancerAutoConfiguration.class }) @EnableAspectJAutoProxy(proxyTargetClass = true) @Configuration public @interface DefaultTestAutoConfiguration { diff --git a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/hystrix/SpanPassingForHystrixViaAnnotationsIntegrationTests.java b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/hystrix/HystrixAnnotationsIntegrationTests.java similarity index 65% rename from spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/hystrix/SpanPassingForHystrixViaAnnotationsIntegrationTests.java rename to spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/hystrix/HystrixAnnotationsIntegrationTests.java index 00008803c..de9e3dc9c 100644 --- a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/hystrix/SpanPassingForHystrixViaAnnotationsIntegrationTests.java +++ b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/hystrix/HystrixAnnotationsIntegrationTests.java @@ -1,5 +1,6 @@ package org.springframework.cloud.sleuth.instrument.hystrix; +import static org.assertj.core.api.BDDAssertions.then; import static org.springframework.cloud.sleuth.assertions.SleuthAssertions.then; import java.util.concurrent.atomic.AtomicReference; @@ -16,7 +17,7 @@ import org.springframework.cloud.sleuth.instrument.DefaultTestAutoConfiguration; import org.springframework.cloud.sleuth.trace.SpanContextHolder; import org.springframework.context.annotation.Bean; import org.springframework.context.annotation.Configuration; -import org.springframework.test.context.TestPropertySource; +import org.springframework.test.annotation.DirtiesContext; import org.springframework.test.context.junit4.SpringJUnit4ClassRunner; import com.jayway.awaitility.Awaitility; @@ -24,16 +25,17 @@ import com.netflix.hystrix.contrib.javanica.annotation.HystrixCommand; @RunWith(SpringJUnit4ClassRunner.class) @SpringApplicationConfiguration(classes = { - SpanPassingForHystrixViaAnnotationsIntegrationTests.TestConfig.class }) -@TestPropertySource(properties="hystrix.command.default.execution.isolation.thread.timeoutInMilliseconds=1000000") -public class SpanPassingForHystrixViaAnnotationsIntegrationTests { + HystrixAnnotationsIntegrationTests.TestConfig.class }) +@DirtiesContext +public class HystrixAnnotationsIntegrationTests { - @Autowired HystrixCommandInvocationSpanCatcher hystrixCommandInvocationSpanCatcher; + @Autowired + HystrixCommandInvocationSpanCatcher catcher; @Autowired Tracer tracer; @After - public void clean() { + public void cleanTrace() { SpanContextHolder.removeCurrentSpan(); } @@ -53,31 +55,31 @@ public class SpanPassingForHystrixViaAnnotationsIntegrationTests { } private void whenHystrixCommandAnnotatedMethodGetsExecuted() { - this.hystrixCommandInvocationSpanCatcher.invokeLogicWrappedInHystrixCommand(); + this.catcher.invokeLogicWrappedInHystrixCommand(); } private void thenTraceIdIsPassedFromTheCurrentThreadToTheHystrixOne(final Span span) { + then(span).isNotNull(); Awaitility.await().until(new Runnable() { @Override public void run() { + then(HystrixAnnotationsIntegrationTests.this.catcher).isNotNull(); then(span) - .hasTraceIdEqualTo(SpanPassingForHystrixViaAnnotationsIntegrationTests.this.hystrixCommandInvocationSpanCatcher.getTraceId()) - .hasNameNotEqualTo(SpanPassingForHystrixViaAnnotationsIntegrationTests.this.hystrixCommandInvocationSpanCatcher.getSpanName()); + .hasTraceIdEqualTo(HystrixAnnotationsIntegrationTests.this.catcher + .getTraceId()) + .hasNameEqualTo(HystrixAnnotationsIntegrationTests.this.catcher + .getSpanName()); } }); } - @After - public void cleanTrace() { - SpanContextHolder.removeCurrentSpan(); - } - @DefaultTestAutoConfiguration @EnableHystrix @Configuration static class TestConfig { - @Bean HystrixCommandInvocationSpanCatcher spanCatcher() { + @Bean + HystrixCommandInvocationSpanCatcher spanCatcher() { return new HystrixCommandInvocationSpanCatcher(); } @@ -89,21 +91,23 @@ public class SpanPassingForHystrixViaAnnotationsIntegrationTests { @HystrixCommand public void invokeLogicWrappedInHystrixCommand() { - this.spanCaughtFromHystrixThread = new AtomicReference<>(SpanContextHolder.getCurrentSpan()); + this.spanCaughtFromHystrixThread = new AtomicReference<>( + SpanContextHolder.getCurrentSpan()); } public Long getTraceId() { - if (this.spanCaughtFromHystrixThread == null || - this.spanCaughtFromHystrixThread.get() == null) { + if (this.spanCaughtFromHystrixThread == null + || this.spanCaughtFromHystrixThread.get() == null) { return null; } return this.spanCaughtFromHystrixThread.get().getTraceId(); } public String getSpanName() { - if (this.spanCaughtFromHystrixThread == null || - (this.spanCaughtFromHystrixThread.get() != null && - this.spanCaughtFromHystrixThread.get().getName() == null)) { + if (this.spanCaughtFromHystrixThread == null + || (this.spanCaughtFromHystrixThread.get() != null + && this.spanCaughtFromHystrixThread.get() + .getName() == null)) { return null; } return this.spanCaughtFromHystrixThread.get().getName(); diff --git a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/hystrix/TraceCommandTests.java b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/hystrix/TraceCommandTests.java index 59f48a1c4..299eba86e 100644 --- a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/hystrix/TraceCommandTests.java +++ b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/hystrix/TraceCommandTests.java @@ -60,11 +60,6 @@ public class TraceCommandTests { then(spanFromCommand.getTraceId()).isEqualTo(EXPECTED_TRACE_ID); } - @After - public void cleanUpTrace() { - SpanContextHolder.removeCurrentSpan(); - } - private Span givenATraceIsPresentInTheCurrentThread() { return this.tracer.joinTrace("test", Span.builder().traceId(EXPECTED_TRACE_ID).build());