feat(bigtable): backfill gfe latency with headersout-headersout latency

Author: sushanb

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;

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 =

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) {

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}

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();
+  }
 }