diff --git a/CHANGELOG.md b/CHANGELOG.md index a8c561d..e370525 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,8 +6,91 @@ 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 `method` + outside the standard set collapses to `other`, 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..5bab5a0 100644 --- a/docs/production-guide.md +++ b/docs/production-guide.md @@ -203,8 +203,9 @@ 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 + // Observe everything admitted — health probes included, reporting + // `operation` as their own path so a dashboard can filter them out. + // on_start (optional) enables an in-flight gauge; on_complete carries // method/target/operation/status/duration/trace_parent. smithy::server::Observe( [](const smithy::server::RequestObservation& o) { @@ -339,7 +340,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 +350,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 +391,175 @@ 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}); +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 (`operation=""`, 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. A method that +never parsed (a 431 can fire mid-headers) is labeled `unparsed` rather than +`other`, 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..b394090 100644 --- a/examples/bazel-consumer/BUILD.bazel +++ b/examples/bazel-consumer/BUILD.bazel @@ -130,6 +130,22 @@ 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 = "todo_beast_acceptance_test", size = "small", 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..bd686d7 --- /dev/null +++ b/runtime/include/smithy/server/metrics.h @@ -0,0 +1,468 @@ +#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. +// - `method` arrives from the wire, so it is whatever a client typed. +// Anything outside the standard set collapses to "other" 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 "other", + // 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. + 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 CountKey { + std::string method; + std::string route; + int status = 0; + + friend bool operator<(const CountKey& a, const CountKey& b) { + return std::tie(a.method, a.route, a.status) < std::tie(b.method, b.route, b.status); + } + }; + + struct LatencyKey { + std::string method; + std::string route; + + friend bool operator<(const LatencyKey& a, const LatencyKey& b) { + return std::tie(a.method, a.route) < std::tie(b.method, b.route); + } + }; + + // One histogram: per-bucket counts (parallel to buckets_, non-cumulative + // here and accumulated at exposition time) plus the sum and count the + // format also carries. + struct HistogramData { + std::vector counts{}; + // In whichever unit options_.latency_unit names. + double sum = 0.0; + std::uint64_t 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; + + MetricsOptions options_; + mutable std::mutex mutex_; + std::map counts_; + std::map latencies_; + // 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..9751d71 --- /dev/null +++ b/runtime/src/server/metrics.cc @@ -0,0 +1,608 @@ +#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'; +} + +void AppendFamilyHeader(std::string& out, std::string_view name, std::string_view type, + std::string_view help) { + out += "# HELP "; + out += name; + out += ' '; + out += 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)]; +} + +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 CountKey count_key{ + .method = NormalizeMethod(observation.method), + .route = observation.operation.empty() ? std::string(kUnmatchedRoute) : observation.operation, + .status = observation.status}; + const LatencyKey latency_key{.method = count_key.method, .route = count_key.route}; + + const std::lock_guard lock(mutex_); + // Only decrement a gauge that was incremented: without RecordStart wired up + // the gauge stays at zero rather than counting downward forever. + if (auto in_flight = in_flight_.find(count_key.method); + in_flight != in_flight_.end() && in_flight->second > 0) { + --in_flight->second; + } + + // One observation refused is one increment, whichever family had to turn + // it away — the counter answers "how much traffic am I blind to", so + // counting it once per family would overstate the gap. + bool dropped = false; + if (auto found = counts_.find(count_key); found != counts_.end()) { + ++found->second; + } else if (counts_.size() < options_.max_series) { + counts_.emplace(count_key, 1); + } else { + dropped = true; + } + + auto latency = latencies_.find(latency_key); + if (latency == latencies_.end() && latencies_.size() >= options_.max_series) { + dropped = true; + } else { + if (latency == latencies_.end()) { + latency = latencies_ + .emplace(latency_key, HistogramData{.counts = std::vector( + HttpLatencyBuckets().size(), 0)}) + .first; + } + HistogramData& histogram = latency->second; + histogram.sum += duration; + ++histogram.count; + // The first bucket at or above the value; a value past the last one + // lands only in +Inf, which the exposition takes from `count`. Buckets + // are upper-inclusive, which is what `le` means. + const auto bucket = std::ranges::lower_bound(HttpLatencyBuckets(), duration); + if (bucket != HttpLatencyBuckets().end()) { + ++histogram.counts[static_cast(bucket - HttpLatencyBuckets().begin())]; + } + } + if (dropped) { + ++observations_dropped_; + } +} + +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 CountKey key{ + .method = method.empty() ? std::string(kUnparsedMethod) : NormalizeMethod(method), + .route = std::string(kUnmatchedRoute), + .status = status}; + const std::lock_guard lock(mutex_); + if (auto found = counts_.find(key); found != counts_.end()) { + ++found->second; + } else if (counts_.size() < options_.max_series) { + counts_.emplace(key, 1); + } else { + ++observations_dropped_; + } +} + +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) { + 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 — std::map keeps every series of + // a family contiguous, which the format requires. Headers print even with + // no samples yet, so a freshly started server still describes its shape. + // + // The three request counters are views of one tally rather than three + // tallies: success and failure are derived from the same status-keyed + // counts the total sums, so they cannot disagree with it or with each + // other, and they need no drop accounting of their own. + struct Outcome { + std::uint64_t total = 0; + std::uint64_t success = 0; + std::uint64_t failure = 0; + }; + std::map by_route; + for (const auto& [key, value] : counts_) { + Outcome& outcome = by_route[LatencyKey{.method = key.method, .route = key.route}]; + outcome.total += value; + // The 400 boundary is the one the rest of the fleet already draws: + // 2xx-3xx succeeded, 4xx and 5xx did not. + if (key.status < 400) { + outcome.success += value; + } else { + outcome.failure += value; + } + } + const auto route_labels = [this](const LatencyKey& 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 Outcome::*field) { + AppendFamilyHeader(out, name, "counter", help); + for (const auto& [key, outcome] : by_route) { + AppendSample(out, name, "", route_labels(key), std::to_string(outcome.*field)); + } + }; + counter_family(kRequestsTotal, kRequestsTotalHelp, &Outcome::total); + counter_family(kRequestsSuccess, kRequestsSuccessHelp, &Outcome::success); + counter_family(kRequestsFailure, kRequestsFailureHelp, &Outcome::failure); + + AppendFamilyHeader(out, kRequestDuration, "histogram", kRequestDurationHelp); + for (const auto& [key, histogram] : latencies_) { + 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 += histogram.counts[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(histogram.count)); + AppendSample(out, kRequestDuration, "_sum", labels, FormatNumber(histogram.sum)); + AppendSample(out, kRequestDuration, "_count", labels, std::to_string(histogram.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)); + } + + AppendFamilyHeader(out, kObservationsDropped, "counter", kObservationsDroppedHelp); + AppendSample(out, kObservationsDropped, "", BuiltInLabels({}), + std::to_string(observations_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. `dropped` rides on the family's + // own line rather than the built-in counter, so a runaway label on one + // application metric is attributable to it. + 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)); + } + if (family->dropped != 0) { + AppendSample(out, kObservationsDropped, "", BuiltInLabels({{"metric", name}}), + std::to_string(family->dropped)); + } + } + 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..22c1680 --- /dev/null +++ b/runtime/tests/server/metrics_test.cc @@ -0,0 +1,1186 @@ +// 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 "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; + } +} + +} // 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;