use anyhow::{Context, Result};
use crate::assert::AssertResult;
use crate::verifier::parse_sched_output;
use crate::vmm;
pub(crate) fn print_assert_result(r: &AssertResult) {
vmm::guest_comms::send_test_result(r);
}
pub(crate) fn parse_assert_result_from_drain(
drain: Option<&vmm::host_comms::BulkDrainResult>,
) -> Result<AssertResult> {
let drain = drain.ok_or_else(|| anyhow::anyhow!("no guest messages"))?;
let entry = drain
.entries
.iter()
.rev()
.find(|e| e.msg_type == vmm::wire::MSG_TYPE_TEST_RESULT && e.crc_ok)
.ok_or_else(|| anyhow::anyhow!("no test result in guest messages"))?;
let result = postcard::from_bytes::<AssertResult>(&entry.payload)
.context("decode AssertResult postcard payload from drain")?;
Ok(result)
}
pub(crate) fn sched_log_fingerprint(output: &str) -> Option<&str> {
let log = parse_sched_output(output)?;
log.lines().rev().find(|l| !l.trim().is_empty())
}
pub(crate) fn extract_sched_ext_dump(output: &str) -> Option<String> {
let lines: Vec<&str> = output
.lines()
.filter(|l| l.contains(super::probe::SCHED_EXT_DUMP_MARKER))
.collect();
if lines.is_empty() {
return None;
}
Some(lines.join("\n"))
}
pub(crate) fn extract_bug_summary(sched_log: &str, dump: &str) -> Option<String> {
let dump_clean = strip_ansi_csi(dump);
let lines: Vec<&str> = dump_clean.lines().collect();
for (i, line) in lines.iter().enumerate() {
if line.contains("triggered exit kind")
&& let Some(next) = find_same_cpu_body_after(&lines, i, parse_trace_cpu(line))
{
let body = next
.find("sched_ext_dump:")
.map(|p| &next[p + "sched_ext_dump:".len()..])
.unwrap_or(next)
.trim();
if !body.is_empty() {
return Some(body.to_string());
}
}
}
let sched_clean = strip_ansi_csi(sched_log);
for line in sched_clean.lines() {
if line.contains("scx_bpf_error") {
let trimmed = line.trim();
if !trimmed.is_empty() {
return Some(trimmed.to_string());
}
}
}
None
}
fn find_same_cpu_body_after<'a>(
lines: &[&'a str],
after: usize,
anchor_cpu: Option<&str>,
) -> Option<&'a str> {
lines
.iter()
.skip(after + 1)
.filter(|n| anchor_cpu.is_none() || parse_trace_cpu(n) == anchor_cpu)
.take_while(|n| !n.contains("triggered exit kind"))
.next()
.copied()
}
fn parse_trace_cpu(line: &str) -> Option<&str> {
let event_pos = line.find(": sched_ext_dump:")?;
let prefix = &line[..event_pos];
let bracket_open = prefix.rfind('[')?;
let bracket_close = bracket_open + 1 + prefix[bracket_open + 1..].find(']')?;
let inner = &prefix[bracket_open + 1..bracket_close];
if inner.is_empty() || inner.len() > 5 || !inner.bytes().all(|b| b.is_ascii_digit()) {
return None;
}
Some(&prefix[bracket_open..=bracket_close])
}
fn strip_ansi_csi(s: &str) -> String {
if !s.contains('\x1b') {
return s.to_string();
}
let bytes = s.as_bytes();
let mut out = Vec::with_capacity(bytes.len());
let mut i = 0;
while i < bytes.len() {
if bytes[i] == 0x1b && i + 1 < bytes.len() && bytes[i + 1] == b'[' {
let mut j = i + 2;
while j < bytes.len() && !(0x40..=0x7e).contains(&bytes[j]) {
j += 1;
}
i = j.saturating_add(1);
} else {
out.push(bytes[i]);
i += 1;
}
}
String::from_utf8(out).expect("strip_ansi_csi preserves UTF-8")
}
pub(crate) fn extract_exit_from_dump_trace(console: &str) -> Option<String> {
let lines: Vec<&str> = console.lines().collect();
for (i, line) in lines.iter().enumerate() {
if line.contains("sched_ext_dump:")
&& line.contains("triggered exit kind")
&& let Some(next) = find_same_cpu_body_after(&lines, i, parse_trace_cpu(line))
&& let Some(pos) = next.find("sched_ext_dump:")
{
let body = next[pos + "sched_ext_dump:".len()..].trim();
if !body.is_empty() {
return Some(body.to_string());
}
}
}
None
}
pub(crate) fn extract_kernel_version(console: &str) -> Option<String> {
for line in console.lines() {
if let Some(rest) = line.split("Linux version ").nth(1) {
return Some(rest.split_whitespace().next().unwrap_or("").to_string());
}
}
None
}
pub(crate) fn extract_panic_message(output: &str) -> Option<&str> {
output
.lines()
.map(|l| l.trim())
.find_map(|l| l.strip_prefix("PANIC:").map(str::trim_start))
}
pub(crate) const STAGE_INIT_NOT_STARTED: &str =
"init script never started (kernel or mount failure)";
pub(crate) const STAGE_INIT_STARTED_NO_PAYLOAD: &str =
"init started but payload never ran (cgroup/scheduler setup failed)";
pub(crate) const STAGE_PAYLOAD_STARTED_NO_RESULT: &str =
"payload started but produced no test result";
pub(crate) fn classify_init_stage(
drain: Option<&vmm::host_comms::BulkDrainResult>,
) -> &'static str {
use crate::vmm::wire::{LifecyclePhase, MSG_TYPE_LIFECYCLE};
let Some(drain) = drain else {
return STAGE_INIT_NOT_STARTED;
};
let mut latest: Option<LifecyclePhase> = None;
for e in &drain.entries {
if e.msg_type != MSG_TYPE_LIFECYCLE || !e.crc_ok || e.payload.is_empty() {
continue;
}
if let Some(phase) = LifecyclePhase::from_wire(e.payload[0]) {
latest = Some(phase);
}
}
if primary_reached_workload(Some(drain)) {
return STAGE_PAYLOAD_STARTED_NO_RESULT;
}
match latest {
Some(_) => STAGE_INIT_STARTED_NO_PAYLOAD,
None => STAGE_INIT_NOT_STARTED,
}
}
pub(crate) fn primary_reached_workload(drain: Option<&vmm::host_comms::BulkDrainResult>) -> bool {
use crate::vmm::wire::{LifecyclePhase, MSG_TYPE_LIFECYCLE};
let Some(drain) = drain else {
return false;
};
drain.entries.iter().any(|e| {
e.msg_type == MSG_TYPE_LIFECYCLE
&& e.crc_ok
&& !e.payload.is_empty()
&& LifecyclePhase::from_wire(e.payload[0]) == Some(LifecyclePhase::PayloadStarting)
})
}
pub(crate) fn format_console_diagnostics(
console: &str,
exit_code: i32,
init_stage: &str,
) -> String {
const TAIL_LINES: usize = 20;
let trimmed = console.trim();
if trimmed.is_empty() && exit_code == 0 {
return String::new();
}
let mut parts = Vec::with_capacity(3);
parts.push(format!("stage: {init_stage}"));
let exit_label = if exit_code < 0 {
crate::errno_name(-exit_code)
.map(|name| format!("exit_code={exit_code} ({name})"))
.unwrap_or_else(|| format!("exit_code={exit_code}"))
} else {
format!("exit_code={exit_code}")
};
parts.push(exit_label);
if !trimmed.is_empty() {
let lines: Vec<&str> = trimmed.lines().collect();
let has_crash = lines.iter().any(|l| l.contains("PANIC:"));
let limit = if has_crash { lines.len() } else { TAIL_LINES };
let start = lines.len().saturating_sub(limit);
let tail = &lines[start..];
let window_dropped = start > 0;
let last_line_incomplete = !console.ends_with('\n');
let header_suffix = match (window_dropped, last_line_incomplete) {
(true, true) => ", window-truncated, last line incomplete",
(true, false) => ", window-truncated",
(false, true) => ", last line incomplete",
(false, false) => "",
};
let body_suffix = if last_line_incomplete {
" [partial]"
} else {
""
};
parts.push(format!(
"console ({} lines{}):\n{}{}",
tail.len(),
header_suffix,
tail.join("\n"),
body_suffix,
));
}
format!("\n\n--- diagnostics ---\n{}", parts.join("\n"))
}
pub(crate) fn format_periodic_samples_section(result: &vmm::VmResult) -> String {
if result.periodic_target == 0 {
return String::new();
}
let fired = result.periodic_fired;
let target = result.periodic_target;
let mut lines = vec![format!(
"fired {fired}/{target} periodic snapshots ({pct:.0}% coverage)",
pct = if target == 0 {
0.0
} else {
100.0 * fired as f64 / target as f64
}
)];
if fired < target {
lines.push(format!(
"missing {miss} sample(s) — see freeze-coord traces \
for skip / timeout reasons",
miss = target.saturating_sub(fired),
));
}
format!("\n\n--- periodic samples ---\n{}", lines.join("\n"))
}
pub(crate) fn format_temporal_assertions_section(result: &crate::assert::AssertResult) -> String {
let temporal: Vec<&crate::assert::AssertDetail> = result
.failure_details()
.chain(result.inconclusive_details())
.filter(|d| d.kind == crate::assert::DetailKind::Temporal)
.collect();
if temporal.is_empty() {
return String::new();
}
let mut lines: Vec<String> = Vec::with_capacity(temporal.len() + 1);
lines.push(format!(
"{n} temporal assertion entry(ies):",
n = temporal.len()
));
for detail in temporal {
lines.push(format!(" {}", detail.message));
}
format!("\n\n--- temporal assertions ---\n{}", lines.join("\n"))
}
#[cfg(test)]
mod tests {
use super::super::test_helpers::{assert_result_tlv_entry, build_assert_result};
use super::*;
use crate::assert::{AssertDetail, DetailKind};
use crate::verifier::{SCHED_OUTPUT_END, SCHED_OUTPUT_START};
use crate::vmm::host_comms::BulkDrainResult;
use crate::vmm::wire::{MSG_TYPE_TEST_RESULT, ShmEntry};
fn drain_with_assert(r: &AssertResult) -> BulkDrainResult {
BulkDrainResult {
entries: vec![assert_result_tlv_entry(r)],
}
}
#[test]
fn parse_assert_result_from_drain_round_trips() {
let original = build_assert_result(true, vec![]);
let drain = drain_with_assert(&original);
let r = parse_assert_result_from_drain(Some(&drain)).unwrap();
assert!(r.is_pass());
}
#[test]
fn parse_assert_result_from_drain_failed_preserves_details() {
let original = build_assert_result(
false,
vec![AssertDetail::new(DetailKind::Stuck, "stuck 3000ms")],
);
let drain = drain_with_assert(&original);
let r = parse_assert_result_from_drain(Some(&drain)).unwrap();
assert!(r.is_fail());
assert_eq!(
r.failure_details()
.map(|d| d.message.as_str())
.collect::<Vec<_>>(),
vec!["stuck 3000ms"]
);
}
#[test]
fn parse_assert_result_from_drain_none_returns_error() {
assert!(parse_assert_result_from_drain(None).is_err());
}
#[test]
fn parse_assert_result_from_drain_empty_returns_error() {
let drain = BulkDrainResult { entries: vec![] };
assert!(parse_assert_result_from_drain(Some(&drain)).is_err());
}
#[test]
fn parse_assert_result_from_drain_skips_crc_bad_entries() {
let drain = BulkDrainResult {
entries: vec![ShmEntry {
msg_type: MSG_TYPE_TEST_RESULT,
payload: vec![0xff; 4],
crc_ok: false,
}],
};
assert!(parse_assert_result_from_drain(Some(&drain)).is_err());
}
#[test]
fn parse_assert_result_from_drain_picks_latest() {
let early = build_assert_result(false, vec![AssertDetail::new(DetailKind::Other, "early")]);
let late = build_assert_result(true, vec![]);
let drain = BulkDrainResult {
entries: vec![
assert_result_tlv_entry(&early),
assert_result_tlv_entry(&late),
],
};
let r = parse_assert_result_from_drain(Some(&drain)).unwrap();
assert!(r.is_pass(), "latest entry must win");
}
#[test]
fn parse_assert_result_from_drain_rejects_garbage_payload() {
let payload = vec![0xab; 8];
let drain = BulkDrainResult {
entries: vec![ShmEntry {
msg_type: MSG_TYPE_TEST_RESULT,
payload,
crc_ok: true,
}],
};
assert!(parse_assert_result_from_drain(Some(&drain)).is_err());
}
#[test]
fn sched_log_fingerprint_last_line() {
let output = format!(
"{SCHED_OUTPUT_START}\nstarting scheduler\nError: apply_cell_config BPF program returned error -2\n{SCHED_OUTPUT_END}",
);
assert_eq!(
sched_log_fingerprint(&output),
Some("Error: apply_cell_config BPF program returned error -2"),
);
}
#[test]
fn sched_log_fingerprint_skips_trailing_blanks() {
let output = format!("{SCHED_OUTPUT_START}\nfatal error here\n\n\n{SCHED_OUTPUT_END}",);
assert_eq!(sched_log_fingerprint(&output), Some("fatal error here"));
}
#[test]
fn sched_log_fingerprint_none_without_markers() {
assert!(sched_log_fingerprint("no markers").is_none());
}
#[test]
fn sched_log_fingerprint_none_empty_content() {
let output = format!("{SCHED_OUTPUT_START}\n\n{SCHED_OUTPUT_END}");
assert!(sched_log_fingerprint(&output).is_none());
}
#[test]
fn extract_sched_ext_dump_present() {
let output = "noise\n ktstr-0 [001] 0.500: sched_ext_dump: Debug dump\n ktstr-0 [001] 0.501: sched_ext_dump: scheduler state\nmore";
let parsed = extract_sched_ext_dump(output);
assert!(parsed.is_some());
let dump = parsed.unwrap();
assert!(dump.contains("sched_ext_dump: Debug dump"));
assert!(dump.contains("sched_ext_dump: scheduler state"));
}
#[test]
fn extract_sched_ext_dump_absent() {
assert!(extract_sched_ext_dump("no dump lines here").is_none());
}
#[test]
fn extract_sched_ext_dump_empty_output() {
assert!(extract_sched_ext_dump("").is_none());
}
#[test]
fn extract_sched_ext_dump_requires_colon_after_marker() {
let output = "[ 0.1] BUG in sched_ext_dump_disable callback\n\
systemd[1]: Started sched_ext_dump.service.\n";
assert!(
extract_sched_ext_dump(output).is_none(),
"non-marker lines must not surface as dump lines"
);
}
#[test]
fn extract_sched_ext_dump_recovers_ktstr_ops_dump_layers() {
let trace_pipe = "\
scx_-1234 [002] 100.000000: sched_ext_dump: Debug dump triggered by error\n\
scx_-1234 [002] 100.000001: sched_ext_dump: ktstr scheduler state:\n\
scx_-1234 [002] 100.000002: sched_ext_dump: stall=1 crash=0 degrade_rt=0\n\
scx_-1234 [002] 100.000003: sched_ext_dump: rodata: degrade=0 slow=0 scattershot=0 verify_loop=0 fail_verify=0\n\
scx_-1234 [002] 100.000004: sched_ext_dump: ktstr_alloc_count=42 degrade_cnt=0 slow_cnt=0\n\
scx_-1234 [002] 100.000005: sched_ext_dump: CPU states\n\
scx_-1234 [002] 100.000006: sched_ext_dump: ----------\n\
scx_-1234 [002] 100.000007: sched_ext_dump: ktstr cpu 1: no per-cpu state\n\
scx_-1234 [002] 100.000008: sched_ext_dump: ktstr cpu 3: no per-cpu state\n\
scx_-1234 [002] 100.000009: sched_ext_dump: ktstr task: magic=0xdeadbeefcafebabe counter=42\n\
unrelated noise that must NOT match\n";
let parsed = extract_sched_ext_dump(trace_pipe)
.expect("parser must surface every sched_ext_dump line");
assert!(
parsed.contains("ktstr scheduler state:"),
"ops.dump header missing; parser dropped the `ktstr scheduler state:` \
line emitted by scx-ktstr's ktstr_dump callback. parsed: {parsed}"
);
assert!(
parsed.contains("stall=1 crash=0 degrade_rt=0"),
"ops.dump body missing; parser dropped the runtime-flag line. \
parsed: {parsed}"
);
assert!(
parsed.contains("ktstr_alloc_count=42"),
"ops.dump body missing; parser dropped the alloc-count line. \
parsed: {parsed}"
);
assert!(
parsed.contains("ktstr cpu 1: no per-cpu state"),
"ops.dump_cpu output missing; parser dropped the CPU 1 \
marker emitted by ktstr_dump_cpu for non-idle CPUs. \
parsed: {parsed}"
);
assert!(
parsed.contains("ktstr cpu 3: no per-cpu state"),
"ops.dump_cpu output missing; parser dropped the CPU 3 \
marker. parsed: {parsed}"
);
assert!(
parsed.contains("ktstr task: magic=0xdeadbeefcafebabe counter=42"),
"ops.dump_task output missing; parser dropped the per-task \
magic/counter line emitted by ktstr_dump_task. parsed: \
{parsed}"
);
assert!(
!parsed.contains("unrelated noise"),
"parser leaked a non-sched_ext_dump line: {parsed}"
);
}
#[test]
fn extract_bug_summary_from_canonical_kernel_dump() {
let dump = " ktstr-1234 [001] 0.500: sched_ext_dump: scheduler[5678] triggered exit kind 5:\n \
ktstr-1234 [001] 0.501: sched_ext_dump: apply_cell_config returned -EINVAL (apply_cell_config)\n";
let summary = extract_bug_summary("", dump).expect("dump with anchor must yield summary");
assert!(
summary.contains("apply_cell_config returned -EINVAL"),
"summary must carry the BPF error text: {summary}",
);
assert!(
!summary.contains("sched_ext_dump:"),
"trace_pipe prefix must be stripped from the returned body: {summary}",
);
}
#[test]
fn extract_bug_summary_first_event_wins() {
let dump = " ktstr-1 [001] 0.500: sched_ext_dump: scheduler[1] triggered exit kind 5:\n \
ktstr-1 [001] 0.501: sched_ext_dump: first_error returned -EINVAL\n \
ktstr-1 [001] 1.000: sched_ext_dump: scheduler[2] triggered exit kind 5:\n \
ktstr-1 [001] 1.001: sched_ext_dump: second_error returned -EBUSY\n";
let summary = extract_bug_summary("", dump).expect("multi-event dump must yield summary");
assert!(
summary.contains("first_error"),
"first event must win: {summary}",
);
assert!(
!summary.contains("second_error"),
"second event must NOT appear in the BUG SUMMARY: {summary}",
);
}
#[test]
fn extract_bug_summary_fallback_to_sched_log_scx_bpf_error() {
let sched_log = "starting up\n\
scx_bpf_error: apply_cell_config: cell_id=3 returned -EINVAL\n\
exiting\n";
let summary = extract_bug_summary(sched_log, "")
.expect("sched_log with scx_bpf_error must yield summary");
assert!(
summary.contains("scx_bpf_error"),
"fallback must surface the scx_bpf_error line: {summary}",
);
assert!(
summary.contains("apply_cell_config"),
"fallback must surface the full error line: {summary}",
);
}
#[test]
fn extract_bug_summary_none_when_no_error_present() {
assert!(extract_bug_summary("clean scheduler log\n", "boot complete\n").is_none());
assert!(extract_bug_summary("", "").is_none());
}
#[test]
fn extract_bug_summary_strips_ansi_csi() {
let sched_log = "\x1b[31mscx_bpf_error\x1b[0m: red-wrapped error text\n";
let summary = extract_bug_summary(sched_log, "")
.expect("ANSI-wrapped error line must still match scx_bpf_error");
assert!(
!summary.contains('\x1b'),
"ANSI escapes must be stripped from the returned summary: {summary:?}",
);
assert!(
summary.contains("scx_bpf_error"),
"the underlying text must still be found: {summary}",
);
}
#[test]
fn extract_bug_summary_strips_ansi_from_dump_anchor() {
let dump = " ktstr-1234 [001] 0.500: sched_ext_dump: \x1b[1mscheduler[5678] triggered exit kind 5:\x1b[0m\n \
ktstr-1234 [001] 0.501: sched_ext_dump: \x1b[31mapply_cell_config returned -EINVAL\x1b[0m (apply_cell_config)\n";
let summary =
extract_bug_summary("", dump).expect("ANSI-wrapped dump anchor must still match");
assert!(
!summary.contains('\x1b'),
"ANSI escapes must be stripped from the dump-path returned summary: {summary:?}",
);
assert!(
summary.contains("apply_cell_config returned -EINVAL"),
"the underlying body text must still be extracted: {summary}",
);
}
#[test]
fn extract_bug_summary_real_shaped_scheduler_crash_trace() {
let dump = "\
scx_layered-3417 [001] 125.812043: sched_ext_dump: scx_layered[3417] triggered exit kind 1025:\n\
ksoftirqd/2-21 [002] 125.812055: sched_switch: prev_comm=ksoftirqd/2 prev_pid=21\n\
kworker/3:1-67 [003] 125.812061: sched_switch: prev_comm=kworker/3:1 prev_pid=67\n\
scx_layered-3417 [001] 125.812078: sched_ext_dump: scx_bpf_error (layer_cpumask_intersect: layer=2 cpu=15 out of range (online_cpus=12))\n\
scx_layered-3417 [001] 125.812091: sched_ext_dump:\n\
scx_layered-3417 [001] 125.812094: sched_ext_dump: Backtrace:\n\
scx_layered-3417 [001] 125.812097: sched_ext_dump: layer_cpumask_intersect+0x5c/0x180 [scx_layered]\n\
scx_layered-3417 [001] 125.812099: sched_ext_dump: pick_idle_cpu+0x1a4/0x420 [scx_layered]\n\
scx_layered-3417 [001] 125.812102: sched_ext_dump: bpf_scx_ops_select_cpu+0x90/0xc0\n\
kworker/0:2-89 [000] 125.812110: sched_wakeup: comm=migration/0 pid=14 prio=120\n\
scx_layered-3417 [001] 125.812115: sched_ext_dump: Stats:\n\
scx_layered-3417 [001] 125.812118: sched_ext_dump: tasks_throttled=0 tasks_unthrottled=0\n\
systemd-1 [000] 125.815201: sched_process_exit: comm=scx_layered pid=3417 prio=120\n\
";
let summary =
extract_bug_summary("", dump).expect("real-shaped multi-CPU dump must yield a summary");
assert_eq!(
summary,
"scx_bpf_error (layer_cpumask_intersect: layer=2 cpu=15 out of range (online_cpus=12))",
"summary must be EXACTLY the first same-CPU body line after the anchor, \
with the trace_pipe `<task>-<pid> [<cpu>] <ts>: sched_ext_dump:` prefix \
stripped and the body trimmed; got: {summary:?}",
);
}
#[test]
fn extract_bug_summary_none_when_body_is_whitespace() {
let dump = " ktstr-1 [001] 0.5: sched_ext_dump: foo triggered exit kind 5:\n \
ktstr-1 [001] 0.5: sched_ext_dump: \n";
assert!(extract_bug_summary("", dump).is_none());
}
#[test]
fn extract_bug_summary_none_on_closer_only_dump() {
let dump = " ktstr-1 [001] 0.5: sched_ext_dump: sched_ext: BPF scheduler \"scx_mitosis\" disabled (Error)\n";
assert!(extract_bug_summary("", dump).is_none());
}
#[test]
fn extract_bug_summary_anchor_on_last_line_falls_through() {
let dump = " ktstr-1 [001] 0.5: sched_ext_dump: scheduler[1] triggered exit kind 5:\n";
assert!(
extract_bug_summary("", dump).is_none(),
"anchor on last line with empty sched_log must yield None",
);
let summary = extract_bug_summary("scx_bpf_error: late fallback\n", dump)
.expect("anchor on last line must fall through to sched_log fallback");
assert_eq!(
summary, "scx_bpf_error: late fallback",
"fallback must return the trimmed scx_bpf_error line verbatim; a \
regression that surfaced the whole sched_log buffer, an empty \
string, or a sentinel placeholder would trip here but slip past \
a `contains` check: {summary}",
);
}
#[test]
fn extract_bug_summary_anchor_takes_precedence_over_sched_log_fallback() {
let dump = " ktstr-1 [001] 0.5: sched_ext_dump: scheduler[1] triggered exit kind 5:\n \
ktstr-1 [001] 0.5: sched_ext_dump: anchor body wins\n";
let sched_log = "scx_bpf_error: fallback should NOT fire when dump has anchor\n";
let summary = extract_bug_summary(sched_log, dump)
.expect("anchor + sched_log → Some via anchor scan");
assert_eq!(
summary, "anchor body wins",
"dump-scan anchor must early-return before the sched_log \
fallback loop runs; a regression that ran fallback first, or \
concatenated the two, would surface the scx_bpf_error line \
instead: {summary}",
);
}
#[test]
fn extract_bug_summary_skips_interleaved_other_cpu_event() {
let dump = "\
ktstr-1234 [001] 0.500: sched_ext_dump: scheduler[1] triggered exit kind 5:
ktstr-5678 [002] 0.500: sched_ext_dump: scheduler[2] unrelated event from cpu 2
ktstr-1234 [001] 0.501: sched_ext_dump: apply_cell_config returned -EINVAL
";
let summary = extract_bug_summary("", dump)
.expect("interleaved cross-CPU event must not block body extraction");
assert!(
summary.contains("apply_cell_config returned -EINVAL"),
"must return the same-CPU body, skipping the [002] interleaved event: {summary}",
);
assert!(
!summary.contains("unrelated event"),
"must NOT surface the cross-CPU interleaved line as the body: {summary}",
);
}
#[test]
fn extract_bug_summary_falls_through_when_no_same_cpu_body() {
let dump = "\
ktstr-1 [001] 0.500: sched_ext_dump: scheduler[1] triggered exit kind 5:
ktstr-2 [002] 0.500: sched_ext_dump: scheduler[2] unrelated from cpu 2
ktstr-3 [003] 0.501: sched_ext_dump: scheduler[3] unrelated from cpu 3
";
assert!(
extract_bug_summary("", dump).is_none(),
"no same-CPU body and empty sched_log must yield None — \
a regression that relaxed the same-CPU restriction back \
to strict adjacency would surface the [002] line instead",
);
let summary = extract_bug_summary("scx_bpf_error: late fallback\n", dump)
.expect("with sched_log fallback, the scx_bpf_error line must surface");
assert!(
summary.contains("scx_bpf_error"),
"fallback path: {summary}",
);
}
#[test]
fn extract_bug_summary_stops_at_next_anchor_on_same_cpu() {
let dump = "\
ktstr-1 [001] 0.500: sched_ext_dump: scheduler[1] triggered exit kind 5:
ktstr-1 [001] 0.510: sched_ext_dump: scheduler[2] triggered exit kind 7:
ktstr-1 [001] 0.511: sched_ext_dump: second_error returned -EBUSY
";
let summary = extract_bug_summary("", dump)
.expect("outer loop must reach the second anchor and extract its body");
assert_eq!(
summary, "second_error returned -EBUSY",
"first anchor must NOT adopt the second anchor's body; the \
outer loop advances to the second anchor: {summary}",
);
}
#[test]
fn extract_bug_summary_no_cpu_prefix_falls_back_to_adjacency() {
let dump = "scheduler[1] triggered exit kind 5:\n body_without_trace_framing\n";
let summary = extract_bug_summary("", dump)
.expect("no-cpu-prefix anchor must still find an adjacent body");
assert_eq!(
summary, "body_without_trace_framing",
"without trace_pipe framing, the first subsequent line wins: {summary}",
);
}
#[test]
fn extract_bug_summary_cpu_parse_uses_last_bracket() {
let dump = "\
[5]-1234 [001] 0.500: sched_ext_dump: scheduler[1] triggered exit kind 5:
ktstr-5678 [002] 0.500: sched_ext_dump: scheduler[2] unrelated event from cpu 2
[7]-1234 [001] 0.501: sched_ext_dump: apply_cell_config returned -EINVAL
";
let summary = extract_bug_summary("", dump).expect(
"rfind on the prefix must pick the CPU bracket [001], not the leading \
task-name token ([5] or [7]) — otherwise anchor and body lock onto \
different fake CPUs and the body is rejected by the same-CPU filter",
);
assert_eq!(
summary, "apply_cell_config returned -EINVAL",
"must lock onto CPU [001] for both anchor and body, skipping the [002] \
interleaved event, despite the divergent leading bracket tokens [5]/[7]: \
{summary}",
);
}
#[test]
fn extract_exit_from_dump_trace_canonical() {
let console = "\
ktstr-1 [001] 0.500: sched_ext_dump: scheduler[1] triggered exit kind 5:
ktstr-1 [001] 0.501: sched_ext_dump: apply_cell_config returned -EINVAL
";
let reason =
extract_exit_from_dump_trace(console).expect("anchor + same-cpu body must yield Some");
assert_eq!(
reason, "apply_cell_config returned -EINVAL",
"must surface the body after `sched_ext_dump:`, trimmed: {reason}",
);
}
#[test]
fn extract_exit_from_dump_trace_skips_interleaved_other_cpu_event() {
let console = "\
ktstr-1234 [001] 0.500: sched_ext_dump: scheduler[1] triggered exit kind 5:
ktstr-5678 [002] 0.500: sched_ext_dump: scheduler[2] unrelated event from cpu 2
ktstr-1234 [001] 0.501: sched_ext_dump: apply_cell_config returned -EINVAL
";
let reason = extract_exit_from_dump_trace(console)
.expect("interleaved cross-CPU event must not block extraction");
assert_eq!(
reason, "apply_cell_config returned -EINVAL",
"must return the same-CPU body, skipping the [002] interleaved event: {reason}",
);
}
#[test]
fn extract_exit_from_dump_trace_none_without_anchor() {
let console = "\
ktstr-1 [001] 0.500: sched_ext_dump: routine status line
ktstr-1 [001] 0.501: sched_ext_dump: another routine line
";
assert!(extract_exit_from_dump_trace(console).is_none());
}
#[test]
fn extract_exit_from_dump_trace_stops_at_next_anchor_on_same_cpu() {
let console = "\
ktstr-1 [001] 0.500: sched_ext_dump: scheduler[1] triggered exit kind 5:
ktstr-1 [001] 0.510: sched_ext_dump: scheduler[2] triggered exit kind 7:
ktstr-1 [001] 0.511: sched_ext_dump: second_error returned -EBUSY
";
let reason = extract_exit_from_dump_trace(console)
.expect("outer loop must reach the second anchor and extract its body");
assert_eq!(
reason, "second_error returned -EBUSY",
"first anchor must NOT adopt the second anchor's body: {reason}",
);
}
#[test]
fn extract_exit_from_dump_trace_cpu_parse_uses_last_bracket() {
let console = "\
[5]-1234 [001] 0.500: sched_ext_dump: scheduler[1] triggered exit kind 5:
ktstr-5678 [002] 0.500: sched_ext_dump: scheduler[2] unrelated event from cpu 2
[7]-1234 [001] 0.501: sched_ext_dump: apply_cell_config returned -EINVAL
";
let reason = extract_exit_from_dump_trace(console)
.expect("rfind on the prefix must pick CPU [001], not the leading task-name token");
assert_eq!(
reason, "apply_cell_config returned -EINVAL",
"must lock onto CPU [001] for both anchor and body despite the divergent \
leading bracket tokens [5]/[7]: {reason}",
);
}
#[test]
fn extract_kernel_version_from_boot() {
let console = "[ 0.000000] Linux version 6.14.0-rc3+ (user@host) (gcc) #1 SMP\n\
[ 0.001000] Command line: console=ttyS0";
assert_eq!(
extract_kernel_version(console),
Some("6.14.0-rc3+".to_string()),
);
}
#[test]
fn extract_kernel_version_none() {
assert_eq!(extract_kernel_version("no kernel here"), None);
}
#[test]
fn extract_kernel_version_bare() {
let console = "Linux version 6.12.0";
assert_eq!(extract_kernel_version(console), Some("6.12.0".to_string()),);
}
#[test]
fn format_console_diagnostics_empty_ok() {
assert_eq!(format_console_diagnostics("", 0, "test stage"), "");
}
#[test]
fn format_console_diagnostics_empty_nonzero_exit() {
let s = format_console_diagnostics("", 1, "test stage");
assert!(s.contains("exit_code=1"));
assert!(s.contains("--- diagnostics ---"));
assert!(s.contains("stage: test stage"));
assert!(!s.contains("console ("));
}
#[test]
fn format_console_diagnostics_with_console() {
let console = "line1\nline2\nKernel panic - not syncing\n";
let s = format_console_diagnostics(console, -1, "payload started");
assert!(s.contains("exit_code=-1"));
assert!(s.contains("console (3 lines)"));
assert!(s.contains("Kernel panic"));
assert!(s.contains("stage: payload started"));
assert!(!s.contains("window-truncated"));
assert!(!s.contains("last line incomplete"));
assert!(!s.contains("[partial]"));
}
#[test]
fn format_console_diagnostics_truncates_long() {
let lines: Vec<String> = (0..50).map(|i| format!("boot line {i}")).collect();
let console = format!("{}\n", lines.join("\n"));
let s = format_console_diagnostics(&console, 0, "test");
assert!(s.contains("console (20 lines, window-truncated)"));
assert!(s.contains("boot line 49"));
assert!(!s.contains("boot line 29"));
assert!(!s.contains("last line incomplete"));
assert!(!s.contains("[partial]"));
}
#[test]
fn format_console_diagnostics_short_console() {
let console = "Linux version 6.14.0\nbooted ok\n";
let s = format_console_diagnostics(console, 0, "test");
assert!(s.contains("console (2 lines)"));
assert!(s.contains("Linux version 6.14.0"));
assert!(s.contains("booted ok"));
assert!(!s.contains("window-truncated"));
assert!(!s.contains("last line incomplete"));
assert!(!s.contains("[partial]"));
}
#[test]
fn format_console_diagnostics_no_truncation_with_trailing_newline() {
let console = "line1\nline2\nline3\n";
let s = format_console_diagnostics(console, 0, "test");
assert!(s.contains("console (3 lines)"));
assert!(!s.contains("window-truncated"));
assert!(!s.contains("last line incomplete"));
assert!(!s.contains("[partial]"));
}
#[test]
fn format_console_diagnostics_last_line_incomplete_without_window_drop() {
let console = "line1\nline2\npartial li";
let s = format_console_diagnostics(console, 0, "test");
assert!(s.contains("console (3 lines, last line incomplete)"));
assert!(s.contains("partial li [partial]"));
assert!(!s.contains("window-truncated"));
}
#[test]
fn format_console_diagnostics_window_drop_and_last_line_incomplete() {
let lines: Vec<String> = (0..50).map(|i| format!("boot line {i}")).collect();
let console = lines.join("\n");
let s = format_console_diagnostics(&console, 0, "test");
assert!(s.contains("console (20 lines, window-truncated, last line incomplete)"));
assert!(s.contains("boot line 49 [partial]"));
assert!(!s.contains("boot line 29"));
}
fn lifecycle_only_drain(
phases: &[crate::vmm::wire::LifecyclePhase],
) -> crate::vmm::host_comms::BulkDrainResult {
let entries = phases
.iter()
.map(|p| ShmEntry {
msg_type: crate::vmm::wire::MSG_TYPE_LIFECYCLE,
payload: vec![p.wire_value()],
crc_ok: true,
})
.collect();
crate::vmm::host_comms::BulkDrainResult { entries }
}
#[test]
fn classify_no_lifecycle_frames() {
assert_eq!(classify_init_stage(None), STAGE_INIT_NOT_STARTED);
let drain = crate::vmm::host_comms::BulkDrainResult { entries: vec![] };
assert_eq!(classify_init_stage(Some(&drain)), STAGE_INIT_NOT_STARTED);
}
#[test]
fn classify_init_started_only() {
let drain = lifecycle_only_drain(&[crate::vmm::wire::LifecyclePhase::InitStarted]);
assert_eq!(
classify_init_stage(Some(&drain)),
STAGE_INIT_STARTED_NO_PAYLOAD,
);
}
#[test]
fn classify_payload_starting() {
let drain = lifecycle_only_drain(&[
crate::vmm::wire::LifecyclePhase::InitStarted,
crate::vmm::wire::LifecyclePhase::PayloadStarting,
]);
assert_eq!(
classify_init_stage(Some(&drain)),
STAGE_PAYLOAD_STARTED_NO_RESULT,
);
}
#[test]
fn classify_payload_starting_without_init() {
let drain = lifecycle_only_drain(&[crate::vmm::wire::LifecyclePhase::PayloadStarting]);
assert_eq!(
classify_init_stage(Some(&drain)),
STAGE_PAYLOAD_STARTED_NO_RESULT,
);
}
#[test]
fn classify_scheduler_died_without_payload_starting_is_init_no_payload() {
let died = lifecycle_only_drain(&[
crate::vmm::wire::LifecyclePhase::InitStarted,
crate::vmm::wire::LifecyclePhase::SchedulerDied,
]);
assert_eq!(
classify_init_stage(Some(&died)),
STAGE_INIT_STARTED_NO_PAYLOAD,
);
let not_attached = lifecycle_only_drain(&[
crate::vmm::wire::LifecyclePhase::InitStarted,
crate::vmm::wire::LifecyclePhase::SchedulerNotAttached,
]);
assert_eq!(
classify_init_stage(Some(¬_attached)),
STAGE_INIT_STARTED_NO_PAYLOAD,
);
}
#[test]
fn classify_scheduler_died_after_payload_starting_is_payload_no_result() {
let died_mid_test = lifecycle_only_drain(&[
crate::vmm::wire::LifecyclePhase::InitStarted,
crate::vmm::wire::LifecyclePhase::PayloadStarting,
crate::vmm::wire::LifecyclePhase::SchedulerDied,
]);
assert_eq!(
classify_init_stage(Some(&died_mid_test)),
STAGE_PAYLOAD_STARTED_NO_RESULT,
);
}
#[test]
fn classify_init_stage_skips_crc_bad_lifecycle_frames() {
let mut drain = lifecycle_only_drain(&[crate::vmm::wire::LifecyclePhase::InitStarted]);
drain.entries[0].crc_ok = false;
assert_eq!(classify_init_stage(Some(&drain)), STAGE_INIT_NOT_STARTED);
}
#[test]
fn extract_panic_message_found() {
let output = "noise\nPANIC: panicked at src/main.rs:5: oh no\nmore";
assert_eq!(
extract_panic_message(output),
Some("panicked at src/main.rs:5: oh no"),
);
}
#[test]
fn extract_panic_message_absent() {
assert!(extract_panic_message("no panic here").is_none());
}
#[test]
fn extract_panic_message_empty() {
assert!(extract_panic_message("").is_none());
}
#[test]
fn extract_panic_message_ignores_midline_occurrences() {
let output = "info: expected PANIC: somewhere in test\nmore noise";
assert!(
extract_panic_message(output).is_none(),
"mid-line `PANIC:` must not be matched as a panic prefix",
);
}
#[test]
fn extract_panic_message_matches_whitespace_prefixed_line() {
let output = "noise\n PANIC: indented panic\nmore";
assert_eq!(
extract_panic_message(output),
Some("indented panic"),
"leading whitespace before `PANIC:` must be trimmed before the prefix check",
);
}
#[test]
fn parse_assert_result_threads_into_verdict_merge() {
use crate::assert::Verdict;
let original = build_assert_result(
false,
vec![AssertDetail::new(DetailKind::Stuck, "tid 42 stuck 3000ms")],
);
let drain = drain_with_assert(&original);
let parsed = parse_assert_result_from_drain(Some(&drain)).unwrap();
assert!(!parsed.is_pass(), "guest result must be failing");
let observed_runtime_us: u64 = 9000;
let mut v = Verdict::new();
crate::claim!(v, observed_runtime_us).at_most(5000);
v.merge(parsed);
let r = v.into_result();
assert!(
!r.is_pass(),
"merge of failing parsed result + failing host claim must fail",
);
assert!(
r.failure_details()
.any(|d| d.message.contains("at most 5000")),
"host claim failure missing: {:?}",
r.outcomes,
);
assert!(
r.failure_details().any(|d| d.kind == DetailKind::Stuck),
"guest Stuck detail missing: {:?}",
r.outcomes,
);
}
#[test]
fn parse_assert_result_passing_merge_keeps_verdict_passing() {
use crate::assert::Verdict;
let original = build_assert_result(true, vec![]);
let drain = drain_with_assert(&original);
let parsed = parse_assert_result_from_drain(Some(&drain)).unwrap();
let observed: u64 = 100;
let mut v = Verdict::new();
crate::claim!(v, observed).at_most(1000);
v.merge(parsed);
let r = v.into_result();
assert!(
r.is_pass(),
"passing merge must keep verdict passing: {:?}",
r.outcomes
);
}
#[test]
fn format_periodic_samples_section_empty_when_target_zero() {
let mut result = crate::vmm::VmResult::test_fixture();
result.periodic_target = 0;
result.periodic_fired = 0;
let s = format_periodic_samples_section(&result);
assert!(s.is_empty());
}
#[test]
fn format_periodic_samples_section_full_coverage() {
let mut result = crate::vmm::VmResult::test_fixture();
result.periodic_target = 5;
result.periodic_fired = 5;
let s = format_periodic_samples_section(&result);
assert!(s.contains("--- periodic samples ---"));
assert!(s.contains("fired 5/5"));
assert!(s.contains("100% coverage"));
assert!(!s.contains("missing"));
}
#[test]
fn format_periodic_samples_section_partial_coverage() {
let mut result = crate::vmm::VmResult::test_fixture();
result.periodic_target = 5;
result.periodic_fired = 2;
let s = format_periodic_samples_section(&result);
assert!(s.contains("--- periodic samples ---"));
assert!(s.contains("fired 2/5"));
assert!(s.contains("missing 3"));
}
#[test]
fn format_temporal_assertions_section_empty_without_temporal_details() {
let mut r = crate::assert::AssertResult::pass();
r.record_fail(AssertDetail::new(DetailKind::Stuck, "tid 7 stuck 2000ms"));
let s = format_temporal_assertions_section(&r);
assert!(s.is_empty());
}
#[test]
fn format_temporal_assertions_section_renders_temporal_details() {
let mut r = crate::assert::AssertResult::pass();
r.record_fail(AssertDetail::new(
DetailKind::Temporal,
"counter (nondecreasing): regression at sample periodic_001",
));
r.record_fail(AssertDetail::new(DetailKind::Stuck, "unrelated failure"));
r.record_fail(AssertDetail::new(
DetailKind::Temporal,
"load (steady_within ...): outlier at sample periodic_005",
));
let s = format_temporal_assertions_section(&r);
assert!(s.contains("--- temporal assertions ---"));
assert!(s.contains("2 temporal assertion entry(ies)"));
assert!(s.contains("counter (nondecreasing)"));
assert!(s.contains("load (steady_within"));
assert!(!s.contains("unrelated failure"));
}
#[test]
fn format_temporal_assertions_section_renders_inconclusive_temporal_details() {
let mut r = crate::assert::AssertResult::pass();
r.record_inconclusive(AssertDetail::new(
DetailKind::Temporal,
"rate_within: zero-denominator at sample periodic_003",
));
r.record_inconclusive(AssertDetail::new(
DetailKind::Temporal,
"ratio_within: zero-denominator at sample periodic_007",
));
r.record_inconclusive(AssertDetail::new(
DetailKind::Benchmark,
"throughput parity inconclusive: zero cpu_time_ns",
));
let s = format_temporal_assertions_section(&r);
assert!(s.contains("--- temporal assertions ---"));
assert!(s.contains("2 temporal assertion entry(ies)"));
assert!(s.contains("rate_within: zero-denominator"));
assert!(s.contains("ratio_within: zero-denominator"));
assert!(!s.contains("throughput parity inconclusive"));
}
#[test]
fn format_temporal_assertions_section_chains_fail_then_inconclusive() {
let mut r = crate::assert::AssertResult::pass();
r.record_fail(AssertDetail::new(
DetailKind::Temporal,
"fail temporal entry",
));
r.record_inconclusive(AssertDetail::new(
DetailKind::Temporal,
"inc temporal entry",
));
let s = format_temporal_assertions_section(&r);
assert!(s.contains("2 temporal assertion entry(ies)"));
let fail_pos = s.find("fail temporal entry").unwrap();
let inc_pos = s.find("inc temporal entry").unwrap();
assert!(
fail_pos < inc_pos,
"Fail must render before Inconclusive (failure_details chained first): {s}"
);
}
}