use std::collections::HashMap;
pub(crate) const SCHED_OUTPUT_START: &str = "===SCHED_OUTPUT_START===";
pub(crate) const SCHED_OUTPUT_END: &str = "===SCHED_OUTPUT_END===";
pub(crate) fn parse_sched_output(output: &str) -> Option<&str> {
let start = output.find(SCHED_OUTPUT_START)?;
let end = output.rfind(SCHED_OUTPUT_END)?;
let after_marker = start + SCHED_OUTPUT_START.len();
if after_marker >= end {
return None;
}
let content = output[after_marker..end].trim();
if content.is_empty() {
return None;
}
Some(content)
}
pub(crate) fn concat_sched_log_chunks(
drain: Option<&crate::vmm::host_comms::BulkDrainResult>,
) -> String {
let Some(drain) = drain else {
return String::new();
};
let mut acc = String::new();
for e in &drain.entries {
if e.msg_type != crate::vmm::wire::MSG_TYPE_SCHED_LOG || !e.crc_ok {
continue;
}
acc.push_str(&String::from_utf8_lossy(&e.payload));
}
acc
}
pub(crate) fn parse_sched_output_partial(output: &str) -> Option<&str> {
if let Some(content) = parse_sched_output(output) {
return Some(content);
}
let start = output.find(SCHED_OUTPUT_START)?;
let after_marker = start + SCHED_OUTPUT_START.len();
let content = output[after_marker..].trim();
if content.is_empty() {
return None;
}
Some(content)
}
pub struct VerifierStats {
pub processed_insns: u64,
pub total_states: u64,
pub peak_states: u64,
pub time_usec: Option<u64>,
pub stack_depth: Option<String>,
}
#[derive(Debug, Clone, PartialEq, Eq, serde::Serialize, serde::Deserialize)]
pub struct ProgStats {
pub name: String,
pub verified_insns: u32,
}
pub struct DiffRow {
pub name: String,
pub a: u64,
pub b: u64,
pub delta: i64,
}
fn parse_or_warn(raw: &str, field: &str) -> u64 {
match raw.parse() {
Ok(n) => n,
Err(e) => {
tracing::warn!(
field,
word = raw,
err = %e,
"malformed BPF verifier count; leaving 0",
);
0
}
}
}
pub fn parse_verifier_stats(log: &str) -> VerifierStats {
let mut stats = VerifierStats {
processed_insns: 0,
total_states: 0,
peak_states: 0,
time_usec: None,
stack_depth: None,
};
let mut found_insns = false;
let mut found_time = false;
let mut found_stack = false;
for line in log.lines().rev() {
if !found_insns && line.starts_with("processed ") {
found_insns = true;
let words: Vec<&str> = line.split_whitespace().collect();
if words.len() >= 2 {
stats.processed_insns = parse_or_warn(words[1], "processed_insns");
}
for (i, &w) in words.iter().enumerate() {
if w == "total_states"
&& let Some(v) = words.get(i + 1)
{
stats.total_states = parse_or_warn(v, "total_states");
}
if w == "peak_states"
&& let Some(v) = words.get(i + 1)
{
stats.peak_states = parse_or_warn(v, "peak_states");
}
}
}
if !found_time && line.contains("verification time") {
found_time = true;
for word in line.split_whitespace() {
if let Ok(n) = word.parse::<u64>() {
stats.time_usec = Some(n);
break;
}
}
}
if !found_stack && line.contains("stack depth") {
found_stack = true;
if let Some(pos) = line.find("stack depth") {
let after = &line[pos + "stack depth".len()..];
let depth_str = after.trim();
if !depth_str.is_empty() {
stats.stack_depth = Some(depth_str.to_string());
}
}
}
if found_insns && found_time && found_stack {
break;
}
}
stats
}
pub fn normalize_verifier_line(line: &str) -> &str {
let trimmed = line.trim();
if trimmed.is_empty() || !trimmed.as_bytes()[0].is_ascii_digit() {
return trimmed;
}
if let Some(colon) = trimmed.find(": ") {
let after = &trimmed[colon + 2..];
if after.starts_with("frame")
|| (after.starts_with('R')
&& after.as_bytes().get(1).is_some_and(|b| b.is_ascii_digit()))
{
return &trimmed[..colon + 1];
}
}
if let Some(pos) = trimmed.find("; frame") {
return trimmed[..pos].trim_end();
}
if let Some(pos) = trimmed.find("; R")
&& trimmed
.as_bytes()
.get(pos + 3)
.is_some_and(|b| b.is_ascii_digit())
{
return trimmed[..pos].trim_end();
}
if let Some(goto_pos) = trimmed.find("goto pc") {
let after_goto = &trimmed[goto_pos + 7..];
let end = after_goto
.find(|c: char| c != '+' && c != '-' && !c.is_ascii_digit())
.unwrap_or(after_goto.len());
let insn_end = goto_pos + 7 + end;
if insn_end < trimmed.len() {
return trimmed[..insn_end].trim_end();
}
}
trimmed
}
fn normalize_for_cycle_detection(line: &str) -> &str {
let n = normalize_verifier_line(line);
if let Some(colon) = n.find(": ") {
let before = &n[..colon];
if !before.is_empty() && before.bytes().all(|b| b.is_ascii_digit()) {
return &n[colon + 2..];
}
}
n
}
pub fn detect_cycle(lines: &[&str]) -> Option<(usize, usize, usize)> {
const MIN_PERIOD: usize = 5;
const MIN_REPS: usize = 3;
if lines.len() < MIN_PERIOD * MIN_REPS {
return None;
}
let anchor_norms: Vec<&str> = lines.iter().map(|l| normalize_verifier_line(l)).collect();
let block_norms: Vec<&str> = lines
.iter()
.map(|l| normalize_for_cycle_detection(l))
.collect();
let mut sorted_norms: Vec<&str> = anchor_norms
.iter()
.filter(|l| l.len() >= 10)
.copied()
.collect();
sorted_norms.sort_unstable();
let mut best_anchor: Option<(&str, usize)> = None;
let mut i = 0;
while i < sorted_norms.len() {
let mut j = i + 1;
while j < sorted_norms.len() && sorted_norms[j] == sorted_norms[i] {
j += 1;
}
let count = j - i;
if count >= MIN_REPS && best_anchor.is_none_or(|(_, best)| count > best) {
best_anchor = Some((sorted_norms[i], count));
}
i = j;
}
let (anchor, use_block_norms_for_positions) = match best_anchor {
Some((a, _)) => (a, false),
None => {
let mut sorted_block: Vec<&str> = block_norms
.iter()
.filter(|l| l.len() >= 10)
.copied()
.collect();
sorted_block.sort_unstable();
let mut ba: Option<(&str, usize)> = None;
let mut bi = 0;
while bi < sorted_block.len() {
let mut bj = bi + 1;
while bj < sorted_block.len() && sorted_block[bj] == sorted_block[bi] {
bj += 1;
}
let c = bj - bi;
if c >= MIN_REPS && ba.is_none_or(|(_, best)| c > best) {
ba = Some((sorted_block[bi], c));
}
bi = bj;
}
match ba {
Some((a, _)) => (a, true),
None => return None,
}
}
};
let norms_for_pos = if use_block_norms_for_positions {
&block_norms
} else {
&anchor_norms
};
let positions: Vec<usize> = norms_for_pos
.iter()
.enumerate()
.filter(|(_, l)| **l == anchor)
.map(|(i, _)| i)
.collect();
for stride in 1..=3usize {
if positions.len() <= stride {
continue;
}
let mut gaps: Vec<usize> = positions
.windows(stride + 1)
.map(|w| w[stride] - w[0])
.filter(|g| *g >= MIN_PERIOD)
.collect();
gaps.sort_unstable();
let mut best_period = 0;
let mut best_gap_count = 0;
let mut gi = 0;
while gi < gaps.len() {
let mut gj = gi + 1;
while gj < gaps.len() && gaps[gj] == gaps[gi] {
gj += 1;
}
let count = gj - gi;
if count > best_gap_count {
best_gap_count = count;
best_period = gaps[gi];
}
gi = gj;
}
if best_period == 0 || best_gap_count < MIN_REPS - 1 {
continue;
}
let period = best_period;
for &pos in &positions {
if pos + 2 * period > lines.len() {
break;
}
if block_norms[pos..pos + period] == block_norms[pos + period..pos + 2 * period] {
let first_block = &block_norms[pos..pos + period];
let mut count = 1;
while pos + (count + 1) * period <= lines.len() {
if block_norms[pos + count * period..pos + (count + 1) * period] != *first_block
{
break;
}
count += 1;
}
let mut best_start = pos;
let mut best_count = count;
for offset in 1..period {
let Some(cand) = pos.checked_sub(offset) else {
break;
};
if cand + 2 * period > lines.len() {
continue;
}
if block_norms[cand..cand + period]
!= block_norms[cand + period..cand + 2 * period]
{
continue;
}
let mut c = 2;
while cand + (c + 1) * period <= lines.len()
&& block_norms[cand + c * period..cand + (c + 1) * period]
== block_norms[cand..cand + period]
{
c += 1;
}
if c > best_count {
best_start = cand;
best_count = c;
}
}
if best_count >= MIN_REPS {
return Some((best_start, period, best_count));
}
}
}
}
None
}
pub fn collapse_cycles(log: &str) -> String {
const MAX_PASSES: usize = 5;
let mut text = log.to_string();
for _ in 0..MAX_PASSES {
let lines: Vec<&str> = text.lines().collect();
let (start, period, count) = match detect_cycle(&lines) {
Some(c) => c,
None => break,
};
let mut out = String::new();
for line in &lines[..start] {
out.push_str(line);
out.push('\n');
}
out.push_str(&format!(
"--- {}x of the following {} lines ---\n",
count, period
));
for line in &lines[start..start + period] {
out.push_str(line);
out.push('\n');
}
out.push_str(&format!(
"--- {} identical iterations omitted ---\n",
count - 2
));
let last_start = start + (count - 1) * period;
for line in &lines[last_start..last_start + period] {
out.push_str(line);
out.push('\n');
}
out.push_str("--- end repeat ---\n");
let suffix_start = start + count * period;
for line in &lines[suffix_start..] {
out.push_str(line);
out.push('\n');
}
text = out;
}
text
}
pub fn build_diff_rows(stats_a: &[ProgStats], b_map: &HashMap<String, u64>) -> Vec<DiffRow> {
let mut rows = Vec::new();
for ps in stats_a {
let a = ps.verified_insns as u64;
let b = b_map.get(&ps.name).copied().unwrap_or(0);
rows.push(DiffRow {
name: ps.name.clone(),
a,
b,
delta: a as i64 - b as i64,
});
}
rows
}
pub fn build_b_map(stats_b: &[ProgStats]) -> HashMap<String, u64> {
stats_b
.iter()
.map(|ps| (ps.name.clone(), ps.verified_insns as u64))
.collect()
}
#[derive(Debug, Clone, PartialEq, Eq)]
pub enum AttachOutcome {
Attached,
Died,
NotAttached(String),
Unconfirmed,
}
impl AttachOutcome {
pub fn failure_reason(&self) -> Option<String> {
match self {
AttachOutcome::Attached => None,
AttachOutcome::Died => {
Some("scheduler process exited during BPF load/startup".to_string())
}
AttachOutcome::NotAttached(reason) if reason.is_empty() => {
Some("scheduler never reached sched_ext 'enabled'".to_string())
}
AttachOutcome::NotAttached(reason) => Some(format!(
"scheduler never reached sched_ext 'enabled': {reason}"
)),
AttachOutcome::Unconfirmed => Some(
"scheduler attach unconfirmed — guest never reached the dispatch phase \
(no PayloadStarting frame; possible early guest kernel panic)"
.to_string(),
),
}
}
}
pub(crate) fn attach_outcome_from_messages(
guest_messages: Option<&crate::vmm::host_comms::BulkDrainResult>,
) -> AttachOutcome {
let Some(drain) = guest_messages else {
return AttachOutcome::Unconfirmed;
};
let mut not_attached: Option<String> = None;
let mut payload_starting = false;
for e in &drain.entries {
if e.msg_type != crate::vmm::wire::MSG_TYPE_LIFECYCLE || !e.crc_ok || e.payload.is_empty() {
continue;
}
match crate::vmm::wire::LifecyclePhase::from_wire(e.payload[0]) {
Some(crate::vmm::wire::LifecyclePhase::SchedulerDied) => return AttachOutcome::Died,
Some(crate::vmm::wire::LifecyclePhase::SchedulerNotAttached) => {
not_attached = Some(String::from_utf8_lossy(&e.payload[1..]).into_owned());
}
Some(crate::vmm::wire::LifecyclePhase::PayloadStarting) => {
payload_starting = true;
}
_ => {}
}
}
if let Some(reason) = not_attached {
AttachOutcome::NotAttached(reason)
} else if payload_starting {
AttachOutcome::Attached
} else {
AttachOutcome::Unconfirmed
}
}
fn dispatch_confirmed_from_messages(
guest_messages: Option<&crate::vmm::host_comms::BulkDrainResult>,
) -> bool {
let Some(drain) = guest_messages else {
return false;
};
drain.entries.iter().any(|e| {
e.msg_type == crate::vmm::wire::MSG_TYPE_LIFECYCLE
&& e.crc_ok
&& !e.payload.is_empty()
&& crate::vmm::wire::LifecyclePhase::from_wire(e.payload[0])
== Some(crate::vmm::wire::LifecyclePhase::WorkloadDispatched)
})
}
pub struct VerifierVmResult {
pub stats: Vec<ProgStats>,
pub scheduler_log: String,
pub attach: AttachOutcome,
pub dispatched: bool,
pub timed_out: bool,
}
impl VerifierVmResult {
pub fn cell_verdict(&self) -> Result<(), String> {
if self.timed_out {
return Err("VM timed out (hung after attach, before exit)".to_string());
}
if let Some(reason) = self.attach.failure_reason() {
return Err(format!("scheduler did not turn on — {reason}"));
}
if !self.dispatched {
return Err(
"scheduler attached but did not dispatch the injected workload (0 iterations)"
.to_string(),
);
}
Ok(())
}
}
pub fn collect_verifier_output(
sched_bin: &std::path::Path,
ktstr_bin: &std::path::Path,
kernel: &std::path::Path,
extra_sched_args: &[String],
topology: crate::test_support::TopologyJson,
) -> anyhow::Result<VerifierVmResult> {
use anyhow::Context;
let validated: crate::vmm::topology::Topology = topology
.try_into()
.map_err(|e: String| anyhow::anyhow!("invalid topology {topology:?}: {e}"))?;
let sched_args: Vec<String> = extra_sched_args.to_vec();
let vm = crate::vmm::KtstrVm::builder()
.kernel(kernel)
.init_binary(ktstr_bin)
.scheduler_binary(sched_bin)
.sched_args(&sched_args)
.run_args(&[crate::test_support::VERIFIER_WORKLOAD_FLAG.to_string()])
.topology(validated)
.memory_mib(2048)
.timeout(std::time::Duration::from_secs(120))
.no_perf_mode(true)
.build()
.context("build verifier VM")?;
let result = vm.run().context("run verifier VM")?;
let merged = concat_sched_log_chunks(result.guest_messages.as_ref());
let scheduler_log = if !merged.is_empty() {
parse_sched_output(&merged).unwrap_or("").to_string()
} else {
parse_sched_output(&result.output).unwrap_or("").to_string()
};
let stats: Vec<ProgStats> = result
.verifier_stats
.iter()
.map(|pvs| ProgStats {
name: pvs.name.clone(),
verified_insns: pvs.verified_insns,
})
.collect();
let attach = attach_outcome_from_messages(result.guest_messages.as_ref());
let dispatched = dispatch_confirmed_from_messages(result.guest_messages.as_ref());
Ok(VerifierVmResult {
stats,
scheduler_log,
attach,
dispatched,
timed_out: result.timed_out,
})
}
pub fn extract_verifier_log(scheduler_log: &str) -> Option<&str> {
const BEGIN: &str = "-- BEGIN PROG LOAD LOG --";
const END: &str = "-- END PROG LOAD LOG --";
let begin_pos = scheduler_log.find(BEGIN)?;
let content_start = begin_pos + BEGIN.len();
let content_start = if scheduler_log.as_bytes().get(content_start) == Some(&b'\n') {
content_start + 1
} else {
content_start
};
let end_pos = scheduler_log[content_start..].find(END)?;
let content = &scheduler_log[content_start..content_start + end_pos];
let content = content
.rfind('\n')
.map(|p| &content[..p])
.unwrap_or(content);
Some(content.trim_end_matches('\n'))
}
pub fn format_verifier_output(label: &str, result: &VerifierVmResult, raw: bool) -> String {
let mut out = String::new();
out.push_str(&format!("\n{label}\n"));
if result.timed_out {
out.push_str(" scheduler: UNKNOWN — VM timed out before exit\n");
} else {
match result.attach.failure_reason() {
None => {
out.push_str(" scheduler: attached (sched_ext enabled)\n");
if result.dispatched {
out.push_str(" dispatch: confirmed (injected workload ran)\n");
} else {
out.push_str(
" dispatch: NOT CONFIRMED — attached but injected workload made no progress\n",
);
}
}
Some(reason) => out.push_str(&format!(" scheduler: NOT ATTACHED — {reason}\n")),
}
}
for ps in &result.stats {
out.push_str(&format!(
" {:<40} verified_insns={}\n",
ps.name, ps.verified_insns
));
}
if !result.scheduler_log.is_empty() {
let verifier_log =
extract_verifier_log(&result.scheduler_log).unwrap_or(&result.scheduler_log);
let vs = parse_verifier_stats(verifier_log);
if vs.processed_insns > 0 {
out.push_str(&format!("\n{label} --- verifier stats ---\n"));
out.push_str(&format!(
" processed={} states={}/{}",
vs.processed_insns, vs.peak_states, vs.total_states
));
if let Some(t) = vs.time_usec {
out.push_str(&format!(" time={t}us"));
}
if let Some(ref s) = vs.stack_depth {
out.push_str(&format!(" stack={s}"));
}
out.push('\n');
}
out.push_str(&format!("\n{label} --- scheduler log ---\n"));
if raw {
out.push_str(&result.scheduler_log);
} else {
out.push_str(&collapse_cycles(verifier_log));
}
}
out
}
pub fn format_verifier_diff(
label_a: &str,
stats_a: &[ProgStats],
label_b: &str,
stats_b: &[ProgStats],
) -> String {
let b_map = build_b_map(stats_b);
let diff_rows = build_diff_rows(stats_a, &b_map);
let mut out = String::new();
out.push_str(&format!("\ndelta A/B diff: {label_a} vs {label_b}\n"));
let mut table = crate::cli::new_table();
table.set_header(vec!["program", "A", "B", "delta"]);
for row in &diff_rows {
table.add_row(vec![
row.name.clone(),
row.a.to_string(),
row.b.to_string(),
format!("{:+}", row.delta),
]);
}
out.push_str(&table.to_string());
out.push('\n');
out
}
#[derive(Debug, Clone, PartialEq, Eq, serde::Serialize, serde::Deserialize)]
pub struct VerifierCellRecord {
pub scheduler: String,
pub kernel: String,
pub topology: String,
pub passed: bool,
pub stats: Vec<ProgStats>,
}
fn cell_record_filename(full_name: &str) -> String {
let mut s: String = full_name
.chars()
.map(|c| if c.is_ascii_alphanumeric() { c } else { '_' })
.collect();
s.push_str(".json");
s
}
pub(crate) fn write_cell_record(
dir: &std::path::Path,
full_name: &str,
passed: bool,
stats: &[ProgStats],
) {
let Some(rest) = full_name.strip_prefix("verifier/") else {
return;
};
let parts: Vec<&str> = rest.splitn(3, '/').collect();
if parts.len() != 3 {
return;
}
let record = VerifierCellRecord {
scheduler: parts[0].to_string(),
kernel: parts[1].to_string(),
topology: parts[2].to_string(),
passed,
stats: stats.to_vec(),
};
let path = dir.join(cell_record_filename(full_name));
match serde_json::to_vec(&record) {
Ok(bytes) => {
if let Err(e) = std::fs::write(&path, bytes) {
eprintln!(
"ktstr verifier: warning: could not write result record {}: {e}",
path.display(),
);
}
}
Err(e) => eprintln!("ktstr verifier: warning: serialize result record: {e}"),
}
}
pub fn read_cell_records(dir: &std::path::Path) -> Vec<VerifierCellRecord> {
let Ok(entries) = std::fs::read_dir(dir) else {
return Vec::new();
};
entries
.flatten()
.filter(|e| {
e.path()
.extension()
.is_some_and(|x| x.eq_ignore_ascii_case("json"))
})
.filter_map(|e| std::fs::read(e.path()).ok())
.filter_map(|bytes| serde_json::from_slice::<VerifierCellRecord>(&bytes).ok())
.collect()
}
pub fn classify_run_outcome(
success: bool,
records_empty: bool,
scheduler: Option<&str>,
exit_code: Option<i32>,
) -> Result<(), String> {
if !success {
let code = exit_code.map_or_else(|| "signal".to_string(), |c| c.to_string());
return Err(format!("cargo nextest run exited with {code}"));
}
if records_empty {
return Err(match scheduler {
Some(name) => format!(
"--scheduler {name:?}: matched no verifier cell — no declared BPF \
scheduler by that name, or no topology preset fits this host for \
it. Run `cargo ktstr verifier` with no --scheduler to see the \
swept set."
),
None => "no verifier cells ran — no scheduler is declared via \
declare_scheduler! in a linked test binary, or every declared \
scheduler's constraints rejected all topology presets on this \
host."
.to_string(),
});
}
Ok(())
}
pub fn build_nextest_args(nextest_profile: Option<&str>, forward: &[String]) -> Vec<String> {
let mut args = vec![
"nextest".to_string(),
"run".to_string(),
"--run-ignored".to_string(),
"all".to_string(),
"--no-tests".to_string(),
"pass".to_string(),
"-E".to_string(),
"test(/^verifier/) & !test(/^verifier::/)".to_string(),
];
if let Some(np) = nextest_profile {
args.push("--profile".to_string());
args.push(np.to_string());
}
args.extend(forward.iter().cloned());
args
}
pub fn render_result_table(records: &[VerifierCellRecord]) -> Option<String> {
if records.is_empty() {
return None;
}
use std::collections::{BTreeMap, BTreeSet};
let mut schedulers: BTreeSet<String> = BTreeSet::new(); let mut rows: BTreeSet<String> = BTreeSet::new(); let mut agg: BTreeMap<(String, String), (u32, u32)> = BTreeMap::new();
let mut failing: BTreeSet<(String, String, String)> = BTreeSet::new();
for r in records {
schedulers.insert(r.scheduler.clone());
rows.insert(r.topology.clone());
let counts = agg
.entry((r.topology.clone(), r.scheduler.clone()))
.or_insert((0, 0));
if r.passed {
counts.0 += 1;
} else {
counts.1 += 1;
failing.insert((r.scheduler.clone(), r.kernel.clone(), r.topology.clone()));
}
}
let (mut n_pass, mut n_fail, mut n_mixed) = (0usize, 0usize, 0usize);
let mut table = crate::cli::new_table();
let mut header: Vec<String> = vec!["topology".to_string()];
for sched in &schedulers {
header.push(sched.clone());
}
table.set_header(header);
for topo in &rows {
let mut line: Vec<String> = vec![topo.clone()];
for sched in &schedulers {
let text = match agg.get(&(topo.clone(), sched.clone())) {
None => "-",
Some((_, 0)) => {
n_pass += 1;
"✅"
}
Some((0, _)) => {
n_fail += 1;
"❌"
}
Some(_) => {
n_mixed += 1;
"🇽"
}
};
line.push(text.to_string());
}
table.add_row(line);
}
let mut out = format!("\nverifier summary: {n_pass} ✅ {n_fail} ❌ {n_mixed} 🇽\n{table}\n");
if !failing.is_empty() {
out.push_str("\nfailing combinations (scheduler / kernel / topology):\n");
for (sched, kernel, topo) in &failing {
out.push_str(&format!(" {sched} / {kernel} / {topo}\n"));
}
}
Some(out)
}
pub fn render_instruction_count_tables(records: &[VerifierCellRecord]) -> Option<String> {
use std::collections::{BTreeMap, BTreeSet};
type VerifiedInsnSpans = BTreeMap<String, BTreeMap<String, BTreeMap<String, (u32, u32)>>>;
let mut by_sched: VerifiedInsnSpans = BTreeMap::new();
let mut sched_progs: BTreeMap<String, BTreeSet<String>> = BTreeMap::new();
for r in records {
for s in &r.stats {
let span = by_sched
.entry(r.scheduler.clone())
.or_default()
.entry(r.kernel.clone())
.or_default()
.entry(s.name.clone())
.or_insert((s.verified_insns, s.verified_insns));
span.0 = span.0.min(s.verified_insns);
span.1 = span.1.max(s.verified_insns);
sched_progs
.entry(r.scheduler.clone())
.or_default()
.insert(s.name.clone());
}
}
if by_sched.is_empty() {
return None;
}
let mut out = String::from(
"\nverifier verified_insns (per scheduler; rows: kernel, cols: BPF program, \
cell: range across topologies):\n",
);
for (sched, kernels) in &by_sched {
let progs = &sched_progs[sched];
let mut table = crate::cli::new_table();
let mut header: Vec<String> = vec!["kernel".to_string()];
for p in progs {
header.push(p.clone());
}
table.set_header(header);
for (kernel, prog_map) in kernels {
let mut line: Vec<String> = vec![kernel.clone()];
for p in progs {
let text = match prog_map.get(p) {
Some((lo, hi)) if lo == hi => lo.to_string(),
Some((lo, hi)) => format!("{lo}..{hi}"),
None => "-".to_string(),
};
line.push(text);
}
table.add_row(line);
}
out.push_str(&format!("\n{sched}:\n{table}\n"));
}
Some(out)
}
#[cfg(test)]
mod tests {
use super::*;
#[test]
fn cell_record_write_read_roundtrip_and_retry_overwrites() {
let dir = std::env::temp_dir().join(format!("ktstr-verif-rec-{}", std::process::id()));
std::fs::create_dir_all(&dir).expect("mk temp dir");
write_cell_record(&dir, "not_a_cell", true, &[]);
write_cell_record(&dir, "verifier/only/two", true, &[]);
let name = "verifier/scx_a/kernel_6_14/tiny-1llc";
write_cell_record(&dir, name, false, &[]);
let stats = [
ProgStats {
name: "ktstr_dispatch".into(),
verified_insns: 321,
},
ProgStats {
name: "ktstr_enqueue".into(),
verified_insns: 123,
},
];
write_cell_record(&dir, name, true, &stats);
let recs = read_cell_records(&dir);
assert_eq!(
recs.len(),
1,
"malformed names skipped; the retry overwrote its own record (one file): {recs:?}",
);
assert_eq!(recs[0].scheduler, "scx_a");
assert_eq!(recs[0].kernel, "kernel_6_14");
assert_eq!(recs[0].topology, "tiny-1llc");
assert!(
recs[0].passed,
"final retry outcome (PASS) wins over the earlier FAIL"
);
assert_eq!(recs[0].stats, stats, "stats roundtrip via serde");
std::fs::remove_dir_all(&dir).ok();
}
#[test]
fn render_result_table_matrix_tally_and_empty() {
let recs = vec![
VerifierCellRecord {
scheduler: "scx_a".into(),
kernel: "kernel_6_14".into(),
topology: "tiny-1llc".into(),
passed: true,
stats: vec![],
},
VerifierCellRecord {
scheduler: "scx_a".into(),
kernel: "kernel_6_14".into(),
topology: "large-4llc".into(),
passed: false,
stats: vec![],
},
];
let out = render_result_table(&recs).expect("non-empty records -> Some");
assert!(
out.contains("verifier summary: 1 ✅ 1 ❌ 0 🇽"),
"tally: {out}"
);
assert!(
out.contains("scx_a") && !out.contains(" @ "),
"columns: {out}"
);
let pass_row = out
.lines()
.find(|l| l.contains("tiny-1llc"))
.expect("tiny-1llc row present");
assert!(
pass_row.contains('✅'),
"all-pass cell renders ✅ in the grid row: {pass_row}"
);
let fail_row = out
.lines()
.find(|l| l.contains("large-4llc"))
.expect("large-4llc row present");
assert!(
fail_row.contains('❌'),
"all-fail cell renders ❌ in the grid row: {fail_row}"
);
assert!(
out.contains("failing combinations (scheduler / kernel / topology):")
&& out.contains("scx_a / kernel_6_14 / large-4llc"),
"failing combinations listed: {out}"
);
assert!(render_result_table(&[]).is_none(), "empty -> None");
}
#[test]
fn render_result_table_mixed_kernels_blue_x() {
let recs = vec![
VerifierCellRecord {
scheduler: "scx_a".into(),
kernel: "kernel_6_14".into(),
topology: "tiny-1llc".into(),
passed: true,
stats: vec![],
},
VerifierCellRecord {
scheduler: "scx_a".into(),
kernel: "kernel_6_15".into(),
topology: "tiny-1llc".into(),
passed: false,
stats: vec![],
},
VerifierCellRecord {
scheduler: "scx_a".into(),
kernel: "kernel_6_14".into(),
topology: "smt-2llc".into(),
passed: true,
stats: vec![],
},
VerifierCellRecord {
scheduler: "scx_a".into(),
kernel: "kernel_6_15".into(),
topology: "smt-2llc".into(),
passed: true,
stats: vec![],
},
];
let out = render_result_table(&recs).expect("Some");
assert!(
out.contains("verifier summary: 1 ✅ 0 ❌ 1 🇽"),
"tally counts one all-pass + one mixed cell: {out}"
);
let mixed_row = out
.lines()
.find(|l| l.contains("tiny-1llc"))
.expect("tiny-1llc row present");
assert!(
mixed_row.contains('🇽'),
"mixed (some pass, some fail) cell renders 🇽: {mixed_row}"
);
let pass_row = out
.lines()
.find(|l| l.contains("smt-2llc"))
.expect("smt-2llc row present");
assert!(
pass_row.contains('✅'),
"all-kernels-pass cell renders ✅: {pass_row}"
);
assert!(
out.contains("scx_a / kernel_6_15 / tiny-1llc"),
"the failing kernel is listed: {out}"
);
assert!(
!out.contains("kernel_6_14 / tiny-1llc"),
"the passing kernel on the mixed topology is not listed: {out}"
);
assert!(
!out.contains("/ smt-2llc"),
"the all-pass topology contributes no failing combination: {out}"
);
}
#[test]
fn instruction_count_tables_per_scheduler_kernel_program_range() {
let recs = vec![
VerifierCellRecord {
scheduler: "scx_a".into(),
kernel: "kernel_6_14".into(),
topology: "tiny".into(),
passed: true,
stats: vec![
ProgStats {
name: "ktstr_dispatch".into(),
verified_insns: 128,
},
ProgStats {
name: "ktstr_enqueue".into(),
verified_insns: 64,
},
],
},
VerifierCellRecord {
scheduler: "scx_a".into(),
kernel: "kernel_6_14".into(),
topology: "large".into(),
passed: true,
stats: vec![
ProgStats {
name: "ktstr_dispatch".into(),
verified_insns: 128,
},
ProgStats {
name: "ktstr_enqueue".into(),
verified_insns: 64,
},
],
},
VerifierCellRecord {
scheduler: "scx_a".into(),
kernel: "kernel_6_15".into(),
topology: "tiny".into(),
passed: true,
stats: vec![ProgStats {
name: "ktstr_dispatch".into(),
verified_insns: 130,
}],
},
VerifierCellRecord {
scheduler: "scx_a".into(),
kernel: "kernel_6_15".into(),
topology: "large".into(),
passed: true,
stats: vec![ProgStats {
name: "ktstr_dispatch".into(),
verified_insns: 150,
}],
},
VerifierCellRecord {
scheduler: "scx_b".into(),
kernel: "kernel_6_14".into(),
topology: "tiny".into(),
passed: true,
stats: vec![ProgStats {
name: "ktstr_dispatch".into(),
verified_insns: 200,
}],
},
];
let out = render_instruction_count_tables(&recs).expect("stats present -> Some");
assert!(
out.contains("scx_a:") && out.contains("scx_b:"),
"one section per declared scheduler: {out}"
);
assert!(
out.contains("ktstr_dispatch") && out.contains("ktstr_enqueue"),
"BPF-program columns: {out}"
);
assert!(
out.contains("kernel_6_14") && out.contains("kernel_6_15"),
"kernel-version rows: {out}"
);
assert!(
out.contains("128"),
"topology-flat cell is a single number: {out}"
);
assert!(
out.contains("130..150"),
"topology-varying cell is a lo..hi range: {out}"
);
assert!(
out.contains("64") && out.contains("200"),
"other counts render: {out}"
);
assert!(
out.contains('-'),
"a (kernel, program) with no stats renders '-': {out}"
);
assert!(
!out.contains("tiny") && !out.contains("large"),
"topology is not a table axis: {out}"
);
let bare = vec![VerifierCellRecord {
scheduler: "scx_a".into(),
kernel: "kernel_6_14".into(),
topology: "tiny".into(),
passed: false,
stats: vec![],
}];
assert!(
render_instruction_count_tables(&bare).is_none(),
"no stats -> None"
);
}
#[test]
fn classify_run_outcome_cases() {
assert!(classify_run_outcome(true, false, None, Some(0)).is_ok());
assert!(classify_run_outcome(true, false, Some("ktstr_sched"), Some(0)).is_ok());
let e = classify_run_outcome(true, true, Some("nope"), Some(0)).unwrap_err();
assert!(
e.contains("--scheduler \"nope\"") && e.contains("matched no verifier cell"),
"scheduler-empty diagnostic: {e}"
);
let e = classify_run_outcome(true, true, None, Some(0)).unwrap_err();
assert!(
e.contains("no verifier cells ran") && e.contains("declare_scheduler!"),
"no-cells diagnostic: {e}"
);
assert_eq!(
classify_run_outcome(false, true, None, Some(4)).unwrap_err(),
"cargo nextest run exited with 4"
);
assert_eq!(
classify_run_outcome(false, false, Some("x"), None).unwrap_err(),
"cargo nextest run exited with signal"
);
}
#[test]
fn build_nextest_args_carries_load_bearing_flags() {
let args = build_nextest_args(None, &[]);
let ri = args
.iter()
.position(|a| a == "--run-ignored")
.expect("--run-ignored present");
assert_eq!(args[ri + 1], "all", "--run-ignored all");
let nt = args
.iter()
.position(|a| a == "--no-tests")
.expect("--no-tests present");
assert_eq!(args[nt + 1], "pass", "--no-tests pass");
assert!(
args.iter()
.any(|a| a == "test(/^verifier/) & !test(/^verifier::/)"),
"verifier-cell filter present: {args:?}"
);
let args = build_nextest_args(Some("ci"), &["--features".to_string(), "wprof".to_string()]);
let p = args
.iter()
.position(|a| a == "--profile")
.expect("--profile present");
assert_eq!(args[p + 1], "ci");
let f = args
.iter()
.position(|a| a == "--features")
.expect("forwarded --features present");
assert!(p < f, "profile emitted before forwarded args: {args:?}");
}
#[test]
fn attach_outcome_from_lifecycle_frames() {
use crate::vmm::host_comms::BulkDrainResult;
use crate::vmm::wire::{LifecyclePhase, MSG_TYPE_LIFECYCLE, ShmEntry};
let frame = |phase: LifecyclePhase, reason: &str| -> ShmEntry {
let mut payload = vec![phase.wire_value()];
payload.extend_from_slice(reason.as_bytes());
ShmEntry {
msg_type: MSG_TYPE_LIFECYCLE,
payload,
crc_ok: true,
}
};
let drain = |entries: Vec<ShmEntry>| BulkDrainResult { entries };
assert_eq!(
attach_outcome_from_messages(None),
AttachOutcome::Unconfirmed,
);
let init_only = drain(vec![frame(LifecyclePhase::InitStarted, "")]);
assert_eq!(
attach_outcome_from_messages(Some(&init_only)),
AttachOutcome::Unconfirmed,
);
let progress = drain(vec![
frame(LifecyclePhase::InitStarted, ""),
frame(LifecyclePhase::PayloadStarting, ""),
]);
assert_eq!(
attach_outcome_from_messages(Some(&progress)),
AttachOutcome::Attached,
);
let not_attached = drain(vec![frame(LifecyclePhase::SchedulerNotAttached, "timeout")]);
assert_eq!(
attach_outcome_from_messages(Some(¬_attached)),
AttachOutcome::NotAttached("timeout".to_string()),
);
let fail_beats_positive = drain(vec![
frame(LifecyclePhase::PayloadStarting, ""),
frame(LifecyclePhase::SchedulerNotAttached, "sysfs absent"),
]);
assert_eq!(
attach_outcome_from_messages(Some(&fail_beats_positive)),
AttachOutcome::NotAttached("sysfs absent".to_string()),
);
for entries in [
vec![
frame(LifecyclePhase::SchedulerNotAttached, "timeout"),
frame(LifecyclePhase::SchedulerDied, ""),
],
vec![
frame(LifecyclePhase::SchedulerDied, ""),
frame(LifecyclePhase::SchedulerNotAttached, "timeout"),
],
] {
let d = drain(entries);
assert_eq!(attach_outcome_from_messages(Some(&d)), AttachOutcome::Died);
}
let died_beats_positive = drain(vec![
frame(LifecyclePhase::PayloadStarting, ""),
frame(LifecyclePhase::SchedulerDied, ""),
]);
assert_eq!(
attach_outcome_from_messages(Some(&died_beats_positive)),
AttachOutcome::Died,
);
let corrupt_died = ShmEntry {
msg_type: MSG_TYPE_LIFECYCLE,
payload: vec![LifecyclePhase::SchedulerDied.wire_value()],
crc_ok: false,
};
let empty = ShmEntry {
msg_type: MSG_TYPE_LIFECYCLE,
payload: Vec::new(),
crc_ok: true,
};
let non_lifecycle_died = ShmEntry {
msg_type: MSG_TYPE_LIFECYCLE + 1,
payload: vec![LifecyclePhase::SchedulerDied.wire_value()],
crc_ok: true,
};
let unknown_phase = ShmEntry {
msg_type: MSG_TYPE_LIFECYCLE,
payload: vec![250],
crc_ok: true,
};
for skipped in [corrupt_died, empty, non_lifecycle_died, unknown_phase] {
let d = drain(vec![skipped, frame(LifecyclePhase::PayloadStarting, "")]);
assert_eq!(
attach_outcome_from_messages(Some(&d)),
AttachOutcome::Attached,
"a skipped frame must not suppress a valid PayloadStarting",
);
}
}
#[test]
fn dispatch_confirmed_from_lifecycle_frames() {
use crate::vmm::host_comms::BulkDrainResult;
use crate::vmm::wire::{LifecyclePhase, MSG_TYPE_LIFECYCLE, ShmEntry};
let frame = |phase: LifecyclePhase| -> ShmEntry {
ShmEntry {
msg_type: MSG_TYPE_LIFECYCLE,
payload: vec![phase.wire_value()],
crc_ok: true,
}
};
let drain = |entries: Vec<ShmEntry>| BulkDrainResult { entries };
assert!(!dispatch_confirmed_from_messages(None));
let attached_only = drain(vec![frame(LifecyclePhase::PayloadStarting)]);
assert!(!dispatch_confirmed_from_messages(Some(&attached_only)));
let dispatched = drain(vec![
frame(LifecyclePhase::PayloadStarting),
frame(LifecyclePhase::WorkloadDispatched),
]);
assert!(dispatch_confirmed_from_messages(Some(&dispatched)));
let corrupt = ShmEntry {
msg_type: MSG_TYPE_LIFECYCLE,
payload: vec![LifecyclePhase::WorkloadDispatched.wire_value()],
crc_ok: false,
};
let empty = ShmEntry {
msg_type: MSG_TYPE_LIFECYCLE,
payload: Vec::new(),
crc_ok: true,
};
let non_lifecycle = ShmEntry {
msg_type: MSG_TYPE_LIFECYCLE + 1,
payload: vec![LifecyclePhase::WorkloadDispatched.wire_value()],
crc_ok: true,
};
for skipped in [corrupt, empty, non_lifecycle] {
let d = drain(vec![skipped]);
assert!(
!dispatch_confirmed_from_messages(Some(&d)),
"a corrupt/empty/non-LIFECYCLE frame must not confirm dispatch",
);
}
}
#[test]
fn cell_verdict_gate_order_and_messages() {
let base = |attach: AttachOutcome, dispatched: bool, timed_out: bool| VerifierVmResult {
stats: Vec::new(),
scheduler_log: String::new(),
attach,
dispatched,
timed_out,
};
assert_eq!(
base(AttachOutcome::Attached, true, false).cell_verdict(),
Ok(()),
);
let no_dispatch = base(AttachOutcome::Attached, false, false).cell_verdict();
assert!(
no_dispatch
.as_ref()
.unwrap_err()
.contains("did not dispatch"),
"dispatch gate must name the failure: {no_dispatch:?}",
);
let attach_fail = base(AttachOutcome::Died, true, false).cell_verdict();
assert!(
attach_fail
.as_ref()
.unwrap_err()
.contains("did not turn on"),
"attach gate must win over dispatch: {attach_fail:?}",
);
let hung = base(AttachOutcome::Attached, true, true).cell_verdict();
assert!(
hung.as_ref().unwrap_err().contains("timed out"),
"timed_out must win: {hung:?}",
);
let both = base(AttachOutcome::Died, false, false).cell_verdict();
assert!(
both.as_ref().unwrap_err().contains("did not turn on"),
"attach failure reported before dispatch failure: {both:?}",
);
}
#[test]
fn attach_outcome_failure_reason() {
assert_eq!(AttachOutcome::Attached.failure_reason(), None);
assert!(
AttachOutcome::Died
.failure_reason()
.unwrap()
.contains("exited during BPF load"),
);
assert!(
AttachOutcome::NotAttached(String::new())
.failure_reason()
.unwrap()
.contains("never reached sched_ext 'enabled'"),
);
assert_eq!(
AttachOutcome::NotAttached("sysfs absent".to_string()).failure_reason(),
Some("scheduler never reached sched_ext 'enabled': sysfs absent".to_string()),
);
assert!(
AttachOutcome::Unconfirmed
.failure_reason()
.unwrap()
.contains("attach unconfirmed"),
);
}
#[test]
fn format_verifier_output_timed_out_shows_unknown() {
let result = VerifierVmResult {
stats: Vec::new(),
scheduler_log: String::new(),
attach: AttachOutcome::Attached,
dispatched: false,
timed_out: true,
};
let out = format_verifier_output("verifier", &result, false);
assert!(
out.contains("scheduler: UNKNOWN — VM timed out"),
"timed-out run must show UNKNOWN: {out}",
);
assert!(
!out.contains("scheduler: attached"),
"timed-out run must not claim attached: {out}",
);
}
#[test]
fn format_verifier_output_attached_not_dispatched_shows_not_confirmed() {
let result = VerifierVmResult {
stats: Vec::new(),
scheduler_log: String::new(),
attach: AttachOutcome::Attached,
dispatched: false,
timed_out: false,
};
let out = format_verifier_output("verifier", &result, false);
assert!(
out.contains("scheduler: attached"),
"attached run must show the attach line: {out}",
);
assert!(
out.contains("dispatch: NOT CONFIRMED"),
"attached-but-not-dispatched must render the NOT CONFIRMED signal: {out}",
);
}
#[test]
fn parse_verifier_stats_full_line() {
let log = "processed 1234 insns (limit 1000000) max_states_per_insn 5 total_states 200 peak_states 50 mark_read 10\nverification time 42 usec\nstack depth 32+0\n";
let vs = parse_verifier_stats(log);
assert_eq!(vs.processed_insns, 1234);
assert_eq!(vs.total_states, 200);
assert_eq!(vs.peak_states, 50);
assert_eq!(vs.time_usec, Some(42));
assert_eq!(vs.stack_depth.as_deref(), Some("32+0"));
}
#[test]
fn parse_verifier_stats_insns_only() {
let log = "processed 500 insns (limit 1000000) max_states_per_insn 1 total_states 10 peak_states 3 mark_read 0\n";
let vs = parse_verifier_stats(log);
assert_eq!(vs.processed_insns, 500);
assert_eq!(vs.total_states, 10);
assert_eq!(vs.peak_states, 3);
assert!(vs.time_usec.is_none());
assert!(vs.stack_depth.is_none());
}
#[test]
fn parse_verifier_stats_empty() {
let vs = parse_verifier_stats("");
assert_eq!(vs.processed_insns, 0);
assert_eq!(vs.total_states, 0);
assert_eq!(vs.peak_states, 0);
assert!(vs.time_usec.is_none());
assert!(vs.stack_depth.is_none());
}
#[test]
fn parse_verifier_stats_garbage_lines() {
let log = "some random output\nnot a stats line\n";
let vs = parse_verifier_stats(log);
assert_eq!(vs.processed_insns, 0);
assert_eq!(vs.total_states, 0);
assert!(vs.time_usec.is_none());
}
#[test]
fn parse_verifier_stats_time_without_insns() {
let log = "verification time 100 usec\nstack depth 64\n";
let vs = parse_verifier_stats(log);
assert_eq!(vs.processed_insns, 0);
assert_eq!(vs.time_usec, Some(100));
assert_eq!(vs.stack_depth.as_deref(), Some("64"));
}
#[test]
fn parse_verifier_stats_multi_subprogram_stack() {
let log = "processed 42 insns (limit 1000000) max_states_per_insn 1 total_states 5 peak_states 2 mark_read 0\nstack depth 32+16+8\n";
let vs = parse_verifier_stats(log);
assert_eq!(vs.processed_insns, 42);
assert_eq!(vs.stack_depth.as_deref(), Some("32+16+8"));
}
#[test]
fn parse_verifier_stats_noise_between_lines() {
let log = "\
libbpf: loading something
processed 999 insns (limit 1000000) max_states_per_insn 3 total_states 77 peak_states 20 mark_read 5
libbpf: prog 'dispatch': attached
verification time 7 usec
stack depth 48+0
";
let vs = parse_verifier_stats(log);
assert_eq!(vs.processed_insns, 999);
assert_eq!(vs.total_states, 77);
assert_eq!(vs.peak_states, 20);
assert_eq!(vs.time_usec, Some(7));
assert_eq!(vs.stack_depth.as_deref(), Some("48+0"));
}
#[test]
fn parse_verifier_stats_partial_insns_line() {
let log = "processed 123\n";
let vs = parse_verifier_stats(log);
assert_eq!(vs.processed_insns, 123);
assert_eq!(vs.total_states, 0);
assert_eq!(vs.peak_states, 0);
}
#[test]
fn parse_verifier_stats_only_stack_depth() {
let log = "stack depth 128\n";
let vs = parse_verifier_stats(log);
assert_eq!(vs.stack_depth.as_deref(), Some("128"));
assert_eq!(vs.processed_insns, 0);
}
#[test]
fn parse_verifier_stats_zero_insns() {
let log = "processed 0 insns (limit 1000000) max_states_per_insn 0 total_states 0 peak_states 0 mark_read 0\n";
let vs = parse_verifier_stats(log);
assert_eq!(vs.processed_insns, 0);
assert_eq!(vs.total_states, 0);
assert_eq!(vs.peak_states, 0);
}
#[test]
fn parse_verifier_stats_large_values() {
let log = "processed 999999 insns (limit 1000000) max_states_per_insn 100 total_states 50000 peak_states 12345 mark_read 9999\nverification time 123456 usec\n";
let vs = parse_verifier_stats(log);
assert_eq!(vs.processed_insns, 999999);
assert_eq!(vs.total_states, 50000);
assert_eq!(vs.peak_states, 12345);
assert_eq!(vs.time_usec, Some(123456));
}
#[test]
fn parse_verifier_stats_stack_depth_single() {
let log = "stack depth 64\n";
let vs = parse_verifier_stats(log);
assert_eq!(vs.stack_depth.as_deref(), Some("64"));
}
#[test]
fn parse_verifier_stats_stack_depth_many_subprograms() {
let log = "stack depth 32+16+8+0+0\n";
let vs = parse_verifier_stats(log);
assert_eq!(vs.stack_depth.as_deref(), Some("32+16+8+0+0"));
}
#[test]
fn parse_verifier_stats_multiple_processed_lines_takes_last() {
let log = "processed 100 insns (limit 1000000) max_states_per_insn 1 total_states 5 peak_states 2 mark_read 0\nprocessed 200 insns (limit 1000000) max_states_per_insn 2 total_states 10 peak_states 4 mark_read 0\n";
let vs = parse_verifier_stats(log);
assert_eq!(vs.processed_insns, 200);
assert_eq!(vs.total_states, 10);
}
#[test]
fn parse_verifier_stats_complexity_error_with_stats() {
let log = "\
func#0 @0
0: R1=ctx() R10=fp0
1: (bf) r6 = r1 ; R1=ctx() R6_w=ctx()
back-edge from insn 42 to 10
BPF program is too complex
processed 131071 insns (limit 131072) max_states_per_insn 12 total_states 9999 peak_states 5000 mark_read 800
verification time 250000 usec
stack depth 96+32
";
let vs = parse_verifier_stats(log);
assert_eq!(vs.processed_insns, 131071);
assert_eq!(vs.total_states, 9999);
assert_eq!(vs.peak_states, 5000);
assert_eq!(vs.time_usec, Some(250000));
assert_eq!(vs.stack_depth.as_deref(), Some("96+32"));
}
#[test]
fn parse_verifier_stats_complexity_error_no_stats() {
let log = "\
func#0 @0
0: R1=ctx() R10=fp0
R1 type=ctx expected=fp
";
let vs = parse_verifier_stats(log);
assert_eq!(vs.processed_insns, 0);
assert_eq!(vs.total_states, 0);
assert!(vs.time_usec.is_none());
assert!(vs.stack_depth.is_none());
}
#[test]
fn parse_verifier_stats_loop_warning_with_stats() {
let log = "\
infinite loop detected at insn 15
back-edge from insn 30 to 15
processed 500 insns (limit 1000000) max_states_per_insn 3 total_states 40 peak_states 15 mark_read 5
verification time 100 usec
";
let vs = parse_verifier_stats(log);
assert_eq!(vs.processed_insns, 500);
assert_eq!(vs.total_states, 40);
assert_eq!(vs.peak_states, 15);
assert_eq!(vs.time_usec, Some(100));
}
#[test]
fn parse_verifier_stats_processed_no_number() {
let log = "processed\n";
let vs = parse_verifier_stats(log);
assert_eq!(vs.processed_insns, 0);
}
#[test]
fn parse_verifier_stats_keyword_at_end_no_value() {
let log = "processed 100 insns (limit 1000000) max_states_per_insn 1 total_states\n";
let vs = parse_verifier_stats(log);
assert_eq!(vs.processed_insns, 100);
assert_eq!(vs.total_states, 0);
}
#[test]
fn parse_verifier_stats_non_numeric_values() {
let log = "processed 100 insns (limit 1000000) max_states_per_insn 1 total_states abc peak_states xyz mark_read 0\n";
let vs = parse_verifier_stats(log);
assert_eq!(vs.processed_insns, 100);
assert_eq!(vs.total_states, 0);
assert_eq!(vs.peak_states, 0);
}
#[test]
fn parse_verifier_stats_verification_time_no_number() {
let log = "verification time unknown usec\n";
let vs = parse_verifier_stats(log);
assert!(vs.time_usec.is_none());
}
#[test]
fn parse_verifier_stats_stack_depth_empty() {
let log = "stack depth \n";
let vs = parse_verifier_stats(log);
assert!(vs.stack_depth.is_none());
}
#[test]
fn parse_verifier_stats_peak_states_at_end() {
let log = "processed 50 insns (limit 1000000) max_states_per_insn 1 total_states 10 peak_states\n";
let vs = parse_verifier_stats(log);
assert_eq!(vs.processed_insns, 50);
assert_eq!(vs.total_states, 10);
assert_eq!(vs.peak_states, 0);
}
#[test]
fn parse_verifier_stats_windows_line_endings() {
let log = "processed 42 insns (limit 1000000) max_states_per_insn 1 total_states 5 peak_states 2 mark_read 0\r\nverification time 10 usec\r\nstack depth 16\r\n";
let vs = parse_verifier_stats(log);
assert_eq!(vs.processed_insns, 42);
assert_eq!(vs.time_usec, Some(10));
assert!(vs.stack_depth.is_some());
}
#[test]
fn normalize_plain_instruction() {
assert_eq!(
normalize_verifier_line("100: (07) r1 += 8"),
"100: (07) r1 += 8"
);
}
#[test]
fn normalize_strips_frame_annotation() {
assert_eq!(
normalize_verifier_line("3006: (07) r9 += 1 ; frame1: R9_w=2"),
"3006: (07) r9 += 1"
);
}
#[test]
fn normalize_strips_register_annotation() {
assert_eq!(
normalize_verifier_line("42: (bf) r6 = r1 ; R1=ctx() R6_w=ctx()"),
"42: (bf) r6 = r1"
);
}
#[test]
fn normalize_standalone_register_dump() {
assert_eq!(
normalize_verifier_line("3041: frame1: R0_w=scalar()"),
"3041:"
);
}
#[test]
fn normalize_goto_inline_state() {
assert_eq!(
normalize_verifier_line(
"3026: (b5) if r6 <= 0x11dc0 goto pc+2 3029: frame1: R0=1 R6=scalar()"
),
"3026: (b5) if r6 <= 0x11dc0 goto pc+2"
);
}
#[test]
fn normalize_goto_no_inline_state() {
assert_eq!(
normalize_verifier_line("50: (05) goto pc+10"),
"50: (05) goto pc+10"
);
}
#[test]
fn normalize_non_instruction_line() {
assert_eq!(normalize_verifier_line("func#0 @0"), "func#0 @0");
}
#[test]
fn normalize_empty() {
assert_eq!(normalize_verifier_line(""), "");
}
#[test]
fn normalize_goto_negative_offset() {
assert_eq!(
normalize_verifier_line("50: (05) goto pc-10 60: frame1: R0=1"),
"50: (05) goto pc-10"
);
}
#[test]
fn normalize_semicolon_source_comment() {
let line = "100: (07) r1 += 8 ; for (int j = 0; j < n; j++)";
assert_eq!(normalize_verifier_line(line), line);
}
#[test]
fn normalize_semicolon_return_value_comment() {
let line = "200: (b7) r0 = 0 ; Return value";
assert_eq!(normalize_verifier_line(line), line);
}
#[test]
fn normalize_standalone_bare_register_dump() {
assert_eq!(
normalize_verifier_line("3029: R0=1 R6=scalar(id=1)"),
"3029:"
);
}
#[test]
fn normalize_standalone_r10_dump() {
assert_eq!(normalize_verifier_line("42: R10=fp0"), "42:");
}
fn repeating_log(prefix: usize, period: usize, reps: usize, suffix: usize) -> String {
let mut lines = Vec::new();
for i in 0..prefix {
lines.push(format!("{}: (07) r1 += {i}", 1000 + i));
}
for rep in 0..reps {
for j in 0..period {
let insn = 100 + j;
lines.push(format!(
"{insn}: (bf) r{} = r{} ; frame1: R{}_w={}",
j % 10,
(j + 1) % 10,
j % 10,
rep * 100 + j
));
}
}
for i in 0..suffix {
lines.push(format!("{}: (95) exit_{i}", 2000 + i));
}
lines.join("\n")
}
#[test]
fn detect_cycle_basic() {
let log = repeating_log(0, 10, 8, 0);
let lines: Vec<&str> = log.lines().collect();
let result = detect_cycle(&lines);
assert!(result.is_some(), "should detect cycle");
let (start, period, count) = result.unwrap();
assert_eq!(period, 10);
assert!(count >= 6, "count={count}");
assert_eq!(start, 0);
}
#[test]
fn detect_cycle_with_prefix_suffix() {
let log = repeating_log(5, 10, 8, 5);
let lines: Vec<&str> = log.lines().collect();
let result = detect_cycle(&lines);
assert!(result.is_some(), "should detect cycle with prefix/suffix");
let (_start, period, count) = result.unwrap();
assert_eq!(period, 10);
assert!(count >= 6);
}
#[test]
fn detect_cycle_too_few_reps() {
let log = repeating_log(0, 10, 2, 0);
let lines: Vec<&str> = log.lines().collect();
assert!(detect_cycle(&lines).is_none());
}
#[test]
fn detect_cycle_too_few_lines() {
let lines: Vec<String> = (0..20)
.map(|i| format!("{}: (07) r1 += {i}", 100 + i % 3))
.collect();
let refs: Vec<&str> = lines.iter().map(|s| s.as_str()).collect();
assert!(detect_cycle(&refs).is_none());
}
#[test]
fn detect_cycle_no_cycle() {
let lines: Vec<String> = (0..100).map(|i| format!("{i}: unique_insn_{i}")).collect();
let refs: Vec<&str> = lines.iter().map(|s| s.as_str()).collect();
assert!(detect_cycle(&refs).is_none());
}
#[test]
fn detect_cycle_empty() {
let empty: Vec<&str> = vec![];
assert!(detect_cycle(&empty).is_none());
}
#[test]
fn detect_cycle_exact_boundary() {
let log = repeating_log(0, 5, 6, 0);
let lines: Vec<&str> = log.lines().collect();
assert_eq!(lines.len(), 30);
let result = detect_cycle(&lines);
assert!(result.is_some(), "boundary case should detect cycle");
let (_start, period, count) = result.unwrap();
assert_eq!(period, 5);
assert_eq!(count, 6);
}
#[test]
fn collapse_cycles_empty_string() {
assert_eq!(collapse_cycles(""), "");
}
#[test]
fn collapse_cycles_basic() {
let log = repeating_log(2, 10, 8, 2);
let collapsed = collapse_cycles(&log);
assert!(collapsed.contains("identical iterations omitted"));
assert!(collapsed.contains("8x of the following 10 lines"));
assert!(collapsed.contains("end repeat"));
assert!(collapsed.lines().count() < log.lines().count());
}
#[test]
fn collapse_cycles_no_cycle() {
let log = "line 1\nline 2\nline 3\n";
let collapsed = collapse_cycles(log);
assert_eq!(collapsed, log);
}
#[test]
fn collapse_cycles_preserves_stats() {
let mut log = repeating_log(0, 10, 8, 0);
log.push_str("\nprocessed 1000 insns (limit 1000000) max_states_per_insn 5 total_states 100 peak_states 30 mark_read 10\n");
let collapsed = collapse_cycles(&log);
assert!(collapsed.contains("processed 1000 insns"));
}
#[test]
fn collapse_cycles_with_register_annotations() {
let mut lines = Vec::new();
lines.push("0: (07) r1 += 1".to_string());
for rep in 0..8 {
for j in 0..6 {
let insn = 100 + j;
lines.push(format!(
"{insn}: (bf) r{} = r{} ; frame1: R{}_w={}",
j % 10,
(j + 1) % 10,
j % 10,
rep * 100 + j
));
}
}
lines.push("200: (95) exit".to_string());
let log = lines.join("\n");
let collapsed = collapse_cycles(&log);
assert!(collapsed.contains("identical iterations omitted"));
}
fn prog(name: &str, verified_insns: u32) -> ProgStats {
ProgStats {
name: name.to_string(),
verified_insns,
}
}
#[test]
fn build_b_map_basic() {
let stats_b = vec![prog("dispatch", 500)];
let map = build_b_map(&stats_b);
assert_eq!(map.get("dispatch"), Some(&500));
}
#[test]
fn build_b_map_empty() {
let map = build_b_map(&[]);
assert!(map.is_empty());
}
#[test]
fn build_diff_rows_matching_programs() {
let stats_a = vec![prog("dispatch", 500)];
let mut b_map = HashMap::new();
b_map.insert("dispatch".to_string(), 300u64);
let rows = build_diff_rows(&stats_a, &b_map);
assert_eq!(rows.len(), 1);
assert_eq!(rows[0].name, "dispatch");
assert_eq!(rows[0].a, 500);
assert_eq!(rows[0].b, 300);
assert_eq!(rows[0].delta, 200);
}
#[test]
fn build_diff_rows_program_missing_from_b() {
let stats_a = vec![prog("new_prog", 100)];
let b_map = HashMap::new();
let rows = build_diff_rows(&stats_a, &b_map);
assert_eq!(rows.len(), 1);
assert_eq!(rows[0].a, 100);
assert_eq!(rows[0].b, 0);
assert_eq!(rows[0].delta, 100);
}
#[test]
fn build_diff_rows_negative_delta() {
let stats_a = vec![prog("dispatch", 200)];
let mut b_map = HashMap::new();
b_map.insert("dispatch".to_string(), 500u64);
let rows = build_diff_rows(&stats_a, &b_map);
assert_eq!(rows[0].delta, -300);
}
#[test]
fn build_diff_rows_empty_a() {
let b_map = HashMap::new();
let rows = build_diff_rows(&[], &b_map);
assert!(rows.is_empty());
}
fn unrolled_verifier_log(copies: usize, body_len: usize) -> String {
let ops = [
"(85) call bpf_ktime_get_ns#5",
"(bf) r2 = r0",
"(77) r0 >>= 16",
"(af) r1 ^= r0",
"(77) r2 >>= 32",
"(0f) r1 += r2",
"(24) w1 *= 7",
"(04) w1 += 1",
];
let mut lines = Vec::new();
lines.push("func#0 @0".to_string());
lines.push("0: R1=ctx() R10=fp0".to_string());
let mut addr = 10;
for copy in 0..copies {
for (j, op) in ops.iter().enumerate().take(body_len) {
lines.push(format!(
"{}: {op} ; R0_w=scalar(id={})",
addr,
copy * 100 + j
));
addr += 1;
}
}
lines.push(format!("{addr}: (05) goto pc-1"));
lines.push(
"processed 1000 insns (limit 1000000) max_states_per_insn 3 \
total_states 50 peak_states 20 mark_read 5"
.to_string(),
);
lines.join("\n")
}
#[test]
fn detect_cycle_unrolled_loop() {
let log = unrolled_verifier_log(8, 6);
let lines: Vec<&str> = log.lines().collect();
let result = detect_cycle(&lines);
assert!(result.is_some(), "should detect cycle in unrolled loop");
let (_start, period, count) = result.unwrap();
assert_eq!(period, 6);
assert!(count >= 6, "count={count}");
}
#[test]
fn collapse_cycles_unrolled_loop() {
let log = unrolled_verifier_log(8, 6);
let collapsed = collapse_cycles(&log);
assert!(
collapsed.contains("identical iterations omitted"),
"should collapse unrolled loop"
);
assert!(collapsed.lines().count() < log.lines().count());
}
#[test]
fn extract_verifier_log_basic() {
let log = "\
libbpf: prog 'dispatch': BPF program load failed: -22
-- BEGIN PROG LOAD LOG --
func#0 @0
0: R1=ctx() R10=fp0
processed 100 insns (limit 1000000) max_states_per_insn 1 total_states 5 peak_states 2 mark_read 0
-- END PROG LOAD LOG --
libbpf: failed to load object 'ktstr_ops'
";
let extracted = extract_verifier_log(log);
assert!(extracted.is_some());
let v = extracted.unwrap();
assert!(v.starts_with("func#0 @0"));
assert!(v.contains("processed 100 insns"));
assert!(!v.contains("BEGIN PROG LOAD LOG"));
assert!(!v.contains("END PROG LOAD LOG"));
assert!(!v.contains("libbpf:"));
}
#[test]
fn extract_verifier_log_none_without_markers() {
let log = "func#0 @0\n0: R1=ctx()\nprocessed 50 insns\n";
assert!(extract_verifier_log(log).is_none());
}
#[test]
fn extract_verifier_log_empty() {
assert!(extract_verifier_log("").is_none());
}
#[test]
fn extract_verifier_log_attack1_stats_parse() {
let blob = "\
libbpf: prog 'ktstr_ops_dispatch': BPF program load failed: -22
libbpf: -- BEGIN PROG LOAD LOG --
func#0 @0
0: R1=ctx() R10=fp0
1: (bf) r6 = r1 ; R1=ctx() R6_w=ctx()
back-edge from insn 42 to 10
BPF program is too complex
processed 131071 insns (limit 131072) max_states_per_insn 12 total_states 9999 peak_states 5000 mark_read 800
verification time 250000 usec
stack depth 96+32
libbpf: -- END PROG LOAD LOG --
libbpf: failed to load BPF skeleton 'ktstr_ops': -22
";
let extracted = extract_verifier_log(blob);
assert!(extracted.is_some(), "should find markers");
let v = extracted.unwrap();
let vs = parse_verifier_stats(v);
assert_eq!(vs.processed_insns, 131071);
assert_eq!(vs.total_states, 9999);
assert_eq!(vs.peak_states, 5000);
assert_eq!(vs.time_usec, Some(250000));
assert_eq!(vs.stack_depth.as_deref(), Some("96+32"));
let vs_raw = parse_verifier_stats(blob);
assert_eq!(vs_raw.processed_insns, 131071);
}
#[test]
fn extract_verifier_log_attack3_no_false_collapse() {
let blob = "\
libbpf: prog 'init': BPF program load failed: -22
libbpf: -- BEGIN PROG LOAD LOG --
func#0 @0
0: R1=ctx() R10=fp0
1: (bf) r6 = r1
2: (07) r6 += 8
3: (61) r0 = *(u32 *)(r6 + 0)
4: (95) exit
processed 5 insns (limit 1000000) max_states_per_insn 1 total_states 3 peak_states 1 mark_read 0
libbpf: -- END PROG LOAD LOG --
libbpf: prog 'dispatch': BPF program load failed: -22
libbpf: -- BEGIN PROG LOAD LOG --
func#1 @10
10: R1=ctx() R10=fp0
11: (bf) r7 = r1
12: (85) call bpf_ktime_get_ns#5
13: (77) r0 >>= 32
14: (95) exit
processed 5 insns (limit 1000000) max_states_per_insn 1 total_states 3 peak_states 1 mark_read 0
libbpf: -- END PROG LOAD LOG --
libbpf: prog 'enqueue': BPF program load failed: -22
libbpf: -- BEGIN PROG LOAD LOG --
func#2 @20
20: R1=ctx() R10=fp0
21: (b7) r0 = 0
22: (63) *(u32 *)(r10 - 4) = r0
23: (61) r1 = *(u32 *)(r10 - 4)
24: (95) exit
processed 5 insns (limit 1000000) max_states_per_insn 1 total_states 3 peak_states 1 mark_read 0
libbpf: -- END PROG LOAD LOG --
libbpf: failed to load BPF skeleton 'ktstr_ops': -22
";
let extracted = extract_verifier_log(blob);
assert!(extracted.is_some());
let v = extracted.unwrap();
assert!(v.contains("func#0 @0"), "should get first program's log");
assert!(!v.contains("func#1"), "should not include second program");
let collapsed = collapse_cycles(v);
assert!(
!collapsed.contains("identical iterations omitted"),
"must not false-collapse distinct program logs"
);
}
#[test]
fn snapshot_format_verifier_output_no_log() {
let result = VerifierVmResult {
stats: vec![
ProgStats {
name: "enqueue".into(),
verified_insns: 500,
},
ProgStats {
name: "dispatch".into(),
verified_insns: 1200,
},
ProgStats {
name: "init".into(),
verified_insns: 300,
},
],
scheduler_log: String::new(),
attach: AttachOutcome::Attached,
dispatched: true,
timed_out: false,
};
insta::assert_snapshot!(format_verifier_output("default", &result, false));
}
#[test]
fn snapshot_format_verifier_output_with_log() {
let log = "\
-- BEGIN PROG LOAD LOG --\n\
func#0 @0\n\
0: R1=ctx() R10=fp0\n\
processed 42 insns (limit 1000000) max_states_per_insn 1 total_states 10 peak_states 8 mark_read 5\n\
-- END PROG LOAD LOG --";
let result = VerifierVmResult {
stats: vec![ProgStats {
name: "enqueue".into(),
verified_insns: 42,
}],
scheduler_log: log.into(),
attach: AttachOutcome::Died,
dispatched: false,
timed_out: false,
};
insta::assert_snapshot!(format_verifier_output("llc+steal", &result, false));
}
#[test]
fn snapshot_format_verifier_diff() {
let stats_a = vec![
ProgStats {
name: "enqueue".into(),
verified_insns: 500,
},
ProgStats {
name: "dispatch".into(),
verified_insns: 1200,
},
ProgStats {
name: "init".into(),
verified_insns: 300,
},
];
let stats_b = vec![
ProgStats {
name: "enqueue".into(),
verified_insns: 480,
},
ProgStats {
name: "dispatch".into(),
verified_insns: 1350,
},
ProgStats {
name: "init".into(),
verified_insns: 300,
},
];
insta::assert_snapshot!(format_verifier_diff("default", &stats_a, "llc", &stats_b));
}
#[test]
fn snapshot_format_verifier_diff_missing_program() {
let stats_a = vec![
ProgStats {
name: "enqueue".into(),
verified_insns: 500,
},
ProgStats {
name: "new_prog".into(),
verified_insns: 100,
},
];
let stats_b = vec![ProgStats {
name: "enqueue".into(),
verified_insns: 500,
}];
insta::assert_snapshot!(format_verifier_diff("A", &stats_a, "B", &stats_b));
}
#[test]
fn extract_verifier_log_between_begin_end_markers() {
let blob = "\
unrelated preamble\n\
libbpf: -- BEGIN PROG LOAD LOG --\n\
processed 1234 insns (limit 1000000) max_states_per_insn 5 total_states 200 peak_states 50 mark_read 10\n\
libbpf: -- END PROG LOAD LOG --\n\
trailing diagnostics\n";
let log = extract_verifier_log(blob).expect("markers present");
assert!(log.contains("processed 1234 insns"));
assert!(!log.contains("BEGIN PROG LOAD LOG"));
assert!(!log.contains("END PROG LOAD LOG"));
}
#[test]
fn extract_verifier_log_returns_none_when_markers_absent() {
assert!(extract_verifier_log("no markers in here").is_none());
assert!(extract_verifier_log("only BEGIN marker -- BEGIN PROG LOAD LOG --").is_none());
}
#[test]
fn extract_verifier_log_consistent_with_parse_sched_output() {
let sched_inner = "\
libbpf: -- BEGIN PROG LOAD LOG --\n\
processed 7 insns (limit 1000000) max_states_per_insn 1 total_states 1 peak_states 1 mark_read 0\n\
libbpf: -- END PROG LOAD LOG --\n";
let vm_output = format!(
"kernel boot junk\n{SCHED_OUTPUT_START}\n{sched_inner}{SCHED_OUTPUT_END}\nafterward\n",
);
let sched = parse_sched_output(&vm_output).expect("SCHED_OUTPUT block");
let verifier_log = extract_verifier_log(sched).expect("verifier markers");
assert!(verifier_log.contains("processed 7 insns"));
assert!(!verifier_log.contains("SCHED_OUTPUT"));
assert!(!verifier_log.contains("BEGIN PROG LOAD LOG"));
}
#[test]
fn parse_sched_output_valid() {
let output = format!(
"noise\n{SCHED_OUTPUT_START}\nscheduler log line 1\nline 2\n{SCHED_OUTPUT_END}\nmore"
);
let parsed = parse_sched_output(&output);
assert!(parsed.is_some());
let content = parsed.unwrap();
assert!(content.contains("scheduler log line 1"));
assert!(content.contains("line 2"));
}
#[test]
fn parse_sched_output_missing_start() {
let output = format!("no start\n{SCHED_OUTPUT_END}\n");
assert!(parse_sched_output(&output).is_none());
}
#[test]
fn parse_sched_output_missing_end() {
let output = format!("{SCHED_OUTPUT_START}\nsome content");
assert!(parse_sched_output(&output).is_none());
}
#[test]
fn parse_sched_output_empty_content() {
let output = format!("{SCHED_OUTPUT_START}\n\n{SCHED_OUTPUT_END}");
assert!(parse_sched_output(&output).is_none());
}
#[test]
fn parse_sched_output_with_stack_traces() {
let stack = "do_enqueue_task+0x1a0/0x380\nbalance_one+0x50/0x100\n";
let output = format!("{SCHED_OUTPUT_START}\n{stack}\n{SCHED_OUTPUT_END}");
let parsed = parse_sched_output(&output).unwrap();
assert!(parsed.contains("do_enqueue_task"));
assert!(parsed.contains("balance_one"));
}
#[test]
fn parse_sched_output_rfind_survives_end_marker_in_content() {
let content = format!("line1\nfake {SCHED_OUTPUT_END} inside\nline3");
let output = format!("{SCHED_OUTPUT_START}\n{content}\n{SCHED_OUTPUT_END}\n");
let parsed = parse_sched_output(&output).unwrap();
assert!(
parsed.contains("line3"),
"rfind must keep content after an embedded END marker: {parsed:?}"
);
assert!(
parsed.contains("fake"),
"content before the embedded marker must also survive: {parsed:?}"
);
}
#[test]
fn parse_sched_output_partial_well_formed_matches_strict() {
let output = format!(
"noise\n{SCHED_OUTPUT_START}\nscheduler log line 1\nline 2\n{SCHED_OUTPUT_END}\nmore"
);
assert_eq!(
parse_sched_output_partial(&output),
parse_sched_output(&output),
);
}
#[test]
fn parse_sched_output_partial_missing_end_returns_partial() {
let output = format!("{SCHED_OUTPUT_START}\nstack frame 1\nstack frame 2");
assert!(parse_sched_output(&output).is_none());
let partial = parse_sched_output_partial(&output).unwrap();
assert!(partial.contains("stack frame 1"));
assert!(partial.contains("stack frame 2"));
}
#[test]
fn parse_sched_output_partial_missing_start_returns_none() {
let output = format!("garbage\n{SCHED_OUTPUT_END}\n");
assert!(parse_sched_output_partial(&output).is_none());
}
#[test]
fn parse_sched_output_partial_empty_content_returns_none() {
let output = format!("{SCHED_OUTPUT_START}\n");
assert!(parse_sched_output_partial(&output).is_none());
}
}