mirror of
https://github.com/milvus-io/milvus.git
synced 2026-10-12 02:19:10 +00:00
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]>