From 6414de82d91d90848fc60048cfc5d22e4f9a1c23 Mon Sep 17 00:00:00 2001 From: Tyler Benson Date: Thu, 25 Apr 2019 10:24:13 -0700 Subject: [PATCH 1/4] Add support for HystrixObservableCommand This change is slightly breaking for existing hystrixCommand code since the resource name changes from run->execute and getFallback->fallback. The fallback span is also now a child of the execute span. --- .../trace/agent/tooling/Constants.java | 10 +- .../hystrix-1.4/hystrix-1.4.gradle | 1 + .../HystrixCommandInstrumentation.java | 70 ------ .../hystrix/HystrixDecorator.java | 6 +- .../hystrix/HystrixInstrumentation.java | 206 ++++++++++++++++++ .../src/main/java/rx/DDTracingUtil.java | 10 + .../groovy/HystrixObservableChainTest.groovy | 125 +++++++++++ .../test/groovy/HystrixObservableTest.groovy | 182 ++++++++++++++++ .../src/test/groovy/HystrixTest.groovy | 44 ++-- ...syncPropagatingDisableInstrumentation.java | 102 +++++++++ .../test/groovy/JBossClassloadingTest.groovy | 2 +- .../test/groovy/OSGIClassloadingTest.groovy | 2 +- .../datadog/trace/agent/test/SpockRunner.java | 8 +- 13 files changed, 663 insertions(+), 105 deletions(-) delete mode 100644 dd-java-agent/instrumentation/hystrix-1.4/src/main/java/datadog/trace/instrumentation/hystrix/HystrixCommandInstrumentation.java create mode 100644 dd-java-agent/instrumentation/hystrix-1.4/src/main/java/datadog/trace/instrumentation/hystrix/HystrixInstrumentation.java create mode 100644 dd-java-agent/instrumentation/hystrix-1.4/src/main/java/rx/DDTracingUtil.java create mode 100644 dd-java-agent/instrumentation/hystrix-1.4/src/test/groovy/HystrixObservableChainTest.groovy create mode 100644 dd-java-agent/instrumentation/hystrix-1.4/src/test/groovy/HystrixObservableTest.groovy create mode 100644 dd-java-agent/instrumentation/java-concurrent/src/main/java/datadog/trace/instrumentation/java/concurrent/AsyncPropagatingDisableInstrumentation.java diff --git a/dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/tooling/Constants.java b/dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/tooling/Constants.java index b1081c90f1..d92b11ad72 100644 --- a/dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/tooling/Constants.java +++ b/dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/tooling/Constants.java @@ -13,11 +13,11 @@ public final class Constants { *

Updates should be mirrored in TestUtils#BOOTSTRAP_PACKAGE_PREFIXES_COPY */ public static final String[] BOOTSTRAP_PACKAGE_PREFIXES = { - "io.opentracing", "datadog.slf4j", - "datadog.trace.bootstrap", "datadog.trace.api", - "datadog.trace.context" + "datadog.trace.bootstrap", + "datadog.trace.context", + "io.opentracing", }; // This is used in IntegrationTestUtils.java @@ -46,7 +46,9 @@ public final class Constants { "okio", "jnr", "org.objectweb.asm", - "com.kenai" + "com.kenai", + // Custom RxJava Utility + "rx.DDTracingUtil", }; private Constants() {} diff --git a/dd-java-agent/instrumentation/hystrix-1.4/hystrix-1.4.gradle b/dd-java-agent/instrumentation/hystrix-1.4/hystrix-1.4.gradle index dacf809375..faaca0f737 100644 --- a/dd-java-agent/instrumentation/hystrix-1.4/hystrix-1.4.gradle +++ b/dd-java-agent/instrumentation/hystrix-1.4/hystrix-1.4.gradle @@ -18,6 +18,7 @@ testSets { dependencies { compileOnly group: 'com.netflix.hystrix', name: 'hystrix-core', version: '1.4.0' + compileOnly group: 'io.reactivex', name: 'rxjava', version: '1.0.7' compile project(':dd-trace-ot') compile project(':dd-java-agent:agent-tooling') diff --git a/dd-java-agent/instrumentation/hystrix-1.4/src/main/java/datadog/trace/instrumentation/hystrix/HystrixCommandInstrumentation.java b/dd-java-agent/instrumentation/hystrix-1.4/src/main/java/datadog/trace/instrumentation/hystrix/HystrixCommandInstrumentation.java deleted file mode 100644 index d56c7af59c..0000000000 --- a/dd-java-agent/instrumentation/hystrix-1.4/src/main/java/datadog/trace/instrumentation/hystrix/HystrixCommandInstrumentation.java +++ /dev/null @@ -1,70 +0,0 @@ -package datadog.trace.instrumentation.hystrix; - -import static datadog.trace.agent.tooling.ByteBuddyElementMatchers.safeHasSuperType; -import static datadog.trace.instrumentation.hystrix.HystrixDecorator.DECORATE; -import static java.util.Collections.singletonMap; -import static net.bytebuddy.matcher.ElementMatchers.isInterface; -import static net.bytebuddy.matcher.ElementMatchers.isMethod; -import static net.bytebuddy.matcher.ElementMatchers.named; -import static net.bytebuddy.matcher.ElementMatchers.not; - -import com.google.auto.service.AutoService; -import com.netflix.hystrix.HystrixCommand; -import datadog.trace.agent.tooling.Instrumenter; -import io.opentracing.Scope; -import io.opentracing.util.GlobalTracer; -import java.util.Map; -import net.bytebuddy.asm.Advice; -import net.bytebuddy.description.method.MethodDescription; -import net.bytebuddy.description.type.TypeDescription; -import net.bytebuddy.matcher.ElementMatcher; - -@AutoService(Instrumenter.class) -public class HystrixCommandInstrumentation extends Instrumenter.Default { - - private static final String OPERATION_NAME = "hystrix.cmd"; - - public HystrixCommandInstrumentation() { - super("hystrix"); - } - - @Override - public ElementMatcher typeMatcher() { - return not(isInterface()).and(safeHasSuperType(named("com.netflix.hystrix.HystrixCommand"))); - } - - @Override - public String[] helperClassNames() { - return new String[] { - "datadog.trace.agent.decorator.BaseDecorator", packageName + ".HystrixDecorator", - }; - } - - @Override - public Map, String> transformers() { - return singletonMap( - isMethod().and(named("run").or(named("getFallback"))), TraceAdvice.class.getName()); - } - - public static class TraceAdvice { - - @Advice.OnMethodEnter(suppress = Throwable.class) - public static Scope startSpan( - @Advice.This final HystrixCommand command, - @Advice.Origin("#m") final String methodName) { - - final Scope scope = GlobalTracer.get().buildSpan(OPERATION_NAME).startActive(true); - DECORATE.afterStart(scope); - DECORATE.onCommand(scope, command, methodName); - return scope; - } - - @Advice.OnMethodExit(onThrowable = Throwable.class, suppress = Throwable.class) - public static void stopSpan( - @Advice.Enter final Scope scope, @Advice.Thrown final Throwable throwable) { - DECORATE.onError(scope, throwable); - DECORATE.beforeFinish(scope); - scope.close(); - } - } -} diff --git a/dd-java-agent/instrumentation/hystrix-1.4/src/main/java/datadog/trace/instrumentation/hystrix/HystrixDecorator.java b/dd-java-agent/instrumentation/hystrix-1.4/src/main/java/datadog/trace/instrumentation/hystrix/HystrixDecorator.java index d6203d512f..7ba2498d1d 100644 --- a/dd-java-agent/instrumentation/hystrix-1.4/src/main/java/datadog/trace/instrumentation/hystrix/HystrixDecorator.java +++ b/dd-java-agent/instrumentation/hystrix-1.4/src/main/java/datadog/trace/instrumentation/hystrix/HystrixDecorator.java @@ -1,9 +1,8 @@ package datadog.trace.instrumentation.hystrix; -import com.netflix.hystrix.HystrixCommand; +import com.netflix.hystrix.HystrixInvokableInfo; import datadog.trace.agent.decorator.BaseDecorator; import datadog.trace.api.DDTags; -import io.opentracing.Scope; import io.opentracing.Span; public class HystrixDecorator extends BaseDecorator { @@ -25,7 +24,7 @@ public class HystrixDecorator extends BaseDecorator { } public void onCommand( - final Scope scope, final HystrixCommand command, final String methodName) { + final Span span, final HystrixInvokableInfo command, final String methodName) { if (command != null) { final String commandName = command.getCommandKey().name(); final String groupName = command.getCommandGroup().name(); @@ -33,7 +32,6 @@ public class HystrixDecorator extends BaseDecorator { final String resourceName = groupName + "." + commandName + "." + methodName; - final Span span = scope.span(); span.setTag(DDTags.RESOURCE_NAME, resourceName); span.setTag("hystrix.command", commandName); span.setTag("hystrix.group", groupName); diff --git a/dd-java-agent/instrumentation/hystrix-1.4/src/main/java/datadog/trace/instrumentation/hystrix/HystrixInstrumentation.java b/dd-java-agent/instrumentation/hystrix-1.4/src/main/java/datadog/trace/instrumentation/hystrix/HystrixInstrumentation.java new file mode 100644 index 0000000000..51ef00d7e0 --- /dev/null +++ b/dd-java-agent/instrumentation/hystrix-1.4/src/main/java/datadog/trace/instrumentation/hystrix/HystrixInstrumentation.java @@ -0,0 +1,206 @@ +package datadog.trace.instrumentation.hystrix; + +import static datadog.trace.agent.tooling.ByteBuddyElementMatchers.safeHasSuperType; +import static datadog.trace.instrumentation.hystrix.HystrixDecorator.DECORATE; +import static net.bytebuddy.matcher.ElementMatchers.named; +import static net.bytebuddy.matcher.ElementMatchers.returns; + +import com.google.auto.service.AutoService; +import com.netflix.hystrix.HystrixInvokableInfo; +import datadog.trace.agent.tooling.Instrumenter; +import datadog.trace.context.TraceScope; +import io.opentracing.Scope; +import io.opentracing.ScopeManager; +import io.opentracing.Span; +import io.opentracing.Tracer; +import io.opentracing.util.GlobalTracer; +import java.util.HashMap; +import java.util.Map; +import net.bytebuddy.asm.Advice; +import net.bytebuddy.description.method.MethodDescription; +import net.bytebuddy.description.type.TypeDescription; +import net.bytebuddy.matcher.ElementMatcher; +import rx.DDTracingUtil; +import rx.Observable; +import rx.Subscriber; + +@AutoService(Instrumenter.class) +public class HystrixInstrumentation extends Instrumenter.Default { + + private static final String OPERATION_NAME = "hystrix.cmd"; + + public HystrixInstrumentation() { + super("hystrix"); + } + + @Override + public ElementMatcher typeMatcher() { + return safeHasSuperType( + named("com.netflix.hystrix.HystrixCommand") + .or(named("com.netflix.hystrix.HystrixObservableCommand"))); + } + + @Override + public String[] helperClassNames() { + return new String[] { + "rx.DDTracingUtil", + "datadog.trace.agent.decorator.BaseDecorator", + packageName + ".HystrixDecorator", + packageName + ".HystrixInstrumentation$TracedSubscriber", + packageName + ".HystrixInstrumentation$TracedOnSubscribe", + }; + } + + @Override + public Map, String> transformers() { + final Map, String> transformers = new HashMap<>(); + transformers.put( + named("getExecutionObservable").and(returns(named("rx.Observable"))), + ExecuteAdvice.class.getName()); + transformers.put( + named("getFallbackObservable").and(returns(named("rx.Observable"))), + FallbackAdvice.class.getName()); + return transformers; + } + + public static class ExecuteAdvice { + + @Advice.OnMethodExit(onThrowable = Throwable.class, suppress = Throwable.class) + public static void stopSpan( + @Advice.This final HystrixInvokableInfo command, + @Advice.Return(readOnly = false) Observable result, + @Advice.Thrown final Throwable throwable) { + final Observable.OnSubscribe onSubscribe = DDTracingUtil.extractOnSubscribe(result); + result = + Observable.create( + new TracedOnSubscribe( + onSubscribe, command, "execute", GlobalTracer.get().scopeManager().active())); + } + } + + public static class FallbackAdvice { + + @Advice.OnMethodExit(onThrowable = Throwable.class, suppress = Throwable.class) + public static void stopSpan( + @Advice.This final HystrixInvokableInfo command, + @Advice.Return(readOnly = false) Observable result, + @Advice.Thrown final Throwable throwable) { + final Observable.OnSubscribe onSubscribe = DDTracingUtil.extractOnSubscribe(result); + result = + Observable.create( + new TracedOnSubscribe( + onSubscribe, command, "fallback", GlobalTracer.get().scopeManager().active())); + } + } + + public static class TracedOnSubscribe implements Observable.OnSubscribe { + + private final Observable.OnSubscribe delegate; + private final HystrixInvokableInfo command; + private final String methodName; + private final TraceScope.Continuation continuation; + + public TracedOnSubscribe( + final Observable.OnSubscribe delegate, + final HystrixInvokableInfo command, + final String methodName, + final Scope parentScope) { + this.delegate = delegate; + this.command = command; + this.methodName = methodName; + continuation = + parentScope instanceof TraceScope ? ((TraceScope) parentScope).capture() : null; + } + + @Override + public void call(final Subscriber subscriber) { + final Tracer tracer = GlobalTracer.get(); + final Span span; // span finished by TracedSubscriber + if (continuation != null) { + try (final TraceScope scope = continuation.activate()) { + span = tracer.buildSpan(OPERATION_NAME).start(); + } + } else { + span = tracer.buildSpan(OPERATION_NAME).start(); + } + DECORATE.afterStart(span); + DECORATE.onCommand(span, command, methodName); + + try (final Scope scope = tracer.scopeManager().activate(span, false)) { + delegate.call(new TracedSubscriber(span, subscriber)); + } + } + } + + public static class TracedSubscriber extends Subscriber { + + private final ScopeManager scopeManager = GlobalTracer.get().scopeManager(); + private final Span span; + private final Subscriber delegate; + + public TracedSubscriber(final Span span, final Subscriber delegate) { + this.span = span; + this.delegate = delegate; + } + + @Override + public void onStart() { + try (final Scope scope = scopeManager.activate(span, false)) { + if (scope instanceof TraceScope) { + ((TraceScope) scope).setAsyncPropagation(true); + } + delegate.onStart(); + } + } + + @Override + public void onNext(final T value) { + try (final Scope scope = scopeManager.activate(span, false)) { + if (scope instanceof TraceScope) { + ((TraceScope) scope).setAsyncPropagation(true); + } + delegate.onNext(value); + } catch (final Throwable e) { + onError(e); + } + } + + @Override + public void onCompleted() { + boolean errored = false; + try (final Scope scope = scopeManager.activate(span, false)) { + if (scope instanceof TraceScope) { + ((TraceScope) scope).setAsyncPropagation(true); + } + delegate.onCompleted(); + } catch (final Throwable e) { + onError(e); + errored = true; + } finally { + // finish called by onError, so don't finish again. + if (!errored) { + DECORATE.beforeFinish(span); + span.finish(); + } + } + } + + @Override + public void onError(final Throwable e) { + try (final Scope scope = scopeManager.activate(span, false)) { + if (scope instanceof TraceScope) { + ((TraceScope) scope).setAsyncPropagation(true); + } + DECORATE.onError(span, e); + delegate.onError(e); + } catch (final Throwable e2) { + DECORATE.onError(span, e2); + // This recursive call might be dangerous... not sure what the best response is. + onError(e2); + } finally { + DECORATE.beforeFinish(span); + span.finish(); + } + } + } +} diff --git a/dd-java-agent/instrumentation/hystrix-1.4/src/main/java/rx/DDTracingUtil.java b/dd-java-agent/instrumentation/hystrix-1.4/src/main/java/rx/DDTracingUtil.java new file mode 100644 index 0000000000..a877d1385a --- /dev/null +++ b/dd-java-agent/instrumentation/hystrix-1.4/src/main/java/rx/DDTracingUtil.java @@ -0,0 +1,10 @@ +package rx; + +/** + * This class must be in the rx package in order to access the package accessible onSubscribe field. + */ +public class DDTracingUtil { + public static Observable.OnSubscribe extractOnSubscribe(final Observable observable) { + return observable.onSubscribe; + } +} diff --git a/dd-java-agent/instrumentation/hystrix-1.4/src/test/groovy/HystrixObservableChainTest.groovy b/dd-java-agent/instrumentation/hystrix-1.4/src/test/groovy/HystrixObservableChainTest.groovy new file mode 100644 index 0000000000..6d83b404b3 --- /dev/null +++ b/dd-java-agent/instrumentation/hystrix-1.4/src/test/groovy/HystrixObservableChainTest.groovy @@ -0,0 +1,125 @@ +import com.netflix.hystrix.HystrixObservableCommand +import datadog.trace.agent.test.AgentTestRunner +import datadog.trace.api.Trace +import io.opentracing.tag.Tags +import rx.Observable + +import static com.netflix.hystrix.HystrixCommandGroupKey.Factory.asKey +import static datadog.trace.agent.test.utils.TraceUtils.runUnderTrace + +class HystrixObservableChainTest extends AgentTestRunner { + // Uncomment for debugging: + // static { + // System.setProperty("hystrix.command.default.execution.timeout.enabled", "false") + // } + + def "test command #action"() { + setup: + def command = new HystrixObservableCommand(asKey("ExampleGroup")) { + @Trace + private String tracedMethod() { + return "Hello" + } + + @Override + protected Observable construct() { + Observable.defer { + Observable.just(tracedMethod()) + } + } + } + + def result = runUnderTrace("parent") { + command.toObservable().map { + it.toUpperCase() + }.flatMap { str -> + new HystrixObservableCommand(asKey("OtherGroup")) { + @Trace + private String tracedMethod() { + return "$str!" + } + + @Override + protected Observable construct() { + Observable.defer { + Observable.just(tracedMethod()) + } + } + }.toObservable() + }.toBlocking().first() + } + + expect: + result == "HELLO!" + + assertTraces(1) { + trace(0, 5) { + span(0) { + serviceName "unnamed-java-app" + operationName "parent" + resourceName "parent" + spanType null + parent() + errored false + tags { + defaultTags() + } + } + span(1) { + serviceName "unnamed-java-app" + operationName "hystrix.cmd" + resourceName "ExampleGroup.HystrixObservableChainTest\$1.execute" + spanType null + childOf span(0) + errored false + tags { + "hystrix.command" "HystrixObservableChainTest\$1" + "hystrix.group" "ExampleGroup" + "hystrix.circuit-open" false + "$Tags.COMPONENT.key" "hystrix" + defaultTags() + } + } + span(2) { + serviceName "unnamed-java-app" + operationName "hystrix.cmd" + resourceName "OtherGroup.HystrixObservableChainTest\$2.execute" + spanType null + childOf span(1) + errored false + tags { + "hystrix.command" "HystrixObservableChainTest\$2" + "hystrix.group" "OtherGroup" + "hystrix.circuit-open" false + "$Tags.COMPONENT.key" "hystrix" + defaultTags() + } + } + span(3) { + serviceName "unnamed-java-app" + operationName "HystrixObservableChainTest\$2.tracedMethod" + resourceName "HystrixObservableChainTest\$2.tracedMethod" + spanType null + childOf span(2) + errored false + tags { + "$Tags.COMPONENT.key" "trace" + defaultTags() + } + } + span(4) { + serviceName "unnamed-java-app" + operationName "HystrixObservableChainTest\$1.tracedMethod" + resourceName "HystrixObservableChainTest\$1.tracedMethod" + spanType null + childOf span(1) + errored false + tags { + "$Tags.COMPONENT.key" "trace" + defaultTags() + } + } + } + } + } +} diff --git a/dd-java-agent/instrumentation/hystrix-1.4/src/test/groovy/HystrixObservableTest.groovy b/dd-java-agent/instrumentation/hystrix-1.4/src/test/groovy/HystrixObservableTest.groovy new file mode 100644 index 0000000000..0d74ba1a1d --- /dev/null +++ b/dd-java-agent/instrumentation/hystrix-1.4/src/test/groovy/HystrixObservableTest.groovy @@ -0,0 +1,182 @@ +import com.netflix.hystrix.HystrixObservable +import com.netflix.hystrix.HystrixObservableCommand +import datadog.trace.agent.test.AgentTestRunner +import datadog.trace.api.Trace +import io.opentracing.tag.Tags +import rx.Observable + +import java.util.concurrent.BlockingQueue +import java.util.concurrent.LinkedBlockingQueue + +import static com.netflix.hystrix.HystrixCommandGroupKey.Factory.asKey +import static datadog.trace.agent.test.utils.TraceUtils.runUnderTrace + +class HystrixObservableTest extends AgentTestRunner { + // Uncomment for debugging: + // static { + // System.setProperty("hystrix.command.default.execution.timeout.enabled", "false") + // } + + def "test command #action"() { + setup: + def command = new HystrixObservableCommand(asKey("ExampleGroup")) { + @Trace + private String tracedMethod() { + return "Hello!" + } + + @Override + protected Observable construct() { + Observable.defer { + Observable.just(tracedMethod()) + } + } + } + + def result = runUnderTrace("parent") { + operation(command) + } + + expect: + TRANSFORMED_CLASSES.contains("HystrixObservableTest\$1") + result == "Hello!" + + assertTraces(1) { + trace(0, 3) { + span(0) { + serviceName "unnamed-java-app" + operationName "parent" + resourceName "parent" + spanType null + parent() + errored false + tags { + defaultTags() + } + } + span(1) { + serviceName "unnamed-java-app" + operationName "hystrix.cmd" + resourceName "ExampleGroup.HystrixObservableTest\$1.execute" + spanType null + childOf span(0) + errored false + tags { + "hystrix.command" "HystrixObservableTest\$1" + "hystrix.group" "ExampleGroup" + "hystrix.circuit-open" false + "$Tags.COMPONENT.key" "hystrix" + defaultTags() + } + } + span(2) { + serviceName "unnamed-java-app" + operationName "HystrixObservableTest\$1.tracedMethod" + resourceName "HystrixObservableTest\$1.tracedMethod" + spanType null + childOf span(1) + errored false + tags { + "$Tags.COMPONENT.key" "trace" + defaultTags() + } + } + } + } + + where: + action | operation + "toObservable" | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "observe" | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe block" | { HystrixObservable cmd -> + BlockingQueue queue = new LinkedBlockingQueue() + cmd.observe().subscribe { next -> + queue.put(next) + } + queue.take() + } + } + + def "test command #action fallback"() { + setup: + def command = new HystrixObservableCommand(asKey("ExampleGroup")) { + @Override + protected Observable construct() { + Observable.defer { + Observable.error(new IllegalArgumentException()) + } + } + + protected Observable resumeWithFallback() { + return Observable.just("Fallback!") + } + } + + def result = runUnderTrace("parent") { + operation(command) + } + + expect: + TRANSFORMED_CLASSES.contains("HystrixObservableTest\$2") + result == "Fallback!" + + assertTraces(1) { + trace(0, 3) { + span(0) { + serviceName "unnamed-java-app" + operationName "parent" + resourceName "parent" + spanType null + parent() + errored false + tags { + defaultTags() + } + } + span(1) { + serviceName "unnamed-java-app" + operationName "hystrix.cmd" + resourceName "ExampleGroup.HystrixObservableTest\$2.execute" + spanType null + childOf span(0) + errored true + tags { + "hystrix.command" "HystrixObservableTest\$2" + "hystrix.group" "ExampleGroup" + "hystrix.circuit-open" false + "$Tags.COMPONENT.key" "hystrix" + errorTags(IllegalArgumentException) + defaultTags() + } + } + span(2) { + serviceName "unnamed-java-app" + operationName "hystrix.cmd" + resourceName "ExampleGroup.HystrixObservableTest\$2.fallback" + spanType null + childOf span(1) + errored false + tags { + "hystrix.command" "HystrixObservableTest\$2" + "hystrix.group" "ExampleGroup" + "hystrix.circuit-open" false + "$Tags.COMPONENT.key" "hystrix" + defaultTags() + } + } + } + } + + where: + action | operation + "toObservable" | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "observe" | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe block" | { HystrixObservable cmd -> + BlockingQueue queue = new LinkedBlockingQueue() + cmd.observe().subscribe { next -> + queue.put(next) + } + queue.take() + } + } +} diff --git a/dd-java-agent/instrumentation/hystrix-1.4/src/test/groovy/HystrixTest.groovy b/dd-java-agent/instrumentation/hystrix-1.4/src/test/groovy/HystrixTest.groovy index 70c978da46..0154435319 100644 --- a/dd-java-agent/instrumentation/hystrix-1.4/src/test/groovy/HystrixTest.groovy +++ b/dd-java-agent/instrumentation/hystrix-1.4/src/test/groovy/HystrixTest.groovy @@ -17,9 +17,9 @@ class HystrixTest extends AgentTestRunner { def "test command #action"() { setup: - def command = new HystrixCommand(asKey("ExampleGroup")) { + def command = new HystrixCommand(asKey("ExampleGroup")) { @Override - protected Object run() throws Exception { + protected String run() throws Exception { return tracedMethod() } @@ -52,7 +52,7 @@ class HystrixTest extends AgentTestRunner { span(1) { serviceName "unnamed-java-app" operationName "hystrix.cmd" - resourceName "ExampleGroup.HystrixTest\$1.run" + resourceName "ExampleGroup.HystrixTest\$1.execute" spanType null childOf span(0) errored false @@ -83,6 +83,7 @@ class HystrixTest extends AgentTestRunner { action | operation "execute" | { HystrixCommand cmd -> cmd.execute() } "queue" | { HystrixCommand cmd -> cmd.queue().get() } + "toObservable" | { HystrixCommand cmd -> cmd.toObservable().toBlocking().first() } "observe" | { HystrixCommand cmd -> cmd.observe().toBlocking().first() } "observe block" | { HystrixCommand cmd -> BlockingQueue queue = new LinkedBlockingQueue() @@ -95,9 +96,9 @@ class HystrixTest extends AgentTestRunner { def "test command #action fallback"() { setup: - def command = new HystrixCommand(asKey("ExampleGroup")) { + def command = new HystrixCommand(asKey("ExampleGroup")) { @Override - protected Object run() throws Exception { + protected String run() throws Exception { throw new IllegalArgumentException() } @@ -129,22 +130,7 @@ class HystrixTest extends AgentTestRunner { span(1) { serviceName "unnamed-java-app" operationName "hystrix.cmd" - resourceName "ExampleGroup.HystrixTest\$2.getFallback" - spanType null - childOf span(0) - errored false - tags { - "hystrix.command" "HystrixTest\$2" - "hystrix.group" "ExampleGroup" - "hystrix.circuit-open" false - "$Tags.COMPONENT.key" "hystrix" - defaultTags() - } - } - span(2) { - serviceName "unnamed-java-app" - operationName "hystrix.cmd" - resourceName "ExampleGroup.HystrixTest\$2.run" + resourceName "ExampleGroup.HystrixTest\$2.execute" spanType null childOf span(0) errored true @@ -157,6 +143,21 @@ class HystrixTest extends AgentTestRunner { defaultTags() } } + span(2) { + serviceName "unnamed-java-app" + operationName "hystrix.cmd" + resourceName "ExampleGroup.HystrixTest\$2.fallback" + spanType null + childOf span(1) + errored false + tags { + "hystrix.command" "HystrixTest\$2" + "hystrix.group" "ExampleGroup" + "hystrix.circuit-open" false + "$Tags.COMPONENT.key" "hystrix" + defaultTags() + } + } } } @@ -164,6 +165,7 @@ class HystrixTest extends AgentTestRunner { action | operation "execute" | { HystrixCommand cmd -> cmd.execute() } "queue" | { HystrixCommand cmd -> cmd.queue().get() } + "toObservable" | { HystrixCommand cmd -> cmd.toObservable().toBlocking().first() } "observe" | { HystrixCommand cmd -> cmd.observe().toBlocking().first() } "observe block" | { HystrixCommand cmd -> BlockingQueue queue = new LinkedBlockingQueue() diff --git a/dd-java-agent/instrumentation/java-concurrent/src/main/java/datadog/trace/instrumentation/java/concurrent/AsyncPropagatingDisableInstrumentation.java b/dd-java-agent/instrumentation/java-concurrent/src/main/java/datadog/trace/instrumentation/java/concurrent/AsyncPropagatingDisableInstrumentation.java new file mode 100644 index 0000000000..d446c34f4d --- /dev/null +++ b/dd-java-agent/instrumentation/java-concurrent/src/main/java/datadog/trace/instrumentation/java/concurrent/AsyncPropagatingDisableInstrumentation.java @@ -0,0 +1,102 @@ +package datadog.trace.instrumentation.java.concurrent; + +import static java.util.Collections.singletonMap; +import static net.bytebuddy.matcher.ElementMatchers.isConstructor; +import static net.bytebuddy.matcher.ElementMatchers.named; + +import com.google.auto.service.AutoService; +import com.google.common.collect.ImmutableMap; +import datadog.trace.agent.tooling.Instrumenter; +import datadog.trace.context.TraceScope; +import io.opentracing.Scope; +import io.opentracing.ScopeManager; +import io.opentracing.noop.NoopSpan; +import io.opentracing.util.GlobalTracer; +import java.util.Map; +import lombok.extern.slf4j.Slf4j; +import net.bytebuddy.agent.builder.AgentBuilder; +import net.bytebuddy.asm.Advice; +import net.bytebuddy.description.method.MethodDescription; +import net.bytebuddy.description.type.TypeDescription; +import net.bytebuddy.matcher.ElementMatcher; +import net.bytebuddy.matcher.ElementMatchers; + +/** + * Sometimes classes do lazy initialization for scheduling of tasks. If this is done during a trace + * it can cause the trace to never be reported. Add matchers below to disable async propagation + * during this period. + */ +@Slf4j +@AutoService(Instrumenter.class) +public final class AsyncPropagatingDisableInstrumentation implements Instrumenter { + + private static final Map< + ElementMatcher, ElementMatcher> + CLASS_AND_METHODS = + new ImmutableMap.Builder< + ElementMatcher, ElementMatcher>() + .put(named("rx.internal.util.ObjectPool"), isConstructor()) + .build(); + + @Override + public AgentBuilder instrument(AgentBuilder agentBuilder) { + + for (final Map.Entry, ElementMatcher> + entry : CLASS_AND_METHODS.entrySet()) { + agentBuilder = + new DisableAsyncInstrumentation(entry.getKey(), entry.getValue()) + .instrument(agentBuilder); + } + return agentBuilder; + } + + // Not Using AutoService to hook up this instrumentation + public static class DisableAsyncInstrumentation extends Default { + + private final ElementMatcher typeMatcher; + private final ElementMatcher methodMatcher; + + /** No-arg constructor only used by muzzle and tests. */ + public DisableAsyncInstrumentation() { + this(ElementMatchers.none(), ElementMatchers.none()); + } + + public DisableAsyncInstrumentation( + final ElementMatcher typeMatcher, + final ElementMatcher methodMatcher) { + super(AbstractExecutorInstrumentation.EXEC_NAME); + this.typeMatcher = typeMatcher; + this.methodMatcher = methodMatcher; + } + + @Override + public ElementMatcher typeMatcher() { + return typeMatcher; + } + + @Override + public Map, String> transformers() { + return singletonMap(methodMatcher, DisableAsyncAdvice.class.getName()); + } + } + + public static class DisableAsyncAdvice { + + @Advice.OnMethodEnter(suppress = Throwable.class) + public static Scope enter() { + final ScopeManager scopeManager = GlobalTracer.get().scopeManager(); + final Scope scope = scopeManager.active(); + if (scope instanceof TraceScope && ((TraceScope) scope).isAsyncPropagating()) { + return scopeManager.activate(NoopSpan.INSTANCE, false); + } + return null; + } + + @Advice.OnMethodExit(suppress = Throwable.class) + public static void exit(@Advice.Enter final Scope scope) { + if (scope != null) { + scope.close(); + } + } + } +} diff --git a/dd-java-agent/instrumentation/jboss-classloading/src/test/groovy/JBossClassloadingTest.groovy b/dd-java-agent/instrumentation/jboss-classloading/src/test/groovy/JBossClassloadingTest.groovy index 48960e4602..98db8b6420 100644 --- a/dd-java-agent/instrumentation/jboss-classloading/src/test/groovy/JBossClassloadingTest.groovy +++ b/dd-java-agent/instrumentation/jboss-classloading/src/test/groovy/JBossClassloadingTest.groovy @@ -6,6 +6,6 @@ class JBossClassloadingTest extends AgentTestRunner { org.jboss.modules.Module.getName() expect: - System.getProperty("jboss.modules.system.pkgs") == "io.opentracing,datadog.slf4j,datadog.trace.bootstrap,datadog.trace.api,datadog.trace.context" + System.getProperty("jboss.modules.system.pkgs") == "datadog.slf4j,datadog.trace.api,datadog.trace.bootstrap,datadog.trace.context,io.opentracing" } } diff --git a/dd-java-agent/instrumentation/osgi-classloading/src/test/groovy/OSGIClassloadingTest.groovy b/dd-java-agent/instrumentation/osgi-classloading/src/test/groovy/OSGIClassloadingTest.groovy index 37cf7a4ec9..6ca92d074f 100644 --- a/dd-java-agent/instrumentation/osgi-classloading/src/test/groovy/OSGIClassloadingTest.groovy +++ b/dd-java-agent/instrumentation/osgi-classloading/src/test/groovy/OSGIClassloadingTest.groovy @@ -15,7 +15,7 @@ class OSGIClassloadingTest extends AgentTestRunner { org.osgi.framework.Bundle.getName() then: - System.getProperty("org.osgi.framework.bootdelegation") == "io.opentracing.*,io.opentracing,datadog.slf4j.*,datadog.slf4j,datadog.trace.bootstrap.*,datadog.trace.bootstrap,datadog.trace.api.*,datadog.trace.api,datadog.trace.context.*,datadog.trace.context" + System.getProperty("org.osgi.framework.bootdelegation") == "datadog.slf4j.*,datadog.slf4j,datadog.trace.api.*,datadog.trace.api,datadog.trace.bootstrap.*,datadog.trace.bootstrap,datadog.trace.context.*,datadog.trace.context,io.opentracing.*,io.opentracing" } def "test Eclipse OSGi framework factory"() { diff --git a/dd-java-agent/testing/src/main/groovy/datadog/trace/agent/test/SpockRunner.java b/dd-java-agent/testing/src/main/groovy/datadog/trace/agent/test/SpockRunner.java index 149eb386c9..f803323c85 100644 --- a/dd-java-agent/testing/src/main/groovy/datadog/trace/agent/test/SpockRunner.java +++ b/dd-java-agent/testing/src/main/groovy/datadog/trace/agent/test/SpockRunner.java @@ -25,17 +25,17 @@ import org.spockframework.runtime.Sputnik; */ public class SpockRunner extends Sputnik { /** - * An exact copy of Utils#BOOSTRAP_PACKAGE_PREFIXES. + * An exact copy of {@link datadog.trace.agent.tooling.Constants#BOOTSTRAP_PACKAGE_PREFIXES}. * *

This list is needed to initialize the bootstrap classpath because Utils' static initializer * references bootstrap classes (e.g. DatadogClassLoader). */ public static final String[] BOOTSTRAP_PACKAGE_PREFIXES_COPY = { - "io.opentracing", "datadog.slf4j", - "datadog.trace.bootstrap", "datadog.trace.api", - "datadog.trace.context" + "datadog.trace.bootstrap", + "datadog.trace.context", + "io.opentracing", }; private static final String[] TEST_BOOTSTRAP_PREFIXES; From 54287fa54816a666a4107b7af2a378d469e6f79c Mon Sep 17 00:00:00 2001 From: Tyler Benson Date: Mon, 29 Apr 2019 12:08:49 -0700 Subject: [PATCH 2/4] Add comment and consistency. --- .../datadog/trace/agent/decorator/HttpClientDecorator.java | 1 + .../datadog/trace/agent/decorator/HttpServerDecorator.java | 4 +++- 2 files changed, 4 insertions(+), 1 deletion(-) diff --git a/dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/decorator/HttpClientDecorator.java b/dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/decorator/HttpClientDecorator.java index 09dc011a8e..a57e6ccb99 100644 --- a/dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/decorator/HttpClientDecorator.java +++ b/dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/decorator/HttpClientDecorator.java @@ -68,6 +68,7 @@ public abstract class HttpClientDecorator extends ClientDecor Tags.PEER_HOSTNAME.set(span, hostname(request)); final Integer port = port(request); + // Negative or Zero ports might represent an unset/null value for an int type. Skip setting. Tags.PEER_PORT.set(span, port != null && port > 0 ? port : null); if (Config.get().isHttpClientSplitByDomain()) { diff --git a/dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/decorator/HttpServerDecorator.java b/dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/decorator/HttpServerDecorator.java index 9fd2b0563c..5e89056af4 100644 --- a/dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/decorator/HttpServerDecorator.java +++ b/dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/decorator/HttpServerDecorator.java @@ -88,7 +88,9 @@ public abstract class HttpServerDecorator extends Tags.PEER_HOST_IPV6.set(span, ip); } } - Tags.PEER_PORT.set(span, peerPort(connection)); + final Integer port = peerPort(connection); + // Negative or Zero ports might represent an unset/null value for an int type. Skip setting. + Tags.PEER_PORT.set(span, port != null && port > 0 ? port : null); } return span; } From c971c434d148003804858241fba40acc741f9645 Mon Sep 17 00:00:00 2001 From: Tyler Benson Date: Mon, 29 Apr 2019 12:03:39 -0700 Subject: [PATCH 3/4] Fix propagation and add onUnsubscribe handler Ensures that span is closed when Observable is unsubscribed from. Also added retransform error logger since retransforms might be missed if an exception is thrown, leading to odd behavior. --- .../trace/agent/tooling/AgentInstaller.java | 32 +- .../hystrix/HystrixInstrumentation.java | 117 ++++++-- .../groovy/HystrixObservableChainTest.groovy | 113 ++++--- .../test/groovy/HystrixObservableTest.groovy | 280 +++++++++++++++--- .../src/test/groovy/HystrixTest.groovy | 13 +- ...syncPropagatingDisableInstrumentation.java | 18 +- .../trace/agent/test/AgentTestRunner.java | 10 + .../test/groovy/AgentTestRunnerTest.groovy | 22 ++ 8 files changed, 469 insertions(+), 136 deletions(-) diff --git a/dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/tooling/AgentInstaller.java b/dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/tooling/AgentInstaller.java index fa046dda0f..546fee5299 100644 --- a/dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/tooling/AgentInstaller.java +++ b/dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/tooling/AgentInstaller.java @@ -12,6 +12,7 @@ import static net.bytebuddy.matcher.ElementMatchers.not; import datadog.trace.api.Config; import datadog.trace.bootstrap.WeakMap; import java.lang.instrument.Instrumentation; +import java.util.Collections; import java.util.List; import java.util.Map; import java.util.ServiceLoader; @@ -60,9 +61,10 @@ public class AgentInstaller { new AgentBuilder.Default() .disableClassFormatChanges() .with(AgentBuilder.RedefinitionStrategy.RETRANSFORMATION) + .with(new RedefinitionLoggingListener()) .with(AgentBuilder.DescriptionStrategy.Default.POOL_ONLY) .with(POOL_STRATEGY) - .with(new LoggingListener()) + .with(new TransformLoggingListener()) .with(new ClassLoadListener()) .with(LOCATION_STRATEGY) // FIXME: we cannot enable it yet due to BB/JVM bug, see @@ -159,7 +161,33 @@ public class AgentInstaller { } @Slf4j - static class LoggingListener implements AgentBuilder.Listener { + static class RedefinitionLoggingListener implements AgentBuilder.RedefinitionStrategy.Listener { + + @Override + public void onBatch(final int index, final List> batch, final List> types) {} + + @Override + public Iterable>> onError( + final int index, + final List> batch, + final Throwable throwable, + final List> types) { + if (log.isDebugEnabled()) { + log.debug( + "Exception while retransforming " + batch.size() + " classes: " + batch, throwable); + } + return Collections.emptyList(); + } + + @Override + public void onComplete( + final int amount, + final List> types, + final Map>, Throwable> failures) {} + } + + @Slf4j + static class TransformLoggingListener implements AgentBuilder.Listener { @Override public void onError( diff --git a/dd-java-agent/instrumentation/hystrix-1.4/src/main/java/datadog/trace/instrumentation/hystrix/HystrixInstrumentation.java b/dd-java-agent/instrumentation/hystrix-1.4/src/main/java/datadog/trace/instrumentation/hystrix/HystrixInstrumentation.java index 51ef00d7e0..61cece5ecd 100644 --- a/dd-java-agent/instrumentation/hystrix-1.4/src/main/java/datadog/trace/instrumentation/hystrix/HystrixInstrumentation.java +++ b/dd-java-agent/instrumentation/hystrix-1.4/src/main/java/datadog/trace/instrumentation/hystrix/HystrixInstrumentation.java @@ -16,6 +16,7 @@ import io.opentracing.Tracer; import io.opentracing.util.GlobalTracer; import java.util.HashMap; import java.util.Map; +import java.util.concurrent.atomic.AtomicReference; import net.bytebuddy.asm.Advice; import net.bytebuddy.description.method.MethodDescription; import net.bytebuddy.description.type.TypeDescription; @@ -23,6 +24,7 @@ import net.bytebuddy.matcher.ElementMatcher; import rx.DDTracingUtil; import rx.Observable; import rx.Subscriber; +import rx.Subscription; @AutoService(Instrumenter.class) public class HystrixInstrumentation extends Instrumenter.Default { @@ -46,6 +48,7 @@ public class HystrixInstrumentation extends Instrumenter.Default { "rx.DDTracingUtil", "datadog.trace.agent.decorator.BaseDecorator", packageName + ".HystrixDecorator", + packageName + ".HystrixInstrumentation$SpanFinishingSubscription", packageName + ".HystrixInstrumentation$TracedSubscriber", packageName + ".HystrixInstrumentation$TracedOnSubscribe", }; @@ -127,6 +130,9 @@ public class HystrixInstrumentation extends Instrumenter.Default { DECORATE.onCommand(span, command, methodName); try (final Scope scope = tracer.scopeManager().activate(span, false)) { + if (!((TraceScope) scope).isAsyncPropagating()) { + ((TraceScope) scope).setAsyncPropagation(true); + } delegate.call(new TracedSubscriber(span, subscriber)); } } @@ -135,72 +141,119 @@ public class HystrixInstrumentation extends Instrumenter.Default { public static class TracedSubscriber extends Subscriber { private final ScopeManager scopeManager = GlobalTracer.get().scopeManager(); - private final Span span; + private final AtomicReference spanRef; private final Subscriber delegate; public TracedSubscriber(final Span span, final Subscriber delegate) { - this.span = span; + spanRef = new AtomicReference<>(span); this.delegate = delegate; + final SpanFinishingSubscription subscription = new SpanFinishingSubscription(spanRef); + delegate.add(subscription); } @Override public void onStart() { - try (final Scope scope = scopeManager.activate(span, false)) { - if (scope instanceof TraceScope) { - ((TraceScope) scope).setAsyncPropagation(true); + final Span span = spanRef.get(); + if (span != null) { + try (final Scope scope = scopeManager.activate(span, false)) { + if (scope instanceof TraceScope) { + ((TraceScope) scope).setAsyncPropagation(true); + } + delegate.onStart(); } + } else { delegate.onStart(); } } @Override public void onNext(final T value) { - try (final Scope scope = scopeManager.activate(span, false)) { - if (scope instanceof TraceScope) { - ((TraceScope) scope).setAsyncPropagation(true); + final Span span = spanRef.get(); + if (span != null) { + try (final Scope scope = scopeManager.activate(span, false)) { + if (scope instanceof TraceScope) { + ((TraceScope) scope).setAsyncPropagation(true); + } + delegate.onNext(value); + } catch (final Throwable e) { + onError(e); } + } else { delegate.onNext(value); - } catch (final Throwable e) { - onError(e); } } @Override public void onCompleted() { - boolean errored = false; - try (final Scope scope = scopeManager.activate(span, false)) { - if (scope instanceof TraceScope) { - ((TraceScope) scope).setAsyncPropagation(true); + final Span span = spanRef.getAndSet(null); + if (span != null) { + boolean errored = false; + try (final Scope scope = scopeManager.activate(span, false)) { + if (scope instanceof TraceScope) { + ((TraceScope) scope).setAsyncPropagation(true); + } + delegate.onCompleted(); + } catch (final Throwable e) { + // Repopulate the spanRef for onError + spanRef.compareAndSet(null, span); + onError(e); + errored = true; + } finally { + // finish called by onError, so don't finish again. + if (!errored) { + DECORATE.beforeFinish(span); + span.finish(); + } } + } else { delegate.onCompleted(); - } catch (final Throwable e) { - onError(e); - errored = true; - } finally { - // finish called by onError, so don't finish again. - if (!errored) { - DECORATE.beforeFinish(span); - span.finish(); - } } } @Override public void onError(final Throwable e) { - try (final Scope scope = scopeManager.activate(span, false)) { - if (scope instanceof TraceScope) { - ((TraceScope) scope).setAsyncPropagation(true); + final Span span = spanRef.getAndSet(null); + if (span != null) { + try (final Scope scope = scopeManager.activate(span, false)) { + if (scope instanceof TraceScope) { + ((TraceScope) scope).setAsyncPropagation(true); + } + DECORATE.onError(span, e); + delegate.onError(e); + } catch (final Throwable e2) { + DECORATE.onError(span, e2); + // This recursive call might be dangerous... not sure what the best response is. + onError(e2); + } finally { + DECORATE.beforeFinish(span); + span.finish(); } - DECORATE.onError(span, e); + } else { delegate.onError(e); - } catch (final Throwable e2) { - DECORATE.onError(span, e2); - // This recursive call might be dangerous... not sure what the best response is. - onError(e2); - } finally { + } + } + } + + public static class SpanFinishingSubscription implements Subscription { + + private final AtomicReference spanRef; + + public SpanFinishingSubscription(final AtomicReference spanRef) { + this.spanRef = spanRef; + } + + @Override + public void unsubscribe() { + final Span span = spanRef.getAndSet(null); + if (span != null) { DECORATE.beforeFinish(span); span.finish(); } } + + @Override + public boolean isUnsubscribed() { + return spanRef.get() == null; + } } } diff --git a/dd-java-agent/instrumentation/hystrix-1.4/src/test/groovy/HystrixObservableChainTest.groovy b/dd-java-agent/instrumentation/hystrix-1.4/src/test/groovy/HystrixObservableChainTest.groovy index 6d83b404b3..6cdf7f448b 100644 --- a/dd-java-agent/instrumentation/hystrix-1.4/src/test/groovy/HystrixObservableChainTest.groovy +++ b/dd-java-agent/instrumentation/hystrix-1.4/src/test/groovy/HystrixObservableChainTest.groovy @@ -3,39 +3,50 @@ import datadog.trace.agent.test.AgentTestRunner import datadog.trace.api.Trace import io.opentracing.tag.Tags import rx.Observable +import rx.schedulers.Schedulers +import spock.lang.Retry +import spock.lang.Timeout import static com.netflix.hystrix.HystrixCommandGroupKey.Factory.asKey import static datadog.trace.agent.test.utils.TraceUtils.runUnderTrace +@Retry +@Timeout(5) class HystrixObservableChainTest extends AgentTestRunner { - // Uncomment for debugging: - // static { - // System.setProperty("hystrix.command.default.execution.timeout.enabled", "false") - // } + static { + // Disable so failure testing below doesn't inadvertently change the behavior. + System.setProperty("hystrix.command.default.circuitBreaker.enabled", "false") + + // Uncomment for debugging: + // System.setProperty("hystrix.command.default.execution.timeout.enabled", "false") + } def "test command #action"() { setup: - def command = new HystrixObservableCommand(asKey("ExampleGroup")) { - @Trace - private String tracedMethod() { - return "Hello" - } - - @Override - protected Observable construct() { - Observable.defer { - Observable.just(tracedMethod()) - } - } - } def result = runUnderTrace("parent") { - command.toObservable().map { - it.toUpperCase() - }.flatMap { str -> + def val = new HystrixObservableCommand(asKey("ExampleGroup")) { + @Trace + private String tracedMethod() { + return "Hello" + } + + @Override + protected Observable construct() { + Observable.defer { + Observable.just(tracedMethod()) + } + .subscribeOn(Schedulers.immediate()) + } + }.toObservable() + .subscribeOn(Schedulers.io()) + .map { + it.toUpperCase() + }.flatMap { str -> new HystrixObservableCommand(asKey("OtherGroup")) { @Trace private String tracedMethod() { + blockUntilChildSpansFinished(2) return "$str!" } @@ -44,9 +55,15 @@ class HystrixObservableChainTest extends AgentTestRunner { Observable.defer { Observable.just(tracedMethod()) } + .subscribeOn(Schedulers.computation()) } }.toObservable() + .subscribeOn(Schedulers.trampoline()) }.toBlocking().first() + // when this is running in different threads, we don't know when the other span is done + // adding sleep to improve ordering consistency + blockUntilChildSpansFinished(4) + return val } expect: @@ -66,6 +83,33 @@ class HystrixObservableChainTest extends AgentTestRunner { } } span(1) { + serviceName "unnamed-java-app" + operationName "hystrix.cmd" + resourceName "OtherGroup.HystrixObservableChainTest\$2.execute" + spanType null + childOf span(3) + errored false + tags { + "hystrix.command" "HystrixObservableChainTest\$2" + "hystrix.group" "OtherGroup" + "hystrix.circuit-open" false + "$Tags.COMPONENT.key" "hystrix" + defaultTags() + } + } + span(2) { + serviceName "unnamed-java-app" + operationName "HystrixObservableChainTest\$2.tracedMethod" + resourceName "HystrixObservableChainTest\$2.tracedMethod" + spanType null + childOf span(1) + errored false + tags { + "$Tags.COMPONENT.key" "trace" + defaultTags() + } + } + span(3) { serviceName "unnamed-java-app" operationName "hystrix.cmd" resourceName "ExampleGroup.HystrixObservableChainTest\$1.execute" @@ -80,39 +124,12 @@ class HystrixObservableChainTest extends AgentTestRunner { defaultTags() } } - span(2) { - serviceName "unnamed-java-app" - operationName "hystrix.cmd" - resourceName "OtherGroup.HystrixObservableChainTest\$2.execute" - spanType null - childOf span(1) - errored false - tags { - "hystrix.command" "HystrixObservableChainTest\$2" - "hystrix.group" "OtherGroup" - "hystrix.circuit-open" false - "$Tags.COMPONENT.key" "hystrix" - defaultTags() - } - } - span(3) { - serviceName "unnamed-java-app" - operationName "HystrixObservableChainTest\$2.tracedMethod" - resourceName "HystrixObservableChainTest\$2.tracedMethod" - spanType null - childOf span(2) - errored false - tags { - "$Tags.COMPONENT.key" "trace" - defaultTags() - } - } span(4) { serviceName "unnamed-java-app" operationName "HystrixObservableChainTest\$1.tracedMethod" resourceName "HystrixObservableChainTest\$1.tracedMethod" spanType null - childOf span(1) + childOf span(3) errored false tags { "$Tags.COMPONENT.key" "trace" diff --git a/dd-java-agent/instrumentation/hystrix-1.4/src/test/groovy/HystrixObservableTest.groovy b/dd-java-agent/instrumentation/hystrix-1.4/src/test/groovy/HystrixObservableTest.groovy index 0d74ba1a1d..c3d094d274 100644 --- a/dd-java-agent/instrumentation/hystrix-1.4/src/test/groovy/HystrixObservableTest.groovy +++ b/dd-java-agent/instrumentation/hystrix-1.4/src/test/groovy/HystrixObservableTest.groovy @@ -1,9 +1,13 @@ import com.netflix.hystrix.HystrixObservable import com.netflix.hystrix.HystrixObservableCommand +import com.netflix.hystrix.exception.HystrixRuntimeException import datadog.trace.agent.test.AgentTestRunner import datadog.trace.api.Trace import io.opentracing.tag.Tags import rx.Observable +import rx.schedulers.Schedulers +import spock.lang.Retry +import spock.lang.Timeout import java.util.concurrent.BlockingQueue import java.util.concurrent.LinkedBlockingQueue @@ -11,30 +15,46 @@ import java.util.concurrent.LinkedBlockingQueue import static com.netflix.hystrix.HystrixCommandGroupKey.Factory.asKey import static datadog.trace.agent.test.utils.TraceUtils.runUnderTrace +@Retry +@Timeout(5) class HystrixObservableTest extends AgentTestRunner { - // Uncomment for debugging: - // static { - // System.setProperty("hystrix.command.default.execution.timeout.enabled", "false") - // } + static { + // Disable so failure testing below doesn't inadvertently change the behavior. + System.setProperty("hystrix.command.default.circuitBreaker.enabled", "false") + + // Uncomment for debugging: + // System.setProperty("hystrix.command.default.execution.timeout.enabled", "false") + } def "test command #action"() { setup: - def command = new HystrixObservableCommand(asKey("ExampleGroup")) { - @Trace - private String tracedMethod() { - return "Hello!" - } + def observeOnFn = observeOn + def subscribeOnFn = subscribeOn + def result = runUnderTrace("parent") { + def val = operation new HystrixObservableCommand(asKey("ExampleGroup")) { + @Trace + private String tracedMethod() { + return "Hello!" + } - @Override - protected Observable construct() { - Observable.defer { - Observable.just(tracedMethod()) + @Override + protected Observable construct() { + def obs = Observable.defer { + Observable.just(tracedMethod()).repeat(1) + } + if (observeOnFn) { + obs = obs.observeOn(observeOnFn) + } + if (subscribeOnFn) { + obs = obs.subscribeOn(subscribeOnFn) + } + return obs } } - } - - def result = runUnderTrace("parent") { - operation(command) + // when this is running in different threads, we don't know when the other span is done + // adding sleep to improve ordering consistency + blockUntilChildSpansFinished(2) + return val } expect: @@ -85,35 +105,66 @@ class HystrixObservableTest extends AgentTestRunner { } where: - action | operation - "toObservable" | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } - "observe" | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } - "observe block" | { HystrixObservable cmd -> + action | observeOn | subscribeOn | operation + "toObservable" | null | null | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable-I" | Schedulers.immediate() | null | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable-T" | Schedulers.trampoline() | null | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable-C" | Schedulers.computation() | null | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable-IO" | Schedulers.io() | null | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable-NT" | Schedulers.newThread() | null | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable+I" | null | Schedulers.immediate() | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable+T" | null | Schedulers.trampoline() | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable+C" | null | Schedulers.computation() | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable+IO" | null | Schedulers.io() | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable+NT" | null | Schedulers.newThread() | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "observe" | null | null | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe-I" | Schedulers.immediate() | null | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe-T" | Schedulers.trampoline() | null | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe-C" | Schedulers.computation() | null | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe-IO" | Schedulers.io() | null | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe-NT" | Schedulers.newThread() | null | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe+I" | null | Schedulers.immediate() | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe+T" | null | Schedulers.trampoline() | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe+C" | null | Schedulers.computation() | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe+IO" | null | Schedulers.io() | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe+NT" | null | Schedulers.newThread() | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "toObservable block" | Schedulers.computation() | Schedulers.newThread() | { HystrixObservable cmd -> BlockingQueue queue = new LinkedBlockingQueue() - cmd.observe().subscribe { next -> + def subscription = cmd.toObservable().subscribe { next -> queue.put(next) } - queue.take() + def val = queue.take() + subscription.unsubscribe() + return val } } def "test command #action fallback"() { setup: - def command = new HystrixObservableCommand(asKey("ExampleGroup")) { - @Override - protected Observable construct() { - Observable.defer { - Observable.error(new IllegalArgumentException()) + def observeOnFn = observeOn + def subscribeOnFn = subscribeOn + def result = runUnderTrace("parent") { + def val = operation new HystrixObservableCommand(asKey("ExampleGroup")) { + @Override + protected Observable construct() { + def err = Observable.defer { + Observable.error(new IllegalArgumentException()).repeat(1) + } + if (observeOnFn) { + err = err.observeOn(observeOnFn) + } + if (subscribeOnFn) { + err = err.subscribeOn(subscribeOnFn) + } + return err + } + + protected Observable resumeWithFallback() { + return Observable.just("Fallback!").repeat(1) } } - - protected Observable resumeWithFallback() { - return Observable.just("Fallback!") - } - } - - def result = runUnderTrace("parent") { - operation(command) + blockUntilChildSpansFinished(2) // Improve span ordering consistency + return val } expect: @@ -168,15 +219,160 @@ class HystrixObservableTest extends AgentTestRunner { } where: - action | operation - "toObservable" | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } - "observe" | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } - "observe block" | { HystrixObservable cmd -> + action | observeOn | subscribeOn | operation + "toObservable" | null | null | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable-I" | Schedulers.immediate() | null | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable-T" | Schedulers.trampoline() | null | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable-C" | Schedulers.computation() | null | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable-IO" | Schedulers.io() | null | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable-NT" | Schedulers.newThread() | null | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable+I" | null | Schedulers.immediate() | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable+T" | null | Schedulers.trampoline() | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable+C" | null | Schedulers.computation() | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable+IO" | null | Schedulers.io() | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable+NT" | null | Schedulers.newThread() | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "observe" | null | null | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe-I" | Schedulers.immediate() | null | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe-T" | Schedulers.trampoline() | null | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe-C" | Schedulers.computation() | null | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe-IO" | Schedulers.io() | null | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe-NT" | Schedulers.newThread() | null | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe+I" | null | Schedulers.immediate() | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe+T" | null | Schedulers.trampoline() | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe+C" | null | Schedulers.computation() | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe+IO" | null | Schedulers.io() | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe+NT" | null | Schedulers.newThread() | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "toObservable block" | null | null | { HystrixObservable cmd -> BlockingQueue queue = new LinkedBlockingQueue() - cmd.observe().subscribe { next -> + def subscription = cmd.toObservable().subscribe { next -> queue.put(next) } - queue.take() + def val = queue.take() + subscription.unsubscribe() + return val + } + } + + def "test no fallback results in error for #action"() { + setup: + def observeOnFn = observeOn + def subscribeOnFn = subscribeOn + + when: + runUnderTrace("parent") { + try { + operation new HystrixObservableCommand(asKey("FailingGroup")) { + + @Override + protected Observable construct() { + def err = Observable.defer { + Observable.error(new IllegalArgumentException()) + } + if (observeOnFn) { + err = err.observeOn(observeOnFn) + } + if (subscribeOnFn) { + err = err.subscribeOn(subscribeOnFn) + } + return err + } + } + } finally { + // when this is running in different threads, we don't know when the other span is done + // adding sleep to improve ordering consistency + // Also an exception is being thrown here, so we need to wrap it in a try block. + blockUntilChildSpansFinished(2) + } + } + + then: + TRANSFORMED_CLASSES.contains("HystrixObservableTest\$3") + def err = thrown HystrixRuntimeException + err.cause instanceof IllegalArgumentException + + assertTraces(1) { + trace(0, 3) { + span(0) { + serviceName "unnamed-java-app" + operationName "parent" + resourceName "parent" + spanType null + parent() + errored true + tags { + errorTags(HystrixRuntimeException, "HystrixObservableTest\$3 failed and no fallback available.") + defaultTags() + } + } + span(1) { + serviceName "unnamed-java-app" + operationName "hystrix.cmd" + resourceName "FailingGroup.HystrixObservableTest\$3.execute" + spanType null + childOf span(0) + errored true + tags { + "hystrix.command" "HystrixObservableTest\$3" + "hystrix.group" "FailingGroup" + "hystrix.circuit-open" false + "$Tags.COMPONENT.key" "hystrix" + errorTags(IllegalArgumentException) + defaultTags() + } + } + span(2) { + serviceName "unnamed-java-app" + operationName "hystrix.cmd" + resourceName "FailingGroup.HystrixObservableTest\$3.fallback" + spanType null + childOf span(1) + errored true + tags { + "hystrix.command" "HystrixObservableTest\$3" + "hystrix.group" "FailingGroup" + "hystrix.circuit-open" false + "$Tags.COMPONENT.key" "hystrix" + errorTags(UnsupportedOperationException, "No fallback available.") + defaultTags() + } + } + } + } + + where: + action | observeOn | subscribeOn | operation + "toObservable" | null | null | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable-I" | Schedulers.immediate() | null | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable-T" | Schedulers.trampoline() | null | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable-C" | Schedulers.computation() | null | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable-IO" | Schedulers.io() | null | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable-NT" | Schedulers.newThread() | null | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable+I" | null | Schedulers.immediate() | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable+T" | null | Schedulers.trampoline() | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable+C" | null | Schedulers.computation() | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable+IO" | null | Schedulers.io() | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "toObservable+NT" | null | Schedulers.newThread() | { HystrixObservable cmd -> cmd.toObservable().toBlocking().first() } + "observe" | null | null | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe-I" | Schedulers.immediate() | null | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe-T" | Schedulers.trampoline() | null | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe-C" | Schedulers.computation() | null | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe-IO" | Schedulers.io() | null | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe-NT" | Schedulers.newThread() | null | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe+I" | null | Schedulers.immediate() | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe+T" | null | Schedulers.trampoline() | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe+C" | null | Schedulers.computation() | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe+IO" | null | Schedulers.io() | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "observe+NT" | null | Schedulers.newThread() | { HystrixObservable cmd -> cmd.observe().toBlocking().first() } + "toObservable block" | Schedulers.computation() | Schedulers.newThread() | { HystrixObservable cmd -> + def queue = new LinkedBlockingQueue() + def subscription = cmd.toObservable().subscribe({ next -> + queue.put(new Exception("Unexpectedly got a next")) + }, { next -> + queue.put(next) + }) + Throwable ex = queue.take() + subscription.unsubscribe() + throw ex } } } diff --git a/dd-java-agent/instrumentation/hystrix-1.4/src/test/groovy/HystrixTest.groovy b/dd-java-agent/instrumentation/hystrix-1.4/src/test/groovy/HystrixTest.groovy index 0154435319..800cf03c8c 100644 --- a/dd-java-agent/instrumentation/hystrix-1.4/src/test/groovy/HystrixTest.groovy +++ b/dd-java-agent/instrumentation/hystrix-1.4/src/test/groovy/HystrixTest.groovy @@ -2,6 +2,7 @@ import com.netflix.hystrix.HystrixCommand import datadog.trace.agent.test.AgentTestRunner import datadog.trace.api.Trace import io.opentracing.tag.Tags +import spock.lang.Timeout import java.util.concurrent.BlockingQueue import java.util.concurrent.LinkedBlockingQueue @@ -9,11 +10,15 @@ import java.util.concurrent.LinkedBlockingQueue import static com.netflix.hystrix.HystrixCommandGroupKey.Factory.asKey import static datadog.trace.agent.test.utils.TraceUtils.runUnderTrace +@Timeout(10) class HystrixTest extends AgentTestRunner { - // Uncomment for debugging: - // static { - // System.setProperty("hystrix.command.default.execution.timeout.enabled", "false") - // } + static { + // Disable so failure testing below doesn't inadvertently change the behavior. + System.setProperty("hystrix.command.default.circuitBreaker.enabled", "false") + + // Uncomment for debugging: + // System.setProperty("hystrix.command.default.execution.timeout.enabled", "false") + } def "test command #action"() { setup: diff --git a/dd-java-agent/instrumentation/java-concurrent/src/main/java/datadog/trace/instrumentation/java/concurrent/AsyncPropagatingDisableInstrumentation.java b/dd-java-agent/instrumentation/java-concurrent/src/main/java/datadog/trace/instrumentation/java/concurrent/AsyncPropagatingDisableInstrumentation.java index d446c34f4d..dcd0b02cbd 100644 --- a/dd-java-agent/instrumentation/java-concurrent/src/main/java/datadog/trace/instrumentation/java/concurrent/AsyncPropagatingDisableInstrumentation.java +++ b/dd-java-agent/instrumentation/java-concurrent/src/main/java/datadog/trace/instrumentation/java/concurrent/AsyncPropagatingDisableInstrumentation.java @@ -1,7 +1,7 @@ package datadog.trace.instrumentation.java.concurrent; +import static datadog.trace.agent.tooling.ByteBuddyElementMatchers.safeHasSuperType; import static java.util.Collections.singletonMap; -import static net.bytebuddy.matcher.ElementMatchers.isConstructor; import static net.bytebuddy.matcher.ElementMatchers.named; import com.google.auto.service.AutoService; @@ -31,17 +31,19 @@ import net.bytebuddy.matcher.ElementMatchers; public final class AsyncPropagatingDisableInstrumentation implements Instrumenter { private static final Map< - ElementMatcher, ElementMatcher> + ElementMatcher, ElementMatcher> CLASS_AND_METHODS = new ImmutableMap.Builder< - ElementMatcher, ElementMatcher>() - .put(named("rx.internal.util.ObjectPool"), isConstructor()) + ElementMatcher, + ElementMatcher>() + .put(safeHasSuperType(named("rx.Scheduler$Worker")), named("schedulePeriodically")) .build(); @Override public AgentBuilder instrument(AgentBuilder agentBuilder) { - for (final Map.Entry, ElementMatcher> + for (final Map.Entry< + ElementMatcher, ElementMatcher> entry : CLASS_AND_METHODS.entrySet()) { agentBuilder = new DisableAsyncInstrumentation(entry.getKey(), entry.getValue()) @@ -54,7 +56,7 @@ public final class AsyncPropagatingDisableInstrumentation implements Instrumente public static class DisableAsyncInstrumentation extends Default { private final ElementMatcher typeMatcher; - private final ElementMatcher methodMatcher; + private final ElementMatcher methodMatcher; /** No-arg constructor only used by muzzle and tests. */ public DisableAsyncInstrumentation() { @@ -63,7 +65,7 @@ public final class AsyncPropagatingDisableInstrumentation implements Instrumente public DisableAsyncInstrumentation( final ElementMatcher typeMatcher, - final ElementMatcher methodMatcher) { + final ElementMatcher methodMatcher) { super(AbstractExecutorInstrumentation.EXEC_NAME); this.typeMatcher = typeMatcher; this.methodMatcher = methodMatcher; @@ -75,7 +77,7 @@ public final class AsyncPropagatingDisableInstrumentation implements Instrumente } @Override - public Map, String> transformers() { + public Map, String> transformers() { return singletonMap(methodMatcher, DisableAsyncAdvice.class.getName()); } } diff --git a/dd-java-agent/testing/src/main/groovy/datadog/trace/agent/test/AgentTestRunner.java b/dd-java-agent/testing/src/main/groovy/datadog/trace/agent/test/AgentTestRunner.java index 254e3765bb..9d97fd4d5c 100644 --- a/dd-java-agent/testing/src/main/groovy/datadog/trace/agent/test/AgentTestRunner.java +++ b/dd-java-agent/testing/src/main/groovy/datadog/trace/agent/test/AgentTestRunner.java @@ -5,6 +5,7 @@ import ch.qos.logback.classic.Logger; import com.google.common.collect.Sets; import datadog.opentracing.DDSpan; import datadog.opentracing.DDTracer; +import datadog.opentracing.PendingTrace; import datadog.trace.agent.test.asserts.ListWriterAssert; import datadog.trace.agent.test.utils.GlobalTracerUtils; import datadog.trace.agent.tooling.AgentInstaller; @@ -197,6 +198,15 @@ public abstract class AgentTestRunner extends Specification { ListWriterAssert.assertTraces(TEST_WRITER, size, spec); } + public void blockUntilChildSpansFinished(final int numberOfSpans) throws InterruptedException { + final DDSpan span = (DDSpan) io.opentracing.util.GlobalTracer.get().activeSpan(); + final PendingTrace pendingTrace = span.context().getTrace(); + + while (pendingTrace.size() < numberOfSpans) { + Thread.sleep(10); + } + } + public static class TestRunnerListener implements AgentBuilder.Listener { private static final List activeTests = new CopyOnWriteArrayList<>(); diff --git a/dd-java-agent/testing/src/test/groovy/AgentTestRunnerTest.groovy b/dd-java-agent/testing/src/test/groovy/AgentTestRunnerTest.groovy index 9f24b21f68..1e319a227d 100644 --- a/dd-java-agent/testing/src/test/groovy/AgentTestRunnerTest.groovy +++ b/dd-java-agent/testing/src/test/groovy/AgentTestRunnerTest.groovy @@ -97,6 +97,28 @@ class AgentTestRunnerTest extends AgentTestRunner { new config.exclude.packagename.SomeClass.NestedClass() | _ } + def "test unblocked by completed span"() { + setup: + runUnderTrace("parent") { + runUnderTrace("child") {} + blockUntilChildSpansFinished(1) + } + + expect: + assertTraces(1) { + trace(0, 2) { + span(0) { + operationName "parent" + parent() + } + span(1) { + operationName "child" + childOf(span(0)) + } + } + } + } + private static getAgentTransformer() { Field f try { From c8743fce644f5765026c715f8fb0d21c0261886d Mon Sep 17 00:00:00 2001 From: Tyler Benson Date: Tue, 30 Apr 2019 14:53:15 -0700 Subject: [PATCH 4/4] Remove potentially dangerous recursive call. --- .../trace/instrumentation/hystrix/HystrixInstrumentation.java | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/dd-java-agent/instrumentation/hystrix-1.4/src/main/java/datadog/trace/instrumentation/hystrix/HystrixInstrumentation.java b/dd-java-agent/instrumentation/hystrix-1.4/src/main/java/datadog/trace/instrumentation/hystrix/HystrixInstrumentation.java index 61cece5ecd..dada399519 100644 --- a/dd-java-agent/instrumentation/hystrix-1.4/src/main/java/datadog/trace/instrumentation/hystrix/HystrixInstrumentation.java +++ b/dd-java-agent/instrumentation/hystrix-1.4/src/main/java/datadog/trace/instrumentation/hystrix/HystrixInstrumentation.java @@ -222,8 +222,7 @@ public class HystrixInstrumentation extends Instrumenter.Default { delegate.onError(e); } catch (final Throwable e2) { DECORATE.onError(span, e2); - // This recursive call might be dangerous... not sure what the best response is. - onError(e2); + throw e2; } finally { DECORATE.beforeFinish(span); span.finish();