diag(safety): attribute lockstep mismatches; time NVS flushes by iliabaranov · Pull Request #154 · polymathrobotics/protective-stop

iliabaranov · 2026-09-19T16:12:14Z

Diagnostics, plus one safety-path behaviour change (review round 2, see below).

Safety-path behaviour change: one 80 ms publish window for both cores

Before: the comparator took core 0's completion semaphore with an 80 ms timeout and then core 1's with another 80 ms, so a tick could transmit when core 1 published as late as 160 ms after the notify, and a both-late tick was attributed to core 0 alone.
Now: one absolute CORE_PUBLISH_TIMEOUT deadline for both takes — core 1 gets the remainder (lockstep_window.h, lockstep_second_wait_ticks). A core landing in the former 80–160 ms slot taints the tick (nothing is sent; the machine fail-safes on its heartbeat timeout as for any tainted tick) instead of transmitting a stale encoding; the worst-case comparator hold drops from 160 ms to 80 ms. Fail-safe direction only: nothing that was tainted before can transmit now.
Test: firmware/test/test_lockstep_window.c (runs in make -C firmware/test run, the coverage CI job) — 17 checks plus a 1681-point sweep asserting transmit iff both cores published within the window and never a relaxation versus the old sequential takes.

Why

pstop_mismatch counts two different things with one counter: a core missing the 80 ms publish deadline, and both cores publishing different bytes. A 4 h USB soak on 2026-09-10 had one genuine mismatch coincident with a >80 ms peer-cache NVS flush; the Ethernet pass had 25 such flushes and no mismatch. Undecidable with the old counter. (Mechanism analysis: every NVS page erase runs with caches off and the other core frozen for 45–400 ms — the "timeout" hypothesis is favoured but unproven.)

What is exported (`/state.json`)

pstop_mm_timeout, pstop_mm_content — the split.
pstop_mm_last — packed late-core mask + both cores' verdicts, the late core's lateness (ms), uptime at the event.
pstop_core_lat_max_ms — worst notify→publish latency per core.
nvs_pf / nvs_dcs — start/duration/max of peer-table and dcs NVS writes (nvs_dcs times every dcs read-write handle open→close, not only the health blob).

Safety-path notes

Both semaphore takes still execute every tick (two statements, not a short-circuit; when core 0 consumed the whole window, core 1's take runs with a 0-tick timeout and a later give is drained by the next tick's explicit drain). The first-differing-byte scan is bounded by the already-failed memcmp. JSON_CAP 4352 → 4864 (measured live headroom ~1.4 KB).

Host-side: correlate.py (to follow with the soak tooling) attributes each mismatch increment to HIL cycle events or NVS flushes — on the 2026-09-19 run all 44 increments on the DUT were on HIL cycles (rig relay skew), zero unattributed.

Records read by /state.json (g_dcs_pstop_mm, peer-cache flush diag) are atomic payloads published under a seqlock with fenced readers — no torn or racy reads.

Soak evidence

8 h steady-state run (2026-09-19/20) with this PR in the image: the only timeout-class events were two at one unit's boot (core 1, 97 ms late); none of the 13 peer-cache flushes logged (103–152 ms) coincided with a comparator timeout; content-class events lined up 1:1 with the rig's relay edges. Details in the PR comments.

pstop_mismatch counted two different things with one counter: a core missing the 80 ms publish deadline, and both cores publishing different bytes. A 4 h USB soak on 2026-09-10 had one genuine mismatch coincident with a >80 ms peer-cache NVS flush; the Ethernet pass had 25 such flushes and none. Undecidable with the old counter. Now exported in /state.json: pstop_mm_timeout / pstop_mm_content, the last mismatch (packed late-core mask + verdicts, late-core lateness ms, uptime), the worst notify->publish latency per core, and the start/ duration/max of peer-table and dcs NVS writes (nvs_pf, nvs_dcs). The two semaphore takes still both execute every tick; the first-differing-byte scan is bounded by the failed memcmp. JSON_CAP 4352 -> 4864 (measured headroom ~1.4 KB). Diagnostics only; no safety decision changes.

graphify-labs

Graphify reviewed this change.

Worth a look — the grounded gate found no coupling regressions or blocking issues, but 1 advisory finding(s) below merit a look before merge.

Graphify review — findings

Adds lockstep-mismatch attribution to E-stop telemetry: the comparator now records per-event kind (timeout vs content), the late core, first-differing byte, verdicts, and its actual notify→publish latency into g_dcs_pstop_mm, with each core stamping its publish time into g_core_done_us. Stamps dcs-side NVS writes with start uptime and duration in g_dcs_nvs_write (measured across the flash program in dcs_nvs_write_health) and extends the peer-cache flush diag to also report the last flush's start uptime via ml_peer_nvs_get_flush_diag. Surfaces all of these through /state.json (new pstop_mm_*, pstop_core_lat_max_ms, nvs_pf, nvs_dcs fields), bumping its JSON_CAP from 4352 to 4864 to hold the extra bytes.

Worth a look

ml_peer_nvs_get_flush_diag now writes past buffers valid under the old contract — components/microlink/src/ml_peer_nvs.c:263 · Escalate · high
- agreed by 2 of 2 members but NOT verified (no proof, no reproducing execution) — consensus is not a verdict; needs human review

Analysis details — impact, health, verification

Impact & health

Graphify review

Impact — 292 functions depend on the 207 functions this change touches.

Health — this change adds coupling hotspots:

new: dcs_support_init() — 2 callers, 30 callees
new: add_peer() — 2 callers, 22 callees
new: disco_send_ping_to_peer() — 8 callers, 5 callees
new: disco_send_call_me_maybe() — 6 callers, 4 callees
new: noise_send() — 7 callers, 3 callees
new: microlink_init() — 1 callers, 17 callees
new: disco_periodic_probes() — 1 callers, 16 callees
new: dcs_pstop_set_peer_slot() — 3 callers, 5 callees
…and 33 more — each is listed as a finding

Verification — 292 functions in the blast radius were not formally verified this run (proofs are advisory here).

Gate & verification

graphify gate

PASS — objectively clean (no health regressions, tests not run — proofs not run this pass (advisory)). Grounded, not self-assessed.

Advisory (not blocking):

verification_scope: 286 function(s) in the blast radius were not formally verified this run

· 41 more finding(s) on lines outside this diff (see the check run).

claude

Nothing blocking. The comments below are optional suggestions. There is no need to push a fix for them before merging.

Beyond the two inline findings, I also checked two other candidates and ruled them out: the per-core worst-latency tracker (main.c:1281-1286) is scoped inside the both_in branch by design — timeout-path latency is captured separately via mm[3], so it isn't a data-loss bug, just a different metric than the timeout one. I also checked the now_ms/s_diag_flush_at_ms uint32 millisecond timestamps (main.c:1301, ml_peer_nvs.c:296) for wraparound — they roll over every ~49.7 days, a pre-existing limitation of this style of uptime counter rather than something newly introduced with materially different risk here.

Extended reasoning...

This run's hunt ended at the max_bugs budget rather than running dry, and two confirmed findings (main.c:1243 stale/zeroed late-core latency sample, main.c:1544 torn multi-word read of pstop_mm_last) are already queued as inline comments, so approval is off the table regardless. I independently verified both ruled-out candidates against the current diff: the worst-case-latency loop at main.c:1281-1286 is guarded by if (both_in), confirming it only measures latency on ticks where both cores met the 80ms deadline (the timeout case is tracked separately via mm[3]), so it is a scope choice rather than a bug; and the ms-resolution uptime fields introduced/reused here (mm[4], s_diag_flush_at_ms) are uint32 millisecond counters that wrap at ~49.7 days, consistent with existing firmware conventions elsewhere and not a new regression class worth blocking on. Given the outstanding confirmed findings and the non-dry_streak exit reason, a human should review this PR; this note only records the additional ground covered.

rajasimman-madhivanan · 2026-09-20T00:18:19Z


-    bool both_in = (xSemaphoreTake(g_done[0], CORE_PUBLISH_TIMEOUT) == pdTRUE) &
-                   (xSemaphoreTake(g_done[1], CORE_PUBLISH_TIMEOUT) == pdTRUE);
+    const bool in0 = (xSemaphoreTake(g_done[0], CORE_PUBLISH_TIMEOUT) == pdTRUE); /* sequential -> late core known */


core 0 waits until 80ms, and core 1 starts waiting after that - which effectively means core 1 gets 160ms?

Yes — with sequential takes core 1 effectively had up to 160 ms whenever core 0 timed out. That pre-dates this PR (the old & form had the same two sequential 80 ms waits), but it matters here because it skews attribution: a both-late event where core 1 landed at 150 ms was reported as "core 0 late". Fixed in 2f59549: one absolute deadline for both takes — core 1 gets the remainder of CORE_PUBLISH_TIMEOUT (xTaskGetTickCount delta, 1 ms ticks). Side effect in the safety loop is a tightening only: the worst-case tick stall drops from 160 ms to 80 ms; a tick that times out is tainted (nothing sent) exactly as before.

rajasimman-madhivanan · 2026-09-20T00:20:38Z

    }

+    if (mm_late != 0u) { /* previous tick timed out: when did the late core finally publish? */
+      uint64_t done = (uint64_t)atomic_load(&g_core_done_us[(mm_late & 1u) ? 0 : 1]);


If both cores are late, mm_late & 1u ? 0 : 1 chooses core 0 - diagnostic issue? Add a Todo may be?

Correct — it attributed only core 0 when both were late. 2f59549 iterates both bits: each late core is attributed when it lands and mm[3] keeps the max (the slowest late core). No TODO left.

rajasimman-madhivanan · 2026-09-20T00:28:49Z

+    if (mm_late != 0u) { /* previous tick timed out: when did the late core finally publish? */
+      uint64_t done = (uint64_t)atomic_load(&g_core_done_us[(mm_late & 1u) ? 0 : 1]);
+      mm[3] = (done > notify_us) ? (uint32_t)((done - notify_us) / 1000u) : 0u;
+      mm_late = 0;


If the late core mask is always cleared, a core that doesn't land for 2 loops gets a free pass?

Safety-wise no free pass: the next tick's own take times out again and increments the counter; the flaw was diagnostic — a core that had not published by the next tick was reported as "0 ms late", indistinguishable from "published just before the tick". 2f59549 keeps the late bit pending per core until g_core_done_us[c] is past the timed-out tick's notify time (mm_late_notify_us), then records its real latency; a new timeout supersedes a still-pending attribution.

rajasimman-madhivanan · 2026-09-20T00:31:54Z

    (unsigned long)atomic_load(&g_dcs_pstop_replies),
    (unsigned long)atomic_load(&g_dcs_pstop_last_msg),
    (unsigned long)atomic_load(&g_dcs_pstop_mismatch),
+    (unsigned long)atomic_load(&g_dcs_pstop_mm[0]),


If the publish and load happens one variable at a time, there is a race condition here that can read certain values from one cycle and certain values from another? If this only affects diagnostics a todo with issue # would be fine

Right — and rather than a TODO I made the record consistent: the comparator publishes the 7 words under a seqlock (g_dcs_pstop_mm_seq bumped before and after the stores, odd while in flux), and /state.json reads through dcs_pstop_mm_snapshot() (retry on odd/changed, 8 attempts, single writer). A reader can no longer mix two events. Same pattern applied to the peer-cache flush diag in ml_peer_nvs.c (four values, same class of tear).

rajasimman-madhivanan · 2026-09-20T00:36:47Z

    r = nvs_commit(h);
  }
  nvs_close(h);
+  atomic_store(&g_dcs_nvs_write[1], (uint32_t)(esp_timer_get_time() / 1000) - t0);


Similar issue as admin_pages here - state variables are getting written separately which may result in a drift.

Fixed in 2f59549: start and duration are now ONE 64-bit atomic word (g_dcs_nvs_write = start << 32 | duration), so a reader can never pair this write's duration with the previous write's start. 64-bit atomics already have precedent in dcs_support (g_dcs_pstop_last_reply_ms etc.). Both roles build.

…ibution, torn-read-free records - comparator: one absolute CORE_PUBLISH_TIMEOUT deadline for both takes — core 1 gets the remainder, not a fresh 80 ms after core 0 timed out (which gave it 160 ms and reported a both-late event as "core 0 late"). Worst-case tick stall is now 80 ms instead of 160 ms. - attribution: the late-core mask stays pending per core until that core has actually published for the timed-out tick; mm[3] = slowest late core's real notify->publish ms (both-late records the max, not core 0 only). A core that never lands is no longer reported as "0 ms late". - g_dcs_pstop_mm: 7-word record published under a seqlock (g_dcs_pstop_mm_seq); /state.json reads it via dcs_pstop_mm_snapshot(), never mixing two events. - g_dcs_nvs_write: start and duration in ONE 64-bit atomic word. - ml_peer_nvs flush diag: same seqlock pattern around the 4-value record.

graphify-labs

Graphify reviewed this change.

Worth a look — the grounded gate found no coupling regressions or blocking issues, but 4 advisory finding(s) below merit a look before merge.

Graphify review — findings

Adds lockstep-mismatch attribution and flash-write timing to the DCS /state.json payload: dcs_pstop_mm_snapshot returns a seqlock-consistent copy of the comparator's mismatch record (timeout- vs content-class counts, packed detail of the last event, per-core worst publish latency), and page_state emits it alongside peer-cache flush timing and the dcs-side NVS write time, bumping JSON_CAP 4352→4864 to fit. Extends ml_peer_nvs_get_flush_diag to a 4-word out that adds the last flush's start uptime, and guards the whole diag record with a seqlock so readers never pair a new count with a stale duration. Stamps dcs_nvs_write_health into a single 64-bit g_dcs_nvs_write word (start ms << 32 | duration ms) so start and duration are always read atomically from the same write.

Worth a look

Flush diag API now writes a fourth word into callers' existing 3-word buffers — components/microlink/include/microlink_internal.h:1262 · Escalate · medium
- agreed by 2 of 2 members but NOT verified (no proof, no reproducing execution) — consensus is not a verdict; needs human review
Seqlock reader can return uninitialized buffer when all retries fail — firmware/components/dcs_support/src/dcs_support.c:105 · Escalate · medium
- agreed by 2 of 2 members but NOT verified (no proof, no reproducing execution) — consensus is not a verdict; needs human review
in1 not evaluated / cores not drained when in0 times out under sequential-take change — firmware/main/main.c:1277 · Escalate · medium
- agreed by 2 of 2 members but NOT verified (no proof, no reproducing execution) — consensus is not a verdict; needs human review
Timeout telemetry reads core-owned verdict without synchronization — firmware/main/main.c:1312 · Escalate · medium
- agreed by 2 of 2 members but NOT verified (no proof, no reproducing execution) — consensus is not a verdict; needs human review

Analysis details — impact, health, verification

Impact & health

Graphify review

Impact — 293 functions depend on the 208 functions this change touches.

Health — this change adds coupling hotspots:

new: dcs_support_init() — 2 callers, 30 callees
new: add_peer() — 2 callers, 22 callees
new: disco_send_ping_to_peer() — 8 callers, 5 callees
new: disco_send_call_me_maybe() — 6 callers, 4 callees
new: noise_send() — 7 callers, 3 callees
new: microlink_init() — 1 callers, 17 callees
new: disco_periodic_probes() — 1 callers, 16 callees
new: dcs_pstop_set_peer_slot() — 3 callers, 5 callees
…and 33 more — each is listed as a finding

Verification — 293 functions in the blast radius were not formally verified this run (proofs are advisory here).

Gate & verification

graphify gate

PASS — objectively clean (no health regressions, tests not run — proofs not run this pass (advisory)). Grounded, not self-assessed.

Advisory (not blocking):

verification_scope: 287 function(s) in the blast radius were not formally verified this run

· 41 more finding(s) on lines outside this diff (see the check run).

claude

Nothing blocking. The comments below are optional suggestions. There is no need to push a fix for them before merging.

…es; mm[3] scoped to timeout records - mm[5+c] (per-core worst notify->publish ms) now also folds in the on-time core's latency on a timeout tick and the late core's real latency when it lands, so the gauge no longer excludes exactly the slow publishes it exists to surface. - mm[3] (late core's latency) is written only while the record still describes that timeout event and is zeroed by a content event, so a content record can never carry a stale timeout-class latency. - seqlock readers (dcs_pstop_mm_snapshot, ml_peer_nvs_get_flush_diag) always deliver a copy — a best-effort one after 8 collisions — instead of leaving the caller's buffer untouched. - layout doc: on a timeout record the late core's verdict byte is from its previous publish (the late mask says which); mm[3]/mm[5..6] semantics.

iliabaranov · 2026-09-20T07:13:34Z

Graphify advisories on 2f595495, addressed in 64ce7e54 where warranted:

Flush diag writes a fourth word into 3-word buffers — no such caller: the prototype (microlink_internal.h) and both callers (ml_config_httpd.c fl[4], dcs_admin_pages.c pf[4]) are 4-word.
Seqlock reader can return an uninitialized buffer after 8 collisions — fixed: both readers (dcs_pstop_mm_snapshot, ml_peer_nvs_get_flush_diag) now deliver a best-effort copy on the fall-through path, so out[] is always written (the writer runs once per 100 ms tick / once per ≥5 s flush, so 8 consecutive collisions are effectively impossible, but the contract is now unconditional).
in1 not evaluated / cores not drained when in0 times out — in1 is always evaluated: when core 0 consumed the whole budget, core 1's take runs with a 0-tick timeout (non-blocking), so a give already pending is consumed. A give that lands later is drained by the next tick's explicit xSemaphoreTake(g_done[x], 0) at step 3, exactly as before this PR.
Timeout telemetry reads the late core's verdict without synchronization — a uint8_t read cannot tear; what it can be is stale: on a timeout record the late core has not published for this tick, so its byte is from its previous publish. That is inherent to a timeout event; the late mask in the same word tells the reader which byte it is. Documented in the dcs_internal.h layout comment.

Both roles build.

graphify-labs

Graphify reviewed this change.

Worth a look — the grounded gate found no coupling regressions or blocking issues, but 3 advisory finding(s) below merit a look before merge.

Graphify review — findings

Adds lockstep-mismatch attribution to /state.json: page_state now emits pstop_mm_* fields (timeout- vs content-class counts, packed last-event detail, late-core publish latency, per-core worst notify→publish times) sourced from a new comparator-written seqlock record read via dcs_pstop_mm_snapshot, plus nvs_pf peer-cache and nvs_dcs firmware flash-flush timing, and bumps JSON_CAP from 4352 to 4864 to fit them. Stamps each dcs-side NVS health write in dcs_nvs_write_health with start-uptime and duration packed into the single 64-bit g_dcs_nvs_write so a reader never pairs one write's duration with another's start. Extends ml_peer_nvs_get_flush_diag to a 4-element output carrying the last flush's start uptime, and wraps the flush-diag reads/writes in a seqlock so callers never see a new count paired with a stale duration.

Worth a look

Seqlock payload is accessed with non-atomic concurrent reads and writes — components/microlink/src/ml_peer_nvs.c:269 · Escalate · medium
- agreed by 2 of 2 members but NOT verified (no proof, no reproducing execution) — consensus is not a verdict; needs human review
Flush diag getter now writes a fourth word, breaking the prior 3-word buffer contract — components/microlink/include/microlink_internal.h:1261 · Escalate · medium
- agreed by 2 of 2 members but NOT verified (no proof, no reproducing execution) — consensus is not a verdict; needs human review
Timeout path reads late core verdict without synchronization — firmware/main/main.c:1329 · Escalate · medium
- agreed by 2 of 2 members but NOT verified (no proof, no reproducing execution) — consensus is not a verdict; needs human review

Analysis details — impact, health, verification

Impact & health

Graphify review

Impact — 293 functions depend on the 208 functions this change touches.

Health — this change adds coupling hotspots:

new: dcs_support_init() — 2 callers, 30 callees
new: add_peer() — 2 callers, 22 callees
new: disco_send_ping_to_peer() — 8 callers, 5 callees
new: disco_send_call_me_maybe() — 6 callers, 4 callees
new: noise_send() — 7 callers, 3 callees
new: microlink_init() — 1 callers, 17 callees
new: disco_periodic_probes() — 1 callers, 16 callees
new: dcs_pstop_set_peer_slot() — 3 callers, 5 callees
…and 33 more — each is listed as a finding

Verification — 293 functions in the blast radius were not formally verified this run (proofs are advisory here).

Gate & verification

graphify gate

PASS — objectively clean (no health regressions, tests not run — proofs not run this pass (advisory)). Grounded, not self-assessed.

Advisory (not blocking):

verification_scope: 287 function(s) in the blast radius were not formally verified this run

· 41 more finding(s) on lines outside this diff (see the check run).

claude

Nothing blocking. The comments below are optional suggestions. There is no need to push a fix for them before merging.

claude · 2026-09-20T07:37:43Z

  uint32_t dur = (uint32_t)((esp_timer_get_time() - t0) / 1000);
+  (void)atomic_fetch_add(&s_diag_flush_seq, 1u); /* odd: record in flux */
  s_diag_flush_last_ms = dur;
+  s_diag_flush_at_ms = (uint32_t)(t0 / 1000);


🟡 (optional) Operators correlating pstop_mm_last/nvs_pf/nvs_dcs timestamps on a long-running unit get wrong or ambiguous event times once uptime passes ~49.7 days. Each new field truncates esp_timer_get_time() (int64 us) to a uint32_t ms uptime stamp, which wraps every 2^32 ms, unlike existing 64-bit stamps like g_dcs_pstop_last_reply_ms. Fix: publish these 'start'/'event' uptime fields as 64-bit or wrap-safe deltas. Same pattern at 3 sites (components/microlink/src/ml_peer_nvs.c:317, firmware/main/main.c:1335, firmware/components/dcs_support/src/dcs_nvs.c:625).

Extended reasoning...

Trigger: a pstop controller running continuously for >49.7 days (2^32 ms), plausible for industrial deployments even though the soak tests cited were only hours. ml_peer_nvs.c:317 sets s_diag_flush_at_ms=(uint32_t)(t0/1000), t0=esp_timer_get_time() (int64 us since boot); dcs_nvs.c:625 does the same for t0 packed into g_dcs_nvs_write bits 63:32; main.c:1335/1344 store mm[4]=(uint32_t)now_ms the same way. Base branch never exposed these fields, so no prior export was wraparound-sensitive here. After 2^32 ms each value wraps to a small number while esp_timer_get_time() itself keeps counting (g_dcs_pstop_last_reply_ms stays 64-bit, confirming the underlying clock does not wrap). A flush just before the wrap and a mismatch just after can both show similarly small pstop_mm_last[2]/nvs_pf[0]/nvs_dcs[0] values despite being ~50 days apart, so host tooling (correlate.py) or an operator comparing timestamps in /state.json gets a plausible-looking but wrong ~49.7-day-off event proximity, defeating the NVS-stall-vs-mismatch correlation this feature exists for.

Verification: Severity: nit (diagnostic-only precision limit; nothing breaks). The truncation is real and present at all three listed sites. ml_peer_nvs.c:317 s_diag_flush_at_ms = (uint32_t)(t0 / 1000); where t0 = esp_timer_get_time() (int64 us since boot); exported as nvs_pf "start uptime ms" via ml_peer_nvs_get_flush_diag(out[4]) -> pf[3] (dcs_admin_pages.c:391). dcs_nvs.c:17-29… | nit. The truncation…

…read An acquire LOAD only pins the accesses that follow it; without a fence the payload loads could sink below the second sequence read and a torn record could pass the check. Both readers (dcs_pstop_mm_snapshot, ml_peer_nvs_get_flush_diag) now use the textbook reader: load seq (acquire), copy payload, atomic_thread_fence(acquire), re-read seq.

iliabaranov · 2026-09-20T07:42:10Z

Round on 64ce7e54 → bc53048a (both roles build):

Seqlock payload accessed with non-atomic concurrent reads/writes (ml_peer_nvs.c) — fair point on the memory model: the payload words are plain and only the sequence is atomic, and an acquire load alone only pins the accesses that follow it, so the payload loads could in principle sink below the second sequence read. Both readers now use the textbook form — load seq (acquire), copy payload, atomic_thread_fence(memory_order_acquire), re-read seq — and the writer's seq_cst fetch-adds already order its stores on the other side. (dcs_pstop_mm_snapshot reads atomics anyway; fenced for symmetry.)
Flush diag getter writes a fourth word into 3-word buffers — re-raised per head, still not the case: the prototype and both callers (ml_config_httpd.c fl[4], dcs_admin_pages.c pf[4]) are 4-word.
Timeout path reads the late core's verdict without synchronization — as answered on the previous head: a byte cannot tear; it is stale by definition on a timeout record (the late core has not published for that tick) and the late mask in the same word identifies it. Documented in dcs_internal.h.

graphify-labs

Graphify reviewed this change.

Worth a look — the grounded gate found no coupling regressions or blocking issues, but 1 advisory finding(s) below merit a look before merge.

Graphify review — findings

Adds cross-core lockstep-mismatch and NVS-flush attribution to /state.json: surfaces per-core worst notify→publish latency, timeout-vs-content mismatch classification with a packed last-event detail, and start/duration/max timings for both the peer-cache flush and dcs-side NVS writes. Makes the flush-diag readers race-free by publishing under a single-writer seqlock — ml_peer_nvs_get_flush_diag and dcs_pstop_mm_snapshot retry while the sequence is odd and fall back to a best-effort copy after 8 collisions, so a caller never sees a new count paired with a stale duration. Extends ml_peer_nvs_get_flush_diag to a 4-element output (adds flush start uptime), stamps each dcs NVS write into a single 64-bit word, and bumps the page_state JSON buffer 4352→4864 to fit the ~230 B of new fields.

Worth a look

Seqlock protects non-atomic diagnostic fields with concurrent readers/writer — components/microlink/src/ml_peer_nvs.c:272 · Escalate · medium
- agreed by 2 of 2 members but NOT verified (no proof, no reproducing execution) — consensus is not a verdict; needs human review

Analysis details — impact, health, verification

Impact & health

Graphify review

Impact — 293 functions depend on the 208 functions this change touches.

Health — this change adds coupling hotspots:

new: dcs_support_init() — 2 callers, 30 callees
new: add_peer() — 2 callers, 22 callees
new: disco_send_ping_to_peer() — 8 callers, 5 callees
new: disco_send_call_me_maybe() — 6 callers, 4 callees
new: noise_send() — 7 callers, 3 callees
new: microlink_init() — 1 callers, 17 callees
new: disco_periodic_probes() — 1 callers, 16 callees
new: dcs_pstop_set_peer_slot() — 3 callers, 5 callees
…and 33 more — each is listed as a finding

Verification — 293 functions in the blast radius were not formally verified this run (proofs are advisory here).

Gate & verification

graphify gate

PASS — objectively clean (no health regressions, tests not run — proofs not run this pass (advisory)). Grounded, not self-assessed.

Advisory (not blocking):

verification_scope: 287 function(s) in the blast radius were not formally verified this run

· 41 more finding(s) on lines outside this diff (see the check run).

claude

Code review found no issues

No high-confidence issues detected in this change.

Still open from earlier reviews (1):

Unresolved: 1 minor or pre-existing.

iliabaranov · 2026-09-20T10:11:30Z

Soak run 4 evidence (8 h 15 min steady state, image includes this PR as of `2f595495`)

What the new instrumentation showed on three units (/state.json sampled at 1 Hz):

	DUT	7a60	eed0
`pstop_mm_timeout` (timeout-class, total)	0	2 — both at boot (uptime 15.6 s), packed detail: late core = core 1, actual publish latency 97 ms vs the 80 ms budget	0
`pstop_mm_content` (content-class, total)	6 — all at relay-driven re-arms (18:50, 19:18, 01:07): slot 1, first differing byte 0x01, verdicts 0x55/0x92 = the known HIL relay pole-latency artefact	0	0
`nvs_pf` peer-cache flush (last / max)	140 / 152 ms	121 / 122 ms	136 / 136 ms
`nvs_dcs` write duration	3–4 ms	3 ms	3 ms

Take-aways:

The attribution does its job: the only timeout-class events are now identified (core 1, 97 ms late, boot-time load), and none of the 13 peer-cache flushes logged during the run coincided with a comparator timeout — even though every flush (103–152 ms) exceeds the 80 ms publish budget. The 7a60 boot events were 4 s after its first flush, not during it. So "NVS flush ⇒ lockstep timeout" is not supported for steady state; the flush budget problem is real but shows up elsewhere — as an IWDT panic in the v1.3 fleet firmware, filed as IWDT panic in ml_wg_mgr during the peer-table NVS flush (v1.3 fleet firmware coredump) #158 with the decoded coredump.
Content-class events are cleanly separated from timeout-class ones and line up 1:1 with the rig's relay edges (parked as a rig artefact).
No torn records observed in ~90 000 /state.json reads (the seqlock readers of the current head make that a guarantee rather than an observation).

Current head bc53048a = soaked code + the review-round changes (attribution folds late publishes into the per-core gauge; mm[3] scoped to timeout records; fenced seqlock readers); both roles build, CI green.

rajasimman-madhivanan

Approving assuming the concurrency issue is fixed before merge

rajasimman-madhivanan · 2026-09-20T13:51:56Z


-    bool both_in = (xSemaphoreTake(g_done[0], CORE_PUBLISH_TIMEOUT) == pdTRUE) &
-                   (xSemaphoreTake(g_done[1], CORE_PUBLISH_TIMEOUT) == pdTRUE);
+    /* Sequential takes so the late core is known, but ONE absolute deadline for


Minor: Now that the wait is corrected, there is a safety related change since earlier if Core 1 came in < 160ms, the heartbeat is transmitted, now that window is reduced to 80ms (which should be the intended behavior) - so PR description needs updating and tests need to be added.

Agreed on both counts. The PR description now states the behavioural change explicitly (it was buried in a commit message): a tick transmits only if both cores publish within one 80 ms window from the notify; a core landing in the old 80–160 ms second slot now taints the tick instead of transmitting a stale encoding, and the worst-case comparator hold drops from 160 ms to 80 ms — a tightening in the fail-safe direction (SR-R-07 fresh-agreement). Test added in 010f4c0c: the window arithmetic is extracted into firmware/main/lockstep_window.h (pure; main.c calls it) and firmware/test/test_lockstep_window.c pins it — 17 checks (79/150 ms now tainted; both-late mask 0b11; dead core → 80 ms hold) plus a 1681-point sweep asserting transmit iff both ≤ 80 ms and never a relaxation vs the old sequential takes. It runs in make -C firmware/test run, which the coverage CI job executes.

rajasimman-madhivanan · 2026-09-20T13:55:39Z

+      taskYIELD();
+      continue;
+    }
+    out[0] = s_diag_flush_last_ms;


There is still no guarantee that the updated values would be reflected in the reader since the variables themselves are not atomic.

Correct — the seqlock made the record consistent but the plain words were still a data race in the C11 sense. Fixed in 010f4c0c: the four payload words are atomic_uint_fast32_t (atomic loads/stores, so every read returns a value some store wrote), and the seqlock remains for cross-word consistency. Same shape as g_dcs_pstop_mm, whose payload was already atomic.

rajasimman-madhivanan · 2026-09-20T14:01:43Z

+  /* start and duration in ONE atomic word: a reader never pairs this write's
+   * duration with the previous write's start (or vice versa). */
+  const uint32_t dur = (uint32_t)(esp_timer_get_time() / 1000) - t0;
+  atomic_store(&g_dcs_nvs_write, ((uint64_t)t0 << 32) | (uint64_t)dur);


Minor: Is this also needed for other dcs writes?

Yes — any dcs-side NVS write stalls both cores, so timing only the health blob understated the gauge. 010f4c0c times every READWRITE handle open→close through two small wrappers (nvs_open_rw/nvs_close_rw; the 18 write functions, none of the read-only ones), and keeps a max-hold: /state.json nvs_dcs is now [start, duration, max], mirroring nvs_pf.

… shared publish window, every dcs NVS write timed - ml_peer_nvs flush diag: the four payload words are atomics now (no data race), still published under the seqlock for record consistency. - comparator: the shared CORE_PUBLISH_TIMEOUT window is expressed through lockstep_window.h (pure) and pinned by firmware/test/test_lockstep_window.c (17 checks + a 1681-point sweep asserting: transmit iff both cores published within the ONE window, never a relaxation vs the old sequential takes, hold bounded by the window). Runs in make -C firmware/test run (CI coverage job). - dcs_nvs: every READWRITE handle is timed open->close (nvs_open_rw / nvs_close_rw), not only the health blob, and a max-hold is kept; /state.json nvs_dcs = [start, duration, max].

graphify-labs

Graphify reviewed this change.

Worth a look — the grounded gate found no coupling regressions or blocking issues, but 1 advisory finding(s) below merit a look before merge.

Formal verification. No changes could be formally verified in this run.

Graphify review — findings

Adds lockstep-mismatch attribution to the comparator: on every pstop_mismatch it records whether a core timed out or the frames differed, which core was late and its publish latency, the first differing byte, and per-core worst notify→publish times, published through the g_dcs_pstop_mm seqlock and read back via dcs_pstop_mm_snapshot. Times every dcs-side NVS read-write handle open→close into a single 64-bit g_dcs_nvs_write word (start uptime and duration together) plus a boot-max, so flash-stall cost is measurable, and extends the peer-cache flush diag (ml_peer_nvs_get_flush_diag) with the flush start-uptime as a fourth word. Surfaces all of this on /state.json (pstop_mm_*, pstop_core_lat_max_ms, nvs_pf, nvs_dcs, JSON_CAP bumped 4352→4864) and hardens the flush diag reader/writer to a proper seqlock with an acquire fence and an 8-attempt cap that falls back to a best-effort copy so out[] is always written.

Worth a look

ml_peer_nvs_get_flush_diag now writes a fourth element, overflowing callers built against the prior out[3] contract — components/microlink/src/ml_peer_nvs.c:272 · Escalate · medium
- agreed by 2 of 2 members but NOT verified (no proof, no reproducing execution) — consensus is not a verdict; needs human review

Analysis details — impact, health, verification

Impact & health

Graphify review

Impact — 316 functions depend on the 231 functions this change touches.

Health — this change adds coupling hotspots:

new: dcs_support_init() — 2 callers, 30 callees
new: add_peer() — 2 callers, 22 callees
new: disco_send_ping_to_peer() — 8 callers, 5 callees
new: disco_send_call_me_maybe() — 6 callers, 4 callees
new: noise_send() — 7 callers, 3 callees
new: microlink_init() — 1 callers, 17 callees
new: disco_periodic_probes() — 1 callers, 16 callees
new: dcs_pstop_set_peer_slot() — 3 callers, 5 callees
…and 33 more — each is listed as a finding

Verification — 316 functions in the blast radius were not formally verified this run (proofs are advisory here).

Gate & verification

graphify gate

PASS — objectively clean (no health regressions, tests not run — proofs not run this pass (advisory)). Grounded, not self-assessed.

Advisory (not blocking):

verification_scope: 310 function(s) in the blast radius were not formally verified this run

Formal verification

Could not verify: Could not verify handler\_monitor.

The verifier did not have enough to check handler\_monitor, so it is saying so rather than guessing. No false assurance is the whole point.