Skip to content

fix(council): Perplexity research outage — port collision, invisible failures, keeper that never survived - #72

Draft
intellegix wants to merge 7 commits into
masterfrom
worktree-pplx-keeper-port-and-failure-visibility
Draft

fix(council): Perplexity research outage — port collision, invisible failures, keeper that never survived#72
intellegix wants to merge 7 commits into
masterfrom
worktree-pplx-keeper-port-and-failure-visibility

Conversation

@intellegix

@intellegix intellegix commented Aug 8, 2026

Copy link
Copy Markdown
Owner

Second machine-wide Perplexity research outage in 24h (2026-08-08). Filed evidence:
council-automation/PERPLEXITY-SESSION-FAILURE-EVIDENCE-2026-08-08.md.

Was yesterday's fix a regression?

No. PR #71's identity gate worked exactly as designed — it correctly refused the
foreign Chrome on 9222 seconds before each failure. Three separate defects were found.

1. The identity gate was applied at one call site, not its twin

_start_via_cdp refused the relay's Chrome and fell back to a local launch. That
fallback runs _ensure_fresh_session("local-launch"), which still probed 9222 with a
bare urlopen and concluded "the keeper is alive" — the same reachability-is-not-identity
mistake, un-fixed. It then fired a keeper refresh that could never land, waited 120s, and
submitted on expired cookies.

Compounding it, PerplexitySessionKeeper had been Disabled since 2026-07-30, so
Start-ScheduledTask was a silent no-op and that 120s could only ever time out.

Fixes: both call sites share _keeper_cdp_alive(); _keeper_task_state() checks the task
before waiting on it; the keeper moves to a dedicated CDP port 9223 so it can never
contend with /takeover on 9222 again (the collision port-registry flagged as "latent,
still unresolved"); session_keeper.py refuses to adopt a foreign Chrome on its own port.

2. Failures were invisible — arguably the bigger bug

The queue logged started and never error, so errors_today read 0 through a total
outage. acquire_slot's error path cannot run when the process is killed outright, and
that is the normal end for a research run: the MCP layer calls execFileAsync with a 540s
timeout, and Node's timeout kill on Windows is TerminateProcess — no signal, no
unwinding. Queue-based monitoring was structurally blind to the dominant failure mode,
which is why both outages were found by a session tripping over them.

gc_dead_tickets() is the one place another process can observe the death, so it now logs
a dropped event there (once, by the winner of the unlink race). errors_today counts it,
the snapshot carries last_failure, queue_monitor alerts on it, and the MCP layer
returns RUNNER_KILLED instead of an opaque "Task failed".

3. The keeper never survived its launcher — found while verifying

DETACHED_PROCESS detaches the console but does not leave the parent's job object, and
every realistic launcher supplies one. Chrome died ~60s after each keeper invocation,
cleanly enough that it removed its own DevToolsActivePort file. Every run then found no
CDP and fell back to the local launch — i.e. this is why traffic reached the broken path
at all. Fixed with CREATE_BREAKAWAY_FROM_JOB (with fallback).

Two follow-ons: session_keeper.cdp now records Chrome's pid, not the one-shot keeper
python's; and the identity gates are reordered so the weakest signal (a recorded pid)
cannot veto positive proof of ownership. Previously that veto rejected every healthy
keeper
. The foreign-Chrome protection is unchanged and still tested.

Correction (commit 4). I first claimed the breakaway flag made Chrome survive past
t+120s. That measurement came from a launch that had not picked up the new code, so it
does not support the claim — corrected rather than left standing. Measured reality:
[keeper 07:27:14] Job breakaway not permitted ([WinError 5] Access is denied).
Breakaway needs the containing job to grant JOB_OBJECT_LIMIT_BREAKAWAY_OK and Task
Scheduler's does not — the same constraint already proved with IsProcessInJob for the
Santee app. Under the task, Chrome lives on the order of minutes and the task repetition
re-establishes it; from an interactive shell the flag works and Chrome persists, so the
code stays. The proper fix (make the long-lived process the task's own process) needs
a new scheduled task and schtasks /Create is denied without elevation here — left as a
documented open item. This changes nothing about the outage fix or the monitoring fix:
nothing depends on the keeper being continuously up, and the verified 32.9s query ran on
the local-launch path, which now has a correct freshness guard and a working refresher.

Also: keeper-timeout-stale-proceed no longer proceeds

Hard-expired cookies raise SessionStaleError before submit (SESSION_STALE to the
caller) rather than burning a 5–8 minute slot on a doomed run. Cookies that are merely
expiring soon still proceed — that is what the old always-proceed rationale was about.

Verified by doing, not asserting

  • Real research_query succeeded in 32.9s (was: two identical ~9-minute deaths).
  • Keeper on 9223 and /takeover relay on 9222 coexisting; neither displaced.
  • Keeper Chrome alive past t+120s with its launcher long exited (before: gone by t+60s).
  • Forced a failure: os._exit inside a live queue slot — same semantics as the
    TerminateProcess Node issues. Produced enqueued/started/dropped, errors_today
    0 → 1, last_failure populated, and the monitor daemon logged ALERT [critical].
    That exact sequence was completely silent before this PR.
  • 95 tests pass (17 new in tests/test_pplx_failure_visibility.py; 10 of the first 11
    fail against pre-fix code).

Ops changes already applied to the live machine

PerplexitySessionKeeper and PerplexityQueueMonitor re-enabled and running; keeper
rebound to 9223. ~/.claude/council-automation and mcp-servers/browser-bridge/server.js
updated in place (the MCP server executes them directly, so the fix had to be live to be
verifiable). server.js changes take effect for newly started sessions.

Note: the first commit snapshots two improvements that were live in the working tree but
unmerged, so the fixes apply on top of what actually runs.

🤖 Generated with Claude Code

https://claude.ai/code/session_013jYxW6be3KvPW4Sm8zdW5q

intellegix and others added 7 commits August 7, 2026 14:18
…orphaned results

Machine-wide Perplexity research outage on 2026-08-07: four consecutive
research_query runs failed at ~128s with "Page.wait_for_timeout: Target page,
context or browser has been closed".

Root cause: the runner attached to the wrong Chrome. _start_via_cdp() treated
"port 9222 answers /json/version" as proof the session keeper was alive. Three
facts lined up: the PerplexitySessionKeeper task has been Disabled since 07-30;
a stale session_keeper.cdp from 08-02 still pointed at 9222 recording a PID dead
since the reboot; and browser-relay/relay.mjs (the /takeover phone relay) claimed
port 9222 at 12:57 with a throwaway C:\Temp\igx-cdp-profile. From 12:57 the health
check passed against the relay's cookie-less Chrome, so every run navigated to a
logged-out wall and was torn down ~128s later. Last success 11:49 (pre-reboot,
launch path); relay up 12:57; first failure 13:19.

A reachable port was being treated as a trusted port.

council_browser.py — prove endpoint identity before attaching, layered so an
indeterminate probe degrades to the next check rather than blocking a healthy
keeper:
  - recorded PID must be alive (stale .cdp file is deleted)
  - DevToolsActivePort GUID in the keeper's profile must match the endpoint's
    webSocketDebuggerUrl (canonical launch-time/discovery-time match)
  - failing that, the port owner's command line must name session_keeper_profile
  - post-attach, the context must carry a Perplexity auth cookie — which also
    catches a live keeper whose login has expired
The "synthesize a .cdp file because 9222 answers" fast path is gated behind the
same ownership check. Any refusal falls back to local launch, which is what was
working before 12:57.

council_query.py — invocation_id is a fresh UUID per call, so a caller dying
orphans a completed result (council_fae5c9e0.json). Results now carry a
query_fingerprint and run_browser_query checks for a matching, usable, recent
result before re-running. Age comes from the recorded timestamp rather than file
mtime, so re-saving a recovered orphan cannot keep it alive indefinitely.

Verified: first post-patch run completed in 159.5s where the two runs before it
failed at 128s. Gates unit-tested against live machine state — refuse the relay's
Chrome, wrong GUID and wrong port; accept a simulated healthy keeper. Orphan
recovery verified against the real council_fae5c9e0.json.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01VsT8c4wZQYv2fRN6szvEQ6
Captures two improvements that were live in the working tree but not on any
merged branch, so the follow-up fixes apply on top of what actually runs:
  - council_browser.py: tier-0 aria-pressed mode-activation verifier
  - research_queue.py:  _atomic_write WinError 5 retry loop

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_013jYxW6be3KvPW4Sm8zdW5q
…sible

Second machine-wide Perplexity outage in 24h (2026-08-08). Two independent
defects, one of which hid the other.

1. IDENTITY, NOT REACHABILITY (the outage). `_ensure_fresh_session` probed
   port 9222 with a bare urlopen and treated any answer as "the keeper is
   alive". The /takeover browser relay binds that same port, so the guard
   fired a keeper refresh that could never land, waited SESSION_KEEPER_WAIT_S,
   then submitted on expired cookies. `_start_via_cdp` had been hardened
   against exactly this on 08-07 and correctly REFUSED the same port seconds
   earlier -- the two paths disagreed. This is not a regression of that fix;
   it is its un-fixed twin. Both call sites now share `_keeper_cdp_alive()`.

   Compounding it, PerplexitySessionKeeper had been Disabled since 07-30, so
   `Start-ScheduledTask` was a silent no-op and the 120s wait could only ever
   time out. `_keeper_task_state()` now checks before entering that branch.

   Structural fix: the keeper moves to a DEDICATED CDP port (9223, via
   COUNCIL_KEEPER_CDP_PORT) so it can never contend with the relay again --
   the collision memory port-registry flagged as "latent, still unresolved".
   session_keeper.py also refuses to adopt a foreign Chrome on its port.

2. FAILURE INVISIBILITY (the reason nobody caught #1). The queue logged
   `started` and never `error`, so errors_today read 0 through a total
   outage. `acquire_slot`'s error path cannot run when the process is killed
   outright, and that is the normal end for a research run: the MCP layer
   calls execFileAsync with a 540s timeout, and Node's timeout kill on
   Windows is TerminateProcess -- no signal, no unwinding. gc_dead_tickets()
   is the one place another process can observe the death, so it now logs a
   `dropped` event there (once, by the winner of the unlink race).
   errors_today counts it, the snapshot carries last_failure so callers see
   WHAT broke, queue_monitor alerts on it, and the MCP layer returns
   RUNNER_KILLED instead of an opaque "Task failed".

Also: `keeper-timeout-stale-proceed` no longer proceeds. Hard-expired cookies
now raise SessionStaleError before submit (SESSION_STALE to the caller).
Cookies that are merely expiring-soon still proceed, which is what the old
always-proceed rationale was actually about.

Tests: tests/test_pplx_failure_visibility.py -- 11 cases, 10 of which fail
against the pre-fix code. Full suite 92 passed.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_013jYxW6be3KvPW4Sm8zdW5q
…ntity gates

Verifying the previous commit on live infrastructure surfaced the reason the
keeper has effectively never stayed up -- which is what routed every research
run onto the local-launch path where the 08-08 outage lived.

- CREATE_BREAKAWAY_FROM_JOB on the Chrome launch. DETACHED_PROCESS only
  detaches the console; it does NOT leave the parent's job object, and every
  realistic launcher supplies one (Task Scheduler gives each task instance a
  job; so does the agent harness). When the launching instance ended the job
  was torn down and took Chrome with it within ~60s -- cleanly enough that
  Chrome removed its own DevToolsActivePort file, so it read as a normal
  shutdown rather than a kill. Measured before: Chrome gone by t+60s. After:
  alive past t+120s with the launcher long exited. Falls back to the old
  flags if the job forbids breakaway.

- session_keeper.cdp now records the pid of the process SERVING CDP (Chrome)
  rather than the keeper python's. The keeper is one-shot and exits seconds
  after launching Chrome, so the pid it published was always dead by the time
  a reader looked.

- Identity gates reordered. The recorded-pid check ran FIRST and vetoed
  everything, so with the bug above every healthy keeper was judged a stale
  .cdp file and deleted. Decisive gates (DevToolsActivePort GUID, then port
  ownership) now run first; the recorded pid only breaks ties when neither can
  reach a verdict. An over-strict identity gate silently disabled the CDP path
  it was written to protect -- the foreign-Chrome protection itself is
  unchanged and still tested.

Verified live, not asserted:
  - real research_query succeeded in 32.9s (was: two identical 9-minute deaths)
  - keeper on 9223 and /takeover relay on 9222 coexisting, neither displaced
  - forced a hard-killed run (os._exit inside the slot, same semantics as the
    TerminateProcess that Node's timeout issues): produced enqueued/started/
    dropped, errors_today 0 -> 1, last_failure populated, and the monitor
    daemon logged ALERT [critical]. That exact sequence was silent before.

Tests: 95 passed (17 new).

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_013jYxW6be3KvPW4Sm8zdW5q
…Scheduler

The previous commit claimed CREATE_BREAKAWAY_FROM_JOB made the keeper's Chrome
survive past t+120s. That measurement was taken from a launch that had NOT
picked up the new code (the redeploy raced the task start), so it does not
support the claim. Correcting it rather than leaving it standing.

What is actually true, measured 2026-08-08 07:27:
  [keeper 07:27:14] Job breakaway not permitted ([WinError 5] Access is denied)

Breakaway only succeeds if the CONTAINING job grants
JOB_OBJECT_LIMIT_BREAKAWAY_OK, and Task Scheduler's job does not — the same
constraint already proved with IsProcessInJob for the Santee demo app (memory
port-registry). Under the task, Chrome lives on the order of minutes and the
task's own repetition re-establishes it. Launched from an interactive shell the
flag works and Chrome persists, so the code is kept.

The proper fix (make the long-lived process the task's OWN process) is not
applied: it needs a new scheduled task, and schtasks /Create is denied without
elevation on this box. Documented as a known open item in the code.

This does not affect the outage fix or the monitoring fix, and does not change
the verified result — nothing depends on the keeper being continuously up. The
local-launch path has a correct freshness guard and a working refresher, and
that is the path the verified 32.9s research_query actually used.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_013jYxW6be3KvPW4Sm8zdW5q
…rowser-relay

The diagnostic string a human reads to decide what to go kill was pointing at
the wrong process. The Chrome on C:\Temp\igx-cdp-profile is launched by the
Dogfood Supervisor (Intellegix Code\scripts\start-dogfood.cmd, auto-starts at
logon), NOT by browser-relay/relay.mjs. Verified by walking the parent chain:
chrome pid 25944 -> cmd.exe 7628 -> start-dogfood.cmd. The profile name is
browser-relay's, which is what made the misattribution durable across two
outage writeups. Credit: session fb-page-pricing-iterated-perplexity flagged it.

The label now also says do NOT kill it: the supervisor relaunches a
byte-identical Chrome within ~3s, and the phone-takeover bridge on :7070
depends on it. And because it auto-starts at logon, this collision was never
"latent" as previously recorded — it holds 9222 essentially always, which is
why moving the keeper to its own port was the only real fix.

Behaviour is unchanged; this corrects operator-facing text and the assertion
that pins it. Memories perplexity-cdp-identity-gate and port-registry corrected
to match. 95 tests pass.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_013jYxW6be3KvPW4Sm8zdW5q
…ng is a no-op

Found by applying another lane's reframing to my own work: tracked-vs-untracked
is the wrong axis, "reproducible from what IS tracked" is the right one. This PR
failed that test.

queue_monitor.py imports research_monitor for _send_pushover and _trigger_keeper
(queue_monitor.py:89-97). research_monitor.py was untracked and existed in git
NOWHERE — not on this branch, not in origin/master — so a fresh checkout of this
PR got queue_monitor without it.

Reproduced against a clean directory containing only this branch's files:
  WARNING queue_monitor: research_monitor unavailable, pushover/self-heal disabled
  _send_pushover is: None
  INFO    queue_monitor: pushover unavailable, alert not sent: dropped run_id=x

So the whole point of the monitoring half of this PR — make a killed run SURFACE
— degraded to a log line nobody reads. The `dropped` event would still be
written and errors_today would still count it, but the critical alert would
never leave the machine. That is precisely the failure class this PR exists to
fix: a signal that looks correct and reports nothing. It survived my own
verification because I tested the alert firing in the LIVE tree, where the
untracked file happens to sit next to it.

After adding the file, the same clean-directory check reports _send_pushover
WIRED. 95 tests pass.

Deliberately NOT a blanket `git add` of the untracked set: council-automation has
12 untracked .py files and one of them, ensure_perplexity_tab.py, was written
against a root cause disproven the next morning and is documented as
ignore/delete. Committing it would give known-wrong code the authority of being
in git. This commit adds exactly the one file this PR's own behaviour depends on.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_013jYxW6be3KvPW4Sm8zdW5q
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant