How to get C compiler stderr when building C extension via pip wheel or via build?

mcepl · June 12, 2024, 1:54pm

With old python3 -mpip wheel gcc output (centos7 (#6860716143) · Jobs · m2crypto / m2crypto · GitLab, CentOS 7, pip 9.0.3, setuptools 39.2.0) have shown all gcc messages, with more recent setup (fedora (#6860716141) · Jobs · m2crypto / m2crypto · GitLab, Fedora 40, pip 23.3.2, setuptools 69.0.3) I get nothing. How to persuade pip to show these gcc messages?

I tried everything, all the way to python3 -mpip wheel --no-build-isolation --no-clean --no-color --progress-bar off --no-deps -v --config-setting=--global-option=--verbose --wheel-dir dist/ . and still I get nothing.

Any ideas, please?

mcepl · June 12, 2024, 1:54pm

Test build at build #1249116 - success

pf_moore · June 12, 2024, 2:00pm

I don’t recall the exact level pip shows build backend output at, but you could try a higher verbosity - -vvv is what we normally recommend for full output.

mcepl · June 12, 2024, 3:25pm

The line is python3 -mpip wheel --no-build-isolation --no-clean --no-color --progress-bar off --no-deps -vvvv --config-setting=--build-option=-vvvv --wheel-dir dist/ . and still nothing
https://builds.sr.ht/~mcepl/job/1249252

cameron · June 12, 2024, 11:52pm

This sounds like a setuptools problem rather than a pip problem,
although that is a guess.

Your output seem to be SourceHut build runs.

Do you get the same lack of output when you run this locally at a
command prompt?

Sometimes a build system stuffs error output into a log file and recites
the log file name (not that I see that in your runs).

cameron · June 12, 2024, 11:57pm

If this is the relevant line in the build:
https://builds.sr.ht/~mcepl/job/1249252#task-build-259
then I do not see your -vvv getting used.

mcepl · June 13, 2024, 9:58am

Compiler is run during the pip wheel run (see line 54).

pf_moore · June 13, 2024, 10:09am

Hang on. The build was successful, and the install was successful. Why do you need to see the setuptools output? Pip generally only shows build backend output when there’s a failure. And that’s by design, as people were unhappy with the amount of output being generated by a successful install.

mcepl · June 13, 2024, 12:04pm

See the original centos7 build, it supplied plenty of warnings, which suggested things I could and should fix before they will become bugs.

pf_moore · June 13, 2024, 12:10pm

OK, personally I don’t see that as something pip as an installer should be focusing on. Maybe something like build allows you to do this?

cameron · June 13, 2024, 11:22pm

Maybe a workaround might be to provide a shell script called “gcc” or
“clang” or whatever compiler is involved, which runs the real compiler
but emits a nonzero exit code if there are any warnings. Something along
the lines of:

 #!/bin/sh
 errs=/tmp/cc$$-errs
 the-real-cc-command "$@" 2>"$errs"
 xit=$?
 cat "$errs" >&2
 [ -s "$errs" ] && xit=1
 exit $xit

Just a thought.

Of course you’d need to get that into the CI environment also.

pradyunsg · June 14, 2024, 4:24am

To the best of my ability to tell, the issue here is that something external to pip has changed.

Either setuptools is suppressing the compiler warnings (which I would be very surprised by because I’ve never seen it do that), or
you’re not getting them anymore because setuptools is passing better options in the (checks changelog) 6 years between the versions being mentioned here, or
your compiler changed across versions and got better. CentOS 7 and current Fedora release are literally a decade apart in their initial release dates (which is when their underlying compiler versions are effectively pinned, modulo bugfixes/backports that RH does).

Wait, that’s not quite complete. Yes, It’ll show output unconditionally on failures. However, relevant to this situation, it will show the output of the build system when the verbosity levels internally are 1 or more (i.e. -v was passed).

github.com

pypa/pip/blob/24.0/src/pip/_internal/utils/subprocess.py#L102-L116


      
          # Most places in pip use show_stdout=False. What this means is--
          #
          # - We connect the child's output (combined stderr and stdout) to a
          #   single pipe, which we read.
          # - We log this output to stderr at DEBUG level as it is received.
          # - If DEBUG logging isn't enabled (e.g. if --verbose logging wasn't
          #   requested), then we show a spinner so the user can still see the
          #   subprocess is in progress.
          # - If the subprocess exits with an error, we log the output to stderr
          #   at ERROR level if it hasn't already been displayed to the console
          #   (e.g. if --verbose logging wasn't enabled).  This way we don't log
          #   the output to the console twice.
          #
          # If show_stdout=True, then the above is still done, but with DEBUG
          # replaced by INFO.

From the logs of the build:

INFO:copy_file:copying build/lib.linux-x86_64-cpython-312/M2Crypto/ftpslib.py -> build/bdist.linux-x86_64/wheel/M2Crypto

This is very much output from setuptools, so we’re definitely not suppressing this.

INFO:copy_file:copying build/lib.linux-x86_64-cpython-312/M2Crypto/ftpslib.py -> build/bdist.linux-x86_64/wheel/M2Crypto

Do you have something like a .pth file affecting how things are logged, or have an otherwise patched copy of setuptools? I haven’t seen setuptools ever log things without the logger being set up and these logs look like a logging module that’s not been setup correctly. I don’t think you have a setuptools copy that originated from PyPI unpatched, at least in this run.

I checked and pip does print to stderr correctly.

❯ pwd                       
/tmp/test-pkg

❯ tree .
.
└── setup.py

1 directory, 1 file

❯ cat setup.py        
import sys
import setuptools

sys.stderr.write("This is a message from setup.py")

setuptools.setup(
    name="test-package",
    version="0.0.1",
    packages=[],
)
❯ PIP_REQUIRE_VENV=0 pip install -v /tmp/test-pkg --dry-run
Using pip 23.3.2 from /Users/pradyunsg/Developer/github/pip/.venv/lib/python3.12/site-packages/pip (python 3.12)
Processing /tmp/test-pkg
  Running command pip subprocess to install build dependencies
  Collecting setuptools>=40.8.0
    Using cached setuptools-70.0.0-py3-none-any.whl.metadata (5.9 kB)
  Collecting wheel
    Using cached wheel-0.43.0-py3-none-any.whl.metadata (2.2 kB)
  Using cached setuptools-70.0.0-py3-none-any.whl (863 kB)
  Using cached wheel-0.43.0-py3-none-any.whl (65 kB)
  Installing collected packages: wheel, setuptools
  Successfully installed setuptools-70.0.0 wheel-0.43.0
  Installing build dependencies ... done
  Running command Getting requirements to build wheel
  running egg_info
  writing test_package.egg-info/PKG-INFO
  writing dependency_links to test_package.egg-info/dependency_links.txt
  writing top-level names to test_package.egg-info/top_level.txt
  reading manifest file 'test_package.egg-info/SOURCES.txt'
  writing manifest file 'test_package.egg-info/SOURCES.txt'
  This is a message from setup.py
  Getting requirements to build wheel ... done
  Running command Preparing metadata (pyproject.toml)
  running dist_info
  creating /private/var/folders/y1/j465wvf92vs938kmgqh63bj80000gn/T/pip-modern-metadata-b2khfe1f/test_package.egg-info
  writing /private/var/folders/y1/j465wvf92vs938kmgqh63bj80000gn/T/pip-modern-metadata-b2khfe1f/test_package.egg-info/PKG-INFO
  writing dependency_links to /private/var/folders/y1/j465wvf92vs938kmgqh63bj80000gn/T/pip-modern-metadata-b2khfe1f/test_package.egg-info/dependency_links.txt
  writing top-level names to /private/var/folders/y1/j465wvf92vs938kmgqh63bj80000gn/T/pip-modern-metadata-b2khfe1f/test_package.egg-info/top_level.txt
  writing manifest file '/private/var/folders/y1/j465wvf92vs938kmgqh63bj80000gn/T/pip-modern-metadata-b2khfe1f/test_package.egg-info/SOURCES.txt'
  reading manifest file '/private/var/folders/y1/j465wvf92vs938kmgqh63bj80000gn/T/pip-modern-metadata-b2khfe1f/test_package.egg-info/SOURCES.txt'
  writing manifest file '/private/var/folders/y1/j465wvf92vs938kmgqh63bj80000gn/T/pip-modern-metadata-b2khfe1f/test_package.egg-info/SOURCES.txt'
  creating '/private/var/folders/y1/j465wvf92vs938kmgqh63bj80000gn/T/pip-modern-metadata-b2khfe1f/test_package-0.0.1.dist-info'
  This is a message from setup.py
  Preparing metadata (pyproject.toml) ... done
Would install test-package-0.0.1

As you can see, output in stderr does show up (and I separately checked, it’s in stderr). That’s also to be expected since pip’s presenting the subprocess stderr basically the same way as stdout (when invoking the backend).

github.com

pypa/pip/blob/24.0/src/pip/_internal/utils/subprocess.py#L146


      
          if extra_environ:
              env.update(extra_environ)
          for name in unset_environ:
              env.pop(name, None)
          try:
              proc = subprocess.Popen(
                  # Convert HiddenText objects to the underlying str.
                  reveal_command_args(cmd),
                  stdin=subprocess.PIPE,
                  stdout=subprocess.PIPE,
                  stderr=subprocess.STDOUT if not stdout_only else subprocess.PIPE,
                  cwd=cwd,
                  env=env,
                  errors="backslashreplace",
              )
          except Exception as exc:
              if log_failed_cmd:
                  subprocess_logger.critical(
                      "Error %s while executing command %s",
                      exc,
                      command_desc,

You should be able to verify that pip isn’t implicated in this by doing a pip install build and python -m build --no-isolation ., which should provide you with ~basically the same build output (albeit, by building the wheel from the sdist so maybe you’ll want to pass --wheel to that command if this difference matters to you).

A hack like this should not be necessary. Unless something is drastically wrong about my understanding of how pip and setuptools works ^[1], nothing is suppressing stderr in this situation. Having a wrapper script around gcc/clang/cc isn’t going to help much here unless something else in the stack is supressing stderr.

Which I think is highly unlikely in this case. ↩︎

mcepl · June 14, 2024, 8:57pm

Pradyun Gedam:

From the logs of the build:
INFO:copy_file:copying build/lib.linux-x86_64-cpython-312/M2Crypto/ftpslib.py -> build/bdist.linux-x86_64/wheel/M2Crypto
This is very much output from setuptools, so we’re definitely not suppressing this.

It is from setuptools, but not from subprocesses run from the Python. Notice that neither gcc nor swig’s output is shown.

It is --no-build-isolation and I have it already there.

When I have tried python3 -mbuild --no-isolation ., the results are the same: plenty of logging from the Python script itself, nothing from the subprocesses (swig and gcc).

pradyunsg · June 15, 2024, 7:26pm

What happens if you run without --no-build-isolation and use an definitely-not-patched copy of setuptools from PyPI?

mcepl · June 19, 2024, 10:26am

Of course, there is no difference. I have tried, and if you can tell me which patch in Tree - rpms/python-setuptools - src.fedoraproject.org could break output from subprocess?