Files
9b91094cdd enhance: fix client telemetry and tracing gaps found auditing the Go SDK against the server (#51967)
issue: #51963

Audit of the client telemetry (`ClientTelemetryService`) and client-side
tracing paths, comparing the Go SDK against
`internal/rootcoord/telemetry` and `pkg/tracer`. Five commits,
reviewable independently.

Most of the protocol core holds up — `config_hash`,
reply-retry-on-failed-heartbeat, reservoir P99. These are the gaps
around it.

**Correction:** earlier revisions of this description also listed the
`last_command_timestamp` watermark as already correct. It is not. The
cursor is a millisecond timestamp compared strictly, so a command
created in the *same millisecond* as one the client has already
processed is filtered out of every later heartbeat and never delivered —
it survives only until its TTL, with no error to whoever pushed it.
Reproduced in isolation: the second command comes back in zero
heartbeats. Relaxing to `>=` does not fix it, because the client prunes
its executed-ID set at the watermark and would re-run commands sitting
exactly on it; a correct fix needs a per-command cursor (a monotonic
sequence, or `(timestamp, command_id)` compared lexicographically) on
both sides. That is a protocol change and out of scope here — it is
pre-existing, documented in the design doc, and tracked in #51963.

---

## 1. `fix:` `client_request_id` no longer disables trace sampling

**The one behavioural bug.** A request carrying `client_request_id` was
**never sampled**, whatever `trace.sampleFraction` said, and the
suppression propagated to every downstream component. Silent, because
the trace ID still reached the logs — you kept log correlation and lost
tracing with no signal.

`clientRequestIDPropagator` carries the client ID in a synthesized
**remote parent span context** with no sampled flag. `ParentBased` maps
*remote parent, not sampled* → `NeverSample` (`[email protected].0
trace/sampling.go:200`), and its `root` sampler — the only one
consulting `sampleFraction` — is reached **only when there is no parent
at all**.

Root design error: a client-supplied *correlation ID* was placed in the
*parent span context*, a slot that in OTel also encodes an upstream
sampling decision.

**Fix.** Separate the two meanings. The propagator marks the context it
synthesized (an **in-process context value**, never a span-context
field, so nothing reaches the wire), and `clientRequestIDSampler`
samples a synthetic parent **as if it were a root span**. Everything
else delegates to `ParentBased`, so a genuine `traceparent` — including
`sampled=0` — keeps standard W3C semantics.

The marker is validated against the current parent span ID rather than
trusted alone: it stays in the context for the whole request, so without
that check an in-process **child** span would be re-sampled
independently of its parent and split the trace.

Also swapped the composite propagator order.
`clientRequestIDPropagator.Extract` opens with an "already have a span
context" guard meant to yield to a real `traceparent`, but running
**first** it could never fire — the two only composed correctly because
`TraceContext` ran later and overwrote it. Now precedence is explicit
rather than incidental.

| Incoming | Before | After |
|---|---|---|
| `client_request_id`, fraction=1.0 | **dropped** | sampled, trace ID =
client's ID |
| `client_request_id`, fraction=0.0 | dropped | dropped (ratio governs)
|
| `traceparent` sampled=1, fraction=0.0 | sampled | unchanged |
| `traceparent` sampled=0, fraction=1.0 | dropped | unchanged (W3C
respected) |
| both | traceparent wins | traceparent wins (by design now) |

Reverting the sampler branch makes
`TestClientRequestIDIsSampledByRatio/sampled_when_fraction_is_1.0` fail
with `sampled=false` at `sampleFraction=1.0` — the tests reproduce the
bug, not just describe it.

## 2. `enhance:` Go SDK telemetry correctness

- **`Unimplemented` was retried forever at full rate.** Against an older
server the heartbeat fired every 30s indefinitely, and the error was
dropped despite a comment claiming it was logged. Now the interval
**backs off exponentially** while the server keeps answering
`Unimplemented` — doubling per consecutive rejection, capped at 30
minutes, never shortening below the configured interval — and the streak
resets on the first reply. Deliberately *not* latched off: a client
load-balances across proxies, so mid rolling-upgrade one heartbeat can
land on an old proxy while the rest of the cluster already supports the
service, and a client that gave up would stay dark until restarted.
`IsSupported()` / `LastHeartbeatError()` expose the state — the
`client/` module has no logger, so an accessor is the only way to
surface a best-effort failure. `IsSupported()` is optimistic: it returns
true before the first heartbeat, so it means "no evidence of an old
server", not "confirmed working". Also opts the heartbeat out of the
client-wide retry interceptor (six RPCs with backoff → one against an
`Unavailable` server).
- **`max_latency_ms`** was collected but omitted at every proto
conversion site, so the server could never show it.
- **`TelemetryConfig.ClientID`** to pin a client identity across process
restarts; unchanged when unset.
- **Opt-in `WithClientRequestID` / `NewClientRequestID`**, matching
pymilvus's `CallContext(client_request_id=...)`. Kept opt-in even though
commit 1 fixes the server: an SDK cannot assume the server has the fix,
and sending it unconditionally would silently disable tracing against
any older cluster.
- **Deleted a test-only fork that had already diverged.**
`processCommands` / `calculateConfigHash` / `collectProtoMetrics` /
`getPendingReplies` were reachable only from tests, and the test-only
`calculateConfigHash` hashed `ID:Type` while production hashes `ID +
Type + payload`. Since `config_hash` must match the server
byte-for-byte, the tests were validating an algorithm that never runs.
Collapsed the duplicated proto conversion into one
`toProtoOperationMetrics()` and pointed the tests at production code.

## 3. `enhance:` command-reply endpoint

Commands are answered on the client's next heartbeat, but the reply
landed in a `StoredCommandReply` **no endpoint exposed** — smuggled
through `ClientInfo.Reserved["command_replies"]` as a JSON string, with
`GetClientCommandReplies()` having no production caller. The only way to
read one was to list every client and scan by hand.

Adds `GET /_telemetry/commands/{commandId}/reply`, with `?client_id=` to
look up one client instead of scanning every cached one.

```bash
curl -u root:pw "$M/_telemetry/commands/$CMD/reply?client_id=$CID"
{"command_id":"...","client_id":"...","status":"done","responded":1,"observed_clients":1,"replies":[...]}
```

Deliberately **no server-side blocking mode**. An earlier revision
offered `?wait=`; it was removed after review. Each lookup carries every
matching client's *entire* stored reply history (50 entries, encoded
into `ClientInfo.Reserved` regardless of `IncludeMetrics`), the 1MiB
payload cap applies only to built-in handlers, and
`authorizationEnabled` defaults to false — so a blocking mode turned one
unauthenticated request into dozens of full-history transfers. A caller
that wants to wait polls on its own schedule, which keeps one request to
one internal query. `GetClientTelemetryRequest.command_id`
(milvus-io/milvus-proto#647) would remove the amplification at its
source; using it is gated on a proto bump.

`pending` is 200, not an error — a reply that has not arrived is
indistinguishable from one that never will.

No proto changes — built on the existing `GetClientTelemetry` RPC.

## 4. `doc:` MEP refreshed to match the implementation

The MEP was written before the feature landed and never updated; anyone
porting the client half from it would build something that does not
interoperate. Corrected the command types (three of the documented ones
were never implemented), `TargetScope` values, REST paths, service name,
the non-existent `NewConfigHash`, persistent-command resend behaviour,
the default-enabled flag, and the `CommandHandler` signature.

Added what was missing and is load-bearing for a port: the exact
`config_hash` algorithm, the watermark's exactly-once consequence,
reply-as-garbage-collection, the `ttl_seconds: 0` leak,
persistent-config JSON merge, the hardcoded server limits (and that
there are **no** `milvus.yaml` keys), and the `legacy:` client-ID
collision.

## 5. `enhance:` alignment

The four above were written independently and contradict each other once
bundled — the SDK comment described sampling behaviour that commit 1
fixes, and the MEP documented the absence of the endpoint commit 3 adds.
Reconciled.

---

## Compatibility

- **No proto changes and no dependency changes.** `go.mod` and `go.sum`
are byte-identical to master across all four modules. (Earlier revisions
bumped milvus-proto; that is fully reverted — see
milvus-io/milvus-proto#647 and #648 for the upstream fields, which
milvus does not yet consume.)
- No exported Go API removed, `SetTracerProvider`'s signature unchanged;
every new symbol in `pkg/tracer` is unexported.
- Telemetry REST behaviour without `?wait=` is unchanged: `command_id`
and `status: "pending"` are still returned, which is what the WebUI
branches on.
- Go SDK: `client_request_id` is off unless the caller opts in, so no
request gains a header by default.

## Verification

`go test` green for the `client/` module, `pkg/tracer`, and the
`Telemetry` suite in `internal/proxy`; `golangci-lint` 0 issues across
all touched packages; `gofmt` clean.

**All verification is unit-level — nothing here has been run against a
live cluster or a live Jaeger/OTLP backend.** The sampling matrix is
derived from the sampler/propagator semantics plus tests that fail
without the fix; the end-to-end claim that a reply arrives within one
heartbeat is reasoned from the protocol, not observed.

## Not addressed

Found during the audit, left out deliberately: client telemetry exists
only in the Go SDK (pymilvus/Java/Node/Rust do not implement it); there
are no `milvus.yaml`/paramtable keys for the feature; the REST surface
is Basic Auth with no RBAC; non-persistent commands live only on the
RootCoord that received the push; `ttl_seconds: 0` commands leak if a
client never replies; and `PushCommand` does not validate
`command_type`. All recorded in #51963.

---

## Review follow-ups

Post-review fixes are in the commits after the five above; the
substantive ones:

- **Broadcast commands survived only until the first reply.**
`cleanupRepliedCommands` deleted any replied one-time command regardless
of scope, so on a `global` command the fastest client's reply cancelled
delivery to everyone else — a fleet-wide `collection_metrics` silently
reached part of the fleet. Deletion on reply is now limited to `client:`
scope; `global`/`database:` expire on their TTL.
- **`?wait=` was removed entirely** (an earlier revision added it, then
fixed its deadline handling and its stopping condition; all of that is
gone). Each lookup carries every matching client's *entire* stored reply
history, the 1MiB payload cap covers only the built-in handlers, and
`authorizationEnabled` defaults to false — so a blocking mode turned one
unauthenticated request into dozens of full-history transfers.
Collecting a reply is always deferred now.
- **The milvus-proto bump was reverted.** Earlier revisions bumped it
for `GetClientTelemetryRequest.command_id`; it dragged in three rounds
of unrelated collateral (regenerated mocks, a field-ID collision in
`planparserv2`'s test schema, and a broken `fastpb` hand-decoder
contract for a new `schemapb.IDs` oneof variant). `go.mod` and `go.sum`
are byte-identical to master again.
- **`observed_clients`** (was `known_clients`) — the count reflects what
the lookup scanned, not what the command targeted, so it never
established completeness and no longer claims to.
- **`ClientMetricsCache` data race** — the heartbeat wrote five fields
while admin readers polled them unsynchronized. Now behind an `RWMutex`,
with readers cloning/encoding off the lock. Pre-existing; fixed here
because this PR adds another poller.

---------

Signed-off-by: xiaofanluan <[email protected]>
Co-authored-by: xiaofanluan <[email protected]>
Co-authored-by: Claude Opus 5 (1M context) <[email protected]>
2026-08-02 10:50:50 -07:00
..
2023-09-21 09:45:27 +08:00