diff --git a/CHANGELOG.md b/CHANGELOG.md index a8c561d..9efdebb 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,8 +6,92 @@ policy in [docs/versioning.md](docs/versioning.md). ## [Unreleased] +### Added + +- **A dependency-free Prometheus `/metrics` endpoint** (#91, first work + item). `smithy::server::MetricsRegistry` aggregates the existing `Observe` + hooks into three families — + the five `http_server_*` families labeled by `service_name`, `http_method` + and `route` — and `MetricsEndpoint` serves them in the + text exposition format, which needs no client library and so costs zero new + dependencies. `RecordMetrics` is `Observe` wired to a registry, so request + timing keeps one implementation and the scraped numbers cannot drift from + the logged ones; compose the endpoint outside the recorder and scrapes + answer without inflating the request rate they report. Label cardinality is + bounded by construction: `target` is never a label (path parameters and + query strings would mint a series per request id), an off-wire + `http_method` outside the nine RFC 9110 verbs collapses to `CUSTOM`, and a + series cap backstops + anything unforeseen while counting what it refused in + `metrics_observations_dropped_total`. Application metrics join the + same scrape through `NewCounter` / `NewGauge` / `NewHistogram`, so one + Prometheus target covers the service; the registry keeps owning escaping, + label ordering, and the per-family cap. `Declare` exports a known series at + zero from startup, so the first event is a visible step rather than a + counter's invisible first sample. `RecordRejections` feeds + `BeastServerTransport::Options::on_rejected`, so the 413/431 the transport + writes before any middleware exists are counted too — without filing a + zero latency that would flatter the panel during an over-limit flood. + + The whole stack is **off unless `MetricsOptions::enabled` says otherwise**, + and off means absent rather than idle: `RecordMetrics` and `MetricsEndpoint` + compose to the identity, so a disabled registry puts no wrapper on the + request path and `/metrics` 404s through to the router rather than serving + an empty scrape that would read as a live target with nothing to report. + Handles from a disabled registry are inert rather than unusable, so + application code never branches on the flag. Registration is deliberately + *not* conditional on it — an invalid name, a type collision, or a bad bucket + ladder aborts at startup either way, so enabling metrics in production is + never the first time those checks run. + + The exposition is [MoonBase](https://github.com/muchq/MoonBase)'s shared + HTTP serving contract, and is deliberately not configurable: the five + `http_server_*` families with the descriptions its three emitter rails pin, + the `service_name`/`http_method`/`route` label set, the `unmatched` and + `/health` route sentinels, the `CUSTOM` and `(unparsed)` method sentinels, + and the microsecond bucket ladder `//domains/platform/libs/otel_contract` + pins equal across them. Those services are who scrapes this, so a service + here can replace an aura/futility, yodel, or server_pal one without touching + a dashboard — and a knob would only be a way to drift off the contract + silently, since the failure renders as an empty panel rather than an error. + `service_name` is required when enabled and an empty one aborts, because + every dashboard query selects on it. Status is not a label: the success and + failure counters carry the outcome and are derived from the same tally the + total sums, so the three cannot disagree. The active gauge carries no route, + which is where every rail leaves it — it moves before dispatch. See the + Observability section of + [docs/production-guide.md](docs/production-guide.md). + +- **`RequestObservation` carries what an access log needs** (#202). + `Observe` reported six fields, which was enough for metrics and not for the + other thing every server does with a per-request hook. MoonBase's aura says + so in its own comment: its access log is *kept separate from `Observe`* + because the observation lacks the response size and the forwarded client, + so the chain runs two clocks per request measuring the same interval. Worse, + the raw `x-forwarded-for` it logs instead is not the ADR-0012 derived client + `PerClientRateLimit` keys on, so "whose bucket did that 429 come from" was + unanswerable. The observation now adds `request_bytes`, `response_bytes`, + `handler_threw`, and `client` — the derived client with its provenance, + never the forgeable header. `Observe` takes the trust boundary as a fourth + defaulted parameter (`TrustedProxies::None()`, the direct-connect + statement); pass it the same one given to the limiter. `handler_threw` + separates a contained crash from a deliberate 500, which report identically + otherwise. + ### Fixed +- **Health probes are distinguishable from dispatch failures in observability + hooks.** `HealthEndpoint` built its response without stamping + `HttpResponse::operation`, so every probe reached `Observe` (and so any + metrics or logging backend) as the empty operation — the same value + 404/405/400 use. Since Kubernetes polls a probe every few seconds, that is + usually the highest-volume path a service has, and merging the two meant + the 404 rate could not be read, the probe's own latency contaminated the + service's duration histogram, and no filter could separate them. + `HealthEndpoint` and `MetricsEndpoint` now report their own configured path + as the operation (`/livez`, `/readyz`, `/metrics`), which is fixed at + composition and so adds one series per composed endpoint. Chains that do + not observe probe traffic are unaffected. - **Numeric wire values no longer truncate into generated narrow types** (#109). Three holes in the otherwise-uniform range-check posture: an `intEnum` member in a document body cast the raw wire int64 straight into diff --git a/docs/production-guide.md b/docs/production-guide.md index 775cee5..7fa40ce 100644 --- a/docs/production-guide.md +++ b/docs/production-guide.md @@ -203,17 +203,26 @@ transport.Start(smithy::server::Chain( smithy::server::PerClientRateLimit( [limiter](const std::string& client) { return limiter->Allow(client); }, trusted, std::chrono::seconds(30)), - // Observe everything admitted — health probes included. on_start - // (optional) enables an in-flight gauge; on_complete carries - // method/target/operation/status/duration/trace_parent. + // Observe everything admitted — health probes included, reporting + // `operation` as their own path so a dashboard can filter them out. + // Hand it the SAME trust boundary as the limiter: without it the + // observation reports the peer while the limiter keyed on the + // forwarded client, and the log cannot answer a question about the + // limiter's own decision. smithy::server::Observe( [](const smithy::server::RequestObservation& o) { - // gauge -1; count 1; latency o.duration — feed any backend. + // One access-log record: o.method, o.target, o.operation, + // o.status, o.duration, o.trace_parent, o.request_bytes, + // o.response_bytes, o.handler_threw (a contained crash, not a + // deliberate 500), and o.client — the derived client with its + // .source provenance, which is the bucket the limiter keyed on. + // Also gauge -1; count 1; latency o.duration. }, [](const smithy::server::RequestStart& s) { // gauge +1 (labeled by s.method/s.target; the operation is not // known until the router runs). - }), + }, + nullptr, trusted), // Liveness: GET or HEAD /livez -> 200 {"status":"healthy"}. A HEAD // gets that body's Content-Length and none of its octets, framed by // the transport; everything else passes through to the router. @@ -229,7 +238,9 @@ transport.Start(smithy::server::Chain( The first middleware in the chain is outermost: it sees the request first and can short-circuit before anything below it runs (so the limiter's rejections -never reach `Observe` — track rejection rates in the limiter itself). Because +never reach `Observe` — track rejection rates in the limiter itself, or +compose `Observe` *outside* the limiter, which logs the 429s with the client +they were rejected for at the cost of observing traffic you refused). Because admission keys on the derived client address, health probes budget as their real source (the node or balancer address the transport saw) rather than sharing one spoofable key with abusive traffic; if even that source's own @@ -260,12 +271,11 @@ address changed; the CIDR didn't) fails silently: the spoof defense ignores the header on every request and all traffic collapses onto the proxy's one key. The fingerprint is visible in `smithy::http::DeriveClient` — the richer form of `ClientAddress` that also reports *how* the address was -derived. Count its `source` where the request is still in hand — a -one-line middleware wrapping the chain above; `Observe`'s sink sees only -the finished observation, not the request. On the dashboard: behind a -proxy, ~100% `kUntrustedHeaderIgnored` means the trust set no longer -matches the topology, and ~100% `kTrustedTier` means the proxy is not -appending `x-forwarded-for`. +derived. `Observe` reports it directly — `o.client.source`, derived against +the `TrustedProxies` you passed it — so counting it needs no extra +middleware. On the dashboard: behind a proxy, ~100% `kUntrustedHeaderIgnored` +means the trust set no longer matches the topology, and ~100% `kTrustedTier` +means the proxy is not appending `x-forwarded-for`. **Plumbing the trust set.** The boundary is deployment config; the convention is a `TRUSTED_PROXY_CIDRS` environment variable holding a @@ -339,7 +349,8 @@ OpenTelemetry — plugs in without the core taking a telemetry dependency. **Server:** `Observe` (above) reports, per request: `method`, `target`, `operation` (the Smithy operation that handled it, stamped by the generated -router; empty for 404/405/400 dispatch failures), `status`, `duration`, and +router; the endpoint's own path for `HealthEndpoint` and `MetricsEndpoint`; +empty for 404/405/400 dispatch failures), `status`, `duration`, and `trace_parent` — the request's W3C `traceparent` header, which always parses: a valid inbound one continues verbatim, and the transport ingress mints a fresh root when the client sent none or sent garbage (ADR-0011). The same @@ -348,6 +359,25 @@ throws. An optional `on_start` callback fires before dispatch (method and target only), enabling in-flight gauges; start/complete always pair, even when the handler throws. +It also reports `request_bytes` and `response_bytes`, a `handler_threw` flag, +and `client` — the ADR-0012 derived client (address plus provenance), **not** +the raw `x-forwarded-for`, which a direct client can forge. That is the +identity `PerClientRateLimit` keys on, so it is the one that answers "whose +bucket did that 429 come from"; pass `Observe` the same `TrustedProxies` you +give the limiter or the two will disagree. Unset means +`TrustedProxies::None()` — the deliberate direct-connect statement, under +which the peer is the client and the header is ignored wholly. Watch the +distribution of `client.source`: every request reporting `kDirectPeer` with +one address means you are behind a proxy and did not say so. + +`handler_threw` separates "we crashed" from "the handler deliberately +answered 500" — both report status 500 with no operation, and an access log +that cannot tell them apart sends whoever reads a 5xx spike looking for the +wrong thing. A thrown request has no response, so its `response_bytes` is 0; +`handler_threw` is what makes that an absence rather than an empty body. The +exception text stays on the transport's containment log, which carries the +same trace id. + **Client:** two ready-made interceptors in `smithy/client/observability.h`: @@ -370,6 +400,177 @@ config.interceptors.push_back(smithy::PropagateTraceContext()); `GenerateSpanId` — for building richer integrations (e.g. a server middleware that opens a span from `RequestObservation::trace_parent`). +**Prometheus:** the one bundled backend, because the text exposition format +needs no client library — it is a few lines of text over HTTP, so it costs +zero dependencies. Two middleware compose around the generated handler: + +```cpp +auto metrics = std::make_shared( + smithy::server::MetricsOptions{.enabled = true, .service_name = "todo-service"}); +transport.Start(smithy::server::Chain({smithy::server::MetricsEndpoint(metrics), + smithy::server::RecordMetrics(metrics)}, + server.Handler())); +``` + +**It is off unless you say otherwise.** `MetricsOptions::enabled` defaults to +false, and a disabled registry is not a registry that records into a void: the +two middleware compose to the *identity*, so nothing wraps the request path — +no timing, no lock, not even an extra call frame — and `/metrics` reaches the +router like any other unmodeled path and 404s. (A disabled endpoint answering +an empty 200 would read to Prometheus as a live target reporting no series, +which is exactly what a service whose metrics have gone silent looks like.) +Handles from a disabled registry are inert rather than unusable, so +application code never branches on the flag; only their *arguments* still +cost anything, so guard a hot call site whose labels are themselves expensive +with `metrics->enabled()`. + +Registration is not conditional on the flag. An invalid metric name, a type +collision, or a bad bucket ladder aborts at startup either way (ADR-0009), so +switching metrics on in production is never the first time those checks run. + +`RecordMetrics` is `Observe` wired to the registry, so request timing has one +implementation and the scraped numbers cannot drift from the logged ones. The +order above is deliberate: the endpoint sits *outside* the recorder, so +scrapes answer without being counted as served traffic — swap them and every +scrape inflates your own request rate, at whatever interval Prometheus polls. + +Five families are exposed on `/metrics` (path configurable), labeled by +`service_name`, `http_method` and `route`: + +| Family | Type | Notes | +| --- | --- | --- | +| `http_server_requests_total` | counter | every completed request | +| `http_server_requests_success_total` | counter | status < 400 | +| `http_server_requests_failure_total` | counter | status >= 400 | +| `http_server_requests_active_gauge` | gauge | no `route` label; see below | +| `http_server_request_duration_microseconds` | histogram | `_bucket`/`_sum`/`_count` | + +plus `metrics_observations_dropped_total`, the registry's own health. + +This is not a vocabulary of our own invention, and it is deliberately **not +configurable**. It is [MoonBase](https://github.com/muchq/MoonBase)'s shared +HTTP serving contract — spoken identically by its Java (yodel), Rust +(server_pal) and C++ (futility/otel, behind aura) emitters, and pinned across +them by `//domains/platform/libs/otel_contract`: names, descriptions, label +sets, route sentinels and bucket boundaries alike. Those services are who +scrapes this, and their dashboards (prom_proxy) query exactly these names with +exactly these labels. A knob here would be a way for one service to drift off +that contract, and the drift is silent — the panel renders empty, which looks +like a quiet service rather than a misconfigured one. If a second fleet ever +needs a different dialect, that is the point to design one. + +`service_name` is required whenever metrics are enabled, and an empty one +aborts at construction: every dashboard query selects on it, so a service +reporting the empty string is scraped, stored, and invisible. + +Three consequences of the contract worth knowing: + +- **Status is not a label.** The outcome rides on the success and failure + counters, which are two views of the same tally the total sums — so the + three can never disagree, and no series is multiplied by the codes a + service happens to return. +- **The active gauge carries no route.** It moves at request start, before + dispatch, where nothing bounded is known about the path. Every rail leaves + the route off it for that reason, and prom_proxy's negative + `route!="/health"` matcher passes a series without the label through + untouched — which is what makes the same filter safe on it. +- **Durations are microseconds**, on the ladder the rails pin equal. + `histogram_quantile` reads `le` off bucket counts, so a service on a + different ladder charts a quantile computed against different bins than + everything beside it. + +The label set is bounded by construction, because cardinality is what +actually kills a metrics endpoint. `target` is deliberately *not* a label — +it carries path parameters and query strings, so one series per distinct URL +is one series per request id; `route` is the bounded stand-in the router +stamps from the model, and a request that reached no operation reports the +`unmatched` sentinel rather than the empty string (`route!="/health"` matches +the empty string, so unrouted traffic would silently join the serving +figures). `HealthEndpoint` and `MetricsEndpoint` answer paths the model does +not define, so they stamp that path as their route (`route="/health"`): +probes are usually a service's highest-volume route, and left unlabeled they +would bury the 404 rate in the sentinel they share with it, and mix their own +latency into the same duration histogram. The path is fixed at composition, +so it is one series per composed endpoint — compose the probes inside +`RecordMetrics` if you want them counted, outside it if you do not. +`http_method` arrives from the wire, so anything outside the nine RFC 9110 +verbs collapses to `CUSTOM` rather than minting a series per invented verb, +and a request rejected before its method parsed reports `(unparsed)`. Past +`max_series` combinations the registry stops minting and counts what it +refused in `metrics_observations_dropped_total` — alert on that being +non-zero rather than discovering the cap as an OOM. + +Two things composition still has to get right for the MoonBase dashboards: +compose `HealthEndpoint()` on its default `/health` path and *inside* +`RecordMetrics`, because prom_proxy subtracts `route!="/health"` from every +serving number and charts that route on its own tile — a service that never +reports it reads as having no probe rather than as a healthy one. And point +Prometheus at the service directly: this produces the collector's output +shape without the collector. + +Your own metrics share the same scrape — one Prometheus target covers the +service, rather than the built-in families sitting behind one endpoint and +your domain numbers behind another. Mint a family once and keep the handle: + +```cpp +auto orders = metrics->NewCounter("orders_processed_total", "Orders processed."); +auto latency = metrics->NewHistogram("order_pipeline_seconds", "Pipeline time."); +auto depth = metrics->NewGauge("queue_depth", "Pending jobs."); + +orders.Increment({{"region", "us-east"}}); +latency.Observe(elapsed.count()); +depth.Set(pending); +``` + +Declare the series whose labels are known at startup — `orders.Declare({{"region", +"us-east"}})`, or `depth.Declare()` for an unlabeled one. A series nobody has +touched is simply absent from the scrape, and a counter whose first exported +sample is its first event's value hides that event for good: `increase()` and +`rate()` measure the change *between* samples, so with nothing earlier the +first one shows no increase at all and the panel reads zero — worse than a +missing tile, because it looks like an answer. Declaring is idempotent and +never disturbs a series that already has events. A declared histogram is +genuinely empty rather than an observation of zero, so `rate(_sum)/rate(_count)` +stays unbiased. Labels carrying request data have no series to declare (and +are the cardinality problem above); bound them to a known kind and declare +that instead. + +Handles are cheap to copy and address the same family, so a handler can hold +them as members. The registry keeps owning the parts that are easy to get +wrong: label values are escaped, labels are sorted so `{a,b}` and `{b,a}` are +one series rather than two, and the same per-family cap applies — a label +taken from unbounded data (a user id) costs that family its series budget and +is attributed on +`metrics_observations_dropped_total{metric="..."}` instead of taking +the process down. A metric name that isn't a valid Prometheus name, or that +collides with an existing family under a different type, aborts at +registration: both produce a scrape Prometheus rejects in full, and nothing +in-process would notice. + +One more hook is worth wiring, because middleware cannot reach it. The +transport answers over-limit requests (413/431) itself, while the parser is +still reading and before any handler chain exists — so `RecordMetrics` never +sees them and an over-limit flood would be invisible in the counters: + +```cpp +options.on_rejected = smithy::server::RecordRejections(metrics); +``` + +These count as requests (`route="unmatched"`, with `413`/`431` as the +signature) but file no latency and never move the in-flight gauge: a request +refused at parse time has no service latency to report, and recording it as a +zero observation would drag `rate(_sum)/rate(_count)` down — flattering the +latency panel during exactly the flood it should be exposing. Because they +are counted and not timed, a route that only ever saw rejections appears in +the request counters with no histogram series at all. A method that never +parsed (a 431 can fire mid-headers) is labeled `(unparsed)` rather than +`CUSTOM`, since "never parsed" and "client invented a verb" are different +diagnoses. + +The endpoint is unauthenticated: it is middleware, so gate it the way you +gate anything else — compose `Guard` or `RequireBearerAuth` outside it, or +bind the scrape listener somewhere the internet cannot reach. + **OpenTelemetry:** not bundled, by design — opentelemetry-cpp's dependency tree (protobuf, gRPC for OTLP) would violate the runtime's dep-light rule. The hooks above map 1:1 onto OTel spans and metrics; an optional diff --git a/docs/working-agreement.md b/docs/working-agreement.md index 0515cb0..ebe57ea 100644 --- a/docs/working-agreement.md +++ b/docs/working-agreement.md @@ -6,11 +6,49 @@ rediscovering the same conventions. This is process, not architecture. Architecture lives in `docs/adr/`. +The same agreement is kept in MoonBase (`docs/WORKING_AGREEMENT.md`), and +improvements flow both ways. Where a convention there has no analogue here it +has been dropped rather than restated aspirationally, and where the tooling +differs this repo's command is the one named. + ## Shipping a change -**One item, one PR.** Work items come off a tracking issue (e.g. #109, the -Core Guidelines conformance review). Take the highest-severity open item, -finish it, ship it, then take the next. Don't batch unrelated fixes. +**One item, one PR — a default, not a law.** Work items come off a tracking +issue. Take the highest-severity open item, finish it, ship it, then take the +next. What the rule protects is a reviewer's ability to hold the whole change +at once, so judge a candidate against that rather than against a file count. It +binds hardest on genuinely independent work: two features, or a refactor riding +along with a fix. + +A causal chain is one item. A fix, the regeneration it forces, and the golden +diff that follows cannot land separately — the generator change alone leaves +the checked-in goldens contradicting it, and CI fails on exactly that. + +Work too small to be worth splitting is fine too: a one-line doc fix noticed in +passing does not need its own branch, review and CI cycle. And when you carry a +genuine second item because splitting would cost more than it saves, name it in +the PR body so the reviewer can ask for it to come out. + +**Fold review feedback into the PR it came from.** When a review turns up +something small — a doc line that now contradicts itself, an assertion that +doesn't bite, a name that misleads — fix it in that PR. Don't file it. An issue +for a twenty-line fix costs more to write, triage, schedule and re-explain than +the fix does, and it lands on a reader who no longer has any of the context +that made the finding obvious. + +This looks like a tension with "one item, one PR", and it resolves toward +folding, because the two rules protect against different costs and only one of +them is expensive here. Batching unrelated work makes a PR hard to review; that +is what the first rule is for. But a finding that came *out of* this review is +not unrelated to it — it is the review working. Splitting it out buys nothing +and spends the scarcest thing in the process: a reviewer who has the code +loaded right now. + +Reach for a separate issue when the answer is genuinely unrelated to the change +under review, or when it is large enough to need its own design conversation. +"It wasn't in the original scope" is not one of them, and neither is "the +commit would touch a third file." When in doubt, fold it in and say in the PR +that you did. **Altitude review first.** Before writing any code: read the cited code, confirm the finding is actually real (several tracked items turned out to be @@ -23,32 +61,100 @@ minimal version and a thorough version that lead to genuinely different work, ask — with a recommendation, not a survey. If they only differ cosmetically, pick the obvious one and say so. +**Question the request itself, not just how to build it.** Before implementing, +step back once and ask whether the framing is right. A request describes a +symptom the reporter noticed; it is not automatically the best response to that +symptom, and the person asking usually hasn't seen the constraint you're about +to read in the code. + +Issue #130 is the worked example. It named a design question to settle first — +whether a timed-out receive should stash the late message or cancel the parked +one — and treated it as the hard part. Reading the transports dissolved it: +both already land inbound messages in per-session state and hand them to +whoever receives next, so timing out a *parked callback* releases the slot +without touching the wire, the read pump, or any in-flight message. There was +no stash to build and no cancellation primitive to invent. Answering the +question as posed would have added per-session state the socket layer already +had. + +Raise the alternative in a sentence or two, give a recommendation, and proceed +— don't stall. If it turns out to be the better design, that is a much cheaper +discovery before the code exists than after. + **Don't open a PR unless asked.** Commit and push when the work is done; open the PR only on request. Reference the tracking issue and, when the issue is a checklist, tick the item once merged. **Update the tracking issue.** Fold new data (reproductions, measurements, -scope corrections) back into the issue so it stays the source of truth. - -## Review panel +scope corrections) back into the issue so it stays the source of truth. File +follow-ups for what you deliberately left out rather than leaving it implicit. -Before committing anything non-trivial, run a self-review panel: +**What goes in commit messages, comments and PR bodies is one set of rules**, +and they live under "Writing it down" below. -- **Three independent agents, three distinct lenses.** Typically correctness - and control flow; concurrency, threading, and resource safety; and - tests/docs/CI-gates. The lenses should barely overlap. -- **Each agent hunts, then tries to refute its own findings** before - reporting. This is what keeps the signal-to-noise usable. -- **Verify the survivors yourself** before acting on them. Agents are - sometimes confidently wrong; don't take a finding at face value. - -The panel has earned its cost — it caught a real defect on several -consecutive PRs (an INT64_MIN decompose UB, a keep-alive framing gap, an -unguarded WebSocket upgrade target, and two libraries missing from a new CI -gate). +## Review panel -**If the panel didn't run, say so.** A restart or an interrupt can kill it. -Report that plainly rather than letting the reader assume the step happened. +Push the work — and open the PR, where one is being opened — then run a +self-review panel against that head. + +Panelling before the first commit hides the step. Its findings get folded into +the same diff, so nothing in the PR says what the panel caught, what it got +wrong, or whether it ran at all — the reader is asked to take the claim on +trust. Opened first, every fix the panel produces is a commit on top of a +baseline CI has already judged, and the history is the evidence: this was +found, this changed because of it, this was reported and deliberately not acted +on. + +It also gets the panel better inputs. The agents can read the PR body and the +CI result rather than a working tree, and a finding can be checked against a +known-green head instead of against a tree that has never been built anywhere +but here. Where no PR is being opened, the pushed branch is the baseline. + +None of that licenses pushing a draft for the panel to finish. Push work you +would defend as it stands; the panel is the second opinion on a finished +change, not the first pass over an unfinished one. + +The panel itself: + +- **Four independent agents, four distinct lenses.** Typically correctness and + control flow; concurrency, threading, and resource safety; tests, docs, and + CI gates; and altitude. The lenses should barely overlap. +- **The altitude lens re-asks the pre-code question of the finished diff.** Is + this change at the right level, or a patch over a symptom of something + bigger? Does each new abstraction earn its keep, and would less code do? The + other lenses stare at what the diff does; this one asks whether it should + exist in this shape at all — the review most likely to be skipped, precisely + because nothing is "wrong." +- **Panel agents read; they never write.** No edits, no "revert it and see what + happens" — not even a change the agent fully intends to undo. The panel runs + several agents at once over the same files, so one agent's scratch mutation + is another's mystery failure; an agent that dies mid-run leaves deliberately + broken code in the tree; and a dirty tree invites a commit that ships the + mutation. An agent that wants to know whether a test bites reports that as a + finding instead of finding out. +- **Enforce read-only structurally, not by instruction.** Convene panels on an + agent type without edit or write tools, and keep write-shaped questions out + of the briefs — "verify this test fails on the old code" is an instruction to + mutate the tree no matter how firmly the same brief says never to. +- **Each agent hunts, then tries to refute its own findings** before reporting. + This is what keeps the signal-to-noise usable. +- **Verify the survivors yourself** before acting on them. Agents are sometimes + confidently wrong; don't take a finding at face value. +- **Aggregation is where the writing happens.** Every surviving finding not + already covered gets a test — positive *and* negative — including the + findings you decide *not* to act on, where the test pins the behavior you + chose to keep so the next reader doesn't reopen the question. Mutation + checking belongs here too: it needs a clean tree and a single writer. + +The panel has earned its cost — it caught a real defect on several consecutive +PRs (an INT64_MIN decompose UB, a keep-alive framing gap, an unguarded +WebSocket upgrade target, two libraries missing from a new CI gate, and a +`std::thread` spawn that could throw beside a still-armed park, which from a +coroutine is a use-after-free). + +**If the panel didn't run, say so.** A restart, an interrupt, or simply +forgetting can kill it. Report that plainly rather than letting the reader +assume the step happened. **Answer review questions with tests, not paragraphs.** See below — this is the single highest-leverage rule in this document. @@ -134,69 +240,181 @@ every level that fits the behavior: - **integration** — the behavior through the real wire, transport, or codec, - **out-of-tree consumer example** — where the behavior is part of the contract a consumer depends on, prove it through the module boundary the - way a consumer would actually hit it. + way a consumer would actually hit it. That means raw bytes and raw frames + where the contract is a wire contract, not a round trip through generated + types that regenerate on both sides and hide a rename. An untested observable behavior is not a guarantee; it is a coincidence that currently holds. -**TDD for bug fixes.** Write the failing test first, watch it fail for the -right reason, then fix it. - -**Consumer and e2e tests that flex the feature, not smoke tests.** New -functionality needs a test in the out-of-tree consumer module -(`examples/bazel-consumer`) that actually demonstrates it working through the -module boundary — the way a real consumer would use it. - -**Fuzz targets for anything that parses.** Decoders, framing, URIs, headers, -compression. See `docs/fuzzing.md`. - -**Mutation-test negative and security tests.** A test asserting that -something is *rejected* must be proven to fail when the property it pins is -broken — temporarily remove the check, confirm that exact test fails with its -own message, then restore. A test that passes for the wrong reason is worse -than no test, because it advertises coverage that isn't there. This is how -the client TLS hostname and version-floor tests were validated. +**Test through the same objects production uses.** A wire test that builds its +own serializer is testing the serializer it built. Pull the real one — the +generated router, the real transport, the production codec — and when "the real +one" is itself an inference, add one test that reads the actual bytes off a +real server. The consumer-side metrics test exists for exactly this: in-tree the +endpoint is driven by hand-written handlers that stamp the operation label +themselves, so those tests would keep passing if the generated router stopped +stamping it. + +**TDD, nearly always — not just for bug fixes.** Write the test first, watch it +fail for the right reason, then write the code. This is the default for +features as much as for fixes; the exceptions are narrow (a spike you intend to +throw away, a pure rename) and "I already know what this does" is not one of +them. + +The reason is design, not discipline. Writing the expectation first forces the +question "what should this do, and how would anyone tell?" while the answer is +still cheap to change — before an interface exists to be accommodated. Tests +written afterwards answer a different question: "what does this code do?" They +inherit the shape of whatever was built, including the parts that are awkward +to observe, and they are systematically blind to the case the implementation +forgot, because they were derived from it. + +**Mutation checking is not a substitute for writing the test first.** It is +worth doing and it answers a genuinely useful question, but a much narrower +one: *does this assertion, as written, bite right now?* It cannot tell you the +assertion is the right one, and it cannot recover a case nobody thought to +assert, because it only mutates code that exists to break tests that exist. +Reaching for it to justify tests written after the fact is the failure it looks +most like a fix for. + +**Mutation-test negative and security tests.** A test asserting that something +is *rejected* must be proven to fail when the property it pins is broken — +temporarily remove the check, confirm that exact test fails with its own +message, then restore. A test that passes for the wrong reason is worse than +no test, because it advertises coverage that isn't there. This is how the +client TLS hostname and version-floor tests were validated. **Prove isolation with a control.** When a negative test asserts a failure, add the positive twin that shares the fixture (e.g. the same hand-built listener, one version higher) so a broken fixture can't masquerade as the property holding. +**Fuzz targets for anything that parses.** Decoders, framing, URIs, headers, +compression. See `docs/fuzzing.md`. + +**Consumer and e2e tests that flex the feature, not smoke tests.** New +functionality needs a test in the out-of-tree consumer module +(`examples/bazel-consumer`) that actually demonstrates it working through the +module boundary — the way a real consumer would use it. + **Re-run timing-sensitive tests.** Anything with threads or sockets gets `--runs_per_test=15` or so before it's trusted. -## Verification before pushing +**Watch for tests that don't actually run.** A `--test_filter` that matches +nothing exits green, and so does a suite whose new file never made it into +`srcs`. When a run "passes" the first time on a test you expected to be hard, +check the count: `--test_output=all` and read the `N tests from M test suites +ran` line before believing it. -Run these, and don't report success on a step that didn't run: +## Verification before pushing -- `clang-format` on every changed `.h`/`.cc` -- `clang-tidy` on changed `.cc` — this is a **separate CI job** from the - Makefile's `lint` target, and it has failed PRs that were otherwise clean - (e.g. `readability-use-anyofallof` on hand-rolled scan loops) -- `buildifier` for changed BUILD files -- the full runtime suite -- sanitizers: asan/ubsan, plus tsan for anything touching concurrency -- `make noexcept` — the ADR-0003 `-fno-exceptions` gate -- the consumer module where it's reachable +| Step | Command | Gated in CI? | +|---|---|---| +| C++ formatting | `clang-format` on every changed `.h`/`.cc` | yes — `lint` | +| BUILD formatting | `npx -y @bazel/buildifier@8.2.1 --lint=warn --mode=check -r .` | yes — `lint` | +| clang-tidy | `make tidy` | yes — `lint` | +| Runtime suite | `bazel test //...` | yes — `bazel (…)`, four toolchains | +| Lockfile freshness | `make lockfiles` | yes — `lockfiles` | +| Codegen + goldens | `make codegen goldens` | yes — `codegen (gradle)` | +| Sanitizers | `make sanitize`, plus tsan for concurrency | yes — `bazel (asan + ubsan, …)` | +| Exceptions-disabled gate | `make noexcept` | yes — `bazel (-fno-exceptions runtime)` | +| Consumer module | `bazel test //...` in `examples/bazel-consumer` | yes — `bazel consumer (…)` | +| Fuzz harnesses | `make fuzz-smoke` | yes — `fuzz (libFuzzer smoke)` | + +`make verify` covers formatting, the runtime suite, lockfiles, and +codegen+goldens. `make verify-full` adds clang-tidy, the sanitizers, the +exceptions-disabled gate, the consumer module, and the fuzz harnesses. Note +that `make lint` shells out to a system `buildifier`, which the sandbox does +not have — the `npx` invocation above is the one CI uses and the one that runs +here. + +**Check the exit code, not the tail of the output.** `make verify 2>&1 | tail` +reports *tail's* status, so a failed step scrolls past and the pipeline exits +0. That is how `make verify` got reported as passing twice in one session while +`lint` was aborting on a missing `buildifier` binary. Run the command bare, or +check `${PIPESTATUS[0]}`. + +**CI is cheaper than model tokens.** The table is what CI will run, not a gate +every session must reproduce end to end before pushing. Run the fast checks — +the formatters, the tests beside the change — and push; a cold Bazel build of +half the repo costs more session time than the CI cycle it duplicates, and the +branch is where CI's answer lands anyway. This tunes economics, not honesty: +say exactly what ran locally and what is riding on CI, treat a red result as +work now, and never claim a step ran when it didn't. It also doesn't license +pushing what nothing checked — a change that never compiled anywhere is a +guess, not a candidate. + +**New source files must be added to `srcs` and `hdrs` by name.** Nothing globs +here, so a file that isn't listed doesn't compile and its tests don't run. **Be explicit about what couldn't be verified locally, and why.** The sandbox has a pre-existing `rules_android` resolution failure in `//codegen`'s JVM -plugin that blocks consumer targets needing generated code. When you hit a -limitation like that, *prove it's pre-existing* by reproducing it with your -changes stashed, then say so in the PR body. CI runs those jobs natively. +plugin that blocks consumer targets needing generated code, the proxy 403s +GitHub source archives that most BCR modules fetch (`bazel/make-git-overrides.sh` +rebuilds those from git clones — run it before concluding a target is +unbuildable here), and the clang sanitizer runtime is absent, so CI's +clang asan+ubsan combination can only be approximated with the gcc ones. When +you hit a limitation like that, *prove it's pre-existing* by reproducing it +with your changes stashed, then say so in the PR body. ## Docs and changelog - Update docs in the same PR as the code: ADRs, guides, public header contract comments. - Add a CHANGELOG entry. -- **If a change alters an ADR's stated posture, amend the ADR.** Leaving an - ADR contradicting the code is a defect in its own right — ADR-0003 was +- **When behavior changes, fix the doc that describes it in the same commit.** + A doc left contradicting the code is a defect in its own right. +- **If a change alters an ADR's stated posture, amend the ADR.** ADR-0003 was amended when contract violations moved from `throw` to fail-fast, and again when recoverable config moved to an `Outcome`. - Keep the claims accurate. Don't write that something is covered "everywhere" when a subtree is deliberately excluded; name the exclusion. +## Writing it down + +**No archeology in comments.** A comment describes the code as it is, not how +it got there. No "used to", no "previously", no retelling of the bug that +prompted the line. Git has the history, and a comment narrating a deleted +alternative ages into a lie the moment someone edits around it. + +A live trap is not archeology. `beast_transport.cc`'s "`empty_body`, not a +`string_body` with the body cleared out" earns its place because clearing the +body is the obvious wrong turn and the failure is a silent hang — that warns +about the code in front of you rather than recounting a previous attempt. + +**A comment must not claim a property the code doesn't have.** A comment +describing the guarantee the author meant to build rather than the one that +shipped is worse than no comment: it makes a vacuous assertion look +deliberate. When the code changes underneath a comment, the comment is part of +the change. + +**Comments are terse and present-tense.** A comment states a constraint the +code can't show, in a sentence or two. Keep the *why* — one line of why beats +five of history. + +**Commit messages under 100 words, usually well under.** What changed and why, +in the fewest words that carry it; a one-line subject is often the whole job. +No narrated account of the session: no mutation-check kill lists, no "written +before the change and observed red", no confession that the panel didn't run. +That material is real, and its home is the PR body or the tests. + +This repo merges with merge commits, so every branch commit keeps its own +message in `git log` forever. A bloated message is bloat in the history of +every future `git log` and `git blame` that walks through it. If the short +paragraph keeps growing, that is a sign the *change* should have been split, +not that the message needs more room. + +**Terse PR bodies.** The change, the consequences a reviewer cannot see from +the diff, and what is deliberately not covered. Nothing else. The body is +spent entirely on reviewer attention, which is the scarcest thing in the +process. + +**No journaling in any artifact.** "My first attempt", "this turned out to +be", "I then found" — none of that belongs in code, commit messages, or PR +bodies. A finding from a review lives in the review thread; the artifact +carries only the conclusion. + ## Dependencies and infrastructure **Re-check assumed limitations instead of repeating them.** A limitation @@ -216,6 +434,14 @@ security-sensitive dependency, also ask what the existing tests actually *assert* (a posture test that checks the negotiated cipher is worth far more than one that checks the connection succeeded). +**A bump that clears an advisory may need more than the version number.** Read +the advisory's affected range against the available versions rather than taking +a proposed bump at face value; an in-range bump sometimes cannot clear the +advisory at all. + +**Bumps have fallout beyond compilation.** A build that still succeeds is not +the whole answer — run what the change touches, not just its tests. + ## Communication - Raise a concern in a sentence or two, then proceed with the work. Don't @@ -235,3 +461,6 @@ than one that checks the connection succeeded). directly, leaving the PR object open with phantom conflicts. Before believing a conflict, check whether the PR head is already an ancestor of `origin/main`; a push to the branch un-wedges it. +- **Never commit `MODULE.bazel.lock` churn** produced by the sandbox module + overrides — they run under `--lockfile_mode=off` for exactly that reason, + and `make lockfiles` is what CI checks the real lockfiles against. diff --git a/examples/bazel-consumer/BUILD.bazel b/examples/bazel-consumer/BUILD.bazel index fa92497..8090047 100644 --- a/examples/bazel-consumer/BUILD.bazel +++ b/examples/bazel-consumer/BUILD.bazel @@ -130,6 +130,38 @@ cc_test( # wiring), including the handler-executor and throwing-handler paths. Behind # a download-blocking proxy exclude it like the main repo's Beast targets: # bazel test //... -- -//:todo_beast_acceptance_test +cc_test( + name = "metrics_acceptance_test", + size = "small", + srcs = ["metrics_acceptance_test.cc"], + copts = SMITHY_COPTS, + deps = [ + ":todo_client", + ":todo_server", + "@googletest//:gtest_main", + "@smithy_cpp//runtime:client", + "@smithy_cpp//runtime:http", + "@smithy_cpp//runtime:http_beast", + "@smithy_cpp//runtime:server", + ], +) + +cc_test( + name = "access_log_acceptance_test", + size = "small", + srcs = ["access_log_acceptance_test.cc"], + copts = SMITHY_COPTS, + deps = [ + ":todo_client", + ":todo_server", + "@googletest//:gtest_main", + "@smithy_cpp//runtime:client", + "@smithy_cpp//runtime:http", + "@smithy_cpp//runtime:http_beast", + "@smithy_cpp//runtime:server", + ], +) + cc_test( name = "todo_beast_acceptance_test", size = "small", diff --git a/examples/bazel-consumer/access_log_acceptance_test.cc b/examples/bazel-consumer/access_log_acceptance_test.cc new file mode 100644 index 0000000..d2613e3 --- /dev/null +++ b/examples/bazel-consumer/access_log_acceptance_test.cc @@ -0,0 +1,298 @@ +// The access log a consumer actually writes, from outside the module (#202). +// +// What only this level proves: that `RequestObservation` carries enough to BE +// an access log, on the composition the production guide teaches, over a real +// socket. In-tree the fields are pinned on a hand-driven chain — no generated +// router, no transport-stamped peer, no rate limiter beside it — so every one +// of them could be deleted without a consumer file noticing. +// +// The claim under test is the one #202 was opened for: the client an +// observation reports is the same one `PerClientRateLimit` keyed on, so "whose +// bucket did that 429 come from" is answerable from the log. That needs the +// same `TrustedProxies` handed to both, which is the step the guide's snippet +// used to omit. +// +// `Observe` is composed OUTSIDE the limiter here, deliberately. The limiter +// short-circuits, so a 429 never reaches middleware below it — and the 429 is +// exactly the request whose client you want logged. Put the limiter outermost +// instead and the rejections are invisible to the log. + +#include + +#include +#include +#include +#include + +#include "acme/todo/client.h" +#include "acme/todo/server.h" +#include "smithy/client/config.h" +#include "smithy/http/beast_transport.h" +#include "smithy/http/forwarded.h" +#include "smithy/server/middleware.h" + +namespace { + +using acme::todo::AddTaskInput; +using acme::todo::AddTaskOutput; +using acme::todo::GetTaskInput; +using acme::todo::GetTaskOutput; +using acme::todo::TodoClient; +using acme::todo::TodoHandler; +using acme::todo::TodoServer; + +// One access-log record, which is all four of the #202 fields plus what was +// already there. A real sink would render this as JSON (#203); recording it +// verbatim is what lets the test assert on it. +struct LogLine { + std::string method; + std::string route; + int status = 0; + std::size_t request_bytes = 0; + std::size_t response_bytes = 0; + bool handler_threw = false; + std::string client; + smithy::http::DerivedClient::Source client_source = smithy::http::DerivedClient::Source::kUnknown; +}; + +class AccessLog { + public: + void Write(const smithy::server::RequestObservation& o) { + const std::lock_guard lock(mutex_); + lines_.push_back(LogLine{.method = o.method, + .route = o.operation, + .status = o.status, + .request_bytes = o.request_bytes, + .response_bytes = o.response_bytes, + .handler_threw = o.handler_threw, + .client = o.client.address, + .client_source = o.client.source}); + } + std::vector lines() const { + const std::lock_guard lock(mutex_); + return lines_; + } + + private: + mutable std::mutex mutex_; + std::vector lines_; +}; + +// Records every key the limiter was asked to admit, so the test can compare +// the log's client against the bucket rather than against a literal. +class RecordingLimiter { + public: + explicit RecordingLimiter(int budget) : budget_(budget) {} + bool Allow(const std::string& client) { + const std::lock_guard lock(mutex_); + keys_.push_back(client); + return --budget_ >= 0; + } + std::vector keys() const { + const std::lock_guard lock(mutex_); + return keys_; + } + + private: + mutable std::mutex mutex_; + int budget_; + std::vector keys_; +}; + +class ThrowingOnDemandHandler final : public TodoHandler { + public: + smithy::Outcome AddTask(const AddTaskInput& input, + const smithy::server::RequestContext&) override { + if (input.title == "boom") { + throw std::runtime_error("handler exploded"); + } + return AddTaskOutput{.taskId = "task-1", .title = input.title}; + } + + smithy::Outcome GetTask(const GetTaskInput&, + const smithy::server::RequestContext&) override { + return GetTaskOutput{.taskId = "task-1", .title = "stored"}; + } +}; + +class AccessLogAcceptanceTest : public ::testing::Test { + protected: + void SetUp() override { Start(/*observe_trusts_the_proxy=*/true); } + + // The limiter always gets the real trust boundary. `Observe` gets it only + // when asked — the negative control below starts a server without it, which + // is the wiring the production guide's snippet used to teach. + void Start(bool observe_trusts_the_proxy) { + // The loopback peer is 127.0.0.1, so trusting it makes this connection + // look like one arriving through a proxy — the topology the derivation + // exists for. + auto trusted = smithy::http::TrustedProxies::Parse({"127.0.0.0/8"}); + ASSERT_TRUE(trusted.ok()) << trusted.error().message(); + const smithy::http::TrustedProxies observe_trust = + observe_trusts_the_proxy ? *trusted : smithy::http::TrustedProxies::None(); + + log_ = std::make_shared(); + limiter_ = std::make_shared(kBudget); + server_ = std::make_unique(std::make_shared()); + transport_ = std::make_unique( + smithy::http::BeastServerTransport::Options{.threads = 1, .handler_threads = 2}); + + auto log = log_; + auto limiter = limiter_; + ASSERT_TRUE( + transport_ + ->Start(smithy::server::Chain( + {// Outermost, so a rejected request is still logged with the + // client it was rejected for. + smithy::server::Observe( + [log](const smithy::server::RequestObservation& o) { log->Write(o); }, nullptr, + nullptr, observe_trust), + smithy::server::PerClientRateLimit( + [limiter](const std::string& client) { return limiter->Allow(client); }, + *trusted, std::chrono::seconds(1))}, + server_->Handler())) + .ok()); + } + + void TearDown() override { transport_->Stop(); } + + // A request carrying an x-forwarded-for, the way one arrives through a + // proxy. The client is the header's entry; the peer is the proxy. + smithy::Outcome SendForwarded(const std::string& body) { + smithy::http::BeastHttpClient raw({.host = "127.0.0.1", .port = transport_->port()}); + smithy::http::HttpRequest request; + request.method = "POST"; + request.target = "/tasks"; + request.headers.Set("content-type", "application/json"); + request.headers.Set("x-forwarded-for", kForwardedClient); + request.body = body; + return raw.Send(request); + } + + static constexpr int kBudget = 2; + static constexpr const char* kForwardedClient = "203.0.113.7"; + + std::shared_ptr log_; + std::shared_ptr limiter_; + std::unique_ptr server_; + std::unique_ptr transport_; +}; + +TEST_F(AccessLogAcceptanceTest, TheLoggedClientIsTheBucketTheLimiterKeyedOn) { + // The #202 claim, end to end. Both are handed the same TrustedProxies, so + // the log can answer a question about the limiter's decision. Given + // different boundaries — or none, which is what the guide's snippet used to + // copy — these two disagree and the log names the proxy. + const auto served = SendForwarded(R"({"title":"ship it"})"); + ASSERT_TRUE(served.ok()) << served.error().message(); + ASSERT_EQ(served->status, 200); + + const auto lines = log_->lines(); + ASSERT_EQ(lines.size(), 1u); + const auto keys = limiter_->keys(); + ASSERT_EQ(keys.size(), 1u); + + EXPECT_EQ(lines[0].client, keys[0]) + << "the log names a different client than the limiter keyed on"; + EXPECT_EQ(lines[0].client, kForwardedClient); + // Not the peer, which is what the raw header or an unconfigured Observe + // would have reported. + EXPECT_NE(lines[0].client, "127.0.0.1"); + EXPECT_EQ(lines[0].client_source, smithy::http::DerivedClient::Source::kForwarded); +} + +TEST_F(AccessLogAcceptanceTest, ARejectionIsLoggedWithTheClientItWasRejectedFor) { + // "Whose bucket did that 429 come from" — unanswerable before #202, because + // the observation carried only the raw header, which is not what the + // limiter keys on. + for (int i = 0; i < kBudget; ++i) { + ASSERT_TRUE(SendForwarded(R"({"title":"ok"})").ok()); + } + const auto rejected = SendForwarded(R"({"title":"over"})"); + ASSERT_TRUE(rejected.ok()) << rejected.error().message(); + EXPECT_EQ(rejected->status, 429); + + const auto lines = log_->lines(); + ASSERT_EQ(lines.size(), static_cast(kBudget) + 1); + const LogLine& last = lines.back(); + EXPECT_EQ(last.status, 429); + EXPECT_EQ(last.client, kForwardedClient); + EXPECT_EQ(last.client, limiter_->keys().back()); + // The limiter short-circuits, so the request never reached the router. + EXPECT_EQ(last.route, ""); +} + +TEST_F(AccessLogAcceptanceTest, ByteCountsComeFromTheRealWireBodies) { + const std::string body = R"({"title":"ship it"})"; + const auto served = SendForwarded(body); + ASSERT_TRUE(served.ok()) << served.error().message(); + + const auto lines = log_->lines(); + ASSERT_EQ(lines.size(), 1u); + EXPECT_EQ(lines[0].request_bytes, body.size()); + EXPECT_EQ(lines[0].response_bytes, served->body.size()); + EXPECT_GT(lines[0].response_bytes, 0u); + EXPECT_EQ(lines[0].route, "AddTask") << "the route came from the generated router"; +} + +TEST_F(AccessLogAcceptanceTest, AThrownHandlerIsLoggedAsThrownThroughBeastContainment) { + // The transport contains the throw and answers 500. A deliberate 500 looks + // identical on the wire, so handler_threw is the only thing that separates + // "we crashed" from "we said no" — and it has to survive the transport's + // containment, not just an in-process rethrow. + const auto boom = SendForwarded(R"({"title":"boom"})"); + ASSERT_TRUE(boom.ok()) << boom.error().message(); + EXPECT_EQ(boom->status, 500); + + const auto lines = log_->lines(); + ASSERT_EQ(lines.size(), 1u); + EXPECT_TRUE(lines[0].handler_threw); + EXPECT_EQ(lines[0].status, 500); + // No response was built, so there are no body bytes to report — which is + // what makes handler_threw the thing that reads it as an absence. + EXPECT_EQ(lines[0].response_bytes, 0u); + // And the client is still there: a 500 is exactly when you want to know + // who was calling. + EXPECT_EQ(lines[0].client, kForwardedClient); +} + +// The negative control for TheLoggedClientIsTheBucketTheLimiterKeyedOn. +// +// A passing test only means something if it can fail, and the way this one +// fails is a wiring mistake rather than a code change — so the mistake is +// wired up here and its symptom asserted, instead of being a claim in a +// commit message that has to be re-verified by hand. +// +// This is exactly what the production guide's chain used to teach: the trust +// boundary handed to `PerClientRateLimit` and not to `Observe`. +class MisconfiguredAccessLogTest : public AccessLogAcceptanceTest { + protected: + void SetUp() override { Start(/*observe_trusts_the_proxy=*/false); } +}; + +TEST_F(MisconfiguredAccessLogTest, ObserveWithoutTheTrustBoundaryLogsTheProxy) { + const auto served = SendForwarded(R"({"title":"ship it"})"); + ASSERT_TRUE(served.ok()) << served.error().message(); + ASSERT_EQ(served->status, 200); + + const auto lines = log_->lines(); + ASSERT_EQ(lines.size(), 1u); + const auto keys = limiter_->keys(); + ASSERT_EQ(keys.size(), 1u); + + // The symptom: the log names the proxy, the limiter keyed on the client, + // and nothing anywhere reports an error. Both numbers look plausible on + // their own — which is why the positive test compares them to each other + // rather than to literals. + EXPECT_EQ(lines[0].client, "127.0.0.1"); + EXPECT_EQ(keys[0], kForwardedClient); + EXPECT_NE(lines[0].client, keys[0]) + << "the misconfiguration stopped being observable, so the positive test " + "can no longer fail and has stopped proving anything"; + // TrustedProxies::None() is the deliberate direct-connect statement, so the + // peer IS the client and the header is ignored wholly — correct behavior + // for that configuration, and the wrong configuration for this deployment. + EXPECT_EQ(lines[0].client_source, smithy::http::DerivedClient::Source::kUntrustedHeaderIgnored); +} + +} // namespace diff --git a/examples/bazel-consumer/metrics_acceptance_test.cc b/examples/bazel-consumer/metrics_acceptance_test.cc new file mode 100644 index 0000000..62c6422 --- /dev/null +++ b/examples/bazel-consumer/metrics_acceptance_test.cc @@ -0,0 +1,382 @@ +// The Prometheus endpoint (issue #91) from the consumer's side of the module +// boundary: the generated Todo service on BeastServerTransport, wrapped in the +// exact middleware chain docs/production-guide.md teaches, scraped over a real +// socket. +// +// What only this level proves is the `operation` label. In-tree the endpoint is +// driven by hand-written handlers that stamp `HttpResponse::operation` +// themselves, so those tests would keep passing if the generated router stopped +// stamping it — and the label would silently go empty for every request in +// every real deployment, collapsing per-operation dashboards into one anonymous +// bucket. Here the router is the generated one, so the label is the model's. + +#include + +#include +#include + +#include "acme/todo/client.h" +#include "acme/todo/server.h" +#include "smithy/client/config.h" +#include "smithy/http/beast_transport.h" +#include "smithy/server/metrics.h" +#include "smithy/server/middleware.h" + +namespace { + +using acme::todo::AddTaskInput; +using acme::todo::AddTaskOutput; +using acme::todo::GetTaskInput; +using acme::todo::GetTaskOutput; +using acme::todo::NoSuchTask; +using acme::todo::TodoClient; +using acme::todo::TodoHandler; +using acme::todo::TodoServer; + +// A handler that emits its own domain metrics alongside the built-in HTTP +// families — the reason MetricsRegistry hands out typed families rather than +// only serving what Observe feeds it. The handles are minted once and held; +// they are cheap to copy and address the same family. +class MetricsHandler final : public TodoHandler { + public: + explicit MetricsHandler(const std::shared_ptr& metrics) + : tasks_added_(metrics->NewCounter("todo_tasks_added_total", "Tasks added, by priority.")), + title_length_(metrics->NewHistogram("todo_title_length_chars", "Task title length.", + {8.0, 32.0, 128.0})), + tasks_stored_(metrics->NewGauge("todo_tasks_stored", "Tasks currently stored.")) { + // The priority label has a bounded, known-at-startup set, so both series + // are declared: without this the first task of each kind lands as a + // counter's first sample and increase() never sees it. + tasks_added_.Declare({{"priority", "set"}}); + tasks_added_.Declare({{"priority", "unset"}}); + tasks_stored_.Declare(); + } + + smithy::Outcome AddTask(const AddTaskInput& input, + const smithy::server::RequestContext&) override { + tasks_added_.Increment({{"priority", input.priority.has_value() ? "set" : "unset"}}); + title_length_.Observe(static_cast(input.title.size())); + tasks_stored_.Increment(); + return AddTaskOutput{.taskId = "task-1", .title = input.title}; + } + + smithy::Outcome GetTask(const GetTaskInput& input, + const smithy::server::RequestContext&) override { + smithy::Error error = smithy::Error::Modeled("NoSuchTask", "no task: " + input.taskId); + error.set_detail(NoSuchTask{.message = "no task: " + input.taskId}); + return error; + } + + private: + smithy::server::Counter tasks_added_; + smithy::server::Histogram title_length_; + smithy::server::Gauge tasks_stored_; +}; + +class MetricsAcceptanceTest : public ::testing::Test { + protected: + void SetUp() override { + Start(smithy::server::MetricsOptions{.enabled = true, .service_name = "todo-service"}); + } + + // Stands the service up under `options`, so a subclass can exercise a + // different dialect — or none at all — over the same real socket. + void Start(smithy::server::MetricsOptions options) { + metrics_ = std::make_shared(std::move(options)); + server_ = std::make_unique(std::make_shared(metrics_)); + transport_ = std::make_unique( + smithy::http::BeastServerTransport::Options{.threads = 1, .handler_threads = 4}); + // The composition the production guide documents, assembled here in + // consumer code against the published targets alone. + // The liveness probe sits INSIDE the recorder, so probe traffic is + // counted — the arrangement that makes its operation label matter. + ASSERT_TRUE(transport_ + ->Start(smithy::server::Chain({smithy::server::MetricsEndpoint(metrics_), + smithy::server::RecordMetrics(metrics_), + smithy::server::HealthEndpoint("/livez")}, + server_->Handler())) + .ok()); + + smithy::ClientConfig config; + config.endpoint = "http://127.0.0.1:" + std::to_string(transport_->port()); + auto http_client = smithy::http::BeastHttpClient::FromConfig(config); + ASSERT_TRUE(http_client.ok()) << http_client.error().message(); + config.http_client = *http_client; + auto client = TodoClient::Create(std::move(config)); + ASSERT_TRUE(client.ok()) << client.error().message(); + client_ = std::make_unique(std::move(*client)); + } + + void TearDown() override { transport_->Stop(); } + + // Scrapes /metrics the way Prometheus does: a plain GET, no generated code + // in the loop. + smithy::Outcome Scrape() { + smithy::http::BeastHttpClient raw({.host = "127.0.0.1", .port = transport_->port()}); + smithy::http::HttpRequest request; + request.method = "GET"; + request.target = "/metrics"; + return raw.Send(request); + } + + std::unique_ptr server_; + std::shared_ptr metrics_; + std::unique_ptr transport_; + std::unique_ptr client_; +}; + +TEST_F(MetricsAcceptanceTest, TheGeneratedRoutersOperationIsTheMetricLabel) { + ASSERT_TRUE(client_->AddTask(AddTaskInput{.title = "ship it"}).ok()); + ASSERT_TRUE(client_->AddTask(AddTaskInput{.title = "again"}).ok()); + const auto missing = client_->GetTask(GetTaskInput{.taskId = "nope"}); + ASSERT_FALSE(missing.ok()); + + const auto scrape = Scrape(); + ASSERT_TRUE(scrape.ok()) << scrape.error().message(); + EXPECT_EQ(scrape->status, 200); + EXPECT_EQ(scrape->headers.Get("content-type").value_or(""), + "text/plain; version=0.0.4; charset=utf-8"); + + const std::string& body = scrape->body; + // The route values come from the model, through the generated router — not + // from anything this test stamped. + EXPECT_NE(body.find(R"(route="AddTask")"), std::string::npos) << body; + EXPECT_NE(body.find(R"(route="GetTask")"), std::string::npos) << body; + EXPECT_NE( + body.find( + R"(http_server_requests_total{service_name="todo-service",http_method="POST",route="AddTask"} 2)"), + std::string::npos) + << body; + // The modeled error is served traffic too, and a failure by the 400 + // boundary the dashboards split on. + EXPECT_NE(body.find(R"(http_server_requests_failure_total{service_name="todo-service",)" + R"(http_method="GET",route="GetTask"} 1)"), + std::string::npos) + << body; + + // Latency was filed under the same operation label, with a real total. + EXPECT_NE( + body.find( + R"(http_server_request_duration_microseconds_count{service_name="todo-service",http_method="POST",route="AddTask"} 2)"), + std::string::npos) + << body; +} + +TEST_F(MetricsAcceptanceTest, ScrapesDoNotCountThemselvesAndLeaveNothingInFlight) { + ASSERT_TRUE(client_->AddTask(AddTaskInput{.title = "one"}).ok()); + ASSERT_TRUE(Scrape().ok()); + ASSERT_TRUE(Scrape().ok()); + + const auto scrape = Scrape(); + ASSERT_TRUE(scrape.ok()) << scrape.error().message(); + const std::string& body = scrape->body; + // MetricsEndpoint sits outside RecordMetrics, so three scrapes added no + // GET series of their own. + EXPECT_EQ(body.find(R"(http_method="GET")"), std::string::npos) << body; + // Every request that started also finished. + EXPECT_NE(body.find(R"(http_server_requests_active_gauge{service_name="todo-service",)" + R"(http_method="POST"} 0)"), + std::string::npos) + << body; +} + +TEST_F(MetricsAcceptanceTest, AnUnroutedRequestCountsWithAnEmptyOperation) { + // A 404 never reaches an operation, and its target — which is what varies + // without bound — must not become a label. + smithy::http::BeastHttpClient raw({.host = "127.0.0.1", .port = transport_->port()}); + smithy::http::HttpRequest request; + request.method = "GET"; + request.target = "/no/such/route/8f3a2b"; + const auto missed = raw.Send(request); + ASSERT_TRUE(missed.ok()) << missed.error().message(); + EXPECT_EQ(missed->status, 404); + + const auto scrape = Scrape(); + ASSERT_TRUE(scrape.ok()) << scrape.error().message(); + const std::string& body = scrape->body; + EXPECT_NE( + body.find( + R"(http_server_requests_total{service_name="todo-service",http_method="GET",route="unmatched"} 1)"), + std::string::npos) + << body; + EXPECT_EQ(body.find("8f3a2b"), std::string::npos) + << "the request target leaked into a label: " << body; +} + +TEST_F(MetricsAcceptanceTest, AHealthProbeIsItsOwnSeriesNotAnAnonymous404) { + // Over a real socket, out of tree: the orchestrator's probe and a request + // for a route the model does not define must not share a series. They both + // miss the generated router, and before HealthEndpoint stamped its path + // both reported `operation=""` — so a service polled every few seconds had + // its 404 rate buried under probe volume and no query could separate them. + smithy::http::BeastHttpClient raw({.host = "127.0.0.1", .port = transport_->port()}); + smithy::http::HttpRequest probe; + probe.method = "GET"; + probe.target = "/livez"; + const auto probed = raw.Send(probe); + ASSERT_TRUE(probed.ok()) << probed.error().message(); + EXPECT_EQ(probed->status, 200); + + smithy::http::HttpRequest unrouted; + unrouted.method = "GET"; + unrouted.target = "/livez-typo"; + ASSERT_TRUE(raw.Send(unrouted).ok()); + + const auto scrape = Scrape(); + ASSERT_TRUE(scrape.ok()) << scrape.error().message(); + const std::string& body = scrape->body; + EXPECT_NE( + body.find( + R"(http_server_requests_total{service_name="todo-service",http_method="GET",route="/livez"} 1)"), + std::string::npos) + << body; + EXPECT_NE( + body.find( + R"(http_server_requests_total{service_name="todo-service",http_method="GET",route="unmatched"} 1)"), + std::string::npos) + << body; + // And the probe's latency is its own, so a service p99 can exclude it. + EXPECT_NE( + body.find( + R"(http_server_request_duration_microseconds_count{service_name="todo-service",http_method="GET",route="/livez"} 1)"), + std::string::npos) + << body; +} + +TEST_F(MetricsAcceptanceTest, ApplicationMetricsShareTheEndpointWithTheBuiltIns) { + // What a consumer actually wants from a metrics endpoint: its own domain + // numbers on the same scrape as the HTTP families, so one Prometheus target + // covers the service. The handler minted these from the same registry the + // middleware serves. + ASSERT_TRUE(client_->AddTask(AddTaskInput{.title = "short"}).ok()); + ASSERT_TRUE(client_ + ->AddTask(AddTaskInput{.title = "a considerably longer task title", + .priority = acme::todo::Priority::kHigh}) + .ok()); + + const auto scrape = Scrape(); + ASSERT_TRUE(scrape.ok()) << scrape.error().message(); + const std::string& body = scrape->body; + + EXPECT_NE(body.find("# TYPE todo_tasks_added_total counter"), std::string::npos) << body; + EXPECT_NE(body.find(R"(todo_tasks_added_total{priority="unset"} 1)"), std::string::npos) << body; + EXPECT_NE(body.find(R"(todo_tasks_added_total{priority="set"} 1)"), std::string::npos) << body; + + EXPECT_NE(body.find("# TYPE todo_title_length_chars histogram"), std::string::npos) << body; + EXPECT_NE(body.find(R"(todo_title_length_chars_bucket{le="8"} 1)"), std::string::npos) << body; + EXPECT_NE(body.find("todo_title_length_chars_count 2"), std::string::npos) << body; + + EXPECT_NE(body.find("# TYPE todo_tasks_stored gauge"), std::string::npos) << body; + EXPECT_NE(body.find("todo_tasks_stored 2"), std::string::npos) << body; + + // Still one scrape: the built-in families are unaffected by the additions. + EXPECT_NE(body.find(R"(route="AddTask")"), std::string::npos) << body; +} + +TEST_F(MetricsAcceptanceTest, DeclaredSeriesAreOnTheScrapeBeforeAnyTraffic) { + // The zero baseline, end to end: a dashboard built against this service + // reads 0 from startup rather than finding no series at all, so the first + // task added is a visible step instead of an invisible one. + const auto scrape = Scrape(); + ASSERT_TRUE(scrape.ok()) << scrape.error().message(); + const std::string& body = scrape->body; + EXPECT_NE(body.find(R"(todo_tasks_added_total{priority="set"} 0)"), std::string::npos) << body; + EXPECT_NE(body.find(R"(todo_tasks_added_total{priority="unset"} 0)"), std::string::npos) << body; + EXPECT_NE(body.find("todo_tasks_stored 0"), std::string::npos) << body; +} + +TEST_F(MetricsAcceptanceTest, TheOutcomeCountersAndDurationCarryTheModelsRoute) { + ASSERT_TRUE(client_->AddTask(AddTaskInput{.title = "ship it"}).ok()); + ASSERT_FALSE(client_->GetTask(GetTaskInput{.taskId = "nope"}).ok()); + + const auto scrape = Scrape(); + ASSERT_TRUE(scrape.ok()) << scrape.error().message(); + const std::string& body = scrape->body; + + // Exactly the series prom_proxy's `{service_name="todo-service"}` queries + // select, with the route coming from the Smithy model. + EXPECT_NE(body.find(R"(http_server_requests_total{service_name="todo-service",)" + R"(http_method="POST",route="AddTask"} 1)"), + std::string::npos) + << body; + EXPECT_NE(body.find(R"(http_server_requests_success_total{service_name="todo-service",)" + R"(http_method="POST",route="AddTask"} 1)"), + std::string::npos) + << body; + // The modeled error is a failure by the 400 boundary the dashboards use. + EXPECT_NE(body.find(R"(http_server_requests_failure_total{service_name="todo-service",)" + R"(http_method="GET",route="GetTask"} 1)"), + std::string::npos) + << body; + EXPECT_NE(body.find(R"(http_server_request_duration_microseconds_count{)" + R"(service_name="todo-service",http_method="POST",route="AddTask"} 1)"), + std::string::npos) + << body; + EXPECT_NE(body.find("http_server_requests_active_gauge{service_name=\"todo-service\""), + std::string::npos) + << body; + // The registry's own health rides along, outside the contract. + EXPECT_NE(body.find("metrics_observations_dropped_total"), std::string::npos) << body; +} + +TEST_F(MetricsAcceptanceTest, TheProbeRouteThePanelsSubtractIsReported) { + // This fixture composes HealthEndpoint("/livez"), so the probe reports + // route="/livez". Under prom_proxy's fleet convention the endpoint would + // be composed on its default "/health" and the Probes tile would find it; + // what this pins is that the probe gets a route of its own rather than + // joining unmatched traffic, which is what makes the subtraction possible + // at all. + smithy::http::BeastHttpClient raw({.host = "127.0.0.1", .port = transport_->port()}); + smithy::http::HttpRequest probe; + probe.method = "GET"; + probe.target = "/livez"; + ASSERT_TRUE(raw.Send(probe).ok()); + + smithy::http::HttpRequest unrouted; + unrouted.method = "GET"; + unrouted.target = "/nope"; + ASSERT_TRUE(raw.Send(unrouted).ok()); + + const auto scrape = Scrape(); + ASSERT_TRUE(scrape.ok()) << scrape.error().message(); + const std::string& body = scrape->body; + EXPECT_NE(body.find(R"(http_server_requests_total{service_name="todo-service",)" + R"(http_method="GET",route="/livez"} 1)"), + std::string::npos) + << body; + // Unrouted traffic parks on the sentinel the rails agreed on — never the + // empty string, which `route!="/health"` would match into the serving + // numbers. + EXPECT_NE(body.find(R"(http_server_requests_total{service_name="todo-service",)" + R"(http_method="GET",route="unmatched"} 1)"), + std::string::npos) + << body; + EXPECT_EQ(body.find(R"(route="")"), std::string::npos) << body; +} + +// Off is the default, so this is what a consumer gets by linking the metrics +// stack without asking for it. +class DisabledMetricsAcceptanceTest : public MetricsAcceptanceTest { // NOLINT + protected: + void SetUp() override { Start(smithy::server::MetricsOptions{}); } +}; + +TEST_F(DisabledMetricsAcceptanceTest, TheScrapePathIsNotServedAndTheServiceStillWorks) { + // The endpoint composed away, so /metrics is just a path the model does + // not define. A 200 with an empty body would look to Prometheus like a + // healthy target reporting nothing — the same picture as a service whose + // metrics have gone silent. + const auto scrape = Scrape(); + ASSERT_TRUE(scrape.ok()) << scrape.error().message(); + EXPECT_EQ(scrape->status, 404); + EXPECT_EQ(scrape->body.find("http_server_"), std::string::npos) << scrape->body; + EXPECT_EQ(scrape->body.find("http_server_requests_total"), std::string::npos) << scrape->body; + + // And the recorder composed away too, without disturbing the service or + // the handler's own metric handles, which are inert rather than unusable. + const auto added = client_->AddTask(AddTaskInput{.title = "still works"}); + ASSERT_TRUE(added.ok()) << added.error().message(); + EXPECT_EQ(added->taskId, "task-1"); +} + +} // namespace diff --git a/runtime/BUILD.bazel b/runtime/BUILD.bazel index 83fad1e..2ccbaf1 100644 --- a/runtime/BUILD.bazel +++ b/runtime/BUILD.bazel @@ -574,12 +574,14 @@ cc_test( cc_library( name = "server", srcs = [ + "src/server/metrics.cc", "src/server/middleware.cc", "src/server/origin_gate.cc", "src/server/router.cc", "src/server/websocket_router.cc", ], hdrs = [ + "include/smithy/server/metrics.h", "include/smithy/server/middleware.h", "include/smithy/server/origin_gate.h", "include/smithy/server/router.h", @@ -630,6 +632,17 @@ cc_test( ], ) +cc_test( + name = "metrics_test", + size = "small", + srcs = ["tests/server/metrics_test.cc"], + copts = COPTS, + deps = [ + ":server", + "@googletest//:gtest_main", + ], +) + cc_test( name = "middleware_test", size = "small", diff --git a/runtime/include/smithy/http/message.h b/runtime/include/smithy/http/message.h index e96428f..d8820ab 100644 --- a/runtime/include/smithy/http/message.h +++ b/runtime/include/smithy/http/message.h @@ -38,7 +38,9 @@ struct HttpResponse { // Server-side annotation, never written to the wire: the Smithy operation // whose route produced this response (stamped by the generated router so // observability middleware can label by operation; empty on 404/405/400 - // dispatch failures and hand-rolled handlers). + // dispatch failures and hand-rolled handlers). Built-in endpoints that + // answer off-model paths (HealthEndpoint, MetricsEndpoint) stamp that path + // instead, so their traffic is distinguishable from a dispatch failure. std::string operation{}; }; diff --git a/runtime/include/smithy/server/metrics.h b/runtime/include/smithy/server/metrics.h new file mode 100644 index 0000000..ffb4c1b --- /dev/null +++ b/runtime/include/smithy/server/metrics.h @@ -0,0 +1,480 @@ +#ifndef SMITHY_SERVER_METRICS_H_ +#define SMITHY_SERVER_METRICS_H_ + +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include + +#include "smithy/core/fatal.h" +#include "smithy/server/middleware.h" + +namespace smithy::server { + +// A dependency-free Prometheus backend for the server hooks (issue #91). +// +// The runtime bundles no telemetry SDK by design (docs/production-guide.md), +// but the Prometheus text exposition format needs no client library at all — +// it is a few lines of text over HTTP. So the turnkey path is two middleware +// composed around the generated handler: RecordMetrics feeds a registry from +// the same Observe hook everything else uses, and MetricsEndpoint serves what +// the registry holds. +// +// auto metrics = std::make_shared( +// smithy::server::MetricsOptions{.enabled = true, +// .service_name = "todo-service"}); +// transport.Start(smithy::server::Chain({MetricsEndpoint(metrics), +// RecordMetrics(metrics), +// HealthEndpoint()}, +// server.Handler())); +// +// Order matters, and this one is deliberate: the endpoint sits OUTSIDE the +// recorder, so scrapes answer without being counted as served traffic. Put +// RecordMetrics first instead and every scrape inflates your own request +// rate — at whatever interval Prometheus polls. +// +// The five built-in families, labeled by service_name, http_method and route: +// +// http_server_requests_total counter +// http_server_requests_success_total counter (status < 400) +// http_server_requests_failure_total counter (status >= 400) +// http_server_requests_active_gauge gauge (no route; see below) +// http_server_request_duration_microseconds histogram (+ _sum/_count) +// +// plus `metrics_observations_dropped_total`, the registry's own health. +// +// This is not a vocabulary of our own invention. It is MoonBase's shared HTTP +// serving contract, spoken identically by its Java (yodel), Rust +// (server_pal), and C++ (futility/otel, behind aura) emitters and pinned +// across them by //domains/platform/libs/otel_contract — names, descriptions, +// label sets, route sentinels, and bucket boundaries alike. Those services +// are who scrapes this, and their dashboards (prom_proxy) query these names +// with these labels. A service here that invented its own spelling would +// simply not appear on them. +// +// So the exposition is deliberately NOT configurable. A knob here is a way +// for one service to drift off the contract, and the failure is silent: the +// dashboard renders an empty panel, which looks like a quiet service rather +// than a misconfigured one. If a second fleet ever needs a different dialect, +// that is the point to design one — not before. +// +// Consequences of the contract worth knowing before reading the code: +// +// - The status code is not a label. The outcome rides on the success and +// failure counters, which are two views of the same tally the total sums +// — so the three can never disagree, and no series is multiplied by the +// codes a service happens to return. +// - The active gauge carries no route. It moves at request start, before +// dispatch, where nothing bounded is known about the path; every rail +// leaves the route off it for that reason, and prom_proxy's negative +// `route!="/health"` matcher passes a series without the label through +// untouched, which is what makes the same filter safe on it. +// - Durations are microseconds, on the ladder the rails pin equal. +// `histogram_quantile` reads `le` off bucket counts, so a service on a +// different ladder charts a quantile computed against different bins +// than everything beside it. +// +// Application metrics join the same scrape through NewCounter / NewGauge / +// NewHistogram; see MetricsRegistry below. + +// The HTTP latency bucket boundaries, in microseconds (MoonBase #1286, +// pinned equal across its three emitter rails by +// //domains/platform/libs/otel_contract). Exported because an application +// histogram that measures a request-shaped duration should land on the same +// ladder; one measuring anything else should pass its own. +inline const std::vector& HttpLatencyBuckets() { + static const std::vector kBuckets = {100, 250, 500, 1000, 2500, + 5000, 10000, 25000, 50000, 100000, + 250000, 500000, 1000000, 2500000, 10000000}; + return kBuckets; +} + +// The labels of one application-metric sample. Names are code constants and +// are validated (an invalid one aborts, ADR-0009 — it would otherwise emit a +// scrape Prometheus rejects wholesale); values are data and are escaped. +// Order does not matter: labels are sorted by name, so {a,b} and {b,a} are +// the same series rather than two. +using MetricLabels = std::vector>; + +namespace internal { + +// One application-metric family: its identity, and every sample under it +// keyed by rendered label text. Held by shared_ptr so a handle that outlives +// its registry updates a family nobody exposes rather than dangling. +struct MetricFamily { + enum class Kind { kCounter, kGauge, kHistogram }; + + struct Sample { + // Counter/gauge value, or the histogram's running sum. + double value = 0.0; + // Histogram only: observation count and per-bucket counts, parallel to + // `buckets` and accumulated into cumulative form at exposition time. + std::uint64_t count = 0; + std::vector bucket_counts{}; + }; + + std::string name; + std::string help; + Kind kind = Kind::kCounter; + std::vector buckets; + std::size_t max_series = 0; + + mutable std::mutex mutex; + std::map samples; + std::uint64_t dropped = 0; + + // `set` replaces the value (a gauge Set); otherwise it adds to it. + void Add(const MetricLabels& labels, double amount, bool set); + void Observe(const MetricLabels& labels, double value); + // Materializes a series at its zero without recording an event. + void Declare(const MetricLabels& labels); +}; + +} // namespace internal + +// A monotonically increasing count. Cheap to copy; every copy addresses the +// same family. +class Counter { + public: + void Increment(double amount = 1.0) { Increment(MetricLabels{}, amount); } + void Increment(const MetricLabels& labels, double amount = 1.0) { + // A handle from a disabled registry holds no family. The branch is what + // makes an always-compiled call site free when metrics are off; the + // argument is not, so guard a hot call site whose labels are themselves + // expensive with MetricsRegistry::enabled(). + if (family_ == nullptr) { + return; + } + family_->Add(labels, amount, /*set=*/false); + } + // Exports this series as 0 from startup; see the zero-baseline note on + // MetricsRegistry. Idempotent, and harmless once events have arrived. + void Declare(const MetricLabels& labels = {}) { + if (family_ != nullptr) { + family_->Declare(labels); + } + } + + private: + friend class MetricsRegistry; + explicit Counter(std::shared_ptr family) : family_(std::move(family)) {} + std::shared_ptr family_; +}; + +// A value that goes up and down. +class Gauge { + public: + void Set(double value) { Set(MetricLabels{}, value); } + void Set(const MetricLabels& labels, double value) { + // Inert when the registry is disabled; see Counter::Increment. + if (family_ != nullptr) { + family_->Add(labels, value, /*set=*/true); + } + } + void Increment(double amount = 1.0) { Increment(MetricLabels{}, amount); } + void Increment(const MetricLabels& labels, double amount = 1.0) { + if (family_ != nullptr) { + family_->Add(labels, amount, /*set=*/false); + } + } + void Decrement(double amount = 1.0) { Increment(MetricLabels{}, -amount); } + void Decrement(const MetricLabels& labels, double amount = 1.0) { Increment(labels, -amount); } + // Exports this series as 0 from startup; see the zero-baseline note on + // MetricsRegistry. Idempotent. + void Declare(const MetricLabels& labels = {}) { + if (family_ != nullptr) { + family_->Declare(labels); + } + } + + private: + friend class MetricsRegistry; + explicit Gauge(std::shared_ptr family) : family_(std::move(family)) {} + std::shared_ptr family_; +}; + +// A distribution over configured buckets, exposed with _bucket/_sum/_count. +class Histogram { + public: + void Observe(double value) { Observe(MetricLabels{}, value); } + void Observe(const MetricLabels& labels, double value) { + // Inert when the registry is disabled; see Counter::Increment. + if (family_ != nullptr) { + family_->Observe(labels, value); + } + } + // Exports this series as an empty distribution — every bucket, `_sum` and + // `_count` at 0 — from startup. Unlike a histogram behind a record-only + // API, this is not an observation of 0: it adds nothing to `_sum` or + // `_count`, so the windowed mean `rate(_sum)/rate(_count)` is unbiased. + // Idempotent. + void Declare(const MetricLabels& labels = {}) { + if (family_ != nullptr) { + family_->Declare(labels); + } + } + + private: + friend class MetricsRegistry; + explicit Histogram(std::shared_ptr family) : family_(std::move(family)) {} + std::shared_ptr family_; +}; + +// How a registry behaves. Everything about *what* it exposes is fixed by the +// contract described at the top of this header; what is left is whether it +// runs at all, who it says it is, and the cardinality backstop. +// +// `enabled` is false, so a registry costs nothing until something turns it +// on. Disabled, RecordMetrics and MetricsEndpoint compose to the identity — +// not a wrapper that checks a flag, but no wrapper at all, so a served +// request runs the same call chain it would if metrics had never been +// written. Registration still validates: a bad metric name or a type +// collision aborts whether or not the registry is enabled, so switching it +// on in production is never the first time those checks run. +struct MetricsOptions { + // Nothing is recorded, exposed, or composed until this is true. + bool enabled = false; + + // The `service_name` label on every built-in series. Required when + // enabled, and an empty one aborts (ADR-0009): every dashboard query + // selects on it, so a service reporting the empty string is scraped, + // stored, and invisible — the failure mode that looks like success. + std::string service_name{}; + + // Bounds the distinct {method,route,status} and {method,route} + // combinations retained, and separately the series of each application + // family; see the cardinality note on MetricsRegistry. + std::size_t max_series = 4096; +}; + +// A thread-safe aggregate of served requests, exposable as Prometheus text. +// +// Cardinality is the failure mode a metrics endpoint actually dies of, so +// the label set is chosen to be bounded by construction rather than by +// convention: +// +// - `target` is never a label. It carries path parameters and query +// strings, so one series per distinct URL is one series per request id. +// `operation` is the bounded stand-in — the generated router stamps it +// from the model, and it is empty for the 404/405/400 dispatch failures +// that never reached an operation. +// - `http_method` arrives from the wire, so it is whatever a client typed. +// Anything outside the nine RFC 9110 verbs collapses to "CUSTOM" rather +// than minting a series per invented verb. +// - Past `max_series` distinct label combinations the registry stops +// minting new ones and counts each refused observation once in +// `metrics_observations_dropped_total`. With the two rules above +// the cap should be unreachable; it is the backstop for a handler that +// stamps its own unbounded operation, and it fails visibly (a counter +// you can alert on) rather than by exhausting memory. +// +// Application metrics share the same scrape and the same protections. Mint a +// family once, keep the handle, and use it from anywhere: +// +// auto orders = metrics->NewCounter("orders_processed_total", +// "Orders processed."); +// orders.Increment({{"region", "us-east"}}); +// +// The cap applies per family, so a label chosen from unbounded data (a user +// id, an order id) costs that family its own series budget and shows up in +// the dropped counter — it cannot take the process down with it. +// +// Declare the series whose labels are known at startup: +// +// orders.Declare({{"region", "us-east"}}); +// +// A series that has never been touched does not exist in the scrape, and a +// counter that springs into existence already carrying its first event's +// value hides that event forever: `increase()` and `rate()` measure the +// change *between* samples, so with nothing earlier to measure from, the +// first one shows no increase at all. The panel reads zero, which is worse +// than a missing tile because it looks like an answer. Declaring exports the +// series as 0 from startup so the first real event is a visible step. +// +// Declare the label sets that are known up front — outcomes, error kinds, +// regions. A label carrying request data has no series to declare (and is +// the cardinality problem above); bound it to a known kind and declare that. +// The built-in unlabeled families are always exported, so they are already +// baselined; the per-operation ones cannot be, since this registry never +// sees the model. +class MetricsRegistry { + public: + // Disabled unless `options.enabled`; see MetricsOptions. + explicit MetricsRegistry(MetricsOptions options = {}); + + // Whether this registry records anything. Worth branching on only around a + // call site whose label arguments are themselves expensive to build — the + // handles are already inert, and the built-in middleware compose away. + bool enabled() const { return options_.enabled; } + + // Feed from Observe's on_complete: counts the request, files its latency, + // and decrements the in-flight gauge. Safe from concurrent request threads. + void Record(const RequestObservation& observation); + + // Feed from Observe's on_start: increments the in-flight gauge. Optional — + // without it the gauge stays at zero and the other families are unaffected. + void RecordStart(const RequestStart& start); + + // Counts a request the transport rejected before any handler chain ran — + // the 413/431 an over-limit body or header set earns while the parser is + // still reading. RecordMetrics cannot see these: it is middleware, and the + // transport answers these before middleware exists, so without this an + // over-limit flood is invisible in the request counters entirely. + // + // It counts and nothing more. The in-flight gauge never moves, because + // such a request was never in flight through a handler; and no latency is + // filed, because a request refused at parse time has no service latency to + // report. Filing it as a zero observation would be worse than filing + // nothing: a flood of them drags `rate(_sum)/rate(_count)` toward zero, so + // the latency panel would look its best exactly while the service is being + // hammered. + // + // `method` is whatever the parser had reached — normalized like every + // other method label, and empty becomes "(unparsed)" rather than "CUSTOM", + // since a 431 can fire mid-headers and "never parsed" is a different + // diagnosis from "invented verb". The rejected target is deliberately + // dropped: a flood against distinct paths must not mint a series each, and + // the route reports the unmatched sentinel like any other unrouted + // request. + void RecordRejection(std::string_view method, int status); + + // Mints an application metric family. The name must be a valid Prometheus + // metric name, and must not collide with a family already registered (the + // built-ins included) under a different type or help text — both abort at + // registration (ADR-0009), because either produces a scrape Prometheus + // rejects in full, and a metrics endpoint has no in-process consumer to + // notice. Re-minting the same name with the same type and help returns a + // handle to the same family, so a helper can hand one out repeatedly + // without callers coordinating. + Counter NewCounter(std::string name, std::string help); + Gauge NewGauge(std::string name, std::string help); + // `buckets` has no default on purpose: the built-in ladder is in + // microseconds and shaped for request latency, and silently inheriting it + // for a histogram of bytes or queue depth would produce a chart whose bins + // mean nothing. Pass HttpLatencyBuckets() for a request-shaped duration. + Histogram NewHistogram(std::string name, std::string help, std::vector buckets); + + // The Prometheus text exposition format (version 0.0.4), ready to serve. + // Empty when the registry is disabled. + std::string Expose() const; + + private: + std::shared_ptr Register(std::string name, std::string help, + internal::MetricFamily::Kind kind, + std::vector buckets); + + struct RouteKey { + std::string method; + std::string route; + + friend bool operator<(const RouteKey& a, const RouteKey& b) { + return std::tie(a.method, a.route) < std::tie(b.method, b.route); + } + }; + + // Everything the four built-in per-route families report, in one record + // under one key. + // + // Deliberately not two maps. Counters were once keyed by {method,route, + // status} while the histogram was keyed by {method,route}, and since + // status is not exported the counter map held strictly more keys for the + // same traffic — so it reached the cap first, and past that point a new + // status on an already-seen route was refused by the counters while the + // histogram, whose key already existed, kept recording. requests_total + // silently stopped counting while _count went on rising. One key, one + // admission, one cap: the families cannot drift apart because there is + // nothing to drift. + // + // duration_count is separate from `requests` because a request rejected + // before any handler ran is counted and deliberately not timed; a route + // that only ever saw rejections has requests but no histogram at all. + struct RouteStats { + std::uint64_t requests = 0; + std::uint64_t success = 0; + std::uint64_t failure = 0; + // Per-bucket counts parallel to HttpLatencyBuckets(), non-cumulative + // here and accumulated at exposition time, in microseconds. + std::vector buckets{}; + double duration_sum = 0.0; + std::uint64_t duration_count = 0; + }; + + // Renders `{a="1",b="2"}` from the constant labels plus what is passed, + // dropping any pair whose name is empty. Callers hold mutex_. + std::string BuiltInLabels(const MetricLabels& labels) const; + + // Finds or admits the stats for `key`, or returns nullptr when the cap + // refuses it (recording the refusal). Callers hold mutex_. + RouteStats* AdmitRoute(const RouteKey& key); + + MetricsOptions options_; + mutable std::mutex mutex_; + std::map routes_; + // Always keyed by method, whether or not the gauge is exposed that way: + // the unlabeled form is the sum, and the key set is bounded by the method + // vocabulary. + std::map in_flight_; + std::uint64_t observations_dropped_ = 0; + // Sorted by name so each family's samples stay contiguous in the output. + std::map> families_; +}; + +// The recording half: Observe wired to `registry`. Implemented in terms of +// Observe rather than beside it, so the request timing has exactly one +// implementation and cannot drift from what the logging hook reports. A null +// registry aborts at composition time (ADR-0009) — a metrics endpoint that +// silently reports nothing is worse than one that never starts. +// +// A disabled registry composes to the identity: the returned middleware +// hands back the handler it was given, so nothing wraps the request path and +// a served request pays nothing at all — no timing, no lock, not even an +// extra call frame. +Middleware RecordMetrics(std::shared_ptr registry); + +// A ready-made sink for `BeastServerTransport::Options::on_rejected`: +// +// options.on_rejected = smithy::server::RecordRejections(metrics); +// +// Generic in the rejection type so this header — and `:server` with it — +// keeps no dependency on the Beast transport that defines it. A null +// registry aborts (ADR-0009). +inline auto RecordRejections(std::shared_ptr registry) { + if (registry == nullptr) { + smithy::internal::Fatal("smithy::server::RecordRejections: registry may not be null"); + } + return [registry = std::move(registry)](const auto& rejected) { + registry->RecordRejection(rejected.method, rejected.status); + }; +} + +// The serving half: answers GET or HEAD (query string ignored) with +// the registry's exposition; every other request passes through to the next +// handler. A HEAD is answered like the GET, body included — the transport +// withholds the octets and keeps the length (RFC 9110 §9.3.2), which is the +// only question a HEAD asks. A null registry aborts at composition time. +// +// The response carries as its HttpResponse::operation, which the +// documented composition never reads — it matters only if you deliberately +// put the endpoint inside the recorder to measure scrape volume. +// +// A disabled registry composes to the identity, so is not served at +// all — it reaches the router like any other unmodeled path, and answers +// whatever that answers (a 404). A disabled endpoint that returned an empty +// 200 would read to Prometheus as a live target reporting no series, which +// is indistinguishable from a service whose metrics have all gone quiet. +// +// The endpoint is unauthenticated: it is middleware, so gate it the way you +// gate anything else — compose Guard or RequireBearerAuth outside it, or +// bind the scrape listener somewhere the internet cannot reach. +Middleware MetricsEndpoint(std::shared_ptr registry, + std::string path = "/metrics"); + +} // namespace smithy::server + +#endif // SMITHY_SERVER_METRICS_H_ diff --git a/runtime/include/smithy/server/middleware.h b/runtime/include/smithy/server/middleware.h index e43da82..96a9273 100644 --- a/runtime/include/smithy/server/middleware.h +++ b/runtime/include/smithy/server/middleware.h @@ -2,6 +2,7 @@ #define SMITHY_SERVER_MIDDLEWARE_H_ #include +#include #include #include #include @@ -92,6 +93,10 @@ struct ReadinessCheck { // A HEAD is answered like the GET, body included: the transport withholds // the octets and keeps the length (RFC 9110 §9.3.2), and that length is // what the HEAD was asking for. +// +// Probe responses carry as their HttpResponse::operation, so a probe +// composed inside an observability chain reports as itself rather than as +// the empty operation that 404s and 405s already use. Middleware HealthEndpoint(std::string path = "/health", std::vector checks = {}); // One served request, as seen from outside the router. @@ -100,7 +105,9 @@ struct RequestObservation { std::string target; // The Smithy operation that handled the request (from the generated // router's HttpResponse::operation annotation); empty for 404/405/400 - // dispatch failures. + // dispatch failures. HealthEndpoint and MetricsEndpoint report their own + // path here, so `operation="/health"` can be filtered out of a latency + // panel and an empty operation means a dispatch failure and nothing else. std::string operation; // The request's W3C traceparent header, verbatim, for log correlation. // Never empty for requests served through a transport: the ingress mints a @@ -113,6 +120,28 @@ struct RequestObservation { // as zero; duration_cast to coarser units at the metrics boundary if // needed. std::chrono::microseconds duration{0}; + // Body sizes in bytes. response_bytes is 0 when the handler threw, since + // there is no response — read handler_threw to tell that apart from a + // handler that deliberately answered with an empty body. + std::size_t request_bytes = 0; + std::size_t response_bytes = 0; + // The client as derived from the L4 peer and x-forwarded-for (ADR-0012), + // with its provenance — NOT the raw header, which a client can forge. This + // is the identity PerClientRateLimit keys on, so it is the one that answers + // "whose bucket did that 429 come from". Derived against the TrustedProxies + // passed to Observe: unset means TrustedProxies::None(), the deliberate + // direct-connect statement, under which the peer is the client and the + // header is ignored wholly. `source` is worth reporting alongside the + // address — the *distribution* of sources across requests is the + // misconfiguration signal docs/production-guide.md reads. + http::DerivedClient client{}; + // True when the handler threw and Observe reported the contained 500 on its + // behalf. Distinguishes "we crashed" from "the handler deliberately + // answered 500", which is the first question asked about a 5xx spike. The + // exception text is not here: it stays on the transport's containment log, + // which carries the same trace id (ADR-0011). Always false under + // -fno-exceptions, where the path is compiled out. + bool handler_threw = false; }; // What on_start sees, before the router runs. The Smithy operation is not @@ -134,9 +163,15 @@ struct RequestStart { // sink would otherwise fail silently); on_start and now may be null. Callbacks run on the // transport's request thread; keep them cheap or hand off. now is injectable for deterministic // tests (null means steady_clock). +// `trusted` is the ADR-0012 trust boundary used to derive +// RequestObservation::client. Pass the same one given to PerClientRateLimit, +// or a 429's bucket and the client an observation reports will disagree. +// Unset means TrustedProxies::None() — the deliberate direct-connect +// statement, which reports the peer itself. Middleware Observe(std::function on_complete, std::function on_start = nullptr, - std::function now = nullptr); + std::function now = nullptr, + http::TrustedProxies trusted = http::TrustedProxies::None()); // 401 unless the request carries "authorization: Bearer " (scheme // matched case-insensitively per RFC 6750) and validator(token) returns diff --git a/runtime/src/server/metrics.cc b/runtime/src/server/metrics.cc new file mode 100644 index 0000000..ab1c253 --- /dev/null +++ b/runtime/src/server/metrics.cc @@ -0,0 +1,651 @@ +#include "smithy/server/metrics.h" + +#include +#include +#include +#include +#include +#include +#include + +#include "smithy/core/fatal.h" + +namespace smithy::server { +namespace { + +// The exposition format's own escaping for label values: backslash, double +// quote, and newline (docs: "Prometheus text format", label_value). Applied +// to every label even where the value is already bounded — a handler that +// stamps its own operation reaches this too, and a stray quote there would +// otherwise produce a scrape the server cannot parse. +std::string EscapeLabel(std::string_view value) { + std::string escaped; + escaped.reserve(value.size()); + for (const char c : value) { + switch (c) { + case '\\': + escaped += "\\\\"; + break; + case '"': + escaped += "\\\""; + break; + case '\n': + escaped += "\\n"; + break; + default: + escaped += c; + } + } + return escaped; +} + +// The request method is whatever the client typed, so it cannot be a label +// as-is: `curl -X ` in a loop would mint a series per invented verb +// until the process runs out of memory. The standard set passes through and +// everything else shares one bucket. Case-sensitive, because HTTP methods +// are (RFC 9110 §9.1) — "get" is not GET, and folding it in would report +// traffic the server actually rejected as if it had been served. +// The contract, transcribed. Every literal below is pinned on the MoonBase +// side by //domains/platform/libs/otel_contract; treat this block as data +// copied from there rather than as names chosen here. +constexpr std::string_view kRequestsTotal = "http_server_requests_total"; +constexpr std::string_view kRequestsSuccess = "http_server_requests_success_total"; +constexpr std::string_view kRequestsFailure = "http_server_requests_failure_total"; +constexpr std::string_view kRequestsActive = "http_server_requests_active_gauge"; +constexpr std::string_view kRequestDuration = "http_server_request_duration_microseconds"; +constexpr std::string_view kObservationsDropped = "metrics_observations_dropped_total"; + +constexpr std::string_view kRequestsTotalHelp = "HTTP requests received"; +constexpr std::string_view kRequestsSuccessHelp = "HTTP requests completed successfully (2xx-3xx)"; +constexpr std::string_view kRequestsFailureHelp = "HTTP requests that returned 4xx or 5xx"; +constexpr std::string_view kRequestsActiveHelp = "HTTP requests currently in flight"; +constexpr std::string_view kRequestDurationHelp = "HTTP request duration in microseconds"; +constexpr std::string_view kObservationsDroppedHelp = + "Observations dropped after the registry hit its series cap."; + +constexpr std::string_view kServiceLabel = "service_name"; +constexpr std::string_view kMethodLabel = "http_method"; +constexpr std::string_view kRouteLabel = "route"; + +// A request that reached no operation. Never the empty string: prom_proxy +// subtracts `route!="/health"` from every serving number, and that matcher +// matches the empty string too — unrouted traffic would silently join the +// serving figures instead of being visible as its own thing. +constexpr std::string_view kUnmatchedRoute = "unmatched"; +// A method outside the nine RFC 9110 verbs, and one the transport rejected +// before a method token existed at all (a 431 can fire mid-headers). Kept +// distinct because "never parsed" and "client invented a verb" are different +// diagnoses. +constexpr std::string_view kCustomMethod = "CUSTOM"; +constexpr std::string_view kUnparsedMethod = "(unparsed)"; + +std::string NormalizeMethod(std::string_view method) { + static constexpr std::array kKnown = { + "GET", "HEAD", "POST", "PUT", "PATCH", "DELETE", "OPTIONS", "TRACE", "CONNECT"}; + const auto* found = std::ranges::find(kKnown, method); + return std::string(found == kKnown.end() ? kCustomMethod : *found); +} + +// Prometheus numbers: plain decimal, no trailing zero noise. Six decimals is +// exactly the input granularity (RequestObservation::duration is +// microseconds), so nothing is rounded away that was ever measured. +std::string FormatNumber(double value) { + if (std::isinf(value)) { + return value > 0 ? "+Inf" : "-Inf"; + } + std::array buffer{}; + const int written = std::snprintf(buffer.data(), buffer.size(), "%.6f", value); + if (written <= 0) { + return "0"; + } + std::string text(buffer.data(), static_cast(written)); + if (text.find('.') != std::string::npos) { + text.erase(text.find_last_not_of('0') + 1); + if (!text.empty() && text.back() == '.') { + text.pop_back(); + } + } + return text.empty() ? "0" : text; +} + +// Prometheus metric names are [a-zA-Z_:][a-zA-Z0-9_:]*, label names the same +// without the colon. Both are code constants here, so an invalid one is a +// programming error caught on the first run rather than data to sanitize — +// and letting one through corrupts the whole scrape, not just its own line. +bool ValidName(std::string_view name, bool allow_colon) { + if (name.empty()) return false; + const auto valid = [allow_colon](char c, bool first) { + if (c == '_' || (c >= 'a' && c <= 'z') || (c >= 'A' && c <= 'Z')) return true; + if (allow_colon && c == ':') return true; + return !first && c >= '0' && c <= '9'; + }; + if (!valid(name.front(), true)) return false; + return std::ranges::all_of(name.substr(1), [&](char c) { return valid(c, false); }); +} + +// Renders a label set into the inner text of `{...}`, sorted by name so the +// same labels in a different order address the same series instead of +// silently minting a second one. +std::string RenderLabels(const MetricLabels& labels) { + std::vector> sorted(labels.begin(), labels.end()); + std::ranges::sort(sorted, [](const auto& a, const auto& b) { return a.first < b.first; }); + std::string out; + for (const auto& [name, value] : sorted) { + if (!ValidName(name, /*allow_colon=*/false)) { + smithy::internal::Fatal("smithy::server::MetricsRegistry: invalid label name '" + name + "'"); + } + if (!out.empty()) out += ','; + out += name; + out += "=\""; + out += EscapeLabel(value); + out += '"'; + } + return out; +} + +// Appends `{labels} ` and a newline, omitting the braces +// when the sample carries no labels. +void AppendSample(std::string& out, std::string_view name, std::string_view suffix, + std::string_view labels, std::string_view value) { + out += name; + out += suffix; + if (!labels.empty()) { + out += '{'; + out += labels; + out += '}'; + } + out += ' '; + out += value; + out += '\n'; +} + +// HELP runs to the end of the line, so a backslash or a newline in it +// corrupts the scrape the same way an unescaped label value would — and for +// an application family the help text is a caller's string. The format +// escapes only these two here; a quote needs no escaping in HELP, unlike in +// a label value. +std::string EscapeHelp(std::string_view help) { + std::string escaped; + escaped.reserve(help.size()); + for (const char c : help) { + switch (c) { + case '\\': + escaped += "\\\\"; + break; + case '\n': + escaped += "\\n"; + break; + default: + escaped += c; + } + } + return escaped; +} + +void AppendFamilyHeader(std::string& out, std::string_view name, std::string_view type, + std::string_view help) { + out += "# HELP "; + out += name; + out += ' '; + out += EscapeHelp(help); + out += "\n# TYPE "; + out += name; + out += ' '; + out += type; + out += '\n'; +} + +} // namespace + +namespace internal { + +void MetricFamily::Add(const MetricLabels& labels, double amount, bool set) { + const std::string key = RenderLabels(labels); + const std::lock_guard lock(mutex); + if (auto found = samples.find(key); found != samples.end()) { + if (set) { + found->second.value = amount; + } else { + found->second.value += amount; + } + return; + } + if (samples.size() >= max_series) { + ++dropped; + return; + } + samples.emplace(key, Sample{.value = amount}); +} + +void MetricFamily::Observe(const MetricLabels& labels, double value) { + const std::string key = RenderLabels(labels); + const std::lock_guard lock(mutex); + auto found = samples.find(key); + if (found == samples.end()) { + if (samples.size() >= max_series) { + ++dropped; + return; + } + found = + samples.emplace(key, Sample{.bucket_counts = std::vector(buckets.size(), 0)}) + .first; + } + Sample& sample = found->second; + sample.value += value; + ++sample.count; + const auto bucket = std::ranges::lower_bound(buckets, value); + if (bucket != buckets.end()) { + ++sample.bucket_counts[static_cast(bucket - buckets.begin())]; + } +} + +void MetricFamily::Declare(const MetricLabels& labels) { + const std::string key = RenderLabels(labels); + const std::lock_guard lock(mutex); + if (samples.contains(key)) { + return; // idempotent, and never disturbs a series already carrying events + } + if (samples.size() >= max_series) { + ++dropped; + return; + } + // A counter or gauge baselines at 0; a histogram baselines as an empty + // distribution, which costs `_sum` and `_count` nothing — the mean stays + // unbiased, unlike recording a literal 0 observation. + samples.emplace(key, Sample{.bucket_counts = std::vector(buckets.size(), 0)}); +} + +} // namespace internal + +MetricsRegistry::MetricsRegistry(MetricsOptions options) : options_(std::move(options)) { + // Composition-time validation (ADR-0009). An empty service_name is scraped + // and stored exactly like a good one — every dashboard query selects on the + // label, so the service is simply absent from all of them. That is the + // failure mode worth aborting for: it looks like success everywhere except + // the panel nobody is watching yet. + if (options_.enabled && options_.service_name.empty()) { + smithy::internal::Fatal( + "smithy::server::MetricsRegistry: service_name is required when metrics are enabled"); + } +} + +std::string MetricsRegistry::BuiltInLabels(const MetricLabels& labels) const { + // Not RenderLabels: these are emitted in a fixed order (service_name, then + // method, route) rather than sorted, so the built-in families read the way + // the header documents them. Prometheus does not care about label order; a + // human reading a scrape does. + std::string out; + out += kServiceLabel; + out += "=\""; + out += EscapeLabel(options_.service_name); + out += '"'; + for (const auto& [name, value] : labels) { + out += ','; + out += name; + out += "=\""; + out += EscapeLabel(value); + out += '"'; + } + return out; +} + +void MetricsRegistry::RecordStart(const RequestStart& start) { + if (!options_.enabled) { + return; + } + // The target is deliberately not read: this runs before dispatch, so the + // only bounded thing known about the request is its method. The gauge is + // always keyed by method — the unlabeled form is the sum over these keys — + // and the key set is bounded by the method vocabulary. + std::string method = NormalizeMethod(start.method); + const std::lock_guard lock(mutex_); + ++in_flight_[std::move(method)]; +} + +MetricsRegistry::RouteStats* MetricsRegistry::AdmitRoute(const RouteKey& key) { + if (auto found = routes_.find(key); found != routes_.end()) { + return &found->second; + } + if (routes_.size() >= options_.max_series) { + // The backstop for an unbounded route stamped by a hand-written handler. + // Counted once per refused observation, not once per family: the counter + // answers "how much traffic am I blind to", and one event is one gap. + ++observations_dropped_; + return nullptr; + } + return &routes_ + .emplace(key, RouteStats{.buckets = std::vector( + HttpLatencyBuckets().size(), 0)}) + .first->second; +} + +void MetricsRegistry::Record(const RequestObservation& observation) { + if (!options_.enabled) { + return; + } + // The hook is already microseconds, which is the exposition's unit too, so + // nothing is converted and nothing is rounded away. + const auto duration = static_cast(observation.duration.count()); + const RouteKey key{.method = NormalizeMethod(observation.method), + .route = observation.operation.empty() ? std::string(kUnmatchedRoute) + : observation.operation}; + + const std::lock_guard lock(mutex_); + // Before the cap check: a request that started must bring the gauge back + // down whether or not its route survives admission, or a refused route + // leaks in-flight forever. Only decrement one that was incremented — + // without RecordStart wired up the gauge stays at zero rather than + // counting downward. + if (auto in_flight = in_flight_.find(key.method); + in_flight != in_flight_.end() && in_flight->second > 0) { + --in_flight->second; + } + + RouteStats* stats = AdmitRoute(key); + if (stats == nullptr) { + return; + } + ++stats->requests; + // The 400 boundary is the one the rest of the fleet already draws: + // 2xx-3xx succeeded, 4xx and 5xx did not. + if (observation.status < 400) { + ++stats->success; + } else { + ++stats->failure; + } + stats->duration_sum += duration; + ++stats->duration_count; + // The first bucket at or above the value; a value past the last one lands + // only in +Inf, which the exposition takes from the count. Buckets are + // upper-inclusive, which is what `le` means. + const auto bucket = std::ranges::lower_bound(HttpLatencyBuckets(), duration); + if (bucket != HttpLatencyBuckets().end()) { + ++stats->buckets[static_cast(bucket - HttpLatencyBuckets().begin())]; + } +} + +void MetricsRegistry::RecordRejection(std::string_view method, int status) { + if (!options_.enabled) { + return; + } + // The unparsed sentinel rather than the nonstandard one: a 431 can fire + // before the method token was ever read, and that is a different diagnosis + // from a client inventing a verb. Both are constants, which is what the + // label set needs. + const RouteKey key{ + .method = method.empty() ? std::string(kUnparsedMethod) : NormalizeMethod(method), + .route = std::string(kUnmatchedRoute)}; + + const std::lock_guard lock(mutex_); + RouteStats* stats = AdmitRoute(key); + if (stats == nullptr) { + return; + } + // Counted, and deliberately not timed: a request refused at parse time has + // no service latency to report, and filing it as a zero observation would + // drag rate(_sum)/rate(_count) toward zero — flattering the latency panel + // during exactly the flood it should be exposing. + ++stats->requests; + if (status < 400) { + ++stats->success; + } else { + ++stats->failure; + } +} + +std::shared_ptr MetricsRegistry::Register(std::string name, + std::string help, + internal::MetricFamily::Kind kind, + std::vector buckets) { + if (!ValidName(name, /*allow_colon=*/true)) { + smithy::internal::Fatal("smithy::server::MetricsRegistry: invalid metric name '" + name + "'"); + } + // The built-ins are emitted unconditionally, so a family under one of their + // names would appear twice with two TYPE lines — a scrape Prometheus + // rejects whole. Checked against the configured names, since those are + // what actually reach the exposition. + for (const std::string_view reserved : + {kRequestsTotal, kRequestsSuccess, kRequestsFailure, kRequestsActive, kRequestDuration, + kObservationsDropped}) { + if (name == reserved) { + smithy::internal::Fatal("smithy::server::MetricsRegistry: '" + name + + "' is one of the built-in families"); + } + } + const std::lock_guard lock(mutex_); + if (auto found = families_.find(name); found != families_.end()) { + // Idempotent for an identical re-registration; a mismatch is the case + // that would corrupt the scrape, so it aborts rather than picking one. + const internal::MetricFamily& existing = *found->second; + if (existing.kind != kind || existing.help != help) { + smithy::internal::Fatal("smithy::server::MetricsRegistry: '" + name + + "' is already registered with a different type or help text"); + } + return found->second; + } + auto family = std::make_shared(); + family->name = std::move(name); + family->help = std::move(help); + family->kind = kind; + family->buckets = std::move(buckets); + family->max_series = options_.max_series; + families_.emplace(family->name, family); + return family; +} + +// A handle from a disabled registry holds no family, so every operation on +// it is a null check. The family is still registered either way: the name +// and collision checks in Register are exactly the fail-fast that must not +// wait for someone to turn metrics on in production. +Counter MetricsRegistry::NewCounter(std::string name, std::string help) { + auto family = + Register(std::move(name), std::move(help), internal::MetricFamily::Kind::kCounter, {}); + return Counter(options_.enabled ? std::move(family) : nullptr); +} + +Gauge MetricsRegistry::NewGauge(std::string name, std::string help) { + auto family = + Register(std::move(name), std::move(help), internal::MetricFamily::Kind::kGauge, {}); + return Gauge(options_.enabled ? std::move(family) : nullptr); +} + +Histogram MetricsRegistry::NewHistogram(std::string name, std::string help, + std::vector buckets) { + // The same fail-fast the built-in ladder gets by being a constant. An + // unsorted or non-finite ladder does not fail loudly at scrape time; it + // silently produces cumulative buckets that disagree with themselves, + // which a dashboard renders as plausible nonsense (ADR-0009). + if (buckets.empty()) { + smithy::internal::Fatal("smithy::server::MetricsRegistry: histogram '" + name + + "' needs at least one bucket (the +Inf bucket is implicit)"); + } + for (std::size_t i = 0; i < buckets.size(); ++i) { + if (!std::isfinite(buckets[i])) { + smithy::internal::Fatal("smithy::server::MetricsRegistry: histogram '" + name + + "' buckets must all be finite (the +Inf bucket is implicit)"); + } + if (i > 0 && buckets[i] <= buckets[i - 1]) { + smithy::internal::Fatal("smithy::server::MetricsRegistry: histogram '" + name + + "' buckets must be strictly ascending"); + } + } + auto family = Register(std::move(name), std::move(help), internal::MetricFamily::Kind::kHistogram, + std::move(buckets)); + return Histogram(options_.enabled ? std::move(family) : nullptr); +} + +std::string MetricsRegistry::Expose() const { + // A disabled registry has nothing to say, and MetricsEndpoint does not + // serve it — see the header on why an empty 200 would be worse. + if (!options_.enabled) { + return {}; + } + std::string out; + const std::lock_guard lock(mutex_); + + // Families are emitted whole and in order. The format requires every line + // of a family to be contiguous, so each family is written in one pass — + // including the drop counter below, whose per-family samples used to trail + // the application families and split it in two. + const auto route_labels = [this](const RouteKey& key) { + return BuiltInLabels( + {{std::string(kMethodLabel), key.method}, {std::string(kRouteLabel), key.route}}); + }; + const auto counter_family = [&](std::string_view name, std::string_view help, + std::uint64_t RouteStats::*field) { + AppendFamilyHeader(out, name, "counter", help); + for (const auto& [key, stats] : routes_) { + AppendSample(out, name, "", route_labels(key), std::to_string(stats.*field)); + } + }; + // Three views of one tally, read off one record, so they cannot disagree. + counter_family(kRequestsTotal, kRequestsTotalHelp, &RouteStats::requests); + counter_family(kRequestsSuccess, kRequestsSuccessHelp, &RouteStats::success); + counter_family(kRequestsFailure, kRequestsFailureHelp, &RouteStats::failure); + + AppendFamilyHeader(out, kRequestDuration, "histogram", kRequestDurationHelp); + for (const auto& [key, stats] : routes_) { + // A route that was only ever rejected has requests but nothing timed. + // Emitting an all-zero histogram for it would claim an observation that + // was deliberately not filed. + if (stats.duration_count == 0) { + continue; + } + const std::string labels = route_labels(key); + const std::string prefix = labels + ","; + std::uint64_t cumulative = 0; + for (std::size_t i = 0; i < HttpLatencyBuckets().size(); ++i) { + cumulative += stats.buckets[i]; + AppendSample(out, kRequestDuration, "_bucket", + prefix + "le=\"" + FormatNumber(HttpLatencyBuckets()[i]) + "\"", + std::to_string(cumulative)); + } + // +Inf is the total by definition, which also covers values past the + // last finite bucket. + AppendSample(out, kRequestDuration, "_bucket", prefix + "le=\"+Inf\"", + std::to_string(stats.duration_count)); + AppendSample(out, kRequestDuration, "_sum", labels, FormatNumber(stats.duration_sum)); + AppendSample(out, kRequestDuration, "_count", labels, std::to_string(stats.duration_count)); + } + + // No route label, and no zero baseline: the gauge moves at request start, + // where the method is the only bounded thing known, and the methods a + // service will see are not knowable before it sees them. + AppendFamilyHeader(out, kRequestsActive, "gauge", kRequestsActiveHelp); + for (const auto& [method, count] : in_flight_) { + AppendSample(out, kRequestsActive, "", BuiltInLabels({{std::string(kMethodLabel), method}}), + std::to_string(count)); + } + + // The drop counter, whole: the unlabeled total and every per-family + // attribution under one header. `dropped` rides on the family's own line + // rather than only the built-in counter, so a runaway label on one + // application metric is attributable to it. + AppendFamilyHeader(out, kObservationsDropped, "counter", kObservationsDroppedHelp); + AppendSample(out, kObservationsDropped, "", BuiltInLabels({}), + std::to_string(observations_dropped_)); + for (const auto& [name, family] : families_) { + const std::lock_guard family_lock(family->mutex); + if (family->dropped != 0) { + AppendSample(out, kObservationsDropped, "", BuiltInLabels({{"metric", name}}), + std::to_string(family->dropped)); + } + } + + // Application families last, each whole and in name order; their samples + // are already keyed by rendered labels, so a family's series are + // contiguous the way the format requires. + for (const auto& [name, family] : families_) { + const std::lock_guard family_lock(family->mutex); + const char* type = "counter"; + if (family->kind == internal::MetricFamily::Kind::kGauge) type = "gauge"; + if (family->kind == internal::MetricFamily::Kind::kHistogram) type = "histogram"; + AppendFamilyHeader(out, name, type, family->help); + for (const auto& [labels, sample] : family->samples) { + if (family->kind != internal::MetricFamily::Kind::kHistogram) { + AppendSample(out, name, "", labels, FormatNumber(sample.value)); + continue; + } + // Bucket lines always carry `le`, so they always have braces. + std::string bucket_labels; + std::uint64_t cumulative = 0; + for (std::size_t i = 0; i < family->buckets.size(); ++i) { + cumulative += sample.bucket_counts[i]; + bucket_labels = labels.empty() ? std::string() : labels + ","; + bucket_labels += "le=\""; + bucket_labels += FormatNumber(family->buckets[i]); + bucket_labels += '"'; + AppendSample(out, name, "_bucket", bucket_labels, std::to_string(cumulative)); + } + bucket_labels = labels.empty() ? std::string() : labels + ","; + bucket_labels += "le=\"+Inf\""; + AppendSample(out, name, "_bucket", bucket_labels, std::to_string(sample.count)); + AppendSample(out, name, "_sum", labels, FormatNumber(sample.value)); + AppendSample(out, name, "_count", labels, std::to_string(sample.count)); + } + } + return out; +} + +Middleware RecordMetrics(std::shared_ptr registry) { + if (registry == nullptr) { + smithy::internal::Fatal("smithy::server::RecordMetrics: registry may not be null"); + } + // Disabled: compose to the identity. Not a wrapper that checks a flag per + // request — no wrapper at all, so the composed chain is byte-for-byte the + // handler it would have been had this middleware never been written. + if (!registry->enabled()) { + return [](http::RequestHandler next) { return next; }; + } + // Built on Observe rather than beside it: the request timing then has one + // implementation, and the numbers the endpoint serves cannot drift from + // what the logging hook reports about the same request. + // + // The two captures are sequenced into locals rather than written inline as + // arguments: the second moves the registry, and argument evaluation order + // is unspecified, so inline the move could run first and leave the other + // lambda holding a null. + auto complete = [registry](const RequestObservation& observation) { + registry->Record(observation); + }; + auto start = [registry = std::move(registry)](const RequestStart& request) { + registry->RecordStart(request); + }; + return Observe(std::move(complete), std::move(start)); +} + +Middleware MetricsEndpoint(std::shared_ptr registry, std::string path) { + if (registry == nullptr) { + smithy::internal::Fatal("smithy::server::MetricsEndpoint: registry may not be null"); + } + // Disabled: the path is not served at all, so it reaches the router like + // any other unmodeled path. An empty 200 would read to Prometheus as a + // live target reporting no series — indistinguishable from a service whose + // metrics have all gone silent, which is the alert you least want faked. + if (!registry->enabled()) { + return [](http::RequestHandler next) { return next; }; + } + return [registry = std::move(registry), path = std::move(path)](http::RequestHandler next) { + return [registry, path, next = std::move(next)](const http::HttpRequest& request) { + const std::string_view target(request.target); + if ((request.method == "GET" || request.method == "HEAD") && + target.substr(0, target.find('?')) == path) { + http::HttpResponse response; + response.status = 200; + // The version is part of the content type Prometheus negotiates on; + // it names the exposition format, not this library. + response.headers.Set("content-type", "text/plain; version=0.0.4; charset=utf-8"); + // Only reached when this endpoint is composed inside the recorder + // instead of outside it; the documented order never records a scrape. + response.operation = path; + // Set for HEAD too: the transport withholds the octets and keeps the + // length (RFC 9110 §9.3.2), and that length is what the HEAD asked. + response.body = registry->Expose(); + return response; + } + return next(request); + }; + }; +} + +} // namespace smithy::server diff --git a/runtime/src/server/middleware.cc b/runtime/src/server/middleware.cc index 773d103..a04b1c1 100644 --- a/runtime/src/server/middleware.cc +++ b/runtime/src/server/middleware.cc @@ -140,6 +140,12 @@ Middleware HealthEndpoint(std::string path, std::vector checks) http::HttpResponse response; response.status = failing.empty() ? 200 : 503; response.headers.Set("content-type", "application/json"); + // Probes are labeled with the endpoint's own path. Without it they + // report as the empty operation, which is also what 404s and 405s + // report — so probe traffic and dispatch failures land in one series + // and neither can be read. The path is fixed at composition, never + // off the wire, so this adds one series per composed endpoint. + response.operation = path; // Set for HEAD too. Framing is the transport's, which withholds the // octets and keeps the length (RFC 9110 §9.3.2); emptying the body // here would answer Content-Length: 0 instead — a false claim about @@ -155,7 +161,8 @@ Middleware HealthEndpoint(std::string path, std::vector checks) Middleware Observe(std::function on_complete, std::function on_start, - std::function now) { + std::function now, + http::TrustedProxies trusted) { if (on_complete == nullptr) { smithy::internal::Fatal("smithy::server::Observe: on_complete may not be null"); } @@ -163,8 +170,9 @@ Middleware Observe(std::function on_complete, now = [] { return std::chrono::steady_clock::now(); }; } return [on_complete = std::move(on_complete), on_start = std::move(on_start), - now = std::move(now)](http::RequestHandler next) { - return [on_complete, on_start, now, next = std::move(next)](const http::HttpRequest& request) { + now = std::move(now), trusted = std::move(trusted)](http::RequestHandler next) { + return [on_complete, on_start, now, trusted, + next = std::move(next)](const http::HttpRequest& request) { if (on_start != nullptr) { CallContained(on_start, RequestStart{request.method, request.target}, "Observe on_start"); } @@ -172,6 +180,11 @@ Middleware Observe(std::function on_complete, observation.method = request.method; observation.target = request.target; observation.trace_parent = request.headers.Get("traceparent").value_or(""); + observation.request_bytes = request.body.size(); + // Derived once here rather than per sink: the walk parses + // x-forwarded-for, and two sinks deriving it independently could + // disagree if they were handed different trust boundaries. + observation.client = http::DeriveClient(request, trusted); const auto start = now(); http::HttpResponse response; #if defined(__cpp_exceptions) @@ -183,6 +196,9 @@ Middleware Observe(std::function on_complete, // containment (server_dispatch.h). Under -fno-exceptions next() // cannot throw, so this pairing is unreachable and compiled out. observation.status = 500; + observation.handler_threw = true; + // response_bytes stays 0: there is no response. handler_threw is what + // tells that apart from a handler that answered with an empty body. observation.duration = std::chrono::duration_cast(now() - start); CallContained(on_complete, observation, "Observe on_complete"); throw; @@ -192,6 +208,7 @@ Middleware Observe(std::function on_complete, #endif observation.operation = response.operation; observation.status = response.status; + observation.response_bytes = response.body.size(); observation.duration = std::chrono::duration_cast(now() - start); CallContained(on_complete, observation, "Observe on_complete"); return response; diff --git a/runtime/tests/http/beast_transport_test.cc b/runtime/tests/http/beast_transport_test.cc index 9e5f946..d72aedf 100644 --- a/runtime/tests/http/beast_transport_test.cc +++ b/runtime/tests/http/beast_transport_test.cc @@ -12,6 +12,7 @@ #include #include #include +#include #include #include #include @@ -19,6 +20,7 @@ #include #include "smithy/http/socket_transport.h" +#include "smithy/server/metrics.h" #include "smithy/server/middleware.h" #include "smithy/testing/connection_event_recorder.h" @@ -1265,6 +1267,137 @@ TEST(BeastTransportTest, HeadResponsesCarryTheGetsLengthAndNoBody) { server.Stop(); } +TEST(BeastTransportTest, TheMetricsEndpointScrapesOverTheRealTransport) { + // The registry and the exposition are unit-tested; what only a real socket + // proves is that a scrape survives the transport — the exposition's own + // content type reaches the client, and the traffic counted is the traffic + // the transport actually served. + auto metrics = std::make_shared( + smithy::server::MetricsOptions{.enabled = true, .service_name = "todo-service"}); + BeastServerTransport server; + ASSERT_TRUE(server + .Start(smithy::server::Chain({smithy::server::MetricsEndpoint(metrics), + smithy::server::RecordMetrics(metrics)}, + [](const HttpRequest&) { + HttpResponse response; + response.status = 200; + response.operation = "GetThing"; + response.body = "ok"; + return response; + })) + .ok()); + + ASSERT_FALSE( + RawRoundTrip(server.port(), "GET /thing HTTP/1.1\r\nhost: x\r\nconnection: close\r\n\r\n") + .empty()); + + const std::string scrape = + RawRoundTrip(server.port(), "GET /metrics HTTP/1.1\r\nhost: x\r\nconnection: close\r\n\r\n"); + const auto header_end = scrape.find("\r\n\r\n"); + ASSERT_NE(header_end, std::string::npos) << scrape; + EXPECT_NE(AsciiLowerCopy(scrape.substr(0, header_end)) + .find("content-type: text/plain; version=0.0.4; charset=utf-8"), + std::string::npos) + << scrape; + const std::string body = scrape.substr(header_end + 4); + EXPECT_NE( + body.find( + R"(http_server_requests_total{service_name="todo-service",http_method="GET",route="GetThing"} 1)"), + std::string::npos) + << body; + // The scrape itself went through MetricsEndpoint, which sits outside + // RecordMetrics — so it answered without counting itself. + EXPECT_EQ(body.find(R"(operation="",status="200")"), std::string::npos) << body; + + server.Stop(); +} + +TEST(BeastTransportTest, AnOverLimitRejectionReachesTheMetricsScrape) { + // The gap RecordMetrics cannot close on its own: the transport writes this + // 413 before any handler chain exists, so middleware never sees it and an + // over-limit flood would be invisible in the request counters. Wiring + // on_rejected is what makes it visible, and only a real transport proves + // the wiring — the rejection has no in-process caller to fake. + auto metrics = std::make_shared( + smithy::server::MetricsOptions{.enabled = true, .service_name = "todo-service"}); + BeastServerTransport server(BeastServerTransport::Options{ + .max_body_bytes = 1024, .on_rejected = smithy::server::RecordRejections(metrics)}); + ASSERT_TRUE(server + .Start(smithy::server::Chain({smithy::server::MetricsEndpoint(metrics), + smithy::server::RecordMetrics(metrics)}, + [](const HttpRequest&) { + HttpResponse response; + response.status = 200; + response.operation = "GetThing"; + return response; + })) + .ok()); + + SocketHttpClient client("127.0.0.1", server.port()); + HttpRequest oversized; + oversized.method = "POST"; + oversized.target = "/upload"; + oversized.body = std::string(64 * 1024, 'x'); + const auto rejected = client.Send(oversized); + ASSERT_TRUE(rejected.ok()) << rejected.error().message(); + ASSERT_EQ(rejected->status, 413); + + const std::string scrape = + RawRoundTrip(server.port(), "GET /metrics HTTP/1.1\r\nhost: x\r\nconnection: close\r\n\r\n"); + const auto header_end = scrape.find("\r\n\r\n"); + ASSERT_NE(header_end, std::string::npos) << scrape; + const std::string body = scrape.substr(header_end + 4); + EXPECT_NE( + body.find( + R"(http_server_requests_total{service_name="todo-service",http_method="POST",route="unmatched"} 1)"), + std::string::npos) + << body; + // Counted, but not filed as a latency observation: a request refused at + // parse time has no service latency, and zeros here would flatter the + // panel during exactly the flood it should expose. + EXPECT_EQ( + body.find( + R"(http_server_request_duration_microseconds_count{service_name="todo-service",http_method="POST",route="unmatched"})"), + std::string::npos) + << body; + + server.Stop(); +} + +TEST(BeastTransportTest, TheMetricsEndpointsHeadReportsTheGetsLength) { + // Same framing hazard as the health endpoint below: MetricsEndpoint answers + // HEAD itself, so it is on the handler to hand the transport a full body + // and let the transport withhold the octets while keeping the length. + auto metrics = std::make_shared( + smithy::server::MetricsOptions{.enabled = true, .service_name = "todo-service"}); + BeastServerTransport server; + ASSERT_TRUE(server + .Start(smithy::server::Chain({smithy::server::MetricsEndpoint(metrics)}, + [](const HttpRequest&) { + HttpResponse response; + response.status = 404; + response.body = "no route"; + return response; + })) + .ok()); + + const std::string head = + RawRoundTrip(server.port(), "HEAD /metrics HTTP/1.1\r\nhost: x\r\nconnection: close\r\n\r\n"); + const std::string get = + RawRoundTrip(server.port(), "GET /metrics HTTP/1.1\r\nhost: x\r\nconnection: close\r\n\r\n"); + const auto head_end = head.find("\r\n\r\n"); + const auto get_end = get.find("\r\n\r\n"); + ASSERT_NE(head_end, std::string::npos) << head; + ASSERT_NE(get_end, std::string::npos) << get; + + EXPECT_EQ(head.substr(head_end + 4), "") << "HEAD answered with a body: " << head; + const std::string expected_length = "content-length: " + std::to_string(get.size() - get_end - 4); + EXPECT_NE(AsciiLowerCopy(head.substr(0, head_end)).find(expected_length), std::string::npos) + << "HEAD did not report the GET's length: " << head; + + server.Stop(); +} + TEST(BeastTransportTest, TheHealthEndpointsHeadReportsTheGetsLength) { // HealthEndpoint answers HEAD itself rather than routing it, so it is the // one shipped handler that can get the HEAD shape wrong on its own. Framing diff --git a/runtime/tests/server/metrics_test.cc b/runtime/tests/server/metrics_test.cc new file mode 100644 index 0000000..7a7309b --- /dev/null +++ b/runtime/tests/server/metrics_test.cc @@ -0,0 +1,1341 @@ +// Pins the dependency-free Prometheus backend (issue #91): what the registry +// aggregates from the Observe hooks, what the endpoint serves, and the +// cardinality rules that keep a scrape endpoint from becoming the outage. +// +// The exposition assertions are deliberately literal. A metrics endpoint has +// no in-process consumer to catch a format slip — the failure surfaces as a +// scrape Prometheus silently rejects, hours later, on a dashboard nobody is +// watching yet. + +#include "smithy/server/metrics.h" + +#include + +#include +#include +#include +#include +#include +#include +#include +#include +#include + +#include "smithy/server/middleware.h" + +namespace smithy::server { +namespace { + +using std::chrono::microseconds; + +RequestObservation Served(std::string method, std::string operation, int status, + microseconds duration) { + return RequestObservation{.method = std::move(method), + .target = "/ignored", + .operation = std::move(operation), + .trace_parent = "", + .status = status, + .duration = duration}; +} + +// Every test that expects a registry to record anything has to turn it on: +// MetricsOptions::enabled is false by default so that a metrics stack that +// is linked in but not switched on costs nothing. The DisabledRegistry tests +// below pin that default and what it buys. +MetricsOptions Enabled() { + MetricsOptions options; + options.enabled = true; + options.service_name = "todo-service"; + return options; +} + +// The label prefix every built-in series carries, spelled once. +const std::string kService = R"(service_name="todo-service")"; + +// The exposition is line-oriented, so assertions read best as "this exact +// line is present" rather than as substring soup. +bool HasLine(const std::string& exposition, const std::string& line) { + const std::string padded = "\n" + exposition; + return padded.find("\n" + line + "\n") != std::string::npos; +} + +http::HttpRequest Get(std::string target) { + http::HttpRequest request; + request.method = "GET"; + request.target = std::move(target); + return request; +} + +// A terminal handler standing in for the generated router. +http::RequestHandler Handler(int status = 200, std::string operation = "GetThing") { + return [status, operation = std::move(operation)](const http::HttpRequest&) { + http::HttpResponse response; + response.status = status; + response.operation = operation; + return response; + }; +} + +// --------------------------------------------------------------------------- +// What the registry aggregates. +// --------------------------------------------------------------------------- + +TEST(MetricsRegistryTest, CountsRequestsByMethodOperationAndStatus) { + MetricsRegistry registry(Enabled()); + registry.Record(Served("GET", "GetThing", 200, microseconds(1000))); + registry.Record(Served("GET", "GetThing", 200, microseconds(2000))); + registry.Record(Served("POST", "PutThing", 500, microseconds(3000))); + + const std::string exposition = registry.Expose(); + EXPECT_TRUE(HasLine( + exposition, + R"(http_server_requests_total{service_name="todo-service",http_method="GET",route="GetThing"} 2)")) + << exposition; + EXPECT_TRUE(HasLine( + exposition, + R"(http_server_requests_total{service_name="todo-service",http_method="POST",route="PutThing"} 1)")) + << exposition; +} + +TEST(MetricsRegistryTest, EmitsTheFamilyHeadersEvenBeforeAnyTraffic) { + // A freshly started server should still describe its shape, so a scrape + // configured against it is verifiable before the first request arrives. + const std::string exposition = MetricsRegistry(Enabled()).Expose(); + EXPECT_TRUE(HasLine(exposition, "# TYPE http_server_requests_total counter")) << exposition; + EXPECT_TRUE(HasLine(exposition, "# TYPE http_server_request_duration_microseconds histogram")) + << exposition; + EXPECT_TRUE(HasLine(exposition, "# TYPE http_server_requests_active_gauge gauge")) << exposition; + EXPECT_TRUE(HasLine(exposition, "# TYPE http_server_requests_success_total counter")) + << exposition; + EXPECT_TRUE(HasLine(exposition, "# TYPE http_server_requests_failure_total counter")) + << exposition; + // The gauge gets no zero baseline: its label is the method, and which + // methods a service will see is not knowable before it sees them. + EXPECT_EQ(exposition.find("http_server_requests_active_gauge{"), std::string::npos) << exposition; +} + +TEST(MetricsRegistryTest, HistogramBucketsAreCumulativeAndEndAtInf) { + MetricsRegistry registry(Enabled()); + registry.Record(Served("GET", "GetThing", 200, microseconds(100))); // the le="100" bucket + registry.Record(Served("GET", "GetThing", 200, microseconds(2500))); // the le="2500" bucket + registry.Record(Served("GET", "GetThing", 200, microseconds(50000000))); // past the ladder + + const std::string exposition = registry.Expose(); + const std::string labels = R"(service_name="todo-service",http_method="GET",route="GetThing")"; + // Buckets are upper-inclusive, which is what `le` means: exactly 100µs + // belongs in the 100 bucket rather than the one above it. + EXPECT_TRUE(HasLine( + exposition, "http_server_request_duration_microseconds_bucket{" + labels + R"(,le="100"} 1)")) + << exposition; + EXPECT_TRUE(HasLine(exposition, "http_server_request_duration_microseconds_bucket{" + labels + + R"(,le="2500"} 2)")) + << exposition; + // The last finite bound still holds 2: the 50s observation is past it and + // lands only in +Inf. + EXPECT_TRUE(HasLine(exposition, "http_server_request_duration_microseconds_bucket{" + labels + + R"(,le="10000000"} 2)")) + << exposition; + EXPECT_TRUE(HasLine(exposition, "http_server_request_duration_microseconds_bucket{" + labels + + R"(,le="+Inf"} 3)")) + << exposition; + EXPECT_TRUE( + HasLine(exposition, "http_server_request_duration_microseconds_count{" + labels + "} 3")) + << exposition; + EXPECT_TRUE( + HasLine(exposition, "http_server_request_duration_microseconds_sum{" + labels + "} 50002600")) + << exposition; +} + +TEST(MetricsRegistryTest, SubMillisecondLatenciesSurviveTheMicrosecondHook) { + // The hook is microseconds precisely so cache hits and loopback don't + // report as zero (#92), and the exposition's unit is microseconds too, so + // the value travels undivided. + MetricsRegistry registry(Enabled()); + registry.Record(Served("GET", "GetThing", 200, microseconds(1))); + EXPECT_TRUE( + HasLine(registry.Expose(), + R"(http_server_request_duration_microseconds_sum{service_name="todo-service",)" + R"(http_method="GET",route="GetThing"} 1)")) + << registry.Expose(); +} + +TEST(MetricsRegistryTest, DispatchFailuresCountUnderAnEmptyOperation) { + // 404/405/400 never reached an operation, so the label is empty rather + // than inventing one — and the target that caused it is deliberately not + // a label at all. + MetricsRegistry registry(Enabled()); + registry.Record(Served("GET", "", 404, microseconds(100))); + EXPECT_TRUE(HasLine( + registry.Expose(), + R"(http_server_requests_total{service_name="todo-service",http_method="GET",route="unmatched"} 1)")) + << registry.Expose(); +} + +TEST(MetricsRegistryTest, RecordsConcurrentlyWithoutLosingCounts) { + MetricsRegistry registry(Enabled()); + constexpr int kThreads = 8; + constexpr int kPerThread = 500; + std::vector threads; + threads.reserve(kThreads); + for (int t = 0; t < kThreads; ++t) { + threads.emplace_back([®istry] { + for (int i = 0; i < kPerThread; ++i) { + registry.Record(Served("GET", "GetThing", 200, microseconds(1000))); + } + }); + } + for (std::thread& thread : threads) { + thread.join(); + } + EXPECT_TRUE(HasLine( + registry.Expose(), + R"(http_server_requests_total{service_name="todo-service",http_method="GET",route="GetThing"} )" + + std::to_string(kThreads * kPerThread))) + << registry.Expose(); +} + +// --------------------------------------------------------------------------- +// Cardinality: the failure mode a metrics endpoint dies of. +// --------------------------------------------------------------------------- + +TEST(MetricsRegistryTest, AnInventedMethodCollapsesInsteadOfMintingASeries) { + // The method comes off the wire, so a loop of `curl -X ` is a + // memory-exhaustion vector if it reaches the label set verbatim. + MetricsRegistry registry(Enabled()); + for (int i = 0; i < 100; ++i) { + registry.Record(Served("BOGUS" + std::to_string(i), "", 405, microseconds(10))); + } + const std::string exposition = registry.Expose(); + EXPECT_TRUE(HasLine( + exposition, + R"(http_server_requests_total{service_name="todo-service",http_method="CUSTOM",route="unmatched"} 100)")) + << exposition; + EXPECT_EQ(exposition.find("BOGUS"), std::string::npos) << exposition; +} + +TEST(MetricsRegistryTest, LowercaseMethodIsNotFoldedIntoTheRealOne) { + // HTTP methods are case-sensitive (RFC 9110 §9.1): a "get" the server + // rejected must not report as served GET traffic. + MetricsRegistry registry(Enabled()); + registry.Record(Served("get", "", 405, microseconds(10))); + const std::string exposition = registry.Expose(); + EXPECT_TRUE(HasLine( + exposition, + R"(http_server_requests_total{service_name="todo-service",http_method="CUSTOM",route="unmatched"} 1)")) + << exposition; +} + +TEST(MetricsRegistryTest, TheSeriesCapStopsGrowthAndSaysSoOutLoud) { + // The backstop for an unbounded operation stamped by a hand-written + // handler: stop minting, and expose the drops so it can be alerted on + // rather than discovered as an OOM. + MetricsOptions options = Enabled(); + options.max_series = 4; + MetricsRegistry registry(options); + for (int i = 0; i < 50; ++i) { + registry.Record(Served("GET", "Op" + std::to_string(i), 200, microseconds(10))); + } + const std::string exposition = registry.Expose(); + EXPECT_TRUE(HasLine( + exposition, + R"(http_server_requests_total{service_name="todo-service",http_method="GET",route="Op0"} 1)")) + << exposition; + EXPECT_EQ(exposition.find(R"(route="Op49")"), std::string::npos) << exposition; + // Four combinations fit; the remaining 46 observations are refused, and + // each is counted exactly once even though both families turned it away. + EXPECT_TRUE( + HasLine(exposition, "metrics_observations_dropped_total{service_name=\"todo-service\"} 46")) + << exposition; +} + +TEST(MetricsRegistryTest, LabelValuesAreEscapedSoTheScrapeStaysParseable) { + // An operation is bounded by the model, but a hand-written handler can + // stamp anything; an unescaped quote would corrupt the whole scrape. + MetricsRegistry registry(Enabled()); + registry.Record(Served("GET", R"(We"ird\Op)", 200, microseconds(10))); + EXPECT_TRUE(HasLine( + registry.Expose(), + R"(http_server_requests_total{service_name="todo-service",http_method="GET",route="We\"ird\\Op"} 1)")) + << registry.Expose(); +} + +// --------------------------------------------------------------------------- +// The in-flight gauge. +// --------------------------------------------------------------------------- + +TEST(MetricsRegistryTest, InFlightRisesOnStartAndFallsOnCompletion) { + MetricsRegistry registry(Enabled()); + registry.RecordStart(RequestStart{.method = "GET", .target = "/a"}); + registry.RecordStart(RequestStart{.method = "GET", .target = "/b"}); + EXPECT_TRUE(HasLine(registry.Expose(), + R"(http_server_requests_active_gauge{service_name="todo-service",)" + R"(http_method="GET"} 2)")) + << registry.Expose(); + + registry.Record(Served("GET", "GetThing", 200, microseconds(10))); + EXPECT_TRUE(HasLine(registry.Expose(), + R"(http_server_requests_active_gauge{service_name="todo-service",)" + R"(http_method="GET"} 1)")) + << registry.Expose(); +} + +TEST(MetricsRegistryTest, CompletionsWithoutStartsLeaveTheGaugeAtZero) { + // RecordStart is optional; an unpaired completion must not drive the gauge + // negative, which would render as a nonsense dashboard forever after. + MetricsRegistry registry(Enabled()); + registry.Record(Served("GET", "GetThing", 200, microseconds(10))); + registry.Record(Served("GET", "GetThing", 200, microseconds(10))); + // The series does not exist at all rather than reading -2: nothing ever + // started, so there is no method key to have driven negative. + EXPECT_EQ(registry.Expose().find("http_server_requests_active_gauge{"), std::string::npos) + << registry.Expose(); +} + +// --------------------------------------------------------------------------- +// Transport rejections: the 413/431 written before any middleware exists. +// --------------------------------------------------------------------------- + +TEST(MetricsRegistryTest, ARejectionIsCountedLikeAnyOtherServedRequest) { + // Without this an over-limit flood is invisible in the counters: the + // transport answers these before the handler chain RecordMetrics wraps. + MetricsRegistry registry(Enabled()); + registry.RecordRejection("POST", 413); + registry.RecordRejection("POST", 413); + EXPECT_TRUE(HasLine( + registry.Expose(), + R"(http_server_requests_total{service_name="todo-service",http_method="POST",route="unmatched"} 2)")) + << registry.Expose(); +} + +TEST(MetricsRegistryTest, ARejectionBeforeTheMethodParsedIsNotAnInventedVerb) { + // A 431 can fire mid-headers, before the method token was read. "never + // parsed" and "client invented a verb" are different diagnoses, so they + // must not share the "other" bucket. + MetricsRegistry registry(Enabled()); + registry.RecordRejection("", 431); + registry.RecordRejection("BREW", 431); + const std::string exposition = registry.Expose(); + EXPECT_TRUE(HasLine(exposition, R"lit(http_server_requests_total{service_name="todo-service",)lit" + R"lit(http_method="(unparsed)",route="unmatched"} 1)lit")) + << exposition; + EXPECT_TRUE(HasLine( + exposition, + R"(http_server_requests_total{service_name="todo-service",http_method="CUSTOM",route="unmatched"} 1)")) + << exposition; +} + +TEST(MetricsRegistryTest, ARejectionFilesNoLatencyAndMovesNoGauge) { + // The improvement over recording a zero observation: a request refused at + // parse time has no service latency, and a flood of zeros would drag + // rate(_sum)/rate(_count) down — making the latency panel look its best + // exactly while the service is being hammered. It was also never in + // flight through a handler, so the gauge must not move either. + MetricsRegistry registry(Enabled()); + registry.Record(Served("POST", "AddThing", 200, microseconds(200000))); // 0.2s + for (int i = 0; i < 50; ++i) { + registry.RecordRejection("POST", 413); + } + + const std::string exposition = registry.Expose(); + // One real observation, and the mean is still that observation. + EXPECT_TRUE(HasLine( + exposition, + R"(http_server_request_duration_microseconds_count{service_name="todo-service",http_method="POST",route="AddThing"} 1)")) + << exposition; + EXPECT_TRUE(HasLine( + exposition, + R"(http_server_request_duration_microseconds_sum{service_name="todo-service",http_method="POST",route="AddThing"} 200000)")) + << exposition; + // No latency series was minted for the rejections at all. + EXPECT_EQ( + exposition.find( + R"(http_server_request_duration_microseconds_count{service_name="todo-service",http_method="POST",route="unmatched"})"), + std::string::npos) + << exposition; + EXPECT_EQ(exposition.find("http_server_requests_active_gauge{"), std::string::npos) << exposition; +} + +TEST(MetricsRegistryTest, TheRejectionSinkFeedsTheRegistry) { + // The shape a consumer wires into BeastServerTransport::Options, checked + // against a stand-in with the same fields — :server keeps no Beast dep. + struct Rejected { + int status = 0; + std::string peer_address{}; + std::string method{}; + std::string target{}; + }; + auto registry = std::make_shared(Enabled()); + auto sink = RecordRejections(registry); + sink(Rejected{.status = 413, .method = "PUT", .target = "/upload/8f3a2b"}); + + const std::string exposition = registry->Expose(); + EXPECT_TRUE(HasLine( + exposition, + R"(http_server_requests_total{service_name="todo-service",http_method="PUT",route="unmatched"} 1)")) + << exposition; + // The target is dropped: a flood against distinct paths mints no series. + EXPECT_EQ(exposition.find("8f3a2b"), std::string::npos) << exposition; +} + +// --------------------------------------------------------------------------- +// Application metrics. +// --------------------------------------------------------------------------- + +TEST(MetricsRegistryTest, ACustomCounterJoinsTheSameScrape) { + MetricsRegistry registry(Enabled()); + auto orders = registry.NewCounter("orders_processed_total", "Orders processed."); + orders.Increment(); + orders.Increment({{"region", "us-east"}}, 4); + + const std::string exposition = registry.Expose(); + EXPECT_TRUE(HasLine(exposition, "# HELP orders_processed_total Orders processed.")) << exposition; + EXPECT_TRUE(HasLine(exposition, "# TYPE orders_processed_total counter")) << exposition; + EXPECT_TRUE(HasLine(exposition, "orders_processed_total 1")) << exposition; + EXPECT_TRUE(HasLine(exposition, R"(orders_processed_total{region="us-east"} 4)")) << exposition; + // The built-in families are still there, whole. + EXPECT_TRUE(HasLine(exposition, "# TYPE http_server_requests_total counter")) << exposition; +} + +TEST(MetricsRegistryTest, AGaugeGoesUpAndDown) { + MetricsRegistry registry(Enabled()); + auto depth = registry.NewGauge("queue_depth", "Pending jobs."); + depth.Set(10); + depth.Increment(5); + depth.Decrement(3); + EXPECT_TRUE(HasLine(registry.Expose(), "queue_depth 12")) << registry.Expose(); +} + +TEST(MetricsRegistryTest, ACustomHistogramExposesBucketsSumAndCount) { + MetricsRegistry registry(Enabled()); + auto sizes = registry.NewHistogram("batch_size", "Rows per batch.", {10.0, 100.0}); + sizes.Observe(5); + sizes.Observe(50); + sizes.Observe(500); + + const std::string exposition = registry.Expose(); + EXPECT_TRUE(HasLine(exposition, R"(batch_size_bucket{le="10"} 1)")) << exposition; + EXPECT_TRUE(HasLine(exposition, R"(batch_size_bucket{le="100"} 2)")) << exposition; + EXPECT_TRUE(HasLine(exposition, R"(batch_size_bucket{le="+Inf"} 3)")) << exposition; + EXPECT_TRUE(HasLine(exposition, "batch_size_sum 555")) << exposition; + EXPECT_TRUE(HasLine(exposition, "batch_size_count 3")) << exposition; +} + +TEST(MetricsRegistryTest, LabelOrderDoesNotSplitASeries) { + // Sorting by name is what keeps {a,b} and {b,a} one series; without it a + // caller that swapped two labels would silently double-count. + MetricsRegistry registry(Enabled()); + auto hits = registry.NewCounter("cache_hits_total", "Cache hits."); + hits.Increment({{"tier", "hot"}, {"region", "eu"}}); + hits.Increment({{"region", "eu"}, {"tier", "hot"}}); + EXPECT_TRUE(HasLine(registry.Expose(), R"(cache_hits_total{region="eu",tier="hot"} 2)")) + << registry.Expose(); +} + +TEST(MetricsRegistryTest, ACustomLabelValueIsEscaped) { + // All three the exposition format requires: quote, backslash, newline. An + // unescaped one corrupts the whole scrape, not just this line. + MetricsRegistry registry(Enabled()); + auto errors = registry.NewCounter("job_errors_total", "Job errors."); + errors.Increment({{"reason", "quote\" back\\slash\nnewline"}}); + EXPECT_TRUE( + HasLine(registry.Expose(), R"(job_errors_total{reason="quote\" back\\slash\nnewline"} 1)")) + << registry.Expose(); +} + +TEST(MetricsRegistryTest, AnUnboundedCustomLabelIsCappedAndAttributed) { + // The whole point of the per-family cap: a label taken from unbounded data + // costs that family its budget and says so, instead of the process. + MetricsOptions options = Enabled(); + options.max_series = 4; + MetricsRegistry registry(options); + auto seen = registry.NewCounter("user_events_total", "User events."); + for (int i = 0; i < 50; ++i) { + seen.Increment({{"user_id", std::to_string(i)}}); + } + const std::string exposition = registry.Expose(); + EXPECT_EQ(exposition.find(R"(user_id="49")"), std::string::npos) << exposition; + EXPECT_TRUE(HasLine( + exposition, + R"(metrics_observations_dropped_total{service_name="todo-service",metric="user_events_total"} 46)")) + << exposition; +} + +// The zero baseline. A series nobody has touched is absent from the scrape, +// and a counter whose first exported sample is its first event's value hides +// that event forever — increase() has nothing earlier to measure against, so +// the panel reads zero, which looks like an answer. + +TEST(MetricsRegistryTest, ADeclaredSeriesExportsAtZeroBeforeAnyEvent) { + MetricsRegistry registry(Enabled()); + auto orders = registry.NewCounter("orders_processed_total", "Orders."); + orders.Declare({{"region", "us-east"}}); + + const std::string exposition = registry.Expose(); + EXPECT_TRUE(HasLine(exposition, R"(orders_processed_total{region="us-east"} 0)")) << exposition; +} + +TEST(MetricsRegistryTest, DeclaringDoesNotDisturbASeriesThatHasEvents) { + // Idempotent, and harmless after the fact: re-declaring must not reset a + // counter that has already counted something. + MetricsRegistry registry(Enabled()); + auto orders = registry.NewCounter("orders_processed_total", "Orders."); + orders.Increment(7); + orders.Declare(); + orders.Declare(); + EXPECT_TRUE(HasLine(registry.Expose(), "orders_processed_total 7")) << registry.Expose(); +} + +TEST(MetricsRegistryTest, ADeclaredHistogramIsEmptyRatherThanAnObservationOfZero) { + // The distinction that matters: a record-only API can only baseline a + // histogram by observing 0, which biases rate(_sum)/rate(_count). Writing + // the exposition directly means the declared series can be genuinely + // empty — every bucket, _sum and _count at 0 — so the first real + // observation is the only one the mean ever sees. + MetricsRegistry registry(Enabled()); + auto sizes = registry.NewHistogram("batch_size", "Rows per batch.", {10.0}); + sizes.Declare(); + + std::string exposition = registry.Expose(); + EXPECT_TRUE(HasLine(exposition, R"(batch_size_bucket{le="10"} 0)")) << exposition; + EXPECT_TRUE(HasLine(exposition, R"(batch_size_bucket{le="+Inf"} 0)")) << exposition; + EXPECT_TRUE(HasLine(exposition, "batch_size_sum 0")) << exposition; + EXPECT_TRUE(HasLine(exposition, "batch_size_count 0")) << exposition; + + // One observation of 4 must read as a mean of 4, not 2 — which is what a + // baseline recorded as an observation would have produced. + sizes.Observe(4); + exposition = registry.Expose(); + EXPECT_TRUE(HasLine(exposition, "batch_size_sum 4")) << exposition; + EXPECT_TRUE(HasLine(exposition, "batch_size_count 1")) << exposition; +} + +TEST(MetricsRegistryTest, ADeclaredGaugeReadsZeroRatherThanBeingAbsent) { + MetricsRegistry registry(Enabled()); + auto depth = registry.NewGauge("queue_depth", "Pending jobs."); + depth.Declare(); + EXPECT_TRUE(HasLine(registry.Expose(), "queue_depth 0")) << registry.Expose(); +} + +TEST(MetricsRegistryTest, DeclaringRespectsTheSeriesCap) { + // Declaration is series creation, so it cannot be a way around the cap. + MetricsOptions options = Enabled(); + options.max_series = 2; + MetricsRegistry registry(options); + auto seen = registry.NewCounter("user_events_total", "User events."); + for (int i = 0; i < 10; ++i) { + seen.Declare({{"user_id", std::to_string(i)}}); + } + const std::string exposition = registry.Expose(); + EXPECT_EQ(exposition.find(R"(user_id="9")"), std::string::npos) << exposition; + EXPECT_TRUE(HasLine( + exposition, + R"(metrics_observations_dropped_total{service_name="todo-service",metric="user_events_total"} 8)")) + << exposition; +} + +TEST(MetricsRegistryTest, ReMintingTheSameFamilyReturnsTheSameSeries) { + // A helper handing out a handle repeatedly must not fork the family. + MetricsRegistry registry(Enabled()); + auto first = registry.NewCounter("widgets_total", "Widgets."); + auto second = registry.NewCounter("widgets_total", "Widgets."); + first.Increment(); + second.Increment(); + EXPECT_TRUE(HasLine(registry.Expose(), "widgets_total 2")) << registry.Expose(); +} + +TEST(MetricsRegistryDeathTest, RegisteringAnInvalidOrCollidingNameAborts) { + // Each of these emits a scrape Prometheus rejects in full, and nothing + // in-process would notice — so they fail at registration (ADR-0009). + EXPECT_DEATH( + { MetricsRegistry(Enabled()).NewCounter("bad-name", "Dashes are not name characters."); }, + ""); + EXPECT_DEATH( + { + MetricsRegistry(Enabled()).NewCounter("http_server_requests_total", "Shadows a built-in."); + }, + ""); + EXPECT_DEATH( + { + MetricsRegistry registry(Enabled()); + registry.NewCounter("thing_total", "One help string."); + registry.NewGauge("thing_total", "One help string."); + }, + ""); +} + +TEST(MetricsRegistryDeathTest, AnInvalidLabelNameAborts) { + EXPECT_DEATH( + { + MetricsRegistry registry(Enabled()); + registry.NewCounter("things_total", "Things.").Increment({{"not a name", "v"}}); + }, + ""); +} + +TEST(MetricsRegistryTest, AHandleOutlivingItsRegistryIsInert) { + // Handles share ownership of the family, so a stray one left in a + // long-lived lambda updates something nobody exposes rather than dangling. + Counter orphan = [] { + MetricsRegistry registry(Enabled()); + return registry.NewCounter("orphan_total", "Orphaned."); + }(); + orphan.Increment(); // must not crash under ASan +} + +// --------------------------------------------------------------------------- +// The composed middleware. +// --------------------------------------------------------------------------- + +TEST(MetricsEndpointTest, ServesTheExpositionWithThePrometheusContentType) { + auto registry = std::make_shared(Enabled()); + http::RequestHandler handler = Chain({MetricsEndpoint(registry)}, Handler()); + + const http::HttpResponse response = handler(Get("/metrics")); + EXPECT_EQ(response.status, 200); + EXPECT_EQ(response.headers.Get("content-type"), "text/plain; version=0.0.4; charset=utf-8"); + EXPECT_TRUE(HasLine(response.body, "# TYPE http_server_requests_total counter")) << response.body; +} + +TEST(MetricsEndpointTest, OtherPathsPassThroughToTheHandler) { + auto registry = std::make_shared(Enabled()); + http::RequestHandler handler = Chain({MetricsEndpoint(registry)}, Handler(201, "MakeThing")); + + const http::HttpResponse response = handler(Get("/things")); + EXPECT_EQ(response.status, 201); + EXPECT_EQ(response.operation, "MakeThing"); +} + +TEST(MetricsEndpointTest, IgnoresTheQueryStringOnItsOwnPath) { + auto registry = std::make_shared(Enabled()); + http::RequestHandler handler = Chain({MetricsEndpoint(registry)}, Handler()); + EXPECT_EQ(handler(Get("/metrics?collect=all")).status, 200); +} + +TEST(MetricsEndpointTest, AHeadIsAnsweredLikeTheGetBodyIncluded) { + // The transport withholds the octets and keeps the length (RFC 9110 + // §9.3.2); emptying the body here would answer a false Content-Length. + auto registry = std::make_shared(Enabled()); + http::RequestHandler handler = Chain({MetricsEndpoint(registry)}, Handler()); + + http::HttpRequest head = Get("/metrics"); + head.method = "HEAD"; + const http::HttpResponse response = handler(head); + EXPECT_EQ(response.status, 200); + EXPECT_EQ(response.body, handler(Get("/metrics")).body); +} + +TEST(MetricsEndpointTest, ARequestOnADifferentMethodFallsThrough) { + auto registry = std::make_shared(Enabled()); + http::RequestHandler handler = Chain({MetricsEndpoint(registry)}, Handler(201, "MakeThing")); + + http::HttpRequest post = Get("/metrics"); + post.method = "POST"; + EXPECT_EQ(handler(post).status, 201); +} + +TEST(MetricsEndpointTest, TheCanonicalChainRecordsTrafficButNotScrapes) { + // The composition the header documents: the endpoint outside the recorder, + // so a scrape answers without inflating the request rate it reports. + auto registry = std::make_shared(Enabled()); + http::RequestHandler handler = + Chain({MetricsEndpoint(registry), RecordMetrics(registry)}, Handler(200, "GetThing")); + + handler(Get("/things")); + handler(Get("/things")); + const std::string exposition = handler(Get("/metrics")).body; + + EXPECT_TRUE(HasLine( + exposition, + R"(http_server_requests_total{service_name="todo-service",http_method="GET",route="GetThing"} 2)")) + << exposition; + // Nothing recorded for the scrape itself: no /metrics route series. + EXPECT_EQ(exposition.find(R"(route="/metrics")"), std::string::npos) << exposition; +} + +TEST(MetricsEndpointTest, RecordMetricsCarriesTheOperationAndStatusFromTheResponse) { + auto registry = std::make_shared(Enabled()); + http::RequestHandler handler = + Chain({MetricsEndpoint(registry), RecordMetrics(registry)}, Handler(503, "GetThing")); + + handler(Get("/things")); + EXPECT_TRUE(HasLine( + handler(Get("/metrics")).body, + R"(http_server_requests_total{service_name="todo-service",http_method="GET",route="GetThing"} 1)")); +} + +TEST(MetricsEndpointTest, HealthProbesAreSeparableFromDispatchFailures) { + // The reason HealthEndpoint labels its own path. Kubernetes polls a probe + // every few seconds, so it is often the highest-volume "route" a service + // has. Sharing the empty operation with 404s means the probe drowns the + // signal in `http_server_requests_total{route="unmatched"}` and the 404 rate + // cannot be read at all — and the probe's own latency, which is not the + // service's, contaminates the same duration series. + auto registry = std::make_shared(Enabled()); + http::RequestHandler handler = + Chain({MetricsEndpoint(registry), RecordMetrics(registry), HealthEndpoint("/livez"), + HealthEndpoint("/readyz", {{"db", [] { return false; }}})}, + [](const http::HttpRequest&) { + http::HttpResponse response; // the router's 404: no operation to stamp + response.status = 404; + return response; + }); + + handler(Get("/livez")); + handler(Get("/readyz")); + handler(Get("/nope")); + + const std::string exposition = handler(Get("/metrics")).body; + EXPECT_TRUE(HasLine( + exposition, + R"(http_server_requests_total{service_name="todo-service",http_method="GET",route="/livez"} 1)")) + << exposition; + EXPECT_TRUE(HasLine( + exposition, + R"(http_server_requests_total{service_name="todo-service",http_method="GET",route="/readyz"} 1)")) + << exposition; + // The 404 keeps the empty operation, and now means only that. + EXPECT_TRUE(HasLine( + exposition, + R"(http_server_requests_total{service_name="todo-service",http_method="GET",route="unmatched"} 1)")) + << exposition; + // Each probe has its own latency series, so `route!~"/livez|/readyz"` is + // expressible; before the label none of these three could be told apart. + // It is also what prom_proxy's `route!="/health"` subtraction depends on. + EXPECT_TRUE(HasLine( + exposition, R"(http_server_request_duration_microseconds_count{service_name="todo-service",)" + R"(http_method="GET",route="/livez"} 1)")) + << exposition; + EXPECT_TRUE(HasLine( + exposition, R"(http_server_request_duration_microseconds_count{service_name="todo-service",)" + R"(http_method="GET",route="/readyz"} 1)")) + << exposition; +} + +TEST(MetricsEndpointTest, TheEndpointLabelsItselfWhenDeliberatelyRecorded) { + // Inverted from the documented order on purpose: a user who wants scrape + // volume as a signal gets a named series rather than an unlabeled one. + auto registry = std::make_shared(Enabled()); + http::RequestHandler handler = + Chain({RecordMetrics(registry), MetricsEndpoint(registry)}, Handler()); + + handler(Get("/metrics")); + const std::string exposition = handler(Get("/metrics")).body; + EXPECT_TRUE(HasLine( + exposition, + R"(http_server_requests_total{service_name="todo-service",http_method="GET",route="/metrics"} 1)")) + << exposition; +} + +TEST(MetricsEndpointTest, AThrowingHandlerStillCompletesItsObservation) { + // Observe pairs start and complete even when dispatch throws (reporting + // 500 with an empty operation) — the gauge must come back down, or an + // in-flight panel climbs forever after the first handler bug. + auto registry = std::make_shared(Enabled()); + http::RequestHandler handler = Chain( + {MetricsEndpoint(registry), RecordMetrics(registry)}, + [](const http::HttpRequest&) -> http::HttpResponse { throw std::runtime_error("bug"); }); + + EXPECT_THROW(handler(Get("/things")), std::runtime_error); + const std::string exposition = handler(Get("/metrics")).body; + // The start did fire, so the series exists — and it came back down. + EXPECT_TRUE(HasLine(exposition, + R"(http_server_requests_active_gauge{service_name="todo-service",)" + R"(http_method="GET"} 0)")) + << exposition; + EXPECT_TRUE(HasLine(exposition, R"(http_server_requests_total{service_name="todo-service",)" + R"(http_method="GET",route="unmatched"} 1)")) + << exposition; + // A thrown handler reports 500, a failure by the 400 boundary. + EXPECT_TRUE(HasLine(exposition, + R"(http_server_requests_failure_total{service_name="todo-service",)" + R"(http_method="GET",route="unmatched"} 1)")) + << exposition; +} + +// --------------------------------------------------------------------------- +// Off by default, and free while it is off. +// --------------------------------------------------------------------------- + +TEST(DisabledRegistryTest, IsTheDefaultAndRecordsNothing) { + // The default. A service can link, construct and wire the whole metrics + // stack and still ship with it dark. + MetricsRegistry registry; + EXPECT_FALSE(registry.enabled()); + + registry.Record(Served("GET", "GetThing", 200, microseconds(1000))); + registry.RecordStart(RequestStart{.method = "GET", .target = "/things"}); + registry.RecordRejection("POST", 413); + // Not "the families with no samples" — nothing at all. An empty 200 on + // /metrics reads to Prometheus as a live target reporting no series, which + // is what a service whose metrics have gone silent also looks like. + EXPECT_EQ(registry.Expose(), ""); +} + +TEST(DisabledRegistryTest, HandlesAreInertRatherThanUnusable) { + // Application code should not have to branch: the handles it already holds + // keep working and simply record nothing, so `enabled` is a deployment + // decision rather than a code-structure one. + MetricsRegistry registry; + auto orders = registry.NewCounter("orders_total", "Orders."); + auto depth = registry.NewGauge("queue_depth", "Pending."); + auto sizes = registry.NewHistogram("payload_bytes", "Payloads.", {10, 100}); + + orders.Increment(); + orders.Increment({{"region", "us-east"}}, 5); + orders.Declare({{"region", "eu-west"}}); + depth.Set(7); + depth.Increment(); + depth.Decrement(); + depth.Declare(); + sizes.Observe(42); + sizes.Declare(); + + EXPECT_EQ(registry.Expose(), ""); +} + +TEST(DisabledRegistryTest, TheMiddlewareComposeToTheIdentity) { + // The actual "zero cost" claim, and the reason it is not a per-request + // branch: a disabled registry contributes no wrapper, so Chain hands back + // the very handler it was given. + // + // A plain function is the terminal on purpose. std::function::target only + // answers for the exact stored type, so `target()` is non-null exactly + // while the function is still what the chain calls, and goes null the + // moment anything wraps it — which is what the enabled half below shows. + using Fn = http::HttpResponse (*)(const http::HttpRequest&); + const Fn terminal = [](const http::HttpRequest&) { return http::HttpResponse{}; }; + + auto off = std::make_shared(); + const http::RequestHandler composed = + Chain({MetricsEndpoint(off), RecordMetrics(off)}, http::RequestHandler(terminal)); + ASSERT_NE(composed.target(), nullptr) + << "a disabled registry wrapped the handler instead of composing away"; + EXPECT_EQ(*composed.target(), terminal); + + auto on = std::make_shared(Enabled()); + const http::RequestHandler wrapped = + Chain({MetricsEndpoint(on), RecordMetrics(on)}, http::RequestHandler(terminal)); + EXPECT_EQ(wrapped.target(), nullptr) + << "an enabled registry has to wrap, or the assertion above proves nothing"; +} + +TEST(DisabledRegistryTest, TheMetricsPathFallsThroughToTheRouter) { + // Follows from composing away: /metrics is not a route this server has, so + // it answers like any other unmodeled path rather than serving an empty + // scrape that would look like a healthy target with nothing to say. + auto registry = std::make_shared(); + http::RequestHandler handler = + Chain({MetricsEndpoint(registry), RecordMetrics(registry)}, Handler(404, "")); + const http::HttpResponse response = handler(Get("/metrics")); + EXPECT_EQ(response.status, 404); + EXPECT_EQ(response.body, ""); +} + +TEST(DisabledRegistryDeathTest, RegistrationStillValidates) { + // The check that must not wait for someone to turn metrics on: if a bad + // name only aborted when enabled, enabling it in production would be the + // first time anyone found out. + EXPECT_DEATH({ MetricsRegistry().NewCounter("bad-name", "Dashes are not names."); }, ""); + EXPECT_DEATH( + { MetricsRegistry().NewCounter("http_server_requests_total", "Shadows a built-in."); }, ""); + EXPECT_DEATH( + { + MetricsRegistry registry; + registry.NewCounter("thing_total", "One help string."); + registry.NewGauge("thing_total", "One help string."); + }, + ""); +} + +// --------------------------------------------------------------------------- +// The MoonBase serving contract, which is the only exposition this emits. +// Every literal below is pinned on the MoonBase side by +// //domains/platform/libs/otel_contract. These tests are what stops this rail +// drifting off it silently — and silence is how such a drift shows up: an +// empty dashboard panel, indistinguishable from a quiet service. +// --------------------------------------------------------------------------- + +TEST(ExpositionContractTest, ExportsTheFiveSharedFamiliesUnderTheirPinnedNames) { + // The names //domains/platform/libs/otel_contract pins across MoonBase's + // three emitter rails, with the descriptions it pins with them: a + // collector merging series by name keeps the first description it sees and + // logs a conflict for every later one that disagrees. + MetricsRegistry registry(Enabled()); + + const std::string exposition = registry.Expose(); + EXPECT_TRUE(HasLine(exposition, "# HELP http_server_requests_total HTTP requests received")) + << exposition; + EXPECT_TRUE(HasLine(exposition, "# TYPE http_server_requests_total counter")) << exposition; + EXPECT_TRUE(HasLine(exposition, + "# HELP http_server_requests_success_total HTTP requests completed " + "successfully (2xx-3xx)")) + << exposition; + EXPECT_TRUE( + HasLine(exposition, + "# HELP http_server_requests_failure_total HTTP requests that returned 4xx or 5xx")) + << exposition; + EXPECT_TRUE(HasLine(exposition, + "# HELP http_server_requests_active_gauge HTTP requests currently in flight")) + << exposition; + EXPECT_TRUE(HasLine(exposition, "# TYPE http_server_requests_active_gauge gauge")) << exposition; + EXPECT_TRUE(HasLine(exposition, + "# HELP http_server_request_duration_microseconds HTTP request duration in " + "microseconds")) + << exposition; + EXPECT_TRUE(HasLine(exposition, "# TYPE http_server_request_duration_microseconds histogram")) + << exposition; + // The registry's own health rides along under a name of its own, outside + // the contract. + EXPECT_TRUE(HasLine(exposition, "# TYPE metrics_observations_dropped_total counter")) + << exposition; +} + +TEST(ExpositionContractTest, LabelsEverySeriesTheWayTheDashboardsSelect) { + // prom_proxy selects `{service_name="x",route!="/health"}` on every query + // it makes, so all three have to be present and spelled this way. + MetricsRegistry registry(Enabled()); + registry.Record(Served("GET", "GetThing", 200, microseconds(1500))); + + const std::string exposition = registry.Expose(); + EXPECT_TRUE(HasLine( + exposition, + R"(http_server_requests_total{service_name="todo-service",http_method="GET",route="GetThing"} 1)")) + << exposition; + EXPECT_TRUE(HasLine( + exposition, R"(http_server_request_duration_microseconds_count{service_name="todo-service",)" + R"(http_method="GET",route="GetThing"} 1)")) + << exposition; + // Microseconds, not seconds: the value is the hook's own unit, undivided. + EXPECT_TRUE(HasLine( + exposition, R"(http_server_request_duration_microseconds_sum{service_name="todo-service",)" + R"(http_method="GET",route="GetThing"} 1500)")) + << exposition; +} + +TEST(ExpositionContractTest, SuccessAndFailureSplitAtFourHundred) { + // ErrorRatePercent is failure/(success+failure), so the split has to land + // where the rest of the fleet draws it: 2xx-3xx succeeded, 4xx and 5xx did + // not. The three counters are views of one tally, so they cannot disagree. + MetricsRegistry registry(Enabled()); + registry.Record(Served("GET", "GetThing", 200, microseconds(100))); + registry.Record(Served("GET", "GetThing", 301, microseconds(100))); + registry.Record(Served("GET", "GetThing", 404, microseconds(100))); + registry.Record(Served("GET", "GetThing", 500, microseconds(100))); + + const std::string exposition = registry.Expose(); + const std::string labels = R"(service_name="todo-service",http_method="GET",route="GetThing")"; + EXPECT_TRUE(HasLine(exposition, "http_server_requests_total{" + labels + "} 4")) << exposition; + EXPECT_TRUE(HasLine(exposition, "http_server_requests_success_total{" + labels + "} 2")) + << exposition; + EXPECT_TRUE(HasLine(exposition, "http_server_requests_failure_total{" + labels + "} 2")) + << exposition; + // Status is not a label in this dialect — the outcome counters carry it, + // and keeping both would multiply every series by the codes observed. + EXPECT_EQ(exposition.find("status="), std::string::npos) << exposition; +} + +TEST(ExpositionContractTest, TheActiveGaugeIsKeyedByMethodAndNeverByRoute) { + // It moves at request start, before dispatch, where no bounded route is + // known. Every rail leaves the route off it for that reason, and + // prom_proxy's `route!="/health"` matcher passes a series without the + // label through untouched — which is why the same filter is safe on it. + MetricsRegistry registry(Enabled()); + registry.RecordStart(RequestStart{.method = "GET", .target = "/things/1"}); + registry.RecordStart(RequestStart{.method = "POST", .target = "/things"}); + registry.RecordStart(RequestStart{.method = "GET", .target = "/things/2"}); + + std::string exposition = registry.Expose(); + EXPECT_TRUE(HasLine( + exposition, + R"(http_server_requests_active_gauge{service_name="todo-service",http_method="GET"} 2)")) + << exposition; + EXPECT_TRUE(HasLine( + exposition, + R"(http_server_requests_active_gauge{service_name="todo-service",http_method="POST"} 1)")) + << exposition; + EXPECT_EQ( + exposition.find("active_gauge{service_name=\"todo-service\",http_method=\"GET\",route="), + std::string::npos) + << exposition; + + // And it comes back down, per method, when those requests complete. + registry.Record(Served("GET", "GetThing", 200, microseconds(10))); + registry.Record(Served("GET", "GetThing", 200, microseconds(10))); + exposition = registry.Expose(); + EXPECT_TRUE(HasLine( + exposition, + R"(http_server_requests_active_gauge{service_name="todo-service",http_method="GET"} 0)")) + << exposition; + EXPECT_TRUE(HasLine( + exposition, + R"(http_server_requests_active_gauge{service_name="todo-service",http_method="POST"} 1)")) + << exposition; +} + +TEST(ExpositionContractTest, UsesTheRouteAndMethodSentinelsTheOtherRailsAgreedOn) { + // Three constants that have to be byte-equal across the rails, because a + // fleet-wide "unmatched traffic" query only means one thing if every + // service spells it the same way. + MetricsRegistry registry(Enabled()); + registry.Record(Served("GET", "", 404, microseconds(10))); + registry.Record(Served("BREW", "GetThing", 200, microseconds(10))); + registry.RecordRejection("", 431); + + const std::string exposition = registry.Expose(); + EXPECT_TRUE(HasLine( + exposition, + R"(http_server_requests_total{service_name="todo-service",http_method="GET",route="unmatched"} 1)")) + << exposition; + EXPECT_TRUE(HasLine( + exposition, + R"(http_server_requests_total{service_name="todo-service",http_method="CUSTOM",route="GetThing"} 1)")) + << exposition; + EXPECT_TRUE(HasLine( + exposition, + R"line(http_server_requests_total{service_name="todo-service",http_method="(unparsed)",route="unmatched"} 1)line")) + << exposition; + // Never the empty route: `route!="/health"` would match it, so unrouted + // traffic would silently join the serving numbers. + EXPECT_EQ(exposition.find(R"(route="")"), std::string::npos) << exposition; +} + +TEST(ExpositionContractTest, TheHealthProbeLandsOnTheRouteThePanelsSubtract) { + // The composition that makes the /health literal real: prom_proxy + // subtracts route!="/health" from every serving number and charts that + // route on its own Probes tile, so a service that never reports it reads + // as having no probe rather than as a healthy one. HealthEndpoint's + // default path is already the literal. + auto registry = std::make_shared(Enabled()); + http::RequestHandler handler = Chain( + {MetricsEndpoint(registry), RecordMetrics(registry), HealthEndpoint()}, Handler(404, "")); + + handler(Get("/health")); + handler(Get("/things/1")); + + const std::string exposition = handler(Get("/metrics")).body; + EXPECT_TRUE(HasLine( + exposition, + R"(http_server_requests_total{service_name="todo-service",http_method="GET",route="/health"} 1)")) + << exposition; + EXPECT_TRUE(HasLine( + exposition, + R"(http_server_requests_total{service_name="todo-service",http_method="GET",route="unmatched"} 1)")) + << exposition; +} + +TEST(ExpositionContractTest, UsesTheMicrosecondBucketLadderTheRailsShare) { + // histogram_quantile reads `le` off bucket counts, so p95 only compares + // like with like when the boundaries match. These are pinned equal across + // the three rails by //domains/platform/libs/otel_contract; a service on a + // different ladder charts a quantile computed against different bins than + // everything beside it. + MetricsRegistry registry(Enabled()); + EXPECT_EQ(HttpLatencyBuckets(), + (std::vector{100, 250, 500, 1000, 2500, 5000, 10000, 25000, 50000, 100000, + 250000, 500000, 1000000, 2500000, 10000000})); + + registry.Record(Served("GET", "GetThing", 200, microseconds(100))); + const std::string exposition = registry.Expose(); + const std::string labels = R"(service_name="todo-service",http_method="GET",route="GetThing")"; + // Buckets are upper-inclusive, which is what `le` means: exactly 100µs + // belongs in the 100 bucket, not the one above it. + EXPECT_TRUE(HasLine( + exposition, "http_server_request_duration_microseconds_bucket{" + labels + R"(,le="100"} 1)")) + << exposition; + EXPECT_TRUE(HasLine(exposition, "http_server_request_duration_microseconds_bucket{" + labels + + R"(,le="10000000"} 1)")) + << exposition; +} + +TEST(ExpositionContractTest, ApplicationMetricsStillShareTheScrape) { + // Switching dialects changes the built-in vocabulary, not the endpoint: a + // service's own numbers still ride the same target. + MetricsRegistry registry(Enabled()); + auto orders = registry.NewCounter("orders_processed_total", "Orders processed."); + orders.Increment(); + + const std::string exposition = registry.Expose(); + EXPECT_TRUE(HasLine(exposition, "orders_processed_total 1")) << exposition; + EXPECT_TRUE(HasLine(exposition, "# TYPE http_server_requests_total counter")) << exposition; +} + +TEST(ExpositionContractDeathTest, EveryBuiltInNameIsReserved) { + // All six, not just the ones a test happened to name: a family shadowing + // any of them appears twice with two TYPE lines, which Prometheus rejects + // whole rather than per line. + for (const std::string name : + {"http_server_requests_total", "http_server_requests_success_total", + "http_server_requests_failure_total", "http_server_requests_active_gauge", + "http_server_request_duration_microseconds", "metrics_observations_dropped_total"}) { + EXPECT_DEATH( + { MetricsRegistry(Enabled()).NewCounter(name, "Shadows a built-in."); }, "") + << name; + } +} + +TEST(ExpositionContractDeathTest, AnEnabledRegistryWithoutAServiceNameAborts) { + // Every dashboard query selects on service_name, so a service reporting + // the empty string is scraped, stored, and absent from all of them — + // success everywhere except the panel nobody is watching yet. + EXPECT_DEATH({ MetricsRegistry registry(MetricsOptions{.enabled = true}); }, ""); + // Disabled it is not required: nothing is exposed to be unfindable. + MetricsRegistry disabled{}; + EXPECT_FALSE(disabled.enabled()); +} + +// Four pins adapted from MoonBase's own rails (aura/middleware_test.cc and +// futility/otel/http_metrics_test.cc). Each catches a class of drift that +// the per-value assertions above would miss, and each is asserted here +// against the rendered scrape rather than against a recording sink — which +// is strictly stronger, since the scrape is what Prometheus actually reads. + +// Every sample line of a built-in family, stripped of its value. +std::vector BuiltInSampleLines(const std::string& exposition) { + std::vector lines; + std::istringstream stream(exposition); + for (std::string line; std::getline(stream, line);) { + if (line.starts_with("http_server_")) { + lines.push_back(line); + } + } + return lines; +} + +TEST(ExpositionContractTest, NoSeriesCarriesTheOldMethodSpelling) { + // futility's #1305 pin, which it needed because that rail alone had + // historically spelled the label `method`. A single stray old spelling + // forks every dashboard series for this service — the query selects + // http_method, finds nothing, and charts an empty panel. Swept across all + // five families rather than asserted per call site, so a family added + // later cannot quietly reintroduce it. + MetricsRegistry registry(Enabled()); + registry.RecordStart(RequestStart{.method = "GET", .target = "/things"}); + registry.Record(Served("GET", "GetThing", 200, microseconds(1000))); + registry.Record(Served("POST", "PutThing", 500, microseconds(1000))); + registry.RecordRejection("PUT", 413); + + const std::vector lines = BuiltInSampleLines(registry.Expose()); + ASSERT_FALSE(lines.empty()); + for (const std::string& line : lines) { + EXPECT_EQ(line.find("{method=\""), std::string::npos) << line; + EXPECT_EQ(line.find(",method=\""), std::string::npos) << line; + EXPECT_NE(line.find("service_name=\"todo-service\""), std::string::npos) << line; + EXPECT_NE(line.find("http_method=\""), std::string::npos) << line; + } +} + +TEST(ExpositionContractTest, AQueryStringDoesNotDefeatTheHealthRoute) { + // The probe is polled with a query string by plenty of orchestrators. If + // that pushed it off the /health route, prom_proxy's subtraction would + // stop matching and the probe's volume would silently rejoin the serving + // numbers — the exact arithmetic error the route label exists to prevent. + auto registry = std::make_shared(Enabled()); + http::RequestHandler handler = Chain( + {MetricsEndpoint(registry), RecordMetrics(registry), HealthEndpoint()}, Handler(404, "")); + + handler(Get("/health?probe=1")); + EXPECT_TRUE(HasLine(handler(Get("/metrics")).body, + R"(http_server_requests_total{service_name="todo-service",)" + R"(http_method="GET",route="/health"} 1)")) + << handler(Get("/metrics")).body; +} + +TEST(ExpositionContractTest, ScannerPathsCollapseIntoOneSeries) { + // The same cardinality rule the cap backstops, stated the way an operator + // meets it: a scanner walking distinct paths must not mint a series per + // path. The cap would eventually stop it, but only after the damage — + // collapsing at the label is what keeps it from starting. + auto registry = std::make_shared(Enabled()); + http::RequestHandler handler = + Chain({MetricsEndpoint(registry), RecordMetrics(registry)}, Handler(404, "")); + + for (const std::string target : {"/wp-login.php", "/admin/config", "/v1/nope?x=1"}) { + handler(Get(target)); + } + + const std::string exposition = handler(Get("/metrics")).body; + EXPECT_TRUE(HasLine(exposition, R"(http_server_requests_total{service_name="todo-service",)" + R"(http_method="GET",route="unmatched"} 3)")) + << exposition; + for (const std::string fragment : {"wp-login", "admin/config", "v1/nope"}) { + EXPECT_EQ(exposition.find(fragment), std::string::npos) + << "a scanned path reached a label: " << exposition; + } +} + +TEST(ExpositionContractTest, InventedMethodsCollapseOnTheGaugeToo) { + // The method label is bounded on the counters (asserted above), but the + // gauge is keyed by method as well and moves at request *start* — so a + // flood of invented verbs would mint a gauge series each unless the same + // normalization runs there. Lowercase "get" is deliberately in the set: + // methods are case-sensitive, so it is an invented token, not GET. + MetricsRegistry registry(Enabled()); + for (const std::string method : {"FOOBAR1", "FOOBAR2", "get"}) { + registry.RecordStart(RequestStart{.method = method, .target = "/echo"}); + } + + const std::string exposition = registry.Expose(); + EXPECT_TRUE(HasLine(exposition, + R"(http_server_requests_active_gauge{service_name="todo-service",)" + R"(http_method="CUSTOM"} 3)")) + << exposition; + for (const std::string token : {"FOOBAR1", "FOOBAR2", R"(http_method="get")"}) { + EXPECT_EQ(exposition.find(token), std::string::npos) << exposition; + } +} + +// The name of the metric a sample line reports, or "" for a comment or a +// blank. Everything before the '{' or the space, which is what the format +// requires to be grouped. +std::string SampleMetricName(const std::string& line) { + if (line.empty() || line.starts_with('#')) { + return ""; + } + const std::size_t end = line.find_first_of("{ "); + return end == std::string::npos ? line : line.substr(0, end); +} + +// The first metric name whose sample lines are split into two or more +// blocks, or "" when every family is contiguous. +std::string FirstSplitFamily(const std::string& exposition) { + std::vector order; + std::istringstream stream(exposition); + for (std::string line; std::getline(stream, line);) { + const std::string name = SampleMetricName(line); + if (!name.empty() && (order.empty() || order.back() != name)) { + order.push_back(name); + } + } + std::set seen; + for (const std::string& name : order) { + if (!seen.insert(name).second) { + return name; + } + } + return ""; +} + +TEST(ExpositionContractTest, EveryFamilyIsContiguous) { + // Prometheus 0.0.4 requires all lines of a metric to arrive as one group. + // The drop counter used to be emitted unlabeled, then the application + // families, then its own per-family attributions — splitting it in two, + // which a strict parser rejects and a lenient one silently mis-stores. + MetricsOptions options = Enabled(); + options.max_series = 1; + MetricsRegistry registry(options); + registry.RecordStart(RequestStart{.method = "GET", .target = "/things"}); + registry.Record(Served("GET", "GetThing", 200, microseconds(1000))); + registry.Record(Served("POST", "PutThing", 500, microseconds(1000))); // over the cap + + auto counter = registry.NewCounter("widgets_total", "Widgets."); + auto gauge = registry.NewGauge("queue_depth", "Pending."); + auto sizes = registry.NewHistogram("payload_bytes", "Payloads.", {10, 100}); + counter.Increment(); + gauge.Set(3); + sizes.Observe(42); + for (int i = 0; i < 5; ++i) { + counter.Increment({{"shard", std::to_string(i)}}); // over the cap, attributed + } + + const std::string exposition = registry.Expose(); + EXPECT_EQ(FirstSplitFamily(exposition), "") << exposition; + // And the attribution is still there, next to the unlabeled total. + EXPECT_TRUE(HasLine(exposition, + R"(metrics_observations_dropped_total{service_name="todo-service",)" + R"(metric="widgets_total"} 5)")) + << exposition; +} + +TEST(ExpositionContractTest, HelpTextIsEscapedSoItCannotForgeALine) { + // HELP runs to the end of the line and an application family's help is a + // caller's string. A newline in it would end the HELP line early and let + // whatever follows pose as its own directive. + MetricsRegistry registry(Enabled()); + auto counter = registry.NewCounter("widgets_total", "Widgets.\n# TYPE forged_total counter"); + counter.Increment(); + + const std::string exposition = registry.Expose(); + EXPECT_TRUE(HasLine(exposition, R"(# HELP widgets_total Widgets.\n# TYPE forged_total counter)")) + << exposition; + EXPECT_FALSE(HasLine(exposition, "# TYPE forged_total counter")) + << "a newline in help forged a TYPE line: " << exposition; + + // A backslash is escaped too, or it would eat the character after it. + MetricsRegistry other(Enabled()); + auto slashed = other.NewCounter("paths_total", R"(Paths like C:\temp.)"); + slashed.Increment(); + EXPECT_TRUE(HasLine(other.Expose(), R"(# HELP paths_total Paths like C:\\temp.)")) + << other.Expose(); +} + +TEST(MetricsRegistryTest, TheCapCannotSplitACountFromItsLatency) { + // The counters and the histogram share one key and one admission, so a + // route that is past the cap is refused from all four families at once. + // They were once keyed differently — counters by {method,route,status}, + // the histogram by {method,route} — so the counter map filled first, and + // past that point a new status on an already-admitted route was refused + // by the counters while the histogram, whose key already existed, kept + // recording. requests_total silently stopped counting while _count rose. + MetricsOptions options = Enabled(); + options.max_series = 2; + MetricsRegistry registry(options); + registry.Record(Served("GET", "GetThing", 200, microseconds(1000))); + registry.Record(Served("GET", "PutThing", 200, microseconds(1000))); // cap now full + + // A new status on an already-admitted route: same key, so it counts. + registry.Record(Served("GET", "GetThing", 500, microseconds(1000))); + // A genuinely new route: refused, and counted as refused. + registry.Record(Served("GET", "Unseen", 200, microseconds(1000))); + + const std::string exposition = registry.Expose(); + const std::string labels = R"(service_name="todo-service",http_method="GET",route="GetThing")"; + EXPECT_TRUE(HasLine(exposition, "http_server_requests_total{" + labels + "} 2")) << exposition; + EXPECT_TRUE(HasLine(exposition, "http_server_requests_success_total{" + labels + "} 1")) + << exposition; + EXPECT_TRUE(HasLine(exposition, "http_server_requests_failure_total{" + labels + "} 1")) + << exposition; + // The number that used to drift: the histogram agrees with the counter. + EXPECT_TRUE( + HasLine(exposition, "http_server_request_duration_microseconds_count{" + labels + "} 2")) + << exposition; + + EXPECT_EQ(exposition.find(R"(route="Unseen")"), std::string::npos) << exposition; + EXPECT_TRUE( + HasLine(exposition, R"(metrics_observations_dropped_total{service_name="todo-service"} 1)")) + << exposition; +} + +TEST(MetricsRegistryTest, ARejectedRouteIsCountedWithoutInventingAHistogram) { + // Rejections share the unmatched route with 404s. The route is counted, + // and the histogram counts only the requests that were actually timed — + // an all-zero histogram would claim an observation nobody filed. + MetricsRegistry registry(Enabled()); + registry.RecordRejection("PUT", 413); + registry.RecordRejection("PUT", 413); + + const std::string exposition = registry.Expose(); + const std::string labels = R"(service_name="todo-service",http_method="PUT",route="unmatched")"; + EXPECT_TRUE(HasLine(exposition, "http_server_requests_total{" + labels + "} 2")) << exposition; + EXPECT_TRUE(HasLine(exposition, "http_server_requests_failure_total{" + labels + "} 2")) + << exposition; + EXPECT_EQ(exposition.find("http_server_request_duration_microseconds_count{" + labels), + std::string::npos) + << exposition; +} + +TEST(MetricsRegistryDeathTest, AnUnusableHistogramLadderAborts) { + // The guide promises this, and the built-in ladder gets it for free by + // being a constant. An unsorted ladder yields cumulative buckets that + // disagree with themselves — plausible nonsense on a dashboard rather + // than a loud failure (ADR-0009). + EXPECT_DEATH({ MetricsRegistry(Enabled()).NewHistogram("a_bytes", "A.", {}); }, ""); + const std::vector descending = {100, 10}; + EXPECT_DEATH({ MetricsRegistry(Enabled()).NewHistogram("b_bytes", "B.", descending); }, ""); + const std::vector repeated = {10, 10}; + EXPECT_DEATH({ MetricsRegistry(Enabled()).NewHistogram("c_bytes", "C.", repeated); }, ""); + const std::vector infinite = {10, std::numeric_limits::infinity()}; + EXPECT_DEATH({ MetricsRegistry(Enabled()).NewHistogram("d_bytes", "D.", infinite); }, ""); +} + +} // namespace +} // namespace smithy::server diff --git a/runtime/tests/server/middleware_test.cc b/runtime/tests/server/middleware_test.cc index f4c94ce..580147f 100644 --- a/runtime/tests/server/middleware_test.cc +++ b/runtime/tests/server/middleware_test.cc @@ -103,6 +103,120 @@ TEST(ObserveTest, ReportsMethodTargetStatusAndDuration) { EXPECT_EQ(observations[0].duration, std::chrono::microseconds(750)); } +TEST(ObserveTest, ReportsBodySizesOnBothSides) { + std::vector observations; + auto handler = Chain({Observe([&](const RequestObservation& o) { observations.push_back(o); })}, + [](const http::HttpRequest&) { return Ok("twelve chars"); }); + + http::HttpRequest request; + request.method = "POST"; + request.target = "/things"; + request.body = "four"; + (void)handler(request); + + ASSERT_EQ(observations.size(), 1u); + EXPECT_EQ(observations[0].request_bytes, 4u); + EXPECT_EQ(observations[0].response_bytes, 12u); +} + +TEST(ObserveTest, AThrownHandlerIsDistinguishableFromADeliberateFiveHundred) { + // Both report 500 with no operation, and an access log that cannot tell + // them apart sends whoever reads a 5xx spike looking for the wrong thing. + // The thrown one also has no response, so its response_bytes is 0 — + // handler_threw is what says that is an absence rather than an empty body. + std::vector observations; + auto thrown = Chain({Observe([&](const RequestObservation& o) { observations.push_back(o); })}, + [](const http::HttpRequest&) -> http::HttpResponse { + throw std::runtime_error("handler exploded"); + }); + EXPECT_THROW((void)thrown({}), std::runtime_error); + + auto deliberate = + Chain({Observe([&](const RequestObservation& o) { observations.push_back(o); })}, + [](const http::HttpRequest&) { + http::HttpResponse response; + response.status = 500; + response.body = "sorry"; + return response; + }); + (void)deliberate({}); + + ASSERT_EQ(observations.size(), 2u); + EXPECT_EQ(observations[0].status, 500); + EXPECT_TRUE(observations[0].handler_threw); + EXPECT_EQ(observations[0].response_bytes, 0u); + + EXPECT_EQ(observations[1].status, 500); + EXPECT_FALSE(observations[1].handler_threw); + EXPECT_EQ(observations[1].response_bytes, 5u); +} + +TEST(ObserveTest, TheClientIsTheDerivedOneNotTheForgeableHeader) { + // The gap this closes: PerClientRateLimit keys on the ADR-0012 derived + // client, so an observation carrying the raw x-forwarded-for could not say + // whose bucket a 429 came from. Behind a trusted proxy the header's client + // entry is the answer; the proxy's own address is not. + auto trusted = http::TrustedProxies::Parse({"10.0.0.0/8"}); + ASSERT_TRUE(trusted.ok()) << trusted.error().message(); + + std::vector observations; + auto handler = Chain({Observe([&](const RequestObservation& o) { observations.push_back(o); }, + nullptr, nullptr, *trusted)}, + [](const http::HttpRequest&) { return Ok("served"); }); + + http::HttpRequest request; + request.method = "GET"; + request.target = "/things"; + request.peer_address = "10.1.2.3"; // the proxy, inside the trust set + request.headers.Set("x-forwarded-for", "203.0.113.7, 10.1.2.3"); + (void)handler(request); + + ASSERT_EQ(observations.size(), 1u); + EXPECT_EQ(observations[0].client.address, "203.0.113.7"); + EXPECT_EQ(observations[0].client.source, http::DerivedClient::Source::kForwarded); +} + +TEST(ObserveTest, AnUntrustedPeerIsTheClientAndItsHeaderIsIgnored) { + // The forgery case, and the reason the raw header is the wrong thing to + // log: a direct client claiming to be someone else must not be believed. + // Unset trust is TrustedProxies::None(), so every peer is untrusted. + std::vector observations; + auto handler = Chain({Observe([&](const RequestObservation& o) { observations.push_back(o); })}, + [](const http::HttpRequest&) { return Ok("served"); }); + + http::HttpRequest request; + request.method = "GET"; + request.target = "/things"; + request.peer_address = "198.51.100.9"; + request.headers.Set("x-forwarded-for", "1.2.3.4"); + (void)handler(request); + + ASSERT_EQ(observations.size(), 1u); + EXPECT_EQ(observations[0].client.address, "198.51.100.9"); + EXPECT_EQ(observations[0].client.source, http::DerivedClient::Source::kUntrustedHeaderIgnored) + << "the forged header was believed"; +} + +TEST(ObserveTest, TheClientIsReportedOnTheThrownPathToo) { + // The 500s are exactly when someone wants to know who was calling. + std::vector observations; + auto handler = Chain({Observe([&](const RequestObservation& o) { observations.push_back(o); })}, + [](const http::HttpRequest&) -> http::HttpResponse { + throw std::runtime_error("handler exploded"); + }); + + http::HttpRequest request; + request.method = "GET"; + request.target = "/boom"; + request.peer_address = "198.51.100.9"; + request.body = "payload"; + EXPECT_THROW((void)handler(request), std::runtime_error); + + ASSERT_EQ(observations.size(), 1u); + EXPECT_EQ(observations[0].client.address, "198.51.100.9"); + EXPECT_EQ(observations[0].request_bytes, 7u); +} + TEST(ObserveTest, TracesAreNeverEmptyWhenServedThroughATransport) { // ADR-0011: the transport ingress (server_dispatch.h) mints a root // traceparent when the client sent none, so an Observe composed under any @@ -422,6 +536,50 @@ TEST(HealthEndpointTest, AnswersGetOnThePath) { EXPECT_FALSE(reached); } +TEST(HealthEndpointTest, LabelsItsResponseWithItsOwnPath) { + // Without this the probe reports as the empty operation, which is what a + // 404 reports too — so a metrics backend cannot tell a liveness probe from + // a request for a route that does not exist. + auto live = + Chain({HealthEndpoint("/livez")}, [](const http::HttpRequest&) { return Ok("router"); }); + auto ready = Chain({HealthEndpoint("/readyz", {{"db", [] { return false; }}})}, + [](const http::HttpRequest&) { return Ok("router"); }); + + http::HttpRequest request; + request.method = "GET"; + request.target = "/livez"; + EXPECT_EQ(live(request).operation, "/livez"); + + // The 503 path is labeled too: an unhealthy probe is the one you most need + // to find on a dashboard. + request.target = "/readyz"; + const auto unhealthy = ready(request); + EXPECT_EQ(unhealthy.status, 503); + EXPECT_EQ(unhealthy.operation, "/readyz"); + + // Two instances on one server stay distinguishable rather than collapsing + // into a single "health" bucket, and a HEAD is labeled like its GET. + http::HttpRequest head; + head.method = "HEAD"; + head.target = "/livez"; + EXPECT_EQ(live(head).operation, "/livez"); + head.target = "/readyz"; + EXPECT_EQ(ready(head).operation, "/readyz"); +} + +TEST(HealthEndpointTest, LeavesTheOperationToTheRouterOnPassThrough) { + auto handler = Chain({HealthEndpoint()}, [](const http::HttpRequest&) { + http::HttpResponse response; + response.operation = "GetThing"; + return response; + }); + + http::HttpRequest request; + request.method = "GET"; + request.target = "/things/1"; + EXPECT_EQ(handler(request).operation, "GetThing"); +} + TEST(HealthEndpointTest, IgnoresTheQueryString) { auto handler = Chain({HealthEndpoint()}, [](const http::HttpRequest&) { return Ok("router"); }); http::HttpRequest request;