Tox hangs on waiting for pyproject_api backend if `--installpkg` is used

[vytas7]

Issue

Tox hangs when using certain PEP 517 backends such as pdm-backend together with the --installpkg option.
It is the option that, for instance, devpi-client opts to use for the devpi test command.

Interesting that it only happens if tox is run with at least two environments. Only one environment does not trigger the issue.

Environment

CPython 3.12 on Ubuntu/Debian Linux.
The issue is reproducible with the official python:3.12 Docker image (see below).

Output of running tox

The output is indistinguishable from the normal, expected output unless the --exit-and-dump-after option is used.

Minimal example

Consider the following self-contained example, let's assume it is saved under /tmp/test.sh:

#!/bin/bash

set -e
set -x

python -m venv /tmp/venv
source /tmp/venv/bin/activate
pip install -qU build pip tox

mkdir -p /tmp/skeleton/skeleton
cat << EOF > /tmp/skeleton/pyproject.toml
[build-system]
requires = ["pdm-backend"]
build-backend = "pdm.backend"

[project]
name = "skeleton"
description = "Just a skeleton for reproducing a tox issue."
version = "0.1.1337"
dependencies = [
    "requests",
]

[tool.pdm.build]
includes = [
    "skeleton/",
]
source-includes = [
    "tests/",
    "tox.ini",
]
EOF
cat << EOF > /tmp/skeleton/tox.ini
[tox]
envlist = dummy1,dummy2

[testenv:dummy1]
commands =
    python -c print(1)

[testenv:dummy2]
commands =
    python -c print(42)
EOF

pushd /tmp/skeleton
python -m build --sdist
popd
tox --installpkg /tmp/skeleton/dist/skeleton-0.1.1337.tar.gz -c /tmp/skeleton/tox.ini

Now, run this /tmp/test.sh inside the python:3.12 Docker image:

docker run --rm -it -v /tmp/test.sh:/tmp/test.sh python:3.12 /bin/bash /tmp/test.sh

[vytas7]

I am aware this might be a duplicate of #2844, however, the described symptoms don't seem to match exactly 🤔.

When Tox hangs as per the above description, there is an idle pyproject_api process along the below line:

vytas     571942  0.5  0.0  29500 24216 pts/0    S+   16:49   0:00 /tmp/skeleton/.tox/.pkg_external_sdist_meta/bin/python /tmp/venv/lib/python3.12/site-packages/pyproject_api/_backend.py True pdm.backend

If I kill or interrupt this PID, Tox finishes normally.

Output with --exit-and-dump-after 60:

Timeout (0:01:00)!
Thread 0x00007e18f4df16c0 (most recent call first):
  File "/tmp/venv/lib/python3.12/site-packages/tox/execute/local_sub_process/read_via_thread_unix.py", line 34 in _read_available
  File "/tmp/venv/lib/python3.12/site-packages/tox/execute/local_sub_process/read_via_thread_unix.py", line 23 in _read_stream
  File "/usr/local/lib/python3.12/threading.py", line 1012 in run
  File "/usr/local/lib/python3.12/threading.py", line 1075 in _bootstrap_inner
  File "/usr/local/lib/python3.12/threading.py", line 1032 in _bootstrap

Thread 0x00007e18dffff6c0 (most recent call first):
  File "/tmp/venv/lib/python3.12/site-packages/tox/execute/local_sub_process/read_via_thread_unix.py", line 34 in _read_available
  File "/tmp/venv/lib/python3.12/site-packages/tox/execute/local_sub_process/read_via_thread_unix.py", line 23 in _read_stream
  File "/usr/local/lib/python3.12/threading.py", line 1012 in run
  File "/usr/local/lib/python3.12/threading.py", line 1075 in _bootstrap_inner
  File "/usr/local/lib/python3.12/threading.py", line 1032 in _bootstrap

Thread 0x00007e18f86e0b80 (most recent call first):
  File "/usr/local/lib/python3.12/threading.py", line 1624 in _shutdown

[vytas7]

It is interesting that the issue is not reproducible with the now-EOL python:3.8 container, but affects 3.9+ and newer PyPy versions. Not sure if it just an older version of something that one gets on 3.8, or another difference.

[vytas7]

It would be nice for us to get this resolved somehow, although of course we can simply skip these Devpi tests...

I gave it an hour or two with my MRE, pdb, print(...) statements, and what not (😰), and to my understanding, it seems that the problem lies in unexpectedly resetting the frontend in Pep517VenvPackager:

• when using --installpkg as in my MRE, it seems that the Pep517VenvPackager.root property is set multiple times, with essentially the same path (extracted dir from my --installpkg tarball)
• resetting root recreates the frontend, however, with the new frontend comes a new frontend._backend_executor_, and the reference to the old one is lost
• when shutting down, Tox tries to shutdown the wrong (newest) backend executor, but it is not even started
• the initial executor, its process, and its tox-r-err-* & tox-r-out-* threads keep lingering

I could essentially work around the issue by this two liner:

--- a/src/tox/tox_env/python/virtual_env/package/pyproject.py
+++ b/src/tox/tox_env/python/virtual_env/package/pyproject.py
@@ -118,7 +118,11 @@ class Pep517VenvPackager(PythonPackageToxEnv, ABC):
 
     @root.setter
     def root(self, value: Path) -> None:
+        if value == self._root:
+            print(f'Pep517VenvPackager {id(self)}: not recreating frontend, same root!')
+            return
         self._root = value
+        print(f'Pep517VenvPackager {id(self)}: recreate frontend with new root {value!r}')
         self._frontend_ = None  # force recreating the frontend with new root

Does this change make sense? And what other ramifications are of recreating a frontend vs not recreating a frontend?
Thanks in advance for any ideas and help!
@gaborbernat @webknjaz ⬆

[webknjaz]

Wow, so that's what's been happening in some of my automations on Python 3.12+

(at least seems like it)

Although, in my case, I've been seeing something like this when installing from sdist but not wheel.

[webknjaz]

@vytas7 could you check your example with a whl instead of a tarball to confirm?

[webknjaz]

Also, check it all against Python 3.11

[webknjaz]

Also, add --notest. I think in my case, I'm doing that and envlist = python + TOXENV=python... There are several envs in tox.ini but I'm not invoking more than one at a time.

[vytas7]

@webknjaz I've already checked the attached example (from the description), and it is the same behaviour with all current versions. The now-EOL Python 3.8, however, passes (which we were using at work prior to recent upgrade).

Wheel should not be an issue, however, when it comes to our use case at work, devpi test essentially only operates from sdist (where you should ship tox.ini and other auxiliary files normally not distributed as part of wheels).

Edit: I have just tested roughly the same case usage --installpkg <some>.whl, and it passes just fine, yes.

Edit2: --notest still hangs (expected, because the issue is in the packaging "frontend"/"backend", not testing per se).

[webknjaz]

@vytas7 (on an unrelated note) you might be interested in my experimental workflow, then (that also integrates https://github.com/re-actors/checkout-python-sdist): https://github.com/ansible/awx-plugins/blob/21173c4/.github/workflows/ci-cd.yml#L454-L537.

[webknjaz]

Wheel should not be an issue, however

Right, because wheels don't need to go through the PEP 517 code path...

[vytas7]

@webknjaz For now, I'm thinking to simply upload Tox .post1 with my twoliner patch to our internal Devpi at work, I don't see why it should cause any problems.

I would submit a PR to Tox too, but tbh I don't even understand why Pep517VenvPackager.root can be changed at all (Tox is always testing the same package albeit with different environment, isn't it 🤔).

Dropping an old ._frontend_ without properly exiting ._frontend_._backend_executor_ sounds like a bug no matter what to me. But as said, I don't really understand this flow (the previous debugging session was the first time I ever peeked at Tox's src code), so not sure how a comprehensive fix in the general case could look like. Are you familiar with these internals?

[gaborbernat]

I would submit a PR to Tox too, but tbh I don't even understand why Pep517VenvPackager.root can be changed at all

This was done part of #3237 to address the respective issue.