The compositor's 2 s stats line, and the terminal's and console's copies of the shell session, leave the log

issues/t14-desktop-froze-at-64s.md

@@ -58,10 +58,14 @@ ruled it out.
 **What the next boot should capture.** Nothing new, which is the point: the
 compositor now names every client it drops and why. A recurrence with no
 `compositor: dropping pid` line and no telemetry is a mechanism none of the
-four closed ones covers, and that is itself the finding. If it is worth
-narrowing further before then, the cheap change is a `pipes=` field on the
-compositor's own 2 s report — same cadence as the thing that goes missing,
-where the PMM dump's is not.
+four closed ones covers, and that is itself the finding.
+
+**Nothing replaces the 2 s report as a heartbeat.** It left the log (#891),
+and with it the `pipes=` field this issue once proposed for it, so a
+recurrence's log no longer says when the compositor last composited. On a
+machine still up, `inspect display` says it: `frames.composited` asked twice
+a few seconds apart, the taskbar damaging itself every second, or a `did not
+answer` from a compositor no longer in its loop. After the fact, nothing does.
 
 Do not read the 9.58 s of no kernel output as evidence. It is the longest gap
 in the log, but an idle desktop in this same session goes 4–6 s between

sdk/window/src/framebuffer.rs

@@ -149,57 +149,13 @@ impl Screen {
     }
 }
 
-/// Bytes a [`Framebuffer`] has moved through its surface since it was created.
-///
-/// Cumulative; a caller sampling a window subtracts its previous sample.
-#[derive(Clone, Copy, Default)]
-pub struct Traffic {
-    /// Bytes written by the bulk paths — `blit` and `fill_rect`.
-    ///
-    /// `put_pixel` is not counted. It is the per-pixel path — every glyph a
-    /// font draws goes through it one pixel at a time — so a counter there
-    /// would tax every program that draws text to pay for one program's
-    /// instrument.
-    pub written: u64,
-    /// Bytes read back *out of* the surface: `get_pixel`, and the row
-    /// replication inside `fill_rect`.
-    ///
-    /// Zero for a surface that is only ever drawn into. A caller holding a
-    /// scanout mapping should read this as its bill: a read of write-combining
-    /// memory misses every cache, so it costs a bus transaction that a write —
-    /// which merges with its neighbours — does not.
-    pub read: u64,
-    /// Reads of a single pixel (`get_pixel`) — each one a separate round trip.
-    pub pixel_reads: u64,
-    /// Reads of a whole row or region (`fill_rect`).
-    pub bulk_reads: u64,
-}
-
-impl Traffic {
-    /// What moved between an earlier sample and this one. Both must come from
-    /// the same surface; a sample from another one underflows rather than
-    /// producing a plausible figure.
-    pub fn since(self, earlier: Self) -> Self {
-        Self {
-            written: self.written - earlier.written,
-            read: self.read - earlier.read,
-            pixel_reads: self.pixel_reads - earlier.pixel_reads,
-            bulk_reads: self.bulk_reads - earlier.bulk_reads,
-        }
-    }
-}
-
 pub struct Framebuffer {
     buf: *mut u8,
     len: usize,
     width: usize,
     height: usize,
     stride: usize,
     pixel_format: PixelFormat,
-    written: Cell<u64>,
-    read: Cell<u64>,
-    pixel_reads: Cell<u64>,
-    bulk_reads: Cell<u64>,
 }
 
 impl Framebuffer {
@@ -214,19 +170,6 @@ impl Framebuffer {
             height,
             stride,
             pixel_format: PixelFormat::from_raw(pixel_format),
-            written: Cell::new(0),
-            read: Cell::new(0),
-            pixel_reads: Cell::new(0),
-            bulk_reads: Cell::new(0),
-        }
-    }
-
-    pub fn traffic(&self) -> Traffic {
-        Traffic {
-            written: self.written.get(),
-            read: self.read.get(),
-            pixel_reads: self.pixel_reads.get(),
-            bulk_reads: self.bulk_reads.get(),
         }
     }
 
@@ -260,8 +203,6 @@ impl Framebuffer {
         if x < self.width && y < self.height {
             let offset = (y * self.stride + x) * 4;
             debug_assert!(offset + 4 <= self.len);
-            self.read.set(self.read.get() + 4);
-            self.pixel_reads.set(self.pixel_reads.get() + 1);
             let pixel = unsafe { core::slice::from_raw_parts(self.buf.add(offset), 4) };
             match self.pixel_format {
                 PixelFormat::Rgb => Color { r: pixel[0], g: pixel[1], b: pixel[2] },
@@ -285,22 +226,18 @@ impl Framebuffer {
     }
 
     /// Fill a row of pixels with a 4-byte pattern using doubling memcpy.
-    /// Returns how many of those copies read back out of the row.
-    unsafe fn fill_row(dst: *mut u8, pixel: &[u8; 4], count: usize) -> u64 {
+    unsafe fn fill_row(dst: *mut u8, pixel: &[u8; 4], count: usize) {
         if count == 0 {
-            return 0;
+            return;
         }
         ptr::copy_nonoverlapping(pixel.as_ptr(), dst, 4);
         let total_bytes = count * 4;
         let mut filled = 4usize;
-        let mut copies = 0;
         while filled < total_bytes {
             let chunk = filled.min(total_bytes - filled);
             ptr::copy_nonoverlapping(dst, dst.add(filled), chunk);
             filled += chunk;
-            copies += 1;
         }
-        copies
     }
 
     pub fn fill_rect(&self, x: usize, y: usize, w: usize, h: usize, color: Color) {
@@ -314,26 +251,17 @@ impl Framebuffer {
         let row_bytes = actual_w * 4;
         let pixel = self.encode_pixel(color);
 
-        let doubling_copies = unsafe {
+        unsafe {
             let first_row = self.buf.add((y * self.stride + x) * 4);
             debug_assert!((y * self.stride + x) * 4 + row_bytes <= self.len);
-            let copies = Self::fill_row(first_row, &pixel, actual_w);
+            Self::fill_row(first_row, &pixel, actual_w);
             for dy in 1..rows {
                 let dst_offset = ((y + dy) * self.stride + x) * 4;
                 debug_assert!(dst_offset + row_bytes <= self.len);
                 let dst = self.buf.add(dst_offset);
                 ptr::copy_nonoverlapping(first_row, dst, row_bytes);
             }
-            copies
-        };
-
-        // Every row but the first is a copy *of* the first, and the doubling
-        // that built the first read all but its seed pixel back.
-        self.written.set(self.written.get() + (row_bytes * rows) as u64);
-        self.read
-            .set(self.read.get() + (row_bytes - 4 + row_bytes * (rows - 1)) as u64);
-        self.bulk_reads
-            .set(self.bulk_reads.get() + doubling_copies + (rows - 1) as u64);
+        }
     }
 
     /// Blit a buffer to a region of the framebuffer (row-by-row memcpy).
@@ -358,7 +286,6 @@ impl Framebuffer {
                 );
             }
         }
-        self.written.set(self.written.get() + (copy_bytes * rows) as u64);
     }
 
     pub fn clear(&self, color: Color) {

sdk/window/src/lib.rs

@@ -2,7 +2,7 @@ mod arch;
 pub mod framebuffer;
 pub mod wait;
 
-pub use framebuffer::{Color, Framebuffer, Screen, Traffic};
+pub use framebuffer::{Color, Framebuffer, Screen};
 pub use wait::{Waiter, Waker, Woke};
 /// What [`Window::handle`] answers with, and what a [`Waiter`] waits on.
 pub use toyos_abi::RawHandle;

system/compositor/src/client.rs

@@ -257,15 +257,11 @@ pub fn announce(dead: &[Dead]) {
 
 /// Say that a window was deliberately closed, and by what.
 ///
-/// A client that *dies* is already announced — `dropping client N — why` — and
-/// a window somebody closed was not, so the desktop's only record of one was the
-/// `windows=N` count in the statistics line. That is a sample of a level taken
-/// every two seconds: two closes inside one interval are indistinguishable
-/// from one, and from none if a window opened in between. Every report the
-/// owner has made about this desktop begins "I closed a window and then", so
-/// which window went, why, and how many are left is the first thing anyone
-/// 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.
+/// A client that *dies* is already announced — `dropping client N — why`.
+/// Every report the owner has made about this desktop begins "I closed a window
+/// and then", so which window went, why, and how many are left is the first
+/// thing anyone 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) {
     println!(
         "compositor: window closed client={} by {by}, {remaining} left, presents={} frames={}",

system/compositor/src/main.rs

@@ -29,7 +29,6 @@ use toyos_manifest::package;
 
 pub const DOUBLE_CLICK_TIME: Duration = Duration::from_millis(400);
 pub const FRAME_INTERVAL: Duration = Duration::from_nanos(16_666_667); // ~60fps
-pub const STATS_INTERVAL: Duration = Duration::from_secs(2);
 
 /// How long one pass may spend draining clients before it must composite.
 ///

system/compositor/src/session.rs

@@ -33,10 +33,10 @@ use crate::client::{
     HANDSHAKE_TIMEOUT, MAX_KEPT_PAYLOAD, MAX_PENDING_CONNS,
 };
 use crate::render::{self, Assets, BackBuffer, SystemStats, TitleBarIcons};
-use crate::stats::{FrameStats, FrameTotals};
+use crate::stats::FrameTotals;
 use crate::{
     launcher_apps, DOUBLE_CLICK_TIME, DRAIN_BUDGET, FIXED_POLL_HANDLES,
-    FLAG_HARDWARE_CURSOR, FRAME_INTERVAL, MAX_WINDOW_SLOTS, PROMPT_POLL_HANDLES, STATS_INTERVAL,
+    FLAG_HARDWARE_CURSOR, FRAME_INTERVAL, MAX_WINDOW_SLOTS, PROMPT_POLL_HANDLES,
 };
 
 const _: () = assert!(
@@ -148,16 +148,11 @@ pub struct Session {
     /// Tokens the last `wait` reported ready.
     ready: Vec<u64>,
 
-    stats: FrameStats,
-    /// Every window `stats` has reported, summed, for `inspect`.
     totals: FrameTotals,
     cached_stats: SystemStats,
     prev_busy_ticks: u64,
     prev_total_ticks: u64,
     last_taskbar_update: Instant,
-    next_stats_report: Instant,
-    reported_traffic: (u64, u64),
-    reported_composed: window::Traffic,
 }
 
 impl Session {
@@ -265,8 +260,6 @@ impl Session {
 
         let now = Instant::now();
         Self {
-            reported_traffic: screen.traffic(),
-            reported_composed: back.surface.traffic(),
             acceptor,
             prompts,
             prompt: None,
@@ -303,13 +296,11 @@ impl Session {
             max_windows,
             dead: Vec::new(),
             ready: Vec::new(),
-            stats: FrameStats::default(),
             totals: FrameTotals::default(),
             cached_stats: SystemStats { used_mb: 0, total_mb: 0, cpu_pct: 0 },
             prev_busy_ticks: 0,
             prev_total_ticks: 0,
             last_taskbar_update: now,
-            next_stats_report: now + STATS_INTERVAL,
         }
     }
 
@@ -1144,7 +1135,7 @@ impl Session {
         snap.put("cursor", if self.hw_cursor { "hardware" } else { "software" });
         snap.put("windows.open", self.stack.len());
         snap.put("windows.max", self.max_windows);
-        self.totals.plus(&self.stats).inspect(&mut snap);
+        self.totals.inspect(&mut snap);
         let encoded =
             snap.encode().unwrap_or_else(|why| panic!("compositor: its snapshot: {why}"));
         if let Err(e) = ipc::try_send_bytes(handle, toyos_inspect::MSG_SNAPSHOT, &encoded) {
@@ -1169,10 +1160,6 @@ impl Session {
         );
         self.back =
             BackBuffer::new(self.screen.width(), self.screen.height(), self.pixel_format());
-        // The counters belong to the mapping, and this is a new one starting at
-        // zero.
-        self.reported_traffic = self.screen.traffic();
-        self.reported_composed = self.back.surface.traffic();
         self.desk = desk_of(&self.screen, &self.font, self.apps.len());
         // What a window costs moved, so what we can afford moved with it.
         // Windows already open are left alone if the new figure is below their
@@ -1321,7 +1308,6 @@ impl Session {
             );
             if regions.iter().any(|r| r.overlaps(rect)) {
                 render::draw_software_cursor(&self.back.surface, sprite, self.cursor);
-                self.stats.cursor_draws += 1;
             }
         }
 
@@ -1337,12 +1323,7 @@ impl Session {
             );
             damage_px += region.area();
         }
-        let composited_at = Instant::now();
-        self.stats.record(
-            composited_at.duration_since(started).as_nanos() as u64,
-            regions.len(),
-            damage_px,
-        );
+        self.totals.record(started.elapsed().as_nanos() as u64, regions.len(), damage_px);
 
         for region in &regions {
             self.fb_dev
@@ -1356,21 +1337,6 @@ impl Session {
         }
 
         self.frame_callbacks(&regions);
-
-        if composited_at >= self.next_stats_report {
-            let traffic = self.screen.traffic();
-            let composed = self.back.surface.traffic();
-            self.stats.report(
-                (traffic.0 - self.reported_traffic.0, traffic.1 - self.reported_traffic.1),
-                composed.since(self.reported_composed),
-                self.stack.len(),
-            );
-            self.totals.fold(&self.stats);
-            self.stats = FrameStats::default();
-            self.reported_traffic = traffic;
-            self.reported_composed = composed;
-            self.next_stats_report = composited_at + STATS_INTERVAL;
-        }
     }
 
     /// Tell every window that presented and was composited that its frame is