Cover tracing in the provider blueprint

The blueprint reduced tracing to "don't open per-operation spans", which
reads as "nothing to do". Add an observability section: the operation
spans the decorators give for free, the child spans per backend call a
provider should add (parent-gated transport or a span decorator over the
SDK seam), the ctx/logger rules that keep traceID on log lines, and the
status per provider: kubernetes and gcp have child spans, kvm has none.
Matrix rows, the checklist item, gaps and a kvm proposal follow suit.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
This commit is contained in:
2026-09-16 09:14:06 +00:00
co-authored by Claude Opus 5
parent e08f23bcb3
commit 01c27b5f35
2 changed files with 129 additions and 9 deletions
@@ -98,3 +98,31 @@ go build ./... && go test -short ./...
Worth noting: no CHANGELOG entry yet. Per CLAUDE.md it goes in after the user Worth noting: no CHANGELOG entry yet. Per CLAUDE.md it goes in after the user
confirms the doc. confirms the doc.
### Follow-up — tracing was missing from the blueprint
The user pointed out, after the PR was opened, that the blueprint said almost
nothing about tracing. The plan's questionnaire item 10 had collected the
evidence, but the doc reduced it to a matrix row about logging and a checklist
line telling authors not to open spans. That line even suggests tracing needs
no work. A provider author needs the opposite message: the operation span comes
free, and child spans for backend calls are theirs to add.
Added a new §6, "Observability: tracing, logs and metrics", and renumbered the
matrix, checklist and gaps sections to §7–§9. It covers:
- **Three layers:** decorator operation spans; child spans per backend call,
with parent-gated HTTP transports or a span decorator over the SDK seam; and
logs.
- **The ctx and logger rules** that keep `traceID` on log lines.
- **A per-provider status table:**
- kubernetes: parent-gated `RestConfigWrapper` spans.
- gcp: the Google SDK's own `otelhttp`, never disabled by the provider.
- kvm: no spans. `trace.go` is a log decorator.
Also added two tracing rows to the §7 matrix, rewrote checklist item 8 as
"Tracing and logging" with an in-memory span-recorder test, and added gaps (kvm
has no child spans; only kubernetes is checked against Tempo, and only at
operation level). A proposal notes that the kvm `libvirtAPI` seam takes no
`ctx`, so per-RPC spans need that plumbed in.
The links were re-checked, including the new `architecture.md#10-tracing-internaltracing` anchor.
+101 -9
View File
@@ -87,7 +87,7 @@ Rules:
- **SHOULD return once the request is submitted, not once the instance is - **SHOULD return once the request is submitted, not once the instance is
running.** Readiness is discovered by polling `Get`. A blocking `Create` holds running.** Readiness is discovered by polling `Get`. A blocking `Create` holds
one of the 3 reconcile workers for its whole duration. kvm breaks this rule on one of the 3 reconcile workers for its whole duration. kvm breaks this rule on
purpose, see §8. purpose, see §9.
- **SHOULD reject a request it can never satisfy** with `ErrPermanent` before - **SHOULD reject a request it can never satisfy** with `ErrPermanent` before
touching the backend: a missing zone, machine type or image, or a name that is touching the backend: a missing zone, machine type or image, or a name that is
not in its catalogue (gcp `gcp.go:137-141`, kvm `kvm.go:126-144`, `:160-164`). not in its catalogue (gcp `gcp.go:137-141`, kvm `kvm.go:126-144`, `:160-164`).
@@ -216,7 +216,7 @@ Pitfalls:
can't tell quota from RBAC and picks Permanent (`kubernetes.go:201-206`). can't tell quota from RBAC and picks Permanent (`kubernetes.go:201-206`).
- **Don't return NotFound from `Create`.** The reconciler treats it as Transient - **Don't return NotFound from `Create`.** The reconciler treats it as Transient
there, but it misleads the metrics and anyone reading logs. kvm can currently there, but it misleads the metrics and anyone reading logs. kvm can currently
do this (§8). do this (§9).
- **Classify in one `classify` function** with a table-driven test. All three - **Classify in one `classify` function** with a table-driven test. All three
providers do. providers do.
@@ -263,7 +263,72 @@ unsupported, not as failed (`monitor.go:212`).
- **MAY fill `Details`** with facts useful when triaging, such as versions or - **MAY fill `Details`** with facts useful when triaging, such as versions or
capacity. Only kvm does today. capacity. Only kvm does today.
## 6. Feature matrix ## 6. Observability: tracing, logs and metrics
Tracing is OpenTelemetry, set up in `internal/tracing` from the standard
`OTEL_*` environment variables. With no exporter configured, spans are no-ops
and logs are unchanged ([architecture.md §10](architecture.md#10-tracing-internaltracing)).
A provider has three layers to think about; the first comes for free.
**1. Operation spans and metrics: the decorators, nothing to write.**
`cmd/main.go:219-222` wraps every provider in
`WithTracing(WithMetrics(...))`:
- `provider.WithTracing` opens one client span per call, `provider.create`,
`provider.get`, `provider.delete` or `provider.list`, with `provider.name`,
`provider.id` and `provider.result` (the error class) as attributes
(`internal/provider/tracing.go:27-80`). `ErrNotFound` keeps the span status
Ok, because polling to NotFound is expected.
- `provider.WithMetrics` counts each call by provider, op and result
(`metrics.go:15-74`).
- The spans sit under `Reconcile Proxy → reconcile.managed |
reconcile.replaceInstance | reconcile.delete`, or under `gc.sweep`.
Rules:
- **MUST NOT** open its own per-operation span or count its own requests. They
would duplicate the decorators.
- **MUST pass the caller's `ctx`** to every backend call and log through
`logf.FromContext(ctx)` **at call time**. The decorator starts the span with
`tracing.StartSpan`, which puts a logger carrying `traceID` and `spanID` into
`ctx` (`internal/tracing/logger.go:32-44`). A logger cached at construction,
or a backend call made with `context.Background()`, loses the trace.
- **Health checks bypass the decorators** (`cmd/main.go:211-218`). A
`Checker` runs under the monitor's `providerhealth.check` span
(`monitor.go:176`), and the same `ctx` rules apply to it.
**2. Child spans for backend calls: SHOULD.**
One operation span says that `Create` took 40 seconds. Child spans say which
backend call took them. Every provider SHOULD produce one child span per backend
request, under the operation span:
- **HTTP backends:** wrap the SDK's transport with `otelhttp`. Gate it on an
existing parent span, as `tracing.RestConfigWrapper` does
(`internal/tracing/transport.go:12-51`). Otherwise background traffic such as
watches, token refreshes or keepalives becomes root spans. Check first whether
the SDK already does this: Google's does.
- **Non-HTTP backends** (RPC over SSH, gRPC without interceptors, CLIs): start
child spans yourself with `tracing.Start(ctx, "<type>.<call>")`, around each
RPC and around long steps such as a dial or an image download. Use a
decorator over the SDK seam, not call-site code.
- **MUST NOT** put secrets or CloudInit contents in span attributes. Put
identifiers, sizes and error codes there.
**3. Logs.** V(1): one line per operation outcome and per failed backend call.
V(2): curated detail. V(5): raw wire, if the backend has one. Log lines are
matched to traces by the `traceID` key from layer 1, which is how kvm's
per-RPC log lines join a trace today.
What each provider does now:
| Layer | kubernetes | gcp | kvm |
|---|---|---|---|
| 1. Operation spans and metrics | yes: decorators | yes: decorators | yes: decorators |
| 2. Child spans per backend call | yes: `tracing.RestConfigWrapper()` on its `rest.Config` (`cmd/main.go:196-200`, `kubernetes.go:58-60`), parent-gated | yes: the Google SDK adds `otelhttp` itself unless telemetry is disabled (`google.golang.org/api/transport/http/dial.go:308-312`); not parent-gated, but every call site has a parent | **no**: `kvm/trace.go` is a log decorator, not spans |
| 3. Logs carry `traceID`/`spanID` | n/a: the package doesn't log | yes, including the V(5) wire log (`gcp/wirelog.go:54-59`) | yes: every `libvirt call` line at V(1) |
| Tested against a real collector | yes: kind e2e checks the `provider.create` and `provider.delete` traces in Tempo (`test/e2e/tracing_test.go:200-238`), operation spans only | no | no |
## 7. Feature matrix
Legend: **yes** / **partial** / **no**, with a short note. The evidence is in Legend: **yes** / **partial** / **no**, with a short note. The evidence is in
the per-provider notes below the table. the per-provider notes below the table.
@@ -294,6 +359,8 @@ the per-provider notes below the table.
| Credential rotation without restart | n/a | via ADC | no: cached after first load | | Credential rotation without restart | n/a | via ADC | no: cached after first load |
| Connection handling | client-go | SDK client; SDK retries on Get and List | one pooled SSH+libvirt connection per host, keepalive | | Connection handling | client-go | SDK client; SDK retries on Get and List | one pooled SSH+libvirt connection per host, keepalive |
| Logging | none in the package | V(1) ops, V(2) detail, wire log | V(1) ops and RPCs, V(2) detail | | Logging | none in the package | V(1) ops, V(2) detail, wire log | V(1) ops and RPCs, V(2) detail |
| Tracing: operation spans (§6) | yes | yes | yes |
| Tracing: child spans per backend call | yes: parent-gated transport | yes: SDK's otelhttp | **no** |
| Unit tests with a fake | yes: controller-runtime fake client | yes: `fakeAPI` + httptest | yes: `fakeAPI` + in-process SSH server | | Unit tests with a fake | yes: controller-runtime fake client | yes: `fakeAPI` + httptest | yes: `fakeAPI` + in-process SSH server |
| Real-backend test | kind e2e | manual runbook | `//go:build integration` | | Real-backend test | kind e2e | manual runbook | `//go:build integration` |
@@ -364,7 +431,7 @@ the per-provider notes below the table.
the RPC and leaves the connection open. the RPC and leaves the connection open.
- **Full guide:** [kvm-provider.md](kvm-provider.md). - **Full guide:** [kvm-provider.md](kvm-provider.md).
## 7. Adding a provider: checklist ## 8. Adding a provider: checklist
1. **Package:** create `internal/provider/<type>/` with the provider type and a 1. **Package:** create `internal/provider/<type>/` with the provider type and a
compile-time interface assertions: `var _ provider.Checker = (*Provider)(nil)` compile-time interface assertions: `var _ provider.Checker = (*Provider)(nil)`
@@ -405,11 +472,19 @@ the per-provider notes below the table.
"not an SDK error → Transient". Use `cfg.Name` in `provider.Wrap`. "not an SDK error → Transient". Use `cfg.Name` in `provider.Wrap`.
7. **Checker:** shared reasons first, a table test for the reasons, and a test 7. **Checker:** shared reasons first, a table test for the reasons, and a test
that `Check` returns promptly with an expired `ctx`. that `Check` returns promptly with an expired `ctx`.
8. **Logging:** 8. **Tracing and logging** (§6):
- Child spans for backend calls: an existing SDK instrumentation, a
parent-gated transport wrapper, or a span decorator over the SDK seam.
Add a test with an in-memory span recorder
(`sdktrace.NewTracerProvider(sdktrace.WithSpanProcessor(tracetest.NewSpanRecorder()))`,
as in `internal/provider/tracing_test.go`) asserting the spans are
children of the operation span.
- Take the logger from `ctx` on every call so log lines carry `traceID`.
- V(1): one line per operation outcome, plus a `logAPIError`-style line with - V(1): one line per operation outcome, plus a `logAPIError`-style line with
the raw backend error. the raw backend error.
- V(2): request and response detail. - V(2): request and response detail.
- Never log CloudInit contents; add a sentinel test for it. - Never put CloudInit contents in logs or span attributes; add a sentinel
test for it.
9. **Real-backend test:** behind `//go:build integration`, skipped when its 9. **Real-backend test:** behind `//go:build integration`, skipped when its
environment variables are unset. It runs the whole lifecycle: create, create environment variables are unset. It runs the whole lifecycle: create, create
again, poll until Running, list, delete, delete again, and confirm it is gone again, poll until Running, list, delete, delete again, and confirm it is gone
@@ -426,12 +501,12 @@ the per-provider notes below the table.
placement mapping, what lands on the backend, the health check, and known placement mapping, what lands on the backend, the health check, and known
gaps. gaps.
- A row in the architecture.md components table, and a block in §5 and - A row in the architecture.md components table, and a block in §5 and
§11. §11. If the provider adds spans, update the span topology in §10.
- A column in the §6 matrix above. - A column in the §7 matrix above.
- A sample in `config/samples/`. - A sample in `config/samples/`.
12. **Optional:** a demo script under `docs/demo/`. 12. **Optional:** a demo script under `docs/demo/`.
## 8. Gaps and proposed features ## 9. Gaps and proposed features
These are listed only. Nothing below is designed or implemented. These are listed only. Nothing below is designed or implemented.
@@ -468,6 +543,16 @@ These are listed only. Nothing below is designed or implemented.
`http_access allow all` (`pod.go`). `http_access allow all` (`pod.go`).
- **No logging** in the package, and **no Checker `Details`**. - **No logging** in the package, and **no Checker `Details`**.
**Tracing**
- **kvm has no child spans.** A kvm trace shows `provider.create` and nothing
under it: no libvirt RPCs, no SSH dial, no image download, although that is
where the time goes. Correlation works only through the `traceID` on its V(1)
log lines, which needs debug logging on.
- **Only kubernetes is tested against a real collector**, and that test checks
only the operation spans. Nothing checks that gcp's SDK spans or the
kubernetes API spans actually nest under `provider.*`.
**gcp** **gcp**
- **Asynchronous insert failures are never read.** An insert that the API - **Asynchronous insert failures are never read.** An insert that the API
@@ -507,6 +592,13 @@ These are listed only. Nothing below is designed or implemented.
### Proposed features (not implemented) ### Proposed features (not implemented)
- **Child spans in kvm:** extend the `tracingAPI` decorator in `kvm/trace.go`,
which already wraps every libvirt call, to also start a span per RPC, and add
spans for the SSH dial and the image download. The seam's methods take no
`ctx` today (`hostPool.call` hands `fn` only the API), so the span context has
to be plumbed in.
- **Tempo e2e checks for child spans**, and for gcp and kvm through their real
backend runbooks.
- **A shared conformance suite:** for example `internal/provider/providertest`, - **A shared conformance suite:** for example `internal/provider/providertest`,
which runs the §2 rules against any provider plus a fake backend, so a new which runs the §2 rules against any provider plus a fake backend, so a new
provider gets the contract tests for free. provider gets the contract tests for free.