diff --git a/.vscode/settings.json b/.vscode/settings.json index a6651047..fe702ca9 100644 --- a/.vscode/settings.json +++ b/.vscode/settings.json @@ -1,9 +1,8 @@ -{ +i{ "rust-analyzer.check.invocationLocation": "workspace", "rust-analyzer.cargo.buildScripts.invocationLocation": "workspace", "rust-analyzer.cargo.buildScripts.overrideCommand": [ "cargo", - "mn", "clippy", "--quiet", "--message-format=json", @@ -11,7 +10,6 @@ ], "rust-analyzer.check.overrideCommand": [ "cargo", - "mn", "clippy", "--quiet", "--message-format=json", @@ -19,4 +17,4 @@ ], "rust-analyzer.workspace.symbol.search.scope": "workspace_and_dependencies", "rust-analyzer.typing.continueCommentsOnNewline": false, -} \ No newline at end of file +} diff --git a/Cargo.lock b/Cargo.lock index 7067f851..a01c1495 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -4427,7 +4427,7 @@ dependencies = [ "httpdate", "itoa 1.0.11", "pin-project-lite", - "socket2 0.4.10", + "socket2 0.5.7", "tokio", "tower-service", "tracing 0.1.40", @@ -5695,7 +5695,10 @@ dependencies = [ "bootloader-boot-config", "camino", "clap 4.5.15", + "heck 0.5.0", "ovmf-prebuilt", + "owo-colors 4.0.0", + "supports-color 3.0.0", "tracing 0.1.40", "tracing-subscriber", ] @@ -8164,7 +8167,7 @@ version = "0.8.4" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "38d1e02fca405f6280643174a50c942219f0bbf4dbf7d480f1dd864d6f211ae5" dependencies = [ - "heck 0.4.1", + "heck 0.5.0", "proc-macro2", "quote", "syn 2.0.72", @@ -9205,7 +9208,7 @@ version = "1.6.3" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "97fee6b57c6a41524a810daee9286c02d7752c4253064d0b05472833a438f675" dependencies = [ - "cfg-if 0.1.10", + "cfg-if 1.0.0", "static_assertions", ] diff --git a/scripts/test.sh b/scripts/test.sh new file mode 100755 index 00000000..28ee68f8 --- /dev/null +++ b/scripts/test.sh @@ -0,0 +1,9 @@ +#!/usr/bin/env bash + +source scripts/_util.sh + +if confirm "test"; then +echo "ok you confirmed" +else +echo "you didn't confirm" +fi diff --git a/tools/x86_64-bootimager/Cargo.toml b/tools/x86_64-bootimager/Cargo.toml index 15777071..5a93d6df 100644 --- a/tools/x86_64-bootimager/Cargo.toml +++ b/tools/x86_64-bootimager/Cargo.toml @@ -8,12 +8,15 @@ edition = "2021" [dependencies] anyhow = "1" camino = "1" +heck = "0.5" # cargo_metadata = "0.18.1" # used for UEFI booting in QEMU ovmf-prebuilt = "0.1.0-alpha.1" +owo-colors = "4" clap = { version = "4.5", features = ["derive", "env"] } bootloader = "0.11" bootloader-boot-config = "0.11.3" # escargot = "0.5" tracing = "0.1" -tracing-subscriber = "0.3" +tracing-subscriber = { version = "0.3", features = ["fmt", "tracing-log"] } +supports-color = "3" diff --git a/tools/x86_64-bootimager/src/lib.rs b/tools/x86_64-bootimager/src/lib.rs index d30e1c6b..728d06c7 100644 --- a/tools/x86_64-bootimager/src/lib.rs +++ b/tools/x86_64-bootimager/src/lib.rs @@ -3,6 +3,8 @@ use camino::{Utf8Path, Utf8PathBuf}; use clap::{Args, Parser, ValueEnum, ValueHint}; use std::fmt; +pub mod output; + #[derive(Debug, Parser)] #[command(next_help_heading = "Build Options")] pub struct Builder { @@ -176,22 +178,22 @@ impl QemuOptions { qemu_args, } = self; + tracing::info!(qemu = %qemu_path, args = ?qemu_args, "Booting mnemOS VM"); + let mut cmd = std::process::Command::new(qemu_path); if !qemu_args.is_empty() { cmd.args(qemu_args.iter()); } + cmd.arg("-drive") + .arg(format!("format=raw,file={bootimage_path}")); + if let BootMode::Uefi = boot_mode { cmd.arg("-bios").arg(ovmf_prebuilt::ovmf_pure_efi()); } - tracing::info!( - ?qemu_args, - %qemu_path, - %boot_mode, - "booting in QEMU: {bootimage_path}" - ); - cmd.arg("-drive") - .arg(format!("format=raw,file={bootimage_path}")); + + tracing::debug!("Running QEMU command: {cmd:?}"); + let mut qemu = cmd.spawn().context("failed to spawn QEMU child process")?; let status = qemu.wait().context("QEMU child process failed")?; @@ -239,10 +241,10 @@ impl BootloaderOptions { bootcfg.frame_buffer.minimum_framebuffer_width = self.framebuffer_width; } tracing::debug!( - ?bootcfg.log_level, - bootcfg.frame_buffer_logging, - bootcfg.serial_logging, - ?bootcfg.frame_buffer + log.info = ?bootcfg.log_level, + log.framebuffer = bootcfg.frame_buffer_logging, + log.serial = bootcfg.serial_logging, + "Configuring bootloader", ); bootcfg } @@ -250,10 +252,11 @@ impl BootloaderOptions { impl Builder { pub fn build_bootimage(&self) -> anyhow::Result { + let t0 = std::time::Instant::now(); tracing::info!( - boot_mode = ?self.bootloader.mode, + boot_mode = %self.bootloader.mode, kernel = %self.kernel_bin, - "Building boot image." + "Building boot image" ); let canonical_kernel_bin: Utf8PathBuf = self @@ -290,7 +293,11 @@ impl Builder { } }; - tracing::info!("Created bootable disk image ({path})",); + tracing::info!( + "Finished bootable disk image [{}] in {:.02?} ({path})", + self.bootloader.mode, + t0.elapsed(), + ); Ok(path) } diff --git a/tools/x86_64-bootimager/src/main.rs b/tools/x86_64-bootimager/src/main.rs index f9651eb7..b89077f3 100644 --- a/tools/x86_64-bootimager/src/main.rs +++ b/tools/x86_64-bootimager/src/main.rs @@ -1,18 +1,14 @@ -use clap::{Args, Parser}; -use mnemos_x86_64_bootimager::{Builder, QemuOptions}; +use clap::Parser; +use mnemos_x86_64_bootimager::{output, Builder, QemuOptions}; fn main() -> anyhow::Result<()> { - use tracing_subscriber::prelude::*; - let App { cmd, builder, output, } = App::parse(); - tracing_subscriber::registry() - .with(tracing_subscriber::fmt::layer().without_time().pretty()) - .with(output.trace_filter) - .init(); + output.init()?; + tracing::info!("Assuming direct control over the build!"); let bootimage_path = builder.build_bootimage()?; let mode = builder.bootloader.mode; @@ -38,7 +34,7 @@ struct App { builder: Builder, #[clap(flatten)] - output: OutputOptions, + output: output::Options, } #[derive(Debug, Clone, Parser)] @@ -52,17 +48,3 @@ enum Subcommand { #[clap(alias = "run")] Qemu(QemuOptions), } - -#[derive(Clone, Debug, Args)] -#[command(next_help_heading = "Output Options")] -struct OutputOptions { - /// Tracing filter for the bootimage builder. - #[clap( - long = "trace", - alias = "log", - env = "RUST_LOG", - default_value = "info", - global = true - )] - trace_filter: tracing_subscriber::filter::Targets, -} diff --git a/tools/x86_64-bootimager/src/output.rs b/tools/x86_64-bootimager/src/output.rs new file mode 100644 index 00000000..0c2fba3f --- /dev/null +++ b/tools/x86_64-bootimager/src/output.rs @@ -0,0 +1,352 @@ +use clap::Args; +use heck::ToTitleCase; +use std::fmt; +use tracing::{field::Field, Event, Level, Subscriber}; +use tracing_subscriber::{ + field::Visit, + fmt::{format::Writer, FmtContext, FormatEvent, FormatFields, FormattedFields}, + registry::LookupSpan, +}; + +pub use owo_colors::{style, OwoColorize, Style}; + +#[derive(Clone, Debug, Args)] +#[command(next_help_heading = "Output Options")] +pub struct Options { + /// Tracing filter for the bootimage builder. + #[clap( + long = "trace", + alias = "log", + env = "RUST_LOG", + default_value = "info", + global = true + )] + trace_filter: tracing_subscriber::filter::Targets, + + /// Whether to emit colors in output. + #[clap( + long, + env = "CARGO_TERM_COLORS", + default_value_t = ColorMode::Auto, + global = true, + )] + color: ColorMode, +} + +pub const CARGO_LOG_WIDTH: usize = 12; + +#[derive(Copy, Clone, Debug, Eq, PartialEq, clap::ValueEnum)] +#[repr(u8)] +#[clap(rename_all = "lower")] +enum ColorMode { + /// Determine whether to color output based on whether or not stderr is a + /// TTY. + Auto = 0, + /// Always color output. + Always = 1, + /// Never color output. + Never = 2, +} + +// === impl OutputOptions === + +impl Options { + pub fn init(&self) -> anyhow::Result<()> { + use tracing_subscriber::prelude::*; + let fmt = tracing_subscriber::fmt::layer() + .event_format(CargoFormatter { + styles: Styles::new(self.color), + }) + .with_writer(std::io::stderr); + + tracing_subscriber::registry() + .with(fmt) + .with(self.trace_filter.clone()) + .try_init()?; + Ok(()) + } +} + +// === impl ColorMode === + +impl fmt::Display for ColorMode { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + f.pad(self.as_str()) + } +} + +impl ColorMode { + fn if_color(self, style: owo_colors::Style) -> owo_colors::Style { + if self.should_color_stderr() { + style + } else { + owo_colors::style() + } + } + + fn as_str(&self) -> &'static str { + match self { + ColorMode::Auto => "auto", + ColorMode::Always => "always", + ColorMode::Never => "never", + } + } + + fn should_color_stderr(self) -> bool { + match self { + ColorMode::Auto => supports_color::on(supports_color::Stream::Stderr) + .map(|c| c.has_basic) + .unwrap_or(false), + ColorMode::Always => true, + ColorMode::Never => false, + } + } +} + +#[derive(Debug)] +struct CargoFormatter { + styles: Styles, +} + +struct Visitor<'styles, 'writer> { + level: Level, + writer: Writer<'writer>, + is_empty: bool, + styles: &'styles Styles, + did_cargo_format: bool, +} + +#[derive(Debug)] +struct Styles { + error: Style, + warn: Style, + info: Style, + debug: Style, + trace: Style, + pipes: Style, + bold: Style, +} + +struct Prefixed { + prefix: &'static str, + val: T, +} + +impl FormatEvent for CargoFormatter +where + S: Subscriber + for<'a> LookupSpan<'a>, + N: for<'a> FormatFields<'a> + 'static, +{ + fn format_event( + &self, + ctx: &FmtContext<'_, S, N>, + mut writer: Writer<'_>, + event: &Event<'_>, + ) -> fmt::Result { + let metadata = event.metadata(); + let level = metadata.level(); + + let include_spans = { + let mut visitor = self.visitor(*level, writer.by_ref()); + event.record(&mut visitor); + !visitor.did_cargo_format && ctx.lookup_current().is_some() + }; + + writer.write_char('\n')?; + + if include_spans { + writeln!( + writer, + " {} {}{}", + "-->".style(self.styles.pipes), + metadata.file().unwrap_or_else(|| metadata.target()), + DisplayOpt(metadata.line().map(Prefixed::prefix(":"))), + )?; + ctx.visit_spans(|span| { + let exts = span.extensions(); + let fields = exts + .get::>() + .map(|f| f.fields.as_str()) + .unwrap_or(""); + writeln!( + writer, + " {} {}{}{}", + "|".style(self.styles.pipes), + span.name().style(self.styles.bold), + if fields.is_empty() { "" } else { ": " }, + fields + ) + })?; + + writer.write_char('\n')?; + } + + Ok(()) + } +} + +impl CargoFormatter { + fn visitor<'styles, 'writer>( + &'styles self, + level: Level, + writer: Writer<'writer>, + ) -> Visitor<'styles, 'writer> { + Visitor { + level, + writer, + is_empty: true, + styles: &self.styles, + did_cargo_format: false, + } + } +} + +// === impl Visitor === + +impl<'styles, 'writer> Visitor<'styles, 'writer> { + const MESSAGE: &'static str = "message"; + const INDENT: usize = 12; +} + +impl<'styles, 'writer> Visit for Visitor<'styles, 'writer> { + fn record_debug(&mut self, field: &Field, value: &dyn fmt::Debug) { + // If we're writing the first field of the event, either emit cargo + // formatting, or a level header. + if self.is_empty { + // If the level is `INFO` and it has a message that's + // shaped like a cargo log tag, emit the cargo tag followed by the + // rest of the message. + if self.level == Level::INFO && field.name() == Self::MESSAGE { + let message = format!("{value:?}"); + if let Some((tag, message)) = message.as_str().split_once(' ') { + if tag.len() <= Self::INDENT { + let tag = tag.to_title_case(); + let style = match self.level { + Level::DEBUG => self.styles.debug, + _ => self.styles.info, + }; + + let _ = write!( + self.writer, + "{:>indent$} ", + tag.style(style), + indent = Self::INDENT + ); + + let _ = self.writer.write_str(message); + self.is_empty = false; + self.did_cargo_format = true; + return; + } + } + } + + // Otherwise, emit a level tag. + let _ = match self.level { + Level::ERROR => write!( + self.writer, + "{}{} ", + "error".style(self.styles.error), + ":".style(self.styles.bold) + ), + Level::WARN => write!( + self.writer, + "{}{} ", + "warning".style(self.styles.warn), + ":".style(self.styles.bold), + ), + Level::INFO => write!( + self.writer, + "{}{} ", + "info".style(self.styles.info), + ":".style(self.styles.bold) + ), + Level::DEBUG => write!( + self.writer, + "{}{} ", + "debug".style(self.styles.debug), + ":".style(self.styles.bold) + ), + Level::TRACE => write!( + self.writer, + "{}{} ", + "trace".style(self.styles.trace), + ":".style(self.styles.bold) + ), + }; + } else { + // If this is *not* the first field of the event, prefix it with a + // comma for the preceding field, instead of a cargo tag or level tag. + let _ = self.writer.write_str(", "); + } + + if field.name() == Self::MESSAGE { + let _ = write!(self.writer, "{value:?}"); + } else { + let _ = write!( + self.writer, + "{}{} {:?}", + field.name().style(self.styles.bold), + ":".style(self.styles.bold), + value + ); + } + + self.is_empty = false; + } +} + +// === impl Styles === + +impl Styles { + fn new(colors: ColorMode) -> Self { + Self { + error: colors.if_color(style().red().bold()), + warn: colors.if_color(style().yellow().bold()), + info: colors.if_color(style().green().bold()), + debug: colors.if_color(style().blue().bold()), + trace: colors.if_color(style().purple().bold()), + bold: colors.if_color(style().bold()), + pipes: colors.if_color(style().blue().bold()), + } + } +} + +impl Prefixed { + fn prefix(prefix: &'static str) -> impl Fn(T) -> Prefixed { + move |val| Prefixed { val, prefix } + } +} + +impl fmt::Display for Prefixed +where + T: fmt::Display, +{ + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + write!(f, "{}{}", self.prefix, self.val) + } +} + +impl fmt::Debug for Prefixed +where + T: fmt::Debug, +{ + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + write!(f, "{}{:?}", self.prefix, self.val) + } +} + +struct DisplayOpt(Option); + +impl fmt::Display for DisplayOpt +where + T: fmt::Display, +{ + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + if let Some(ref val) = self.0 { + fmt::Display::fmt(val, f)?; + } + + Ok(()) + } +}