Log build output

crates/uv-build/src/lib.rs

@@ -463,27 +463,7 @@ impl SourceBuild {
             OsString::from(venv.scripts())
         };
 
-        // Create the PEP 517 build environment. If build isolation is disabled, we assume the build
+        let source_build = Self {
-        // environment is already setup.
-        if build_isolation.is_isolated() {
-            if let Some(pep517_backend) = &pep517_backend {
-                create_pep517_build_environment(
-                    &source_tree,
-                    &venv,
-                    pep517_backend,
-                    build_context,
-                    &package_id,
-                    build_kind,
-                    &config_settings,
-                    &environment_variables,
-                    &modified_path,
-                    &temp_dir,
-                )
-                .await?;
-            }
-        }
-
-        Ok(Self {
             temp_dir,
             source_tree,
             pep517_backend,
@@ -494,7 +474,118 @@ impl SourceBuild {
             package_id,
             environment_variables,
             modified_path,
-        })
+        };
+
+        // Create the PEP 517 build environment. If build isolation is disabled, we assume the build
+        // environment is already setup.
+        if build_isolation.is_isolated() {
+            if let Some(pep517_backend) = &source_build.pep517_backend {
+                source_build
+                    .create_pep517_build_environment(pep517_backend, build_context)
+                    .await?;
+            }
+        }
+
+        Ok(source_build)
+    }
+
+    /// Not a method because we call it before the builder is completely initialized
+    #[allow(clippy::too_many_arguments)]
+    async fn create_pep517_build_environment(
+        &self,
+        pep517_backend: &Pep517Backend,
+        build_context: &impl BuildContext,
+    ) -> Result<(), Error> {
+        // Write the hook output to a file so that we can read it back reliably.
+        let outfile = self
+            .temp_dir
+            .path()
+            .join(format!("get_requires_for_build_{}.txt", self.build_kind));
+
+        debug!(
+            "Calling `{}.get_requires_for_build_{}()`",
+            pep517_backend.backend, self.build_kind
+        );
+
+        let script = formatdoc! {
+            r#"
+            {}
+            import json
+
+            get_requires_for_build = getattr(backend, "get_requires_for_build_{}", None)
+            if get_requires_for_build:
+                requires = get_requires_for_build(config_settings={})
+            else:
+                requires = []
+
+            with open("{}", "w") as fp:
+                json.dump(requires, fp)
+        "#,
+            pep517_backend.backend_import(),
+            self.build_kind,
+            self.config_settings.escape_for_python(),
+            outfile.escape_for_python()
+        };
+        let build_hook = format!("get_requires_for_build_{}", self.build_kind);
+        let span = info_span!(
+            "run_python_script",
+            script=&build_hook,
+            python_version = %self.venv.interpreter().python_version()
+        );
+        let output = self
+            .run_python_script(&script, &build_hook)
+            .instrument(span)
+            .await?;
+
+        // Read the requirements from the output file.
+        let contents = fs_err::read(&outfile).map_err(|err| {
+            Error::from_command_output(
+                format!(
+                    "Build backend failed to read extra requires from `get_requires_for_build_{}`: {err}", self.build_kind
+                ),
+                &output,
+                &self.package_id,
+            )
+        })?;
+
+        // Deserialize the requirements from the output file.
+        let extra_requires: Vec<Requirement> = serde_json::from_slice(&contents).map_err(|err| {
+            Error::from_command_output(
+                format!(
+                    "Build backend failed to return extra requires with `get_requires_for_build_{}`: {err}", self.build_kind
+                ),
+                &output,
+                &self.package_id,
+            )
+        })?;
+
+        // Some packages (such as tqdm 4.66.1) list only extra requires that have already been part of
+        // the pyproject.toml requires (in this case, `wheel`). We can skip doing the whole resolution
+        // and installation again.
+        if extra_requires
+            .iter()
+            .any(|req| !pep517_backend.requirements.contains(req))
+        {
+            debug!("Installing extra requirements for build backend");
+            let requirements: Vec<Requirement> = pep517_backend
+                .requirements
+                .iter()
+                .cloned()
+                .chain(extra_requires)
+                .collect();
+            let resolution = build_context.resolve(&requirements).await.map_err(|err| {
+                Error::RequirementsInstall("build-system.requires (resolve)", err)
+            })?;
+
+            build_context
+                .install(&resolution, &self.venv)
+                .await
+                .map_err(|err| {
+                    Error::RequirementsInstall("build-system.requires (install)", err)
+                })?;
+        }
+
+        Ok(())
     }
 
     async fn get_resolved_requirements(
@@ -644,22 +735,9 @@ impl SourceBuild {
             script="prepare_metadata_for_build_wheel",
             python_version = %self.venv.interpreter().python_version()
         );
-        let output = run_python_script(
+        self.run_python_script(&script, "prepare_metadata_for_build_wheel")
-            &self.venv,
+            .instrument(span)
-            &script,
+            .await?;
-            &self.source_tree,
-            &self.environment_variables,
-            &self.modified_path,
-        )
-        .instrument(span)
-        .await?;
-        if !output.status.success() {
-            return Err(Error::from_command_output(
-                "Build backend failed to determine metadata through `prepare_metadata_for_build_wheel`".to_string(),
-                &output,
-                &self.package_id,
-            ));
-        }
 
         let dirname = fs::read_to_string(&outfile)?;
         if dirname.is_empty() {
@@ -772,30 +850,16 @@ impl SourceBuild {
             self.config_settings.escape_for_python(),
             outfile.escape_for_python()
         };
+        let build_hook = format!("build_{}", self.build_kind);
         let span = info_span!(
             "run_python_script",
-            script=format!("build_{}", self.build_kind),
+            script=&build_hook,
             python_version = %self.venv.interpreter().python_version()
         );
-        let output = run_python_script(
+        let output = self
-            &self.venv,
+            .run_python_script(&script, &build_hook)
-            &script,
+            .instrument(span)
-            &self.source_tree,
+            .await?;
-            &self.environment_variables,
-            &self.modified_path,
-        )
-        .instrument(span)
-        .await?;
-        if !output.status.success() {
-            return Err(Error::from_command_output(
-                format!(
-                    "Build backend failed to build wheel through `build_{}()`",
-                    self.build_kind
-                ),
-                &output,
-                &self.package_id,
-            ));
-        }
 
         let distribution_filename = fs::read_to_string(&outfile)?;
         if !wheel_dir.join(&distribution_filename).is_file() {
@@ -810,6 +874,42 @@ impl SourceBuild {
         }
         Ok(distribution_filename)
     }
+
+    /// It is the caller's responsibility to create an informative span.
+    async fn run_python_script(&self, script: &str, build_hook: &str) -> Result<Output, Error> {
+        let output = Command::new(self.venv.python_executable())
+            .args(["-c", script])
+            .current_dir(self.source_tree.simplified())
+            // Pass in remaining environment variables
+            .envs(&self.environment_variables)
+            // Set the modified PATH
+            .env("PATH", &self.modified_path)
+            // Activate the venv
+            .env("VIRTUAL_ENV", self.venv.root())
+            .output()
+            .await
+            .map_err(|err| {
+                Error::CommandFailed(self.venv.python_executable().to_path_buf(), err)
+            })?;
+        if !output.status.success() {
+            return Err(Error::from_command_output(
+                format!("Build backend failed when calling `{build_hook}()`"),
+                &output,
+                &self.package_id,
+            ));
+        }
+        let stdout = String::from_utf8_lossy(&output.stdout).trim().to_string();
+        let stderr = String::from_utf8_lossy(&output.stderr).trim().to_string();
+        if stdout.is_empty() && stderr.is_empty() {
+            debug!("Output `{}` for {} empty", build_hook, self.package_id);
+        } else {
+            debug!(
+                "Output `{}` for {}:\n--- stdout:\n{stdout}\n--- stderr:\n{stderr}\n---",
+                build_hook, self.package_id
+            );
+        }
+        Ok(output)
+    }
 }
 
 impl SourceBuildTrait for SourceBuild {
@@ -828,144 +928,6 @@ fn escape_path_for_python(path: &Path) -> String {
         .replace('"', "\\\"")
 }
 
-/// Not a method because we call it before the builder is completely initialized
-#[allow(clippy::too_many_arguments)]
-async fn create_pep517_build_environment(
-    source_tree: &Path,
-    venv: &PythonEnvironment,
-    pep517_backend: &Pep517Backend,
-    build_context: &impl BuildContext,
-    package_id: &str,
-    build_kind: BuildKind,
-    config_settings: &ConfigSettings,
-    environment_variables: &FxHashMap<OsString, OsString>,
-    modified_path: &OsString,
-    temp_dir: &TempDir,
-) -> Result<(), Error> {
-    // Write the hook output to a file so that we can read it back reliably.
-    let outfile = temp_dir
-        .path()
-        .join(format!("get_requires_for_build_{build_kind}.txt"));
-
-    debug!(
-        "Calling `{}.get_requires_for_build_{}()`",
-        pep517_backend.backend, build_kind
-    );
-
-    let script = formatdoc! {
-        r#"
-            {}
-            import json
-
-            get_requires_for_build = getattr(backend, "get_requires_for_build_{}", None)
-            if get_requires_for_build:
-                requires = get_requires_for_build(config_settings={})
-            else:
-                requires = []
-
-            with open("{}", "w") as fp:
-                json.dump(requires, fp)
-        "#,
-        pep517_backend.backend_import(),
-        build_kind,
-        config_settings.escape_for_python(),
-        outfile.escape_for_python()
-    };
-    let span = info_span!(
-        "run_python_script",
-        script=format!("get_requires_for_build_{}", build_kind),
-        python_version = %venv.interpreter().python_version()
-    );
-    let output = run_python_script(
-        venv,
-        &script,
-        source_tree,
-        environment_variables,
-        modified_path,
-    )
-    .instrument(span)
-    .await?;
-    if !output.status.success() {
-        return Err(Error::from_command_output(
-            format!("Build backend failed to determine extra requires with `build_{build_kind}()`"),
-            &output,
-            package_id,
-        ));
-    }
-
-    // Read the requirements from the output file.
-    let contents = fs_err::read(&outfile).map_err(|err| {
-        Error::from_command_output(
-            format!(
-                "Build backend failed to read extra requires from `get_requires_for_build_{build_kind}`: {err}"
-            ),
-            &output,
-            package_id,
-        )
-    })?;
-
-    // Deserialize the requirements from the output file.
-    let extra_requires: Vec<Requirement> = serde_json::from_slice(&contents).map_err(|err| {
-        Error::from_command_output(
-            format!(
-                "Build backend failed to return extra requires with `get_requires_for_build_{build_kind}`: {err}"
-            ),
-            &output,
-            package_id,
-        )
-    })?;
-
-    // Some packages (such as tqdm 4.66.1) list only extra requires that have already been part of
-    // the pyproject.toml requires (in this case, `wheel`). We can skip doing the whole resolution
-    // and installation again.
-    // TODO(konstin): Do we still need this when we have a fast resolver?
-    if extra_requires
-        .iter()
-        .any(|req| !pep517_backend.requirements.contains(req))
-    {
-        debug!("Installing extra requirements for build backend");
-        let requirements: Vec<Requirement> = pep517_backend
-            .requirements
-            .iter()
-            .cloned()
-            .chain(extra_requires)
-            .collect();
-        let resolution = build_context
-            .resolve(&requirements)
-            .await
-            .map_err(|err| Error::RequirementsInstall("build-system.requires (resolve)", err))?;
-
-        build_context
-            .install(&resolution, venv)
-            .await
-            .map_err(|err| Error::RequirementsInstall("build-system.requires (install)", err))?;
-    }
-
-    Ok(())
-}
-
-/// It is the caller's responsibility to create an informative span.
-async fn run_python_script(
-    venv: &PythonEnvironment,
-    script: &str,
-    source_tree: &Path,
-    environment_variables: &FxHashMap<OsString, OsString>,
-    modified_path: &OsString,
-) -> Result<Output, Error> {
-    Command::new(venv.python_executable())
-        .args(["-c", script])
-        .current_dir(source_tree.simplified())
-        // Pass in remaining environment variables
-        .envs(environment_variables)
-        // Set the modified PATH
-        .env("PATH", modified_path)
-        // Activate the venv
-        .env("VIRTUAL_ENV", venv.root())
-        .output()
-        .await
-        .map_err(|err| Error::CommandFailed(venv.python_executable().to_path_buf(), err))
-}
-
 #[cfg(test)]
 mod test {
     use std::process::{ExitStatus, Output};

crates/uv/src/logging.rs

@@ -167,7 +167,7 @@ pub(crate) fn setup_logging(
                     HierarchicalLayer::default()
                         .with_targets(true)
                         .with_timer(Uptime::default())
-                        .with_writer(std::io::stderr),
+                        .with_writer(anstream::stderr),
                 )
                 .init();
         }

crates/uv/tests/pip_install.rs

@@ -2397,7 +2397,7 @@ fn no_build_isolation() -> Result<()> {
     ----- stderr -----
     error: Failed to download and build: anyio @ https://files.pythonhosted.org/packages/db/4d/3970183622f0330d3c23d9b8a5f52e365e50381fd484d08e3285104333d3/anyio-4.3.0.tar.gz
       Caused by: Failed to build: anyio @ https://files.pythonhosted.org/packages/db/4d/3970183622f0330d3c23d9b8a5f52e365e50381fd484d08e3285104333d3/anyio-4.3.0.tar.gz
-      Caused by: Build backend failed to determine metadata through `prepare_metadata_for_build_wheel` with exit status: 1
+      Caused by: Build backend failed when calling `prepare_metadata_for_build_wheel()` with exit status: 1
     --- stdout:
 
     --- stderr: