Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

add span stacktrace config option #1414

Merged
merged 16 commits into from
Sep 16, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
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
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The delimiter situation is always a bit hard.. Thoughts:

  • The autoconfigure module automatically turns any - into ., so there doesn't seem to be any point in introducing other delimeters.
  • I could see this evolving to have a log record processor one day, in which case nesting the properties under otel.java.experimental.stacktrace.* (or otel.java.experimental.stacktraceprocessor.*) would allow for a more uniform property schema. But on the other hand, the component is currently named *-span-stacktrace - maybe the component name is worth revisiting?
Suggested change
The `otel.java.experimental.span-stacktrace.min.duration` configuration option (defaults to 5ms) allows configuring
The `otel.java.experimental.stacktrace.span.min.duration` configuration option (defaults to 5ms) allows configuring

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm fine to remove - and replace it with ., for now we just need to have one configuration option to start, we will of course need to revise this later when making this feature stable.

I think the suggestion to use - in the feature name came from what we currently have for otel.java.experimental.span-attributes.copy-from-baggage.include in the baggage-processor, which by the way isn't really consistent as we have otel.java.experimental.span-attributes as prefix for a module named baggage-processor.

As long as things are not marked as stable, I think those minor inconsistencies are fine and acceptable, especially in the contrib repo where things are mostly alpha.


However we probably need to have some proper definition somewhere about those configuration options, for example to at least define what are the main namespaces like otel.java.*, otel.javaagent.* or otel.java.experimental.* or even define a global registry with all the possible options to ensure there isn't any conflict between all the repositories. Also, this might be something also happening in other platforms & otel components SIGs.

However that's definitely something that will take a while and should be covered separately, and I know that it sounds like "let's start another SIG about configuration options" 😄 .

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ha - well unfortunately I doubt we'll get any additional clarity around property naming anytime soon. There's already a dedicated config sig (which I lead), focussing on building out declarative configuration which aims to replace the system property / env var config scheme as the dominant mechanism for configuration. That's where all the configuration effort is being spent these days.

I think you're right to stick with precedents that already exist in this repo - I wasn't aware of those.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ok, then let's stick to otel.java.experimental.span-stacktrace.min.duration for now if you agree and we can always change it later as it's experimental, we can even still support the current experimental config for as long as we'd like.

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);
}
}
}
Loading