From bfad9fdab7d1389d30dc2f105b2fbef3b5d7c246 Mon Sep 17 00:00:00 2001 From: Liudmila Molkova Date: Fri, 20 May 2022 10:46:32 -0700 Subject: [PATCH 1/5] Suppress nested SDK public method calls --- .../azure-core-tracing-opentelemetry/pom.xml | 1 + .../OpenTelemetryHttpPolicy.java | 18 +- .../opentelemetry/OpenTelemetryTracer.java | 125 +++++++-- .../OpenTelemetrySpanSuppressionHelper.java | 99 ------- .../OpenTelemetryHttpPolicyTests.java | 26 -- .../OpenTelemetryTracerTest.java | 249 +++++++++++++++++- .../tracing/opentelemetry/TestExporter.java | 37 +++ 7 files changed, 394 insertions(+), 161 deletions(-) delete mode 100644 sdk/core/azure-core-tracing-opentelemetry/src/main/java/com/azure/core/tracing/opentelemetry/implementation/OpenTelemetrySpanSuppressionHelper.java create mode 100644 sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/TestExporter.java diff --git a/sdk/core/azure-core-tracing-opentelemetry/pom.xml b/sdk/core/azure-core-tracing-opentelemetry/pom.xml index ac91cb7ed171d..201616a03dcd9 100644 --- a/sdk/core/azure-core-tracing-opentelemetry/pom.xml +++ b/sdk/core/azure-core-tracing-opentelemetry/pom.xml @@ -34,6 +34,7 @@ --add-opens com.azure.core.tracing.opentelemetry/com.azure.core.tracing.opentelemetry.implementation=ALL-UNNAMED + --add-opens com.azure.core.tracing.opentelemetry/com.azure.core.tracing.opentelemetry=ALL-UNNAMED diff --git a/sdk/core/azure-core-tracing-opentelemetry/src/main/java/com/azure/core/tracing/opentelemetry/OpenTelemetryHttpPolicy.java b/sdk/core/azure-core-tracing-opentelemetry/src/main/java/com/azure/core/tracing/opentelemetry/OpenTelemetryHttpPolicy.java index 5bb742147d3a1..250db870b0527 100644 --- a/sdk/core/azure-core-tracing-opentelemetry/src/main/java/com/azure/core/tracing/opentelemetry/OpenTelemetryHttpPolicy.java +++ b/sdk/core/azure-core-tracing-opentelemetry/src/main/java/com/azure/core/tracing/opentelemetry/OpenTelemetryHttpPolicy.java @@ -11,7 +11,6 @@ import com.azure.core.http.policy.AfterRetryPolicyProvider; import com.azure.core.http.policy.HttpPipelinePolicy; import com.azure.core.tracing.opentelemetry.implementation.HttpTraceUtil; -import com.azure.core.tracing.opentelemetry.implementation.OpenTelemetrySpanSuppressionHelper; import com.azure.core.util.CoreUtils; import io.opentelemetry.api.GlobalOpenTelemetry; import io.opentelemetry.api.common.AttributeKey; @@ -228,7 +227,7 @@ private static io.opentelemetry.context.Context getTraceContextOrCurrent(HttpPip */ static final class ScalarPropagatingMono extends Mono { public static final Mono INSTANCE = new ScalarPropagatingMono(); - + private static final AutoCloseable NOOP_CLOSEABLE = () -> { }; private final Object value = new Object(); private ScalarPropagatingMono() { @@ -237,16 +236,11 @@ private ScalarPropagatingMono() { @Override public void subscribe(CoreSubscriber actual) { Context traceContext = actual.currentContext().getOrDefault(REACTOR_PARENT_TRACE_CONTEXT_KEY, null); - if (traceContext != null) { - Object agentContext = OpenTelemetrySpanSuppressionHelper.registerClientSpan(traceContext); - AutoCloseable closeable = OpenTelemetrySpanSuppressionHelper.makeCurrent(agentContext, traceContext); - actual.onSubscribe(Operators.scalarSubscription(actual, value)); - try { - closeable.close(); - } catch (Exception ignored) { - } - } else { - actual.onSubscribe(Operators.scalarSubscription(actual, value)); + AutoCloseable closeable = traceContext != null ? traceContext.makeCurrent() : NOOP_CLOSEABLE; + actual.onSubscribe(Operators.scalarSubscription(actual, value)); + try { + closeable.close(); + } catch (Exception ignored) { } } } diff --git a/sdk/core/azure-core-tracing-opentelemetry/src/main/java/com/azure/core/tracing/opentelemetry/OpenTelemetryTracer.java b/sdk/core/azure-core-tracing-opentelemetry/src/main/java/com/azure/core/tracing/opentelemetry/OpenTelemetryTracer.java index 5153b8e1279e3..e06526e7d556b 100644 --- a/sdk/core/azure-core-tracing-opentelemetry/src/main/java/com/azure/core/tracing/opentelemetry/OpenTelemetryTracer.java +++ b/sdk/core/azure-core-tracing-opentelemetry/src/main/java/com/azure/core/tracing/opentelemetry/OpenTelemetryTracer.java @@ -35,6 +35,7 @@ * requests. */ public class OpenTelemetryTracer implements com.azure.core.util.tracing.Tracer { + private static final StartSpanOptions DEFAULT_OPTIONS = new StartSpanOptions(com.azure.core.util.tracing.SpanKind.INTERNAL); private final Tracer tracer; /** @@ -64,16 +65,16 @@ public OpenTelemetryTracer() { private static final ClientLogger LOGGER = new ClientLogger(OpenTelemetryTracer.class); private static final AutoCloseable NOOP_CLOSEABLE = () -> { }; + private static final SpanKind SHARED_SPAN_BUILDER_KIND = SpanKind.CLIENT; + private static final String SUPPRESSED_SPAN_FLAG = "suppressed-span-flag"; + private static final String CLIENT_METHOD_CALL_FLAG = "client-method-call-flag"; /** * {@inheritDoc} */ @Override public Context start(String spanName, Context context) { - Objects.requireNonNull(spanName, "'spanName' cannot be null."); - SpanBuilder spanBuilder = createSpanBuilder(spanName, null, SpanKind.INTERNAL, null, context); - - return startSpanInternal(spanBuilder, null, context); + return start(spanName, DEFAULT_OPTIONS, context); } /** @@ -81,11 +82,19 @@ public Context start(String spanName, Context context) { */ @Override public Context start(String spanName, StartSpanOptions options, Context context) { + Objects.requireNonNull(spanName, "'spanName' cannot be null."); Objects.requireNonNull(options, "'options' cannot be null."); - SpanBuilder spanBuilder = createSpanBuilder(spanName, null, convertToOtelKind(options.getSpanKind()), + + SpanKind spanKind = convertToOtelKind(options.getSpanKind()); + if (shouldSuppress(spanKind, context)) { + return startSuppressedSpan(context); + } + + context = unsuppress(context); + SpanBuilder spanBuilder = createSpanBuilder(spanName, null, spanKind, options.getAttributes(), context); - return startSpanInternal(spanBuilder, null, context); + return startSpanInternal(spanBuilder, isClientCall(spanKind), null, context); } /** @@ -98,28 +107,44 @@ public Context start(String spanName, Context context, ProcessKind processKind) Objects.requireNonNull(processKind, "'processKind' cannot be null."); SpanBuilder spanBuilder; + if (shouldSuppress(processKindToSpanKind(processKind), context)) { + return startSuppressedSpan(context); + } + + context = unsuppress(context); switch (processKind) { case SEND: // use previously created span builder from the LINK process. spanBuilder = getOrNull(context, SPAN_BUILDER_KEY, SpanBuilder.class); if (spanBuilder == null) { - return context; + // we can't return context here, because called would not know that span was not created. + // will add attributes, events to parent span and end parent span. + LOGGER.atWarning() + .addKeyValue("spanName", spanName) + .addKeyValue("processKind", processKind) + .log("start span is called without builder on the context, creating default builder"); + spanBuilder = createSpanBuilder(spanName, null, SHARED_SPAN_BUILDER_KIND, null, context); } - return startSpanInternal(spanBuilder, this::addMessagingAttributes, context); + + return startSpanInternal(spanBuilder, isClientCall(SHARED_SPAN_BUILDER_KIND), this::addMessagingAttributes, context); case MESSAGE: spanBuilder = createSpanBuilder(spanName, null, SpanKind.PRODUCER, null, context); - context = startSpanInternal(spanBuilder, this::addMessagingAttributes, context); + context = startSpanInternal(spanBuilder, false, this::addMessagingAttributes, context); return setDiagnosticId(context); case PROCESS: SpanContext remoteParentContext = getOrNull(context, SPAN_CONTEXT_KEY, SpanContext.class); spanBuilder = createSpanBuilder(spanName, remoteParentContext, SpanKind.CONSUMER, null, context); - context = startSpanInternal(spanBuilder, this::addMessagingAttributes, context); + context = startSpanInternal(spanBuilder, false, this::addMessagingAttributes, context); // TODO (limolkova) we should do this in the EventHub/ServiceBus SDK instead to make sure scope is // closed in the same thread where it was started to prevent leaking the context. return context.addData(SCOPE_KEY, makeSpanCurrent(context)); default: - return context; + LOGGER.atWarning() + .addKeyValue("spanName", spanName) + .addKeyValue("processKind", processKind) + .log("start span is called with unknown process kind, suppressing the span"); + return startSuppressedSpan(context); } } @@ -129,6 +154,7 @@ public Context start(String spanName, Context context, ProcessKind processKind) @Override public void end(int responseCode, Throwable throwable, Context context) { Objects.requireNonNull(context, "'context' cannot be null."); + final Span span = getSpanOrNull(context); if (span == null) { return; @@ -146,6 +172,7 @@ public void end(int responseCode, Throwable throwable, Context context) { @Override public void setAttribute(String key, String value, Context context) { Objects.requireNonNull(context, "'context' cannot be null"); + if (CoreUtils.isNullOrEmpty(value)) { LOGGER.verbose("Failed to set span attribute since value is null or empty."); return; @@ -175,7 +202,6 @@ public Context setSpanName(String spanName, Context context) { @Override public void end(String statusMessage, Throwable throwable, Context context) { Span span = getSpanOrNull(context); - if (span == null) { return; } @@ -218,7 +244,7 @@ public Context extractContext(String diagnosticId, Context context) { @Override public Context getSharedSpanBuilder(String spanName, Context context) { // this is used to create messaging send spanBuilder, and it's a CLIENT span - return context.addData(SPAN_BUILDER_KEY, createSpanBuilder(spanName, null, SpanKind.CLIENT, null, context)); + return context.addData(SPAN_BUILDER_KEY, createSpanBuilder(spanName, null, SHARED_SPAN_BUILDER_KIND, null, context)); } /** @@ -226,6 +252,10 @@ public Context getSharedSpanBuilder(String spanName, Context context) { */ @Override public AutoCloseable makeSpanCurrent(Context context) { + if (getBoolean(SUPPRESSED_SPAN_FLAG, context)) { + return NOOP_CLOSEABLE; + } + io.opentelemetry.context.Context traceContext = getTraceContextOrDefault(context, null); if (traceContext == null) { LOGGER.verbose("There is no OpenTelemetry Context on the context, cannot make it current"); @@ -278,6 +308,7 @@ public void addEvent(String eventName, Map traceEventAttributes, * @return A {@link Context} with created {@link Span}. */ private Context startSpanInternal(SpanBuilder spanBuilder, + boolean isClientMethod, java.util.function.BiConsumer setAttributes, Context context) { Objects.requireNonNull(spanBuilder, "'spanBuilder' cannot be null."); @@ -297,7 +328,12 @@ private Context startSpanInternal(SpanBuilder spanBuilder, } } - return context.addData(PARENT_TRACE_CONTEXT_KEY, getTraceContextOrDefault(context, io.opentelemetry.context.Context.current()).with(span)); + if (isClientMethod && !context.getData(CLIENT_METHOD_CALL_FLAG).isPresent()) { + context = context.addData(CLIENT_METHOD_CALL_FLAG, true); + } + + return context + .addData(PARENT_TRACE_CONTEXT_KEY, getTraceContextOrDefault(context, io.opentelemetry.context.Context.current()).with(span)); } /** @@ -307,7 +343,7 @@ private Context startSpanInternal(SpanBuilder spanBuilder, * @param spanName The name of the returned Span. * @param remoteParentContext Remote parent context if any, or {@code null} otherwise. * @param spanKind Kind of the span to create. - * @param beforeSaplingAttributes Optional attributes available when span starts and important for sampling. + * @param beforeSamplingAttributes Optional attributes available when span starts and important for sampling. * @param context The context containing the span and the span name. * @return A {@link SpanBuilder} to create and start a new {@link Span}. */ @@ -315,7 +351,7 @@ private Context startSpanInternal(SpanBuilder spanBuilder, private SpanBuilder createSpanBuilder(String spanName, SpanContext remoteParentContext, SpanKind spanKind, - Map beforeSaplingAttributes, + Map beforeSamplingAttributes, Context context) { String spanNameKey = getOrNull(context, USER_SPAN_NAME_KEY, String.class); @@ -335,8 +371,8 @@ private SpanBuilder createSpanBuilder(String spanName, } // if some attributes are provided, set them - if (!CoreUtils.isNullOrEmpty(beforeSaplingAttributes)) { - Attributes otelAttributes = convertToOtelAttributes(beforeSaplingAttributes); + if (!CoreUtils.isNullOrEmpty(beforeSamplingAttributes)) { + Attributes otelAttributes = convertToOtelAttributes(beforeSamplingAttributes); otelAttributes.forEach( (key, value) -> spanBuilder.setAttribute((AttributeKey) key, value)); } @@ -468,7 +504,7 @@ private void addMessagingAttributes(Span span, Context context) { * @return The T type of raw class object */ @SuppressWarnings("unchecked") - private T getOrNull(Context context, String key, Class clazz) { + private static T getOrNull(Context context, String key, Class clazz) { final Optional optional = context.getData(key); final Object result = optional.filter(value -> clazz.isAssignableFrom(value.getClass())).orElseGet(() -> { LOGGER.verbose("Could not extract key '{}' of type '{}' from context.", key, clazz); @@ -484,7 +520,7 @@ private T getOrNull(Context context, String key, Class clazz) { * or PARENT_SPAN_KEY (for backward-compatibility) or default value. */ @SuppressWarnings("deprecation") - private io.opentelemetry.context.Context getTraceContextOrDefault(Context azContext, io.opentelemetry.context.Context defaultContext) { + private static io.opentelemetry.context.Context getTraceContextOrDefault(Context azContext, io.opentelemetry.context.Context defaultContext) { io.opentelemetry.context.Context traceContext = getOrNull(azContext, PARENT_TRACE_CONTEXT_KEY, io.opentelemetry.context.Context.class); @@ -507,6 +543,10 @@ private io.opentelemetry.context.Context getTraceContextOrDefault(Context azCont */ @SuppressWarnings("deprecation") private Span getSpanOrNull(Context azContext) { + if (getBoolean(SUPPRESSED_SPAN_FLAG, azContext)) { + return null; + } + io.opentelemetry.context.Context traceContext = getOrNull(azContext, PARENT_TRACE_CONTEXT_KEY, io.opentelemetry.context.Context.class); @@ -523,4 +563,49 @@ private Span getSpanOrNull(Context azContext) { return traceContext == null ? null : Span.fromContext(traceContext); } + + private SpanKind processKindToSpanKind(ProcessKind processKind) { + switch (processKind) { + case SEND: + return SHARED_SPAN_BUILDER_KIND; + case MESSAGE: + return SpanKind.PRODUCER; + case PROCESS: + return SpanKind.CONSUMER; + default: + return SpanKind.INTERNAL; + } + } + + private Context startSuppressedSpan(Context context) { + return context.addData(SUPPRESSED_SPAN_FLAG, true); + } + + private static boolean shouldSuppress(SpanKind kind, Context context) { + if (isClientCall(kind)) { + boolean suppress = getBoolean(CLIENT_METHOD_CALL_FLAG, context); + boolean suppressed = getBoolean(SUPPRESSED_SPAN_FLAG, context); + + return suppress && !suppressed; + } + + return false; + } + + private static Context unsuppress(Context context) { + if (getBoolean(SUPPRESSED_SPAN_FLAG, context)) { + return context.addData(SUPPRESSED_SPAN_FLAG, false); + } + + return context; + } + + private static boolean getBoolean(String key, Context context) { + Optional flag = context.getData(key); + return flag.isPresent() && Boolean.TRUE.equals(flag.get()); + } + + private static boolean isClientCall(SpanKind kind) { + return kind == SpanKind.CLIENT || kind == SpanKind.INTERNAL; + } } diff --git a/sdk/core/azure-core-tracing-opentelemetry/src/main/java/com/azure/core/tracing/opentelemetry/implementation/OpenTelemetrySpanSuppressionHelper.java b/sdk/core/azure-core-tracing-opentelemetry/src/main/java/com/azure/core/tracing/opentelemetry/implementation/OpenTelemetrySpanSuppressionHelper.java deleted file mode 100644 index 9c9d030256c7f..0000000000000 --- a/sdk/core/azure-core-tracing-opentelemetry/src/main/java/com/azure/core/tracing/opentelemetry/implementation/OpenTelemetrySpanSuppressionHelper.java +++ /dev/null @@ -1,99 +0,0 @@ -// Copyright (c) Microsoft Corporation. All rights reserved. -// Licensed under the MIT License. - -package com.azure.core.tracing.opentelemetry.implementation; - -import com.azure.core.util.logging.ClientLogger; -import io.opentelemetry.api.trace.Span; -import io.opentelemetry.context.Context; - -import java.lang.reflect.Method; -import java.util.Objects; - -/** - * Helper allowing to register CLIENT spans to suppress nested auto-collected CLIENT spans - * and propagate context to lower levels of instrumentation or logs. - * Currently it's done through reflection against OpenTelemetry instrumentation-api in the agent. - * long-term solution for opentelemetry-api is under development https://github.com/open-telemetry/oteps/pull/172 - */ -public class OpenTelemetrySpanSuppressionHelper { - private static boolean agentDiscovered; - private static final ClientLogger LOGGER = new ClientLogger(OpenTelemetrySpanSuppressionHelper.class); - private static Method getAgentContextMethod; - private static Method setSpanKeyMethod; - private static Object clientSpanKey; - private static Method getAgentSpanMethod; - private static Method agentContextMakeCurrentMethod; - - static { - agentDiscovered = true; - try { - Class agentContextStorageClass = Class.forName("io.opentelemetry.javaagent.instrumentation.opentelemetryapi.context.AgentContextStorage"); - Class agentContextClass = Class.forName("io.opentelemetry.javaagent.shaded.io.opentelemetry.context.Context"); - Class spanKeyClass = Class.forName("io.opentelemetry.javaagent.shaded.instrumentation.api.instrumenter.SpanKey"); - Class bridgingClass = Class.forName("io.opentelemetry.javaagent.instrumentation.opentelemetryapi.trace.Bridging"); - Class agentSpanClass = Class.forName("io.opentelemetry.javaagent.shaded.io.opentelemetry.api.trace.Span"); - - getAgentContextMethod = agentContextStorageClass.getDeclaredMethod("getAgentContext", io.opentelemetry.context.Context.class); - getAgentSpanMethod = bridgingClass.getDeclaredMethod("toAgentOrNull", io.opentelemetry.api.trace.Span.class); - clientSpanKey = spanKeyClass.getDeclaredField("ALL_CLIENTS").get(null); - setSpanKeyMethod = spanKeyClass.getDeclaredMethod("storeInContext", agentContextClass, agentSpanClass); - agentContextMakeCurrentMethod = agentContextClass.getMethod("makeCurrent"); - - if (getAgentContextMethod.getReturnType() != agentContextClass - || getAgentSpanMethod.getReturnType() != agentSpanClass - || setSpanKeyMethod.getReturnType() != agentContextClass - || !AutoCloseable.class.isAssignableFrom(agentContextMakeCurrentMethod.getReturnType())) { - agentDiscovered = false; - } - - } catch (Exception ex) { - LOGGER.verbose("Failed to discover OpenTelemetry agent classes, HTTP spans may be duplicated", ex); - agentDiscovered = false; - } - } - - /** - * Registers span from given trace context as client span for opentelemetry agent to avoid duplication. - * @param traceContext OpenTelemetry context with client span - * @return Agent context or null when agent is not running or doesn't behave as expected. - */ - public static Object registerClientSpan(Context traceContext) { - Objects.requireNonNull(traceContext, "'traceContext' cannot be null"); - if (agentDiscovered) { - try { - return setSpanKeyMethod.invoke( - clientSpanKey, - getAgentContextMethod.invoke(null, traceContext), - getAgentSpanMethod.invoke(null, Span.fromContext(traceContext))); - } catch (Exception ex) { - // should not happen, If it does, we'll log it once. - LOGGER.warning("Failed to register client span on OpenTelemetry agent", ex); - agentDiscovered = false; - } - } - return null; - } - - /** - * Makes passed agent context current. Falls back to passed trace context when agent is not running - * or doesn't behave as expected. - * @param agentContext agent context instance obtained from {@link OpenTelemetrySpanSuppressionHelper#registerClientSpan} - * @param traceContext Regular OpenTelemetry context to fallback to. - * @return scope to be closed in the same thread as it was started. - */ - public static AutoCloseable makeCurrent(Object agentContext, Context traceContext) { - Objects.requireNonNull(traceContext, "'traceContext' cannot be null"); - if (agentDiscovered && agentContext != null) { - try { - return (AutoCloseable) agentContextMakeCurrentMethod.invoke(agentContext); - } catch (Exception ex) { - // should not happen, If it does, we'll log it once. - LOGGER.warning("Failed to make OpenTelemetry agent context current", ex); - agentDiscovered = false; - } - } - - return traceContext.makeCurrent(); - } -} diff --git a/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/OpenTelemetryHttpPolicyTests.java b/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/OpenTelemetryHttpPolicyTests.java index 790db7cefbdf4..381d0f7370202 100644 --- a/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/OpenTelemetryHttpPolicyTests.java +++ b/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/OpenTelemetryHttpPolicyTests.java @@ -22,13 +22,11 @@ import io.opentelemetry.api.trace.SpanKind; import io.opentelemetry.api.trace.Tracer; import io.opentelemetry.sdk.OpenTelemetrySdk; -import io.opentelemetry.sdk.common.CompletableResultCode; import io.opentelemetry.sdk.trace.ReadableSpan; import io.opentelemetry.sdk.trace.SdkTracerProvider; import io.opentelemetry.sdk.trace.data.LinkData; import io.opentelemetry.sdk.trace.data.SpanData; import io.opentelemetry.sdk.trace.export.SimpleSpanProcessor; -import io.opentelemetry.sdk.trace.export.SpanExporter; import io.opentelemetry.sdk.trace.samplers.Sampler; import io.opentelemetry.sdk.trace.samplers.SamplingDecision; import io.opentelemetry.sdk.trace.samplers.SamplingResult; @@ -39,7 +37,6 @@ import reactor.test.StepVerifier; import java.util.ArrayList; -import java.util.Collection; import java.util.HashMap; import java.util.List; import java.util.Map; @@ -281,27 +278,4 @@ public Mono send(HttpRequest request) { } } - static class TestExporter implements SpanExporter { - - private final List exportedSpans = new ArrayList<>(); - @Override - public CompletableResultCode export(Collection spans) { - exportedSpans.addAll(spans); - return CompletableResultCode.ofSuccess(); - } - - @Override - public CompletableResultCode flush() { - return CompletableResultCode.ofSuccess(); - } - - @Override - public CompletableResultCode shutdown() { - return CompletableResultCode.ofSuccess(); - } - - public List getSpans() { - return exportedSpans; - } - } } diff --git a/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/OpenTelemetryTracerTest.java b/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/OpenTelemetryTracerTest.java index a6f5cbcb3e392..be698f6a27e20 100644 --- a/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/OpenTelemetryTracerTest.java +++ b/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/OpenTelemetryTracerTest.java @@ -20,21 +20,30 @@ import io.opentelemetry.api.trace.Tracer; import io.opentelemetry.context.Scope; import io.opentelemetry.sdk.OpenTelemetrySdk; +import io.opentelemetry.sdk.trace.ReadWriteSpan; import io.opentelemetry.sdk.trace.ReadableSpan; +import io.opentelemetry.sdk.trace.SdkTracerProvider; +import io.opentelemetry.sdk.trace.SpanProcessor; import io.opentelemetry.sdk.trace.data.EventData; import io.opentelemetry.sdk.trace.data.LinkData; import io.opentelemetry.sdk.trace.data.SpanData; +import io.opentelemetry.sdk.trace.export.SpanExporter; import org.junit.jupiter.api.AfterEach; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; +import org.junit.jupiter.params.ParameterizedTest; +import org.junit.jupiter.params.provider.Arguments; +import org.junit.jupiter.params.provider.MethodSource; import java.time.Instant; import java.time.OffsetDateTime; import java.time.ZoneOffset; +import java.util.Collections; import java.util.HashMap; import java.util.List; import java.util.Map; import java.util.Optional; +import java.util.stream.Stream; import static com.azure.core.tracing.opentelemetry.OpenTelemetryTracer.AZ_NAMESPACE_KEY; import static com.azure.core.tracing.opentelemetry.OpenTelemetryTracer.MESSAGE_ENQUEUED_TIME; @@ -43,15 +52,16 @@ import static com.azure.core.util.tracing.Tracer.ENTITY_PATH_KEY; import static com.azure.core.util.tracing.Tracer.HOST_NAME_KEY; import static com.azure.core.util.tracing.Tracer.PARENT_SPAN_KEY; +import static com.azure.core.util.tracing.Tracer.PARENT_TRACE_CONTEXT_KEY; import static com.azure.core.util.tracing.Tracer.SCOPE_KEY; import static com.azure.core.util.tracing.Tracer.SPAN_BUILDER_KEY; import static com.azure.core.util.tracing.Tracer.SPAN_CONTEXT_KEY; -import static com.azure.core.util.tracing.Tracer.PARENT_TRACE_CONTEXT_KEY; import static com.azure.core.util.tracing.Tracer.USER_SPAN_NAME_KEY; import static io.opentelemetry.api.trace.StatusCode.UNSET; import static org.junit.jupiter.api.Assertions.assertEquals; import static org.junit.jupiter.api.Assertions.assertFalse; import static org.junit.jupiter.api.Assertions.assertNotNull; +import static org.junit.jupiter.api.Assertions.assertNotSame; import static org.junit.jupiter.api.Assertions.assertNull; import static org.junit.jupiter.api.Assertions.assertSame; import static org.junit.jupiter.api.Assertions.assertThrows; @@ -77,9 +87,12 @@ public class OpenTelemetryTracerTest { TRACE_ID_OFFSET + TRACE_ID_HEX_SIZE + TRACEPARENT_DELIMITER_SIZE; private static final int TRACE_OPTION_OFFSET = SPAN_ID_OFFSET + SPAN_ID_HEX_SIZE + TRACEPARENT_DELIMITER_SIZE; - private static OpenTelemetryTracer openTelemetryTracer; + private OpenTelemetryTracer openTelemetryTracer; + private static final SpanContext TEST_CONTEXT = SpanContext.create("0123456789abcdef0123456789abcdef", "0123456789abcdef", TraceFlags.getSampled(), TraceState.getDefault()); - private static Tracer tracer = OpenTelemetrySdk.builder().build().getTracer("TracerSdkTest"); + private TestExporter testExporter; + private Tracer tracer; + private SpanProcessor spanProcessor; private Context tracingContext; private Span parentSpan; @@ -91,10 +104,49 @@ public class OpenTelemetryTracerTest { } }; + class TestSpanProcessor implements SpanProcessor { + + private final SpanExporter exporter; + + TestSpanProcessor(SpanExporter exporter) { + this.exporter = exporter; + } + + @Override + public void onStart(io.opentelemetry.context.Context parentContext, ReadWriteSpan span) { + + } + + @Override + public boolean isStartRequired() { + return false; + } + + @Override + public void onEnd(ReadableSpan span) { + exporter.export(Collections.singletonList(span.toSpanData())); + } + + @Override + public boolean isEndRequired() { + return true; + } + } + @BeforeEach public void setUp() { + testExporter = new TestExporter(); + spanProcessor = new TestSpanProcessor(testExporter); + tracer = OpenTelemetrySdk.builder() + .setTracerProvider(SdkTracerProvider.builder() + .addSpanProcessor(spanProcessor) + .build()) + .build().getTracer("TracerSdkTest"); + // Start user parent span. - parentSpan = tracer.spanBuilder(METHOD_NAME).setNoParent().startSpan(); + parentSpan = tracer.spanBuilder(METHOD_NAME) + .setSpanKind(SpanKind.SERVER) + .setNoParent().startSpan(); // Add parent span to tracingContext tracingContext = new Context(PARENT_TRACE_CONTEXT_KEY, io.opentelemetry.context.Context.root().with(parentSpan)); @@ -793,6 +845,195 @@ public void startSpanWithAttributes() { verifySpanAttributes(expectedAttributes, span.toSpanData().getAttributes()); } + @Test + public void suppressNestedClientSpan() { + Context outer = openTelemetryTracer.start("outer", Context.NONE); + Context innerSuppressed = openTelemetryTracer.start("innerSuppressed", outer); + Context innerNotSuppressed = openTelemetryTracer.start("innerNotSuppressed", new StartSpanOptions(com.azure.core.util.tracing.SpanKind.PRODUCER), innerSuppressed); + + openTelemetryTracer.end("ok", null, innerNotSuppressed); + assertEquals(1, testExporter.getSpans().size()); + openTelemetryTracer.end("ok", null, innerSuppressed); + + assertEquals(1, testExporter.getSpans().size()); + openTelemetryTracer.end("ok", null, outer); + + assertEquals(2, testExporter.getSpans().size()); + + SpanData innerNotSuppressedSpan = testExporter.getSpans().get(0); + SpanData outerSpan = testExporter.getSpans().get(1); + assertEquals(innerNotSuppressedSpan.getSpanContext().getTraceId(), outerSpan.getSpanContext().getTraceId()); + assertEquals(innerNotSuppressedSpan.getParentSpanId(), outerSpan.getSpanContext().getSpanId()); + } + + @Test + public void suppressNestedInterleavedClientSpan() { + Context outer = openTelemetryTracer.getSharedSpanBuilder("outer", Context.NONE); + openTelemetryTracer.addLink(outer.addData(SPAN_CONTEXT_KEY, TEST_CONTEXT)); + outer = openTelemetryTracer.start("innerSuppressed", outer, ProcessKind.SEND); + + Context inner1Suppressed = openTelemetryTracer.start("innerSuppressed", outer); + Context inner1NotSuppressed = openTelemetryTracer.start("innerNotSuppressed", new StartSpanOptions(com.azure.core.util.tracing.SpanKind.PRODUCER), inner1Suppressed); + Context inner2Suppressed = openTelemetryTracer.start("innerSuppressed", inner1NotSuppressed); + + openTelemetryTracer.end("ok", null, inner2Suppressed); + assertEquals(0, testExporter.getSpans().size()); + + openTelemetryTracer.end("ok", null, inner1NotSuppressed); + openTelemetryTracer.end("ok", null, inner1Suppressed); + openTelemetryTracer.end("ok", null, outer); + assertEquals(2, testExporter.getSpans().size()); + + SpanData innerNotSuppressedSpan = testExporter.getSpans().get(0); + SpanData outerSpan = testExporter.getSpans().get(1); + assertEquals(innerNotSuppressedSpan.getSpanContext().getTraceId(), outerSpan.getSpanContext().getTraceId()); + assertEquals(innerNotSuppressedSpan.getParentSpanId(), outerSpan.getSpanContext().getSpanId()); + } + + @ParameterizedTest + @MethodSource("spanKinds") + public void suppressNestedClientSpan(com.azure.core.util.tracing.SpanKind outerKind, com.azure.core.util.tracing.SpanKind innerKind, boolean shouldSuppressInner) { + Context outer = openTelemetryTracer.start("outer", new StartSpanOptions(outerKind), Context.NONE); + Context inner = openTelemetryTracer.start("inner", new StartSpanOptions(innerKind), outer); + Context neverSuppressed = openTelemetryTracer.start("innerNotSuppressed", new StartSpanOptions(com.azure.core.util.tracing.SpanKind.PRODUCER), inner); + + openTelemetryTracer.end("ok", null, neverSuppressed); + assertEquals(1, testExporter.getSpans().size()); + + openTelemetryTracer.end("ok", null, inner); + assertEquals(shouldSuppressInner ? 1 : 2, testExporter.getSpans().size()); + + openTelemetryTracer.end("ok", null, outer); + assertEquals(shouldSuppressInner ? 2 : 3, testExporter.getSpans().size()); + + SpanData neverSuppressedSpan = testExporter.getSpans().get(0); + + if (shouldSuppressInner) { + SpanData outerSpan = testExporter.getSpans().get(1); + assertEquals(neverSuppressedSpan.getParentSpanId(), outerSpan.getSpanContext().getSpanId()); + } else { + SpanData innerSpan = testExporter.getSpans().get(1); + SpanData outerSpan = testExporter.getSpans().get(2); + assertEquals(neverSuppressedSpan.getParentSpanId(), innerSpan.getSpanContext().getSpanId()); + assertEquals(innerSpan.getParentSpanId(), outerSpan.getSpanContext().getSpanId()); + } + } + + private static Stream spanKinds() { + return Stream.of( + Arguments.of(com.azure.core.util.tracing.SpanKind.CLIENT, com.azure.core.util.tracing.SpanKind.CLIENT, true), + Arguments.of(com.azure.core.util.tracing.SpanKind.CLIENT, com.azure.core.util.tracing.SpanKind.INTERNAL, true), + Arguments.of(com.azure.core.util.tracing.SpanKind.CLIENT, com.azure.core.util.tracing.SpanKind.PRODUCER, false), + Arguments.of(com.azure.core.util.tracing.SpanKind.CLIENT, com.azure.core.util.tracing.SpanKind.CONSUMER, false), + Arguments.of(com.azure.core.util.tracing.SpanKind.CLIENT, com.azure.core.util.tracing.SpanKind.SERVER, false), + Arguments.of(com.azure.core.util.tracing.SpanKind.INTERNAL, com.azure.core.util.tracing.SpanKind.CLIENT, true), + Arguments.of(com.azure.core.util.tracing.SpanKind.INTERNAL, com.azure.core.util.tracing.SpanKind.INTERNAL, true), + Arguments.of(com.azure.core.util.tracing.SpanKind.INTERNAL, com.azure.core.util.tracing.SpanKind.PRODUCER, false), + Arguments.of(com.azure.core.util.tracing.SpanKind.INTERNAL, com.azure.core.util.tracing.SpanKind.CONSUMER, false), + Arguments.of(com.azure.core.util.tracing.SpanKind.INTERNAL, com.azure.core.util.tracing.SpanKind.SERVER, false), + Arguments.of(com.azure.core.util.tracing.SpanKind.PRODUCER, com.azure.core.util.tracing.SpanKind.CLIENT, false), + Arguments.of(com.azure.core.util.tracing.SpanKind.PRODUCER, com.azure.core.util.tracing.SpanKind.INTERNAL, false), + Arguments.of(com.azure.core.util.tracing.SpanKind.PRODUCER, com.azure.core.util.tracing.SpanKind.PRODUCER, false), + Arguments.of(com.azure.core.util.tracing.SpanKind.PRODUCER, com.azure.core.util.tracing.SpanKind.CONSUMER, false), + Arguments.of(com.azure.core.util.tracing.SpanKind.PRODUCER, com.azure.core.util.tracing.SpanKind.SERVER, false), + Arguments.of(com.azure.core.util.tracing.SpanKind.CONSUMER, com.azure.core.util.tracing.SpanKind.CLIENT, false), + Arguments.of(com.azure.core.util.tracing.SpanKind.CONSUMER, com.azure.core.util.tracing.SpanKind.INTERNAL, false), + Arguments.of(com.azure.core.util.tracing.SpanKind.CONSUMER, com.azure.core.util.tracing.SpanKind.PRODUCER, false), + Arguments.of(com.azure.core.util.tracing.SpanKind.CONSUMER, com.azure.core.util.tracing.SpanKind.CONSUMER, false), + Arguments.of(com.azure.core.util.tracing.SpanKind.CONSUMER, com.azure.core.util.tracing.SpanKind.SERVER, false), + Arguments.of(com.azure.core.util.tracing.SpanKind.SERVER, com.azure.core.util.tracing.SpanKind.CLIENT, false), + Arguments.of(com.azure.core.util.tracing.SpanKind.SERVER, com.azure.core.util.tracing.SpanKind.INTERNAL, false), + Arguments.of(com.azure.core.util.tracing.SpanKind.SERVER, com.azure.core.util.tracing.SpanKind.PRODUCER, false), + Arguments.of(com.azure.core.util.tracing.SpanKind.SERVER, com.azure.core.util.tracing.SpanKind.CONSUMER, false), + Arguments.of(com.azure.core.util.tracing.SpanKind.SERVER, com.azure.core.util.tracing.SpanKind.SERVER, false)); + + } + + @Test + public void suppressNestedClientSpanAttributes() { + Context outer = openTelemetryTracer.start("outer", Context.NONE); + openTelemetryTracer.setAttribute("outer1", "foo", outer); + + Context innerSuppressed = openTelemetryTracer.start("innerSuppressed", outer); + openTelemetryTracer.setAttribute("outer2", "bar", outer); + openTelemetryTracer.setAttribute("innerSuppressed", "foo", innerSuppressed); + + openTelemetryTracer.end("ok", null, innerSuppressed); + openTelemetryTracer.end("ok", null, outer); + + SpanData outerSpan = testExporter.getSpans().get(0); + assertEquals("outer", outerSpan.getName()); + + Map outerAttributesExpected = new HashMap() {{ + put("outer1", "foo"); + put("outer2", "bar"); + }}; + + verifySpanAttributes(outerAttributesExpected, outerSpan.getAttributes()); + } + + @Test + public void suppressNestedClientSpanEvents() { + Context outer = openTelemetryTracer.start("outer", Context.NONE); + openTelemetryTracer.addEvent("outer1", null, null, outer); + + Context innerSuppressed = openTelemetryTracer.start("innerSuppressed", outer); + openTelemetryTracer.addEvent("outer2", null, null, outer); + openTelemetryTracer.addEvent("innerSuppressed", null, null, innerSuppressed); + + openTelemetryTracer.end("ok", null, innerSuppressed); + openTelemetryTracer.end("ok", null, outer); + + SpanData outerSpan = testExporter.getSpans().get(0); + assertEquals(2, outerSpan.getEvents().size()); + assertEquals("outer1", outerSpan.getEvents().get(0).getName()); + assertEquals("outer2", outerSpan.getEvents().get(1).getName()); + } + + @Test + public void suppressNestedClientSpanLinks() { + Context outer = openTelemetryTracer.start("outer", Context.NONE); + Context innerSuppressed = openTelemetryTracer.getSharedSpanBuilder("innerSuppressed", outer); + openTelemetryTracer.addLink(innerSuppressed.addData(SPAN_CONTEXT_KEY, TEST_CONTEXT)); + innerSuppressed = openTelemetryTracer.start("innerSuppressed", innerSuppressed, ProcessKind.SEND); + + openTelemetryTracer.end("ok", null, innerSuppressed); + + assertTrue(testExporter.getSpans().isEmpty()); + } + + @Test + public void suppressNestedClientSpanMakeCurrent() throws Exception { + Context outer = openTelemetryTracer.start("outer", Context.NONE); + AutoCloseable outerScope = openTelemetryTracer.makeSpanCurrent(outer); + Span outerSpan = Span.current(); + Context inner = openTelemetryTracer.start("inner", outer); + + AutoCloseable innerScope = openTelemetryTracer.makeSpanCurrent(outer); + assertSame(outerSpan, Span.current()); + innerScope.close(); + assertSame(outerSpan, Span.current()); + openTelemetryTracer.end("ok", null, inner); + assertTrue(testExporter.getSpans().isEmpty()); + } + + @Test + public void startSendSpanWithoutBuilder() { + Context outer = openTelemetryTracer.start("outer", new StartSpanOptions(com.azure.core.util.tracing.SpanKind.SERVER), Context.NONE); + Context sendNoBuilder = openTelemetryTracer.start("sendNoBuilder", outer, ProcessKind.SEND); + + assertNotSame(sendNoBuilder, outer); + openTelemetryTracer.end("ok", null, sendNoBuilder); + openTelemetryTracer.end("ok", null, outer); + + assertEquals(2, testExporter.getSpans().size()); + + SpanData sendNoBuilderSpan = testExporter.getSpans().get(0); + SpanData outerSpan = testExporter.getSpans().get(1); + assertEquals(sendNoBuilderSpan.getSpanContext().getTraceId(), outerSpan.getSpanContext().getTraceId()); + assertEquals(sendNoBuilderSpan.getParentSpanId(), outerSpan.getSpanContext().getSpanId()); + } + private static ReadableSpan getSpan(Context context) { Optional otelCtx = context.getData(PARENT_TRACE_CONTEXT_KEY); assertTrue(otelCtx.isPresent()); diff --git a/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/TestExporter.java b/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/TestExporter.java new file mode 100644 index 0000000000000..8c7c4c35acb08 --- /dev/null +++ b/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/TestExporter.java @@ -0,0 +1,37 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. + +package com.azure.core.tracing.opentelemetry; + +import io.opentelemetry.sdk.common.CompletableResultCode; +import io.opentelemetry.sdk.trace.data.SpanData; +import io.opentelemetry.sdk.trace.export.SpanExporter; + +import java.util.Collection; +import java.util.List; +import java.util.concurrent.CopyOnWriteArrayList; + +class TestExporter implements SpanExporter { + + private final List exportedSpans = new CopyOnWriteArrayList<>(); + + @Override + public CompletableResultCode export(Collection spans) { + exportedSpans.addAll(spans); + return CompletableResultCode.ofSuccess(); + } + + @Override + public CompletableResultCode flush() { + return CompletableResultCode.ofSuccess(); + } + + @Override + public CompletableResultCode shutdown() { + return CompletableResultCode.ofSuccess(); + } + + public List getSpans() { + return exportedSpans; + } +} From b3909fbc75e344470c8c3b467019f10dcf890302 Mon Sep 17 00:00:00 2001 From: Liudmila Molkova Date: Fri, 20 May 2022 11:15:39 -0700 Subject: [PATCH 2/5] changelog --- sdk/core/azure-core-tracing-opentelemetry/CHANGELOG.md | 2 ++ .../core/tracing/opentelemetry/OpenTelemetryTracer.java | 8 ++++---- 2 files changed, 6 insertions(+), 4 deletions(-) diff --git a/sdk/core/azure-core-tracing-opentelemetry/CHANGELOG.md b/sdk/core/azure-core-tracing-opentelemetry/CHANGELOG.md index e7bd5d293636a..bd457915d9b92 100644 --- a/sdk/core/azure-core-tracing-opentelemetry/CHANGELOG.md +++ b/sdk/core/azure-core-tracing-opentelemetry/CHANGELOG.md @@ -6,6 +6,8 @@ ### Breaking Changes +- Started suppressing spans for nested Azure client libraries public API calls with `INTERNAL` or `CLIENT` kind. ([#28998](https://github.com/Azure/azure-sdk-for-java/pull/28998)) + ### Bugs Fixed ### Other Changes diff --git a/sdk/core/azure-core-tracing-opentelemetry/src/main/java/com/azure/core/tracing/opentelemetry/OpenTelemetryTracer.java b/sdk/core/azure-core-tracing-opentelemetry/src/main/java/com/azure/core/tracing/opentelemetry/OpenTelemetryTracer.java index e06526e7d556b..feb131cbe7757 100644 --- a/sdk/core/azure-core-tracing-opentelemetry/src/main/java/com/azure/core/tracing/opentelemetry/OpenTelemetryTracer.java +++ b/sdk/core/azure-core-tracing-opentelemetry/src/main/java/com/azure/core/tracing/opentelemetry/OpenTelemetryTracer.java @@ -117,12 +117,12 @@ public Context start(String spanName, Context context, ProcessKind processKind) // use previously created span builder from the LINK process. spanBuilder = getOrNull(context, SPAN_BUILDER_KEY, SpanBuilder.class); if (spanBuilder == null) { - // we can't return context here, because called would not know that span was not created. - // will add attributes, events to parent span and end parent span. + // we can't return context here, because caller would not know that span was not created. + // it will add attributes or events to parent span and end parent span. LOGGER.atWarning() .addKeyValue("spanName", spanName) .addKeyValue("processKind", processKind) - .log("start span is called without builder on the context, creating default builder"); + .log("Start span is called without builder on the context, creating default builder."); spanBuilder = createSpanBuilder(spanName, null, SHARED_SPAN_BUILDER_KIND, null, context); } @@ -143,7 +143,7 @@ public Context start(String spanName, Context context, ProcessKind processKind) LOGGER.atWarning() .addKeyValue("spanName", spanName) .addKeyValue("processKind", processKind) - .log("start span is called with unknown process kind, suppressing the span"); + .log("Start span is called with unknown process kind, suppressing the span."); return startSuppressedSpan(context); } } From 7603020d094c0d687b9778a73596ea53fcf6b775 Mon Sep 17 00:00:00 2001 From: Liudmila Molkova Date: Mon, 23 May 2022 12:03:37 -0700 Subject: [PATCH 3/5] fix multilayer suppression --- .../opentelemetry/OpenTelemetryTracer.java | 9 +-------- .../opentelemetry/OpenTelemetryTracerTest.java | 16 +++++++++++++++- 2 files changed, 16 insertions(+), 9 deletions(-) diff --git a/sdk/core/azure-core-tracing-opentelemetry/src/main/java/com/azure/core/tracing/opentelemetry/OpenTelemetryTracer.java b/sdk/core/azure-core-tracing-opentelemetry/src/main/java/com/azure/core/tracing/opentelemetry/OpenTelemetryTracer.java index feb131cbe7757..4cf115d3b1171 100644 --- a/sdk/core/azure-core-tracing-opentelemetry/src/main/java/com/azure/core/tracing/opentelemetry/OpenTelemetryTracer.java +++ b/sdk/core/azure-core-tracing-opentelemetry/src/main/java/com/azure/core/tracing/opentelemetry/OpenTelemetryTracer.java @@ -582,14 +582,7 @@ private Context startSuppressedSpan(Context context) { } private static boolean shouldSuppress(SpanKind kind, Context context) { - if (isClientCall(kind)) { - boolean suppress = getBoolean(CLIENT_METHOD_CALL_FLAG, context); - boolean suppressed = getBoolean(SUPPRESSED_SPAN_FLAG, context); - - return suppress && !suppressed; - } - - return false; + return isClientCall(kind) && getBoolean(CLIENT_METHOD_CALL_FLAG, context); } private static Context unsuppress(Context context) { diff --git a/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/OpenTelemetryTracerTest.java b/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/OpenTelemetryTracerTest.java index be698f6a27e20..0c52c8ea0c45d 100644 --- a/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/OpenTelemetryTracerTest.java +++ b/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/OpenTelemetryTracerTest.java @@ -870,7 +870,7 @@ public void suppressNestedClientSpan() { public void suppressNestedInterleavedClientSpan() { Context outer = openTelemetryTracer.getSharedSpanBuilder("outer", Context.NONE); openTelemetryTracer.addLink(outer.addData(SPAN_CONTEXT_KEY, TEST_CONTEXT)); - outer = openTelemetryTracer.start("innerSuppressed", outer, ProcessKind.SEND); + outer = openTelemetryTracer.start("outer", outer, ProcessKind.SEND); Context inner1Suppressed = openTelemetryTracer.start("innerSuppressed", outer); Context inner1NotSuppressed = openTelemetryTracer.start("innerNotSuppressed", new StartSpanOptions(com.azure.core.util.tracing.SpanKind.PRODUCER), inner1Suppressed); @@ -890,6 +890,20 @@ public void suppressNestedInterleavedClientSpan() { assertEquals(innerNotSuppressedSpan.getParentSpanId(), outerSpan.getSpanContext().getSpanId()); } + @Test + public void suppressNestedMultipleLayersSpan() { + Context outer = openTelemetryTracer.start("outer", Context.NONE); + Context inner1Suppressed = openTelemetryTracer.start("innerSuppressed", outer); + Context inner2Suppressed = openTelemetryTracer.start("inner2Suppressed", inner1Suppressed); + + openTelemetryTracer.end("ok", null, inner2Suppressed); + openTelemetryTracer.end("ok", null, inner1Suppressed); + assertEquals(0, testExporter.getSpans().size()); + + openTelemetryTracer.end("ok", null, outer); + assertEquals(1, testExporter.getSpans().size()); + } + @ParameterizedTest @MethodSource("spanKinds") public void suppressNestedClientSpan(com.azure.core.util.tracing.SpanKind outerKind, com.azure.core.util.tracing.SpanKind innerKind, boolean shouldSuppressInner) { From 07af6216ecd5a2e4f22760132579ed1ff7db27e7 Mon Sep 17 00:00:00 2001 From: Liudmila Molkova Date: Mon, 23 May 2022 12:13:53 -0700 Subject: [PATCH 4/5] review --- eng/versioning/external_dependencies.txt | 1 + .../azure-core-tracing-opentelemetry/pom.xml | 7 ++ .../OpenTelemetryHttpPolicyTests.java | 13 +-- .../OpenTelemetryTracerTest.java | 90 +++++++------------ .../tracing/opentelemetry/TestExporter.java | 37 -------- 5 files changed, 45 insertions(+), 103 deletions(-) delete mode 100644 sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/TestExporter.java diff --git a/eng/versioning/external_dependencies.txt b/eng/versioning/external_dependencies.txt index d58f979336204..fd50441696f03 100644 --- a/eng/versioning/external_dependencies.txt +++ b/eng/versioning/external_dependencies.txt @@ -198,6 +198,7 @@ io.opentelemetry:opentelemetry-api;1.11.0 io.opentelemetry:opentelemetry-sdk;1.11.0 io.opentelemetry:opentelemetry-exporter-logging;1.11.0 io.opentelemetry:opentelemetry-exporter-jaeger;1.11.0 +io.opentelemetry:opentelemetry-sdk-testing;1.11.0 io.projectreactor:reactor-test;3.4.17 junit:junit;4.13.2 commons-cli:commons-cli;1.3 diff --git a/sdk/core/azure-core-tracing-opentelemetry/pom.xml b/sdk/core/azure-core-tracing-opentelemetry/pom.xml index 201616a03dcd9..e261b5bee9cb1 100644 --- a/sdk/core/azure-core-tracing-opentelemetry/pom.xml +++ b/sdk/core/azure-core-tracing-opentelemetry/pom.xml @@ -93,6 +93,12 @@ 4.0.0 test + + io.opentelemetry + opentelemetry-sdk-testing + test + 1.11.0 + @@ -147,6 +153,7 @@ io.opentelemetry:opentelemetry-sdk:[1.11.0] io.opentelemetry:opentelemetry-exporter-logging:[1.11.0] io.opentelemetry:opentelemetry-exporter-jaeger:[1.11.0] + io.opentelemetry:opentelemetry-sdk-testing:[1.11.0] diff --git a/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/OpenTelemetryHttpPolicyTests.java b/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/OpenTelemetryHttpPolicyTests.java index 381d0f7370202..2197de1ede70a 100644 --- a/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/OpenTelemetryHttpPolicyTests.java +++ b/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/OpenTelemetryHttpPolicyTests.java @@ -22,6 +22,7 @@ import io.opentelemetry.api.trace.SpanKind; import io.opentelemetry.api.trace.Tracer; import io.opentelemetry.sdk.OpenTelemetrySdk; +import io.opentelemetry.sdk.testing.exporter.InMemorySpanExporter; import io.opentelemetry.sdk.trace.ReadableSpan; import io.opentelemetry.sdk.trace.SdkTracerProvider; import io.opentelemetry.sdk.trace.data.LinkData; @@ -57,13 +58,13 @@ public class OpenTelemetryHttpPolicyTests { private static final String X_MS_REQUEST_ID_1 = "response id 1"; private static final String X_MS_REQUEST_ID_2 = "response id 2"; private static final int RESPONSE_STATUS_CODE = 201; - private TestExporter exporter; + private InMemorySpanExporter exporter; private Tracer tracer; private static final String SPAN_NAME = "foo"; @BeforeEach public void setUp(TestInfo testInfo) { - exporter = new TestExporter(); + exporter = InMemorySpanExporter.create(); SdkTracerProvider otelProvider = SdkTracerProvider.builder() .addSpanProcessor(SimpleSpanProcessor.create(exporter)).build(); @@ -96,7 +97,7 @@ public void openTelemetryHttpPolicyTest() { HttpResponse response = createHttpPipeline(tracer).send(request, tracingContext).block(); // Assert - List exportedSpans = exporter.getSpans(); + List exportedSpans = exporter.getFinishedSpanItems(); // rest proxy span is not exported as global otel is not configured assertEquals(1, exportedSpans.size()); @@ -153,7 +154,7 @@ public String getDescription() { HttpResponse response = createHttpPipeline(tracer).send(request).block(); // Assert - List exportedSpans = exporter.getSpans(); + List exportedSpans = exporter.getFinishedSpanItems(); // rest proxy span is not exported as global otel is not configured assertEquals(0, exportedSpans.size()); assertTrue(samplerCalled.get()); @@ -165,7 +166,7 @@ public void clientRequestIdIsStamped() { HttpResponse response = createHttpPipeline(tracer, new RequestIdPolicy()).send(request).block(); // Assert - List exportedSpans = exporter.getSpans(); + List exportedSpans = exporter.getFinishedSpanItems(); assertEquals(1, exportedSpans.size()); assertEquals("HTTP PUT", exportedSpans.get(0).getName()); @@ -223,7 +224,7 @@ public void everyTryIsTraced() { .assertNext(response -> assertEquals(200, response.getStatusCode())) .verifyComplete(); - List exportedSpans = exporter.getSpans(); + List exportedSpans = exporter.getFinishedSpanItems(); assertEquals(2, exportedSpans.size()); SpanData try503 = exportedSpans.get(0); diff --git a/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/OpenTelemetryTracerTest.java b/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/OpenTelemetryTracerTest.java index 0c52c8ea0c45d..acc2abb97bc43 100644 --- a/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/OpenTelemetryTracerTest.java +++ b/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/OpenTelemetryTracerTest.java @@ -20,14 +20,14 @@ import io.opentelemetry.api.trace.Tracer; import io.opentelemetry.context.Scope; import io.opentelemetry.sdk.OpenTelemetrySdk; -import io.opentelemetry.sdk.trace.ReadWriteSpan; +import io.opentelemetry.sdk.testing.exporter.InMemorySpanExporter; import io.opentelemetry.sdk.trace.ReadableSpan; import io.opentelemetry.sdk.trace.SdkTracerProvider; import io.opentelemetry.sdk.trace.SpanProcessor; import io.opentelemetry.sdk.trace.data.EventData; import io.opentelemetry.sdk.trace.data.LinkData; import io.opentelemetry.sdk.trace.data.SpanData; -import io.opentelemetry.sdk.trace.export.SpanExporter; +import io.opentelemetry.sdk.trace.export.SimpleSpanProcessor; import org.junit.jupiter.api.AfterEach; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; @@ -38,7 +38,6 @@ import java.time.Instant; import java.time.OffsetDateTime; import java.time.ZoneOffset; -import java.util.Collections; import java.util.HashMap; import java.util.List; import java.util.Map; @@ -90,7 +89,7 @@ public class OpenTelemetryTracerTest { private OpenTelemetryTracer openTelemetryTracer; private static final SpanContext TEST_CONTEXT = SpanContext.create("0123456789abcdef0123456789abcdef", "0123456789abcdef", TraceFlags.getSampled(), TraceState.getDefault()); - private TestExporter testExporter; + private InMemorySpanExporter testExporter; private Tracer tracer; private SpanProcessor spanProcessor; private Context tracingContext; @@ -104,39 +103,10 @@ public class OpenTelemetryTracerTest { } }; - class TestSpanProcessor implements SpanProcessor { - - private final SpanExporter exporter; - - TestSpanProcessor(SpanExporter exporter) { - this.exporter = exporter; - } - - @Override - public void onStart(io.opentelemetry.context.Context parentContext, ReadWriteSpan span) { - - } - - @Override - public boolean isStartRequired() { - return false; - } - - @Override - public void onEnd(ReadableSpan span) { - exporter.export(Collections.singletonList(span.toSpanData())); - } - - @Override - public boolean isEndRequired() { - return true; - } - } - @BeforeEach public void setUp() { - testExporter = new TestExporter(); - spanProcessor = new TestSpanProcessor(testExporter); + testExporter = InMemorySpanExporter.create(); + spanProcessor = SimpleSpanProcessor.create(testExporter); tracer = OpenTelemetrySdk.builder() .setTracerProvider(SdkTracerProvider.builder() .addSpanProcessor(spanProcessor) @@ -852,16 +822,16 @@ public void suppressNestedClientSpan() { Context innerNotSuppressed = openTelemetryTracer.start("innerNotSuppressed", new StartSpanOptions(com.azure.core.util.tracing.SpanKind.PRODUCER), innerSuppressed); openTelemetryTracer.end("ok", null, innerNotSuppressed); - assertEquals(1, testExporter.getSpans().size()); + assertEquals(1, testExporter.getFinishedSpanItems().size()); openTelemetryTracer.end("ok", null, innerSuppressed); - assertEquals(1, testExporter.getSpans().size()); + assertEquals(1, testExporter.getFinishedSpanItems().size()); openTelemetryTracer.end("ok", null, outer); - assertEquals(2, testExporter.getSpans().size()); + assertEquals(2, testExporter.getFinishedSpanItems().size()); - SpanData innerNotSuppressedSpan = testExporter.getSpans().get(0); - SpanData outerSpan = testExporter.getSpans().get(1); + SpanData innerNotSuppressedSpan = testExporter.getFinishedSpanItems().get(0); + SpanData outerSpan = testExporter.getFinishedSpanItems().get(1); assertEquals(innerNotSuppressedSpan.getSpanContext().getTraceId(), outerSpan.getSpanContext().getTraceId()); assertEquals(innerNotSuppressedSpan.getParentSpanId(), outerSpan.getSpanContext().getSpanId()); } @@ -877,15 +847,15 @@ public void suppressNestedInterleavedClientSpan() { Context inner2Suppressed = openTelemetryTracer.start("innerSuppressed", inner1NotSuppressed); openTelemetryTracer.end("ok", null, inner2Suppressed); - assertEquals(0, testExporter.getSpans().size()); + assertEquals(0, testExporter.getFinishedSpanItems().size()); openTelemetryTracer.end("ok", null, inner1NotSuppressed); openTelemetryTracer.end("ok", null, inner1Suppressed); openTelemetryTracer.end("ok", null, outer); - assertEquals(2, testExporter.getSpans().size()); + assertEquals(2, testExporter.getFinishedSpanItems().size()); - SpanData innerNotSuppressedSpan = testExporter.getSpans().get(0); - SpanData outerSpan = testExporter.getSpans().get(1); + SpanData innerNotSuppressedSpan = testExporter.getFinishedSpanItems().get(0); + SpanData outerSpan = testExporter.getFinishedSpanItems().get(1); assertEquals(innerNotSuppressedSpan.getSpanContext().getTraceId(), outerSpan.getSpanContext().getTraceId()); assertEquals(innerNotSuppressedSpan.getParentSpanId(), outerSpan.getSpanContext().getSpanId()); } @@ -898,10 +868,10 @@ public void suppressNestedMultipleLayersSpan() { openTelemetryTracer.end("ok", null, inner2Suppressed); openTelemetryTracer.end("ok", null, inner1Suppressed); - assertEquals(0, testExporter.getSpans().size()); + assertEquals(0, testExporter.getFinishedSpanItems().size()); openTelemetryTracer.end("ok", null, outer); - assertEquals(1, testExporter.getSpans().size()); + assertEquals(1, testExporter.getFinishedSpanItems().size()); } @ParameterizedTest @@ -912,22 +882,22 @@ public void suppressNestedClientSpan(com.azure.core.util.tracing.SpanKind outerK Context neverSuppressed = openTelemetryTracer.start("innerNotSuppressed", new StartSpanOptions(com.azure.core.util.tracing.SpanKind.PRODUCER), inner); openTelemetryTracer.end("ok", null, neverSuppressed); - assertEquals(1, testExporter.getSpans().size()); + assertEquals(1, testExporter.getFinishedSpanItems().size()); openTelemetryTracer.end("ok", null, inner); - assertEquals(shouldSuppressInner ? 1 : 2, testExporter.getSpans().size()); + assertEquals(shouldSuppressInner ? 1 : 2, testExporter.getFinishedSpanItems().size()); openTelemetryTracer.end("ok", null, outer); - assertEquals(shouldSuppressInner ? 2 : 3, testExporter.getSpans().size()); + assertEquals(shouldSuppressInner ? 2 : 3, testExporter.getFinishedSpanItems().size()); - SpanData neverSuppressedSpan = testExporter.getSpans().get(0); + SpanData neverSuppressedSpan = testExporter.getFinishedSpanItems().get(0); if (shouldSuppressInner) { - SpanData outerSpan = testExporter.getSpans().get(1); + SpanData outerSpan = testExporter.getFinishedSpanItems().get(1); assertEquals(neverSuppressedSpan.getParentSpanId(), outerSpan.getSpanContext().getSpanId()); } else { - SpanData innerSpan = testExporter.getSpans().get(1); - SpanData outerSpan = testExporter.getSpans().get(2); + SpanData innerSpan = testExporter.getFinishedSpanItems().get(1); + SpanData outerSpan = testExporter.getFinishedSpanItems().get(2); assertEquals(neverSuppressedSpan.getParentSpanId(), innerSpan.getSpanContext().getSpanId()); assertEquals(innerSpan.getParentSpanId(), outerSpan.getSpanContext().getSpanId()); } @@ -975,7 +945,7 @@ public void suppressNestedClientSpanAttributes() { openTelemetryTracer.end("ok", null, innerSuppressed); openTelemetryTracer.end("ok", null, outer); - SpanData outerSpan = testExporter.getSpans().get(0); + SpanData outerSpan = testExporter.getFinishedSpanItems().get(0); assertEquals("outer", outerSpan.getName()); Map outerAttributesExpected = new HashMap() {{ @@ -998,7 +968,7 @@ public void suppressNestedClientSpanEvents() { openTelemetryTracer.end("ok", null, innerSuppressed); openTelemetryTracer.end("ok", null, outer); - SpanData outerSpan = testExporter.getSpans().get(0); + SpanData outerSpan = testExporter.getFinishedSpanItems().get(0); assertEquals(2, outerSpan.getEvents().size()); assertEquals("outer1", outerSpan.getEvents().get(0).getName()); assertEquals("outer2", outerSpan.getEvents().get(1).getName()); @@ -1013,7 +983,7 @@ public void suppressNestedClientSpanLinks() { openTelemetryTracer.end("ok", null, innerSuppressed); - assertTrue(testExporter.getSpans().isEmpty()); + assertTrue(testExporter.getFinishedSpanItems().isEmpty()); } @Test @@ -1028,7 +998,7 @@ public void suppressNestedClientSpanMakeCurrent() throws Exception { innerScope.close(); assertSame(outerSpan, Span.current()); openTelemetryTracer.end("ok", null, inner); - assertTrue(testExporter.getSpans().isEmpty()); + assertTrue(testExporter.getFinishedSpanItems().isEmpty()); } @Test @@ -1040,10 +1010,10 @@ public void startSendSpanWithoutBuilder() { openTelemetryTracer.end("ok", null, sendNoBuilder); openTelemetryTracer.end("ok", null, outer); - assertEquals(2, testExporter.getSpans().size()); + assertEquals(2, testExporter.getFinishedSpanItems().size()); - SpanData sendNoBuilderSpan = testExporter.getSpans().get(0); - SpanData outerSpan = testExporter.getSpans().get(1); + SpanData sendNoBuilderSpan = testExporter.getFinishedSpanItems().get(0); + SpanData outerSpan = testExporter.getFinishedSpanItems().get(1); assertEquals(sendNoBuilderSpan.getSpanContext().getTraceId(), outerSpan.getSpanContext().getTraceId()); assertEquals(sendNoBuilderSpan.getParentSpanId(), outerSpan.getSpanContext().getSpanId()); } diff --git a/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/TestExporter.java b/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/TestExporter.java deleted file mode 100644 index 8c7c4c35acb08..0000000000000 --- a/sdk/core/azure-core-tracing-opentelemetry/src/test/java/com/azure/core/tracing/opentelemetry/TestExporter.java +++ /dev/null @@ -1,37 +0,0 @@ -// Copyright (c) Microsoft Corporation. All rights reserved. -// Licensed under the MIT License. - -package com.azure.core.tracing.opentelemetry; - -import io.opentelemetry.sdk.common.CompletableResultCode; -import io.opentelemetry.sdk.trace.data.SpanData; -import io.opentelemetry.sdk.trace.export.SpanExporter; - -import java.util.Collection; -import java.util.List; -import java.util.concurrent.CopyOnWriteArrayList; - -class TestExporter implements SpanExporter { - - private final List exportedSpans = new CopyOnWriteArrayList<>(); - - @Override - public CompletableResultCode export(Collection spans) { - exportedSpans.addAll(spans); - return CompletableResultCode.ofSuccess(); - } - - @Override - public CompletableResultCode flush() { - return CompletableResultCode.ofSuccess(); - } - - @Override - public CompletableResultCode shutdown() { - return CompletableResultCode.ofSuccess(); - } - - public List getSpans() { - return exportedSpans; - } -} From bfccd110abe9b4884bc43fc3996bd89e00a250cf Mon Sep 17 00:00:00 2001 From: Liudmila Molkova Date: Mon, 23 May 2022 12:19:43 -0700 Subject: [PATCH 5/5] review --- .../opentelemetry/OpenTelemetryHttpPolicy.java | 14 ++++++++------ 1 file changed, 8 insertions(+), 6 deletions(-) diff --git a/sdk/core/azure-core-tracing-opentelemetry/src/main/java/com/azure/core/tracing/opentelemetry/OpenTelemetryHttpPolicy.java b/sdk/core/azure-core-tracing-opentelemetry/src/main/java/com/azure/core/tracing/opentelemetry/OpenTelemetryHttpPolicy.java index 250db870b0527..d194b1f27f83b 100644 --- a/sdk/core/azure-core-tracing-opentelemetry/src/main/java/com/azure/core/tracing/opentelemetry/OpenTelemetryHttpPolicy.java +++ b/sdk/core/azure-core-tracing-opentelemetry/src/main/java/com/azure/core/tracing/opentelemetry/OpenTelemetryHttpPolicy.java @@ -19,6 +19,7 @@ import io.opentelemetry.api.trace.Tracer; import io.opentelemetry.api.trace.propagation.W3CTraceContextPropagator; import io.opentelemetry.context.Context; +import io.opentelemetry.context.Scope; import io.opentelemetry.context.propagation.TextMapPropagator; import io.opentelemetry.context.propagation.TextMapSetter; import reactor.core.CoreSubscriber; @@ -227,20 +228,21 @@ private static io.opentelemetry.context.Context getTraceContextOrCurrent(HttpPip */ static final class ScalarPropagatingMono extends Mono { public static final Mono INSTANCE = new ScalarPropagatingMono(); - private static final AutoCloseable NOOP_CLOSEABLE = () -> { }; private final Object value = new Object(); private ScalarPropagatingMono() { } @Override + @SuppressWarnings("try") public void subscribe(CoreSubscriber actual) { Context traceContext = actual.currentContext().getOrDefault(REACTOR_PARENT_TRACE_CONTEXT_KEY, null); - AutoCloseable closeable = traceContext != null ? traceContext.makeCurrent() : NOOP_CLOSEABLE; - actual.onSubscribe(Operators.scalarSubscription(actual, value)); - try { - closeable.close(); - } catch (Exception ignored) { + if (traceContext != null) { + try (Scope scope = traceContext.makeCurrent()) { + actual.onSubscribe(Operators.scalarSubscription(actual, value)); + } + } else { + actual.onSubscribe(Operators.scalarSubscription(actual, value)); } } }