diff --git a/crates/ely-lok/src/view.rs b/crates/ely-lok/src/view.rs index 6da81c6..26073e4 100644 --- a/crates/ely-lok/src/view.rs +++ b/crates/ely-lok/src/view.rs @@ -471,15 +471,11 @@ impl LokView { log::warn!("lok: a tile came back the wrong size"); return; }; - let entry = TileEntry { - image: Arc::new(RenderImage::new([Frame::new(image)])), - stale: false, - }; - log::debug!("lok: tile {key:?} shown"); - if let Some(old) = self.tiles.insert(key, entry) { + let image = Arc::new(RenderImage::new([Frame::new(image)])); + self.clock.painted(tile.generation, Arc::as_ptr(&image) as usize); + if let Some(old) = self.tiles.insert(key, TileEntry { image, stale: false }) { self.retired.push(old.image); } - self.clock.painted(tile.generation); cx.notify(); } Ok(_) => cx.notify(), diff --git a/crates/ely-lok/src/view/clock.rs b/crates/ely-lok/src/view/clock.rs index 9da6bf7..2345ba9 100644 --- a/crates/ely-lok/src/view/clock.rs +++ b/crates/ely-lok/src/view/clock.rs @@ -7,6 +7,8 @@ type Edit = (Instant, Option, Option); #[derive(Default)] pub(super) struct EditClock { edit: Option, + /// The tile that shows the edit, until it is drawn. + awaited: Option, /// The last generation bump: its revision and generation. bumped: (u64, u64), } @@ -42,16 +44,30 @@ impl EditClock { } } - /// A tile of `generation` came; logs the edit it shows. - pub(super) fn painted(&mut self, generation: u64) { - if let Some((at, _, Some(shown))) = self.edit + /// A tile of `generation` came as `tile`; it awaits drawing. + pub(super) fn painted(&mut self, generation: u64, tile: usize) { + if let Some((_, _, Some(shown))) = self.edit && generation >= shown { - log::debug!("lok: edit to tile {} ms", at.elapsed().as_millis()); - self.edit = None; + self.awaited = Some(tile); } } + /// `tile` reached the window; the edit it shows is timed. + pub(super) fn drawn(&mut self, tile: usize) { + if self.awaited == Some(tile) + && let Some((at, ..)) = self.edit.take() + { + log::debug!("lok: edit to tile {} ms", at.elapsed().as_millis()); + self.awaited = None; + } + } + + /// Whether a drawn `tile` would end the timing. + pub(super) fn awaits(&self, tile: usize) -> bool { + self.awaited == Some(tile) + } + #[cfg(test)] fn running(&self) -> bool { self.edit.is_some() @@ -68,9 +84,12 @@ mod tests { clock.sent(); clock.bumped(7, 3); clock.landed(Some(7)); - clock.painted(2); + clock.painted(2, 20); + clock.drawn(20); assert!(clock.running(), "an older picture leaves it running"); - clock.painted(3); + clock.painted(3, 30); + assert!(clock.running(), "arriving is not yet drawn"); + clock.drawn(30); assert!(!clock.running(), "the edit's own picture ends it"); } @@ -80,10 +99,12 @@ mod tests { clock.sent(); clock.bumped(6, 3); clock.landed(Some(7)); - clock.painted(3); + clock.painted(3, 30); + clock.drawn(30); assert!(clock.running(), "a batch before the edit shows the old text"); clock.bumped(7, 4); - clock.painted(4); + clock.painted(4, 40); + clock.drawn(40); assert!(!clock.running()); } @@ -94,4 +115,16 @@ mod tests { clock.landed(None); assert!(!clock.running()); } + + #[test] + fn a_tile_that_never_draws_keeps_the_edit_open() { + let mut clock = EditClock::default(); + clock.sent(); + clock.bumped(5, 2); + clock.landed(Some(5)); + clock.painted(2, 50); + assert!(clock.awaits(50)); + clock.drawn(51); + assert!(clock.running(), "another tile's drawing does not count"); + } } diff --git a/crates/ely-lok/src/view/render.rs b/crates/ely-lok/src/view/render.rs index 81a1792..2f5d130 100644 --- a/crates/ely-lok/src/view/render.rs +++ b/crates/ely-lok/src/view/render.rs @@ -110,7 +110,13 @@ impl Render for LokView { ) }); match painted { - Ok(()) => drawn = true, + Ok(()) => { + drawn = true; + let tile = Arc::as_ptr(image) as usize; + if this.read(app).clock.awaits(tile) { + this.update(app, |view, _| view.clock.drawn(tile)); + } + } Err(error) => log::error!("lok: tile paint failed: {error}"), } } diff --git a/tests/perf/__pycache__/bench.cpython-314.pyc b/tests/perf/__pycache__/bench.cpython-314.pyc index 089db20..e11d7c7 100644 Binary files a/tests/perf/__pycache__/bench.cpython-314.pyc and b/tests/perf/__pycache__/bench.cpython-314.pyc differ diff --git a/tests/perf/bench.py b/tests/perf/bench.py index e025684..fb67bab 100644 --- a/tests/perf/bench.py +++ b/tests/perf/bench.py @@ -29,7 +29,7 @@ def sh(*args, **kw): def tools(folder): - for tool in ["ax-values", "ax-press", "click"]: + for tool in ["ax-values", "ax-press", "click", "chord"]: sh("swiftc", "-O", "-o", os.path.join(folder, tool), os.path.join(ROOT, "tests", "scripts", tool + ".swift")) @@ -98,9 +98,6 @@ class App: def memory_mb(self): return self.family()[1] / 1024 - def files(self): - return sum(self.handles().values()) - def handles(self): """Open handles of the app and its children, as type and name.""" ours, _ = self.family() @@ -207,6 +204,9 @@ def perf02(work, runs): lines = app.lines() finally: app.stop() + failed = [line for line in lines if re.search(PAINT_FAILED, line)] + if failed: + raise RuntimeError(f"ely-doc: a tile failed to draw while typing: {failed[0]}") ticks = [int(m.group(1)) for line in lines if (m := re.search(tick, line))] if len(ticks) != runs: raise RuntimeError(f"ely-doc: {runs} keys gave {len(ticks)} timings") @@ -269,8 +269,8 @@ def perf08(work, cycles=40): """New and close a document; memory, handles and live documents.""" app = App("ely-doc", os.path.join(work, "home-cycles")) - def open_docs(): - return documents_open(app.lines()) + def open_docs(since=0): + return documents_open(app.lines()[since:]) try: app.wait("opened Untitled") @@ -280,19 +280,24 @@ def perf08(work, cycles=40): baseline = (app.memory_mb(), sum(before.values()), open_docs()) seen, extra = [], None for n in range(cycles): - keys('keystroke "n" using command down') + cursor = len(app.lines()) + sh(os.path.join(work, "chord"), str(app.process.pid), "45") for _ in range(40): if "title=Use template" in app.ax(): break time.sleep(0.25) sh(os.path.join(work, "ax-press"), str(app.process.pid), "Use template", "AXButton") app.wait(f"opened Untitled {n + 2} ", timeout=30) + # This cycle's own report, not an earlier one. + if open_docs(cursor) != baseline[2] + 1: + raise RuntimeError(f"ely-doc: cycle {n + 1} opened, yet {open_docs(cursor)} documents") + cursor = len(app.lines()) time.sleep(1) # A keystroke can miss a window still taking focus. for _ in range(3): app.front() raise_main(app) - keys('keystroke "w" using command down') + sh(os.path.join(work, "chord"), str(app.process.pid), "13") try: app.wait(f"office: closed Untitled {n + 2}$", timeout=5) break @@ -304,17 +309,20 @@ def perf08(work, cycles=40): else: said = [line for line in app.lines() if re.search("clos|dialog|opened|focus", line)] raise RuntimeError(f"ely-doc: Untitled {n + 2} never closed: {said[-8:]}") - # The kernel lets go in the background. + # The kernel lets go later; a fresh report must come. for _ in range(100): - if open_docs() == baseline[2]: - break + try: + if open_docs(cursor) == baseline[2]: + break + except RuntimeError: + pass time.sleep(0.05) else: - raise RuntimeError(f"ely-doc: {open_docs()} documents after closing, not {baseline[2]}") + raise RuntimeError(f"ely-doc: cycle {n + 1} closed, yet no report of {baseline[2]} documents") time.sleep(0.5) now = app.handles() extra = handles_kept(before, now, extra, n + 1) - seen.append((app.memory_mb(), sum(now.values()), open_docs())) + seen.append((app.memory_mb(), sum(now.values()), open_docs(cursor))) finally: app.stop() return baseline, seen diff --git a/tests/perf/test_bench.py b/tests/perf/test_bench.py index 452bcf0..f7a12db 100644 --- a/tests/perf/test_bench.py +++ b/tests/perf/test_bench.py @@ -35,6 +35,12 @@ class Verdicts(unittest.TestCase): with self.assertRaisesRegex(RuntimeError, "no document count"): bench.documents_open(["office: closed Untitled 2"]) + def test_a_cycle_needs_its_own_count(self): + log = ["lok-worker: 1 documents open", "ely-doc: opened Untitled 2 as tab 1", "office: closed Untitled 2"] + cursor = 1 + with self.assertRaisesRegex(RuntimeError, "no document count"): + bench.documents_open(log[cursor:]) + if __name__ == "__main__": unittest.main() diff --git a/tests/scripts/chord.swift b/tests/scripts/chord.swift new file mode 100644 index 0000000..c2d6c73 --- /dev/null +++ b/tests/scripts/chord.swift @@ -0,0 +1,14 @@ +// Posts Command plus a key to one process, flag included. +import CoreGraphics +import Foundation + +// chord +let pid = pid_t(CommandLine.arguments[1])! +let code = CGKeyCode(CommandLine.arguments[2])! +let source = CGEventSource(stateID: .privateState) +for down in [true, false] { + let event = CGEvent(keyboardEventSource: source, virtualKey: code, keyDown: down)! + event.flags = .maskCommand + event.postToPid(pid) + usleep(30_000) +}