1use std::collections::HashMap;
15use std::fs::File;
16use std::io::{BufRead, BufReader};
17use std::os::unix::process::CommandExt;
18use std::path::{Path, PathBuf};
19use std::process::{Child, Command, Stdio};
20use std::sync::atomic::AtomicBool;
21use std::thread::sleep;
22use std::time::{Duration, Instant};
23
24use anyhow::{Context, Result};
25use serde_json::{json, Value};
26
27use crate::cargo_program;
28use crate::color::Style;
29use crate::interrupt;
30use crate::progress::ProgressSpinner;
31use crate::spec::{Spec, METRIC_NAME};
32use crate::sudo::Sudo;
33
34const SCX_STATE_PATH: &str = "/sys/kernel/sched_ext/state";
35
36#[derive(Debug, Clone)]
37pub struct Verdict {
38 pub ok: bool,
39 pub stage: String,
40 pub metric_name: String,
41 pub goal: String,
42 pub value: Option<f64>,
43 pub median: Option<f64>,
44 pub stddev: Option<f64>,
45 pub errors: Vec<String>,
46 pub raw: Value,
47}
48
49impl Verdict {
50 pub fn is_complete(&self) -> bool {
51 self.ok && self.stage == "complete" && self.value.is_some()
52 }
53}
54
55fn scx_state() -> Option<String> {
57 std::fs::read_to_string(SCX_STATE_PATH)
58 .ok()
59 .map(|s| s.trim().to_string())
60}
61
62fn wait_for_state(want: &str, timeout: Duration, interrupted: &AtomicBool) -> bool {
64 let deadline = Instant::now() + timeout;
65 loop {
66 if scx_state().as_deref() == Some(want) {
67 return true;
68 }
69 if interrupt::requested(interrupted) {
70 return false;
71 }
72 if Instant::now() >= deadline {
73 return scx_state().as_deref() == Some(want);
74 }
75 sleep(Duration::from_millis(100));
76 }
77}
78
79fn scx_is_enabled(state: Option<&str>) -> bool {
80 state == Some("enabled")
81}
82
83fn sleep_interruptible(duration: Duration, interrupted: &AtomicBool) -> bool {
85 let deadline = Instant::now() + duration;
86 loop {
87 if interrupt::requested(interrupted) {
88 return true;
89 }
90 let now = Instant::now();
91 if now >= deadline {
92 return false;
93 }
94 sleep((deadline - now).min(Duration::from_millis(100)));
95 }
96}
97
98fn cargo_build(
100 repo_root: &Path,
101 package: &str,
102 profile: &str,
103 interrupted: &AtomicBool,
104) -> (bool, String) {
105 let cargo = cargo_program();
106 let mut command = Command::new(&cargo);
107 command
108 .args(["build", "--profile", profile, "-p", package])
109 .current_dir(repo_root)
110 .stdout(Stdio::piped())
111 .stderr(Stdio::piped());
112 unsafe {
113 command.pre_exec(|| {
114 libc::setsid();
115 Ok(())
116 });
117 }
118 let mut child = match command.spawn() {
119 Ok(child) => child,
120 Err(e) => {
121 return (
122 false,
123 format!("spawn {} build: {e}", cargo.to_string_lossy()),
124 )
125 }
126 };
127 let pid = child.id() as i32;
128 loop {
129 if interrupt::requested(interrupted) {
130 unsafe {
131 libc::kill(-pid, libc::SIGINT);
132 }
133 let deadline = Instant::now() + Duration::from_secs(2);
134 loop {
135 match child.try_wait() {
136 Ok(Some(_)) | Err(_) => break,
137 Ok(None) if Instant::now() >= deadline => {
138 unsafe {
139 libc::kill(-pid, libc::SIGKILL);
140 }
141 break;
142 }
143 Ok(None) => sleep(Duration::from_millis(50)),
144 }
145 }
146 let out = match child.wait_with_output() {
147 Ok(out) => out,
148 Err(e) => {
149 return (
150 false,
151 format!("cargo build interrupted; collect output: {e}"),
152 )
153 }
154 };
155 let mut s = String::from("cargo build interrupted by Ctrl-C\n");
156 s.push_str(&String::from_utf8_lossy(&out.stdout));
157 s.push_str(&String::from_utf8_lossy(&out.stderr));
158 return (false, s);
159 }
160 match child.try_wait() {
161 Ok(Some(_)) => break,
162 Ok(None) => sleep(Duration::from_millis(100)),
163 Err(e) => {
164 return (
165 false,
166 format!("poll {} build: {e}", cargo.to_string_lossy()),
167 )
168 }
169 }
170 }
171 let out = match child.wait_with_output() {
172 Ok(out) => out,
173 Err(e) => {
174 return (
175 false,
176 format!("collect {} build output: {e}", cargo.to_string_lossy()),
177 )
178 }
179 };
180 let mut s = String::from_utf8_lossy(&out.stdout).to_string();
181 s.push_str(&String::from_utf8_lossy(&out.stderr));
182 (out.status.success(), s)
183}
184
185pub(crate) fn binary_path(repo_root: &Path, package: &str, profile: &str) -> PathBuf {
188 let subdir = match profile {
189 "release" => "release",
190 "dev" => "debug",
191 other => other,
192 };
193 repo_root.join("target").join(subdir).join(package)
194}
195
196fn read_lossy(path: &Path) -> String {
197 std::fs::read(path)
198 .map(|b| String::from_utf8_lossy(&b).into_owned())
199 .unwrap_or_default()
200}
201
202fn perf_available() -> bool {
203 Command::new("perf")
204 .arg("--version")
205 .stdout(Stdio::null())
206 .stderr(Stdio::null())
207 .status()
208 .is_ok()
209}
210
211fn perf_mmap_pages_per_cpu(max_total_bytes: u64) -> u64 {
215 let cpus = std::thread::available_parallelism()
216 .map(|n| n.get() as u64)
217 .unwrap_or(1)
218 .max(1);
219 const PAGE_SIZE: u64 = 4096;
220 let pages = (max_total_bytes / PAGE_SIZE / cpus).max(1);
221 let mut pow2 = 1;
222 while pow2 <= pages / 2 {
223 pow2 *= 2;
224 }
225 pow2
226}
227
228#[derive(Default, Debug)]
229struct TraceStats {
230 start_ts: Option<f64>,
231 end_ts: Option<f64>,
232 events: HashMap<String, u64>,
233 per_cpu_events: HashMap<String, u64>,
234}
235
236impl TraceStats {
237 fn total(&self) -> u64 {
238 self.events.values().sum()
239 }
240}
241
242fn trace_cpu(line: &str) -> Option<String> {
243 let start = line.find('[')? + 1;
244 let end = line[start..].find(']')? + start;
245 Some(line[start..end].trim().to_string())
246}
247
248fn trace_event(line: &str) -> Option<(f64, String, Option<String>)> {
249 let cpu = trace_cpu(line);
250 let cpu_end = line.find(']')? + 1;
251 let mut tokens = line[cpu_end..].split_whitespace();
252 while let Some(token) = tokens.next() {
253 let ts_token = token.trim_end_matches(':');
254 if let Ok(ts) = ts_token.parse::<f64>() {
255 for token in tokens {
256 let event = token.trim_end_matches(':');
257 if event.is_empty() || event.parse::<f64>().is_ok() {
258 continue;
259 }
260 return Some((ts, event.to_string(), cpu));
261 }
262 return None;
263 }
264 }
265 None
266}
267
268fn update_trace_stats(stats: &mut TraceStats, line: &str) {
269 if let Some((ts, event, cpu)) = trace_event(line) {
270 stats.start_ts = Some(stats.start_ts.map_or(ts, |start| start.min(ts)));
271 stats.end_ts = Some(stats.end_ts.map_or(ts, |end| end.max(ts)));
272 *stats.events.entry(event).or_insert(0) += 1;
273 if let Some(cpu) = cpu {
274 *stats.per_cpu_events.entry(cpu).or_insert(0) += 1;
275 }
276 }
277}
278
279fn trace_window_sec(start_ts: Option<f64>, end_ts: Option<f64>) -> Option<f64> {
280 let window = end_ts? - start_ts?;
281 (window > 0.0).then_some(window)
282}
283
284fn round_trace_float(value: f64) -> f64 {
285 (value * 1_000_000.0).round() / 1_000_000.0
286}
287
288fn rounded_option(value: Option<f64>) -> Value {
289 match value {
290 Some(value) => json!(round_trace_float(value)),
291 None => Value::Null,
292 }
293}
294
295fn rate_value(count: u64, window: Option<f64>) -> Value {
296 match window {
297 Some(window) => json!(round_trace_float(count as f64 / window)),
298 None => Value::Null,
299 }
300}
301
302fn sorted_counts(map: &HashMap<String, u64>) -> Vec<(&String, &u64)> {
303 let mut v = map.iter().collect::<Vec<_>>();
304 v.sort_by(|(ka, va), (kb, vb)| vb.cmp(va).then_with(|| ka.cmp(kb)));
305 v
306}
307
308fn event_counts_json(events: &HashMap<String, u64>) -> Value {
309 json!(sorted_counts(events)
310 .into_iter()
311 .map(|(event, count)| json!({"event": event, "count": count}))
312 .collect::<Vec<_>>())
313}
314
315fn event_rates_json(events: &HashMap<String, u64>, window: Option<f64>) -> Value {
316 json!(sorted_counts(events)
317 .into_iter()
318 .map(|(event, count)| json!({"event": event, "per_sec": rate_value(*count, window)}))
319 .collect::<Vec<_>>())
320}
321
322fn cpu_event_rate_summary(stats: &TraceStats, window: Option<f64>, limit: usize) -> Value {
323 let mut cpus = stats.per_cpu_events.iter().collect::<Vec<_>>();
324 cpus.sort_by(|(cpu_a, count_a), (cpu_b, count_b)| {
325 count_b.cmp(count_a).then_with(|| cpu_a.cmp(cpu_b))
326 });
327
328 let rates = match window {
329 Some(window) => cpus
330 .iter()
331 .map(|(_, count)| **count as f64 / window)
332 .collect::<Vec<_>>(),
333 None => Vec::new(),
334 };
335 let max_rate = rates.iter().copied().reduce(f64::max);
336 let median_rate = if rates.is_empty() {
337 None
338 } else {
339 Some(median(&rates))
340 };
341 let max_to_median = match (max_rate, median_rate) {
342 (Some(max), Some(median)) if median > 0.0 => Some(max / median),
343 _ => None,
344 };
345 let top_cpus = cpus
346 .iter()
347 .take(limit)
348 .map(|(cpu, count)| {
349 json!({
350 "cpu": cpu,
351 "events": count,
352 "events_per_sec": rate_value(**count, window),
353 })
354 })
355 .collect::<Vec<_>>();
356
357 json!({
358 "cpus_observed": stats.per_cpu_events.len(),
359 "rates_scope": "per-CPU observed event totals divided by the global retained trace_window.duration_sec",
360 "median_events_per_sec": rounded_option(median_rate),
361 "max_events_per_sec": rounded_option(max_rate),
362 "max_to_median_ratio": rounded_option(max_to_median),
363 "top_cpus_by_total_events": top_cpus,
364 })
365}
366
367fn trace_stats_json(
368 stats: &TraceStats,
369 trace_path: &Path,
370 report_path: &Path,
371 events: &[String],
372) -> Value {
373 let window = trace_window_sec(stats.start_ts, stats.end_ts);
374 json!({
375 "enabled": true,
376 "backend": "perf",
377 "events": events,
378 "artifacts": {
379 "perf_data": trace_path.display().to_string(),
380 "perf_script": report_path.display().to_string(),
381 },
382 "trace_window": {
383 "start_ts": rounded_option(stats.start_ts),
384 "end_ts": rounded_option(stats.end_ts),
385 "duration_sec": rounded_option(window),
386 "scope": "retained perf script sample window; max-size limits may make this shorter than the workload",
387 },
388 "event_count_semantics": "perf sample records. Tracepoints are sampled per occurrence; hardware PMU events are sampled according to perf's configured/default sampling period, not raw hardware event totals.",
389 "event_count_total": stats.total(),
390 "event_rate_total_per_sec": rate_value(stats.total(), window),
391 "event_counts": event_counts_json(&stats.events),
392 "event_rates_per_sec": event_rates_json(&stats.events, window),
393 "cpu_event_rate_summary": cpu_event_rate_summary(stats, window, 8),
394 })
395}
396
397struct TraceRecorder {
398 child: Child,
399 trace_path: PathBuf,
400 log_path: PathBuf,
401}
402
403impl TraceRecorder {
404 fn start(
405 sudo: &Sudo,
406 trace_path: PathBuf,
407 log_path: PathBuf,
408 max_total_bytes: u64,
409 max_size_arg: &str,
410 events: &[String],
411 ) -> Result<Self> {
412 let _ = std::fs::remove_file(&trace_path);
413 let _ = sudo
414 .command("rm", &["-f".to_string(), trace_path.display().to_string()])
415 .status();
416 let log = File::create(&log_path)
417 .with_context(|| format!("create perf record log {}", log_path.display()))?;
418 let log_err = log.try_clone().context("clone perf record log handle")?;
419 let mut args = vec![
420 "record".to_string(),
421 "-a".to_string(),
422 "-q".to_string(),
423 "--sample-cpu".to_string(),
424 "-T".to_string(),
425 "-o".to_string(),
426 trace_path.display().to_string(),
427 "--max-size".to_string(),
428 max_size_arg.to_string(),
429 "-m".to_string(),
430 perf_mmap_pages_per_cpu(max_total_bytes).to_string(),
431 ];
432 for event in events {
433 args.push("-e".to_string());
434 args.push(event.to_string());
435 }
436 args.push("--".to_string());
437 args.push("sleep".to_string());
438 args.push("2147483647".to_string());
439 let mut command = sudo.command("perf", &args);
440 command.stdout(log).stderr(log_err).stdin(Stdio::null());
441 unsafe {
442 command.pre_exec(|| {
443 libc::setsid();
444 Ok(())
445 });
446 }
447 let mut child = command
448 .spawn()
449 .with_context(|| format!("spawn perf record {}", trace_path.display()))?;
450 sleep(Duration::from_millis(250));
451 if let Some(status) = child.try_wait().context("poll perf startup")? {
452 anyhow::bail!(
453 "perf record exited during startup with {status}; log tail:\n{}",
454 tail(&read_lossy(&log_path), 1000)
455 );
456 }
457 Ok(Self {
458 child,
459 trace_path,
460 log_path,
461 })
462 }
463
464 fn stop(mut self, sudo: &Sudo, events: &[String]) -> Value {
465 let pid = self.child.id() as i32;
466 unsafe {
467 libc::kill(-pid, libc::SIGINT);
468 }
469 let deadline = Instant::now() + Duration::from_secs(10);
470 let mut stopped = false;
471 loop {
472 match self.child.try_wait() {
473 Ok(Some(_)) => {
474 stopped = true;
475 break;
476 }
477 Ok(None) => {
478 if Instant::now() >= deadline {
479 break;
480 }
481 sleep(Duration::from_millis(100));
482 }
483 Err(_) => break,
484 }
485 }
486 if !stopped {
487 unsafe {
488 libc::kill(-pid, libc::SIGKILL);
489 }
490 let _ = self.child.wait();
491 }
492 summarize_trace(sudo, &self.trace_path, &self.log_path, events)
493 }
494}
495
496fn summarize_trace(sudo: &Sudo, trace_path: &Path, log_path: &Path, events: &[String]) -> Value {
497 if !trace_path.exists() {
498 return json!({
499 "enabled": false,
500 "backend": "perf",
501 "error": format!("perf record did not create {}", trace_path.display()),
502 "log_tail": tail(&read_lossy(log_path), 1000),
503 });
504 }
505 let report_path = trace_path.with_extension("script");
506 let report = match File::create(&report_path) {
507 Ok(f) => f,
508 Err(e) => {
509 return json!({
510 "enabled": false,
511 "backend": "perf",
512 "perf_data": trace_path.display().to_string(),
513 "error": format!("create perf script report {}: {e}", report_path.display()),
514 "log_tail": tail(&read_lossy(log_path), 1000),
515 })
516 }
517 };
518 let report_err = match report.try_clone() {
519 Ok(f) => f,
520 Err(e) => {
521 return json!({
522 "enabled": false,
523 "backend": "perf",
524 "perf_data": trace_path.display().to_string(),
525 "error": format!("clone perf script report handle: {e}"),
526 "log_tail": tail(&read_lossy(log_path), 1000),
527 })
528 }
529 };
530 let args = vec![
531 "script".to_string(),
532 "--ns".to_string(),
533 "-F".to_string(),
534 "comm,pid,cpu,time,event".to_string(),
535 "-i".to_string(),
536 trace_path.display().to_string(),
537 ];
538 let status = sudo
539 .command("perf", &args)
540 .stdout(report)
541 .stderr(report_err)
542 .status();
543 if !matches!(status, Ok(s) if s.success()) {
544 return json!({
545 "enabled": false,
546 "backend": "perf",
547 "perf_data": trace_path.display().to_string(),
548 "perf_script": report_path.display().to_string(),
549 "error": format!("perf script failed: {:?}", status),
550 "report_tail": tail(&read_lossy(&report_path), 1000),
551 "log_tail": tail(&read_lossy(log_path), 1000),
552 });
553 }
554
555 let file = match File::open(&report_path) {
556 Ok(f) => f,
557 Err(e) => {
558 return json!({
559 "enabled": false,
560 "backend": "perf",
561 "perf_data": trace_path.display().to_string(),
562 "perf_script": report_path.display().to_string(),
563 "error": format!("open perf script report: {e}"),
564 "log_tail": tail(&read_lossy(log_path), 1000),
565 })
566 }
567 };
568 let mut stats = TraceStats::default();
569 for line in BufReader::new(file).lines().map_while(Result::ok) {
570 update_trace_stats(&mut stats, &line);
571 }
572 trace_stats_json(&stats, trace_path, &report_path, events)
573}
574
575fn run_capture(
579 cmd: &str,
580 timeout: Duration,
581 out_path: &Path,
582 progress: Option<Style>,
583 label: String,
584 interrupted: &AtomicBool,
585) -> Result<String> {
586 let out = File::create(out_path)
587 .with_context(|| format!("create workload log {}", out_path.display()))?;
588 let err = out.try_clone().context("clone workload log handle")?;
589 let mut command = Command::new("sh");
590 command
591 .arg("-c")
592 .arg(cmd)
593 .stdout(out)
594 .stderr(err)
595 .stdin(Stdio::null());
596 unsafe {
598 command.pre_exec(|| {
599 libc::setsid();
600 Ok(())
601 });
602 }
603 let mut child = command
604 .spawn()
605 .with_context(|| format!("spawn workload: {cmd}"))?;
606 let _spinner = progress.map(|style| ProgressSpinner::stdout(label, style));
607 let pid = child.id() as i32;
608 let deadline = Instant::now() + timeout;
609 loop {
610 match child.try_wait().context("poll workload")? {
611 Some(_) => break,
612 None => {
613 if interrupt::requested(interrupted) {
614 unsafe {
615 libc::kill(-pid, libc::SIGINT);
616 }
617 let deadline = Instant::now() + Duration::from_secs(2);
618 loop {
619 match child.try_wait().context("poll interrupted workload")? {
620 Some(_) => break,
621 None if Instant::now() >= deadline => {
622 unsafe {
623 libc::kill(-pid, libc::SIGKILL);
624 }
625 let _ = child.wait();
626 break;
627 }
628 None => sleep(Duration::from_millis(50)),
629 }
630 }
631 break;
632 }
633 if Instant::now() >= deadline {
634 unsafe {
635 libc::kill(-pid, libc::SIGKILL);
636 }
637 let _ = child.wait();
638 break;
639 }
640 sleep(Duration::from_millis(100));
641 }
642 }
643 }
644 Ok(read_lossy(out_path))
645}
646
647fn extract_metric(text: &str) -> Option<f64> {
650 let value = text.trim();
651 if value.is_empty() {
652 return None;
653 }
654 value.parse::<f64>().ok()
655}
656
657fn median(values: &[f64]) -> f64 {
658 let mut v = values.to_vec();
659 v.sort_by(|a, b| a.partial_cmp(b).unwrap_or(std::cmp::Ordering::Equal));
660 let n = v.len();
661 if n % 2 == 1 {
662 v[n / 2]
663 } else {
664 (v[n / 2 - 1] + v[n / 2]) / 2.0
665 }
666}
667
668fn pstdev(values: &[f64]) -> f64 {
670 let n = values.len();
671 if n <= 1 {
672 return 0.0;
673 }
674 let mean = values.iter().sum::<f64>() / n as f64;
675 let var = values.iter().map(|x| (x - mean).powi(2)).sum::<f64>() / n as f64;
676 var.sqrt()
677}
678
679fn binary_help(binary: &Path) -> String {
684 match std::process::Command::new(binary).arg("--help").output() {
685 Ok(out) => {
686 let mut help = String::from_utf8_lossy(&out.stdout).into_owned();
687 help.push_str(&String::from_utf8_lossy(&out.stderr));
688 help
689 }
690 Err(_) => String::new(),
691 }
692}
693
694struct Scheduler {
696 binary: PathBuf,
697 stats_interval: u64,
698 supports_stats: bool,
699 supports_verbose: bool,
700 log_path: PathBuf,
701 child: Option<Child>,
702}
703
704impl Scheduler {
705 fn new(binary: PathBuf, stats_interval: u64, log_path: PathBuf) -> Self {
706 let help = binary_help(&binary);
707 Scheduler {
708 binary,
709 stats_interval,
710 supports_stats: help.contains("--stats"),
711 supports_verbose: help.contains("--verbose"),
712 log_path,
713 child: None,
714 }
715 }
716
717 fn start(&mut self, sudo: &Sudo) -> Result<()> {
718 let log = File::create(&self.log_path)
719 .with_context(|| format!("create scheduler log {}", self.log_path.display()))?;
720 let log_err = log.try_clone().context("clone scheduler log handle")?;
721 let mut full_args: Vec<String> = Vec::new();
722 if self.supports_verbose {
726 full_args.push("--verbose".into());
727 }
728 if self.supports_stats {
731 full_args.push("--stats".into());
732 full_args.push(self.stats_interval.to_string());
733 }
734 let mut command = sudo.command(&self.binary.to_string_lossy(), &full_args);
735 command.stdout(log).stderr(log_err).stdin(Stdio::null());
736 unsafe {
738 command.pre_exec(|| {
739 libc::setsid();
740 Ok(())
741 });
742 }
743 self.child = Some(
744 command
745 .spawn()
746 .with_context(|| format!("spawn scheduler {}", self.binary.display()))?,
747 );
748 Ok(())
749 }
750
751 fn log_text(&self) -> String {
752 read_lossy(&self.log_path)
753 }
754
755 fn stop(&mut self, sudo: &Sudo) -> Option<String> {
757 if let Some(child) = self.child.as_mut() {
758 if matches!(child.try_wait(), Ok(None)) {
759 unsafe {
761 libc::kill(child.id() as i32, libc::SIGINT);
762 }
763 let deadline = Instant::now() + Duration::from_secs(8);
764 loop {
765 match child.try_wait() {
766 Ok(Some(_)) | Err(_) => break,
767 Ok(None) => {
768 if Instant::now() >= deadline {
769 break;
770 }
771 sleep(Duration::from_millis(100));
772 }
773 }
774 }
775 }
776 }
777 let base = self
781 .binary
782 .file_name()
783 .map(|s| s.to_string_lossy().into_owned())
784 .unwrap_or_default();
785 for sig in ["-INT", "-KILL"] {
786 if !matches!(scx_state().as_deref(), None | Some("disabled")) {
787 let _ = sudo
788 .command("pkill", &[sig.into(), "-x".into(), base.clone()])
789 .status();
790 let never_interrupted = AtomicBool::new(false);
791 wait_for_state("disabled", Duration::from_secs(6), &never_interrupted);
792 }
793 }
794 scx_state()
795 }
796}
797
798pub fn exec_scheduler_foreground(
804 repo_root: &Path,
805 package: &str,
806 profile: &str,
807 sudo: &Sudo,
808) -> Result<()> {
809 match scx_state() {
810 None => {
811 anyhow::bail!("{SCX_STATE_PATH} not found; kernel lacks sched_ext");
812 }
813 Some(s) if s != "disabled" => {
814 anyhow::bail!("a scheduler is already attached (state={s:?})");
815 }
816 _ => {}
817 }
818 sudo.authenticate().context("sudo authentication failed")?;
819
820 let sched_bin = binary_path(repo_root, package, profile);
821 if !sched_bin.exists() {
822 anyhow::bail!("scheduler binary not found at {}", sched_bin.display());
823 }
824
825 let sched_prog = sched_bin.to_string_lossy().into_owned();
826 let args = Vec::new();
827 let mut command = sudo.command(&sched_prog, &args);
828 Err::<(), _>(command.exec()).with_context(|| format!("exec scheduler {}", sched_bin.display()))
829}
830
831struct Measurement {
833 value: Option<f64>,
834 scheduler_stats: String,
835 runtime_ok: bool,
836 sched_trace: Option<Value>,
837}
838
839fn measure_once(
840 spec: &Spec,
841 sched_bin: &Path,
842 workdir: &Path,
843 run_idx: u64,
844 sudo: &Sudo,
845 errors: &mut Vec<String>,
846 progress: Option<Style>,
847 trace_enabled: bool,
848 interrupted: &AtomicBool,
849) -> Result<Measurement> {
850 let log_path = workdir.join(format!("sched.run{run_idx}.log"));
851 let mut sched = Scheduler::new(
852 sched_bin.to_path_buf(),
853 spec.scheduler.stats_interval,
854 log_path,
855 );
856
857 sched.start(sudo)?;
858 let warmup = spec.scheduler.warmup_time;
859 let mut wl_out = String::new();
860 let mut sched_trace = None;
861 let attached = wait_for_state("enabled", Duration::from_secs(warmup + 6), interrupted);
862 if attached {
863 if !sleep_interruptible(Duration::from_secs(warmup), interrupted) {
864 let duration = Duration::from_secs(spec.workload.duration);
865 let cmd = spec
866 .workload
867 .command
868 .as_deref()
869 .context("[workload].command is required")?;
870 let out_path = workdir.join(format!("wl.run{run_idx}.out"));
871 let total_runs = spec.runs();
872 let label = if total_runs > 1 {
873 format!("running workload ({}/{total_runs})...", run_idx + 1)
874 } else {
875 "running workload...".to_string()
876 };
877 let trace_recorder = if trace_enabled {
878 let trace_path = workdir.join(format!("perf.run{run_idx}.data"));
879 let trace_log_path = workdir.join(format!("perf.run{run_idx}.log"));
880 let max_trace_bytes = spec.tracing.max_trace_bytes()?;
881 match TraceRecorder::start(
882 sudo,
883 trace_path,
884 trace_log_path,
885 max_trace_bytes,
886 &spec.tracing.max_trace_size,
887 &spec.tracing.trace_events,
888 ) {
889 Ok(recorder) => Some(recorder),
890 Err(e) => {
891 sched_trace = Some(json!({
892 "enabled": false,
893 "error": format!("{e:#}"),
894 }));
895 None
896 }
897 }
898 } else {
899 None
900 };
901 let workload = run_capture(cmd, duration, &out_path, progress, label, interrupted);
902 if let Some(recorder) = trace_recorder {
903 sched_trace = Some(recorder.stop(sudo, &spec.tracing.trace_events));
904 }
905 wl_out = workload?;
906 }
907 } else {
908 errors.push(format!(
909 "run {run_idx}: scheduler did not attach; log tail:\n{}",
910 tail(&sched.log_text(), 2000)
911 ));
912 }
913
914 let runtime_ok = if attached {
915 let post_workload_state = scx_state();
916 if scx_is_enabled(post_workload_state.as_deref()) {
917 true
918 } else {
919 errors.push(format!(
920 "run {run_idx}: scheduler is no longer enabled after workload \
921 (scx state={:?}); treating candidate as a regression to avoid \
922 measuring the default scheduler; log tail:\n{}",
923 post_workload_state,
924 tail(&sched.log_text(), 2000)
925 ));
926 false
927 }
928 } else {
929 true
930 };
931
932 let final_state = sched.stop(sudo);
933 if !matches!(final_state.as_deref(), None | Some("disabled")) {
934 errors.push(format!(
935 "run {run_idx}: teardown failed, scx state={:?}",
936 final_state
937 ));
938 }
939 if !attached {
940 return Ok(Measurement {
941 value: None,
942 scheduler_stats: sched.log_text(),
943 runtime_ok,
944 sched_trace,
945 });
946 }
947 if !runtime_ok {
948 return Ok(Measurement {
949 value: None,
950 scheduler_stats: sched.log_text(),
951 runtime_ok,
952 sched_trace,
953 });
954 }
955
956 let val = extract_metric(&wl_out);
957 if val.is_none() {
958 errors.push(format!(
959 "run {run_idx}: workload command output was not a plain number"
960 ));
961 }
962 Ok(Measurement {
963 value: val,
964 scheduler_stats: sched.log_text(),
965 runtime_ok,
966 sched_trace,
967 })
968}
969
970fn tail(s: &str, n: usize) -> String {
971 if s.len() > n {
972 s[s.len() - n..].to_string()
973 } else {
974 s.to_string()
975 }
976}
977
978#[allow(clippy::too_many_arguments)]
980fn fail(
981 stage: &str,
982 spec: Option<&Spec>,
983 errors: Vec<String>,
984 extra: Vec<(&str, Value)>,
985) -> Verdict {
986 let (metric_name, goal, package) = match spec {
987 Some(s) => (
988 METRIC_NAME.to_string(),
989 s.goal.direction.clone(),
990 Some(s.scheduler.package.clone()),
991 ),
992 None => (METRIC_NAME.to_string(), "minimize".to_string(), None),
993 };
994 let mut raw = serde_json::Map::new();
995 raw.insert("ok".into(), json!(false));
996 raw.insert("stage".into(), json!(stage));
997 if let Some(p) = &package {
998 raw.insert("package".into(), json!(p));
999 }
1000 raw.insert("errors".into(), json!(errors));
1001 for (k, v) in extra {
1002 raw.insert(k.into(), v);
1003 }
1004 Verdict {
1005 ok: false,
1006 stage: stage.to_string(),
1007 metric_name,
1008 goal,
1009 value: None,
1010 median: None,
1011 stddev: None,
1012 errors,
1013 raw: Value::Object(raw),
1014 }
1015}
1016
1017pub fn run_validation(
1019 repo_root: &Path,
1020 spec_path: &Path,
1021 sudo: &Sudo,
1022 verbose: bool,
1023 progress: Option<Style>,
1024 tracing_enabled: bool,
1025 interrupted: &AtomicBool,
1026) -> Result<Verdict> {
1027 let spec = match Spec::load(spec_path) {
1028 Ok(s) => s,
1029 Err(e) => return Ok(fail("spec", None, vec![format!("{e:#}")], vec![])),
1030 };
1031
1032 if interrupt::requested(interrupted) {
1033 return Ok(fail(
1034 "interrupted",
1035 Some(&spec),
1036 vec!["interrupted by Ctrl-C".to_string()],
1037 vec![],
1038 ));
1039 }
1040
1041 if spec.workload.command.is_none() {
1042 return Ok(fail(
1043 "spec",
1044 Some(&spec),
1045 vec![
1046 "[workload].command is required; it must run the workload and print one numeric \
1047 metric value"
1048 .to_string(),
1049 ],
1050 vec![],
1051 ));
1052 }
1053
1054 let package = spec.scheduler.package.clone();
1055 let profile = spec.scheduler.profile.clone();
1056
1057 if verbose {
1059 eprintln!(
1060 " validate: {} build --profile {profile} -p {package}",
1061 cargo_program().to_string_lossy()
1062 );
1063 }
1064 let _spinner = progress.map(|style| {
1065 ProgressSpinner::stdout(
1066 format!("building scheduler {package} for validation..."),
1067 style,
1068 )
1069 });
1070 let (ok, build_out) = cargo_build(repo_root, &package, &profile, interrupted);
1071 drop(_spinner);
1072 if interrupt::requested(interrupted) {
1073 return Ok(fail(
1074 "interrupted",
1075 Some(&spec),
1076 vec!["interrupted by Ctrl-C".to_string()],
1077 vec![("stderr", json!(tail(&build_out, 4000)))],
1078 ));
1079 }
1080 if !ok {
1081 return Ok(fail(
1082 "build",
1083 Some(&spec),
1084 vec!["cargo build failed".to_string()],
1085 vec![("stderr", json!(tail(&build_out, 4000)))],
1086 ));
1087 }
1088 let sched_bin = binary_path(repo_root, &package, &profile);
1089 if !sched_bin.exists() {
1090 return Ok(fail(
1091 "build",
1092 Some(&spec),
1093 vec![format!("built binary not found at {}", sched_bin.display())],
1094 vec![],
1095 ));
1096 }
1097
1098 match scx_state() {
1101 None => {
1102 return Ok(fail(
1103 "preflight",
1104 Some(&spec),
1105 vec![format!(
1106 "{SCX_STATE_PATH} not found; kernel lacks sched_ext"
1107 )],
1108 vec![],
1109 ));
1110 }
1111 Some(s) if s != "disabled" => {
1112 return Ok(fail(
1113 "preflight",
1114 Some(&spec),
1115 vec![format!("a scheduler is already attached (state={s:?})")],
1116 vec![],
1117 ));
1118 }
1119 _ => {}
1120 }
1121 if let Err(e) = sudo.authenticate() {
1122 return Ok(fail(
1123 "preflight",
1124 Some(&spec),
1125 vec![
1126 "sudo authentication failed; run as root, configure passwordless \
1127 sudo, set [system].sudo_passwd_file in the spec, or point \
1128 SCX_SUDO_PASSWORD_FILE at a file containing the sudo password"
1129 .to_string(),
1130 tail(&format!("{e}"), 500),
1131 ],
1132 vec![],
1133 ));
1134 }
1135
1136 let workdir = repo_root.join("target").join(format!("{package}_validate"));
1137 std::fs::create_dir_all(&workdir)
1138 .with_context(|| format!("create workdir {}", workdir.display()))?;
1139
1140 let mut errors: Vec<String> = Vec::new();
1141 let mut runtime_failed = false;
1142 let trace_enabled = tracing_enabled && perf_available();
1143 if verbose && tracing_enabled && !trace_enabled {
1144 eprintln!(" validate: perf not available; tracing disabled");
1145 }
1146
1147 let mut values: Vec<f64> = Vec::new();
1152 let mut last_stats = String::new();
1153 let mut trace_runs: Vec<Value> = Vec::new();
1154 for i in 0..spec.runs() {
1155 if interrupt::requested(interrupted) {
1156 break;
1157 }
1158 if verbose {
1159 eprintln!(" validate: run {}/{}", i + 1, spec.runs());
1160 }
1161 let measurement = measure_once(
1162 &spec,
1163 &sched_bin,
1164 &workdir,
1165 i,
1166 sudo,
1167 &mut errors,
1168 progress,
1169 trace_enabled,
1170 interrupted,
1171 )?;
1172 runtime_failed |= !measurement.runtime_ok;
1173 last_stats = measurement.scheduler_stats;
1174 if let Some(trace) = measurement.sched_trace {
1175 trace_runs.push(json!({
1176 "run": i,
1177 "summary": trace,
1178 }));
1179 }
1180 if let Some(v) = measurement.value {
1181 values.push(v);
1182 }
1183 if interrupt::requested(interrupted) {
1184 break;
1185 }
1186 }
1187
1188 if interrupt::requested(interrupted) {
1189 return Ok(fail(
1190 "interrupted",
1191 Some(&spec),
1192 vec!["interrupted by Ctrl-C".to_string()],
1193 vec![
1194 ("scheduler_log_tail", json!(tail(&last_stats, 2000))),
1195 ("sched_trace", json!(trace_runs)),
1196 ],
1197 ));
1198 }
1199
1200 if runtime_failed {
1201 return Ok(fail(
1202 "runtime",
1203 Some(&spec),
1204 errors,
1205 vec![
1206 ("scheduler_log_tail", json!(tail(&last_stats, 2000))),
1207 ("sched_trace", json!(trace_runs)),
1208 ],
1209 ));
1210 }
1211 if values.is_empty() && scx_state().as_deref() != Some("disabled") {
1212 return Ok(fail(
1213 "attach",
1214 Some(&spec),
1215 errors,
1216 vec![
1217 ("scheduler_log_tail", json!(tail(&last_stats, 2000))),
1218 ("sched_trace", json!(trace_runs)),
1219 ],
1220 ));
1221 }
1222 if values.is_empty() {
1223 let errs = if errors.is_empty() {
1224 vec!["no metric value extracted".to_string()]
1225 } else {
1226 errors
1227 };
1228 return Ok(fail(
1229 "metric",
1230 Some(&spec),
1231 errs,
1232 vec![
1233 ("scheduler_log_tail", json!(tail(&last_stats, 2000))),
1234 ("sched_trace", json!(trace_runs)),
1235 ],
1236 ));
1237 }
1238
1239 let med = median(&values);
1240 let std = pstdev(&values);
1241 let raw = json!({
1242 "ok": true,
1243 "stage": "complete",
1244 "package": package,
1245 "metric": {"name": METRIC_NAME, "goal": spec.goal.direction, "value": med},
1246 "runs": values,
1247 "median": med,
1248 "stddev": std,
1249 "scheduler_log_tail": tail(&last_stats, 2000),
1250 "sched_trace": trace_runs,
1251 "errors": errors,
1252 });
1253 Ok(Verdict {
1254 ok: true,
1255 stage: "complete".to_string(),
1256 metric_name: METRIC_NAME.to_string(),
1257 goal: spec.goal.direction.clone(),
1258 value: Some(med),
1259 median: Some(med),
1260 stddev: Some(std),
1261 errors,
1262 raw,
1263 })
1264}
1265
1266#[cfg(test)]
1267mod tests {
1268 use super::*;
1269
1270 #[test]
1271 fn extract_metric_parses_plain_number() {
1272 assert_eq!(extract_metric(" 42.5\n"), Some(42.5));
1273 assert_eq!(extract_metric(""), None);
1274 assert_eq!(extract_metric("value=42.5"), None);
1275 assert_eq!(extract_metric("42.5\n43.5"), None);
1276 }
1277
1278 #[test]
1279 fn trace_stats_parse_events_generically() {
1280 let mut stats = TraceStats::default();
1281 assert_eq!(
1282 trace_event("bash-10 [003] d..2. 1.000: sched_switch: prev_comm=bash prev_pid=10"),
1283 Some((1.0, "sched_switch".to_string(), Some("003".to_string())))
1284 );
1285 assert_eq!(
1286 trace_event("workload 1234 [007] 2.000000001: 100000 cache-misses:"),
1287 Some((
1288 2.000000001,
1289 "cache-misses".to_string(),
1290 Some("007".to_string())
1291 ))
1292 );
1293 update_trace_stats(
1294 &mut stats,
1295 "bash-10 [003] d..2. 1.000: sched_switch: prev_comm=bash prev_pid=10 prev_prio=120 prev_state=R ==> next_comm=schbench next_pid=11 next_prio=120",
1296 );
1297 update_trace_stats(
1298 &mut stats,
1299 "kworker-7 [001] d..2. 1.001: sched_wakeup: comm=schbench pid=11 prio=120 target_cpu=003",
1300 );
1301 update_trace_stats(
1302 &mut stats,
1303 "kworker-8 [002] d..2. 1.002: sched_wakeup_new: comm=worker pid=12 prio=120 target_cpu=004",
1304 );
1305 update_trace_stats(
1306 &mut stats,
1307 "bash-10 [003] d..2. 1.003: sched_migrate_task: comm=schbench pid=11 prio=120 orig_cpu=003 dest_cpu=005",
1308 );
1309 update_trace_stats(
1310 &mut stats,
1311 "irq/99-42 [005] d..2. 1.004: irq_handler_entry: irq=99 name=test_irq",
1312 );
1313
1314 assert_eq!(stats.total(), 5);
1315 assert_eq!(stats.events.get("sched_switch"), Some(&1));
1316 assert_eq!(stats.events.get("sched_wakeup"), Some(&1));
1317 assert_eq!(stats.events.get("sched_wakeup_new"), Some(&1));
1318 assert_eq!(stats.events.get("sched_migrate_task"), Some(&1));
1319 assert_eq!(stats.events.get("irq_handler_entry"), Some(&1));
1320 assert_eq!(stats.per_cpu_events.get("003"), Some(&2));
1321 assert_eq!(stats.start_ts, Some(1.0));
1322 assert_eq!(stats.end_ts, Some(1.004));
1323
1324 let summary = trace_stats_json(
1325 &stats,
1326 Path::new("/tmp/perf.data"),
1327 Path::new("/tmp/perf.script"),
1328 &[
1329 "sched:sched_switch".to_string(),
1330 "irq:irq_handler_entry".to_string(),
1331 ],
1332 );
1333 assert_eq!(summary["trace_window"]["start_ts"], json!(1.0));
1334 assert_eq!(summary["trace_window"]["end_ts"], json!(1.004));
1335 assert_eq!(summary["trace_window"]["duration_sec"], json!(0.004));
1336 assert_eq!(summary["event_count_total"], json!(5));
1337 assert_eq!(summary["event_rate_total_per_sec"], json!(1250.0));
1338 assert_eq!(
1339 summary["event_counts"][0],
1340 json!({"event": "irq_handler_entry", "count": 1})
1341 );
1342 assert_eq!(
1343 summary["event_rates_per_sec"][0],
1344 json!({"event": "irq_handler_entry", "per_sec": 250.0})
1345 );
1346 assert!(!summary.as_object().unwrap().contains_key("sched_switch"));
1347 assert!(!summary.as_object().unwrap().contains_key("top_switch_cpu"));
1348 assert!(!summary
1349 .as_object()
1350 .unwrap()
1351 .contains_key("top_cpu_event_rates"));
1352 assert_eq!(summary["cpu_event_rate_summary"]["cpus_observed"], json!(4));
1353 assert_eq!(
1354 summary["cpu_event_rate_summary"]["median_events_per_sec"],
1355 json!(250.0)
1356 );
1357 assert_eq!(
1358 summary["cpu_event_rate_summary"]["max_events_per_sec"],
1359 json!(500.0)
1360 );
1361 assert_eq!(
1362 summary["cpu_event_rate_summary"]["max_to_median_ratio"],
1363 json!(2.0)
1364 );
1365 assert_eq!(
1366 summary["cpu_event_rate_summary"]["top_cpus_by_total_events"][0]["cpu"],
1367 json!("003")
1368 );
1369 assert_eq!(
1370 summary["cpu_event_rate_summary"]["top_cpus_by_total_events"][0]["events"],
1371 json!(2)
1372 );
1373 assert_eq!(
1374 summary["cpu_event_rate_summary"]["top_cpus_by_total_events"][0]["events_per_sec"],
1375 json!(500.0)
1376 );
1377 }
1378
1379 #[test]
1380 fn scx_is_enabled_only_accepts_enabled_state() {
1381 assert!(scx_is_enabled(Some("enabled")));
1382 assert!(!scx_is_enabled(Some("disabled")));
1383 assert!(!scx_is_enabled(Some("enabling")));
1384 assert!(!scx_is_enabled(None));
1385 }
1386
1387 #[test]
1388 fn median_odd_even() {
1389 assert_eq!(median(&[3.0, 1.0, 2.0]), 2.0);
1390 assert_eq!(median(&[1.0, 2.0, 3.0, 4.0]), 2.5);
1391 }
1392
1393 #[test]
1394 fn pstdev_matches_population() {
1395 let s = pstdev(&[1.0, 2.0, 3.0, 4.0, 5.0]);
1397 assert!((s - 1.414_213_562).abs() < 1e-6);
1398 assert_eq!(pstdev(&[42.0]), 0.0);
1399 }
1400
1401 #[test]
1402 fn binary_path_profiles() {
1403 let r = Path::new("/repo");
1404 assert_eq!(
1405 binary_path(r, "scx_forge", "release"),
1406 Path::new("/repo/target/release/scx_forge")
1407 );
1408 assert_eq!(
1409 binary_path(r, "scx_forge", "dev"),
1410 Path::new("/repo/target/debug/scx_forge")
1411 );
1412 assert_eq!(
1413 binary_path(r, "scx_forge", "bench"),
1414 Path::new("/repo/target/bench/scx_forge")
1415 );
1416 }
1417}