From bc4e1cf03b9eabd7171519df3635d81e07b4e301 Mon Sep 17 00:00:00 2001 From: Sushan Bhattarai Date: Thu, 23 Apr 2026 16:32:21 -0400 Subject: [PATCH 1/4] feat(bigtable): backfill gfe latency with headersout-headersout latency --- .../csm/tracers/BigtableGrpcStreamTracer.java | 10 +++++++ .../csm/tracers/BuiltinMetricsTracer.java | 26 +++++++++++++++++++ .../internal/csm/tracers/CompositeTracer.java | 14 ++++++++++ .../data/v2/stub/metrics/BigtableTracer.java | 10 +++++++ .../csm/tracers/CompositeTracerTest.java | 14 ++++++++++ 5 files changed, 74 insertions(+) diff --git a/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/BigtableGrpcStreamTracer.java b/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/BigtableGrpcStreamTracer.java index 99a184b5e3..5267b9ef24 100644 --- a/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/BigtableGrpcStreamTracer.java +++ b/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/BigtableGrpcStreamTracer.java @@ -36,6 +36,16 @@ public void outboundMessageSent(int seqNo, long optionalWireSize, long optionalU tracer.grpcMessageSent(); } + @Override + public void outboundHeaders() { + tracer.grpcHeadersSent(); + } + + @Override + public void inboundHeaders() { + tracer.grpcHeadersReceived(); + } + static class Factory extends ClientStreamTracer.Factory { private final BigtableTracer tracer; diff --git a/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/BuiltinMetricsTracer.java b/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/BuiltinMetricsTracer.java index 305ec53315..a49e7e4870 100644 --- a/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/BuiltinMetricsTracer.java +++ b/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/BuiltinMetricsTracer.java @@ -82,6 +82,8 @@ class BuiltinMetricsTracer extends BigtableTracer { private final AtomicLong totalClientBlockingTime = new AtomicLong(0); private final AtomicLong grpcMessageSentDelay = new AtomicLong(0); + private final AtomicLong grpcHeadersSentNanos = new AtomicLong(0); + private final AtomicLong grpcHeadersOutHeaderInLatency = new AtomicLong(0); private Deadline operationDeadline = null; private volatile Duration remainingDeadlineAtAttemptStart = Duration.ZERO; @@ -263,6 +265,18 @@ public void grpcMessageSent() { grpcMessageSentDelay.set(attemptTimer.elapsed(TimeUnit.NANOSECONDS)); } + @Override + public void grpcHeadersSent() { + grpcHeadersSentNanos.set(attemptTimer.elapsed(TimeUnit.NANOSECONDS)); + } + + @Override + public void grpcHeadersReceived() { + long receivedNanos = attemptTimer.elapsed(TimeUnit.NANOSECONDS); + long sentNanos = grpcHeadersSentNanos.get(); + grpcHeadersOutHeaderInLatency.set(receivedNanos - sentNanos); + } + @Override public void setTotalTimeoutDuration(java.time.Duration totalTimeoutDuration) { // This method is called by BigtableTracerStreamingCallable and @@ -395,6 +409,18 @@ private void recordAttemptCompletion(@Nullable Throwable throwable) { sidebandData.getClusterInfo(), code, sidebandData.getGfeTiming()); + } else { + // Fallback to header latency if GFE timing is not available + long fallbackLatencyNanos = grpcHeadersOutHeaderInLatency.get(); + if (fallbackLatencyNanos > 0) { + recorder.serverLatency.record( + clientInfo, + tableId, + methodInfo, + sidebandData.getClusterInfo(), + code, + Duration.ofNanos(fallbackLatencyNanos)); + } } boolean seenServer = diff --git a/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/CompositeTracer.java b/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/CompositeTracer.java index d9362acb48..eb17ec939a 100644 --- a/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/CompositeTracer.java +++ b/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/CompositeTracer.java @@ -241,6 +241,20 @@ public void grpcMessageSent() { } } + @Override + public void grpcHeadersSent() { + for (BigtableTracer tracer : bigtableTracers) { + tracer.grpcHeadersSent(); + } + } + + @Override + public void grpcHeadersReceived() { + for (BigtableTracer tracer : bigtableTracers) { + tracer.grpcHeadersReceived(); + } + } + @Override public void setTotalTimeoutDuration(java.time.Duration totalTimeoutDuration) { for (BigtableTracer tracer : bigtableTracers) { diff --git a/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/stub/metrics/BigtableTracer.java b/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/stub/metrics/BigtableTracer.java index df27fbd842..48468eb518 100644 --- a/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/stub/metrics/BigtableTracer.java +++ b/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/stub/metrics/BigtableTracer.java @@ -89,6 +89,16 @@ public void grpcMessageSent() { // noop } + /** Called when the header is sent on a grpc channel. */ + public void grpcHeadersSent() { + // noop + } + + /** Called when the header is received on a grpc channel. */ + public void grpcHeadersReceived() { + // noop + } + /** * Record the operation timeout from user settings for calculating remaining deadline. Currently, * it's called in BuiltinMetricsTracer on attempt start from {@link BigtableTracerUnaryCallable} diff --git a/google-cloud-bigtable/src/test/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/CompositeTracerTest.java b/google-cloud-bigtable/src/test/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/CompositeTracerTest.java index c77f3e1e50..dd68618856 100644 --- a/google-cloud-bigtable/src/test/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/CompositeTracerTest.java +++ b/google-cloud-bigtable/src/test/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/CompositeTracerTest.java @@ -271,4 +271,18 @@ public void testGrpcMessageSent() { verify(child3, times(1)).grpcMessageSent(); verify(child4, times(1)).grpcMessageSent(); } + + @Test + public void testGrpcHeadersSent() { + compositeTracer.grpcHeadersSent(); + verify(child3, times(1)).grpcHeadersSent(); + verify(child4, times(1)).grpcHeadersSent(); + } + + @Test + public void testGrpcHeadersReceived() { + compositeTracer.grpcHeadersReceived(); + verify(child3, times(1)).grpcHeadersReceived(); + verify(child4, times(1)).grpcHeadersReceived(); + } } From 0399eb1e64a7ea02a1e3a02acf2cdbcd7a8f761c Mon Sep 17 00:00:00 2001 From: Sushan Bhattarai Date: Thu, 23 Apr 2026 16:53:19 -0400 Subject: [PATCH 2/4] fix --- .../data/v2/internal/csm/tracers/BuiltinMetricsTracer.java | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/BuiltinMetricsTracer.java b/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/BuiltinMetricsTracer.java index a49e7e4870..76d9d85125 100644 --- a/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/BuiltinMetricsTracer.java +++ b/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/BuiltinMetricsTracer.java @@ -400,7 +400,8 @@ private void recordAttemptCompletion(@Nullable Throwable throwable) { code, Comparators.max(remainingDeadlineAtAttemptStart, Duration.ZERO)); } - + // if we don't have t4t7 latency from gfe, we use dur between initial metadata sent and initial + // metadata recv if (sidebandData.getGfeTiming() != null) { recorder.serverLatency.record( clientInfo, From b126bedad263fbc0913f13de834c66871040dbfd Mon Sep 17 00:00:00 2001 From: Sushan Bhattarai Date: Fri, 24 Apr 2026 16:01:32 -0400 Subject: [PATCH 3/4] fix --- .../csm/tracers/BuiltinMetricsTracer.java | 29 ++++++++----------- 1 file changed, 12 insertions(+), 17 deletions(-) diff --git a/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/BuiltinMetricsTracer.java b/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/BuiltinMetricsTracer.java index 76d9d85125..063a617924 100644 --- a/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/BuiltinMetricsTracer.java +++ b/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/BuiltinMetricsTracer.java @@ -82,13 +82,12 @@ class BuiltinMetricsTracer extends BigtableTracer { private final AtomicLong totalClientBlockingTime = new AtomicLong(0); private final AtomicLong grpcMessageSentDelay = new AtomicLong(0); - private final AtomicLong grpcHeadersSentNanos = new AtomicLong(0); - private final AtomicLong grpcHeadersOutHeaderInLatency = new AtomicLong(0); private Deadline operationDeadline = null; private volatile Duration remainingDeadlineAtAttemptStart = Duration.ZERO; private volatile MetadataExtractorInterceptor.SidebandData sidebandData = new SidebandData(); + private volatile Optional faket4t7 = Optional.empty(); BuiltinMetricsTracer( MetricRegistry.RecorderRegistry recorder, ClientInfo clientInfo, MethodInfo methodInfo) { @@ -267,14 +266,12 @@ public void grpcMessageSent() { @Override public void grpcHeadersSent() { - grpcHeadersSentNanos.set(attemptTimer.elapsed(TimeUnit.NANOSECONDS)); + faket4t7 = Optional.of(Stopwatch.createStarted()); } @Override public void grpcHeadersReceived() { - long receivedNanos = attemptTimer.elapsed(TimeUnit.NANOSECONDS); - long sentNanos = grpcHeadersSentNanos.get(); - grpcHeadersOutHeaderInLatency.set(receivedNanos - sentNanos); + faket4t7.map(Stopwatch::stop); } @Override @@ -411,17 +408,15 @@ private void recordAttemptCompletion(@Nullable Throwable throwable) { code, sidebandData.getGfeTiming()); } else { - // Fallback to header latency if GFE timing is not available - long fallbackLatencyNanos = grpcHeadersOutHeaderInLatency.get(); - if (fallbackLatencyNanos > 0) { - recorder.serverLatency.record( - clientInfo, - tableId, - methodInfo, - sidebandData.getClusterInfo(), - code, - Duration.ofNanos(fallbackLatencyNanos)); - } + faket4t7.ifPresent( + stopwatch -> + recorder.serverLatency.record( + clientInfo, + tableId, + methodInfo, + sidebandData.getClusterInfo(), + code, + stopwatch.elapsed())); } boolean seenServer = From 0ac435ed23559e210353722f494d2a3562dfdfc3 Mon Sep 17 00:00:00 2001 From: Sushan Bhattarai Date: Fri, 24 Apr 2026 16:15:11 -0400 Subject: [PATCH 4/4] fix --- .../data/v2/internal/csm/tracers/BuiltinMetricsTracer.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/BuiltinMetricsTracer.java b/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/BuiltinMetricsTracer.java index 063a617924..504f960195 100644 --- a/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/BuiltinMetricsTracer.java +++ b/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/BuiltinMetricsTracer.java @@ -271,7 +271,7 @@ public void grpcHeadersSent() { @Override public void grpcHeadersReceived() { - faket4t7.map(Stopwatch::stop); + faket4t7.ifPresent(Stopwatch::stop); } @Override