Split async and sync advice and misc cleanup.

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<
+  public ElementMatcher<? super net.bytebuddy.description.type.TypeDescription> typeMatcher() {
-          ? super net.bytebuddy.description.type.TypeDescription>
-      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")
+                named("createAsync")
-                    .or(nameStartsWith("delete"))
+                    .or(named("deleteAsync"))
-                    .or(nameStartsWith("read"))
+                    .or(named("readAsync"))
-                    .or(nameStartsWith("fetch"))
+                    .or(named("fetchAsync"))
-                    .or(nameStartsWith("update"))),
+                    .or(named("updateAsync")))
-        TwilioClientAdvice.class.getName());
+            .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.Return final ListenableFuture response) {
-        @Advice.Origin("#m") final String methodName) {
 
       // 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);
+          if (throwable != null) {
-          DECORATE.beforeFinish(span);
+            // There was an synchronous error,
-
+            // which means we shouldn't wait for a callback to close the span.
-          // If we're calling an async operation, we still need to finish the span when it's
+            DECORATE.onError(span, throwable);
-          // complete and report the results; set an appropriate callback
-          if (isAsync && response instanceof ListenableFuture) {
-            Futures.addCallback(
-                (ListenableFuture) response,
-                new SpanFinishingCallback(span),
-                Twilio.getExecutorService());
-          } else {
             DECORATE.beforeFinish(span);
-            DECORATE.onResult(span, response);
+            span.finish();
-            // span is implicitly closed with the scope
+          } 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();
+          scope.close(); // won't finish the span.
-          CallDepthThreadLocalMap.reset(Twilio.class); // reset call deptch count
+          CallDepthThreadLocalMap.reset(Twilio.class); // reset call depth count
         }
       }
     }

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) {

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<? extends ElementMatcher<? super MethodDescription>, 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
+        }
+      }
+    }
+  }
+}

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) {

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: '+'
 }