diff --git a/docs/plans-executions/2026-09-16-0841-provider-blueprint.md b/docs/plans-executions/2026-09-16-0841-provider-blueprint.md index b092194..97fef0b 100644 --- a/docs/plans-executions/2026-09-16-0841-provider-blueprint.md +++ b/docs/plans-executions/2026-09-16-0841-provider-blueprint.md @@ -98,3 +98,31 @@ go build ./... && go test -short ./... Worth noting: no CHANGELOG entry yet. Per CLAUDE.md it goes in after the user 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. diff --git a/docs/providers.md b/docs/providers.md index 3821318..94c6b6b 100644 --- a/docs/providers.md +++ b/docs/providers.md @@ -87,7 +87,7 @@ Rules: - **SHOULD return once the request is submitted, not once the instance is 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 - purpose, see §8. + purpose, see §9. - **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 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`). - **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 - do this (§8). + do this (§9). - **Classify in one `classify` function** with a table-driven test. All three 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 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, ".")`, 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 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 | | 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 | +| 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 | | 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. - **Full guide:** [kvm-provider.md](kvm-provider.md). -## 7. Adding a provider: checklist +## 8. Adding a provider: checklist 1. **Package:** create `internal/provider//` with the provider type and a 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`. 7. **Checker:** shared reasons first, a table test for the reasons, and a test 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 the raw backend error. - 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 environment variables are unset. It runs the whole lifecycle: create, create 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 gaps. - A row in the architecture.md components table, and a block in §5 and - §11. - - A column in the §6 matrix above. + §11. If the provider adds spans, update the span topology in §10. + - A column in the §7 matrix above. - A sample in `config/samples/`. 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. @@ -468,6 +543,16 @@ These are listed only. Nothing below is designed or implemented. `http_access allow all` (`pod.go`). - **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** - **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) +- **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`, which runs the §2 rules against any provider plus a fake backend, so a new provider gets the contract tests for free.