From f79d13453a8f8544235ffaa53fb5b119c6923348 Mon Sep 17 00:00:00 2001 From: Julien Calixte Date: Mon, 13 Jul 2026 21:04:18 +0200 Subject: [PATCH] fix(sync): survive push heap exhaustion and instrument the push path MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Run 4 (2026-07-13): remote.push() consumed ~6 MB of PSRAM over 66 s and the UI thread aborted on Frame::new_white's per-draw vec![0xFF; 26928]. Run 5 confirmed the UI now survives, but the push still exhausts both pools (a ~7 KB inflateInit fails inside the pack build) and the heap telemetry never fired — hence the telemetry rework. - display/editor: Editor::draw_into() renders into a caller-owned Frame; main.rs keeps two boot-time frames (shown/back) and mem::swaps on success, so steady-state repaints never allocate. - git_sync: odb cache capped at 1 MB via raw libgit2-sys opts (git2 0.20 doesn't wrap the total cap); log_push_heap at pre-push, post-push and push-failure with largest-PSRAM-block and per-pool min-evers; pack_progress logging is now time-gated (2 s) — the count gate (+256 objects) never fired because AddingObjects reports total=0 and a small push inserts only dozens of objects. - editor: empty/whitespace snippets file parses as 0 snippets instead of a JSON error at boot. - build.rs: refuse a git-feature build with unset TW_* publish vars — a bare `cargo build --features git` baked empty creds and produced a firmware whose :sync could never work. --- display/src/lib.rs | 19 +++++++++ editor/src/lib.rs | 28 +++++++++++-- firmware/Cargo.toml | 7 +++- firmware/build.rs | 24 ++++++++++++ firmware/src/git_sync.rs | 85 ++++++++++++++++++++++++++++++++++++++++ firmware/src/main.rs | 42 +++++++++++--------- 6 files changed, 182 insertions(+), 23 deletions(-) diff --git a/display/src/lib.rs b/display/src/lib.rs index ad5ae0f..a185384 100644 --- a/display/src/lib.rs +++ b/display/src/lib.rs @@ -35,6 +35,25 @@ impl Frame { Self { buf: vec![0xFF; FB_BYTES] } } + /// A zero-capacity placeholder, for the buffer-swap pattern: + /// `Editor::draw_into` takes the caller's buffer out through one of these + /// and puts it back when done. Not drawable until [`clear_white`] + /// (or a `draw_into`) gives it its buffer. + /// + /// [`clear_white`]: Frame::clear_white + pub fn empty() -> Self { + Self { buf: Vec::new() } + } + + /// Reset to all-white paper, reusing the existing allocation when the + /// buffer is already full-size. This is what lets firmware repaint without + /// allocating: a background `:sync` push can take the heap to the floor, + /// and a failed framebuffer alloc aborts the whole app (2026-07-13). + pub fn clear_white(&mut self) { + self.buf.clear(); + self.buf.resize(FB_BYTES, 0xFF); + } + pub fn new_black() -> Self { Self { buf: vec![0x00; FB_BYTES] } } diff --git a/editor/src/lib.rs b/editor/src/lib.rs index b12c835..0199e2c 100644 --- a/editor/src/lib.rs +++ b/editor/src/lib.rs @@ -352,9 +352,13 @@ impl Snippets { /// display name, each value `{ prefix, body, description? }` where `body` is a /// string or an array of lines. Labels in `${n:label}` stops are stripped to /// `$n`. Entries come back sorted by name (a `BTreeMap` parse — deterministic, - /// and the empty-`$` palette order; a query re-ranks by fuzzy score anyway). A - /// malformed file is an `Err` the host logs before booting with no snippets. + /// and the empty-`$` palette order; a query re-ranks by fuzzy score anyway). An + /// empty (or whitespace-only) file means "no snippets", same as a missing one — + /// only a malformed file is an `Err` the host logs before booting with none. pub fn parse(src: &str) -> Result { + if src.trim().is_empty() { + return Ok(Self::default()); + } let raw: std::collections::BTreeMap = serde_json::from_str(src)?; let snippets = raw .into_iter() @@ -3166,11 +3170,25 @@ impl Editor { /// text (e.g. a boot message). View never draws a caret. In the main loop /// Normal always passes `true`, so its block caret is unaffected. pub fn draw(&mut self, cursor_on: bool) -> Frame { + let mut f = Frame::empty(); + self.draw_into(&mut f, cursor_on); + f + } + + /// [`draw`](Self::draw) into a caller-owned frame, reusing its allocation. + /// Firmware keeps two boot-time frames and round-trips them through here so + /// a repaint never allocates: the editor must stay drawable even when a + /// background `:sync` push has taken the heap to the floor — a failed + /// framebuffer alloc aborts the whole app (the 2026-07-13 OOM). + pub fn draw_into(&mut self, out: &mut Frame, cursor_on: bool) { let lay = self.layout(); let (crow, ccol) = self.caret_rc(&lay); self.adjust_scroll(crow, lay.len()); - let mut f = Frame::new_white(); + // Take the caller's buffer (no copy, no alloc), render into it as an + // owned frame — the body predates this signature — and hand it back. + let mut f = std::mem::replace(out, Frame::empty()); + f.clear_white(); let text_style = MonoTextStyle::new(&FONT_10X20, BinaryColor::On); let gutter = self.gutter_cols(); let cols = WRITE_COLS - gutter; // text columns after the gutter @@ -3335,7 +3353,7 @@ impl Editor { if self.prefs.theme == "dark" { f.invert(); } - f + *out = f; } /// Draw the side panel: a full-height rule, word count at the top, and the @@ -5910,6 +5928,8 @@ mod tests { #[test] fn parse_snippets_empty_and_malformed() { assert!(Snippets::parse("{}").unwrap().0.is_empty()); + assert!(Snippets::parse("").unwrap().0.is_empty()); // empty file = no snippets + assert!(Snippets::parse(" \n\t").unwrap().0.is_empty()); // whitespace-only too assert!(Snippets::parse("{ not json").is_err()); // host logs, boots with none } diff --git a/firmware/Cargo.toml b/firmware/Cargo.toml index 9daf44d..2240628 100644 --- a/firmware/Cargo.toml +++ b/firmware/Cargo.toml @@ -110,7 +110,7 @@ esp-idf-svc = { git = "https://github.com/esp-rs/esp-idf-svc.git" } # do; `build-light` doesn't, so the component is an empty no-op). git2/libgit2-sys # run in system mode (LIBGIT2_NO_VENDOR=1) purely for the Rust bindings, with # default features off to avoid dragging in openssl-sys/libssh2-sys. -git = ["dep:git2"] +git = ["dep:git2", "dep:libgit2-sys"] [dependencies] anyhow = "1" @@ -124,6 +124,11 @@ keymap = { path = "../keymap" } editor = { path = "../editor" } display = { path = "../display" } git2 = { version = "0.20", default-features = false, optional = true } +# Already in the tree under git2 (same system-mode build); named directly for +# the raw `git_libgit2_opts` calls git2 doesn't wrap — the odb-cache cap +# (GIT_OPT_SET_CACHE_MAX_SIZE) and cache telemetry (GIT_OPT_GET_CACHED_MEMORY) +# that git_sync sets against the run-4 push OOM (2026-07-13). +libgit2-sys = { version = "0.18", default-features = false, optional = true } esp-idf-svc = { version = "0.52.1", features = ["critical-section", "embassy-time-driver", "embassy-sync"] } # Remove `generic-queue-8` if you plan to use `embassy-time` WITH `embassy-executor` embassy-time = { version = "0.5", features = ["generic-queue-8"] } diff --git a/firmware/build.rs b/firmware/build.rs index 44adf72..2514d06 100644 --- a/firmware/build.rs +++ b/firmware/build.rs @@ -47,6 +47,30 @@ fn main() { println!("cargo:rerun-if-env-changed={var}"); } + // A git-feature build with an empty publish config can only ever fail at + // runtime (git_sync's publish_cycle guard), so refuse it here instead. + // env!() bakes the values at compile time and only `just` dotenv-loads + // firmware/.env — a plain `cargo build --features git` in a bare shell + // silently produced a firmware whose `:sync` could never work (bit the + // 2026-07-13 flash). TW_WIFI_PASS may be legitimately empty (open network) + // and TW_AUTHOR_* have runtime defaults, so only the four required vars + // are checked. + if std::env::var("CARGO_FEATURE_GIT").is_ok() { + let missing: Vec<&str> = ["TW_WIFI_SSID", "TW_REMOTE_URL", "TW_GH_USER", "TW_PAT"] + .into_iter() + .filter(|v| std::env::var(v).map_or(true, |val| val.is_empty())) + .collect(); + if !missing.is_empty() { + panic!( + "git-feature build without publish config: {} unset/empty. \ + Build through `just build` (dotenv-loads firmware/.env), or \ + source firmware/.env into this shell. For a no-git editor \ + build use `just build-light` (drops --features git).", + missing.join(", ") + ); + } + } + // Pointing rerun-if-changed at a file that never exists forces this // script to rerun on every build, keeping BUILD_TIME fresh. println!("cargo:rerun-if-changed=.force-build-stamp"); diff --git a/firmware/src/git_sync.rs b/firmware/src/git_sync.rs index a841619..49a45a8 100644 --- a/firmware/src/git_sync.rs +++ b/firmware/src/git_sync.rs @@ -81,6 +81,15 @@ const SNTP_TIMEOUT: Duration = Duration::from_secs(20); /// now also runs here, but it's shallow next to libgit2's path-buffer nesting. pub const GIT_STACK: usize = 96 * 1024; +/// Cap on libgit2's odb object cache (default max: 256 MB — unbounded on this +/// device). Run 4 (2026-07-13): the real-repo push ground through pack-building +/// for 66 s and PSRAM hit the floor — the UI aborted on a 27 KB framebuffer +/// alloc. Every tree/commit the push's walks read lands in this cache, and +/// nothing bounded it. 1 MB still holds the whole tree set the push's two +/// full-tree walks share (mark-uninteresting over origin's tip, then the insert +/// over ours — near-identical trees), so the second walk stays off the SD card. +const ODB_CACHE_MAX_BYTES: isize = 1024 * 1024; + /// A request to publish. The UI task has already saved every dirty buffer to /// the card before sending this; `paths` is `Storage::take_dirty`'s snapshot — /// the repo-relative paths saved or `:delete`d since the last confirmed @@ -130,6 +139,15 @@ pub fn run_git_service( if let Err(e) = git2::opts::set_mwindow_mapped_limit(4 * 1024 * 1024) { log::error!("set_mwindow_mapped_limit failed ({e}); first pack access may OOM"); } + // Odb cache cap (see ODB_CACHE_MAX_BYTES). git2 0.20 wraps only the + // per-object-type limit, not the total, so this one is a raw call. + let rc = libgit2_sys::git_libgit2_opts( + libgit2_sys::GIT_OPT_SET_CACHE_MAX_SIZE as i32, + ODB_CACHE_MAX_BYTES, + ); + if rc < 0 { + log::error!("set cache_max_size failed (rc {rc}); a push may exhaust the heap"); + } } // Lazily initialised on the first request, then reused across publishes. @@ -507,9 +525,34 @@ fn try_push(repo: &Repository, refspec: &str) -> Result<(), PushFailure> { Ok(()) }); } + // Progress + heap tracing through the otherwise-silent stretch between the + // TLS verify and the first byte sent (66 s in runs 4 and 5, OOM both times). + { + // Time-gated, NOT count-gated: during AddingObjects libgit2 reports + // `total` = 0 and `current` = objects inserted so far, and a two-commit + // push only inserts a few dozen objects — run 5's `current >= last+256` + // gate swallowed every callback and the grind stayed silent. libgit2 + // already rate-limits to ~2/s (MIN_PROGRESS_UPDATE_INTERVAL); gate to + // ~1 line per 2 s on top of that. + let mut last: Option = None; + cbs.pack_progress(move |stage, current, total| { + if last.is_none_or(|t| t.elapsed() >= Duration::from_secs(2)) { + last = Some(Instant::now()); + log_push_heap(&format!("pack {stage:?} {current}/{total}")); + } + }); + let mut next_bytes: usize = 0; + cbs.push_transfer_progress(move |current, total, bytes| { + if bytes >= next_bytes || (total > 0 && current == total) { + next_bytes = bytes + 64 * 1024; + log_push_heap(&format!("send {current}/{total} objects, {bytes} B")); + } + }); + } let mut opts = PushOptions::new(); opts.remote_callbacks(cbs); + log_push_heap("pre-push"); // A non-fast-forward can also surface here, not just via the callback: // libgit2 compares against origin's advertised tips during negotiation and // errors out of push() with ErrorCode::NotFastForward before sending @@ -518,6 +561,11 @@ fn try_push(repo: &Repository, refspec: &str) -> Result<(), PushFailure> { // (bit the 2026-07-13 run 3: the real-repo rejection surfaced as "push // transport" and skipped the reconcile built for it). remote.push(&[refspec], Some(&mut opts)).map_err(|e| { + // Heap post-mortem: run 5 died on a ~7 KB inflateInit inside the pack + // build ("failed to init zlib stream on unpack") — the min-ever lines + // here say which pool zeroed and whether it was exhaustion or + // fragmentation, even when no progress callback got a chance to fire. + log_push_heap("push failed"); if e.code() == git2::ErrorCode::NotFastForward { PushFailure::Rejected(format!("{refspec}: {}", e.message())) } else { @@ -528,6 +576,7 @@ fn try_push(repo: &Repository, refspec: &str) -> Result<(), PushFailure> { if let Some(msg) = rejection.borrow().clone() { return Err(PushFailure::Rejected(msg)); } + log_push_heap("post-push"); log::info!("push accepted by remote"); Ok(()) } @@ -661,3 +710,39 @@ fn internal_free_heap() -> u32 { fn min_free_heap() -> u32 { unsafe { sys::esp_get_minimum_free_heap_size() } } + +/// One-line heap + odb-cache snapshot for the push path. Runs 4 and 5 +/// (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; +/// run 5: a ~7 KB inflateInit failed inside the pack build). These lines +/// exist to name the consumer: `largest PSRAM` distinguishes exhaustion from +/// fragmentation, and the per-pool min-evers survive to the failure log even +/// when the spike itself fell between two callbacks. +fn log_push_heap(stage: &str) { + let (mut cached, mut allowed): (isize, isize) = (0, 0); + // SAFETY: GET_CACHED_MEMORY only writes the two out-params. + unsafe { + libgit2_sys::git_libgit2_opts( + libgit2_sys::GIT_OPT_GET_CACHED_MEMORY as i32, + &mut cached as *mut isize, + &mut allowed as *mut isize, + ); + } + let (largest_psram, min_psram, min_internal) = unsafe { + ( + sys::heap_caps_get_largest_free_block(sys::MALLOC_CAP_SPIRAM), + sys::heap_caps_get_minimum_free_size(sys::MALLOC_CAP_SPIRAM), + sys::heap_caps_get_minimum_free_size(sys::MALLOC_CAP_INTERNAL), + ) + }; + log::info!( + "push heap [{stage}]: free {} ({} internal), largest PSRAM {}, min-ever PSRAM {} / internal {}, odb cache {}/{} KB", + free_heap(), + internal_free_heap(), + largest_psram, + min_psram, + min_internal, + cached / 1024, + allowed / 1024 + ); +} diff --git a/firmware/src/main.rs b/firmware/src/main.rs index c1d7f4b..79d46cc 100644 --- a/firmware/src/main.rs +++ b/firmware/src/main.rs @@ -186,6 +186,13 @@ fn main() -> anyhow::Result<()> { // (every FULL_REFRESH_EVERY updates) clears any residue. let mut shown = ed.draw(true); epd.display_frame_partial_window(shown.bytes(), 0, epd::HEIGHT)?; + // The only two framebuffers the loop ever uses, both allocated here at + // boot: every repaint below renders into `back` (`draw_into` reuses its + // allocation) and swaps it with `shown` on success. A repaint must never + // allocate — a background `:sync` push can take the heap to the floor, and + // a failed `Vec` alloc aborts the whole app (the 2026-07-13 OOM: 66 s into + // the push, one HalfPageUp repaint died on a 27 KB framebuffer). + let mut back = Frame::new_white(); // Boot-time measurement (the ≤ 5 s v0.1 / ≤ 3 s v1.0 target). Two clocks, and // they disagree by ~1.4 s here, so report both. `esp_log_timestamp()` counts @@ -292,26 +299,26 @@ fn main() -> anyhow::Result<()> { UpToDate => "up to date".to_string(), Failed(reason) => reason, }); - let f = ed.draw(true); - if let Err(e) = epd.display_frame_partial_window(f.bytes(), 0, epd::HEIGHT) { + ed.draw_into(&mut back, true); + if let Err(e) = epd.display_frame_partial_window(back.bytes(), 0, epd::HEIGHT) { log::warn!("sync-notice repaint FAILED ({e}); full refresh next"); force_full = true; continue; } - shown = f; + std::mem::swap(&mut shown, &mut back); cursor_shown = true; continue; } // A connect/disconnect while idle must still repaint the panel flag — // no keystroke will arrive to trigger it otherwise. if kbd_changed { - let f = ed.draw(true); - if let Err(e) = epd.display_frame_partial_window(f.bytes(), 0, epd::HEIGHT) { + ed.draw_into(&mut back, true); + if let Err(e) = epd.display_frame_partial_window(back.bytes(), 0, epd::HEIGHT) { log::warn!("kbd-flag repaint FAILED ({e}); full refresh next"); force_full = true; continue; } - shown = f; + std::mem::swap(&mut shown, &mut back); cursor_shown = true; log::info!("keyboard {}", if kbd { "connected" } else { "disconnected" }); continue; @@ -348,12 +355,12 @@ fn main() -> anyhow::Result<()> { && last_activity.elapsed().as_millis() >= CURSOR_DEBOUNCE_MS { ed.refresh_stats(); - let f = ed.draw(true); - if let Err(e) = epd.display_frame_partial_window(f.bytes(), 0, epd::HEIGHT) { + ed.draw_into(&mut back, true); + if let Err(e) = epd.display_frame_partial_window(back.bytes(), 0, epd::HEIGHT) { log::warn!("caret repaint FAILED ({e}); full refresh next"); force_full = true; } else { - shown = f; + std::mem::swap(&mut shown, &mut back); cursor_shown = true; log::info!("caret shown"); } @@ -375,14 +382,13 @@ fn main() -> anyhow::Result<()> { // and View render their caret regardless of this flag. let insert_cursor_on = ed.mode() != Mode::Insert; let prev_scroll = ed.scroll_top(); - let frame = ed.draw(insert_cursor_on); + ed.draw_into(&mut back, insert_cursor_on); let scrolled = ed.scroll_top() != prev_scroll; // Only the rows that changed since the last shown frame need updating. - let Some((y0, y1)) = changed_rows(shown.bytes(), frame.bytes()) else { - shown = frame; + let Some((y0, y1)) = changed_rows(shown.bytes(), back.bytes()) else { cursor_shown = ed.mode() != Mode::Insert; - continue; // no visible change + continue; // no visible change (the frames are identical — no swap needed) }; // Snap the band to whole text lines so a partial-window boundary never // lands mid-glyph — otherwise the boundary gate crops tall characters. @@ -398,18 +404,18 @@ fn main() -> anyhow::Result<()> { let periodic = updates % FULL_REFRESH_EVERY == 0; let additive = ed.mode() == Mode::Insert && !scrolled - && only_adds_ink(shown.bytes(), frame.bytes(), y0, y1); + && only_adds_ink(shown.bytes(), back.bytes(), y0, y1); let t0 = Instant::now(); // `force_full` promotes to a full refresh after a failed paint: it // rewrites both RAM banks, recovering from a partial that may have died // mid-transfer and desynced them. let (result, refresh) = if periodic || force_full { - (epd.display_frame(frame.bytes()), "FULL") + (epd.display_frame(back.bytes()), "FULL") } else if additive { - (epd.display_frame_partial_window(frame.bytes(), y0, y1 - y0 + 1), "windowed") + (epd.display_frame_partial_window(back.bytes(), y0, y1 - y0 + 1), "windowed") } else { - (epd.display_frame_partial_window(frame.bytes(), 0, epd::HEIGHT), "full-area") + (epd.display_frame_partial_window(back.bytes(), 0, epd::HEIGHT), "full-area") }; let ms = t0.elapsed().as_millis(); if let Err(e) = result { @@ -428,7 +434,7 @@ fn main() -> anyhow::Result<()> { "{refresh} refresh #{updates} [{:?}]: {ms} ms (rows {y0}..={y1}, {keys} key(s))", ed.mode() ); - shown = frame; + std::mem::swap(&mut shown, &mut back); cursor_shown = ed.mode() != Mode::Insert; } }