From c6fc3d0241cbfadef389a847abfee1792b3573aa Mon Sep 17 00:00:00 2001 From: serversdown Date: Thu, 17 Sep 2026 05:45:26 +0000 Subject: [PATCH] =?UTF-8?q?docs:=20BE12599=20incident=20=E2=80=94=20the=20?= =?UTF-8?q?inverted=20rescue,=20plus=20a=20rescue-listener=20plan?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The wedged_unit_recovery runbook covered exactly one failure mode. BE12599 turned out to be a second one wearing the same symptoms, and the existing procedure did not work on it. Adds a "TWO failure modes" table up front so the next incident branches correctly, and a full second-incident section covering what the ALEOS serial debug log revealed: the device repeating a 29-byte AT modem-init string (ATQ1/ATE0/ATS0=2, no ATD) every 75 s, never getting an OK because the modem is in TCP data mode, and therefore never entering S3 mode at all. Inbound cannot win against that, no matter how well framed. Also records the two red herrings, since together they cost ~90 minutes: the RV50 trusted-IP whitelist drops non-listed sources silently (presents as a connect timeout, and Brian's dynamic dev IP had rotated off the list), and sfm/server.py returns 502 for BOTH "Protocol error:" and "Connection error:", so a 502 was misread as "TCP connected, device mute" and a theory built on it. And the gotchas worth never re-deriving: slow_drip's send_error=null plus a full duration is not success (only bytes_received > 0 is); stopping monitoring removes the call-in trigger, so it costs you the channel; --events-only skips the device-info step, so the serial is never read and ach_state keys on peer:ephemeral_port, silently breaking dedup and re-downloading the same event every session. The plan doc captures the tool Brian wants built out of this — a rescue listener with a real lifecycle and, critically, a confirmation gate before shutdown, because leaving the modem's Destination pointed at a dead listener is worse than never having started. Open questions are listed rather than guessed at. Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_01Qcu9ByJfuKBQxmrWb8rSrN --- docs/runbooks/wedged_unit_recovery.md | 224 ++++++++++++++++++ .../plans/2026-09-17-rescue-listener.md | 134 +++++++++++ 2 files changed, 358 insertions(+) create mode 100644 docs/superpowers/plans/2026-09-17-rescue-listener.md 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.