pip: Better reporting on output from PEP 517 build backends

Running with -v is also problematic because it contains lots of noise, duplicates the build backend’s output in case of errors and prints an irrelevant stack trace.

These issues are no longer a concern. We’ve improved handling of output from the build-backends in 22.0 and also reduced the verbosity of a single -v flag in releases since this issue was filed.

I’m going to go ahead and close this now – I think we’re in a good spot w.r.t. output handling from build backends, but if folks think there’s specific improvements we can make, I’d like you to chip in at https://discuss.python.org/t/13779/ (you can log in via GitHub) since the relevant changes here likely affect more tools than just pip (at the very least, it affects build backends).

It seems like six different issues or proposed improvements are being mentioned:

1. Verbose mode logs too many messages
2. The setup.py clean traceback isn’t needed
3. The InstallationError traceback at the end isn’t needed
4. The subprocess build output (stdout and/or stderr) shouldn’t require verbose mode to display
5. The build output should forward directly to the console instead of going through pip when displayed (e.g. to take advantage of tty)
6. ~The beginning and end of the build output should be distinguished / delineated better~ (This was addressed by PR #6655.)

To keep the discussions manageable, I think it would be best to separate these into different issues. Each one can be discussed separately, and any resolution / PR if it gets to that point could likely be implemented independent of the PR for any other. Here it seems like the interest is mainly in (4) and (5). I would suggest creating a new issue for each one you think should be addressed.

I started by creating an issue for (2) here: https://github.com/pypa/pip/issues/6642 (But I’m not completely sure it’s an issue after starting to investigate.)

What solution are you proposing? The problem I see is that if the output is shown by default, then that could be too noisy for most users. Are you suggesting an option “between” verbose and default, where the default log messages are shown, plus the output from the subprocesses? Or are you suggesting verbose showing less in general?

pip install and pip wheel should stop capturing stdout and stderr when calling the build backend. sys.stdout.isatty() and sys.stderr.isatty() should stay true if they were true for pip. If forwarding stdout is too verbose with other build backends, only stderr should be forwarded.

Ideally, I think the combined output should look something like this, but with terminal colors and a progress bar that I can’t show in markdown:

$ pip install .
Processing /home/konsti/pyo3-pack/test-crates/cffi-pure
Installing build dependencies ... done
Getting requirements to build wheel ... done
Installing backend dependencies ... done
Preparing wheel metadata ...
🐍 Using CPython 3.6m at python to generate the cffi bindings
Successfully prepared metadata for cffi-pure-0.1.0
Building wheel for cffi-pure (PEP 517)
   Compiling aho-corasick v0.7.3
   Compiling quote v0.6.12
   Compiling mashup-impl v0.1.9
   Compiling mashup v0.1.9
   Compiling pyo3 v0.7.0
   Compiling pyo3-derive-backend v0.7.0
   Compiling ctor v0.1.9
   Compiling inventory-impl v0.1.3
   Compiling ghost v0.1.0
   Compiling inventory v0.1.3
   Compiling pyo3cls v0.7.0
   Compiling pyo3-pure v2.1.0 (/home/konsti/pyo3-pack/test-crates/pyo3-pure)
    Finished dev [unoptimized + debuginfo] target(s) in 37.36s
Successfully built cffi-pure-0.1.0
Uninstalling existing installation cffi-pure-0.1.0 ... done
Installing collected packages: cffi-pure ... done
Successfully installed cffi-pure-0.1.0

Since we’ve already discussed it, the output of pip install . -v should become less verbose. I’d say at least the “Found link” / “Skipping link” lines and the InstallationError backtrace should go away. The output of -vv and -vvv is fine, those can also keep showing backtraces.

Is the first traceback actually from pip? It looks like that one is coming from the underlying subprocess.

Afaik that traceback comes from the setup.py fallback at _internal/req/req_install.py

Maybe one way to improve the situation could be to better delineate the output from the subprocess, e.g. by prefixing each line or putting some kind of divider at the beginning and end.

I think using Building XY and Successfully build XY/Failed to build XY makes a good delimiter. I’d like to avoid prefixing each line because that breaks isatty() and thereby terminal colors and progress bars.

I’m marking this “discussion needed” instead of “awaiting PR” because I think it would be good to discuss what a PR should do before work goes into writing one. For example, some of the issues mentioned in the original post turned out not to be issues. Also, we might find that more than one improvement would be worth implementing, and so more than one PR.

Totally agree; I opened the issue to discuss what the best solution for logging/error reporting would be. Just making pip not capture stdout and stderr took less time then writing up the initial post.

Sounds good to me @cjerdonek!

Running with -v is also problematic because it contains lots of noise, duplicates the build backend’s output in case of errors and prints an irrelevant stack trace.

I think improving these things would be good, for a start. The second two seem pretty easy to address. (There is a separate issue to let people make the logs less noisy.)