Files
box/docs/SIDECHAT-RELIABILITY.md
T

231 lines
13 KiB
Markdown
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
# 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.