A121: RPC Delay Observability - #556
Conversation
| * **Pass-Through Container Policies**: Policies like `xds_cluster_manager`, `weighted_target`, and `rls` **do not prepend any prefix or wrap the delay type**. They simply bubble up the child's `grpc.delay_type` (e.g., `"connecting"`) directly as-is. | ||
| * **Pass-Through Container Policies**: Policies like `xds_cluster_manager`, `weighted_target`, and `rls` **do not prepend any prefix or wrap the delay type**. They bubble up the child's `grpc.delay_type` (e.g., `"connecting"`) as-is. | ||
|
|
||
| Because only the priority policy contributes a prefix and it contributes exactly one (its active tier index), the resulting `grpc.delay_type` cardinality stays bounded; prefixes do not stack across nested pass-through containers. Implementations should keep the prefix a small bounded token (the tier index) so metric cardinality remains low; detailed per-container structure belongs in the `grpc.delay_reason` span event, not the metric label. |
There was a problem hiding this comment.
We are not gonna limit the nesting for priority policies right(as in px:py:pz.....:connecting ) ??
markdroth
left a comment
markdroth
left a comment
There was a problem hiding this comment.
The design looks good overall. I have one or two minor questions about design details, but they don't affect the overall shape of the design. Most of my comments are about the organization of the document -- the content is good but is not organized in a way that makes it easy to understand.
Please let me know if you have any questions. Thanks!
This PR implements **Attempt-Level RPC Delay Observability** across the core channel transport, built-in load balancers, xDS policies, and the OpenTelemetry telemetry plugin, aligned with [gRPC Proposal A121](grpc/proposal#556).
markdroth
left a comment
markdroth
left a comment
There was a problem hiding this comment.
This looks much better! Remaining comments are mostly minor.
Please let me know if you have any questions. Thanks!
| | `grpc.delay_type` | Scope | Meaning | Generated by | | ||
| |---|---|---|---| | ||
| | `resolving` | call | waiting on name resolution | channel (resolver) | | ||
| | `connecting` | attempt | waiting on a subchannel connection | leaf pickers (`pick_first`, `round_robin`, `ring_hash`, `weighted_round_robin`, `xds_override_host`) | |
There was a problem hiding this comment.
"leaf picker" is the wrong term here, because the xds_override_host policy is not a leaf policy -- and technically, every other policy here except pick_first is a petiole policy, not a leaf policy.
I suggest instead saying something like "LB policies that trigger connection attempts".
| | `picker_failing_with_wait_for_ready` | attempt | `wait_for_ready` RPC queued on a failing picker | channel | | ||
|
|
||
| If the state changes but the `grpc.delay_type` remains the same (e.g., a priority policy fails over or RLS changes backend targets), the tracer emits a new `"Delay state transition"` span event on the active child span with the updated `grpc.delay_reason` string, without recreating the span. | ||
| The `priority` policy composes the attempt-level values by prepending its numeric priority (e.g. `"0:connecting"`), and these prefixes stack when priority policies are nested (e.g. `"0:1:connecting"`), so the composed set is not statically enumerable. |
There was a problem hiding this comment.
The phrase "attempt-level value" seems confusing here, since this has nothing to do with the question of call vs. attempt.
I suggest instead saying something like "The priority policy prepends the numeric priority to the delay type returned by the child policy".
| Because only the priority policy contributes a prefix and it contributes exactly one (its active tier index), the resulting `grpc.delay_type` cardinality stays bounded; prefixes do not stack across nested pass-through containers. Implementations should keep the prefix a small bounded token (the tier index) so metric cardinality remains low; detailed per-container structure belongs in the `grpc.delay_reason` span event, not the metric label. | ||
| ```json | ||
| { | ||
| "name": "Delay state transition", |
There was a problem hiding this comment.
This isn't actually a state transition if it's the initial delay reason recorded when the span starts. Maybe this should instead just say something like "Delay triggered".
|
|
||
| For both layers, a child span is created for each distinct `grpc.delay_type`, and transitions within that type are recorded as span events: | ||
| * **`grpc.delay_type`**: A low-cardinality string representing the type of the delay. See below for supported values. This value is constant over the lifetime of an individual delay; if the value changes, that implies that the original delay has ended and a new delay has started. For metrics, this value is used in a metric label. For tracing, this value is an attribute on the trace span. | ||
| * **`grpc.delay_reason`**: A high-cardinality string capturing runtime details (such as target names, subchannel IP addresses, or connection error messages). This value can change over the lifetime of a delay. This value is not used in metrics. In tracing, this value is recorded in an event on the trace span. |
There was a problem hiding this comment.
It might be useful to explicitly say that this field is intended primarily for human understanding, not for automated interpretation.
|
|
||
| ##### Category A: Resolver Scenarios (Type: `"resolving"`) | ||
| * **DNS Resolver Pending**: The channel is waiting for the initial name resolution query to complete. The reason string should describe the pending resolver query (e.g., `"waiting for DNS query to complete for target example.com"`). | ||
| **Call tracer (telemetry plugin) responsibilities.** On `Start`, the plugin opens the `Delay` span (see [Tracing Schema](#tracing-schema)) and begins timing. On `ReasonChanged`, it adds a `Delay state transition` event. On `End`, it closes the span and records the elapsed duration to the corresponding histogram. The plugin owns timing, so the `End` methods carry no duration argument. |
There was a problem hiding this comment.
Instead of "begins timing", I suggest saying "records the delay type and start time of the delay".
| A delay begins when the channel starts waiting and ends when the wait resolves, when the `grpc.delay_type` changes (which ends the current delay and starts a new one), or when the RPC is cancelled or reaches its deadline. | ||
|
|
||
| When the delay resolves or transitions to a different delay type, the active child span is closed. | ||
| ### Metric Schema |
There was a problem hiding this comment.
This needs to include a statement about metric stability, similar to this:
| Recorded on the `grpc.client.attempt.delay.duration` histogram. These represent delays that occur during a specific RPC attempt: | ||
| * `"connecting"`: The attempt is delayed waiting for subchannel connection establishment or picker initialization. | ||
| * `"rls_lookup_pending"`: Specifically for Route Lookup Service (RLS) control-plane cache-miss query lookups. | ||
| * `"cds_dynamic_discovery"`: Specifically for xDS Cluster Discovery Service (CDS) dynamic metadata resource fetches. |
There was a problem hiding this comment.
Sorry, I steered you wrong here: I meant that it should reference A74, not A61. The reference should be where we discuss the cds_dynamic_discovery delay type, not where we discuss pick_first.
| | `recordCallDelayStart(delay_type, reason)` | call | a call-level delay begins (or the `delay_type` changes) | | ||
| | `recordCallDelayReasonChanged(reason)` | call | the reason changes within the same `delay_type` | | ||
| | `recordCallDelayEnd()` | call | the call-level delay resolves | | ||
| | `recordAttemptDelayStart(delay_type, reason)` | attempt | an attempt-level delay begins (or the `delay_type` changes) | | ||
| | `recordAttemptDelayReasonChanged(reason)` | attempt | the reason changes within the same `delay_type` | | ||
| | `recordAttemptDelayEnd()` | attempt | the attempt-level delay resolves | |
There was a problem hiding this comment.
For LB pick delays, I think this API will require both the channel and the call tracer impl to store the current delay type. The channel will need to store it to know whether it should call recordAttemptDelayStart() or recordAttemptDelayReasonChanged() on each LB pick, and the call tracer will need to store it to know what label value to record for the metric when the delay ends.
I think it might be better to structure this API such that we need to store the delay type in only one place, either the channel or the call tracer impl. It would probably make more sense to do it in the channel, because there could be multiple call tracers, and it would use more memory if each one has to do this itself.
To do it in the channel, we could just add the delay_type parameter to the recordAttemptDelayReasonChanged() and recordAttemptDelayEnd() methods.
| | `recordCallDelayStart(delay_type, reason)` | call | a call-level delay begins (or the `delay_type` changes) | | ||
| | `recordCallDelayReasonChanged(reason)` | call | the reason changes within the same `delay_type` | | ||
| | `recordCallDelayEnd()` | call | the call-level delay resolves | | ||
| | `recordAttemptDelayStart(delay_type, reason)` | attempt | an attempt-level delay begins (or the `delay_type` changes) | | ||
| | `recordAttemptDelayReasonChanged(reason)` | attempt | the reason changes within the same `delay_type` | | ||
| | `recordAttemptDelayEnd()` | attempt | the attempt-level delay resolves | |
There was a problem hiding this comment.
I don't think we need different method names for call-level and attempt-level delays. We'll already differentiate them based on whether they are called on the call-level tracer or the attempt-level tracer. I think both objects can have the same methods. So they can just be called RecordDelayStart(), RecordDelayReasonChanged(), and RecordDelayEnd().
|
|
||
| ## Rationale | ||
|
|
||
| **Call vs. attempt metrics.** We split metrics into two histograms to differentiate channel-initialization bottlenecks (name resolution) from per-attempt routing bottlenecks (LB pick and connection). Combining them would obscure whether a delay occurred before or during connection establishment. |
There was a problem hiding this comment.
I'm not sure this bullet is useful. It's not really about whethre the delay occurred before or during connection establishment -- that in and of itself wouldn't necessarily have been a reason to split the metrics.
Given that both metrics and tracing already differentiate calls from attempts, and that hedging means that there can be multiple attempts in parallel, I think this split was just the most natural approach. I don't think it's something we need to explicitly justify.
7 participants
No description provided.