Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

tox hangs on CTRL+C, with a zombie child process #3056

Closed
sk1p opened this issue Jul 6, 2023 · 3 comments · Fixed by #3057
Closed

tox hangs on CTRL+C, with a zombie child process #3056

sk1p opened this issue Jul 6, 2023 · 3 comments · Fixed by #3057

Comments

@sk1p
Copy link
Contributor

sk1p commented Jul 6, 2023

Issue

Pressing CTRL+C while tox is running a test command sometimes hangs. There is a zombie process running alongside the main tox process. This has been observed before, for example in #2712 or #2825 (comment)

Environment

  • OS: Linux, Debian sid
Output of pip list of the host Python, where tox is installed
Package       Version
------------- -------
cachetools    5.3.1
chardet       5.1.0
colorama      0.4.6
distlib       0.3.6
filelock      3.12.2
packaging     23.1
pip           23.1.2
platformdirs  3.8.0
pluggy        1.2.0
pyproject-api 1.5.2
setuptools    67.8.0
tomli         2.0.1
tox           4.6.3
virtualenv    20.23.1
wheel         0.38.4

Output of running tox

Output of tox -rvv
py: 104 W remove tox env folder /tmp/toxtest2/.tox/py [tox/tox_env/api.py:322]
.pkg: 121 W remove tox env folder /tmp/toxtest2/.tox/.pkg [tox/tox_env/api.py:322]
py: 141 I find interpreter for spec PythonSpec(path=/home/alex/miniconda3/envs/toxtest/bin/python) [virtualenv/discovery/builtin.py:58]
py: 141 I proposed PythonInfo(spec=CPython3.10.12.final.0-64, exe=/home/alex/miniconda3/envs/toxtest/bin/python, platform=linux, version='3.10.12 (main, Jul  5 2023, 18:54:27) [GCC 11.2.0]', encoding_fs_io=utf-8-utf-8) [virtualenv/discovery/builtin.py:65]
py: 141 D accepted PythonInfo(spec=CPython3.10.12.final.0-64, exe=/home/alex/miniconda3/envs/toxtest/bin/python, platform=linux, version='3.10.12 (main, Jul  5 2023, 18:54:27) [GCC 11.2.0]', encoding_fs_io=utf-8-utf-8) [virtualenv/discovery/builtin.py:67]
py: 141 D filesystem is case-sensitive [virtualenv/info.py:26]
py: 154 I create virtual environment via CPython3Posix(dest=/tmp/toxtest2/.tox/py, clear=False, no_vcs_ignore=False, global=False) [virtualenv/run/session.py:50]
py: 154 D create folder /tmp/toxtest2/.tox/py/bin [virtualenv/util/path/_sync.py:12]
py: 154 D create folder /tmp/toxtest2/.tox/py/lib/python3.10/site-packages [virtualenv/util/path/_sync.py:12]
py: 155 D write /tmp/toxtest2/.tox/py/pyvenv.cfg [virtualenv/create/pyenv_cfg.py:32]
py: 155 D 	home = /home/alex/miniconda3/envs/toxtest/bin [virtualenv/create/pyenv_cfg.py:36]
py: 155 D 	implementation = CPython [virtualenv/create/pyenv_cfg.py:36]
py: 155 D 	version_info = 3.10.12.final.0 [virtualenv/create/pyenv_cfg.py:36]
py: 155 D 	virtualenv = 20.23.1 [virtualenv/create/pyenv_cfg.py:36]
py: 155 D 	include-system-site-packages = false [virtualenv/create/pyenv_cfg.py:36]
py: 155 D 	base-prefix = /home/alex/miniconda3/envs/toxtest [virtualenv/create/pyenv_cfg.py:36]
py: 155 D 	base-exec-prefix = /home/alex/miniconda3/envs/toxtest [virtualenv/create/pyenv_cfg.py:36]
py: 155 D 	base-executable = /home/alex/miniconda3/envs/toxtest/bin/python [virtualenv/create/pyenv_cfg.py:36]
py: 155 D symlink /home/alex/miniconda3/envs/toxtest/bin/python to /tmp/toxtest2/.tox/py/bin/python [virtualenv/util/path/_sync.py:32]
py: 155 D create virtualenv import hook file /tmp/toxtest2/.tox/py/lib/python3.10/site-packages/_virtualenv.pth [virtualenv/create/via_global_ref/api.py:91]
py: 155 D create /tmp/toxtest2/.tox/py/lib/python3.10/site-packages/_virtualenv.py [virtualenv/create/via_global_ref/api.py:94]
py: 155 D ============================== target debug ============================== [virtualenv/run/session.py:52]
py: 155 D debug via /tmp/toxtest2/.tox/py/bin/python /home/alex/miniconda3/envs/toxtest/lib/python3.10/site-packages/virtualenv/create/debug.py [virtualenv/create/creator.py:200]
py: 155 D {
  "sys": {
    "executable": "/tmp/toxtest2/.tox/py/bin/python",
    "_base_executable": "/tmp/toxtest2/.tox/py/bin/python",
    "prefix": "/tmp/toxtest2/.tox/py",
    "base_prefix": "/home/alex/miniconda3/envs/toxtest",
    "real_prefix": null,
    "exec_prefix": "/tmp/toxtest2/.tox/py",
    "base_exec_prefix": "/home/alex/miniconda3/envs/toxtest",
    "path": [
      "/home/alex/miniconda3/envs/toxtest/lib/python310.zip",
      "/home/alex/miniconda3/envs/toxtest/lib/python3.10",
      "/home/alex/miniconda3/envs/toxtest/lib/python3.10/lib-dynload",
      "/tmp/toxtest2/.tox/py/lib/python3.10/site-packages"
    ],
    "meta_path": [
      "<class '_virtualenv._Finder'>",
      "<class '_frozen_importlib.BuiltinImporter'>",
      "<class '_frozen_importlib.FrozenImporter'>",
      "<class '_frozen_importlib_external.PathFinder'>"
    ],
    "fs_encoding": "utf-8",
    "io_encoding": "utf-8"
  },
  "version": "3.10.12 (main, Jul  5 2023, 18:54:27) [GCC 11.2.0]",
  "makefile_filename": "/home/alex/miniconda3/envs/toxtest/lib/python3.10/config-3.10-x86_64-linux-gnu/Makefile",
  "os": "<module 'os' from '/home/alex/miniconda3/envs/toxtest/lib/python3.10/os.py'>",
  "site": "<module 'site' from '/home/alex/miniconda3/envs/toxtest/lib/python3.10/site.py'>",
  "datetime": "<module 'datetime' from '/home/alex/miniconda3/envs/toxtest/lib/python3.10/datetime.py'>",
  "math": "<module 'math' from '/home/alex/miniconda3/envs/toxtest/lib/python3.10/lib-dynload/math.cpython-310-x86_64-linux-gnu.so'>",
  "json": "<module 'json' from '/home/alex/miniconda3/envs/toxtest/lib/python3.10/json/__init__.py'>"
} [virtualenv/run/session.py:53]
py: 169 I add seed packages via FromAppData(download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/home/alex/.local/share/virtualenv) [virtualenv/run/session.py:57]
py: 171 D got embed update of distribution %s from ('pip', PosixPath('/home/alex/.local/share/virtualenv/wheel/3.10/embed/3/pip.json')) [virtualenv/app_data/via_disk_folder.py:131]
py: 171 D got embed update of distribution %s from ('setuptools', PosixPath('/home/alex/.local/share/virtualenv/wheel/3.10/embed/3/setuptools.json')) [virtualenv/app_data/via_disk_folder.py:131]
py: 171 D got embed update of distribution %s from ('wheel', PosixPath('/home/alex/.local/share/virtualenv/wheel/3.10/embed/3/wheel.json')) [virtualenv/app_data/via_disk_folder.py:131]
py: 172 D using periodically updated wheel /home/alex/.local/share/virtualenv/wheel/house/setuptools-67.6.0-py3-none-any.whl [virtualenv/seed/wheels/periodic_update.py:49]
py: 172 D using periodically updated wheel /home/alex/.local/share/virtualenv/wheel/house/pip-23.0.1-py3-none-any.whl [virtualenv/seed/wheels/periodic_update.py:49]
py: 172 D install setuptools from wheel /home/alex/.local/share/virtualenv/wheel/house/setuptools-67.6.0-py3-none-any.whl via CopyPipInstall [virtualenv/seed/embed/via_app_data/via_app_data.py:49]
py: 173 D install wheel from wheel /home/alex/miniconda3/envs/toxtest/lib/python3.10/site-packages/virtualenv/seed/wheels/embed/wheel-0.40.0-py3-none-any.whl via CopyPipInstall [virtualenv/seed/embed/via_app_data/via_app_data.py:49]
py: 173 D install pip from wheel /home/alex/.local/share/virtualenv/wheel/house/pip-23.0.1-py3-none-any.whl via CopyPipInstall [virtualenv/seed/embed/via_app_data/via_app_data.py:49]
py: 174 D copy /home/alex/.local/share/virtualenv/wheel/3.10/image/1/CopyPipInstall/pip-23.0.1-py3-none-any/pip-23.0.1.virtualenv to /tmp/toxtest2/.tox/py/lib/python3.10/site-packages/pip-23.0.1.virtualenv [virtualenv/util/path/_sync.py:40]
py: 174 D copy /home/alex/.local/share/virtualenv/wheel/3.10/image/1/CopyPipInstall/wheel-0.40.0-py3-none-any/wheel-0.40.0.virtualenv to /tmp/toxtest2/.tox/py/lib/python3.10/site-packages/wheel-0.40.0.virtualenv [virtualenv/util/path/_sync.py:40]
py: 174 D copy /home/alex/.local/share/virtualenv/wheel/3.10/image/1/CopyPipInstall/setuptools-67.6.0-py3-none-any/setuptools-67.6.0.virtualenv to /tmp/toxtest2/.tox/py/lib/python3.10/site-packages/setuptools-67.6.0.virtualenv [virtualenv/util/path/_sync.py:40]
py: 174 D copy directory /home/alex/.local/share/virtualenv/wheel/3.10/image/1/CopyPipInstall/pip-23.0.1-py3-none-any/pip-23.0.1.dist-info to /tmp/toxtest2/.tox/py/lib/python3.10/site-packages/pip-23.0.1.dist-info [virtualenv/util/path/_sync.py:40]
py: 175 D copy directory /home/alex/.local/share/virtualenv/wheel/3.10/image/1/CopyPipInstall/setuptools-67.6.0-py3-none-any/pkg_resources to /tmp/toxtest2/.tox/py/lib/python3.10/site-packages/pkg_resources [virtualenv/util/path/_sync.py:40]
py: 175 D copy directory /home/alex/.local/share/virtualenv/wheel/3.10/image/1/CopyPipInstall/wheel-0.40.0-py3-none-any/wheel-0.40.0.dist-info to /tmp/toxtest2/.tox/py/lib/python3.10/site-packages/wheel-0.40.0.dist-info [virtualenv/util/path/_sync.py:40]
py: 176 D copy directory /home/alex/.local/share/virtualenv/wheel/3.10/image/1/CopyPipInstall/wheel-0.40.0-py3-none-any/wheel to /tmp/toxtest2/.tox/py/lib/python3.10/site-packages/wheel [virtualenv/util/path/_sync.py:40]
py: 177 D copy directory /home/alex/.local/share/virtualenv/wheel/3.10/image/1/CopyPipInstall/pip-23.0.1-py3-none-any/pip to /tmp/toxtest2/.tox/py/lib/python3.10/site-packages/pip [virtualenv/util/path/_sync.py:40]
py: 184 D generated console scripts wheel-3.10 wheel3.10 wheel wheel3 [virtualenv/seed/embed/via_app_data/pip_install/base.py:43]
py: 185 D copy /home/alex/.local/share/virtualenv/wheel/3.10/image/1/CopyPipInstall/setuptools-67.6.0-py3-none-any/distutils-precedence.pth to /tmp/toxtest2/.tox/py/lib/python3.10/site-packages/distutils-precedence.pth [virtualenv/util/path/_sync.py:40]
py: 186 D copy directory /home/alex/.local/share/virtualenv/wheel/3.10/image/1/CopyPipInstall/setuptools-67.6.0-py3-none-any/setuptools to /tmp/toxtest2/.tox/py/lib/python3.10/site-packages/setuptools [virtualenv/util/path/_sync.py:40]
py: 202 D copy directory /home/alex/.local/share/virtualenv/wheel/3.10/image/1/CopyPipInstall/setuptools-67.6.0-py3-none-any/setuptools-67.6.0.dist-info to /tmp/toxtest2/.tox/py/lib/python3.10/site-packages/setuptools-67.6.0.dist-info [virtualenv/util/path/_sync.py:40]
py: 203 D copy directory /home/alex/.local/share/virtualenv/wheel/3.10/image/1/CopyPipInstall/setuptools-67.6.0-py3-none-any/_distutils_hack to /tmp/toxtest2/.tox/py/lib/python3.10/site-packages/_distutils_hack [virtualenv/util/path/_sync.py:40]
py: 204 D generated console scripts  [virtualenv/seed/embed/via_app_data/pip_install/base.py:43]
py: 218 D generated console scripts pip pip3 pip-3.10 pip3.10 [virtualenv/seed/embed/via_app_data/pip_install/base.py:43]
py: 218 I add activators for Bash, CShell, Fish, Nushell, PowerShell, Python [virtualenv/run/session.py:63]
py: 219 D write /tmp/toxtest2/.tox/py/pyvenv.cfg [virtualenv/create/pyenv_cfg.py:32]
py: 219 D 	home = /home/alex/miniconda3/envs/toxtest/bin [virtualenv/create/pyenv_cfg.py:36]
py: 219 D 	implementation = CPython [virtualenv/create/pyenv_cfg.py:36]
py: 219 D 	version_info = 3.10.12.final.0 [virtualenv/create/pyenv_cfg.py:36]
py: 219 D 	virtualenv = 20.23.1 [virtualenv/create/pyenv_cfg.py:36]
py: 219 D 	include-system-site-packages = false [virtualenv/create/pyenv_cfg.py:36]
py: 219 D 	base-prefix = /home/alex/miniconda3/envs/toxtest [virtualenv/create/pyenv_cfg.py:36]
py: 219 D 	base-exec-prefix = /home/alex/miniconda3/envs/toxtest [virtualenv/create/pyenv_cfg.py:36]
py: 219 D 	base-executable = /home/alex/miniconda3/envs/toxtest/bin/python [virtualenv/create/pyenv_cfg.py:36]
.pkg: 221 I find interpreter for spec PythonSpec(path=/home/alex/miniconda3/envs/toxtest/bin/python) [virtualenv/discovery/builtin.py:58]
.pkg: 221 I proposed PythonInfo(spec=CPython3.10.12.final.0-64, exe=/home/alex/miniconda3/envs/toxtest/bin/python, platform=linux, version='3.10.12 (main, Jul  5 2023, 18:54:27) [GCC 11.2.0]', encoding_fs_io=utf-8-utf-8) [virtualenv/discovery/builtin.py:65]
.pkg: 221 D accepted PythonInfo(spec=CPython3.10.12.final.0-64, exe=/home/alex/miniconda3/envs/toxtest/bin/python, platform=linux, version='3.10.12 (main, Jul  5 2023, 18:54:27) [GCC 11.2.0]', encoding_fs_io=utf-8-utf-8) [virtualenv/discovery/builtin.py:67]
.pkg: 222 I create virtual environment via CPython3Posix(dest=/tmp/toxtest2/.tox/.pkg, clear=False, no_vcs_ignore=False, global=False) [virtualenv/run/session.py:50]
.pkg: 222 D create folder /tmp/toxtest2/.tox/.pkg/bin [virtualenv/util/path/_sync.py:12]
.pkg: 222 D create folder /tmp/toxtest2/.tox/.pkg/lib/python3.10/site-packages [virtualenv/util/path/_sync.py:12]
.pkg: 222 D write /tmp/toxtest2/.tox/.pkg/pyvenv.cfg [virtualenv/create/pyenv_cfg.py:32]
.pkg: 222 D 	home = /home/alex/miniconda3/envs/toxtest/bin [virtualenv/create/pyenv_cfg.py:36]
.pkg: 222 D 	implementation = CPython [virtualenv/create/pyenv_cfg.py:36]
.pkg: 222 D 	version_info = 3.10.12.final.0 [virtualenv/create/pyenv_cfg.py:36]
.pkg: 222 D 	virtualenv = 20.23.1 [virtualenv/create/pyenv_cfg.py:36]
.pkg: 222 D 	include-system-site-packages = false [virtualenv/create/pyenv_cfg.py:36]
.pkg: 222 D 	base-prefix = /home/alex/miniconda3/envs/toxtest [virtualenv/create/pyenv_cfg.py:36]
.pkg: 222 D 	base-exec-prefix = /home/alex/miniconda3/envs/toxtest [virtualenv/create/pyenv_cfg.py:36]
.pkg: 222 D 	base-executable = /home/alex/miniconda3/envs/toxtest/bin/python [virtualenv/create/pyenv_cfg.py:36]
.pkg: 223 D symlink /home/alex/miniconda3/envs/toxtest/bin/python to /tmp/toxtest2/.tox/.pkg/bin/python [virtualenv/util/path/_sync.py:32]
.pkg: 223 D create virtualenv import hook file /tmp/toxtest2/.tox/.pkg/lib/python3.10/site-packages/_virtualenv.pth [virtualenv/create/via_global_ref/api.py:91]
.pkg: 223 D create /tmp/toxtest2/.tox/.pkg/lib/python3.10/site-packages/_virtualenv.py [virtualenv/create/via_global_ref/api.py:94]
.pkg: 223 D ============================== target debug ============================== [virtualenv/run/session.py:52]
.pkg: 223 D debug via /tmp/toxtest2/.tox/.pkg/bin/python /home/alex/miniconda3/envs/toxtest/lib/python3.10/site-packages/virtualenv/create/debug.py [virtualenv/create/creator.py:200]
.pkg: 223 D {
  "sys": {
    "executable": "/tmp/toxtest2/.tox/.pkg/bin/python",
    "_base_executable": "/tmp/toxtest2/.tox/.pkg/bin/python",
    "prefix": "/tmp/toxtest2/.tox/.pkg",
    "base_prefix": "/home/alex/miniconda3/envs/toxtest",
    "real_prefix": null,
    "exec_prefix": "/tmp/toxtest2/.tox/.pkg",
    "base_exec_prefix": "/home/alex/miniconda3/envs/toxtest",
    "path": [
      "/home/alex/miniconda3/envs/toxtest/lib/python310.zip",
      "/home/alex/miniconda3/envs/toxtest/lib/python3.10",
      "/home/alex/miniconda3/envs/toxtest/lib/python3.10/lib-dynload",
      "/tmp/toxtest2/.tox/.pkg/lib/python3.10/site-packages"
    ],
    "meta_path": [
      "<class '_virtualenv._Finder'>",
      "<class '_frozen_importlib.BuiltinImporter'>",
      "<class '_frozen_importlib.FrozenImporter'>",
      "<class '_frozen_importlib_external.PathFinder'>"
    ],
    "fs_encoding": "utf-8",
    "io_encoding": "utf-8"
  },
  "version": "3.10.12 (main, Jul  5 2023, 18:54:27) [GCC 11.2.0]",
  "makefile_filename": "/home/alex/miniconda3/envs/toxtest/lib/python3.10/config-3.10-x86_64-linux-gnu/Makefile",
  "os": "<module 'os' from '/home/alex/miniconda3/envs/toxtest/lib/python3.10/os.py'>",
  "site": "<module 'site' from '/home/alex/miniconda3/envs/toxtest/lib/python3.10/site.py'>",
  "datetime": "<module 'datetime' from '/home/alex/miniconda3/envs/toxtest/lib/python3.10/datetime.py'>",
  "math": "<module 'math' from '/home/alex/miniconda3/envs/toxtest/lib/python3.10/lib-dynload/math.cpython-310-x86_64-linux-gnu.so'>",
  "json": "<module 'json' from '/home/alex/miniconda3/envs/toxtest/lib/python3.10/json/__init__.py'>"
} [virtualenv/run/session.py:53]
.pkg: 237 I add seed packages via FromAppData(download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/home/alex/.local/share/virtualenv) [virtualenv/run/session.py:57]
.pkg: 238 D got embed update of distribution %s from ('pip', PosixPath('/home/alex/.local/share/virtualenv/wheel/3.10/embed/3/pip.json')) [virtualenv/app_data/via_disk_folder.py:131]
.pkg: 238 D got embed update of distribution %s from ('setuptools', PosixPath('/home/alex/.local/share/virtualenv/wheel/3.10/embed/3/setuptools.json')) [virtualenv/app_data/via_disk_folder.py:131]
.pkg: 238 D using periodically updated wheel /home/alex/.local/share/virtualenv/wheel/house/pip-23.0.1-py3-none-any.whl [virtualenv/seed/wheels/periodic_update.py:49]
.pkg: 238 D got embed update of distribution %s from ('wheel', PosixPath('/home/alex/.local/share/virtualenv/wheel/3.10/embed/3/wheel.json')) [virtualenv/app_data/via_disk_folder.py:131]
.pkg: 238 D using periodically updated wheel /home/alex/.local/share/virtualenv/wheel/house/setuptools-67.6.0-py3-none-any.whl [virtualenv/seed/wheels/periodic_update.py:49]
.pkg: 239 D install pip from wheel /home/alex/.local/share/virtualenv/wheel/house/pip-23.0.1-py3-none-any.whl via CopyPipInstall [virtualenv/seed/embed/via_app_data/via_app_data.py:49]
.pkg: 239 D install wheel from wheel /home/alex/miniconda3/envs/toxtest/lib/python3.10/site-packages/virtualenv/seed/wheels/embed/wheel-0.40.0-py3-none-any.whl via CopyPipInstall [virtualenv/seed/embed/via_app_data/via_app_data.py:49]
.pkg: 239 D install setuptools from wheel /home/alex/.local/share/virtualenv/wheel/house/setuptools-67.6.0-py3-none-any.whl via CopyPipInstall [virtualenv/seed/embed/via_app_data/via_app_data.py:49]
.pkg: 240 D copy /home/alex/.local/share/virtualenv/wheel/3.10/image/1/CopyPipInstall/pip-23.0.1-py3-none-any/pip-23.0.1.virtualenv to /tmp/toxtest2/.tox/.pkg/lib/python3.10/site-packages/pip-23.0.1.virtualenv [virtualenv/util/path/_sync.py:40]
.pkg: 240 D copy /home/alex/.local/share/virtualenv/wheel/3.10/image/1/CopyPipInstall/wheel-0.40.0-py3-none-any/wheel-0.40.0.virtualenv to /tmp/toxtest2/.tox/.pkg/lib/python3.10/site-packages/wheel-0.40.0.virtualenv [virtualenv/util/path/_sync.py:40]
.pkg: 240 D copy directory /home/alex/.local/share/virtualenv/wheel/3.10/image/1/CopyPipInstall/pip-23.0.1-py3-none-any/pip-23.0.1.dist-info to /tmp/toxtest2/.tox/.pkg/lib/python3.10/site-packages/pip-23.0.1.dist-info [virtualenv/util/path/_sync.py:40]
.pkg: 241 D copy directory /home/alex/.local/share/virtualenv/wheel/3.10/image/1/CopyPipInstall/wheel-0.40.0-py3-none-any/wheel-0.40.0.dist-info to /tmp/toxtest2/.tox/.pkg/lib/python3.10/site-packages/wheel-0.40.0.dist-info [virtualenv/util/path/_sync.py:40]
.pkg: 241 D copy /home/alex/.local/share/virtualenv/wheel/3.10/image/1/CopyPipInstall/setuptools-67.6.0-py3-none-any/setuptools-67.6.0.virtualenv to /tmp/toxtest2/.tox/.pkg/lib/python3.10/site-packages/setuptools-67.6.0.virtualenv [virtualenv/util/path/_sync.py:40]
.pkg: 241 D copy directory /home/alex/.local/share/virtualenv/wheel/3.10/image/1/CopyPipInstall/setuptools-67.6.0-py3-none-any/pkg_resources to /tmp/toxtest2/.tox/.pkg/lib/python3.10/site-packages/pkg_resources [virtualenv/util/path/_sync.py:40]
.pkg: 242 D copy directory /home/alex/.local/share/virtualenv/wheel/3.10/image/1/CopyPipInstall/wheel-0.40.0-py3-none-any/wheel to /tmp/toxtest2/.tox/.pkg/lib/python3.10/site-packages/wheel [virtualenv/util/path/_sync.py:40]
.pkg: 243 D copy directory /home/alex/.local/share/virtualenv/wheel/3.10/image/1/CopyPipInstall/pip-23.0.1-py3-none-any/pip to /tmp/toxtest2/.tox/.pkg/lib/python3.10/site-packages/pip [virtualenv/util/path/_sync.py:40]
.pkg: 250 D generated console scripts wheel3 wheel3.10 wheel-3.10 wheel [virtualenv/seed/embed/via_app_data/pip_install/base.py:43]
.pkg: 251 D copy /home/alex/.local/share/virtualenv/wheel/3.10/image/1/CopyPipInstall/setuptools-67.6.0-py3-none-any/distutils-precedence.pth to /tmp/toxtest2/.tox/.pkg/lib/python3.10/site-packages/distutils-precedence.pth [virtualenv/util/path/_sync.py:40]
.pkg: 251 D copy directory /home/alex/.local/share/virtualenv/wheel/3.10/image/1/CopyPipInstall/setuptools-67.6.0-py3-none-any/setuptools to /tmp/toxtest2/.tox/.pkg/lib/python3.10/site-packages/setuptools [virtualenv/util/path/_sync.py:40]
.pkg: 268 D copy directory /home/alex/.local/share/virtualenv/wheel/3.10/image/1/CopyPipInstall/setuptools-67.6.0-py3-none-any/setuptools-67.6.0.dist-info to /tmp/toxtest2/.tox/.pkg/lib/python3.10/site-packages/setuptools-67.6.0.dist-info [virtualenv/util/path/_sync.py:40]
.pkg: 269 D copy directory /home/alex/.local/share/virtualenv/wheel/3.10/image/1/CopyPipInstall/setuptools-67.6.0-py3-none-any/_distutils_hack to /tmp/toxtest2/.tox/.pkg/lib/python3.10/site-packages/_distutils_hack [virtualenv/util/path/_sync.py:40]
.pkg: 270 D generated console scripts  [virtualenv/seed/embed/via_app_data/pip_install/base.py:43]
.pkg: 284 D generated console scripts pip pip3 pip-3.10 pip3.10 [virtualenv/seed/embed/via_app_data/pip_install/base.py:43]
.pkg: 284 I add activators for Bash, CShell, Fish, Nushell, PowerShell, Python [virtualenv/run/session.py:63]
.pkg: 285 D write /tmp/toxtest2/.tox/.pkg/pyvenv.cfg [virtualenv/create/pyenv_cfg.py:32]
.pkg: 285 D 	home = /home/alex/miniconda3/envs/toxtest/bin [virtualenv/create/pyenv_cfg.py:36]
.pkg: 285 D 	implementation = CPython [virtualenv/create/pyenv_cfg.py:36]
.pkg: 285 D 	version_info = 3.10.12.final.0 [virtualenv/create/pyenv_cfg.py:36]
.pkg: 285 D 	virtualenv = 20.23.1 [virtualenv/create/pyenv_cfg.py:36]
.pkg: 285 D 	include-system-site-packages = false [virtualenv/create/pyenv_cfg.py:36]
.pkg: 285 D 	base-prefix = /home/alex/miniconda3/envs/toxtest [virtualenv/create/pyenv_cfg.py:36]
.pkg: 285 D 	base-exec-prefix = /home/alex/miniconda3/envs/toxtest [virtualenv/create/pyenv_cfg.py:36]
.pkg: 286 D 	base-executable = /home/alex/miniconda3/envs/toxtest/bin/python [virtualenv/create/pyenv_cfg.py:36]
.pkg: 286 W install_requires> python -I -m pip install 'setuptools>=40.8.0' wheel [tox/tox_env/api.py:427]
Requirement already satisfied: setuptools>=40.8.0 in ./.tox/.pkg/lib/python3.10/site-packages (67.6.0)
Requirement already satisfied: wheel in ./.tox/.pkg/lib/python3.10/site-packages (0.40.0)
.pkg: 839 I exit 0 (0.55 seconds) /tmp/toxtest2> python -I -m pip install 'setuptools>=40.8.0' wheel pid=1025592 [tox/execute/api.py:279]
.pkg: 840 W _optional_hooks> python /home/alex/miniconda3/envs/toxtest/lib/python3.10/site-packages/pyproject_api/_backend.py True setuptools.build_meta __legacy__ [tox/tox_env/api.py:427]
Backend: run command _optional_hooks with args {}
Backend: Wrote response {'return': {'get_requires_for_build_sdist': True, 'prepare_metadata_for_build_wheel': True, 'get_requires_for_build_wheel': True, 'build_editable': True, 'get_requires_for_build_editable': True, 'prepare_metadata_for_build_editable': True}} to /tmp/pep517__optional_hooks-q354bv0c.json
.pkg: 952 I exit None (0.11 seconds) /tmp/toxtest2> python /home/alex/miniconda3/envs/toxtest/lib/python3.10/site-packages/pyproject_api/_backend.py True setuptools.build_meta __legacy__ pid=1025616 [tox/execute/api.py:279]
.pkg: 953 W get_requires_for_build_sdist> python /home/alex/miniconda3/envs/toxtest/lib/python3.10/site-packages/pyproject_api/_backend.py True setuptools.build_meta __legacy__ [tox/tox_env/api.py:427]
Backend: run command get_requires_for_build_sdist with args {'config_settings': None}
running egg_info
writing UNKNOWN.egg-info/PKG-INFO
writing dependency_links to UNKNOWN.egg-info/dependency_links.txt
writing top-level names to UNKNOWN.egg-info/top_level.txt
reading manifest file 'UNKNOWN.egg-info/SOURCES.txt'
writing manifest file 'UNKNOWN.egg-info/SOURCES.txt'
Backend: Wrote response {'return': []} to /tmp/pep517_get_requires_for_build_sdist-rcbfgshf.json
.pkg: 969 I exit None (0.02 seconds) /tmp/toxtest2> python /home/alex/miniconda3/envs/toxtest/lib/python3.10/site-packages/pyproject_api/_backend.py True setuptools.build_meta __legacy__ pid=1025616 [tox/execute/api.py:279]
.pkg: 970 W get_requires_for_build_wheel> python /home/alex/miniconda3/envs/toxtest/lib/python3.10/site-packages/pyproject_api/_backend.py True setuptools.build_meta __legacy__ [tox/tox_env/api.py:427]
Backend: run command get_requires_for_build_wheel with args {'config_settings': None}
running egg_info
writing UNKNOWN.egg-info/PKG-INFO
writing dependency_links to UNKNOWN.egg-info/dependency_links.txt
writing top-level names to UNKNOWN.egg-info/top_level.txt
reading manifest file 'UNKNOWN.egg-info/SOURCES.txt'
writing manifest file 'UNKNOWN.egg-info/SOURCES.txt'
Backend: Wrote response {'return': ['wheel']} to /tmp/pep517_get_requires_for_build_wheel-heyqamnp.json
.pkg: 975 I exit None (0.01 seconds) /tmp/toxtest2> python /home/alex/miniconda3/envs/toxtest/lib/python3.10/site-packages/pyproject_api/_backend.py True setuptools.build_meta __legacy__ pid=1025616 [tox/execute/api.py:279]
.pkg: 976 W install_requires_for_build_wheel> python -I -m pip install wheel [tox/tox_env/api.py:427]
Requirement already satisfied: wheel in ./.tox/.pkg/lib/python3.10/site-packages (0.40.0)
.pkg: 1224 I exit 0 (0.25 seconds) /tmp/toxtest2> python -I -m pip install wheel pid=1025643 [tox/execute/api.py:279]
.pkg: 1224 W prepare_metadata_for_build_wheel> python /home/alex/miniconda3/envs/toxtest/lib/python3.10/site-packages/pyproject_api/_backend.py True setuptools.build_meta __legacy__ [tox/tox_env/api.py:427]
Backend: run command prepare_metadata_for_build_wheel with args {'metadata_directory': '/tmp/toxtest2/.tox/.pkg/.meta', 'config_settings': {'--build-option': []}}
running dist_info
creating /tmp/toxtest2/.tox/.pkg/.meta/UNKNOWN.egg-info
writing /tmp/toxtest2/.tox/.pkg/.meta/UNKNOWN.egg-info/PKG-INFO
writing dependency_links to /tmp/toxtest2/.tox/.pkg/.meta/UNKNOWN.egg-info/dependency_links.txt
writing top-level names to /tmp/toxtest2/.tox/.pkg/.meta/UNKNOWN.egg-info/top_level.txt
writing manifest file '/tmp/toxtest2/.tox/.pkg/.meta/UNKNOWN.egg-info/SOURCES.txt'
reading manifest file '/tmp/toxtest2/.tox/.pkg/.meta/UNKNOWN.egg-info/SOURCES.txt'
writing manifest file '/tmp/toxtest2/.tox/.pkg/.meta/UNKNOWN.egg-info/SOURCES.txt'
creating '/tmp/toxtest2/.tox/.pkg/.meta/UNKNOWN-0.0.0.dist-info'
Backend: Wrote response {'return': 'UNKNOWN-0.0.0.dist-info'} to /tmp/pep517_prepare_metadata_for_build_wheel-9imze6f1.json
.pkg: 1251 I exit None (0.03 seconds) /tmp/toxtest2> python /home/alex/miniconda3/envs/toxtest/lib/python3.10/site-packages/pyproject_api/_backend.py True setuptools.build_meta __legacy__ pid=1025616 [tox/execute/api.py:279]
.pkg: 1252 W build_sdist> python /home/alex/miniconda3/envs/toxtest/lib/python3.10/site-packages/pyproject_api/_backend.py True setuptools.build_meta __legacy__ [tox/tox_env/api.py:427]
Backend: run command build_sdist with args {'sdist_directory': '/tmp/toxtest2/.tox/.pkg/dist', 'config_settings': None}
running sdist
running egg_info
writing UNKNOWN.egg-info/PKG-INFO
writing dependency_links to UNKNOWN.egg-info/dependency_links.txt
writing top-level names to UNKNOWN.egg-info/top_level.txt
reading manifest file 'UNKNOWN.egg-info/SOURCES.txt'
writing manifest file 'UNKNOWN.egg-info/SOURCES.txt'
warning: sdist: standard file not found: should have one of README, README.rst, README.txt, README.md

running check
warning: check: missing required meta-data: name

creating UNKNOWN-0.0.0
creating UNKNOWN-0.0.0/UNKNOWN.egg-info
copying files to UNKNOWN-0.0.0...
copying setup.py -> UNKNOWN-0.0.0
copying UNKNOWN.egg-info/PKG-INFO -> UNKNOWN-0.0.0/UNKNOWN.egg-info
copying UNKNOWN.egg-info/SOURCES.txt -> UNKNOWN-0.0.0/UNKNOWN.egg-info
copying UNKNOWN.egg-info/dependency_links.txt -> UNKNOWN-0.0.0/UNKNOWN.egg-info
copying UNKNOWN.egg-info/top_level.txt -> UNKNOWN-0.0.0/UNKNOWN.egg-info
Writing UNKNOWN-0.0.0/setup.cfg
Creating tar archive
removing 'UNKNOWN-0.0.0' (and everything under it)
Backend: Wrote response {'return': 'UNKNOWN-0.0.0.tar.gz'} to /tmp/pep517_build_sdist-qzzrcf6r.json
.pkg: 1261 I exit None (0.01 seconds) /tmp/toxtest2> python /home/alex/miniconda3/envs/toxtest/lib/python3.10/site-packages/pyproject_api/_backend.py True setuptools.build_meta __legacy__ pid=1025616 [tox/execute/api.py:279]
.pkg: 1261 D package .tmp/package/34/UNKNOWN-0.0.0.tar.gz links to .pkg/dist/UNKNOWN-0.0.0.tar.gz (/tmp/toxtest2/.tox) [tox/util/file_view.py:39]
py: 1261 W install_package> python -I -m pip install --force-reinstall --no-deps /tmp/toxtest2/.tox/.tmp/package/34/UNKNOWN-0.0.0.tar.gz [tox/tox_env/api.py:427]
Processing ./.tox/.tmp/package/34/UNKNOWN-0.0.0.tar.gz
  Preparing metadata (setup.py) ... done
Building wheels for collected packages: UNKNOWN
  Building wheel for UNKNOWN (setup.py) ... done
  Created wheel for UNKNOWN: filename=UNKNOWN-0.0.0-py3-none-any.whl size=920 sha256=0cd67256ec534a86136e36fcc67f6b8a009fef15ef20784f82815da32b3149fb
  Stored in directory: /home/alex/.cache/pip/wheels/f3/28/8a/a1b88ff30500cde75b1898a6fbf6be60197a8cf7a7b71103a9
Successfully built UNKNOWN
Installing collected packages: UNKNOWN
Successfully installed UNKNOWN-0.0.0
py: 2070 I exit 0 (0.81 seconds) /tmp/toxtest2> python -I -m pip install --force-reinstall --no-deps /tmp/toxtest2/.tox/.tmp/package/34/UNKNOWN-0.0.0.tar.gz pid=1025704 [tox/execute/api.py:279]
py: 2071 W commands[0]> sleep 1000000 [tox/tox_env/api.py:427]
^CROOT: 3757 E [1025571] KeyboardInterrupt - teardown started [tox/session/cmd/run/common.py:249]
ROOT: 3757 W interrupt tox environment: py [tox/tox_env/api.py:398]
ROOT: 3757 W requested interrupt of 1025739 from 1025571, activate in 0.00 [tox/execute/local_sub_process/__init__.py:76]
ROOT: 3757 W send signal SIGINT(2) to 1025739 from 1025571 with timeout 0.30 [tox/execute/local_sub_process/__init__.py:81]
py: 3758 C exit -2 (1.69 seconds) /tmp/toxtest2> sleep 1000000 pid=1025739 [tox/execute/api.py:279]
.pkg: 3758 W _exit> python /home/alex/miniconda3/envs/toxtest/lib/python3.10/site-packages/pyproject_api/_backend.py True setuptools.build_meta __legacy__ [tox/tox_env/api.py:427]
ROOT: 3758 W interrupt finished with success [tox/execute/local_sub_process/__init__.py:92]
Traceback(s) acquired using py-spy dump -p $(pgrep tox) while tox is hanging:
Process 1025791: /home/alex/miniconda3/envs/toxtest/bin/python /home/alex/miniconda3/envs/toxtest/bin/tox
Python v3.10.12 (/home/alex/miniconda3/envs/toxtest/bin/python3.10)

Thread 1025791 (idle): "MainThread"
    _func (tox/tox_env/package.py:39)
    _call_pkg_envs (tox/tox_env/runner.py:117)
    interrupt (tox/tox_env/runner.py:89)
    execute (tox/session/cmd/run/common.py:256)
    run_sequential (tox/session/cmd/run/sequential.py:24)
    legacy (tox/session/cmd/legacy.py:115)
    main (tox/run.py:45)
    run (tox/run.py:19)
    <module> (tox:8)
Thread 1025792 (idle): "tox-interrupt"
    wait (threading.py:320)
    wait (threading.py:607)
    as_completed (concurrent/futures/_base.py:245)
    _queue_and_wait (tox/session/cmd/run/common.py:342)
    run (threading.py:953)
    _bootstrap_inner (threading.py:1016)
    _bootstrap (threading.py:973)
Thread 1025793 (idle): "Thread-1 (render)"
    wait (threading.py:324)
    wait (threading.py:607)
    render (tox/util/spinner.py:85)
    run (threading.py:953)
    _bootstrap_inner (threading.py:1016)
    _bootstrap (threading.py:973)
Thread 1025794 (idle): "tox-driver_0"
    _send (pyproject_api/_frontend.py:508)
    _send (tox/tox_env/python/virtual_env/package/pyproject.py:365)
    _teardown (tox/tox_env/python/virtual_env/package/pyproject.py:178)
    _func (tox/tox_env/package.py:45)
    teardown_env (tox/tox_env/package.py:101)
    _func (tox/tox_env/package.py:45)
    _call_pkg_envs (tox/tox_env/runner.py:118)
    _teardown (tox/tox_env/runner.py:85)
    teardown (tox/tox_env/api.py:263)
    _evaluate (tox/session/cmd/run/single.py:63)
    run_one (tox/session/cmd/run/single.py:35)
    _run (tox/session/cmd/run/common.py:318)
    run (concurrent/futures/thread.py:58)
    _worker (concurrent/futures/thread.py:83)
    run (threading.py:953)
    _bootstrap_inner (threading.py:1016)
    _bootstrap (threading.py:973)

Minimal example

tox.ini:

[testenv]
commands=
    sleep 1000000
allowlist_externals=
    sleep

setup.py

from setuptools import setup
setup()

Then, just run tox:

tox

When sleep is running, press CTRL+C. Sometimes this does exit, the output then contains the following:

ROOT: process already dead with -2 within 1026221

More analysis

The last thread, tox-driver_0, looks suspicious: it sits in a loop indefinitely.

_frontend.py:508 is in Frontend._send, and the loop is the following:

[...]
506    with self._send_msg(cmd, result_file, msg) as status:
507        while not status.done:  # pragma: no branch
508            sleep(0.001)  # wait a bit for things to happen         <------------------- 
[...]

status is, in this case, a ToxCmdStatus, and its done property looks like this:

@property
def done(self) -> bool:
    # 1. process died
    status = self._execute_status
    if status.exit_code is not None:  # pragma: no branch
        return True  # pragma: no cover
    # 2. the backend output reported back that our command is done
    return b"\n" in status.out.rpartition(b"Backend: Wrote response ")[0]

So, we are looking at the exit_code attribute of ToxCmdStatus._execute_status.
Going down further, _execute_status is an instance of LocalSubprocessExecuteStatus,
and its exit_code property implementation looks like this:

@property
def exit_code(self) -> int | None:
    return self._process.returncode

... where self._process is a Popen instance. Now, checking [the documentation of Popen.returncode, it states the following:

"The child return code. Initially None, returncode is set by a call to the
poll(), wait(), or communicate() methods if they detect that the process
has terminated."

As we don't wait, communicate or poll in the loop above, the returncode is not being set, if it wasn't already set before we entered the loop (or another thread calls wait or poll for us...).

Possible fix

If we modify LocalSubprocessExecuteStatus.exit_code to call Popen.poll, the hang does not happen anymore:

@property
def exit_code(self) -> int | None:
    self._process.poll()
    return self._process.returncode

Note: there is similar code in pyproject-api which might also need a fix.

@gaborbernat
Copy link
Member

Note: there is similar code in pyproject-api which might also need a fix.

Can you open a PR there too please? Thanks!

@sk1p
Copy link
Contributor Author

sk1p commented Jul 6, 2023

Can you open a PR there too please? Thanks!

Will do! Currently trying to understand how to reproduce the issue there...

@sk1p
Copy link
Contributor Author

sk1p commented Jul 6, 2023

Note: there is similar code in pyproject-api which might also need a fix.

Can you open a PR there too please? Thanks!

I missed that the SubprocessCmdStatus is running Popen.communicate in a background thread, which means the returncode is updated once the thread finishes running. So it seems no fix is needed there.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants