diff --git a/docs/runbooks/wedged_unit_recovery.md b/docs/runbooks/wedged_unit_recovery.md index 8d27dd0..3536195 100644 --- a/docs/runbooks/wedged_unit_recovery.md +++ b/docs/runbooks/wedged_unit_recovery.md @@ -14,6 +14,27 @@ This runbook describes how to break the loop and recover control. --- +## ⚠ There are TWO failure modes under "wedged unit" + +Same root cause — an offset/connector fault drives the geophone above trigger, +the unit records back-to-back, ACH set to "after event recorded" dials +constantly — but the *recovery* differs, because the thing blocking you is +different. + +| | **BE9558H (2026-05)** | **BE12599 (2026-09)** | +|---|---|---| +| What blocks you | Modem mode-flipping kills inbound TCP | Device never enters S3 mode at all | +| Device state | Alive, in S3 mode, responsive once reached | Stuck repeating an **AT modem-init** string, deaf to S3 | +| Fix direction | **Inbound** — clear Destination, slow-drip a Stop | **Inverted** — point Destination at our own ACH server and let the unit call *us* | +| Winning tool | `scripts/slow_drip.sh` | `bridges/ach_server.py --stop-monitoring` | + +**Tell them apart with the ALEOS serial log** (see "Turn on ALEOS_SERIAL debug" +below). If the device is emitting `ATQ1/ATE0/ATS0=2` every ~75 s, it is in the +BE12599 mode and **no amount of inbound work will reach it** — skip to +"Second incident" below. + +--- + ## Symptoms - Terra-View / SFM `/device/info` either hangs or fails on `count_events()`. @@ -253,3 +274,206 @@ service). Total time from "i was wondering if its possible to" first attempt to recovery: ~7 hours of intermittent debugging across one evening. + +--- + +# Second incident — BE12599, 2026-09-16/17 + +**Unit:** BE12599 at `166.246.64.226:9034`, RV50, job *I-80 North Fork Bridge +— Abut 1 West* (Fay Company). Same job as BE9558H, which is a coincidence. + +**Fault:** the connector fault documented in `docs/offset_investigation.md` +§8e progressed until the Tran pedestal reached **0.400 in/s** — its trigger +level. Constant triggering → constant recording → ACH "after event recorded" +→ continuous dialing. Same disease as BE9558H. + +**But the recovery was the opposite direction**, and none of the Step 1–4 +procedure above worked. Total time ≈ 5 h, of which ~90 min was spent on two +red herrings documented below. + +--- + +## Turn on ALEOS_SERIAL debug FIRST + +This is the single highest-value diagnostic and it should be step zero on any +future incident. ACEmanager → **Admin → Log → ALEOS_SERIAL log level → +DEBUG**, then view the serial log. + +It is the only thing that tells you what the *device* is actually saying. +Everything before we did this was guesswork. + +## What the log showed — the device was never in S3 mode + +Every ~75 seconds, verbatim: + +``` +ALEOS_SERIAL_HIF: 29 byte(s) in buffer: 'ATQ1^MATE0^MATS0=2^M^MRADIO RING^M' +ALEOS_SERIAL_HMC: TCP recvhost fd 65535 len 29 state TCPMode::kClosed +ALEOS_SERIAL_HMC: tcpmode trying to send to invalid socket +ALEOS_SERIAL_HMC: Connect to IP: 0.0.0.0 Port 0 +ALEOS_SERIAL_HMC: Initialize Auto answer on port 9034 +ALEOS_SERIAL_HMC: Cannot connect to 0.0.0.0 +``` + +Read that carefully: + +- `ATQ1` (quiet) / `ATE0` (echo off) / `ATS0=2` (auto-answer after 2 rings). + **There is no `ATD`.** The device is not dialing — it is trying to + *configure* its modem. +- The modem's serial port is in TCP data mode, so it never interprets these + as AT commands. It treats them as payload and tries to ship them to a TCP + socket that does not exist. +- The device therefore never receives `OK`, never progresses, and **retries + the identical 29 bytes forever**. + +**Consequence: the device is not running the S3 protocol parser.** You can +land a byte-perfect S3 frame on it and it will be ignored. This is why every +inbound approach failed, and it is the structural difference from BE9558H. + +### Why `slow_drip` lied + +`slow_drip` returned the *success* signature except for the one field that +mattered: + +```json +{"duration_s":120.0,"drips_sent":38,"bytes_sent":920, + "bytes_received":0,"send_error":null} +``` + +Full duration, no broken pipe — but zero bytes back. Cause is in the log +above: each 75 s cycle re-runs `Initialize Auto answer on port 9034`, which +orphans the held session (`data in for unknown reason 3 removing from +select`, `OnMsg recv error: 107 - Transport endpoint is not connected`). Our +local TCP stayed open so `sendall` never raised — but the modem stopped +bridging after the first re-init, so every drip after that went into a socket +nobody was reading. + +⚠ **`send_error: null` + full duration is NOT success. Only +`bytes_received > 0` is success.** + +--- + +## ⚠ Two red herrings that cost ~90 minutes + +### 1. The trusted-IP whitelist (this was the real reason inbound never worked) + +The RV50s run with **Security → Trusted IPs (Friends List) enabled**. A +source IP that is not on the list is dropped **silently** — inbound presents +as `Connection error: timed out`, never a refusal. + +Brian's dev-box public IP is **dynamic** and had changed, so `tmi-dev` was no +longer whitelisted. Every inbound attempt failed identically across four +different modem and device states, which looked exactly like the BE9558H +mode-flipping symptom and sent us chasing modem configuration for over an +hour. + +**Check this before diagnosing anything else.** Note that SFM in Docker +egresses via the *host's public IP*, not its LAN IP. + +### 2. A 502 from SFM does not mean TCP connected + +`sfm/server.py` raises **502 for both** failure classes: + +```python +raise HTTPException(status_code=502, detail=f"Protocol error: {exc}") +raise HTTPException(status_code=502, detail=f"Connection error: {exc}") +``` + +We read an early 502 as "TCP connected, modem bridged, device mute" and built +a whole theory on it. It was almost certainly a connect timeout. +**Always read the `detail` string** — "connect failed" and "device didn't +answer" are completely different problems and the status code will not +separate them. + +--- + +## What actually worked — invert the direction + +The key observation is in the log above: + +> `TCP recvhost ... state TCPMode::kClosed` → `Connect to IP: 0.0.0.0 Port 0` + +**The modem auto-dials its Destination whenever serial data arrives while +closed.** So instead of fighting for inbound, give it somewhere to dial: +point `Destination Address` at our own `ach_server` and the device's own +75-second attempts become **device-initiated sessions the modem bridges +correctly**. No race, no contention, worst case a 75-second wait. + +### Procedure + +1. **Run the rescue server** on a host the modem can reach (public IP + + forwarded port): + + ```bash + cd /home/serversdown/seismo-relay + .venv/bin/python -u bridges/ach_server.py --port 12345 \ + -o bridges/captures/-diag --stop-monitoring -v + ``` + +2. **Point the modem at it** — ACEmanager → Serial → Port Configuration → + `Destination Address` = your public IP, `Destination Port` = 12345. + +3. **Wait for the call-in.** `--stop-monitoring` fires SUB 0x97 at step 1.5, + after the handshake and *before* the event walk. Confirm via + `rescue.json` in the session directory: + + ```json + {"peer": "166.246.64.226:60921", "stop_monitoring": "ok"} + ``` + +4. **Restore the modem's Destination** once you are done, then finish the + device side (disable ACH, erase) through whichever channel works. + +On BE12599 the first call-in landed at 20:58:11 and reported +`stop_monitoring: ok`; a second at 20:58:20 confirmed it. `is_monitoring: +false` was still true **6½ hours later** — the fix is durable. + +--- + +## Hard-won gotchas (do not re-derive) + +- **Never leave the Destination pointed at a host with nothing listening.** + That is the worst state available: the device still dials, the modem still + flips, inbound stays blocked, and nothing is delivered. An 8-minute gap + with the listener down produced a spurious inbound timeout that cost + another round of misdiagnosis. + +- **Stopping monitoring removes your call-in channel.** ACH is "after event + recorded"; no new events means no new dials. The backlog sitting in memory + does *not* re-arm it. After a successful stop the unit goes quiet and you + need the modem cycled (works — produced a call-in), the scheduled daily call + (BE12599 calls at **05:00:14 device-local**, per §8e), or working inbound. + **Plan the order before you fire the stop.** + +- **`--events-only` silently breaks dedup.** It skips the device-info step, + so the serial is never read; `ach_state.json` then keys on + `peer:ephemeral_port`, which is unique per connection. Every session looks + like a new unit, starts from key 0, and re-downloads the same event. Four + sessions on BE12599 downloaded the identical event four times and made zero + progress on the backlog. Events also file as `serial=UNKNOWN` with a + `M000…` BW filename (serial_numeric 0) instead of `N599…`. + **Do not use `--events-only` when you intend to download anything.** + +- **`/device/events/index` reported `lifetime_count: 0`** on a unit with years + of history. Suspected decode bug in the SUB 0x08 field offset — do not + trust that number. The 88-byte payload is preserved in the `raw_hex` field + if someone wants to chase it. + +- **Memory used cross-checks the event keys exactly:** + `last_key − buffer_start = memory_total − memory_free`. On BE12599: + `0x011230ec − 0x01110000 = 78,060` and `983,028 − 904,968 = 78,060`. + Useful sanity check that you are reading the keys right. + +--- + +## Final state (2026-09-17 ~01:30 local) + +- `is_monitoring: false`, held 6½ hours +- Battery 6.76 V +- Memory 78,060 / 983,028 bytes used (8%) +- `first_key 01121728`, `last_key 011230ec` — ~6.6 KB of addressable event + chain, roughly 3 events +- ACH still **enabled** — to be disabled after the backlog is preserved +- Modem Destination still pointed at tmi-dev — to be restored +- ⚠ **Do not re-enable ACH until the connector is serviced.** Tran is still + sitting at 0.400 and the loop restarts the moment monitoring resumes. diff --git a/docs/superpowers/plans/2026-09-17-rescue-listener.md b/docs/superpowers/plans/2026-09-17-rescue-listener.md new file mode 100644 index 0000000..58a5de4 --- /dev/null +++ b/docs/superpowers/plans/2026-09-17-rescue-listener.md @@ -0,0 +1,134 @@ +# Plan — "Rescue Listener": a first-class tool for the inverted rescue + +**Status:** proposal, not started. Written 2026-09-17 ~01:40 local, straight +off the BE12599 incident. Open questions at the bottom need Brian's answer +before anything is built. + +**Background:** `docs/runbooks/wedged_unit_recovery.md`, "Second incident — +BE12599". The manual version of this worked; this plan is about making it a +tool instead of a sequence of remembered steps at 1 AM. + +--- + +## The problem, stated plainly + +When a unit is wedged in the BE12599 mode — geophone offset above trigger, +recording back-to-back, ACH dialing constantly, device stuck repeating an AT +modem-init string and therefore **deaf to S3 over inbound** — the only channel +that works is the one the *device* opens. + +Recovering it currently means: + +1. Remember that `bridges/ach_server.py` exists and takes the right flags +2. Start it by hand on a box the modem can reach, with a public port forwarded +3. Go into ACEmanager and repoint the modem's Destination +4. Watch a terminal for a call-in +5. Read `rescue.json` to find out whether it worked +6. Go back into ACEmanager and repoint the modem to where it belongs +7. **Not forget step 6**, because leaving the Destination pointed at a dead + listener is worse than never having started + +That is six manual steps and one landmine, executed under pressure while a +unit floods the office server. + +## What the tool should be + +**A "rescue listener" an operator can start for one unit, which handles +whatever that unit says when it calls in, and refuses to go away until the +operator confirms the modem has been pointed back.** + +Lifecycle: + +1. **Start** — operator names the target unit and starts a rescue listener. + The tool reports the exact address/port to enter in ACEmanager, plus the + actions it will take. +2. **Operator repoints the modem** to that address. +3. **Wait** — listener sits there. Live status: "waiting for call-in", + elapsed, last-seen. +4. **Act** — on call-in, run the configured rescue actions automatically, + in a safe order, each independently guarded. Report per-action outcome. +5. **Hold** — the listener **stays up** and keeps reporting, because the + modem is still pointed at it. +6. **Confirm & stop** — the operator explicitly confirms the Destination has + been restored (to `0.0.0.0`, or to the office Instantel ACH server). + Only then does the listener shut down. + +Step 6 is the whole point of making this a tool. It is the step that is +easiest to skip and most expensive to skip. + +## Default action set + +Ordered deliberately — see "order matters" below. + +| # | Action | Default | Why | +|---|---|---|---| +| 1 | **Stop monitoring** (SUB 0x97) | ✅ on | Halts recording; ends the trigger→record→dial loop at its source. Already implemented as `--stop-monitoring`. | +| 2 | **Drain events** to a diagnostics store | ⚙ configurable | The backlog is usually evidence, not garbage — see the BE12599 offset investigation. Must NOT land in the prod SFM DB. | +| 3 | **Disable ACH** (SUB 0x2C/0x7E/0x7F) | ❌ off by default | Stops the dialing — **and stops your only channel**. Opt-in, and ideally gated on step 1 having succeeded. | +| 4 | **Erase events** | ❌ off by default | Destructive. Only after a verified drain. | + +### Order matters — the lesson from BE12599 + +Stopping monitoring *removes the call-in trigger*. ACH fires on "after event +recorded"; with recording stopped, the unit has no reason to dial again, even +though the backlog is still sitting in its memory. So a naive +"stop + disable + erase, all at once" rescue can silence the unit before +you've collected anything, leaving you with no channel and a device full of +evidence. + +The tool should either sequence around this or warn loudly about it. My +instinct is: **stop monitoring immediately** (it's the bleeding), then drain +across however many call-ins it takes, and treat disable-ACH/erase as a +separate, explicit "finish" action once the operator is satisfied. + +## Where it should live — open question, with a proposal + +The natural tier is **SFM** (device-side, per the three-tier model in +CLAUDE.md). But the rescue listener must be reachable *from the cellular +network*, which is a deployment constraint SFM's usual profile doesn't have. + +**Proposal worth considering:** run it at the office, beside the real Instantel +ACH server, on a **different port** (e.g. 12346 while Instantel holds 12345). +Then the ACEmanager change is a **port change, not an IP change** — smaller, +faster, less to get wrong, and trivially reversible. It also means the office +public IP (already stable and known) is the destination, rather than whatever +Brian's dynamic home IP happens to be that week. + +The tmi-dev approach used on BE12599 worked, but required a router forward and +ran into the dynamic-IP problem in the same session. + +## Open questions + +1. **Where does it run?** Office beside Instantel ACH (port swap), SFM on the + NAS, or ad-hoc on tmi-dev? Affects everything else. +2. **What drives it?** Terra-View admin page (fits "operator UI"), an SFM + endpoint pair (`POST /device/rescue_listener/start` + `/stop` + `/status`), + or a CLI wrapper? A long-lived listener doesn't fit the request/response + endpoint shape well — probably needs a background task with a status poll. +3. **How does it identify the unit?** It can't know the serial until the + device calls in and the handshake reads it. Allowlist by modem IP? Accept + anything and report what showed up? +4. **Where do drained events go?** A per-incident diagnostics store + (`bridges/captures/-diag`) seems right — explicitly *not* the prod + SFM DB. Does that store need to be a first-class thing with its own + retention, or is a directory fine? +5. **How is "confirm the modem is repointed" verified?** Operator attestation + (a button), or can we actually probe it? If the listener stops seeing + call-ins that's weak evidence; if inbound to the unit starts working that's + stronger. +6. **Multi-unit?** One listener per incident, or one listener that handles any + unit that dials in? Probably the former for safety. +7. **Timeout / abandonment policy.** If nobody ever confirms, does it run + forever? Alert after N hours? + +## What already exists + +- `bridges/ach_server.py` — the listener itself, with `--stop-monitoring`, + `--disable-ach`, `--rescue` (added on `feat/ach-rescue-on-connect`, commit + `9f1050b`), `--clear-after-download`, `--max-events`, `--allow-ip`. +- Per-session `rescue.json` recording per-action outcomes. +- Isolated per-output-dir SQLite + waveform store, so a diagnostics capture is + already separate from prod by construction. + +So the gap is not protocol work — it's lifecycle, operator surface, and the +confirmation gate. Most of the risk is in questions 1 and 2.