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

The desktop app installed no logger, so every log::warn!/log::error! in
the workspace was discarded: the graphics adapter in use, a lost graphics
device, the engine guard's report of a recovered panic. A launch from a
desktop menu has no terminal either, so there was nothing to attach to a
bug report.

apps/vectorcraft/src/logging.rs (no new dependency):
- standard error plus logs/vectorcraft.log next to the preferences
  (~/.config/vectorcraft/logs, or under $XDG_CONFIG_HOME); each launch
  rotates the previous log to vectorcraft.1.log and .2.log, so the log of
  a run that crashed survives the next start; the file is capped at 16 MiB
- records logged before the settings directory is known are buffered
  (bounded) and written once the file is attached
- default levels: info for vectorcraft*, warn for everything else;
  RUST_LOG replaces them with env_logger-style directives
- never panics: an unusable directory or a failed write leaves standard
  error as the only sink
- runs with VECTORCRAFT_NO_PREFS (agents' test runs) log to standard
  error only, so they don't rotate away the user's own logs

The logger is installed first in main and the file is opened after
argument parsing (--version leaves no file). Log messages of this crate
drop their "vectorcraft: " prefix, which the record's target now shows.
vectorcraft-cli keeps its own MCP logger (vectorcraft_mcp::logging).
Documented in docs/development.md (Logs, Environment variables).

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,19 @@ 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()),
+                Err(e) => eprintln!("vectorcraft: 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 +415,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: