Files
box/docs/SIDECHAT-RELIABILITY.md
T

231 lines
13 KiB
Markdown
Raw Normal View History

# Sidechat Reliability Runbook
> **Box is the main surface.** All operator work goes through Box (box.muse-dev.online). The web UI, `box` CLI, and agents share the same API endpoints. No UI-only powers.
Fleet sidechat DMs are the fleet's nervous system. On 2026-10-04 they were
measured at ~1/3 navigation success. This runbook is the single place that
explains how the machinery works, how each known failure looks in the logs,
and what to do when a DM doesn't arrive.
All paths below are on **bl** (`super@100.123.153.75`, via the VM).
Repo: `/home/super/Projects/NetVM` (git, local-only, no remotes).
Companion tools (all read-only unless noted):
- `bin/dm-log-taxonomy.py` — failure taxonomy over dm-log.jsonl (counts, nav-failure
breakdown per target/agent-pair, hourly bursts, ghost rate). Run: `python3 bin/dm-log-taxonomy.py`
- `bin/placement-audit.py` — human-readable placement/gate activity.
`placement-audit.py --since 24h`, `--since 60m`, `--watch`
- `bin/tests/test_followup_fixes.py` — 25 unit tests pinning the sweeper/harvester/gate contracts
---
## 1. Architecture (10 lines)
1. Operator (or timer) runs `bin/dm.py send --agent <node> --to <agent> --target <sidechat> "<msg>"`.
2. `dm.py` resolves the target name → thread UUID: `SIDCHAT_ALIASES` (intentionally
empty — hardcoded UUIDs rot), then `job-sidechats.json` dynamic mapping, then
passthrough name for sidebar search.
3. Unknown names autoprovision: `sidechat create` in the recipient's browser, and the
fresh UUID is registered in `job-sidechats.json` (self-healing).
4. Browser control goes `netvm-exec.sh <node> -- python3 muse-chat-api.py --account <node> <cmd>`,
which drives headless Chromium over CDP inside the node's Warp netns.
5. `dm.py` navigates to `/thread/<uuid>` (or sidebar title search), then the
**pre-send gate** (2026-10-04) independently samples the browser URL and requires
the expected UUID in it — fail-closed, never sends blind.
6. Send happens via CDP; `verify_placement()` re-navigates and reads the thread back
(post-send check, complementary to the pre-send gate).
7. Every step appends machine-readable events to `dm-log.jsonl` (`send_start`,
`nav_ok`, `sent`, `verified`, `placement_failed`, `pre_send_assert_failed`, …).
8. If the message carries `reply:expected` tags, `_register_followup()` arms a record in
`followups.json` (deadline, nudges, escalate target).
9. `followup-sweeper.py` (driven by gravity loop) sends nudges on expiry — in-thread
first, main chat on the final nudge — then escalates. It backfills `thread_uuid`
when a nudge provisions the thread.
10. `response-harvester.py` (every ~60s via `response-harvester.service`) reads agent
threads, records `[RESULT job_id]` markers to `job-log.jsonl`, and resolves
followups when an assistant reply lands in the matching thread.
---
## 2. Failure-mode catalog
How to read the signatures: `grep '"type": "<event>"' dm-log.jsonl`, or use
`placement-audit.py --since 24h` / `dm-log-taxonomy.py`.
### 2a. Landing-page nav (caught by the pre-send gate)
- **Signature:** `{"type":"pre_send_assert_failed","id":…,"agent":…,"to":…,
"target":…,"expected_uuid":…,"actual_url":"https://muse.ai/",
"reason":"url_mismatch"|"not_on_thread_page"|"direct_nav_failed"}`
- **Cause:** the browser never left the muse.ai landing page (or parked on the wrong
thread) after `sidechat use`; the old code would have sent anyway.
- **Effect:** send aborted, exit 1, nothing delivered, nothing marked verified.
- **Fix:** re-run the send; if it repeats, the nav layer is flapping — see §2g and the
nav workstream. The gate doing its job is *good news*, not a bug.
- **Owner:** dm.py placement-gate workstream (landed 2026-10-04).
### 2b. `sidechat_uuid_capture_failed` (autoprovision went nowhere)
- **Signature:** `{"type":"sidechat_uuid_capture_failed","id":…,"out":"https://muse.ai/"}`
- **Cause:** `sidechat create` ran but UUID capture saw the landing page — the thread
may or may not exist; dm.py cannot know.
- **Effect (pre-gate era):** the send proceeded with `thread_uuid: null` and reported
`verified:true` — a ghost send (see §2d). With the gate live, the send now fails
closed instead.
- **Owner:** dm.py autoprovision path; gate workstream.
### 2c. Stale UUID rotation (the UUID you have is dead)
- **Signature:** `{"type":"placement_failed",…,"expected_uuid":"<uuid>",
"actual_url":"https://muse.ai/thread/<different-uuid>","reason":"url_mismatch"}`
or `{"type":"placement_mismatch",…,"expected_uuid":…,"actual_uuid":…}`.
- **Cause:** thread UUIDs rotate — observed same-day (`heartbeat-opm`:
`5bd5b350` → `0077e918` → dead). Any hardcoded UUID is a time bomb; the SPA may
also redirect a dead-UUID nav to whatever thread was last open (misdelivery, not
just failure).
- **Fix:** never hardcode UUIDs — `SIDCHAT_ALIASES` in dm.py is intentionally empty
(sibling workstream removed the last hardcoded entries 2026-10-04, incl. the
twice-dead heartbeat UUID). Use name-based autoprovision + `job-sidechats.json`
dynamic mappings, which self-heal on re-provision.
- **Owner:** UUID-rotation workstream. TODO: `docs/UUID-ROTATION.md` not yet written;
this section is the interim reference.
### 2d. Placement-blind `verified:true` (the ghost send)
- **Signature:** `{"type":"verified","id":…,"agent":…,"target":…}` with **no**
`thread_uuid` field (or `"thread_uuid": null`), paired with a `sent` event —
and no `placement_failed`/`pre_send_assert_failed` anywhere near it.
- **Cause:** the old verify step checked the *current* browser chat, not the target
(see operator AGENTS.md). A send parked on the landing page still "verified".
- **Effect:** the message is lost but every downstream system believes it landed —
followups nudge a ghost, pipelines stall as `dispatched`.
- **Fix:** the pre-send gate (§2a) makes new ghost sends impossible (fail-closed).
For historical ghosts: backfill `thread_uuid` in `followups.json` once the thread
provisions, register the alias in `job-sidechats.json`, resolve manually with a note.
- **Owner:** gate workstream (prevention); operators (historical repair).
### 2e. Logged-out / dead session
- **Signature:** no single event type. Look for `nav_failed` with `"rc": 1` and CDP
tracebacks, or muse-chat-api.py login-state detection: page `Title == "muse.ai"`
(LANDING), body containing `"To log in, enter the code"` (OTP_PROMPT), or
`"Your email matches multiple accounts"` (ACCOUNT_SELECTION).
- **Cause:** Meta session expired, OTP pending, or (2026-10-04 ~19:43 UTC) all four
chromebox browsers dying silently every 10–15 min with no crash log.
- **Fix:** `agent-health.sh` watchdog relaunches dead Chromium; OTP/account-selection
states need the human (approval flow). Track: board task `9e8b15d69ca9` for the
2026-10-04 browser-flapping root cause.
- **Owner:** session-state workstream. TODO: dedicated session-probe tooling pending.
### 2f. Ghost followup (`thread_uuid: null` — can never auto-resolve)
- **Signature:** in `followups.json`: `"thread_uuid": null`, `"status": "pending"`;
in dm-log: the original send's `sidechat_uuid_capture_failed`, then sweeper
`followup_nudged` events that never resolve.
- **Cause:** the harvester's `clear_matching_followups` only matches exact
`thread_uuid` (or `target=="main"` in main). A null-UUID followup matches nothing,
forever — the sweeper nudges then escalates on a ghost.
- **Fix:** sweeper now backfills `thread_uuid` when a nudge successfully provisions
the thread (workstream landed 2026-10-04). For existing ghosts: backfill manually,
register the alias, resolve with a note. Longer-term TODO: sweeper should also
backfill on sweep ticks by scanning dm-log for the *original* dm_id's
`sidechat_autoprovisioned` event (currently only backfills on nudge success).
- **Owner:** sweeper-policy workstream.
### 2g. Flaky nav (~1/3 success) and timing races
- **Signature:** bursts of `nav_failed` / `pre_send_assert_failed` /
`placement_mismatch` for the same target in `placement-audit.py --since 60m`;
`dm-log-taxonomy.py` shows the per-target failure rate.
- **Cause:** under investigation 2026-10-04 — sidebar DOM races, CDP timing,
possibly the browser-flapping issue (§2e). The gate converts these from silent
misdeliveries into loud, retried failures (strictly better).
- **Owner:** nav-shootout, timing-races, and retry-module workstreams.
TODO: their findings land here when complete.
### 2h. `main_chat_blocked`
- **Signature:** `{"type":"main_chat_blocked","id":…,"agent":…,"to":…,"target":"main"}`
- **Cause:** a send targeted `main` without `--allow-main-chat`. Deliberate guardrail:
automation stays out of main chat unless explicitly allowed.
- **Fix:** pass `--allow-main-chat` if main delivery is really intended.
---
## 3. Diagnosis playbook: "a DM didn't arrive"
Run in order. All commands on bl unless noted.
1. **Find the send.** `grep '"id": "<8-hex-id>"' /home/super/Projects/NetVM/dm-log.jsonl`
(or grep by target). Walk its event sequence: `send_start` → `nav_ok`? →
`sent`? → `verified`? Any `*_failed` event is your answer.
2. **Placement first.** `python3 bin/placement-audit.py --since 24h` — if you see
`pre_send_assert_failed` / `placement_failed` / `placement_mismatch` for the id,
the message never left bl correctly. Check `actual_url`: landing page (§2a),
wrong thread (§2c).
3. **Check the taxonomy.** `python3 bin/dm-log-taxonomy.py` — is this an isolated
incident or is the target/agent-pair failing at a high rate right now (§2g)?
4. **Check the session.** If `nav_failed` with rc=1: is the browser alive?
`ss -tln` for the CDP port in the netns; muse-chat-api.py login-state detection
(LANDING vs LOGGED_IN per operator AGENTS.md). If all four browsers are flapping,
see board task `9e8b15d69ca9` (§2e).
5. **Check UUID freshness.** `python3 -c "import json;print(json.load(open(
'/home/super/Projects/NetVM/job-sidechats.json')).get('<target>'))"` — does the
mapped UUID still open the right thread? If the send used a UUID from anywhere
else, suspect rotation (§2c).
6. **Check the followup.** `grep -A12 '<dm_id>' /home/super/Projects/NetVM/followups.json`
— `thread_uuid: null` + `pending` = ghost (§2f). If nudges are firing, the reply
(if any) landed in a thread the harvester doesn't match: backfill + resolve manually.
7. **Check the pipeline.** If it was a pipeline step: `grep '<job_id>'
/home/super/Projects/NetVM/pipelines.json` — `dispatched` with no result after a
ghost send needs `pipeline_engine.record_step_result()` + a decision on chaining.
8. **Repair, don't re-fire blindly.** Fix the cause (nav, session, UUID), then resend
once. Repeated blind retries of a ghost just burn the nudge budget.
---
## 4. Hard lessons (non-negotiable)
1. **Never trust `verified:true` alone.** It historically meant "found the msg_id in
whatever chat the browser happened to be parked in." Always corroborate with a
placement assertion (pre-send gate) or a thread read-back.
2. **Assert the post-nav URL before sending.** The gate is now the enforcement; any
new send path must go through it. Fail closed, fail loudly (non-zero exit +
`pre_send_assert_failed` event), never degrade to blind send.
3. **Thread UUIDs rotate — never hardcode them.** Observed same-day rotation.
`SIDCHAT_ALIASES` stays empty; name-based autoprovision + `job-sidechats.json`
self-heals. If you find a hardcoded UUID anywhere, delete it.
4. **Backfill `thread_uuid`.** A followup with null UUID can never auto-resolve.
Backfill on provision (sweeper does this now), and repair historical ghosts by
hand with a note.
5. **Atomic writes on live files.** siphon/response-harvester fire every ~60s; the
sweeper loop is tight. Edit to `/tmp`, `py_compile`, atomic `mv`. Never half-write
a live file. Back up (`*.bak-<date>-<who>`) before touching shared code.
6. **One owner per file per change.** Parallel fixes on shared surfaces caused the
2026-10-03 502s: reconcile first, disjoint ownership, review the combined diff
before it goes live. dm.py is the single chokepoint — treat it accordingly.
7. **The dm-log is the source of truth for delivery; the harvester is the source of
truth for replies.** `verified` ≠ delivered; `sent` ≠ read. When they disagree,
believe the thread read-back.
---
## 5. Sibling workstream map (2026-10-04 troubleshooting sprint)
| # | Workstream | Output | Status |
|---|-----------|--------|--------|
| 1 | Gate restore | pre-send gate in `dm.py` (`assert_pre_send_placement`) | **Landed** |
| 2 | Log taxonomy | `bin/dm-log-taxonomy.py` | **Landed** |
| 3 | UUID rotation | hardcoded UUID removal (`SIDCHAT_ALIASES` emptied) | **Landed** |
| 4 | Nav shootout | — | TODO: findings pending |
| 5 | Session-state | — | TODO: probe tooling pending |
| 6 | Timing races | — | TODO: findings pending |
| 7 | Retry module | shared retry helper | TODO: pending |
| 8 | Sweeper policy | thread_uuid backfill + `final_nudge_target` | **Landed** |
| 9 | Audit CLI | `bin/placement-audit.py` | **Landed** |
| 10 | This runbook | `docs/SIDECHAT-RELIABILITY.md` | **This file** |
Related docs: `docs/DM-SPEC.md` (DM system spec), `docs/SIDECHAT_SPEC.md`,
`docs/SIDECHAT-POLICY-TRIAGE.md`, `docs/CHROMEBOX-RUNBOOK.md`.
TODO: `docs/UUID-ROTATION.md` (rotation mechanics deep-dive) — §2c is the interim reference.