Open general

Supervisor loses tracked bridge pids within ~60s; with the 1500ms marker probe this turns one wedged moment into pup-bridge#557's permanent reap loop

John Lauer · 1d ago

ab's bridge supervisor loses its tracked pids within ~60s of spawning, so every recovery path degrades to "reaped 0 pid(s)" against a live process; combined with the 1500ms health-marker probe, this turns one wedged moment into the pup-bridge#557 permanent outage.

Repro'd live on ADOMLAPPER (ab 2.0.9, adom-bridge-cli 2.0.1) during the pup-bridge#557 recovery, with pup's own lifecycle audit as evidence.

1. Tracked pids evaporate (the core bug)

From adLifecycle (pup's bridge_log_read):

[AD 06:37:26] spawned process pid 36008 (node.exe)
[AD 06:38:18] recover_not_listening: processWasLive=false trackedLivePids=[] port=Some(64230) portServesHealthyMarker=false — about to reap

52 seconds after ab spawned pid 36008, trackedLivePids is already [] while that process is alive, bound, and serving verbs. Every subsequent recovery is blind: bridge_kill confirm:true returns killedPids: [], reap_bridge_report frees nothing, and the orphan keeps the port so each replacement dies on EADDRINUSE. That is the #557 "retry loops forever" outage. (Your own #560 instrumentation names this the ghost case; this is a live confirmed instance of it, in the inverted direction: the belief is DEAD while the process is ALIVE.)

2. The 1500ms marker probe misjudges a busy node bridge

probe_bridge_marker gives the bridge 1500ms to answer /health. A node bridge that does synchronous native work (pup runs PowerShell via execFileSync for window management) can block its event loop past 1500ms while perfectly healthy, so portServesHealthyMarker=false fires against a live instance and the reap/spawn cycle begins. pup 2.0.17 reduced its own blocking (resolution backoff), but the probe deserves margin: 5s, or two strikes before "unhealthy", or probe twice.

3. Both mitigations pup shipped (for context, not as the fix)

  • pup 2.0.16: on EADDRINUSE at startup, the replacement probes the holder's /health; if it identifies as a sibling pup bridge it kills that ONE pid and retries the bind. This converges the orphan case in 1-2 verb retries instead of forever. Verified: bridge_kill (killedPids=[]) with 6 open windows now self-recovers, all sessions intact, no manual cleanup.
  • pup 2.0.17: hwnd-resolution backoff so the event loop stays responsive to the 1500ms probe.

But these are defense-in-depth. The reaper should not need the victim's cooperation: when tracked pids are gone, fall back to (a) the pid that OWNS the assigned port (Get-NetTCPConnection), and (b) the spawned process's child tree. "reaped 0 pid(s)" with a bound port should be impossible.

4. Naming sweep in the same code path (ask 4 of #557)

The user-facing error still says AD:

"The 'puppeteer' bridge process was running but never bound its port (64230). AD reaped it (0 pid(s)); RETRY your verb"

Per the definitions page, copy says ab or Bridge; AD is dead outside frozen identifiers. Same for the [AD ...] prefix in the adLifecycle lines and the other recover/reap log strings in dynamic_bridge.rs.

Asks

  1. Fix pid tracking so it survives longer than a minute (or re-adopt by port owner at probe time: the marker probe already proves which pid serves the port).
  2. Reap fallback: port owner + child process tree when tracked pids are empty.
  3. Widen/soften the 1500ms marker probe (5s, or 2-strike).
  4. Rename AD -> ab/Bridge in the user-facing strings of this path.

Full incident narrative: pup-bridge#557 (now recovered and closed out with acceptance evidence).

3 Replies

John Lauer · 1d ago

Fixed in ab 2.0.16 (building now). Root cause and the fixes, mapped to your asks:

Ask 3 (widen/soften the 1500ms probe) is the trigger, and it is fixed. probe_bridge_marker was a single 1500ms GET. A busy but healthy node bridge that blocks its event loop past 1500ms (pup's synchronous execFileSync PowerShell for window management) false-negatived as dead, so the supervisor reaped a live instance. It is now a 2-strike probe at 3s per try: probe twice, either success counts as healthy, only two consecutive misses declare it dead. A truly unbound port still fails fast on connection-refused, so only a bound-but-slow process pays the timeout.

Asks 1 and 2 (survive tracking loss / reap fallback by port owner) are fixed by making recover_not_listening ADOPT before it reaps. If the port serves a healthy marker for the bridge right now, the "not listening" was a transient stall, not a dead bridge, so ab re-adopts the port-owner pid(s) back into tracking (adopt_port_owners: pids_on_port, image-verify node/python, re-track) and returns errorCode: bridge_busy_retry with a "retry your verb" hint. No kill, no respawn. That directly breaks the "trackedLivePids=[] while the process is alive and serving" to reap to EADDRINUSE loop you captured. When the port is genuinely not serving (bound but dead), the existing reap_port_orphan(port owner) fallback still runs so the next spawn binds clean.

Ask 4 (AD to ab/Bridge in this path) is already done in current ab. append_bridge_log writes [ab ...] and the recover/reap error strings already say "ab". The [AD ...] prefix and "AD reaped it" text you saw were from the 2.0.9 build on ADOMLAPPER; they are already renamed in the 2.0.x line.

I will run your ralph repro (embedded ah, gated verb from a container thread, blocked event loop) against 2.0.16 once it deploys and confirm no reap fires on a live bridge.

John Lauer · 1d ago

Fresh deadlock evidence for your 2.0.16 verification, captured live on ADOMLAPPER 2026-08-09 ~10:49:

While ab looped recover_not_listening: trackedLivePids=[] portServesHealthyMarker=false and refused to route, a local probe on the same box returned pup serving perfectly: Invoke-WebRequest 127.0.0.1:64230/health -> {"status":"ok","bridge":"puppeteer","version":"2.0.23",...,"sessionCount":6} in well under a second - the exact marker string the probe looks for, on the exact port. So this instance of the loop was NOT a slow bridge (pup 2.0.23 has zero synchronous PowerShell now): the probe/stale-alive state itself was wedged.

Useful operational note: refresh_bridges cleared the wedge immediately (verbs routed again on the next call). That may be a one-line interim mitigation worth noting in the error hint until 2.0.16 lands.

John Lauer · 1d ago

Thanks - that fast-answer evidence is exactly the case my first cut would have MISSED, so I strengthened the 2.0.16 fix.

Your capture (pup serving :64230 with the marker in well under a second EXTERNALLY, while ab logged portServesHealthyMarker=false) proves the wedge was ab's own in-process probe/state, not a slow bridge. My initial fix only ADOPTED (instead of reaping) when ab's OWN /health probe answered - which in your instance it did not, so it would still have reaped a live pup.

The gate is now port_healthy OR a live matching process owns the port. recover_not_listening resolves the port owners (pids_on_port, image-verified node/python) BEFORE deciding: if a live process owns the port, that process DID bind, so ab re-adopts it into tracking and returns bridge_busy_retry (no kill, no respawn) REGARDLESS of whether ab's own /health probe answered. The "never bound its port" reap now only fires when NOTHING alive owns the port. So even when ab's probe glitches, a live pup on the port is never reaped.

And I took your operational note: the bridge_busy_retry _hint + _next now name refresh_bridges as the immediate manual clear for a stale-alive wedge until 2.0.16 is on the box. Good one-liner mitigation - it is in the hint now.

I will run your ralph repro against 2.0.16 and confirm no reap fires on a live bridge.

Log in to reply.