0s autopkgtest [11:12:17]: starting date and time: 2025-05-02 11:12:17+0000 0s autopkgtest [11:12:17]: git checkout: 9986aa8c Merge branch 'skia/fix_network_interface' into 'ubuntu/production' 0s autopkgtest [11:12:17]: host juju-7f2275-prod-proposed-migration-environment-15; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.dvb8www2/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-s390x --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-15@bos03-s390x-6.secgroup --name adt-questing-s390x-poolcounter-20250502-111217-juju-7f2275-prod-proposed-migration-environment-15-2685425d-4850-415c-97d4-aba590d26f16 --image adt/ubuntu-questing-s390x-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-15 --net-id=net_prod-proposed-migration-s390x -e TERM=linux --mirror=http://ftpmaster.internal/ubuntu/ 108s autopkgtest [11:14:05]: testbed dpkg architecture: s390x 108s autopkgtest [11:14:05]: testbed apt version: 3.0.0 109s autopkgtest [11:14:06]: @@@@@@@@@@@@@@@@@@@@ test bed setup 109s autopkgtest [11:14:06]: testbed release detected to be: None 110s autopkgtest [11:14:07]: updating testbed package index (apt update) 110s Get:1 http://ftpmaster.internal/ubuntu questing-proposed InRelease [110 kB] 110s Hit:2 http://ftpmaster.internal/ubuntu questing InRelease 110s Hit:3 http://ftpmaster.internal/ubuntu questing-updates InRelease 110s Hit:4 http://ftpmaster.internal/ubuntu questing-security InRelease 110s Get:5 http://ftpmaster.internal/ubuntu questing-proposed/main Sources [175 kB] 110s Get:6 http://ftpmaster.internal/ubuntu questing-proposed/universe Sources [2076 kB] 111s Get:7 http://ftpmaster.internal/ubuntu questing-proposed/multiverse Sources [44.4 kB] 111s Get:8 http://ftpmaster.internal/ubuntu questing-proposed/main s390x Packages [208 kB] 111s Get:9 http://ftpmaster.internal/ubuntu questing-proposed/universe s390x Packages [1079 kB] 111s Get:10 http://ftpmaster.internal/ubuntu questing-proposed/multiverse s390x Packages [9148 B] 111s Fetched 3701 kB in 1s (3065 kB/s) 112s Reading package lists... 112s autopkgtest [11:14:09]: upgrading testbed (apt dist-upgrade and autopurge) 112s Reading package lists... 112s Building dependency tree... 112s Reading state information... 113s Calculating upgrade...Starting pkgProblemResolver with broken count: 0 113s Starting 2 pkgProblemResolver with broken count: 0 113s Done 113s Entering ResolveByKeep 113s 113s Calculating upgrade... 113s The following packages will be upgraded: 113s htop nano 113s 2 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 113s Need to get 488 kB of archives. 113s After this operation, 3072 B of additional disk space will be used. 113s Get:1 http://ftpmaster.internal/ubuntu questing/main s390x nano s390x 8.4-1 [299 kB] 114s Get:2 http://ftpmaster.internal/ubuntu questing/main s390x htop s390x 3.4.1-4 [189 kB] 114s Fetched 488 kB in 0s (1022 kB/s) 114s (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 ... 81472 files and directories currently installed.) 114s Preparing to unpack .../archives/nano_8.4-1_s390x.deb ... 114s Unpacking nano (8.4-1) over (8.3-1) ... 114s Preparing to unpack .../htop_3.4.1-4_s390x.deb ... 114s Unpacking htop (3.4.1-4) over (3.4.0-2) ... 114s Setting up htop (3.4.1-4) ... 114s Setting up nano (8.4-1) ... 114s Installing new version of config file /etc/nanorc ... 114s Processing triggers for man-db (2.13.0-1) ... 115s Processing triggers for install-info (7.1.1-1) ... 115s Reading package lists... 115s Building dependency tree... 115s Reading state information... 115s Starting pkgProblemResolver with broken count: 0 115s Starting 2 pkgProblemResolver with broken count: 0 115s Done 115s Solving dependencies... 115s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 118s autopkgtest [11:14:15]: testbed running kernel: Linux 6.14.0-15-generic #15-Ubuntu SMP Sun Apr 6 13:39:00 UTC 2025 118s autopkgtest [11:14:15]: @@@@@@@@@@@@@@@@@@@@ apt-source poolcounter 119s Get:1 http://ftpmaster.internal/ubuntu questing/universe poolcounter 1.1.3-3 (dsc) [2065 B] 119s Get:2 http://ftpmaster.internal/ubuntu questing/universe poolcounter 1.1.3-3 (tar) [26.9 kB] 119s Get:3 http://ftpmaster.internal/ubuntu questing/universe poolcounter 1.1.3-3 (diff) [3480 B] 120s gpgv: Signature made Sun Jun 30 05:09:49 2024 UTC 120s gpgv: using RSA key D8CB59F05DBB9E0538C4819DF105F8101B05269B 120s gpgv: issuer "legoktm@riseup.net" 120s gpgv: Can't check signature: No public key 120s dpkg-source: warning: cannot verify inline signature for ./poolcounter_1.1.3-3.dsc: no acceptable signature found 120s autopkgtest [11:14:17]: testing package poolcounter version 1.1.3-3 120s autopkgtest [11:14:17]: build not needed 120s autopkgtest [11:14:17]: test command1: preparing testbed 121s Reading package lists... 121s Building dependency tree... 121s Reading state information... 121s Starting pkgProblemResolver with broken count: 0 121s Starting 2 pkgProblemResolver with broken count: 0 121s Done 121s The following NEW packages will be installed: 121s libevent-2.1-7t64 poolcounter python3-iniconfig python3-packaging 121s python3-pluggy python3-pytest 121s 0 upgraded, 6 newly installed, 0 to remove and 0 not upgraded. 121s Need to get 489 kB of archives. 121s After this operation, 2116 kB of additional disk space will be used. 121s Get:1 http://ftpmaster.internal/ubuntu questing/main s390x libevent-2.1-7t64 s390x 2.1.12-stable-10 [145 kB] 121s Get:2 http://ftpmaster.internal/ubuntu questing/universe s390x poolcounter s390x 1.1.3-3 [13.7 kB] 121s Get:3 http://ftpmaster.internal/ubuntu questing/universe s390x python3-iniconfig all 1.1.1-2 [6024 B] 121s Get:4 http://ftpmaster.internal/ubuntu questing/main s390x python3-packaging all 24.2-1 [51.5 kB] 121s Get:5 http://ftpmaster.internal/ubuntu questing/universe s390x python3-pluggy all 1.5.0-1 [21.0 kB] 121s Get:6 http://ftpmaster.internal/ubuntu questing-proposed/universe s390x python3-pytest all 8.3.5-2 [252 kB] 122s Fetched 489 kB in 0s (1031 kB/s) 122s Selecting previously unselected package libevent-2.1-7t64:s390x. 122s (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 ... 81472 files and directories currently installed.) 122s Preparing to unpack .../0-libevent-2.1-7t64_2.1.12-stable-10_s390x.deb ... 122s Unpacking libevent-2.1-7t64:s390x (2.1.12-stable-10) ... 122s Selecting previously unselected package poolcounter. 122s Preparing to unpack .../1-poolcounter_1.1.3-3_s390x.deb ... 122s Unpacking poolcounter (1.1.3-3) ... 122s Selecting previously unselected package python3-iniconfig. 122s Preparing to unpack .../2-python3-iniconfig_1.1.1-2_all.deb ... 122s Unpacking python3-iniconfig (1.1.1-2) ... 122s Selecting previously unselected package python3-packaging. 122s Preparing to unpack .../3-python3-packaging_24.2-1_all.deb ... 122s Unpacking python3-packaging (24.2-1) ... 122s Selecting previously unselected package python3-pluggy. 122s Preparing to unpack .../4-python3-pluggy_1.5.0-1_all.deb ... 122s Unpacking python3-pluggy (1.5.0-1) ... 122s Selecting previously unselected package python3-pytest. 122s Preparing to unpack .../5-python3-pytest_8.3.5-2_all.deb ... 122s Unpacking python3-pytest (8.3.5-2) ... 122s Setting up python3-iniconfig (1.1.1-2) ... 122s Setting up libevent-2.1-7t64:s390x (2.1.12-stable-10) ... 122s Setting up python3-packaging (24.2-1) ... 122s Setting up poolcounter (1.1.3-3) ... 122s Created symlink '/etc/systemd/system/multi-user.target.wants/poolcounter.service' → '/usr/lib/systemd/system/poolcounter.service'. 122s Setting up python3-pluggy (1.5.0-1) ... 122s Setting up python3-pytest (8.3.5-2) ... 123s Processing triggers for man-db (2.13.0-1) ... 123s Processing triggers for libc-bin (2.41-6ubuntu1) ... 124s autopkgtest [11:14:21]: test command1: POOLCOUNTERD=/usr/bin/poolcounterd pytest-3 -v 124s autopkgtest [11:14:21]: test command1: [----------------------- 124s ============================= test session starts ============================== 124s platform linux -- Python 3.13.3, pytest-8.3.5, pluggy-1.5.0 -- /usr/bin/python3 124s cachedir: .pytest_cache 124s rootdir: /tmp/autopkgtest.MitMGQ/build.ttw/src 124s plugins: typeguard-4.4.2 124s collecting ... collected 74 items 124s 124s tests/test_errors.py::test_garbage PASSED [ 1%] 124s tests/test_errors.py::test_locking_just_lockname[ACQ4ME] PASSED [ 2%] 124s tests/test_errors.py::test_locking_just_lockname[ACQ4ANY] PASSED [ 4%] 124s tests/test_errors.py::test_locking_no_workers[ACQ4ME] PASSED [ 5%] 124s tests/test_errors.py::test_locking_no_workers[ACQ4ANY] PASSED [ 6%] 124s tests/test_errors.py::test_locking_no_queue[ACQ4ME] PASSED [ 8%] 124s tests/test_errors.py::test_locking_no_queue[ACQ4ANY] PASSED [ 9%] 124s tests/test_errors.py::test_locking_non_integers[ACQ4ME] PASSED [ 10%] 124s tests/test_errors.py::test_locking_non_integers[ACQ4ANY] PASSED [ 12%] 129s tests/test_errors.py::test_locking_while_waiting[ACQ4ME] XFAIL [ 13%] 134s tests/test_errors.py::test_locking_while_waiting[ACQ4ANY] XFAIL [ 14%] 134s tests/test_errors.py::test_invalid_listen PASSED [ 16%] 134s tests/test_single_client.py::test_can_lock[ACQ4ME] PASSED [ 17%] 134s tests/test_single_client.py::test_can_lock[ACQ4ANY] PASSED [ 18%] 134s tests/test_single_client.py::test_can_lock_and_release[ACQ4ME] PASSED [ 20%] 135s tests/test_single_client.py::test_can_lock_and_release[ACQ4ANY] PASSED [ 21%] 135s tests/test_single_client.py::test_can_lock_and_release_and_relock[ACQ4ME] PASSED [ 22%] 135s tests/test_single_client.py::test_can_lock_and_release_and_relock[ACQ4ANY] PASSED [ 24%] 135s tests/test_single_client.py::test_can_lock_and_release_and_relock_and_unlock[ACQ4ME] PASSED [ 25%] 135s tests/test_single_client.py::test_can_lock_and_release_and_relock_and_unlock[ACQ4ANY] PASSED [ 27%] 135s tests/test_single_client.py::test_release_without_lock PASSED [ 28%] 135s tests/test_single_client.py::test_locking_holding_four_locks[ACQ4ME] PASSED [ 29%] 135s tests/test_single_client.py::test_locking_holding_four_locks[ACQ4ANY] PASSED [ 31%] 135s tests/test_single_client.py::test_locking_no_timeout[ACQ4ME] PASSED [ 32%] 135s tests/test_single_client.py::test_locking_no_timeout[ACQ4ANY] PASSED [ 33%] 135s tests/test_single_client.py::test_locking_timeout_left_off[ACQ4ME] PASSED [ 35%] 135s tests/test_single_client.py::test_locking_timeout_left_off[ACQ4ANY] PASSED [ 36%] 135s tests/test_single_client.py::test_locking_garbage_timeout[ACQ4ME] PASSED [ 37%] 135s tests/test_single_client.py::test_locking_garbage_timeout[ACQ4ANY] PASSED [ 39%] 135s tests/test_single_client.py::test_same_lock_twice[ACQ4ME] PASSED [ 40%] 135s tests/test_single_client.py::test_same_lock_twice[ACQ4ANY] PASSED [ 41%] 135s tests/test_single_client.py::test_same_lock_twice_timeout[ACQ4ME] PASSED [ 43%] 136s tests/test_single_client.py::test_same_lock_twice_timeout[ACQ4ANY] PASSED [ 44%] 136s tests/test_single_client.py::test_same_lock_twice_zero_timeout[ACQ4ME] PASSED [ 45%] 136s tests/test_single_client.py::test_same_lock_twice_zero_timeout[ACQ4ANY] PASSED [ 47%] 136s tests/test_single_client.py::test_same_lock_twice_queue_full[ACQ4ME] PASSED [ 48%] 136s tests/test_single_client.py::test_same_lock_twice_queue_full[ACQ4ANY] PASSED [ 50%] 137s tests/test_single_client.py::test_timeout_doesnt_unlock[ACQ4ME] PASSED [ 51%] 137s tests/test_single_client.py::test_timeout_doesnt_unlock[ACQ4ANY] PASSED [ 52%] 137s tests/test_single_client.py::test_timeout_doesnt_consume[ACQ4ME-0] PASSED [ 54%] 137s tests/test_single_client.py::test_timeout_doesnt_consume[ACQ4ME-1] PASSED [ 55%] 137s tests/test_single_client.py::test_timeout_doesnt_consume[ACQ4ANY-0] PASSED [ 56%] 137s tests/test_single_client.py::test_timeout_doesnt_consume[ACQ4ANY-1] PASSED [ 58%] 137s tests/test_single_client.py::test_no_queue_slots_not_consumed[ACQ4ME] PASSED [ 59%] 137s tests/test_single_client.py::test_no_queue_slots_not_consumed[ACQ4ANY] PASSED [ 60%] 137s tests/test_single_client.py::test_release_not_consumed[ACQ4ME] PASSED [ 62%] 137s tests/test_single_client.py::test_release_not_consumed[ACQ4ANY] PASSED [ 63%] 137s tests/test_single_client.py::test_disconnect_release[ACQ4ME] PASSED [ 64%] 137s tests/test_single_client.py::test_disconnect_release[ACQ4ANY] PASSED [ 66%] 137s tests/test_stats.py::test_uptime PASSED [ 67%] 137s tests/test_stats.py::test_full PASSED [ 68%] 137s tests/test_stats.py::test_waiting_workers PASSED [ 70%] 137s tests/test_stats.py::test_hashtable_entries PASSED [ 71%] 137s tests/test_two_clients.py::test_both_lock[ACQ4ME] PASSED [ 72%] 137s tests/test_two_clients.py::test_both_lock[ACQ4ANY] PASSED [ 74%] 137s tests/test_two_clients.py::test_only_one_lock_no_queue_space[ACQ4ME] PASSED [ 75%] 137s tests/test_two_clients.py::test_only_one_lock_no_queue_space[ACQ4ANY] PASSED [ 77%] 137s tests/test_two_clients.py::test_only_one_lock_no_workers_nor_queue_space[ACQ4ME] PASSED [ 78%] 137s tests/test_two_clients.py::test_only_one_lock_no_workers_nor_queue_space[ACQ4ANY] PASSED [ 79%] 137s tests/test_two_clients.py::test_close_socket_release PASSED [ 81%] 138s tests/test_two_clients.py::test_second_timeout_gt_zero PASSED [ 82%] 138s tests/test_two_clients.py::test_second_timeout_eq_zero PASSED [ 83%] 140s tests/test_two_clients.py::test_second_timeout_after_first_finish PASSED [ 85%] 140s tests/test_two_clients.py::test_second_timeout_after_first_finish_zero_timeout PASSED [ 86%] 140s tests/test_two_clients.py::test_second_lock_first_unlock PASSED [ 87%] 140s tests/test_two_clients.py::test_second_lock_first_unlock_any XFAIL [ 89%] 140s tests/test_two_clients.py::test_done_no_unlock XFAIL [ 90%] 140s tests/test_two_clients.py::test_done_no_consume_lock XFAIL [ 91%] 140s tests/test_two_clients.py::test_lock_twice_multiple_executors[ACQ4ME] PASSED [ 93%] 140s tests/test_two_clients.py::test_lock_twice_multiple_executors[ACQ4ANY] PASSED [ 94%] 140s tests/test_two_clients.py::test_disconnect_while_timeout[ACQ4ME] PASSED [ 95%] 140s tests/test_two_clients.py::test_disconnect_while_timeout[ACQ4ANY] PASSED [ 97%] 145s tests/test_two_clients.py::test_no_timeout_after_initial_delay PASSED [ 98%] 150s tests/test_two_clients.py::test_no_early_timeout_after_initial_delay PASSED [100%] 150s 150s ======================== 69 passed, 5 xfailed in 25.42s ======================== 150s autopkgtest [11:14:47]: test command1: -----------------------] 150s command1 PASS 150s autopkgtest [11:14:47]: test command1: - - - - - - - - - - results - - - - - - - - - - 151s autopkgtest [11:14:48]: @@@@@@@@@@@@@@@@@@@@ summary 151s command1 PASS 168s nova [W] Using flock in prodstack6-s390x 168s flock: timeout while waiting to get lock 168s Creating nova instance adt-questing-s390x-poolcounter-20250502-111217-juju-7f2275-prod-proposed-migration-environment-15-2685425d-4850-415c-97d4-aba590d26f16 from image adt/ubuntu-questing-s390x-server-20250502.img (UUID 632ecfca-a19d-4f3a-af48-b7883fa0ccf2)... 168s nova [W] Timed out waiting for 82e5495d-f005-44c9-b96e-6d58b2464c3c to get deleted.