diff --git a/dd-java-agent/instrumentation/play/play.gradle b/dd-java-agent/instrumentation/play/play.gradle new file mode 100644 index 0000000000..3cbdedafeb --- /dev/null +++ b/dd-java-agent/instrumentation/play/play.gradle @@ -0,0 +1,21 @@ +apply from: "${rootDir}/gradle/java.gradle" +apply from: "${rootDir}/gradle/test-with-scala.gradle" + +// TODO: Rename to play-{version} + +dependencies { + compileOnly group: 'com.typesafe.play', name: 'play_2.12', version: '2.6.0' + + compile project(':dd-trace-api') + compile project(':dd-java-agent:agent-tooling') + compile deps.bytebuddy + compile deps.opentracing + compile deps.autoservice + + testCompile group: 'com.typesafe.play', name: 'play_2.12', version: '2.6.0' + testCompile group: 'com.typesafe.play', name: 'play-test_2.12', version: '2.6.0' + testCompile project(':dd-java-agent:testing') + testCompile project(':dd-java-agent:instrumentation:java-concurrent') + testCompile project(':dd-java-agent:instrumentation:trace-annotation') + testCompile group: 'com.squareup.okhttp3', name: 'okhttp', version: '3.6.0' +} diff --git a/dd-java-agent/instrumentation/play/src/main/java/datadog/trace/instrumentation/play/PlayInstrumentation.java b/dd-java-agent/instrumentation/play/src/main/java/datadog/trace/instrumentation/play/PlayInstrumentation.java new file mode 100644 index 0000000000..7d1f998988 --- /dev/null +++ b/dd-java-agent/instrumentation/play/src/main/java/datadog/trace/instrumentation/play/PlayInstrumentation.java @@ -0,0 +1,217 @@ +package datadog.trace.instrumentation.play; + +import static net.bytebuddy.matcher.ElementMatchers.*; + +import akka.japi.JavaPartialFunction; +import com.google.auto.service.AutoService; +import datadog.trace.agent.tooling.DDAdvice; +import datadog.trace.agent.tooling.DDTransformers; +import datadog.trace.agent.tooling.HelperInjector; +import datadog.trace.agent.tooling.Instrumenter; +import datadog.trace.api.DDSpanTypes; +import datadog.trace.api.DDTags; +import io.opentracing.Scope; +import io.opentracing.Span; +import io.opentracing.SpanContext; +import io.opentracing.propagation.Format; +import io.opentracing.propagation.TextMap; +import io.opentracing.tag.Tags; +import io.opentracing.util.GlobalTracer; +import java.io.PrintWriter; +import java.io.StringWriter; +import java.util.*; +import lombok.extern.slf4j.Slf4j; +import net.bytebuddy.agent.builder.AgentBuilder; +import net.bytebuddy.asm.Advice; +import org.slf4j.LoggerFactory; +import play.api.mvc.Action; +import play.api.mvc.Request; +import play.api.mvc.Result; +import play.routing.HandlerDef; +import play.routing.Router; +import scala.Function1; +import scala.Option; +import scala.Tuple2; +import scala.concurrent.Future; + +@Slf4j +@AutoService(Instrumenter.class) +public final class PlayInstrumentation extends Instrumenter.Configurable { + private static final HelperInjector PLAY_HELPERS = + new HelperInjector( + PlayInstrumentation.class.getName() + "$RequestCallback", + PlayInstrumentation.class.getName() + "$RequestError", + PlayInstrumentation.class.getName() + "$PlayHeaders"); + + public PlayInstrumentation() { + super("play"); + } + + @Override + protected boolean defaultEnabled() { + return false; + } + + @Override + public AgentBuilder apply(final AgentBuilder agentBuilder) { + return agentBuilder + .type(hasSuperType(named("play.api.mvc.Action"))) + .and( + declaresMethod( + named("executionContext").and(returns(named("scala.concurrent.ExecutionContext"))))) + .transform(PLAY_HELPERS) + .transform(DDTransformers.defaultTransformers()) + .transform( + DDAdvice.create() + .advice( + named("apply") + .and(takesArgument(0, named("play.api.mvc.Request"))) + .and(returns(named("scala.concurrent.Future"))), + PlayAdvice.class.getName())) + .asDecorator(); + } + + public static class PlayAdvice { + @Advice.OnMethodEnter(suppress = Throwable.class) + public static Scope startSpan(@Advice.Argument(0) final Request req) { + // TODO + // begin tracking across threads + + if (GlobalTracer.get().activeSpan() == null) { + final SpanContext extractedContext; + if (GlobalTracer.get().scopeManager().active() == null) { + extractedContext = + GlobalTracer.get().extract(Format.Builtin.HTTP_HEADERS, new PlayHeaders(req)); + } else { + extractedContext = null; + } + return GlobalTracer.get() + .buildSpan("play.request") + .asChildOf(extractedContext) + .startActive(false); + } else { + // An upstream framework (e.g. akka-http, netty) has already started the span. + // Do not extract the context. + return GlobalTracer.get().buildSpan("play.request").startActive(false); + } + } + + @Advice.OnMethodExit(onThrowable = Throwable.class, suppress = Throwable.class) + public static void stopTraceOnResponse( + @Advice.Enter final Scope scope, + @Advice.This final Object thisAction, + @Advice.Thrown final Throwable throwable, + @Advice.Argument(0) final Request req, + @Advice.Return(readOnly = false) Future responseFuture) { + // more about routes here: https://github.com/playframework/playframework/blob/master/documentation/manual/releases/release26/migration26/Migration26.md + final Option handlerOption = req.attrs().get(Router.Attrs.HANDLER_DEF.underlying()); + if (!handlerOption.isEmpty()) { + final HandlerDef handlerDef = (HandlerDef) handlerOption.get(); + scope.span().setTag(Tags.HTTP_URL.getKey(), handlerDef.path()); + scope.span().setOperationName(handlerDef.path()); + scope.span().setTag(DDTags.RESOURCE_NAME, req.method() + " " + handlerDef.path()); + } + scope.span().setTag(Tags.SPAN_KIND.getKey(), Tags.SPAN_KIND_SERVER); + scope.span().setTag(Tags.HTTP_METHOD.getKey(), req.method()); + scope.span().setTag(DDTags.SPAN_TYPE, DDSpanTypes.WEB_SERVLET); + scope.span().setTag(Tags.COMPONENT.getKey(), "play-action"); + + if (throwable == null) { + responseFuture.onFailure( + new RequestError(scope.span()), ((Action) thisAction).executionContext()); + responseFuture = + responseFuture.map( + new RequestCallback(scope.span()), ((Action) thisAction).executionContext()); + } else { + RequestError.onError(scope.span(), throwable); + scope.span().finish(); + } + scope.close(); + } + } + + public static class PlayHeaders implements TextMap { + private final Request request; + + public PlayHeaders(Request request) { + this.request = request; + } + + @Override + public Iterator> iterator() { + final scala.collection.Map scalaMap = request.headers().toSimpleMap(); + final Map javaMap = new HashMap<>(scalaMap.size()); + final scala.collection.Iterator> scalaIterator = scalaMap.iterator(); + while (scalaIterator.hasNext()) { + final Tuple2 tuple = scalaIterator.next(); + javaMap.put(tuple._1(), tuple._2()); + } + return javaMap.entrySet().iterator(); + } + + @Override + public void put(String s, String s1) { + throw new IllegalStateException("play headers can only be extracted"); + } + } + + public static class RequestError extends JavaPartialFunction { + private final Span span; + + public RequestError(Span span) { + this.span = span; + } + + @Override + public Object apply(Throwable t, boolean isCheck) throws Exception { + try { + onError(span, t); + } catch (Throwable t2) { + LoggerFactory.getLogger(RequestCallback.class).debug("error in play instrumentation", t); + } + span.finish(); + return null; + } + + public static void onError(final Span span, final Throwable t) { + Tags.ERROR.set(span, Boolean.TRUE); + span.log(logsForException(t)); + Tags.HTTP_STATUS.set(span, 500); + } + + public static Map logsForException(Throwable throwable) { + final Map errorLogs = new HashMap<>(4); + errorLogs.put("event", Tags.ERROR.getKey()); + errorLogs.put("error.kind", throwable.getClass().getName()); + errorLogs.put("error.object", throwable); + + errorLogs.put("message", throwable.getMessage()); + + final StringWriter sw = new StringWriter(); + throwable.printStackTrace(new PrintWriter(sw)); + errorLogs.put("stack", sw.toString()); + + return errorLogs; + } + } + + public static class RequestCallback implements Function1 { + private final Span span; + + public RequestCallback(Span span) { + this.span = span; + } + + public Result apply(Result result) { + // TODO + // stop tracking across threads + try { + Tags.HTTP_STATUS.set(span, result.header().status()); + } catch (Throwable t) { + LoggerFactory.getLogger(RequestCallback.class).debug("error in play instrumentation", t); + } + span.finish(); + return result; + } + } +} diff --git a/dd-java-agent/instrumentation/play/src/test/groovy/PlayTest.groovy b/dd-java-agent/instrumentation/play/src/test/groovy/PlayTest.groovy new file mode 100644 index 0000000000..fb89ffcdf3 --- /dev/null +++ b/dd-java-agent/instrumentation/play/src/test/groovy/PlayTest.groovy @@ -0,0 +1,151 @@ +import datadog.opentracing.DDSpan +import datadog.trace.agent.test.AgentTestRunner +import okhttp3.OkHttpClient +import okhttp3.Request +import play.api.test.TestServer +import play.test.Helpers +import spock.lang.Shared + +class PlayTest extends AgentTestRunner { + static { + System.setProperty("dd.integration.java_concurrent.enabled", "true") + System.setProperty("dd.integration.play.enabled", "true") + } + + @Shared + TestServer testServer + + def setupSpec() { + testServer = Helpers.testServer(9080, PlayTestUtils.buildTestApp()) + testServer.start() + } + + def cleanupSpec() { + testServer.stop() + } + + @Override + void afterTest() { + // Ignore failures to instrument sun proxy classes + } + + def "request traces" () { + setup: + OkHttpClient client = new OkHttpClient.Builder().build() + def request = new Request.Builder() + .url("http://localhost:9080/helloplay/spock") + .header("x-datadog-trace-id", "123") + .header("x-datadog-parent-id", "456") + .get() + .build() + def response = client.newCall(request).execute() + TEST_WRITER.waitForTraces(1) + DDSpan[] playTrace = TEST_WRITER.get(0) + DDSpan root = playTrace[0] + + expect: + testServer != null + response.code() == 200 + response.body().string() == "hello spock" + + // async work is linked to play trace + playTrace.size() == 2 + playTrace[1].operationName == 'TracedWork$.doWork' + + root.traceId == 123 + root.parentId == 456 + root.serviceName == "unnamed-java-app" + root.operationName == "/helloplay/:from" + root.resourceName == "GET /helloplay/:from" + !root.context().getErrorFlag() + root.context().tags["http.status_code"] == 200 + root.context().tags["http.url"] == "/helloplay/:from" + root.context().tags["http.method"] == "GET" + root.context().tags["span.kind"] == "server" + root.context().tags["component"] == "play-action" + } + + def "5xx errors trace" () { + setup: + OkHttpClient client = new OkHttpClient.Builder().build() + def request = new Request.Builder() + .url("http://localhost:9080/make-error") + .get() + .build() + def response = client.newCall(request).execute() + TEST_WRITER.waitForTraces(1) + DDSpan[] playTrace = TEST_WRITER.get(0) + DDSpan root = playTrace[0] + + expect: + testServer != null + response.code() == 500 + + root.serviceName == "unnamed-java-app" + root.operationName == "/make-error" + root.resourceName == "GET /make-error" + root.context().getErrorFlag() + root.context().tags["http.status_code"] == 500 + root.context().tags["http.url"] == "/make-error" + root.context().tags["http.method"] == "GET" + root.context().tags["span.kind"] == "server" + root.context().tags["component"] == "play-action" + } + + def "error thrown in request" () { + setup: + OkHttpClient client = new OkHttpClient.Builder().build() + def request = new Request.Builder() + .url("http://localhost:9080/exception") + .get() + .build() + def response = client.newCall(request).execute() + TEST_WRITER.waitForTraces(1) + DDSpan[] playTrace = TEST_WRITER.get(0) + DDSpan root = playTrace[0] + + expect: + testServer != null + response.code() == 500 + + root.context().getErrorFlag() + root.context().tags["error.msg"] == "oh no" + root.context().tags["error.type"] == RuntimeException.getName() + + root.serviceName == "unnamed-java-app" + root.operationName == "/exception" + root.resourceName == "GET /exception" + root.context().tags["http.status_code"] == 500 + root.context().tags["http.url"] == "/exception" + root.context().tags["http.method"] == "GET" + root.context().tags["span.kind"] == "server" + root.context().tags["component"] == "play-action" + } + + def "4xx errors trace" () { + setup: + OkHttpClient client = new OkHttpClient.Builder().build() + def request = new Request.Builder() + .url("http://localhost:9080/nowhere") + .get() + .build() + def response = client.newCall(request).execute() + TEST_WRITER.waitForTraces(1) + DDSpan[] playTrace = TEST_WRITER.get(0) + DDSpan root = playTrace[0] + + expect: + testServer != null + response.code() == 404 + + root.serviceName == "unnamed-java-app" + root.operationName == "play.request" + root.resourceName == "404" + !root.context().getErrorFlag() + root.context().tags["http.status_code"] == 404 + root.context().tags["http.url"] == null + root.context().tags["http.method"] == "GET" + root.context().tags["span.kind"] == "server" + root.context().tags["component"] == "play-action" + } +} diff --git a/dd-java-agent/instrumentation/play/src/test/scala/PlayTestUtils.scala b/dd-java-agent/instrumentation/play/src/test/scala/PlayTestUtils.scala new file mode 100644 index 0000000000..93fb96dd56 --- /dev/null +++ b/dd-java-agent/instrumentation/play/src/test/scala/PlayTestUtils.scala @@ -0,0 +1,64 @@ +import play.api.mvc.Action +import play.api.routing.{HandlerDef, Router} +import play.api.mvc._ +import play.api.routing.sird._ +import java.lang.reflect.Field + +import datadog.trace.api.Trace + +import scala.concurrent.{Await, Future} +import scala.concurrent.duration._ + + +object PlayTestUtils { + def buildTestApp(): play.Application = { + // build play.api.Application with desired setting and pass into play.Application for testing + val apiApp :play.api.Application = new play.api.inject.guice.GuiceApplicationBuilder() + .requireAtInjectOnConstructors(true) + .router( + Router.from { + case GET(p"/helloplay/$from") => Action { req: RequestHeader => + HandlerSetter.setHandler(req, "/helloplay/:from") + val f: Future[String] = Future[String] { + TracedWork.doWork() + from + }(Action.executionContext) + Results.Ok(s"hello " + Await.result(f, 5 seconds)) + } + case GET(p"/make-error") => Action { req: RequestHeader => + HandlerSetter.setHandler(req, "/make-error") + Results.InternalServerError("Really sorry...") + } + case GET(p"/exception") => Action { req: RequestHeader => + HandlerSetter.setHandler(req, "/exception") + if (System.currentTimeMillis() > 0) { + throw new RuntimeException("oh no") + } + Results.Ok("hello") + } + case _ => Action { + Results.NotFound("Sorry..") + } + }) + .build() + + return new play.DefaultApplication(apiApp, new play.inject.guice.GuiceApplicationBuilder().build().injector()) + } +} + +object TracedWork { + @Trace + def doWork(): Unit = { + } +} + +object HandlerSetter { + def setHandler(req: RequestHeader, path: String): Unit = { + val f: Field = req.getClass().getDeclaredField("attrs") + f.setAccessible(true) + f.set(req, req.attrs.updated(play.routing.Router.Attrs.HANDLER_DEF.underlying(), new HandlerDef(null, null, null, null, null, null, path, null, null))) + f.setAccessible(false) + } +} + +class PlayTestUtils {} diff --git a/settings.gradle b/settings.gradle index 4650010a19..e2545e5ee2 100644 --- a/settings.gradle +++ b/settings.gradle @@ -30,6 +30,7 @@ include ':dd-java-agent:instrumentation:mongo-3.1' include ':dd-java-agent:instrumentation:mongo-async-3.3' include ':dd-java-agent:instrumentation:okhttp-3' include ':dd-java-agent:instrumentation:osgi-classloading' +include ':dd-java-agent:instrumentation:play' include ':dd-java-agent:instrumentation:servlet-2' include ':dd-java-agent:instrumentation:servlet-3' include ':dd-java-agent:instrumentation:spring-web'