diff --git a/CHANGELOG.md b/CHANGELOG.md index 4052da676..0ba79e890 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -10,6 +10,131 @@ Semver applies from 1.0.0. A breaking change to a documented API needs a major ### Fixed +- **A `cache:` query served one actor's rows to the next.** `cacheKeyFor` returned + `query:::` — no actor, no tenant — and `readThrough` wrote that + key into a **process-wide** tier, while `sql(input, ctx)` is handed the `Ctx` and `@ultimat3/entity` + scopes every tenant-scoped read off `ctx.actor.orgId`. Reproduced: a query declaring + `cache: { tags: [], ttlMs: 60_000 }` and filtering on `ctx.actor.orgId` answered an **`org-b`** + actor with `{id:'a1', orgId:'org-a', secret:'ALPHA'}`. Cross-tenant disclosure, no attacker + required — two logged-in users and one cached query. + + The key now carries the read's authority: `query::::`, where + the authority is `JSON.stringify([kind, id, orgId ?? null])`. JSON rather than a joined string + because an actor id containing the separator could otherwise spell a boundary it does not own — + the rule `@ultimat3/entity`'s `scopeKey` already states. A new `cache.scope` picks the sharing + width: **`'actor'` (the default)**, `'tenant'`, or `'global'`. The default is the narrowest, which + is what makes forgetting safe; widening is a written claim that the rows do not vary by caller, + and `'tenant'` with no `orgId` narrows to the actor rather than widening to everyone. A fourth + scope is an `assertNever` compile error. The **request memo was never affected** — it keys on `ctx` + identity and `.as()` mints a child context — so only the tier key was wrong. + +- **An action's `cache.invalidates` busted nothing on any deployment without Redis.** The read cache + was installed beside the tier registry rather than inside it, and `invalidateTags` fans out to + registered tiers only; `invalidateQueryTags` — the function that would have closed the gap — had + **zero production callers**. So after an invalidation reported `errors: []` over + `['request-memo','lru']`, a fresh `Ctx` was served pre-write rows without executing the source. + The read cache is now always a view of an object the same boot also registers, so it sits inside + the one fan-out. This one landed first: it produces a failure indistinguishable from the two + race conditions below and would have masked them in any reproduction. + +- **An invalidation landing while a read was in flight was overwritten by pre-write rows, for the + full TTL.** T0 miss → `run()`; T1 a mutator commits and the bust drops a key that is not there + yet (a no-op); T2 `run()` resolves with rows read *before* the write; T3 the fill publishes them. + Invisible to every reader until the TTL expired, and the invalidation report said `errors: []`. + A read-through fill now samples a **fence** before the source read and re-checks it before every + tier write, taking back what it already wrote. The fence is a bounded ring of recent invalidation + marks (`FENCE_MEMORY = 1024`) sampled by generation, not a per-tag epoch map: a map keyed by tag + is unbounded and a single global counter over-invalidates every fill. It degrades + **conservatively** — a sample older than the ring proves answers invalid, on the argument that one + refetch beats a stale TTL. `markInvalidated` fires on an explicit `write` too, since a write is + newer truth than a load already in flight. + + This is the executed path for every `cache:` query: `runQuery` → `readRows` → `readThrough` → + `fill`. `createCacheStack` carries the same fence and **still has no production caller**, so its + copy is dormant. The fence is also **per process** — two pods can still interleave a load on one + with a write and bust on the other; that residual has a `wiki/Known-Gaps.md` row. + +- **Two ordering defects on the shared Redis tier, and fixing the second one alone would have made + it worse.** The invalidation script dropped the tag bucket atomically with `SMEMBERS`, so a + refusal in the client-side `DEL` batch orphaned the surviving members permanently — a retry + answered `keys: []` and those value keys lived out their TTL unreachable. And `set` wrote the + value key before the tag `SADD`s, so a bust landing between them found an empty bucket and the + just-written value survived its own invalidation. Reversing that order **on its own is worse**: + `SADD`-then-`SET` with no re-check lets the bust `SREM` the membership and the later `SET` + publish a row unreachable by *any* tag, so it can never be invalidated at all. Both halves landed + together — buckets joined first, then `SET`, then an `SISMEMBER` re-check that deletes the value + it just wrote when a bucket says it is gone (only a literal `0` counts as evidence; a reply the + tier cannot read is not). The sweep now `DEL`s, then `SREM`s **only the members that actually + died**, and rethrows the first refusal. Every command stays single-key and slot-local, so the + Redis Cluster and Dragonfly fix from 1.2.0 is not reintroduced. Proven against a real Redis, not + a fake. + +- **Invalidation fanned out in read order, so a racing read promoted a stale value backwards.** + After `invalidateTags` returned `errors: []` over `['request-memo','lru','redis']`, `lru.get` + still answered `'STALE'` — a read racing the bust pulled the value out of the not-yet-cleared far + tier and promoted it into the already-cleared near ones. The fan-out and `CacheStack.drop` now + clear **farthest-first**; the report is re-sorted into read order afterwards so the `/_x` panel is + unchanged. + +- **One transient database error killed the `worker` role, permanently and silently.** A rejecting + `fleetSlots.acquire()` left the in-process limiter lease unreleased, so each failure burned one + concurrency slot for good. Proven: a concurrency-4 worker whose lease store rejects four times + reports `limiter.inFlight() === 4` and then claims nothing — after the store recovers, + `worker.tick()` returns 0 executions, forever. The only symptom was four `jobs.worker.tick-failed` + lines and a climbing queue depth. The acquire now runs inside a `try` whose `catch` releases + before rethrowing. + +- **A fleet-slot renewal answering `false` was discarded, so `job.concurrency` was silently + exceeded.** `LeaseStore.renew` documents `false` as "the slot is no longer this holder's" and + `SQL_LEASE_RENEW` is guarded on `holder = $3` for exactly that, but the renewal was + fire-and-forget. A worker stalling past the slot TTL kept running after another worker took slot + 0 — two concurrent runs under `concurrency: 1`, nothing logged. The renewal now reads its answer, + stops the timer, logs, and aborts the run with the new `X_JOB_SLOT_LOST`. The file's own comment + claiming "the heartbeat is what reports a lost lease" was **wrong** and is deleted: the heartbeat + renews `x_jobs.visible_at`, a different row on a different clock. + +- **`OutboxRelay.stop()` did not join the tick in flight** — the one loop in the package whose + `stop()` did not, where `worker.ts` and `scheduler.ts` both do. A SIGTERM between `driver.enqueue` + and `markPublished` either re-published the row next boot or hit a closed pool. It now awaits the + pass, and the dev runtime's two teardown paths hold the promise rather than dropping it. + +- **`x jobs ls` against `x dev` paged the hundred *oldest* rows.** The memory driver's + `introspect.list` sorted `createdAt` ascending where the Postgres driver sorts `created_at desc`, + and the limit lands after the sort — so an operator looking for what had just broken got the + oldest jobs in the queue. The two drivers now answer the same question, pinned by a new + `driver-parity.test.ts`; there was no driver-parity mechanism in the package before this. + +- **`configureLifecycle({ deadlineMs })` did not bound a drain at all.** Only the in-flight wait was + bounded; every shutdown hook was awaited with no deadline, so the file header's "under one + deadline" was false. Proven: `deadlineMs: 100` with one 5-second `accept`-phase hook resolved + after **5053 ms**. A `worker` pod holding a 10-minute job ignored its budget and was SIGKILLed + mid-job by the kubelet — turning at-least-once into the every-deploy duplicate that draining + exists to prevent. Each phase is now raced against the remaining budget. See *Changed* for the + behaviour this now has by default. + +- **A statement from a finished transaction landed inside the next one.** The PGlite driver skipped + its turn queue whenever an `AsyncLocalStorage` transaction store was present, and that store + survives into any promise chain started inside a transaction body — so a statement an app forgot + to `await` jumped the single-session queue into somebody else's open transaction. Reproduced as + `BEGIN, select 'inside tx', COMMIT, BEGIN, select 'straggler', select 'inside tx 2', COMMIT`. The + fence is now the transaction's **liveness**, not the store's presence. The late statement takes + its own turn quietly, matching what the pooled driver already does — a throw here would mean an + app that works in production crashes under `x dev`. + +- **A `cache.ttlMs` mistake became a permanent runtime failure.** Nothing validated it at + declaration, so `ttlMs: Infinity` compiled, passed review, and made **every** read of that query + fail forever with `X_CACHE_TTL_INVALID`. `query()` now refuses it at declaration with the new + `X_QUERY_CACHE_TTL_INVALID`. + +- **A dropped `await` was caught by nothing, and the deployed app was linted against nothing.** + Three floating promises shipped in this one sweep — a relay teardown, an outbox pass, and an + `authorize` call in a test that therefore asserted nothing at all. `lint/nursery/noFloatingPromises` + is now `error`: 2 pre-existing violations repo-wide, 3884 files, and `bun run lint` costs 6s → 7.1s. + Found while enabling it: `dummy/social-media-clone/biome.json` set `"root": false` with **no + `extends`**, so the one **deployed** app inherited none of the repo's lint rules — proven both ways + with a planted probe. It now extends the root, and its config no longer pins a stale Biome schema + or a field Biome will remove in its next major. + - **A subscribe cap was checked before the registration that grows the count, so one batch of frames walked past every one of them.** `LiveQueryRegistry.subscribe` called `assertCapacity` at the top and attached the subscription three awaits later; `ChannelHub.subscribe` read @@ -361,10 +486,82 @@ Semver applies from 1.0.0. A breaking change to a documented API needs a major - **A ledger the MCP host cannot read is not an empty ledger.** `db.migrate`'s dry run mapped every `readLedger()` failure to `[]`, so a permission denied or an unreachable server reported every migration as pending. Only Postgres' `undefined_table` does that now, through the new `isLedgerMissing()`; everything else propagates. +- **Four repo-scanning gate tests no longer time out under their own sharding.** `x test unit` + runs eight shards competing for the same cores, and four tests in `scripts/` pay a whole-repo + cost against bun's default 5000ms budget: `boundaries.test.ts`'s two `collectSourceFiles(repoRoot())` + scans, `manifest.test.ts`'s `buildManifest(repoRoot())` `beforeAll`, and `verify.test.ts`'s error + reference check — which is not a directory walk at all, but `registeredErrorCodes()` dynamically + importing all 29 packages no matter how small the temp dir it was handed. Serially all four pass + in well under a second of headroom; under contention that headroom is exactly what disappears, + and **which** shard a file lands in depends on the file count, so it presented as an intermittent + failure rather than a slow test. It surfaced now because this release adds files: every + repo-scanning test got slower. + + The budget moves to `30_000`, following `error-contract.test.ts`, which had already been fixed + this way and whose comment ends "same shape as `scripts/verify.test.ts`" — the diagnosis was + written down and never applied to the file it named. Both `collectSourceFiles` tests moved, not + just the one observed failing: they call the identical scan, so fixing one relocates the failure + to another shard on another run. Proven by reproducing the failure under the gate's own + `--workers 8` command and re-running it after the fix, once plain and once with four extra CPU + hogs — 16 of 16 shard processes exit 0. + - **`scripts/stdout-truncation.test.ts` no longer asserts a race.** The premise case measured a naive `process.stdout.write` against a reader draining concurrently, and on a fast runner the whole payload landed by luck — a flaky gate step. It now writes past any kernel buffer and reads nothing until the child has exited, so what `process.exit()` discarded was genuinely discarded. ### Changed +- **BREAKING — a drain is bounded by default: 25s, and a hook that outruns it is ABANDONED.** + `configureLifecycle({ deadlineMs })` had existed since 1.0.0 and `drainDeadlineMs()` answered + `undefined` until something declared one — so a role that declared none drained *unbounded*, and + the two roles that most need a bound declare none: `jobs` and `realtime` set no budget anywhere. + A worker pod holding a long job past `terminationGracePeriodSeconds` is `SIGKILL`ed by the + kubelet mid-statement, which is the failure the deadline exists to prevent and the one it was + not preventing. `drainDeadlineMs()` now returns a `number` always, and `remainingBudget()` is a + `number` rather than `number | undefined`. + + Read `X_SHUTDOWN_TIMEOUT` literally: the hook is **abandoned, not stopped**. It is still running + when the process exits, so whatever it had in flight may be half-done — the framework cannot + cancel app code it did not write. Both `fix:` lines now name the pair that has to move together: + `configureLifecycle({ deadlineMs: 600_000 })` **and** a `terminationGracePeriodSeconds` at least + as large, because raising one without the other just relocates the kill. + + An app whose drain legitimately takes longer than 25s must now say so. That is the point: a + budget nobody declared was previously read as "no limit", and a limit nobody can see is not a + limit anyone tuned. + +- **BREAKING — `cacheKeyFor(name, input, tags, authority)` takes a fourth, required, positional + argument.** Optional would have defeated it: an optional authority is one a call site can forget, + and the forgotten one is the cross-tenant read above. `readAuthority(actor, scope)` is the only + thing that produces the value. A direct caller — the export is public — passes + `readAuthority(ctx.actor, 'actor')` to keep 1.2.0 behaviour for a per-caller read, and must + choose deliberately before writing `'global'`. + +- **BREAKING — the query fingerprint is SHA-256/16 hex; cursors minted before this are rejected + once.** It was FNV-1a/32 — 4×10⁹ values, brute-forceable offline in seconds — and a fingerprint + here is a **sharing key over client-chosen input**, not a checksum: it decides which read-cache + entry two callers are served from and which scope a cursor is bound to. The canonical form is + unchanged, so only the hash moved. A cursor issued by 1.2.0 fails its scope check as + `X_CURSOR_INVALID`, whose `fix:` is already "request the first page again", and a warm read + cache is cold exactly once. Same primitive and width `@ultimat3/realtime`'s `stableDigest` and + `@ultimat3/entity`'s `planScope` chose. + +- **BREAKING — `semantic.remember` rejects a TTL the tiers would have rejected.** It computed + `ttlMs` itself and handed it on, so a non-finite or negative lease reached the tier as a value + no other write path can produce. It now goes through `assertTtl` like every other write, with + `jitterFraction: 0` — jitter is a herd defence for expiry, and a semantic lease is not a herd. + +- **BREAKING — `OutboxRelay.stop()` returns `Promise`.** It was `void`: it cleared the timer + and returned *underneath* the pass in flight, so a test or a role shutdown that awaited it + resumed while a publish and its `markPublished` were still running — a torn write against a + closing pool. It now retains the tick chain and joins it, the way `worker.stop()` waits out its + rounds and `scheduler.stop()` its dispatch. Callers ignoring the return value keep compiling and + keep the old race; `x dev`'s role teardown awaits it. + +- **BREAKING — `TierFailure.tier` is `TierLabel`, not `TierName`.** `TierLabel = TierName | + 'query-read'`, because `@ultimat3/query`'s read tier degrades through the same `bestEffort` + wrapper and had nowhere to report as. The union is closed by hand rather than widened to + `string`: a label is a value operators read in `/_x`, and an open one is a typo nobody catches. + A `switch` over `TierFailure.tier` needs a `'query-read'` arm. + - **BREAKING — `hello` carries no cursors: `HelloFrame.resume` and `FRAME_LIMITS.resume` are deleted.** The field was filled by every client on open and read by nobody — the node replied `resume: []` and decided resume per subscription from the `subscribe` frame — so every reconnect diff --git a/biome.json b/biome.json index ed1f04ba7..209271576 100644 --- a/biome.json +++ b/biome.json @@ -52,6 +52,9 @@ "correctness": { "noUnusedVariables": "error", "noUnusedImports": "error" + }, + "nursery": { + "noFloatingPromises": "error" } } }, diff --git a/docs/plans/2026/08/16/101-deep-dive-bug-audit/status.yml b/docs/plans/2026/08/16/101-deep-dive-bug-audit/status.yml index bb6bfe810..696d7395b 100644 --- a/docs/plans/2026/08/16/101-deep-dive-bug-audit/status.yml +++ b/docs/plans/2026/08/16/101-deep-dive-bug-audit/status.yml @@ -4,8 +4,12 @@ status: in_progress created_by: sebi worked_by: "claude (hive of 4 per PR, one checkout)" owner: sebi -percent: 27 -current_focus: "01+09+04 next (tiers 0-1, logic, projection). 05/10 = #101; 07 = #102/#103/#104, all merged" +percent: 60 +current_focus: > + 02+06 land their cache/query/jobs/core/db half as #110 — the realtime half was #107, so both + slices sit at 70% with only http, action, auth and entity left. Merged so far: 05/10 = #101; + 07 = #102/#103/#104; 01/09 = #105; 04 = #106; 02/06 realtime = #107. + Next after #110: 02+06's http/action/auth/entity remainder, then 03. slices: - file: 05-gate-and-scripts.md tier: 0 @@ -24,24 +28,29 @@ slices: prs: [102, 103, 104] - file: 01-tier01-bugs.md tier: 0 - status: not_started - percent: 0 + status: done + percent: 100 + pr: 105 - file: 09-logic-edge-cases.md tier: 0 - status: not_started - percent: 0 + status: done + percent: 100 + pr: 105 - file: 04-projection-contract.md tier: 0 - status: not_started - percent: 0 + status: done + percent: 100 + pr: 106 - file: 02-tier23-bugs.md tier: 2 - status: not_started - percent: 0 + status: in_progress + percent: 70 + prs: [107, 110] - file: 06-concurrency-lifecycle.md tier: 2 - status: not_started - percent: 0 + status: in_progress + percent: 70 + prs: [107, 110] - file: 03-tier45-bugs.md tier: 4 status: not_started @@ -91,6 +100,44 @@ evidence: - "X_PACKAGE_UNREFERENCED fail-opens on a JSONC root tsconfig (comment => parse returns undefined => rule reads it as 'no project references')." new_codes: [X_REFERENCE_APP_NO_FLOOR, X_SCAFFOLD_GATE_RED, X_PACKAGE_UNREFERENCED] + - pr: 110 + slices: [02, 06] + gate: "14 of 17 passed, 3 skipped (drift, contract-diff, budgets); app gate green, every pin + holds — examples/dummy 10/17 (7 red, 7 pinned), social-media-clone 14/17 (3 red, 3 pinned)" + falsified: + - "02-3b: 'reverse the Redis set ordering' is HALF a fix and worse alone. SADD-then-SET with + no re-check lets the bust SREM the membership and the later SET publish a row unreachable + by ANY tag — permanently uninvalidatable. Ships with an SISMEMBER re-check." + - "02-cursor: fixing `queryHash` alone was too narrow. `fingerprint` also backs + `cacheKeyFor`, so the 32-bit hash over client-chosen input was ALSO the shared cache + entry key — strictly worse than the cursor case the sweep named." + - "06-attempt: repeated suspensions cannot drive `attempt` negative. `nack` is fenced on + state === 'running', which only `claim` sets, and `claim` increments." + - "06-deadline: `configureLifecycle({deadlineMs})` is NOT unused — http/src/server.ts:97 + declares one on every createServer. And X_SHUTDOWN_TIMEOUT already existed." + - "02-dates: the bare-Date.now() list in the cache package is EMPTY — fixed in #105/#106/#107. + Only `remember` bypassing assertTtl was real." + decided: + - "The drain deadline flipped from opt-in to bounded-by-default (25s). Built opt-in as + briefed, but `jobs` and `realtime` declare no budget, so the proven symptom — a worker pod + SIGKILLed mid-job — stayed unfixed. A mechanism that does not fix the symptom while + claiming the deadline works is a claim wider than what is enforced." + - "Colocated test fakes ship in the tarball. Four now do; a one-off `files` negation in one + package invents a convention nothing else follows. If it matters it is one sweep over all + 29 package.json, and it belongs to the dead-code slice." + deferred: + - "The cache fill fence is PER PROCESS — two pods still interleave a load on one with a write + and bust on the other. Cross-node needs a Redis-side epoch and a wire change. Known-Gaps + row landed." + - "`createCacheStack` has zero production callers, so its copy of the fence is dormant. The + live fenced path is runQuery -> readRows -> readThrough -> fill." + - "`recentTierFailures()` has no reader outside cache, and /_x's invalidations source is + `unwired` — routed to slice 03." + - "`invalidateWireTags` has zero callers but is the wire-form door `x cache bust` will call. + Not dead; recorded for slice 15 to weigh." + - "`cache.scope` is auditable by grep, not by `x queries describe` — publishing it on + QueryDescriptor ripples into both tracked apps' manifests." + new_codes: [X_JOB_SLOT_LOST, X_QUERY_CACHE_TTL_INVALID] notes: > Slice order in this file is execution order, not tier order — 05 and 10 land first because the gate does not yet mean what it says, and 08 lands late because it is mostly deletions that would collide diff --git a/dummy/social-media-clone/biome.json b/dummy/social-media-clone/biome.json index f3eb77d00..06c3b04c6 100644 --- a/dummy/social-media-clone/biome.json +++ b/dummy/social-media-clone/biome.json @@ -1,11 +1,12 @@ { - "$schema": "https://biomejs.dev/schemas/2.4.15/schema.json", + "$schema": "https://biomejs.dev/schemas/2.5.5/schema.json", "root": false, + "extends": "//", "files": { "includes": ["**", "!x.manifest.json", "!openapi.json"] }, "formatter": { "indentStyle": "space", "indentWidth": 2, "lineWidth": 100 }, "linter": { "rules": { - "recommended": true, + "preset": "recommended", "suspicious": { "noExplicitAny": "error" }, "correctness": { "noUnusedVariables": "error", "noUnusedImports": "error" } } diff --git a/framework.manifest.json b/framework.manifest.json index 5f628fc21..2e64f3b89 100644 --- a/framework.manifest.json +++ b/framework.manifest.json @@ -1,6 +1,6 @@ { "version": 1, - "buildId": "5725ea6384f5b77df89c7119aa39b86014a8f703dcf4fcfbdcc16a8b4662aa4b", + "buildId": "ff623eefe238316b928facb903cb4e87573dd3a1aeb767886f5b975ed7ba9195", "tiers": { "0": [ "core", @@ -1010,6 +1010,11 @@ "owner": "jobs", "at": "packages/jobs/src/errors.ts" }, + { + "code": "X_JOB_SLOT_LOST", + "owner": "jobs", + "at": "packages/jobs/src/errors.ts" + }, { "code": "X_JOB_TENANT_REQUIRED", "owner": "jobs", @@ -1440,6 +1445,11 @@ "owner": "pwa", "at": "packages/pwa/src/errors.ts" }, + { + "code": "X_QUERY_CACHE_TTL_INVALID", + "owner": "query", + "at": "packages/query/src/errors.ts" + }, { "code": "X_QUERY_DEPRECATION_INVALID", "owner": "query", diff --git a/packages/cache/CLAUDE.md b/packages/cache/CLAUDE.md index 4684adc2f..ac6dd12f1 100644 --- a/packages/cache/CLAUDE.md +++ b/packages/cache/CLAUDE.md @@ -14,9 +14,32 @@ Tier 1. Tagged caching + THE invalidation graph. `tier.invalidateTags()` from outside it. It is also the only place the log is written: `recentInvalidations()` is a read of what that one path already reported, never a second recorder a caller has to remember to call. +- **The fan-out clears FARTHEST tier first, and reports in read order.** Near-to-far leaves the far + tier holding the old value after the near ones are clear, and a read racing the bust promotes it + straight back up — `report.errors` empty, LRU stale again before the call returns. `CacheStack.drop` + reverses for the same reason. The report is re-sorted into `TIER_ORDER` because it is what the + `/_x` panel renders. Pinned in `invalidation-race.test.ts`. +- **A fill is fenced: sample before `load()`, ask before the write** (`fence.ts`). A read-through + fill publishes rows `load()` read in the past, so a bust landing in between finds a key that is + not there yet, reports `errors: []`, and is overwritten milliseconds later — invisible for the + whole TTL. `sampleFence({ key, tags })` → `fence.isValid()` is the whole API, `markInvalidated` + is its write half (called by `fanOut`, `CacheStack.write` and `CacheStack.drop`; a caller only + needs it for a clearing path of its own). It is **exported** because `@ultimat3/query`'s read + cache has the same hole and must not grow a second mechanism. `cover()` widens a fence + RETROACTIVELY — needed only where joiners contribute tags the leader never sampled, which is + `createCacheStack.read` and nothing else. A fence never fails a read: it declines to publish. + This is the one process-global here with **no `isolate*()` seam and no reset**, and that is + structural: a fence samples the current generation, which is always at or above what the ring has + forgotten, so another file's marks cannot invalidate a fence sampled after them. - One graph. `graph.ts` exports functions over module state and **no constructor** — do not add one, do not add a second registry anywhere else. - Tag order is `TIER_ORDER`, never registration order. `sortTiers()` enforces it. +- **`bestEffort()` is public, and it is the only sanctioned way to swallow a cache refusal.** A + store outside this package that wraps its own `try/catch` degrades invisibly, and a second + failure log nobody reads is what this bounded one exists to prevent. Its label is `TierLabel` — + `TierName` plus `'query-read'` — closed, and deliberately NOT a widening of `TierName`: a name + missing from `TIER_ORDER` sorts to `-1`, ahead of the request memo. A label is a log facet; a + `TierName` is a position on the ladder. - Tier failures go into `report.errors`. A cache tier may never fail a business read or write. `createCacheStack` routes every `get`/`set`/`del` through `bestEffort()` for that reason — a refusal becomes "that tier did not answer" and lands in `recentTierFailures()`, the read side's @@ -43,7 +66,11 @@ Tier 1. Tagged caching + THE invalidation graph. `isolateTiers()` already covers. - Clocks are injected (`LruOptions.clock`, `CacheStackOptions.clock`); read them through `nowMs()`. - **`ttlMs` is positive and finite, and `assertTtl` (in `tiers.ts`) is the one place that says so.** - Every tier calls it before it writes. `0` used to be "never expires" here and `EX 1` in `redis.ts`, + Every tier calls it before it writes, and so does `createMemorySemanticCache.remember` — which was + the one writer skipping it, so `ttlMs: 0` stored an entry already past its expiry and every lookup + missed with a completion bill as the only evidence. Its scope is `'semantic'` (`TtlScope`), with + `jitterFraction: 0`: spreading a lease is a herd defence for a SHARED store, and that one is per + process. `0` used to be "never expires" here and `EX 1` in `redis.ts`, so one stack answered two ways; the rule lives beside `CacheSetOptions` precisely so a new tier cannot invent a third reading. `X_CACHE_TTL_INVALID`, never a resolution. - **`assertTtl` also SPREADS the lease it validated** — validate, then jitter, one choke point. A @@ -56,6 +83,12 @@ Tier 1. Tagged caching + THE invalidation graph. `realtime`'s `entry.reading`). The share ends as the load settles — a REJECTED load must clear its entry too, or one origin failure becomes a permanent cached rejection. One `SingleFlight` per stack, never a module-level map: two stacks are two ladders. +- **A joiner shares the leader's WRITE, so it contributes to it** (`FlightJoin`, merged by + `mergeSetOptions` in `set-options.ts`). Keyed on `key` alone and read late, the entry used to land + carrying only the leader's tags: the joiner's tag reached nothing, so the invalidation it declared + never fired. Tags union, TTLs take the SHORTEST — an entry held longer than a caller asked for is + stale to that caller. `work` reads the merge through `shared()` **after** the load, or it sees + only what the leader brought. - **`negativeTtlMs` is the stack's decision, not a tier's.** Only `createCacheStack` sees what `load()` answered, so the `null`/`undefined` branch lives in `ttlOptionsFor` there and reaches a tier as an ordinary `ttlMs`. @@ -68,11 +101,28 @@ Tier 1. Tagged caching + THE invalidation graph. owns the clock, so it survives skew between the node that wrote and the node that reads, and no stored payload shape changes under a running deployment. `-1`/`-2` are sentinels, not durations: they mean no expiry, never one millisecond ago. -- **`redis.ts`'s script deletes only keys it was handed in `KEYS`.** The members of a tag set are - value keys in slots this node may not own, so `DEL`ing them from Lua is a cross-slot access that - fails on Redis Cluster and Dragonfly strict mode — into `report.errors`, so the bust reads as - partial and stale rows serve until TTL. The script returns the members; the tier deletes them - client-side, one key per `DEL`, which is slot-local under every topology. +- **`redis.ts`'s script deletes NOTHING — it reads.** The members of a tag set are value keys in + slots this node may not own, so `DEL`ing them from Lua is a cross-slot access that fails on Redis + Cluster and Dragonfly strict mode — into `report.errors`, so the bust reads as partial and stale + rows serve until TTL. The script returns the members; the tier deletes them client-side, one key + per `DEL`, which is slot-local under every topology. +- **The bucket is not dropped in the script either, and the tier `SREM`s only what it deleted.** + Dropping it atomically with the `SMEMBERS` made one failure permanent: a refused `DEL` left its + member with no bucket to be found in, so the retry the error asks for answered `keys: []` and + those rows served until their own TTL. `Promise.allSettled` is what makes "what actually died" + knowable. A member a concurrent write added between the two halves keeps its membership instead + of being orphaned by a bust that never deleted it. +- **A `set` joins its buckets BEFORE it writes the value, and re-checks membership after.** Value + first left a window where a bust's `SMEMBERS` saw an empty bucket and the value survived its own + invalidation for the full TTL. Joining first moves the window somewhere observable: membership + gone by the time the `SET` lands means this write was busted in the air, and the value goes with + it — a row nothing can reach by tag is one no later bust can clear. Only a literal `0` from + `SISMEMBER` counts as gone (`saysAbsent`); a reply the tier cannot read is not evidence, and + deleting on one is a cache that never caches. +- **`GET` and `PTTL` are two commands and the key can die between them.** `PTTL: -2` for a value + the `GET` returned is a MISS, not an entry with no expiry — reported as a hit it is promoted into + the LRU on the CALLER's ttl, so a row one millisecond from death gets a fresh five minutes one + tier closer. - **That fixed half of it; `KEYS` itself was the other half.** Tag keys carry a `{entity}` hash tag (`:t:{post}`, `:t:{post}:7`) and `invalidateTags` issues **one script call per tag**, so every key a call is handed hashes to one slot. A single `EVAL` carrying two tags' buckets is @@ -133,7 +183,9 @@ Tier 1. Tagged caching + THE invalidation graph. |---|---| | `tags.ts` | `tag` factory, wire form, match semantics, declared-tag registry | | `graph.ts` | tag → dependents (cache keys, ISR routes, CDN paths, live queries) | -| `tiers.ts` | `CacheTier`, `TIER_ORDER`, read-through stack | +| `tiers.ts` | `CacheTier`, `TIER_ORDER`, `TierLabel`, `assertTtl`, read-through stack | +| `fence.ts` | the invalidation fence a fill (here or in `query`) checks before it publishes | +| `set-options.ts` | how two callers' `CacheSetOptions` combine, and the `null`-load TTL | | `tier-failures.ts` | `bestEffort()`, and the bounded log of refusals it absorbs | | `memo.ts` | request memo over the ALS ctx (WeakMap, no lifecycle) | | `lru.ts` | byte-budgeted LRU (linked list + map + tag index) | diff --git a/packages/cache/README.md b/packages/cache/README.md index 0a2d2353b..c0f6432c0 100644 --- a/packages/cache/README.md +++ b/packages/cache/README.md @@ -67,7 +67,23 @@ a reader arriving while another's load is running joins it instead of issuing it ends as the load settles, rejection included, so one failure is never held as a permanent one. A feed cached for 60s and read 8,000×/s otherwise sends ~1,600 identical queries to Postgres at every TTL boundary, because the write only lands after `load()` resolves. The primitive is -`createSingleFlight()` if you need it elsewhere; the stack holds one per stack. +`createSingleFlight()` if you need it elsewhere; the stack holds one per stack. A joiner shares the +leader's **write** as well as its load, so it contributes to it: tags union, TTLs take the shortest. +Without that the entry landed carrying only the leader's tags and the joiner's invalidation never +fired. + +**A fill obeys an invalidation that raced it.** `load()` answers with rows it read in the past, so a +bust landing in between finds a key that is not there yet — it reports `errors: []` and the fill +republishes the pre-write rows for the full TTL, invisibly. `stack.read` samples a fence before the +load and re-checks it before each tier write; a fill that lost the race is dropped, and anything it +already wrote is taken back. The caller still gets what the origin answered: a fence declines to +publish, it never fails a read. It is exported for any cache doing its own read-through: + +```ts +const fence = sampleFence({ key, tags }); +const value = await run(); +if (fence.isValid()) await tier.set(key, value, { tags }); +``` **A `null` can carry its own TTL.** `negativeTtlMs` is used when the loaded value is `null` or `undefined`, so a lookup for a row that has not replicated yet is not held for the positive lease: @@ -93,6 +109,10 @@ though it were the value. operation, the key and the `X_*` code, and each one also logged as `cache.tier.failed`. Same bargain as `report.errors` on the invalidation side — degraded is visible, not merely slow. +`bestEffort(label, op, key, run)` is that guard, exported: a cache that is not a rung of this ladder +(`@ultimat3/query`'s read cache, `label: 'query-read'`) degrades into the same log rather than a +private `try/catch` nobody can read. The label is closed (`TierLabel`) so the panel can group by it. + ## Tags ```ts @@ -134,6 +154,13 @@ its collection's bucket hash to one slot, so a script may take both in `KEYS`. I partial bust while stale rows served until TTL. Value keys are still deleted client-side, one `DEL` each, which is slot-local under every topology. +The script **deletes nothing at all** — not the value keys, and not the buckets either. The tier +`SREM`s exactly the members whose `DEL` succeeded, so a refused delete keeps its membership and the +retry the error asks for still finds it; dropping the bucket inside the script made that failure +permanent. A `set` mirrors it: buckets are joined **before** the value is written and membership is +re-checked after, because a bust that landed in between would otherwise leave a row nothing can +reach by tag, serving until its own lease ran out. + **Every tag set carries a lease**, renewed on each write to the member's own TTL plus 60s, raised only when the new lease is longer — a 60s member must not shorten a bucket a 1h member is in. Without it a tag set grew forever: value keys died after five minutes, their membership never did, @@ -157,7 +184,9 @@ your own payloads. const report = await invalidateTags([tag('post', postId)]); ``` -One function. Returns the report the `/_x` cache panel and `x cache bust --json` render: +One function. It returns the report below, which is also what the `/_x` cache panel renders — and +what `x cache bust --json` will print once it ships; that command is planned and exits +`X_NOT_IMPLEMENTED` today. ```json { @@ -174,6 +203,12 @@ One function. Returns the report the `/_x` cache panel and `x cache bust --json` A dead tier lands in `errors` and never throws — a Redis outage must not fail the write that triggered the bust. Entries there expire by TTL instead. +The fan-out walks the ladder **farthest tier first** — Redis before the LRU before the request memo +— and reports in read order. Clearing near-to-far leaves the far tier holding the old value after +the near ones are clear, and a read racing the bust promotes it straight back up into them: every +tier reports cleared and the LRU is stale again before the call returns. `stack.drop(key)` reverses +for the same reason. + `cdn` is what the dependency graph hangs off these tags, not what cleared: the `cdn` tier purges those paths (as surrogate keys, alongside the tags), so what actually cleared is that tier's row in `tiers`. With no `cdn` tier registered the list purges nowhere, which is why diff --git a/packages/cache/src/fence.test.ts b/packages/cache/src/fence.test.ts new file mode 100644 index 000000000..3b79d33d9 --- /dev/null +++ b/packages/cache/src/fence.test.ts @@ -0,0 +1,78 @@ +// The fence's whole job is to answer "did anything I am about to write get invalidated while I +// was loading it?" — so every test here samples first, invalidates second, and asks third. The +// ordering is explicit in the calls, never in a timer: the fence is synchronous by construction. + +import { describe, expect, test } from 'bun:test'; +import { FENCE_MEMORY, markInvalidated, sampleFence } from './fence'; +import { tag } from './tags'; + +describe('sampleFence', () => { + test('a fence with nothing invalidated under it is valid', () => { + const fence = sampleFence({ key: 'post:1', tags: [tag('post', '1')] }); + expect(fence.isValid()).toBe(true); + }); + + test('an invalidation of the exact tag AFTER the sample invalidates it', () => { + const fence = sampleFence({ key: 'post:1', tags: [tag('post', '1')] }); + markInvalidated({ tags: [tag('post', '1')] }); + expect(fence.isValid()).toBe(false); + }); + + test('an invalidation BEFORE the sample does not — the load already saw that write', () => { + markInvalidated({ tags: [tag('post', '7')] }); + const fence = sampleFence({ tags: [tag('post', '7')] }); + expect(fence.isValid()).toBe(true); + }); + + test('a collection bust invalidates a row fence, and a row bust a collection fence', () => { + const row = sampleFence({ tags: [tag('post', '2')] }); + markInvalidated({ tags: [tag('post')] }); + expect(row.isValid()).toBe(false); + + const collection = sampleFence({ tags: [tag('post')] }); + markInvalidated({ tags: [tag('post', '3')] }); + expect(collection.isValid()).toBe(false); + }); + + test('another entity, and another row of the same entity, leave it valid', () => { + // Over-invalidation is not free: every fence it trips is a fill skipped and an origin read + // the next request pays for, so the match is `tagMatches`, never "something happened". + const fence = sampleFence({ tags: [tag('post', '4')] }); + markInvalidated({ tags: [tag('user', '4')] }); + markInvalidated({ tags: [tag('post', '5')] }); + expect(fence.isValid()).toBe(true); + }); + + test('a key drop invalidates a fence over that key, and only that key', () => { + const fence = sampleFence({ key: 'post:1' }); + markInvalidated({ key: 'post:2' }); + expect(fence.isValid()).toBe(true); + markInvalidated({ key: 'post:1' }); + expect(fence.isValid()).toBe(false); + }); + + test('cover() widens the fence RETROACTIVELY, back to when it was sampled', () => { + // A joiner arriving mid-load declares tags the leader never sampled. Covering them has to + // reach back, or the joiner's tag is unfenced for exactly the window it was absent. + const fence = sampleFence({ key: 'feed' }); + markInvalidated({ tags: [tag('post', '9')] }); + expect(fence.isValid()).toBe(true); + fence.cover({ tags: [tag('post', '9')] }); + expect(fence.isValid()).toBe(false); + }); + + test('an empty scope records nothing — a bust of no tags invalidates no fence', () => { + const fence = sampleFence({ key: 'k', tags: [tag('post')] }); + markInvalidated({ tags: [] }); + expect(fence.isValid()).toBe(true); + }); + + test('a fence older than the ring can remember answers INVALID, never "probably fine"', () => { + const fence = sampleFence({ tags: [tag('post', '1')] }); + for (let i = 0; i <= FENCE_MEMORY; i += 1) + markInvalidated({ tags: [tag('unrelated', String(i))] }); + // Nothing matching was busted, but the ring can no longer prove that: the conservative + // answer costs one refetch, the optimistic one serves a stale row for the whole TTL. + expect(fence.isValid()).toBe(false); + }); +}); diff --git a/packages/cache/src/fence.ts b/packages/cache/src/fence.ts new file mode 100644 index 000000000..8807f5c75 --- /dev/null +++ b/packages/cache/src/fence.ts @@ -0,0 +1,110 @@ +// A read-through fill writes what `load()` read, and `load()` read it in the past. An +// invalidation that lands in between finds nothing to clear and the fill then republishes the +// pre-write rows for a full TTL — invisibly, with `errors: []`. The fence is the identity check +// `single-flight.ts` does on a promise, done on time: sample before the load, ask before the write. + +import type { CacheTag } from './tags'; +import { tagMatches } from './tags'; + +/** + * What a fill is about to publish, in invalidation terms. Both halves are optional and both are + * checked: `key` catches a `drop`/`write` of that exact key, `tags` catch a tag bust. + */ +export interface FenceScope { + readonly key?: string; + readonly tags?: readonly CacheTag[]; +} + +export interface CacheFence { + /** `false` once anything this fence covers was invalidated after the sample. Never throws. */ + isValid(): boolean; + /** + * Widen what this fence covers — retroactively, back to the sample. A joiner arriving mid-load + * declares tags the leader never sampled, and those tags are unfenced for exactly the window + * they were absent unless covering reaches back. + */ + cover(scope: FenceScope): void; +} + +/** + * How many recent invalidations stay inspectable. A fill window is milliseconds and this is + * process-wide, so the ring is only ever short of an answer under a bust storm — where the + * conservative answer costs one refetch and the optimistic one serves a stale row until TTL. + */ +export const FENCE_MEMORY = 1024; + +interface Mark { + /** The generation this mark was recorded at; marks are pushed in generation order. */ + readonly at: number; + readonly key?: string; + readonly tag?: CacheTag; +} + +const marks: Mark[] = []; +let generation = 0; +/** The highest generation the ring has forgotten. A fence older than this cannot be proven. */ +let forgottenThrough = 0; + +/** + * Record an invalidation. `invalidateTags` already calls this for every fan-out, inbound + * broadcasts included, and `CacheStack` calls it for `drop`/`write` — a caller only needs it when + * it clears a cache key by some path of its own. + * + * Unlike every other process-global registry in this package this one needs no `isolate*()` seam + * and has no reset: a fence samples the CURRENT generation, which is always at or above + * `forgottenThrough`, so marks left behind by another test file can never invalidate a fence + * sampled after them. + */ +export function markInvalidated(scope: FenceScope): void { + const key = scope.key; + const tags = scope.tags ?? []; + if (key === undefined && tags.length === 0) return; + + generation += 1; + if (key !== undefined) marks.push({ at: generation, key }); + for (const owned of tags) marks.push({ at: generation, tag: owned }); + + while (marks.length > FENCE_MEMORY) { + const dropped = marks.shift(); + if (dropped !== undefined) forgottenThrough = dropped.at; + } +} + +function hits(mark: Mark, scope: FenceScope): boolean { + if (mark.key !== undefined) return scope.key !== undefined && mark.key === scope.key; + const owned = mark.tag; + if (owned === undefined) return false; + // `tagMatches` is symmetric on the wildcard: a collection bust hits a row fence and a row bust + // hits a collection fence, which is the same asymmetry-tolerance every tier invalidates with. + return (scope.tags ?? []).some((wanted) => tagMatches(wanted, owned)); +} + +/** + * Take a fence before `load()`; ask it before the write: + * + * const fence = sampleFence({ key, tags }); + * const value = await load(); + * if (fence.isValid()) await tier.set(key, value, { tags }); + */ +export function sampleFence(scope: FenceScope): CacheFence { + const sampledAt = generation; + const covered: FenceScope[] = [scope]; + + return { + cover(next: FenceScope): void { + covered.push(next); + }, + + isValid(): boolean { + // Older than the ring remembers: unprovable, so refused. One refetch, not a stale TTL. + if (sampledAt < forgottenThrough) return false; + for (let i = marks.length - 1; i >= 0; i -= 1) { + const mark = marks[i]; + // Marks are pushed in generation order, so the first one at or below the sample ends it. + if (mark === undefined || mark.at <= sampledAt) break; + if (covered.some((scoped) => hits(mark, scoped))) return false; + } + return true; + }, + }; +} diff --git a/packages/cache/src/index.ts b/packages/cache/src/index.ts index e1b0f7a1e..95cacbb71 100644 --- a/packages/cache/src/index.ts +++ b/packages/cache/src/index.ts @@ -13,6 +13,8 @@ export { CacheTooLargeError, CacheTtlInvalidError, } from './errors'; +export type { CacheFence, FenceScope } from './fence'; +export { FENCE_MEMORY, markInvalidated, sampleFence } from './fence'; export type { CacheDependent, DependentKind } from './graph'; export { dependentsOf, @@ -73,7 +75,7 @@ export type { SemanticRememberOptions, } from './semantic'; export { cosineSimilarity, createMemorySemanticCache } from './semantic'; -export type { SingleFlight } from './single-flight'; +export type { FlightJoin, SingleFlight } from './single-flight'; export { createSingleFlight } from './single-flight'; export type { CacheTag, CacheTagRegistry, TagFactory } from './tags'; export { @@ -91,7 +93,7 @@ export { tagsIntersect, } from './tags'; export type { TierFailure, TierOperation } from './tier-failures'; -export { recentTierFailures } from './tier-failures'; +export { bestEffort, recentTierFailures } from './tier-failures'; export type { CacheEntry, CacheSetOptions, @@ -100,8 +102,10 @@ export type { CacheTier, Rng, TierInvalidation, + TierLabel, TierName, TtlJitter, + TtlScope, } from './tiers'; export { assertTtl, diff --git a/packages/cache/src/invalidate.ts b/packages/cache/src/invalidate.ts index bc0314c0e..42a05fc11 100644 --- a/packages/cache/src/invalidate.ts +++ b/packages/cache/src/invalidate.ts @@ -5,12 +5,13 @@ // answerable without a log dive. import { currentSpan, logger, systemClock, withSpan } from '@ultimat3/core'; +import { markInvalidated } from './fence'; import { dependentsOfKind } from './graph'; import type { CacheTag } from './tags'; import { assertKnownTags, knownTags, parseTag, serializeTags } from './tags'; import { isolateTierFailures, resetTierFailures } from './tier-failures'; import type { CacheTier, TierInvalidation } from './tiers'; -import { sortTiers } from './tiers'; +import { sortTiers, TIER_ORDER } from './tiers'; /** Revalidates one ISR route path. Provided by `@ultimat3/render`; absent on a worker. */ export type Revalidator = (path: string) => Promise | void; @@ -206,10 +207,18 @@ function fanOut(tags: readonly CacheTag[], options: FanOutOptions): Promise TIER_ORDER.indexOf(a.tier) - TIER_ORDER.indexOf(b.tier)); const isr = dependentsOfKind(tags, 'isr-route'); const cdn = dependentsOfKind(tags, 'cdn-path'); diff --git a/packages/cache/src/invalidation-race.test.ts b/packages/cache/src/invalidation-race.test.ts new file mode 100644 index 000000000..ad0f794ac --- /dev/null +++ b/packages/cache/src/invalidation-race.test.ts @@ -0,0 +1,209 @@ +// Every test here is a RACE, and none of them sleeps: a deferred promise is what puts one +// operation provably inside another's window. The two failures pinned are the ones a report of +// `errors: []` cannot see — a fill that lands after the bust it should have obeyed, and a read +// that promotes a not-yet-cleared far tier back into an already-cleared near one. + +import { afterAll, beforeEach, describe, expect, test } from 'bun:test'; +import { invalidateTags, isolateTiers, registerTier, resetTiers } from './invalidate'; +import { createLruTier } from './lru'; +import { declareTags, isolateDeclaredTags, tag } from './tags'; +import type { CacheEntry, CacheSetOptions, CacheTier, TierInvalidation, TierName } from './tiers'; +import { createCacheStack } from './tiers'; + +const restoreTiers = isolateTiers(); +const restoreTags = isolateDeclaredTags(); +// Declared rather than left off: a neighbouring file in the same `bun test` process may have +// switched validation on, and these tags must be legal either way. +declareTags(['post', 'user']); +afterAll(() => { + restoreTiers(); + restoreTags(); +}); + +beforeEach(() => { + resetTiers(); +}); + +/** A promise a test resolves by hand — the only ordering primitive this file is allowed. */ +function deferred(): { promise: Promise; resolve(value: T): void } { + let resolve!: (value: T) => void; + const promise = new Promise((res) => { + resolve = res; + }); + return { promise, resolve }; +} + +/** Records the order tiers are asked to invalidate in. */ +function recordingTier(name: TierName, order: TierName[]): CacheTier { + return { + name, + get: () => Promise.resolve(undefined), + set: () => Promise.resolve(), + del: () => Promise.resolve(), + invalidateTags(): Promise { + order.push(name); + return Promise.resolve({ tier: name, keys: [] }); + }, + }; +} + +/** A far tier holding a stale value, whose own bust a test can hold open. */ +function gatedFarTier(value: string): CacheTier & { entered: Promise; release(): void } { + const store = new Map>(); + store.set('post:1', { value, tags: [tag('post', '1')] }); + const entered = deferred(); + const gate = deferred(); + return { + name: 'redis', + entered: entered.promise, + release: () => { + gate.resolve(); + }, + get(key: string) { + return Promise.resolve(store.get(key) as CacheEntry | undefined); + }, + set(key: string, next: T, options?: CacheSetOptions) { + store.set(key, { value: next, tags: options?.tags ?? [] }); + return Promise.resolve(); + }, + del(key: string) { + store.delete(key); + return Promise.resolve(); + }, + async invalidateTags(): Promise { + entered.resolve(); + await gate.promise; + const keys = [...store.keys()]; + store.clear(); + return { tier: 'redis', keys }; + }, + }; +} + +describe('a fill that outlives the invalidation it raced', () => { + test('an invalidation landing during an in-flight load is NOT overwritten by the fill', async () => { + // T0 miss -> load(); T1 the mutator commits and busts a key that is not there yet, a no-op; + // T2 load() resolves with rows read BEFORE that write; T3 the fill writes them for the full + // TTL. The write is invisible to every reader for `ttlMs` and the report says `errors: []`. + const lru = createLruTier({ rng: () => 0 }); + registerTier(lru); + const stack = createCacheStack([lru]); + + const started = deferred(); + const gate = deferred(); + const read = stack.read( + 'post:1', + () => { + started.resolve(); + return gate.promise; + }, + { ttlMs: 60_000, tags: [tag('post', '1')] }, + ); + + await started.promise; + const report = await invalidateTags([tag('post', '1')]); + expect(report.errors).toEqual([]); + + gate.resolve('rows-read-before-the-write'); + + // The caller still gets what the origin answered — a fence never fails a business read. + expect(await read).toBe('rows-read-before-the-write'); + expect(lru.cache.get('post:1')).toBeUndefined(); + }); + + test('a stack.drop during an in-flight load is not overwritten either', async () => { + const lru = createLruTier({ rng: () => 0 }); + const stack = createCacheStack([lru]); + + const started = deferred(); + const gate = deferred(); + const read = stack.read( + 'post:1', + () => { + started.resolve(); + return gate.promise; + }, + { ttlMs: 60_000, tags: [tag('post', '1')] }, + ); + + await started.promise; + await stack.drop('post:1'); + gate.resolve('stale'); + + expect(await read).toBe('stale'); + expect(lru.cache.get('post:1')).toBeUndefined(); + }); + + test('a write() landing during an in-flight load wins over the fill', async () => { + const lru = createLruTier({ rng: () => 0 }); + const stack = createCacheStack([lru]); + + const started = deferred(); + const gate = deferred(); + const read = stack.read( + 'post:1', + () => { + started.resolve(); + return gate.promise; + }, + { ttlMs: 60_000, tags: [tag('post', '1')] }, + ); + + await started.promise; + await stack.write('post:1', 'written-after-the-load-began', { ttlMs: 60_000 }); + gate.resolve('stale'); + await read; + + expect(lru.cache.get('post:1')?.value).toBe('written-after-the-load-began'); + }); + + test('nothing racing it: an ordinary fill still lands in every tier', async () => { + // The mutation that would otherwise make every test above pass for free — a fence that + // refuses every write is not a fence. + const lru = createLruTier({ rng: () => 0 }); + const stack = createCacheStack([lru]); + + expect(await stack.read('post:1', () => Promise.resolve('fresh'), { ttlMs: 60_000 })).toBe( + 'fresh', + ); + expect(lru.cache.get('post:1')?.value).toBe('fresh'); + }); +}); + +describe('the fan-out clears farthest-first', () => { + test('tiers are invalidated in reverse read order', async () => { + const order: TierName[] = []; + registerTier(recordingTier('lru', order)); + registerTier(recordingTier('redis', order)); + registerTier(recordingTier('request-memo', order)); + + const report = await invalidateTags([tag('post')]); + + expect(order).toEqual(['redis', 'lru', 'request-memo']); + // The REPORT stays in read order: it is what the `/_x` panel renders, and a ladder printed + // upside down is a second thing to learn. + expect(report.tiers.map((entry) => entry.tier)).toEqual(['request-memo', 'lru', 'redis']); + }); + + test('a read racing the bust cannot promote a stale value into a cleared near tier', async () => { + const lru = createLruTier({ rng: () => 0 }); + const far = gatedFarTier('STALE'); + registerTier(lru); + registerTier(far); + const stack = createCacheStack([lru, far]); + + const bust = invalidateTags([tag('post', '1')]); + await far.entered; + + // The far tier has not cleared yet, so this read finds STALE there and promotes it up. + await stack.read('post:1', () => Promise.resolve('FRESH'), { + ttlMs: 60_000, + tags: [tag('post', '1')], + }); + + far.release(); + await bust; + + expect(lru.cache.get('post:1')).toBeUndefined(); + }); +}); diff --git a/packages/cache/src/redis-fake.ts b/packages/cache/src/redis-fake.ts new file mode 100644 index 000000000..c1be4ee16 --- /dev/null +++ b/packages/cache/src/redis-fake.ts @@ -0,0 +1,115 @@ +// The fake `Bun.redis` both redis test files drive, and the two wire readers they assert with. +// It is a RECORDER, never an interpreter: it cannot run Lua, so it never pretends to, and every +// claim about what a script DOES lives in `redis.live.test.ts`. Not exported from `index.ts` — +// it is a test double shaped around this package's own assertions, not public API. + +import type { RedisLike, RedisTierOptions } from './redis'; +import { createRedisTier, REDIS_TAG_MEMBER_SCRIPT } from './redis'; +import type { CacheTier } from './tiers'; + +export interface FakeRedis extends RedisLike { + readonly sent: string[][]; + /** + * What the server's script answers for one `EVAL`. A test driving a path that READS the reply + * has to say what came back; there is no default, because `[]` is exactly what a gutted + * `INVALIDATE_SCRIPT` returns and a silent one would make "the bust cleared nothing" the + * baseline of both files. + */ + answerEval(script: string, reply: unknown): void; + /** Makes one value key's `DEL` refuse, which is the half of a bust that can fail alone. */ + refuseDel(key: string): void; +} + +export function fakeRedis(): FakeRedis { + const values = new Map(); + // The lease `EX` bought, in ms. A fake that answered no `PTTL` could not catch a tier that + // stopped asking for one — and a hit read back without its remaining life is promoted on the + // caller's ttl, which is how a value one second from expiry gets a fresh five minutes. + const expiries = new Map(); + const sent: string[][] = []; + // A fake cannot run Lua. This one used to mirror both script bodies in TypeScript, which is why + // gutting either to `return 1` / `return {}` left all 517 tests in `cache` + `query` green — the + // assertions ran against the mirror and the script itself was executed by nothing, ever. What is + // left is a recorder: the wire traffic is what those files assert, the script body is opaque to + // them, and every claim about what a script DOES lives behind TEST_REDIS_URL. + const evalReplies = new Map([ + // Nothing reads the tag-join's reply, so a constant here asserts nothing about the script. + [REDIS_TAG_MEMBER_SCRIPT, 1], + ]); + const refused = new Set(); + return { + sent, + answerEval(script, reply) { + evalReplies.set(script, reply); + }, + refuseDel(key) { + refused.add(key); + }, + get(key) { + return Promise.resolve(values.get(key) ?? null); + }, + set(key, value) { + values.set(key, value); + return Promise.resolve('OK'); + }, + send(command, args) { + sent.push([command, ...args]); + if (command === 'SET') { + values.set(String(args[0]), String(args[1])); + if (args[2] === 'EX') expiries.set(String(args[0]), Number(args[3]) * 1_000); + if (args[2] === 'PX') expiries.set(String(args[0]), Number(args[3])); + return Promise.resolve('OK'); + } + if (command === 'PTTL') { + const key = String(args[0]); + if (!values.has(key)) return Promise.resolve(-2); + return Promise.resolve(expiries.get(key) ?? -1); + } + if (command === 'DEL') { + if (refused.has(String(args[0]))) { + return Promise.reject(new Error(`redis refused DEL ${String(args[0])}`)); + } + values.delete(String(args[0])); + expiries.delete(String(args[0])); + return Promise.resolve(1); + } + if (command === 'EVAL') { + const script = String(args[0]); + if (!evalReplies.has(script)) { + // Loud rather than `[]`: an empty member list is what the gutted script answers, so a + // default would report every bust in these files as clean and every one of them green. + throw new Error( + 'fake redis cannot execute EVAL — call answerEval(script, reply) to state what the ' + + 'server returned, or move the claim to redis.live.test.ts, which runs the script', + ); + } + return Promise.resolve(evalReplies.get(script)); + } + return Promise.resolve(null); + }, + }; +} + +/** + * `buildId: null` and `rng: () => 0` are the two things a wire assertion needs pinned: the + * namespace carries the build id by default, and the lease is spread by default. + */ +export function tierFor(client: RedisLike, extra: RedisTierOptions = {}): CacheTier { + return createRedisTier({ client, buildId: null, rng: () => 0, ...extra }); +} + +/** The `{...}` hash tag of a key, which is what Redis Cluster hashes to a slot. */ +export function slotTokenOf(key: string): string { + return /\{([^}]*)\}/.exec(key)?.[1] ?? key; +} + +/** + * Every key argument of one command — `EVAL script numkeys k1 .. kN`, `DEL key` and + * `SREM key member..`, whose members are values rather than keys and so hash to nothing. + */ +export function keysOf(command: readonly string[]): string[] { + if (command[0] === 'EVAL') return command.slice(3, 3 + Number(command[2])); + if (command[0] === 'DEL') return command.slice(1); + if (command[0] === 'SREM' || command[0] === 'SISMEMBER') return command.slice(1, 2); + return []; +} diff --git a/packages/cache/src/redis-ordering.test.ts b/packages/cache/src/redis-ordering.test.ts new file mode 100644 index 000000000..1fdbaa880 --- /dev/null +++ b/packages/cache/src/redis-ordering.test.ts @@ -0,0 +1,177 @@ +// The shared tier's ORDERING guarantees, which are only visible on the wire: which command goes +// out before which, which keys travel together, which slot they hash to, and which lease each +// join asks for. Every failure pinned here is one a report of `errors: []` cannot see — the tier +// answers correctly to its caller and leaves the store in a state no later bust can repair. +// The fake is a recorder (`redis-fake.ts`); what a script DOES is `redis.live.test.ts`'s subject. + +import { describe, expect, test } from 'bun:test'; +import type { RedisLike } from './redis'; +import { REDIS_INVALIDATE_SCRIPT, REDIS_TAG_MEMBER_SCRIPT } from './redis'; +import { fakeRedis, keysOf, slotTokenOf, tierFor } from './redis-fake'; +import { tag } from './tags'; + +// Both halves of the shared tier's write and both halves of its bust are ORDERED, and the order +// is only visible on the wire. Each test here pins one interleaving that a report of `errors: []` +// cannot see. +describe('a bust racing a write, on the wire', () => { + test('the tag buckets are joined BEFORE the value key is written', async () => { + // SET first leaves a window where a bust finds an empty bucket: the value it should have + // cleared is invisible to the bust and serves its own pre-invalidation payload for the full + // TTL. Joining first moves the window somewhere the re-check below can see it. + const client = fakeRedis(); + await tierFor(client).set('feed', 'v', { ttlMs: 60_000, tags: [tag('post', '1')] }); + + const wire = client.sent.map((entry) => (entry[0] === 'EVAL' ? 'JOIN' : entry[0])); + expect(wire.indexOf('SET')).toBeGreaterThan(wire.lastIndexOf('JOIN')); + }); + + test('a bust that landed mid-write takes the value with it, rather than orphaning it', async () => { + // The membership is the signal: `invalidateTags` only removes a member whose value key it + // deleted, so a member gone by the time the SET lands means this write was busted while it + // was in the air. Keeping it would serve a row nothing can reach by tag ever again. + const sent: string[][] = []; + const client: RedisLike = { + get: () => Promise.resolve(null), + set: () => Promise.resolve('OK'), + send(command, args) { + sent.push([command, ...args]); + // 0 = "not a member": the bust ran between the join and the write. + return Promise.resolve(command === 'SISMEMBER' ? 0 : 1); + }, + }; + + await tierFor(client).set('feed', 'v', { ttlMs: 60_000, tags: [tag('post', '1')] }); + + expect(sent.filter((entry) => entry[0] === 'DEL')).toEqual([['DEL', 'x:c:feed']]); + }); + + test('a write nothing raced is not deleted by its own re-check', async () => { + // The mutation this catches: a re-check that reads any reply as "gone" deletes every value + // the tier writes, which is a cache that never caches. + const client = fakeRedis(); + await tierFor(client).set('feed', 'v', { ttlMs: 60_000, tags: [tag('post', '1')] }); + + expect(client.sent.filter((entry) => entry[0] === 'DEL')).toEqual([]); + expect((await tierFor(client).get('feed'))?.value).toBe('v'); + }); + + test('a member whose DEL failed stays in its bucket, so a retry still reaches it', async () => { + // The bust used to drop the bucket atomically with the SMEMBERS that read it, so a failure in + // the client-side DEL batch orphaned every surviving member permanently: the retry the error + // asks for returns `keys: []` and those rows live out their TTL untouched. + const client = fakeRedis(); + const tier = tierFor(client); + await tier.set('gone', 'a', { ttlMs: 60_000, tags: [tag('post', '1')] }); + await tier.set('stuck', 'b', { ttlMs: 60_000, tags: [tag('post', '1')] }); + client.answerEval(REDIS_INVALIDATE_SCRIPT, ['x:c:gone', 'x:c:stuck']); + client.refuseDel('x:c:stuck'); + client.sent.length = 0; + + await expect(tier.invalidateTags([tag('post', '1')])).rejects.toThrow('redis refused DEL'); + + const removed = client.sent + .filter((entry) => entry[0] === 'SREM') + .map((entry) => entry.slice(2)); + // Only what actually died leaves the bucket. `x:c:stuck` is still a member, still tagged, + // and the retry the error asks for — `invalidateTags([tag('post', '1')])` — reaches it. + expect(removed).toEqual([['x:c:gone'], ['x:c:gone']]); + }); + + test('a bust that succeeded empties the buckets it read, member by member', async () => { + const client = fakeRedis(); + const tier = tierFor(client); + await tier.set('feed', 'a', { ttlMs: 60_000, tags: [tag('post', '1')] }); + client.answerEval(REDIS_INVALIDATE_SCRIPT, ['x:c:feed']); + client.sent.length = 0; + + await tier.invalidateTags([tag('post', '1')]); + + expect(client.sent.filter((entry) => entry[0] === 'SREM')).toEqual([ + ['SREM', 'x:t:{post}:1', 'x:c:feed'], + ['SREM', 'x:t:{post}', 'x:c:feed'], + ]); + }); + + test('a key that expires between GET and PTTL is a miss, not a full-lease promotion', async () => { + // Two commands, one key: it can die between them. The value comes back, PTTL answers -2 (no + // such key), and an entry with no `expiresAt` is promoted into the LRU on the CALLER's ttl — + // a row that was one millisecond from death gets a fresh five minutes, one tier closer. + const client: RedisLike = { + get: () => Promise.resolve(JSON.stringify({ v: 'reaped', t: [] })), + set: () => Promise.resolve('OK'), + send: (command) => Promise.resolve(command === 'PTTL' ? -2 : 1), + }; + + expect(await tierFor(client).get('feed')).toBeUndefined(); + }); +}); + +describe('invalidation is slot-local on Redis Cluster', () => { + test('no single command is ever handed keys from two different tags', async () => { + // The failure this pins: one EVAL carrying every tag-set key is rejected with CROSSSLOT + // before the script runs, because `x:t:post` and `x:t:user` hash to different slots. It + // lands in report.errors as a partial bust, and stale rows serve until TTL. + const client = fakeRedis(); + const tier = tierFor(client); + await tier.set('feed', ['a'], { tags: [tag('post', '1')] }); + await tier.set('inbox', ['b'], { tags: [tag('user', '9')] }); + await tier.set('teams', ['c'], { tags: [tag('team')] }); + client.answerEval(REDIS_INVALIDATE_SCRIPT, []); + client.sent.length = 0; + + await tier.invalidateTags([tag('post', '1'), tag('user', '9'), tag('team')]); + + for (const command of client.sent) { + const slots = new Set(keysOf(command).map(slotTokenOf)); + expect(slots.size).toBeLessThanOrEqual(1); + } + // One script call per tag, not one for the batch. + expect(client.sent.filter((entry) => entry[1] === REDIS_INVALIDATE_SCRIPT)).toHaveLength(3); + }); + + test("a row tag's two buckets share one slot, so they may travel in one call", async () => { + const client = fakeRedis(); + const tier = tierFor(client); + await tier.set('feed', ['a'], { tags: [tag('post', '1')] }); + client.answerEval(REDIS_INVALIDATE_SCRIPT, []); + client.sent.length = 0; + + await tier.invalidateTags([tag('post', '1')]); + + const evals = client.sent.filter((entry) => entry[1] === REDIS_INVALIDATE_SCRIPT); + expect(keysOf(evals[0] ?? [])).toEqual(['x:t:{post}:1', 'x:t:{post}']); + expect(new Set(keysOf(evals[0] ?? []).map(slotTokenOf))).toEqual(new Set(['post'])); + }); + + test('every tag-set key carries a hash tag; value keys never need one', async () => { + const client = fakeRedis(); + const tier = tierFor(client); + await tier.set('feed', ['a'], { tags: [tag('post', '1'), tag('user')] }); + + const buckets = client.sent + .filter((entry) => entry[1] === REDIS_TAG_MEMBER_SCRIPT) + .map((entry) => String(entry[3])); + expect(buckets).toEqual(['x:t:{post}:1', 'x:t:{post}', 'x:t:{user}']); + for (const bucket of buckets) expect(bucket).toMatch(/\{[^}]+\}/); + }); +}); + +// The lease a join ASKS for is wire traffic and belongs here. Whether the server then grants it, +// keeps the longer of two, and gives a fresh bucket one at all is `TAG_MEMBER_SCRIPT`'s own +// semantics — three claims a fake can only restate, so they live in `redis.live.test.ts`. +describe('tag sets are bounded', () => { + test('every join asks for a lease longer than the member it added', async () => { + // Without this a tag set grows forever: value keys expire after five minutes, their + // membership never does, and one publish becomes a multi-million-member SMEMBERS. + const client = fakeRedis(); + const tier = tierFor(client); + await tier.set('feed', ['a'], { ttlMs: 60_000, tags: [tag('post', '1')] }); + + const joins = client.sent.filter((entry) => entry[1] === REDIS_TAG_MEMBER_SCRIPT); + expect(joins).toHaveLength(2); + for (const join of joins) { + // 60s member + the 60s grace: the bucket must outlive what it points at. + expect(Number(join[5])).toBe(120); + } + }); +}); diff --git a/packages/cache/src/redis.live.test.ts b/packages/cache/src/redis.live.test.ts index 503829a76..3a92d5657 100644 --- a/packages/cache/src/redis.live.test.ts +++ b/packages/cache/src/redis.live.test.ts @@ -68,7 +68,7 @@ describe.skipIf(!hasRedis)('live · redis · both Lua scripts, executed by a rea expect(await tier.get('feed')).toBeUndefined(); }); - test('the invalidation script drops the buckets it was handed and no value key', async () => { + test('the invalidation script reads the buckets it was handed and deletes NOTHING', async () => { const client = raw(); const tier = tierOn(client); await tier.set('kept', 'v', { ttlMs: 60_000, tags: [tag('user', '9')] }); @@ -77,11 +77,56 @@ describe.skipIf(!hasRedis)('live · redis · both Lua scripts, executed by a rea const members = await reply(client, 'EVAL', [REDIS_INVALIDATE_SCRIPT, '1', bucket]); expect(members).toEqual([`${PREFIX}:c:kept`]); - expect(await count(client, 'EXISTS', bucket)).toBe(0); - // Still there, deliberately: a script may only touch keys handed to it in `KEYS`, and a `DEL` - // of a `SMEMBERS` result from inside Lua is "attempted to access a non-local key in a cluster - // node" on Redis Cluster and in Dragonfly's strict mode. The tier deletes it, one key per DEL. + // The value key is untouched deliberately: a script may only reach keys handed to it in + // `KEYS`, and a `DEL` of a `SMEMBERS` result from inside Lua is "attempted to access a + // non-local key in a cluster node" on Redis Cluster and in Dragonfly's strict mode. expect(await count(client, 'EXISTS', `${PREFIX}:c:kept`)).toBe(1); + // And the BUCKET is untouched too, which is the newer half. Dropping it here made a refused + // client-side `DEL` permanent: the member had no bucket left to be found in, so the retry the + // error asks for cleared nothing and the row served until its own TTL. + expect(await count(client, 'EXISTS', bucket)).toBe(1); + }); + + test('the TIER empties the bucket, one SREM of what it actually deleted', async () => { + const client = raw(); + const tier = tierOn(client); + await tier.set('swept', 'v', { ttlMs: 60_000, tags: [tag('swept', '11')] }); + const bucket = `${PREFIX}:t:{swept}:11`; + expect(await count(client, 'SCARD', bucket)).toBe(1); + + expect((await tier.invalidateTags([tag('swept', '11')])).keys).toEqual(['swept']); + + // An emptied set is a set Redis removes, so the end state matches the old in-script `DEL` — + // reached by a path where a failure leaves the membership behind instead of orphaning it. + expect(await count(client, 'EXISTS', bucket)).toBe(0); + expect(await count(client, 'EXISTS', `${PREFIX}:c:swept`)).toBe(0); + }); + + test('a bust landing between the join and the write leaves no unreachable row', async () => { + // The real interleaving, driven by a client that busts the tag as the `SET` goes out: the + // bucket already holds this key's membership, the value key does not exist yet, so the bust + // removes the membership and deletes nothing. Without the re-check the `SET` that follows + // publishes a row no bust of `raced` can ever reach again. + const client = raw(); + const buster = tierOn(raw()); + let busted = false; + const racing: RedisLike = { + get: (key) => client.get(key), + set: (key, value) => client.set(key, value), + async send(command: string, args: string[]): Promise { + if (command === 'SET' && !busted) { + busted = true; + await buster.invalidateTags([tag('raced')]); + } + return await client.send(command, args); + }, + }; + const tier = createRedisTier({ client: racing, prefix: PREFIX, buildId: null, rng: () => 0 }); + + await tier.set('raced', 'v', { ttlMs: 60_000, tags: [tag('raced')] }); + + expect(busted).toBe(true); + expect(await tier.get('raced')).toBeUndefined(); }); test('a fresh bucket comes out of the join with a lease, never immortal', async () => { diff --git a/packages/cache/src/redis.test.ts b/packages/cache/src/redis.test.ts index 4f56e4fd3..39f8dc74e 100644 --- a/packages/cache/src/redis.test.ts +++ b/packages/cache/src/redis.test.ts @@ -1,118 +1,23 @@ -// The tag -> keys bookkeeping is what buys the scripted invalidation instead of a `KEYS` scan, -// and it is invisible from the outside: a bucket written wrong leaves keys that no tag can ever -// reach again. A fake Redis records every command, so the wire traffic itself is the assertion: -// which keys travel together, which slot they hash to, which lease each join asks for. What a -// fake cannot do is run a Lua script — so it no longer pretends to, and every claim about what -// the two scripts DO lives in `redis.live.test.ts`. +// The tier's own behaviour: what it stores, what it reads back, what lease it spends and which +// namespace it spends it in. The tag -> keys bookkeeping is invisible from the outside — a bucket +// written wrong leaves keys no tag can ever reach again — so a fake Redis records every command +// and the wire traffic is the assertion. Its ORDERING guarantees are `redis-ordering.test.ts`'s +// subject, and what a Lua script actually does is `redis.live.test.ts`'s. import { describe, expect, test } from 'bun:test'; import { appVersion, frozenClock } from '@ultimat3/core'; import { CacheDriverUnavailableError } from './errors'; import { createLruTier } from './lru'; -import type { RedisLike, RedisTierOptions } from './redis'; import { createRedisTier, namespaceFor, REDIS_INVALIDATE_SCRIPT, REDIS_TAG_MEMBER_SCRIPT, } from './redis'; +import { fakeRedis, tierFor } from './redis-fake'; import { tag } from './tags'; import { createCacheStack } from './tiers'; -interface FakeRedis extends RedisLike { - readonly sent: string[][]; - /** - * What the server's script answers for one `EVAL`. A test driving a path that READS the reply - * has to say what came back; there is no default, because `[]` is exactly what a gutted - * `INVALIDATE_SCRIPT` returns and a silent one would make "the bust cleared nothing" the - * baseline of this whole file. - */ - answerEval(script: string, reply: unknown): void; -} - -function fakeRedis(): FakeRedis { - const values = new Map(); - // The lease `EX` bought, in ms. A fake that answered no `PTTL` could not catch a tier that - // stopped asking for one — and a hit read back without its remaining life is promoted on the - // caller's ttl, which is how a value one second from expiry gets a fresh five minutes. - const expiries = new Map(); - const sent: string[][] = []; - // A fake cannot run Lua. This one used to mirror both script bodies in TypeScript, which is why - // gutting either to `return 1` / `return {}` left all 517 tests in `cache` + `query` green — the - // assertions ran against the mirror and the script itself was executed by nothing, ever. What is - // left is a recorder: the wire traffic is this file's subject, the script body is opaque to it, - // and every claim about what a script DOES lives in `redis.live.test.ts` behind TEST_REDIS_URL. - const evalReplies = new Map([ - // Nothing reads the tag-join's reply, so a constant here asserts nothing about the script. - [REDIS_TAG_MEMBER_SCRIPT, 1], - ]); - return { - sent, - answerEval(script, reply) { - evalReplies.set(script, reply); - }, - get(key) { - return Promise.resolve(values.get(key) ?? null); - }, - set(key, value) { - values.set(key, value); - return Promise.resolve('OK'); - }, - send(command, args) { - sent.push([command, ...args]); - if (command === 'SET') { - values.set(String(args[0]), String(args[1])); - if (args[2] === 'EX') expiries.set(String(args[0]), Number(args[3]) * 1_000); - if (args[2] === 'PX') expiries.set(String(args[0]), Number(args[3])); - return Promise.resolve('OK'); - } - if (command === 'PTTL') { - const key = String(args[0]); - if (!values.has(key)) return Promise.resolve(-2); - return Promise.resolve(expiries.get(key) ?? -1); - } - if (command === 'DEL') { - values.delete(String(args[0])); - expiries.delete(String(args[0])); - return Promise.resolve(1); - } - if (command === 'EVAL') { - const script = String(args[0]); - if (!evalReplies.has(script)) { - // Loud rather than `[]`: an empty member list is what the gutted script answers, so a - // default would report every bust in this file as clean and every one of them as green. - throw new Error( - 'fake redis cannot execute EVAL — call answerEval(script, reply) to state what the ' + - 'server returned, or move the claim to redis.live.test.ts, which runs the script', - ); - } - return Promise.resolve(evalReplies.get(script)); - } - return Promise.resolve(null); - }, - }; -} - -/** - * `buildId: null` and `rng: () => 0` are the two things a wire assertion needs pinned: the - * namespace carries the build id by default, and the lease is spread by default. - */ -function tierFor(client: RedisLike, extra: RedisTierOptions = {}) { - return createRedisTier({ client, buildId: null, rng: () => 0, ...extra }); -} - -/** The `{...}` hash tag of a key, which is what Redis Cluster hashes to a slot. */ -function slotTokenOf(key: string): string { - return /\{([^}]*)\}/.exec(key)?.[1] ?? key; -} - -/** Every key argument of one command — `EVAL script numkeys k1 .. kN` and `DEL key`. */ -function keysOf(command: readonly string[]): string[] { - if (command[0] === 'EVAL') return command.slice(3, 3 + Number(command[2])); - if (command[0] === 'DEL') return command.slice(1); - return []; -} - describe('createRedisTier', () => { test('is named "redis"', () => { const tier = tierFor(fakeRedis()); @@ -336,76 +241,6 @@ describe('createRedisTier', () => { }); }); -describe('invalidation is slot-local on Redis Cluster', () => { - test('no single command is ever handed keys from two different tags', async () => { - // The failure this pins: one EVAL carrying every tag-set key is rejected with CROSSSLOT - // before the script runs, because `x:t:post` and `x:t:user` hash to different slots. It - // lands in report.errors as a partial bust, and stale rows serve until TTL. - const client = fakeRedis(); - const tier = tierFor(client); - await tier.set('feed', ['a'], { tags: [tag('post', '1')] }); - await tier.set('inbox', ['b'], { tags: [tag('user', '9')] }); - await tier.set('teams', ['c'], { tags: [tag('team')] }); - client.answerEval(REDIS_INVALIDATE_SCRIPT, []); - client.sent.length = 0; - - await tier.invalidateTags([tag('post', '1'), tag('user', '9'), tag('team')]); - - for (const command of client.sent) { - const slots = new Set(keysOf(command).map(slotTokenOf)); - expect(slots.size).toBeLessThanOrEqual(1); - } - // One script call per tag, not one for the batch. - expect(client.sent.filter((entry) => entry[1] === REDIS_INVALIDATE_SCRIPT)).toHaveLength(3); - }); - - test("a row tag's two buckets share one slot, so they may travel in one call", async () => { - const client = fakeRedis(); - const tier = tierFor(client); - await tier.set('feed', ['a'], { tags: [tag('post', '1')] }); - client.answerEval(REDIS_INVALIDATE_SCRIPT, []); - client.sent.length = 0; - - await tier.invalidateTags([tag('post', '1')]); - - const evals = client.sent.filter((entry) => entry[1] === REDIS_INVALIDATE_SCRIPT); - expect(keysOf(evals[0] ?? [])).toEqual(['x:t:{post}:1', 'x:t:{post}']); - expect(new Set(keysOf(evals[0] ?? []).map(slotTokenOf))).toEqual(new Set(['post'])); - }); - - test('every tag-set key carries a hash tag; value keys never need one', async () => { - const client = fakeRedis(); - const tier = tierFor(client); - await tier.set('feed', ['a'], { tags: [tag('post', '1'), tag('user')] }); - - const buckets = client.sent - .filter((entry) => entry[1] === REDIS_TAG_MEMBER_SCRIPT) - .map((entry) => String(entry[3])); - expect(buckets).toEqual(['x:t:{post}:1', 'x:t:{post}', 'x:t:{user}']); - for (const bucket of buckets) expect(bucket).toMatch(/\{[^}]+\}/); - }); -}); - -// The lease a join ASKS for is wire traffic and belongs here. Whether the server then grants it, -// keeps the longer of two, and gives a fresh bucket one at all is `TAG_MEMBER_SCRIPT`'s own -// semantics — three claims a fake can only restate, so they live in `redis.live.test.ts`. -describe('tag sets are bounded', () => { - test('every join asks for a lease longer than the member it added', async () => { - // Without this a tag set grows forever: value keys expire after five minutes, their - // membership never does, and one publish becomes a multi-million-member SMEMBERS. - const client = fakeRedis(); - const tier = tierFor(client); - await tier.set('feed', ['a'], { ttlMs: 60_000, tags: [tag('post', '1')] }); - - const joins = client.sent.filter((entry) => entry[1] === REDIS_TAG_MEMBER_SCRIPT); - expect(joins).toHaveLength(2); - for (const join of joins) { - // 60s member + the 60s grace: the bucket must outlive what it points at. - expect(Number(join[5])).toBe(120); - } - }); -}); - describe('the shared tier is namespaced per build', () => { test('the default namespace carries appVersion(), so two builds cannot read each other', async () => { // Rename a field and deploy: old and new pods share one Redis, `JSON.parse` does not diff --git a/packages/cache/src/redis.ts b/packages/cache/src/redis.ts index 840485ae5..77c9f65d8 100644 --- a/packages/cache/src/redis.ts +++ b/packages/cache/src/redis.ts @@ -67,7 +67,7 @@ interface StoredEntry { } /** - * Read the tag sets out and drop the tag sets themselves — and nothing else. + * Read the tag sets out. It deletes nothing at all, and both halves of that are deliberate. * * A script may only touch keys it was handed in `KEYS`, and the members of a tag set are not * among them: they are value keys hashing to slots this node may not even own. `DEL`ing them from @@ -75,13 +75,15 @@ interface StoredEntry { * Redis Cluster and in Dragonfly's strict mode — swallowed into `report.errors`, so a bust read * as "partial", the write that triggered it still succeeded, and stale rows served until TTL. * - * The value keys come back to the client instead, which drops them one `DEL` at a time: a single - * key is always slot-local, whatever the topology. Only the SMEMBERS + tag-set `DEL` stay atomic, - * and that is the pair that needed to be — a value key re-added by a concurrent write between the - * two halves is at worst a cache miss, never a stale read. + * The buckets themselves used to go, atomically with the `SMEMBERS` that read them. That made one + * failure permanent: a refused `DEL` in the client-side batch left its member with no bucket to + * be found in again, so the retry the error asks for answered `keys: []` and those rows served + * until their own TTL. The tier now `SREM`s exactly the members it managed to delete, which is + * strictly more precise — a member added by a concurrent write between the two halves is not in + * that list, so it keeps its membership instead of being silently orphaned by the bust. * - * That fixed HALF the cluster story. The other half is `KEYS` itself: one `EVAL` carrying every - * tag's buckets is rejected with `CROSSSLOT` before the script runs, because `:t:post` and + * That is HALF the cluster story. The other half is `KEYS` itself: one `EVAL` carrying every tag's + * buckets is rejected with `CROSSSLOT` before the script runs, because `:t:post` and * `:t:user` hash to different slots. So the buckets carry a `{entity}` hash tag and the tier * issues ONE call per tag — every key of a call then hashes on the same entity, by construction. */ @@ -92,7 +94,6 @@ for i, tagKey in ipairs(KEYS) do for _, key in ipairs(members) do table.insert(removed, key) end - redis.call('DEL', tagKey) end return removed `.trim(); @@ -145,13 +146,47 @@ const toStrings = (value: unknown): string[] => Array.isArray(value) ? value.map((item) => String(item)) : []; /** - * `PTTL`'s answer as milliseconds of remaining life, or `undefined` for the two sentinels it - * answers with instead of a duration: `-1` (key exists, no expiry) and `-2` (no such key). - * A driver may hand either back as a string, so the parse goes through `Number`. + * What `PTTL` said about a key the `GET` beside it just answered for. `-1` and `-2` are sentinels, + * not durations — and they mean different things here: `-1` is a key with no lease (one written + * outside this tier), `-2` is no key at all, which for a value the `GET` returned means it expired + * BETWEEN the two commands. A driver may hand either back as a string, so the parse is `Number`. */ -function remainingMs(reply: unknown): number | undefined { +type Lease = { readonly kind: 'reaped' } | { readonly kind: 'none' } | { readonly ms: number }; + +function leaseFrom(reply: unknown): Lease { const pttl = Number(reply); - return Number.isFinite(pttl) && pttl > 0 ? pttl : undefined; + if (!Number.isFinite(pttl)) return { kind: 'none' }; + if (pttl === -2) return { kind: 'reaped' }; + return pttl > 0 ? { ms: pttl } : { kind: 'none' }; +} + +/** + * `SISMEMBER` answered a literal `0`, and nothing else counts. A reply this cannot read is not + * evidence: treating one as "gone" deletes every value the tier writes, which is a cache that + * never caches. + */ +function saysAbsent(reply: unknown): boolean { + if (typeof reply === 'number') return reply === 0; + if (typeof reply === 'string') return Number(reply) === 0; + return false; +} + +/** + * The first refusal, verbatim when it is one — `fanOut` renders `message` into `report.errors`, so + * the operator sees which key the store refused rather than a count. + * + * The `fix:` is the call, not a command: there is no `x cache` in this build, and the retry is one + * line of the app's own code. It is safe to repeat because every key the store refused kept its + * tag membership — the bust `SREM`s only what it deleted. + */ +function raiseSweepFailure(failures: readonly unknown[], attempted: number): never { + const first = failures[0]; + if (first instanceof Error) throw first; + throw new CacheDriverUnavailableError({ + driver: 'redis', + cause: `${String(failures.length)} of ${String(attempted)} value keys could not be deleted`, + fix: "await invalidateTags(tags) again once redis answers — from '@ultimat3/cache', with the same tags; every key it refused kept its bucket membership, so the retry reaches it", + }); } export function createRedisTier(options: RedisTierOptions = {}): CacheTier { @@ -199,13 +234,17 @@ export function createRedisTier(options: RedisTierOptions = {}): CacheTier { conn().send('PTTL', [stored]) as Promise, ]); if (raw === null) return undefined; - const remaining = remainingMs(pttl); + const lease = leaseFrom(pttl); + // Expired between the two commands. Reported as a hit it would be a hit with no `expiresAt`, + // which the stack promotes into the LRU on the CALLER's ttl — a row one millisecond from + // death handed a fresh five minutes, one tier closer to the request. + if ('kind' in lease && lease.kind === 'reaped') return undefined; try { const parsed = JSON.parse(raw) as StoredEntry; return { value: parsed.v as T, tags: parsed.t.map(parseTag), - ...(remaining === undefined ? {} : { expiresAt: nowMs(clock) + remaining }), + ...('ms' in lease ? { expiresAt: nowMs(clock) + lease.ms } : {}), }; } catch { // A poisoned value is a miss, never a 500. Redis TTL will reap it. @@ -214,7 +253,18 @@ export function createRedisTier(options: RedisTierOptions = {}): CacheTier { } }, - /** The value key gets a lease and so does every bucket it joins — see `TAG_MEMBER_SCRIPT`. */ + /** + * The value key gets a lease and so does every bucket it joins — see `TAG_MEMBER_SCRIPT`. + * + * The buckets are joined FIRST and the membership is re-checked LAST, because this write and + * a bust of the same tag are two clients with no lock between them. Writing the value first + * left a window where the bust's `SMEMBERS` found an empty bucket and the value it should + * have cleared survived its own invalidation for the full TTL. Joining first moves the window + * somewhere observable: `invalidateTags` removes a member only when it deleted that member's + * value key, so a membership gone by the time the `SET` lands means this write was busted + * while it was in the air — and the value goes with it, because a row nothing can reach by + * tag is one no later bust can clear either. + */ async set(key: string, value: T, setOptions?: CacheSetOptions): Promise { const tags = setOptions?.tags ?? []; const ttlMs = assertTtl(key, setOptions?.ttlMs ?? defaultTtlMs, 'redis', jitter); @@ -226,12 +276,20 @@ export function createRedisTier(options: RedisTierOptions = {}): CacheTier { // the LRU tier about when the same entry dies. The BUCKET keeps whole seconds and keeps // rounding up: a tag set has to outlive every member it holds. const bucketTtlSeconds = String(Math.max(1, Math.ceil(ttlMs / 1000)) + TAG_TTL_GRACE_SECONDS); + // Deduped: two tags of one entity share the collection bucket, and joining it twice is a + // round trip that changes nothing. Issued together — one key each, so still slot-local. + const buckets = [...new Set(tags.flatMap(tagKeysFor))]; + await Promise.all( + buckets.map((bucket) => + conn().send('EVAL', [TAG_MEMBER_SCRIPT, '1', bucket, stored, bucketTtlSeconds]), + ), + ); await conn().send('SET', [stored, JSON.stringify(payload), 'PX', String(Math.ceil(ttlMs))]); - for (const owned of tags) { - for (const bucket of tagKeysFor(owned)) { - await conn().send('EVAL', [TAG_MEMBER_SCRIPT, '1', bucket, stored, bucketTtlSeconds]); - } - } + if (buckets.length === 0) return; + const membership = await Promise.all( + buckets.map((bucket) => conn().send('SISMEMBER', [bucket, stored])), + ); + if (membership.some(saysAbsent)) await conn().send('DEL', [stored]); }, async del(key: string): Promise { @@ -263,13 +321,37 @@ export function createRedisTier(options: RedisTierOptions = {}): CacheTier { // A member may sit in two tag sets; deleting it twice is harmless but reporting it twice // makes the `/_x` panel overstate what cleared. const members = [...new Set(replies.flatMap(toStrings))]; + const deleted = new Set(); + const failures: unknown[] = []; for (let start = 0; start < members.length; start += DELETE_BATCH) { // One key per DEL — always slot-local. Issued together so the batch costs one round trip. - await Promise.all( - members.slice(start, start + DELETE_BATCH).map((member) => conn().send('DEL', [member])), + // `allSettled`, because which ones died decides what leaves the buckets below. + const batch = members.slice(start, start + DELETE_BATCH); + const settled = await Promise.allSettled( + batch.map((member) => conn().send('DEL', [member])), ); + settled.forEach((result, index) => { + const member = batch[index]; + if (member === undefined) return; + if (result.status === 'fulfilled') deleted.add(member); + else failures.push(result.reason); + }); } - const stripped = members.map((key) => key.slice(`${ns}:c:`.length)); + + // Only what actually died leaves its bucket. A member the store refused to delete keeps its + // membership, so the retry `report.errors` asks for still finds it; the script no longer + // drops the bucket, which is what made that failure permanent. + for (let i = 0; i < perTag.length; i += 1) { + const gone = [...new Set(toStrings(replies[i]))].filter((member) => deleted.has(member)); + for (const bucket of perTag[i] ?? []) { + for (let start = 0; start < gone.length; start += DELETE_BATCH) { + await conn().send('SREM', [bucket, ...gone.slice(start, start + DELETE_BATCH)]); + } + } + } + + if (failures.length > 0) raiseSweepFailure(failures, members.length); + const stripped = [...deleted].map((key) => key.slice(`${ns}:c:`.length)); return { tier: 'redis', keys: stripped }; }, }; diff --git a/packages/cache/src/semantic.test.ts b/packages/cache/src/semantic.test.ts index 28873d501..d86ba18cc 100644 --- a/packages/cache/src/semantic.test.ts +++ b/packages/cache/src/semantic.test.ts @@ -162,6 +162,21 @@ describe('TTL expiry', () => { expect(await cache.size()).toBe(0); }); + test('a ttlMs that is not a positive, finite number is refused, never stored expired', async () => { + // The rule every tier writes under, applied to the one cache that was skipping it: `0` stored + // an entry already past its expiry, so every lookup missed and the only evidence was a + // completion bill. `X_CACHE_TTL_INVALID` names the edit instead. + const cache = createMemorySemanticCache({ clock: fakeClock(1_000) }); + + // Thrown where it is validated, exactly as `LruCache.set` throws X_CACHE_TOO_LARGE: the + // caller's `await` sees a rejection either way, and `bestEffort` absorbs both shapes. + expect(() => cache.remember('k', [1, 0], 'v', { ttlMs: 0 })).toThrow('X_CACHE_TTL_INVALID'); + expect(() => cache.remember('k', [1, 0], 'v', { ttlMs: Number.POSITIVE_INFINITY })).toThrow( + 'X_CACHE_TTL_INVALID', + ); + expect(await cache.size()).toBe(0); + }); + test('defaultTtlMs applies when remember is called without an explicit ttlMs', async () => { const clock = fakeClock(1_000_000); const cache = createMemorySemanticCache({ defaultTtlMs: 500, clock }); diff --git a/packages/cache/src/semantic.ts b/packages/cache/src/semantic.ts index 3156ccc20..21b133eda 100644 --- a/packages/cache/src/semantic.ts +++ b/packages/cache/src/semantic.ts @@ -8,7 +8,7 @@ import type { Clock } from '@ultimat3/core'; import { systemClock } from '@ultimat3/core'; import type { CacheTag } from './tags'; import { tagsIntersect } from './tags'; -import { nowMs } from './tiers'; +import { assertTtl, nowMs } from './tiers'; export type Embedding = readonly number[]; @@ -111,12 +111,19 @@ export function createMemorySemanticCache(options: SemanticCacheOptions = {}): S value: T, rememberOptions?: SemanticRememberOptions, ): Promise { + // The same TTL rule every tier writes under, and for the same reason: `0` here silently + // stored an entry that was already expired, so the cache answered every lookup with a miss + // and nothing said why. `jitterFraction: 0` — spreading a lease is a herd defence for a + // shared store, and this one is per process. + const ttlMs = assertTtl(key, rememberOptions?.ttlMs ?? defaultTtlMs, 'semantic', { + jitterFraction: 0, + }); records.delete(key); records.set(key, { key, embedding, value, - expiresAt: nowMs(clock) + (rememberOptions?.ttlMs ?? defaultTtlMs), + expiresAt: nowMs(clock) + ttlMs, tags: rememberOptions?.tags ?? [], }); // Insertion-ordered Map: the oldest key is the first one. diff --git a/packages/cache/src/set-options.ts b/packages/cache/src/set-options.ts new file mode 100644 index 000000000..629d70ffe --- /dev/null +++ b/packages/cache/src/set-options.ts @@ -0,0 +1,65 @@ +// How two callers' `CacheSetOptions` become one write, and how a `null` load picks its TTL. Both +// belong to the stack rather than to a tier — a tier sees one caller and one value, and neither +// decision is answerable from there. + +import type { CacheTag } from './tags'; +import { serializeTag } from './tags'; +import type { CacheSetOptions } from './tiers'; + +/** + * `negativeTtlMs` selected when the value IS the absence of one. A lookup for a row that has not + * replicated yet answers `null` 40ms before it lands; holding that for the positive TTL serves + * "does not exist" for five minutes. + */ +export function ttlOptionsFor(value: T, options?: CacheSetOptions): CacheSetOptions | undefined { + const negative = options?.negativeTtlMs; + if (negative === undefined) return options; + if (value !== null && value !== undefined) return options; + return { ...options, ttlMs: negative }; +} + +/** First-seen order, deduped on the wire form — the same identity every tier indexes by. */ +function mergeTags( + current: readonly CacheTag[] | undefined, + joining: readonly CacheTag[] | undefined, +): readonly CacheTag[] | undefined { + if (current === undefined) return joining; + if (joining === undefined) return current; + const seen = new Set(current.map(serializeTag)); + const merged = [...current]; + for (const owned of joining) { + const wire = serializeTag(owned); + if (seen.has(wire)) continue; + seen.add(wire); + merged.push(owned); + } + return merged; +} + +/** The SHORTEST lease wins: an entry held longer than a caller asked for is that caller's bug. */ +function shortest(current: number | undefined, joining: number | undefined): number | undefined { + if (current === undefined) return joining; + if (joining === undefined) return current; + return Math.min(current, joining); +} + +/** + * Fold a joiner's options into the single-flight leader's. + * + * A joiner that shares a load also shares its WRITE, so options it declared and the leader did not + * are silently dropped without this: the entry lands carrying only the leader's tags, and the + * joiner's invalidation — the whole point of declaring a tag — never reaches it again. + */ +export function mergeSetOptions( + current: CacheSetOptions, + joining: CacheSetOptions, +): CacheSetOptions { + const tags = mergeTags(current.tags, joining.tags); + const ttlMs = shortest(current.ttlMs, joining.ttlMs); + const negativeTtlMs = shortest(current.negativeTtlMs, joining.negativeTtlMs); + return { + ...(tags === undefined ? {} : { tags }), + ...(ttlMs === undefined ? {} : { ttlMs }), + ...(negativeTtlMs === undefined ? {} : { negativeTtlMs }), + }; +} diff --git a/packages/cache/src/single-flight.test.ts b/packages/cache/src/single-flight.test.ts index fdc81b78e..d7f866f6d 100644 --- a/packages/cache/src/single-flight.test.ts +++ b/packages/cache/src/single-flight.test.ts @@ -129,6 +129,32 @@ describe('createSingleFlight', () => { expect(flight.size).toBe(0); }); + test('a joiner contributes to the leader, which reads the merge LATE', async () => { + // A joiner shares the leader's write as well as its load, so anything it declared about that + // write is silently dropped unless it reaches the leader before the leader publishes. + const flight = createSingleFlight(); + const gate = deferred(); + const seen: string[][] = []; + const work = (shared: () => string[] | undefined) => async (): Promise => { + const value = await gate.promise; + seen.push(shared() ?? []); + return value; + }; + + const leader = flight.run('k', (shared) => work(shared)(), { + context: ['leader'], + merge: (current, joining) => [...current, ...joining], + }); + const joiner = flight.run('k', (shared) => work(shared)(), { + context: ['joiner'], + merge: (current, joining) => [...current, ...joining], + }); + + gate.resolve('loaded'); + expect(await Promise.all([leader, joiner])).toEqual(['loaded', 'loaded']); + expect(seen).toEqual([['leader', 'joiner']]); + }); + test('a late settle from a replaced load does not drop the live one', async () => { // `settled` compares identity before deleting: without that, the first load's callback would // evict the second load's entry and every joiner after it would start its own. @@ -231,6 +257,41 @@ describe('createCacheStack read: concurrent misses share ONE load', () => { expect(attempts).toBe(2); }); + test("a joiner's tags and its shorter TTL reach the fill it shares", async () => { + // The consequence of dropping them: the entry lands carrying only the leader's tags, so the + // tag the joiner declared can never reach it and its invalidation silently never fires. + const written: CacheSetOptions[] = []; + const recorder: CacheTier = { + name: 'lru', + get: () => Promise.resolve(undefined), + set: (_key, _value, options?: CacheSetOptions) => { + written.push(options ?? {}); + return Promise.resolve(); + }, + del: () => Promise.resolve(), + invalidateTags: () => Promise.resolve({ tier: 'lru' as const, keys: [] }), + }; + const stack = createCacheStack([recorder]); + const gate = deferred(); + + const leader = stack.read('post:1', () => gate.promise, { + ttlMs: 300_000, + tags: [{ entity: 'post' }], + }); + const joiner = stack.read('post:1', () => Promise.resolve('never runs'), { + ttlMs: 60_000, + tags: [{ entity: 'post', id: '1' }], + }); + + gate.resolve('loaded'); + await Promise.all([leader, joiner]); + + expect(written).toHaveLength(1); + expect(written[0]?.tags).toEqual([{ entity: 'post' }, { entity: 'post', id: '1' }]); + // The SHORTEST lease of the two: an entry held longer than a caller asked for is stale to it. + expect(written[0]?.ttlMs).toBe(60_000); + }); + test('two stacks are two ladders and never join each other loads', async () => { const calls: string[] = []; const one = createCacheStack([fakeTier('lru', calls)]); diff --git a/packages/cache/src/single-flight.ts b/packages/cache/src/single-flight.ts index 7824d0bd3..750a209f0 100644 --- a/packages/cache/src/single-flight.ts +++ b/packages/cache/src/single-flight.ts @@ -3,36 +3,71 @@ // that window misses too and every one of them queries the origin. The share is per load and // never a second cache — the entry clears as it settles, rejection included. +/** + * What a joiner contributes to the load it joined. Without one a joiner is a free rider: it takes + * the leader's value AND the leader's write, so anything it declared about that write is dropped. + */ +export interface FlightJoin { + readonly context: C; + /** Folds a joiner in. Called synchronously as it arrives, so the leader sees it before it writes. */ + readonly merge: (current: C, joining: C) => C; +} + /** Shares one in-flight `work()` per key. `@ultimat3/realtime`'s `entry.reading`, one tier down. */ export interface SingleFlight { - run(key: string, work: () => Promise): Promise; + /** + * `work` receives a reader for the merged context — read it LATE (after the load settles), or + * it answers with only what the leader brought. + */ + run( + key: string, + work: (shared: () => C | undefined) => Promise, + join?: FlightJoin, + ): Promise; /** In-flight loads right now. A number that does not fall back to `0` is a leak. */ readonly size: number; } +/** The leader's promise, plus the box its merged context lives in — one identity for both. */ +interface Flight { + readonly running: Promise; + readonly shared: { context: unknown }; +} + export function createSingleFlight(): SingleFlight { - const inflight = new Map>(); + const inflight = new Map(); return { get size(): number { return inflight.size; }, - run(key: string, work: () => Promise): Promise { + run( + key: string, + work: (shared: () => C | undefined) => Promise, + join?: FlightJoin, + ): Promise { const joined = inflight.get(key); // Two readers of one key asking for two different `T` is an app bug the cache cannot see; // the value they share is the same object either way, so the cast is the honest one. - if (joined !== undefined) return joined as Promise; + if (joined !== undefined) { + if (join !== undefined) { + joined.shared.context = join.merge(joined.shared.context as C, join.context); + } + return joined.running as Promise; + } + const shared: { context: unknown } = { context: join?.context }; // Wrapped so a `work()` that throws SYNCHRONOUSLY still rejects the joiners rather than // escaping past the map and leaving no entry to clear. - const running: Promise = (async () => await work())(); - inflight.set(key, running); + const running: Promise = (async () => await work(() => shared.context as C | undefined))(); + const entry: Flight = { running, shared }; + inflight.set(key, entry); const settled = (): void => { // Only the leader clears its own entry: a load started after this one settled must not be // dropped by a late callback from the load it replaced. - if (inflight.get(key) === running) inflight.delete(key); + if (inflight.get(key) === entry) inflight.delete(key); }; // A rejected load MUST clear too, or one failure is cached as a permanent rejection. void running.then(settled, settled); diff --git a/packages/cache/src/tier-failures.test.ts b/packages/cache/src/tier-failures.test.ts index 92272b9b2..90ee2951f 100644 --- a/packages/cache/src/tier-failures.test.ts +++ b/packages/cache/src/tier-failures.test.ts @@ -41,6 +41,24 @@ describe('bestEffort', () => { expect(recentTierFailures()).toEqual([]); }); + test('a cache OFF the ladder degrades into the same one log', async () => { + // `@ultimat3/query`'s read cache is not a rung of the ladder and refuses the same way. It has + // to reach this log, not a private try/catch of its own: a second, invisible failure record + // is exactly what one bounded log exists to prevent — and it needs a name it can pass + // honestly, because attributing a query-cache refusal to `redis` is a lie in the `/_x` panel. + const answer = await bestEffort('query-read', 'get', 'cache:posts', () => + Promise.reject(new Error('read cache is down')), + ); + + expect(answer).toBeUndefined(); + expect(recentTierFailures()[0]).toMatchObject({ + tier: 'query-read', + op: 'get', + key: 'cache:posts', + message: 'read cache is down', + }); + }); + test('a rejection resolves to undefined instead of propagating', async () => { const answer = await bestEffort('redis', 'set', 'k', () => Promise.reject(new Error('connection refused')), diff --git a/packages/cache/src/tier-failures.ts b/packages/cache/src/tier-failures.ts index 25936a10f..e47a7b2e0 100644 --- a/packages/cache/src/tier-failures.ts +++ b/packages/cache/src/tier-failures.ts @@ -4,7 +4,7 @@ // running degraded stays answerable instead of merely looking slow. import { logger, systemClock, UltimateError } from '@ultimat3/core'; -import type { TierName } from './tiers'; +import type { TierLabel } from './tiers'; /** The three tier calls a stack makes on the value path. `invalidateTags` reports its own. */ export type TierOperation = 'get' | 'set' | 'del'; @@ -12,7 +12,7 @@ export type TierOperation = 'get' | 'set' | 'del'; export interface TierFailure { /** ISO-8601, from core's `systemClock` — never `new Date()`. */ readonly at: string; - readonly tier: TierName; + readonly tier: TierLabel; readonly op: TierOperation; readonly key: string; /** The `X_*` code when the tier threw an `UltimateError`; absent for anything else. */ @@ -57,9 +57,14 @@ export function isolateTierFailures(): () => void { * `get` already reads as a miss and a `set`/`del` as "that tier is unchanged" — so the caller * needs no branch. The entry a tier refused to hold expires by TTL, exactly as one an * `invalidateTags` failure left behind does. + * + * Public, and the only sanctioned way to swallow a cache refusal: a store outside this package + * (`@ultimat3/query`'s read cache) that wrapped its own `try/catch` would degrade invisibly, and + * a second failure log nobody reads is what this one exists to prevent. Pass the store's + * `TierLabel` — it is closed for that reason. */ export async function bestEffort( - tier: TierName, + tier: TierLabel, op: TierOperation, key: string, run: () => Promise, @@ -72,7 +77,7 @@ export async function bestEffort( } } -function record(tier: TierName, op: TierOperation, key: string, error: unknown): void { +function record(tier: TierLabel, op: TierOperation, key: string, error: unknown): void { const failure: TierFailure = { at: systemClock.now().toISOString(), tier, diff --git a/packages/cache/src/tiers.test.ts b/packages/cache/src/tiers.test.ts index 3cff6a07f..bdac5161b 100644 --- a/packages/cache/src/tiers.test.ts +++ b/packages/cache/src/tiers.test.ts @@ -216,7 +216,10 @@ describe('createCacheStack write', () => { }); describe('createCacheStack drop', () => { - test('calls del() on every tier once', async () => { + test('calls del() on every tier once, FARTHEST first', async () => { + // Read order clears the near tiers while the far one still holds the old value, and a read + // racing the drop promotes it straight back up into them. `invalidateTags` fans out the same + // way and for the same reason — `invalidation-race.test.ts` pins the outcome that follows. const calls: string[] = []; const lru = fakeTier('lru', calls); const redis = fakeTier('redis', calls); @@ -224,7 +227,7 @@ describe('createCacheStack drop', () => { await stack.drop('k'); - expect(calls).toEqual(['del:lru:k', 'del:redis:k']); + expect(calls).toEqual(['del:redis:k', 'del:lru:k']); }); }); @@ -334,7 +337,7 @@ describe('createCacheStack: a refusing tier never fails the business call', () = await stack.drop('k'); - expect(calls).toEqual(['del:lru:k', 'del:redis:k']); + expect(calls).toEqual(['del:redis:k', 'del:lru:k']); expect(recentTierFailures()[0]).toMatchObject({ tier: 'lru', op: 'del', key: 'k' }); }); }); diff --git a/packages/cache/src/tiers.ts b/packages/cache/src/tiers.ts index 0091b178a..82c091a23 100644 --- a/packages/cache/src/tiers.ts +++ b/packages/cache/src/tiers.ts @@ -6,6 +6,9 @@ import type { Clock } from '@ultimat3/core'; import { systemClock } from '@ultimat3/core'; import { CacheJitterInvalidError, CacheTtlInvalidError } from './errors'; +import type { CacheFence } from './fence'; +import { markInvalidated, sampleFence } from './fence'; +import { mergeSetOptions, ttlOptionsFor } from './set-options'; import { createSingleFlight } from './single-flight'; import type { CacheTag } from './tags'; import { bestEffort } from './tier-failures'; @@ -15,6 +18,17 @@ export type TierName = 'request-memo' | 'lru' | 'redis' | 'cdn'; /** Read order. Index in this array is the tier's distance from the request. */ export const TIER_ORDER: readonly TierName[] = ['request-memo', 'lru', 'redis', 'cdn']; +/** + * Who a swallowed refusal is attributed to in `recentTierFailures()` and the `/_x` panel: every + * rung of the ladder, plus a cache that degrades the same way without being on it — + * `@ultimat3/query`'s read cache, which is a tier-3 store this tier-1 package cannot import. + * + * Closed rather than a free-form string, and NOT a widening of `TierName`: `TIER_ORDER` is the + * ladder and a name missing from it sorts to `-1`, ahead of the request memo. A label is a log + * facet; a `TierName` is a position. Two spellings of one store is a panel nobody can group. + */ +export type TierLabel = TierName | 'query-read'; + /** Injected so a jittered TTL is deterministic in a test. Never `Math.random()` at a call site. */ export type Rng = () => number; @@ -66,10 +80,16 @@ export interface CacheSetOptions { * window, and with single-flight sharing only the loads that overlap that is still 40,000 origin * reads. Shaving a random slice off each lease is what turns one cliff into a ramp. */ +/** + * Where a lease is being spent. Every tier — plus `'semantic'`, which is not a tier and still may + * not invent its own reading of `ttlMs: 0`. + */ +export type TtlScope = TierName | 'semantic'; + export function assertTtl( key: string, ttlMs: number, - tier: TierName, + tier: TtlScope, jitter: TtlJitter = {}, ): number { if (!Number.isFinite(ttlMs) || ttlMs <= 0) { @@ -128,17 +148,6 @@ export function sortTiers(tiers: readonly CacheTier[]): readonly CacheTier[] { return [...tiers].sort((a, b) => TIER_ORDER.indexOf(a.name) - TIER_ORDER.indexOf(b.name)); } -/** - * `negativeTtlMs` selected when the value IS the absence of one. Kept here rather than in a tier - * because the stack is the only layer that ever sees what `load()` answered. - */ -function ttlOptionsFor(value: T, options?: CacheSetOptions): CacheSetOptions | undefined { - const negative = options?.negativeTtlMs; - if (negative === undefined) return options; - if (value !== null && value !== undefined) return options; - return { ...options, ttlMs: negative }; -} - /** * Every tier call here goes through `bestEffort`: a tier that refuses is a tier that did not * answer, never a failed business read. `load()` is the one call left unguarded — it *is* the @@ -158,10 +167,34 @@ export function createCacheStack( // Per stack, not per module: two stacks are two ladders and must not join each other's loads. const flight = createSingleFlight(); - const fill = async (key: string, value: T, setOptions?: CacheSetOptions): Promise => { + /** Take back what a fence refused mid-ladder: half a stale ladder is still a stale read. */ + const rollback = async (written: readonly CacheTier[], key: string): Promise => { + for (const tier of [...written].reverse()) { + await bestEffort(tier.name, 'del', key, () => tier.del(key)); + } + }; + + /** + * `fence` is what stops a fill from republishing what an invalidation just cleared: the value + * was read by a `load()` that started before the bust, so writing it now hides that write from + * every reader for the whole TTL — and the invalidation reported `errors: []` while doing it. + * Re-checked per tier rather than once, because the ladder is several awaits long. + */ + const fill = async ( + key: string, + value: T, + setOptions?: CacheSetOptions, + fence?: CacheFence, + ): Promise => { const resolved = ttlOptionsFor(value, setOptions); + const written: CacheTier[] = []; for (const tier of ordered) { + if (fence !== undefined && !fence.isValid()) { + await rollback(written, key); + return; + } await bestEffort(tier.name, 'set', key, () => tier.set(key, value, resolved)); + written.push(tier); } }; @@ -170,6 +203,11 @@ export function createCacheStack( key: string, setOptions?: CacheSetOptions, ): Promise | undefined> => { + // A promotion is a write too. The ladder is one await per rung, so a bust can finish between + // the far `get` and the near `set` — which promotes a value out of a tier nothing has cleared + // yet into one that was cleared a millisecond ago. Fan-out order makes that window small; the + // fence is what makes crossing it not matter. + const fence = sampleFence({ key }); for (let i = 0; i < ordered.length; i += 1) { const tier = ordered[i]; if (tier === undefined) continue; @@ -188,11 +226,20 @@ export function createCacheStack( tags: hit.tags, ...(hit.expiresAt === undefined ? {} : { ttlMs: hit.expiresAt - now }), }; + fence.cover({ tags: hit.tags }); + const promotedInto: CacheTier[] = []; for (let up = 0; up < i; up += 1) { const closer = ordered[up]; if (closer === undefined) continue; + if (!fence.isValid()) { + await rollback(promotedInto, key); + break; + } await bestEffort(closer.name, 'set', key, () => closer.set(key, hit.value, promoted)); + promotedInto.push(closer); } + // Returned either way: this IS what a tier held when it was asked, and a fence never fails + // a business read — it only declines to publish. return hit; } return undefined; @@ -208,19 +255,40 @@ export function createCacheStack( // The stampede guard. The homepage feed read 8,000x/s with a 60s lease misses for the whole // ~200ms `load()` takes, so ~1,600 identical queries reach Postgres at every TTL boundary // unless the arrivals inside that window join the read already running. - return await flight.run(key, async () => { - const value = await load(); - await fill(key, value, setOptions); - return value; - }); + return await flight.run( + key, + async (shared) => { + // Sampled BEFORE `load()` — everything after this instant is a write this value has + // not seen, and a fill that ignored it would hide that write for the whole TTL. + const fence = sampleFence({ + key, + ...(setOptions?.tags === undefined ? {} : { tags: setOptions.tags }), + }); + const value = await load(); + // Joiners merged their own tags into the load they shared; covering is retroactive, so + // a tag that arrived mid-load is fenced back to the sample rather than from now. + const merged = shared() ?? setOptions; + if (merged?.tags !== undefined) fence.cover({ tags: merged.tags }); + await fill(key, value, merged, fence); + return value; + }, + { context: setOptions ?? {}, merge: mergeSetOptions }, + ); }, write(key: string, value: T, options?: CacheSetOptions): Promise { + // An explicit write is newer truth than any load already in flight for this key, so it + // fences those fills off before it starts rather than losing a race with one. + markInvalidated({ key }); return fill(key, value, options); }, async drop(key: string): Promise { - for (const tier of ordered) { + markInvalidated({ key }); + // Farthest tier first, for the reason `invalidateTags` fans out that way: clearing the near + // tiers first leaves a window where a racing read finds the far tier still holding the old + // value and promotes it back up, into tiers this call has already cleared. + for (const tier of [...ordered].reverse()) { await bestEffort(tier.name, 'del', key, () => tier.del(key)); } }, diff --git a/packages/cli/src/dev-cache.test.ts b/packages/cli/src/dev-cache.test.ts index 750f7ee00..43cf5f5b8 100644 --- a/packages/cli/src/dev-cache.test.ts +++ b/packages/cli/src/dev-cache.test.ts @@ -12,6 +12,7 @@ import { noopPurgeDriver, registeredTiers, } from '@ultimat3/cache'; +import { getReadCache, MemoryReadCache } from '@ultimat3/query'; import { InProcessTransport } from '@ultimat3/realtime'; import { CACHE_INVALIDATE_SUBJECT, startCacheTiers, tierReadCache } from './dev-cache'; @@ -83,6 +84,53 @@ describe('which tiers a boot registers', () => { }); }); +describe("the read tier an action's cache.invalidates has to reach", () => { + /** + * The failure this pins: `invalidateTags` fans out to REGISTERED tiers, the read tier a `cache:` + * query fills through is `@ultimat3/query`'s own seam, and on a boot with no `REDIS_URL` that + * seam was left as the module-default `MemoryReadCache` — an object in no registry, which + * nothing in the framework called `invalidateQueryTags` on. Every `cache:` read on every + * non-Redis deployment therefore served pre-write rows for the whole TTL while the invalidation + * report said `errors: []`. + */ + const fillReadCache = async (): Promise => { + const key = 'query:feed:fingerprint:post'; + await getReadCache().set(key, { + value: ['pre-write'], + expiresAt: Date.now() + 60_000, + tags: [{ entity: 'post' }], + }); + return key; + }; + + test('with no REDIS_URL an invalidateTags fan-out drops the read entry', async () => { + restore = isolateTiers(); + declareTags(['post']); + release = startCacheTiers({ + env: {}, + purge: noopPurgeDriver(), + transport: new InProcessTransport(), + }); + const key = await fillReadCache(); + expect(await getReadCache().get(key)).toBeDefined(); + + await invalidateTags([{ entity: 'post' }]); + + expect(await getReadCache().get(key)).toBeUndefined(); + }); + + test('the release puts the process back on an unwired read cache', async () => { + restore = isolateTiers(); + const stop = startCacheTiers({ + env: {}, + purge: noopPurgeDriver(), + transport: new InProcessTransport(), + }); + await stop(); + expect(getReadCache()).toBeInstanceOf(MemoryReadCache); + }); +}); + describe('cross-instance invalidation', () => { test('a local bust is published on the wire', async () => { restore = isolateTiers(); diff --git a/packages/cli/src/dev-cache.ts b/packages/cli/src/dev-cache.ts index 15fd59077..cedfd6dd0 100644 --- a/packages/cli/src/dev-cache.ts +++ b/packages/cli/src/dev-cache.ts @@ -102,14 +102,20 @@ export function startCacheTiers(options: CacheTiersOptions): () => Promise // they are the "embedded default" that needs no variable to switch on. Registration order does // not decide read order — `sortTiers` does — but it is written in read order anyway. registerTier(createMemoTier()); - registerTier(createLruTier()); + const lru = createLruTier(); + registerTier(lru); const shared = sharedTier(options.env); - if (shared !== undefined) { - registerTier(shared); - // The read tier follows the shared tier and only the shared tier: with none configured the - // in-process `MemoryReadCache` is already the right answer for a single node. - setReadCache(tierReadCache(shared)); - } + if (shared !== undefined) registerTier(shared); + // The read tier is ALWAYS one of the objects registered above, and that is the whole point: + // `invalidateTags` fans out to registered tiers and to nothing else, so a read cache holding + // entries of its own is a `cache:` query an action's `invalidates` can never bust. Left as the + // module-default `MemoryReadCache`, every non-Redis deployment served pre-write rows for the + // full TTL and reported `errors: []` while doing it. The shared tier when there is one — a + // second replica must not answer from this node's heap — otherwise the same `LruCache` the + // `lru` tier holds, so one bust reaches both views of it. + setReadCache( + shared === undefined ? new MemoryReadCache({ cache: lru.cache }) : tierReadCache(shared), + ); // Registered only when a credential named a real edge. A noop tier would put a `cdn` line in // every invalidation report claiming keys an edge that does not exist had accepted — and the // `/_x` cache panel renders those reports, so the lie would be the thing an agent reads. diff --git a/packages/cli/src/dev-roles-csp.test.ts b/packages/cli/src/dev-roles-csp.test.ts new file mode 100644 index 000000000..26aeb6e1d --- /dev/null +++ b/packages/cli/src/dev-roles-csp.test.ts @@ -0,0 +1,110 @@ +// Single responsibility: the `style-src` the web role sends, against the styles that same response +// carries. Split from `dev-roles.test.ts` because it asks nothing about which roles start — it +// asks whether one started role's response is self-consistent. +// +// The bug it pins: the web role sent `style-src 'self'` and every document it served carried its +// surface's CSS in an inline `', csp)).toEqual([]); + }); +}); diff --git a/packages/cli/src/dev-roles-fixture.ts b/packages/cli/src/dev-roles-fixture.ts new file mode 100644 index 000000000..0959a486d --- /dev/null +++ b/packages/cli/src/dev-roles-fixture.ts @@ -0,0 +1,67 @@ +// The one `RunningServices` every `dev-roles` test file boots roles against, and the one reset +// between them. Shared rather than copied, for the reason `policy-fixture.ts` gives: three files +// start the same roles, and a second copy of the runtime drifts while each file keeps passing. +// +// Its own module rather than a `.test.ts` neighbours import, because `tsconfig.json` excludes +// `*.test.ts` — a fixture written there is one `tsc` never reads. + +import { noopPurgeDriver } from '@ultimat3/cache'; +import { resetLifecycle } from '@ultimat3/core'; +import { + createMemoryDriver, + createMemoryEventBus, + createMemoryOutboxStore, + resetJobs, + resetJobsFacade, + resetTasks, +} from '@ultimat3/jobs'; +import { createMemoryDriver as createMemoryMailDriver } from '@ultimat3/mail'; +import { DEFAULT_PRESENCE_TTL_MS, InProcessTransport } from '@ultimat3/realtime'; +import { defineStorage, localDriver } from '@ultimat3/storage'; +import type { RunningServices } from './dev-runtime'; +import { resolveServices } from './dev-services'; + +/** + * Every service a role touches, embedded but real — no PGlite boot for a role-wiring test. + * + * `root` is a parameter and not a constant: each test file owns its own directory and deletes it, + * so two files sharing one on-disk storage root cannot leave the other's fixture half-removed. + */ +export function fixtureRuntime(root: string): RunningServices { + const services = resolveServices(root, {}); + const transport = new InProcessTransport(); + return { + services, + db: { async ping() {}, async close() {} } as unknown as RunningServices['db'], + jobs: createMemoryDriver(), + // A real store, not a stub: the `worker` role starts the outbox relay against it, and a relay + // whose `claim()` rejects on the first 200ms tick is an unhandled rejection in whichever test + // happens to still be running. + outbox: createMemoryOutboxStore(), + events: createMemoryEventBus(), + transport, + transportDetail: 'in-process fanout', + // The sync role reads this to build its `PresenceRegistry`; the default is what a boot with no + // `NATS_URL` resolves to, so the fixture is the real number rather than a rounder one. + presenceTtlMs: DEFAULT_PRESENCE_TTL_MS, + storage: defineStorage({ disks: { local: localDriver({ root: `${root}/storage` }) } }), + mail: createMemoryMailDriver(), + mailDetail: 'embedded', + purge: noopPurgeDriver(), + purgeDetail: 'none', + stop: async () => transport.close(), + }; +} + +/** + * The process-global state one started role leaves behind. `resetLifecycle` is the load-bearing + * one: core's lifecycle is process-wide and a stopped server leaves it drained, so without it the + * SECOND web role in a file answers every request `X_DRAINING` — a suite that only passes when its + * tests are run one at a time. `@ultimat3/http`'s own server suite resets it for the same reason. + */ +export function resetDevRolesState(): void { + resetJobs(); + resetJobsFacade(); + resetTasks(); + resetLifecycle(); +} diff --git a/packages/cli/src/dev-roles-identity.test.ts b/packages/cli/src/dev-roles-identity.test.ts new file mode 100644 index 000000000..4e0e84581 --- /dev/null +++ b/packages/cli/src/dev-roles-identity.test.ts @@ -0,0 +1,213 @@ +// Single responsibility: where a booted role's ACTOR comes from. `dev-roles.test.ts` proves which +// roles `--role` starts and stops; this proves that a role which started can say who is calling — +// the web role over a request, the sync node over a socket, and the warning a process emits when +// nothing can answer at all. +// +// `startWeb` passed `devHooks()`, which returned `authorize` and nothing else, so +// `hooks.authenticate` had no caller anywhere in the framework: `auth: 'required'` was +// unsatisfiable under `x dev` AND under `apps/web/server.ts`, which boots through the same +// function. Every case here is driven end to end rather than off a hook table. + +import { afterAll, afterEach, describe, expect, test } from 'bun:test'; +import { rm } from 'node:fs/promises'; +import { logger, userActor } from '@ultimat3/core'; +import type { Route } from '@ultimat3/http'; +import { configureAuthenticator, resetAuthenticator } from '@ultimat3/http'; +import type { RunningRoles } from './dev-roles'; +import { selectRoles, startRoles } from './dev-roles'; +import { fixtureRuntime, resetDevRolesState } from './dev-roles-fixture'; + +const ROOT = `${import.meta.dir}/../.roles-identity-fixture`; +const fakeRuntime = (): ReturnType => fixtureRuntime(ROOT); + +let running: RunningRoles | undefined; + +afterEach(async () => { + await running?.stop(); + running = undefined; + resetDevRolesState(); +}); + +afterAll(async () => { + await rm(ROOT, { recursive: true, force: true }); +}); + +describe('integration · the web role resolves an actor from the request', () => { + afterEach(resetAuthenticator); + + const routes = [ + { + method: 'GET' as const, + path: '/whoami', + meta: { name: 'whoami', auth: 'required' as const }, + handler: (_request: unknown, ctx: { actor: { id: string } }) => new Response(ctx.actor.id), + }, + ]; + + test('a session cookie becomes the actor; no cookie is still a 401', async () => { + let calls = 0; + configureAuthenticator((request) => { + calls += 1; + const session = request.cookie('session'); + return session === null ? null : userActor({ id: session }); + }); + + running = await startRoles({ + roles: selectRoles('web'), + port: 0, + buildId: 'test', + runtime: fakeRuntime(), + env: {}, + routes, + }); + + const anonymous = await running.server?.fetch(new Request('http://dev.test/whoami')); + expect(anonymous?.status).toBe(401); + + const signedIn = await running.server?.fetch( + new Request('http://dev.test/whoami', { headers: { cookie: 'session=u-7' } }), + ); + expect(signedIn?.status).toBe(200); + expect(await signedIn?.text()).toBe('u-7'); + expect(calls).toBe(2); + }); + + test('an app that declares no authenticator still boots — every caller is anonymous', async () => { + running = await startRoles({ + roles: selectRoles('web'), + port: 0, + buildId: 'test', + runtime: fakeRuntime(), + env: {}, + routes, + }); + + const response = await running.server?.fetch(new Request('http://dev.test/whoami')); + expect(response?.status).toBe(401); + }); +}); +/** + * The sync node evaluated no credential of its own AND no host handed it one, so every socket the + * framework ever opened carried `actorId: null` — the channel guard, the live-query gate, the + * presence entry and the per-tenant cap all decided against an anonymous actor. Realtime was + * single-tenant by wiring. + */ +describe('integration · the sync role is handed the app’s own authenticator', () => { + afterEach(resetAuthenticator); + + const startSyncOnly = async (): Promise => { + const lines: string[] = []; + const original = logger.warn; + logger.warn = (line: string) => lines.push(line); + try { + running = await startRoles({ + roles: ['sync'], + port: 0, + buildId: 'test', + runtime: fakeRuntime(), + routes: [], + env: {}, + }); + } finally { + logger.warn = original; + } + return lines; + }; + + test('no authenticator stays anonymous, loudly — the correct default for x dev', async () => { + resetAuthenticator(); + const lines = await startSyncOnly(); + expect(lines.some((line) => line.includes('no authenticator'))).toBe(true); + }); + + test('an app that configured one is used, and the node stops saying it is anonymous', async () => { + configureAuthenticator(() => userActor({ id: 'u1', roles: ['member'] })); + const lines = await startSyncOnly(); + expect(lines.some((line) => line.includes('no authenticator'))).toBe(false); + }); +}); + +describe('unit · a server that cannot resolve an identity says so', () => { + const guarded: Route = { + method: 'GET', + path: '/private', + meta: { name: 'private', auth: 'required' }, + handler: () => new Response('ok'), + }; + const open: Route = { + method: 'GET', + path: '/public', + meta: { name: 'public', auth: 'public' }, + handler: () => new Response('ok'), + }; + + // The exact production state the demo app shipped in: guarded routes, no authenticator, a clean + // boot, and a 401 on every valid session. Silence there is what let it survive to a deployment. + test('guarded routes with no authenticator warn, naming the call that fixes it', async () => { + resetAuthenticator(); + const lines: string[] = []; + const original = logger.warn; + logger.warn = (line: string) => lines.push(line); + try { + const running = await startRoles({ + roles: ['web'], + port: 0, + buildId: 'test', + runtime: fakeRuntime(), + routes: [open, guarded], + env: {}, + }); + await running.stop(); + } finally { + logger.warn = original; + } + const warned = lines.find((line) => line.includes('X_CONFIG_INVALID')); + expect(warned).toBeDefined(); + expect(warned).toContain("1 route(s) declare auth: 'required'"); + expect(warned).toContain('configureAuthenticator()'); + }); + + test('an app that configured one is silent', async () => { + resetAuthenticator(); + configureAuthenticator(() => null); + const lines: string[] = []; + const original = logger.warn; + logger.warn = (line: string) => lines.push(line); + try { + const running = await startRoles({ + roles: ['web'], + port: 0, + buildId: 'test', + runtime: fakeRuntime(), + routes: [guarded], + env: {}, + }); + await running.stop(); + } finally { + logger.warn = original; + resetAuthenticator(); + } + expect(lines.filter((line) => line.includes('X_CONFIG_INVALID'))).toEqual([]); + }); + + test('a route table with nothing guarded is silent', async () => { + resetAuthenticator(); + const lines: string[] = []; + const original = logger.warn; + logger.warn = (line: string) => lines.push(line); + try { + const running = await startRoles({ + roles: ['web'], + port: 0, + buildId: 'test', + runtime: fakeRuntime(), + routes: [open], + env: {}, + }); + await running.stop(); + } finally { + logger.warn = original; + } + expect(lines.filter((line) => line.includes('X_CONFIG_INVALID'))).toEqual([]); + }); +}); diff --git a/packages/cli/src/dev-roles.test.ts b/packages/cli/src/dev-roles.test.ts index 1305659be..67c6c33fe 100644 --- a/packages/cli/src/dev-roles.test.ts +++ b/packages/cli/src/dev-roles.test.ts @@ -1,65 +1,30 @@ // `--role` used to be parsed and thrown away. These tests pin both halves of the fix: the flag -// selects, and the selection actually starts (and stops) the framework objects that role runs. +// selects, and the selection actually starts (and STOPS) the framework objects that role runs. +// What a started role then does is elsewhere, one file per question: who is calling +// (`dev-roles-identity.test.ts`) and what its responses admit (`dev-roles-csp.test.ts`). import { afterAll, afterEach, describe, expect, test } from 'bun:test'; import { rm } from 'node:fs/promises'; -import { noopPurgeDriver } from '@ultimat3/cache'; -import { logger, METRICS_PATH, resetLifecycle, userActor } from '@ultimat3/core'; -import type { Route } from '@ultimat3/http'; -import { configureAuthenticator, cspHashSource, resetAuthenticator } from '@ultimat3/http'; -import { - createMemoryDriver, - createMemoryEventBus, - createMemoryOutboxStore, - resetJobs, - resetJobsFacade, - resetTasks, - task, -} from '@ultimat3/jobs'; -import { createMemoryDriver as createMemoryMailDriver } from '@ultimat3/mail'; -import { DEFAULT_PRESENCE_TTL_MS, InProcessTransport } from '@ultimat3/realtime'; -import { - clearRoutes, - clearStylesheets, - defineRoute, - loadStylesheet, - registerRoute, -} from '@ultimat3/render'; -import { defineStorage, localDriver } from '@ultimat3/storage'; -import { appRoutes } from './dev-render'; +import { METRICS_PATH } from '@ultimat3/core'; +import type { OutboxRecord, OutboxStore } from '@ultimat3/jobs'; +import { task } from '@ultimat3/jobs'; import type { RunningRoles } from './dev-roles'; import { DEV_ROLES, SELECTABLE_ROLES, selectRoles, startRoles } from './dev-roles'; -import type { RunningServices } from './dev-runtime'; -import { resolveServices } from './dev-services'; +import { fixtureRuntime, resetDevRolesState } from './dev-roles-fixture'; const ROOT = `${import.meta.dir}/../.roles-fixture`; -/** Every service a role touches, embedded but real — no PGlite boot for a role-wiring test. */ -function fakeRuntime(): RunningServices { - const services = resolveServices(ROOT, {}); - const transport = new InProcessTransport(); - return { - services, - db: { async ping() {}, async close() {} } as unknown as RunningServices['db'], - jobs: createMemoryDriver(), - // A real store, not a stub: the `worker` role starts the outbox relay against it, and a relay - // whose `claim()` rejects on the first 200ms tick is an unhandled rejection in whichever test - // happens to still be running. - outbox: createMemoryOutboxStore(), - events: createMemoryEventBus(), - transport, - transportDetail: 'in-process fanout', - // The sync role reads this to build its `PresenceRegistry`; the default is what a boot with no - // `NATS_URL` resolves to, so the fixture is the real number rather than a rounder one. - presenceTtlMs: DEFAULT_PRESENCE_TTL_MS, - storage: defineStorage({ disks: { local: localDriver({ root: `${ROOT}/storage` }) } }), - mail: createMemoryMailDriver(), - mailDetail: 'embedded', - purge: noopPurgeDriver(), - purgeDetail: 'none', - stop: async () => transport.close(), - }; -} +/** + * Hand the loop back until nothing is queued but the work this test is holding. A macrotask turn, + * not a duration: the teardown's other awaits are all already-settled promises, so one turn is + * everything it can do without the pass — and a sleep would be asserting how long that took. + */ +const scheduled = (): Promise => + new Promise((resolve) => { + setImmediate(resolve); + }); + +const fakeRuntime = (): ReturnType => fixtureRuntime(ROOT); /** The thrown value, so the matcher sees an error rather than a thunk. */ function refused(flag: string): unknown { @@ -76,14 +41,7 @@ let running: RunningRoles | undefined; afterEach(async () => { await running?.stop(); running = undefined; - resetJobs(); - resetJobsFacade(); - resetTasks(); - // Core's lifecycle is process-global and a stopped server leaves it drained, so without this - // the SECOND web role in this file answers every request `X_DRAINING` — a suite that only - // passes when its own tests are run one at a time. `@ultimat3/http`'s own server suite does the - // same thing for the same reason. - resetLifecycle(); + resetDevRolesState(); }); afterAll(async () => { @@ -153,6 +111,73 @@ describe('unit · x dev --role', () => { expect(await scrape.text()).toContain('# TYPE queue_depth gauge'); }); + /** + * `OutboxRelay.stop()` waits out the pass in flight — a publish and the `markPublished` behind + * it are one pass, and a teardown that returns between them closed the database under the row it + * was about to mark. That join is only as good as the `await`, and both teardown paths here + * called it in statement position, which is a promise the boot dropped on the floor. + */ + test('stopping the worker role joins the outbox pass instead of returning underneath it', async () => { + const events: string[] = []; + const gate = Promise.withResolvers(); + const claimed = Promise.withResolvers(); + let claims = 0; + const record: OutboxRecord = { + id: 'row-1', + job: 'staged-job', + queue: 'default', + input: {}, + idempotencyKey: 'staged-job:1', + maxAttempts: 1, + runAt: 0, + stagedAt: 0, + }; + const outbox: OutboxStore = { + async stage() {}, + async commit() { + return []; + }, + async rollback() {}, + async claim() { + claims += 1; + // One gated pass. A later tick must not re-enter it — `stop()` clears the interval first, + // so a second claim only ever happens if the pass this test holds was never joined. + if (claims > 1) return []; + claimed.resolve(); + await gate.promise; + return [record]; + }, + async markPublished() { + events.push('marked'); + }, + async pendingCount() { + return 0; + }, + }; + + const started = await startRoles({ + roles: selectRoles('worker'), + port: 0, + buildId: 'test', + runtime: { ...fakeRuntime(), outbox }, + env: {}, + routes: [], + }); + + // No sleep: the relay's own poll resolves this, and until it does there is no pass to join. + await claimed.promise; + const stopping = started.stop().then(() => { + events.push('stopped'); + }); + // Everything the teardown can reach without the pass has now run. Releasing the pass here is + // what makes the order an assertion about a dependency rather than about a duration. + await scheduled(); + gate.resolve(); + await stopping; + + expect(events).toEqual(['marked', 'stopped']); + }); + test('the web role serves the routes it was handed, and nothing else starts', async () => { running = await startRoles({ roles: selectRoles('web'), @@ -216,269 +241,3 @@ describe('unit · x dev --role', () => { blocker.stop(true); }); }); - -/** - * `startWeb` passed `devHooks()`, which returned `authorize` and nothing else — so - * `hooks.authenticate` had no caller anywhere in the framework and `auth: 'required'` was - * unsatisfiable under `x dev` AND under `apps/web/server.ts`, which boots through this same - * function. This is that wiring, driven end to end: the app declares the resolver, the web role - * picks it up, and the `auth` stage calls it. - */ -describe('integration · the web role resolves an actor from the request', () => { - afterEach(resetAuthenticator); - - const routes = [ - { - method: 'GET' as const, - path: '/whoami', - meta: { name: 'whoami', auth: 'required' as const }, - handler: (_request: unknown, ctx: { actor: { id: string } }) => new Response(ctx.actor.id), - }, - ]; - - test('a session cookie becomes the actor; no cookie is still a 401', async () => { - let calls = 0; - configureAuthenticator((request) => { - calls += 1; - const session = request.cookie('session'); - return session === null ? null : userActor({ id: session }); - }); - - running = await startRoles({ - roles: selectRoles('web'), - port: 0, - buildId: 'test', - runtime: fakeRuntime(), - env: {}, - routes, - }); - - const anonymous = await running.server?.fetch(new Request('http://dev.test/whoami')); - expect(anonymous?.status).toBe(401); - - const signedIn = await running.server?.fetch( - new Request('http://dev.test/whoami', { headers: { cookie: 'session=u-7' } }), - ); - expect(signedIn?.status).toBe(200); - expect(await signedIn?.text()).toBe('u-7'); - expect(calls).toBe(2); - }); - - test('an app that declares no authenticator still boots — every caller is anonymous', async () => { - running = await startRoles({ - roles: selectRoles('web'), - port: 0, - buildId: 'test', - runtime: fakeRuntime(), - env: {}, - routes, - }); - - const response = await running.server?.fetch(new Request('http://dev.test/whoami')); - expect(response?.status).toBe(401); - }); -}); - -/** - * The bug this pins: the web role sent `style-src 'self'` and every document it served carried its - * surface's CSS in an inline `', csp)).toEqual([]); - }); -}); - -/** - * The sync node evaluated no credential of its own AND no host handed it one, so every socket the - * framework ever opened carried `actorId: null` — the channel guard, the live-query gate, the - * presence entry and the per-tenant cap all decided against an anonymous actor. Realtime was - * single-tenant by wiring. - */ -describe('integration · the sync role is handed the app’s own authenticator', () => { - afterEach(resetAuthenticator); - - const startSyncOnly = async (): Promise => { - const lines: string[] = []; - const original = logger.warn; - logger.warn = (line: string) => lines.push(line); - try { - running = await startRoles({ - roles: ['sync'], - port: 0, - buildId: 'test', - runtime: fakeRuntime(), - routes: [], - env: {}, - }); - } finally { - logger.warn = original; - } - return lines; - }; - - test('no authenticator stays anonymous, loudly — the correct default for x dev', async () => { - resetAuthenticator(); - const lines = await startSyncOnly(); - expect(lines.some((line) => line.includes('no authenticator'))).toBe(true); - }); - - test('an app that configured one is used, and the node stops saying it is anonymous', async () => { - configureAuthenticator(() => userActor({ id: 'u1', roles: ['member'] })); - const lines = await startSyncOnly(); - expect(lines.some((line) => line.includes('no authenticator'))).toBe(false); - }); -}); - -describe('unit · a server that cannot resolve an identity says so', () => { - const guarded: Route = { - method: 'GET', - path: '/private', - meta: { name: 'private', auth: 'required' }, - handler: () => new Response('ok'), - }; - const open: Route = { - method: 'GET', - path: '/public', - meta: { name: 'public', auth: 'public' }, - handler: () => new Response('ok'), - }; - - // The exact production state the demo app shipped in: guarded routes, no authenticator, a clean - // boot, and a 401 on every valid session. Silence there is what let it survive to a deployment. - test('guarded routes with no authenticator warn, naming the call that fixes it', async () => { - resetAuthenticator(); - const lines: string[] = []; - const original = logger.warn; - logger.warn = (line: string) => lines.push(line); - try { - const running = await startRoles({ - roles: ['web'], - port: 0, - buildId: 'test', - runtime: fakeRuntime(), - routes: [open, guarded], - env: {}, - }); - await running.stop(); - } finally { - logger.warn = original; - } - const warned = lines.find((line) => line.includes('X_CONFIG_INVALID')); - expect(warned).toBeDefined(); - expect(warned).toContain("1 route(s) declare auth: 'required'"); - expect(warned).toContain('configureAuthenticator()'); - }); - - test('an app that configured one is silent', async () => { - resetAuthenticator(); - configureAuthenticator(() => null); - const lines: string[] = []; - const original = logger.warn; - logger.warn = (line: string) => lines.push(line); - try { - const running = await startRoles({ - roles: ['web'], - port: 0, - buildId: 'test', - runtime: fakeRuntime(), - routes: [guarded], - env: {}, - }); - await running.stop(); - } finally { - logger.warn = original; - resetAuthenticator(); - } - expect(lines.filter((line) => line.includes('X_CONFIG_INVALID'))).toEqual([]); - }); - - test('a route table with nothing guarded is silent', async () => { - resetAuthenticator(); - const lines: string[] = []; - const original = logger.warn; - logger.warn = (line: string) => lines.push(line); - try { - const running = await startRoles({ - roles: ['web'], - port: 0, - buildId: 'test', - runtime: fakeRuntime(), - routes: [open], - env: {}, - }); - await running.stop(); - } finally { - logger.warn = original; - } - expect(lines.filter((line) => line.includes('X_CONFIG_INVALID'))).toEqual([]); - }); -}); diff --git a/packages/cli/src/dev-roles.ts b/packages/cli/src/dev-roles.ts index c7f5a1878..d45c71521 100644 --- a/packages/cli/src/dev-roles.ts +++ b/packages/cli/src/dev-roles.ts @@ -301,11 +301,9 @@ export async function startRoles(options: StartRolesOptions): Promise { - relay.stop(); - }); - } + // Returned, not called-and-discarded: `stop()` waits out the pass in flight, and an unawaited + // one hands the failure rollback the same window a dropped `await` gives the teardown below. + if (relay !== null) started.push(() => relay.stop()); // `state` and `leader`, not the defaults. `createMemorySchedulerState` forgets every watermark // on restart, so a rolling deploy re-fires or skips whatever was due across it, and @@ -351,8 +349,11 @@ export async function startRoles(options: StartRolesOptions): Promise ({ kind: 'failed', error }); + +/** + * `work()` raced against `budgetMs` of REAL elapsed time. `budgetMs` is required and is a `number`: + * every drain has a budget, so "no budget" is not a case this has to answer for, and the signature + * is what stops it from becoming one. + * + * A synchronous throw and a rejection are one outcome (`failed`); the caller logs both the same + * way. Nothing here throws: a drain that rejects never reaches `process.exit(0)`. + */ +export function settleWithin( + work: () => void | Promise, + budgetMs: number, +): Promise { + let started: void | Promise; + try { + started = work(); + } catch (error) { + return Promise.resolve(failed(error)); + } + const pending = Promise.resolve(started); + return new Promise((resolve) => { + let decided = false; + const timer = setTimeout( + () => { + if (decided) return; + decided = true; + resolve(ABANDONED); + }, + Math.max(0, budgetMs), + ); + // A budget already spent still gives a synchronous hook its turn — a resolved promise settles + // on a microtask and this timer on a macrotask — so closing a pool costs nothing it does not + // already have. It must also never be the thing keeping a drained process alive. + timer.unref?.(); + // Attached unconditionally, on both settle paths: an abandoned hook that rejects later has + // nobody left awaiting it, and an unhandled rejection would kill the process this drain is + // trying to end cleanly. After the decision the outcome is dropped on purpose — the overrun + // was already reported, and a second line about a hook nobody is waiting for is noise. + pending.then( + () => { + if (decided) return; + decided = true; + clearTimeout(timer); + resolve(SETTLED); + }, + (error: unknown) => { + if (decided) return; + decided = true; + clearTimeout(timer); + resolve(failed(error)); + }, + ); + }); +} diff --git a/packages/core/src/lifecycle.test.ts b/packages/core/src/lifecycle.test.ts index fff1ed447..a195b4342 100644 --- a/packages/core/src/lifecycle.test.ts +++ b/packages/core/src/lifecycle.test.ts @@ -1,8 +1,10 @@ import { afterEach, beforeEach, describe, expect, test } from 'bun:test'; +import { frozenClock, systemClock } from './clock'; import { beginWork, configureLifecycle, drain, + drainDeadlineMs, healthzPayload, idleWaiterCount, inflightCount, @@ -28,6 +30,18 @@ afterEach(() => { resetLifecycle(); }); +/** + * A promise a test resolves by hand. Races here are driven by these and never by a sleep: a + * shutdown-deadline assertion ordered on wall-clock time is exactly the shard that flakes. + */ +function deferred(): { readonly promise: Promise; readonly resolve: () => void } { + let resolve!: () => void; + const promise = new Promise((settle) => { + resolve = settle; + }); + return { promise, resolve }; +} + describe('lifecycle', () => { test('health state machine: starting -> ready -> draining -> stopped', async () => { expect(lifecycleState()).toBe('starting'); @@ -189,6 +203,157 @@ describe('lifecycle', () => { }); }); +describe('the drain deadline', () => { + test('a declared deadline bounds a slow hook: the drain abandons it and names it', async () => { + const lines: string[] = []; + const stuck = deferred(); + configureLifecycle({ + deadlineMs: 10, + logger: createLogger({ level: 'info', writer: (line) => lines.push(line) }), + }); + markReady(); + expect(drainDeadlineMs()).toBe(10); + + // A `worker` pod's real shape: `jobs`' hook awaits every in-flight job and then `driver.close()`. + // Nothing in it reads `reason.deadlineAt`, so before this the 10ms budget bounded nothing at + // all — `drain()` sat here until the kubelet SIGKILLed the process mid-job. + onShutdown('slow-accept', () => stuck.promise, { phase: 'accept' }); + let closed = 0; + onShutdown('close-db', () => { + closed += 1; + }); + + await drain('SIGTERM'); + + expect(lifecycleState()).toBe('stopped'); + // The code alone is not an instruction: an operator has to know WHICH hook to shorten. + const timeout = lines.find((line) => line.includes('X_SHUTDOWN_TIMEOUT')); + expect(timeout).toContain('slow-accept'); + expect(timeout).toContain('accept'); + // Abandoned, not merely logged — the phases after it still ran, which is the whole point of + // resolving: `installSignalHandlers` reaches `process.exit(0)` instead of being killed. + expect(closed).toBe(1); + + stuck.resolve(); + }); + + test('a hook abandoned at the deadline cannot crash the process when it later rejects', async () => { + const lines: string[] = []; + const stuck = deferred(); + configureLifecycle({ + deadlineMs: 10, + logger: createLogger({ level: 'info', writer: (line) => lines.push(line) }), + }); + let rejectLate!: (error: unknown) => void; + const late = new Promise((_resolve, reject) => { + rejectLate = reject; + }); + onShutdown('slow-accept', () => late, { phase: 'accept' }); + + await drain('SIGTERM'); + // The drain has moved on and nobody awaits this promise anymore. Unhandled, it would take + // down the process the drain exists to end cleanly. + rejectLate(new Error('closed after abandonment')); + stuck.resolve(); + await stuck.promise; + + expect(lifecycleState()).toBe('stopped'); + }); + + test('the budget bounds the WHOLE drain — a hook that spends it leaves none for the ones behind', async () => { + const lines: string[] = []; + const stuck = deferred(); + configureLifecycle({ + deadlineMs: 30, + logger: createLogger({ level: 'info', writer: (line) => lines.push(line) }), + }); + + onShutdown('spends-it', () => stuck.promise, { phase: 'accept' }); + // Deterministic, and not a stopwatch: both waits are timers in one queue, so they settle in + // due-time order however slow the machine is. Whole-drain, this hook's budget is already 0 and + // its own 15ms timer cannot beat it; per-hook, it would get a fresh 30ms and finish. + let finished = false; + onShutdown( + 'after-it', + () => + new Promise((resolve) => { + setTimeout(() => { + finished = true; + resolve(); + }, 15); + }), + { phase: 'close' }, + ); + + await drain('SIGTERM'); + + const overran = lines.filter((line) => line.includes('X_SHUTDOWN_TIMEOUT')); + expect(overran).toHaveLength(2); + expect(overran[1]).toContain('after-it'); + expect(finished).toBe(false); + + stuck.resolve(); + }); + + // The default is ENFORCED, not absent: `jobs`, `realtime` and `cli` declare no budget, and a + // deadline that bounded only the packages that happened to ask would be a mechanism claiming + // more than it enforces — the worker pod the finding proved would still be SIGKILLed. + test('an unset deadline is the DEFAULT budget, enforced — not the absence of one', async () => { + const order: string[] = []; + const entered = deferred(); + const release = deferred(); + configureLifecycle({ + logger: createLogger({ level: 'info', writer: () => undefined }), + }); + markReady(); + // 25s, the literal, because no stopwatch in a test can tell 25s from unbounded — so the value + // is pinned where it is decided, and `remainingBudget` has no second place to disagree from. + expect(drainDeadlineMs()).toBe(25_000); + onShutdown( + 'slow-accept', + async () => { + entered.resolve(); + await release.promise; + order.push('hook'); + }, + { phase: 'accept' }, + ); + + const drained = drain('SIGTERM').then(() => { + order.push('drained'); + }); + await entered.promise; + // Not an ordering assertion: a hook well inside the budget must be awaited to completion, so + // waiting longer only strengthens this. 30ms against a 25s budget is what makes a default that + // shrank — to 0, to a per-phase slice, to whatever a refactor thought "no budget" meant — show + // up here as an abandoned hook rather than as a green test. + await Bun.sleep(30); + expect(order).toEqual([]); + + release.resolve(); + await drained; + expect(order).toEqual(['hook', 'drained']); + }); + + test('the budget is REAL elapsed time — a frozen clock cannot extend a grace period', async () => { + const clock = frozenClock(0); + configureLifecycle({ deadlineMs: 5_000, clock }); + clock.advance(1_000_000); + let seen: number | undefined; + onShutdown('probe', (reason) => { + seen = reason.deadlineAt; + }); + + await drain('SIGTERM'); + + // `waitForIdle` sleeps on a real `setTimeout` while the budget was read off the injected + // clock, so the two disagreed: here the old arithmetic answered 1,005,000 — a 16-minute + // budget, on a clock a test controls, for a deadline the kubelet enforces in real seconds. + expect(seen).toBeLessThan(1_000_000); + expect(seen).toBeGreaterThan(systemClock.monotonic()); + }); +}); + describe('readiness checks', () => { test('a bound-but-unusable process is NOT ready — the rolling-deploy 500s', () => { let poolOpen = false; diff --git a/packages/core/src/lifecycle.ts b/packages/core/src/lifecycle.ts index 62bac839e..64d69e935 100644 --- a/packages/core/src/lifecycle.ts +++ b/packages/core/src/lifecycle.ts @@ -4,6 +4,7 @@ import { type Clock, systemClock } from './clock'; import { UltimateError } from './errors'; +import { settleWithin } from './lifecycle-deadline'; import { type Logger, logger as rootLogger } from './logger'; export type HealthState = 'starting' | 'ready' | 'draining' | 'stopped'; @@ -18,7 +19,13 @@ export type ProcessSignal = 'SIGTERM' | 'SIGINT' | 'SIGHUP' | 'SIGQUIT'; export interface ShutdownReason { readonly signal: string; - /** Monotonic ms after which hooks are abandoned. */ + /** + * Real monotonic ms (`systemClock`) after which hooks are abandoned — deliberately NOT the + * injected clock. The budget this bounds is `terminationGracePeriodSeconds`, counted by the + * kubelet in real seconds, so a frozen clock must be unable to extend it: read off `clock` a + * test that advanced an hour of fake time handed the drain a 16-minute grace period, while + * `waitForIdle` went on sleeping on a real `setTimeout`. `clock` still owns `uptimeMs`. + */ readonly deadlineAt: number; } @@ -29,6 +36,19 @@ export interface OnShutdownOptions { } export interface LifecycleOptions { + /** + * The whole drain's budget — the in-flight wait AND every hook, in every phase. 25s by default, + * and **enforced whether or not an app sets it**: `ShutdownReason.deadlineAt` was always computed + * and handed to every hook, so the deadline was declared by the design and only the enforcement + * was missing. No hook reads `deadlineAt`, which is why it has to be imposed here. + * + * The lever is a LARGER value, not the absence of one: a `worker` holding a 10-minute job wants + * `configureLifecycle({ deadlineMs: 600_000 })` and a `terminationGracePeriodSeconds` at least as + * large. Left at 25s it is abandoned and the process exits clean — the row's visibility lease + * lapses and another worker re-claims it, which is what at-least-once already promises. The + * alternative is not "the job finishes": it is the same duplicate, delivered by SIGKILL at the + * kubelet's grace period, with no log line naming what overran. + */ readonly deadlineMs?: number | undefined; readonly clock?: Clock | undefined; readonly logger?: Logger | undefined; @@ -222,15 +242,51 @@ function waitForIdle(timeoutMs: number): Promise { }); } +/** + * The budget every drain is bounded by — `DEFAULT_DEADLINE_MS` until an app raises it. There is no + * unbounded state: `ShutdownReason.deadlineAt` was always computed and handed to every hook, so the + * deadline was declared by the design all along and only the enforcement was missing. + * + * The ONE place the budget is decided, and exported so a test can pin it: 25s is far above any + * drain a test can wait out, so the default needs a probe and not only a stopwatch. + */ +export function drainDeadlineMs(): number { + return deadlineMs; +} + +/** + * What is left of that budget. Read per hook, not per phase: the deadline bounds the WHOLE drain, + * so a hook that spent it leaves nothing for the ones behind it — which is what + * `terminationGracePeriodSeconds` means, and what makes the SUM of the phases bounded rather than + * each one of them separately. Returns `number`, never `number | undefined`: "no budget" is not a + * state this file has, and the type is what keeps it from becoming one again. + */ +function remainingBudget(reason: ShutdownReason): number { + return Math.max(0, reason.deadlineAt - systemClock.monotonic()); +} + async function runPhase(phase: ShutdownPhase, reason: ShutdownReason): Promise { for (const registration of registrations.filter((entry) => entry.phase === phase)) { - try { - await registration.hook(reason); - } catch (thrown) { + const outcome = await settleWithin(() => registration.hook(reason), remainingBudget(reason)); + if (outcome.kind === 'failed') { log.error('shutdown hook failed', { hook: registration.name, phase, - error: thrown, + error: outcome.error, + }); + continue; + } + if (outcome.kind === 'abandoned') { + // Abandoned, not merely logged. A deadline that waited anyway would leave the kubelet to + // SIGKILL this process — the every-deploy duplicate that draining exists to prevent — so + // the drain moves on and the hook is left running with nobody reading it. The cost of that + // choice is real and named in the cause: a write it had in flight may be half done. + log.warn('X_SHUTDOWN_TIMEOUT', { + code: 'X_SHUTDOWN_TIMEOUT', + cause: `the "${registration.name}" shutdown hook (phase: ${phase}) was still running at the ${deadlineMs}ms drain deadline and has been ABANDONED — the process exits without it, so anything it had in flight may be incomplete`, + fix: `raise the budget past the work this hook does — configureLifecycle({ deadlineMs: 600_000 }) for a 10-minute job — and set terminationGracePeriodSeconds to at least as many seconds, or make the "${registration.name}" hook return once it has stopped accepting work rather than once it has finished`, + hook: registration.name, + phase, }); } } @@ -240,19 +296,21 @@ async function runPhase(phase: ShutdownPhase, reason: ShutdownReason): Promise { if (drainPromise !== undefined) return drainPromise; state = 'draining'; - const reason: ShutdownReason = { signal, deadlineAt: clock.monotonic() + deadlineMs }; + const reason: ShutdownReason = { signal, deadlineAt: systemClock.monotonic() + deadlineMs }; drainPromise = (async () => { log.info('draining', { signal, deadlineMs, inflight }); await runPhase('accept', reason); - const remaining = Math.max(0, reason.deadlineAt - clock.monotonic()); + // Real monotonic, like `deadlineAt` itself: `waitForIdle` sleeps on a real `setTimeout`, and a + // budget read off an injected clock is a number that timer will never honour. + const remaining = Math.max(0, reason.deadlineAt - systemClock.monotonic()); const idle = await waitForIdle(remaining); if (!idle) { log.warn('X_SHUTDOWN_TIMEOUT', { code: 'X_SHUTDOWN_TIMEOUT', cause: `${inflight} in-flight operations still running after ${deadlineMs}ms`, - fix: 'raise configureLifecycle({ deadlineMs }) or shorten the slow handler', + fix: 'raise the budget past the slowest handler — configureLifecycle({ deadlineMs: 600_000 }) for a 10-minute one — and set terminationGracePeriodSeconds to at least as many seconds, or shorten the handler', }); } diff --git a/packages/db/CLAUDE.md b/packages/db/CLAUDE.md index 0c89b03b3..9e86bd236 100644 --- a/packages/db/CLAUDE.md +++ b/packages/db/CLAUDE.md @@ -29,16 +29,31 @@ itself. Keep both sides `function` declarations so hoisting covers the TDZ. `pglite.ts` is a pool of exactly one: PGlite is a single session, so `reserve()` (backed by `pglite-turns.ts`) is what stops two concurrent `BEGIN`s becoming one transaction. Three rules -hold it together and none is optional — the plain path takes a turn; a statement issued while -`currentTx()` is set skips the queue because it is already inside the transaction holding it; and -a reservation runs direct **only while its turn is held**, re-queueing through `turns.run` once -`release()` has been called. Drop the first and a rollback is silently lost; drop the second and -`enqueue(input, { outbox: false })` inside `withTransaction` hangs forever; drop the third and a -`tx` handle leaked past its scope writes into whichever transaction holds the connection next. The -first two are pinned by real-database tests in `pglite-embedded.test.ts` and a fake driver cannot -catch either; the third is a fake-driver test in `pglite.test.ts`, because it is about ordering, -not SQL. That is the split between the two files: `pglite.test.ts` pins the adapter against fakes, -`pglite-embedded.test.ts` boots the WASM module once and pins the binding. +hold it together and none is optional — the plain path takes a turn; a statement issued while a +transaction is **live** (`inLiveTx()`) skips the queue because it is already inside the transaction +holding it; and a reservation runs direct **only while its turn is held**, re-queueing through +`turns.run` once `release()` has been called. Drop the first and a rollback is silently lost; drop +the second and `enqueue(input, { outbox: false })` inside `withTransaction` hangs forever; drop the +third and a `tx` handle leaked past its scope writes into whichever transaction holds the connection +next. The first two are pinned by real-database tests in `pglite-embedded.test.ts` and a fake driver +cannot catch either; the third is a fake-driver test in `pglite.test.ts`, because it is about +ordering, not SQL. That is the split between the two files: `pglite.test.ts` pins the adapter +against fakes, `pglite-embedded.test.ts` boots the WASM module once and pins the binding. +`pglite-observer.test.ts` is the third, split off the first purely for the line ceiling, along the +seam `observe.ts` already draws. + +**The second rule fences on `inLiveTx()`, never on `currentTx() !== undefined`** — the two are +different questions and reading the second as the first was a cross-transaction write. The +`AsyncLocalStorage` store rides into every promise chain started inside `withTransaction`, so a +statement the app forgot to `await` still found a store after COMMIT, skipped the turn queue, and +landed inside whichever unit of work held the single session next: measured `BEGIN`, `select 'inside +tx'`, `COMMIT`, `BEGIN`, `select 'straggler'`, `select 'inside tx 2'`, `COMMIT` — committed by a +transaction that never issued it, with nothing anywhere to read. `runRoot` now marks `TxState.live` +false on every exit and `inLiveTx()` (`transaction.ts`) is the one reader. A closed scope falls +through to `turns.run` **quietly**, exactly as `client.ts`'s released pin sends a late statement back +to the pool — one answer to one question, on both drivers. `currentTx()` deliberately still answers +with the dead handle: its statements go through the reservation, whose own `held` fence already +re-queues them, and it is a pinned public seam three packages are written against. `Turn` (`pglite-turns.ts`) is `Disposable`, same shape as `DbConnection`: `release()` and `[Symbol.dispose]` are the same call, idempotent for free because it is a settled promise's diff --git a/packages/db/src/fake-pglite.ts b/packages/db/src/fake-pglite.ts new file mode 100644 index 000000000..b4329efbd --- /dev/null +++ b/packages/db/src/fake-pglite.ts @@ -0,0 +1,32 @@ +// Single responsibility: the PGlite driver fake the adapter tests record statements against. +// Shared rather than copied for the same reason `fake-reservable.ts` is: the assertion in every +// one of these tests is the recorded ORDER, and two copies of the recorder drift into two orders. + +import type { PgliteDriver, PgliteResult } from './pglite'; + +/** One statement as the driver received it — the text after binding, and the bound values. */ +export interface Recorded { + readonly text: string; + readonly values: readonly unknown[]; +} + +export type RecordingPgliteDriver = PgliteDriver & { + readonly calls: Recorded[]; + closed: number; +}; + +/** A driver that answers every statement with `result` and remembers the order it saw them in. */ +export function fakeDriver(result: PgliteResult): RecordingPgliteDriver { + const calls: Recorded[] = []; + return { + calls, + closed: 0, + async query(text, values) { + calls.push({ text, values: values ?? [] }); + return result; + }, + async close() { + this.closed += 1; + }, + }; +} diff --git a/packages/db/src/pglite-observer.test.ts b/packages/db/src/pglite-observer.test.ts new file mode 100644 index 000000000..1af76051f --- /dev/null +++ b/packages/db/src/pglite-observer.test.ts @@ -0,0 +1,181 @@ +// Split out of `pglite.test.ts` to stay under the file-size ceiling, along the seam the source +// already has: `pglite.test.ts` pins the adapter's ordering against fakes, and this file pins the +// one funnel every statement passes through — `observe.ts`'s seam, the attribution and the +// expected-loop reason stamped on the event. + +import { afterEach, describe, expect, test } from 'bun:test'; +import { withStatementAttribution } from './attribution'; +import { setDbClient } from './client'; +import { expectedQueryLoop } from './expected-loop'; +import { fakeDriver } from './fake-pglite'; +import type { StatementEvent, StatementObserver } from './observe'; +import { setStatementObserver } from './observe'; +import { createPgliteClient } from './pglite'; +import { sql } from './sql'; +import { withTransaction } from './transaction'; + +const failure = async (run: () => Promise): Promise<{ code: string; fix: string }> => { + try { + await run(); + } catch (error) { + return error as { code: string; fix: string }; + } + throw new Error('expected the call to reject'); +}; + +function recorder(): StatementObserver & { readonly seen: StatementEvent[] } { + const seen: StatementEvent[] = []; + return { + seen, + onStatement(event: StatementEvent): void { + seen.push(event); + }, + }; +} + +describe('the statement observer', () => { + afterEach(() => { + // Both are process-wide: leaving either installed makes every later test observe this one's. + setStatementObserver(undefined); + setDbClient(undefined); + }); + + // `statement()` is the funnel: the queued path, the pinned path and the in-transaction path that + // skips the queue all land on it. A detector fed by only one of the three would be blind to + // exactly the reads that happen inside a transaction. + test('sees every statement once, whichever of the three paths it took', async () => { + const driver = fakeDriver({ rows: [{ id: 1 }, { id: 2 }], affectedRows: 0 }); + const client = createPgliteClient({ driver }); + setDbClient(client); + const observer = recorder(); + setStatementObserver(observer); + + await client.query(sql`select id from posts where org = ${'o_1'}`); + await withTransaction(async (tx) => { + await tx.execute(sql`insert into posts values (${1})`); + // Through the ambient client, so it reaches `run()` with a transaction open and skips the + // queue rather than waiting for a turn the transaction is already holding. + await client.query(sql`select id from posts`); + }); + + expect(observer.seen.map((event) => event.text)).toEqual([ + 'select id from posts where org = $1', + 'BEGIN', + 'insert into posts values ($1)', + 'select id from posts', + 'COMMIT', + ]); + expect(observer.seen[0]?.values).toEqual(['o_1']); + expect(observer.seen[0]?.rows).toBe(2); + expect(observer.seen[0]?.durationMs).toBeGreaterThanOrEqual(0); + expect(observer.seen[0]).not.toHaveProperty('error'); + }); + + // The same count `execute()` answers with, from the same helper — a report saying 0 rows for + // every write while `execute` said 3 would make the two disagree about the same statement. + test('counts rows the way execute does: the command tag for a write', async () => { + const client = createPgliteClient({ driver: fakeDriver({ rows: [], affectedRows: 3 }) }); + const observer = recorder(); + setStatementObserver(observer); + + expect(await client.execute(sql`delete from posts`)).toBe(3); + expect(observer.seen[0]?.rows).toBe(3); + }); + + test('reports a failed statement with the error the caller is about to be thrown', async () => { + const client = createPgliteClient({ + driver: { + query: () => Promise.reject(new Error('syntax error')), + close: async () => undefined, + }, + }); + const observer = recorder(); + setStatementObserver(observer); + + const error = await failure(() => client.query(sql`selct 1`)); + + expect(error.code).toBe('X_DB_UNAVAILABLE'); + // Identity, not shape: the event carries the very error thrown, already wrapped by the funnel. + expect(observer.seen[0]?.error).toBe(error); + expect(observer.seen[0]?.rows).toBe(0); + }); + + // Strict test mode is an observer that throws, and the throw must arrive as itself. Notifying + // inside the statement's own `try` would report a statement that succeeded as X_DB_UNAVAILABLE. + test('a throwing observer reaches the caller as its own error, not a database failure', async () => { + const client = createPgliteClient({ driver: fakeDriver({ rows: [] }) }); + setStatementObserver({ + onStatement(): void { + throw new Error('n+1 in a strict test'); + }, + }); + + await expect(client.query(sql`select 1`)).rejects.toThrow('n+1 in a strict test'); + }); + + test('booting, reserving and closing are not statements', async () => { + const driver = fakeDriver({ rows: [] }); + const client = createPgliteClient({ driver }); + const observer = recorder(); + setStatementObserver(observer); + + await client.ping(); + (await client.reserve()).release(); + await client.close(); + + expect(observer.seen).toEqual([]); + }); + + test('an uninstalled seam observes nothing, which is the production path', async () => { + const observer = recorder(); + setStatementObserver(observer); + setStatementObserver(undefined); + + await createPgliteClient({ driver: fakeDriver({ rows: [] }) }).query(sql`select 1`); + + expect(observer.seen).toEqual([]); + }); + + test('carries the attribution declared by the scope, undefined outside every scope', async () => { + const client = createPgliteClient({ driver: fakeDriver({ rows: [] }) }); + const observer = recorder(); + setStatementObserver(observer); + + await withStatementAttribution('members', 'findById', () => client.query(sql`select 1`)); + await client.query(sql`select 2`); + + expect(observer.seen.map((event) => event.attribution)).toEqual([ + { entity: 'members', op: 'findById' }, + undefined, + ]); + }); + + test('the failing statement path still carries the attribution', async () => { + const client = createPgliteClient({ + driver: { query: () => Promise.reject(new Error('boom')), close: async () => undefined }, + }); + const observer = recorder(); + setStatementObserver(observer); + + await failure(() => + withStatementAttribution('members', 'findById', () => client.query(sql`selct 1`)), + ); + + expect(observer.seen[0]?.attribution).toEqual({ entity: 'members', op: 'findById' }); + expect(observer.seen[0]?.rows).toBe(0); + }); + + // Two independent scopes: an expected-loop reason does not crowd out the attribution. + test('attribution and an expected-loop reason are stamped together, independently', async () => { + const client = createPgliteClient({ driver: fakeDriver({ rows: [] }) }); + const observer = recorder(); + setStatementObserver(observer); + + await withStatementAttribution('members', 'findMany', () => + expectedQueryLoop('one lookup per id', () => client.query(sql`select 1`)), + ); + + expect(observer.seen[0]?.attribution).toEqual({ entity: 'members', op: 'findMany' }); + expect(observer.seen[0]?.expected).toBe('one lookup per id'); + }); +}); diff --git a/packages/db/src/pglite.test.ts b/packages/db/src/pglite.test.ts index 52721ff49..ac83e68fb 100644 --- a/packages/db/src/pglite.test.ts +++ b/packages/db/src/pglite.test.ts @@ -1,44 +1,17 @@ -import { afterEach, describe, expect, test } from 'bun:test'; -import { withStatementAttribution } from './attribution'; -import { isReservable, setDbClient } from './client'; -import { expectedQueryLoop } from './expected-loop'; -import type { StatementEvent, StatementObserver } from './observe'; -import { setStatementObserver } from './observe'; +import { describe, expect, test } from 'bun:test'; +import { isReservable } from './client'; +import { fakeDriver } from './fake-pglite'; import { createPgliteClient, loadPgliteDriver, PGLITE_FIX, PGLITE_MEMORY, - type PgliteDriver, type PgliteResult, pgliteDataDir, } from './pglite'; import { sql } from './sql'; import { withTransaction } from './transaction'; -interface Recorded { - readonly text: string; - readonly values: readonly unknown[]; -} - -function fakeDriver(result: PgliteResult): PgliteDriver & { - readonly calls: Recorded[]; - closed: number; -} { - const calls: Recorded[] = []; - return { - calls, - closed: 0, - async query(text, values) { - calls.push({ text, values: values ?? [] }); - return result; - }, - async close() { - this.closed += 1; - }, - }; -} - /** A stand-in for the `@electric-sql/pglite` namespace: same one export, no WASM. */ const fakeModule = ( onConstruct: (dataDir: string | undefined) => void, @@ -55,6 +28,15 @@ const fakeModule = ( }, }); +/** A promise the test resolves by hand, so a race is driven by an event and not by the clock. */ +function deferred(): { readonly promise: Promise; readonly resolve: () => void } { + let resolve!: () => void; + const promise = new Promise((settle) => { + resolve = settle; + }); + return { promise, resolve }; +} + const failure = async (run: () => Promise): Promise<{ code: string; fix: string }> => { try { await run(); @@ -319,180 +301,95 @@ describe('createPgliteClient', () => { await expect(client.execute(sql`insert into t values (1)`)).resolves.toBeDefined(); }); - test('releasing after disposal is a no-op, not a second turn', async () => { + // The transaction's ALS store survives into any promise chain started inside its body, so a + // statement the app forgot to `await` still read a live-looking store minutes after COMMIT — and + // `run()` fenced on the store's PRESENCE, so it skipped the turn queue and landed inside whoever + // held the single session next. Measured order before the fix: begin, inside tx, commit, begin, + // straggler, inside tx 2, commit — a statement from a finished transaction committed by another. + test('a straggler from a finished transaction waits its turn instead of joining the next one', async () => { const driver = fakeDriver({ rows: [] }); const client = createPgliteClient({ driver }); - const reserved = await client.reserve(); - - reserved[Symbol.dispose](); - reserved.release(); + const gate = deferred(); + let straggler!: Promise; + + await withTransaction( + async () => { + await client.query(sql`select 'inside tx'`); + // The forgotten `await`: a chain started inside the body that outlives the scope. `.then` + // inherits the store from here, which is exactly what made the dead transaction look live. + straggler = gate.promise.then(() => client.query(sql`select 'straggler'`)); + }, + { client }, + ); - // A second turn handed out would let this statement start while the holder below still owns - // the connection; taking a fresh reservation proves the queue has exactly one turn in it. + // Somebody else's unit of work takes the one session. const holder = await client.reserve(); - const queued = client.execute(sql`insert into t values (1)`); + await holder.execute(sql`begin`); + gate.resolve(); + // Not an ordering assertion: the straggler must never run here, so waiting longer only + // strengthens it — the same shape as the released-reservation test above. await Bun.sleep(5); - expect(driver.calls).toEqual([]); + expect(driver.calls.map((call) => call.text)).toEqual([ + 'BEGIN', + "select 'inside tx'", + 'COMMIT', + 'begin', + ]); + await holder.execute(sql`select 'inside tx 2'`); + await holder.execute(sql`commit`); holder.release(); - await queued; - expect(driver.calls.map((call) => call.text)).toEqual(['insert into t values (1)']); - }); -}); - -function recorder(): StatementObserver & { readonly seen: StatementEvent[] } { - const seen: StatementEvent[] = []; - return { - seen, - onStatement(event: StatementEvent): void { - seen.push(event); - }, - }; -} + await straggler; -describe('the statement observer', () => { - afterEach(() => { - // Both are process-wide: leaving either installed makes every later test observe this one's. - setStatementObserver(undefined); - setDbClient(undefined); - }); - - // `statement()` is the funnel: the queued path, the pinned path and the in-transaction path that - // skips the queue all land on it. A detector fed by only one of the three would be blind to - // exactly the reads that happen inside a transaction. - test('sees every statement once, whichever of the three paths it took', async () => { - const driver = fakeDriver({ rows: [{ id: 1 }, { id: 2 }], affectedRows: 0 }); - const client = createPgliteClient({ driver }); - setDbClient(client); - const observer = recorder(); - setStatementObserver(observer); - - await client.query(sql`select id from posts where org = ${'o_1'}`); - await withTransaction(async (tx) => { - await tx.execute(sql`insert into posts values (${1})`); - // Through the ambient client, so it reaches `run()` with a transaction open and skips the - // queue rather than waiting for a turn the transaction is already holding. - await client.query(sql`select id from posts`); - }); - - expect(observer.seen.map((event) => event.text)).toEqual([ - 'select id from posts where org = $1', + expect(driver.calls.map((call) => call.text)).toEqual([ 'BEGIN', - 'insert into posts values ($1)', - 'select id from posts', + "select 'inside tx'", 'COMMIT', + 'begin', + "select 'inside tx 2'", + 'commit', + "select 'straggler'", ]); - expect(observer.seen[0]?.values).toEqual(['o_1']); - expect(observer.seen[0]?.rows).toBe(2); - expect(observer.seen[0]?.durationMs).toBeGreaterThanOrEqual(0); - expect(observer.seen[0]).not.toHaveProperty('error'); - }); - - // The same count `execute()` answers with, from the same helper — a report saying 0 rows for - // every write while `execute` said 3 would make the two disagree about the same statement. - test('counts rows the way execute does: the command tag for a write', async () => { - const client = createPgliteClient({ driver: fakeDriver({ rows: [], affectedRows: 3 }) }); - const observer = recorder(); - setStatementObserver(observer); - - expect(await client.execute(sql`delete from posts`)).toBe(3); - expect(observer.seen[0]?.rows).toBe(3); }); - test('reports a failed statement with the error the caller is about to be thrown', async () => { - const client = createPgliteClient({ - driver: { - query: () => Promise.reject(new Error('syntax error')), - close: async () => undefined, - }, - }); - const observer = recorder(); - setStatementObserver(observer); - - const error = await failure(() => client.query(sql`selct 1`)); - - expect(error.code).toBe('X_DB_UNAVAILABLE'); - // Identity, not shape: the event carries the very error thrown, already wrapped by the funnel. - expect(observer.seen[0]?.error).toBe(error); - expect(observer.seen[0]?.rows).toBe(0); - }); - - // Strict test mode is an observer that throws, and the throw must arrive as itself. Notifying - // inside the statement's own `try` would report a statement that succeeded as X_DB_UNAVAILABLE. - test('a throwing observer reaches the caller as its own error, not a database failure', async () => { - const client = createPgliteClient({ driver: fakeDriver({ rows: [] }) }); - setStatementObserver({ - onStatement(): void { - throw new Error('n+1 in a strict test'); - }, - }); - - await expect(client.query(sql`select 1`)).rejects.toThrow('n+1 in a strict test'); - }); - - test('booting, reserving and closing are not statements', async () => { + // A statement issued while the transaction is genuinely OPEN must still skip the queue: the + // transaction is holding the turn, so waiting for one would hang forever. This is the shape + // `handle.enqueue(input, { outbox: false })` inside `withTransaction` takes. + test('a statement inside a LIVE transaction still runs on the turn that transaction holds', async () => { const driver = fakeDriver({ rows: [] }); const client = createPgliteClient({ driver }); - const observer = recorder(); - setStatementObserver(observer); - - await client.ping(); - (await client.reserve()).release(); - await client.close(); - - expect(observer.seen).toEqual([]); - }); - - test('an uninstalled seam observes nothing, which is the production path', async () => { - const observer = recorder(); - setStatementObserver(observer); - setStatementObserver(undefined); - - await createPgliteClient({ driver: fakeDriver({ rows: [] }) }).query(sql`select 1`); - expect(observer.seen).toEqual([]); - }); - - test('carries the attribution declared by the scope, undefined outside every scope', async () => { - const client = createPgliteClient({ driver: fakeDriver({ rows: [] }) }); - const observer = recorder(); - setStatementObserver(observer); - - await withStatementAttribution('members', 'findById', () => client.query(sql`select 1`)); - await client.query(sql`select 2`); + await withTransaction( + async () => { + await client.execute(sql`insert into outbox values (1)`); + }, + { client }, + ); - expect(observer.seen.map((event) => event.attribution)).toEqual([ - { entity: 'members', op: 'findById' }, - undefined, + expect(driver.calls.map((call) => call.text)).toEqual([ + 'BEGIN', + 'insert into outbox values (1)', + 'COMMIT', ]); }); - test('the failing statement path still carries the attribution', async () => { - const client = createPgliteClient({ - driver: { query: () => Promise.reject(new Error('boom')), close: async () => undefined }, - }); - const observer = recorder(); - setStatementObserver(observer); - - await failure(() => - withStatementAttribution('members', 'findById', () => client.query(sql`selct 1`)), - ); - - expect(observer.seen[0]?.attribution).toEqual({ entity: 'members', op: 'findById' }); - expect(observer.seen[0]?.rows).toBe(0); - }); + test('releasing after disposal is a no-op, not a second turn', async () => { + const driver = fakeDriver({ rows: [] }); + const client = createPgliteClient({ driver }); + const reserved = await client.reserve(); - // Two independent scopes: an expected-loop reason does not crowd out the attribution. - test('attribution and an expected-loop reason are stamped together, independently', async () => { - const client = createPgliteClient({ driver: fakeDriver({ rows: [] }) }); - const observer = recorder(); - setStatementObserver(observer); + reserved[Symbol.dispose](); + reserved.release(); - await withStatementAttribution('members', 'findMany', () => - expectedQueryLoop('one lookup per id', () => client.query(sql`select 1`)), - ); + // A second turn handed out would let this statement start while the holder below still owns + // the connection; taking a fresh reservation proves the queue has exactly one turn in it. + const holder = await client.reserve(); + const queued = client.execute(sql`insert into t values (1)`); + await Bun.sleep(5); + expect(driver.calls).toEqual([]); - expect(observer.seen[0]?.attribution).toEqual({ entity: 'members', op: 'findMany' }); - expect(observer.seen[0]?.expected).toBe('one lookup per id'); + holder.release(); + await queued; + expect(driver.calls.map((call) => call.text)).toEqual(['insert into t values (1)']); }); }); diff --git a/packages/db/src/pglite.ts b/packages/db/src/pglite.ts index 00ef35be8..35e44f6bb 100644 --- a/packages/db/src/pglite.ts +++ b/packages/db/src/pglite.ts @@ -11,7 +11,7 @@ import { statementObserver } from './observe'; import { createTurnQueue } from './pglite-turns'; import type { SqlFragment } from './sql'; import { withStatementSpan } from './statement-span'; -import { currentTx } from './transaction'; +import { inLiveTx } from './transaction'; /** What PGlite answers with. `rows` is empty for a write, which is why the count is separate. */ export interface PgliteResult { @@ -203,7 +203,14 @@ export function createPgliteClient(options: PgliteOptions = {}): PgliteClient { // inside of would hang. `handle.enqueue(input, { outbox: false })` within `withTransaction` // is the shape that reaches this line; on a pooled server it would get its own connection, // and here it joins the caller's transaction because a second connection does not exist. - if (currentTx() !== undefined) return statement(driver, fragment); + // + // The fence is the transaction's LIVENESS, never the ALS store's presence: the store rides + // into every promise chain started inside `withTransaction`, so a statement the app forgot to + // `await` still found one after COMMIT, skipped the queue, and landed inside whichever unit of + // work held the session next — a stray statement in someone else's transaction, committed or + // rolled back with it, with no error anywhere. A closed scope falls through and takes its own + // turn, exactly as `client.ts`'s released pin sends a late statement back to the pool. + if (inLiveTx()) return statement(driver, fragment); return turns.run(() => statement(driver, fragment)); } diff --git a/packages/db/src/transaction.ts b/packages/db/src/transaction.ts index 0da729ea5..00a0c0cf6 100644 --- a/packages/db/src/transaction.ts +++ b/packages/db/src/transaction.ts @@ -67,6 +67,16 @@ interface TxState { readonly undos: (() => void)[]; /** Shared by reference across nesting levels so savepoint names never collide. */ readonly savepoints: { value: number }; + /** + * Whether the scope is still OPEN. Shared by reference across nesting for the same reason the + * savepoint counter is: a SAVEPOINT lives and dies with the root transaction that opened it. + * + * Mutable because the store outlives the scope. `AsyncLocalStorage` propagates into every + * promise chain started inside `fn`, so a statement the app forgot to `await` still finds this + * store long after COMMIT — and a reader that treats the store's PRESENCE as an open + * transaction believes a dead one is live. + */ + readonly live: { value: boolean }; } const storage = new AsyncLocalStorage(); @@ -76,6 +86,19 @@ export function currentTx(): DbTx | undefined { return storage.getStore()?.tx; } +/** + * Is a transaction still OPEN on this async context? A different question from `currentTx() !== + * undefined`, which only says a store is present — and the store survives the scope. The one + * reader is `pglite.ts`'s `run()`, where the answer decides whether a statement may skip the + * single session's turn queue; skipping it on a *closed* transaction is how a straggler landed + * inside whichever unit of work held the connection next, committed with it, with nothing to read. + * `currentTx()` deliberately still answers with the dead handle: its statements go through the + * reservation, whose own `held` fence already re-queues them. + */ +export function inLiveTx(): boolean { + return storage.getStore()?.live.value === true; +} + export function beginStatement(options: TransactionOptions): string { const modes: string[] = []; if (options.isolation !== undefined) { @@ -156,10 +179,12 @@ async function runRoot(fn: (tx: DbTx) => Promise, options: TransactionOpti const connection: DbClient = reserved ?? client; const undos: (() => void)[] = []; const tx = makeTx(`tx_${nanoid(12)}`, connection, undos, client); + // Each attempt gets its own state, and therefore its own `live` — a retry re-runs `fn` against a + // transaction that is genuinely new, so the abandoned attempt's stragglers must read as closed. + const state: TxState = { tx, connection, undos, savepoints: { value: 0 }, live: { value: true } }; try { await connection.execute(raw(beginStatement(options))); - const state: TxState = { tx, connection, undos, savepoints: { value: 0 } }; const result = await storage.run(state, () => fn(tx)); await connection.execute(raw('COMMIT')); return result; @@ -169,6 +194,12 @@ async function runRoot(fn: (tx: DbTx) => Promise, options: TransactionOpti await connection.execute(raw('ROLLBACK')).catch(() => undefined); runUndos(undos); throw error; + } finally { + // The scope says when it CLOSED, on every exit, because nothing else can: the store it left + // behind is indistinguishable from a live one, and `inLiveTx()` is what tells them apart. + // Cleared before the `using` pin is given back, so no window exists where a straggler could + // still be sent direct at a connection this scope no longer owns. + state.live.value = false; } } diff --git a/packages/jobs/CLAUDE.md b/packages/jobs/CLAUDE.md index 5c996e8aa..1e8abc893 100644 --- a/packages/jobs/CLAUDE.md +++ b/packages/jobs/CLAUDE.md @@ -193,6 +193,32 @@ Tier 3. The `job` + `task` primitives, durable steps, transactional outbox, queu snapshots `inFlight` has decided there is nothing to wait for, and `close()` then lands under a live job. The round re-reads the state before each queue — "stop claiming" means this round too — and what it already holds runs to the end. +- **A fleet slot is taken INSIDE a `try`, and a renewal answering `false` CANCELS the run** + (`As of 2026-08`). Two halves of one guarantee, and each was a way for `job.concurrency` to be a + number the framework prints and does not hold. + + `fleetSlots.acquire()` is a WRITE to `x_job_leases`, so a failover, a pool timeout or a `57P01` + rejects it — and it sits between `limiter.tryAcquire` and the `.finally` that releases what that + returned. The in-process slot was burned permanently: four rejections on a concurrency-4 worker + and the role claims nothing again for the life of the process, with `jobs.worker.tick-failed` and + a climbing `queue_depth` as the only symptoms. The `catch` releases the lease and rethrows; the + claimed row goes back to the queue by its visibility timeout, as it does for any round that dies. + + `LeaseStore.renew` answering `false` means the row is another holder's — two runs live under a cap + of one — and it was discarded by `.catch(noop)`. It now stops the timer, logs + `jobs.worker.slot-lost` and aborts the run through `X_JOB_SLOT_LOST`. Its own code, not + `X_JOB_LEASE_LOST`: those are different rows on different clocks, and the queue can still consider + this worker the owner of the JOB while another one is running under the same cap. Read as + `renewed !== false` for the reason `heartbeat` reads `held === false` — a store from before the + return value resolves `undefined`, and treating that as a loss would cancel every job on every + renewal. **The heartbeat cannot cover for this**: it renews `x_jobs.visible_at`, a different row, + and knows nothing about `x_job_leases`. +- **The run's signal is a controller this worker owns, never `AbortSignal.any`** (`As of 2026-08`). + `run-signal.ts` composes the caller's `Ctx.signal` and the heartbeat's into one controller, and + `worker-run.ts` disposes it in the same `finally` that stops the timers. `AbortSignal.any` cannot + be undone, which cost twice: an app whose `WorkerOptions.context()` carries a process-lifetime + signal accumulated one composite per job run, and nothing could abort the result — so a lost fleet + slot had no way to reach the body running under it. - **A lease is HELD, not owned, and losing one is said out loud.** `heartbeat.ts` renews the window `claim()` bought and decides between two facts: one failed renewal is not a lost lease (`jobs.heartbeat.failed`, warn — the window has room for the next), a window that passes with @@ -369,6 +395,21 @@ Tier 3. The `job` + `task` primitives, durable steps, transactional outbox, queu moving past it, and `at` rather than the last element of `due`, which `maxCatchUp` truncates. `skip` still fires the latest occurrence WITHIN the cap rather than the true latest missed — named in the README, unchanged here. +- **`relay.stop()` JOINS the pass in flight, and answers a promise for it** (`As of 2026-08`). It + cleared the interval and returned — the one loop in this package whose `stop()` did not wait out + its own work, where `worker.stop()` waits for its rounds and `scheduler.stop()` for its dispatch. + A SIGTERM landing between `driver.enqueue` and `markPublished` returned to a caller that then + closed the database under the row it was about to mark. `OutboxRelay.stop(): Promise` — a + caller that does not await gets what it always got (the chain carries its own `catch`), so the + join is only as good as the `await`: **`packages/cli/src/dev-roles.ts` still calls it without + one**, in both teardown paths. +- **A driver's semantics are pinned in ONE test with the pg statement beside them.** + `driver-parity.test.ts` asserts the memory driver's behaviour and the SQL that has to mean the + same thing in a single test, so neither side can move alone. `introspect.list` answered + `createdAt` ASCENDING in memory and `created_at desc` in pg — one call, two answers, and because + the limit lands after the sort, `x jobs ls` against `x dev` paged the hundred OLDEST rows. The + `attempt` floor is the same shape: `greatest(attempt - 1, 0)` in pg, `Math.max(0, …)` in memory, + with the settle fence in front of both. - **Every timer body catches before it finalises.** `worker.ts`, `scheduler.ts` and the outbox relay all spell `void work().catch(log).finally(...)`. The relay's missing `.catch` made a rejected `store.claim()` an unhandled rejection, and Bun ends the process on one — with every @@ -480,6 +521,8 @@ picture from the other side. | `execute.ts` | `executeJob` — one claimed job run and settled, and the run's deadline/cancel | | `heartbeat.ts` | one claimed job's lease: the renewal interval and the loss it reports | | `worker.ts` | `worker` role, claim loop, drain | +| `worker-run.ts` | one claimed job, wired: its heartbeat, its slot renewal, its run signal and its span, started together and handed back in one `finally` | +| `run-signal.ts` | the signal ONE run is cancelled by — composition that can be handed back, and that the worker can abort itself | | `worker-fleet-slots.ts` | the fleet slot an in-flight job holds — take, renew, hand back. The claim loop asks "may I start this one?"; this answers it across the fleet | | `task.ts` | the `task()` primitive + registry + the handle's surface + `registerTask` | | `scheduler.ts` | `scheduler` role: the dispatch round, catch-up, leader election, the drain | diff --git a/packages/jobs/README.md b/packages/jobs/README.md index f446a29da..e44cefe0f 100644 --- a/packages/jobs/README.md +++ b/packages/jobs/README.md @@ -360,6 +360,11 @@ The memory store (`createMemoryOutboxStore`, `x dev` and tests) **drops** a publ the audit trail this map is not. A relay pass that throws is logged as `jobs.outbox.tick-failed` and the loop re-arms: an unobserved rejection would end the process with rows still staged. +`relay.stop()` is **async and joins the pass in flight** — `await` it before closing the database, +the way `worker.stop()` and `scheduler.stop()` are awaited. A pass is a publish followed by a +`markPublished`, and a caller that returned between the two closed the pool under the row it was +about to mark. + ## Drivers One interface: `enqueue`, `claim` (visibility timeout), `ack`, `nack` (backoff), @@ -521,6 +526,7 @@ FOR a user takes that user's id in its input and re-authorises it in the body. | `X_DRIVER_UNAVAILABLE` | no `DATABASE_URL` / executor for the pg driver | | `X_ABORTED` | a cancelled attempt tried to write a step — core's code, not a second name for it | | `X_JOB_LEASE_LOST` | the job was cancelled, or its lease lapsed and the queue re-delivered it, while this worker was still running it | +| `X_JOB_SLOT_LOST` | the fleet `concurrency` slot this run held was taken by another worker — a different row on a different clock from the lease above | | `X_JOB_NOT_CANCELLABLE` | `cancelJob` reached a job that already finished, or a driver with no `cancel` | | `X_JOB_CONCURRENCY_UNENFORCEABLE` | a registered job declares `concurrency` and the driver has no lease store | | `X_NOT_IMPLEMENTED` | redis / nats driver | diff --git a/packages/jobs/src/driver-memory.ts b/packages/jobs/src/driver-memory.ts index 680e0bf6e..9db0bd6f2 100644 --- a/packages/jobs/src/driver-memory.ts +++ b/packages/jobs/src/driver-memory.ts @@ -73,7 +73,10 @@ export function createMemoryDriver(options: MemoryDriverOptions = {}): JobDriver .filter((record) => filter.queue === undefined || record.queue === filter.queue) .filter((record) => filter.name === undefined || record.name === filter.name) .filter((record) => filter.state === undefined || record.state === filter.state) - .sort((a, b) => a.createdAt - b.createdAt) + // NEWEST first, as `createPgDriver`'s `order by created_at desc` is. Ascending here meant + // `x jobs ls` answered one thing against `x dev` and the opposite in production — and, + // because the limit is applied after the sort, a default page of the hundred OLDEST rows. + .sort((a, b) => b.createdAt - a.createdAt) .slice(0, filter.limit ?? 100); return Promise.resolve(rows); }, @@ -205,8 +208,11 @@ export function createMemoryDriver(options: MemoryDriverOptions = {}): JobDriver const patch: Partial = { state: nackOptions.deadLetter === true ? 'dead' : counts ? 'ready' : 'suspended', runAt: at + nackOptions.delayMs, - // A suspension must not burn an attempt, or a 3-day sleep dead-letters the run. - attempt: counts ? record.attempt : record.attempt - 1, + // A suspension must not burn an attempt, or a 3-day sleep dead-letters the run. Floored + // where `SQL_NACK` floors it (`greatest(attempt - 1, 0)`): the fence above is what keeps + // the decrement paired with a claim today, so this is the guard that survives the fence + // being read as the only one. + attempt: counts ? record.attempt : Math.max(0, record.attempt - 1), ...(nackOptions.error === undefined ? {} : { lastError: nackOptions.error }), }; update(jobId, patch); diff --git a/packages/jobs/src/driver-parity.test.ts b/packages/jobs/src/driver-parity.test.ts new file mode 100644 index 000000000..557460ec6 --- /dev/null +++ b/packages/jobs/src/driver-parity.test.ts @@ -0,0 +1,111 @@ +// One question, one answer, whichever driver is asked. `driver-memory.ts` is what `x dev`, every +// test in this repo and every test in an app runs against; `driver-pg.ts` is what production runs +// against — so a semantic only one of them holds is a guarantee that passes CI and breaks on +// deploy. Each case asserts the memory driver's BEHAVIOUR and the pg statement that has to mean +// the same thing, in one test, so neither side can move alone. + +import { describe, expect, test } from 'bun:test'; +import { frozenClock } from '@ultimat3/core'; +import type { JobDriver } from './driver'; +import { createMemoryDriver } from './driver-memory'; +import type { PgExecutor } from './driver-pg'; +import { createPgDriver } from './driver-pg'; +import { SQL_NACK } from './driver-pg-sql'; + +/** The pg driver compiles its SQL against this seam, so the statement it issues is readable. */ +function recordingExecutor(): PgExecutor & { readonly sql: string[] } { + const sql: string[] = []; + return { + sql, + query(text: string): Promise { + sql.push(text); + return Promise.resolve([] as readonly R[]); + }, + }; +} + +const claimOne = (driver: JobDriver): Promise => + driver.claim({ queues: ['default'], limit: 1, visibilityTimeoutMs: 30_000, workerId: 'w1' }); + +describe('attempt never goes below zero', () => { + test('a suspension that does not burn an attempt cannot drive the count negative', async () => { + const driver = createMemoryDriver(); + const { id } = await driver.enqueue({ + name: 'sleeper', + queue: 'default', + input: {}, + idempotencyKey: 'sleeper:1', + maxAttempts: 3, + }); + + // A `step.sleep` loop is one claim and one suspension per pass, and each pass gives the + // attempt back: three of them on a fresh row is `0 -> 1 -> 0`, three times, never `-1`. A + // negative attempt is a row `nextRetry` reads as having tries it does not have. + for (let pass = 0; pass < 3; pass += 1) { + await claimOne(driver); + await driver.nack(id, { delayMs: 0, countsAsAttempt: false }); + } + expect((await driver.introspect?.job(id))?.attempt).toBe(0); + + // Two guards, and this asks for both: the settle fence refuses a nack on a row that is not + // `running` (a suspended row is already back on the queue), and the decrement itself has a + // floor. Drop either and this row reaches `-1`. + await driver.nack(id, { delayMs: 0, countsAsAttempt: false }); + await driver.nack(id, { delayMs: 0, countsAsAttempt: false }); + expect((await driver.introspect?.job(id))?.attempt).toBe(0); + // The floor the pg driver has always had. Both halves in one test: dropped from either side, + // this fails. + expect(SQL_NACK).toContain('greatest(attempt - 1, 0)'); + }); +}); + +describe('introspect.list answers newest first', () => { + test('the memory driver orders by createdAt descending, as the pg statement does', async () => { + const clock = frozenClock(1_700_000_000_000); + const driver = createMemoryDriver({ clock }); + for (const key of ['oldest', 'middle', 'newest']) { + await driver.enqueue({ + name: 'listed', + queue: 'default', + input: {}, + idempotencyKey: `listed:${key}`, + maxAttempts: 1, + }); + clock.advance(1_000); + } + + // `x jobs ls`, `/_x`'s jobs panel and the MCP tool all read whichever driver the process + // wired: ascending here meant an operator comparing a dev list with a production one was + // shown two different halves of the queue. + expect(((await driver.introspect?.list()) ?? []).map((row) => row.idempotencyKey)).toEqual([ + 'listed:newest', + 'listed:middle', + 'listed:oldest', + ]); + + const executor = recordingExecutor(); + await createPgDriver({ executor }).introspect?.list(); + expect(executor.sql.join('\n')).toContain('order by created_at desc'); + }); + + test('a limit keeps the newest rows, not the oldest', async () => { + const clock = frozenClock(1_700_000_000_000); + const driver = createMemoryDriver({ clock }); + for (const key of ['a', 'b', 'c']) { + await driver.enqueue({ + name: 'listed', + queue: 'default', + input: {}, + idempotencyKey: `listed:${key}`, + maxAttempts: 1, + }); + clock.advance(1_000); + } + + // The limit is applied AFTER the sort in both drivers, so sorting the wrong way did not just + // reverse the page — it returned the rows least likely to be asked about. + expect( + ((await driver.introspect?.list({ limit: 1 })) ?? []).map((row) => row.idempotencyKey), + ).toEqual(['listed:c']); + }); +}); diff --git a/packages/jobs/src/errors.ts b/packages/jobs/src/errors.ts index 02839e0b8..639d5bf94 100644 --- a/packages/jobs/src/errors.ts +++ b/packages/jobs/src/errors.ts @@ -13,6 +13,7 @@ export const JOB_OWNED_ERROR_CODES = [ 'X_JOB_TENANT_REQUIRED', 'X_JOB_CONCURRENCY_UNENFORCEABLE', 'X_JOB_LEASE_LOST', + 'X_JOB_SLOT_LOST', 'X_JOB_NOT_CANCELLABLE', 'X_OUTBOX_NO_TX', 'X_BACKFILL_PENDING', @@ -47,6 +48,7 @@ export const JOB_ERROR_TITLES: Readonly> = { X_JOB_TENANT_REQUIRED: 'the job declares no tenant', X_JOB_CONCURRENCY_UNENFORCEABLE: 'job.concurrency is declared and cannot be enforced', X_JOB_LEASE_LOST: 'the queue took this job back mid-run', + X_JOB_SLOT_LOST: 'the fleet concurrency slot was taken by another worker', X_JOB_NOT_CANCELLABLE: 'the job cannot be cancelled', X_OUTBOX_NO_TX: 'enqueue outside a transaction', X_BACKFILL_PENDING: 'a declared backfill has never completed', @@ -231,6 +233,24 @@ export class LeaseLostError extends UltimateError { } } +/** + * The fleet slot this run holds under `job.concurrency` is somebody else's now: renewal answered + * "not yours", which is the one thing `LeaseStore.renew` can say that a retry cannot fix. Its own + * code and not `X_JOB_LEASE_LOST`, because they are different rows on different clocks — the + * queue may still consider this worker the owner of the JOB while another worker is already + * running one under the same cap, which is precisely the guarantee `concurrency` sells. + */ +export class JobSlotLostError extends UltimateError { + constructor(input: { job: string; jobId: string; slot: number }) { + super({ + code: 'X_JOB_SLOT_LOST', + cause: `job "${input.job}" (${input.jobId}) no longer holds fleet concurrency slot ${input.slot} — its lease expired and another worker took it`, + fix: `x jobs show ${input.jobId} --json`, + docs: docsFor('X_JOB_SLOT_LOST'), + }); + } +} + /** * `x jobs cancel` reached a job that already finished. Not a failure of the command — the work is * done — but never a silent success either: an operator cancelling a runaway pass has to know diff --git a/packages/jobs/src/index.ts b/packages/jobs/src/index.ts index 49a3f38a0..140f3f304 100644 --- a/packages/jobs/src/index.ts +++ b/packages/jobs/src/index.ts @@ -138,6 +138,7 @@ export { JobMaxAttemptsError, JobNameTakenError, JobNotCancellableError, + JobSlotLostError, JobsNotImplementedError, JobTenantRequiredError, JobTimeoutError, diff --git a/packages/jobs/src/outbox.test.ts b/packages/jobs/src/outbox.test.ts index 8573cebb0..9ee66158a 100644 --- a/packages/jobs/src/outbox.test.ts +++ b/packages/jobs/src/outbox.test.ts @@ -244,7 +244,10 @@ describe('the relay loop', () => { await new Promise((resolve) => setTimeout(resolve, 5)); } } finally { - relay.stop(); + // AWAITED: the assertions below read the state the pass in flight is still writing, so a + // teardown that returned before it was the difference between this test proving the row was + // published and this test proving it usually is. + await relay.stop(); } expect(store.claims).toBeGreaterThanOrEqual(2); @@ -292,6 +295,76 @@ describe('the relay loop', () => { }); }); +describe('the relay joins the tick it is stopping', () => { + /** A promise the test opens by hand — the only way to park a tick inside one exact await. */ + function gate(): { readonly passed: Promise; open: () => void } { + let open = (): void => undefined; + const passed = new Promise((resolve) => { + open = resolve; + }); + return { passed, open: () => open() }; + } + + // Every other loop in this package joins its in-flight work in `stop()` — `worker.ts` waits out + // its rounds, `scheduler.ts` its dispatch. The relay only cleared its interval, so a SIGTERM + // landing between `driver.enqueue` and `markPublished` returned to a caller that then closed the + // database under the row it was about to mark. + test('stop() does not resolve until the row in flight is marked published', async () => { + const entered = gate(); + const release = gate(); + const published: string[] = []; + const driver: Pick = { + async enqueue(request: EnqueueRequest) { + entered.open(); + await release.passed; + published.push(request.idempotencyKey); + return { id: 'x', runId: 'r', deduped: false }; + }, + }; + const store = createMemoryOutboxStore(); + const tx = fakeTx(); + await store.stage(tx, { + id: 'row-parked', + job: 'notify', + queue: 'default', + input: {}, + idempotencyKey: 'notify:parked', + maxAttempts: 1, + runAt: 0, + stagedAt: 0, + }); + await store.commit(tx); + + const relay = createOutboxRelay({ store, driver: driver as JobDriver, intervalMs: 1 }); + relay.start(); + await entered.passed; + + let joined = false; + const stopped = (async (): Promise => { + await relay.stop(); + joined = true; + })(); + // Drained in microtasks, never on a clock: a `stop()` that joined nothing resolves in the + // first turn, and this is the whole difference between the two shapes. + for (let turn = 0; turn < 5; turn += 1) await Promise.resolve(); + expect(joined).toBe(false); + + release.open(); + await stopped; + expect(published).toEqual(['notify:parked']); + expect(await store.pendingCount()).toBe(0); + }); + + test('stop() with nothing in flight resolves, and a second one is a no-op', async () => { + const relay = createOutboxRelay({ + store: createMemoryOutboxStore(), + driver: createMemoryDriver(), + }); + await relay.stop(); + await relay.stop(); + }); +}); + describe('createMemoryOutboxStore retention', () => { // Rewriting the record in place kept every payload ever enqueued for the process's lifetime, // and made `claim()` and `pendingCount()` walk all of them every 200ms tick. diff --git a/packages/jobs/src/outbox.ts b/packages/jobs/src/outbox.ts index a3584fcb1..f8ad643e1 100644 --- a/packages/jobs/src/outbox.ts +++ b/packages/jobs/src/outbox.ts @@ -293,7 +293,13 @@ export interface OutboxRelay { /** One pass. Returns how many rows were published. Call it directly in tests. */ tick(): Promise; start(): void; - stop(): void; + /** + * Stop polling and WAIT OUT the pass in flight, the way `worker.stop()` waits out its rounds and + * `scheduler.stop()` its dispatch. A pass is a publish followed by a `markPublished`, and a + * caller that returned between the two closed the database under the row it was about to mark: + * re-published next boot at best, a rejection against a closed pool at worst. + */ + stop(): Promise; pending(): Promise; } @@ -306,6 +312,8 @@ export function createOutboxRelay(options: RelayOptions): OutboxRelay { const intervalMs = options.intervalMs ?? 200; let timer: ReturnType | undefined; let running = false; + /** The pass in flight, so `stop()` joins it instead of returning underneath it. */ + let pass: Promise | undefined; const tick = async (): Promise => { const batch = await options.store.claim(batchSize); @@ -356,7 +364,13 @@ export function createOutboxRelay(options: RelayOptions): OutboxRelay { // guards each publish but not `store.claim()` — one pool timeout during a failover // rejects here unobserved, and Bun's default for an unhandled rejection is to end the // process, taking every staged, unpublished row with it. - void tick() + // + // Kept rather than discarded, because `stop()` awaits exactly this chain: the publish and + // the `markPublished` behind it are one pass, and a teardown that returned between them + // closed the database under the row it was about to mark. The chain carries its own + // `catch`, so a caller that does not await still gets no unhandled rejection. + pass = tick() + .then((): void => undefined) .catch((error: unknown) => { logger.error('jobs.outbox.tick-failed', { error: error instanceof Error ? error.message : String(error), @@ -364,12 +378,15 @@ export function createOutboxRelay(options: RelayOptions): OutboxRelay { }) .finally(() => { running = false; + pass = undefined; }); }, intervalMs); }, - stop() { + async stop() { if (timer !== undefined) clearInterval(timer); timer = undefined; + // Awaited AFTER the interval is cleared, so no further pass can start behind this one. + await pass; }, pending: () => options.store.pendingCount(), }; diff --git a/packages/jobs/src/run-signal.test.ts b/packages/jobs/src/run-signal.test.ts new file mode 100644 index 000000000..a97461eeb --- /dev/null +++ b/packages/jobs/src/run-signal.test.ts @@ -0,0 +1,61 @@ +// What `AbortSignal.any` cannot do: be undone. A worker composes the caller's signal into every +// job it runs, so a caller signal that lives as long as the process — an app wiring its own +// shutdown controller into `WorkerOptions.context()` — collected one composite per job run. + +import { describe, expect, test } from 'bun:test'; +import { createRunSignal } from './run-signal'; + +describe('the signal one run is cancelled by', () => { + test('follows every source it was given', () => { + const caller = new AbortController(); + const lease = new AbortController(); + const run = createRunSignal([caller.signal, lease.signal]); + + expect(run.signal.aborted).toBe(false); + lease.abort(new Error('lease lost')); + expect(run.signal.aborted).toBe(true); + expect((run.signal.reason as Error).message).toBe('lease lost'); + }); + + test('a source already aborted aborts the run at composition, with its own reason', () => { + const caller = new AbortController(); + caller.abort(new Error('caller gone')); + const run = createRunSignal([caller.signal, undefined]); + + expect(run.signal.aborted).toBe(true); + expect((run.signal.reason as Error).message).toBe('caller gone'); + }); + + test('dispose detaches from the sources, so a run that ended holds nothing of theirs', () => { + const caller = new AbortController(); + let listeners = 0; + const add = caller.signal.addEventListener.bind(caller.signal); + const remove = caller.signal.removeEventListener.bind(caller.signal); + // The count is the assertion: `AbortSignal.any` registers nothing here, which is exactly why + // there was nothing to hand back — the composite hung off the caller's signal instead. + caller.signal.addEventListener = (type, listener, options): void => { + listeners += 1; + add(type, listener, options); + }; + caller.signal.removeEventListener = (type, listener, options): void => { + listeners -= 1; + remove(type, listener, options); + }; + + const run = createRunSignal([caller.signal]); + expect(listeners).toBe(1); + + run.dispose(); + expect(listeners).toBe(0); + caller.abort(new Error('after the run')); + expect(run.signal.aborted).toBe(false); + }); + + test('the worker can cancel the run itself, and the first reason wins', () => { + const run = createRunSignal([]); + run.abort(new Error('slot lost')); + run.abort(new Error('second')); + + expect((run.signal.reason as Error).message).toBe('slot lost'); + }); +}); diff --git a/packages/jobs/src/run-signal.ts b/packages/jobs/src/run-signal.ts new file mode 100644 index 000000000..f09175b06 --- /dev/null +++ b/packages/jobs/src/run-signal.ts @@ -0,0 +1,50 @@ +// The signal ONE job run is cancelled by: the caller's `Ctx.signal`, the lease heartbeat, and +// whatever else the worker holds over the run. `AbortSignal.any` composed the same thing and could +// not be undone — an app wiring a process-lifetime controller into `WorkerOptions.context()` grew +// one composite per job for the life of the worker, and nothing could abort the result either. + +export interface RunSignal { + /** Handed to the run as `ctx.signal`; dies with the run. */ + readonly signal: AbortSignal; + /** Cancel this run. The first reason wins, exactly as `AbortController.abort` already does. */ + abort(reason: unknown): void; + /** + * Stop following the sources. Idempotent, and it never aborts: a run that settled leaves its + * signal in whatever state it ended in, it just stops being the caller's problem. + */ + dispose(): void; +} + +/** + * One controller per run, following every source it was given. A source already aborted aborts the + * run at composition, carrying its own reason — the same semantics `AbortSignal.any` has, minus + * the part that cannot be handed back. + * + * `undefined` and a non-`AbortSignal` are both skipped rather than refused: `Ctx.signal` is + * non-optional in the type and still arrives missing across a cast (`@ultimat3/http`'s `asCtx`, a + * test's `{} as Ctx`), and a job that crashed on a missing field is worse than a job with no + * caller to follow. + */ +export function createRunSignal(sources: readonly (AbortSignal | undefined)[]): RunSignal { + const controller = new AbortController(); + const detach: (() => void)[] = []; + + for (const source of sources) { + if (!(source instanceof AbortSignal)) continue; + if (source.aborted) { + controller.abort(source.reason); + continue; + } + const forward = (): void => controller.abort(source.reason); + source.addEventListener('abort', forward, { once: true }); + detach.push(() => source.removeEventListener('abort', forward)); + } + + return { + signal: controller.signal, + abort: (reason) => controller.abort(reason), + dispose: () => { + for (const off of detach.splice(0)) off(); + }, + }; +} diff --git a/packages/jobs/src/task.test.ts b/packages/jobs/src/task.test.ts index 679deec3b..65efa48b0 100644 --- a/packages/jobs/src/task.test.ts +++ b/packages/jobs/src/task.test.ts @@ -196,10 +196,12 @@ describe('task', () => { const occurrenceMs = dispatched[0]?.occurrenceMs ?? 0; // Two rows, two different keys: the occurrence key is what stops two schedulers from - // double-firing a tick, and a manual run has no occurrence to scope itself to. + // double-firing a tick, and a manual run has no occurrence to scope itself to. Newest first — + // `introspect.list` answers in `createdAt desc` in both drivers, and the dispatched row was + // enqueued four hours after the manual one. expect(((await driver.introspect?.list()) ?? []).map((row) => row.idempotencyKey)).toEqual([ - 'digest', `nightlyDigest:${occurrenceMs}:digest`, + 'digest', ]); }); }); diff --git a/packages/jobs/src/worker-fleet-slots.test.ts b/packages/jobs/src/worker-fleet-slots.test.ts new file mode 100644 index 000000000..ff335f3b4 --- /dev/null +++ b/packages/jobs/src/worker-fleet-slots.test.ts @@ -0,0 +1,166 @@ +// The fleet slot's two failure modes, neither of which the queue can recover from on its own: an +// acquire that REJECTS (the lease store is a database, so a failover rejects it) must not keep the +// in-process slot it was taken under, and a renewal that answers `false` — another worker holds +// this slot now — must stop the run rather than let two of them share one `job.concurrency`. + +import { afterEach, describe, expect, test } from 'bun:test'; +import { type Ctx, createContext, isUltimateError } from '@ultimat3/core'; +import type { StandardSchemaV1 } from '@ultimat3/schema'; +import { createMemoryDriver } from './driver-memory'; +import { job, resetJobs } from './job'; +import type { HeldLease, LeaseStore } from './leases'; +import { createMemoryLeaseStore } from './leases'; +import { createLimiter } from './limits'; +import { createWorker } from './worker'; + +const context = (): Ctx => createContext({ role: 'worker', buildId: 'test' }); + +function passthrough(): StandardSchemaV1 { + return { + '~standard': { + version: 1, + vendor: 'ultimate-test', + validate: (value: unknown) => ({ value: value as T }), + }, + }; +} + +interface Gate { + readonly passed: Promise; + open(): void; +} + +/** A promise the test opens by hand — the only way to park a run inside one exact await. */ +function gate(): Gate { + let open = (): void => undefined; + const passed = new Promise((resolve) => { + open = resolve; + }); + return { passed, open: () => open() }; +} + +afterEach(() => { + resetJobs(); +}); + +describe('a fleet-slot acquire that rejects', () => { + test('gives the in-process slot back, so the worker claims again once the store recovers', async () => { + job({ + tenant: 'none', + name: 'cappedJob', + input: passthrough>(), + idempotencyKey: () => 'capped', + retry: { attempts: 1, jitter: false }, + concurrency: 3, + run: () => Promise.resolve(), + }); + + let down = true; + const backing = createMemoryLeaseStore(); + const leases: LeaseStore = { + ...backing, + acquire: (key, limit, ttlMs, holder) => + down + ? Promise.reject(new Error('lease store down')) + : backing.acquire(key, limit, ttlMs, holder), + }; + const driver = createMemoryDriver({ leases }); + const limiter = createLimiter({}); + const worker = createWorker({ + driver, + concurrency: 1, + limiter, + context, + drainOnShutdown: false, + }); + + const enqueue = (key: string): Promise => + driver.enqueue({ + name: 'cappedJob', + queue: 'default', + input: {}, + idempotencyKey: key, + maxAttempts: 1, + }); + + await enqueue('capped:1'); + // The store's rejection reaches the caller — `schedule()` logs it as `jobs.worker.tick-failed`. + await expect(worker.tick()).rejects.toThrow('lease store down'); + // And it costs this worker nothing: a burned slot is permanent, so four of them on a + // concurrency-4 worker is the whole role dead from one transient database error. + expect(limiter.inFlight({ queue: 'default' })).toBe(0); + + down = false; + await enqueue('capped:2'); + expect((await worker.tick()).map((execution) => execution.job)).toEqual(['cappedJob']); + }); +}); + +describe('a fleet-slot renewal that answers false', () => { + test('cancels the run instead of sharing the slot with the worker that took it', async () => { + const started = gate(); + let reason: unknown; + job({ + tenant: 'none', + name: 'sharedJob', + input: passthrough>(), + idempotencyKey: () => 'shared', + retry: { attempts: 1, jitter: false }, + concurrency: 1, + run: ({ ctx }) => { + started.open(); + return new Promise((resolve) => { + ctx.signal.addEventListener( + 'abort', + () => { + reason = ctx.signal.reason; + resolve(); + }, + { once: true }, + ); + }); + }, + }); + + const backing = createMemoryLeaseStore(); + let renewals = 0; + const leases: LeaseStore = { + ...backing, + // The slot expired under this worker and another one took it: the row is somebody else's, + // which `SQL_LEASE_RENEW`'s `holder = $3` reports as zero rows updated. + renew: (_lease: HeldLease) => { + renewals += 1; + return Promise.resolve(false); + }, + }; + const driver = createMemoryDriver({ leases }); + const worker = createWorker({ + driver, + concurrency: 1, + visibilityTimeoutMs: 30_000, + heartbeatIntervalMs: 1, + context, + drainOnShutdown: false, + }); + await driver.enqueue({ + name: 'sharedJob', + queue: 'default', + input: {}, + idempotencyKey: 'shared', + maxAttempts: 1, + }); + + const tick = worker.tick(); + await started.passed; + // The body ends because the run was cancelled — before the fix nothing ever aborted it and + // this await never resolved. + await tick; + + expect(isUltimateError(reason) && reason.code).toBe('X_JOB_SLOT_LOST'); + // Reported once and then the timer stops: renewing a slot this worker no longer holds would + // extend somebody else's lease. + const atLoss = renewals; + await Bun.sleep(20); + expect(renewals).toBe(atLoss); + }); +}); diff --git a/packages/jobs/src/worker-fleet-slots.ts b/packages/jobs/src/worker-fleet-slots.ts index 49d3e86fc..113a79a36 100644 --- a/packages/jobs/src/worker-fleet-slots.ts +++ b/packages/jobs/src/worker-fleet-slots.ts @@ -9,7 +9,12 @@ import { getJob } from './job'; import type { HeldLease, LeaseStore } from './leases'; import { jobLeaseKey } from './leases'; -/** A slot renewal that failed has a TTL behind it; the heartbeat is what reports a lost lease. */ +/** + * A renewal that REJECTED is not a lost slot: there is a TTL behind it and the interval gets + * several tries inside it, exactly as `heartbeat.ts` treats a failed `driver.heartbeat`. The + * heartbeat cannot cover for this one either way — it renews `x_jobs.visible_at`, a different row + * on a different clock, and knows nothing about `x_job_leases`. + */ const noop = (): void => undefined; export interface FleetSlotOptions { @@ -37,8 +42,15 @@ export interface FleetSlots { * impossible. */ acquire(claimed: ClaimedJob): Promise; - /** Keeps this job's slot alive until the returned stop is called. A no-op when it holds none. */ - startRenewal(jobId: string): () => void; + /** + * Keeps this job's slot alive until the returned stop is called. A no-op when it holds none. + * + * `onLost` fires once, when a renewal comes back `false` — the row is another holder's, so this + * run and the one that took the slot are both live under a cap of one. The caller cancels the + * run on it; renewal stops here either way, because extending a slot this worker no longer holds + * would push out somebody else's expiry. + */ + startRenewal(jobId: string, onLost?: (slot: HeldLease) => void): () => void; release(jobId: string): Promise; } @@ -61,18 +73,35 @@ export function createFleetSlots(options: FleetSlotOptions): FleetSlots { return true; }, - startRenewal(jobId) { + startRenewal(jobId, onLost) { const slot = held.get(jobId); if (slot === undefined) return noop; + const stop = (): void => { + clearInterval(timer); + }; // Renewed on the lease heartbeat's own interval and released in the same `finally`: one // clock for "this worker still owns the job" and "this worker still owns the slot" is one // fewer way for them to disagree. const timer = setInterval(() => { - void options.leases?.renew(slot, options.ttlMs).catch(noop); + void options.leases + ?.renew(slot, options.ttlMs) + .then((renewed) => { + // `=== false`, never `!renewed`, for the reason `heartbeat.ts` reads `held` that way: + // a store written before this return value existed resolves `undefined`, and treating + // that as a loss would cancel every job on every renewal. Only an explicit no is one. + if (renewed !== false) return; + stop(); + logger.error('jobs.worker.slot-lost', { + workerId: options.workerId, + jobId, + leaseKey: slot.key, + slot: slot.slot, + }); + onLost?.(slot); + }) + .catch(noop); }, options.renewIntervalMs); - return () => { - clearInterval(timer); - }; + return stop; }, async release(jobId) { diff --git a/packages/jobs/src/worker-run.ts b/packages/jobs/src/worker-run.ts new file mode 100644 index 000000000..6a71522a4 --- /dev/null +++ b/packages/jobs/src/worker-run.ts @@ -0,0 +1,132 @@ +// One claimed job, wired: its lease heartbeat, the fleet slot it holds, the signal the run is +// cancelled by, and the span it is executed under — all started together and handed back in one +// `finally`. Apart from `worker.ts` because that file's job is the claim loop and the drain; this +// one is everything that has to be true for the duration of a single run. + +import type { Clock, Ctx } from '@ultimat3/core'; +import { parseTraceparent, withSpan } from '@ultimat3/core'; +import type { ClaimedJob, JobDriver } from './driver'; +import { JobSlotLostError } from './errors'; +import type { JobExecution } from './execute'; +import { executeJob } from './execute'; +import { startLeaseHeartbeat } from './heartbeat'; +import { getJob } from './job'; +import { createRunSignal } from './run-signal'; +import type { EventLookup } from './steps'; +import type { FleetSlots } from './worker-fleet-slots'; + +export interface RunClaimedOptions { + readonly driver: JobDriver; + readonly claimed: ClaimedJob; + /** Supplies the ambient Ctx for this run; the app wires ALS + tenant here. */ + readonly context: () => Ctx; + readonly fleetSlots: FleetSlots; + readonly workerId: string; + readonly visibilityTimeoutMs: number; + readonly heartbeatIntervalMs: number; + readonly clock?: Clock; + readonly events?: EventLookup; +} + +/** A name this deploy does not know, parked rather than failed — almost always a deploy skew. */ +function unknownJob(claimed: ClaimedJob): JobExecution { + return { + outcome: 'suspended', + jobId: claimed.id, + job: claimed.name, + attempt: claimed.attempt, + durationMs: 0, + error: `no job registered as "${claimed.name}"`, + steps: [], + replayed: [], + }; +} + +/** Run one claimed job under its lease, its slot and its span, and settle it with the driver. */ +export async function runClaimedJob(options: RunClaimedOptions): Promise { + const { claimed, driver, fleetSlots, workerId, visibilityTimeoutMs } = options; + const handle = getJob(claimed.name); + if (handle === undefined) { + // Park it, do not burn attempts: the job may well be registered by the pod next to this one. + await driver.nack(claimed.id, { + delayMs: 30_000, + error: `no job registered as "${claimed.name}"`, + countsAsAttempt: false, + }); + return unknownJob(claimed); + } + + // Read BEFORE the timers start. `context()` is the app's own function and it can throw; started + // first, a heartbeat interval and a slot renewal were left running for a job that never ran, + // with nothing left holding a reference to stop them. + const base = options.context(); + + // The lease, kept alive and NOT kept quiet: a renewal that stops landing means the queue hands + // this job to another worker while this one is still running it, and `.catch(() => undefined)` + // made that — the one failure a queue cannot recover from on its own — indistinguishable from a + // healthy run. + const heartbeat = startLeaseHeartbeat({ + driver, + claimed, + visibilityTimeoutMs, + intervalMs: options.heartbeatIntervalMs, + workerId, + ...(options.clock === undefined ? {} : { clock: options.clock }), + }); + + // The caller's context plus this lease's cancellation, so a job cancelled from outside — or one + // this worker lost the lease on — stops at the next renewal. `steps.ts` refuses every write past + // the signal, which is what unwinds a body that never reads it. Composed through a controller + // this worker owns rather than `AbortSignal.any`, for two reasons: it is handed BACK when the run + // settles (an app whose `context()` carries a process-lifetime signal was accumulating one + // composite per job), and the worker can abort it itself — which is the only way a fleet slot + // taken by somebody else reaches the body running under it. + const runSignal = createRunSignal([base.signal, heartbeat.signal]); + const ctx: Ctx = { ...base, signal: runSignal.signal }; + + // The fleet slot this job already holds, kept alive for as long as the lease is and stopped in + // the same `finally`: one clock for "this worker still owns the job" and "this worker still owns + // the slot" is one fewer way for them to disagree. A renewal answering "not yours" means another + // worker is already running this job under a cap of one, so it CANCELS — discarding that boolean + // made `job.concurrency` a number the framework prints and does not hold. + const stopSlotRenewal = fleetSlots.startRenewal(claimed.id, (slot) => { + runSignal.abort( + new JobSlotLostError({ job: claimed.name, jobId: claimed.id, slot: slot.slot }), + ); + }); + + // The job's span is a CHILD of the request that queued it when the row carries a trace. That + // link is what `04-jobs.md` promised and no column existed to hold: without it a checkout's + // `chargeCard` opens a fresh root two seconds later with nothing pointing back. + const parent = parseTraceparent(claimed.traceparent); + + try { + return await withSpan( + `job.${handle.name}`, + () => + executeJob({ + driver, + claimed, + handle, + ctx, + ...(options.clock === undefined ? {} : { clock: options.clock }), + ...(options.events === undefined ? {} : { events: options.events }), + }), + { + ...(parent === undefined ? {} : { parent }), + attributes: { + 'job.name': handle.name, + 'job.id': claimed.id, + 'job.attempt': claimed.attempt, + ...(claimed.enqueuedBy === undefined ? {} : { 'job.enqueued_by': claimed.enqueuedBy }), + }, + }, + ); + } finally { + stopSlotRenewal(); + heartbeat.stop(); + // Nothing of the caller's is held past the run: `dispose` is what makes the composition above + // reversible, and it is the whole reason this is not `AbortSignal.any`. + runSignal.dispose(); + } +} diff --git a/packages/jobs/src/worker.ts b/packages/jobs/src/worker.ts index 804dc5766..e7da65e03 100644 --- a/packages/jobs/src/worker.ts +++ b/packages/jobs/src/worker.ts @@ -4,28 +4,19 @@ // deploy turns "at least once" into "always twice", so draining is on by default. import type { Clock, Ctx } from '@ultimat3/core'; -import { - logger, - onShutdown, - parseTraceparent, - recordJob, - recordQueueDepth, - uuid, - withSpan, -} from '@ultimat3/core'; +import { logger, onShutdown, recordJob, recordQueueDepth, uuid } from '@ultimat3/core'; import { nowMs } from './clock'; import type { ClaimedJob, JobDriver, QueueStats } from './driver'; import { DEFAULT_QUEUE, DEFAULT_VISIBILITY_TIMEOUT_MS } from './driver'; import { ConcurrencyUnenforceableError } from './errors'; import type { JobExecution, JobOutcome } from './execute'; -import { executeJob } from './execute'; -import { startLeaseHeartbeat } from './heartbeat'; import { getJob, registeredJobs } from './job'; import type { Limiter } from './limits'; import { createLimiter } from './limits'; import { recordQueueDeadJobs, recordQueueOldestReady } from './metrics'; import type { EventLookup } from './steps'; import { createFleetSlots } from './worker-fleet-slots'; +import { runClaimedJob } from './worker-run'; /** * How often the claim loop republishes `queue_depth`. Its own interval, not `pollIntervalMs`: @@ -156,88 +147,19 @@ export function createWorker(options: WorkerOptions): Worker { } }; - const runClaimed = async (claimed: ClaimedJob): Promise => { - const handle = getJob(claimed.name); - if (handle === undefined) { - // Unknown job name: almost always a deploy skew. Park it, do not burn attempts. - await options.driver.nack(claimed.id, { - delayMs: 30_000, - error: `no job registered as "${claimed.name}"`, - countsAsAttempt: false, - }); - return { - outcome: 'suspended', - jobId: claimed.id, - job: claimed.name, - attempt: claimed.attempt, - durationMs: 0, - error: `no job registered as "${claimed.name}"`, - steps: [], - replayed: [], - }; - } - - // The lease, kept alive and NOT kept quiet: a renewal that stops landing means the queue hands - // this job to another worker while this one is still running it, and `.catch(() => undefined)` - // made that — the one failure a queue cannot recover from on its own — indistinguishable from - // a healthy run. - const heartbeat = startLeaseHeartbeat({ + /** One claimed job, run under its lease, its slot and its span. `worker-run.ts` owns the wiring. */ + const runClaimed = (claimed: ClaimedJob): Promise => + runClaimedJob({ driver: options.driver, claimed, - visibilityTimeoutMs, - intervalMs: heartbeatIntervalMs, + context: options.context, + fleetSlots, workerId, + visibilityTimeoutMs, + heartbeatIntervalMs, ...(options.clock === undefined ? {} : { clock: options.clock }), + ...(options.events === undefined ? {} : { events: options.events }), }); - // The fleet slot this job already holds, kept alive for as long as the lease is and stopped in - // the same `finally`: one clock for "this worker still owns the job" and "this worker still - // owns the slot" is one fewer way for them to disagree. - const stopSlotRenewal = fleetSlots.startRenewal(claimed.id); - - // The caller's context plus this lease's cancellation, so a job cancelled from outside — or - // one this worker lost the lease on — stops at the next renewal. `steps.ts` refuses every - // write past the signal, which is what unwinds a body that never reads it. - const base = options.context(); - const ctx: Ctx = { - ...base, - signal: - base.signal instanceof AbortSignal - ? AbortSignal.any([base.signal, heartbeat.signal]) - : heartbeat.signal, - }; - - // The job's span is a CHILD of the request that queued it when the row carries a trace. That - // link is what `04-jobs.md` promised and no column existed to hold: without it a checkout's - // `chargeCard` opens a fresh root two seconds later with nothing pointing back. - const parent = parseTraceparent(claimed.traceparent); - - try { - return await withSpan( - `job.${handle.name}`, - () => - executeJob({ - driver: options.driver, - claimed, - handle, - ctx, - ...(options.clock === undefined ? {} : { clock: options.clock }), - ...(options.events === undefined ? {} : { events: options.events }), - }), - { - ...(parent === undefined ? {} : { parent }), - attributes: { - 'job.name': handle.name, - 'job.id': claimed.id, - 'job.attempt': claimed.attempt, - ...(claimed.enqueuedBy === undefined ? {} : { 'job.enqueued_by': claimed.enqueuedBy }), - }, - }, - ); - } finally { - stopSlotRenewal(); - heartbeat.stop(); - } - }; /** The drain's one question: may this worker still take work off the queue? */ const claiming = (): boolean => state !== 'draining' && state !== 'stopped'; @@ -286,7 +208,20 @@ export function createWorker(options: WorkerOptions): Worker { // `job.concurrency`, at last enforced. The limiter above counts slots in THIS heap, which // twenty pods multiply by twenty; this one is a row every replica sees. Taken after the // in-process lease so the cheap refusal happens first, and released in the same `finally`. - if (!(await fleetSlots.acquire(job))) { + // + // The `try` is the whole of a bug this had: taking a fleet slot is a WRITE to + // `x_job_leases`, so a failover, a pool timeout or a `57P01` REJECTS here — between the + // in-process lease above and the `.finally` below that gives it back. The slot was burned + // permanently, and four of them on a concurrency-4 worker is the whole role dead, silent + // but for `jobs.worker.tick-failed` and a queue depth that climbs forever. + let granted: boolean; + try { + granted = await fleetSlots.acquire(job); + } catch (error) { + lease.release(); + throw error; + } + if (!granted) { lease.release(); await options.driver.nack(job.id, { delayMs: pollIntervalMs, diff --git a/packages/query/CLAUDE.md b/packages/query/CLAUDE.md index 785c387dc..2e12daa58 100644 --- a/packages/query/CLAUDE.md +++ b/packages/query/CLAUDE.md @@ -252,14 +252,62 @@ Owns the `query` primitive: reads, live reads, cursors, the incremental matcher. The memo is not what `cache:` buys — a list that renders one uncached lookup per row pays for every row otherwise, which is the N+1 this collapses. Never gate `readOnce` on `def.cache` again, and never let a second key function grow beside `cacheKeyFor`. -- **`invalidateQueryTags` drops two things, and both are required.** `invalidateTags` reaches the - graph `@ultimat3/cache` owns — every registered `CacheTier`, ISR route, CDN path and live query; - the read tier is *not* in that registry (it is this package's seam, swapped per deployment - through `setReadCache`), so the same tags are passed to `tier.invalidateTags?.()` in the same - hop. Dropping only the first is the defect this pairing replaced: the fan-out reported success - and the pre-write list was served until the process ended. An entry is therefore written with - the read's `cache.tags` — `readThrough`'s last argument — or it is reachable by key alone and - can only expire. +- **A cache key carries the read's AUTHORITY, and `cache.scope` is what widens it** (`As of + 2026-08`). `cacheKeyFor` held the name, the input and the tags — nothing about who asked — while + `sql(input, ctx)` is handed the context and `@ultimat3/entity` derives every tenant predicate + from `ctx.actor.orgId`. The tier is process-wide, so the first actor to ask filled the entry and + the next was served it: a query filtering on `ctx.actor.orgId` returned `org-a`'s row to an + `org-b` actor. `readAuthority(actor, scope)` is the ONE producer of the component and + `cacheKeyFor`'s fourth argument is **required and positional**, because an optional one is one a + call site forgets and a forgotten one is that read. `scope` defaults to `'actor'` and the default + is the mechanism: declaring nothing gets the narrowest key. `'tenant'` and `'global'` are written + statements about the rows — the `unenforced:` shape one field over — and `'tenant'` with no + `orgId` narrows to the actor rather than widening to everyone, because nothing here can prove two + org-less callers share a tenant. The authority is JSON, never a joined string, for the reason + `@ultimat3/entity`'s `scopeKey` gives: an actor id is app data and may carry the separator. +- **`cache.ttlMs` is judged at `query()`, not on the first read.** Every `CacheTier` refuses a + lease that is not positive and finite (`assertTtl`), and the read tier's one catch absorbs + `X_CACHE_TOO_LARGE` only — so `ttlMs: Infinity` turned a typo into a permanently failing business + read whose cause named a cache key. `X_QUERY_CACHE_TTL_INVALID`, on the line that wrote it. It + restates `assertTtl`'s bar as a refusal and never as a second resolution. +- **`fingerprint` is SHA-256/16, never a 32-bit hash** (`stable.ts`, `As of 2026-08`). It is a + SHARING key over client-chosen input — which read-cache entry two callers are served from, which + scope a cursor is bound to — so FNV-1a/32's 4×10⁹ values are a collision found offline in + seconds. Same primitive and width as `@ultimat3/realtime`'s `stableDigest`. `stableStringify` did + not move, so the only cost is one cold cache and every open cursor answering `X_CURSOR_INVALID` + with its own "request the first page again" fix. +- **A fill is FENCED, and the fence is `@ultimat3/cache`'s** (`As of 2026-08`). `run()` answers with + rows it read in the past: a mutator committing in between busts a key not yet in the tier, so the + drop is a no-op reporting `errors: []`, and the fill then publishes the pre-write rows for the + full TTL — invisible to every reader until it expires. `sampleFence({ key, tags })` immediately + before `run()`, `fence.isValid()` before the write. **Sampling before the tier `get` would be + wrong**: a bust landing while the `get` is in flight is one the source read has not started yet + and will therefore see. The caller is answered either way — those rows ARE its answer; only + publishing is refused. No `cover()`: every joiner of a key joins one in-flight read under one + scope, so there are no tags the sample missed. Never write a second fence — this is the one + mechanism, and `packages/cache/src/fence.ts` is where it lives. +- **A tier refusal degrades the cache, never the read.** `tier.get`/`tier.set` go through + `bestEffort('query-read', …)` from `@ultimat3/cache`: a refused `get` reads as a miss, a refused + `set` as "that tier is unchanged", and the entry expires by TTL. The label is `'query-read'` — + a `TierLabel`, deliberately NOT a `TierName` — because this seam is not a rung of that ladder and + `TIER_ORDER.indexOf` answers `-1` for a name it does not know, which would sort a query tier ahead + of the request memo. The refusal lands in `recentTierFailures()` under its own honest name; never + wrap this in a private try/catch, which would be a second failure log the `/_x` panel cannot read. +- **The read tier reads its clock, and `readThrough` hands it one.** `fill` dated an entry with + `Date.now()` and `MemoryReadCache` decided staleness with another, in a package where every read + arrives holding `ctx.clock` — so a frozen clock could not drive either. `nowMs(clock)`, both + places. +- **The installed read cache must be an object the ONE fan-out already reaches.** `invalidateTags` + walks the registered `CacheTier`s and nothing else; a `ReadCache` is registered nowhere. Left as + the module-default `MemoryReadCache`, every deployment without `REDIS_URL` served pre-write rows + for the whole TTL while the invalidation report said `errors: []` — and the hop that would have + dropped them, `invalidateQueryTags`, had zero callers in the repo. The boot + (`packages/cli/src/dev-cache.ts`) therefore installs a read cache **over a registered object**: + the shared tier through `tierReadCache`, or the `lru` tier's own `LruCache` through + `MemoryReadCacheOptions.cache`. `invalidateQueryTags` stays for the host that supplies a + `ReadCache` of its own, which no fan-out can see. An entry is written with the read's + `cache.tags` — `readThrough`'s last argument — or it is reachable by key alone and can only + expire. - **The read tier is bounded and a `cache:` read always expires.** `MemoryReadCache` is `@ultimat3/cache`'s `LruCache` (byte budget, tag index, one definition of tag matching — never a second one derived here), and `def.cache.ttlMs ?? DEFAULT_READ_CACHE_TTL_MS` is what diff --git a/packages/query/README.md b/packages/query/README.md index 6c3b642df..cbb3c29f1 100644 --- a/packages/query/README.md +++ b/packages/query/README.md @@ -143,6 +143,14 @@ the package, and rotating the secret is what invalidates every open cursor. This the only thing that is its business — the scope, `queryHash(name, input)` — and re-exports `CursorInvalidError` so the failure keeps its name on this surface. +The scope's hash is **SHA-256, first 16 hex** (`fingerprint` in `stable.ts`), the primitive and +width `@ultimat3/realtime`'s `stableDigest` and `@ultimat3/entity`'s `planScope` already use. It +was FNV-1a/32 until 2026-08 — 4×10⁹ values over input a client chooses, brute-forceable offline in +seconds, and a fingerprint here is a *sharing* key: which read-cache entry two callers are served +from, and which scope a cursor is bound to. The canonical serialization did not change, only the +hash, so a cursor issued before it fails its scope check as `X_CURSOR_INVALID` with "request the +first page again" as its fix, and a warm read cache is cold once. + A cursor names a **position in the ordering**, never a row and never a count. Both seek paths answer "is this row after that position?" through the one predicate, `isAfterKey`: `Builder.seek()` compiles it to SQL — spelled out per key, so a mixed `createdAt desc, id asc` listing is a real @@ -193,15 +201,45 @@ with it, and a driver whose default differs cannot re-open the divergence. ## Caching Request memo (same read twice in one render ⇒ one round trip), then the tier behind -`ReadCache`. Keys are `query:::`. An action's +`ReadCache`. Keys are `query::::`. An action's `cache.invalidates` and a query's `cache.tags` meet in the one graph owned by `@ultimat3/cache`. -`invalidateQueryTags(tags)` is what an action's `invalidates` runs, and it drops **both**: the -graph `@ultimat3/cache` owns (every registered tier, ISR route, CDN path and live query) and the -read tier, which is this package's own seam and therefore not in that registry. An entry is -written with the read's `cache.tags`, so a row bust (`post:1`) drops the lists that held the row, -exactly as `tagMatches` defines it. +**The authority is who the read was answered for, and it is not optional.** `sql(input, ctx)` is +handed the context and `@ultimat3/entity` derives every tenant predicate from `ctx.actor.orgId`, +never from the input — so a key made of the name, the input and the tags did not identify a read's +answer, and the process-wide tier served one org's rows to the next org that asked. `cache.scope` +declares who may be served one entry: + +| `scope` | Key holds | Use it when | +|---|---|---| +| `actor` (default) | the actor's kind, id and org | anything. Declaring nothing gets this, and this is always correct | +| `tenant` | the actor's org — the actor itself when there is none | every member of one org sees the same rows | +| `global` | nothing | the rows are the same for everyone, signed-in or not | + +The default is the mechanism: forgetting to declare a scope gives the narrowest key. Widening it +is a written statement about the rows, one `grep` away — the same shape `unenforced:` uses for a +skipped policy. `readAuthority(actor, scope)` is the only producer of the component, and it is a +required positional argument of `cacheKeyFor`, because an optional one is one a call site forgets. + +**The fill is fenced and best-effort.** `fill` samples `@ultimat3/cache`'s fence +(`sampleFence({ key, tags })`) immediately before it runs the source and asks it before it writes, +so a bust that lands mid-read cannot be republished for the whole TTL — the caller still gets the +rows it read, because those are its answer; only publishing is refused. Both tier calls go through +`bestEffort('query-read', …)`: a Redis refusal is a miss, not a failed business read, and it shows +up in `recentTierFailures()` under the `query-read` label. This `fill` is the live read-through +path — `createCacheStack` has no production caller. + +`cache.ttlMs` is refused at `query()` unless it is positive and finite +(`X_QUERY_CACHE_TTL_INVALID`): every tier refuses such a lease, so `ttlMs: Infinity` used to make +one read fail permanently at run time with a cause about a cache key. + +An entry is written with the read's `cache.tags`, so a row bust (`post:1`) drops the lists that +held the row, exactly as `tagMatches` defines it. The framework's boot installs a read cache over +an object it also registers as a `CacheTier` — the shared tier seen through `tierReadCache`, or +the `lru` tier's own `LruCache` — so a single `invalidateTags` reaches it. `invalidateQueryTags(tags)` +is for a host that installs a `ReadCache` of its own: registered nowhere, it is reachable by no +fan-out, and that hop is the only thing that drops it. The default `MemoryReadCache` is **bounded** — `@ultimat3/cache`'s byte-budgeted `LruCache`, `DEFAULT_READ_CACHE_MAX_BYTES` (32 MiB), tunable per instance — and a `cache:` block that omits diff --git a/packages/query/src/cache-authority.test.ts b/packages/query/src/cache-authority.test.ts new file mode 100644 index 000000000..9f4320b97 --- /dev/null +++ b/packages/query/src/cache-authority.test.ts @@ -0,0 +1,153 @@ +// Single responsibility: WHO a cached read may be handed back to. `cache.test.ts` proves how many +// times the read path reaches for the tier; this proves that two callers reaching for the same +// name, input and tags are not automatically reaching for the same entry. + +import { afterAll, beforeEach, describe, expect, test } from 'bun:test'; +import { declareTags, isolateDeclaredTags, tag } from '@ultimat3/cache'; +import { createContext, userActor } from '@ultimat3/core'; +import { allow } from '@ultimat3/policy'; +import { t } from '@ultimat3/schema'; +import { cacheKeyFor, readAuthority } from './cache'; +import { query } from './query'; +import { runQuery } from './read'; +import { getReadCache, MemoryReadCache, setReadCache } from './read-cache'; +import { from } from './source'; + +const original = getReadCache(); + +/** The `cache:` fixtures below tag `post`, and the graph validates a tag against the registry. */ +const restoreTags = isolateDeclaredTags(); +declareTags(['post']); + +/** Fresh tier per test: the module default is a process-wide singleton other files share. */ +beforeEach(() => { + setReadCache(new MemoryReadCache()); +}); + +afterAll(() => { + setReadCache(original); + restoreTags(); +}); + +/** + * The tier is process-wide and its key held the query name, the input and the tags — nothing about + * who asked. `sql(input, ctx)` is handed the context and `@ultimat3/entity` derives every tenant + * predicate from `ctx.actor.orgId`, so two actors asking one question with one input are asking + * two different questions: the first one to arrive filled the entry and the second was served it. + */ +describe('the authority a cached read was answered under', () => { + interface SecretRow { + readonly id: string; + readonly orgId: string; + readonly secret: string; + } + + const ROWS: readonly SecretRow[] = [ + { id: 'a1', orgId: 'org-a', secret: 'ALPHA' }, + { id: 'b1', orgId: 'org-b', secret: 'BRAVO' }, + ]; + + /** Filters on the ACTOR's org, exactly as a tenant-scoped repository read does. */ + function tenantFeed(name: string, scope?: 'actor' | 'tenant' | 'global') { + const counts = { executed: 0 }; + const target = query({ + input: t.object({ q: t.string }), + policy: allow(), + cache: { + tags: [tag('post')], + ttlMs: 60_000, + ...(scope === undefined ? {} : { scope }), + }, + sql: (_input: { q: string }, ctx) => + from('rows', async () => { + counts.executed += 1; + return ROWS.filter((row) => row.orgId === ctx.actor.orgId); + }), + }).named(name); + return { target, counts }; + } + + const asOrg = ( + id: string, + orgId?: string, + ): { readonly ctx: ReturnType } => ({ + ctx: createContext({ actor: userActor(orgId === undefined ? { id } : { id, orgId }) }), + }); + + test('an org-b actor is never served the org-a entry', async () => { + const { target, counts } = tenantFeed('leakFeed'); + + const first = await runQuery(target, { q: 'all' }, asOrg('u-a', 'org-a')); + const second = await runQuery(target, { q: 'all' }, asOrg('u-b', 'org-b')); + + expect(first).toEqual([{ id: 'a1', orgId: 'org-a', secret: 'ALPHA' }]); + expect(second).toEqual([{ id: 'b1', orgId: 'org-b', secret: 'BRAVO' }]); + // Two authorities, two keys, two reads: the shared entry is what the leak was. + expect(counts.executed).toBe(2); + }); + + test('the default scope is the actor, so one org-mate does not answer for another', async () => { + const { target, counts } = tenantFeed('perActorFeed'); + + await runQuery(target, { q: 'all' }, asOrg('u-a', 'org-a')); + await runQuery(target, { q: 'all' }, asOrg('u-a2', 'org-a')); + + expect(counts.executed).toBe(2); + }); + + test("scope: 'tenant' shares inside one org and never across two", async () => { + const { target, counts } = tenantFeed('tenantFeed', 'tenant'); + + await runQuery(target, { q: 'all' }, asOrg('u-a', 'org-a')); + await runQuery(target, { q: 'all' }, asOrg('u-a2', 'org-a')); + expect(counts.executed).toBe(1); + + const other = await runQuery(target, { q: 'all' }, asOrg('u-b', 'org-b')); + expect(other).toEqual([{ id: 'b1', orgId: 'org-b', secret: 'BRAVO' }]); + expect(counts.executed).toBe(2); + }); + + test("scope: 'tenant' with no org narrows to the actor rather than widening to everyone", async () => { + const { target, counts } = tenantFeed('orglessFeed', 'tenant'); + + await runQuery(target, { q: 'all' }, asOrg('u-a')); + await runQuery(target, { q: 'all' }, asOrg('u-b')); + + // Nothing proves two actors with no org share a tenant, so the key declines to say they do. + expect(counts.executed).toBe(2); + }); + + test("scope: 'global' is the written opt-out, and it shares one entry", async () => { + const { target, counts } = tenantFeed('publicFeed', 'global'); + + await runQuery(target, { q: 'all' }, asOrg('u-a', 'org-a')); + await runQuery(target, { q: 'all' }, asOrg('u-b', 'org-b')); + + expect(counts.executed).toBe(1); + }); + + test('an uncached read is keyed the same way, so no second key function can grow', async () => { + const actor = userActor({ id: 'u-a', orgId: 'org-a' }); + const other = userActor({ id: 'u-b', orgId: 'org-b' }); + + expect(cacheKeyFor('feed', { q: 'all' }, [], readAuthority(actor, 'actor'))).not.toBe( + cacheKeyFor('feed', { q: 'all' }, [], readAuthority(other, 'actor')), + ); + expect(readAuthority(actor, 'global')).toBe(readAuthority(other, 'global')); + }); + + test('two distinct actors never share an authority, however their ids are spelled', () => { + // JSON, never a joined string — the rule `@ultimat3/entity`'s `scopeKey` states: an actor id + // is app data, and a value that can spell the separator can spell a boundary it does not own. + const actors = [ + userActor({ id: 'u-a', orgId: 'org-a' }), + userActor({ id: 'u-a:org-a' }), + userActor({ id: 'u-a' }), + userActor({ id: 'u-a', orgId: '' }), + userActor({ id: 'u-a"', orgId: 'org-a' }), + ]; + + const authorities = actors.map((actor) => readAuthority(actor, 'actor')); + expect(new Set(authorities).size).toBe(actors.length); + }); +}); diff --git a/packages/query/src/cache-degraded.test.ts b/packages/query/src/cache-degraded.test.ts new file mode 100644 index 000000000..1a5ea1ed4 --- /dev/null +++ b/packages/query/src/cache-degraded.test.ts @@ -0,0 +1,49 @@ +// Single responsibility: what a `cache:` read does when the tier under it refuses. A tier is +// best-effort infrastructure — a Redis refusal must degrade the cache, never fail the business +// read the database could have answered. That is the rule `packages/cache/CLAUDE.md` states and +// `createCacheStack` already kept, and this path did not. + +import { afterAll, afterEach, describe, expect, test } from 'bun:test'; +import { recentTierFailures } from '@ultimat3/cache'; +import { createContext } from '@ultimat3/core'; +import { readThrough } from './cache'; +import type { ReadCache, ReadCacheEntry } from './read-cache'; +import { getReadCache, MemoryReadCache, setReadCache } from './read-cache'; + +const original = getReadCache(); + +afterEach(() => { + setReadCache(new MemoryReadCache()); +}); + +afterAll(() => { + setReadCache(original); +}); + +describe('a read tier that refuses', () => { + class RefusingCache implements ReadCache { + async get(): Promise { + throw new Error('redis: connection refused'); + } + async set(): Promise { + throw new Error('redis: connection refused'); + } + async delete(): Promise {} + } + + // Keyed uniquely rather than reset: the failure log is process-global, capped, and has no + // exported way back — a file that cleared it would be deleting a neighbouring suite's evidence. + const KEY = 'query-read-refusal-probe'; + + test('answers the read from the source instead of failing it', async () => { + setReadCache(new RefusingCache()); + + expect(await readThrough(createContext({}), KEY, 60_000, async () => 'rows', [])).toBe('rows'); + + // Degraded, and SAYABLE: the refusal reaches `recentTierFailures()` under its own label, so a + // stack running without its cache is answerable instead of merely looking slow. + const failures = recentTierFailures().filter((failure) => failure.key === KEY); + expect(failures.map((failure) => failure.op).sort()).toEqual(['get', 'set']); + expect(failures.every((failure) => failure.tier === 'query-read')).toBe(true); + }); +}); diff --git a/packages/query/src/cache-fence.test.ts b/packages/query/src/cache-fence.test.ts new file mode 100644 index 000000000..0d7a85bb3 --- /dev/null +++ b/packages/query/src/cache-fence.test.ts @@ -0,0 +1,127 @@ +// Single responsibility: what a read-through fill is allowed to PUBLISH. `cache.test.ts` proves +// how many times the read path reaches for the tier; this proves whether the answer it got is +// still true by the time it would be written down. +// +// T0 miss → `run()`. T1 a mutator commits and `invalidateTags` drops a key that is not there yet, +// so the drop is a no-op and the report says `errors: []`. T2 `run()` resolves with pre-write rows. +// T3 the fill publishes them for the full TTL — invisible to every reader until it expires. The +// fence is `@ultimat3/cache`'s, sampled before the load and asked before the write; there is no +// second one here. + +import { afterAll, beforeEach, describe, expect, test } from 'bun:test'; +import { declareTags, invalidateTags, isolateDeclaredTags, tag } from '@ultimat3/cache'; +import { createContext } from '@ultimat3/core'; +import { readThrough } from './cache'; +import { getReadCache, MemoryReadCache, setReadCache } from './read-cache'; + +/** A source that hangs until released, so the sequence below is an ordering, not a duration. */ +function gate(): { readonly wait: Promise; readonly open: () => void } { + let open = (): void => undefined; + const wait = new Promise((resolve) => { + open = resolve; + }); + return { wait, open }; +} + +const original = getReadCache(); +const restoreTags = isolateDeclaredTags(); +declareTags(['post', 'comment']); + +beforeEach(() => { + setReadCache(new MemoryReadCache()); +}); + +afterAll(() => { + setReadCache(original); + restoreTags(); +}); + +/** + * "Was it published?" is asked of the tier itself rather than of a call counter: what matters is + * whether a later reader can be served the entry, and a count of `set` calls is one step removed + * from that. + */ +const published = async (key: string): Promise => (await getReadCache().get(key))?.value; + +describe('the fence around a read-through fill', () => { + /** + * T0: the source read has STARTED — `entered` resolves from inside it. Sampling the fence before + * the load is the whole mechanism, and a bust landing before the read began is a bust the read + * will see for itself. + */ + function startedRead(value: string): { + readonly run: () => Promise; + readonly entered: Promise; + readonly finish: () => void; + readonly calls: () => number; + } { + const source = gate(); + const entry = gate(); + let calls = 0; + return { + entered: entry.wait, + finish: source.open, + calls: () => calls, + run: async () => { + calls += 1; + entry.open(); + await source.wait; + return value; + }, + }; + } + + test('a bust that lands mid-read is answered, never published', async () => { + const read = startedRead('pre-write rows'); + + const reading = readThrough(createContext({}), 'k', 60_000, read.run, [tag('post')]); + await read.entered; + // The drop finds no key — it is not in the tier yet — so it reports `errors: []`. + await invalidateTags([tag('post')]); + read.finish(); + + // Its own caller still gets what the source read: that IS this request's answer, and + // swallowing it would turn a cache concern into a failed business read. + expect(await reading).toBe('pre-write rows'); + expect(read.calls()).toBe(1); + // Nobody else does. Published, this would have been served for the whole 60s. + expect(await published('k')).toBeUndefined(); + }); + + test('the next request re-reads, rather than joining an entry that was never written', async () => { + const first = startedRead('pre-write rows'); + + const reading = readThrough(createContext({}), 'k', 60_000, first.run, [tag('post')]); + await first.entered; + await invalidateTags([tag('post')]); + first.finish(); + await reading; + + const second = await readThrough( + createContext({}), + 'k', + 60_000, + async () => 'post-write rows', + [tag('post')], + ); + expect(second).toBe('post-write rows'); + }); + + test('a bust of an unrelated tag does not stop the write', async () => { + const read = startedRead('rows'); + + const reading = readThrough(createContext({}), 'k', 60_000, read.run, [tag('comment')]); + await read.entered; + await invalidateTags([tag('post')]); + read.finish(); + await reading; + + expect(await published('k')).toBe('rows'); + }); + + test('a fill nothing raced still writes', async () => { + await readThrough(createContext({}), 'k', 60_000, async () => 'rows', [tag('post')]); + + expect(await published('k')).toBe('rows'); + }); +}); diff --git a/packages/query/src/cache.test.ts b/packages/query/src/cache.test.ts index af217a7b6..b3beb16f3 100644 --- a/packages/query/src/cache.test.ts +++ b/packages/query/src/cache.test.ts @@ -1,6 +1,8 @@ // Single responsibility: tests for the read path's one guarantee — a key is read once per // request. The tier it fills through is `read-cache.test.ts`; what is proved here is how many -// times the read path reaches for it. +// times the read path reaches for it. Three questions about a fill that are NOT this file's: +// who an entry may be served to (`cache-authority.test.ts`), whether it may be written at all +// (`cache-fence.test.ts`), and what happens when the tier refuses (`cache-degraded.test.ts`). // Concurrency is the half that used to be missing: the memo holds the read *in flight*, // not its value, or two readers arriving in the same tick both miss and both execute. The same // shape is what lets a legitimately `undefined` result memoize, and the failure case is here @@ -8,7 +10,7 @@ import { afterAll, beforeEach, describe, expect, test } from 'bun:test'; import type { CacheTag } from '@ultimat3/cache'; -import { createContext } from '@ultimat3/core'; +import { createContext, frozenClock } from '@ultimat3/core'; import { readFresh, readOnce, readThrough, requestMemo } from './cache'; import type { ReadCache, ReadCacheEntry } from './read-cache'; import { getReadCache, MemoryReadCache, setReadCache } from './read-cache'; @@ -293,6 +295,16 @@ describe('readThrough', () => { expect(tier.writes).toHaveLength(2); }); + // `Date.now()` in a package that is handed a `Clock` on every read: a test could not decide the + // expiry it asserts, and a read served under an injected clock wrote an entry under another one. + test("dates the entry by the request's own clock, never the wall clock", async () => { + const ctx = createContext({ clock: frozenClock(1_000) }); + + await readThrough(ctx, 'k', 60_000, async () => 'rows'); + + expect(tier.writes[0]?.expiresAt).toBe(61_000); + }); + test('fails every reader that joined the read, having run the source once', async () => { const ctx = createContext({}); const source = gate(); diff --git a/packages/query/src/cache.ts b/packages/query/src/cache.ts index cfb196908..092f4dfe9 100644 --- a/packages/query/src/cache.ts +++ b/packages/query/src/cache.ts @@ -6,7 +6,9 @@ */ import type { CacheTag } from '@ultimat3/cache'; -import type { Ctx } from '@ultimat3/core'; +import { bestEffort, nowMs, sampleFence } from '@ultimat3/cache'; +import type { Actor, Clock, Ctx } from '@ultimat3/core'; +import { assertNever } from '@ultimat3/core'; import { getReadCache } from './read-cache'; import { fingerprint } from './stable'; import { tagKeys } from './tags'; @@ -30,9 +32,64 @@ export function requestMemo(ctx: Ctx): Map> { return created; } -/** Deterministic: same query + same input + same tags => same key. */ -export function cacheKeyFor(name: string, input: unknown, tags: readonly CacheTag[]): string { - return `query:${name}:${fingerprint(input)}:${tagKeys(tags).join(',')}`; +/** + * Who a cached answer may be handed back to. Declared as `cache: { scope }`. + * + * `actor` is the default, and the default is the mechanism (axiom 3): a read that says nothing + * gets the NARROWEST key, which is always correct. Widening is a written statement about what the + * rows are — `tenant` says "every member of this org gets the same rows", `global` says "everyone + * does" — and a wrong one is visible in the declaration rather than in a support ticket. + */ +export type QueryCacheScope = 'actor' | 'tenant' | 'global'; + +/** + * The authority a read was answered under, as a key component. + * + * `sql(input, ctx)` is handed the context, and `@ultimat3/entity` derives every tenant predicate + * from `ctx.actor.orgId` rather than from the input — so the name, the input and the tags do not + * identify a read's answer, and a tier keyed on those three served one org's rows to the next org + * that asked. Folding the authority in is what `@ultimat3/entity`'s `scopeKey` does for a batched + * point read, for exactly this reason. + * + * JSON, never a joined string: an actor id is app data and may carry the separator, and a value + * that can spell a boundary can spell someone else's. + */ +export function readAuthority(actor: Actor, scope: QueryCacheScope): string { + switch (scope) { + case 'global': + return '*'; + case 'tenant': + // An actor inside no org is not a shared tenant. Nothing here can prove two org-less callers + // see the same rows, so the key narrows to the actor rather than widening to everyone — + // declining instead of guessing, which is the only safe direction for a sharing key. + return actor.orgId === undefined || actor.orgId === '' + ? actorAuthority(actor) + : JSON.stringify(['org', actor.orgId]); + case 'actor': + return actorAuthority(actor); + default: + // A fourth scope is a compile error here, not a value that silently keys as `undefined`. + return assertNever(scope); + } +} + +const actorAuthority = (actor: Actor): string => + JSON.stringify([actor.kind, actor.id, actor.orgId ?? null]); + +/** + * Deterministic: same query + same input + same tags + same authority => same key. + * + * `authority` is REQUIRED and positional rather than optional, because an optional one is one a + * call site can forget — and a forgotten one is the cross-tenant read this argument exists to + * make impossible. `readAuthority` is the only thing that produces it. + */ +export function cacheKeyFor( + name: string, + input: unknown, + tags: readonly CacheTag[], + authority: string, +): string { + return `query:${name}:${authority}:${fingerprint(input)}:${tagKeys(tags).join(',')}`; } /** @@ -96,11 +153,12 @@ export function readThrough( run: () => Promise, tags: readonly CacheTag[] = [], ): Promise { - return readOnce(ctx, key, () => fill(key, ttlMs, tags, run)); + return readOnce(ctx, key, () => fill(ctx.clock, key, ttlMs, tags, run)); } /** The read itself — tier, then the source. Runs once per key per request; the rest join it. */ async function fill( + clock: Clock, key: string, ttlMs: number | null, tags: readonly CacheTag[], @@ -109,10 +167,28 @@ async function fill( // Read per call, never captured: `setReadCache` after the first read has to be honoured, and a // module-level binding here would be a second handle on a tier the seam exists to swap. const tier = getReadCache(); - const cached = await tier.get(key); + // A tier that refuses is a tier that did not answer, never a failed business read — the rule + // `@ultimat3/cache` keeps for its own ladder, kept here through the same helper so one Redis + // outage degrades the cache instead of 500-ing every `cache:` query. The label is `query-read` + // and not a `TierName`: this seam is not a rung of that ladder, and `sortTiers` would place a + // name it does not know ahead of the request memo. + const cached = await bestEffort('query-read', 'get', key, () => tier.get(key)); if (cached !== undefined) return cached.value as T; + // Sampled BEFORE the load and asked before the write. The read below is about to answer with + // rows it read in the past: a mutator committing in between busts a key that is not in the tier + // yet, so the drop is a no-op reporting `errors: []`, and publishing afterwards serves the + // pre-write rows for the whole TTL. `@ultimat3/cache`'s fence is the one mechanism for this — + // no `cover()`, because every joiner of this key joins the same in-flight read under the same + // scope, so there are no tags the sample missed. + const fence = sampleFence({ key, tags }); const value = await run(); - await tier.set(key, { value, expiresAt: ttlMs === null ? null : Date.now() + ttlMs, tags }); + // The request's own clock, never `Date.now()`: every other reading of "now" on this path is + // injected, and an expiry decided by the wall clock is one no test can drive. + const expiresAt = ttlMs === null ? null : nowMs(clock) + ttlMs; + // Answered either way — the rows ARE this request's answer. Only publishing is refused. + if (fence.isValid()) { + await bestEffort('query-read', 'set', key, () => tier.set(key, { value, expiresAt, tags })); + } return value; } diff --git a/packages/query/src/errors.ts b/packages/query/src/errors.ts index b65fe0295..53c59b9b4 100644 --- a/packages/query/src/errors.ts +++ b/packages/query/src/errors.ts @@ -11,6 +11,7 @@ export { CursorInvalidError } from '@ultimat3/core'; const OWNED_TITLES: Readonly> = { X_CURSOR_VALUE_UNSUPPORTED: 'a sort value cannot be carried in a cursor', X_MATCHER_UNSUPPORTED: 'live query shape cannot be patched incrementally', + X_QUERY_CACHE_TTL_INVALID: 'a query declares a cache ttlMs no tier can hold', X_QUERY_DEPRECATION_INVALID: 'a query declares a deprecation whose dates cannot be rendered', X_QUERY_DUPLICATE: 'two queries are registered under one name', X_QUERY_FOREIGN: 'a value that is not a query was projected as one', @@ -129,6 +130,30 @@ export class QueryInputUnencodableError extends UltimateError { } } +/** + * A `cache.ttlMs` no tier will accept, refused at `query()` — so the file that wrote it fails, and + * not every read of that query for the life of the process. + * + * Every `CacheTier` refuses a non-positive or non-finite lease (`assertTtl`, `X_CACHE_TTL_INVALID`) + * and the read path's only catch absorbs `X_CACHE_TOO_LARGE`, so `ttlMs: Infinity` used to make a + * working read fail permanently with a cause naming a cache key. The value is a number the author + * typed, so it is echoed: it is the one fact that repairs the line. + * + * The query has no name yet — `query()` runs before `registerQueries()` stamps one — which is why + * the cause describes the declaration, exactly as `X_QUERY_INPUT_UNENCODABLE` does. + */ +export class QueryCacheTtlInvalidError extends UltimateError { + constructor(ttlMs: number) { + super({ + code: 'X_QUERY_CACHE_TTL_INVALID', + cause: `a query declares cache.ttlMs as ${ttlMs}, and every cache tier refuses a lease that is not positive and finite`, + fix: 'set `cache: { ttlMs: 60_000 }` to a positive whole number of milliseconds, or drop ttlMs to take the read cache default', + docs: docs('X_QUERY_CACHE_TTL_INVALID'), + meta: { ttlMs }, + }); + } +} + export class QueryDuplicateError extends UltimateError { constructor(name: string) { super({ diff --git a/packages/query/src/index.ts b/packages/query/src/index.ts index aedc853fc..edebcff37 100644 --- a/packages/query/src/index.ts +++ b/packages/query/src/index.ts @@ -9,7 +9,9 @@ /** Re-exported so a `query` file needs one import, not two. Same object as schema's. */ export type { Infer } from '@ultimat3/schema'; export { t } from '@ultimat3/schema'; -export { cacheKeyFor, readOnce, readThrough, requestMemo } from './cache'; +export type { QueryCacheScope } from './cache'; +/** `readAuthority` is the ONLY producer of `cacheKeyFor`'s authority — never spell one by hand. */ +export { cacheKeyFor, readAuthority, readOnce, readThrough, requestMemo } from './cache'; export type { FetchLike, QueryCallOptions, diff --git a/packages/query/src/live.test.ts b/packages/query/src/live.test.ts index 12d7df748..d0895bb9d 100644 --- a/packages/query/src/live.test.ts +++ b/packages/query/src/live.test.ts @@ -52,7 +52,12 @@ describe('live query descriptor', () => { const feed = registerQuery('liveFeed', defineFeed()); const live = await toLiveQuery(feed, { orgId: ORG }, { ctx: member, epoch: 'build-1' }); - live.authorize({ actor: readerActor, input: {}, ctx: member, query: 'liveFeed' }); + // Both halves, on ONE descriptor: the claim is that two subscribers get two answers, and the + // allowed one was a floating promise asserting nothing — an `authorize` that denied EVERY + // subscriber passed this test, which is the opposite failure to the one it is named for. + await expect( + live.authorize({ actor: readerActor, input: {}, ctx: member, query: 'liveFeed' }), + ).resolves.toBeUndefined(); const denial = await live .authorize({ actor: null, input: {}, ctx: anonymous, query: 'liveFeed' }) .catch((error: unknown) => error); diff --git a/packages/query/src/query.test.ts b/packages/query/src/query.test.ts index 67b0aabed..c924ca257 100644 --- a/packages/query/src/query.test.ts +++ b/packages/query/src/query.test.ts @@ -189,6 +189,40 @@ describe('query', () => { }); }); +/** + * A `ttlMs` no tier can hold is a DECLARATION mistake, so it is refused where it was written. + * Left to run time it became `X_CACHE_TTL_INVALID` on every read of that query, forever: the read + * tier's only catch absorbs `X_CACHE_TOO_LARGE`, so `ttlMs: Infinity` turned a typo into a + * permanently failing business read with a fix line about a cache key. + */ +describe('cache.ttlMs is judged at declaration', () => { + const withTtl = + (ttlMs: number): (() => unknown) => + () => + query({ + input: Input, + policy: can('feed:read'), + cache: { tags: [], ttlMs }, + sql: () => from('posts', posts), + }); + + test.each([Number.POSITIVE_INFINITY, 0, -1, Number.NaN])('%p is refused', (ttlMs) => { + expect(withTtl(ttlMs)).toThrow('X_QUERY_CACHE_TTL_INVALID'); + }); + + test('a positive finite ttlMs is accepted, and so is a cache block that names none', () => { + expect(withTtl(60_000)).not.toThrow(); + expect(() => + query({ + input: Input, + policy: can('feed:read'), + cache: { tags: [] }, + sql: () => from('posts', posts), + }), + ).not.toThrow(); + }); +}); + // A `cache:` block buys the tier. It never bought the request memo — that one is every read's, // or a list rendering one uncached lookup per row pays for every row. describe('a query with no cache block', () => { diff --git a/packages/query/src/query.ts b/packages/query/src/query.ts index 8a0779b2d..5b145ec01 100644 --- a/packages/query/src/query.ts +++ b/packages/query/src/query.ts @@ -9,8 +9,10 @@ import type { CacheTag } from '@ultimat3/cache'; import type { Actor, Ctx } from '@ultimat3/core'; import type { InferInput, InferOutput, StandardSchemaV1 } from '@ultimat3/schema'; +import type { QueryCacheScope } from './cache'; import type { QueryClientMethod, QueryClientOptions } from './client'; import type { Deprecation } from './deprecation'; +import { QueryCacheTtlInvalidError } from './errors'; import { facadeFor } from './facade'; import { assertEncodableInput } from './input-shape'; import type { LiveQuery, ToLiveOptions } from './live'; @@ -26,7 +28,19 @@ import { tagKeys } from './tags'; export interface QueryCache { /** Tags this read depends on. An action's `invalidates` drops exactly these keys. */ readonly tags: readonly CacheTag[]; + /** + * Lifetime of a tier entry. Positive and finite — `Infinity`, `0` and `NaN` are refused at + * `query()` (`X_QUERY_CACHE_TTL_INVALID`), where the file that wrote them fails, rather than on + * every read of that query forever. Omitted takes `DEFAULT_READ_CACHE_TTL_MS`. + */ readonly ttlMs?: number; + /** + * Who a cached answer may be handed back to. **Defaults to `actor`**, and that default is the + * mechanism: a read that declares nothing gets the narrowest key, which is always correct. + * `tenant` and `global` are written statements that the rows do not depend on the caller beyond + * their org, or at all — see `readAuthority`. + */ + readonly scope?: QueryCacheScope; } export interface QueryMcp { @@ -216,9 +230,22 @@ export function query( // anyone mounts it, and the typed client derives that same URL — so an input a query string // cannot carry is wrong for every call, and the file that declared it is where it is repaired. assertEncodableInput(def.input); + assertCacheTtl(def.cache); return build(def, ''); } +/** + * The same rule, for the same reason: a lease every `CacheTier` refuses is wrong for every read of + * this query, so it fails on the line that wrote it rather than on the first request. Positive and + * finite is `assertTtl`'s bar in `@ultimat3/cache`, restated as a refusal and never as a second + * resolution — there is no "never expires" to fall back to. + */ +function assertCacheTtl(cache: QueryCache | undefined): void { + const ttlMs = cache?.ttlMs; + if (ttlMs === undefined) return; + if (!Number.isFinite(ttlMs) || ttlMs <= 0) throw new QueryCacheTtlInvalidError(ttlMs); +} + /** * Structural, not nominal: an object only counts as a query if `query()` built it, * because only then does a declaration exist for `sourceFor` to read. A look-alike diff --git a/packages/query/src/read-cache.test.ts b/packages/query/src/read-cache.test.ts index d07e72ecb..84d7d498e 100644 --- a/packages/query/src/read-cache.test.ts +++ b/packages/query/src/read-cache.test.ts @@ -4,7 +4,8 @@ // `read.test.ts`. Here the tier is driven directly, so a failure names the tier and not the read. import { afterAll, beforeEach, describe, expect, test } from 'bun:test'; -import { declareTags, isolateDeclaredTags, tag } from '@ultimat3/cache'; +import { declareTags, isolateDeclaredTags, LruCache, tag } from '@ultimat3/cache'; +import { frozenClock } from '@ultimat3/core'; import type { ReadCache, ReadCacheEntry } from './read-cache'; import { DEFAULT_READ_CACHE_MAX_BYTES, @@ -144,6 +145,35 @@ describe('MemoryReadCache', () => { expect((await memory.get('c'))?.value).toBe(3); }); + // `Date.now()` here decided whether an entry was already stale, so a frozen clock could not + // drive it and a read served under an injected clock was judged against the wall clock. + test('reads "now" from the injected clock, never the wall clock', async () => { + const clock = frozenClock(1_000); + const memory = new MemoryReadCache({ clock }); + + await memory.set('stale', { value: 'rows', expiresAt: 999 }); + await memory.set('live', { value: 'rows', expiresAt: 61_000 }); + + expect(await memory.get('stale')).toBeUndefined(); + expect((await memory.get('live'))?.value).toBe('rows'); + }); + + /** + * The wiring the boot depends on: `invalidateTags` fans out to registered `CacheTier`s only, so + * the read cache holds entries in the SAME `LruCache` the process registers as its `lru` tier. + * Sharing the object is what makes the read tier reachable by the one fan-out. + */ + test('holds its entries in a caller-supplied LruCache, tag index included', async () => { + const shared = new LruCache(); + const memory = new MemoryReadCache({ cache: shared }); + + await memory.set('a', { value: 1, expiresAt: null, tags: [tag('post')] }); + + // Dropped through the tier's own handle on the cache — the half `invalidateTags` reaches. + expect(shared.invalidateTags([tag('post')])).toEqual(['a']); + expect(await memory.get('a')).toBeUndefined(); + }); + test('the defaults are the numbers the read path is documented against', () => { expect(DEFAULT_READ_CACHE_TTL_MS).toBe(60_000); expect(DEFAULT_READ_CACHE_MAX_BYTES).toBe(32 * 1024 * 1024); diff --git a/packages/query/src/read-cache.ts b/packages/query/src/read-cache.ts index f312ec763..618fefb60 100644 --- a/packages/query/src/read-cache.ts +++ b/packages/query/src/read-cache.ts @@ -6,7 +6,9 @@ */ import type { CacheTag, LruOptions } from '@ultimat3/cache'; -import { CacheTooLargeError, invalidateTags, LruCache } from '@ultimat3/cache'; +import { CacheTooLargeError, invalidateTags, LruCache, nowMs } from '@ultimat3/cache'; +import type { Clock } from '@ultimat3/core'; +import { systemClock } from '@ultimat3/core'; export interface ReadCacheEntry { readonly value: unknown; @@ -40,6 +42,19 @@ export const DEFAULT_READ_CACHE_TTL_MS = 60_000; /** 32 MiB: half the LRU tier's budget, because a read cache is not the whole cache. */ export const DEFAULT_READ_CACHE_MAX_BYTES = 32 * 1024 * 1024; +export interface MemoryReadCacheOptions extends LruOptions { + /** + * An `LruCache` to hold entries in rather than one of this cache's own. + * + * The one caller is a boot that ALSO registers that same cache as `@ultimat3/cache`'s `lru` + * tier. `invalidateTags` fans out to the registered tiers and to nothing else, so a read cache + * over a private `LruCache` is a `cache:` query an action's `invalidates` can never drop — + * which is what every deployment without a shared tier shipped until 2026-08. Sharing the + * object is what puts the read tier inside the one fan-out instead of beside it. + */ + readonly cache?: LruCache; +} + /** * In-memory default. Production installs the tiered cache from @ultimat3/cache. * @@ -49,9 +64,14 @@ export const DEFAULT_READ_CACHE_MAX_BYTES = 32 * 1024 * 1024; */ export class MemoryReadCache implements ReadCache { readonly #entries: LruCache; + readonly #clock: Clock; - constructor(options: LruOptions = {}) { - this.#entries = new LruCache({ maxBytes: DEFAULT_READ_CACHE_MAX_BYTES, ...options }); + constructor(options: MemoryReadCacheOptions = {}) { + const { cache, ...lru } = options; + this.#entries = cache ?? new LruCache({ maxBytes: DEFAULT_READ_CACHE_MAX_BYTES, ...lru }); + // Injected, never `Date.now()`: an expiry decided by the wall clock cannot be driven by a + // test, and this package hands every other reading of "now" through a `Clock` already. + this.#clock = options.clock ?? systemClock; } async get(key: string): Promise { @@ -59,7 +79,7 @@ export class MemoryReadCache implements ReadCache { } async set(key: string, entry: ReadCacheEntry): Promise { - const now = Date.now(); + const now = nowMs(this.#clock); // Already stale on arrival: storing it would hand the next reader an entry `get` has to // throw away, and `ttl <= 0` is how the LRU spells "no expiry" — the opposite answer. if (entry.expiresAt !== null && entry.expiresAt <= now) { @@ -102,12 +122,15 @@ export function getReadCache(): ReadCache { } /** - * The one invalidation path. Actions call the same function via their `cache`. + * Two drops, one call — for a `ReadCache` the fan-out cannot see. * - * Two drops, one call: the graph @ultimat3/cache owns reaches every registered tier, ISR route, - * CDN path and live query, and the read tier is dropped by the same tags in the same hop. The - * read tier is not a registered `CacheTier` — it is this package's seam, replaceable per - * deployment through `setReadCache` — so the fan-out cannot reach it and this must. + * The graph @ultimat3/cache owns reaches every registered `CacheTier`, ISR route, CDN path and + * live query. A `ReadCache` is this package's own seam and is registered nowhere, so a host that + * installs one through `setReadCache` has to hand it the same tags in the same hop or its entries + * can only expire. The framework's own boot avoids needing this at all: it installs a read cache + * over the very object it registers as a tier (`MemoryReadCacheOptions.cache`, or the shared tier + * seen through `tierReadCache`), so one `invalidateTags` already drops it. An app supplying a + * `ReadCache` of its own is the caller this exists for. */ export async function invalidateQueryTags(tags: readonly CacheTag[]): Promise { await invalidateTags(tags); diff --git a/packages/query/src/read.test.ts b/packages/query/src/read.test.ts index 4be272835..31763fb57 100644 --- a/packages/query/src/read.test.ts +++ b/packages/query/src/read.test.ts @@ -7,7 +7,7 @@ import { declareTags, isolateDeclaredTags, tag } from '@ultimat3/cache'; import { createContext, userActor } from '@ultimat3/core'; import { allow, can } from '@ultimat3/policy'; import { t } from '@ultimat3/schema'; -import { cacheKeyFor } from './cache'; +import { cacheKeyFor, readAuthority } from './cache'; import { QueryDeniedError, QueryForeignError, QueryUnregisteredError } from './errors'; import type { AnyQuery } from './query'; import { query } from './query'; @@ -329,7 +329,12 @@ describe("a cache: read's tier entry, and what drops it", () => { await runQuery(target, { orgId: ORG }, { ctx: createContext({ actor: allowedActor }) }); - const key = cacheKeyFor(queryName(target), { orgId: ORG }, [tag('post')]); + const key = cacheKeyFor( + queryName(target), + { orgId: ORG }, + [tag('post')], + readAuthority(allowedActor, 'actor'), + ); const entry = await getReadCache().get(key); expect(entry?.expiresAt).toBeGreaterThanOrEqual(before + DEFAULT_READ_CACHE_TTL_MS); expect(entry?.tags).toEqual([tag('post')]); @@ -342,7 +347,12 @@ describe("a cache: read's tier entry, and what drops it", () => { await runQuery(target, { orgId: ORG }, { ctx: createContext({ actor: allowedActor }) }); - const key = cacheKeyFor(queryName(target), { orgId: ORG }, [tag('post')]); + const key = cacheKeyFor( + queryName(target), + { orgId: ORG }, + [tag('post')], + readAuthority(allowedActor, 'actor'), + ); const entry = await getReadCache().get(key); expect(entry?.expiresAt).toBeLessThan(before + DEFAULT_READ_CACHE_TTL_MS); }); diff --git a/packages/query/src/read.ts b/packages/query/src/read.ts index 0a865ca64..5e9193a73 100644 --- a/packages/query/src/read.ts +++ b/packages/query/src/read.ts @@ -19,7 +19,7 @@ import { } from '@ultimat3/core'; import type { StandardSchemaV1 } from '@ultimat3/schema'; import { formatPath, validateAsync } from '@ultimat3/schema'; -import { cacheKeyFor, readFresh, readOnce, readThrough } from './cache'; +import { cacheKeyFor, readAuthority, readFresh, readOnce, readThrough } from './cache'; import { QueryForeignError, QueryInputInvalidError, QueryUnregisteredError } from './errors'; import { actorOf, guard } from './policy-gate'; import type { AnyQuery, AnyQueryDef, Query, QueryOptions, SourceOptions } from './query'; @@ -162,7 +162,12 @@ async function readRowsIn( // The source came from this query's own `sql()`, so its rows are TRow throughout — // which is what the typed overload above states, and this body never has to assert. const tags = def.cache?.tags ?? []; - const key = cacheKeyFor(name, raw, tags); + // The authority is part of the key on EVERY read, cached or not, because there is one key + // function and a second one beside it is what this package's own rule forbids. It costs the memo + // nothing — a memo is already per-ctx — and it is the whole of what the tier was missing: keyed + // on the name, the input and the tags alone, the process-wide tier handed one org's rows to the + // next org that asked for them. `actor` when the declaration named no scope, always. + const key = cacheKeyFor(name, raw, tags, readAuthority(ctx.actor, def.cache?.scope ?? 'actor')); // `fresh` is the caller saying no cache may answer this one — the memo included, a memo being // a cache whose lifetime is the request. It still *publishes* into the memo: this read is the // newest answer the request has, so the next plain read of the key joins it rather than the diff --git a/packages/query/src/stable.test.ts b/packages/query/src/stable.test.ts index e935e1c0b..2cf0b9a34 100644 --- a/packages/query/src/stable.test.ts +++ b/packages/query/src/stable.test.ts @@ -33,8 +33,25 @@ test('a bare token cannot be spelled by a string, so nothing collides the other } }); -test('an ordinary number is untouched — every existing cursor scope still resolves', () => { +test('the canonical form is untouched — the digest changed, the serialization did not', () => { expect(stableStringify({ limit: 50, ratio: 1.5, cursor: 'abc' })).toBe( '{"cursor":"abc","limit":50,"ratio":1.5}', ); }); + +/** + * A fingerprint is a SHARING key over input a client chooses — the read-cache entry two callers + * may be served from, and the scope a cursor is bound to. 32 bits of FNV-1a is a collision anyone + * finds offline in seconds, which is the same argument `@ultimat3/realtime` moved its `qid` on; + * `stableDigest` there is the primitive this matches, not the code. + */ +test('a fingerprint is SHA-256, 64 bits wide — never a 32-bit non-cryptographic hash', () => { + const digest = fingerprint({ q: 'all' }); + expect(digest).toMatch(/^[0-9a-f]{16}$/); + expect(digest).toBe( + new Bun.CryptoHasher('sha256') + .update(stableStringify({ q: 'all' })) + .digest('hex') + .slice(0, 16), + ); +}); diff --git a/packages/query/src/stable.ts b/packages/query/src/stable.ts index 849790ccd..56f6752c4 100644 --- a/packages/query/src/stable.ts +++ b/packages/query/src/stable.ts @@ -42,18 +42,22 @@ export function stableStringify(value: unknown): string { return `{${entries.join(',')}}`; } -/** FNV-1a/32 as hex. Identity of a query shape, never a security boundary. */ -export function fnv1a(input: string): string { - let hash = 0x811c9dc5; - for (let i = 0; i < input.length; i += 1) { - hash ^= input.charCodeAt(i); - hash = Math.imul(hash, 0x01000193) >>> 0; - } - return hash.toString(16).padStart(8, '0'); -} - +/** + * SHA-256, first 16 hex characters — the same primitive and the same width `@ultimat3/realtime`'s + * `stableDigest` and `@ultimat3/entity`'s `planScope` already chose, and for the same reason. + * + * A fingerprint is a SHARING key, not a checksum: it decides which read-cache entry two callers + * are served from and which scope a cursor is bound to, over input a client chooses. FNV-1a/32 — + * what this was — is 4x10^9 values, brute-forceable offline in seconds, so an attacker could mint + * an input that lands on another read's entry or another page's scope. It identifies, and here + * identifying IS the boundary. + * + * The canonical form above is unchanged, so the only thing that moved is the hash: a cursor issued + * before this fails its scope check as `X_CURSOR_INVALID` — cleanly, with "request the first page + * again" as its fix — and a warm read cache is cold once. + */ export function fingerprint(value: unknown): string { - return fnv1a(stableStringify(value)); + return new Bun.CryptoHasher('sha256').update(stableStringify(value)).digest('hex').slice(0, 16); } /** Column read that works for interfaces without an index signature. */ diff --git a/scripts/boundaries.test.ts b/scripts/boundaries.test.ts index 9c00199ba..0be3c90ea 100644 --- a/scripts/boundaries.test.ts +++ b/scripts/boundaries.test.ts @@ -353,24 +353,31 @@ describe('unit · shared/ is a leaf', () => { }); describe('unit · the source set is every directory a package ships from', () => { + // `collectSourceFiles(repoRoot())` walks the whole monorepo. Bun's 5s default covered that while + // the suite ran serially and stopped the moment `x test` began sharding across workers, because + // the shards compete for the same cores — and WHICH shard a file lands in depends on the file + // count, so it presents as an intermittent failure rather than a slow test. The scan is the + // point of the test, so the timeout is what moves. Same shape as `scripts/verify.test.ts`. + // // `packages/*/e2e` held real source that `filesize`, `errors` and this file all walked past. test('collectSourceFiles includes packages/*/e2e, not just src/', async () => { const paths = (await collectSourceFiles(repoRoot())).map((entry) => entry.path); expect(paths).toContain('packages/cli/src/bin.ts'); expect(paths.some((path) => /^packages\/[^/]+\/e2e\//.test(path))).toBe(true); expect(new Set(paths).size).toBe(paths.length); - }); + }, 30_000); /** * The other half of `errors` walks `@ultimat3/cli`'s `SOURCE_GLOBS`, which names `scripts/**`. * This list did not, so the 16 `X_*` codes declared here were held to the fix-line rule and not - * to the render-safety rule — one step, two answers to "what is source". + * to the render-safety rule — one step, two answers to "what is source". Same full-repo scan as + * the test above, same timeout for the same reason. */ test('collectSourceFiles includes scripts/, so both halves of the errors step see it', async () => { const paths = (await collectSourceFiles(repoRoot())).map((entry) => entry.path); expect(paths).toContain('scripts/error-render.ts'); expect(paths).toContain('scripts/lib/tiers.ts'); - }); + }, 30_000); }); const FLATTENER = 'packages/admin/src/entity-columns.ts'; diff --git a/scripts/manifest.test.ts b/scripts/manifest.test.ts index f24c4373e..4077a97ff 100644 --- a/scripts/manifest.test.ts +++ b/scripts/manifest.test.ts @@ -18,10 +18,15 @@ import { buildManifest, DEFAULT_OUT, frameworkManifestDrift, ownerOf } from './m let dir = ''; let fresh: FrameworkManifest; +// `buildManifest(repoRoot())` is a full manifest regeneration over 29 packages — one of the four +// full-repo scans named in `scripts/verify.test.ts`'s own comment, run once here for the whole +// file. Bun's 5s default covered that while the suite ran serially and stopped the moment +// `x test` began sharding across workers, because the shards compete for the same cores. The scan +// is the point of the hook, so the timeout is what moves. Same shape as `scripts/verify.test.ts`. beforeAll(async () => { dir = await mkdtemp(join(tmpdir(), 'ultimate-framework-manifest-')); fresh = await buildManifest(repoRoot()); -}); +}, 30_000); afterAll(async () => { await rm(dir, { recursive: true, force: true }); diff --git a/scripts/verify.test.ts b/scripts/verify.test.ts index 9c6b07e2c..e564e2ab2 100644 --- a/scripts/verify.test.ts +++ b/scripts/verify.test.ts @@ -30,6 +30,12 @@ describe('unit · the repo gate is the CLI gate', () => { expect(Object.keys(HOST_CHECKS)).toEqual(['boundaries', 'errors', 'manifest', 'roadmap']); }); + // `errorCodeDocs` calls the CLI's process-wide `registeredErrorCodes()`, which dynamically + // imports every @ultimat3/* package to build the registry — real work regardless of how small + // `dir` is. Bun's 5s default covered that while the suite ran serially and stopped the moment + // `x test` began sharding across workers, because the shards compete for the same cores. The + // import walk is the point of the call, so the timeout is what moves. Same shape as + // `packages/cli/src/error-contract.test.ts`'s `this repo` describe block. test('the error reference is enforced through the errors step', async () => { const dir = await mkdtemp(join(tmpdir(), 'ultimate-verify-docs-')); try { @@ -45,7 +51,7 @@ describe('unit · the repo gate is the CLI gate', () => { } finally { await rm(dir, { recursive: true, force: true }); } - }); + }, 30_000); test('a documented code no package registers fails the same step', async () => { const dir = await mkdtemp(join(tmpdir(), 'ultimate-verify-registry-')); diff --git a/wiki/Error-Codes.md b/wiki/Error-Codes.md index 715148485..02f1be7a4 100644 --- a/wiki/Error-Codes.md +++ b/wiki/Error-Codes.md @@ -161,6 +161,7 @@ A denial is `X_FORBIDDEN`, above — `@ultimat3/policy` owns it and every surfac | `X_QUERY_POLICY_MISSING` | a query was registered without a policy | same, for reads | add `policy: can('')` to the query | | `X_QUERY_NOT_PAGEABLE` | a read returned rows with no id, so a cursor cannot name a position | a projection or aggregate that drops the primary key — the id is the tiebreak that makes the sort order total | return the key from the query's `sql:`, e.g. `db.posts.select({ id: true, … })` | | `X_CURSOR_VALUE_UNSUPPORTED` | a sort value cannot be carried in a cursor | a read ordered by a column whose values are objects, or by a number that is `NaN`/`±Infinity` — a cursor is JSON, and `Date` and `bigint` are the only non-JSON types it tags and revives. Raised where the cursor is MINTED, not where one arrives: the mistake is the read's own `orderBy`, so no retry and no fresh first page repairs it | order by a scalar column — `.orderBy('createdAt')` or `.orderBy('id')` — and project the composite value into the row instead | +| `X_QUERY_CACHE_TTL_INVALID` | a query declares a cache `ttlMs` no tier can hold | `cache: { ttlMs: Infinity }`, `0`, a negative value or `NaN`. Judged at `query()`, in the file that declared it, rather than on the first read: the tiers already refuse the value with `X_CACHE_TTL_INVALID`, so before this the mistake compiled, passed review, and made **every** read of that query fail permanently in production. The cause echoes the value rather than the query name — `query()` runs before `registerQueries()` stamps a name, exactly as `X_QUERY_INPUT_UNENCODABLE` does | pass a positive, finite `ttlMs`, or drop the `cache` block — "do not cache" is expressed by not declaring one | | `X_QUERY_INPUT_UNENCODABLE` | a query input cannot be carried in a query string | a read declaring a nested `t.object`/`t.record`/`t.money` member, an array or union of one, a REQUIRED `t.nullable(...)` member, or a top-level input that is not an object. A read is served as `GET /_x/query/`, so its input is characters: the typed client would encode a structure as JSON text and skip a `null`, and `coerceQuery` has no inverse for either. Raised at `query()`, in the file that declared it | flatten the key into scalar arguments (`status: t.string, limit: t.number`), spell an absent value as `.optional()` rather than `t.nullable(...)`, or declare it as an `action()` if it really needs a JSON body | ## Auth and sessions @@ -264,6 +265,7 @@ synthesizes `https://ultimate.dev/errors/` for a code no page here documen | `X_JOB_TIMEOUT` | a job exceeded its wall-clock limit | one long step | raise `timeout`, or split the work into more `step.run()` calls | | `X_JOB_CONCURRENCY_UNENFORCEABLE` | `job.concurrency` is declared and cannot be enforced | a jobs driver with no lease store — the cap then holds per **process** and the fleet runs `concurrency × replicas`. `job.concurrency` was documented, in the manifest, and enforced by nothing; the worker now refuses to start rather than run with the wrong number, which is what axiom 3 means by a convention that is not a build error not existing | remove `concurrency` from the job `cause` names, or set `jobs: { driver: 'postgres' }` in `app.config.ts` | | `X_JOB_LEASE_LOST` | the queue took this job back mid-run | `x jobs cancel` wrote a terminal state, or this worker's visibility lease lapsed and another worker re-claimed the row. Its own code and not `X_ABORTED` because the response differs: `X_ABORTED` is "your deadline passed, make the work smaller", this is "somebody else owns this run now, stop writing to it" | `x jobs show --json` | +| `X_JOB_SLOT_LOST` | the fleet concurrency slot this run held was taken by another worker | this worker stalled past the slot TTL and a second worker renewed slot 0 for itself, so `job.concurrency` was about to be exceeded. Its own code and not `X_JOB_LEASE_LOST` because the queue may still consider this worker the owner of the *job* — the two are different rows on different clocks (`x_job_leases` vs `x_jobs.visible_at`), and only one of them was lost. The run is aborted rather than left to double up | `x jobs show --json` — a run that keeps losing its slot is slower than its slot TTL, so raise the TTL or make the job shorter | | `X_JOB_NOT_CANCELLABLE` | the job cannot be cancelled | `x jobs cancel` reached a job that already finished, or an id no queue holds — not a failure of the command, but never a silent success either: an operator cancelling a runaway pass has to know whether they stopped it or missed it. Also raised by a driver with no `introspect.cancel` (the redis and nats stubs, and any hand-rolled driver) | `x jobs ls --state running --json` — for a driver that cannot cancel one job, set `jobs: { driver: 'postgres' }` in `app.config.ts`, then `x jobs cancel --json` | | `X_OUTBOX_NO_TX` | enqueue outside a transaction | `.enqueue` called with no ambient tx | wrap in `ctx.tx(async (tx) => …)`, or enqueue with `{ outbox: false }` deliberately | | `X_DRIVER_UNAVAILABLE` | the queue driver is unreachable | Redis/NATS down, or the URL is wrong | `x doctor --json`; check the driver URL in `app.config.ts` | diff --git a/wiki/Known-Gaps.md b/wiki/Known-Gaps.md index 8f1126304..a85fa1a83 100644 --- a/wiki/Known-Gaps.md +++ b/wiki/Known-Gaps.md @@ -18,6 +18,8 @@ A reference manual that hides these is lying to the reader. Source of truth is t | `@ultimat3/flags` is not on npm | the repository versions all 29 packages in lockstep, but **28 are published**: the registry answers 404 for `@ultimat3/flags` at every version, verified `As of 2026-08`, while the other 28 resolve at 1.2.0. So `bun add @ultimat3/flags` fails, and `defineFlag` / `isEnabled` / `flagsReport` are reachable only from a checkout — the reference app depends on it through the workspace, which is why nothing in the repo notices. Nothing in the package opts out: it declares `publishConfig.access: public`. **Not in `CHANGELOG.md`'s list** | vendor the ten source files of `packages/flags/src` into your app, or wrap your own switch behind one function and swap it later — the primitive shape is `(subject) => boolean`, so an app-local `isEnabled` is a drop-in → [Configuration](Configuration) | | Planned CLI commands with flags | a planned command's spec declares no flags, so `x env check --fix` fails at the **parser** with `X_CLI_BAD_FLAG` rather than the honest `X_NOT_IMPLEMENTED` | run the flagless form to see the real message → [CLI reference](CLI-Reference) | | No test file is typechecked | all 29 package `tsconfig.json`s carry `"exclude": ["src/**/*.test.ts"]`, so `bun run typecheck` — a `tsc -b` — never reads a `.test.ts` in `packages/`, and the gate's `typecheck` step reports green over every one of them. Measured `As of 2026-08`: dropping the exclusion surfaces **282 errors across 110 files in 24 packages** (worst: `entity` 60, `cli` 55, `render` 36), overwhelmingly mechanical — `TS4111` index-signature access, `TS2345`/`TS2769` argument and overload mismatches, `TS2379` under `exactOptionalPropertyTypes`. `packages/*/e2e/**` is in no package's `include` either, so those three directories compile nowhere at all. **Recorded in `CHANGELOG.md` under `[Unreleased]`.** `scripts/` is exempt as of this change — it has no such `exclude`, so its tests do typecheck | nothing to work around at runtime: the tests run, they are simply not compiler-checked. Typecheck one package's tests directly with `bunx tsc --noEmit` over a config that drops the `exclude` | +| The cache fill fence is **per process** | a read-through fill re-checks a fence before writing, so an invalidation landing mid-read can no longer be overwritten by pre-write rows — but the fence is one process's memory. Two pods still interleave: a load on pod A, a write and a bust on pod B, and A's fill is not covered. On the shared Redis tier the membership re-check narrows that to "the value is deleted rather than orphaned", so the stale row does not outlive its own invalidation there; a **process-local** tier on pod A can still hold it for the TTL. A genuine cross-node fence needs a Redis-side epoch and a wire-format change, which is a bigger change than the one this closes | give a `cache:` query a TTL you can afford to be wrong for on a single pod, or run the shared tier as the only cached tier for reads that must not go stale across nodes | +| A long `backfill()` retains one step name per batch | `createStepRunner`'s `claimed` Set is the authority for `X_STEP_DUPLICATE`, and it is deliberately unbounded: a 5M-row sweep at `batch: 250` holds 20,000 short strings (~1–2 MB) for the life of the attempt, released when it ends. `MAX_TRACE_NAMES` bounds the *reported* trace, not the membership set. Left as is on purpose — bounding the set would let a duplicate step name through after 200 batches, and silently replaying a step is the worse failure | nothing at runtime; raise `batch` if the attempt is long enough for the retention to matter | ## Found while writing the tutorials