diff --git a/dd-java-agent/instrumentation/twilio/src/main/java/datadog/trace/instrumentation/twilio/TwilioInstrumentation.java b/dd-java-agent/instrumentation/twilio/src/main/java/datadog/trace/instrumentation/twilio/TwilioAsyncInstrumentation.java similarity index 74% rename from dd-java-agent/instrumentation/twilio/src/main/java/datadog/trace/instrumentation/twilio/TwilioInstrumentation.java rename to dd-java-agent/instrumentation/twilio/src/main/java/datadog/trace/instrumentation/twilio/TwilioAsyncInstrumentation.java index 59bed69105..c9d9b8e8bd 100644 --- a/dd-java-agent/instrumentation/twilio/src/main/java/datadog/trace/instrumentation/twilio/TwilioInstrumentation.java +++ b/dd-java-agent/instrumentation/twilio/src/main/java/datadog/trace/instrumentation/twilio/TwilioAsyncInstrumentation.java @@ -6,9 +6,9 @@ import static java.util.Collections.singletonMap; import static net.bytebuddy.matcher.ElementMatchers.isAbstract; import static net.bytebuddy.matcher.ElementMatchers.isMethod; import static net.bytebuddy.matcher.ElementMatchers.isPublic; -import static net.bytebuddy.matcher.ElementMatchers.nameStartsWith; import static net.bytebuddy.matcher.ElementMatchers.named; import static net.bytebuddy.matcher.ElementMatchers.not; +import static net.bytebuddy.matcher.ElementMatchers.returns; import com.google.auto.service.AutoService; import com.google.common.util.concurrent.FutureCallback; @@ -20,7 +20,6 @@ import datadog.trace.bootstrap.CallDepthThreadLocalMap; import datadog.trace.context.TraceScope; import io.opentracing.Scope; import io.opentracing.Span; -import io.opentracing.Tracer; import io.opentracing.util.GlobalTracer; import java.util.Map; import net.bytebuddy.asm.Advice; @@ -29,17 +28,15 @@ import net.bytebuddy.matcher.ElementMatcher; /** Instrument the Twilio SDK to identify calls as a seperate service. */ @AutoService(Instrumenter.class) -public class TwilioInstrumentation extends Instrumenter.Default { +public class TwilioAsyncInstrumentation extends Instrumenter.Default { - public TwilioInstrumentation() { + public TwilioAsyncInstrumentation() { super("twilio-sdk"); } /** Match any child class of the base Twilio service classes. */ @Override - public net.bytebuddy.matcher.ElementMatcher< - ? super net.bytebuddy.description.type.TypeDescription> - typeMatcher() { + public ElementMatcher typeMatcher() { return safeHasSuperType( named("com.twilio.base.Creator") .or(named("com.twilio.base.Deleter")) @@ -55,7 +52,7 @@ public class TwilioInstrumentation extends Instrumenter.Default { "datadog.trace.agent.decorator.BaseDecorator", "datadog.trace.agent.decorator.ClientDecorator", packageName + ".TwilioClientDecorator", - packageName + ".TwilioInstrumentation$SpanFinishingCallback" + packageName + ".TwilioAsyncInstrumentation$SpanFinishingCallback", }; } @@ -75,16 +72,17 @@ public class TwilioInstrumentation extends Instrumenter.Default { .and(isPublic()) .and(not(isAbstract())) .and( - nameStartsWith("create") - .or(nameStartsWith("delete")) - .or(nameStartsWith("read")) - .or(nameStartsWith("fetch")) - .or(nameStartsWith("update"))), - TwilioClientAdvice.class.getName()); + named("createAsync") + .or(named("deleteAsync")) + .or(named("readAsync")) + .or(named("fetchAsync")) + .or(named("updateAsync"))) + .and(returns(named("com.google.common.util.concurrent.ListenableFuture"))), + TwilioClientAsyncAdvice.class.getName()); } /** Advice for instrumenting Twilio service classes. */ - public static class TwilioClientAdvice { + public static class TwilioClientAsyncAdvice { /** Method entry instrumentation. */ @Advice.OnMethodEnter(suppress = Throwable.class) @@ -100,20 +98,15 @@ public class TwilioInstrumentation extends Instrumenter.Default { return null; } - // By convention, all Twilio async methods end with Async - final boolean isAsync = methodName.endsWith("Async"); - - final Tracer tracer = GlobalTracer.get(); - // Don't automatically close the span with the scope if we're executing an async method - final Scope scope = tracer.buildSpan("twilio.sdk").startActive(!isAsync); + final Scope scope = GlobalTracer.get().buildSpan("twilio.sdk").startActive(false); final Span span = scope.span(); DECORATE.afterStart(span); DECORATE.onServiceExecution(span, that, methodName); // If an async operation was invoked and we have a TraceScope, - if (isAsync && scope instanceof TraceScope) { + if (scope instanceof TraceScope) { // Enable async propagation, so the newly spawned task will be associated back with this // original trace. ((TraceScope) scope).setAsyncPropagation(true); @@ -127,35 +120,28 @@ public class TwilioInstrumentation extends Instrumenter.Default { public static void methodExit( @Advice.Enter final Scope scope, @Advice.Thrown final Throwable throwable, - @Advice.Return final Object response, - @Advice.Origin("#m") final String methodName) { + @Advice.Return final ListenableFuture response) { // If we have a scope (i.e. we were the top-level Twilio SDK invocation), if (scope != null) { try { - final boolean isAsync = methodName.endsWith("Async"); - final Span span = scope.span(); - DECORATE.onError(span, throwable); - DECORATE.beforeFinish(span); - - // If we're calling an async operation, we still need to finish the span when it's - // complete and report the results; set an appropriate callback - if (isAsync && response instanceof ListenableFuture) { - Futures.addCallback( - (ListenableFuture) response, - new SpanFinishingCallback(span), - Twilio.getExecutorService()); - } else { + if (throwable != null) { + // There was an synchronous error, + // which means we shouldn't wait for a callback to close the span. + DECORATE.onError(span, throwable); DECORATE.beforeFinish(span); - DECORATE.onResult(span, response); - // span is implicitly closed with the scope + span.finish(); + } else { + // We're calling an async operation, we still need to finish the span when it's + // complete and report the results; set an appropriate callback + Futures.addCallback( + response, new SpanFinishingCallback(span), Twilio.getExecutorService()); } - } finally { - scope.close(); - CallDepthThreadLocalMap.reset(Twilio.class); // reset call deptch count + scope.close(); // won't finish the span. + CallDepthThreadLocalMap.reset(Twilio.class); // reset call depth count } } } diff --git a/dd-java-agent/instrumentation/twilio/src/main/java/datadog/trace/instrumentation/twilio/TwilioClientDecorator.java b/dd-java-agent/instrumentation/twilio/src/main/java/datadog/trace/instrumentation/twilio/TwilioClientDecorator.java index 7d8a75b69c..af8ab93a19 100644 --- a/dd-java-agent/instrumentation/twilio/src/main/java/datadog/trace/instrumentation/twilio/TwilioClientDecorator.java +++ b/dd-java-agent/instrumentation/twilio/src/main/java/datadog/trace/instrumentation/twilio/TwilioClientDecorator.java @@ -9,8 +9,10 @@ import datadog.trace.api.DDTags; import io.opentracing.Span; import java.lang.reflect.Method; import java.util.concurrent.TimeUnit; +import lombok.extern.slf4j.Slf4j; /** Decorate Twilio span's with relevant contextual information. */ +@Slf4j public class TwilioClientDecorator extends ClientDecorator { public static final TwilioClientDecorator DECORATE = new TwilioClientDecorator(); @@ -58,7 +60,7 @@ public class TwilioClientDecorator extends ClientDecorator { try { result = ((ListenableFuture) result).get(0, TimeUnit.MICROSECONDS); } catch (final Exception e) { - e.printStackTrace(); + log.debug("Error unwrapping result", e); } } @@ -73,7 +75,6 @@ public class TwilioClientDecorator extends ClientDecorator { // Instrument the most popular resource types directly if (result instanceof Message) { final Message message = (Message) result; - span.setTag("twilio.type", result.getClass().getCanonicalName()); span.setTag("twilio.account", message.getAccountSid()); span.setTag("twilio.sid", message.getSid()); if (message.getStatus() != null) { diff --git a/dd-java-agent/instrumentation/twilio/src/main/java/datadog/trace/instrumentation/twilio/TwilioSyncInstrumentation.java b/dd-java-agent/instrumentation/twilio/src/main/java/datadog/trace/instrumentation/twilio/TwilioSyncInstrumentation.java new file mode 100644 index 0000000000..358f236708 --- /dev/null +++ b/dd-java-agent/instrumentation/twilio/src/main/java/datadog/trace/instrumentation/twilio/TwilioSyncInstrumentation.java @@ -0,0 +1,127 @@ +package datadog.trace.instrumentation.twilio; + +import static datadog.trace.agent.tooling.ByteBuddyElementMatchers.safeHasSuperType; +import static datadog.trace.instrumentation.twilio.TwilioClientDecorator.DECORATE; +import static java.util.Collections.singletonMap; +import static net.bytebuddy.matcher.ElementMatchers.isAbstract; +import static net.bytebuddy.matcher.ElementMatchers.isMethod; +import static net.bytebuddy.matcher.ElementMatchers.isPublic; +import static net.bytebuddy.matcher.ElementMatchers.named; +import static net.bytebuddy.matcher.ElementMatchers.not; + +import com.google.auto.service.AutoService; +import com.twilio.Twilio; +import datadog.trace.agent.tooling.Instrumenter; +import datadog.trace.bootstrap.CallDepthThreadLocalMap; +import io.opentracing.Scope; +import io.opentracing.Span; +import io.opentracing.util.GlobalTracer; +import java.util.Map; +import net.bytebuddy.asm.Advice; +import net.bytebuddy.description.method.MethodDescription; +import net.bytebuddy.matcher.ElementMatcher; + +/** Instrument the Twilio SDK to identify calls as a seperate service. */ +@AutoService(Instrumenter.class) +public class TwilioSyncInstrumentation extends Instrumenter.Default { + + public TwilioSyncInstrumentation() { + super("twilio-sdk"); + } + + /** Match any child class of the base Twilio service classes. */ + @Override + public net.bytebuddy.matcher.ElementMatcher< + ? super net.bytebuddy.description.type.TypeDescription> + typeMatcher() { + return safeHasSuperType( + named("com.twilio.base.Creator") + .or(named("com.twilio.base.Deleter")) + .or(named("com.twilio.base.Fetcher")) + .or(named("com.twilio.base.Reader")) + .or(named("com.twilio.base.Updater"))); + } + + /** Return the helper classes which will be available for use in instrumentation. */ + @Override + public String[] helperClassNames() { + return new String[] { + "datadog.trace.agent.decorator.BaseDecorator", + "datadog.trace.agent.decorator.ClientDecorator", + packageName + ".TwilioClientDecorator", + }; + } + + /** Return bytebuddy transformers for instrumenting the Twilio SDK. */ + @Override + public Map, String> transformers() { + + /* + We are listing out the main service calls on the Creator, Deleter, Fetcher, Reader, and + Updater abstract classes. The isDeclaredBy() matcher did not work in the unit tests and + we found that there were certain methods declared on the base class (particularly Reader), + which we weren't interested in annotating. + */ + + return singletonMap( + isMethod() + .and(isPublic()) + .and(not(isAbstract())) + .and( + named("create") + .or(named("delete")) + .or(named("read")) + .or(named("fetch")) + .or(named("update"))), + TwilioClientAdvice.class.getName()); + } + + /** Advice for instrumenting Twilio service classes. */ + public static class TwilioClientAdvice { + + /** Method entry instrumentation. */ + @Advice.OnMethodEnter(suppress = Throwable.class) + public static Scope methodEnter( + @Advice.This final Object that, @Advice.Origin("#m") final String methodName) { + + // Ensure that we only create a span for the top-level Twilio client method; except in the + // case of async operations where we want visibility into how long the task was delayed from + // starting. Our call depth checker does not span threads, so the async case is handled + // automatically for us. + final int callDepth = CallDepthThreadLocalMap.incrementCallDepth(Twilio.class); + if (callDepth > 0) { + return null; + } + + final Scope scope = GlobalTracer.get().buildSpan("twilio.sdk").startActive(true); + final Span span = scope.span(); + + DECORATE.afterStart(span); + DECORATE.onServiceExecution(span, that, methodName); + + return scope; + } + + /** Method exit instrumentation. */ + @Advice.OnMethodExit(onThrowable = Throwable.class, suppress = Throwable.class) + public static void methodExit( + @Advice.Enter final Scope scope, + @Advice.Thrown final Throwable throwable, + @Advice.Return final Object response) { + + // If we have a scope (i.e. we were the top-level Twilio SDK invocation), + if (scope != null) { + try { + final Span span = scope.span(); + + DECORATE.onResult(span, response); + DECORATE.onError(span, throwable); + DECORATE.beforeFinish(span); + } finally { + scope.close(); + CallDepthThreadLocalMap.reset(Twilio.class); // reset call depth count + } + } + } + } +} diff --git a/dd-java-agent/instrumentation/twilio/src/test/groovy/test/TwilioClientTest.groovy b/dd-java-agent/instrumentation/twilio/src/test/groovy/test/TwilioClientTest.groovy index cf3f5b01d6..efa871876d 100644 --- a/dd-java-agent/instrumentation/twilio/src/test/groovy/test/TwilioClientTest.groovy +++ b/dd-java-agent/instrumentation/twilio/src/test/groovy/test/TwilioClientTest.groovy @@ -511,19 +511,21 @@ class TwilioClientTest extends AgentTestRunner { defaultTags() } } + // Spans are reported in reverse order of completion, + // so the error span is last even though it happened first. span(3) { serviceName "twilio-sdk" operationName "http.request" resourceName "POST /?/Accounts/abc/Messages.json" spanType DDSpanTypes.HTTP_CLIENT - errored true + errored false } span(4) { serviceName "twilio-sdk" operationName "http.request" resourceName "POST /?/Accounts/abc/Messages.json" spanType DDSpanTypes.HTTP_CLIENT - errored false + errored true } } } @@ -617,7 +619,6 @@ class TwilioClientTest extends AgentTestRunner { } } } - } def "asynchronous call"(a) { diff --git a/dd-java-agent/instrumentation/twilio/twilio.gradle b/dd-java-agent/instrumentation/twilio/twilio.gradle index f8dc7ac327..fb5f4213e5 100644 --- a/dd-java-agent/instrumentation/twilio/twilio.gradle +++ b/dd-java-agent/instrumentation/twilio/twilio.gradle @@ -8,8 +8,14 @@ muzzle { apply from: "${rootDir}/gradle/java.gradle" +apply plugin: 'org.unbroken-dome.test-sets' + +testSets { + latestDepTest +} + dependencies { - compileOnly group: 'com.twilio.sdk', name: 'twilio', version: '7.36.2' + compileOnly group: 'com.twilio.sdk', name: 'twilio', version: '0.0.1' compile project(':dd-java-agent:agent-tooling') @@ -18,11 +24,12 @@ dependencies { annotationProcessor deps.autoservice implementation deps.autoservice - testCompile group: 'com.twilio.sdk', name: 'twilio', version: '7.36.2' + testCompile group: 'com.twilio.sdk', name: 'twilio', version: '0.0.1' testCompile project(':dd-java-agent:testing') testCompile project(':dd-java-agent:instrumentation:apache-httpclient-4') testCompile project(':dd-java-agent:instrumentation:java-concurrent') testCompile group: 'org.objenesis', name: 'objenesis', version: '2.6' // Last version to support Java7 testCompile group: 'nl.jqno.equalsverifier', name: 'equalsverifier', version: '2.5.2' // Last version to support Java7 + latestDepTestCompile group: 'com.twilio.sdk', name: 'twilio', version: '+' }