stacktrace span processor (#1255)

Author: SylvainJuge

.github/component_owners.yml

@@ -66,3 +66,7 @@ components:
   kafka-exporter:
     - spockz
     - vincentfree
+  span-stacktrace:
+    - jackshirazi
+    - jonaskunz
+    - sylvainjuge

settings.gradle.kts

@@ -86,3 +86,4 @@ include(":static-instrumenter:bootstrap")
 include(":static-instrumenter:test-app")
 include(":kafka-exporter")
 include(":gcp-resources")
+include(":span-stacktrace")

span-stacktrace/README.md

@@ -0,0 +1,18 @@
+
+# Span stacktrace capture
+
+This module provides a `SpanProcessor` that captures the [`code.stacktrace`](https://opentelemetry.io/docs/specs/semconv/attributes-registry/code/).
+
+Capturing the stack trace is an expensive operation and does not provide any value on short-lived spans.
+As a consequence it should only be used when the span duration is known, thus on span end.
+
+However, the current SDK API does not allow to modify span attributes on span end, so we have to
+introduce other components to make it work as expected.
+
+## Component owners
+
+- [Jack Shirazi](https://github.com/jackshirazi), Elastic
+- [Jonas Kunz](https://github.com/jonaskunz), Elastic
+- [Sylvain Juge](https://github.com/sylvainjuge), Elastic
+
+Learn more about component owners in [component_owners.yml](../.github/component_owners.yml).

span-stacktrace/build.gradle.kts

@@ -0,0 +1,10 @@
+plugins {
+  id("otel.java-conventions")
+}
+
+description = "OpenTelemetry Java span stacktrace capture module"
+
+dependencies {
+  api("io.opentelemetry:opentelemetry-sdk")
+  testImplementation("io.opentelemetry:opentelemetry-sdk-testing")
+}

span-stacktrace/src/main/java/io/opentelemetry/contrib/stacktrace/StackTraceSpanProcessor.java

@@ -0,0 +1,99 @@
+/*
+ * Copyright The OpenTelemetry Authors
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+package io.opentelemetry.contrib.stacktrace;
+
+import io.opentelemetry.api.common.AttributeKey;
+import io.opentelemetry.contrib.stacktrace.internal.AbstractSimpleChainingSpanProcessor;
+import io.opentelemetry.contrib.stacktrace.internal.MutableSpan;
+import io.opentelemetry.sdk.trace.ReadableSpan;
+import io.opentelemetry.sdk.trace.SpanProcessor;
+import java.io.PrintWriter;
+import java.io.StringWriter;
+import java.util.function.Predicate;
+import java.util.logging.Level;
+import java.util.logging.Logger;
+
+public class StackTraceSpanProcessor extends AbstractSimpleChainingSpanProcessor {
+
+  // TODO : remove this once semconv 1.24.0 is available
+  static final AttributeKey<String> SPAN_STACKTRACE = AttributeKey.stringKey("code.stacktrace");
+
+  private static final Logger logger = Logger.getLogger(StackTraceSpanProcessor.class.getName());
+
+  private final long minSpanDurationNanos;
+
+  private final Predicate<ReadableSpan> filterPredicate;
+
+  /**
+   * @param next next span processor to invoke
+   * @param minSpanDurationNanos minimum span duration in ns for stacktrace capture
+   * @param filterPredicate extra filter function to exclude spans if needed
+   */
+  public StackTraceSpanProcessor(
+      SpanProcessor next, long minSpanDurationNanos, Predicate<ReadableSpan> filterPredicate) {
+    super(next);
+    this.minSpanDurationNanos = minSpanDurationNanos;
+    this.filterPredicate = filterPredicate;
+    logger.log(
+        Level.FINE,
+        "Stack traces will be added to spans with a minimum duration of {0} nanos",
+        minSpanDurationNanos);
+  }
+
+  @Override
+  protected boolean requiresStart() {
+    return false;
+  }
+
+  @Override
+  protected boolean requiresEnd() {
+    return true;
+  }
+
+  @Override
+  protected ReadableSpan doOnEnd(ReadableSpan span) {
+    if (span.getLatencyNanos() < minSpanDurationNanos) {
+      return span;
+    }
+    if (span.getAttribute(SPAN_STACKTRACE) != null) {
+      // Span already has a stacktrace, do not override
+      return span;
+    }
+    if (!filterPredicate.test(span)) {
+      return span;
+    }
+    MutableSpan mutableSpan = MutableSpan.makeMutable(span);
+
+    String stacktrace = generateSpanEndStacktrace();
+    mutableSpan.setAttribute(SPAN_STACKTRACE, stacktrace);
+    return mutableSpan;
+  }
+
+  private static String generateSpanEndStacktrace() {
+    Throwable exception = new Throwable();
+    StringWriter stringWriter = new StringWriter();
+    try (PrintWriter printWriter = new PrintWriter(stringWriter)) {
+      exception.printStackTrace(printWriter);
+    }
+    return removeInternalFrames(stringWriter.toString());
+  }
+
+  private static String removeInternalFrames(String stackTrace) {
+    String lastInternal = "at io.opentelemetry.sdk.trace.SdkSpan.end";
+
+    int idx = stackTrace.lastIndexOf(lastInternal);
+    if (idx == -1) {
+      // should usually not happen, this means that the span processor was called from somewhere
+      // else
+      return stackTrace;
+    }
+    int nextNewLine = stackTrace.indexOf('\n', idx);
+    if (nextNewLine == -1) {
+      nextNewLine = stackTrace.length() - 1;
+    }
+    return stackTrace.substring(nextNewLine + 1);
+  }
+}

span-stacktrace/src/main/java/io/opentelemetry/contrib/stacktrace/internal/AbstractSimpleChainingSpanProcessor.java

@@ -0,0 +1,139 @@
+/*
+ * Copyright The OpenTelemetry Authors
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+package io.opentelemetry.contrib.stacktrace.internal;
+
+import com.google.errorprone.annotations.CanIgnoreReturnValue;
+import io.opentelemetry.context.Context;
+import io.opentelemetry.sdk.common.CompletableResultCode;
+import io.opentelemetry.sdk.trace.ReadWriteSpan;
+import io.opentelemetry.sdk.trace.ReadableSpan;
+import io.opentelemetry.sdk.trace.SpanProcessor;
+import java.util.Arrays;
+
+/**
+ * A @{@link SpanProcessor} which in addition to all standard operations is capable of modifying and
+ * optionally filtering spans in the end-callback.
+ *
+ * <p>This is done by chaining processors and registering only the first processor with the SDK.
+ * Mutations can be performed in {@link #doOnEnd(ReadableSpan)} by wrapping the span in a {@link
+ * MutableSpan}
+ */
+public abstract class AbstractSimpleChainingSpanProcessor implements SpanProcessor {
+
+  protected final SpanProcessor next;
+  private final boolean nextRequiresStart;
+  private final boolean nextRequiresEnd;
+
+  /**
+   * @param next the next processor to be invoked after the one being constructed.
+   */
+  public AbstractSimpleChainingSpanProcessor(SpanProcessor next) {
+    this.next = next;
+    nextRequiresStart = next.isStartRequired();
+    nextRequiresEnd = next.isEndRequired();
+  }
+
+  /**
+   * Equivalent of {@link SpanProcessor#onStart(Context, ReadWriteSpan)}. The onStart callback of
+   * the next processor must not be invoked from this method, this is already handled by the
+   * implementation of {@link #onStart(Context, ReadWriteSpan)}.
+   */
+  protected void doOnStart(Context context, ReadWriteSpan readWriteSpan) {}
+
+  /**
+   * Equivalent of {@link SpanProcessor#onEnd(ReadableSpan)}}.
+   *
+   * <p>If this method returns null, the provided span will be dropped and not passed to the next
+   * processor. If anything non-null is returned, the returned instance is passed to the next
+   * processor.
+   *
+   * <p>So in order to mutate the span, simply use {@link MutableSpan#makeMutable(ReadableSpan)} on
+   * the provided argument and return the {@link MutableSpan} from this method.
+   */
+  @CanIgnoreReturnValue
+  protected ReadableSpan doOnEnd(ReadableSpan readableSpan) {
+    return readableSpan;
+  }
+
+  /**
+   * Indicates if span processor needs to be called on span start
+   *
+   * @return true, if this implementation would like {@link #doOnStart(Context, ReadWriteSpan)} to
+   *     be invoked.
+   */
+  protected boolean requiresStart() {
+    return true;
+  }
+
+  /**
+   * Indicates if span processor needs to be called on span end
+   *
+   * @return true, if this implementation would like {@link #doOnEnd(ReadableSpan)} to be invoked.
+   */
+  protected boolean requiresEnd() {
+    return true;
+  }
+
+  protected CompletableResultCode doForceFlush() {
+    return CompletableResultCode.ofSuccess();
+  }
+
+  protected CompletableResultCode doShutdown() {
+    return CompletableResultCode.ofSuccess();
+  }
+
+  @Override
+  public final void onStart(Context context, ReadWriteSpan readWriteSpan) {
+    try {
+      if (requiresStart()) {
+        doOnStart(context, readWriteSpan);
+      }
+    } finally {
+      if (nextRequiresStart) {
+        next.onStart(context, readWriteSpan);
+      }
+    }
+  }
+
+  @Override
+  public final void onEnd(ReadableSpan readableSpan) {
+    ReadableSpan mappedTo = readableSpan;
+    try {
+      if (requiresEnd()) {
+        mappedTo = doOnEnd(readableSpan);
+      }
+    } finally {
+      if (mappedTo != null && nextRequiresEnd) {
+        next.onEnd(mappedTo);
+      }
+    }
+  }
+
+  @Override
+  public final boolean isStartRequired() {
+    return requiresStart() || nextRequiresStart;
+  }
+
+  @Override
+  public final boolean isEndRequired() {
+    return requiresEnd() || nextRequiresEnd;
+  }
+
+  @Override
+  public final CompletableResultCode shutdown() {
+    return CompletableResultCode.ofAll(Arrays.asList(doShutdown(), next.shutdown()));
+  }
+
+  @Override
+  public final CompletableResultCode forceFlush() {
+    return CompletableResultCode.ofAll(Arrays.asList(doForceFlush(), next.forceFlush()));
+  }
+
+  @Override
+  public final void close() {
+    SpanProcessor.super.close();
+  }
+}