diff --git a/sdk-platform-java/gax-java/dependencies.properties b/sdk-platform-java/gax-java/dependencies.properties index 6682d09eff89..135749d324d9 100644 --- a/sdk-platform-java/gax-java/dependencies.properties +++ b/sdk-platform-java/gax-java/dependencies.properties @@ -97,6 +97,7 @@ maven.io_opentelemetry_opentelemetry_sdk_testing=io.opentelemetry:opentelemetry- maven.io_opentelemetry_opentelemetry_sdk=io.opentelemetry:opentelemetry-sdk:1.57.0 maven.io_opentelemetry_opentelemetry_sdk_common=io.opentelemetry:opentelemetry-sdk-common:1.57.0 maven.io_opentelemetry_opentelemetry_sdk_metrics=io.opentelemetry:opentelemetry-sdk-metrics:1.57.0 +maven.io_opentelemetry_opentelemetry_sdk_trace=io.opentelemetry:opentelemetry-sdk-trace:1.57.0 maven.com_google_guava_guava_testlib=com.google.guava:guava-testlib:32.1.3-jre maven.org_awaitility_awaitility=org.awaitility:awaitility:4.3.0 diff --git a/sdk-platform-java/gax-java/gax/BUILD.bazel b/sdk-platform-java/gax-java/gax/BUILD.bazel index c98939ba7e18..a77329ede135 100644 --- a/sdk-platform-java/gax-java/gax/BUILD.bazel +++ b/sdk-platform-java/gax-java/gax/BUILD.bazel @@ -49,6 +49,7 @@ _TEST_COMPILE_DEPS = [ "@io_opentelemetry_opentelemetry_sdk//jar", "@io_opentelemetry_opentelemetry_sdk_metrics//jar", "@io_opentelemetry_opentelemetry_sdk_common//jar", + "@io_opentelemetry_opentelemetry_sdk_trace//jar", "@com_google_guava_guava_testlib//jar", "@org_awaitility_awaitility//jar", ] diff --git a/sdk-platform-java/gax-java/gax/pom.xml b/sdk-platform-java/gax-java/gax/pom.xml index 02c64480defb..8db559aabf12 100644 --- a/sdk-platform-java/gax-java/gax/pom.xml +++ b/sdk-platform-java/gax-java/gax/pom.xml @@ -104,6 +104,11 @@ opentelemetry-sdk-common test + + io.opentelemetry + opentelemetry-sdk-trace + test + org.junit.jupiter junit-jupiter-api diff --git a/sdk-platform-java/gax-java/gax/src/main/java/com/google/api/gax/tracing/OpenTelemetryTracingTracer.java b/sdk-platform-java/gax-java/gax/src/main/java/com/google/api/gax/tracing/OpenTelemetryTracingTracer.java index cb41da9ccbeb..a4a87463c26d 100644 --- a/sdk-platform-java/gax-java/gax/src/main/java/com/google/api/gax/tracing/OpenTelemetryTracingTracer.java +++ b/sdk-platform-java/gax-java/gax/src/main/java/com/google/api/gax/tracing/OpenTelemetryTracingTracer.java @@ -35,10 +35,14 @@ import io.opentelemetry.api.trace.Span; import io.opentelemetry.api.trace.SpanBuilder; import io.opentelemetry.api.trace.SpanKind; +import io.opentelemetry.api.trace.StatusCode; import io.opentelemetry.api.trace.Tracer; +import io.opentelemetry.api.trace.propagation.W3CTraceContextPropagator; +import io.opentelemetry.context.Context; import java.util.HashMap; import java.util.Map; import java.util.concurrent.CancellationException; +import java.util.concurrent.locks.ReentrantLock; import org.jspecify.annotations.NullMarked; import org.jspecify.annotations.Nullable; @@ -51,15 +55,30 @@ class OpenTelemetryTracingTracer implements ApiTracer { private final Tracer tracer; private final Map attemptAttributes; private final String attemptSpanName; + private final String operationSpanName; private final ApiTracerContext apiTracerContext; - private @Nullable Span attemptSpan; + // Captures the active trace context from the calling thread at RPC initiation. + // This allows the operation span and attempt spans to link back to the caller's trace. + private final Context parentContext; + // Trace context containing the operationSpan, serving as the parent for attempt spans. + private final Context operationContext; + // Lock coordinates attempt transitions and operation completion across threads. + private final ReentrantLock lock = new ReentrantLock(); + private boolean operationCompleted; + // operationSpan and attemptSpan are volatile to ensure fresh reads for thread-safe snapshotting. + private volatile @Nullable Span operationSpan; + private volatile @Nullable Span attemptSpan; @Override - public void injectTraceContext(java.util.Map carrier) { - if (attemptSpan != null) { - io.opentelemetry.context.Context context = - io.opentelemetry.context.Context.current().with(attemptSpan); - io.opentelemetry.api.trace.propagation.W3CTraceContextPropagator.getInstance() + public void injectTraceContext(Map carrier) { + // Prefer the active attempt span (T4) so outgoing RPC wire context reflects the specific + // attempt; + // fall back to the overall operation span (T3) if no attempt is currently in-flight. + Span currentAttempt = attemptSpan; + Span spanToInject = currentAttempt != null ? currentAttempt : operationSpan; + if (spanToInject != null) { + Context context = Context.current().with(spanToInject); + W3CTraceContextPropagator.getInstance() .inject( context, carrier, @@ -71,6 +90,20 @@ public void injectTraceContext(java.util.Map carrier) { } } + @Override + @SuppressWarnings("MustBeClosedChecker") + public Scope inScope() { + // Attach the active attempt span to the current execution thread context; + // fall back to the overall operation span when between attempts. + Span currentAttempt = attemptSpan; + Span currentSpan = currentAttempt != null ? currentAttempt : operationSpan; + if (currentSpan == null) { + return () -> {}; + } + io.opentelemetry.context.Scope otelScope = currentSpan.makeCurrent(); + return otelScope::close; + } + /** * Creates a new instance of {@code OpenTelemetryTracingTracer}. * @@ -78,11 +111,7 @@ public void injectTraceContext(java.util.Map carrier) { * @param apiTracerContext the {@link ApiTracerContext} to use for recording spans */ OpenTelemetryTracingTracer(Tracer tracer, ApiTracerContext apiTracerContext) { - this.tracer = tracer; - this.apiTracerContext = apiTracerContext; - this.attemptSpanName = resolveAttemptSpanName(apiTracerContext); - this.attemptAttributes = new HashMap<>(); - buildAttributes(); + this(tracer, apiTracerContext, resolveAttemptSpanName(apiTracerContext)); } /** @@ -96,13 +125,72 @@ public void injectTraceContext(java.util.Map carrier) { @InternalApi OpenTelemetryTracingTracer( Tracer tracer, ApiTracerContext apiTracerContext, String attemptSpanName) { + this(tracer, apiTracerContext, attemptSpanName, resolveOperationSpanName(attemptSpanName)); + } + + /** + * Creates a new instance of {@code OpenTelemetryTracingTracer} with explicitly provided attempt + * and operation span names. + * + * @param tracer the {@link Tracer} to use for recording spans + * @param apiTracerContext the {@link ApiTracerContext} to use for recording spans + * @param attemptSpanName the name of the individual attempt spans + * @param operationSpanName the name of the overall client request operation span + */ + @InternalApi + OpenTelemetryTracingTracer( + Tracer tracer, + ApiTracerContext apiTracerContext, + String attemptSpanName, + String operationSpanName) { this.tracer = tracer; - this.attemptSpanName = attemptSpanName; this.apiTracerContext = apiTracerContext; + this.operationSpanName = operationSpanName; + this.attemptSpanName = attemptSpanName; this.attemptAttributes = new HashMap<>(); + this.parentContext = Context.current(); buildAttributes(); + this.operationSpan = startOperationSpan(); + this.operationContext = parentContext.with(this.operationSpan); } + /** + * Starts and initializes the operation-level client request span (T3). + * + * @return the newly started {@link Span} for the overall operation + */ + private Span startOperationSpan() { + SpanBuilder operationSpanBuilder = tracer.spanBuilder(operationSpanName); + operationSpanBuilder.setSpanKind(SpanKind.INTERNAL); + operationSpanBuilder.setParent(parentContext); + operationSpanBuilder.setAllAttributes( + ObservabilityUtils.toOtelAttributes(this.attemptAttributes)); + return operationSpanBuilder.startSpan(); + } + + /** + * Derives the operation-level span name from the attempt span name. + * + * @param attemptSpanName the attempt span name + * @return the operation span name + */ + private static String resolveOperationSpanName(String attemptSpanName) { + if (!Strings.isNullOrEmpty(attemptSpanName)) { + if (attemptSpanName.endsWith("/attempt")) { + String name = attemptSpanName.substring(0, attemptSpanName.length() - "/attempt".length()); + return name.isEmpty() ? "operation" : name; + } + return "attempt".equals(attemptSpanName) ? "operation" : attemptSpanName; + } + return "operation"; + } + + /** + * Resolves the canonical attempt-level span name based on transport and context. + * + * @param apiTracerContext the tracer context containing transport and method metadata + * @return the attempt span name + */ private static String resolveAttemptSpanName(ApiTracerContext apiTracerContext) { if (apiTracerContext.transport() == ApiTracerContext.Transport.GRPC) { // gRPC Uses the full method name as span name. @@ -118,34 +206,122 @@ private static String resolveAttemptSpanName(ApiTracerContext apiTracerContext) } } + /** Copies attempt-level attributes from the tracer context into the local attribute cache. */ private void buildAttributes() { this.attemptAttributes.putAll(this.apiTracerContext.getAttemptAttributes()); } @Override public void attemptStarted(Object request, int attemptNumber) { - Map currentAttemptAttributes = new HashMap<>(this.attemptAttributes); - - if (attemptNumber > 0) { - ApiTracerContext.Transport transport = apiTracerContext.transport(); - if (transport == ApiTracerContext.Transport.GRPC) { - currentAttemptAttributes.put( - ObservabilityAttributes.GRPC_RESEND_COUNT_ATTRIBUTE, (long) attemptNumber); - } else if (transport == ApiTracerContext.Transport.HTTP) { - currentAttemptAttributes.put( - ObservabilityAttributes.HTTP_RESEND_COUNT_ATTRIBUTE, (long) attemptNumber); + Span oldSpan = null; + lock.lock(); + try { + // Prevent creating new attempt spans if the overall operation has already concluded. + if (operationCompleted || operationSpan == null) { + return; + } + // If a previous attempt was not explicitly closed before a retry started, + // capture it so it can be ended cleanly outside the lock without blocking. + if (attemptSpan != null) { + oldSpan = attemptSpan; + attemptSpan = null; } + Map currentAttemptAttributes = new HashMap<>(this.attemptAttributes); + + if (attemptNumber > 0) { + ApiTracerContext.Transport transport = apiTracerContext.transport(); + if (transport == ApiTracerContext.Transport.GRPC) { + currentAttemptAttributes.put( + ObservabilityAttributes.GRPC_RESEND_COUNT_ATTRIBUTE, (long) attemptNumber); + } else if (transport == ApiTracerContext.Transport.HTTP) { + currentAttemptAttributes.put( + ObservabilityAttributes.HTTP_RESEND_COUNT_ATTRIBUTE, (long) attemptNumber); + } + } + + SpanBuilder spanBuilder = tracer.spanBuilder(attemptSpanName); + + // Attempt spans are of the CLIENT kind + spanBuilder.setSpanKind(SpanKind.CLIENT); + + // Link attempt span to operation context (parent T3 span) + spanBuilder.setParent(operationContext); + + // Pass the combined attributes to the new SpanBuilder method + spanBuilder.setAllAttributes(ObservabilityUtils.toOtelAttributes(currentAttemptAttributes)); + + this.attemptSpan = spanBuilder.startSpan(); + } finally { + lock.unlock(); + } + // End lingering previous attempt outside the lock to avoid holding the lock during callbacks. + if (oldSpan != null) { + endSpan(oldSpan, null); } + } - SpanBuilder spanBuilder = tracer.spanBuilder(attemptSpanName); + /** + * Signals that the overall logical operation succeeded. + * + *

Closes any remaining in-flight attempt span and ends the operation span. + */ + @Override + public void operationSucceeded() { + recordErrorAndEndOperation(null); + } - // Attempt spans are of the CLIENT kind - spanBuilder.setSpanKind(SpanKind.CLIENT); + /** + * Signals that the overall logical operation was cancelled. + * + *

Closes any remaining in-flight attempt span with a {@link CancellationException} and ends + * the operation span with an ERROR status. + */ + @Override + public void operationCancelled() { + recordErrorAndEndOperation(new CancellationException()); + } - // Pass the combined attributes to the new SpanBuilder method - spanBuilder.setAllAttributes(ObservabilityUtils.toOtelAttributes(currentAttemptAttributes)); + /** + * Signals that the overall logical operation failed permanently. + * + *

Closes any remaining in-flight attempt span and ends the operation span with the provided + * error details and an ERROR status. + * + * @param error the cause of the operation failure + */ + @Override + public void operationFailed(Throwable error) { + recordErrorAndEndOperation(error); + } - this.attemptSpan = spanBuilder.startSpan(); + /** + * Records error details and ends both the active attempt span and the operation span in a + * thread-safe manner. + * + * @param error the exception associated with the operation failure, or {@code null} if successful + */ + private void recordErrorAndEndOperation(@Nullable Throwable error) { + Span localOperationSpan; + Span localAttemptSpan; + lock.lock(); + try { + operationCompleted = true; + localOperationSpan = operationSpan; + if (localOperationSpan == null) { + return; + } + operationSpan = null; + localAttemptSpan = attemptSpan; + attemptSpan = null; + } finally { + lock.unlock(); + } + + if (localAttemptSpan != null) { + endSpan(localAttemptSpan, error); + } + + endSpan(localOperationSpan, error); } @Override @@ -154,13 +330,16 @@ public void attemptSucceeded() { } @Override - public void responseHeadersReceived(java.util.Map headers) { - if (attemptSpan == null) { + public void responseHeadersReceived(Map headers) { + // Snapshot to a local variable to prevent race conditions if another thread + // clears attemptSpan concurrently. + Span currentSpan = attemptSpan; + if (currentSpan == null) { return; } long contentLength = extractContentLength(headers); if (contentLength >= 0) { - attemptSpan.setAttribute(ObservabilityAttributes.HTTP_RESPONSE_BODY_SIZE, contentLength); + currentSpan.setAttribute(ObservabilityAttributes.HTTP_RESPONSE_BODY_SIZE, contentLength); } } @@ -215,42 +394,65 @@ public void attemptPermanentFailure(Throwable error) { recordErrorAndEndAttempt(error); } + /** + * Records error details and ends the current attempt span in a thread-safe manner. + * + * @param error the exception associated with the attempt failure, or {@code null} if successful + */ private void recordErrorAndEndAttempt(@Nullable Throwable error) { - if (attemptSpan == null) { - return; + Span localAttemptSpan; + lock.lock(); + try { + localAttemptSpan = attemptSpan; + if (localAttemptSpan == null) { + return; + } + attemptSpan = null; + } finally { + lock.unlock(); } + + endSpan(localAttemptSpan, error); + } + + /** + * Attaches response status attributes and error messages to the span and ends it. + * + *

This method runs outside of synchronization locks to avoid blocking threads during + * OpenTelemetry span completion callbacks. + * + * @param span the span to finish + * @param error the exception that caused the span to end, or {@code null} if successful + */ + private void endSpan(Span span, @Nullable Throwable error) { Map responseAttributes = ObservabilityUtils.getResponseAttributes(error, this.apiTracerContext.transport()); if (!responseAttributes.isEmpty()) { - attemptSpan.setAllAttributes(ObservabilityUtils.toOtelAttributes(responseAttributes)); + span.setAllAttributes(ObservabilityUtils.toOtelAttributes(responseAttributes)); } - if (error != null && !Strings.isNullOrEmpty(error.getMessage())) { - attemptSpan.setAttribute( - ObservabilityAttributes.STATUS_MESSAGE_ATTRIBUTE, error.getMessage()); - } - - endAttempt(); - } - - private void endAttempt() { - if (attemptSpan == null) { - return; + if (error != null) { + span.setStatus(StatusCode.ERROR); + if (!Strings.isNullOrEmpty(error.getMessage())) { + span.setAttribute(ObservabilityAttributes.STATUS_MESSAGE_ATTRIBUTE, error.getMessage()); + } } - attemptSpan.end(); - attemptSpan = null; + span.end(); } @Override public void requestUrlResolved(String url) { - if (attemptSpan == null) { + // Snapshot to a local variable to prevent race conditions if another thread + // clears attemptSpan concurrently. + Span currentSpan = attemptSpan; + if (currentSpan == null) { return; } String sanitizedUrlString = ObservabilityUtils.sanitizeUrlFull(url); if (sanitizedUrlString.isEmpty()) { return; } - attemptSpan.setAttribute(ObservabilityAttributes.HTTP_URL_FULL_ATTRIBUTE, sanitizedUrlString); + currentSpan.setAttribute(ObservabilityAttributes.HTTP_URL_FULL_ATTRIBUTE, sanitizedUrlString); } } diff --git a/sdk-platform-java/gax-java/gax/src/test/java/com/google/api/gax/tracing/OpenTelemetryTracingTracerFactoryTest.java b/sdk-platform-java/gax-java/gax/src/test/java/com/google/api/gax/tracing/OpenTelemetryTracingTracerFactoryTest.java index 3c78cef6dbd7..4a58a3b07bfd 100644 --- a/sdk-platform-java/gax-java/gax/src/test/java/com/google/api/gax/tracing/OpenTelemetryTracingTracerFactoryTest.java +++ b/sdk-platform-java/gax-java/gax/src/test/java/com/google/api/gax/tracing/OpenTelemetryTracingTracerFactoryTest.java @@ -75,6 +75,7 @@ void setUp() { when(openTelemetry.getTracer(anyString())).thenReturn(tracer); when(tracer.spanBuilder(anyString())).thenReturn(spanBuilder); when(spanBuilder.setSpanKind(any())).thenReturn(spanBuilder); + when(spanBuilder.setParent(any())).thenReturn(spanBuilder); when(spanBuilder.setAllAttributes(any(Attributes.class))).thenReturn(spanBuilder); when(spanBuilder.startSpan()).thenReturn(span); @@ -228,7 +229,7 @@ void testNewTracer_withContext_grpc_usesFullMethodName() { tracerInstance.attemptStarted(null, 1); - verify(tracer).spanBuilder("google.cloud.v1.Service/Method"); + verify(tracer, atLeastOnce()).spanBuilder("google.cloud.v1.Service/Method"); } @ParameterizedTest @@ -255,7 +256,7 @@ void testNewTracer_withContext_http_usesHttpMethodAndPathTemplate( tracerInstance.attemptStarted(null, 1); - verify(tracer).spanBuilder(expectedSpanName); + verify(tracer, atLeastOnce()).spanBuilder(expectedSpanName); } @Test @@ -273,7 +274,7 @@ void testNewTracer_withContext_http_noHttpMethodOrPathTemplate_usesFullMethodNam tracerInstance.attemptStarted(null, 1); - verify(tracer).spanBuilder("google.cloud.v1.Service.Method"); + verify(tracer, atLeastOnce()).spanBuilder("google.cloud.v1.Service.Method"); } @Test @@ -309,7 +310,7 @@ void testNewTracer_mergesFactoryContext() { tracerInstance.attemptStarted(null, 1); ArgumentCaptor attributesCaptor = ArgumentCaptor.forClass(Attributes.class); - verify(spanBuilder).setAllAttributes(attributesCaptor.capture()); + verify(spanBuilder, atLeastOnce()).setAllAttributes(attributesCaptor.capture()); Attributes attributes = attributesCaptor.getValue(); assertThat(attributes.asMap()) diff --git a/sdk-platform-java/gax-java/gax/src/test/java/com/google/api/gax/tracing/OpenTelemetryTracingTracerIntegrationTest.java b/sdk-platform-java/gax-java/gax/src/test/java/com/google/api/gax/tracing/OpenTelemetryTracingTracerIntegrationTest.java new file mode 100644 index 000000000000..b479a6a5eccb --- /dev/null +++ b/sdk-platform-java/gax-java/gax/src/test/java/com/google/api/gax/tracing/OpenTelemetryTracingTracerIntegrationTest.java @@ -0,0 +1,368 @@ +/* + * Copyright 2026 Google LLC + * + * Redistribution and use in source and binary forms, with or without + * modification, are permitted provided that the following conditions are + * met: + * + * * Redistributions of source code must retain the above copyright + * notice, this list of conditions and the following disclaimer. + * * Redistributions in binary form must reproduce the above + * copyright notice, this list of conditions and the following disclaimer + * in the documentation and/or other materials provided with the + * distribution. + * * Neither the name of Google LLC nor the names of its + * contributors may be used to endorse or promote products derived from + * this software without specific prior written permission. + * + * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS + * "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT + * LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR + * A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT + * OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, + * SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT + * LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, + * DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY + * THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT + * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE + * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. + */ +package com.google.api.gax.tracing; + +import static com.google.common.truth.Truth.assertThat; + +import com.google.api.gax.rpc.LibraryMetadata; +import com.google.api.gax.tracing.ApiTracerContext.Transport; +import com.google.api.gax.tracing.ApiTracerFactory.OperationType; +import io.opentelemetry.api.common.AttributeKey; +import io.opentelemetry.api.trace.Span; +import io.opentelemetry.api.trace.SpanKind; +import io.opentelemetry.api.trace.Tracer; +import io.opentelemetry.context.Scope; +import io.opentelemetry.sdk.OpenTelemetrySdk; +import io.opentelemetry.sdk.testing.exporter.InMemorySpanExporter; +import io.opentelemetry.sdk.trace.SdkTracerProvider; +import io.opentelemetry.sdk.trace.data.SpanData; +import io.opentelemetry.sdk.trace.export.SimpleSpanProcessor; +import java.time.Duration; +import java.util.List; +import java.util.stream.Collectors; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; + +class OpenTelemetryTracingTracerIntegrationTest { + + private static final String FULL_METHOD_NAME = "google.fake.v1.FakeService/FakeMethod"; + private static final LibraryMetadata LIBRARY_METADATA = + LibraryMetadata.newBuilder() + .setRepository("googleapis/google-cloud-java") + .setArtifactName("google-cloud-fake") + .setVersion("1.0.0") + .build(); + private static final ApiTracerContext TRACER_CONTEXT = + ApiTracerContext.newBuilder() + .setFullMethodName(FULL_METHOD_NAME) + .setTransport(Transport.GRPC) + .setLibraryMetadata(LIBRARY_METADATA) + .setOperationType(OperationType.Unary) + .build(); + + private InMemorySpanExporter spanExporter; + private SdkTracerProvider tracerProvider; + private OpenTelemetrySdk openTelemetrySdk; + private Tracer tracer; + private ApiTracerFactory tracingFactory; + + @BeforeEach + void setUp() { + spanExporter = InMemorySpanExporter.create(); + tracerProvider = + SdkTracerProvider.builder() + .addSpanProcessor(SimpleSpanProcessor.create(spanExporter)) + .build(); + openTelemetrySdk = OpenTelemetrySdk.builder().setTracerProvider(tracerProvider).build(); + tracer = openTelemetrySdk.getTracer("test-tracer"); + tracingFactory = new OpenTelemetryTracingFactory(openTelemetrySdk).withContext(TRACER_CONTEXT); + } + + @AfterEach + void tearDown() { + tracerProvider.close(); + } + + @Test + void testAttemptSpan_linkedToParentContextFromCallingThread() { + // Verifies that when an application trace parent exists, the operation span (T3) + // links to the application parent, and the attempt span (T4) links to the operation span. + Span parentSpan = tracer.spanBuilder("application-parent-operation").startSpan(); + ApiTracer apiTracer; + try (Scope scope = parentSpan.makeCurrent()) { + apiTracer = tracingFactory.newTracer(BaseApiTracer.getInstance(), TRACER_CONTEXT); + } + + apiTracer.attemptStarted(new Object(), 0); + apiTracer.attemptSucceeded(); + apiTracer.operationSucceeded(); + parentSpan.end(); + + List finishedSpans = spanExporter.getFinishedSpanItems(); + assertThat(finishedSpans).hasSize(3); // root, operation, attempt + + SpanData attemptSpan = + finishedSpans.stream() + .filter(s -> s.getKind() == SpanKind.CLIENT) + .findFirst() + .orElseThrow(() -> new AssertionError("Attempt span not found")); + SpanData operationSpan = + finishedSpans.stream() + .filter(s -> s.getKind() == SpanKind.INTERNAL) + .findFirst() + .orElseThrow(() -> new AssertionError("Operation span not found")); + SpanData rootSpan = + finishedSpans.stream() + .filter(s -> s.getName().equals("application-parent-operation")) + .findFirst() + .orElseThrow(() -> new AssertionError("Parent span not found")); + + assertThat(attemptSpan.getKind()).isEqualTo(SpanKind.CLIENT); + assertThat(attemptSpan.getParentSpanId()).isEqualTo(operationSpan.getSpanContext().getSpanId()); + assertThat(operationSpan.getParentSpanId()).isEqualTo(rootSpan.getSpanContext().getSpanId()); + assertThat(attemptSpan.getSpanContext().getTraceId()) + .isEqualTo(rootSpan.getSpanContext().getTraceId()); + assertThat(operationSpan.getSpanContext().getTraceId()) + .isEqualTo(rootSpan.getSpanContext().getTraceId()); + } + + @Test + void testAttemptSpan_withoutParentContext_hasNoParent() { + // Verifies that without an external parent context, the operation span acts as root + // and the attempt span is a child of the operation span. + ApiTracer apiTracer = tracingFactory.newTracer(BaseApiTracer.getInstance(), TRACER_CONTEXT); + + apiTracer.attemptStarted(new Object(), 0); + apiTracer.attemptSucceeded(); + apiTracer.operationSucceeded(); + + List finishedSpans = spanExporter.getFinishedSpanItems(); + assertThat(finishedSpans).hasSize(2); // operation, attempt + + SpanData attemptSpan = + finishedSpans.stream() + .filter(s -> s.getKind() == SpanKind.CLIENT) + .findFirst() + .orElseThrow(() -> new AssertionError("Attempt span not found")); + SpanData operationSpan = + finishedSpans.stream() + .filter(s -> s.getKind() == SpanKind.INTERNAL) + .findFirst() + .orElseThrow(() -> new AssertionError("Operation span not found")); + + assertThat(operationSpan.getParentSpanContext().isValid()).isFalse(); + assertThat(attemptSpan.getParentSpanId()).isEqualTo(operationSpan.getSpanContext().getSpanId()); + } + + @Test + void testSequentialAttempts_closesPreviousAttemptSpanAndLinksAllToParent() { + Span parentSpan = tracer.spanBuilder("application-parent-operation").startSpan(); + ApiTracer apiTracer; + try (Scope scope = parentSpan.makeCurrent()) { + apiTracer = tracingFactory.newTracer(BaseApiTracer.getInstance(), TRACER_CONTEXT); + } + + // Start attempt 0 (e.g. transient failure without explicit endAttempt before retry) + apiTracer.attemptStarted(new Object(), 0); + + // Start attempt 1 - should automatically end attempt 0 + apiTracer.attemptStarted(new Object(), 1); + assertThat(spanExporter.getFinishedSpanItems()).hasSize(1); + SpanData attempt0Span = spanExporter.getFinishedSpanItems().get(0); + + // Complete attempt 1 and operation + apiTracer.attemptSucceeded(); + apiTracer.operationSucceeded(); + parentSpan.end(); + + List finishedSpans = spanExporter.getFinishedSpanItems(); + assertThat(finishedSpans).hasSize(4); // attempt 0, attempt 1, operation, parent + + SpanData operationSpan = + finishedSpans.stream() + .filter(s -> s.getKind() == SpanKind.INTERNAL) + .findFirst() + .orElseThrow(() -> new AssertionError("Operation span not found")); + + assertThat(attempt0Span.getParentSpanId()) + .isEqualTo(operationSpan.getSpanContext().getSpanId()); + + SpanData attempt1Span = + finishedSpans.stream() + .filter( + s -> + s.getKind() == SpanKind.CLIENT + && !s.getSpanContext() + .getSpanId() + .equals(attempt0Span.getSpanContext().getSpanId())) + .findFirst() + .orElseThrow(() -> new AssertionError("Attempt 1 span not found")); + + assertThat(attempt1Span.getParentSpanId()) + .isEqualTo(operationSpan.getSpanContext().getSpanId()); + assertThat(operationSpan.getParentSpanId()).isEqualTo(parentSpan.getSpanContext().getSpanId()); + assertThat(attempt1Span.getSpanContext().getTraceId()) + .isEqualTo(parentSpan.getSpanContext().getTraceId()); + } + + @Test + void testOperationFailed_endsActiveAttemptSpanWithErrorAttributes() { + // Verifies that when the operation fails permanently while an attempt is in-flight, + // both the attempt span and the operation span end with the error status and message. + Span parentSpan = tracer.spanBuilder("application-parent-operation").startSpan(); + ApiTracer apiTracer; + try (Scope scope = parentSpan.makeCurrent()) { + apiTracer = tracingFactory.newTracer(BaseApiTracer.getInstance(), TRACER_CONTEXT); + } + + apiTracer.attemptStarted(new Object(), 0); + // Operation fails while attempt was still in flight + apiTracer.operationFailed(new RuntimeException("network timeout")); + parentSpan.end(); + + List finishedSpans = spanExporter.getFinishedSpanItems(); + assertThat(finishedSpans).hasSize(3); // parent, operation, attempt + + SpanData attemptSpan = + finishedSpans.stream() + .filter(s -> s.getKind() == SpanKind.CLIENT) + .findFirst() + .orElseThrow(() -> new AssertionError("Attempt span not found")); + SpanData operationSpan = + finishedSpans.stream() + .filter(s -> s.getKind() == SpanKind.INTERNAL) + .findFirst() + .orElseThrow(() -> new AssertionError("Operation span not found")); + + assertThat(attemptSpan.getParentSpanId()).isEqualTo(operationSpan.getSpanContext().getSpanId()); + assertThat(operationSpan.getParentSpanId()).isEqualTo(parentSpan.getSpanContext().getSpanId()); + assertThat( + attemptSpan + .getAttributes() + .get(AttributeKey.stringKey(ObservabilityAttributes.STATUS_MESSAGE_ATTRIBUTE))) + .isEqualTo("network timeout"); + } + + @Test + void testAttemptStarted_afterOperationCompleted_doesNotEmitNewSpan() { + // Verifies that after operation completion, subsequent attemptStarted calls + // do not create orphan attempt spans. + ApiTracer apiTracer = tracingFactory.newTracer(BaseApiTracer.getInstance(), TRACER_CONTEXT); + + apiTracer.operationSucceeded(); + + // Any attempts started after operation completed must be ignored + apiTracer.attemptStarted(new Object(), 0); + + // Only the operation span was emitted and ended + List finishedSpans = spanExporter.getFinishedSpanItems(); + assertThat(finishedSpans).hasSize(1); + assertThat(finishedSpans.get(0).getKind()).isEqualTo(SpanKind.INTERNAL); + } + + @Test + void testRetrySucceeds_operationAggregatesSuccessAttributes() { + // Verifies that when a transient failure is retried and succeeds: + // 1. Exactly one overall INTERNAL operation span (T3) is created. + // 2. Both attempt spans (T4) have the operation span as their parent. + // 3. The operation span aggregates the successful status (OK) from the final attempt. + ApiTracer apiTracer = tracingFactory.newTracer(BaseApiTracer.getInstance(), TRACER_CONTEXT); + + // Attempt 0 fails with transient error + apiTracer.attemptStarted(new Object(), 0); + apiTracer.attemptFailedDuration(new RuntimeException("transient 503"), Duration.ofMillis(10)); + + // Attempt 1 succeeds + apiTracer.attemptStarted(new Object(), 1); + apiTracer.attemptSucceeded(); + apiTracer.operationSucceeded(); + + SpanData operationSpan = + verifySpanHierarchyAndGetOperationSpan(spanExporter.getFinishedSpanItems()); + + assertThat(operationSpan.getStatus().getStatusCode()) + .isEqualTo(io.opentelemetry.api.trace.StatusCode.UNSET); + assertThat( + operationSpan + .getAttributes() + .get(AttributeKey.stringKey(ObservabilityAttributes.RPC_RESPONSE_STATUS_ATTRIBUTE))) + .isEqualTo("OK"); + assertThat( + operationSpan + .getAttributes() + .get(AttributeKey.stringKey(ObservabilityAttributes.ERROR_TYPE_ATTRIBUTE))) + .isNull(); + } + + @Test + void testRetriesExhausted_operationAggregatesFailureAttributes() { + // Verifies that when retries are exhausted: + // 1. Exactly one overall INTERNAL operation span (T3) is created. + // 2. Both attempt spans (T4) have the operation span as their parent. + // 3. The operation span aggregates the final ERROR status and error attributes. + ApiTracer apiTracer = tracingFactory.newTracer(BaseApiTracer.getInstance(), TRACER_CONTEXT); + + // Attempt 0 fails with transient error + apiTracer.attemptStarted(new Object(), 0); + apiTracer.attemptFailedDuration(new RuntimeException("transient 503"), Duration.ofMillis(10)); + + // Attempt 1 fails and exhausts retries + apiTracer.attemptStarted(new Object(), 1); + RuntimeException finalError = new RuntimeException("unavailable: retries exhausted"); + apiTracer.attemptFailedRetriesExhausted(finalError); + apiTracer.operationFailed(finalError); + + SpanData operationSpan = + verifySpanHierarchyAndGetOperationSpan(spanExporter.getFinishedSpanItems()); + + assertThat(operationSpan.getStatus().getStatusCode()) + .isEqualTo(io.opentelemetry.api.trace.StatusCode.ERROR); + assertThat( + operationSpan + .getAttributes() + .get(AttributeKey.stringKey(ObservabilityAttributes.STATUS_MESSAGE_ATTRIBUTE))) + .isEqualTo("unavailable: retries exhausted"); + assertThat( + operationSpan + .getAttributes() + .get(AttributeKey.stringKey(ObservabilityAttributes.ERROR_TYPE_ATTRIBUTE))) + .isNotNull(); + } + + /** + * Verifies that exactly one internal operation span and two client attempt spans exist in the + * finished spans, and that each attempt span has the operation span as its parent. + * + * @param finishedSpans the list of recorded finished spans + * @return the verified operation {@link SpanData} + */ + private SpanData verifySpanHierarchyAndGetOperationSpan(List finishedSpans) { + assertThat(finishedSpans).hasSize(3); + + List internalSpans = + finishedSpans.stream() + .filter(s -> s.getKind() == SpanKind.INTERNAL) + .collect(Collectors.toList()); + assertThat(internalSpans).hasSize(1); + SpanData operationSpan = internalSpans.get(0); + + List attemptSpans = + finishedSpans.stream() + .filter(s -> s.getKind() == SpanKind.CLIENT) + .collect(Collectors.toList()); + assertThat(attemptSpans).hasSize(2); + + for (SpanData attempt : attemptSpans) { + assertThat(attempt.getParentSpanId()).isEqualTo(operationSpan.getSpanContext().getSpanId()); + } + return operationSpan; + } +} diff --git a/sdk-platform-java/gax-java/gax/src/test/java/com/google/api/gax/tracing/OpenTelemetryTracingTracerTest.java b/sdk-platform-java/gax-java/gax/src/test/java/com/google/api/gax/tracing/OpenTelemetryTracingTracerTest.java index 33fa2efcc0da..6d1659ee0c71 100644 --- a/sdk-platform-java/gax-java/gax/src/test/java/com/google/api/gax/tracing/OpenTelemetryTracingTracerTest.java +++ b/sdk-platform-java/gax-java/gax/src/test/java/com/google/api/gax/tracing/OpenTelemetryTracingTracerTest.java @@ -30,9 +30,12 @@ package com.google.api.gax.tracing; import static com.google.common.truth.Truth.assertThat; +import static io.opentelemetry.api.trace.StatusCode.ERROR; import static org.mockito.ArgumentMatchers.any; import static org.mockito.ArgumentMatchers.anyString; import static org.mockito.ArgumentMatchers.eq; +import static org.mockito.Mockito.lenient; +import static org.mockito.Mockito.mock; import static org.mockito.Mockito.never; import static org.mockito.Mockito.verify; import static org.mockito.Mockito.when; @@ -51,6 +54,7 @@ import io.opentelemetry.api.trace.Tracer; import java.net.ConnectException; import java.net.SocketTimeoutException; +import java.util.HashMap; import java.util.Map; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; @@ -64,15 +68,32 @@ class OpenTelemetryTracingTracerTest { @Mock private Tracer tracer; @Mock private SpanBuilder spanBuilder; @Mock private Span span; + @Mock private SpanBuilder operationSpanBuilder; + @Mock private Span operationSpan; private OpenTelemetryTracingTracer openTelemetryTracingTracer; private static final String ATTEMPT_SPAN_NAME = "Service/Method/attempt"; @BeforeEach void setUp() { - when(tracer.spanBuilder(anyString())).thenReturn(spanBuilder); - when(spanBuilder.setSpanKind(any(SpanKind.class))).thenReturn(spanBuilder); - when(spanBuilder.setAllAttributes(any(Attributes.class))).thenReturn(spanBuilder); - when(spanBuilder.startSpan()).thenReturn(span); + lenient().when(tracer.spanBuilder(anyString())).thenReturn(spanBuilder); + lenient().when(spanBuilder.setSpanKind(any(SpanKind.class))).thenReturn(spanBuilder); + lenient().when(spanBuilder.setParent(any())).thenReturn(spanBuilder); + lenient().when(spanBuilder.setAllAttributes(any(Attributes.class))).thenReturn(spanBuilder); + lenient().when(spanBuilder.startSpan()).thenReturn(span); + + lenient() + .when(operationSpanBuilder.setSpanKind(any(SpanKind.class))) + .thenReturn(operationSpanBuilder); + lenient().when(operationSpanBuilder.setParent(any())).thenReturn(operationSpanBuilder); + lenient() + .when(operationSpanBuilder.setAllAttributes(any(Attributes.class))) + .thenReturn(operationSpanBuilder); + lenient().when(operationSpanBuilder.startSpan()).thenReturn(operationSpan); + lenient() + .when(operationSpan.storeInContext(any(io.opentelemetry.context.Context.class))) + .thenAnswer(invocation -> invocation.getArgument(0)); + lenient().when(tracer.spanBuilder("Service/Method")).thenReturn(operationSpanBuilder); + openTelemetryTracingTracer = new OpenTelemetryTracingTracer(tracer, ApiTracerContext.empty(), ATTEMPT_SPAN_NAME); } @@ -680,4 +701,128 @@ void testInjectTraceContext_addsHeaders() { assertThat(carrier.get("traceparent")).contains("00000000000000000000000000000001"); assertThat(carrier.get("traceparent")).contains("0000000000000002"); } + + @Test + void testAttemptStarted_setsParentToParentContext() { + openTelemetryTracingTracer.attemptStarted(new Object(), 1); + verify(spanBuilder).setParent(any(io.opentelemetry.context.Context.class)); + } + + @Test + void testOperationSucceeded_endsActiveAttemptSpan() { + openTelemetryTracingTracer.attemptStarted(new Object(), 1); + openTelemetryTracingTracer.operationSucceeded(); + + verify(span).end(); + verify(operationSpan).end(); + } + + @Test + void testOperationFailed_endsActiveAttemptSpanWithErrorAttributes() { + openTelemetryTracingTracer.attemptStarted(new Object(), 1); + openTelemetryTracingTracer.operationFailed(new RuntimeException("operation failed")); + + verify(span).setAttribute(ObservabilityAttributes.STATUS_MESSAGE_ATTRIBUTE, "operation failed"); + verify(span).end(); + verify(operationSpan).setStatus(ERROR); + verify(operationSpan).end(); + } + + @Test + void testOperationCancelled_endsActiveAttemptSpanWithCancellation() { + openTelemetryTracingTracer.attemptStarted(new Object(), 1); + openTelemetryTracingTracer.operationCancelled(); + + ArgumentCaptor attrsCaptor = ArgumentCaptor.forClass(Attributes.class); + verify(span).setAllAttributes(attrsCaptor.capture()); + verify(span).end(); + verify(operationSpan).setStatus(ERROR); + verify(operationSpan).end(); + + assertThat(attrsCaptor.getValue().asMap()) + .containsEntry( + AttributeKey.stringKey(ObservabilityAttributes.RPC_RESPONSE_STATUS_ATTRIBUTE), + "CANCELLED"); + } + + @Test + void testInScope_withAttemptSpan() { + // Verifies that inScope() activates the current attempt span if an attempt is currently active. + io.opentelemetry.context.Scope mockScope = mock(io.opentelemetry.context.Scope.class); + when(span.makeCurrent()).thenReturn(mockScope); + + openTelemetryTracingTracer.attemptStarted(new Object(), 1); + try (ApiTracer.Scope scope = openTelemetryTracingTracer.inScope()) { + verify(span).makeCurrent(); + } + verify(mockScope).close(); + } + + @Test + void testInScope_withOperationSpanFallback() { + // Verifies that inScope() falls back to activating the operation span when no attempt span is + // active. + io.opentelemetry.context.Scope mockScope = mock(io.opentelemetry.context.Scope.class); + when(operationSpan.makeCurrent()).thenReturn(mockScope); + + try (ApiTracer.Scope scope = openTelemetryTracingTracer.inScope()) { + verify(operationSpan).makeCurrent(); + } + verify(mockScope).close(); + } + + @Test + void testInjectTraceContext_withOperationSpanFallback() { + // Verifies that injectTraceContext() injects the operation span context into the carrier + // when between attempts so that context propagation doesn't drop trace state. + io.opentelemetry.api.trace.SpanContext mockSpanContext = + io.opentelemetry.api.trace.SpanContext.create( + "00000000000000000000000000000003", + "0000000000000004", + io.opentelemetry.api.trace.TraceFlags.getSampled(), + io.opentelemetry.api.trace.TraceState.getDefault()); + Span realSpan = Span.wrap(mockSpanContext); + when(operationSpanBuilder.startSpan()).thenReturn(realSpan); + + openTelemetryTracingTracer = + new OpenTelemetryTracingTracer(tracer, ApiTracerContext.empty(), ATTEMPT_SPAN_NAME); + + Map carrier = new HashMap<>(); + openTelemetryTracingTracer.injectTraceContext(carrier); + + assertThat(carrier).containsKey("traceparent"); + assertThat(carrier.get("traceparent")).contains("00000000000000000000000000000003"); + assertThat(carrier.get("traceparent")).contains("0000000000000004"); + } + + @Test + void testAttemptStarted_whenPreviousAttemptActive_closesOldSpan() { + // Verifies that starting a new retry attempt cleanly closes any lingering previous attempt + // span. + Span span1 = mock(Span.class); + Span span2 = mock(Span.class); + + when(spanBuilder.startSpan()).thenReturn(span1, span2); + + openTelemetryTracingTracer.attemptStarted(new Object(), 0); + + // Start a second attempt before the first attempt was ended + openTelemetryTracingTracer.attemptStarted(new Object(), 1); + verify(span1).end(); + verify(span2, never()).end(); + + // Now complete the second attempt + openTelemetryTracingTracer.attemptSucceeded(); + verify(span2).end(); + } + + @Test + void testAttemptStarted_afterOperationCompleted_doesNotStartNewSpan() { + // Verifies that after operation completion, late callbacks cannot spawn new attempt spans. + openTelemetryTracingTracer.operationSucceeded(); + + // Attempting to start a new attempt after operation completion should be a no-op + openTelemetryTracingTracer.attemptStarted(new Object(), 1); + verify(spanBuilder, never()).startSpan(); + } }