Merge pull request #430 from DataDog/tyler/spring-controllers

Add span representing the spring web controller execution

dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/tooling/AgentInstaller.java

@@ -68,6 +68,7 @@ public class AgentInstaller {
             .or(nameStartsWith("org.groovy."))
             .or(nameStartsWith("com.p6spy."))
             .or(nameStartsWith("org.slf4j."))
+            .or(nameStartsWith("com.newrelic."))
             .or(nameContains("javassist"))
             .or(nameContains(".asm."))
             .or(nameMatches("com\\.mchange\\.v2\\.c3p0\\..*Proxy"));

dd-java-agent/instrumentation/servlet-2/src/main/java/datadog/trace/instrumentation/servlet2/Servlet2Advice.java

@@ -39,6 +39,9 @@ public class Servlet2Advice {
         GlobalTracer.get()
             .buildSpan("servlet.request")
             .asChildOf(extractedContext)
+            .withTag(Tags.COMPONENT.getKey(), "java-web-servlet")
+            .withTag(Tags.HTTP_METHOD.getKey(), httpServletRequest.getMethod())
+            .withTag(Tags.HTTP_URL.getKey(), httpServletRequest.getRequestURL().toString())
             .withTag(Tags.SPAN_KIND.getKey(), Tags.SPAN_KIND_SERVER)
             .withTag(DDTags.SPAN_TYPE, DDSpanTypes.WEB_SERVLET)
             .withTag("servlet.context", httpServletRequest.getContextPath())
@@ -48,12 +51,8 @@ public class Servlet2Advice {
       ((TraceScope) scope).setAsyncPropagation(true);
     }
 
-    final Span span = scope.span();
-    Tags.COMPONENT.set(span, "java-web-servlet");
-    Tags.HTTP_METHOD.set(span, httpServletRequest.getMethod());
-    Tags.HTTP_URL.set(span, httpServletRequest.getRequestURL().toString());
     if (httpServletRequest.getUserPrincipal() != null) {
-      span.setTag("user.principal", httpServletRequest.getUserPrincipal().getName());
+      scope.span().setTag("user.principal", httpServletRequest.getUserPrincipal().getName());
     }
     return scope;
   }

dd-java-agent/instrumentation/servlet-3/src/main/java/datadog/trace/instrumentation/servlet3/Servlet3Advice.java

@@ -39,6 +39,9 @@ public class Servlet3Advice {
         GlobalTracer.get()
             .buildSpan("servlet.request")
             .asChildOf(extractedContext)
+            .withTag(Tags.COMPONENT.getKey(), "java-web-servlet")
+            .withTag(Tags.HTTP_METHOD.getKey(), httpServletRequest.getMethod())
+            .withTag(Tags.HTTP_URL.getKey(), httpServletRequest.getRequestURL().toString())
             .withTag(Tags.SPAN_KIND.getKey(), Tags.SPAN_KIND_SERVER)
             .withTag(DDTags.SPAN_TYPE, DDSpanTypes.WEB_SERVLET)
             .withTag("servlet.context", httpServletRequest.getContextPath())
@@ -48,12 +51,8 @@ public class Servlet3Advice {
       ((TraceScope) scope).setAsyncPropagation(true);
     }
 
-    final Span span = scope.span();
-    Tags.COMPONENT.set(span, "java-web-servlet");
-    Tags.HTTP_METHOD.set(span, httpServletRequest.getMethod());
-    Tags.HTTP_URL.set(span, httpServletRequest.getRequestURL().toString());
     if (httpServletRequest.getUserPrincipal() != null) {
-      span.setTag("user.principal", httpServletRequest.getUserPrincipal().getName());
+      scope.span().setTag("user.principal", httpServletRequest.getUserPrincipal().getName());
     }
     return scope;
   }

dd-java-agent/instrumentation/spring-web/src/main/java/datadog/trace/instrumentation/springweb/DispatcherServletInstrumentation.java

@@ -0,0 +1,99 @@
+package datadog.trace.instrumentation.springweb;
+
+import static io.opentracing.log.Fields.ERROR_OBJECT;
+import static net.bytebuddy.matcher.ElementMatchers.isMethod;
+import static net.bytebuddy.matcher.ElementMatchers.isProtected;
+import static net.bytebuddy.matcher.ElementMatchers.nameStartsWith;
+import static net.bytebuddy.matcher.ElementMatchers.named;
+import static net.bytebuddy.matcher.ElementMatchers.takesArgument;
+
+import com.google.auto.service.AutoService;
+import datadog.trace.agent.tooling.Instrumenter;
+import io.opentracing.Scope;
+import io.opentracing.Span;
+import io.opentracing.Tracer;
+import io.opentracing.tag.Tags;
+import io.opentracing.util.GlobalTracer;
+import java.util.Collections;
+import java.util.HashMap;
+import java.util.Map;
+import net.bytebuddy.asm.Advice;
+import net.bytebuddy.description.type.TypeDescription;
+import net.bytebuddy.matcher.ElementMatcher;
+import org.springframework.web.servlet.ModelAndView;
+
+@AutoService(Instrumenter.class)
+public final class DispatcherServletInstrumentation extends Instrumenter.Default {
+
+  public DispatcherServletInstrumentation() {
+    super("spring-web");
+  }
+
+  @Override
+  public ElementMatcher<TypeDescription> typeMatcher() {
+    return named("org.springframework.web.servlet.DispatcherServlet");
+  }
+
+  @Override
+  public Map<ElementMatcher, String> transformers() {
+    final Map<ElementMatcher, String> transformers = new HashMap<>();
+    transformers.put(
+        isMethod()
+            .and(isProtected())
+            .and(named("render"))
+            .and(takesArgument(0, named("org.springframework.web.servlet.ModelAndView"))),
+        DispatcherAdvice.class.getName());
+    transformers.put(
+        isMethod()
+            .and(isProtected())
+            .and(nameStartsWith("processHandlerException"))
+            .and(takesArgument(3, Exception.class)),
+        ErrorHandlerAdvice.class.getName());
+    return transformers;
+  }
+
+  public static class DispatcherAdvice {
+
+    @Advice.OnMethodEnter(suppress = Throwable.class)
+    public static Scope startSpan(@Advice.Argument(0) final ModelAndView mv) {
+
+      final Tracer.SpanBuilder builder =
+          GlobalTracer.get()
+              .buildSpan("response.render")
+              .withTag(Tags.COMPONENT.getKey(), "spring-webmvc");
+      if (mv.getViewName() != null) {
+        builder.withTag("view.name", mv.getViewName());
+      }
+      if (mv.getView() != null) {
+        builder.withTag("view.type", mv.getView().getClass().getName());
+      }
+      return builder.startActive(true);
+    }
+
+    @Advice.OnMethodExit(onThrowable = Throwable.class, suppress = Throwable.class)
+    public static void stopSpan(
+        @Advice.Enter final Scope scope, @Advice.Thrown final Throwable throwable) {
+
+      if (throwable != null) {
+        final Span span = scope.span();
+        Tags.ERROR.set(span, true);
+        span.log(Collections.singletonMap(ERROR_OBJECT, throwable));
+      }
+      scope.close();
+    }
+  }
+
+  public static class ErrorHandlerAdvice {
+    @Advice.OnMethodEnter(suppress = Throwable.class)
+    public static void nameResource(@Advice.Argument(3) final Exception exception) {
+      final Scope scope = GlobalTracer.get().scopeManager().active();
+      if (scope != null && exception != null) {
+        final Span span = scope.span();
+        span.log(Collections.singletonMap(ERROR_OBJECT, exception));
+        // We want to capture the stacktrace, but that doesn't mean it should be an error.
+        // We rely on a decorator to set the error state based on response code. (5xx -> error)
+        Tags.ERROR.set(span, false);
+      }
+    }
+  }
+}

dd-java-agent/instrumentation/spring-web/src/main/java/datadog/trace/instrumentation/springweb/HandlerAdapterInstrumentation.java

@@ -0,0 +1,144 @@
+package datadog.trace.instrumentation.springweb;
+
+import static datadog.trace.agent.tooling.ByteBuddyElementMatchers.safeHasSuperType;
+import static datadog.trace.agent.tooling.ClassLoaderMatcher.classLoaderHasClassWithField;
+import static io.opentracing.log.Fields.ERROR_OBJECT;
+import static net.bytebuddy.matcher.ElementMatchers.isInterface;
+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.takesArgument;
+import static net.bytebuddy.matcher.ElementMatchers.takesArguments;
+
+import com.google.auto.service.AutoService;
+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.tag.Tags;
+import io.opentracing.util.GlobalTracer;
+import java.lang.reflect.Method;
+import java.util.Collections;
+import java.util.Map;
+import javax.servlet.Servlet;
+import javax.servlet.http.HttpServletRequest;
+import net.bytebuddy.asm.Advice;
+import net.bytebuddy.description.type.TypeDescription;
+import net.bytebuddy.matcher.ElementMatcher;
+import org.springframework.web.HttpRequestHandler;
+import org.springframework.web.method.HandlerMethod;
+import org.springframework.web.servlet.HandlerMapping;
+import org.springframework.web.servlet.mvc.Controller;
+
+@AutoService(Instrumenter.class)
+public final class HandlerAdapterInstrumentation extends Instrumenter.Default {
+
+  public HandlerAdapterInstrumentation() {
+    super("spring-web");
+  }
+
+  @Override
+  public ElementMatcher<TypeDescription> typeMatcher() {
+    return not(isInterface())
+        .and(safeHasSuperType(named("org.springframework.web.servlet.HandlerAdapter")));
+  }
+
+  @Override
+  public ElementMatcher<ClassLoader> classLoaderMatcher() {
+    return classLoaderHasClassWithField(
+        "org.springframework.web.servlet.HandlerMapping", "BEST_MATCHING_PATTERN_ATTRIBUTE");
+  }
+
+  @Override
+  public Map<ElementMatcher, String> transformers() {
+    return Collections.<ElementMatcher, String>singletonMap(
+        isMethod()
+            .and(isPublic())
+            .and(nameStartsWith("handle"))
+            .and(takesArgument(0, named("javax.servlet.http.HttpServletRequest")))
+            .and(takesArguments(3)),
+        ControllerAdvice.class.getName());
+  }
+
+  public static class ControllerAdvice {
+
+    @Advice.OnMethodEnter(suppress = Throwable.class)
+    public static Scope nameResourceAndStartSpan(
+        @Advice.Argument(0) final HttpServletRequest request,
+        @Advice.Argument(2) final Object handler) {
+      // Name the parent span based on the matching pattern
+      // This is likely the servlet.request span.
+      final Scope parentScope = GlobalTracer.get().scopeManager().active();
+      if (parentScope != null && request != null) {
+        final String method = request.getMethod();
+        final Object bestMatchingPattern =
+            request.getAttribute(HandlerMapping.BEST_MATCHING_PATTERN_ATTRIBUTE);
+        if (method != null && bestMatchingPattern != null) {
+          final String resourceName = method + " " + bestMatchingPattern;
+          parentScope.span().setTag(DDTags.RESOURCE_NAME, resourceName);
+          parentScope.span().setTag(DDTags.SPAN_TYPE, DDSpanTypes.WEB_SERVLET);
+        }
+      }
+
+      // Now create a span for controller execution.
+
+      final Class<?> clazz;
+      final String methodName;
+
+      if (handler instanceof HandlerMethod) {
+        // name span based on the class and method name defined in the handler
+        final Method method = ((HandlerMethod) handler).getMethod();
+        clazz = method.getDeclaringClass();
+        methodName = method.getName();
+      } else if (handler instanceof HttpRequestHandler) {
+        // org.springframework.web.servlet.mvc.HttpRequestHandlerAdapter
+        clazz = handler.getClass();
+        methodName = "handleRequest";
+      } else if (handler instanceof Controller) {
+        // org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter
+        clazz = handler.getClass();
+        methodName = "handleRequest";
+      } else if (handler instanceof Servlet) {
+        // org.springframework.web.servlet.handler.SimpleServletHandlerAdapter
+        clazz = handler.getClass();
+        methodName = "service";
+      } else {
+        // perhaps org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter
+        clazz = handler.getClass();
+        methodName = "<annotation>";
+      }
+
+      String className = clazz.getSimpleName();
+      if (className.isEmpty()) {
+        className = clazz.getName();
+        if (clazz.getPackage() != null) {
+          final String pkgName = clazz.getPackage().getName();
+          if (!pkgName.isEmpty()) {
+            className = clazz.getName().replace(pkgName, "").substring(1);
+          }
+        }
+      }
+
+      final String operationName = className + "." + methodName;
+
+      return GlobalTracer.get()
+          .buildSpan(operationName)
+          .withTag(Tags.COMPONENT.getKey(), "spring-web-controller")
+          .startActive(true);
+    }
+
+    @Advice.OnMethodExit(onThrowable = Throwable.class, suppress = Throwable.class)
+    public static void stopSpan(
+        @Advice.Enter final Scope scope, @Advice.Thrown final Throwable throwable) {
+      if (throwable != null) {
+        final Span span = scope.span();
+        Tags.ERROR.set(span, true);
+        span.log(Collections.singletonMap(ERROR_OBJECT, throwable));
+      }
+      scope.close();
+    }
+  }
+}

dd-java-agent/instrumentation/spring-web/src/main/java/datadog/trace/instrumentation/springweb/SpringWebInstrumentation.java

@@ -1,118 +0,0 @@
-package datadog.trace.instrumentation.springweb;
-
-import static datadog.trace.agent.tooling.ByteBuddyElementMatchers.safeHasSuperType;
-import static datadog.trace.agent.tooling.ClassLoaderMatcher.classLoaderHasClassWithField;
-import static io.opentracing.log.Fields.ERROR_OBJECT;
-import static net.bytebuddy.matcher.ElementMatchers.isInterface;
-import static net.bytebuddy.matcher.ElementMatchers.isMethod;
-import static net.bytebuddy.matcher.ElementMatchers.isProtected;
-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.takesArgument;
-
-import com.google.auto.service.AutoService;
-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.tag.Tags;
-import io.opentracing.util.GlobalTracer;
-import java.util.Collections;
-import java.util.HashMap;
-import java.util.Map;
-import javax.servlet.http.HttpServletRequest;
-import net.bytebuddy.asm.Advice;
-import net.bytebuddy.matcher.ElementMatcher;
-import org.springframework.web.servlet.HandlerMapping;
-
-@AutoService(Instrumenter.class)
-public final class SpringWebInstrumentation extends Instrumenter.Default {
-
-  public SpringWebInstrumentation() {
-    super("spring-web");
-  }
-
-  @Override
-  public ElementMatcher typeMatcher() {
-    return not(isInterface())
-        .and(safeHasSuperType(named("org.springframework.web.servlet.HandlerAdapter")));
-  }
-
-  @Override
-  public ElementMatcher<? super ClassLoader> classLoaderMatcher() {
-    return classLoaderHasClassWithField(
-        "org.springframework.web.servlet.HandlerMapping", "BEST_MATCHING_PATTERN_ATTRIBUTE");
-  }
-
-  @Override
-  public Map<ElementMatcher, String> transformers() {
-    final Map<ElementMatcher, String> transformers = new HashMap<>();
-    transformers.put(
-        isMethod()
-            .and(isPublic())
-            .and(nameStartsWith("handle"))
-            .and(takesArgument(0, named("javax.servlet.http.HttpServletRequest"))),
-        SpringWebNamingAdvice.class.getName());
-    return transformers;
-  }
-
-  @AutoService(Instrumenter.class)
-  public static class DispatcherServletInstrumentation extends Default {
-
-    public DispatcherServletInstrumentation() {
-      super("spring-web");
-    }
-
-    @Override
-    public ElementMatcher typeMatcher() {
-      return not(isInterface()).and(named("org.springframework.web.servlet.DispatcherServlet"));
-    }
-
-    @Override
-    public Map<ElementMatcher, String> transformers() {
-      final Map<ElementMatcher, String> transformers = new HashMap<>();
-      transformers.put(
-          isMethod()
-              .and(isProtected())
-              .and(nameStartsWith("processHandlerException"))
-              .and(takesArgument(3, Exception.class)),
-          SpringWebErrorHandlerAdvice.class.getName());
-      return transformers;
-    }
-  }
-
-  public static class SpringWebNamingAdvice {
-
-    @Advice.OnMethodEnter(suppress = Throwable.class)
-    public static void nameResource(@Advice.Argument(0) final HttpServletRequest request) {
-      final Scope scope = GlobalTracer.get().scopeManager().active();
-      if (scope != null && request != null) {
-        final String method = request.getMethod();
-        final Object bestMatchingPattern =
-            request.getAttribute(HandlerMapping.BEST_MATCHING_PATTERN_ATTRIBUTE);
-        if (method != null && bestMatchingPattern != null) {
-          final String resourceName = method + " " + bestMatchingPattern;
-          scope.span().setTag(DDTags.RESOURCE_NAME, resourceName);
-          scope.span().setTag(DDTags.SPAN_TYPE, DDSpanTypes.WEB_SERVLET);
-        }
-      }
-    }
-  }
-
-  public static class SpringWebErrorHandlerAdvice {
-    @Advice.OnMethodEnter(suppress = Throwable.class)
-    public static void nameResource(@Advice.Argument(3) final Exception exception) {
-      final Scope scope = GlobalTracer.get().scopeManager().active();
-      if (scope != null && exception != null) {
-        final Span span = scope.span();
-        span.log(Collections.singletonMap(ERROR_OBJECT, exception));
-        // We want to capture the stacktrace, but that doesn't mean it should be an error.
-        // We rely on a decorator to set the error state based on response code. (5xx -> error)
-        Tags.ERROR.set(span, false);
-      }
-    }
-  }
-}

dd-java-agent/instrumentation/spring-web/src/test/groovy/test/SpringBootBasedTest.groovy

@@ -1,7 +1,10 @@
 package test
 
 import datadog.trace.agent.test.AgentTestRunner
+import datadog.trace.agent.test.TraceAssert
 import datadog.trace.api.DDSpanTypes
+import datadog.trace.api.DDTags
+import io.opentracing.tag.Tags
 import org.springframework.beans.factory.annotation.Autowired
 import org.springframework.boot.context.embedded.LocalServerPort
 import org.springframework.boot.test.context.SpringBootTest
@@ -10,6 +13,8 @@ import org.springframework.boot.test.web.client.TestRestTemplate
 import org.springframework.web.bind.MethodArgumentNotValidException
 import org.springframework.web.util.NestedServletException
 
+import static datadog.trace.agent.test.ListWriterAssert.assertTraces
+
 @SpringBootTest(webEnvironment = WebEnvironment.RANDOM_PORT)
 class SpringBootBasedTest extends AgentTestRunner {
 
@@ -25,218 +30,259 @@ class SpringBootBasedTest extends AgentTestRunner {
     restTemplate.getForObject("http://localhost:$port/", String) == "Hello World"
 
     and:
-    TEST_WRITER.waitForTraces(1)
+    assertTraces(TEST_WRITER, 1) {
-    TEST_WRITER.size() == 1
+      trace(0, 2) {
+        span(0) {
+          operationName "servlet.request"
+          resourceName "GET /"
+          spanType DDSpanTypes.WEB_SERVLET
+          parent()
+          errored false
+          tags {
+            "http.url" "http://localhost:$port/"
+            "http.method" "GET"
+            "span.kind" "server"
+            "span.type" "web"
+            "component" "java-web-servlet"
+            "http.status_code" 200
+            defaultTags()
+          }
+        }
+        controllerSpan(it, 1, "TestController.greeting")
+      }
+    }
   }
 
   def "generates spans"() {
     expect:
     restTemplate.getForObject("http://localhost:$port/param/asdf1234/", String) == "Hello asdf1234"
-    TEST_WRITER.waitForTraces(1)
-    TEST_WRITER.size() == 1
 
-    def trace = TEST_WRITER.firstTrace()
+    assertTraces(TEST_WRITER, 1) {
-    trace.size() == 1
+      trace(0, 2) {
-    def span = trace[0]
+        span(0) {
-
+          operationName "servlet.request"
-    span.context().operationName == "servlet.request"
+          resourceName "GET /param/{parameter}/"
-    span.context().resourceName == "GET /param/{parameter}/"
+          spanType DDSpanTypes.WEB_SERVLET
-    span.context().spanType == DDSpanTypes.WEB_SERVLET
+          parent()
-    !span.context().getErrorFlag()
+          errored false
-    span.context().parentId == "0"
+          tags {
-    span.context().tags["http.url"] == "http://localhost:$port/param/asdf1234/"
+            "http.url" "http://localhost:$port/param/asdf1234/"
-    span.context().tags["http.method"] == "GET"
+            "http.method" "GET"
-    span.context().tags["span.kind"] == "server"
+            "span.kind" "server"
-    span.context().tags["span.type"] == "web"
+            "span.type" "web"
-    span.context().tags["component"] == "java-web-servlet"
+            "component" "java-web-servlet"
-    span.context().tags["http.status_code"] == 200
+            "http.status_code" 200
-    span.context().tags["thread.name"] != null
+            defaultTags()
-    span.context().tags["thread.id"] != null
+          }
-    span.context().tags.size() == 8
+        }
+        controllerSpan(it, 1, "TestController.withParam")
+      }
+    }
   }
 
   def "generates 404 spans"() {
+    setup:
     def response = restTemplate.getForObject("http://localhost:$port/invalid", Map)
+
     expect:
     response.get("status") == 404
     response.get("error") == "Not Found"
-    TEST_WRITER.waitForTraces(2)
-    TEST_WRITER.size() == 2
 
-    and: // trace 0
+    assertTraces(TEST_WRITER, 2) {
-    def trace0 = TEST_WRITER.get(0)
+      trace(0, 2) {
-    trace0.size() == 1
+        span(0) {
-    def span0 = trace0[0]
+          operationName "servlet.request"
-
+          resourceName "404"
-    span0.context().operationName == "servlet.request"
+          spanType DDSpanTypes.WEB_SERVLET
-    span0.context().resourceName == "404"
+          parent()
-    span0.context().spanType == DDSpanTypes.WEB_SERVLET
+          errored false
-    !span0.context().getErrorFlag()
+          tags {
-    span0.context().parentId == "0"
+            "http.url" "http://localhost:$port/invalid"
-    span0.context().tags["http.url"] == "http://localhost:$port/invalid"
+            "http.method" "GET"
-    span0.context().tags["http.method"] == "GET"
+            "span.kind" "server"
-    span0.context().tags["span.kind"] == "server"
+            "span.type" "web"
-    span0.context().tags["span.type"] == "web"
+            "component" "java-web-servlet"
-    span0.context().tags["component"] == "java-web-servlet"
+            "http.status_code" 404
-    span0.context().tags["http.status_code"] == 404
+            defaultTags()
-    span0.context().tags["thread.name"] != null
+          }
-    span0.context().tags["thread.id"] != null
+        }
-    span0.context().tags.size() == 8
+        controllerSpan(it, 1, "ResourceHttpRequestHandler.handleRequest")
-
+      }
-    and: // trace 1
+      trace(1, 2) {
-    def trace1 = TEST_WRITER.get(1)
+        span(0) {
-    trace1.size() == 1
+          operationName "servlet.request"
-    def span1 = trace1[0]
+          resourceName "404"
-
+          spanType DDSpanTypes.WEB_SERVLET
-    span1.context().operationName == "servlet.request"
+          parent()
-    span1.context().resourceName == "404"
+          errored false
-    span1.context().spanType == DDSpanTypes.WEB_SERVLET
+          tags {
-    !span1.context().getErrorFlag()
+            "http.url" "http://localhost:$port/error"
-    span1.context().parentId == "0"
+            "http.method" "GET"
-    span1.context().tags["http.url"] == "http://localhost:$port/error"
+            "span.kind" "server"
-    span1.context().tags["http.method"] == "GET"
+            "span.type" "web"
-    span1.context().tags["span.kind"] == "server"
+            "component" "java-web-servlet"
-    span1.context().tags["span.type"] == "web"
+            "http.status_code" 404
-    span1.context().tags["component"] == "java-web-servlet"
+            defaultTags()
-    span1.context().tags["http.status_code"] == 404
+          }
-    span1.context().tags["thread.name"] != null
+        }
-    span1.context().tags["thread.id"] != null
+        controllerSpan(it, 1, "BasicErrorController.error")
-    span1.context().tags.size() == 8
+      }
+    }
   }
 
   def "generates error spans"() {
-    expect:
+    setup:
     def response = restTemplate.getForObject("http://localhost:$port/error/qwerty/", Map)
+
+    expect:
     response.get("status") == 500
     response.get("error") == "Internal Server Error"
     response.get("exception") == "java.lang.RuntimeException"
     response.get("message") == "qwerty"
-    TEST_WRITER.waitForTraces(2)
-    TEST_WRITER.size() == 2
 
-    and: // trace 0
+    assertTraces(TEST_WRITER, 2) {
-    def trace0 = TEST_WRITER.get(0)
+      trace(0, 2) {
-    trace0.size() == 1
+        span(0) {
-    def span0 = trace0[0]
+          operationName "servlet.request"
-
+          resourceName "GET /error/{parameter}/"
-    span0.context().operationName == "servlet.request"
+          spanType DDSpanTypes.WEB_SERVLET
-    span0.context().resourceName == "GET /error/{parameter}/"
+          parent()
-    span0.context().spanType == DDSpanTypes.WEB_SERVLET
+          errored true
-    span0.context().getErrorFlag()
+          tags {
-    span0.context().parentId == "0"
+            "http.url" "http://localhost:$port/error/qwerty/"
-    span0.context().tags["http.url"] == "http://localhost:$port/error/qwerty/"
+            "http.method" "GET"
-    span0.context().tags["http.method"] == "GET"
+            "span.kind" "server"
-    span0.context().tags["span.kind"] == "server"
+            "span.type" "web"
-    span0.context().tags["span.type"] == "web"
+            "component" "java-web-servlet"
-    span0.context().tags["component"] == "java-web-servlet"
+            "http.status_code" 500
-    span0.context().tags["http.status_code"] == 500
+            errorTags NestedServletException, "Request processing failed; nested exception is java.lang.RuntimeException: qwerty"
-    span0.context().tags["thread.name"] != null
+            defaultTags()
-    span0.context().tags["thread.id"] != null
+          }
-    span0.context().tags["error"] == true
+        }
-    span0.context().tags["error.msg"] == "Request processing failed; nested exception is java.lang.RuntimeException: qwerty"
+        controllerSpan(it, 1, "TestController.withError", RuntimeException)
-    span0.context().tags["error.type"] == NestedServletException.getName()
+      }
-    span0.context().tags["error.stack"] != null
+      trace(1, 2) {
-    span0.context().tags.size() == 12
+        span(0) {
-
+          operationName "servlet.request"
-    and: // trace 1
+          resourceName "GET /error"
-    def trace1 = TEST_WRITER.get(1)
+          spanType DDSpanTypes.WEB_SERVLET
-    trace1.size() == 1
+          parent()
-    def span1 = trace1[0]
+          errored true
-
+          tags {
-    span1.context().operationName == "servlet.request"
+            "http.url" "http://localhost:$port/error"
-    span1.context().resourceName == "GET /error"
+            "http.method" "GET"
-    span1.context().spanType == DDSpanTypes.WEB_SERVLET
+            "span.kind" "server"
-    span1.context().parentId == "0"
+            "span.type" "web"
-    span1.context().tags["http.url"] == "http://localhost:$port/error"
+            "component" "java-web-servlet"
-    span1.context().tags["http.method"] == "GET"
+            "http.status_code" 500
-    span1.context().tags["span.kind"] == "server"
+            "error" true
-    span1.context().tags["span.type"] == "web"
+            defaultTags()
-    span1.context().tags["component"] == "java-web-servlet"
+          }
-    span1.context().tags["http.status_code"] == 500
+        }
-    span1.context().getErrorFlag()
+        controllerSpan(it, 1, "BasicErrorController.error")
-    span1.context().tags["thread.name"] != null
+      }
-    span1.context().tags["thread.id"] != null
+    }
-    span1.context().tags.size() == 9
   }
 
   def "validated form"() {
     expect:
     restTemplate.postForObject("http://localhost:$port/validated", new TestForm("bob", 20), String) == "Hello bob Person(Name: bob, Age: 20)"
-    TEST_WRITER.waitForTraces(1)
-    TEST_WRITER.size() == 1
 
-    def trace = TEST_WRITER.firstTrace()
+    assertTraces(TEST_WRITER, 1) {
-    trace.size() == 1
+      trace(0, 2) {
-    def span = trace[0]
+        span(0) {
-
+          operationName "servlet.request"
-    span.context().operationName == "servlet.request"
+          resourceName "POST /validated"
-    span.context().resourceName == "POST /validated"
+          spanType DDSpanTypes.WEB_SERVLET
-    span.context().spanType == DDSpanTypes.WEB_SERVLET
+          parent()
-    !span.context().getErrorFlag()
+          errored false
-    span.context().parentId == "0"
+          tags {
-    span.context().tags["http.url"] == "http://localhost:$port/validated"
+            "http.url" "http://localhost:$port/validated"
-    span.context().tags["http.method"] == "POST"
+            "http.method" "POST"
-    span.context().tags["span.kind"] == "server"
+            "span.kind" "server"
-    span.context().tags["span.type"] == "web"
+            "span.type" "web"
-    span.context().tags["component"] == "java-web-servlet"
+            "component" "java-web-servlet"
-    span.context().tags["http.status_code"] == 200
+            "http.status_code" 200
-    span.context().tags["thread.name"] != null
+            defaultTags()
-    span.context().tags["thread.id"] != null
+          }
-    span.context().tags.size() == 8
+        }
+        controllerSpan(it, 1, "TestController.withValidation")
+      }
+    }
   }
 
   def "invalid form"() {
-    expect:
+    setup:
     def response = restTemplate.postForObject("http://localhost:$port/validated", new TestForm("bill", 5), Map, Map)
+
+    expect:
     response.get("status") == 400
     response.get("error") == "Bad Request"
     response.get("exception") == "org.springframework.web.bind.MethodArgumentNotValidException"
     response.get("message") == "Validation failed for object='testForm'. Error count: 1"
-    TEST_WRITER.waitForTraces(2)
-    TEST_WRITER.size() == 2
 
-    and: // trace 0
+    assertTraces(TEST_WRITER, 2) {
-    def trace0 = TEST_WRITER.get(0)
+      trace(0, 2) {
-    trace0.size() == 1
+        span(0) {
-    def span0 = trace0[0]
+          operationName "servlet.request"
+          resourceName "POST /validated"
+          spanType DDSpanTypes.WEB_SERVLET
+          parent()
+          errored false
+          tags {
+            "http.url" "http://localhost:$port/validated"
+            "http.method" "POST"
+            "span.kind" "server"
+            "span.type" "web"
+            "component" "java-web-servlet"
+            "http.status_code" 400
+            "error" false
+            "error.msg" String
+            "error.type" MethodArgumentNotValidException.name
+            "error.stack" String
+            defaultTags()
+          }
+        }
+        controllerSpan(it, 1, "TestController.withValidation", MethodArgumentNotValidException)
+      }
+      trace(1, 2) {
+        span(0) {
+          operationName "servlet.request"
+          resourceName "POST /error"
+          spanType DDSpanTypes.WEB_SERVLET
+          parent()
+          errored false
+          tags {
+            "http.url" "http://localhost:$port/error"
+            "http.method" "POST"
+            "span.kind" "server"
+            "span.type" "web"
+            "component" "java-web-servlet"
+            "http.status_code" 400
+            defaultTags()
+          }
+        }
+        controllerSpan(it, 1, "BasicErrorController.error")
+      }
+    }
+  }
 
-    span0.context().operationName == "servlet.request"
+  def controllerSpan(TraceAssert trace, int index, String name, Class<Throwable> errorType = null) {
-    span0.context().resourceName == "POST /validated"
+    trace.span(index) {
-    span0.context().spanType == DDSpanTypes.WEB_SERVLET
+      serviceName "unnamed-java-app"
-    !span0.context().getErrorFlag() // This should be an error once we have the http status code decorator working.
+      operationName name
-    span0.context().parentId == "0"
+      resourceName name
-    span0.context().tags["http.url"] == "http://localhost:$port/validated"
+      childOf(trace.span(0))
-    span0.context().tags["http.method"] == "POST"
+      errored errorType != null
-    span0.context().tags["span.kind"] == "server"
+      tags {
-    span0.context().tags["span.type"] == "web"
+        "$DDTags.SPAN_TYPE" DDSpanTypes.WEB_SERVLET
-    span0.context().tags["component"] == "java-web-servlet"
+        "$Tags.COMPONENT.key" "spring-web-controller"
-    span0.context().tags["http.status_code"] == 400
+        if (errorType) {
-    span0.context().tags["thread.name"] != null
+          "error.msg" String
-    span0.context().tags["thread.id"] != null
+          errorTags(errorType)
-//    span0.context().tags["error"] == true // This should be an error once we have the http status code decorator working.
+        }
-    span0.context().tags["error.msg"].toString().startsWith("Validation failed")
+        defaultTags()
-    span0.context().tags["error.type"] == MethodArgumentNotValidException.getName()
+      }
-    span0.context().tags["error.stack"] != null
+    }
-    span0.context().tags.size() == 12
-
-    and: // trace 1
-    def trace1 = TEST_WRITER.get(1)
-    trace1.size() == 1
-    def span1 = trace1[0]
-
-    span1.context().operationName == "servlet.request"
-    span1.context().resourceName == "POST /error"
-    span1.context().spanType == DDSpanTypes.WEB_SERVLET
-    !span1.context().getErrorFlag()
-    span1.context().parentId == "0"
-    span1.context().tags["http.url"] == "http://localhost:$port/error"
-    span1.context().tags["http.method"] == "POST"
-    span1.context().tags["span.kind"] == "server"
-    span1.context().tags["span.type"] == "web"
-    span1.context().tags["component"] == "java-web-servlet"
-    span1.context().tags["http.status_code"] == 400
-    span1.context().tags["thread.name"] != null
-    span1.context().tags["thread.id"] != null
-    span1.context().tags.size() == 8
   }
 }

dd-trace-ot/src/main/java/datadog/opentracing/DDSpan.java

@@ -87,6 +87,7 @@ public class DDSpan implements Span, MutableSpan {
   private void finishAndAddToTrace(final long durationNano) {
     // ensure a min duration of 1
     if (this.durationNano.compareAndSet(0, Math.max(1, durationNano))) {
+      log.debug("Finished: {}", this);
       context.getTrace().addSpan(this);
     } else {
       log.debug("{} - already finished!", this);
@@ -149,7 +150,7 @@ public class DDSpan implements Span, MutableSpan {
    */
   @Override
   public final DDSpan setTag(final String tag, final String value) {
-    this.context().setTag(tag, (Object) value);
+    context().setTag(tag, (Object) value);
     return this;
   }
 
@@ -158,7 +159,7 @@ public class DDSpan implements Span, MutableSpan {
    */
   @Override
   public final DDSpan setTag(final String tag, final boolean value) {
-    this.context().setTag(tag, (Object) value);
+    context().setTag(tag, (Object) value);
     return this;
   }
 
@@ -167,7 +168,7 @@ public class DDSpan implements Span, MutableSpan {
    */
   @Override
   public final DDSpan setTag(final String tag, final Number value) {
-    this.context().setTag(tag, (Object) value);
+    context().setTag(tag, (Object) value);
     return this;
   }
 
@@ -176,7 +177,7 @@ public class DDSpan implements Span, MutableSpan {
    */
   @Override
   public final DDSpanContext context() {
-    return this.context;
+    return context;
   }
 
   /* (non-Javadoc)
@@ -184,7 +185,7 @@ public class DDSpan implements Span, MutableSpan {
    */
   @Override
   public final String getBaggageItem(final String key) {
-    return this.context.getBaggageItem(key);
+    return context.getBaggageItem(key);
   }
 
   /* (non-Javadoc)
@@ -192,7 +193,7 @@ public class DDSpan implements Span, MutableSpan {
    */
   @Override
   public final DDSpan setBaggageItem(final String key, final String value) {
-    this.context.setBaggageItem(key, value);
+    context.setBaggageItem(key, value);
     return this;
   }
 
@@ -201,7 +202,7 @@ public class DDSpan implements Span, MutableSpan {
    */
   @Override
   public final DDSpan setOperationName(final String operationName) {
-    this.context().setOperationName(operationName);
+    context().setOperationName(operationName);
     return this;
   }
 
@@ -247,13 +248,13 @@ public class DDSpan implements Span, MutableSpan {
 
   @Override
   public final DDSpan setServiceName(final String serviceName) {
-    this.context().setServiceName(serviceName);
+    context().setServiceName(serviceName);
     return this;
   }
 
   @Override
   public final DDSpan setResourceName(final String resourceName) {
-    this.context().setResourceName(resourceName);
+    context().setResourceName(resourceName);
     return this;
   }
 
@@ -264,13 +265,13 @@ public class DDSpan implements Span, MutableSpan {
    */
   @Override
   public final DDSpan setSamplingPriority(final int newPriority) {
-    this.context().setSamplingPriority(newPriority);
+    context().setSamplingPriority(newPriority);
     return this;
   }
 
   @Override
   public final DDSpan setSpanType(final String type) {
-    this.context().setSpanType(type);
+    context().setSpanType(type);
     return this;
   }
 
@@ -371,7 +372,7 @@ public class DDSpan implements Span, MutableSpan {
   @Override
   @JsonIgnore
   public Map<String, Object> getTags() {
-    return this.context().getTags();
+    return context().getTags();
   }
 
   @JsonGetter
@@ -405,12 +406,13 @@ public class DDSpan implements Span, MutableSpan {
       this(null);
     }
 
-    public UInt64IDStringSerializer(Class<String> stringClass) {
+    public UInt64IDStringSerializer(final Class<String> stringClass) {
       super(stringClass);
     }
 
     @Override
-    public void serialize(String value, JsonGenerator gen, SerializerProvider provider)
+    public void serialize(
+        final String value, final JsonGenerator gen, final SerializerProvider provider)
         throws IOException {
       gen.writeNumber(value);
     }

dd-trace-ot/src/main/java/datadog/opentracing/DDSpanContext.java

@@ -325,7 +325,7 @@ public class DDSpanContext implements io.opentracing.SpanContext {
   public String toString() {
     final StringBuilder s =
         new StringBuilder()
-            .append("Span [ t_id=")
+            .append("DDSpan [ t_id=")
             .append(traceId)
             .append(", s_id=")
             .append(spanId)

dd-trace-ot/src/main/java/datadog/opentracing/scopemanager/ContinuableScope.java

@@ -48,7 +48,7 @@ public class ContinuableScope implements Scope, TraceScope {
     this.continuation = continuation;
     this.spanUnderScope = spanUnderScope;
     this.finishOnClose = finishOnClose;
-    this.toRestore = scopeManager.tlsScope.get();
+    toRestore = scopeManager.tlsScope.get();
     scopeManager.tlsScope.set(this);
   }
 
@@ -96,6 +96,11 @@ public class ContinuableScope implements Scope, TraceScope {
     }
   }
 
+  @Override
+  public String toString() {
+    return super.toString() + "->" + spanUnderScope;
+  }
+
   public class Continuation implements Closeable, TraceScope.Continuation {
     public WeakReference<Continuation> ref;
 

dd-trace-ot/src/test/groovy/datadog/trace/DDSpanContextTest.groovy

@@ -18,7 +18,7 @@ class DDSpanContextTest extends Specification {
     context.serviceName == "fakeService"
     context.resourceName == "fakeResource"
     context.spanType == "fakeType"
-    context.toString() == "Span [ t_id=1, s_id=1, p_id=0] trace=fakeService/fakeOperation/fakeResource metrics={} *errored* tags={${extra}span.type=${context.getSpanType()}, thread.id=${Thread.currentThread().id}, thread.name=${Thread.currentThread().name}}"
+    context.toString() == "DDSpan [ t_id=1, s_id=1, p_id=0] trace=fakeService/fakeOperation/fakeResource metrics={} *errored* tags={${extra}span.type=${context.getSpanType()}, thread.id=${Thread.currentThread().id}, thread.name=${Thread.currentThread().name}}"
 
     where:
     name                 | extra             | tags
@@ -35,7 +35,7 @@ class DDSpanContextTest extends Specification {
     def thread = Thread.currentThread()
 
     def expectedTags = [(DDTags.THREAD_NAME): thread.name, (DDTags.THREAD_ID): thread.id, (DDTags.SPAN_TYPE): context.getSpanType()]
-    def expectedTrace = "Span [ t_id=1, s_id=1, p_id=0] trace=$details metrics={} tags={span.type=${context.getSpanType()}, thread.id=$thread.id, thread.name=$thread.name}"
+    def expectedTrace = "DDSpan [ t_id=1, s_id=1, p_id=0] trace=$details metrics={} tags={span.type=${context.getSpanType()}, thread.id=$thread.id, thread.name=$thread.name}"
 
     expect:
     context.getTags() == expectedTags
@@ -62,7 +62,7 @@ class DDSpanContextTest extends Specification {
       (DDTags.THREAD_NAME): thread.name,
       (DDTags.THREAD_ID)  : thread.id
     ]
-    context.toString() == "Span [ t_id=1, s_id=1, p_id=0] trace=fakeService/fakeOperation/fakeResource metrics={} tags={span.type=${context.getSpanType()}, $name=$value, thread.id=$thread.id, thread.name=$thread.name}"
+    context.toString() == "DDSpan [ t_id=1, s_id=1, p_id=0] trace=fakeService/fakeOperation/fakeResource metrics={} tags={span.type=${context.getSpanType()}, $name=$value, thread.id=$thread.id, thread.name=$thread.name}"
 
     where:
     name             | value