diff --git a/docs/notes/sync-commit-handoff.md b/docs/notes/sync-commit-handoff.md index da32643..2092ada 100644 --- a/docs/notes/sync-commit-handoff.md +++ b/docs/notes/sync-commit-handoff.md @@ -22,6 +22,32 @@ the toy `typoena-test` (`notes.md`) has. The repo cannot be shrunk (the 150 MB o images serve another app — see the images note). So the fix is a **new commit mechanism**, not a tuning knob. +> **Splice bench result (2026-07-12, later the same day): 6.5 s — do NOT wire it +> in yet.** The walk is in `git_bench` (`splice stage→tree`) and its O(depth) +> shape is confirmed on the real repo (flat pack reads, heap healthy, no OOM), +> but each of its 4 loose-object writes costs **~1.5 s** — isolated `odb.write` +> regressed 142 ms → 1.5 s vs the previous run, with **0 mmap-cache hits**. +> Projected full commit ≈ 8–9 s. +> +> **Root cause found the same evening (sd_bench seek op): FatFS lseek walks the +> FAT cluster chain** — seek+read(4 KB) into the 263 MB pack costs **198.7 ms at +> the end vs 5.8 ms at offset 0**, and each loose write pays ~8 such walks via +> the freshen path's small `p_mmap`s → the ~1.5 s. Fix landed in +> `sdkconfig.defaults`: `CONFIG_FATFS_USE_FASTSEEK=y` + +> `FAST_SEEK_BUFFER_SIZE=256` (O(1) lseek for read-mode files, i.e. the pack — +> see [FatFS f_lseek/CLMT](http://elm-chan.org/fsw/ff/doc/lseek.html) and the +> [ESP-IDF FatFS docs](https://docs.espressif.com/projects/esp-idf/en/latest/esp32/api-reference/storage/fatfs.html)). +> **Verified on device: far seek 198.7 → 20.4 ms.** The A/B (splice 6.5 → 2.8 s, +> odb.write 1.5 s → 416 ms) plus new probes then localized the residual to ~7–8 +> repeated small (~4 KB) pack reads per op that the mmap cache's 64 KB floor +> excluded (`odb.read_header(packed)` = 470 ms; the strict-object-creation +> theory was refuted — strict-off changed nothing). **esp_map.c v2 built**: +> cache admission keyed on FILE size ≥ 1 MB so the hot small windows cache, and +> evict-on-`p_munmap` to a 2 MB low-water mark fixes the 7.4 MB OOM. **Final +> `git_bench` verdict pending — if splice lands sub-second, proceed with the +> firmware plumbing below.** Full trail: the splice-bench, root-cause and +> second-localization sections of the tradeoff curve. + ## The fix — O(depth) TreeBuilder walk Rebuild only the edited file's ancestor subtree chain onto HEAD's tree. Never @@ -70,11 +96,24 @@ tree), and path splitting on `/` (paths are repo-relative POSIX). **Bench it first** (per the established discipline): add a `treebuilder splice→tree` op to `firmware/src/bin/git_bench.rs` alongside the existing ones and confirm it's sub-second cold on the real repo, with heap staying healthy (no OOM). Only then wire -it into the firmware. +it into the firmware. While in there, two bench-hygiene fixes: (a) the `edit_path` +seed block does the cold `read_tree(HEAD)` **untimed** (the 77 s number came from +log timestamps), so the `Index::new + read_tree` bench only ever measures warm — +wrap the seed in a timer so a re-run prints the cold number; (b) the "3) THE +PROPOSED FIX — index-free commit tree" comment is now stale — the real-repo run +refuted that path (77 s + OOM) and this handoff supersedes it — retitle it as the +refuted alternative. ## Firmware plumbing (after the bench validates) 1. **`firmware/src/git_sync.rs`** + - **Set the mwindow options at service start** (before the first + `Repository::open`): `git2::opts::set_mwindow_size(256 * 1024)` + + `set_mwindow_mapped_limit(4 * 1024 * 1024)`. Today only `git_bench.rs` sets + them — the shipping service runs libgit2's 32-bit defaults (**32 MB window / + 256 MB mapped limit**, mwindow.c:16), so the first pack access on the 570 MB + clone would try to `git__malloc` a 32 MB window and die on the 8 MB PSRAM + heap before the walk even runs. - Rewrite `stage_and_commit` (currently ~L271–332) to the `splice`-walk above. Drop `add_all`/`update_all`/`index.write`/`index.write_tree`. Keep the `commit split —` timing log, the `tree unchanged → nothing to publish` check, @@ -89,13 +128,26 @@ it into the firmware. - The macOS-cruft filter (`skip_macos_cruft`) is no longer needed — the walk only ever touches paths the editor explicitly hands it, so `._*`/`.DS_Store` can't sneak in. (Keep a note; don't silently lose the Spike-14 lesson.) + - **Deliberate behavior change to record:** the walk commits *only* the + editor's dirty set. Files changed on the card outside the editor (e.g. the + card mounted on a Mac) were swept in by `add_all` before; they will now never + be committed, and the working tree will show a permanent diff against HEAD if + inspected on a desktop. Correct for the appliance (it's also what makes the + cruft filter unnecessary), but it must be intentional, not accidental. 2. **Dirty-set source — `firmware/src/persistence.rs` + `main.rs`** - - Writes funnel through `Storage::save_path` (~L296) and deletes through - `Storage::delete_path` (~L332), both `&self`. Accumulate a dirty/deleted set + - Writes funnel through `Storage::save_path` (~L316) and deletes through + `Storage::delete_path` (~L352), both `&self`. Accumulate a dirty/deleted set (needs `RefCell` interior mutability, or move the set up to `main.rs`). - `Effect::Publish` handler in `main.rs` (~L222) builds the `PublishRequest` from that set and clears it on a successful `Pushed`/`UpToDate` outcome. + - **FD budget: `main.rs` (~L413) mounts with `Storage::mount()` = 4 open + files, and the git thread shares that mount.** libgit2 keeps the pack + + `.idx` (+ commit-graph) descriptors open and opens loose objects on top — + that's why `git_bench` needed `mount_for_git` (16). On the real repo the + shipping `:sync` will fail with "no free file descriptors" long before any + latency question. Either mount with the 16-file budget in `main.rs` (the + editor's 2-FD peak coexists fine) or split the budgets some other way. 3. **`esp_map.c` cache fix (same pass) — `firmware/components/libgit2/esp_map.c`** - Bug: cached buffers are freed only lazily in `p_mmap`'s `evict_for`, so a @@ -128,11 +180,22 @@ the toy pack understates everything by ~2 orders of magnitude. ## What's proven vs open -**Proven (2026-07-12, real repo):** `odb.write` 142 ms (mmap cache holds); -`index.write` 611 s (whole-tree re-hash via `truncate_racily_clean`, index.c:822 / -index.h:117); index-free `read_tree` 77 s cold; mmap cache OOM at 7.4 MB → zlib -crash. `Repository::open` 88 ms, odb-open ~6 s cold (maps 1.7 MB `.idx`). +**Proven (2026-07-12, real repo):** `index.write` 611 s (whole-tree re-hash via +`truncate_racily_clean`, index.c:822 / index.h:117); index-free `read_tree` +77–82 s cold (reproduced across both runs); mmap cache OOM at 7.4 MB → zlib crash +(reproduced). `Repository::open` ~90–99 ms, odb-open ~6–8 s cold (maps 1.7 MB +`.idx`). **Splice walk benched (second run): 6.5 s p50, warm ≈ cold** — O(depth) +shape confirmed (flat reads ~40 KB/write, 6.4 MB heap free), cost is 4 loose +writes × ~1.6 s. `commit(None)` 1.7 s. -**Open:** the TreeBuilder walk is **designed but not yet benched or built.** Confirm -its cold-real-repo latency and heap before wiring. Push (network half, ~6.5 s) is a -separate floor, untouched here. +**Open — the new gating question: why does one loose-object write cost ~1.5 s?** +`odb.write(blob)` measured 142 ms in the first real-repo run but 1.5 s in the +second (same `esp_map.c`, same card, **0 cache hits** the whole second run) — the +two runs are unreconciled. Suspects, cheapest first: (a) FAT free-cluster scan on +the ~740 MB-full card → re-run `sd_bench` as-is on this card; (b) loose-write +internals (filebuf tmp + rename, per-write `git_odb_refresh` readdir) under the +accumulating orphan objects from bench runs → re-provision a fresh clone and A/B; +(c) the ~10 small 4 KB `p_mmap`s per write (sub-64 KB, uncacheable) — bounded +~100 ms, secondary. Also open: whether the esp_map cache earns its keep at all +(0 hits this run), the ref/reflog-update cost on the real repo, and the push +(network ~6.5 s) floor — all untouched here. diff --git a/docs/tradeoff-curves/sync-commit-staging.md b/docs/tradeoff-curves/sync-commit-staging.md index 4ba9ad3..c01a6ad 100644 --- a/docs/tradeoff-curves/sync-commit-staging.md +++ b/docs/tradeoff-curves/sync-commit-staging.md @@ -4,10 +4,19 @@ > nor an index-free `read_tree`+`write_tree` is viable on the real > `jcalixte/notes` clone — **both are O(N_tree)** and blow up on the 570 MB pack / > 1179-file tree (611 s hash one end, 77 s tree-read + OOM the other; see -> [Real-repo run](#real-repo-run-2026-07-12-jcalixtenotes-570 mb-pack--the-index-is-the-wrong-primitive) +> [Real-repo run](#real-repo-run-2026-07-12-jcalixtenotes-570-mb-pack--the-index-is-the-wrong-primitive) > below). The commit must be rebuilt with an **O(depth) TreeBuilder walk** — > patch only the edited file's ancestor subtree chain onto HEAD's tree, never -> materialise all 1179 entries. Shrinking the repo is **not** an option +> materialise all 1179 entries. +> +> **Splice-bench update (2026-07-12, later the same day):** the walk was built +> into `git_bench` and measured on the real repo — **6.5 s, failing the +> sub-second bar.** The O(depth) *shape* holds (flat pack reads, healthy heap), +> but each of its 4 loose-object writes costs **~1.5 s** (isolated `odb.write` +> regressed from the 142 ms above; the mmap cache scored **0 hits** this run). +> Localizing the loose-write cost is now the gating work — see +> [Splice bench](#splice-bench-2026-07-12-second-real-repo-run--the-walk-is-right-the-loose-object-write-is-the-new-wall). +> Shrinking the repo is **not** an option > ([`../notes/git-sync-images-and-repo-size.md`](../notes/git-sync-images-and-repo-size.md): > the images are load-bearing for another app), which is exactly why the O(depth) > mechanism is the only lever left. This note records the cost model and the full @@ -221,6 +230,139 @@ needs an evict-on-`munmap` fix (drop the cap, free past a low-water mark) so it never again starve a downstream `git__malloc`, but with the TreeBuilder walk the pressure it was under largely disappears. +### Splice bench (2026-07-12, second real-repo run) — the walk is right, the loose-object write is the new wall + +The O(depth) splice op was added to `git_bench` (1 blob + 3 tree writes onto the +depth-3 path `.claude/commands/bsky.md`, run FIRST so its first iteration is +cold; the index ops moved last so their OOM can't cost the new data — it did +crash again, after everything was logged): + +| op | result | reading | +| --- | ---: | --- | +| `splice stage→tree` (1 blob + 3 trees) | **6.5 s p50, warm ≈ cold** | O(depth) confirmed — cost is 4 loose writes × ~1.6 s | +| `commit(None)` orphan obj | 1.7 s p50 | one more loose write | +| `odb.write(blob)` | **1.5 s p50** | ⚠️ was 142 ms in the previous run | +| `repo.index()` load | 524 ms max | matches previous run | +| seed `read_tree(HEAD)` cold (now timed) | 81.6 s | reproduces the 77 s | +| `index-free stage→tree` | 💥 crash, 508 KB heap | reproduces the zlib OOM exactly | + +Three readings: + +1. **The splice mechanism is validated as a mechanism.** Pack reads stayed flat + (~40 KB per write; 6.4 MB heap free through splice + commit + odb.write), so + it really is O(depth) and it cannot OOM. The 6.5 s is not tree-walk cost. +2. **The wall moved to the loose-object write: ~1.5 s each, ×4 per splice.** + The isolated `odb.write(blob)` — one tiny orphan blob — took 1.5 s where the + raw FAT composite is 86 ms. Projected full commit (splice 6.5 s + commit-obj + 1.7 s + ref/reflog update) ≈ **8–9 s**: enormously better than 611 s, still + far off the bar. +3. **The mmap cache scored 0 hits over the entire run** — the documented + 862→142 ms `odb.write` win did **not reproduce** (same `esp_map.c`, same + card). Either the earlier run's conditions differed (orphan-object + population? FAT allocation state?) or the win was misattributed. Whatever the + 1.5 s is, it is *not* SD data volume: each write moves ~40 KB read + ~1 KB + written. + +### ROOT CAUSE FOUND (2026-07-12, `sd_bench` seek op): FatFS lseek walks the cluster chain + +Two `sd_bench` re-runs on the ~740 MB-full card settled it: + +1. **Free-cluster-scan hypothesis: refuted.** Raw FAT write ops are unchanged on + the full card — loose-object composite **77 ms p50** (was 86 ms), create + 20 ms, rename 10 ms. The card is exonerated a second time. +2. **Long seeks are the cost.** A new op opens the repo's largest packfile + (263 MB — the "570 MB pack" was actually the whole `.git`) read-only and does + seek+read(4 KB): **@offset 0 = 5.8 ms; @end = 198.7 ms** — dead constant + across 20 iters. Without `CONFIG_FATFS_USE_FASTSEEK`, FatFS resolves lseek by + walking the file's FAT cluster chain over SPI: forward from the current + position, **from the chain head on any backward seek**. 263 MB ≈ 16.8k + clusters ≈ ~67 KB of FAT reads ≈ ~190 ms per long walk. + +**Why FAT behaves this way:** FAT has no extent map or inode — a file is a +singly-linked list of clusters, and the only way to find "byte 260,000,000" is +to follow that list entry by entry through the allocation table. FatFS walks +forward from the current position when it can, but a backward seek restarts +from the chain head ([FatFS `f_lseek` docs, elm-chan.org](http://elm-chan.org/fsw/ff/doc/lseek.html)). +The fast-seek feature fixes exactly this: a pre-computed **cluster link map +table (CLMT)** per file object, "(fragments + 1) × 2" words, after which "no +FAT access is occured in subsequent f_read/f_write/f_lseek" (same page). On +esp-idf it's `CONFIG_FATFS_USE_FASTSEEK` — the official docs recommend it "for +read-heavy workloads with long backward seeks" and note it does not apply to +files opened in write mode +([ESP-IDF FatFS docs](https://docs.espressif.com/projects/esp-idf/en/latest/esp32/api-reference/storage/fatfs.html)). + +The budget closes: each loose write does ~8–10 small (~4 KB) `p_mmap`s (freshen +→ trailer/idx probes) interleaved with low-offset reads, so ~8 of them pay a +fresh ~190 ms walk → **~1.5 s per object**. It also explains everything the +cache couldn't: warm ≈ cold (the walk is paid inside `lseek` before any data +moves, and the maps are below the 64 KB cache floor), the 142 ms vs 1.5 s +run-1/run-2 discrepancy (run 1's `odb.write` bench ran first and hammered only +the trailer — the file position stayed there, so its seeks were forward/no-ops), +and a large slice of the 81.6 s `read_tree` (133 windows × backward seeks ≈ 25 s +of walking on top of the 25 MB of data). + +**Fix (config, not code): `CONFIG_FATFS_USE_FASTSEEK=y` + +`CONFIG_FATFS_FAST_SEEK_BUFFER_SIZE=256`** (landed in `sdkconfig.defaults` +2026-07-12). Fast seek builds an in-memory cluster-link map per read-mode file — +exactly how the pack is opened — making lseek O(1); write-mode files fall back +to the walk transparently. 256 words = 1 KB per open read-only file, covering +~127 fragments (default 64 covers ~31; a fragmented pack would silently fall +back to slow seeks, so the headroom matters). + +**A/B measured (same evening): a 2.3× partial win, not a full one.** + +| op | fast-seek off | fast-seek on | +| --- | ---: | ---: | +| `splice stage→tree` | 6.5 s | **2.81 s** | +| `odb.write(blob)` | 1.5 s | **416 ms** | +| `commit(None)` | 1.7 s | **1.72 s — unchanged** | + +`odb.write` dropped by almost exactly the ~6 chain walks the model predicted — +the seek theory holds — but two residuals remain: **~400 ms per loose write** +(vs the 77 ms raw-FAT floor) and **`commit(None)`'s ~1.3 s premium over a plain +write, which was never seek-bound at all**. Prime suspect for the commit +premium: strict object creation makes `git_commit_create` validate its parent + +tree OIDs with pack header resolves, and `git_treebuilder_insert` does the same +per inserted entry — `git_bench` grew `odb.read_header(packed)` / +`odb.exists(missing)` probes and strict-off re-benches to test it. + +### Second localization round (2026-07-12, run 3b + sd_bench re-run) + +**Fast-seek verified on the metal:** re-running the sd_bench seek op with +`CONFIG_FATFS_USE_FASTSEEK=y` dropped `pack seek+read 4KB @end` from +**198.7 ms → 20.4 ms** (the CLMT fits the pack in the 256-word buffer — the +pack is not too fragmented). A far seek is now ~15 ms, i.e. effectively fixed. + +**The strict-creation theory is refuted; the probes found the real unit cost:** + +| op | p50 | reading | +| --- | ---: | --- | +| `odb.read_header(packed)` | **470 ms** | ONE pack header resolve costs ~½ s | +| `odb.exists(missing)` | **968 ms** (±0.1 ms) | miss path (scan → refresh → rescan) ≈ 2× | +| `commit(None)` strict OFF | 1.80 s | vs 1.93 s strict on — validation is NOT the premium | +| `splice` strict OFF | 5.7 s | noise-worse; also not validation | + +The ±0.1 ms constancy of `exists(missing)` = a fixed, deterministic SD-op +sequence. The map counters identify it: **~7–8 small (~4 KB) `p_mmap` reads per +op** — pack trailer probes, idx fanout reads and delta-base windows, repeated +at the *same offsets* on every freshen/refresh. Post-fast-seek those cost +~20 ms each (~150 ms/op); the rest of `read_header`'s 470 ms is CPU-side +delta-chain inflation on the 160 MHz core plus repeated re-reads. Two other +observations from run 3b: the loose-object orphan population from bench runs +is creeping costs upward (splice 2.81 s → 3.21 s between consecutive +fast-seek runs — a re-provision resets it), and the mmap cache STILL scored 0 +hits — because its 64 KB map-length floor excluded exactly these hot small +maps. + +**Fix built (esp_map.c v2, pending re-bench):** cache admission re-keyed from +map length to **file size ≥ 1 MB** — the pack/idx's small repeated windows now +cache (RAM hits after first touch) while small mutable working-tree files stay +excluded — plus **evict-on-`p_munmap` down to a 2 MB low-water mark**, fixing +the 7.4 MB OOM from the first real-repo run (released windows are actually +returned to `git__malloc`, so `MWINDOW_MAPPED_LIMIT` stays honest). Expected: +`read_header` collapses toward CPU-only, `odb.write` toward ~150–250 ms, +splice at or under the sub-second bar, and no end-of-run zlib OOM. + ### The walk is ~1.4 s even at N ≈ 2 Mostly fixed cost — the worktree-diff setup and the second (`update_all`) pass — @@ -245,7 +387,9 @@ work, ranked: flat in repo size, small heap, images carried forward untouched. Replaces `stage_and_commit`'s `add_all`/`update_all`/`index.write`/`write_tree`. Needs the editor's dirty set (+ deleted set) plumbed to the git service — the editor - already knows both. **Bench the walk on the real repo before wiring it in.** + already knows both. **Benched 2026-07-12: 6.5 s — the shape is right but it + fails the sub-second bar**; wiring it in is blocked on localizing the ~1.5 s + loose-object write (see the splice-bench section above). 2. **Fix the `esp_map.c` cache so it can't OOM (do it alongside #1).** It grew to 7.4 MB resident past its 4 MB cap and starved zlib. Evict on `p_munmap` (not only lazily on the next `p_mmap`) down to a low-water mark, and lower the cap, so