Merge main into feat/stroke-latency-trace (keep both new stroke tests)

Testers report ~50 ms input-to-pixel while painting on Linux and macOS, and asked for a
per-stage breakdown. With PHOTOCRAFT_STROKE_TRACE=1 the app prints, per stroke, p50/p95 of
the frame interval, pointer moves per frame, the live stroke's render, the canvas refresh
(composite + upload), the UI build, eframe's CPU time (UI, tessellation, submission) and the
remaining vsync/swap-chain wait, with the GPU backend; =<file.csv> also appends every frame.
The last summary is in the control channel's perf.strokeTrace.

RTX 5090, Vulkan, 120 Hz: interval 8.33, cpu 2.2 (ui 0.9, stroke 0.8, canvas 0.4), wait 6.0 ms.

crates/ui-egui/src/canvas.rs

@@ -697,10 +697,12 @@ fn feed_live_stroke(app: &mut PhotocraftApp) {
         return;
     }
     l.fed = d.points.len();
+    let started = crate::gpu_canvas::now_ms();
     match l.stroke.push(&pts) {
         Ok(r) => l.damage.push(r),
         Err(_) => app.live_stroke = None,
     }
+    app.stroke_trace.stroke(crate::gpu_canvas::now_ms() - started);
 }
 
 /// The points the live retouching stroke has rendered.
@@ -5460,7 +5462,9 @@ fn commit_brush_stroke(app: &mut PhotocraftApp, d: &Drag) {
     {
         app.session.clear_live_stroke();
     }
+    let started = crate::gpu_canvas::now_ms();
     let result = app.run(stroke_command(app, d.tool), p);
+    app.stroke_trace.stroke(crate::gpu_canvas::now_ms() - started);
     app.session.clear_live_stroke();
     let Ok(r) = result else { return };
     let revision = app.session.documents().iter().find(|st| st.doc.id == doc).map(|st| st.revision);

crates/ui-egui/src/control.rs

@@ -1315,7 +1315,7 @@ pub fn inspect(app: &PhotocraftApp, ctx: &egui::Context) -> Value {
         "frame": app.frame,
         "session": photocraft_engine::inspect::session(&app.session),
         "document": app.session.active().map(photocraft_engine::inspect::document),
-        "perf": {"fps": app.fps, "timings": app.perf},
+        "perf": {"fps": app.fps, "timings": app.perf, "strokeTrace": app.stroke_trace.last},
         "brush": {"size": app.session.tools.brush.size, "hardness": app.session.tools.brush.hardness, "opacity": app.session.tools.brush.opacity},
         "distort": app.distort.describe(),
         "jobs": crate::jobs_ui::inspect(app),

crates/ui-egui/src/gpu_canvas.rs

@@ -898,6 +898,9 @@ pub struct Perf {
     pub spans: std::collections::BTreeMap<&'static str, f64>,
     #[serde(skip)]
     max_decay: f64,
+    /// Composite and upload time of this frame's canvas refreshes, in ms (the stroke trace).
+    #[serde(skip)]
+    pub(crate) frame_refresh_ms: f64,
 }
 
 /// What the app renders with and why (Help › System Info, Preferences › Performance, the `perf`
@@ -1012,6 +1015,7 @@ pub fn backend_name(b: wgpu::Backend) -> &'static str {
 
 impl Perf {
     pub fn record(&mut self, kind: &'static str, px: u64, composite_ms: f64, upload_ms: f64) {
+        self.frame_refresh_ms += composite_ms + upload_ms;
         self.last_refresh = kind;
         self.last_refresh_px = px;
         self.composite_ms = composite_ms;

crates/ui-egui/src/lib.rs

@@ -190,6 +190,7 @@ pub mod spring_tools;
 pub mod stack_dialog;
 pub mod state;
 pub mod stroke_constraint;
+pub mod stroke_trace;
 pub mod stroke_trail;
 pub mod stroke_ui;
 pub mod stylus;
@@ -730,6 +731,8 @@ pub struct PhotocraftApp {
     started: Option<gpu_status::StartedHook>,
     /// Frame and canvas-upload timings (exposed via `ui.inspect`).
     pub perf: gpu_canvas::Perf,
+    /// Per-frame stroke timings for latency reports (`PHOTOCRAFT_STROKE_TRACE`, see `stroke_trace`).
+    pub stroke_trace: stroke_trace::StrokeTrace,
     /// Preferences, autosave and snapping runtime state (see `prefs_ui`, `snap_ui`).
     pub(crate) prefs_rt: prefs_ui::Runtime,
     /// Close, Revert or Exit parked behind the unsaved-changes prompt (see `discard_ui`).
@@ -875,6 +878,7 @@ impl PhotocraftApp {
             gpu: None,
             started: None,
             perf: Default::default(),
+            stroke_trace: stroke_trace::StrokeTrace::from_env(),
             prefs_rt: Default::default(),
             discard: None,
             file_dialog: None,
@@ -1756,6 +1760,7 @@ impl eframe::App for PhotocraftApp {
     }
 
     fn raw_input_hook(&mut self, ctx: &egui::Context, raw_input: &mut egui::RawInput) {
+        let frame_start = gpu_canvas::now_ms();
         // An undecorated window gets its caption back when the toolkit changes its flags
         // (maximize, restore, …): take it off again before the frame is laid out (#2246).
         if let Some(window_frame) = self.services.window_frame.as_mut() {
@@ -1779,6 +1784,11 @@ impl eframe::App for PhotocraftApp {
         if self.custom_titlebar {
             titlebar::release_after_os_resize(ctx, raw_input);
         }
+        if self.stroke_trace.enabled() {
+            // The OS's moves and the control channel's (injected just above).
+            let moves = raw_input.events.iter().filter(|e| matches!(e, egui::Event::PointerMoved(_))).count();
+            self.stroke_trace.begin_frame(frame_start, moves);
+        }
     }
 
     fn ui(&mut self, ui: &mut egui::Ui, frame: &mut eframe::Frame) {
@@ -1792,6 +1802,8 @@ impl eframe::App for PhotocraftApp {
             return;
         }
         let t0 = gpu_canvas::now_ms();
+        self.perf.frame_refresh_ms = 0.0;
+        self.stroke_trace.cpu_prev(frame.info().cpu_usage);
         // A text field's right-click menu, before any field is drawn (text_field_menu.rs).
         text_field_menu::show(&ctx);
         // Each painting tool keeps its own brush (#218), so switch the active tool's brush in
@@ -1893,7 +1905,13 @@ impl eframe::App for PhotocraftApp {
             egui::Modal::new(egui::Id::new("screen-color-wait")).frame(egui::Frame::NONE).backdrop_color(egui::Color32::TRANSPARENT).show(&ctx, |_| {});
             ctx.set_cursor_icon(egui::CursorIcon::Wait);
         }
-        self.perf.frame(gpu_canvas::now_ms() - t0);
+        let ui_ms = gpu_canvas::now_ms() - t0;
+        self.perf.frame(ui_ms);
+        if self.stroke_trace.enabled() {
+            self.stroke_trace.canvas(self.perf.frame_refresh_ms);
+            let info = &self.perf.gpu_info;
+            self.stroke_trace.end_frame(ui_ms, self.live_stroke.is_some(), || format!("{} {}", info.backend, info.adapter).trim().to_string());
+        }
         // Synthetic input is injected one press/release step per frame: keep frames coming until
         // the queue is empty, then release control replies waiting on it.
         if !self.synthetic.is_empty() {

crates/ui-egui/src/stroke_timing_tests.rs

@@ -338,6 +338,48 @@ fn a_committed_stroke_refreshes_only_what_each_cache_had_not_shown() {
     assert_eq!(c.since(99), None, "not a key of this stroke");
 }
 
+#[test]
+fn the_stroke_trace_times_each_frame_of_a_stroke_and_ends_on_release() {
+    // The app's hooks around the canvas (`raw_input_hook` starts a frame, `ui` ends it); the
+    // canvas times the live stroke and the release's commit itself.
+    let mut app = PhotocraftApp::new(photocraft_engine::Session::new(), crate::Services::default());
+    app.run("file.new", json!({"width": 200, "height": 100, "background": "white"})).unwrap();
+    app.sync_views();
+    app.ui.tool = Tool::Brush;
+    app.stroke_trace.output = crate::stroke_trace::Output::Stderr;
+    let mut h = Harness::builder().with_size(vec2(900.0, 600.0)).build_ui_state(
+        |ui, app: &mut PhotocraftApp| {
+            let ctx = ui.ctx().clone();
+            if !ctx.fonts(|f| f.families().contains(&egui::FontFamily::Name("medium".into()))) {
+                return;
+            }
+            let t0 = crate::gpu_canvas::now_ms();
+            let moves = ctx.input(|i| i.raw.events.iter().filter(|e| matches!(e, egui::Event::PointerMoved(_))).count());
+            app.stroke_trace.begin_frame(t0, moves);
+            app.stroke_trace.cpu_prev(Some(0.004));
+            egui::CentralPanel::default().show(ui, |ui| crate::canvas::document_area(app, ui));
+            let stroking = app.live_stroke.is_some();
+            app.stroke_trace.end_frame(crate::gpu_canvas::now_ms() - t0, stroking, || "test".into());
+        },
+        app,
+    );
+    PhotocraftApp::setup_context(&h.ctx, crate::theme::ThemeKind::ALL[0]);
+    h.run_steps(4);
+    move_to(&mut h, 20.0, 50.0);
+    button(&mut h, 20.0, 50.0, true);
+    for x in [40.0, 60.0, 80.0, 100.0, 120.0] {
+        move_to(&mut h, x, 50.0);
+    }
+    assert!(h.state().stroke_trace.last.is_none(), "the stroke is still being drawn");
+    button(&mut h, 120.0, 50.0, false);
+    h.run_steps(2);
+    let s = h.state().stroke_trace.last.clone().expect("releasing ends the stroke's trace");
+    assert!(s.frames >= 6, "{s:?}");
+    assert!(s.stroke[1] > 0.0 && s.ui[0] >= s.stroke[0], "{s:?}");
+    assert_eq!(s.moves[1], 1.0, "one move per test frame: {s:?}");
+    assert_eq!(s.backend, "test");
+}
+
 /// A Clone Stamp stroke through the canvas renders the points its commit gets (position and
 /// pressure, no tilt or times), so the commit can take the live pixels; they are what replaying
 /// the journaled command paints.

crates/ui-egui/src/stroke_trace.rs

@@ -0,0 +1,297 @@
+//! Stroke latency trace (#1343): where each frame's time goes while a brush stroke is drawn, so
+//! a tester on any platform can report a per-stage breakdown instead of one input-to-pixel number.
+//!
+//! Set `PHOTOCRAFT_STROKE_TRACE` before launching: `1` prints a summary to stderr when each stroke
+//! ends; a file path also appends every frame of every stroke to that CSV. The last summary is in
+//! the control channel's `perf` output (`strokeTrace`).
+//!
+//! Per frame of a stroke it records the interval since the previous frame started, the pointer
+//! moves the frame delivered, the live stroke's render time, the canvas refresh (composite and
+//! upload), the UI build, and eframe's CPU time for the frame before (UI, tessellation and GPU
+//! submission, without the vsync wait). What the app can't see (the OS input queue before a frame
+//! starts, frames queued for the display, the compositor) is the rest of the input-to-photon time;
+//! the summary names the GPU backend because GL ignores the frame-latency setting.
+
+use std::fmt::Write as _;
+
+/// One frame of a stroke. Times in ms.
+#[derive(Clone, Debug, Default, PartialEq)]
+pub(crate) struct Row {
+    /// Frame start, from [`crate::gpu_canvas::now_ms`].
+    pub t: f64,
+    /// Since the previous frame started (0 for the first frame the trace saw).
+    pub interval: f64,
+    /// Pointer moves the frame delivered.
+    pub moves: usize,
+    /// Rendering the stroke's new points (the live stroke, or the commit on release).
+    pub stroke: f64,
+    /// Canvas refresh: composite and upload.
+    pub canvas: f64,
+    /// Building the UI (`App::ui`), the two above included.
+    pub ui: f64,
+    /// eframe's CPU time for the previous frame: UI, tessellation and GPU submission.
+    pub cpu_prev: Option<f64>,
+}
+
+/// Percentiles of a stroke's frames, for the summary line and the control channel.
+#[derive(Clone, Debug, Default, PartialEq, serde::Serialize)]
+#[serde(rename_all = "camelCase")]
+pub struct Summary {
+    pub frames: usize,
+    /// GPU backend and adapter ("vulkan NVIDIA GeForce …").
+    pub backend: String,
+    /// `[p50, p95]` of each stage, in ms.
+    pub interval: [f64; 2],
+    pub moves: [f64; 2],
+    pub stroke: [f64; 2],
+    pub canvas: [f64; 2],
+    pub ui: [f64; 2],
+    /// eframe's CPU time per frame (UI, tessellation, submission).
+    pub cpu: [f64; 2],
+    /// Frame interval minus that CPU time: waiting on vsync / the swap chain, or idle.
+    pub wait: [f64; 2],
+}
+
+impl Summary {
+    /// One line for stderr.
+    pub fn line(&self) -> String {
+        let f = |name: &str, [p50, p95]: [f64; 2]| format!("{name} {p50:.2}/{p95:.2}");
+        [
+            format!("stroke trace: {} frames on {} (p50/p95 ms):", self.frames, self.backend),
+            f("interval", self.interval),
+            f("moves/frame", self.moves),
+            f("stroke", self.stroke),
+            f("canvas", self.canvas),
+            f("ui", self.ui),
+            f("cpu", self.cpu),
+            f("wait", self.wait),
+        ]
+        .join(" ")
+    }
+}
+
+/// Where the trace goes ([`StrokeTrace::from_env`]).
+// The web build has no clock, so it never traces.
+#[cfg_attr(target_arch = "wasm32", allow(dead_code))]
+#[derive(Clone, Debug, Default, PartialEq)]
+pub(crate) enum Output {
+    #[default]
+    Off,
+    /// A summary per stroke on stderr.
+    Stderr,
+    /// The summary on stderr, and every frame appended to this CSV.
+    Csv(std::path::PathBuf),
+}
+
+#[derive(Debug, Default)]
+pub struct StrokeTrace {
+    pub(crate) output: Output,
+    /// The frame being built (started by `begin_frame`).
+    frame: Option<Row>,
+    last_start: Option<f64>,
+    /// The current stroke's frames.
+    rows: Vec<Row>,
+    /// Strokes finished so far (numbers the CSV rows).
+    strokes: usize,
+    /// The last finished stroke's summary.
+    pub last: Option<Summary>,
+}
+
+/// `[p50, p95]` of `v` (nearest rank; zeros when empty).
+fn percentiles(mut v: Vec<f64>) -> [f64; 2] {
+    v.retain(|x| x.is_finite());
+    if v.is_empty() {
+        return [0.0, 0.0];
+    }
+    v.sort_by(f64::total_cmp);
+    let at = |p: f64| v.get(((p * (v.len() - 1) as f64).round() as usize).min(v.len() - 1)).copied().unwrap_or(0.0);
+    let r = |x: f64| (x * 100.0).round() / 100.0;
+    [r(at(0.5)), r(at(0.95))]
+}
+
+impl StrokeTrace {
+    /// Reads `PHOTOCRAFT_STROKE_TRACE` (off on the web, where there is no clock).
+    pub fn from_env() -> Self {
+        #[cfg(not(target_arch = "wasm32"))]
+        if let Some(v) = std::env::var_os("PHOTOCRAFT_STROKE_TRACE").filter(|v| !v.is_empty()) {
+            let output = if v == "1" || v == "stderr" { Output::Stderr } else { Output::Csv(v.into()) };
+            return Self { output, ..Default::default() };
+        }
+        Self::default()
+    }
+
+    pub fn enabled(&self) -> bool {
+        self.output != Output::Off
+    }
+
+    /// A frame starts (the raw input hook) with `moves` pointer moves.
+    pub fn begin_frame(&mut self, now: f64, moves: usize) {
+        if !self.enabled() {
+            return;
+        }
+        let interval = self.last_start.map_or(0.0, |t| now - t);
+        self.last_start = Some(now);
+        self.frame = Some(Row { t: now, interval, moves, ..Default::default() });
+    }
+
+    /// eframe's CPU time for the previous frame, in seconds (`Frame::info().cpu_usage`).
+    pub fn cpu_prev(&mut self, secs: Option<f32>) {
+        if let Some(f) = self.frame.as_mut() {
+            f.cpu_prev = secs.map(|s| f64::from(s) * 1000.0);
+        }
+    }
+
+    /// Time spent rendering stroke points this frame.
+    pub fn stroke(&mut self, ms: f64) {
+        if let Some(f) = self.frame.as_mut() {
+            f.stroke += ms;
+        }
+    }
+
+    /// Time spent refreshing the canvas this frame.
+    pub fn canvas(&mut self, ms: f64) {
+        if let Some(f) = self.frame.as_mut() {
+            f.canvas += ms;
+        }
+    }
+
+    /// The frame's UI is built (`ui` ms). `stroking`: a stroke is being drawn (a frame that
+    /// rendered stroke points counts too, such as the release's commit). A stroke's frames are
+    /// kept until the first frame without one, which ends it.
+    pub fn end_frame(&mut self, ui: f64, stroking: bool, backend: impl FnOnce() -> String) {
+        let Some(mut f) = self.frame.take() else { return };
+        if stroking || f.stroke > 0.0 {
+            f.ui = ui;
+            // The first frame of a stroke doesn't follow a stroke frame: its interval is idle time.
+            if self.rows.is_empty() {
+                f.interval = 0.0;
+            }
+            self.rows.push(f);
+        } else if !self.rows.is_empty() {
+            self.finish(backend());
+        }
+    }
+
+    fn finish(&mut self, backend: String) {
+        let rows = std::mem::take(&mut self.rows);
+        self.strokes += 1;
+        let col = |g: fn(&Row) -> Option<f64>| percentiles(rows.iter().filter_map(g).collect());
+        let summary = Summary {
+            frames: rows.len(),
+            backend,
+            interval: col(|r| (r.interval > 0.0).then_some(r.interval)),
+            moves: col(|r| Some(r.moves as f64)),
+            stroke: col(|r| Some(r.stroke)),
+            canvas: col(|r| Some(r.canvas)),
+            ui: col(|r| Some(r.ui)),
+            // A frame's cpu_prev belongs to the frame before it, so pair it with that interval.
+            cpu: percentiles(rows.iter().skip(1).filter_map(|r| r.cpu_prev).collect()),
+            wait: percentiles(rows.windows(2).filter_map(|w| Some((w[1].interval - w[1].cpu_prev?).max(0.0))).collect()),
+        };
+        if self.enabled() {
+            eprintln!("{}", summary.line());
+        }
+        #[cfg(not(target_arch = "wasm32"))]
+        if let Output::Csv(path) = &self.output
+            && let Err(e) = append_csv(path, self.strokes, &rows)
+        {
+            eprintln!("stroke trace: can't write {}: {e}", path.display());
+        }
+        self.last = Some(summary);
+    }
+}
+
+/// The CSV text for `rows` of stroke `stroke` (with the header when `header`).
+// The web build has no clock, so it never traces.
+#[cfg_attr(target_arch = "wasm32", allow(dead_code))]
+pub(crate) fn csv(stroke: usize, rows: &[Row], header: bool) -> String {
+    let mut s = String::new();
+    if header {
+        s.push_str("stroke,t_ms,interval_ms,moves,stroke_ms,canvas_ms,ui_ms,cpu_prev_ms\n");
+    }
+    for r in rows {
+        let cpu = r.cpu_prev.map_or(String::new(), |c| format!("{c:.3}"));
+        let _ = writeln!(s, "{stroke},{:.3},{:.3},{},{:.3},{:.3},{:.3},{cpu}", r.t, r.interval, r.moves, r.stroke, r.canvas, r.ui);
+    }
+    s
+}
+
+#[cfg(not(target_arch = "wasm32"))]
+fn append_csv(path: &std::path::Path, stroke: usize, rows: &[Row]) -> std::io::Result<()> {
+    use std::io::Write as _;
+    let header = std::fs::metadata(path).map_or(true, |m| m.len() == 0);
+    let mut f = std::fs::OpenOptions::new().create(true).append(true).open(path)?;
+    f.write_all(csv(stroke, rows, header).as_bytes())
+}
+
+#[cfg(test)]
+mod tests {
+    use super::*;
+
+    fn on() -> StrokeTrace {
+        StrokeTrace { output: Output::Stderr, ..Default::default() }
+    }
+
+    fn frame(t: &mut StrokeTrace, now: f64, cpu: f32, stroking: bool) {
+        t.begin_frame(now, 3);
+        t.cpu_prev(Some(cpu / 1000.0));
+        if stroking {
+            t.stroke(1.0);
+            t.canvas(2.0);
+        }
+        t.end_frame(4.0, stroking, || "vulkan Test GPU".into());
+    }
+
+    #[test]
+    fn a_stroke_is_its_frames_from_the_first_stroke_frame_to_the_first_without() {
+        let mut t = on();
+        frame(&mut t, 0.0, 5.0, false);
+        frame(&mut t, 100.0, 5.0, true);
+        for k in 1..=10 {
+            frame(&mut t, 100.0 + 16.0 * f64::from(k), 6.0, true);
+        }
+        assert!(t.last.is_none(), "still drawing");
+        frame(&mut t, 276.0, 6.0, false);
+        let s = t.last.clone().expect("the stroke ended");
+        assert_eq!(s.frames, 11);
+        assert_eq!(s.interval, [16.0, 16.0], "the idle gap before the stroke isn't a frame interval");
+        assert_eq!((s.stroke, s.canvas, s.ui, s.moves), ([1.0, 1.0], [2.0, 2.0], [4.0, 4.0], [3.0, 3.0]));
+        assert_eq!((s.cpu, s.wait), ([6.0, 6.0], [10.0, 10.0]));
+        assert!(s.line().contains("11 frames on vulkan Test GPU") && s.line().contains("wait 10.00/10.00"), "{}", s.line());
+        // Off: nothing is kept.
+        let mut off = StrokeTrace::default();
+        frame(&mut off, 0.0, 1.0, true);
+        frame(&mut off, 16.0, 1.0, false);
+        assert!(off.last.is_none() && off.rows.is_empty());
+    }
+
+    #[test]
+    fn csv_rows_and_odd_numbers() {
+        let rows = [Row { t: 1.0, interval: 16.5, moves: 2, stroke: 0.25, canvas: 1.0, ui: 3.0, cpu_prev: None }];
+        assert_eq!(csv(1, &rows, true), "stroke,t_ms,interval_ms,moves,stroke_ms,canvas_ms,ui_ms,cpu_prev_ms\n1,1.000,16.500,2,0.250,1.000,3.000,\n");
+        assert_eq!(percentiles(vec![]), [0.0, 0.0]);
+        assert_eq!(percentiles(vec![f64::NAN, 2.0, f64::INFINITY]), [2.0, 2.0]);
+        assert_eq!(percentiles((1..=100).map(f64::from).collect()), [51.0, 95.0]);
+    }
+
+    #[cfg(not(target_arch = "wasm32"))]
+    #[test]
+    fn the_csv_gets_one_header_and_every_strokes_frames() {
+        let dir = std::env::temp_dir().join(format!("photocraft-stroke-trace-{}", std::process::id()));
+        let _ = std::fs::create_dir_all(&dir);
+        let path = dir.join("trace.csv");
+        let _ = std::fs::remove_file(&path);
+        let mut t = StrokeTrace { output: Output::Csv(path.clone()), ..Default::default() };
+        for start in [0.0, 1000.0] {
+            for k in 0..3 {
+                frame(&mut t, start + 16.0 * f64::from(k), 5.0, true);
+            }
+            frame(&mut t, start + 48.0, 5.0, false);
+        }
+        let text = std::fs::read_to_string(&path).unwrap();
+        let _ = std::fs::remove_dir_all(&dir);
+        let lines: Vec<&str> = text.lines().collect();
+        assert_eq!(lines.len(), 7, "{text}");
+        assert!(lines[0].starts_with("stroke,") && lines[1].starts_with("1,") && lines[6].starts_with("2,"));
+    }
+}

docs/development.md

@@ -119,6 +119,7 @@ By default PhotoCraft's own crates log at `info` and everything else at `warn`.
 | `PHOTOCRAFT_CPU_COMPOSE=1` | Keep the wgpu canvas but composite on the CPU (compare GPU vs CPU renders, e.g. with the snapshot example) |
 | `PHOTOCRAFT_LOCALE` | Override Auto's native UI language for this launch; unsupported tags use English. See [system language detection](localization.md#first-launch-and-system-language). |
 | `PHOTOCRAFT_FX_TRACE=1` | Print the CPU time spent on GPU effect shapes and distance fields per rebuild |
+| `PHOTOCRAFT_STROKE_TRACE=1` (or `=<file.csv>`) | Time every frame of each brush stroke; print a summary per stroke, and with a path also append each frame to that CSV (see [Stroke latency trace](#stroke-latency-trace)) |
 | `PHOTOCRAFT_THEME_FILE=tokens.json` | **Debug builds only:** live design-token overrides, re-read on change |
 
 ### Live design tokens
@@ -129,6 +130,26 @@ By default PhotoCraft's own crates log at `info` and everything else at `warn`.
 
 Keys are the field names of `theme::Tokens` (`crates/ui-egui/src/theme.rs`). Edit and save the file while the app runs to see changes immediately, with no recompile. This is compiled out of release builds.
 
+### Stroke latency trace
+
+To find where a stroke's input-to-pixel time goes on a given machine (#1343), launch with `PHOTOCRAFT_STROKE_TRACE=1` (a summary per stroke on standard error) or `PHOTOCRAFT_STROKE_TRACE=strokes.csv` (also every frame, appended to that file). Paint a few strokes with the mouse or pen. Each summary gives p50/p95 in ms:
+
+```text
+stroke trace: 62 frames on vulkan NVIDIA GeForce RTX 5090 (p50/p95 ms): interval 8.33/8.53 moves/frame 1.00/2.00 stroke 0.80/1.53 canvas 0.40/0.75 ui 0.91/1.41 cpu 2.20/2.84 wait 6.04/6.64
+```
+
+| Column | What it is |
+|---|---|
+| `interval` | Time between frame starts while drawing (the display's refresh period when the app keeps up) |
+| `moves/frame` | Pointer moves the OS delivered per frame (control-channel `ui.pointer` input bypasses raw input and counts 0) |
+| `stroke` | Rendering the stroke's new points (the live stroke; on the last frame, the commit) |
+| `canvas` | Canvas refresh: composite and upload |
+| `ui` | Building the UI, the two above included |
+| `cpu` | eframe's CPU time per frame: UI, tessellation and GPU submission, without the vsync wait |
+| `wait` | `interval − cpu`: waiting on vsync or the swap chain, or idle |
+
+What the app can't time is the rest of input-to-photon: the OS input queue before a frame starts (up to one `interval`), frames queued for the display (the surface keeps up to two; the GL backend ignores that setting), and the compositor. So the first line names the backend. The last summary is also in the control channel's `perf.strokeTrace` (`ui.inspect`). The code is `crates/ui-egui/src/stroke_trace.rs`.
+
 ## Driving the app programmatically
 
 Start the app with a private token file. It then accepts authenticated JSON lines on `127.0.0.1:7878`: