feat(bench): attribute the loose-write residual — dir-scaling + splice I/O counters

sd_bench grows a directory-entry-scaling section (stat hit/miss and
the loose-object composite at 8/64/256 siblings): FAT resolves every
path component by linear scan, so cost climbing with N convicts
directory scans as the ~360ms residual; flat cost exonerates them.
stage_and_commit brackets the splice with the p_mmap counters and logs
'N mmaps / M KB read' per commit, splitting the residual into pack-read
I/O vs everything else on the next real :sync.
This commit is contained in:
Julien Calixte
2026-07-14 01:12:35 +02:00
parent a941ae39b3
commit 8c4866df1f
3 changed files with 66 additions and 4 deletions

View File

@@ -51,9 +51,15 @@ Sync performance — inherited from the
- [ ] Close the publish gap: 19.8 s today — the splice's 5.0 s and the ~7 s of
repo-open/negotiation overhead are the next curves
([tradeoff analysis](tradeoff-curves/sync-commit-staging.md)).
- [ ] Instrument the residual ~360 ms/loose-write (suspect: FAT directory-op
cost in the freshen/refresh path) — one `sd_bench` + `p_mmap`-miss
logging pass.
- [~] Instrument the residual ~360 ms/loose-write (suspect: FAT directory-op
cost in the freshen/refresh path) — **instrumentation BUILT 2026-07-14,
measurement run pending**: `sd_bench` grew a directory-entry-scaling
section (stat hit/miss + the loose-object composite at 8/64/256
siblings — FAT resolves paths by linear scan, so cost climbing with N
convicts dir scans; flash with `just flash-bench`), and `stage_and_commit`
now brackets the splice with the `p_mmap` counters, logging
`N mmaps / M KB read` per commit so the next real `:sync` splits the
residual into pack-read I/O vs everything else.
- [ ] The images-off-card lever
([notes/git-sync-images-and-repo-size.md](notes/git-sync-images-and-repo-size.md))
composes with the splice — decide whether to take it here.

View File

@@ -117,6 +117,42 @@ fn run() -> Result<()> {
Ok(())
})?);
// 6b) Directory-entry scaling — the ~360 ms/loose-write residual suspect
// (2026-07-13, post-FASTSEEK; see sync-commit-staging.md). FAT has no
// directory index: every path resolution scans the parent's entries
// linearly over SPI, so op cost should grow with sibling count. A repo
// `.git/objects/` accumulates up to 256 fan-out dirs, and every loose
// write resolves multi-component paths under it several times (freshen
// stat, temp create, remove, rename). If stat/create cost climbs with N
// here, the residual is directory scans, not data I/O — and the miss
// case (full scan, no early exit) is the worst-case bound.
for n in [8usize, 64, 256] {
let dir = format!("{BENCH_DIR}/fan{n}");
fs::create_dir_all(&dir)?;
for j in 0..n {
File::create(format!("{dir}/e{j:04}"))?; // sibling entries (untimed setup)
}
summarize(&format!("stat hit, {n:>3} siblings"), time_each(|i| {
fs::metadata(format!("{dir}/e{:04}", i % n)).map(|_| ()).map_err(Into::into)
})?);
summarize(&format!("stat miss, {n:>3} siblings"), time_each(|i| {
let _ = fs::metadata(format!("{dir}/nope{i}"));
Ok(())
})?);
summarize(&format!("loose composite, {n:>3} sib"), time_each(|i| {
let tmp = format!("{dir}/tmp_obj{i}");
let fin = format!("{dir}/{i:038x}");
let _ = fs::metadata(&fin); // freshen probe, misses
{
let mut f = File::create(&tmp)?;
f.write_all(&PAYLOAD)?;
}
let _ = fs::remove_file(&fin); // p_rename's remove(to) — ENOENT
fs::rename(&tmp, &fin)?;
Ok(())
})?);
}
// Clean up so the card is left as we found it.
fs::remove_dir_all(BENCH_DIR).with_context(|| format!("removing {BENCH_DIR}"))?;

View File

@@ -476,6 +476,13 @@ fn stage_and_commit(repo: &Repository, paths: &BTreeSet<String>) -> Result<Optio
None => None,
};
// I/O attribution for the ~360 ms/loose-write residual (v0.7 follow-up):
// bracket the splice with the p_mmap counters so the log says how many
// mmap windows (≈ unique pack reads) and how many KB the whole splice
// issued. Divided by the loose writes (~4/path: blob + tree chain), this
// pins whether the residual is pack-read I/O or FAT directory ops — the
// two candidates left after FASTSEEK.
let (maps_before, read_kb_before) = map_counters();
let t_splice = Instant::now();
let mut tree = base;
for path in paths {
@@ -514,9 +521,12 @@ fn stage_and_commit(repo: &Repository, paths: &BTreeSet<String>) -> Result<Optio
let oid = repo
.commit(Some("HEAD"), &sig, &sig, &message, &tree, &parents)
.context("creating commit")?;
let (maps_after, read_kb_after) = map_counters();
log::info!(
"commit split — splice {splice_ms}ms ({} path(s)), commit-obj {}ms; committed {} — free heap {} ({} internal)",
"commit split — splice {splice_ms}ms ({} path(s), {} mmaps / {} KB read), commit-obj {}ms; committed {} — free heap {} ({} internal)",
paths.len(),
maps_after - maps_before,
read_kb_after - read_kb_before,
t_commit.elapsed().as_millis(),
short(oid),
free_heap(),
@@ -931,6 +941,16 @@ unsafe extern "C" {
fn esp_map_stats(hits: *mut u32, misses: *mut u32, read_kb: *mut u32, cached_kb: *mut u32);
}
/// The p_mmap emulation's cumulative counters: (mappings created, KB read).
/// Deltas around an operation attribute its pack-read I/O (each mapping is a
/// real lseek+read over SPI in esp_map.c).
fn map_counters() -> (u32, u32) {
let (mut maps, mut read_kb) = (0u32, 0u32);
// SAFETY: esp_map_stats only writes the non-null out-params.
unsafe { esp_map_stats(std::ptr::null_mut(), &mut maps, &mut read_kb, std::ptr::null_mut()) };
(maps, read_kb)
}
/// One-line heap + odb-cache + mmap snapshot for the push path. Runs 46
/// (2026-07-13) each spent ~65 s inside `remote.push()` while something
/// consumed ~6 MB of PSRAM (run 4: the UI aborted on a framebuffer alloc;