Skip to content

Commit

Permalink
Stream build backend output to debug! (#6903)
Browse files Browse the repository at this point in the history 
## Summary

We need to decide whether we want this in `debug!` or `tracing!`. We
also _probably_ (?) want to show this by default in `uv build`.

Closes #1567.

Closes #5893.
  • Loading branch information
@charliermarsh
charliermarsh authored Sep 2, 2024
1 parent 8eef1a2 commit 6897001
Show file tree
Hide file tree
Showing 5 changed files with 111 additions and 56 deletions.
153 changes: 104 additions & 49 deletions crates/uv-build/src/lib.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -13,16 +13,17 @@ use std::ffi::OsString;
use std::fmt::{Display, Formatter};
use std::io;
use std::path::{Path, PathBuf};
use std::process::{ExitStatus, Output};
use std::process::ExitStatus;
use std::rc::Rc;
use std::str::FromStr;
use std::sync::LazyLock;
use std::{env, iter};
use tempfile::{tempdir_in, TempDir};
use thiserror::Error;
use tokio::io::AsyncBufReadExt;
use tokio::process::Command;
use tokio::sync::{Mutex, Semaphore};
use tracing::{debug, info_span, instrument, Instrument};
use tracing::{debug, error, info_span, instrument, Instrument};

use distribution_types::Resolution;
use pep440_rs::Version;
Expand Down Expand Up @@ -89,7 +90,7 @@ pub enum Error {
RequirementsInstall(&'static str, #[source] anyhow::Error),
#[error("Failed to create temporary virtualenv")]
Virtualenv(#[from] uv_virtualenv::Error),
#[error("Failed to run {0}")]
#[error("Failed to run `{0}`")]
CommandFailed(PathBuf, #[source] io::Error),
#[error("{message} with {exit_code}\n--- stdout:\n{stdout}\n--- stderr:\n{stderr}\n---")]
BuildBackend {
Expand Down Expand Up @@ -159,14 +160,11 @@ impl Display for MissingHeaderCause {
impl Error {
fn from_command_output(
message: String,
output: &Output,
output: &PythonRunnerOutput,
version_id: impl Into<String>,
) -> Self {
let stdout = String::from_utf8_lossy(&output.stdout).trim().to_string();
let stderr = String::from_utf8_lossy(&output.stderr).trim().to_string();

// In the cases i've seen it was the 5th and 3rd last line (see test case), 10 seems like a reasonable cutoff
let missing_library = stderr.lines().rev().take(10).find_map(|line| {
// In the cases I've seen it was the 5th and 3rd last line (see test case), 10 seems like a reasonable cutoff.
let missing_library = output.stderr.iter().rev().take(10).find_map(|line| {
if let Some((_, [header])) = MISSING_HEADER_RE_GCC
.captures(line.trim())
.or(MISSING_HEADER_RE_CLANG.captures(line.trim()))
Expand All @@ -191,8 +189,8 @@ impl Error {
return Self::MissingHeader {
message,
exit_code: output.status,
stdout,
stderr,
stdout: output.stdout.iter().join("\n"),
stderr: output.stderr.iter().join("\n"),
missing_header_cause: MissingHeaderCause {
missing_library,
version_id: version_id.into(),
Expand All @@ -203,8 +201,8 @@ impl Error {
Self::BuildBackend {
message,
exit_code: output.status,
stdout,
stderr,
stdout: output.stdout.iter().join("\n"),
stderr: output.stderr.iter().join("\n"),
}
}
}
Expand Down Expand Up @@ -454,7 +452,7 @@ impl SourceBuild {
.install(&resolved_requirements, &venv)
.await
.map_err(|err| {
Error::RequirementsInstall("build-system.requires (install)", err)
Error::RequirementsInstall("`build-system.requires` (install)", err)
})?;
}

Expand Down Expand Up @@ -540,7 +538,7 @@ impl SourceBuild {
.resolve(&default_backend.requirements)
.await
.map_err(|err| {
Error::RequirementsInstall("setup.py build (resolve)", err)
Error::RequirementsInstall("`setup.py` build (resolve)", err)
})?;
*resolution = Some(resolved_requirements.clone());
resolved_requirements
Expand All @@ -550,7 +548,7 @@ impl SourceBuild {
.resolve(&pep517_backend.requirements)
.await
.map_err(|err| {
Error::RequirementsInstall("build-system.requires (resolve)", err)
Error::RequirementsInstall("`build-system.requires` (resolve)", err)
})?
},
)
Expand Down Expand Up @@ -682,8 +680,8 @@ impl SourceBuild {
};
let span = info_span!(
"run_python_script",
script=format!("prepare_metadata_for_build_{}", self.build_kind),
python_version = %self.venv.interpreter().python_version()
script = format!("prepare_metadata_for_build_{}", self.build_kind),
version_id = self.version_id,
);
let output = self
.runner
Expand Down Expand Up @@ -808,8 +806,8 @@ impl SourceBuild {

let span = info_span!(
"run_python_script",
script=format!("build_{}", self.build_kind),
python_version = %self.venv.interpreter().python_version()
script = format!("build_{}", self.build_kind),
version_id = self.version_id,
);
let output = self
.runner
Expand Down Expand Up @@ -909,8 +907,8 @@ async fn create_pep517_build_environment(
};
let span = info_span!(
"run_python_script",
script=format!("get_requires_for_build_{}", build_kind),
python_version = %venv.interpreter().python_version()
script = format!("get_requires_for_build_{}", build_kind),
version_id = version_id,
);
let output = runner
.run_script(
Expand Down Expand Up @@ -971,23 +969,31 @@ async fn create_pep517_build_environment(
let resolution = build_context
.resolve(&requirements)
.await
.map_err(|err| Error::RequirementsInstall("build-system.requires (resolve)", err))?;
.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))?;
.map_err(|err| Error::RequirementsInstall("`build-system.requires` (install)", err))?;
}

Ok(())
}

/// A runner that manages the execution of external python processes with a
/// concurrency limit.
#[derive(Debug)]
struct PythonRunner {
control: Semaphore,
}

#[derive(Debug)]
struct PythonRunnerOutput {
stdout: Vec<String>,
stderr: Vec<String>,
status: ExitStatus,
}

impl PythonRunner {
/// Create a `PythonRunner` with the provided concurrency limit.
fn new(concurrency: usize) -> PythonRunner {
Expand All @@ -1009,36 +1015,85 @@ impl PythonRunner {
source_tree: &Path,
environment_variables: &FxHashMap<OsString, OsString>,
modified_path: &OsString,
) -> Result<Output, Error> {
) -> Result<PythonRunnerOutput, Error> {
/// Read lines from a reader and store them in a buffer.
async fn read_from(
mut reader: tokio::io::Lines<tokio::io::BufReader<impl tokio::io::AsyncRead + Unpin>>,
buffer: &mut Vec<String>,
) -> io::Result<()> {
loop {
match reader.next_line().await? {
Some(line) => {
debug!("{line}");
buffer.push(line);
}
None => return Ok(()),
}
}
}

let _permit = self.control.acquire().await.unwrap();

Command::new(venv.python_executable())
let mut child = 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())
.env("CLICOLOR_FORCE", "1")
.output()
.stdout(std::process::Stdio::piped())
.stderr(std::process::Stdio::piped())
.spawn()
.map_err(|err| Error::CommandFailed(venv.python_executable().to_path_buf(), err))?;

// Create buffers to capture `stdout` and `stderr`.
let mut stdout_buf = Vec::with_capacity(1024);
let mut stderr_buf = Vec::with_capacity(1024);

// Create separate readers for `stdout` and `stderr`.
let stdout_reader = tokio::io::BufReader::new(child.stdout.take().unwrap()).lines();
let stderr_reader = tokio::io::BufReader::new(child.stderr.take().unwrap()).lines();

// Asynchronously read from the in-memory pipes.
let result = tokio::join!(
read_from(stdout_reader, &mut stdout_buf),
read_from(stderr_reader, &mut stderr_buf),
);
match result {
(Ok(()), Ok(())) => {}
(Err(err), _) | (_, Err(err)) => {
return Err(Error::CommandFailed(
venv.python_executable().to_path_buf(),
err,
))
}
}

// Wait for the child process to finish.
let status = child
.wait()
.await
.map_err(|err| Error::CommandFailed(venv.python_executable().to_path_buf(), err))
.map_err(|err| Error::CommandFailed(venv.python_executable().to_path_buf(), err))?;

Ok(PythonRunnerOutput {
stdout: stdout_buf,
stderr: stderr_buf,
status,
})
}
}

#[cfg(test)]
mod test {
use std::process::{ExitStatus, Output};
use std::process::ExitStatus;

use indoc::indoc;

use crate::Error;
use crate::{Error, PythonRunnerOutput};

#[test]
fn missing_header() {
let output = Output {
let output = PythonRunnerOutput {
status: ExitStatus::default(), // This is wrong but `from_raw` is platform-gated.
stdout: indoc!(r"
running bdist_wheel
Expand All @@ -1047,7 +1102,7 @@ mod test {
creating build/temp.linux-x86_64-cpython-39/pygraphviz
gcc -Wno-unused-result -Wsign-compare -DNDEBUG -g -fwrapv -O3 -Wall -DOPENSSL_NO_SSL3 -fPIC -DSWIG_PYTHON_STRICT_BYTE_CHAR -I/tmp/.tmpy6vVes/.venv/include -I/home/konsti/.pyenv/versions/3.9.18/include/python3.9 -c pygraphviz/graphviz_wrap.c -o build/temp.linux-x86_64-cpython-39/pygraphviz/graphviz_wrap.o
"
).as_bytes().to_vec(),
).lines().map(ToString::to_string).collect(),
stderr: indoc!(r#"
warning: no files found matching '*.png' under directory 'doc'
warning: no files found matching '*.txt' under directory 'doc'
Expand All @@ -1059,7 +1114,7 @@ mod test {
compilation terminated.
error: command '/usr/bin/gcc' failed with exit code 1
"#
).as_bytes().to_vec(),
).lines().map(ToString::to_string).collect(),
};

let err = Error::from_command_output(
Expand Down Expand Up @@ -1098,20 +1153,20 @@ mod test {

#[test]
fn missing_linker_library() {
let output = Output {
let output = PythonRunnerOutput {
status: ExitStatus::default(), // This is wrong but `from_raw` is platform-gated.
stdout: Vec::new(),
stderr: indoc!(
r"
1099 | n = strlen(p);
| ^~~~~~~~~
1099 | n = strlen(p);
| ^~~~~~~~~
/usr/bin/ld: cannot find -lncurses: No such file or directory
collect2: error: ld returned 1 exit status
error: command '/usr/bin/x86_64-linux-gnu-gcc' failed with exit code 1
"
error: command '/usr/bin/x86_64-linux-gnu-gcc' failed with exit code 1"
)
.as_bytes()
.to_vec(),
.lines()
.map(ToString::to_string)
.collect(),
};

let err = Error::from_command_output(
Expand All @@ -1128,7 +1183,7 @@ mod test {
--- stderr:
1099 | n = strlen(p);
| ^~~~~~~~~
| ^~~~~~~~~
/usr/bin/ld: cannot find -lncurses: No such file or directory
collect2: error: ld returned 1 exit status
error: command '/usr/bin/x86_64-linux-gnu-gcc' failed with exit code 1
Expand All @@ -1142,7 +1197,7 @@ mod test {

#[test]
fn missing_wheel_package() {
let output = Output {
let output = PythonRunnerOutput {
status: ExitStatus::default(), // This is wrong but `from_raw` is platform-gated.
stdout: Vec::new(),
stderr: indoc!(
Expand All @@ -1152,11 +1207,11 @@ mod test {
or: setup.py --help-commands
or: setup.py cmd --help
error: invalid command 'bdist_wheel'
"
error: invalid command 'bdist_wheel'"
)
.as_bytes()
.to_vec(),
.lines()
.map(ToString::to_string)
.collect(),
};

let err = Error::from_command_output(
Expand Down
8 changes: 4 additions & 4 deletions crates/uv-virtualenv/src/virtualenv.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -8,7 +8,7 @@ use std::path::Path;
use fs_err as fs;
use fs_err::File;
use itertools::Itertools;
use tracing::info;
use tracing::debug;

use pypi_types::Scheme;
use uv_fs::{cachedir, Simplified, CWD};
Expand Down Expand Up @@ -92,16 +92,16 @@ pub(crate) fn create(
)));
} else if metadata.is_dir() {
if allow_existing {
info!("Allowing existing directory");
debug!("Allowing existing directory");
} else if location.join("pyvenv.cfg").is_file() {
info!("Removing existing directory");
debug!("Removing existing directory");
fs::remove_dir_all(location)?;
fs::create_dir_all(location)?;
} else if location
.read_dir()
.is_ok_and(|mut dir| dir.next().is_none())
{
info!("Ignoring empty directory");
debug!("Ignoring empty directory");
} else {
return Err(Error::Io(io::Error::new(
io::ErrorKind::AlreadyExists,
Expand Down
2 changes: 1 addition & 1 deletion crates/uv/tests/pip_compile.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -11781,7 +11781,7 @@ fn incompatible_build_constraint() -> Result<()> {
----- stderr -----
error: Failed to download and build `requests==1.2.0`
Caused by: Failed to install requirements from setup.py build (resolve)
Caused by: Failed to install requirements from `setup.py` build (resolve)
Caused by: No solution found when resolving: setuptools>=40.8.0
Caused by: Because you require setuptools>=40.8.0 and setuptools==1, we can conclude that your requirements are unsatisfiable.
"###
Expand Down
2 changes: 1 addition & 1 deletion crates/uv/tests/pip_install.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -6171,7 +6171,7 @@ fn incompatible_build_constraint() -> Result<()> {
----- stderr -----
error: Failed to download and build `requests==1.2.0`
Caused by: Failed to install requirements from setup.py build (resolve)
Caused by: Failed to install requirements from `setup.py` build (resolve)
Caused by: No solution found when resolving: setuptools>=40.8.0
Caused by: Because you require setuptools>=40.8.0 and setuptools==1, we can conclude that your requirements are unsatisfiable.
"###
Expand Down
2 changes: 1 addition & 1 deletion crates/uv/tests/pip_sync.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -5473,7 +5473,7 @@ fn incompatible_build_constraint() -> Result<()> {
----- stderr -----
error: Failed to download and build `requests==1.2.0`
Caused by: Failed to install requirements from setup.py build (resolve)
Caused by: Failed to install requirements from `setup.py` build (resolve)
Caused by: No solution found when resolving: setuptools>=40.8.0
Caused by: Because you require setuptools>=40.8.0 and setuptools==1, we can conclude that your requirements are unsatisfiable.
"###
Expand Down

0 comments on commit 6897001

Please sign in to comment.