From 151b74446d65fd483972fbffe6720cc9fd164918 Mon Sep 17 00:00:00 2001 From: SylvainJuge <763082+SylvainJuge@users.noreply.github.com> Date: Mon, 16 Sep 2024 19:23:19 +0200 Subject: [PATCH] add span stacktrace config option (#1414) Co-authored-by: jackshirazi --- span-stacktrace/README.md | 16 +++- span-stacktrace/build.gradle.kts | 5 ++ .../stacktrace/StackTraceSpanProcessor.java | 33 +++++-- .../StackTraceSpanProcessorTest.java | 86 +++++++++++++------ 4 files changed, 106 insertions(+), 34 deletions(-) diff --git a/span-stacktrace/README.md b/span-stacktrace/README.md index 2cffbcb38..fcd9f6554 100644 --- a/span-stacktrace/README.md +++ b/span-stacktrace/README.md @@ -20,13 +20,17 @@ section below to configure it. ### Manual SDK setup Here is an example registration of `StackTraceSpanProcessor` to capture stack trace for all -the spans that have a duration >= 1000 ns. The spans that have an `ignorespan` string attribute +the spans that have a duration >= 1 ms. The spans that have an `ignorespan` string attribute will be ignored. ```java InMemorySpanExporter spansExporter = InMemorySpanExporter.create(); SpanProcessor exportProcessor = SimpleSpanProcessor.create(spansExporter); +Map configMap = new HashMap<>(); +configMap.put("otel.java.experimental.span-stacktrace.min.duration", "1ms"); +ConfigProperties config = DefaultConfigProperties.createFromMap(configMap); + Predicate filterPredicate = readableSpan -> { if(readableSpan.getAttribute(AttributeKey.stringKey("ignorespan")) != null){ return false; @@ -34,12 +38,20 @@ Predicate filterPredicate = readableSpan -> { return true; }; SdkTracerProvider tracerProvider = SdkTracerProvider.builder() - .addSpanProcessor(new StackTraceSpanProcessor(exportProcessor, 1000, filterPredicate)) + .addSpanProcessor(new StackTraceSpanProcessor(exportProcessor, config, filterPredicate)) .build(); OpenTelemetrySdk sdk = OpenTelemetrySdk.builder().setTracerProvider(tracerProvider).build(); ``` +### Configuration + +The `otel.java.experimental.span-stacktrace.min.duration` configuration option (defaults to 5ms) allows configuring +the minimal duration for which spans should have a stacktrace captured. + +Setting `otel.java.experimental.span-stacktrace.min.duration` to zero will include all spans, and using a negative +value will disable the feature. + ## Component owners - [Jack Shirazi](https://github.com/jackshirazi), Elastic diff --git a/span-stacktrace/build.gradle.kts b/span-stacktrace/build.gradle.kts index 80e861635..50901b6e4 100644 --- a/span-stacktrace/build.gradle.kts +++ b/span-stacktrace/build.gradle.kts @@ -10,5 +10,10 @@ dependencies { api("io.opentelemetry:opentelemetry-sdk") testImplementation("io.opentelemetry:opentelemetry-sdk-testing") + compileOnly("io.opentelemetry:opentelemetry-sdk-extension-autoconfigure") + compileOnly("io.opentelemetry:opentelemetry-sdk-extension-autoconfigure-spi") + testImplementation("io.opentelemetry:opentelemetry-sdk-extension-autoconfigure") + testImplementation("io.opentelemetry:opentelemetry-sdk-extension-autoconfigure-spi") + testImplementation("io.opentelemetry.semconv:opentelemetry-semconv-incubating") } diff --git a/span-stacktrace/src/main/java/io/opentelemetry/contrib/stacktrace/StackTraceSpanProcessor.java b/span-stacktrace/src/main/java/io/opentelemetry/contrib/stacktrace/StackTraceSpanProcessor.java index 4b9f99ad4..1714cc917 100644 --- a/span-stacktrace/src/main/java/io/opentelemetry/contrib/stacktrace/StackTraceSpanProcessor.java +++ b/span-stacktrace/src/main/java/io/opentelemetry/contrib/stacktrace/StackTraceSpanProcessor.java @@ -8,16 +8,22 @@ import io.opentelemetry.api.common.AttributeKey; import io.opentelemetry.contrib.stacktrace.internal.AbstractSimpleChainingSpanProcessor; import io.opentelemetry.contrib.stacktrace.internal.MutableSpan; +import io.opentelemetry.sdk.autoconfigure.spi.ConfigProperties; import io.opentelemetry.sdk.trace.ReadableSpan; import io.opentelemetry.sdk.trace.SpanProcessor; import java.io.PrintWriter; import java.io.StringWriter; +import java.time.Duration; import java.util.function.Predicate; import java.util.logging.Level; import java.util.logging.Logger; public class StackTraceSpanProcessor extends AbstractSimpleChainingSpanProcessor { + private static final String CONFIG_MIN_DURATION = + "otel.java.experimental.span-stacktrace.min.duration"; + private static final Duration CONFIG_MIN_DURATION_DEFAULT = Duration.ofMillis(5); + // inlined incubating attribute to prevent direct dependency on incubating semconv private static final AttributeKey SPAN_STACKTRACE = AttributeKey.stringKey("code.stacktrace"); @@ -38,10 +44,27 @@ public StackTraceSpanProcessor( 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); + if (minSpanDurationNanos < 0) { + logger.log(Level.FINE, "Stack traces capture is disabled"); + } else { + logger.log( + Level.FINE, + "Stack traces will be added to spans with a minimum duration of {0} nanos", + minSpanDurationNanos); + } + } + + /** + * @param next next span processor to invoke + * @param config configuration + * @param filterPredicate extra filter function to exclude spans if needed + */ + public StackTraceSpanProcessor( + SpanProcessor next, ConfigProperties config, Predicate filterPredicate) { + this( + next, + config.getDuration(CONFIG_MIN_DURATION, CONFIG_MIN_DURATION_DEFAULT).toNanos(), + filterPredicate); } @Override @@ -56,7 +79,7 @@ protected boolean requiresEnd() { @Override protected ReadableSpan doOnEnd(ReadableSpan span) { - if (span.getLatencyNanos() < minSpanDurationNanos) { + if (minSpanDurationNanos < 0 || span.getLatencyNanos() < minSpanDurationNanos) { return span; } if (span.getAttribute(SPAN_STACKTRACE) != null) { diff --git a/span-stacktrace/src/test/java/io/opentelemetry/contrib/stacktrace/StackTraceSpanProcessorTest.java b/span-stacktrace/src/test/java/io/opentelemetry/contrib/stacktrace/StackTraceSpanProcessorTest.java index 87cf2093b..0ddffec9e 100644 --- a/span-stacktrace/src/test/java/io/opentelemetry/contrib/stacktrace/StackTraceSpanProcessorTest.java +++ b/span-stacktrace/src/test/java/io/opentelemetry/contrib/stacktrace/StackTraceSpanProcessorTest.java @@ -13,58 +13,71 @@ import io.opentelemetry.context.Scope; import io.opentelemetry.contrib.stacktrace.internal.TestUtils; import io.opentelemetry.sdk.OpenTelemetrySdk; +import io.opentelemetry.sdk.autoconfigure.spi.internal.DefaultConfigProperties; import io.opentelemetry.sdk.testing.exporter.InMemorySpanExporter; import io.opentelemetry.sdk.trace.ReadableSpan; import io.opentelemetry.sdk.trace.SpanProcessor; import io.opentelemetry.sdk.trace.data.SpanData; import io.opentelemetry.sdk.trace.export.SimpleSpanProcessor; import io.opentelemetry.semconv.incubating.CodeIncubatingAttributes; +import java.time.Duration; import java.time.Instant; +import java.util.HashMap; import java.util.List; +import java.util.Map; import java.util.function.Consumer; import java.util.function.Function; import java.util.function.Predicate; -import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; class StackTraceSpanProcessorTest { - private InMemorySpanExporter spansExporter; - private SpanProcessor exportProcessor; - - @BeforeEach - public void setup() { - spansExporter = InMemorySpanExporter.create(); - exportProcessor = SimpleSpanProcessor.create(spansExporter); + private static long msToNs(int ms) { + return Duration.ofMillis(ms).toNanos(); } @Test void durationAndFiltering() { + // on duration threshold + checkSpanWithStackTrace(span -> true, "1ms", msToNs(1)); // over duration threshold - testSpan(span -> true, 11, 1); + checkSpanWithStackTrace(span -> true, "1ms", msToNs(2)); // under duration threshold - testSpan(span -> true, 9, 0); + checkSpanWithoutStackTrace(span -> true, "2ms", msToNs(1)); // filtering out span - testSpan(span -> false, 20, 0); + checkSpanWithoutStackTrace(span -> false, "1ms", 20); + } + + @Test + void defaultConfig() { + long expectedDefault = msToNs(5); + checkSpanWithStackTrace(span -> true, null, expectedDefault); + checkSpanWithStackTrace(span -> true, null, expectedDefault + 1); + checkSpanWithoutStackTrace(span -> true, null, expectedDefault - 1); + } + + @Test + void disabledConfig() { + checkSpanWithoutStackTrace(span -> true, "-1", 5); } @Test void spanWithExistingStackTrace() { - testSpan( + checkSpan( span -> true, - 20, - 1, + "1ms", + Duration.ofMillis(1).toNanos(), sb -> sb.setAttribute(CodeIncubatingAttributes.CODE_STACKTRACE, "hello"), stacktrace -> assertThat(stacktrace).isEqualTo("hello")); } - private void testSpan( - Predicate filterPredicate, long spanDurationNanos, int expectedSpansCount) { - testSpan( + private static void checkSpanWithStackTrace( + Predicate filterPredicate, String configString, long spanDurationNanos) { + checkSpan( filterPredicate, + configString, spanDurationNanos, - expectedSpansCount, Function.identity(), (stackTrace) -> assertThat(stackTrace) @@ -72,14 +85,35 @@ private void testSpan( .contains(StackTraceSpanProcessorTest.class.getCanonicalName())); } - private void testSpan( + private static void checkSpanWithoutStackTrace( + Predicate filterPredicate, String configString, long spanDurationNanos) { + checkSpan( + filterPredicate, + configString, + spanDurationNanos, + Function.identity(), + (stackTrace) -> assertThat(stackTrace).describedAs("no stack trace expected").isNull()); + } + + private static void checkSpan( Predicate filterPredicate, + String configString, long spanDurationNanos, - int expectedSpansCount, Function customizeSpanBuilder, Consumer stackTraceCheck) { + + // they must be re-created as they are shutdown when the span processor is closed + InMemorySpanExporter spansExporter = InMemorySpanExporter.create(); + SpanProcessor exportProcessor = SimpleSpanProcessor.create(spansExporter); + + Map configMap = new HashMap<>(); + if (configString != null) { + configMap.put("otel.java.experimental.span-stacktrace.min.duration", configString); + } + try (SpanProcessor processor = - new StackTraceSpanProcessor(exportProcessor, 10, filterPredicate)) { + new StackTraceSpanProcessor( + exportProcessor, DefaultConfigProperties.createFromMap(configMap), filterPredicate)) { OpenTelemetrySdk sdk = TestUtils.sdkWith(processor); Tracer tracer = sdk.getTracer("test"); @@ -96,14 +130,12 @@ private void testSpan( } List finishedSpans = spansExporter.getFinishedSpanItems(); - assertThat(finishedSpans).hasSize(expectedSpansCount); + assertThat(finishedSpans).hasSize(1); - if (!finishedSpans.isEmpty()) { - String stackTrace = - finishedSpans.get(0).getAttributes().get(CodeIncubatingAttributes.CODE_STACKTRACE); + String stackTrace = + finishedSpans.get(0).getAttributes().get(CodeIncubatingAttributes.CODE_STACKTRACE); - stackTraceCheck.accept(stackTrace); - } + stackTraceCheck.accept(stackTrace); } } }