Skip to content

Instantly share code, notes, and snippets.

@ogrisel

ogrisel/loky_failures_log.txt

Created February 24, 2023 09:25
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save ogrisel/371405ac68b5c7a977b907c843cdf798 to your computer and use it in GitHub Desktop.
Save ogrisel/371405ac68b5c7a977b907c843cdf798 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
loky_failures_log.txt
2023-02-24T08:51:55.0856095Z ##[section]Starting: Test loky
2023-02-24T08:51:55.0862853Z ==============================================================================
2023-02-24T08:51:55.0863227Z Task : Command line
2023-02-24T08:51:55.0863416Z Description : Run a command line script using Bash on Linux and macOS and cmd.exe on Windows
2023-02-24T08:51:55.0863830Z Version : 2.212.0
2023-02-24T08:51:55.0864023Z Author : Microsoft Corporation
2023-02-24T08:51:55.0864198Z Help : https://docs.microsoft.com/azure/devops/pipelines/tasks/utility/command-line
2023-02-24T08:51:55.0864458Z ==============================================================================
2023-02-24T08:51:55.2236683Z Generating script.
2023-02-24T08:51:55.2246660Z Script contents:
2023-02-24T08:51:55.2247205Z bash continuous_integration/runtests.sh
2023-02-24T08:51:55.2247701Z ========================== Starting Command Output ===========================
2023-02-24T08:51:55.2268626Z [command]/usr/bin/bash --noprofile --norc /home/vsts/work/_temp/bd9ce111-93f1-4aa6-9a42-3332814208a9.sh
2023-02-24T08:51:55.2341438Z /opt/hostedtoolcache/Python/3.9.16/x64/bin/python
2023-02-24T08:51:55.8131462Z Python 3.9.16
2023-02-24T08:51:55.8133782Z py39
2023-02-24T08:51:56.4753898Z 3.10: Pulling from library/python
2023-02-24T08:51:56.7537170Z 1e4aec178e08: Already exists
2023-02-24T08:51:56.7568187Z 6c1024729fee: Already exists
2023-02-24T08:51:56.7588690Z c3aa11fbc85a: Already exists
2023-02-24T08:51:56.7604927Z aa54add66b3a: Already exists
2023-02-24T08:51:56.7705576Z 9e3a60c2bce7: Already exists
2023-02-24T08:51:56.7768845Z 3b2123ce9d0d: Pulling fs layer
2023-02-24T08:51:56.7769432Z 663f76eb1ef6: Pulling fs layer
2023-02-24T08:51:56.7769894Z 13593c418669: Pulling fs layer
2023-02-24T08:51:56.7770590Z 0b33fd811e1d: Pulling fs layer
2023-02-24T08:51:56.7770997Z 0b33fd811e1d: Waiting
2023-02-24T08:51:57.0530957Z 13593c418669: Download complete
2023-02-24T08:51:57.1077521Z 3b2123ce9d0d: Verifying Checksum
2023-02-24T08:51:57.1078319Z 3b2123ce9d0d: Download complete
2023-02-24T08:51:57.1952210Z 663f76eb1ef6: Verifying Checksum
2023-02-24T08:51:57.1954476Z 663f76eb1ef6: Download complete
2023-02-24T08:51:57.3618490Z 0b33fd811e1d: Verifying Checksum
2023-02-24T08:51:57.3619128Z 0b33fd811e1d: Download complete
2023-02-24T08:51:58.1058712Z 3b2123ce9d0d: Pull complete
2023-02-24T08:51:58.8248377Z 663f76eb1ef6: Pull complete
2023-02-24T08:51:58.8790183Z 13593c418669: Pull complete
2023-02-24T08:51:59.1344560Z 0b33fd811e1d: Pull complete
2023-02-24T08:51:59.1401358Z Digest: sha256:0b21ab6fe705300678a84c3f4786ba056fa9af94790d8addf764c789b48987a2
2023-02-24T08:51:59.1418389Z Status: Downloaded newer image for python:3.10
2023-02-24T08:51:59.1432122Z docker.io/library/python:3.10
2023-02-24T08:51:59.7452368Z .pkg: find interpreter for spec PythonSpec(major=3, minor=9)
2023-02-24T08:51:59.7454500Z .pkg: proposed PythonInfo(spec=CPython3.9.16.final.0-64, exe=/opt/hostedtoolcache/Python/3.9.16/x64/bin/python, platform=linux, version='3.9.16 (main, Dec 8 2022, 11:00:20) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:51:59.7772275Z .pkg: find interpreter for spec PythonSpec(path=/opt/hostedtoolcache/Python/3.9.16/x64/bin/python)
2023-02-24T08:51:59.7774308Z .pkg: proposed PythonInfo(spec=CPython3.9.16.final.0-64, exe=/opt/hostedtoolcache/Python/3.9.16/x64/bin/python, platform=linux, version='3.9.16 (main, Dec 8 2022, 11:00:20) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:51:59.7819644Z .pkg: find interpreter for spec PythonSpec(major=3, minor=7)
2023-02-24T08:51:59.7821235Z .pkg: proposed PythonInfo(spec=CPython3.9.16.final.0-64, exe=/opt/hostedtoolcache/Python/3.9.16/x64/bin/python, platform=linux, version='3.9.16 (main, Dec 8 2022, 11:00:20) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:51:59.8475281Z .pkg: proposed PathPythonInfo(spec=CPython3.9.16.final.0-64, exe=/opt/hostedtoolcache/Python/3.9.16/x64/bin/python3, platform=linux, version='3.9.16 (main, Dec 8 2022, 11:00:20) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:51:59.9121369Z .pkg: proposed PathPythonInfo(spec=CPython3.9.16.final.0-64, exe=/opt/hostedtoolcache/Python/3.9.16/x64/python, platform=linux, version='3.9.16 (main, Dec 8 2022, 11:00:20) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:52:00.0759410Z .pkg: proposed PathPythonInfo(spec=CPython3.8.10.final.0-64, exe=/usr/bin/python3, platform=linux, version='3.8.10 (default, Nov 14 2022, 12:59:47) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:52:00.1328948Z .pkg: proposed PathPythonInfo(spec=CPython3.8.10.final.0-64, exe=/usr/bin/python, platform=linux, version='3.8.10 (default, Nov 14 2022, 12:59:47) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:52:00.1896077Z .pkg: proposed PathPythonInfo(spec=CPython3.8.10.final.0-64, exe=/bin/python3, platform=linux, version='3.8.10 (default, Nov 14 2022, 12:59:47) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:52:00.2463149Z .pkg: proposed PathPythonInfo(spec=CPython3.8.10.final.0-64, exe=/bin/python, platform=linux, version='3.8.10 (default, Nov 14 2022, 12:59:47) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:52:00.2518615Z .pkg: find interpreter for spec PythonSpec(major=3, minor=8)
2023-02-24T08:52:00.2519937Z .pkg: proposed PythonInfo(spec=CPython3.9.16.final.0-64, exe=/opt/hostedtoolcache/Python/3.9.16/x64/bin/python, platform=linux, version='3.9.16 (main, Dec 8 2022, 11:00:20) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:52:00.2525372Z .pkg: proposed PathPythonInfo(spec=CPython3.9.16.final.0-64, exe=/opt/hostedtoolcache/Python/3.9.16/x64/bin/python3, platform=linux, version='3.9.16 (main, Dec 8 2022, 11:00:20) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:52:00.2530412Z .pkg: proposed PathPythonInfo(spec=CPython3.9.16.final.0-64, exe=/opt/hostedtoolcache/Python/3.9.16/x64/python, platform=linux, version='3.9.16 (main, Dec 8 2022, 11:00:20) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:52:00.3110414Z .pkg: proposed PathPythonInfo(spec=CPython3.8.10.final.0-64, exe=/usr/bin/python3.8, platform=linux, version='3.8.10 (default, Nov 14 2022, 12:59:47) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:52:00.3186769Z .pkg: find interpreter for spec PythonSpec(major=3, minor=10)
2023-02-24T08:52:00.3188380Z .pkg: proposed PythonInfo(spec=CPython3.9.16.final.0-64, exe=/opt/hostedtoolcache/Python/3.9.16/x64/bin/python, platform=linux, version='3.9.16 (main, Dec 8 2022, 11:00:20) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:52:00.3193897Z .pkg: proposed PathPythonInfo(spec=CPython3.9.16.final.0-64, exe=/opt/hostedtoolcache/Python/3.9.16/x64/bin/python3, platform=linux, version='3.9.16 (main, Dec 8 2022, 11:00:20) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:52:00.3198741Z .pkg: proposed PathPythonInfo(spec=CPython3.9.16.final.0-64, exe=/opt/hostedtoolcache/Python/3.9.16/x64/python, platform=linux, version='3.9.16 (main, Dec 8 2022, 11:00:20) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:52:00.3206963Z .pkg: proposed PathPythonInfo(spec=CPython3.8.10.final.0-64, exe=/usr/bin/python3, platform=linux, version='3.8.10 (default, Nov 14 2022, 12:59:47) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:52:00.3208275Z .pkg: proposed PathPythonInfo(spec=CPython3.8.10.final.0-64, exe=/usr/bin/python, platform=linux, version='3.8.10 (default, Nov 14 2022, 12:59:47) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:52:00.3213623Z .pkg: proposed PathPythonInfo(spec=CPython3.8.10.final.0-64, exe=/bin/python3, platform=linux, version='3.8.10 (default, Nov 14 2022, 12:59:47) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:52:00.3217052Z .pkg: proposed PathPythonInfo(spec=CPython3.8.10.final.0-64, exe=/bin/python, platform=linux, version='3.8.10 (default, Nov 14 2022, 12:59:47) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:52:00.3258835Z .pkg: find interpreter for spec PythonSpec(implementation=pypy, major=3)
2023-02-24T08:52:00.3260187Z .pkg: proposed PythonInfo(spec=CPython3.9.16.final.0-64, exe=/opt/hostedtoolcache/Python/3.9.16/x64/bin/python, platform=linux, version='3.9.16 (main, Dec 8 2022, 11:00:20) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:52:00.3266250Z .pkg: proposed PathPythonInfo(spec=CPython3.9.16.final.0-64, exe=/opt/hostedtoolcache/Python/3.9.16/x64/bin/python3, platform=linux, version='3.9.16 (main, Dec 8 2022, 11:00:20) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:52:00.3271439Z .pkg: proposed PathPythonInfo(spec=CPython3.9.16.final.0-64, exe=/opt/hostedtoolcache/Python/3.9.16/x64/python, platform=linux, version='3.9.16 (main, Dec 8 2022, 11:00:20) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:52:00.3281742Z .pkg: proposed PathPythonInfo(spec=CPython3.8.10.final.0-64, exe=/usr/bin/python3, platform=linux, version='3.8.10 (default, Nov 14 2022, 12:59:47) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:52:00.3285197Z .pkg: proposed PathPythonInfo(spec=CPython3.8.10.final.0-64, exe=/usr/bin/python, platform=linux, version='3.8.10 (default, Nov 14 2022, 12:59:47) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:52:00.3290173Z .pkg: proposed PathPythonInfo(spec=CPython3.8.10.final.0-64, exe=/bin/python3, platform=linux, version='3.8.10 (default, Nov 14 2022, 12:59:47) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:52:00.3293896Z .pkg: proposed PathPythonInfo(spec=CPython3.8.10.final.0-64, exe=/bin/python, platform=linux, version='3.8.10 (default, Nov 14 2022, 12:59:47) \n[GCC 9.4.0]', encoding_fs_io=utf-8-utf-8)
2023-02-24T08:52:00.3318150Z py39: create virtual environment via CPython3Posix(dest=/home/vsts/work/1/s/.tox/py39, clear=False, no_vcs_ignore=False, global=False)
2023-02-24T08:52:00.3332801Z py39: add seed packages via FromAppData(download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/home/vsts/.local/share/virtualenv)
2023-02-24T08:52:00.5571363Z py39: add activators for Bash, CShell, Fish, Nushell, PowerShell, Python
2023-02-24T08:52:00.5583736Z py39: install_deps> python -I -m pip install coverage 'numpy; implementation_name == "cpython"' 'psutil; python_version != "3.8"' pytest pytest-timeout tblib 'viztracer; python_version >= "3.8" and python_version <= "3.10"'
2023-02-24T08:52:09.6012656Z py39: exit 0 (9.04 seconds) /home/vsts/work/1/s> python -I -m pip install coverage 'numpy; implementation_name == "cpython"' 'psutil; python_version != "3.8"' pytest pytest-timeout tblib 'viztracer; python_version >= "3.8" and python_version <= "3.10"' pid=1705
2023-02-24T08:52:09.6014585Z .pkg: create virtual environment via CPython3Posix(dest=/home/vsts/work/1/s/.tox/.pkg, clear=False, no_vcs_ignore=False, global=False)
2023-02-24T08:52:09.6016853Z .pkg: add seed packages via FromAppData(download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/home/vsts/.local/share/virtualenv)
2023-02-24T08:52:09.6876542Z .pkg: add activators for Bash, CShell, Fish, Nushell, PowerShell, Python
2023-02-24T08:52:09.6897266Z .pkg: install_requires> python -I -m pip install 'setuptools>=40.8.0' wheel
2023-02-24T08:52:10.9294627Z .pkg: exit 0 (1.24 seconds) /home/vsts/work/1/s> python -I -m pip install 'setuptools>=40.8.0' wheel pid=1733
2023-02-24T08:52:10.9302173Z .pkg: _optional_hooks> python /opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/site-packages/pyproject_api/_backend.py True setuptools.build_meta __legacy__
2023-02-24T08:52:11.3882558Z .pkg: exit None (0.46 seconds) /home/vsts/work/1/s> python /opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/site-packages/pyproject_api/_backend.py True setuptools.build_meta __legacy__ pid=1740
2023-02-24T08:52:11.3887818Z .pkg: get_requires_for_build_editable> python /opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/site-packages/pyproject_api/_backend.py True setuptools.build_meta __legacy__
2023-02-24T08:52:11.4510567Z .pkg: exit None (0.05 seconds) /home/vsts/work/1/s> python /opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/site-packages/pyproject_api/_backend.py True setuptools.build_meta __legacy__ pid=1740
2023-02-24T08:52:11.4512013Z .pkg: install_requires_for_build_editable> python -I -m pip install wheel
2023-02-24T08:52:12.0018315Z .pkg: exit 0 (0.55 seconds) /home/vsts/work/1/s> python -I -m pip install wheel pid=1743
2023-02-24T08:52:12.0029584Z .pkg: build_editable> python /opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/site-packages/pyproject_api/_backend.py True setuptools.build_meta __legacy__
2023-02-24T08:52:12.1859582Z .pkg: exit None (0.18 seconds) /home/vsts/work/1/s> python /opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/site-packages/pyproject_api/_backend.py True setuptools.build_meta __legacy__ pid=1740
2023-02-24T08:52:12.1897815Z py39: install_package_deps> python -I -m pip install cloudpickle
2023-02-24T08:52:12.9870737Z py39: exit 0 (0.80 seconds) /home/vsts/work/1/s> python -I -m pip install cloudpickle pid=1750
2023-02-24T08:52:12.9875409Z py39: install_package> python -I -m pip install --force-reinstall --no-deps /home/vsts/work/1/s/.tox/.tmp/package/1/loky-3.4.0.dev0-0.editable-py3-none-any.whl
2023-02-24T08:52:13.5572057Z py39: exit 0 (0.57 seconds) /home/vsts/work/1/s> python -I -m pip install --force-reinstall --no-deps /home/vsts/work/1/s/.tox/.tmp/package/1/loky-3.4.0.dev0-0.editable-py3-none-any.whl pid=1757
2023-02-24T08:52:13.5589757Z py39: commands[0]> python -c 'import struct; print('"'"'platform: %d'"'"' % (8 * struct.calcsize('"'"'P'"'"')))'
2023-02-24T08:52:13.5866040Z platform: 64
2023-02-24T08:52:13.5939585Z py39: exit 0 (0.03 seconds) /home/vsts/work/1/s> python -c 'import struct; print('"'"'platform: %d'"'"' % (8 * struct.calcsize('"'"'P'"'"')))' pid=1766
2023-02-24T08:52:13.5940599Z py39: commands[1]> python -c 'import loky; print('"'"'loky.cpu_count():'"'"', loky.cpu_count())'
2023-02-24T08:52:13.8147763Z loky.cpu_count(): 2
2023-02-24T08:52:13.8263290Z py39: exit 0 (0.23 seconds) /home/vsts/work/1/s> python -c 'import loky; print('"'"'loky.cpu_count():'"'"', loky.cpu_count())' pid=1772
2023-02-24T08:52:13.8267603Z py39: commands[2]> python -c 'import os; print('"'"'os.cpu_count():'"'"', os.cpu_count())'
2023-02-24T08:52:13.8538802Z os.cpu_count(): 2
2023-02-24T08:52:13.8598204Z py39: exit 0 (0.03 seconds) /home/vsts/work/1/s> python -c 'import os; print('"'"'os.cpu_count():'"'"', os.cpu_count())' pid=1778
2023-02-24T08:52:13.8599092Z py39: commands[3]> python continuous_integration/install_coverage_subprocess_pth.py
2023-02-24T08:52:14.1884468Z Installed subprocess coverage support: /home/vsts/work/1/s/.tox/py39/lib/python3.9/site-packages/coverage_subprocess.pth
2023-02-24T08:52:14.2069038Z py39: exit 0 (0.35 seconds) /home/vsts/work/1/s> python continuous_integration/install_coverage_subprocess_pth.py pid=1784
2023-02-24T08:52:14.2071644Z py39: commands[4]> py.test -vl --timeout=60 --maxfail=5 --junitxml=test-data.xml
2023-02-24T08:52:15.2137205Z ============================= test session starts ==============================
2023-02-24T08:52:15.2139018Z platform linux -- Python 3.9.16, pytest-7.2.1, pluggy-1.0.0 -- /home/vsts/work/1/s/.tox/py39/bin/python
2023-02-24T08:52:15.2139743Z cachedir: .tox/py39/.pytest_cache
2023-02-24T08:52:15.2140611Z rootdir: /home/vsts/work/1/s
2023-02-24T08:52:15.2141644Z plugins: timeout-2.1.0
2023-02-24T08:52:15.2141953Z timeout: 60.0s
2023-02-24T08:52:15.2142245Z timeout method: signal
2023-02-24T08:52:15.2142533Z timeout func_only: False
2023-02-24T08:52:16.0007990Z collecting ... collected 312 items
2023-02-24T08:52:16.0009155Z
2023-02-24T08:52:16.0267892Z tests/test_cloudpickle_wrapper.py::TestCloudpickleWrapper::test_isolated_pickler_dispatch_tables PASSED [ 0%]
2023-02-24T08:52:17.2405458Z tests/test_cloudpickle_wrapper.py::TestCloudpickleWrapper::test_serialization_function_from_main PASSED [ 0%]
2023-02-24T08:52:17.8091718Z tests/test_cloudpickle_wrapper.py::TestCloudpickleWrapper::test_serialization_class_from_main PASSED [ 0%]
2023-02-24T08:52:18.4856114Z tests/test_cloudpickle_wrapper.py::TestCloudpickleWrapper::test_cloudpickle_flag_wrapper PASSED [ 1%]
2023-02-24T08:52:19.0354379Z tests/test_cloudpickle_wrapper.py::TestCloudpickleWrapper::test_set_loky_pickler[None] PASSED [ 1%]
2023-02-24T08:52:19.6004785Z tests/test_cloudpickle_wrapper.py::TestCloudpickleWrapper::test_set_loky_pickler[''] PASSED [ 1%]
2023-02-24T08:52:20.1674885Z tests/test_cloudpickle_wrapper.py::TestCloudpickleWrapper::test_set_loky_pickler['cloudpickle'] PASSED [ 2%]
2023-02-24T08:52:20.6604043Z tests/test_cloudpickle_wrapper.py::TestCloudpickleWrapper::test_set_loky_pickler['pickle'] PASSED [ 2%]
2023-02-24T08:52:20.6638409Z tests/test_cloudpickle_wrapper.py::TestCloudpickleWrapper::test_set_loky_pickler_failures PASSED [ 2%]
2023-02-24T08:52:20.6657802Z tests/test_futures.py::TestsFuture::test_done_callback_with_result PASSED [ 3%]
2023-02-24T08:52:20.6673471Z tests/test_futures.py::TestsFuture::test_done_callback_with_exception PASSED [ 3%]
2023-02-24T08:52:20.6692498Z tests/test_futures.py::TestsFuture::test_done_callback_with_cancel PASSED [ 3%]
2023-02-24T08:52:20.6720752Z tests/test_futures.py::TestsFuture::test_done_callback_raises PASSED [ 4%]
2023-02-24T08:52:20.6737019Z tests/test_futures.py::TestsFuture::test_done_callback_already_successful PASSED [ 4%]
2023-02-24T08:52:20.6751898Z tests/test_futures.py::TestsFuture::test_done_callback_already_failed PASSED [ 4%]
2023-02-24T08:52:20.6767162Z tests/test_futures.py::TestsFuture::test_done_callback_already_cancelled PASSED [ 5%]
2023-02-24T08:52:20.6797452Z tests/test_futures.py::TestsFuture::test_repr PASSED [ 5%]
2023-02-24T08:52:20.6813583Z tests/test_futures.py::TestsFuture::test_cancel PASSED [ 5%]
2023-02-24T08:52:20.6828763Z tests/test_futures.py::TestsFuture::test_cancelled PASSED [ 6%]
2023-02-24T08:52:20.6844460Z tests/test_futures.py::TestsFuture::test_done PASSED [ 6%]
2023-02-24T08:52:20.6859909Z tests/test_futures.py::TestsFuture::test_running PASSED [ 6%]
2023-02-24T08:52:20.6876937Z tests/test_futures.py::TestsFuture::test_result_with_timeout PASSED [ 7%]
2023-02-24T08:52:20.7900241Z tests/test_futures.py::TestsFuture::test_result_with_success PASSED [ 7%]
2023-02-24T08:52:20.8925613Z tests/test_futures.py::TestsFuture::test_result_with_cancel PASSED [ 7%]
2023-02-24T08:52:20.8945473Z tests/test_futures.py::TestsFuture::test_exception_with_timeout PASSED [ 8%]
2023-02-24T08:52:20.9972688Z tests/test_futures.py::TestsFuture::test_exception_with_success PASSED [ 8%]
2023-02-24T08:52:20.9996887Z tests/test_loky_backend.py::TestLokyBackend::test_current PASSED [ 8%]
2023-02-24T08:52:21.0024340Z tests/test_loky_backend.py::TestLokyBackend::test_daemon_argument PASSED [ 8%]
2023-02-24T08:52:21.4532926Z tests/test_loky_backend.py::TestLokyBackend::test_process[loky] PASSED [ 9%]
2023-02-24T08:52:21.8155168Z tests/test_loky_backend.py::TestLokyBackend::test_process[loky_init_main] PASSED [ 9%]
2023-02-24T08:52:22.1791348Z tests/test_loky_backend.py::TestLokyBackend::test_socket PASSED [ 9%]
2023-02-24T08:52:22.5399957Z tests/test_loky_backend.py::TestLokyBackend::test_socket_queue PASSED [ 10%]
2023-02-24T08:52:22.8979852Z tests/test_loky_backend.py::TestLokyBackend::test_connection PASSED [ 10%]
2023-02-24T08:52:23.2599916Z tests/test_loky_backend.py::TestLokyBackend::test_connection_queue PASSED [ 10%]
2023-02-24T08:52:23.9746085Z tests/test_loky_backend.py::TestLokyBackend::test_child_env_process PASSED [ 11%]
2023-02-24T08:52:24.5363444Z tests/test_loky_backend.py::TestLokyBackend::test_terminate PASSED [ 11%]
2023-02-24T08:52:24.7997948Z tests/test_loky_backend.py::TestLokyBackend::test_active_children PASSED [ 11%]
2023-02-24T08:52:27.0567578Z tests/test_loky_backend.py::TestLokyBackend::test_recursion PASSED [ 12%]
2023-02-24T08:52:27.4191970Z tests/test_loky_backend.py::TestLokyBackend::test_sentinel PASSED [ 12%]
2023-02-24T08:52:27.8452723Z tests/test_loky_backend.py::TestLokyBackend::test_wait_sentinel PASSED [ 12%]
2023-02-24T08:52:28.3100798Z tests/test_loky_backend.py::TestLokyBackend::test_sync_object_handling PASSED [ 13%]
2023-02-24T08:52:28.3125901Z tests/test_loky_backend.py::TestLokyBackend::test_compatibility_openmp SKIPPED [ 13%]
2023-02-24T08:52:28.7107134Z tests/test_loky_backend.py::TestLokyBackend::test_interactively_define_process_no_main[True] PASSED [ 13%]
2023-02-24T08:52:29.1082237Z tests/test_loky_backend.py::TestLokyBackend::test_interactively_define_process_no_main[False] PASSED [ 14%]
2023-02-24T08:52:29.5088245Z tests/test_loky_backend.py::TestLokyBackend::test_interactively_define_process_fail_main PASSED [ 14%]
2023-02-24T08:52:29.5107607Z tests/test_loky_backend.py::TestLokyBackend::test_loky_get_context PASSED [ 14%]
2023-02-24T08:52:29.9084511Z tests/test_loky_backend.py::TestLokyBackend::test_interactive_contex_no_main PASSED [ 15%]
2023-02-24T08:52:31.5310269Z tests/test_loky_backend.py::test_kill_process_tree[True] PASSED [ 15%]
2023-02-24T08:52:33.1928455Z tests/test_loky_backend.py::test_kill_process_tree[False] PASSED [ 15%]
2023-02-24T08:52:33.9976353Z tests/test_loky_backend.py::test_default_subcontext[loky] PASSED [ 16%]
2023-02-24T08:52:34.8100895Z tests/test_loky_backend.py::test_default_subcontext[loky_init_main] PASSED [ 16%]
2023-02-24T08:52:36.3207668Z tests/test_loky_backend.py::test_default_subcontext[spawn] PASSED [ 16%]
2023-02-24T08:52:36.3209040Z tests/test_loky_backend.py::test_default_subcontext[fork] PASSED [ 16%]
2023-02-24T08:52:36.6377573Z tests/test_loky_backend.py::test_default_subcontext[forkserver] PASSED [ 17%]
2023-02-24T08:52:36.6397549Z tests/test_loky_module.py::test_version PASSED [ 17%]
2023-02-24T08:52:36.6905524Z tests/test_loky_module.py::test_cpu_count PASSED [ 17%]
2023-02-24T08:52:36.9907411Z tests/test_loky_module.py::test_cpu_count_os_sched_getaffinity PASSED [ 18%]
2023-02-24T08:52:36.9935991Z tests/test_loky_module.py::test_cpu_count_psutil_affinity PASSED [ 18%]
2023-02-24T08:52:55.1186527Z tests/test_loky_module.py::test_cpu_count_cgroup_limit PASSED [ 18%]
2023-02-24T08:52:55.1268860Z tests/test_loky_module.py::test_only_physical_cores_error PASSED [ 19%]
2023-02-24T08:52:55.1286010Z tests/test_loky_module.py::test_only_physical_cores_with_user_limitation PASSED [ 19%]
2023-02-24T08:52:55.7207888Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverShutdown::test_run_after_shutdown PASSED [ 19%]
2023-02-24T08:52:56.4939328Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverShutdown::test_shutdown_with_pickle_error PASSED [ 20%]
2023-02-24T08:52:57.2738271Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverShutdown::test_shutdown_with_sys_exit_at_pickle PASSED [ 20%]
2023-02-24T08:52:59.0521976Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverShutdown::test_interpreter_shutdown PASSED [ 20%]
2023-02-24T08:52:59.5687985Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverShutdown::test_hang_issue12364 PASSED [ 21%]
2023-02-24T08:53:00.1795638Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverShutdown::test_processes_terminate PASSED [ 21%]
2023-02-24T08:53:01.0914981Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverShutdown::test_processes_terminate_on_executor_gc PASSED [ 21%]
2023-02-24T08:53:03.7007939Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverShutdown::test_processes_crash_handling_after_executor_gc PASSED [ 22%]
2023-02-24T08:53:04.5364781Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverShutdown::test_context_manager_shutdown PASSED [ 22%]
2023-02-24T08:53:05.3663472Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverShutdown::test_del_shutdown PASSED [ 22%]
2023-02-24T08:53:06.0914055Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverShutdown::test_shutdown_no_wait PASSED [ 23%]
2023-02-24T08:53:06.6763166Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverShutdown::test_shutdown_deadlock_pickle PASSED [ 23%]
2023-02-24T08:53:08.9306159Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverShutdown::test_hang_issue39205 PASSED [ 23%]
2023-02-24T08:53:09.3504924Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverShutdown::test_shutdown_and_kill_workers PASSED [ 24%]
2023-02-24T08:53:11.2551215Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverWait::test_first_completed PASSED [ 24%]
2023-02-24T08:53:13.1547828Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverWait::test_first_completed_some_already_completed PASSED [ 24%]
2023-02-24T08:53:16.5911404Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverWait::test_first_exception PASSED [ 25%]
2023-02-24T08:53:18.5108837Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverWait::test_first_exception_some_already_complete PASSED [ 25%]
2023-02-24T08:53:20.9088620Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverWait::test_first_exception_one_already_failed PASSED [ 25%]
2023-02-24T08:53:22.3337668Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverWait::test_all_completed PASSED [ 25%]
2023-02-24T08:53:22.3339082Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverWait::test_timeout PASSED [ 26%]
2023-02-24T08:53:22.7577757Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverAsCompleted::test_no_timeout PASSED [ 26%]
2023-02-24T08:53:25.1570421Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverAsCompleted::test_zero_timeout PASSED [ 26%]
2023-02-24T08:53:25.6649496Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverAsCompleted::test_duplicate_futures PASSED [ 27%]
2023-02-24T08:53:26.0932130Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_submit PASSED [ 27%]
2023-02-24T08:53:26.5929560Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_submit_keyword PASSED [ 27%]
2023-02-24T08:53:27.0205619Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_map PASSED [ 28%]
2023-02-24T08:53:27.4563994Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_map_exception PASSED [ 28%]
2023-02-24T08:53:32.8460293Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_map_timeout PASSED [ 28%]
2023-02-24T08:53:33.2812416Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_shutdown_race_issue12456 PASSED [ 29%]
2023-02-24T08:53:33.7588384Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_no_stale_references PASSED [ 29%]
2023-02-24T08:53:34.1758869Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_max_workers_negative PASSED [ 29%]
2023-02-24T08:53:34.5919719Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_killed_child PASSED [ 30%]
2023-02-24T08:53:35.0212190Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_map_chunksize PASSED [ 30%]
2023-02-24T08:53:35.5399087Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_traceback PASSED [ 30%]
2023-02-24T08:53:36.2079897Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_thread_safety PASSED [ 31%]
2023-02-24T08:53:37.0244746Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_submit_from_callback PASSED [ 31%]
2023-02-24T08:53:39.2444385Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_worker_timeout PASSED [ 31%]
2023-02-24T08:53:40.2219002Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_serialization PASSED [ 32%]
2023-02-24T08:53:42.9623552Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_max_depth[True] PASSED [ 32%]
2023-02-24T08:53:45.7472640Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_max_depth[False] PASSED [ 32%]
2023-02-24T08:53:54.8724938Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_no_failure_on_large_data_send PASSED [ 33%]
2023-02-24T08:53:54.9154008Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_expected_failure_on_large_data_send SKIPPED [ 33%]
2023-02-24T08:53:56.9497552Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_memory_leak_protection PASSED [ 33%]
2023-02-24T08:53:58.0885076Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_reference_cycle_collection PASSED [ 33%]
2023-02-24T08:53:58.6646321Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_exited_child PASSED [ 34%]
2023-02-24T08:53:59.1002338Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_child_env_executor SKIPPED [ 34%]
2023-02-24T08:54:00.4678364Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_viztracer_profiler PASSED [ 34%]
2023-02-24T08:54:01.2237448Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_viztracer_profiler_with_custom_init PASSED [ 35%]
2023-02-24T08:54:01.9909284Z tests/test_process_executor_forkserver.py::TestsProcessPoolForkserverExecutor::test_exception_cause_with_tblib PASSED [ 35%]
2023-02-24T08:54:02.7784365Z tests/test_process_executor_loky.py::TestsProcessPoolLokyShutdown::test_run_after_shutdown PASSED [ 35%]
2023-02-24T08:54:03.9152428Z tests/test_process_executor_loky.py::TestsProcessPoolLokyShutdown::test_shutdown_with_pickle_error PASSED [ 36%]
2023-02-24T08:55:05.8227964Z tests/test_process_executor_loky.py::TestsProcessPoolLokyShutdown::test_shutdown_with_sys_exit_at_pickle FAILED [ 36%]
2023-02-24T08:55:05.8247547Z tests/test_process_executor_loky.py::TestsProcessPoolLokyShutdown::test_shutdown_with_sys_exit_at_pickle ERROR [ 36%]
2023-02-24T08:55:08.5291002Z tests/test_process_executor_loky.py::TestsProcessPoolLokyShutdown::test_interpreter_shutdown ERROR [ 36%]
2023-02-24T08:55:08.5306605Z tests/test_process_executor_loky.py::TestsProcessPoolLokyShutdown::test_interpreter_shutdown ERROR [ 36%]
2023-02-24T08:55:11.2051793Z tests/test_process_executor_loky.py::TestsProcessPoolLokyShutdown::test_hang_issue12364 ERROR [ 37%]
2023-02-24T08:55:11.2144755Z tests/test_process_executor_loky.py::TestsProcessPoolLokyShutdown::test_hang_issue12364 ERROR [ 37%]teardown class with <loky.backend.context.LokyContext object at 0x7fdb2de3bd60>
2023-02-24T08:55:11.2145657Z
2023-02-24T08:55:11.2152515Z
2023-02-24T08:55:11.2155574Z ==================================== ERRORS ====================================
2023-02-24T08:55:11.2158287Z _ ERROR at teardown of TestsProcessPoolLokyShutdown.test_shutdown_with_sys_exit_at_pickle _
2023-02-24T08:55:11.2158615Z
2023-02-24T08:55:11.2161462Z self = <tests.test_process_executor_loky.TestsProcessPoolLokyShutdown object at 0x7fdb27926eb0>
2023-02-24T08:55:11.2162158Z method = <bound method ExecutorShutdownTest.test_shutdown_with_sys_exit_at_pickle of <tests.test_process_executor_loky.TestsProcessPoolLokyShutdown object at 0x7fdb27926eb0>>
2023-02-24T08:55:11.2165543Z
2023-02-24T08:55:11.2165872Z def teardown_method(self, method):
2023-02-24T08:55:11.2168437Z # Make sure executor is not broken if it should not be
2023-02-24T08:55:11.2168842Z executor = getattr(self, "executor", None)
2023-02-24T08:55:11.2172576Z if executor is not None:
2023-02-24T08:55:11.2173025Z try:
2023-02-24T08:55:11.2173284Z # old pytest markers:
2023-02-24T08:55:11.2176205Z expect_broken_pool = hasattr(method, "broken_pool")
2023-02-24T08:55:11.2176803Z # new pytest markers:
2023-02-24T08:55:11.2177200Z for mark in getattr(method, "pytestmark", []):
2023-02-24T08:55:11.2177525Z if mark.name == "broken_pool":
2023-02-24T08:55:11.2193090Z expect_broken_pool = True
2023-02-24T08:55:11.2194109Z
2023-02-24T08:55:11.2194575Z if expect_broken_pool:
2023-02-24T08:55:11.2196022Z for _ in range(10):
2023-02-24T08:55:11.2196662Z # The executor manager thread can take some time to
2023-02-24T08:55:11.2197417Z # mark the executor broken.
2023-02-24T08:55:11.2201696Z is_actually_broken = executor._flags.broken is not None
2023-02-24T08:55:11.2202485Z if is_actually_broken:
2023-02-24T08:55:11.2204402Z break
2023-02-24T08:55:11.2204983Z sleep(0.1)
2023-02-24T08:55:11.2205399Z else:
2023-02-24T08:55:11.2205976Z raise AssertionError(
2023-02-24T08:55:11.2207767Z "The executor was not flagged broken at the end of "
2023-02-24T08:55:11.2211514Z f" {method.__qualname__} as expected."
2023-02-24T08:55:11.2211983Z )
2023-02-24T08:55:11.2212299Z else:
2023-02-24T08:55:11.2212686Z # Check that the executor is not broken right away to avoid
2023-02-24T08:55:11.2213617Z # wasting CI time. False negative should be very rare.
2023-02-24T08:55:11.2214106Z is_actually_broken = executor._flags.broken is not None
2023-02-24T08:55:11.2219183Z assert not is_actually_broken
2023-02-24T08:55:11.2219702Z finally:
2023-02-24T08:55:11.2220518Z # Always shutdown the executor, with SIGKILL if the executor
2023-02-24T08:55:11.2221290Z # is actually broken.
2023-02-24T08:55:11.2221792Z kill_workers = executor._flags.broken is not None
2023-02-24T08:55:11.2226700Z t_start = time.time()
2023-02-24T08:55:11.2228561Z executor.shutdown(wait=True, kill_workers=kill_workers)
2023-02-24T08:55:11.2298646Z dt = time.time() - t_start
2023-02-24T08:55:11.2299561Z assert dt < 10, "Executor took too long to shutdown"
2023-02-24T08:55:11.2301291Z > _check_subprocesses_number(executor, 0)
2023-02-24T08:55:11.2301763Z
2023-02-24T08:55:11.2302166Z dt = 0.00012826919555664062
2023-02-24T08:55:11.2305121Z executor = <loky.process_executor.ProcessPoolExecutor object at 0x7fdb24053730>
2023-02-24T08:55:11.2305837Z expect_broken_pool = False
2023-02-24T08:55:11.2306291Z is_actually_broken = False
2023-02-24T08:55:11.2310233Z kill_workers = False
2023-02-24T08:55:11.2310866Z method = <bound method ExecutorShutdownTest.test_shutdown_with_sys_exit_at_pickle of <tests.test_process_executor_loky.TestsProcessPoolLokyShutdown object at 0x7fdb27926eb0>>
2023-02-24T08:55:11.2311564Z self = <tests.test_process_executor_loky.TestsProcessPoolLokyShutdown object at 0x7fdb27926eb0>
2023-02-24T08:55:11.2316003Z t_start = 1677228904.8229644
2023-02-24T08:55:11.2316284Z
2023-02-24T08:55:11.2316609Z tests/_executor_mixin.py:223:
2023-02-24T08:55:11.2316990Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
2023-02-24T08:55:11.2317448Z tests/_executor_mixin.py:125: in _check_subprocesses_number
2023-02-24T08:55:11.2317799Z raise e
2023-02-24T08:55:11.2318251Z children_pids = {3302, 3303, 3304, 3305}
2023-02-24T08:55:11.2318676Z executor = <loky.process_executor.ProcessPoolExecutor object at 0x7fdb24053730>
2023-02-24T08:55:11.2322294Z expected_max_process_number = None
2023-02-24T08:55:11.2322654Z expected_process_number = 0
2023-02-24T08:55:11.2322925Z patience = 10
2023-02-24T08:55:11.2324149Z pids_cmdlines = [(3302, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-344 --pi... '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-347 --pipe 29')]
2023-02-24T08:55:11.2324843Z trial_idx = 9
2023-02-24T08:55:11.2325306Z worker_pids = set()
2023-02-24T08:55:11.2329159Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
2023-02-24T08:55:11.2329378Z
2023-02-24T08:55:11.2329745Z executor = <loky.process_executor.ProcessPoolExecutor object at 0x7fdb24053730>
2023-02-24T08:55:11.2330540Z expected_process_number = 0, expected_max_process_number = None, patience = 10
2023-02-24T08:55:11.2330905Z
2023-02-24T08:55:11.2331161Z def _check_subprocesses_number(
2023-02-24T08:55:11.2331564Z executor=None,
2023-02-24T08:55:11.2331841Z expected_process_number=None,
2023-02-24T08:55:11.2336153Z expected_max_process_number=None,
2023-02-24T08:55:11.2336510Z patience=10,
2023-02-24T08:55:11.2336797Z ):
2023-02-24T08:55:11.2337029Z if not psutil:
2023-02-24T08:55:11.2365446Z # psutil is not installed, we cannot check the number of subprocesses
2023-02-24T08:55:11.2369953Z return
2023-02-24T08:55:11.2370588Z
2023-02-24T08:55:11.2371142Z for trial_idx in range(patience):
2023-02-24T08:55:11.2371535Z try:
2023-02-24T08:55:11.2371993Z # Wait for terminating processes to disappear
2023-02-24T08:55:11.2372524Z pids_cmdlines = _running_children_pids_with_cmdline(
2023-02-24T08:55:11.2372976Z psutil.Process()
2023-02-24T08:55:11.2376534Z )
2023-02-24T08:55:11.2377084Z children_pids = {pid for pid, _ in pids_cmdlines}
2023-02-24T08:55:11.2377589Z if executor is not None:
2023-02-24T08:55:11.2378073Z worker_pids = set(executor._processes.keys())
2023-02-24T08:55:11.2378571Z # Consistency check: all workers should be in the children list
2023-02-24T08:55:11.2379114Z assert worker_pids.issubset(children_pids)
2023-02-24T08:55:11.2384262Z else:
2023-02-24T08:55:11.2384799Z # Bypass pids checks when executor has been garbage collected
2023-02-24T08:55:11.2385408Z worker_pids = children_pids
2023-02-24T08:55:11.2385849Z if expected_process_number is not None:
2023-02-24T08:55:11.2386307Z > assert (
2023-02-24T08:55:11.2386850Z len(children_pids) == expected_process_number
2023-02-24T08:55:11.2387287Z ), pids_cmdlines
2023-02-24T08:55:11.2391452Z E AssertionError: [(3302, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-344 --pipe 26'), (3303, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-345 --pipe 27'), (3304, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-346 --pipe 28'), (3305, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-347 --pipe 29')]
2023-02-24T08:55:11.2393100Z
2023-02-24T08:55:11.2398075Z children_pids = {3302, 3303, 3304, 3305}
2023-02-24T08:55:11.2398699Z executor = <loky.process_executor.ProcessPoolExecutor object at 0x7fdb24053730>
2023-02-24T08:55:11.2403911Z expected_max_process_number = None
2023-02-24T08:55:11.2408706Z expected_process_number = 0
2023-02-24T08:55:11.2409158Z patience = 10
2023-02-24T08:55:11.2410988Z pids_cmdlines = [(3302, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-344 --pi... '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-347 --pipe 29')]
2023-02-24T08:55:11.2438922Z trial_idx = 9
2023-02-24T08:55:11.2440267Z worker_pids = set()
2023-02-24T08:55:11.2440627Z
2023-02-24T08:55:11.2441009Z tests/_executor_mixin.py:103: AssertionError
2023-02-24T08:55:11.2496705Z ---------------------------- Captured stderr setup -----------------------------
2023-02-24T08:55:11.2499818Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579355418624 and name "None"
2023-02-24T08:55:11.2501645Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579351658496 and name "None"
2023-02-24T08:55:11.2502356Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235098624 and name "None"
2023-02-24T08:55:11.2505442Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235094528 and name "None"
2023-02-24T08:55:11.2509989Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235090432 and name "None"
2023-02-24T08:55:11.2511394Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235086336 and name "None"
2023-02-24T08:55:11.2515037Z [DEBUG:MainProcess:MainThread] ProcessPoolExecutor is setup
2023-02-24T08:55:11.2516048Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235057664 and name "None"
2023-02-24T08:55:11.2516743Z [DEBUG:MainProcess:MainThread] launched python with pid 3293 and cmd:
2023-02-24T08:55:11.2523002Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-339', '--pipe', '26']
2023-02-24T08:55:11.2525832Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235053568 and name "None"
2023-02-24T08:55:11.2526570Z [DEBUG:MainProcess:MainThread] launched python with pid 3294 and cmd:
2023-02-24T08:55:11.2531479Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-340', '--pipe', '27']
2023-02-24T08:55:11.2532696Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235049472 and name "None"
2023-02-24T08:55:11.2533343Z [DEBUG:MainProcess:MainThread] launched python with pid 3295 and cmd:
2023-02-24T08:55:11.2536240Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-341', '--pipe', '28']
2023-02-24T08:55:11.2537000Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235045376 and name "None"
2023-02-24T08:55:11.2537545Z [DEBUG:MainProcess:MainThread] launched python with pid 3296 and cmd:
2023-02-24T08:55:11.2542792Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-342', '--pipe', '29']
2023-02-24T08:55:11.2547894Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235041280 and name "None"
2023-02-24T08:55:11.2548600Z [DEBUG:MainProcess:MainThread] launched python with pid 3297 and cmd:
2023-02-24T08:55:11.2555606Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-343', '--pipe', '30']
2023-02-24T08:55:11.2557124Z [DEBUG:MainProcess:MainThread] Adjusted process count to 5: [('LokyProcess-339', 3293), ('LokyProcess-340', 3294), ('LokyProcess-341', 3295), ('LokyProcess-342', 3296), ('LokyProcess-343', 3297)]
2023-02-24T08:55:11.2560119Z [DEBUG:MainProcess:MainThread] _start_executor_manager_thread called
2023-02-24T08:55:11.2560829Z [DEBUG:MainProcess:ExecutorManagerThread] Queue._start_thread()
2023-02-24T08:55:11.2565405Z [DEBUG:MainProcess:ExecutorManagerThread] doing self._thread.start()
2023-02-24T08:55:11.2566145Z [DEBUG:MainProcess:QueueFeederThread] starting thread to feed data to pipe
2023-02-24T08:55:11.2566735Z [DEBUG:MainProcess:ExecutorManagerThread] ... done self._thread.start()
2023-02-24T08:55:11.2568041Z [DEBUG:LokyProcess-342:MainThread] recreated blocker with handle 140579351658496 and name "/loky-1790-oxk_xfy6"
2023-02-24T08:55:11.2569120Z [DEBUG:LokyProcess-342:MainThread] recreated blocker with handle 140579235098624 and name "/loky-1790-nfpv8xsl"
2023-02-24T08:55:11.2570027Z [DEBUG:LokyProcess-342:MainThread] recreated blocker with handle 140579235094528 and name "/loky-1790-1omtcbbz"
2023-02-24T08:55:11.2574139Z [DEBUG:LokyProcess-342:MainThread] recreated blocker with handle 140579235090432 and name "/loky-1790-eknrtpls"
2023-02-24T08:55:11.2575604Z [DEBUG:LokyProcess-342:MainThread] recreated blocker with handle 140579235086336 and name "/loky-1790-lt9d1m08"
2023-02-24T08:55:11.2576750Z [DEBUG:LokyProcess-340:MainThread] recreated blocker with handle 140579351658496 and name "/loky-1790-oxk_xfy6"
2023-02-24T08:55:11.2579804Z [DEBUG:LokyProcess-340:MainThread] recreated blocker with handle 140579235098624 and name "/loky-1790-nfpv8xsl"
2023-02-24T08:55:11.2581006Z [DEBUG:LokyProcess-340:MainThread] recreated blocker with handle 140579235094528 and name "/loky-1790-1omtcbbz"
2023-02-24T08:55:11.2581952Z [DEBUG:LokyProcess-340:MainThread] recreated blocker with handle 140579235090432 and name "/loky-1790-eknrtpls"
2023-02-24T08:55:11.2587185Z [DEBUG:LokyProcess-340:MainThread] recreated blocker with handle 140579235086336 and name "/loky-1790-lt9d1m08"
2023-02-24T08:55:11.2588253Z [DEBUG:LokyProcess-339:MainThread] recreated blocker with handle 140579351658496 and name "/loky-1790-oxk_xfy6"
2023-02-24T08:55:11.2589115Z [DEBUG:LokyProcess-339:MainThread] recreated blocker with handle 140579235098624 and name "/loky-1790-nfpv8xsl"
2023-02-24T08:55:11.2590006Z [DEBUG:LokyProcess-339:MainThread] recreated blocker with handle 140579235094528 and name "/loky-1790-1omtcbbz"
2023-02-24T08:55:11.2590906Z [DEBUG:LokyProcess-339:MainThread] recreated blocker with handle 140579235090432 and name "/loky-1790-eknrtpls"
2023-02-24T08:55:11.2591733Z [DEBUG:LokyProcess-339:MainThread] recreated blocker with handle 140579235086336 and name "/loky-1790-lt9d1m08"
2023-02-24T08:55:11.2595728Z [DEBUG:LokyProcess-341:MainThread] recreated blocker with handle 140579351658496 and name "/loky-1790-oxk_xfy6"
2023-02-24T08:55:11.2597084Z [DEBUG:LokyProcess-341:MainThread] recreated blocker with handle 140579235098624 and name "/loky-1790-nfpv8xsl"
2023-02-24T08:55:11.2598023Z [DEBUG:LokyProcess-341:MainThread] recreated blocker with handle 140579235094528 and name "/loky-1790-1omtcbbz"
2023-02-24T08:55:11.2599232Z [DEBUG:LokyProcess-341:MainThread] recreated blocker with handle 140579235090432 and name "/loky-1790-eknrtpls"
2023-02-24T08:55:11.2600230Z [DEBUG:LokyProcess-341:MainThread] recreated blocker with handle 140579235086336 and name "/loky-1790-lt9d1m08"
2023-02-24T08:55:11.2603357Z [DEBUG:LokyProcess-343:MainThread] recreated blocker with handle 140579351658496 and name "/loky-1790-oxk_xfy6"
2023-02-24T08:55:11.2604340Z [DEBUG:LokyProcess-343:MainThread] recreated blocker with handle 140579235098624 and name "/loky-1790-nfpv8xsl"
2023-02-24T08:55:11.2608783Z [DEBUG:LokyProcess-343:MainThread] recreated blocker with handle 140579235094528 and name "/loky-1790-1omtcbbz"
2023-02-24T08:55:11.2609965Z [DEBUG:LokyProcess-343:MainThread] recreated blocker with handle 140579235090432 and name "/loky-1790-eknrtpls"
2023-02-24T08:55:11.2611176Z [DEBUG:LokyProcess-343:MainThread] recreated blocker with handle 140579235086336 and name "/loky-1790-lt9d1m08"
2023-02-24T08:55:11.2614797Z [DEBUG:LokyProcess-342:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.2616243Z [DEBUG:LokyProcess-342:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.2617273Z [DEBUG:LokyProcess-342:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.2620880Z [DEBUG:LokyProcess-342:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.2622585Z [DEBUG:LokyProcess-342:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.2623622Z [DEBUG:LokyProcess-342:MainThread] recreated blocker with handle 140579355418624 and name "/loky-1790-38bnqfa3"
2023-02-24T08:55:11.2627799Z [DEBUG:LokyProcess-342:MainThread] recreated blocker with handle 140579235045376 and name "/loky-1790-w_6n1w74"
2023-02-24T08:55:11.2628855Z [INFO:LokyProcess-342:MainThread] child process calling self.run()
2023-02-24T08:55:11.2629592Z [DEBUG:LokyProcess-342:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.2632142Z ----------------------------- Captured stderr call -----------------------------
2023-02-24T08:55:11.2634579Z [DEBUG:MainProcess:MainThread] shutting down executor <loky.process_executor.ProcessPoolExecutor object at 0x7fdb24053730>
2023-02-24T08:55:11.2635455Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-339
2023-02-24T08:55:11.2639601Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-340
2023-02-24T08:55:11.2643448Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-341
2023-02-24T08:55:11.2644237Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-342
2023-02-24T08:55:11.2646505Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-343
2023-02-24T08:55:11.2650107Z [DEBUG:MainProcess:ExecutorManagerThread] found 5 processes to stop
2023-02-24T08:55:11.2703072Z [DEBUG:MainProcess:ExecutorManagerThread] sent 5 sentinels to the call queue
2023-02-24T08:55:11.2705534Z [DEBUG:MainProcess:ExecutorManagerThread] closing call_queue
2023-02-24T08:55:11.2709268Z [DEBUG:MainProcess:ExecutorManagerThread] telling queue thread to quit
2023-02-24T08:55:11.2709740Z [DEBUG:MainProcess:ExecutorManagerThread] Queue.join_thread()
2023-02-24T08:55:11.2710232Z [DEBUG:MainProcess:ExecutorManagerThread] closing result_queue
2023-02-24T08:55:11.2710676Z [DEBUG:MainProcess:ExecutorManagerThread] closing thread_wakeup
2023-02-24T08:55:11.2712996Z [DEBUG:MainProcess:QueueFeederThread] feeder thread got sentinel -- exiting
2023-02-24T08:55:11.2713453Z [DEBUG:MainProcess:ExecutorManagerThread] joining 5 processes
2023-02-24T08:55:11.2714163Z [DEBUG:MainProcess:ExecutorManagerThread] joining process LokyProcess-343 with pid 3297
2023-02-24T08:55:11.2720233Z [DEBUG:LokyProcess-342:MainThread] psutil return memory size: 30466048
2023-02-24T08:55:11.2721049Z [INFO:LokyProcess-342:MainThread] Shutting down worker on sentinel
2023-02-24T08:55:11.2721801Z [DEBUG:LokyProcess-342:MainThread] Exited cleanly
2023-02-24T08:55:11.2725858Z [INFO:LokyProcess-342:MainThread] process shutting down
2023-02-24T08:55:11.2726637Z [DEBUG:LokyProcess-342:MainThread] running all "atexit" finalizers with priority >= 0
2023-02-24T08:55:11.2730537Z [DEBUG:LokyProcess-342:MainThread] running the remaining "atexit" finalizers
2023-02-24T08:55:11.2733602Z [INFO:LokyProcess-342:MainThread] process exiting with exitcode 0
2023-02-24T08:55:11.2734468Z [DEBUG:LokyProcess-341:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.2735384Z [DEBUG:LokyProcess-341:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.2738950Z [DEBUG:LokyProcess-341:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.2739889Z [DEBUG:LokyProcess-341:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.2740802Z [DEBUG:LokyProcess-341:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.2743845Z [DEBUG:LokyProcess-341:MainThread] recreated blocker with handle 140579355418624 and name "/loky-1790-38bnqfa3"
2023-02-24T08:55:11.2744733Z [DEBUG:LokyProcess-341:MainThread] recreated blocker with handle 140579235049472 and name "/loky-1790-9w1drh86"
2023-02-24T08:55:11.2745553Z [INFO:LokyProcess-341:MainThread] child process calling self.run()
2023-02-24T08:55:11.2748230Z [DEBUG:LokyProcess-341:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.2749023Z [INFO:LokyProcess-341:MainThread] Shutting down worker on sentinel
2023-02-24T08:55:11.2749747Z [DEBUG:LokyProcess-341:MainThread] Exited cleanly
2023-02-24T08:55:11.2752942Z [INFO:LokyProcess-341:MainThread] process shutting down
2023-02-24T08:55:11.2753752Z [DEBUG:LokyProcess-341:MainThread] running all "atexit" finalizers with priority >= 0
2023-02-24T08:55:11.2756410Z [DEBUG:LokyProcess-341:MainThread] running the remaining "atexit" finalizers
2023-02-24T08:55:11.2757179Z [INFO:LokyProcess-341:MainThread] process exiting with exitcode 0
2023-02-24T08:55:11.2758225Z [DEBUG:LokyProcess-340:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.2767455Z [DEBUG:LokyProcess-340:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.2768711Z [DEBUG:LokyProcess-340:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.2769667Z [DEBUG:LokyProcess-340:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.2772595Z [DEBUG:LokyProcess-340:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.2773420Z [DEBUG:LokyProcess-340:MainThread] recreated blocker with handle 140579355418624 and name "/loky-1790-38bnqfa3"
2023-02-24T08:55:11.2831885Z [DEBUG:LokyProcess-340:MainThread] recreated blocker with handle 140579235053568 and name "/loky-1790-b0vl6jad"
2023-02-24T08:55:11.2842065Z [INFO:LokyProcess-340:MainThread] child process calling self.run()
2023-02-24T08:55:11.2842728Z [DEBUG:LokyProcess-340:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.2847694Z [INFO:LokyProcess-340:MainThread] Shutting down worker on sentinel
2023-02-24T08:55:11.2851115Z [DEBUG:LokyProcess-340:MainThread] Exited cleanly
2023-02-24T08:55:11.2851943Z [INFO:LokyProcess-340:MainThread] process shutting down
2023-02-24T08:55:11.2854038Z [DEBUG:LokyProcess-340:MainThread] running all "atexit" finalizers with priority >= 0
2023-02-24T08:55:11.2854726Z [DEBUG:LokyProcess-340:MainThread] running the remaining "atexit" finalizers
2023-02-24T08:55:11.2859903Z [INFO:LokyProcess-340:MainThread] process exiting with exitcode 0
2023-02-24T08:55:11.2860623Z [DEBUG:LokyProcess-339:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.2865889Z [DEBUG:LokyProcess-339:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.2866726Z [DEBUG:LokyProcess-339:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.2867501Z [DEBUG:LokyProcess-339:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.2870393Z [DEBUG:LokyProcess-339:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.2872618Z [DEBUG:LokyProcess-339:MainThread] recreated blocker with handle 140579355418624 and name "/loky-1790-38bnqfa3"
2023-02-24T08:55:11.2873442Z [DEBUG:LokyProcess-339:MainThread] recreated blocker with handle 140579235057664 and name "/loky-1790-1mny4qpj"
2023-02-24T08:55:11.2878157Z [INFO:LokyProcess-339:MainThread] child process calling self.run()
2023-02-24T08:55:11.2879003Z [DEBUG:LokyProcess-339:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.2881750Z [INFO:LokyProcess-339:MainThread] Shutting down worker on sentinel
2023-02-24T08:55:11.2885041Z [DEBUG:LokyProcess-339:MainThread] Exited cleanly
2023-02-24T08:55:11.2885861Z [INFO:LokyProcess-339:MainThread] process shutting down
2023-02-24T08:55:11.2886653Z [DEBUG:LokyProcess-339:MainThread] running all "atexit" finalizers with priority >= 0
2023-02-24T08:55:11.2889366Z [DEBUG:LokyProcess-339:MainThread] running the remaining "atexit" finalizers
2023-02-24T08:55:11.2890184Z [INFO:LokyProcess-339:MainThread] process exiting with exitcode 0
2023-02-24T08:55:11.2891272Z [DEBUG:LokyProcess-343:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.2894188Z [DEBUG:LokyProcess-343:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.2895168Z [DEBUG:LokyProcess-343:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.2896087Z [DEBUG:LokyProcess-343:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.2899314Z [DEBUG:LokyProcess-343:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.2900268Z [DEBUG:LokyProcess-343:MainThread] recreated blocker with handle 140579355418624 and name "/loky-1790-38bnqfa3"
2023-02-24T08:55:11.2901393Z [DEBUG:LokyProcess-343:MainThread] recreated blocker with handle 140579235041280 and name "/loky-1790-k04a4ftm"
2023-02-24T08:55:11.2905812Z [INFO:LokyProcess-343:MainThread] child process calling self.run()
2023-02-24T08:55:11.2947177Z [DEBUG:LokyProcess-343:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.2950570Z [INFO:LokyProcess-343:MainThread] Shutting down worker on sentinel
2023-02-24T08:55:11.2954262Z [DEBUG:LokyProcess-343:MainThread] Exited cleanly
2023-02-24T08:55:11.2954934Z [INFO:LokyProcess-343:MainThread] process shutting down
2023-02-24T08:55:11.2963212Z [DEBUG:LokyProcess-343:MainThread] running all "atexit" finalizers with priority >= 0
2023-02-24T08:55:11.2970563Z [DEBUG:LokyProcess-343:MainThread] running the remaining "atexit" finalizers
2023-02-24T08:55:11.2971366Z [INFO:LokyProcess-343:MainThread] process exiting with exitcode 0
2023-02-24T08:55:11.2980545Z [DEBUG:MainProcess:ExecutorManagerThread] joining process LokyProcess-342 with pid 3296
2023-02-24T08:55:11.2984664Z [DEBUG:MainProcess:ExecutorManagerThread] joining process LokyProcess-341 with pid 3295
2023-02-24T08:55:11.2985802Z [DEBUG:MainProcess:ExecutorManagerThread] joining process LokyProcess-340 with pid 3294
2023-02-24T08:55:11.2989640Z [DEBUG:MainProcess:ExecutorManagerThread] joining process LokyProcess-339 with pid 3293
2023-02-24T08:55:11.3000193Z [DEBUG:MainProcess:ExecutorManagerThread] executor management thread clean shutdown of 5 workers
2023-02-24T08:55:11.3001189Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579355418624 and name "None"
2023-02-24T08:55:11.3004080Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579351658496 and name "None"
2023-02-24T08:55:11.3004728Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235098624 and name "None"
2023-02-24T08:55:11.3005305Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235094528 and name "None"
2023-02-24T08:55:11.3005930Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235090432 and name "None"
2023-02-24T08:55:11.3009190Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235086336 and name "None"
2023-02-24T08:55:11.3009749Z [DEBUG:MainProcess:MainThread] ProcessPoolExecutor is setup
2023-02-24T08:55:11.3010511Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235057664 and name "None"
2023-02-24T08:55:11.3011224Z [DEBUG:MainProcess:MainThread] launched python with pid 3302 and cmd:
2023-02-24T08:55:11.3012226Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-344', '--pipe', '26']
2023-02-24T08:55:11.3012964Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235053568 and name "None"
2023-02-24T08:55:11.3016314Z [DEBUG:MainProcess:MainThread] launched python with pid 3303 and cmd:
2023-02-24T08:55:11.3017416Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-345', '--pipe', '27']
2023-02-24T08:55:11.3018152Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235049472 and name "None"
2023-02-24T08:55:11.3018752Z [DEBUG:MainProcess:MainThread] launched python with pid 3304 and cmd:
2023-02-24T08:55:11.3019576Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-346', '--pipe', '28']
2023-02-24T08:55:11.3020283Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235045376 and name "None"
2023-02-24T08:55:11.3023692Z [DEBUG:MainProcess:MainThread] launched python with pid 3305 and cmd:
2023-02-24T08:55:11.3024543Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-347', '--pipe', '29']
2023-02-24T08:55:11.3025774Z [DEBUG:MainProcess:MainThread] Adjusted process count to 4: [('LokyProcess-344', 3302), ('LokyProcess-345', 3303), ('LokyProcess-346', 3304), ('LokyProcess-347', 3305)]
2023-02-24T08:55:11.3026618Z [DEBUG:MainProcess:MainThread] _start_executor_manager_thread called
2023-02-24T08:55:11.3029679Z [DEBUG:MainProcess:ExecutorManagerThread] Queue._start_thread()
2023-02-24T08:55:11.3030246Z [DEBUG:MainProcess:ExecutorManagerThread] doing self._thread.start()
2023-02-24T08:55:11.3030809Z [DEBUG:MainProcess:QueueFeederThread] starting thread to feed data to pipe
2023-02-24T08:55:11.3031344Z [DEBUG:MainProcess:ExecutorManagerThread] ... done self._thread.start()
2023-02-24T08:55:11.3031999Z [DEBUG:MainProcess:MainThread] shutting down executor <loky.process_executor.ProcessPoolExecutor object at 0x7fdb2405a9a0>
2023-02-24T08:55:11.3032907Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-344
2023-02-24T08:55:11.3033677Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-345
2023-02-24T08:55:11.3038930Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-346
2023-02-24T08:55:11.3043682Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-347
2023-02-24T08:55:11.3044263Z [DEBUG:MainProcess:ExecutorManagerThread] found 4 processes to stop
2023-02-24T08:55:11.3046499Z [DEBUG:MainProcess:ExecutorManagerThread] sent 4 sentinels to the call queue
2023-02-24T08:55:11.3047068Z [DEBUG:MainProcess:ExecutorManagerThread] closing call_queue
2023-02-24T08:55:11.3047572Z [DEBUG:MainProcess:ExecutorManagerThread] telling queue thread to quit
2023-02-24T08:55:11.3051062Z [DEBUG:MainProcess:ExecutorManagerThread] Queue.join_thread()
2023-02-24T08:55:11.3051704Z [DEBUG:MainProcess:ExecutorManagerThread] closing result_queue
2023-02-24T08:55:11.3052241Z [DEBUG:MainProcess:ExecutorManagerThread] closing thread_wakeup
2023-02-24T08:55:11.3052797Z [DEBUG:MainProcess:ExecutorManagerThread] joining 4 processes
2023-02-24T08:55:11.3056442Z [DEBUG:MainProcess:ExecutorManagerThread] joining process LokyProcess-347 with pid 3305
2023-02-24T08:55:11.3057301Z [DEBUG:LokyProcess-344:MainThread] recreated blocker with handle 140579351658496 and name "/loky-1790-29vfjc37"
2023-02-24T08:55:11.3058230Z [DEBUG:LokyProcess-344:MainThread] recreated blocker with handle 140579235098624 and name "/loky-1790-ngr09fkn"
2023-02-24T08:55:11.3059133Z [DEBUG:LokyProcess-344:MainThread] recreated blocker with handle 140579235094528 and name "/loky-1790-ldz6mbek"
2023-02-24T08:55:11.3059992Z [DEBUG:LokyProcess-344:MainThread] recreated blocker with handle 140579235090432 and name "/loky-1790-cwbrqj05"
2023-02-24T08:55:11.3060901Z [DEBUG:LokyProcess-344:MainThread] recreated blocker with handle 140579235086336 and name "/loky-1790-ln61byu1"
2023-02-24T08:55:11.3118836Z [DEBUG:LokyProcess-344:MainThread] recreated blocker with handle 140579355418624 and name "/loky-1790-nhqnm68y"
2023-02-24T08:55:11.3139167Z [DEBUG:LokyProcess-344:MainThread] recreated blocker with handle 140579235057664 and name "/loky-1790-b9z03gfz"
2023-02-24T08:55:11.3139939Z [INFO:LokyProcess-344:MainThread] child process calling self.run()
2023-02-24T08:55:11.3145604Z [DEBUG:LokyProcess-344:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.3146405Z [DEBUG:LokyProcess-347:MainThread] recreated blocker with handle 140579351658496 and name "/loky-1790-29vfjc37"
2023-02-24T08:55:11.3147171Z [DEBUG:LokyProcess-347:MainThread] recreated blocker with handle 140579235098624 and name "/loky-1790-ngr09fkn"
2023-02-24T08:55:11.3151570Z [DEBUG:LokyProcess-347:MainThread] recreated blocker with handle 140579235094528 and name "/loky-1790-ldz6mbek"
2023-02-24T08:55:11.3152350Z [DEBUG:LokyProcess-347:MainThread] recreated blocker with handle 140579235090432 and name "/loky-1790-cwbrqj05"
2023-02-24T08:55:11.3153176Z [DEBUG:LokyProcess-347:MainThread] recreated blocker with handle 140579235086336 and name "/loky-1790-ln61byu1"
2023-02-24T08:55:11.3154186Z [DEBUG:LokyProcess-347:MainThread] recreated blocker with handle 140579355418624 and name "/loky-1790-nhqnm68y"
2023-02-24T08:55:11.3154960Z [DEBUG:LokyProcess-347:MainThread] recreated blocker with handle 140579235045376 and name "/loky-1790-zv0f0d16"
2023-02-24T08:55:11.3159476Z [INFO:LokyProcess-347:MainThread] child process calling self.run()
2023-02-24T08:55:11.3160146Z [DEBUG:LokyProcess-347:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.3160863Z [DEBUG:LokyProcess-345:MainThread] recreated blocker with handle 140579351658496 and name "/loky-1790-29vfjc37"
2023-02-24T08:55:11.3161682Z [DEBUG:LokyProcess-345:MainThread] recreated blocker with handle 140579235098624 and name "/loky-1790-ngr09fkn"
2023-02-24T08:55:11.3162442Z [DEBUG:LokyProcess-345:MainThread] recreated blocker with handle 140579235094528 and name "/loky-1790-ldz6mbek"
2023-02-24T08:55:11.3166306Z [DEBUG:LokyProcess-345:MainThread] recreated blocker with handle 140579235090432 and name "/loky-1790-cwbrqj05"
2023-02-24T08:55:11.3167143Z [DEBUG:LokyProcess-345:MainThread] recreated blocker with handle 140579235086336 and name "/loky-1790-ln61byu1"
2023-02-24T08:55:11.3167910Z [DEBUG:LokyProcess-345:MainThread] recreated blocker with handle 140579355418624 and name "/loky-1790-nhqnm68y"
2023-02-24T08:55:11.3168734Z [DEBUG:LokyProcess-345:MainThread] recreated blocker with handle 140579235053568 and name "/loky-1790-3e5hza75"
2023-02-24T08:55:11.3173041Z [INFO:LokyProcess-345:MainThread] child process calling self.run()
2023-02-24T08:55:11.3173745Z [DEBUG:LokyProcess-345:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.3174514Z [DEBUG:LokyProcess-346:MainThread] recreated blocker with handle 140579351658496 and name "/loky-1790-29vfjc37"
2023-02-24T08:55:11.3175283Z [DEBUG:LokyProcess-346:MainThread] recreated blocker with handle 140579235098624 and name "/loky-1790-ngr09fkn"
2023-02-24T08:55:11.3179398Z [DEBUG:LokyProcess-346:MainThread] recreated blocker with handle 140579235094528 and name "/loky-1790-ldz6mbek"
2023-02-24T08:55:11.3180219Z [DEBUG:LokyProcess-346:MainThread] recreated blocker with handle 140579235090432 and name "/loky-1790-cwbrqj05"
2023-02-24T08:55:11.3180985Z [DEBUG:LokyProcess-346:MainThread] recreated blocker with handle 140579235086336 and name "/loky-1790-ln61byu1"
2023-02-24T08:55:11.3184565Z [DEBUG:LokyProcess-346:MainThread] recreated blocker with handle 140579355418624 and name "/loky-1790-nhqnm68y"
2023-02-24T08:55:11.3185389Z [DEBUG:LokyProcess-346:MainThread] recreated blocker with handle 140579235049472 and name "/loky-1790-l6vt2eh3"
2023-02-24T08:55:11.3186063Z [INFO:LokyProcess-346:MainThread] child process calling self.run()
2023-02-24T08:55:11.3188658Z [DEBUG:LokyProcess-346:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.3188928Z
2023-02-24T08:55:11.3193270Z +++++++++++++++++++++++++++++++++++ Timeout ++++++++++++++++++++++++++++++++++++
2023-02-24T08:55:11.3193542Z
2023-02-24T08:55:11.3193893Z ~~~~~~~~~~~~~~~ Stack of ExecutorManagerThread (140579197097728) ~~~~~~~~~~~~~~~
2023-02-24T08:55:11.3194434Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/threading.py", line 937, in _bootstrap
2023-02-24T08:55:11.3197195Z self._bootstrap_inner()
2023-02-24T08:55:11.3197641Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/threading.py", line 980, in _bootstrap_inner
2023-02-24T08:55:11.3198093Z self.run()
2023-02-24T08:55:11.3198439Z File "/home/vsts/work/1/s/loky/process_executor.py", line 613, in run
2023-02-24T08:55:11.3198867Z self.join_executor_internals()
2023-02-24T08:55:11.3202426Z File "/home/vsts/work/1/s/loky/process_executor.py", line 911, in join_executor_internals
2023-02-24T08:55:11.3202842Z p.join()
2023-02-24T08:55:11.3203286Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/multiprocessing/process.py", line 149, in join
2023-02-24T08:55:11.3203726Z res = self._popen.wait(timeout)
2023-02-24T08:55:11.3204157Z File "/home/vsts/work/1/s/loky/backend/popen_loky_posix.py", line 79, in wait
2023-02-24T08:55:11.3204700Z return self.poll(os.WNOHANG if timeout == 0.0 else 0)
2023-02-24T08:55:11.3205169Z File "/home/vsts/work/1/s/loky/backend/popen_loky_posix.py", line 58, in poll
2023-02-24T08:55:11.3208931Z pid, sts = os.waitpid(self.pid, flag)
2023-02-24T08:55:11.3209153Z
2023-02-24T08:55:11.3209709Z ~~~~~~~~~~~~~~~~~~~~~ Stack of Thread-12 (140579297109760) ~~~~~~~~~~~~~~~~~~~~~
2023-02-24T08:55:11.3210255Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/threading.py", line 937, in _bootstrap
2023-02-24T08:55:11.3213111Z self._bootstrap_inner()
2023-02-24T08:55:11.3213554Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/threading.py", line 980, in _bootstrap_inner
2023-02-24T08:55:11.3214003Z self.run()
2023-02-24T08:55:11.3214378Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/threading.py", line 917, in run
2023-02-24T08:55:11.3214852Z self._target(*self._args, **self._kwargs)
2023-02-24T08:55:11.3217860Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/multiprocessing/resource_sharer.py", line 138, in _serve
2023-02-24T08:55:11.3218358Z with self._listener.accept() as conn:
2023-02-24T08:55:11.3218856Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/multiprocessing/connection.py", line 463, in accept
2023-02-24T08:55:11.3219301Z c = self._listener.accept()
2023-02-24T08:55:11.3223024Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/multiprocessing/connection.py", line 609, in accept
2023-02-24T08:55:11.3223531Z s, self._last_accepted = self._socket.accept()
2023-02-24T08:55:11.3223963Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/socket.py", line 293, in accept
2023-02-24T08:55:11.3224409Z fd, addr = self._accept()
2023-02-24T08:55:11.3224582Z
2023-02-24T08:55:11.3224957Z +++++++++++++++++++++++++++++++++++ Timeout ++++++++++++++++++++++++++++++++++++
2023-02-24T08:55:11.3225611Z --------------------------- Captured stderr teardown ---------------------------
2023-02-24T08:55:11.3228767Z [DEBUG:MainProcess:MainThread] shutting down executor <loky.process_executor.ProcessPoolExecutor object at 0x7fdb24053730>
2023-02-24T08:55:11.3229328Z ___ ERROR at setup of TestsProcessPoolLokyShutdown.test_interpreter_shutdown ___
2023-02-24T08:55:11.3229637Z
2023-02-24T08:55:11.3229985Z self = <tests.test_process_executor_loky.TestsProcessPoolLokyShutdown object at 0x7fdb2786f880>
2023-02-24T08:55:11.3232469Z
2023-02-24T08:55:11.3232760Z @pytest.fixture(autouse=True)
2023-02-24T08:55:11.3233119Z def setup_method(self):
2023-02-24T08:55:11.3233418Z global _test_event
2023-02-24T08:55:11.3236653Z assert _test_event is not None
2023-02-24T08:55:11.3236947Z try:
2023-02-24T08:55:11.3237298Z self.executor = self.executor_type(
2023-02-24T08:55:11.3237640Z max_workers=self.worker_count,
2023-02-24T08:55:11.3238012Z context=self.context,
2023-02-24T08:55:11.3238383Z initializer=initializer_event,
2023-02-24T08:55:11.3238710Z initargs=(_test_event,),
2023-02-24T08:55:11.3241666Z )
2023-02-24T08:55:11.3241985Z except NotImplementedError as e:
2023-02-24T08:55:11.3242349Z self.skipTest(str(e))
2023-02-24T08:55:11.3242680Z _check_executor_started(self.executor)
2023-02-24T08:55:11.3246024Z > _check_subprocesses_number(self.executor, self.worker_count)
2023-02-24T08:55:11.3246259Z
2023-02-24T08:55:11.3246680Z self = <tests.test_process_executor_loky.TestsProcessPoolLokyShutdown object at 0x7fdb2786f880>
2023-02-24T08:55:11.3246965Z
2023-02-24T08:55:11.3249767Z tests/_executor_mixin.py:183:
2023-02-24T08:55:11.3250163Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
2023-02-24T08:55:11.3250715Z tests/_executor_mixin.py:125: in _check_subprocesses_number
2023-02-24T08:55:11.3251060Z raise e
2023-02-24T08:55:11.3253802Z children_pids = {3302, 3303, 3304, 3305, 3345, 3346, ...}
2023-02-24T08:55:11.3254411Z executor = <loky.process_executor.ProcessPoolExecutor object at 0x7fdb24037280>
2023-02-24T08:55:11.3254828Z expected_max_process_number = None
2023-02-24T08:55:11.3257951Z expected_process_number = 5
2023-02-24T08:55:11.3258354Z patience = 10
2023-02-24T08:55:11.3259418Z pids_cmdlines = [(3302, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-344 --pi...me/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-349 --pipe 33'), ...]
2023-02-24T08:55:11.3260142Z trial_idx = 9
2023-02-24T08:55:11.3260468Z worker_pids = {3345, 3346, 3347, 3348, 3349}
2023-02-24T08:55:11.3263580Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
2023-02-24T08:55:11.3263799Z
2023-02-24T08:55:11.3264198Z executor = <loky.process_executor.ProcessPoolExecutor object at 0x7fdb24037280>
2023-02-24T08:55:11.3264656Z expected_process_number = 5, expected_max_process_number = None, patience = 10
2023-02-24T08:55:11.3267939Z
2023-02-24T08:55:11.3268231Z def _check_subprocesses_number(
2023-02-24T08:55:11.3268595Z executor=None,
2023-02-24T08:55:11.3268901Z expected_process_number=None,
2023-02-24T08:55:11.3272314Z expected_max_process_number=None,
2023-02-24T08:55:11.3272674Z patience=10,
2023-02-24T08:55:11.3272930Z ):
2023-02-24T08:55:11.3273235Z if not psutil:
2023-02-24T08:55:11.3273592Z # psutil is not installed, we cannot check the number of subprocesses
2023-02-24T08:55:11.3276466Z return
2023-02-24T08:55:11.3276734Z
2023-02-24T08:55:11.3277068Z for trial_idx in range(patience):
2023-02-24T08:55:11.3277365Z try:
2023-02-24T08:55:11.3279782Z # Wait for terminating processes to disappear
2023-02-24T08:55:11.3280212Z pids_cmdlines = _running_children_pids_with_cmdline(
2023-02-24T08:55:11.3280567Z psutil.Process()
2023-02-24T08:55:11.3284780Z )
2023-02-24T08:55:11.3285137Z children_pids = {pid for pid, _ in pids_cmdlines}
2023-02-24T08:55:11.3285567Z if executor is not None:
2023-02-24T08:55:11.3285926Z worker_pids = set(executor._processes.keys())
2023-02-24T08:55:11.3288477Z # Consistency check: all workers should be in the children list
2023-02-24T08:55:11.3288921Z assert worker_pids.issubset(children_pids)
2023-02-24T08:55:11.3289244Z else:
2023-02-24T08:55:11.3289632Z # Bypass pids checks when executor has been garbage collected
2023-02-24T08:55:11.3290008Z worker_pids = children_pids
2023-02-24T08:55:11.3293175Z if expected_process_number is not None:
2023-02-24T08:55:11.3293515Z > assert (
2023-02-24T08:55:11.3293895Z len(children_pids) == expected_process_number
2023-02-24T08:55:11.3294286Z ), pids_cmdlines
2023-02-24T08:55:11.3297152Z E AssertionError: [(3302, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-344 --pipe 26'), (3303, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-345 --pipe 27'), (3304, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-346 --pipe 28'), (3305, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-347 --pipe 29'), (3345, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-348 --pipe 32'), (3346, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-349 --pipe 33'), (3347, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-350 --pipe 34'), (3348, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-351 --pipe 35'), (3349, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-352 --pipe 36')]
2023-02-24T08:55:11.3301483Z
2023-02-24T08:55:11.3303906Z children_pids = {3302, 3303, 3304, 3305, 3345, 3346, ...}
2023-02-24T08:55:11.3304380Z executor = <loky.process_executor.ProcessPoolExecutor object at 0x7fdb24037280>
2023-02-24T08:55:11.3304857Z expected_max_process_number = None
2023-02-24T08:55:11.3305225Z expected_process_number = 5
2023-02-24T08:55:11.3305520Z patience = 10
2023-02-24T08:55:11.3309417Z pids_cmdlines = [(3302, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-344 --pi...me/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-349 --pipe 33'), ...]
2023-02-24T08:55:11.3310155Z trial_idx = 9
2023-02-24T08:55:11.3310474Z worker_pids = {3345, 3346, 3347, 3348, 3349}
2023-02-24T08:55:11.3310726Z
2023-02-24T08:55:11.3311033Z tests/_executor_mixin.py:103: AssertionError
2023-02-24T08:55:11.3314524Z ---------------------------- Captured stderr setup -----------------------------
2023-02-24T08:55:11.3315053Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235082240 and name "None"
2023-02-24T08:55:11.3315613Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235078144 and name "None"
2023-02-24T08:55:11.3316163Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235074048 and name "None"
2023-02-24T08:55:11.3316671Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235069952 and name "None"
2023-02-24T08:55:11.3319592Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235065856 and name "None"
2023-02-24T08:55:11.3320122Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235061760 and name "None"
2023-02-24T08:55:11.3320635Z [DEBUG:MainProcess:MainThread] ProcessPoolExecutor is setup
2023-02-24T08:55:11.3321138Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579234779136 and name "None"
2023-02-24T08:55:11.3321606Z [DEBUG:MainProcess:MainThread] launched python with pid 3345 and cmd:
2023-02-24T08:55:11.3322442Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-348', '--pipe', '32']
2023-02-24T08:55:11.3323031Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579234775040 and name "None"
2023-02-24T08:55:11.3326005Z [DEBUG:MainProcess:MainThread] launched python with pid 3346 and cmd:
2023-02-24T08:55:11.3326830Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-349', '--pipe', '33']
2023-02-24T08:55:11.3327408Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579234770944 and name "None"
2023-02-24T08:55:11.3327927Z [DEBUG:MainProcess:MainThread] launched python with pid 3347 and cmd:
2023-02-24T08:55:11.3331362Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-350', '--pipe', '34']
2023-02-24T08:55:11.3331982Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579234766848 and name "None"
2023-02-24T08:55:11.3332510Z [DEBUG:MainProcess:MainThread] launched python with pid 3348 and cmd:
2023-02-24T08:55:11.3333291Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-351', '--pipe', '35']
2023-02-24T08:55:11.3336365Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579234762752 and name "None"
2023-02-24T08:55:11.3336886Z [DEBUG:MainProcess:MainThread] launched python with pid 3349 and cmd:
2023-02-24T08:55:11.3337662Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-352', '--pipe', '36']
2023-02-24T08:55:11.3338689Z [DEBUG:MainProcess:MainThread] Adjusted process count to 5: [('LokyProcess-348', 3345), ('LokyProcess-349', 3346), ('LokyProcess-350', 3347), ('LokyProcess-351', 3348), ('LokyProcess-352', 3349)]
2023-02-24T08:55:11.3341591Z [DEBUG:MainProcess:MainThread] _start_executor_manager_thread called
2023-02-24T08:55:11.3342144Z [DEBUG:MainProcess:ExecutorManagerThread] Queue._start_thread()
2023-02-24T08:55:11.3342643Z [DEBUG:MainProcess:ExecutorManagerThread] doing self._thread.start()
2023-02-24T08:55:11.3343143Z [DEBUG:MainProcess:QueueFeederThread] starting thread to feed data to pipe
2023-02-24T08:55:11.3343605Z [DEBUG:MainProcess:ExecutorManagerThread] ... done self._thread.start()
2023-02-24T08:55:11.3346964Z [DEBUG:LokyProcess-348:MainThread] recreated blocker with handle 140579235078144 and name "/loky-1790-8u6pts0x"
2023-02-24T08:55:11.3347777Z [DEBUG:LokyProcess-348:MainThread] recreated blocker with handle 140579235074048 and name "/loky-1790-y_vv5qlm"
2023-02-24T08:55:11.3348614Z [DEBUG:LokyProcess-348:MainThread] recreated blocker with handle 140579235069952 and name "/loky-1790-mlf2p1mi"
2023-02-24T08:55:11.3349467Z [DEBUG:LokyProcess-348:MainThread] recreated blocker with handle 140579235065856 and name "/loky-1790-hcfe2lik"
2023-02-24T08:55:11.3350255Z [DEBUG:LokyProcess-348:MainThread] recreated blocker with handle 140579235061760 and name "/loky-1790-shn4y8x7"
2023-02-24T08:55:11.3354098Z [DEBUG:LokyProcess-350:MainThread] recreated blocker with handle 140579235078144 and name "/loky-1790-8u6pts0x"
2023-02-24T08:55:11.3354918Z [DEBUG:LokyProcess-350:MainThread] recreated blocker with handle 140579235074048 and name "/loky-1790-y_vv5qlm"
2023-02-24T08:55:11.3355689Z [DEBUG:LokyProcess-350:MainThread] recreated blocker with handle 140579235069952 and name "/loky-1790-mlf2p1mi"
2023-02-24T08:55:11.3358739Z [DEBUG:LokyProcess-350:MainThread] recreated blocker with handle 140579235065856 and name "/loky-1790-hcfe2lik"
2023-02-24T08:55:11.3359541Z [DEBUG:LokyProcess-350:MainThread] recreated blocker with handle 140579235061760 and name "/loky-1790-shn4y8x7"
2023-02-24T08:55:11.3360375Z [DEBUG:LokyProcess-349:MainThread] recreated blocker with handle 140579235078144 and name "/loky-1790-8u6pts0x"
2023-02-24T08:55:11.3363842Z [DEBUG:LokyProcess-349:MainThread] recreated blocker with handle 140579235074048 and name "/loky-1790-y_vv5qlm"
2023-02-24T08:55:11.3364645Z [DEBUG:LokyProcess-349:MainThread] recreated blocker with handle 140579235069952 and name "/loky-1790-mlf2p1mi"
2023-02-24T08:55:11.3365472Z [DEBUG:LokyProcess-349:MainThread] recreated blocker with handle 140579235065856 and name "/loky-1790-hcfe2lik"
2023-02-24T08:55:11.3366296Z [DEBUG:LokyProcess-349:MainThread] recreated blocker with handle 140579235061760 and name "/loky-1790-shn4y8x7"
2023-02-24T08:55:11.3367071Z [DEBUG:LokyProcess-351:MainThread] recreated blocker with handle 140579235078144 and name "/loky-1790-8u6pts0x"
2023-02-24T08:55:11.3370871Z [DEBUG:LokyProcess-351:MainThread] recreated blocker with handle 140579235074048 and name "/loky-1790-y_vv5qlm"
2023-02-24T08:55:11.3371679Z [DEBUG:LokyProcess-351:MainThread] recreated blocker with handle 140579235069952 and name "/loky-1790-mlf2p1mi"
2023-02-24T08:55:11.3372503Z [DEBUG:LokyProcess-351:MainThread] recreated blocker with handle 140579235065856 and name "/loky-1790-hcfe2lik"
2023-02-24T08:55:11.3375963Z [DEBUG:LokyProcess-351:MainThread] recreated blocker with handle 140579235061760 and name "/loky-1790-shn4y8x7"
2023-02-24T08:55:11.3376785Z [DEBUG:LokyProcess-352:MainThread] recreated blocker with handle 140579235078144 and name "/loky-1790-8u6pts0x"
2023-02-24T08:55:11.3377612Z [DEBUG:LokyProcess-352:MainThread] recreated blocker with handle 140579235074048 and name "/loky-1790-y_vv5qlm"
2023-02-24T08:55:11.3385592Z [DEBUG:LokyProcess-352:MainThread] recreated blocker with handle 140579235069952 and name "/loky-1790-mlf2p1mi"
2023-02-24T08:55:11.3386389Z [DEBUG:LokyProcess-352:MainThread] recreated blocker with handle 140579235065856 and name "/loky-1790-hcfe2lik"
2023-02-24T08:55:11.3387212Z [DEBUG:LokyProcess-352:MainThread] recreated blocker with handle 140579235061760 and name "/loky-1790-shn4y8x7"
2023-02-24T08:55:11.3395431Z [DEBUG:LokyProcess-348:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.3396306Z [DEBUG:LokyProcess-348:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.3397261Z [DEBUG:LokyProcess-348:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.3398069Z [DEBUG:LokyProcess-348:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.3400617Z [DEBUG:LokyProcess-348:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.3401435Z [DEBUG:LokyProcess-348:MainThread] recreated blocker with handle 140579235082240 and name "/loky-1790-2j2eh39v"
2023-02-24T08:55:11.3402213Z [DEBUG:LokyProcess-348:MainThread] recreated blocker with handle 140579234779136 and name "/loky-1790-fq4t2o2o"
2023-02-24T08:55:11.3405115Z [INFO:LokyProcess-348:MainThread] child process calling self.run()
2023-02-24T08:55:11.3405787Z [DEBUG:LokyProcess-348:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.3406418Z [DEBUG:LokyProcess-348:MainThread] psutil return memory size: 30502912
2023-02-24T08:55:11.3407187Z [DEBUG:LokyProcess-350:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.3407957Z [DEBUG:LokyProcess-350:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.3410590Z [DEBUG:LokyProcess-350:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.3411433Z [DEBUG:LokyProcess-350:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.3412201Z [DEBUG:LokyProcess-350:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.3413025Z [DEBUG:LokyProcess-350:MainThread] recreated blocker with handle 140579235082240 and name "/loky-1790-2j2eh39v"
2023-02-24T08:55:11.3413790Z [DEBUG:LokyProcess-350:MainThread] recreated blocker with handle 140579234770944 and name "/loky-1790-09lzhql6"
2023-02-24T08:55:11.3416276Z [INFO:LokyProcess-350:MainThread] child process calling self.run()
2023-02-24T08:55:11.3416945Z [DEBUG:LokyProcess-350:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.3417653Z [DEBUG:LokyProcess-349:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.3420429Z [DEBUG:LokyProcess-349:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.3421247Z [DEBUG:LokyProcess-349:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.3422023Z [DEBUG:LokyProcess-349:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.3422834Z [DEBUG:LokyProcess-349:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.3423602Z [DEBUG:LokyProcess-349:MainThread] recreated blocker with handle 140579235082240 and name "/loky-1790-2j2eh39v"
2023-02-24T08:55:11.3427377Z [DEBUG:LokyProcess-349:MainThread] recreated blocker with handle 140579234775040 and name "/loky-1790-g1ozqwbc"
2023-02-24T08:55:11.3428105Z [INFO:LokyProcess-349:MainThread] child process calling self.run()
2023-02-24T08:55:11.3428721Z [DEBUG:LokyProcess-349:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.3429477Z [DEBUG:LokyProcess-351:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.3430243Z [DEBUG:LokyProcess-351:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.3431071Z [DEBUG:LokyProcess-351:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.3435195Z [DEBUG:LokyProcess-351:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.3435985Z [DEBUG:LokyProcess-351:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.3436901Z [DEBUG:LokyProcess-351:MainThread] recreated blocker with handle 140579235082240 and name "/loky-1790-2j2eh39v"
2023-02-24T08:55:11.3437716Z [DEBUG:LokyProcess-351:MainThread] recreated blocker with handle 140579234766848 and name "/loky-1790-ply3dxcc"
2023-02-24T08:55:11.3438390Z [INFO:LokyProcess-351:MainThread] child process calling self.run()
2023-02-24T08:55:11.3441365Z [DEBUG:LokyProcess-351:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.3442075Z [DEBUG:LokyProcess-352:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.3442898Z [DEBUG:LokyProcess-352:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.3443714Z [DEBUG:LokyProcess-352:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.3444481Z [DEBUG:LokyProcess-352:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.3445293Z [DEBUG:LokyProcess-352:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.3448306Z [DEBUG:LokyProcess-352:MainThread] recreated blocker with handle 140579235082240 and name "/loky-1790-2j2eh39v"
2023-02-24T08:55:11.3449136Z [DEBUG:LokyProcess-352:MainThread] recreated blocker with handle 140579234762752 and name "/loky-1790-kcv5f1su"
2023-02-24T08:55:11.3449865Z [INFO:LokyProcess-352:MainThread] child process calling self.run()
2023-02-24T08:55:11.3450593Z [DEBUG:LokyProcess-352:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.3451194Z _ ERROR at teardown of TestsProcessPoolLokyShutdown.test_interpreter_shutdown __
2023-02-24T08:55:11.3451466Z
2023-02-24T08:55:11.3451889Z self = <tests.test_process_executor_loky.TestsProcessPoolLokyShutdown object at 0x7fdb2786f880>
2023-02-24T08:55:11.3454864Z method = <bound method ExecutorShutdownTest.test_interpreter_shutdown of <tests.test_process_executor_loky.TestsProcessPoolLokyShutdown object at 0x7fdb2786f880>>
2023-02-24T08:55:11.3455289Z
2023-02-24T08:55:11.3455577Z def teardown_method(self, method):
2023-02-24T08:55:11.3455992Z # Make sure executor is not broken if it should not be
2023-02-24T08:55:11.3456408Z executor = getattr(self, "executor", None)
2023-02-24T08:55:11.3456743Z if executor is not None:
2023-02-24T08:55:11.3457070Z try:
2023-02-24T08:55:11.3457348Z # old pytest markers:
2023-02-24T08:55:11.3460275Z expect_broken_pool = hasattr(method, "broken_pool")
2023-02-24T08:55:11.3460645Z # new pytest markers:
2023-02-24T08:55:11.3461033Z for mark in getattr(method, "pytestmark", []):
2023-02-24T08:55:11.3461432Z if mark.name == "broken_pool":
2023-02-24T08:55:11.3461759Z expect_broken_pool = True
2023-02-24T08:55:11.3462084Z
2023-02-24T08:55:11.3462360Z if expect_broken_pool:
2023-02-24T08:55:11.3464776Z for _ in range(10):
2023-02-24T08:55:11.3465141Z # The executor manager thread can take some time to
2023-02-24T08:55:11.3465550Z # mark the executor broken.
2023-02-24T08:55:11.3465961Z is_actually_broken = executor._flags.broken is not None
2023-02-24T08:55:11.3466336Z if is_actually_broken:
2023-02-24T08:55:11.3466684Z break
2023-02-24T08:55:11.3466962Z sleep(0.1)
2023-02-24T08:55:11.3469379Z else:
2023-02-24T08:55:11.3469689Z raise AssertionError(
2023-02-24T08:55:11.3470207Z "The executor was not flagged broken at the end of "
2023-02-24T08:55:11.3470588Z f" {method.__qualname__} as expected."
2023-02-24T08:55:11.3470945Z )
2023-02-24T08:55:11.3471310Z else:
2023-02-24T08:55:11.3471652Z # Check that the executor is not broken right away to avoid
2023-02-24T08:55:11.3474110Z # wasting CI time. False negative should be very rare.
2023-02-24T08:55:11.3474536Z is_actually_broken = executor._flags.broken is not None
2023-02-24T08:55:11.3474968Z assert not is_actually_broken
2023-02-24T08:55:11.3475310Z finally:
2023-02-24T08:55:11.3475653Z # Always shutdown the executor, with SIGKILL if the executor
2023-02-24T08:55:11.3476058Z # is actually broken.
2023-02-24T08:55:11.3476401Z kill_workers = executor._flags.broken is not None
2023-02-24T08:55:11.3479007Z t_start = time.time()
2023-02-24T08:55:11.3479380Z executor.shutdown(wait=True, kill_workers=kill_workers)
2023-02-24T08:55:11.3480010Z dt = time.time() - t_start
2023-02-24T08:55:11.3480424Z assert dt < 10, "Executor took too long to shutdown"
2023-02-24T08:55:11.3480796Z > _check_subprocesses_number(executor, 0)
2023-02-24T08:55:11.3480998Z
2023-02-24T08:55:11.3481314Z dt = 0.08818364143371582
2023-02-24T08:55:11.3481701Z executor = <loky.process_executor.ProcessPoolExecutor object at 0x7fdb24037280>
2023-02-24T08:55:11.3484596Z expect_broken_pool = False
2023-02-24T08:55:11.3484954Z is_actually_broken = False
2023-02-24T08:55:11.3485251Z kill_workers = False
2023-02-24T08:55:11.3485796Z method = <bound method ExecutorShutdownTest.test_interpreter_shutdown of <tests.test_process_executor_loky.TestsProcessPoolLokyShutdown object at 0x7fdb2786f880>>
2023-02-24T08:55:11.3486420Z self = <tests.test_process_executor_loky.TestsProcessPoolLokyShutdown object at 0x7fdb2786f880>
2023-02-24T08:55:11.3486897Z t_start = 1677228907.4469657
2023-02-24T08:55:11.3487081Z
2023-02-24T08:55:11.3490157Z tests/_executor_mixin.py:223:
2023-02-24T08:55:11.3490634Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
2023-02-24T08:55:11.3491106Z tests/_executor_mixin.py:125: in _check_subprocesses_number
2023-02-24T08:55:11.3491559Z raise e
2023-02-24T08:55:11.3491867Z children_pids = {3302, 3303, 3304, 3305}
2023-02-24T08:55:11.3492323Z executor = <loky.process_executor.ProcessPoolExecutor object at 0x7fdb24037280>
2023-02-24T08:55:11.3492742Z expected_max_process_number = None
2023-02-24T08:55:11.3496495Z expected_process_number = 0
2023-02-24T08:55:11.3496795Z patience = 10
2023-02-24T08:55:11.3497804Z pids_cmdlines = [(3302, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-344 --pi... '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-347 --pipe 29')]
2023-02-24T08:55:11.3498524Z trial_idx = 9
2023-02-24T08:55:11.3498863Z worker_pids = set()
2023-02-24T08:55:11.3499212Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
2023-02-24T08:55:11.3499425Z
2023-02-24T08:55:11.3502918Z executor = <loky.process_executor.ProcessPoolExecutor object at 0x7fdb24037280>
2023-02-24T08:55:11.3503425Z expected_process_number = 0, expected_max_process_number = None, patience = 10
2023-02-24T08:55:11.3503676Z
2023-02-24T08:55:11.3503927Z def _check_subprocesses_number(
2023-02-24T08:55:11.3504281Z executor=None,
2023-02-24T08:55:11.3504632Z expected_process_number=None,
2023-02-24T08:55:11.3504962Z expected_max_process_number=None,
2023-02-24T08:55:11.3508767Z patience=10,
2023-02-24T08:55:11.3509050Z ):
2023-02-24T08:55:11.3509456Z if not psutil:
2023-02-24T08:55:11.3509806Z # psutil is not installed, we cannot check the number of subprocesses
2023-02-24T08:55:11.3510197Z return
2023-02-24T08:55:11.3510440Z
2023-02-24T08:55:11.3510770Z for trial_idx in range(patience):
2023-02-24T08:55:11.3511128Z try:
2023-02-24T08:55:11.3514955Z # Wait for terminating processes to disappear
2023-02-24T08:55:11.3515392Z pids_cmdlines = _running_children_pids_with_cmdline(
2023-02-24T08:55:11.3515741Z psutil.Process()
2023-02-24T08:55:11.3516059Z )
2023-02-24T08:55:11.3516372Z children_pids = {pid for pid, _ in pids_cmdlines}
2023-02-24T08:55:11.3516767Z if executor is not None:
2023-02-24T08:55:11.3517110Z worker_pids = set(executor._processes.keys())
2023-02-24T08:55:11.3520202Z # Consistency check: all workers should be in the children list
2023-02-24T08:55:11.3520656Z assert worker_pids.issubset(children_pids)
2023-02-24T08:55:11.3520981Z else:
2023-02-24T08:55:11.3524266Z # Bypass pids checks when executor has been garbage collected
2023-02-24T08:55:11.3524660Z worker_pids = children_pids
2023-02-24T08:55:11.3525055Z if expected_process_number is not None:
2023-02-24T08:55:11.3525370Z > assert (
2023-02-24T08:55:11.3525745Z len(children_pids) == expected_process_number
2023-02-24T08:55:11.3526137Z ), pids_cmdlines
2023-02-24T08:55:11.3527736Z E AssertionError: [(3302, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-344 --pipe 26'), (3303, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-345 --pipe 27'), (3304, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-346 --pipe 28'), (3305, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-347 --pipe 29')]
2023-02-24T08:55:11.3531263Z
2023-02-24T08:55:11.3531592Z children_pids = {3302, 3303, 3304, 3305}
2023-02-24T08:55:11.3532007Z executor = <loky.process_executor.ProcessPoolExecutor object at 0x7fdb24037280>
2023-02-24T08:55:11.3532454Z expected_max_process_number = None
2023-02-24T08:55:11.3532825Z expected_process_number = 0
2023-02-24T08:55:11.3533114Z patience = 10
2023-02-24T08:55:11.3537360Z pids_cmdlines = [(3302, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-344 --pi... '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-347 --pipe 29')]
2023-02-24T08:55:11.3538085Z trial_idx = 9
2023-02-24T08:55:11.3538369Z worker_pids = set()
2023-02-24T08:55:11.3538581Z
2023-02-24T08:55:11.3538891Z tests/_executor_mixin.py:103: AssertionError
2023-02-24T08:55:11.3539530Z ---------------------------- Captured stderr setup -----------------------------
2023-02-24T08:55:11.3540025Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235082240 and name "None"
2023-02-24T08:55:11.3544789Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235078144 and name "None"
2023-02-24T08:55:11.3545354Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235074048 and name "None"
2023-02-24T08:55:11.3545860Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235069952 and name "None"
2023-02-24T08:55:11.3546408Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235065856 and name "None"
2023-02-24T08:55:11.3546907Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235061760 and name "None"
2023-02-24T08:55:11.3547416Z [DEBUG:MainProcess:MainThread] ProcessPoolExecutor is setup
2023-02-24T08:55:11.3550212Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579234779136 and name "None"
2023-02-24T08:55:11.3550817Z [DEBUG:MainProcess:MainThread] launched python with pid 3345 and cmd:
2023-02-24T08:55:11.3551645Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-348', '--pipe', '32']
2023-02-24T08:55:11.3552353Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579234775040 and name "None"
2023-02-24T08:55:11.3552835Z [DEBUG:MainProcess:MainThread] launched python with pid 3346 and cmd:
2023-02-24T08:55:11.3553630Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-349', '--pipe', '33']
2023-02-24T08:55:11.3554211Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579234770944 and name "None"
2023-02-24T08:55:11.3559588Z [DEBUG:MainProcess:MainThread] launched python with pid 3347 and cmd:
2023-02-24T08:55:11.3560403Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-350', '--pipe', '34']
2023-02-24T08:55:11.3560992Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579234766848 and name "None"
2023-02-24T08:55:11.3561516Z [DEBUG:MainProcess:MainThread] launched python with pid 3348 and cmd:
2023-02-24T08:55:11.3562245Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-351', '--pipe', '35']
2023-02-24T08:55:11.3562874Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579234762752 and name "None"
2023-02-24T08:55:11.3567449Z [DEBUG:MainProcess:MainThread] launched python with pid 3349 and cmd:
2023-02-24T08:55:11.3568240Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-352', '--pipe', '36']
2023-02-24T08:55:11.3569284Z [DEBUG:MainProcess:MainThread] Adjusted process count to 5: [('LokyProcess-348', 3345), ('LokyProcess-349', 3346), ('LokyProcess-350', 3347), ('LokyProcess-351', 3348), ('LokyProcess-352', 3349)]
2023-02-24T08:55:11.3569998Z [DEBUG:MainProcess:MainThread] _start_executor_manager_thread called
2023-02-24T08:55:11.3570589Z [DEBUG:MainProcess:ExecutorManagerThread] Queue._start_thread()
2023-02-24T08:55:11.3571043Z [DEBUG:MainProcess:ExecutorManagerThread] doing self._thread.start()
2023-02-24T08:55:11.3579706Z [DEBUG:MainProcess:QueueFeederThread] starting thread to feed data to pipe
2023-02-24T08:55:11.3580217Z [DEBUG:MainProcess:ExecutorManagerThread] ... done self._thread.start()
2023-02-24T08:55:11.3581042Z [DEBUG:LokyProcess-348:MainThread] recreated blocker with handle 140579235078144 and name "/loky-1790-8u6pts0x"
2023-02-24T08:55:11.3581863Z [DEBUG:LokyProcess-348:MainThread] recreated blocker with handle 140579235074048 and name "/loky-1790-y_vv5qlm"
2023-02-24T08:55:11.3582634Z [DEBUG:LokyProcess-348:MainThread] recreated blocker with handle 140579235069952 and name "/loky-1790-mlf2p1mi"
2023-02-24T08:55:11.3583453Z [DEBUG:LokyProcess-348:MainThread] recreated blocker with handle 140579235065856 and name "/loky-1790-hcfe2lik"
2023-02-24T08:55:11.3584222Z [DEBUG:LokyProcess-348:MainThread] recreated blocker with handle 140579235061760 and name "/loky-1790-shn4y8x7"
2023-02-24T08:55:11.3587804Z [DEBUG:LokyProcess-350:MainThread] recreated blocker with handle 140579235078144 and name "/loky-1790-8u6pts0x"
2023-02-24T08:55:11.3588644Z [DEBUG:LokyProcess-350:MainThread] recreated blocker with handle 140579235074048 and name "/loky-1790-y_vv5qlm"
2023-02-24T08:55:11.3589411Z [DEBUG:LokyProcess-350:MainThread] recreated blocker with handle 140579235069952 and name "/loky-1790-mlf2p1mi"
2023-02-24T08:55:11.3590240Z [DEBUG:LokyProcess-350:MainThread] recreated blocker with handle 140579235065856 and name "/loky-1790-hcfe2lik"
2023-02-24T08:55:11.3591051Z [DEBUG:LokyProcess-350:MainThread] recreated blocker with handle 140579235061760 and name "/loky-1790-shn4y8x7"
2023-02-24T08:55:11.3591830Z [DEBUG:LokyProcess-349:MainThread] recreated blocker with handle 140579235078144 and name "/loky-1790-8u6pts0x"
2023-02-24T08:55:11.3605012Z [DEBUG:LokyProcess-349:MainThread] recreated blocker with handle 140579235074048 and name "/loky-1790-y_vv5qlm"
2023-02-24T08:55:11.3605833Z [DEBUG:LokyProcess-349:MainThread] recreated blocker with handle 140579235069952 and name "/loky-1790-mlf2p1mi"
2023-02-24T08:55:11.3606746Z [DEBUG:LokyProcess-349:MainThread] recreated blocker with handle 140579235065856 and name "/loky-1790-hcfe2lik"
2023-02-24T08:55:11.3607648Z [DEBUG:LokyProcess-349:MainThread] recreated blocker with handle 140579235061760 and name "/loky-1790-shn4y8x7"
2023-02-24T08:55:11.3608390Z [DEBUG:LokyProcess-351:MainThread] recreated blocker with handle 140579235078144 and name "/loky-1790-8u6pts0x"
2023-02-24T08:55:11.3609213Z [DEBUG:LokyProcess-351:MainThread] recreated blocker with handle 140579235074048 and name "/loky-1790-y_vv5qlm"
2023-02-24T08:55:11.3612580Z [DEBUG:LokyProcess-351:MainThread] recreated blocker with handle 140579235069952 and name "/loky-1790-mlf2p1mi"
2023-02-24T08:55:11.3613436Z [DEBUG:LokyProcess-351:MainThread] recreated blocker with handle 140579235065856 and name "/loky-1790-hcfe2lik"
2023-02-24T08:55:11.3614336Z [DEBUG:LokyProcess-351:MainThread] recreated blocker with handle 140579235061760 and name "/loky-1790-shn4y8x7"
2023-02-24T08:55:11.3615089Z [DEBUG:LokyProcess-352:MainThread] recreated blocker with handle 140579235078144 and name "/loky-1790-8u6pts0x"
2023-02-24T08:55:11.3615914Z [DEBUG:LokyProcess-352:MainThread] recreated blocker with handle 140579235074048 and name "/loky-1790-y_vv5qlm"
2023-02-24T08:55:11.3616726Z [DEBUG:LokyProcess-352:MainThread] recreated blocker with handle 140579235069952 and name "/loky-1790-mlf2p1mi"
2023-02-24T08:55:11.3617484Z [DEBUG:LokyProcess-352:MainThread] recreated blocker with handle 140579235065856 and name "/loky-1790-hcfe2lik"
2023-02-24T08:55:11.3621402Z [DEBUG:LokyProcess-352:MainThread] recreated blocker with handle 140579235061760 and name "/loky-1790-shn4y8x7"
2023-02-24T08:55:11.3622223Z [DEBUG:LokyProcess-348:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.3622994Z [DEBUG:LokyProcess-348:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.3623808Z [DEBUG:LokyProcess-348:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.3624629Z [DEBUG:LokyProcess-348:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.3625393Z [DEBUG:LokyProcess-348:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.3629413Z [DEBUG:LokyProcess-348:MainThread] recreated blocker with handle 140579235082240 and name "/loky-1790-2j2eh39v"
2023-02-24T08:55:11.3630277Z [DEBUG:LokyProcess-348:MainThread] recreated blocker with handle 140579234779136 and name "/loky-1790-fq4t2o2o"
2023-02-24T08:55:11.3631016Z [INFO:LokyProcess-348:MainThread] child process calling self.run()
2023-02-24T08:55:11.3631676Z [DEBUG:LokyProcess-348:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.3632299Z [DEBUG:LokyProcess-348:MainThread] psutil return memory size: 30502912
2023-02-24T08:55:11.3633061Z [DEBUG:LokyProcess-350:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.3633837Z [DEBUG:LokyProcess-350:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.3645157Z [DEBUG:LokyProcess-350:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.3646019Z [DEBUG:LokyProcess-350:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.3646816Z [DEBUG:LokyProcess-350:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.3647663Z [DEBUG:LokyProcess-350:MainThread] recreated blocker with handle 140579235082240 and name "/loky-1790-2j2eh39v"
2023-02-24T08:55:11.3648620Z [DEBUG:LokyProcess-350:MainThread] recreated blocker with handle 140579234770944 and name "/loky-1790-09lzhql6"
2023-02-24T08:55:11.3649302Z [INFO:LokyProcess-350:MainThread] child process calling self.run()
2023-02-24T08:55:11.3653012Z [DEBUG:LokyProcess-350:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.3653880Z [DEBUG:LokyProcess-349:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.3654704Z [DEBUG:LokyProcess-349:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.3655519Z [DEBUG:LokyProcess-349:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.3656285Z [DEBUG:LokyProcess-349:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.3657101Z [DEBUG:LokyProcess-349:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.3660294Z [DEBUG:LokyProcess-349:MainThread] recreated blocker with handle 140579235082240 and name "/loky-1790-2j2eh39v"
2023-02-24T08:55:11.3661117Z [DEBUG:LokyProcess-349:MainThread] recreated blocker with handle 140579234775040 and name "/loky-1790-g1ozqwbc"
2023-02-24T08:55:11.3661847Z [INFO:LokyProcess-349:MainThread] child process calling self.run()
2023-02-24T08:55:11.3662464Z [DEBUG:LokyProcess-349:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.3663224Z [DEBUG:LokyProcess-351:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.3664029Z [DEBUG:LokyProcess-351:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.3664795Z [DEBUG:LokyProcess-351:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.3668491Z [DEBUG:LokyProcess-351:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.3669281Z [DEBUG:LokyProcess-351:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.3670104Z [DEBUG:LokyProcess-351:MainThread] recreated blocker with handle 140579235082240 and name "/loky-1790-2j2eh39v"
2023-02-24T08:55:11.3670930Z [DEBUG:LokyProcess-351:MainThread] recreated blocker with handle 140579234766848 and name "/loky-1790-ply3dxcc"
2023-02-24T08:55:11.3671604Z [INFO:LokyProcess-351:MainThread] child process calling self.run()
2023-02-24T08:55:11.3672278Z [DEBUG:LokyProcess-351:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.3675772Z [DEBUG:LokyProcess-352:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.3676612Z [DEBUG:LokyProcess-352:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.3677462Z [DEBUG:LokyProcess-352:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.3678229Z [DEBUG:LokyProcess-352:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.3679045Z [DEBUG:LokyProcess-352:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.3679893Z [DEBUG:LokyProcess-352:MainThread] recreated blocker with handle 140579235082240 and name "/loky-1790-2j2eh39v"
2023-02-24T08:55:11.3680660Z [DEBUG:LokyProcess-352:MainThread] recreated blocker with handle 140579234762752 and name "/loky-1790-kcv5f1su"
2023-02-24T08:55:11.3684828Z [INFO:LokyProcess-352:MainThread] child process calling self.run()
2023-02-24T08:55:11.3685505Z [DEBUG:LokyProcess-352:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.3686132Z --------------------------- Captured stderr teardown ---------------------------
2023-02-24T08:55:11.3686745Z [DEBUG:MainProcess:MainThread] shutting down executor <loky.process_executor.ProcessPoolExecutor object at 0x7fdb24037280>
2023-02-24T08:55:11.3687606Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-348
2023-02-24T08:55:11.3688347Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-349
2023-02-24T08:55:11.3692235Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-350
2023-02-24T08:55:11.3692991Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-351
2023-02-24T08:55:11.3693721Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-352
2023-02-24T08:55:11.3694204Z [DEBUG:MainProcess:ExecutorManagerThread] found 5 processes to stop
2023-02-24T08:55:11.3694706Z [DEBUG:MainProcess:ExecutorManagerThread] sent 5 sentinels to the call queue
2023-02-24T08:55:11.3695196Z [DEBUG:MainProcess:ExecutorManagerThread] closing call_queue
2023-02-24T08:55:11.3695636Z [DEBUG:MainProcess:ExecutorManagerThread] telling queue thread to quit
2023-02-24T08:55:11.3698761Z [DEBUG:MainProcess:ExecutorManagerThread] Queue.join_thread()
2023-02-24T08:55:11.3699211Z [DEBUG:MainProcess:ExecutorManagerThread] closing result_queue
2023-02-24T08:55:11.3699666Z [DEBUG:MainProcess:ExecutorManagerThread] closing thread_wakeup
2023-02-24T08:55:11.3700263Z [INFO:LokyProcess-348:MainThread] Shutting down worker on sentinel
2023-02-24T08:55:11.3700907Z [DEBUG:MainProcess:QueueFeederThread] feeder thread got sentinel -- exiting
2023-02-24T08:55:11.3701510Z [DEBUG:LokyProcess-348:MainThread] Exited cleanly
2023-02-24T08:55:11.3702081Z [INFO:LokyProcess-348:MainThread] process shutting down
2023-02-24T08:55:11.3707691Z [DEBUG:LokyProcess-348:MainThread] running all "atexit" finalizers with priority >= 0
2023-02-24T08:55:11.3708368Z [DEBUG:LokyProcess-348:MainThread] running the remaining "atexit" finalizers
2023-02-24T08:55:11.3709059Z [INFO:LokyProcess-348:MainThread] process exiting with exitcode 0
2023-02-24T08:55:11.3709526Z [DEBUG:MainProcess:ExecutorManagerThread] joining 5 processes
2023-02-24T08:55:11.3710138Z [DEBUG:MainProcess:ExecutorManagerThread] joining process LokyProcess-352 with pid 3349
2023-02-24T08:55:11.3710793Z [INFO:LokyProcess-350:MainThread] Shutting down worker on sentinel
2023-02-24T08:55:11.3711334Z [DEBUG:LokyProcess-350:MainThread] Exited cleanly
2023-02-24T08:55:11.3714160Z [INFO:LokyProcess-350:MainThread] process shutting down
2023-02-24T08:55:11.3714837Z [DEBUG:LokyProcess-350:MainThread] running all "atexit" finalizers with priority >= 0
2023-02-24T08:55:11.3715490Z [DEBUG:LokyProcess-350:MainThread] running the remaining "atexit" finalizers
2023-02-24T08:55:11.3716151Z [INFO:LokyProcess-350:MainThread] process exiting with exitcode 0
2023-02-24T08:55:11.3716758Z [INFO:LokyProcess-349:MainThread] Shutting down worker on sentinel
2023-02-24T08:55:11.3717409Z [INFO:LokyProcess-351:MainThread] Shutting down worker on sentinel
2023-02-24T08:55:11.3717983Z [DEBUG:LokyProcess-349:MainThread] Exited cleanly
2023-02-24T08:55:11.3721747Z [INFO:LokyProcess-349:MainThread] process shutting down
2023-02-24T08:55:11.3722360Z [DEBUG:LokyProcess-351:MainThread] Exited cleanly
2023-02-24T08:55:11.3722978Z [DEBUG:LokyProcess-349:MainThread] running all "atexit" finalizers with priority >= 0
2023-02-24T08:55:11.3723638Z [INFO:LokyProcess-351:MainThread] process shutting down
2023-02-24T08:55:11.3724253Z [DEBUG:LokyProcess-349:MainThread] running the remaining "atexit" finalizers
2023-02-24T08:55:11.3724963Z [DEBUG:LokyProcess-351:MainThread] running all "atexit" finalizers with priority >= 0
2023-02-24T08:55:11.3728631Z [INFO:LokyProcess-349:MainThread] process exiting with exitcode 0
2023-02-24T08:55:11.3729313Z [DEBUG:LokyProcess-351:MainThread] running the remaining "atexit" finalizers
2023-02-24T08:55:11.3729979Z [INFO:LokyProcess-351:MainThread] process exiting with exitcode 0
2023-02-24T08:55:11.3730711Z [INFO:LokyProcess-352:MainThread] Shutting down worker on sentinel
2023-02-24T08:55:11.3731352Z [DEBUG:LokyProcess-352:MainThread] Exited cleanly
2023-02-24T08:55:11.3732028Z [INFO:LokyProcess-352:MainThread] process shutting down
2023-02-24T08:55:11.3732710Z [DEBUG:LokyProcess-352:MainThread] running all "atexit" finalizers with priority >= 0
2023-02-24T08:55:11.3736504Z [DEBUG:LokyProcess-352:MainThread] running the remaining "atexit" finalizers
2023-02-24T08:55:11.3737227Z [INFO:LokyProcess-352:MainThread] process exiting with exitcode 0
2023-02-24T08:55:11.3737930Z [DEBUG:MainProcess:ExecutorManagerThread] joining process LokyProcess-351 with pid 3348
2023-02-24T08:55:11.3738602Z [DEBUG:MainProcess:ExecutorManagerThread] joining process LokyProcess-350 with pid 3347
2023-02-24T08:55:11.3739335Z [DEBUG:MainProcess:ExecutorManagerThread] joining process LokyProcess-349 with pid 3346
2023-02-24T08:55:11.3740064Z [DEBUG:MainProcess:ExecutorManagerThread] joining process LokyProcess-348 with pid 3345
2023-02-24T08:55:11.3740587Z [DEBUG:MainProcess:ExecutorManagerThread] executor management thread clean shutdown of 5 workers
2023-02-24T08:55:11.3745599Z _____ ERROR at setup of TestsProcessPoolLokyShutdown.test_hang_issue12364 ______
2023-02-24T08:55:11.3745860Z
2023-02-24T08:55:11.3746277Z self = <tests.test_process_executor_loky.TestsProcessPoolLokyShutdown object at 0x7fdb2786fe50>
2023-02-24T08:55:11.3746560Z
2023-02-24T08:55:11.3746886Z @pytest.fixture(autouse=True)
2023-02-24T08:55:11.3747203Z def setup_method(self):
2023-02-24T08:55:11.3747545Z global _test_event
2023-02-24T08:55:11.3747852Z assert _test_event is not None
2023-02-24T08:55:11.3752611Z try:
2023-02-24T08:55:11.3752908Z self.executor = self.executor_type(
2023-02-24T08:55:11.3753290Z max_workers=self.worker_count,
2023-02-24T08:55:11.3753656Z context=self.context,
2023-02-24T08:55:11.3753975Z initializer=initializer_event,
2023-02-24T08:55:11.3754350Z initargs=(_test_event,),
2023-02-24T08:55:11.3754631Z )
2023-02-24T08:55:11.3757890Z except NotImplementedError as e:
2023-02-24T08:55:11.3758223Z self.skipTest(str(e))
2023-02-24T08:55:11.3764677Z _check_executor_started(self.executor)
2023-02-24T08:55:11.3765064Z > _check_subprocesses_number(self.executor, self.worker_count)
2023-02-24T08:55:11.3769825Z
2023-02-24T08:55:11.3770207Z self = <tests.test_process_executor_loky.TestsProcessPoolLokyShutdown object at 0x7fdb2786fe50>
2023-02-24T08:55:11.3774736Z
2023-02-24T08:55:11.3775036Z tests/_executor_mixin.py:183:
2023-02-24T08:55:11.3777122Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
2023-02-24T08:55:11.3777553Z tests/_executor_mixin.py:125: in _check_subprocesses_number
2023-02-24T08:55:11.3782620Z raise e
2023-02-24T08:55:11.3782947Z children_pids = {3302, 3303, 3304, 3305, 3357, 3358, ...}
2023-02-24T08:55:11.3787878Z executor = <loky.process_executor.ProcessPoolExecutor object at 0x7fdb274735b0>
2023-02-24T08:55:11.3795886Z expected_max_process_number = None
2023-02-24T08:55:11.3796244Z expected_process_number = 5
2023-02-24T08:55:11.3802478Z patience = 10
2023-02-24T08:55:11.3803483Z pids_cmdlines = [(3302, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-344 --pi...me/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-354 --pipe 33'), ...]
2023-02-24T08:55:11.3808484Z trial_idx = 9
2023-02-24T08:55:11.3812364Z worker_pids = {3357, 3358, 3359, 3360, 3361}
2023-02-24T08:55:11.3812741Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
2023-02-24T08:55:11.3819705Z
2023-02-24T08:55:11.3820056Z executor = <loky.process_executor.ProcessPoolExecutor object at 0x7fdb274735b0>
2023-02-24T08:55:11.3826691Z expected_process_number = 5, expected_max_process_number = None, patience = 10
2023-02-24T08:55:11.3826945Z
2023-02-24T08:55:11.3830278Z def _check_subprocesses_number(
2023-02-24T08:55:11.3830597Z executor=None,
2023-02-24T08:55:11.3835310Z expected_process_number=None,
2023-02-24T08:55:11.3835646Z expected_max_process_number=None,
2023-02-24T08:55:11.3841462Z patience=10,
2023-02-24T08:55:11.3845204Z ):
2023-02-24T08:55:11.3845496Z if not psutil:
2023-02-24T08:55:11.3850113Z # psutil is not installed, we cannot check the number of subprocesses
2023-02-24T08:55:11.3850599Z return
2023-02-24T08:55:11.3854275Z
2023-02-24T08:55:11.3854585Z for trial_idx in range(patience):
2023-02-24T08:55:11.3859890Z try:
2023-02-24T08:55:11.3860208Z # Wait for terminating processes to disappear
2023-02-24T08:55:11.3863945Z pids_cmdlines = _running_children_pids_with_cmdline(
2023-02-24T08:55:11.3869542Z psutil.Process()
2023-02-24T08:55:11.3869858Z )
2023-02-24T08:55:11.3875159Z children_pids = {pid for pid, _ in pids_cmdlines}
2023-02-24T08:55:11.3875531Z if executor is not None:
2023-02-24T08:55:11.3879455Z worker_pids = set(executor._processes.keys())
2023-02-24T08:55:11.3879903Z # Consistency check: all workers should be in the children list
2023-02-24T08:55:11.3884684Z assert worker_pids.issubset(children_pids)
2023-02-24T08:55:11.3889199Z else:
2023-02-24T08:55:11.3889580Z # Bypass pids checks when executor has been garbage collected
2023-02-24T08:55:11.3893380Z worker_pids = children_pids
2023-02-24T08:55:11.3893758Z if expected_process_number is not None:
2023-02-24T08:55:11.3897826Z > assert (
2023-02-24T08:55:11.3898160Z len(children_pids) == expected_process_number
2023-02-24T08:55:11.3902632Z ), pids_cmdlines
2023-02-24T08:55:11.3912007Z E AssertionError: [(3302, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-344 --pipe 26'), (3303, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-345 --pipe 27'), (3304, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-346 --pipe 28'), (3305, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-347 --pipe 29'), (3357, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-353 --pipe 32'), (3358, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-354 --pipe 33'), (3359, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-355 --pipe 34'), (3360, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-356 --pipe 35'), (3361, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-357 --pipe 36')]
2023-02-24T08:55:11.3923326Z
2023-02-24T08:55:11.3923787Z children_pids = {3302, 3303, 3304, 3305, 3357, 3358, ...}
2023-02-24T08:55:11.3927984Z executor = <loky.process_executor.ProcessPoolExecutor object at 0x7fdb274735b0>
2023-02-24T08:55:11.3928397Z expected_max_process_number = None
2023-02-24T08:55:11.3932906Z expected_process_number = 5
2023-02-24T08:55:11.3935978Z patience = 10
2023-02-24T08:55:11.3937074Z pids_cmdlines = [(3302, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-344 --pi...me/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-354 --pipe 33'), ...]
2023-02-24T08:55:11.3943089Z trial_idx = 9
2023-02-24T08:55:11.3947090Z worker_pids = {3357, 3358, 3359, 3360, 3361}
2023-02-24T08:55:11.3947322Z
2023-02-24T08:55:11.3951373Z tests/_executor_mixin.py:103: AssertionError
2023-02-24T08:55:11.3952031Z ---------------------------- Captured stderr setup -----------------------------
2023-02-24T08:55:11.3957224Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235082240 and name "None"
2023-02-24T08:55:11.3957757Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235078144 and name "None"
2023-02-24T08:55:11.3967323Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235074048 and name "None"
2023-02-24T08:55:11.3973986Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235069952 and name "None"
2023-02-24T08:55:11.3974541Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235065856 and name "None"
2023-02-24T08:55:11.3977904Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235061760 and name "None"
2023-02-24T08:55:11.3978382Z [DEBUG:MainProcess:MainThread] ProcessPoolExecutor is setup
2023-02-24T08:55:11.3982676Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579234779136 and name "None"
2023-02-24T08:55:11.3986426Z [DEBUG:MainProcess:MainThread] launched python with pid 3357 and cmd:
2023-02-24T08:55:11.3987256Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-353', '--pipe', '32']
2023-02-24T08:55:11.3994135Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579234775040 and name "None"
2023-02-24T08:55:11.3999946Z [DEBUG:MainProcess:MainThread] launched python with pid 3358 and cmd:
2023-02-24T08:55:11.4000756Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-354', '--pipe', '33']
2023-02-24T08:55:11.4006061Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579234770944 and name "None"
2023-02-24T08:55:11.4006556Z [DEBUG:MainProcess:MainThread] launched python with pid 3359 and cmd:
2023-02-24T08:55:11.4010391Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-355', '--pipe', '34']
2023-02-24T08:55:11.4014200Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579234766848 and name "None"
2023-02-24T08:55:11.4014711Z [DEBUG:MainProcess:MainThread] launched python with pid 3360 and cmd:
2023-02-24T08:55:11.4019257Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-356', '--pipe', '35']
2023-02-24T08:55:11.4023593Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579234762752 and name "None"
2023-02-24T08:55:11.4024113Z [DEBUG:MainProcess:MainThread] launched python with pid 3361 and cmd:
2023-02-24T08:55:11.4028395Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-357', '--pipe', '36']
2023-02-24T08:55:11.4029397Z [DEBUG:MainProcess:MainThread] Adjusted process count to 5: [('LokyProcess-353', 3357), ('LokyProcess-354', 3358), ('LokyProcess-355', 3359), ('LokyProcess-356', 3360), ('LokyProcess-357', 3361)]
2023-02-24T08:55:11.4032838Z [DEBUG:MainProcess:MainThread] _start_executor_manager_thread called
2023-02-24T08:55:11.4037114Z [DEBUG:MainProcess:ExecutorManagerThread] Queue._start_thread()
2023-02-24T08:55:11.4037562Z [DEBUG:MainProcess:ExecutorManagerThread] doing self._thread.start()
2023-02-24T08:55:11.4041641Z [DEBUG:MainProcess:QueueFeederThread] starting thread to feed data to pipe
2023-02-24T08:55:11.4045322Z [DEBUG:MainProcess:ExecutorManagerThread] ... done self._thread.start()
2023-02-24T08:55:11.4046095Z [DEBUG:LokyProcess-353:MainThread] recreated blocker with handle 140579235078144 and name "/loky-1790-2ue004yf"
2023-02-24T08:55:11.4049577Z [DEBUG:LokyProcess-353:MainThread] recreated blocker with handle 140579235074048 and name "/loky-1790-3kjsb678"
2023-02-24T08:55:11.4050449Z [DEBUG:LokyProcess-353:MainThread] recreated blocker with handle 140579235069952 and name "/loky-1790-7t1_3clx"
2023-02-24T08:55:11.4054647Z [DEBUG:LokyProcess-353:MainThread] recreated blocker with handle 140579235065856 and name "/loky-1790-cu8szvj4"
2023-02-24T08:55:11.4058321Z [DEBUG:LokyProcess-353:MainThread] recreated blocker with handle 140579235061760 and name "/loky-1790-_h8of_52"
2023-02-24T08:55:11.4059241Z [DEBUG:LokyProcess-356:MainThread] recreated blocker with handle 140579235078144 and name "/loky-1790-2ue004yf"
2023-02-24T08:55:11.4063700Z [DEBUG:LokyProcess-356:MainThread] recreated blocker with handle 140579235074048 and name "/loky-1790-3kjsb678"
2023-02-24T08:55:11.4067973Z [DEBUG:LokyProcess-356:MainThread] recreated blocker with handle 140579235069952 and name "/loky-1790-7t1_3clx"
2023-02-24T08:55:11.4068774Z [DEBUG:LokyProcess-356:MainThread] recreated blocker with handle 140579235065856 and name "/loky-1790-cu8szvj4"
2023-02-24T08:55:11.4072570Z [DEBUG:LokyProcess-356:MainThread] recreated blocker with handle 140579235061760 and name "/loky-1790-_h8of_52"
2023-02-24T08:55:11.4076096Z [DEBUG:LokyProcess-354:MainThread] recreated blocker with handle 140579235078144 and name "/loky-1790-2ue004yf"
2023-02-24T08:55:11.4076934Z [DEBUG:LokyProcess-354:MainThread] recreated blocker with handle 140579235074048 and name "/loky-1790-3kjsb678"
2023-02-24T08:55:11.4080457Z [DEBUG:LokyProcess-354:MainThread] recreated blocker with handle 140579235069952 and name "/loky-1790-7t1_3clx"
2023-02-24T08:55:11.4081245Z [DEBUG:LokyProcess-354:MainThread] recreated blocker with handle 140579235065856 and name "/loky-1790-cu8szvj4"
2023-02-24T08:55:11.4085805Z [DEBUG:LokyProcess-354:MainThread] recreated blocker with handle 140579235061760 and name "/loky-1790-_h8of_52"
2023-02-24T08:55:11.4089701Z [DEBUG:LokyProcess-355:MainThread] recreated blocker with handle 140579235078144 and name "/loky-1790-2ue004yf"
2023-02-24T08:55:11.4090583Z [DEBUG:LokyProcess-355:MainThread] recreated blocker with handle 140579235074048 and name "/loky-1790-3kjsb678"
2023-02-24T08:55:11.4095199Z [DEBUG:LokyProcess-355:MainThread] recreated blocker with handle 140579235069952 and name "/loky-1790-7t1_3clx"
2023-02-24T08:55:11.4099273Z [DEBUG:LokyProcess-355:MainThread] recreated blocker with handle 140579235065856 and name "/loky-1790-cu8szvj4"
2023-02-24T08:55:11.4100116Z [DEBUG:LokyProcess-355:MainThread] recreated blocker with handle 140579235061760 and name "/loky-1790-_h8of_52"
2023-02-24T08:55:11.4103586Z [DEBUG:LokyProcess-357:MainThread] recreated blocker with handle 140579235078144 and name "/loky-1790-2ue004yf"
2023-02-24T08:55:11.4104377Z [DEBUG:LokyProcess-357:MainThread] recreated blocker with handle 140579235074048 and name "/loky-1790-3kjsb678"
2023-02-24T08:55:11.4108845Z [DEBUG:LokyProcess-357:MainThread] recreated blocker with handle 140579235069952 and name "/loky-1790-7t1_3clx"
2023-02-24T08:55:11.4146554Z [DEBUG:LokyProcess-357:MainThread] recreated blocker with handle 140579235065856 and name "/loky-1790-cu8szvj4"
2023-02-24T08:55:11.4147521Z [DEBUG:LokyProcess-357:MainThread] recreated blocker with handle 140579235061760 and name "/loky-1790-_h8of_52"
2023-02-24T08:55:11.4158753Z [DEBUG:LokyProcess-353:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.4159796Z [DEBUG:LokyProcess-353:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.4163377Z [DEBUG:LokyProcess-353:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.4164296Z [DEBUG:LokyProcess-353:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.4165121Z [DEBUG:LokyProcess-353:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.4165881Z [DEBUG:LokyProcess-353:MainThread] recreated blocker with handle 140579235082240 and name "/loky-1790-bqbmgea3"
2023-02-24T08:55:11.4168928Z [DEBUG:LokyProcess-353:MainThread] recreated blocker with handle 140579234779136 and name "/loky-1790-qp6lcu6i"
2023-02-24T08:55:11.4169673Z [INFO:LokyProcess-353:MainThread] child process calling self.run()
2023-02-24T08:55:11.4170467Z [DEBUG:LokyProcess-353:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.4173612Z [DEBUG:LokyProcess-353:MainThread] psutil return memory size: 30572544
2023-02-24T08:55:11.4174347Z [DEBUG:LokyProcess-356:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.4176094Z [DEBUG:LokyProcess-356:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.4179673Z [DEBUG:LokyProcess-356:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.4180491Z [DEBUG:LokyProcess-356:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.4184652Z [DEBUG:LokyProcess-356:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.4185471Z [DEBUG:LokyProcess-356:MainThread] recreated blocker with handle 140579235082240 and name "/loky-1790-bqbmgea3"
2023-02-24T08:55:11.4186299Z [DEBUG:LokyProcess-356:MainThread] recreated blocker with handle 140579234766848 and name "/loky-1790-8ec6tjfw"
2023-02-24T08:55:11.4189156Z [INFO:LokyProcess-356:MainThread] child process calling self.run()
2023-02-24T08:55:11.4189779Z [DEBUG:LokyProcess-356:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.4190540Z [DEBUG:LokyProcess-354:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.4193187Z [DEBUG:LokyProcess-354:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.4194006Z [DEBUG:LokyProcess-354:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.4194948Z [DEBUG:LokyProcess-354:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.4197366Z [DEBUG:LokyProcess-354:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.4198231Z [DEBUG:LokyProcess-354:MainThread] recreated blocker with handle 140579235082240 and name "/loky-1790-bqbmgea3"
2023-02-24T08:55:11.4201079Z [DEBUG:LokyProcess-354:MainThread] recreated blocker with handle 140579234775040 and name "/loky-1790-fdvexoxq"
2023-02-24T08:55:11.4201864Z [INFO:LokyProcess-354:MainThread] child process calling self.run()
2023-02-24T08:55:11.4204858Z [DEBUG:LokyProcess-354:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.4209650Z [DEBUG:LokyProcess-357:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.4210848Z [DEBUG:LokyProcess-357:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.4211798Z [DEBUG:LokyProcess-357:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.4212626Z [DEBUG:LokyProcess-357:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.4215550Z [DEBUG:LokyProcess-357:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.4218252Z [DEBUG:LokyProcess-357:MainThread] recreated blocker with handle 140579235082240 and name "/loky-1790-bqbmgea3"
2023-02-24T08:55:11.4219109Z [DEBUG:LokyProcess-357:MainThread] recreated blocker with handle 140579234762752 and name "/loky-1790-u06x8ffp"
2023-02-24T08:55:11.4219861Z [INFO:LokyProcess-357:MainThread] child process calling self.run()
2023-02-24T08:55:11.4222437Z [DEBUG:LokyProcess-357:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.4223259Z [DEBUG:LokyProcess-355:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.4227698Z [DEBUG:LokyProcess-355:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.4228525Z [DEBUG:LokyProcess-355:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.4232224Z [DEBUG:LokyProcess-355:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.4235507Z [DEBUG:LokyProcess-355:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.4236311Z [DEBUG:LokyProcess-355:MainThread] recreated blocker with handle 140579235082240 and name "/loky-1790-bqbmgea3"
2023-02-24T08:55:11.4238391Z [DEBUG:LokyProcess-355:MainThread] recreated blocker with handle 140579234770944 and name "/loky-1790-jja7nnn2"
2023-02-24T08:55:11.4240963Z [INFO:LokyProcess-355:MainThread] child process calling self.run()
2023-02-24T08:55:11.4241692Z [DEBUG:LokyProcess-355:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.4243790Z ____ ERROR at teardown of TestsProcessPoolLokyShutdown.test_hang_issue12364 ____
2023-02-24T08:55:11.4244054Z
2023-02-24T08:55:11.4246736Z self = <tests.test_process_executor_loky.TestsProcessPoolLokyShutdown object at 0x7fdb2786fe50>
2023-02-24T08:55:11.4247360Z method = <bound method ExecutorShutdownTest.test_hang_issue12364 of <tests.test_process_executor_loky.TestsProcessPoolLokyShutdown object at 0x7fdb2786fe50>>
2023-02-24T08:55:11.4251057Z
2023-02-24T08:55:11.4251336Z def teardown_method(self, method):
2023-02-24T08:55:11.4253383Z # Make sure executor is not broken if it should not be
2023-02-24T08:55:11.4253737Z executor = getattr(self, "executor", None)
2023-02-24T08:55:11.4258767Z if executor is not None:
2023-02-24T08:55:11.4320966Z try:
2023-02-24T08:55:11.4321403Z # old pytest markers:
2023-02-24T08:55:11.4321806Z expect_broken_pool = hasattr(method, "broken_pool")
2023-02-24T08:55:11.4322154Z # new pytest markers:
2023-02-24T08:55:11.4322537Z for mark in getattr(method, "pytestmark", []):
2023-02-24T08:55:11.4322937Z if mark.name == "broken_pool":
2023-02-24T08:55:11.4323268Z expect_broken_pool = True
2023-02-24T08:55:11.4327892Z
2023-02-24T08:55:11.4328202Z if expect_broken_pool:
2023-02-24T08:55:11.4328558Z for _ in range(10):
2023-02-24T08:55:11.4328906Z # The executor manager thread can take some time to
2023-02-24T08:55:11.4329321Z # mark the executor broken.
2023-02-24T08:55:11.4329729Z is_actually_broken = executor._flags.broken is not None
2023-02-24T08:55:11.4330096Z if is_actually_broken:
2023-02-24T08:55:11.4334259Z break
2023-02-24T08:55:11.4334576Z sleep(0.1)
2023-02-24T08:55:11.4334896Z else:
2023-02-24T08:55:11.4335186Z raise AssertionError(
2023-02-24T08:55:11.4335592Z "The executor was not flagged broken at the end of "
2023-02-24T08:55:11.4336015Z f" {method.__qualname__} as expected."
2023-02-24T08:55:11.4336330Z )
2023-02-24T08:55:11.4339601Z else:
2023-02-24T08:55:11.4339964Z # Check that the executor is not broken right away to avoid
2023-02-24T08:55:11.4340421Z # wasting CI time. False negative should be very rare.
2023-02-24T08:55:11.4340825Z is_actually_broken = executor._flags.broken is not None
2023-02-24T08:55:11.4341253Z assert not is_actually_broken
2023-02-24T08:55:11.4341600Z finally:
2023-02-24T08:55:11.4341942Z # Always shutdown the executor, with SIGKILL if the executor
2023-02-24T08:55:11.4345057Z # is actually broken.
2023-02-24T08:55:11.4345430Z kill_workers = executor._flags.broken is not None
2023-02-24T08:55:11.4345822Z t_start = time.time()
2023-02-24T08:55:11.4346181Z executor.shutdown(wait=True, kill_workers=kill_workers)
2023-02-24T08:55:11.4347015Z dt = time.time() - t_start
2023-02-24T08:55:11.4347567Z assert dt < 10, "Executor took too long to shutdown"
2023-02-24T08:55:11.4347946Z > _check_subprocesses_number(executor, 0)
2023-02-24T08:55:11.4348156Z
2023-02-24T08:55:11.4351500Z dt = 0.09300041198730469
2023-02-24T08:55:11.4352033Z executor = <loky.process_executor.ProcessPoolExecutor object at 0x7fdb274735b0>
2023-02-24T08:55:11.4352425Z expect_broken_pool = False
2023-02-24T08:55:11.4352778Z is_actually_broken = False
2023-02-24T08:55:11.4353074Z kill_workers = False
2023-02-24T08:55:11.4353622Z method = <bound method ExecutorShutdownTest.test_hang_issue12364 of <tests.test_process_executor_loky.TestsProcessPoolLokyShutdown object at 0x7fdb2786fe50>>
2023-02-24T08:55:11.4354238Z self = <tests.test_process_executor_loky.TestsProcessPoolLokyShutdown object at 0x7fdb2786fe50>
2023-02-24T08:55:11.4358007Z t_start = 1677228910.1175008
2023-02-24T08:55:11.4358191Z
2023-02-24T08:55:11.4358534Z tests/_executor_mixin.py:223:
2023-02-24T08:55:11.4358904Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
2023-02-24T08:55:11.4359361Z tests/_executor_mixin.py:125: in _check_subprocesses_number
2023-02-24T08:55:11.4359749Z raise e
2023-02-24T08:55:11.4360054Z children_pids = {3302, 3303, 3304, 3305}
2023-02-24T08:55:11.4363543Z executor = <loky.process_executor.ProcessPoolExecutor object at 0x7fdb274735b0>
2023-02-24T08:55:11.4363986Z expected_max_process_number = None
2023-02-24T08:55:11.4364364Z expected_process_number = 0
2023-02-24T08:55:11.4364662Z patience = 10
2023-02-24T08:55:11.4365810Z pids_cmdlines = [(3302, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-344 --pi... '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-347 --pipe 29')]
2023-02-24T08:55:11.4366543Z trial_idx = 9
2023-02-24T08:55:11.4369422Z worker_pids = set()
2023-02-24T08:55:11.4369802Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
2023-02-24T08:55:11.4370018Z
2023-02-24T08:55:11.4370508Z executor = <loky.process_executor.ProcessPoolExecutor object at 0x7fdb274735b0>
2023-02-24T08:55:11.4371023Z expected_process_number = 0, expected_max_process_number = None, patience = 10
2023-02-24T08:55:11.4373319Z
2023-02-24T08:55:11.4373586Z def _check_subprocesses_number(
2023-02-24T08:55:11.4381236Z executor=None,
2023-02-24T08:55:11.4384232Z expected_process_number=None,
2023-02-24T08:55:11.4384606Z expected_max_process_number=None,
2023-02-24T08:55:11.4384964Z patience=10,
2023-02-24T08:55:11.4385222Z ):
2023-02-24T08:55:11.4385527Z if not psutil:
2023-02-24T08:55:11.4385878Z # psutil is not installed, we cannot check the number of subprocesses
2023-02-24T08:55:11.4386272Z return
2023-02-24T08:55:11.4386515Z
2023-02-24T08:55:11.4389698Z for trial_idx in range(patience):
2023-02-24T08:55:11.4390045Z try:
2023-02-24T08:55:11.4390356Z # Wait for terminating processes to disappear
2023-02-24T08:55:11.4390784Z pids_cmdlines = _running_children_pids_with_cmdline(
2023-02-24T08:55:11.4391133Z psutil.Process()
2023-02-24T08:55:11.4391455Z )
2023-02-24T08:55:11.4391770Z children_pids = {pid for pid, _ in pids_cmdlines}
2023-02-24T08:55:11.4394476Z if executor is not None:
2023-02-24T08:55:11.4394823Z worker_pids = set(executor._processes.keys())
2023-02-24T08:55:11.4395270Z # Consistency check: all workers should be in the children list
2023-02-24T08:55:11.4395714Z assert worker_pids.issubset(children_pids)
2023-02-24T08:55:11.4396036Z else:
2023-02-24T08:55:11.4396420Z # Bypass pids checks when executor has been garbage collected
2023-02-24T08:55:11.4396910Z worker_pids = children_pids
2023-02-24T08:55:11.4400494Z if expected_process_number is not None:
2023-02-24T08:55:11.4400868Z > assert (
2023-02-24T08:55:11.4401203Z len(children_pids) == expected_process_number
2023-02-24T08:55:11.4401680Z ), pids_cmdlines
2023-02-24T08:55:11.4403334Z E AssertionError: [(3302, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-344 --pipe 26'), (3303, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-345 --pipe 27'), (3304, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-346 --pipe 28'), (3305, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-347 --pipe 29')]
2023-02-24T08:55:11.4404329Z
2023-02-24T08:55:11.4407214Z children_pids = {3302, 3303, 3304, 3305}
2023-02-24T08:55:11.4407653Z executor = <loky.process_executor.ProcessPoolExecutor object at 0x7fdb274735b0>
2023-02-24T08:55:11.4408109Z expected_max_process_number = None
2023-02-24T08:55:11.4408481Z expected_process_number = 0
2023-02-24T08:55:11.4408773Z patience = 10
2023-02-24T08:55:11.4409863Z pids_cmdlines = [(3302, '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-344 --pi... '/home/vsts/work/1/s/.tox/py39/bin/python -m loky.backend.popen_loky_posix --process-name LokyProcess-347 --pipe 29')]
2023-02-24T08:55:11.4413619Z trial_idx = 9
2023-02-24T08:55:11.4413935Z worker_pids = set()
2023-02-24T08:55:11.4414152Z
2023-02-24T08:55:11.4414464Z tests/_executor_mixin.py:103: AssertionError
2023-02-24T08:55:11.4415122Z ---------------------------- Captured stderr setup -----------------------------
2023-02-24T08:55:11.4415618Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235082240 and name "None"
2023-02-24T08:55:11.4416182Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235078144 and name "None"
2023-02-24T08:55:11.4420214Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235074048 and name "None"
2023-02-24T08:55:11.4420744Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235069952 and name "None"
2023-02-24T08:55:11.4421296Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235065856 and name "None"
2023-02-24T08:55:11.4421791Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235061760 and name "None"
2023-02-24T08:55:11.4422294Z [DEBUG:MainProcess:MainThread] ProcessPoolExecutor is setup
2023-02-24T08:55:11.4422800Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579234779136 and name "None"
2023-02-24T08:55:11.4423275Z [DEBUG:MainProcess:MainThread] launched python with pid 3357 and cmd:
2023-02-24T08:55:11.4426622Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-353', '--pipe', '32']
2023-02-24T08:55:11.4427267Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579234775040 and name "None"
2023-02-24T08:55:11.4427747Z [DEBUG:MainProcess:MainThread] launched python with pid 3358 and cmd:
2023-02-24T08:55:11.4428537Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-354', '--pipe', '33']
2023-02-24T08:55:11.4429110Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579234770944 and name "None"
2023-02-24T08:55:11.4429637Z [DEBUG:MainProcess:MainThread] launched python with pid 3359 and cmd:
2023-02-24T08:55:11.4432829Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-355', '--pipe', '34']
2023-02-24T08:55:11.4433432Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579234766848 and name "None"
2023-02-24T08:55:11.4433951Z [DEBUG:MainProcess:MainThread] launched python with pid 3360 and cmd:
2023-02-24T08:55:11.4434857Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-356', '--pipe', '35']
2023-02-24T08:55:11.4435430Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579234762752 and name "None"
2023-02-24T08:55:11.4436027Z [DEBUG:MainProcess:MainThread] launched python with pid 3361 and cmd:
2023-02-24T08:55:11.4436762Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-357', '--pipe', '36']
2023-02-24T08:55:11.4442004Z [DEBUG:MainProcess:MainThread] Adjusted process count to 5: [('LokyProcess-353', 3357), ('LokyProcess-354', 3358), ('LokyProcess-355', 3359), ('LokyProcess-356', 3360), ('LokyProcess-357', 3361)]
2023-02-24T08:55:11.4442713Z [DEBUG:MainProcess:MainThread] _start_executor_manager_thread called
2023-02-24T08:55:11.4443286Z [DEBUG:MainProcess:ExecutorManagerThread] Queue._start_thread()
2023-02-24T08:55:11.4443731Z [DEBUG:MainProcess:ExecutorManagerThread] doing self._thread.start()
2023-02-24T08:55:11.4444235Z [DEBUG:MainProcess:QueueFeederThread] starting thread to feed data to pipe
2023-02-24T08:55:11.4444692Z [DEBUG:MainProcess:ExecutorManagerThread] ... done self._thread.start()
2023-02-24T08:55:11.4447716Z [DEBUG:LokyProcess-353:MainThread] recreated blocker with handle 140579235078144 and name "/loky-1790-2ue004yf"
2023-02-24T08:55:11.4448549Z [DEBUG:LokyProcess-353:MainThread] recreated blocker with handle 140579235074048 and name "/loky-1790-3kjsb678"
2023-02-24T08:55:11.4449330Z [DEBUG:LokyProcess-353:MainThread] recreated blocker with handle 140579235069952 and name "/loky-1790-7t1_3clx"
2023-02-24T08:55:11.4450141Z [DEBUG:LokyProcess-353:MainThread] recreated blocker with handle 140579235065856 and name "/loky-1790-cu8szvj4"
2023-02-24T08:55:11.4451033Z [DEBUG:LokyProcess-353:MainThread] recreated blocker with handle 140579235061760 and name "/loky-1790-_h8of_52"
2023-02-24T08:55:11.4451853Z [DEBUG:LokyProcess-356:MainThread] recreated blocker with handle 140579235078144 and name "/loky-1790-2ue004yf"
2023-02-24T08:55:11.4456514Z [DEBUG:LokyProcess-356:MainThread] recreated blocker with handle 140579235074048 and name "/loky-1790-3kjsb678"
2023-02-24T08:55:11.4457302Z [DEBUG:LokyProcess-356:MainThread] recreated blocker with handle 140579235069952 and name "/loky-1790-7t1_3clx"
2023-02-24T08:55:11.4458139Z [DEBUG:LokyProcess-356:MainThread] recreated blocker with handle 140579235065856 and name "/loky-1790-cu8szvj4"
2023-02-24T08:55:11.4458948Z [DEBUG:LokyProcess-356:MainThread] recreated blocker with handle 140579235061760 and name "/loky-1790-_h8of_52"
2023-02-24T08:55:11.4459716Z [DEBUG:LokyProcess-354:MainThread] recreated blocker with handle 140579235078144 and name "/loky-1790-2ue004yf"
2023-02-24T08:55:11.4460534Z [DEBUG:LokyProcess-354:MainThread] recreated blocker with handle 140579235074048 and name "/loky-1790-3kjsb678"
2023-02-24T08:55:11.4461291Z [DEBUG:LokyProcess-354:MainThread] recreated blocker with handle 140579235069952 and name "/loky-1790-7t1_3clx"
2023-02-24T08:55:11.4467211Z [DEBUG:LokyProcess-354:MainThread] recreated blocker with handle 140579235065856 and name "/loky-1790-cu8szvj4"
2023-02-24T08:55:11.4468020Z [DEBUG:LokyProcess-354:MainThread] recreated blocker with handle 140579235061760 and name "/loky-1790-_h8of_52"
2023-02-24T08:55:11.4468787Z [DEBUG:LokyProcess-355:MainThread] recreated blocker with handle 140579235078144 and name "/loky-1790-2ue004yf"
2023-02-24T08:55:11.4469600Z [DEBUG:LokyProcess-355:MainThread] recreated blocker with handle 140579235074048 and name "/loky-1790-3kjsb678"
2023-02-24T08:55:11.4470404Z [DEBUG:LokyProcess-355:MainThread] recreated blocker with handle 140579235069952 and name "/loky-1790-7t1_3clx"
2023-02-24T08:55:11.4471166Z [DEBUG:LokyProcess-355:MainThread] recreated blocker with handle 140579235065856 and name "/loky-1790-cu8szvj4"
2023-02-24T08:55:11.4474507Z [DEBUG:LokyProcess-355:MainThread] recreated blocker with handle 140579235061760 and name "/loky-1790-_h8of_52"
2023-02-24T08:55:11.4475384Z [DEBUG:LokyProcess-357:MainThread] recreated blocker with handle 140579235078144 and name "/loky-1790-2ue004yf"
2023-02-24T08:55:11.4476198Z [DEBUG:LokyProcess-357:MainThread] recreated blocker with handle 140579235074048 and name "/loky-1790-3kjsb678"
2023-02-24T08:55:11.4477088Z [DEBUG:LokyProcess-357:MainThread] recreated blocker with handle 140579235069952 and name "/loky-1790-7t1_3clx"
2023-02-24T08:55:11.4477861Z [DEBUG:LokyProcess-357:MainThread] recreated blocker with handle 140579235065856 and name "/loky-1790-cu8szvj4"
2023-02-24T08:55:11.4478715Z [DEBUG:LokyProcess-357:MainThread] recreated blocker with handle 140579235061760 and name "/loky-1790-_h8of_52"
2023-02-24T08:55:11.4484691Z [DEBUG:LokyProcess-353:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.4485497Z [DEBUG:LokyProcess-353:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.4486323Z [DEBUG:LokyProcess-353:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.4487136Z [DEBUG:LokyProcess-353:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.4487902Z [DEBUG:LokyProcess-353:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.4488712Z [DEBUG:LokyProcess-353:MainThread] recreated blocker with handle 140579235082240 and name "/loky-1790-bqbmgea3"
2023-02-24T08:55:11.4489480Z [DEBUG:LokyProcess-353:MainThread] recreated blocker with handle 140579234779136 and name "/loky-1790-qp6lcu6i"
2023-02-24T08:55:11.4494120Z [INFO:LokyProcess-353:MainThread] child process calling self.run()
2023-02-24T08:55:11.4494801Z [DEBUG:LokyProcess-353:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.4495427Z [DEBUG:LokyProcess-353:MainThread] psutil return memory size: 30572544
2023-02-24T08:55:11.4499336Z [DEBUG:LokyProcess-356:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.4500131Z [DEBUG:LokyProcess-356:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.4508106Z [DEBUG:LokyProcess-356:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.4508963Z [DEBUG:LokyProcess-356:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.4509748Z [DEBUG:LokyProcess-356:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.4512852Z [DEBUG:LokyProcess-356:MainThread] recreated blocker with handle 140579235082240 and name "/loky-1790-bqbmgea3"
2023-02-24T08:55:11.4513667Z [DEBUG:LokyProcess-356:MainThread] recreated blocker with handle 140579234766848 and name "/loky-1790-8ec6tjfw"
2023-02-24T08:55:11.4514344Z [INFO:LokyProcess-356:MainThread] child process calling self.run()
2023-02-24T08:55:11.4519483Z [DEBUG:LokyProcess-356:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.4520208Z [DEBUG:LokyProcess-354:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.4521014Z [DEBUG:LokyProcess-354:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.4521838Z [DEBUG:LokyProcess-354:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.4522605Z [DEBUG:LokyProcess-354:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.4523483Z [DEBUG:LokyProcess-354:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.4527978Z [DEBUG:LokyProcess-354:MainThread] recreated blocker with handle 140579235082240 and name "/loky-1790-bqbmgea3"
2023-02-24T08:55:11.4528800Z [DEBUG:LokyProcess-354:MainThread] recreated blocker with handle 140579234775040 and name "/loky-1790-fdvexoxq"
2023-02-24T08:55:11.4529636Z [INFO:LokyProcess-354:MainThread] child process calling self.run()
2023-02-24T08:55:11.4530247Z [DEBUG:LokyProcess-354:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.4531164Z [DEBUG:LokyProcess-357:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.4532058Z [DEBUG:LokyProcess-357:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.4532828Z [DEBUG:LokyProcess-357:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.4536088Z [DEBUG:LokyProcess-357:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.4536841Z [DEBUG:LokyProcess-357:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.4537653Z [DEBUG:LokyProcess-357:MainThread] recreated blocker with handle 140579235082240 and name "/loky-1790-bqbmgea3"
2023-02-24T08:55:11.4547993Z [DEBUG:LokyProcess-357:MainThread] recreated blocker with handle 140579234762752 and name "/loky-1790-u06x8ffp"
2023-02-24T08:55:11.4548680Z [INFO:LokyProcess-357:MainThread] child process calling self.run()
2023-02-24T08:55:11.4549348Z [DEBUG:LokyProcess-357:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.4550097Z [DEBUG:LokyProcess-355:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.4550861Z [DEBUG:LokyProcess-355:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.4555299Z [DEBUG:LokyProcess-355:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.4556080Z [DEBUG:LokyProcess-355:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.4556896Z [DEBUG:LokyProcess-355:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.4559997Z [DEBUG:LokyProcess-355:MainThread] recreated blocker with handle 140579235082240 and name "/loky-1790-bqbmgea3"
2023-02-24T08:55:11.4560790Z [DEBUG:LokyProcess-355:MainThread] recreated blocker with handle 140579234770944 and name "/loky-1790-jja7nnn2"
2023-02-24T08:55:11.4561519Z [INFO:LokyProcess-355:MainThread] child process calling self.run()
2023-02-24T08:55:11.4566286Z [DEBUG:LokyProcess-355:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.4566980Z --------------------------- Captured stderr teardown ---------------------------
2023-02-24T08:55:11.4567569Z [DEBUG:MainProcess:MainThread] shutting down executor <loky.process_executor.ProcessPoolExecutor object at 0x7fdb274735b0>
2023-02-24T08:55:11.4568295Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-353
2023-02-24T08:55:11.4569027Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-354
2023-02-24T08:55:11.4571889Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-355
2023-02-24T08:55:11.4572640Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-356
2023-02-24T08:55:11.4573367Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-357
2023-02-24T08:55:11.4573853Z [DEBUG:MainProcess:ExecutorManagerThread] found 5 processes to stop
2023-02-24T08:55:11.4574356Z [DEBUG:MainProcess:ExecutorManagerThread] sent 5 sentinels to the call queue
2023-02-24T08:55:11.4578146Z [DEBUG:MainProcess:ExecutorManagerThread] closing call_queue
2023-02-24T08:55:11.4578611Z [DEBUG:MainProcess:ExecutorManagerThread] telling queue thread to quit
2023-02-24T08:55:11.4579098Z [DEBUG:MainProcess:ExecutorManagerThread] Queue.join_thread()
2023-02-24T08:55:11.4579530Z [DEBUG:MainProcess:ExecutorManagerThread] closing result_queue
2023-02-24T08:55:11.4580013Z [DEBUG:MainProcess:ExecutorManagerThread] closing thread_wakeup
2023-02-24T08:55:11.4580779Z [INFO:LokyProcess-353:MainThread] Shutting down worker on sentinel
2023-02-24T08:55:11.4581412Z [DEBUG:MainProcess:QueueFeederThread] feeder thread got sentinel -- exiting
2023-02-24T08:55:11.4585497Z [DEBUG:MainProcess:ExecutorManagerThread] joining 5 processes
2023-02-24T08:55:11.4586189Z [DEBUG:LokyProcess-353:MainThread] Exited cleanly
2023-02-24T08:55:11.4586871Z [DEBUG:MainProcess:ExecutorManagerThread] joining process LokyProcess-357 with pid 3361
2023-02-24T08:55:11.4587494Z [INFO:LokyProcess-353:MainThread] process shutting down
2023-02-24T08:55:11.4588169Z [DEBUG:LokyProcess-353:MainThread] running all "atexit" finalizers with priority >= 0
2023-02-24T08:55:11.4588867Z [DEBUG:LokyProcess-353:MainThread] running the remaining "atexit" finalizers
2023-02-24T08:55:11.4589485Z [INFO:LokyProcess-353:MainThread] process exiting with exitcode 0
2023-02-24T08:55:11.4592493Z [INFO:LokyProcess-356:MainThread] Shutting down worker on sentinel
2023-02-24T08:55:11.4593088Z [DEBUG:LokyProcess-356:MainThread] Exited cleanly
2023-02-24T08:55:11.4593700Z [INFO:LokyProcess-356:MainThread] process shutting down
2023-02-24T08:55:11.4594369Z [DEBUG:LokyProcess-356:MainThread] running all "atexit" finalizers with priority >= 0
2023-02-24T08:55:11.4595027Z [DEBUG:LokyProcess-356:MainThread] running the remaining "atexit" finalizers
2023-02-24T08:55:11.4595695Z [INFO:LokyProcess-356:MainThread] process exiting with exitcode 0
2023-02-24T08:55:11.4596302Z [INFO:LokyProcess-354:MainThread] Shutting down worker on sentinel
2023-02-24T08:55:11.4601571Z [INFO:LokyProcess-357:MainThread] Shutting down worker on sentinel
2023-02-24T08:55:11.4602209Z [DEBUG:LokyProcess-354:MainThread] Exited cleanly
2023-02-24T08:55:11.4602775Z [INFO:LokyProcess-354:MainThread] process shutting down
2023-02-24T08:55:11.4603452Z [DEBUG:LokyProcess-354:MainThread] running all "atexit" finalizers with priority >= 0
2023-02-24T08:55:11.4604052Z [DEBUG:LokyProcess-357:MainThread] Exited cleanly
2023-02-24T08:55:11.4604703Z [DEBUG:LokyProcess-354:MainThread] running the remaining "atexit" finalizers
2023-02-24T08:55:11.4605300Z [INFO:LokyProcess-357:MainThread] process shutting down
2023-02-24T08:55:11.4611412Z [DEBUG:LokyProcess-357:MainThread] running all "atexit" finalizers with priority >= 0
2023-02-24T08:55:11.4612097Z [INFO:LokyProcess-354:MainThread] process exiting with exitcode 0
2023-02-24T08:55:11.4612727Z [DEBUG:LokyProcess-357:MainThread] running the remaining "atexit" finalizers
2023-02-24T08:55:11.4613400Z [INFO:LokyProcess-357:MainThread] process exiting with exitcode 0
2023-02-24T08:55:11.4614009Z [INFO:LokyProcess-355:MainThread] Shutting down worker on sentinel
2023-02-24T08:55:11.4618178Z [DEBUG:LokyProcess-355:MainThread] Exited cleanly
2023-02-24T08:55:11.4618824Z [INFO:LokyProcess-355:MainThread] process shutting down
2023-02-24T08:55:11.4619452Z [DEBUG:LokyProcess-355:MainThread] running all "atexit" finalizers with priority >= 0
2023-02-24T08:55:11.4620149Z [DEBUG:LokyProcess-355:MainThread] running the remaining "atexit" finalizers
2023-02-24T08:55:11.4620771Z [INFO:LokyProcess-355:MainThread] process exiting with exitcode 0
2023-02-24T08:55:11.4621469Z [DEBUG:MainProcess:ExecutorManagerThread] joining process LokyProcess-356 with pid 3360
2023-02-24T08:55:11.4622141Z [DEBUG:MainProcess:ExecutorManagerThread] joining process LokyProcess-355 with pid 3359
2023-02-24T08:55:11.4625891Z [DEBUG:MainProcess:ExecutorManagerThread] joining process LokyProcess-354 with pid 3358
2023-02-24T08:55:11.4626615Z [DEBUG:MainProcess:ExecutorManagerThread] joining process LokyProcess-353 with pid 3357
2023-02-24T08:55:11.4627144Z [DEBUG:MainProcess:ExecutorManagerThread] executor management thread clean shutdown of 5 workers
2023-02-24T08:55:11.4627673Z =================================== FAILURES ===================================
2023-02-24T08:55:11.4628176Z ______ TestsProcessPoolLokyShutdown.test_shutdown_with_sys_exit_at_pickle ______
2023-02-24T08:55:11.4628438Z
2023-02-24T08:55:11.4628812Z self = <tests.test_process_executor_loky.TestsProcessPoolLokyShutdown object at 0x7fdb27926eb0>
2023-02-24T08:55:11.4633577Z
2023-02-24T08:55:11.4633893Z def test_shutdown_with_sys_exit_at_pickle(self):
2023-02-24T08:55:11.4634289Z self.executor.shutdown()
2023-02-24T08:55:11.4634632Z with self.executor_type(max_workers=4) as e:
2023-02-24T08:55:11.4635113Z > e.submit(id, ExitAtPickle())
2023-02-24T08:55:11.4635296Z
2023-02-24T08:55:11.4635681Z e = <loky.process_executor.ProcessPoolExecutor object at 0x7fdb2405a9a0>
2023-02-24T08:55:11.4636169Z self = <tests.test_process_executor_loky.TestsProcessPoolLokyShutdown object at 0x7fdb27926eb0>
2023-02-24T08:55:11.4638833Z
2023-02-24T08:55:11.4639142Z tests/_test_process_executor.py:119:
2023-02-24T08:55:11.4639571Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
2023-02-24T08:55:11.4640028Z /opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/concurrent/futures/_base.py:637: in __exit__
2023-02-24T08:55:11.4640501Z self.shutdown(wait=True)
2023-02-24T08:55:11.4640845Z exc_tb = None
2023-02-24T08:55:11.4641129Z exc_type = None
2023-02-24T08:55:11.4647428Z exc_val = None
2023-02-24T08:55:11.4647822Z self = <loky.process_executor.ProcessPoolExecutor object at 0x7fdb2405a9a0>
2023-02-24T08:55:11.4648300Z loky/process_executor.py:1288: in shutdown
2023-02-24T08:55:11.4648647Z executor_manager_thread.join()
2023-02-24T08:55:11.4649129Z executor_manager_thread = <_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>
2023-02-24T08:55:11.4649703Z executor_manager_thread_wakeup = <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>
2023-02-24T08:55:11.4650117Z kill_workers = False
2023-02-24T08:55:11.4652796Z self = <loky.process_executor.ProcessPoolExecutor object at 0x7fdb2405a9a0>
2023-02-24T08:55:11.4653190Z wait = True
2023-02-24T08:55:11.4653614Z /opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/threading.py:1060: in join
2023-02-24T08:55:11.4654064Z self._wait_for_tstate_lock()
2023-02-24T08:55:11.4654463Z self = <_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>
2023-02-24T08:55:11.4659575Z timeout = None
2023-02-24T08:55:11.4659931Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
2023-02-24T08:55:11.4660196Z
2023-02-24T08:55:11.4660538Z self = <_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>
2023-02-24T08:55:11.4661241Z block = True, timeout = -1
2023-02-24T08:55:11.4661424Z
2023-02-24T08:55:11.4661937Z def _wait_for_tstate_lock(self, block=True, timeout=-1):
2023-02-24T08:55:11.4662344Z # Issue #18808: wait for the thread state to be gone.
2023-02-24T08:55:11.4668484Z # At the end of the thread's life, after all knowledge of the thread
2023-02-24T08:55:11.4668960Z # is removed from C data structures, C code releases our _tstate_lock.
2023-02-24T08:55:11.4669471Z # This method passes its arguments to _tstate_lock.acquire().
2023-02-24T08:55:11.4669882Z # If the lock is acquired, the C code is done, and self._stop() is
2023-02-24T08:55:11.4670362Z # called. That sets ._is_stopped to True, and ._tstate_lock to None.
2023-02-24T08:55:11.4673025Z lock = self._tstate_lock
2023-02-24T08:55:11.4673343Z if lock is None:
2023-02-24T08:55:11.4673707Z # already determined that the C code is done
2023-02-24T08:55:11.4674044Z assert self._is_stopped
2023-02-24T08:55:11.4674410Z return
2023-02-24T08:55:11.4674656Z
2023-02-24T08:55:11.4674947Z try:
2023-02-24T08:55:11.4677810Z > if lock.acquire(block, timeout):
2023-02-24T08:55:11.4678170Z E Failed: Timeout >60.0s
2023-02-24T08:55:11.4678346Z
2023-02-24T08:55:11.4678645Z block = True
2023-02-24T08:55:11.4678974Z lock = <unlocked _thread.lock object at 0x7fdb2403b240>
2023-02-24T08:55:11.4679557Z self = <_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>
2023-02-24T08:55:11.4680140Z timeout = -1
2023-02-24T08:55:11.4680304Z
2023-02-24T08:55:11.4680656Z /opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/threading.py:1080: Failed
2023-02-24T08:55:11.4683746Z ---------------------------- Captured stderr setup -----------------------------
2023-02-24T08:55:11.4684284Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579355418624 and name "None"
2023-02-24T08:55:11.4684796Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579351658496 and name "None"
2023-02-24T08:55:11.4685349Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235098624 and name "None"
2023-02-24T08:55:11.4685846Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235094528 and name "None"
2023-02-24T08:55:11.4686393Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235090432 and name "None"
2023-02-24T08:55:11.4688516Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235086336 and name "None"
2023-02-24T08:55:11.4689004Z [DEBUG:MainProcess:MainThread] ProcessPoolExecutor is setup
2023-02-24T08:55:11.4689514Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235057664 and name "None"
2023-02-24T08:55:11.4689985Z [DEBUG:MainProcess:MainThread] launched python with pid 3293 and cmd:
2023-02-24T08:55:11.4690891Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-339', '--pipe', '26']
2023-02-24T08:55:11.4693767Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235053568 and name "None"
2023-02-24T08:55:11.4694266Z [DEBUG:MainProcess:MainThread] launched python with pid 3294 and cmd:
2023-02-24T08:55:11.4695077Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-340', '--pipe', '27']
2023-02-24T08:55:11.4695698Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235049472 and name "None"
2023-02-24T08:55:11.4696172Z [DEBUG:MainProcess:MainThread] launched python with pid 3295 and cmd:
2023-02-24T08:55:11.4696953Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-341', '--pipe', '28']
2023-02-24T08:55:11.4697530Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235045376 and name "None"
2023-02-24T08:55:11.4701011Z [DEBUG:MainProcess:MainThread] launched python with pid 3296 and cmd:
2023-02-24T08:55:11.4701818Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-342', '--pipe', '29']
2023-02-24T08:55:11.4702393Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235041280 and name "None"
2023-02-24T08:55:11.4702910Z [DEBUG:MainProcess:MainThread] launched python with pid 3297 and cmd:
2023-02-24T08:55:11.4703636Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-343', '--pipe', '30']
2023-02-24T08:55:11.4704663Z [DEBUG:MainProcess:MainThread] Adjusted process count to 5: [('LokyProcess-339', 3293), ('LokyProcess-340', 3294), ('LokyProcess-341', 3295), ('LokyProcess-342', 3296), ('LokyProcess-343', 3297)]
2023-02-24T08:55:11.4712649Z [DEBUG:MainProcess:MainThread] _start_executor_manager_thread called
2023-02-24T08:55:11.4713119Z [DEBUG:MainProcess:ExecutorManagerThread] Queue._start_thread()
2023-02-24T08:55:11.4713631Z [DEBUG:MainProcess:ExecutorManagerThread] doing self._thread.start()
2023-02-24T08:55:11.4714147Z [DEBUG:MainProcess:QueueFeederThread] starting thread to feed data to pipe
2023-02-24T08:55:11.4714621Z [DEBUG:MainProcess:ExecutorManagerThread] ... done self._thread.start()
2023-02-24T08:55:11.4715472Z [DEBUG:LokyProcess-342:MainThread] recreated blocker with handle 140579351658496 and name "/loky-1790-oxk_xfy6"
2023-02-24T08:55:11.4716287Z [DEBUG:LokyProcess-342:MainThread] recreated blocker with handle 140579235098624 and name "/loky-1790-nfpv8xsl"
2023-02-24T08:55:11.4719916Z [DEBUG:LokyProcess-342:MainThread] recreated blocker with handle 140579235094528 and name "/loky-1790-1omtcbbz"
2023-02-24T08:55:11.4720734Z [DEBUG:LokyProcess-342:MainThread] recreated blocker with handle 140579235090432 and name "/loky-1790-eknrtpls"
2023-02-24T08:55:11.4721596Z [DEBUG:LokyProcess-342:MainThread] recreated blocker with handle 140579235086336 and name "/loky-1790-lt9d1m08"
2023-02-24T08:55:11.4722419Z [DEBUG:LokyProcess-340:MainThread] recreated blocker with handle 140579351658496 and name "/loky-1790-oxk_xfy6"
2023-02-24T08:55:11.4723226Z [DEBUG:LokyProcess-340:MainThread] recreated blocker with handle 140579235098624 and name "/loky-1790-nfpv8xsl"
2023-02-24T08:55:11.4723998Z [DEBUG:LokyProcess-340:MainThread] recreated blocker with handle 140579235094528 and name "/loky-1790-1omtcbbz"
2023-02-24T08:55:11.4727993Z [DEBUG:LokyProcess-340:MainThread] recreated blocker with handle 140579235090432 and name "/loky-1790-eknrtpls"
2023-02-24T08:55:11.4728762Z [DEBUG:LokyProcess-340:MainThread] recreated blocker with handle 140579235086336 and name "/loky-1790-lt9d1m08"
2023-02-24T08:55:11.4729584Z [DEBUG:LokyProcess-339:MainThread] recreated blocker with handle 140579351658496 and name "/loky-1790-oxk_xfy6"
2023-02-24T08:55:11.4730487Z [DEBUG:LokyProcess-339:MainThread] recreated blocker with handle 140579235098624 and name "/loky-1790-nfpv8xsl"
2023-02-24T08:55:11.4731271Z [DEBUG:LokyProcess-339:MainThread] recreated blocker with handle 140579235094528 and name "/loky-1790-1omtcbbz"
2023-02-24T08:55:11.4734531Z [DEBUG:LokyProcess-339:MainThread] recreated blocker with handle 140579235090432 and name "/loky-1790-eknrtpls"
2023-02-24T08:55:11.4735356Z [DEBUG:LokyProcess-339:MainThread] recreated blocker with handle 140579235086336 and name "/loky-1790-lt9d1m08"
2023-02-24T08:55:11.4736126Z [DEBUG:LokyProcess-341:MainThread] recreated blocker with handle 140579351658496 and name "/loky-1790-oxk_xfy6"
2023-02-24T08:55:11.4736942Z [DEBUG:LokyProcess-341:MainThread] recreated blocker with handle 140579235098624 and name "/loky-1790-nfpv8xsl"
2023-02-24T08:55:11.4737701Z [DEBUG:LokyProcess-341:MainThread] recreated blocker with handle 140579235094528 and name "/loky-1790-1omtcbbz"
2023-02-24T08:55:11.4738508Z [DEBUG:LokyProcess-341:MainThread] recreated blocker with handle 140579235090432 and name "/loky-1790-eknrtpls"
2023-02-24T08:55:11.4741991Z [DEBUG:LokyProcess-341:MainThread] recreated blocker with handle 140579235086336 and name "/loky-1790-lt9d1m08"
2023-02-24T08:55:11.4742776Z [DEBUG:LokyProcess-343:MainThread] recreated blocker with handle 140579351658496 and name "/loky-1790-oxk_xfy6"
2023-02-24T08:55:11.4745837Z [DEBUG:LokyProcess-343:MainThread] recreated blocker with handle 140579235098624 and name "/loky-1790-nfpv8xsl"
2023-02-24T08:55:11.4749175Z [DEBUG:LokyProcess-343:MainThread] recreated blocker with handle 140579235094528 and name "/loky-1790-1omtcbbz"
2023-02-24T08:55:11.4749954Z [DEBUG:LokyProcess-343:MainThread] recreated blocker with handle 140579235090432 and name "/loky-1790-eknrtpls"
2023-02-24T08:55:11.4750779Z [DEBUG:LokyProcess-343:MainThread] recreated blocker with handle 140579235086336 and name "/loky-1790-lt9d1m08"
2023-02-24T08:55:11.4805953Z [DEBUG:LokyProcess-342:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.4807135Z [DEBUG:LokyProcess-342:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.4811874Z [DEBUG:LokyProcess-342:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.4812684Z [DEBUG:LokyProcess-342:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.4816014Z [DEBUG:LokyProcess-342:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.4818742Z [DEBUG:LokyProcess-342:MainThread] recreated blocker with handle 140579355418624 and name "/loky-1790-38bnqfa3"
2023-02-24T08:55:11.4819659Z [DEBUG:LokyProcess-342:MainThread] recreated blocker with handle 140579235045376 and name "/loky-1790-w_6n1w74"
2023-02-24T08:55:11.4822406Z [INFO:LokyProcess-342:MainThread] child process calling self.run()
2023-02-24T08:55:11.4823165Z [DEBUG:LokyProcess-342:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.4823785Z ----------------------------- Captured stderr call -----------------------------
2023-02-24T08:55:11.4826698Z [DEBUG:MainProcess:MainThread] shutting down executor <loky.process_executor.ProcessPoolExecutor object at 0x7fdb24053730>
2023-02-24T08:55:11.4827478Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-339
2023-02-24T08:55:11.4828233Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-340
2023-02-24T08:55:11.4830857Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-341
2023-02-24T08:55:11.4831595Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-342
2023-02-24T08:55:11.4832327Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-343
2023-02-24T08:55:11.4832813Z [DEBUG:MainProcess:ExecutorManagerThread] found 5 processes to stop
2023-02-24T08:55:11.4838460Z [DEBUG:MainProcess:ExecutorManagerThread] sent 5 sentinels to the call queue
2023-02-24T08:55:11.4838963Z [DEBUG:MainProcess:ExecutorManagerThread] closing call_queue
2023-02-24T08:55:11.4839401Z [DEBUG:MainProcess:ExecutorManagerThread] telling queue thread to quit
2023-02-24T08:55:11.4843893Z [DEBUG:MainProcess:ExecutorManagerThread] Queue.join_thread()
2023-02-24T08:55:11.4844379Z [DEBUG:MainProcess:ExecutorManagerThread] closing result_queue
2023-02-24T08:55:11.4844866Z [DEBUG:MainProcess:ExecutorManagerThread] closing thread_wakeup
2023-02-24T08:55:11.4845610Z [DEBUG:MainProcess:QueueFeederThread] feeder thread got sentinel -- exiting
2023-02-24T08:55:11.4848281Z [DEBUG:MainProcess:ExecutorManagerThread] joining 5 processes
2023-02-24T08:55:11.4848997Z [DEBUG:MainProcess:ExecutorManagerThread] joining process LokyProcess-343 with pid 3297
2023-02-24T08:55:11.4849643Z [DEBUG:LokyProcess-342:MainThread] psutil return memory size: 30466048
2023-02-24T08:55:11.4852484Z [INFO:LokyProcess-342:MainThread] Shutting down worker on sentinel
2023-02-24T08:55:11.4853068Z [DEBUG:LokyProcess-342:MainThread] Exited cleanly
2023-02-24T08:55:11.4853761Z [INFO:LokyProcess-342:MainThread] process shutting down
2023-02-24T08:55:11.4857930Z [DEBUG:LokyProcess-342:MainThread] running all "atexit" finalizers with priority >= 0
2023-02-24T08:55:11.4858647Z [DEBUG:LokyProcess-342:MainThread] running the remaining "atexit" finalizers
2023-02-24T08:55:11.4861887Z [INFO:LokyProcess-342:MainThread] process exiting with exitcode 0
2023-02-24T08:55:11.4862607Z [DEBUG:LokyProcess-341:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.4866655Z [DEBUG:LokyProcess-341:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.4867475Z [DEBUG:LokyProcess-341:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.4868244Z [DEBUG:LokyProcess-341:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.4870703Z [DEBUG:LokyProcess-341:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.4871521Z [DEBUG:LokyProcess-341:MainThread] recreated blocker with handle 140579355418624 and name "/loky-1790-38bnqfa3"
2023-02-24T08:55:11.4872291Z [DEBUG:LokyProcess-341:MainThread] recreated blocker with handle 140579235049472 and name "/loky-1790-9w1drh86"
2023-02-24T08:55:11.4873013Z [INFO:LokyProcess-341:MainThread] child process calling self.run()
2023-02-24T08:55:11.4873626Z [DEBUG:LokyProcess-341:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.4877482Z [INFO:LokyProcess-341:MainThread] Shutting down worker on sentinel
2023-02-24T08:55:11.4878239Z [DEBUG:LokyProcess-341:MainThread] Exited cleanly
2023-02-24T08:55:11.4878809Z [INFO:LokyProcess-341:MainThread] process shutting down
2023-02-24T08:55:11.4879485Z [DEBUG:LokyProcess-341:MainThread] running all "atexit" finalizers with priority >= 0
2023-02-24T08:55:11.4880213Z [DEBUG:LokyProcess-341:MainThread] running the remaining "atexit" finalizers
2023-02-24T08:55:11.4880889Z [INFO:LokyProcess-341:MainThread] process exiting with exitcode 0
2023-02-24T08:55:11.4881592Z [DEBUG:LokyProcess-340:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.4884884Z [DEBUG:LokyProcess-340:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.4885704Z [DEBUG:LokyProcess-340:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.4886467Z [DEBUG:LokyProcess-340:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.4887287Z [DEBUG:LokyProcess-340:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.4888101Z [DEBUG:LokyProcess-340:MainThread] recreated blocker with handle 140579355418624 and name "/loky-1790-38bnqfa3"
2023-02-24T08:55:11.4888866Z [DEBUG:LokyProcess-340:MainThread] recreated blocker with handle 140579235053568 and name "/loky-1790-b0vl6jad"
2023-02-24T08:55:11.4892366Z [INFO:LokyProcess-340:MainThread] child process calling self.run()
2023-02-24T08:55:11.4892979Z [DEBUG:LokyProcess-340:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.4893641Z [INFO:LokyProcess-340:MainThread] Shutting down worker on sentinel
2023-02-24T08:55:11.4894261Z [DEBUG:LokyProcess-340:MainThread] Exited cleanly
2023-02-24T08:55:11.4894824Z [INFO:LokyProcess-340:MainThread] process shutting down
2023-02-24T08:55:11.4895502Z [DEBUG:LokyProcess-340:MainThread] running all "atexit" finalizers with priority >= 0
2023-02-24T08:55:11.4896160Z [DEBUG:LokyProcess-340:MainThread] running the remaining "atexit" finalizers
2023-02-24T08:55:11.4899044Z [INFO:LokyProcess-340:MainThread] process exiting with exitcode 0
2023-02-24T08:55:11.4899799Z [DEBUG:LokyProcess-339:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.4900606Z [DEBUG:LokyProcess-339:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.4901428Z [DEBUG:LokyProcess-339:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.4902193Z [DEBUG:LokyProcess-339:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.4903004Z [DEBUG:LokyProcess-339:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.4907001Z [DEBUG:LokyProcess-339:MainThread] recreated blocker with handle 140579355418624 and name "/loky-1790-38bnqfa3"
2023-02-24T08:55:11.4907804Z [DEBUG:LokyProcess-339:MainThread] recreated blocker with handle 140579235057664 and name "/loky-1790-1mny4qpj"
2023-02-24T08:55:11.4908530Z [INFO:LokyProcess-339:MainThread] child process calling self.run()
2023-02-24T08:55:11.4909195Z [DEBUG:LokyProcess-339:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.4909809Z [INFO:LokyProcess-339:MainThread] Shutting down worker on sentinel
2023-02-24T08:55:11.4914166Z [DEBUG:LokyProcess-339:MainThread] Exited cleanly
2023-02-24T08:55:11.4914784Z [INFO:LokyProcess-339:MainThread] process shutting down
2023-02-24T08:55:11.4918147Z [DEBUG:LokyProcess-339:MainThread] running all "atexit" finalizers with priority >= 0
2023-02-24T08:55:11.4918811Z [DEBUG:LokyProcess-339:MainThread] running the remaining "atexit" finalizers
2023-02-24T08:55:11.4921769Z [INFO:LokyProcess-339:MainThread] process exiting with exitcode 0
2023-02-24T08:55:11.4922535Z [DEBUG:LokyProcess-343:MainThread] recreated blocker with handle 140579356774400 and name "/loky-1790-f7q2kmff"
2023-02-24T08:55:11.4923436Z [DEBUG:LokyProcess-343:MainThread] recreated blocker with handle 140579356770304 and name "/loky-1790-sdzz3g0t"
2023-02-24T08:55:11.4927077Z [DEBUG:LokyProcess-343:MainThread] recreated blocker with handle 140579356766208 and name "/loky-1790-c2r2s6yd"
2023-02-24T08:55:11.4928079Z [DEBUG:LokyProcess-343:MainThread] recreated blocker with handle 140579355426816 and name "/loky-1790-otj62yh_"
2023-02-24T08:55:11.4928855Z [DEBUG:LokyProcess-343:MainThread] recreated blocker with handle 140579355422720 and name "/loky-1790-pfkvvfdd"
2023-02-24T08:55:11.4931590Z [DEBUG:LokyProcess-343:MainThread] recreated blocker with handle 140579355418624 and name "/loky-1790-38bnqfa3"
2023-02-24T08:55:11.4932384Z [DEBUG:LokyProcess-343:MainThread] recreated blocker with handle 140579235041280 and name "/loky-1790-k04a4ftm"
2023-02-24T08:55:11.4935125Z [INFO:LokyProcess-343:MainThread] child process calling self.run()
2023-02-24T08:55:11.4937871Z [DEBUG:LokyProcess-343:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.4938513Z [INFO:LokyProcess-343:MainThread] Shutting down worker on sentinel
2023-02-24T08:55:11.4939137Z [DEBUG:LokyProcess-343:MainThread] Exited cleanly
2023-02-24T08:55:11.4939702Z [INFO:LokyProcess-343:MainThread] process shutting down
2023-02-24T08:55:11.4942398Z [DEBUG:LokyProcess-343:MainThread] running all "atexit" finalizers with priority >= 0
2023-02-24T08:55:11.4943103Z [DEBUG:LokyProcess-343:MainThread] running the remaining "atexit" finalizers
2023-02-24T08:55:11.4943726Z [INFO:LokyProcess-343:MainThread] process exiting with exitcode 0
2023-02-24T08:55:11.4947023Z [DEBUG:MainProcess:ExecutorManagerThread] joining process LokyProcess-342 with pid 3296
2023-02-24T08:55:11.4947735Z [DEBUG:MainProcess:ExecutorManagerThread] joining process LokyProcess-341 with pid 3295
2023-02-24T08:55:11.4948474Z [DEBUG:MainProcess:ExecutorManagerThread] joining process LokyProcess-340 with pid 3294
2023-02-24T08:55:11.4949204Z [DEBUG:MainProcess:ExecutorManagerThread] joining process LokyProcess-339 with pid 3293
2023-02-24T08:55:11.4949728Z [DEBUG:MainProcess:ExecutorManagerThread] executor management thread clean shutdown of 5 workers
2023-02-24T08:55:11.4952680Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579355418624 and name "None"
2023-02-24T08:55:11.4953217Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579351658496 and name "None"
2023-02-24T08:55:11.4953766Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235098624 and name "None"
2023-02-24T08:55:11.4957824Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235094528 and name "None"
2023-02-24T08:55:11.4958348Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235090432 and name "None"
2023-02-24T08:55:11.4962978Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235086336 and name "None"
2023-02-24T08:55:11.4963438Z [DEBUG:MainProcess:MainThread] ProcessPoolExecutor is setup
2023-02-24T08:55:11.4963946Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235057664 and name "None"
2023-02-24T08:55:11.4967294Z [DEBUG:MainProcess:MainThread] launched python with pid 3302 and cmd:
2023-02-24T08:55:11.4968104Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-344', '--pipe', '26']
2023-02-24T08:55:11.4968747Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235053568 and name "None"
2023-02-24T08:55:11.4973698Z [DEBUG:MainProcess:MainThread] launched python with pid 3303 and cmd:
2023-02-24T08:55:11.4974500Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-345', '--pipe', '27']
2023-02-24T08:55:11.4975128Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235049472 and name "None"
2023-02-24T08:55:11.4975599Z [DEBUG:MainProcess:MainThread] launched python with pid 3304 and cmd:
2023-02-24T08:55:11.4976507Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-346', '--pipe', '28']
2023-02-24T08:55:11.4977122Z [DEBUG:MainProcess:MainThread] created semlock with handle 140579235045376 and name "None"
2023-02-24T08:55:11.4977668Z [DEBUG:MainProcess:MainThread] launched python with pid 3305 and cmd:
2023-02-24T08:55:11.4981259Z ['/home/vsts/work/1/s/.tox/py39/bin/python', '-m', 'loky.backend.popen_loky_posix', '--process-name', 'LokyProcess-347', '--pipe', '29']
2023-02-24T08:55:11.4982200Z [DEBUG:MainProcess:MainThread] Adjusted process count to 4: [('LokyProcess-344', 3302), ('LokyProcess-345', 3303), ('LokyProcess-346', 3304), ('LokyProcess-347', 3305)]
2023-02-24T08:55:11.4982878Z [DEBUG:MainProcess:MainThread] _start_executor_manager_thread called
2023-02-24T08:55:11.4983372Z [DEBUG:MainProcess:ExecutorManagerThread] Queue._start_thread()
2023-02-24T08:55:11.4983820Z [DEBUG:MainProcess:ExecutorManagerThread] doing self._thread.start()
2023-02-24T08:55:11.4984330Z [DEBUG:MainProcess:QueueFeederThread] starting thread to feed data to pipe
2023-02-24T08:55:11.4984782Z [DEBUG:MainProcess:ExecutorManagerThread] ... done self._thread.start()
2023-02-24T08:55:11.4987713Z [DEBUG:MainProcess:MainThread] shutting down executor <loky.process_executor.ProcessPoolExecutor object at 0x7fdb2405a9a0>
2023-02-24T08:55:11.4988513Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-344
2023-02-24T08:55:11.4989192Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-345
2023-02-24T08:55:11.4989914Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-346
2023-02-24T08:55:11.4990653Z [DEBUG:MainProcess:ExecutorManagerThread] releasing worker exit lock on LokyProcess-347
2023-02-24T08:55:11.4991134Z [DEBUG:MainProcess:ExecutorManagerThread] found 4 processes to stop
2023-02-24T08:55:11.4995542Z [DEBUG:MainProcess:ExecutorManagerThread] sent 4 sentinels to the call queue
2023-02-24T08:55:11.4996024Z [DEBUG:MainProcess:ExecutorManagerThread] closing call_queue
2023-02-24T08:55:11.4996514Z [DEBUG:MainProcess:ExecutorManagerThread] telling queue thread to quit
2023-02-24T08:55:11.4997003Z [DEBUG:MainProcess:ExecutorManagerThread] Queue.join_thread()
2023-02-24T08:55:11.4997448Z [DEBUG:MainProcess:ExecutorManagerThread] closing result_queue
2023-02-24T08:55:11.5000059Z [DEBUG:MainProcess:ExecutorManagerThread] closing thread_wakeup
2023-02-24T08:55:11.5000519Z [DEBUG:MainProcess:ExecutorManagerThread] joining 4 processes
2023-02-24T08:55:11.5001234Z [DEBUG:MainProcess:ExecutorManagerThread] joining process LokyProcess-347 with pid 3305
2023-02-24T08:55:11.5001969Z [DEBUG:LokyProcess-344:MainThread] recreated blocker with handle 140579351658496 and name "/loky-1790-29vfjc37"
2023-02-24T08:55:11.5002796Z [DEBUG:LokyProcess-344:MainThread] recreated blocker with handle 140579235098624 and name "/loky-1790-ngr09fkn"
2023-02-24T08:55:11.5003609Z [DEBUG:LokyProcess-344:MainThread] recreated blocker with handle 140579235094528 and name "/loky-1790-ldz6mbek"
2023-02-24T08:55:11.5004375Z [DEBUG:LokyProcess-344:MainThread] recreated blocker with handle 140579235090432 and name "/loky-1790-cwbrqj05"
2023-02-24T08:55:11.5007655Z [DEBUG:LokyProcess-344:MainThread] recreated blocker with handle 140579235086336 and name "/loky-1790-ln61byu1"
2023-02-24T08:55:11.5008485Z [DEBUG:LokyProcess-344:MainThread] recreated blocker with handle 140579355418624 and name "/loky-1790-nhqnm68y"
2023-02-24T08:55:11.5009267Z [DEBUG:LokyProcess-344:MainThread] recreated blocker with handle 140579235057664 and name "/loky-1790-b9z03gfz"
2023-02-24T08:55:11.5009995Z [INFO:LokyProcess-344:MainThread] child process calling self.run()
2023-02-24T08:55:11.5010772Z [DEBUG:LokyProcess-344:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.5011549Z [DEBUG:LokyProcess-347:MainThread] recreated blocker with handle 140579351658496 and name "/loky-1790-29vfjc37"
2023-02-24T08:55:11.5015451Z [DEBUG:LokyProcess-347:MainThread] recreated blocker with handle 140579235098624 and name "/loky-1790-ngr09fkn"
2023-02-24T08:55:11.5016360Z [DEBUG:LokyProcess-347:MainThread] recreated blocker with handle 140579235094528 and name "/loky-1790-ldz6mbek"
2023-02-24T08:55:11.5017185Z [DEBUG:LokyProcess-347:MainThread] recreated blocker with handle 140579235090432 and name "/loky-1790-cwbrqj05"
2023-02-24T08:55:11.5018097Z [DEBUG:LokyProcess-347:MainThread] recreated blocker with handle 140579235086336 and name "/loky-1790-ln61byu1"
2023-02-24T08:55:11.5018873Z [DEBUG:LokyProcess-347:MainThread] recreated blocker with handle 140579355418624 and name "/loky-1790-nhqnm68y"
2023-02-24T08:55:11.5019688Z [DEBUG:LokyProcess-347:MainThread] recreated blocker with handle 140579235045376 and name "/loky-1790-zv0f0d16"
2023-02-24T08:55:11.5020360Z [INFO:LokyProcess-347:MainThread] child process calling self.run()
2023-02-24T08:55:11.5023677Z [DEBUG:LokyProcess-347:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.5024427Z [DEBUG:LokyProcess-345:MainThread] recreated blocker with handle 140579351658496 and name "/loky-1790-29vfjc37"
2023-02-24T08:55:11.5029483Z [DEBUG:LokyProcess-345:MainThread] recreated blocker with handle 140579235098624 and name "/loky-1790-ngr09fkn"
2023-02-24T08:55:11.5030308Z [DEBUG:LokyProcess-345:MainThread] recreated blocker with handle 140579235094528 and name "/loky-1790-ldz6mbek"
2023-02-24T08:55:11.5031118Z [DEBUG:LokyProcess-345:MainThread] recreated blocker with handle 140579235090432 and name "/loky-1790-cwbrqj05"
2023-02-24T08:55:11.5031885Z [DEBUG:LokyProcess-345:MainThread] recreated blocker with handle 140579235086336 and name "/loky-1790-ln61byu1"
2023-02-24T08:55:11.5035085Z [DEBUG:LokyProcess-345:MainThread] recreated blocker with handle 140579355418624 and name "/loky-1790-nhqnm68y"
2023-02-24T08:55:11.5035871Z [DEBUG:LokyProcess-345:MainThread] recreated blocker with handle 140579235053568 and name "/loky-1790-3e5hza75"
2023-02-24T08:55:11.5036598Z [INFO:LokyProcess-345:MainThread] child process calling self.run()
2023-02-24T08:55:11.5037270Z [DEBUG:LokyProcess-345:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.5037969Z [DEBUG:LokyProcess-346:MainThread] recreated blocker with handle 140579351658496 and name "/loky-1790-29vfjc37"
2023-02-24T08:55:11.5038785Z [DEBUG:LokyProcess-346:MainThread] recreated blocker with handle 140579235098624 and name "/loky-1790-ngr09fkn"
2023-02-24T08:55:11.5039536Z [DEBUG:LokyProcess-346:MainThread] recreated blocker with handle 140579235094528 and name "/loky-1790-ldz6mbek"
2023-02-24T08:55:11.5043274Z [DEBUG:LokyProcess-346:MainThread] recreated blocker with handle 140579235090432 and name "/loky-1790-cwbrqj05"
2023-02-24T08:55:11.5044088Z [DEBUG:LokyProcess-346:MainThread] recreated blocker with handle 140579235086336 and name "/loky-1790-ln61byu1"
2023-02-24T08:55:11.5044856Z [DEBUG:LokyProcess-346:MainThread] recreated blocker with handle 140579355418624 and name "/loky-1790-nhqnm68y"
2023-02-24T08:55:11.5045660Z [DEBUG:LokyProcess-346:MainThread] recreated blocker with handle 140579235049472 and name "/loky-1790-l6vt2eh3"
2023-02-24T08:55:11.5046380Z [INFO:LokyProcess-346:MainThread] child process calling self.run()
2023-02-24T08:55:11.5046989Z [DEBUG:LokyProcess-346:MainThread] Worker started with timeout=None
2023-02-24T08:55:11.5050126Z
2023-02-24T08:55:11.5050596Z +++++++++++++++++++++++++++++++++++ Timeout ++++++++++++++++++++++++++++++++++++
2023-02-24T08:55:11.5050841Z
2023-02-24T08:55:11.5051232Z ~~~~~~~~~~~~~~~ Stack of ExecutorManagerThread (140579197097728) ~~~~~~~~~~~~~~~
2023-02-24T08:55:11.5051766Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/threading.py", line 937, in _bootstrap
2023-02-24T08:55:11.5052184Z self._bootstrap_inner()
2023-02-24T08:55:11.5052648Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/threading.py", line 980, in _bootstrap_inner
2023-02-24T08:55:11.5053050Z self.run()
2023-02-24T08:55:11.5056112Z File "/home/vsts/work/1/s/loky/process_executor.py", line 613, in run
2023-02-24T08:55:11.5056587Z self.join_executor_internals()
2023-02-24T08:55:11.5057041Z File "/home/vsts/work/1/s/loky/process_executor.py", line 911, in join_executor_internals
2023-02-24T08:55:11.5057462Z p.join()
2023-02-24T08:55:11.5057860Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/multiprocessing/process.py", line 149, in join
2023-02-24T08:55:11.5058397Z res = self._popen.wait(timeout)
2023-02-24T08:55:11.5058785Z File "/home/vsts/work/1/s/loky/backend/popen_loky_posix.py", line 79, in wait
2023-02-24T08:55:11.5062203Z return self.poll(os.WNOHANG if timeout == 0.0 else 0)
2023-02-24T08:55:11.5062677Z File "/home/vsts/work/1/s/loky/backend/popen_loky_posix.py", line 58, in poll
2023-02-24T08:55:11.5063073Z pid, sts = os.waitpid(self.pid, flag)
2023-02-24T08:55:11.5063265Z
2023-02-24T08:55:11.5063869Z ~~~~~~~~~~~~~~~~~~~~~ Stack of Thread-12 (140579297109760) ~~~~~~~~~~~~~~~~~~~~~
2023-02-24T08:55:11.5064412Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/threading.py", line 937, in _bootstrap
2023-02-24T08:55:11.5064827Z self._bootstrap_inner()
2023-02-24T08:55:11.5068652Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/threading.py", line 980, in _bootstrap_inner
2023-02-24T08:55:11.5069067Z self.run()
2023-02-24T08:55:11.5069494Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/threading.py", line 917, in run
2023-02-24T08:55:11.5069921Z self._target(*self._args, **self._kwargs)
2023-02-24T08:55:11.5070432Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/multiprocessing/resource_sharer.py", line 138, in _serve
2023-02-24T08:55:11.5070931Z with self._listener.accept() as conn:
2023-02-24T08:55:11.5071378Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/multiprocessing/connection.py", line 463, in accept
2023-02-24T08:55:11.5074205Z c = self._listener.accept()
2023-02-24T08:55:11.5074632Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/multiprocessing/connection.py", line 609, in accept
2023-02-24T08:55:11.5075138Z s, self._last_accepted = self._socket.accept()
2023-02-24T08:55:11.5075620Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/socket.py", line 293, in accept
2023-02-24T08:55:11.5076021Z fd, addr = self._accept()
2023-02-24T08:55:11.5076245Z
2023-02-24T08:55:11.5076575Z +++++++++++++++++++++++++++++++++++ Timeout ++++++++++++++++++++++++++++++++++++
2023-02-24T08:55:11.5079890Z =============================== warnings summary ===============================
2023-02-24T08:55:11.5080440Z tests/test_process_executor_loky.py::TestsProcessPoolLokyShutdown::test_shutdown_with_sys_exit_at_pickle
2023-02-24T08:55:11.5081417Z /home/vsts/work/1/s/.tox/py39/lib/python3.9/site-packages/_pytest/threadexception.py:73: PytestUnhandledThreadExceptionWarning: Exception in thread QueueFeederThread
2023-02-24T08:55:11.5081960Z
2023-02-24T08:55:11.5082249Z Traceback (most recent call last):
2023-02-24T08:55:11.5085417Z File "/home/vsts/work/1/s/loky/backend/queues.py", line 159, in _feed
2023-02-24T08:55:11.5085835Z obj_ = dumps(obj, reducers=reducers)
2023-02-24T08:55:11.5086277Z File "/home/vsts/work/1/s/loky/backend/reduction.py", line 215, in dumps
2023-02-24T08:55:11.5086687Z dump(obj, buf, reducers=reducers, protocol=protocol)
2023-02-24T08:55:11.5087157Z File "/home/vsts/work/1/s/loky/backend/reduction.py", line 208, in dump
2023-02-24T08:55:11.5087631Z _LokyPickler(file, reducers=reducers, protocol=protocol).dump(obj)
2023-02-24T08:55:11.5088348Z File "/home/vsts/work/1/s/.tox/py39/lib/python3.9/site-packages/cloudpickle/cloudpickle_fast.py", line 632, in dump
2023-02-24T08:55:11.5091515Z return Pickler.dump(self, obj)
2023-02-24T08:55:11.5091938Z File "/home/vsts/work/1/s/tests/test_reusable_executor.py", line 158, in __reduce__
2023-02-24T08:55:11.5092350Z exit()
2023-02-24T08:55:11.5092706Z File "/home/vsts/work/1/s/tests/test_reusable_executor.py", line 84, in exit
2023-02-24T08:55:11.5093209Z sys.exit(0)
2023-02-24T08:55:11.5093530Z SystemExit: 0
2023-02-24T08:55:11.5093782Z
2023-02-24T08:55:11.5096570Z During handling of the above exception, another exception occurred:
2023-02-24T08:55:11.5096927Z
2023-02-24T08:55:11.5097251Z Traceback (most recent call last):
2023-02-24T08:55:11.5097759Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/threading.py", line 980, in _bootstrap_inner
2023-02-24T08:55:11.5098211Z self.run()
2023-02-24T08:55:11.5098639Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/threading.py", line 917, in run
2023-02-24T08:55:11.5099067Z self._target(*self._args, **self._kwargs)
2023-02-24T08:55:11.5102024Z File "/home/vsts/work/1/s/loky/backend/queues.py", line 184, in _feed
2023-02-24T08:55:11.5102402Z onerror(e, obj)
2023-02-24T08:55:11.5102901Z File "/home/vsts/work/1/s/loky/process_executor.py", line 340, in _on_queue_feeder_error
2023-02-24T08:55:11.5103306Z self.thread_wakeup.wakeup()
2023-02-24T08:55:11.5103738Z File "/home/vsts/work/1/s/loky/process_executor.py", line 132, in wakeup
2023-02-24T08:55:11.5104159Z self._writer.send_bytes(b"")
2023-02-24T08:55:11.5104601Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/multiprocessing/connection.py", line 200, in send_bytes
2023-02-24T08:55:11.5107983Z self._send_bytes(m[offset:offset + size])
2023-02-24T08:55:11.5108479Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/multiprocessing/connection.py", line 411, in _send_bytes
2023-02-24T08:55:11.5108964Z self._send(header + buf)
2023-02-24T08:55:11.5109446Z File "/opt/hostedtoolcache/Python/3.9.16/x64/lib/python3.9/multiprocessing/connection.py", line 368, in _send
2023-02-24T08:55:11.5109879Z n = write(self._handle, buf)
2023-02-24T08:55:11.5110256Z OSError: [Errno 9] Bad file descriptor
2023-02-24T08:55:11.5110540Z
2023-02-24T08:55:11.5114607Z warnings.warn(pytest.PytestUnhandledThreadExceptionWarning(msg))
2023-02-24T08:55:11.5114873Z
2023-02-24T08:55:11.5115438Z -- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html
2023-02-24T08:55:11.5116060Z ------------ generated xml file: /home/vsts/work/1/s/test-data.xml -------------
2023-02-24T08:55:11.5116574Z =========================== short test summary info ============================
2023-02-24T08:55:11.5117100Z FAILED tests/test_process_executor_loky.py::TestsProcessPoolLokyShutdown::test_shutdown_with_sys_exit_at_pickle
2023-02-24T08:55:11.5117763Z ERROR tests/test_process_executor_loky.py::TestsProcessPoolLokyShutdown::test_shutdown_with_sys_exit_at_pickle
2023-02-24T08:55:11.5120806Z ERROR tests/test_process_executor_loky.py::TestsProcessPoolLokyShutdown::test_interpreter_shutdown
2023-02-24T08:55:11.5121415Z ERROR tests/test_process_executor_loky.py::TestsProcessPoolLokyShutdown::test_interpreter_shutdown
2023-02-24T08:55:11.5122041Z ERROR tests/test_process_executor_loky.py::TestsProcessPoolLokyShutdown::test_hang_issue12364
2023-02-24T08:55:11.5122647Z ERROR tests/test_process_executor_loky.py::TestsProcessPoolLokyShutdown::test_hang_issue12364
2023-02-24T08:55:11.5123155Z !!!!!!!!!!!!!!!!!!!!!!!!!! stopping after 6 failures !!!!!!!!!!!!!!!!!!!!!!!!!!!
2023-02-24T08:55:11.5126703Z == 1 failed, 110 passed, 3 skipped, 1 warning, 5 errors in 176.04s (0:02:56) ===
2023-02-24T08:55:11.5127265Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5128189Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5128868Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5129582Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5133553Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5134273Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5135085Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5135801Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5136474Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5137190Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5140564Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5141256Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5141975Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5142680Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5143354Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5144064Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5147620Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5148317Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5149039Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5149748Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5150420Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5151122Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5154278Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5154982Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5155693Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5156468Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5157131Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5157845Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5161215Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5161989Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5162716Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5163430Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5164099Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5164808Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5167998Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5168708Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5169432Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5170134Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5170900Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5171622Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5174653Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5175357Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5176074Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5176781Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5177452Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5179863Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5180589Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5181263Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5184379Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5185042Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5185831Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5186537Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5187316Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5187977Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5191171Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5191829Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5192556Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5193270Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5193992Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5194659Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5198042Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5198708Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5199427Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5200131Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5203362Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5204077Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5204790Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5205450Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5206172Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5206897Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5210433Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5211144Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5211857Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5212515Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5213377Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5218514Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5219192Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5219902Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5220622Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5221291Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5221998Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5225248Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5225934Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5226645Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5227363Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5228023Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5231466Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5232206Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5232870Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5233581Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5234297Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5234957Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5238131Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5238841Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5239512Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5240236Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5241034Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5241691Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5245588Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5246302Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5246967Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5247680Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5248395Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5249058Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5252253Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5252969Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5253642Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5254351Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5255067Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5255728Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5259776Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5260502Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5261166Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5261882Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5262600Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5263263Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5263999Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5264708Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5265382Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5266093Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5269139Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5269906Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5270709Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5271434Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5272096Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5272815Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5275752Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5276443Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5277165Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5280088Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5280781Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5281495Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5282210Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5282871Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5283576Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5284288Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5284951Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5287283Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5288000Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5288662Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5291566Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5292280Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5293033Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5293743Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5296820Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5297505Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5298226Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5298944Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5299614Z [DEBUG:MainProcess:MainThread] Interpreter shutting down. Waking up {len(items)}executor_manager_thread:
2023-02-24T08:55:11.5300324Z [(<_ExecutorManagerThread(ExecutorManagerThread, stopped 140579197097728)>, (<unlocked _thread.lock object at 0x7fdb2404d480>, <loky.process_executor._ThreadWakeup object at 0x7fdb2404d310>))]
2023-02-24T08:55:11.5303236Z [INFO:MainProcess:MainThread] process shutting down
2023-02-24T08:55:11.5303702Z [DEBUG:MainProcess:MainThread] running all "atexit" finalizers with priority >= 0
2023-02-24T08:55:11.5304647Z [INFO:MainProcess:MainThread] calling join() for process LokyProcess-347
2023-02-24T09:24:46.0116854Z ##[error]The operation was canceled.
2023-02-24T09:24:46.0191875Z ##[section]Finishing: Test loky
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment