Skip to content

clean up tracing spans, fields, span-level #149

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
syphar merged 2 commits into from
Sep 8, 2026
Merged

clean up tracing spans, fields, span-level #149

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
5b08931
clean up tracing spans, fields, span-level
syphar Sep 3, 2026
811f0fe
log format_command: use debug repr
syphar Sep 8, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
9 changes: 2 additions & 7 deletions src/build.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -215,6 +215,7 @@ impl BuildDirectory {
feature = "tracing",
tracing::instrument(
skip_all,
level = "debug",
fields(
build_dir = %self.name,
krate = %krate,
Expand Down Expand Up @@ -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,
Expand Down
44 changes: 36 additions & 8 deletions src/cmd/mod.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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};
Expand Down Expand Up @@ -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<ProcessOutput, CommandError> {
if let Some(sandbox) = self.sandbox {
let binary = match self.binary {
Expand Down Expand Up @@ -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);

Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -701,8 +697,40 @@ async fn log_command(
})
}

fn format_command<S1, S2, I>(binary: S1, args: I) -> OsString
where
S1: AsRef<OsStr>,
S2: AsRef<OsStr>,
I: IntoIterator<Item = S2>,
{
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""#
);
}
}
2 changes: 1 addition & 1 deletion src/cmd/sandbox/docker.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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<u64> {
if let Some(host_cgroup) = self.detect_host_cgroup()
&& let Some(peak) = host_cgroup.read_memory_peak()
Expand Down
46 changes: 6 additions & 40 deletions src/cmd/sandbox/mod.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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<Container<'_>, CommandError> {
let mut args: Vec<String> = vec!["create".into()];

Expand Down Expand Up @@ -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<InspectContainer, CommandError> {
let output = Command::new(self.workspace, "docker")
.args(["inspect", self.id()])
Expand All @@ -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()])
Expand Down Expand Up @@ -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,
Expand Down Expand Up @@ -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(());
Expand Down Expand Up @@ -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,
Expand Down
13 changes: 4 additions & 9 deletions src/crates/git.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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:
Expand Down Expand Up @@ -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"])
Expand Down
8 changes: 1 addition & 7 deletions src/crates/local.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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 {}",
Expand Down
33 changes: 4 additions & 29 deletions src/crates/registry.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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<String> {
match &self.registry {
Registry::CratesIo => Ok(format!(
Expand Down Expand Up @@ -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<()> {
Expand Down Expand Up @@ -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)?;
Expand Down
35 changes: 7 additions & 28 deletions src/prepare.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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()?;
Expand All @@ -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 {}",
Expand All @@ -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"),
Expand All @@ -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)?;
Expand All @@ -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!(
Expand All @@ -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,
Expand Down
Loading
Loading