Name resolution delay - #12893
Merged
Merged
Name resolution delay#12893
Conversation
This commit implements the plumbing required to propagate delay reason tokens from load balancing policies up to the transport layer and tracers, as specified in the LB policy delay design.
…dence invariants - Refactor ClientStreamTracer to expose delayTypeStarted(String) and delayReasonAttached(String) - Enhance PickResult with separate delayType and delayReason diagnostic fields - Implement Mark Roth's hybrid telemetry cadence model in DelayedClientTransport.PendingStream - Support channel fallback delay states (client_channel_init, subchannel_state_mismatch, wait_for_ready_failed) - Simplify leaf and container LB policies to emit canonical unified connecting metric labels
# Conflicts: # core/src/main/java/io/grpc/internal/PickFirstLeafLoadBalancer.java
… in OpenTelemetry modules
…ay and Attempt-Level Delay
…for name resolution in ManagedChannelImpl
AgraVator
marked this pull request as draft
July 6, 2026 14:32
…name-resolution-delay branch
…ame-resolution-delay branch
…elay # Conflicts: # core/src/main/java/io/grpc/internal/DelayedClientTransport.java # core/src/main/java/io/grpc/internal/PickFirstLoadBalancer.java # core/src/test/java/io/grpc/internal/DelayedClientTransportTest.java # opentelemetry/src/main/java/io/grpc/opentelemetry/GrpcOpenTelemetry.java # opentelemetry/src/main/java/io/grpc/opentelemetry/OpenTelemetryMetricsModule.java # opentelemetry/src/main/java/io/grpc/opentelemetry/OpenTelemetryMetricsResource.java # opentelemetry/src/main/java/io/grpc/opentelemetry/OpenTelemetryTracingModule.java # opentelemetry/src/test/java/io/grpc/opentelemetry/OpenTelemetryMetricsModuleTest.java # opentelemetry/src/test/java/io/grpc/opentelemetry/OpenTelemetryTracingModuleTest.java # rls/src/main/java/io/grpc/rls/CachingRlsLbClient.java # rls/src/test/java/io/grpc/rls/CachingRlsLbClientTest.java # util/src/main/java/io/grpc/util/RoundRobinLoadBalancer.java # util/src/test/java/io/grpc/util/RoundRobinLoadBalancerTest.java # xds/src/main/java/io/grpc/xds/CdsLoadBalancer2.java # xds/src/main/java/io/grpc/xds/PriorityLoadBalancer.java # xds/src/test/java/io/grpc/xds/CdsLoadBalancer2Test.java # xds/src/test/java/io/grpc/xds/PriorityLoadBalancerTest.java
… and expand unit/stress tests
…nelImpl callback pattern
…y observability (gRFC A66) - Add nameResolutionDelay, lbPolicyDelay, and baselineNoDelay end-to-end tests to GrpcOpenTelemetryTest - Update LoadBalancer.PickResult.withError to set delayType="connecting" and delayReason=error.getDescription() - Fix missing static import checkstyle violation in CdsLoadBalancer2Test
…lay, remove debug prints, restore stress tests and add unit tests for patch coverage
…hStreamTracerFactory tests in LoadBalancerTest
…est and ManagedChannelImplTest
kannanjgithub
requested changes
Sep 9, 2026
…olve review comments - Unify call- and attempt-level child delay tracing span names to "Delay" - Align "Delay state transition" span event to record only grpc.delay_reason - Remove redundant local variables in OpenTelemetryTracingModule and OpenTelemetryMetricsModule - Eliminate redundant fully qualified Attributes references - Clean up synchronization and remove redundant volatile qualifiers - Update tests to follow repository style and verify updated span names and attributes
kannanjgithub
requested changes
Sep 10, 2026
… coverage - Update grpc.client.call.delay.duration and grpc.client.attempt.delay.duration descriptions to match gRFC A121 - Add assertions for metric descriptions, units, and required labels (grpc.target, grpc.method, grpc.delay_type) - Add test verifying null-safe behavior when delay observability flag is enabled but metrics are not opted in
kannanjgithub
approved these changes
Sep 10, 2026
AgraVator
commented
Sep 10, 2026
Comment on lines
+228
to
+230
| activeCallDelaySpan.addEvent( | ||
| "Delay state transition", | ||
| Attributes.of(AttributeKey.stringKey("grpc.delay_reason"), delayReason)); |
Contributor
Author
There was a problem hiding this comment.
Being discussed at grpc/proposal#556 (comment)
… alignment and concurrency fixes - Unify ClientStreamTracer and ClientStreamTracer.Factory delay APIs to recordDelayStart(type, reason), recordDelayReasonChanged(type, reason), and recordDelayEnd(type); update ForwardingClientStreamTracer classes. - Remove GRPC_EXPERIMENTAL_ENABLE_DELAY_OBSERVABILITY environment flag gating; register call and attempt delay duration histograms as standard optional metrics on GrpcOpenTelemetry. - Emit 'Delay triggered' span events with grpc.delay.type and grpc.delay.reason attributes on call and attempt spans. - Queue wait_for_ready calls arriving after initial name resolution failure (when no defaultServiceConfig is set) in pendingCalls with the resolution failure reason; release queued calls when defaultServiceConfig is applied. - Ensure all tracer callbacks run outside internal locks; add wait barrier in PendingStream.endDelay() and streamCreated guards in OTel ClientTracer to prevent stream creation/closure races. - Prefix child delay reasons with numeric priority index in PriorityLoadBalancer and unwrap FixedResultPicker in equals/hashCode. - Pass child connecting pickers through WeightedRandomPicker in WeightedTargetLoadBalancer when overall state is CONNECTING/IDLE.
…ay gaps and remove bogus tests
Two sites left the channel without a picker while carrying no A121 annotation,
so an RPC queued there fell back to the channel's generic "waiting for picker":
- GracefulSwitchLoadBalancer publishes its pending placeholder as-is when the
outgoing policy is not READY, i.e. before the incoming policy has reported
anything. Annotated as "waiting for the new load balancing policy to report
a picker".
- AutoConfiguredLoadBalancerFactory publishes a bare CONNECTING picker between
delegate.shutdown() and the new delegate producing one, on every policy
change. Annotated as "waiting for the load balancing policy to be applied".
Test quality pass. Removed tests that asserted nothing:
- lbPolicyDelay_endToEndClientServerSimulation and
baselineNoDelay_endToEndClientServerSimulation hand-drove a tracer and then
asserted the value they had just fed it; the latter asserted the absence of
delay metrics and would pass if the feature regressed entirely.
- nameResolutionDelay_endToEndClientServerSimulation stood up a real server,
channel and RPC but asserted on a separately constructed tracer factory, so
the RPC contributed nothing. Rewritten without the dead scaffolding and
renamed to describe what it actually verifies.
- delayMethodsForwarded (core and util) duplicated allMethodsForwarded, which
already reflects over every public method.
- clientAttemptDelayDuration_recorded and clientCallDelayDuration_recorded are
strict subsets of delayHistograms_bucketBoundariesAndUnit.
- clientMetrics_targetAttributeFilter_returnsFilteredOrOther is trivially true
with a null filter and covers code this change does not touch.
PriorityLoadBalancerTest.priorityPicker_equalsAndHashCodeAndToString compared a
picker to itself: updateOverallState suppresses a picker equal to the current
one, so the second publish never reached the helper and the captor returned the
prior instance. Interleave a distinct reason so the equality contract is really
exercised, and assert the instances differ.
Assert the delay type and reason at the emission sites that had none: pick_first
(address list updated, attempting to connect, requesting connection, health
check state), grpclb, the RLS fallback and child-without-picker paths,
cluster_impl, lazy, weighted_target, the DelayedClientTransport legacy-picker
fallback, and PickResult.copyWithSubchannel/copyWithStreamTracerFactory. The
last is invisible to every other test because PickResult.equals deliberately
excludes the delay attributes.
All new tests live in existing test classes.
…chines
The delay span is deliberately built outside the tracer's monitor, so a
concurrent call end, stream close or delay-type rollover can race its
publication. The production code detects that window ("stale") and ends the
orphaned span on the creating thread, because no other thread can observe it.
Nothing exercised that path: the OpenTelemetry modules had no multi-threaded
coverage at all, even though they hold the most intricate synchronization in
this change (the delay epoch counter, span creation outside the lock, and the
double-checked call-ended tests).
Count span starts and ends through a real SDK SpanProcessor and require them to
balance. That invariant holds under every possible interleaving, so the
assertion is deterministic even though the execution is not, and it is exactly
the property the stale handling exists to guarantee: a span that is started must
always be ended.
Three races are driven, 300 iterations each, through a CyclicBarrier:
recordDelayStart against callEnded, recordDelayStart against streamClosed, and
two threads driving delay type transitions at the same time.
Verified by mutation: disabling either stale-cleanup branch fails all three
tests. Verified for flakiness by 10 consecutive runs, 9000 racing iterations
total, with no failures. This also brings the two stale-cleanup branches under
coverage.
…ests The new tests called picker.pickSubchannel(null), copying an idiom from production code: PriorityLoadBalancer.fixedPickResult does pass null, because a FixedResultPicker ignores its argument. The xds tests do not follow that convention. Before this branch they used mock(PickSubchannelArgs.class) and never passed null, and PriorityLoadBalancerTest and GracefulSwitchLoadBalancerTest already had such call sites, so the new tests were inconsistent with the files they were added to. Pass a mock instead, which also avoids a NullPointerException if one of these pickers ever starts reading its arguments. Also shorten the SpanBalanceProcessor javadoc, which described the tests rather than the class, and move that rationale onto the test that depends on it. No behavior change.
The guards that protect an already terminated `resolving` delay were not
exercised. `callCancelled()` marks the delay finished synchronously but only
schedules the call's removal from the pending queue, so a test that cancels
from its own thread has the removal drained before it can deliver a resolver
event, and the release pass then sweeps an empty queue.
`callDelay_cancelledWhileQueued_laterResolutionFailureIsNotReported` documented
exactly that scenario but did not produce it, so it asserted that nothing
changed while nothing had been delivered. It now queues the resolver failure
and the cancellation from inside the SynchronizationContext, which keeps the
cancelled call in the queue when the failure arrives.
Two cases are added:
- a successful resolution reaching a cancelled call, which reprocesses it and
must not end a delay the tracer already terminated. The success path runs
one hop behind the failure path, since the result goes through onResult()
before onResult2() applies it, so the cancellation is nested accordingly.
- a call created just as resolution completes, which observes the initial
config selector but is handed to a real call before it is ever queued, and
so must not report a delay at all.
Verified by mutation: removing either guard in endDelayIfNeeded() fails the new
tests. The delayFinished check in notifyNameResolutionFailed() stays covered but
is not independently observable, as the isDelayFinished() check inside the
notification loop already stops the fan-out.
Resolves one conflict in ManagedChannelImpl.updateConfigSelector(). Upstream grpc#12832 resets the config selector when the channel enters IDLE, by calling realChannel.updateConfigSelector(INITIAL_PENDING_SELECTOR) from enterIdleMode(), and guards the method so that this reset does not reprocess the queued calls. This branch had rewritten the same method to release the pending calls through releasePendingCalls() and no longer has the prevConfig check that the guard was added to, so the two changes could not be combined textually. The reset is now handled by an early return that keeps upstream's behaviour: the new config selector is stored, but nothing is released. It also clears initialConfigResolved and lastResolutionError, because entering IDLE shuts the name resolver down and the channel really is back to the state it was in before its first resolution. Leaving initialConfigResolved set would make a resolution failure after the idle period skip the default service config in onConfigError(), and a stale lastResolutionError would be reported as the delay reason for a call queued after the channel went idle. Everything else merged cleanly.
…lign with master Simplifies the gRFC A121 delay observability implementation across core, opentelemetry, util and xds so that the shape matches upstream/master and the previously approved ece66db revision, instead of the extra machinery this PR had accumulated. Core (DelayedClientTransport, ManagedChannelImpl): - Remove the DelayEvent queue / deliverDelayEvents / delayEpoch / rolledOverNanos / abandonDelay / AtomicReferenceFieldUpdater machinery. Tracers are invoked under the same lock as in master; the "never call tracers under a lock" rule was PR-invented and is what produced the unbalanced recordDelayEnd bug. - Restore the three tests that had been silently disabled and repair the four ManagedChannelImplTest cases broken by a blanket search/replace. OpenTelemetry: - Restore @GuardedBy on fields that are still lock-guarded, restore `private` on the module initializer, and build delay Attributes directly instead of via toBuilder() per RPC. - Remove redundant post-race callEnded/streamClosed calls from the tracing module test. Util / xds LB policies: - Apply the reviewed load-balancer delay plumbing (GracefulSwitch, MultiChild, RoundRobin, LeastRequest, RingHash, WeightedRoundRobin) unchanged. Net -626 lines vs the previous branch tip. All module suites pass: api 602, core 1588, opentelemetry 130, util 178, xds 4443 (0 failures).
…on and priority plumbing Re-entrancy (DelayedClientTransport.PendingStream, ManagedChannelImpl.PendingCall): - Remove notifyingTracers / endDeferred / deferredCancelReason / finishTracerNotification / fanOutDelayEnd. Deferring the end (or the cancel) behind a flag produced `closed` before `end`, or required nested deferrals. - Track only how many tracers/factories have been told the delay started (startedTracers / startedFactories). Starts run first-to-last, ends run last-to-first over exactly that prefix, and every fan-out loop stops as soon as the delay has ended. A tracer that cancels from inside its own callback now observes [start, reason, end, closed], with no double end and no end for a tracer that never saw a start. - Tests: DelayedClientTransportTest gains three cancel-inside-callback cases (reason change, type rollover end, type rollover start); the two ManagedChannelImplTest re-entrancy tests assert the loop-break semantics. DelayedClientTransport reason derivation: - Drop the Object-typed activeDelayReasonSource / determineQueuingDelayReasonSource indirection and the two-stage equality check. determineQueuingDelayReason (PickResult) returns the String directly, as in master; updateDelay compares the reason string. Equal wait_for_ready failure Statuses still produce equal strings, so no repeated callbacks. PriorityLoadBalancer: - Apply the numeric priority prefix in one place, updateOverallState(), using priorityNames.indexOf(priority) at publish time. This removes UNINITIALIZED_CHILD_PICKER and ChildLbState.priorityIndex / childPicker / updatePriorityIndex / buildPicker; ChildLbState's fields and constructor are identical to master again, and ChildHelper.updateBalancingState just stores the child's picker. The child's initial picker is prefixed through the same path (so its delay type does not change when the child first reports), and priority-list reorders are covered because every config update ends in tryNextPriority() -> updateOverallState(). - PriorityLoadBalancerTest: use equals(new Object()) for the type guard to satisfy ErrorProne. Net -119 production lines. Suites: core 1591, opentelemetry 130, util 178, xds 4443 (0 failures); checkstyle clean.
…shape Drop the defensive re-entrancy machinery that was layered on top of the delay bookkeeping and return to the state machine reviewed in the earlier PR: PendingStream starts its tracers in the constructor and keeps only activeDelayType/activeDelayReason/delayEnded; PendingCall keeps only queuedForResolution/delayEnded. The startedTracers/startedFactories counters, the per-tracer mid-loop aborts and the reprocessed flag are gone; reprocess() is now gated on endDelayIfNeeded() instead. Per Eric's review on the earlier PR, PendingStream ends its delay from onEarlyCancellation() rather than cancel(), so the end is reported before streamClosed() and only when the stream is actually cancelled early. RealChannel no longer tracks initialConfigResolved separately; the existing configSelector/lastResolutionError pair already encodes it, and onConfigError() applies the default service config through updateConfigSelector() as on master. The OpenTelemetry tracers drop the streamCreated guard, which duplicated what the channel already enforces. Tests follow: the cancel-inside-callback tests that only exercised the removed counters are deleted and the remaining one is the ece66db test.
Rebuild the branch as upstream/master (which already carries the attempt-level A121 work from grpc#12807) plus the reviewed call-level delta from ece66db, plus only the deltas the final gRFC text requires: - API: fold the attempt/call method pairs into recordDelayStart(type, reason), recordDelayReasonChanged(type, reason) and recordDelayEnd(type) on both ClientStreamTracer and ClientStreamTracer.Factory (gRFC A121 tracer API); concise self-contained Javadocs; all A121 members marked @SInCE 1.85.0. - Tracing: span "Delay" and event "Delay triggered" for both scopes. - Metrics: register grpc.client.call.delay.duration; drop the GRPC_EXPERIMENTAL_ENABLE_DELAY_OBSERVABILITY gate (the gRFC requires none; both histograms remain opt-in through the metric enable map). - priority LB: prefix the numeric priority ("0:connecting", nested "0:1:...") instead of the priority name. - DelayedClientTransport: non-null delay type/reason plumbing, ece66db's else-if reason update; no re-entrancy flags, constants or checkNotNull. - ManagedChannelImpl: ece66db's PendingCall resolving delay, unchanged. - OpenTelemetry modules: ece66db's synchronized/@GuardedBy tracers with a single endOpenDelay()/endActiveDelaySpan() helper per tracer. Everything else this branch had added on top of master (per-picker reason strings in pick_first/grpclb/rls/cluster LBs, GracefulSwitch/AutoConfigured/ WeightedTarget changes, lastResolutionError retention, null-argument tests, gate tests) is reverted to master.
grpc.client.attempt.delay.duration is specified with exactly grpc.target, grpc.method and grpc.delay_type. Restore master's label code for the attempt delay histogram (no grpc.lb.locality / grpc.lb.backend_service re-attachment) and put recordFinishedAttempt() back to master verbatim. Remove tests that either asserted nothing (bare assertNotNull) or covered pre-existing, non-A121 behaviour, and give the remaining no-op tests real assertions: no delay metric after streamClosed()/callEnded(), no "Delay" span for a reason change without an open delay, and only the three gRFC labels on the delay histogram even when optional labels are enabled.
…lay reasons
DelayedClientCall.cancel() dispatched the listener's onClose (and drained
the pending runnables) before invoking callCancelled(). ManagedChannelImpl's
PendingCall ends its "resolving" delay from callCancelled(), so a cancel or
deadline while queued for name resolution let tracers observe
recordDelayEnd("resolving") - or, if the syncContext task had not run yet,
recordDelayStart("resolving") - after the call had already completed. Move
callCancelled() ahead of the listener close. Reproduced at scale by a
concurrent stress run (thousands of occurrences per run); zero afterwards.
The picker_failing_with_wait_for_ready reason embedded Status.toString(),
which appends the cause's full stack trace; with a refused connection that
put a 20-line Netty stack trace into every delay span event. Format the
reason as "CODE: description" instead, like StatusRuntimeException.
PendingStream.endDelay() now clears its state before calling the tracers,
and updateDelay() reuses it instead of duplicating the loop.
In NameResolverListener.handleErrorInSyncContext(), realChannel.onConfigError()
ran before helper.lb.handleNameResolutionError(error). Calls queued for initial
name resolution were released into DelayedClientTransport before the LB
installed its failing picker, recording a transient "connecting" attempt delay
("client channel: waiting for picker") on fail-fast RPCs and ahead of
"picker_failing_with_wait_for_ready" on wait-for-ready RPCs.
Notify the LB of the resolution error before calling realChannel.onConfigError()
so that released calls observe the failing picker directly.
LoadBalancer.FixedResultPicker.equals() and hashCode() previously compared only the underlying PickResult. Because PickResult equality intentionally ignores delayType and delayReason, child LB updates during CONNECTING (such as pick_first or cds updating from an uninitialized picker to a connecting picker with reasons) produced pickers that compared equal to the previous picker. Parent load balancers (such as PriorityLoadBalancer) that deduplicate picker updates dropped these updates, leaving the channel stuck with no delayType or delayReason and preventing the emission of required delay observability attributes under gRFC A121 (e.g. lines 129-136, 172-178). Include delayType and delayReason in FixedResultPicker.equals() and hashCode() using Objects.equal and Objects.hashCode.
…hild delays PriorityLoadBalancer wrapped child pickers in PriorityPicker inside ChildHelper.updateBalancingState(). If a child LB's initial state transition used GracefulSwitchLoadBalancer's pending picker (which has null delayType), or if priority lists were reordered/shrunk dynamically, the numeric priority prefix could either be omitted or retain a stale index (violating gRFC A121 line 172: "Load Balancer Policies MUST prepend the priority index and a colon to the delay type"). Move PriorityPicker wrapping into updateOverallState() so that published pickers consistently reflect the current priority index across child lifecycle and dynamic config reorders. When a child PickResult has no result and lacks an explicit delayType, default childType to "connecting" so the numeric prefix is properly composed.
ForwardingClientStreamTracerTest in both grpc-core and grpc-util already verifies via reflection in allMethodsForwarded() that all methods on ClientStreamTracer (including delay methods) are properly forwarded. Drop the redundant explicit delayMethodsForwarded tests and unused imports. In GrpcOpenTelemetryTest, drop the synthetic client/server simulation tests which manually invoked tracer delay methods disconnected from the actual RPC lifecycle. Replace with deterministic unit tests asserting that delay duration histograms for attempt and call delays are recorded with specification-defined attributes (grpc.target, grpc.method, grpc.delay_type) when opted in, and that no instruments or metrics are registered when not opted in.
…-ready delays
Drive a real in-process channel configured via
GrpcOpenTelemetry.configureChannelBuilder through the sequence: RPC
queued for name resolution -> resolver error -> resolver success ->
connect -> OK, and assert the exported grpc.client.call.delay.duration /
grpc.client.attempt.delay.duration points and the Delay spans.
Per gRFC A121 a wait-for-ready RPC in this scenario records exactly one
call-level "resolving" delay, one attempt-level
"picker_failing_with_wait_for_ready" delay and one "connecting" delay.
Before the channel notified the LB of the resolution error before
releasing pending calls, the released RPC additionally recorded a
spurious "connecting" delay ("client channel: waiting for picker"), so
this test doubles as the observability-level regression test for that
ordering fix.
The shared test method descriptor is marked sampledToLocalTracing so the
grpc.method label is populated, matching OpenTelemetryMetricsModuleTest.
…estore callCancelled ordering - Revert 828ece4 ("core: notify LB of name resolution error before releasing pending calls") and fbddfca ("opentelemetry: add end-to-end test for resolver failure with wait-for-ready delays") so NameResolverListener.handleErrorInSyncContext calls realChannel.onConfigError() before helper.lb.handleNameResolutionError(error) as on master. - Revert 47c97d4 ("api: include delay type and reason in FixedResultPicker equality") to keep FixedResultPicker.equals consistent with PickResult.equals. - Revert 88787cb ("xds: wrap priority child pickers in one place and prefix null-typed child delays") so PriorityLoadBalancer wraps child pickers in ChildHelper.updateBalancingState with the priorityIndex >= 0 guard. - Restore DelayedClientCall.callCancelled() to run after listener drain and realCall.cancel() as on master; OpenTelemetry interceptors already end call delay via callEnded(status) before delegating onClose.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
2 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
This finishes the remaining work in #12807