Merge pull request #139 from DataDog/tyler/errors

tylerbenson · web-flow · commit a711a27db04b · 2017-10-13T18:18:27.000+02:00
Capture and report errors and stacktraces
diff --git a/dd-java-agent-ittests/src/test/groovy/com/datadoghq/agent/integration/servlet/JettyServletTest.groovy b/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)
diff --git a/dd-java-agent-ittests/src/test/groovy/com/datadoghq/agent/integration/servlet/TestServlet.groovy b/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")
     }
   }
diff --git a/dd-java-agent-ittests/src/test/groovy/com/datadoghq/agent/integration/servlet/TomcatServletTest.groovy b/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)
diff --git a/dd-java-agent-ittests/src/test/java/com/datadoghq/agent/TraceAnnotationsManagerTest.java b/dd-java-agent-ittests/src/test/java/com/datadoghq/agent/TraceAnnotationsManagerTest.java
@@ -3,10 +3,13 @@
 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 void testExceptionExit() {
 
     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");
-    assertThat(writer.firstTrace().get(0).getError()).isEqualTo(1);
+
+    final StringWriter errorString = new StringWriter();
+    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);
   }
 }
diff --git a/dd-java-agent/integrations/helpers/src/main/java/com/datadoghq/agent/integration/Servlet2Helper.java b/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.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 void onError(
     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();
     }
   }
diff --git a/dd-java-agent/integrations/helpers/src/main/java/com/datadoghq/agent/integration/Servlet3Helper.java b/dd-java-agent/integrations/helpers/src/main/java/com/datadoghq/agent/integration/Servlet3Helper.java
@@ -3,6 +3,7 @@
 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 void onError(final AsyncEvent event) throws IOException {
                         (HttpServletResponse) event.getSuppliedResponse(),
                         event.getThrowable(),
                         span);
+                    span.log(Collections.singletonMap("error.object", event.getThrowable()));
                   }
                 }
               }
diff --git a/dd-java-agent/src/main/java/com/datadoghq/agent/TraceAnnotationsManager.java b/dd-java-agent/src/main/java/com/datadoghq/agent/TraceAnnotationsManager.java
@@ -7,6 +7,7 @@
 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;
diff --git a/dd-trace/src/main/java/com/datadoghq/trace/DDBaseSpan.java b/dd-trace/src/main/java/com/datadoghq/trace/DDBaseSpan.java
@@ -4,6 +4,8 @@
 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 @@ protected final boolean isRootSpan() {
         && 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 final S setOperationName(final String operationName) {
    */
   @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 final S log(final Map<String, ?> map) {
    */
   @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();
   }
 
diff --git a/dd-trace/src/main/java/com/datadoghq/trace/DDTags.java b/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
 }

Original file line number	Diff line number	Diff line change
`@@ -12,6 +12,9 @@ class TestServlet {`
`12`	`12`	`static class Sync extends AbstractHttpServlet {`
`13`	`13`	`@Override`
`14`	`14`	`void doGet(HttpServletRequest req, HttpServletResponse resp) {`
	`15`	`+ if (req.getParameter("error") != null) {`
	`16`	`+ throw new RuntimeException("some sync error")`
	`17`	`+ }`
`15`	`18`	`resp.writer.print("Hello Sync")`
`16`	`19`	`}`
`17`	`20`	`}`
Original file line number	Diff line number	Diff line change
`@@ -3,6 +3,7 @@`
`3`	`3`	`import io.opentracing.ActiveSpan;`
`4`	`4`	`import io.opentracing.contrib.web.servlet.filter.ServletFilterSpanDecorator;`
`5`	`5`	`import java.io.IOException;`
	`6`	`+import java.util.Collections;`
`6`	`7`	`import java.util.concurrent.atomic.AtomicBoolean;`
`7`	`8`	`import javax.servlet.AsyncEvent;`
`8`	`9`	`import javax.servlet.AsyncListener;`
`@@ -86,6 +87,7 @@ public void onError(final AsyncEvent event) throws IOException {`
`86`	`87`	`(HttpServletResponse) event.getSuppliedResponse(),`
`87`	`88`	`event.getThrowable(),`
`88`	`89`	`span);`
	`90`	`+ span.log(Collections.singletonMap("error.object", event.getThrowable()));`
`89`	`91`	`}`
`90`	`92`	`}`
`91`	`93`	`}`
Original file line number	Diff line number	Diff line change
`@@ -7,4 +7,8 @@ public class DDTags {`
`7`	`7`	`public static final String THREAD_NAME = "thread.name";`
`8`	`8`	`public static final String THREAD_ID = "thread.id";`
`9`	`9`	`public static final String DB_STATEMENT = "sql.query";`
	`10`	`+`
	`11`	`+ public static final String ERROR_MSG = "error.msg"; // string representing the error message`
	`12`	`+ public static final String ERROR_TYPE = "error.type"; // string representing the type of the error`
	`13`	`+ public static final String ERROR_STACK = "error.stack"; // human readable version of the stack`
`10`	`14`	`}`