Move servlet tests to individual modules. Fix servlet 2 instrumentation.

Turns out we weren’t actually servlet 2 compatible.  That should be fixed now.  Unfortunately it appears servlet 2 also doesn’t expose the http response code, so we aren’t able to set it as a tag without custom instrumentation for each framework.

I also removed our log4j2 stuff since we’re using logback.

dd-java-agent-ittests/dd-java-agent-ittests.gradle

@@ -24,6 +24,7 @@ dependencies {
   testCompile project(':dd-trace-ot')
 
   testCompile deps.opentracingMock
+  testCompile deps.testLogging
 
   testCompile(project(':dd-java-agent:testing')) {
     // Otherwise this can bring in classes that aren't "shadowed"
@@ -36,16 +37,9 @@ dependencies {
   // run embeded mongodb for integration testing
   testCompile group: 'de.flapdoodle.embed', name: 'de.flapdoodle.embed.mongo', version: '1.50.5'
 
-  testCompile group: 'org.eclipse.jetty', name: 'jetty-server', version: '8.2.0.v20160908'
-  testCompile group: 'org.eclipse.jetty', name: 'jetty-servlet', version: '8.2.0.v20160908'
-  testCompile group: 'org.apache.tomcat.embed', name: 'tomcat-embed-core', version: '8.0.41'
-  testCompile group: 'org.apache.tomcat.embed', name: 'tomcat-embed-jasper', version: '8.0.41'
   testCompile group: 'org.apache.httpcomponents', name: 'httpclient', version: '4.3'
   testCompile group: 'com.squareup.okhttp3', name: 'okhttp', version: '3.6.0'
 
-  testCompile group: 'org.apache.logging.log4j', name: 'log4j-api', version: '2.8.2'
-  testCompile group: 'org.apache.logging.log4j', name: 'log4j-core', version: '2.8.2'
-
   // JDBC tests:
   testCompile group: 'com.h2database', name: 'h2', version: '1.4.196'
   testCompile group: 'org.hsqldb', name: 'hsqldb', version: '2.3.+'

dd-java-agent-ittests/src/test/resources/log4j2.properties

@@ -1,5 +0,0 @@
-appender.console.type=Console
-appender.console.name=console
-appender.console.layout.type=PatternLayout
-rootLogger.level=debug
-rootLogger.appenderRef.console.ref=console

dd-java-agent/instrumentation/servlet-2/servlet-2.gradle

@@ -24,4 +24,11 @@ dependencies {
   compile deps.bytebuddy
   compile deps.opentracing
   compile deps.autoservice
+
+  testCompile project(':dd-java-agent:testing')
+  testCompile group: 'org.eclipse.jetty', name: 'jetty-server', version: '7.0.0.v20091005'
+  testCompile group: 'org.eclipse.jetty', name: 'jetty-servlet', version: '7.0.0.v20091005'
+
+  testCompile project(':dd-java-agent:instrumentation:okhttp-3') // used in the tests
+  testCompile group: 'com.squareup.okhttp3', name: 'okhttp', version: '3.6.0'
 }

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

@@ -19,7 +19,6 @@ import io.opentracing.Scope;
 import io.opentracing.Span;
 import io.opentracing.SpanContext;
 import io.opentracing.contrib.web.servlet.filter.HttpServletRequestExtractAdapter;
-import io.opentracing.contrib.web.servlet.filter.ServletFilterSpanDecorator;
 import io.opentracing.propagation.Format;
 import io.opentracing.tag.Tags;
 import io.opentracing.util.GlobalTracer;
@@ -52,10 +51,7 @@ public final class FilterChain2Instrumentation extends Instrumenter.Configurable
             new HelperInjector(
                 "io.opentracing.contrib.web.servlet.filter.HttpServletRequestExtractAdapter",
                 "io.opentracing.contrib.web.servlet.filter.HttpServletRequestExtractAdapter$MultivaluedMapFlatIterator",
-                "io.opentracing.contrib.web.servlet.filter.ServletFilterSpanDecorator",
+                "datadog.trace.instrumentation.servlet2.ServletFilterSpanDecorator"))
-                "io.opentracing.contrib.web.servlet.filter.ServletFilterSpanDecorator$1",
-                "io.opentracing.contrib.web.servlet.filter.TracingFilter",
-                "io.opentracing.contrib.web.servlet.filter.TracingFilter$1"))
         .transform(
             DDAdvice.create()
                 .advice(

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

@@ -19,7 +19,6 @@ import io.opentracing.Scope;
 import io.opentracing.Span;
 import io.opentracing.SpanContext;
 import io.opentracing.contrib.web.servlet.filter.HttpServletRequestExtractAdapter;
-import io.opentracing.contrib.web.servlet.filter.ServletFilterSpanDecorator;
 import io.opentracing.propagation.Format;
 import io.opentracing.tag.Tags;
 import io.opentracing.util.GlobalTracer;
@@ -52,12 +51,9 @@ public final class HttpServlet2Instrumentation extends Instrumenter.Configurable
             new HelperInjector(
                 "io.opentracing.contrib.web.servlet.filter.HttpServletRequestExtractAdapter",
                 "io.opentracing.contrib.web.servlet.filter.HttpServletRequestExtractAdapter$MultivaluedMapFlatIterator",
-                "io.opentracing.contrib.web.servlet.filter.ServletFilterSpanDecorator",
+                "datadog.trace.instrumentation.servlet2.ServletFilterSpanDecorator"))
-                "io.opentracing.contrib.web.servlet.filter.ServletFilterSpanDecorator$1",
-                "io.opentracing.contrib.web.servlet.filter.TracingFilter",
-                "io.opentracing.contrib.web.servlet.filter.TracingFilter$1"))
         .transform(
-            DDAdvice.create()
+            DDAdvice.create(false) // Can't use the error handler for pre 1.5 classes...
                 .advice(
                     named("service")
                         .and(takesArgument(0, named("javax.servlet.http.HttpServletRequest")))

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

@@ -0,0 +1,142 @@
+package datadog.trace.instrumentation.servlet2;
+
+import io.opentracing.Span;
+import io.opentracing.tag.Tags;
+import java.io.PrintWriter;
+import java.io.StringWriter;
+import java.util.HashMap;
+import java.util.Map;
+import javax.servlet.FilterChain;
+import javax.servlet.ServletRequest;
+import javax.servlet.ServletResponse;
+import javax.servlet.http.HttpServletRequest;
+import javax.servlet.http.HttpServletResponse;
+
+/**
+ * SpanDecorator to decorate span at different stages in filter processing (before
+ * filterChain.doFilter(), after and if exception is thrown).
+ *
+ * <p>Taken from
+ * https://raw.githubusercontent.com/opentracing-contrib/java-web-servlet-filter/v0.1.0/opentracing-web-servlet-filter/src/main/java/io/opentracing/contrib/web/servlet/filter/ServletFilterSpanDecorator.java
+ * and removed async and status code stuff to be Servlet 2.x compatible.
+ *
+ * @author Pavol Loffay
+ */
+public interface ServletFilterSpanDecorator {
+
+  /**
+   * Decorate span before {@link javax.servlet.Filter#doFilter(ServletRequest, ServletResponse,
+   * FilterChain)} is called. This is called right after span in created. Span is already present in
+   * request attributes with name {@link TracingFilter#SERVER_SPAN_CONTEXT}.
+   *
+   * @param httpServletRequest request
+   * @param span span to decorate
+   */
+  void onRequest(HttpServletRequest httpServletRequest, Span span);
+
+  /**
+   * Decorate span after {@link javax.servlet.Filter#doFilter(ServletRequest, ServletResponse,
+   * FilterChain)}.
+   *
+   * @param httpServletRequest request
+   * @param httpServletResponse response
+   * @param span span to decorate
+   */
+  void onResponse(
+      HttpServletRequest httpServletRequest, HttpServletResponse httpServletResponse, Span span);
+
+  /**
+   * Decorate span when an exception is thrown during processing in {@link
+   * javax.servlet.Filter#doFilter(ServletRequest, ServletResponse, FilterChain)}.
+   *
+   * @param httpServletRequest request
+   * @param exception exception
+   * @param span span to decorate
+   */
+  void onError(
+      HttpServletRequest httpServletRequest,
+      HttpServletResponse httpServletResponse,
+      Throwable exception,
+      Span span);
+
+  /**
+   * Decorate span on asynchronous request timeout.
+   *
+   * @param httpServletRequest request
+   * @param httpServletResponse response
+   * @param timeout timeout
+   * @param span span to decorate
+   */
+  void onTimeout(
+      HttpServletRequest httpServletRequest,
+      HttpServletResponse httpServletResponse,
+      long timeout,
+      Span span);
+
+  /**
+   * Adds standard tags to span. {@link Tags#HTTP_URL}, {@link Tags#HTTP_STATUS}, {@link
+   * Tags#HTTP_METHOD} and {@link Tags#COMPONENT}. If an exception during {@link
+   * javax.servlet.Filter#doFilter(ServletRequest, ServletResponse, FilterChain)} is thrown tag
+   * {@link Tags#ERROR} is added and {@link Tags#HTTP_STATUS} not because at this point it is not
+   * known.
+   */
+  ServletFilterSpanDecorator STANDARD_TAGS =
+      new ServletFilterSpanDecorator() {
+        @Override
+        public void onRequest(final HttpServletRequest httpServletRequest, final Span span) {
+          Tags.COMPONENT.set(span, "java-web-servlet");
+
+          Tags.HTTP_METHOD.set(span, httpServletRequest.getMethod());
+          //without query params
+          Tags.HTTP_URL.set(span, httpServletRequest.getRequestURL().toString());
+        }
+
+        @Override
+        public void onResponse(
+            final HttpServletRequest httpServletRequest,
+            final HttpServletResponse httpServletResponse,
+            final Span span) {}
+
+        @Override
+        public void onError(
+            final HttpServletRequest httpServletRequest,
+            final HttpServletResponse httpServletResponse,
+            final Throwable exception,
+            final Span span) {
+          Tags.ERROR.set(span, Boolean.TRUE);
+          span.log(logsForException(exception));
+        }
+
+        @Override
+        public void onTimeout(
+            final HttpServletRequest httpServletRequest,
+            final HttpServletResponse httpServletResponse,
+            final long timeout,
+            final Span span) {
+          Tags.ERROR.set(span, Boolean.TRUE);
+
+          final Map<String, Object> timeoutLogs = new HashMap<>();
+          timeoutLogs.put("event", Tags.ERROR.getKey());
+          timeoutLogs.put("message", "timeout");
+          timeoutLogs.put("timeout", timeout);
+        }
+
+        private Map<String, String> logsForException(final Throwable throwable) {
+          final Map<String, String> errorLog = new HashMap<>(3);
+          errorLog.put("event", Tags.ERROR.getKey());
+
+          final String message =
+              throwable.getCause() != null
+                  ? throwable.getCause().getMessage()
+                  : throwable.getMessage();
+          if (message != null) {
+            errorLog.put("message", message);
+          }
+          final StringWriter sw = new StringWriter();
+          throwable.printStackTrace(new PrintWriter(sw));
+          errorLog.put("stack", sw.toString());
+
+          return errorLog;
+        }
+      };
+}

dd-java-agent/instrumentation/servlet-2/src/test/groovy/JettyServletTest.groovy

@@ -0,0 +1,160 @@
+import datadog.opentracing.DDSpan
+import datadog.opentracing.DDTracer
+import datadog.trace.agent.test.AgentTestRunner
+import datadog.trace.api.DDSpanTypes
+import datadog.trace.common.writer.ListWriter
+import io.opentracing.util.GlobalTracer
+import okhttp3.Interceptor
+import okhttp3.OkHttpClient
+import okhttp3.Request
+import okhttp3.Response
+import org.eclipse.jetty.server.Server
+import org.eclipse.jetty.servlet.ServletContextHandler
+import spock.lang.Unroll
+
+import java.lang.reflect.Field
+import java.util.concurrent.CountDownLatch
+import java.util.concurrent.TimeUnit
+
+class JettyServletTest extends AgentTestRunner {
+
+  static final int PORT = randomOpenPort()
+
+  // Jetty needs this to ensure consistent ordering for async.
+  static CountDownLatch latch
+  OkHttpClient client = new OkHttpClient.Builder()
+    .addNetworkInterceptor(new Interceptor() {
+    @Override
+    Response intercept(Interceptor.Chain chain) throws IOException {
+      def response = chain.proceed(chain.request())
+      JettyServletTest.latch.await(10, TimeUnit.SECONDS) // don't block forever or test never fails.
+      return response
+    }
+  })
+  // Uncomment when debugging:
+    .connectTimeout(1, TimeUnit.HOURS)
+    .writeTimeout(1, TimeUnit.HOURS)
+    .readTimeout(1, TimeUnit.HOURS)
+    .build()
+
+  private Server jettyServer
+  private ServletContextHandler servletContext
+
+  ListWriter writer = new ListWriter() {
+    @Override
+    void write(final List<DDSpan> trace) {
+      add(trace)
+      JettyServletTest.latch.countDown()
+    }
+  }
+  DDTracer tracer = new DDTracer(writer)
+
+  def setup() {
+    jettyServer = new Server(PORT)
+    servletContext = new ServletContextHandler()
+
+    servletContext.addServlet(TestServlet.Sync, "/sync")
+
+    jettyServer.setHandler(servletContext)
+    jettyServer.start()
+
+    System.out.println(
+      "Jetty server: http://localhost:" + PORT + "/")
+
+    try {
+      GlobalTracer.register(tracer)
+    } catch (final Exception e) {
+      // Force it anyway using reflection
+      final Field field = GlobalTracer.getDeclaredField("tracer")
+      field.setAccessible(true)
+      field.set(null, tracer)
+    }
+    writer.start()
+    assert GlobalTracer.isRegistered()
+  }
+
+  def cleanup() {
+    jettyServer.stop()
+    jettyServer.destroy()
+  }
+
+  @Unroll
+  def "test #path servlet call"() {
+    setup:
+    latch = new CountDownLatch(1)
+    def request = new Request.Builder()
+      .url("http://localhost:$PORT/$path")
+      .get()
+      .build()
+    def response = client.newCall(request).execute()
+
+    expect:
+    response.body().string().trim() == expectedResponse
+    writer.size() == 2 // second (parent) trace is the okhttp call above...
+    def trace = writer.firstTrace()
+    trace.size() == 1
+    def span = trace[0]
+
+    span.context().operationName == "servlet.request"
+    span.context().spanType == DDSpanTypes.WEB_SERVLET
+    !span.context().getErrorFlag()
+    span.context().parentId != 0 // parent should be the okhttp call.
+    span.context().tags["http.url"] == "http://localhost:$PORT/$path"
+    span.context().tags["http.method"] == "GET"
+    span.context().tags["span.kind"] == "server"
+    span.context().tags["component"] == "java-web-servlet"
+    span.context().tags["http.status_code"] == null // sadly servlet 2.x doesn't expose it generically.
+    span.context().tags["thread.name"] != null
+    span.context().tags["thread.id"] != null
+    span.context().tags.size() == 7
+
+    where:
+    path   | expectedResponse
+    "sync" | "Hello Sync"
+  }
+
+  @Unroll
+  def "test #path error servlet call"() {
+    setup:
+    def request = new Request.Builder()
+      .url("http://localhost:$PORT/$path?error=true")
+      .get()
+      .build()
+    def response = client.newCall(request).execute()
+
+    expect:
+    response.body().string().trim() != expectedResponse
+    writer.size() == 2 // second (parent) trace is the okhttp call above...
+    def trace = writer.firstTrace()
+    trace.size() == 1
+    def span = trace[0]
+
+    span.context().operationName == "servlet.request"
+    span.context().spanType == DDSpanTypes.WEB_SERVLET
+    span.context().getErrorFlag()
+    span.context().parentId != 0 // parent should be the okhttp call.
+    span.context().tags["http.url"] == "http://localhost:$PORT/$path"
+    span.context().tags["http.method"] == "GET"
+    span.context().tags["span.kind"] == "server"
+    span.context().tags["component"] == "java-web-servlet"
+    span.context().tags["http.status_code"] == null // sadly servlet 2.x doesn't expose it generically.
+    span.context().tags["thread.name"] != null
+    span.context().tags["thread.id"] != null
+    span.context().tags["error"] == true
+    span.context().tags["error.msg"] == "some $path error"
+    span.context().tags["error.type"] == RuntimeException.getName()
+    span.context().tags["error.stack"] != null
+    span.context().tags.size() == 11
+
+    where:
+    path   | expectedResponse
+    "sync" | "Hello Sync"
+  }
+
+  private static int randomOpenPort() {
+    new ServerSocket(0).withCloseable {
+      it.setReuseAddress(true)
+      return it.getLocalPort()
+    }
+  }
+}

dd-java-agent/instrumentation/servlet-2/src/test/groovy/TestServlet.groovy

@@ -0,0 +1,17 @@
+import groovy.servlet.AbstractHttpServlet
+
+import javax.servlet.http.HttpServletRequest
+import javax.servlet.http.HttpServletResponse
+
+class TestServlet {
+
+  static class Sync extends AbstractHttpServlet {
+    @Override
+    void doGet(HttpServletRequest req, HttpServletResponse resp) {
+      if (req.getParameter("error") != null) {
+        throw new RuntimeException("some sync error")
+      }
+      resp.writer.print("Hello Sync")
+    }
+  }
+}

dd-java-agent/instrumentation/servlet-3/servlet-3.gradle

@@ -25,4 +25,13 @@ dependencies {
   compile deps.bytebuddy
   compile deps.opentracing
   compile deps.autoservice
+
+  testCompile project(':dd-java-agent:testing')
+  testCompile group: 'org.eclipse.jetty', name: 'jetty-server', version: '8.2.0.v20160908'
+  testCompile group: 'org.eclipse.jetty', name: 'jetty-servlet', version: '8.2.0.v20160908'
+  testCompile group: 'org.apache.tomcat.embed', name: 'tomcat-embed-core', version: '8.0.41'
+  testCompile group: 'org.apache.tomcat.embed', name: 'tomcat-embed-jasper', version: '8.0.41'
+
+  testCompile project(':dd-java-agent:instrumentation:okhttp-3') // used in the tests
+  testCompile group: 'com.squareup.okhttp3', name: 'okhttp', version: '3.6.0'
 }

dd-java-agent/instrumentation/servlet-3/src/test/groovy/JettyServletTest.groovy

@@ -1,7 +1,6 @@
-package datadog.trace.agent.integration.servlet
-
 import datadog.opentracing.DDSpan
 import datadog.opentracing.DDTracer
+import datadog.trace.agent.test.AgentTestRunner
 import datadog.trace.api.DDSpanTypes
 import datadog.trace.common.writer.ListWriter
 import io.opentracing.util.GlobalTracer
@@ -11,21 +10,20 @@ import okhttp3.Request
 import okhttp3.Response
 import org.eclipse.jetty.server.Server
 import org.eclipse.jetty.servlet.ServletContextHandler
-import spock.lang.Specification
 import spock.lang.Unroll
 
 import java.lang.reflect.Field
 import java.util.concurrent.CountDownLatch
 import java.util.concurrent.TimeUnit
 
-class JettyServletTest extends Specification {
+class JettyServletTest extends AgentTestRunner {
 
   static final int PORT = randomOpenPort()
 
   // Jetty needs this to ensure consistent ordering for async.
   static CountDownLatch latch
   OkHttpClient client = new OkHttpClient.Builder()
-  .addNetworkInterceptor(new Interceptor() {
+    .addNetworkInterceptor(new Interceptor() {
     @Override
     Response intercept(Interceptor.Chain chain) throws IOException {
       def response = chain.proceed(chain.request())
@@ -151,9 +149,9 @@ class JettyServletTest extends Specification {
     span.context().tags.size() == 12
 
     where:
-    path    | expectedResponse
+    path   | expectedResponse
     //"async" | "Hello Async" // FIXME: I can't seem get the async error handler to trigger
-    "sync"  | "Hello Sync"
+    "sync" | "Hello Sync"
   }
 
   private static int randomOpenPort() {

dd-java-agent/instrumentation/servlet-3/src/test/groovy/TestServlet.groovy

@@ -1,5 +1,3 @@
-package datadog.trace.agent.integration.servlet
-
 import groovy.servlet.AbstractHttpServlet
 
 import javax.servlet.annotation.WebServlet

dd-java-agent/instrumentation/servlet-3/src/test/groovy/TomcatServletTest.groovy

@@ -1,7 +1,6 @@
-package datadog.trace.agent.integration.servlet
-
 import com.google.common.io.Files
 import datadog.opentracing.DDTracer
+import datadog.trace.agent.test.AgentTestRunner
 import datadog.trace.api.DDSpanTypes
 import datadog.trace.common.writer.ListWriter
 import io.opentracing.util.GlobalTracer
@@ -11,12 +10,11 @@ import org.apache.catalina.Context
 import org.apache.catalina.startup.Tomcat
 import org.apache.tomcat.JarScanFilter
 import org.apache.tomcat.JarScanType
-import spock.lang.Specification
 import spock.lang.Unroll
 
 import java.lang.reflect.Field
 
-class TomcatServletTest extends Specification {
+class TomcatServletTest extends AgentTestRunner {
 
   static final int PORT = randomOpenPort()
   OkHttpClient client = new OkHttpClient.Builder()

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

@@ -18,9 +18,15 @@ public class DDAdvice extends AgentBuilder.Transformer.ForAdvice {
    * @return the bytebuddy advice
    */
   public static AgentBuilder.Transformer.ForAdvice create() {
-    return new DDAdvice()
+    return create(true);
-        .with(AGENT_CLASS_LOCATION_STRATEGY)
+  }
-        .withExceptionHandler(ExceptionHandlers.defaultExceptionHandler());
+
+  public static AgentBuilder.Transformer.ForAdvice create(final boolean includeExceptionHandler) {
+    ForAdvice advice = new DDAdvice().with(AGENT_CLASS_LOCATION_STRATEGY);
+    if (includeExceptionHandler) {
+      advice = advice.withExceptionHandler(ExceptionHandlers.defaultExceptionHandler());
+    }
+    return advice;
   }
 
   private DDAdvice() {}