fix(firmware): take the control snapshot per reading, not per pass

CHANGELOG.md

@@ -152,6 +152,16 @@ This project did not use formal release tags through most of its history, so thi
 
 ### Fixed
 
+- **GET_STATE replies are no longer cut short** (#81). `relayControlLogic()`
+  opened four masked windows on every loop pass, often enough to delay the
+  TWI interrupt in a slave clock stretch, so the controller saw a reply cut
+  to 0xFF partway. It now takes its snapshot, runs the PIDs and publishes
+  the on-times on a new thermocouple reading or once
+  `RLHT_SNAPSHOT_INTERVAL_MS` (default 10) has passed, and drives the relays
+  from that snapshot in between. The e-stop, watchdog and fault hold is
+  still checked on every pass, with no masked window. On the gen2 Nano, with
+  `replylog.py 19 1 300`: main 187 and 175 bad replies in 300 s, this build
+  1 in 2551. A command now waits up to the interval to reach a relay.
 - **Host tests rebuild after a library pin change** (#74). `pio pkg
   install` keeps a release archive's mtimes, so a plain `make -C test/host`
   kept linking objects built from the previous CRUMBS. A stamp of the

firmware/include/config_hardware.h

@@ -10,6 +10,14 @@
 // ----- Timing constants -----
 #define SERIAL_UPDATE_TIME_MS 1000
 #define THERMO_UPDATE_TIME_MS 300
+// relayControlLogic() takes its masked snapshot of the command fields on each
+// new reading and otherwise at most this often. A masked window on every loop
+// pass delayed the TWI interrupt often enough to cut GET_STATE replies short
+// (feastorg/Slice_RLHT#81). A command waits at most this long to drive a
+// relay; the e-stop, watchdog and fault hold still act on every pass.
+#ifndef RLHT_SNAPSHOT_INTERVAL_MS
+#define RLHT_SNAPSHOT_INTERVAL_MS 10
+#endif
 
 // Gen1 has one relay, on D6; D7 is not connected (docs/hardware-revisions.md).
 #if (RLHT_HW_GEN == 1)

firmware/src/main.cpp

@@ -98,6 +98,9 @@ static double pidSetpoint2 = 0.0;
 // so each reading gets one compute (feastorg/Slice_RLHT#53).
 static bool pidReadingPending1 = false;
 static bool pidReadingPending2 = false;
+// Set by each thermocouple reading and by the end of a hold, so the next
+// relayControlLogic() pass takes a snapshot whatever the interval.
+static bool snapshotDue = true;
 
 PID relay1PID(&pidInput1, &pidOutput1, &pidSetpoint1,
               slice.relayHeater1.Kp, slice.relayHeater1.Ki, slice.relayHeater1.Kd, DIRECT);
@@ -539,6 +542,7 @@ bool measureThermocouples()
         timing.lastThermoRead += THERMO_UPDATE_TIME_MS;
         pidReadingPending1 = true;
         pidReadingPending2 = true;
+        snapshotDue = true;
         return true;
     }
     return false;
@@ -684,19 +688,21 @@ void checkHeaterFaults()
         latchFaults(bits);
 }
 
-void relayControlLogic()
+// What actuateRelay() drives between snapshots: the on-times the last
+// snapshot settled on.
+static double drive1 = 0.0;
+static double drive2 = 0.0;
+static unsigned long lastSnapshotMs = 0;
+
+// Snapshot ISR-written command fields, run the PIDs and publish the on-times.
+// Keep each masked window short (<~10 us): a long cli window delays TWI ISR
+// entry at the SLA+R boundary and the resulting clock stretch is mishandled
+// by Linux SBC I2C masters (see feastorg/Slice_DCMT#3). Per-heater fields stay
+// in one window so a heater's tunings are never torn; a torn view across
+// windows self-corrects next snapshot.
+static void takeSnapshot()
 {
-    // Apply any deferred relay period changes from ISR context.
-    applyPendingPeriods();
-
-    // Snapshot ISR-written command fields atomically. Keep each masked
-    // window short (<~10 us): a long cli window delays TWI ISR entry at the
-    // SLA+R boundary and the resulting clock stretch is mishandled by Linux
-    // SBC I2C masters (see feastorg/Slice_DCMT#3). Per-heater fields stay in
-    // one window so a heater's tunings are never torn; a torn view across
-    // windows self-corrects next iteration.
     noInterrupts();
-    bool localEStop = estopInput.asserted() || commandWatchdog.tripped() || heaterFaults != 0;
     ControlMode localMode = slice.mode;
     double sp1 = slice.relayHeater1.setpointTemperature;
     double sp2 = slice.relayHeater2.setpointTemperature;
@@ -742,31 +748,19 @@ void relayControlLogic()
     // and a write-back would overwrite a command that landed after the
     // snapshot (feastorg/Slice_RLHT#14).
 
-    // A tripped command watchdog or a latched fault holds the same safe state
-    // as e-stop until an explicit clear (CLEAR_WATCHDOG_TRIP or serial
-    // WDCLEAR; CLEAR_FAULTS or serial FAULTCLEAR).
-    if (localEStop)
-    {
-        relaysLow();
-        noInterrupts();
-        slice.relay1State = false;
-        slice.relay2State = false;
-        interrupts();
-        return;
-    }
-
     apply_mode_transition_if_needed(localMode);
     apply_tunings_if_needed(kp1, ki1, kd1, kp2, ki2, kd2);
 
-    double drive1;
-    double drive2;
-
     if (localMode == CLOSED_LOOP)
     {
         computeHeater(relay1PID, pidSetpoint1, pidInput1, pidOutput1, pidReadingPending1, sp1, selectedTemperature(tc1));
 
 #if (RLHT_RELAY_COUNT >= 2)
         computeHeater(relay2PID, pidSetpoint2, pidInput2, pidOutput2, pidReadingPending2, sp2, selectedTemperature(tc2));
+#else
+        // Gen1 has no second heater: its snapshot fields go unused.
+        (void)sp2;
+        (void)tc2;
 #endif
 
         drive1 = pidOutput1;
@@ -793,23 +787,51 @@ void relayControlLogic()
     }
     else
     {
-        relaysLow();
-        noInterrupts();
-        slice.relay1State = false;
-        slice.relay2State = false;
-        interrupts();
+        // Drives of 0 hold both relays off until a valid mode arrives.
+        drive1 = 0.0;
+        drive2 = 0.0;
         SLICE_DEBUG_PRINTLN(F("ERROR INVALID MODE, ENTERED UNKNOWN STATE!"));
+    }
+}
+
+void relayControlLogic()
+{
+    // Apply any deferred relay period changes from ISR context.
+    applyPendingPeriods();
+
+    // A tripped command watchdog or a latched fault holds the same safe state
+    // as e-stop until an explicit clear (CLEAR_WATCHDOG_TRIP or serial
+    // WDCLEAR; CLEAR_FAULTS or serial FAULTCLEAR). Checked on every pass and
+    // with no masked window: each flag is one byte, read in one instruction,
+    // and only the main loop sets them.
+    if (estopInput.asserted() || commandWatchdog.tripped() || heaterFaults != 0)
+    {
+        relaysLow();
+        if (slice.relay1State || slice.relay2State)
+        {
+            noInterrupts();
+            slice.relay1State = false;
+            slice.relay2State = false;
+            interrupts();
+        }
+        // After the hold, the first pass drives from a fresh snapshot.
+        snapshotDue = true;
         return;
     }
 
+    // The masked snapshot only on a new reading or once the interval has
+    // passed, not on every pass (feastorg/Slice_RLHT#81).
+    const unsigned long now = millis();
+    if (snapshotDue || now - lastSnapshotMs >= RLHT_SNAPSHOT_INTERVAL_MS)
+    {
+        snapshotDue = false;
+        lastSnapshotMs = now;
+        takeSnapshot();
+    }
+
     actuateRelay(RELAY1, timing.relay1Start, (unsigned long)slice.relayHeater1.relayPeriod, (unsigned long)drive1, slice.relay1State);
 #if (RLHT_RELAY_COUNT >= 2)
     actuateRelay(RELAY2, timing.relay2Start, (unsigned long)slice.relayHeater2.relayPeriod, (unsigned long)drive2, slice.relay2State);
-#else
-    // Gen1 has no second heater: its snapshot fields go unused.
-    (void)sp2;
-    (void)tc2;
-    (void)drive2;
 #endif
 }
 

firmware/test/host/Makefile

@@ -36,7 +36,7 @@ FW_SRC   := $(wildcard $(FW)/src/*.cpp) $(PIDLIB)/PID_v1.cpp $(wildcard $(CORE)/
 CRUMBS_OBJ := $(OUT)/crumbs_core.o $(OUT)/crumbs_crc.o $(OUT)/crc8_nibble.o
 # test_status_led runs once per e-stop case (the test target); the others
 # run once.
-SINGLE   := test_dispatch test_estop_hold test_watchdog_trip test_serial_burst test_serial_numbers test_set_pid_length test_setpoint_limits test_heater_faults test_watchdog_lease test_pid_sample test_tc_select test_status_led_hold
+SINGLE   := test_dispatch test_estop_hold test_watchdog_trip test_serial_burst test_serial_numbers test_set_pid_length test_setpoint_limits test_heater_faults test_watchdog_lease test_pid_sample test_tc_select test_status_led_hold test_mask_rate
 TESTS    := $(SINGLE) test_status_led
 
 .PHONY: all test clean check-libdeps FORCE

firmware/test/host/README.md

@@ -10,7 +10,8 @@ and run on the host. Nothing is reimplemented:
   the last frame (`bsc_host_led_frame`) instead of sending it.
 - **Stubbed** (`stubs/`): the Arduino core, the AVR watchdog and the MAX6675
   driver. `digitalWrite()` records each pin's level (`host_pin_level`), so a
-  test reads the relays; the MAX6675 stub returns `host_tc1_celsius` and
+  test reads the relays; `noInterrupts()` counts its calls
+  (`host_masked_windows`); the MAX6675 stub returns `host_tc1_celsius` and
   `host_tc2_celsius`.
 
 Frames go in through `crumbs_peripheral_handle_receive()` and replies come
@@ -48,6 +49,7 @@ the board. `make` exits non-zero if any check fails.
 | `test_set_pid_length.cpp` | SET_PID takes 6 bytes (u8 x10) and 12 bytes (u16 x1000, up to 65.535, `RLHT_CAP_PID_X1000`); 5, 7, 11 and 13 bytes are refused `MALFORMED` and change no gain (#50, bread-crumbs-contracts#64) |
 | `test_status_led.cpp` | Blue through the boot wait, then green or red on the first `loop()` pass, with the e-stop released or held from power-up; no LED driven on gen1 (#46) |
 | `test_status_led_hold.cpp` | Amber while a command-watchdog trip or a latched heater fault holds the heaters off, red over amber while the e-stop is held, amber again on the release while the hold stays latched, and green once it is cleared; no LED driven on gen1 |
+| `test_mask_rate.cpp` | The loop opens a masked window only on a thermocouple reading or once `RLHT_SNAPSHOT_INTERVAL_MS` has passed, not on every pass (#81): counted over 3 s of closed-loop heating through a `noInterrupts()` that counts. A duty change still reaches relay 1 within the interval, and the e-stop drops it on the next pass |
 
 ## Writing a test
 

firmware/test/host/host.cpp

@@ -14,7 +14,8 @@ float host_tc2_celsius = 25.0f;
 crumbs_context_t *host_ctx = nullptr;
 
 unsigned long millis() { return host_now; }
-void noInterrupts() {}
+unsigned long host_masked_windows = 0;
+void noInterrupts() { host_masked_windows++; }
 void interrupts() {}
 void pinMode(uint8_t, uint8_t) {}
 

firmware/test/host/host.h

@@ -11,6 +11,10 @@
 // passed, ends after about 1000 reads.
 extern unsigned long host_now;
 
+// How many times the firmware has called noInterrupts(): one per masked
+// window it opens. bread-slice-core's BSC_ATOMIC blocks are not counted.
+extern unsigned long host_masked_windows;
+
 // Level of the e-stop input (pin ESTOP). HIGH is released: the firmware uses
 // the internal pull-up and asserts on LOW.
 extern int host_estop_level;

firmware/test/host/test_mask_rate.cpp

@@ -0,0 +1,96 @@
+// The loop opens a masked window only on a new thermocouple reading or once
+// RLHT_SNAPSHOT_INTERVAL_MS has passed, not on every pass. A window on every
+// pass delayed the TWI interrupt often enough to cut GET_STATE replies short
+// (feastorg/Slice_RLHT#81). A command still reaches the relays within the
+// interval, and the e-stop still drops them on the next pass.
+#include "host.h"
+#include "globals.h"
+#include <bread/rlht_ops.h>
+#include <cstdio>
+
+void setup();
+void loop();
+
+int main()
+{
+    setup();
+    loop();
+
+    // Closed loop at 300 C against 25 C: both heaters at full on-time.
+    const uint8_t closed = RLHT_MODE_CLOSED_LOOP;
+    host_send(RLHT_TYPE_ID, RLHT_OP_SET_MODE, &closed, 1);
+    (void)host_read_ack();
+    const int16_t sp = 3000; // deci-degrees
+    const uint8_t sps[4] = {(uint8_t)(sp & 0xFF), (uint8_t)(sp >> 8), (uint8_t)(sp & 0xFF), (uint8_t)(sp >> 8)};
+    host_send(RLHT_TYPE_ID, RLHT_OP_SET_SETPOINTS, sps, 4);
+    host_check("SET_SETPOINTS is applied", host_read_ack().status == CRUMBS_ACK_APPLIED);
+
+    // 3 s of 1 ms passes (each loop() also reads the e-stop, +1 ms).
+    int passes = 0, masked = 0, high = 0;
+    const unsigned long start = host_now;
+    while (host_now - start < 3000)
+    {
+        const unsigned long before = host_masked_windows;
+        loop();
+        host_now++;
+        passes++;
+        if (host_masked_windows != before)
+            masked++;
+        if (host_pin_level[RELAY1] == HIGH)
+            high++;
+    }
+    const unsigned long ms = host_now - start;
+    const int allowed = (int)(ms / RLHT_SNAPSHOT_INTERVAL_MS) + (int)(ms / THERMO_UPDATE_TIME_MS) + 2;
+    printf("     %d of %d passes opened a masked window over %lu ms (allowed %d); relay 1 high on %d\n",
+           masked, passes, ms, allowed, high);
+    host_check("a masked window opens only on a snapshot or a reading, not every pass", masked <= allowed);
+    // Kp 1 against a 275 C error: 275 ms on in each 1000 ms period.
+    host_check("closed loop still switches relay 1", high > 0 && high < passes);
+
+    // Open loop at full duty, until relay 1 is on.
+    const uint8_t open = RLHT_MODE_OPEN_LOOP;
+    host_send(RLHT_TYPE_ID, RLHT_OP_SET_MODE, &open, 1);
+    (void)host_read_ack();
+    const uint8_t duty100[2] = {100, 100};
+    host_send(RLHT_TYPE_ID, RLHT_OP_SET_OPEN_DUTY, duty100, 2);
+    host_check("SET_OPEN_DUTY 100 is applied", host_read_ack().status == CRUMBS_ACK_APPLIED);
+    for (int i = 0; i < 2 * RLHT_SNAPSHOT_INTERVAL_MS; i++)
+    {
+        loop();
+        host_now++;
+    }
+    host_check("full duty drives relay 1", host_pin_level[RELAY1] == HIGH);
+
+    // A command reaches the relays within the interval: duty 0 drops relay 1
+    // within RLHT_SNAPSHOT_INTERVAL_MS plus a pass.
+    const uint8_t duty0[2] = {0, 0};
+    host_send(RLHT_TYPE_ID, RLHT_OP_SET_OPEN_DUTY, duty0, 2);
+    host_check("SET_OPEN_DUTY 0 is applied", host_read_ack().status == CRUMBS_ACK_APPLIED);
+    const unsigned long sent = host_now;
+    int waited = 0;
+    while (host_pin_level[RELAY1] == HIGH && waited < 1000)
+    {
+        loop();
+        host_now++;
+        waited++;
+    }
+    printf("     relay 1 low %lu ms after SET_OPEN_DUTY 0\n", host_now - sent);
+    host_check("a command drives the relay within the snapshot interval",
+               host_pin_level[RELAY1] == LOW && host_now - sent <= RLHT_SNAPSHOT_INTERVAL_MS + 4);
+
+    // Full duty again, then the e-stop: relays low on the next pass.
+    host_send(RLHT_TYPE_ID, RLHT_OP_SET_OPEN_DUTY, duty100, 2);
+    (void)host_read_ack();
+    for (int i = 0; i < 2 * RLHT_SNAPSHOT_INTERVAL_MS; i++)
+    {
+        loop();
+        host_now++;
+    }
+    host_check("full duty drives relay 1 again", host_pin_level[RELAY1] == HIGH);
+    host_estop_level = LOW;
+    loop();
+    host_check("the e-stop drops relay 1 on the next pass", host_pin_level[RELAY1] == LOW);
+    host_estop_level = HIGH;
+
+    return host_finish();
+}