Merge pull request #139 from DataDog/tyler/errors

Capture and report errors and stacktraces

dd-java-agent-ittests/src/test/groovy/com/datadoghq/agent/integration/servlet/JettyServletTest.groovy

@@ -114,6 +114,44 @@ class JettyServletTest extends Specification {
     "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().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"] == 500
+    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
+    //"async" | "Hello Async" // FIXME: I can't seem get the async error handler to trigger
+    "sync"  | "Hello Sync"
+  }
+
   private static int randomOpenPort() {
     new ServerSocket(0).withCloseable {
       it.setReuseAddress(true)

dd-java-agent-ittests/src/test/groovy/com/datadoghq/agent/integration/servlet/TestServlet.groovy

@@ -12,6 +12,9 @@ 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-ittests/src/test/groovy/com/datadoghq/agent/integration/servlet/TomcatServletTest.groovy

@@ -114,6 +114,44 @@ class TomcatServletTest extends Specification {
     "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().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"] == 500
+    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
+    //"async" | "Hello Async" // FIXME: I can't seem get the async error handler to trigger
+    "sync"  | "Hello Sync"
+  }
+
   private static int randomOpenPort() {
     new ServerSocket(0).withCloseable {
       it.setReuseAddress(true)

dd-java-agent-ittests/src/test/java/com/datadoghq/agent/TraceAnnotationsManagerTest.java

@@ -3,10 +3,13 @@ package com.datadoghq.agent;
 import static org.assertj.core.api.Assertions.assertThat;
 
 import com.datadoghq.agent.test.SayTracedHello;
+import com.datadoghq.trace.DDBaseSpan;
 import com.datadoghq.trace.DDTracer;
 import com.datadoghq.trace.integration.ErrorFlag;
 import com.datadoghq.trace.writer.ListWriter;
 import io.opentracing.util.GlobalTracer;
+import java.io.PrintWriter;
+import java.io.StringWriter;
 import java.lang.reflect.Field;
 import org.junit.Before;
 import org.junit.Test;
@@ -67,13 +70,22 @@ public class TraceAnnotationsManagerTest {
 
     tracer.addDecorator(new ErrorFlag());
 
+    Throwable error = null;
     try {
       SayTracedHello.sayERROR();
     } catch (final Throwable ex) {
-      // DO NOTHING
+      error = ex;
     }
-    assertThat(writer.firstTrace().get(0).getOperationName()).isEqualTo("ERROR");
+
-    assertThat(writer.firstTrace().get(0).getTags().get("error")).isEqualTo("true");
+    final StringWriter errorString = new StringWriter();
-    assertThat(writer.firstTrace().get(0).getError()).isEqualTo(1);
+    error.printStackTrace(new PrintWriter(errorString));
+
+    final DDBaseSpan<?> span = writer.firstTrace().get(0);
+    assertThat(span.getOperationName()).isEqualTo("ERROR");
+    assertThat(span.getTags().get("error")).isEqualTo("true");
+    assertThat(span.getTags().get("error.msg")).isEqualTo(error.getMessage());
+    assertThat(span.getTags().get("error.type")).isEqualTo(error.getClass().getName());
+    assertThat(span.getTags().get("error.stack")).isEqualTo(errorString.toString());
+    assertThat(span.getError()).isEqualTo(1);
   }
 }

dd-java-agent/integrations/helpers/src/main/java/com/datadoghq/agent/integration/Servlet2Helper.java

@@ -8,6 +8,7 @@ import io.opentracing.contrib.web.servlet.filter.HttpServletRequestExtractAdapte
 import io.opentracing.contrib.web.servlet.filter.ServletFilterSpanDecorator;
 import io.opentracing.propagation.Format;
 import io.opentracing.tag.Tags;
+import java.util.Collections;
 import javax.servlet.http.HttpServletRequest;
 import javax.servlet.http.HttpServletResponse;
 import lombok.extern.slf4j.Slf4j;
@@ -73,6 +74,7 @@ public class Servlet2Helper extends OpenTracingHelper {
     final ActiveSpan span = tracer.activeSpan();
     if (span != null) {
       ServletFilterSpanDecorator.STANDARD_TAGS.onError(req, resp, ex, span);
+      span.log(Collections.singletonMap("error.object", ex));
       span.deactivate();
     }
   }

dd-java-agent/integrations/helpers/src/main/java/com/datadoghq/agent/integration/Servlet3Helper.java

@@ -3,6 +3,7 @@ package com.datadoghq.agent.integration;
 import io.opentracing.ActiveSpan;
 import io.opentracing.contrib.web.servlet.filter.ServletFilterSpanDecorator;
 import java.io.IOException;
+import java.util.Collections;
 import java.util.concurrent.atomic.AtomicBoolean;
 import javax.servlet.AsyncEvent;
 import javax.servlet.AsyncListener;
@@ -86,6 +87,7 @@ public class Servlet3Helper extends Servlet2Helper {
                         (HttpServletResponse) event.getSuppliedResponse(),
                         event.getThrowable(),
                         span);
+                    span.log(Collections.singletonMap("error.object", event.getThrowable()));
                   }
                 }
               }

dd-java-agent/src/main/java/com/datadoghq/agent/TraceAnnotationsManager.java

@@ -7,6 +7,7 @@ import java.io.PrintWriter;
 import java.io.StringWriter;
 import java.lang.reflect.Method;
 import java.util.Arrays;
+import java.util.Collections;
 import java.util.Set;
 import javassist.ClassPool;
 import javassist.CtClass;
@@ -43,7 +44,10 @@ public class TraceAnnotationsManager {
           + "DO\n"
           + "span.setTag("
           + Tags.class.getName()
-          + " .ERROR.getKey(),\"true\");\n"
+          + ".ERROR.getKey(),\"true\");\n"
+          + "span.log("
+          + Collections.class.getName()
+          + ".singletonMap(\"error.object\",$^));\n"
           + "span.deactivate();\n";
 
   private final Retransformer transformer;

dd-trace/src/main/java/com/datadoghq/trace/DDBaseSpan.java

@@ -4,6 +4,8 @@ import com.datadoghq.trace.util.Clock;
 import com.fasterxml.jackson.annotation.JsonGetter;
 import com.fasterxml.jackson.annotation.JsonIgnore;
 import io.opentracing.BaseSpan;
+import java.io.PrintWriter;
+import java.io.StringWriter;
 import java.util.HashMap;
 import java.util.Map;
 import java.util.Map.Entry;
@@ -95,6 +97,26 @@ public abstract class DDBaseSpan<S extends BaseSpan> implements BaseSpan<S> {
         && this.context.getTracer() != null;
   }
 
+  public void setErrorMeta(final Throwable error) {
+    context.setErrorFlag(true);
+
+    setTag(DDTags.ERROR_MSG, error.getMessage());
+    setTag(DDTags.ERROR_TYPE, error.getClass().getName());
+
+    final StringWriter errorString = new StringWriter();
+    error.printStackTrace(new PrintWriter(errorString));
+    setTag(DDTags.ERROR_STACK, errorString.toString());
+  }
+
+  private boolean extractError(final Map<String, ?> map) {
+    if (map.get("error.object") instanceof Throwable) {
+      final Throwable error = (Throwable) map.get("error.object");
+      setErrorMeta(error);
+      return true;
+    }
+    return false;
+  }
+
   /* (non-Javadoc)
    * @see io.opentracing.BaseSpan#setTag(java.lang.String, java.lang.String)
    */
@@ -161,7 +183,9 @@ public abstract class DDBaseSpan<S extends BaseSpan> implements BaseSpan<S> {
    */
   @Override
   public final S log(final Map<String, ?> map) {
-    log.debug("`log` method is not implemented. Doing nothing");
+    if (!extractError(map)) {
+      log.debug("`log` method is not implemented. Doing nothing");
+    }
     return thisInstance();
   }
 
@@ -170,7 +194,9 @@ public abstract class DDBaseSpan<S extends BaseSpan> implements BaseSpan<S> {
    */
   @Override
   public final S log(final long l, final Map<String, ?> map) {
-    log.debug("`log` method is not implemented. Doing nothing");
+    if (!extractError(map)) {
+      log.debug("`log` method is not implemented. Doing nothing");
+    }
     return thisInstance();
   }
 

dd-trace/src/main/java/com/datadoghq/trace/DDTags.java

@@ -7,4 +7,8 @@ public class DDTags {
   public static final String THREAD_NAME = "thread.name";
   public static final String THREAD_ID = "thread.id";
   public static final String DB_STATEMENT = "sql.query";
+
+  public static final String ERROR_MSG = "error.msg"; // string representing the error message
+  public static final String ERROR_TYPE = "error.type"; // string representing the type of the error
+  public static final String ERROR_STACK = "error.stack"; // human readable version of the stack
 }