0s autopkgtest [13:32:06]: starting date and time: 2025-05-02 13:32:06+0000 0s autopkgtest [13:32:06]: git checkout: 9986aa8c Merge branch 'skia/fix_network_interface' into 'ubuntu/production' 0s autopkgtest [13:32:06]: host juju-7f2275-prod-proposed-migration-environment-20; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.he9rnuhq/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:pytest --apt-upgrade poolcounter --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=pytest/8.3.5-2 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-20@bos03-arm64-7.secgroup --name adt-questing-arm64-poolcounter-20250502-133206-juju-7f2275-prod-proposed-migration-environment-20-bd08d40c-5aab-4af2-8a6b-02ff9cb03252 --image adt/ubuntu-questing-arm64-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-20 --net-id=net_prod-proposed-migration -e TERM=linux --mirror=http://ftpmaster.internal/ubuntu/ 82s autopkgtest [13:33:28]: testbed dpkg architecture: arm64 82s autopkgtest [13:33:28]: testbed apt version: 3.0.0 83s autopkgtest [13:33:29]: @@@@@@@@@@@@@@@@@@@@ test bed setup 83s autopkgtest [13:33:29]: testbed release detected to be: None 84s autopkgtest [13:33:30]: updating testbed package index (apt update) 84s Get:1 http://ftpmaster.internal/ubuntu questing-proposed InRelease [110 kB] 84s Hit:2 http://ftpmaster.internal/ubuntu questing InRelease 84s Hit:3 http://ftpmaster.internal/ubuntu questing-updates InRelease 85s Hit:4 http://ftpmaster.internal/ubuntu questing-security InRelease 85s Get:5 http://ftpmaster.internal/ubuntu questing-proposed/multiverse Sources [44.4 kB] 85s Get:6 http://ftpmaster.internal/ubuntu questing-proposed/main Sources [171 kB] 85s Get:7 http://ftpmaster.internal/ubuntu questing-proposed/universe Sources [2029 kB] 86s Get:8 http://ftpmaster.internal/ubuntu questing-proposed/main arm64 Packages [218 kB] 86s Get:9 http://ftpmaster.internal/ubuntu questing-proposed/universe arm64 Packages [1476 kB] 86s Get:10 http://ftpmaster.internal/ubuntu questing-proposed/multiverse arm64 Packages [15.4 kB] 86s Fetched 4063 kB in 2s (1879 kB/s) 87s Reading package lists... 88s autopkgtest [13:33:34]: upgrading testbed (apt dist-upgrade and autopurge) 88s Reading package lists... 88s Building dependency tree... 88s Reading state information... 89s Calculating upgrade...Starting pkgProblemResolver with broken count: 0 89s Starting 2 pkgProblemResolver with broken count: 0 89s Done 90s Entering ResolveByKeep 90s 90s Calculating upgrade... 91s The following packages will be upgraded: 91s htop libnpth0t64 mokutil mtd-utils nano usb.ids 91s 6 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 91s Need to get 1196 kB of archives. 91s After this operation, 727 kB of additional disk space will be used. 91s Get:1 http://ftpmaster.internal/ubuntu questing/main arm64 libnpth0t64 arm64 1.8-3 [8818 B] 91s Get:2 http://ftpmaster.internal/ubuntu questing/main arm64 nano arm64 8.4-1 [290 kB] 91s Get:3 http://ftpmaster.internal/ubuntu questing/main arm64 usb.ids all 2025.04.01-1 [223 kB] 91s Get:4 http://ftpmaster.internal/ubuntu questing/main arm64 htop arm64 3.4.1-4 [177 kB] 91s Get:5 http://ftpmaster.internal/ubuntu questing/main arm64 mokutil arm64 0.7.2-1 [28.4 kB] 91s Get:6 http://ftpmaster.internal/ubuntu questing/main arm64 mtd-utils arm64 1:2.3.0-1ubuntu1 [469 kB] 92s Fetched 1196 kB in 1s (1575 kB/s) 92s (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 ... 117820 files and directories currently installed.) 92s Preparing to unpack .../libnpth0t64_1.8-3_arm64.deb ... 92s Unpacking libnpth0t64:arm64 (1.8-3) over (1.8-2) ... 92s Setting up libnpth0t64:arm64 (1.8-3) ... 92s (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 ... 117820 files and directories currently installed.) 92s Preparing to unpack .../archives/nano_8.4-1_arm64.deb ... 92s Unpacking nano (8.4-1) over (8.3-1) ... 92s Preparing to unpack .../usb.ids_2025.04.01-1_all.deb ... 92s Unpacking usb.ids (2025.04.01-1) over (2025.01.14-1) ... 92s Preparing to unpack .../htop_3.4.1-4_arm64.deb ... 92s Unpacking htop (3.4.1-4) over (3.4.0-2) ... 92s Preparing to unpack .../mokutil_0.7.2-1_arm64.deb ... 92s Unpacking mokutil (0.7.2-1) over (0.6.0-2build3) ... 93s Preparing to unpack .../mtd-utils_1%3a2.3.0-1ubuntu1_arm64.deb ... 93s Unpacking mtd-utils (1:2.3.0-1ubuntu1) over (1:2.2.0-2ubuntu2) ... 93s Setting up mokutil (0.7.2-1) ... 93s Setting up htop (3.4.1-4) ... 93s Setting up mtd-utils (1:2.3.0-1ubuntu1) ... 93s Setting up usb.ids (2025.04.01-1) ... 93s Setting up nano (8.4-1) ... 93s Installing new version of config file /etc/nanorc ... 93s Processing triggers for libc-bin (2.41-6ubuntu1) ... 93s Processing triggers for man-db (2.13.0-1) ... 94s Processing triggers for install-info (7.1.1-1) ... 95s Reading package lists... 95s Building dependency tree... 95s Reading state information... 96s Starting pkgProblemResolver with broken count: 0 96s Starting 2 pkgProblemResolver with broken count: 0 96s Done 96s Solving dependencies... 97s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 99s autopkgtest [13:33:45]: testbed running kernel: Linux 6.14.0-15-generic #15-Ubuntu SMP PREEMPT_DYNAMIC Sun Apr 6 14:37:51 UTC 2025 100s autopkgtest [13:33:46]: @@@@@@@@@@@@@@@@@@@@ apt-source poolcounter 101s Get:1 http://ftpmaster.internal/ubuntu questing/universe poolcounter 1.1.3-3 (dsc) [2065 B] 101s Get:2 http://ftpmaster.internal/ubuntu questing/universe poolcounter 1.1.3-3 (tar) [26.9 kB] 101s Get:3 http://ftpmaster.internal/ubuntu questing/universe poolcounter 1.1.3-3 (diff) [3480 B] 101s gpgv: Signature made Sun Jun 30 05:09:49 2024 UTC 101s gpgv: using RSA key D8CB59F05DBB9E0538C4819DF105F8101B05269B 101s gpgv: issuer "legoktm@riseup.net" 101s gpgv: Can't check signature: No public key 101s dpkg-source: warning: cannot verify inline signature for ./poolcounter_1.1.3-3.dsc: no acceptable signature found 101s autopkgtest [13:33:47]: testing package poolcounter version 1.1.3-3 102s autopkgtest [13:33:48]: build not needed 102s autopkgtest [13:33:48]: test command1: preparing testbed 102s Reading package lists... 103s Building dependency tree... 103s Reading state information... 103s Starting pkgProblemResolver with broken count: 0 103s Starting 2 pkgProblemResolver with broken count: 0 103s Done 104s The following NEW packages will be installed: 104s libevent-2.1-7t64 poolcounter python3-iniconfig python3-packaging 104s python3-pluggy python3-pytest 104s 0 upgraded, 6 newly installed, 0 to remove and 0 not upgraded. 104s Need to get 484 kB of archives. 104s After this operation, 2198 kB of additional disk space will be used. 104s Get:1 http://ftpmaster.internal/ubuntu questing/main arm64 libevent-2.1-7t64 arm64 2.1.12-stable-10 [140 kB] 105s Get:2 http://ftpmaster.internal/ubuntu questing/universe arm64 poolcounter arm64 1.1.3-3 [12.9 kB] 105s Get:3 http://ftpmaster.internal/ubuntu questing/universe arm64 python3-iniconfig all 1.1.1-2 [6024 B] 105s Get:4 http://ftpmaster.internal/ubuntu questing/main arm64 python3-packaging all 24.2-1 [51.5 kB] 105s Get:5 http://ftpmaster.internal/ubuntu questing/universe arm64 python3-pluggy all 1.5.0-1 [21.0 kB] 105s Get:6 http://ftpmaster.internal/ubuntu questing-proposed/universe arm64 python3-pytest all 8.3.5-2 [252 kB] 105s Fetched 484 kB in 1s (861 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 ... 117821 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-3_arm64.deb ... 105s Unpacking poolcounter (1.1.3-3) ... 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.2-1_all.deb ... 105s Unpacking python3-packaging (24.2-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.3.5-2_all.deb ... 105s Unpacking python3-pytest (8.3.5-2) ... 105s Setting up python3-iniconfig (1.1.1-2) ... 106s Setting up libevent-2.1-7t64:arm64 (2.1.12-stable-10) ... 106s Setting up python3-packaging (24.2-1) ... 106s Setting up poolcounter (1.1.3-3) ... 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) ... 106s Setting up python3-pytest (8.3.5-2) ... 107s Processing triggers for man-db (2.13.0-1) ... 107s Processing triggers for libc-bin (2.41-6ubuntu1) ... 108s autopkgtest [13:33:54]: test command1: POOLCOUNTERD=/usr/bin/poolcounterd pytest-3 -v 108s autopkgtest [13:33:54]: test command1: [----------------------- 109s ============================= test session starts ============================== 109s platform linux -- Python 3.13.3, pytest-8.3.5, pluggy-1.5.0 -- /usr/bin/python3 109s cachedir: .pytest_cache 109s rootdir: /tmp/autopkgtest.b2djcN/build.zMU/src 109s plugins: typeguard-4.4.2 109s collecting ... collected 74 items 109s 109s tests/test_errors.py::test_garbage PASSED [ 1%] 109s tests/test_errors.py::test_locking_just_lockname[ACQ4ME] PASSED [ 2%] 109s tests/test_errors.py::test_locking_just_lockname[ACQ4ANY] PASSED [ 4%] 109s tests/test_errors.py::test_locking_no_workers[ACQ4ME] PASSED [ 5%] 109s tests/test_errors.py::test_locking_no_workers[ACQ4ANY] PASSED [ 6%] 109s tests/test_errors.py::test_locking_no_queue[ACQ4ME] PASSED [ 8%] 109s tests/test_errors.py::test_locking_no_queue[ACQ4ANY] PASSED [ 9%] 109s tests/test_errors.py::test_locking_non_integers[ACQ4ME] PASSED [ 10%] 109s tests/test_errors.py::test_locking_non_integers[ACQ4ANY] PASSED [ 12%] 109s tests/test_errors.py::test_locking_while_waiting[ACQ4ME] XPASS [ 13%] 114s tests/test_errors.py::test_locking_while_waiting[ACQ4ANY] XFAIL [ 14%] 114s tests/test_errors.py::test_invalid_listen PASSED [ 16%] 114s tests/test_single_client.py::test_can_lock[ACQ4ME] PASSED [ 17%] 114s tests/test_single_client.py::test_can_lock[ACQ4ANY] PASSED [ 18%] 114s tests/test_single_client.py::test_can_lock_and_release[ACQ4ME] PASSED [ 20%] 114s tests/test_single_client.py::test_can_lock_and_release[ACQ4ANY] PASSED [ 21%] 114s tests/test_single_client.py::test_can_lock_and_release_and_relock[ACQ4ME] PASSED [ 22%] 114s tests/test_single_client.py::test_can_lock_and_release_and_relock[ACQ4ANY] PASSED [ 24%] 114s tests/test_single_client.py::test_can_lock_and_release_and_relock_and_unlock[ACQ4ME] PASSED [ 25%] 114s tests/test_single_client.py::test_can_lock_and_release_and_relock_and_unlock[ACQ4ANY] PASSED [ 27%] 114s tests/test_single_client.py::test_release_without_lock PASSED [ 28%] 114s tests/test_single_client.py::test_locking_holding_four_locks[ACQ4ME] PASSED [ 29%] 114s tests/test_single_client.py::test_locking_holding_four_locks[ACQ4ANY] PASSED [ 31%] 114s tests/test_single_client.py::test_locking_no_timeout[ACQ4ME] PASSED [ 32%] 114s tests/test_single_client.py::test_locking_no_timeout[ACQ4ANY] PASSED [ 33%] 114s tests/test_single_client.py::test_locking_timeout_left_off[ACQ4ME] PASSED [ 35%] 114s tests/test_single_client.py::test_locking_timeout_left_off[ACQ4ANY] PASSED [ 36%] 114s tests/test_single_client.py::test_locking_garbage_timeout[ACQ4ME] PASSED [ 37%] 114s tests/test_single_client.py::test_locking_garbage_timeout[ACQ4ANY] PASSED [ 39%] 114s tests/test_single_client.py::test_same_lock_twice[ACQ4ME] PASSED [ 40%] 114s tests/test_single_client.py::test_same_lock_twice[ACQ4ANY] PASSED [ 41%] 115s tests/test_single_client.py::test_same_lock_twice_timeout[ACQ4ME] PASSED [ 43%] 116s tests/test_single_client.py::test_same_lock_twice_timeout[ACQ4ANY] PASSED [ 44%] 116s tests/test_single_client.py::test_same_lock_twice_zero_timeout[ACQ4ME] PASSED [ 45%] 116s tests/test_single_client.py::test_same_lock_twice_zero_timeout[ACQ4ANY] PASSED [ 47%] 116s tests/test_single_client.py::test_same_lock_twice_queue_full[ACQ4ME] PASSED [ 48%] 116s tests/test_single_client.py::test_same_lock_twice_queue_full[ACQ4ANY] PASSED [ 50%] 116s tests/test_single_client.py::test_timeout_doesnt_unlock[ACQ4ME] PASSED [ 51%] 116s tests/test_single_client.py::test_timeout_doesnt_unlock[ACQ4ANY] PASSED [ 52%] 116s tests/test_single_client.py::test_timeout_doesnt_consume[ACQ4ME-0] PASSED [ 54%] 116s tests/test_single_client.py::test_timeout_doesnt_consume[ACQ4ME-1] PASSED [ 55%] 116s tests/test_single_client.py::test_timeout_doesnt_consume[ACQ4ANY-0] PASSED [ 56%] 116s tests/test_single_client.py::test_timeout_doesnt_consume[ACQ4ANY-1] PASSED [ 58%] 116s tests/test_single_client.py::test_no_queue_slots_not_consumed[ACQ4ME] PASSED [ 59%] 116s tests/test_single_client.py::test_no_queue_slots_not_consumed[ACQ4ANY] PASSED [ 60%] 116s tests/test_single_client.py::test_release_not_consumed[ACQ4ME] PASSED [ 62%] 116s tests/test_single_client.py::test_release_not_consumed[ACQ4ANY] PASSED [ 63%] 116s tests/test_single_client.py::test_disconnect_release[ACQ4ME] PASSED [ 64%] 116s tests/test_single_client.py::test_disconnect_release[ACQ4ANY] PASSED [ 66%] 116s tests/test_stats.py::test_uptime PASSED [ 67%] 116s tests/test_stats.py::test_full PASSED [ 68%] 116s tests/test_stats.py::test_waiting_workers PASSED [ 70%] 116s tests/test_stats.py::test_hashtable_entries PASSED [ 71%] 116s tests/test_two_clients.py::test_both_lock[ACQ4ME] PASSED [ 72%] 116s tests/test_two_clients.py::test_both_lock[ACQ4ANY] PASSED [ 74%] 116s tests/test_two_clients.py::test_only_one_lock_no_queue_space[ACQ4ME] PASSED [ 75%] 116s tests/test_two_clients.py::test_only_one_lock_no_queue_space[ACQ4ANY] PASSED [ 77%] 116s tests/test_two_clients.py::test_only_one_lock_no_workers_nor_queue_space[ACQ4ME] PASSED [ 78%] 116s tests/test_two_clients.py::test_only_one_lock_no_workers_nor_queue_space[ACQ4ANY] PASSED [ 79%] 116s tests/test_two_clients.py::test_close_socket_release PASSED [ 81%] 117s tests/test_two_clients.py::test_second_timeout_gt_zero PASSED [ 82%] 117s tests/test_two_clients.py::test_second_timeout_eq_zero PASSED [ 83%] 119s tests/test_two_clients.py::test_second_timeout_after_first_finish PASSED [ 85%] 119s tests/test_two_clients.py::test_second_timeout_after_first_finish_zero_timeout PASSED [ 86%] 119s tests/test_two_clients.py::test_second_lock_first_unlock PASSED [ 87%] 119s tests/test_two_clients.py::test_second_lock_first_unlock_any XPASS [ 89%] 119s tests/test_two_clients.py::test_done_no_unlock XFAIL [ 90%] 119s tests/test_two_clients.py::test_done_no_consume_lock XPASS [ 91%] 119s tests/test_two_clients.py::test_lock_twice_multiple_executors[ACQ4ME] PASSED [ 93%] 119s tests/test_two_clients.py::test_lock_twice_multiple_executors[ACQ4ANY] PASSED [ 94%] 119s tests/test_two_clients.py::test_disconnect_while_timeout[ACQ4ME] PASSED [ 95%] 119s tests/test_two_clients.py::test_disconnect_while_timeout[ACQ4ANY] PASSED [ 97%] 124s tests/test_two_clients.py::test_no_timeout_after_initial_delay PASSED [ 98%] 129s tests/test_two_clients.py::test_no_early_timeout_after_initial_delay PASSED [100%] 129s 129s ================== 69 passed, 2 xfailed, 3 xpassed in 20.31s =================== 129s autopkgtest [13:34:15]: test command1: -----------------------] 130s command1 PASS 130s autopkgtest [13:34:16]: test command1: - - - - - - - - - - results - - - - - - - - - - 130s autopkgtest [13:34:16]: @@@@@@@@@@@@@@@@@@@@ summary 130s command1 PASS 148s nova [W] Using flock in prodstack6-arm64 148s Creating nova instance adt-questing-arm64-poolcounter-20250502-133206-juju-7f2275-prod-proposed-migration-environment-20-bd08d40c-5aab-4af2-8a6b-02ff9cb03252 from image adt/ubuntu-questing-arm64-server-20250502.img (UUID a0b7b7fd-ad05-4ea9-97eb-0f52dbbe98e1)... 148s nova [W] Timed out waiting for e1b6108f-49d9-44c3-bb46-5be1d2dcb571 to get deleted.