Routine lines go on stdout, so only a failure is drawn as an error

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.

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,

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<SyscallError> for DropReason {
+    fn from(e: SyscallError) -> Self {
+        match e {
+            SyscallError::Gone => Self::Gone,
+            e => Self::Refused(e),
         }
     }
 }
@@ -184,7 +224,8 @@ impl From<ipc::TrySendError> 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<Dead>, 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,

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) {

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={}",

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 };
     }
 }

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}")

userland/toybox/src/stats.rs

@@ -31,52 +31,52 @@ pub fn main(args: Vec<String>) {
     }
 
     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))); }
         if s.blocked_pipe_ns > 0 { parts.push(format!("pipe {}", fmt_ns(s.blocked_pipe_ns))); }
         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 {

userland/toybox/src/tone.rs

@@ -25,7 +25,7 @@ pub fn main(args: Vec<String>) {
         },
     };
 
-    eprintln!(
+    println!(
         "tone: {freq}Hz for {duration_secs}s at amplitude {}",
         amplitude as i32
     );
@@ -100,5 +100,5 @@ pub fn main(args: Vec<String>) {
 
     // Let the last buffer drain
     std::thread::sleep(std::time::Duration::from_millis(100));
-    eprintln!("tone: done");
+    println!("tone: done");
 }