Files
OneCAD-Simulation/crates/engine/src/crash.rs
T
jyvikoandClaude Opus 5.5 080ff048c6 Engine: crash reports, a log file and bug report drafts (#107)
crash: a panic hook and a locked per-run command journal (adapted from
SolidCraft's crash reports). A panic in a command becomes a report with
the model from before it and the command; one outside commands, or an
unclean exit found at the next start (abort, segfault, a crash in a
graphics driver, a kill: what #248 needs), a report with the model the
journal starts from (autosave, file or a copy) and the commands since,
the last control request and the dead run's log lines. Reports are
bounded, deduplicated by signature and replayable (crash::replay, with
writes confined to a scratch folder). The crash folder follows the
automation temp area in --control and CI runs.

logfile: a small size-rotated file logger behind the log facade.

bug_report: GitHub bug-form drafts. Version, OS and what happened by
default, home folder shown as ~; the command journal only with Share my
session, the model only with Include the model as well; a session too
long for the link becomes a file to attach and the clipboard text.

Commands: diagnostics.crash_reports, diagnostics.crash_report,
diagnostics.bug_report (Tools › Help, with its icon) and
diagnostics.crash_test (FIELDCRAFT_CRASH_TEST=1 only).

Co-Authored-By: Claude Opus 5.5 <[email protected]>
Claude-Session: https://claude.ai/code/session_01UhhZMBTviDQxZvwnyP89fo
2026-10-15 00:36:18 -04:00

1159 lines
44 KiB
Rust

//! Crash reports: enough to reproduce a crash and fix it, without slowing the app down or
//! filling the disk (docs/crash-reports.md).
//!
//! - **Panics** are caught by a hook. One inside a command becomes a report with the model as it
//! was before the command and the command itself, so `fieldcraft-cli crashes replay <id>`
//! reproduces it. A panic something inside the command caught and turned into an error is
//! reported the same way, marked recovered.
//! - **Crashes no hook sees** (an abort, a stack overflow, a segfault, a crash inside a graphics
//! driver, the process being killed) are found at the next start: every running app keeps a
//! small, locked command journal; a journal nobody holds any more belongs to an app that died.
//! Its report carries the model the journal starts from (the last autosave, the model's file,
//! or a copy taken when the model was opened) and the commands run since, ending with the one
//! in flight, plus the app's last control request and the dead run's lines of the log file
//! ([`crate::logfile`]).
//! - **Cost**: nothing until [`install`] is called (tests, the CLI and the web build never do);
//! after that, two small unbuffered appends per top-level command of the app's own model
//! ([`Session::crash_journal`]), and work only when something panics.
//! - **Bounded**: the same crash (its signature: place + message, digits ignored) is counted, not
//! written again; at most [`MAX_NEW_PER_SESSION`] new reports per run, [`MAX_REPORTS`]
//! reports, [`MAX_TOTAL_BYTES`] on disk, nothing older than [`MAX_AGE_DAYS`] days.
//!
//! Reports are folders `crashes/<time>-<signature>/` holding `report.json`, and when known
//! `model.fieldcraft`, `replay.json` and `log.txt`. Nothing is ever sent anywhere.
//!
//! Adapted from SolidCraft's `crates/engine/src/crash.rs` (MIT OR Apache-2.0), see ATTRIBUTION.md.
use std::backtrace::Backtrace;
use std::cell::{Cell, RefCell};
use std::collections::HashMap;
use std::fs::{self, File, OpenOptions};
use std::io::{Read, Seek, SeekFrom, Write};
use std::path::{Path, PathBuf};
use std::sync::atomic::{AtomicBool, AtomicU64, AtomicUsize, Ordering};
use std::sync::{Mutex, OnceLock};
use serde_json::{Value, json};
use crate::{EngineError, Session};
/// Reports kept (the oldest, and recovered panics, go first).
pub const MAX_REPORTS: usize = 20;
/// Bytes all reports may take together.
pub const MAX_TOTAL_BYTES: u64 = 100 << 20;
/// Reports older than this are deleted.
pub const MAX_AGE_DAYS: u64 = 90;
/// New reports one run of the app may write (repeats are only counted).
pub const MAX_NEW_PER_SESSION: usize = 5;
/// A model bigger than this is not copied into a report.
pub const MAX_MODEL_BYTES: usize = 20 << 20;
/// A journal stops recording commands at this size (until the next autosave restarts it).
const MAX_JOURNAL_BYTES: u64 = 512 << 10;
/// Command parameters recorded per command.
const MAX_PARAMS_BYTES: usize = 16 << 10;
/// Recent commands shown in a report.
const RECENT: usize = 32;
const MAX_FRAMES: usize = 60;
const MAX_MESSAGE: usize = 2000;
/// The log lines copied into a report.
const LOG_TAIL_BYTES: usize = 64 << 10;
/// The report format.
pub const FORMAT: &str = "fieldcraft-crash/1";
/// The model file in a report folder.
pub const MODEL_FILE: &str = "model.fieldcraft";
/// What the app is (shown in every report).
#[derive(Clone, Debug, Default)]
pub struct Build {
pub version: &'static str,
/// The commit it was built from, when known.
pub commit: &'static str,
}
impl Build {
/// This build: the workspace version, and the commit when the build named one
/// (`FIELDCRAFT_BUILD_SHA`, packaging/env.sh).
pub fn current() -> Build {
let sha = option_env!("FIELDCRAFT_BUILD_SHA").unwrap_or("");
Build { version: env!("CARGO_PKG_VERSION"), commit: sha.get(..10).unwrap_or(sha) }
}
/// `v0.5.8 (abc1234567), macos aarch64`.
pub fn version_line(&self) -> String {
crate::bug_report::version_line(self.version, self.commit)
}
}
/// One report, as listed.
#[derive(Clone, Debug, PartialEq, serde::Serialize)]
pub struct Summary {
pub id: String,
/// `command_panic`, `panic`, `recovered_panic` or `unclean_exit`.
pub kind: String,
/// When it first happened (UTC).
pub time: String,
pub message: String,
/// The command running when it happened, if one was.
pub command: Option<String>,
/// Times it happened.
pub count: u64,
pub version: String,
/// The report's folder.
pub path: String,
/// `replay.json` is there: the crash can be replayed.
pub replayable: bool,
}
struct State {
dir: PathBuf,
build: Build,
journal: Mutex<Journal>,
/// Signatures already reported (this run's count; the report's folder name).
known: Mutex<HashMap<u64, (u64, String)>>,
written: AtomicUsize,
started: u64,
}
static STATE: OnceLock<State> = OnceLock::new();
/// The hook is writing a report (a panic inside it must not write another).
static IN_HOOK: AtomicBool = AtomicBool::new(false);
static SEQ: AtomicU64 = AtomicU64::new(0);
thread_local! {
/// Commands running on this thread (their panics are reported when the outermost ends).
static IN_COMMAND: Cell<u32> = const { Cell::new(0) };
/// Panics caught inside the running command, waiting for it to end.
static PENDING: RefCell<Vec<Panic>> = const { RefCell::new(Vec::new()) };
}
/// Crash reporting is on in this process.
pub fn enabled() -> bool {
STATE.get().is_some()
}
/// The crash folder: `FIELDCRAFT_CRASH_DIR`, else `crashes` in the app's data folder (a
/// temporary folder in runs driven by automation, [`fieldcraft_io::recovery::data_dir`]).
pub fn default_dir() -> Option<PathBuf> {
if let Some(s) = STATE.get() {
return Some(s.dir.clone());
}
if let Some(d) = std::env::var_os("FIELDCRAFT_CRASH_DIR").filter(|d| !d.is_empty()) {
return Some(PathBuf::from(d));
}
fieldcraft_io::recovery::data_dir().map(|d| d.join("crashes"))
}
fn now() -> u64 {
std::time::SystemTime::now().duration_since(std::time::UNIX_EPOCH).map_or(0, |d| d.as_secs())
}
/// `secs` since 1970 as (year, month, day, hour, minute, second) in UTC.
fn civil(secs: u64) -> (i64, i64, i64, u64, u64, u64) {
let days = i64::try_from(secs / 86_400).unwrap_or(0);
let rem = secs % 86_400;
let z = days + 719_468;
let era = z.div_euclid(146_097);
let doe = z.rem_euclid(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 };
(yoe + era * 400 + i64::from(m <= 2), m, d, rem / 3600, rem % 3600 / 60, rem % 60)
}
/// `2026-10-12T14:03:22Z`.
pub fn utc(secs: u64) -> String {
let (y, m, d, h, mi, s) = civil(secs);
format!("{y:04}-{m:02}-{d:02}T{h:02}:{mi:02}:{s:02}Z")
}
/// `20261012-140322`, for file and folder names.
pub fn stamp(secs: u64) -> String {
let (y, m, d, h, mi, s) = civil(secs);
format!("{y:04}{m:02}{d:02}-{h:02}{mi:02}{s:02}")
}
/// The current time as [`stamp`] gives it.
pub fn stamp_now() -> String {
stamp(now())
}
/// A crash's identity: where it happened and what it said, numbers ignored (ids and sizes vary).
pub fn signature(location: &str, message: &str) -> u64 {
let mut h: u64 = 0xcbf2_9ce4_8422_2325;
let mut eat = |b: u8| {
h ^= u64::from(b);
h = h.wrapping_mul(0x0100_0000_01b3);
};
for b in location.bytes() {
eat(b);
}
eat(b'|');
let mut digit = false;
for b in message.bytes().take(300) {
if b.is_ascii_digit() {
if !digit {
eat(b'#');
}
digit = true;
} else {
digit = false;
eat(b);
}
}
h
}
fn valid_id(id: &str) -> bool {
!id.is_empty() && id.len() <= 64 && id.chars().all(|c| c.is_ascii_alphanumeric() || c == '-')
}
/// `s` cut to at most `n` bytes (on a character boundary), saying how long it was.
pub fn limited(s: &str, n: usize) -> String {
if s.len() <= n {
return s.to_string();
}
let mut end = n;
while !s.is_char_boundary(end) {
end -= 1;
}
format!("{}… ({} bytes)", s.get(..end).unwrap_or_default(), s.len())
}
/// Serialise `v`, giving up past `limit` bytes.
fn bounded_json(v: &Value, limit: usize) -> Option<String> {
struct W(Vec<u8>, usize);
impl Write for W {
fn write(&mut self, b: &[u8]) -> std::io::Result<usize> {
if self.0.len() + b.len() > self.1 {
return Err(std::io::Error::other("too long"));
}
self.0.extend_from_slice(b);
Ok(b.len())
}
fn flush(&mut self) -> std::io::Result<()> {
Ok(())
}
}
let mut w = W(Vec::new(), limit);
serde_json::to_writer(&mut w, v).ok()?;
String::from_utf8(w.0).ok()
}
/// The user's home folder in `s` shown as `~` (reports and drafts name no user folders).
pub fn without_home(s: &str) -> String {
let home = std::env::var("HOME").or_else(|_| std::env::var("USERPROFILE")).unwrap_or_default();
if home.len() > 1 { s.replace(&home, "~") } else { s.to_string() }
}
// ---------------------------------------------------------------------------------------------
// Panics
/// What a panic said.
#[derive(Clone, Debug)]
struct Panic {
message: String,
location: String,
thread: String,
backtrace: Vec<String>,
signature: u64,
}
/// A backtrace as frames `symbol (file:line)`, without the panic machinery, the user's home
/// folder or the toolchain's hash.
fn frames(bt: &str) -> Vec<String> {
let mut out: Vec<String> = Vec::new();
for line in bt.lines() {
let t = line.trim();
if let Some(at) = t.strip_prefix("at ") {
let mut at = without_home(at);
if let Some(i) = at.find("/rustc/")
&& let Some(j) = at.get(i + 7..).and_then(|r| r.find('/'))
{
at = format!("rustc{}", at.get(i + 7 + j..).unwrap_or_default());
}
if let Some(last) = out.last_mut()
&& !last.ends_with(')')
{
last.push_str(&format!(" ({at})"));
}
} else if let Some((n, sym)) = t.split_once(": ")
&& n.chars().all(|c| c.is_ascii_digit())
{
out.push(sym.to_string());
}
}
// Drop the hook and the panic machinery on top (everything up to where the panic began),
// everything below the thread's start, and the standard library's own frames between.
let entry = ["panicking::begin_panic", "panic::panic_any", "rust_begin_unwind", "core::panicking::", "__rust_end_short_backtrace"];
let skip = out.iter().take(40).rposition(|f| entry.iter().any(|e| f.contains(e))).map_or(0, |i| i + 1);
let mut v: Vec<String> = out.into_iter().skip(skip).collect();
if let Some(end) = v.iter().position(|f| f.contains("__rust_begin_short_backtrace")) {
v.truncate(end);
}
v.retain(|f| !f.contains("(rustc/"));
v.truncate(MAX_FRAMES);
v
}
/// Install the panic hook and start this run's journal; reports the runs that crashed without a
/// report (unclean exits). Returns the reports the user has not been told about yet, newest
/// first, for the app to offer. Call once, early (before the log file is opened: an unclean
/// exit's report takes the dead run's lines from it).
pub fn install(dir: PathBuf, build: Build) -> Vec<Summary> {
let _ = fs::create_dir_all(dir.join("sessions"));
let started = now();
for path in dead_journals(&dir) {
unclean_exit(&dir, &build, &path);
remove_journal(&path);
}
prune(&dir, started);
// Reports the user has been told about (by id).
let seen_file = dir.join(".seen");
let mut seen = String::new();
if let Ok(f) = File::open(&seen_file) {
let _ = f.take(64 << 10).read_to_string(&mut seen);
}
let all = list(&dir);
let fresh: Vec<Summary> = all.iter().filter(|s| !seen.lines().any(|l| l == s.id)).cloned().collect();
let _ = fs::write(&seen_file, all.iter().map(|s| s.id.as_str()).collect::<Vec<_>>().join("\n"));
let known = all.into_iter().filter_map(|s| sig_of(&s.id).map(|sig| (sig, (0, s.id)))).collect();
let journal = Journal::open(&dir, &build, started);
if STATE.set(State { dir, build, journal: Mutex::new(journal), known: Mutex::new(known), written: AtomicUsize::new(0), started }).is_ok() {
let previous = std::panic::take_hook();
std::panic::set_hook(Box::new(move |info| {
if !hook(info) {
previous(info);
}
}));
}
fresh
}
/// What the app is doing outside commands (`"startup"`, `"running"`, a control request such as
/// `"control ui.capture"`): the journal keeps the latest, so a crash nothing catches still says
/// what came last.
pub fn activity(what: &str) {
let Some(s) = STATE.get() else { return };
if let Ok(mut j) = s.journal.lock() {
// Bounded like the commands: a full journal keeps its last word.
if j.activity_text.as_deref() == Some(what) || j.bytes > MAX_JOURNAL_BYTES {
return;
}
let line = json!({ "activity": limited(what, 200), "at": utc(now()) }).to_string();
j.write(&line);
j.activity = Some(line);
j.activity_text = Some(what.to_string());
}
}
/// The app is closing normally: its journal goes, and repeat counts are written.
pub fn end_session() {
let Some(s) = STATE.get() else { return };
if let Ok(mut j) = s.journal.lock()
&& let Some(path) = j.path.take()
{
j.file = None;
remove_journal(&path);
}
let counts: Vec<(u64, String)> = s.known.lock().map(|k| k.values().filter(|(n, _)| *n > 0).cloned().collect()).unwrap_or_default();
for (n, id) in counts {
bump(&s.dir, &id, n);
}
}
/// A journal and the model copy it starts from.
fn remove_journal(path: &Path) {
let _ = fs::remove_file(path);
let _ = fs::remove_file(base_copy(path));
}
/// Where a journal keeps the model it starts from, when that is no file of its own.
fn base_copy(journal: &Path) -> PathBuf {
journal.with_extension("base.fieldcraft")
}
/// The panic hook. Returns true when the panic was recorded for a command (which will catch
/// it), so the default "thread panicked" message is not printed twice.
fn hook(info: &std::panic::PanicHookInfo<'_>) -> bool {
let Some(state) = STATE.get() else { return false };
if IN_HOOK.swap(true, Ordering::SeqCst) {
return false;
}
let message = limited(info.payload_as_str().unwrap_or("(not a text message)"), MAX_MESSAGE);
let location = info.location().map_or_else(|| "(unknown)".to_string(), |l| format!("{}:{}", l.file(), l.line()));
log::error!("panic at {location}: {message}");
let sig = signature(&location, &message);
let in_command = IN_COMMAND.with(Cell::get) > 0;
// Already reported (this run or before): count it, nothing else.
let repeat = match state.known.lock() {
Ok(mut k) => match k.get_mut(&sig) {
Some(e) => {
e.0 += 1;
true
}
None => false,
},
Err(_) => true,
};
if repeat {
IN_HOOK.store(false, Ordering::SeqCst);
return in_command;
}
let thread = std::thread::current().name().unwrap_or("(unnamed)").to_string();
let backtrace = frames(&Backtrace::force_capture().to_string());
let p = Panic { message, location, thread, backtrace, signature: sig };
if in_command {
// Reported with the model and the command when the outermost command ends.
PENDING.with(|q| {
let mut q = q.borrow_mut();
if q.len() < 8 {
q.push(p);
}
});
} else {
// Outside any command: what the journal knows has to do.
let extra = from_journal(read_live_journal(state), None);
if let Some(id) = write_report(state, "panic", Some(&p), extra) {
eprintln!("FieldCraft: internal error; crash report {}", state.dir.join(&id).display());
if let Ok(mut j) = state.journal.try_lock() {
j.record(&json!({ "reported": id }));
}
}
}
IN_HOOK.store(false, Ordering::SeqCst);
in_command
}
/// Marks a command running on this thread; panics inside it wait for [`command_done`].
pub(crate) struct Scope(bool);
impl Scope {
pub(crate) fn enter() -> Scope {
if !enabled() {
return Scope(false);
}
IN_COMMAND.with(|c| c.set(c.get() + 1));
Scope(true)
}
/// The outermost command on this thread.
pub(crate) fn top_level(&self) -> bool {
self.0 && IN_COMMAND.with(Cell::get) == 1
}
}
impl Drop for Scope {
fn drop(&mut self) {
if self.0 {
IN_COMMAND.with(|c| c.set(c.get().saturating_sub(1)));
}
}
}
/// A top-level command of the app's own model is about to run: the journal records it. Returns
/// whether it did.
pub(crate) fn command_begin(scope: &Scope, s: &Session, id: &str, params: &Value) -> bool {
let Some(state) = STATE.get() else { return false };
if !s.crash_journal || !scope.top_level() {
return false;
}
let Ok(mut j) = state.journal.lock() else { return false };
if j.document != Some(s.opened()) {
// The model on screen changed outside a recorded command (the app's first command).
rebase_on_session(&mut j, s);
}
j.run(id, params);
true
}
/// A top-level command ended (`scope` already dropped): the journal records how; when it
/// opened another model the journal starts again from it. Panics caught inside it are reported
/// with the session (restored to how it was before the command after an internal error) and
/// the command, which together reproduce them.
pub(crate) fn command_done(s: &Session, journaled: bool, changed: bool, id: &str, params: &Value, result: &crate::Result<Value>) {
let Some(state) = STATE.get() else { return };
if journaled && let Ok(mut j) = state.journal.lock() {
j.done(result.as_ref().map(|_| ()).map_err(ToString::to_string), changed);
if j.document != Some(s.opened()) {
rebase_on_session(&mut j, s);
}
}
if IN_COMMAND.with(Cell::get) > 0 {
return;
}
let pending: Vec<Panic> = PENDING.with(|q| std::mem::take(&mut *q.borrow_mut()));
if pending.is_empty() {
return;
}
// The command failed with the panic: the session is as it was before it. A panic caught
// inside the command (and turned into an error or worked around) left the command's own
// outcome; it is reported, but as recovered, with the model as it is now.
let crashed = matches!(result, Err(EngineError::Internal { .. }));
let kind = if crashed { "command_panic" } else { "recovered_panic" };
let mut notes = Vec::new();
let model = match s.file_bytes(None) {
Ok(b) if b.len() <= MAX_MODEL_BYTES => Some(b),
Ok(b) => {
notes.push(format!("the model ({} MB) is larger than {} MB and was not copied", b.len() >> 20, MAX_MODEL_BYTES >> 20));
None
}
Err(e) => {
notes.push(format!("the model could not be written: {e}"));
None
}
};
let recent = if journaled { read_live_journal(state).recent } else { Vec::new() };
for p in pending {
let extra = Extra {
command: Some(json!({ "command": id, "params": params })),
model: model.clone(),
replay: (crashed && model.is_some()).then(|| json!({ "commands": [{ "command": id, "params": params }] })),
recent: recent.clone(),
base: json!(if crashed { "the model as it was when the command started" } else { "the model after the command" }),
notes: notes.clone(),
fields: serde_json::Map::new(),
log_pid: Some(std::process::id()),
};
write_report(state, kind, Some(&p), extra);
}
}
/// An autosave just wrote the session to `file`: replays start from there.
pub(crate) fn autosaved(s: &Session, file: &Path) {
let Some(state) = STATE.get() else { return };
if !s.crash_journal {
return;
}
let Ok(mut j) = state.journal.lock() else { return };
j.rebase(&json!({ "autosave": file.to_string_lossy() }), s.opened());
}
/// Start the journal again from the session as it is now: its file when that holds it, a new
/// model when it is empty, else a copy beside the journal.
fn rebase_on_session(j: &mut Journal, s: &Session) {
let opened = s.opened();
if !s.is_dirty()
&& let Some(p) = &s.path
{
j.rebase(&json!({ "file": p }), opened);
return;
}
if s.journal.is_empty() && s.model.nodes().is_empty() && s.model.elements().is_empty() && s.design.is_none() && s.surfaces.is_empty() {
j.rebase(&json!("new"), opened);
return;
}
let base = j.path.as_deref().map(base_copy);
let copied = base.as_ref().is_some_and(|b| match s.file_bytes(None) {
Ok(bytes) if bytes.len() <= MAX_MODEL_BYTES => fieldcraft_io::fs::write_atomic(b, &bytes, false).is_ok(),
_ => false,
});
match base.filter(|_| copied) {
Some(b) => j.rebase(&json!({ "copy": b.to_string_lossy() }), opened),
None => j.rebase(&json!("unknown"), opened),
}
}
// ---------------------------------------------------------------------------------------------
// The journal
struct Journal {
path: Option<PathBuf>,
file: Option<File>,
bytes: u64,
full: bool,
/// The document ([`Session::opened`]) the journal follows.
document: Option<u64>,
header: String,
/// Where the running command's line starts (to take it back when it changed nothing).
running_at: Option<u64>,
/// The latest activity's line and text (kept across rebases).
activity: Option<String>,
activity_text: Option<String>,
}
impl Journal {
fn open(dir: &Path, build: &Build, started: u64) -> Journal {
let seq = SEQ.fetch_add(1, Ordering::Relaxed);
let path = dir.join("sessions").join(format!("{}-{}-{seq}.jsonl", stamp(started), std::process::id()));
// Append-only handles cannot truncate on Windows; seek explicitly for each write.
let file = OpenOptions::new().create(true).truncate(false).read(true).write(true).open(&path).ok().filter(|f| f.try_lock().is_ok());
let header = json!({ "start": utc(started), "pid": std::process::id(), "version": build.version, "commit": build.commit }).to_string();
let mut j = Journal {
path: file.as_ref().map(|_| path),
file,
bytes: 0,
full: false,
document: None,
header,
running_at: None,
activity: None,
activity_text: None,
};
j.rebase(&json!("new"), 0);
j.document = None;
j
}
fn write(&mut self, line: &str) {
let Some(f) = &mut self.file else { return };
if f.seek(SeekFrom::End(0)).and_then(|_| f.write_all(line.as_bytes())).and_then(|()| f.write_all(b"\n")).is_err() {
self.file = None;
}
self.bytes += line.len() as u64 + 1;
}
fn record(&mut self, v: &Value) {
self.write(&v.to_string());
}
fn rebase(&mut self, base: &Value, document: u64) {
if let Some(f) = &self.file
&& f.set_len(0).is_err()
{
self.file = None;
}
self.bytes = 0;
self.full = false;
self.running_at = None;
self.document = Some(document);
let h = self.header.clone();
self.write(&h);
self.record(&json!({ "base": base }));
if let Some(line) = self.activity.clone() {
self.write(&line);
}
}
fn run(&mut self, id: &str, params: &Value) {
if self.full {
return;
}
if self.bytes > MAX_JOURNAL_BYTES {
self.full = true;
self.record(&json!({ "full": true }));
return;
}
self.running_at = Some(self.bytes);
let id = Value::String(id.to_string()).to_string();
let line = match bounded_json(params, MAX_PARAMS_BYTES) {
Some(p) => format!("{{\"run\":{id},\"params\":{p}}}"),
None => format!("{{\"run\":{id},\"params_omitted\":true}}"),
};
self.write(&line);
}
fn done(&mut self, outcome: std::result::Result<(), String>, changed: bool) {
let at = self.running_at.take();
if self.full {
return;
}
match outcome {
// Nothing changed: take the command's line back (one truncate, no write).
Ok(()) if !changed => {
if let (Some(at), Some(f)) = (at, &self.file) {
if f.set_len(at).is_ok() {
self.bytes = at;
} else {
self.file = None;
}
}
}
Ok(()) => self.write("{\"ok\":true}"),
Err(e) => self.record(&json!({ "ok": false, "error": limited(&e, 300) })),
}
}
}
/// What a journal says.
#[derive(Default)]
struct JournalRead {
header: Value,
base: Value,
/// Commands since the base that changed something, in order.
replay: Vec<Value>,
/// The command that was running, if one was.
in_flight: Option<Value>,
recent: Vec<Value>,
complete: bool,
reported: bool,
/// The latest activity outside commands.
activity: Option<String>,
}
// Read through the lock-owning file object: on Windows an independently opened handle cannot
// read a live journal's exclusively locked byte range.
fn read_live_journal(state: &State) -> JournalRead {
state.journal.try_lock().ok().and_then(|j| j.file.as_ref()?.try_clone().ok().map(read_journal_file)).unwrap_or_default()
}
fn read_journal(path: &Path) -> JournalRead {
File::open(path).ok().map(read_journal_file).unwrap_or_default()
}
fn read_journal_file(mut file: File) -> JournalRead {
let mut text = String::new();
if file.seek(SeekFrom::Start(0)).is_ok() {
let _ = file.take(MAX_JOURNAL_BYTES + (64 << 10)).read_to_string(&mut text);
}
parse_journal(&text)
}
fn parse_journal(text: &str) -> JournalRead {
let mut r = JournalRead { complete: true, ..Default::default() };
let mut running: Option<Value> = None;
for (i, line) in text.lines().enumerate() {
let Ok(v) = serde_json::from_str::<Value>(line) else { continue };
if i == 0 {
r.header = v;
continue;
}
if let Some(a) = v.get("activity").and_then(Value::as_str) {
r.activity = Some(a.to_string());
continue;
}
r.reported = v.get("reported").is_some();
if let Some(b) = v.get("base") {
r.base = b.clone();
r.replay.clear();
r.recent.clear();
r.complete = true;
running = None;
} else if let Some(id) = v.get("run") {
let c = match v.get("params") {
Some(p) => json!({ "command": id, "params": p }),
None => {
r.complete = false;
json!({ "command": id, "params_omitted": true })
}
};
running = Some(c);
} else if let Some(ok) = v.get("ok").and_then(Value::as_bool) {
if let Some(c) = running.take() {
let mut shown = c.clone();
shown["ok"] = json!(ok);
if let Some(e) = v.get("error") {
shown["error"] = e.clone();
}
r.recent.push(shown);
if ok {
r.replay.push(c);
}
}
} else if v.get("full").is_some() {
r.complete = false;
}
}
r.in_flight = running;
let n = r.recent.len();
r.recent.drain(..n.saturating_sub(RECENT));
r
}
/// Journals of apps that are not running any more (nobody holds their lock).
fn dead_journals(dir: &Path) -> Vec<PathBuf> {
fs::read_dir(dir.join("sessions"))
.into_iter()
.flatten()
.flatten()
.map(|e| e.path())
.filter(|p| p.extension().and_then(|x| x.to_str()) == Some("jsonl"))
.take(100)
.filter(|p| File::open(p).is_ok_and(|f| f.try_lock().is_ok()))
.collect()
}
fn unclean_exit(dir: &Path, build: &Build, journal: &Path) {
let j = read_journal(journal);
if j.reported {
return;
}
let was = j.header.get("version").and_then(Value::as_str).unwrap_or("?").to_string();
let when = j.header.get("start").and_then(Value::as_str).unwrap_or("?").to_string();
let pid = j.header.get("pid").and_then(Value::as_u64).and_then(|p| u32::try_from(p).ok());
let doing = j.in_flight.as_ref().and_then(|c| c.get("command")).and_then(Value::as_str).map(str::to_string);
let during = match (&doing, &j.activity) {
(Some(c), _) => format!("while running `{c}`"),
(None, Some(a)) => format!("between commands (last: {a})"),
(None, None) => "between commands".to_string(),
};
let p = Panic {
message: format!("FieldCraft {was} (started {when}) ended without a clean exit {during}"),
location: format!("unclean exit in {}", doing.as_deref().unwrap_or("(between commands)")),
thread: "(unknown)".into(),
backtrace: Vec::new(),
signature: signature("unclean exit", doing.as_deref().or(j.activity.as_deref()).unwrap_or("idle")),
};
// A temporary state just for this report (the app's own is not set up yet).
let state = State {
dir: dir.to_path_buf(),
build: build.clone(),
journal: Mutex::new(Journal {
path: None,
file: None,
bytes: 0,
full: true,
document: None,
header: String::new(),
running_at: None,
activity: None,
activity_text: None,
}),
known: Mutex::new(list(dir).into_iter().filter_map(|s| sig_of(&s.id).map(|sig| (sig, (0, s.id)))).collect()),
written: AtomicUsize::new(0),
started: now(),
};
if let Ok(mut k) = state.known.lock()
&& let Some(e) = k.get_mut(&p.signature)
{
e.0 += 1;
let (n, id) = e.clone();
drop(k);
bump(dir, &id, n);
return;
}
write_report(&state, "unclean_exit", Some(&p), from_journal(j, pid));
}
// ---------------------------------------------------------------------------------------------
// Reports
struct Extra {
command: Option<Value>,
model: Option<Vec<u8>>,
replay: Option<Value>,
recent: Vec<Value>,
base: Value,
notes: Vec<String>,
/// More top-level fields for the report (`last_activity`).
fields: serde_json::Map<String, Value>,
/// The process whose log lines go into the report.
log_pid: Option<u32>,
}
/// Model and replay from a journal: the base model (autosave, the model's file or the copy
/// taken when it was opened) and the commands since, ending with the one in flight.
fn from_journal(j: JournalRead, log_pid: Option<u32>) -> Extra {
let mut notes = Vec::new();
let file = ["autosave", "file", "copy"].iter().find_map(|k| j.base.get(*k)).and_then(Value::as_str).map(PathBuf::from);
let model = match &file {
Some(f) => match fs::metadata(f) {
Ok(m) if m.len() <= MAX_MODEL_BYTES as u64 => fs::read(f).ok(),
Ok(_) => {
notes.push(format!(
"the model ({}) is larger than {} MB and was not copied",
without_home(&f.to_string_lossy()),
MAX_MODEL_BYTES >> 20
));
None
}
Err(_) => {
notes.push(format!("the model the commands start from ({}) is gone", without_home(&f.to_string_lossy())));
None
}
},
None => None,
};
let fresh = j.base.as_str() == Some("new");
let mut commands = j.replay;
if let Some(c) = &j.in_flight {
commands.push(c.clone());
}
if !j.complete {
notes.push("the journal was cut short (too many or too large commands): the replay is incomplete".into());
}
if j.base.as_str() == Some("unknown") {
notes.push("the model could not be copied when it was opened; it cannot be rebuilt from the journal".into());
}
if commands.iter().any(|c| matches!(c.get("command").and_then(Value::as_str), Some("edit.undo" | "edit.redo"))) {
notes.push("the replay starts without undo history: edit.undo and edit.redo may not do what they did".into());
}
let replay = (model.is_some() || fresh) && j.complete && !commands.is_empty();
let mut fields = serde_json::Map::new();
if let Some(a) = j.activity {
fields.insert("last_activity".into(), json!(a));
}
Extra {
command: j.in_flight,
model,
replay: replay.then(|| json!({ "commands": commands })),
recent: j.recent,
base: match file {
Some(f) => json!({ "file": without_home(&f.to_string_lossy()) }),
None => j.base,
},
notes,
fields,
log_pid,
}
}
fn write_report(state: &State, kind: &str, p: Option<&Panic>, extra: Extra) -> Option<String> {
let sig = p.map_or(0, |p| p.signature);
let mut k = state.known.lock().ok()?;
if let Some(e) = k.get_mut(&sig) {
e.0 += 1;
return None;
}
if state.written.load(Ordering::SeqCst) >= MAX_NEW_PER_SESSION {
return None;
}
state.written.fetch_add(1, Ordering::SeqCst);
let t = now();
let id = format!("{}-{sig:016x}", stamp(t));
k.insert(sig, (0, id.clone()));
drop(k);
let folder = state.dir.join(&id);
fs::create_dir_all(&folder).ok()?;
let mut files = serde_json::Map::new();
let mut notes = extra.notes;
if let Some(m) = &extra.model {
if m.len() <= MAX_MODEL_BYTES {
if fieldcraft_io::fs::write_atomic(&folder.join(MODEL_FILE), m, false).is_ok() {
files.insert("model".into(), json!(MODEL_FILE));
}
} else {
notes.push(format!("the model is larger than {} MB and was not copied", MAX_MODEL_BYTES >> 20));
}
}
if let Some(r) = &extra.replay
&& let Ok(b) = serde_json::to_vec_pretty(r)
&& fieldcraft_io::fs::write_atomic(&folder.join("replay.json"), &b, false).is_ok()
{
files.insert("replay".into(), json!("replay.json"));
}
if let Some(log) = crate::logfile::tail(extra.log_pid, LOG_TAIL_BYTES).filter(|l| !l.is_empty())
&& fieldcraft_io::fs::write_atomic(&folder.join("log.txt"), log.as_bytes(), false).is_ok()
{
files.insert("log".into(), json!("log.txt"));
}
let reproduce = files.contains_key("replay").then(|| format!("fieldcraft-cli crashes replay {id}"));
let mut report = json!({
"format": FORMAT,
"id": id,
"kind": kind,
"signature": format!("{sig:016x}"),
"count": 1,
"first_seen": utc(t),
"last_seen": utc(t),
"app": { "version": state.build.version, "commit": state.build.commit },
"system": { "os": std::env::consts::OS, "arch": std::env::consts::ARCH },
"session": { "uptime_s": t.saturating_sub(state.started) },
"message": p.map(|p| without_home(&p.message)),
"location": p.map(|p| without_home(&p.location)),
"thread": p.map(|p| p.thread.clone()),
"backtrace": p.map(|p| p.backtrace.clone()).unwrap_or_default(),
"command": extra.command,
"base": extra.base,
"recent_commands": extra.recent,
"files": files,
"reproduce": reproduce,
"notes": notes,
});
if let Some(r) = report.as_object_mut() {
for (k, v) in extra.fields {
r.entry(k).or_insert(v);
}
}
let bytes = serde_json::to_vec_pretty(&report).ok()?;
fieldcraft_io::fs::write_atomic(&folder.join("report.json"), &bytes, false).ok()?;
prune(&state.dir, t);
Some(id)
}
/// Add `n` repeats to a report.
fn bump(dir: &Path, id: &str, n: u64) {
if !valid_id(id) || n == 0 {
return;
}
let path = dir.join(id).join("report.json");
let Some(mut v) = read_report_file(&path) else { return };
let count = v.get("count").and_then(Value::as_u64).unwrap_or(1).saturating_add(n);
v["count"] = json!(count);
v["last_seen"] = json!(utc(now()));
if let Ok(b) = serde_json::to_vec_pretty(&v) {
let _ = fieldcraft_io::fs::write_atomic(&path, &b, false);
}
}
fn read_report_file(path: &Path) -> Option<Value> {
let f = File::open(path).ok()?;
let mut s = String::new();
f.take(4 << 20).read_to_string(&mut s).ok()?;
serde_json::from_str(&s).ok().filter(Value::is_object)
}
fn sig_of(id: &str) -> Option<u64> {
id.rsplit('-').next().and_then(|h| u64::from_str_radix(h, 16).ok())
}
/// Seconds since 1970 at which report `id` was made (from its file's time).
fn report_time(dir: &Path, id: &str) -> u64 {
fs::metadata(dir.join(id).join("report.json"))
.and_then(|m| m.modified())
.ok()
.and_then(|t| t.duration_since(std::time::UNIX_EPOCH).ok())
.map_or(0, |d| d.as_secs())
}
fn folder_bytes(p: &Path) -> u64 {
fs::read_dir(p).into_iter().flatten().flatten().filter_map(|e| e.metadata().ok()).map(|m| m.len()).sum()
}
/// Report folders in `dir`, oldest first.
fn report_ids(dir: &Path) -> Vec<String> {
let mut v: Vec<String> = fs::read_dir(dir)
.into_iter()
.flatten()
.flatten()
.filter(|e| e.file_type().is_ok_and(|t| t.is_dir()))
.filter_map(|e| e.file_name().to_str().map(str::to_string))
.filter(|n| valid_id(n) && n.len() == 32 && sig_of(n).is_some())
.take(1000)
.collect();
v.sort();
v
}
/// Keep the reports within the limits: drop expired ones, then recovered panics, then the
/// oldest, until at most [`MAX_REPORTS`] and [`MAX_TOTAL_BYTES`] remain.
pub fn prune(dir: &Path, now_secs: u64) {
let mut keep: Vec<(String, bool, u64)> = Vec::new();
for id in report_ids(dir) {
let folder = dir.join(&id);
let t = report_time(dir, &id);
if (t > 0 && now_secs.saturating_sub(t) > MAX_AGE_DAYS * 86_400) || !folder.join("report.json").is_file() {
let _ = fs::remove_dir_all(&folder);
continue;
}
let recovered =
read_report_file(&folder.join("report.json")).is_some_and(|v| v.get("kind").and_then(Value::as_str) == Some("recovered_panic"));
keep.push((id, recovered, folder_bytes(&folder)));
}
let over = |k: &[(String, bool, u64)]| k.len() > MAX_REPORTS || k.iter().map(|e| e.2).sum::<u64>() > MAX_TOTAL_BYTES;
while over(&keep) {
let i = keep.iter().position(|e| e.1).unwrap_or(0);
if i >= keep.len() {
break;
}
let (id, _, _) = keep.remove(i);
let _ = fs::remove_dir_all(dir.join(id));
}
}
/// The reports in `dir`, newest first.
pub fn list(dir: &Path) -> Vec<Summary> {
let mut out: Vec<Summary> = report_ids(dir)
.into_iter()
.rev()
.filter_map(|id| {
let folder = dir.join(&id);
let v = read_report_file(&folder.join("report.json"))?;
let s = |k: &str| v.get(k).and_then(Value::as_str).unwrap_or_default().to_string();
Some(Summary {
kind: s("kind"),
time: s("first_seen"),
message: limited(&s("message"), 300),
command: v.get("command").and_then(|c| c.get("command")).and_then(Value::as_str).map(str::to_string),
count: v.get("count").and_then(Value::as_u64).unwrap_or(1),
version: v.get("app").and_then(|a| a.get("version")).and_then(Value::as_str).unwrap_or_default().to_string(),
path: folder.to_string_lossy().into_owned(),
replayable: folder.join("replay.json").is_file(),
id,
})
})
.collect();
out.truncate(MAX_REPORTS * 2);
out
}
/// One report's `report.json`, with the paths of its files.
pub fn read(dir: &Path, id: &str) -> std::result::Result<Value, String> {
if !valid_id(id) {
return Err(format!("no crash report `{}`", limited(id, 64)));
}
let folder = dir.join(id);
let mut v = read_report_file(&folder.join("report.json")).ok_or_else(|| format!("no crash report `{id}`"))?;
v["path"] = json!(folder.to_string_lossy());
for (k, f) in [("model_path", MODEL_FILE), ("replay_path", "replay.json"), ("log_path", "log.txt")] {
if folder.join(f).is_file() {
v[k] = json!(folder.join(f).to_string_lossy());
}
}
Ok(v)
}
/// Delete one report, or all of them.
pub fn clear(dir: &Path, id: Option<&str>) -> usize {
let ids = match id {
Some(i) if valid_id(i) && report_ids(dir).iter().any(|r| r == i) => vec![i.to_string()],
Some(_) => Vec::new(),
None => report_ids(dir),
};
ids.iter().filter(|i| fs::remove_dir_all(dir.join(i)).is_ok()).count()
}
// ---------------------------------------------------------------------------------------------
// Replay
/// What replaying a report did.
#[derive(Debug)]
pub struct Replay {
/// Each command and how it ended (`Ok` with nothing, or the error).
pub steps: Vec<(String, std::result::Result<(), String>)>,
/// Internal errors seen: (location, message).
pub panics: Vec<(String, String)>,
/// One of them is the reported one (the same signature).
pub reproduced: bool,
/// The session the replay ends with.
pub session: Session,
}
static REPLAY_PANICS: Mutex<Vec<(String, String)>> = Mutex::new(Vec::new());
/// Replay a report ([`read`]): open its model (or start from an empty one), run its commands,
/// and say whether the same internal error happens again. Files the commands write can go only
/// into `scratch` (reads go anywhere: the model's geometry is where it was). The panic hook is
/// replaced while it runs: for the CLI and tests, never the app.
pub fn replay(report: &Value, scratch: &Path) -> std::result::Result<Replay, String> {
let id = report.get("id").and_then(Value::as_str).unwrap_or_default();
let replay_path = report.get("replay_path").and_then(Value::as_str).ok_or_else(|| format!("report {id} cannot be replayed (see its notes)"))?;
let script: Value = fieldcraft_io::fs::read_capped(Path::new(replay_path), MAX_JOURNAL_BYTES * 4)
.ok()
.and_then(|b| serde_json::from_slice(&b).ok())
.ok_or_else(|| format!("{replay_path}: not a replay"))?;
let commands = script.get("commands").and_then(Value::as_array).cloned().unwrap_or_default();
let mut s = Session::default();
if let Some(m) = report.get("model_path").and_then(Value::as_str) {
s.execute("file.open", &json!({ "path": m })).map_err(|e| format!("{m}: {e}"))?;
}
s.file_access = fieldcraft_io::roots::Roots::writes_within(scratch).map_err(|e| e.to_string())?;
if let Ok(mut p) = REPLAY_PANICS.lock() {
p.clear();
}
let previous = std::panic::take_hook();
std::panic::set_hook(Box::new(|info| {
let loc = info.location().map_or_else(|| "(unknown)".to_string(), |l| format!("{}:{}", l.file(), l.line()));
let msg = info.payload_as_str().unwrap_or("(not a text message)").to_string();
if let Ok(mut p) = REPLAY_PANICS.lock() {
p.push((loc, limited(&msg, MAX_MESSAGE)));
}
}));
let mut steps = Vec::new();
for c in commands.iter().take(100_000) {
let cmd = c.get("command").and_then(Value::as_str).unwrap_or_default().to_string();
let r = s.execute(&cmd, c.get("params").unwrap_or(&Value::Null)).map(|_| ()).map_err(|e| e.to_string());
steps.push((cmd, r));
}
std::panic::set_hook(previous);
let panics = REPLAY_PANICS.lock().map(|p| p.clone()).unwrap_or_default();
let want = report.get("signature").and_then(Value::as_str).unwrap_or_default();
let reproduced = panics.iter().any(|(l, m)| format!("{:016x}", signature(l, m)) == want);
Ok(Replay { steps, panics, reproduced, session: s })
}
#[cfg(test)]
#[path = "crash_tests.rs"]
mod tests;