From 8e29e8b90b6da5698b5f9f090712da8c002e93a5 Mon Sep 17 00:00:00 2001 From: Levi Neuwirth Date: Fri, 29 May 2026 09:26:38 -0400 Subject: [PATCH] =?UTF-8?q?9.3=20perf=20=E2=80=94=20collapse=20per-tick=20?= =?UTF-8?q?rope=20copy;=20add=20frame=20timing?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Investigating the cursor slowdown reported after the wash became visible. Confident daemon-side win: `scoped_decorations` (run every tick per semantic frontend, in the daemon's single-threaded loop that also serves the TUI) was materializing the whole buffer via `buffer_source_bytes` — an O(n) rope→Vec copy — TWICE per tick: once in the 9.2 CurrentLine branch and again in the diagnostics branch. For an LSP buffer (diagnostics present, the common case) that doubled the per-tick copy cost, and the daemon's tick latency gates TUI cursor responsiveness. Now the source + line-start table is materialized at most once per call via `get_or_insert_with` and shared between both branches (and skipped entirely when neither branch needs it). Consumer instrumentation to localize any remaining cost: - `PMACS_GPU_DEBUG_FRAME=1` logs per-`render()` sub-phase timings (background rects / minimap rects / glyph prepare+submit / total / peer count). winit defaults to ControlFlow::Wait, so renders are on-demand (one per coalesced redraw request), not a continuous loop — the timing isolates the cost of a single cursor-driven frame. - The `PMACS_GPU_DEBUG_PRESENCE` check is now one-shot via OnceLock instead of a per-message `std::env::var_os` (which locks the global env table); same for the new frame flag. No behavior change to the rendered output. `render()` gains the clippy too_many_lines allow (now 115 lines with the timing block), matching the precedent on the other linear GPU-setup functions. Gates green: - cargo fmt --all -- --check - cargo clippy --all-targets --workspace -- -D warnings - cargo clippy --all-targets --workspace --features crdt -- -D warnings - pmacs lib 1329 + pmacs-protocol 11; pmacs-gpu unit 15 - m4_acceptance 88, m11_5_semantic_acceptance (--features crdt) 2 Co-Authored-By: Claude Opus 4.8 (1M context) --- pmacs-gpu/src/main.rs | 38 ++++++++++++++++++++++++- src/semantic_render.rs | 64 ++++++++++++++++++++++-------------------- 2 files changed, 71 insertions(+), 31 deletions(-) diff --git a/pmacs-gpu/src/main.rs b/pmacs-gpu/src/main.rs index 610cbf8..47f55ef 100644 --- a/pmacs-gpu/src/main.rs +++ b/pmacs-gpu/src/main.rs @@ -777,7 +777,7 @@ impl State { // A `buf != current` line means the peer is on a buffer // this mirror isn't displaying (no wash expected); no // line at all means the message isn't reaching us. - if std::env::var_os("PMACS_GPU_DEBUG_PRESENCE").is_some() { + if debug_presence() { eprintln!( "pmacs-gpu presence: fid={frontend_id:?} buf={buffer_id:?} \ current={:?} cursor={cursor} sel={selection:?}", @@ -1020,6 +1020,7 @@ impl State { self.window.request_redraw(); } + #[allow(clippy::too_many_lines)] // linear per-frame GPU sequence + optional timing. fn render(&mut self) { let frame = match self.surface.get_current_texture() { wgpu::CurrentSurfaceTexture::Success(frame) @@ -1037,6 +1038,7 @@ impl State { let view = frame .texture .create_view(&wgpu::TextureViewDescriptor::default()); + let frame_start = debug_frame().then(std::time::Instant::now); let bg_vertices = self.decoration_background_vertex_bytes(); let bg_vertex_count = (bg_vertices.len() / QUAD_VERTEX_STRIDE as usize) as u32; let bg_buffer = (!bg_vertices.is_empty()).then(|| { @@ -1047,6 +1049,7 @@ impl State { usage: wgpu::BufferUsages::VERTEX, }) }); + let after_bg = debug_frame().then(std::time::Instant::now); let minimap_vertices = self.minimap_vertex_bytes(); let minimap_vertex_count = (minimap_vertices.len() / QUAD_VERTEX_STRIDE as usize) as u32; let minimap_buffer = (!minimap_vertices.is_empty()).then(|| { @@ -1057,6 +1060,7 @@ impl State { usage: wgpu::BufferUsages::VERTEX, }) }); + let after_minimap = debug_frame().then(std::time::Instant::now); let text_bounds_right = self.text_bounds_right(); self.text_renderer @@ -1126,6 +1130,21 @@ impl State { self.queue.submit(std::iter::once(encoder.finish())); frame.present(); self.atlas.trim(); + + if let (Some(start), Some(after_bg), Some(after_minimap)) = + (frame_start, after_bg, after_minimap) + { + let end = std::time::Instant::now(); + let us = |a: std::time::Instant, b: std::time::Instant| b.duration_since(a).as_micros(); + eprintln!( + "pmacs-gpu frame: bg={}us minimap={}us prepare+submit={}us total={}us peers={}", + us(start, after_bg), + us(after_bg, after_minimap), + us(after_minimap, end), + us(start, end), + self.peer_presences.len(), + ); + } } fn text_bounds_right(&self) -> i32 { @@ -1529,6 +1548,23 @@ fn rgb_to_minimap_color(r: u8, g: u8, b: u8) -> [f32; 4] { ] } +/// One-shot env flag: `PMACS_GPU_DEBUG_PRESENCE=1` logs each received +/// `PresenceUpdate`. Read once (the env lock is not free per call) and +/// cached for the process lifetime. +fn debug_presence() -> bool { + static FLAG: std::sync::OnceLock = std::sync::OnceLock::new(); + *FLAG.get_or_init(|| std::env::var_os("PMACS_GPU_DEBUG_PRESENCE").is_some()) +} + +/// One-shot env flag: `PMACS_GPU_DEBUG_FRAME=1` logs per-`render()` +/// sub-phase timings (background rects, minimap rects, glyph prepare, +/// total) so a perceived cursor-tracking slowdown can be localized to +/// a specific phase. +fn debug_frame() -> bool { + static FLAG: std::sync::OnceLock = std::sync::OnceLock::new(); + *FLAG.get_or_init(|| std::env::var_os("PMACS_GPU_DEBUG_FRAME").is_some()) +} + /// Byte range `[start, end)` of the source line containing `cursor`: /// `start` is just after the previous `\n` (or 0), `end` is just after /// the next `\n` (or text length). Mirrors the producer's diff --git a/src/semantic_render.rs b/src/semantic_render.rs index 26fa451..b1d7bc6 100644 --- a/src/semantic_render.rs +++ b/src/semantic_render.rs @@ -370,8 +370,18 @@ impl SemanticRenderState { /// contract boundary. fn scoped_decorations(&self, state: &EditorState, vp: &DeclaredViewport) -> Vec { let core = state.core.borrow(); + let registry = core.registry.clone(); + let reg = registry.borrow(); let mut out = Vec::new(); + // Byte<->line mapping is needed by both the CurrentLine + // derivation and the diagnostics projection, and + // `buffer_source_bytes` is an O(n) rope copy. This runs every + // tick in the daemon's hot loop, so materialize at most once + // per call and reuse — never twice (the pre-9.2 shape copied + // separately in each branch). + let mut line_info: Option<(Vec, Vec)> = None; + // Selection + CurrentLine — per-window (per-frontend) state. // Only this session's active window for the declared buffer // contributes either kind. @@ -394,12 +404,13 @@ impl SemanticRenderState { kind: DecorationKind::Selection, }); } - let registry = core.registry.clone(); - let reg = registry.borrow(); if let Ok(buf) = reg.get(vp.buffer_id) { - let source = buffer_source_bytes(buf); - let line_starts = line_start_offsets(&source); - let (lo, hi) = current_line_range(&line_starts, source.len() as u64, win.cursor); + let (source, line_starts) = line_info.get_or_insert_with(|| { + let s = buffer_source_bytes(buf); + let ls = line_start_offsets(&s); + (s, ls) + }); + let (lo, hi) = current_line_range(line_starts, source.len() as u64, win.cursor); if let Some(range) = clip_to_viewport(lo, hi, vp) { out.push(Decoration { range, @@ -427,31 +438,24 @@ impl SemanticRenderState { let guard = store.lock().expect("diag store mutex poisoned"); (guard.for_uri(&uri).to_vec(), guard.is_stale(&uri)) }; - if !is_stale && !diags.is_empty() { - let registry = core.registry.clone(); - let reg = registry.borrow(); - if let Ok(buf) = reg.get(vp.buffer_id) { - let source = buffer_source_bytes(buf); - let line_starts = line_start_offsets(&source); - for d in &diags { - let lo = line_col_to_byte( - &line_starts, - source.len() as u64, - d.start_line, - d.start_col, - ); - let hi = line_col_to_byte( - &line_starts, - source.len() as u64, - d.end_line, - d.end_col, - ); - if let Some(range) = clip_to_viewport(lo, hi, vp) { - out.push(Decoration { - range, - kind: severity_to_kind(d.severity), - }); - } + if !is_stale + && !diags.is_empty() + && let Ok(buf) = reg.get(vp.buffer_id) + { + let (source, line_starts) = line_info.get_or_insert_with(|| { + let s = buffer_source_bytes(buf); + let ls = line_start_offsets(&s); + (s, ls) + }); + let source_len = source.len() as u64; + for d in &diags { + let lo = line_col_to_byte(line_starts, source_len, d.start_line, d.start_col); + let hi = line_col_to_byte(line_starts, source_len, d.end_line, d.end_col); + if let Some(range) = clip_to_viewport(lo, hi, vp) { + out.push(Decoration { + range, + kind: severity_to_kind(d.severity), + }); } } }