fix: optimize performance by wrapping trace logs, adding captured drag event subscriptions, and adding regression tests for adjustment compositing.

This commit is contained in:
Your Name
2026-07-24 02:04:35 +03:00
parent f2cca7e6a1
commit fba10b753c
9 changed files with 364 additions and 50 deletions
+41 -4
View File
@@ -3550,6 +3550,7 @@ impl HcieIcedApp {
}
Message::CanvasCursorPos { x, y } => {
crate::canvas::perf::record_idle_pointer_message(false);
self.canvas_cursor_pos = Some((x, y));
}
@@ -4707,6 +4708,7 @@ impl HcieIcedApp {
self.layer_style_dragging = true;
}
Message::LayerStyleDialogDragMove(x, y) | Message::DockPointerMoved(x, y) => {
crate::canvas::perf::record_idle_pointer_message(true);
self.last_cursor_pos = Some((x, y));
let pointer = iced::Point::new(x, y);
if self.dock.drag.is_none() {
@@ -9677,13 +9679,19 @@ impl HcieIcedApp {
colors,
));
}
let _elapsed = view_start.elapsed();
let elapsed = view_start.elapsed();
if !self.tool_state.is_drawing {
crate::canvas::perf::record_idle_view(elapsed);
}
// Performance log measuring Elm view reconstruction time.
// useful to track widget layout allocation and view model reconstruction times.
// log::info!("[perf] view(): {:.1}ms", elapsed.as_secs_f64() * 1000.0);
stack.width(Length::Fill).height(Length::Fill).into()
} else {
let _elapsed = view_start.elapsed();
let elapsed = view_start.elapsed();
if !self.tool_state.is_drawing {
crate::canvas::perf::record_idle_view(elapsed);
}
// Performance log measuring Elm view reconstruction time.
// log::info!("[perf] view(): {:.1}ms", elapsed.as_secs_f64() * 1000.0);
content.into()
@@ -9933,7 +9941,9 @@ impl HcieIcedApp {
iced::mouse::Event::ButtonPressed(iced::mouse::Button::Left) => (status
== iced::event::Status::Ignored)
.then_some(Message::OverlayOutsideClick),
iced::mouse::Event::CursorMoved { position } => {
iced::mouse::Event::CursorMoved { position }
if status == iced::event::Status::Ignored =>
{
Some(Message::DockPointerMoved(position.x, position.y))
}
iced::mouse::Event::ButtonReleased(iced::mouse::Button::Left) => {
@@ -9982,6 +9992,27 @@ impl HcieIcedApp {
}
});
// Captured canvas events normally stay local to the retained overlay.
// During a real global drag, forward captured movement so dock/dialog
// interactions continue across the canvas without rebuilding the app
// for every idle canvas movement.
let captured_drag_pointer = if self.layer_style_dragging
|| self.dock.header_drag.is_some()
|| self.dock.drag.is_some()
|| self.dock.floating_drag.is_some()
{
iced::event::listen_with(|event, status, _id| match event {
iced::Event::Mouse(iced::mouse::Event::CursorMoved { position })
if status == iced::event::Status::Captured =>
{
Some(Message::DockPointerMoved(position.x, position.y))
}
_ => None,
})
} else {
iced::Subscription::none()
};
// The marching ants are rendered in the persistent GPU canvas shader.
// Use a real timer rather than an immediately-ready async loop: the old
// loop generated an unbounded stream of CompositeRefresh messages and
@@ -10010,7 +10041,13 @@ impl HcieIcedApp {
iced::Subscription::none()
};
iced::Subscription::batch(vec![keyboard, mouse, marching_ants, stroke_frames])
iced::Subscription::batch(vec![
keyboard,
mouse,
captured_drag_pointer,
marching_ants,
stroke_frames,
])
}
}
@@ -87,6 +87,8 @@ struct OverlayProgram {
_quick_mask: bool,
/// Active brush diameter in canvas pixels for the footprint cursor.
brush_size: f32,
/// Whether a raster stroke is active; used to keep idle latency metrics isolated.
is_drawing: bool,
/// Normalized bounds of the selected vector shape in canvas-space (x1, y1, x2, y2).
selected_vector_bounds: Option<(f32, f32, f32, f32)>,
/// Rotation angle (radians) of the selected vector shape.
@@ -108,6 +110,10 @@ struct OverlayProgram {
struct OverlayState {
/// Current cursor position in viewport-local coordinates.
cursor_pos: Option<Point>,
/// Monotonic timestamp of the latest cursor event for opt-in latency diagnostics.
cursor_event_at: Option<std::time::Instant>,
/// Sequence used to avoid measuring duplicate redraws of one cursor event.
cursor_event_sequence: u64,
/// Whether the mouse is over the overlay.
is_hovered: bool,
/// Current handle being hovered (for cursor changes).
@@ -2050,6 +2056,14 @@ impl canvas::Program<Message> for OverlayProgram {
},
);
geometries.push(crosshair_frame.into_geometry());
if !self.is_drawing {
if let Some(captured_at) = state.cursor_event_at {
crate::canvas::perf::record_idle_cursor_draw(
state.cursor_event_sequence,
captured_at,
);
}
}
}
}
@@ -2096,6 +2110,8 @@ impl canvas::Program<Message> for OverlayProgram {
canvas::Event::Mouse(mouse::Event::CursorMoved { position }) => {
let local_pos = Point::new(position.x - bounds.x, position.y - bounds.y);
state.cursor_pos = Some(local_pos);
state.cursor_event_at = Some(std::time::Instant::now());
state.cursor_event_sequence = state.cursor_event_sequence.wrapping_add(1);
state.is_hovered = bounds.contains(position);
// Update hovered handle
@@ -2305,6 +2321,7 @@ pub fn view<'a>(
polygon_points: doc.polygon_points.clone(),
_quick_mask: doc.quick_mask,
brush_size: tool_state.brush_size,
is_drawing: tool_state.is_drawing,
selected_vector_bounds: sel_vec_bounds,
selected_vector_angle: sel_vec_angle,
vector_edit_handle: doc.vector_edit_handle,
@@ -27,6 +27,92 @@ struct PerfState {
latest_render_input: Option<Instant>,
last_prepare: Option<Instant>,
finish_pending: bool,
idle_cursor_samples_ms: Vec<f64>,
idle_view_samples_ms: Vec<f64>,
idle_canvas_messages: u64,
idle_dock_messages: u64,
last_idle_cursor_sequence: Option<u64>,
}
/// Records one application view reconstruction during cursor diagnostics.
///
/// **Arguments:** `elapsed` is the time spent constructing the Elm element tree.
/// **Returns:** Nothing. **Side Effects / Dependencies:** Stores a bounded sample
/// only when `HCIE_CANVAS_PERF=1`; reporting is performed by cursor draw samples.
pub fn record_idle_view(elapsed: Duration) {
if !enabled() {
return;
}
with_state(|state| {
if state.idle_view_samples_ms.len() < 240 {
state
.idle_view_samples_ms
.push(elapsed.as_secs_f64() * 1000.0);
}
});
}
/// Counts an app-level message generated by idle pointer movement.
///
/// **Arguments:** `dock_message` is `true` for the global dock subscription and
/// `false` for canvas status coordinates. **Returns:** Nothing.
/// **Side Effects / Dependencies:** Updates diagnostic counters only when enabled.
pub fn record_idle_pointer_message(dock_message: bool) {
if !enabled() {
return;
}
with_state(|state| {
if dock_message {
state.idle_dock_messages = state.idle_dock_messages.saturating_add(1);
} else {
state.idle_canvas_messages = state.idle_canvas_messages.saturating_add(1);
}
});
}
/// Records native cursor-event to overlay-draw latency and periodically reports it.
///
/// **Arguments:** `sequence` identifies a unique retained-overlay event and
/// `captured_at` is its monotonic timestamp. **Returns:** Nothing.
/// **Side Effects / Dependencies:** Emits one summary per 120 unique cursor draws
/// when `HCIE_CANVAS_PERF=1`; duplicate draws of the same event are ignored.
pub fn record_idle_cursor_draw(sequence: u64, captured_at: Instant) {
if !enabled() {
return;
}
with_state(|state| {
if state.last_idle_cursor_sequence == Some(sequence) {
return;
}
state.last_idle_cursor_sequence = Some(sequence);
state
.idle_cursor_samples_ms
.push(captured_at.elapsed().as_secs_f64() * 1000.0);
if state.idle_cursor_samples_ms.len() < 120 {
return;
}
let mut cursor_samples = std::mem::take(&mut state.idle_cursor_samples_ms);
let mut view_samples = std::mem::take(&mut state.idle_view_samples_ms);
cursor_samples.sort_by(f64::total_cmp);
view_samples.sort_by(f64::total_cmp);
log::info!(
target: "hcie_canvas_perf",
"idle_cursor draws={} event_to_overlay_draw[p50={:.3}ms,p95={:.3}ms,max={:.3}ms] view_rebuild[n={},p50={:.3}ms,p95={:.3}ms,max={:.3}ms] messages[canvas={},dock={}]",
cursor_samples.len(),
percentile(&cursor_samples, 0.50),
percentile(&cursor_samples, 0.95),
cursor_samples.last().copied().unwrap_or(0.0),
view_samples.len(),
percentile(&view_samples, 0.50),
percentile(&view_samples, 0.95),
view_samples.last().copied().unwrap_or(0.0),
state.idle_canvas_messages,
state.idle_dock_messages,
);
state.idle_canvas_messages = 0;
state.idle_dock_messages = 0;
});
}
/// Returns whether diagnostics are enabled for this process.
@@ -963,6 +963,30 @@ pub struct CanvasShaderState {
pub space_left_pan: bool,
/// Immediate local pan offset maintained during active panning to eliminate 1-frame Elm update latency.
pub local_pan_offset: Option<Vector>,
/// Last canvas coordinate published to the status bar.
pub last_status_cursor: Option<(u32, u32)>,
/// Time of the last status-bar coordinate publication.
pub last_status_emit: Option<std::time::Instant>,
/// Last pane size sent to application state, stored as exact float bit patterns.
pub last_reported_pane_size: Option<(u32, u32)>,
}
/// Minimum interval between status-bar cursor messages during idle movement.
const CURSOR_STATUS_INTERVAL: std::time::Duration = std::time::Duration::from_millis(500);
/// Decides whether an idle cursor coordinate needs an Elm application message.
///
/// **Arguments:** `previous` and `current` are integer canvas coordinates;
/// `elapsed` is time since the previous publication, or `None` for the first.
/// **Returns:** `true` only for a changed coordinate whose interval is due.
/// **Side Effects / Dependencies:** None.
fn should_publish_cursor_status(
previous: Option<(u32, u32)>,
current: (u32, u32),
elapsed: Option<std::time::Duration>,
) -> bool {
previous != Some(current)
&& elapsed.map_or(true, |duration| duration >= CURSOR_STATUS_INTERVAL)
}
/// Canvas shader program — implements `iced::widget::shader::Program`.
@@ -1070,8 +1094,6 @@ impl shader::Program<Message> for CanvasShaderProgram {
state.cursor_pos = Some(local_pos);
state.is_hovered = bounds.contains(position);
let pane_size_msg = Message::CanvasSize((bounds.width, bounds.height));
let (canvas_x, canvas_y) = screen_to_canvas_local(
local_pos,
bounds.width,
@@ -1139,16 +1161,38 @@ impl shader::Program<Message> for CanvasShaderProgram {
// Cursor over canvas → status bar coords
if let (Some(cx), Some(cy)) = (canvas_x, canvas_y) {
return (
iced::event::Status::Captured,
Some(Message::CanvasCursorPos {
x: cx as u32,
y: cy as u32,
}),
);
let current = (cx as u32, cy as u32);
let now = std::time::Instant::now();
let elapsed = state
.last_status_emit
.map(|previous| now.duration_since(previous));
if should_publish_cursor_status(
state.last_status_cursor,
current,
elapsed,
) {
state.last_status_cursor = Some(current);
state.last_status_emit = Some(now);
return (
iced::event::Status::Captured,
Some(Message::CanvasCursorPos {
x: current.0,
y: current.1,
}),
);
}
return (iced::event::Status::Captured, None);
}
return (iced::event::Status::Captured, Some(pane_size_msg));
let pane_size = (bounds.width.to_bits(), bounds.height.to_bits());
if state.last_reported_pane_size != Some(pane_size) {
state.last_reported_pane_size = Some(pane_size);
return (
iced::event::Status::Captured,
Some(Message::CanvasSize((bounds.width, bounds.height))),
);
}
return (iced::event::Status::Captured, None);
}
mouse::Event::ButtonPressed(button) => {
@@ -1365,10 +1409,38 @@ impl shader::Program<Message> for CanvasShaderProgram {
#[cfg(test)]
mod shader_regression_tests {
use super::{should_publish_cursor_status, CURSOR_STATUS_INTERVAL};
/// Prevents restoration of the nine-sample per-fragment selection border detector.
#[test]
fn selection_overlay_uses_one_texture_sample() {
let shader = include_str!("canvas.wgsl");
assert_eq!(shader.matches("textureSample(selection_texture").count(), 1);
}
/// Confirms status-bar messages are bounded without suppressing the first update.
///
/// **Purpose:** Protects the retained overlay from accidental per-pointer Elm
/// rebuilds. **Logic & Workflow:** Exercises first, early, due, and unchanged
/// cursor publications. **Arguments & Returns:** None.
/// **Side Effects / Dependencies:** None.
#[test]
fn idle_cursor_status_updates_are_rate_limited() {
assert!(should_publish_cursor_status(None, (10, 20), None));
assert!(!should_publish_cursor_status(
Some((10, 20)),
(11, 20),
Some(CURSOR_STATUS_INTERVAL / 2),
));
assert!(should_publish_cursor_status(
Some((10, 20)),
(11, 20),
Some(CURSOR_STATUS_INTERVAL),
));
assert!(!should_publish_cursor_status(
Some((11, 20)),
(11, 20),
Some(CURSOR_STATUS_INTERVAL * 2),
));
}
}