From 472fc82e2b5e3dc3adee7ddfd14891ea3fb2b370 Mon Sep 17 00:00:00 2001 From: Teknium <127238744+teknium1@users.noreply.github.com> Date: Sun, 4 Oct 2026 07:13:31 -0700 Subject: [PATCH] fix(desktop): update gate stops waiting on a held checkout at the scripts' 7200 s ceiling A dead marker whose checkout lock a leftover process still holds (`held` / `busy` from the script helper) parked the Desktop with no deadline (review R6 m7): a lock leaked into a long-lived process held start-up hostage while the scripts themselves give up after RELEASE_WAIT_S = 7200 s. The gate's marker probe now counts a held wait from the marker's line 2 (the last time an owner wrote it), or from the first sighting in this process for an unreadable line 2, and stops blocking after HELD_CEILING_MS = 7200 s: it logs it once, reports it through onHeld, and leaves the marker untouched (A7: the Desktop never mutates it). While held, boot progress names the update process that exited and the time left; past the ceiling a non-blocking dialog tells the user what still holds the install and how to move on. A helper `live ` keeps no ceiling (C1 rule 3). The ceiling is a test seam option, not an env var. (cherry picked from commit ac513e33ce0f5c99338d51607f894cf0dc3b4a8c) --- apps/desktop/electron/main.ts | 42 +++++- apps/desktop/electron/update-gate.ts | 4 +- .../electron/update-marker-gate.test.ts | 70 ++++++++- apps/desktop/electron/update-marker-gate.ts | 140 ++++++++++++++++-- 4 files changed, 237 insertions(+), 19 deletions(-) diff --git a/apps/desktop/electron/main.ts b/apps/desktop/electron/main.ts index 04a6ee0f1b..ba399cbe74 100644 --- a/apps/desktop/electron/main.ts +++ b/apps/desktop/electron/main.ts @@ -598,7 +598,7 @@ import { updateHandoffConflict, writeUpdateMarker } from './update-marker' -import { liveMarkerProbe } from './update-marker-gate' +import { heldCeilingNotice, type HeldState, heldWaitMessage, liveMarkerProbe } from './update-marker-gate' import { updateConnectionsBeforeLocal } from './update-order' import { resolveUpdaterMechanism, @@ -2997,7 +2997,10 @@ const UPDATE_HANDOFF_DWELL_MS = 2500 // The hand-off state closes the later Windows `cmd start` wrapper gap: the // wrapper exits 0 before the real PowerShell script claims the marker, and // `finally` clears updateInFlight immediately after the hand-off is accepted. -function updateGateDeps(onLiveMarker?: (marker: { startedAt: number | null }) => void) { +function updateGateDeps( + onLiveMarker?: (marker: { startedAt: number | null }) => void, + onHeld?: (state: HeldState) => void +) { // One creation-time probe per pid for this wait: on Windows each probe is a // powershell spawn and the gate polls every second. const createTime = cachedCreateTimeProbe() @@ -3013,6 +3016,7 @@ function updateGateDeps(onLiveMarker?: (marker: { startedAt: number | null }) => hermesHome: HERMES_HOME, createTime, onLiveMarker, + onHeld, log: rememberLog, reclaim: async () => { const updateRoot = resolveUpdateRoot() @@ -3091,8 +3095,20 @@ async function waitForUpdateToFinish() { // Marker line 2 of the run this boot parked on: the result we report is that // run's, never an older one (C2 started_at match). let parkedRunStartedAt: number | null = null + // A dead marker whose checkout a leftover process still holds (R6): its + // state this poll, and whether its ceiling let us through (review R6 m7). + let held: HeldState | null = null + let heldExpired: HeldState | null = null - const outcome = await waitForUpdateClearance(updateGateDeps(marker => (parkedRunStartedAt = marker.startedAt)), { + const gateDeps = updateGateDeps( + marker => (parkedRunStartedAt = marker.startedAt), + state => { + held = state + heldExpired = state.expired ? state : heldExpired + } + ) + + const outcome = await waitForUpdateClearance(gateDeps, { signal: localBackendLifecycle.signal, onWaitTick: async (reason, waitedMs) => { if (!announced) { @@ -3100,6 +3116,15 @@ async function waitForUpdateToFinish() { rememberLog(`[updates] update in progress (${reason}); deferring backend start until it finishes`) } + const heldNow = held + held = null + + if (reason === 'marker' && heldNow) { + await advanceBootProgress('backend.update-wait', heldWaitMessage(heldNow), 12) + + return + } + // A live update owner is waited out, never aged out (C1 rule 3): booting // a backend into a half-replaced runtime is the failure this gate exists // for. Past the old ceiling, say so instead of silently counting down. @@ -3199,6 +3224,17 @@ async function waitForUpdateToFinish() { localBackendLifecycle.assertCanStart() } + if (heldExpired) { + // The way forward when the gate stopped waiting on a held checkout: boot + // goes on (non-blocking dialog); the marker stays for the scripts/Python. + void dialog.showMessageBox({ + type: 'warning', + title: 'Hermes update', + message: 'Hermes started while an earlier update still holds the install', + detail: heldCeilingNotice(heldExpired) + }) + } + if (outcome === 'clear') { return false } diff --git a/apps/desktop/electron/update-gate.ts b/apps/desktop/electron/update-gate.ts index d176de80bb..7241e9f867 100644 --- a/apps/desktop/electron/update-gate.ts +++ b/apps/desktop/electron/update-gate.ts @@ -85,7 +85,9 @@ export interface WaitForUpdateClearanceOptions { * Windows update is exactly the failure the gate exists for. The marker reader * still bounds the wait: an owner whose creation time cannot be read stops * reading live at the 20-minute ceiling (A1), so a reused pid never parks - * boot forever. + * boot forever, and a dead marker whose checkout a leftover process still + * holds (`held`) stops reading live at the scripts' 7200 s ceiling + * (update-marker-gate.ts, review R6 m7). */ export async function waitForUpdateClearance( deps: UpdateGateDeps, diff --git a/apps/desktop/electron/update-marker-gate.test.ts b/apps/desktop/electron/update-marker-gate.test.ts index b9c151fb26..96ba4162fd 100644 --- a/apps/desktop/electron/update-marker-gate.test.ts +++ b/apps/desktop/electron/update-marker-gate.test.ts @@ -12,7 +12,7 @@ import path from 'path' import { afterEach, describe, test } from 'vitest' import { markerPath } from './update-marker' -import { liveMarkerProbe } from './update-marker-gate' +import { HELD_CEILING_MS, type HeldState, heldWaitMessage, liveMarkerProbe } from './update-marker-gate' import { cleanupMarkerFixtures, deadPid, liveOwner, minutesAgo, tmpHome } from './update-marker.test-helpers' import { runMarkerHelper } from './updater/marker-helper' import { cleanupFakeCheckouts, fakeHelperCheckout } from './updater/marker-helper.test-helpers' @@ -31,14 +31,78 @@ function helperCalls(home: string): string[] { } describe.skipIf(process.platform === 'win32')('gate over a dead marker (R6)', () => { - function gate(root: string, home: string, now?: () => number) { + function gate( + root: string, + home: string, + now?: () => number, + extra: { onHeld?: (state: HeldState) => void; log?: (line: string) => void } = {} + ) { return liveMarkerProbe({ hermesHome: home, reclaim: () => runMarkerHelper('reclaim', { updateRoot: root, hermesHome: home, isWindows: false }), - now + now, + ...extra }) } + test('`held` stops blocking at the scripts\' 7200 s ceiling: told to the user, logged once, marker never touched (R6 m7)', async () => { + const { root, home } = fakeHelperCheckout() + const owner = await deadPid() + const body = `${owner}\n${minutesAgo(1)}\nct:1.000\n` + fs.writeFileSync(markerPath(home), body) + fs.writeFileSync(path.join(home, 'helper-verdict'), 'held') + let clock = Date.now() + const states: HeldState[] = [] + const logs: string[] = [] + const hasLiveMarker = gate(root, home, () => clock, { onHeld: s => states.push(s), log: l => logs.push(l) }) + + assert.equal(await hasLiveMarker(), true, 'held: still parked') + clock += HELD_CEILING_MS - 2 * 60_000 + assert.equal(await hasLiveMarker(), true, 'still inside the ceiling (counted from line 2, a minute ago)') + + clock += 2 * 60_000 + assert.equal(await hasLiveMarker(), false, 'past the ceiling the gate stops blocking') + assert.equal(await hasLiveMarker(), false) + assert.equal(fs.readFileSync(markerPath(home), 'utf8'), body, 'Desktop never mutates the marker (A7)') + + const [first] = states + assert.deepEqual([first.verdict, first.ownerPid, first.expired], ['held', owner, false]) + assert.ok(first.remainingMs! > HELD_CEILING_MS - 2 * 60_000, 'counted from line 2, not from boot') + assert.match(heldWaitMessage(first), new RegExp(`update \\(process ${owner}\\) exited.*still holds`)) + assert.equal(states.at(-1)!.expired, true) + assert.equal(logs.filter(l => l.includes('no longer blocking')).length, 1, 'logged once') + + assert.equal(await gate(root, home, () => clock)(), false, 'a later gate wait does not restart the ceiling') + }) + + test('a malformed held marker counts its ceiling from the first sighting, across gate waits', async () => { + const { root, home } = fakeHelperCheckout() + fs.writeFileSync(markerPath(home), `garbage-${process.pid}-${Date.now()}\n`) + fs.writeFileSync(path.join(home, 'helper-verdict'), 'busy') + let clock = Date.now() + + assert.equal(await gate(root, home, () => clock)(), true) + clock += HELD_CEILING_MS - 1_000 + assert.equal(await gate(root, home, () => clock)(), true, 'a new wait continues the same count') + clock += 1_000 + assert.equal(await gate(root, home, () => clock)(), false) + }) + + test('a helper `live ` names a live identity: no ceiling', async () => { + const { root, home } = fakeHelperCheckout() + fs.writeFileSync(markerPath(home), `${await deadPid()}\n${minutesAgo(1)}\nct:1.000\n`) + fs.writeFileSync(path.join(home, 'helper-verdict'), 'live 4242') + let clock = Date.now() + const states: HeldState[] = [] + const hasLiveMarker = gate(root, home, () => clock, { onHeld: s => states.push(s) }) + + assert.equal(await hasLiveMarker(), true) + clock += 10 * HELD_CEILING_MS + assert.equal(await hasLiveMarker(), true) + assert.equal(states.at(-1)!.remainingMs, null) + assert.equal(states.at(-1)!.livePid, 4242) + }) + test('`held` keeps the gate closed and is re-asked every 5 s; the marker is never touched', async () => { const { root, home } = fakeHelperCheckout() const body = `${await deadPid()}\n${minutesAgo(1)}\nct:1.000\n` diff --git a/apps/desktop/electron/update-marker-gate.ts b/apps/desktop/electron/update-marker-gate.ts index 021b1808e3..9b625c7b72 100644 --- a/apps/desktop/electron/update-marker-gate.ts +++ b/apps/desktop/electron/update-marker-gate.ts @@ -16,6 +16,17 @@ * The helper is asked once per distinct dead marker body per wait; a `held` / * `busy` / `live` answer is re-asked every `reprobeMs` (5 s) because only the * script can see the lock being released. + * + * `held` / `busy` have a ceiling (review R6 m7): no owner identity is alive, + * only some process still holding the checkout lock, and that can be a + * leaked long-lived one. The scripts stop waiting on it after RELEASE_WAIT_S + * (7200 s); the gate stops blocking after the same span, counted from the + * marker's line 2 (the last time an owner wrote it; the scripts keep it young + * while they live) or, when line 2 is unreadable, from the first time this + * process saw the body held. Past the ceiling the probe answers "not + * running", logs it once and reports it through `onHeld` so the caller can + * tell the user; the marker is left exactly as it is. A helper `live ` + * names a live identity and is waited out like any live marker (C1 rule 3). */ import { type CreateTimeProbe, inspectUpdateMarker } from './update-marker' @@ -23,30 +34,72 @@ import type { MarkerHelperVerdict } from './updater/marker-helper' export const HELD_REPROBE_MS = 5_000 +/** The scripts' own wait on the checkout lock (posix.sh RELEASE_WAIT_S, marker.ps1 MarkerReleaseWaitSeconds). */ +export const HELD_CEILING_MS = 7_200_000 + +/** Why a dead marker still keeps the gate closed, as the script helper put it. */ +export interface HeldState { + verdict: 'held' | 'busy' | 'live' + /** Line 1 of the marker: the update process that started it (exited), when it parses. */ + ownerPid: number | null + /** The live process the helper named (`live `), else null. */ + livePid: number | null + /** Epoch ms the ceiling counts from. */ + since: number + /** Ms until the gate stops blocking; null when there is no ceiling (`live`). */ + remainingMs: number | null + /** The ceiling passed: the gate is open and the marker untouched. */ + expired: boolean +} + export interface LiveMarkerProbeOptions { hermesHome: string /** The script helper `reclaim`, or null when the checkout's script predates protocol 2. */ reclaim: (() => Promise) | null createTime?: CreateTimeProbe onLiveMarker?: (marker: { startedAt: number | null }) => void + /** Every answer that comes from a running helper verdict (boot progress, the ceiling notice). */ + onHeld?: (state: HeldState) => void log?: (line: string) => void now?: () => number reprobeMs?: number + /** Test seam; production is HELD_CEILING_MS. */ + heldCeilingMs?: number } const STILL_RUNNING = new Set(['held', 'busy', 'live']) +// First sighting of each held body, process-wide: a later gate wait (a pool +// backend, a reconnect) continues the same ceiling instead of restarting it. +const firstHeldAt = new Map() + +function heldSince(key: string, startedAt: number | null, at: number): number { + if (!firstHeldAt.has(key)) { + if (firstHeldAt.size >= 16) { + firstHeldAt.clear() + } + + firstHeldAt.set(key, at) + } + + const written = startedAt !== null && Number.isFinite(startedAt) && startedAt > 0 ? startedAt * 1000 : Infinity + + return Math.min(firstHeldAt.get(key)!, written) +} + /** `hasLiveMarker` for one gate wait (create it per wait, never module-wide). */ export function liveMarkerProbe({ hermesHome, reclaim, createTime, onLiveMarker, + onHeld, log, now = Date.now, - reprobeMs = HELD_REPROBE_MS + reprobeMs = HELD_REPROBE_MS, + heldCeilingMs = HELD_CEILING_MS }: LiveMarkerProbeOptions): () => Promise { - const asked = new Map() + const asked = new Map() return async () => { const inspection = await inspectUpdateMarker(hermesHome, { createTime, now }) @@ -63,24 +116,87 @@ export function liveMarkerProbe({ const key = inspection.raw.toString('hex') const previous = asked.get(key) + let entry = previous - if (previous && (!previous.running || now() - previous.at < reprobeMs)) { - return previous.running + if (!previous || (STILL_RUNNING.has(previous.verdict.kind) && now() - previous.at >= reprobeMs)) { + const verdict = await reclaim() + + if (!previous || STILL_RUNNING.has(previous.verdict.kind) !== STILL_RUNNING.has(verdict.kind)) { + log?.(`[updates] dead update marker: script helper says ${verdict.kind}${'pid' in verdict ? ` ${verdict.pid}` : ''}`) + } + + entry = { ...previous, verdict, at: now() } + asked.set(key, entry) } - const verdict = await reclaim() - const running = STILL_RUNNING.has(verdict.kind) + const { verdict } = entry! - if (!previous || previous.running !== running) { - log?.(`[updates] dead update marker: script helper says ${verdict.kind}${'pid' in verdict ? ` ${verdict.pid}` : ''}`) + if (!STILL_RUNNING.has(verdict.kind)) { + return false } - asked.set(key, { running, at: now() }) + const startedAt = inspection.marker?.startedAt ?? null + const since = heldSince(key, startedAt, now()) + const remainingMs = verdict.kind === 'live' ? null : Math.max(0, since + heldCeilingMs - now()) - if (running) { - onLiveMarker?.({ startedAt: inspection.marker?.startedAt ?? null }) + const state: HeldState = { + verdict: verdict.kind as HeldState['verdict'], + ownerPid: inspection.marker?.pid ?? null, + livePid: 'pid' in verdict ? verdict.pid : null, + since, + remainingMs, + expired: remainingMs === 0 } - return running + onHeld?.(state) + + if (state.expired) { + if (!entry!.expiryLogged) { + entry!.expiryLogged = true + log?.( + `[updates] update marker still ${state.verdict} ${Math.round((now() - since) / 60_000)} min after its owner` + + `${state.ownerPid ? ` (pid ${state.ownerPid})` : ''} last wrote it; no longer blocking start-up` + + ' (the scripts stop waiting at the same ceiling). The marker is left in place.' + ) + } + + return false + } + + onLiveMarker?.({ startedAt }) + + return true } } + +function duration(ms: number): string { + const m = Math.max(1, Math.ceil(ms / 60_000)) + + return m >= 120 ? `${Math.round(m / 60)} hours` : m === 1 ? '1 minute' : `${m} minutes` +} + +/** Boot-progress text while a dead marker's checkout is still held. */ +export function heldWaitMessage(state: HeldState): string { + if (state.livePid !== null) { + return `An update is still finishing (process ${state.livePid}) — Hermes will start automatically when it completes…` + } + + const who = state.ownerPid ? `the update (process ${state.ownerPid}) exited, but a process` : 'a process' + + return ( + `An update is still finishing: ${who} it started still holds the Hermes install. ` + + `Hermes will start when that process exits, or in ${duration(state.remainingMs ?? 0)} at the latest.` + ) +} + +/** Dialog detail once the ceiling let Hermes start over a still-held checkout. */ +export function heldCeilingNotice(state: HeldState): string { + const owner = state.ownerPid ? ` (process ${state.ownerPid}, now exited)` : '' + + return ( + `An earlier update${owner} left a process that still held the Hermes install ${duration(HELD_CEILING_MS)} ` + + 'later, so Hermes started without waiting for it. The update marker was left in place.\n\n' + + 'If something looks wrong: quit Hermes, end leftover git or hermes processes (or restart the computer), ' + + 'then run the update again from Settings or with `hermes update`. Details are in logs/update.log.' + ) +}