diff --git a/MIGRATIONS.md b/MIGRATIONS.md index e2a57982f..352ceac8d 100644 --- a/MIGRATIONS.md +++ b/MIGRATIONS.md @@ -4,6 +4,40 @@ Breaking changes and upgrade notes for downstream projects. --- +## Migration runner: claim-with-status — interrupted runs resume instead of being skipped forever (2026-07-28) + +Fixes a data-integrity gap in `lib/services/migrations.js`: the runner previously claimed a migration as executed (an insert into the `migrations` collection) BEFORE calling its `up()`. A hard process kill mid-`up()` (OOM, SIGKILL, pod eviction) left that claim in place with no completion signal — on the next boot the migration was treated as already done and permanently skipped, even though `up()` never finished (found reviewing #3990's backfill: an interrupted `updateMany` could strand a subset of documents; the runner semantics were the generic root cause). + +### ⚠️ New house rule: migrations MUST be idempotent + +Every migration's `up()` MUST be safe to re-run from scratch — this was already the de facto style in this repo (every existing migration backfills/creates conditionally, e.g. skip-if-already-set, skip-if-index-already-exact-spec), but it is now a **hard requirement**, not a convention: the boot-time stale-claim resume below re-runs a migration whenever a `'running'` claim is found stuck past the grace window, with no way to know how far the interrupted run got. A non-idempotent `up()` would corrupt data on resume. + +### What changed (this repo) + +- **`modules/core/models/migration.model.mongoose.js`** — the Migration schema gains `status: 'running' | 'done'` (no default), `startedAt`, `finishedAt`, and forensic context `pid` / `host` (captured at claim time). +- **`modules/core/repositories/migration.repository.js`** — new `claim(name, {pid, host})` (inserts `status:'running'`), `markDone(name)` (atomic `$set: {status:'done', finishedAt}`), `listRunning()`, `findByName(name)`. `listExecuted()` now projects `status` too. `create(name)` (used by `recordMigration`) is unchanged — it never sets `status`, which is correct: see back-compat below. +- **`lib/services/migrations.js`**: + - `claimMigration` now calls `repository.claim(...)` instead of a bare insert — the claim record is `status:'running'` from the moment it's written. + - On `up()` success, `runMigration` calls the new `markMigrationDone(name)` to atomically flip the claim to `status:'done'`. **The thrown-error path is unchanged** — `up()` throwing still unclaims (deletes) the record so the next boot retries, exactly as before. + - **New `resolveStaleClaims(cfg)`**, called by `run()` BEFORE the files/executed comparison. Scans every `status:'running'` claim: + - **Age < `config.migrations.staleRunningGraceMs`** (default **10 minutes**): presumed a genuinely concurrent runner (another instance mid-deploy) — WAITS, polling the live record every ~1s until it flips to `'done'` or disappears (unclaimed elsewhere on failure). The unique claim index already serializes any brand-new claim against this one; this wait only covers an already-existing claim. + - **Age ≥ grace window**: presumed crash residue from a hard kill. Logs a loud `WARN` naming the migration, deletes the stale claim, and lets the normal claim/run loop in `run()` re-claim and re-execute it — safe because of the idempotence requirement above. + - **New config knob** `config.migrations.staleRunningGraceMs` (`config/defaults/development.config.js`, default `10 * 60 * 1000`). + - `getExecutedMigrations()` now filters `listExecuted()` by status: only `status:'done'` OR **no `status` field at all** count as "already done" and are skipped. `status:'running'` is never treated as done — it is exclusively `resolveStaleClaims`'s concern. + +### Back-compat (critical — read before deploying) + +An existing claim record predating this change has **no `status` field**. It is **always** treated as `'done'` — it completed under the old semantics (a bare insert WAS the completion signal), and there is no way to distinguish it from a genuinely-finished migration after the fact. This is explicit and unconditional in `getExecutedMigrations()`: `status == null || status === 'done'`. Getting this wrong in either direction is bad — reinterpreting a legacy record as anything else would re-run migration history on every already-deployed database. + +### Action required for downstream projects (`/update-stack`) + +1. All changes are devkit-owned stack files → arrive via `/update-stack` (`--theirs`). No data migration — the new `status`/`startedAt`/`finishedAt`/`pid`/`host` fields are additive; existing `migrations` collection rows are untouched (and correctly treated as done, see back-compat above). +2. **No action needed for the default 10-minute grace window** unless a project has a migration whose `up()` is expected to legitimately run longer than that under normal (non-crashed) conditions — override `config.migrations.staleRunningGraceMs` in `config/defaults/{project}.config.js` if so. +3. **Confirm every project-owned migration (`modules/{name}/migrations/*.js` outside the stack) is idempotent** — re-runnable after a partial application. This was already best practice; it is now enforced by the resume behavior above. +4. No env var changes, no breaking API/contract change. + +--- + ## Billing usage weekKey-index partial-filter fix (2026-07-28) Fixes a silent write-loss bug: the meter-mode `(organizationId, weekKey)` unique index on `billingusages` declared `sparse: true` on a COMPOUND index. MongoDB's sparse-exclusion rule for a compound index only skips a document when it is missing **ALL** indexed fields — since `organizationId` is always present (on legacy AND meter-mode documents alike), sparse never excluded anything: every legacy (weekKey-less) document was indexed too, with `weekKey` treated as `null`. A second legacy document for the **same organization** — regardless of month — then collided on `{organizationId, weekKey: null}` and was rejected as a duplicate key; `BillingUsageRepository.increment`'s duplicate-key retry filter (`{organizationId, month}`) matched nothing for the new month, so the write silently resolved to `null` with **no error surfaced**. Net effect: under `meterMode: false` (the default), a downstream consumer's legacy usage counters could only ever be recorded for the **first** month an organization was active — every subsequent month's write was lost. diff --git a/config/defaults/development.config.js b/config/defaults/development.config.js index 9fbb987d1..9e9c72801 100644 --- a/config/defaults/development.config.js +++ b/config/defaults/development.config.js @@ -74,6 +74,18 @@ const config = { // key: './config/sslcerts/key.pem', // cert: './config/sslcerts/cert.pem', // }, + migrations: { + // Bounds lib/services/migrations.js#resolveStaleClaims (#3992): on boot, a + // migration claim stuck in status:'running' younger than this is presumed + // to be a genuinely concurrent runner (another instance mid-deploy) and is + // waited on (polled) until it flips to 'done' or crosses this window. Once + // a claim's age reaches this window, it is presumed to be crash residue + // (OOM/SIGKILL/pod eviction hard-killed the process mid-up()) — the claim + // is deleted and the migration re-runs (all in-tree migrations are + // required to be idempotent, see MIGRATIONS.md). 10 minutes comfortably + // exceeds any single migration's expected runtime in this stack. + staleRunningGraceMs: 10 * 60 * 1000, + }, log: { // logging with Morgan - https://github.com/expressjs/morgan // Can specify one of 'combined', 'common', 'dev', 'short', 'tiny', 'custom' diff --git a/lib/services/migrations.js b/lib/services/migrations.js index 6c2d59005..25eae28ba 100644 --- a/lib/services/migrations.js +++ b/lib/services/migrations.js @@ -2,11 +2,34 @@ * Module dependencies. */ import chalk from 'chalk'; +import os from 'os'; import path from 'path'; import { glob } from 'glob'; +import config from '../../config/index.js'; import logger from './logger.js'; import migrationRepository from '../../modules/core/repositories/migration.repository.js'; +/** + * Default bound (ms) on {@link resolveStaleClaims} when + * `config.migrations.staleRunningGraceMs` is not a positive number (#3992). + */ +const DEFAULT_STALE_RUNNING_GRACE_MS = 10 * 60 * 1000; + +/** + * Poll interval (ms) used by {@link resolveStaleClaims} while waiting on a + * `'running'` claim that is still within the grace window (#3992). Not + * config-exposed — only the grace window itself is a documented knob; this is + * an implementation detail bounded by that window (worst case wait = grace). + */ +const DEFAULT_STALE_CLAIM_POLL_INTERVAL_MS = 1000; + +/** + * @desc Promise-based sleep helper used by {@link resolveStaleClaims}'s poll loop. + * @param {number} ms - milliseconds to wait + * @returns {Promise} Resolves after `ms` milliseconds. + */ +const sleep = (ms) => new Promise((resolve) => setTimeout(resolve, ms)); + /** * Scan all modules for migration files matching `modules/*/migrations/*.js`. * @returns {Promise} sorted list of absolute migration file paths @@ -24,12 +47,25 @@ const discoverMigrationFiles = async () => { }; /** - * Retrieve the set of migration names that have already been executed. - * @returns {Promise>} set of executed migration names + * Retrieve the set of migration names that are genuinely complete — i.e. + * safe to skip on this and every future boot. + * + * Back-compat (#3992): a record with no `status` field at all predates + * claim-with-status and completed under the old claim-before-up() semantics + * (a bare insert WAS the completion signal) — it is ALWAYS treated as + * `'done'`, explicitly and unconditionally, never re-interpreted as anything + * else. Getting this wrong in either direction is bad: treating it as + * incomplete would re-run migration history that already applied on every + * project that upgrades past this change; there is no third state to invent. + * A record with `status:'running'` is NOT included here — it is either still + * genuinely in flight or stale crash residue, both handled by + * {@link resolveStaleClaims} before this function is ever consulted in + * {@link run}. + * @returns {Promise>} set of migration names considered complete */ const getExecutedMigrations = async () => { const records = await migrationRepository.listExecuted(); - return new Set(records.map((r) => r.name)); + return new Set(records.filter((r) => r.status == null || r.status === 'done').map((r) => r.name)); }; /** @@ -40,14 +76,17 @@ const getExecutedMigrations = async () => { const recordMigration = (name) => migrationRepository.create(name); /** - * Atomically claim a migration by inserting a record before execution. - * Uses the unique name index to prevent concurrent runners from executing the same migration. + * Atomically claim a migration by inserting a `status:'running'` record + * before execution (#3992). Uses the unique name index to prevent concurrent + * runners from executing the same migration. Captures `pid`/`host` forensic + * context so a stale claim can later be attributed to the process/host that + * left it behind. * @param {string} name - the migration filename used as unique key * @returns {Promise} true if claimed successfully, false if already claimed by another runner */ -const claimMigration = async (name) => { +const claimMigration = async (name, context) => { try { - await migrationRepository.create(name); + await migrationRepository.claim(name, context); return true; } catch (err) { // Duplicate key error means another runner already claimed it @@ -57,11 +96,129 @@ const claimMigration = async (name) => { }; /** - * Remove a claimed migration record on failure so it can be retried. + * Flip a claimed migration's status to `'done'` after its `up()` resolves + * successfully (#3992). The prior thrown-error path (unclaim → retry next + * boot) is unchanged — this only runs on the success branch. Scoped to + * `status:'running'` at the repository layer so a late success from a + * runner whose claim was already cleared as stale can never overwrite a + * newer runner's `'done'` record (#3992 follow-up). * @param {string} name - the migration filename + * @returns {Promise} the update result + */ +const markMigrationDone = (name) => migrationRepository.markDone(name); + +/** + * Remove a migration's claim record so it can be retried. + * - With `context` ({pid, host}): ownership-scoped, via + * {@link migrationRepository.deleteClaim} — only removes the record if it + * is still the exact claim `context` identifies. Used by + * {@link runMigration}'s own failure paths so a late failure can never + * delete a DIFFERENT (newer) runner's record after this claim was already + * cleared as stale by another boot (#3992 follow-up). + * - Without `context`: unscoped, via {@link migrationRepository.deleteByName} + * — used ONLY by {@link resolveRunningClaim} to clear crash residue left + * by a different, presumed-dead process; the caller does not own that claim. + * @param {string} name - the migration filename + * @param {{pid?: number, host?: string}} [context] - claim ownership context * @returns {Promise} the deletion result */ -const unclaimMigration = (name) => migrationRepository.deleteByName(name); +const unclaimMigration = (name, context) => + context ? migrationRepository.deleteClaim(name, context) : migrationRepository.deleteByName(name); + +/** + * @desc Resolve the effective stale-claim grace window (ms). Mirrors the + * `Number(...)` coercion pattern in `lib/services/mongoose.js#awaitIndexBuilds` + * so a Layer-4 `DEVKIT_NODE_*` env override (always a string) still works. + * @param {object} [cfg=config] - application configuration object + * @returns {number} grace window in milliseconds + */ +const resolveStaleGraceMs = (cfg = config) => { + const configured = Number(cfg?.migrations?.staleRunningGraceMs); + // >= 0 (not > 0): a configured `0` is a deliberate, valid override (treat any + // running claim as immediately stale) — only a negative/NaN/missing value + // falls back to the default. + return Number.isFinite(configured) && configured >= 0 ? configured : DEFAULT_STALE_RUNNING_GRACE_MS; +}; + +/** + * @desc Resolve a single `status:'running'` claim found at boot (#3992): + * either it is a genuinely concurrent runner (another instance mid-deploy, + * still within the grace window) or crash residue from a hard-killed process + * (OOM/SIGKILL/pod eviction) that never reached the success branch. + * + * While the claim's age is below `graceMs`, this WAITS — polling the live + * record until it flips to `'done'` (the concurrent runner finished; nothing + * more to do, {@link getExecutedMigrations} will see it as complete) or + * disappears (the concurrent runner's `up()` threw and unclaimed it; the + * migration is now claimable again in the normal loop). The wait is bounded + * by the remaining grace window — worst case this blocks boot for `graceMs`. + * + * Once the age reaches `graceMs` with the claim still `'running'`, it is + * presumed to be crash residue: this logs a loud WARN and deletes the claim + * so the normal claim/run loop in {@link run} re-claims and re-runs it. + * Re-running is safe because every migration in this tree is required to be + * idempotent (MIGRATIONS.md) — the unique claim index still serializes any + * genuinely-new claim against this one. + * @param {object} record - a lean Migration record with `status:'running'` + * @param {{graceMs: number, pollIntervalMs?: number}} opts - resolution options + * @returns {Promise} Resolves once the claim is no longer an open question. + */ +const resolveRunningClaim = async (record, { graceMs, pollIntervalMs = DEFAULT_STALE_CLAIM_POLL_INTERVAL_MS }) => { + let current = record; + + while (current && current.status === 'running') { + // startedAt is always set alongside status:'running' by repository.claim() + // — but a manually-tampered or otherwise malformed record could still + // carry a missing/unparsable startedAt. A non-finite age can't be + // compared against graceMs, so treat it as immediately stale rather than + // let `NaN >= graceMs` (always false) spin this loop forever on a ~1ms + // setTimeout (setTimeout coerces a NaN delay to ~1ms). + const startedAt = new Date(current.startedAt).getTime(); + const ageMs = Number.isFinite(startedAt) ? Date.now() - startedAt : Infinity; + + if (ageMs >= graceMs) { + logger.warn( + chalk.yellow( + ` Resuming migration ${current.name} after interrupted run: claim stuck in 'running' for ${ageMs}ms (>= grace window ${graceMs}ms) — presumed crash residue from a hard kill (OOM/SIGKILL/pod eviction). Deleting the stale claim; it will re-run (migrations are required to be idempotent, see MIGRATIONS.md).`, + ), + ); + await unclaimMigration(current.name); + return; + } + + // Still within the grace window: could be a concurrent runner on another + // instance mid-deploy. Wait, then re-check the live record. + await sleep(Math.min(pollIntervalMs, graceMs - ageMs)); + current = await migrationRepository.findByName(current.name); + } +}; + +/** + * @desc Boot-time stale-claim detection (#3992). Scans every Migration record + * still `status:'running'` and resolves each one via + * {@link resolveRunningClaim} — waiting out genuinely concurrent runners, + * deleting crash residue so it can be resumed. Must run BEFORE + * {@link getExecutedMigrations} is consulted, so a resumed migration is + * correctly excluded from the "already done" set and re-attempted below. + * + * Resolves every record CONCURRENTLY (`Promise.all`, mirroring + * `lib/services/mongoose.js#awaitIndexBuilds`'s own `Promise.all` shape for + * the same "bounded parallel wait at boot" problem) — each record is an + * independent migration (unique `name`), so there is no ordering dependency + * between them. Sequential resolution would make a multi-replica rolling + * deploy's boot time scale additively with the number of concurrently + * in-flight claims (up to N × `graceMs` worst case) instead of the shared + * bound of a single `graceMs`. + * @param {object} [cfg=config] - application configuration object + * @param {{pollIntervalMs?: number}} [opts] - test seam for the wait-poll interval (default {@link DEFAULT_STALE_CLAIM_POLL_INTERVAL_MS}) + * @returns {Promise} Resolves once every running claim is settled. + */ +const resolveStaleClaims = async (cfg = config, { pollIntervalMs = DEFAULT_STALE_CLAIM_POLL_INTERVAL_MS } = {}) => { + const graceMs = resolveStaleGraceMs(cfg); + const runningRecords = await migrationRepository.listRunning(); + + await Promise.all(runningRecords.map((record) => resolveRunningClaim(record, { graceMs, pollIntervalMs }))); +}; /** * Run a single migration file's `up()` export. @@ -79,8 +236,14 @@ const runMigration = async (filePath, executed) => { return false; } - // Atomically claim the migration to prevent concurrent execution - const claimed = await claimMigration(name); + // Atomically claim the migration to prevent concurrent execution. This + // process's own pid/host identify exactly the claim record it is about to + // insert — captured once so every failure-path unclaim below can be scoped + // to it (#3992 follow-up: a late failure must never delete a claim this + // process doesn't own, e.g. one a newer runner already re-claimed/completed + // after this claim was cleared as stale by another boot). + const claimContext = { pid: process.pid, host: os.hostname() }; + const claimed = await claimMigration(name, claimContext); if (!claimed) { logger.warn(chalk.yellow(` Migration already claimed by another runner: ${name}`)); return false; @@ -91,12 +254,12 @@ const runMigration = async (filePath, executed) => { mod = await import(path.resolve(filePath)); } catch (err) { // Unclaim so the migration can be retried on next startup - await unclaimMigration(name); + await unclaimMigration(name, claimContext); throw err; } if (typeof mod.up !== 'function') { - await unclaimMigration(name); + await unclaimMigration(name, claimContext); throw new Error(`Migration file ${name} does not export an up() function`); } @@ -104,10 +267,15 @@ const runMigration = async (filePath, executed) => { await mod.up(); } catch (err) { // Remove the claim so the migration can be retried on next startup - await unclaimMigration(name); + await unclaimMigration(name, claimContext); throw err; } + // Flip the claim to 'done' now that up() has actually finished (#3992) — + // this is the atomic completion signal a hard kill mid-up() used to skip + // entirely, since the pre-fix claim (a bare insert) doubled as "executed". + await markMigrationDone(name); + logger.info(chalk.green(` Migration executed: ${name}`)); return true; }; @@ -127,9 +295,17 @@ const ensureMigrationIndexes = () => migrationRepository.syncIndexes(); * Scans `modules/*/migrations/*.js`, compares with the `migrations` MongoDB * collection, and executes any pending migrations sorted by filename date prefix. * If any migration fails, the error is thrown to prevent the app from starting. + * + * Boot-time stale-claim detection (#3992): before computing which migrations + * are already done, {@link resolveStaleClaims} settles every leftover + * `status:'running'` claim — a hard kill mid-`up()` on a prior boot leaves + * exactly this trace. Must run first so a resumed migration is excluded from + * the "already done" set below and re-attempted in the loop, instead of being + * permanently skipped. + * @param {object} [cfg=config] - application configuration object (test seam) * @returns {Promise<{total: number, executed: number}>} summary of migration run */ -const run = async () => { +const run = async (cfg = config) => { // Ensure the Migration model is registered await import(path.resolve('modules/core/models/migration.model.mongoose.js')); @@ -138,6 +314,10 @@ const run = async () => { // before the unique index was added would silently allow duplicate claims. await ensureMigrationIndexes(); + // Resolve any 'running' claim left over from a prior boot (crash residue or + // a genuinely concurrent runner) BEFORE the files/executed comparison below. + await resolveStaleClaims(cfg); + const files = await discoverMigrationFiles(); if (files.length === 0) { @@ -169,4 +349,13 @@ const run = async () => { return { total: files.length, executed: executedCount }; }; -export default { run, discoverMigrationFiles, getExecutedMigrations, recordMigration, runMigration, ensureMigrationIndexes }; +export default { + run, + discoverMigrationFiles, + getExecutedMigrations, + recordMigration, + runMigration, + ensureMigrationIndexes, + resolveStaleClaims, + resolveRunningClaim, +}; diff --git a/modules/core/migrations/20260728130000-noop-core-test-fixture.js b/modules/core/migrations/20260728130000-noop-core-test-fixture.js new file mode 100644 index 000000000..7a028d223 --- /dev/null +++ b/modules/core/migrations/20260728130000-noop-core-test-fixture.js @@ -0,0 +1,25 @@ +/** + * Migration: no-op core test fixture. + * + * Purely a stable, side-effect-free migration file OWNED by `modules/core` + * (unlike every other real migration, which lives inside the module it + * changes). The `modules/core` migration test suite (`migrations.integration.tests.js` + * / `migrations.unit.tests.js`) needs a real, safe-to-inspect/re-run + * migration record to exercise claim/status/resume behavior against — before + * this fixture it borrowed `modules/billing/migrations/20260501000000-add-meter-fields.js`, + * coupling core's own test suite to an unrelated (optional, downstream-may-not-ship-it) + * module. "Each module is self-contained" (MIGRATIONS.md / stack coding + * guidelines) applies to test fixtures too (#3992 follow-up). + * + * Safe on every project: does nothing, touches no collection, no index. + * @returns {Promise} + */ +export async function up() { + // Intentionally empty — see file doc above. +} + +/** + * Down: no-op, mirrors up(). + * @returns {void} + */ +export function down() {} diff --git a/modules/core/models/migration.model.mongoose.js b/modules/core/models/migration.model.mongoose.js index 66ac87efb..dab527315 100644 --- a/modules/core/models/migration.model.mongoose.js +++ b/modules/core/models/migration.model.mongoose.js @@ -19,6 +19,42 @@ const MigrationSchema = new Schema({ required: true, default: Date.now, }, + // Claim-with-status (#3992): tells apart a migration whose `up()` genuinely + // finished from one whose claim was written but the process was hard-killed + // (OOM/SIGKILL/pod eviction) before `up()` returned. + // - 'running': claimed, `up()` has not yet resolved. lib/services/ + // migrations.js#resolveStaleClaims() treats a 'running' claim older + // than config.migrations.staleRunningGraceMs as crash residue from a + // prior boot and resumes it (all in-tree migrations are required to be + // idempotent — see MIGRATIONS.md — so re-running is safe). + // - 'done': `up()` completed successfully. + // - absent (no `status` field at all): a legacy claim written before this + // field existed. ALWAYS treated as 'done' — see the back-compat + // handling in lib/services/migrations.js#getExecutedMigrations(). It is + // never reinterpreted as anything else, or migration history would + // silently re-run on every project that upgrades past this change. + status: { + type: String, + enum: ['running', 'done'], + }, + // Set when the claim is written (status:'running'); mirrors `executedAt` + // but is the field `resolveStaleClaims()` measures claim age against. + startedAt: { + type: Date, + }, + // Set when `up()` resolves successfully (status flips to 'done'). + finishedAt: { + type: Date, + }, + // Forensic context captured at claim time — which process/host claimed + // this migration, useful when diagnosing a stale 'running' claim after a + // crash. + pid: { + type: Number, + }, + host: { + type: String, + }, }); /** diff --git a/modules/core/repositories/migration.repository.js b/modules/core/repositories/migration.repository.js index 1cc6fd079..4e7a055a5 100644 --- a/modules/core/repositories/migration.repository.js +++ b/modules/core/repositories/migration.repository.js @@ -15,28 +15,111 @@ const syncIndexes = () => mongoose.model('Migration').syncIndexes(); /** * @function listExecuted - * @description Fetch the name of every migration recorded as executed. - * @returns {Promise>} Lean records with only the `name` field. + * @description Fetch the name + status of every Migration record. Despite the + * name (kept for back-compat with existing callers), this returns records + * regardless of status — `status` is included precisely so callers (see + * `lib/services/migrations.js#getExecutedMigrations`) can distinguish a + * genuinely completed migration (status `'done'` or absent/legacy) from one + * still `'running'` (#3992). + * @returns {Promise>} Lean records with `name` + `status`. */ -const listExecuted = () => mongoose.model('Migration').find({}, { name: 1, _id: 0 }).lean(); +const listExecuted = () => mongoose.model('Migration').find({}, { name: 1, status: 1, _id: 0 }).lean(); + +/** + * @function listRunning + * @description Fetch every Migration record whose claim is still `'running'` + * — candidates for `resolveStaleClaims()`'s boot-time stale-claim check + * (#3992). A record in this state was either claimed by a runner still + * genuinely in flight (another instance mid-deploy), or is crash residue from + * a hard-killed process. + * @returns {Promise>} Lean records with all fields (name, status, startedAt, pid, host, ...). + */ +const listRunning = () => mongoose.model('Migration').find({ status: 'running' }).lean(); + +/** + * @function findByName + * @description Fetch a single Migration record by name. Used to re-check a + * `'running'` claim's live status while polling in `resolveStaleClaims()`. + * @param {string} name - Migration filename. + * @returns {Promise} Lean record, or null if no longer present (unclaimed). + */ +const findByName = (name) => mongoose.model('Migration').findOne({ name }).lean(); /** * @function create * @description Insert a new Migration record. Relies on the unique index on - * `name` to reject duplicates — used both by the public `recordMigration()` - * flow and the atomic claim logic in `claimMigration()`. + * `name` to reject duplicates — used by the public `recordMigration()` flow. + * No `status` is set: a record inserted this way is legacy-shaped by design + * and is treated as `'done'` under the back-compat rule (missing status = + * done), which is correct here too — this call represents an already-complete + * migration, not a claim-in-progress. * @param {string} name - Migration filename, unique key for the collection. * @returns {Promise} The created Migration document. */ const create = (name) => mongoose.model('Migration').create({ name, executedAt: new Date() }); +/** + * @function claim + * @description Atomically claim a migration by inserting a `status:'running'` + * record before its `up()` runs (#3992). Relies on the unique index on `name` + * to reject a concurrent claim (E11000) exactly like `create()`. Captures + * forensic context (`pid`, `host`) so a stale claim can be diagnosed later. + * @param {string} name - Migration filename, unique key for the collection. + * @param {{pid?: number, host?: string}} [context] - forensic claim context. + * @returns {Promise} The created Migration document. + */ +const claim = (name, { pid, host } = {}) => { + const claimedAt = new Date(); + return mongoose.model('Migration').create({ + name, + executedAt: claimedAt, + status: 'running', + startedAt: claimedAt, + pid, + host, + }); +}; + +/** + * @function markDone + * @description Flip a claimed migration's status from `'running'` to `'done'` + * after its `up()` resolves successfully, stamping `finishedAt` (#3992). + * Scoped to `status:'running'` so a late success from a runner whose claim + * was already cleared as stale (and possibly re-claimed/completed by a + * newer runner) can never overwrite that newer runner's already-`'done'` + * record — the update simply matches zero documents (#3992 follow-up). + * @param {string} name - Migration filename. + * @returns {Promise} Mongo update result. + */ +const markDone = (name) => + mongoose.model('Migration').updateOne({ name, status: 'running' }, { $set: { status: 'done', finishedAt: new Date() } }); + /** * @function deleteByName - * @description Remove a Migration record by name. Used to unclaim a migration - * when its execution fails so it can be retried on the next boot. + * @description Remove a Migration record by name, regardless of ownership. + * Used ONLY to clear a stale `'running'` claim left by a DIFFERENT, + * presumed-dead process during boot-time stale-claim resolution (#3992) — + * the caller does not own that claim, so this is intentionally unscoped. + * For a runner unclaiming its OWN claim on failure, use {@link deleteClaim} + * instead so a late failure can never delete a newer runner's record. * @param {string} name - Migration filename to delete. * @returns {Promise} Mongo deletion result. */ const deleteByName = (name) => mongoose.model('Migration').deleteOne({ name }); -export default { syncIndexes, listExecuted, create, deleteByName }; +/** + * @function deleteClaim + * @description Remove a `'running'` claim only if it is still owned by the + * calling process (matching `name` + `status:'running'` + `pid`/`host`). + * Used by a runner's own failure path to unclaim its claim so it can be + * retried on the next boot — scoped so a late failure from a process whose + * claim was already cleared as stale by another boot (and possibly + * re-claimed/completed by a newer runner) can never delete that newer + * runner's record (#3992 follow-up). + * @param {string} name - Migration filename. + * @param {{pid?: number, host?: string}} [context] - claim ownership context. + * @returns {Promise} Mongo deletion result. + */ +const deleteClaim = (name, { pid, host } = {}) => mongoose.model('Migration').deleteOne({ name, status: 'running', pid, host }); + +export default { syncIndexes, listExecuted, listRunning, findByName, create, claim, markDone, deleteByName, deleteClaim }; diff --git a/modules/core/tests/fixtures/noop-migration.js b/modules/core/tests/fixtures/noop-migration.js new file mode 100644 index 000000000..8f19f54c4 --- /dev/null +++ b/modules/core/tests/fixtures/noop-migration.js @@ -0,0 +1,16 @@ +/** + * Test fixture: a real, side-effect-free migration module. + * + * Used by `migrations.unit.tests.js` to exercise `runMigration()`'s claim → + * import → up() → markDone success path against a real (non-mocked) file + * import, without depending on `modules/billing`'s migration file (module + * self-containment, #3992 follow-up). Lives under `tests/fixtures/` — NOT + * `modules/core/migrations/` — so it is never picked up by + * `discoverMigrationFiles()`'s `modules/*/migrations/*.js` glob and never + * runs as a real migration; `runMigration()` is called directly with this + * file's path in the test, bypassing discovery entirely. + * @returns {Promise} + */ +export async function up() { + // Intentionally empty — see file doc above. +} diff --git a/modules/core/tests/migrations.integration.tests.js b/modules/core/tests/migrations.integration.tests.js index 464373ed6..05e8cdbdb 100644 --- a/modules/core/tests/migrations.integration.tests.js +++ b/modules/core/tests/migrations.integration.tests.js @@ -1,11 +1,17 @@ /** * Module dependencies. */ +import { jest } from '@jest/globals'; +import fs from 'fs'; +import os from 'os'; +import path from 'path'; import mongoose from 'mongoose'; import mongooseService from '../../../lib/services/mongoose.js'; import { bootstrap } from '../../../lib/app.js'; import migrations from '../../../lib/services/migrations.js'; +import migrationRepository from '../repositories/migration.repository.js'; +import logger from '../../../lib/services/logger.js'; /** * Integration tests for the migration system (requires DB connection) @@ -64,6 +70,192 @@ describe('Migrations integration tests:', () => { }); }); + // #3992: real end-to-end coverage of claim-with-status against a live DB — + // by this point every real migration file has been executed at least once + // by the `run` describe block above, so their Migration records exist. + describe('claim-with-status (#3992)', () => { + it('a completed migration record carries status:done + startedAt/finishedAt/pid/host', async () => { + const Migration = mongoose.model('Migration'); + // No-op, side-effect-free real migration — safe to inspect/re-run. + const record = await Migration.findOne({ name: /add-meter-fields\.js$/ }).lean(); + expect(record).toBeTruthy(); + expect(record.status).toBe('done'); + expect(record.startedAt).toBeInstanceOf(Date); + expect(record.finishedAt).toBeInstanceOf(Date); + expect(record.finishedAt.getTime()).toBeGreaterThanOrEqual(record.startedAt.getTime()); + expect(typeof record.pid).toBe('number'); + expect(typeof record.host).toBe('string'); + }); + }); + + describe('legacy record (no status field) treated as done (#3992)', () => { + const legacyName = `__legacy_no_status_${Date.now()}.js`; + + afterAll(async () => { + const Migration = mongoose.model('Migration'); + await Migration.deleteOne({ name: legacyName }); + }); + + it('is included in getExecutedMigrations() even though it predates the status field', async () => { + // recordMigration() inserts the exact legacy shape (name + executedAt, + // no status) — the same shape every pre-#3992 claim has in production. + await migrations.recordMigration(legacyName); + const executed = await migrations.getExecutedMigrations(); + expect(executed.has(legacyName)).toBe(true); + }); + }); + + describe('boot-time stale-claim resolution (#3992)', () => { + // A core-owned, no-op, side-effect-free real migration as the resume + // target (`modules/core/migrations/20260728130000-noop-core-test-fixture.js`) + // — re-running its up() is a genuine no-op, so tampering with its claim + // record here is safe and requires no cleanup of DB state beyond the + // Migration record itself. Core-owned (not modules/billing's fixture) so + // this suite never depends on an unrelated, optional module (#3992 follow-up). + const targetName = 'modules/core/migrations/20260728130000-noop-core-test-fixture.js'; + let originalRecord; + + beforeEach(async () => { + const Migration = mongoose.model('Migration'); + originalRecord = await Migration.findOne({ name: targetName }).lean(); + // Sanity: must already be 'done' from the `run` describe block above. + expect(originalRecord?.status).toBe('done'); + }); + + afterEach(async () => { + // If the beforeEach sanity check failed, originalRecord was never + // snapshotted — skip restoration so that assertion failure surfaces + // instead of being masked by a TypeError reading .status off undefined. + if (!originalRecord) return; + // Restore the record to its pre-tampering state so later suites/tests + // (and any other assertion relying on stable migration history) see + // consistent state. + const Migration = mongoose.model('Migration'); + await Migration.updateOne( + { name: targetName }, + { + $set: { + status: originalRecord.status, + startedAt: originalRecord.startedAt, + finishedAt: originalRecord.finishedAt, + }, + }, + ); + }); + + it('a stale running claim (age >= grace) is deleted with a loud WARN, then re-executed by run()', async () => { + const Migration = mongoose.model('Migration'); + const staleStartedAt = new Date(Date.now() - 5000); + await Migration.updateOne( + { name: targetName }, + { $set: { status: 'running', startedAt: staleStartedAt }, $unset: { finishedAt: 1 } }, + ); + + const warnSpy = jest.spyOn(logger, 'warn').mockImplementation(() => {}); + let result; + try { + // graceMs: 1 — the 5s-old claim above is immediately past grace, no real wait. + result = await migrations.run({ migrations: { staleRunningGraceMs: 1 } }); + expect(warnSpy).toHaveBeenCalled(); + expect(warnSpy.mock.calls.some((args) => String(args[0]).includes(targetName))).toBe(true); + } finally { + warnSpy.mockRestore(); + } + + expect(result.executed).toBeGreaterThanOrEqual(1); + const record = await Migration.findOne({ name: targetName }).lean(); + expect(record.status).toBe('done'); + expect(record.finishedAt.getTime()).toBeGreaterThan(staleStartedAt.getTime()); + }); + + it('a fresh running claim within the grace window is waited on, not deleted, until it flips to done', async () => { + const Migration = mongoose.model('Migration'); + await Migration.updateOne( + { name: targetName }, + { $set: { status: 'running', startedAt: new Date() }, $unset: { finishedAt: 1 } }, + ); + + // Simulate a genuinely concurrent runner (another instance mid-deploy) + // completing shortly after boot begins polling. + const flipTimer = setTimeout(() => { + Migration.updateOne({ name: targetName }, { $set: { status: 'done', finishedAt: new Date() } }).catch(() => {}); + }, 50); + + const warnSpy = jest.spyOn(logger, 'warn').mockImplementation(() => {}); + try { + await migrations.resolveStaleClaims({ migrations: { staleRunningGraceMs: 2000 } }, { pollIntervalMs: 20 }); + expect(warnSpy).not.toHaveBeenCalled(); + } finally { + warnSpy.mockRestore(); + clearTimeout(flipTimer); + } + + const record = await Migration.findOne({ name: targetName }).lean(); + expect(record.status).toBe('done'); + }); + }); + + // #3992 follow-up: a late failure from a runner must only ever remove ITS + // OWN claim (name + status:'running' + matching pid/host), never a + // differently-owned record — real Mongo coverage of migration.repository.js#deleteClaim, + // not just the mocked call-shape assertions in the unit suite. + describe('ownership-scoped unclaim on failure (#3992 follow-up)', () => { + it('a failing runMigration deletes only the claim it just inserted', async () => { + const Migration = mongoose.model('Migration'); + // Real ESM file outside modules/*/migrations/ so discoverMigrationFiles()'s + // glob can never pick up a leftover if cleanup failed. + const tmpFile = path.join(os.tmpdir(), `__3992-ownership-throws-${process.pid}-${Date.now()}.mjs`); + const name = path.relative(process.cwd(), tmpFile).replace(/\\/g, '/'); + fs.writeFileSync(tmpFile, "export async function up() { throw new Error('boom'); }\n"); + try { + await expect(migrations.runMigration(tmpFile, new Set())).rejects.toThrow('boom'); + expect(await Migration.findOne({ name }).lean()).toBeNull(); + } finally { + fs.unlinkSync(tmpFile); + await Migration.deleteOne({ name }); + } + }); + + it('deleteClaim never removes a still-running claim owned by a different pid/host', async () => { + const Migration = mongoose.model('Migration'); + const name = `__3992_ownership_running_${Date.now()}.js`; + // Simulate a genuinely different, still-in-flight runner's claim + // (status:'running', foreign pid/host) — isolates the ownership check + // itself, distinct from markDone's separate status:'running' guard. + await Migration.create({ name, executedAt: new Date(), status: 'running', startedAt: new Date(), pid: 999999, host: 'a-different-host' }); + try { + const result = await migrationRepository.deleteClaim(name, { pid: process.pid, host: os.hostname() }); + expect(result.deletedCount).toBe(0); + const record = await Migration.findOne({ name }).lean(); + expect(record).toBeTruthy(); + expect(record.status).toBe('running'); + expect(record.pid).toBe(999999); + } finally { + await Migration.deleteOne({ name }); + } + }); + + it('deleteClaim never removes an already-completed record, even one this pid/host once owned', async () => { + const Migration = mongoose.model('Migration'); + const name = `__3992_ownership_done_${Date.now()}.js`; + const context = { pid: process.pid, host: os.hostname() }; + // Simulate THIS process's own claim having already been flipped to + // done by the time a (hypothetically delayed) failure handler runs — + // status:'running' in the filter must block the delete even when + // pid/host match exactly. + await Migration.create({ name, executedAt: new Date(), status: 'done', startedAt: new Date(), finishedAt: new Date(), ...context }); + try { + const result = await migrationRepository.deleteClaim(name, context); + expect(result.deletedCount).toBe(0); + const record = await Migration.findOne({ name }).lean(); + expect(record).toBeTruthy(); + expect(record.status).toBe('done'); + } finally { + await Migration.deleteOne({ name }); + } + }); + }); + afterAll(async () => { try { await mongooseService.disconnect(); diff --git a/modules/core/tests/migrations.unit.tests.js b/modules/core/tests/migrations.unit.tests.js index 6fa0c55f8..c7f38dbf1 100644 --- a/modules/core/tests/migrations.unit.tests.js +++ b/modules/core/tests/migrations.unit.tests.js @@ -2,6 +2,8 @@ * Module dependencies. */ import { jest } from '@jest/globals'; +import fs from 'fs'; +import os from 'os'; import path from 'path'; import mongoose from 'mongoose'; @@ -10,6 +12,7 @@ import '../models/migration.model.mongoose.js'; import migrations from '../../../lib/services/migrations.js'; import migrationRepository from '../repositories/migration.repository.js'; +import logger from '../../../lib/services/logger.js'; /** * Unit tests for the migration system (no DB connection required) @@ -88,22 +91,44 @@ describe('Migrations unit tests:', () => { // no longer re-runs migrations.run() per suite (it sets DEVKIT_MIGRATIONS_RAN // in globalSetup), so these branches must be covered explicitly. describe('repository-mocked branches', () => { - let createSpy; + let claimSpy; + let markDoneSpy; let deleteByNameSpy; + let deleteClaimSpy; let listExecutedSpy; + let listRunningSpy; + let findByNameSpy; let syncIndexesSpy; beforeEach(() => { - createSpy = jest.spyOn(migrationRepository, 'create'); + claimSpy = jest.spyOn(migrationRepository, 'claim'); + markDoneSpy = jest.spyOn(migrationRepository, 'markDone').mockResolvedValue({ acknowledged: true, modifiedCount: 1 }); deleteByNameSpy = jest.spyOn(migrationRepository, 'deleteByName').mockResolvedValue({ acknowledged: true, deletedCount: 1 }); + // Ownership-scoped unclaim used by runMigration's own failure paths + // (#3992 follow-up) — distinct from the unscoped deleteByName used by + // resolveRunningClaim's stale-residue path. + deleteClaimSpy = jest.spyOn(migrationRepository, 'deleteClaim').mockResolvedValue({ acknowledged: true, deletedCount: 1 }); listExecutedSpy = jest.spyOn(migrationRepository, 'listExecuted'); + // #3992: run() now calls resolveStaleClaims() before the files/executed + // comparison — default to "nothing running" so pre-existing tests below + // that don't care about stale-claim resolution are unaffected. + listRunningSpy = jest.spyOn(migrationRepository, 'listRunning').mockResolvedValue([]); + // Default to null (never a real DB round-trip): a test that reaches the + // poll branch without explicitly mocking a resolved value would otherwise + // silently fall through to the REAL mongoose call and hang/timeout on + // buffering instead of failing fast on an unexpected call. + findByNameSpy = jest.spyOn(migrationRepository, 'findByName').mockResolvedValue(null); syncIndexesSpy = jest.spyOn(migrationRepository, 'syncIndexes').mockResolvedValue([]); }); afterEach(() => { - createSpy.mockRestore(); + claimSpy.mockRestore(); + markDoneSpy.mockRestore(); deleteByNameSpy.mockRestore(); + deleteClaimSpy.mockRestore(); listExecutedSpy.mockRestore(); + listRunningSpy.mockRestore(); + findByNameSpy.mockRestore(); syncIndexesSpy.mockRestore(); }); @@ -111,25 +136,76 @@ describe('Migrations unit tests:', () => { it('returns false when another runner already claimed the migration (E11000)', async () => { // Simulate the unique-index duplicate-key error from a concurrent runner const dup = Object.assign(new Error('E11000 duplicate key'), { code: 11000 }); - createSpy.mockRejectedValueOnce(dup); + claimSpy.mockRejectedValueOnce(dup); const result = await migrations.runMigration('modules/core/migrations/__never-run-claim-fail.js', new Set()); expect(result).toBe(false); - expect(createSpy).toHaveBeenCalledTimes(1); + expect(claimSpy).toHaveBeenCalledTimes(1); }); it('rethrows non-duplicate errors from the repository', async () => { - createSpy.mockRejectedValueOnce(new Error('boom')); + claimSpy.mockRejectedValueOnce(new Error('boom')); await expect( migrations.runMigration('modules/core/migrations/__never-run-other-error.js', new Set()), ).rejects.toThrow('boom'); }); it('unclaims when the migration file fails to import', async () => { - createSpy.mockResolvedValueOnce({ name: 'doesNotExist' }); + claimSpy.mockResolvedValueOnce({ name: 'doesNotExist', status: 'running' }); await expect( migrations.runMigration('modules/core/migrations/__file-does-not-exist.js', new Set()), ).rejects.toThrow(); - expect(deleteByNameSpy).toHaveBeenCalledTimes(1); + // Ownership-scoped unclaim (#3992 follow-up) — not the unscoped + // deleteByName, which is reserved for resolveRunningClaim's + // stale-residue path. + expect(deleteClaimSpy).toHaveBeenCalledTimes(1); + expect(deleteByNameSpy).not.toHaveBeenCalled(); + expect(markDoneSpy).not.toHaveBeenCalled(); + }); + + it('claims with status:running + pid/host forensic context, then marks done on success (#3992)', async () => { + claimSpy.mockResolvedValueOnce({ name: 'ok', status: 'running' }); + // A real, side-effect-free migration module (no-op up()) so the import + up() + // call succeed for real. A core-owned test fixture (not a real migration file — + // lives under tests/fixtures/, outside discoverMigrationFiles()'s glob), so + // this suite never depends on an unrelated module like billing (#3992 follow-up). + const realNoopMigration = path.resolve('modules/core/tests/fixtures/noop-migration.js'); + const result = await migrations.runMigration(realNoopMigration, new Set()); + expect(result).toBe(true); + expect(claimSpy).toHaveBeenCalledWith( + expect.any(String), + expect.objectContaining({ pid: expect.any(Number), host: expect.any(String) }), + ); + expect(markDoneSpy).toHaveBeenCalledTimes(1); + expect(deleteByNameSpy).not.toHaveBeenCalled(); + expect(deleteClaimSpy).not.toHaveBeenCalled(); + }); + + it('unclaims (never marks done) when up() itself throws', async () => { + claimSpy.mockResolvedValueOnce({ name: 'boom-up', status: 'running' }); + // A real ESM module living outside modules/*/migrations/ (so a leftover + // file, if cleanup ever failed, could never be picked up by + // discoverMigrationFiles()'s glob and re-run against a real DB). + // `.mjs` (not `.js`): this file lives outside the project root, so + // there is no ancestor package.json with "type":"module" for Node's + // loader to find — a plain `.js` extension there is parsed as + // CommonJS and `export` throws a syntax error. `.mjs` is always ESM. + const tmpFile = path.join(os.tmpdir(), `__3992-throws-in-up-${process.pid}-${Date.now()}.mjs`); + const expectedName = path.relative(process.cwd(), tmpFile).replace(/\\/g, '/'); + fs.writeFileSync(tmpFile, "export async function up() { throw new Error('boom-up'); }\n"); + try { + await expect(migrations.runMigration(tmpFile, new Set())).rejects.toThrow('boom-up'); + // Ownership-scoped unclaim (#3992 follow-up), keyed on this + // process's own pid/host so a late failure can never delete a + // different (newer) runner's record. + expect(deleteClaimSpy).toHaveBeenCalledWith( + expectedName, + expect.objectContaining({ pid: expect.any(Number), host: expect.any(String) }), + ); + expect(deleteByNameSpy).not.toHaveBeenCalled(); + expect(markDoneSpy).not.toHaveBeenCalled(); + } finally { + fs.unlinkSync(tmpFile); + } }); }); @@ -142,17 +218,140 @@ describe('Migrations unit tests:', () => { const result = await migrations.run(); expect(result.total).toBe(files.length); expect(result.executed).toBe(0); + // resolveStaleClaims() runs before the executed-set comparison on every run() + expect(listRunningSpy).toHaveBeenCalledTimes(1); }); it('unclaims and rethrows when the imported migration has no up() export', async () => { // claim succeeds; the file we point at exists but exports no up() - createSpy.mockResolvedValueOnce({ name: 'no-up' }); + claimSpy.mockResolvedValueOnce({ name: 'no-up', status: 'running' }); // This very test file is a real ESM module that does not export up() const realFileWithoutUp = path.resolve('modules/core/tests/migrations.unit.tests.js'); await expect( migrations.runMigration(realFileWithoutUp, new Set()), ).rejects.toThrow(/does not export an up\(\) function/); - expect(deleteByNameSpy).toHaveBeenCalled(); + // Ownership-scoped unclaim (#3992 follow-up) + expect(deleteClaimSpy).toHaveBeenCalled(); + expect(deleteByNameSpy).not.toHaveBeenCalled(); + expect(markDoneSpy).not.toHaveBeenCalled(); + }); + }); + + // #3992: getExecutedMigrations() decides what "already done" means — + // legacy records (no status field) and status:'done' are both skippable; + // status:'running' must NEVER be treated as done (resolveStaleClaims owns it). + describe('getExecutedMigrations status filtering (#3992)', () => { + it('treats a legacy record (no status field) as done', async () => { + listExecutedSpy.mockResolvedValueOnce([{ name: 'legacy-no-status.js' }]); + const executed = await migrations.getExecutedMigrations(); + expect(executed.has('legacy-no-status.js')).toBe(true); + }); + + it('treats status:"done" as done', async () => { + listExecutedSpy.mockResolvedValueOnce([{ name: 'finished.js', status: 'done' }]); + const executed = await migrations.getExecutedMigrations(); + expect(executed.has('finished.js')).toBe(true); + }); + + it('does NOT treat status:"running" as done', async () => { + listExecutedSpy.mockResolvedValueOnce([{ name: 'in-flight.js', status: 'running' }]); + const executed = await migrations.getExecutedMigrations(); + expect(executed.has('in-flight.js')).toBe(false); + }); + + it('filters a mixed batch correctly', async () => { + listExecutedSpy.mockResolvedValueOnce([ + { name: 'legacy.js' }, + { name: 'done.js', status: 'done' }, + { name: 'running.js', status: 'running' }, + ]); + const executed = await migrations.getExecutedMigrations(); + expect([...executed].sort()).toEqual(['done.js', 'legacy.js']); + }); + }); + + // #3992: resolveRunningClaim is the boot-time decision unit for a single + // status:'running' claim — stale (past grace) vs genuinely concurrent + // (within grace, waits/polls). + describe('resolveRunningClaim (#3992)', () => { + it('stale claim (age >= grace) logs a WARN and deletes it so it can re-run', async () => { + const staleRecord = { name: 'stale.js', status: 'running', startedAt: new Date(Date.now() - 1000) }; + const warnSpy = jest.spyOn(logger, 'warn').mockImplementation(() => {}); + await migrations.resolveRunningClaim(staleRecord, { graceMs: 0 }); + expect(deleteByNameSpy).toHaveBeenCalledWith('stale.js'); + expect(warnSpy).toHaveBeenCalledTimes(1); + expect(warnSpy.mock.calls[0][0]).toEqual(expect.stringContaining('stale.js')); + warnSpy.mockRestore(); + }); + + it('running record with a missing startedAt resolves immediately as stale (non-finite age, #3992 follow-up)', async () => { + const noStartedAtRecord = { name: 'no-started-at.js', status: 'running' }; + const warnSpy = jest.spyOn(logger, 'warn').mockImplementation(() => {}); + // A generous grace window proves this isn't just "aged past a tiny + // graceMs" — a non-finite age must resolve as stale regardless. + await migrations.resolveRunningClaim(noStartedAtRecord, { graceMs: 5000 }); + expect(deleteByNameSpy).toHaveBeenCalledWith('no-started-at.js'); + expect(warnSpy).toHaveBeenCalledTimes(1); + expect(warnSpy.mock.calls[0][0]).toEqual(expect.stringContaining('no-started-at.js')); + warnSpy.mockRestore(); + }); + + it('fresh claim within grace waits (polls), then returns quietly once it flips to done', async () => { + const freshRecord = { name: 'fresh.js', status: 'running', startedAt: new Date() }; + findByNameSpy.mockResolvedValueOnce({ ...freshRecord, status: 'done' }); + const warnSpy = jest.spyOn(logger, 'warn').mockImplementation(() => {}); + await migrations.resolveRunningClaim(freshRecord, { graceMs: 5000, pollIntervalMs: 5 }); + expect(findByNameSpy).toHaveBeenCalledWith('fresh.js'); + expect(deleteByNameSpy).not.toHaveBeenCalledWith('fresh.js'); + expect(warnSpy).not.toHaveBeenCalled(); + warnSpy.mockRestore(); + }); + + it('claim that disappears mid-wait (unclaimed elsewhere on failure) returns quietly', async () => { + const freshRecord = { name: 'vanishing.js', status: 'running', startedAt: new Date() }; + findByNameSpy.mockResolvedValueOnce(null); + const warnSpy = jest.spyOn(logger, 'warn').mockImplementation(() => {}); + await migrations.resolveRunningClaim(freshRecord, { graceMs: 5000, pollIntervalMs: 5 }); + expect(findByNameSpy).toHaveBeenCalledWith('vanishing.js'); + expect(deleteByNameSpy).not.toHaveBeenCalledWith('vanishing.js'); + expect(warnSpy).not.toHaveBeenCalled(); + warnSpy.mockRestore(); + }); + }); + + // #3992: resolveStaleClaims is the boot-time orchestrator — fetches every + // running claim and resolves each one. + describe('resolveStaleClaims (#3992)', () => { + it('resolves every running claim returned by listRunning', async () => { + listRunningSpy.mockResolvedValueOnce([ + { name: 'stale-a.js', status: 'running', startedAt: new Date(Date.now() - 1000) }, + { name: 'stale-b.js', status: 'running', startedAt: new Date(Date.now() - 1000) }, + ]); + const warnSpy = jest.spyOn(logger, 'warn').mockImplementation(() => {}); + await migrations.resolveStaleClaims({ migrations: { staleRunningGraceMs: 0 } }); + expect(deleteByNameSpy).toHaveBeenCalledWith('stale-a.js'); + expect(deleteByNameSpy).toHaveBeenCalledWith('stale-b.js'); + warnSpy.mockRestore(); + }); + + it('is a no-op when nothing is running', async () => { + listRunningSpy.mockResolvedValueOnce([]); + await migrations.resolveStaleClaims({ migrations: { staleRunningGraceMs: 0 } }); + expect(deleteByNameSpy).not.toHaveBeenCalled(); + }); + + it('falls back to the default grace window when config value is not a positive number', async () => { + listRunningSpy.mockResolvedValueOnce([{ name: 'edge.js', status: 'running', startedAt: new Date() }]); + findByNameSpy.mockResolvedValueOnce({ name: 'edge.js', status: 'done' }); + // An invalid config value (negative / NaN / string) must not crash — + // it falls back to DEFAULT_STALE_RUNNING_GRACE_MS (10 min), so the + // fresh claim above takes the "wait" branch, not "stale". Small + // pollIntervalMs override keeps this test fast. + const warnSpy = jest.spyOn(logger, 'warn').mockImplementation(() => {}); + await migrations.resolveStaleClaims({ migrations: { staleRunningGraceMs: -5 } }, { pollIntervalMs: 5 }); + expect(warnSpy).not.toHaveBeenCalled(); + expect(deleteByNameSpy).not.toHaveBeenCalledWith('edge.js'); + warnSpy.mockRestore(); }); }); });