Play Instrumentation

This commit is contained in:
Andrew Kent 2018-03-28 10:26:57 -07:00
parent 2fce4de1c5
commit 772872bcb5
5 changed files with 454 additions and 0 deletions

View File

@ -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'
}

View File

@ -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<Result> 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<Map.Entry<String, String>> iterator() {
final scala.collection.Map scalaMap = request.headers().toSimpleMap();
final Map<String, String> javaMap = new HashMap<>(scalaMap.size());
final scala.collection.Iterator<Tuple2<String, String>> scalaIterator = scalaMap.iterator();
while (scalaIterator.hasNext()) {
final Tuple2<String, String> 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<Throwable, Object> {
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<String, Object> logsForException(Throwable throwable) {
final Map<String, Object> 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<Result, Result> {
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;
}
}
}

View File

@ -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"
}
}

View File

@ -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 {}

View File

@ -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'