diff --git a/.gitignore b/.gitignore index 340127f..9a929b3 100644 --- a/.gitignore +++ b/.gitignore @@ -59,6 +59,13 @@ scripts/.deps-hash scripts/.python-cmd scripts/.update.lock scripts/update.log +# updater bookkeeping (scripts/update-check.mjs) +scripts/.built-commit +scripts/.update-failed +scripts/update-worker.log +# 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/ # clicker virtualenv (Linux/Pi) clicker/.venv/ diff --git a/README.md b/README.md index 1d7489e..45237f2 100644 --- a/README.md +++ b/README.md @@ -355,13 +355,32 @@ nothing updates** — signs it, and publishes the CRX and update manifest. See ## Updating -Once auto-start is installed, nothing here is manual. Every 5 minutes the update -task fetches `master`, and when it has moved it pulls, reinstalls dependencies if -`package-lock.json` or `clicker/requirements.txt` changed, rebuilds, restarts -AutoFirmer, and restarts the clicker if anything under `clicker/` changed. +Once auto-start is installed, nothing here is manual. Every minute (the +installer's default interval) the update check fetches `master`. When there is something to do, it starts a background +worker. The worker pulls, reinstalls dependencies if `package-lock.json` or +`clicker/requirements.txt` changed, rebuilds, restarts every instance, and +restarts the clicker if anything under `clicker/` changed. -**A failed build is never deployed.** The build runs before anything restarts, so -a broken push leaves the previous build serving and logs the failure instead. +**Why a check and a separate worker.** PM2 runs the check as a cron *restart*, +and a restart kills a run that is still going at the next minute boundary. An +npm install or a build takes longer than that, so doing the work in the cron +process itself got it killed half-way through. The check finishes in seconds, +and the worker runs outside PM2's process tree, where the next tick can't +reach it. + +**Deployed means built, not pulled.** `scripts/.built-commit` records the commit +`.next` was last built from, and the check compares `master` with that, not with +HEAD. A pull that was never built is therefore finished on the next check, and +so is a missing `.next/BUILD_ID`. The first time this version runs on a machine +it judges the build already on disk: one that is complete, newer than HEAD and +already serving is adopted, and anything else is rebuilt. + +**A failed build is never deployed.** The build runs before anything restarts, +and the previous build is set aside as `.next-prev` first. A failed build is +rolled back to it, so the box is left serving the previous build and a later +restart or reboot still has one. A failure is retried 15 minutes later, then +hourly until it succeeds or a new commit lands. `scripts/.update-failed` records +which step failed and when the next try is due. ### Checking it is alive @@ -378,19 +397,27 @@ cron-restart process as `stopped` with a restart count of `0` even while it is firing on schedule. Neither is evidence of a problem; `.last-check` is the signal to trust. -Everything that actually happens is appended to `scripts/update.log`. To see -what it would do without touching anything: +While a worker is running, `.last-check` says `update in progress` with its pid. +After a failure it says `waiting to retry` with the time of the next attempt. + +Everything that actually happens is appended to `scripts/update.log`. The full +npm and build output of the latest worker run is in `scripts/update-worker.log`, +which is the first place to look when an update failed. To see what it would do +without touching anything: ```powershell node scripts\update-check.mjs --dry-run ``` -To apply an update immediately rather than waiting for the next check: +To apply an update immediately in the foreground, bypassing the retry wait: ```powershell -node scripts\update-check.mjs +node scripts\update-check.mjs --apply ``` +Without `--apply` it does what the schedule does: it checks, starts a worker if +there is anything to do, and returns straight away. + ### What reloads itself, and what does not - **The extension** updates itself now. `/api/autobuyer/status` reports the diff --git a/scripts/ensure-python-deps.mjs b/scripts/ensure-python-deps.mjs index 42601c1..b201c71 100644 --- a/scripts/ensure-python-deps.mjs +++ b/scripts/ensure-python-deps.mjs @@ -27,6 +27,9 @@ function run(cmd, args, opts = {}) { cwd: ROOT, encoding: 'utf8', shell: process.platform === 'win32', + // The updater's worker is detached with no console, so without this + // every python/pip child pops a visible window on the trading desktop. + windowsHide: true, ...opts, }); } diff --git a/scripts/update-check.mjs b/scripts/update-check.mjs index 2c3ebc4..2a3b8db 100644 --- a/scripts/update-check.mjs +++ b/scripts/update-check.mjs @@ -1,36 +1,88 @@ /** - * Pull master, rebuild, restart — once per invocation. + * Keep this checkout on master: fetch, and when something needs doing, pull, + * rebuild and restart, without ever leaving a deploy half-applied. * - * A scheduled task fires this every few minutes. Deliberately not a long-lived - * loop: if a run dies, the next fire is a clean slate. + * PM2 fires this every minute (--no-autorestart --cron-restart, registered by + * install-autostart.*), and that schedule dictates the shape of the script. + * PM2's cron handler *restarts* the process, and a restart first stops a + * process that is still running: it is tree-killed at the next minute boundary. + * So anything that outlasts ~55 s (npm install, next build) used to die + * half-way through, and a kill skips `finally`. The lock stayed behind, HEAD + * had already moved at the pull (so the next run saw nothing to pull and never + * retried), and next build had already wiped .next under the live server. * - * The important guarantee is that a broken push cannot take a trading PC down. - * The build runs before anything is restarted, and a failed build stops the run - * with the previous build still serving. + * Hence two halves: * - * node scripts/update-check.mjs # normal + * CHECK (no arguments; what the cron runs) takes seconds. It fetches, decides + * whether anything needs doing, hands the work to a detached worker and + * exits. PM2 sees the process stop on its own, so the next tick has nothing + * to kill, and the worker, orphaned once this process exits, is outside the + * process tree PM2 kills. + * + * APPLY (--apply) is the worker, and is also safe to run by hand in the + * foreground. It takes the lock, re-checks under it, then pulls, installs, + * builds, restarts and warms up. + * + * "Needs doing" is judged against scripts/.built-commit, the commit .next was + * last built from, not against HEAD. HEAD moves at the pull, before the work + * that makes it real, so HEAD === origin says nothing about whether the build + * finished. + * + * A broken push still cannot take a trading PC down. The build runs before + * anything is restarted, the previous build is set aside first and put back if + * the build fails, and a failure is retried on a backoff (scripts/.update-failed) + * rather than every minute. + * + * 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 */ -import { spawnSync } from 'node:child_process'; -import { appendFileSync, existsSync, mkdirSync, readFileSync, rmSync, statSync, writeFileSync } from 'node:fs'; +import { spawn, spawnSync } from 'node:child_process'; +import { + appendFileSync, closeSync, existsSync, lstatSync, mkdirSync, openSync, readdirSync, readFileSync, + renameSync, rmdirSync, rmSync, statSync, unlinkSync, writeFileSync, writeSync, +} from 'node:fs'; +import os from 'node:os'; import path from 'node:path'; import { fileURLToPath } from 'node:url'; import { ensurePythonDeps } from './ensure-python-deps.mjs'; import { loadInstances } from './instances.mjs'; -const ROOT = path.resolve(path.dirname(fileURLToPath(import.meta.url)), '..'); +const SELF = fileURLToPath(import.meta.url); +const ROOT = path.resolve(path.dirname(SELF), '..'); const LOG_FILE = path.join(ROOT, 'scripts', 'update.log'); +const WORKER_LOG_FILE = path.join(ROOT, 'scripts', 'update-worker.log'); const LOCK_FILE = path.join(ROOT, 'scripts', '.update.lock'); const LAST_CHECK_FILE = path.join(ROOT, 'scripts', '.last-check'); +const BUILT_FILE = path.join(ROOT, 'scripts', '.built-commit'); +const FAILED_FILE = path.join(ROOT, 'scripts', '.update-failed'); +const NEXT_DIR = path.join(ROOT, '.next'); +const PREV_DIR = path.join(ROOT, '.next-prev'); +const BUILD_ID_FILE = path.join(NEXT_DIR, 'BUILD_ID'); const BRANCH = process.env.AUTOFIRMER_BRANCH ?? 'master'; // One checkout, one build — but possibly several PM2 processes to restart and // warm afterwards (see scripts/instances.mjs). const INSTANCES = loadInstances(); +const APPLY = process.argv.includes('--apply'); const DRY_RUN = process.argv.includes('--dry-run'); -const STALE_LOCK_MS = 60 * 60 * 1000; +const STALE_LOCK_MS = 2 * 60 * 60 * 1000; +const LEGACY_STALE_LOCK_MS = 10 * 60 * 1000; +const LOCK_SETTLE_MS = 1000; +const FIRST_RETRY_MS = 15 * 60 * 1000; +const REPEAT_RETRY_MS = 60 * 60 * 1000; +// Bounds on the steps that wait on something else (the network, the PM2 +// daemon). Without them a stalled one holds the worker, and the lock, until the +// lock goes stale by age, and the worker that takes over then runs alongside +// 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; +const PM2_TIMEOUT_MS = 3 * 60 * 1000; const LOG_MAX_BYTES = 256 * 1024; const LOG_KEEP_LINES = 500; +const short = (commit) => (commit ? commit.slice(0, 8) : 'unknown'); + /** * Keep update.log from growing without bound. * @@ -68,12 +120,18 @@ function recordCheck(status) { } catch { /* never let bookkeeping break an update */ } } -function run(cmd, args, { capture = false } = {}) { +function run(cmd, args, { capture = false, timeout } = {}) { return spawnSync(cmd, args, { cwd: ROOT, encoding: 'utf8', stdio: capture ? 'pipe' : 'inherit', shell: process.platform === 'win32', + // The worker is detached, so on Windows it has no console of its own + // and every npm/git/pm2 child would otherwise open a visible console + // window on the trading desktop, stealing focus from the clicker. + windowsHide: true, + maxBuffer: 16 * 1024 * 1024, + timeout, }); } @@ -83,101 +141,696 @@ function git(...args) { return (r.stdout ?? '').trim(); } +/** git fetch, bounded: git sets no network timeout of its own, so a stalled + * connection would otherwise wait forever (see FETCH_TIMEOUT_MS). */ +function fetchOrigin() { + const r = run('git', ['fetch', 'origin', BRANCH], { capture: true, timeout: FETCH_TIMEOUT_MS }); + if (r.status === 0) return; + const why = r.error?.code === 'ETIMEDOUT' ? `timed out after ${FETCH_TIMEOUT_MS / 1000} s` : (r.stderr ?? '').trim(); + throw new Error(`git fetch origin ${BRANCH} failed: ${why}`); +} + +/** A complete build: BUILD_ID alone is not proof. next build writes it before + * static generation, so a build killed late has one; export-marker.json is + * among the last things it writes. */ +const buildComplete = (dir) => existsSync(path.join(dir, 'BUILD_ID')) && existsSync(path.join(dir, 'export-marker.json')); + +/** Block for a moment without an event loop turn (retries on Windows only). */ +function sleepSync(ms) { + Atomics.wait(new Int32Array(new SharedArrayBuffer(4)), 0, 0, ms); +} + +/** + * renameSync with the retries Windows needs. Defender or the search indexer + * briefly holding a handle inside the directory turns a rename into + * EPERM/EBUSY/EACCES, and unlike rmSync there is no maxRetries option. + */ +function renameWithRetries(from, to) { + for (let attempt = 1; ; attempt++) { + try { + renameSync(from, to); + return; + } catch (err) { + const transient = ['EPERM', 'EBUSY', 'EACCES'].includes(err.code); + if (process.platform !== 'win32' || !transient || attempt >= 10) throw err; + sleepSync(attempt * 200); + } + } +} + +/** + * Delete a build directory without ever following a link out of it. + * + * .next/node_modules holds links into the real node_modules for the external + * packages (better-sqlite3, ws, undici, signalr) — symlinks on macOS/Linux, + * possibly junctions on Windows. A recursive delete that followed one would + * empty ROOT/node_modules/better-sqlite3, and the next restart would crash-loop + * until someone ran npm install. So walk the tree with lstat and unlink every + * link as a link (lstat reports Windows junctions as symbolic links too); only + * real files and directories are removed by content. + */ +function removeDir(dir) { + let st; + try { st = lstatSync(dir); } catch (err) { if (err.code === 'ENOENT') return; throw err; } + if (st.isSymbolicLink()) { removeLink(dir); return; } + if (!st.isDirectory()) { rmSync(dir, { force: true, maxRetries: 10, retryDelay: 200 }); return; } + for (const name of readdirSync(dir)) removeDir(path.join(dir, name)); + // Now empty. Windows can briefly refuse (indexer/Defender handles). + for (let attempt = 1; ; attempt++) { + try { + rmdirSync(dir); + return; + } catch (err) { + if (err.code === 'ENOENT') return; + const transient = ['EPERM', 'EBUSY', 'EACCES', 'ENOTEMPTY'].includes(err.code); + if (process.platform !== 'win32' || !transient || attempt >= 10) throw err; + sleepSync(attempt * 200); + } + } +} + +/** A symlink unlinks; a Windows junction (a directory link) needs rmdir, which + * removes the link itself and never touches its target. */ +function removeLink(link) { + try { + unlinkSync(link); + } catch (err) { + if (process.platform === 'win32' && ['EPERM', 'EISDIR', 'EACCES'].includes(err.code)) rmdirSync(link); + else if (err.code !== 'ENOENT') throw err; + } +} + // ── lock ──────────────────────────────────────────────────────────────────── // A build outlasts the schedule interval, so overlapping runs are otherwise a -// certainty rather than a risk. -function acquireLock() { - if (existsSync(LOCK_FILE)) { - const age = Date.now() - Number(readFileSync(LOCK_FILE, 'utf8').trim() || 0); - if (age < STALE_LOCK_MS) return false; - log(`clearing a stale lock (${Math.round(age / 60000)} min old)`); +// certainty rather than a risk. Only APPLY takes the lock; CHECK only looks. + +function pidAlive(pid) { + try { + process.kill(pid, 0); + return true; + } catch (err) { + return err.code === 'EPERM'; // exists, just not ours to signal } - writeFileSync(LOCK_FILE, String(Date.now())); - return true; } -const releaseLock = () => { try { rmSync(LOCK_FILE, { force: true }); } catch { /* ignore */ } }; -async function main() { - mkdirSync(path.join(ROOT, 'scripts'), { recursive: true }); - trimLog(); +/** + * Whether anything is left in the process group `pid` led. A worker is a group + * leader (startWorker spawns it detached, and a shell gives a foreground run a + * group of its own), and its npm and next build children are in that group, so + * they outlive a worker that is killed on its own. POSIX only: Windows has no + * process groups to ask, and says no. + */ +function groupAlive(pid) { + if (process.platform === 'win32' || pid <= 1) return false; + try { + process.kill(-pid, 0); + return true; + } catch (err) { + return err.code === 'EPERM'; + } +} - if (!DRY_RUN && !acquireLock()) { - console.log('another update is already running — exiting'); +/** + * Who holds the lock, and whether they still can. null = no lock. + * + * The pid check is what matters: a worker killed outright (or a machine + * rebooted mid-update) never reaches its `finally`, and waiting out an age + * limit would hold every later update back for it. The age limit is the + * backstop for a worker that is alive but wedged, and for a pid reused by an + * unrelated process. + * + * A dead pid is not the whole story, though. A worker killed on its own leaves + * its build running, still writing into .next, and a worker that took over + * would pull .next out from under it and start a second build into the same + * directory. So the lock stays held until the dead worker's process group is + * empty too (orphaned: true). + * + * Age and "taken before the last boot" are measured on the uptime clock the + * lock records, not on the wall clock. The wall clock can step by hours under + * a live worker: a Pi has no RTC and jumps forward at its first NTP sync after + * boot, and a VM resumed from a pause does the same. A jump must never make a + * running worker's lock look abandoned, because the worker that took over + * would put .next-prev back under the first one's build, and both would build + * and restart. Uptime only goes backwards across a reboot. + */ +function readLock() { + let raw; + let mtime; + try { + raw = readFileSync(LOCK_FILE, 'utf8').trim(); + mtime = statSync(LOCK_FILE).mtimeMs; + } catch { + return null; + } + let info = null; + try { info = JSON.parse(raw); } catch { /* legacy, or caught between create and write */ } + + if (info && typeof info === 'object' && Number.isInteger(info.pid)) { + const upNow = os.uptime(); + const upThen = Number(info.uptime); + const hasUptime = Number.isFinite(upThen) && upThen > 0; + const rebooted = hasUptime && upNow < upThen; + const age = hasUptime && !rebooted + ? (upNow - upThen) * 1000 + : Date.now() - (Number(info.startedAt) || mtime); + const mins = Math.round(age / 60000); + if (!pidAlive(info.pid)) { + // Nothing outlives a reboot, and the age limit caps a wedged + // orphaned build just as it caps a wedged worker. + if (!rebooted && age <= STALE_LOCK_MS && groupAlive(info.pid)) return { stale: false, pid: info.pid, age, orphaned: true }; + return { stale: true, pid: info.pid, age, why: `pid ${info.pid} is gone, ${mins} min old` }; + } + if (rebooted) return { stale: true, pid: info.pid, age, why: 'taken before the last boot' }; + if (age > STALE_LOCK_MS) return { stale: true, pid: info.pid, age, why: `pid ${info.pid} has held it for ${mins} min` }; + return { stale: false, pid: info.pid, age }; + } + + // The pre-worker version of this script wrote a bare Date.now(). It ran + // under the cron, which kills it at the next minute boundary, so one of + // those locks older than a few minutes was left by a killed run, and the + // box behind it may be sitting on a wiped .next. Waiting the old hour out + // before repairing it would be the wrong trade. An empty file is a new lock + // caught between create and write; its mtime is as good as a timestamp. + const since = /^\d+$/.test(raw) ? Number(raw) : mtime; + const age = Date.now() - since; + if (age < LEGACY_STALE_LOCK_MS) return { stale: false, pid: null, age }; + return { stale: true, pid: null, age, why: `left by an older updater, ${Math.round(age / 60000)} min old` }; +} + +/** Whether the lock on disk names this process. */ +function ownsLock() { + try { + return JSON.parse(readFileSync(LOCK_FILE, 'utf8')).pid === process.pid; + } catch { + return false; // absent or unreadable: not ours + } +} + +/** + * Atomic create ('wx'), so two workers can never both believe they won. + * + * Breaking a stale lock is not atomic, though: it is a read, then a delete. + * Workers racing over the same stale lock (two checks at once, or a check and + * a by-hand --apply) each judge it stale, and a later one's delete then removes + * the lock an earlier one has just created, so several carry on at once. The + * delete follows its read at once (nothing, not even the log line, sits + * between them), so after a pause the file names the one worker that really + * holds the lock, and the rest back off. + */ +function acquireLock() { + for (let attempt = 0; attempt < 2; attempt++) { + try { + const fd = openSync(LOCK_FILE, 'wx'); + try { + writeSync(fd, JSON.stringify({ pid: process.pid, startedAt: Date.now(), uptime: os.uptime() })); + } finally { + closeSync(fd); + } + sleepSync(LOCK_SETTLE_MS); + return ownsLock(); + } catch (err) { + if (err.code !== 'EEXIST') throw err; + } + const lock = readLock(); + if (lock && !lock.stale) return false; + // No lock by now means its holder just released it: nothing to delete, + // and a delete here could only hit a lock someone made since. + if (lock) { + rmSync(LOCK_FILE, { force: true }); + log(`clearing a stale lock (${lock.why})`); + } + } + return false; +} + +/** Remove the lock only if it is still ours. One taken over as stale belongs to its new holder. */ +function releaseLock() { + if (!ownsLock()) return; + try { rmSync(LOCK_FILE, { force: true }); } catch { /* already gone */ } +} + +// ── failure record ────────────────────────────────────────────────────────── +// scripts/.update-failed = { target, step, at, count, restart, clicker }. +// +// Written when an attempt STARTS and deleted when it succeeds, so a worker +// that dies without reporting (killed, rebooted) still counts as a failed +// attempt. Without that a crash would be retried every minute (the first one +// is retried at once, see retryAt, but only the first). `restart` +// marks a target whose build finished but whose restarts did not; the check +// has no other way to see that, because .built-commit already matches. + +function readFailure() { + try { + const f = JSON.parse(readFileSync(FAILED_FILE, 'utf8')); + return f && typeof f === 'object' && typeof f.target === 'string' ? f : null; + } catch { + return null; + } +} +function writeFailure(f) { + try { writeFileSync(FAILED_FILE, JSON.stringify(f) + '\n'); } catch { /* bookkeeping */ } +} +function clearFailure() { + try { rmSync(FAILED_FILE, { force: true }); } catch { /* bookkeeping */ } +} +/** 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 + * on its own. + * + * A first attempt that never reported (still 'started': its worker was + * killed, or the machine went down under it) is retried at once instead. That + * is a reboot or a person far more often than the update itself, and until + * the retry the only complete build may be the one set aside in .next-prev, + * where neither a restart nor a boot can find it: after a reboot mid-build + * the instances would sit on a partial .next for the whole backoff. A second + * death is a pattern, and waits like any other failure. */ +const retryAt = (f) => Number(f.at) + (f.count > 1 ? REPEAT_RETRY_MS : f.step === 'started' ? 0 : FIRST_RETRY_MS); + +// ── what is deployed ──────────────────────────────────────────────────────── + +/** + * When HEAD last moved (epoch ms), or null when there is no way to tell. + * The reflog's own timestamp, not the commit date: what matters is when this + * checkout changed, not when the commit was written. + * + * The selector is picked out of the default output (" HEAD@{}: ...") + * rather than asked for with --format=%gd: on Windows this goes through cmd, + * and a % on a cmd command line is one typo away from variable expansion. A + * git too old for --date=unix prints HEAD@{0}, which would read as "HEAD never + * moved" and adopt anything, hence the sanity bound. + */ +function headMovedAt() { + try { + const m = /HEAD@\{(\d+)\}/.exec(git('reflog', '-1', '--date=unix')); + if (m && Number(m[1]) > 1e9) return Number(m[1]) * 1000; + } catch { /* no reflog: fall through */ } + try { + const head = readFileSync(path.join(ROOT, '.git', 'HEAD'), 'utf8').trim(); + const ref = /^ref: (.+)$/.exec(head)?.[1]; + return statSync(path.join(ROOT, '.git', ref ?? 'HEAD')).mtimeMs; + } 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 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) + .map((p) => p.name); +} + +/** + * The commit .next was built from: { commit } or { commit: null, why }. + * + * scripts/.built-commit is written only after `npm run build` succeeds. When it + * is absent (every machine, the first time this version runs) the build on + * disk is judged instead. Adopting it as HEAD avoids a pointless rebuild and + * restart on every healthy machine. Anything doubtful counts as unknown, and + * unknown means rebuild. That is what rescues machines the old updater + * stranded: their HEAD already equals origin, but their build is stale, + * partial or missing. + */ +function builtCommit(head, { adopt }) { + try { + const recorded = readFileSync(BUILT_FILE, 'utf8').trim(); + if (/^[0-9a-f]{40}([0-9a-f]{24})?$/.test(recorded)) return { commit: recorded }; + } catch { /* absent: first run of this version on this machine */ } + + if (!buildComplete(NEXT_DIR)) return { commit: null, why: 'no complete build on disk' }; + const builtAt = statSync(BUILD_ID_FILE).mtimeMs; + const movedAt = headMovedAt(); + if (movedAt === null) return { commit: null, why: 'cannot tell when HEAD last moved' }; + if (builtAt < movedAt) return { commit: null, why: 'the build on disk is older than HEAD' }; + // Built after HEAD moved, but a run killed between the build and the + // restarts leaves the old processes serving the new .next. + const behind = instancesStartedBefore(builtAt); + if (behind.length) return { commit: null, why: `${behind.join(', ')} started before the build on disk` }; + + if (adopt) { + writeFileSync(BUILT_FILE, head + '\n'); + log(`adopted the build on disk as ${short(head)} (first run with scripts/.built-commit)`); + } + return { commit: head }; +} + +function isAncestor(a, b) { + const r = run('git', ['merge-base', '--is-ancestor', a, b], { capture: true }); + if (r.status === 0) return true; + if (r.status === 1) return false; + throw new Error(`git merge-base failed: ${(r.stderr ?? '').trim()}`); +} + +/** Files changed from→to, or null when `from` is unknown (treat everything as changed). */ +function changedFiles(from, to) { + if (!from) return null; + if (from === to) return []; + try { + return git('diff', '--name-only', from, to).split('\n').filter(Boolean); + } catch { + return null; // e.g. the recorded commit is gone + } +} + +/** Fetch and work out what, if anything, needs doing. Shared by CHECK and APPLY. */ +function inspect({ adopt }) { + fetchOrigin(); + const local = git('rev-parse', 'HEAD'); + const remote = git('rev-parse', `origin/${BRANCH}`); + // A checkout AHEAD of origin (a commit made on this machine) has nothing to + // pull. `pull --ff-only` would "succeed" as a no-op and the old updater then + // rebuilt and restarted on every tick. + const needsPull = local !== remote && !isAncestor(remote, local); + const target = needsPull ? remote : local; + const built = builtCommit(local, { adopt }); + // Complete, not merely present: a build of the SAME commit killed after + // BUILD_ID was written (a by-hand `npm run build`, or a worker redoing a + // missing build) would otherwise pass for up to date indefinitely. + const buildMissing = !buildComplete(NEXT_DIR); + const needsBuild = built.commit !== target || buildMissing; + const failed = readFailure(); + const pending = failed?.target === target ? failed : null; + const needsRestart = !needsBuild && pending?.restart === true; + return { local, remote, target, needsPull, built, buildMissing, needsBuild, needsRestart, pending }; +} + +function describe(plan) { + if (plan.needsPull) return `${short(plan.local)} -> ${short(plan.remote)}`; + if (plan.needsBuild) { + const why = plan.buildMissing ? 'no complete build on disk' : plan.built.why ?? `last built ${short(plan.built.commit)}`; + return `rebuild ${short(plan.target)} (${why})`; + } + return `restart onto ${short(plan.target)} (the last restart did not complete)`; +} + +/** Which of the optional steps this plan needs. */ +function workFor(plan) { + const changed = changedFiles(plan.built.commit, plan.target); + const touched = (f) => changed === null || changed.includes(f); + return { + changed, + npmInstall: plan.needsBuild && touched('package-lock.json'), + pythonDeps: plan.needsBuild && touched('clicker/requirements.txt'), + restartClicker: plan.needsBuild + ? changed === null || changed.some((f) => f.startsWith('clicker/')) + : plan.needsRestart && plan.pending?.clicker === true, + }; +} + +// ── build ─────────────────────────────────────────────────────────────────── + +/** + * npm run build, with the previous build set aside so a failure can be undone. + * + * next build empties .next as its first step, under the live server, whatever + * we do. Renaming it to .next-prev first costs nothing extra, and it means a + * FAILED build can be rolled back instead of leaving the box on a half-written + * .next that a restart or a reboot would then crash-loop on. When the rename + * is refused (Windows, something holding a handle), build in place without a + * safety net rather than not update at all. + */ +function build() { + // A worker that died between setting the old build aside and putting it + // back leaves the only complete build in .next-prev. Restore it first, or + // the cleanup below would delete it. If it can't be put back, it stays + // where it is (clearing it would leave no complete build anywhere), this + // build runs in place, and a failure tries the restore once more. + let prevIsOnlyBuild = false; + if (buildComplete(PREV_DIR) && !buildComplete(NEXT_DIR)) { + try { + removeDir(NEXT_DIR); + renameWithRetries(PREV_DIR, NEXT_DIR); + log('put back the previous build left in .next-prev by an interrupted update'); + } catch (err) { + prevIsOnlyBuild = true; + log(`could not put back .next-prev (${err.code ?? err.message}) — leaving it there and building in place`); + } + } + + let backedUp = false; + const hadBuild = existsSync(NEXT_DIR); + if (hadBuild && !prevIsOnlyBuild) { + try { + removeDir(PREV_DIR); + renameWithRetries(NEXT_DIR, PREV_DIR); + backedUp = true; + } catch (err) { + log(`could not set the previous build aside (${err.code ?? err.message}) — building in place, no rollback this time`); + } + } + // next build keeps .next/cache (the incremental type-check state among it) + // from one build to the next. Carry it over so setting .next aside doesn't + // make every build a cold one. Best effort: without it a build is only + // slower. Not carried back on failure, so a retry starts from a clean cache. + if (backedUp) { + try { + mkdirSync(NEXT_DIR); + renameSync(path.join(PREV_DIR, 'cache'), path.join(NEXT_DIR, 'cache')); + } catch { /* a cold build */ } + } + + log('building'); + if (run('npm', ['run', 'build']).status === 0) return true; + + if (backedUp || prevIsOnlyBuild) { + try { + removeDir(NEXT_DIR); + renameWithRetries(PREV_DIR, NEXT_DIR); + log('build failed — restored the previous build'); + } catch (err) { + log(`build failed, and restoring the previous build failed too (${err.code ?? err.message}) — it is still in .next-prev`); + } + } else if (hadBuild) { + log('build failed — it ran in place, so there is no previous build to restore'); + } else { + log('build failed — there was no previous build to restore'); + } + return false; +} + +function removePrevBuild() { + if (!existsSync(PREV_DIR)) return; + try { + removeDir(PREV_DIR); + } catch (err) { + log(`could not remove .next-prev (${err.code ?? err.message}) — the next build clears it`); + } +} + +// ── check ─────────────────────────────────────────────────────────────────── + +/** + * Start `update-check.mjs --apply` detached, logging to update-worker.log. + * The log is truncated per run: it holds the full npm/next output of the + * latest attempt, the first place to look when one fails. + */ +function startWorker() { + let out = 'ignore'; + try { out = openSync(WORKER_LOG_FILE, 'w'); } catch { /* run it without a log rather than not at all */ } + try { + const child = spawn(process.execPath, [SELF, '--apply'], { + cwd: ROOT, + detached: true, + windowsHide: true, + stdio: ['ignore', out, out], + }); + child.on('error', () => { /* surfaces below as the missing pid */ }); + child.unref(); + if (!child.pid) throw new Error('could not start the update worker'); + return child.pid; + } finally { + if (typeof out === 'number') closeSync(out); + } +} + +function dryRunReport(plan) { + const work = workFor(plan); + log(`update available: ${describe(plan)}`); + if (work.changed) log(`${work.changed.length} file(s) changed since the last build`); + log('dry run — stopping before any change'); + const restarts = plan.needsBuild || plan.needsRestart; + log(`would run: ${[ + plan.needsPull && 'git pull --ff-only', + work.npmInstall && 'npm install', + work.pythonDeps && 'pip install', + plan.needsBuild && 'npm run build', + ...(restarts ? INSTANCES.map((i) => `pm2 restart ${i.name}`) : []), + work.restartClicker && 'pm2 restart clicker', + ].filter(Boolean).join(', ')}`); + if (plan.pending) { + log(`last attempt at ${short(plan.target)}: ${plan.pending.step} (attempt ${plan.pending.count}); next automatic try after ${new Date(retryAt(plan.pending)).toISOString()}`); + } +} + +function check() { + const lock = readLock(); + if (lock && !lock.stale) { + const who = !lock.pid ? 'an older updater' + : lock.orphaned ? `the build left by dead worker pid ${lock.pid}` + : `worker pid ${lock.pid}`; + console.log(`an update is already running (${who}) — exiting`); + if (!DRY_RUN) recordCheck(`update in progress (${who}, ${Math.round(lock.age / 60000)} min)`); return 0; } - let outcome = 'interrupted'; - + let outcome = null; try { - git('fetch', 'origin', BRANCH); - const local = git('rev-parse', 'HEAD'); - const remote = git('rev-parse', `origin/${BRANCH}`); - - if (local === remote) { - outcome = `up to date at ${local.slice(0, 8)}`; - return 0; // silent in the log by design - } - - log(`update available: ${local.slice(0, 8)} -> ${remote.slice(0, 8)}`); - const changed = git('diff', '--name-only', local, remote).split('\n').filter(Boolean); - log(`${changed.length} file(s) changed`); - - if (DRY_RUN) { - log('dry run — stopping before any change'); - log(`would run: ${[ - changed.includes('package-lock.json') && 'npm install', - changed.includes('clicker/requirements.txt') && 'pip install', - 'npm run build', - ...INSTANCES.map((i) => `pm2 restart ${i.name}`), - changed.some((f) => f.startsWith('clicker/')) && 'pm2 restart clicker', - ].filter(Boolean).join(', ')}`); + const plan = inspect({ 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); return 0; } - - git('pull', '--ff-only', 'origin', BRANCH); - - if (changed.includes('package-lock.json')) { - log('package-lock.json changed — npm install'); - if (run('npm', ['install']).status !== 0) { log('ABORTED: npm install failed'); outcome = 'npm install failed'; return 1; } + if (DRY_RUN) { + dryRunReport(plan); + return 0; } - - if (changed.includes('clicker/requirements.txt')) { - log('clicker/requirements.txt changed — refreshing python deps'); - ensurePythonDeps({ log: (m) => log(m) }); // non-fatal by design + // 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()}`; + return 0; } - - // Build BEFORE restarting. A failed build leaves the running process - // untouched, which is the whole point of doing it in this order. - log('building'); - if (run('npm', ['run', 'build']).status !== 0) { - log('ABORTED: build failed — the previous build is still serving, nothing was restarted'); - outcome = 'build failed — not deployed'; - return 1; - } - - for (const instance of INSTANCES) { - log(`restarting ${instance.name}`); - if (run('pm2', ['restart', instance.name]).status !== 0) { log(`pm2 restart ${instance.name} failed`); outcome = 'pm2 restart failed'; return 1; } - } - - if (changed.some((f) => f.startsWith('clicker/'))) { - log('clicker changed — restarting it too'); - run('pm2', ['restart', 'clicker']); - } - - await warmUp(); - log(`updated to ${remote.slice(0, 8)}`); - outcome = `updated to ${remote.slice(0, 8)}`; + const pid = startWorker(); + log(`update available: ${describe(plan)} — started worker pid ${pid}`); + outcome = `worker pid ${pid} started: ${describe(plan)}`; return 0; } catch (err) { log(`ERROR: ${err.message}`); outcome = `ERROR: ${err.message}`; return 1; } finally { - if (!DRY_RUN) { - releaseLock(); - recordCheck(outcome); + if (!DRY_RUN && outcome) recordCheck(outcome); + } +} + +// ── apply ─────────────────────────────────────────────────────────────────── + +/** + * A kill skips `finally`, so the lock is released here too. The next check + * then retries after the usual backoff instead of waiting out a stale lock. + * Node runs this on the event loop, so it never lands in the middle of a + * spawnSync. An interrupted build still comes back through build()'s restore. + */ +function interrupted(signal) { + log(`${signal} — stopping; lock released${readFailure() ? ', the next check retries after the backoff' : ''}`); + releaseLock(); + recordCheck(`interrupted by ${signal}`); + process.exit(1); +} + +async function apply() { + let locked; + try { + locked = acquireLock(); + } catch (err) { + log(`ERROR: could not take the update lock: ${err.message}`); + return 1; + } + if (!locked) { + console.log('another update is already running — exiting'); + return 0; + } + for (const signal of ['SIGINT', 'SIGTERM', 'SIGHUP']) process.on(signal, () => interrupted(signal)); + + let outcome = 'interrupted'; + let attempt = null; + const abort = (step, why) => { + log(`ABORTED: ${why}`); + outcome = why; + if (attempt) writeFailure({ ...attempt, step, at: Date.now() }); + return 1; + }; + + try { + const plan = inspect({ adopt: true }); + if (!plan.needsPull && !plan.needsBuild && !plan.needsRestart) { + outcome = `up to date at ${short(plan.target)}`; + clearFailure(); + return 0; } + const { target } = plan; + const work = workFor(plan); + const because = (what) => (work.changed ? `${what} changed` : 'last build unknown'); + attempt = { + target, + step: 'started', + at: Date.now(), + count: (plan.pending?.count ?? 0) + 1, + restart: plan.needsRestart, + clicker: plan.needsRestart && plan.pending?.clicker === true, + }; + writeFailure(attempt); + + log(`applying ${describe(plan)} (worker pid ${process.pid}, attempt ${attempt.count})`); + if (work.changed) log(`${work.changed.length} file(s) changed since the last build`); + 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.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'); + } + if (work.pythonDeps) { + log(`${because('clicker/requirements.txt')} — refreshing python deps`); + ensurePythonDeps({ log: (m) => log(m) }); // non-fatal by design + } + + // 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'); + + // .built-commit says what .next holds, so it changes the moment .next + // does. From here a failed restart must not rebuild, only restart, + // which the `restart` flag on the attempt tells the next check. + writeFileSync(BUILT_FILE, target + '\n'); + attempt = { ...attempt, step: 'restart', at: Date.now(), restart: true, clicker: work.restartClicker }; + writeFailure(attempt); + } + + if (plan.needsBuild || plan.needsRestart) { + for (const instance of INSTANCES) { + log(`restarting ${instance.name}`); + if (run('pm2', ['restart', instance.name], { timeout: PM2_TIMEOUT_MS }).status !== 0) return abort('restart', `pm2 restart ${instance.name} failed`); + } + if (work.restartClicker) { + log(`${because('clicker')} — restarting it too`); + run('pm2', ['restart', 'clicker'], { timeout: PM2_TIMEOUT_MS }); + } + } + + removePrevBuild(); + clearFailure(); + await warmUp(); + log(`updated to ${short(target)}`); + outcome = `updated to ${short(target)}`; + return 0; + } catch (err) { + log(`ERROR: ${err.message}`); + outcome = `ERROR: ${err.message}`; + if (attempt) writeFailure({ ...attempt, step: 'error', at: Date.now() }); + return 1; + } finally { + releaseLock(); + recordCheck(outcome); } } @@ -205,7 +858,47 @@ async function warmUp() { } catch (err) { log(`${instance.name}: post-restart check failed: ${err.message}`); } + await logHealth(instance, base); } } +/** + * One line from /api/health, when the build has it. Informational only: right + * after a restart the clients may not have synced yet, so this never fails an + * update. Parsed loosely, because the endpoint may be newer than this script. + */ +async function logHealth(instance, base) { + let res; + try { + res = await fetch(`${base}/api/health`, { signal: AbortSignal.timeout(10_000) }); + } catch { + return; + } + if (res.status === 404) return; // a build from before the endpoint + let body = null; + try { body = await res.json(); } catch { /* not JSON: the status alone */ } + const parts = [`HTTP ${res.status}`]; + if (typeof body?.ok === 'boolean') parts.push(body.ok ? 'ok' : 'NOT ok'); + // A tradable firm with no client (no credentials yet) is listed with + // hasClient: false and is not something that failed to sync. + const listed = Array.isArray(body?.clients) ? body.clients : Array.isArray(body) ? body : null; + const clients = listed?.filter((c) => c?.hasClient !== false); + if (clients) { + const now = Date.now(); + const ready = clients.filter((c) => { + if (typeof c?.ready === 'boolean') return c.ready; + const h = c?.health ?? c; + return h?.syncComplete === true && h.lastSyncAt > 0 && now - h.lastSyncAt < 5 * 60_000; + }).length; + parts.push(`${ready}/${clients.length} client(s) synced`); + } + log(`${instance.name}: health ${parts.join(', ')}`); +} + +async function main() { + mkdirSync(path.join(ROOT, 'scripts'), { recursive: true }); + trimLog(); + return APPLY && !DRY_RUN ? apply() : check(); +} + process.exit(await main());