diff --git a/apps/effectcraft/src/audio_out.rs b/apps/effectcraft/src/audio_out.rs index 7d0ec4b2..b4bdebb3 100644 --- a/apps/effectcraft/src/audio_out.rs +++ b/apps/effectcraft/src/audio_out.rs @@ -117,7 +117,7 @@ fn run>( let dev_lat = ts.playback.duration_since(&ts.callback).map(|d| d.as_secs_f64()).unwrap_or(0.0); latency.store((dev_lat * rate) as u64 + frames as u64, Ordering::Relaxed); }, - |e| eprintln!("effectcraft: audio output: {e}"), + |e| log::warn!("audio output: {e}"), None, ) .map_err(|e| e.to_string()) @@ -187,7 +187,7 @@ impl AudioDevice for CpalOut { return; } if let Err(e) = stream.play() { - eprintln!("effectcraft: audio output: {e}"); + log::warn!("audio output: {e}"); return; } let _ = stop_rx.recv(); diff --git a/apps/effectcraft/src/control_server.rs b/apps/effectcraft/src/control_server.rs index e5af3999..0ae8bfab 100644 --- a/apps/effectcraft/src/control_server.rs +++ b/apps/effectcraft/src/control_server.rs @@ -27,11 +27,11 @@ pub fn start(port: u16, ctx: egui::Context) -> Receiver { let listener = match TcpListener::bind(("127.0.0.1", port)) { Ok(l) => l, Err(e) => { - eprintln!("effectcraft: control server failed to bind 127.0.0.1:{port}: {e}"); + log::error!("control server failed to bind 127.0.0.1:{port}: {e}"); return rx; } }; - eprintln!("effectcraft: control server listening on 127.0.0.1:{port}"); + log::info!("control server listening on 127.0.0.1:{port}"); std::thread::spawn(move || accept_loop(listener, tx, ctx)); rx } diff --git a/apps/effectcraft/src/main.rs b/apps/effectcraft/src/main.rs index 1b5f74f3..3b7d266b 100644 --- a/apps/effectcraft/src/main.rs +++ b/apps/effectcraft/src/main.rs @@ -88,13 +88,24 @@ fn parse_args(args: impl IntoIterator, env_port: Option) } fn main() -> eframe::Result { - // Help ▸ Enable Logging writes through this logger; warnings feed the compatibility report. + // First, so the panic hook and every start-up warning are recorded. Records go to stderr + // and the session log; Help ▸ Enable Logging writes through this logger too, and warnings + // feed the compatibility report. effectcraft_engine::logging::install(); effectcraft_engine::logging::install_panic_hook(); let Some(Args { control_port, files, demo, home }) = parse_args(std::env::args().skip(1), std::env::var("EFFECTCRAFT_CONTROL_PORT").ok()) else { println!("effectcraft {}", env!("CARGO_PKG_VERSION")); return Ok(()); }; + // The session log lives in the settings folder (`Logs/effectcraft.log`, the previous two runs + // kept): a launch from the Dock or a menu has no terminal. Opened after the arguments, so + // `--version` leaves no file behind; records logged until now are written to it first. + if let Some(dir) = effectcraft_host::config_dir() { + match effectcraft_engine::logging::attach_session_log(&effectcraft_engine::logging::log_dir(Some(&dir))) { + Ok(path) => log::info!("effectcraft {}, log file {}", env!("CARGO_PKG_VERSION"), path.display()), + Err(e) => log::warn!("no log file: {e}"), + } + } // The font menus list the installed fonts: read their names while the window opens. effectcraft_engine::text::fonts::scan_system_in_background(); // Wayland shows the window's icon from its desktop entry: an AppImage brings its own. @@ -120,8 +131,8 @@ fn main() -> eframe::Result { wgpu_options: wgpu_options(launch.backends), ..Default::default() }; - // Start-up milestones: with `RUST_LOG=info` they go to stderr, so a window that never - // appears shows how far start-up got (#234). + // Start-up milestones go to stderr and the session log, so a window that never appears + // shows how far start-up got (#234). log::info!("effectcraft {}: opening the window", env!("CARGO_PKG_VERSION")); // Registered before the event loop starts, so it catches the Finder event that launched us as // well as later ones. Lives until the event loop returns; the app creator only borrows it. @@ -174,7 +185,7 @@ fn main() -> eframe::Result { let project = files.iter().find(|f| is_project_file(f)).cloned(); if let Some(p) = project { if let Err(e) = session.execute("file.open", json!({"path": p})) { - eprintln!("effectcraft: {e}"); + log::warn!("{p}: {e}"); } } else if demo { let _ = session.execute("file.openDemoProject", json!({})); @@ -183,7 +194,7 @@ fn main() -> eframe::Result { if !media.is_empty() && let Err(e) = session.execute("file.import", json!({"paths": media})) { - eprintln!("effectcraft: {e}"); + log::warn!("import: {e}"); } let show_home = home.unwrap_or(session.prefs.startup.show_home_on_launch && files.is_empty() && control_port.is_none()); // The ScriptUI panels open when the app last quit open again (a failing one is @@ -315,8 +326,12 @@ fn startup_failed(e: &eframe::Error, gl_next: bool) { let message = format!( "EffectCraft couldn't start its window: {e}\n\n{next}Updating the graphics driver often helps. If it keeps happening, please report it at https://github.com/storytold/effectcraft/issues with this message." ); - log::error!("{message}"); - eprintln!("effectcraft: {message}"); + // Standard error and the session log; standard error alone when RUST_LOG turned errors off. + if log::log_enabled!(log::Level::Error) { + log::error!("{message}"); + } else { + eprintln!("effectcraft: {message}"); + } let _ = rfd::MessageDialog::new() .set_level(rfd::MessageLevel::Error) .set_title("EffectCraft") diff --git a/crates/engine/src/commands/app_more.rs b/crates/engine/src/commands/app_more.rs index b6101c5a..86db00ec 100644 --- a/crates/engine/src/commands/app_more.rs +++ b/crates/engine/src/commands/app_more.rs @@ -288,7 +288,12 @@ fn enable_logging(s: &mut Session, p: &Value) -> Result { } fn reveal_log(s: &mut Session, _: &Value) -> Result { - let file = crate::logging::current_file().unwrap_or_else(|| log_file(s)); + // Enable Logging's file while it is on, else this run's session log. + let file = crate::logging::current_file() + .filter(|_| crate::logging::is_enabled()) + .or_else(crate::logging::session_file) + .or_else(crate::logging::current_file) + .unwrap_or_else(|| log_file(s)); let path = file.to_string_lossy().to_string(); let url = super::layer_menu::folder_url(&path); s.events.push(Event::OpenUrl(url.clone())); diff --git a/crates/engine/src/logging.rs b/crates/engine/src/logging.rs index f5750372..2c89466a 100644 --- a/crates/engine/src/logging.rs +++ b/crates/engine/src/logging.rs @@ -1,25 +1,47 @@ -//! Help ▸ Enable Logging / Reveal Logging File: a `log` logger that, while enabled, appends -//! every record to `Logs/EffectCraft Log.txt` in the settings folder (or the temporary folder), -//! and always keeps the last few hundred warnings and errors in memory for the System -//! Compatibility Report. +//! The `log` logger. Records go to standard error and, on the desktop, to a session log that +//! every launch starts afresh: `Logs/effectcraft.log` in the settings folder, with the two runs +//! before it kept as `effectcraft.1.log` and `effectcraft.2.log`, so the log of a run that +//! crashed survives the next start. A launch from the Dock, the Start menu or a launcher has no +//! terminal, so that file is what a bug report can attach. The last few hundred warnings and +//! errors are also kept in memory for the System Compatibility Report. //! -//! Frontends call [`install`] once at startup; [`set_enabled`] (the `help.enableLogging` -//! command) turns file logging on and off. `RUST_LOG` (a level such as `debug`, or per target: -//! `effectcraft=debug,wgpu=warn`) also prints what it lets through to stderr, so a start-up that -//! fails before the window opens leaves a trace. +//! Levels: `info` for EffectCraft's own crates, `warn` for everything else (wgpu and naga are +//! chatty). `RUST_LOG` replaces that (a level such as `debug`, or per target: +//! `effectcraft=debug,wgpu=warn`). +//! +//! Help ▸ Enable Logging ([`set_enabled`], the `help.enableLogging` command) additionally appends +//! every EffectCraft record to `Logs/EffectCraft Log.txt`, across launches. +//! +//! Frontends call [`install`] once at startup and the desktop app [`attach_session_log`] once the +//! settings folder is known; records logged before that are kept (up to [`MAX_PENDING`]) and +//! written first. Writing never panics: a file that can't be created or written leaves standard +//! error as the only sink. Never log the control-channel token. use std::collections::VecDeque; +use std::fs::File; use std::io::Write; use std::path::{Path, PathBuf}; use std::sync::atomic::{AtomicBool, Ordering}; -use std::sync::{Mutex, OnceLock}; +use std::sync::{Mutex, OnceLock, PoisonError}; use log::LevelFilter; +/// The session log's name inside the `Logs` folder. +pub const SESSION_LOG: &str = "effectcraft.log"; +/// How many previous session logs are kept (`effectcraft.1.log` … `effectcraft..log`). +pub const KEEP: usize = 2; +/// The session log 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 session log is attached. +pub const MAX_PENDING: usize = 512; +/// The filter when `RUST_LOG` is unset or empty. +pub const DEFAULT_FILTER: &str = "warn,effectcraft=info"; + static ENABLED: AtomicBool = AtomicBool::new(false); -/// The `RUST_LOG` filter for stderr: (target prefix or every target, level). -static STDERR: OnceLock, LevelFilter)>> = OnceLock::new(); +/// The filter for standard error and the session log: (target prefix or every target, level). +static FILTER: OnceLock, LevelFilter)>> = OnceLock::new(); static STATE: Mutex = Mutex::new(State { file: None, recent: VecDeque::new() }); +static SESSION: Mutex = Mutex::new(Sink::new(MAX_FILE_BYTES)); struct State { file: Option, @@ -32,15 +54,16 @@ const RECENT: usize = 300; impl log::Log for Logger { fn enabled(&self, m: &log::Metadata) -> bool { - m.level() <= log::Level::Warn || (ENABLED.load(Ordering::Relaxed) && m.target().starts_with("effectcraft")) || to_stderr(m) + m.level() <= log::Level::Warn || (ENABLED.load(Ordering::Relaxed) && m.target().starts_with("effectcraft")) || shown(m) } fn log(&self, r: &log::Record) { if !self.enabled(r.metadata()) { return; } - let line = format!("{} {:<5} {}: {}", unix_secs(), r.level(), r.target(), r.args()); - if to_stderr(r.metadata()) { - eprintln!("{line}"); + let line = format_line(×tamp(unix_millis()), r.level(), &thread_name(), r.target(), &r.args().to_string()); + if shown(r.metadata()) { + let _ = writeln!(std::io::stderr(), "{line}"); + SESSION.lock().unwrap_or_else(PoisonError::into_inner).write(&format!("{line}\n")); } let Ok(mut st) = STATE.lock() else { return }; if r.level() <= log::Level::Warn { @@ -59,22 +82,62 @@ impl log::Log for Logger { fn flush(&self) {} } -fn unix_secs() -> u64 { - web_time::SystemTime::now().duration_since(web_time::UNIX_EPOCH).map(|d| d.as_secs()).unwrap_or(0) +fn unix_millis() -> u64 { + web_time::SystemTime::now().duration_since(web_time::UNIX_EPOCH).map(|d| u64::try_from(d.as_millis()).unwrap_or(u64::MAX)).unwrap_or(0) +} + +fn thread_name() -> String { + #[cfg(not(target_arch = "wasm32"))] + return std::thread::current().name().unwrap_or("?").to_string(); + #[cfg(target_arch = "wasm32")] + return "main".to_string(); +} + +/// `2026-10-08T07:59:17.728Z` (UTC, milliseconds) for `ms` milliseconds since 1970. +fn timestamp(ms: u64) -> String { + let secs = ms / 1000; + 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, ms % 1000) +} + +/// Days since 1970-01-01 to a proleptic Gregorian (year, month, day) (Howard Hinnant's +/// `civil_from_days`, unsigned since the clock is clamped at the epoch). `days` is at most +/// `u64::MAX / 86_400_000`, so none of the arithmetic below can overflow. +fn civil_from_days(days: u64) -> (u64, u64, u64) { + let z = days + 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 = yoe + era * 400 + u64::from(m <= 2); + (y, m, d) +} + +/// One log line (without the newline): ` [] : `. +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}") } /// Install the logger (once; later calls and other installed loggers are left alone). pub fn install() { static LOGGER: Logger = Logger; if log::set_logger(&LOGGER).is_ok() { - let stderr = STDERR.get_or_init(|| std::env::var("RUST_LOG").map(|s| parse_filter(&s)).unwrap_or_default()); - log::set_max_level(stderr.iter().map(|d| d.1).fold(LevelFilter::Info, Ord::max)); + let filter = FILTER.get_or_init(|| { + let spec = std::env::var("RUST_LOG").ok().filter(|s| !s.trim().is_empty()); + parse_filter(spec.as_deref().unwrap_or(DEFAULT_FILTER)) + }); + log::set_max_level(filter.iter().map(|d| d.1).fold(LevelFilter::Info, Ord::max)); } } -/// Whether `RUST_LOG` lets a record through to stderr. -fn to_stderr(m: &log::Metadata) -> bool { - STDERR.get().is_some_and(|f| m.level() <= level_for(f, m.target())) +/// Whether the filter lets a record through to standard error and the session log. +fn shown(m: &log::Metadata) -> bool { + FILTER.get().is_some_and(|f| m.level() <= level_for(f, m.target())) } /// `RUST_LOG`'s directives, as env_logger reads them: `level`, `target=level` or a bare target @@ -110,9 +173,112 @@ pub fn install_panic_hook() { })); } -/// The log file inside `config_dir` (the settings folder), or the temporary folder. +/// The `Logs` folder inside `config_dir` (the settings folder), or in the temporary folder. +pub fn log_dir(config_dir: Option<&Path>) -> PathBuf { + config_dir.map(Path::to_path_buf).unwrap_or_else(std::env::temp_dir).join("Logs") +} + +/// Help ▸ Enable Logging's file inside `config_dir` (the settings folder), or the temporary folder. pub fn log_path(config_dir: Option<&Path>) -> PathBuf { - config_dir.map(Path::to_path_buf).unwrap_or_else(std::env::temp_dir).join("Logs").join("EffectCraft Log.txt") + log_dir(config_dir).join("EffectCraft Log.txt") +} + +fn numbered(dir: &Path, n: usize) -> PathBuf { + if n == 0 { dir.join(SESSION_LOG) } else { dir.join(format!("effectcraft.{n}.log")) } +} + +/// Shift the previous session logs up one (`.log` → `.1.log` → … → `..log`, the oldest +/// dropped) and create a fresh, empty log file in `dir` (created if missing). +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)) +} + +/// Rotate the session logs in `dir` (the `Logs` folder, see [`log_dir`]) and write records to +/// a fresh `effectcraft.log` there, first the ones logged so far; returns its path. +pub fn attach_session_log(dir: &Path) -> Result { + let (path, file) = rotate(dir).map_err(|e| format!("{}: {e}", dir.display()))?; + let mut sink = SESSION.lock().unwrap_or_else(PoisonError::into_inner); + sink.attach(file); + sink.path = Some(path.clone()); + Ok(path) +} + +/// This run's session log (once [`attach_session_log`] succeeded). +pub fn session_file() -> Option { + SESSION.lock().unwrap_or_else(PoisonError::into_inner).path.clone() +} + +/// Where lines go besides standard error: kept in memory until a file is attached, then +/// appended to it until it reaches its size cap. +struct Sink { + file: Option, + path: Option, + pending: Vec, + dropped: usize, + written: u64, + max_bytes: u64, + capped: bool, +} + +impl Sink { + const fn new(max_bytes: u64) -> Sink { + Sink { file: None, path: None, pending: Vec::new(), dropped: 0, written: 0, max_bytes, capped: false } + } + + /// Append `line` to the file, or keep it until [`Sink::attach`]. + fn write(&mut self, line: &str) { + if self.file.is_none() && !self.capped { + 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`, first the lines kept so far. + fn attach(&mut self, file: File) { + self.file = Some(file); + 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(¬e); + } + } + + 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; + } + } } /// Turn file logging on (writing to `file`) or off. @@ -123,7 +289,7 @@ pub fn set_enabled(on: bool, file: PathBuf) -> std::io::Result<()> { std::fs::create_dir_all(d)?; } let mut f = std::fs::OpenOptions::new().create(true).append(true).open(&file)?; - writeln!(f, "{} INFO effectcraft: logging enabled ({} {})", unix_secs(), std::env::consts::OS, env!("CARGO_PKG_VERSION"))?; + writeln!(f, "{} INFO effectcraft: logging enabled ({} {})", timestamp(unix_millis()), std::env::consts::OS, env!("CARGO_PKG_VERSION"))?; } if let Ok(mut st) = STATE.lock() { st.file = Some(file); @@ -136,7 +302,7 @@ pub fn is_enabled() -> bool { ENABLED.load(Ordering::Relaxed) } -/// The current log file (set once logging was enabled). +/// The current Enable Logging file (set once logging was enabled). pub fn current_file() -> Option { STATE.lock().ok().and_then(|s| s.file.clone()) } @@ -148,7 +314,8 @@ pub fn recent() -> Vec { #[cfg(test)] mod tests { - use super::{LevelFilter, level_for, parse_filter}; + use super::*; + use std::sync::atomic::AtomicUsize; /// `RUST_LOG` picks what start-up prints to stderr (#234). #[test] @@ -162,4 +329,111 @@ mod tests { assert_eq!(level_for(&parse_filter("wgpu=debug"), "winit"), LevelFilter::Off); assert!(parse_filter("").is_empty()); } + + fn temp_dir(tag: &str) -> PathBuf { + static N: AtomicUsize = AtomicUsize::new(0); + let d = std::env::temp_dir().join(format!("effectcraft-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).unwrap() + } + + /// Without `RUST_LOG`, EffectCraft's own info records and everyone's warnings are shown. + #[test] + fn the_default_filter_shows_effectcraft_info_and_other_crates_warnings() { + let f = parse_filter(DEFAULT_FILTER); + assert_eq!(level_for(&f, "effectcraft"), LevelFilter::Info); + assert_eq!(level_for(&f, "effectcraft_ui_egui::app"), LevelFilter::Info); + assert_eq!(level_for(&f, "wgpu_core::device"), LevelFilter::Warn); + assert_eq!(level_for(&f, "naga"), LevelFilter::Warn); + } + + #[test] + fn timestamps_are_utc_with_milliseconds() { + assert_eq!(timestamp(0), "1970-01-01T00:00:00.000Z"); + assert_eq!(timestamp(1_791_446_357_728), "2026-10-08T07:59:17.728Z"); + assert_eq!(timestamp(1_709_164_800_000), "2024-02-29T00:00:00.000Z"); + assert_eq!(timestamp(951_782_400_000), "2000-02-29T00:00:00.000Z"); + assert_eq!(timestamp(1_767_225_599_000), "2025-12-31T23:59:59.000Z"); + let _ = timestamp(u64::MAX); + } + + /// Each launch keeps the previous runs' logs, so the log of a run that crashed survives. + #[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).unwrap(); + assert_eq!(path, dir.join(SESSION_LOG)); + assert_eq!(read(&path), ""); + std::fs::write(&path, format!("run {run}")).unwrap(); + } + assert_eq!(read(&dir.join(SESSION_LOG)), "run 4"); + assert_eq!(read(&dir.join("effectcraft.1.log")), "run 3"); + assert_eq!(read(&dir.join("effectcraft.2.log")), "run 2"); + assert!(!dir.join("effectcraft.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::write(&dir, "a file where the directory should be").unwrap(); + 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).unwrap(); + 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).unwrap(); + 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_eq!(text.matches("5 earlier log lines were dropped").count(), 1, "{text}"); + let _ = std::fs::remove_dir_all(&dir); + } + + #[test] + fn the_file_stops_at_its_size_cap_with_one_note() { + let dir = temp_dir("cap"); + let (path, file) = rotate(&dir).unwrap(); + 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!(text.lines().filter(|l| l.starts_with("line ")).count() < 5, "{text}"); + assert_eq!(text.matches("log file reached").count(), 1, "{text}"); + let _ = std::fs::remove_dir_all(&dir); + } + + #[test] + fn a_line_carries_time_level_thread_target_and_message() { + assert_eq!( + format_line("2026-10-08T07:59:17.728Z", log::Level::Warn, "main", "effectcraft_engine::autosave", "disk full\n"), + "2026-10-08T07:59:17.728Z WARN [main] effectcraft_engine::autosave: disk full" + ); + } } diff --git a/docs/preferences.md b/docs/preferences.md index 157eca99..de41cd17 100644 --- a/docs/preferences.md +++ b/docs/preferences.md @@ -223,3 +223,17 @@ checkpoint after a client restart. Commands: `file.autoSave` (now), `file.recoveryInfo`, `file.openRecent {index? | path?}`, `file.clearRecent`, `file.revert`, `file.incrementAndSave`. + +## Logs + +The desktop app writes its log records to standard error and to `Logs/effectcraft.log` in the +config directory. Each launch moves the previous log to `effectcraft.1.log` (and that one to +`effectcraft.2.log`), so the log of a run that crashed survives the next start; a log stops +growing at 16 MiB. A launch from the Dock, the Start menu or a launcher has no terminal, so +attach these files to a bug report. Help ▸ Reveal Logging File shows this run's log (or Help ▸ +Enable Logging's `EffectCraft Log.txt` while that is on, which keeps every EffectCraft record +across launches). + +By default the log has `info` records from EffectCraft and warnings and errors from everything +else. `RUST_LOG` replaces that with env_logger-style directives: `debug`, +`warn,effectcraft_render=trace`, `wgpu_core=info`. The control-channel token is never logged.