0s autopkgtest [00:25:54]: starting date and time: 2024-06-08 00:25:54+0000 0s autopkgtest [00:25:54]: git checkout: 433ed4cb Merge branch 'skia/nova_flock' into 'ubuntu/5.34+prod' 0s autopkgtest [00:25:54]: host juju-7f2275-prod-proposed-migration-environment-3; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.589qykpk/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-3@lcy02-58.secgroup --name adt-oracular-amd64-poolcounter-20240608-002554-juju-7f2275-prod-proposed-migration-environment-3-6851ab8f-1525-4cde-9f02-2d355df460ca --image adt/ubuntu-oracular-amd64-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-3 --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/ 115s autopkgtest [00:27:49]: testbed dpkg architecture: amd64 115s autopkgtest [00:27:49]: testbed apt version: 2.9.3 115s autopkgtest [00:27:49]: @@@@@@@@@@@@@@@@@@@@ test bed setup 115s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [110 kB] 115s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [7972 B] 115s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [339 kB] 115s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [2852 B] 115s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [44.3 kB] 115s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main i386 Packages [37.8 kB] 115s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main amd64 Packages [65.6 kB] 115s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/restricted i386 Packages [9340 B] 115s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/restricted amd64 Packages [27.4 kB] 115s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/universe i386 Packages [124 kB] 115s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/universe amd64 Packages [300 kB] 115s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse i386 Packages [3368 B] 115s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse amd64 Packages [9280 B] 115s Fetched 1081 kB in 0s (4351 kB/s) 115s Reading package lists... 117s Reading package lists... 117s Building dependency tree... 117s Reading state information... 118s Calculating upgrade... 118s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 118s Reading package lists... 119s Building dependency tree... 119s Reading state information... 119s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 119s Hit:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease 119s Hit:2 http://ftpmaster.internal/ubuntu oracular InRelease 119s Hit:3 http://ftpmaster.internal/ubuntu oracular-updates InRelease 119s Hit:4 http://ftpmaster.internal/ubuntu oracular-security InRelease 121s Reading package lists... 121s Reading package lists... 121s Building dependency tree... 121s Reading state information... 121s Calculating upgrade... 122s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 122s Reading package lists... 122s Building dependency tree... 122s Reading state information... 122s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 123s autopkgtest [00:27:57]: testbed running kernel: Linux 6.8.0-31-generic #31-Ubuntu SMP PREEMPT_DYNAMIC Sat Apr 20 00:40:06 UTC 2024 123s autopkgtest [00:27:57]: @@@@@@@@@@@@@@@@@@@@ apt-source poolcounter 124s Get:1 http://ftpmaster.internal/ubuntu oracular/universe poolcounter 1.1.3-2build4 (dsc) [2139 B] 124s Get:2 http://ftpmaster.internal/ubuntu oracular/universe poolcounter 1.1.3-2build4 (tar) [26.9 kB] 124s Get:3 http://ftpmaster.internal/ubuntu oracular/universe poolcounter 1.1.3-2build4 (diff) [3796 B] 125s gpgv: Signature made Mon Apr 1 07:12:32 2024 UTC 125s gpgv: using RSA key A089FB36AAFBDAD5ACC1325069F790171A210984 125s gpgv: Can't check signature: No public key 125s dpkg-source: warning: cannot verify inline signature for ./poolcounter_1.1.3-2build4.dsc: no acceptable signature found 125s autopkgtest [00:27:59]: testing package poolcounter version 1.1.3-2build4 125s autopkgtest [00:27:59]: build not needed 125s autopkgtest [00:27:59]: test command1: preparing testbed 125s Reading package lists... 125s Building dependency tree... 125s Reading state information... 126s Starting pkgProblemResolver with broken count: 0 126s Starting 2 pkgProblemResolver with broken count: 0 126s Done 126s The following additional packages will be installed: 126s libevent-2.1-7t64 poolcounter python3-iniconfig python3-packaging 126s python3-pluggy python3-pytest 126s The following NEW packages will be installed: 126s autopkgtest-satdep libevent-2.1-7t64 poolcounter python3-iniconfig 126s python3-packaging python3-pluggy python3-pytest 126s 0 upgraded, 7 newly installed, 0 to remove and 0 not upgraded. 126s Need to get 476 kB/476 kB of archives. 126s After this operation, 2022 kB of additional disk space will be used. 126s Get:1 /tmp/autopkgtest.YhHSxp/1-autopkgtest-satdep.deb autopkgtest-satdep amd64 0 [720 B] 126s Get:2 http://ftpmaster.internal/ubuntu oracular/main amd64 libevent-2.1-7t64 amd64 2.1.12-stable-10 [144 kB] 126s Get:3 http://ftpmaster.internal/ubuntu oracular/universe amd64 poolcounter amd64 1.1.3-2build4 [13.0 kB] 126s Get:4 http://ftpmaster.internal/ubuntu oracular/universe amd64 python3-iniconfig all 1.1.1-2 [6024 B] 126s Get:5 http://ftpmaster.internal/ubuntu oracular/main amd64 python3-packaging all 24.0-1 [41.1 kB] 126s Get:6 http://ftpmaster.internal/ubuntu oracular/universe amd64 python3-pluggy all 1.5.0-1 [21.0 kB] 126s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/universe amd64 python3-pytest all 8.2.2-1ubuntu1 [250 kB] 127s Fetched 476 kB in 0s (12.4 MB/s) 127s Selecting previously unselected package libevent-2.1-7t64:amd64. 127s (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 ... 74365 files and directories currently installed.) 127s Preparing to unpack .../0-libevent-2.1-7t64_2.1.12-stable-10_amd64.deb ... 127s Unpacking libevent-2.1-7t64:amd64 (2.1.12-stable-10) ... 127s Selecting previously unselected package poolcounter. 127s Preparing to unpack .../1-poolcounter_1.1.3-2build4_amd64.deb ... 127s Unpacking poolcounter (1.1.3-2build4) ... 127s Selecting previously unselected package python3-iniconfig. 127s Preparing to unpack .../2-python3-iniconfig_1.1.1-2_all.deb ... 127s Unpacking python3-iniconfig (1.1.1-2) ... 127s Selecting previously unselected package python3-packaging. 127s Preparing to unpack .../3-python3-packaging_24.0-1_all.deb ... 127s Unpacking python3-packaging (24.0-1) ... 127s Selecting previously unselected package python3-pluggy. 127s Preparing to unpack .../4-python3-pluggy_1.5.0-1_all.deb ... 127s Unpacking python3-pluggy (1.5.0-1) ... 127s Selecting previously unselected package python3-pytest. 127s Preparing to unpack .../5-python3-pytest_8.2.2-1ubuntu1_all.deb ... 127s Unpacking python3-pytest (8.2.2-1ubuntu1) ... 127s Selecting previously unselected package autopkgtest-satdep. 127s Preparing to unpack .../6-1-autopkgtest-satdep.deb ... 127s Unpacking autopkgtest-satdep (0) ... 127s Setting up python3-iniconfig (1.1.1-2) ... 128s Setting up libevent-2.1-7t64:amd64 (2.1.12-stable-10) ... 128s Setting up python3-packaging (24.0-1) ... 128s Setting up poolcounter (1.1.3-2build4) ... 128s info: Selecting GID from range 100 to 999 ... 128s info: Adding group `poolcounter' (GID 109) ... 128s info: The home dir / you specified already exists. 128s 128s info: Selecting UID from range 100 to 999 ... 128s 128s info: Adding system user `poolcounter' (UID 108) ... 128s info: Adding new user `poolcounter' (UID 108) with group `poolcounter' ... 128s warn: The home directory `/' already exists. Not touching this directory. 128s warn: Warning: The home directory `/' does not belong to the user you are currently creating. 128s Created symlink /etc/systemd/system/multi-user.target.wants/poolcounter.service → /usr/lib/systemd/system/poolcounter.service. 128s Setting up python3-pluggy (1.5.0-1) ... 129s Setting up python3-pytest (8.2.2-1ubuntu1) ... 129s Setting up autopkgtest-satdep (0) ... 129s Processing triggers for man-db (2.12.1-1) ... 130s Processing triggers for libc-bin (2.39-0ubuntu8.1) ... 132s (Reading database ... 74541 files and directories currently installed.) 132s Removing autopkgtest-satdep (0) ... 132s autopkgtest [00:28:06]: test command1: POOLCOUNTERD=/usr/bin/poolcounterd pytest-3 -v 132s autopkgtest [00:28:06]: test command1: [----------------------- 133s ============================= test session starts ============================== 133s platform linux -- Python 3.12.3, pytest-8.2.2, pluggy-1.5.0 -- /usr/bin/python3 133s cachedir: .pytest_cache 133s rootdir: /tmp/autopkgtest.YhHSxp/build.7sp/src 133s collecting ... collected 74 items 133s 133s tests/test_errors.py::test_garbage PASSED [ 1%] 133s tests/test_errors.py::test_locking_just_lockname[ACQ4ME] PASSED [ 2%] 133s tests/test_errors.py::test_locking_just_lockname[ACQ4ANY] PASSED [ 4%] 133s tests/test_errors.py::test_locking_no_workers[ACQ4ME] PASSED [ 5%] 133s tests/test_errors.py::test_locking_no_workers[ACQ4ANY] PASSED [ 6%] 133s tests/test_errors.py::test_locking_no_queue[ACQ4ME] PASSED [ 8%] 133s tests/test_errors.py::test_locking_no_queue[ACQ4ANY] PASSED [ 9%] 133s tests/test_errors.py::test_locking_non_integers[ACQ4ME] PASSED [ 10%] 133s tests/test_errors.py::test_locking_non_integers[ACQ4ANY] PASSED [ 12%] 133s tests/test_errors.py::test_locking_while_waiting[ACQ4ME] XPASS [ 13%] 133s tests/test_errors.py::test_locking_while_waiting[ACQ4ANY] XPASS [ 14%] 133s tests/test_errors.py::test_invalid_listen PASSED [ 16%] 133s tests/test_single_client.py::test_can_lock[ACQ4ME] PASSED [ 17%] 133s tests/test_single_client.py::test_can_lock[ACQ4ANY] PASSED [ 18%] 133s tests/test_single_client.py::test_can_lock_and_release[ACQ4ME] PASSED [ 20%] 133s tests/test_single_client.py::test_can_lock_and_release[ACQ4ANY] PASSED [ 21%] 133s tests/test_single_client.py::test_can_lock_and_release_and_relock[ACQ4ME] PASSED [ 22%] 133s tests/test_single_client.py::test_can_lock_and_release_and_relock[ACQ4ANY] PASSED [ 24%] 133s tests/test_single_client.py::test_can_lock_and_release_and_relock_and_unlock[ACQ4ME] PASSED [ 25%] 133s tests/test_single_client.py::test_can_lock_and_release_and_relock_and_unlock[ACQ4ANY] PASSED [ 27%] 133s tests/test_single_client.py::test_release_without_lock PASSED [ 28%] 133s tests/test_single_client.py::test_locking_holding_four_locks[ACQ4ME] PASSED [ 29%] 133s tests/test_single_client.py::test_locking_holding_four_locks[ACQ4ANY] PASSED [ 31%] 133s tests/test_single_client.py::test_locking_no_timeout[ACQ4ME] PASSED [ 32%] 133s tests/test_single_client.py::test_locking_no_timeout[ACQ4ANY] PASSED [ 33%] 133s tests/test_single_client.py::test_locking_timeout_left_off[ACQ4ME] PASSED [ 35%] 133s tests/test_single_client.py::test_locking_timeout_left_off[ACQ4ANY] PASSED [ 36%] 133s tests/test_single_client.py::test_locking_garbage_timeout[ACQ4ME] PASSED [ 37%] 133s tests/test_single_client.py::test_locking_garbage_timeout[ACQ4ANY] PASSED [ 39%] 133s tests/test_single_client.py::test_same_lock_twice[ACQ4ME] PASSED [ 40%] 133s tests/test_single_client.py::test_same_lock_twice[ACQ4ANY] PASSED [ 41%] 134s tests/test_single_client.py::test_same_lock_twice_timeout[ACQ4ME] PASSED [ 43%] 135s tests/test_single_client.py::test_same_lock_twice_timeout[ACQ4ANY] PASSED [ 44%] 135s tests/test_single_client.py::test_same_lock_twice_zero_timeout[ACQ4ME] PASSED [ 45%] 135s tests/test_single_client.py::test_same_lock_twice_zero_timeout[ACQ4ANY] PASSED [ 47%] 135s tests/test_single_client.py::test_same_lock_twice_queue_full[ACQ4ME] PASSED [ 48%] 135s tests/test_single_client.py::test_same_lock_twice_queue_full[ACQ4ANY] PASSED [ 50%] 135s tests/test_single_client.py::test_timeout_doesnt_unlock[ACQ4ME] PASSED [ 51%] 135s tests/test_single_client.py::test_timeout_doesnt_unlock[ACQ4ANY] PASSED [ 52%] 135s tests/test_single_client.py::test_timeout_doesnt_consume[ACQ4ME-0] PASSED [ 54%] 135s tests/test_single_client.py::test_timeout_doesnt_consume[ACQ4ME-1] PASSED [ 55%] 135s tests/test_single_client.py::test_timeout_doesnt_consume[ACQ4ANY-0] PASSED [ 56%] 135s tests/test_single_client.py::test_timeout_doesnt_consume[ACQ4ANY-1] PASSED [ 58%] 135s tests/test_single_client.py::test_no_queue_slots_not_consumed[ACQ4ME] PASSED [ 59%] 135s tests/test_single_client.py::test_no_queue_slots_not_consumed[ACQ4ANY] PASSED [ 60%] 135s tests/test_single_client.py::test_release_not_consumed[ACQ4ME] PASSED [ 62%] 135s tests/test_single_client.py::test_release_not_consumed[ACQ4ANY] PASSED [ 63%] 135s tests/test_single_client.py::test_disconnect_release[ACQ4ME] PASSED [ 64%] 135s tests/test_single_client.py::test_disconnect_release[ACQ4ANY] PASSED [ 66%] 135s tests/test_stats.py::test_uptime PASSED [ 67%] 135s tests/test_stats.py::test_full PASSED [ 68%] 135s tests/test_stats.py::test_waiting_workers PASSED [ 70%] 135s tests/test_stats.py::test_hashtable_entries PASSED [ 71%] 135s tests/test_two_clients.py::test_both_lock[ACQ4ME] PASSED [ 72%] 135s tests/test_two_clients.py::test_both_lock[ACQ4ANY] PASSED [ 74%] 135s tests/test_two_clients.py::test_only_one_lock_no_queue_space[ACQ4ME] PASSED [ 75%] 135s tests/test_two_clients.py::test_only_one_lock_no_queue_space[ACQ4ANY] PASSED [ 77%] 135s tests/test_two_clients.py::test_only_one_lock_no_workers_nor_queue_space[ACQ4ME] PASSED [ 78%] 135s tests/test_two_clients.py::test_only_one_lock_no_workers_nor_queue_space[ACQ4ANY] PASSED [ 79%] 135s tests/test_two_clients.py::test_close_socket_release PASSED [ 81%] 136s tests/test_two_clients.py::test_second_timeout_gt_zero PASSED [ 82%] 136s tests/test_two_clients.py::test_second_timeout_eq_zero PASSED [ 83%] 138s tests/test_two_clients.py::test_second_timeout_after_first_finish PASSED [ 85%] 138s tests/test_two_clients.py::test_second_timeout_after_first_finish_zero_timeout PASSED [ 86%] 138s tests/test_two_clients.py::test_second_lock_first_unlock PASSED [ 87%] 138s tests/test_two_clients.py::test_second_lock_first_unlock_any XPASS [ 89%] 138s tests/test_two_clients.py::test_done_no_unlock XPASS [ 90%] 138s tests/test_two_clients.py::test_done_no_consume_lock XPASS [ 91%] 138s tests/test_two_clients.py::test_lock_twice_multiple_executors[ACQ4ME] PASSED [ 93%] 138s tests/test_two_clients.py::test_lock_twice_multiple_executors[ACQ4ANY] PASSED [ 94%] 138s tests/test_two_clients.py::test_disconnect_while_timeout[ACQ4ME] PASSED [ 95%] 138s tests/test_two_clients.py::test_disconnect_while_timeout[ACQ4ANY] PASSED [ 97%] 143s tests/test_two_clients.py::test_no_timeout_after_initial_delay PASSED [ 98%] 148s tests/test_two_clients.py::test_no_early_timeout_after_initial_delay PASSED [100%] 148s 148s ======================== 69 passed, 5 xpassed in 15.26s ======================== 148s autopkgtest [00:28:22]: test command1: -----------------------] 148s command1 PASS 148s autopkgtest [00:28:22]: test command1: - - - - - - - - - - results - - - - - - - - - - 149s autopkgtest [00:28:23]: @@@@@@@@@@@@@@@@@@@@ summary 149s command1 PASS 161s nova [W] Skipping flock for amd64 161s Creating nova instance adt-oracular-amd64-poolcounter-20240608-002554-juju-7f2275-prod-proposed-migration-environment-3-6851ab8f-1525-4cde-9f02-2d355df460ca from image adt/ubuntu-oracular-amd64-server-20240607.img (UUID d996b44c-1e10-4875-aeab-5b4c434d75a2)...