Implement Name Resolution and unified RPC Delay Observability specification

Author: AgraVator

api/src/main/java/io/grpc/ClientStreamTracer.java

@@ -58,29 +58,42 @@ public void createPendingStream() {
   }
 
   /**
-   * A delay segment started with a canonical root cause.
+   * Called when an attempt-level delay segment (such as waiting for a load balancing pick or
+   * connection establishment) starts.
    *
-   * @param delayType the canonical root cause label (e.g., "connecting", "client_channel_init")
+   * <p>This method is invoked synchronously on the attempt thread. Implementations should start
+   * internal timers or child tracing spans (named strictly {@code "Attempt Delay"}) carrying the
+   * canonical {@code grpc.delay_type} attribute.
+   *
+   * @param delayType canonical low-cardinality label categorizing the delay (e.g., "connecting")
+   * @param delayReason high-cardinality diagnostic string describing granular runtime conditions
    * @since 1.82.0
    */
-  public void delayTypeStarted(String delayType) {
+  public void recordAttemptDelayStart(String delayType, String delayReason) {
   }
 
   /**
-   * High-cardinality diagnostic context attached to the active delay span.
+   * Called when an attempt-level delay reason changes while the overall delay type remains
+   * constant (for example, when a priority load balancing policy fails over between tiers).
+   *
+   * <p>Implementations should record structured events (such as {@code "Delay state transition"})
+   * on the active delay span without recreating the span or resetting cumulative timers.
    *
-   * @param delayReason verbose diagnostic description of the delay
+   * @param delayReason updated high-cardinality diagnostic string describing new conditions
    * @since 1.82.0
    */
-  public void delayReasonAttached(String delayReason) {
+  public void recordAttemptDelayReasonChanged(String delayReason) {
   }
 
   /**
-   * The current delay segment ended.
+   * Called when an attempt-level delay segment ends upon successful pick or stream creation.
+   *
+   * <p>Implementations should simultaneously close active child tracing spans and record elapsed
+   * duration to the {@code grpc.client.attempt.delay.duration} histogram.
    *
    * @since 1.82.0
    */
-  public void delayEnded() {
+  public void recordAttemptDelayEnd() {
   }
 
   /**
@@ -143,6 +156,44 @@ public abstract static class Factory {
     public ClientStreamTracer newClientStreamTracer(StreamInfo info, Metadata headers) {
       throw new UnsupportedOperationException("Not implemented");
     }
+
+    /**
+     * Called when a call-level delay segment (such as waiting for name resolution or service
+     * configuration parsing) starts before any individual RPC attempt is created.
+     *
+     * <p>Implementations should start logical timers and create child tracing spans (named strictly
+     * {@code "Call Delay"}) carrying the canonical {@code grpc.delay_type} attribute.
+     *
+     * @param delayType canonical low-cardinality label categorizing the delay (e.g., "resolving")
+     * @param delayReason high-cardinality diagnostic string describing granular runtime conditions
+     * @since 1.82.0
+     */
+    public void recordCallDelayStart(String delayType, String delayReason) {
+    }
+
+    /**
+     * Called when a call-level delay reason changes while the active delay segment continues.
+     *
+     * <p>Implementations should emit structured events (such as {@code "Delay state transition"})
+     * on the active call delay span without recreating the span or resetting timers.
+     *
+     * @param delayReason updated high-cardinality diagnostic string describing new conditions
+     * @since 1.82.0
+     */
+    public void recordCallDelayReasonChanged(String delayReason) {
+    }
+
+    /**
+     * Called when a call-level delay segment ends upon successful name resolution or when an RPC
+     * is cancelled before resolution completes.
+     *
+     * <p>Implementations should close active call delay spans and record elapsed duration to the
+     * {@code grpc.client.call.delay.duration} histogram.
+     *
+     * @since 1.82.0
+     */
+    public void recordCallDelayEnd() {
+    }
   }
 
   /**

core/src/main/java/io/grpc/internal/DelayedClientTransport.java

@@ -413,43 +413,52 @@ private PendingStream(PickSubchannelArgs args, ClientStreamTracer[] tracers,
       this.activeDelayReason = initialReason;
       if (initialType != null) {
         for (ClientStreamTracer tracer : tracers) {
-          tracer.delayTypeStarted(initialType);
-        }
-      }
-      if (initialReason != null) {
-        for (ClientStreamTracer tracer : tracers) {
-          tracer.delayReasonAttached(initialReason);
+          tracer.recordAttemptDelayStart(initialType, initialReason != null ? initialReason : "");
         }
       }
     }
 
+    /**
+     * Updates active attempt delay telemetry state upon load balancing state transitions.
+     *
+     * <p>If {@code newType} differs from the active delay type, active segment timers and child
+     * spans are ended and a new segment is initiated. If only {@code newReason} changes, a
+     * structured transition event is appended to the active span without span re-creation.
+     */
     void updateDelay(@Nullable String newType, @Nullable String newReason) {
       if (!Objects.equals(activeDelayType, newType)) {
+        // Delay categorization changed (e.g., from RLS lookup to TCP connecting).
+        // Close prior active segment across all tracers before starting new canonical segment.
         if (activeDelayType != null) {
           for (ClientStreamTracer tracer : tracers) {
-            tracer.delayEnded();
+            tracer.recordAttemptDelayEnd();
           }
         }
         activeDelayType = newType;
         activeDelayReason = null;
         if (newType != null) {
           for (ClientStreamTracer tracer : tracers) {
-            tracer.delayTypeStarted(newType);
+            tracer.recordAttemptDelayStart(newType, newReason != null ? newReason : "");
           }
         }
       }
       if (newType != null && newReason != null && !Objects.equals(activeDelayReason, newReason)) {
+        // Categorization remained constant, but granular runtime diagnostics updated
+        // (e.g., priority policy failover between tiers). Emit transition event.
         activeDelayReason = newReason;
         for (ClientStreamTracer tracer : tracers) {
-          tracer.delayReasonAttached(newReason);
+          tracer.recordAttemptDelayReasonChanged(newReason);
         }
       }
     }
 
+    /**
+     * Ends active attempt delay segment telemetry upon stream creation or stream cancellation.
+     */
     void endDelay() {
       if (activeDelayType != null) {
         for (ClientStreamTracer tracer : tracers) {
-          tracer.delayEnded();
+          tracer.recordAttemptDelayEnd();
         }
         activeDelayType = null;
         activeDelayReason = null;

core/src/main/java/io/grpc/internal/ForwardingClientStreamTracer.java

@@ -40,18 +40,18 @@ public void createPendingStream() {
   }
 
   @Override
-  public void delayTypeStarted(String delayType) {
-    delegate().delayTypeStarted(delayType);
+  public void recordAttemptDelayStart(String delayType, String delayReason) {
+    delegate().recordAttemptDelayStart(delayType, delayReason);
   }
 
   @Override
-  public void delayReasonAttached(String delayReason) {
-    delegate().delayReasonAttached(delayReason);
+  public void recordAttemptDelayReasonChanged(String delayReason) {
+    delegate().recordAttemptDelayReasonChanged(delayReason);
   }
 
   @Override
-  public void delayEnded() {
-    delegate().delayEnded();
+  public void recordAttemptDelayEnd() {
+    delegate().recordAttemptDelayEnd();
   }
 
   @Override

core/src/main/java/io/grpc/internal/ManagedChannelImpl.java

@@ -993,10 +993,20 @@ private final class PendingCall<ReqT, RespT> extends DelayedClientCall<ReqT, Res
         this.method = method;
         this.callOptions = callOptions;
         this.callCreationTime = ticker.nanoTime();
+        // Category A (Resolver delay): Notify all registered tracer factories that this RPC
+        // is queued waiting for initial name resolution or service configuration parsing.
+        for (ClientStreamTracer.Factory factory : callOptions.getStreamTracerFactories()) {
+          factory.recordCallDelayStart(
+              "resolving", "waiting for name resolution or service config");
+        }
       }
 
       /** Called when it's ready to create a real call and reprocess the pending call. */
       void reprocess() {
+        // Name resolution succeeded; end Call-Level delay segment before launching attempts.
+        for (ClientStreamTracer.Factory factory : callOptions.getStreamTracerFactories()) {
+          factory.recordCallDelayEnd();
+        }
         ClientCall<ReqT, RespT> realCall;
         Context previous = context.attach();
         try {
@@ -1022,6 +1032,9 @@ public void run() {
 
       @Override
       protected void callCancelled() {
+        for (ClientStreamTracer.Factory factory : callOptions.getStreamTracerFactories()) {
+          factory.recordCallDelayEnd();
+        }
         super.callCancelled();
         syncContext.execute(new PendingCallRemoval());
       }

core/src/test/java/io/grpc/internal/DelayedClientTransportTest.java

@@ -785,22 +785,22 @@ public void streamDelayMetrics() {
     delayedTransport.newStream(method, headers, callOptions, customTracers);
 
     InOrder inOrder = inOrder(mockTracer);
-    inOrder.verify(mockTracer).delayTypeStarted("connecting");
-    inOrder.verify(mockTracer).delayReasonAttached("pick_first: attempting to connect");
+    inOrder.verify(mockTracer).recordAttemptDelayStart(
+        "connecting", "pick_first: attempting to connect");
 
     SubchannelPicker customDelayPicker = mock(SubchannelPicker.class);
     when(customDelayPicker.pickSubchannel(any(PickSubchannelArgs.class)))
         .thenReturn(PickResult.withNoResult("rls_lookup_pending", "RLS request pending."));
 
     delayedTransport.reprocess(customDelayPicker);
 
-    inOrder.verify(mockTracer).delayEnded();
-    inOrder.verify(mockTracer).delayTypeStarted("rls_lookup_pending");
-    inOrder.verify(mockTracer).delayReasonAttached("RLS request pending.");
+    inOrder.verify(mockTracer).recordAttemptDelayEnd();
+    inOrder.verify(mockTracer).recordAttemptDelayStart(
+        "rls_lookup_pending", "RLS request pending.");
 
     delayedTransport.reprocess(mockPicker);
 
-    inOrder.verify(mockTracer).delayEnded();
+    inOrder.verify(mockTracer).recordAttemptDelayEnd();
   }
 
   @Test
@@ -816,12 +816,12 @@ public void streamDelayMetrics_cancelled() {
     ClientStream stream = delayedTransport.newStream(method, headers, callOptions, customTracers);
     stream.start(streamListener);
 
-    verify(mockTracer).delayTypeStarted("connecting");
-    verify(mockTracer).delayReasonAttached("pick_first: attempting to connect");
+    verify(mockTracer).recordAttemptDelayStart(
+        "connecting", "pick_first: attempting to connect");
 
     stream.cancel(Status.CANCELLED);
 
-    verify(mockTracer).delayEnded();
+    verify(mockTracer).recordAttemptDelayEnd();
   }
 
   @Test
@@ -837,12 +837,12 @@ public void streamDelayMetrics_shutdownNow() {
     ClientStream stream = delayedTransport.newStream(method, headers, callOptions, customTracers);
     stream.start(streamListener);
 
-    verify(mockTracer).delayTypeStarted("connecting");
-    verify(mockTracer).delayReasonAttached("pick_first: attempting to connect");
+    verify(mockTracer).recordAttemptDelayStart(
+        "connecting", "pick_first: attempting to connect");
 
     delayedTransport.shutdownNow(Status.UNAVAILABLE);
 
-    verify(mockTracer).delayEnded();
+    verify(mockTracer).recordAttemptDelayEnd();
   }
 
   @Test
@@ -857,18 +857,17 @@ public void streamDelayMetrics_cadenceReasonUpdate_doesNotStartNewTypeSegment()
     delayedTransport.reprocess(picker1);
     delayedTransport.newStream(method, headers, callOptions, customTracers);
 
-    verify(mockTracer, times(1)).delayTypeStarted("connecting");
-    verify(mockTracer).delayReasonAttached("attempt 1");
+    verify(mockTracer, times(1)).recordAttemptDelayStart("connecting", "attempt 1");
 
     SubchannelPicker picker2 = mock(SubchannelPicker.class);
     when(picker2.pickSubchannel(any(PickSubchannelArgs.class)))
         .thenReturn(PickResult.withNoResult("connecting", "attempt 2"));
 
     delayedTransport.reprocess(picker2);
 
-    verify(mockTracer, times(1)).delayTypeStarted("connecting");
-    verify(mockTracer).delayReasonAttached("attempt 2");
-    verify(mockTracer, never()).delayEnded();
+    verify(mockTracer, times(1)).recordAttemptDelayStart("connecting", "attempt 1");
+    verify(mockTracer).recordAttemptDelayReasonChanged("attempt 2");
+    verify(mockTracer, never()).recordAttemptDelayEnd();
   }
 
   @Test
@@ -879,8 +878,8 @@ public void streamDelayMetrics_channelFallback_clientChannelInit() {
     // No picker reprocessed yet (lastPicker == null)
     delayedTransport.newStream(method, headers, callOptions, customTracers);
 
-    verify(mockTracer).delayTypeStarted("client_channel_init");
-    verify(mockTracer).delayReasonAttached("client channel: created LB policy.");
+    verify(mockTracer).recordAttemptDelayStart(
+        "client_channel_init", "client channel: created LB policy.");
   }
 
   @Test
@@ -900,8 +899,8 @@ public void streamDelayMetrics_channelFallback_subchannelStateMismatch() {
     delayedTransport.reprocess(stalePicker);
     delayedTransport.newStream(method, headers, callOptions, customTracers);
 
-    verify(mockTracer).delayTypeStarted("subchannel_state_mismatch");
-    verify(mockTracer).delayReasonAttached(
+    verify(mockTracer).recordAttemptDelayStart(
+        "subchannel_state_mismatch",
         "subchannel returned by LB picker has no connected subchannel");
   }
 
@@ -918,8 +917,8 @@ public void streamDelayMetrics_channelFallback_waitForReadyFailed() {
     CallOptions wfrOptions = callOptions.withWaitForReady();
     delayedTransport.newStream(method, headers, wfrOptions, customTracers);
 
-    verify(mockTracer).delayTypeStarted("wait_for_ready_failed");
-    verify(mockTracer).delayReasonAttached(
+    verify(mockTracer).recordAttemptDelayStart(
+        "wait_for_ready_failed",
         "wait_for_ready RPC failed with status: " + Status.UNAVAILABLE);
   }
 

opentelemetry/src/main/java/io/grpc/opentelemetry/GrpcOpenTelemetry.java

@@ -232,12 +232,24 @@ static OpenTelemetryMetricsResource createMetricInstruments(Meter meter,
               .build());
     }
 
-    if (isMetricEnabled("grpc.client.attempt.delay", enableMetrics, disableDefault)) {
+    if (isDelayObservabilityEnabled()
+        && isMetricEnabled("grpc.client.attempt.delay.duration", enableMetrics, disableDefault)) {
       builder.clientAttemptDelayCounter(
           meter.histogramBuilder(
-                  "grpc.client.attempt.delay")
+                  "grpc.client.attempt.delay.duration")
               .setUnit("s")
-              .setDescription("Time taken to complete a client call attempt delay")
+              .setDescription("Time taken before a client call attempt starts")
+              .setExplicitBucketBoundariesAdvice(LATENCY_BUCKETS)
+              .build());
+    }
+
+    if (isDelayObservabilityEnabled()
+        && isMetricEnabled("grpc.client.call.delay.duration", enableMetrics, disableDefault)) {
+      builder.clientCallDelayCounter(
+          meter.histogramBuilder(
+                  "grpc.client.call.delay.duration")
+              .setUnit("s")
+              .setDescription("Time taken before a client call starts")
               .setExplicitBucketBoundariesAdvice(LATENCY_BUCKETS)
               .build());
     }
@@ -359,6 +371,17 @@ static OpenTelemetryMetricsResource createMetricInstruments(Meter meter,
     return builder.build();
   }
 
+  /**
+   * Checks whether experimental client attempt and call delay observability is globally enabled.
+   *
+   * <p>Guarded strictly by the {@code GRPC_EXPERIMENTAL_ENABLE_DELAY_OBSERVABILITY} environment
+   * variable or JVM system property (defaults to {@code false}). When disabled, delay spans and
+   * duration histograms are suppressed to avoid runtime overhead.
+   */
+  static boolean isDelayObservabilityEnabled() {
+    return GrpcUtil.getFlag("GRPC_EXPERIMENTAL_ENABLE_DELAY_OBSERVABILITY", false);
+  }
+
   static boolean isMetricEnabled(String metricName, Map<String, Boolean> enableMetrics,
       boolean disableDefault) {
     Boolean explicitlyEnabled = enableMetrics.get(metricName);