diff --git a/inferred-spans/README.md b/inferred-spans/README.md index 33560a9aa..56ae21a5b 100644 --- a/inferred-spans/README.md +++ b/inferred-spans/README.md @@ -41,6 +41,8 @@ So if you are using an autoconfigured OpenTelemetry SDK, you'll only need to add | otel.inferred.spans.interval
OTEL_INFERRED_SPANS_INTERVAL | `5s` | The interval at which profiling sessions should be started. | | otel.inferred.spans.duration
OTEL_INFERRED_SPANS_DURATION | `5s` | The duration of a profiling session. For sampled transactions which fall within a profiling session (they start after and end before the session), so-called inferred spans will be created. They appear in the trace waterfall view like regular spans.
NOTE: It is not recommended to set much higher durations as it may fill the activation events file and async-profiler's frame buffer. Warnings will be logged if the activation events file is full. If you want to have more profiling coverage, try decreasing `profiling_inferred_spans_interval` | | otel.inferred.spans.lib.directory
OTEL_INFERRED_SPANS_LIB_DIRECTORY | Defaults to the value of `java.io.tmpdir` | Profiling requires that the [async-profiler](https://github.com/async-profiler/async-profiler) shared library is exported to a temporary location and loaded by the JVM. The partition backing this location must be executable, however in some server-hardened environments, `noexec` may be set on the standard `/tmp` partition, leading to `java.lang.UnsatisfiedLinkError` errors. Set this property to an alternative directory (e.g. `/var/tmp`) to resolve this. | +| otel.inferred.spans.duration
OTEL_INFERRED_SPANS_DURATION | `5s` | The duration of a profiling session. For sampled transactions which fall within a profiling session (they start after and end before the session), so-called inferred spans will be created. They appear in the trace waterfall view like regular spans.
NOTE: It is not recommended to set much higher durations as it may fill the activation events file and async-profiler's frame buffer. Warnings will be logged if the activation events file is full. If you want to have more profiling coverage, try decreasing `profiling_inferred_spans_interval` | +| otel.inferred.spans.parent.override.handler
OTEL_INFERRED_SPANS_PARENT_OVERRIDE_HANDLER | Defaults to a handler adding span-links to the inferred span | Inferred spans sometimes need to be inserted as the new parent of a normal span, which is not directly possible because that span has already been sent. For this reason, this relationship needs to be represented differently, which normally is done by adding a span-link to the inferred span. This configuration can be used to override that behaviour by providing the fully qualified name of a class implementing `BiConsumer`: The biconsumer will be invoked with the inferred span as first argument and the span for which the inferred one was detected as new parent as second argument | ### Manual SDK setup diff --git a/inferred-spans/src/main/java/io/opentelemetry/contrib/inferredspans/InferredSpansAutoConfig.java b/inferred-spans/src/main/java/io/opentelemetry/contrib/inferredspans/InferredSpansAutoConfig.java index a64bb2641..6a4e1ba00 100644 --- a/inferred-spans/src/main/java/io/opentelemetry/contrib/inferredspans/InferredSpansAutoConfig.java +++ b/inferred-spans/src/main/java/io/opentelemetry/contrib/inferredspans/InferredSpansAutoConfig.java @@ -6,12 +6,15 @@ package io.opentelemetry.contrib.inferredspans; import com.google.auto.service.AutoService; +import io.opentelemetry.api.trace.SpanBuilder; +import io.opentelemetry.api.trace.SpanContext; import io.opentelemetry.sdk.autoconfigure.spi.AutoConfigurationCustomizer; import io.opentelemetry.sdk.autoconfigure.spi.AutoConfigurationCustomizerProvider; import io.opentelemetry.sdk.autoconfigure.spi.ConfigProperties; import java.time.Duration; import java.util.Arrays; import java.util.List; +import java.util.function.BiConsumer; import java.util.function.Consumer; import java.util.logging.Logger; import java.util.stream.Collectors; @@ -34,6 +37,8 @@ public class InferredSpansAutoConfig implements AutoConfigurationCustomizerProvi static final String INTERVAL_OPTION = "otel.inferred.spans.interval"; static final String DURATION_OPTION = "otel.inferred.spans.duration"; static final String LIB_DIRECTORY_OPTION = "otel.inferred.spans.lib.directory"; + static final String PARENT_OVERRIDE_HANDLER_OPTION = + "otel.inferred.spans.parent.override.handler"; @Override public void customize(AutoConfigurationCustomizer config) { @@ -56,6 +61,12 @@ public void customize(AutoConfigurationCustomizer config) { applier.applyDuration(DURATION_OPTION, builder::profilingDuration); applier.applyString(LIB_DIRECTORY_OPTION, builder::profilerLibDirectory); + String parentOverrideHandlerName = properties.getString(PARENT_OVERRIDE_HANDLER_OPTION); + if (parentOverrideHandlerName != null && !parentOverrideHandlerName.isEmpty()) { + builder.parentOverrideHandler( + constructParentOverrideHandler(parentOverrideHandlerName)); + } + providerBuilder.addSpanProcessor(builder.build()); } else { log.finest( @@ -65,6 +76,16 @@ public void customize(AutoConfigurationCustomizer config) { }); } + @SuppressWarnings("unchecked") + private static BiConsumer constructParentOverrideHandler(String name) { + try { + Class clazz = Class.forName(name); + return (BiConsumer) clazz.getConstructor().newInstance(); + } catch (Exception e) { + throw new IllegalArgumentException("Could not construct parent override handler", e); + } + } + private static class PropertiesApplier { private final ConfigProperties properties; diff --git a/inferred-spans/src/main/java/io/opentelemetry/contrib/inferredspans/InferredSpansProcessorBuilder.java b/inferred-spans/src/main/java/io/opentelemetry/contrib/inferredspans/InferredSpansProcessorBuilder.java index de28a8709..3e487bd6b 100644 --- a/inferred-spans/src/main/java/io/opentelemetry/contrib/inferredspans/InferredSpansProcessorBuilder.java +++ b/inferred-spans/src/main/java/io/opentelemetry/contrib/inferredspans/InferredSpansProcessorBuilder.java @@ -5,12 +5,16 @@ package io.opentelemetry.contrib.inferredspans; +import io.opentelemetry.api.trace.SpanBuilder; +import io.opentelemetry.api.trace.SpanContext; +import io.opentelemetry.contrib.inferredspans.internal.CallTree; import io.opentelemetry.contrib.inferredspans.internal.InferredSpansConfiguration; import io.opentelemetry.contrib.inferredspans.internal.SpanAnchoredClock; import java.io.File; import java.time.Duration; import java.util.Arrays; import java.util.List; +import java.util.function.BiConsumer; import javax.annotation.Nullable; @SuppressWarnings("CanIgnoreReturnValueSuggester") @@ -48,6 +52,8 @@ public class InferredSpansProcessorBuilder { @Nullable private File activationEventsFile = null; @Nullable private File jfrFile = null; + private BiConsumer parentOverrideHandler = + CallTree.DEFAULT_PARENT_OVERRIDE; InferredSpansProcessorBuilder() {} @@ -64,7 +70,8 @@ public InferredSpansProcessor build() { excludedClasses, profilerInterval, profilingDuration, - profilerLibDirectory); + profilerLibDirectory, + parentOverrideHandler); return new InferredSpansProcessor( config, clock, startScheduledProfiling, activationEventsFile, jfrFile); } @@ -188,4 +195,17 @@ InferredSpansProcessorBuilder jfrFile(@Nullable File jfrFile) { this.jfrFile = jfrFile; return this; } + + /** + * Defines the action to perform when a inferred span is discovered to actually be the parent of a + * normal span. The first argument of the handler is the modifiable inferred span, the second + * argument the span context of the normal span which should be somehow marked as child of the + * inferred one. By default, a span link is added to the inferred span to represent this + * relationship. + */ + InferredSpansProcessorBuilder parentOverrideHandler( + BiConsumer handler) { + this.parentOverrideHandler = handler; + return this; + } } diff --git a/inferred-spans/src/main/java/io/opentelemetry/contrib/inferredspans/internal/CallTree.java b/inferred-spans/src/main/java/io/opentelemetry/contrib/inferredspans/internal/CallTree.java index fa8540e30..74468a3fd 100644 --- a/inferred-spans/src/main/java/io/opentelemetry/contrib/inferredspans/internal/CallTree.java +++ b/inferred-spans/src/main/java/io/opentelemetry/contrib/inferredspans/internal/CallTree.java @@ -25,6 +25,7 @@ import java.util.Arrays; import java.util.List; import java.util.concurrent.TimeUnit; +import java.util.function.BiConsumer; import java.util.logging.Logger; import javax.annotation.Nullable; import org.agrona.collections.LongHashSet; @@ -50,9 +51,12 @@ public class CallTree implements Recyclable { private static final int INITIAL_CHILD_SIZE = 2; - private static final Attributes CHILD_LINK_ATTRIBUTES = + public static final Attributes CHILD_LINK_ATTRIBUTES = Attributes.builder().put(LINK_IS_CHILD, true).build(); + public static final BiConsumer DEFAULT_PARENT_OVERRIDE = + (inferredSpan, child) -> inferredSpan.addLink(child, CHILD_LINK_ATTRIBUTES); + @Nullable private CallTree parent; protected int count; private List children = new ArrayList<>(INITIAL_CHILD_SIZE); @@ -427,6 +431,7 @@ int spanify( @Nullable Span parentSpan, TraceContext parentContext, SpanAnchoredClock clock, + BiConsumer spanParentOverride, StringBuilder tempBuilder, Tracer tracer) { int createdSpans = 0; @@ -437,7 +442,8 @@ int spanify( Span span = null; if (!isPillar() || isLeaf()) { createdSpans++; - span = asSpan(root, parentSpan, parentContext, tracer, clock, tempBuilder); + span = + asSpan(root, parentSpan, parentContext, tracer, clock, spanParentOverride, tempBuilder); this.isSpan = true; } List children = getChildren(); @@ -450,6 +456,7 @@ int spanify( span != null ? span : parentSpan, parentContext, clock, + spanParentOverride, tempBuilder, tracer); } @@ -462,6 +469,7 @@ protected Span asSpan( TraceContext parentContext, Tracer tracer, SpanAnchoredClock clock, + BiConsumer spanParentOverride, StringBuilder tempBuilder) { Context parentOtelCtx; @@ -494,7 +502,11 @@ protected Span asSpan( clock.toEpochNanos(parentContext.getClockAnchor(), this.start), TimeUnit.NANOSECONDS); insertChildIdLinks( - spanBuilder, Span.fromContext(parentOtelCtx).getSpanContext(), parentContext, tempBuilder); + spanBuilder, + Span.fromContext(parentOtelCtx).getSpanContext(), + parentContext, + spanParentOverride, + tempBuilder); // we're not interested in the very bottom of the stack which contains things like accepting and // handling connections @@ -517,6 +529,7 @@ private void insertChildIdLinks( SpanBuilder span, SpanContext parentContext, TraceContext nonInferredParent, + BiConsumer spanParentOverride, StringBuilder tempBuilder) { if (childIds == null || childIds.isEmpty()) { return; @@ -527,13 +540,13 @@ private void insertChildIdLinks( if (nonInferredParent.getSpanId() == childIds.getParentId(i)) { tempBuilder.setLength(0); HexUtils.appendLongAsHex(childIds.getId(i), tempBuilder); - SpanContext spanContext = + SpanContext childSpanContext = SpanContext.create( parentContext.getTraceId(), tempBuilder.toString(), parentContext.getTraceFlags(), parentContext.getTraceState()); - span.addLink(spanContext, CHILD_LINK_ATTRIBUTES); + spanParentOverride.accept(span, childSpanContext); } } } @@ -863,13 +876,18 @@ private static CallTree findCommonAncestor(CallTree previousTopOfStack, CallTree * possible to update the parent ID of a regular span so that it correctly reflects being a * child of an inferred span. */ - public int spanify(SpanAnchoredClock clock, Tracer tracer) { + public int spanify( + SpanAnchoredClock clock, + Tracer tracer, + BiConsumer normalSpanOverride) { StringBuilder tempBuilder = new StringBuilder(); int createdSpans = 0; List callTrees = getChildren(); for (int i = 0, size = callTrees.size(); i < size; i++) { createdSpans += - callTrees.get(i).spanify(this, null, rootContext, clock, tempBuilder, tracer); + callTrees + .get(i) + .spanify(this, null, rootContext, clock, normalSpanOverride, tempBuilder, tracer); } return createdSpans; } diff --git a/inferred-spans/src/main/java/io/opentelemetry/contrib/inferredspans/internal/InferredSpansConfiguration.java b/inferred-spans/src/main/java/io/opentelemetry/contrib/inferredspans/internal/InferredSpansConfiguration.java index 7652982c3..5091a36a5 100644 --- a/inferred-spans/src/main/java/io/opentelemetry/contrib/inferredspans/internal/InferredSpansConfiguration.java +++ b/inferred-spans/src/main/java/io/opentelemetry/contrib/inferredspans/internal/InferredSpansConfiguration.java @@ -5,9 +5,12 @@ package io.opentelemetry.contrib.inferredspans.internal; +import io.opentelemetry.api.trace.SpanBuilder; +import io.opentelemetry.api.trace.SpanContext; import io.opentelemetry.contrib.inferredspans.WildcardMatcher; import java.time.Duration; import java.util.List; +import java.util.function.BiConsumer; import javax.annotation.Nullable; public class InferredSpansConfiguration { @@ -22,8 +25,8 @@ public class InferredSpansConfiguration { private final List excludedClasses; private final Duration profilerInterval; private final Duration profilingDuration; - @Nullable private final String profilerLibDirectory; + private final BiConsumer parentOverrideHandler; @SuppressWarnings("TooManyParameters") public InferredSpansConfiguration( @@ -37,7 +40,8 @@ public InferredSpansConfiguration( List excludedClasses, Duration profilerInterval, Duration profilingDuration, - @Nullable String profilerLibDirectory) { + @Nullable String profilerLibDirectory, + BiConsumer parentOverrideHandler) { this.profilerLoggingEnabled = profilerLoggingEnabled; this.backupDiagnosticFiles = backupDiagnosticFiles; this.asyncProfilerSafeMode = asyncProfilerSafeMode; @@ -49,6 +53,7 @@ public InferredSpansConfiguration( this.profilerInterval = profilerInterval; this.profilingDuration = profilingDuration; this.profilerLibDirectory = profilerLibDirectory; + this.parentOverrideHandler = parentOverrideHandler; } public boolean isProfilingLoggingEnabled() { @@ -100,4 +105,8 @@ public String getProfilerLibDirectory() { public boolean isPostProcessingEnabled() { return postProcessingEnabled; } + + public BiConsumer getParentOverrideHandler() { + return parentOverrideHandler; + } } diff --git a/inferred-spans/src/main/java/io/opentelemetry/contrib/inferredspans/internal/SamplingProfiler.java b/inferred-spans/src/main/java/io/opentelemetry/contrib/inferredspans/internal/SamplingProfiler.java index b3282ae0b..d05496084 100644 --- a/inferred-spans/src/main/java/io/opentelemetry/contrib/inferredspans/internal/SamplingProfiler.java +++ b/inferred-spans/src/main/java/io/opentelemetry/contrib/inferredspans/internal/SamplingProfiler.java @@ -952,7 +952,10 @@ private void stopProfiling(SamplingProfiler samplingProfiler) { callTree.end( samplingProfiler.callTreePool, samplingProfiler.getInferredSpansMinDurationNs()); int createdSpans = - callTree.spanify(samplingProfiler.getClock(), samplingProfiler.tracerProvider.get()); + callTree.spanify( + samplingProfiler.getClock(), + samplingProfiler.tracerProvider.get(), + samplingProfiler.config.getParentOverrideHandler()); if (logger.isLoggable(Level.FINE)) { if (createdSpans > 0) { logger.log( diff --git a/inferred-spans/src/test/java/io/opentelemetry/contrib/inferredspans/InferredSpansAutoConfigTest.java b/inferred-spans/src/test/java/io/opentelemetry/contrib/inferredspans/InferredSpansAutoConfigTest.java index 432d9f84f..1b6a7e3e2 100644 --- a/inferred-spans/src/test/java/io/opentelemetry/contrib/inferredspans/InferredSpansAutoConfigTest.java +++ b/inferred-spans/src/test/java/io/opentelemetry/contrib/inferredspans/InferredSpansAutoConfigTest.java @@ -11,6 +11,8 @@ import io.opentelemetry.api.GlobalOpenTelemetry; import io.opentelemetry.api.OpenTelemetry; import io.opentelemetry.api.trace.Span; +import io.opentelemetry.api.trace.SpanBuilder; +import io.opentelemetry.api.trace.SpanContext; import io.opentelemetry.api.trace.Tracer; import io.opentelemetry.context.Scope; import io.opentelemetry.contrib.inferredspans.internal.InferredSpansConfiguration; @@ -23,6 +25,7 @@ import java.nio.file.Path; import java.time.Duration; import java.util.List; +import java.util.function.BiConsumer; import java.util.stream.Collectors; import org.junit.jupiter.api.AfterEach; import org.junit.jupiter.api.BeforeEach; @@ -40,6 +43,12 @@ public void resetGlobalOtel() { OtelReflectionUtils.shutdownAndResetGlobalOtel(); } + public static class NoOpParentOverrideHandler implements BiConsumer { + + @Override + public void accept(SpanBuilder spanBuilder, SpanContext spanContext) {} + } + @Test @DisabledOnOpenJ9 public void checkAllOptions(@TempDir Path tmpDir) { @@ -57,7 +66,10 @@ public void checkAllOptions(@TempDir Path tmpDir) { .put(InferredSpansAutoConfig.EXCLUDED_CLASSES_OPTION, "blub,test*.test2") .put(InferredSpansAutoConfig.INTERVAL_OPTION, "2s") .put(InferredSpansAutoConfig.DURATION_OPTION, "3s") - .put(InferredSpansAutoConfig.LIB_DIRECTORY_OPTION, libDir)) { + .put(InferredSpansAutoConfig.LIB_DIRECTORY_OPTION, libDir) + .put( + InferredSpansAutoConfig.PARENT_OVERRIDE_HANDLER_OPTION, + NoOpParentOverrideHandler.class.getName())) { OpenTelemetry otel = GlobalOpenTelemetry.get(); List processors = OtelReflectionUtils.getSpanProcessors(otel); @@ -81,6 +93,7 @@ public void checkAllOptions(@TempDir Path tmpDir) { assertThat(config.getProfilingInterval()).isEqualTo(Duration.ofSeconds(2)); assertThat(config.getProfilingDuration()).isEqualTo(Duration.ofSeconds(3)); assertThat(config.getProfilerLibDirectory()).isEqualTo(libDir); + assertThat(config.getParentOverrideHandler()).isInstanceOf(NoOpParentOverrideHandler.class); } } diff --git a/inferred-spans/src/test/java/io/opentelemetry/contrib/inferredspans/internal/CallTreeSpanifyTest.java b/inferred-spans/src/test/java/io/opentelemetry/contrib/inferredspans/internal/CallTreeSpanifyTest.java index 302de16e4..8eddda06f 100644 --- a/inferred-spans/src/test/java/io/opentelemetry/contrib/inferredspans/internal/CallTreeSpanifyTest.java +++ b/inferred-spans/src/test/java/io/opentelemetry/contrib/inferredspans/internal/CallTreeSpanifyTest.java @@ -48,7 +48,10 @@ void testSpanification() throws Exception { setup.profiler.setProfilingSessionOngoing(true); CallTree.Root callTree = CallTreeTest.getCallTree(setup, new String[] {" dd ", " cc ", " bbb ", "aaaaee"}); - assertThat(callTree.spanify(nanoClock, setup.sdk.getTracer("dummy-tracer"))).isEqualTo(4); + assertThat( + callTree.spanify( + nanoClock, setup.sdk.getTracer("dummy-tracer"), CallTree.DEFAULT_PARENT_OVERRIDE)) + .isEqualTo(4); assertThat(setup.getSpans()).hasSize(5); assertThat(setup.getSpans().stream().map(SpanData::getName)) .containsExactly( @@ -158,7 +161,8 @@ void testCallTreeWithActiveSpan() { .build()); try (OpenTelemetrySdk outputSdk = sdkBuilder.build()) { - root.spanify(nanoClock, outputSdk.getTracer("dummy-tracer")); + root.spanify( + nanoClock, outputSdk.getTracer("dummy-tracer"), CallTree.DEFAULT_PARENT_OVERRIDE); List spans = exporter.getFinishedSpanItems(); assertThat(spans).hasSize(2); @@ -206,7 +210,8 @@ void testSpanWithInvertedActivation() { .addSpanProcessor(SimpleSpanProcessor.create(exporter)) .build()); try (OpenTelemetrySdk outputSdk = sdkBuilder.build()) { - root.spanify(nanoClock, outputSdk.getTracer("dummy-tracer")); + root.spanify( + nanoClock, outputSdk.getTracer("dummy-tracer"), CallTree.DEFAULT_PARENT_OVERRIDE); List spans = exporter.getFinishedSpanItems(); assertThat(spans).hasSize(1); @@ -249,7 +254,8 @@ void testSpanWithNestedActivation() { .addSpanProcessor(SimpleSpanProcessor.create(exporter)) .build()); try (OpenTelemetrySdk outputSdk = sdkBuilder.build()) { - root.spanify(nanoClock, outputSdk.getTracer("dummy-tracer")); + root.spanify( + nanoClock, outputSdk.getTracer("dummy-tracer"), CallTree.DEFAULT_PARENT_OVERRIDE); List spans = exporter.getFinishedSpanItems(); assertThat(spans).hasSize(1); diff --git a/inferred-spans/src/test/java/io/opentelemetry/contrib/inferredspans/internal/CallTreeTest.java b/inferred-spans/src/test/java/io/opentelemetry/contrib/inferredspans/internal/CallTreeTest.java index 3f23f1e63..8692158a6 100644 --- a/inferred-spans/src/test/java/io/opentelemetry/contrib/inferredspans/internal/CallTreeTest.java +++ b/inferred-spans/src/test/java/io/opentelemetry/contrib/inferredspans/internal/CallTreeTest.java @@ -869,7 +869,10 @@ private Map assertCallTree( assertThat(actualResult).isEqualTo(expectedResult.toString()); if (expectedSpans != null) { - root.spanify(nanoClock, profilerSetup.sdk.getTracer("dummy-inferred-spans-tracer")); + root.spanify( + nanoClock, + profilerSetup.sdk.getTracer("dummy-inferred-spans-tracer"), + CallTree.DEFAULT_PARENT_OVERRIDE); Map spans = profilerSetup.getSpans().stream() .collect(toMap(s -> s.getName().replaceAll(".*#", ""), Function.identity()));