inoculate/
qemu.rs

1use crate::{
2    term::{ColorMode, OwoColorize},
3    BootMode, Result,
4};
5use color_eyre::{
6    eyre::{ensure, format_err, WrapErr},
7    Help, SectionExt,
8};
9use mycotest::TestName;
10use std::{
11    collections::BTreeMap,
12    fmt,
13    path::Path,
14    process::{Child, Command, ExitStatus, Stdio},
15    time::Duration,
16};
17
18#[derive(Debug, clap::Subcommand)]
19pub enum Cmd {
20    /// Builds a bootable disk image and runs it in QEMU (implies: `build`).
21    Run {
22        /// Redirect the VM's serial output to stdout
23        #[clap(long, short)]
24        serial: bool,
25
26        /// Extra arguments passed to QEMU
27        #[clap(flatten)]
28        qemu_settings: Settings,
29    },
30    /// Builds a bootable disk image with tests enabled, and runs the tests in QEMU.
31    Test {
32        /// Timeout for failing test run, in seconds.
33        ///
34        /// If a test run doesn't complete before this timeout has elapsed, the
35        /// QEMU VM is killed and the test run is assumed to have failed.
36        ///
37        /// Note that this timeout applies to the entire test run, including
38        /// booting the kernel and running the whole kernel test suite, rather
39        /// than to each individual test.
40        ///
41        /// By default, this is 20 minutes (1200 seconds).
42        #[clap(long, value_parser = parse_secs, default_value = "1200")]
43        timeout_secs: Duration,
44
45        /// Disables capturing test serial output.
46        #[clap(long)]
47        nocapture: bool,
48
49        /// Show captured serial output of successful tests
50        #[clap(long)]
51        show_output: bool,
52
53        /// Extra arguments passed to QEMU
54        #[clap(flatten)]
55        qemu_settings: Settings,
56    },
57}
58
59#[derive(Debug, clap::Args)]
60pub struct Settings {
61    /// Listen for GDB connections.
62    #[clap(long, short)]
63    gdb: bool,
64
65    /// The TCP port to listen for debug connections on.
66    #[clap(long, default_value = "1234")]
67    gdb_port: u16,
68
69    /// Extra arguments passed to QEMU
70    #[clap(raw = true)]
71    qemu_args: Vec<String>,
72}
73
74#[derive(Debug)]
75struct TestResults {
76    tests: usize,
77    completed: usize,
78    failed: BTreeMap<TestName<'static, String>, Vec<String>>,
79    panicked: usize,
80    faulted: usize,
81    total: usize,
82}
83
84impl Cmd {
85    fn should_capture(&self) -> bool {
86        match self {
87            Cmd::Test { .. } => true,
88            Cmd::Run { serial: true, .. } => {
89                tracing::debug!("running normally with `--serial`, will not capture");
90                false
91            }
92            Cmd::Run { qemu_settings, .. }
93                if qemu_settings
94                    .qemu_args
95                    .iter()
96                    .map(String::as_str)
97                    .any(|s| s == "-d") =>
98            {
99                tracing::debug!("qemu args contains a `-d` flag, skipping capturing");
100                false
101            }
102            _ => true,
103        }
104    }
105
106    #[tracing::instrument(skip(self), level = "debug")]
107    fn spawn_qemu(&self, qemu: &mut Command, binary: &Path) -> Result<Child> {
108        let (Cmd::Run { qemu_settings, .. } | Cmd::Test { qemu_settings, .. }) = self;
109
110        if self.should_capture() {
111            qemu.stdout(Stdio::piped()).stderr(Stdio::piped());
112        }
113
114        // if we're running gdb, ensure that qemu doesn't exit, and block qemu
115        // from inheriting stdin, so it's free for gdb to use.
116        if qemu_settings.gdb {
117            qemu.stdin(Stdio::piped()).arg("-no-shutdown");
118        }
119
120        let mut child = qemu.spawn().context("spawning qemu failed")?;
121
122        // If the `--gdb` flag was passed, try to run gdb & connect to the kernel.
123        if qemu_settings.gdb {
124            crate::gdb::run_gdb(binary, qemu_settings.gdb_port)?;
125            if let Err(error) = child.kill() {
126                tracing::error!(?error, "failed to kill qemu");
127            }
128        }
129
130        Ok(child)
131    }
132
133    #[tracing::instrument(skip(self, paths), level = "debug")]
134    pub fn run_qemu(&self, image: &Path, paths: &crate::Paths, boot: BootMode) -> Result<()> {
135        let mut qemu = Command::new("qemu-system-x86_64");
136        qemu.arg("-drive")
137            .arg(format!("format=raw,file={}", image.display()))
138            .arg("-no-reboot");
139        if boot == BootMode::Uefi {
140            qemu.arg("-bios").arg(ovmf_prebuilt::ovmf_pure_efi());
141        }
142
143        match self {
144            Cmd::Run {
145                serial,
146                qemu_settings,
147            } => {
148                tracing::info!(
149                    "running mycelium in QEMU ({})",
150                    paths.relative(image).display()
151                );
152                if *serial {
153                    tracing::debug!("configured QEMU to output serial on stdio");
154                    qemu.arg("-serial").arg("stdio");
155                }
156
157                qemu_settings.configure(&mut qemu);
158                qemu.arg("--no-shutdown");
159
160                let mut child = self.spawn_qemu(&mut qemu, paths.kernel_bin())?;
161                if child.stdout.is_some() {
162                    tracing::debug!("should capture qemu output");
163                    let out = child.wait_with_output()?;
164                    if out.status.success() {
165                        return Ok(());
166                    }
167
168                    let stdout = String::from_utf8_lossy(&out.stdout);
169                    let stderr = String::from_utf8_lossy(&out.stderr);
170                    let status = out.status.code();
171                    Err(format_err!("qemu exited with a non-zero status code"))
172                        .with_section(move || format!("{status:?}").header("status code:"))
173                        .with_section(move || stdout.trim().to_string().header("stdout:"))
174                        .with_section(move || stderr.trim().to_string().header("stderr:"))
175                } else {
176                    tracing::debug!("not capturing qemu output");
177                    let status = child.wait()?;
178                    if status.success() {
179                        return Ok(());
180                    }
181                    let status = status.code();
182                    Err(format_err!("qemu exited with a non-zero status code"))
183                        .with_section(move || format!("{status:?}").header("status code:"))
184                }
185            }
186
187            Cmd::Test {
188                nocapture,
189                qemu_settings,
190                timeout_secs,
191                ..
192            } => {
193                use wait_timeout::ChildExt;
194
195                // TODO(eliza):
196                const TEST_ARGS: &[&str] = &[
197                    "-device",
198                    "isa-debug-exit,iobase=0xf4,iosize=0x04",
199                    "-display",
200                    "none",
201                    "-serial",
202                    "stdio",
203                    // tell QEMU to log guest errors
204                    "-d",
205                    "guest_errors",
206                ];
207                tracing::info!("running kernel tests ({})", paths.relative(image).display());
208                qemu_settings.configure(&mut qemu);
209
210                tracing::info!(qemu.test_args = ?TEST_ARGS, "using test mode qemu args");
211                qemu.args(TEST_ARGS);
212
213                let nocapture = *nocapture;
214                let mut child = self.spawn_qemu(&mut qemu, paths.kernel_bin())?;
215                let stdout = child.stdout.take().map(|stdout| {
216                    std::thread::spawn(move || TestResults::watch_tests(stdout, nocapture))
217                });
218
219                let res = match child
220                    .wait_timeout(*timeout_secs)
221                    .context("waiting for QEMU to complete failed")?
222                {
223                    None => child
224                        .kill()
225                        .map_err(Into::into)
226                        .and_then(|_| {
227                            child
228                                .wait()
229                                .context("waiting for QEMU process to complete failed")
230                        })
231                        .context("killing QEMU process failed")
232                        .and_then(|status: ExitStatus| {
233                            Err(format_err!("test QEMU process exited with {}", status))
234                        })
235                        .with_context(|| format!("tests timed out after {:?}", *timeout_secs))
236                        .note("maybe the kernel hung or boot looped?"),
237                    Some(status) => {
238                        if let Some(code) = status.code() {
239                            if code == 33 {
240                                Ok(())
241                            } else {
242                                Err(format_err!("QEMU exited with status code {}", code))
243                            }
244                        } else {
245                            Err(format_err!("QEMU exited without a status code, wtf?"))
246                        }
247                    }
248                }
249                .context("tests failed");
250                tracing::debug!("tests done");
251
252                if let Some(res) = stdout {
253                    tracing::trace!("collecting stdout");
254                    let res = res.join().unwrap()?;
255                    eprintln!("{res}");
256                    // exit with an error if the tests failed.
257                    if !res.failed.is_empty() {
258                        std::process::exit(1);
259                    }
260
261                    Ok(())
262                } else {
263                    tracing::warn!("no stdout from QEMU process?");
264                    res
265                }
266            }
267        }
268    }
269}
270
271impl Settings {
272    fn configure(&self, cmd: &mut Command) {
273        // tell QEMU to be a generic 4-core x86_64 machine by default.
274        //
275        // this is so tests are run with the same machine regardless of whether
276        // KVM or other accelerators are available, unless a specific QEMU
277        // configuration is requested.
278        const DEFAULT_QEMU_ARGS: &[&str] = &["-cpu", "qemu64", "-smp", "cores=4"];
279        if self.gdb {
280            tracing::debug!(gdb_port = self.gdb_port, "configuring QEMU to wait for GDB");
281            cmd.arg("-S")
282                .arg("-gdb")
283                .arg(format!("tcp::{}", self.gdb_port));
284        }
285
286        if !self.qemu_args.is_empty() {
287            tracing::info!(qemu.args = ?self.qemu_args, "configuring qemu");
288            cmd.args(&self.qemu_args[..]);
289        } else {
290            tracing::info!(qemu.args = ?DEFAULT_QEMU_ARGS, "using default qemu args");
291            cmd.args(DEFAULT_QEMU_ARGS);
292        }
293    }
294}
295
296fn parse_secs(s: &str) -> Result<Duration> {
297    s.parse::<u64>()
298        .map(Duration::from_secs)
299        .context("not a valid number of seconds")
300}
301
302impl TestResults {
303    fn watch_tests(output: impl std::io::Read, nocapture: bool) -> Result<Self> {
304        use std::io::{BufRead, BufReader};
305        let mut results = Self {
306            tests: 0,
307            completed: 0,
308            failed: BTreeMap::new(),
309            total: 0,
310            panicked: 0,
311            faulted: 0,
312        };
313        let mut lines = BufReader::new(output).lines();
314        let colors = ColorMode::default();
315        let green = colors.if_color(owo_colors::style().green());
316        let red = colors.if_color(owo_colors::style().red());
317
318        while let Some(line) = lines.next() {
319            tracing::trace!(message = ?line);
320            let line = line?;
321
322            if let Some(count) = line.strip_prefix(mycotest::report::TEST_COUNT) {
323                results.total = count
324                    .trim()
325                    .parse::<usize>()
326                    .with_context(|| format!("parse string: {:?}", count.trim()))?;
327            }
328
329            if let Some(test) = TestName::parse_start(&line) {
330                let _span =
331                    tracing::debug_span!("test", "{}::{}", test.module(), test.name()).entered();
332                tracing::debug!(?test, "found a test");
333                eprint!("test {test} ...");
334                results.tests += 1;
335
336                let mut curr_output = Vec::new();
337                let mut curr_outcome = None;
338                for line in &mut lines {
339                    tracing::trace!(message = ?line);
340                    let line = match line {
341                        Err(err) => {
342                            tracing::debug!(?err, "unexpected qemu error");
343                            curr_output.push(err.to_string());
344                            break;
345                        }
346                        Ok(line) => line,
347                    };
348
349                    match TestName::parse_outcome(&line) {
350                        Ok(None) => {}
351                        Ok(Some((completed_test, outcome))) => {
352                            ensure!(
353                                test == completed_test,
354                                "an unexpected test completed (actual: {completed_test}, expected: {test}, outcome={outcome:?})",
355                            );
356                            tracing::trace!(?outcome);
357                            curr_outcome = Some(outcome);
358                            break;
359                        }
360                        Err(err) => {
361                            tracing::error!(?line, ?err, "failed to parse test outcome!");
362                            return Err(
363                                format_err!("failed to parse test outcome").note(err.to_string())
364                            )
365                            .note(format!("line: {line:?}"));
366                        }
367                    }
368                    if nocapture {
369                        println!("{line}")
370                    } else {
371                        curr_output.push(line);
372                    }
373                }
374
375                match curr_outcome {
376                    Some(Ok(())) => eprintln!(" {}", "ok".style(green)),
377                    Some(Err(mycotest::report::Failure::Fail)) => {
378                        eprintln!(" {}", "not ok!".style(red));
379                        results.failed.insert(test.to_static(), curr_output);
380                    }
381                    Some(Err(mycotest::report::Failure::Panic)) => {
382                        eprintln!(" {}", "panic!".style(red));
383                        results.failed.insert(test.to_static(), curr_output);
384                        results.panicked += 1;
385                    }
386                    Some(Err(mycotest::report::Failure::Fault)) => {
387                        eprintln!(" {}", "FAULT".style(red));
388                        results.failed.insert(test.to_static(), curr_output);
389                        results.faulted += 1;
390                    }
391                    None => {
392                        tracing::info!("qemu exited unexpectedly! wtf!");
393                        if !nocapture {
394                            curr_output.push("<AND THEN QEMU EXITS???>".to_string());
395                        }
396                        eprintln!(" {}", "exit!".style(red));
397                        results.failed.insert(test.to_static(), curr_output);
398                        break;
399                    }
400                };
401
402                results.completed += 1;
403            }
404        }
405
406        tracing::trace!("lines ended");
407
408        Ok(results)
409    }
410}
411
412impl fmt::Display for TestResults {
413    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
414        let num_failed = self.failed.len();
415        if num_failed > 0 {
416            writeln!(f, "\nfailures:")?;
417            for (test, output) in &self.failed {
418                writeln!(f, "\n---- {test} serial ----\n{}\n", &output[..].join("\n"))?;
419            }
420            writeln!(f, "\nfailures:\n")?;
421            for test in self.failed.keys() {
422                writeln!(f, "\t{test}")?;
423            }
424        }
425        let colors = ColorMode::default();
426        let res = if !self.failed.is_empty() {
427            "FAILED".style(colors.if_color(owo_colors::style().red()))
428        } else {
429            "ok".style(colors.if_color(owo_colors::style().green()))
430        };
431
432        let num_missed = self.total - (self.completed + num_failed);
433        let panicked_faulted = if self.panicked > 0 || self.faulted > 0 {
434            format!(" ({} panicked, {} faulted)", self.panicked, self.faulted)
435        } else {
436            String::new()
437        };
438        writeln!(
439            f,
440            "\ntest result: {res}. {} passed{panicked_faulted}; {num_failed} failed; {num_missed} missed; {} total",
441            self.completed - num_failed,
442            self.total
443        )?;
444
445        if num_missed > 0 {
446            writeln!(
447                f,
448                "\n{}: {num_missed} tests didn't get to run due to a panic/fault",
449                "warning".style(colors.if_color(owo_colors::style().yellow().bold())),
450            )?;
451        }
452
453        Ok(())
454    }
455}
inoculate/qemu.rs

inoculate/
qemu.rs
