Release v0.31.0 — report parity + the inverted rescue (0.29.0 → 0.31.0) #40
+31
-10
@@ -6,17 +6,28 @@ All notable changes to seismo-relay are documented here.
|
||||
|
||||
## Unreleased
|
||||
|
||||
**Blastware Event/FFT-Report parity — the FFT, the USBM compliance chart, and
|
||||
the sensor self-check.** Three analyses Blastware derives from event data,
|
||||
reverse-engineered against BE12844 (MiniMate Plus) reports and reproduced in
|
||||
seismo-relay: the compliance chart and the sensor-check strip now render on
|
||||
the event-report PDF, and the FFT reproduces Blastware's FFT Report. All three
|
||||
are additive and read from data already on disk — the `.h5` samples and the
|
||||
retained raw BW binary — so there is **no `.h5`/DB change, no migration, and no
|
||||
backfill**: a report regenerated for an existing event simply gains the new
|
||||
panels.
|
||||
|
||||
### Added
|
||||
- **Rescue-on-connect for `bridges/ach_server.py`** — `--stop-monitoring`
|
||||
(SUB 0x97), `--disable-ach` (SUB 0x2C read → 0x7E write → 0x7F confirm) and
|
||||
`--rescue` (both). They fire immediately after the startup handshake and
|
||||
**before** the event walk, so a unit that is recording back-to-back on a
|
||||
stuck-triggered geophone is quieted as early in the session as possible.
|
||||
Each action is independently guarded — a failure does not abort the download
|
||||
— and the outcome is written to `rescue.json` in the session directory.
|
||||
|
||||
This inverts the `docs/runbooks/wedged_unit_recovery.md` approach. That
|
||||
runbook reaches the unit *inbound* and clears the modem's Destination Address
|
||||
to stop it dialing. When the device is instead wedged mid-modem-init — ALEOS
|
||||
logs `tcpmode trying to send to invalid socket` and re-runs `Initialize Auto
|
||||
answer` every ~75 s, orphaning any held inbound session — inbound cannot win.
|
||||
Pointing the modem's Destination at an `ach_server` and letting the unit call
|
||||
*us* gives a device-initiated session the modem bridges properly.
|
||||
|
||||
⚠ Prefer `--stop-monitoring` alone on first contact. `--disable-ach` stops
|
||||
the unit calling, which is the only channel to a unit in this state; stopping
|
||||
the recording ends the call-home loop on its own when ACH is
|
||||
"after event recorded".
|
||||
|
||||
- **Blastware-compatible channel FFT (`waveform_fft`).** Reproduces Blastware's
|
||||
FFT Report: DC-removed, no window, zero-padded to 4096 (0.25 Hz bins at
|
||||
1024 sps), single-sided `2/N` amplitude. Matches Blastware's dominant
|
||||
@@ -64,6 +75,16 @@ panels.
|
||||
|
||||
---
|
||||
|
||||
### Migration
|
||||
|
||||
**None.** Every change here is additive and reads from data already on disk —
|
||||
the `.h5` samples and the retained raw BW binary. No `.h5`/DB change, no
|
||||
schema change, no migration, no backfill, and **no `TOOL_VERSION` bump**: a
|
||||
report regenerated for an existing event simply gains the new panels, and the
|
||||
`ach_server` rescue flags don't touch the codec.
|
||||
|
||||
---
|
||||
|
||||
## v0.30.0 — 2026-09-12
|
||||
|
||||
**The series-4 correctness release** — the Thor / Micromate counterpart to
|
||||
|
||||
@@ -89,6 +89,47 @@ When new information about the protocol is discovered, please update the instant
|
||||
|
||||
---
|
||||
|
||||
## Changelog & release convention
|
||||
|
||||
**Feature branches do NOT touch `CHANGELOG.md`. Write the entry on `dev`, as
|
||||
part of finishing the merge, under `## Unreleased`. Cut the version on `dev` in a
|
||||
dedicated release commit when you are ready to ship to `main`.**
|
||||
|
||||
- **The changelog is written on `dev`, never on a feature branch.** With
|
||||
several branches in flight they all edit the same few lines at the top of
|
||||
the file and conflict every time. Writing it once, after the merge, also
|
||||
lets it describe what actually *landed* — including anything that changed
|
||||
during conflict resolution.
|
||||
- ⚠ **The merge is not finished until `## Unreleased` is updated.** Same sitting,
|
||||
not "later" — that is the one failure mode of writing it after the fact.
|
||||
Reconstruct from the branch's own commit messages:
|
||||
`git log --oneline dev..<branch>` before you merge, or
|
||||
`git log --oneline <merge-base>..<branch>` after.
|
||||
- **No preamble under `## Unreleased`** — just the `### Added` / `### Changed` /
|
||||
`### Fixed` lists. The themed opening paragraph gets written at release
|
||||
time, when the whole release is visible and can be named honestly. A theme
|
||||
written when the first item landed is stale by the third.
|
||||
- ⚠ **State the operational consequence** on any entry touching the codec, the
|
||||
waveform store, or the DB — **including when it is "none."** "requires
|
||||
`backfill_sidecars.py` + `backfill_event_shape.py`, ~2 h on the NAS",
|
||||
"`TOOL_VERSION` bumped", "no schema change, no migration". Silence is
|
||||
ambiguous; "none" is information. This repo's changelog is how future-you
|
||||
learns whether a deploy costs two hours.
|
||||
- **Releases are cut on judgement, not on a schedule or a merge.** `Unreleased`
|
||||
is the staging area for whatever is going into the next release; when enough
|
||||
has accumulated to be worth shipping, it gets a number and a date. Nothing
|
||||
about a merge to `dev` triggers a release.
|
||||
- **Cutting a release** is its own `chore(release): vX.Y.Z — <theme>` commit on
|
||||
`dev`, renaming `## Unreleased` → `## vX.Y.Z — YYYY-MM-DD` and touching:
|
||||
`CHANGELOG.md`, `pyproject.toml`, the version line in `CLAUDE.md` and
|
||||
`README.md`, and `minimateplus/event_file_io.py` (`TOOL_VERSION`) **when the
|
||||
codec changed** — that constant gates `.h5` regeneration.
|
||||
- **`main` carries only released versions.** No `## Unreleased` section there;
|
||||
it lands via the `dev` → `main` PR. `main` lagging `dev` by a version is
|
||||
normal.
|
||||
|
||||
---
|
||||
|
||||
## Architecture: three-tier conceptual model
|
||||
|
||||
seismo-relay is a **suite of cooperating components**, not a single app.
|
||||
|
||||
@@ -177,6 +177,8 @@ class AchSession:
|
||||
store: "WaveformStore",
|
||||
clear_after_download: bool = False,
|
||||
restart_monitoring: bool = False,
|
||||
rescue_stop_monitoring: bool = False,
|
||||
rescue_disable_ach: bool = False,
|
||||
force_redownload: bool = False,
|
||||
) -> None:
|
||||
self.sock = sock
|
||||
@@ -190,6 +192,9 @@ class AchSession:
|
||||
self.store = store
|
||||
self.clear_after_download = clear_after_download
|
||||
self.restart_monitoring = restart_monitoring
|
||||
# Rescue actions for a runaway unit — fired before the event walk.
|
||||
self.rescue_stop_monitoring = rescue_stop_monitoring
|
||||
self.rescue_disable_ach = rescue_disable_ach
|
||||
# `force_redownload` tells this session to ignore ach_state and
|
||||
# re-download every event currently on the device, regardless of any
|
||||
# (key, timestamp) match. Useful as a manual override when state has
|
||||
@@ -290,6 +295,41 @@ class AchSession:
|
||||
root_logger.addHandler(fh)
|
||||
|
||||
try:
|
||||
# ── Step 1.5: rescue actions ──────────────────────────────────────
|
||||
# Fired BEFORE the event walk so a runaway unit is quieted as early
|
||||
# in the session as possible. A unit whose geophone sits above the
|
||||
# trigger threshold records back-to-back and, with ACH set to "after
|
||||
# event recorded", re-dials every time — saturating its own firmware
|
||||
# so it never services inbound requests. See
|
||||
# docs/runbooks/wedged_unit_recovery.md.
|
||||
#
|
||||
# Each action is independently guarded: a failure here must not
|
||||
# abort the download that follows.
|
||||
if self.rescue_stop_monitoring or self.rescue_disable_ach:
|
||||
rescue: dict = {"peer": self.peer, "ts": ts}
|
||||
|
||||
if self.rescue_stop_monitoring:
|
||||
log.info("Step 1.5: RESCUE — stop monitoring (SUB 0x97)")
|
||||
try:
|
||||
client.stop_monitoring()
|
||||
rescue["stop_monitoring"] = "ok"
|
||||
log.info(" stop monitoring OK — device should stop recording")
|
||||
except Exception as exc:
|
||||
rescue["stop_monitoring"] = f"failed: {exc}"
|
||||
log.error(" stop monitoring FAILED: %s", exc)
|
||||
|
||||
if self.rescue_disable_ach:
|
||||
log.info("Step 1.5: RESCUE — disable auto call home (SUB 0x2C/0x7E/0x7F)")
|
||||
try:
|
||||
client.set_call_home_config(auto_call_home_enabled=False)
|
||||
rescue["disable_ach"] = "ok"
|
||||
log.info(" disable ACH OK — unit should stop calling home")
|
||||
except Exception as exc:
|
||||
rescue["disable_ach"] = f"failed: {exc}"
|
||||
log.error(" disable ACH FAILED: %s", exc)
|
||||
|
||||
_save_json(session_dir / "rescue.json", rescue)
|
||||
|
||||
# ── Step 2: device info ───────────────────────────────────────────
|
||||
device_info = None
|
||||
if not self.events_only:
|
||||
@@ -747,6 +787,13 @@ def serve(args: argparse.Namespace) -> None:
|
||||
print(f" Max events per session: {max_ev if max_ev else 'unlimited'}")
|
||||
print(f" Clear device after download: {'YES' if args.clear_after_download else 'no'}")
|
||||
print(f" Restart monitoring after download: {'YES' if args.restart_monitoring else 'no'}")
|
||||
_stop_mon = args.stop_monitoring or args.rescue
|
||||
_dis_ach = args.disable_ach or args.rescue
|
||||
print(f" RESCUE stop monitoring on connect: {'YES' if _stop_mon else 'no'}")
|
||||
print(f" RESCUE disable auto call home: {'YES' if _dis_ach else 'no'}")
|
||||
if _stop_mon and args.restart_monitoring:
|
||||
print(" !! --restart-monitoring will re-start the unit after download,")
|
||||
print(" undoing --stop-monitoring. Drop one of them.")
|
||||
print(f" Force re-download all (ignore state): {'YES' if args.force_redownload_all else 'no'}")
|
||||
print(f"{'='*60}")
|
||||
print(f"\n Point your test unit's ACEmanager call-home settings to:")
|
||||
@@ -788,6 +835,8 @@ def serve(args: argparse.Namespace) -> None:
|
||||
store=store,
|
||||
clear_after_download=args.clear_after_download,
|
||||
restart_monitoring=args.restart_monitoring,
|
||||
rescue_stop_monitoring=args.stop_monitoring or args.rescue,
|
||||
rescue_disable_ach=args.disable_ach or args.rescue,
|
||||
force_redownload=args.force_redownload_all,
|
||||
)
|
||||
t = threading.Thread(target=session.run, daemon=True, name=f"ach-{peer}")
|
||||
@@ -862,6 +911,32 @@ def parse_args() -> argparse.Namespace:
|
||||
"DCD on disconnect — without this the unit stays idle after a call-home."
|
||||
),
|
||||
)
|
||||
p.add_argument(
|
||||
"--stop-monitoring",
|
||||
action="store_true",
|
||||
default=False,
|
||||
help=(
|
||||
"RESCUE: send SUB 0x97 (stop monitoring) immediately after the "
|
||||
"handshake, before any event download. Use on a unit that is "
|
||||
"recording back-to-back because of a stuck-triggered geophone."
|
||||
),
|
||||
)
|
||||
p.add_argument(
|
||||
"--disable-ach",
|
||||
action="store_true",
|
||||
default=False,
|
||||
help=(
|
||||
"RESCUE: disable Auto Call Home on the device (SUB 0x2C read → "
|
||||
"0x7E write → 0x7F confirm) immediately after the handshake. The "
|
||||
"unit stops dialing out until ACH is explicitly re-enabled."
|
||||
),
|
||||
)
|
||||
p.add_argument(
|
||||
"--rescue",
|
||||
action="store_true",
|
||||
default=False,
|
||||
help="Shorthand for --stop-monitoring --disable-ach.",
|
||||
)
|
||||
p.add_argument(
|
||||
"--clear-after-download",
|
||||
action="store_true",
|
||||
|
||||
@@ -1,6 +1,7 @@
|
||||
# Runbook — Recovering a wedged unit stuck in a call-home loop
|
||||
|
||||
**Original incident:** BE9558H at `166.246.130.1:9034`, recovered 2026-05-17.
|
||||
**Incidents:** BE9558H at `166.246.130.1:9034`, 2026-05-17 (Method B) ·
|
||||
BE12599 at `166.246.64.226:9034`, 2026-09-16 (Method A).
|
||||
|
||||
A field unit with a stuck-triggered geophone (or any hardware fault causing
|
||||
constant event triggering) will record events back-to-back, and if Auto Call
|
||||
@@ -14,6 +15,33 @@ This runbook describes how to break the loop and recover control.
|
||||
|
||||
---
|
||||
|
||||
## ⚠ Two cures for one disease — intercept first
|
||||
|
||||
Both incidents below are the **same failure**: a geophone offset crosses the
|
||||
trigger level, the unit records back-to-back, ACH set to "after event
|
||||
recorded" dials continuously, and the unit becomes unreachable because its
|
||||
modem is in client mode almost all of the time.
|
||||
|
||||
There are two ways to get a Stop Monitoring command into it.
|
||||
|
||||
| | **A — intercept the call** (preferred) | **B — catch it between calls** (original) |
|
||||
|---|---|---|
|
||||
| Idea | Be the server it dials. Point the modem's Destination at our own ACH server and answer it. | Clear the Destination so it stops dialing, then race a Stop into the gap. |
|
||||
| Needs inbound? | **No — the unit calls us** | Yes: working inbound TCP to the modem |
|
||||
| Determinism | Deterministic — it dials every ~75 s, we only have to be listening | A race. BE9558H took ~7 h of attempts before one landed. |
|
||||
| Tool | `bridges/ach_server.py --stop-monitoring` | `scripts/slow_drip.sh` |
|
||||
| Proven on | BE12599, 2026-09-16 | BE9558H, 2026-05-17 |
|
||||
|
||||
**Method A is the standard procedure now.** The unit won't answer us because
|
||||
it is on the phone — so stop dialing it and be the one it calls. It rings,
|
||||
we pick up, take its data, and tell it to stop calling here.
|
||||
|
||||
Method B is kept because it is proven, and because A needs a listener the
|
||||
modem can actually reach (public IP + forwarded port). When you have that,
|
||||
don't race it — intercept it.
|
||||
|
||||
---
|
||||
|
||||
## Symptoms
|
||||
|
||||
- Terra-View / SFM `/device/info` either hangs or fails on `count_events()`.
|
||||
@@ -31,9 +59,85 @@ If you see *all* of these, the unit is in this exact failure mode.
|
||||
|
||||
---
|
||||
|
||||
## Quick reference — how to recover
|
||||
## Method A (preferred) — intercept the call
|
||||
|
||||
You need **ACEmanager access** to the unit's modem.
|
||||
You need **ACEmanager access** and a host the modem can dial: public IP with
|
||||
the listener's port forwarded to it.
|
||||
|
||||
### A1 — start the listener BEFORE touching the modem
|
||||
|
||||
```bash
|
||||
cd /home/serversdown/seismo-relay
|
||||
tmux new -s rescue
|
||||
.venv/bin/python -u bridges/ach_server.py --port 12345 \
|
||||
-o bridges/captures/<unit>-diag --stop-monitoring -v
|
||||
```
|
||||
|
||||
⚠ **Listener first, always.** A Destination pointed at a dead port is the
|
||||
worst state available — the device still dials, the modem still flips to
|
||||
client mode, inbound stays blocked, and nothing gets delivered.
|
||||
|
||||
Do **not** add `--events-only` (it silently breaks dedup — see gotchas), and
|
||||
do **not** add `--disable-ach` yet (see A4).
|
||||
|
||||
### A2 — point the modem at it
|
||||
|
||||
ACEmanager → **Serial → Port Configuration**:
|
||||
|
||||
| Field | Set to |
|
||||
|---|---|
|
||||
| **Destination Address** | the listener's public IP |
|
||||
| **Destination Port** | the listener's port (e.g. `12345`) |
|
||||
|
||||
Apply. The modem auto-dials its Destination whenever serial data arrives
|
||||
while the serial port is closed — so the unit's own retry cycle now lands on
|
||||
you instead of nowhere.
|
||||
|
||||
### A3 — answer, and stop the bleeding
|
||||
|
||||
Within ~75 s you should see a call-in. `--stop-monitoring` fires SUB 0x97 at
|
||||
step 1.5 — after the handshake, **before** the event walk — so the recording
|
||||
halts at the earliest possible moment in the session. Confirm via
|
||||
`rescue.json` in the session directory:
|
||||
|
||||
```json
|
||||
{"peer": "166.246.64.226:60921", "stop_monitoring": "ok"}
|
||||
```
|
||||
|
||||
That is the bleeding stopped. Everything after this is cleanup.
|
||||
|
||||
### A4 — drain the backlog, THEN disable ACH
|
||||
|
||||
⚠ **Order matters, and it is counter-intuitive.** Stopping monitoring also
|
||||
removes your call-in trigger: ACH fires on "after event recorded", so with
|
||||
recording stopped the unit has no reason to dial again. The backlog sitting
|
||||
in its memory does **not** re-arm it.
|
||||
|
||||
So if the stored events are worth keeping — and on a fault unit they usually
|
||||
are, they're the evidence — drain them across however many call-ins it takes
|
||||
*before* you silence it. Only then add `--disable-ach` (or use
|
||||
`scripts/rescue_device.sh <host> <port> --no-erase`).
|
||||
|
||||
If the unit has gone quiet and you still need it, cycling the modem produces
|
||||
a call-in, and a unit with a scheduled daily call will dial at its configured
|
||||
time regardless.
|
||||
|
||||
### A5 — restore the Destination, and confirm you did
|
||||
|
||||
Put `Destination Address` back to `0.0.0.0` (or the office Instantel ACH
|
||||
server) once you are finished, and only stop the listener after that is done.
|
||||
|
||||
### A6 — do NOT re-enable ACH until the hardware fault is repaired
|
||||
|
||||
Otherwise the loop restarts the moment monitoring resumes and you run this
|
||||
runbook again.
|
||||
|
||||
---
|
||||
|
||||
## Method B (fallback) — catch it between calls
|
||||
|
||||
The original 2026-05 procedure. Use when you cannot stand up a listener the
|
||||
modem can reach. You need **ACEmanager access** to the unit's modem.
|
||||
|
||||
### Step 1: stop the modem's mode-flipping
|
||||
|
||||
@@ -253,3 +357,223 @@ 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.
|
||||
|
||||
**Same disease, inverted cure.** Method B's Step 1 *did* work — clearing the
|
||||
Destination stopped the dial-outs, confirmed in the ALEOS log. It was Step 2
|
||||
that didn't land, and rather than keep racing we turned the rescue around:
|
||||
gave the unit a different server to call, and answered it.
|
||||
|
||||
Total time ≈ 5 h, of which ~90 min went to two red herrings documented below.
|
||||
Much of the rest was rediscovering the May procedure, which is why the
|
||||
"two cures" table now sits at the top of this file.
|
||||
|
||||
---
|
||||
|
||||
## 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 unit is on the phone
|
||||
|
||||
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**.
|
||||
|
||||
**While it is in this state it is busy placing a call, not listening for
|
||||
us.** This is almost certainly what BE9558H was doing too — we simply never
|
||||
turned on ALEOS_SERIAL debug in May to look. It is not a different disease;
|
||||
it is the same one, seen properly for the first time.
|
||||
|
||||
It is also the argument for Method A in one picture: the unit is mid-dial
|
||||
every ~75 s, and our inbound Stop has to thread the gaps between those
|
||||
attempts. Give it somewhere to dial and the problem inverts into a
|
||||
deterministic one.
|
||||
|
||||
### 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.**
|
||||
|
||||
⚠ **In fairness to slow_drip: it got exactly one attempt here**, run ~90 s
|
||||
after a modem reboot, with a dead session visible in the log at 20:19:17 in
|
||||
that same window. BE9558H took hours of attempts before one landed. Method B
|
||||
was not ruled out on BE12599 so much as abandoned in favour of something that
|
||||
doesn't need luck.
|
||||
|
||||
---
|
||||
|
||||
## ⚠ 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/<unit>-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.
|
||||
|
||||
@@ -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/<unit>-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.
|
||||
Reference in New Issue
Block a user