diff --git a/src/build.rs b/src/build.rs index b205a82e..71058b4a 100644 --- a/src/build.rs +++ b/src/build.rs @@ -215,6 +215,7 @@ impl BuildDirectory { feature = "tracing", tracing::instrument( skip_all, + level = "debug", fields( build_dir = %self.name, krate = %krate, @@ -256,13 +257,7 @@ impl BuildDirectory { let res = { #[cfg(feature = "tracing")] - let _entered = tracing::info_span!( - "build.user_callback", - build_dir = %self.name, - krate = %krate, - toolchain = %toolchain, - ) - .entered(); + let _entered = tracing::debug_span!("build.user_callback").entered(); f(&Build { dir: self, diff --git a/src/cmd/mod.rs b/src/cmd/mod.rs index 589d80f4..6e97daa6 100644 --- a/src/cmd/mod.rs +++ b/src/cmd/mod.rs @@ -16,7 +16,7 @@ use log::{error, info}; use process_lines_actions::InnerState; use std::ffi::{OsStr, OsString}; use std::fmt; -use std::path::PathBuf; +use std::path::{Path, PathBuf}; use std::process::{ExitStatus, Stdio}; use std::time::{Duration, Instant}; use std::{cell::RefCell, env::consts::EXE_SUFFIX, rc::Rc}; @@ -417,10 +417,7 @@ impl<'w> Command<'w, '_> { self.run_inner(true) } - #[cfg_attr( - feature = "tracing", - tracing::instrument(skip_all, fields(self = ?self, capture)) - )] + #[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] fn run_inner(self, capture: bool) -> Result { if let Some(sandbox) = self.sandbox { let binary = match self.binary { @@ -477,6 +474,7 @@ impl<'w> Command<'w, '_> { } }; + let cmdstr = format_command(binary.as_os_str(), &self.args); let mut cmd = AsyncCommand::new(binary); cmd.args(&self.args); @@ -507,14 +505,12 @@ impl<'w> Command<'w, '_> { cmd.env(k, v); } - let cmdstr = format!("{cmd:?}"); - if let Some(ref current_directory) = self.current_directory { cmd.current_dir(current_directory); } if self.log_command { - info!("running `{cmdstr}`"); + info!("running `{}`", cmdstr.to_string_lossy()); } let out = RUNTIME @@ -701,8 +697,40 @@ async fn log_command( }) } +fn format_command(binary: S1, args: I) -> OsString +where + S1: AsRef, + S2: AsRef, + I: IntoIterator, +{ + let binary = binary.as_ref(); + let binary_name = Path::new(binary).file_name().unwrap_or(binary); + + let mut command = OsString::from(format!("{:?}", binary_name)); + + for arg in args { + command.push(format!(" {:?}", arg.as_ref())); + } + command +} + fn exe_suffix(file: &OsStr) -> OsString { let mut path = OsString::from(file); path.push(EXE_SUFFIX); path } + +#[cfg(test)] +mod tests { + use super::*; + + #[test] + fn formats_only_the_program_and_arguments() { + let args = ["argument", "argument with spaces"]; + + assert_eq!( + format_command(OsStr::new("/path/to/program"), args), + r#""program" "argument" "argument with spaces""# + ); + } +} diff --git a/src/cmd/sandbox/docker.rs b/src/cmd/sandbox/docker.rs index fdd85d81..e43653da 100644 --- a/src/cmd/sandbox/docker.rs +++ b/src/cmd/sandbox/docker.rs @@ -322,7 +322,7 @@ impl<'w> CgroupStatsReader<'w> { self.oom_kill_count = self.read_oom_kill_count(); } - #[cfg_attr(feature = "tracing", tracing::instrument(skip_all))] + #[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] pub(super) fn read_memory_peak(&mut self) -> Option { if let Some(host_cgroup) = self.detect_host_cgroup() && let Some(peak) = host_cgroup.read_memory_peak() diff --git a/src/cmd/sandbox/mod.rs b/src/cmd/sandbox/mod.rs index d660431a..ff796a94 100644 --- a/src/cmd/sandbox/mod.rs +++ b/src/cmd/sandbox/mod.rs @@ -598,21 +598,7 @@ impl SandboxBuilder { Ok(container) } - #[cfg_attr( - feature = "tracing", - tracing::instrument( - skip_all, - fields( - image = %workspace.sandbox_image().name, - mounts = self.mounts.len(), - memory_limit = ?self.memory_limit, - cpu_limit = ?self.cpu_limit, - cpuset_cpus = ?self.cpuset_cpus, - enable_networking = self.enable_networking, - docker_runtime = ?self.docker_runtime, - ) - ) - )] + #[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] fn create(self, workspace: &Workspace) -> Result, CommandError> { let mut args: Vec = vec!["create".into()]; @@ -726,7 +712,7 @@ impl fmt::Display for Container<'_> { } impl Container<'_> { - #[cfg_attr(feature = "tracing", tracing::instrument(skip_all))] + #[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] fn inspect(&self) -> Result { let output = Command::new(self.workspace, "docker") .args(["inspect", self.id()]) @@ -741,7 +727,7 @@ impl Container<'_> { } /// Start the container in detached mode (without `-a`). - #[cfg_attr(feature = "tracing", tracing::instrument(skip_all))] + #[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] fn start(&self) -> Result<(), CommandError> { Command::new(self.workspace, "docker") .args(["start", self.id()]) @@ -770,10 +756,7 @@ impl Container<'_> { } #[allow(clippy::too_many_arguments, clippy::type_complexity)] - #[cfg_attr( - feature = "tracing", - tracing::instrument(skip_all, fields(container_id = %self.id(), capture)) - )] + #[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] fn run_command( &mut self, command: SandboxCommand, @@ -846,7 +829,7 @@ impl Container<'_> { /// stored id is taken (so subsequent calls — including the one in /// [`Drop`] — are no-ops). On failure the id is restored so [`Drop`] /// (or a later call) can retry. - #[cfg_attr(feature = "tracing", tracing::instrument(skip_all))] + #[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] fn delete(&mut self) -> Result<(), CommandError> { let Some(id) = self.id.take() else { return Ok(()); @@ -969,24 +952,7 @@ impl<'w> Sandbox<'w> { } #[allow(clippy::too_many_arguments, clippy::type_complexity)] - #[cfg_attr( - feature = "tracing", - tracing::instrument( - skip_all, - fields( - image = %self.workspace.sandbox_image().name, - mounts = self.builder.mounts.len(), - memory_limit = ?self.builder.memory_limit, - cpu_limit = ?self.builder.cpu_limit, - cpuset_cpus = ?self.builder.cpuset_cpus, - enable_networking = self.builder.enable_networking, - docker_runtime = ?self.builder.docker_runtime, - capture, - timeout_secs = ?timeout.map(|timeout| timeout.as_secs()), - no_output_timeout_secs = ?no_output_timeout.map(|timeout| timeout.as_secs()), - ) - ) - )] + #[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] pub(crate) fn run( &mut self, command: SandboxCommand, diff --git a/src/crates/git.rs b/src/crates/git.rs index c9663628..bfc24146 100644 --- a/src/crates/git.rs +++ b/src/crates/git.rs @@ -67,17 +67,15 @@ impl CrateTrait for GitRepo { feature = "tracing", tracing::instrument( skip_all, - fields(url = %self.url, cache_hit = tracing::field::Empty, path = tracing::field::Empty) + level = "debug", + fields(cache_hit = tracing::field::Empty) ) )] fn fetch(&self, workspace: &Workspace) -> anyhow::Result<()> { let path = self.cached_path(workspace); let cache_hit = path.join("HEAD").is_file(); #[cfg(feature = "tracing")] - { - tracing::Span::current().record("cache_hit", cache_hit); - tracing::Span::current().record("path", path.display().to_string()); - } + tracing::Span::current().record("cache_hit", cache_hit); // The credential helper that suppresses the password prompt shows this message when a // repository requires authentication: @@ -127,10 +125,7 @@ impl CrateTrait for GitRepo { Ok(()) } - #[cfg_attr( - feature = "tracing", - tracing::instrument(skip_all, fields(url = %self.url, dest = %dest.display())) - )] + #[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] fn copy_source_to(&self, workspace: &Workspace, dest: &Path) -> anyhow::Result<()> { Command::new(workspace, "git") .args(["clone"]) diff --git a/src/crates/local.rs b/src/crates/local.rs index 796da008..091812f9 100644 --- a/src/crates/local.rs +++ b/src/crates/local.rs @@ -25,13 +25,7 @@ impl CrateTrait for Local { Ok(()) } - #[cfg_attr( - feature = "tracing", - tracing::instrument( - skip_all, - fields(source = %self.path.display(), dest = %dest.display()) - ) - )] + #[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] fn copy_source_to(&self, _workspace: &Workspace, dest: &Path) -> anyhow::Result<()> { info!( "copying local crate from {} to {}", diff --git a/src/crates/registry.rs b/src/crates/registry.rs index 68e2c782..4a58fd25 100644 --- a/src/crates/registry.rs +++ b/src/crates/registry.rs @@ -96,17 +96,7 @@ impl RegistryCrate { } #[allow(unused_variables)] - #[cfg_attr( - feature = "tracing", - tracing::instrument( - skip_all, - fields( - registry = %self.registry.name(), - crate_name = %self.name, - version = %self.version, - ) - ) - )] + #[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] fn fetch_url(&self, workspace: &Workspace) -> anyhow::Result { match &self.registry { Registry::CratesIo => Ok(format!( @@ -175,12 +165,8 @@ impl CrateTrait for RegistryCrate { feature = "tracing", tracing::instrument( skip_all, - fields( - registry = %self.registry.name(), - crate_name = %self.name, - version = %self.version, - cache_hit = tracing::field::Empty, - ) + level = "debug", + fields(cache_hit = tracing::field::Empty) ) )] fn fetch(&self, workspace: &Workspace) -> anyhow::Result<()> { @@ -219,18 +205,7 @@ impl CrateTrait for RegistryCrate { Ok(()) } - #[cfg_attr( - feature = "tracing", - tracing::instrument( - skip_all, - fields( - registry = %self.registry.name(), - crate_name = %self.name, - version = %self.version, - dest = %dest.display(), - ) - ) - )] + #[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] fn copy_source_to(&self, workspace: &Workspace, dest: &Path) -> anyhow::Result<()> { let cached = self.cache_path(workspace); let mut file = File::open(cached)?; diff --git a/src/prepare.rs b/src/prepare.rs index 10e75159..cf778ce4 100644 --- a/src/prepare.rs +++ b/src/prepare.rs @@ -33,18 +33,7 @@ impl<'a> Prepare<'a> { } } - #[cfg_attr( - feature = "tracing", - tracing::instrument( - skip_all, - fields( - krate = %self.krate, - toolchain = %self.toolchain, - source_dir = %self.source_dir.display(), - patches = self.patches.len(), - ) - ) - )] + #[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] pub(crate) fn prepare(&mut self) -> anyhow::Result<()> { self.krate.copy_source_to(self.workspace, self.source_dir)?; self.remove_override_files()?; @@ -56,7 +45,7 @@ impl<'a> Prepare<'a> { Ok(()) } - #[cfg_attr(feature = "tracing", tracing::instrument(skip_all))] + #[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] fn validate_manifest(&self) -> anyhow::Result<()> { info!( "validating manifest of {} on toolchain {}", @@ -80,7 +69,7 @@ impl<'a> Prepare<'a> { Ok(()) } - #[cfg_attr(feature = "tracing", tracing::instrument(skip_all))] + #[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] fn remove_override_files(&self) -> anyhow::Result<()> { let paths = [ &Path::new(".cargo").join("config"), @@ -98,7 +87,7 @@ impl<'a> Prepare<'a> { Ok(()) } - #[cfg_attr(feature = "tracing", tracing::instrument(skip_all))] + #[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] fn tweak_toml(&self) -> anyhow::Result<()> { let path = self.source_dir.join("Cargo.toml"); let mut tweaker = TomlTweaker::new(self.krate, &path, &self.patches)?; @@ -107,7 +96,7 @@ impl<'a> Prepare<'a> { Ok(()) } - #[cfg_attr(feature = "tracing", tracing::instrument(skip_all))] + #[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] fn capture_lockfile(&mut self) -> anyhow::Result<()> { if self.source_dir.join("Cargo.lock").exists() { info!( @@ -131,23 +120,13 @@ impl<'a> Prepare<'a> { run_command(cmd.current_directory(self.source_dir)) } - #[cfg_attr(feature = "tracing", tracing::instrument(skip_all))] + #[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] fn fetch_deps(&mut self) -> anyhow::Result<()> { fetch_deps(self.workspace, self.toolchain, self.source_dir, &[]) } } -#[cfg_attr( - feature = "tracing", - tracing::instrument( - skip_all, - fields( - toolchain = %toolchain, - source_dir = %source_dir.display(), - build_std_targets = fetch_build_std_targets.len(), - ) - ) -)] +#[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] pub(crate) fn fetch_deps( workspace: &Workspace, toolchain: &Toolchain, diff --git a/src/toolchain.rs b/src/toolchain.rs index 75e1f187..ce70afc2 100644 --- a/src/toolchain.rs +++ b/src/toolchain.rs @@ -307,13 +307,7 @@ impl Toolchain { self.list_rustup_things(workspace, RustupThing::Target) } - #[cfg_attr( - feature = "tracing", - tracing::instrument( - skip_all, - fields(toolchain = %self, action = %action, thing = %thing, name) - ) - )] + #[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] fn change_rustup_thing( &self, workspace: &Workspace, @@ -386,10 +380,7 @@ impl Toolchain { Ok(()) } - #[cfg_attr( - feature = "tracing", - tracing::instrument(skip_all, fields(toolchain = %self, thing = %thing)) - )] + #[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] fn list_rustup_things( &self, workspace: &Workspace, diff --git a/src/tools/mod.rs b/src/tools/mod.rs index 97ea833b..d97c9b0a 100644 --- a/src/tools/mod.rs +++ b/src/tools/mod.rs @@ -46,10 +46,7 @@ trait Tool: Send + Sync { } } -#[cfg_attr( - feature = "tracing", - tracing::instrument(skip_all, fields(fast_install)) -)] +#[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] pub(crate) fn install(workspace: &Workspace, fast_install: bool) -> anyhow::Result<()> { for tool in INSTALLABLE_TOOLS { if tool.is_installed(workspace)? { diff --git a/src/utils.rs b/src/utils.rs index 3147e610..7392b9bb 100644 --- a/src/utils.rs +++ b/src/utils.rs @@ -73,10 +73,7 @@ pub(crate) fn remove_file(path: &Path) -> std::io::Result<()> { std::fs::remove_file(path).map_err(|error| crate::utils::improve_remove_error(error, path)) } -#[cfg_attr( - feature = "tracing", - tracing::instrument(skip_all, fields(path = %path.display())) -)] +#[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] pub(crate) fn remove_dir_all(path: &Path) -> std::io::Result<()> { remove_dir_all::remove_dir_all(path) .map_err(|error| crate::utils::improve_remove_error(error, path)) diff --git a/src/workspace.rs b/src/workspace.rs index 9e8c1bbd..5c6f5d8f 100644 --- a/src/workspace.rs +++ b/src/workspace.rs @@ -137,7 +137,7 @@ impl WorkspaceBuilder { /// Initialize the workspace. This will create all the necessary local files and fetch the rest from the network. It's /// not unexpected for this method to take minutes to run on slower network connections. - #[cfg_attr(feature = "tracing", tracing::instrument())] + #[cfg_attr(feature = "tracing", tracing::instrument(skip_all))] pub fn init(self) -> anyhow::Result { std::fs::create_dir_all(&self.path).with_context(|| { format!( @@ -319,7 +319,7 @@ impl Workspace { &self.inner.rustup_profile } - #[cfg_attr(feature = "tracing", tracing::instrument(skip(self)))] + #[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] fn init(&self, fast_init: bool) -> anyhow::Result<()> { info!("installing tools required by rustwide"); crate::tools::install(self, fast_init)?; @@ -330,7 +330,7 @@ impl Workspace { Ok(()) } - #[cfg_attr(feature = "tracing", tracing::instrument(skip_all))] + #[cfg_attr(feature = "tracing", tracing::instrument(skip_all, level = "debug"))] #[allow(clippy::unnecessary_wraps)] // hopefully we could actually catch the error here at some point fn update_cratesio_registry(&self) -> anyhow::Result<()> { // This nop cargo command is to update the registry so we don't have to do it for each