astral-sh / uv

An extremely fast Python package and project manager, written in Rust.
https://docs.astral.sh/uv
Apache License 2.0
19.92k stars 589 forks source link

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

Closed burgholzer closed 1 week ago

burgholzer commented 1 month ago

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 ```console 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 ```console 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.

zanieb commented 1 month ago

I think we might only show build backend output if it fails, the relevant code being https://github.com/astral-sh/uv/blob/cb47aed9dea568811c6c5dd526574eb3cae739b0/crates/uv-build/src/lib.rs#L721-L738

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

burgholzer commented 1 month ago

I can confirm that output is shown on errors 👍🏻

eth3lbert commented 1 month ago

I can help if needed.

zanieb commented 1 month ago

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

zanieb commented 1 month ago

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.