Merge pull request #465 from switch87/desktop-log-file

Desktop: write log records to standard error and a rotating log file

ROADMAP.md

@@ -4,7 +4,7 @@ VectorCraft is a clean-room, open-source, pure-Rust reimplementation of the Adob
 
 This file tracks **how far we are and what's left**. Time estimates are wall-clock hours of continuous Claude Opus 5.5 agent work (including builds and the CI gate), given both for **one agent** and for **4–6 parallel agents** on disjoint crates. They are counted from the remaining work (see [Parity estimate](#parity-estimate)), calibrated against measured throughput, and updated as work lands.
 
-_Last updated: 2026-10-08 (after M4.14–M4.98, M8.1–M8.20, M14.4–M14.7, the MCP prompts, resource templates, completions and logging, the 2026-10-07 issue fixes, the Layers panel rework and the 2026-10-08 community contributions: Pen and shape-tool modifiers, path editing, Layers, Artboards, Swatches/Brushes and dialogs, Japanese composition and PDF text, Hebrew/Arabic type, interface languages (Spanish among them), the font menu, saved selections, MCP and EPS, the missing-font export warning (#319), open paths in the Shape Builder (#374), PDF/`.ai` import keeping strokes live and hidden and nested layers (#372), per-corner Live Corners (#381), SVG type opening at the size it draws at (#396), the Wayland clipboard with copied-file paste (#398), ruler guides that can be selected, moved and deleted (#414), two batches of Preferences options that were stored but unused (#394), skeleton reads with `document.find` for large documents over MCP (#416) and anchors dragged with Direct Selection snapping to points, segments and smart guides, clipped SVG layers opening as clipping layers (#420), PDF/`.ai` layers read on pages of tens of millions of operators (#419), Document Color Mode putting RGB greys on the black plate on request and converting pattern tiles (#421) and movable dialogs with Offset Path's Joins dropdown (#423) and numeric fields scrubbed by dragging their label (#400), stroke weight presets in the stroke unit (#426), the Appearance panel's Opacity popup (#430), type on a path brackets, flip and Type on a Path Options that keep the type in place (#429), Layers rows dragged with a ghost and dropped on the trash or New Layer (#435), tool flyouts opening on a right or corner press (#436), tool flyouts torn off into floating toolbars (#437), the Shape Builder's erase mode deleting edges too (#439), installed fonts registered outside the font folders and fonts installed while the app runs listed in the font menus (#443), alike circular corners on rectangles that aren't square (#442), tool cursors as OS cursors so the pointer no longer trails over the canvas (#444), artboards copied and pasted with their art (#446), guides dragged out of the rulers snapping to the art's side midpoints and the artboards, artboard guides (#451), the toolbar's double arrow and Window › Toolbars › Double Column switching between one and two columns in any window height (#455), the Smart Guides display options and Snapping Tolerance (#394), Font Size and Leading combo boxes with preset lists in the Character and Properties panels and the Control bar (#458), screenshots pasted from the clipboard on macOS, Windows and the web (#457), the Properties panel's Fill and Stroke matching the Control bar's, Illustrator's Window menu panel keys (Shift+F7 for Align…) and Alt-wheel zoom whatever the wheel preference (Discord feedback), the point/area type widget (Discord feedback), groups in legacy Illustrator .ai files (Discord feedback); see [Honest assessment](#honest-assessment-2026-10-05))._
+_Last updated: 2026-10-08 (after M4.14–M4.98, M8.1–M8.20, M14.4–M14.7, the MCP prompts, resource templates, completions and logging, the 2026-10-07 issue fixes, the Layers panel rework and the 2026-10-08 community contributions: Pen and shape-tool modifiers, path editing, Layers, Artboards, Swatches/Brushes and dialogs, Japanese composition and PDF text, Hebrew/Arabic type, interface languages (Spanish among them), the font menu, saved selections, MCP and EPS, the missing-font export warning (#319), open paths in the Shape Builder (#374), PDF/`.ai` import keeping strokes live and hidden and nested layers (#372), per-corner Live Corners (#381), SVG type opening at the size it draws at (#396), the Wayland clipboard with copied-file paste (#398), ruler guides that can be selected, moved and deleted (#414), two batches of Preferences options that were stored but unused (#394), skeleton reads with `document.find` for large documents over MCP (#416) and anchors dragged with Direct Selection snapping to points, segments and smart guides, clipped SVG layers opening as clipping layers (#420), PDF/`.ai` layers read on pages of tens of millions of operators (#419), Document Color Mode putting RGB greys on the black plate on request and converting pattern tiles (#421) and movable dialogs with Offset Path's Joins dropdown (#423) and numeric fields scrubbed by dragging their label (#400), stroke weight presets in the stroke unit (#426), the Appearance panel's Opacity popup (#430), type on a path brackets, flip and Type on a Path Options that keep the type in place (#429), Layers rows dragged with a ghost and dropped on the trash or New Layer (#435), tool flyouts opening on a right or corner press (#436), tool flyouts torn off into floating toolbars (#437), the Shape Builder's erase mode deleting edges too (#439), installed fonts registered outside the font folders and fonts installed while the app runs listed in the font menus (#443), alike circular corners on rectangles that aren't square (#442), tool cursors as OS cursors so the pointer no longer trails over the canvas (#444), artboards copied and pasted with their art (#446), guides dragged out of the rulers snapping to the art's side midpoints and the artboards, artboard guides (#451), the toolbar's double arrow and Window › Toolbars › Double Column switching between one and two columns in any window height (#455), the Smart Guides display options and Snapping Tolerance (#394), Font Size and Leading combo boxes with preset lists in the Character and Properties panels and the Control bar (#458), screenshots pasted from the clipboard on macOS, Windows and the web (#457), the Properties panel's Fill and Stroke matching the Control bar's, Illustrator's Window menu panel keys (Shift+F7 for Align…) and Alt-wheel zoom whatever the wheel preference (Discord feedback), the point/area type widget (Discord feedback), groups in legacy Illustrator .ai files (Discord feedback), a rotating desktop log file (#465); see [Honest assessment](#honest-assessment-2026-10-05))._
 
 ## Where we are
 
@@ -150,7 +150,7 @@ grade by behaviour against `plan/illustrator/`, not by whether a menu item exist
 - **Colour, type and file workflows:** Recolor Artwork (dialog with harmonies), Edit Colors, Find & Replace, Change Case, Smart Punctuation, Guides, Lock/Hide Above, Transform Each, Rasterize.
 - **Fonts:** a font is found by any of its names (family and style in every language of its name table, legacy family/style pairs, PostScript name), so documents from other apps open with the font they name; Find Font and `text.fonts` say for each font whether it was found exactly, by another name, substituted or missing, and how many glyphs are missing. PDF and `.ai` import brings Japanese text back as live type: CID fonts without a ToUnicode map read through the standard CMaps, vertical columns (WMode 1) as vertical type, letter spacing as tracking; a glyph is live type only when the installed font (in the closest style of its family) draws the same glyph, and text in a font that isn't installed comes in as live type shown in the fallback font until the font is installed (exports that draw it — PDF, EPS, EMF/WMF, raster, SVG outlines or embedded fonts — warn that they wrote the fallback font; `textAs: outlines` keeps the PDF's embedded glyphs).
 - **Files (M4):**
-  - `.vectorcraft` (lossless JSON, compressed, atomic saves, save down to v1), Save As with a format chooser, Save a Copy, Revert, templates, Data Recovery after a crash (browser tabs hold their copies with Web Locks too, so a background tab's copies are never taken for a crash's, and a tab repairs copies another removed when it resumes: #367), background save and export.
+  - `.vectorcraft` (lossless JSON, compressed, atomic saves, save down to v1), Save As with a format chooser, Save a Copy, Revert, templates, Data Recovery after a crash (browser tabs hold their copies with Web Locks too, so a background tab's copies are never taken for a crash's, and a tab repairs copies another removed when it resumes: #367), background save and export. The desktop app writes its warnings and errors (graphics adapter, a lost graphics device, panics the guard recovered from) to standard error and to `logs/vectorcraft.log` next to the preferences, the two previous runs kept and each file capped at 16 MiB, so a launch without a terminal still leaves something to attach to a bug report (#465).
   - SVG/SVGZ in and out with SVG Options, Preserve Editing, symbols, filters, rich text and physical units (SVG type under a transform or `viewBox` scale opens at the size it draws at, the scale moved into its size, leading, baseline shift and strokes, a stretch, skew or rotation kept as its transform: #396; a top-level group with a clip path, such as a clipped Inkscape layer, opens as a layer with a clipping mask, its name kept: #420); PDF and PDF-compatible `.ai` in and out (layers, with hidden ones kept hidden with their art and nested ones as sublayers, on pages of up to 64 million operators, art whose layer can't be told going to a hidden, non-printing layer rather than showing or printing: #419; strokes kept live, a fill and a stroke of one outline as one object; masks, editable text with type set along a curve coming back as type on a path, each artboard's art on its own page only, an `.ai`'s white page under its layers left out rather than coming in as art, spot colours, presets, security, marks and bleed, ICC output intents, raster effects, subset fonts, PDF/X, PDF layers, overprint, page thumbnails, fast web view, PDF 1.3). CMYK images keep their ink amounts from PDF import (and from placed CMYK TIFFs) to PDF export: a CMYK JPEG passes through unchanged, others stay CMYK (DeviceCMYK, or ICC-based CMYK in PDF/X-3/X-4) unless the Output settings convert them; the canvas shows them through the working CMYK profile (#320).
   - EPS and DXF in and out, EMF/WMF in and out; PNG (with PNG-8), JPEG, WebP, GIF, TIFF, BMP, Targa and layered PSD export. EPS import runs Illustrator's AGM/CoolType prologs (resource categories, `resourceforall`, `clipsave`/`cliprestore`, subarrays and substrings that share storage, the standard dictionaries in `systemdict`, `dictstack`, `internaldict`, executable filters, `cshow`, metadata skipped with `flushfile`), so Illustrator 30 EPS files open as vectors, and falls back to its palette TIFF preview. Legacy PostScript `.ai` files (Illustrator 3–8, written with the prolog that defines their operators) keep their groups and nested groups (`u` … `U`), between and inside clipping groups; EPS and EMF/WMF import nest clips (and groups) at most 128 deep, so a hostile file can't exhaust the stack. DXF TEXT justified Fit or Aligned spans its two points (stretched, or scaled as a whole).
   - Place and the Links panel, Package, File Info, Print with print presets, PostScript output and print tiling, slices and Save for Web, Export for Screens and Asset Export, CSS Properties, PNG/PDF/SVG/text clipboard flavours; files copied in a file manager paste as art (SVG, PDF, EMF/WMF, bitmaps) on every desktop platform, and Linux/Wayland reads the compositor's clipboard (#398); screenshots and other copied pictures paste as embedded images at the view centre everywhere, the web included (#457).

apps/vectorcraft/src/logging.rs

@@ -0,0 +1,582 @@
+//! The desktop app's logger: `log::` records go to standard error and to a log file.
+//!
+//! Without a logger every `log::warn!`/`log::error!` in the workspace (the graphics adapter, a
+//! lost graphics device, a panic the engine's guard recovered from) vanished. A launch from a desktop menu
+//! has no terminal, so the file is what a bug report can attach: `<settings dir>/logs/vectorcraft.log`,
+//! next to the preferences (`prefs_path` in `main.rs`). Each start moves the previous log to
+//! `vectorcraft.1.log` (and that one to `.2`), so the log of a run that crashed survives the next
+//! launch. Runs without preferences (`VECTORCRAFT_NO_PREFS`) log to standard error only.
+//!
+//! Levels: `info` for VectorCraft's own crates, `warn` for everything else (wgpu and naga are
+//! chatty). `RUST_LOG` replaces that with env_logger-style directives: `debug`,
+//! `warn,vectorcraft_render=trace`, `wgpu_core=info`. A directive ending in `*` matches every
+//! target that starts with it (`vectorcraft*=debug`).
+//!
+//! Records logged before the settings directory is known are kept (up to [`MAX_PENDING`]) and
+//! written once the file is attached. Writing never panics: a file that can't be created or
+//! written leaves standard error as the only sink.
+//!
+//! This is the desktop app's logger only. `vectorcraft-cli mcp` installs its own
+//! (`vectorcraft_mcp::logging`, MCP `notifications/message`); the two never share a process.
+
+use std::fs::File;
+use std::io::Write;
+use std::path::{Path, PathBuf};
+use std::sync::{Mutex, OnceLock, PoisonError};
+use std::time::SystemTime;
+
+use log::LevelFilter;
+
+/// The current log file's name inside the log directory.
+pub const LOG_FILE: &str = "vectorcraft.log";
+/// How many previous logs are kept (`vectorcraft.1.log` … `vectorcraft.<KEEP>.log`).
+pub const KEEP: usize = 2;
+/// The log file stops growing past this size (a runaway warning can't fill the disk).
+pub const MAX_FILE_BYTES: u64 = 16 * 1024 * 1024;
+/// Records kept in memory until the log file is attached.
+pub const MAX_PENDING: usize = 512;
+/// The built-in filter when `RUST_LOG` is unset or empty.
+pub const DEFAULT_FILTER: &str = "warn,vectorcraft*=info";
+
+/// Per-target level filter parsed from env_logger-style directives.
+#[derive(Clone, Debug, PartialEq, Eq)]
+pub struct Filter {
+    default: LevelFilter,
+    directives: Vec<(String, LevelFilter)>,
+}
+
+impl Filter {
+    /// Parse `spec`; unknown levels and empty parts are skipped. Without a bare level, targets no
+    /// directive names log errors only.
+    pub fn parse(spec: &str) -> Filter {
+        let mut f = Filter { default: LevelFilter::Error, directives: Vec::new() };
+        for part in spec.split(',').map(str::trim).filter(|p| !p.is_empty()) {
+            match part.split_once('=') {
+                Some((name, level)) => {
+                    let name = name.trim();
+                    if let (false, Some(level)) = (name.is_empty(), parse_level(level)) {
+                        f.directives.push((name.to_owned(), level));
+                    }
+                }
+                None => match parse_level(part) {
+                    Some(level) => f.default = level,
+                    // A bare target name: everything from it (env_logger does the same).
+                    None => f.directives.push((part.to_owned(), LevelFilter::Trace)),
+                },
+            }
+        }
+        f
+    }
+
+    /// The level that applies to `target` (the most specific matching directive wins).
+    pub fn level_for(&self, target: &str) -> LevelFilter {
+        self.directives.iter().filter(|(name, _)| matches(name, target)).max_by_key(|(name, _)| name.len()).map_or(self.default, |(_, level)| *level)
+    }
+
+    /// The most verbose level any target can reach (for `log::set_max_level`).
+    pub fn max(&self) -> LevelFilter {
+        self.directives.iter().map(|(_, level)| *level).fold(self.default, Ord::max)
+    }
+}
+
+fn parse_level(s: &str) -> Option<LevelFilter> {
+    s.trim().parse().ok()
+}
+
+/// `name` matches `target` itself and its submodules (`a` matches `a` and `a::b`, not `ab`);
+/// `name*` matches every target starting with `name`.
+fn matches(name: &str, target: &str) -> bool {
+    match name.strip_suffix('*') {
+        Some(prefix) => target.starts_with(prefix),
+        None => target.strip_prefix(name).is_some_and(|rest| rest.is_empty() || rest.starts_with("::")),
+    }
+}
+
+/// `2026-10-08T07:59:17.728Z` (UTC, milliseconds). A clock before 1970 reads as the epoch.
+pub fn timestamp(t: SystemTime) -> String {
+    let since = t.duration_since(std::time::UNIX_EPOCH).unwrap_or_default();
+    let secs = since.as_secs();
+    let (days, rem) = (secs / 86_400, secs % 86_400);
+    let (y, m, d) = civil_from_days(days);
+    format!("{y:04}-{m:02}-{d:02}T{:02}:{:02}:{:02}.{:03}Z", rem / 3600, rem % 3600 / 60, rem % 60, since.subsec_millis())
+}
+
+/// Days since 1970-01-01 to a proleptic Gregorian (year, month, day) (Howard Hinnant's
+/// `civil_from_days`, unsigned because `timestamp` clamps at the epoch). Saturating, so no clock
+/// value can overflow it.
+fn civil_from_days(days: u64) -> (u64, u64, u64) {
+    let z = days.saturating_add(719_468);
+    let era = z / 146_097;
+    let doe = z % 146_097;
+    let yoe = (doe - doe / 1460 + doe / 36_524 - doe / 146_096) / 365;
+    let doy = doe - (365 * yoe + yoe / 4 - yoe / 100);
+    let mp = (5 * doy + 2) / 153;
+    let d = doy - (153 * mp + 2) / 5 + 1;
+    let m = if mp < 10 { mp + 3 } else { mp - 9 };
+    let y = era.saturating_mul(400).saturating_add(yoe).saturating_add(u64::from(m <= 2));
+    (y, m, d)
+}
+
+fn numbered(dir: &Path, n: usize) -> PathBuf {
+    if n == 0 { dir.join(LOG_FILE) } else { dir.join(format!("vectorcraft.{n}.log")) }
+}
+
+/// Shift the previous logs up one (`.log` → `.1.log` → … → `.<KEEP>.log`, the oldest dropped)
+/// and create a fresh, empty log file in `dir` (created if missing).
+pub fn rotate(dir: &Path) -> std::io::Result<(PathBuf, File)> {
+    std::fs::create_dir_all(dir)?;
+    for n in (1..=KEEP).rev() {
+        match std::fs::rename(numbered(dir, n - 1), numbered(dir, n)) {
+            Err(e) if e.kind() != std::io::ErrorKind::NotFound => return Err(e),
+            _ => {}
+        }
+    }
+    let path = numbered(dir, 0);
+    let file = File::create(&path)?;
+    Ok((path, file))
+}
+
+/// One formatted log line: `<timestamp> <LEVEL> [<thread>] <target>: <message>\n`.
+pub fn format_line(ts: &str, level: log::Level, thread: &str, target: &str, message: &str) -> String {
+    let message = message.strip_suffix('\n').unwrap_or(message);
+    format!("{ts} {level:<5} [{thread}] {target}: {message}\n")
+}
+
+/// Where formatted lines go besides standard error: kept in memory until a file is attached,
+/// then appended to it until it reaches its size cap.
+pub struct Sink {
+    file: Option<File>,
+    pending: Vec<String>,
+    dropped: usize,
+    written: u64,
+    max_bytes: u64,
+    capped: bool,
+}
+
+impl Sink {
+    pub fn new(max_bytes: u64) -> Sink {
+        Sink { file: None, pending: Vec::new(), dropped: 0, written: 0, max_bytes, capped: false }
+    }
+
+    /// Append `line` to the file, or keep it until [`Sink::attach`].
+    pub fn write(&mut self, line: &str) {
+        if self.file.is_none() {
+            if self.capped {
+                // No file is coming ([`Sink::no_file`]): standard error had the line.
+            } else if self.pending.len() < MAX_PENDING {
+                self.pending.push(line.to_owned());
+            } else {
+                self.dropped = self.dropped.saturating_add(1);
+            }
+            return;
+        }
+        self.append(line);
+    }
+
+    /// Start writing to `file` (a fresh one: the size cap starts over), first the lines kept so far.
+    pub fn attach(&mut self, file: File) {
+        self.file = Some(file);
+        self.written = 0;
+        self.capped = false;
+        for line in std::mem::take(&mut self.pending) {
+            self.append(&line);
+        }
+        if self.dropped > 0 {
+            let note = format!("{} earlier log lines were dropped before the log file was opened\n", self.dropped);
+            self.dropped = 0;
+            self.append(&note);
+        }
+    }
+
+    /// There will be no log file: forget the lines kept for it and keep no more.
+    pub fn no_file(&mut self) {
+        self.pending = Vec::new();
+        self.dropped = 0;
+        self.capped = true;
+    }
+
+    fn append(&mut self, line: &str) {
+        if self.capped {
+            return;
+        }
+        let Some(file) = self.file.as_mut() else { return };
+        let len = u64::try_from(line.len()).unwrap_or(u64::MAX);
+        let text = if self.written.saturating_add(len) > self.max_bytes {
+            self.capped = true;
+            format!("log file reached {} bytes; later records go to standard error only\n", self.max_bytes)
+        } else {
+            self.written = self.written.saturating_add(len);
+            line.to_owned()
+        };
+        // A full disk or a vanished file must not take the app down: drop the file sink.
+        if file.write_all(text.as_bytes()).is_err() {
+            self.file = None;
+            self.capped = true;
+        }
+    }
+}
+
+/// The installed logger: a [`Filter`], standard error and a [`Sink`].
+pub struct AppLogger {
+    filter: Filter,
+    stderr: bool,
+    sink: Mutex<Sink>,
+}
+
+impl AppLogger {
+    pub fn new(filter: Filter, stderr: bool) -> AppLogger {
+        AppLogger { filter, stderr, sink: Mutex::new(Sink::new(MAX_FILE_BYTES)) }
+    }
+
+    /// Rotate the logs in `dir` and send records to the fresh file; returns its path. On an error
+    /// standard error stays the only sink.
+    pub fn attach_dir(&self, dir: &Path) -> Result<PathBuf, String> {
+        // A thread that panicked while logging leaves the sink usable: take it back.
+        let mut sink = self.sink.lock().unwrap_or_else(PoisonError::into_inner);
+        match rotate(dir) {
+            Ok((path, file)) => {
+                sink.attach(file);
+                Ok(path)
+            }
+            Err(e) => {
+                sink.no_file();
+                Err(format!("{}: {e}", dir.display()))
+            }
+        }
+    }
+
+    /// No log file for this run (runs without preferences): log to standard error only.
+    pub fn no_file(&self) {
+        self.sink.lock().unwrap_or_else(PoisonError::into_inner).no_file();
+    }
+}
+
+impl log::Log for AppLogger {
+    fn enabled(&self, metadata: &log::Metadata<'_>) -> bool {
+        metadata.level() <= self.filter.level_for(metadata.target())
+    }
+
+    fn log(&self, record: &log::Record<'_>) {
+        if !self.enabled(record.metadata()) {
+            return;
+        }
+        // Formatted before the sink is locked, so a message that logs while it is formatted can't deadlock.
+        let thread = std::thread::current();
+        let line =
+            format_line(&timestamp(SystemTime::now()), record.level(), thread.name().unwrap_or("?"), record.target(), &record.args().to_string());
+        if self.stderr {
+            // No terminal (a Windows GUI build, a closed pipe) is not an error worth reporting.
+            let _ = std::io::stderr().write_all(line.as_bytes());
+        }
+        self.sink.lock().unwrap_or_else(PoisonError::into_inner).write(&line);
+    }
+
+    fn flush(&self) {}
+}
+
+/// Install the logger (filter from `RUST_LOG`, else [`DEFAULT_FILTER`]); `None` when another
+/// logger was installed first. Call [`AppLogger::attach_dir`] once the settings directory is known.
+pub fn install() -> Option<&'static AppLogger> {
+    static LOGGER: OnceLock<AppLogger> = OnceLock::new();
+    let spec = std::env::var("RUST_LOG").ok().filter(|s| !s.trim().is_empty());
+    let filter = Filter::parse(spec.as_deref().unwrap_or(DEFAULT_FILTER));
+    let max = filter.max();
+    let logger = LOGGER.get_or_init(|| AppLogger::new(filter, true));
+    log::set_logger(logger).ok()?;
+    log::set_max_level(max);
+    Some(logger)
+}
+
+#[cfg(test)]
+mod tests {
+    use super::*;
+    use std::sync::atomic::{AtomicUsize, Ordering};
+    use std::time::{Duration, UNIX_EPOCH};
+
+    fn temp_dir(tag: &str) -> PathBuf {
+        static N: AtomicUsize = AtomicUsize::new(0);
+        let d = std::env::temp_dir().join(format!("vectorcraft-logging-{tag}-{}-{}", std::process::id(), N.fetch_add(1, Ordering::Relaxed)));
+        let _ = std::fs::remove_dir_all(&d);
+        d
+    }
+
+    fn read(path: &Path) -> String {
+        std::fs::read_to_string(path).expect("read log")
+    }
+
+    #[test]
+    fn the_default_filter_shows_vectorcraft_info_and_other_crates_warnings() {
+        let f = Filter::parse(DEFAULT_FILTER);
+        assert_eq!(f.level_for("vectorcraft"), LevelFilter::Info);
+        assert_eq!(f.level_for("vectorcraft::window"), LevelFilter::Info);
+        assert_eq!(f.level_for("vectorcraft_engine::guard"), LevelFilter::Info);
+        assert_eq!(f.level_for("vectorcraft_ui_egui::io"), LevelFilter::Info);
+        assert_eq!(f.level_for("wgpu_core::device"), LevelFilter::Warn);
+        assert_eq!(f.level_for("naga"), LevelFilter::Warn);
+        assert_eq!(f.max(), LevelFilter::Info);
+    }
+
+    #[test]
+    fn directives_follow_env_logger_and_the_most_specific_one_wins() {
+        let f = Filter::parse("info,wgpu_core=error,vectorcraft_render=trace,vectorcraft_render::tiles=off");
+        assert_eq!(f.level_for("eframe"), LevelFilter::Info);
+        assert_eq!(f.level_for("wgpu_core::instance"), LevelFilter::Error);
+        assert_eq!(f.level_for("vectorcraft_render::canvas"), LevelFilter::Trace);
+        assert_eq!(f.level_for("vectorcraft_render::tiles"), LevelFilter::Off);
+        assert_eq!(f.max(), LevelFilter::Trace);
+        // A module name is matched at `::` boundaries, not as a bare prefix.
+        assert_eq!(f.level_for("wgpu_core_extra"), LevelFilter::Info);
+        // A trailing `*` is a prefix.
+        assert_eq!(Filter::parse("vectorcraft*=debug").level_for("vectorcraft_text::shape"), LevelFilter::Debug);
+        assert_eq!(Filter::parse("vectorcraft*=debug").level_for("eframe"), LevelFilter::Error);
+        // A bare target name sets that target to the most verbose level, as env_logger does.
+        assert_eq!(Filter::parse("naga").level_for("naga::front"), LevelFilter::Trace);
+        assert_eq!(Filter::parse("naga").level_for("eframe"), LevelFilter::Error);
+        // Levels are case-insensitive and surrounding blanks are ignored.
+        assert_eq!(Filter::parse(" WARN , vectorcraft = Debug ").level_for("vectorcraft"), LevelFilter::Debug);
+        assert_eq!(Filter::parse(" WARN , vectorcraft = Debug ").level_for("eframe"), LevelFilter::Warn);
+    }
+
+    #[test]
+    fn hostile_specs_never_panic_and_fall_back_sensibly() {
+        let long = "x".repeat(100_000);
+        let many = "a=info,".repeat(10_000);
+        for spec in [
+            "",
+            ",,,",
+            "=",
+            "==",
+            "=debug",
+            "vectorcraft=",
+            "nonsense=loud",
+            "🦀=info",
+            "*",
+            "*=",
+            "=*",
+            "a=b=c",
+            "warn,,vectorcraft=DEBUG",
+            "\0",
+            "é::ü=trace",
+            &long,
+            &many,
+        ] {
+            let f = Filter::parse(spec);
+            for target in ["", "vectorcraft", "🦀", "a::b", "*"] {
+                let _ = f.level_for(target);
+            }
+            let _ = f.max();
+        }
+        assert_eq!(Filter::parse("warn,,vectorcraft=DEBUG").level_for("vectorcraft"), LevelFilter::Debug);
+        // An unknown level is skipped: that target keeps the default.
+        assert_eq!(Filter::parse("nonsense=loud").level_for("nonsense"), LevelFilter::Error);
+        assert_eq!(Filter::parse("vectorcraft=").level_for("vectorcraft"), LevelFilter::Error);
+        assert_eq!(Filter::parse("=debug").max(), LevelFilter::Error);
+        assert_eq!(Filter::parse("🦀=info").level_for("🦀::claw"), LevelFilter::Info);
+    }
+
+    #[test]
+    fn timestamps_are_utc_with_milliseconds() {
+        assert_eq!(timestamp(UNIX_EPOCH), "1970-01-01T00:00:00.000Z");
+        assert_eq!(timestamp(UNIX_EPOCH + Duration::from_millis(1_791_446_357_728)), "2026-10-08T07:59:17.728Z");
+        // Leap day, and the day after it.
+        assert_eq!(timestamp(UNIX_EPOCH + Duration::from_secs(1_709_164_800)), "2024-02-29T00:00:00.000Z");
+        assert_eq!(timestamp(UNIX_EPOCH + Duration::from_secs(1_709_251_199)), "2024-02-29T23:59:59.000Z");
+        assert_eq!(timestamp(UNIX_EPOCH + Duration::from_secs(1_709_251_200)), "2024-03-01T00:00:00.000Z");
+        // 2000 is a leap year (divisible by 400), 2100 is not.
+        assert_eq!(timestamp(UNIX_EPOCH + Duration::from_secs(951_782_400)), "2000-02-29T00:00:00.000Z");
+        assert_eq!(timestamp(UNIX_EPOCH + Duration::from_secs(4_107_542_400)), "2100-03-01T00:00:00.000Z");
+        // Before the epoch (a clock set wrong) clamps instead of panicking.
+        assert_eq!(timestamp(UNIX_EPOCH - Duration::from_secs(5)), "1970-01-01T00:00:00.000Z");
+    }
+
+    #[test]
+    fn a_line_carries_time_level_thread_target_and_message() {
+        assert_eq!(
+            format_line("2026-10-08T07:59:17.728Z", log::Level::Info, "main", "vectorcraft", "rendering with Mesa (Vulkan, IntegratedGpu)"),
+            "2026-10-08T07:59:17.728Z INFO  [main] vectorcraft: rendering with Mesa (Vulkan, IntegratedGpu)\n"
+        );
+        // A multi-line message keeps its lines; the record still ends in one newline.
+        assert!(format_line("t", log::Level::Error, "w", "x", "a\nb\n").ends_with("x: a\nb\n"));
+    }
+
+    #[test]
+    fn rotation_keeps_the_previous_logs_and_starts_an_empty_file() {
+        let dir = temp_dir("rotate");
+        for run in 1..=4 {
+            let (path, _file) = rotate(&dir).expect("rotate");
+            assert_eq!(path, dir.join(LOG_FILE));
+            assert_eq!(read(&path), "");
+            std::fs::write(&path, format!("run {run}")).expect("write");
+        }
+        assert_eq!(read(&dir.join(LOG_FILE)), "run 4");
+        assert_eq!(read(&dir.join("vectorcraft.1.log")), "run 3");
+        assert_eq!(read(&dir.join("vectorcraft.2.log")), "run 2");
+        assert!(!dir.join("vectorcraft.3.log").exists(), "only {KEEP} old logs are kept");
+        let _ = std::fs::remove_dir_all(&dir);
+    }
+
+    #[test]
+    fn rotation_into_an_unusable_directory_is_an_error_not_a_panic() {
+        let dir = temp_dir("blocked");
+        std::fs::create_dir_all(dir.parent().expect("parent")).expect("tmp");
+        std::fs::write(&dir, "a file where the directory should be").expect("block");
+        assert!(rotate(&dir).is_err());
+        let _ = std::fs::remove_file(&dir);
+    }
+
+    #[test]
+    fn lines_logged_before_the_file_exists_are_written_when_it_is_attached() {
+        let dir = temp_dir("pending");
+        let (path, file) = rotate(&dir).expect("rotate");
+        let mut sink = Sink::new(MAX_FILE_BYTES);
+        sink.write("early 1\n");
+        sink.write("early 2\n");
+        sink.attach(file);
+        sink.write("late\n");
+        assert_eq!(read(&path), "early 1\nearly 2\nlate\n");
+        let _ = std::fs::remove_dir_all(&dir);
+    }
+
+    #[test]
+    fn the_pending_buffer_is_bounded_and_says_how_much_it_dropped() {
+        let dir = temp_dir("bounded");
+        let (path, file) = rotate(&dir).expect("rotate");
+        let mut sink = Sink::new(MAX_FILE_BYTES);
+        for i in 0..MAX_PENDING + 5 {
+            sink.write(&format!("line {i}\n"));
+        }
+        sink.attach(file);
+        let text = read(&path);
+        assert_eq!(text.lines().filter(|l| l.starts_with("line ")).count(), MAX_PENDING);
+        assert!(text.contains("5 earlier log lines were dropped"), "{text}");
+        assert!(text.contains("line 0\n") && !text.contains(&format!("line {MAX_PENDING}\n")));
+        let _ = std::fs::remove_dir_all(&dir);
+    }
+
+    #[test]
+    fn exactly_a_full_pending_buffer_drops_nothing() {
+        let dir = temp_dir("full");
+        let (path, file) = rotate(&dir).expect("rotate");
+        let mut sink = Sink::new(MAX_FILE_BYTES);
+        for i in 0..MAX_PENDING {
+            sink.write(&format!("line {i}\n"));
+        }
+        sink.attach(file);
+        let text = read(&path);
+        assert_eq!(text.lines().count(), MAX_PENDING);
+        assert!(!text.contains("dropped"), "{text}");
+        let _ = std::fs::remove_dir_all(&dir);
+    }
+
+    #[test]
+    fn without_a_file_nothing_is_kept_in_memory() {
+        let mut sink = Sink::new(MAX_FILE_BYTES);
+        sink.write("early\n");
+        sink.no_file();
+        sink.write("late\n");
+        assert!(sink.pending.is_empty() && sink.dropped == 0);
+    }
+
+    #[test]
+    fn the_file_stops_at_its_size_cap_with_one_note() {
+        let dir = temp_dir("cap");
+        let (path, file) = rotate(&dir).expect("rotate");
+        let mut sink = Sink::new(100);
+        sink.attach(file);
+        for i in 0..50 {
+            sink.write(&format!("line {i:02} with some padding\n"));
+        }
+        let text = read(&path);
+        assert_eq!(text.lines().filter(|l| l.starts_with("line ")).count(), 3, "{text}");
+        assert_eq!(text.matches("log file reached").count(), 1, "{text}");
+        let _ = std::fs::remove_dir_all(&dir);
+    }
+
+    #[test]
+    fn the_logger_filters_records_and_writes_them_to_the_attached_file() {
+        use log::Log;
+        let dir = temp_dir("logger");
+        let logger = AppLogger::new(Filter::parse(DEFAULT_FILTER), false);
+        let record = |level, target: &'static str, msg: &'static str| {
+            logger.log(&log::Record::builder().level(level).target(target).args(format_args!("{msg}")).build());
+        };
+        record(log::Level::Info, "vectorcraft", "before the settings directory");
+        record(log::Level::Info, "wgpu_core::device", "too chatty");
+        let path = logger.attach_dir(&dir).expect("attach");
+        assert_eq!(path, dir.join(LOG_FILE));
+        record(log::Level::Warn, "wgpu_hal::vulkan", "a real warning");
+        record(log::Level::Error, "vectorcraft_engine::guard", "recovered from a panic: boom");
+        record(log::Level::Debug, "vectorcraft", "below info");
+        let text = read(&path);
+        let lines: Vec<&str> = text.lines().collect();
+        assert_eq!(lines.len(), 3, "{text}");
+        assert!(lines[0].contains(" INFO  [") && lines[0].ends_with("vectorcraft: before the settings directory"), "{text}");
+        assert!(lines[1].ends_with("wgpu_hal::vulkan: a real warning"), "{text}");
+        assert!(lines[2].contains(" ERROR [") && lines[2].ends_with("vectorcraft_engine::guard: recovered from a panic: boom"), "{text}");
+        assert!(logger.enabled(&log::Metadata::builder().level(log::Level::Info).target("vectorcraft_ui_egui").build()));
+        assert!(!logger.enabled(&log::Metadata::builder().level(log::Level::Info).target("naga").build()));
+        // Attaching again rotates: the first log becomes `.1`.
+        logger.attach_dir(&dir).expect("attach again");
+        assert_eq!(read(&dir.join("vectorcraft.1.log")), text);
+        let _ = std::fs::remove_dir_all(&dir);
+    }
+
+    #[test]
+    fn records_from_many_threads_are_whole_lines() {
+        use log::Log;
+        let dir = temp_dir("threads");
+        let logger = std::sync::Arc::new(AppLogger::new(Filter::parse("info"), false));
+        let path = logger.attach_dir(&dir).expect("attach");
+        let workers: Vec<_> = (0..8)
+            .map(|t| {
+                let l = std::sync::Arc::clone(&logger);
+                std::thread::spawn(move || {
+                    for i in 0..100 {
+                        l.log(
+                            &log::Record::builder().level(log::Level::Info).target("vectorcraft").args(format_args!("thread {t} record {i}")).build(),
+                        );
+                    }
+                })
+            })
+            .collect();
+        for w in workers {
+            w.join().expect("worker");
+        }
+        let text = read(&path);
+        assert_eq!(text.lines().count(), 800);
+        assert!(text.lines().all(|l| l.contains(" vectorcraft: thread ")), "{text}");
+        let _ = std::fs::remove_dir_all(&dir);
+    }
+
+    #[test]
+    fn attaching_to_an_unusable_directory_reports_an_error_and_keeps_logging() {
+        use log::Log;
+        let dir = temp_dir("unusable");
+        std::fs::create_dir_all(dir.parent().expect("parent")).expect("tmp");
+        std::fs::write(&dir, "not a directory").expect("block");
+        let logger = AppLogger::new(Filter::parse("info"), false);
+        assert!(logger.attach_dir(&dir).is_err());
+        logger.log(&log::Record::builder().level(log::Level::Error).target("x").args(format_args!("still fine")).build());
+        // Nothing waits in memory for a file that won't come.
+        assert!(logger.sink.lock().expect("sink").pending.is_empty());
+        let _ = std::fs::remove_file(&dir);
+    }
+
+    #[test]
+    fn a_poisoned_sink_still_logs() {
+        use log::Log;
+        let dir = temp_dir("poison");
+        let logger = std::sync::Arc::new(AppLogger::new(Filter::parse("info"), false));
+        let l = std::sync::Arc::clone(&logger);
+        let _ = std::thread::spawn(move || {
+            let _guard = l.sink.lock().expect("lock");
+            panic!("poison the sink");
+        })
+        .join();
+        assert!(logger.sink.is_poisoned());
+        let path = logger.attach_dir(&dir).expect("attach");
+        logger.log(&log::Record::builder().level(log::Level::Warn).target("vectorcraft").args(format_args!("after the poison")).build());
+        assert!(read(&path).contains("vectorcraft: after the poison"));
+        let _ = std::fs::remove_dir_all(&dir);
+    }
+}

apps/vectorcraft/src/main.rs

@@ -16,6 +16,7 @@ compile_error!("the win7 target requires --no-default-features --features window
 
 mod clipboard;
 mod control_server;
+mod logging;
 #[cfg(target_os = "macos")]
 mod native_menu;
 #[cfg(target_os = "macos")]
@@ -139,6 +140,11 @@ fn prefs_path_for(name: &str, lower: &str) -> Option<std::path::PathBuf> {
     base.map(|b| b.join("ui.json"))
 }
 
+/// Where the log files live: `logs` in the preferences folder (see `logging`).
+fn log_dir() -> Option<std::path::PathBuf> {
+    Some(prefs_path()?.parent()?.join("logs"))
+}
+
 /// Runs without preferences (`VECTORCRAFT_NO_PREFS`, agents' test runs) neither read nor write them.
 fn prefs_enabled() -> bool {
     std::env::var_os("VECTORCRAFT_NO_PREFS").is_none()
@@ -319,6 +325,8 @@ fn adapter_summary(info: &eframe::wgpu::AdapterInfo) -> String {
 const CUSTOM_TITLEBAR: bool = !cfg!(target_os = "macos");
 
 fn main() -> eframe::Result {
+    // First, so every start-up warning is recorded (`logging`).
+    let logger = logging::install();
     vectorcraft_ui_egui::i18n::detect_system_lang_in_background();
     let mut control_port: Option<u16> = std::env::var("VECTORCRAFT_CONTROL_PORT").ok().and_then(|p| p.parse().ok());
     let mut files = Vec::new();
@@ -333,6 +341,20 @@ fn main() -> eframe::Result {
             _ => files.push(a),
         }
     }
+    // The log file lives in the settings directory, next to the preferences; opened after the
+    // arguments, so `--version` leaves no file behind. Records logged until now are written to it
+    // first. Runs without preferences (agents' test runs) log to standard error only, so they
+    // don't rotate away the user's own logs.
+    if let Some(logger) = logger {
+        match log_dir().filter(|_| prefs_enabled()) {
+            Some(dir) => match logger.attach_dir(&dir) {
+                Ok(path) => log::info!("VectorCraft {}, log file {}", env!("CARGO_PKG_VERSION"), path.display()),
+                // Standard error only by now (`attach_dir` gave up on the file); unlike `eprintln!`, never panics.
+                Err(e) => log::warn!("no log file: {e}"),
+            },
+            None => logger.no_file(),
+        }
+    }
     let saved = read_prefs();
     let saved_window = saved.as_ref().and_then(|ui| ui.window);
     #[cfg(feature = "wgpu")]
@@ -394,7 +416,7 @@ fn main() -> eframe::Result {
             #[cfg(feature = "wgpu")]
             if let Some(rs) = &cc.wgpu_render_state {
                 let summary = adapter_summary(&rs.adapter.get_info());
-                log::info!("vectorcraft: rendering with {summary} (power preference {power:?})");
+                log::info!("rendering with {summary} (power preference {power:?})");
                 app.graphics_adapter = Some(summary);
                 let (loss, ctx) = (graphics_loss.clone(), cc.egui_ctx.clone());
                 rs.device.set_device_lost_callback(move |reason, msg| loss.report(&ctx, format!("{reason:?}: {msg}")));

apps/vectorcraft/src/open_documents.rs

@@ -59,7 +59,7 @@ pub fn take() -> Vec<String> {
 fn add_open_urls_method() {
     let Some(mtm) = MainThreadMarker::new() else { return };
     let Some(delegate) = NSApplication::sharedApplication(mtm).delegate() else {
-        log::warn!("vectorcraft: no application delegate; files opened from Finder won't open");
+        log::warn!("no application delegate; files opened from Finder won't open");
         return;
     };
     let class = AsRef::<AnyObject>::as_ref(&*delegate).class();
@@ -72,7 +72,7 @@ fn add_open_urls_method() {
         objc2::ffi::class_addMethod(std::ptr::from_ref(class).cast_mut(), sel!(application:openURLs:), imp, c"v@:@@".as_ptr())
     };
     if !added.as_bool() {
-        log::warn!("vectorcraft: the application delegate already handles open-document events");
+        log::warn!("the application delegate already handles open-document events");
     }
 }
 

docs/development.md

@@ -42,6 +42,21 @@ The canvas is rasterized on the CPU (`vectorcraft-render`, vello_cpu); the GPU (
 - The `WGPU_POWER_PREF` environment variable (`low`, `high` or `none`) overrides the preference.
 - Help › About and the control channel's `ui.inspect` (`graphicsAdapter`) show the adapter in use, and the app logs it at startup.
 
+## Logs
+
+The desktop app writes its `log` records to standard error and to `logs/vectorcraft.log` next to the preferences (Linux `$XDG_CONFIG_HOME/vectorcraft/logs/`, by default `~/.config/vectorcraft/logs/`; macOS `~/Library/Application Support/VectorCraft/logs/`; Windows `%APPDATA%\VectorCraft\logs\`). A start launched from a desktop menu or the Dock has no terminal, so this file is what to attach to a bug report: the graphics adapter in use, a lost graphics device, panics the engine's guard recovered from and clipboard formats that couldn't be made land there. Each launch moves the previous log to `vectorcraft.1.log` (and that one to `vectorcraft.2.log`), so the log of a run that crashed survives the next start. The file stops growing at 16 MiB. `--version` writes no file, and runs with `VECTORCRAFT_NO_PREFS` log to standard error only.
+
+By default VectorCraft's own crates log at `info` and everything else at `warn`. `RUST_LOG` replaces that with env_logger-style directives, for example `RUST_LOG=debug`, `RUST_LOG=warn,vectorcraft_render=trace` or `RUST_LOG=info,wgpu_core=warn`; a directive ending in `*` covers every target starting with it (`vectorcraft*=debug`). The logger is `apps/vectorcraft/src/logging.rs`. `vectorcraft-cli mcp` has its own logger, which sends records to the MCP client (`docs/mcp.md`).
+
+## Environment variables (desktop app)
+
+| Variable | Effect |
+|---|---|
+| `VECTORCRAFT_CONTROL_PORT` | Same as `--control <port>` |
+| `VECTORCRAFT_NO_PREFS` | No preferences read or written, no default Data Recovery folder and no log file (agents' test runs) |
+| `WGPU_POWER_PREF` | Graphics adapter: `low`, `high` or `none` (see [Desktop graphics processor](#desktop-graphics-processor)) |
+| `RUST_LOG` | Log levels for standard error and the log file (see [Logs](#logs)) |
+
 ## Linux: Wayland and X11
 
 The window runs natively on Wayland (eframe's `wayland` feature) and on X11. The system clipboard (`apps/vectorcraft/src/clipboard.rs`) is arboard with its `wayland-data-control` feature: