diff --git a/clippy.toml b/clippy.toml index c4b887869..073d13ee2 100644 --- a/clippy.toml +++ b/clippy.toml @@ -2,3 +2,16 @@ disallowed-methods = [ # https://github.com/rust-lang/rust-clippy/issues/13434#issuecomment-2484292914 { path = "str::len", reason = "use .as_bytes().len() instead" } ] + +# anstream's print macros aren't covered by clippy::print_stdout/print_stderr, +# which crates/lib denies. Only crates/lib denies this lint, and it's the +# only user of these macros. +disallowed-macros = [ + { path = "anstream::print", reason = "use ProgressWriter::message() or an explicit writer" }, + { path = "anstream::println", reason = "use ProgressWriter::message() or an explicit writer" }, + { path = "anstream::eprint", reason = "use ProgressWriter::message() or an explicit writer" }, + { path = "anstream::eprintln", reason = "use ProgressWriter::message() or an explicit writer" }, +] + +# Printing from tests is fine; see the print_stdout deny in crates/lib +allow-print-in-tests = true diff --git a/crates/lib/src/bootc_composefs/boot.rs b/crates/lib/src/bootc_composefs/boot.rs index d3a466775..420085216 100644 --- a/crates/lib/src/bootc_composefs/boot.rs +++ b/crates/lib/src/bootc_composefs/boot.rs @@ -2724,6 +2724,7 @@ fn install_composefs_bootloader( crate::bootloader::install_via_zipl( &root_setup.device_info.require_single_root()?, boot_uuid, + &state.prog, )?; } else if matches!(bootloader, Bootloader::Grub | Bootloader::GrubCC) { let chroot_target = Utf8Path::from_path(mounted_root.root_path()) @@ -2742,6 +2743,7 @@ fn install_composefs_bootloader( &state.config_opts, Some(chroot_target), Some(bind_boot_path.as_path()), + &state.prog, )?; // FIXME: Remove this hack once we have support in bootupd @@ -2793,6 +2795,7 @@ fn install_composefs_bootloader( &mounted_root, &state.config_opts, get_secureboot_keys(mounted_root.dir(), BOOTC_AUTOENROLL_PATH)?, + &state.prog, ) })?; } @@ -2955,6 +2958,7 @@ pub(crate) async fn setup_composefs_boot( &deployment, state.load_policy()?.as_ref(), contents, + &state.prog, )?; } diff --git a/crates/lib/src/bootc_composefs/delete.rs b/crates/lib/src/bootc_composefs/delete.rs index 955c32f20..2a0584d58 100644 --- a/crates/lib/src/bootc_composefs/delete.rs +++ b/crates/lib/src/bootc_composefs/delete.rs @@ -17,6 +17,7 @@ use crate::{ TYPE1_ENT_PATH, TYPE1_ENT_PATH_STAGED, USER_CFG_STAGED, }, parsers::bls_config::{BLSConfigType, EFIKey, parse_bls_config}, + progress_jsonl::ProgressWriter, spec::{BootEntry, BootloaderKind, DeploymentEntry}, status::Slot, store::{BootedComposefs, Storage}, @@ -250,7 +251,7 @@ pub(crate) async fn delete_composefs_deployment( // Unqueue rollback. This makes it easier to delete boot entries later on if matches!(depl_to_del.ty, Some(Slot::Rollback)) && host.status.rollback_queued { - composefs_rollback(storage, booted_cfs).await?; + composefs_rollback(storage, booted_cfs, &ProgressWriter::default()).await?; } let kind = if depl_to_del.pinned { diff --git a/crates/lib/src/bootc_composefs/progress.rs b/crates/lib/src/bootc_composefs/progress.rs index daf33c361..83e0ac44c 100644 --- a/crates/lib/src/bootc_composefs/progress.rs +++ b/crates/lib/src/bootc_composefs/progress.rs @@ -5,7 +5,7 @@ //! composefs-rs (`composefs::progress`) reports progress via a synchronous, //! `Send + Sync` callback trait invoked directly from whatever task is //! driving the pull. That's a poor fit for [`crate::progress_jsonl::ProgressWriter`], -//! whose API is `async`. We bridge the two by handing composefs-rs a trivial +//! whose writes can block on a slow reader. We bridge the two by handing composefs-rs a trivial //! reporter that forwards every [`ProgressEvent`] over an unbounded channel, //! and processing that channel from a concurrently spawned Tokio task which //! owns the `indicatif` state and the `ProgressWriter`. This mirrors the @@ -254,9 +254,9 @@ async fn drive_progress( subtasks, }; if required { - prog.send(event).await; + prog.send(event); } else if any_activity { - prog.send_lossy(event).await; + prog.send_lossy(event); } } diff --git a/crates/lib/src/bootc_composefs/rollback.rs b/crates/lib/src/bootc_composefs/rollback.rs index 37d7ed4ef..fde8b32af 100644 --- a/crates/lib/src/bootc_composefs/rollback.rs +++ b/crates/lib/src/bootc_composefs/rollback.rs @@ -17,6 +17,7 @@ use crate::composefs_consts::{ COMPOSEFS_STAGED_DEPLOYMENT_FNAME, COMPOSEFS_TRANSIENT_STATE_DIR, TYPE1_ENT_PATH_STAGED, }; use crate::deploy::ROLLBACK_JOURNAL_ID; +use crate::progress_jsonl::ProgressWriter; use crate::spec::{Bootloader, BootloaderKind, Host}; use crate::store::{BootedComposefs, Storage}; use crate::{ @@ -216,6 +217,7 @@ fn rollback_composefs_entries(host: &Host, boot_dir: &Dir, bootloader: Bootloade pub(crate) async fn composefs_rollback( storage: &Storage, booted_cfs: &BootedComposefs, + prog: &ProgressWriter, ) -> Result<()> { const COMPOSEFS_ROLLBACK_JOURNAL_ID: &str = "6f5e4d3c2b1a0f9e8d7c6b5a4e3d2c1b0"; @@ -238,7 +240,7 @@ pub(crate) async fn composefs_rollback( let reverting = new_spec.boot_order == BootOrder::Default; if reverting { - println!("notice: Reverting queued rollback state"); + prog.info("notice: Reverting queued rollback state"); } let rollback_status = host @@ -302,9 +304,9 @@ pub(crate) async fn composefs_rollback( } if reverting { - println!("Next boot: current deployment"); + prog.info("Next boot: current deployment"); } else { - println!("Next boot: rollback deployment"); + prog.info("Next boot: rollback deployment"); } Ok(()) diff --git a/crates/lib/src/bootc_composefs/soft_reboot.rs b/crates/lib/src/bootc_composefs/soft_reboot.rs index 2bfd3317c..1d0bbfffe 100644 --- a/crates/lib/src/bootc_composefs/soft_reboot.rs +++ b/crates/lib/src/bootc_composefs/soft_reboot.rs @@ -4,6 +4,7 @@ use crate::{ status::{build_composefs_karg, get_composefs_status}, }, cli::SoftRebootMode, + progress_jsonl::ProgressWriter, store::{BootedComposefs, Storage}, }; use anyhow::{Context, Result}; @@ -23,7 +24,7 @@ use std::{fs::create_dir_all, os::unix::process::CommandExt, path::PathBuf, proc const NEXTROOT: &str = "/run/nextroot"; #[context("Resetting soft reboot state")] -pub(crate) fn reset_soft_reboot() -> Result<()> { +pub(crate) fn reset_soft_reboot(prog: &ProgressWriter) -> Result<()> { // NOTE: By default bootc runs in an unshared mount namespace; // this sets up our /runto actually be the same as the host/run // so the umount (at the end of this function) actually affects the host @@ -40,7 +41,7 @@ pub(crate) fn reset_soft_reboot() -> Result<()> { let Some(nextroot) = nextroot else { tracing::debug!("Nextroot does not exist"); - println!("No deployment staged for soft rebooting"); + prog.info("No deployment staged for soft rebooting"); return Ok(()); }; @@ -50,13 +51,13 @@ pub(crate) fn reset_soft_reboot() -> Result<()> { if !nextroot_mounted { tracing::debug!("Nextroot is not a mountpoint"); - println!("No deployment staged for soft rebooting"); + prog.info("No deployment staged for soft rebooting"); return Ok(()); } unmount(NEXTROOT, UnmountFlags::DETACH).context("Unmounting nextroot")?; - println!("Cleared soft reboot queued state"); + prog.info("Cleared soft reboot queued state"); Ok(()) } @@ -70,6 +71,7 @@ pub(crate) async fn prepare_soft_reboot_composefs( deployment_id: Option<&str>, soft_reboot_mode: SoftRebootMode, reboot: bool, + prog: &ProgressWriter, ) -> Result<()> { if !systemd_has_soft_reboot() { anyhow::bail!("System does not support soft reboots") @@ -133,7 +135,7 @@ pub(crate) async fn prepare_soft_reboot_composefs( setup_root(args)?; - println!("Soft reboot setup complete"); + prog.info("Soft reboot setup complete"); if reboot { // Replacing the current process should be fine as we restart userspace anyway diff --git a/crates/lib/src/bootc_composefs/state.rs b/crates/lib/src/bootc_composefs/state.rs index 57055a3de..1ce6c25cb 100644 --- a/crates/lib/src/bootc_composefs/state.rs +++ b/crates/lib/src/bootc_composefs/state.rs @@ -30,6 +30,7 @@ use crate::bootc_composefs::status::{ ComposefsCmdline, StagedDeployment, get_sorted_type1_boot_entries, }; use crate::parsers::bls_config::{BLSConfigType, EFIKey}; +use crate::progress_jsonl::ProgressWriter; use crate::store::{BootedComposefs, Storage}; use crate::{ composefs_consts::{ @@ -344,10 +345,13 @@ pub(crate) fn remove_staged_deployment() -> Result<()> { Ok(()) } -pub(crate) fn composefs_usr_overlay(access_mode: FilesystemOverlayAccessMode) -> Result<()> { +pub(crate) fn composefs_usr_overlay( + access_mode: FilesystemOverlayAccessMode, + prog: &ProgressWriter, +) -> Result<()> { let status = get_usr_overlay_status()?; if status.is_some() { - println!("An overlayfs is already mounted on /usr"); + prog.info("An overlayfs is already mounted on /usr"); return Ok(()); } @@ -361,8 +365,11 @@ pub(crate) fn composefs_usr_overlay(access_mode: FilesystemOverlayAccessMode) -> let overlay_fd = overlay_transient(usr.as_fd(), "transient", mount_attr_flags)?; mount_at_wrapper(overlay_fd, &usr, ".").context("Attaching /usr overlay")?; - println!("A {} overlayfs is now mounted on /usr", access_mode); - println!("All changes there will be discarded on reboot."); + prog.info(format!( + "A {} overlayfs is now mounted on /usr", + access_mode + )); + prog.info("All changes there will be discarded on reboot."); Ok(()) } diff --git a/crates/lib/src/bootc_composefs/switch.rs b/crates/lib/src/bootc_composefs/switch.rs index ee5f622d3..90cce7918 100644 --- a/crates/lib/src/bootc_composefs/switch.rs +++ b/crates/lib/src/bootc_composefs/switch.rs @@ -57,7 +57,9 @@ pub(crate) async fn switch_composefs( }; if new_spec == host.spec { - println!("Image specification is unchanged."); + do_upgrade_opts + .prog + .info("Image specification is unchanged."); if opts.apply && host.status.staged.is_some() { crate::reboot::reboot()?; } @@ -129,7 +131,9 @@ pub(crate) async fn switch_composefs( match action { UpdateAction::Skip => { - println!("No changes in image: {target_imgref:#}"); + do_upgrade_opts + .prog + .info(format!("No changes in image: {target_imgref:#}")); return Ok(()); } diff --git a/crates/lib/src/bootc_composefs/uki_addons_cli.rs b/crates/lib/src/bootc_composefs/uki_addons_cli.rs index 05c93fcc1..82c5e35f6 100644 --- a/crates/lib/src/bootc_composefs/uki_addons_cli.rs +++ b/crates/lib/src/bootc_composefs/uki_addons_cli.rs @@ -1,4 +1,4 @@ -use std::io::{Seek, SeekFrom}; +use std::io::{Seek, SeekFrom, Write}; use std::path::Path; use anyhow::{Context, Result}; @@ -17,6 +17,7 @@ use ostree_ext::{ }; use crate::bootc_composefs::boot::STAGED_GLOBAL_UKI_ADDONS_DIR; +use crate::progress_jsonl::ProgressWriter; use crate::spec::Host; use crate::{ bootc_composefs::{ @@ -106,6 +107,8 @@ pub(crate) fn handle_addon_cli_cmd( anyhow::bail!("ESP not found"); }; + let prog = ProgressWriter::default(); + match opts { UkiAddonCliOpts::List { json, verbose } => { let mut addons = list_installed_uki_addons(storage, &host.status.staged)?; @@ -123,16 +126,16 @@ pub(crate) fn handle_addon_cli_cmd( } if addons.is_empty() { - println!("No UKI addons installed"); + writeln!(std::io::stdout(), "No UKI addons installed")?; return Ok(()); } for (i, addon) in addons.iter().enumerate() { // Separate addon blocks with a blank line. if i > 0 { - println!(); + writeln!(std::io::stdout())?; } - println!("{addon}"); + writeln!(std::io::stdout(), "{addon}")?; } } UkiAddonCliOpts::Remove { @@ -198,7 +201,7 @@ pub(crate) fn handle_addon_cli_cmd( .remove_file(&addon_path) .with_context(|| format!("Failed to remove addon {addon_name}"))?; - println!("Removed addon {addon_name}"); + prog.info(format!("Removed addon {addon_name}")); let addons_dir = addon_path .parent() @@ -218,7 +221,7 @@ pub(crate) fn handle_addon_cli_cmd( format!("Removing addons dir: {}", addons_dir.display()) })?; - println!("Removed empty directory {}", addons_dir.display()); + prog.info(format!("Removed empty directory {}", addons_dir.display())); } } @@ -247,7 +250,7 @@ pub(crate) fn handle_addon_cli_cmd( .remove_file(format!("{global_addons_dir}/{full_addon_name}")) .with_context(|| format!("Removing global addon {full_addon_name}"))?; - println!("Removed Global Addon {addon_name}"); + prog.info(format!("Removed Global Addon {addon_name}")); let num_ents = esp .fd @@ -263,7 +266,7 @@ pub(crate) fn handle_addon_cli_cmd( .remove_dir(global_addons_dir) .context("Removing global addons dir")?; - println!("Removed empty directory {global_addons_dir}"); + prog.info(format!("Removed empty directory {global_addons_dir}")); // The staged global addon set is a transient overlay that // finalize exchanges with the live set on the next boot. An @@ -271,13 +274,13 @@ pub(crate) fn handle_addon_cli_cmd( // the last staged global addon leaves the currently active // global addons in effect after reboot. if is_staged { - println!( + prog.info(format!( "Note: '{addon_name}' was the last staged global addon. \ An empty staged global addon set is not applied on boot, so \ the currently active global addons remain in effect after \ reboot. To drop all global addons, remove them while no \ deployment is staged." - ); + )); } } } @@ -321,7 +324,9 @@ pub(crate) fn handle_addon_cli_cmd( }); if already_present { - println!("Addon {addon_name} is already present. Nothing to do."); + prog.info(format!( + "Addon {addon_name} is already present. Nothing to do." + )); return Ok(()); } @@ -434,17 +439,15 @@ pub(crate) fn handle_addon_cli_cmd( .context("fsync")?; match addon_type { - UkiAddonScope::Global => println!("Global UKI Addon {addon_name} added"), - UkiAddonScope::Scoped => { - println!( - "UKI Addon {addon_name} added to {} deployment", - if host.status.staged.is_some() { - "staged" - } else { - "booted" - } - ) - } + UkiAddonScope::Global => prog.info(format!("Global UKI Addon {addon_name} added")), + UkiAddonScope::Scoped => prog.info(format!( + "UKI Addon {addon_name} added to {} deployment", + if host.status.staged.is_some() { + "staged" + } else { + "booted" + } + )), } } UkiAddonCliOpts::ListReferenced { json } => { @@ -460,17 +463,17 @@ pub(crate) fn handle_addon_cli_cmd( } if referenced.is_empty() { - println!("No referenced UKI addons found"); + writeln!(std::io::stdout(), "No referenced UKI addons found")?; return Ok(()); } for (verity, addons) in &referenced { - println!("Deployment {verity}:"); + writeln!(std::io::stdout(), "Deployment {verity}:")?; if addons.is_empty() { - println!(" (none)"); + writeln!(std::io::stdout(), " (none)")?; } else { for addon in addons { - println!(" {addon}"); + writeln!(std::io::stdout(), " {addon}")?; } } } diff --git a/crates/lib/src/bootc_composefs/update.rs b/crates/lib/src/bootc_composefs/update.rs index 7fc373d9b..84f39c89c 100644 --- a/crates/lib/src/bootc_composefs/update.rs +++ b/crates/lib/src/bootc_composefs/update.rs @@ -300,6 +300,7 @@ async fn apply_upgrade( Some(depl_id), soft_reboot_mode, opts.apply, + &opts.prog, ) .await; }; @@ -524,13 +525,13 @@ pub(crate) async fn do_upgrade( )?; if !pending.is_empty() { - println!( + opts.prog.info( "notice: these global UKI addons are not provided by the new image and will be \ removed on a future update/switch unless re-added with \ - `bootc uki-addon add global`:" + `bootc uki-addon add global`:", ); for addon in &pending { - println!(" - {addon}"); + opts.prog.info(format!(" - {addon}")); } } } @@ -553,8 +554,9 @@ pub(crate) async fn apply_upgrade_from_downloaded( // Staged deployment exists, but it will be finalized if !staged.download_only { - println!("Staged deployment is present and not in download only mode."); - println!("Use `bootc update --apply` to apply the update."); + let prog = &do_upgrade_opts.prog; + prog.info("Staged deployment is present and not in download only mode."); + prog.info("Use `bootc update --apply` to apply the update."); return Ok(()); } @@ -688,7 +690,9 @@ pub(crate) async fn upgrade_composefs( return crate::reboot::reboot(); } - println!("Update already staged. To apply update run `bootc update --apply`"); + do_upgrade_opts + .prog + .info("Update already staged. To apply update run `bootc update --apply`"); return Ok(()); } @@ -713,7 +717,9 @@ pub(crate) async fn upgrade_composefs( match action { UpdateAction::Skip => { - println!("No changes in staged image: {booted_imgref:#}"); + do_upgrade_opts + .prog + .info(format!("No changes in staged image: {booted_imgref:#}")); return Ok(()); } @@ -745,7 +751,9 @@ pub(crate) async fn upgrade_composefs( match action { UpdateAction::Skip => { - println!("No changes in: {booted_imgref:#}"); + do_upgrade_opts + .prog + .info(format!("No changes in: {booted_imgref:#}")); return Ok(()); } diff --git a/crates/lib/src/bootloader.rs b/crates/lib/src/bootloader.rs index 08a208d28..ebb845868 100644 --- a/crates/lib/src/bootloader.rs +++ b/crates/lib/src/bootloader.rs @@ -12,6 +12,7 @@ use fn_error_context::context; use bootc_mount as mount; use crate::bootc_composefs::boot::{MountedImageRoot, SecurebootKeys}; +use crate::progress_jsonl::ProgressWriter; use crate::utils; /// The name of the mountpoint for efi (as a subdirectory of /boot, or at the toplevel) @@ -151,6 +152,7 @@ pub(crate) fn install_via_bootupd( configopts: &crate::install::InstallConfigOpts, chroot_target: Option<&Utf8Path>, bind_boot_path: Option<&Utf8Path>, + prog: &ProgressWriter, ) -> Result<()> { let verbose = std::env::var_os("BOOTC_BOOTLOADER_DEBUG").map(|_| "-vvvv"); // bootc defaults to only targeting the platform boot method. @@ -167,7 +169,7 @@ pub(crate) fn install_via_bootupd( "/" }; - println!("Installing bootloader via bootupd"); + prog.info("Installing bootloader via bootupd"); // Build the bootupctl arguments let mut bootupd_args: Vec<&str> = vec!["backend", "install"]; @@ -268,8 +270,9 @@ pub(crate) fn install_systemd_boot( prepared_root: &MountedImageRoot, configopts: &crate::install::InstallConfigOpts, autoenroll: Option, + prog: &ProgressWriter, ) -> Result<()> { - println!("Installing bootloader via systemd-boot"); + prog.info("Installing bootloader via systemd-boot"); // We use the --root of the mounted target root, so we have the right /etc/os-release. let root_path = prepared_root @@ -347,11 +350,11 @@ pub(crate) fn install_systemd_boot( } dir.copy(filename, &keys_dir, filename) .with_context(|| format!("Copying secure boot key {filename:?}"))?; - println!( + prog.info(format!( "Wrote Secure Boot key: {}/{}", keys_path.display(), filename.as_str() - ); + )); } if keys.is_empty() { tracing::debug!("No Secure Boot keys provided for systemd-boot enrollment"); @@ -394,7 +397,11 @@ pub(crate) fn parse_systemd_version(output: &str) -> Result { } #[context("Installing bootloader using zipl")] -pub(crate) fn install_via_zipl(device: &bootc_blockdev::Device, boot_uuid: &str) -> Result<()> { +pub(crate) fn install_via_zipl( + device: &bootc_blockdev::Device, + boot_uuid: &str, + prog: &ProgressWriter, +) -> Result<()> { // Identify the target boot partition from UUID let fs = mount::inspect_filesystem_by_uuid(boot_uuid)?; let boot_dir = Utf8Path::new(&fs.target); @@ -456,7 +463,7 @@ pub(crate) fn install_via_zipl(device: &bootc_blockdev::Device, boot_uuid: &str) let ramdisk = boot_dir.join(initrd).canonicalize_utf8()?; // Execute the zipl command to install bootloader - println!("Running zipl on {device_path}"); + prog.info(format!("Running zipl on {device_path}")); Command::new("zipl") .args(["--target", boot_dir.as_str()]) .args(["--image", image.as_str()]) diff --git a/crates/lib/src/boundimage.rs b/crates/lib/src/boundimage.rs index c99aeb6fb..f62b1e912 100644 --- a/crates/lib/src/boundimage.rs +++ b/crates/lib/src/boundimage.rs @@ -14,6 +14,7 @@ use ostree_ext::containers_image_proxy; use ostree_ext::ostree::Deployment; use crate::podstorage::{CStorage, PullMode}; +use crate::progress_jsonl::ProgressWriter; use crate::store::Storage; /// The path in a root for bound images; this directory should only contain @@ -38,7 +39,11 @@ pub(crate) struct ResolvedBoundImage { } /// Given a deployment, pull all container images it references. -pub(crate) async fn pull_bound_images(sysroot: &Storage, deployment: &Deployment) -> Result<()> { +pub(crate) async fn pull_bound_images( + sysroot: &Storage, + deployment: &Deployment, + prog: &ProgressWriter, +) -> Result<()> { // Log the bound images operation to systemd journal const BOUND_IMAGES_JOURNAL_ID: &str = "1a0b9c8d7e6f5a4b3c2d1e0f9a8b7c6d5"; tracing::info!( @@ -56,7 +61,7 @@ pub(crate) async fn pull_bound_images(sysroot: &Storage, deployment: &Deployment "Found {} bound images to pull", bound_images.len() ); - pull_images(sysroot, bound_images).await + pull_images(sysroot, bound_images, prog).await } #[context("Querying bound images")] @@ -164,19 +169,21 @@ fn parse_container_file(file_contents: &tini::Ini) -> Result { pub(crate) async fn pull_images( sysroot: &Storage, bound_images: Vec, + prog: &ProgressWriter, ) -> Result<()> { // Always initialize the img store to ensure labels are set when upgrading let imgstore = sysroot.get_ensure_imgstore()?; if bound_images.is_empty() { return Ok(()); } - pull_images_impl(imgstore, bound_images).await + pull_images_impl(imgstore, bound_images, prog).await } #[context("Pulling bound images")] pub(crate) async fn pull_images_impl( imgstore: &CStorage, bound_images: Vec, + prog: &ProgressWriter, ) -> Result<()> { let n = bound_images.len(); tracing::debug!("Pulling bound images: {n}"); @@ -196,7 +203,7 @@ pub(crate) async fn pull_images_impl( .await?; } - println!("Bound images stored: {n}"); + prog.info(format!("Bound images stored: {n}")); Ok(()) } diff --git a/crates/lib/src/cli.rs b/crates/lib/src/cli.rs index ed784c4e5..f7d91672f 100644 --- a/crates/lib/src/cli.rs +++ b/crates/lib/src/cli.rs @@ -4,7 +4,7 @@ use std::ffi::{CString, OsStr, OsString}; use std::fs::File; -use std::io::{BufWriter, Seek, SeekFrom}; +use std::io::{BufWriter, Seek, SeekFrom, Write}; use std::os::fd::AsFd; use std::os::unix::process::CommandExt; use std::process::Command; @@ -72,7 +72,8 @@ use crate::{bootc_composefs, lints}; /// Shared progress options #[derive(Clone, Debug, Parser, PartialEq, Eq)] pub(crate) struct ProgressOptions { - /// File descriptor number which must refer to an open pipe. + /// File descriptor number to write progress to, typically the write end + /// of a pipe. /// /// Progress is written as JSON lines to this file descriptor. #[clap(long, hide = true)] @@ -1351,19 +1352,20 @@ fn handle_staged_soft_reboot( booted_ostree: &BootedOstree<'_>, soft_reboot_mode: Option, host: &crate::spec::Host, + prog: &ProgressWriter, ) -> Result<()> { handle_soft_reboot( soft_reboot_mode, host.status.staged.as_ref(), "staged", - || soft_reboot_staged(booted_ostree.sysroot), + || soft_reboot_staged(booted_ostree.sysroot, prog), ) } /// Perform a soft reboot for a staged deployment #[context("Soft reboot staged deployment")] -fn soft_reboot_staged(sysroot: &SysrootLock) -> Result<()> { - println!("Staged deployment is soft-reboot capable, preparing for soft-reboot..."); +fn soft_reboot_staged(sysroot: &SysrootLock, prog: &ProgressWriter) -> Result<()> { + prog.info("Staged deployment is soft-reboot capable, preparing for soft-reboot..."); let deployments_list = sysroot.deployments(); let staged_deployment = deployments_list @@ -1377,8 +1379,8 @@ fn soft_reboot_staged(sysroot: &SysrootLock) -> Result<()> { /// Perform a soft reboot for a rollback deployment #[context("Soft reboot rollback deployment")] -fn soft_reboot_rollback(booted_ostree: &BootedOstree<'_>) -> Result<()> { - println!("Rollback deployment is soft-reboot capable, preparing for soft-reboot..."); +fn soft_reboot_rollback(booted_ostree: &BootedOstree<'_>, prog: &ProgressWriter) -> Result<()> { + prog.info("Rollback deployment is soft-reboot capable, preparing for soft-reboot..."); let deployments_list = booted_ostree.sysroot.deployments(); let target_deployment = deployments_list @@ -1426,6 +1428,7 @@ async fn apply_from_downloaded_ostree( booted_ostree: &BootedOstree<'_>, host: &crate::spec::Host, opts: &ApplyFromDownloadedOpts, + prog: &ProgressWriter, ) -> Result<()> { let ostree = storage.get_ostree()?; let staged_deployment = ostree @@ -1433,14 +1436,14 @@ async fn apply_from_downloaded_ostree( .ok_or_else(|| anyhow::anyhow!("No staged deployment found"))?; if staged_deployment.is_finalization_locked() { - crate::boundimage::pull_bound_images(storage, &staged_deployment).await?; + crate::boundimage::pull_bound_images(storage, &staged_deployment, prog).await?; ostree.change_finalization(&staged_deployment)?; - println!("Staged deployment will now be applied on reboot"); + prog.info("Staged deployment will now be applied on reboot"); } else { - println!("Staged deployment is already set to apply on reboot"); + prog.info("Staged deployment is already set to apply on reboot"); } - handle_staged_soft_reboot(booted_ostree, opts.soft_reboot, &host)?; + handle_staged_soft_reboot(booted_ostree, opts.soft_reboot, &host, prog)?; if opts.apply { crate::reboot::reboot()?; } @@ -1514,6 +1517,7 @@ async fn upgrade( soft_reboot: opts.soft_reboot, apply: opts.apply, }, + &prog, ) .await; } @@ -1533,15 +1537,15 @@ async fn upgrade( .await?; match imp.prepare().await? { PrepareResult::AlreadyPresent(_) => { - println!("No changes in: {ostree_imgref:#}"); + prog.info(format!("No changes in: {ostree_imgref:#}")); } PrepareResult::Ready(r) => { crate::deploy::check_bootc_label(&r.config); - println!("Update available for: {ostree_imgref:#}"); + prog.info(format!("Update available for: {ostree_imgref:#}")); if let Some(version) = r.version() { - println!(" Version: {version}"); + prog.info(format!(" Version: {version}")); } - println!(" Digest: {}", r.manifest_digest); + prog.info(format!(" Digest: {}", r.manifest_digest)); changed = true; if let Some(previous_image) = booted_image.as_ref() { let diff = @@ -1605,7 +1609,7 @@ async fn upgrade( // --download-only: set download-only mode if !staged.is_finalization_locked() { storage.get_ostree()?.change_finalization(&staged)?; - println!("Image downloaded, but will not be applied on reboot"); + prog.info("Image downloaded, but will not be applied on reboot"); download_only_changed = true; } } else if !opts.check { @@ -1613,7 +1617,7 @@ async fn upgrade( // (skip if --check, which is read-only) if staged.is_finalization_locked() { storage.get_ostree()?.change_finalization(&staged)?; - println!("Staged deployment will now be applied on reboot"); + prog.info("Staged deployment will now be applied on reboot"); download_only_changed = true; } } @@ -1622,15 +1626,15 @@ async fn upgrade( } if !download_only_changed { - println!("Staged update present, not changed"); + prog.info("Staged update present, not changed"); } - handle_staged_soft_reboot(booted_ostree, opts.soft_reboot, &host)?; + handle_staged_soft_reboot(booted_ostree, opts.soft_reboot, &host, &prog)?; if opts.apply { crate::reboot::reboot()?; } } else if booted_unchanged { - println!("No update available.") + prog.info("No update available.") } else { let stateroot = booted_ostree.stateroot(); let from = MergeState::from_stateroot(storage, &stateroot)?; @@ -1660,7 +1664,7 @@ async fn upgrade( // At this point we have new staged deployment and the host definition has changed. // We need the updated host status before we check if we can prepare the soft-reboot. let updated_host = crate::status::get_status(booted_ostree)?.1; - handle_staged_soft_reboot(booted_ostree, opts.soft_reboot, &updated_host)?; + handle_staged_soft_reboot(booted_ostree, opts.soft_reboot, &updated_host, &prog)?; } if opts.apply { @@ -1703,6 +1707,7 @@ async fn switch_ostree( .map(std::sync::Arc::new); let (_, host) = crate::status::get_status(booted_ostree)?; + let prog: ProgressWriter = opts.progress.clone().try_into()?; if opts.download_opts.from_downloaded { return apply_from_downloaded_ostree( @@ -1713,12 +1718,12 @@ async fn switch_ostree( soft_reboot: opts.soft_reboot, apply: opts.apply, }, + &prog, ) .await; } let target = imgref_for_switch(&opts)?; - let prog: ProgressWriter = opts.progress.try_into()?; let cancellable = gio::Cancellable::NONE; let repo = &booted_ostree.repo(); @@ -1730,7 +1735,7 @@ async fn switch_ostree( }; if new_spec == host.spec { - println!("Image specification is unchanged."); + prog.info("Image specification is unchanged."); if opts.apply && host.status.staged.is_some() { crate::reboot::reboot()?; } @@ -1836,7 +1841,7 @@ async fn switch_ostree( // At this point we have staged the deployment and the host definition has changed. // We need the updated host status before we check if we can prepare the soft-reboot. let updated_host = crate::status::get_status(booted_ostree)?.1; - handle_staged_soft_reboot(booted_ostree, opts.soft_reboot, &updated_host)?; + handle_staged_soft_reboot(booted_ostree, opts.soft_reboot, &updated_host, &prog)?; } // `--apply` cannot be passed along with `--download-only` (handled by clap) @@ -1865,7 +1870,10 @@ async fn switch(opts: SwitchOpts) -> Result<()> { }) .await?? }; - println!("Updated {deployid} to pull from {target}"); + // Only this branch creates a writer from the fd; the others below + // take ownership of it themselves. + let prog: ProgressWriter = opts.progress.clone().try_into()?; + prog.info(format!("Updated {deployid} to pull from {target}")); return Ok(()); } let storage = &get_storage().await?; @@ -1889,8 +1897,9 @@ async fn rollback_ostree( opts: &RollbackOpts, storage: &Storage, booted_ostree: &BootedOstree<'_>, + prog: &ProgressWriter, ) -> Result<()> { - crate::deploy::rollback(storage).await?; + crate::deploy::rollback(storage, prog).await?; if opts.soft_reboot.is_some() { // Get status of rollback deployment to check soft-reboot capability @@ -1900,7 +1909,7 @@ async fn rollback_ostree( opts.soft_reboot, host.status.rollback.as_ref(), "rollback", - || soft_reboot_rollback(booted_ostree), + || soft_reboot_rollback(booted_ostree, prog), )?; } @@ -1911,11 +1920,14 @@ async fn rollback_ostree( #[context("Rollback")] async fn rollback(opts: &RollbackOpts) -> Result<()> { let storage = &get_storage().await?; + let prog = &ProgressWriter::default(); match storage.kind()? { BootedStorageKind::Ostree(booted_ostree) => { - rollback_ostree(opts, storage, &booted_ostree).await + rollback_ostree(opts, storage, &booted_ostree, prog).await + } + BootedStorageKind::Composefs(booted_cfs) => { + composefs_rollback(storage, &booted_cfs, prog).await } - BootedStorageKind::Composefs(booted_cfs) => composefs_rollback(storage, &booted_cfs).await, } } @@ -1940,19 +1952,18 @@ async fn edit_ostree( serde_yaml::from_reader(&mut tmpf.as_file())? }; + let prog = ProgressWriter::default(); if new_host.spec == host.spec { - println!("Edit cancelled, no changes made."); + prog.info("Edit cancelled, no changes made."); return Ok(()); } host.spec.verify_transition(&new_host.spec)?; let new_spec = RequiredHostSpec::from_spec(&new_host.spec)?; - let prog = ProgressWriter::default(); - // We only support two state transitions right now; switching the image, // or flipping the bootloader ordering. if host.spec.boot_order != new_host.spec.boot_order { - return crate::deploy::rollback(storage).await; + return crate::deploy::rollback(storage, &prog).await; } let fetched = crate::deploy::pull( @@ -1994,7 +2005,7 @@ async fn edit(opts: EditOpts) -> Result<()> { async fn usroverlay(access_mode: FilesystemOverlayAccessMode) -> Result<()> { let status = get_usr_overlay_status()?; if status.is_some() { - println!("An overlayfs is already mounted on /usr"); + ProgressWriter::default().info("An overlayfs is already mounted on /usr"); return Ok(()); } @@ -2051,6 +2062,7 @@ fn join_host_ipc_namespace() -> Result<()> { /// Perform process global initialization. This should be called as early as possible /// in the standard `main` function. #[allow(unsafe_code)] +#[expect(clippy::print_stderr, reason = "runs before tracing is initialized")] pub fn global_init() -> Result<()> { join_host_ipc_namespace()?; // In some cases we re-exec with a temporary binary, @@ -2265,7 +2277,9 @@ async fn run_from_opt(opt: Opt) -> Result { }; match env { Environment::OstreeBooted => usroverlay(access_mode).await, - Environment::ComposefsBooted(_) => composefs_usr_overlay(access_mode), + Environment::ComposefsBooted(_) => { + composefs_usr_overlay(access_mode, &ProgressWriter::default()) + } _ => anyhow::bail!("usroverlay only applies on booted hosts"), } } @@ -2329,7 +2343,7 @@ async fn run_from_opt(opt: Opt) -> Result { write_dumpfile_to.as_deref(), ) .await?; - println!("{digest}"); + writeln!(std::io::stdout(), "{digest}")?; Ok(()) } ContainerOpts::ComputeComposefsDigestFromStorage { @@ -2382,7 +2396,7 @@ async fn run_from_opt(opt: Opt) -> Result { .context("Populating fs")?; fs.transform_for_boot(&repo).context("Preparing for boot")?; let id = fs.compute_image_id(repo.erofs_version()); - println!("{}", id.to_hex()); + writeln!(std::io::stdout(), "{}", id.to_hex())?; if let Some(path) = write_dumpfile_to.as_deref() { let mut w = File::create(path) @@ -2618,7 +2632,7 @@ async fn run_from_opt(opt: Opt) -> Result { std::fs::File::open(&path).with_context(|| format!("Reading {path}"))?; let digest: fsverity::Sha256HashValue = fsverity::measure_verity(&fd)?; let digest = digest.to_hex(); - println!("{digest}"); + writeln!(std::io::stdout(), "{digest}")?; Ok(()) } FsverityOpts::Enable { path } => { @@ -2651,7 +2665,9 @@ async fn run_from_opt(opt: Opt) -> Result { crate::fsck::fsck(&storage, std::io::stdout().lock()).await?; Ok(()) } - InternalsOpts::FixupEtcFstab => crate::deploy::fixup_etc_fstab(&root), + InternalsOpts::FixupEtcFstab => { + crate::deploy::fixup_etc_fstab(&root, &ProgressWriter::default()) + } InternalsOpts::SysusersSync => crate::sysusers_cleanup::run(&root), InternalsOpts::PrintJsonSchema { of } => { let schema = match of { @@ -2664,7 +2680,7 @@ async fn run_from_opt(opt: Opt) -> Result { } InternalsOpts::Cleanup => { let storage = get_storage().await?; - crate::deploy::cleanup(&storage).await + crate::deploy::cleanup(&storage, &ProgressWriter::default()).await } InternalsOpts::Relabel { as_path, path } => { let root = &Dir::open_ambient_dir("/", cap_std::ambient_authority())?; @@ -2694,14 +2710,18 @@ async fn run_from_opt(opt: Opt) -> Result { let loopback = crate::blockdev::LoopbackDevice::new(temp_path) .context("Failed to create loopback device")?; - println!("Created loopback device: {}", loopback.path()); + writeln!( + std::io::stdout(), + "Created loopback device: {}", + loopback.path() + )?; // Close the device to test cleanup loopback .close() .context("Failed to close loopback device")?; - println!("Successfully closed loopback device"); + writeln!(std::io::stdout(), "Successfully closed loopback device")?; Ok(()) } #[cfg(feature = "rhsm")] @@ -2711,7 +2731,7 @@ async fn run_from_opt(opt: Opt) -> Result { use clap::CommandFactory; let cmd = Opt::command(); let json = crate::cli_json::dump_cli_json(&cmd)?; - println!("{}", json); + writeln!(std::io::stdout(), "{json}")?; Ok(()) } InternalsOpts::DirDiff { @@ -2755,8 +2775,9 @@ async fn run_from_opt(opt: Opt) -> Result { } BootedStorageKind::Composefs(booted_cfs) => { + let prog = &ProgressWriter::default(); if reset { - return reset_soft_reboot().map(|()| CliExitStatus::Success); + return reset_soft_reboot(prog).map(|()| CliExitStatus::Success); } prepare_soft_reboot_composefs( @@ -2765,6 +2786,7 @@ async fn run_from_opt(opt: Opt) -> Result { deployment.as_deref(), SoftRebootMode::Required, reboot, + prog, ) .await } @@ -2794,20 +2816,23 @@ async fn run_from_opt(opt: Opt) -> Result { ) .await?; + let mut stdout = std::io::stdout().lock(); if dry_run { - println!("Dry run (no files deleted)"); + writeln!(stdout, "Dry run (no files deleted)")?; } - println!( + writeln!( + stdout, "Objects: {} removed ({} bytes)", gc_result.objects_removed, gc_result.objects_bytes - ); + )?; if gc_result.images_pruned > 0 || gc_result.streams_pruned > 0 { - println!( + writeln!( + stdout, "Pruned symlinks: {} images, {} streams", gc_result.images_pruned, gc_result.streams_pruned - ); + )?; } if assert_no_op { @@ -2836,8 +2861,9 @@ async fn run_from_opt(opt: Opt) -> Result { crate::blockdev::list_dev_by_dir(&dir)? } }; - serde_json::to_writer_pretty(std::io::stdout().lock(), &dev)?; - println!(); + let mut stdout = std::io::stdout().lock(); + serde_json::to_writer_pretty(&mut stdout, &dev)?; + writeln!(stdout)?; Ok(()) } InternalsOpts::Uki(uki_opts) => match uki_opts { diff --git a/crates/lib/src/deploy.rs b/crates/lib/src/deploy.rs index 1f19afc62..9a1466932 100644 --- a/crates/lib/src/deploy.rs +++ b/crates/lib/src/deploy.rs @@ -112,13 +112,18 @@ impl PullProgress { } } - async fn send(&self, event: Event<'_>) { - self.json.send(event.clone()).await; + fn send(&self, event: Event<'_>) { + self.json.send(event.clone()); if let Event::ProgressSteps { description, .. } = &event { self.println(description); } } + /// The writer for `--progress-fd` output and status messages. + pub(crate) fn writer(&self) -> &ProgressWriter { + &self.json + } + fn clear(&self) { if let Err(error) = self.bars.clear() { tracing::debug!(%error, "Clearing pull progress"); @@ -355,7 +360,7 @@ async fn handle_layer_progress_print(mut config: LayerProgressConfig) { steps: layers_bar.position(), steps_total: config.n_layers_to_fetch as u64, subtasks: subtasks.clone(), - }).await; + }); } } else { // If the receiver is disconnected, then we're done @@ -390,7 +395,7 @@ async fn handle_layer_progress_print(mut config: LayerProgressConfig) { steps: layers_bar.position(), steps_total: config.n_layers_to_fetch as u64, subtasks: subtasks.clone().into_iter().chain([subtask.clone()]).collect(), - }).await; + }); } } } @@ -414,25 +419,21 @@ async fn handle_layer_progress_print(mut config: LayerProgressConfig) { // Since the progress notifier closed, we know import has started // use as a heuristic to begin import progress // Cannot be lossy or it is dropped - config - .progress - .json - .send(Event::ProgressSteps { - task: "importing".into(), + config.progress.json.send(Event::ProgressSteps { + task: "importing".into(), + description: "Importing Image".into(), + id: (*config.digest).into(), + steps_cached: 0, + steps: 0, + steps_total: 1, + subtasks: [SubTaskStep { + subtask: "importing".into(), description: "Importing Image".into(), - id: (*config.digest).into(), - steps_cached: 0, - steps: 0, - steps_total: 1, - subtasks: [SubTaskStep { - subtask: "importing".into(), - description: "Importing Image".into(), - id: "importing".into(), - completed: false, - }] - .into(), - }) - .await; + id: "importing".into(), + completed: false, + }] + .into(), + }); } /// Gather all bound images in all deployments, then prune the image store, @@ -552,6 +553,7 @@ pub(crate) async fn prepare_for_pull( imgref: &ImageReference, target_imgref: Option<&OstreeImageReference>, booted_deployment: Option<&ostree::Deployment>, + prog: &ProgressWriter, ) -> Result { let imgref_canonicalized = imgref.clone().canonicalize()?; tracing::debug!("Canonicalized image reference: {imgref_canonicalized:#}"); @@ -562,7 +564,7 @@ pub(crate) async fn prepare_for_pull( } let prep = match imp.prepare().await? { PrepareResult::AlreadyPresent(c) => { - println!("No changes in {imgref:#} => {}", c.manifest_digest); + prog.info(format!("No changes in {imgref:#} => {}", c.manifest_digest)); return Ok(PreparedPullResult::AlreadyPresent(Box::new((*c).into()))); } PrepareResult::Ready(p) => p, @@ -693,6 +695,7 @@ pub(crate) async fn prepare_for_pull_unified( target_imgref: Option<&OstreeImageReference>, store: &Storage, booted_deployment: Option<&ostree::Deployment>, + prog: &ProgressWriter, ) -> Result { // Get or initialize the bootc container storage (same as used for LBIs) let imgstore = store.get_ensure_imgstore()?; @@ -741,7 +744,7 @@ pub(crate) async fn prepare_for_pull_unified( } let prep = match imp.prepare().await? { PrepareResult::AlreadyPresent(c) => { - println!("No changes in {imgref:#} => {}", c.manifest_digest); + prog.info(format!("No changes in {imgref:#} => {}", c.manifest_digest)); return Ok(PreparedPullResult::AlreadyPresent(Box::new((*c).into()))); } PrepareResult::Ready(p) => p, @@ -789,7 +792,16 @@ pub(crate) async fn pull_unified( booted_deployment: Option<&ostree::Deployment>, ) -> Result> { let progress = PullProgress::new(quiet, prog); - match prepare_for_pull_unified(repo, imgref, target_imgref, store, booted_deployment).await? { + match prepare_for_pull_unified( + repo, + imgref, + target_imgref, + store, + booted_deployment, + progress.writer(), + ) + .await? + { PreparedPullResult::AlreadyPresent(existing) => { // Log that the image was already present (Debug level since it's not actionable) const IMAGE_ALREADY_PRESENT_ID: &str = "5c4d3e2f1a0b9c8d7e6f5a4b3c2d1e0f9"; @@ -848,24 +860,21 @@ pub(crate) async fn pull_from_prepared( let import = prepared_image.imp.import(prepared_image.prep).await; printer.await?; // Both the progress and the import are done, so import is done as well - progress - .json - .send(Event::ProgressSteps { - task: "importing".into(), + progress.json.send(Event::ProgressSteps { + task: "importing".into(), + description: "Importing Image".into(), + id: digest_imp.clone().as_ref().into(), + steps_cached: 0, + steps: 1, + steps_total: 1, + subtasks: [SubTaskStep { + subtask: "importing".into(), description: "Importing Image".into(), - id: digest_imp.clone().as_ref().into(), - steps_cached: 0, - steps: 1, - steps_total: 1, - subtasks: [SubTaskStep { - subtask: "importing".into(), - description: "Importing Image".into(), - id: "importing".into(), - completed: true, - }] - .into(), - }) - .await; + id: "importing".into(), + completed: true, + }] + .into(), + }); let import = import?; let imgref_canonicalized = imgref.clone().canonicalize()?; tracing::debug!("Canonicalized image reference: {imgref_canonicalized:#}"); @@ -934,17 +943,15 @@ where "Container image pull failed; retrying in {} seconds ({attempt}/{PULL_MAX_RETRIES}): {error}", retry_delay.as_secs() ); - progress - .send(Event::ProgressSteps { - task: "pulling".into(), - description: description.into(), - id: "pull-retry".into(), - steps_cached: 0, - steps: attempt.into(), - steps_total: PULL_MAX_RETRIES.into(), - subtasks: Vec::new(), - }) - .await; + progress.send(Event::ProgressSteps { + task: "pulling".into(), + description: description.into(), + id: "pull-retry".into(), + steps_cached: 0, + steps: attempt.into(), + steps_total: PULL_MAX_RETRIES.into(), + subtasks: Vec::new(), + }); retries += 1; tokio::time::sleep(retry_delay).await; } @@ -960,7 +967,15 @@ async fn pull_once( progress: PullProgress, booted_deployment: Option<&ostree::Deployment>, ) -> Result> { - match prepare_for_pull(repo, imgref, target_imgref, booted_deployment).await? { + match prepare_for_pull( + repo, + imgref, + target_imgref, + booted_deployment, + progress.writer(), + ) + .await? + { PreparedPullResult::AlreadyPresent(existing) => { // Log that the image was already present (Debug level since it's not actionable) const IMAGE_ALREADY_PRESENT_ID: &str = "5c4d3e2f1a0b9c8d7e6f5a4b3c2d1e0f9"; @@ -1028,7 +1043,7 @@ pub(crate) async fn wipe_ostree(sysroot: Sysroot) -> Result<()> { Ok(()) } -pub(crate) async fn cleanup(sysroot: &Storage) -> Result<()> { +pub(crate) async fn cleanup(sysroot: &Storage, prog: &ProgressWriter) -> Result<()> { // Log the cleanup operation to systemd journal const CLEANUP_JOURNAL_ID: &str = "2f1a0b9c8d7e6f5a4b3c2d1e0f9a8b7c6"; @@ -1042,6 +1057,7 @@ pub(crate) async fn cleanup(sysroot: &Storage) -> Result<()> { // We create clones (just atomic reference bumps) here to move to the thread. let ostree = sysroot.get_ostree_cloned()?; let repo = ostree.repo(); + let prog = prog.clone(); let repo_prune = ostree_ext::tokio_util::spawn_blocking_cancellable_flatten(move |cancellable| { let locked_sysroot = &SysrootLock::from_assumed_locked(&ostree); @@ -1076,10 +1092,10 @@ pub(crate) async fn cleanup(sysroot: &Storage) -> Result<()> { ostree_container::deploy::prune(locked_sysroot).context("Pruning images")?; if !pruned.is_empty() { let size = glib::format_size(pruned.objsize); - println!( + prog.info(format!( "Pruned images: {} (layers: {}, objsize: {})", pruned.n_images, pruned.n_layers, size - ); + )); } else { tracing::debug!("Nothing to prune"); } @@ -1216,7 +1232,11 @@ impl MergeState { /// Pull the bound images referenced by an imported commit before staging it. #[context("Pulling bound images for ostree commit {commit}")] -async fn pull_bound_images_for_commit(sysroot: &Storage, commit: &str) -> Result<()> { +async fn pull_bound_images_for_commit( + sysroot: &Storage, + commit: &str, + prog: &ProgressWriter, +) -> Result<()> { let repo = sysroot.get_ostree()?.repo(); let repo_dir = Dir::reopen_dir(&repo.dfd_borrow())?; let repo_tmp = repo_dir @@ -1243,7 +1263,7 @@ async fn pull_bound_images_for_commit(sysroot: &Storage, commit: &str) -> Result .context("Checking out imported commit")?; let root = td.open_dir(root_name)?; let bound_images = crate::boundimage::query_bound_images(&root)?; - crate::boundimage::pull_images(sysroot, bound_images).await + crate::boundimage::pull_images(sysroot, bound_images, prog).await } /// Stage (queue deployment of) a fetched container image. @@ -1288,8 +1308,7 @@ pub(crate) async fn stage( .into_iter() .chain([subtask.clone()]) .collect(), - }) - .await; + }); subtask.completed = true; subtasks.push(subtask.clone()); @@ -1309,9 +1328,8 @@ pub(crate) async fn stage( .into_iter() .chain([subtask.clone()]) .collect(), - }) - .await; - pull_bound_images_for_commit(sysroot, &image.ostree_commit).await?; + }); + pull_bound_images_for_commit(sysroot, &image.ostree_commit, &prog).await?; subtask.completed = true; subtasks.push(subtask.clone()); @@ -1331,8 +1349,7 @@ pub(crate) async fn stage( .into_iter() .chain([subtask.clone()]) .collect(), - }) - .await; + }); let origin = origin_from_imageref(spec.image)?; crate::deploy::deploy(sysroot, from, image, &origin, lock_finalization).await?; @@ -1354,20 +1371,22 @@ pub(crate) async fn stage( .into_iter() .chain([subtask.clone()]) .collect(), - }) - .await; - crate::deploy::cleanup(sysroot).await?; + }); + crate::deploy::cleanup(sysroot, &prog).await?; if !lock_finalization { - println!("Queued for next boot: {:#}", spec.image); + prog.info(format!("Queued for next boot: {:#}", spec.image)); } else { - println!("Staged but not queued for next boot: {:#}", spec.image); + prog.info(format!( + "Staged but not queued for next boot: {:#}", + spec.image + )); } if let Some(version) = image.version.as_deref() { - println!(" Version: {version}"); + prog.info(format!(" Version: {version}")); } - println!(" Digest: {}", image.manifest_digest); + prog.info(format!(" Digest: {}", image.manifest_digest)); subtask.completed = true; subtasks.push(subtask.clone()); @@ -1383,8 +1402,7 @@ pub(crate) async fn stage( .into_iter() .chain([subtask.clone()]) .collect(), - }) - .await; + }); // Unconditionally create or update /run/reboot-required to signal a reboot is needed. // This is monitored by kured (Kubernetes Reboot Daemon). @@ -1407,7 +1425,7 @@ fn write_reboot_required(image: &str) -> Result<()> { pub(crate) const ROLLBACK_JOURNAL_ID: &str = "26f3b1eb24464d12aa5e7b544a6b5468"; /// Implementation of rollback functionality -pub(crate) async fn rollback(sysroot: &Storage) -> Result<()> { +pub(crate) async fn rollback(sysroot: &Storage, prog: &ProgressWriter) -> Result<()> { let ostree = sysroot.get_ostree()?; let (booted_ostree, deployments, host) = crate::status::get_status_require_booted(ostree)?; @@ -1424,7 +1442,7 @@ pub(crate) async fn rollback(sysroot: &Storage) -> Result<()> { let reverting = new_spec.boot_order == BootOrder::Default; if reverting { - println!("notice: Reverting queued rollback state"); + prog.info("notice: Reverting queued rollback state"); } let rollback_status = host .status @@ -1469,9 +1487,9 @@ pub(crate) async fn rollback(sysroot: &Storage) -> Result<()> { .sysroot .write_deployments(&new_deployments, gio::Cancellable::NONE)?; if reverting { - println!("Next boot: current deployment"); + prog.info("Next boot: current deployment"); } else { - println!("Next boot: rollback deployment"); + prog.info("Next boot: rollback deployment"); } write_reboot_required(rollback_image.manifest_digest.as_ref())?; @@ -1560,7 +1578,7 @@ pub(crate) fn switch_origin_inplace(root: &Dir, imgref: &ImageReference) -> Resu /// A workaround for /// as generated by anaconda. #[context("Updating /etc/fstab for anaconda+composefs")] -pub(crate) fn fixup_etc_fstab(root: &Dir) -> Result<()> { +pub(crate) fn fixup_etc_fstab(root: &Dir, prog: &ProgressWriter) -> Result<()> { let fstab_path = "etc/fstab"; // Read the old file let fd = root @@ -1633,7 +1651,7 @@ pub(crate) fn fixup_etc_fstab(root: &Dir) -> Result<()> { }) .context("Replacing /etc/fstab")?; - println!("Updated /etc/fstab to add `ro` for `/`"); + prog.info("Updated /etc/fstab to add `ro` for `/`"); Ok(()) } @@ -1707,8 +1725,11 @@ mod tests { #[tokio::test(start_paused = true)] async fn test_retry_pull_operation_reports_progress() -> Result<()> { let attempts = std::cell::Cell::new(0); + // ProgressWriter does blocking writes and we only read the pipe + // afterwards on this same thread, so the output must fit in the + // pipe buffer. let (send, recv) = tokio::net::unix::pipe::pipe()?; - let progress = PullProgress::new(true, ProgressWriter::from(send)); + let progress = PullProgress::new(true, ProgressWriter::try_from(send)?); retry_pull_operation(&progress, || { let attempt = attempts.get() + 1; @@ -1726,7 +1747,9 @@ mod tests { let mut lines = BufReader::new(recv).lines(); let start_line = lines.next_line().await?.unwrap(); let start: Event = serde_json::from_str(&start_line)?; - assert!(matches!(start, Event::Start { version } if version == "0.1.0")); + assert!( + matches!(start, Event::Start { version } if version == crate::progress_jsonl::API_VERSION) + ); let retry_line = lines.next_line().await?.unwrap(); let retry: Event = serde_json::from_str(&retry_line)?; @@ -1867,7 +1890,7 @@ mod tests { let default = "UUID=f7436547-20ac-43cb-aa2f-eac9632183f6 /boot auto ro 0 0\n"; tempdir.create_dir_all("etc")?; tempdir.atomic_write("etc/fstab", default)?; - fixup_etc_fstab(&tempdir).unwrap(); + fixup_etc_fstab(&tempdir, &ProgressWriter::default()).unwrap(); assert_eq!(tempdir.read_to_string("etc/fstab")?, default); Ok(()) } @@ -1879,7 +1902,7 @@ mod tests { UUID=6907-17CA /boot/efi vfat umask=0077,shortname=winnt 0 2\n"; tempdir.create_dir_all("etc")?; tempdir.atomic_write("etc/fstab", default)?; - fixup_etc_fstab(&tempdir).unwrap(); + fixup_etc_fstab(&tempdir, &ProgressWriter::default()).unwrap(); assert_eq!(tempdir.read_to_string("etc/fstab")?, default); Ok(()) } @@ -1892,7 +1915,7 @@ UUID=1eef9f42-40e3-4bd8-ae20-e9f2325f8b52 / xfs ro 0 0\n\ UUID=6907-17CA /boot/efi vfat umask=0077,shortname=winnt 0 2\n"; tempdir.create_dir_all("etc")?; tempdir.atomic_write("etc/fstab", default)?; - fixup_etc_fstab(&tempdir).unwrap(); + fixup_etc_fstab(&tempdir, &ProgressWriter::default()).unwrap(); assert_eq!(tempdir.read_to_string("etc/fstab")?, default); Ok(()) } @@ -1910,7 +1933,7 @@ UUID=1eef9f42-40e3-4bd8-ae20-e9f2325f8b52 / xfs defaults,ro 0 0\n\ UUID=6907-17CA /boot/efi vfat umask=0077,shortname=winnt 0 2\n"; tempdir.create_dir_all("etc")?; tempdir.atomic_write("etc/fstab", default)?; - fixup_etc_fstab(&tempdir).unwrap(); + fixup_etc_fstab(&tempdir, &ProgressWriter::default()).unwrap(); assert_eq!(tempdir.read_to_string("etc/fstab")?, modified); Ok(()) } diff --git a/crates/lib/src/image.rs b/crates/lib/src/image.rs index 2221db430..8e90e7578 100644 --- a/crates/lib/src/image.rs +++ b/crates/lib/src/image.rs @@ -13,6 +13,8 @@ //! for environments like ext4 where podman access to the OS image matters //! more than disk efficiency. +use std::io::Write; + use anyhow::{Context, Result, bail}; use bootc_utils::CommandRunExt; use cap_std_ext::cap_std::{self, fs::Dir}; @@ -26,6 +28,7 @@ use crate::{ boundimage::query_bound_images, cli::{ImageListFormat, ImageListType}, podstorage::CStorage, + progress_jsonl::ProgressWriter, spec::Host, store::Storage, utils::async_task_with_spinner, @@ -175,7 +178,7 @@ pub(crate) async fn list_entrypoint( table.add_row([image.image, image.image_type.to_string()]); } - println!("{table}"); + writeln!(std::io::stdout(), "{table}")?; } ImageListFormat::Json => { let mut stdout = std::io::stdout(); @@ -248,10 +251,11 @@ pub(crate) async fn push_entrypoint( let mut opts = ostree_ext::container::store::ExportToOCIOpts::default(); opts.progress_to_stdout = true; - println!("Copying local image {source} to {target} ..."); + let prog = ProgressWriter::default(); + prog.info(format!("Copying local image {source} to {target} ...")); let r = ostree_ext::container::store::export(repo, &source, &target, Some(opts)).await?; - println!("Pushed: {target} {r}"); + prog.info(format!("Pushed: {target} {r}")); Ok(()) } @@ -277,7 +281,7 @@ pub(crate) async fn set_unified_entrypoint() -> Result<()> { let storage = crate::cli::get_storage().await?; if let crate::store::BootedStorageKind::Composefs(booted_cfs) = storage.kind()? { - return set_unified_composefs(&storage, &booted_cfs).await; + return set_unified_composefs(&storage, &booted_cfs, &ProgressWriter::default()).await; } // Initialize floating c_storage early - needed for container operations @@ -293,6 +297,7 @@ pub(crate) async fn set_unified_entrypoint() -> Result<()> { async fn set_unified_composefs( storage: &crate::store::Storage, booted_cfs: &crate::store::BootedComposefs, + prog: &ProgressWriter, ) -> Result<()> { use crate::bootc_composefs::status::get_composefs_status; @@ -321,7 +326,10 @@ async fn set_unified_composefs( // Check if the image is already in bootc storage let img_transport = imgref.to_transport_image()?; if imgstore.exists(&img_transport).await? { - println!("Image {} is already in bootc storage.", imgref.image); + prog.info(format!( + "Image {} is already in bootc storage.", + imgref.image + )); tracing::info!( message_id = SET_UNIFIED_CFS_JOURNAL_ID, bootc.status = "already_unified", @@ -371,7 +379,7 @@ async fn set_unified_composefs( bootc.status = "set_unified_complete", "Unified storage set. Future upgrade/switch will use zero-copy path automatically.", ); - println!("Unified storage enabled for {}.", imgref.image); + prog.info(format!("Unified storage enabled for {}.", imgref.image)); Ok(()) } diff --git a/crates/lib/src/install.rs b/crates/lib/src/install.rs index 36ae98393..0fc0ed996 100644 --- a/crates/lib/src/install.rs +++ b/crates/lib/src/install.rs @@ -767,6 +767,9 @@ pub(crate) struct State { pub(crate) allow_missing_verity_explicit: bool, #[cfg(feature = "install-to-disk")] pub(crate) aboot_disk_layout: Option, + + /// Status output, see [`ProgressWriter::message`] + pub(crate) prog: ProgressWriter, } // Shared read-only global state @@ -1033,7 +1036,7 @@ fn composefs_fetch_reference( } pub(crate) fn print_configuration(opts: InstallPrintConfigurationOpts) -> Result<()> { - let mut install_config = config::load_config()?.unwrap_or_default(); + let mut install_config = config::load_config(&ProgressWriter::default())?.unwrap_or_default(); if !opts.all { install_config.filter_to_external(); } @@ -1058,7 +1061,7 @@ async fn initialize_ostree_root(state: &State, root_setup: &RootSetup) -> Result .cwd(rootfs_dir)? .run()?; } else { - println!("Reusing extant ostree layout"); + state.prog.info("Reusing extant ostree layout"); let path = ".".into(); let _ = crate::utils::open_dir_remount_rw(rootfs_dir, path) @@ -1178,7 +1181,8 @@ async fn pull_ostree_install_once( target_imgref: &ostree_container::OstreeImageReference, progress: PullProgress, ) -> Result> { - let prepared = prepare_for_pull(repo, imgref, Some(target_imgref), None).await?; + let prepared = + prepare_for_pull(repo, imgref, Some(target_imgref), None, progress.writer()).await?; pull_ostree_install_from_prepared(repo, imgref, prepared, progress).await } @@ -1257,6 +1261,7 @@ async fn install_container( Some(&state.target_imgref), storage, None, + progress.writer(), ) .await?; pull_ostree_install_from_prepared(repo, &spec_imgref, prepared, progress.clone()).await? @@ -1414,7 +1419,7 @@ async fn install_container( } if let Some(contents) = state.root_ssh_authorized_keys.as_deref() { - osconfig::inject_root_ssh_authorized_keys(&root, &root, sepolicy, contents)?; + osconfig::inject_root_ssh_authorized_keys(&root, &root, sepolicy, contents, &state.prog)?; } let aleph = InstallAleph::new( @@ -1559,13 +1564,14 @@ pub(crate) fn reexecute_self_for_selinux_if_needed( srcdata: &SourceInfo, override_disable_selinux: bool, reexec_env: &[(&str, &str)], + prog: &ProgressWriter, ) -> Result { // If the target state has SELinux enabled, we need to check the host state. if srcdata.selinux { let host_selinux = crate::lsm::host_selinux_enabled()?; tracing::debug!("Target has SELinux, host={host_selinux}"); let r = if override_disable_selinux { - println!("notice: Target has SELinux enabled, overriding to disable"); + prog.info("notice: Target has SELinux enabled, overriding to disable"); SELinuxFinalState::ForceTargetDisabled } else if host_selinux { // /sys/fs/selinuxfs is not normally mounted, so we do that now. @@ -1733,6 +1739,7 @@ async fn prepare_install( mut composefs_options: InstallComposefsOpts, target_fs: Option, disk_install: bool, + prog: ProgressWriter, ) -> Result> { tracing::trace!("Preparing install"); @@ -1782,7 +1789,7 @@ async fn prepare_install( // Load install configuration from TOML drop-in files early, so that // config values are available when constructing the target image reference. - let install_config = config::load_config()?; + let install_config = config::load_config(&prog)?; if let Some(ref config) = install_config { tracing::debug!("Loaded install configuration"); // Merge config file values into config_opts (CLI takes precedence) @@ -1956,13 +1963,17 @@ async fn prepare_install( setup_sys_mount("efivarfs", EFIVARFS)?; // Now, deal with SELinux state. - let selinux_state = - reexecute_self_for_selinux_if_needed(&source, config_opts.disable_selinux, &reexec_env)?; + let selinux_state = reexecute_self_for_selinux_if_needed( + &source, + config_opts.disable_selinux, + &reexec_env, + &prog, + )?; tracing::debug!("SELinux state: {selinux_state:?}"); - println!("Installing image: {:#}", &target_imgref); + prog.info(format!("Installing image: {:#}", &target_imgref)); if let Some(digest) = source.digest.as_deref() { - println!("Digest: {digest}"); + prog.info(format!("Digest: {digest}")); } // Don't error out if a filesystem is not passed in via cli as we could have @@ -2059,6 +2070,7 @@ async fn prepare_install( allow_missing_verity_explicit, #[cfg(feature = "install-to-disk")] aboot_disk_layout, + prog, }); Ok(state) @@ -2074,7 +2086,9 @@ impl PostFetchState { // Priority: user-specified > image-required > bootupd availability > systemd-boot fallback let detected_bootloader = select_bootloader(state.config_opts.bootloader, image_bootloader, d)?; - println!("Bootloader: {detected_bootloader}"); + state + .prog + .info(format!("Bootloader: {detected_bootloader}")); let r = Self { detected_bootloader, }; @@ -2129,7 +2143,11 @@ async fn install_with_sysroot( if cfg!(target_arch = "s390x") { // TODO: Integrate s390x support into install_via_bootupd // zipl only supports single device - crate::bootloader::install_via_zipl(&rootfs.device_info.require_single_root()?, boot_uuid)?; + crate::bootloader::install_via_zipl( + &rootfs.device_info.require_single_root()?, + boot_uuid, + &state.prog, + )?; } else { match postfetch.detected_bootloader { Bootloader::Grub => { @@ -2145,6 +2163,7 @@ async fn install_with_sysroot( &state.config_opts, Some(chroot_target.as_path()), Some(bind_boot_path.as_path()), + &state.prog, )?; } Bootloader::Systemd | Bootloader::GrubCC | Bootloader::Ukiboot => { @@ -2169,7 +2188,7 @@ async fn install_with_sysroot( } } BoundImages::Unresolved(bound_images) => { - crate::boundimage::pull_images_impl(c_storage, bound_images) + crate::boundimage::pull_images_impl(c_storage, bound_images, &state.prog) .await .context("pulling bound images")?; } @@ -2273,14 +2292,16 @@ async fn install_to_filesystem_impl( match rootfs.device_info.pttype.as_deref() { Some("dos") => crate::utils::medium_visibility_warning( + &state.prog, "Installing to `dos` format partitions is not recommended", ), Some("gpt") => { // The only thing we should be using in general } - Some(o) => { - crate::utils::medium_visibility_warning(&format!("Unknown partition table type {o}")) - } + Some(o) => crate::utils::medium_visibility_warning( + &state.prog, + &format!("Unknown partition table type {o}"), + ), None => { // No partition table type - may be a filesystem install or loop device } @@ -2403,8 +2424,8 @@ async fn install_to_filesystem_impl( Ok(()) } -fn installation_complete() { - println!("Installation complete!"); +fn installation_complete(prog: &ProgressWriter) { + prog.info("Installation complete!"); } /// Implementation of the `bootc install to-disk` CLI command. @@ -2420,6 +2441,7 @@ pub(crate) async fn install_to_disk(mut opts: InstallToDiskOpts) -> Result<()> { .map(|s| s.as_str()) .unwrap_or("none"); let target_device = opts.block_opts.device.as_str(); + let prog = ProgressWriter::default(); tracing::info!( message_id = INSTALL_DISK_JOURNAL_ID, @@ -2439,6 +2461,7 @@ pub(crate) async fn install_to_disk(mut opts: InstallToDiskOpts) -> Result<()> { if opts.via_loopback { if !opts.config_opts.generic_image { crate::utils::medium_visibility_warning( + &prog, "Automatically enabling --generic-image when installing via loopback", ); opts.config_opts.generic_image = true; @@ -2460,6 +2483,7 @@ pub(crate) async fn install_to_disk(mut opts: InstallToDiskOpts) -> Result<()> { opts.composefs_opts, block_opts.filesystem, true, + prog.clone(), ) .await?; @@ -2507,7 +2531,7 @@ pub(crate) async fn install_to_disk(mut opts: InstallToDiskOpts) -> Result<()> { tracing::warn!("Failed to consume state Arc"); } - installation_complete(); + installation_complete(&prog); Ok(()) } @@ -2719,7 +2743,7 @@ fn find_root_args_to_inherit( Ok(RootMountInfo { mount_spec, kargs }) } -fn warn_on_host_root(rootfs_fd: &Dir) -> Result<()> { +fn warn_on_host_root(rootfs_fd: &Dir, prog: &ProgressWriter) -> Result<()> { // Seconds for which we wait while warning const DELAY_SECONDS: u64 = 20; @@ -2732,12 +2756,16 @@ fn warn_on_host_root(rootfs_fd: &Dir) -> Result<()> { } let dashes = "----------------------------"; let timeout = Duration::from_secs(DELAY_SECONDS); - eprintln!("{dashes}"); + // Purely visual framing, so only for the terminal + let _ = writeln!(std::io::stderr(), "{dashes}"); crate::utils::medium_visibility_warning( + prog, "WARNING: This operation will OVERWRITE THE BOOTED HOST ROOT FILESYSTEM and is NOT REVERSIBLE.", ); - eprintln!("Waiting {timeout:?} to continue; interrupt (Control-C) to cancel."); - eprintln!("{dashes}"); + prog.warning(format!( + "Waiting {timeout:?} to continue; interrupt (Control-C) to cancel." + )); + let _ = writeln!(std::io::stderr(), "{dashes}"); let bar = indicatif::ProgressBar::new_spinner(); bar.enable_steady_tick(Duration::from_millis(100)); @@ -2768,6 +2796,7 @@ pub(crate) async fn install_to_filesystem( .map(|s| s.as_str()) .unwrap_or("none"); let target_path = opts.filesystem_opts.root_path.as_str(); + let prog = ProgressWriter::default(); tracing::info!( message_id = INSTALL_FILESYSTEM_JOURNAL_ID, @@ -2867,18 +2896,19 @@ pub(crate) async fn install_to_filesystem( opts.composefs_opts, Some(inspect.fstype.as_str().try_into()?), false, + prog.clone(), ) .await?; // Check to see if this happens to be the real host root if !fsopts.acknowledge_destructive { - warn_on_host_root(&target_rootfs_fd)?; + warn_on_host_root(&target_rootfs_fd, &prog)?; } match fsopts.replace { Some(ReplaceMode::Wipe) => { let rootfs_fd = rootfs_fd.try_clone()?; - println!("Wiping contents of root"); + prog.info("Wiping contents of root"); tokio::task::spawn_blocking(move || remove_all_in_dir_no_xdev(&rootfs_fd, true)) .await??; } @@ -3037,7 +3067,7 @@ pub(crate) async fn install_to_filesystem( // Drop all data about the root except the path to ensure any file descriptors etc. are closed. drop(rootfs); - installation_complete(); + installation_complete(&prog); Ok(()) } diff --git a/crates/lib/src/install/baseline.rs b/crates/lib/src/install/baseline.rs index 28e89a972..dfcd865b6 100644 --- a/crates/lib/src/install/baseline.rs +++ b/crates/lib/src/install/baseline.rs @@ -35,6 +35,7 @@ use super::State; use super::config::Filesystem; use crate::bootloader::systemd_version; use crate::discoverable_partition_specification::BIOS_BOOT; +use crate::progress_jsonl::ProgressWriter; use crate::task::Task; #[cfg(feature = "install-to-disk")] use bootc_mount::is_mounted_in_pid1_mountns; @@ -183,8 +184,8 @@ fn mkfs<'a>( Ok(u) } -pub(crate) fn wipefs(dev: &Utf8Path) -> Result<()> { - println!("Wiping device {dev}"); +pub(crate) fn wipefs(dev: &Utf8Path, prog: &ProgressWriter) -> Result<()> { + prog.info(format!("Wiping device {dev}")); Command::new("wipefs") .args(["-a", dev.as_str()]) .run_inherited_with_cmd_context() @@ -891,6 +892,7 @@ pub(crate) fn install_create_rootfs( run_repart: bool, ) -> Result { let install_config = state.install_config.as_ref(); + let prog = &state.prog; let luks_name = "root"; // Verify that the target is empty (if not already wiped in particular, but it's // also good to verify that the wipe worked) @@ -906,11 +908,11 @@ pub(crate) fn install_create_rootfs( let dev = &opts.device; for child in device.children.iter().flatten() { let child = child.path(); - println!("Wiping {child}"); - wipefs(Utf8Path::new(&child))?; + prog.info(format!("Wiping {child}")); + wipefs(Utf8Path::new(&child), prog)?; } - println!("Wiping {dev}"); - wipefs(dev)?; + prog.info(format!("Wiping {dev}")); + wipefs(dev, prog)?; } else if device.has_children() { anyhow::bail!( "Detected existing partitions on {}; use e.g. `wipefs` or --wipe if you intend to overwrite", @@ -967,14 +969,14 @@ pub(crate) fn install_create_rootfs( "aboot disk layouts require the composefs backend" ); } - println!("Block setup: {block_setup}"); - println!(" Size: {}", device.size); - println!(" Serial: {serial}"); - println!(" Model: {model}"); - println!( + prog.info(format!("Block setup: {block_setup}")); + prog.info(format!(" Size: {}", device.size)); + prog.info(format!(" Serial: {serial}")); + prog.info(format!(" Model: {model}")); + prog.info(format!( " Partitions: {}", if discoverable { "Discoverable" } else { "UUID" } - ); + )); let root_size = opts .root_size diff --git a/crates/lib/src/install/completion.rs b/crates/lib/src/install/completion.rs index 047d2632d..5dde74c1a 100644 --- a/crates/lib/src/install/completion.rs +++ b/crates/lib/src/install/completion.rs @@ -15,6 +15,7 @@ use rustix::fs::Mode; use rustix::fs::OFlags; use crate::podstorage::CStorage; +use crate::progress_jsonl::ProgressWriter; use crate::utils::deployment_fd; use super::config; @@ -42,7 +43,11 @@ pub(crate) const RUN_BOOTC_INSTALL_RECONCILED: &str = "run/bootc-install-reconci /// Assuming that the current root is an ostree deployment, pull kargs /// from it and inject them. -fn reconcile_kargs(sysroot: &ostree::Sysroot, deployment: &ostree::Deployment) -> Result<()> { +fn reconcile_kargs( + sysroot: &ostree::Sysroot, + deployment: &ostree::Deployment, + prog: &ProgressWriter, +) -> Result<()> { let deployment_root = &crate::utils::deployment_fd(sysroot, deployment)?; let cancellable = gio::Cancellable::NONE; @@ -58,7 +63,7 @@ fn reconcile_kargs(sysroot: &ostree::Sysroot, deployment: &ostree::Deployment) - let current_kargs = ostree::KernelArgs::from_string(¤t_kargs); // Keep this in sync with install_container - let install_config = config::load_config()?; + let install_config = config::load_config(prog)?; let install_config_kargs = install_config .as_ref() .and_then(|c| c.kargs.as_ref()) @@ -197,6 +202,7 @@ fn open_proc1_root(rootfs: &Dir) -> Result { /// Core entrypoint invoked when we are likely being invoked from inside Anaconda as a `%post`. pub(crate) async fn run_from_anaconda(rootfs: &Dir) -> Result<()> { + let prog = &ProgressWriter::default(); // unshare our mount namespace, so any *further* mounts aren't leaked. // Note that because this does a re-exec, anything *before* this point // should be idempotent. @@ -221,7 +227,7 @@ pub(crate) async fn run_from_anaconda(rootfs: &Dir) -> Result<()> { .try_exists(RUN_BOOTC_INSTALL_RECONCILED) .context("Querying reconciliation")? { - println!("Reconciliation already completed."); + prog.info("Reconciliation already completed."); return Ok(()); } @@ -235,7 +241,7 @@ pub(crate) async fn run_from_anaconda(rootfs: &Dir) -> Result<()> { sysroot .load(gio::Cancellable::NONE) .context("Loading sysroot")?; - impl_completion(rootfs, &sysroot, None).await?; + impl_completion(rootfs, &sysroot, None, prog).await?; proc1_root .write(RUN_BOOTC_INSTALL_RECONCILED, b"") @@ -253,7 +259,13 @@ pub async fn run_from_ostree(rootfs: &Dir, sysroot: &Utf8Path, stateroot: &str) let sysroot = ostree::Sysroot::new(Some(&gio::File::for_path(sysroot))); sysroot.load(gio::Cancellable::NONE)?; - impl_completion(rootfs, &sysroot, Some(stateroot)).await?; + impl_completion( + rootfs, + &sysroot, + Some(stateroot), + &ProgressWriter::default(), + ) + .await?; // In this case we write the completion directly to /run as we're running from // the host context. @@ -275,6 +287,7 @@ pub(crate) async fn impl_completion( rootfs: &Dir, sysroot: &ostree::Sysroot, stateroot: Option<&str>, + prog: &ProgressWriter, ) -> Result<()> { // Log the completion operation to systemd journal const COMPLETION_JOURNAL_ID: &str = "0f9a8b7c6d5e4f3a2b1c0d9e8f7a6b5c4"; @@ -295,7 +308,7 @@ pub(crate) async fn impl_completion( let rundir = &rootfs.open_dir(rundir)?; // ostree-ext doesn't do kargs, so handle that now - reconcile_kargs(&sysroot, deployment)?; + reconcile_kargs(&sysroot, deployment, prog)?; // ostree-ext doesn't do logically bound images let bound_images = crate::boundimage::query_bound_images_for_deployment(sysroot, deployment)?; @@ -316,7 +329,7 @@ pub(crate) async fn impl_completion( // When we're run through ostree, we only lazily initialize the podman storage to avoid // having a hard dependency on it. let imgstorage = CStorage::create(&sysroot_dir, &rundir, sepolicy.as_ref())?; - crate::boundimage::pull_images_impl(&imgstorage, bound_images) + crate::boundimage::pull_images_impl(&imgstorage, bound_images, prog) .await .context("pulling bound images")?; // Ensure the image storage is SELinux-labeled after all pulls are complete. diff --git a/crates/lib/src/install/config.rs b/crates/lib/src/install/config.rs index 55fdd42f9..76c844fe5 100644 --- a/crates/lib/src/install/config.rs +++ b/crates/lib/src/install/config.rs @@ -2,6 +2,7 @@ //! //! This module handles the TOML configuration file for `bootc install`. +use crate::progress_jsonl::ProgressWriter; use crate::spec::Bootloader; use anyhow::{Context, Result}; use clap::ValueEnum; @@ -289,7 +290,7 @@ impl InstallConfiguration { #[context("Loading configuration")] /// Load the install configuration, merging all found configuration files. -pub(crate) fn load_config() -> Result> { +pub(crate) fn load_config(prog: &ProgressWriter) -> Result> { let env = EnvProperties { sys_arch: std::env::consts::ARCH.to_string(), }; @@ -305,7 +306,7 @@ pub(crate) fn load_config() -> Result> { }) .with_context(|| format!("Parsing {path:?}"))?; for key in unused { - eprintln!("warning: {path:?}: Unknown key {key}"); + prog.warning(format!("warning: {path:?}: Unknown key {key}")); } if let Some(config) = config.as_mut() { if let Some(install) = c.install { diff --git a/crates/lib/src/install/osconfig.rs b/crates/lib/src/install/osconfig.rs index c5117f603..43ca5c202 100644 --- a/crates/lib/src/install/osconfig.rs +++ b/crates/lib/src/install/osconfig.rs @@ -8,6 +8,8 @@ use cap_std_ext::{cap_std, dirext::CapStdExtDirExt}; use fn_error_context::context; use ostree_ext::ostree; +use crate::progress_jsonl::ProgressWriter; + const ETC_TMPFILES: &str = "etc/tmpfiles.d"; const ROOT_SSH_TMPFILE: &str = "bootc-root-ssh.conf"; @@ -20,6 +22,7 @@ pub(crate) fn inject_root_ssh_authorized_keys( dest: &Dir, sepolicy: Option<&ostree::SePolicy>, contents: &str, + prog: &ProgressWriter, ) -> Result<()> { // While not documented right now, this one looks like it does not newline wrap let b64_encoded = ostree_ext::glib::base64_encode(contents.as_bytes()); @@ -46,7 +49,7 @@ pub(crate) fn inject_root_ssh_authorized_keys( w.write_all(tmpfiles_content.as_bytes()).map_err(Into::into) })?; - println!("Injected: {target}"); + prog.info(format!("Injected: {target}")); Ok(()) } @@ -73,6 +76,7 @@ mod tests { root, Some(&policy), "ssh-ed25519 ABCDE example@demo\n", + &ProgressWriter::default(), )?; let expected = crate::lsm::require_label( @@ -98,8 +102,14 @@ mod tests { root.create_dir("etc")?; // Test with a symlink root.symlink("var/roothome", "root")?; - inject_root_ssh_authorized_keys(root, root, None, "ssh-ed25519 ABCDE example@demo\n") - .unwrap(); + inject_root_ssh_authorized_keys( + root, + root, + None, + "ssh-ed25519 ABCDE example@demo\n", + &ProgressWriter::default(), + ) + .unwrap(); let content = root.read_to_string(format!("etc/tmpfiles.d/{ROOT_SSH_TMPFILE}"))?; assert_eq!( @@ -116,8 +126,14 @@ mod tests { root.create_dir("etc")?; root.create_dir("root")?; - inject_root_ssh_authorized_keys(root, root, None, "ssh-ed25519 ABCDE example@demo\n") - .unwrap(); + inject_root_ssh_authorized_keys( + root, + root, + None, + "ssh-ed25519 ABCDE example@demo\n", + &ProgressWriter::default(), + ) + .unwrap(); let content = root.read_to_string(format!("etc/tmpfiles.d/{ROOT_SSH_TMPFILE}"))?; assert_eq!( @@ -134,8 +150,14 @@ mod tests { root.symlink("var/roothome", "root")?; dest.create_dir("etc")?; - inject_root_ssh_authorized_keys(root, dest, None, "ssh-ed25519 ABCDE example@demo\n") - .unwrap(); + inject_root_ssh_authorized_keys( + root, + dest, + None, + "ssh-ed25519 ABCDE example@demo\n", + &ProgressWriter::default(), + ) + .unwrap(); let content = dest.read_to_string(format!("etc/tmpfiles.d/{ROOT_SSH_TMPFILE}"))?; assert_eq!( diff --git a/crates/lib/src/journal.rs b/crates/lib/src/journal.rs index bed50ec62..11271b522 100644 --- a/crates/lib/src/journal.rs +++ b/crates/lib/src/journal.rs @@ -9,6 +9,10 @@ static EMITTED_JOURNAL_ERROR: AtomicBool = AtomicBool::new(false); /// Wrapper for structured logging which is an explicit no-op /// when systemd is not in use (e.g. in a container). +#[expect( + clippy::print_stderr, + reason = "the journal is failing, and tracing to stderr is filtered by default" +)] pub(crate) fn journal_send( priority: libsystemd::logging::Priority, msg: &str, diff --git a/crates/lib/src/lib.rs b/crates/lib/src/lib.rs index 428ba21a2..e9c54d7f4 100644 --- a/crates/lib/src/lib.rs +++ b/crates/lib/src/lib.rs @@ -1,6 +1,13 @@ // The internals docs are built with --document-private-items, so allow // linking to private items from module documentation. #![allow(rustdoc::private_intra_doc_links)] +// Library code should not write to stdout/stderr behind the caller's back, +// as that bypasses --progress-fd and can corrupt machine-readable output. +// Use `ProgressWriter::message()` for status output meant for the user, +// `tracing` for diagnostics, or write a command's results to an explicit +// `impl Write`. The anstream equivalents are covered by disallowed-macros +// in clippy.toml. +#![deny(clippy::print_stdout, clippy::print_stderr, clippy::disallowed_macros)] //! # Bootable container tool //! diff --git a/crates/lib/src/mount.rs b/crates/lib/src/mount.rs index 56d3870a1..bfc450ff0 100644 --- a/crates/lib/src/mount.rs +++ b/crates/lib/src/mount.rs @@ -30,6 +30,7 @@ use ostree_ext::{ostree, ostree_prepareroot}; use rustix::mount::{MoveMountFlags, OpenTreeFlags, move_mount, open_tree}; use crate::composefs_consts::STATE_DIR_RELATIVE; +use crate::progress_jsonl::ProgressWriter; const ETC: &str = "etc"; const VAR: &str = "var"; @@ -58,14 +59,16 @@ pub(crate) struct MountOpts { /// Open the mount target. Like mount(8), this mounts wherever the caller asks; /// like systemd, it warns when that hides existing content. -fn open_mount_target(target: &Utf8Path) -> Result { +fn open_mount_target(target: &Utf8Path, prog: &ProgressWriter) -> Result { let target_dir = Dir::open_ambient_dir(target, ambient_authority()) .with_context(|| format!("Opening mount target {target}"))?; let mut entries = target_dir .entries() .with_context(|| format!("Reading mount target {target}"))?; if entries.next().is_some() { - eprintln!("warning: mount target {target} is not empty; its contents will be hidden"); + prog.warning(format!( + "warning: mount target {target} is not empty; its contents will be hidden" + )); } Ok(target_dir) } @@ -94,7 +97,7 @@ pub(crate) async fn mount(opts: MountOpts) -> Result<()> { // clap already requires --latest, the only selector so far. ensure!(opts.latest, "no deployment selected; pass --latest"); let target = &opts.target; - let target_dir = open_mount_target(target)?; + let target_dir = open_mount_target(target, &ProgressWriter::default())?; let sysroot_dir = Dir::open_ambient_dir(&opts.sysroot, ambient_authority()) .with_context(|| format!("Opening target sysroot {}", opts.sysroot))?; @@ -294,6 +297,7 @@ fn attach(tree: impl AsFd, target: &Dir, name: &str) -> Result<()> { mod tests { use super::{DeploymentBackend, open_mount_target, select_backend}; use crate::cli::{InstallOpts, Opt}; + use crate::progress_jsonl::ProgressWriter; use camino::Utf8Path; use clap::Parser; @@ -345,10 +349,11 @@ mod tests { let temp = Utf8Path::from_path(temp.path()).unwrap(); let target = temp.join("target"); std::fs::create_dir(&target).unwrap(); - open_mount_target(&target).unwrap(); + let prog = &ProgressWriter::default(); + open_mount_target(&target, prog).unwrap(); // Non-empty only warns, as with systemd. std::fs::create_dir(target.join("nested")).unwrap(); - open_mount_target(&target).unwrap(); - assert!(open_mount_target(&temp.join("missing")).is_err()); + open_mount_target(&target, prog).unwrap(); + assert!(open_mount_target(&temp.join("missing"), prog).is_err()); } } diff --git a/crates/lib/src/progress_jsonl.rs b/crates/lib/src/progress_jsonl.rs index 4b9341d81..362428f8b 100644 --- a/crates/lib/src/progress_jsonl.rs +++ b/crates/lib/src/progress_jsonl.rs @@ -6,19 +6,20 @@ use canon_json::CanonJsonSerialize; use schemars::JsonSchema; use serde::Serialize; use std::borrow::Cow; +use std::fs::File; +use std::io::{BufWriter, Write}; use std::os::fd::{FromRawFd, OwnedFd, RawFd}; use std::str::FromStr; -use std::sync::Arc; +use std::sync::{Arc, Mutex}; use std::time::Instant; -use tokio::io::{AsyncWriteExt, BufWriter}; +#[cfg(test)] use tokio::net::unix::pipe::Sender; -use tokio::sync::Mutex; // Maximum number of times per second that an event will be written. const REFRESH_HZ: u16 = 5; /// Semantic version of the protocol. -const API_VERSION: &str = "0.1.0"; +pub(crate) const API_VERSION: &str = "0.2.0"; /// An incremental update to e.g. a container image layer download. /// The first time a given "subtask" name is seen, a new progress bar should be created. @@ -70,6 +71,17 @@ pub struct SubTaskStep<'t> { pub completed: bool, } +/// The severity of a `Message` event. +#[derive(Debug, Clone, Copy, serde::Serialize, serde::Deserialize, JsonSchema, PartialEq, Eq)] +#[serde(rename_all = "lowercase")] +pub enum MessageLevel { + /// Regular status output, e.g. which image was queued for the next boot. + Info, + /// Something the user should pay attention to, which did not cause + /// the operation to fail. + Warning, +} + /// An event emitted as JSON. #[derive(Debug, Clone, serde::Serialize, serde::Deserialize, JsonSchema, PartialEq, Eq)] #[serde( @@ -135,6 +147,15 @@ pub enum Event<'t> { /// The currently running subtasks. subtasks: Vec>, }, + /// A human readable status message, with the same text that is + /// printed to the terminal. The text is not a stable interface. + Message { + /// The severity of the message. + level: MessageLevel, + /// The message text, without a trailing newline. + #[serde(borrow)] + text: Cow<'t, str>, + }, } #[derive(Debug, Clone, PartialEq, Eq)] @@ -158,29 +179,26 @@ struct ProgressWriterInner { /// true if we sent the initial Start message sent_start: bool, last_write: Option, - fd: BufWriter, + fd: BufWriter, } +/// Writes progress events as JSON lines to the file descriptor given +/// with `--progress-fd`, if any. +/// +/// Writes are blocking so that this can be used from both sync and +/// async code. Events are small and the lossy ones are rate limited, so +/// this only blocks if the reader stops draining the pipe. #[derive(Clone, Debug, Default)] pub(crate) struct ProgressWriter { inner: Arc>>, } -impl TryFrom for ProgressWriter { - type Error = anyhow::Error; - - fn try_from(value: OwnedFd) -> Result { - let value = Sender::from_owned_fd(value)?; - Ok(Self::from(value)) - } -} - -impl From for ProgressWriter { - fn from(value: Sender) -> Self { +impl From for ProgressWriter { + fn from(value: OwnedFd) -> Self { let inner = ProgressWriterInner { sent_start: false, last_write: None, - fd: BufWriter::new(value), + fd: BufWriter::new(File::from(value)), }; Self { inner: Arc::new(Some(inner).into()), @@ -188,31 +206,48 @@ impl From for ProgressWriter { } } +#[cfg(test)] +impl TryFrom for ProgressWriter { + type Error = anyhow::Error; + + fn try_from(value: Sender) -> Result { + Ok(value.into_blocking_fd()?.into()) + } +} + impl TryFrom for ProgressWriter { type Error = anyhow::Error; #[allow(unsafe_code)] fn try_from(fd: RawProgressFd) -> Result { - unsafe { OwnedFd::from_raw_fd(fd.0) }.try_into() + let fd = unsafe { OwnedFd::from_raw_fd(fd.0) }; + // We do blocking writes, so make sure the caller didn't hand us a + // non-blocking fd, which would fail with EAGAIN when the pipe is full. + let flags = rustix::fs::fcntl_getfl(&fd)?; + if flags.contains(rustix::fs::OFlags::NONBLOCK) { + rustix::fs::fcntl_setfl(&fd, flags - rustix::fs::OFlags::NONBLOCK)?; + } + Ok(fd.into()) } } impl ProgressWriter { /// Serialize the target value as a single line of JSON and write it. - async fn send_impl_inner(inner: &mut ProgressWriterInner, v: T) -> Result<()> { + fn send_impl_inner(inner: &mut ProgressWriterInner, v: T) -> Result<()> { // canon_json is guaranteed not to output newlines here let buf = v.to_canon_json_vec()?; - inner.fd.write_all(&buf).await?; + inner.fd.write_all(&buf)?; // We always end in a newline - inner.fd.write_all(b"\n").await?; + inner.fd.write_all(b"\n")?; // And flush to ensure the remote side sees updates immediately - inner.fd.flush().await?; + inner.fd.flush()?; Ok(()) } /// Serialize the target object to JSON as a single line - pub(crate) async fn send_impl(&self, v: T, required: bool) -> Result<()> { - let mut guard = self.inner.lock().await; + fn send_impl(&self, v: T, required: bool) -> Result<()> { + // SAFETY: Propagating panics from the mutex here is intentional + let mut guard = self.inner.lock().unwrap(); // Check if we have an inner value; if not, nothing to do. let Some(inner) = guard.as_mut() else { return Ok(()); @@ -224,7 +259,7 @@ impl ProgressWriter { let start = Event::Start { version: API_VERSION.into(), }; - Self::send_impl_inner(inner, &start).await?; + Self::send_impl_inner(inner, &start)?; } // For messages that can be dropped, if we already sent an update within this cycle, discard this one. @@ -239,41 +274,60 @@ impl ProgressWriter { } } - Self::send_impl_inner(inner, &v).await?; + Self::send_impl_inner(inner, &v)?; // Update the last write time inner.last_write = Some(now); Ok(()) } /// Send an event. - pub(crate) async fn send(&self, event: Event<'_>) { - if let Err(e) = self.send_impl(event, true).await { - eprintln!("Failed to write to jsonl: {e}"); - // Stop writing to fd but let process continue - // SAFETY: Propagating panics from the mutex here is intentional - let _ = self.inner.lock().await.take(); - } + pub(crate) fn send(&self, event: Event<'_>) { + self.send_or_disable(event, true) } /// Send an event that can be dropped. - pub(crate) async fn send_lossy(&self, event: Event<'_>) { - if let Err(e) = self.send_impl(event, false).await { + pub(crate) fn send_lossy(&self, event: Event<'_>) { + self.send_or_disable(event, false) + } + + /// Print a status message for the user, and if a progress fd is + /// attached, also send it there as an [`Event::Message`]. + /// + /// Like `println!()` and `eprintln!()`, info messages go to stdout + /// and warnings to stderr; unlike them, a failure to write (e.g. a + /// closed pipe) is ignored rather than causing a panic. + pub(crate) fn message(&self, level: MessageLevel, text: impl AsRef) { + let text = text.as_ref(); + let _ = match level { + MessageLevel::Info => writeln!(std::io::stdout().lock(), "{text}"), + MessageLevel::Warning => writeln!(std::io::stderr().lock(), "{text}"), + }; + self.send(Event::Message { + level, + text: text.into(), + }); + } + + /// Shorthand for [`Self::message`] with [`MessageLevel::Info`]. + pub(crate) fn info(&self, text: impl AsRef) { + self.message(MessageLevel::Info, text) + } + + /// Shorthand for [`Self::message`] with [`MessageLevel::Warning`]. + pub(crate) fn warning(&self, text: impl AsRef) { + self.message(MessageLevel::Warning, text) + } + + #[expect( + clippy::print_stderr, + reason = "the progress fd itself is failing, so report it on stderr" + )] + fn send_or_disable(&self, event: Event<'_>, required: bool) { + if let Err(e) = self.send_impl(event, required) { eprintln!("Failed to write to jsonl: {e}"); // Stop writing to fd but let process continue // SAFETY: Propagating panics from the mutex here is intentional - let _ = self.inner.lock().await.take(); - } - } - - /// Flush remaining data and return the underlying file. - #[allow(dead_code)] - pub(crate) async fn into_inner(self) -> Result> { - // SAFETY: Propagating panics from the mutex here is intentional - let mut mutex = self.inner.lock().await; - if let Some(inner) = mutex.take() { - Ok(Some(inner.fd.into_inner())) - } else { - Ok(None) + let _ = self.inner.lock().unwrap().take(); } } } @@ -308,13 +362,24 @@ mod test { steps_total: 3, subtasks: Vec::new(), }, + Event::Message { + level: MessageLevel::Warning, + text: "some warning".into(), + }, ]; + // ProgressWriter does blocking writes, and the sender and reader + // below run on the same thread, so the whole output must fit in + // the pipe buffer or this test would deadlock. let (send, recv) = tokio::net::unix::pipe::pipe()?; let testvalues_sender = testvalues.iter().cloned(); let sender = async move { let w = ProgressWriter::try_from(send)?; for value in testvalues_sender { - w.send(value).await; + match value { + // Exercise the helper, which should send the same event + Event::Message { level, text } => w.message(level, text), + value => w.send(value), + } } anyhow::Ok(()) }; diff --git a/crates/lib/src/task.rs b/crates/lib/src/task.rs index 8af8196f7..ec7573694 100644 --- a/crates/lib/src/task.rs +++ b/crates/lib/src/task.rs @@ -9,6 +9,8 @@ use cap_std::fs::Dir; use cap_std_ext::cap_std; use cap_std_ext::prelude::CapStdExtCommandExt; +use crate::progress_jsonl::ProgressWriter; + /// How much information we output #[derive(Debug, PartialEq, Eq, Default)] enum CmdVerbosity { @@ -94,28 +96,26 @@ impl Task { } fn pre_run_output(&self) { + // Tasks mostly run during install, which doesn't take --progress-fd + // yet, so they aren't given a writer. + let prog = ProgressWriter::default(); match self.verbosity { CmdVerbosity::Quiet => {} CmdVerbosity::Description => { - println!("{}", self.description); + prog.info(&self.description); } CmdVerbosity::Verbose => { // Output the description first - println!("{}", self.description); + prog.info(&self.description); - // Lock stdout so we buffer - let mut stdout = std::io::stdout().lock(); - let cmd_args = std::iter::once(self.cmd.get_program()) + let cmdline = std::iter::once(self.cmd.get_program()) .chain(self.cmd.get_args()) - .map(|arg| arg.to_string_lossy()); - // We unwrap() here to match the default for println!() even though - // arguably that's wrong - stdout.write_all(b">").unwrap(); - for s in cmd_args { - stdout.write_all(b" ").unwrap(); - stdout.write_all(s.as_bytes()).unwrap(); - } - stdout.write_all(b"\n").unwrap(); + .fold(String::from(">"), |mut buf, arg| { + buf.push(' '); + buf.push_str(&arg.to_string_lossy()); + buf + }); + prog.info(cmdline); } } } diff --git a/crates/lib/src/utils.rs b/crates/lib/src/utils.rs index 7941606a1..070a13f23 100644 --- a/crates/lib/src/utils.rs +++ b/crates/lib/src/utils.rs @@ -18,6 +18,8 @@ use ostree::glib; use ostree_ext::container::SignatureSource; use ostree_ext::ostree; +use crate::progress_jsonl::{Event, MessageLevel, ProgressWriter}; + /// Try to look for keys injected by e.g. rpm-ostree requesting machine-local /// changes; if any are present, return `true`. pub(crate) fn origin_has_rpmostree_stuff(kf: &glib::KeyFile) -> bool { @@ -170,12 +172,23 @@ pub(crate) fn sigpolicy_from_opt(enforce_container_verification: bool) -> Signat /// Output a warning message that we want to be quite visible. /// The process (thread) execution will be delayed for a short time. -pub(crate) fn medium_visibility_warning(s: &str) { +/// +/// Unlike [`ProgressWriter::message`], this highlights the warning on +/// the terminal; it is sent to any progress fd as a regular warning. +#[expect( + clippy::disallowed_macros, + reason = "colored output for the terminal; also sent as a Message event below" +)] +pub(crate) fn medium_visibility_warning(prog: &ProgressWriter, s: &str) { anstream::eprintln!( "{}{s}{}", anstyle::AnsiColor::Red.render_fg(), anstyle::Reset.render() ); + prog.send(Event::Message { + level: MessageLevel::Warning, + text: s.into(), + }); // When warning, add a sleep to ensure it's seen std::thread::sleep(std::time::Duration::from_secs(1)); } @@ -184,6 +197,10 @@ pub(crate) fn medium_visibility_warning(s: &str) { /// with an automatic spinner to show that we're not blocked. /// Note that generally the called function should not output /// anything to stderr as this will interfere with the spinner. +#[expect( + clippy::print_stderr, + reason = "fallback when the progress bar is hidden (no tty)" +)] pub(crate) async fn async_task_with_spinner(msg: &str, f: F) -> T where F: Future, diff --git a/docs/src/bootc-experimental-progress-fd.7.md b/docs/src/bootc-experimental-progress-fd.7.md index 597b86a38..d7306a23f 100644 --- a/docs/src/bootc-experimental-progress-fd.7.md +++ b/docs/src/bootc-experimental-progress-fd.7.md @@ -25,6 +25,16 @@ and removing old images. Note that new stages or fields may be added at any time. +Status messages that bootc prints for the user (e.g. which image was +queued for the next boot) are also sent as `Message` events, with a +`level` of `info` or `warning` and the same `text` as printed to the +terminal. That text is meant for humans and may change between releases, +so don't parse it. `Message` events were added in version 0.2.0 of the +protocol, as reported in the initial `Start` event. + +New event types may also be added at any time, so consumers must ignore +events with a `type` they don't recognize. + Importing and staging are affected by disk speed and the total image size. Pulling is affected by network speed and how many layers invalidate between pulls. Therefore, a large image with a good caching strategy will have longer diff --git a/docs/src/progress-v0.schema.json b/docs/src/progress-v0.schema.json index dc5fef217..dc267885a 100644 --- a/docs/src/progress-v0.schema.json +++ b/docs/src/progress-v0.schema.json @@ -154,9 +154,47 @@ "stepsTotal", "subtasks" ] + }, + { + "description": "A human readable status message, with the same text that is\nprinted to the terminal. The text is not a stable interface.", + "type": "object", + "properties": { + "level": { + "description": "The severity of the message.", + "$ref": "#/$defs/MessageLevel" + }, + "text": { + "description": "The message text, without a trailing newline.", + "type": "string" + }, + "type": { + "type": "string", + "const": "Message" + } + }, + "required": [ + "type", + "level", + "text" + ] } ], "$defs": { + "MessageLevel": { + "description": "The severity of a `Message` event.", + "oneOf": [ + { + "description": "Regular status output, e.g. which image was queued for the next boot.", + "type": "string", + "const": "info" + }, + { + "description": "Something the user should pay attention to, which did not cause\nthe operation to fail.", + "type": "string", + "const": "warning" + } + ] + }, "SubTaskBytes": { "description": "An incremental update to e.g. a container image layer download.\nThe first time a given \"subtask\" name is seen, a new progress bar should be created.\nIf bytes == bytes_total, then the subtask is considered complete.", "type": "object", diff --git a/tmt/tests/booted/test-image-pushpull-upgrade.nu b/tmt/tests/booted/test-image-pushpull-upgrade.nu index 237cb3c3f..6f3c45d47 100644 --- a/tmt/tests/booted/test-image-pushpull-upgrade.nu +++ b/tmt/tests/booted/test-image-pushpull-upgrade.nu @@ -110,6 +110,15 @@ RUN echo test content > /usr/share/blah.txt # This just does some basic verification of the progress JSON def sanity_check_switch_progress_json [data] { + # Status messages (e.g. "Queued for next boot") are interleaved with + # the progress events; check them separately. + let messages = $data | where type == "Message" + assert (($messages | length) > 0) + for m in $messages { + assert ($m.level in ["info", "warning"]) + assert (($m.text | str length) > 0) + } + let data = $data | where type != "Message" let event_count = $data | length # The first one should always be a start event let first = $data.0;