From 9d2421b163711e8bdca019129ff47c87534bee3d Mon Sep 17 00:00:00 2001 From: rahul2393 Date: Mon, 14 Apr 2025 10:47:38 +0530 Subject: [PATCH 1/5] =?UTF-8?q?Revert=20"Revert=20"feat:=20built=20in=20me?= =?UTF-8?q?trics=20for=20afe=20latency=20and=20connectivity=20error?= =?UTF-8?q?=E2=80=A6"?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit This reverts commit b6c9c6e1debe8a529f15fc7ea4067cddf6cfd343. --- .../clirr-ignored-differences.xml | 9 ++- .../cloud/spanner/BuiltInMetricsConstant.java | 31 ++++--- .../cloud/spanner/BuiltInMetricsRecorder.java | 46 ++++++++++- .../cloud/spanner/BuiltInMetricsTracer.java | 51 +++++++----- .../google/cloud/spanner/CompositeTracer.java | 24 ++++++ .../cloud/spanner/spi/v1/GapicSpannerRpc.java | 10 +++ .../spanner/spi/v1/HeaderInterceptor.java | 15 +++- .../spi/v1/SpannerMetadataProvider.java | 8 ++ .../spanner/AbstractNettyMockServerTest.java | 7 +- ...OpenTelemetryBuiltInMetricsTracerTest.java | 80 +++++++++++++++++-- .../spi/v1/SpannerMetadataProviderTest.java | 11 +++ 11 files changed, 245 insertions(+), 47 deletions(-) diff --git a/google-cloud-spanner/clirr-ignored-differences.xml b/google-cloud-spanner/clirr-ignored-differences.xml index d6d36b0e147..28e22e4a86c 100644 --- a/google-cloud-spanner/clirr-ignored-differences.xml +++ b/google-cloud-spanner/clirr-ignored-differences.xml @@ -758,6 +758,13 @@ boolean isEnableGRPCBuiltInMetrics() + + + 7012 + com/google/cloud/spanner/SpannerOptions$SpannerEnvironment + boolean isEnableAFEServerTiming() + + 7012 @@ -899,7 +906,7 @@ com/google/cloud/spanner/connection/Connection java.lang.String getDefaultSequenceKind() - + 7012 diff --git a/google-cloud-spanner/src/main/java/com/google/cloud/spanner/BuiltInMetricsConstant.java b/google-cloud-spanner/src/main/java/com/google/cloud/spanner/BuiltInMetricsConstant.java index 050484ae66e..2e0266cec5c 100644 --- a/google-cloud-spanner/src/main/java/com/google/cloud/spanner/BuiltInMetricsConstant.java +++ b/google-cloud-spanner/src/main/java/com/google/cloud/spanner/BuiltInMetricsConstant.java @@ -27,6 +27,7 @@ import io.opentelemetry.sdk.metrics.InstrumentType; import io.opentelemetry.sdk.metrics.View; import java.util.Collection; +import java.util.List; import java.util.Map; import java.util.Set; import java.util.stream.Collectors; @@ -39,6 +40,9 @@ public class BuiltInMetricsConstant { static final String SPANNER_METER_NAME = "spanner-java"; static final String GRPC_METER_NAME = "grpc-java"; static final String GFE_LATENCIES_NAME = "gfe_latencies"; + static final String AFE_LATENCIES_NAME = "afe_latencies"; + static final String GFE_CONNECTIVITY_ERROR_NAME = "gfe_connectivity_error_count"; + static final String AFE_CONNECTIVITY_ERROR_NAME = "afe_connectivity_error_count"; static final String OPERATION_LATENCIES_NAME = "operation_latencies"; static final String ATTEMPT_LATENCIES_NAME = "attempt_latencies"; static final String OPERATION_LATENCY_NAME = "operation_latency"; @@ -52,7 +56,10 @@ public class BuiltInMetricsConstant { ATTEMPT_LATENCIES_NAME, OPERATION_COUNT_NAME, ATTEMPT_COUNT_NAME, - GFE_LATENCIES_NAME) + GFE_LATENCIES_NAME, + AFE_LATENCIES_NAME, + GFE_CONNECTIVITY_ERROR_NAME, + AFE_CONNECTIVITY_ERROR_NAME) .stream() .map(m -> METER_NAME + '/' + m) .collect(Collectors.toSet()); @@ -110,14 +117,14 @@ public class BuiltInMetricsConstant { static final Set GRPC_LB_RLS_ATTRIBUTES = ImmutableSet.of("grpc.lb.rls.data_plane_target", "grpc.lb.pick_result"); + static List BUCKET_BOUNDARIES = + ImmutableList.of( + 0.0, 0.5, 1.0, 2.0, 3.0, 4.0, 5.0, 6.0, 7.0, 8.0, 9.0, 10.0, 11.0, 12.0, 13.0, 14.0, 15.0, + 16.0, 17.0, 18.0, 19.0, 20.0, 25.0, 30.0, 40.0, 50.0, 65.0, 80.0, 100.0, 130.0, 160.0, + 200.0, 250.0, 300.0, 400.0, 500.0, 650.0, 800.0, 1000.0, 2000.0, 5000.0, 10000.0, 20000.0, + 50000.0, 100000.0, 200000.0, 400000.0, 800000.0, 1600000.0, 3200000.0); static Aggregation AGGREGATION_WITH_MILLIS_HISTOGRAM = - Aggregation.explicitBucketHistogram( - ImmutableList.of( - 0.0, 0.5, 1.0, 2.0, 3.0, 4.0, 5.0, 6.0, 7.0, 8.0, 9.0, 10.0, 11.0, 12.0, 13.0, 14.0, - 15.0, 16.0, 17.0, 18.0, 19.0, 20.0, 25.0, 30.0, 40.0, 50.0, 65.0, 80.0, 100.0, 130.0, - 160.0, 200.0, 250.0, 300.0, 400.0, 500.0, 650.0, 800.0, 1000.0, 2000.0, 5000.0, - 10000.0, 20000.0, 50000.0, 100000.0, 200000.0, 400000.0, 800000.0, 1600000.0, - 3200000.0)); + Aggregation.explicitBucketHistogram(BUCKET_BOUNDARIES); static final Collection GRPC_METRICS_ENABLED_BY_DEFAULT = ImmutableList.of( @@ -145,14 +152,6 @@ static Map getAllViews() { BuiltInMetricsConstant.AGGREGATION_WITH_MILLIS_HISTOGRAM, InstrumentType.HISTOGRAM, "ms"); - defineView( - views, - BuiltInMetricsConstant.SPANNER_METER_NAME, - BuiltInMetricsConstant.GFE_LATENCIES_NAME, - BuiltInMetricsConstant.GFE_LATENCIES_NAME, - BuiltInMetricsConstant.AGGREGATION_WITH_MILLIS_HISTOGRAM, - InstrumentType.HISTOGRAM, - "ms"); defineView( views, BuiltInMetricsConstant.GAX_METER_NAME, diff --git a/google-cloud-spanner/src/main/java/com/google/cloud/spanner/BuiltInMetricsRecorder.java b/google-cloud-spanner/src/main/java/com/google/cloud/spanner/BuiltInMetricsRecorder.java index a12da470b61..0229bb02dcf 100644 --- a/google-cloud-spanner/src/main/java/com/google/cloud/spanner/BuiltInMetricsRecorder.java +++ b/google-cloud-spanner/src/main/java/com/google/cloud/spanner/BuiltInMetricsRecorder.java @@ -23,6 +23,7 @@ import io.opentelemetry.api.common.Attributes; import io.opentelemetry.api.common.AttributesBuilder; import io.opentelemetry.api.metrics.DoubleHistogram; +import io.opentelemetry.api.metrics.LongCounter; import io.opentelemetry.api.metrics.Meter; import java.util.Map; @@ -35,6 +36,9 @@ class BuiltInMetricsRecorder extends OpenTelemetryMetricsRecorder { private final DoubleHistogram gfeLatencyRecorder; + private final DoubleHistogram afeLatencyRecorder; + private final LongCounter gfeHeaderMissingCountRecorder; + private final LongCounter afeHeaderMissingCountRecorder; /** * Creates the following instruments for the following metrics: @@ -59,6 +63,27 @@ class BuiltInMetricsRecorder extends OpenTelemetryMetricsRecorder { .setDescription( "Latency between Google's network receiving an RPC and reading back the first byte of the response") .setUnit("ms") + .setExplicitBucketBoundariesAdvice(BuiltInMetricsConstant.BUCKET_BOUNDARIES) + .build(); + this.afeLatencyRecorder = + meter + .histogramBuilder(serviceName + '/' + BuiltInMetricsConstant.AFE_LATENCIES_NAME) + .setDescription( + "Latency between Spanner API Frontend receiving an RPC and starting to write back the response.") + .setExplicitBucketBoundariesAdvice(BuiltInMetricsConstant.BUCKET_BOUNDARIES) + .setUnit("ms") + .build(); + this.gfeHeaderMissingCountRecorder = + meter + .counterBuilder(serviceName + '/' + BuiltInMetricsConstant.GFE_CONNECTIVITY_ERROR_NAME) + .setDescription("Number of requests that failed to reach the Google network.") + .setUnit("1") + .build(); + this.afeHeaderMissingCountRecorder = + meter + .counterBuilder(serviceName + '/' + BuiltInMetricsConstant.AFE_CONNECTIVITY_ERROR_NAME) + .setDescription("Number of requests that failed to reach the Spanner API Frontend.") + .setUnit("1") .build(); } @@ -69,8 +94,25 @@ class BuiltInMetricsRecorder extends OpenTelemetryMetricsRecorder { * @param gfeLatency Attempt Latency in ms * @param attributes Map of the attributes to store */ - void recordGFELatency(double gfeLatency, Map attributes) { - gfeLatencyRecorder.record(gfeLatency, toOtelAttributes(attributes)); + void recordServerTimingHeaderMetrics( + Long gfeLatency, + Long afeLatency, + Long gfeHeaderMissingCount, + Long afeHeaderMissingCount, + Map attributes) { + io.opentelemetry.api.common.Attributes otelAttributes = toOtelAttributes(attributes); + if (gfeLatency != null) { + gfeLatencyRecorder.record(gfeLatency, otelAttributes); + } + if (gfeHeaderMissingCount > 0) { + gfeHeaderMissingCountRecorder.add(gfeHeaderMissingCount, otelAttributes); + } + if (afeLatency != null) { + afeLatencyRecorder.record(afeLatency, otelAttributes); + } + if (afeHeaderMissingCount > 0) { + afeHeaderMissingCountRecorder.add(afeHeaderMissingCount, otelAttributes); + } } Attributes toOtelAttributes(Map attributes) { diff --git a/google-cloud-spanner/src/main/java/com/google/cloud/spanner/BuiltInMetricsTracer.java b/google-cloud-spanner/src/main/java/com/google/cloud/spanner/BuiltInMetricsTracer.java index 6faff5ad6d7..79b80b20797 100644 --- a/google-cloud-spanner/src/main/java/com/google/cloud/spanner/BuiltInMetricsTracer.java +++ b/google-cloud-spanner/src/main/java/com/google/cloud/spanner/BuiltInMetricsTracer.java @@ -37,8 +37,10 @@ class BuiltInMetricsTracer extends MetricsTracer implements ApiTracer { private final BuiltInMetricsRecorder builtInOpenTelemetryMetricsRecorder; // These are RPC specific attributes and pertain to a specific API Trace private final Map attributes = new HashMap<>(); - private Long gfeLatency = null; + private Long afeLatency = null; + private long gfeHeaderMissingCount = 0; + private long afeHeaderMissingCount = 0; BuiltInMetricsTracer( MethodName methodName, BuiltInMetricsRecorder builtInOpenTelemetryMetricsRecorder) { @@ -54,10 +56,9 @@ class BuiltInMetricsTracer extends MetricsTracer implements ApiTracer { @Override public void attemptSucceeded() { super.attemptSucceeded(); - if (gfeLatency != null) { - attributes.put(STATUS_ATTRIBUTE, StatusCode.Code.OK.toString()); - builtInOpenTelemetryMetricsRecorder.recordGFELatency(gfeLatency, attributes); - } + attributes.put(STATUS_ATTRIBUTE, StatusCode.Code.OK.toString()); + builtInOpenTelemetryMetricsRecorder.recordServerTimingHeaderMetrics( + gfeLatency, afeLatency, gfeHeaderMissingCount, afeHeaderMissingCount, attributes); } /** @@ -67,10 +68,9 @@ public void attemptSucceeded() { @Override public void attemptCancelled() { super.attemptCancelled(); - if (gfeLatency != null) { - attributes.put(STATUS_ATTRIBUTE, StatusCode.Code.CANCELLED.toString()); - builtInOpenTelemetryMetricsRecorder.recordGFELatency(gfeLatency, attributes); - } + attributes.put(STATUS_ATTRIBUTE, StatusCode.Code.CANCELLED.toString()); + builtInOpenTelemetryMetricsRecorder.recordServerTimingHeaderMetrics( + gfeLatency, afeLatency, gfeHeaderMissingCount, afeHeaderMissingCount, attributes); } /** @@ -84,10 +84,9 @@ public void attemptCancelled() { @Override public void attemptFailedDuration(Throwable error, java.time.Duration delay) { super.attemptFailedDuration(error, delay); - if (gfeLatency != null) { - attributes.put(STATUS_ATTRIBUTE, extractStatus(error)); - builtInOpenTelemetryMetricsRecorder.recordGFELatency(gfeLatency, attributes); - } + attributes.put(STATUS_ATTRIBUTE, extractStatus(error)); + builtInOpenTelemetryMetricsRecorder.recordServerTimingHeaderMetrics( + gfeLatency, afeLatency, gfeHeaderMissingCount, afeHeaderMissingCount, attributes); } /** @@ -100,10 +99,9 @@ public void attemptFailedDuration(Throwable error, java.time.Duration delay) { @Override public void attemptFailedRetriesExhausted(Throwable error) { super.attemptFailedRetriesExhausted(error); - if (gfeLatency != null) { - attributes.put(STATUS_ATTRIBUTE, extractStatus(error)); - builtInOpenTelemetryMetricsRecorder.recordGFELatency(gfeLatency, attributes); - } + attributes.put(STATUS_ATTRIBUTE, extractStatus(error)); + builtInOpenTelemetryMetricsRecorder.recordServerTimingHeaderMetrics( + gfeLatency, afeLatency, gfeHeaderMissingCount, afeHeaderMissingCount, attributes); } /** @@ -116,16 +114,27 @@ public void attemptFailedRetriesExhausted(Throwable error) { @Override public void attemptPermanentFailure(Throwable error) { super.attemptPermanentFailure(error); - if (gfeLatency != null) { - attributes.put(STATUS_ATTRIBUTE, extractStatus(error)); - builtInOpenTelemetryMetricsRecorder.recordGFELatency(gfeLatency, attributes); - } + attributes.put(STATUS_ATTRIBUTE, extractStatus(error)); + builtInOpenTelemetryMetricsRecorder.recordServerTimingHeaderMetrics( + gfeLatency, afeLatency, gfeHeaderMissingCount, afeHeaderMissingCount, attributes); } void recordGFELatency(Long gfeLatency) { this.gfeLatency = gfeLatency; } + void recordAFELatency(Long afeLatency) { + this.afeLatency = afeLatency; + } + + void recordGfeHeaderMissingCount(Long value) { + this.gfeHeaderMissingCount = value; + } + + void recordAfeHeaderMissingCount(Long value) { + this.afeHeaderMissingCount = value; + } + @Override public void addAttributes(Map attributes) { super.addAttributes(attributes); diff --git a/google-cloud-spanner/src/main/java/com/google/cloud/spanner/CompositeTracer.java b/google-cloud-spanner/src/main/java/com/google/cloud/spanner/CompositeTracer.java index 5268e9046f8..afc202342d8 100644 --- a/google-cloud-spanner/src/main/java/com/google/cloud/spanner/CompositeTracer.java +++ b/google-cloud-spanner/src/main/java/com/google/cloud/spanner/CompositeTracer.java @@ -198,4 +198,28 @@ public void recordGFELatency(Long gfeLatency) { } } } + + public void recordGfeHeaderMissingCount(Long value) { + for (ApiTracer child : children) { + if (child instanceof BuiltInMetricsTracer) { + ((BuiltInMetricsTracer) child).recordGfeHeaderMissingCount(value); + } + } + } + + public void recordAFELatency(Long afeLatency) { + for (ApiTracer child : children) { + if (child instanceof BuiltInMetricsTracer) { + ((BuiltInMetricsTracer) child).recordAFELatency(afeLatency); + } + } + } + + public void recordAfeHeaderMissingCount(Long value) { + for (ApiTracer child : children) { + if (child instanceof BuiltInMetricsTracer) { + ((BuiltInMetricsTracer) child).recordAfeHeaderMissingCount(value); + } + } + } } diff --git a/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/GapicSpannerRpc.java b/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/GapicSpannerRpc.java index 2a0ac1839dd..84a2f12b8c4 100644 --- a/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/GapicSpannerRpc.java +++ b/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/GapicSpannerRpc.java @@ -689,6 +689,10 @@ private static boolean isEmulatorEnabled(SpannerOptions options, String emulator && options.getHost().endsWith(emulatorHost); } + public static boolean isEnableAFEServerTiming() { + return !Boolean.parseBoolean(System.getenv("SPANNER_DISABLE_AFE_SERVER_TIMING")); + } + private static final RetrySettings ADMIN_REQUESTS_LIMIT_EXCEEDED_RETRY_SETTINGS = RetrySettings.newBuilder() .setInitialRetryDelayDuration(Duration.ofSeconds(5L)) @@ -2043,6 +2047,12 @@ GrpcCallContext newCallContext( if (routeToLeader && leaderAwareRoutingEnabled) { context = context.withExtraHeaders(metadataProvider.newRouteToLeaderHeader()); } + if (endToEndTracingEnabled) { + context = context.withExtraHeaders(metadataProvider.newEndToEndTracingHeader()); + } + if (isEnableAFEServerTiming()) { + context = context.withExtraHeaders(metadataProvider.newAfeServerTimingHeader()); + } if (callCredentialsProvider != null) { CallCredentials callCredentials = callCredentialsProvider.getCallCredentials(); if (callCredentials != null) { diff --git a/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/HeaderInterceptor.java b/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/HeaderInterceptor.java index b972ecdcef4..a3338a8b50e 100644 --- a/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/HeaderInterceptor.java +++ b/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/HeaderInterceptor.java @@ -72,6 +72,7 @@ class HeaderInterceptor implements ClientInterceptor { private static final Metadata.Key SERVER_TIMING_HEADER_KEY = Metadata.Key.of("server-timing", Metadata.ASCII_STRING_MARSHALLER); private static final String GFE_TIMING_HEADER = "gfet4t7"; + private static final String AFE_TIMING_HEADER = "afet4t7"; private static final Metadata.Key GOOGLE_CLOUD_RESOURCE_PREFIX_KEY = Metadata.Key.of("google-cloud-resource-prefix", Metadata.ASCII_STRING_MARSHALLER); private static final Pattern SERVER_TIMING_PATTERN = @@ -174,13 +175,25 @@ private void processHeader( if (compositeTracer != null) { compositeTracer.recordGFELatency(gfeLatency); } - if (span != null) { span.setAttribute("gfe_latency", String.valueOf(gfeLatency)); } } else { measureMap.put(SPANNER_GFE_HEADER_MISSING_COUNT, 1L).record(tagContext); spannerRpcMetrics.recordGfeHeaderMissingCount(1L, attributes); + if (compositeTracer != null) { + compositeTracer.recordGfeHeaderMissingCount(1L); + } + } + + // Record AFE metrics + if (compositeTracer != null && GapicSpannerRpc.isEnableAFEServerTiming()) { + if (serverTimingMetrics.containsKey(AFE_TIMING_HEADER)) { + long afeLatency = serverTimingMetrics.get(AFE_TIMING_HEADER); + compositeTracer.recordAFELatency(afeLatency); + } else { + compositeTracer.recordAfeHeaderMissingCount(1L); + } } } catch (NumberFormatException e) { LOGGER.log(LEVEL, "Invalid server-timing object in header: {}", serverTiming); diff --git a/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/SpannerMetadataProvider.java b/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/SpannerMetadataProvider.java index 2ebc4925788..e9c74847275 100644 --- a/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/SpannerMetadataProvider.java +++ b/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/SpannerMetadataProvider.java @@ -38,6 +38,8 @@ class SpannerMetadataProvider { private final String resourceHeaderKey; private static final String ROUTE_TO_LEADER_HEADER_KEY = "x-goog-spanner-route-to-leader"; private static final String END_TO_END_TRACING_HEADER_KEY = "x-goog-spanner-end-to-end-tracing"; + private static final String AFE_SERVER_TIMING_HEADER_KEY = + "x-goog-spanner-enable-afe-server-timing"; private static final Pattern[] RESOURCE_TOKEN_PATTERNS = { Pattern.compile("^(?projects/[^/]*/instances/[^/]*/databases/[^/]*)(.*)?"), Pattern.compile("^(?projects/[^/]*/instances/[^/]*)(.*)?") @@ -47,6 +49,8 @@ class SpannerMetadataProvider { ImmutableMap.of(ROUTE_TO_LEADER_HEADER_KEY, Collections.singletonList("true")); private static final Map> END_TO_END_TRACING_HEADER_MAP = ImmutableMap.of(END_TO_END_TRACING_HEADER_KEY, Collections.singletonList("true")); + private static final Map> AFE_SERVER_TIMING_HEADER_MAP = + ImmutableMap.of(AFE_SERVER_TIMING_HEADER_KEY, Collections.singletonList("true")); private SpannerMetadataProvider(Map headers, String resourceHeaderKey) { this.resourceHeaderKey = resourceHeaderKey; @@ -96,6 +100,10 @@ Map> newEndToEndTracingHeader() { return END_TO_END_TRACING_HEADER_MAP; } + Map> newAfeServerTimingHeader() { + return AFE_SERVER_TIMING_HEADER_MAP; + } + private Map, String> constructHeadersAsMetadata( Map headers) { ImmutableMap.Builder, String> headersAsMetadataBuilder = diff --git a/google-cloud-spanner/src/test/java/com/google/cloud/spanner/AbstractNettyMockServerTest.java b/google-cloud-spanner/src/test/java/com/google/cloud/spanner/AbstractNettyMockServerTest.java index 8e8da054b08..6e8589d4a44 100644 --- a/google-cloud-spanner/src/test/java/com/google/cloud/spanner/AbstractNettyMockServerTest.java +++ b/google-cloud-spanner/src/test/java/com/google/cloud/spanner/AbstractNettyMockServerTest.java @@ -47,6 +47,9 @@ abstract class AbstractNettyMockServerTest { protected static AtomicInteger fakeServerTiming = new AtomicInteger(new Random().nextInt(1000) + 1); + protected static AtomicInteger fakeAFEServerTiming = + new AtomicInteger(new Random().nextInt(500) + 1); + protected Spanner spanner; @BeforeClass @@ -72,7 +75,9 @@ public ServerCall.Listener interceptCall( public void sendHeaders(Metadata headers) { headers.put( Metadata.Key.of("server-timing", Metadata.ASCII_STRING_MARSHALLER), - String.format("gfet4t7; dur=%d", fakeServerTiming.get())); + String.format( + "afet4t7; dur=%d, gfet4t7; dur=%d", + fakeAFEServerTiming.get(), fakeServerTiming.get())); super.sendHeaders(headers); } }, diff --git a/google-cloud-spanner/src/test/java/com/google/cloud/spanner/OpenTelemetryBuiltInMetricsTracerTest.java b/google-cloud-spanner/src/test/java/com/google/cloud/spanner/OpenTelemetryBuiltInMetricsTracerTest.java index d2db2e4bca0..326a141cb5f 100644 --- a/google-cloud-spanner/src/test/java/com/google/cloud/spanner/OpenTelemetryBuiltInMetricsTracerTest.java +++ b/google-cloud-spanner/src/test/java/com/google/cloud/spanner/OpenTelemetryBuiltInMetricsTracerTest.java @@ -38,7 +38,9 @@ import com.google.common.collect.ImmutableList; import com.google.common.collect.Range; import io.grpc.ManagedChannelBuilder; +import io.grpc.Server; import io.grpc.Status; +import io.grpc.netty.shaded.io.grpc.netty.NettyServerBuilder; import io.opentelemetry.api.OpenTelemetry; import io.opentelemetry.api.common.Attributes; import io.opentelemetry.sdk.OpenTelemetrySdk; @@ -47,6 +49,8 @@ import io.opentelemetry.sdk.metrics.data.LongPointData; import io.opentelemetry.sdk.metrics.data.MetricData; import io.opentelemetry.sdk.testing.exporter.InMemoryMetricReader; +import java.io.IOException; +import java.net.InetSocketAddress; import java.time.Duration; import java.util.Collection; import java.util.List; @@ -73,6 +77,7 @@ public class OpenTelemetryBuiltInMetricsTracerTest extends AbstractNettyMockServ private static Attributes expectedCommonBaseAttributes; private static Attributes expectedCommonRequestAttributes; + private static ApiTracerFactory metricsTracerFactory; private static final long MIN_LATENCY = 0; @@ -104,6 +109,10 @@ public static void setup() { expectedCommonRequestAttributes = Attributes.builder().put(BuiltInMetricsConstant.DIRECT_PATH_USED_KEY, "false").build(); + metricsTracerFactory = + new BuiltInMetricsTracerFactory( + new BuiltInMetricsRecorder(openTelemetry, BuiltInMetricsConstant.METER_NAME), + attributes); } @BeforeClass @@ -116,16 +125,12 @@ public static void setupResults() { @After public void clearRequests() { mockSpanner.clearRequests(); + metricReader.forceFlush(); } @Override public void createSpannerInstance() { SpannerOptions.Builder builder = SpannerOptions.newBuilder(); - - ApiTracerFactory metricsTracerFactory = - new BuiltInMetricsTracerFactory( - new BuiltInMetricsRecorder(openTelemetry, BuiltInMetricsConstant.METER_NAME), - attributes); // Set a quick polling algorithm to prevent this from slowing down the test unnecessarily. builder .getDatabaseAdminStubSettingsBuilder() @@ -203,6 +208,19 @@ public void testMetricsSingleUseQuery() { getMetricData(metricReader, BuiltInMetricsConstant.GFE_LATENCIES_NAME); long gfeLatencyValue = getAggregatedValue(gfeLatencyMetricData, expectedAttributes); assertEquals(fakeServerTiming.get(), gfeLatencyValue, 0); + + MetricData afeLatencyMetricData = + getMetricData(metricReader, BuiltInMetricsConstant.AFE_LATENCIES_NAME); + long afeLatencyValue = getAggregatedValue(afeLatencyMetricData, expectedAttributes); + assertEquals(fakeAFEServerTiming.get(), afeLatencyValue, 0); + + MetricData gfeConnectivityMetricData = + getMetricData(metricReader, BuiltInMetricsConstant.GFE_CONNECTIVITY_ERROR_NAME); + assertThat(getAggregatedValue(gfeConnectivityMetricData, expectedAttributes)).isEqualTo(0); + + MetricData afeConnectivityMetricData = + getMetricData(metricReader, BuiltInMetricsConstant.AFE_CONNECTIVITY_ERROR_NAME); + assertThat(getAggregatedValue(afeConnectivityMetricData, expectedAttributes)).isEqualTo(0); } @Test @@ -339,6 +357,58 @@ public void testNoNetworkConnection() { 1, getAggregatedValue(attemptCountMetricData, expectedAttributesCreateSessionFailed)); } + @Test + public void testNoServerTimingHeader() throws IOException, InterruptedException { + // Create Spanner Object without headers + InetSocketAddress addressNoHeader = new InetSocketAddress("localhost", 0); + Server serverNoHeader = + NettyServerBuilder.forAddress(addressNoHeader).addService(mockSpanner).build().start(); + String endpoint = address.getHostString() + ":" + serverNoHeader.getPort(); + Spanner spannerNoHeader = + SpannerOptions.newBuilder() + .setProjectId("test-project") + .setChannelConfigurator(ManagedChannelBuilder::usePlaintext) + .setHost("http://" + endpoint) + .setCredentials(NoCredentials.getInstance()) + .setSessionPoolOption( + SessionPoolOptions.newBuilder() + .setWaitForMinSessionsDuration(Duration.ofSeconds(5L)) + .setFailOnSessionLeak() + .setSkipVerifyingBeginTransactionForMuxRW(true) + .build()) + // Setting this to false so that Spanner Options does not register Metrics Tracer + // factory again. + .setBuiltInMetricsEnabled(false) + .setApiTracerFactory(metricsTracerFactory) + .build() + .getService(); + DatabaseClient databaseClientNoHeader = + spannerNoHeader.getDatabaseClient(DatabaseId.of("test-project", "i", "d")); + + databaseClientNoHeader + .readWriteTransaction() + .run(transaction -> transaction.executeUpdate(UPDATE_RANDOM)); + + Attributes expectedAttributes = + expectedCommonBaseAttributes + .toBuilder() + .putAll(expectedCommonRequestAttributes) + .put(BuiltInMetricsConstant.STATUS_KEY, "OK") + .put(BuiltInMetricsConstant.METHOD_KEY, "Spanner.ExecuteSql") + .build(); + + MetricData gfeConnectivityMetricData = + getMetricData(metricReader, BuiltInMetricsConstant.GFE_CONNECTIVITY_ERROR_NAME); + assertThat(getAggregatedValue(gfeConnectivityMetricData, expectedAttributes)).isEqualTo(1); + + MetricData afeConnectivityMetricData = + getMetricData(metricReader, BuiltInMetricsConstant.AFE_CONNECTIVITY_ERROR_NAME); + assertThat(getAggregatedValue(afeConnectivityMetricData, expectedAttributes)).isEqualTo(1); + spannerNoHeader.close(); + serverNoHeader.shutdown(); + serverNoHeader.awaitTermination(); + } + private MetricData getMetricData(InMemoryMetricReader reader, String metricName) { String fullMetricName = BuiltInMetricsConstant.METER_NAME + "/" + metricName; Collection allMetricData; diff --git a/google-cloud-spanner/src/test/java/com/google/cloud/spanner/spi/v1/SpannerMetadataProviderTest.java b/google-cloud-spanner/src/test/java/com/google/cloud/spanner/spi/v1/SpannerMetadataProviderTest.java index c4fdd6200af..8073b11735e 100644 --- a/google-cloud-spanner/src/test/java/com/google/cloud/spanner/spi/v1/SpannerMetadataProviderTest.java +++ b/google-cloud-spanner/src/test/java/com/google/cloud/spanner/spi/v1/SpannerMetadataProviderTest.java @@ -105,6 +105,17 @@ public void testNewEndToEndTracingHeader() { assertTrue(Maps.difference(extraHeaders, expectedHeaders).areEqual()); } + @Test + public void testNewAfeServerTimingHeader() { + SpannerMetadataProvider metadataProvider = + SpannerMetadataProvider.create(ImmutableMap.of(), "header1"); + Map> extraHeaders = metadataProvider.newAfeServerTimingHeader(); + Map> expectedHeaders = + ImmutableMap.>of( + "x-goog-spanner-enable-afe-server-timing", ImmutableList.of("true")); + assertTrue(Maps.difference(extraHeaders, expectedHeaders).areEqual()); + } + private String getResourceHeaderValue( SpannerMetadataProvider headerProvider, String resourceTokenTemplate) { Metadata metadata = headerProvider.newMetadata(resourceTokenTemplate, "projects/p"); From 0f9c7f8a7e2719ce104592b15092557c5c345c18 Mon Sep 17 00:00:00 2001 From: surbhigarg92 Date: Tue, 15 Apr 2025 23:11:27 +0530 Subject: [PATCH 2/5] rebase --- .../com/google/cloud/spanner/spi/v1/GapicSpannerRpc.java | 9 +++------ 1 file changed, 3 insertions(+), 6 deletions(-) diff --git a/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/GapicSpannerRpc.java b/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/GapicSpannerRpc.java index 84a2f12b8c4..dedc76c49fa 100644 --- a/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/GapicSpannerRpc.java +++ b/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/GapicSpannerRpc.java @@ -1997,6 +1997,9 @@ private GrpcCallContext createBaseCallContext() { if (endToEndTracingEnabled) { context = context.withExtraHeaders(metadataProvider.newEndToEndTracingHeader()); } + if (isEnableAFEServerTiming()) { + context = context.withExtraHeaders(metadataProvider.newAfeServerTimingHeader()); + } return context .withStreamWaitTimeoutDuration(waitTimeout) .withStreamIdleTimeoutDuration(idleTimeout); @@ -2047,12 +2050,6 @@ GrpcCallContext newCallContext( if (routeToLeader && leaderAwareRoutingEnabled) { context = context.withExtraHeaders(metadataProvider.newRouteToLeaderHeader()); } - if (endToEndTracingEnabled) { - context = context.withExtraHeaders(metadataProvider.newEndToEndTracingHeader()); - } - if (isEnableAFEServerTiming()) { - context = context.withExtraHeaders(metadataProvider.newAfeServerTimingHeader()); - } if (callCredentialsProvider != null) { CallCredentials callCredentials = callCredentialsProvider.getCallCredentials(); if (callCredentials != null) { From af74423be5106d2856e76cda68e29dce42d89f5e Mon Sep 17 00:00:00 2001 From: surbhigarg92 Date: Wed, 16 Apr 2025 10:48:06 +0530 Subject: [PATCH 3/5] review comments --- .../cloud/spanner/spi/v1/GapicSpannerRpc.java | 2 +- .../spanner/spi/v1/HeaderInterceptor.java | 2 +- .../spanner/AbstractNettyMockServerTest.java | 2 +- ...OpenTelemetryBuiltInMetricsTracerTest.java | 40 +++++++++++-------- 4 files changed, 27 insertions(+), 19 deletions(-) diff --git a/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/GapicSpannerRpc.java b/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/GapicSpannerRpc.java index dedc76c49fa..7f661c013de 100644 --- a/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/GapicSpannerRpc.java +++ b/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/GapicSpannerRpc.java @@ -690,7 +690,7 @@ private static boolean isEmulatorEnabled(SpannerOptions options, String emulator } public static boolean isEnableAFEServerTiming() { - return !Boolean.parseBoolean(System.getenv("SPANNER_DISABLE_AFE_SERVER_TIMING")); + return "false".equalsIgnoreCase(System.getenv("SPANNER_DISABLE_AFE_SERVER_TIMING")); } private static final RetrySettings ADMIN_REQUESTS_LIMIT_EXCEEDED_RETRY_SETTINGS = diff --git a/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/HeaderInterceptor.java b/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/HeaderInterceptor.java index a3338a8b50e..0f132593565 100644 --- a/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/HeaderInterceptor.java +++ b/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/HeaderInterceptor.java @@ -72,7 +72,7 @@ class HeaderInterceptor implements ClientInterceptor { private static final Metadata.Key SERVER_TIMING_HEADER_KEY = Metadata.Key.of("server-timing", Metadata.ASCII_STRING_MARSHALLER); private static final String GFE_TIMING_HEADER = "gfet4t7"; - private static final String AFE_TIMING_HEADER = "afet4t7"; + private static final String AFE_TIMING_HEADER = "afe"; private static final Metadata.Key GOOGLE_CLOUD_RESOURCE_PREFIX_KEY = Metadata.Key.of("google-cloud-resource-prefix", Metadata.ASCII_STRING_MARSHALLER); private static final Pattern SERVER_TIMING_PATTERN = diff --git a/google-cloud-spanner/src/test/java/com/google/cloud/spanner/AbstractNettyMockServerTest.java b/google-cloud-spanner/src/test/java/com/google/cloud/spanner/AbstractNettyMockServerTest.java index 6e8589d4a44..afb550b5c6a 100644 --- a/google-cloud-spanner/src/test/java/com/google/cloud/spanner/AbstractNettyMockServerTest.java +++ b/google-cloud-spanner/src/test/java/com/google/cloud/spanner/AbstractNettyMockServerTest.java @@ -76,7 +76,7 @@ public void sendHeaders(Metadata headers) { headers.put( Metadata.Key.of("server-timing", Metadata.ASCII_STRING_MARSHALLER), String.format( - "afet4t7; dur=%d, gfet4t7; dur=%d", + "afe; dur=%d, gfet4t7; dur=%d", fakeAFEServerTiming.get(), fakeServerTiming.get())); super.sendHeaders(headers); } diff --git a/google-cloud-spanner/src/test/java/com/google/cloud/spanner/OpenTelemetryBuiltInMetricsTracerTest.java b/google-cloud-spanner/src/test/java/com/google/cloud/spanner/OpenTelemetryBuiltInMetricsTracerTest.java index 326a141cb5f..18c027b1c2d 100644 --- a/google-cloud-spanner/src/test/java/com/google/cloud/spanner/OpenTelemetryBuiltInMetricsTracerTest.java +++ b/google-cloud-spanner/src/test/java/com/google/cloud/spanner/OpenTelemetryBuiltInMetricsTracerTest.java @@ -209,18 +209,8 @@ public void testMetricsSingleUseQuery() { long gfeLatencyValue = getAggregatedValue(gfeLatencyMetricData, expectedAttributes); assertEquals(fakeServerTiming.get(), gfeLatencyValue, 0); - MetricData afeLatencyMetricData = - getMetricData(metricReader, BuiltInMetricsConstant.AFE_LATENCIES_NAME); - long afeLatencyValue = getAggregatedValue(afeLatencyMetricData, expectedAttributes); - assertEquals(fakeAFEServerTiming.get(), afeLatencyValue, 0); - - MetricData gfeConnectivityMetricData = - getMetricData(metricReader, BuiltInMetricsConstant.GFE_CONNECTIVITY_ERROR_NAME); - assertThat(getAggregatedValue(gfeConnectivityMetricData, expectedAttributes)).isEqualTo(0); - - MetricData afeConnectivityMetricData = - getMetricData(metricReader, BuiltInMetricsConstant.AFE_CONNECTIVITY_ERROR_NAME); - assertThat(getAggregatedValue(afeConnectivityMetricData, expectedAttributes)).isEqualTo(0); + assertFalse(checkIfMetricExists(metricReader, BuiltInMetricsConstant.AFE_LATENCIES_NAME)); + assertFalse(checkIfMetricExists(metricReader, BuiltInMetricsConstant.AFE_CONNECTIVITY_ERROR_NAME)); } @Test @@ -400,10 +390,7 @@ public void testNoServerTimingHeader() throws IOException, InterruptedException MetricData gfeConnectivityMetricData = getMetricData(metricReader, BuiltInMetricsConstant.GFE_CONNECTIVITY_ERROR_NAME); assertThat(getAggregatedValue(gfeConnectivityMetricData, expectedAttributes)).isEqualTo(1); - - MetricData afeConnectivityMetricData = - getMetricData(metricReader, BuiltInMetricsConstant.AFE_CONNECTIVITY_ERROR_NAME); - assertThat(getAggregatedValue(afeConnectivityMetricData, expectedAttributes)).isEqualTo(1); + assertFalse(checkIfMetricExists(metricReader, BuiltInMetricsConstant.AFE_CONNECTIVITY_ERROR_NAME)); spannerNoHeader.close(); serverNoHeader.shutdown(); serverNoHeader.awaitTermination(); @@ -442,6 +429,27 @@ private MetricData getMetricData(InMemoryMetricReader reader, String metricName) return null; } + private boolean checkIfMetricExists(InMemoryMetricReader reader, String metricName) { + String fullMetricName = BuiltInMetricsConstant.METER_NAME + "/" + metricName; + + for (int attemptsLeft = 1000; attemptsLeft > 0; attemptsLeft--) { + boolean exists = reader.collectAllMetrics().stream() + .anyMatch(md -> md.getName().equals(fullMetricName)); + if (exists) { + return true; + } + try { + Thread.sleep(1); + } catch (InterruptedException e) { + Thread.currentThread().interrupt(); + throw new RuntimeException(e); + } + } + + return false; + } + + private long getAggregatedValue(MetricData metricData, Attributes attributes) { switch (metricData.getType()) { case HISTOGRAM: From 0bf8f4c71710c20380afd155e17f2dbac078b637 Mon Sep 17 00:00:00 2001 From: cloud-java-bot Date: Wed, 16 Apr 2025 05:20:56 +0000 Subject: [PATCH 4/5] chore: generate libraries at Wed Apr 16 05:18:36 UTC 2025 --- .../OpenTelemetryBuiltInMetricsTracerTest.java | 11 ++++++----- 1 file changed, 6 insertions(+), 5 deletions(-) diff --git a/google-cloud-spanner/src/test/java/com/google/cloud/spanner/OpenTelemetryBuiltInMetricsTracerTest.java b/google-cloud-spanner/src/test/java/com/google/cloud/spanner/OpenTelemetryBuiltInMetricsTracerTest.java index 18c027b1c2d..a56832da22d 100644 --- a/google-cloud-spanner/src/test/java/com/google/cloud/spanner/OpenTelemetryBuiltInMetricsTracerTest.java +++ b/google-cloud-spanner/src/test/java/com/google/cloud/spanner/OpenTelemetryBuiltInMetricsTracerTest.java @@ -210,7 +210,8 @@ public void testMetricsSingleUseQuery() { assertEquals(fakeServerTiming.get(), gfeLatencyValue, 0); assertFalse(checkIfMetricExists(metricReader, BuiltInMetricsConstant.AFE_LATENCIES_NAME)); - assertFalse(checkIfMetricExists(metricReader, BuiltInMetricsConstant.AFE_CONNECTIVITY_ERROR_NAME)); + assertFalse( + checkIfMetricExists(metricReader, BuiltInMetricsConstant.AFE_CONNECTIVITY_ERROR_NAME)); } @Test @@ -390,7 +391,8 @@ public void testNoServerTimingHeader() throws IOException, InterruptedException MetricData gfeConnectivityMetricData = getMetricData(metricReader, BuiltInMetricsConstant.GFE_CONNECTIVITY_ERROR_NAME); assertThat(getAggregatedValue(gfeConnectivityMetricData, expectedAttributes)).isEqualTo(1); - assertFalse(checkIfMetricExists(metricReader, BuiltInMetricsConstant.AFE_CONNECTIVITY_ERROR_NAME)); + assertFalse( + checkIfMetricExists(metricReader, BuiltInMetricsConstant.AFE_CONNECTIVITY_ERROR_NAME)); spannerNoHeader.close(); serverNoHeader.shutdown(); serverNoHeader.awaitTermination(); @@ -433,8 +435,8 @@ private boolean checkIfMetricExists(InMemoryMetricReader reader, String metricNa String fullMetricName = BuiltInMetricsConstant.METER_NAME + "/" + metricName; for (int attemptsLeft = 1000; attemptsLeft > 0; attemptsLeft--) { - boolean exists = reader.collectAllMetrics().stream() - .anyMatch(md -> md.getName().equals(fullMetricName)); + boolean exists = + reader.collectAllMetrics().stream().anyMatch(md -> md.getName().equals(fullMetricName)); if (exists) { return true; } @@ -449,7 +451,6 @@ private boolean checkIfMetricExists(InMemoryMetricReader reader, String metricNa return false; } - private long getAggregatedValue(MetricData metricData, Attributes attributes) { switch (metricData.getType()) { case HISTOGRAM: From 128d3253436b5a4aa72b2127f28329d6a59829ad Mon Sep 17 00:00:00 2001 From: surbhigarg92 Date: Tue, 22 Apr 2025 15:14:07 +0530 Subject: [PATCH 5/5] metrics test refactoring --- ...OpenTelemetryBuiltInMetricsTracerTest.java | 153 ++++++++++++------ 1 file changed, 108 insertions(+), 45 deletions(-) diff --git a/google-cloud-spanner/src/test/java/com/google/cloud/spanner/OpenTelemetryBuiltInMetricsTracerTest.java b/google-cloud-spanner/src/test/java/com/google/cloud/spanner/OpenTelemetryBuiltInMetricsTracerTest.java index a56832da22d..b26a76471d7 100644 --- a/google-cloud-spanner/src/test/java/com/google/cloud/spanner/OpenTelemetryBuiltInMetricsTracerTest.java +++ b/google-cloud-spanner/src/test/java/com/google/cloud/spanner/OpenTelemetryBuiltInMetricsTracerTest.java @@ -24,12 +24,12 @@ import static org.junit.Assert.assertThrows; import static org.junit.Assert.assertTrue; import static org.junit.Assert.fail; +import static org.junit.Assume.assumeFalse; +import static org.junit.Assume.assumeTrue; import com.google.api.gax.longrunning.OperationTimedPollAlgorithm; import com.google.api.gax.retrying.RetrySettings; import com.google.api.gax.tracing.ApiTracerFactory; -import com.google.api.gax.tracing.MetricsTracerFactory; -import com.google.api.gax.tracing.OpenTelemetryMetricsRecorder; import com.google.cloud.NoCredentials; import com.google.cloud.spanner.MockSpannerServiceImpl.SimulatedExecutionTime; import com.google.cloud.spanner.MockSpannerServiceImpl.StatementResult; @@ -50,6 +50,7 @@ import io.opentelemetry.sdk.metrics.data.MetricData; import io.opentelemetry.sdk.testing.exporter.InMemoryMetricReader; import java.io.IOException; +import java.lang.reflect.Field; import java.net.InetSocketAddress; import java.time.Duration; import java.util.Collection; @@ -65,54 +66,37 @@ @RunWith(JUnit4.class) public class OpenTelemetryBuiltInMetricsTracerTest extends AbstractNettyMockServerTest { - private static final Statement SELECT_RANDOM = Statement.of("SELECT * FROM random"); - private static final Statement UPDATE_RANDOM = Statement.of("UPDATE random SET foo=1 WHERE id=1"); private static InMemoryMetricReader metricReader; - - private static OpenTelemetry openTelemetry; - - private static Map attributes; - - private static Attributes expectedCommonBaseAttributes; - private static Attributes expectedCommonRequestAttributes; - private static ApiTracerFactory metricsTracerFactory; + private static Map attributes = + BuiltInMetricsProvider.INSTANCE.createClientAttributes(); + private static Attributes expectedCommonBaseAttributes = + Attributes.builder() + .put(BuiltInMetricsConstant.CLIENT_NAME_KEY, "spanner-java/") + .put(BuiltInMetricsConstant.CLIENT_UID_KEY, attributes.get("client_uid")) + .put(BuiltInMetricsConstant.INSTANCE_ID_KEY, "i") + .put(BuiltInMetricsConstant.DATABASE_KEY, "d") + .put(BuiltInMetricsConstant.DIRECT_PATH_ENABLED_KEY, "false") + .build();; + private static Attributes expectedCommonRequestAttributes = + Attributes.builder().put(BuiltInMetricsConstant.DIRECT_PATH_USED_KEY, "false").build();; private static final long MIN_LATENCY = 0; private DatabaseClient client; - @BeforeClass - public static void setup() { + public ApiTracerFactory createMetricsTracerFactory() { metricReader = InMemoryMetricReader.create(); - BuiltInMetricsProvider provider = BuiltInMetricsProvider.INSTANCE; - SdkMeterProviderBuilder meterProvider = SdkMeterProvider.builder().registerMetricReader(metricReader); - BuiltInMetricsConstant.getAllViews().forEach(meterProvider::registerView); + OpenTelemetry openTelemetry = + OpenTelemetrySdk.builder().setMeterProvider(meterProvider.build()).build(); - String client_name = "spanner-java/"; - openTelemetry = OpenTelemetrySdk.builder().setMeterProvider(meterProvider.build()).build(); - attributes = provider.createClientAttributes(); - - expectedCommonBaseAttributes = - Attributes.builder() - .put(BuiltInMetricsConstant.CLIENT_NAME_KEY, client_name) - .put(BuiltInMetricsConstant.CLIENT_UID_KEY, attributes.get("client_uid")) - .put(BuiltInMetricsConstant.INSTANCE_ID_KEY, "i") - .put(BuiltInMetricsConstant.DATABASE_KEY, "d") - .put(BuiltInMetricsConstant.DIRECT_PATH_ENABLED_KEY, "false") - .build(); - - expectedCommonRequestAttributes = - Attributes.builder().put(BuiltInMetricsConstant.DIRECT_PATH_USED_KEY, "false").build(); - metricsTracerFactory = - new BuiltInMetricsTracerFactory( - new BuiltInMetricsRecorder(openTelemetry, BuiltInMetricsConstant.METER_NAME), - attributes); + return new BuiltInMetricsTracerFactory( + new BuiltInMetricsRecorder(openTelemetry, BuiltInMetricsConstant.METER_NAME), attributes); } @BeforeClass @@ -123,9 +107,9 @@ public static void setupResults() { } @After - public void clearRequests() { + public void clearRequests() throws IOException { mockSpanner.clearRequests(); - metricReader.forceFlush(); + metricReader.close(); } @Override @@ -159,7 +143,7 @@ public void createSpannerInstance() { // Setting this to false so that Spanner Options does not register Metrics Tracer // factory again. .setBuiltInMetricsEnabled(false) - .setApiTracerFactory(metricsTracerFactory) + .setApiTracerFactory(createMetricsTracerFactory()) .build() .getService(); client = spanner.getDatabaseClient(DatabaseId.of("test-project", "i", "d")); @@ -209,11 +193,92 @@ public void testMetricsSingleUseQuery() { long gfeLatencyValue = getAggregatedValue(gfeLatencyMetricData, expectedAttributes); assertEquals(fakeServerTiming.get(), gfeLatencyValue, 0); + assertFalse( + checkIfMetricExists(metricReader, BuiltInMetricsConstant.GFE_CONNECTIVITY_ERROR_NAME)); assertFalse(checkIfMetricExists(metricReader, BuiltInMetricsConstant.AFE_LATENCIES_NAME)); assertFalse( checkIfMetricExists(metricReader, BuiltInMetricsConstant.AFE_CONNECTIVITY_ERROR_NAME)); } + private boolean isJava8() { + return JavaVersionUtil.getJavaMajorVersion() == 8; + } + + private boolean isWindows() { + return System.getProperty("os.name").toLowerCase().contains("windows"); + } + + @Test + public void testMetricsSingleUseQueryWithAfeEnabled() throws Exception { + assumeTrue(isJava8() && !isWindows()); + assumeFalse(System.getenv().containsKey("SPANNER_DISABLE_AFE_SERVER_TIMING")); + + Class classOfMap = System.getenv().getClass(); + Field field = classOfMap.getDeclaredField("m"); + field.setAccessible(true); + Map writeableEnvironmentVariables = + (Map) field.get(System.getenv()); + + try { + writeableEnvironmentVariables.put("SPANNER_DISABLE_AFE_SERVER_TIMING", "false"); + + Stopwatch stopwatch = Stopwatch.createStarted(); + try (ResultSet resultSet = client.singleUse().executeQuery(SELECT_RANDOM)) { + assertTrue(resultSet.next()); + assertFalse(resultSet.next()); + } + + long elapsed = stopwatch.elapsed(TimeUnit.MILLISECONDS); + Attributes expectedAttributes = + expectedCommonBaseAttributes + .toBuilder() + .putAll(expectedCommonRequestAttributes) + .put(BuiltInMetricsConstant.STATUS_KEY, "OK") + .put(BuiltInMetricsConstant.METHOD_KEY, "Spanner.ExecuteStreamingSql") + .build(); + + MetricData operationLatencyMetricData = + getMetricData(metricReader, BuiltInMetricsConstant.OPERATION_LATENCIES_NAME); + assertNotNull(operationLatencyMetricData); + long operationLatencyValue = + getAggregatedValue(operationLatencyMetricData, expectedAttributes); + assertThat(operationLatencyValue).isIn(Range.closed(MIN_LATENCY, elapsed)); + + MetricData attemptLatencyMetricData = + getMetricData(metricReader, BuiltInMetricsConstant.ATTEMPT_LATENCIES_NAME); + assertNotNull(attemptLatencyMetricData); + long attemptLatencyValue = getAggregatedValue(attemptLatencyMetricData, expectedAttributes); + assertThat(attemptLatencyValue).isIn(Range.closed(MIN_LATENCY, elapsed)); + + MetricData operationCountMetricData = + getMetricData(metricReader, BuiltInMetricsConstant.OPERATION_COUNT_NAME); + assertNotNull(operationCountMetricData); + assertThat(getAggregatedValue(operationCountMetricData, expectedAttributes)).isEqualTo(1); + + MetricData attemptCountMetricData = + getMetricData(metricReader, BuiltInMetricsConstant.ATTEMPT_COUNT_NAME); + assertNotNull(attemptCountMetricData); + assertThat(getAggregatedValue(attemptCountMetricData, expectedAttributes)).isEqualTo(1); + + MetricData gfeLatencyMetricData = + getMetricData(metricReader, BuiltInMetricsConstant.GFE_LATENCIES_NAME); + long gfeLatencyValue = getAggregatedValue(gfeLatencyMetricData, expectedAttributes); + assertEquals(fakeServerTiming.get(), gfeLatencyValue, 0); + + assertFalse( + checkIfMetricExists(metricReader, BuiltInMetricsConstant.GFE_CONNECTIVITY_ERROR_NAME)); + + MetricData afeLatencyMetricData = + getMetricData(metricReader, BuiltInMetricsConstant.AFE_LATENCIES_NAME); + long afeLatencyValue = getAggregatedValue(afeLatencyMetricData, expectedAttributes); + assertEquals(fakeAFEServerTiming.get(), afeLatencyValue, 0); + assertFalse( + checkIfMetricExists(metricReader, BuiltInMetricsConstant.AFE_CONNECTIVITY_ERROR_NAME)); + } finally { + writeableEnvironmentVariables.remove("GOOGLE_CLOUD_SPANNER_MULTIPLEXED_SESSIONS"); + } + } + @Test public void testMetricsWithGaxRetryUnaryRpc() { Stopwatch stopwatch = Stopwatch.createStarted(); @@ -284,10 +349,6 @@ public void testNoNetworkConnection() { return null; }); - ApiTracerFactory metricsTracerFactory = - new MetricsTracerFactory( - new OpenTelemetryMetricsRecorder(openTelemetry, BuiltInMetricsConstant.METER_NAME), - attributes); Spanner spanner = builder .setProjectId("test-project") @@ -305,7 +366,7 @@ public void testNoNetworkConnection() { // Setting this to false so that Spanner Options does not register Metrics Tracer // factory again. .setBuiltInMetricsEnabled(false) - .setApiTracerFactory(metricsTracerFactory) + .setApiTracerFactory(createMetricsTracerFactory()) .build() .getService(); String instance = "i"; @@ -370,7 +431,7 @@ public void testNoServerTimingHeader() throws IOException, InterruptedException // Setting this to false so that Spanner Options does not register Metrics Tracer // factory again. .setBuiltInMetricsEnabled(false) - .setApiTracerFactory(metricsTracerFactory) + .setApiTracerFactory(createMetricsTracerFactory()) .build() .getService(); DatabaseClient databaseClientNoHeader = @@ -391,6 +452,8 @@ public void testNoServerTimingHeader() throws IOException, InterruptedException MetricData gfeConnectivityMetricData = getMetricData(metricReader, BuiltInMetricsConstant.GFE_CONNECTIVITY_ERROR_NAME); assertThat(getAggregatedValue(gfeConnectivityMetricData, expectedAttributes)).isEqualTo(1); + assertFalse(checkIfMetricExists(metricReader, BuiltInMetricsConstant.AFE_LATENCIES_NAME)); + assertFalse(checkIfMetricExists(metricReader, BuiltInMetricsConstant.GFE_LATENCIES_NAME)); assertFalse( checkIfMetricExists(metricReader, BuiltInMetricsConstant.AFE_CONNECTIVITY_ERROR_NAME)); spannerNoHeader.close();