[java-bigtable] throttling_latencies adds flow-control time in milliseconds to a total recorded as nanoseconds, and carries it across attempts #14771

Issue Details

throttling_latencies (TableClientBlockingLatency) under-reports the time a bulk mutation spends throttled by the batcher's flow control, by a factor of a million. It also over-reports after a retry, because the total is carried across attempts.

In BuiltinMetricsTracer:

• batchRequestThrottled(long throttledTimeNanos) adds the throttled time to totalClientBlockingTime after converting it to milliseconds:

  google-cloud-java/java-bigtable/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/BuiltinMetricsTracer.java

  Lines 256 to 259 in 165f02e

  	@Override
  	public void batchRequestThrottled(long throttledTimeNanos) {
  	totalClientBlockingTime.addAndGet(java.time.Duration.ofNanos(throttledTimeNanos).toMillis());
  	}

• recordAttemptCompletion adds grpcMessageSentDelay, which is in nanoseconds, to the same total, and then records the total as nanoseconds with Duration.ofNanos(totalClientBlockingTime.get()):

  google-cloud-java/java-bigtable/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/tracers/BuiltinMetricsTracer.java

  Lines 352 to 359 in 165f02e

  	totalClientBlockingTime.addAndGet(grpcMessageSentDelay.get());
  	recorder.clientBlockingLatency.record(
  	clientInfo,
  	tableId,
  	methodInfo,
  	sidebandData.getClusterInfo(),
  	Duration.ofNanos(totalClientBlockingTime.get()));

So a batch throttled for 500 ms contributes 500 to a total read as nanoseconds, and throttling_latencies records 0.0005 ms for it. For the bulk MutateRows path, where flow control is the main source of client blocking, the metric is close to zero whatever the throttling.

totalClientBlockingTime is a field of the tracer and is never reset between attempts. Attempt k therefore records the running total of attempts 1 to k, rather than its own blocking time, although the metric is recorded once per attempt.

The likely fix is to keep the total in nanoseconds (addAndGet(throttledTimeNanos) in batchRequestThrottled), and to reset it, or record a per-attempt delta, at each attempt's completion.

Found while exporting the client's metrics into Apache Flink's metric system through CustomOpenTelemetryMetricsProvider (flink-gcp/flink-connector-gcp). This is reported from reading the source; it has not been measured against the service.

Environment

• Java Version and JDK Vendor: Eclipse Temurin 17

Dependencies

• Libraries-Bom: 26.90.0
  • google-cloud-bigtable 2.85.0

The affected code is identical in 2.85.0 and on main at 165f02e.