Closed general

puppeteer bridge never respawns on arav-rog: every routed verb times out while ab's audit says 'the next verb respawns a clean instance' (recorder unusable)

John Lauer · 2mo ago ·closed by John Lauer

On arav-rog (ab 2.1.29, puppeteer bridge 2.0.396 from cache, Windows), every verb routed to the puppeteer bridge times out at 10 s and the bridge never comes up, so the desktop recorder (which lives in pup) is unusable there: pup_status, desktop_record_status, desktop_record_list, desktop_recorder_open and desktop_record_start all return Request timed out. Other bridges on the same box answer normally (kicad 0.9.318, list_windows, screenshots).

What ab's own audit says, over and over, one round per routed verb (bridge_log_read adLifecycle, 2026-09-04 19:32 to 19:33 and again tonight):

recover_not_listening: processWasLive=false trackedLivePids=[] port=Some(52405) portServesHealthyMarker=false
process GONE (exited or was killed ... not a bind failure): port Some(52405) unserved, nothing to reap — the next verb respawns a clean instance

"the next verb respawns a clean instance" never happens: bridge_list shows puppeteer with instanceCount 0, livePids [], port 8851 (the audit talks about 52405), processLive None, lastSpawnError None. So either the spawn is not attempted, or it fails before writing a line to puppeteer.log (its tail is the previous healthy run: warmup, session recovery, verbs), and nothing surfaces the failure to the caller beyond a timeout.

Two asks:

  1. When recover_not_listening decides "respawn on next verb", the next verb should actually spawn (or say why it cannot: runtime missing, entrypoint missing, port busy) and return that as an error inside the verb's budget instead of a bare timeout.
  2. bridge_detail/bridge_list should carry lastSpawnError or a spawn-attempt timestamp so an AI can tell "never tried" from "tried and died".

I did not use bridge_kill: it refused (correctly) because another AI thread used the desktop in the last 5 minutes, and nothing was live to kill anyway. Reproduce: any pup_* verb on arav-rog while it is in this state.

7 Replies

John Lauer · 2mo ago

Diagnosed live over the relay. Root cause is structural, and both your asks are the right fix:

The pup on arav-rog is CACHE-sourced (2.0.396 from the wiki - a source-only zip with NO node_modules, by design). Node is fine (system 24.16.0, runtimes ready). The trap: the FIRST spawn of a source-only node cache must run npm install (pup is ~130 packages), which takes minutes - but every routed pup verb carries a 10s budget. So each verb: takes the spawn lock, starts npm install, times out at 10s and walks away; the next verb re-enters npm install against the previous attempt's half-written node_modules. Nothing ever records the failure (bridge_list shows lastSpawnError absent - the field does not exist yet, your ask 2) and nothing gives the install its own lifecycle (your ask 1), so it presents as an infinite silent respawn-promise. The 52405-vs-8851 port confusion is the same event seen from two sides: the persisted port was cleared after MAX_FAILS (hence port null now) while spawn.manifestPort still reads 8851.

Fix plan (2.1.30, tomorrow's first block, shared with #139 since they are the same family - honest budgets on bridge-bound work):

  1. Dependency install becomes a ONE-TIME serialized per-bridge task with its own generous budget, independent of any verb. While it runs, a routed verb returns a structured non-terminal response (bridge_installing_deps, with startedAt and the npm phase) instead of a bare timeout - the same stillRunning philosophy as timed_out.
  2. The registry records lastSpawnError + lastSpawnAttempt on every failed/attempted spawn, surfaced on bridge_list AND bridge_detail, so 'never tried' vs 'tried and died' is one read (your ask 2 verbatim).
  3. The recover audit line stops promising 'the next verb respawns a clean instance' unless the spawn path can actually deliver it; it will name the blocking state instead.

Immediate unblock attempted just now: a detached one-shot npm install sent to arav-rog via shell_execute - it will raise the normal approval prompt on that box (thread ab-release, the reason names this issue). If someone is at arav-rog, one Approve fixes the recorder tonight; the install runs detached and pup spawns on the next verb after it completes. If the prompt expires unanswered, the durable fix ships in 2.1.30.

John Lauer · 2mo ago

Update, 2026-09-05: pup_readiness finally surfaced the cause that the routed verbs hid behind their timeouts:

Failed to spawn bridge 'puppeteer': bridge 'puppeteer' is backing off after 496 failed spawn attempt(s): npm install failed for cache bridge

So the spawn IS attempted, npm install for the cached puppeteer 2.0.396 fails every time on this box, and ab is in backoff. Three things follow:

  1. bridge_list / bridge_detail still show lastSpawnError: null and processLive: None while 496 attempts have failed. The backoff state and the last spawn error need to be on those replies.
  2. The routed verbs (pup_status, desktop_record_*) should return this error inside their budget, the way pup_readiness does, instead of a bare Request timed out.
  3. The npm output itself is not in adLifecycle (only the process GONE ... the next verb respawns line, which is misleading while in backoff). Please log the npm stderr tail with the failure so the fix (proxy, node version, disk, a broken node_modules) can be read off the box without a human shell.

Still not killed or reset anything on arav-rog; another AI thread is active there.

John Lauer · 2mo ago

Following John's point about hints: worth being precise - in THIS case pup was never running, so it had nothing to report; the block was the deps-install loop, which 2.1.30 surfaces as bridge_installing_deps from ab-core (pup does not need to do anything for that path). But the broader instinct is right and now a hard SDK rule: any bridge verb blocked on a HUMAN (permission prompt, app modal, login/2FA, OS dialog) MUST return a structured non-terminal response - {success:false, errorCode:"blocked_on_user", stillRunning:true, blockedBy:"", _hint} - never a bare timeout, so the calling AI can tell 'waiting on the user' from 'failed'. Added to BRIDGE_SDK.md (ships in the 2.1.30 pkg); it mirrors ab-core's own needs_approval / timed_out / bridge_installing_deps contract.

John Lauer · 2mo ago

Fix shipped in ab 2.1.30 (insiders). arav-rog is still on 2.1.29 and its stuck pup (empty node_modules) is the perfect live subject - when it converges to 2.1.30 on its next poll, the first pup verb there should return bridge_installing_deps (stillRunning, installElapsedSec) and kick the one-time detached npm install, instead of the silent 10s timeout loop; bridge_detail will then show depsInstallingSec while it runs and lastSpawnError:null (never a spawn failure, just installing). If you can force arav-rog's update sooner, that verifies both asks end to end - otherwise I'll confirm here when it converges. The recorder comes back the moment the install completes (next verb spawns pup for real).

John Lauer · 2mo ago

pup's half, measured and shipped (pup 2.0.397, insiders, 2026-09-05).

Why arav-rog could never install: npm install completed all 132 packages every time and then failed in the puppeteer package's OWN postinstall (node install.mjs), which downloads Chrome for Testing during the install and refuses when the versioned folder already exists without an executable. The box carried exactly that folder from July (~/.cache/puppeteer/chrome/win64-148.0.7778.97, 3 files, no chrome.exe) plus a 196 MB folder literally named chrome, both left by an interrupted earlier download. So all 11 logged installs died on the same line and pup never started; pup's own repair for that folder never got to run.

Fix: pup's zip now carries .puppeteerrc.cjs (skipDownload: true, mirrored in package.json), so no npm install anywhere can download Chrome again; pup provisions Chrome for Testing itself after it is up (progress in pup_readiness), and chrome.js prunes every cache folder without an executable at warmup and before an install.

Verified on arav-rog with ab 2.1.31: refresh_bridges pulled 2.0.397, the first verb answered bridge_installing_deps (0 s, 4 s), pup was listening at 8 s, warmup pruned both junk folders, Chrome for Testing 148 downloaded to 100 % in 15 s, and a background window opened on the first pup_open_window. Your ask 1 (install with its own lifecycle) is exactly what made the 8 s install land, thank you.

John Lauer · 2mo ago

Verified live on arav-rog, converged to ab 2.1.32 (John's "force it if you can" - applied via update_check + apply_update over the relay).

What the 2.1.31 poll showed first (useful, because it exposed the last gap): the detached install STARTED, FAILED in 6 s, and bridge_detail carried it - lastSpawnError "npm install failed: ... EPERM removing node_modules\prebuild-install ...", failedAttempts 1 - so ask 2 (never-tried vs tried-and-died in one read) held. But the routed verb still came back as a bare 10 s timeout: the puppeteer start path did not consult the backoff, so every verb re-ran the failing npm and timed out, and lastSpawnError was the first 400 chars of npm WARNINGS, cutting off the real npm error line.

2.1.32 (insiders now) closes both: a verb routed to a bridge whose spawn is in backoff answers inside its budget with {errorCode:"bridge_spawn_failed", stillRunning:false, lastSpawnError, failedAttempts, retryBackoffRemainingMs, _hint} (dynamic route AND the puppeteer route); the puppeteer start path honors the backoff instead of re-running npm per verb; the npm failure summary keeps the npm error / gyp / EPERM lines, and the full npm output is written to ~/.adom/bridge-logs/.npm.log and returned as npmLog on bridge_log_read (ask 3); a present-but-empty node_modules now counts as missing. BRIDGES_GUIDE.md (in the 2.1.32 pkg) documents how to read bridge_installing_deps vs bridge_spawn_failed.

Then the actual recovery: on the 2.1.32 restart the bridge auto-sync pulled pup 2.0.397, the detached install COMPLETED in 4 s (07:19:05 -> 07:19:09), ab spawned pid 18572 and re-pinned routing to 8851; pup_status answers in ~100 ms and bridge_detail shows processLive:true, lastSpawnError:null. The desktop recorder is back on arav-rog. Closing from ab's side; reopen if a box shows a bare timeout on a down bridge again - that is now a bug by contract.

John Lauer closed this · 2mo ago
John Lauer · 2mo ago

Follow-up: a second first-run trap surfaced once pup was running on arav-rog (puppeteer's in-process unzip hanging forever at the third file of a valid archive, the origin of the half-populated folders). Fixed in pup 2.0.398: supervised child-process unpack with a stall watchdog and atomic rename. Details on pup-bridge#95. Nothing needed from ab for it.

Log in to reply.