From 13aa267d8482c3f46267129fec2f96e016bb0aa6 Mon Sep 17 00:00:00 2001 From: Daryl Robbins Date: Thu, 21 Mar 2019 16:42:55 -0400 Subject: [PATCH] WIP Twilio SDK Instrumentation Missed Gradle file Updates to handle async calls, which have broken all tests --- .../AbstractExecutorInstrumentation.java | 3 + .../concurrent/FutureInstrumentation.java | 3 +- .../twilio/TwilioClientDecorator.java | 95 +++++++ .../twilio/TwilioInstrumentation.java | 165 ++++++++++++ .../test/groovy/test/TwilioClientTest.groovy | 244 ++++++++++++++++++ .../instrumentation/twilio/twilio.gradle | 25 ++ settings.gradle | 2 + 7 files changed, 536 insertions(+), 1 deletion(-) create mode 100644 dd-java-agent/instrumentation/twilio/src/main/java/datadog/trace/instrumentation/twilio/TwilioClientDecorator.java create mode 100644 dd-java-agent/instrumentation/twilio/src/main/java/datadog/trace/instrumentation/twilio/TwilioInstrumentation.java create mode 100644 dd-java-agent/instrumentation/twilio/src/test/groovy/test/TwilioClientTest.groovy create mode 100644 dd-java-agent/instrumentation/twilio/twilio.gradle diff --git a/dd-java-agent/instrumentation/java-concurrent/src/main/java/datadog/trace/instrumentation/java/concurrent/AbstractExecutorInstrumentation.java b/dd-java-agent/instrumentation/java-concurrent/src/main/java/datadog/trace/instrumentation/java/concurrent/AbstractExecutorInstrumentation.java index c514afdbe7..ffbeb5ea62 100644 --- a/dd-java-agent/instrumentation/java-concurrent/src/main/java/datadog/trace/instrumentation/java/concurrent/AbstractExecutorInstrumentation.java +++ b/dd-java-agent/instrumentation/java-concurrent/src/main/java/datadog/trace/instrumentation/java/concurrent/AbstractExecutorInstrumentation.java @@ -69,6 +69,9 @@ public abstract class AbstractExecutorInstrumentation extends Instrumenter.Defau "io.netty.util.concurrent.SingleThreadEventExecutor", "io.netty.channel.nio.NioEventLoop", "io.netty.channel.SingleThreadEventLoop", + "com.google.common.util.concurrent.AbstractListeningExecutorService", + "com.google.common.util.concurrent.MoreExecutors$ListeningDecorator", + "com.google.common.util.concurrent.MoreExecutors$ScheduledListeningDecorator", }; WHITELISTED_EXECUTORS = Collections.unmodifiableSet(new HashSet<>(Arrays.asList(whitelist))); diff --git a/dd-java-agent/instrumentation/java-concurrent/src/main/java/datadog/trace/instrumentation/java/concurrent/FutureInstrumentation.java b/dd-java-agent/instrumentation/java-concurrent/src/main/java/datadog/trace/instrumentation/java/concurrent/FutureInstrumentation.java index a1b2317c21..157b166c56 100644 --- a/dd-java-agent/instrumentation/java-concurrent/src/main/java/datadog/trace/instrumentation/java/concurrent/FutureInstrumentation.java +++ b/dd-java-agent/instrumentation/java-concurrent/src/main/java/datadog/trace/instrumentation/java/concurrent/FutureInstrumentation.java @@ -62,7 +62,8 @@ public final class FutureInstrumentation extends Instrumenter.Default { "com.google.common.util.concurrent.SettableFuture", "com.google.common.util.concurrent.AbstractFuture$TrustedFuture", "com.google.common.util.concurrent.AbstractFuture", - "io.netty.util.concurrent.ScheduledFutureTask" + "io.netty.util.concurrent.ScheduledFutureTask", + "com.google.common.util.concurrent.ListenableFutureTask" }; WHITELISTED_FUTURES = Collections.unmodifiableSet(new HashSet<>(Arrays.asList(whitelist))); } 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 new file mode 100644 index 0000000000..54ad6ff7c9 --- /dev/null +++ b/dd-java-agent/instrumentation/twilio/src/main/java/datadog/trace/instrumentation/twilio/TwilioClientDecorator.java @@ -0,0 +1,95 @@ +package datadog.trace.instrumentation.twilio; + +import com.twilio.rest.api.v2010.account.Call; +import com.twilio.rest.api.v2010.account.Message; +import datadog.trace.agent.decorator.ClientDecorator; +import datadog.trace.api.DDSpanTypes; +import datadog.trace.api.DDTags; +import io.opentracing.Span; +import java.lang.reflect.Method; + +/** Decorate Twilio span's with relevant contextual information. */ +public class TwilioClientDecorator extends ClientDecorator { + + public static final TwilioClientDecorator DECORATE = new TwilioClientDecorator(); + + static final String COMPONENT_NAME = "twilio-sdk"; + + @Override + protected String spanType() { + return DDSpanTypes.HTTP_CLIENT; + } + + @Override + protected String[] instrumentationNames() { + return new String[] {COMPONENT_NAME}; + } + + @Override + protected String component() { + return COMPONENT_NAME; + } + + @Override + protected String service() { + return COMPONENT_NAME; + } + + /** Decorate trace based on service execution metadata */ + public Span onServiceExecution( + final Span span, final Object serviceExecutor, final String methodName) { + + // Drop common package prefix (com.twilio.rest) + final String simpleClassName = + serviceExecutor.getClass().getCanonicalName().replaceFirst("^com\\.twilio\\.rest\\.", ""); + + span.setTag(DDTags.RESOURCE_NAME, String.format("%s.%s", simpleClassName, methodName)); + + return span; + } + + /** Annotate the span with the results of the operation. */ + public Span onResult(final Span span, final Object result) { + + // Provide helpful metadata for some of the more common response types + span.setTag("twilio.type", result.getClass().getCanonicalName()); + // 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()); + span.setTag("twilio.status", message.getStatus().toString()); + } else if (result instanceof Call) { + final Call call = (Call) result; + span.setTag("twilio.account", call.getAccountSid()); + span.setTag("twilio.sid", call.getSid()); + span.setTag("twilio.parentSid", call.getParentCallSid()); + span.setTag("twilio.status", call.getStatus().toString()); + } else { + // Use reflection to gather insight from other types; note that Twilio requests take close to + // 1 second, so the added hit from reflection here is relatively minimal in the grand scheme + // of things + setTagIfPresent(span, result, "twilio.sid", "getSid"); + setTagIfPresent(span, result, "twilio.account", "getAccountSid"); + setTagIfPresent(span, result, "twilio.status", "getStatus"); + } + + return span; + } + + private void setTagIfPresent( + final Span span, final Object result, final String tag, final String getter) { + try { + final Method method = result.getClass().getMethod(getter); + final Object value = method.invoke(result); + + if (value != null) { + span.setTag(tag, value.toString()); + } + + } catch (final Exception e) { + // Expected that this won't work for all result types + } + } +} 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/TwilioInstrumentation.java new file mode 100644 index 0000000000..163f2e3056 --- /dev/null +++ b/dd-java-agent/instrumentation/twilio/src/main/java/datadog/trace/instrumentation/twilio/TwilioInstrumentation.java @@ -0,0 +1,165 @@ +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.nameStartsWith; +import static net.bytebuddy.matcher.ElementMatchers.named; +import static net.bytebuddy.matcher.ElementMatchers.not; + +import com.google.auto.service.AutoService; +import com.google.common.util.concurrent.FutureCallback; +import com.google.common.util.concurrent.Futures; +import com.google.common.util.concurrent.ListenableFuture; +import com.twilio.Twilio; +import datadog.trace.agent.tooling.Instrumenter; +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; +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 TwilioInstrumentation extends Instrumenter.Default { + + public TwilioInstrumentation() { + super("twilio-sdk"); + } + + @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"))); + } + + @Override + public String[] helperClassNames() { + return new String[] { + "datadog.trace.agent.decorator.BaseDecorator", + "datadog.trace.agent.decorator.ClientDecorator", + packageName + ".TwilioClientDecorator", + }; + } + + @Override + public Map, String> transformers() { + + return singletonMap( + isMethod() + .and(isPublic()) + .and(not(isAbstract())) + .and( + nameStartsWith("create") + .or(nameStartsWith("delete")) + .or(nameStartsWith("read")) + .or(nameStartsWith("fetch")) + .or(nameStartsWith("update"))), + TwilioClientAdvice.class.getName()); + } + + 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) { + + final int callDepth = CallDepthThreadLocalMap.incrementCallDepth(Twilio.class); + if (callDepth > 0) { + return null; + } + + final boolean isAsync = methodName.endsWith("Async"); + + final Tracer tracer = GlobalTracer.get(); + final Scope scope = tracer.buildSpan("twilio.sdk").startActive(!isAsync); + final Span span = scope.span(); + + DECORATE.afterStart(span); + DECORATE.onServiceExecution(span, that, methodName); + + if (scope instanceof TraceScope) { + ((TraceScope) scope).setAsyncPropagation(true); + } + + 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, + @Advice.Origin("#m") final String methodName) { + if (scope != null) { + try { + final boolean isAsync = methodName.endsWith("Async"); + System.err.println("isAsync = " + isAsync); + + 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; set an appropriate callback + if (isAsync && response instanceof ListenableFuture) { + Futures.addCallback( + (ListenableFuture) response, + new SpanFinishingCallback(span), + Twilio.getExecutorService()); + } else { + DECORATE.onResult(span, response); + } + + } finally { + scope.close(); + CallDepthThreadLocalMap.reset(Twilio.class); + } + } + } + } + + /** + * FutureCallback, which automatically finishes the span and annotates with any appropriate + * metadata on a potential failure. + */ + private static class SpanFinishingCallback implements FutureCallback { + + private final Span span; + + SpanFinishingCallback(final Span span) { + this.span = span; + } + + @Override + public void onSuccess(final Object result) { + DECORATE.beforeFinish(span); + DECORATE.onResult(span, result); + span.finish(); + } + + @Override + public void onFailure(final Throwable t) { + DECORATE.onError(span, t); + DECORATE.beforeFinish(span); + span.finish(); + } + } +} 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 new file mode 100644 index 0000000000..a0f6caeed4 --- /dev/null +++ b/dd-java-agent/instrumentation/twilio/src/test/groovy/test/TwilioClientTest.groovy @@ -0,0 +1,244 @@ +package test + +import com.fasterxml.jackson.databind.ObjectMapper +import com.google.common.util.concurrent.ListenableFuture +import com.twilio.Twilio +import com.twilio.exception.ApiException +import com.twilio.http.Response +import com.twilio.http.TwilioRestClient +import com.twilio.rest.api.v2010.account.Message +import com.twilio.type.PhoneNumber +import datadog.trace.agent.test.AgentTestRunner +import datadog.trace.api.DDSpanTypes +import io.opentracing.util.GlobalTracer + +import java.util.concurrent.TimeUnit + +class TwilioClientTest extends AgentTestRunner { + + final static String ACCOUNT_SID = "abc" + final static String AUTH_TOKEN = "efg" + + final static String MESSAGE_RESPONSE_BODY = """ + { + "account_sid": "AC14984e09e497506cf0d5eb59b1f6ace7", + "api_version": "2010-04-01", + "body": "Hello, World!", + "date_created": "Thu, 30 Jul 2015 20:12:31 +0000", + "date_sent": "Thu, 30 Jul 2015 20:12:33 +0000", + "date_updated": "Thu, 30 Jul 2015 20:12:33 +0000", + "direction": "outbound-api", + "from": "+14155552345", + "messaging_service_sid": "MGXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX", + "num_media": "0", + "num_segments": "1", + "price": -0.00750, + "price_unit": "USD", + "sid": "MMXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX", + "status": "sent", + "subresource_uris": { + "media": "/2010-04-01/Accounts/AC14984e09e497506cf0d5eb59b1f6ace7/Messages/SMXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX/Media.json" + }, + "to": "+14155552345", + "uri": "/2010-04-01/Accounts/AC14984e09e497506cf0d5eb59b1f6ace7/Messages/SMXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX.json" + } + """ + + TwilioRestClient twilioRestClient = Mock() + + def setupSpec() { + Twilio.init(ACCOUNT_SID, AUTH_TOKEN) + } + + def "synchronous call"() { + setup: + twilioRestClient.getObjectMapper() >> new ObjectMapper() + + 1 * twilioRestClient.request(_) >> new Response(new ByteArrayInputStream(MESSAGE_RESPONSE_BODY.getBytes()), 200) + + GlobalTracer.get().buildSpan("test").startActive(true) + + Message message = Message.creator( + new PhoneNumber("+1 555 720 5913"), // To number + new PhoneNumber("+1 555 555 5215"), // From number + "Hello world!" // SMS body + ).create(twilioRestClient) + + Thread.sleep(1000); + + def scope = GlobalTracer.get().scopeManager().active() + if (scope) { + scope.close() + } + + expect: + + message.body == "Hello, World!" + + assertTraces(1) { + trace(0, 2) { + span(0) { + serviceName "unnamed-java-app" + operationName "test" + resourceName "test" + errored false + parent() + } + span(1) { + serviceName "twilio-sdk" + operationName "twilio.sdk" + resourceName "api.v2010.account.MessageCreator.create" + spanType DDSpanTypes.HTTP_CLIENT + errored false + } + tags { + "twilio.sid" "MMXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX" + } + } + } + } + + def "500 Error"() { + setup: + final String errorResponse = """ + { + "code": 123, + "message": "Testing Failure", + "code": 567, + "more_info": "Testing" + } + """ + + + twilioRestClient.getObjectMapper() >> new ObjectMapper() + + 1 * twilioRestClient.request(_) >> new Response(new ByteArrayInputStream(errorResponse.getBytes()), 500) + + GlobalTracer.get().buildSpan("test").startActive(true) + + when: + Message.creator( + new PhoneNumber("+1 555 720 5913"), // To number + new PhoneNumber("+1 555 555 5215"), // From number + "Hello world!" // SMS body + ).create(twilioRestClient) + + then: + thrown(ApiException) + + Thread.sleep(1000); + + def scope = GlobalTracer.get().scopeManager().active() + if (scope) { + scope.close() + } + + expect: + + assertTraces(1) { + trace(0, 2) { + span(0) { + serviceName "unnamed-java-app" + operationName "test" + resourceName "test" + errored false + parent() + } + span(1) { + serviceName "twilio-sdk" + operationName "twilio.sdk" + resourceName "api.v2010.account.MessageCreator.create" + spanType DDSpanTypes.HTTP_CLIENT + errored true + } + } + } + } + + def "root span"() { + setup: + twilioRestClient.getObjectMapper() >> new ObjectMapper() + + 1 * twilioRestClient.request(_) >> new Response(new ByteArrayInputStream(MESSAGE_RESPONSE_BODY.getBytes()), 200) + + Message message = Message.creator( + new PhoneNumber("+1 555 720 5913"), // To number + new PhoneNumber("+1 555 555 5215"), // From number + "Hello world!" // SMS body + ).create(twilioRestClient) + + expect: + + Thread.sleep(1000); + + message.body == "Hello, World!" + + assertTraces(1) { + trace(0, 1) { + span(0) { + serviceName "twilio-sdk" + operationName "twilio.sdk" + resourceName "api.v2010.account.MessageCreator.create" + parent() + spanType DDSpanTypes.HTTP_CLIENT + errored false + } + } + } + } + + def "asynchronous call"() { + setup: + twilioRestClient.getObjectMapper() >> new ObjectMapper() + + 1 * twilioRestClient.request(_) >> new Response(new ByteArrayInputStream(MESSAGE_RESPONSE_BODY.getBytes()), 200) + + GlobalTracer.get().buildSpan("test").startActive(true) + + ListenableFuture future = Message.creator( + new PhoneNumber("+1 555 720 5913"), // To number + new PhoneNumber("+1 555 555 5215"), // From number + "Hello world!" // SMS body + ).createAsync(twilioRestClient) + + Message message = future.get(10, TimeUnit.SECONDS) + + Thread.sleep(1000); + + def scope = GlobalTracer.get().scopeManager().active() + if (scope) { + scope.close() + } + + expect: + + message != null + message.body == "Hello, World!" + + assertTraces(1) { + trace(0, 3) { + span(0) { + serviceName "unnamed-java-app" + operationName "test" + resourceName "test" + errored false + parent() + } + span(1) { + serviceName "twilio-sdk" + operationName "twilio.sdk" + resourceName "api.v2010.account.MessageCreator.createAsync" + spanType DDSpanTypes.HTTP_CLIENT + errored false + } + span(2) { + serviceName "twilio-sdk" + operationName "twilio.sdk" + resourceName "api.v2010.account.MessageCreator.create" + spanType DDSpanTypes.HTTP_CLIENT + errored false + } + } + } + } +} diff --git a/dd-java-agent/instrumentation/twilio/twilio.gradle b/dd-java-agent/instrumentation/twilio/twilio.gradle new file mode 100644 index 0000000000..48ed0329ac --- /dev/null +++ b/dd-java-agent/instrumentation/twilio/twilio.gradle @@ -0,0 +1,25 @@ +muzzle { + pass { + group = 'com.twilio.sdk' + module = 'twilio' + versions = "(,)" + } +} + +apply from: "${rootDir}/gradle/java.gradle" + +dependencies { + compileOnly group: 'com.twilio.sdk', name: 'twilio', version: '7.36.2' + + compile project(':dd-java-agent:agent-tooling') + + compile deps.bytebuddy + compile deps.opentracing + annotationProcessor deps.autoservice + implementation deps.autoservice + + testCompile group: 'com.twilio.sdk', name: 'twilio', version: '7.36.2' + testCompile project(':dd-java-agent:testing') + testCompile project(':dd-java-agent:instrumentation:java-concurrent') + testCompile group: 'org.objenesis', name: 'objenesis', version: '3.0.1' +} diff --git a/settings.gradle b/settings.gradle index b57a5f08bf..1f594115e2 100644 --- a/settings.gradle +++ b/settings.gradle @@ -83,6 +83,7 @@ include ':dd-java-agent:instrumentation:spring-webflux' include ':dd-java-agent:instrumentation:spymemcached-2.12' include ':dd-java-agent:instrumentation:tomcat-classloading' include ':dd-java-agent:instrumentation:trace-annotation' +include ':dd-java-agent:instrumentation:twilio' include ':dd-java-agent:instrumentation:vertx' // benchmark @@ -99,3 +100,4 @@ def setBuildFile(project) { } setBuildFile(rootProject) +