From 13e03c3d0f1202bac7d14bc0c6532ce633f52e5f Mon Sep 17 00:00:00 2001 From: Brandon Li Date: Mon, 19 Oct 2026 00:41:04 -0500 Subject: [PATCH] Updater heals itself: PM2 cron revived, Update now, failure reasons PM2's cron for autofirmer-update dies inside a live daemon (six Windows machines in October), and nothing on the machine noticed. The app now watches scripts/.last-check and, past 10 minutes, runs update-check.mjs --heal: a checker PM2 still lists is restarted (which re-registers its cron), one it lost is registered again, and one whose errored entry still holds a live pid is left alone, since PM2 would kill that pid. The heal scrubs PM2's per-app fields from its environment first. The master's new 'update-now' command runs --heal --now, skipping a failed update's retry wait. A failed pull, npm install or build records one line of reason (or the chown to run when a file isn't ours), which rides on .last-check to the master. A package-lock.json rewritten by npm is put back before the pull. The fetch timeout drops under the cron's minute. scripts/.no-auto-update opts a checkout out. Co-Authored-By: Claude Opus 5.5 --- .gitignore | 2 + lib/clients.ts | 4 + lib/master-link.ts | 5 + lib/master-protocol.ts | 7 +- lib/updater-watchdog.ts | 103 ++++++++++++++ scripts/update-check.mjs | 298 ++++++++++++++++++++++++++++++++++++--- 6 files changed, 396 insertions(+), 23 deletions(-) create mode 100644 lib/updater-watchdog.ts diff --git a/.gitignore b/.gitignore index 9a929b3..837c87a 100644 --- a/.gitignore +++ b/.gitignore @@ -63,6 +63,8 @@ scripts/update.log scripts/.built-commit scripts/.update-failed scripts/update-worker.log +# present = this checkout is never auto-updated or healed (a dev checkout) +scripts/.no-auto-update # the previous build, set aside while the updater builds (Tailwind's source # scan also honours this, so it never reads the old bundles) /.next-prev/ diff --git a/lib/clients.ts b/lib/clients.ts index 534cea2..b900db2 100644 --- a/lib/clients.ts +++ b/lib/clients.ts @@ -12,6 +12,7 @@ import { startReporter, sendReport } from './reporter'; import { startBackupSync } from './backup-sync'; import { applyBrokerHttpDefaults, applyBrokerProxy } from './outbound-proxy'; import { startMasterLink } from './master-link'; +import { startUpdaterWatchdog } from './updater-watchdog'; import { resumeSchedulerIfPersisted } from './auto-trade'; import { superviseQuotes, SUPERVISE_INTERVAL_MS, type QuoteClient } from './live-quotes'; @@ -227,6 +228,9 @@ export function getClients(): Map { // Start master dashboard reporter startReporter(); + // Bring this machine's auto-updater back if its PM2 cron stops firing. + startUpdaterWatchdog(); + // Push settings+credentials backups to the master, so a dead VPS // can be replaced and this identity adopted. startBackupSync(); diff --git a/lib/master-link.ts b/lib/master-link.ts index db6f997..ab1215a 100644 --- a/lib/master-link.ts +++ b/lib/master-link.ts @@ -24,6 +24,7 @@ import { queueRun } from './queue-run'; import { pushBackup } from './backup-sync'; import { getBuildVersion } from './version'; import { updaterStatus } from './updater-status'; +import { runUpdateNow } from './updater-watchdog'; import type { Command, InstanceCapabilities, @@ -87,6 +88,7 @@ export function collectCapabilities(): InstanceCapabilities { })) ), runnerOnline, + updateNow: true, }; } @@ -131,6 +133,9 @@ async function execute(command: Command): Promise { case 'backup-now': return pushBackup(true); + case 'update-now': + return runUpdateNow(); + default: { // A newer master may know commands this build does not. Say so // rather than failing silently. diff --git a/lib/master-protocol.ts b/lib/master-protocol.ts index ae67125..1a3df1f 100644 --- a/lib/master-protocol.ts +++ b/lib/master-protocol.ts @@ -318,6 +318,8 @@ export interface InstanceCapabilities { symbols: string[]; automations: AutomationSummary[]; runnerOnline: boolean; + /** Answers the 'update-now' command; the master offers it only then. */ + updateNow: boolean; } // ── Firm catalog ───────────────────────────────────────────────────────────── @@ -508,7 +510,10 @@ export type Command = | { kind: 'autobuyer-run'; automationId: string; inputs?: Record } | { kind: 'report-now' } /** Push a fresh settings/credentials backup right now. */ - | { kind: 'backup-now' }; + | { kind: 'backup-now' } + /** Heal this machine's auto-updater if it stopped, then check for an + * update at once, skipping a failed update's retry wait. */ + | { kind: 'update-now' }; export type MasterMessage = /** personId is the person's stable uuid; the instance stores it and diff --git a/lib/updater-watchdog.ts b/lib/updater-watchdog.ts new file mode 100644 index 0000000..6646417 --- /dev/null +++ b/lib/updater-watchdog.ts @@ -0,0 +1,103 @@ +/** + * Keeps this machine's auto-updater (scripts/update-check.mjs) alive. + * + * PM2 fires the update checker every minute, and nothing on the machine + * notices when it stops. On the fleet it stops on its own: PM2's cron dies + * inside a live daemon (six Windows machines in October 2026; the mechanism + * is in update-check.mjs heal), and a `pm2 stop` or a reboot after an unsaved + * process-list change does the same. The master's dashboard notices ("updater + * not running"), but then someone has to get onto the machine. The app is a + * long-running PM2 process, which PM2 keeps alive reliably, so it checks: once + * the last check is older than the master's 10 minutes, it asks the script to + * heal, i.e. get PM2 firing it again, and run a check. + * + * It only revives an updater that has run here before (scripts/.last-check + * exists). A checkout that never had one is someone's choice, and + * scripts/.no-auto-update switches a checkout off outright (a dev checkout). + * Only the checkout's first instance watches — PM2 name `autofirmer`, which + * scripts/instances.mjs keeps for instance 1 — since the others share its + * updater. + * + * The master's "Update now" command comes through here as well. + */ +import { spawn } from 'node:child_process'; +import { existsSync, readFileSync, statSync } from 'node:fs'; +import path from 'node:path'; + +const EVERY_MS = 5 * 60_000; +/** The master's UPDATER_STALE_MS: past this its dashboard says "not running". */ +const STALE_MS = 10 * 60_000; +/** A heal that didn't take (PM2 missing, say) is retried no sooner than this. */ +const RETRY_MS = 30 * 60_000; + +const scriptsDir = () => path.join(process.cwd(), 'scripts'); +const optedOut = () => existsSync(path.join(scriptsDir(), '.no-auto-update')); + +// Per process: instrumentation.ts and the route handlers each load this module. +const g = globalThis as typeof globalThis & { __updaterWatchdog?: { lastHealAt: number } }; + +/** When the updater last checked (epoch ms), or null if it never has here. */ +function lastCheckAt(): number | null { + const file = path.join(scriptsDir(), '.last-check'); + try { + // " ", rewritten on every check. + const at = Date.parse(readFileSync(file, 'utf8').split(/\s/, 1)[0]); + return Number.isFinite(at) ? at : statSync(file).mtimeMs; + } catch { + return null; + } +} + +/** + * Start update-check.mjs on its own. Detached, because what it starts may + * restart this very process; the script logs to scripts/update.log itself. + */ +function spawnUpdateCheck(args: string[]): number { + const child = spawn(process.execPath, [path.join(scriptsDir(), 'update-check.mjs'), ...args], { + cwd: process.cwd(), + detached: true, + // No console window popping up on a Windows trading desktop. + windowsHide: true, + stdio: 'ignore', + }); + child.on('error', (err) => console.error(`[updater-watchdog] update-check.mjs failed to start: ${err.message}`)); + child.unref(); + if (!child.pid) throw new Error('could not start scripts/update-check.mjs'); + return child.pid; +} + +function tick(): void { + const state = g.__updaterWatchdog; + if (!state || optedOut()) return; + const last = lastCheckAt(); + if (last === null) return; // never ran here: not ours to start + const now = Date.now(); + if (now - last <= STALE_MS || now - state.lastHealAt < RETRY_MS) return; + state.lastHealAt = now; + try { + const pid = spawnUpdateCheck(['--heal']); + console.log(`[updater-watchdog] last update check ${Math.round((now - last) / 60_000)} min ago — asked update-check.mjs to heal (pid ${pid})`); + } catch (err) { + console.error(`[updater-watchdog] ${err instanceof Error ? err.message : String(err)}`); + } +} + +export function startUpdaterWatchdog(): void { + if (g.__updaterWatchdog) return; + // Under PM2 only (pm_id is PM2's): `next dev`, a sandbox copy or a + // by-hand `next start` has no updater to keep alive. + if (process.env.pm_id === undefined || process.env.name !== 'autofirmer') return; + g.__updaterWatchdog = { lastHealAt: 0 }; + setInterval(tick, EVERY_MS).unref(); +} + +/** + * The master's "Update now": heal the updater if it stopped, then check at + * once, skipping a failed update's retry wait. Answers before the update + * runs — it may restart this process — so its outcome reaches the master + * with the next report's updater status. + */ +export function runUpdateNow(): { started: true; pid: number } { + if (optedOut()) throw new Error('updates are switched off on this machine (scripts/.no-auto-update)'); + return { started: true, pid: spawnUpdateCheck(['--heal', '--now']) }; +} diff --git a/scripts/update-check.mjs b/scripts/update-check.mjs index 2a3b8db..18c0ae7 100644 --- a/scripts/update-check.mjs +++ b/scripts/update-check.mjs @@ -33,9 +33,15 @@ * the build fails, and a failure is retried on a backoff (scripts/.update-failed) * rather than every minute. * + * A machine whose checker stopped firing can't notice by itself, so the app + * asks for a heal (lib/updater-watchdog.ts) once the last check goes stale, and + * the master's "Update now" asks for a heal plus an immediate check. + * * node scripts/update-check.mjs # check; start a worker if needed * node scripts/update-check.mjs --apply # update now, here, in the foreground * node scripts/update-check.mjs --dry-run # report only, change nothing + * node scripts/update-check.mjs --heal # re-register a checker that stopped, then check + * node scripts/update-check.mjs --now # check without waiting out a failure's backoff */ import { spawn, spawnSync } from 'node:child_process'; import { @@ -65,6 +71,14 @@ const BRANCH = process.env.AUTOFIRMER_BRANCH ?? 'master'; const INSTANCES = loadInstances(); const APPLY = process.argv.includes('--apply'); const DRY_RUN = process.argv.includes('--dry-run'); +const HEAL = process.argv.includes('--heal'); +const NOW = process.argv.includes('--now'); +const OPT_OUT_FILE = path.join(ROOT, 'scripts', '.no-auto-update'); +// The PM2 app install-autostart.* registers, and its schedule. +const CHECKER = 'autofirmer-update'; +const DEFAULT_CRON = '*/1 * * * *'; +// The master's UPDATER_STALE_MS: past this its dashboard says "updater not running". +const STALE_CHECK_MS = 10 * 60 * 1000; const STALE_LOCK_MS = 2 * 60 * 60 * 1000; const LEGACY_STALE_LOCK_MS = 10 * 60 * 1000; const LOCK_SETTLE_MS = 1000; @@ -76,7 +90,10 @@ const REPEAT_RETRY_MS = 60 * 60 * 1000; // it. npm and next build are left unbounded: on Windows a timeout would kill // only the cmd.exe in front of them, and an orphaned build still writing into // .next is worse than a slow one. -const FETCH_TIMEOUT_MS = 2 * 60 * 1000; +// The fetch also stays under the cron's minute: a check still running at the next +// fire has to be killed by PM2, and that kill is where PM2 loses the cron +// (see heal). +const FETCH_TIMEOUT_MS = 45 * 1000; const PM2_TIMEOUT_MS = 3 * 60 * 1000; const LOG_MAX_BYTES = 256 * 1024; const LOG_KEEP_LINES = 500; @@ -120,6 +137,13 @@ function recordCheck(status) { } catch { /* never let bookkeeping break an update */ } } +/** + * An argument for run() as cmd.exe will see it. On Windows run() goes through + * the shell, which joins the arguments with plain spaces, so a cron string or + * a path with a space in it would arrive as several. + */ +const shellArg = (arg) => (process.platform === 'win32' && /[\s"]/.test(arg) ? `"${arg.replace(/"/g, '""')}"` : arg); + function run(cmd, args, { capture = false, timeout } = {}) { return spawnSync(cmd, args, { cwd: ROOT, @@ -370,7 +394,7 @@ function releaseLock() { } // ── failure record ────────────────────────────────────────────────────────── -// scripts/.update-failed = { target, step, at, count, restart, clicker }. +// scripts/.update-failed = { target, step, at, count, restart, clicker, detail? }. // // Written when an attempt STARTS and deleted when it succeeds, so a worker // that dies without reporting (killed, rebooted) still counts as a failed @@ -393,6 +417,54 @@ function writeFailure(f) { function clearFailure() { try { rmSync(FAILED_FILE, { force: true }); } catch { /* bookkeeping */ } } +/** Size of update-worker.log right now, so a step's own output can be told apart. */ +function workerLogSize() { + try { return statSync(WORKER_LOG_FILE).size; } catch { return 0; } +} + +/** What update-worker.log gained since `from` ('' when a by-hand --apply + * wrote to the terminal instead). */ +function workerLogSince(from) { + try { + const buf = readFileSync(WORKER_LOG_FILE); + return buf.length > from ? buf.subarray(from).toString('utf8') : ''; + } catch { + return ''; + } +} + +/** + * Why a step failed, from its output since `from`: the file this user can't + * replace when a permission is what stopped it, else one line of the output. + */ +function explainFailure(from) { + const text = workerLogSince(from); + return (PERMISSION_DENIED.test(text) && ownershipProblem()) || failureReason(text); +} + +/** + * One line on why a step failed, from its output, or null. + * + * The full npm/next output stays on the machine. Without a reason the master + * shows only "update failed at build", and a machine failing for a cause of + * its own (a Node upgrade leaving better-sqlite3 on the old ABI, a file + * Defender holds, a full disk) can't be told from a broken push. The line + * rides on .last-check, which every app build and the master already carry. + */ +function failureReason(text) { + // eslint-disable-next-line no-control-regex + const lines = text.replace(/\x1b\[[0-9;]*m/g, '').split(/\r?\n/).map((l) => l.trim()).filter(Boolean); + // npm's own epilogue says only that the script failed, and where its log + // is; and this script's own log lines (they go to the console too) aren't + // the step's output. + const boilerplate = /^npm (ERR!|error)( (code|path|command|errno|syscall|signal|workspace|location|A complete log|Lifecycle)\b|\s*$)|^> |^\d{4}-\d\d-\d\dT\S+ {2}/; + const first = (re) => lines.find((l) => re.test(l) && !boilerplate.test(l)); + const line = first(/NODE_MODULE_VERSION|ERR_DLOPEN_FAILED|\bE(PERM|BUSY|ACCES|NOSPC)\b|heap out of memory|Type error:/) + ?? first(/\b[Ee]rror\b/) + ?? lines.filter((l) => !boilerplate.test(l)).pop(); + return line ? line.replace(/\s+/g, ' ').slice(0, 100) : null; +} + /** 15 min after the first failure, an hour after repeated ones: long enough * that a deterministic failure (a broken push) doesn't rebuild every minute * on a trading PC, short enough that a transient one (network, EPERM) heals @@ -434,19 +506,28 @@ function headMovedAt() { } } +/** PM2's process list, or null when PM2 can't be asked. */ +function pm2List() { + const r = run('pm2', ['jlist'], { capture: true, timeout: 30_000 }); + if (r.status !== 0) return null; + // jlist prints the process list as one JSON line, possibly after "[PM2] ..." chatter. + const line = (r.stdout ?? '').split('\n').find((l) => /^\s*\[\s*[{\]]/.test(l)); + try { + const procs = JSON.parse(line); + return Array.isArray(procs) ? procs : null; + } catch { + return null; + } +} + /** * Names of this checkout's PM2 instances that started before `ms`, i.e. still * running code from before the build on disk. Empty when PM2 can't be asked: * this only sharpens a heuristic and must never block an update. */ function instancesStartedBefore(ms) { - const r = run('pm2', ['jlist'], { capture: true, timeout: 30_000 }); - if (r.status !== 0) return []; - // jlist prints the process list as one JSON line, possibly after "[PM2] ..." chatter. - const line = (r.stdout ?? '').split('\n').find((l) => /^\s*\[\s*[{\]]/.test(l)); - let procs; - try { procs = JSON.parse(line); } catch { return []; } - if (!Array.isArray(procs)) return []; + const procs = pm2List(); + if (!procs) return []; const names = new Set(INSTANCES.map((i) => i.name)); return procs .filter((p) => names.has(p?.name) && p.pm2_env?.status === 'online' && Number(p.pm2_env.pm_uptime) < ms) @@ -550,6 +631,65 @@ function workFor(plan) { }; } +// ── stuck states ──────────────────────────────────────────────────────────── +// Two states that fail every update until a person gets onto the machine. + +/** What a step prints when it may not touch a file. */ +const PERMISSION_DENIED = /permission denied|insufficient permission|\bEACCES\b|\bEPERM\b/i; + +/** + * A file in the checkout this user doesn't own, as the fix to run, or null. + * + * One `sudo git pull` or `sudo npm run build` leaves files this user cannot + * replace, and from then on every update fails: the build can't clear .next, + * and a fetch can't write into .git (Ziad's Pi, 2026-10-02: ~1,800 of them). + * The failure itself only says EACCES somewhere in npm's output, so name the + * file and the one command that fixes it — the master's updater chip shows + * this line. Asked only once a step has failed on a permission: a stray + * root-owned file that blocks nothing must not stop an update. POSIX only. + */ +function ownershipProblem() { + if (typeof process.getuid !== 'function') return null; + const r = run('find', [ROOT, '!', '-user', String(process.getuid()), '-print', '-quit'], { capture: true, timeout: 20_000 }); + const hit = (r.stdout ?? '').split('\n')[0].trim(); + if (!hit) return null; + let owner = 'another user'; + try { + const uid = lstatSync(hit).uid; + owner = uid === 0 ? 'root' : `uid ${uid}`; + } catch { /* gone since: the generic name will do */ } + return `${path.relative(ROOT, hit) || '.'} is owned by ${owner}: run sudo chown -R ${os.userInfo().username} ${ROOT}`; +} + +/** inspect(), with a fetch refused by a .git this user can't write named as such. */ +function inspectNamingOwnership(opts) { + try { + return inspect(opts); + } catch (err) { + const why = PERMISSION_DENIED.test(err.message) ? ownershipProblem() : null; + throw why ? new Error(why) : err; + } +} + +/** + * npm install rewrites package-lock.json on some machines (another npm + * version, platform-specific optional dependencies), and that edit then + * refuses every fast-forward that touches the file. It is generated, so when + * it is the only tracked edit, put it back. Any other edit is a person's and + * stays, showing as "edited here" on the master. + */ +function restoreRewrittenLockfile() { + let changed; + try { + changed = git('diff', '--name-only', 'HEAD').split('\n').filter(Boolean); + } catch { + return; + } + if (changed.length !== 1 || changed[0] !== 'package-lock.json') return; + git('checkout', 'HEAD', '--', 'package-lock.json'); + log('package-lock.json had been rewritten here (npm) — put it back before the pull'); +} + // ── build ─────────────────────────────────────────────────────────────────── /** @@ -630,6 +770,111 @@ function removePrevBuild() { } } +// ── heal ──────────────────────────────────────────────────────────────────── +// The checker runs only while PM2 fires it, and PM2 loses it easily: a +// `pm2 stop`, a `pm2 delete all`, a reboot after a list change nobody saved. + +/** How long ago the last check ran, in ms; null = never on this checkout. */ +function lastCheckAge() { + try { + const at = Date.parse(readFileSync(LAST_CHECK_FILE, 'utf8').split(/\s/, 1)[0]); + return Date.now() - (Number.isFinite(at) ? at : statSync(LAST_CHECK_FILE).mtimeMs); + } catch { + return null; + } +} + +const fmtAge = (ms) => (ms >= 90 * 60 * 1000 ? `${Math.round(ms / 3_600_000)} h` : `${Math.round(ms / 60_000)} min`); + +/** + * The fields PM2 adds to an app's environment. + * + * PM2 hands every app the scalar fields of its own record as environment + * (name, pm_id, autorestart, …), and `pm2 start` captures the caller's + * environment for the new app, then copies it over the new app's record. A + * checker registered by a heal, which the dashboard app starts, would take + * that app's name and id, and its autorestart would override + * --no-autorestart. These are the fields PM2 put on real records, plus the + * ones only some records carry. PORT and AUTOFIRMER_DB are the instance's + * own, and the checker serves every instance. + */ +const INHERITED_FIELDS = new Set([ + 'NODE_APP_INSTANCE', 'automation', 'autorestart', 'autostart', 'created_at', 'cron_restart', + 'exec_interpreter', 'exec_mode', 'exit_code', 'filter_env', 'instance_var', 'instances', + 'kill_retry_time', 'km_link', 'merge_logs', 'name', 'namespace', 'node_version', 'pmx', + 'prev_restart_delay', 'restart_time', 'status', 'stop_exit_codes', 'treekill', 'unique_id', + 'unstable_restarts', 'username', 'version', 'versioning', 'vizion', 'vizion_running', 'watch', + 'windowsHide', 'PORT', 'AUTOFIRMER_DB', +]); + +/** Drop what PM2 (and the instance) put in this process's environment, so + * nothing started from here inherits it. */ +function scrubInheritedEnv() { + // PM2 also files the app's own config under its name. + if (process.env.name) delete process.env[process.env.name]; + for (const key of Object.keys(process.env)) { + if (INHERITED_FIELDS.has(key) || key.startsWith('pm_') || key.startsWith('axm_')) delete process.env[key]; + } +} + +/** + * Get PM2 firing this script again once its checks have stopped. Returns + * false when this checkout is opted out of updates altogether. + * + * What the fleet shows (2026-10, six Windows machines): the cron dies inside + * a live PM2 daemon, nobody involved. Every fire runs restartProcessId, + * whose first step drops the cron; only a restart that gets as far as + * launching the app registers it again. croner sometimes fires twice in + * one second, the second restart has to stop a check that is still + * launching, and a refused or timed-out stop leaves the checker `stopped` + * or `errored` with no cron at all. + * + * So a checker PM2 still lists is restarted, which registers its cron again + * with the schedule and environment it already had, and nothing is deleted: + * `pm2 delete` kills the pid an `errored` entry kept, and Windows hands pids + * out again quickly, so that could be any program by now. If that pid is + * alive, PM2 is left alone and this run checks instead. Only a checker PM2 + * has lost entirely is registered again, the way install-autostart.* does. + */ +function heal() { + if (existsSync(OPT_OUT_FILE)) { + console.log('scripts/.no-auto-update is here — this checkout is not auto-updated'); + return false; + } + // Before anything is started from here, the worker below included: the + // app that asked for this heal is a PM2 app, and may be instance 2. + scrubInheritedEnv(); + const age = lastCheckAge(); + if (age !== null && age <= STALE_CHECK_MS) return true; // checking on schedule + const why = age === null ? 'the update checker had never run here' : `the update checker had stopped (last check ${fmtAge(age)} ago)`; + + const pm2 = (...args) => run('pm2', args.map(shellArg), { capture: true, timeout: PM2_TIMEOUT_MS }); + const lastLine = (r) => (((r.stderr || r.stdout) ?? '').trim().split('\n').pop() || `exit ${r.status}`); + const listed = pm2List()?.find((p) => p?.name === CHECKER); + const pid = Number(listed?.pid); + if (listed && pid > 0 && pidAlive(pid)) { + log(`${why}, but PM2 still has it on pid ${pid}, which is alive — left PM2 alone (a restart would kill that pid); checking from here`); + return true; + } + + let how; + if (listed && pm2('restart', CHECKER).status === 0) { + how = `restarted it in PM2 (${listed.pm2_env?.status ?? 'unknown'}), which registers its cron again`; + } else { + const cron = listed?.pm2_env?.cron_restart || DEFAULT_CRON; + if (listed) pm2('delete', CHECKER); // its restart failed, and its pid is dead + const r = pm2('start', SELF, '--name', CHECKER, '--no-autorestart', '--cron-restart', cron); + if (r.status !== 0) { + log(`${why} — ERROR: could not register it with PM2: ${lastLine(r)}`); + return true; // the check below can still update this machine + } + how = `registered it with PM2 again (${cron})`; + } + const saved = pm2('save').status === 0; + log(`${why} — ${how}${saved ? '' : ', but pm2 save failed: a reboot would lose it'}`); + return true; +} + // ── check ─────────────────────────────────────────────────────────────────── /** @@ -688,7 +933,7 @@ function check() { let outcome = null; try { - const plan = inspect({ adopt: !DRY_RUN }); + const plan = inspectNamingOwnership({ adopt: !DRY_RUN }); if (!plan.needsPull && !plan.needsBuild && !plan.needsRestart) { outcome = `up to date at ${short(plan.target)}`; // silent in the log by design if (DRY_RUN) console.log(outcome); @@ -699,9 +944,11 @@ function check() { return 0; } // Silent in update.log too: the failure itself was logged once, and a - // line a minute until the retry would bury it. - if (plan.pending && Date.now() < retryAt(plan.pending)) { - outcome = `waiting to retry ${short(plan.target)}: ${plan.pending.step} (attempt ${plan.pending.count}), next try after ${new Date(retryAt(plan.pending)).toISOString()}`; + // line a minute until the retry would bury it. --now (the master's + // "Update now") is a person asking for the retry. + if (plan.pending && !NOW && Date.now() < retryAt(plan.pending)) { + outcome = `waiting to retry ${short(plan.target)}: ${plan.pending.step} (attempt ${plan.pending.count}), next try after ${new Date(retryAt(plan.pending)).toISOString()}` + + (plan.pending.detail ? ` — ${plan.pending.detail}` : ''); return 0; } const pid = startWorker(); @@ -748,15 +995,15 @@ async function apply() { let outcome = 'interrupted'; let attempt = null; - const abort = (step, why) => { - log(`ABORTED: ${why}`); - outcome = why; - if (attempt) writeFailure({ ...attempt, step, at: Date.now() }); + const abort = (step, why, detail = null) => { + log(`ABORTED: ${why}${detail ? ` (${detail})` : ''}`); + outcome = detail ? `${why}: ${detail}` : why; + if (attempt) writeFailure({ ...attempt, step, at: Date.now(), ...(detail ? { detail } : {}) }); return 1; }; try { - const plan = inspect({ adopt: true }); + const plan = inspectNamingOwnership({ adopt: true }); if (!plan.needsPull && !plan.needsBuild && !plan.needsRestart) { outcome = `up to date at ${short(plan.target)}`; clearFailure(); @@ -780,14 +1027,19 @@ async function apply() { else if (plan.needsBuild) log('last build unknown — treating every file as changed'); // The exact commit the check saw, not whatever `git pull` would fetch now. - if (plan.needsPull && run('git', ['merge', '--ff-only', target]).status !== 0) { - return abort('pull', `git pull --ff-only to ${short(target)} failed — see scripts/update-worker.log`); + if (plan.needsPull) { + restoreRewrittenLockfile(); + const from = workerLogSize(); + if (run('git', ['merge', '--ff-only', target]).status !== 0) { + return abort('pull', `git pull --ff-only to ${short(target)} failed — see scripts/update-worker.log`, explainFailure(from)); + } } if (plan.needsBuild) { if (work.npmInstall) { log(`${because('package-lock.json')} — npm install`); - if (run('npm', ['install']).status !== 0) return abort('npm install', 'npm install failed — nothing was built or restarted'); + const from = workerLogSize(); + if (run('npm', ['install']).status !== 0) return abort('npm install', 'npm install failed — nothing was built or restarted', explainFailure(from)); } if (work.pythonDeps) { log(`${because('clicker/requirements.txt')} — refreshing python deps`); @@ -796,7 +1048,8 @@ async function apply() { // Build BEFORE restarting. A failed build leaves the running process // untouched, which is the whole point of doing it in this order. - if (!build()) return abort('build', 'build failed — not deployed, nothing was restarted'); + const from = workerLogSize(); + if (!build()) return abort('build', 'build failed — not deployed, nothing was restarted', explainFailure(from)); // .built-commit says what .next holds, so it changes the moment .next // does. From here a failed restart must not rebuild, only restart, @@ -898,6 +1151,7 @@ async function logHealth(instance, base) { async function main() { mkdirSync(path.join(ROOT, 'scripts'), { recursive: true }); trimLog(); + if (HEAL && !DRY_RUN && !heal()) return 0; return APPLY && !DRY_RUN ? apply() : check(); }