core, opentelemetry, rls, xds, util: Enrich delay_reason diagnostic metadata across pass-through containers and Category C scenarios

AgraVator · AgraVator · commit af69f94018fe · 2026-06-23T15:46:26.000Z
diff --git a/core/src/main/java/io/grpc/internal/DelayedClientTransport.java b/core/src/main/java/io/grpc/internal/DelayedClientTransport.java
@@ -372,7 +372,7 @@ private static String determineQueuingDelayType(@Nullable PickResult pickResult)
       return "subchannel_state_mismatch";
     }
     if (!pickResult.getStatus().isOk()) {
-      return "wait_for_ready_failed";
+      return "picker_failing_with_wait_for_ready";
     }
     if (pickResult.getDelayType() != null) {
       return pickResult.getDelayType();
@@ -427,8 +427,7 @@ private PendingStream(PickSubchannelArgs args, ClientStreamTracer[] tracers,
      */
     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.
+        // Delay type changed (e.g., from RLS lookup to connecting). End the previous delay.
         if (activeDelayType != null) {
           for (ClientStreamTracer tracer : tracers) {
             tracer.recordAttemptDelayEnd();
@@ -443,8 +442,7 @@ void updateDelay(@Nullable String newType, @Nullable String 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.
+        // Delay type is unchanged, but the reason changed (e.g., priority failover).
         activeDelayReason = newReason;
         for (ClientStreamTracer tracer : tracers) {
           tracer.recordAttemptDelayReasonChanged(newReason);
diff --git a/core/src/main/java/io/grpc/internal/PickFirstLoadBalancer.java b/core/src/main/java/io/grpc/internal/PickFirstLoadBalancer.java
@@ -85,7 +85,7 @@ public void onSubchannelState(ConnectivityStateInfo stateInfo) {
 
       // The channel state does not get updated when doing name resolving today, so for the moment
       // let LB report CONNECTION and call subchannel.requestConnection() immediately.
-      updateBalancingState(CONNECTING, new FixedResultPicker(CONNECTING_RESULT));
+      updateBalancingState(CONNECTING, new FixedResultPicker(connectingResult()));
       subchannel.requestConnection();
     } else {
       subchannel.updateAddresses(servers);
@@ -137,7 +137,7 @@ private void processSubchannelState(Subchannel subchannel, ConnectivityStateInfo
       case CONNECTING:
         // It's safe to use RequestConnectionPicker here, so when coming from IDLE we could leave
         // the current picker in-place. But ignoring the potential optimization is simpler.
-        picker = new FixedResultPicker(CONNECTING_RESULT);
+        picker = new FixedResultPicker(connectingResult());
         break;
       case READY:
         picker = new FixedResultPicker(PickResult.withSubchannel(subchannel));
@@ -171,6 +171,10 @@ public void requestConnection() {
     }
   }
 
+  private PickResult connectingResult() {
+    return PickResult.withNoResult("connecting", "pick_first: attempting to connect");
+  }
+
   /** Picker that requests connection during the first pick, and returns noResult. */
   private final class RequestConnectionPicker extends SubchannelPicker {
     private final AtomicBoolean connectionRequested = new AtomicBoolean(false);
diff --git a/core/src/test/java/io/grpc/internal/DelayedClientTransportTest.java b/core/src/test/java/io/grpc/internal/DelayedClientTransportTest.java
@@ -918,7 +918,7 @@ public void streamDelayMetrics_channelFallback_waitForReadyFailed() {
     delayedTransport.newStream(method, headers, wfrOptions, customTracers);
 
     verify(mockTracer).recordAttemptDelayStart(
-        "wait_for_ready_failed",
+        "picker_failing_with_wait_for_ready",
         "wait_for_ready RPC failed with status: " + Status.UNAVAILABLE);
   }
 
diff --git a/opentelemetry/src/main/java/io/grpc/opentelemetry/OpenTelemetryMetricsModule.java b/opentelemetry/src/main/java/io/grpc/opentelemetry/OpenTelemetryMetricsModule.java
@@ -228,7 +228,7 @@ public void streamCreated(io.grpc.Attributes transportAtts, Metadata headers) {
     public void recordAttemptDelayStart(String delayType, String delayReason) {
       if (!GrpcOpenTelemetry.isDelayObservabilityEnabled()
           || (activeDelayStopwatch != null && Objects.equals(activeDelayType, delayType))) {
-        // If delay metrics are disabled or canonical delay type is unchanged, skip timer reset.
+        // Do not reset the stopwatch if the delay type is unchanged.
         return;
       }
       recordAttemptDelayEnd();
@@ -238,7 +238,7 @@ public void recordAttemptDelayStart(String delayType, String delayReason) {
 
     @Override
     public void recordAttemptDelayReasonChanged(String delayReason) {
-      // Reason strings are high-cardinality diagnostics intended strictly for tracing spans.
+      // Reason strings are high-cardinality diagnostics intended for tracing spans.
     }
 
     @Override
@@ -251,7 +251,6 @@ public void recordAttemptDelayEnd() {
         activeDelayStopwatch = null;
         activeDelayType = null;
         if (module.resource.clientAttemptDelayCounter() != null) {
-          // Export elapsed duration to grpc.client.attempt.delay.duration histogram (seconds).
           AttributesBuilder builder = io.opentelemetry.api.common.Attributes.builder()
               .put(METHOD_KEY, fullMethodName)
               .put(TARGET_KEY, target)
diff --git a/opentelemetry/src/main/java/io/grpc/opentelemetry/OpenTelemetryTracingModule.java b/opentelemetry/src/main/java/io/grpc/opentelemetry/OpenTelemetryTracingModule.java
@@ -223,8 +223,7 @@ public void recordAttemptDelayStart(String delayType, String delayReason) {
         return;
       }
       if (activeDelaySpan != null && Objects.equals(activeDelayType, delayType)) {
-        // Active Span Retention invariant: If canonical delay type remains identical
-        // (e.g., priority failover between tiers), delegate to reason changed hook.
+        // Do not recreate the span if the delay type is unchanged (e.g., priority failover).
         recordAttemptDelayReasonChanged(delayReason);
         return;
       }
@@ -237,7 +236,6 @@ public void recordAttemptDelayStart(String delayType, String delayReason) {
           .setAttribute("grpc.delay_type", delayType)
           .startSpan();
       activeDelaySpan = delaySpan;
-      // Emit structured transition event containing explicit categorization attributes.
       delaySpan.addEvent(
           "Delay state transition",
           io.opentelemetry.api.common.Attributes.of(
@@ -251,7 +249,6 @@ public void recordAttemptDelayReasonChanged(String delayReason) {
         return;
       }
       String type = activeDelayType;
-      // Append granular runtime diagnostics to active child span without span re-creation.
       activeDelaySpan.addEvent(
           "Delay state transition",
           io.opentelemetry.api.common.Attributes.of(
diff --git a/rls/src/main/java/io/grpc/rls/CachingRlsLbClient.java b/rls/src/main/java/io/grpc/rls/CachingRlsLbClient.java
@@ -1028,8 +1028,7 @@ public PickResult pickSubchannel(PickSubchannelArgs args) {
         SubchannelPicker picker =
             (childPolicyWrapper != null) ? childPolicyWrapper.getPicker() : null;
         if (picker == null) {
-          // Category F (Pass-Through container): Preserve leaf "connecting" delay type while
-          // recording RLS child policy context.
+          // Child policy is connecting. Preserve leaf delay type.
           return PickResult.withNoResult(
               "connecting", "RLS child policy connecting");
         }
@@ -1040,6 +1039,11 @@ public PickResult pickSubchannel(PickSubchannelArgs args) {
               Arrays.asList(helper.getChannelTarget(), lookupService,
                   childPolicyWrapper.getTarget(), determineMetricsPickResult(pickResult)),
               Arrays.asList(determineCustomLabel(args)));
+        } else if (pickResult.getDelayType() != null) {
+          return PickResult.withNoResult(
+              pickResult.getDelayType(),
+              "RLS child (" + childPolicyWrapper.getTarget() + ") delayed: "
+                  + pickResult.getDelayReason());
         }
         return pickResult;
       } else if (response.hasError()) {
@@ -1053,8 +1057,7 @@ public PickResult pickSubchannel(PickSubchannelArgs args) {
             convertRlsServerStatus(response.getStatus(),
                 lbPolicyConfig.getRouteLookupConfig().lookupService()));
       } else {
-        // Category B (Control-Plane scenario): RPC is blocked executing an RLS control-plane
-        // query. Report canonical "rls_lookup_pending" type and target server address.
+        // RLS control-plane query is pending.
         return PickResult.withNoResult(
             "rls_lookup_pending",
             "Route Lookup Service query pending on " + lookupService);
@@ -1074,6 +1077,11 @@ private PickResult useFallback(PickSubchannelArgs args) {
             Arrays.asList(helper.getChannelTarget(), lookupService,
                 fallbackChildPolicyWrapper.getTarget(), determineMetricsPickResult(pickResult)),
             Arrays.asList(determineCustomLabel(args)));
+      } else if (pickResult.getDelayType() != null) {
+        return PickResult.withNoResult(
+            pickResult.getDelayType(),
+            "RLS fallback (" + fallbackChildPolicyWrapper.getTarget() + ") delayed: "
+                + pickResult.getDelayReason());
       }
       return pickResult;
     }
diff --git a/util/src/main/java/io/grpc/util/RoundRobinLoadBalancer.java b/util/src/main/java/io/grpc/util/RoundRobinLoadBalancer.java
@@ -44,12 +44,17 @@ final class RoundRobinLoadBalancer extends MultiChildLoadBalancer {
   private static final PickResult CONNECTING_RESULT =
       PickResult.withNoResult("connecting", "round_robin: attempting to connect");
   private final AtomicInteger sequence = new AtomicInteger(new Random().nextInt());
-  private SubchannelPicker currentPicker = new FixedResultPicker(CONNECTING_RESULT);
+  private SubchannelPicker currentPicker = new FixedResultPicker(connectingResult());
 
   public RoundRobinLoadBalancer(Helper helper) {
     super(helper);
   }
 
+  private PickResult connectingResult() {
+    return PickResult.withNoResult("connecting",
+        "round_robin connecting: TCP/TLS handshake in progress to child balancers");
+  }
+
   /**
    * Updates picker with the list of active subchannels (state == READY).
    */
@@ -70,7 +75,7 @@ protected void updateOverallBalancingState() {
       }
 
       if (isConnecting) {
-        updateBalancingState(CONNECTING, new FixedResultPicker(CONNECTING_RESULT));
+        updateBalancingState(CONNECTING, new FixedResultPicker(connectingResult()));
       } else {
         updateBalancingState(TRANSIENT_FAILURE, createReadyPicker(getChildLbStates()));
       }
diff --git a/util/src/test/java/io/grpc/util/RoundRobinLoadBalancerTest.java b/util/src/test/java/io/grpc/util/RoundRobinLoadBalancerTest.java
@@ -87,7 +87,8 @@ public class RoundRobinLoadBalancerTest {
   private static final Attributes.Key<String> MAJOR_KEY = Attributes.Key.create("major-key");
   private static final SubchannelPicker EMPTY_PICKER =
       new FixedResultPicker(
-          PickResult.withNoResult("connecting", "round_robin: attempting to connect"));
+          PickResult.withNoResult("connecting",
+              "round_robin connecting: TCP/TLS handshake in progress to child balancers"));
 
   @Rule public final MockitoRule mocks = MockitoJUnit.rule();
 
@@ -584,7 +585,7 @@ public void roundRobin_delayAttributes() {
         .updateBalancingState(eq(CONNECTING), pickerCaptor.capture());
     PickResult res = pickerCaptor.getValue().pickSubchannel(mockArgs);
     assertThat(res.getDelayType()).isEqualTo("connecting");
-    assertThat(res.getDelayReason()).contains("attempting to connect");
+    assertThat(res.getDelayReason()).contains("TCP/TLS handshake in progress");
   }
 
   private static class FakeSocketAddress extends SocketAddress {
diff --git a/xds/src/main/java/io/grpc/xds/CdsLoadBalancer2.java b/xds/src/main/java/io/grpc/xds/CdsLoadBalancer2.java
@@ -123,7 +123,8 @@ public Status acceptResolvedAddresses(ResolvedAddresses resolvedAddresses) {
           CONNECTING,
           new FixedResultPicker(
               PickResult.withNoResult(
-                  "cds_dynamic_discovery", "cds: fetching xDS cluster metadata")));
+                  "cds_dynamic_discovery",
+                  "waiting for CDS resource definition for cluster " + clusterName)));
       return Status.OK;
     }
     if (!clusterConfigOr.hasValue()) {
diff --git a/xds/src/main/java/io/grpc/xds/ClusterManagerLoadBalancer.java b/xds/src/main/java/io/grpc/xds/ClusterManagerLoadBalancer.java
@@ -150,7 +150,13 @@ public PickResult pickSubchannel(PickSubchannelArgs args) {
                   Status.UNAVAILABLE.withDescription("CDS encountered error: unable to find "
                       + "available subchannel for cluster " + clusterName));
         }
-        return childPicker.pickSubchannel(args);
+        PickResult childResult = childPicker.pickSubchannel(args);
+        if (!childResult.hasResult() && childResult.getDelayType() != null) {
+          String reason = "xds_cluster_manager: child '" + clusterName + "': "
+              + (childResult.getDelayReason() != null ? childResult.getDelayReason() : "");
+          return PickResult.withNoResult(childResult.getDelayType(), reason);
+        }
+        return childResult;
       }
 
       @Override
diff --git a/xds/src/main/java/io/grpc/xds/PriorityLoadBalancer.java b/xds/src/main/java/io/grpc/xds/PriorityLoadBalancer.java
@@ -384,8 +384,10 @@ public PickResult pickSubchannel(PickSubchannelArgs args) {
       PickResult childResult = delegate.pickSubchannel(args);
       if (!childResult.hasResult() && childResult.getDelayType() != null) {
         String childReason = childResult.getDelayReason();
-        String reason = "priority_" + priority + ":" + (childReason != null ? childReason : "");
-        return PickResult.withNoResult(childResult.getDelayType(), reason);
+        String composedType = priority + ":" + childResult.getDelayType();
+        String reason = "waiting on priority group " + priority + " ("
+            + (childReason != null ? childReason : "connecting") + ")";
+        return PickResult.withNoResult(composedType, reason);
       }
       return childResult;
     }
diff --git a/xds/src/main/java/io/grpc/xds/WeightedRandomPicker.java b/xds/src/main/java/io/grpc/xds/WeightedRandomPicker.java
@@ -132,7 +132,12 @@ public final PickResult pickSubchannel(PickSubchannelArgs args) {
       checkNotNull(childPicker, "childPicker not found");
     }
 
-    return childPicker.pickSubchannel(args);
+    PickResult res = childPicker.pickSubchannel(args);
+    if (!res.hasResult() && res.getDelayType() != null) {
+      return PickResult.withNoResult(res.getDelayType(),
+          "weighted_target: " + (res.getDelayReason() != null ? res.getDelayReason() : ""));
+    }
+    return res;
   }
 
   @Override
diff --git a/xds/src/test/java/io/grpc/xds/CdsLoadBalancer2Test.java b/xds/src/test/java/io/grpc/xds/CdsLoadBalancer2Test.java
@@ -25,6 +25,7 @@
 import static io.grpc.xds.XdsTestControlPlaneService.ADS_TYPE_URL_RDS;
 import static org.mockito.ArgumentMatchers.any;
 import static org.mockito.ArgumentMatchers.eq;
+import static org.mockito.Mockito.atLeastOnce;
 import static org.mockito.Mockito.mock;
 import static org.mockito.Mockito.never;
 import static org.mockito.Mockito.verify;
@@ -369,7 +370,8 @@ public XdsConfig.Subscription subscribeToCluster(String clusterName) {
     verify(helper).updateBalancingState(eq(ConnectivityState.CONNECTING), pickerCaptor.capture());
     PickResult result = pickerCaptor.getValue().pickSubchannel(mock(PickSubchannelArgs.class));
     assertThat(result.getDelayType()).isEqualTo("cds_dynamic_discovery");
-    assertThat(result.getDelayReason()).isEqualTo("cds: fetching xDS cluster metadata");
+    assertThat(result.getDelayReason())
+        .isEqualTo("waiting for CDS resource definition for cluster cluster2");
   }
 
   @Test
@@ -675,8 +677,8 @@ public void cds_resolutionError_updatesAttemptDelay() {
         eq(ConnectivityState.TRANSIENT_FAILURE), pickerCaptor.capture());
     PickResult pick = pickerCaptor.getValue().pickSubchannel(
         mock(PickSubchannelArgs.class));
-    assertThat(pick.getDelayType()).isEqualTo("connecting");
-    assertThat(pick.getDelayReason()).contains("cds lookup failed");
+    assertThat(pick.getStatus().getCode()).isEqualTo(Status.Code.UNAVAILABLE);
+    assertThat(pick.getStatus().getDescription()).contains("cds lookup failed");
   }
 
   private static void assertPickerStatus(SubchannelPicker picker, Status expectedStatus)  {
diff --git a/xds/src/test/java/io/grpc/xds/PriorityLoadBalancerTest.java b/xds/src/test/java/io/grpc/xds/PriorityLoadBalancerTest.java
@@ -445,8 +445,8 @@ public void handleNameResolutionError_updatesDelayAttributes() {
         eq(ConnectivityState.TRANSIENT_FAILURE), pickerCaptor.capture());
     PickResult pick = pickerCaptor.getValue().pickSubchannel(
         mock(PickSubchannelArgs.class));
-    assertThat(pick.getDelayType()).isEqualTo("connecting");
-    assertThat(pick.getDelayReason()).contains("priority dns error");
+    assertThat(pick.getStatus().getCode()).isEqualTo(Status.Code.UNAVAILABLE);
+    assertThat(pick.getStatus().getDescription()).contains("priority dns error");
   }
 
   @Test
@@ -1053,8 +1053,9 @@ public void priorityPicker_prependsToken() throws Exception {
     SubchannelPicker priorityPicker = pickerCaptor.getValue();
     PickResult result = priorityPicker.pickSubchannel(mock(PickSubchannelArgs.class));
     
-    assertThat(result.getDelayType()).isEqualTo("connecting");
-    assertThat(result.getDelayReason()).isEqualTo("priority_p0:child_reason");
+    assertThat(result.getDelayType()).isEqualTo("p0:connecting");
+    assertThat(result.getDelayReason())
+        .isEqualTo("waiting on priority group p0 (child_reason)");
   }
 
   private void assertLatestConnectivityState(ConnectivityState expectedState) {
diff --git a/xds/src/test/java/io/grpc/xds/WeightedRandomPickerTest.java b/xds/src/test/java/io/grpc/xds/WeightedRandomPickerTest.java
@@ -28,6 +28,7 @@
 import io.grpc.xds.WeightedRandomPicker.WeightedChildPicker;
 import java.util.ArrayList;
 import java.util.Arrays;
+import java.util.Collections;
 import java.util.List;
 import org.junit.Rule;
 import org.junit.Test;
@@ -248,4 +249,24 @@ public void allZeroWeights() {
     assertThat(xdsPicker.pickSubchannel(pickSubchannelArgs)).isSameInstanceAs(pickResult3);
     assertThat(fakeRandom.bound).isEqualTo(4);
   }
+
+  @Test
+  public void pickSubchannelEnrichesDelayReason() {
+    final PickResult pending =
+        PickResult.withNoResult("connecting", "TCP handshake in progress");
+    SubchannelPicker delayedPicker = new SubchannelPicker() {
+      @Override
+      public PickResult pickSubchannel(PickSubchannelArgs args) {
+        return pending;
+      }
+    };
+    WeightedRandomPicker picker = new WeightedRandomPicker(
+        Collections.singletonList(new WeightedChildPicker(10, delayedPicker)));
+
+    PickResult res = picker.pickSubchannel(pickSubchannelArgs);
+    assertThat(res.hasResult()).isFalse();
+    assertThat(res.getDelayType()).isEqualTo("connecting");
+    assertThat(res.getDelayReason())
+        .isEqualTo("weighted_target: TCP handshake in progress");
+  }
 }

Original file line number	Diff line number	Diff line change
`@@ -918,7 +918,7 @@ public void streamDelayMetrics_channelFallback_waitForReadyFailed() {`
`918`	`918`	`delayedTransport.newStream(method, headers, wfrOptions, customTracers);`
`919`	`919`
`920`	`920`	`verify(mockTracer).recordAttemptDelayStart(`
`921`		`- "wait_for_ready_failed",`
	`921`	`+ "picker_failing_with_wait_for_ready",`
`922`	`922`	`"wait_for_ready RPC failed with status: " + Status.UNAVAILABLE);`
`923`	`923`	`}`
`924`	`924`
Original file line number	Diff line number	Diff line change
`@@ -150,7 +150,13 @@ public PickResult pickSubchannel(PickSubchannelArgs args) {`
`150`	`150`	`Status.UNAVAILABLE.withDescription("CDS encountered error: unable to find "`
`151`	`151`	`+ "available subchannel for cluster " + clusterName));`
`152`	`152`	`}`
`153`		`- return childPicker.pickSubchannel(args);`
	`153`	`+ PickResult childResult = childPicker.pickSubchannel(args);`
	`154`	`+ if (!childResult.hasResult() && childResult.getDelayType() != null) {`
	`155`	`+ String reason = "xds_cluster_manager: child '" + clusterName + "': "`
	`156`	`+ + (childResult.getDelayReason() != null ? childResult.getDelayReason() : "");`
	`157`	`+ return PickResult.withNoResult(childResult.getDelayType(), reason);`
	`158`	`+ }`
	`159`	`+ return childResult;`
`154`	`160`	`}`
`155`	`161`
`156`	`162`	`@Override`