[regression?] v0.46.2 seems to be crashing under Python 3.9

[webknjaz]

Here's the trace:

[ERROR]: Task failed: Module failed: stdout: Processing /tmp/ansible.4smzxd23.test/pip_module
  Preparing metadata (setup.py): started
  Preparing metadata (setup.py): finished with status 'done'
Building wheels for collected packages: ansible-test-pip-chdir
  Building wheel for ansible-test-pip-chdir (setup.py): started
  Building wheel for ansible-test-pip-chdir (setup.py): finished with status 'error'
  Running setup.py clean for ansible-test-pip-chdir
Failed to build ansible-test-pip-chdir
Installing collected packages: ansible-test-pip-chdir

:stderr:   ERROR: Command errored out with exit status 1:
   command: /usr/bin/python3.9 -u -c 'import io, os, sys, setuptools, tokenize; sys.argv[0] = '"'"'/tmp/ansible.4smzxd23.test/pip_module/setup.py'"'"'; __file__='"'"'/tmp/ansible.4smzxd23.test/pip_module/setup.py'"'"';f = getattr(tokenize, '"'"'open'"'"', open)(__file__) if os.path.exists(__file__) else io.StringIO('"'"'from setuptools import setup; setup()'"'"');code = f.read().replace('"'"'\r\n'"'"', '"'"'\n'"'"');f.close();exec(compile(code, __file__, '"'"'exec'"'"'))' bdist_wheel -d /tmp/pip-wheel-yfzrmvfg
       cwd: /tmp/ansible.4smzxd23.test/pip_module/
  Complete output (41 lines):
  /usr/local/lib/python3.9/site-packages/wheel/bdist_wheel.py:4: FutureWarning: The 'wheel' package is no longer the canonical location of the 'bdist_wheel' command, and will be removed in a future release. Please update to setuptools v70.1 or later which contains an integrated version of this command.
    warn(
  Traceback (most recent call last):
    File "/usr/local/lib/python3.9/site-packages/wheel/bdist_wheel.py", line 21, in <module>
      from setuptools.command.bdist_wheel import bdist_wheel
  ModuleNotFoundError: No module named 'setuptools.command.bdist_wheel'
  
  During handling of the above exception, another exception occurred:

  Traceback (most recent call last):
    File "/usr/local/lib/python3.9/site-packages/wheel/_bdist_wheel.py", line 40, in <module>
      __import__("setuptools.logging")
  ModuleNotFoundError: No module named 'setuptools.logging'
  
  During handling of the above exception, another exception occurred:

  Traceback (most recent call last):
    File "<string>", line 1, in <module>
    File "/tmp/ansible.4smzxd23.test/pip_module/setup.py", line 7, in <module>
      setup(
    File "/usr/lib/python3.9/site-packages/setuptools/__init__.py", line 153, in setup
      return distutils.core.setup(**attrs)
    File "/usr/lib64/python3.9/distutils/core.py", line 134, in setup
      ok = dist.parse_command_line()
    File "/usr/lib64/python3.9/distutils/dist.py", line 483, in parse_command_line
      args = self._parse_command_opts(parser, args)
    File "/usr/lib/python3.9/site-packages/setuptools/dist.py", line 951, in _parse_command_opts
      nargs = _Distribution._parse_command_opts(self, parser, args)
    File "/usr/lib64/python3.9/distutils/dist.py", line 539, in _parse_command_opts
      cmd_class = self.get_command_class(command)
    File "/usr/lib/python3.9/site-packages/setuptools/dist.py", line 790, in get_command_class
;31m      self.cmdclass[command] = cmdclass = ep.load()
    File "/usr/lib/python3.9/site-packages/pkg_resources/__init__.py", line 2450, in load
      return self.resolve()
    File "/usr/lib/python3.9/site-packages/pkg_resources/__init__.py", line 2456, in resolve
      module = __import__(self.module_name, fromlist=['__name__'], level=0)
    File "/usr/local/lib/python3.9/site-packages/wheel/bdist_wheel.py", line 26, in <module>
      from ._bdist_wheel import bdist_wheel as bdist_wheel
    File "/usr/local/lib/python3.9/site-packages/wheel/_bdist_wheel.py", line 43, in <module>
      from . import _setuptools_logging
  ImportError: cannot import name '_setuptools_logging' from 'wheel' (/usr/local/lib/python3.9/site-packages/wheel/__init__.py)
  ----------------------------------------
  ERROR: Failed building wheel for ansible-test-pip-chdir
ERROR: Exception:
Traceback (most recent call last):
  File "/usr/lib/python3.9/site-packages/pip/_internal/req/req_install.py", line 827, in install
    success = install_legacy(
  File "/usr/lib/python3.9/site-packages/pip/_internal/operations/install/legacy.py", line 114, in install
    raise LegacyInstallFailure from e
pip._internal.operations.install.legacy.LegacyInstallFailure

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.9/site-packages/pip/_internal/cli/base_command.py", line 164, in exc_logging_wrapper
    status = run_func(*args)
  File "/usr/lib/python3.9/site-packages/pip/_internal/cli/req_command.py", line 205, in wrapper
    return func(self, options, args)
  File "/usr/lib/python3.9/site-packages/pip/_internal/commands/install.py", line 404, in run
    installed = install_given_reqs(
  File "/usr/lib/python3.9/site-packages/pip/_internal/req/__init__.py", line 73, in install_given_reqs
    requirement.install(
  File "/usr/lib/python3.9/site-packages/pip/_internal/req/req_install.py", line 845, in install
    raise exc.__cause__
  File "/usr/lib/python3.9/site-packages/pip/_internal/operations/install/legacy.py", line 84, in install
    install_args = make_setuptools_install_args(
  File "/usr/lib/python3.9/site-packages/pip/_internal/utils/setuptools_build.py", line 137, in make_setuptools_install_args
    assert not (use_user_site and root)
AssertionError

(https://dev.azure.com/ansible/ansible/_build/results?buildId=169396&view=logs&j=8485562d-17b5-57e5-5147-a1d610660c89&t=378224a2-8b31-5b15-d1c1-b20ee426fb5b&l=15912)

Is this #662 again?

I'm yet to figure out specifics of the repro. I'll add more context as I learn it.

[agronholm]

Can you confirm that it's fixed in main now?

[webknjaz]

@agronholm I'll try once I figure out the repro — we have a custom test runner + some dynamically created test pkg layout. Though I think an almost-empty setup.py should do.. One thing that worries me is that the wheel path in the trace is in /usr/local/lib/python3.9/site-packages/wheel and not in a venv. So I originally thought it might've been yesterday's setuptools release. Yet to confirm the details.

[agronholm]

Well, there was a clear problem with wheel importing a non-existent module which I fixed in that commit.

[webknjaz]

@agronholm yeah, I'd expect that to improve things.

This seems to trigger the same trace:

$ python3.9 -Im venv some-venv-py39
$ some-venv-py39/bin/python -Im pip install wheel
$ some-venv-py39/bin/python -Im pip install --no-build-isolation test/integration/targets/pip/files/

Upgrading it to the new commit now triggers another error

$ some-venv-py39/bin/python -Im pip install git+https://github.com/pypa/wheel
Collecting git+https://github.com/pypa/wheel
  Cloning https://github.com/pypa/wheel to /tmp/pip-req-build-0nugqy4v
  Running command git clone --filter=blob:none --quiet https://github.com/pypa/wheel /tmp/pip-req-build-0nugqy4v
  Resolved https://github.com/pypa/wheel to commit 7445fb5bc13c91052021c40981fb0ec7172880bd
  Installing build dependencies ... done
  Getting requirements to build wheel ... done
  Preparing metadata (pyproject.toml) ... done
Requirement already satisfied: packaging>=24.0 in ./some-venv-py39/lib/python3.9/site-packages (from wheel==0.46.2) (26.0)

[notice] A new release of pip is available: 23.0.1 -> 25.3
[notice] To update, run: ~/src/github/ansible/ansible--devel/some-venv-py39/bin/python -m pip install --upgrade pip

$ some-venv-py39/bin/python -Im pip install --no-build-isolation test/integration/targets/pip/files/
Processing ./test/integration/targets/pip/files
  Preparing metadata (pyproject.toml) ... error
  error: subprocess-exited-with-error
  
  × Preparing metadata (pyproject.toml) did not run successfully.
  │ exit code: 1
  ╰─> [66 lines of output]
      running dist_info
      creating /tmp/pip-modern-metadata-311oc804/ansible_test_pip_chdir.egg-info
      writing /tmp/pip-modern-metadata-311oc804/ansible_test_pip_chdir.egg-info/PKG-INFO
      writing dependency_links to /tmp/pip-modern-metadata-311oc804/ansible_test_pip_chdir.egg-info/dependency_links.txt
      writing entry points to /tmp/pip-modern-metadata-311oc804/ansible_test_pip_chdir.egg-info/entry_points.txt
      writing top-level names to /tmp/pip-modern-metadata-311oc804/ansible_test_pip_chdir.egg-info/top_level.txt
      writing manifest file '/tmp/pip-modern-metadata-311oc804/ansible_test_pip_chdir.egg-info/SOURCES.txt'
      reading manifest file '/tmp/pip-modern-metadata-311oc804/ansible_test_pip_chdir.egg-info/SOURCES.txt'
      writing manifest file '/tmp/pip-modern-metadata-311oc804/ansible_test_pip_chdir.egg-info/SOURCES.txt'
      creating '/tmp/pip-modern-metadata-311oc804/ansible_test_pip_chdir.dist-info'
      ~/src/github/ansible/ansible--devel/some-venv-py39/lib/python3.9/site-packages/wheel/bdist_wheel.py:4: FutureWarning: The 'wheel' package is no longer the canonical location of the 'bdist_wheel' command, and will be removed in a future release. Please update to setuptools v70.1 or later which contains an integrated version of this command.
        warn(
      Traceback (most recent call last):
        File "~/src/github/ansible/ansible--devel/some-venv-py39/lib/python3.9/site-packages/wheel/bdist_wheel.py", line 21, in <module>
          from setuptools.command.bdist_wheel import bdist_wheel
      ModuleNotFoundError: No module named 'setuptools.command.bdist_wheel'
      
      During handling of the above exception, another exception occurred:
      
      Traceback (most recent call last):
        File "~/src/github/ansible/ansible--devel/some-venv-py39/lib/python3.9/site-packages/wheel/_bdist_wheel.py", line 40, in <module>
          __import__("setuptools.logging")
      ModuleNotFoundError: No module named 'setuptools.logging'
      
      During handling of the above exception, another exception occurred:
      
      Traceback (most recent call last):
        File "~/src/github/ansible/ansible--devel/some-venv-py39/lib/python3.9/site-packages/pip/_vendor/pyproject_hooks/_in_process/_in_process.py", line 353, in <module>
          main()
        File "~/src/github/ansible/ansible--devel/some-venv-py39/lib/python3.9/site-packages/pip/_vendor/pyproject_hooks/_in_process/_in_process.py", line 335, in main
          json_out['return_val'] = hook(**hook_input['kwargs'])
        File "~/src/github/ansible/ansible--devel/some-venv-py39/lib/python3.9/site-packages/pip/_vendor/pyproject_hooks/_in_process/_in_process.py", line 149, in prepare_metadata_for_build_wheel
          return hook(metadata_directory, config_settings)
        File "~/src/github/ansible/ansible--devel/some-venv-py39/lib/python3.9/site-packages/setuptools/build_meta.py", line 166, in prepare_metadata_for_build_wheel
          self.run_setup()
        File "~/src/github/ansible/ansible--devel/some-venv-py39/lib/python3.9/site-packages/setuptools/build_meta.py", line 258, in run_setup
          super(_BuildMetaLegacyBackend,
        File "~/src/github/ansible/ansible--devel/some-venv-py39/lib/python3.9/site-packages/setuptools/build_meta.py", line 150, in run_setup
          exec(compile(code, __file__, 'exec'), locals())
        File "setup.py", line 7, in <module>
          setup(
        File "~/src/github/ansible/ansible--devel/some-venv-py39/lib/python3.9/site-packages/setuptools/__init__.py", line 153, in setup
          return distutils.core.setup(**attrs)
        File "~/.pyenv/versions/3.9.19/lib/python3.9/distutils/core.py", line 148, in setup
          dist.run_commands()
        File "~/.pyenv/versions/3.9.19/lib/python3.9/distutils/dist.py", line 966, in run_commands
          self.run_command(cmd)
        File "~/.pyenv/versions/3.9.19/lib/python3.9/distutils/dist.py", line 985, in run_command
          cmd_obj.run()
        File "~/src/github/ansible/ansible--devel/some-venv-py39/lib/python3.9/site-packages/setuptools/command/dist_info.py", line 35, in run
          bdist_wheel = self.get_finalized_command('bdist_wheel')
        File "~/.pyenv/versions/3.9.19/lib/python3.9/distutils/cmd.py", line 298, in get_finalized_command
          cmd_obj = self.distribution.get_command_obj(command, create)
        File "~/.pyenv/versions/3.9.19/lib/python3.9/distutils/dist.py", line 857, in get_command_obj
          klass = self.get_command_class(command)
        File "~/src/github/ansible/ansible--devel/some-venv-py39/lib/python3.9/site-packages/setuptools/dist.py", line 887, in get_command_class
          self.cmdclass[command] = cmdclass = ep.load()
        File "~/src/github/ansible/ansible--devel/some-venv-py39/lib/python3.9/site-packages/pkg_resources/__init__.py", line 2450, in load
          return self.resolve()
        File "~/src/github/ansible/ansible--devel/some-venv-py39/lib/python3.9/site-packages/pkg_resources/__init__.py", line 2456, in resolve
          module = __import__(self.module_name, fromlist=['__name__'], level=0)
        File "~/src/github/ansible/ansible--devel/some-venv-py39/lib/python3.9/site-packages/wheel/bdist_wheel.py", line 26, in <module>
          from ._bdist_wheel import bdist_wheel as bdist_wheel
        File "~/src/github/ansible/ansible--devel/some-venv-py39/lib/python3.9/site-packages/wheel/_bdist_wheel.py", line 43, in <module>
          from . import _setuptools_logging
      ImportError: cannot import name '_setuptools_logging' from 'wheel' (~/src/github/ansible/ansible--devel/some-venv-py39/lib/python3.9/site-packages/wheel/__init__.py)
      [end of output]
  
  note: This error originates from a subprocess, and is likely not a problem with pip.
error: metadata-generation-failed

× Encountered error while generating package metadata.
╰─> See above for output.

note: This is an issue with the package mentioned above, not pip.
hint: See above for details.

[notice] A new release of pip is available: 23.0.1 -> 25.3
[notice] To update, run: ~/src/github/ansible/ansible--devel/some-venv-py39/bin/python -m pip install --upgrade pip

$ some-venv-py39/bin/python -Im pip install setuptools                                               
Requirement already satisfied: setuptools in ./some-venv-py39/lib/python3.9/site-packages (58.1.0)

[notice] A new release of pip is available: 23.0.1 -> 25.3
[notice] To update, run: ~/src/github/ansible/ansible--devel/some-venv-py39/bin/python -m pip install --upgrade pip

Looks like the fix will only work when `setuptools is also upgraded:

$ some-venv-py39/bin/python -Im pip install setuptools -U
Requirement already satisfied: setuptools in ./some-venv-py39/lib/python3.9/site-packages (58.1.0)
Collecting setuptools
  Using cached setuptools-80.10.1-py3-none-any.whl (1.1 MB)
Installing collected packages: setuptools
  Attempting uninstall: setuptools
    Found existing installation: setuptools 58.1.0
    Uninstalling setuptools-58.1.0:
      Successfully uninstalled setuptools-58.1.0
Successfully installed setuptools-80.10.1

[notice] A new release of pip is available: 23.0.1 -> 25.3
[notice] To update, run: ~/src/github/ansible/ansible--devel/some-venv-py39/bin/python -m pip install --upgrade pip

$ some-venv-py39/bin/python -Im pip install --no-build-isolation test/integration/targets/pip/files/ 
Processing ./test/integration/targets/pip/files
  Preparing metadata (pyproject.toml) ... done
Building wheels for collected packages: ansible_test_pip_chdir
  Building wheel for ansible_test_pip_chdir (pyproject.toml) ... done
  Created wheel for ansible_test_pip_chdir: filename=ansible_test_pip_chdir-0-py3-none-any.whl size=1590 sha256=bbadc0fc80c889a443ae7bdf4bd724ff49ae8e92eaea533f81d0304e315209e2
  Stored in directory: /tmp/pip-ephem-wheel-cache-59cx1ofc/wheels/9d/cd/aa/80bd6d89ab5da2c380a41867c590ba1c83ee0a8680c76d26b8
Successfully built ansible_test_pip_chdir
Installing collected packages: ansible_test_pip_chdir
  Attempting uninstall: ansible_test_pip_chdir
    Found existing installation: ansible_test_pip_chdir 0
    Uninstalling ansible_test_pip_chdir-0:
      Successfully uninstalled ansible_test_pip_chdir-0
Successfully installed ansible_test_pip_chdir-0

[notice] A new release of pip is available: 23.0.1 -> 25.3
[notice] To update, run: ~/src/github/ansible/ansible--devel/some-venv-py39/bin/python -m pip install --upgrade pip

[agronholm]

That makes no sense. The error still says ImportError: cannot import name '_setuptools_logging' from 'wheel', claiming the module I added in the commit doesn't exist.

[agronholm]

Could setuptools's import hooks be messing with this somehow?

[webknjaz]

@agronholm rg setupt some-venv-py39/lib/python3.9/site-packages/wheel-0.46.2.dist-info/RECORD doesn't return anything — your newly added module isn't packaged. Perhaps you have you tell flit about it?

[agronholm]

I manually installed setuptools==58.1.0 and git+https://github.com/pypa/wheel in an empty Python 3.9 venv and imported wheel._bdist_wheel and wheel._setuptools_logging successfully. If the new module isn't packaged, how could that work?

[agronholm]

The RECORD in the venv after installation shows wheel/_setuptools_logging.py,sha256=-5KC-lne0ilOUWIDfOkqapUWGMFZhuKYDIavIZiB5kM,781, so it most definitely is there.

[agronholm]

I think you need to provide me reproducing instructions so I could investigate this further.

[webknjaz]

Urgh.. Looks like pip might've cached the released version of wheel and the one being installed from Git has the same version number. And so it might've skipped re-processing records.

You're right, it's packaged when I uninstall older wheel and then install from Git instead of installing one over the other:

$ some-venv-py39/bin/python -Im pip uninstall wheel
Found existing installation: wheel 0.46.2
Uninstalling wheel-0.46.2:
  Would remove:
    ~/src/github/ansible/ansible--devel/some-venv-py39/bin/wheel
    ~/src/github/ansible/ansible--devel/some-venv-py39/lib/python3.9/site-packages/wheel-0.46.2.dist-info/*
    ~/src/github/ansible/ansible--devel/some-venv-py39/lib/python3.9/site-packages/wheel/*
Proceed (Y/n)? y 
  Successfully uninstalled wheel-0.46.2

$ some-venv-py39/bin/python -Im pip install -U pip                                                   
Requirement already satisfied: pip in ./some-venv-py39/lib/python3.9/site-packages (23.0.1)
Collecting pip
  Downloading pip-25.3-py3-none-any.whl (1.8 MB)
     ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 23.5 MB/s eta 0:00:00
Installing collected packages: pip
  Attempting uninstall: pip
    Found existing installation: pip 23.0.1
    Uninstalling pip-23.0.1:
      Successfully uninstalled pip-23.0.1
Successfully installed pip-25.3

$ some-venv-py39/bin/python -Im pip install git+https://github.com/pypa/wheel
Collecting git+https://github.com/pypa/wheel
  Cloning https://github.com/pypa/wheel to /tmp/pip-req-build-_0zylgd0
  Running command git clone --filter=blob:none --quiet https://github.com/pypa/wheel /tmp/pip-req-build-_0zylgd0
  Resolved https://github.com/pypa/wheel to commit 7445fb5bc13c91052021c40981fb0ec7172880bd
  Installing build dependencies ... done
  Getting requirements to build wheel ... done
  Preparing metadata (pyproject.toml) ... done
Requirement already satisfied: packaging>=24.0 in ./some-venv-py39/lib/python3.9/site-packages (from wheel==0.46.2) (26.0)
Building wheels for collected packages: wheel
  Building wheel for wheel (pyproject.toml) ... done
  Created wheel for wheel: filename=wheel-0.46.2-py3-none-any.whl size=30558 sha256=1d41a62cefc0fbd290cc8c463e59e144e9b2d08758f788294db9c2dc8835a1a0
  Stored in directory: /tmp/pip-ephem-wheel-cache-l1mze80p/wheels/6e/90/5a/c485d47c5d4d7d63ee2459d9916d1da87dd68d1085c23b0974
Successfully built wheel
Installing collected packages: wheel
Successfully installed wheel-0.46.2

$ rg setupt some-venv-py39/lib/python3.9/site-packages/wheel-0.46.2.dist-info/RECORD
16:wheel/__pycache__/_setuptools_logging.cpython-39.pyc,,
33:wheel/_setuptools_logging.py,sha256=-5KC-lne0ilOUWIDfOkqapUWGMFZhuKYDIavIZiB5kM,781```

[agronholm]

Yeah, I figured that might be the case. Time to release a hotfix then?