diff --git a/cmd/pad/main.go b/cmd/pad/main.go index 7417649..27dd1e7 100644 --- a/cmd/pad/main.go +++ b/cmd/pad/main.go @@ -6,17 +6,19 @@ import ( "os" "path/filepath" "sync" + "time" "gioui.org/app" + "gioui.org/font/gofont" + "gioui.org/io/key" "gioui.org/op" "gioui.org/text" "gioui.org/unit" - "gioui.org/font/gofont" - "gioui.org/io/key" "gioui.org/widget" "pad/internal/editor" "pad/internal/io/pool/real" + "pad/internal/perf" "pad/internal/ui" ) @@ -45,7 +47,7 @@ func run(w *app.Window) error { // Initialize the real filesystem rooted at the system root "/" // so that the browser can navigate the entire system. fs := real.NewRealFileSystem("/") - + // Get the absolute path of the startup directory startAbs, err := filepath.Abs(*rootDir) if err != nil { @@ -56,6 +58,32 @@ func run(w *app.Window) error { logic := editor.NewLogic(fs, startAbs, OpenFile) renderer := ui.New(ui.Theme{FontSize: 14}, shaper) + // In-app frame profiler (default off). Enabled by the presence of a marker + // file so the shipping APK needs no rebuild to toggle profiling. When on, + // it records logic-frame cadence plus scroll/visible-range context to a CSV + // and logs rolling percentiles; it also enables the scroll-jump debug poller. + const perfDir = "/storage/emulated/0/PadPerf" + var prof *perf.Profiler + var perfOn bool + var presentN int + var presentStart time.Time + if _, err := os.Stat(filepath.Join(perfDir, "enable")); err == nil { + prof = perf.New(true, perfDir, "logic_frames.csv") + editor.PerfRecord = func(rec editor.ProbeRecord) { + prof.Record(perf.Ctx{ + Page: rec.Page, + ScrollDP: rec.ScrollDP, + MaxScrollDP: rec.MaxScrollDP, + TotalLines: rec.TotalLines, + VisStart: rec.VisStart, + VisEnd: rec.VisEnd, + }) + } + logic.EnableDebugCmdPoll(perfDir) + perfOn = true + log.Printf("PERF: enabled (dir=%s)", perfDir) + } + // The search bar's widget.Editor is owned by the MAIN goroutine: Gio // mutates it during draw, and the logic goroutine must never touch it // (architecture.md §1). Its text is forwarded to the logic goroutine via @@ -76,6 +104,9 @@ func run(w *app.Window) error { for { switch e := w.Event().(type) { case app.DestroyEvent: + if prof != nil { + prof.Stop() + } logic.Shutdown() return e.Err case app.ConfigEvent: @@ -85,6 +116,18 @@ func run(w *app.Window) error { PixelHeight: e.Config.Size.Y, } case app.FrameEvent: + if perfOn { + presentN++ + if presentStart.IsZero() { + presentStart = time.Now() + } + if time.Since(presentStart) >= 2*time.Second { + dt := time.Since(presentStart).Seconds() + log.Printf("PERF-PRESENT frames=%d fps=%.1f", presentN, float64(presentN)/dt) + presentN = 0 + presentStart = time.Time{} + } + } gtx := app.NewContext(&ops, e) newScale := gtx.Metric.PxPerDp // Read ONLY the frame-receiver-stored snapshot; the main goroutine diff --git a/doc/README.md b/doc/README.md index 3d9d06e..cc1cb71 100644 --- a/doc/README.md +++ b/doc/README.md @@ -9,6 +9,18 @@ line-by-line code — so they stay true as the implementation evolves. | [`architecture.md`](./architecture.md) | How it works: single-owner concurrency model, channel topology, Frame handoff contract, ownership rules, editor/browser/render internals. | | [`development_plan.md`](./development_plan.md) | The active plan: completed phases, remaining work, and the on-device observation loop. | +## Package inventory + +| Package | Role | +|---------|------| +| `internal/editor` | Chunked buffer, line index, virtualized viewport, IME ops, autosave, logic goroutine, state, Frame | +| `internal/browser` | Directory browsing, search, sort, pagination, browser state machine | +| `internal/ui` | Element tree, frame layout, renderer (op-based), IME wiring, gestures | +| `internal/perf` | Default-off performance profiler (per-logic-frame cadence + scroll state → CSV) | +| `internal/io/pool` | Worker pool (8 workers, 2 priority lanes) + file/dir tasks | +| `internal/test/e2e` | Harness driving the real `Logic` + `Inspect` | +| `cmd/pad` | `main.go` (entry), `impl_android.go` (base path) | + ## Documentation policy 1. **Docs describe invariants and contracts, not code lines.** If a document diff --git a/doc/architecture.md b/doc/architecture.md index 63d42ef..44cd46a 100644 --- a/doc/architecture.md +++ b/doc/architecture.md @@ -304,3 +304,32 @@ Only the visible byte range is shaped and drawn each frame: (`development_plan.md` Phase 4). - Dead task types (`ReadChunk`, `SaveState`, `SaveUndo`, …) and unused element types are candidates for removal in the same round. + +## 11. Performance profiler (default-off, `internal/perf`) + +Pad ships a built-in profiler that is **off by default** and costs nothing when +off. It is the in-app frame-timing tool (see `development_plan.md` §9: `gfxinfo` +cannot measure this app because it renders into a `SurfaceView`). + +- **Enable** by creating the marker file + `/storage/emulated/0/PadPerf/enable` before launch. `main.go` then creates a + `perf.Profiler` that writes `logic_frames.csv` (one row per logic frame: seq, + ms-since-start, frame delta, page, scroll Dp, max-scroll Dp, total lines, + visible byte range) and logs a rolling ~1 s `PERF` summary. `DestroyEvent` + stops it (final flush + `PERF stopped` summary with p50/p90/p99/max). +- **Hook**: `internal/editor.PerfRecord` is a package-level func, set by + `main.go` only when enabled. `Logic.emitFrame` calls it on the owner + goroutine with a `ProbeRecord` **before** sending the frame. When disabled it + is `nil` and the per-frame cost is a single nil check. +- **Debug scroll jumps** (for testing, off by default): with the profiler on, + `main.go` also polls `/storage/emulated/0/PadPerf/cmd` (a one-shot file + consumed on read). `top`, `bottom`, `frac <0..1>`, and `dp ` jump the + editor's `ScrollOffset` (clamped to `[0, MaxScroll]`) and emit a frame. This + lets a test drive large-offset scrolls deterministically without pixel taps. +- The profiler is owned by the goroutine that creates it and is single-goroutine + (no locks). It does **not** `Sync()` the CSV per flush (only per row batch) to + avoid periodic fsync hitches in the logic path. +- **Measured** (emulator, 10 MB file, 2026-08): logic-frame cadence is flat + across scroll offsets 0.02→1.0 (no large-offset degradation); the visible byte + range stays ≤ ~4.3 KB (0.04% of the file); PSS plateaus ~250 MB (bounded + high-water mark, no leak). See `development_plan.md` Phase 6. diff --git a/doc/development_plan.md b/doc/development_plan.md index efd28cd..abdf173 100644 --- a/doc/development_plan.md +++ b/doc/development_plan.md @@ -1,7 +1,7 @@ # Development Plan: reach a lean, usable Android text editor -Status: v4, 2026-08-16 (Phases 0–3 complete; doc reorganization done). Written -against the **live** repo `/home/gmp/pad`. v1 (the widget-rebuild plan) is +Status: v5, 2026-08-16 (Phases 0–3 + doc reorg + Phase 6 scroll-perf/clamping +verification complete). Written against the **live** repo `/home/gmp/pad`. v1 (the widget-rebuild plan) is superseded — see §12 for why. Doc reorganization (2026-08-16): the over-detailed docs (`*_implementation_plan.md`, `touch.md`, `element_model.md`, `layout_rendering.md`, `virtual_scroll_render_optimization.md`, @@ -11,7 +11,10 @@ adds the doc policy + build/install recipe. See `doc/README.md`. Phases 0–3 done: single-owner no-lock architecture, Android IME wiring, on-device IME validation (passing), viewport-on-open fix, chunked-buffer drift fix, the whole-file shaper memory-leak fix, a measured 50 MB size limit, and the IME -rapid-commit desync fix (snippet/selection dedup). Remaining: real-device +rapid-commit desync fix (snippet/selection dedup). Phase 6 (2026-08-16) added a +default-off in-app performance profiler and verified: scroll does not degrade at +large offsets (10 MB file), scroll clamping is exact across 2→130,955-line +files, and memory plateaus ~250 MB (no leak). Remaining: real-device swipe/autocorrect sign-off (the emulator's AOSP/Gboard keyboard is a proxy). ## 1. Decision summary (updated) @@ -239,7 +242,43 @@ but are not needed for a usable v1. - ✓ Build/install recipe (2026-08-16: in `doc/README.md`; machine-local script `/tmp/build_pad.sh`). - ☐ In-repo device test checklist (the adb tap/swipe/IME sequences used in - Phases 2–3 are in this plan's phase notes but not a standalone checklist). + Phases 2–3 and Phase 6 are in this plan's phase notes but not a standalone + checklist). + +### Phase 6 — scroll performance & clamping verification — DONE (2026-08-16) + +Goal: (a) confirm scroll does not degrade at large offsets in a large file, +(b) confirm scroll clamping is correct across file sizes. Enabled the default-off +in-app profiler (architecture.md §11) and drove deterministic `frac` scroll +jumps + real swipes on the emulator. + +**Scroll performance at large offsets (10 MB file, 130,955 lines):** swept +`frac` 0.02→1.0 with swipes. Logic-frame cadence is **flat across all offsets** +(p50 ~38–44 ms, p90 ~51–75 ms, no trend up at 0.9/0.98/1.0) — **no large-offset +degradation**. The visible byte range stays **≤ 4,274 B (0.04% of the file)** at +every offset, confirming the shaper never lays out the whole file. `ScreenRecord` +and `gfxinfo` were ruled out as metrics (downsampled / View-layer-only, since Pad +renders into a `SurfaceView`); the in-app profiler is the instrument. + +**Scroll clamping (6 sizes, 2→130,955 lines):** for each, `top` and `bottom` +commands set the offset to exactly 0 and to exactly `maxScroll`; **no frame ever +exceeded `maxScroll` or went negative**. Sub-viewport files (`tiny_1line` 2 lines, +`small_10` 11 lines) correctly have `maxScroll = 0` and cannot scroll; larger +files' `maxScroll` scales correctly with content. No blank viewport at any size +(content verified on-screen). + +**Memory (bonus):** PSS **plateaus ~250 MB** for the 10 MB file under sustained +scroll (bounded high-water mark from the shaper glyph cache + Go heap; grows +~13 MB over the first ~30 scrolls then flat) — **no leak**, well under the 2.5 GB +OOM line. The profiler's own overhead is negligible (same plateau with it off). + +**Test-harness gotcha:** the 390×844 Dp window is **letterboxed** on the +1080×2400 screen (~28 px left / ~133 px top offset), so on-screen tap +coordinates are offset from the naive 1:1 Dp→px map. The editor back-arrow hits +at ~`(86, 264)` px, not the glyph's apparent 1:1 position. Browser file rows +(newest-first) start ~y=520 px, ~134 px apart. Verify every open via the exact +logcat line `Logic: OpenFileChan /storage/emulated/0/Notes/`, not a loose +`OpenFileChan` match. ## 6. File-size decision (re-framed) diff --git a/doc/spec.md b/doc/spec.md index 7b2f824..d13d327 100644 --- a/doc/spec.md +++ b/doc/spec.md @@ -119,15 +119,19 @@ Full details, channel topology, and ownership rules: [`architecture.md`](./archi owner-dispatches-a-task pattern. 6. **Logic work stays < 16 ms.** Anything that can block or scan more than the viewport goes to the worker pool. +7. **Scroll offset is always clamped to `[0, maxScroll]`,** where + `maxScroll = contentHeight − viewportHeight` floored at 0. A file whose + content fits the viewport has `maxScroll = 0` and cannot scroll. Verified + on-device across 2→130,955 lines (`development_plan.md` Phase 6). ## 6. Performance expectations (validated on-device) | Operation | Target | Measured (10 MB file, Android 35 emulator) | |---|---|---| | Open file | instant feel | ~120 ms (stat + read + line index) | -| Scroll | 60 fps | flat ~240 MB RSS, no growth, no OOM | +| Scroll | 60 fps | logic-frame cadence flat across offsets 0.02→1.0 — **no large-offset degradation**; present fps is emulator-limited (~14–27 on the software-rendered emulator, not a Pad quality metric) | | Type | responsive | single IME path; rapid commits land cleanly | -| Memory | bounded | ~150 MB PSS / ~230 MB RSS at 10 MB file, flat | +| Memory | bounded | PSS plateaus ~250 MB at a 10 MB file (bounded high-water mark, no growth under sustained scroll; no OOM) | ## 7. Deferred / not implemented (explicit non-goals for v1) diff --git a/internal/editor/logic.go b/internal/editor/logic.go index 4beeb18..3db00ce 100644 --- a/internal/editor/logic.go +++ b/internal/editor/logic.go @@ -2,6 +2,10 @@ package editor import ( "log" + "os" + "path/filepath" + "strconv" + "strings" "sync" "time" @@ -51,23 +55,25 @@ type ResultEvent struct { // the channels below. The only exception is Inspect, a test-only request // channel whose fn still executes on the owner. type Logic struct { - state *State - browserManager *browser.BrowserManager - configChan chan ConfigUpdate - frameChan chan Frame // frames carry the view-state snapshot - inputChan chan []ui.InputEvent - layoutChan chan ui.GlyphLayout - resultChan chan ResultEvent - searchQueryChan chan string - openFileChan chan string - retryChan chan string // auto-save retries - autosaveChan chan struct{} // auto-save debounce ticks (timer -> owner) - inspectChan chan *inspectReq - workerPool *pool.WorkerPool - mockFS pool.FileSystem - done chan struct{} - exitWg sync.WaitGroup - saveTimer *time.Timer // auto-save debounce timer; non-nil while pending + state *State + browserManager *browser.BrowserManager + configChan chan ConfigUpdate + frameChan chan Frame // frames carry the view-state snapshot + inputChan chan []ui.InputEvent + layoutChan chan ui.GlyphLayout + resultChan chan ResultEvent + searchQueryChan chan string + openFileChan chan string + retryChan chan string // auto-save retries + autosaveChan chan struct{} // auto-save debounce ticks (timer -> owner) + inspectChan chan *inspectReq + workerPool *pool.WorkerPool + mockFS pool.FileSystem + done chan struct{} + exitWg sync.WaitGroup + saveTimer *time.Timer // auto-save debounce timer; non-nil while pending + lastEmit time.Time // time of the last frame emission (profiler cadence) + debugCmdC chan string // one-shot debug commands from the cmd-file poller; nil = disabled } // NewLogic creates a new Logic instance, accepting an optional mockFS. @@ -127,8 +133,6 @@ func (l *Logic) FrameChan() <-chan Frame { return l.frameChan } - - // InputChan returns the input channel for the logic goroutine. func (l *Logic) InputChan() chan<- []ui.InputEvent { return l.inputChan @@ -169,7 +173,7 @@ func (l *Logic) Run() { case update := <-l.configChan: log.Printf("Logic: ConfigEvent") update.apply(l.state) - l.frameChan <- l.frameOf(l.state.layout(l.browserManager)) + l.emitFrame() case layout := <-l.layoutChan: // Store the full GlyphLayout on editor state. // Derive LastLineY from it for scroll clamping. @@ -181,14 +185,14 @@ func (l *Logic) Run() { } if derivedLastLineY != l.state.LastLineY { l.state.LastLineY = derivedLastLineY - l.frameChan <- l.frameOf(l.state.layout(l.browserManager)) + l.emitFrame() } case events := <-l.inputChan: log.Printf("Logic: InputEvents") for _, evt := range events { evt.Handler(evt.Data) } - l.frameChan <- l.frameOf(l.state.layout(l.browserManager)) + l.emitFrame() case query := <-l.searchQueryChan: log.Printf("Logic: SearchQuery") if query != l.state.Browser.Query { @@ -197,7 +201,7 @@ func (l *Logic) Run() { browser.HandleSearch(&l.state.Browser, query) } } - l.frameChan <- l.frameOf(l.state.layout(l.browserManager)) + l.emitFrame() case path := <-l.openFileChan: log.Printf("Logic: OpenFileChan %s", path) // Create chunked buffer for virtual scrolling @@ -241,11 +245,138 @@ func (l *Logic) Run() { case res := <-l.workerPool.ResultChan(): l.handleWorkerResult(res) case <-l.resultChan: - l.frameChan <- l.frameOf(l.state.layout(l.browserManager)) + l.emitFrame() + case cmd := <-l.debugCmdC: + l.applyDebugCmd(cmd) } } } +// emitFrame computes the current frame, records a profiler probe (if enabled), +// and hands it to the main goroutine. Centralizing emission here ensures the +// in-app profiler (PerfRecord) sees every frame exactly once, on the owner +// goroutine. Must be called on the logic goroutine. +func (l *Logic) emitFrame() { + elems := l.state.layout(l.browserManager) + now := time.Now() + if PerfRecord != nil { + var delta time.Duration + if !l.lastEmit.IsZero() { + delta = now.Sub(l.lastEmit) + } + l.lastEmit = now + s := l.state + rec := ProbeRecord{T: now, DeltaMs: float64(delta.Nanoseconds()) / 1e6, Page: pageName(s.page)} + if s.page == EditorPage { + rec.ScrollDP = float32(s.ScrollOffset) + rec.MaxScrollDP = float32(s.MaxScroll) + rec.VisStart = s.VisibleStart + rec.VisEnd = s.VisibleEnd + if cb := s.Editor.ChunkedBuffer; cb != nil { + if li := cb.LineIndex; li != nil { + rec.TotalLines = li.LineCount() + } + } + } else { + rec.ScrollDP = float32(s.Browser.ScrollOffset) + } + PerfRecord(rec) + } + l.frameChan <- l.frameOf(elems) +} + +// EnableDebugCmdPoll starts a background poller (debug-only) that watches +// /cmd for a one-shot scroll command and forwards it to the owner for +// application. Used to jump the editor to specific scroll offsets for +// performance/clamping validation. The poller does the (blocking) file read +// off the owner and sends the command via debugCmdC; the owner applies it. +func (l *Logic) EnableDebugCmdPoll(dir string) { + l.debugCmdC = make(chan string, 1) + l.exitWg.Add(1) + go func() { + defer l.exitWg.Done() + t := time.NewTicker(120 * time.Millisecond) + defer t.Stop() + cmdPath := filepath.Join(dir, "cmd") + for { + select { + case <-l.done: + return + case <-t.C: + b, err := os.ReadFile(cmdPath) + if err != nil { + continue + } + cmd := strings.TrimSpace(string(b)) + if cmd == "" { + continue + } + // Consume the command so it is applied exactly once. + _ = os.WriteFile(cmdPath, nil, 0o644) + select { + case l.debugCmdC <- cmd: + case <-l.done: + return + } + } + } + }() +} + +// applyDebugCmd applies a one-shot debug scroll command from the cmd-file +// poller. Commands: "top", "bottom", "frac <0..1>", "dp ". Must be +// called on the logic goroutine. +func (l *Logic) applyDebugCmd(cmd string) { + s := l.state + if s.page != EditorPage { + log.Printf("DebugCmd: %q ignored (not on editor page)", cmd) + return + } + fields := strings.Fields(cmd) + if len(fields) == 0 { + return + } + var target ui.Dp + switch fields[0] { + case "top": + target = 0 + case "bottom": + target = s.MaxScroll + case "frac": + if len(fields) < 2 { + return + } + f, err := strconv.ParseFloat(fields[1], 64) + if err != nil || f < 0 || f > 1 { + log.Printf("DebugCmd: bad frac %q", fields[1]) + return + } + target = ui.Dp(float64(f) * float64(s.MaxScroll)) + case "dp": + if len(fields) < 2 { + return + } + n, err := strconv.Atoi(fields[1]) + if err != nil { + log.Printf("DebugCmd: bad dp %q", fields[1]) + return + } + target = ui.Dp(n) + default: + log.Printf("DebugCmd: unknown %q", cmd) + return + } + if target < 0 { + target = 0 + } + if target > s.MaxScroll { + target = s.MaxScroll + } + s.ScrollOffset = target + log.Printf("DebugCmd: %q -> scroll=%d maxScroll=%d", cmd, int(s.ScrollOffset), int(s.MaxScroll)) + l.emitFrame() +} + // fullContentBytes reconstructs the full file content from the chunked // buffer (or the deprecated full Buffer). Returns ok=false on error. // Must be called on the logic goroutine. @@ -330,7 +461,7 @@ func (l *Logic) handleWorkerResult(res pool.Result) { l.state.Editor.TooLarge = true l.state.Editor.TooLargeSize = stat.Size log.Printf("Logic: %s is %d bytes, exceeds the %d-byte edit limit", stat.Path, stat.Size, MaxEditableFileSize) - l.frameChan <- l.frameOf(l.state.layout(l.browserManager)) + l.emitFrame() return } if l.state.Editor.ChunkedBuffer != nil { @@ -375,7 +506,7 @@ func (l *Logic) handleWorkerResult(res pool.Result) { }) } } - l.frameChan <- l.frameOf(l.state.layout(l.browserManager)) + l.emitFrame() } // applyBuildIndexResult applies a completed BuildIndexTask result to browser state. @@ -405,7 +536,7 @@ func (l *Logic) PruneMaps() { return } - // Simply clear the maps for now. A true LRU would require + // Simply clear the maps for now. A true LRU would require // tracking access times. l.state.Editor.fileVersion = make(map[string]int) l.state.Editor.lastWriteVersion = make(map[string]int) diff --git a/internal/editor/perf_probe.go b/internal/editor/perf_probe.go new file mode 100644 index 0000000..1d7dead --- /dev/null +++ b/internal/editor/perf_probe.go @@ -0,0 +1,30 @@ +package editor + +import "time" + +// ProbeRecord captures per-frame context for the in-app profiler (see +// internal/perf). It is filled on the logic goroutine and handed to the +// PerfRecord hook once per frame emission. Debug-only: PerfRecord is nil +// unless the app enables profiling (cmd/pad), so the per-frame cost is a +// single nil check. +type ProbeRecord struct { + T time.Time + DeltaMs float64 // ms since the previous frame emission + Page string // "editor" | "browser" + ScrollDP float32 // editor scroll offset (Dp); browser scroll when on browser + MaxScrollDP float32 // editor max scroll (Dp) + TotalLines int + VisStart int // visible byte range start + VisEnd int // visible byte range end (exclusive) +} + +// PerfRecord is an optional per-frame probe hook, set by the app when in-app +// profiling is enabled. It is called on the logic goroutine, once per frame. +var PerfRecord func(ProbeRecord) + +func pageName(p Page) string { + if p == EditorPage { + return "editor" + } + return "browser" +} diff --git a/internal/editor/state.go b/internal/editor/state.go index 31f2fc0..29e90a0 100644 --- a/internal/editor/state.go +++ b/internal/editor/state.go @@ -133,15 +133,20 @@ func (e *EditorState) IncrementRetryAttempts(filename string) int { // State holds all application state owned by the logic goroutine. type State struct { - PixelWidth int // raw pixel width from Gio ConfigEvent - PixelHeight int // raw pixel height from Gio ConfigEvent - scale float32 - page Page // current page (Browser or Editor) - WordWrap bool - ScrollOffset ui.Dp // vertical scroll position in Dp - ByteOffset int // Byte offset of the first visible line - LastLineY ui.Dp // last line baseline offset from text origin, from renderer - MaxScroll ui.Dp // max scroll offset (content height - viewport height) + PixelWidth int // raw pixel width from Gio ConfigEvent + PixelHeight int // raw pixel height from Gio ConfigEvent + scale float32 + page Page // current page (Browser or Editor) + WordWrap bool + ScrollOffset ui.Dp // vertical scroll position in Dp + ByteOffset int // Byte offset of the first visible line + LastLineY ui.Dp // last line baseline offset from text origin, from renderer + MaxScroll ui.Dp // max scroll offset (content height - viewport height) + // VisibleStart/VisibleEnd are the byte range the last editor layout shaped + // for the viewport. Set by EditorLayout each frame; read by the profiler + // probe to confirm the shaped range stays viewport-bounded (not the file). + VisibleStart int + VisibleEnd int FocusedElementID string // ID of the currently focused element Elems []ui.Element lastEvictionTime time.Time // Throttles chunk eviction @@ -929,13 +934,17 @@ func EditorLayout(screenWidth, screenHeight ui.Dp, wordWrap bool) []ui.Element { // Content() will load chunks immediately needed by the viewport. cb.Prefetch(scrollChunk, 1) } else { - fmt.Printf("LAYOUT: fallback, no cb\n") // Fallback: no chunked buffer, use full buffer (small files) visibleContent = TheState.Editor.Buffer visibleCursorPos = TheState.Editor.CursorPosition visibleScrollOffset = TheState.ScrollOffset } + // Record the shaped visible range for the profiler probe (confirms the + // virtual-scroll window stays viewport-bounded, not the whole file). + TheState.VisibleStart = start + TheState.VisibleEnd = end + // Record the visible window for IME: the snippet is this window, so an // EditEvent.Range (relative to the window) is offset by IMEWindowStartByte // to address the buffer. start is 0 for small (string) files, so the diff --git a/internal/perf/perf.go b/internal/perf/perf.go new file mode 100644 index 0000000..875074b --- /dev/null +++ b/internal/perf/perf.go @@ -0,0 +1,210 @@ +// Package perf provides a lightweight, dependency-free in-app frame profiler. +// +// It is owned by a single goroutine (the logic goroutine) and records +// per-frame timing plus a small context (scroll offset, max scroll, total +// lines, visible byte range) so scroll performance and clamping can be +// analysed offline. It is an instrumentation facility: the app enables it at +// runtime (see cmd/pad) and the per-frame cost is a slice append plus +// occasional log/flush. With the record hook nil (the default), it is unused. +package perf + +import ( + "fmt" + "log" + "math" + "os" + "path/filepath" + "sort" + "time" +) + +// Ctx is the per-frame context recorded alongside timing. +type Ctx struct { + Page string // "editor" | "browser" + ScrollDP float32 // scroll offset (Dp) + MaxScrollDP float32 // max scroll (Dp) + TotalLines int + VisStart int // visible byte range start + VisEnd int // visible byte range end (exclusive) +} + +// Row is one recorded frame, the unit of CSV output. +type Row struct { + Seq int + Tms float64 // ms since profiling started + DeltaMs float64 // ms since previous frame emission + Page string + ScrollDP float32 + MaxScrollDP float32 + TotalLines int + VisStart int + VisEnd int +} + +// Profiler records logic-frame cadence plus context. All methods must be +// called from the owning goroutine only (no locks). +type Profiler struct { + enabled bool + outPath string + start time.Time + last time.Time + lastLog time.Time + lastFlush time.Time + buf []Row + seq int + file *os.File +} + +// New creates a profiler. If enabled and outDir is non-empty, it creates the +// output directory and file (named outDir/name). A failed file disables CSV +// output but keeps the logcat summaries. +func New(enabled bool, outDir, name string) *Profiler { + p := &Profiler{enabled: enabled} + if !enabled { + return p + } + p.start = time.Now() + p.lastLog = time.Now() + p.lastFlush = time.Now() + if outDir != "" { + if err := os.MkdirAll(outDir, 0o755); err == nil { + p.outPath = filepath.Join(outDir, name) + if f, err := os.Create(p.outPath); err == nil { + p.file = f + } else { + log.Printf("PERF: cannot create %s: %v", p.outPath, err) + } + } else { + log.Printf("PERF: cannot create dir %s: %v", outDir, err) + } + } + return p +} + +// Record is called once per frame emission, on the owner goroutine. It is the +// only hot-path cost: a slice append, with a logcat summary ~1/s and a disk +// flush ~2/s (the flush is a single small write, never per-frame). +func (p *Profiler) Record(ctx Ctx) { + if !p.enabled { + return + } + now := time.Now() + if p.start.IsZero() { + p.start = now + p.lastLog = now + p.lastFlush = now + } + var delta time.Duration + if !p.last.IsZero() { + delta = now.Sub(p.last) + } + p.last = now + p.seq++ + p.buf = append(p.buf, Row{ + Seq: p.seq, + Tms: float64(now.Sub(p.start).Nanoseconds()) / 1e6, + DeltaMs: float64(delta.Nanoseconds()) / 1e6, + Page: ctx.Page, + ScrollDP: ctx.ScrollDP, + MaxScrollDP: ctx.MaxScrollDP, + TotalLines: ctx.TotalLines, + VisStart: ctx.VisStart, + VisEnd: ctx.VisEnd, + }) + + if now.Sub(p.lastLog) >= time.Second { + p.logSummary() + p.lastLog = now + } + if now.Sub(p.lastFlush) >= 2*time.Second { + p.flush() + p.lastFlush = now + } +} + +// logSummary prints a rolling percentile summary of the frames buffered since +// the last flush to logcat. +func (p *Profiler) logSummary() { + n := len(p.buf) + if n == 0 { + return + } + ds := make([]float64, n) + for i, r := range p.buf { + ds[i] = r.DeltaMs + } + p50, p90, p99, mx := percentiles(ds) + over16, over33 := 0, 0 + for _, d := range ds { + if d > 16.7 { + over16++ + } + if d > 33.4 { + over33++ + } + } + log.Printf("PERF frames=%d p50=%.1f p90=%.1f p99=%.1f max=%.1f ms over16.7=%.0f%% over33.4=%.0f%%", + n, p50, p90, p99, mx, pct(over16, n), pct(over33, n)) +} + +// flush appends the buffered rows to the CSV file and clears the buffer. +func (p *Profiler) flush() { + if len(p.buf) > 0 && p.file != nil { + for _, r := range p.buf { + fmt.Fprintf(p.file, "%d,%.3f,%.3f,%s,%.1f,%.1f,%d,%d,%d\n", + r.Seq, r.Tms, r.DeltaMs, r.Page, r.ScrollDP, r.MaxScrollDP, r.TotalLines, r.VisStart, r.VisEnd) + } + } + p.buf = p.buf[:0] +} + +// Stop flushes remaining rows and closes the file. Call once on shutdown. +func (p *Profiler) Stop() { + if !p.enabled { + return + } + p.flush() + if p.file != nil { + p.file.Close() + p.file = nil + } + log.Printf("PERF stopped: %d frames, out=%s", p.seq, p.outPath) +} + +// percentiles returns p50/p90/p99/max of ds in ms. +func percentiles(ds []float64) (p50, p90, p99, mx float64) { + if len(ds) == 0 { + return + } + s := make([]float64, len(ds)) + copy(s, ds) + sort.Float64s(s) + p50 = s[pctlIdx(len(s), 0.50)] + p90 = s[pctlIdx(len(s), 0.90)] + p99 = s[pctlIdx(len(s), 0.99)] + if p99 < p90 { + p99 = p90 + } + mx = s[len(s)-1] + return +} + +// pctlIdx returns the nearest-rank index for fraction f (in [0,1]) of n +// samples: the smallest i such that i/n >= f, clamped to [0, n-1]. +func pctlIdx(n int, f float64) int { + i := int(math.Ceil(float64(n)*f)) - 1 + if i < 0 { + i = 0 + } + if i >= n { + i = n - 1 + } + return i +} + +func pct(part, whole int) float64 { + if whole == 0 { + return 0 + } + return 100 * float64(part) / float64(whole) +} diff --git a/internal/perf/perf_test.go b/internal/perf/perf_test.go new file mode 100644 index 0000000..ff96b30 --- /dev/null +++ b/internal/perf/perf_test.go @@ -0,0 +1,74 @@ +package perf + +import ( + "os" + "path/filepath" + "strings" + "testing" + "time" +) + +func TestPercentiles(t *testing.T) { + ds := []float64{10, 20, 30, 40, 50, 60, 70, 80, 90, 100} + p50, p90, p99, mx := percentiles(ds) + if p50 != 50 { + t.Errorf("p50 = %v, want 50", p50) + } + if p90 != 90 { + t.Errorf("p90 = %v, want 90", p90) + } + if p99 != 100 { + t.Errorf("p99 = %v, want 100", p99) + } + if mx != 100 { + t.Errorf("max = %v, want 100", mx) + } + // Empty input is a no-op. + if _, _, _, m := percentiles(nil); m != 0 { + t.Errorf("empty max = %v, want 0", m) + } +} + +func TestDisabledIsNoOp(t *testing.T) { + p := New(false, t.TempDir(), "x.csv") + p.Record(Ctx{Page: "editor"}) + if p.enabled { + t.Fatalf("disabled profiler reported enabled") + } + if p.seq != 0 || len(p.buf) != 0 { + t.Errorf("disabled profiler recorded: seq=%d buf=%d", p.seq, len(p.buf)) + } +} + +func TestRecordFlushAndStop(t *testing.T) { + dir := t.TempDir() + p := New(true, dir, "logic_frames.csv") + if p == nil || p.file == nil { + t.Fatalf("expected an open output file, got %+v", p) + } + for i := 0; i < 5; i++ { + p.Record(Ctx{Page: "editor", ScrollDP: float32(i * 10), MaxScrollDP: 1000, TotalLines: 42, VisStart: i, VisEnd: i + 100}) + } + // Force a flush regardless of the 2s timer. + p.lastFlush = time.Time{} + p.Record(Ctx{Page: "editor", ScrollDP: 50}) + p.Stop() + + out := filepath.Join(dir, "logic_frames.csv") + b, err := os.ReadFile(out) + if err != nil { + t.Fatalf("read csv: %v", err) + } + lines := strings.Split(strings.TrimSpace(string(b)), "\n") + if len(lines) != 6 { + t.Fatalf("want 6 CSV rows, got %d:\n%s", len(lines), b) + } + // First row is seq 1, editor page. + if !strings.HasPrefix(lines[0], "1,") || !strings.Contains(lines[0], "editor") { + t.Errorf("unexpected first row: %s", lines[0]) + } + // Last row should have TotalLines 42 (from the 5th record) and the 6th (Stop flush). + if !strings.Contains(lines[4], "42") { + t.Errorf("row 5 missing TotalLines=42: %s", lines[4]) + } +}