Skip to content

Commit

Permalink
Suppress nested SDK public method calls (#28998)
Browse files Browse the repository at this point in the history
* Suppress nested SDK public method calls
  • Loading branch information
lmolkova authored May 27, 2022
1 parent fc3911d commit e849033
Show file tree
Hide file tree
Showing 8 changed files with 349 additions and 163 deletions.
1 change: 1 addition & 0 deletions eng/versioning/external_dependencies.txt
Original file line number Diff line number Diff line change
Expand Up @@ -199,6 +199,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
Expand Down
2 changes: 2 additions & 0 deletions sdk/core/azure-core-tracing-opentelemetry/CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
8 changes: 8 additions & 0 deletions sdk/core/azure-core-tracing-opentelemetry/pom.xml
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,7 @@
<properties>
<javaModulesSurefireArgLine>
--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
</javaModulesSurefireArgLine>
</properties>

Expand Down Expand Up @@ -92,6 +93,12 @@
<version>4.0.0</version> <!-- {x-version-update;org.mockito:mockito-core;external_dependency} -->
<scope>test</scope>
</dependency>
<dependency>
<groupId>io.opentelemetry</groupId>
<artifactId>opentelemetry-sdk-testing</artifactId>
<scope>test</scope>
<version>1.11.0</version> <!-- {x-version-update;io.opentelemetry:opentelemetry-sdk-testing;external_dependency} -->
</dependency>

<!-- sample file dependencies -->
<dependency>
Expand Down Expand Up @@ -146,6 +153,7 @@
<include>io.opentelemetry:opentelemetry-sdk:[1.11.0]</include> <!-- {x-include-update;io.opentelemetry:opentelemetry-sdk;external_dependency} -->
<include>io.opentelemetry:opentelemetry-exporter-logging:[1.11.0]</include> <!-- {x-include-update;io.opentelemetry:opentelemetry-exporter-logging;external_dependency} -->
<include>io.opentelemetry:opentelemetry-exporter-jaeger:[1.11.0]</include> <!-- {x-include-update;io.opentelemetry:opentelemetry-exporter-jaeger;external_dependency} -->
<include>io.opentelemetry:opentelemetry-sdk-testing:[1.11.0]</include> <!-- {x-include-update;io.opentelemetry:opentelemetry-sdk-testing;external_dependency} -->
</includes>
</bannedDependencies>
</rules>
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -20,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;
Expand Down Expand Up @@ -228,22 +228,18 @@ private static io.opentelemetry.context.Context getTraceContextOrCurrent(HttpPip
*/
static final class ScalarPropagatingMono extends Mono<Object> {
public static final Mono<Object> INSTANCE = new ScalarPropagatingMono();

private final Object value = new Object();

private ScalarPropagatingMono() {
}

@Override
@SuppressWarnings("try")
public void subscribe(CoreSubscriber<? super Object> 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) {
try (Scope scope = traceContext.makeCurrent()) {
actual.onSubscribe(Operators.scalarSubscription(actual, value));
}
} else {
actual.onSubscribe(Operators.scalarSubscription(actual, value));
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;

/**
Expand Down Expand Up @@ -64,28 +65,36 @@ 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);
}

/**
* {@inheritDoc}
*/
@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);
}

/**
Expand All @@ -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 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.");
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);
}
}

Expand All @@ -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;
Expand All @@ -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;
Expand Down Expand Up @@ -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;
}
Expand Down Expand Up @@ -218,14 +244,18 @@ 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));
}

/**
* {@inheritDoc}
*/
@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");
Expand Down Expand Up @@ -278,6 +308,7 @@ public void addEvent(String eventName, Map<String, Object> traceEventAttributes,
* @return A {@link Context} with created {@link Span}.
*/
private Context startSpanInternal(SpanBuilder spanBuilder,
boolean isClientMethod,
java.util.function.BiConsumer<Span, Context> setAttributes,
Context context) {
Objects.requireNonNull(spanBuilder, "'spanBuilder' cannot be null.");
Expand All @@ -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));
}

/**
Expand All @@ -307,15 +343,15 @@ 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}.
*/
@SuppressWarnings("unchecked")
private SpanBuilder createSpanBuilder(String spanName,
SpanContext remoteParentContext,
SpanKind spanKind,
Map<String, Object> beforeSaplingAttributes,
Map<String, Object> beforeSamplingAttributes,
Context context) {
String spanNameKey = getOrNull(context, USER_SPAN_NAME_KEY, String.class);

Expand All @@ -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<Object>) key, value));
}
Expand Down Expand Up @@ -468,7 +504,7 @@ private void addMessagingAttributes(Span span, Context context) {
* @return The T type of raw class object
*/
@SuppressWarnings("unchecked")
private <T> T getOrNull(Context context, String key, Class<T> clazz) {
private static <T> T getOrNull(Context context, String key, Class<T> clazz) {
final Optional<Object> 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);
Expand All @@ -484,7 +520,7 @@ private <T> T getOrNull(Context context, String key, Class<T> 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);
Expand All @@ -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);
Expand All @@ -523,4 +563,42 @@ 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) {
return isClientCall(kind) && getBoolean(CLIENT_METHOD_CALL_FLAG, context);
}

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

0 comments on commit e849033

Please sign in to comment.