From 21196466ed332fdddcec6ab4e22a08131d22e560 Mon Sep 17 00:00:00 2001 From: wtclaude Date: Mon, 10 Aug 2026 20:32:00 -0500 Subject: [PATCH 1/2] feat(modules): boot/shutdown hook dispatch and the installed_modules reconcile Phase 2, PR 5 of docs/website/MODULE_SYSTEM.md 2.7. api.onBoot/api.onShutdown stop throwing, server.js gains one call on each side, and the 2.4 state machine finally runs against real outcomes -- which is what makes 4.5's `disabled` 404 leg reachable for the first time. Dispatch and reconcile live in src/modules/lifecycle.js rather than in the loader, for the reason the schema replay does: routeManifest.js and swagger.js both require app.js against a dead pool, so the loader may not reach the database. The two halves meet at exactly one function, loader.setState(), so the in-memory record the dispatch guard reads and the row the admin panel reads are moved together and cannot disagree. Four decisions, all recorded in MODULE_API.md 2.5 and 4.4: - The loader classifies its failures by 4.3 step, so failure_stage says where a module broke instead of being a column nothing ever filled. The four steps readManifest covers in one pass label themselves; the rest are inferred from how far load() had got, and an unlabelled throw is recorded against the step that was running rather than guessed at. - A row whose directory is gone is marked startup_failed rather than left claiming `enabled` -- the boot reset has just moved it there, and a row claiming to be enabled for a module that is not on the volume is the one state that is simply untrue. An uninstall leaves `disabled`, which the reset never touches, so this catches only a hand-deleted directory. - Core's eight UO boot call sites stay in server.js until Phase 3. Unlike a registered announce leg, a boot call site already has somewhere to live, so moving it now would be extraction done early in a phase whose exit criterion is that nothing changes. - onBoot gets no timeout. Shutdown races a SIGKILL and boot does not, and a slow onBoot delaying the listener is the contract's promise to a module that must warm up before it serves. The operator's switch wins over everything: a disabled module is guarded, not booted, and does not have its failure re-recorded, or an outcome would silently switch it back on next boot. Every database write in the reconcile is individually caught -- a row that will not update is worse reporting, never a failed boot. 900 tests pass (17 new). routes.manifest.json is unchanged at 229 routes and the OpenAPI spec regenerates byte-identical. Co-Authored-By: Claude --- server/src/modules/lifecycle.js | 208 +++++++++++++++ server/src/modules/loader.js | 149 ++++++++--- server/src/modules/schema.js | 2 +- server/src/server.js | 16 ++ server/test/moduleLifecycle.test.js | 376 ++++++++++++++++++++++++++++ server/test/moduleLoader.test.js | 102 ++++++-- 6 files changed, 802 insertions(+), 51 deletions(-) create mode 100644 server/src/modules/lifecycle.js create mode 100644 server/test/moduleLifecycle.test.js diff --git a/server/src/modules/lifecycle.js b/server/src/modules/lifecycle.js new file mode 100644 index 0000000..f6f837a --- /dev/null +++ b/server/src/modules/lifecycle.js @@ -0,0 +1,208 @@ +// ── Module lifecycle dispatch ────────────────────────────────────────────── +// +// Phase 2, PR 5 of docs/website/MODULE_SYSTEM.md §2.7. Normative contract: +// docs/website/MODULE_API.md §2.5 (the hooks and when they run) and §4.4 +// (failure is a state), plus MODULE_SYSTEM.md §2.4 (what a boot does to +// `installed_modules`). +// +// This is the database half of the loader, and it is a separate file for the +// same reason modules/schema.js is: `scripts/routeManifest.js` and +// `swagger/swagger.js` both require app.js with the pool pointed at a dead port, +// so loader.js may not reach the database. Everything here runs from server.js, +// after ensureSchema() has proved the database is up. +// +// The two halves meet at exactly one place — `loader.setState()` — so the +// in-memory record that the §4.5 dispatch guard reads and the row the admin +// panel reads are moved together and cannot disagree. +// +// Two properties this file exists to keep: +// +// 1. **A module's boot failure costs that module and nothing else** (§4.4). +// Its routes stay mounted and answer 503; the site comes up; the next +// module boots as if nothing happened. +// 2. **The row is a record of what happened, never the source of truth for +// what is mounted** (§2.4). Nothing here mounts, unmounts or re-scans. It +// reads the outcome of a scan that already happened and writes it down. + +const log = require('../utils/logger')('modules') + +// §2.5: shutdown races the process being killed, so a module that will not let +// go is logged and skipped rather than allowed to hang the exit. `onBoot` has no +// such budget on purpose — it delays the listener binding, which is the feature. +const SHUTDOWN_BUDGET_MS = 5000 + +/** + * Run one database call for one module without letting it become everyone's + * failure. Returns null on failure, having logged it. + * + * The boot path is the whole reason this exists. A row that will not update is + * bad — the admin panel shows the wrong thing — but it is strictly less bad than + * a site that will not start, and it must not stop the modules after it from + * booting. + */ +async function safe(what, fn) { + try { + return await fn() + } catch (err) { + log.error(`module bookkeeping failed: ${what}`, { error: err.message }) + return null + } +} + +/** + * Reconcile `installed_modules` with what the loader found, then run every + * surviving module's `onBoot`. + * + * Called once from server.js, after `ensureSchema()` (so a module's own tables + * exist) and `seedDefaults()`, and **before the HTTP listener binds** — a module + * that must not serve traffic until it has warmed a cache gets that for free + * (§2.5). + * + * The order of the four steps is the whole design: + * + * 1. `beginBoot()` clears the last boot's outcomes, so what is on display + * afterwards is what THIS boot did. `disabled` rows are left alone: that is + * an operator decision, not an outcome (§2.4). + * 2. Every module on the volume gets a row, written with null provenance if it + * does not have one — a directory placed on the volume by hand is a + * supported install (§2.4/§2.5), and without a row it could never be + * disabled or shown as failed. + * 3. Rows with no directory are marked failed, because step 1 has just reset + * them to `enabled` and a row claiming to be enabled for a module that is + * not there is the one state that is simply untrue. (A plain uninstall + * leaves `disabled`, which step 1 never touches, so this only catches a + * directory deleted by hand.) + * 4. The outcome each module already carries — disabled by the operator, + * failed during load or schema replay, or ready — is written down, and only + * then is `onBoot` dispatched. + * + * Never throws. @param {object} [deps] injection seam for tests. + */ +async function boot({ modules, model } = {}) { + /* eslint-disable global-require */ + const loader = modules || require('./loader') + const rows = model || require('../model/modules/modules.model') + /* eslint-enable global-require */ + + // Not an error, and the same guard replayFragments carries: a process that + // never required app.js has no scan to reconcile against, and writing rows + // from an empty list would mark every installed module as missing. + if (!loader.isLoaded()) { + log.info('no module scan in this process — skipping module boot') + return + } + + const scanned = loader.list() + + await safe('resetting last boot\'s outcomes', () => rows.beginBoot()) + + for (const m of scanned) { + await safe(`recording module "${m.id}"`, () => rows.recordInstalled({ + id: m.id, + name: m.name, + version: m.version, + // Null provenance is what a hand-placed directory looks like. An install + // performed through the admin panel (§2.5, a later phase) writes the row + // with its source and hash first; this refresh deliberately does not + // overwrite either, because recordInstalled leaves what it is not given. + })) + } + + const stored = (await safe('reading module rows', () => rows.list())) || [] + const onVolume = new Set(scanned.map((m) => m.id)) + + for (const row of stored) { + if (onVolume.has(row.id) || row.state === 'disabled') continue + await safe(`marking module "${row.id}" missing`, () => rows.markStartupFailed(row.id, { + stage: 'require', + reason: 'module directory not present on the volume', + })) + } + + const disabled = new Set(stored.filter((r) => r.state === 'disabled').map((r) => r.id)) + + for (const m of scanned) { + // The operator's switch wins over everything, including a failure. Its + // routes 404 from here on (§4.5 — the leg that was unreachable until this + // PR), it is not booted, and its failure is not re-recorded: overwriting a + // deliberate `disabled` with an outcome would silently re-enable it on the + // next boot. + if (disabled.has(m.id)) { + loader.setState(m.id, 'disabled') + continue + } + if (m.state === 'startup_failed') { + // Already failed in load() or the schema replay — both of which ran before + // the database was available to write it down. This is where it lands. + await safe(`recording failure for "${m.id}"`, () => rows.markStartupFailed(m.id, { + stage: m.stage, + reason: m.reason, + })) + } + } + + for (const { id, hook, ctx } of loader.bootable()) { + try { + // Awaited without a timeout, deliberately (§2.5): a slow onBoot delays the + // listener, which is the contract's promise to a module that must warm up + // before it serves. Core's own boot steps are awaited the same way. + if (hook) await hook(ctx) + loader.setState(id, 'started') + await safe(`marking module "${id}" started`, () => rows.markStarted(id)) + log.info(`module "${id}" started`) + } catch (err) { + // §4.4's second column: the routes are already mounted, so they stay + // mounted and answer 503. A module that failed to warm up serving + // half-initialised data is worse than one that says it is down. + loader.setState(id, 'startup_failed', { stage: 'boot', reason: err.message }) + await safe(`recording boot failure for "${id}"`, () => rows.markStartupFailed(id, { + stage: 'boot', + reason: err.message, + })) + log.error(`module "${id}" onBoot failed — its routes will answer 503`, { + reason: err.message, + }) + } + } +} + +/** Reject if `fn`'s promise has not settled within `ms`. */ +function withBudget(fn, ms) { + let timer + const budget = new Promise((_, reject) => { + timer = setTimeout(() => reject(new Error(`onShutdown exceeded its ${ms}ms budget`)), ms) + }) + return Promise.race([Promise.resolve().then(fn), budget]).finally(() => clearTimeout(timer)) +} + +/** + * Run every started module's `onShutdown`, in reverse registration order. + * + * Called from server.js's signal handler before anything core owns is closed, so + * a module still has a working database pool and push dispatcher to flush + * through. Reverse order is the mirror of boot order: a module that booted after + * another may be holding something the earlier one handed it. + * + * Never throws, and never hangs: each hook gets `SHUTDOWN_BUDGET_MS`, after + * which it is logged and abandoned. Abandoned, not cancelled — nothing can stop + * a promise that is still running — but the process is exiting anyway, and the + * alternative is a shard host where `systemctl stop` hangs until SIGKILL. + */ +async function shutdown({ modules, budgetMs = SHUTDOWN_BUDGET_MS } = {}) { + // eslint-disable-next-line global-require + const loader = modules || require('./loader') + if (!loader.isLoaded()) return + + for (const { id, hook } of loader.shutdownHooks()) { + try { + await withBudget(hook, budgetMs) + log.info(`module "${id}" shut down`) + } catch (err) { + log.warn(`module "${id}" onShutdown failed or timed out — continuing`, { + error: err.message, + }) + } + } +} + +module.exports = { boot, shutdown, SHUTDOWN_BUDGET_MS } diff --git a/server/src/modules/loader.js b/server/src/modules/loader.js index d223959..bbc3aa1 100644 --- a/server/src/modules/loader.js +++ b/server/src/modules/loader.js @@ -18,15 +18,19 @@ // boot (§4.4). // // What is deliberately NOT here yet, each landing with the PR that first calls -// it (§2.7): the three de-entanglement registries (PR 4), boot/shutdown hook -// dispatch and the `installed_modules` reconcile (PR 5), GET -// /api/v1/public/modules and the client chunk's static mount (PRs 6-7). Until -// PR 5 the state a module carries is in memory only. +// it (§2.7): GET /api/v1/public/modules and the client chunk's static mount +// (PRs 6-7). // // PR 3 added the fragment half of the schema story: this file VALIDATES a // fragment (statement by statement, at load time, before anything is mounted) // and publishes it through `fragments()`. Replaying it needs a database, so it // belongs to modules/schema.js, which utils/db.js calls after core's schema. +// +// PR 5 added the lifecycle hooks a module registers here (`onBoot`/`onShutdown`) +// and the failure STAGE carried beside every reason. Dispatching those hooks and +// reconciling `installed_modules` need a database, so they live in +// modules/lifecycle.js for the same reason schema.js is a separate file: this one +// stays require-able against a dead pool. const fs = require('fs') const path = require('path') @@ -145,11 +149,10 @@ function buildApi(record) { if (record.called.has(name)) throw new Error(`${name}() called twice`) record.called.add(name) } - // PR 5 brings the boot hooks. They throw rather than no-op: an accepting stub - // would let a module believe it had registered something and fail silently at - // the far end. - const notYet = (name, pr) => () => { - throw new Error(`${name}: not available until phase 2 PR ${pr}`) + const hook = (name) => (fn) => { + once(name) + if (typeof fn !== 'function') throw new Error(`${name}: expected a function`) + record.hooks[name] = fn } return { registerRoutes(mounts) { @@ -180,13 +183,34 @@ function buildApi(record) { record.staged.registerNotificationStreams(streams) }, registerAnnounceLeg: record.staged.registerAnnounceLeg, - onBoot: notYet('onBoot', 5), - onShutdown: notYet('onShutdown', 5), + // The two lifecycle hooks (§2.5). Registered here, dispatched from + // lifecycle.js — this file runs with no database and the hooks run with one. + // Both are optional: a module with no warm-up and nothing to close simply + // never calls them. + onBoot: hook('onBoot'), + onShutdown: hook('onShutdown'), } } // ── Validation ───────────────────────────────────────────────────────────── +/** + * Throw with the §4.3 step that failed attached. + * + * `installed_modules.failure_stage` exists so the admin panel can say *where* a + * module broke and not only what the message was, and the model enumerates the + * eight stages (`FAILURE_STAGES`). The steps that share one function — a + * manifest read that also checks `coreApi`, the mounts and the slots — cannot be + * told apart by position in load(), so they carry their own label; everything + * else is inferred from how far load() had got. An untagged error is recorded + * against the step that was running, never guessed at. + */ +function fail(stage, message) { + const err = new Error(message) + err.stage = stage + throw err +} + // Table names a module may create despite not carrying its own id as a prefix. // // module-uo's twenty-seven tables predate the module system by two years, and @@ -305,42 +329,42 @@ function readManifest(dir, id, tierRouters) { for (const key of Object.keys(manifest)) { // Rejected, not ignored: a typo'd key must be a loud failure rather than a // silently inert setting the operator believes they configured. - if (!MANIFEST_KEYS.has(key)) throw new Error(`unknown key "${key}" in module.json`) + if (!MANIFEST_KEYS.has(key)) fail('manifest', `unknown key "${key}" in module.json`) } - if (!ID.test(manifest.id || '')) throw new Error(`invalid id "${manifest.id}"`) - if (manifest.id !== id) throw new Error(`id "${manifest.id}" does not match directory "${id}"`) - if (!manifest.version) throw new Error('missing version') - if (!manifest.coreApi) throw new Error('missing coreApi') + if (!ID.test(manifest.id || '')) fail('manifest', `invalid id "${manifest.id}"`) + if (manifest.id !== id) fail('manifest', `id "${manifest.id}" does not match directory "${id}"`) + if (!manifest.version) fail('manifest', 'missing version') + if (!manifest.coreApi) fail('core_api', 'missing coreApi') if (!semver.satisfies(MODULE_API_VERSION, manifest.coreApi)) { - throw new Error(`needs core API ${manifest.coreApi}, this core is ${MODULE_API_VERSION}`) + fail('core_api', `needs core API ${manifest.coreApi}, this core is ${MODULE_API_VERSION}`) } for (const [tier, prefixes] of Object.entries(manifest.mounts || {})) { - if (!TIERS.includes(tier)) throw new Error(`unknown tier "${tier}" in mounts`) + if (!TIERS.includes(tier)) fail('mounts', `unknown tier "${tier}" in mounts`) for (const prefix of prefixes) { - if (!PREFIX.test(prefix)) throw new Error(`bad prefix "${prefix}" in mounts.${tier}`) + if (!PREFIX.test(prefix)) fail('mounts', `bad prefix "${prefix}" in mounts.${tier}`) if (ownedByCore(tierRouters[tier], prefix)) { - throw new Error(`prefix ${tier}${prefix} is owned by core`) + fail('mounts', `prefix ${tier}${prefix} is owned by core`) } for (const other of modules.values()) { if ((other.manifest.mounts?.[tier] || []).includes(prefix)) { - throw new Error(`prefix ${tier}${prefix} already registered by module "${other.id}"`) + fail('mounts', `prefix ${tier}${prefix} already registered by module "${other.id}"`) } } } } for (const slot of manifest.extensions || []) { - if (!registries.hasSlot(slot)) throw new Error(`unknown extension slot "${slot}"`) + if (!registries.hasSlot(slot)) fail('extensions', `unknown extension slot "${slot}"`) } if (manifest.schema && !manifest.purge) { // A module that can create tables and cannot drop them leaves an operator // with orphaned data and no supported way to remove it. - throw new Error('declares schema but no purge') + fail('schema', 'declares schema but no purge') } if (manifest.purge && !fs.existsSync(path.join(dir, manifest.purge))) { - throw new Error(`purge file "${manifest.purge}" is missing`) + fail('schema', `purge file "${manifest.purge}" is missing`) } return manifest } @@ -409,20 +433,34 @@ function load(tierRouters) { staged: registries.stage(id), tables: new Set(), called: new Set(), + hooks: { onBoot: null, onShutdown: null }, + ctx: null, state: 'installed', + stage: null, reason: null, } + // How far load() has got, so an untagged throw is recorded against the step + // that was actually running (§4.3's steps 5-7). The steps before it label + // themselves, because readManifest covers four of them in one pass. + let stage = 'manifest' try { record.manifest = readManifest(dir, id, tierRouters) + stage = 'schema' record.tables = tablesOf(dir, record.manifest) checkTableNames(id, record.tables) if (record.manifest.server) { const entry = path.join(dir, record.manifest.server) + stage = 'require' // eslint-disable-next-line global-require, import/no-dynamic-require const register = require(entry) if (typeof register !== 'function') throw new Error(`${record.manifest.server} does not export a function`) - register(buildCtx(id, dir), buildApi(record)) + stage = 'register' + // Kept on the record, not discarded after register(): §2.5 hands the + // same ctx to onBoot, and building a second one would be a second frozen + // object claiming to be the same handle. + record.ctx = buildCtx(id, dir) + register(record.ctx, buildApi(record)) checkDeclared(record) } record.state = 'registered' @@ -434,10 +472,14 @@ function load(tierRouters) { // A failure here is BEFORE any route was mounted, so this module's routes // and nav are simply absent and the site comes up without it (§4.4). record.state = 'startup_failed' + record.stage = err.stage || stage record.reason = err.message record.manifest = record.manifest || { id, version: 'unknown' } modules.set(id, record) - log.error(`module "${id}" failed to load — continuing without it`, { reason: err.message }) + log.error(`module "${id}" failed to load — continuing without it`, { + stage: record.stage, + reason: err.message, + }) } } @@ -455,6 +497,7 @@ function load(tierRouters) { registries.apply(record.staged.staged) } catch (err) { record.state = 'startup_failed' + record.stage = 'register' record.reason = err.message log.error(`module "${record.id}" failed to register — continuing without it`, { reason: err.message, @@ -502,20 +545,25 @@ const RECORD_STATES = new Set(['registered', 'started', 'disabled', 'startup_fai * Move a loaded module to a new state — the POST-mount transitions. * * Called by whoever ran the step that failed or the step that succeeded, because - * only they can know: PR 3's `ensureSchema()` replays the fragments, PR 5's boot - * dispatch runs `onBoot` and reconciles `installed_modules` (whose `disabled` - * rows are what first make the guard's 404 leg reachable). + * only they can know: `ensureSchema()` replays the fragments (PR 3), and + * lifecycle.js runs `onBoot` and reconciles `installed_modules` (whose `disabled` + * rows are what make the guard's 404 leg reachable). + * + * The stage travels with the reason and is cleared by every non-failing move, + * for the same reason the database columns are (§2.4): a running module must + * never be able to show a stale failure. * * Unknown ids are ignored rather than thrown on: a module can be absent from the * volume and still have a row, and a caller on the boot path must not turn that * into everyone's failure. */ -function setState(id, state, reason = null) { +function setState(id, state, { stage = null, reason = null } = {}) { if (!RECORD_STATES.has(state)) throw new Error(`unknown module state "${state}"`) const record = modules.get(id) if (!record) return record.state = state - record.reason = reason + record.stage = state === 'startup_failed' ? stage : null + record.reason = state === 'startup_failed' ? reason : null } // ── Introspection ────────────────────────────────────────────────────────── @@ -550,11 +598,48 @@ function list() { name: r.manifest.name || r.id, version: r.manifest.version, state: r.state, + stage: r.stage, reason: r.reason, capabilities: r.manifest.capabilities || [], })) } +/** + * The modules that are ready to be booted, with their hook, in scan order. + * + * `registered` only — the state a module holds between a clean load and its + * `onBoot`. One that failed validation or schema replay is not going to run, and + * one already `started` has run. A module with no `onBoot` is still listed: it + * has nothing to warm up, but it still has to reach `started` so the admin panel + * and `installed_modules` agree with the guard about what is serving. + * + * @returns {{id: string, hook: Function|null, ctx: object|null}[]} + */ +function bootable() { + assertLoaded('bootable') + return [...modules.values()] + .filter((r) => r.state === 'registered') + .map((r) => ({ id: r.id, hook: r.hooks.onBoot, ctx: r.ctx })) +} + +/** + * The shutdown hooks to run, in REVERSE registration order (§2.5). + * + * `started` only. A module whose `onBoot` threw is mid-way through a warm-up it + * never finished, and calling its `onShutdown` would hand it a half-built world + * to tear down — the one thing worse than not closing cleanly. Reverse order is + * the same reasoning applied between modules rather than within one. + * + * @returns {{id: string, hook: Function}[]} + */ +function shutdownHooks() { + assertLoaded('shutdownHooks') + return [...modules.values()] + .filter((r) => r.state === 'started' && r.hooks.onShutdown) + .map((r) => ({ id: r.id, hook: r.hooks.onShutdown })) + .reverse() +} + /** * Every schema fragment waiting to be replayed, in scan order. * @@ -575,4 +660,4 @@ function fragments() { /** Absolute path of the modules directory. */ const dir = () => MODULES_DIR -module.exports = { load, list, setState, fragments, isLoaded, dir } +module.exports = { load, list, setState, fragments, bootable, shutdownHooks, isLoaded, dir } diff --git a/server/src/modules/schema.js b/server/src/modules/schema.js index 13b59d0..b1df79c 100644 --- a/server/src/modules/schema.js +++ b/server/src/modules/schema.js @@ -73,7 +73,7 @@ async function replayFragments({ query, modules } = {}) { } log.info(`schema ensured for module "${id}"`, { statements: statements.length }) } catch (err) { - loader.setState(id, 'startup_failed', err.message) + loader.setState(id, 'startup_failed', { stage: 'schema', reason: err.message }) log.error(`module "${id}" schema fragment failed — its routes will answer 503`, { reason: err.message, }) diff --git a/server/src/server.js b/server/src/server.js index e6e7afa..8055468 100644 --- a/server/src/server.js +++ b/server/src/server.js @@ -17,6 +17,7 @@ const mobileAuthBridge = require('./model/mobileAuthBridge/mobileAuthBridge.mode const shardAtlas = require('./model/shardAtlas/shardAtlas.model') const shardClilocs = require('./model/shardClilocs/shardClilocs.model') const shardMarket = require('./model/shardMarket/shardMarket.model') +const moduleLifecycle = require('./modules/lifecycle') const createLogger = require('./utils/logger') const { evaluateBotInternalKey } = require('./utils/botInternalKey') const brand = require('./config/brand') @@ -109,6 +110,15 @@ async function start() { const mode = await settings.get('site_mode') log.info(`site mode: ${String(mode || 'live').toUpperCase()}`) + // Reconcile installed_modules with what the loader found on the volume at + // require time, then run each module's onBoot (MODULE_API.md §2.5). Placed + // after core's own boot work and BEFORE the listener binds, for both reasons + // the contract gives: a module's warm-up may depend on core being up, and a + // module that must not serve traffic until it has warmed a cache gets that + // guarantee only if nothing is listening yet. Never throws — a module that + // fails here keeps its URLs and answers 503. + await moduleLifecycle.boot() + const server = http.createServer(app) server.listen(PORT, HOST, () => { log.info(`listening on http://${HOST}:${PORT} (API at /api/v1, health at /api/health)`) @@ -174,6 +184,12 @@ function setupShutdown(server, internalServer) { if (closing) return closing = true log.warn(`${signal} received — shutting down gracefully`) + // Modules first, while everything they were handed still works: the database + // pool, the push dispatcher and the SSE fan-out are all still open here, and + // a module's onShutdown is the only chance it gets to flush through them + // (MODULE_API.md §2.5). Each hook is budgeted, so one that will not let go + // costs five seconds rather than the whole shutdown. + await moduleLifecycle.shutdown() botScore.stopSweeper() // stop the bot-store cleanup interval announceWorker.stop() // stop the news-announcement dispatcher poller uoLinkSocket.stop() // close the uo-link WS ingest client diff --git a/server/test/moduleLifecycle.test.js b/server/test/moduleLifecycle.test.js new file mode 100644 index 0000000..b741548 --- /dev/null +++ b/server/test/moduleLifecycle.test.js @@ -0,0 +1,376 @@ +// ── Boot and shutdown dispatch ───────────────────────────────────────────── +// +// Phase 2, PR 5. The contract is MODULE_API.md §2.5 (when the hooks run, in what +// order, with what budget), §4.4 (a failure after mounting is a 503, not a +// crash), §4.5 (a disabled module is guarded, never unmounted) and +// MODULE_SYSTEM.md §2.4 (what a boot does to installed_modules). +// +// The property under test throughout, as in moduleLoader.test.js and +// moduleSchema.test.js: **the failing module fails alone.** A hook that throws, +// a hook that hangs, a row that will not write — none of them may cost the site +// its boot or the next module its start. +// +// No database is involved: `boot()` takes the model as an injectable dependency +// for exactly the reason `replayFragments` takes its query, and the fake below +// records every call so the ORDER of the reconcile can be asserted — which is +// the whole design, not an implementation detail. +process.env.DB_HOST = '127.0.0.1' +process.env.DB_PORT = '59999' + +const fs = require('fs') +const os = require('os') +const path = require('path') + +const { test, beforeEach, after } = require('node:test') +const assert = require('node:assert/strict') + +const express = require('express') + +const db = require('../src/utils/db') +const registries = require('../src/modules/registries') +const lifecycle = require('../src/modules/lifecycle') +const { startApp } = require('./_helper') + +after(() => db.close()) + +let tmpRoot + +const emptyTiers = () => ({ + public: express.Router(), + admin: express.Router(), + player: express.Router(), +}) + +function freshLoader(dir, tiers = emptyTiers()) { + process.env.MODULES_DIR = dir + registries._reset() + delete require.cache[require.resolve('../src/modules/loader')] + // eslint-disable-next-line global-require + const loader = require('../src/modules/loader') + loader.load(tiers) + return loader +} + +/** + * A module whose hooks report themselves into a file. + * + * A file rather than a shared array because the module is `require`d from disk + * and cannot close over anything this file owns — the same trick the ctx probe + * in moduleLoader.test.js uses. + */ +function writeModule(id, { boot, shutdown, mounts, log: logFile } = {}) { + const dir = path.join(tmpRoot, id) + fs.mkdirSync(dir, { recursive: true }) + fs.writeFileSync(path.join(dir, 'module.json'), JSON.stringify({ + id, + name: `Module ${id}`, + version: '1.2.3', + coreApi: '^1.0.0', + server: 'index.js', + ...(mounts === undefined ? {} : { mounts }), + })) + const note = logFile + ? `const note = (what) => require('fs').appendFileSync(${JSON.stringify(logFile)}, what + '\\n')` + : 'const note = () => {}' + const register = mounts === undefined ? '' : ` + const r = ctx.express.Router() + r.get('/', (req, res) => res.json({ ok: true })) + api.registerRoutes({ public: { '${(mounts.public || [])[0]}': r } })` + // `boot: ''` means "registers a hook that does nothing", which is a different + // module from one that registers no hook at all — hence the undefined check + // rather than a truthiness test. + fs.writeFileSync(path.join(dir, 'index.js'), `${note} + module.exports = (ctx, api) => {${register} + ${boot === undefined ? '' : `api.onBoot(async (c) => { note('boot:${id}' + (c && c.moduleId === '${id}' ? ':ctx' : ':NOCTX')); ${boot} })`} + ${shutdown === undefined ? '' : `api.onShutdown(async () => { note('shutdown:${id}'); ${shutdown} })`} + }`) + return dir +} + +/** An in-memory stand-in for model/modules/modules.model.js. */ +function fakeModel(seed = []) { + const rows = new Map(seed.map((r) => [r.id, { failureStage: null, failureReason: null, ...r }])) + const calls = [] + const model = { + rows, + calls, + async beginBoot() { + calls.push('beginBoot') + for (const row of rows.values()) { + if (row.state === 'disabled') continue + Object.assign(row, { state: 'enabled', failureStage: null, failureReason: null }) + } + }, + async recordInstalled({ id, name, version }) { + calls.push(`recordInstalled:${id}`) + const row = rows.get(id) + // Metadata is refreshed; state is deliberately left alone (§2.4). + if (row) Object.assign(row, { name, version }) + else rows.set(id, { id, name, version, state: 'installed', failureStage: null, failureReason: null }) + }, + async list() { + calls.push('list') + return [...rows.values()] + }, + async markStarted(id) { + calls.push(`markStarted:${id}`) + Object.assign(rows.get(id), { state: 'started', failureStage: null, failureReason: null }) + }, + async markStartupFailed(id, { stage, reason }) { + calls.push(`markStartupFailed:${id}`) + const row = rows.get(id) + // The model's own softening, reproduced because tests below depend on it: + // a disabled row is a no-op, or an outcome would overwrite the operator's + // decision and silently re-enable the module next boot. + if (!row || row.state === 'disabled') return + Object.assign(row, { state: 'startup_failed', failureStage: stage, failureReason: reason }) + }, + } + return model +} + +const stateOf = (loader, id) => loader.list().find((m) => m.id === id) +const noted = (file) => (fs.existsSync(file) ? fs.readFileSync(file, 'utf8').trim().split('\n') : []) + +beforeEach(() => { + tmpRoot = fs.mkdtempSync(path.join(os.tmpdir(), 'rg-lifecycle-')) +}) + +// ── The happy path ───────────────────────────────────────────────────────── + +test('every module is recorded, booted with its ctx and marked started, in scan order', async () => { + const file = path.join(tmpRoot, 'log.txt') + writeModule('aaa', { boot: '', log: file }) + writeModule('bbb', { boot: '', log: file }) + const loader = freshLoader(tmpRoot) + const model = fakeModel() + + await lifecycle.boot({ modules: loader, model }) + + // The reconcile order IS the design (§2.4): clear the last boot's outcomes + // first, so what is on display afterwards is what this boot did. + assert.equal(model.calls[0], 'beginBoot') + assert.deepEqual(model.calls.slice(1, 3), ['recordInstalled:aaa', 'recordInstalled:bbb']) + assert.deepEqual(noted(file), ['boot:aaa:ctx', 'boot:bbb:ctx']) + assert.equal(stateOf(loader, 'aaa').state, 'started') + assert.equal(model.rows.get('bbb').state, 'started') + // §2.4's metadata refresh: the row carries what the admin screen shows. + assert.equal(model.rows.get('aaa').name, 'Module aaa') + assert.equal(model.rows.get('aaa').version, '1.2.3') +}) + +test('a hand-placed directory gets a row with no provenance', async () => { + // §2.5 keeps a directory dropped on the volume by hand a supported install. + // Without a row it could never be disabled, and nothing could report it. + writeModule('byhand', { boot: '' }) + const model = fakeModel() + + await lifecycle.boot({ modules: freshLoader(tmpRoot), model }) + + const row = model.rows.get('byhand') + assert.equal(row.state, 'started') + assert.equal(row.source ?? null, null) + assert.equal(row.sha256 ?? null, null) +}) + +test('a module with no onBoot still reaches started', async () => { + writeModule('quiet', {}) + const loader = freshLoader(tmpRoot) + const model = fakeModel() + + await lifecycle.boot({ modules: loader, model }) + + // Nothing to warm up is not the same as never having started: the guard lets + // its routes through, so the row has to agree that it is serving. + assert.equal(stateOf(loader, 'quiet').state, 'started') + assert.equal(model.rows.get('quiet').state, 'started') +}) + +// ── Failure is a state ───────────────────────────────────────────────────── + +test('an onBoot that throws fails its own module and no one else', async () => { + const file = path.join(tmpRoot, 'log.txt') + writeModule('aaa', { boot: '', log: file }) + writeModule('bbb', { boot: 'throw new Error("cache warm-up failed")', log: file }) + writeModule('ccc', { boot: '', log: file }) + const loader = freshLoader(tmpRoot) + const model = fakeModel() + + await lifecycle.boot({ modules: loader, model }) + + assert.equal(stateOf(loader, 'bbb').state, 'startup_failed') + assert.equal(stateOf(loader, 'bbb').stage, 'boot') + assert.match(stateOf(loader, 'bbb').reason, /cache warm-up failed/) + assert.equal(model.rows.get('bbb').failureStage, 'boot') + // The one that matters: the module AFTER the failure still booted. + assert.deepEqual(noted(file), ['boot:aaa:ctx', 'boot:bbb:ctx', 'boot:ccc:ctx']) + assert.equal(stateOf(loader, 'ccc').state, 'started') +}) + +test('a module whose onBoot failed keeps its URLs and answers 503', async () => { + // §4.4's right-hand column, reached by the real mechanism rather than a + // hand-moved state: routes.manifest.json must not depend on whether a boot + // hook happened to succeed on the machine that generated it. + writeModule('svc', { boot: 'throw new Error("no")', mounts: { public: ['/widgets'] } }) + const tiers = emptyTiers() + const loader = freshLoader(tmpRoot, tiers) + const app = await startApp((a) => a.use('/public', tiers.public)) + + try { + assert.equal((await fetch(`${app.url}/public/widgets`)).status, 200) + await lifecycle.boot({ modules: loader, model: fakeModel() }) + assert.equal((await fetch(`${app.url}/public/widgets`)).status, 503) + } finally { + await app.close() + } +}) + +test('a failure from load or schema replay is written down with its stage', async () => { + // Both happen before the database is reachable — load() at require time, the + // replay inside ensureSchema — so the boot reconcile is where they land. + writeModule('bad', {}) + fs.writeFileSync(path.join(tmpRoot, 'bad', 'module.json'), JSON.stringify({ + id: 'bad', name: 'bad', version: '1.0.0', coreApi: '^99.0.0', + })) + const loader = freshLoader(tmpRoot) + const model = fakeModel() + + await lifecycle.boot({ modules: loader, model }) + + const row = model.rows.get('bad') + assert.equal(row.state, 'startup_failed') + assert.equal(row.failureStage, 'core_api') + assert.match(row.failureReason, /needs core API \^99\.0\.0/) +}) + +// ── The operator's switch ────────────────────────────────────────────────── + +test('a disabled row guards the module, skips its hook and is not overwritten', async () => { + const file = path.join(tmpRoot, 'log.txt') + writeModule('off', { boot: '', shutdown: '', mounts: { public: ['/widgets'] }, log: file }) + const tiers = emptyTiers() + const loader = freshLoader(tmpRoot, tiers) + const model = fakeModel([{ id: 'off', name: 'Module off', version: '1.2.3', state: 'disabled' }]) + const app = await startApp((a) => a.use('/public', tiers.public)) + + try { + await lifecycle.boot({ modules: loader, model }) + + // §4.5's 404 leg, unreachable until this reconcile existed: mounted and + // guarded, never unmounted, so the URL surface stays a property of the + // volume rather than of a database row. + assert.equal((await fetch(`${app.url}/public/widgets`)).status, 404) + assert.equal(stateOf(loader, 'off').state, 'disabled') + assert.deepEqual(noted(file), [], 'a disabled module must not be booted') + // Still disabled: an outcome must never overwrite a decision, or the next + // boot would silently switch it back on. + assert.equal(model.rows.get('off').state, 'disabled') + // And nothing to tear down, because it never started. + await lifecycle.shutdown({ modules: loader }) + assert.deepEqual(noted(file), []) + } finally { + await app.close() + } +}) + +test('a row whose directory is gone is marked failed rather than left claiming enabled', async () => { + writeModule('here', { boot: '' }) + const model = fakeModel([ + { id: 'here', name: 'Module here', version: '1.2.3', state: 'started' }, + { id: 'gone', name: 'Module gone', version: '0.9.0', state: 'started' }, + // An uninstall leaves `disabled`, which beginBoot never touches — so this + // one is not an anomaly and must be left exactly as the operator left it. + { id: 'uninstalled', name: 'Module uninstalled', version: '0.1.0', state: 'disabled' }, + ]) + + await lifecycle.boot({ modules: freshLoader(tmpRoot), model }) + + assert.equal(model.rows.get('here').state, 'started') + assert.equal(model.rows.get('gone').state, 'startup_failed') + assert.match(model.rows.get('gone').failureReason, /not present on the volume/) + assert.equal(model.rows.get('uninstalled').state, 'disabled') +}) + +// ── The site comes up regardless ─────────────────────────────────────────── + +test('a database that will not take the bookkeeping still boots the modules', async () => { + // A row that will not update is bad — the admin panel shows the wrong thing — + // but it is strictly less bad than a site that will not start. + const file = path.join(tmpRoot, 'log.txt') + writeModule('aaa', { boot: '', log: file }) + const loader = freshLoader(tmpRoot) + const model = fakeModel() + for (const name of ['beginBoot', 'recordInstalled', 'list', 'markStarted']) { + model[name] = async () => { throw new Error('ER_LOCK_WAIT_TIMEOUT') } + } + + await assert.doesNotReject(() => lifecycle.boot({ modules: loader, model })) + + assert.deepEqual(noted(file), ['boot:aaa:ctx']) + assert.equal(stateOf(loader, 'aaa').state, 'started') +}) + +test('a process that never scanned writes nothing at all', async () => { + // `npm run seed` is exactly this: it calls ensureSchema() without ever + // requiring app.js. Reconciling against an empty scan would mark every + // installed module as missing from the volume. + process.env.MODULES_DIR = tmpRoot + delete require.cache[require.resolve('../src/modules/loader')] + // eslint-disable-next-line global-require + const unscanned = require('../src/modules/loader') + const model = fakeModel([{ id: 'real', name: 'Module real', version: '1.0.0', state: 'started' }]) + + await lifecycle.boot({ modules: unscanned, model }) + + assert.deepEqual(model.calls, []) + assert.equal(model.rows.get('real').state, 'started') +}) + +// ── Shutdown ─────────────────────────────────────────────────────────────── + +test('shutdown runs started modules in reverse order and skips the rest', async () => { + const file = path.join(tmpRoot, 'log.txt') + writeModule('aaa', { boot: '', shutdown: '', log: file }) + writeModule('bbb', { boot: 'throw new Error("no")', shutdown: '', log: file }) + writeModule('ccc', { boot: '', shutdown: '', log: file }) + const loader = freshLoader(tmpRoot) + + await lifecycle.boot({ modules: loader, model: fakeModel() }) + fs.writeFileSync(file, '') // only the shutdown half is under test + await lifecycle.shutdown({ modules: loader }) + + // Reverse of boot order, and `bbb` absent: its onBoot threw, so it has a + // half-built world that its onShutdown was never written to tear down. + assert.deepEqual(noted(file), ['shutdown:ccc', 'shutdown:aaa']) +}) + +test('a hook that hangs costs its budget, not the shutdown', async () => { + const file = path.join(tmpRoot, 'log.txt') + writeModule('aaa', { boot: '', shutdown: '', log: file }) + writeModule('zzz', { boot: '', shutdown: 'await new Promise(() => {})', log: file }) + const loader = freshLoader(tmpRoot) + + await lifecycle.boot({ modules: loader, model: fakeModel() }) + fs.writeFileSync(file, '') + + const started = Date.now() + await lifecycle.shutdown({ modules: loader, budgetMs: 50 }) + + // zzz never returns; it is abandoned and aaa still gets its turn. The + // alternative is a host where `systemctl stop` hangs until SIGKILL. + assert.deepEqual(noted(file), ['shutdown:zzz', 'shutdown:aaa']) + assert.ok(Date.now() - started < 2000, 'shutdown must not wait on a hung hook') +}) + +test('a hook that throws does not stop the ones behind it', async () => { + const file = path.join(tmpRoot, 'log.txt') + writeModule('aaa', { boot: '', shutdown: '', log: file }) + writeModule('zzz', { boot: '', shutdown: 'throw new Error("close failed")', log: file }) + const loader = freshLoader(tmpRoot) + + await lifecycle.boot({ modules: loader, model: fakeModel() }) + fs.writeFileSync(file, '') + + await assert.doesNotReject(() => lifecycle.shutdown({ modules: loader })) + assert.deepEqual(noted(file), ['shutdown:zzz', 'shutdown:aaa']) +}) diff --git a/server/test/moduleLoader.test.js b/server/test/moduleLoader.test.js index dd5b09f..70e234f 100644 --- a/server/test/moduleLoader.test.js +++ b/server/test/moduleLoader.test.js @@ -437,9 +437,10 @@ test('a registered module answers on its prefix; a failed one is simply absent', test('a module that fails AFTER mounting keeps its URLs and answers 503', async () => { // The right-hand column of §4.4, and the reason routes.manifest.json can be // generated off a dead database: the URL surface must not depend on whether a - // boot step succeeded on the generating machine. PR 3 (schema replay) and PR 5 - // (onBoot) are the two things that will trip this in real life; here the state - // is moved by hand, because the loader is the thing under test. + // boot step succeeded on the generating machine. The schema replay and onBoot + // are the two things that trip this in real life (moduleSchema.test.js and + // moduleLifecycle.test.js cover both); here the state is moved by hand, + // because the loader is the thing under test. writeModule('later', oneRoute('/widgets')) const tiers = emptyTiers() @@ -451,18 +452,23 @@ test('a module that fails AFTER mounting keeps its URLs and answers 503', async assert.equal(stateOf(loader, 'later').state, 'registered') - loader.setState('later', 'startup_failed', 'schema fragment blew up') + loader.setState('later', 'startup_failed', { stage: 'schema', reason: 'schema fragment blew up' }) assert.equal((await fetch(`${app.url}/public/widgets`)).status, 503) assert.equal(stateOf(loader, 'later').reason, 'schema fragment blew up') + assert.equal(stateOf(loader, 'later').stage, 'schema') - // The 404 leg becomes reachable for real in PR 5, when the boot reconcile - // reads a `disabled` row out of installed_modules. A disabled module is - // mounted and guarded, never unmounted (§4.5) — same reason as the 503. + // The 404 leg is reached for real by the boot reconcile, when it finds a + // `disabled` row in installed_modules. A disabled module is mounted and + // guarded, never unmounted (§4.5) — same reason as the 503. loader.setState('later', 'disabled') assert.equal((await fetch(`${app.url}/public/widgets`)).status, 404) loader.setState('later', 'started') assert.equal((await fetch(`${app.url}/public/widgets`)).status, 200) + // Every non-failing move clears the failure, so a running module can never + // show the reason it failed two boots ago (§2.4). + assert.equal(stateOf(loader, 'later').reason, null) + assert.equal(stateOf(loader, 'later').stage, null) } finally { await app.close() } @@ -506,19 +512,79 @@ test('ctx exposes exactly the documented surface, and is frozen', () => { assert.equal(probe.mutable, false, 'ctx members must be frozen') }) -test('the register calls PR 5 owns throw rather than silently accepting', () => { - // An accepting no-op would let a module believe it had registered a boot hook - // and fail silently at the far end. - for (const [call, pr] of [ - ['onBoot', 5], - ['onShutdown', 5], +// ── Lifecycle hooks ──────────────────────────────────────────────────────── + +test('a lifecycle hook must be a function, and may be registered once', () => { + // Both are register-time failures, so they cost the module its mount entirely + // rather than surfacing at boot — the far end of a hook that was never really + // registered is a module that silently never warms up. + for (const [body, expected] of [ + ['api.onBoot("later")', /onBoot: expected a function/], + ['api.onShutdown("later")', /onShutdown: expected a function/], + ['api.onBoot(() => {}); api.onBoot(() => {})', /onBoot\(\) called twice/], ]) { tmpRoot = fs.mkdtempSync(path.join(os.tmpdir(), 'rg-modules-')) - writeModule('early', { server: `module.exports = (ctx, api) => api.${call}(() => {})` }) - assert.match( - stateOf(freshLoader(tmpRoot), 'early').reason, - new RegExp(`${call}: not available until phase 2 PR ${pr}`), - ) + writeModule('hooked', { server: `module.exports = (ctx, api) => { ${body} }` }) + const state = stateOf(freshLoader(tmpRoot), 'hooked') + assert.match(state.reason, expected) + assert.equal(state.stage, 'register') + } +}) + +test('a module with no hooks is bootable, and offers nothing to shut down', () => { + writeModule('quiet', oneRoute('/widgets')) + const loader = freshLoader(tmpRoot) + + // Listed with a null hook rather than filtered out: it still has to reach + // `started`, or the admin panel and the dispatch guard would disagree about + // whether it is serving. + assert.deepEqual(loader.bootable().map((b) => b.id), ['quiet']) + assert.equal(loader.bootable()[0].hook, null) + assert.deepEqual(loader.shutdownHooks(), []) +}) + +test('shutdown hooks come back in reverse order, and only for started modules', () => { + const hook = 'module.exports = (ctx, api) => api.onShutdown(async () => {})' + writeModule('aaa', { server: hook }) + writeModule('bbb', { server: hook }) + writeModule('ccc', { server: hook }) + const loader = freshLoader(tmpRoot) + + // Nothing has started yet, so there is nothing to tear down. + assert.deepEqual(loader.shutdownHooks(), []) + + loader.setState('aaa', 'started') + loader.setState('bbb', 'startup_failed', { stage: 'boot', reason: 'never warmed up' }) + loader.setState('ccc', 'started') + + // Reverse registration order (§2.5), and `bbb` is absent: a module whose + // onBoot threw is mid-way through a warm-up it never finished, and handing it + // a half-built world to tear down is worse than not closing cleanly. + assert.deepEqual(loader.shutdownHooks().map((h) => h.id), ['ccc', 'aaa']) +}) + +// ── Failure stages ───────────────────────────────────────────────────────── + +test('a failure is recorded against the §4.3 step that produced it', () => { + // installed_modules.failure_stage exists so the admin panel can say WHERE a + // module broke. The four steps readManifest covers in one pass have to label + // themselves; the rest are inferred from how far load() had got. + const cases = [ + ['a-manifest', { manifest: { nonsense: true } }, 'manifest'], + ['b-coreapi', { manifest: { coreApi: '^99.0.0' } }, 'core_api'], + ['c-mounts', { manifest: { mounts: { public: ['/bad prefix'] } } }, 'mounts'], + ['d-slots', { manifest: { extensions: ['no.such.slot'] } }, 'extensions'], + ['e-schema', { schema: 'DELETE FROM x;' }, 'schema'], + ['f-require', { server: 'throw new Error("boom")' }, 'require'], + ['g-register', { server: 'module.exports = (ctx, api) => { throw new Error("nope") }' }, 'register'], + ] + for (const [id, spec] of cases) writeModule(id, spec) + const loader = freshLoader(tmpRoot) + + for (const [id, , stage] of cases) { + const state = stateOf(loader, id) + assert.equal(state.state, 'startup_failed', `${id} should have failed`) + assert.equal(state.stage, stage, `${id} should have failed at "${stage}"`) } }) From 32ed8e441173fb663c52d8caf1899dfe87468d30 Mon Sep 17 00:00:00 2001 From: wtclaude Date: Mon, 10 Aug 2026 21:27:47 -0500 Subject: [PATCH 2/2] fix(test): stop the suite reaching a real database, and make it exit `npm test` never terminated. Twenty-two test files omitted the two lines that point the pool at a dead port, so utils/db.js -- which builds its mariadb pool at require time and calls dotenv.config() itself -- picked up server/.env and opened five live connections to the developer's MariaDB. The tests still passed, because they stub their models and never issue a query; the only symptoms were a process that never exited and five connections held for as long as it lived. Thirty stranded workers is 150 connections, which is the whole server's limit, and that is the "too many connections" this workspace has hit before. The convention was right and only ever as good as the next test file's memory of it, so it moves into the harness: test/_setup.js is loaded with --require by the npm script, ahead of the test file it hosts, which is the only moment early enough to matter. It pins the dead port -- dotenv does not overwrite an existing variable, so an explicit DB_PORT= still wins for anyone who wants a live database -- and closes the pool after the file's tests, so the process exits at once instead of waiting out the driver's connect retries. The per-file preambles stay: they keep `node --test test/one.test.js` safe on its own. Two supporting fixes: - db.close() is idempotent. pool.end() throws "pool is already closed" on a second call, and closing twice is now normal rather than exceptional -- the harness closes the pool for every file on top of the suites that close it themselves, and a SIGINT followed by a SIGTERM already reached the shutdown handler twice. - test/_helper.js's close() destroys open connections. server.close() only stops accepting and waits for existing connections to end, and node's global fetch keeps its sockets alive, so the listener outlived the test that created it -- invisible until now, because the pool was holding the process open anyway. announceJobs.test.js alone: 120s+ hang -> 0.35s. The whole suite now finishes in ~75s where it previously did not finish at all: 901 tests, 901 pass, verified three times on CI's exact platform (node:20 on Linux, via Docker). Co-Authored-By: Claude --- server/package.json | 2 +- server/src/utils/db.js | 8 ++++++++ server/test/_helper.js | 9 ++++++++- server/test/_setup.js | 42 ++++++++++++++++++++++++++++++++++++++++++ 4 files changed, 59 insertions(+), 2 deletions(-) create mode 100644 server/test/_setup.js diff --git a/server/package.json b/server/package.json index 9bc9042..417a9cf 100644 --- a/server/package.json +++ b/server/package.json @@ -10,7 +10,7 @@ "swagger": "node swagger/swagger.js", "routes:manifest": "node scripts/routeManifest.js", "atlas:import": "node scripts/importSpawnAtlas.js", - "test": "node --test" + "test": "node --test --require ./test/_setup.js" }, "keywords": [ "express", diff --git a/server/src/utils/db.js b/server/src/utils/db.js index 713784b..86f63c9 100644 --- a/server/src/utils/db.js +++ b/server/src/utils/db.js @@ -87,7 +87,15 @@ async function ensureCoreSchema({ retries, delayMs }) { } } +// Idempotent: `pool.end()` throws "pool is already closed" on a second call, and +// closing twice is normal rather than exceptional — a SIGINT followed by a +// SIGTERM reaches the shutdown handler twice, and the test harness closes the +// pool for every file on top of the suites that close it themselves. A teardown +// that fails because it had already succeeded is noise. +let closed = false async function close() { + if (closed) return + closed = true await pool.end() } diff --git a/server/test/_helper.js b/server/test/_helper.js index 3baf6c8..0bad8b0 100644 --- a/server/test/_helper.js +++ b/server/test/_helper.js @@ -14,7 +14,14 @@ async function startApp(configure) { const { port } = server.address() return { url: `http://127.0.0.1:${port}`, - close: () => new Promise((resolve) => server.close(resolve)), + // `server.close()` stops accepting and waits for open connections to end on + // their own — and node's global fetch keeps its sockets alive, so nothing + // ever ends them. The listener then outlives the test that made it, which + // used to be invisible because the pool held the process open anyway. + close: () => new Promise((resolve) => { + server.closeAllConnections() + server.close(resolve) + }), } } diff --git a/server/test/_setup.js b/server/test/_setup.js new file mode 100644 index 0000000..81fa20c --- /dev/null +++ b/server/test/_setup.js @@ -0,0 +1,42 @@ +// ── Test-process setup, loaded into every test file ──────────────────────── +// +// `npm test` passes this with `--require`, so it runs before the test file it +// is hosting — which is the only moment early enough to matter, because +// `utils/db.js` builds its mariadb pool at REQUIRE time. +// +// It fixes two things that were per-file conventions, and therefore held only +// as well as the next test file remembered them: +// +// 1. **Nothing in the suite may reach a real database.** Without this, a file +// that forgot the two `process.env` lines picked up `server/.env` through +// db.js's own `dotenv.config()` and pooled five live connections to the +// developer's MariaDB. The tests still passed — they stub their models — +// so the only symptom was the process never exiting, plus five connections +// held for as long as the worker lived. Thirty stranded workers is 150 +// connections, which is the whole server's limit. +// 2. **The pool is closed when the file's tests are done**, so the process can +// exit at once instead of waiting out the driver's connect retries. +// +// `dotenv` does not overwrite variables that already exist, so pinning the dead +// port here beats `.env` while still letting an explicit `DB_PORT=… npm test` +// through for anyone who deliberately wants a live database. +const { after } = require('node:test') + +process.env.DB_HOST = process.env.DB_HOST || '127.0.0.1' +process.env.DB_PORT = process.env.DB_PORT || '59999' + +// A root-level hook, registered before the test file is even read, so it runs +// once after everything in that file. +// +// Only in the per-file child processes. `--require` is inherited by the runner +// process too, and registering a root hook there gives node:test a second root +// context to report — an empty "tests 0 / pass 0" summary printed after the real +// one, which reads like a suite that silently ran nothing. +if (process.env.NODE_TEST_CONTEXT) { + after(async () => { + // Resolved rather than required: a file that never touched the database must + // not have a pool built for it here just so this can close one. + const cached = require.cache[require.resolve('../src/utils/db')] + if (cached) await cached.exports.close() + }) +}