Skip to content

Restore sd_logger utc-origin, confine_format and SD diagnostics on top of ccp - #3

Open
kipp-ing wants to merge 9 commits into
mainfrom
feat/rig-restore
Open

kipp-ing wants to merge 9 commits into
mainfrom
feat/rig-restore

Conversation

@kipp-ing

Copy link
Copy Markdown
Owner

Brings the generic work that never reached main after the history squash back onto one branch:

  • feat/ccp-master (generic CCP 2.1 master, CI matrix + required-checks gate)
  • sd_logger/can_gateway: utc-origin timestamps (time_id), DAQ memory-read, optional RX-ISR frame hook — the commit from feat/sd-logger-utc-origin
  • sd_logger: confine_format action, SD diagnostics, confine policy, switch platform — recovered from an unmerged WIP stash

Supersedes feat/ccp-master and feat/sd-logger-utc-origin.

Verification (local): script/check.sh exit 0 (938 pytest, clang-format, esphome config, no-private-data guard), make -C tests/host 452 cases 0 failed, esphome compile of all three tests/build/sd_logger images exit 0.

https://claude.ai/code/session_01AjXiyweBQw3gysrQBgvwSf

New ESPHome external component `ccp`: a CAN Calibration Protocol master on
can_gateway (single-frame CRO/DTO, no ISO-TP). Full command set + high-level
read_memory/write_memory helpers, ESPHome actions, on_connected/on_response/
on_error/on_daq triggers, and a pure host-testable ccp_proto.h codec.

Every field (command/response CAN ids, station address, byte order, timeout)
is configurable; the schema defaults and every test/example address are
generic placeholders, not tied to any one ECU. Observe-first safety: no
auto-connect, allow_write gates every write command; emits
USE_CAN_GATEWAY_OBSERVE.

Gates green: script/check.sh (14 ccp schema tests, both build fixtures,
clang-format, esphome config); make -C tests/host (5 ccp_proto cases incl.
little-endian SET_MTA and 12->5/5/2 read chunking).
Both ccp build fixtures (default read-only, allow_write:true) now compile in
CI alongside the rest of the matrix, so a ccp change is gated the same as
every other component before it can reach main.

Claude-Session: https://claude.ai/code/session_01JpmPzXhUDovTMWBiNMzb89
Branch protection on main will require this one context rather than every
individual compile-matrix leg by name, so renaming or adding a build fixture
never requires touching the ruleset.

Claude-Session: https://claude.ai/code/session_01JpmPzXhUDovTMWBiNMzb89
…ame hook

Squashed from 9 working commits (see the retired pre-squash branch for
individual history, where still accessible): sd_logger anchors on-card
timestamps to real UTC and tags chunks with their origin; the collection
server publishes real card state and recovers a card whose ACMD41 handshake
latched, without a power cycle; the tap-drain and serving tasks' stack sizes
were corrected after two separate under-sizing bugs; can_gateway gained a
per-port record of what that node itself transmits, and an optional RX-ISR
frame hook (behind a component-emitted define, opt-in only) for a consumer
whose state machine needs sub-loop-interval latency; ccp gained a first-class
DAQ memory-read action with an in-frame anchor that self-verifies against a
target's configured expectation.

script/check_no_private_data.py and script/check.sh are green as of this
commit.
Recovered from the pre-rebase WIP stash that never landed after the
history squash (diff 1cd21b6..stash, todo.txt excluded), on top of the
utc-origin work (0127697) and feat/ccp-master. Gate: check.sh exit 0,
938 pytest, 452 host cases, no-private-data OK; tests/build/sd_logger
compiles (3/3).

Claude-Session: https://claude.ai/code/session_01AjXiyweBQw3gysrQBgvwSf
…watchdog across confine_format

The chunk index refused every chunk once full while retention could only fire at
retention_percent card fill. On a 32 GiB confined volume with ~1.4 MB chunks and 512 slots
the index filled at ~2 % fill against a threshold of 80 %, so it filled ~36x over before a
victim could be chosen, and every later chunk was written but never listed, served or
deleted. That stranded a capture on the bench.

add() still refuses on its own. The writer may now answer that refusal by deleting the
oldest non-serving CONFIRMED chunk and retrying: those bytes are already collected and
acknowledged, so the deletion is not a #gap. SEALED and OPEN chunks are never spent on
index pressure; only fill-triggered retention may lose never-collected data, and that is
still billed into the gap window.

confine_format's f_fdisk()/f_mkfs() are wrapped in a task-watchdog pause/yield bracket:
the format completed but the watchdog fired during it and ESPHome rolled back the image.
That half is code and diagnosis only - it has not run on hardware.

Claude-Session: https://claude.ai/code/session_01AjXiyweBQw3gysrQBgvwSf
`try_recover_() -> mount_card_() -> run_capacity_self_test_()` needs ~4,544 B of stack; the
writer task was created with 4,096. On a bench where the card started failing writes, every
single recovery attempt panicked:

    [W][sd_logger:3210][sdlog_wr]: card recovery: attempt 1 (remount)
    Guru Meditation Error: Core  0 panic'ed (Stack protection fault).
    Detected in task "sdlog_wr"
    Stack pointer: 0x40855ae0   Stack bounds: 0x40855b20 - 0x40856b10

Bounds are exactly 0x1000 and the stack pointer is 64 B below the lower bound. The hardware
watchpoint was right; the ladder was simply too deep for the stack it ran on. The board
crash-looped into ESPHome safe mode, so the component's own recovery design — count the
losses, keep the rings still, try again on a backoff — could never once execute.

Both task-creation sites go to 8192 (the second is the re-create path; fixing only one fixes
it until the writer restarts). `writer_stack_free` is published in the status JSON, sampled
after every `try_recover_()` return, so the headroom is readable instead of inferred, with
`writer stack low`/`critical` warnings below 2048/1024 B.

MEASURED on hardware after the fix, 600 s against a card that fails a write ~1.4 s after every
successful mount: 414 recovery attempts, 413 recovered and resumed logging, zero panics, zero
resets, `writer_stack_free` 3684. The same path panicked on attempt 1 every time before.

Deliberately not done: nothing here suppresses, skips or shortens the recovery ladder. A ladder
that cannot run is worse than one that crashes loudly.
Two defects, measured on an ESP32-C6 with a card on SPI, IDF 5.5.4.

Mounts failed ESP_ERR_NO_MEM because esp_vfs_fat_register_cfg() asks for
sizeof(vfs_fat_ctx_t) + max_files * sizeof(FIL) as ONE contiguous
MALLOC_CAP_DEFAULT block on every mount, and sizeof(FIL) carries an FF_MAX_SS
per-file cache. FF_MAX_SS is set by CONFIG_WL_SECTOR_SIZE, not by
CONFIG_FATFS_SECTOR_*, which only feeds the host-side fatfsgen tool and never
reaches the firmware. At the IDF default of 4096 each FIL was 4136 B and every
mount a 20,680 B contiguous request against a largest free block of 28,672 B.
So: max_files 5 -> 3 with every concurrent opener enumerated, dump_config now
publishes FF_MAX_SS, sizeof(FIL) and the resulting allocation against the
DEFAULT-cap largest block, and final validation warns for any image that has
not set CONFIG_WL_SECTOR_SIZE to 512. That stays a warning and never a silent
override: an image may legitimately need a 4096 B wear-levelled FAT volume on
flash, and forcing 512 would corrupt it.

The second was worse. A write() that failed with EIO went into the same
unbounded remount ladder as a dead card: remount, re-scan every chunk file,
reopen, fail, 1.3 s, ~256 times, indefinitely. The SPI trace said why that
could never work -- 817 commands sampled across several complete cycles, 2976
CMD13 and 2952 CMD17, zero CMD24, zero CMD25, every one err 0. The card was
never asked to write anything, so remounting could not change the outcome.
classify_write_failure() now stops the ladder when the failing write issued no
SDSPI transaction at all, and says so; any command in the interval keeps the
full ladder, because that ambiguity must bias toward retrying a card that may
really be coming back. The stop clears on the next successful mount, nothing is
ever erased to recover, and the component still refuses to take the buses down.

A failure now names its own layer without a bench session: real lseek() offset
alongside the old derived one (a disagreement is itself a finding), the SPI
sequence span and worst error across the call, card-vs-volume sectors, the
DEFAULT and DMA heap figures, and elapsed time. The trace ring carries the
card's response raw and post-mask, so a post-write status rejection is finally
visible in the instrument built to see it. Fields that mean nothing before the
first failure render as null rather than as zero.

486 host cases, 0 failed.

Claude-Session: https://claude.ai/code/session_01AjXiyweBQw3gysrQBgvwSf
@kipp-ing

Copy link
Copy Markdown
Owner Author

Two more sd_logger commits on this branch, both from defects measured on real hardware (ESP32-C6, card on SPI, IDF 5.5.4).

088a78c — the writer's card-recovery path overflowed its own stack. try_recover_() → mount_card_() → run_capacity_self_test_() needs ~4,544 B; the writer task had 4,096. Every recovery attempt panicked, so the component's own recovery design could never once execute.

09ac24a — the mount's real cost, and a ladder that knew when to stop. Two independent defects:

Mount ESP_ERR_NO_MEM. esp_vfs_fat_register_cfg() asks for sizeof(vfs_fat_ctx_t) + max_files * sizeof(FIL) as one contiguous MALLOC_CAP_DEFAULT block on every mount, and sizeof(FIL) carries an FF_MAX_SS per-file cache. FF_MAX_SS is set by CONFIG_WL_SECTOR_SIZEnot by CONFIG_FATFS_SECTOR_*, which only feeds the host-side fatfsgen tool and never reaches the firmware. At IDF's 4096 default each FIL was 4136 B and every mount a 20,680 B contiguous request against a largest free block of 28,672 B and falling. max_files drops 5 → 3 with every concurrent opener enumerated; dump_config() now publishes FF_MAX_SS, sizeof(FIL) and the resulting allocation against the DEFAULT-cap largest block; final validation warns for any image not explicitly at 512. That stays a warning, never a silent override — an image may legitimately need a 4096 B wear-levelled FAT volume on flash, and forcing 512 would corrupt it.

A recovery ladder that live-locked. A write() failing with EIO went into the same unbounded remount ladder as a dead card: remount, re-scan every chunk file, reopen, fail, 1.3 s, ~256 times, indefinitely. The SPI trace said why that could never work — 817 commands sampled across several complete failure cycles: 2976 × CMD13, 2952 × CMD17, zero × CMD24, zero × CMD25, every one err 0. The card was never asked to write anything, so remounting could not change the outcome. classify_write_failure() now stops the ladder when the failing write issued no SDSPI transaction at all; any command in the interval keeps the full ladder, because that ambiguity must bias toward retrying a card that may really be coming back. The stop clears on the next successful mount, nothing is ever erased to recover, and a failing card still cannot take the buses down.

A failure now names its own layer without a bench session: real lseek() offset alongside the old derived one (a disagreement is itself a finding), the SPI sequence span and worst error across the call, card-vs-volume sectors, DEFAULT and DMA heap figures, elapsed time. The trace ring carries the card's response raw and post-mask, so a post-write status rejection is visible in the instrument built to see it. Fields meaningless before the first failure render as null, not 0.

Verification: 486 host cases 0 failed; consuming project's gate exit 0; a real esphome compile; flashed and confirmed live — recovery_state=mounted, write_failures=0, absent last_write_* rendering as null, CMD13 rows carrying the card's response, and card_dropped 4307 → 0.

Not closed, and the commit says so: which FatFs condition produced the EIO is still unknown. A card reformat cleared it, and that is a workaround. What ships here is the instrument that will name it on the next occurrence.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant