|
|
|
|
@ -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.<KEEP>.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<Vec<(Option<String>, LevelFilter)>> = OnceLock::new();
|
|
|
|
|
/// The filter for standard error and the session log: (target prefix or every target, level).
|
|
|
|
|
static FILTER: OnceLock<Vec<(Option<String>, LevelFilter)>> = OnceLock::new();
|
|
|
|
|
static STATE: Mutex<State> = Mutex::new(State { file: None, recent: VecDeque::new() });
|
|
|
|
|
static SESSION: Mutex<Sink> = Mutex::new(Sink::new(MAX_FILE_BYTES));
|
|
|
|
|
|
|
|
|
|
struct State {
|
|
|
|
|
file: Option<PathBuf>,
|
|
|
|
|
@ -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): `<timestamp> <LEVEL> [<thread>] <target>: <message>`.
|
|
|
|
|
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` → … → `.<KEEP>.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<PathBuf, String> {
|
|
|
|
|
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<PathBuf> {
|
|
|
|
|
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<File>,
|
|
|
|
|
path: Option<PathBuf>,
|
|
|
|
|
pending: Vec<String>,
|
|
|
|
|
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<PathBuf> {
|
|
|
|
|
STATE.lock().ok().and_then(|s| s.file.clone())
|
|
|
|
|
}
|
|
|
|
|
@ -148,7 +314,8 @@ pub fn recent() -> Vec<String> {
|
|
|
|
|
|
|
|
|
|
#[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"
|
|
|
|
|
);
|
|
|
|
|
}
|
|
|
|
|
}
|
|
|
|
|
|
Brandon Thomas