chore: add better logging for build backends

crates/pixi_build_frontend/src/backend/json_rpc.rs

@@ -26,6 +26,7 @@ use pixi_build_types::{
         negotiate_capabilities::{NegotiateCapabilitiesParams, NegotiateCapabilitiesResult},
     },
 };
+use rattler_conda_types::VersionWithSource;
 use thiserror::Error;
 use tokio::{
     io::{AsyncBufReadExt, BufReader, Lines},
@@ -126,6 +127,8 @@ impl CommunicationError {
 pub struct JsonRpcBackend {
     /// The identifier of the backend.
     backend_identifier: String,
+    /// The version of the backend.
+    backend_version: Option<VersionWithSource>,
     /// The capabilities of the backend.
     backend_capabilities: BackendCapabilities,
     /// The JSON-RPC client to communicate with the backend.
@@ -187,6 +190,7 @@ impl JsonRpcBackend {
         let (tx, rx) = stdio_transport(stdin, stdout);
         Self::setup_with_transport(
             backend_identifier,
+            tool.version().cloned(),
             source_dir,
             manifest_path,
             package_manifest,
@@ -204,6 +208,7 @@ impl JsonRpcBackend {
     #[allow(clippy::too_many_arguments)]
     pub(crate) async fn setup_with_transport(
         backend_identifier: String,
+        backend_version: Option<VersionWithSource>,
         source_dir: PathBuf,
         manifest_path: PathBuf,
         project_model: Option<ProjectModelV1>,
@@ -265,6 +270,7 @@ impl JsonRpcBackend {
         Ok(Self {
             client,
             backend_identifier,
+            backend_version,
             backend_capabilities: negotiate_result.capabilities,
             manifest_path,
             stderr: stderr.map(Mutex::new).map(Arc::new),
@@ -480,6 +486,11 @@ impl JsonRpcBackend {
         &self.backend_identifier
     }
 
+    /// Returns the version of the backend, if available.
+    pub fn version(&self) -> Option<&VersionWithSource> {
+        self.backend_version.as_ref()
+    }
+
     /// Returns the advertised capabilities of the backend.
     pub fn capabilities(&self) -> &BackendCapabilities {
         &self.backend_capabilities

crates/pixi_build_frontend/src/backend/mod.rs

@@ -1,5 +1,7 @@
 use std::fmt::{Debug, Formatter};
 
+use rattler_conda_types::VersionWithSource;
+
 pub mod in_memory;
 
 use in_memory::InMemoryBackend;
@@ -66,6 +68,13 @@ impl BackendImplementation {
             BackendImplementation::InMemory(in_memory) => in_memory.identifier(),
         }
     }
+
+    pub fn version(&self) -> Option<&VersionWithSource> {
+        match self {
+            BackendImplementation::JsonRpc(json_rpc) => json_rpc.version(),
+            BackendImplementation::InMemory(_) => None,
+        }
+    }
 }
 
 impl From<json_rpc::JsonRpcBackend> for BackendImplementation {
@@ -96,6 +105,12 @@ impl Backend {
         self.inner.identifier()
     }
 
+    /// Returns the version of the backend, if available. This is useful for
+    /// debugging purposes mostly.
+    pub fn version(&self) -> Option<&VersionWithSource> {
+        self.inner.version()
+    }
+
     /// Returns the capabilities of the backend. This takes into account both
     /// the actual capabilities of the backend and the API version that is in
     /// use.
@@ -107,6 +122,13 @@ impl Backend {
         &self.capabilities
     }
 
+    /// Returns the capabilities of the backend, without taking into account the
+    /// API version. This is only useful for debugging purposes. In most cases
+    /// [`Self::capabilities`] should be used instead.
+    pub fn backend_capabilities(&self) -> BackendCapabilities {
+        self.inner.capabilities()
+    }
+
     /// Returns the API version that was used to establish the backend.
     pub fn api_version(&self) -> PixiBuildApiVersion {
         self.api_version

crates/pixi_build_frontend/src/tool.rs

@@ -1,9 +1,10 @@
+use rattler_conda_types::VersionWithSource;
 use std::{collections::HashMap, path::PathBuf};
 
 /// A tool that can be invoked.
 #[derive(Debug)]
 pub enum Tool {
-    Isolated(IsolatedTool),
+    Isolated(Box<IsolatedTool>),
     System(SystemTool),
 }
 
@@ -30,7 +31,7 @@ impl From<SystemTool> for Tool {
 
 impl From<IsolatedTool> for Tool {
     fn from(value: IsolatedTool) -> Self {
-        Self::Isolated(value)
+        Self::Isolated(Box::new(value))
     }
 }
 
@@ -39,6 +40,8 @@ impl From<IsolatedTool> for Tool {
 pub struct IsolatedTool {
     /// The command to invoke.
     command: String,
+    /// The version of the tool that was installed.
+    version: Option<VersionWithSource>,
     /// The prefix to use for the isolated environment.
     prefix: PathBuf,
     /// Activation scripts
@@ -49,11 +52,13 @@ impl IsolatedTool {
     /// Construct a new instance from a command and prefix.
     pub fn new(
         command: impl Into<String>,
+        version: Option<VersionWithSource>,
         prefix: impl Into<PathBuf>,
         activation: HashMap<String, String>,
     ) -> Self {
         Self {
             command: command.into(),
+            version,
             prefix: prefix.into(),
             activation_scripts: activation,
         }
@@ -76,14 +81,23 @@ impl Tool {
         }
     }
 
+    /// Returns the version of the tool, if available.
+    pub fn version(&self) -> Option<&VersionWithSource> {
+        match self {
+            Tool::Isolated(tool) => tool.version.as_ref(),
+            Tool::System(_) => None,
+        }
+    }
+
     /// Construct a new tool that calls another executable.
     pub fn with_executable(&self, executable: impl Into<String>) -> Self {
         match self {
-            Tool::Isolated(tool) => Tool::Isolated(IsolatedTool::new(
+            Tool::Isolated(tool) => Tool::Isolated(Box::new(IsolatedTool::new(
                 executable,
+                tool.version.clone(),
                 tool.prefix.clone(),
                 tool.activation_scripts.clone(),
-            )),
+            ))),
             Tool::System(_) => Tool::System(SystemTool::new(executable)),
         }
     }

crates/pixi_build_types/src/lib.rs

@@ -6,6 +6,7 @@ pub mod procedures;
 mod project_model;
 mod stable_hash;
 
+use std::fmt::Display;
 use std::sync::LazyLock;
 
 pub use capabilities::{BackendCapabilities, FrontendCapabilities};
@@ -89,6 +90,12 @@ impl PixiBuildApiVersion {
     }
 }
 
+impl Display for PixiBuildApiVersion {
+    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
+        write!(f, "{}", self.0)
+    }
+}
+
 /// A platform and associated virtual packages
 #[derive(Clone, Debug, Serialize, Deserialize)]
 #[serde(rename_all = "camelCase")]

crates/pixi_command_dispatcher/src/build_backend_metadata/mod.rs

@@ -17,6 +17,7 @@ use pixi_spec::{SourceAnchor, SourceSpec};
 use rand::random;
 use rattler_conda_types::{ChannelConfig, ChannelUrl};
 use thiserror::Error;
+use tracing::instrument;
 
 use crate::{
     BuildEnvironment, CommandDispatcher, CommandDispatcherError, CommandDispatcherErrorResultExt,
@@ -71,15 +72,18 @@ pub struct BuildBackendMetadata {
 }
 
 impl BuildBackendMetadataSpec {
+    #[instrument(
+        skip_all,
+        name="backend-metadata",
+        fields(
+            source = %self.source,
+            platform = %self.build_environment.host_platform,
+        )
+    )]
     pub(crate) async fn request(
         self,
         command_dispatcher: CommandDispatcher,
     ) -> Result<BuildBackendMetadata, CommandDispatcherError<BuildBackendMetadataError>> {
-        tracing::debug!(
-            "Requesting source metadata for source spec: {}",
-            self.source
-        );
-
         // Ensure that the source is checked out before proceeding.
         let source_checkout = command_dispatcher
             .checkout_pinned_source(self.source.clone())
@@ -142,15 +146,23 @@ impl BuildBackendMetadataSpec {
         // Based on the version of the backend, call the appropriate method to get
         // metadata.
         let source = source_checkout.pinned.clone();
-        let metadata = if backend.capabilities().provides_conda_outputs == Some(true) {
+        let metadata = if backend.capabilities().provides_conda_outputs() {
+            tracing::trace!(
+                "Using `{}` procedure to get metadata information",
+                pixi_build_types::procedures::conda_outputs::METHOD_NAME
+            );
             self.call_conda_outputs(
                 command_dispatcher,
                 source_checkout,
                 backend,
                 project_model_hash,
             )
             .await?
-        } else if backend.capabilities().provides_conda_metadata == Some(true) {
+        } else if backend.capabilities().provides_conda_metadata() {
+            tracing::trace!(
+                "Using `{}` procedure to get metadata information",
+                pixi_build_types::procedures::conda_metadata::METHOD_NAME
+            );
             self.call_conda_get_metadata(
                 command_dispatcher,
                 source_checkout,
@@ -191,14 +203,18 @@ impl BuildBackendMetadataSpec {
             return Ok(None);
         };
 
-        tracing::debug!(
-            "Found source metadata in cache for source spec: {}",
-            source_checkout.pinned
-        );
+        let metadata_kind = match metadata.metadata {
+            MetadataKind::GetMetadata { .. } => {
+                pixi_build_types::procedures::conda_metadata::METHOD_NAME
+            }
+            MetadataKind::Outputs { .. } => {
+                pixi_build_types::procedures::conda_outputs::METHOD_NAME
+            }
+        };
 
         let Some(input_globs) = &metadata.input_hash else {
             // No input hash so just assume it is still valid.
-            tracing::debug!("found cached metadata.");
+            tracing::trace!("found cached `{metadata_kind}` response.");
             return Ok(Some(metadata));
         };
 
@@ -215,10 +231,10 @@ impl BuildBackendMetadataSpec {
             .map_err(CommandDispatcherError::Failed)?;
 
         if new_hash.hash == input_globs.hash {
-            tracing::debug!("found up-to-date cached metadata.");
+            tracing::trace!("found up-to-date cached `{metadata_kind}` response..");
             Ok(Some(metadata))
         } else {
-            tracing::debug!("found stale cached metadata.");
+            tracing::trace!("found stale `{metadata_kind}` response..");
             Ok(None)
         }
     }

crates/pixi_command_dispatcher/src/command_dispatcher/instantiate_backend.rs

@@ -85,7 +85,11 @@ impl CommandDispatcher {
             ),
             CommandSpec::EnvironmentSpec(env_spec) => {
                 let (tool_platform, tool_platform_virtual_packages) = self.tool_platform();
-                let InstantiateToolEnvironmentResult { prefix, api } = self
+                let InstantiateToolEnvironmentResult {
+                    prefix,
+                    version,
+                    api,
+                } = self
                     .instantiate_tool_environment(InstantiateToolEnvironmentSpec {
                         requirement: env_spec.requirement,
                         additional_requirements: env_spec.additional_requirements,
@@ -119,6 +123,7 @@ impl CommandDispatcher {
                 (
                     Tool::from(IsolatedTool::new(
                         env_spec.command.unwrap_or(backend_spec.name),
+                        Some(version),
                         prefix.path().to_path_buf(),
                         activation_scripts,
                     )),
@@ -127,6 +132,15 @@ impl CommandDispatcher {
             }
         };
 
+        // Add debug information about what the backend supports.
+        tracing::debug!(
+            "Instantiated backend {}{}, negotiated API version {}",
+            tool.executable(),
+            tool.version()
+                .map_or_else(String::new, |v| format!("@{}", v)),
+            api_version,
+        );
+
         // The backend expects both the manifest path and the source directory to be
         // absolute paths.
         let manifest_path = spec

crates/pixi_command_dispatcher/src/instantiate_tool_env/mod.rs

@@ -16,7 +16,9 @@ use pixi_build_types::{
 use pixi_spec::{BinarySpec, PixiSpec};
 use pixi_spec_containers::DependencyMap;
 use pixi_utils::AsyncPrefixGuard;
-use rattler_conda_types::{ChannelConfig, ChannelUrl, PackageName, prefix::Prefix};
+use rattler_conda_types::{
+    ChannelConfig, ChannelUrl, PackageName, VersionWithSource, prefix::Prefix,
+};
 use rattler_solve::{ChannelPriority, SolveStrategy};
 use thiserror::Error;
 use xxhash_rust::xxh3::Xxh3;
@@ -69,6 +71,9 @@ pub struct InstantiateToolEnvironmentResult {
     /// The prefix of the tool environment.
     pub prefix: Prefix,
 
+    /// The version of the requirement that was eventually installed.
+    pub version: VersionWithSource,
+
     /// The version of the Pixi build API to use.
     pub api: PixiBuildApiVersion,
 }
@@ -223,6 +228,15 @@ impl InstantiateToolEnvironmentSpec {
             ));
         };
 
+        // Extract the version of the main requirement package.
+        let version = solved_environment
+            .iter()
+            .find(|r| r.package_record().name == self.requirement.0)
+            .expect("The solved environment should always contain the main requirement package")
+            .package_record()
+            .version
+            .clone();
+
         // Construct the prefix for the tool environment.
         let prefix = Prefix::create(command_queue.cache_dirs().build_backends().join(cache_key))
             .map_err(InstantiateToolEnvironmentError::CreatePrefix)
@@ -269,6 +283,7 @@ impl InstantiateToolEnvironmentSpec {
 
         Ok(InstantiateToolEnvironmentResult {
             prefix,
+            version,
             api: api_version,
         })
     }

crates/pixi_command_dispatcher/src/solve_pixi/mod.rs

@@ -177,7 +177,7 @@ impl PixiEnvironmentSpec {
             .map_err(SolvePixiEnvironmentError::QueryError)
             .map_err(CommandDispatcherError::Failed)?;
         let total_records = binary_repodata.iter().map(RepoData::len).sum::<usize>();
-        tracing::info!(
+        tracing::debug!(
             "fetched {total_records} records in {:?}",
             fetch_repodata_start.elapsed()
         );

crates/pixi_command_dispatcher/src/source_build/mod.rs

@@ -107,7 +107,14 @@ pub struct BuiltPackage {
 }
 
 impl SourceBuildSpec {
-    #[instrument(skip_all, fields(package = %self.package, source = %self.source))]
+    #[instrument(
+        skip_all,
+        name = "source-build",
+        fields(
+            source= %self.source,
+            package = %self.package,
+        )
+    )]
     pub(crate) async fn build(
         mut self,
         command_dispatcher: CommandDispatcher,