0s autopkgtest [10:54:03]: starting date and time: 2025-01-08 10:54:03+0000 0s autopkgtest [10:54:03]: git checkout: 325255d2 Merge branch 'pin-any-arch' into 'ubuntu/production' 0s autopkgtest [10:54:03]: host juju-7f2275-prod-proposed-migration-environment-15; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.pj1wubcg/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:sphinx --apt-upgrade python-pytest-xprocess --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=sphinx/8.1.3-4 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-15@bos03-arm64-3.secgroup --name adt-plucky-arm64-python-pytest-xprocess-20250108-105403-juju-7f2275-prod-proposed-migration-environment-15-ad8dab0b-2993-49b3-83d9-cd25e3012f55 --image adt/ubuntu-plucky-arm64-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-15 --net-id=net_prod-proposed-migration -e TERM=linux -e ''"'"'http_proxy=http://squid.internal:3128'"'"'' -e ''"'"'https_proxy=http://squid.internal:3128'"'"'' -e ''"'"'no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,keyserver.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com,radosgw.ps5.canonical.com'"'"'' --mirror=http://ftpmaster.internal/ubuntu/ 135s autopkgtest [10:56:18]: testbed dpkg architecture: arm64 135s autopkgtest [10:56:18]: testbed apt version: 2.9.18 135s autopkgtest [10:56:18]: @@@@@@@@@@@@@@@@@@@@ test bed setup 135s autopkgtest [10:56:18]: testbed release detected to be: None 136s autopkgtest [10:56:19]: updating testbed package index (apt update) 137s Get:1 http://ftpmaster.internal/ubuntu plucky-proposed InRelease [73.9 kB] 137s Hit:2 http://ftpmaster.internal/ubuntu plucky InRelease 137s Hit:3 http://ftpmaster.internal/ubuntu plucky-updates InRelease 137s Hit:4 http://ftpmaster.internal/ubuntu plucky-security InRelease 137s Get:5 http://ftpmaster.internal/ubuntu plucky-proposed/main Sources [129 kB] 137s Get:6 http://ftpmaster.internal/ubuntu plucky-proposed/universe Sources [818 kB] 137s Get:7 http://ftpmaster.internal/ubuntu plucky-proposed/restricted Sources [9708 B] 137s Get:8 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse Sources [17.3 kB] 137s Get:9 http://ftpmaster.internal/ubuntu plucky-proposed/main arm64 Packages [260 kB] 137s Get:10 http://ftpmaster.internal/ubuntu plucky-proposed/restricted arm64 Packages [57.8 kB] 137s Get:11 http://ftpmaster.internal/ubuntu plucky-proposed/universe arm64 Packages [1011 kB] 137s Get:12 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse arm64 Packages [22.8 kB] 138s Fetched 2398 kB in 1s (2350 kB/s) 139s Reading package lists... 140s Reading package lists... 140s Building dependency tree... 140s Reading state information... 141s Calculating upgrade... 141s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 141s Reading package lists... 142s Building dependency tree... 142s Reading state information... 143s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 143s autopkgtest [10:56:26]: upgrading testbed (apt dist-upgrade and autopurge) 143s Reading package lists... 143s Building dependency tree... 143s Reading state information... 144s Calculating upgrade...Starting pkgProblemResolver with broken count: 0 144s Starting 2 pkgProblemResolver with broken count: 0 144s Done 145s Entering ResolveByKeep 146s 146s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 147s Reading package lists... 147s Building dependency tree... 147s Reading state information... 148s Starting pkgProblemResolver with broken count: 0 148s Starting 2 pkgProblemResolver with broken count: 0 148s Done 150s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 153s autopkgtest [10:56:36]: testbed running kernel: Linux 6.11.0-8-generic #8-Ubuntu SMP PREEMPT_DYNAMIC Mon Sep 16 14:19:41 UTC 2024 153s autopkgtest [10:56:36]: @@@@@@@@@@@@@@@@@@@@ apt-source python-pytest-xprocess 155s Get:1 http://ftpmaster.internal/ubuntu plucky/universe python-pytest-xprocess 0.22.2-1 (dsc) [2426 B] 155s Get:2 http://ftpmaster.internal/ubuntu plucky/universe python-pytest-xprocess 0.22.2-1 (tar) [31.3 kB] 155s Get:3 http://ftpmaster.internal/ubuntu plucky/universe python-pytest-xprocess 0.22.2-1 (diff) [3104 B] 156s gpgv: Signature made Mon Aug 7 15:28:10 2023 UTC 156s gpgv: using RSA key A0B1A9F3508956130E7A425CD416AD15AC6B43FE 156s gpgv: Can't check signature: No public key 156s dpkg-source: warning: cannot verify inline signature for ./python-pytest-xprocess_0.22.2-1.dsc: no acceptable signature found 156s autopkgtest [10:56:39]: testing package python-pytest-xprocess version 0.22.2-1 156s autopkgtest [10:56:39]: build not needed 157s autopkgtest [10:56:40]: test upstream: preparing testbed 157s Reading package lists... 157s Building dependency tree... 157s Reading state information... 158s Starting pkgProblemResolver with broken count: 0 158s Starting 2 pkgProblemResolver with broken count: 0 158s Done 159s The following NEW packages will be installed: 159s libpython3.13-minimal libpython3.13-stdlib python3-all python3-iniconfig 159s python3-packaging python3-pluggy python3-psutil python3-py python3-pytest 159s python3-pytest-xprocess python3.13 python3.13-minimal 160s 0 upgraded, 12 newly installed, 0 to remove and 0 not upgraded. 160s Need to get 6540 kB of archives. 160s After this operation, 27.7 MB of additional disk space will be used. 160s Get:1 http://ftpmaster.internal/ubuntu plucky/main arm64 libpython3.13-minimal arm64 3.13.1-2 [879 kB] 160s Get:2 http://ftpmaster.internal/ubuntu plucky/main arm64 python3.13-minimal arm64 3.13.1-2 [2262 kB] 160s Get:3 http://ftpmaster.internal/ubuntu plucky/main arm64 libpython3.13-stdlib arm64 3.13.1-2 [2061 kB] 160s Get:4 http://ftpmaster.internal/ubuntu plucky/main arm64 python3.13 arm64 3.13.1-2 [729 kB] 160s Get:5 http://ftpmaster.internal/ubuntu plucky/main arm64 python3-all arm64 3.12.8-1 [892 B] 160s Get:6 http://ftpmaster.internal/ubuntu plucky/universe arm64 python3-iniconfig all 1.1.1-2 [6024 B] 160s Get:7 http://ftpmaster.internal/ubuntu plucky/main arm64 python3-packaging all 24.2-1 [51.5 kB] 160s Get:8 http://ftpmaster.internal/ubuntu plucky/universe arm64 python3-pluggy all 1.5.0-1 [21.0 kB] 160s Get:9 http://ftpmaster.internal/ubuntu plucky/main arm64 python3-psutil arm64 5.9.8-2build3 [196 kB] 160s Get:10 http://ftpmaster.internal/ubuntu plucky/universe arm64 python3-py all 1.11.0-2 [72.7 kB] 160s Get:11 http://ftpmaster.internal/ubuntu plucky/universe arm64 python3-pytest all 8.3.3-1 [251 kB] 160s Get:12 http://ftpmaster.internal/ubuntu plucky/universe arm64 python3-pytest-xprocess all 0.22.2-1 [10.2 kB] 161s Fetched 6540 kB in 1s (7872 kB/s) 161s Selecting previously unselected package libpython3.13-minimal:arm64. 161s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 80185 files and directories currently installed.) 161s Preparing to unpack .../00-libpython3.13-minimal_3.13.1-2_arm64.deb ... 161s Unpacking libpython3.13-minimal:arm64 (3.13.1-2) ... 161s Selecting previously unselected package python3.13-minimal. 161s Preparing to unpack .../01-python3.13-minimal_3.13.1-2_arm64.deb ... 161s Unpacking python3.13-minimal (3.13.1-2) ... 161s Selecting previously unselected package libpython3.13-stdlib:arm64. 161s Preparing to unpack .../02-libpython3.13-stdlib_3.13.1-2_arm64.deb ... 161s Unpacking libpython3.13-stdlib:arm64 (3.13.1-2) ... 162s Selecting previously unselected package python3.13. 162s Preparing to unpack .../03-python3.13_3.13.1-2_arm64.deb ... 162s Unpacking python3.13 (3.13.1-2) ... 162s Selecting previously unselected package python3-all. 162s Preparing to unpack .../04-python3-all_3.12.8-1_arm64.deb ... 162s Unpacking python3-all (3.12.8-1) ... 162s Selecting previously unselected package python3-iniconfig. 162s Preparing to unpack .../05-python3-iniconfig_1.1.1-2_all.deb ... 162s Unpacking python3-iniconfig (1.1.1-2) ... 162s Selecting previously unselected package python3-packaging. 162s Preparing to unpack .../06-python3-packaging_24.2-1_all.deb ... 162s Unpacking python3-packaging (24.2-1) ... 162s Selecting previously unselected package python3-pluggy. 162s Preparing to unpack .../07-python3-pluggy_1.5.0-1_all.deb ... 162s Unpacking python3-pluggy (1.5.0-1) ... 162s Selecting previously unselected package python3-psutil. 162s Preparing to unpack .../08-python3-psutil_5.9.8-2build3_arm64.deb ... 162s Unpacking python3-psutil (5.9.8-2build3) ... 162s Selecting previously unselected package python3-py. 162s Preparing to unpack .../09-python3-py_1.11.0-2_all.deb ... 162s Unpacking python3-py (1.11.0-2) ... 162s Selecting previously unselected package python3-pytest. 162s Preparing to unpack .../10-python3-pytest_8.3.3-1_all.deb ... 162s Unpacking python3-pytest (8.3.3-1) ... 162s Selecting previously unselected package python3-pytest-xprocess. 162s Preparing to unpack .../11-python3-pytest-xprocess_0.22.2-1_all.deb ... 162s Unpacking python3-pytest-xprocess (0.22.2-1) ... 162s Setting up python3-iniconfig (1.1.1-2) ... 163s Setting up python3-py (1.11.0-2) ... 163s Setting up python3-psutil (5.9.8-2build3) ... 164s Setting up libpython3.13-minimal:arm64 (3.13.1-2) ... 164s Setting up python3-packaging (24.2-1) ... 164s Setting up python3-pluggy (1.5.0-1) ... 165s Setting up python3.13-minimal (3.13.1-2) ... 166s Setting up libpython3.13-stdlib:arm64 (3.13.1-2) ... 166s Setting up python3.13 (3.13.1-2) ... 167s Setting up python3-pytest (8.3.3-1) ... 168s Setting up python3-all (3.12.8-1) ... 168s Setting up python3-pytest-xprocess (0.22.2-1) ... 169s Processing triggers for man-db (2.13.0-1) ... 169s Processing triggers for systemd (257-2ubuntu1) ... 170s autopkgtest [10:56:53]: test upstream: [----------------------- 171s -=-=-=-=-=-=-=- running tests for python3.13 -=-=-=-=-=-=-=-=- 171s $ python3.13 -m pytest -v -k "not test_interruption_cleanup and not test_interruption_does_not_cleanup" tests 171s ============================= test session starts ============================== 171s platform linux -- Python 3.13.1, pytest-8.3.3, pluggy-1.5.0 -- /usr/bin/python3.13 171s cachedir: .pytest_cache 171s rootdir: /tmp/autopkgtest.zyRopY/autopkgtest_tmp 171s plugins: xprocess-0.22.2, typeguard-4.4.1 171s collecting ... collected 45 items / 2 deselected / 43 selected 171s 171s tests/test_callback.py::test_callback_success[s1] PASSED [ 2%] 171s tests/test_callback.py::test_callback_success[s2] PASSED [ 4%] 172s tests/test_callback.py::test_callback_success[s3] PASSED [ 6%] 177s tests/test_callback.py::test_callback_fail[s1] PASSED [ 9%] 182s tests/test_callback.py::test_callback_fail[s2] PASSED [ 11%] 187s tests/test_callback.py::test_callback_fail[s3] PASSED [ 13%] 187s tests/test_functional_workflow.py::test_functional_work_flow PASSED [ 16%] 188s tests/test_process_initialization.py::test_servers_start[s1] PASSED [ 18%] 188s tests/test_process_initialization.py::test_servers_start[s2] PASSED [ 20%] 188s tests/test_process_initialization.py::test_servers_start[s3] PASSED [ 23%] 188s tests/test_process_initialization.py::test_ensure_not_restart[s1] PASSED [ 25%] 188s tests/test_process_initialization.py::test_ensure_not_restart[s2] PASSED [ 27%] 189s tests/test_process_initialization.py::test_ensure_not_restart[s3] PASSED [ 30%] 189s tests/test_process_initialization.py::test_startup_detection_max_read_lines[s1-started-21] PASSED [ 32%] 189s tests/test_process_initialization.py::test_startup_detection_max_read_lines[s2-spam, bacon, eggs-30] PASSED [ 34%] 189s tests/test_process_initialization.py::test_startup_detection_max_read_lines[s3-finally started-130] PASSED [ 37%] 190s tests/test_process_initialization.py::test_runtime_error_on_start_fail[s1] PASSED [ 39%] 190s tests/test_process_initialization.py::test_runtime_error_on_start_fail[s2] PASSED [ 41%] 190s tests/test_process_initialization.py::test_runtime_error_on_start_fail[s3] PASSED [ 44%] 190s tests/test_process_initialization.py::test_popen_kwargs[s1] PASSED [ 46%] 190s tests/test_process_initialization.py::test_popen_kwargs[s2] PASSED [ 48%] 191s tests/test_process_initialization.py::test_popen_kwargs[s3] PASSED [ 51%] 191s tests/test_process_termination.py::test_clean_shutdown[s1] PASSED [ 53%] 191s tests/test_process_termination.py::test_clean_shutdown[s2] PASSED [ 55%] 191s tests/test_process_termination.py::test_clean_shutdown[s3] PASSED [ 58%] 192s tests/test_process_termination.py::test_terminate_no_pid[s1] PASSED [ 60%] 192s tests/test_process_termination.py::test_terminate_no_pid[s2] PASSED [ 62%] 192s tests/test_process_termination.py::test_terminate_no_pid[s3] PASSED [ 65%] 192s tests/test_process_termination.py::test_terminate_only_parent[s1] PASSED [ 67%] 192s tests/test_process_termination.py::test_terminate_only_parent[s2] PASSED [ 69%] 193s tests/test_process_termination.py::test_terminate_only_parent[s3] PASSED [ 72%] 195s tests/test_process_termination.py::test_sigkill_after_failed_sigterm[s1] PASSED [ 74%] 197s tests/test_process_termination.py::test_sigkill_after_failed_sigterm[s2] PASSED [ 76%] 199s tests/test_process_termination.py::test_sigkill_after_failed_sigterm[s3] PASSED [ 79%] 200s tests/test_process_termination.py::test_return_value_on_failure[s1] PASSED [ 81%] 200s tests/test_process_termination.py::test_return_value_on_failure[s2] PASSED [ 83%] 200s tests/test_process_termination.py::test_return_value_on_failure[s3] PASSED [ 86%] 200s tests/test_resource_cleanup.py::test_0 PASSED [ 88%] 200s tests/test_resource_cleanup.py::test_1 PASSED [ 90%] 201s tests/test_resource_cleanup.py::test_2 PASSED [ 93%] 203s tests/test_startup_timeout.py::test_timeout_raise_exception[s1] PASSED [ 95%] 205s tests/test_startup_timeout.py::test_timeout_raise_exception[s2] PASSED [ 97%] 207s tests/test_startup_timeout.py::test_timeout_raise_exception[s3] PASSED [100%] 207s 207s ====================== 43 passed, 2 deselected in 36.27s ======================= 207s pytest-xprocess reminder::Be sure to terminate the started process by running 'pytest --xkill' if you have not explicitly done so in your fixture with 'xprocess.getinfo().terminate()'. 207s -=-=-=-=-=-=-=- running tests for python3.12 -=-=-=-=-=-=-=-=- 207s $ python3.12 -m pytest -v -k "not test_interruption_cleanup and not test_interruption_does_not_cleanup" tests 208s ============================= test session starts ============================== 208s platform linux -- Python 3.12.8, pytest-8.3.3, pluggy-1.5.0 -- /usr/bin/python3.12 208s cachedir: .pytest_cache 208s rootdir: /tmp/autopkgtest.zyRopY/autopkgtest_tmp 208s plugins: xprocess-0.22.2, typeguard-4.4.1 208s collecting ... collected 45 items / 2 deselected / 43 selected 208s 208s tests/test_callback.py::test_callback_success[s1] PASSED [ 2%] 208s tests/test_callback.py::test_callback_success[s2] PASSED [ 4%] 208s tests/test_callback.py::test_callback_success[s3] PASSED [ 6%] 213s tests/test_callback.py::test_callback_fail[s1] PASSED [ 9%] 219s tests/test_callback.py::test_callback_fail[s2] PASSED [ 11%] 224s tests/test_callback.py::test_callback_fail[s3] PASSED [ 13%] 224s tests/test_functional_workflow.py::test_functional_work_flow PASSED [ 16%] 224s tests/test_process_initialization.py::test_servers_start[s1] PASSED [ 18%] 224s tests/test_process_initialization.py::test_servers_start[s2] PASSED [ 20%] 225s tests/test_process_initialization.py::test_servers_start[s3] PASSED [ 23%] 225s tests/test_process_initialization.py::test_ensure_not_restart[s1] PASSED [ 25%] 225s tests/test_process_initialization.py::test_ensure_not_restart[s2] PASSED [ 27%] 225s tests/test_process_initialization.py::test_ensure_not_restart[s3] PASSED [ 30%] 225s tests/test_process_initialization.py::test_startup_detection_max_read_lines[s1-started-21] PASSED [ 32%] 226s tests/test_process_initialization.py::test_startup_detection_max_read_lines[s2-spam, bacon, eggs-30] PASSED [ 34%] 226s tests/test_process_initialization.py::test_startup_detection_max_read_lines[s3-finally started-130] PASSED [ 37%] 226s tests/test_process_initialization.py::test_runtime_error_on_start_fail[s1] PASSED [ 39%] 226s tests/test_process_initialization.py::test_runtime_error_on_start_fail[s2] PASSED [ 41%] 227s tests/test_process_initialization.py::test_runtime_error_on_start_fail[s3] PASSED [ 44%] 227s tests/test_process_initialization.py::test_popen_kwargs[s1] PASSED [ 46%] 227s tests/test_process_initialization.py::test_popen_kwargs[s2] PASSED [ 48%] 227s tests/test_process_initialization.py::test_popen_kwargs[s3] PASSED [ 51%] 227s tests/test_process_termination.py::test_clean_shutdown[s1] PASSED [ 53%] 228s tests/test_process_termination.py::test_clean_shutdown[s2] PASSED [ 55%] 228s tests/test_process_termination.py::test_clean_shutdown[s3] PASSED [ 58%] 228s tests/test_process_termination.py::test_terminate_no_pid[s1] PASSED [ 60%] 228s tests/test_process_termination.py::test_terminate_no_pid[s2] PASSED [ 62%] 228s tests/test_process_termination.py::test_terminate_no_pid[s3] PASSED [ 65%] 229s tests/test_process_termination.py::test_terminate_only_parent[s1] PASSED [ 67%] 229s tests/test_process_termination.py::test_terminate_only_parent[s2] PASSED [ 69%] 229s tests/test_process_termination.py::test_terminate_only_parent[s3] PASSED [ 72%] 231s tests/test_process_termination.py::test_sigkill_after_failed_sigterm[s1] PASSED [ 74%] 234s tests/test_process_termination.py::test_sigkill_after_failed_sigterm[s2] PASSED [ 76%] 236s tests/test_process_termination.py::test_sigkill_after_failed_sigterm[s3] PASSED [ 79%] 236s tests/test_process_termination.py::test_return_value_on_failure[s1] PASSED [ 81%] 236s tests/test_process_termination.py::test_return_value_on_failure[s2] PASSED [ 83%] 237s tests/test_process_termination.py::test_return_value_on_failure[s3] PASSED [ 86%] 237s tests/test_resource_cleanup.py::test_0 PASSED [ 88%] 237s tests/test_resource_cleanup.py::test_1 PASSED [ 90%] 237s tests/test_resource_cleanup.py::test_2 PASSED [ 93%] 239s tests/test_startup_timeout.py::test_timeout_raise_exception[s1] PASSED [ 95%] 242s tests/test_startup_timeout.py::test_timeout_raise_exception[s2] PASSED [ 97%] 244s tests/test_startup_timeout.py::test_timeout_raise_exception[s3] PASSED [100%] 244s 244s ====================== 43 passed, 2 deselected in 36.04s ======================= 244s pytest-xprocess reminder::Be sure to terminate the started process by running 'pytest --xkill' if you have not explicitly done so in your fixture with 'xprocess.getinfo().terminate()'. 244s autopkgtest [10:58:07]: test upstream: -----------------------] 245s upstream PASS 245s autopkgtest [10:58:08]: test upstream: - - - - - - - - - - results - - - - - - - - - - 245s autopkgtest [10:58:08]: @@@@@@@@@@@@@@@@@@@@ summary 245s upstream PASS 263s nova [W] Using flock in prodstack6-arm64 263s Creating nova instance adt-plucky-arm64-python-pytest-xprocess-20250108-105403-juju-7f2275-prod-proposed-migration-environment-15-ad8dab0b-2993-49b3-83d9-cd25e3012f55 from image adt/ubuntu-plucky-arm64-server-20250108.img (UUID 053f5e9f-d810-4aac-9e57-cf8ac63865d2)... 263s nova [W] Timed out waiting for 90b5589e-df85-43c4-85db-b786179a6549 to get deleted.