diff --git a/Cargo.lock b/Cargo.lock index 03e789f08..37233ef58 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1422,6 +1422,7 @@ dependencies = [ name = "effectcraft" version = "0.23.1" dependencies = [ + "chrono", "cpal", "craft-update", "effectcraft-engine", @@ -1439,6 +1440,7 @@ dependencies = [ "rfd", "serde", "serde_json", + "sysinfo", "winit", "winresource", "zbus", @@ -3068,7 +3070,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "1bd49230192a3797a9a4d6abe9b3eed6f7fa4c8a8a4947977c6f80025f92cbd8" dependencies = [ "rustix 1.1.5", - "windows-link", + "windows-link 0.2.1", ] [[package]] @@ -3668,7 +3670,7 @@ dependencies = [ "simd_cesu8", "thiserror 2.0.21", "walkdir", - "windows-link", + "windows-link 0.2.1", ] [[package]] @@ -3814,7 +3816,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "d7c4b02199fee7c5d21a5ae7d8cfa79a6ef5bb2fc834d6e9058e89c825efdc55" dependencies = [ "cfg-if", - "windows-link", + "windows-link 0.2.1", ] [[package]] @@ -4120,6 +4122,15 @@ dependencies = [ "memchr", ] +[[package]] +name = "ntapi" +version = "0.4.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c3b335231dfd352ffb0f8017f3b6027a4917f7df785ea2143d8af2adc66980ae" +dependencies = [ + "winapi", +] + [[package]] name = "nu-ansi-term" version = "0.50.3" @@ -4434,6 +4445,16 @@ dependencies = [ "objc2-core-foundation", ] +[[package]] +name = "objc2-io-kit" +version = "0.3.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "33fafba39597d6dc1fb709123dfa8289d39406734be322956a69f0931c73bb15" +dependencies = [ + "libc", + "objc2-core-foundation", +] + [[package]] name = "objc2-io-surface" version = "0.3.2" @@ -4664,7 +4685,7 @@ dependencies = [ "libc", "redox_syscall 0.5.18", "smallvec", - "windows-link", + "windows-link 0.2.1", ] [[package]] @@ -6071,6 +6092,20 @@ dependencies = [ "walkdir", ] +[[package]] +name = "sysinfo" +version = "0.37.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "16607d5caffd1c07ce073528f9ed972d88db15dd44023fa57142963be3feb11f" +dependencies = [ + "libc", + "memchr", + "ntapi", + "objc2-core-foundation", + "objc2-io-kit", + "windows 0.61.3", +] + [[package]] name = "tag_ptr" version = "0.1.0" @@ -7224,16 +7259,38 @@ dependencies = [ "windows-targets 0.52.6", ] +[[package]] +name = "windows" +version = "0.61.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9babd3a767a4c1aef6900409f85f5d53ce2544ccdfaa86dad48c91782c6d6893" +dependencies = [ + "windows-collections 0.2.0", + "windows-core 0.61.2", + "windows-future 0.2.1", + "windows-link 0.1.3", + "windows-numerics 0.2.0", +] + [[package]] name = "windows" version = "0.62.2" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "527fadee13e0c05939a6a05d5bd6eec6cd2e3dbd648b9f8e447c6518133d8580" dependencies = [ - "windows-collections", + "windows-collections 0.3.2", "windows-core 0.62.2", - "windows-future", - "windows-numerics", + "windows-future 0.3.2", + "windows-numerics 0.3.1", +] + +[[package]] +name = "windows-collections" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3beeceb5e5cfd9eb1d76b381630e82c4241ccd0d27f1a39ed41b2760b255c5e8" +dependencies = [ + "windows-core 0.61.2", ] [[package]] @@ -7255,6 +7312,19 @@ dependencies = [ "windows-targets 0.52.6", ] +[[package]] +name = "windows-core" +version = "0.61.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c0fdd3ddb90610c7638aa2b3a3ab2904fb9e5cdbecc643ddb3647212781c4ae3" +dependencies = [ + "windows-implement", + "windows-interface", + "windows-link 0.1.3", + "windows-result 0.3.4", + "windows-strings 0.4.2", +] + [[package]] name = "windows-core" version = "0.62.2" @@ -7263,9 +7333,20 @@ checksum = "b8e83a14d34d0623b51dce9581199302a221863196a1dde71a7663a4c2be9deb" dependencies = [ "windows-implement", "windows-interface", - "windows-link", + "windows-link 0.2.1", "windows-result 0.4.1", - "windows-strings", + "windows-strings 0.5.1", +] + +[[package]] +name = "windows-future" +version = "0.2.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "fc6a41e98427b19fe4b73c550f060b59fa592d7d686537eebf9385621bfbad8e" +dependencies = [ + "windows-core 0.61.2", + "windows-link 0.1.3", + "windows-threading 0.1.0", ] [[package]] @@ -7275,8 +7356,8 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "e1d6f90251fe18a279739e78025bd6ddc52a7e22f921070ccdc67dde84c605cb" dependencies = [ "windows-core 0.62.2", - "windows-link", - "windows-threading", + "windows-link 0.2.1", + "windows-threading 0.2.1", ] [[package]] @@ -7301,12 +7382,28 @@ dependencies = [ "syn 2.0.119", ] +[[package]] +name = "windows-link" +version = "0.1.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5e6ad25900d524eaabdbbb96d20b4311e1e7ae1699af4fb28c17ae66c80d798a" + [[package]] name = "windows-link" version = "0.2.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "f0805222e57f7521d6a62e36fa9163bc891acd422f971defe97d64e70d0a4fe5" +[[package]] +name = "windows-numerics" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9150af68066c4c5c07ddc0ce30421554771e528bde427614c61038bc2c92c2b1" +dependencies = [ + "windows-core 0.61.2", + "windows-link 0.1.3", +] + [[package]] name = "windows-numerics" version = "0.3.1" @@ -7314,7 +7411,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "6e2e40844ac143cdb44aead537bbf727de9b044e107a0f1220392177d15b0f26" dependencies = [ "windows-core 0.62.2", - "windows-link", + "windows-link 0.2.1", ] [[package]] @@ -7323,9 +7420,9 @@ version = "0.6.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "02752bf7fbdcce7f2a27a742f798510f3e5ad88dbe84871e5168e2120c3d5720" dependencies = [ - "windows-link", + "windows-link 0.2.1", "windows-result 0.4.1", - "windows-strings", + "windows-strings 0.5.1", ] [[package]] @@ -7337,13 +7434,31 @@ dependencies = [ "windows-targets 0.52.6", ] +[[package]] +name = "windows-result" +version = "0.3.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "56f42bd332cc6c8eac5af113fc0c1fd6a8fd2aa08a0119358686e5160d0586c6" +dependencies = [ + "windows-link 0.1.3", +] + [[package]] name = "windows-result" version = "0.4.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "7781fa89eaf60850ac3d2da7af8e5242a5ea78d1a11c49bf2910bb5a73853eb5" dependencies = [ - "windows-link", + "windows-link 0.2.1", +] + +[[package]] +name = "windows-strings" +version = "0.4.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "56e6c93f3a0c3b36176cb1327a4958a0353d5d166c2a35cb268ace15e91d3b57" +dependencies = [ + "windows-link 0.1.3", ] [[package]] @@ -7352,7 +7467,7 @@ version = "0.5.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "7837d08f69c77cf6b07689544538e017c1bfcf57e34b4c0ff58e6c2cd3b37091" dependencies = [ - "windows-link", + "windows-link 0.2.1", ] [[package]] @@ -7388,7 +7503,7 @@ version = "0.61.2" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "ae137229bcbd6cdf0f7b80a31df61766145077ddf49416a728b02cb3921ff3fc" dependencies = [ - "windows-link", + "windows-link 0.2.1", ] [[package]] @@ -7422,13 +7537,22 @@ dependencies = [ "windows_x86_64_msvc 0.52.6", ] +[[package]] +name = "windows-threading" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b66463ad2e0ea3bbf808b7f1d371311c80e115c0b71d60efc142cafbcfb057a6" +dependencies = [ + "windows-link 0.1.3", +] + [[package]] name = "windows-threading" version = "0.2.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "3949bd5b99cafdf1c7ca86b43ca564028dfe27d66958f2470940f73d86d75b37" dependencies = [ - "windows-link", + "windows-link 0.2.1", ] [[package]] diff --git a/apps/effectcraft/Cargo.toml b/apps/effectcraft/Cargo.toml index 3030ee96d..21bd46755 100644 --- a/apps/effectcraft/Cargo.toml +++ b/apps/effectcraft/Cargo.toml @@ -25,6 +25,9 @@ rfd = { workspace = true } pollster = { workspace = true } cpal = { workspace = true } log = { workspace = true } +chrono = { workspace = true } +# MIT; safe process handles and target-only memory observation for the crash helper. +sysinfo = { version = "=0.37.2", default-features = false, features = ["system"] } [target.'cfg(target_os = "linux")'.dependencies] # Native GNOME/Wayland controls without a bundled title font. diff --git a/apps/effectcraft/src/crash_observation.rs b/apps/effectcraft/src/crash_observation.rs new file mode 100644 index 000000000..b67dc07fe --- /dev/null +++ b/apps/effectcraft/src/crash_observation.rs @@ -0,0 +1,264 @@ +//! Bounded observations made outside the failed GUI. Measurements are evidence, not a cause. +use std::io::{self, Write}; +use std::sync::mpsc::{self, Receiver}; +use std::time::{Duration, Instant, SystemTime}; + +use sysinfo::{MemoryRefreshKind, Pid, ProcessRefreshKind, ProcessesToUpdate, System}; + +pub fn utc() -> String { + chrono::DateTime::::from(SystemTime::now()).to_rfc3339_opts(chrono::SecondsFormat::Millis, true) +} + +#[derive(Default)] +struct Memory { + samples: u64, + resident_peak: u64, + virtual_peak: u64, + available_min: Option, + total: u64, + last_at: Option, + last_uptime_secs: Option, +} + +impl Memory { + fn sample(&mut self, resident: u64, virtual_bytes: u64, available: u64, total: u64) { + self.samples = self.samples.saturating_add(1); + self.resident_peak = self.resident_peak.max(resident); + self.virtual_peak = self.virtual_peak.max(virtual_bytes); + // Zero total means the platform could not supply physical-memory information. + if total != 0 { + self.available_min = Some(self.available_min.map_or(available, |old| old.min(available))); + self.total = total; + } + self.last_at = Some(utc()); + } +} + +pub struct Observation { + pid: Pid, + system: System, + birth: Option, + started: Instant, + started_at: String, + detected_at: Option, + last_sample: Instant, + memory: Memory, + // Only Windows can retrieve an unrelated process's ExitStatus through a retained handle. + exit: Receiver>, + status: Option, + alive: Option, +} + +fn target_system(pid: Pid) -> System { + let mut system = System::new(); + system.refresh_processes_specifics(ProcessesToUpdate::Some(&[pid]), false, ProcessRefreshKind::nothing().with_memory()); + system +} + +impl Observation { + /// Acquire the Windows handle before acknowledging reporter readiness, so even an immediate + /// GUI abort leaves an observable process object. Never enumerate commands or environments. + pub fn start(pid: u32) -> Self { + let pid = Pid::from_u32(pid); + let system = target_system(pid); + let birth = system.process(pid).map(|p| p.start_time()); + let (send, exit) = mpsc::sync_channel(1); + #[cfg(windows)] + { + let waiting = target_system(pid); + let _ = std::thread::Builder::new().name("ec-exit-status".into()).spawn(move || { + let status = waiting.process(pid).and_then(|p| p.wait()); + let _ = send.send(status); + }); + } + #[cfg(not(windows))] + drop(send); + let now = Instant::now(); + let mut result = Self { + pid, + system, + birth, + started: now, + started_at: utc(), + detected_at: None, + last_sample: now, + memory: Memory::default(), + exit, + status: None, + alive: None, + }; + result.sample(); + result + } + + fn sample(&mut self) { + self.system.refresh_processes_specifics(ProcessesToUpdate::Some(&[self.pid]), false, ProcessRefreshKind::nothing().with_memory()); + self.system.refresh_memory_specifics(MemoryRefreshKind::nothing().with_ram()); + let process = self.system.process(self.pid).filter(|p| Some(p.start_time()) == self.birth && p.exists()); + self.alive = self.birth.map(|_| process.is_some()); + if let Some(process) = process { + self.memory.last_uptime_secs = Some(process.run_time()); + self.memory.sample(process.memory(), process.virtual_memory(), self.system.available_memory(), self.system.total_memory()); + } + if let Ok(status) = self.exit.try_recv() { + self.status = status; + } + self.last_sample = Instant::now(); + } + + pub fn tick(&mut self) { + if self.last_sample.elapsed() >= Duration::from_secs(1) { + self.sample(); + } + } + + /// Pipe closure can precede the OS signalling process termination. Bound that grace period; + /// a broken pipe or early reporter drop must never be called a confirmed process exit. + pub fn finish(&mut self) { + self.detected_at = Some(utc()); + if self.status.is_none() + && let Ok(status) = self.exit.recv_timeout(Duration::from_millis(750)) + { + self.status = status; + } + self.sample(); + } + + pub fn confirmed_exit(&self) -> bool { + self.status.is_some() + } + + pub fn write(&self, report: &mut impl Write) -> io::Result<()> { + writeln!( + report, + "Detection UTC: {}\nObserver started UTC: {}\nObserved duration: {} ms", + self.detected_at.as_deref().unwrap_or("not captured"), + self.started_at, + self.started.elapsed().as_millis() + )?; + writeln!( + report, + "Process observation: {}", + if self.confirmed_exit() { + "process termination observed" + } else if self.alive == Some(true) { + "GUI still present when the control channel ended" + } else { + "target absent from refresh or process identity/status unavailable (not proof of termination)" + } + )?; + match &self.status { + Some(status) => { + writeln!(report, "OS exit status: {status}")?; + #[cfg(windows)] + if let Some(code) = status.code() { + write_windows_status(report, code as u32)?; + } + } + None => writeln!(report, "OS exit status: unavailable (not inferred from the control pipe)")?, + } + let memory = &self.memory; + writeln!(report, "\nMemory evidence (1 s sampling; sampled maxima, not OS peaks):\nTarget-present sampling attempts: {}", memory.samples)?; + if let Some(uptime) = memory.last_uptime_secs { + writeln!(report, "GUI uptime at last target-present observation: {uptime} s")?; + } + #[cfg(windows)] + let virtual_label = "Peak sampled private committed bytes"; + #[cfg(not(windows))] + let virtual_label = "Peak sampled virtual bytes"; + if memory.samples != 0 { + writeln!( + report, + "Last target sampling attempt UTC: {}\nPeak sampled resident bytes: {}\n{virtual_label}: {}", + memory.last_at.as_deref().unwrap_or("unavailable"), + memory.resident_peak, + memory.virtual_peak + )?; + } + if let Some(available) = memory.available_min { + writeln!(report, "Minimum sampled system available RAM bytes: {available}\nSystem total RAM bytes at last sample: {}", memory.total)?; + } + writeln!( + report, + "Samples can miss short spikes or retain stale/zero readings when an OS query fails; per-field success is not exposed by sysinfo. Windows private commit is not GPU VRAM; on other platforms virtual memory is not physical RAM. System commit limit/usage and GPU memory budgets were not collected. No memory-pressure threshold establishes the cause of this incident.\nThe memory observer does not collect process command lines, environments, documents, native dumps or system event logs. The existing session-log tail below may contain paths or other logged details; review it before sharing." + ) + } +} + +#[cfg(any(windows, test))] +fn write_windows_status(report: &mut impl Write, code: u32) -> io::Result<()> { + let meaning = match code { + 0xc0000005 => "STATUS_ACCESS_VIOLATION", + 0xc0000017 => "STATUS_NO_MEMORY", + 0xc000012d => "STATUS_COMMITMENT_LIMIT", + 0xc0000374 => "STATUS_HEAP_CORRUPTION", + 0xc0000409 => "STATUS_STACK_BUFFER_OVERRUN / fast fail", + 0x40000015 => "STATUS_FATAL_APP_EXIT", + _ => "unclassified", + }; + writeln!( + report, + "Windows status bits: 0x{code:08X} ({meaning})\nThese are process exit bits, not a verified exception record. Software can set an exit code explicitly; an access violation does not identify the faulting module or prove a driver crash." + ) +} + +#[cfg(test)] +mod tests { + use super::*; + + #[test] + fn missing_target_without_exit_status_does_not_confirm_termination() { + let (send, exit) = mpsc::sync_channel(1); + drop(send); + let now = Instant::now(); + let observation = Observation { + pid: Pid::from_u32(1), + system: System::new(), + birth: Some(1), + started: now, + started_at: utc(), + detected_at: Some(utc()), + last_sample: now, + memory: Memory::default(), + exit, + status: None, + alive: Some(false), + }; + assert!(!observation.confirmed_exit()); + let mut report = Vec::new(); + observation.write(&mut report).unwrap(); + let report = String::from_utf8(report).unwrap(); + assert!(report.contains("not proof of termination")); + assert!(!report.contains("process termination observed")); + } + + #[test] + fn memory_high_water_marks_are_bounded_and_not_a_causal_diagnosis() { + let mut memory = Memory::default(); + memory.sample(40, 80, 30, 100); + memory.sample(20, 90, 50, 100); + assert_eq!((memory.samples, memory.resident_peak, memory.virtual_peak, memory.available_min), (2, 40, 90, Some(30))); + memory.sample(0, 0, 0, 0); + assert_eq!(memory.available_min, Some(30)); + } + + #[test] + fn windows_status_bits_preserve_unsigned_codes_without_claiming_a_driver_crash() { + for (code, name) in + [(0xc0000005, "STATUS_ACCESS_VIOLATION"), (0xc0000017, "STATUS_NO_MEMORY"), (0xc000012d, "STATUS_COMMITMENT_LIMIT"), (42, "unclassified")] + { + let mut text = Vec::new(); + write_windows_status(&mut text, code).unwrap(); + let text = String::from_utf8(text).unwrap(); + assert!(text.contains(name)); + assert!(text.contains(&format!("0x{code:08X}"))); + assert!(text.contains("not a verified exception record")); + } + } + + #[test] + fn utc_timestamps_are_parseable_and_zero_offset() { + let time = chrono::DateTime::parse_from_rfc3339(&utc()).unwrap(); + assert_eq!(time.offset().local_minus_utc(), 0); + } +} diff --git a/apps/effectcraft/src/crash_report.rs b/apps/effectcraft/src/crash_report.rs index 32306aa5c..6ca42aab7 100644 --- a/apps/effectcraft/src/crash_report.rs +++ b/apps/effectcraft/src/crash_report.rs @@ -2,23 +2,31 @@ //! //! Allocation failure can abort without a panic hook. The GUI therefore owns a pipe to a //! helper which never loads a project, font database or GPU. Only an explicit marker after -//! normal teardown suppresses the report. EOF alone identifies an unexpected exit, not its -//! cause. System-wide exhaustion can still prevent the helper or its native dialog working. +//! normal teardown suppresses the report. EOF alone identifies a lost control channel, not +//! a process exit or its cause. System-wide exhaustion can still prevent the helper or its native dialog working. +use std::collections::VecDeque; use std::ffi::{OsStr, OsString}; use std::fs::{File, OpenOptions}; use std::io::{self, Read, Seek, SeekFrom, Write}; use std::path::{Path, PathBuf}; use std::process::{Child, ChildStdin, Command, Stdio}; +use std::sync::mpsc::{self, RecvTimeoutError}; use std::time::{Duration, Instant, SystemTime, UNIX_EPOCH}; +#[path = "crash_observation.rs"] +mod observation; + const FLAG: &str = "--internal-crash-reporter"; const CLEAN: &[u8] = b"EFFECTCRAFT_CLEAN_EXIT_V1\n"; const LOG_BYTES: usize = 64 * 1024; const HEADER_BYTES: usize = 128; +const READY: &[u8] = b"READY\n"; +const EVENT_BYTES: usize = 128; +const EVENT_COUNT: usize = 32; /// Owned only by the GUI, never handed to another child. Dropping it without `finish` closes -/// the pipe and reports an unexpected exit; there is intentionally no clean-exit Drop hook. +/// the pipe and reports the incident; there is intentionally no clean-exit Drop hook. pub struct Reporter { pipe: ChildStdin, child: Child, @@ -72,6 +80,20 @@ impl Shutdown { Ok(()) } + /// Keep only fixed-vocabulary, bounded lifecycle facts outside the GUI. Callers emit each + /// category once; their combined payload fits well below the smallest OS pipe buffer. + pub fn record(&self, event: &'static str) -> io::Result<()> { + if event.len() > 100 || event.contains(['\n', '\r']) { + return Err(io::Error::other("invalid diagnostic observation")); + } + let mut slot = self.0.lock().map_err(|_| io::Error::other("crash reporter ownership was poisoned"))?; + if let Some(reporter) = slot.as_mut() { + writeln!(reporter.pipe, "EVENT {event}")?; + reporter.pipe.flush()?; + } + Ok(()) + } + /// Consume the reporter exactly once, after the applicable platform teardown boundary. pub fn finish(&self) -> io::Result<()> { let reporter = self.0.lock().map_err(|_| io::Error::other("crash reporter ownership was poisoned"))?.take(); @@ -105,12 +127,18 @@ pub fn start(id: &str, log: Option<&Path>, reports: &Path, interactive: bool) -> log.map_or_else(OsString::new, |p| p.as_os_str().to_owned()), reports.as_os_str().to_owned(), OsString::from(if interactive { "1" } else { "0" }), + OsString::from(std::process::id().to_string()), ]; spawn(&exe, &args) } fn spawn(exe: &Path, args: &[OsString]) -> io::Result { - let mut child = Command::new(exe).args(args).stdin(Stdio::piped()).stdout(Stdio::null()).spawn()?; + let mut child = Command::new(exe).args(args).stdin(Stdio::piped()).stdout(Stdio::piped()).spawn()?; + if let Err(error) = ready(&mut child) { + let _ = child.kill(); + let _ = finish_child(&mut child, Duration::from_millis(100)); + return Err(error); + } match child.stdin.take() { Some(pipe) => Ok(Reporter { pipe, child }), None => { @@ -121,6 +149,36 @@ fn spawn(exe: &Path, args: &[OsString]) -> io::Result { } } +/// A fixed acknowledgement means the helper holds the process observation before heavy GUI +/// work begins. A suspended helper cannot hold startup indefinitely. +fn ready(child: &mut Child) -> io::Result<()> { + let mut output = child.stdout.take().ok_or_else(|| io::Error::other("crash reporter has no readiness pipe"))?; + let (send, receive) = mpsc::sync_channel(1); + std::thread::Builder::new().name("ec-reporter-ready".into()).spawn(move || { + let mut bytes = [0; READY.len()]; + #[cfg(not(test))] + let result = + output.read_exact(&mut bytes).and_then(|()| if bytes == READY { Ok(()) } else { Err(io::Error::other("invalid reporter acknowledgement")) }); + // libtest prints its bounded banner before invoking the helper role. + #[cfg(test)] + let result = (|| { + for _ in 0..1024 { + bytes.rotate_left(1); + output.read_exact(&mut bytes[READY.len() - 1..])?; + if bytes == READY { + return Ok(()); + } + } + Err(io::Error::other("reporter acknowledgement missing")) + })(); + let _ = send.send(result); + // Keep the pipe open for libtest's trailing result (and future helper output), without + // storing it. Dropping it at READY would turn a clean helper exit into BrokenPipe. + let _ = io::copy(&mut output, &mut io::sink()); + })?; + receive.recv_timeout(Duration::from_secs(3)).map_err(|_| io::Error::other("crash reporter readiness timed out"))? +} + /// Handle the internal mode before logging, argument parsing, updates or GUI initialization. /// The callback is a native dialog on this helper's main thread, not on the failed GUI's. pub fn maybe_run(args: &[OsString], show: impl FnOnce(&str)) -> bool { @@ -128,7 +186,7 @@ pub fn maybe_run(args: &[OsString], show: impl FnOnce(&str)) -> bool { return false; } let parsed = match args { - [_, id, log, reports, interactive] => id + [_, id, log, reports, interactive, pid] => id .to_str() .filter(|id| valid_id(id)) .zip(match interactive.to_str() { @@ -136,27 +194,61 @@ pub fn maybe_run(args: &[OsString], show: impl FnOnce(&str)) -> bool { Some("1") => Some(true), _ => None, }) - .map(|(id, interactive)| (id, (!log.is_empty()).then(|| Path::new(log)), Path::new(reports), interactive)), + .zip(pid.to_str().and_then(|p| p.parse::().ok()).filter(|pid| *pid != 0)) + .map(|((id, interactive), pid)| (id, (!log.is_empty()).then(|| Path::new(log)), Path::new(reports), interactive, pid)), _ => None, }; - let Some((id, log, reports, interactive)) = parsed else { + let Some((id, log, reports, interactive, pid)) = parsed else { eprintln!("EffectCraft crash reporter: invalid internal arguments"); return true; }; // Keep the exact file open while the GUI is alive: a later rotation must not substitute // another instance's log. If rotation won the startup race, the session marker rejects it. let mut log = SessionLog::open(log, id); - match clean_exit(&mut io::stdin().lock()) { - Ok(true) => {} - result => { - let failure = result.err().map(|e| e.to_string()); - let saved = write_report(reports, id, &mut log, failure.as_deref()); - let description = description(&saved); - eprintln!("{description}"); - if interactive { - show(&description); + let mut observation = observation::Observation::start(pid); + // A GUI that dies during helper startup can already have closed this read end. Keep + // watching its control pipe and save the report rather than losing that early failure. + let _ = io::stdout().write_all(READY).and_then(|()| io::stdout().flush()); + // The reader has one bounded queue; the monitor never waits on a live pipe, so it can + // sample the target even when no log or lifecycle message is emitted. + let (send, receive) = mpsc::sync_channel(1); + let reader = std::thread::Builder::new().name("ec-reporter-pipe".into()).spawn(move || { + let mut input = io::stdin().lock(); + loop { + let message = read_message(&mut input); + let terminal = !matches!(message, Ok(Message::Event(_))); + if send.send(message).is_err() || terminal { + break; } } + }); + let mut events = VecDeque::with_capacity(EVENT_COUNT); + let failure = if reader.is_err() { + Some("control reader could not start".to_owned()) + } else { + loop { + observation.tick(); + match receive.recv_timeout(Duration::from_millis(250)) { + Ok(Ok(Message::Clean)) => return true, + Ok(Ok(Message::Event(event))) => { + if events.len() == EVENT_COUNT { + events.pop_front(); + } + events.push_back(format!("{} {event}", observation::utc())); + } + Ok(Ok(Message::Ended)) => break None, + Ok(Err(error)) => break Some(error.to_string()), + Err(RecvTimeoutError::Timeout) => continue, + Err(RecvTimeoutError::Disconnected) => break Some("control reader disconnected".to_owned()), + } + } + }; + observation.finish(); + let saved = write_report(reports, id, &mut log, failure.as_deref(), &observation, &events); + let description = description(&saved, observation.confirmed_exit()); + eprintln!("{description}"); + if interactive { + show(&description); } true } @@ -165,20 +257,43 @@ fn valid_id(id: &str) -> bool { !id.is_empty() && id.len() <= 80 && id.bytes().all(|c| c.is_ascii_digit() || c == b'-') } -/// Fixed-size comparison: arbitrary/truncated input never grows a buffer or counts as clean. -fn clean_exit(input: &mut impl Read) -> io::Result { - let mut marker = [0u8; CLEAN.len()]; - let mut filled = 0; - while filled < marker.len() { - let remaining = marker.get_mut(filled..).ok_or_else(|| io::Error::other("invalid control marker offset"))?; - match input.read(remaining) { - Ok(0) => return Ok(false), - Ok(n) => filled += n, - Err(e) if e.kind() == io::ErrorKind::Interrupted => {} - Err(e) => return Err(e), +enum Message { + Clean, + Event(String), + Ended, +} + +/// Every line and the retained event ring are bounded, including malformed control input. +fn read_message(input: &mut impl Read) -> io::Result { + let mut line = [0u8; EVENT_BYTES]; + for i in 0..line.len() { + let byte = line.get_mut(i).ok_or_else(|| io::Error::other("invalid control offset"))?; + loop { + match input.read(std::slice::from_mut(byte)) { + Ok(0) => return Ok(Message::Ended), + Ok(_) => break, + Err(error) if error.kind() == io::ErrorKind::Interrupted => continue, + Err(error) => return Err(error), + } + } + if *byte == b'\n' { + let text = line.get(..=i).ok_or_else(|| io::Error::other("invalid control line"))?; + if text == CLEAN { + return Ok(Message::Clean); + } + if let Some(event) = text.strip_prefix(b"EVENT ") { + let event = std::str::from_utf8(event).map_err(|_| io::Error::other("non-UTF8 diagnostic observation"))?; + return Ok(Message::Event(event.trim_end().to_owned())); + } + return Ok(Message::Ended); } } - Ok(marker == CLEAN) + Err(io::Error::other("control line exceeded its fixed limit")) +} + +#[cfg(test)] +fn clean_exit(input: &mut impl Read) -> io::Result { + Ok(matches!(read_message(input)?, Message::Clean)) } enum SessionLog { @@ -228,7 +343,14 @@ impl SessionLog { } } -fn write_report(reports: &Path, id: &str, log: &mut SessionLog, pipe_error: Option<&str>) -> io::Result { +fn write_report( + reports: &Path, + id: &str, + log: &mut SessionLog, + pipe_error: Option<&str>, + observation: &observation::Observation, + events: &VecDeque, +) -> io::Result { if !valid_id(id) { return Err(io::Error::other("invalid report identity")); } @@ -244,8 +366,13 @@ fn write_report(reports: &Path, id: &str, log: &mut SessionLog, pipe_error: Opti )?; writeln!( report, - "The GUI's control pipe ended without its clean-exit marker.\nThe exit status and exact cause are not available to this reporter.\nMemory exhaustion, a native crash or external termination are possible.\nThis report was saved locally; it was not sent anywhere." + "The GUI control channel ended without its clean-exit marker.\nThe exact cause is not established. GPU fallback, memory pressure and process exit are separate observations, not a proven causal chain.\nThis report was saved locally; it was not sent anywhere." )?; + observation.write(&mut report)?; + writeln!(report, "\nRetained lifecycle observations (last {EVENT_COUNT}; UTC is helper receipt time):")?; + for event in events { + writeln!(report, "{event}")?; + } if let Some(error) = pipe_error { writeln!(report, "Control pipe error: {error}")?; } @@ -256,13 +383,15 @@ fn write_report(reports: &Path, id: &str, log: &mut SessionLog, pipe_error: Opti Ok(path) } -fn description(saved: &io::Result) -> String { +fn description(saved: &io::Result, confirmed_exit: bool) -> String { let diagnostic = match saved { Ok(path) => format!("A diagnostic report was saved to:\n{}", path.display()), Err(error) => format!("A diagnostic report could not be saved: {error}"), }; + let incident = + if confirmed_exit { "EffectCraft stopped unexpectedly." } else { "EffectCraft lost its diagnostic control channel; process exit is not confirmed." }; format!( - "EffectCraft stopped unexpectedly.\n\n{diagnostic}\n\nThe exact cause is unknown. Reopen EffectCraft to check for an existing auto-save. Changes since the last auto-save may be lost.\n\nNo report has been sent anywhere." + "{incident}\n\n{diagnostic}\n\nThe exact cause is unknown. If EffectCraft has closed, reopen it to check for an existing auto-save. Changes since the last auto-save may be lost.\n\nNo report has been sent anywhere." ) } @@ -276,6 +405,10 @@ mod tests { static NEXT: AtomicUsize = AtomicUsize::new(0); const ROLE: &str = "EFFECTCRAFT_CRASH_REPORT_TEST_ROLE"; + fn test_report(dir: &Path, id: &str, log: &mut SessionLog) -> io::Result { + write_report(dir, id, log, None, &observation::Observation::start(std::process::id()), &VecDeque::new()) + } + fn folder() -> PathBuf { let p = std::env::temp_dir().join(format!("ec-crash-report-{}-{}", run_id(), NEXT.fetch_add(1, Ordering::Relaxed))); std::fs::create_dir_all(&p).unwrap(); @@ -283,7 +416,7 @@ mod tests { } fn test_name(name: &str) -> String { - // Also usable as a standalone std-only rustc test while the app's build cache is busy. + // Also usable from an isolated harness with the reporter dependencies. let prefix = module_path!().split_once("::").map_or("", |(_, rest)| rest); format!("{prefix}::{name}") } @@ -299,10 +432,12 @@ mod tests { .env("EC_REPORT_DIR", dir) .env("EC_REPORT_ID", id) .env("EC_REPORT_INTERACTIVE", if interactive { "1" } else { "0" }) + .env("EC_REPORT_PID", std::process::id().to_string()) .stdin(Stdio::piped()) - .stdout(Stdio::null()) + .stdout(Stdio::piped()) .spawn() .unwrap(); + ready(&mut child).unwrap(); Reporter { pipe: child.stdin.take().unwrap(), child } } @@ -321,7 +456,7 @@ mod tests { for mut input in [b"".as_slice(), &CLEAN[..CLEAN.len() - 1], b"clean", b"EFFECTCRAFT_CLEAN_EXIT_V0\n"] { assert!(!clean_exit(&mut input).unwrap()); } - assert!(!clean_exit(&mut &vec![b'x'; 100_000][..]).unwrap()); + assert!(clean_exit(&mut &vec![b'x'; 100_000][..]).is_err()); } #[test] @@ -336,9 +471,9 @@ mod tests { let mut old = OpenOptions::new().append(true).open(dir.join("effectcraft.1.log")).unwrap(); old.write_all(&vec![b'a'; LOG_BYTES * 2]).unwrap(); old.write_all(b"\nGPU context retired\n").unwrap(); - let report = write_report(&dir, id, &mut log, None).unwrap(); + let report = test_report(&dir, id, &mut log).unwrap(); let text = std::fs::read_to_string(report).unwrap(); - assert!(text.len() < LOG_BYTES + 2048); + assert!(text.len() < LOG_BYTES + 4096); assert!(text.contains("GPU context retired")); assert!(!text.contains("OTHER SESSION")); std::fs::remove_dir_all(dir).unwrap(); @@ -350,7 +485,7 @@ mod tests { let path = dir.join("log"); std::fs::write(&path, "private other session").unwrap(); for (id, source) in [("1-1", Some(path.as_path())), ("1-2", None)] { - let report = write_report(&dir, id, &mut SessionLog::open(source, id), None).unwrap(); + let report = test_report(&dir, id, &mut SessionLog::open(source, id)).unwrap(); let text = std::fs::read_to_string(report).unwrap(); assert!(text.contains("Recent log unavailable")); assert!(!text.contains("private other session")); @@ -365,7 +500,7 @@ mod tests { std::fs::write(&path, "crash-report session 1-2\noriginal session\n").unwrap(); let mut log = SessionLog::open(Some(&path), "1-2"); std::fs::write(&path, "crash-report session 3-4\nprivate other session\n").unwrap(); - let report = write_report(&dir, "1-2", &mut log, None).unwrap(); + let report = test_report(&dir, "1-2", &mut log).unwrap(); let text = std::fs::read_to_string(report).unwrap(); assert!(text.contains("Recent log unavailable")); assert!(!text.contains("private other session")); @@ -388,13 +523,13 @@ mod tests { fn report_write_failure_is_described_and_existing_report_is_not_overwritten() { let dir = folder(); let mut log = SessionLog::Unavailable("no log".into()); - let first = write_report(&dir, "2-1", &mut log, None).unwrap(); + let first = test_report(&dir, "2-1", &mut log).unwrap(); let before = std::fs::read(&first).unwrap(); - let result = write_report(&dir, "2-1", &mut log, None); + let result = test_report(&dir, "2-1", &mut log); assert!(result.is_err()); - assert!(description(&result).contains("could not be saved")); + assert!(description(&result, false).contains("could not be saved")); assert_eq!(std::fs::read(first).unwrap(), before); - assert!(write_report(&dir, "../escape", &mut log, None).is_err()); + assert!(test_report(&dir, "../escape", &mut log).is_err()); std::fs::remove_dir_all(dir).unwrap(); } @@ -470,7 +605,10 @@ mod tests { assert!(!status.success()); wait_file(&dir.join("ready-4-1")); let text = std::fs::read_to_string(dir.join("crash-4-1.txt")).unwrap(); - assert!(text.contains("exact cause are not available")); + assert!(text.contains("exact cause is not established")); + assert!(text.contains("Detection UTC:")); + #[cfg(windows)] + assert!(text.contains("Windows status bits:")); std::fs::remove_dir_all(dir).unwrap(); } @@ -531,15 +669,70 @@ mod tests { std::fs::remove_dir_all(dir).unwrap(); } + #[test] + fn lost_pipe_keeps_bounded_lifecycle_evidence_without_claiming_process_exit() { + let dir = folder(); + let reporter = Shutdown::default(); + reporter.install(helper(&dir, "9-1")).unwrap(); + for _ in 0..40 { + reporter.record("GPU observation: wgpu validation error").unwrap(); + } + drop(reporter); + wait_file(&dir.join("ready-9-1")); + let text = std::fs::read_to_string(dir.join("crash-9-1.txt")).unwrap(); + assert!(text.contains("GUI still present")); + assert!(!text.contains("process termination observed")); + assert_eq!(text.matches("GPU observation: wgpu validation error").count(), EVENT_COUNT); + assert!(text.contains("Target-present sampling attempts:")); + assert!(text.len() < 8192); + std::fs::remove_dir_all(dir).unwrap(); + } + + #[test] + fn clean_exit_after_lifecycle_events_does_not_write_a_report() { + let dir = folder(); + let reporter = Shutdown::default(); + reporter.install(helper(&dir, "9-2")).unwrap(); + reporter.record("Backend selection source: default").unwrap(); + reporter.finish().unwrap(); + wait_file(&dir.join("ready-9-2")); + assert!(!dir.join("crash-9-2.txt").exists()); + std::fs::remove_dir_all(dir).unwrap(); + } + + #[test] + #[cfg(windows)] + fn windows_report_preserves_real_unsigned_exit_bits() { + let dir = folder(); + let status = Command::new(std::env::current_exe().unwrap()) + .args(["--exact", &test_name("aborting_parent"), "--ignored", "--nocapture"]) + .env(ROLE, "windows-status") + .env("EC_REPORT_DIR", &dir) + .stdout(Stdio::null()) + .status() + .unwrap(); + assert_eq!(status.code().map(|code| code as u32), Some(0xc0000017)); + wait_file(&dir.join("ready-9-3")); + let text = std::fs::read_to_string(dir.join("crash-9-3.txt")).unwrap(); + assert!(text.contains("Windows status bits: 0xC0000017 (STATUS_NO_MEMORY)")); + assert!(text.contains("not a verified exception record")); + assert!(text.contains("process termination observed")); + std::fs::remove_dir_all(dir).unwrap(); + } + #[test] fn internal_mode_rejects_invalid_arguments_without_launching_the_app() { assert!(!maybe_run(&[], |_| panic!("no dialog"))); assert!(!maybe_run(&[OsString::from("--version")], |_| panic!("no dialog"))); assert!(maybe_run(&[OsString::from(FLAG)], |_| panic!("no dialog"))); - let args = [FLAG, "../escape", "", "", "1"].map(OsString::from); + let args = [FLAG, "../escape", "", "", "1", "1"].map(OsString::from); assert!(maybe_run(&args, |_| panic!("no dialog"))); - let args = [FLAG, "1-1", "", "", "invalid"].map(OsString::from); + let args = [FLAG, "1-1", "", "", "invalid", "1"].map(OsString::from); assert!(maybe_run(&args, |_| panic!("no dialog"))); + for pid in ["0", "not-a-pid", "4294967296"] { + let args = [FLAG, "1-1", "", "", "0", pid].map(OsString::from); + assert!(maybe_run(&args, |_| panic!("no dialog"))); + } } #[test] @@ -556,7 +749,14 @@ mod tests { let dir = PathBuf::from(std::env::var_os("EC_REPORT_DIR").unwrap()); let id = std::env::var("EC_REPORT_ID").unwrap(); let interactive = std::env::var("EC_REPORT_INTERACTIVE").unwrap(); - let args = [OsString::from(FLAG), OsString::from(&id), OsString::new(), dir.as_os_str().to_owned(), OsString::from(&interactive)]; + let args = [ + OsString::from(FLAG), + OsString::from(&id), + OsString::new(), + dir.as_os_str().to_owned(), + OsString::from(&interactive), + std::env::var_os("EC_REPORT_PID").unwrap(), + ]; assert!(maybe_run(&args, |description| { assert_eq!(interactive, "1", "non-interactive reporter must not show a dialog"); assert!(dir.join(format!("crash-{id}.txt")).exists()); @@ -577,6 +777,12 @@ mod tests { after_teardown(Some(&reporter.clone()), || {}).unwrap(); std::process::exit(0); // Models macOS not returning from its native event loop. } + if role == "windows-status" { + let _reporter = helper(&dir, "9-3"); + // The real OS status is intentionally set, not actual memory exhaustion. The + // report must preserve this distinction rather than claiming a verified exception. + std::process::exit(0xc0000017u32 as i32); + } assert_eq!(role, "abort"); let _reporter = helper(&dir, "4-1"); std::process::abort(); diff --git a/apps/effectcraft/src/diagnostic_state.rs b/apps/effectcraft/src/diagnostic_state.rs new file mode 100644 index 000000000..042e6e88c --- /dev/null +++ b/apps/effectcraft/src/diagnostic_state.rs @@ -0,0 +1,147 @@ +//! Fixed-vocabulary observations retained by the crash helper independently of the log tail. +//! Driver messages and environment text can contain private data; never forward either here. + +use std::ffi::OsStr; +use std::sync::Arc; +use std::sync::atomic::{AtomicU8, Ordering}; + +use crate::crash_report::Shutdown; + +pub fn record(reporter: &Shutdown, event: &'static str) { + log::info!("diagnostic observation: {event}"); + if let Err(error) = reporter.record(event) { + log::warn!("could not retain diagnostic observation: {error}"); + } +} + +/// Mirror only wgpu's documented names/aliases, without calling its parser: that parser +/// logs unknown tokens verbatim. Unknown, non-Unicode and oversized values remain private. +pub fn backend_override_events(value: &OsStr) -> Vec<&'static str> { + let Some(value) = value.to_str().filter(|value| value.len() <= 4096) else { + return vec!["WGPU_BACKEND: non-Unicode or oversized value omitted"]; + }; + let mut selected = [false; 6]; + let mut unknown = false; + for token in value.split(',').map(str::trim) { + let aliases: &[&[&str]] = &[&["vulkan", "vk"], &["dx12", "d3d12"], &["metal", "mtl"], &["opengl", "gles", "gl"], &["webgpu"], &["noop"]]; + if let Some(index) = aliases.iter().position(|names| names.iter().any(|name| token.eq_ignore_ascii_case(name))) { + if let Some(flag) = selected.get_mut(index) { + *flag = true; + } + } else { + unknown = true; + } + } + let events = [ + "WGPU_BACKEND requests: vulkan", + "WGPU_BACKEND requests: dx12", + "WGPU_BACKEND requests: metal", + "WGPU_BACKEND requests: gl", + "WGPU_BACKEND requests: webgpu", + "WGPU_BACKEND requests: noop", + ]; + let mut result: Vec<_> = selected.into_iter().zip(events).filter_map(|(present, event)| present.then_some(event)).collect(); + if unknown { + result.push("WGPU_BACKEND: unrecognized or empty tokens omitted"); + } + result +} + +/// At most eight events per device, even when a driver floods its callbacks. A wgpu OOM +/// observation is not proof of system RAM exhaustion; device loss is not a driver-crash verdict. +#[derive(Clone)] +pub struct GpuObservations { + seen: Arc, + reporter: Shutdown, +} + +impl GpuObservations { + pub fn new(reporter: &Shutdown) -> Self { + Self { seen: Arc::new(AtomicU8::new(0)), reporter: reporter.clone() } + } + + pub fn uncaptured(&self, error: &eframe::wgpu::Error) { + let (bit, event) = match error { + eframe::wgpu::Error::OutOfMemory { .. } => (1, "GPU observation: wgpu out-of-memory error (not proof of system RAM exhaustion)"), + eframe::wgpu::Error::Validation { .. } => (2, "GPU observation: wgpu validation error"), + eframe::wgpu::Error::Internal { .. } => (4, "GPU observation: wgpu internal error"), + }; + self.once(bit, event); + } + + pub fn scoped(&self, error: effectcraft_ui_egui::gpu_failure::ScopedError) { + use effectcraft_ui_egui::gpu_failure::ScopedError; + let (bit, event) = match error { + ScopedError::OutOfMemory => (32, "GPU scoped observation: out-of-memory (not proof of system RAM exhaustion)"), + ScopedError::Internal => (64, "GPU scoped observation: internal error (not confirmed out-of-memory)"), + ScopedError::Validation => (128, "GPU scoped observation: validation error"), + }; + self.once(bit, event); + } + + pub fn device_lost(&self, reason: eframe::wgpu::DeviceLostReason) { + match reason { + eframe::wgpu::DeviceLostReason::Unknown => self.once(8, "GPU observation: device lost, reason unknown (not proof of a driver crash)"), + eframe::wgpu::DeviceLostReason::Destroyed => self.once(16, "GPU observation: device-lost callback, explicit device destruction"), + }; + } + + fn once(&self, bit: u8, event: &'static str) -> bool { + if self.seen.fetch_or(bit, Ordering::Relaxed) & bit != 0 { + return false; + } + record(&self.reporter, event); + true + } +} + +#[cfg(test)] +mod tests { + use super::*; + + #[test] + fn override_names_are_normalized_deduplicated_and_private() { + let events = backend_override_events(OsStr::new(" Vk, VULKAN, d3d12, MTL, gles, webgpu, noop, private-token")); + assert_eq!(events.len(), 7); + assert_eq!(events.first(), Some(&"WGPU_BACKEND requests: vulkan")); + assert!(!events.join(" ").contains("private-token")); + assert!(events.iter().all(|event| event.len() <= 100)); + assert_eq!(backend_override_events(OsStr::new("")).len(), 1); + assert_eq!(backend_override_events(OsStr::new(&"x".repeat(4097))), ["WGPU_BACKEND: non-Unicode or oversized value omitted"]); + } + + #[test] + fn gpu_categories_are_latched_independently() { + let observations = GpuObservations::new(&Shutdown::default()); + observations.uncaptured(&eframe::wgpu::Error::OutOfMemory { source: Box::new(std::io::Error::other("private driver detail")) }); + observations.device_lost(eframe::wgpu::DeviceLostReason::Unknown); + observations.device_lost(eframe::wgpu::DeviceLostReason::Unknown); + assert_eq!(observations.seen.load(Ordering::Relaxed), 9); + observations.device_lost(eframe::wgpu::DeviceLostReason::Destroyed); + observations.uncaptured(&eframe::wgpu::Error::Validation { + source: Box::new(std::io::Error::other("private driver detail")), + description: "private validation detail".into(), + }); + observations.uncaptured(&eframe::wgpu::Error::Internal { + source: Box::new(std::io::Error::other("private driver detail")), + description: "private internal detail".into(), + }); + assert_eq!(observations.seen.load(Ordering::Relaxed), 31); + use effectcraft_ui_egui::gpu_failure::ScopedError; + observations.scoped(ScopedError::Internal); + assert_eq!(observations.seen.load(Ordering::Relaxed), 95, "internal scope must not set scoped OOM bit"); + observations.scoped(ScopedError::OutOfMemory); + observations.scoped(ScopedError::Validation); + observations.scoped(ScopedError::OutOfMemory); + assert_eq!(observations.seen.load(Ordering::Relaxed), 255); + assert!(!observations.once(1, "GPU observation: duplicate")); + assert!(!observations.once(8, "GPU observation: duplicate")); + } + + #[test] + #[cfg(unix)] + fn non_unicode_override_is_not_copied() { + use std::os::unix::ffi::OsStrExt; + assert_eq!(backend_override_events(OsStr::from_bytes(b"private\xff")), ["WGPU_BACKEND: non-Unicode or oversized value omitted"]); + } +} diff --git a/apps/effectcraft/src/launch_guard.rs b/apps/effectcraft/src/launch_guard.rs index a99981cd7..2656179ac 100644 --- a/apps/effectcraft/src/launch_guard.rs +++ b/apps/effectcraft/src/launch_guard.rs @@ -68,11 +68,34 @@ fn acquire_guard(dir: &Path) -> Option { /// switch back in Settings. pub const SETTLE: Duration = Duration::from_secs(3); +/// Why this launch requested its window graphics APIs. An interrupted startup is an +/// observation, not proof that a driver caused the previous exit. +#[derive(Debug, Default, Clone, Copy, PartialEq, Eq)] +pub enum BackendSource { + #[default] + Default, + SavedPreference, + InterruptedStartup, + EnvironmentOverride, +} + +impl BackendSource { + pub fn event(self) -> &'static str { + match self { + Self::Default => "backend source: default", + Self::SavedPreference => "backend source: saved OpenGL preference", + Self::InterruptedStartup => "backend source: previous interrupted startup; OpenGL fallback", + Self::EnvironmentOverride => "backend source: WGPU_BACKEND present", + } + } +} + /// This launch's window graphics. #[derive(Debug, Default)] pub struct Launch { /// The graphics APIs the window may use (`None`: eframe's default). pub backends: Option, + pub source: BackendSource, /// Switched to OpenGL because the previous launch stopped as its window opened: the message /// to show. pub notice: Option, @@ -88,12 +111,17 @@ impl Launch { /// launch stopped as its window opened (where OpenGL exists: not macOS), and leave this /// launch's marker. `env_override`: `WGPU_BACKEND` is set. pub fn begin(dir: Option<&Path>, env_override: bool) -> Launch { - let Some(dir) = dir.filter(|_| !env_override) else { return Launch::default() }; + if env_override { + return Launch { source: BackendSource::EnvironmentOverride, ..Launch::default() }; + } + let Some(dir) = dir else { return Launch::default() }; let prefs_path = dir.join(PREFS_FILE); let mut prefs = std::fs::read_to_string(&prefs_path).map(|t| Prefs::from_json(&t)).unwrap_or_default(); let marker = dir.join(MARKER); let Some(lock) = acquire_guard(dir) else { - return Launch { backends: (prefs.startup.window_graphics == "gl").then_some(Backends::GL), ..Launch::default() }; + let backends = (prefs.startup.window_graphics == "gl").then_some(Backends::GL); + let source = if backends.is_some() { BackendSource::SavedPreference } else { BackendSource::Default }; + return Launch { backends, source, ..Launch::default() }; }; // Read again while owning the guard: another launch may have just changed preferences. prefs = std::fs::read_to_string(&prefs_path).map(|t| Prefs::from_json(&t)).unwrap_or_default(); @@ -112,6 +140,13 @@ impl Launch { ); } let backends = (prefs.startup.window_graphics == "gl").then_some(Backends::GL); + let source = if notice.is_some() { + BackendSource::InterruptedStartup + } else if backends.is_some() { + BackendSource::SavedPreference + } else { + BackendSource::Default + }; let marker = match File::create(&marker) { Ok(_) => Some(marker), Err(e) => { @@ -119,7 +154,7 @@ impl Launch { None } }; - Launch { backends, notice, marker, lock: Some(lock), first_frame: None } + Launch { backends, source, notice, marker, lock: Some(lock), first_frame: None } } /// The window drew a frame. Until the launch has settled, returns how long that still takes @@ -185,6 +220,7 @@ mod tests { // may still crash as the window is shown); frames for `SETTLE` do. let mut l = Launch::begin(Some(&dir), false); assert_eq!((l.backends, l.notice.is_some()), (None, false)); + assert_eq!(l.source, BackendSource::Default); assert!(dir.join(MARKER).exists()); let t0 = Instant::now(); assert_eq!(l.frame_drawn_at(t0), Some(SETTLE)); @@ -202,14 +238,18 @@ mod tests { } else { assert_eq!(l.backends, Some(Backends::GL)); assert!(l.notice.is_some()); + assert_eq!(l.source, BackendSource::InterruptedStartup); assert_eq!(window_graphics(&dir), "gl", "saved in Settings"); l.exited(); let l = Launch::begin(Some(&dir), false); assert_eq!((l.backends, l.notice.is_some()), (Some(Backends::GL), false), "it stays, without the notice"); + assert_eq!(l.source, BackendSource::SavedPreference); } // `WGPU_BACKEND` wins, and leaves no marker. let _ = std::fs::remove_file(dir.join(MARKER)); - assert_eq!(Launch::begin(Some(&dir), true).backends, None); + let overridden = Launch::begin(Some(&dir), true); + assert_eq!(overridden.backends, None); + assert_eq!(overridden.source, BackendSource::EnvironmentOverride); assert!(!dir.join(MARKER).exists()); let _ = std::fs::remove_dir_all(&dir); } @@ -276,6 +316,19 @@ mod tests { std::fs::write(dir.join(PREFS_FILE), prefs.to_json()).unwrap(); } + #[test] + fn a_second_copy_reports_the_saved_backend_without_owning_the_guard() { + let dir = fresh_dir("second-source"); + save_opengl(&dir); + let mut first = Launch::begin(Some(&dir), false); + let mut second = Launch::begin(Some(&dir), false); + assert!(second.lock.is_none()); + assert_eq!((second.backends, second.source), (Some(Backends::GL), BackendSource::SavedPreference)); + second.exited(); + first.exited(); + let _ = std::fs::remove_dir_all(dir); + } + /// A second copy that quits normally while the first is still opening doesn't remove the first /// one's marker (#477). #[test] diff --git a/apps/effectcraft/src/main.rs b/apps/effectcraft/src/main.rs index 3d9455c81..5a602adcb 100644 --- a/apps/effectcraft/src/main.rs +++ b/apps/effectcraft/src/main.rs @@ -23,6 +23,7 @@ mod apple_events; mod audio_out; mod control_server; mod crash_report; +mod diagnostic_state; mod launch_guard; #[cfg(target_os = "macos")] mod native_menu; @@ -183,7 +184,7 @@ fn start_helpers_if_opted_in(session: &mut effectcraft_engine::Session) { fn main() -> eframe::Result { let args: Vec<_> = std::env::args_os().skip(1).collect(); if crash_report::maybe_run(&args, |description| { - rfd::MessageDialog::new().set_level(rfd::MessageLevel::Error).set_title("EffectCraft stopped unexpectedly").set_description(description).show(); + rfd::MessageDialog::new().set_level(rfd::MessageLevel::Error).set_title("EffectCraft diagnostic report").set_description(description).show(); }) { return Ok(()); } @@ -246,8 +247,15 @@ fn run_desktop(reporter: &crash_report::Shutdown) -> eframe::Result { #[cfg(target_os = "linux")] appimage::integrate_from_env(ICON_PNG); // Settings ▸ Startup & Repair ▸ Window Graphics, switched to OpenGL when the last launch - // stopped as its window opened (a crashing graphics driver, #243). - let mut launch = launch_guard::Launch::begin(effectcraft_host::config_dir().as_deref(), std::env::var_os("WGPU_BACKEND").is_some()); + // stopped as its window opened (the marker alone does not establish a cause). + let backend_override = std::env::var_os("WGPU_BACKEND"); + let mut launch = launch_guard::Launch::begin(effectcraft_host::config_dir().as_deref(), backend_override.is_some()); + diagnostic_state::record(reporter, launch.source.event()); + if let Some(value) = backend_override { + for event in diagnostic_state::backend_override_events(&value) { + diagnostic_state::record(reporter, event); + } + } let on_gl = launch.backends == Some(eframe::wgpu::Backends::GL); let notice = launch.notice.take(); let options = eframe::NativeOptions { @@ -281,16 +289,33 @@ fn run_desktop(reporter: &crash_report::Shutdown) -> eframe::Result { Box::new(move |cc| { EffectcraftApp::install_ime_reset_hooks(&cc.egui_ctx); match &cc.wgpu_render_state { - Some(rs) => log::info!("graphics: {:?}", rs.adapter.get_info()), - None => log::info!("graphics: no wgpu device"), + Some(rs) => { + let info = rs.adapter.get_info(); + log::info!("graphics: {info:?}"); + let event = match info.backend { + eframe::wgpu::Backend::Noop => "actual GPU backend: noop", + eframe::wgpu::Backend::Vulkan => "actual GPU backend: vulkan", + eframe::wgpu::Backend::Metal => "actual GPU backend: metal", + eframe::wgpu::Backend::Dx12 => "actual GPU backend: dx12", + eframe::wgpu::Backend::Gl => "actual GPU backend: gl", + eframe::wgpu::Backend::BrowserWebGpu => "actual GPU backend: webgpu", + }; + diagnostic_state::record(&desktop_reporter, event); + } + None => diagnostic_state::record(&desktop_reporter, "actual GPU backend: no wgpu device"), } // This executable owns the shared device's handlers. Install them before // EffectCraft's compositor pipelines are built, without changing handlers from // inside Gpu::new. eframe has already constructed its presentation renderer here. let gpu_failures = effectcraft_ui_egui::gpu_failure::GpuFailureBridge::new(&cc.egui_ctx); + let observations = diagnostic_state::GpuObservations::new(&desktop_reporter); + let scoped_observed = observations.clone(); + gpu_failures.set_scoped_error_observer(move |error| scoped_observed.scoped(error)); if let Some(rs) = &cc.wgpu_render_state { + let errors_observed = observations.clone(); let errors = gpu_failures.clone(); rs.device.on_uncaptured_error(std::sync::Arc::new(move |error| { + errors_observed.uncaptured(&error); let message = format!("uncaptured GPU error: {error}"); if errors.report(&message, false) { log::error!("{message}"); @@ -298,6 +323,7 @@ fn run_desktop(reporter: &crash_report::Shutdown) -> eframe::Result { })); let lost = gpu_failures.clone(); rs.device.set_device_lost_callback(move |reason, message| { + observations.device_lost(reason); lost.report(&format!("GPU device lost ({reason:?}): {message}"), true); }); } diff --git a/crates/gpu/src/diagnostics.rs b/crates/gpu/src/diagnostics.rs new file mode 100644 index 000000000..a37adff22 --- /dev/null +++ b/crates/gpu/src/diagnostics.rs @@ -0,0 +1,102 @@ +//! Per-compositor, fixed-category observations from error scopes. No driver strings escape. + +#[cfg(any(test, not(target_arch = "wasm32")))] +use std::sync::atomic::{AtomicU8, Ordering}; +use std::sync::{Arc, OnceLock}; + +#[derive(Clone, Copy, Debug, PartialEq, Eq)] +pub enum ScopedError { + OutOfMemory, + Internal, + Validation, +} + +pub type ScopedErrorObserver = Arc; + +#[derive(Default)] +pub(crate) struct ScopedObservations { + observer: OnceLock, + #[cfg(any(test, not(target_arch = "wasm32")))] + seen: AtomicU8, +} + +impl ScopedObservations { + /// Register before rendering. Shared by all clones of the compositor, never global. + pub(crate) fn install(&self, observer: ScopedErrorObserver) -> bool { + self.observer.set(observer).is_ok() + } + + #[cfg(any(test, not(target_arch = "wasm32")))] + pub(crate) fn report_scopes(&self, oom: bool, internal: bool, validation: bool) { + for (present, category) in [(oom, ScopedError::OutOfMemory), (internal, ScopedError::Internal), (validation, ScopedError::Validation)] { + if present { + self.report(category); + } + } + } + + #[cfg(any(test, not(target_arch = "wasm32")))] + fn report(&self, error: ScopedError) { + let Some(observer) = self.observer.get() else { return }; + let bit = match error { + ScopedError::OutOfMemory => 1, + ScopedError::Internal => 2, + ScopedError::Validation => 4, + }; + if self.seen.fetch_or(bit, Ordering::Relaxed) & bit != 0 { + return; + } + // Diagnostics must not turn a recoverable GPU frame error into an application panic. + #[cfg(not(target_arch = "wasm32"))] + if std::panic::catch_unwind(std::panic::AssertUnwindSafe(|| observer(error))).is_err() { + log::warn!("GPU scoped-error observer panicked"); + } + #[cfg(target_arch = "wasm32")] + observer(error); + } +} + +#[cfg(test)] +mod tests { + use super::*; + + #[test] + fn categories_are_independent_bounded_and_not_global() { + let observations = ScopedObservations::default(); + let seen = Arc::new(std::sync::Mutex::new(Vec::new())); + let copy = seen.clone(); + assert!(observations.install(Arc::new(move |error| copy.lock().unwrap().push(error)))); + assert!(!observations.install(Arc::new(|_| panic!("must not replace observer")))); + for _ in 0..100 { + observations.report(ScopedError::Internal); + observations.report(ScopedError::Validation); + observations.report(ScopedError::OutOfMemory); + } + ScopedObservations::default().report(ScopedError::OutOfMemory); + assert_eq!(*seen.lock().unwrap(), [ScopedError::Internal, ScopedError::Validation, ScopedError::OutOfMemory]); + } + + #[test] + fn internal_and_validation_scopes_do_not_claim_out_of_memory() { + let observations = ScopedObservations::default(); + let seen = Arc::new(std::sync::Mutex::new(Vec::new())); + let copy = seen.clone(); + observations.install(Arc::new(move |error| copy.lock().unwrap().push(error))); + observations.report_scopes(false, false, false); + assert!(seen.lock().unwrap().is_empty()); + observations.report_scopes(false, true, true); + assert_eq!(*seen.lock().unwrap(), [ScopedError::Internal, ScopedError::Validation]); + observations.report_scopes(true, true, true); + assert_eq!(*seen.lock().unwrap(), [ScopedError::Internal, ScopedError::Validation, ScopedError::OutOfMemory]); + } + + #[test] + #[cfg(not(target_arch = "wasm32"))] + fn observer_panic_does_not_escape_frame_recovery() { + let observations = ScopedObservations::default(); + observations.install(Arc::new(|_| panic!("synthetic observer panic"))); + observations.report(ScopedError::OutOfMemory); + observations.report(ScopedError::Internal); + assert_eq!(observations.seen.load(Ordering::Relaxed), 3); + } +} diff --git a/crates/gpu/src/lib.rs b/crates/gpu/src/lib.rs index ddbc8d54a..86a498c6e 100644 --- a/crates/gpu/src/lib.rs +++ b/crates/gpu/src/lib.rs @@ -58,6 +58,7 @@ mod bokeh; mod classic3d; mod context; pub mod deferred; +mod diagnostics; mod effects; mod fx_color; mod fx_depth; @@ -91,6 +92,7 @@ mod yuv; use std::sync::Arc; pub use context::{GpuContext, GpuImage, TransferStats}; +pub use diagnostics::{ScopedError, ScopedErrorObserver}; use effectcraft_effects::Buf; use effectcraft_project::ItemId; use effectcraft_raster::Image; @@ -126,6 +128,7 @@ impl std::error::Error for FrameError {} /// The GPU compositor (cheap to clone; one device shared by all clones). #[derive(Clone)] pub struct Gpu { + scoped_observations: Arc, ctx: Arc, /// Backend::Auto's per-comp CPU / GPU timings. auto: Arc, @@ -162,7 +165,7 @@ impl Gpu { } pub fn from_context(ctx: GpuContext) -> Gpu { - Gpu { ctx: Arc::new(ctx), auto: Default::default(), declined: Default::default() } + Gpu { ctx: Arc::new(ctx), auto: Default::default(), declined: Default::default(), scoped_observations: Default::default() } } /// A device of its own without blocking, with deferred readbacks (a browser worker, see @@ -173,6 +176,13 @@ impl Gpu { Ok(Gpu::from_context(ctx)) } + /// Install a host's fixed-category observer before rendering. It is called at most once + /// per category across all clones, outside device/renderer locks. Returns false if already + /// registered. The observer must remain brief and must not perform GPU work. + pub fn set_scoped_error_observer(&self, observer: ScopedErrorObserver) -> bool { + self.scoped_observations.install(observer) + } + /// [`Gpu::request_deferred`] blocking (tests of the browser worker's path, natively). #[cfg(not(target_arch = "wasm32"))] pub fn headless_deferred() -> Option { @@ -316,6 +326,9 @@ impl Gpu { let validation = pollster::block_on(validation.pop()); let internal = pollster::block_on(internal.pop()); let oom = pollster::block_on(oom.pop()); + // Preserve the typed scope observations before FrameError::Memory combines OOM + // and internal errors. An internal error alone is not evidence of actual OOM. + self.scoped_observations.report_scopes(oom.is_some(), internal.is_some(), validation.is_some()); let memory = oom.is_some() || internal.is_some(); // The allocation failure first: a validation error is often its consequence. let errors: Vec = [oom, internal, validation].into_iter().flatten().map(|e| e.to_string()).collect(); diff --git a/crates/ui-egui/src/app/gpu.rs b/crates/ui-egui/src/app/gpu.rs index c9849e921..92ea7665c 100644 --- a/crates/ui-egui/src/app/gpu.rs +++ b/crates/ui-egui/src/app/gpu.rs @@ -44,6 +44,9 @@ impl EffectcraftApp { pub fn set_gpu_failure_bridge(&mut self, bridge: gpu_failure::GpuFailureBridge) { if let Some(gpu) = &self.gpu { bridge.forward_to(gpu.context().device_failure_notifier()); + if let Some(observer) = bridge.scoped_error_observer() { + gpu.set_scoped_error_observer(observer); + } } self.gpu_failures = Some(bridge); } @@ -257,6 +260,9 @@ impl EffectcraftApp { Ok(Ok(g)) => { if let Some(bridge) = &self.gpu_failures { bridge.forward_to(g.context().device_failure_notifier()); + if let Some(observer) = bridge.scoped_error_observer() { + g.set_scoped_error_observer(observer); + } if bridge.failure().is_some() { return; } diff --git a/crates/ui-egui/src/gpu_failure.rs b/crates/ui-egui/src/gpu_failure.rs index 275112912..a0840b790 100644 --- a/crates/ui-egui/src/gpu_failure.rs +++ b/crates/ui-egui/src/gpu_failure.rs @@ -2,7 +2,9 @@ //! embedding host, never to a library borrowing its device. This bridge does no device work, //! document mutation, file I/O or renderer locking inside a notification. -use std::sync::{Arc, Mutex}; +use std::sync::{Arc, Mutex, OnceLock}; + +pub use effectcraft_gpu::{ScopedError, ScopedErrorObserver}; type Notifier = Arc; @@ -25,11 +27,22 @@ struct State { pub struct GpuFailureBridge { state: Arc>, ctx: egui::Context, + scoped_observer: Arc>, } impl GpuFailureBridge { pub fn new(ctx: &egui::Context) -> Self { - Self { state: Arc::default(), ctx: ctx.clone() } + Self { state: Arc::default(), ctx: ctx.clone(), scoped_observer: Arc::default() } + } + + /// Register the host observer before handing this bridge to the app. Scoped errors do + /// not retire the device: they remain recoverable per-frame observations. + pub fn set_scoped_error_observer(&self, observer: impl Fn(ScopedError) + Send + Sync + 'static) -> bool { + self.scoped_observer.set(Arc::new(observer)).is_ok() + } + + pub(crate) fn scoped_error_observer(&self) -> Option { + self.scoped_observer.get().cloned() } pub fn failure(&self) -> Option { @@ -90,6 +103,18 @@ mod tests { use super::*; use std::sync::atomic::{AtomicUsize, Ordering}; + #[test] + fn scoped_observer_is_shared_without_retiring_the_device() { + let bridge = GpuFailureBridge::new(&egui::Context::default()); + let seen = Arc::new(Mutex::new(Vec::new())); + let copy = seen.clone(); + assert!(bridge.set_scoped_error_observer(move |error| copy.lock().unwrap().push(error))); + assert!(!bridge.set_scoped_error_observer(|_| panic!("must not replace observer"))); + bridge.clone().scoped_error_observer().unwrap()(ScopedError::Internal); + assert_eq!(*seen.lock().unwrap(), [ScopedError::Internal]); + assert!(bridge.failure().is_none()); + } + #[test] fn a_construction_failure_is_replayed_after_notifier_registration() { let bridge = GpuFailureBridge::new(&egui::Context::default()); diff --git a/docs/testing.md b/docs/testing.md index e6cd8df68..4a7610d16 100644 --- a/docs/testing.md +++ b/docs/testing.md @@ -123,16 +123,45 @@ A teardown panic leaves reporting armed. An abort or other unexpected process te closes the pipe without that marker. The helper saves a local report under the session log folder's `Crash Reports` directory and shows a native error dialog. Control-server launches save the report without a modal dialog. -Reports contain version/platform and at most the last 64 KiB of the matching session's log. -Logging filters and the session file size cap can omit later events from that tail. +Reports contain version/platform, UTC detection and observer-start times, observed duration, +GUI uptime at the last target-present sample, and at most the last 64 KiB of the matching +session's log. A separate ring retains the last 32 timestamped, fixed-vocabulary backend and +GPU observations even if startup messages have fallen out of the log tail. `WGPU_BACKEND` +values are normalized to known backend names; arbitrary environment text is not copied. +Logging filters and the session file size cap can omit later events from the log tail. They are never uploaded automatically. Review logs for private project paths before sharing. +On Windows the helper acquires a process handle before acknowledging readiness and retains +it until the GUI exits. It records the real OS exit status in unsigned hexadecimal, with a +small lookup of known status names. These bits are **not a verified exception record**: +software can explicitly set the same code, and an access violation does not identify the +faulting module or prove a driver crash. Other platforms report exit status as unavailable. +A lost pipe while the GUI is still present, or a failed/absent process refresh, is not reported +as confirmed termination. + +The helper samples only the target process and system RAM at roughly one-second intervals, +retaining a count, last-attempt time, sampled resident-memory maximum, Windows private-commit +maximum (virtual memory on other platforms), and system available-RAM minimum. This is a +fixed-size summary, not a memory dump. OS query failure can leave stale or zero values, and +sampling misses short spikes. System commit limits/usage and GPU VRAM budgets are not captured. +No threshold is treated as proof of memory exhaustion. Typed wgpu OOM, internal/validation +errors and device-loss notifications are observations; device destruction is distinguished +from unknown loss, and neither establishes why the process later exited. + Run `cargo test -p effectcraft crash_report::tests` for bounded protocol, normal shutdown, actual subprocess abort, unrelated child handles, concurrent sessions, missing log/helper, -log rotation and report-write failure coverage. The three ignored tests are subprocess entry +log rotation, bounded retained events, live-GUI pipe loss, and report-write failure coverage. +Windows also tests a real subprocess exit with explicit `0xC0000017` bits, without exhausting +memory or pretending that the exit was an actual OOM exception. The three ignored tests are subprocess entry points launched by these tests, not manual tests. -This is diagnosis, not memory recovery: a pipe closing does not prove an out-of-memory failure -or provide the process's exit code. System-wide exhaustion, killing the whole process tree, +These are observations, not memory recovery or a causal diagnosis: a pipe closing does not +prove an out-of-memory failure. System-wide exhaustion, killing the whole process tree, or an unavailable native dialog service can also prevent the helper from reporting. Existing auto-save recovery remains responsible for restoring previously saved work. + +Native exception records, faulting-module attribution and driver/TDR confirmation require +separately collected OS event evidence or a native dump. They are deliberately not gathered +here: dumps can contain document contents and credentials. Any future dump workflow must be +explicitly opt-in, bounded, local-first and separately reviewed before sharing. This reporter +must remain useful when those sources are unavailable.