Introduce SpanContext as internal detail of SpanContextHolder

The fact that a Span was active when a new one is created needs
to be recorded, but it doesn't seem to belong in the Span. However
the DefaultTracer can call other methods on the SpanContextHolder
and that's what this change does (with package private methods).

There are still some usages of the public methods in
SpanContextHolder which I'd like to stamp out as a separate issue.

Fixes gh-141
This commit is contained in:
Dave Syer
2016-02-04 12:30:25 +00:00
parent e819881be8
commit 7f012ac02c
8 changed files with 102 additions and 85 deletions

View File

@@ -16,11 +16,12 @@
package org.springframework.cloud.sleuth.instrument;
import lombok.Getter;
import org.springframework.cloud.sleuth.Span;
import org.springframework.cloud.sleuth.Tracer;
import org.springframework.cloud.sleuth.trace.SpanContextHolder;
import lombok.Getter;
/**
* @author Spencer Gibb
*/
@@ -49,9 +50,6 @@ public abstract class TraceDelegate<T> {
protected void closeAll(Span span) {
span = this.tracer.close(span);
while (span != null) {
span = this.tracer.detach(span);
}
}
protected Span startSpan() {

View File

@@ -16,13 +16,12 @@
package org.springframework.cloud.sleuth.instrument.hystrix;
import com.netflix.hystrix.HystrixCommand;
import com.netflix.hystrix.HystrixCommandGroupKey;
import com.netflix.hystrix.HystrixThreadPoolKey;
import org.springframework.cloud.sleuth.Span;
import org.springframework.cloud.sleuth.Tracer;
import org.springframework.cloud.sleuth.trace.SpanContextHolder;
import com.netflix.hystrix.HystrixCommand;
/**
* Abstraction over {@code HystrixCommand} that wraps command execution with Trace setting
*
@@ -38,30 +37,6 @@ public abstract class TraceCommand<R> extends HystrixCommand<R> {
private final Tracer tracer;
private final Span parentSpan;
protected TraceCommand(Tracer tracer, HystrixCommandGroupKey group) {
super(group);
this.tracer = tracer;
this.parentSpan = tracer.getCurrentSpan();
}
protected TraceCommand(Tracer tracer, HystrixCommandGroupKey group, HystrixThreadPoolKey threadPool) {
super(group, threadPool);
this.tracer = tracer;
this.parentSpan = tracer.getCurrentSpan();
}
protected TraceCommand(Tracer tracer, HystrixCommandGroupKey group, int executionIsolationThreadTimeoutInMilliseconds) {
super(group, executionIsolationThreadTimeoutInMilliseconds);
this.tracer = tracer;
this.parentSpan = tracer.getCurrentSpan();
}
protected TraceCommand(Tracer tracer, HystrixCommandGroupKey group, HystrixThreadPoolKey threadPool, int executionIsolationThreadTimeoutInMilliseconds) {
super(group, threadPool, executionIsolationThreadTimeoutInMilliseconds);
this.tracer = tracer;
this.parentSpan = tracer.getCurrentSpan();
}
protected TraceCommand(Tracer tracer, Setter setter) {
super(setter);
this.tracer = tracer;
@@ -74,7 +49,8 @@ public abstract class TraceCommand<R> extends HystrixCommand<R> {
Span span = this.tracer.joinTrace(getCommandKey().name(), this.parentSpan);
try {
return doRun();
} finally {
}
finally {
this.tracer.close(span);
}
}

View File

@@ -105,8 +105,9 @@ public class TraceFilter extends OncePerRequestFilter
protected void doFilterInternal(HttpServletRequest request,
HttpServletResponse response, FilterChain filterChain)
throws ServletException, IOException {
SpanContextHolder.removeCurrentSpan();
// TODO: this should not be necessary
SpanContextHolder.removeCurrentSpan();
String uri = this.urlPathHelper.getPathWithinApplication(request);
boolean skip = this.skipPattern.matcher(uri).matches()
|| getHeader(request, response, Span.NOT_SAMPLED_NAME) != null;
@@ -195,7 +196,7 @@ public class TraceFilter extends OncePerRequestFilter
spanFromRequest));
}
// Double close to clean up the parent (remote span as well)
this.tracer.close(this.tracer.close(spanFromRequest));
this.tracer.close(spanFromRequest);
}
}
}

View File

@@ -16,8 +16,6 @@
package org.springframework.cloud.sleuth.trace;
import static org.springframework.cloud.sleuth.util.ExceptionUtils.warn;
import java.util.Random;
import java.util.concurrent.Callable;
@@ -55,11 +53,6 @@ public class DefaultTracer implements Tracer {
if (parent == null) {
return startTrace(name);
}
Span currentSpan = getCurrentSpan();
if (currentSpan != null && !parent.equals(currentSpan)) {
warn("Tried to start a new Span with parent " + parent
+ ", but there is already a " + "currentSpan " + currentSpan);
}
return continueSpan(createChild(parent, name));
}
@@ -100,12 +93,7 @@ public class DefaultTracer implements Tracer {
+ ". You may have forgotten to close or detach " + cur);
}
else {
if (span.hasSavedSpan()) {
SpanContextHolder.setCurrentSpan(span.getSavedSpan());
}
else {
SpanContextHolder.removeCurrentSpan();
}
SpanContextHolder.removeCurrentSpan();
}
return span.getSavedSpan();
}
@@ -126,14 +114,13 @@ public class DefaultTracer implements Tracer {
span.stop();
if (savedSpan != null && span.getParents().contains(savedSpan.getSpanId())) {
this.publisher.publishEvent(new SpanReleasedEvent(this, savedSpan, span));
SpanContextHolder.setCurrentSpan(savedSpan);
}
else {
if (!span.isRemote()) {
this.publisher.publishEvent(new SpanReleasedEvent(this, span));
}
SpanContextHolder.removeCurrentSpan();
}
SpanContextHolder.close();
}
return savedSpan;
}
@@ -148,13 +135,12 @@ public class DefaultTracer implements Tracer {
}
else {
if (SpanContextHolder.getCurrentSpan() == null) {
Span span = createSpan(parent, null);
SpanContextHolder.setCurrentSpan(span);
SpanContextHolder.push(parent, true);
}
Span span = Span.builder().begin(System.currentTimeMillis()).name(name)
.traceId(parent.getTraceId()).parent(parent.getSpanId()).spanId(id)
.processId(parent.getProcessId()).exportable(parent.isExportable())
.build();
.processId(parent.getProcessId()).savedSpan(parent)
.exportable(parent.isExportable()).build();
this.publisher.publishEvent(new SpanAcquiredEvent(this, parent, span));
return span;
}

View File

@@ -16,20 +16,22 @@
package org.springframework.cloud.sleuth.trace;
import lombok.extern.apachecommons.CommonsLog;
import org.springframework.cloud.sleuth.Span;
import org.springframework.core.NamedThreadLocal;
import lombok.extern.apachecommons.CommonsLog;
/**
* @author Spencer Gibb
*/
@CommonsLog
public class SpanContextHolder {
private static final ThreadLocal<Span> CURRENT_SPAN = new NamedThreadLocal<>("Trace Context");
private static final ThreadLocal<SpanContext> CURRENT_SPAN = new NamedThreadLocal<>(
"Trace Context");
public static Span getCurrentSpan() {
return isTracing() ? CURRENT_SPAN.get() : null;
return isTracing() ? CURRENT_SPAN.get().span : null;
}
public static void setCurrentSpan(Span span) {
@@ -41,7 +43,7 @@ public class SpanContextHolder {
if (log.isTraceEnabled()) {
log.trace("Setting current span " + span);
}
CURRENT_SPAN.set(span);
push(span, false);
}
public static void removeCurrentSpan() {
@@ -51,4 +53,47 @@ public class SpanContextHolder {
public static boolean isTracing() {
return CURRENT_SPAN.get() != null;
}
/**
* Close the current span and all parents that can be auto closed.
*/
static void close() {
SpanContext current = CURRENT_SPAN.get();
CURRENT_SPAN.remove();
while (current != null) {
current = current.parent;
if (current != null) {
if (!current.autoClose) {
CURRENT_SPAN.set(current);
current = null;
}
}
}
}
static void push(Span span, boolean autoClose) {
if (isCurrent(span)) {
return;
}
CURRENT_SPAN.set(new SpanContext(span, autoClose));
}
private static boolean isCurrent(Span span) {
if (span == null || CURRENT_SPAN.get() == null) {
return false;
}
return span.equals(CURRENT_SPAN.get().span);
}
private static class SpanContext {
Span span;
boolean autoClose;
SpanContext parent;
public SpanContext(Span span, boolean autoClose) {
this.span = span;
this.autoClose = autoClose;
this.parent = CURRENT_SPAN.get();
}
}
}

View File

@@ -20,8 +20,8 @@ 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.TraceRunnableTests;
import org.springframework.cloud.sleuth.template.TraceTemplateTests;
import org.springframework.cloud.sleuth.instrument.hystrix.SpanPassingForHystrixViaAnnotationsIntegrationTests;
import org.springframework.cloud.sleuth.instrument.hystrix.TraceCommandTests;
/**
* A test suite for probing weird ordering problems in the tests.
@@ -29,8 +29,8 @@ import org.springframework.cloud.sleuth.template.TraceTemplateTests;
* @author Dave Syer
*/
@RunWith(Suite.class)
@SuiteClasses({ TraceTemplateTests.class,
TraceRunnableTests.class })
@SuiteClasses({ SpanPassingForHystrixViaAnnotationsIntegrationTests.class,
TraceCommandTests.class })
@Ignore
public class AdhocTestSuite {

View File

@@ -1,7 +1,9 @@
package org.springframework.cloud.sleuth.instrument.hystrix;
import com.jayway.awaitility.Awaitility;
import com.netflix.hystrix.contrib.javanica.annotation.HystrixCommand;
import static org.springframework.cloud.sleuth.assertions.SleuthAssertions.then;
import java.util.concurrent.atomic.AtomicReference;
import org.junit.After;
import org.junit.Test;
import org.junit.runner.RunWith;
@@ -14,21 +16,27 @@ 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.context.junit4.SpringJUnit4ClassRunner;
import java.util.concurrent.atomic.AtomicReference;
import static org.springframework.cloud.sleuth.assertions.SleuthAssertions.then;
import com.jayway.awaitility.Awaitility;
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 {
@Autowired HystrixCommandInvocationSpanCatcher hystrixCommandInvocationSpanCatcher;
@Autowired
Tracer tracer;
@After
public void clean() {
SpanContextHolder.removeCurrentSpan();
}
@Test
public void should_set_span_on_an_hystrix_command_annotated_method() {
Span span = givenASpanInCurrentThread();

View File

@@ -1,7 +1,11 @@
package org.springframework.cloud.sleuth.instrument.hystrix;
import com.netflix.hystrix.HystrixCommandKey;
import com.netflix.hystrix.HystrixThreadPoolProperties;
import static com.netflix.hystrix.HystrixCommand.Setter.withGroupKey;
import static com.netflix.hystrix.HystrixCommandGroupKey.Factory.asKey;
import static org.assertj.core.api.BDDAssertions.then;
import java.util.Random;
import org.junit.After;
import org.junit.Before;
import org.junit.Test;
@@ -13,17 +17,14 @@ import org.springframework.cloud.sleuth.trace.DefaultTracer;
import org.springframework.cloud.sleuth.trace.SpanContextHolder;
import org.springframework.context.ApplicationEventPublisher;
import java.util.Random;
import static com.netflix.hystrix.HystrixCommand.Setter.withGroupKey;
import static com.netflix.hystrix.HystrixCommandGroupKey.Factory.asKey;
import static org.assertj.core.api.BDDAssertions.then;
import com.netflix.hystrix.HystrixCommandProperties;
import com.netflix.hystrix.HystrixThreadPoolProperties;
public class TraceCommandTests {
static final long EXPECTED_TRACE_ID = 1L;
Tracer tracer = new DefaultTracer(new AlwaysSampler(),
new Random(), Mockito.mock(ApplicationEventPublisher.class));
Tracer tracer = new DefaultTracer(new AlwaysSampler(), new Random(),
Mockito.mock(ApplicationEventPublisher.class));
@Before
public void setup() {
@@ -38,15 +39,14 @@ public class TraceCommandTests {
@Test
public void should_remove_span_from_thread_local_after_finishing_work()
throws Exception {
SpanContextHolder.removeCurrentSpan();
Span firstSpanFromHystrix = givenACommandWasExecuted(traceReturningCommand());
Span secondSpanFromHystrix = whenCommandIsExecuted(traceReturningCommand());
then(secondSpanFromHystrix.getTraceId()).as("second span id")
.isNotEqualTo(firstSpanFromHystrix.getTraceId()).as("first span id");
then(secondSpanFromHystrix.getSavedSpan()).as("saved span as remnant of first span")
.isNull();
then(secondSpanFromHystrix.getTraceId()).as("second trace id")
.isNotEqualTo(firstSpanFromHystrix.getTraceId()).as("first trace id");
then(secondSpanFromHystrix.getSavedSpan())
.as("saved span as remnant of first span").isNull();
}
@Test
@@ -66,14 +66,17 @@ public class TraceCommandTests {
}
private Span givenATraceIsPresentInTheCurrentThread() {
return this.tracer
.joinTrace("test", Span.builder().traceId(EXPECTED_TRACE_ID).build());
return this.tracer.joinTrace("test",
Span.builder().traceId(EXPECTED_TRACE_ID).build());
}
private TraceCommand<Span> traceReturningCommand() {
return new TraceCommand<Span>(this.tracer, withGroupKey(asKey(""))
.andCommandKey(HystrixCommandKey.Factory.asKey("")).andThreadPoolPropertiesDefaults(
HystrixThreadPoolProperties.Setter().withMaxQueueSize(1).withCoreSize(1))) {
return new TraceCommand<Span>(this.tracer,
withGroupKey(asKey("group"))
.andThreadPoolPropertiesDefaults(HystrixThreadPoolProperties
.Setter().withCoreSize(1).withMaxQueueSize(1))
.andCommandPropertiesDefaults(HystrixCommandProperties.Setter()
.withExecutionTimeoutEnabled(false))) {
@Override
public Span doRun() throws Exception {
return SpanContextHolder.getCurrentSpan();