Repository navigation
GET_STATE replies from the gen2 Nano arrive cut short in 2-4% of polls #81
Description
On the gen2 Nano (ATmega328P), 2 to 4 % of GET_STATE replies reach the controller cut short: the frame is intact up to some byte, that byte is often corrupt, and every byte after it reads 0xFF. Slice_DCMT on the same MCU, bus and controller does it about 50 times less often.
Measured
2026-10-31, main at d0e6ced (gen2_nano) and Slice_DCMT c3e6fca. Raspberry Pi 4 controller, I2C at 50 kHz, both Slices on the backplane. GET_STATE (0x80) every 100 ms for 300 s, with the Python binding's query retries off (Controller(bus, query_attempts=1)), logging the raw 31-byte read of every reply that failed to decode or had an all-0xFF payload:
| Board | Failed | Passed the CRC with an all-0xFF payload |
|---|---|---|
| RLHT gen2 Nano, run 1 | 90 / 2553 | 5 |
| RLHT gen2 Nano, run 2 | 48 / 2553 | 4 |
| DCMT gen2 Nano (ATmega328P) | 1 / 2555 | 0 |
| DCMT gen2 Nano Every (ATmega4809) | 0 / 2554 | 0 |
Some raw reads from RLHT (address 19), a good reply first:
0180140000e900df000000000000000000e803e8030900 + CRC good, t=23.3,22.3
0180140000e600dc00000000ffffffffffffffffffffffffffffffffffffff cut after 12 bytes
0180140000e900e1000000000000000000e801ffffffffffffffffffffffff e803 arrives as e801, then cut
01c0ffffffffffffffffffffffffffffffffffffffffffffffffffffffffff opcode 0x80 arrives as 0xc0
01801400ffffffffffffffffffffffffffffffffffffffffffffffffffffff cut after the mode byte; passes the CRC
DCMT's one failure has the same shape: 028014000000000000c0ffff....
The cut position varies from the second byte to the CRC byte. The failure times don't lock to the 300 ms thermocouple reading: the Rayleigh statistic at the best period between 290 and 310 ms was 0.21 and 0.35 for the two runs, the same as at control periods of 150 to 1000 ms (0.21 to 0.35).
Why it matters
The binding retries a query that fails to decode, so a controller sees only a slower poll, and earlier bench sessions didn't notice. A reply cut right after a mode byte of 0x00 passes the CRC-8, though (feastorg/CRUMBS#130), and decodes as mode 0, fault, e-stop and both relays set, and both temperatures −0.1 °C. That was 9 of 5106 polls here.
Not known
What RLHT does differently from DCMT while a reply goes out. The shape (a corrupt byte, then a released bus) fits the peripheral losing the transfer partway, for example to clock stretching that the Pi's controller mishandles, but that is not measured.
Done when
- The cause is found, for example by bisecting the firmware on the bench or with a logic analyser on SDA/SCL.
- A 300 s capture like the one above on the gen2 Nano fails no more often than DCMT's.
Activity
docs(bench): add the 2026-10-31 record (#82)
docs(bench): add the 2026-10-31 record (#95)
CameronBrooks11 commentedon Nov 1, 2026
The raw session and loggers behind these figures are in the 2026-10-31 record (step B1) and its assets, and the DCMT control runs in its record.
CameronBrooks11 commentedon Nov 1, 2026
The 2026-11-01 bisect (#84) on
a251158, gen2 Nano: one flash and one 300 sreplylog.py 19 1 300per build, with retries off.loop()but the watchdog reset, e-stop poll and LEDmain.cpp'snoInterrupts()windowsRemoving the masked windows clears it, and so does keeping them all but making them rarer. So the cause is how often the loop masks interrupts, not one long window or the in-ISR reply builder. A TWI interrupt delayed by a masked window during a slave clock stretch fits the one-bit lag seen in every bad frame.
The fix is to mask less often: take the
relayControlLogic()snapshots and commits when there is new data, once per thermocouple reading, rather than every pass. A loop delay would also do it, but it hides the cause. The patch that builds the variants is in the record's assets.docs(bench): add the 2026-11-01 record (#84)