Span Error Handler (#666)

This supports the case where certain backend systems support errors as a first class object.

brave/README.md

@@ -67,11 +67,16 @@ the correct spot in the tree representing the distributed operation.
 
 When tracing local code, just run it inside a span.
 ```java
+// start a new trace or a span within an existing trace representing an operation
 Span span = tracer.nextSpan().name("encode").start();
-try {
-  doSomethingExpensive();
+// put the span in "scope" so that downstream code such as loggers can see trace IDs
+try (SpanInScope ws = tracer.withSpanInScope(span)) {
+  return encoder.encode();
+} catch (RuntimeException | Error e) {
+  span.error(e); // if you don't catch exceptions, you won't know the operation failed!
+  throw e;
 } finally {
-  span.finish();
+  span.finish();  // note the scope is independent of the span
 }
 ```
 
@@ -81,11 +86,6 @@ If you need to be more explicit, call `newChild` or `newTrace` instead.
 
 ```java
 Span span = tracer.newChild(root.context()).name("encode").start();
-try {
-  doSomethingExpensive();
-} finally {
-  span.finish();
-}
 ```
 
 ### Customizing spans
@@ -256,7 +256,7 @@ public Object traceThing(ProceedingJoinPoint pjp, Traced traced) throws Throwabl
   try (Tracer.SpanInScope ws = tracer.withSpanInScope(span)) {
     return pjp.proceed();
   } catch (RuntimeException | Error e) {
-    span.tag("error", e.getMessage());
+    span.error(e);
     throw e;
   } finally {
     span.finish();
@@ -522,6 +522,9 @@ span in scope like this.
 ```java
 try (SpanInScope ws = tracer.withSpanInScope(span)) {
   return inboundRequest.invoke();
+} catch (RuntimeException | Error e) {
+  span.error(e);
+  throw e;
 } finally { // note the scope is independent of the span
   span.finish();
 }

brave/src/main/java/brave/ErrorParser.java

@@ -0,0 +1,40 @@
+package brave;
+
+/** This is a simplified type used for parsing errors. It only allows annotations or tags. */
+// This implementation allows a future type ScopedSpan which will not support backdated annotations
+public class ErrorParser {
+  /** Adds no tags to the span representing the operation in error. */
+  public static final ErrorParser NOOP = new ErrorParser() {
+    @Override protected void error(Throwable error, Object customizer) {
+    }
+  };
+
+  /** Used to parse errors on a subtype of {@linkplain SpanCustomizer} */
+  public final void error(Throwable error, SpanCustomizer customizer) {
+    error(error, (Object) customizer);
+  }
+
+  /**
+   * Override to change what data from the error are parsed into the span modeling it. By
+   * default, this tags "error" as the message or simple name of the type.
+   */
+  protected void error(Throwable error, Object span) {
+    String message = error.getMessage();
+    if (message == null) message = error.getClass().getSimpleName();
+    tag(span, "error", message);
+  }
+
+  /** Same behaviour as {@link brave.SpanCustomizer#annotate(String)} */
+  protected final void annotate(Object span, String value) {
+    if (span instanceof SpanCustomizer) {
+      ((SpanCustomizer) span).annotate(value);
+    }
+  }
+
+  /** Same behaviour as {@link brave.SpanCustomizer#tag(String, String)} */
+  protected final void tag(Object span, String key, String message) {
+    if (span instanceof SpanCustomizer) {
+      ((SpanCustomizer) span).tag(key, message);
+    }
+  }
+}

brave/src/main/java/brave/NoopSpan.java

@@ -51,6 +51,10 @@ static NoopSpan create(TraceContext context) {
     return this;
   }
 
+  @Override public Span error(Throwable throwable) {
+    return this;
+  }
+
   @Override public void finish() {
   }
 

brave/src/main/java/brave/RealSpan.java

@@ -10,9 +10,11 @@
 abstract class RealSpan extends Span {
 
   abstract Recorder recorder();
+  abstract ErrorParser errorParser();
 
-  static RealSpan create(TraceContext context, Recorder recorder) {
-    return new AutoValue_RealSpan(context, RealSpanCustomizer.create(context, recorder), recorder);
+  static RealSpan create(TraceContext context, Recorder recorder, ErrorParser errorParser) {
+    return new AutoValue_RealSpan(context, RealSpanCustomizer.create(context, recorder), recorder,
+        errorParser);
   }
 
   @Override public boolean isNoop() {
@@ -54,6 +56,11 @@ static RealSpan create(TraceContext context, Recorder recorder) {
     return this;
   }
 
+  @Override public Span error(Throwable throwable) {
+    errorParser().error(throwable, customizer());
+    return this;
+  }
+
   @Override public Span remoteEndpoint(Endpoint remoteEndpoint) {
     recorder().remoteEndpoint(context(), remoteEndpoint);
     return this;

brave/src/main/java/brave/Span.java

@@ -6,16 +6,22 @@
 /**
  * Used to model the latency of an operation.
  *
- * <p>For example, to trace a local function call.
+ * Here's a typical example of synchronous tracing from perspective of the span:
  * <pre>{@code
- * Span span = tracer.newTrace().name("encode").start();
- * try {
- *   doSomethingExpensive();
+ * // Note span methods chain. Explicitly start the span when ready.
+ * Span span = tracer.nextSpan().name("encode").start();
+ * // A span is not responsible for making itself current (scoped); the tracer is
+ * try (SpanInScope ws = tracer.withSpanInScope(span)) {
+ *   return encoder.encode();
+ * } catch (RuntimeException | Error e) {
+ *   span.error(e); // Unless you handle exceptions, you might not know the operation failed!
+ *   throw e;
  * } finally {
- *   span.finish();
+ *   span.finish(); // finish - start = the duration of the operation in microseconds
  * }
  * }</pre>
- * This captures duration of {@link #start()} until {@link #finish()} is called.
+ *
+ * <p>This captures duration of {@link #start()} until {@link #finish()} is called.
  */
 // Design note: this does not require a builder as the span is mutable anyway. Having a single
 // mutation interface is less code to maintain. Those looking to prepare a span before starting it
@@ -99,6 +105,11 @@ public enum Kind {
   /** {@inheritDoc} */
   @Override public abstract Span tag(String key, String value);
 
+  /** Adds tags depending on the configured {@link Tracing#errorParser() error parser} */
+  // Design note: <T extends Throwable> T error(T throwable) is tempting but this doesn't work in
+  // multi-catch. In practice, you should always at least catch RuntimeException and Error.
+  public abstract Span error(Throwable throwable);
+
   /**
    * @deprecated use {@link #remoteEndpoint(Endpoint)}, possibly with {@link zipkin.Endpoint#toV2()}
    */

brave/src/main/java/brave/SpanCustomizer.java

@@ -23,6 +23,7 @@
 // Note: this is exposed to users. We cannot add methods to this until Java 8 is required or we do a
 // major version bump
 // BRAVE5: add isNoop to avoid instanceof checks
+// BRAVE5: add error to support error handling
 public interface SpanCustomizer {
   /**
    * Sets the string name for the logical operation this span represents.

brave/src/main/java/brave/Tracer.java

@@ -23,24 +23,18 @@
  * Using a tracer, you can create a root span capturing the critical path of a request. Child spans
  * can be created to allocate latency relating to outgoing requests.
  *
- * Here's a contrived example:
+ * Here's a typical example of synchronous tracing from perspective of the tracer:
  * <pre>{@code
- * Span twoPhase = tracer.newTrace().name("twoPhase").start();
- * try {
- *   Span prepare = tracer.newChild(twoPhase.context()).name("prepare").start();
- *   try {
- *     prepare();
- *   } finally {
- *     prepare.finish();
- *   }
- *   Span commit = tracer.newChild(twoPhase.context()).name("commit").start();
- *   try {
- *     commit();
- *   } finally {
- *     commit.finish();
- *   }
+ * // "nextSpan" starts a new trace or a makes a child within an existing one.
+ * Span span = tracer.nextSpan().name("encode").start();
+ * // put the span in "scope" so that downstream code such as loggers can see trace IDs
+ * try (SpanInScope ws = tracer.withSpanInScope(span)) {
+ *   return encoder.encode();
+ * } catch (RuntimeException | Error e) {
+ *   span.error(e); // Unless you handle exceptions, you might not know the operation failed!
+ *   throw e;
  * } finally {
- *   twoPhase.finish();
+ *   span.finish(); // note the scope is independent of the span. Always finish a span.
  * }
  * }</pre>
  *
@@ -138,8 +132,9 @@ public Tracer build() {
   final CurrentTraceContext currentTraceContext;
   final boolean traceId128Bit, supportsJoin;
   final AtomicBoolean noop;
+  final ErrorParser errorParser;
 
-  Tracer(Tracing.Builder builder, Clock clock, AtomicBoolean noop) {
+  Tracer(Tracing.Builder builder, Clock clock, AtomicBoolean noop, ErrorParser errorParser) {
     this.noop = noop;
     this.propagationFactory = builder.propagationFactory;
     this.supportsJoin = builder.supportsJoin && propagationFactory.supportsJoin();
@@ -149,6 +144,7 @@ public Tracer build() {
     this.sampler = builder.sampler;
     this.currentTraceContext = builder.currentTraceContext;
     this.traceId128Bit = builder.traceId128Bit || propagationFactory.requires128BitTraceId();
+    this.errorParser = errorParser;
   }
 
   /** @deprecated use {@link Tracing#clock(TraceContext)} */
@@ -302,7 +298,7 @@ public Span toSpan(TraceContext context) {
     if (context == null) throw new NullPointerException("context == null");
     TraceContext decorated = propagationFactory.decorate(context);
     if (!noop.get() && Boolean.TRUE.equals(decorated.sampled())) {
-      return RealSpan.create(decorated, recorder);
+      return RealSpan.create(decorated, recorder, errorParser);
     }
     return NoopSpan.create(decorated);
   }
@@ -340,6 +336,10 @@ long nextId() {
    * // Assume a framework interceptor uses this method to set the inbound span as current
    * try (SpanInScope ws = tracer.withSpanInScope(span)) {
    *   return inboundRequest.invoke();
+   * // note: try-with-resources closes the scope *before* the catch block
+   * } catch (RuntimeException | Error e) {
+   *   span.error(e);
+   *   throw e;
    * } finally {
    *   span.finish();
    * }
@@ -349,6 +349,10 @@ long nextId() {
    * Span span = tracer.nextSpan().name("outbound").start(); // parent is implicitly looked up
    * try (SpanInScope ws = tracer.withSpanInScope(span)) {
    *   return outboundRequest.invoke();
+   * // note: try-with-resources closes the scope *before* the catch block
+   * } catch (RuntimeException | Error e) {
+   *   span.error(e);
+   *   throw e;
    * } finally {
    *   span.finish();
    * }

brave/src/main/java/brave/Tracing.java

@@ -65,6 +65,8 @@ public final Clock clock(TraceContext context) {
     return tracer().recorder.clock(context);
   }
 
+  abstract public ErrorParser errorParser();
+
   // volatile for visibility on get. writes guarded by Tracing.class
   static volatile Tracing current = null;
 
@@ -122,6 +124,7 @@ public static final class Builder {
     boolean traceId128Bit = false;
     boolean supportsJoin = true;
     Propagation.Factory propagationFactory = B3Propagation.FACTORY;
+    ErrorParser errorParser = new ErrorParser();
 
     /**
      * Controls the name of the service being traced, while still using a default site-local IP.
@@ -274,6 +277,11 @@ public Builder supportsJoin(boolean supportsJoin) {
       return this;
     }
 
+    public Builder errorParser(ErrorParser errorParser) {
+      this.errorParser = errorParser;
+      return this;
+    }
+
     public Tracing build() {
       if (clock == null) clock = Platform.get().clock();
       if (endpoint == null) {
@@ -296,10 +304,12 @@ static final class Default extends Tracing {
     final Propagation<String> stringPropagation;
     final CurrentTraceContext currentTraceContext;
     final Clock clock;
+    final ErrorParser errorParser;
 
     Default(Builder builder) {
       this.clock = builder.clock;
-      this.tracer = new Tracer(builder, clock, noop);
+      this.errorParser = builder.errorParser;
+      this.tracer = new Tracer(builder, clock, noop, errorParser);
       this.propagationFactory = builder.propagationFactory;
       this.stringPropagation = builder.propagationFactory.create(Propagation.KeyFactory.STRING);
       this.currentTraceContext = builder.currentTraceContext;
@@ -326,6 +336,10 @@ static final class Default extends Tracing {
       return clock;
     }
 
+    @Override public ErrorParser errorParser() {
+      return errorParser;
+    }
+
     private void maybeSetCurrent() {
       if (current != null) return;
       synchronized (Tracing.class) {

brave/src/test/java/brave/ErrorParserTest.java

@@ -0,0 +1,33 @@
+package brave;
+
+import org.junit.Test;
+import org.junit.runner.RunWith;
+import org.mockito.Mock;
+import org.mockito.junit.MockitoJUnitRunner;
+
+import static org.mockito.Mockito.verify;
+import static org.mockito.Mockito.verifyNoMoreInteractions;
+
+@RunWith(MockitoJUnitRunner.class)
+public class ErrorParserTest {
+  @Mock SpanCustomizer customizer;
+  ErrorParser parser = new ErrorParser();
+
+  @Test public void error() {
+    parser.error(new RuntimeException("this cake is a lie"), customizer);
+
+    verify(customizer).tag("error", "this cake is a lie");
+  }
+
+  @Test public void error_noMessage() {
+    parser.error(new RuntimeException(), customizer);
+
+    verify(customizer).tag("error", "RuntimeException");
+  }
+
+  @Test public void error_noop() {
+    ErrorParser.NOOP.error(new RuntimeException("this cake is a lie"), customizer);
+
+    verifyNoMoreInteractions(customizer);
+  }
+}

brave/src/test/java/brave/RealSpanTest.java

@@ -122,4 +122,20 @@ public class RealSpanTest {
 
     assertThat(spans).hasSize(1);
   }
+
+  @Test public void error() {
+    span.error(new RuntimeException("this cake is a lie"));
+    span.flush();
+
+    assertThat(spans).flatExtracting(s -> s.tags().entrySet())
+        .containsExactly(entry("error", "this cake is a lie"));
+  }
+
+  @Test public void error_noMessage() {
+    span.error(new RuntimeException());
+    span.flush();
+
+    assertThat(spans).flatExtracting(s -> s.tags().entrySet())
+        .containsExactly(entry("error", "RuntimeException"));
+  }
 }

brave/src/test/java/brave/features/sampler/AspectJSamplerTest.java

@@ -84,7 +84,7 @@ public Object traceThing(ProceedingJoinPoint pjp, Traced traced) throws Throwabl
       try (Tracer.SpanInScope ws = tracer.withSpanInScope(span)) {
         return pjp.proceed();
       } catch (RuntimeException | Error e) {
-        span.tag("error", e.getMessage());
+        span.error(e);
         throw e;
       } finally {
         span.finish();