From 7f645654c76e43e64088b275debff98767acc2e7 Mon Sep 17 00:00:00 2001 From: Colin Walters Date: Sat, 26 Oct 2024 16:56:55 -0400 Subject: [PATCH 1/3] deploy: Use bar.println In some cases I wasn't seeing this output, and I think it's because we hadn't `drop()`'d the bar. Since it's in scope it's cleaner to use its `println` method. Signed-off-by: Colin Walters --- lib/src/deploy.rs | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/lib/src/deploy.rs b/lib/src/deploy.rs index 17f1208bd..60de81c67 100644 --- a/lib/src/deploy.rs +++ b/lib/src/deploy.rs @@ -211,12 +211,14 @@ async fn handle_layer_progress_print( let elapsed = end.duration_since(start); let persec = total_read as f64 / elapsed.as_secs_f64(); let persec = indicatif::HumanBytes(persec as u64); - println!( + if let Err(e) = bar.println(&format!( "Fetched layers: {} in {} ({}/s)", indicatif::HumanBytes(total_read), indicatif::HumanDuration(elapsed), persec, - ); + )) { + tracing::warn!("writing to stdout: {e}"); + } } /// Wrapper for pulling a container image, wiring up status output. From 3638b411580f81e84edb21dc9fa8cca220c93b7e Mon Sep 17 00:00:00 2001 From: Colin Walters Date: Sat, 26 Oct 2024 17:33:01 -0400 Subject: [PATCH 2/3] deploy: Add a spinner First, this operation was absolutely not asynchronous and we need to spawn it in a helper thread on general principle. Doing that is unfortunately VERY hacky because we need to clone a lot of things and especially there's an ergonomics hit here since `Deployment` is incorrectly `!Send`. But the main motivation is this operation can be slow sometimes, so let's show progress output so the admin knows we're not blocked. Closes: https://github.com/containers/bootc/issues/842 Signed-off-by: Colin Walters --- lib/src/deploy.rs | 67 +++++++++++++++++++++++++++++++---------------- 1 file changed, 45 insertions(+), 22 deletions(-) diff --git a/lib/src/deploy.rs b/lib/src/deploy.rs index 60de81c67..8e9183c6e 100644 --- a/lib/src/deploy.rs +++ b/lib/src/deploy.rs @@ -19,11 +19,13 @@ use ostree_ext::oci_spec::image::{Descriptor, Digest}; use ostree_ext::ostree::Deployment; use ostree_ext::ostree::{self, Sysroot}; use ostree_ext::sysroot::SysrootLock; +use ostree_ext::tokio_util::spawn_blocking_cancellable_flatten; use crate::spec::ImageReference; use crate::spec::{BootOrder, HostSpec}; use crate::status::labels_of_config; use crate::store::Storage; +use crate::utils::async_task_with_spinner; // TODO use https://github.com/ostreedev/ostree-rs-ext/pull/493/commits/afc1837ff383681b947de30c0cefc70080a4f87a const BASE_IMAGE_PREFIX: &str = "ostree/container/baseimage/bootc"; @@ -375,8 +377,6 @@ async fn deploy( image: &ImageState, origin: &glib::KeyFile, ) -> Result { - let stateroot = Some(stateroot); - let mut opts = ostree::SysrootDeployTreeOpts::default(); // Compute the kernel argument overrides. In practice today this API is always expecting // a merge deployment. The kargs code also always looks at the booted root (which // is a distinct minor issue, but not super important as right now the install path @@ -386,26 +386,49 @@ async fn deploy( } else { None }; - // Because the C API expects a Vec<&str>, we need to generate a new Vec<> - // that borrows. - let override_kargs = override_kargs - .as_deref() - .map(|v| v.iter().map(|s| s.as_str()).collect::>()); - if let Some(kargs) = override_kargs.as_deref() { - opts.override_kernel_argv = Some(&kargs); - } - // Copy to move into thread - let cancellable = gio::Cancellable::NONE; - return sysroot - .stage_tree_with_options( - stateroot, - image.ostree_commit.as_str(), - Some(origin), - merge_deployment, - &opts, - cancellable, - ) - .map_err(Into::into); + // Clone all the things to move to worker thread + let sysroot_clone = sysroot.sysroot.clone(); + // ostree::Deployment is incorrently !Send 😢 so convert it to an integer + let merge_deployment = merge_deployment.map(|d| d.index() as usize); + let stateroot = stateroot.to_string(); + let ostree_commit = image.ostree_commit.to_string(); + // GKeyFile also isn't Send! So we serialize that as a string... + let origin_data = origin.to_data(); + let r = async_task_with_spinner( + "Deploying", + spawn_blocking_cancellable_flatten(move |cancellable| -> Result<_> { + let sysroot = sysroot_clone; + let stateroot = Some(stateroot); + let mut opts = ostree::SysrootDeployTreeOpts::default(); + + // Because the C API expects a Vec<&str>, we need to generate a new Vec<> + // that borrows. + let override_kargs = override_kargs + .as_deref() + .map(|v| v.iter().map(|s| s.as_str()).collect::>()); + if let Some(kargs) = override_kargs.as_deref() { + opts.override_kernel_argv = Some(&kargs); + } + let deployments = sysroot.deployments(); + let merge_deployment = merge_deployment.map(|m| &deployments[m]); + let origin = glib::KeyFile::new(); + origin.load_from_data(&origin_data, glib::KeyFileFlags::NONE)?; + let d = sysroot.stage_tree_with_options( + stateroot.as_deref(), + &ostree_commit, + Some(&origin), + merge_deployment, + &opts, + Some(cancellable), + )?; + Ok(d.index()) + }), + ) + .await?; + // SAFETY: We must have a staged deployment + let staged = sysroot.staged_deployment().unwrap(); + assert_eq!(staged.index(), r); + Ok(staged) } #[context("Generating origin")] From daeafeadd5a4c8c6457b7062c6c43b32345cd495 Mon Sep 17 00:00:00 2001 From: Colin Walters Date: Sun, 27 Oct 2024 15:41:48 -0400 Subject: [PATCH 3/3] utils: Print and log time for async_task_with_spinner Things we do via this mechanism can take some time; let's log the elapsed time for greater visibility both to the human output *and* log to the journal. Signed-off-by: Colin Walters --- lib/src/utils.rs | 12 ++++++++++-- 1 file changed, 10 insertions(+), 2 deletions(-) diff --git a/lib/src/utils.rs b/lib/src/utils.rs index 81b253fe2..33403afec 100644 --- a/lib/src/utils.rs +++ b/lib/src/utils.rs @@ -6,6 +6,8 @@ use std::time::Duration; use anyhow::{Context, Result}; use cap_std_ext::cap_std::fs::Dir; +use indicatif::HumanDuration; +use libsystemd::logging::journal_print; use ostree::glib; use ostree_ext::container::SignatureSource; use ostree_ext::ostree; @@ -119,6 +121,7 @@ pub(crate) async fn async_task_with_spinner(msg: &str, f: F) -> T where F: Future, { + let start_time = std::time::Instant::now(); let pb = indicatif::ProgressBar::new_spinner(); let style = indicatif::ProgressStyle::default_bar(); pb.set_style(style.template("{spinner} {msg}").unwrap()); @@ -131,10 +134,15 @@ where std::io::stdout().flush().unwrap(); } let r = f.await; + let elapsed = HumanDuration(start_time.elapsed()); + let _ = journal_print( + libsystemd::logging::Priority::Info, + &format!("completed task in {elapsed}: {msg}"), + ); if pb.is_hidden() { - println!("done"); + println!("done ({elapsed})"); } else { - pb.finish_with_message(format!("{msg}: done")); + pb.finish_with_message(format!("{msg}: done ({elapsed})")); } r }