julien/typewriter
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

perf(sync): bench the index-free commit path and mmap cache

Browse Source 
Replace the index.write()/write_tree ops (which re-hash the whole working
tree on a fresh FAT clone -- up to 611 s on the real repo) with the
index-free candidate: Index::new + read_tree(HEAD) + blob + write_tree_to.
Add per-op mmap-cache + free-heap logging (via esp_map_stats), announce each
op before it runs so a hang reveals the culprit, mount_for_git for the FD
budget, tune the mwindow limits, and drop N 10 -> 3 for the slow real clone.
This commit is contained in:
Julien Calixte
2026-07-12 15:04:52 +02:00
parent 6c5e666f4b
commit a6f52df8b6
1 changed files with 142 additions and 19 deletions
Download Patch File Download Diff File Expand all files Collapse all files

161
firmware/src/bin/git_bench.rs
View File

@@ -22,8 +22,9 @@ use firmware::persistence::{Storage, REPO_DIR};
const BUILD_TAG: &str = concat!("build ", env!("BUILD_TIME"), " @", env!("BUILD_GIT"));
/// Iterations per op. Small — some ops write to the card, and the first vs rest
/// spread (min vs max) is itself the signal (e.g. write vs freshen-skip).
const N: usize = 10;
/// spread (min vs max) is itself the signal (e.g. write vs freshen-skip). Kept
/// low (3) on the real 570 MB-pack clone so a slow op still finishes in seconds.
const N: usize = 3;
fn main() -> Result<()> {
esp_idf_svc::sys::link_patches();
@@ -49,7 +50,18 @@ fn main() -> Result<()> {
}
fn run() -> Result<()> {
let _sd = Storage::mount().context("mounting SD")?;
// libgit2 holds the pack + idx (+ commit-graph) fds open and reads loose
// objects on top; the editor's default 4-FD budget can't cover read_tree.
let _sd = Storage::mount_for_git().context("mounting SD")?;
// A 32 MB default mwindow window (mwindow.c) would git__malloc > PSRAM on the
// real 570 MB pack; small windows keep each p_mmap read cheap, and the
// esp_map cache keeps them from being re-read on every freshen→refresh.
// SAFETY: process-global libgit2 options, set once before any repo work.
unsafe {
git2::opts::set_mwindow_size(256 * 1024).ok();
git2::opts::set_mwindow_mapped_limit(4 * 1024 * 1024).ok();
}
// Repository open — one-time, but shows the cost of scanning .git (config,
// refs, ODB backends/packs) which every later op may implicitly refresh.
@@ -57,40 +69,151 @@ fn run() -> Result<()> {
let repo = Repository::open(REPO_DIR)
.with_context(|| format!("opening git repo at {REPO_DIR}"))?;
log::info!("Repository::open {:.1} ms", t.elapsed().as_micros() as f64 / 1000.0);
log_map_stats("open");
// 1) odb.write(blob) in isolation — unique content each iter forces a real
// write (no freshen-skip). This is the single number that localizes it: if
// ~86 ms the ODB write path is fine and the cost is in the tree/ref layer;
// if ~700 ms the cost is inside the ODB write itself (deflate/sha/freshen).
let odb = repo.odb().context("opening odb")?;
summarize("odb.write(blob)", time_each(|i| {
bench("odb.write(blob)", |i| {
let data = format!("typoena git_bench orphan blob #{i} — unique so the write is real\n");
odb.write(ObjectType::Blob, data.as_bytes())
.map(|_| ())
.context("odb.write")
})?);
})?;
log_map_stats("odb.write");
// 2) repo.index() — cost of loading the index from the card each time.
summarize("repo.index() open", time_each(|_| {
// 2) on-disk index LOAD (no write). Times loading all ~1179 entries from the
// card and prints the count. We deliberately do NOT bench index.write() any
// more: it calls truncate_racily_clean, which diffs the whole working tree
// against the index and — because a fresh FAT clone makes every entry look
// "racy" (2 s mtime granularity) — re-hashes ~170 MB over SPI, up to ~10 min
// on this repo (proven 2026-07-12, index.write max 611 s). The fix below
// never writes the on-disk index, so that path never runs.
bench("repo.index() load", |_| {
repo.index().map(|_| ()).context("index open")
})?);
})?;
let n_entries = repo.index().map(|i| i.len()).unwrap_or(0);
log::info!("on-disk index has {n_entries} entries");
log_map_stats("index load");
// 3) index.write() — serialize + checksum + filebuf (index.lock → rename).
let mut idx = repo.index().context("opening index")?;
summarize("index.write()", time_each(|_| {
idx.write().context("index.write")
})?);
// 3) THE PROPOSED FIX — index-free commit tree (what git_sync::stage_and_commit
// will do). Build the new tree from HEAD + one changed file in a FRESH
// in-memory index: read_tree(HEAD) leaves stamp=0 so truncate_racily_clean
// can NEVER fire; the changed file is written as a blob and added by OID;
// write_tree_to writes to the odb WITHOUT touching the on-disk index. Because
// read_tree seeds the tree cache and add invalidates only the changed path,
// write_tree rebuilds just that path's subtrees — O(changed), not O(1179).
// If this is sub-second on the real repo, the fix is validated.
let head_tree = repo
.head()?
.peel_to_commit()
.context("HEAD → commit")?
.tree()
.context("HEAD tree")?;
// A real path already in the tree, so the add REPLACES it (a realistic edit) and
// write_tree rebuilds its ancestor subtrees — not just the cheap root case.
let edit_path: Vec<u8> = {
let mut seed = git2::Index::new().context("seed index")?;
seed.read_tree(&head_tree).context("seed read_tree")?;
seed.get(0)
.map(|e| e.path)
.unwrap_or_else(|| b"notes.md".to_vec())
};
log::info!(
"index-free: editing existing path {}",
String::from_utf8_lossy(&edit_path)
);
// 4) index.write_tree() — build tree(s) from the index and write to the ODB.
// First call writes the tree; later calls find it exists (freshen-skip), so
// min≈build+exists and max≈build+write — the spread separates the two.
summarize("index.write_tree()", time_each(|_| {
idx.write_tree().map(|_| ()).context("write_tree")
})?);
// read_tree alone: populating the in-memory index from HEAD's tree (reads tree
// objects through the mmap cache; NO working-file hashing).
bench("Index::new + read_tree", |_| {
let mut idx = git2::Index::new().context("Index::new")?;
idx.read_tree(&head_tree).context("read_tree")?;
Ok(())
})?;
log_map_stats("read_tree");
// Full index-free staging → tree — this REPLACES add_all + index.write +
// write_tree (the ~10-min hang) with an O(changed) path.
bench("index-free stage→tree", |i| {
let mut idx = git2::Index::new().context("Index::new")?;
idx.read_tree(&head_tree).context("read_tree")?;
let data = format!("typoena index-free bench edit #{i}\n");
let oid = repo.blob(data.as_bytes()).context("write blob")?;
idx.add(&blob_entry(&edit_path, oid)).context("index.add")?;
idx.write_tree_to(&repo).map(|_| ()).context("write_tree_to")
})?;
log_map_stats("index-free");
// 6) commit(None, …) — create a commit OBJECT without moving HEAD or writing a
// reflog (update_ref = None → an orphan commit, gc-able). Isolates commit-
// object creation from the ref-update + reflog cost. Reuses the parent's
// tree (no new tree needed); unique message each iter forces a real write.
let parent = repo.head()?.peel_to_commit().context("HEAD → commit")?;
let tree = parent.tree().context("parent tree")?;
let sig = Signature::now("typoena-bench", "bench@typoena.local").context("sig")?;
bench("commit(None) orphan obj", |i| {
let msg = format!("typoena git_bench orphan commit #{i}");
repo.commit(None, &sig, &sig, &msg, &tree, &[&parent])
.map(|_| ())
.context("commit(None)")
})?;
log_map_stats("commit");
Ok(())
}
unsafe extern "C" {
/// Counters from the p_mmap cache in `components/libgit2/esp_map.c`.
fn esp_map_stats(hits: *mut u32, misses: *mut u32, read_kb: *mut u32, cached_kb: *mut u32);
}
/// Log the p_mmap cache counters — hits vs misses (SD reads avoided), total KB
/// read from the card, and KB currently resident. If the pack-read hypothesis is
/// right, hits climb and `KB read` stops growing across the write ops.
fn log_map_stats(label: &str) {
let (mut hits, mut misses, mut read_kb, mut cached_kb) = (0u32, 0u32, 0u32, 0u32);
unsafe { esp_map_stats(&mut hits, &mut misses, &mut read_kb, &mut cached_kb) };
// Free heap spans PSRAM here; a drop toward 0 during write_tree/commit on the
// real repo would point at mwindow/idx allocation pressure (or thrash) as the
// cause of an apparent hang, not CPU.
let free_kb = unsafe { esp_idf_svc::sys::esp_get_free_heap_size() } / 1024;
log::info!(
"mmap cache @ {label:<11} {hits} hit / {misses} miss, {read_kb} KB read, {cached_kb} KB resident, {free_kb} KB heap free"
);
}
/// Announce, time, and summarize an op. The `→ label …` line prints BEFORE the op
/// runs, so if an op hangs on the real 570 MB-pack repo we can see which one it
/// entered — a bare `summarize` prints only after all N iters, hiding the culprit.
fn bench<F: FnMut(usize) -> Result<()>>(label: &str, op: F) -> Result<()> {
log::info!("→ {label} …");
summarize(label, time_each(op)?);
Ok(())
}
/// A minimal index entry pointing at an already-written blob — for `index.add`,
/// which (unlike `add_frombuffer`) needs no repo owner, so it works on a bare
/// in-memory index. Only `id`, `path` and `mode` feed the tree write.
fn blob_entry(path: &[u8], oid: Oid) -> IndexEntry {
IndexEntry {
ctime: IndexTime::new(0, 0),
mtime: IndexTime::new(0, 0),
dev: 0,
ino: 0,
mode: 0o100644,
uid: 0,
gid: 0,
file_size: 0,
id: oid,
flags: 0,
flags_extended: 0,
path: path.to_vec(),
}
}
/// Run `op(i)` for `i in 0..N`, returning each call's wall time in microseconds.
fn time_each<F: FnMut(usize) -> Result<()>>(mut op: F) -> Result<Vec<u64>> {
let mut times = Vec::with_capacity(N);