fix(gax): record fractional latency metrics (#12979)

## Summary

Record GAX operation and attempt latency metrics with fractional
millisecond precision instead of truncating to whole milliseconds.

  Previously `MetricsTracer` used:

  ```java
  stopwatch.elapsed(TimeUnit.MILLISECONDS)
```

This floors sub-millisecond precision before the value is recorded into the histogram. For low-latency RPCs, this can make Cloud Monitoring percentiles look significantly lower than application-observed latency.

  For example, a Spanner customer investigation showed:

  - application/client observed P50: ~3.7ms
  - trace-measured GAX operation latency: ~3.9ms
  - exported operation_latencies P50: ~2.9ms

  The apparent ~800us P50 gap looked like extra client-side latency in Spanner, but raw metric prints showed values being recorded as whole numbers only (3.0, 4.0, 7.0). The sub-ms precision was lost before histogram bucketization, so this was a rounding/truncation artifact rather than actual Spanner client overhead.

  ## Fix

  Use nanosecond elapsed time and convert to fractional milliseconds:

  stopwatch.elapsed(TimeUnit.NANOSECONDS) / 1_000_000.0

  Applied to:

  - operation latency
  - attempt latency

Author: rahul2393

sdk-platform-java/gax-java/gax/src/main/java/com/google/api/gax/tracing/MetricsTracer.java

@@ -38,6 +38,7 @@
 import com.google.api.gax.rpc.StatusCode;
 import com.google.common.annotations.VisibleForTesting;
 import com.google.common.base.Stopwatch;
+import com.google.common.base.Ticker;
 import java.util.HashMap;
 import java.util.Map;
 import java.util.concurrent.TimeUnit;
@@ -58,18 +59,27 @@ public class MetricsTracer implements ApiTracer {
   public static final String DEFAULT_LANGUAGE = "Java";
   private static final String OPERATION_FINISHED_STATUS_MESSAGE =
       "Operation has already been completed";
+  private static final double NANOS_PER_MILLISECOND = 1_000_000.0;
   private Stopwatch attemptTimer;
-  private final Stopwatch operationTimer = Stopwatch.createStarted();
+  private final Ticker ticker;
+  private final Stopwatch operationTimer;
   // These are RPC specific attributes and pertain to a specific API Trace
   private final Map<String, String> attributes = new HashMap<>();
   private final MetricsRecorder metricsRecorder;
   private final AtomicBoolean operationFinished;
 
   public MetricsTracer(MethodName methodName, MetricsRecorder metricsRecorder) {
+    this(methodName, metricsRecorder, Ticker.systemTicker());
+  }
+
+  @VisibleForTesting
+  MetricsTracer(MethodName methodName, MetricsRecorder metricsRecorder, Ticker ticker) {
     this.attributes.put(METHOD_ATTRIBUTE, methodName.toString());
     this.attributes.put(LANGUAGE_ATTRIBUTE, DEFAULT_LANGUAGE);
     this.metricsRecorder = metricsRecorder;
     this.operationFinished = new AtomicBoolean();
+    this.ticker = ticker;
+    this.operationTimer = Stopwatch.createStarted(ticker);
   }
 
   /**
@@ -86,7 +96,7 @@ public void operationSucceeded() {
     }
     attributes.put(STATUS_ATTRIBUTE, StatusCode.Code.OK.toString());
     metricsRecorder.recordOperationLatency(
-        operationTimer.elapsed(TimeUnit.MILLISECONDS), attributes);
+        operationTimer.elapsed(TimeUnit.NANOSECONDS) / NANOS_PER_MILLISECOND, attributes);
     metricsRecorder.recordOperationCount(1, attributes);
   }
 
@@ -104,7 +114,7 @@ public void operationCancelled() {
     }
     attributes.put(STATUS_ATTRIBUTE, StatusCode.Code.CANCELLED.toString());
     metricsRecorder.recordOperationLatency(
-        operationTimer.elapsed(TimeUnit.MILLISECONDS), attributes);
+        operationTimer.elapsed(TimeUnit.NANOSECONDS) / NANOS_PER_MILLISECOND, attributes);
     metricsRecorder.recordOperationCount(1, attributes);
   }
 
@@ -123,7 +133,7 @@ public void operationFailed(Throwable error) {
     // Uses the GRPC status code representation.
     attributes.put(STATUS_ATTRIBUTE, ObservabilityUtils.extractStatus(error).toString());
     metricsRecorder.recordOperationLatency(
-        operationTimer.elapsed(TimeUnit.MILLISECONDS), attributes);
+        operationTimer.elapsed(TimeUnit.NANOSECONDS) / NANOS_PER_MILLISECOND, attributes);
     metricsRecorder.recordOperationCount(1, attributes);
   }
 
@@ -138,7 +148,7 @@ public void operationFailed(Throwable error) {
    */
   @Override
   public void attemptStarted(Object request, int attemptNumber) {
-    attemptTimer = Stopwatch.createStarted();
+    attemptTimer = Stopwatch.createStarted(ticker);
   }
 
   /**
@@ -148,7 +158,8 @@ public void attemptStarted(Object request, int attemptNumber) {
   @Override
   public void attemptSucceeded() {
     attributes.put(STATUS_ATTRIBUTE, StatusCode.Code.OK.toString());
-    metricsRecorder.recordAttemptLatency(attemptTimer.elapsed(TimeUnit.MILLISECONDS), attributes);
+    metricsRecorder.recordAttemptLatency(
+        attemptTimer.elapsed(TimeUnit.NANOSECONDS) / NANOS_PER_MILLISECOND, attributes);
     metricsRecorder.recordAttemptCount(1, attributes);
   }
 
@@ -159,7 +170,8 @@ public void attemptSucceeded() {
   @Override
   public void attemptCancelled() {
     attributes.put(STATUS_ATTRIBUTE, StatusCode.Code.CANCELLED.toString());
-    metricsRecorder.recordAttemptLatency(attemptTimer.elapsed(TimeUnit.MILLISECONDS), attributes);
+    metricsRecorder.recordAttemptLatency(
+        attemptTimer.elapsed(TimeUnit.NANOSECONDS) / NANOS_PER_MILLISECOND, attributes);
     metricsRecorder.recordAttemptCount(1, attributes);
   }
 
@@ -174,7 +186,8 @@ public void attemptCancelled() {
   @Override
   public void attemptFailedDuration(Throwable error, java.time.Duration delay) {
     attributes.put(STATUS_ATTRIBUTE, ObservabilityUtils.extractStatus(error).toString());
-    metricsRecorder.recordAttemptLatency(attemptTimer.elapsed(TimeUnit.MILLISECONDS), attributes);
+    metricsRecorder.recordAttemptLatency(
+        attemptTimer.elapsed(TimeUnit.NANOSECONDS) / NANOS_PER_MILLISECOND, attributes);
     metricsRecorder.recordAttemptCount(1, attributes);
   }
 
@@ -198,7 +211,8 @@ public void attemptFailed(Throwable error, org.threeten.bp.Duration delay) {
   @Override
   public void attemptFailedRetriesExhausted(Throwable error) {
     attributes.put(STATUS_ATTRIBUTE, ObservabilityUtils.extractStatus(error).toString());
-    metricsRecorder.recordAttemptLatency(attemptTimer.elapsed(TimeUnit.MILLISECONDS), attributes);
+    metricsRecorder.recordAttemptLatency(
+        attemptTimer.elapsed(TimeUnit.NANOSECONDS) / NANOS_PER_MILLISECOND, attributes);
     metricsRecorder.recordAttemptCount(1, attributes);
   }
 
@@ -212,7 +226,8 @@ public void attemptFailedRetriesExhausted(Throwable error) {
   @Override
   public void attemptPermanentFailure(Throwable error) {
     attributes.put(STATUS_ATTRIBUTE, ObservabilityUtils.extractStatus(error).toString());
-    metricsRecorder.recordAttemptLatency(attemptTimer.elapsed(TimeUnit.MILLISECONDS), attributes);
+    metricsRecorder.recordAttemptLatency(
+        attemptTimer.elapsed(TimeUnit.NANOSECONDS) / NANOS_PER_MILLISECOND, attributes);
     metricsRecorder.recordAttemptCount(1, attributes);
   }
 

sdk-platform-java/gax-java/gax/src/test/java/com/google/api/gax/tracing/MetricsTracerTest.java

@@ -43,8 +43,10 @@
 import com.google.api.gax.rpc.StatusCode.Code;
 import com.google.api.gax.rpc.testing.FakeStatusCode;
 import com.google.common.collect.ImmutableMap;
+import com.google.common.testing.FakeTicker;
 import java.util.HashMap;
 import java.util.Map;
+import java.util.concurrent.TimeUnit;
 import org.junit.jupiter.api.BeforeEach;
 import org.junit.jupiter.api.Test;
 import org.junit.jupiter.api.extension.ExtendWith;
@@ -86,6 +88,35 @@ void testOperationSucceeded_recordsAttributes() {
     verifyNoMoreInteractions(metricsRecorder);
   }
 
+  @Test
+  void testOperationSucceeded_recordsFractionalMilliseconds() {
+    FakeTicker ticker = new FakeTicker();
+    metricsTracer =
+        new MetricsTracer(MethodName.of("fake_service", "fake_method"), metricsRecorder, ticker);
+    ticker.advance(3_900_000, TimeUnit.NANOSECONDS);
+
+    metricsTracer.operationSucceeded();
+
+    verify(metricsRecorder).recordOperationLatency(3.9, getAttributes(Code.OK));
+    verify(metricsRecorder).recordOperationCount(1, getAttributes(Code.OK));
+    verifyNoMoreInteractions(metricsRecorder);
+  }
+
+  @Test
+  void testAttemptSucceeded_recordsFractionalMilliseconds() {
+    FakeTicker ticker = new FakeTicker();
+    metricsTracer =
+        new MetricsTracer(MethodName.of("fake_service", "fake_method"), metricsRecorder, ticker);
+    metricsTracer.attemptStarted(new Object(), 0);
+    ticker.advance(4_200_000, TimeUnit.NANOSECONDS);
+
+    metricsTracer.attemptSucceeded();
+
+    verify(metricsRecorder).recordAttemptLatency(4.2, getAttributes(Code.OK));
+    verify(metricsRecorder).recordAttemptCount(1, getAttributes(Code.OK));
+    verifyNoMoreInteractions(metricsRecorder);
+  }
+
   @Test
   void testOperationFailed_recordsAttributes() {
     ApiException error0 =