Skip to content

Commit

Permalink
add span stacktrace config option (open-telemetry#1414)
Browse files Browse the repository at this point in the history
Co-authored-by: jackshirazi <[email protected]>
  • Loading branch information
2 people authored and robsunday committed Sep 17, 2024
1 parent 9ee5fb1 commit 151b744
Show file tree
Hide file tree
Showing 4 changed files with 106 additions and 34 deletions.
16 changes: 14 additions & 2 deletions span-stacktrace/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -20,26 +20,38 @@ 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<String, String> configMap = new HashMap<>();
configMap.put("otel.java.experimental.span-stacktrace.min.duration", "1ms");
ConfigProperties config = DefaultConfigProperties.createFromMap(configMap);

Predicate<ReadableSpan> filterPredicate = readableSpan -> {
if(readableSpan.getAttribute(AttributeKey.stringKey("ignorespan")) != null){
return false;
}
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
Expand Down
5 changes: 5 additions & 0 deletions span-stacktrace/build.gradle.kts
Original file line number Diff line number Diff line change
Expand Up @@ -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")
}
Original file line number Diff line number Diff line change
Expand Up @@ -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<String> SPAN_STACKTRACE =
AttributeKey.stringKey("code.stacktrace");
Expand All @@ -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<ReadableSpan> filterPredicate) {
this(
next,
config.getDuration(CONFIG_MIN_DURATION, CONFIG_MIN_DURATION_DEFAULT).toNanos(),
filterPredicate);
}

@Override
Expand All @@ -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) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -13,73 +13,107 @@
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<ReadableSpan> filterPredicate, long spanDurationNanos, int expectedSpansCount) {
testSpan(
private static void checkSpanWithStackTrace(
Predicate<ReadableSpan> filterPredicate, String configString, long spanDurationNanos) {
checkSpan(
filterPredicate,
configString,
spanDurationNanos,
expectedSpansCount,
Function.identity(),
(stackTrace) ->
assertThat(stackTrace)
.describedAs("span stack trace should contain caller class name")
.contains(StackTraceSpanProcessorTest.class.getCanonicalName()));
}

private void testSpan(
private static void checkSpanWithoutStackTrace(
Predicate<ReadableSpan> 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<ReadableSpan> filterPredicate,
String configString,
long spanDurationNanos,
int expectedSpansCount,
Function<SpanBuilder, SpanBuilder> customizeSpanBuilder,
Consumer<String> 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<String, String> 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");
Expand All @@ -96,14 +130,12 @@ private void testSpan(
}

List<SpanData> 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);
}
}
}

0 comments on commit 151b744

Please sign in to comment.