Desktop: write log records to standard error and a rotating log file (#122)
* 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 crash guard's panic report, a failed crash-recovery save, font folders that can't be read. A launch from a desktop menu has no terminal either, so there was nothing to attach to a bug report. apps/designcraft/src/logging.rs (no new dependency): - standard error plus <settings dir>/logs/designcraft.log (beside ui.json and prefs.json); each launch rotates the previous log to designcraft.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 designcraft*, 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 The logger is installed first in main (before the engine's panic hook) and the file is opened after argument parsing (--version leaves no file). The settings directory moves out of prefs_path into config_dir. A --control or DESIGNCRAFT_CONTROL_PORT value that is not a port is now logged instead of silently leaving the control channel off. Documented in README.md (Quick start > Logs). * Desktop: no eprintln! on the log and panic paths eprintln! panics when standard error is a broken pipe (a GUI launch on Windows), and a panic inside the panic hook aborts. The "no log file" message goes through log::warn! (standard error only by then); the panic hook's fallback writes to standard error with write_fmt and ignores the error. Same fix as storytold/vectorcraft#465.
This commit is contained in:
Gert Pellin - GPE
GitHub
parent
5369687497
commit
3d2bda4d6b
17
README.md
17
README.md
|
|
@ -123,6 +123,23 @@ include it.
|
|||
To drive a running app, send JSON lines to `127.0.0.1:7979`. The protocol is described in
|
||||
[`docs/control-protocol.md`](docs/control-protocol.md).
|
||||
|
||||
### Logs
|
||||
|
||||
The desktop app writes its `log` records to standard error and to `logs/designcraft.log` in the
|
||||
settings directory, beside `ui.json` and `prefs.json` (Linux `~/.config/designcraft/logs/`, or
|
||||
`$XDG_CONFIG_HOME/designcraft/logs/`; macOS `~/Library/Application Support/DesignCraft/logs/`;
|
||||
Windows `%APPDATA%\DesignCraft\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 crash guard's panic report and a
|
||||
failed crash-recovery save land there. Each launch moves the previous log to `designcraft.1.log`
|
||||
(and that one to `designcraft.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.
|
||||
|
||||
| Variable | Effect |
|
||||
|---|---|
|
||||
| `RUST_LOG` | Log levels for standard error and the log file. Default: `info` for DesignCraft's own crates, `warn` for everything else. env_logger-style directives replace that, e.g. `RUST_LOG=debug`, `RUST_LOG=warn,designcraft_render=trace` or `RUST_LOG=info,wgpu_core=warn`; a directive ending in `*` covers every target starting with it (`designcraft*=debug`). |
|
||||
|
||||
The logger is `apps/designcraft/src/logging.rs`; the web build logs to the browser console instead.
|
||||
|
||||
### Web
|
||||
|
||||
```sh
|
||||
|
|
|
|||
|
|
@ -0,0 +1,437 @@
|
|||
//! 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 crash guard's panic
|
||||
//! report, a failed crash-recovery save, font folders that can't be read) vanished. A launch from
|
||||
//! a desktop menu has no terminal, so the file is what a bug report can attach:
|
||||
//! `<settings dir>/logs/designcraft.log` (the directory beside `ui.json` and `prefs.json`, see
|
||||
//! `config_dir` in `main.rs`). Each start moves the previous log to `designcraft.1.log` (and that
|
||||
//! one to `.2`), so the log of a run that crashed survives the next launch.
|
||||
//!
|
||||
//! Levels: `info` for DesignCraft's own crates, `warn` for everything else (wgpu and naga are
|
||||
//! chatty). `RUST_LOG` replaces that with env_logger-style directives: `debug`,
|
||||
//! `warn,designcraft_render=trace`, `wgpu_core=info`. A directive ending in `*` matches every
|
||||
//! target that starts with it (`designcraft*=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.
|
||||
|
||||
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 = "designcraft.log";
|
||||
/// How many previous logs are kept (`designcraft.1.log` … `designcraft.<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,designcraft*=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).
|
||||
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)
|
||||
}
|
||||
|
||||
fn numbered(dir: &Path, n: usize) -> PathBuf {
|
||||
if n == 0 { dir.join(LOG_FILE) } else { dir.join(format!("designcraft.{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.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.
|
||||
pub 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;
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
/// 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.
|
||||
pub fn attach_dir(&self, dir: &Path) -> Result<PathBuf, String> {
|
||||
let (path, file) = rotate(dir).map_err(|e| format!("{}: {e}", dir.display()))?;
|
||||
self.sink.lock().unwrap_or_else(PoisonError::into_inner).attach(file);
|
||||
Ok(path)
|
||||
}
|
||||
}
|
||||
|
||||
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;
|
||||
}
|
||||
let thread = std::thread::current();
|
||||
let line =
|
||||
format_line(×tamp(SystemTime::now()), record.level(), thread.name().unwrap_or("?"), record.target(), &record.args().to_string());
|
||||
if self.stderr {
|
||||
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!("designcraft-logging-{tag}-{}-{}", std::process::id(), N.fetch_add(1, Ordering::Relaxed)));
|
||||
let _ = std::fs::remove_dir_all(&d);
|
||||
d
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn the_default_filter_shows_designcraft_info_and_other_crates_warnings() {
|
||||
let f = Filter::parse(DEFAULT_FILTER);
|
||||
assert_eq!(f.level_for("designcraft"), LevelFilter::Info);
|
||||
assert_eq!(f.level_for("designcraft::control_server"), LevelFilter::Info);
|
||||
assert_eq!(f.level_for("designcraft_render::tile"), 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,designcraft_render=trace,designcraft_render::tile=off");
|
||||
assert_eq!(f.level_for("eframe"), LevelFilter::Info);
|
||||
assert_eq!(f.level_for("wgpu_core::instance"), LevelFilter::Error);
|
||||
assert_eq!(f.level_for("designcraft_render::raster"), LevelFilter::Trace);
|
||||
assert_eq!(f.level_for("designcraft_render::tile"), 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 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);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn hostile_specs_never_panic_and_fall_back_sensibly() {
|
||||
for spec in ["", ",,,", "=", "=debug", "designcraft=", "nonsense=loud", "🦀=info", "*", "a=b=c", "warn,,designcraft=DEBUG"] {
|
||||
let f = Filter::parse(spec);
|
||||
let _ = f.level_for("designcraft");
|
||||
let _ = f.max();
|
||||
}
|
||||
assert_eq!(Filter::parse("warn,,designcraft=DEBUG").level_for("designcraft"), LevelFilter::Debug);
|
||||
assert_eq!(Filter::parse("nonsense=loud").level_for("nonsense"), LevelFilter::Error);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn timestamps_are_utc_with_milliseconds() {
|
||||
assert_eq!(timestamp(UNIX_EPOCH), "1970-01-01T00:00:00.000Z");
|
||||
// 2026-10-08T07:59:17.728Z
|
||||
assert_eq!(timestamp(UNIX_EPOCH + Duration::from_millis(1_791_446_357_728)), "2026-10-08T07:59:17.728Z");
|
||||
// Leap days, including the century rule (2000 is a leap year, 2100 is not).
|
||||
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(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");
|
||||
assert_eq!(timestamp(UNIX_EPOCH + Duration::from_millis(1_704_067_199_999)), "2023-12-31T23:59:59.999Z");
|
||||
// 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 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!(std::fs::read_to_string(&path).expect("read"), "");
|
||||
std::fs::write(&path, format!("run {run}")).expect("write");
|
||||
}
|
||||
assert_eq!(std::fs::read_to_string(dir.join(LOG_FILE)).expect("current"), "run 4");
|
||||
assert_eq!(std::fs::read_to_string(dir.join("designcraft.1.log")).expect("1"), "run 3");
|
||||
assert_eq!(std::fs::read_to_string(dir.join("designcraft.2.log")).expect("2"), "run 2");
|
||||
assert!(!dir.join("designcraft.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);
|
||||
}
|
||||
fn read(path: &Path) -> String {
|
||||
std::fs::read_to_string(path).expect("read log")
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn a_line_carries_time_level_thread_target_and_message() {
|
||||
assert_eq!(
|
||||
format_line("2026-10-08T07:59:17.728Z", log::Level::Error, "main", "designcraft_engine::guard", "command `frame.create` panicked: boom"),
|
||||
"2026-10-08T07:59:17.728Z ERROR [main] designcraft_engine::guard: command `frame.create` panicked: boom\n"
|
||||
);
|
||||
// A multi-line message (a panic with a backtrace) 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 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 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!(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 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, "designcraft::prefs", "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::Debug, "designcraft", "below info");
|
||||
let text = read(&path);
|
||||
assert!(text.contains(" INFO [") && text.contains("designcraft::prefs: settings directory\n"), "{text}");
|
||||
assert!(text.contains("wgpu_hal::vulkan: a real warning\n"), "{text}");
|
||||
assert!(!text.contains("too chatty") && !text.contains("below info"), "{text}");
|
||||
assert!(logger.enabled(&log::Metadata::builder().level(log::Level::Info).target("designcraft_render").build()));
|
||||
assert!(!logger.enabled(&log::Metadata::builder().level(log::Level::Info).target("naga").build()));
|
||||
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::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());
|
||||
let _ = std::fs::remove_file(&dir);
|
||||
}
|
||||
}
|
||||
|
|
@ -9,6 +9,7 @@
|
|||
#![deny(clippy::unwrap_used, clippy::expect_used, clippy::panic, clippy::unimplemented, clippy::todo, clippy::unreachable)]
|
||||
|
||||
mod control_server;
|
||||
mod logging;
|
||||
#[cfg(target_os = "macos")]
|
||||
mod native_menu;
|
||||
|
||||
|
|
@ -41,8 +42,9 @@ impl eframe::App for App {
|
|||
}
|
||||
}
|
||||
|
||||
fn prefs_path() -> Option<std::path::PathBuf> {
|
||||
let base = if cfg!(target_os = "macos") {
|
||||
/// The per-user settings directory: `ui.json`, `prefs.json` and `logs/` live here.
|
||||
fn config_dir() -> Option<std::path::PathBuf> {
|
||||
if cfg!(target_os = "macos") {
|
||||
std::env::var_os("HOME").map(|h| std::path::PathBuf::from(h).join("Library/Application Support/DesignCraft"))
|
||||
} else if cfg!(windows) {
|
||||
std::env::var_os("APPDATA").map(|a| std::path::PathBuf::from(a).join("DesignCraft"))
|
||||
|
|
@ -51,8 +53,11 @@ fn prefs_path() -> Option<std::path::PathBuf> {
|
|||
.map(std::path::PathBuf::from)
|
||||
.or_else(|| std::env::var_os("HOME").map(|h| std::path::PathBuf::from(h).join(".config")))
|
||||
.map(|c| c.join("designcraft"))
|
||||
};
|
||||
base.map(|b| b.join("ui.json"))
|
||||
}
|
||||
}
|
||||
|
||||
fn prefs_path() -> Option<std::path::PathBuf> {
|
||||
config_dir().map(|b| b.join("ui.json"))
|
||||
}
|
||||
|
||||
fn load_prefs(app: &mut DesignApp) {
|
||||
|
|
@ -182,14 +187,28 @@ fn app_icon() -> Option<egui::IconData> {
|
|||
eframe::icon_data::from_png_bytes(png).map_err(|e| log::warn!("app icon: {e}")).ok()
|
||||
}
|
||||
|
||||
/// The control port from `--control <port>` or `DESIGNCRAFT_CONTROL_PORT` (`source`); a value that
|
||||
/// is not a port is logged and ignored instead of silently starting no control channel.
|
||||
fn control_port_from(source: &str, value: Option<String>) -> Option<u16> {
|
||||
let value = value?;
|
||||
let port = value.trim().parse().ok();
|
||||
if port.is_none() {
|
||||
log::warn!("{source}: {value:?} is not a port number; the control channel is off");
|
||||
}
|
||||
port
|
||||
}
|
||||
|
||||
fn main() -> eframe::Result {
|
||||
let mut control_port: Option<u16> = std::env::var("DESIGNCRAFT_CONTROL_PORT").ok().and_then(|p| p.parse().ok());
|
||||
// First, so every start-up record (and the engine's panic hook, installed with the first
|
||||
// Session) is captured; see `logging`.
|
||||
let logger = logging::install();
|
||||
let mut control_port = control_port_from("DESIGNCRAFT_CONTROL_PORT", std::env::var("DESIGNCRAFT_CONTROL_PORT").ok());
|
||||
let mut files = Vec::new();
|
||||
let mut sample = false;
|
||||
let mut args = std::env::args().skip(1);
|
||||
while let Some(a) = args.next() {
|
||||
match a.as_str() {
|
||||
"--control" => control_port = args.next().and_then(|p| p.parse().ok()),
|
||||
"--control" => control_port = control_port_from("--control", args.next()),
|
||||
"--sample" => sample = true,
|
||||
"--version" => {
|
||||
println!("designcraft {}", env!("CARGO_PKG_VERSION"));
|
||||
|
|
@ -198,6 +217,15 @@ fn main() -> eframe::Result {
|
|||
_ => files.push(a),
|
||||
}
|
||||
}
|
||||
// The log file lives under the settings directory; opened after the arguments, so `--version`
|
||||
// leaves no file behind. Records logged until now are written to it first.
|
||||
if let (Some(logger), Some(dir)) = (logger, config_dir()) {
|
||||
match logger.attach_dir(&dir.join("logs")) {
|
||||
Ok(path) => log::info!("DesignCraft {}, 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}"),
|
||||
}
|
||||
}
|
||||
let mut options = eframe::NativeOptions {
|
||||
viewport: egui::ViewportBuilder::default()
|
||||
.with_title("DesignCraft")
|
||||
|
|
@ -260,6 +288,16 @@ fn main() -> eframe::Result {
|
|||
|
||||
#[cfg(test)]
|
||||
mod tests {
|
||||
#[test]
|
||||
fn control_port_values_that_are_not_ports_are_ignored() {
|
||||
assert_eq!(super::control_port_from("--control", Some("7979".into())), Some(7979));
|
||||
assert_eq!(super::control_port_from("--control", Some(" 7979 ".into())), Some(7979));
|
||||
assert_eq!(super::control_port_from("--control", None), None);
|
||||
for bad in ["", "abc", "-1", "65536", "99999999999999999999"] {
|
||||
assert_eq!(super::control_port_from("--control", Some(bad.into())), None, "{bad:?}");
|
||||
}
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn data_merge_open_dialog_lists_table_extensions() {
|
||||
let filters = super::open_filters("dataMerge");
|
||||
|
|
|
|||
Loading…
Reference in New Issue