diff --git a/issues/the-compositor-says-its-routine-lines-as-errors.md b/issues/the-compositor-says-its-routine-lines-as-errors.md deleted file mode 100644 index 2d477a392b4..00000000000 --- a/issues/the-compositor-says-its-routine-lines-as-errors.md +++ /dev/null @@ -1,19 +0,0 @@ ---- -status: open -kind: defect -opened: 2026-10-04 ---- - -# The compositor says its routine lines as errors - -The compositor writes its status with `eprintln!` (`userland/compositor/src`), -and `toyos::log::stdio` records a line written to stderr at `Severity::Error`. -So `compositor: ready`, its wallpaper size and its periodic `frames=…` census -are Error records. Since the console and `cargo run`'s terminal draw an Error -record's text in bright red, every one of them reads as a failure: a -`cargo run` boot on macOS under TCG drew 22 compositor lines, all -`{… error compositor}` in red, and none of them was one. - -Owner: orchestrator. Exit condition: the compositor's routine lines are -recorded at Info (`toyos::log`'s `say!` or stdout), a boot's console carries -no `error compositor` line that reports no failure, and this file is deleted. diff --git a/issues/the-console-says-its-routine-lines-as-errors.md b/issues/the-console-says-its-routine-lines-as-errors.md new file mode 100644 index 00000000000..bdc8f564cd3 --- /dev/null +++ b/issues/the-console-says-its-routine-lines-as-errors.md @@ -0,0 +1,18 @@ +--- +status: open +kind: defect +opened: 2026-10-04 +--- + +# The console says its routine lines as errors + +`/system/bin/console` (`userland/console/src/main.rs`), the surface of the +`console/system.toml` boot, writes `console: ready …`, `keyboard layout is +now …`, `client N has the keyboard until it exits` and `client N gave the +keyboard back` with `eprintln!`, and a line on stderr is an Error record +(`toyos::log::stdio::Stream::severity`). So every one of them is drawn in red +on the console and reads as a failure, as the terminal's identical lines did +until they moved to stdout. + +Owner: orchestrator. Exit condition: those four lines are written to stdout, +and this file is deleted. diff --git a/toyos/src/log/stdio.rs b/toyos/src/log/stdio.rs index cf12527f38d..6d80bf70347 100644 --- a/toyos/src/log/stdio.rs +++ b/toyos/src/log/stdio.rs @@ -34,7 +34,8 @@ pub enum Stream { } impl Stream { - /// What a line on this stream is, when it becomes a record. + /// What a line on this stream is, when it becomes a record: every line on + /// stderr is an error, so a routine line goes on stdout. pub const fn severity(self) -> Severity { match self { Self::Out => Severity::Info, diff --git a/userland/compositor/src/client.rs b/userland/compositor/src/client.rs index b2504f30f7b..32d9a37ada3 100644 --- a/userland/compositor/src/client.rs +++ b/userland/compositor/src/client.rs @@ -13,12 +13,14 @@ //! used it — so every region a client writes is one the compositor made, and a //! handle a client sends stays queued until its connection closes. +use std::fmt; use std::sync::atomic::Ordering; use std::time::{Duration, Instant}; use toyos::shm::SharedMemory; use toyos::AsHandle; use toyos::{ipc, Connection}; +use toyos_abi::syscall::SyscallError; use toyos_abi::RawHandle; use toyos_desktop::Window; @@ -159,23 +161,61 @@ pub enum DropReason { /// Its pipe would not take a whole frame — an entire pipe of messages it /// has not read. NotReading, - /// The connection is gone. + /// Its other end closed: the one send error that is a client's routine end. Gone, + /// The kernel refused a send to it for any other reason — a handle send + /// to a peer that leaves `MAX_QUEUED_BATCHES` unreceived is + /// `ResourceExhausted`. + Refused(SyscallError), + /// A message to it that this end will not frame. + TooLarge, /// Accepted, and never completed a first frame. HandshakeTimeout, /// Given a region to copy into, and never committed it. CopyTimeout, } +impl fmt::Display for DropReason { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + match self { + Self::OutOfProtocol => f.write_str("it sent a frame this protocol cannot describe"), + Self::Retired => { + f.write_str("it sent the retired clipboard region, whose handle is never taken") + } + Self::NotReading => { + f.write_str("its pipe will not take another message and it is not reading") + } + Self::Gone => f.write_str("its connection is gone"), + Self::Refused(e) => write!(f, "the kernel refused a send to it: {e}"), + Self::TooLarge => f.write_str("a message to it is too large to frame"), + Self::HandshakeTimeout => f.write_str("it never finished its first message"), + Self::CopyTimeout => f.write_str("it began a copy and never committed it"), + } + } +} + impl DropReason { - pub fn why(self) -> &'static str { + /// Whether the going is a failure, said on stderr, rather than a client's + /// routine end, said on stdout. + pub fn failed(self) -> bool { match self { - Self::OutOfProtocol => "it sent a frame this protocol cannot describe", - Self::Retired => "it sent the retired clipboard region, whose handle is never taken", - Self::NotReading => "its pipe will not take another message and it is not reading", - Self::Gone => "its connection is gone", - Self::HandshakeTimeout => "it never finished its first message", - Self::CopyTimeout => "it began a copy and never committed it", + Self::Gone => false, + Self::OutOfProtocol + | Self::Retired + | Self::NotReading + | Self::Refused(_) + | Self::TooLarge + | Self::HandshakeTimeout + | Self::CopyTimeout => true, + } + } +} + +impl From for DropReason { + fn from(e: SyscallError) -> Self { + match e { + SyscallError::Gone => Self::Gone, + e => Self::Refused(e), } } } @@ -184,7 +224,8 @@ impl From for DropReason { fn from(e: ipc::TrySendError) -> Self { match e { ipc::TrySendError::Full => Self::NotReading, - _ => Self::Gone, + ipc::TrySendError::TooLarge => Self::TooLarge, + ipc::TrySendError::Syscall(e) => e.into(), } } } @@ -200,7 +241,12 @@ pub fn mark_dead(dead: &mut Vec, handle: RawHandle, reason: DropReason) { pub fn announce(dead: &[Dead]) { for (handle, reason) in dead { - eprintln!("compositor: dropping client {} — {}", handle.0, reason.why()); + let client = handle.0; + if reason.failed() { + eprintln!("compositor: dropping client {client} — {reason}"); + } else { + println!("compositor: dropping client {client} — {reason}"); + } } } @@ -216,7 +262,7 @@ pub fn announce(dead: &[Dead]) { /// asks of the log — and a caller that re-sends a close because it could not /// tell whether the first one landed closes the next window down. pub fn note_closed(by: &str, win: &Win, remaining: usize) { - eprintln!( + println!( "compositor: window closed client={} by {by}, {remaining} left, presents={} frames={}", win.client.conn.as_handle().0, win.client.presents, @@ -227,7 +273,7 @@ pub fn note_closed(by: &str, win: &Win, remaining: usize) { /// The open's own line, and where the client's pixels are on the panel: the one /// fact about a window that nobody reading the screen can recover from it. pub fn note_opened(client: RawHandle, content: toyos_desktop::Rect, live: usize) { - eprintln!( + println!( "compositor: window opened client={} content={},{} {}x{}, {live} live", client.0, content.x0, diff --git a/userland/compositor/src/session.rs b/userland/compositor/src/session.rs index bc64d560d9d..d03dc0a1c1b 100644 --- a/userland/compositor/src/session.rs +++ b/userland/compositor/src/session.rs @@ -195,7 +195,7 @@ impl Session { raw, scaled: Vec::new(), }; - eprintln!( + println!( "compositor: wallpaper {}x{}, scaling to {}x{}", wallpaper.w, wallpaper.h, @@ -215,7 +215,7 @@ impl Session { let total_mem = total_memory(); let max_windows = toyos_desktop::max_windows(total_mem, desk.screen, MAX_WINDOW_SLOTS as usize); - eprintln!( + println!( "compositor: at most {max_windows} windows ({} MiB each of {} MiB total)", toyos_desktop::window_bytes(desk.screen) / (1024 * 1024), total_mem / (1024 * 1024), @@ -239,7 +239,7 @@ impl Session { let mut damage = Damage::default(); damage.add(desk.screen); - eprintln!("compositor: ready"); + println!("compositor: ready"); let now = Instant::now(); Self { @@ -336,7 +336,7 @@ impl Session { Some(_) => DropReason::CopyTimeout, None => DropReason::HandshakeTimeout, }; - eprintln!("compositor: dropping client {} — {}", p.conn.as_handle().0, reason.why()); + eprintln!("compositor: dropping client {} — {}", p.conn.as_handle().0, reason); } self.pending.retain(|p| now.duration_since(p.since) < HANDSHAKE_TIMEOUT); @@ -990,9 +990,9 @@ impl Session { }; // Moved on its own, so that a refused move leaves `theirs` here to // close: once moved, its number is no longer this process's to close. - if syscall::handle_send(conn.as_handle(), &[theirs]).is_err() { + if let Err(e) = syscall::handle_send(conn.as_handle(), &[theirs]) { syscall::close(theirs); - mark_dead(&mut self.dead, handle, DropReason::Gone); + mark_dead(&mut self.dead, handle, e.into()); return; } if let Err(e) = conn.try_signal(window::MSG_COPY_REGION) { diff --git a/userland/compositor/src/stats.rs b/userland/compositor/src/stats.rs index fb3a203939c..4228668522c 100644 --- a/userland/compositor/src/stats.rs +++ b/userland/compositor/src/stats.rs @@ -52,7 +52,7 @@ impl FrameStats { /// mean is a division, and the total is the share of the window that /// compositing cost, which the mean is not. pub fn report(&self, moved: (u64, u64), composed: Traffic, windows: usize) { - eprintln!( + println!( "compositor: frames={} rects={} damage_px={} damage_px_max={} \ composite_us_min={} composite_us_max={} composite_us_total={} \ scanout_wr_bytes={} scanout_blits={} back_rd_bytes={} cursor={} windows={}", diff --git a/userland/doom/src/sound.rs b/userland/doom/src/sound.rs index 9ef120a7d1f..f622dde2d30 100644 --- a/userland/doom/src/sound.rs +++ b/userland/doom/src/sound.rs @@ -672,7 +672,7 @@ fn music_telemetry(ring: &MusicRing, render_cost: std::time::Duration) { let audio_s = t.chunks as f64 * RENDER_CHUNK as f64 / OUTPUT_RATE as f64; let rt = t.cpu.as_secs_f64() / audio_s; let fill = 100 * (RING_FRAMES - ring.free_space()) / RING_FRAMES; - eprintln!("[music] rt_factor={rt:.2} rendered={audio_s:.1}s/{:.1}s ring={fill}%", wall.as_secs_f64()); + println!("[music] rt_factor={rt:.2} rendered={audio_s:.1}s/{:.1}s ring={fill}%", wall.as_secs_f64()); *t = Tel { window_start: Instant::now(), cpu: Default::default(), chunks: 0 }; } } diff --git a/userland/terminal/src/main.rs b/userland/terminal/src/main.rs index 95405c471d4..a25fd3ad16c 100644 --- a/userland/terminal/src/main.rs +++ b/userland/terminal/src/main.rs @@ -75,7 +75,7 @@ fn main() { // from here a keystroke the compositor forwards has somewhere to land even // if the shell has not reached its first read. Before it, one is dropped // with no trace. - eprintln!("terminal: ready"); + println!("terminal: ready"); loop { poller.watch_raw(RawHandle(shell_stdout.as_raw_fd() as u32), READABLE, TOKEN_STDOUT); @@ -132,10 +132,10 @@ fn main() { // re-read arrives back through `Event::LayoutChanged`. Notice::LayoutChanged => window.notify_layout_changed(), Notice::Grabbed { client } => { - eprintln!("terminal: client {client} has the keyboard until it exits") + println!("terminal: client {client} has the keyboard until it exits") } Notice::Released { client } => { - eprintln!("terminal: client {client} gave the keyboard back") + println!("terminal: client {client} gave the keyboard back") } Notice::Dropped { client, why } => { eprintln!("terminal: dropping client {client} — {why}") diff --git a/userland/toybox/src/stats.rs b/userland/toybox/src/stats.rs index b2d11cc3032..63d816351b4 100644 --- a/userland/toybox/src/stats.rs +++ b/userland/toybox/src/stats.rs @@ -31,30 +31,30 @@ pub fn main(args: Vec) { } let code = status.code().unwrap_or(-1); - eprintln!(); - eprintln!("── process stats (pid {}, exit {code}) ──────────", s.pid); - eprintln!(" wall {}", fmt_ns(s.wall_ns)); - eprintln!(" cpu {}", fmt_ns(s.cpu_ns)); - eprintln!(); + println!(); + println!("── process stats (pid {}, exit {code}) ──────────", s.pid); + println!(" wall {}", fmt_ns(s.wall_ns)); + println!(" cpu {}", fmt_ns(s.cpu_ns)); + println!(); let fault_total = s.fault_demand_count + s.fault_zero_count; if fault_total > 0 || s.fault_ns > 0 { - eprintln!(" faults {:>6} ({} demand, {} zero)", + println!(" faults {:>6} ({} demand, {} zero)", fault_total, s.fault_demand_count, s.fault_zero_count); - eprintln!(" fault time {}", fmt_ns(s.fault_ns)); - eprintln!(); + println!(" fault time {}", fmt_ns(s.fault_ns)); + println!(); } if s.io_read_ops > 0 { - eprintln!(" io ops {:>6}", s.io_read_ops); - eprintln!(" io bytes {}", fmt_bytes(s.io_read_bytes)); - eprintln!(); + println!(" io ops {:>6}", s.io_read_ops); + println!(" io bytes {}", fmt_bytes(s.io_read_bytes)); + println!(); } let blocked_total = s.blocked_io_ns + s.blocked_futex_ns + s.blocked_pipe_ns + s.blocked_ipc_ns + s.blocked_other_ns; if blocked_total > 0 { - eprint!(" blocked {}", fmt_ns(blocked_total)); + print!(" blocked {}", fmt_ns(blocked_total)); let mut parts = Vec::new(); if s.blocked_io_ns > 0 { parts.push(format!("io {}", fmt_ns(s.blocked_io_ns))); } if s.blocked_futex_ns > 0 { parts.push(format!("futex {}", fmt_ns(s.blocked_futex_ns))); } @@ -62,21 +62,21 @@ pub fn main(args: Vec) { if s.blocked_ipc_ns > 0 { parts.push(format!("ipc {}", fmt_ns(s.blocked_ipc_ns))); } if s.blocked_other_ns > 0 { parts.push(format!("other {}", fmt_ns(s.blocked_other_ns))); } if !parts.is_empty() { - eprint!(" ({})", parts.join(", ")); + print!(" ({})", parts.join(", ")); } - eprintln!(); + println!(); } if s.runqueue_wait_ns > 0 { - eprintln!(" runqueue {}", fmt_ns(s.runqueue_wait_ns)); + println!(" runqueue {}", fmt_ns(s.runqueue_wait_ns)); } if blocked_total > 0 || s.runqueue_wait_ns > 0 { - eprintln!(); + println!(); } - eprintln!(" syscalls {:>6} (wall {})", s.syscall_total, fmt_ns(s.syscall_total_ns)); - eprintln!(" peak mem {} ({} allocs)", fmt_bytes(s.peak_memory), s.alloc_count); + println!(" syscalls {:>6} (wall {})", s.syscall_total, fmt_ns(s.syscall_total_ns)); + println!(" peak mem {} ({} allocs)", fmt_bytes(s.peak_memory), s.alloc_count); } fn fmt_ns(ns: u64) -> String { diff --git a/userland/toybox/src/tone.rs b/userland/toybox/src/tone.rs index f1b39582615..ff0c82d63b4 100644 --- a/userland/toybox/src/tone.rs +++ b/userland/toybox/src/tone.rs @@ -25,7 +25,7 @@ pub fn main(args: Vec) { }, }; - eprintln!( + println!( "tone: {freq}Hz for {duration_secs}s at amplitude {}", amplitude as i32 ); @@ -100,5 +100,5 @@ pub fn main(args: Vec) { // Let the last buffer drain std::thread::sleep(std::time::Duration::from_millis(100)); - eprintln!("tone: done"); + println!("tone: done"); }