SpringCloud/spring-cloud-sleuth
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

Continuation of async spans (#784)

Browse Source 
without this change, we always create a new span in TraceAsyncAspect. That's because the span created via LazyTraceExecutor (which is executed before the aspect), contains no useful information.
with this change we're renaming the LTE span in TraceAsyncAspect. We're using an InternalApi class that we kindly ask that nobody uses.

fixes #661 #783
This commit is contained in:
Marcin Grzejszczak
2017-11-17 12:35:59 +01:00
committed by GitHub
parent dd17b70ec7
commit a44bb54354
8 changed files with 101 additions and 10 deletions
Download Patch File Download Diff File Expand all files Collapse all files

14
spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/InternalApi.java Normal file
View File

@@ -0,0 +1,14 @@
package org.springframework.cloud.sleuth;
/**
* Internal API that can be changed any time so please do not use it!
*
* @author Marcin Grzejszczak
* @since 2.0.0
*/
public class InternalApi {
public static void renameSpan(Span span, String newName) {
span.name = newName;
}
}

2
spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/Span.java
View File

@@ -143,7 +143,7 @@ public class Span implements SpanContext {
private final long begin;
private long end = 0;
private final String name;
volatile String name;
private final long traceIdHigh;
private final long traceId;
private List<Long> parents = new ArrayList<>();

5
spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/async/AsyncDefaultAutoConfiguration.java
View File

@@ -24,6 +24,7 @@ import org.springframework.boot.autoconfigure.AutoConfigureAfter;
import org.springframework.boot.autoconfigure.condition.ConditionalOnBean;
import org.springframework.boot.autoconfigure.condition.ConditionalOnMissingBean;
import org.springframework.boot.autoconfigure.condition.ConditionalOnProperty;
import org.springframework.cloud.sleuth.SpanNamer;
import org.springframework.cloud.sleuth.TraceKeys;
import org.springframework.cloud.sleuth.Tracer;
import org.springframework.context.annotation.Bean;
@@ -65,8 +66,8 @@ public class AsyncDefaultAutoConfiguration {
}
@Bean
public TraceAsyncAspect traceAsyncAspect(Tracer tracer, TraceKeys traceKeys) {
return new TraceAsyncAspect(tracer, traceKeys, this.beanFactory);
public TraceAsyncAspect traceAsyncAspect(Tracer tracer, TraceKeys traceKeys, SpanNamer spanNamer) {
return new TraceAsyncAspect(tracer, traceKeys, spanNamer);
}
@Bean

34
spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/async/TraceAsyncAspect.java
View File

@@ -16,11 +16,14 @@
package org.springframework.cloud.sleuth.instrument.async;
import java.lang.reflect.Method;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.reflect.MethodSignature;
import org.springframework.beans.factory.BeanFactory;
import org.springframework.cloud.sleuth.InternalApi;
import org.springframework.cloud.sleuth.Span;
import org.springframework.cloud.sleuth.SpanNamer;
import org.springframework.cloud.sleuth.TraceKeys;
@@ -28,8 +31,6 @@ import org.springframework.cloud.sleuth.Tracer;
import org.springframework.cloud.sleuth.util.SpanNameUtil;
import org.springframework.util.ReflectionUtils;
import java.lang.reflect.Method;
/**
* Aspect that creates a new Span for running threads executing methods annotated with
* {@link org.springframework.scheduling.annotation.Async} annotation.
@@ -49,17 +50,26 @@ public class TraceAsyncAspect {
private final BeanFactory beanFactory;
private SpanNamer spanNamer;
@Deprecated
public TraceAsyncAspect(Tracer tracer, TraceKeys traceKeys, BeanFactory beanFactory) {
this.tracer = tracer;
this.traceKeys = traceKeys;
this.beanFactory = beanFactory;
}
public TraceAsyncAspect(Tracer tracer, TraceKeys traceKeys, SpanNamer spanNamer) {
this.tracer = tracer;
this.traceKeys = traceKeys;
this.spanNamer = spanNamer;
this.beanFactory = null;
}
@Around("execution (@org.springframework.scheduling.annotation.Async * *.*(..))")
public Object traceBackgroundThread(final ProceedingJoinPoint pjp) throws Throwable {
String spanName = spanNamer().name(getMethod(pjp, pjp.getTarget()),
SpanNameUtil.toLowerHyphen(pjp.getSignature().getName()));
Span span = this.tracer.createSpan(spanName);
Span span = span(spanName);
renameAsyncSpan(spanName, span);
this.tracer.addTag(Span.SPAN_LOCAL_COMPONENT_TAG_NAME, ASYNC_COMPONENT);
this.tracer.addTag(this.traceKeys.getAsync().getPrefix() +
this.traceKeys.getAsync().getClassNameKey(), pjp.getTarget().getClass().getSimpleName());
@@ -72,6 +82,22 @@ public class TraceAsyncAspect {
}
}
private void renameAsyncSpan(String spanName, Span span) {
// if there's a tag "lc" -> "async", that means the span came from
// a LazyTraceExecutor component that creates a span that contains very few
// information. If that's the case we want to rename it to have a different name
if (ASYNC_COMPONENT.equals(span.tags().get(Span.SPAN_LOCAL_COMPONENT_TAG_NAME))) {
InternalApi.renameSpan(span, spanName);
}
}
private Span span(String spanName) {
if (this.tracer.isTracing()) {
return this.tracer.getCurrentSpan();
}
return this.tracer.createSpan(spanName);
}
private Method getMethod(ProceedingJoinPoint pjp, Object object) {
MethodSignature signature = (MethodSignature) pjp.getSignature();
Method method = signature.getMethod();
@@ -80,7 +106,7 @@ public class TraceAsyncAspect {
}
SpanNamer spanNamer() {
if (this.spanNamer == null) {
if (this.spanNamer == null && this.beanFactory != null) {
this.spanNamer = this.beanFactory.getBean(SpanNamer.class);
}
return this.spanNamer;

19
spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/InternalApiTests.java Normal file
View File

@@ -0,0 +1,19 @@
package org.springframework.cloud.sleuth;
import org.assertj.core.api.BDDAssertions;
import org.junit.Test;
/**
* @author Marcin Grzejszczak
*/
public class InternalApiTests {
@Test
public void should_rename_a_span() {
Span span = Span.builder().name("foo").build();
InternalApi.renameSpan(span, "bar");
BDDAssertions.then(span.getName()).isEqualTo("bar");
}
}

2
spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/async/ExecutorBeanPostProcessorTests.java
View File

@@ -7,7 +7,7 @@ import java.util.concurrent.ScheduledExecutorService;
import org.junit.Test;
import org.junit.runner.RunWith;
import org.mockito.Mock;
import org.mockito.runners.MockitoJUnitRunner;
import org.mockito.junit.MockitoJUnitRunner;
import org.springframework.aop.framework.AopConfigException;
import org.springframework.beans.factory.BeanFactory;
import org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor;

1
spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/reactor/SpanSubscriberTests.java
View File

@@ -69,7 +69,6 @@ public class SpanSubscriberTests {
then(ExceptionUtils.getLastException()).isNull();
}
@Ignore("Ignored until fixed in Reactor")
@Test public void should_support_reactor_fusion_optimization() {
Span span = this.tracer.createSpan("foo");
final AtomicReference<Span> spanInOperation = new AtomicReference<>();

34
spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/TraceAsyncIntegrationTests.java
View File

@@ -44,6 +44,20 @@ public class TraceAsyncIntegrationTests {
@Test
public void should_set_span_on_an_async_annotated_method() {
whenAsyncProcessingTakesPlace();
thenANewAsyncSpanGetsCreated();
}
@Test
public void should_set_span_with_custom_method_on_an_async_annotated_method() {
whenAsyncProcessingTakesPlaceWithCustomSpanName();
thenAsyncSpanHasCustomName();
}
@Test
public void should_continue_a_span_on_an_async_annotated_method() {
Span span = givenASpanInCurrentThread();
whenAsyncProcessingTakesPlace();
@@ -53,7 +67,7 @@ public class TraceAsyncIntegrationTests {
}
@Test
public void should_set_span_with_custom_method_on_an_async_annotated_method() {
public void should_continue_a_span_with_custom_method_on_an_async_annotated_method() {
Span span = givenASpanInCurrentThread();
whenAsyncProcessingTakesPlaceWithCustomSpanName();
@@ -78,6 +92,15 @@ public class TraceAsyncIntegrationTests {
Awaitility.await().atMost(5, SECONDS).untilAsserted(
() -> then(TraceAsyncIntegrationTests.this.classPerformingAsyncLogic.getSpan())
.hasTraceIdEqualTo(span.getTraceId())
.hasNameEqualTo("http:existing")
.isALocalComponentSpan()
.hasATag("class", "ClassPerformingAsyncLogic")
.hasATag("method", "invokeAsynchronousLogic"));
}
private void thenANewAsyncSpanGetsCreated() {
Awaitility.await().atMost(5, SECONDS).untilAsserted(
() -> then(TraceAsyncIntegrationTests.this.classPerformingAsyncLogic.getSpan())
.hasNameEqualTo("invoke-asynchronous-logic")
.isALocalComponentSpan()
.hasATag("class", "ClassPerformingAsyncLogic")
@@ -88,6 +111,15 @@ public class TraceAsyncIntegrationTests {
Awaitility.await().atMost(5, SECONDS).untilAsserted(
() -> then(TraceAsyncIntegrationTests.this.classPerformingAsyncLogic.getSpan())
.hasTraceIdEqualTo(span.getTraceId())
.hasNameEqualTo("http:existing")
.isALocalComponentSpan()
.hasATag("class", "ClassPerformingAsyncLogic")
.hasATag("method", "customNameInvokeAsynchronousLogic"));
}
private void thenAsyncSpanHasCustomName() {
Awaitility.await().atMost(5, SECONDS).untilAsserted(
() -> then(TraceAsyncIntegrationTests.this.classPerformingAsyncLogic.getSpan())
.hasNameEqualTo("foo")
.isALocalComponentSpan()
.hasATag("class", "ClassPerformingAsyncLogic")