0s autopkgtest [11:47:31]: starting date and time: 2024-06-08 11:47:31+0000 0s autopkgtest [11:47:31]: git checkout: 433ed4cb Merge branch 'skia/nova_flock' into 'ubuntu/5.34+prod' 0s autopkgtest [11:47:31]: host juju-7f2275-prod-proposed-migration-environment-2; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.p6s_x90d/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:pytest,src:astropy --apt-upgrade poolcounter --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 '--env=ADT_TEST_TRIGGERS=pytest/8.2.2-1ubuntu1 astropy/6.0.1-4' -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@bos03-arm64-17.secgroup --name adt-oracular-arm64-poolcounter-20240608-114731-juju-7f2275-prod-proposed-migration-environment-2-8c494b90-08d3-4029-81ee-a39303902c82 --image adt/ubuntu-oracular-arm64-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-2 --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'"'"'' --mirror=http://ftpmaster.internal/ubuntu/ 82s autopkgtest [11:48:53]: testbed dpkg architecture: arm64 82s autopkgtest [11:48:53]: testbed apt version: 2.9.3 82s autopkgtest [11:48:53]: @@@@@@@@@@@@@@@@@@@@ test bed setup 82s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [110 kB] 83s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [7972 B] 83s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [336 kB] 83s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [42.7 kB] 83s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [1680 B] 83s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 Packages [66.8 kB] 83s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/restricted arm64 Packages [31.8 kB] 83s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/universe arm64 Packages [306 kB] 83s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse arm64 Packages [9192 B] 83s Fetched 913 kB in 1s (906 kB/s) 83s Reading package lists... 86s Reading package lists... 86s Building dependency tree... 86s Reading state information... 87s Calculating upgrade... 87s The following packages will be upgraded: 87s bash 87s 1 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 87s Need to get 781 kB of archives. 87s After this operation, 0 B of additional disk space will be used. 87s Get:1 http://ftpmaster.internal/ubuntu oracular/main arm64 bash arm64 5.2.21-2.1ubuntu1 [781 kB] 88s Fetched 781 kB in 1s (1216 kB/s) 88s (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 ... 78200 files and directories currently installed.) 88s Preparing to unpack .../bash_5.2.21-2.1ubuntu1_arm64.deb ... 88s Unpacking bash (5.2.21-2.1ubuntu1) over (5.2.21-2ubuntu5) ... 88s Setting up bash (5.2.21-2.1ubuntu1) ... 88s update-alternatives: using /usr/share/man/man7/bash-builtins.7.gz to provide /usr/share/man/man7/builtins.7.gz (builtins.7.gz) in auto mode 88s Processing triggers for debianutils (5.18) ... 89s Processing triggers for install-info (7.1-3build2) ... 89s Processing triggers for man-db (2.12.1-1) ... 89s Reading package lists... 90s Building dependency tree... 90s Reading state information... 90s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 91s Hit:1 http://ftpmaster.internal/ubuntu oracular InRelease 91s Hit:2 http://ftpmaster.internal/ubuntu oracular-updates InRelease 91s Hit:3 http://ftpmaster.internal/ubuntu oracular-security InRelease 91s Hit:4 http://ftpmaster.internal/ubuntu oracular-proposed InRelease 93s Reading package lists... 93s Reading package lists... 93s Building dependency tree... 93s Reading state information... 94s Calculating upgrade... 94s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 94s Reading package lists... 94s Building dependency tree... 94s Reading state information... 95s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 98s autopkgtest [11:49:09]: testbed running kernel: Linux 6.8.0-31-generic #31-Ubuntu SMP PREEMPT_DYNAMIC Sat Apr 20 02:32:42 UTC 2024 98s autopkgtest [11:49:09]: @@@@@@@@@@@@@@@@@@@@ apt-source poolcounter 100s Get:1 http://ftpmaster.internal/ubuntu oracular/universe poolcounter 1.1.3-2build4 (dsc) [2139 B] 100s Get:2 http://ftpmaster.internal/ubuntu oracular/universe poolcounter 1.1.3-2build4 (tar) [26.9 kB] 100s Get:3 http://ftpmaster.internal/ubuntu oracular/universe poolcounter 1.1.3-2build4 (diff) [3796 B] 100s gpgv: Signature made Mon Apr 1 07:12:32 2024 UTC 100s gpgv: using RSA key A089FB36AAFBDAD5ACC1325069F790171A210984 100s gpgv: Can't check signature: No public key 100s dpkg-source: warning: cannot verify inline signature for ./poolcounter_1.1.3-2build4.dsc: no acceptable signature found 100s autopkgtest [11:49:11]: testing package poolcounter version 1.1.3-2build4 100s autopkgtest [11:49:11]: build not needed 101s autopkgtest [11:49:12]: test command1: preparing testbed 102s Reading package lists... 102s Building dependency tree... 102s Reading state information... 102s Starting pkgProblemResolver with broken count: 0 102s Starting 2 pkgProblemResolver with broken count: 0 102s Done 103s The following additional packages will be installed: 103s libevent-2.1-7t64 poolcounter python3-iniconfig python3-packaging 103s python3-pluggy python3-pytest 103s The following NEW packages will be installed: 103s autopkgtest-satdep libevent-2.1-7t64 poolcounter python3-iniconfig 103s python3-packaging python3-pluggy python3-pytest 103s 0 upgraded, 7 newly installed, 0 to remove and 0 not upgraded. 103s Need to get 471 kB/472 kB of archives. 103s After this operation, 2128 kB of additional disk space will be used. 103s Get:1 /tmp/autopkgtest.0CnYLz/1-autopkgtest-satdep.deb autopkgtest-satdep arm64 0 [716 B] 103s Get:2 http://ftpmaster.internal/ubuntu oracular/main arm64 libevent-2.1-7t64 arm64 2.1.12-stable-10 [140 kB] 104s Get:3 http://ftpmaster.internal/ubuntu oracular/universe arm64 poolcounter arm64 1.1.3-2build4 [13.0 kB] 104s Get:4 http://ftpmaster.internal/ubuntu oracular/universe arm64 python3-iniconfig all 1.1.1-2 [6024 B] 104s Get:5 http://ftpmaster.internal/ubuntu oracular/main arm64 python3-packaging all 24.0-1 [41.1 kB] 104s Get:6 http://ftpmaster.internal/ubuntu oracular/universe arm64 python3-pluggy all 1.5.0-1 [21.0 kB] 104s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/universe arm64 python3-pytest all 8.2.2-1ubuntu1 [250 kB] 105s Fetched 471 kB in 1s (737 kB/s) 105s Selecting previously unselected package libevent-2.1-7t64:arm64. 105s (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 ... 78200 files and directories currently installed.) 105s Preparing to unpack .../0-libevent-2.1-7t64_2.1.12-stable-10_arm64.deb ... 105s Unpacking libevent-2.1-7t64:arm64 (2.1.12-stable-10) ... 105s Selecting previously unselected package poolcounter. 105s Preparing to unpack .../1-poolcounter_1.1.3-2build4_arm64.deb ... 105s Unpacking poolcounter (1.1.3-2build4) ... 105s Selecting previously unselected package python3-iniconfig. 105s Preparing to unpack .../2-python3-iniconfig_1.1.1-2_all.deb ... 105s Unpacking python3-iniconfig (1.1.1-2) ... 105s Selecting previously unselected package python3-packaging. 105s Preparing to unpack .../3-python3-packaging_24.0-1_all.deb ... 105s Unpacking python3-packaging (24.0-1) ... 105s Selecting previously unselected package python3-pluggy. 105s Preparing to unpack .../4-python3-pluggy_1.5.0-1_all.deb ... 105s Unpacking python3-pluggy (1.5.0-1) ... 105s Selecting previously unselected package python3-pytest. 105s Preparing to unpack .../5-python3-pytest_8.2.2-1ubuntu1_all.deb ... 105s Unpacking python3-pytest (8.2.2-1ubuntu1) ... 105s Selecting previously unselected package autopkgtest-satdep. 105s Preparing to unpack .../6-1-autopkgtest-satdep.deb ... 105s Unpacking autopkgtest-satdep (0) ... 105s Setting up python3-iniconfig (1.1.1-2) ... 105s Setting up libevent-2.1-7t64:arm64 (2.1.12-stable-10) ... 105s Setting up python3-packaging (24.0-1) ... 105s Setting up poolcounter (1.1.3-2build4) ... 106s info: Selecting GID from range 100 to 999 ... 106s info: Adding group `poolcounter' (GID 114) ... 106s info: The home dir / you specified already exists. 106s 106s info: Selecting UID from range 100 to 999 ... 106s 106s info: Adding system user `poolcounter' (UID 107) ... 106s info: Adding new user `poolcounter' (UID 107) with group `poolcounter' ... 106s warn: The home directory `/' already exists. Not touching this directory. 106s warn: Warning: The home directory `/' does not belong to the user you are currently creating. 106s Created symlink /etc/systemd/system/multi-user.target.wants/poolcounter.service → /usr/lib/systemd/system/poolcounter.service. 106s Setting up python3-pluggy (1.5.0-1) ... 107s Setting up python3-pytest (8.2.2-1ubuntu1) ... 107s Setting up autopkgtest-satdep (0) ... 107s Processing triggers for man-db (2.12.1-1) ... 107s Processing triggers for libc-bin (2.39-0ubuntu8.1) ... 110s (Reading database ... 78376 files and directories currently installed.) 110s Removing autopkgtest-satdep (0) ... 111s autopkgtest [11:49:22]: test command1: POOLCOUNTERD=/usr/bin/poolcounterd pytest-3 -v 111s autopkgtest [11:49:22]: test command1: [----------------------- 111s ============================= test session starts ============================== 111s platform linux -- Python 3.12.3, pytest-8.2.2, pluggy-1.5.0 -- /usr/bin/python3 111s cachedir: .pytest_cache 111s rootdir: /tmp/autopkgtest.0CnYLz/build.dRo/src 112s collecting ... collected 74 items 112s 112s tests/test_errors.py::test_garbage PASSED [ 1%] 112s tests/test_errors.py::test_locking_just_lockname[ACQ4ME] PASSED [ 2%] 112s tests/test_errors.py::test_locking_just_lockname[ACQ4ANY] PASSED [ 4%] 112s tests/test_errors.py::test_locking_no_workers[ACQ4ME] PASSED [ 5%] 112s tests/test_errors.py::test_locking_no_workers[ACQ4ANY] PASSED [ 6%] 112s tests/test_errors.py::test_locking_no_queue[ACQ4ME] PASSED [ 8%] 112s tests/test_errors.py::test_locking_no_queue[ACQ4ANY] PASSED [ 9%] 112s tests/test_errors.py::test_locking_non_integers[ACQ4ME] PASSED [ 10%] 112s tests/test_errors.py::test_locking_non_integers[ACQ4ANY] PASSED [ 12%] 112s tests/test_errors.py::test_locking_while_waiting[ACQ4ME] XPASS [ 13%] 112s tests/test_errors.py::test_locking_while_waiting[ACQ4ANY] XPASS [ 14%] 112s tests/test_errors.py::test_invalid_listen PASSED [ 16%] 112s tests/test_single_client.py::test_can_lock[ACQ4ME] PASSED [ 17%] 112s tests/test_single_client.py::test_can_lock[ACQ4ANY] PASSED [ 18%] 112s tests/test_single_client.py::test_can_lock_and_release[ACQ4ME] PASSED [ 20%] 112s tests/test_single_client.py::test_can_lock_and_release[ACQ4ANY] PASSED [ 21%] 112s tests/test_single_client.py::test_can_lock_and_release_and_relock[ACQ4ME] PASSED [ 22%] 112s tests/test_single_client.py::test_can_lock_and_release_and_relock[ACQ4ANY] PASSED [ 24%] 112s tests/test_single_client.py::test_can_lock_and_release_and_relock_and_unlock[ACQ4ME] PASSED [ 25%] 112s tests/test_single_client.py::test_can_lock_and_release_and_relock_and_unlock[ACQ4ANY] PASSED [ 27%] 112s tests/test_single_client.py::test_release_without_lock PASSED [ 28%] 112s tests/test_single_client.py::test_locking_holding_four_locks[ACQ4ME] PASSED [ 29%] 112s tests/test_single_client.py::test_locking_holding_four_locks[ACQ4ANY] PASSED [ 31%] 112s tests/test_single_client.py::test_locking_no_timeout[ACQ4ME] PASSED [ 32%] 112s tests/test_single_client.py::test_locking_no_timeout[ACQ4ANY] PASSED [ 33%] 112s tests/test_single_client.py::test_locking_timeout_left_off[ACQ4ME] PASSED [ 35%] 112s tests/test_single_client.py::test_locking_timeout_left_off[ACQ4ANY] PASSED [ 36%] 112s tests/test_single_client.py::test_locking_garbage_timeout[ACQ4ME] PASSED [ 37%] 112s tests/test_single_client.py::test_locking_garbage_timeout[ACQ4ANY] PASSED [ 39%] 112s tests/test_single_client.py::test_same_lock_twice[ACQ4ME] PASSED [ 40%] 112s tests/test_single_client.py::test_same_lock_twice[ACQ4ANY] PASSED [ 41%] 113s tests/test_single_client.py::test_same_lock_twice_timeout[ACQ4ME] PASSED [ 43%] 114s tests/test_single_client.py::test_same_lock_twice_timeout[ACQ4ANY] PASSED [ 44%] 114s tests/test_single_client.py::test_same_lock_twice_zero_timeout[ACQ4ME] PASSED [ 45%] 114s tests/test_single_client.py::test_same_lock_twice_zero_timeout[ACQ4ANY] PASSED [ 47%] 114s tests/test_single_client.py::test_same_lock_twice_queue_full[ACQ4ME] PASSED [ 48%] 114s tests/test_single_client.py::test_same_lock_twice_queue_full[ACQ4ANY] PASSED [ 50%] 114s tests/test_single_client.py::test_timeout_doesnt_unlock[ACQ4ME] PASSED [ 51%] 114s tests/test_single_client.py::test_timeout_doesnt_unlock[ACQ4ANY] PASSED [ 52%] 114s tests/test_single_client.py::test_timeout_doesnt_consume[ACQ4ME-0] PASSED [ 54%] 114s tests/test_single_client.py::test_timeout_doesnt_consume[ACQ4ME-1] PASSED [ 55%] 114s tests/test_single_client.py::test_timeout_doesnt_consume[ACQ4ANY-0] PASSED [ 56%] 114s tests/test_single_client.py::test_timeout_doesnt_consume[ACQ4ANY-1] PASSED [ 58%] 114s tests/test_single_client.py::test_no_queue_slots_not_consumed[ACQ4ME] PASSED [ 59%] 114s tests/test_single_client.py::test_no_queue_slots_not_consumed[ACQ4ANY] PASSED [ 60%] 114s tests/test_single_client.py::test_release_not_consumed[ACQ4ME] PASSED [ 62%] 114s tests/test_single_client.py::test_release_not_consumed[ACQ4ANY] PASSED [ 63%] 114s tests/test_single_client.py::test_disconnect_release[ACQ4ME] PASSED [ 64%] 114s tests/test_single_client.py::test_disconnect_release[ACQ4ANY] PASSED [ 66%] 114s tests/test_stats.py::test_uptime PASSED [ 67%] 114s tests/test_stats.py::test_full PASSED [ 68%] 114s tests/test_stats.py::test_waiting_workers PASSED [ 70%] 114s tests/test_stats.py::test_hashtable_entries PASSED [ 71%] 114s tests/test_two_clients.py::test_both_lock[ACQ4ME] PASSED [ 72%] 114s tests/test_two_clients.py::test_both_lock[ACQ4ANY] PASSED [ 74%] 114s tests/test_two_clients.py::test_only_one_lock_no_queue_space[ACQ4ME] PASSED [ 75%] 114s tests/test_two_clients.py::test_only_one_lock_no_queue_space[ACQ4ANY] PASSED [ 77%] 114s tests/test_two_clients.py::test_only_one_lock_no_workers_nor_queue_space[ACQ4ME] PASSED [ 78%] 114s tests/test_two_clients.py::test_only_one_lock_no_workers_nor_queue_space[ACQ4ANY] PASSED [ 79%] 114s tests/test_two_clients.py::test_close_socket_release PASSED [ 81%] 115s tests/test_two_clients.py::test_second_timeout_gt_zero PASSED [ 82%] 115s tests/test_two_clients.py::test_second_timeout_eq_zero PASSED [ 83%] 117s tests/test_two_clients.py::test_second_timeout_after_first_finish PASSED [ 85%] 117s tests/test_two_clients.py::test_second_timeout_after_first_finish_zero_timeout PASSED [ 86%] 117s tests/test_two_clients.py::test_second_lock_first_unlock PASSED [ 87%] 117s tests/test_two_clients.py::test_second_lock_first_unlock_any XPASS [ 89%] 117s tests/test_two_clients.py::test_done_no_unlock XPASS [ 90%] 117s tests/test_two_clients.py::test_done_no_consume_lock XPASS [ 91%] 117s tests/test_two_clients.py::test_lock_twice_multiple_executors[ACQ4ME] PASSED [ 93%] 117s tests/test_two_clients.py::test_lock_twice_multiple_executors[ACQ4ANY] PASSED [ 94%] 117s tests/test_two_clients.py::test_disconnect_while_timeout[ACQ4ME] PASSED [ 95%] 117s tests/test_two_clients.py::test_disconnect_while_timeout[ACQ4ANY] PASSED [ 97%] 122s tests/test_two_clients.py::test_no_timeout_after_initial_delay PASSED [ 98%] 127s tests/test_two_clients.py::test_no_early_timeout_after_initial_delay PASSED [100%] 127s 127s ======================== 69 passed, 5 xpassed in 15.35s ======================== 127s autopkgtest [11:49:38]: test command1: -----------------------] 128s autopkgtest [11:49:39]: test command1: - - - - - - - - - - results - - - - - - - - - - 128s command1 PASS 129s autopkgtest [11:49:40]: @@@@@@@@@@@@@@@@@@@@ summary 129s command1 PASS 139s nova [W] Skipping flock in bos03-arm64 139s Creating nova instance adt-oracular-arm64-poolcounter-20240608-114731-juju-7f2275-prod-proposed-migration-environment-2-8c494b90-08d3-4029-81ee-a39303902c82 from image adt/ubuntu-oracular-arm64-server-20240608.img (UUID 22fa5d69-8269-442f-bb5d-fd1454f7b08f)...