Wait for the modem, and supervise startup instead of dying silently

CLAUDE.md

@@ -22,6 +22,7 @@ Reasoning belongs in `docs/`.
 | `docs/pin-allocation.md` | Which sensor is on which expander pin, and why allocation is not installation |
 | `docs/block-detector-wiring.md` | The LM-iD output stage: its two modes, why Input A is unpowered, the 3.3 V hazard if it is not |
 | `docs/point-position-feedback.md` | Board 3 (`0x22`): why two inputs per point, the `0x22` allocation, and why command and feedback being different devices is the hazard. **Not built** |
+| `docs/startup-and-status-led.md` | The power-on race with the modem, the retry-then-reset policy, and **what the LED flash codes mean** |
 | `docs/DEVELOPMENT_NOTES.md` | Module conventions, the MCP23017 pin map, hardware wiring |
 | `docs/PN7150_STATE_MACHINE_PLAN.md` | The NCI state machine the RFID reader implements |
 | `docs/MQTT_AT_COMMANDS.md` | The ESP-AT command set the transport speaks |
@@ -113,8 +114,11 @@ publish contract readings that the orchestrator trusts, and the block follows th
 ```
 src/lib/     -> device /lib
   mqtt_at.py            ESP-AT transport. Length-aware frames, reconnect, failures returned.
+                        Waits for the modem to answer before commanding it.
   layout_mqtt.py        The contract: topics, payloads, QoS, retention, the 25 s re-assert.
   sensor_wiring.py      Allocation vs installed, and the occupancy polarity. No `machine`.
+  node_startup.py       Retry-then-reset startup policy, and the LED code table. No `machine`.
+  status_led.py         The onboard LED as a countable flash code. No `machine`.
   mcp23017_io.py        I2C expander, in and out. Poll-only.
   input_pin_monitor.py  Native Pico GPIO, IRQ + timer debounce. Currently unused.
   pcf8591_adc.py        I2C ADC. Wired to nothing; no contract topic for analog yet.
@@ -151,6 +155,11 @@ directory on the path for the same reason.
 
 ### Traps
 
+- **A node that cannot start flashes a code and reboots — it no longer dies quietly.**
+  Solid LED is running, `N` flashes is a failure at stage `N`, dark is no power or a hard
+  crash. Codes and the retry policy are in `docs/startup-and-status-led.md`. Until 2026-08-27
+  a modem still booting when the Pico reached `AT+RST` killed the node outright, with the LED
+  never lighting — the intermittent "doesn't come up after a power cycle".
 - **A point is commanded and read by two devices that know nothing about each other.** The
   Cobalt takes DCC accessory commands and can report nothing; position comes only from its
   `S2` contacts on board 3. So `points.dcc_address` (orchestrator) and `pointId` → pins (here)

docs/startup-and-status-led.md

@@ -0,0 +1,112 @@
+# Node startup, and what the LED is telling you
+
+## The fault this is about
+
+The IO node did not always come up after a power cycle. When it failed it failed
+completely and silently: the onboard LED never lit, nothing appeared on the broker, and
+the board sat at a REPL until someone power-cycled it again. The orchestrator behaved
+correctly — the Goods Shed sensors went stale, the block degraded to `unknown`, and the
+fail-safe rule treated that as occupied — but nothing anywhere pointed at the node.
+
+That is the failure this repo rates worst. The node stopped reporting and said nothing.
+
+## Root cause: the Pico wins the power-on race
+
+The Pico and the ESP-AT modem come out of a power cycle together, and the Pico is much
+faster. Measured on the bench, 2026-08-27:
+
+| Event | Time from power-on |
+|---|---|
+| Pico reaches its first AT command | ~300 ms (MicroPython's boot, plus **19 ms** of I2C and expander setup) |
+| Modem reaches `ready` | **1.2 s – 3.5 s** |
+
+Both ends of the modem's spread were measured in the same session: one reset reached
+`ready` at 3471 ms, another at 1232 ms. The variance is Ethernet link negotiation —
+`+ETH_CONNECTED` came at 3460 ms and 1221 ms respectively.
+
+`MQTTATClient.setup()` opened by sending `AT+RST` and waiting on the constructor's
+2000 ms default. So the deadline for a reply fell about 2.3 s after power-on, while the
+modem became ready somewhere between 1.2 s and 3.5 s. **Sometimes it made it, sometimes
+it did not** — which is exactly the reported "doesn't always start".
+
+A command sent into that window is not refused. It is swallowed whole: no echo, no
+reply. Reproduced deterministically by commanding the modem mid-boot:
+
+```
+STEP 3 - the cold-boot race: command the modem while it is still booting.
+  modem is now rebooting; waiting 200 ms then sending AT+RST as setup() does
+  -> OK within setup()'s 2000 ms default? NO -> RuntimeError('AT+RST failed')
+```
+
+The exception propagated out of `main()`, which was called bare at module scope, so
+`main.py` simply ended.
+
+## Fix 1: ask before commanding
+
+`MQTTATClient.wait_for_modem()` polls a bare `AT` until the modem answers, for up to
+15 s, before anything else is sent. Only then does `AT+RST` go out. A modem that never
+answers now raises `ModemNotResponding` rather than looking like a failed reset.
+
+A related blind spot was closed at the same time: `wait_for_line()` only inspects lines
+recorded *after* it is called, so an `+ETH_GOT_IP` arriving in the same read as the
+reset's own `OK` would have been missed, and `setup()` would have sat out its full 30 s
+and then raised as though the network were down. `setup()` now checks what has already
+arrived before it starts waiting.
+
+## Fix 2: a node that cannot start must not fall silent
+
+`node_startup.start_supervised()` retries startup three times — flashing for 2 s, 5 s
+and 10 s between attempts — and then resets the board, which starts the cycle again.
+It never returns without a running node.
+
+The first retry alone covers the fault above: the modem needs at most 3.5 s from cold
+and `wait_for_modem()` now waits for it, so anything still failing on the second attempt
+is a real fault rather than the power-on race.
+
+A crash in the *main loop* is treated the same way, for the same reason — it is equally
+a node that stopped reporting without saying so.
+
+Retrying a wiring fault forever is deliberate. An expander missing at boot is usually a
+loose ribbon cable, not a permanent fact, and a board that keeps trying and keeps
+flashing is easier to find than one that is simply dark.
+
+## The flash codes
+
+| LED | Meaning |
+|---|---|
+| **Solid on** | Running: sensors configured, broker link up |
+| **Off** | No power, or a hard crash that took the board out |
+| **N flashes, pause, repeat** | Startup failed at stage N — retrying, then resetting |
+
+| Code | Stage | What it means | Where to look |
+|---|---|---|---|
+| **2** | Sensors | A configured expander is not on the I2C bus | Ribbon to boards 1/2, `config.py` addresses |
+| **3** | Modem | The ESP-AT modem is not answering AT commands | UART wiring GP8/GP9, modem power |
+| **4** | Network | The modem answers, but never reported an IP | Ethernet cable, DHCP, switch port |
+| **5** | Broker | Network is up, the MQTT link could not be made | Mosquitto on the bench box, `MQTT_HOST` |
+| **6** | Runtime | The node came up, then the main loop crashed | USB console — this one is a bug, not wiring |
+| **7** | Unknown | Something else | USB console |
+
+Codes start at 2 on purpose. A single flash is too easily confused with a board merely
+blinking on boot, and a miscounted code is worse than no code.
+
+The pattern is 200 ms on, 250 ms between flashes, and a 1400 ms gap before the cycle
+repeats. The gap is deliberately much longer than the space between flashes — otherwise
+a 2 reads as a 4. A cycle is always completed once started, so a code is never cut off
+half way through.
+
+## Reading a code
+
+Count the flashes between the long gaps. Then plug the USB lead in and look at the
+console — every failure prints the exception and the code it chose before it flashes.
+
+## What is covered by the host suite, and what is not
+
+`tests/test_mqtt_setup.py`, `tests/test_node_startup.py` and `tests/test_status_led.py`
+prove the probe, the retry-then-reset policy, the code mapping, and the flash pattern
+against a scripted modem, with no hardware attached.
+
+What the host suite cannot prove is that the LED pin actually lights and that the
+modem's real boot timing stays inside the 15 s budget. Both were checked on the bench —
+see the timings above, and `scripts/` has no permanent home for the diagnostic, which
+lived in the scratchpad.

src/apps/io-node/main.py

@@ -2,19 +2,31 @@
 
 Deployed as the board's `/main.py`, with `src/lib/*` in `/lib`. All wiring and identity
 lives in `config.py`; this file only assembles it and runs the loop.
+
+Startup is supervised (`node_startup.py`): a failure on the way up is flashed on the
+onboard LED, retried, and eventually met with a board reset, rather than dropping to a
+REPL that nobody is watching.
 """
 
-from machine import I2C, Pin
+from machine import I2C, Pin, reset
 from utime import sleep_ms, ticks_ms
 
 from layout_mqtt import LayoutMQTT
 from mcp23017_io import MCP23017Expander
 from mqtt_at import MQTTATClient
+from node_startup import CODE_RUNTIME, SensorWiringError, start_supervised
 from sensor_wiring import is_occupied, select_installed
+from status_led import StatusLED
 
 import config
 
 
+# How long to flash the runtime code before rebooting after a crash in the main loop.
+# Long enough to be seen and counted, short enough that the node is not off the air for
+# any longer than the diagnosis needs.
+RUNTIME_CRASH_FLASH_MS = 5000
+
+
 def build_sensors(i2c, wiring):
     """Configure one input pin per installed sensor, sharing an expander per address.
 
@@ -29,7 +41,7 @@ def build_sensors(i2c, wiring):
     for entry in wiring:
         address = entry["expander"]
         if address not in available:
-            raise RuntimeError(
+            raise SensorWiringError(
                 "expander 0x%02X not on the bus (found %s) — %s cannot be published"
                 % (address, [hex(a) for a in available], entry["sensor_id"]))
 
@@ -44,9 +56,12 @@ def build_sensors(i2c, wiring):
     return sensors
 
 
-def main():
-    led = Pin("LED", Pin.OUT)
+def bring_up():
+    """One complete startup attempt, from a clean slate.
 
+    Everything that can fail on the way up lives in here so a retry starts over rather
+    than resuming from whatever half-configured state the last failure left behind.
+    """
     # Resolve and validate the wiring before touching the modem, so a config mistake
     # fails immediately and obviously rather than as silence on the broker.
     wiring = select_installed(config.SENSORS, config.INSTALLED)
@@ -62,7 +77,12 @@ def main():
         rx_pin=config.MQTT_RX_PIN, baud=config.MQTT_BAUD,
         client_id=config.MQTT_CLIENT_ID,
     )
-    client.setup()
+    try:
+        client.setup()
+    except Exception:
+        # Hand the UART back before the next attempt tries to claim the same pins.
+        client.close()
+        raise
 
     layout = LayoutMQTT(
         client, config.LAYOUT_ID,
@@ -78,30 +98,54 @@ def main():
     for sensor_id, pin in sensors:
         layout.publish_sensor(sensor_id, is_occupied(pin.state, config.ACTIVE_LOW), now)
 
-    led.on()
-    print("io-node: running")
+    return sensors, layout, client
 
-    try:
-        while True:
-            now = ticks_ms()
 
-            for sensor_id, pin in sensors:
-                if pin.update_state():
-                    layout.publish_sensor(
-                        sensor_id, is_occupied(pin.state, config.ACTIVE_LOW), now)
+def run(sensors, layout, client):
+    """The main loop. Returns only on KeyboardInterrupt."""
+    while True:
+        now = ticks_ms()
+
+        for sensor_id, pin in sensors:
+            if pin.update_state():
+                layout.publish_sensor(
+                    sensor_id, is_occupied(pin.state, config.ACTIVE_LOW), now)
 
-            # Re-assert anything that has gone quiet, and retry anything that failed.
-            # Without this every block these sensors feed degrades to `unknown` within
-            # the backend's freshness window, and `unknown` is treated as occupied.
-            layout.tick(now)
+        # Re-assert anything that has gone quiet, and retry anything that failed.
+        # Without this every block these sensors feed degrades to `unknown` within
+        # the backend's freshness window, and `unknown` is treated as occupied.
+        layout.tick(now)
 
-            client.poll()
-            sleep_ms(config.LOOP_SLEEP_MS)
+        client.poll()
+        sleep_ms(config.LOOP_SLEEP_MS)
 
+
+def main():
+    led = StatusLED(Pin("LED", Pin.OUT))
+    led.off()
+
+    def report(exc, code, attempt, delay_ms):
+        print("io-node: startup attempt %d failed — %s: %s" % (attempt, type(exc).__name__, exc))
+        print("io-node: flashing code %d for %d ms, then retrying" % (code, delay_ms))
+        led.flash(code, delay_ms)
+
+    sensors, layout, client = start_supervised(bring_up, report, reset)
+
+    led.on()
+    print("io-node: running")
+
+    try:
+        run(sensors, layout, client)
     except KeyboardInterrupt:
         print("io-node: interrupted")
-    finally:
         led.off()
+    except Exception as exc:
+        # A crash in the loop is the same failure as a crash on the way up: the node
+        # stops reporting and says nothing about it. Flash it, then come back from cold
+        # rather than falling out to a REPL nobody is watching.
+        print("io-node: run loop crashed — %s: %s" % (type(exc).__name__, exc))
+        led.flash(CODE_RUNTIME, RUNTIME_CRASH_FLASH_MS)
+        reset()
 
 
 main()