scx_eevdf/
stats.rs

1use std::collections::BTreeMap;
2use std::io::Write;
3use std::sync::Arc;
4use std::sync::atomic::AtomicBool;
5use std::sync::atomic::Ordering;
6use std::time::Duration;
7
8use anyhow::Result;
9use scx_stats::prelude::*;
10use scx_stats_derive::Stats;
11use scx_stats_derive::stat_doc;
12use serde::Deserialize;
13use serde::Serialize;
14
15use crate::console;
16
17/// Kernel BPF run-time statistics of one sched_ext callback, see
18/// BPF_ENABLE_STATS. Cumulative on the server side, per interval once the
19/// client has taken the delta.
20#[stat_doc]
21#[derive(Clone, Debug, Default, Serialize, Deserialize, Stats)]
22#[stat(_om_prefix = "op_", _om_label = "callback")]
23pub struct OpStats {
24    #[stat(desc = "Times the callback ran")]
25    pub calls: u64,
26
27    #[stat(desc = "Nanoseconds spent in the callback")]
28    pub ns: u64,
29
30    #[stat(desc = "Runs refused because the callback was already active on the CPU")]
31    pub misses: u64,
32}
33
34#[stat_doc]
35#[derive(Clone, Debug, Default, Serialize, Deserialize, Stats)]
36#[stat(top)]
37pub struct Metrics {
38    #[stat(desc = "Monotonic nanoseconds covered by this sample")]
39    pub elapsed_ns: u64,
40
41    #[stat(desc = "Number of CPUs the overhead is spread over")]
42    pub nr_cpus: u64,
43
44    #[stat(desc = "Kernel BPF run-time statistics are enabled (1) or unavailable (0)")]
45    pub ops_profiled: u64,
46
47    #[stat(desc = "Periodic SIS_UTIL scan-budget updates")]
48    pub nr_sis_updates: u64,
49
50    #[stat(desc = "Sum of the scan budgets produced by SIS_UTIL updates")]
51    pub sis_scan_sum: u64,
52
53    #[stat(desc = "Bytes of arena pages the kernel has allocated")]
54    pub arena_bytes: u64,
55
56    #[stat(desc = "Size of the arena map in bytes")]
57    pub arena_max_bytes: u64,
58
59    #[stat(
60        desc = "Arena usage is known (1): counted at the allocator with --stats, or by the kernel"
61    )]
62    pub arena_counted: u64,
63
64    #[stat(desc = "Arena allocator objects currently allocated, task contexts mostly")]
65    pub arena_active_allocs: u64,
66
67    #[stat(desc = "Arena allocations that failed because the kernel refused a page")]
68    pub arena_alloc_failures: u64,
69
70    #[stat(desc = "sched_ext callbacks, keyed by name, see BPF_ENABLE_STATS")]
71    pub ops: BTreeMap<String, OpStats>,
72}
73
74impl Metrics {
75    /// Per-interval view: counters become deltas, the rest stays as it is.
76    fn delta(&self, rhs: &Self) -> Self {
77        let ops = self
78            .ops
79            .iter()
80            .map(|(name, cur)| {
81                let prev = rhs.ops.get(name).cloned().unwrap_or_default();
82                (
83                    name.clone(),
84                    OpStats {
85                        calls: cur.calls.saturating_sub(prev.calls),
86                        ns: cur.ns.saturating_sub(prev.ns),
87                        misses: cur.misses.saturating_sub(prev.misses),
88                    },
89                )
90            })
91            .collect();
92
93        Self {
94            elapsed_ns: self.elapsed_ns.saturating_sub(rhs.elapsed_ns),
95            nr_sis_updates: self.nr_sis_updates.saturating_sub(rhs.nr_sis_updates),
96            sis_scan_sum: self.sis_scan_sum.saturating_sub(rhs.sis_scan_sum),
97            ops,
98            ..self.clone()
99        }
100    }
101
102    fn calls(&self, op: &str) -> u64 {
103        self.ops.get(op).map(|o| o.calls).unwrap_or(0)
104    }
105
106    fn secs(&self) -> f64 {
107        (self.elapsed_ns.max(1)) as f64 / 1e9
108    }
109
110    fn ops_ns(&self) -> u64 {
111        self.ops.values().map(|o| o.ns).sum()
112    }
113
114    /// Total callback time over the sample, as a fraction of one CPU.
115    fn ops_cpu(&self) -> f64 {
116        self.ops_ns() as f64 / self.elapsed_ns.max(1) as f64
117    }
118
119    fn sis_avg_scan(&self) -> f64 {
120        if self.nr_sis_updates > 0 {
121            self.sis_scan_sum as f64 / self.nr_sis_updates as f64
122        } else {
123            0.0
124        }
125    }
126}
127
128/// Display order of the callbacks: the task's life from wakeup to exit,
129/// then the cgroup and scheduler-wide ones. Anything unlisted follows,
130/// alphabetically.
131const OP_ORDER: &[&str] = &[
132    "select_cid",
133    "enqueue",
134    "dequeue",
135    "dispatch",
136    "running",
137    "stopping",
138    "quiescent",
139    "tick",
140    "yield",
141    "core_sched_before",
142    "update_idle",
143    "set_weight",
144    "set_cmask",
145    "enable",
146    "init_task",
147    "exit_task",
148    "cpuctl_init",
149    "cpuctl_exit",
150    "cpuctl_set_weight",
151    "cpuctl_set_idle",
152    "cpuctl_set_bandwidth",
153    "cpuctl_move",
154    "init",
155    "exit",
156];
157
158fn op_rank(name: &str) -> usize {
159    OP_ORDER
160        .iter()
161        .position(|&n| n == name)
162        .unwrap_or(OP_ORDER.len())
163}
164
165/// Human scale for a rate or a count: 12.3k, 1.2M.
166fn human(v: f64) -> String {
167    if v >= 1e6 {
168        format!("{:.1}M", v / 1e6)
169    } else if v >= 1e4 {
170        format!("{:.0}k", v / 1e3)
171    } else if v >= 1e3 {
172        format!("{:.1}k", v / 1e3)
173    } else if v >= 10.0 || (v - v.round()).abs() < 0.05 {
174        format!("{:.0}", v)
175    } else {
176        format!("{:.1}", v)
177    }
178}
179
180/// Human scale for a size in bytes: 512 B, 1.5 MiB.
181pub fn human_bytes(bytes: u64) -> String {
182    const UNITS: &[&str] = &["B", "KiB", "MiB", "GiB", "TiB"];
183    let mut v = bytes as f64;
184    let mut unit = 0;
185    while v >= 1024.0 && unit + 1 < UNITS.len() {
186        v /= 1024.0;
187        unit += 1;
188    }
189    if unit == 0 {
190        format!("{bytes} B")
191    } else {
192        format!("{v:.1} {}", UNITS[unit])
193    }
194}
195
196/// Human scale for a duration in nanoseconds.
197fn human_ns(ns: f64) -> String {
198    if ns >= 1e6 {
199        format!("{:.2}ms", ns / 1e6)
200    } else if ns >= 1e3 {
201        format!("{:.2}us", ns / 1e3)
202    } else {
203        format!("{:.0}ns", ns)
204    }
205}
206
207/// Print the metrics as one block per interval, appended like a log so the
208/// history stays in the scrollback and in any file the output goes to.
209struct Dashboard {
210    intv: Duration,
211    frames: u64,
212    started: std::time::Instant,
213}
214
215impl Dashboard {
216    fn new(intv: Duration) -> Self {
217        Self {
218            intv,
219            frames: 0,
220            started: std::time::Instant::now(),
221        }
222    }
223
224    fn render(&mut self, m: &Metrics) -> Result<()> {
225        // The first read follows the open by microseconds and covers
226        // nothing worth printing.
227        if self.frames == 0 && m.elapsed_ns < self.intv.as_nanos() as u64 / 2 {
228            return Ok(());
229        }
230        self.frames += 1;
231        let mut buf = Vec::new();
232        self.frame(&mut buf, m)?;
233        for line in String::from_utf8_lossy(&buf).lines() {
234            console::emit(line);
235        }
236        Ok(())
237    }
238
239    /// One frame: header, the callback table, the event rates.
240    fn frame<W: Write>(&self, w: &mut W, m: &Metrics) -> Result<()> {
241        let secs = m.secs();
242        let up = self.started.elapsed().as_secs();
243
244        let header = console::header(&[
245            format!("up {:02}:{:02}:{:02}", up / 3600, (up / 60) % 60, up % 60),
246            format!("{} CPUs", m.nr_cpus),
247            format!("{secs:.1} s/sample"),
248            format!("#{}", self.frames),
249        ]);
250        writeln!(w, "{header}")?;
251
252        // sched_ext callbacks: the kernel's own run-time accounting.
253        let cpu = m.ops_cpu();
254        writeln!(
255            w,
256            "sched_ext callbacks   overhead {:.2}% of one CPU ({:.3}% of {})   {}",
257            cpu * 100.0,
258            cpu * 100.0 / m.nr_cpus.max(1) as f64,
259            m.nr_cpus,
260            if m.ops_profiled == 1 {
261                "BPF_ENABLE_STATS on"
262            } else {
263                "BPF run-time stats unavailable"
264            },
265        )?;
266        writeln!(
267            w,
268            "{:<21}{:>9}{:>10}{:>9}{:>8}  {}",
269            "callback", "calls/s", "avg", "cpu%", "share", "of callback time"
270        )?;
271        // Every callback, every sample, in a fixed order, so a row keeps
272        // its place from one block to the next.
273        let mut ops: Vec<(&String, &OpStats)> = m.ops.iter().collect();
274        ops.sort_by_key(|(name, _)| (op_rank(name), (*name).clone()));
275        let total_ns = m.ops_ns().max(1) as f64;
276        let bar_w = 30;
277        for (name, o) in &ops {
278            let avg = if o.calls > 0 {
279                human_ns(o.ns as f64 / o.calls as f64)
280            } else {
281                "-".to_string()
282            };
283            let share = o.ns as f64 / total_ns;
284            let filled = (share * bar_w as f64).round() as usize;
285            let op_cpu = o.ns as f64 / m.elapsed_ns.max(1) as f64 * 100.0;
286            let misses = if o.misses > 0 {
287                format!(" {} misses", o.misses)
288            } else {
289                String::new()
290            };
291            writeln!(
292                w,
293                "{:<21}{:>9}{:>10}{:>8.2}%{:>7.1}%  {}{}{misses}",
294                name,
295                human(o.calls as f64 / secs),
296                avg,
297                op_cpu,
298                share * 100.0,
299                "#".repeat(filled),
300                ".".repeat(bar_w - filled),
301            )?;
302        }
303        if ops.is_empty() {
304            writeln!(w, "no callback program found")?;
305        }
306        // Event rates, read off the callback counts.
307        let per_switch = if m.calls("running") > 0 {
308            m.ops_ns() as f64 / m.calls("running") as f64
309        } else {
310            0.0
311        };
312        // Four to a line, so the block stays narrower than the table.
313        let rate =
314            |name: &str, op: &str| format!("{name:<8}{:>5}", human(m.calls(op) as f64 / secs));
315        writeln!(
316            w,
317            "events/s   {}  {}  {}  {}",
318            rate("wakeups", "select_cid"),
319            rate("switches", "running"),
320            rate("sleeps", "quiescent"),
321            rate("ticks", "tick"),
322        )?;
323        writeln!(
324            w,
325            "           {}  {}  {}  {}",
326            rate("yields", "yield"),
327            rate("forks", "init_task"),
328            rate("exits", "exit_task"),
329            rate("cmask", "set_cmask"),
330        )?;
331        writeln!(
332            w,
333            "callback time per context switch {}",
334            human_ns(per_switch)
335        )?;
336        writeln!(
337            w,
338            "sis updates {}   avg scan budget {:.1}",
339            m.nr_sis_updates,
340            m.sis_avg_scan(),
341        )?;
342        if m.arena_counted == 1 {
343            writeln!(
344                w,
345                "BPF arena memory {} of {} ({:.2}%)   active allocations {}   failed allocations {}",
346                human_bytes(m.arena_bytes),
347                human_bytes(m.arena_max_bytes),
348                m.arena_bytes as f64 * 100.0 / m.arena_max_bytes.max(1) as f64,
349                m.arena_active_allocs,
350                m.arena_alloc_failures,
351            )?;
352        } else {
353            writeln!(
354                w,
355                "BPF arena memory {} reserved, usage counted with --stats   active allocations {}   failed allocations {}",
356                human_bytes(m.arena_max_bytes),
357                m.arena_active_allocs,
358                m.arena_alloc_failures,
359            )?;
360        }
361        Ok(())
362    }
363}
364
365pub fn server_data() -> StatsServerData<(), Metrics> {
366    let open: Box<dyn StatsOpener<(), Metrics>> = Box::new(move |(req_ch, res_ch)| {
367        req_ch.send(())?;
368        let mut prev = res_ch.recv()?;
369
370        let read: Box<dyn StatsReader<(), Metrics>> = Box::new(move |_args, (req_ch, res_ch)| {
371            req_ch.send(())?;
372            let cur = res_ch.recv()?;
373            let delta = cur.delta(&prev);
374            prev = cur;
375            delta.to_json()
376        });
377
378        Ok(read)
379    });
380
381    StatsServerData::new()
382        .add_meta(OpStats::meta())
383        .add_meta(Metrics::meta())
384        .add_ops("top", StatsOps { open, close: None })
385}
386
387pub fn monitor(intv: Duration, shutdown: Arc<AtomicBool>) -> Result<()> {
388    let mut dash = Dashboard::new(intv);
389    scx_utils::monitor_stats::<Metrics>(
390        &[],
391        intv,
392        || shutdown.load(Ordering::Relaxed),
393        |metrics| dash.render(&metrics),
394    )
395}
scx_eevdf/stats.rs

scx_eevdf/
stats.rs
