feat(observability): time HTTP requests and query-path ClickHouse calls

AGENTS.md

@@ -28,7 +28,7 @@ One binary:
 
 Sixteen internal packages under `internal/` (plus `internal/testutil/` for shared test helpers), and five public ones under `pkg/` — `chsql/`, `pipes/`, `policy/`, `settings/` and `tenant/` — that a module outside this repository imports at a release tag to validate a settings directory with the server's own rules ([#834](https://github.com/Wave-RF/WaveHouse/issues/834)); they import nothing under `internal/` and none of the server's runtime dependencies (the `public-packages` depguard rule in `.golangci.yml`):
 
-- **`api/`** — Chi HTTP router, JWT/JWKS middleware (from `auth/`), ingest/query/structured-query/SSE/schema/DLQ/pipes handlers; `ch_errors.go` (`writeCHError`) is the one mapping from a failed ClickHouse query to status, `code` and `retryable` (`writeCHWriteError` for a write pipe: never retryable, no `Retry-After`, since the write may have run)
+- **`api/`** — Chi HTTP router, JWT/JWKS middleware (from `auth/`), ingest/query/structured-query/SSE/schema/DLQ/pipes handlers; `ch_errors.go` (`writeCHError`) is the one mapping from a failed ClickHouse query to status, `code` and `retryable` (`writeCHWriteError` for a write pipe: never retryable, no `Retry-After`, since the write may have run); `metrics.go` holds the API's request-latency and query-path ClickHouse histograms (`wavehouse_http_request_duration_seconds`, `wavehouse_clickhouse_query_duration_seconds`), labeled by route pattern, method, status class, operation and result, never by tenant or path
 - **`app/`** — the process wiring: `New` builds every component from the boot config and the settings directory (each one wired in one place — what it opens, what it loops, what it releases — with the settings registry handed to its wiring function whole, the injection point of the per-tenant registry of #583: store-keyed getters for the handlers, `perTenant` for the async paths (with the tenant each message's `mq.Topic` names for the stream hub and the ingest worker), the `chconn.Pools`, the per-tenant `discoveries` and the per-tenant keepalive wheels (`keepalives`: one `stream.Heartbeater` per served tenant, at its own `stream.keepalive_*`, turned by the `keepalive` component, [#597](https://github.com/Wave-RF/WaveHouse/issues/597)) reconciled from `AfterAdopt`, `gapWindows` handing the sweeper each tenant's own gap window (a rejected tenant's as its folder last had it, unbounded for one rejected since boot) and the `mq.max_bytes_gb` reconcile each served tenant's byte budget, and `defaultPolicy` for the one setting that still follows tenant `0`, a flat directory's ops-gate admin role; the auth verifiers are per tenant, reconfigured (rebuilt only on changed wiring) and pruned from `AfterAdopt`, the same hook's `Hub.Prune` ends the open streams of a tenant no longer served, and `wireCache`'s hook drops, through `LocalCache.Prune`, the cache version index of a tenant no longer served ([#262](https://github.com/Wave-RF/WaveHouse/issues/262))), `Run` drives the long-lived ones under one `errgroup` until the context is cancelled or one fails, `Close` releases them in reverse order. `New` wires only what the process's `roles` need (discovery, dedupe, auth verifiers, the hub bridge and keepalive per API process; the ingest worker per ingest process; the sweeper under its lease through `elected`, on the embedded MQ only); a process without `api` serves `api.NewOpsRouter` — probes, `/version`, metrics, and the settings reload behind the operator key alone. `cmd/wavehouse` and `tests/integration` both boot through it
 - **`auth/`** — JWT auth middleware: HMAC **or** JWKS verification with `alg` pinned to the active verifier, role extraction from a configurable claim path; always runs, never rejects (bad token → empty role + stashed reason). One verifier per tenant ([#583](https://github.com/Wave-RF/WaveHouse/issues/583) story 9): `Authenticator` keys them by `tenant.ID` — the request store's `settings.Store.Tenant()`, through an injected `TenantSource`; `tenant.Default` on the tenant-exempt routes — built from each tenant's `auth` block by `Reconfigure`, dropped by `Prune` once the tenant stops being served (rejected or removed), released by `Close`; the operator key (`Config`) is boot-level and shared, while the HMAC secret is the tenant's own `auth.jwt_secret` (`Wiring`), rotated by a reload ([#529](https://github.com/Wave-RF/WaveHouse/issues/529)). A JWKS key set is fetched off the boot and reload paths: until one has been stored the verifier is pending and a token-bearing request gets `503` + `Retry-After` from `api.refuseUnverifiable` (`auth.ErrVerifierPending`), never a `default_role` evaluation; refresh is library-managed (Eric, 2026-09-22), response capped at 1 MiB; the operator key's admin role is the request tenant's
 - **`cache/`** — `Cache` interface → `LocalCache` (Ristretto: one pool for every tenant) + `VersionManager` (the invalidation index), and `RedisCache`, the Redis-compatible shared backend (random version tokens under the tenant's hash tag, one-round-trip lookups, bypass on failure behind a circuit breaker, deferred invalidations retried; selected by `cache.backend: redis`, configured by the boot config's `cache.redis` block — [#613](https://github.com/Wave-RF/WaveHouse/issues/613)). Every key carries the tenant (in `RedisCache`, after the key prefix: `<prefix>:{<tenant>}:…` for a version token, `<prefix>:q:<tenant>:…` for a value); in `LocalCache` and the version index it leads ([#583](https://github.com/Wave-RF/WaveHouse/issues/583) story 8) — `<tenant>:query:<sha>` for the caller's query key and its singleflight, escaped whole as the lead field of the stored key `<query key>|<tenant>.<gen>|<dependency>|…`, where each raw table and scope name is escaped by `keyenc` (a `Namespace` carries them raw, so no caller escapes); the index holds a version per tenant, per (tenant, table) and per (tenant, table, scope), keyed by raw name and bumped in place (one entry per live namespace however often it is bumped, [#262](https://github.com/Wave-RF/WaveHouse/issues/262)) — so no cached read or coalesced flight crosses tenants, a bump through `Invalidate` names one tenant's namespaces and no other's, and `InvalidateTenant` drops the tenant's index so its next key gets a process-unique generation, orphaning its every cached result in one step, pipe results included (no insert reaches a pipe result until [#343](https://github.com/Wave-RF/WaveHouse/pull/343)); `Lookup` returns a `Snapshot` of the versions it read, taken before the handler chooses any input a bump invalidates — the tenant's connection included — and `Set` files the fill under it, so a write landing mid-query, or a reload moving the tenant to another address or database after the request took its connection, orphans the fill ([#382](https://github.com/Wave-RF/WaveHouse/issues/382)), and every backend runs the conformance suite `internal/testutil/cachetest`; the one crossing is the wiring's, above the package: `internal/app` hands the ingest worker the cache through `sharedTables`, which repeats each of the worker's bumps under every tenant on the same ClickHouse address and database (`chconn.Pools.SharingTables`, whatever their user or tls block — they read the same tables), and orphans the whole cache of a tenant back on a pool after an absence, since it was out of that fan-out while away, or moved to another address or database, since it now reads other tables (story 6)

CHANGELOG.md

@@ -10,6 +10,8 @@ The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.1.0/),
 
 ### Added
 
+- **HTTP request latency and query-path ClickHouse calls are histograms** (`internal/api/metrics.go` (new, + `metrics_test.go`), `internal/api/{router,query,structured_query,pipes}.go`, `docs/src/content/docs/{deployment,architecture}.md`, `AGENTS.md`): the first tier of [#94](https://github.com/Wave-RF/WaveHouse/issues/94), part of the observability epic [#777](https://github.com/Wave-RF/WaveHouse/issues/777). The only request metrics were otelhttp's, which carry no route, so a slow or failing endpoint could not be told from the rest, and nothing timed what the query paths sent to ClickHouse. `wavehouse_http_request_duration_seconds{route, method, status_class}` times every request on `server.port` but the SSE streams, under the route's pattern (`/v1/pipes/{name}`), never the path; `wavehouse_clickhouse_query_duration_seconds{operation, result}` times each statement `POST /v1/query`, a pipe (`pipe`, `pipe_write`) or `POST /v1/ops/query` sends, with `result` `ok`, `canceled` (the client went away) or the response's error code without its `clickhouse.` prefix, so a histogram's `_count` is both the rate and the error rate. A cache hit records no query, and requests coalesced onto one record it once. Neither carries a tenant or table label. The worker's `INSERT` timing is the next tier.
+
 - **Dropped SSE frames say why, on which table and on which connection** (`internal/stream/{metrics,subscriber,hub}.go` (+ tests, `drop_test.go` new), `internal/api/stream.go` (+ `stream_drop_test.go` new), `docs/src/content/docs/{deployment,architecture,configuration}.md*`, `AGENTS.md`): closes [#424](https://github.com/Wave-RF/WaveHouse/issues/424), part of the observability epic [#777](https://github.com/Wave-RF/WaveHouse/issues/777). `wavehouse_sse_dropped_frames_total` counted only frames dropped to a full queue, labeled by `kind` alone, and nothing was logged, so a burst of drops could not be tied to a connection or told apart from clients going away. It now also counts the frames a stream left unwritten when it ended, and carries `reason` (`buffer_full`, `client_gone`, `stream_closed`) and `table` (empty for a table the tenant's schema does not have, since the client names it), which `prometheus.per_table_metrics: false` drops like every other table label; a query that sums the counter now also sees the two new reasons, so filter on `reason="buffer_full"` to keep the old meaning. New `wavehouse_sse_queue_peak_frames` gauge: the deepest any open stream's queue has been since it opened, so a fill between scrapes still shows. Every stream logs `SSE stream opened` and `SSE stream closed` (how it ended, how long it lasted, what it dropped), and a slow consumer logs `SSE stream dropping frames` at `WARN`, at most every 10 seconds per stream, with its queue's depth, peak and capacity; each line carries the connection's `request_id` and `tenant` from the request scope. No metric carries a tenant label.
 
 - **Logs and traces name the real client behind a trusted proxy, and only a trusted proxy's `traceparent` is joined** (`internal/config/proxies.go` (new, + tests), `internal/config/{config,backends}.go`, `internal/api/clientip.go` (new, + tests), `internal/api/router.go`, `internal/observability/{request,logger}.go` (+ tests), one line each in `internal/app/{wire,wire_ops}.go`, comments in `internal/auth/auth.go`, `config.yaml`, `docs/src/content/docs/{configuration,reverse-proxy}.mdx`, `{deployment,architecture}.md`, `AGENTS.md`): closes [#333](https://github.com/Wave-RF/WaveHouse/issues/333), part of the observability epic [#777](https://github.com/Wave-RF/WaveHouse/issues/777). Behind a proxy WaveHouse could log only the proxy's address, while the server span's `client.address`, which OpenTelemetry's HTTP instrumentation takes from the leftmost `X-Forwarded-For` entry, said whatever the client wrote there. `server.trusted_proxies` (`WH_SERVER_TRUSTED_PROXIES`, CIDRs or bare addresses, default empty) lists the proxies to believe: from a listed peer the client is the first `X-Forwarded-For` hop, read right to left, that is not itself a listed proxy; from any other peer it is the connection's address and the header is ignored. The result is `client.address` on the server span, replacing the instrumentation's value, and on every log record written through the request's context, the operator-key audit line included, next to `request_id` and `tenant`; it is never a metric label. An entry that does not parse, or an IPv4-mapped prefix shorter than `/96`, refuses boot, and a `/0` entry is a boot warning. An incoming `traceparent` used to be joined whoever sent it; it is now joined only from a listed proxy, and from any other peer starts a new trace linked to the one it named, so with the list empty (the default) a proxy's trace is linked rather than continued until you list the proxy. `r.RemoteAddr` is still never rewritten, so nothing reintroduces `middleware.RealIP`'s spoofing.

docs/src/content/docs/architecture.md

@@ -87,6 +87,7 @@ The API layer uses [Chi](https://github.com/go-chi/chi) for routing with `reques
 - **pipes.go** — Named query pipe handlers: admin listing (`GET /v1/ops/pipes[/{name}]`, read per request from its `pipes.Source`) and execution with parameter binding. A read is cached and coalesced; a write — bound SQL that `IsMutation` (`clickhouse_exec.go`) classifies as one — bypasses both and runs every call. `pipes.json` is the only way to define or change a pipe.
 - **structured_query.go** — Handler for `POST /v1/query?table={table}`: validates query AST, enforces permissions, builds and executes SQL.
 - **ch_errors.go** — `writeCHError`, the one mapping from a failed ClickHouse query to a response, shared by `/v1/query`, pipes and `/v1/ops/query` so they cannot drift apart: `chconn.Classify` decides the class, and the class the status, `code` and `retryable` ([ClickHouse errors on the query paths](/api#clickhouse-errors-on-the-query-paths)). A write pipe answers through `writeCHWriteError`, the same mapping with `retryable` always `false` and no `Retry-After`, since the write may have run.
+- **metrics.go** — the API's own instruments (meter `wavehouse-api`, no tenant label): `wavehouse_http_request_duration_seconds` by `route` (the matched chi route pattern: a mount's own, such as `/v1/*`, for a request answered inside it short of a route, and `unmatched` for one that reached no mount), `method` (net/http's methods, `other` for any other) and `status_class`, recorded by a middleware every router mounts outside `jsonRecoverer`, so a recovered panic counts as its `500`; `/v1/stream` is not timed, since a stream's lifetime is `wavehouse_sse_stream_duration_seconds`. `wavehouse_clickhouse_query_duration_seconds` by `operation` (`query`, `pipe`, `pipe_write`, `ops_query`) and `result` (`ok`, `canceled` for a call cut short by its client going away, which the response would class as `unavailable`, or the response's error `code` without its `clickhouse.` prefix, through `chFailureOf`), one value per statement sent: a cache hit records none and singleflight-coalesced callers record one. Nil-safe, so a handler built without its constructor records nothing.
 - **ingest.go** — Accepts `POST /v1/ingest?table={table}` in three body shapes: one flat JSON object, a JSON array of them, or NDJSON. The **required** `Content-Type` chooses the format *family* — `application/json` versus the four NDJSON spellings — and within the JSON family the body's first non-whitespace byte picks array versus single object; the bytes never choose the family. Anything that is not exactly one readable media type is a `415`, decided before the body is read: the header is parsed per RFC 9110 §8.3, and because `Content-Type` is a singleton field, repeated header lines must all resolve to the same format and a value carrying a comma is refused unless the value as a whole parses as one media type — a comma inside a *quoted* parameter value is data, so `application/json; a=", application/x-ndjson; b="` is accepted. It then reads the whole (`MaxBytesReader`-capped) body into a pooled buffer and runs the per-format record readers over those bytes, so the `413` lands before any record is processed and peak memory per request is O(body) rather than O(record). Then it validates and encodes each record, and runs the records in windows of up to 256 (`ingestWindow`) through three phases: one dedupe `Reserve` for the window's ids, the publishes in record order (a deduped record under `mq.WithIdempotencyKey`, keyed by `dedupe.IdempotencyKey`), and one `Commit` of the published ids — a window is the unit of a dedupe round trip and of Pebble's commit `fsync`. An id another request holds answers `503` with the lease as `Retry-After`, a store that cannot answer (`dedupe.ErrUnavailable`) `503` with `Retry-After: 5`; a publish that fails at a record commits the ones before it and releases the rest, except that a failure other than `mq.ErrQueueFull` may have stored the event, so that record's claim is left to lapse and the idempotency key drops the retry's copy if it comes within the stream's two-minute duplicate window — `mq.ErrUnavailable` (a broker blip) is one such failure, and still answers `503`: with the lease, rounded up to whole seconds, as `Retry-After` when the failing record held a claim left to lapse, else the flat `Retry-After: 5`. Each row goes through `mq.Publisher` on `mq.Topic{Tenant, Table, Scope}` (the request's tenant, read off its resolved store — `store.Tenant()` — and raw names; the subject it becomes is `internal/mq`'s; a full queue comes back as `mq.ErrQueueFull`, which is the `503` + `Retry-After`). When dedup is on, a row missing the configured `id_field` (or setting it to `null`) can't be deduped: it is logged at `WARN` and counted by `wavehouse_ingest_dedupe_missing_id_total` (labeled by `table`), then published un-deduped — or rejected when `dedupe.require_id` is set ([#219](https://github.com/Wave-RF/WaveHouse/issues/219)).
 - **query.go** — Proxies raw SQL for `POST /v1/ops/query` straight to the `?tenant=`'s ClickHouse HTTP interface (`chconn.Pools.Target` by the resolved store's tenant; the zero target — no pool — is a `503` with `Retry-After`). **Not cached** — sets `Cache-Control: no-store` so every request hits ClickHouse; DateTime is rendered ISO-8601 via `date_time_output_format=iso` (the Go-side type conversion lives in the structured-query / pipes path, not here).
 - **stream.go** — Real-time streaming via SSE. Callers select a table with the `?table=` query parameter. Each connection registers one `Subscriber` (the `stream/` package) with both the event `Hub` (under its `(topic, role)`) and its tenant's keepalive wheel (`Heartbeater`, a lookup by the request's store; a tenant no longer served has none, and its streams are ending), then drains both from a single byte-pump — so idle streams keep emitting `:` keepalive comments (surviving reverse-proxy idle timeouts) while live events arrive already projected and serialized. Per-event projection/serialization happens **once per role** in the `Hub`, not once per subscriber ([#294](https://github.com/Wave-RF/WaveHouse/issues/294)); the handler also snapshots the connection's JWT claims onto the `Subscriber`, which the `Hub` evaluates per subscriber when the role carries a row-level `filter` ([#319](https://github.com/Wave-RF/WaveHouse/issues/319)). Gap-fill replay (`mq.Replayer.ReplaySince` on the connection's `mq.Topic` — a `DeliverByStartTime` consumer inside `internal/mq`) stays per-connection (low-volume, one-time on connect). A stream ends, a gap-fill in progress included, when the server begins shutting down (`Closing`) or its `Subscriber` is evicted because its tenant is no longer served (`Hub.Prune`); one admitted just before the reload that stopped serving its tenant, and registered just after the prune, is ended right after it registers (`Served`). Each stream logs its open and its close (why it ended, how long it lasted, what it dropped), and a stream dropping frames to a full queue logs a rate-limited `WARN` with its queue state, all through the request's context, so each line carries the connection's `request_id` and `tenant`; on close the handler counts a frame it failed to write, and what is still queued, as dropped (`client_gone` or `stream_closed`).