From e0e8ddb13dcd680a0d7f02a9e958889089ddc96e Mon Sep 17 00:00:00 2001 From: sebi Date: Sat, 10 Oct 2026 16:58:54 -0500 Subject: [PATCH 1/3] fix(realtime): NATS is not a boot dependency of a role that only publishes; a sync node without the bus fails in 15 s, coded; a publish with no live connection is refused, never queued MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Under realtime.transport 'nats' every role awaited the first dial before it bound a socket, and openNatsClient set waitOnFirstConnect, under which nats@2.29.3 retries a failed first dial forever. A web, worker or scheduler pod that restarted while NATS was down never served a page, for a bus those roles only send "re-read" events to. - cli: runtime-bus.ts decides by role. sync and the replicator await the dial (15 s, retried on backoff, then X_TRANSPORT_UNAVAILABLE naming the server, the wait and the last attempt); web, worker, scheduler and the dev MCP host dial in the background and boot. realtime.enabled: false never waits. The boot line carries bus=nats(up|connecting)|in-process. - realtime: NatsTransport.connectInBackground() and connect({ withinMs }); the first-dial retry is the transport's own loop, which close() ends. A publish while the client reconnects is refused instead of buffered without bound by the library. The presence bucket is asserted at the dial only for a node that serves presence (presenceBucket: 'first-use'). - core: a readiness check may be degradable ({ onFailure: 'degraded' }): reported by name, never a 503 on /readyz, a 503 on /readyz?deep=1. The transport check is degraded on publishing roles, failing on sync. - serve-graph pins raised 938 → 939 and 1065 → 1066 for runtime-bus.ts. Co-Authored-By: Claude Opus 5.5 --- CHANGELOG.md | 12 +- docs/ops/01-kubernetes.md | 20 ++ packages/cli/CLAUDE.md | 2 +- packages/cli/src/dev-boot.ts | 9 +- packages/cli/src/mcp-host.ts | 3 +- packages/cli/src/runtime-bus.live.test.ts | 291 ++++++++++++++++++ packages/cli/src/runtime-bus.test.ts | 210 +++++++++++++ packages/cli/src/runtime-bus.ts | 158 ++++++++++ packages/cli/src/runtime-services.ts | 62 ++-- packages/cli/src/serve-boot.ts | 5 +- packages/cli/src/serve-graph.test.ts | 10 +- packages/cli/src/serve-types.ts | 5 + packages/cli/src/serve.live.test.ts | 2 + packages/cli/src/serve.ts | 9 +- packages/core/README.md | 5 +- packages/core/src/index.ts | 6 +- packages/core/src/lifecycle-readiness.test.ts | 37 +++ packages/core/src/lifecycle-readiness.ts | 45 ++- packages/core/src/lifecycle.ts | 14 +- packages/realtime/CLAUDE.md | 13 +- packages/realtime/README.md | 17 +- packages/realtime/src/nats-lib-client.ts | 12 +- .../src/nats-transport-background.test.ts | 274 +++++++++++++++++ packages/realtime/src/nats-transport.test.ts | 14 +- packages/realtime/src/nats-transport.ts | 136 +++++++- packages/realtime/src/server.ts | 2 + packages/realtime/src/transport-env.test.ts | 76 +++++ packages/realtime/src/transport-env.ts | 64 +++- wiki/Deployment.md | 4 +- wiki/Error-Codes.md | 2 +- wiki/Realtime.md | 24 +- wiki/Tutorial-05-Deploy-Free.md | 2 +- 32 files changed, 1449 insertions(+), 96 deletions(-) create mode 100644 packages/cli/src/runtime-bus.live.test.ts create mode 100644 packages/cli/src/runtime-bus.test.ts create mode 100644 packages/cli/src/runtime-bus.ts create mode 100644 packages/realtime/src/nats-transport-background.test.ts diff --git a/CHANGELOG.md b/CHANGELOG.md index 65925e201..df66de720 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -8,7 +8,17 @@ Semver applies from 1.0.0. A breaking change to a documented API needs a major ## [Unreleased] -Nothing yet. +### Fixed + +Tier 0 — core. Tier 3 — realtime. Tier 5 — cli. + +- **NATS is no longer a boot dependency of a role that only publishes to it.** Under `realtime: { transport: 'nats' }` every role awaited the first dial before it bound a socket, and that dial never gave up: `openNatsClient` set `waitOnFirstConnect`, under which nats@2.29.3 retries a failed first dial past its attempt counter, forever. A `web`, `worker` or `scheduler` pod that restarted while NATS was down (an OOM, a node drain, a rollout, a scale-up) therefore hung in boot: pages, webhooks and jobs were down for a bus those roles only send "re-read" events to, and `health.readiness: 'process'` could not help because no listener existed yet. The role now decides (`runtime-bus.ts`, `selectTransport(env, realtime, { use })`): `sync` and the replicator still need the bus and await it; `web`, `worker`, `scheduler` and the dev MCP host dial it in the background on a jittered backoff (500 ms doubling to 30 s) and boot at once. Nothing to change in an app. The table is [Realtime → What each role needs from the bus](https://github.com/developerz-ai/ultimate/wiki/Realtime#what-each-role-needs-from-the-bus). +- **A `sync` node or a replicator without the bus fails fast and says why.** The dial is retried for 15 s (`BUS_CONNECT_WAIT_MS`) and then refused with `X_TRANSPORT_UNAVAILABLE`, whose cause names the server, the wait and the last attempt's own failure, and whose fix names the variable `realtime.urlEnv` points at. It used to sit silent until something killed it. +- **A publish with no live connection is refused at once, never queued.** While the background dial is in flight, `publishChannelEvent` and the cache-invalidation broadcast reject with `X_TRANSPORT_UNAVAILABLE` immediately. A publish made while the client is *reconnecting* is refused the same way, in every role: the `nats` client buffered it without bound and replayed the lot when the server returned, minutes late. Publishing resumes with no restart when the bus is back, on first connect and after every loss. **A missed cache bust is not replayed**: the replica that made it, Redis and the CDN are cleared as before, the broadcast lands in the report's `errors` (`cache.invalidate.partial`), and another replica's in-process copy waits for its TTL. +- **Only a `sync` node requires JetStream at boot.** The presence bucket was asserted on every dial of every role, so a publisher failed on a nats-server without `-js`. It is asserted at the dial where presence is served and on first use of `transport.shared` everywhere else (`NatsTransportOptions.presenceBucket`). +- **A dead bus no longer takes a publishing role out of the ingress.** `/readyz` in the default `'dependencies'` mode answered 503 on every `web` pod at once while NATS was down. A readiness check now has a third answer, `'degraded'` (`registerReadinessCheck(name, check, { onFailure: 'degraded' })`, `ReadinessStatus`): reported by name, never a 503 on `/readyz` in either mode, and a 503 on `/readyz?deep=1`. The `transport` check is `degraded` on `web`, `worker` and `scheduler` and stays `failing` on `sync` and the replicator. A monitor that must see a bus outage on a web pod reads `?deep=1`, as [Deployment](https://github.com/developerz-ai/ultimate/wiki/Deployment) already says to. +- **The boot line says where the bus is.** `ultimate started` carries a `bus` field — `nats(up)`, `nats(connecting)` or `in-process` (`ServedApp.bus`) — and `ultimate bus` is logged with `bus: 'nats(up)'` each time the connection lands. A dial that keeps failing is reported on attempts 1, 2, 4, 8, … rather than once per attempt. +- **`realtime.enabled: false` never waits for the bus.** With no realtime role to start, no process of such an app awaits the dial, `ROLE=sync` included (it is refused by `rolesUnderRealtime`, as before, and now without first waiting on NATS). The connection is still opened in the background under `transport: 'nats'`, because cache invalidation between replicas crosses it. ## 27.6.1 - 2026-10-10 diff --git a/docs/ops/01-kubernetes.md b/docs/ops/01-kubernetes.md index ac1f8c8ae..bcfb8178d 100644 --- a/docs/ops/01-kubernetes.md +++ b/docs/ops/01-kubernetes.md @@ -110,6 +110,26 @@ To turn realtime on: | 3 | Enable exactly one replicator per database: `roles.replicator.enabled: true` (chart) or a `ROLE=replicator` service (Compose) | | 4 | Enable sync: `roles.sync.enabled: true`, or `replicas: 1` on the Compose `sync` service. The chart's Ingress routes `/_x/sync` only while sync is enabled. The node refuses a socket from a page on another ORIGIN — scheme, host and port, compared exactly (`X_SOCKET_ORIGIN_REFUSED`); a socket is refused when its origin is not `APP_URL`'s when one is declared; with none declared, not the origin the node was reached on. With the Ingress enabled the chart sets `APP_URL` on the sync role from `ingress.host` (`https` when `ingress.tls`), and a declared origin is the whole list. `env.APP_URL` wins when set: state the page's origin there when the pages are served on another host than `ingress.host` | +### NATS is a boot dependency of `sync` and the replicator only + +`As of 2026-10`. Until then every role awaited the first dial, and the client library retried that +dial forever: a `web`, `worker` or `scheduler` pod that restarted while NATS was down (an OOM, a +node drain, a rollout, a scale-up) hung before it bound a socket, so pages, webhooks and jobs went +down for a bus those roles only publish "re-read" events to. + +| Role | NATS down at pod start | NATS down while running | Needs JetStream (`-js`) | +|---|---|---|---| +| `sync` | retries for 15 s, then exits with `X_TRANSPORT_UNAVAILABLE`; the kubelet restarts it | not ready (`transport: failing`); reconnects on its own | yes, at boot | +| `replicator` | same | same | no | +| `web`, `worker`, `scheduler` | **boots and serves**; dials in the background (jittered, 500 ms doubling to 30 s) | **stays ready**; publishes are refused with `X_TRANSPORT_UNAVAILABLE` until it is back, then resume with no restart | no | + +What to watch: `/readyz?deep=1` answers 503 while `checks.transport` is `degraded` — the probe on +`/readyz` stays 200, by design. The boot line carries the state (`"msg":"ultimate started",…,"bus":"nats(connecting)"`) +and `"msg":"ultimate bus","bus":"nats(up)"` is logged when the connection lands. While the bus is away a cache +invalidation still clears the replica that made it, Redis and the CDN; the other replicas' in-process +copies wait for their TTL, and nothing is replayed afterwards. Do not add NATS to a `web` pod's +`initContainers` or `dependsOn`: that rebuilds the dependency this removes. + ### Replication is a cluster-wide grant `REPLICATION` is a role attribute of the whole Postgres **cluster**, not of one database. A diff --git a/packages/cli/CLAUDE.md b/packages/cli/CLAUDE.md index aa509272d..45dceb034 100644 --- a/packages/cli/CLAUDE.md +++ b/packages/cli/CLAUDE.md @@ -91,7 +91,7 @@ Commands: `bun test packages/cli` (from the repo root — the test preload lives | `module-imports.ts` | the files a module's source imports, resolved once for both graphs: `referenced` (reload) and `evaluated` (document) | | `cmd-dev.ts` / `dev-boot.ts` / `dev-rebuild.ts` / `dev-route-table.ts` | `x dev`: the command (`cmd-dev.ts`, re-exports `startDev`); the boot — every role in one process, `/_x`, the watcher (`dev-boot.ts`); one save rebuilt as one generation (`dev-rebuild.ts`) | | `runtime-bindings.ts` | which service each binding points at (embedded or external); events follow `realtime.transport` / `urlEnv` | -| `runtime-queue.ts` / `runtime-services.ts` | the db + queue pair; everything else and every ambient accessor | +| `runtime-queue.ts` / `runtime-services.ts` / `runtime-bus.ts` | db + queue; every other accessor; the bus | | `framework-schema-apply.ts` / `framework-schema-stamp.ts` | the framework tables: `ROLE=migrate`, `x dev` and every CLI command APPLY them in one transaction behind `MIGRATION_LOCK_KEY` (`pg_advisory_xact_lock`) with a bounded `lock_timeout`, then stamp the build on `x_jobs`' table comment; a serving role on an external database runs no DDL and VERIFIES the stamp (`X_FRAMEWORK_SCHEMA_UNAPPLIED`, a major skew is a warning). A comment, never a table: a new framework table moves every app's schema dump | | `runtime-isr.ts` | the ISR controller both boots serve through, ATTACHED to `invalidateTags` and released on stop (`attachedIsr`); `appRoutes` without one builds and attaches its own | | `runtime-mfa-warning.ts` / `runtime-idempotency-scope.ts` | boot warnings an operator can act on: unsealed MFA secrets (web role, `x auth seal-mfa`), a per-process idempotency store after the app loaded | diff --git a/packages/cli/src/dev-boot.ts b/packages/cli/src/dev-boot.ts index 186fafc2a..3cb964381 100644 --- a/packages/cli/src/dev-boot.ts +++ b/packages/cli/src/dev-boot.ts @@ -113,7 +113,14 @@ export async function startDev(options: StartDevOptions): Promise { // boot passed nothing here and built its own embedded disk, so an app's `/_storage` routes and its // actions wrote to two different places in `x dev` and to one in production. const appRuntime = await loadAppRuntime(options.root); - const runtime: RunningServices = await startServices(resolved, env, appRuntime); + // The roles decide whether this boot waits for the bus, exactly as a container's one role does. + const runtime: RunningServices = await startServices( + resolved, + env, + appRuntime, + 'apply', + options.roles ?? DEV_ROLES, + ); // The events binding the boot line reports is the bus the runtime chose, read off it. const services = withRealtimeEvents(resolved, env, runtime.realtime); // `serve.ts`'s `releaseBoot` shape: everything acquired from here on is released, newest first, diff --git a/packages/cli/src/mcp-host.ts b/packages/cli/src/mcp-host.ts index 7993d1038..0ecf7ef3b 100644 --- a/packages/cli/src/mcp-host.ts +++ b/packages/cli/src/mcp-host.ts @@ -105,7 +105,8 @@ export function lazyServices(input: DevHostInput): LazyServices { // one connection wedged every later tool call in the session with that first error, and the only // way out was restarting the host — `startServices` unwinds everything it started before it // rejects, so there is nothing left over for a second attempt to collide with. - const boot = retryMemo(() => startServices(services, input.env)); + // `[]`: this host starts no role, so it only ever publishes to the bus and never waits for it. + const boot = retryMemo(() => startServices(services, input.env, undefined, 'apply', [])); let closed = false; return { services, diff --git a/packages/cli/src/runtime-bus.live.test.ts b/packages/cli/src/runtime-bus.live.test.ts new file mode 100644 index 000000000..17601bfe3 --- /dev/null +++ b/packages/cli/src/runtime-bus.live.test.ts @@ -0,0 +1,291 @@ +// A web role and a real nats-server that is not there. The unit suite proves the contract against +// an in-memory bus; only a real client shows what the library does while it cannot reach a server +// — it retries a first dial for minutes and QUEUES publishes made during a reconnect — which is +// exactly what made NATS a boot dependency of a role that only publishes to it. +// +// The server is shared and not this file's to stop, so "down" is a TCP relay that is not +// listening: the url the runtime dials is the relay's port, and the subscriber standing in for a +// `sync` node dials the server directly. +// +// Skips unless a server is configured. Locally: +// +// docker run -d --name x-nats -p 4222:4222 nats:2.11-alpine -js +// TEST_NATS_URL=nats://localhost:4222 bun test packages/cli/src/runtime-bus.live.test.ts + +import { afterEach, describe, expect, test } from 'bun:test'; +import { mkdtempSync, rmSync, writeFileSync } from 'node:fs'; // why: Bun has no mkdtemp and no recursive remove. +// why: Bun exposes no tmpdir(), so only node:os answers the platform temp root. +import { tmpdir } from 'node:os'; +// why: Bun exposes no path-join primitive; Bun.file and import() take one already joined. +import { join } from 'node:path'; +import type { HealthReport } from '@ultimat3/core'; +import { isUltimateError, resetLifecycle } from '@ultimat3/core'; +import { allow } from '@ultimat3/policy'; +import { channel, clearChannels } from '@ultimat3/realtime'; +import type { TransportSelection } from '@ultimat3/realtime/server'; +import { publishChannelEvent, selectTransport } from '@ultimat3/realtime/server'; +import { advanceClock } from '@ultimat3/testing'; +import type { RunningRoles } from './role-start'; +import { startRoles } from './role-start'; +import { resolveServices } from './runtime-bindings'; +import { busLabel } from './runtime-bus'; +import type { RunningServices } from './runtime-services'; +import { startServices } from './runtime-services'; + +const url = Bun.env['TEST_NATS_URL']; +const NATS = { enabled: true, transport: 'nats', urlEnv: 'NATS_URL' } as const; + +/** A boot, a first dial's backoff and a reconnect's: seconds each, and the curve is jittered. */ +const TIMEOUT_MS = 120_000; + +interface Leg { + peer: { write(bytes: Uint8Array): number; end(): void } | undefined; + readonly early: Uint8Array[]; +} + +interface Relay { + readonly port: number; + /** Stop listening and end every relayed connection: the server is gone. */ + down(): void; + /** Listen again on the same port: the server is back. */ + up(): void; +} + +/** A TCP relay to the real server on one fixed port, which a test can take down and bring back. */ +function relayTo(host: string, port: number): Relay { + const clients = new Set<{ end(): void }>(); + const listen = (on: number) => + Bun.listen({ + hostname: '127.0.0.1', + port: on, + socket: { + open(client) { + client.data = { peer: undefined, early: [] }; + clients.add(client); + // Not awaited: `open` is synchronous, and the server speaks first (INFO) once this lands. + void Bun.connect({ + hostname: host, + port, + socket: { + open(upstream) { + upstream.data = { peer: client, early: [] }; + client.data.peer = upstream; + for (const bytes of client.data.early.splice(0)) upstream.write(bytes); + }, + data(_upstream, bytes) { + client.write(bytes); + }, + close() { + client.end(); + }, + error() { + client.end(); + }, + }, + }).catch(() => client.end()); + }, + data(client, bytes) { + // Copied: the runtime reuses the chunk's buffer once this handler returns. + if (client.data.peer === undefined) client.data.early.push(Uint8Array.from(bytes)); + else client.data.peer.write(bytes); + }, + close(client) { + clients.delete(client); + client.data.peer?.end(); + }, + }, + }); + // The port is chosen by listening once, then held by number: "down" is nobody listening on it. + let listener: ReturnType | undefined = listen(0); + const fixed = listener.port; + return { + port: fixed, + down() { + listener?.stop(true); + listener = undefined; + for (const client of [...clients]) client.end(); + }, + up() { + listener ??= listen(fixed); + }, + }; +} + +let running: RunningRoles | undefined; +let runtime: RunningServices | undefined; +let root: string | undefined; +let relay: Relay | undefined; +let syncSide: TransportSelection | undefined; + +afterEach(async () => { + await running?.stop(); + running = undefined; + await runtime?.stop().catch(() => undefined); + runtime = undefined; + await syncSide?.transport.close(); + syncSide = undefined; + relay?.down(); + relay = undefined; + if (root !== undefined) rmSync(root, { recursive: true, force: true }); + root = undefined; + clearChannels(); + resetLifecycle(); +}, TIMEOUT_MS); + +const codeOf = (value: unknown): string => + isUltimateError(value) ? value.code : `not an UltimateError: ${String(value)}`; + +/** + * Poll in real time, and move the frozen clock with it. The library redials a server once + * `lastConnect + wait <= Date.now()`, and the test preload freezes `Date.now()` — so without the + * second half no positive backoff is ever reached, and this boot's backoff is the production one. + */ +const until = async (done: () => boolean | Promise, seconds: number): Promise => { + const deadline = Bun.nanoseconds() + seconds * 1_000_000_000; + while (!(await done()) && Bun.nanoseconds() < deadline) { + await Bun.sleep(50); + advanceClock(50); + } +}; + +interface Readyz { + readonly status: number; + readonly body: HealthReport; +} + +const readyz = async (base: string, query = ''): Promise => { + const response = await fetch(`${base}/readyz${query}`); + return { status: response.status, body: (await response.json()) as HealthReport }; +}; + +describe.skipIf(url === undefined)('a web role and a NATS that is not there', () => { + test( + 'boots and serves with the bus down, refuses publishes typed, and resumes on its own — twice', + async () => { + const target = new URL(url ?? ''); + relay = relayTo(target.hostname, Number(target.port === '' ? 4222 : target.port)); + relay.down(); + root = mkdtempSync(join(tmpdir(), 'x-bus-down-')); + writeFileSync( + join(root, 'app.config.ts'), + "export const config = { name: 'bus-down', realtime: { enabled: true, transport: 'nats', urlEnv: 'NATS_URL' } };\n", + ); + const env = { ULTIMATE_ENV: 'development', NATS_URL: `nats://127.0.0.1:${relay.port}` }; + const feed = channel('bus-live-feed', { + params: ['orgId'], + catchUp: { name: 'busLiveFeedRead' }, + events: true, + policy: allow('public'), + }); + const publish = (): Promise => + publishChannelEvent(feed, { orgId: 'o1' }, { kind: 'changed' }).then( + () => undefined, + (error: unknown) => error, + ); + + // NATS DOWN, and the web role boots anyway. Before this landed the line below sat in the + // library's first-dial budget — ten attempts on a 30 s backoff — and then rejected. + const bootedAt = performance.now(); + runtime = await startServices(resolveServices(root, env), env, undefined, 'apply', ['web']); + running = await startRoles({ + roles: ['web'], + port: 0, + metricsPort: 0, + buildId: 'build-1', + runtime, + routes: [], + env: {}, + }); + expect(performance.now() - bootedAt).toBeLessThan(30_000); + const base = running.url ?? expect.unreachable('the web role reported no url'); + expect(runtime.busUse).toBe('publish'); + expect(busLabel(runtime.transport)).toBe('nats(connecting)'); + + // It serves: ready for the probe, `degraded` by name, and a 503 only for the deep reading. + const shallow = await readyz(base); + expect(shallow.status).toBe(200); + expect(shallow.body.checks['transport']).toBe('degraded'); + expect(shallow.body.checks['database']).toBe('ok'); + expect((await readyz(base, '?deep=1')).status).toBe(503); + + // A publish is the typed refusal an app's `catch` already handles, and it is immediate. + const refusedAt = performance.now(); + expect(codeOf(await publish())).toBe('X_TRANSPORT_UNAVAILABLE'); + expect(performance.now() - refusedAt).toBeLessThan(1_000); + + // The subscriber a `sync` node is: on the real server, with the presence bucket it needs. + syncSide = selectTransport({ NATS_URL: url }, NATS, { use: 'sockets' }); + await syncSide.connect(); + const heard: string[] = []; + await syncSide.transport.subscribe('x.channel.bus-live-feed.>', (payload) => { + heard.push(payload); + }); + + // NATS UP: no restart, and inside the dial's backoff a publish reaches the sync side. + relay.up(); + const serving = runtime; + await until(() => busLabel(serving.transport) === 'nats(up)', 90); + expect(busLabel(serving.transport)).toBe('nats(up)'); + expect(await publish()).toBeUndefined(); + await until(() => heard.length === 1, 10); + expect(heard).toHaveLength(1); + expect((await readyz(base, '?deep=1')).status).toBe(200); + + // NATS DIES MID-FLIGHT. The process stays up and ready, and a publish is refused at once + // rather than queued in the client for whenever the server returns. + relay.down(); + await until(() => busLabel(serving.transport) === 'nats(connecting)', 30); + expect(busLabel(serving.transport)).toBe('nats(connecting)'); + const droppedAt = performance.now(); + expect(codeOf(await publish())).toBe('X_TRANSPORT_UNAVAILABLE'); + expect(performance.now() - droppedAt).toBeLessThan(1_000); + const during = await readyz(base); + expect(during.status).toBe(200); + expect(during.body.checks['transport']).toBe('degraded'); + + // AND COMES BACK: publishing resumes, and what was refused in the gap is not replayed. + relay.up(); + await until(() => busLabel(serving.transport) === 'nats(up)', 90); + expect(busLabel(serving.transport)).toBe('nats(up)'); + expect(await publish()).toBeUndefined(); + await until(() => heard.length === 2, 10); + await Bun.sleep(200); + expect(heard).toHaveLength(2); + }, + TIMEOUT_MS, + ); + + test( + 'a sync role with the bus down refuses its boot, coded, inside the bounded wait', + async () => { + relay = relayTo('127.0.0.1', 1); + relay.down(); + root = mkdtempSync(join(tmpdir(), 'x-bus-down-')); + writeFileSync( + join(root, 'app.config.ts'), + "export const config = { name: 'bus-down', realtime: { enabled: true, transport: 'nats', urlEnv: 'NATS_URL' } };\n", + ); + const env = { ULTIMATE_ENV: 'development', NATS_URL: `nats://127.0.0.1:${relay.port}` }; + + const startedAt = performance.now(); + const refused = await startServices(resolveServices(root, env), env, undefined, 'apply', [ + 'sync', + ]).then( + (started) => { + runtime = started; + return undefined; + }, + (error: unknown) => error, + ); + + expect(codeOf(refused)).toBe('X_TRANSPORT_UNAVAILABLE'); + const said = isUltimateError(refused) ? `${refused.cause} | ${refused.fix}` : ''; + expect(said).toContain(`127.0.0.1:${relay.port}`); + expect(said).toContain('NATS_URL'); + expect(said).toContain('serves sockets'); + // The wait is 15 s, plus the embedded database's boot; never the library's minutes. + expect(performance.now() - startedAt).toBeLessThan(45_000); + }, + TIMEOUT_MS, + ); +}); diff --git a/packages/cli/src/runtime-bus.test.ts b/packages/cli/src/runtime-bus.test.ts new file mode 100644 index 000000000..2418cadea --- /dev/null +++ b/packages/cli/src/runtime-bus.test.ts @@ -0,0 +1,210 @@ +// The bus as one boot holds it. What is proven here is the per-role contract: a role that only +// publishes boots with NATS down and reports the bus `degraded`; a role that serves sockets +// refuses, fast and coded. Until 2026-10 every role awaited the dial, so a web pod that restarted +// during a NATS outage never served a page. + +import { afterEach, beforeEach, describe, expect, test } from 'bun:test'; +import { + isUltimateError, + markReady, + readinessCheckCount, + readyzPayload, + resetLifecycle, +} from '@ultimat3/core'; +import { allow } from '@ultimat3/policy'; +import { channel, clearChannels } from '@ultimat3/realtime'; +import type { SelectTransportOptions } from '@ultimat3/realtime/server'; +import { FakeNatsBroker, fakeNatsConnect, publishChannelEvent } from '@ultimat3/realtime/server'; +import { busLabel, busUseFor, selectBus } from './runtime-bus'; + +const ENV = { NATS_URL: 'nats://bus.test:4222' } as const; +const NATS = { enabled: true, transport: 'nats', urlEnv: 'NATS_URL' } as const; +const MEMORY = { enabled: true, transport: 'memory', urlEnv: undefined } as const; + +const codeOf = (value: unknown): string => + isUltimateError(value) ? value.code : `not an UltimateError: ${String(value)}`; + +const caught = (promise: Promise): Promise => + promise.then( + () => undefined, + (error: unknown) => error, + ); + +const waitFor = async (done: () => boolean, polls = 500): Promise => { + for (let poll = 0; poll < polls && !done(); poll += 1) await Bun.sleep(2); +}; + +const fake = (broker: FakeNatsBroker): SelectTransportOptions => ({ + connect: fakeNatsConnect(broker), + backoff: { baseMs: 2, maxMs: 2, factor: 1, jitter: 'none' }, + onError: () => undefined, +}); + +beforeEach(() => resetLifecycle()); +afterEach(() => { + resetLifecycle(); + clearChannels(); +}); + +describe('busUseFor', () => { + test('a sync node serves sockets, a replicator feeds them, every other role only publishes', () => { + expect(busUseFor(['sync'], NATS)).toBe('sockets'); + expect(busUseFor(['web', 'sync', 'worker', 'scheduler'], NATS)).toBe('sockets'); + expect(busUseFor(['replicator'], NATS)).toBe('feed'); + expect(busUseFor(['web'], NATS)).toBe('publish'); + expect(busUseFor(['worker'], NATS)).toBe('publish'); + expect(busUseFor(['scheduler'], NATS)).toBe('publish'); + expect(busUseFor([], NATS)).toBe('publish'); + }); + + test('realtime.enabled: false starts no realtime role, so no role waits for the bus', () => { + const off = { ...NATS, enabled: false }; + expect(busUseFor(['sync'], off)).toBe('publish'); + expect(busUseFor(['web', 'sync', 'replicator'], off)).toBe('publish'); + }); + + test('a boot that names no roles is held to the strictest reading', () => { + expect(busUseFor(undefined, NATS)).toBe('sockets'); + }); +}); + +describe('selectBus().start(), for a role that only publishes', () => { + test('boots with NATS down: degraded on /readyz?deep=1, ready on /readyz, publish refused typed', async () => { + const broker = new FakeNatsBroker(); + broker.offline = true; + const bus = selectBus({ env: ENV, realtime: NATS, roles: ['web'], select: fake(broker) }); + + const running = await bus.start(); + markReady(); + try { + expect(bus.use).toBe('publish'); + expect(busLabel(running.transport)).toBe('nats(connecting)'); + const shallow = readyzPayload(); + expect(shallow.status).toBe(200); + expect(shallow.body.checks).toEqual({ transport: 'degraded' }); + expect(readyzPayload({ deep: true }).status).toBe(503); + + // The app's own publish: the typed refusal its `catch` already handles, and at once. + const feed = channel('bus-feed', { + params: ['orgId'], + catchUp: { name: 'busFeedRead' }, + events: true, + policy: allow('public'), + }); + const refused = await caught(publishChannelEvent(feed, { orgId: 'o1' }, { kind: 'changed' })); + expect(codeOf(refused)).toBe('X_TRANSPORT_UNAVAILABLE'); + + // The bus comes back: no restart, and the same publish is delivered. + const heard: string[] = []; + broker.client().subscribe('x.channel.>', (message) => heard.push(message.subject)); + broker.offline = false; + await waitFor(() => busLabel(running.transport) === 'nats(up)'); + expect(busLabel(running.transport)).toBe('nats(up)'); + expect(readyzPayload().body.checks).toEqual({ transport: 'ok' }); + expect(readyzPayload({ deep: true }).status).toBe(200); + await publishChannelEvent(feed, { orgId: 'o1' }, { kind: 'changed' }); + expect(heard).toEqual(['x.channel.bus-feed.o1']); + } finally { + await running.stop(); + } + expect(readinessCheckCount()).toBe(0); + expect(broker.clients).toHaveLength(1); // the test's own listener; the boot's is closed + }); + + test('a server with no JetStream costs a publisher nothing', async () => { + const broker = new FakeNatsBroker(); + broker.fail('$JS.API', 1_000); + const bus = selectBus({ env: ENV, realtime: NATS, roles: ['worker'], select: fake(broker) }); + const running = await bus.start(); + try { + await waitFor(() => busLabel(running.transport) === 'nats(up)'); + expect(busLabel(running.transport)).toBe('nats(up)'); + expect(broker.streams).toEqual([]); + } finally { + await running.stop(); + } + }); + + test('realtime.enabled: false never waits for the bus, whatever role was asked for', async () => { + const broker = new FakeNatsBroker(); + broker.offline = true; + const bus = selectBus({ + env: ENV, + realtime: { ...NATS, enabled: false }, + roles: ['web', 'sync'], + select: fake(broker), + }); + const running = await bus.start(); + expect(busLabel(running.transport)).toBe('nats(connecting)'); + await running.stop(); + }); +}); + +describe('selectBus().start(), for a role that serves sockets', () => { + test('refuses the boot inside its wait, coded, and leaves nothing registered', async () => { + const hung = Promise.withResolvers(); + const bus = selectBus({ + env: ENV, + realtime: NATS, + roles: ['sync'], + select: { connect: () => hung.promise, connectWithinMs: 30 }, + }); + + const startedAt = performance.now(); + const refused = await caught(bus.start()); + + expect(performance.now() - startedAt).toBeLessThan(2_000); + expect(codeOf(refused)).toBe('X_TRANSPORT_UNAVAILABLE'); + expect(isUltimateError(refused) ? refused.cause : '').toContain('within 30ms'); + expect(isUltimateError(refused) ? refused.fix : '').toContain('NATS_URL'); + expect(readinessCheckCount()).toBe(0); + }); + + test('once up, a lost bus FAILS readiness: a sync node cannot serve without it', async () => { + const broker = new FakeNatsBroker(); + const bus = selectBus({ env: ENV, realtime: NATS, roles: ['sync'], select: fake(broker) }); + const running = await bus.start(); + markReady(); + try { + expect(busLabel(running.transport)).toBe('nats(up)'); + // The node serves presence, so its dial is what creates the bucket. + expect(broker.streams).toEqual(['KV_x_presence']); + broker.drop(); + expect(readyzPayload().body.checks).toEqual({ transport: 'failing' }); + expect(readyzPayload().status).toBe(503); + } finally { + await running.stop(); + } + }); +}); + +describe('selectBus(), the cases that are not NATS', () => { + test('the in-process bus has no state to report and registers no check', async () => { + const bus = selectBus({ env: {}, realtime: MEMORY, roles: ['web'] }); + const running = await bus.start(); + expect(busLabel(running.transport)).toBe('in-process'); + expect(readinessCheckCount()).toBe(0); + await running.stop(); + }); + + test('a transport the host supplied is used as it is, and never closed by the boot', async () => { + const broker = new FakeNatsBroker(); + const own = selectBus({ env: ENV, realtime: NATS, roles: ['sync'], select: fake(broker) }); + const supplied = (await own.start()).transport; + resetLifecycle(); + let closed = 0; + const close = supplied.close.bind(supplied); + supplied.close = async (): Promise => { + closed += 1; + await close(); + }; + + const bus = selectBus({ env: {}, realtime: MEMORY, roles: ['web'], override: supplied }); + const running = await bus.start(); + expect(running.transport).toBe(supplied); + expect(running.detail).toBe('runtime override'); + await running.stop(); + expect(closed).toBe(0); + await close(); + }); +}); diff --git a/packages/cli/src/runtime-bus.ts b/packages/cli/src/runtime-bus.ts new file mode 100644 index 000000000..1f1667376 --- /dev/null +++ b/packages/cli/src/runtime-bus.ts @@ -0,0 +1,158 @@ +// Single responsibility: the fanout bus as ONE boot holds it — what the roles it starts do with +// the bus, the dial that calls for, the readiness check, and the label the boot line prints. +// +// The rule is the role's, not the transport's. A `sync` node serves sockets from the bus and a +// replicator feeds them: neither can work without it, so each awaits the dial and refuses its +// boot, coded, inside a bounded wait. `web`, `worker` and `scheduler` only PUBLISH — channel +// events and cache invalidations, both of which mean "re-read" — so for them the bus is dialled in +// the background and a dead one is `degraded`: the pod still boots, serves and runs jobs. Until +// 2026-10 every role awaited the dial and the JetStream bucket, so a web pod that restarted while +// NATS was down took the app's pages, webhooks and send jobs down with a feature none of them use. + +import type { RealtimeConfig, Role } from '@ultimat3/core'; +import { logger, registerReadinessCheck } from '@ultimat3/core'; +import type { BusUse, SelectTransportOptions, Transport } from '@ultimat3/realtime/server'; +import { selectTransport, setChannelTransport } from '@ultimat3/realtime/server'; +import type { Env } from './runtime-bindings'; + +/** + * What a process running `roles` does with the bus. `undefined` — a boot that names no roles — is + * held to the strictest reading, the one every boot had. `realtime.enabled: false` starts neither + * realtime role (`role-realtime.ts`), so nothing in such a process waits for the bus. + */ +export function busUseFor( + roles: readonly Role[] | undefined, + realtime: Pick, +): BusUse { + if (roles === undefined) return 'sockets'; + if (!realtime.enabled) return 'publish'; + if (roles.includes('sync')) return 'sockets'; + return roles.includes('replicator') ? 'feed' : 'publish'; +} + +/** A transport that says whether it is connected. NATS does; the in-process bus has nothing to be. */ +interface ConnectableTransport { + readonly connected: boolean; +} + +const saysConnected = (transport: Transport): transport is Transport & ConnectableTransport => + typeof (transport as Partial).connected === 'boolean'; + +/** + * The boot line's `bus=` value: `nats(up)`, `nats(connecting)`, or the bare name of a bus with no + * connection to lose. A fixed vocabulary a script may parse, never a catalog lookup. + */ +export function busLabel(transport: Transport): string { + if (!saysConnected(transport)) return transport.name; + return `${transport.name}(${transport.connected ? 'up' : 'connecting'})`; +} + +export interface RunningBus { + readonly transport: Transport; + /** The env key that selected the bus — never the url behind it — or `runtime override`. */ + readonly detail: string; + /** Everything `start()` acquired, newest first; the first failure is rethrown, every step runs. */ + stop(): Promise; +} + +export interface SelectedBus { + readonly use: BusUse; + /** What the sync role must give `PresenceRegistry` (`RunningServices.presenceTtlMs`). */ + readonly presenceTtlMs: number; + /** + * Dial as `use` calls for, install the transport as the process's channel bus, and register its + * readiness check. Rejects — with nothing left registered or open — only for a use that cannot + * work without the bus. + */ + start(): Promise; +} + +export interface SelectBusInput { + readonly env: Env; + readonly realtime: RealtimeConfig; + /** The roles this process will start; `undefined` when the caller does not know. */ + readonly roles: readonly Role[] | undefined; + /** `RuntimeOverrides.transport`: already connected, and its owner's to close. */ + readonly override?: Transport | undefined; + /** Injected by a test: a fake dial, a short wait. */ + readonly select?: SelectTransportOptions | undefined; +} + +/** + * Selection is pure — it parses env and constructs, it dials nothing — so a config and an + * environment that disagree refuse here, before any service starts (`selectTransport`). + */ +export function selectBus(input: SelectBusInput): SelectedBus { + const use = busUseFor(input.roles, input.realtime); + const selection = selectTransport(input.env, input.realtime, { ...input.select, use }); + return { + use, + presenceTtlMs: selection.presenceTtlMs, + async start(): Promise { + const started: (() => void | Promise)[] = []; + const stop = async (): Promise => { + let failure: { readonly error: unknown } | undefined; + for (const step of started.splice(0).reverse()) { + try { + await step(); + } catch (error) { + failure ??= { error }; + } + } + if (failure !== undefined) throw failure.error; + }; + try { + // A supplied transport is already connected and is NOT closed here: whoever built it owns + // its socket, which is why the override skips both halves rather than only the dial. + let transport = input.override; + if (transport === undefined) { + // Before the dial, not after: a dial refused for being late is still in flight inside + // the client library, and closing the transport is what releases whatever it lands as. + started.push(() => selection.transport.close()); + await selection.connect(); + transport = selection.transport; + } + // The bus an app's own code publishes a channel event on (`publishChannelEvent`), in EVERY + // role: the hub is the `sync` role's, so a job or an action reached none, and an + // events-only channel — the one kind that needs no replicator — could be fed by nothing + // but a socket. + started.push(setChannelTransport(transport)); + // Only a transport that can be disconnected gets a check. `NatsTransport.connected` is a + // synchronous getter over the client's own state, so no probe is needed; the in-process + // bus has nothing to lose a connection to, and a check that can only answer `true` is a + // number in `registered` that means nothing. + if (saysConnected(transport)) { + const connectable = transport; + started.push( + registerReadinessCheck( + 'transport', + () => connectable.connected, + // A publisher serves without the bus, so losing it must not pull the pod from the + // ingress — it is reported, and `/readyz?deep=1` is where a monitor reads it. + { onFailure: use === 'publish' ? 'degraded' : 'failing' }, + ), + ); + // Each time the bus comes (back) up, on one line: the boot line may have said + // `connecting`, and this is the other half of it. + started.push( + connectable.onReconnect(() => { + logger.info('ultimate bus', { bus: busLabel(connectable), use }); + }), + ); + } + return { + transport, + // The env key that selected the bus — or the honest answer that no env key did, because + // a boot line reading `NATS_URL` over a transport the host handed in is a lie a script + // parses. + detail: input.override === undefined ? selection.detail : 'runtime override', + stop, + }; + } catch (error) { + // The refusal is the failure worth reporting, not a release on the way out. + await stop().catch(() => undefined); + throw error; + } + }, + }; +} diff --git a/packages/cli/src/runtime-services.ts b/packages/cli/src/runtime-services.ts index 37a00416a..ab4831583 100644 --- a/packages/cli/src/runtime-services.ts +++ b/packages/cli/src/runtime-services.ts @@ -10,6 +10,7 @@ import { isNoopPurgeDriver, selectPurgeDriver } from '@ultimat3/cache'; import { isLocal, type RealtimeConfig, + type Role, registerReadinessCheck, renderThrowable, resolveEnvironment, @@ -26,14 +27,14 @@ import { resetMailDriver, setMailDriver, } from '@ultimat3/mail'; -import type { Transport, TransportSelection } from '@ultimat3/realtime/server'; -import { selectTransport, setChannelTransport } from '@ultimat3/realtime/server'; +import type { BusUse, Transport } from '@ultimat3/realtime/server'; import type { Storage } from '@ultimat3/storage'; import { defineStorage, localDriver, s3Driver, usesDevStorageSecret } from '@ultimat3/storage'; import { loadAppConfig } from './app-config-load'; import { LocalDiskUnsafeError, StorageUnwritableError } from './errors'; import { msg } from './messages'; import type { DevServices, Env } from './runtime-bindings'; +import { selectBus } from './runtime-bus'; import { cacheTiersOf, startCacheTiers } from './runtime-cache'; import { type WorkerConfig, workerConfigOf } from './runtime-jobs'; import { selectAppMailDriver } from './runtime-mail'; @@ -74,6 +75,11 @@ export interface RunningServices { readonly mailDetail: string; /** Same rule as `mailDetail`: the env key that selected the bus, never the url behind it. */ readonly transportDetail: string; + /** + * What this process does with the bus, which decided whether the boot waited for it + * (`runtime-bus.ts`). Optional for the reason `workerConfig` is: a hand-built runtime has none. + */ + readonly busUse?: BusUse; /** * What the sync role must give `PresenceRegistry`. It travels with the transport because the KV * bucket's age limit was derived from it — a registry given a longer TTL than the bucket honours @@ -278,14 +284,6 @@ function probedReadinessCheck(name: string, probe: () => Promise): () = }); } -/** A transport that says whether it is connected. NATS does; the in-process bus has nothing to be. */ -interface ConnectableTransport { - readonly connected: boolean; -} - -const saysConnected = (transport: Transport): transport is Transport & ConnectableTransport => - typeof (transport as Partial).connected === 'boolean'; - /** * Release what has already started, newest first, and return every failure instead of throwing on * the first: a step that rejects must not skip the ones after it, or one transport that will not @@ -324,6 +322,11 @@ export async function startServices( overrides?: RuntimeOverrides, /** `'verify'` for a serving role on an external database — `runtime-queue.ts`'s `SchemaMode`. */ schema: SchemaMode = 'apply', + /** + * The roles this process will start, which decide whether the boot waits for the bus: only a + * `sync` node or a replicator does (`runtime-bus.ts`). Unset is the strictest reading. + */ + roles?: readonly Role[], ): Promise { // The app's config is loaded ONCE, here, first, and every section below is read out of that one // validated object — mail's `retainMime` is the first reader, so it is loaded before mail. @@ -341,13 +344,13 @@ export async function startServices( // service starts, rather than quietly keeping the in-process bus. Which transport, which KV // bucket and which presence TTL is `@ultimat3/realtime`'s decision, and it is the same call a // `ROLE=sync` container makes, so this process cannot resolve the bus differently from the - // container it stands in for. + // container it stands in for. What the bus is USED for is the roles' (`runtime-bus.ts`). const realtime = realtimeConfigOf(config); // Fourth: `pwa.push` and its VAPID pair (`runtime-push.ts`). Resolving the pair reads env and // signs one probe — a deploy with no keys, or two halves of different pairs, refuses here. const push = await selectWebPush(config, env); const workerConfig = workerConfigOf(config, env); - const bus: TransportSelection = selectTransport(env, realtime); + const bus = selectBus({ env, realtime, roles, override: overrides?.transport }); // `env`, not the ambient one: this function is HANDED the boot's environment and every other // reader here already uses it, so a queue that asked `process.env` would decide the standby from // a different answer than the middleware that routes to it. @@ -405,28 +408,14 @@ export async function startServices( // before `sync`, `worker` and `scheduler` start. The chart's `readinessProbe` and the container // healthcheck both route on it, so a replica whose pool was gone kept taking traffic. started.push(probedReadinessCheck('database', () => db.ping())); - // Dialled here rather than at selection: an unreachable bus must fail at `x dev`, not on the - // first change nobody receives, and the socket is a resource the unwind below has to release. - // A supplied transport is already connected and is NOT closed here: whoever built it owns its - // socket, which is why the override skips both halves rather than only the dial. - let transport = overrides?.transport; - if (transport === undefined) { - await bus.connect(); - started.push(() => bus.transport.close()); - transport = bus.transport; - } - // The bus an app's own code publishes a channel event on (`publishChannelEvent`), in EVERY - // role: the hub is the `sync` role's, so a job or an action reached none, and an events-only - // channel — the one kind that needs no replicator — could be fed by nothing but a socket. - started.push(setChannelTransport(transport)); - // Only a transport that can be disconnected gets a check. `NatsTransport.connected` is a - // synchronous getter over the client's own state, so no probe is needed; the in-process bus - // has nothing to lose a connection to, and a check that can only answer `true` is a number in - // `registered` that means nothing. - if (saysConnected(transport)) { - const connectable = transport; - started.push(registerReadinessCheck('transport', () => connectable.connected)); - } + // Dialled here rather than at selection: the socket is a resource the unwind below has to + // release. AWAITED only by a process that cannot work without the bus — a `sync` node, a + // replicator — where an unreachable one must fail the boot, not the first change nobody + // receives. Every other role dials in the background and boots regardless; the channel bus and + // the `transport` readiness check are installed either way (`runtime-bus.ts`). + const running = await bus.start(); + started.push(() => running.stop()); + const transport = running.transport; // Before `loadApp` for the auth limiters' reason: `pushSubscribe()` is declared when the app's // modules import, and reads this runtime per call. if (push !== undefined) started.push(await installAppWebPush(push, executor)); @@ -467,9 +456,8 @@ export async function startServices( // table: three readers of one executor, resolved once. `startWeb` is what an override // replaces it at. rateLimitStore, - // The env key that selected the bus — or the honest answer that no env key did, because a - // boot line reading `NATS_URL` over a transport the host handed in is a lie a script parses. - transportDetail: overrides?.transport === undefined ? bus.detail : 'runtime override', + transportDetail: running.detail, + busUse: bus.use, presenceTtlMs: bus.presenceTtlMs, purge, purgeDetail: cdn.detail, diff --git a/packages/cli/src/serve-boot.ts b/packages/cli/src/serve-boot.ts index 32ff6e6bd..c075f49b6 100644 --- a/packages/cli/src/serve-boot.ts +++ b/packages/cli/src/serve-boot.ts @@ -12,6 +12,7 @@ import { startOtlpExport } from './otlp-export'; import { loadAppForRole, roleLoadFor } from './role-load'; import { startRoles } from './role-start'; import { resolveServices } from './runtime-bindings'; +import { busLabel } from './runtime-bus'; import { warnIfIdempotencyProcessScoped } from './runtime-idempotency-scope'; import { warnUnsealedMfaSecrets } from './runtime-mfa-warning'; import { replicaOverrides } from './runtime-replica'; @@ -89,7 +90,8 @@ export async function bootServing(boot: { // tables first, and this boot only verifies the stamp it left (`framework-schema-apply.ts`). // The embedded database has no migrate step to have run, so it applies its own. const schema = services.db.mode === 'external' ? 'verify' : 'apply'; - const runtime = await startServices(services, options.env, options.runtime, schema); + // The role decides whether this boot waits for the bus: only `sync` and the replicator do. + const runtime = await startServices(services, options.env, options.runtime, schema, [boot.role]); boot.acquired.push(() => runtime.stop()); return bootRoles({ ...boot, runtime }); } @@ -190,6 +192,7 @@ async function bootRoles(boot: { role, url: running.url, buildId, + bus: busLabel(runtime.transport), running, runtime, async stop() { diff --git a/packages/cli/src/serve-graph.test.ts b/packages/cli/src/serve-graph.test.ts index 068e10f3a..59b37d9f4 100644 --- a/packages/cli/src/serve-graph.test.ts +++ b/packages/cli/src/serve-graph.test.ts @@ -181,8 +181,12 @@ const MIGRATE_CEILING = 639; * (`setChannelTransport`), so a job or an action publishes on a declared channel with no hub. * raised 936 → 938, measured 938 (2026-10-10, #752): the two entity modules named on * `MIGRATE_CEILING` for #752, which every role reaches through the entity barrel. + * raised 938 → 939, measured 939 (2026-10-10, the bus is not a boot dependency of a publisher): + * `cli/src/runtime-bus.ts` — which roles await the NATS dial (`sync`, the replicator) and which + * dial it in the background and boot (`web`, `worker`, `scheduler`), the `transport` readiness + * check and the boot line's `bus=`. Split out of `runtime-services.ts`, which sat at the ceiling. */ -const SERVING_ROLE_CEILING = 938; +const SERVING_ROLE_CEILING = 939; /** * measured: 888 — the 796 above plus the 92 `serve-web.ts` adds (41 CLI, 36 MCP, 15 PWA). @@ -263,8 +267,10 @@ const SERVING_ROLE_CEILING = 938; * (held, #506) and which only follow a channel, read off the names each imports from the barrel. * raised 1063 → 1065, measured 1065 (2026-10-10, #752): the two entity modules named on * `MIGRATE_CEILING` for #752. + * raised 1065 → 1066, measured 1066 (2026-10-10, the bus is not a boot dependency of a publisher): + * `cli/src/runtime-bus.ts`, the module named on `SERVING_ROLE_CEILING`, which every role carries. */ -const WEB_ROLE_CEILING = 1065; +const WEB_ROLE_CEILING = 1066; interface MetaInput { readonly imports: readonly { readonly path: string; readonly kind: string }[]; diff --git a/packages/cli/src/serve-types.ts b/packages/cli/src/serve-types.ts index a0a37f24f..ea2f9acb9 100644 --- a/packages/cli/src/serve-types.ts +++ b/packages/cli/src/serve-types.ts @@ -39,6 +39,11 @@ export interface ServedApp { /** `http://…` for the web role; null for the roles that open no HTTP socket. */ readonly url: string | null; readonly buildId: string; + /** + * The bus as the boot left it: `nats(up)`, `nats(connecting)` or `in-process` (`busLabel`). Only + * a role that publishes and serves no socket can boot `connecting`. + */ + readonly bus: string; readonly running: RunningRoles; readonly runtime: RunningServices; stop(): Promise; diff --git a/packages/cli/src/serve.live.test.ts b/packages/cli/src/serve.live.test.ts index 6b593a432..bf5a2658f 100644 --- a/packages/cli/src/serve.live.test.ts +++ b/packages/cli/src/serve.live.test.ts @@ -186,6 +186,8 @@ describe('the scaffolded production entry is a runnable artifact', () => { // if it were the one the operator asked for. expect(started).toContain(`"url":"http://127.0.0.1:${port}"`); expect(started).not.toContain('0.0.0.0'); + // Where the bus is, on the same line: `nats(connecting)` here is a served pod with NATS down. + expect(started).toContain('"bus":"in-process"'); allowHost(`127.0.0.1:${port}`); expect((await fetch(`http://127.0.0.1:${port}/readyz`)).status).toBe(200); child.kill('SIGTERM'); diff --git a/packages/cli/src/serve.ts b/packages/cli/src/serve.ts index ca912542d..4687cad78 100644 --- a/packages/cli/src/serve.ts +++ b/packages/cli/src/serve.ts @@ -203,7 +203,14 @@ export async function runRole(input: ServeOptions): Promise { } const { app, hold } = booted; retire?.adopt(app.running.worker); - logger.info('ultimate started', { role: app.role, url: app.url, buildId: app.buildId }); + logger.info('ultimate started', { + role: app.role, + url: app.url, + buildId: app.buildId, + // `nats(connecting)` on a role that only publishes is a served pod with the bus down; + // `ultimate bus` is logged with `nats(up)` when the dial lands. + bus: app.bus, + }); await hold(); return app; } diff --git a/packages/core/README.md b/packages/core/README.md index f469baa23..e17186515 100644 --- a/packages/core/README.md +++ b/packages/core/README.md @@ -494,7 +494,10 @@ match with `sealAll()`; uniqueness cannot be held across keys. **bound**. `ReadinessCheck` is `() => boolean` and must stay synchronous — a probe that awaits its dependency turns a slow dependency into a wedged endpoint and then a restart loop; keep a boolean fresh and let the check read it. It returns an unregister. `HealthReport.checks` is a map of name - → `'ok' | 'failing'`, so "alert on check failures by check name" is writable. + → `'ok' | 'degraded' | 'failing'`, so "alert on check failures by check name" is writable. + `registerReadinessCheck(name, check, { onFailure: 'degraded' })` is a dependency the role serves + without (the bus of a role that only publishes to it): its `false` is `'degraded'`, never a 503 + on `/readyz` in either mode, and a 503 on `/readyz?deep=1`. - **`HealthReport.registered` is the third state.** `checks: {}` reads identically for "every check passed" and "nobody registered one", and an **empty registry is still ready** — reported, never enforced, so a role with no dependency does not have to invent a check to boot. Read `registered` diff --git a/packages/core/src/index.ts b/packages/core/src/index.ts index 48dd94231..6f84a2c06 100644 --- a/packages/core/src/index.ts +++ b/packages/core/src/index.ts @@ -646,7 +646,11 @@ export { READINESS_GRACE_DEFAULT_MS, READINESS_GRACE_MAX_MS, } from './lifecycle-grace'; -export type { ReadinessCheck, ReadinessStatus } from './lifecycle-readiness'; +export type { + ReadinessCheck, + ReadinessCheckOptions, + ReadinessStatus, +} from './lifecycle-readiness'; export type { SignalHandlerOptions } from './lifecycle-signals'; export { drainSignals, installSignalHandlers } from './lifecycle-signals'; export { isSelfOrigin, listeningOrigins, markListening, resetListeners } from './listeners'; diff --git a/packages/core/src/lifecycle-readiness.test.ts b/packages/core/src/lifecycle-readiness.test.ts index 1aceb26d1..7c4961e8c 100644 --- a/packages/core/src/lifecycle-readiness.test.ts +++ b/packages/core/src/lifecycle-readiness.test.ts @@ -61,6 +61,43 @@ describe("health.readiness: 'process'", () => { expect(readyzPayload({ deep: true }).status).toBe(200); }); + test("a check registered as degradable reports 'degraded' and never fails readiness", () => { + // A dependency the role can serve without: the bus of a role that only publishes to it. + let up = false; + registerReadinessCheck('transport', () => up, { onFailure: 'degraded' }); + registerReadinessCheck('database', () => true); + markReady(); + + // The DEFAULT mode: the kubelet routes on this, and a dead bus must not empty the ingress. + const shallow = readyzPayload(); + expect(shallow.status).toBe(200); + expect(shallow.body.ready).toBe(true); + expect(shallow.body.checks).toEqual({ transport: 'degraded', database: 'ok' }); + // Monitoring's view is strict: anything short of 'ok' is a 503 a monitor can alert on. + expect(readyzPayload({ deep: true }).status).toBe(503); + expect(readyzPayload({ deep: true }).body.checks).toEqual({ + transport: 'degraded', + database: 'ok', + }); + + up = true; + expect(readyzPayload().body.checks).toEqual({ transport: 'ok', database: 'ok' }); + expect(readyzPayload({ deep: true }).status).toBe(200); + }); + + test('a degradable check that THROWS is degraded too, and a failing one beside it still fails', () => { + // The runtime's own SyntaxError: what a check reading a torn-down client really raises. + registerReadinessCheck('transport', () => JSON.parse('gone') === true, { + onFailure: 'degraded', + }); + markReady(); + expect(readyzPayload().status).toBe(200); + expect(readyzPayload().body.checks).toEqual({ transport: 'degraded' }); + + registerReadinessCheck('database', () => false); + expect(readyzPayload().status).toBe(503); + }); + test('the default is unchanged: a failing check is 503', () => { expect(defineConfig({ name: 'app' }).health.readiness).toBe('dependencies'); registerReadinessCheck('database', () => false); diff --git a/packages/core/src/lifecycle-readiness.ts b/packages/core/src/lifecycle-readiness.ts index 4e39cf481..d35e6449f 100644 --- a/packages/core/src/lifecycle-readiness.ts +++ b/packages/core/src/lifecycle-readiness.ts @@ -4,7 +4,22 @@ import { UltimateError } from './errors'; -export type ReadinessStatus = 'ok' | 'failing'; +/** + * `'degraded'` is a failed check the role serves WITHOUT (`onFailure: 'degraded'`): reported by + * name, never a 503 on `/readyz` in either mode, and a 503 on `/readyz?deep=1` — the probe routes + * traffic on the first and a monitor alerts on the second. + */ +export type ReadinessStatus = 'ok' | 'degraded' | 'failing'; + +export interface ReadinessCheckOptions { + /** + * What a `false` (or a throw) from this check is. `'failing'`, the default, is a dependency the + * role cannot serve without. `'degraded'` is one it can — the bus of a role that only publishes + * to it: pulling every replica from the ingress for a dependency no served request waits on is + * the outage the probe exists to prevent. + */ + readonly onFailure?: 'failing' | 'degraded' | undefined; +} /** * Synchronous, and that is the design, not a limitation. **Do not widen this to @@ -23,13 +38,22 @@ export type ReadinessStatus = 'ok' | 'failing'; */ export type ReadinessCheck = () => boolean; -const checks = new Map(); +interface Registered { + readonly check: ReadinessCheck; + readonly onFailure: 'failing' | 'degraded'; +} + +const checks = new Map(); /** * Register a named readiness check. Returns its unregister — the same shape as `onShutdown`, and * owned by whoever can be started twice, for the same reason. */ -export function registerReadinessCheck(name: string, check: ReadinessCheck): () => void { +export function registerReadinessCheck( + name: string, + check: ReadinessCheck, + options: ReadinessCheckOptions = {}, +): () => void { if (checks.has(name)) { throw new UltimateError({ code: 'X_READINESS_CHECK_DUPLICATE', @@ -38,9 +62,10 @@ export function registerReadinessCheck(name: string, check: ReadinessCheck): () meta: { name }, }); } - checks.set(name, check); + const registered: Registered = { check, onFailure: options.onFailure ?? 'failing' }; + checks.set(name, registered); return () => { - if (checks.get(name) === check) checks.delete(name); + if (checks.get(name) === registered) checks.delete(name); }; } @@ -55,8 +80,8 @@ export function clearReadinessChecks(): void { } /** - * Every check, run now, by name. A check that throws is `failing` — never an unhandled error — - * and is handed to `onThrow`, which `lifecycle.ts` routes through its total `report`. + * Every check, run now, by name. A check that throws is its `onFailure` (`failing` unless it was + * registered degradable) — never an unhandled error — and is handed to `onThrow`, which `lifecycle.ts` routes through its total `report`. * * Built through `Object.fromEntries`, never by assigning `results[name]`: assignment to the one * name `__proto__` sets the PROTOTYPE instead of adding a key, so that check vanished from the @@ -67,11 +92,11 @@ export function runReadinessChecks( onThrow: (name: string, thrown: unknown) => void, ): Readonly> { const results: [string, ReadinessStatus][] = []; - for (const [name, check] of checks) { + for (const [name, { check, onFailure }] of checks) { try { - results.push([name, check() ? 'ok' : 'failing']); + results.push([name, check() ? 'ok' : onFailure]); } catch (thrown) { - results.push([name, 'failing']); + results.push([name, onFailure]); onThrow(name, thrown); } } diff --git a/packages/core/src/lifecycle.ts b/packages/core/src/lifecycle.ts index 1a10523db..8f9dd2107 100644 --- a/packages/core/src/lifecycle.ts +++ b/packages/core/src/lifecycle.ts @@ -374,9 +374,15 @@ export function drain(signal = 'manual'): Promise { return drainPromise; } -export function healthReport(mode: ReadinessMode = readinessMode): HealthReport { +export function healthReport( + mode: ReadinessMode = readinessMode, + /** `/readyz?deep=1`: a `'degraded'` check is not ready either. Never the probe's reading. */ + strict = false, +): HealthReport { const checks = readinessChecks(); - const dependencies = Object.values(checks).every((status) => status === 'ok'); + const dependencies = Object.values(checks).every( + (status) => status === 'ok' || (!strict && status === 'degraded'), + ); return { state, // `ready` is the same predicate `/readyz` answers on, so a body and its status can never @@ -405,9 +411,11 @@ export function healthzPayload(): HealthPayload { /** * Readiness: may this instance receive traffic? 503 while starting or draining, and — in the * default `'dependencies'` mode, or always with `deep` (`/readyz?deep=1`) — while any check fails. + * A `'degraded'` check (`ReadinessCheckOptions.onFailure`) is a 503 under `deep` ALONE. */ export function readyzPayload(options: { readonly deep?: boolean } = {}): HealthPayload { - const body = healthReport(options.deep === true ? 'dependencies' : readinessMode); + const deep = options.deep === true; + const body = healthReport(deep ? 'dependencies' : readinessMode, deep); return { ok: body.ready, status: body.ready ? 200 : 503, body }; } diff --git a/packages/realtime/CLAUDE.md b/packages/realtime/CLAUDE.md index 8f3dbcb49..3fd967c08 100644 --- a/packages/realtime/CLAUDE.md +++ b/packages/realtime/CLAUDE.md @@ -119,12 +119,13 @@ Tier 3 package. Channels, live queries, local-first sync. One protocol for all t ## The node, the bus and presence - `sync` is stateless: no sticky sessions, nothing on a socket survives a restart. -- **`selectTransport(env, realtime)` is the one place `realtime.transport` + env become a bus** (KV - bucket and presence TTL come back with it). The config decides, the env supplies: `'nats'` refuses - (`X_CONFIG_INVALID`) when the `urlEnv` variable is unset; `'memory'` refuses a set one. -- **`nats` is imported only by `nats-lib-client.ts`**; its reconnect re-subscribes. Only when it - GIVES UP (`onClosed`) does `NatsTransport` re-dial on backoff and re-bind kept subscriptions - (`nats-subscriptions.ts`); callers meanwhile are refused. KV semantics: `nats-jetstream`/`nats-kv`. +- **`selectTransport(env, realtime, { use })` is the one place config + env become a bus** (bucket + and presence TTL come back). `'nats'` refuses (`X_CONFIG_INVALID`) an unset `urlEnv` variable; + `'memory'` a set one. `use`: `'sockets'`/`'feed'` await a 15 s dial, then + `X_TRANSPORT_UNAVAILABLE`; `'publish'` dials in background. Never `waitOnFirstConnect` + (retries forever). A publish with no live connection is refused. +- **`nats` is imported only by `nats-lib-client.ts`**; its reconnect re-subscribes. When it GIVES + UP (`onClosed`) `NatsTransport` re-dials on backoff and re-binds. - **Nothing leaves `NatsTransport` uncoded** — `#translating` wraps `publish`/`subscribe` refusals as `X_TRANSPORT_UNAVAILABLE`. `#ensure` reuses a mid-reconnect client on purpose; `Transport.onReconnect(listener)` (required) announces each recovery. diff --git a/packages/realtime/README.md b/packages/realtime/README.md index b90f48689..9dc19837d 100644 --- a/packages/realtime/README.md +++ b/packages/realtime/README.md @@ -800,7 +800,22 @@ principal. fanout across nodes. Until 22.0.0 `NATS_URL` alone decided and both keys were read by nothing. `presenceTtlMs` comes back with it because the bucket's whole-stream age limit was derived from it — a `PresenceRegistry` given a different number would report members leaving that never left. - Selection is pure; `connect()` is the dial, so an unreachable bus fails at boot. + Selection is pure; `connect()` is the dial. **What the process does with the bus decides whether + that dial is waited for** — `selectTransport(env, realtime, { use })`, `BusUse`: + `'sockets'` (a `sync` node; the default) awaits it and the presence bucket, retried on backoff for + `connectWithinMs` (default `BUS_CONNECT_WAIT_MS`, 15 s) and then `X_TRANSPORT_UNAVAILABLE`; + `'feed'` (the replicator) awaits it and asks JetStream for nothing; `'publish'` (`web`, `worker`, + `scheduler`) starts it in the background and resolves at once. `selection.state()` answers + `'up' | 'connecting'`. +- **`NatsTransport` has two ways to open.** `connect({ withinMs, fix })` is for a node that cannot + work without the bus. `connectInBackground()` is for a process that only publishes: retried on the + transport's own backoff until it lands or `close()` runs, announced through `onReconnect`, and + until then every `publish`/`subscribe` rejects at once with `X_TRANSPORT_UNAVAILABLE` — never + parked, never queued. A publish made while the client is **reconnecting** is refused too: the + `nats` client would buffer it without bound and replay it late. `presenceBucket: 'first-use'` + asserts the KV bucket when `shared` is first read instead of at the dial, so a publisher needs no + JetStream. The first dial is ONE attempt of the library's — `waitOnFirstConnect` is not set, + because under it nats@2.29.3 retries a failed first dial forever and the promise never settles. - **`NatsTransport` runs on the official `nats` client** — `nats@2.29.3`, pinned exact, admitted at this transport seam and nowhere else ([`docs/idea/18-build-vs-wrap.md`](../../docs/idea/18-build-vs-wrap.md)). The package reaches it diff --git a/packages/realtime/src/nats-lib-client.ts b/packages/realtime/src/nats-lib-client.ts index 950a40f46..d7b52d636 100644 --- a/packages/realtime/src/nats-lib-client.ts +++ b/packages/realtime/src/nats-lib-client.ts @@ -219,9 +219,14 @@ const stopStream = (stream: unknown): void => { }; /** - * The production `NatsConnect`. The first dial retries on the same budget as a later loss - * (`waitOnFirstConnect`), so a `sync` container that raced the bus into readiness recovers on its - * own — and a budget that runs out rejects here rather than leaving a half-live connection behind. + * The production `NatsConnect`: ONE first dial, refused at once when the server is not there. + * + * Deliberately not `waitOnFirstConnect`. Until 2026-10 it was set, on the reading that the first + * dial "retries on the same budget as a later loss" — it does not: in nats@2.29.3 a failed first + * dial under that option `continue`s past the attempt counter, so it retries FOREVER, and the + * promise this returns never settles while the server is down. Every role awaited it at boot, so + * a pod that restarted during a NATS outage hung before it bound a socket. The retry is the + * transport's (`NatsTransport.#redial`), on our backoff, where `close()` can end it. */ export const openNatsClient = async (options: NatsClientOptions): Promise => { const target = parseNatsUrl(options.url); @@ -239,7 +244,6 @@ export const openNatsClient = async (options: NatsClientOptions): Promise + isUltimateError(value) ? value.code : `not an UltimateError: ${String(value)}`; + +const causeOf = (value: unknown): string => (isUltimateError(value) ? value.cause : String(value)); + +const caught = (promise: Promise): Promise => + promise.then( + () => undefined, + (error: unknown) => error, + ); + +/** Real timers: the preload freezes `Date.now()`, never `setTimeout`. */ +const waitFor = async (done: () => boolean, polls = 500): Promise => { + for (let poll = 0; poll < polls && !done(); poll += 1) await Bun.sleep(2); +}; + +const QUICK: BackoffPolicy = { baseMs: 5, maxMs: 5, factor: 1, jitter: 'none' }; + +function harness() { + const clock = frozenClock(1_700_000_000_000); + const broker = new FakeNatsBroker({ clock }); + const open = fakeNatsConnect(broker); + const reported: unknown[] = []; + let attempts = 0; + const connect: NatsConnect = async (options) => { + attempts += 1; + return open(options); + }; + const transport = (overrides: Partial = {}): NatsTransport => + new NatsTransport({ + url: 'nats://bus.test:4222', + bucket: 'x-test', + clock, + rng: () => 0.5, + backoff: QUICK, + connect, + onError: (error) => reported.push(error), + ...overrides, + }); + return { broker, reported, transport, attempts: () => attempts }; +} + +describe('NatsTransport.connectInBackground', () => { + test('returns with the bus down, and a publish is refused at once rather than parked', async () => { + const bus = harness(); + bus.broker.offline = true; + const transport = bus.transport(); + + transport.connectInBackground(); + expect(transport.connected).toBe(false); + await waitFor(() => bus.attempts() >= 2); + const before = bus.attempts(); + const refused = await caught(transport.publish('x.channel.feed', 'lost')); + + expect(codeOf(refused)).toBe('X_TRANSPORT_UNAVAILABLE'); + expect(causeOf(refused)).toContain('has not connected yet'); + // Refused without a dial of its own: a request handler never waits on the bus. + expect(bus.attempts()).toBe(before); + await transport.close(); + }); + + test('the dial is retried on the backoff, never in a spin', async () => { + const bus = harness(); + bus.broker.offline = true; + const transport = bus.transport({ + backoff: { baseMs: 20, maxMs: 20, factor: 1, jitter: 'none' }, + }); + + transport.connectInBackground(); + await Bun.sleep(110); + + // 20 ms apart over ~110 ms: a handful. A loop that spun would be in the thousands. + expect(bus.attempts()).toBeGreaterThanOrEqual(2); + expect(bus.attempts()).toBeLessThan(12); + await transport.close(); + }); + + test('once the bus is up it publishes with no restart, and says so to its listeners', async () => { + const bus = harness(); + bus.broker.offline = true; + const transport = bus.transport(); + let announced = 0; + transport.onReconnect(() => { + announced += 1; + }); + transport.connectInBackground(); + await waitFor(() => bus.attempts() >= 2); + + bus.broker.offline = false; + await waitFor(() => transport.connected); + + expect(transport.connected).toBe(true); + expect(announced).toBe(1); + const seen: string[] = []; + bus.broker + .client() + .subscribe('x.channel.>', (message) => seen.push(new TextDecoder().decode(message.payload))); + await transport.publish('x.channel.feed', 'after'); + expect(seen).toEqual(['after']); + await transport.close(); + }); + + test('a second call, and a call on a connected transport, start no second dial', async () => { + const bus = harness(); + const transport = bus.transport(); + transport.connectInBackground(); + transport.connectInBackground(); + await waitFor(() => transport.connected); + transport.connectInBackground(); + await Bun.sleep(20); + + expect(bus.attempts()).toBe(1); + expect(bus.broker.clients).toHaveLength(1); + await transport.close(); + }); + + test('close() ends the loop: no dial after it, and no client left open', async () => { + const bus = harness(); + bus.broker.offline = true; + const transport = bus.transport(); + transport.connectInBackground(); + await waitFor(() => bus.attempts() >= 1); + + await transport.close(); + const after = bus.attempts(); + bus.broker.offline = false; + await Bun.sleep(30); + + expect(bus.attempts()).toBe(after); + expect(bus.broker.clients).toHaveLength(0); + }); +}); + +describe("NatsTransport with presenceBucket: 'first-use'", () => { + test('a publisher connects to a server with no JetStream, and creates no bucket', async () => { + const bus = harness(); + // Every JetStream call fails, as it does on a nats-server started without `-js`. + bus.broker.fail('$JS.API', 1_000); + const transport = bus.transport({ presenceBucket: 'first-use' }); + + await transport.connect(); + + expect(transport.connected).toBe(true); + expect(bus.broker.streams).toEqual([]); + const seen: string[] = []; + bus.broker.client().subscribe('x.cache.invalidate', (message) => { + seen.push(new TextDecoder().decode(message.payload)); + }); + await transport.publish('x.cache.invalidate', '["post:1"]'); + expect(seen).toEqual(['["post:1"]']); + await transport.close(); + }); + + test('the default still asserts the bucket at the dial: a sync node needs presence to serve', async () => { + const bus = harness(); + bus.broker.fail('$JS.API', 1_000); + const transport = bus.transport(); + + expect(codeOf(await caught(transport.connect()))).toBe('X_TRANSPORT_UNAVAILABLE'); + expect(transport.connected).toBe(false); + await transport.close(); + }); + + test('the first use of the shared set asserts the bucket, once per client', async () => { + const bus = harness(); + const transport = bus.transport({ presenceBucket: 'first-use' }); + await transport.connect(); + expect(bus.broker.streams).toEqual([]); + + await transport.shared.put('room', 'ada', '{}', 30_000); + expect(bus.broker.streams).toEqual(['KV_x-test']); + expect((await transport.shared.entries('room')).map((entry) => entry.member)).toEqual(['ada']); + await transport.close(); + }); +}); + +describe('NatsTransport.connect({ withinMs })', () => { + test('a dial that does not land in time is refused, naming the server and the wait', async () => { + const bus = harness(); + const landed = Promise.withResolvers(); + const transport = bus.transport({ connect: () => landed.promise }); + + const startedAt = performance.now(); + const refused = await caught(transport.connect({ withinMs: 40 })); + + expect(performance.now() - startedAt).toBeLessThan(1_000); + expect(codeOf(refused)).toBe('X_TRANSPORT_UNAVAILABLE'); + expect(causeOf(refused)).toContain('bus.test:4222'); + expect(causeOf(refused)).toContain('within 40ms'); + expect(isUltimateError(refused) ? refused.fix : '').toContain('nats-server'); + + // The boot unwinds by closing the transport; the dial that lands afterwards is not leaked. + await transport.close(); + landed.resolve(bus.broker.client()); + await waitFor(() => bus.broker.clients.length === 0); + expect(bus.broker.clients).toHaveLength(0); + }); + + test('a dial that lands in time resolves, and one the bus keeps refusing says so in the cause', async () => { + const bus = harness(); + const up = bus.transport(); + await up.connect({ withinMs: 1_000 }); + expect(up.connected).toBe(true); + await up.close(); + + bus.broker.offline = true; + const down = bus.transport(); + const refused = await caught(down.connect({ withinMs: 60 })); + expect(codeOf(refused)).toBe('X_TRANSPORT_UNAVAILABLE'); + expect(causeOf(refused)).toContain('within 60ms'); + expect(causeOf(refused)).toContain('refused the connection'); + // Retried inside the wait, not given up on at the first refusal. + expect(bus.attempts()).toBeGreaterThan(2); + await down.close(); + }); + + test('a bus that comes up inside the wait is a boot that succeeds', async () => { + const bus = harness(); + bus.broker.offline = true; + const transport = bus.transport(); + const connecting = transport.connect({ withinMs: 2_000 }); + await waitFor(() => bus.attempts() >= 2); + bus.broker.offline = false; + + await connecting; + expect(transport.connected).toBe(true); + await transport.close(); + }); + + test('closing the transport under the wait ends it, coded', async () => { + const bus = harness(); + bus.broker.offline = true; + const transport = bus.transport(); + const connecting = caught(transport.connect({ withinMs: 5_000 })); + await waitFor(() => bus.attempts() >= 1); + await transport.close(); + + expect(codeOf(await connecting)).toBe('X_TRANSPORT_UNAVAILABLE'); + }); +}); + +describe('NatsTransport.publish while the client is reconnecting', () => { + test('is refused at once: the library would queue it without bound and replay it late', async () => { + const bus = harness(); + const transport = bus.transport(); + await transport.connect(); + const seen: string[] = []; + bus.broker + .client() + .subscribe('x.channel.>', (message) => seen.push(new TextDecoder().decode(message.payload))); + + bus.broker.drop(); + const refused = await caught(transport.publish('x.channel.feed', 'during')); + expect(codeOf(refused)).toBe('X_TRANSPORT_UNAVAILABLE'); + expect(causeOf(refused)).toContain('reconnecting'); + + bus.broker.restore(); + await transport.publish('x.channel.feed', 'after'); + expect(seen).toEqual(['after']); + await transport.close(); + }); +}); diff --git a/packages/realtime/src/nats-transport.test.ts b/packages/realtime/src/nats-transport.test.ts index 7d9f35584..1cc45f47b 100644 --- a/packages/realtime/src/nats-transport.test.ts +++ b/packages/realtime/src/nats-transport.test.ts @@ -176,10 +176,16 @@ describe('NatsTransport', () => { harness.broker.drop(); expect(transport.connected).toBe(false); - // A caller that arrives mid-drop gets the same client back. Dialling a second one here is the - // bug the library's own reconnect exists to prevent: it would come back alongside the one - // already recovering, with its own copy of every subscription, and double every change. - await transport.publish('x.change.posts', 'during'); + // A caller that arrives mid-drop is refused at once, on the same client. Dialling a second one + // here is the bug the library's own reconnect exists to prevent: it would come back alongside + // the one already recovering, with its own copy of every subscription, and double every + // change. Handing the publish to the client is the other bug: the real one queues it without + // bound and replays it when the server is back. + const during = await transport.publish('x.change.posts', 'during').then( + () => undefined, + (error: unknown) => error, + ); + expect(isUltimateError(during) ? during.code : during).toBe('X_TRANSPORT_UNAVAILABLE'); expect(harness.dials()).toBe(1); harness.broker.restore(); await settle(); diff --git a/packages/realtime/src/nats-transport.ts b/packages/realtime/src/nats-transport.ts index d908a0cb4..9e3589331 100644 --- a/packages/realtime/src/nats-transport.ts +++ b/packages/realtime/src/nats-transport.ts @@ -3,6 +3,11 @@ // re-establishing subscriptions, which is what makes a `sync` node stateless. The one loss it does // not own is its own end: a client closed for good once its reconnect budget is spent is replaced // here, on our backoff, and every kept subscription is bound again on the new one. +// +// Two ways to open it, because two kinds of process hold one. A node that SERVES from the bus +// awaits `connect()` and refuses to boot without it; a process that only PUBLISHES calls +// `connectInBackground()` and boots regardless — its publishes are refused, typed and at once, +// until the dial lands. import { type Clock, @@ -39,6 +44,19 @@ export interface NatsTransportOptions { readonly rng?: Rng; /** Injected so the whole transport — reconnect included — runs in a test with no network. */ readonly connect?: NatsConnect; + /** + * When the presence bucket is asserted. `'dial'` (the default) is a node that serves presence: no + * JetStream, no connection. `'first-use'` is a process that only publishes — it never reads + * `shared`, so a server without JetStream, or without the bucket, must not cost it the bus. + */ + readonly presenceBucket?: 'dial' | 'first-use'; +} + +export interface NatsConnectWait { + /** Refuse with `X_TRANSPORT_UNAVAILABLE` once this long has passed without a connection. */ + readonly withinMs?: number | undefined; + /** The `fix:` of that refusal — the caller knows which role is waiting and what it needs. */ + readonly fix?: string | undefined; } const DEFAULT_ATTEMPTS = 10; @@ -57,8 +75,16 @@ export class NatsTransport implements Transport { #dialing: Promise | undefined; #retries = 0; #closed = false; - /** Set while a client the library gave up on is being replaced; the attempt in flight. */ + /** False until the first dial lands: what a refusal says while a background dial is in flight. */ + #everUp = false; + readonly #lazyBucket: boolean; + /** Under `'first-use'`: the clients whose bucket has been asserted since they last connected. */ + readonly #bucketed = new WeakSet(); + /** Set while no client is held and one is being dialled in the background; the attempt in flight. */ #redialing: number | undefined; + #redialLoop: Promise | undefined; + /** The last background dial's own refusal, for the cause of a `connect({ withinMs })` that gave up. */ + #lastFailure: string | undefined; #wakeRedial: (() => void) | undefined; readonly #subscriptions = new NatsSubscriptions(); readonly #reconnectListeners = new Set<() => void>(); @@ -76,16 +102,60 @@ export class NatsTransport implements Transport { options.maxReconnectAttempts ?? DEFAULT_ATTEMPTS, ); this.#rng = options.rng ?? Math.random; + this.#lazyBucket = options.presenceBucket === 'first-use'; this.shared = new NatsKvSet({ - client: () => this.#ensure(), + client: () => this.#presenceClient(), bucket: options.bucket, clock: options.clock ?? systemClock, }); } - /** Fail fast at boot rather than on the first change: `/readyz` is meant to catch a dead bus. */ - async connect(): Promise { - await this.#ensure(); + /** + * Fail fast at boot rather than on the first change: `/readyz` is meant to catch a dead bus. + * Bare, it is ONE dial. With `withinMs` the dial is retried on our backoff for that long — a + * node that raced the bus into readiness recovers on its own — and then refused, naming the + * server, the wait and the last attempt's own failure. The retry is not stopped by the refusal; + * `close()` stops it, and that is what a failed boot calls. + */ + async connect(wait: NatsConnectWait = {}): Promise { + if (wait.withinMs === undefined) { + await this.#ensure(); + return; + } + const withinMs = finiteOption('createNatsTransport', 'connect.withinMs', wait.withinMs); + const target = parseNatsUrl(this.#options.url); + // A real timer, never the injected clock: the wait bounds a container's boot, which the + // kubelet counts in real seconds. + let timer: ReturnType | undefined; + const late = new Promise((_, reject) => { + timer = setTimeout(() => { + const last = this.#lastFailure === undefined ? '' : ` — last attempt: ${this.#lastFailure}`; + reject( + new TransportUnavailableError({ + transport: this.name, + reason: `${target.host}:${target.port} did not accept a connection within ${withinMs}ms${last}`, + ...(wait.fix === undefined ? {} : { fix: wait.fix }), + }), + ); + }, withinMs); + }); + try { + await Promise.race([this.#client === undefined ? this.#redial() : undefined, late]); + } finally { + clearTimeout(timer); + } + // The loop also ends when the transport is closed under it. + if (this.#client === undefined) await this.#ensure(); + } + + /** + * Dial without being waited for: retried on our backoff until it lands or `close()` runs, and + * announced to the `onReconnect` listeners when it does. Until then every publish and subscribe + * is refused at once (`#ensure`) — never parked behind the dial, never queued. + */ + connectInBackground(): void { + if (this.#closed || this.#client !== undefined) return; + void this.#redial(); } get connected(): boolean { @@ -94,6 +164,16 @@ export class NatsTransport implements Transport { async publish(subject: string, payload: string): Promise { const client = await this.#ensure(); + // The library BUFFERS a publish made while it reconnects, without bound, and replays the lot + // when the server is back: a queue nobody sized, delivering events whose only meaning was + // "re-read now" minutes late. A subscriber is told of the gap (`onReconnect`); the publisher + // is told here. + if (!client.connected) { + throw new TransportUnavailableError({ + transport: this.name, + reason: `publish to ${subject} was refused: the client is reconnecting to the bus`, + }); + } // `client.publish` is synchronous and refuses locally: a bad subject, a payload over the // server's `max_payload`, a connection torn down between the `#ensure` and this line. Those // are the LIBRARY's errors — or an app-supplied `connect`'s — so they arrive uncoded, and @@ -167,7 +247,9 @@ export class NatsTransport implements Transport { return Promise.reject( new TransportUnavailableError({ transport: this.name, - reason: `the connection closed once its reconnect budget was spent, and re-dial attempt ${this.#redialing} is in progress`, + reason: this.#everUp + ? `the connection closed once its reconnect budget was spent, and re-dial attempt ${this.#redialing} is in progress` + : `the bus has not connected yet, and dial attempt ${this.#redialing} is in progress`, }), ); } @@ -208,7 +290,7 @@ export class NatsTransport implements Transport { }, }); try { - await this.#ensureBucket(client); + if (!this.#lazyBucket) await this.#ensureBucket(client); if (closedEarly) { throw new TransportUnavailableError({ transport: this.name, @@ -229,10 +311,21 @@ export class NatsTransport implements Transport { } opened = client; this.#client = client; + this.#everUp = true; this.#retries = 0; return client; } + /** `shared`'s client: under `'first-use'` this is where the bucket is asserted, once per client. */ + async #presenceClient(): Promise { + const client = await this.#ensure(); + if (this.#lazyBucket && !this.#bucketed.has(client)) { + await this.#ensureBucket(client); + this.#bucketed.add(client); + } + return client; + } + /** * The library spent its reconnect budget and closed the client. Handing it out again is a node * that refuses every publish until somebody restarts it — and the liveness probe never asks the @@ -253,18 +346,26 @@ export class NatsTransport implements Transport { } /** - * Re-dial until a client is up or the transport is closed. Bounded by our backoff between - * attempts (capped at the policy's `maxMs`), and each attempt is itself a library dial with its - * own budget, so a long outage costs one dial per interval rather than a spin. A dial that lands - * re-binds every kept subscription and is announced: changes published in the gap are gone. + * Dial until a client is up or the transport is closed — the first dial of a process that does + * not wait for the bus, and the replacement of a client the library gave up on. One loop however + * many callers ask. Bounded by our backoff between attempts (capped at the policy's `maxMs`), so + * a long outage costs one dial per interval rather than a spin. A dial that lands re-binds every + * kept subscription and is announced: changes published in the gap are gone. */ - async #redial(): Promise { - if (this.#redialing !== undefined) return; + #redial(): Promise { + this.#redialLoop ??= this.#redialUntilUp().finally(() => { + this.#redialLoop = undefined; + }); + return this.#redialLoop; + } + + async #redialUntilUp(): Promise { try { for (let attempt = 1; !this.#closed && this.#client === undefined; attempt += 1) { this.#redialing = attempt; try { const client = await this.#dialOnce(); + this.#lastFailure = undefined; // Coded like a first subscribe's refusal; the subscription stays kept for the next client. for (const failure of this.#subscriptions.bindAll(client)) { this.#report( @@ -275,7 +376,10 @@ export class NatsTransport implements Transport { this.#announce(); } catch (error) { if (this.#closed) return; - this.#report(error, this.name); + this.#lastFailure = renderThrowable(error); + // Attempts 1, 2, 4, 8, …: an outage is said at once and then ever more rarely, rather + // than once per dial per pod for as long as it lasts. + if ((attempt & (attempt - 1)) === 0) this.#report(error, this.name); await this.#pause(policyDelay(this.#backoff, attempt, this.#rng)); } } @@ -319,7 +423,9 @@ export class NatsTransport implements Transport { const client = this.#client; if (client === undefined) return; // Not awaited: the library calls this from its status loop. The failure has one place to go. - void this.#ensureBucket(client).catch((error: unknown) => this.#report(error, this.name)); + // A lazy bucket is forgotten instead, and asserted again by whoever next reads `shared`. + if (this.#lazyBucket) this.#bucketed.delete(client); + else void this.#ensureBucket(client).catch((error: unknown) => this.#report(error, this.name)); this.#announce(); } diff --git a/packages/realtime/src/server.ts b/packages/realtime/src/server.ts index 1af94354d..c0faaab6f 100644 --- a/packages/realtime/src/server.ts +++ b/packages/realtime/src/server.ts @@ -256,6 +256,8 @@ export { reconnectFrame, } from './thundering-herd'; export { + BUS_CONNECT_WAIT_MS, + type BusUse, DEFAULT_PRESENCE_BUCKET, DEFAULT_PRESENCE_TTL_MS, type SelectTransportOptions, diff --git a/packages/realtime/src/transport-env.test.ts b/packages/realtime/src/transport-env.test.ts index 0f64c90f5..68587b538 100644 --- a/packages/realtime/src/transport-env.test.ts +++ b/packages/realtime/src/transport-env.test.ts @@ -178,6 +178,82 @@ describe('selectTransport', () => { expect(codeOf(error)).toBe('X_CONFIG_INVALID'); }); + // What the process DOES with the bus decides whether its boot waits for it. Until 2026-10 every + // role awaited the dial and the JetStream bucket, so a web pod restarting while NATS was down + // never served a page — for a bus it only publishes "re-read" events to. + test("use: 'publish' connects in the background: connect() resolves with the bus down", async () => { + const broker = new FakeNatsBroker(); + broker.offline = true; + const selection = selectTransport({ NATS_URL: URL }, NATS, { + use: 'publish', + clock: frozenClock(0), + connect: fakeNatsConnect(broker), + backoff: { baseMs: 2, maxMs: 2, factor: 1, jitter: 'none' }, + onError: () => undefined, + }); + + await selection.connect(); + expect(selection.use).toBe('publish'); + expect(selection.state()).toBe('connecting'); + const refused = await selection.transport.publish('x.channel.feed', '{}').then( + () => undefined, + (error: unknown) => error, + ); + expect(codeOf(refused)).toBe('X_TRANSPORT_UNAVAILABLE'); + + broker.offline = false; + for (let poll = 0; poll < 500 && selection.state() !== 'up'; poll += 1) await Bun.sleep(2); + expect(selection.state()).toBe('up'); + // A publisher never reads presence, so it asks JetStream for nothing. + expect(broker.streams).toEqual([]); + await selection.transport.close(); + }); + + test("use: 'feed' awaits the dial and creates no bucket: a replicator serves no presence", async () => { + const broker = new FakeNatsBroker(); + const selection = selectTransport({ NATS_URL: URL }, NATS, { + use: 'feed', + clock: frozenClock(0), + connect: fakeNatsConnect(broker), + }); + await selection.connect(); + + expect(selection.state()).toBe('up'); + expect(broker.streams).toEqual([]); + await selection.transport.close(); + }); + + test("use: 'sockets' is the default and stays a hard dependency, refused within its wait", async () => { + const broker = new FakeNatsBroker(); + const hung = Promise.withResolvers(); + const selection = selectTransport({ NATS_URL: URL }, NATS, { + clock: frozenClock(0), + connect: () => hung.promise, + connectWithinMs: 30, + }); + expect(selection.use).toBe('sockets'); + + const refused = await selection.connect().then( + () => undefined, + (error: unknown) => error, + ); + expect(codeOf(refused)).toBe('X_TRANSPORT_UNAVAILABLE'); + const said = isUltimateError(refused) ? `${refused.cause} | ${refused.fix}` : ''; + expect(said).toContain('within 30ms'); + // The variable to check, what this process needs it for, and which roles do not. + expect(said).toContain('NATS_URL'); + expect(said).toContain('serves sockets'); + expect(said).not.toContain('bus.test:4222/'); + expect(broker.clients).toHaveLength(0); + await selection.transport.close(); + }); + + test('the in-process bus is always up, whatever the use', async () => { + const selection = selectTransport({}, MEMORY, { use: 'publish' }); + await selection.connect(); + expect(selection.state()).toBe('up'); + }); + test('the keys it reads are exactly these', () => { expect([...TRANSPORT_ENV_KEYS]).toEqual(['NATS_URL', 'NATS_KV_BUCKET']); }); diff --git a/packages/realtime/src/transport-env.ts b/packages/realtime/src/transport-env.ts index 0ccc96b0c..ec98ab9cd 100644 --- a/packages/realtime/src/transport-env.ts +++ b/packages/realtime/src/transport-env.ts @@ -11,6 +11,7 @@ import { InProcessTransport } from './fanout'; import type { NatsConnect } from './nats-client'; import { assertBucket } from './nats-jetstream'; import { NatsTransport } from './nats-transport'; +import type { BackoffPolicy } from './thundering-herd'; /** * The keys read here, and nothing else. Named once so docs and tests cannot drift from the code. @@ -36,6 +37,27 @@ export const DEFAULT_PRESENCE_TTL_MS = 30_000; export type TransportEnvironment = Readonly>; +/** + * What this process does with the bus, which decides whether its boot waits for it: + * + * - `'sockets'` — it serves sockets from the bus (a `sync` node). The dial and the presence bucket + * are awaited, and a bus that is not there within `connectWithinMs` refuses the boot. + * - `'feed'` — it feeds those nodes (the replicator). The dial is awaited; it reads no presence, + * so it asks JetStream for nothing. + * - `'publish'` — it only publishes channel events and cache invalidations (`web`, `worker`, + * `scheduler`). The dial runs in the background and the boot does not wait: both kinds of + * message mean "re-read", and a page that cannot say it is still a page. + */ +export type BusUse = 'sockets' | 'feed' | 'publish'; + +/** How long a process that cannot work without the bus waits for it before refusing its boot. */ +export const BUS_CONNECT_WAIT_MS = 15_000; + +const NEEDS: Record, string> = { + sockets: 'serves sockets from the bus', + feed: 'feeds the sync nodes over the bus', +}; + export interface TransportSelection { readonly transport: Transport; /** `embedded` fans out in this process only; `external` reaches every node on the bus. */ @@ -50,12 +72,18 @@ export interface TransportSelection { readonly bucket: string | null; /** What `PresenceRegistry` must be given, so its TTL and the bucket's cannot disagree. */ readonly presenceTtlMs: number; + /** What the process does with the bus, as `connect()` and `state()` obey it. */ + readonly use: BusUse; /** * Dial now rather than on the first change nobody receives. Selection itself stays pure — it * parses env and constructs, it does not touch a socket — so a boot can order its dials. - * Embedded resolves immediately: there is nothing to reach. + * Embedded resolves immediately: there is nothing to reach. Under `use: 'publish'` it STARTS the + * dial and resolves at once; under the other two it resolves connected or rejects with + * `X_TRANSPORT_UNAVAILABLE` inside `connectWithinMs`. */ connect(): Promise; + /** `'connecting'` while a NATS bus is not reachable; the in-process bus is always `'up'`. */ + state(): 'up' | 'connecting'; } export interface SelectTransportOptions { @@ -63,6 +91,14 @@ export interface SelectTransportOptions { readonly clock?: Clock | undefined; /** Injected so a boot — reconnect included — can be proven with no network. */ readonly connect?: NatsConnect | undefined; + /** Default `'sockets'`: a caller that does not say is held to the strictest reading. */ + readonly use?: BusUse | undefined; + /** Default `BUS_CONNECT_WAIT_MS`. Read under `'sockets'` and `'feed'` only. */ + readonly connectWithinMs?: number | undefined; + /** The dial's retry curve; the transport's own default when unset. */ + readonly backoff?: BackoffPolicy | undefined; + /** Where the transport's background failures go; its own logger line when unset. */ + readonly onError?: ((error: unknown, subject: string) => void) | undefined; } const nonEmpty = (value: string | undefined): string | undefined => @@ -92,6 +128,7 @@ export function selectTransport( 'presenceTtlMs', options.presenceTtlMs ?? DEFAULT_PRESENCE_TTL_MS, ); + const use = options.use ?? 'sockets'; if (topology.transport === 'memory') { refuseStrayBusUrl(env, topology); @@ -104,7 +141,9 @@ export function selectTransport( detail: `in-process fanout — set realtime.transport 'nats' in ${CONFIG_FILE} and NATS_URL to reach the other nodes`, bucket: null, presenceTtlMs, + use, connect: () => Promise.resolve(), + state: () => 'up', }; } @@ -124,16 +163,37 @@ export function selectTransport( url, bucket, presenceTtlMs, + // Only a node that serves presence needs the bucket to exist before it can start. + presenceBucket: use === 'sockets' ? 'dial' : 'first-use', ...(options.clock === undefined ? {} : { clock: options.clock }), ...(options.connect === undefined ? {} : { connect: options.connect }), + ...(options.backoff === undefined ? {} : { backoff: options.backoff }), + ...(options.onError === undefined ? {} : { onError: options.onError }), }); + const withinMs = finiteOption( + 'the transport env', + 'connectWithinMs', + options.connectWithinMs ?? BUS_CONNECT_WAIT_MS, + ); return { transport, mode: 'external', detail: urlEnv, bucket, presenceTtlMs, - connect: () => transport.connect(), + use, + connect: async () => { + if (use === 'publish') { + transport.connectInBackground(); + return; + } + await transport.connect({ + withinMs, + // The variable, never the url behind it. `-js` only where the bucket is asked for. + fix: `x doctor — then check ${urlEnv} names a reachable nats-server${use === 'sockets' ? ' started with -js (JetStream)' : ''} — this process ${NEEDS[use]} and cannot start without it; the web, worker and scheduler roles boot without one and connect in the background`, + }); + }, + state: () => (transport.connected ? 'up' : 'connecting'), }; } diff --git a/wiki/Deployment.md b/wiki/Deployment.md index 244d51a9f..667138b03 100644 --- a/wiki/Deployment.md +++ b/wiki/Deployment.md @@ -45,11 +45,13 @@ The body is `{ state, ready, role }` for everyone, and `{ state, ready, uptimeMs | Registered check | When it exists | What it reads | |---|---|---| | `database` | always | the previous `db.ping()`, refreshed on read — never awaited inside the probe | -| `transport` | only when the transport can report a connection: NATS can, the in-process bus cannot | `transport.connected` | +| `transport` | only when the transport can report a connection: NATS can, the in-process bus cannot | `transport.connected`. `failing` on `sync` and the replicator; **`degraded`** on `web`, `worker` and `scheduler`, which only publish to the bus and serve without it (`As of 2026-10`) | | anything per-role | **never** `As of 2026-08-22` | this table used to list five — replication lag, migration-version skew, "one pool claiming", "holds the leader lock", "slot active" — and none was wired. The one since is `replicator` (`As of 2026-10-02`: failing while its stream is down). A `scheduler` standby does not report not-ready: its `/readyz` answers exactly as the leader's | **`health: { readiness: 'process' }` in `app.config.ts`** (`As of 22.5`; default `'dependencies'`). Every replica shares the database, so one blip fails `database` everywhere at once and the ingress answers "no available server" for the whole site — pages that never touch the database included. In `'process'` mode `/readyz` is 503 only while starting, draining or stopped; a failing check stays 200 with `ready: true` and the check still named `failing` in `checks`. `/readyz?deep=1` always answers in `'dependencies'` mode — point monitoring there. Web and sync roles alike; liveness is unchanged in both modes. +**A check has three answers: `ok`, `degraded`, `failing`** (`As of 2026-10`). `degraded` is a dependency the role serves without — today, the bus on a role that only publishes to it. It never turns `/readyz` into a 503, in either mode, so a NATS outage cannot pull every web pod from the ingress; `/readyz?deep=1` is strict and answers 503 for it. An app registers its own with `registerReadinessCheck(name, check, { onFailure: 'degraded' })`. + **Which build answers is a header, on every health answer** (`As of 27.2.3`). `/healthz`, `/readyz` and `/readyz?deep=1` send `x-ultimate-build` — the same header every page sends — on the web port, the sync port and the metrics listener alike, whoever asks. The body does not change: a stranger still reads `{ state, ready, role }`. A deploy check that waits for the new build polls `curl -sI https:///readyz | grep -i x-ultimate-build` rather than a page. Two cases send none: a web role whose `buildId` is `null` (no `BUILD_ID` and none from the boot), and the metrics listener in the moments before its boot has computed the id — a container opens it first, so a cold pod's probe gets the status without the header. **`registered: 0` is a real answer, not an error.** An empty registry is still ready, so a 200 means no more than "the socket is bound" — which is what the chart's and compose's healthchecks route traffic on. Read `registered` before you trust `checks: {}`. diff --git a/wiki/Error-Codes.md b/wiki/Error-Codes.md index b6c6085e0..3ba32d603 100644 --- a/wiki/Error-Codes.md +++ b/wiki/Error-Codes.md @@ -432,7 +432,7 @@ No secret and no signature reaches a `cause`, a `fix` or a `meta`, and a URL is | `X_PROTOCOL_VERSION` | client and sync node disagree on the wire protocol | a client from an older build | `x build` and redeploy the client; the node sends `update-available` before draining | | `X_CURSOR_STALE` | the resume LSN is outside the change buffer | a long disconnect | pass `snapshot` to `resumeFrom()` so the fallback re-snapshots | | `X_REBASE_CONFLICT` | a local mutation could not be rebased | server state moved incompatibly | set `conflict: 'server-wins'`, or return a row from `custom(merge)` | -| `X_TRANSPORT_UNAVAILABLE` | the fanout bus is unreachable | the nats-server `NATS_URL` names is down or misconfigured | `x doctor` — then check `NATS_URL` | +| `X_TRANSPORT_UNAVAILABLE` | the fanout bus is unreachable | the nats-server `NATS_URL` names is down or misconfigured. **At boot** only a `sync` node or a replicator raises it, after retrying the dial for 15 s — the cause names the server, the wait and the last attempt's own failure. A `web`, `worker` or `scheduler` process boots without the bus and raises it from a **publish** instead (`publishChannelEvent`, the cache-invalidation broadcast), at once, until its background dial lands; a publish made while the client is reconnecting is refused the same way rather than queued ([Realtime → what each role needs from the bus](Realtime#what-each-role-needs-from-the-bus)) | `x doctor` — then check `NATS_URL`; in app code, catch it around a publish and log — the event meant "re-read" | | `X_TRANSPORT_PROTOCOL` | the bus does not speak the protocol this build speaks | nats-server older than 2.11, JetStream not enabled, or something that is not NATS on the port | run `nats:2.11-alpine` or newer with `-js`; reconnecting cannot fix it, so this never retries | | `X_REPLICATION_FAILED` | the replication connection was refused | `wal_level` not `logical`, a role that may not create or extend the publication (the replicator ensures it at boot), a role without `REPLICATION`, a slot another replicator holds, wrong credentials | the message names the object; the fix is the exact setting, `CREATE PUBLICATION` or `pg_drop_replication_slot` statement — and a `REPLICATION` grant only on a cluster dedicated to the app ([why](https://github.com/developerz-ai/ultimate/blob/main/docs/ops/01-kubernetes.md#replication-is-a-cluster-wide-grant)) | | `X_REPLICATION_PROTOCOL` | the WAL stream cannot be decoded | a server or `pgoutput` version this build does not speak, or a proxy on the replication port | `x doctor --json` — point the URL at postgres itself, on a server ≥ 14 | diff --git a/wiki/Realtime.md b/wiki/Realtime.md index 2dd1cf710..b97fe0d52 100644 --- a/wiki/Realtime.md +++ b/wiki/Realtime.md @@ -357,6 +357,28 @@ plan-101 DX ledger #21. | the browser | `useChannel(decl, params, handlers?)`; `topic()` is the one way to spell a topic, and `bun run channel-literals` refuses any other | | the manifest | lists every channel (`describeChannels`, on `@ultimat3/realtime/server`). In a contract diff these are **breaking**: a channel removed, its params changed, its policy changed, a record type no longer carried, `events` switched off | +## What each role needs from the bus + +Under `realtime: { transport: 'nats' }` every role holds a connection, and only two cannot work without one (`As of 2026-10`). The role decides, not the transport: a role that only **publishes** sends channel events and cache invalidations, and both mean "re-read". + +| Role | Uses the bus to | At boot | NATS down while running | JetStream / the presence bucket | `transport` check | +|---|---|---|---|---|---| +| `sync` | serve sockets: subscribe to changes and channels, hold presence | **awaits** the dial, retried on backoff for 15 s, then refuses the boot with `X_TRANSPORT_UNAVAILABLE` naming the server, the wait, the last attempt's failure and the variable to check | reconnects on its own; windows re-snapshot on return | **required at the dial** — no `-js`, no boot | `failing` | +| `replicator` | publish committed changes to the nodes | **awaits** the dial, same 15 s, same refusal | reconnects on its own | not asked for | `failing` | +| `web`, `worker`, `scheduler` | publish channel events (`publishChannelEvent`) and cache invalidations; receive peers' invalidations | **does not wait**: dials in the background on a jittered backoff (500 ms doubling to 30 s) and boots, serves and runs jobs meanwhile | stays up and ready; resumes on its own, no restart | not asked for — asserted only if something reads presence | `degraded` | +| `migrate` | nothing | never dials | — | — | — | + +`x dev` is one process running several roles and takes the strictest of them: with `sync` in the set (the default) it awaits the bus, with `--role web,worker` it does not. `realtime.enabled: false` starts neither realtime role, so no process of such an app waits for the bus — the connection is still dialled in the background, because cache invalidation between replicas crosses it. + +| While the bus is down, on a publishing role | What happens | +|---|---| +| `publishChannelEvent(…)` | rejects at once with `X_TRANSPORT_UNAVAILABLE` — never parked behind the dial, never queued. Catch it and log: the event said "re-read", and a subscriber that reconnects re-reads anyway | +| a publish made while the client is **reconnecting** | refused the same way. The `nats` client would otherwise buffer it without bound and replay it when the server returned | +| an action's `invalidates` / `invalidateTags` | every local tier, Redis and the CDN are cleared as usual; the broadcast to the other replicas fails into `report.errors` (`tier: 'broadcast'`, logged as `cache.invalidate.partial`) and the write succeeds. **A missed bust is not replayed**: another replica's in-process `lru` copy and its ISR page stay until their TTL. Nothing is buffered for later, because a replica whose own connection was down missed its peers' busts too and no sender-side queue reaches it | +| `/readyz` | 200 in both `health.readiness` modes, `checks.transport: 'degraded'` | +| `/readyz?deep=1` | 503 — the reading a monitor alerts on | +| the log | the boot line `{"msg":"ultimate started",…,"bus":"nats(connecting)"}` (`nats(up)` when it already is, `in-process` with no NATS); `{"msg":"ultimate bus","bus":"nats(up)"}` when the dial lands, and again after every recovery; `nats transport error` on dial attempts 1, 2, 4, 8, … | + ## LSN cursors Every frame carries an LSN. The client's last-seen LSN is what makes reconnect a **delta** instead of a refetch. @@ -549,7 +571,7 @@ A client on build `A` connecting to a `sync` node on build `B` is **accepted**, | `X_SYNC_UNCONFIGURED` | a live hook needed the page socket, and neither `installRealtime({ sync })` nor `` named a target. The meta is not rendered at all when `app.config.ts` says `realtime: { enabled: false }`: no node is started, so there is nothing to dial (22.2.2) | serve the page through `x dev` or the container, which render the meta, or pass `installRealtime({ signal, sync: { url, buildId } })` | | `X_RECORD_REJECTED` | a row reached the record store with no key, or not as an object | `x entities show --json`, then return whole rows | | `X_MUTATOR_CLOCK_MISSING` | `conflict: 'last-write-wins'` with no number `updatedAt` on the entity | add the clock, or declare `conflict: 'server-wins'` | -| `X_TRANSPORT_UNAVAILABLE` | the fanout bus is down | `x doctor — then check NATS_URL points at a reachable nats-server` | +| `X_TRANSPORT_UNAVAILABLE` | the fanout bus is down. At boot only for `sync` and the replicator, after a bounded wait; on `web`, `worker` and `scheduler` it is what a publish rejects with while the bus is away ([what each role needs](#what-each-role-needs-from-the-bus)) | `x doctor — then check NATS_URL points at a reachable nats-server` | | `X_TRANSPORT_PROTOCOL` | the bus answers in a protocol this build does not speak | `the bus must be nats-server >= 2.11 with JetStream enabled (nats-server -js)` | | `X_BUILD_SKEW` | client build's contract is incompatible with the server's | reload the client; see the fix line on the error | diff --git a/wiki/Tutorial-05-Deploy-Free.md b/wiki/Tutorial-05-Deploy-Free.md index 8f2a78629..a2e36c34d 100644 --- a/wiki/Tutorial-05-Deploy-Free.md +++ b/wiki/Tutorial-05-Deploy-Free.md @@ -46,7 +46,7 @@ docker run -d --name myapp-web -e ROLE=web -e PORT=8080 -p 8085:8080 myapp:dev ```text {"ts":"2026-08-11T17:12:04.499Z","level":"info","msg":"ultimate web listening on http://0.0.0.0:8080"} -{"ts":"2026-08-11T17:12:04.502Z","level":"info","msg":"ultimate started","role":"web","url":"http://0.0.0.0:8080","buildId":"ed71a3fe16aa534e"} +{"ts":"2026-08-11T17:12:04.502Z","level":"info","msg":"ultimate started","role":"web","url":"http://0.0.0.0:8080","buildId":"ed71a3fe16aa534e","bus":"in-process"} ``` ```bash From 88eeee0fb91b0f8f583d9697d9582b7402a7d359 Mon Sep 17 00:00:00 2001 From: sebi Date: Sat, 10 Oct 2026 17:59:27 -0500 Subject: [PATCH 2/3] fix(cache): a bust refused while the bus is away is published when it returns, and a replica that was disconnected drops what it held; the replicator rides out a NATS restart; the dial loop survives a lost client and a throwing reporter MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Review of #755. - cli: the invalidation hop keeps refused wire tags (de-duplicated, at most 1,024; past that one flush-all marker) and publishes them on the transport's reconnect or after the next accepted publish. A process whose connection came back, or whose boot subscribe landed after a refusal, calls flushProcessTiers(). The subscribe retry is woken by the reconnect and warns on attempts 1, 2, 4, 8. - cache: flushProcessTiers() clears in-process tiers (CacheTier.clear, lru), marks every tag-revalidated ISR page stale and fences out fills in flight. - realtime: the replicator retries a publish refused because the bus is away three times over 2 s before ending the run. #redialLoop is cleared in the loop's own finally, so a client lost in the microtask after the loop lands starts a new one. #report is total. Each dial has a 4 s connect timeout; pings are 10 s apart, two unanswered; the client's own protocol flag is read before a publish, so nothing is buffered once its socket has closed. - ServedApp.bus is optional. CHANGELOG states the type changes and the one window in which the client can still buffer. - serve-graph pins raised 939 → 940 and 1066 → 1067 for nats-dial-wait.ts. Co-Authored-By: Claude Opus 5.5 --- CHANGELOG.md | 11 +- docs/ops/01-kubernetes.md | 7 +- packages/cache/CLAUDE.md | 3 + packages/cache/README.md | 13 +- packages/cache/src/fence.ts | 11 + packages/cache/src/flush.test.ts | 115 ++++++++ packages/cache/src/index.ts | 2 + packages/cache/src/invalidate.ts | 68 ++++- packages/cache/src/lru.ts | 3 + packages/cache/src/tiers.ts | 6 + packages/cli/src/runtime-bus.live.test.ts | 13 + .../cli/src/runtime-cache-bus-loss.test.ts | 269 ++++++++++++++++++ packages/cli/src/runtime-cache.ts | 112 +++++++- packages/cli/src/serve-graph.test.ts | 9 +- packages/cli/src/serve-types.ts | 5 +- packages/realtime/src/nats-client.ts | 5 + packages/realtime/src/nats-dial-wait.ts | 61 ++++ .../src/nats-lib-client-bounds.test.ts | 74 +++++ packages/realtime/src/nats-lib-client.ts | 32 ++- .../src/nats-transport-background.test.ts | 96 +++++++ packages/realtime/src/nats-transport.ts | 63 ++-- packages/realtime/src/replicator-blip.test.ts | 127 +++++++++ .../realtime/src/replicator-races.test.ts | 152 +--------- .../realtime/src/replicator-rig-fixture.ts | 159 +++++++++++ packages/realtime/src/replicator.ts | 39 ++- wiki/Error-Codes.md | 2 +- wiki/Realtime.md | 13 +- 27 files changed, 1254 insertions(+), 216 deletions(-) create mode 100644 packages/cache/src/flush.test.ts create mode 100644 packages/cli/src/runtime-cache-bus-loss.test.ts create mode 100644 packages/realtime/src/nats-dial-wait.ts create mode 100644 packages/realtime/src/replicator-blip.test.ts create mode 100644 packages/realtime/src/replicator-rig-fixture.ts diff --git a/CHANGELOG.md b/CHANGELOG.md index 44d0f067a..7f19e86d2 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -10,15 +10,18 @@ Semver applies from 1.0.0. A breaking change to a documented API needs a major ### Fixed -Tier 0 — core. Tier 3 — realtime. Tier 5 — cli. +Tier 0 — core. Tier 1 — cache. Tier 3 — realtime. Tier 5 — cli. - **NATS is no longer a boot dependency of a role that only publishes to it.** Under `realtime: { transport: 'nats' }` every role awaited the first dial before it bound a socket, and that dial never gave up: `openNatsClient` set `waitOnFirstConnect`, under which nats@2.29.3 retries a failed first dial past its attempt counter, forever. A `web`, `worker` or `scheduler` pod that restarted while NATS was down (an OOM, a node drain, a rollout, a scale-up) therefore hung in boot: pages, webhooks and jobs were down for a bus those roles only send "re-read" events to, and `health.readiness: 'process'` could not help because no listener existed yet. The role now decides (`runtime-bus.ts`, `selectTransport(env, realtime, { use })`): `sync` and the replicator still need the bus and await it; `web`, `worker`, `scheduler` and the dev MCP host dial it in the background on a jittered backoff (500 ms doubling to 30 s) and boot at once. Nothing to change in an app. The table is [Realtime → What each role needs from the bus](https://github.com/developerz-ai/ultimate/wiki/Realtime#what-each-role-needs-from-the-bus). -- **A `sync` node or a replicator without the bus fails fast and says why.** The dial is retried for 15 s (`BUS_CONNECT_WAIT_MS`) and then refused with `X_TRANSPORT_UNAVAILABLE`, whose cause names the server, the wait and the last attempt's own failure, and whose fix names the variable `realtime.urlEnv` points at. It used to sit silent until something killed it. -- **A publish with no live connection is refused at once, never queued.** While the background dial is in flight, `publishChannelEvent` and the cache-invalidation broadcast reject with `X_TRANSPORT_UNAVAILABLE` immediately. A publish made while the client is *reconnecting* is refused the same way, in every role: the `nats` client buffered it without bound and replayed the lot when the server returned, minutes late. Publishing resumes with no restart when the bus is back, on first connect and after every loss. **A missed cache bust is not replayed**: the replica that made it, Redis and the CDN are cleared as before, the broadcast lands in the report's `errors` (`cache.invalidate.partial`), and another replica's in-process copy waits for its TTL. +- **A `sync` node or a replicator without the bus fails fast and says why.** The dial is retried for 15 s (`BUS_CONNECT_WAIT_MS`) and then refused with `X_TRANSPORT_UNAVAILABLE`, whose cause names the server, the wait and the last attempt's own failure, and whose fix names the variable `realtime.urlEnv` points at. It used to sit silent until something killed it. Each attempt carries a 4 s connect timeout (`DIAL_TIMEOUT_MS`; the library's is 20 s), so a server that accepts the socket and says nothing still fails attempts inside the wait and the refusal's `last attempt:` is never empty. +- **A publish with no live connection is refused at once, not buffered.** While the background dial is in flight, `publishChannelEvent` and the cache-invalidation broadcast reject with `X_TRANSPORT_UNAVAILABLE` immediately. A publish made after the client's socket has closed is refused the same way, in every role: the `nats` client buffered it without bound and replayed the lot when the server returned, and it has no option that forbids the buffer, so the transport reads the client's own connection flag before it hands a publish over. One window is left and is stated rather than hidden: a connection whose packets are silently dropped reads as connected until two pings go unanswered — now 10 s apart (`PING_INTERVAL_MS`, `MAX_PINGS_OUT`), so within 30 s where the library's default is six minutes — and a publish made inside it is buffered and sent on reconnect. Publishing resumes with no restart when the bus is back, on first connect and after every loss. +- **A cache bust made while the bus is away reaches the other replicas when it returns.** The replica that made it, Redis and the CDN are cleared as before and the broadcast lands in the report's `errors` (`cache.invalidate.partial`). The refused wire tags are now kept — de-duplicated, at most 1,024 (`MAX_DEFERRED_TAGS`) — and published on the transport's next reconnect, or after the next publish the bus accepts; past the bound the process owes one flush-all marker (`{"flush":"all"}` on `x.cache.invalidate`) instead of a queue, so nothing grows with an outage. And every process drops what it holds in its own heap when its connection comes back, or when its boot subscribe lands after a refusal: it heard no peer for a window nobody measured. That is `flushProcessTiers()` on `@ultimat3/cache` — `CacheTier.clear()` on the in-process tier (`lruTier` implements it; a shared tier does not), every tag-revalidated ISR page marked stale (a peer's bust reaches those pages by this broadcast and by nothing else), and every fill in flight fenced out. The cost is one cold in-process cache per replica per NATS outage. A replica running an older build ignores the marker and waits for its TTLs, as it always did. +- **The replicator rides out a NATS restart.** A publish refused because the bus is away ended the run on the spot — stream stopped, lock released, backoff, re-read from the last lsn, `/readyz` false throughout — which the refusal above would have made the cost of every blip. The handler now retries the same envelope three more times over 2 s (`PUBLISH_RETRY_DELAYS_MS`), fenced after each wait, and only then ends the run for the takeover loop. A refusal that is not the bus being away (a payload over the server's limit) is not retried. - **Only a `sync` node requires JetStream at boot.** The presence bucket was asserted on every dial of every role, so a publisher failed on a nats-server without `-js`. It is asserted at the dial where presence is served and on first use of `transport.shared` everywhere else (`NatsTransportOptions.presenceBucket`). - **A dead bus no longer takes a publishing role out of the ingress.** `/readyz` in the default `'dependencies'` mode answered 503 on every `web` pod at once while NATS was down. A readiness check now has a third answer, `'degraded'` (`registerReadinessCheck(name, check, { onFailure: 'degraded' })`, `ReadinessStatus`): reported by name, never a 503 on `/readyz` in either mode, and a 503 on `/readyz?deep=1`. The `transport` check is `degraded` on `web`, `worker` and `scheduler` and stays `failing` on `sync` and the replicator. A monitor that must see a bus outage on a web pod reads `?deep=1`, as [Deployment](https://github.com/developerz-ai/ultimate/wiki/Deployment) already says to. -- **The boot line says where the bus is.** `ultimate started` carries a `bus` field — `nats(up)`, `nats(connecting)` or `in-process` (`ServedApp.bus`) — and `ultimate bus` is logged with `bus: 'nats(up)'` each time the connection lands. A dial that keeps failing is reported on attempts 1, 2, 4, 8, … rather than once per attempt. +- **The boot line says where the bus is.** `ultimate started` carries a `bus` field — `nats(up)`, `nats(connecting)` or `in-process` (`ServedApp.bus`) — and `ultimate bus` is logged with `bus: 'nats(up)'` each time the connection lands. A dial that keeps failing is reported on attempts 1, 2, 4, 8, … rather than once per attempt, and so is `cache.broadcast.subscribe-failed`; that subscribe is woken by the bus coming up instead of waiting out its own backoff. - **`realtime.enabled: false` never waits for the bus.** With no realtime role to start, no process of such an app awaits the dial, `ROLE=sync` included (it is refused by `rolesUnderRealtime`, as before, and now without first waiting on NATS). The connection is still opened in the background under `transport: 'nats'`, because cache invalidation between replicas crosses it. +- **Types that changed, though nothing here is `BREAKING`.** Reading code is unaffected; code that *builds* or *exhausts* one of these needs an edit. `ReadinessStatus` is now `'ok' | 'degraded' | 'failing'`, so an exhaustive `switch` over it (a `never` default) stops compiling until it handles `'degraded'`. `TransportSelection` gained the required `use` and `state()`, so a hand-built one (a test double) must add both; `selectTransport` is the only thing in the framework that builds one. `ServedApp.bus` is optional. `CacheTier` gained the optional `clear()`. New names: `ReadinessCheckOptions`, `BusUse`, `BUS_CONNECT_WAIT_MS`, `NatsTransport.connectInBackground()`, `connect({ withinMs })`, `NatsTransportOptions.presenceBucket` / `dialTimeoutMs`, `flushProcessTiers`, `FLUSH_ALL_TAG`. Tier 5 — cli. - **`x g` no longer corrupts a commented role map.** `x g entity` / `x g resource` / `x g policy` add permissions to `apps/web/shared/roles.ts`, and found each list's end with the first `]` in the raw text and its entries with a quote regex: an apostrophe in a comment ("the firm's") was a string delimiter, so the comments between two of them were rewritten into permissions and the file no longer loaded. Every list a generator grows — a role's `grants`, `definePermissions([…])`, a `defineApi` list, the handle's entity set — is now located on the masked source (`source-list-edit.ts`): a list holding a comment gains rows and no existing byte moves, a comment-free one is re-wrapped the way Biome prints it, a spread entry survives, and the result is read back before it is written. An edit that does not read back as "the same list plus the new entries" is `X_PERMISSION_UNGRANTED` / `X_DB_HANDLE_UNREGISTERED` naming the lines to add, never a write. diff --git a/docs/ops/01-kubernetes.md b/docs/ops/01-kubernetes.md index bcfb8178d..a65babeea 100644 --- a/docs/ops/01-kubernetes.md +++ b/docs/ops/01-kubernetes.md @@ -120,14 +120,17 @@ down for a bus those roles only publish "re-read" events to. | Role | NATS down at pod start | NATS down while running | Needs JetStream (`-js`) | |---|---|---|---| | `sync` | retries for 15 s, then exits with `X_TRANSPORT_UNAVAILABLE`; the kubelet restarts it | not ready (`transport: failing`); reconnects on its own | yes, at boot | -| `replicator` | same | same | no | +| `replicator` | same | not ready while disconnected; a publish refused during a restart of a second or two is retried in place, so the stream is not torn down for it | no | | `web`, `worker`, `scheduler` | **boots and serves**; dials in the background (jittered, 500 ms doubling to 30 s) | **stays ready**; publishes are refused with `X_TRANSPORT_UNAVAILABLE` until it is back, then resume with no restart | no | What to watch: `/readyz?deep=1` answers 503 while `checks.transport` is `degraded` — the probe on `/readyz` stays 200, by design. The boot line carries the state (`"msg":"ultimate started",…,"bus":"nats(connecting)"`) and `"msg":"ultimate bus","bus":"nats(up)"` is logged when the connection lands. While the bus is away a cache invalidation still clears the replica that made it, Redis and the CDN; the other replicas' in-process -copies wait for their TTL, and nothing is replayed afterwards. Do not add NATS to a `web` pod's +copies are stale until it returns. Then each sender publishes the tags it could not (at most 1,024, +else one flush-all), and every replica that was disconnected empties its in-process `lru` and marks +its tag-revalidated ISR pages stale — so expect one cold in-process cache per replica after a NATS +restart, and the database reads that refill it. Do not add NATS to a `web` pod's `initContainers` or `dependsOn`: that rebuilds the dependency this removes. ### Replication is a cluster-wide grant diff --git a/packages/cache/CLAUDE.md b/packages/cache/CLAUDE.md index 409220323..a4043241a 100644 --- a/packages/cache/CLAUDE.md +++ b/packages/cache/CLAUDE.md @@ -42,6 +42,9 @@ Tier 1. Tagged caching + THE invalidation graph. `TIER_ORDER` alias (`X_HELPER_COPY` refuses a value of core's under a second name). Adding a rung is an edit to `packages/core/src/cache-vocabulary.ts` plus a factory here; `scripts/render-modes.ts` refuses a second declaration of the set. **`isr` is not a tier** — the `'isr'` in `invalidate.ts` is an ISR route (`DependentKind = 'isr-route'`). +- **`flushProcessTiers(source)` is for a process that cannot name what it missed** (its bus was + away): `CacheTier.clear()` on in-process tiers only, tagged ISR pages stale, fills fenced out + (`markAllInvalidated`). Never re-emits. A shared tier must NOT implement `clear`. - **`bestEffort()` is the only sanctioned way to swallow a cache refusal.** Its label is `TierLabel` (`TierName` plus `'query-read'`), deliberately not a widening of `TierName`. - **A refusal is rendered with `renderThrowable()`, never `error.message`** — at all five absorbing diff --git a/packages/cache/README.md b/packages/cache/README.md index 13d559140..9d275ae9c 100644 --- a/packages/cache/README.md +++ b/packages/cache/README.md @@ -304,8 +304,17 @@ bus.subscribe('cache.invalidate', (wireTags) => receiveInvalidationBroadcast(wir The inbound half **cannot** re-emit, and that is structural rather than a flag: `emit` lives on the private fan-out options and `receiveInvalidationBroadcast` is the only caller that passes `false`. A receiver that re-broadcast would be a storm bounded by nothing. A failed send lands in -`report.errors` under `tier: "broadcast"` — the other pods then clear on TTL, and the write that -triggered the bust still succeeds. An inbound tag this process has not declared is dropped and +`report.errors` under `tier: "broadcast"` and the write that triggered the bust still succeeds. +What happens to that bust is the sender's (`@ultimat3/cli` keeps the refused tags, bounded, and +publishes them when the bus returns); with no such sender the other pods clear on TTL. + +**`flushProcessTiers(source)` is the repair for a process that cannot know what it missed** — its +bus connection was down for a window, or a peer says it had more refused busts than it could keep. +It calls `CacheTier.clear()` on every tier that has one (only a tier whose store is this process's +heap implements it: `lruTier` does, `redisTier` and `cdnTier` do not), marks every ISR page that +depends on a tag stale through the registered revalidator, and fences out every fill in flight +(`markAllInvalidated`). It never re-emits and never throws; its report and its `/_x` event carry +`tags: ['*']` (`FLUSH_ALL_TAG`). An inbound tag this process has not declared is dropped and reported rather than thrown, because mid-deploy the new pods know an entity the old ones do not and a throw would kill the subscriber loop that delivered it. diff --git a/packages/cache/src/fence.ts b/packages/cache/src/fence.ts index 8807f5c75..5e79f6f68 100644 --- a/packages/cache/src/fence.ts +++ b/packages/cache/src/fence.ts @@ -70,6 +70,17 @@ export function markInvalidated(scope: FenceScope): void { } } +/** + * Everything, invalidated: every fence sampled before this call answers `false`. For a process + * that cannot name what it missed (`flushProcessTiers`) — the same "older than the ring remembers: + * unprovable, so refused" rule, reached on purpose. One refetch per in-flight fill. + */ +export function markAllInvalidated(): void { + generation += 1; + forgottenThrough = generation; + marks.length = 0; +} + function hits(mark: Mark, scope: FenceScope): boolean { if (mark.key !== undefined) return scope.key !== undefined && mark.key === scope.key; const owned = mark.tag; diff --git a/packages/cache/src/flush.test.ts b/packages/cache/src/flush.test.ts new file mode 100644 index 000000000..287bde25c --- /dev/null +++ b/packages/cache/src/flush.test.ts @@ -0,0 +1,115 @@ +// `flushProcessTiers()`: what a process does when it cannot know which busts it missed. Its bus +// connection was down for a window nobody measured, so every peer's invalidation in that window is +// lost to it — and the only correct answer to "which entries are stale" is "any of them". + +import { afterAll, beforeEach, describe, expect, test } from 'bun:test'; +import { sampleFence } from './fence'; +import { isolateGraph, registerDependent, resetGraph } from './graph'; +import { + flushProcessTiers, + isolateTiers, + recentInvalidations, + registerInvalidationBroadcast, + registerRevalidator, + registerTier, + resetTiers, +} from './invalidate'; +import { lruTier } from './lru'; +import { isolateDeclaredTags, resetDeclaredTags, tag } from './tags'; +import type { CacheTier } from './tiers'; + +const restoreRegistries = [isolateTiers(), isolateDeclaredTags(), isolateGraph()]; + +beforeEach(() => { + resetTiers(); + resetDeclaredTags(); + resetGraph(); +}); + +afterAll(() => { + for (const restore of restoreRegistries) restore(); +}); + +/** A tier other processes write too: it was cleared by whoever ran the bust, so it has no `clear`. */ +const sharedTier = (): CacheTier & { cleared: number } => { + const tier = { + name: 'redis' as const, + cleared: 0, + get: async () => undefined, + set: async () => undefined, + del: async () => undefined, + invalidateTags: async () => { + tier.cleared += 1; + return { tier: 'redis' as const, keys: [] }; + }, + }; + return tier; +}; + +describe('flushProcessTiers', () => { + test('drops every in-process entry — tagged, untagged, whatever a peer may have busted', async () => { + const lru = lruTier({ maxBytes: 10_000, defaultTtlMs: 3_600_000 }); + const redis = sharedTier(); + registerTier(lru); + registerTier(redis); + await lru.set('post:1', 'old', { tags: [tag('post', '1')] }); + await lru.set('feed', ['a'], { tags: [tag('post')] }); + await lru.set('untagged', 1); + + const report = await flushProcessTiers('cache.bus-reconnect'); + + expect(await lru.get('post:1')).toBeUndefined(); + expect(await lru.get('feed')).toBeUndefined(); + expect(await lru.get('untagged')).toBeUndefined(); + // The shared tier is not this process's to empty: the bust's sender already cleared it. + expect(redis.cleared).toBe(0); + expect(report.tags).toEqual(['*']); + expect(report.tiers.map((entry) => entry.tier)).toEqual(['lru']); + expect(report.errors).toEqual([]); + }); + + test('marks every tag-revalidated ISR page stale: a peer bust reaches them by no other road', async () => { + registerDependent([tag('post')], { kind: 'isr-route', id: '/blog' }); + registerDependent([tag('post', '1'), tag('author', '9')], { kind: 'isr-route', id: '/blog/1' }); + registerDependent([tag('post')], { kind: 'live-query', id: 'q1' }); + const marked: string[] = []; + registerRevalidator((path) => { + marked.push(path); + }); + + const report = await flushProcessTiers('cache.bus-reconnect'); + + expect([...marked].sort()).toEqual(['/blog', '/blog/1']); + expect([...report.isr].sort()).toEqual(['/blog', '/blog/1']); + }); + + test('a fill that was already loading cannot republish what the flush dropped', async () => { + const fence = sampleFence({ key: 'post:1', tags: [tag('post', '1')] }); + expect(fence.isValid()).toBe(true); + + await flushProcessTiers('cache.bus-reconnect'); + + expect(fence.isValid()).toBe(false); + // One taken afterwards is unaffected: the flush is an instant, not a mode. + expect(sampleFence({ key: 'post:1' }).isValid()).toBe(true); + }); + + test('never re-emits, is recorded under its source, and survives a tier that will not clear', async () => { + let sends = 0; + registerInvalidationBroadcast(() => { + sends += 1; + }); + const lru = lruTier({ maxBytes: 10_000, defaultTtlMs: 3_600_000 }); + registerTier({ + ...lru, + clear: () => Promise.reject(new RangeError('the tier refused')), + }); + + const report = await flushProcessTiers('cache.broadcast'); + + expect(sends).toBe(0); + expect(report.errors).toEqual([{ tier: 'lru', message: expect.stringContaining('refused') }]); + expect(recentInvalidations()[0]?.source).toBe('cache.broadcast'); + expect(recentInvalidations()[0]?.tags).toEqual(['*']); + }); +}); diff --git a/packages/cache/src/index.ts b/packages/cache/src/index.ts index f5eaa662e..cff7452bd 100644 --- a/packages/cache/src/index.ts +++ b/packages/cache/src/index.ts @@ -41,6 +41,8 @@ export type { Revalidator, } from './invalidate'; export { + FLUSH_ALL_TAG, + flushProcessTiers, invalidateTags, invalidateWireTags, isolateTiers, diff --git a/packages/cache/src/invalidate.ts b/packages/cache/src/invalidate.ts index 3c044be4d..2fe12e020 100644 --- a/packages/cache/src/invalidate.ts +++ b/packages/cache/src/invalidate.ts @@ -12,8 +12,8 @@ import { systemClock, withSpan, } from '@ultimat3/core'; -import { markInvalidated } from './fence'; -import { dependentsOfKind } from './graph'; +import { markAllInvalidated, markInvalidated } from './fence'; +import { dependentsOfKind, graphSnapshot } from './graph'; import type { CacheTag } from './tags'; import { assertKnownTags, knownTags, parseTag, serializeTags } from './tags'; import { isolateTierFailures, resetTierFailures } from './tier-failures'; @@ -292,6 +292,70 @@ function fanOut(tags: readonly CacheTag[], options: FanOutOptions): Promise { + return withSpan('cache.flush', async (): Promise => { + const startedAt = performance.now(); + markAllInvalidated(); + const tiers: TierInvalidation[] = []; + const errors: { tier: string; message: string }[] = []; + for (const tier of sortTiers(registry)) { + if (tier.clear === undefined) continue; + try { + await tier.clear(); + tiers.push({ tier: tier.name, keys: [] }); + } catch (error) { + errors.push({ tier: tier.name, message: renderThrowable(error) }); + } + } + const isr = dedupe( + graphSnapshot().flatMap((entry) => + entry.dependents.filter((dep) => dep.kind === 'isr-route').map((dep) => dep.id), + ), + ); + for (const path of isr) { + try { + await revalidator?.(path); + } catch (error) { + errors.push({ tier: 'isr', message: renderThrowable(error) }); + } + } + const report: InvalidationReport = { + tags: [FLUSH_ALL_TAG], + tiers, + isr, + cdn: [], + liveQueries: [], + durationMs: Math.round((performance.now() - startedAt) * 100) / 100, + errors, + }; + recordInvalidation({ + at: systemClock.now().toISOString(), + tags: report.tags, + busted: [...isr], + source, + durationMs: report.durationMs, + errors, + }); + if (errors.length > 0) logger.warn('cache.flush.partial', { ...report }); + return report; + }); +} + /** First-seen order kept — a union of what actually changed, not a sorted report. */ function dedupe(values: readonly string[]): readonly string[] { return [...new Set(values)]; diff --git a/packages/cache/src/lru.ts b/packages/cache/src/lru.ts index b49a4f628..363bedc10 100644 --- a/packages/cache/src/lru.ts +++ b/packages/cache/src/lru.ts @@ -305,5 +305,8 @@ export function lruTier(options: LruOptions = {}): CacheTier & { readonly cache: invalidateTags(tags: readonly CacheTag[]): Promise { return Promise.resolve({ tier: 'lru', keys: cache.invalidateTags(tags) }); }, + clear(): void { + cache.clear(); + }, }; } diff --git a/packages/cache/src/tiers.ts b/packages/cache/src/tiers.ts index 517755039..2ac449114 100644 --- a/packages/cache/src/tiers.ts +++ b/packages/cache/src/tiers.ts @@ -195,6 +195,12 @@ export interface CacheTier { * may never be told about — still stops the fill (`tier-fence.ts`). Omitted by in-process tiers. */ fence?(scope: FenceScope): Promise; + /** + * Drop every entry — implemented ONLY by a tier whose store is this process's own heap (`lru`). + * `flushProcessTiers()` calls it when the process cannot know which busts it missed. A shared + * tier omits it: whoever ran a bust cleared that store for everyone. + */ + clear?(): Promise | void; } export interface CacheStack { diff --git a/packages/cli/src/runtime-bus.live.test.ts b/packages/cli/src/runtime-bus.live.test.ts index 17601bfe3..7c284ad0b 100644 --- a/packages/cli/src/runtime-bus.live.test.ts +++ b/packages/cli/src/runtime-bus.live.test.ts @@ -18,6 +18,7 @@ import { mkdtempSync, rmSync, writeFileSync } from 'node:fs'; // why: Bun has no import { tmpdir } from 'node:os'; // why: Bun exposes no path-join primitive; Bun.file and import() take one already joined. import { join } from 'node:path'; +import { invalidateTags, tag } from '@ultimat3/cache'; import type { HealthReport } from '@ultimat3/core'; import { isUltimateError, resetLifecycle } from '@ultimat3/core'; import { allow } from '@ultimat3/policy'; @@ -29,6 +30,7 @@ import type { RunningRoles } from './role-start'; import { startRoles } from './role-start'; import { resolveServices } from './runtime-bindings'; import { busLabel } from './runtime-bus'; +import { CACHE_INVALIDATE_SUBJECT } from './runtime-cache'; import type { RunningServices } from './runtime-services'; import { startServices } from './runtime-services'; @@ -220,6 +222,14 @@ describe.skipIf(url === undefined)('a web role and a NATS that is not there', () await syncSide.transport.subscribe('x.channel.bus-live-feed.>', (payload) => { heard.push(payload); }); + // And a peer replica's cache hop. A bust made now, with the bus down, is refused — and owed. + const busts: string[] = []; + await syncSide.transport.subscribe(CACHE_INVALIDATE_SUBJECT, (payload) => { + busts.push(payload); + }); + const bust = await invalidateTags([tag('post', '1')]); + expect(bust.errors.map((entry) => entry.tier)).toEqual(['broadcast']); + expect(busts).toEqual([]); // NATS UP: no restart, and inside the dial's backoff a publish reaches the sync side. relay.up(); @@ -230,6 +240,9 @@ describe.skipIf(url === undefined)('a web role and a NATS that is not there', () await until(() => heard.length === 1, 10); expect(heard).toHaveLength(1); expect((await readyz(base, '?deep=1')).status).toBe(200); + // The bust the bus refused reaches the peer now, once, with no second write to trigger it. + await until(() => busts.length >= 1, 10); + expect(busts).toEqual(['["post:1"]']); // NATS DIES MID-FLIGHT. The process stays up and ready, and a publish is refused at once // rather than queued in the client for whenever the server returns. diff --git a/packages/cli/src/runtime-cache-bus-loss.test.ts b/packages/cli/src/runtime-cache-bus-loss.test.ts new file mode 100644 index 000000000..610fa7939 --- /dev/null +++ b/packages/cli/src/runtime-cache-bus-loss.test.ts @@ -0,0 +1,269 @@ +// The invalidation hop across a bus that goes away. A publish with no live connection is refused +// (`NatsTransport`), so a bust made during a NATS restart reached no peer — and a process whose own +// connection was down heard none of its peers' busts either, with nothing to say which. Both are +// repaired when the bus returns: the sender publishes what was refused, and every process drops +// what it holds in its own heap, because it was deaf for a window nobody measured. + +import { afterEach, beforeEach, describe, expect, test } from 'bun:test'; +import { + invalidateTags, + isolateDeclaredTags, + isolateGraph, + isolateTiers, + noopPurgeDriver, + registerDependent, + registeredTiers, + registerRevalidator, + tag, +} from '@ultimat3/cache'; +import { logger } from '@ultimat3/core'; +import type { Transport } from '@ultimat3/realtime/server'; +import { FakeNatsBroker, fakeNatsConnect, selectTransport } from '@ultimat3/realtime/server'; +import { + CACHE_FLUSH_ALL, + CACHE_INVALIDATE_SUBJECT, + DEFAULT_CACHE_TIERS, + MAX_DEFERRED_TAGS, + startCacheTiers, +} from './runtime-cache'; + +const NATS = { transport: 'nats', urlEnv: 'NATS_URL' } as const; +const ENV = { NATS_URL: 'nats://bus.test:4222' } as const; + +let release: (() => Promise) | undefined; +let transport: Transport | undefined; +let restores: (() => void)[] = []; +const warnings: { line: string; meta: Record | undefined }[] = []; +let printWarning = logger.warn; + +beforeEach(() => { + restores = [isolateTiers(), isolateDeclaredTags(), isolateGraph()]; + printWarning = logger.warn; + warnings.length = 0; + logger.warn = (line: string, meta?: Record): void => { + warnings.push({ line, meta }); + }; +}); + +afterEach(async () => { + await release?.(); + release = undefined; + await transport?.close(); + transport = undefined; + for (const restore of restores) restore(); + logger.warn = printWarning; +}); + +const until = async (done: () => boolean, polls = 500): Promise => { + for (let poll = 0; poll < polls && !done(); poll += 1) await Bun.sleep(2); +}; + +/** This process as one replica: a web role's bus (background dial) with the cache hop on top. */ +async function replica(broker: FakeNatsBroker, retryMs: (attempt: number) => number = () => 1) { + const selection = selectTransport(ENV, NATS, { + use: 'publish', + connect: fakeNatsConnect(broker), + backoff: { baseMs: 2, maxMs: 2, factor: 1, jitter: 'none' }, + onError: () => undefined, + }); + transport = selection.transport; + let subscribes = 0; + let landed = 0; + const counted: Transport = { + name: selection.transport.name, + shared: selection.transport.shared, + publish: (subject, payload) => selection.transport.publish(subject, payload), + onReconnect: (listener) => selection.transport.onReconnect(listener), + close: () => selection.transport.close(), + async subscribe(subject, handler) { + subscribes += 1; + const subscription = await selection.transport.subscribe(subject, handler); + landed += 1; + return subscription; + }, + }; + await selection.connect(); + release = startCacheTiers({ + env: {}, + purge: noopPurgeDriver(), + transport: counted, + tiers: DEFAULT_CACHE_TIERS, + subscribeRetryMs: retryMs, + }); + const lru = registeredTiers().find((tier) => tier.name === 'lru'); + if (lru === undefined) expect.unreachable('the default ladder has an lru tier'); + return { selection, lru, subscribes: () => subscribes, landed: () => landed }; +} + +/** Another replica, as the bus sees it: what it is sent, and what it sends. */ +function peer(broker: FakeNatsBroker) { + const client = broker.client(); + const heard: string[] = []; + client.subscribe(CACHE_INVALIDATE_SUBJECT, (message) => { + heard.push(new TextDecoder().decode(message.payload)); + }); + return { + heard, + bust: (payload: string): void => { + client.publish(CACHE_INVALIDATE_SUBJECT, new TextEncoder().encode(payload)); + }, + }; +} + +describe('a bust made while the bus is away', () => { + test('is kept, de-duplicated, and published when the bus returns', async () => { + const broker = new FakeNatsBroker(); + const self = await replica(broker); + const other = peer(broker); + await until(() => self.landed() === 1); + + broker.drop(); + const report = await invalidateTags([tag('post', '1')]); + await invalidateTags([tag('post', '1'), tag('post', '2')]); + // Still an error on the report: the peers have NOT been told yet. + expect(report.errors.map((entry) => entry.tier)).toEqual(['broadcast']); + expect(other.heard).toEqual([]); + + broker.restore(); + await until(() => other.heard.length >= 1); + await Bun.sleep(10); + + expect(other.heard).toEqual(['["post:1","post:2"]']); + }); + + test('past the bound it is ONE flush-all, not a queue: nothing grows with the outage', async () => { + const broker = new FakeNatsBroker(); + const self = await replica(broker); + const other = peer(broker); + await until(() => self.landed() === 1); + + broker.drop(); + for (let id = 0; id <= MAX_DEFERRED_TAGS; id += 1) await invalidateTags([tag('post', `${id}`)]); + // And long after the bound was passed: still nothing kept per bust. + for (let id = 0; id < 50; id += 1) await invalidateTags([tag('comment', `${id}`)]); + + broker.restore(); + await until(() => other.heard.length >= 1); + await Bun.sleep(10); + + expect(other.heard).toEqual([CACHE_FLUSH_ALL]); + }); + + test('a publish that lands later also carries what an earlier one could not', async () => { + const broker = new FakeNatsBroker(); + const self = await replica(broker); + const other = peer(broker); + await until(() => self.landed() === 1); + + // Refused by the bus itself, with the connection up: no reconnect will ever announce it. + const publish = self.selection.transport.publish.bind(self.selection.transport); + let refuse = true; + self.selection.transport.publish = async (subject, payload) => { + if (refuse) return await Promise.reject(new RangeError('max_payload exceeded')); + await publish(subject, payload); + }; + await invalidateTags([tag('post', '1')]); + refuse = false; + await invalidateTags([tag('post', '2')]); + await until(() => other.heard.length >= 2); + + expect(other.heard).toEqual(['["post:2"]', '["post:1"]']); + }); +}); + +describe('a replica whose own connection was down', () => { + test('drops what it cached while deaf, and marks its tagged ISR pages stale, when the bus returns', async () => { + const broker = new FakeNatsBroker(); + const self = await replica(broker); + const other = peer(broker); + await until(() => self.landed() === 1); + registerDependent([tag('post')], { kind: 'isr-route', id: '/blog' }); + const marked: string[] = []; + registerRevalidator((path) => { + marked.push(path); + }); + + broker.drop(); + await self.lru.set('post:1', 'stale', { tags: [tag('post', '1')] }); + // The peer edits the post. This replica cannot hear it, and nobody will repeat it. + other.bust('["post:1"]'); + await Bun.sleep(5); + expect((await self.lru.get('post:1'))?.value).toBe('stale'); + expect(marked).toEqual([]); + + broker.restore(); + await until(() => marked.length > 0); + + expect(await self.lru.get('post:1')).toBeUndefined(); + expect(marked).toEqual(['/blog']); + }); + + test("a peer's flush-all empties this replica too", async () => { + const broker = new FakeNatsBroker(); + const self = await replica(broker); + const other = peer(broker); + await until(() => self.landed() === 1); + await self.lru.set('anything', 1); + + other.bust(CACHE_FLUSH_ALL); + await Bun.sleep(40); + + expect(await self.lru.get('anything')).toBeUndefined(); + }); +}); + +describe('the invalidation subscribe of a role booted with the bus down', () => { + // The key property of a publisher that does not wait for the bus: it must still end up + // SUBSCRIBED, or it is a replica that never hears a peer again. + test("is refused while offline, lands once when the bus is up, and then delivers a peer's bust", async () => { + const broker = new FakeNatsBroker(); + broker.offline = true; + const self = await replica(broker); + await until(() => self.subscribes() >= 3); + expect(self.subscribes()).toBeGreaterThanOrEqual(3); + expect(self.landed()).toBe(0); + await self.lru.set('post:1', 'old', { tags: [tag('post', '1')] }); + + broker.offline = false; + await until(() => self.landed() === 1); + const attempts = self.subscribes(); + await Bun.sleep(20); + // One that lands, then none. + expect(self.landed()).toBe(1); + expect(self.subscribes()).toBe(attempts); + // It was deaf since boot: what it cached meanwhile is not trusted. + expect(await self.lru.get('post:1')).toBeUndefined(); + + await self.lru.set('post:1', 'old', { tags: [tag('post', '1')] }); + peer(broker).bust('["post:1"]'); + await Bun.sleep(40); + expect(await self.lru.get('post:1')).toBeUndefined(); + }); + + test('is woken by the bus coming up, not by its own backoff', async () => { + const broker = new FakeNatsBroker(); + broker.offline = true; + const self = await replica(broker, () => 60_000); + await until(() => self.subscribes() >= 1); + + const startedAt = performance.now(); + broker.offline = false; + await until(() => self.landed() === 1); + + expect(self.landed()).toBe(1); + expect(performance.now() - startedAt).toBeLessThan(2_000); + }); + + test('warns on attempts 1, 2, 4, 8 — not once per retry for as long as the outage lasts', async () => { + const broker = new FakeNatsBroker(); + broker.offline = true; + const self = await replica(broker, () => 0); + await until(() => self.subscribes() >= 20); + + const attempts = warnings + .filter((warning) => warning.line === 'cache.broadcast.subscribe-failed') + .map((warning) => warning.meta?.['attempt']); + expect(attempts.slice(0, 4)).toEqual([1, 2, 4, 8]); + expect(attempts.length).toBeLessThanOrEqual(Math.ceil(Math.log2(self.subscribes())) + 1); + }); +}); diff --git a/packages/cli/src/runtime-cache.ts b/packages/cli/src/runtime-cache.ts index f77cd82ad..4190f1a7c 100644 --- a/packages/cli/src/runtime-cache.ts +++ b/packages/cli/src/runtime-cache.ts @@ -8,6 +8,7 @@ import type { CacheTier, PurgeDriver } from '@ultimat3/cache'; import { CacheDriverUnavailableError, cdnTier, + flushProcessTiers, isNoopPurgeDriver, lruTier, memoTier, @@ -29,6 +30,19 @@ import type { Env } from './runtime-bindings'; */ export const CACHE_INVALIDATE_SUBJECT = 'x.cache.invalidate'; +/** + * "Drop everything you hold in process", on the same subject. An object, where a bust is an array + * of wire tags: a replica from before this marker existed parses it, finds no array and ignores + * it — its entries wait for their TTL, which is what a lost bust always cost it. + */ +export const CACHE_FLUSH_ALL = '{"flush":"all"}'; + +/** + * How many refused wire tags a process keeps for the bus's return. A bound, not a queue: past it + * the set is dropped and ONE flush-all is owed instead, so memory does not grow with the outage. + */ +export const MAX_DEFERRED_TAGS = 1_024; + export interface CacheTiersOptions { readonly env: Env; /** Already resolved by the boot — a `cdn` rung is built against a real edge or not at all. */ @@ -152,8 +166,49 @@ export function startCacheTiers(options: CacheTiersOptions): () => Promise for (const tier of built) registerTier(tier); warnUnnamed(options); + const send = (payload: string): Promise => + options.transport.publish(CACHE_INVALIDATE_SUBJECT, payload); + // What the bus refused, kept for its return. A publish with no live connection is refused, not + // buffered (`NatsTransport`), so without this a bust made during a two-second NATS restart + // reached no peer at all. De-duplicated — a tag is a fact, not an event — and bounded. + const deferred = new Set(); + let flushOwed = false; + const defer = (wireTags: readonly string[]): void => { + if (flushOwed) return; + for (const wire of wireTags) deferred.add(wire); + if (deferred.size <= MAX_DEFERRED_TAGS) return; + deferred.clear(); + flushOwed = true; + }; + /** Publish what is owed. Cleared only once the bus took it; a second refusal keeps it owed. */ + const settle = async (): Promise => { + if (flushOwed) { + await send(CACHE_FLUSH_ALL); + flushOwed = false; + return; + } + if (deferred.size === 0) return; + const batch = [...deferred]; + await send(JSON.stringify(batch)); + for (const wire of batch) deferred.delete(wire); + }; + const settleQuietly = (): void => { + void settle().catch((error: unknown) => { + logger.warn('cache.broadcast.deferred-failed', { error: broadcastErrorText(error) }); + }); + }; + registerInvalidationBroadcast(async (wireTags) => { - await options.transport.publish(CACHE_INVALIDATE_SUBJECT, JSON.stringify(wireTags)); + try { + await send(JSON.stringify(wireTags)); + } catch (error) { + defer(wireTags); + // Still thrown: the report must say the peers have not been told YET. + throw error; + } + // The bus took this one, so it takes what an earlier publish could not — the case no + // reconnect announces, a refusal with the connection up. + if (flushOwed || deferred.size > 0) settleQuietly(); }); // Not awaited HERE: the boot must not block on a subscribe. The PROMISE is held rather than a // handle assigned inside a `.then`, because the release ran first whenever `stop()` beat the round @@ -162,28 +217,56 @@ export function startCacheTiers(options: CacheTiersOptions): () => Promise // logged once and never asked again, so the process missed every peer invalidation for its life. const released = Promise.withResolvers(); let stopped = false; + let subscribed = false; + /** Cuts the retry's wait short: the bus coming up is a better signal than a backoff. */ + let wake: () => void = () => undefined; const retryMs = options.subscribeRetryMs ?? defaultSubscribeRetryMs; + // This process heard no peer for a window nobody measured — since boot, or since the connection + // dropped — so nothing it holds in its own heap is known fresh. One cold cache, never a stale one. + const flushDeaf = (source: string): void => { + void flushProcessTiers(source); + }; const subscribing = (async (): Promise => { for (let attempt = 1; !stopped; attempt += 1) { try { - return await options.transport.subscribe(CACHE_INVALIDATE_SUBJECT, (payload: string) => { - void applyBroadcast(payload); - }); + const subscription = await options.transport.subscribe( + CACHE_INVALIDATE_SUBJECT, + (payload: string) => { + void applyBroadcast(payload); + }, + ); + subscribed = true; + if (attempt > 1) flushDeaf('cache.bus-subscribed'); + return subscription; } catch (error) { - logger.warn('cache.broadcast.subscribe-failed', { - error: broadcastErrorText(error), - attempt, - }); - await Promise.race([Bun.sleep(retryMs(attempt)), released.promise]); + // Attempts 1, 2, 4, 8, …: the dial's own thinning (`NatsTransport`), so an outage is not + // one line per retry per pod for as long as it lasts. + if ((attempt & (attempt - 1)) === 0) { + logger.warn('cache.broadcast.subscribe-failed', { + error: broadcastErrorText(error), + attempt, + }); + } + const woken = Promise.withResolvers(); + wake = (): void => woken.resolve(undefined); + await Promise.race([Bun.sleep(retryMs(attempt)), released.promise, woken.promise]); } } return undefined; })(); + // The bus is (back) up. The subscription came back with the connection, so from here this + // process hears again: drop what it held while deaf, and say what it could not say. + const offReconnect = options.transport.onReconnect(() => { + wake(); + if (subscribed) flushDeaf('cache.bus-reconnect'); + settleQuietly(); + }); // `resetTiers()` drops the registry AND the broadcast in one call: this boot is the only thing // that registers either, and a tier left behind would purge for a process that has stopped. return async () => { stopped = true; + offReconnect(); released.resolve(undefined); (await subscribing)?.unsubscribe(); resetTiers(); @@ -200,6 +283,13 @@ export function startCacheTiers(options: CacheTiersOptions): () => Promise */ export const broadcastErrorText = (error: unknown): string => renderThrowable(error); +/** `CACHE_FLUSH_ALL`, parsed: a peer had more refused busts than it could keep. */ +const isFlushAll = (parsed: unknown): boolean => + typeof parsed === 'object' && + parsed !== null && + !Array.isArray(parsed) && + Reflect.get(parsed, 'flush') === 'all'; + /** * A peer's wire tags, applied here. Never throws: a malformed frame or an undeclared tag must not * kill the subscriber loop, because that would silently end cross-instance invalidation for the @@ -208,6 +298,10 @@ export const broadcastErrorText = (error: unknown): string => renderThrowable(er async function applyBroadcast(payload: string): Promise { try { const parsed: unknown = JSON.parse(payload); + if (isFlushAll(parsed)) { + await flushProcessTiers('cache.broadcast'); + return; + } if (!Array.isArray(parsed)) return; const wire = parsed.filter((value): value is string => typeof value === 'string'); if (wire.length > 0) await receiveInvalidationBroadcast(wire); diff --git a/packages/cli/src/serve-graph.test.ts b/packages/cli/src/serve-graph.test.ts index 59b37d9f4..916b9d4ca 100644 --- a/packages/cli/src/serve-graph.test.ts +++ b/packages/cli/src/serve-graph.test.ts @@ -185,8 +185,11 @@ const MIGRATE_CEILING = 639; * `cli/src/runtime-bus.ts` — which roles await the NATS dial (`sync`, the replicator) and which * dial it in the background and boot (`web`, `worker`, `scheduler`), the `transport` readiness * check and the boot line's `bus=`. Split out of `runtime-services.ts`, which sat at the ceiling. + * raised 939 → 940, measured 940 (2026-10-10, PR #755 review): `realtime/src/nats-dial-wait.ts` — + * one dial's connect timeout and the bounded wait a `sync` node puts on the retry loop, split out + * of `nats-transport.ts` when the dial-loop fixes took it past the 500-line ceiling. */ -const SERVING_ROLE_CEILING = 939; +const SERVING_ROLE_CEILING = 940; /** * measured: 888 — the 796 above plus the 92 `serve-web.ts` adds (41 CLI, 36 MCP, 15 PWA). @@ -269,8 +272,10 @@ const SERVING_ROLE_CEILING = 939; * `MIGRATE_CEILING` for #752. * raised 1065 → 1066, measured 1066 (2026-10-10, the bus is not a boot dependency of a publisher): * `cli/src/runtime-bus.ts`, the module named on `SERVING_ROLE_CEILING`, which every role carries. + * raised 1066 → 1067, measured 1067 (2026-10-10, PR #755 review): `realtime/src/nats-dial-wait.ts`, + * the module named on `SERVING_ROLE_CEILING`. */ -const WEB_ROLE_CEILING = 1066; +const WEB_ROLE_CEILING = 1067; interface MetaInput { readonly imports: readonly { readonly path: string; readonly kind: string }[]; diff --git a/packages/cli/src/serve-types.ts b/packages/cli/src/serve-types.ts index ea2f9acb9..0a5893476 100644 --- a/packages/cli/src/serve-types.ts +++ b/packages/cli/src/serve-types.ts @@ -41,9 +41,10 @@ export interface ServedApp { readonly buildId: string; /** * The bus as the boot left it: `nats(up)`, `nats(connecting)` or `in-process` (`busLabel`). Only - * a role that publishes and serves no socket can boot `connecting`. + * a role that publishes and serves no socket can boot `connecting`. Optional: a hand-built + * `ServedApp` — a test double — has no bus to report, and the boot line then carries none. */ - readonly bus: string; + readonly bus?: string; readonly running: RunningRoles; readonly runtime: RunningServices; stop(): Promise; diff --git a/packages/realtime/src/nats-client.ts b/packages/realtime/src/nats-client.ts index 9135a6aad..166dc75bd 100644 --- a/packages/realtime/src/nats-client.ts +++ b/packages/realtime/src/nats-client.ts @@ -71,6 +71,11 @@ export interface NatsClientOptions { /** Our jitter policy, asked once per attempt — the herd is ours to spread, not the library's. */ readonly reconnectDelay?: (() => number) | undefined; readonly requestTimeoutMs?: number | undefined; + /** + * How long ONE dial may sit before it is an attempt that failed. The library's own default is + * 20 s, which a server that accepts the socket and says nothing spends in full. + */ + readonly connectTimeoutMs?: number | undefined; /** A background failure: a dropped connection, a server error, an exhausted reconnect. */ readonly onError?: ((error: unknown) => void) | undefined; /** The library re-established the connection. The cluster behind it may be a different one. */ diff --git a/packages/realtime/src/nats-dial-wait.ts b/packages/realtime/src/nats-dial-wait.ts new file mode 100644 index 000000000..910ec40af --- /dev/null +++ b/packages/realtime/src/nats-dial-wait.ts @@ -0,0 +1,61 @@ +// Single responsibility: how long a dial is waited for — one attempt's connect timeout, and the +// bounded wait a process that cannot work without the bus puts on the whole retry loop. + +import { finiteOption } from '@ultimat3/core'; +import { TransportUnavailableError } from './errors'; + +/** + * One dial's connect timeout. Well under `BUS_CONNECT_WAIT_MS`: a black-holed server must fail + * several attempts inside a `sync` node's boot wait, so its refusal carries the attempt's own + * reason rather than an empty one, and a background dial keeps its backoff instead of the + * library's 20 s. + */ +export const DIAL_TIMEOUT_MS = 4_000; + +export interface NatsConnectWait { + /** Refuse with `X_TRANSPORT_UNAVAILABLE` once this long has passed without a connection. */ + readonly withinMs?: number | undefined; + /** The `fix:` of that refusal — the caller knows which role is waiting and what it needs. */ + readonly fix?: string | undefined; +} + +export interface DialWait { + readonly transport: string; + /** `host:port`, never the url: the url carries the credential. */ + readonly server: string; + readonly withinMs: number; + readonly fix: string | undefined; + /** The last attempt's own refusal, read when the wait runs out. */ + readonly lastFailure: () => string | undefined; +} + +/** + * `landing`, or a coded refusal once `withinMs` has passed. A real timer, never an injected clock: + * the wait bounds a container's boot, which the kubelet counts in real seconds. The loser is not + * cancelled — a dial cannot be — so the caller's `close()` is what ends it. + */ +export async function landWithin( + landing: Promise | undefined, + wait: DialWait, +): Promise { + const withinMs = finiteOption('createNatsTransport', 'connect.withinMs', wait.withinMs); + let timer: ReturnType | undefined; + const late = new Promise((_, reject) => { + timer = setTimeout(() => { + const failure = wait.lastFailure(); + const last = failure === undefined ? '' : ` — last attempt: ${failure}`; + reject( + new TransportUnavailableError({ + transport: wait.transport, + reason: `${wait.server} did not accept a connection within ${withinMs}ms${last}`, + ...(wait.fix === undefined ? {} : { fix: wait.fix }), + }), + ); + }, withinMs); + }); + try { + await Promise.race([landing, late]); + } finally { + clearTimeout(timer); + } +} diff --git a/packages/realtime/src/nats-lib-client-bounds.test.ts b/packages/realtime/src/nats-lib-client-bounds.test.ts index dd5f9c46f..e84250190 100644 --- a/packages/realtime/src/nats-lib-client-bounds.test.ts +++ b/packages/realtime/src/nats-lib-client-bounds.test.ts @@ -11,6 +11,7 @@ import { describe, expect, test } from 'bun:test'; import { UltimateError } from '@ultimat3/core'; import { openNatsClient } from './nats-lib-client'; +import { NatsTransport } from './nats-transport'; /** Every shape `Number(process.env.NATS_MAX_RECONNECT)` / `parseInt` hands a config reader. */ const NOT_A_BUDGET = [Number.NaN, Number.POSITIVE_INFINITY, Number.NEGATIVE_INFINITY]; @@ -34,4 +35,77 @@ describe('a nats client opened on a reconnect budget that is not a number', () = expect(rendered).toContain('maxReconnectAttempts'); } }); + + test('a non-finite connectTimeoutMs is refused the same way', async () => { + const thrown = await openNatsClient({ + url: 'nats://127.0.0.1:1', + connectTimeoutMs: Number.NaN, + }).then( + () => undefined, + (error: unknown) => error, + ); + expect(thrown instanceof UltimateError ? `${thrown.cause} ${thrown.fix}` : '').toContain( + 'connectTimeoutMs', + ); + }); +}); + +// The server that is worse than a dead one: it accepts the socket and never speaks. The library's +// own connect timeout is 20 s, so a `sync` node's 15 s boot wait ran out with no attempt finished +// and a refusal whose `last attempt:` was empty. +describe('a nats client dialling a server that accepts and says nothing', () => { + test('the dial ends at connectTimeoutMs, coded, naming the server', async () => { + const silent = Bun.listen({ + hostname: '127.0.0.1', + port: 0, + socket: { data() {}, open() {} }, + }); + try { + const startedAt = performance.now(); + const thrown = await openNatsClient({ + url: `nats://127.0.0.1:${silent.port}`, + connectTimeoutMs: 200, + }).then( + () => undefined, + (error: unknown) => error, + ); + + expect(performance.now() - startedAt).toBeLessThan(5_000); + expect(thrown).toBeInstanceOf(UltimateError); + expect(thrown instanceof UltimateError ? thrown.code : '').toBe('X_TRANSPORT_UNAVAILABLE'); + expect(thrown instanceof UltimateError ? thrown.cause : '').toContain( + `127.0.0.1:${silent.port}`, + ); + } finally { + silent.stop(true); + } + }); + + test('a transport waiting on it is refused with the attempt own reason, not an empty one', async () => { + const silent = Bun.listen({ + hostname: '127.0.0.1', + port: 0, + socket: { data() {}, open() {} }, + }); + const transport = new NatsTransport({ + url: `nats://127.0.0.1:${silent.port}`, + bucket: 'x-test', + dialTimeoutMs: 150, + backoff: { baseMs: 10, maxMs: 10, factor: 1, jitter: 'none' }, + onError: () => undefined, + }); + try { + const thrown = await transport.connect({ withinMs: 1_000 }).then( + () => undefined, + (error: unknown) => error, + ); + const cause = thrown instanceof UltimateError ? thrown.cause : ''; + expect(cause).toContain('within 1000ms'); + expect(cause).toContain('last attempt: '); + expect(cause.split('last attempt: ')[1]?.length ?? 0).toBeGreaterThan(10); + } finally { + await transport.close(); + silent.stop(true); + } + }); }); diff --git a/packages/realtime/src/nats-lib-client.ts b/packages/realtime/src/nats-lib-client.ts index d7b52d636..492f1ee8a 100644 --- a/packages/realtime/src/nats-lib-client.ts +++ b/packages/realtime/src/nats-lib-client.ts @@ -92,7 +92,7 @@ class LibNatsClient implements NatsClient { } get connected(): boolean { - return this.#connected && !this.#connection.isClosed(); + return this.#connected && !this.#connection.isClosed() && protocolUp(this.#connection); } publish(subject: string, payload: Uint8Array): void { @@ -211,6 +211,29 @@ class LibNatsClient implements NatsClient { } } +/** + * The library's own flag, read where it is set. `#connected` above follows the status ITERATOR, + * which delivers a disconnect a tick or more after the socket dropped; in between the library + * already knows (`protocol.connected` is cleared in the socket's close handler) and already + * buffers every publish. nats@2.29.3 has no option to forbid that buffer, so the flag is the only + * way to refuse a publish it would queue. It is not on the typed surface: a library that moves it + * answers `true` here and the status iterator is the reading again — the behaviour before this. + */ +const protocolUp = (connection: NatsConnection): boolean => { + const protocol: unknown = Reflect.get(connection, 'protocol'); + if (typeof protocol !== 'object' || protocol === null) return true; + return Reflect.get(protocol, 'connected') !== false; +}; + +/** + * How often the client pings, and how many may go unanswered. The library's defaults are two + * minutes and two: a connection whose packets are silently dropped stays "connected" — and keeps + * buffering publishes — for up to six minutes. 10 s and two is noticed within half a minute, for + * one 6-byte frame every ten seconds on a connection that is otherwise idle. + */ +export const PING_INTERVAL_MS = 10_000; +export const MAX_PINGS_OUT = 2; + /** `QueuedIterator.stop()` is the library's, and missing from the `AsyncIterable` it is typed as. */ const stopStream = (stream: unknown): void => { if (typeof stream !== 'object' || stream === null || !('stop' in stream)) return; @@ -240,10 +263,17 @@ export const openNatsClient = async (options: NatsClientOptions): Promise isUltimateError(value) ? value.code : `not an UltimateError: ${String(value)}`; @@ -143,6 +145,100 @@ describe('NatsTransport.connectInBackground', () => { }); }); +describe('NatsTransport, the dial loop at its edges', () => { + // The loop's memo used to be cleared one microtask AFTER the loop returned. A connection that + // closed for good in that gap asked for a loop, was handed the finished one, and nothing ever + // dialled again: every kept subscription stayed orphaned. + test('a client lost in the microtask after the loop lands still starts a new loop', async () => { + const clock = frozenClock(1_700_000_000_000); + const broker = new FakeNatsBroker({ clock }); + const open = fakeNatsConnect(broker); + const dialled: { client: NatsClient; onClosed: (() => void) | undefined }[] = []; + const connect: NatsConnect = async (options) => { + const client = await open(options); + dialled.push({ client, onClosed: options.onClosed }); + return client; + }; + const transport = new NatsTransport({ + url: 'nats://bus.test:4222', + bucket: 'x-test', + clock, + backoff: QUICK, + connect, + onError: () => undefined, + }); + let losses = 0; + transport.onReconnect(() => { + if (losses > 0) return; + losses += 1; + // Queued while the loop is still on the stack, so it runs after the loop's function has + // returned and before any reaction to its promise: exactly the gap. + queueMicrotask(() => { + const first = dialled[0]; + if (first === undefined) expect.unreachable('no dial landed'); + void first.client.close(); + first.onClosed?.(); + }); + }); + + transport.connectInBackground(); + await waitFor(() => dialled.length === 2 && transport.connected); + + expect(dialled).toHaveLength(2); + expect(transport.connected).toBe(true); + await transport.close(); + }); + + test('an onError that throws does not end the loop, and nothing is left unhandled', async () => { + const bus = harness(); + bus.broker.offline = true; + const unhandled: unknown[] = []; + const note = (reason: unknown): void => { + unhandled.push(reason); + }; + process.on('unhandledRejection', note); + const transport = bus.transport({ + onError: () => { + // What an app's reporter does when the thing it reports to is the thing that is down. + JSON.parse('the sink is gone'); + }, + }); + try { + transport.connectInBackground(); + await waitFor(() => bus.attempts() >= 4); + expect(bus.attempts()).toBeGreaterThanOrEqual(4); + + bus.broker.offline = false; + await waitFor(() => transport.connected); + expect(transport.connected).toBe(true); + await Bun.sleep(5); + expect(unhandled).toEqual([]); + } finally { + process.off('unhandledRejection', note); + await transport.close(); + } + }); + + test('a dial is given a connect timeout below the boot wait, so a black hole is an attempt that ends', async () => { + const seen: (number | undefined)[] = []; + const broker = new FakeNatsBroker(); + const open = fakeNatsConnect(broker); + const transport = new NatsTransport({ + url: 'nats://bus.test:4222', + bucket: 'x-test', + connect: (options) => { + seen.push(options.connectTimeoutMs); + return open(options); + }, + }); + await transport.connect(); + + expect(seen).toEqual([DIAL_TIMEOUT_MS]); + expect(DIAL_TIMEOUT_MS).toBeLessThan(BUS_CONNECT_WAIT_MS / 2); + await transport.close(); + }); +}); + describe("NatsTransport with presenceBucket: 'first-use'", () => { test('a publisher connects to a server with no JetStream, and creates no bucket', async () => { const bus = harness(); diff --git a/packages/realtime/src/nats-transport.ts b/packages/realtime/src/nats-transport.ts index 9e3589331..194b01d9a 100644 --- a/packages/realtime/src/nats-transport.ts +++ b/packages/realtime/src/nats-transport.ts @@ -21,6 +21,7 @@ import { TransportUnavailableError } from './errors'; import type { Transport, TransportHandler, TransportSet, TransportSubscription } from './fanout'; import type { NatsClient, NatsConnect } from './nats-client'; import { parseNatsUrl } from './nats-client'; +import { DIAL_TIMEOUT_MS, landWithin, type NatsConnectWait } from './nats-dial-wait'; import { ensureKvBucket } from './nats-jetstream'; import { NatsKvSet } from './nats-kv'; import { openNatsClient } from './nats-open'; @@ -50,13 +51,8 @@ export interface NatsTransportOptions { * `shared`, so a server without JetStream, or without the bucket, must not cost it the bus. */ readonly presenceBucket?: 'dial' | 'first-use'; -} - -export interface NatsConnectWait { - /** Refuse with `X_TRANSPORT_UNAVAILABLE` once this long has passed without a connection. */ - readonly withinMs?: number | undefined; - /** The `fix:` of that refusal — the caller knows which role is waiting and what it needs. */ - readonly fix?: string | undefined; + /** One dial's connect timeout. Default `DIAL_TIMEOUT_MS`. */ + readonly dialTimeoutMs?: number; } const DEFAULT_ATTEMPTS = 10; @@ -78,6 +74,7 @@ export class NatsTransport implements Transport { /** False until the first dial lands: what a refusal says while a background dial is in flight. */ #everUp = false; readonly #lazyBucket: boolean; + readonly #dialTimeoutMs: number; /** Under `'first-use'`: the clients whose bucket has been asserted since they last connected. */ readonly #bucketed = new WeakSet(); /** Set while no client is held and one is being dialled in the background; the attempt in flight. */ @@ -102,6 +99,11 @@ export class NatsTransport implements Transport { options.maxReconnectAttempts ?? DEFAULT_ATTEMPTS, ); this.#rng = options.rng ?? Math.random; + this.#dialTimeoutMs = finiteOption( + 'createNatsTransport', + 'dialTimeoutMs', + options.dialTimeoutMs ?? DIAL_TIMEOUT_MS, + ); this.#lazyBucket = options.presenceBucket === 'first-use'; this.shared = new NatsKvSet({ client: () => this.#presenceClient(), @@ -122,28 +124,14 @@ export class NatsTransport implements Transport { await this.#ensure(); return; } - const withinMs = finiteOption('createNatsTransport', 'connect.withinMs', wait.withinMs); const target = parseNatsUrl(this.#options.url); - // A real timer, never the injected clock: the wait bounds a container's boot, which the - // kubelet counts in real seconds. - let timer: ReturnType | undefined; - const late = new Promise((_, reject) => { - timer = setTimeout(() => { - const last = this.#lastFailure === undefined ? '' : ` — last attempt: ${this.#lastFailure}`; - reject( - new TransportUnavailableError({ - transport: this.name, - reason: `${target.host}:${target.port} did not accept a connection within ${withinMs}ms${last}`, - ...(wait.fix === undefined ? {} : { fix: wait.fix }), - }), - ); - }, withinMs); + await landWithin(this.#client === undefined ? this.#redial() : undefined, { + transport: this.name, + server: `${target.host}:${target.port}`, + withinMs: wait.withinMs, + fix: wait.fix, + lastFailure: () => this.#lastFailure, }); - try { - await Promise.race([this.#client === undefined ? this.#redial() : undefined, late]); - } finally { - clearTimeout(timer); - } // The loop also ends when the transport is closed under it. if (this.#client === undefined) await this.#ensure(); } @@ -279,6 +267,7 @@ export class NatsTransport implements Transport { url: this.#options.url, name: 'ultimate', maxReconnectAttempts: this.#attempts, + connectTimeoutMs: this.#dialTimeoutMs, // The library retries; the spread is ours, so a cluster restart does not bring every node // back on the same millisecond. reconnectDelay: () => policyDelay(this.#backoff, ++this.#retries, this.#rng), @@ -353,9 +342,7 @@ export class NatsTransport implements Transport { * kept subscription and is announced: changes published in the gap are gone. */ #redial(): Promise { - this.#redialLoop ??= this.#redialUntilUp().finally(() => { - this.#redialLoop = undefined; - }); + this.#redialLoop ??= this.#redialUntilUp(); return this.#redialLoop; } @@ -384,7 +371,11 @@ export class NatsTransport implements Transport { } } } finally { + // Both, HERE, in the loop's own last synchronous step — never in a reaction to its promise. + // A reaction runs a microtask later, and a client lost in that gap (`#lost`) was handed the + // finished loop back: nothing dialled again and its subscriptions stayed orphaned. this.#redialing = undefined; + this.#redialLoop = undefined; } } @@ -470,8 +461,16 @@ export class NatsTransport implements Transport { #report(error: unknown, subject: string): void { const handler = this.#options.onError; if (handler !== undefined) { - handler(error, subject); - return; + // Total: the handler is injected, and its throw would land in whatever called this — the + // dial loop (started with `void`: an unhandled rejection and no more retries), the + // library's status loop, a subscriber's delivery. A reporter that cannot report is not a + // reason to stop dialling; the fault falls through to the logger line below. + try { + handler(error, subject); + return; + } catch (thrown) { + logger.error('nats transport onError threw', { error: renderThrowable(thrown) }); + } } logger.error('nats transport error', { transport: this.name, diff --git a/packages/realtime/src/replicator-blip.test.ts b/packages/realtime/src/replicator-blip.test.ts new file mode 100644 index 000000000..f17414bb0 --- /dev/null +++ b/packages/realtime/src/replicator-blip.test.ts @@ -0,0 +1,127 @@ +// A publish refused because the bus is AWAY, waited out in the handler. It used to end the run on +// the spot: the feed stopped, the lock was released and the takeover loop restarted from `lastLsn` +// — a whole restart cycle, and `/readyz` false, for every two-second NATS restart. + +import { describe, expect, test } from 'bun:test'; +import { formatLsn } from './changefeed'; +import { TransportUnavailableError } from './errors'; +import type { Transport } from './fanout'; +import { InProcessTransport } from './fanout'; +import { PUBLISH_RETRY_DELAYS_MS } from './replicator'; +import { change, rig, turns } from './replicator-rig-fixture'; + +/** A bus that is AWAY for the next `blips` publishes — the coded refusal a NATS restart gives. */ +const blipping = (blips: number): Transport & { published: string[]; attempts: number } => { + const inner = new InProcessTransport(); + const bus = { + name: 'blipping', + shared: inner.shared, + published: [] as string[], + attempts: 0, + subscribe: inner.subscribe.bind(inner), + close: () => inner.close(), + onReconnect: () => inner.onReconnect(), + publish: async (_subject: string, payload: string): Promise => { + bus.attempts += 1; + if (bus.attempts <= blips) { + throw new TransportUnavailableError({ + transport: 'nats', + reason: 'the client is reconnecting to the bus', + }); + } + bus.published.push(payload); + }, + }; + return bus; +}; + +// A publish refused because the bus is away used to end the run on the spot: the feed stopped, the +// lock was released and the takeover loop restarted from `lastLsn` — a whole restart cycle, and +// `/readyz` false, for every two-second NATS restart. +describe('a bus that is away for a moment', () => { + test('is waited out in the handler: same envelope, no restart, still running', async () => { + const bus = blipping(2); + const { feed, lock, timers, replicator } = rig(bus); + await replicator.start(); + + const delivering = feed.deliver(change(7)); + await turns(); + // The first retry is waiting on its timer, and the run is intact meanwhile. + expect(timers.delays).toEqual(PUBLISH_RETRY_DELAYS_MS.slice(0, 1)); + expect(replicator.running).toBe(true); + timers.fire(); + await turns(); + timers.fire(); + await delivering; + await turns(); + + expect(timers.delays).toEqual(PUBLISH_RETRY_DELAYS_MS.slice(0, 2)); + expect(bus.published).toHaveLength(1); + expect(bus.attempts).toBe(3); + expect(replicator.running).toBe(true); + const stats = replicator.stats(); + expect([stats.published, stats.restarts, stats.failure]).toEqual([1, 0, null]); + expect(lock.released).toBe(0); + expect(feed.stops).toBe(0); + await replicator.stop(); + }); + + test('is bounded: past the last retry the run ends and the takeover loop takes it, as before', async () => { + const bus = blipping(Number.POSITIVE_INFINITY); + const { feed, timers, replicator } = rig(bus); + await replicator.start(); + + void feed.deliver(change(7)).catch(() => undefined); + for (const _delay of PUBLISH_RETRY_DELAYS_MS) { + await turns(); + timers.fire(); + } + await turns(); + + expect(bus.attempts).toBe(PUBLISH_RETRY_DELAYS_MS.length + 1); + expect(replicator.running).toBe(false); + expect(replicator.stats().failure ?? '').toContain(formatLsn(7)); + // The retries, then the restart's own base wait. + expect(timers.delays).toEqual([...PUBLISH_RETRY_DELAYS_MS, 100]); + // A few attempts over about two seconds: a blip, never a stall. + expect(PUBLISH_RETRY_DELAYS_MS.reduce((sum, ms) => sum + ms, 0)).toBeLessThanOrEqual(2_500); + await replicator.stop(); + }); + + test('a run that ended during the wait publishes nothing when the timer fires', async () => { + const bus = blipping(1); + const { feed, timers, replicator } = rig(bus); + await replicator.start(); + + void feed.deliver(change(7)).catch(() => undefined); + await turns(); + await replicator.stop(); + timers.fire(); + await turns(); + + expect(bus.attempts).toBe(1); + expect(bus.published).toEqual([]); + }); + + test('a refusal that is not the bus being away is not retried', async () => { + const inner = new InProcessTransport(); + const bus: Transport = { + name: 'oversize', + shared: inner.shared, + subscribe: inner.subscribe.bind(inner), + close: () => inner.close(), + onReconnect: () => inner.onReconnect(), + // The library's own refusal for a change over `max_payload`: retrying it cannot help. + publish: () => Promise.reject(new RangeError('payload exceeds max_payload')), + }; + const { feed, timers, replicator } = rig(bus); + await replicator.start(); + + await feed.deliver(change(7)).catch(() => undefined); + await turns(); + + expect(replicator.running).toBe(false); + expect(timers.delays).toEqual([100]); + await replicator.stop(); + }); +}); diff --git a/packages/realtime/src/replicator-races.test.ts b/packages/realtime/src/replicator-races.test.ts index b1b1a7903..40e6b83b5 100644 --- a/packages/realtime/src/replicator-races.test.ts +++ b/packages/realtime/src/replicator-races.test.ts @@ -2,160 +2,10 @@ // feed and a manual scheduler — so the order of events is the test's and never the runtime's. import { describe, expect, test } from 'bun:test'; -import type { AdvisoryLock } from './advisory-lock'; -import type { ChangeEvent, ChangeFeed, ChangeFeedStartOptions } from './changefeed'; import { formatLsn } from './changefeed'; import type { Transport } from './fanout'; import { InProcessTransport } from './fanout'; -import { changeFeedReplicator, STOP_DEADLINE_MS } from './replicator'; -import type { Scheduler } from './thundering-herd'; - -const turns = async (count = 100): Promise => { - for (let tick = 0; tick < count; tick += 1) await Promise.resolve(); -}; - -const NEVER = new Promise(() => undefined); - -const stubLock = () => { - const listeners = new Set<(reason: string) => void>(); - const lock = { - key: 'x:replicator:races', - held: false, - acquired: 0, - released: 0, - abandoned: 0, - /** What `release()` waits on. `NEVER` is a session whose unlock is never answered. */ - releasing: Promise.resolve() as Promise, - tryAcquire: async (): Promise => { - lock.acquired += 1; - lock.held = true; - return true; - }, - release: async (): Promise => { - lock.released += 1; - await lock.releasing; - lock.held = false; - }, - abandon: (): void => { - lock.abandoned += 1; - lock.held = false; - }, - onLost: (listener: (reason: string) => void): (() => void) => { - listeners.add(listener); - return () => void listeners.delete(listener); - }, - lose: (reason: string): void => { - lock.held = false; - for (const listener of [...listeners]) listener(reason); - }, - }; - return lock satisfies AdvisoryLock; -}; - -const gatedFeed = () => { - const feed = { - source: 'gated', - starts: 0, - stops: 0, - abandons: 0, - /** Who was abandoned, in order — the feed must be silent before the lock is given up. */ - order: [] as string[], - pumping: false, - froms: [] as (string | undefined)[], - handlers: undefined as ChangeFeedStartOptions | undefined, - /** What `start()` waits on before it reports the stream live. */ - dialling: Promise.resolve() as Promise, - stopping: Promise.resolve() as Promise, - start: async (options: ChangeFeedStartOptions): Promise => { - feed.starts += 1; - feed.froms.push(options.from); - await feed.dialling; - feed.handlers = options; - feed.pumping = true; - }, - stop: async (): Promise => { - feed.stops += 1; - await feed.stopping; - feed.pumping = false; - }, - abandon: (): void => { - feed.abandons += 1; - feed.order.push('feed.abandon'); - feed.pumping = false; - }, - lastLsn: (): string | null => null, - /** Deliver one change the way a pump does: a handler that rejects ends the stream. */ - deliver: async (change: ChangeEvent): Promise => { - const handlers = feed.handlers; - if (handlers === undefined || !feed.pumping) return; - try { - await handlers.onChange(change); - } catch (error) { - feed.pumping = false; - handlers.onEnd?.(error instanceof Error ? error.message : String(error)); - } - }, - end: (reason: string): void => { - feed.pumping = false; - feed.handlers?.onEnd?.(reason); - }, - }; - return feed satisfies ChangeFeed; -}; - -const manual = () => { - const pending: { fn: () => void; ms: number }[] = []; - const delays: number[] = []; - const schedule: Scheduler = (fn, ms) => { - const entry = { fn, ms }; - // The unlock deadline rides the same seam; `delays` is the RESTART waits alone. - if (ms !== STOP_DEADLINE_MS) delays.push(ms); - pending.push(entry); - return () => { - const at = pending.indexOf(entry); - if (at >= 0) pending.splice(at, 1); - }; - }; - return { - schedule, - delays, - pending, - fire: (): void => { - for (const entry of pending.splice(0)) entry.fn(); - }, - }; -}; - -const change = (position: number): ChangeEvent => ({ - table: 'posts', - op: 'insert', - before: null, - after: { id: `p${position}` }, - lsn: formatLsn(position), - txid: String(position), - orgId: 'o1', - at: 0, - write: null, -}); - -const rig = (transport: Transport = new InProcessTransport()) => { - const lock = stubLock(); - const feed = gatedFeed(); - const abandonLock = lock.abandon; - lock.abandon = (): void => { - feed.order.push('lock.abandon'); - abandonLock(); - }; - const timers = manual(); - const replicator = changeFeedReplicator({ - feed, - lock, - transport, - schedule: timers.schedule, - backoff: { baseMs: 100, maxMs: 10_000, factor: 2, jitter: 'none' }, - }); - return { lock, feed, timers, replicator }; -}; +import { change, NEVER, rig, turns } from './replicator-rig-fixture'; /** A bus that refuses every publish — a change over the payload limit refuses every time. */ const refusing = (): Transport & { published: string[]; refuse: boolean } => { diff --git a/packages/realtime/src/replicator-rig-fixture.ts b/packages/realtime/src/replicator-rig-fixture.ts new file mode 100644 index 000000000..eae28d1b7 --- /dev/null +++ b/packages/realtime/src/replicator-rig-fixture.ts @@ -0,0 +1,159 @@ +// Single responsibility: the replicator's interleaving rig — a stub lock, a gated feed and a manual +// scheduler — so the order of events is a test's and never the runtime's. Shared by the suites that +// drive `changeFeedReplicator` through its seams; kept out of them so neither outgrows its ceiling. +// Not part of the public API — `index.ts` deliberately does not re-export it. + +import type { AdvisoryLock } from './advisory-lock'; +import type { ChangeEvent, ChangeFeed, ChangeFeedStartOptions } from './changefeed'; +import { formatLsn } from './changefeed'; +import type { Transport } from './fanout'; +import { InProcessTransport } from './fanout'; +import { changeFeedReplicator, STOP_DEADLINE_MS } from './replicator'; +import type { Scheduler } from './thundering-herd'; + +export const turns = async (count = 100): Promise => { + for (let tick = 0; tick < count; tick += 1) await Promise.resolve(); +}; + +export const NEVER = new Promise(() => undefined); + +export const stubLock = () => { + const listeners = new Set<(reason: string) => void>(); + const lock = { + key: 'x:replicator:races', + held: false, + acquired: 0, + released: 0, + abandoned: 0, + /** What `release()` waits on. `NEVER` is a session whose unlock is never answered. */ + releasing: Promise.resolve() as Promise, + tryAcquire: async (): Promise => { + lock.acquired += 1; + lock.held = true; + return true; + }, + release: async (): Promise => { + lock.released += 1; + await lock.releasing; + lock.held = false; + }, + abandon: (): void => { + lock.abandoned += 1; + lock.held = false; + }, + onLost: (listener: (reason: string) => void): (() => void) => { + listeners.add(listener); + return () => void listeners.delete(listener); + }, + lose: (reason: string): void => { + lock.held = false; + for (const listener of [...listeners]) listener(reason); + }, + }; + return lock satisfies AdvisoryLock; +}; + +export const gatedFeed = () => { + const feed = { + source: 'gated', + starts: 0, + stops: 0, + abandons: 0, + /** Who was abandoned, in order — the feed must be silent before the lock is given up. */ + order: [] as string[], + pumping: false, + froms: [] as (string | undefined)[], + handlers: undefined as ChangeFeedStartOptions | undefined, + /** What `start()` waits on before it reports the stream live. */ + dialling: Promise.resolve() as Promise, + stopping: Promise.resolve() as Promise, + start: async (options: ChangeFeedStartOptions): Promise => { + feed.starts += 1; + feed.froms.push(options.from); + await feed.dialling; + feed.handlers = options; + feed.pumping = true; + }, + stop: async (): Promise => { + feed.stops += 1; + await feed.stopping; + feed.pumping = false; + }, + abandon: (): void => { + feed.abandons += 1; + feed.order.push('feed.abandon'); + feed.pumping = false; + }, + lastLsn: (): string | null => null, + /** Deliver one change the way a pump does: a handler that rejects ends the stream. */ + deliver: async (change: ChangeEvent): Promise => { + const handlers = feed.handlers; + if (handlers === undefined || !feed.pumping) return; + try { + await handlers.onChange(change); + } catch (error) { + feed.pumping = false; + handlers.onEnd?.(error instanceof Error ? error.message : String(error)); + } + }, + end: (reason: string): void => { + feed.pumping = false; + feed.handlers?.onEnd?.(reason); + }, + }; + return feed satisfies ChangeFeed; +}; + +export const manual = () => { + const pending: { fn: () => void; ms: number }[] = []; + const delays: number[] = []; + const schedule: Scheduler = (fn, ms) => { + const entry = { fn, ms }; + // The unlock deadline rides the same seam; `delays` is the RESTART waits alone. + if (ms !== STOP_DEADLINE_MS) delays.push(ms); + pending.push(entry); + return () => { + const at = pending.indexOf(entry); + if (at >= 0) pending.splice(at, 1); + }; + }; + return { + schedule, + delays, + pending, + fire: (): void => { + for (const entry of pending.splice(0)) entry.fn(); + }, + }; +}; + +export const change = (position: number): ChangeEvent => ({ + table: 'posts', + op: 'insert', + before: null, + after: { id: `p${position}` }, + lsn: formatLsn(position), + txid: String(position), + orgId: 'o1', + at: 0, + write: null, +}); + +export const rig = (transport: Transport = new InProcessTransport()) => { + const lock = stubLock(); + const feed = gatedFeed(); + const abandonLock = lock.abandon; + lock.abandon = (): void => { + feed.order.push('lock.abandon'); + abandonLock(); + }; + const timers = manual(); + const replicator = changeFeedReplicator({ + feed, + lock, + transport, + schedule: timers.schedule, + backoff: { baseMs: 100, maxMs: 10_000, factor: 2, jitter: 'none' }, + }); + return { lock, feed, timers, replicator }; +}; diff --git a/packages/realtime/src/replicator.ts b/packages/realtime/src/replicator.ts index 3c29c4f64..33b216be9 100644 --- a/packages/realtime/src/replicator.ts +++ b/packages/realtime/src/replicator.ts @@ -11,7 +11,7 @@ // its feed and reports `/readyz` false. A stream that ENDS — or a lock that is LOST — is this file's // to answer: `running` goes false, everything is let go, and the process asks again on a backoff. -import { logger, renderThrowable, uuidV7, withSpan } from '@ultimat3/core'; +import { isUltimateError, logger, renderThrowable, uuidV7, withSpan } from '@ultimat3/core'; import type { AdvisoryLock } from './advisory-lock'; import type { ChangeEvent, ChangeFeed } from './changefeed'; import { ReplicationFailedError } from './errors'; @@ -100,6 +100,18 @@ interface Refusal { */ export const STOP_DEADLINE_MS = 5_000; +/** + * How long a publish refused because the bus is AWAY is waited out, in the handler, before the run + * ends: three more attempts over two seconds. A NATS restart is a second or two, and ending the + * run for it costs a stream stop, an unlock, a backoff and a re-read from `lastLsn` — with + * `/readyz` false throughout. Longer than this is an outage, and the takeover loop's to handle. + */ +export const PUBLISH_RETRY_DELAYS_MS: readonly number[] = [100, 400, 1_500]; + +/** The bus is unreachable — as opposed to a change it will never take (a payload over the limit). */ +const busAway = (thrown: unknown): boolean => + isUltimateError(thrown) && thrown.code === 'X_TRANSPORT_UNAVAILABLE'; + const fencedOut = (reason: string): ReplicationFailedError => new ReplicationFailedError({ stage: 'stream', @@ -180,6 +192,29 @@ export function changeFeedReplicator(options: ReplicatorOptions): Replicator { return outcome.how === 'failed' ? outcome.error : undefined; }; + /** + * One envelope, published — retried on `PUBLISH_RETRY_DELAYS_MS` while the bus is away. The SAME + * envelope each time, so a consumer sees one `seq`. Fenced after every wait: a run that ended + * meanwhile publishes nothing, for the reason the handler below gives. + */ + const publishThroughBlip = async (run: Run, subject: string, envelope: string): Promise => { + for (let retry = 0; ; retry += 1) { + try { + await options.transport.publish(subject, envelope); + return; + } catch (thrown) { + const delay = PUBLISH_RETRY_DELAYS_MS[retry]; + if (delay === undefined || !busAway(thrown)) throw thrown; + await new Promise((resolve) => { + schedule(resolve, delay); + }); + if (current !== run || run.over !== null) { + throw fencedOut(run.over ?? 'a newer run started'); + } + } + } + }; + const changeHandler = (run: Run) => async (raw: ChangeEvent): Promise => { @@ -200,7 +235,7 @@ export function changeFeedReplicator(options: ReplicatorOptions): Replicator { await withSpan('realtime.replicate', async () => { seq += 1; try { - await options.transport.publish(subjectOf(change), encodeEnvelope(change, seq, producer)); + await publishThroughBlip(run, subjectOf(change), encodeEnvelope(change, seq, producer)); } catch (thrown) { const error = renderThrowable(thrown); const same = refusal !== null && refusal.lsn === change.lsn; diff --git a/wiki/Error-Codes.md b/wiki/Error-Codes.md index 3ba32d603..c66e93f3e 100644 --- a/wiki/Error-Codes.md +++ b/wiki/Error-Codes.md @@ -432,7 +432,7 @@ No secret and no signature reaches a `cause`, a `fix` or a `meta`, and a URL is | `X_PROTOCOL_VERSION` | client and sync node disagree on the wire protocol | a client from an older build | `x build` and redeploy the client; the node sends `update-available` before draining | | `X_CURSOR_STALE` | the resume LSN is outside the change buffer | a long disconnect | pass `snapshot` to `resumeFrom()` so the fallback re-snapshots | | `X_REBASE_CONFLICT` | a local mutation could not be rebased | server state moved incompatibly | set `conflict: 'server-wins'`, or return a row from `custom(merge)` | -| `X_TRANSPORT_UNAVAILABLE` | the fanout bus is unreachable | the nats-server `NATS_URL` names is down or misconfigured. **At boot** only a `sync` node or a replicator raises it, after retrying the dial for 15 s — the cause names the server, the wait and the last attempt's own failure. A `web`, `worker` or `scheduler` process boots without the bus and raises it from a **publish** instead (`publishChannelEvent`, the cache-invalidation broadcast), at once, until its background dial lands; a publish made while the client is reconnecting is refused the same way rather than queued ([Realtime → what each role needs from the bus](Realtime#what-each-role-needs-from-the-bus)) | `x doctor` — then check `NATS_URL`; in app code, catch it around a publish and log — the event meant "re-read" | +| `X_TRANSPORT_UNAVAILABLE` | the fanout bus is unreachable | the nats-server `NATS_URL` names is down or misconfigured. **At boot** only a `sync` node or a replicator raises it, after retrying the dial for 15 s — the cause names the server, the wait and the last attempt's own failure. A `web`, `worker` or `scheduler` process boots without the bus and raises it from a **publish** instead (`publishChannelEvent`, the cache-invalidation broadcast), at once, until its background dial lands; a publish made once the client's socket has closed is refused the same way rather than buffered by the client; the replicator retries such a refusal three times over 2 s before its run ends ([Realtime → what each role needs from the bus](Realtime#what-each-role-needs-from-the-bus)) | `x doctor` — then check `NATS_URL`; in app code, catch it around a publish and log — the event meant "re-read" | | `X_TRANSPORT_PROTOCOL` | the bus does not speak the protocol this build speaks | nats-server older than 2.11, JetStream not enabled, or something that is not NATS on the port | run `nats:2.11-alpine` or newer with `-js`; reconnecting cannot fix it, so this never retries | | `X_REPLICATION_FAILED` | the replication connection was refused | `wal_level` not `logical`, a role that may not create or extend the publication (the replicator ensures it at boot), a role without `REPLICATION`, a slot another replicator holds, wrong credentials | the message names the object; the fix is the exact setting, `CREATE PUBLICATION` or `pg_drop_replication_slot` statement — and a `REPLICATION` grant only on a cluster dedicated to the app ([why](https://github.com/developerz-ai/ultimate/blob/main/docs/ops/01-kubernetes.md#replication-is-a-cluster-wide-grant)) | | `X_REPLICATION_PROTOCOL` | the WAL stream cannot be decoded | a server or `pgoutput` version this build does not speak, or a proxy on the replication port | `x doctor --json` — point the URL at postgres itself, on a server ≥ 14 | diff --git a/wiki/Realtime.md b/wiki/Realtime.md index b97fe0d52..7c2f61f74 100644 --- a/wiki/Realtime.md +++ b/wiki/Realtime.md @@ -363,8 +363,8 @@ Under `realtime: { transport: 'nats' }` every role holds a connection, and only | Role | Uses the bus to | At boot | NATS down while running | JetStream / the presence bucket | `transport` check | |---|---|---|---|---|---| -| `sync` | serve sockets: subscribe to changes and channels, hold presence | **awaits** the dial, retried on backoff for 15 s, then refuses the boot with `X_TRANSPORT_UNAVAILABLE` naming the server, the wait, the last attempt's failure and the variable to check | reconnects on its own; windows re-snapshot on return | **required at the dial** — no `-js`, no boot | `failing` | -| `replicator` | publish committed changes to the nodes | **awaits** the dial, same 15 s, same refusal | reconnects on its own | not asked for | `failing` | +| `sync` | serve sockets: subscribe to changes and channels, hold presence | **awaits** the dial, retried on backoff for 15 s (each attempt has a 4 s connect timeout, so a server that accepts and says nothing still fails attempts inside the wait), then refuses the boot with `X_TRANSPORT_UNAVAILABLE` naming the server, the wait, the last attempt's failure and the variable to check | reconnects on its own; windows re-snapshot on return | **required at the dial** — no `-js`, no boot | `failing` | +| `replicator` | publish committed changes to the nodes | **awaits** the dial, same 15 s, same refusal | a publish refused because the bus is away is retried in place — the same envelope, three more attempts over 2 s — so a NATS restart costs no stream restart; past that the run ends and the takeover loop resumes from the last published lsn | not asked for | `failing` | | `web`, `worker`, `scheduler` | publish channel events (`publishChannelEvent`) and cache invalidations; receive peers' invalidations | **does not wait**: dials in the background on a jittered backoff (500 ms doubling to 30 s) and boots, serves and runs jobs meanwhile | stays up and ready; resumes on its own, no restart | not asked for — asserted only if something reads presence | `degraded` | | `migrate` | nothing | never dials | — | — | — | @@ -372,12 +372,13 @@ Under `realtime: { transport: 'nats' }` every role holds a connection, and only | While the bus is down, on a publishing role | What happens | |---|---| -| `publishChannelEvent(…)` | rejects at once with `X_TRANSPORT_UNAVAILABLE` — never parked behind the dial, never queued. Catch it and log: the event said "re-read", and a subscriber that reconnects re-reads anyway | -| a publish made while the client is **reconnecting** | refused the same way. The `nats` client would otherwise buffer it without bound and replay it when the server returned | -| an action's `invalidates` / `invalidateTags` | every local tier, Redis and the CDN are cleared as usual; the broadcast to the other replicas fails into `report.errors` (`tier: 'broadcast'`, logged as `cache.invalidate.partial`) and the write succeeds. **A missed bust is not replayed**: another replica's in-process `lru` copy and its ISR page stay until their TTL. Nothing is buffered for later, because a replica whose own connection was down missed its peers' busts too and no sender-side queue reaches it | +| `publishChannelEvent(…)` | rejects at once with `X_TRANSPORT_UNAVAILABLE` — never parked behind the dial. Catch it and log: the event said "re-read", and a subscriber that reconnects re-reads anyway | +| a publish made while the client is **reconnecting** | refused the same way, from the moment the client's socket closes. The `nats` client would otherwise buffer it without bound and replay it when the server returned, and it has no option to forbid that. One window remains: a connection whose packets are silently dropped still reads as connected until two pings go unanswered (10 s apart — within 30 s, where the library's default is six minutes), and a publish made inside it is buffered and sent on reconnect | +| an action's `invalidates` / `invalidateTags` | every local tier, Redis and the CDN are cleared as usual; the broadcast to the other replicas fails into `report.errors` (`tier: 'broadcast'`, logged as `cache.invalidate.partial`) and the write succeeds. **The refused tags are kept and published when the bus returns** — de-duplicated, at most 1,024 of them; past that the process owes one *flush-all* instead, so nothing grows with the outage. Until then another replica's in-process `lru` copy and its tag-revalidated ISR page are stale | +| when the bus returns | every process whose connection was down **drops its in-process tier and marks its tag-revalidated ISR pages stale** (`flushProcessTiers`): it heard no peer for a window nobody measured, so nothing in its own heap is known fresh. One cold `lru` per replica per outage — sized for by the database, not hidden. A replica that receives a peer's flush-all does the same. Redis and the CDN are not touched: whoever ran a bust cleared those | | `/readyz` | 200 in both `health.readiness` modes, `checks.transport: 'degraded'` | | `/readyz?deep=1` | 503 — the reading a monitor alerts on | -| the log | the boot line `{"msg":"ultimate started",…,"bus":"nats(connecting)"}` (`nats(up)` when it already is, `in-process` with no NATS); `{"msg":"ultimate bus","bus":"nats(up)"}` when the dial lands, and again after every recovery; `nats transport error` on dial attempts 1, 2, 4, 8, … | +| the log | the boot line `{"msg":"ultimate started",…,"bus":"nats(connecting)"}` (`nats(up)` when it already is, `in-process` with no NATS); `{"msg":"ultimate bus","bus":"nats(up)"}` when the dial lands, and again after every recovery; `nats transport error` on dial attempts 1, 2, 4, 8, …, and `cache.broadcast.subscribe-failed` on the same attempts | ## LSN cursors From 0a9adaf1a381055bf9f5077a12778392ec48730e Mon Sep 17 00:00:00 2001 From: sebi Date: Sat, 10 Oct 2026 18:23:20 -0500 Subject: [PATCH 3/3] fix(cache): what is owed to the bus is settled once at a time and taken before its publish; the replicator's stop() ends a publish retry wait at once Review of #755, second round. - cli: settle() ran from every reconnect and after every accepted publish with nothing serializing it, so two that overlapped published the same batch (or the same flush-all) twice. One runs at a time; a call that arrives mid-run asks for one more pass. The batch and the flush-all are taken before the publish and put back if the bus refuses. - realtime: publishThroughBlip kept no cancellation for its timer, so a stop() during a retry held the feed's handler for up to 1.5 s. stop() now clears the timer and settles the wait into the run's fence. - tests for what the changelog claims and nothing asserted: the `ultimate bus` line on first connect and after every recovery (unit and live), the boot line's bus field as nats(connecting) and nats(up) on a booted process against a real server, and dial failures reported on attempts 1, 2, 4, 8. Co-Authored-By: Claude Opus 5.5 --- CHANGELOG.md | 4 +- packages/cli/src/runtime-bus.live.test.ts | 20 ++- packages/cli/src/runtime-bus.test.ts | 37 ++++ .../cli/src/runtime-cache-bus-loss.test.ts | 166 +++++++++++++++++- packages/cli/src/runtime-cache.ts | 48 ++++- packages/cli/src/serve.live.test.ts | 88 +++++++++- .../src/nats-transport-background.test.ts | 28 ++- packages/realtime/src/replicator-blip.test.ts | 27 +++ packages/realtime/src/replicator.ts | 16 +- 9 files changed, 421 insertions(+), 13 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 8c903e27b..96159a98c 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -15,8 +15,8 @@ Tier 0 — core. Tier 1 — cache. Tier 3 — realtime. Tier 5 — cli. - **NATS is no longer a boot dependency of a role that only publishes to it.** Under `realtime: { transport: 'nats' }` every role awaited the first dial before it bound a socket, and that dial never gave up: `openNatsClient` set `waitOnFirstConnect`, under which nats@2.29.3 retries a failed first dial past its attempt counter, forever. A `web`, `worker` or `scheduler` pod that restarted while NATS was down (an OOM, a node drain, a rollout, a scale-up) therefore hung in boot: pages, webhooks and jobs were down for a bus those roles only send "re-read" events to, and `health.readiness: 'process'` could not help because no listener existed yet. The role now decides (`runtime-bus.ts`, `selectTransport(env, realtime, { use })`): `sync` and the replicator still need the bus and await it; `web`, `worker`, `scheduler` and the dev MCP host dial it in the background on a jittered backoff (500 ms doubling to 30 s) and boot at once. Nothing to change in an app. The table is [Realtime → What each role needs from the bus](https://github.com/developerz-ai/ultimate/wiki/Realtime#what-each-role-needs-from-the-bus). - **A `sync` node or a replicator without the bus fails fast and says why.** The dial is retried for 15 s (`BUS_CONNECT_WAIT_MS`) and then refused with `X_TRANSPORT_UNAVAILABLE`, whose cause names the server, the wait and the last attempt's own failure, and whose fix names the variable `realtime.urlEnv` points at. It used to sit silent until something killed it. Each attempt carries a 4 s connect timeout (`DIAL_TIMEOUT_MS`; the library's is 20 s), so a server that accepts the socket and says nothing still fails attempts inside the wait and the refusal's `last attempt:` is never empty. - **A publish with no live connection is refused at once, not buffered.** While the background dial is in flight, `publishChannelEvent` and the cache-invalidation broadcast reject with `X_TRANSPORT_UNAVAILABLE` immediately. A publish made after the client's socket has closed is refused the same way, in every role: the `nats` client buffered it without bound and replayed the lot when the server returned, and it has no option that forbids the buffer, so the transport reads the client's own connection flag before it hands a publish over. One window is left and is stated rather than hidden: a connection whose packets are silently dropped reads as connected until two pings go unanswered — now 10 s apart (`PING_INTERVAL_MS`, `MAX_PINGS_OUT`), so within 30 s where the library's default is six minutes — and a publish made inside it is buffered and sent on reconnect. Publishing resumes with no restart when the bus is back, on first connect and after every loss. -- **A cache bust made while the bus is away reaches the other replicas when it returns.** The replica that made it, Redis and the CDN are cleared as before and the broadcast lands in the report's `errors` (`cache.invalidate.partial`). The refused wire tags are now kept — de-duplicated, at most 1,024 (`MAX_DEFERRED_TAGS`) — and published on the transport's next reconnect, or after the next publish the bus accepts; past the bound the process owes one flush-all marker (`{"flush":"all"}` on `x.cache.invalidate`) instead of a queue, so nothing grows with an outage. And every process drops what it holds in its own heap when its connection comes back, or when its boot subscribe lands after a refusal: it heard no peer for a window nobody measured. That is `flushProcessTiers()` on `@ultimat3/cache` — `CacheTier.clear()` on the in-process tier (`lruTier` implements it; a shared tier does not), every tag-revalidated ISR page marked stale (a peer's bust reaches those pages by this broadcast and by nothing else), and every fill in flight fenced out. The cost is one cold in-process cache per replica per NATS outage. A replica running an older build ignores the marker and waits for its TTLs, as it always did. -- **The replicator rides out a NATS restart.** A publish refused because the bus is away ended the run on the spot — stream stopped, lock released, backoff, re-read from the last lsn, `/readyz` false throughout — which the refusal above would have made the cost of every blip. The handler now retries the same envelope three more times over 2 s (`PUBLISH_RETRY_DELAYS_MS`), fenced after each wait, and only then ends the run for the takeover loop. A refusal that is not the bus being away (a payload over the server's limit) is not retried. +- **A cache bust made while the bus is away reaches the other replicas when it returns.** The replica that made it, Redis and the CDN are cleared as before and the broadcast lands in the report's `errors` (`cache.invalidate.partial`). The refused wire tags are now kept — de-duplicated, at most 1,024 (`MAX_DEFERRED_TAGS`) — and published on the transport's next reconnect, or after the next publish the bus accepts; past the bound the process owes one flush-all marker (`{"flush":"all"}` on `x.cache.invalidate`) instead of a queue, so nothing grows with an outage. What is owed is published by one settle at a time and taken before its publish — put back if the bus refuses — so overlapping reconnects send a batch once and a bust refused mid-publish is never cleared by a success that did not carry it. And every process drops what it holds in its own heap when its connection comes back, or when its boot subscribe lands after a refusal: it heard no peer for a window nobody measured. That is `flushProcessTiers()` on `@ultimat3/cache` — `CacheTier.clear()` on the in-process tier (`lruTier` implements it; a shared tier does not), every tag-revalidated ISR page marked stale (a peer's bust reaches those pages by this broadcast and by nothing else), and every fill in flight fenced out. The cost is one cold in-process cache per replica per NATS outage. A replica running an older build ignores the marker and waits for its TTLs, as it always did. +- **The replicator rides out a NATS restart.** A publish refused because the bus is away ended the run on the spot — stream stopped, lock released, backoff, re-read from the last lsn, `/readyz` false throughout — which the refusal above would have made the cost of every blip. The handler now retries the same envelope three more times over 2 s (`PUBLISH_RETRY_DELAYS_MS`), fenced after each wait, and only then ends the run for the takeover loop. `stop()` ends a wait in flight at once. A refusal that is not the bus being away (a payload over the server's limit) is not retried. - **Only a `sync` node requires JetStream at boot.** The presence bucket was asserted on every dial of every role, so a publisher failed on a nats-server without `-js`. It is asserted at the dial where presence is served and on first use of `transport.shared` everywhere else (`NatsTransportOptions.presenceBucket`). - **A dead bus no longer takes a publishing role out of the ingress.** `/readyz` in the default `'dependencies'` mode answered 503 on every `web` pod at once while NATS was down. A readiness check now has a third answer, `'degraded'` (`registerReadinessCheck(name, check, { onFailure: 'degraded' })`, `ReadinessStatus`): reported by name, never a 503 on `/readyz` in either mode, and a 503 on `/readyz?deep=1`. The `transport` check is `degraded` on `web`, `worker` and `scheduler` and stays `failing` on `sync` and the replicator. A monitor that must see a bus outage on a web pod reads `?deep=1`, as [Deployment](https://github.com/developerz-ai/ultimate/wiki/Deployment) already says to. - **The boot line says where the bus is.** `ultimate started` carries a `bus` field — `nats(up)`, `nats(connecting)` or `in-process` (`ServedApp.bus`) — and `ultimate bus` is logged with `bus: 'nats(up)'` each time the connection lands. A dial that keeps failing is reported on attempts 1, 2, 4, 8, … rather than once per attempt, and so is `cache.broadcast.subscribe-failed`; that subscribe is woken by the bus coming up instead of waiting out its own backoff. diff --git a/packages/cli/src/runtime-bus.live.test.ts b/packages/cli/src/runtime-bus.live.test.ts index 7c284ad0b..625131df6 100644 --- a/packages/cli/src/runtime-bus.live.test.ts +++ b/packages/cli/src/runtime-bus.live.test.ts @@ -20,7 +20,7 @@ import { tmpdir } from 'node:os'; import { join } from 'node:path'; import { invalidateTags, tag } from '@ultimat3/cache'; import type { HealthReport } from '@ultimat3/core'; -import { isUltimateError, resetLifecycle } from '@ultimat3/core'; +import { isUltimateError, logger, resetLifecycle } from '@ultimat3/core'; import { allow } from '@ultimat3/policy'; import { channel, clearChannels } from '@ultimat3/realtime'; import type { TransportSelection } from '@ultimat3/realtime/server'; @@ -118,8 +118,11 @@ let runtime: RunningServices | undefined; let root: string | undefined; let relay: Relay | undefined; let syncSide: TransportSelection | undefined; +let restoreLogger: (() => void) | undefined; afterEach(async () => { + restoreLogger?.(); + restoreLogger = undefined; await running?.stop(); running = undefined; await runtime?.stop().catch(() => undefined); @@ -187,6 +190,15 @@ describe.skipIf(url === undefined)('a web role and a NATS that is not there', () // NATS DOWN, and the web role boots anyway. Before this landed the line below sat in the // library's first-dial budget — ten attempts on a 30 s backoff — and then rejected. + // Every `ultimate bus` line this boot writes: the other half of a `connecting` boot line. + const announced: unknown[] = []; + const info = logger.info; + restoreLogger = (): void => { + logger.info = info; + }; + logger.info = (message: string, fields?: Record): void => { + if (message === 'ultimate bus') announced.push(fields); + }; const bootedAt = performance.now(); runtime = await startServices(resolveServices(root, env), env, undefined, 'apply', ['web']); running = await startRoles({ @@ -236,6 +248,7 @@ describe.skipIf(url === undefined)('a web role and a NATS that is not there', () const serving = runtime; await until(() => busLabel(serving.transport) === 'nats(up)', 90); expect(busLabel(serving.transport)).toBe('nats(up)'); + expect(announced).toEqual([{ bus: 'nats(up)', use: 'publish' }]); expect(await publish()).toBeUndefined(); await until(() => heard.length === 1, 10); expect(heard).toHaveLength(1); @@ -260,6 +273,11 @@ describe.skipIf(url === undefined)('a web role and a NATS that is not there', () relay.up(); await until(() => busLabel(serving.transport) === 'nats(up)', 90); expect(busLabel(serving.transport)).toBe('nats(up)'); + // Said again: one line per recovery, so a log shows when each outage ended. + expect(announced).toEqual([ + { bus: 'nats(up)', use: 'publish' }, + { bus: 'nats(up)', use: 'publish' }, + ]); expect(await publish()).toBeUndefined(); await until(() => heard.length === 2, 10); await Bun.sleep(200); diff --git a/packages/cli/src/runtime-bus.test.ts b/packages/cli/src/runtime-bus.test.ts index 2418cadea..33ff8111a 100644 --- a/packages/cli/src/runtime-bus.test.ts +++ b/packages/cli/src/runtime-bus.test.ts @@ -6,6 +6,7 @@ import { afterEach, beforeEach, describe, expect, test } from 'bun:test'; import { isUltimateError, + logger, markReady, readinessCheckCount, readyzPayload, @@ -111,6 +112,42 @@ describe('selectBus().start(), for a role that only publishes', () => { expect(broker.clients).toHaveLength(1); // the test's own listener; the boot's is closed }); + // Claimed in the changelog and the wiki: the other half of a boot line that said `connecting`. + test('logs `ultimate bus` with bus=nats(up) when the dial lands, and again after every recovery', async () => { + const lines: { message: string; fields: Record | undefined }[] = []; + const info = logger.info; + logger.info = (message: string, fields?: Record): void => { + lines.push({ message, fields }); + }; + const broker = new FakeNatsBroker(); + broker.offline = true; + const bus = selectBus({ env: ENV, realtime: NATS, roles: ['web'], select: fake(broker) }); + const running = await bus.start(); + const said = (): unknown[] => + lines.filter((line) => line.message === 'ultimate bus').map((line) => line.fields); + try { + await Bun.sleep(10); + expect(said()).toEqual([]); + + broker.offline = false; + await waitFor(() => said().length === 1); + expect(said()).toEqual([{ bus: 'nats(up)', use: 'publish' }]); + + broker.drop(); + expect(busLabel(running.transport)).toBe('nats(connecting)'); + broker.restore(); + expect(said()).toEqual([ + { bus: 'nats(up)', use: 'publish' }, + { bus: 'nats(up)', use: 'publish' }, + ]); + } finally { + await running.stop(); + logger.info = info; + } + // Released with the boot: a later recovery of a transport nobody holds says nothing. + expect(said()).toHaveLength(2); + }); + test('a server with no JetStream costs a publisher nothing', async () => { const broker = new FakeNatsBroker(); broker.fail('$JS.API', 1_000); diff --git a/packages/cli/src/runtime-cache-bus-loss.test.ts b/packages/cli/src/runtime-cache-bus-loss.test.ts index 610fa7939..b864e2ff6 100644 --- a/packages/cli/src/runtime-cache-bus-loss.test.ts +++ b/packages/cli/src/runtime-cache-bus-loss.test.ts @@ -18,7 +18,12 @@ import { } from '@ultimat3/cache'; import { logger } from '@ultimat3/core'; import type { Transport } from '@ultimat3/realtime/server'; -import { FakeNatsBroker, fakeNatsConnect, selectTransport } from '@ultimat3/realtime/server'; +import { + FakeNatsBroker, + fakeNatsConnect, + InProcessTransport, + selectTransport, +} from '@ultimat3/realtime/server'; import { CACHE_FLUSH_ALL, CACHE_INVALIDATE_SUBJECT, @@ -267,3 +272,162 @@ describe('the invalidation subscribe of a role booted with the bus down', () => expect(attempts.length).toBeLessThanOrEqual(Math.ceil(Math.log2(self.subscribes())) + 1); }); }); + +/** + * A bus held by hand: every publish waits for the test to accept or refuse it, and the reconnect + * is the test's to announce — so two settles overlap exactly where the test says they do. + */ +function heldBus() { + const inner = new InProcessTransport(); + const sends: { payload: string; accept(): void; refuse(): void }[] = []; + const listeners = new Set<() => void>(); + const held: Transport = { + name: 'held', + shared: inner.shared, + subscribe: (subject, handler) => inner.subscribe(subject, handler), + close: () => inner.close(), + onReconnect: (listener) => { + listeners.add(listener); + return () => { + listeners.delete(listener); + }; + }, + publish: (_subject, payload) => { + const gate = Promise.withResolvers(); + sends.push({ + payload, + accept: () => gate.resolve(), + refuse: () => gate.reject(new RangeError('the bus refused the publish')), + }); + return gate.promise; + }, + }; + transport = held; + release = startCacheTiers({ + env: {}, + purge: noopPurgeDriver(), + transport: held, + tiers: DEFAULT_CACHE_TIERS, + }); + const turns = async (): Promise => { + for (let turn = 0; turn < 50; turn += 1) await Promise.resolve(); + }; + /** One bust the bus refuses: its tags are now owed. */ + const refusedBust = async (...ids: string[]): Promise => { + const busting = invalidateTags(ids.map((id) => tag('post', id))); + await turns(); + sends.at(-1)?.refuse(); + await busting; + }; + return { + sends, + turns, + refusedBust, + reconnect: (): void => { + for (const listener of [...listeners]) listener(); + }, + }; +} + +// `settle` runs from the reconnect and after every accepted publish, and nothing serialized it: +// two that overlapped both read the same owed set and both published it, and one that was refused +// could leave the other's success clearing tags the bus never took. +describe('what is owed to the bus, settled by two callers at once', () => { + test('one batch is published once, however many reconnects announce the bus', async () => { + const bus = heldBus(); + await bus.refusedBust('1', '2'); + const before = bus.sends.length; + + bus.reconnect(); + bus.reconnect(); + bus.reconnect(); + await bus.turns(); + expect(bus.sends.slice(before).map((send) => send.payload)).toEqual(['["post:1","post:2"]']); + + bus.sends.at(-1)?.accept(); + await bus.turns(); + // Nothing is owed any more, so the calls that arrived mid-flight publish nothing. + expect(bus.sends).toHaveLength(before + 1); + }); + + test('one flush-all is published once', async () => { + const bus = heldBus(); + const ids = Array.from({ length: MAX_DEFERRED_TAGS + 1 }, (_, id) => `${id}`); + await bus.refusedBust(...ids); + const before = bus.sends.length; + + bus.reconnect(); + bus.reconnect(); + await bus.turns(); + expect(bus.sends.slice(before).map((send) => send.payload)).toEqual([CACHE_FLUSH_ALL]); + bus.sends.at(-1)?.accept(); + await bus.turns(); + expect(bus.sends).toHaveLength(before + 1); + }); + + test('a batch refused mid-settle is still owed, and the next reconnect publishes it', async () => { + const bus = heldBus(); + await bus.refusedBust('1'); + const before = bus.sends.length; + + bus.reconnect(); + await bus.turns(); + bus.sends.at(-1)?.refuse(); + await bus.turns(); + expect(warnings.map((warning) => warning.line)).toContain('cache.broadcast.deferred-failed'); + + bus.reconnect(); + await bus.turns(); + expect(bus.sends.slice(before).map((send) => send.payload)).toEqual([ + '["post:1"]', + '["post:1"]', + ]); + }); + + test('a flush-all refused mid-settle is still owed', async () => { + const bus = heldBus(); + await bus.refusedBust(...Array.from({ length: MAX_DEFERRED_TAGS + 1 }, (_, id) => `${id}`)); + const before = bus.sends.length; + + bus.reconnect(); + await bus.turns(); + bus.sends.at(-1)?.refuse(); + await bus.turns(); + bus.reconnect(); + await bus.turns(); + + expect(bus.sends.slice(before).map((send) => send.payload)).toEqual([ + CACHE_FLUSH_ALL, + CACHE_FLUSH_ALL, + ]); + }); + + test('a tag refused while a settle is in flight is not lost: the run goes round again', async () => { + const bus = heldBus(); + await bus.refusedBust('1'); + const before = bus.sends.length; + + bus.reconnect(); + await bus.turns(); + // The first batch is on the wire; a second bust is refused meanwhile, and the bus announced. + const busting = invalidateTags([tag('post', '2')]); + await bus.turns(); + bus.sends.at(-1)?.refuse(); + await busting; + bus.reconnect(); + await bus.turns(); + expect(bus.sends.slice(before).map((send) => send.payload)).toEqual([ + '["post:1"]', + '["post:2"]', + ]); + + // The batch already sent is accepted: only what it did not carry goes out next, once. + bus.sends[before]?.accept(); + await bus.turns(); + expect(bus.sends.slice(before).map((send) => send.payload)).toEqual([ + '["post:1"]', + '["post:2"]', + '["post:2"]', + ]); + }); +}); diff --git a/packages/cli/src/runtime-cache.ts b/packages/cli/src/runtime-cache.ts index 4190f1a7c..7cad608c9 100644 --- a/packages/cli/src/runtime-cache.ts +++ b/packages/cli/src/runtime-cache.ts @@ -180,17 +180,55 @@ export function startCacheTiers(options: CacheTiersOptions): () => Promise deferred.clear(); flushOwed = true; }; - /** Publish what is owed. Cleared only once the bus took it; a second refusal keeps it owed. */ - const settle = async (): Promise => { + /** + * One pass over what is owed. It is TAKEN before the publish and put back if the bus refuses, so + * a bust refused while this publish is in flight is owed afresh rather than cleared by a success + * that never carried it — and a flush-all sent before that bust cannot stand in for it. + */ + const settleOnce = async (): Promise => { if (flushOwed) { - await send(CACHE_FLUSH_ALL); flushOwed = false; + try { + await send(CACHE_FLUSH_ALL); + } catch (error) { + deferred.clear(); + flushOwed = true; + throw error; + } return; } if (deferred.size === 0) return; const batch = [...deferred]; - await send(JSON.stringify(batch)); - for (const wire of batch) deferred.delete(wire); + deferred.clear(); + try { + await send(JSON.stringify(batch)); + } catch (error) { + defer(batch); + throw error; + } + }; + // ONE settle at a time. It is asked for by every reconnect and after every accepted publish, + // and two that overlapped both published the same batch (and the same flush-all). A call that + // arrives mid-run asks for one more pass instead, which finds whatever the run did not carry. + let settling: Promise | undefined; + let again = false; + const settle = (): Promise => { + if (settling !== undefined) { + again = true; + return settling; + } + settling = (async (): Promise => { + try { + do { + again = false; + await settleOnce(); + } while (again); + } finally { + again = false; + settling = undefined; + } + })(); + return settling; }; const settleQuietly = (): void => { void settle().catch((error: unknown) => { diff --git a/packages/cli/src/serve.live.test.ts b/packages/cli/src/serve.live.test.ts index bf5a2658f..c34c9240d 100644 --- a/packages/cli/src/serve.live.test.ts +++ b/packages/cli/src/serve.live.test.ts @@ -64,7 +64,8 @@ function freePort(): number { return port ?? expect.unreachable('Bun.serve({ port: 0 }) opened no TCP port'); } -async function writeFixture(): Promise { +/** `realtime` is the section's source text; unset is the scaffold's own (the in-process bus). */ +async function writeFixture(realtime?: string): Promise { await rm(ROOT, { recursive: true, force: true }); await Bun.write( join(ROOT, 'package.json'), @@ -73,7 +74,9 @@ async function writeFixture(): Promise { await Bun.write( join(ROOT, 'app.config.ts'), "import { defineConfig } from '@ultimat3/core';\n" + - "export const config = defineConfig({ name: 'serve-fixture' });\n", + `export const config = defineConfig({ name: 'serve-fixture'${ + realtime === undefined ? '' : `, realtime: ${realtime}` + } });\n`, ); await Bun.write(join(ROOT, 'apps/web/server.ts'), scaffolded('apps/web/server.ts')); // The app's own MCP endpoint, in the contract `app-mcp.ts` reads: `apps//mcp.ts` exports @@ -276,3 +279,84 @@ describe('the scaffolded production entry is a runnable artifact', () => { BOOT_TIMEOUT_MS, ); }); + +// The boot line's `bus` field on a real client, in both states a role that only publishes can +// boot in. A unit test can assert the label; only a booted process shows the LINE an operator +// reads — and that the web role reaches it at all with nothing listening where NATS should be. +describe('the boot line says where the bus is', () => { + const NATS = "{ enabled: true, transport: 'nats', urlEnv: 'NATS_URL' }"; + const natsUrl = Bun.env['TEST_NATS_URL']; + + async function bootWeb( + url: string, + ): Promise<{ started: string; logs: () => string; port: number; stop(): Promise }> { + await writeFixture(NATS); + const port = freePort(); + const child = Bun.spawn(['bun', join(ROOT, 'apps/web/server.ts')], { + cwd: ROOT, + env: { + ...process.env, + PORT: String(port), + ROLE: 'web', + HOST: '127.0.0.1', + METRICS_PORT: String(freePort()), + NATS_URL: url, + }, + stdout: 'pipe', + stderr: 'pipe', + }); + const out = pump(child.stdout); + const err = pump(child.stderr); + const logs = (): string => out() + err(); + const stop = async (): Promise => { + child.kill('SIGKILL'); + await child.exited; + await rm(ROOT, { recursive: true, force: true }); + }; + try { + return { started: await waitFor(logs, 'ultimate started'), logs, port, stop }; + } catch (error) { + await stop(); + throw error; + } + } + + const lineWith = (logs: string, message: string): string => + logs.split('\n').find((line) => line.includes(`"msg":"${message}"`)) ?? ''; + + test( + 'nats(connecting): a web role boots and serves with nothing listening where NATS should be', + async () => { + // A port the kernel just gave back: a refused connection, which is what a dead NATS is. + const app = await bootWeb(`nats://127.0.0.1:${freePort()}`); + try { + expect(lineWith(app.started, 'ultimate started')).toContain('"bus":"nats(connecting)"'); + allowHost(`127.0.0.1:${app.port}`); + expect((await fetch(`http://127.0.0.1:${app.port}/readyz`)).status).toBe(200); + expect((await fetch(`http://127.0.0.1:${app.port}/readyz?deep=1`)).status).toBe(503); + expect(app.logs()).not.toContain('"msg":"ultimate bus"'); + } finally { + await app.stop(); + } + }, + BOOT_TIMEOUT_MS, + ); + + test.skipIf(natsUrl === undefined)( + 'nats(up): with a server there, the dial landed before the line and was announced', + async () => { + const app = await bootWeb(natsUrl ?? ''); + try { + expect(lineWith(app.started, 'ultimate started')).toContain('"bus":"nats(up)"'); + const announced = lineWith(app.logs(), 'ultimate bus'); + expect(announced).toContain('"bus":"nats(up)"'); + expect(announced).toContain('"use":"publish"'); + allowHost(`127.0.0.1:${app.port}`); + expect((await fetch(`http://127.0.0.1:${app.port}/readyz?deep=1`)).status).toBe(200); + } finally { + await app.stop(); + } + }, + BOOT_TIMEOUT_MS, + ); +}); diff --git a/packages/realtime/src/nats-transport-background.test.ts b/packages/realtime/src/nats-transport-background.test.ts index fed14a6ba..d64781316 100644 --- a/packages/realtime/src/nats-transport-background.test.ts +++ b/packages/realtime/src/nats-transport-background.test.ts @@ -219,6 +219,28 @@ describe('NatsTransport, the dial loop at its edges', () => { } }); + // Claimed in the changelog and the ops page: an outage is said at once and then ever more + // rarely, not once per dial per pod for as long as it lasts. + test('a dial that keeps failing is reported on attempts 1, 2, 4, 8, … and on no other', async () => { + const bus = harness(); + bus.broker.offline = true; + const transport = bus.transport({ + backoff: { baseMs: 0, maxMs: 0, factor: 1, jitter: 'none' }, + }); + + transport.connectInBackground(); + await waitFor(() => bus.attempts() >= 40); + await transport.close(); + + // Every failed attempt up to the one `close()` cut short: the powers of two among them. + const attempts = bus.attempts(); + const powers = Math.floor(Math.log2(attempts)) + 1; + expect(attempts).toBeGreaterThanOrEqual(40); + expect(bus.reported.length).toBeGreaterThanOrEqual(powers - 1); + expect(bus.reported.length).toBeLessThanOrEqual(powers); + expect(bus.reported.every((error) => codeOf(error) === 'X_TRANSPORT_UNAVAILABLE')).toBe(true); + }); + test('a dial is given a connect timeout below the boot wait, so a black hole is an attempt that ends', async () => { const seen: (number | undefined)[] = []; const broker = new FakeNatsBroker(); @@ -295,7 +317,11 @@ describe('NatsTransport.connect({ withinMs })', () => { expect(codeOf(refused)).toBe('X_TRANSPORT_UNAVAILABLE'); expect(causeOf(refused)).toContain('bus.test:4222'); expect(causeOf(refused)).toContain('within 40ms'); - expect(isUltimateError(refused) ? refused.fix : '').toContain('nats-server'); + // No `fix` was passed, and the refusal still carries one: `TransportUnavailableError` supplies + // its own when the caller names none (`errors.ts`), so no path leaves this code without a fix. + expect(isUltimateError(refused) ? refused.fix : '').toBe( + 'x doctor — then check NATS_URL points at a reachable nats-server', + ); // The boot unwinds by closing the transport; the dial that lands afterwards is not leaked. await transport.close(); diff --git a/packages/realtime/src/replicator-blip.test.ts b/packages/realtime/src/replicator-blip.test.ts index f17414bb0..97ad64793 100644 --- a/packages/realtime/src/replicator-blip.test.ts +++ b/packages/realtime/src/replicator-blip.test.ts @@ -103,6 +103,33 @@ describe('a bus that is away for a moment', () => { expect(bus.published).toEqual([]); }); + // The wait's timer was scheduled and its cancel thrown away, so a `stop()` that landed during a + // retry left the handler parked for up to 1.5 s — and a feed's stop waits for its handler. + test('stop() during a retry wait cancels the timer and ends the wait at once', async () => { + const bus = blipping(1); + const { feed, timers, replicator } = rig(bus); + await replicator.start(); + + let settled = false; + void feed + .deliver(change(7)) + .catch(() => undefined) + .finally(() => { + settled = true; + }); + await turns(); + expect(timers.pending.map((entry) => entry.ms)).toEqual(PUBLISH_RETRY_DELAYS_MS.slice(0, 1)); + + await replicator.stop(); + await turns(); + + // No timer left to fire, the handler is out of its wait, and nothing more was published. + expect(timers.pending).toEqual([]); + expect(settled).toBe(true); + expect(bus.attempts).toBe(1); + expect(bus.published).toEqual([]); + }); + test('a refusal that is not the bus being away is not retried', async () => { const inner = new InProcessTransport(); const bus: Transport = { diff --git a/packages/realtime/src/replicator.ts b/packages/realtime/src/replicator.ts index 33b216be9..df18dc3da 100644 --- a/packages/realtime/src/replicator.ts +++ b/packages/realtime/src/replicator.ts @@ -143,6 +143,8 @@ export function changeFeedReplicator(options: ReplicatorOptions): Replicator { /** The run whose stream and lock still speak for this replicator. */ let current: Run | undefined; let cancelRetry: (() => void) | undefined; + /** Ends the publish retry's wait in flight, if any — see `publishThroughBlip`. */ + let endBlipWait: (() => void) | undefined; /** Stops listening for the lock being lost. Held only while this replicator holds the lock. */ let unwatchLock: (() => void) | undefined; const unwatch = (): void => { @@ -206,7 +208,17 @@ export function changeFeedReplicator(options: ReplicatorOptions): Replicator { const delay = PUBLISH_RETRY_DELAYS_MS[retry]; if (delay === undefined || !busAway(thrown)) throw thrown; await new Promise((resolve) => { - schedule(resolve, delay); + const cancel = schedule(() => { + endBlipWait = undefined; + resolve(); + }, delay); + // Held so `stop()` can end the wait: the timer is cleared AND the wait settles, into the + // fence below. A stop that only waited it out held the feed's handler for up to 1.5 s. + endBlipWait = (): void => { + endBlipWait = undefined; + cancel(); + resolve(); + }; }); if (current !== run || run.over !== null) { throw fencedOut(run.over ?? 'a newer run started'); @@ -426,6 +438,8 @@ export function changeFeedReplicator(options: ReplicatorOptions): Replicator { pumping = false; if (current !== undefined) current.over ??= 'the replicator was stopped'; current = undefined; + // After the run is marked over, so the wait it ends lands in the fence and publishes nothing. + endBlipWait?.(); unwatch(); // Whatever the feed said: a lock kept because the stream would not close politely is a // slot no standby can take. Its refusal is still the one the caller is owed.