uv swallows output from build backend even in verbose mode #5893

burgholzer · 2024-08-07T20:44:26Z

When installing a package with regular pip in verbose mode, one typically also gets output from the build backend. For example

python -m venv .venv
. .venv/bin/activate
pip install -v git+https://github.com/pybind/scikit_build_example

Console Output

Using pip 24.0 from /Users/burgholzer/Documents/test/.venv/lib/python3.12/site-packages/pip (python 3.12)
Collecting git+https://github.com/pybind/scikit_build_example
Cloning https://github.com/pybind/scikit_build_example to /private/var/folders/94/pdwvr9792913hjv6bw94gg6r0000gn/T/pip-req-build-8wv048d_
Running command git version
git version 2.39.3 (Apple Git-146)
Running command git clone --filter=blob:none https://github.com/pybind/scikit_build_example /private/var/folders/94/pdwvr9792913hjv6bw94gg6r0000gn/T/pip-req-build-8wv048d_
Cloning into '/private/var/folders/94/pdwvr9792913hjv6bw94gg6r0000gn/T/pip-req-build-8wv048d_'...
Updating files:   9% (2/21)
Updating files:  14% (3/21)
Updating files:  19% (4/21)
Updating files:  23% (5/21)
Updating files:  28% (6/21)
Updating files:  33% (7/21)
Updating files:  38% (8/21)
Updating files:  42% (9/21)
Updating files:  47% (10/21)
Updating files:  52% (11/21)
Updating files:  57% (12/21)
Updating files:  61% (13/21)
Updating files:  66% (14/21)
Updating files:  71% (15/21)
Updating files:  76% (16/21)
Updating files:  80% (17/21)
Updating files:  85% (18/21)
Updating files:  90% (19/21)
Updating files:  95% (20/21)
Updating files: 100% (21/21)
Updating files: 100% (21/21), done.
Running command git rev-parse HEAD
6fbb8896ca47e83a38c491cddeaa39a8882a90f9
Resolved https://github.com/pybind/scikit_build_example to commit 6fbb8896ca47e83a38c491cddeaa39a8882a90f9
Running command git rev-parse HEAD
6fbb8896ca47e83a38c491cddeaa39a8882a90f9
Running command pip subprocess to install build dependencies
Collecting scikit-build-core>=0.3.3
  Using cached scikit_build_core-0.10.1-py3-none-any.whl.metadata (20 kB)
Collecting pybind11
  Using cached pybind11-2.13.1-py3-none-any.whl.metadata (9.5 kB)
Collecting packaging>=21.3 (from scikit-build-core>=0.3.3)
  Using cached packaging-24.1-py3-none-any.whl.metadata (3.2 kB)
Collecting pathspec>=0.10.1 (from scikit-build-core>=0.3.3)
  Using cached pathspec-0.12.1-py3-none-any.whl.metadata (21 kB)
Using cached scikit_build_core-0.10.1-py3-none-any.whl (164 kB)
Using cached pybind11-2.13.1-py3-none-any.whl (238 kB)
Using cached packaging-24.1-py3-none-any.whl (53 kB)
Using cached pathspec-0.12.1-py3-none-any.whl (31 kB)
Installing collected packages: pybind11, pathspec, packaging, scikit-build-core
Successfully installed packaging-24.1 pathspec-0.12.1 pybind11-2.13.1 scikit-build-core-0.10.1

[notice] A new release of pip is available: 24.0 -> 24.2
[notice] To update, run: pip install --upgrade pip
Installing build dependencies ... done
Running command Getting requirements to build wheel
Getting requirements to build wheel ... done
Running command Preparing metadata (pyproject.toml)
*** scikit-build-core 0.10.1 using CMake 3.29.3 (metadata_wheel)
Preparing metadata (pyproject.toml) ... done
Building wheels for collected packages: scikit_build_example
Running command Building wheel for scikit_build_example (pyproject.toml)
*** scikit-build-core 0.10.1 using CMake 3.29.3 (wheel)
*** Configuring CMake...
loading initial cache file /var/folders/94/pdwvr9792913hjv6bw94gg6r0000gn/T/tmpj3dkrpke/build/CMakeInit.txt
-- The CXX compiler identification is Clang 18.1.6
-- Detecting CXX compiler ABI info
-- Detecting CXX compiler ABI info - done
-- Check for working CXX compiler: /opt/homebrew/opt/llvm/bin/clang++ - skipped
-- Detecting CXX compile features
-- Detecting CXX compile features - done
-- Found Python: /Users/burgholzer/Documents/test/.venv/bin/python3.12 (found version "3.12.4") found components: Interpreter Development.Module
-- Performing Test HAS_FLTO_THIN
-- Performing Test HAS_FLTO_THIN - Failed
-- Performing Test HAS_FLTO
-- Performing Test HAS_FLTO - Success
-- Found pybind11: /private/var/folders/94/pdwvr9792913hjv6bw94gg6r0000gn/T/pip-build-env-gu20d2my/overlay/lib/python3.12/site-packages/pybind11/include (found version "2.13.1")
-- Configuring done (0.6s)
-- Generating done (0.0s)
-- Build files have been written to: /var/folders/94/pdwvr9792913hjv6bw94gg6r0000gn/T/tmpj3dkrpke/build
*** Building project with Ninja...
[1/2] Building CXX object CMakeFiles/_core.dir/src/main.cpp.o
[2/2] Linking CXX shared module _core.cpython-312-darwin.so
*** Installing project into wheel...
-- Install configuration: "Release"
-- Installing: /var/folders/94/pdwvr9792913hjv6bw94gg6r0000gn/T/tmpj3dkrpke/wheel/platlib/scikit_build_example/_core.cpython-312-darwin.so
/opt/homebrew/anaconda3/bin/strip: changes being made to the file will invalidate the code signature in: /private/var/folders/94/pdwvr9792913hjv6bw94gg6r0000gn/T/tmpj3dkrpke/wheel/platlib/scikit_build_example/_core.cpython-312-darwin.so
[cctools-port]: generating fake signature for '/private/var/folders/94/pdwvr9792913hjv6bw94gg6r0000gn/T/tmpj3dkrpke/wheel/platlib/scikit_build_example/_core.cpython-312-darwin.so.strip'
*** Making wheel...
*** Created scikit_build_example-0.0.1-cp312-cp312-macosx_14_0_arm64.whl
Building wheel for scikit_build_example (pyproject.toml) ... done
Created wheel for scikit_build_example: filename=scikit_build_example-0.0.1-cp312-cp312-macosx_14_0_arm64.whl size=48328 sha256=a7d535323acde9ebe874337213f34bb2220e58d5ba2f4fe29b7b287c8d0cdfbd
Stored in directory: /private/var/folders/94/pdwvr9792913hjv6bw94gg6r0000gn/T/pip-ephem-wheel-cache-02uu75hf/wheels/04/12/1d/cad1972af8fcbb02eb0abefe8236ffb3aaa4ea68c4e72a7b12
Successfully built scikit_build_example
Installing collected packages: scikit_build_example
Successfully installed scikit_build_example-0.0.1

On the other hand, running the same commands with uv, i.e.,

uv venv
. .venv/bin/activate
uv pip install -v git+https://github.com/pybind/scikit_build_example

Console Output

DEBUG uv 0.2.33 (Homebrew 2024-08-01)
DEBUG Searching for Python interpreter in system path
DEBUG Found `cpython-3.11.5-macos-aarch64-none` at `/Users/burgholzer/Documents/test/.venv/bin/python3` (active virtual environment)
DEBUG Using Python 3.11.5 environment at .venv/bin/python3
DEBUG Acquired lock for `.venv`
DEBUG At least one requirement is not satisfied: git+https://github.com/pybind/scikit_build_example
DEBUG Using request timeout of 30s
DEBUG Fetching source distribution from Git: https://github.com/pybind/scikit_build_example
DEBUG Acquired lock for `https://github.com/pybind/scikit_build_example`
DEBUG Updating git source `Url { scheme: "https", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("github.com")), port: None, path: "/pybind/scikit_build_example", query: None, fragment: None }`
DEBUG Attempting GitHub fast path for: https://api.github.com/repos/pybind/scikit_build_example/commits/HEAD
DEBUG Performing a Git fetch for: https://github.com/pybind/scikit_build_example
DEBUG reset /private/var/folders/94/pdwvr9792913hjv6bw94gg6r0000gn/T/.tmp7rSS46/git-v0/checkouts/f1b0f44246bef58f/6fbb889 to 6fbb8896ca47e83a38c491cddeaa39a8882a90f9
DEBUG Fetching source distribution from Git: https://github.com/pybind/scikit_build_example
DEBUG Acquired lock for `https://github.com/pybind/scikit_build_example`
DEBUG Using existing git source `Url { scheme: "https", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("github.com")), port: None, path: "/pybind/scikit_build_example", query: None, fragment: None }`
DEBUG Acquired lock for `/private/var/folders/94/pdwvr9792913hjv6bw94gg6r0000gn/T/.tmp7rSS46/built-wheels-v3/git/09879697cbfb302e/6fbb8896ca47e83a`
DEBUG Preparing metadata for: git+https://github.com/pybind/scikit_build_example
DEBUG No static `PKG-INFO` available for: git+https://github.com/pybind/scikit_build_example (MissingPkgInfo)
DEBUG Found static `pyproject.toml` for: git+https://github.com/pybind/scikit_build_example
DEBUG No workspace root found, using project root
DEBUG Solving with installed Python version: 3.11.5
DEBUG Adding direct dependency: scikit-build-example*
DEBUG Searching for a compatible version of scikit-build-example @ git+https://github.com/pybind/scikit_build_example (*)
DEBUG Tried 1 versions: scikit-build-example 1
DEBUG Split specific environment resolution took 0.001s
Resolved 1 package in 1.40s
DEBUG Identified uncached requirement: scikit-build-example @ git+https://github.com/pybind/scikit_build_example
DEBUG Fetching source distribution from Git: https://github.com/pybind/scikit_build_example
DEBUG Acquired lock for `https://github.com/pybind/scikit_build_example`
DEBUG Using existing git source `Url { scheme: "https", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("github.com")), port: None, path: "/pybind/scikit_build_example", query: None, fragment: None }`
DEBUG Acquired lock for `/private/var/folders/94/pdwvr9792913hjv6bw94gg6r0000gn/T/.tmp7rSS46/built-wheels-v3/git/ed9999dc690d99b0/6fbb8896ca47e83a`
DEBUG Building: scikit-build-example @ git+https://github.com/pybind/scikit_build_example@6fbb8896ca47e83a38c491cddeaa39a8882a90f9
INFO Ignoring empty directory
DEBUG Solving with installed Python version: 3.11.5
DEBUG Adding direct dependency: scikit-build-core>=0.3.3
DEBUG Adding direct dependency: pybind11*
DEBUG No cache entry for: https://pypi.org/simple/scikit-build-core/
DEBUG No cache entry for: https://pypi.org/simple/pybind11/
DEBUG No cache entry for: https://files.pythonhosted.org/packages/84/fb/1a249de406daf2b4ebd2d714b739e8519034617daec085e3833c1a3ed57c/pybind11-2.13.1-py3-none-any.whl.metadata
DEBUG Searching for a compatible version of scikit-build-core (>=0.3.3)
DEBUG Selecting: scikit-build-core==0.10.1 [compatible] (scikit_build_core-0.10.1-py3-none-any.whl)
DEBUG No cache entry for: https://files.pythonhosted.org/packages/df/1a/6a3d2b5d2ce1b87dbc9d58592cf67741f97eafee68e8008c2f56f8fc1be6/scikit_build_core-0.10.1-py3-none-any.whl.metadata
DEBUG Adding transitive dependency for scikit-build-core==0.10.1: packaging>=21.3
DEBUG Adding transitive dependency for scikit-build-core==0.10.1: pathspec>=0.10.1
DEBUG Searching for a compatible version of pybind11 (*)
DEBUG Selecting: pybind11==2.13.1 [compatible] (pybind11-2.13.1-py3-none-any.whl)
DEBUG No cache entry for: https://pypi.org/simple/packaging/
DEBUG No cache entry for: https://pypi.org/simple/pathspec/
DEBUG No cache entry for: https://files.pythonhosted.org/packages/cc/20/ff623b09d963f88bfde16306a54e12ee5ea43e9b597108672ff3a408aad6/pathspec-0.12.1-py3-none-any.whl.metadata
DEBUG Searching for a compatible version of packaging (>=21.3)
DEBUG Selecting: packaging==24.1 [compatible] (packaging-24.1-py3-none-any.whl)
DEBUG No cache entry for: https://files.pythonhosted.org/packages/08/aa/cc0199a5f0ad350994d660967a8efb233fe0416e4639146c089643407ce6/packaging-24.1-py3-none-any.whl.metadata
DEBUG Searching for a compatible version of pathspec (>=0.10.1)
DEBUG Selecting: pathspec==0.12.1 [compatible] (pathspec-0.12.1-py3-none-any.whl)
DEBUG Tried 4 versions: packaging 1, pathspec 1, pybind11 1, scikit-build-core 1
DEBUG Split specific environment resolution took 0.324s
DEBUG Installing in packaging==24.1, pathspec==0.12.1, pybind11==2.13.1, scikit-build-core==0.10.1 in /private/var/folders/94/pdwvr9792913hjv6bw94gg6r0000gn/T/.tmp7rSS46/builds-v0/.tmpkbEwxR
DEBUG Identified uncached requirement: packaging==24.1
DEBUG Identified uncached requirement: pathspec==0.12.1
DEBUG Identified uncached requirement: pybind11==2.13.1
DEBUG Identified uncached requirement: scikit-build-core==0.10.1
DEBUG Downloading and building requirements for build: packaging==24.1, pathspec==0.12.1, pybind11==2.13.1, scikit-build-core==0.10.1
DEBUG No cache entry for: https://files.pythonhosted.org/packages/84/fb/1a249de406daf2b4ebd2d714b739e8519034617daec085e3833c1a3ed57c/pybind11-2.13.1-py3-none-any.whl
DEBUG No cache entry for: https://files.pythonhosted.org/packages/df/1a/6a3d2b5d2ce1b87dbc9d58592cf67741f97eafee68e8008c2f56f8fc1be6/scikit_build_core-0.10.1-py3-none-any.whl
DEBUG No cache entry for: https://files.pythonhosted.org/packages/cc/20/ff623b09d963f88bfde16306a54e12ee5ea43e9b597108672ff3a408aad6/pathspec-0.12.1-py3-none-any.whl
DEBUG No cache entry for: https://files.pythonhosted.org/packages/08/aa/cc0199a5f0ad350994d660967a8efb233fe0416e4639146c089643407ce6/packaging-24.1-py3-none-any.whl
DEBUG Installing build requirements: pathspec==0.12.1, scikit-build-core==0.10.1, pybind11==2.13.1, packaging==24.1
DEBUG Calling `scikit_build_core.build.get_requires_for_build_wheel()`
DEBUG Calling `scikit_build_core.build.build_wheel("/private/var/folders/94/pdwvr9792913hjv6bw94gg6r0000gn/T/.tmp7rSS46/built-wheels-v3/git/ed9999dc690d99b0/6fbb8896ca47e83a/.tmp0CQXob", {}, None)`
DEBUG Finished building: scikit-build-example @ git+https://github.com/pybind/scikit_build_example@6fbb8896ca47e83a38c491cddeaa39a8882a90f9
Prepared 1 package in 8.05s
Installed 1 package in 1ms
+ scikit-build-example==0.0.1 (from git+https://github.com/pybind/scikit_build_example@6fbb8896ca47e83a38c491cddeaa39a8882a90f9)

Note that there is no output between the following two lines

DEBUG Calling `scikit_build_core.build.build_wheel("/private/var/folders/94/pdwvr9792913hjv6bw94gg6r0000gn/T/.tmp7rSS46/built-wheels-v3/git/ed9999dc690d99b0/6fbb8896ca47e83a/.tmp0CQXob", {}, None)`
DEBUG Finished building: scikit-build-example @ git+https://github.com/pybind/scikit_build_example@6fbb8896ca47e83a38c491cddeaa39a8882a90f9

which is where I would have expected to see the information from the build backend similar to how pip displays the information.

Am I overlooking something or is uv swallowing the build system output? If so, is this intended (even in verbose mode)?

Note that the build backend in question is scikit-build-core. I am not quite sure whether that contributes to the problem.
This was tested on uv 0.2.33 on macOS Catalina. However, this dates back to at least uv 0.2.21.

The text was updated successfully, but these errors were encountered:

zanieb · 2024-08-07T20:54:35Z

I think we might only show build backend output if it fails, the relevant code being

uv/crates/uv-build/src/lib.rs

Lines 721 to 738 in cb47aed

    
           let output = self 
        
               .runner 
        
               .run_script( 
        
                   &self.venv, 
        
                   &script, 
        
                   &self.source_tree, 
        
                   &self.environment_variables, 
        
                   &self.modified_path, 
        
               ) 
        
               .instrument(span) 
        
               .await?; 
        
           if !output.status.success() { 
        
               return Err(Error::from_command_output( 
        
                   format!("Build backend failed to determine metadata through `prepare_metadata_for_build_{}`", self.build_kind), 
        
                   &output, 
        
                   &self.version_id, 
        
               )); 
        
           }

I agree it sounds nice to stream the output if verbose mode is enabled.

burgholzer · 2024-08-07T21:06:35Z

I can confirm that output is shown on errors 👍🏻

eth3lbert · 2024-08-09T07:32:53Z

I can help if needed.

zanieb · 2024-08-09T13:40:25Z

@eth3lbert feel free! We just need to stream the output from the subprocess in verbose mode.

zanieb · 2024-08-09T13:41:06Z

Well, I say "just" but it's probably a bit more complicated to make sure it displays nicely with all the concurrency we're doing. Honestly not entirely sure how feasible it will be for it to work well.

zanieb added the tracing Verbose output and debugging label Aug 7, 2024

charliermarsh mentioned this issue Aug 25, 2024

UV --verbose doesn't print out maturin build stdout #6600

Closed

charliermarsh self-assigned this Aug 31, 2024

charliermarsh mentioned this issue Aug 31, 2024

Stream build backend output to debug! #6903

Merged

charliermarsh closed this as completed in 6897001 Sep 2, 2024

charliermarsh closed this as completed in #6903 Sep 2, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

uv swallows output from build backend even in verbose mode #5893

uv swallows output from build backend even in verbose mode #5893

burgholzer commented Aug 7, 2024

zanieb commented Aug 7, 2024

burgholzer commented Aug 7, 2024

eth3lbert commented Aug 9, 2024

zanieb commented Aug 9, 2024

zanieb commented Aug 9, 2024

uv swallows output from build backend even in verbose mode #5893

uv swallows output from build backend even in verbose mode #5893

Comments

burgholzer commented Aug 7, 2024

zanieb commented Aug 7, 2024

burgholzer commented Aug 7, 2024

eth3lbert commented Aug 9, 2024

zanieb commented Aug 9, 2024

zanieb commented Aug 9, 2024