core: Implement [A121](grpc/proposal#556) (#12893)

Author: AgraVator

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

@@ -58,42 +58,45 @@ public void createPendingStream() {
   }
 
   /**
-   * Called when an attempt-level delay segment (such as waiting for a load balancing pick or
-   * connection establishment) starts.
+   * Called when an attempt-level delay (such as waiting for a load balancing pick or connection
+   * establishment) starts, or when the {@code delayType} of the ongoing delay changes, in which
+   * case {@link #recordDelayEnd} is called for the previous delay first.
    *
-   * <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.
+   * <p>Implementations should start a timer and open a child tracing span (named strictly
+   * {@code "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
+   * @since 1.86.0
    */
-  public void recordAttemptDelayStart(String delayType, String delayReason) {
+  public void recordDelayStart(String delayType, String delayReason) {
   }
 
   /**
-   * 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).
+   * Called when an attempt-level delay reason changes while the delay type remains constant (for
+   * example, when a load balancing policy updates its connection status detail).
    *
-   * <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.
+   * <p>Implementations should record a structured event (such as {@code "Delay triggered"}) on
+   * the active delay span without recreating the span or resetting cumulative timers.
    *
+   * @param delayType canonical low-cardinality label of the ongoing delay
    * @param delayReason updated high-cardinality diagnostic string describing new conditions
-   * @since 1.82.0
+   * @since 1.86.0
    */
-  public void recordAttemptDelayReasonChanged(String delayReason) {
+  public void recordDelayReasonChanged(String delayType, String delayReason) {
   }
 
   /**
-   * Called when an attempt-level delay segment ends upon successful pick or stream creation.
+   * Called when an attempt-level delay ends upon successful pick or stream creation, or when the
+   * attempt is cancelled or reaches its deadline while still waiting.
    *
-   * <p>Implementations should simultaneously close active child tracing spans and record elapsed
-   * duration to the {@code grpc.client.attempt.delay.duration} histogram.
+   * <p>Implementations should close the active child tracing span and record the elapsed duration
+   * to the {@code grpc.client.attempt.delay.duration} histogram labeled with {@code delayType}.
    *
-   * @since 1.82.0
+   * @param delayType canonical low-cardinality label of the delay being ended
+   * @since 1.86.0
    */
-  public void recordAttemptDelayEnd() {
+  public void recordDelayEnd(String delayType) {
   }
 
   /**
@@ -156,6 +159,47 @@ public abstract static class Factory {
     public ClientStreamTracer newClientStreamTracer(StreamInfo info, Metadata headers) {
       throw new UnsupportedOperationException("Not implemented");
     }
+
+    /**
+     * Called when a call-level delay (such as waiting for name resolution) starts before any
+     * individual RPC attempt is created, or when the {@code delayType} of the ongoing delay
+     * changes, in which case {@link #recordDelayEnd} is called for the previous delay first.
+     *
+     * <p>Implementations should start a timer and open a child tracing span (named strictly
+     * {@code "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.86.0
+     */
+    public void recordDelayStart(String delayType, String delayReason) {
+    }
+
+    /**
+     * Called when a call-level delay reason changes while the delay type remains constant.
+     *
+     * <p>Implementations should record a structured event (such as {@code "Delay triggered"}) on
+     * the active call delay span without recreating the span or resetting timers.
+     *
+     * @param delayType canonical low-cardinality label of the ongoing delay
+     * @param delayReason updated high-cardinality diagnostic string describing new conditions
+     * @since 1.86.0
+     */
+    public void recordDelayReasonChanged(String delayType, String delayReason) {
+    }
+
+    /**
+     * Called when a call-level delay ends upon successful name resolution, or when the RPC is
+     * cancelled or reaches its deadline before resolution completes.
+     *
+     * <p>Implementations should close the active call delay span and record the elapsed duration
+     * to the {@code grpc.client.call.delay.duration} histogram labeled with {@code delayType}.
+     *
+     * @param delayType canonical low-cardinality label of the delay being ended
+     * @since 1.86.0
+     */
+    public void recordDelayEnd(String delayType) {
+    }
   }
 
   /**

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

@@ -739,21 +739,29 @@ public static PickResult withNoResult() {
      *
      * @param delayType low-cardinality root cause label (e.g., "connecting")
      * @param delayReason high-cardinality diagnostic string for trace events
-     * @since 1.82.0
+     * @since 1.86.0
      */
     public static PickResult withNoResult(String delayType, String delayReason) {
       Preconditions.checkNotNull(delayType, "delayType");
       Preconditions.checkNotNull(delayReason, "delayReason");
       return new PickResult(null, null, Status.OK, false, null, delayType, delayReason);
     }
 
-    /** Returns the delay type label if any. */
+    /**
+     * Returns the delay type label if any.
+     *
+     * @since 1.86.0
+     */
     @Nullable
     public String getDelayType() {
       return delayType;
     }
 
-    /** Returns the diagnostic delay reason if any. */
+    /**
+     * Returns the diagnostic delay reason if any.
+     *
+     * @since 1.86.0
+     */
     @Nullable
     public String getDelayReason() {
       return delayReason;

api/src/test/java/io/grpc/ClientStreamTracerTest.java

@@ -57,4 +57,17 @@ public void streamInfo_toBuilder() {
     StreamInfo info2 = info1.toBuilder().build();
     assertThat(info2.getCallOptions()).isSameInstanceAs(callOptions);
   }
+
+  @Test
+  public void defaultDelayMethodsNoOp() {
+    ClientStreamTracer tracer = new ClientStreamTracer() {};
+    tracer.recordDelayStart("connecting", "test");
+    tracer.recordDelayReasonChanged("connecting", "test2");
+    tracer.recordDelayEnd("connecting");
+
+    ClientStreamTracer.Factory factory = new ClientStreamTracer.Factory() {};
+    factory.recordDelayStart("resolving", "test");
+    factory.recordDelayReasonChanged("resolving", "test2");
+    factory.recordDelayEnd("resolving");
+  }
 }

api/src/test/java/io/grpc/LoadBalancerTest.java

@@ -91,6 +91,19 @@ public void pickResult_withNoResult() {
     assertThat(result.getStatus()).isSameInstanceAs(Status.OK);
     assertThat(result.getStreamTracerFactory()).isNull();
     assertThat(result.isDrop()).isFalse();
+    assertThat(result.getDelayType()).isNull();
+    assertThat(result.getDelayReason()).isNull();
+  }
+
+  @Test
+  public void pickResult_withNoResult_withDelay() {
+    PickResult result = PickResult.withNoResult("connecting", "trying backends");
+    assertThat(result.getSubchannel()).isNull();
+    assertThat(result.getStatus()).isSameInstanceAs(Status.OK);
+    assertThat(result.getStreamTracerFactory()).isNull();
+    assertThat(result.isDrop()).isFalse();
+    assertThat(result.getDelayType()).isEqualTo("connecting");
+    assertThat(result.getDelayReason()).isEqualTo("trying backends");
   }
 
   @Test
@@ -118,6 +131,10 @@ public void pickResult_equals() {
     PickResult sc3 = PickResult.withSubchannel(subchannel, tracerFactory);
     PickResult sc4 = PickResult.withSubchannel(subchannel2);
     PickResult nr = PickResult.withNoResult();
+    PickResult nrDelay1 = PickResult.withNoResult("connecting", "trying 10.0.0.1");
+    PickResult nrDelay2 = PickResult.withNoResult("connecting", "trying 10.0.0.1");
+    PickResult nrDelayDiffReason = PickResult.withNoResult("connecting", "trying 10.0.0.2");
+    PickResult nrDelayDiffType = PickResult.withNoResult("rls_lookup_pending", "trying 10.0.0.1");
     PickResult error1 = PickResult.withError(status);
     PickResult error2 = PickResult.withError(status2);
     PickResult error3 = PickResult.withError(status2);
@@ -132,6 +149,12 @@ public void pickResult_equals() {
     assertThat(sc1).isNotEqualTo(sc3);
     assertThat(sc1).isNotEqualTo(sc4);
 
+    assertThat(nr).isEqualTo(nrDelay1);
+    assertThat(nrDelay1).isEqualTo(nrDelay2);
+    assertThat(nrDelay1.hashCode()).isEqualTo(nrDelay2.hashCode());
+    assertThat(nrDelay1).isEqualTo(nrDelayDiffReason);
+    assertThat(nrDelay1).isEqualTo(nrDelayDiffType);
+
     assertThat(error1).isNotEqualTo(error2);
     assertThat(error2).isEqualTo(error3);
 

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

@@ -37,7 +37,6 @@
 import java.util.Collection;
 import java.util.Collections;
 import java.util.LinkedHashSet;
-import java.util.Objects;
 import java.util.concurrent.Executor;
 import javax.annotation.Nonnull;
 import javax.annotation.Nullable;
@@ -176,7 +175,7 @@ public final ClientStream newStream(
    */
   @GuardedBy("lock")
   private PendingStream createPendingStream(PickSubchannelArgs args, ClientStreamTracer[] tracers,
-      PickResult pickResult, @Nullable String delayType, @Nullable String delayReason) {
+      PickResult pickResult, String delayType, String delayReason) {
     PendingStream pendingStream = new PendingStream(args, tracers, delayType, delayReason);
     if (args.getCallOptions().isWaitForReady() && pickResult != null && pickResult.hasResult()) {
       pendingStream.lastPickStatus = pickResult.getStatus();
@@ -388,7 +387,10 @@ private static String determineQueuingDelayReason(@Nullable PickResult pickResul
       return "subchannel returned by LB picker has no connected subchannel";
     }
     if (!pickResult.getStatus().isOk()) {
-      return "wait_for_ready RPC failed with status: " + pickResult.getStatus();
+      Status status = pickResult.getStatus();
+      // Status.toString() would append the cause's stack trace.
+      return "wait_for_ready RPC failed with status: " + status.getCode()
+          + (status.getDescription() == null ? "" : ": " + status.getDescription());
     }
     if (pickResult.getDelayReason() != null) {
       return pickResult.getDelayReason();
@@ -407,16 +409,14 @@ private class PendingStream extends DelayedStream {
     @Nullable private String activeDelayReason;
 
     private PendingStream(PickSubchannelArgs args, ClientStreamTracer[] tracers,
-        @Nullable String initialType, @Nullable String initialReason) {
+        String delayType, String delayReason) {
       super("connecting_and_lb");
       this.args = args;
       this.tracers = tracers;
-      this.activeDelayType = initialType;
-      this.activeDelayReason = initialReason;
-      if (initialType != null) {
-        for (ClientStreamTracer tracer : tracers) {
-          tracer.recordAttemptDelayStart(initialType, initialReason != null ? initialReason : "");
-        }
+      this.activeDelayType = delayType;
+      this.activeDelayReason = delayReason;
+      for (ClientStreamTracer tracer : tracers) {
+        tracer.recordDelayStart(delayType, delayReason);
       }
     }
 
@@ -427,30 +427,23 @@ private PendingStream(PickSubchannelArgs args, ClientStreamTracer[] tracers,
      * 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.
      */
-    synchronized void updateDelay(@Nullable String newType, @Nullable String newReason) {
+    synchronized void updateDelay(String newType, String newReason) {
       if (getRealStream() != null) {
         return;
       }
-      if (!Objects.equals(activeDelayType, newType)) {
+      if (!newType.equals(activeDelayType)) {
         // Delay type changed (e.g., from RLS lookup to connecting). End the previous delay.
-        if (activeDelayType != null) {
-          for (ClientStreamTracer tracer : tracers) {
-            tracer.recordAttemptDelayEnd();
-          }
-        }
+        endDelay();
         activeDelayType = newType;
-        activeDelayReason = null;
-        if (newType != null) {
-          for (ClientStreamTracer tracer : tracers) {
-            tracer.recordAttemptDelayStart(newType, newReason != null ? newReason : "");
-          }
+        activeDelayReason = newReason;
+        for (ClientStreamTracer tracer : tracers) {
+          tracer.recordDelayStart(newType, newReason);
         }
-      }
-      if (newType != null && newReason != null && !Objects.equals(activeDelayReason, newReason)) {
+      } else if (!newReason.equals(activeDelayReason)) {
         // Delay type is unchanged, but the reason changed (e.g., priority failover).
         activeDelayReason = newReason;
         for (ClientStreamTracer tracer : tracers) {
-          tracer.recordAttemptDelayReasonChanged(newReason);
+          tracer.recordDelayReasonChanged(newType, newReason);
         }
       }
     }
@@ -459,12 +452,13 @@ synchronized void updateDelay(@Nullable String newType, @Nullable String newReas
      * Ends active attempt delay segment telemetry upon stream creation or stream cancellation.
      */
     synchronized void endDelay() {
-      if (activeDelayType != null) {
-        for (ClientStreamTracer tracer : tracers) {
-          tracer.recordAttemptDelayEnd();
-        }
+      String delayType = activeDelayType;
+      if (delayType != null) {
         activeDelayType = null;
         activeDelayReason = null;
+        for (ClientStreamTracer tracer : tracers) {
+          tracer.recordDelayEnd(delayType);
+        }
       }
     }
 

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

@@ -40,18 +40,18 @@ public void createPendingStream() {
   }
 
   @Override
-  public void recordAttemptDelayStart(String delayType, String delayReason) {
-    delegate().recordAttemptDelayStart(delayType, delayReason);
+  public void recordDelayStart(String delayType, String delayReason) {
+    delegate().recordDelayStart(delayType, delayReason);
   }
 
   @Override
-  public void recordAttemptDelayReasonChanged(String delayReason) {
-    delegate().recordAttemptDelayReasonChanged(delayReason);
+  public void recordDelayReasonChanged(String delayType, String delayReason) {
+    delegate().recordDelayReasonChanged(delayType, delayReason);
   }
 
   @Override
-  public void recordAttemptDelayEnd() {
-    delegate().recordAttemptDelayEnd();
+  public void recordDelayEnd(String delayType) {
+    delegate().recordDelayEnd(delayType);
   }
 
   @Override