0s autopkgtest [22:46:31]: starting date: 2024-03-18 0s autopkgtest [22:46:31]: git checkout: d9c0295b adt_testbed.py: supress warnings from apt using a shell pipeline 0s autopkgtest [22:46:31]: host juju-7f2275-prod-proposed-migration-environment-4; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.9urskquk/out --timeout-copy=6000 --setup-commands 'sed -i "s/ports.ubuntu.com/ftpmaster.internal/; s/ubuntu-ports/ubuntu/" /etc/apt/sources.list `ls /etc/apt/sources.list.d/*.list 2>/dev/null || true`; ln -s /dev/null /etc/systemd/system/bluetooth.service; printf "http_proxy=http://squid.internal:3128\nhttps_proxy=http://squid.internal:3128\nno_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,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com\n" >> /etc/environment' --apt-pocket=proposed=src:openssl --apt-upgrade stunnel4 --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=openssl/3.0.13-0ubuntu2 -- lxd -r lxd-armhf-10.44.124.170 lxd-armhf-10.44.124.170:autopkgtest/ubuntu/noble/armhf 47s autopkgtest [22:47:18]: @@@@@@@@@@@@@@@@@@@@ test bed setup 50s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [117 kB] 50s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/multiverse Sources [52.0 kB] 50s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [6540 B] 50s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [3720 kB] 51s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [485 kB] 51s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main armhf Packages [586 kB] 51s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main armhf c-n-f Metadata [2492 B] 51s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/restricted armhf Packages [1372 B] 51s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/restricted armhf c-n-f Metadata [116 B] 51s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/universe armhf Packages [3580 kB] 51s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/universe armhf c-n-f Metadata [7776 B] 51s Get:12 http://ftpmaster.internal/ubuntu noble-proposed/multiverse armhf Packages [35.6 kB] 51s Get:13 http://ftpmaster.internal/ubuntu noble-proposed/multiverse armhf c-n-f Metadata [116 B] 62s Fetched 8593 kB in 4s (2336 kB/s) 63s Reading package lists... 77s tee: /proc/self/fd/2: Permission denied 112s Hit:1 http://ports.ubuntu.com/ubuntu-ports noble InRelease 112s Hit:2 http://ftpmaster.internal/ubuntu noble InRelease 112s Hit:3 http://ports.ubuntu.com/ubuntu-ports noble-updates InRelease 112s Hit:4 http://ftpmaster.internal/ubuntu noble-updates InRelease 112s Hit:5 http://ports.ubuntu.com/ubuntu-ports noble-backports InRelease 112s Hit:6 http://ftpmaster.internal/ubuntu noble-security InRelease 112s Hit:7 http://ports.ubuntu.com/ubuntu-ports noble-security InRelease 112s Hit:8 http://ftpmaster.internal/ubuntu noble-proposed InRelease 117s Reading package lists... 118s Reading package lists... 119s Building dependency tree... 119s Reading state information... 120s Calculating upgrade... 121s The following packages have been kept back: 121s openssl 121s 0 upgraded, 0 newly installed, 0 to remove and 1 not upgraded. 122s Reading package lists... 122s Building dependency tree... 122s Reading state information... 124s 0 upgraded, 0 newly installed, 0 to remove and 1 not upgraded. 126s autopkgtest [22:48:37]: rebooting testbed after setup commands that affected boot 158s autopkgtest [22:49:09]: testbed running kernel: Linux 5.4.0-171-generic #189-Ubuntu SMP Fri Jan 5 14:23:34 UTC 2024 162s autopkgtest [22:49:13]: testbed dpkg architecture: armhf 175s autopkgtest [22:49:26]: @@@@@@@@@@@@@@@@@@@@ apt-source stunnel4 183s Get:1 http://ftpmaster.internal/ubuntu noble/universe stunnel4 3:5.70-2 (dsc) [2581 B] 183s Get:2 http://ftpmaster.internal/ubuntu noble/universe stunnel4 3:5.70-2 (tar) [883 kB] 183s Get:3 http://ftpmaster.internal/ubuntu noble/universe stunnel4 3:5.70-2 (asc) [963 B] 183s Get:4 http://ftpmaster.internal/ubuntu noble/universe stunnel4 3:5.70-2 (diff) [53.2 kB] 183s gpgv: Signature made Sun Sep 10 18:42:44 2023 UTC 183s gpgv: using RSA key 2EE7A7A517FC124CF115C354651EEFB02527DF13 183s gpgv: issuer "roam@debian.org" 183s gpgv: Can't check signature: No public key 183s dpkg-source: warning: cannot verify inline signature for ./stunnel4_5.70-2.dsc: no acceptable signature found 184s autopkgtest [22:49:35]: testing package stunnel4 version 3:5.70-2 184s autopkgtest [22:49:35]: build not needed 192s autopkgtest [22:49:43]: test debian-python: preparing testbed 206s Reading package lists... 207s Building dependency tree... 207s Reading state information... 208s Correcting dependencies...Starting pkgProblemResolver with broken count: 0 208s Starting 2 pkgProblemResolver with broken count: 0 208s Done 209s Done 210s Starting pkgProblemResolver with broken count: 0 210s Starting 2 pkgProblemResolver with broken count: 0 210s Done 211s The following additional packages will be installed: 211s python3-all stunnel4 211s Suggested packages: 211s logcheck-database 212s The following NEW packages will be installed: 212s python3-all stunnel4 212s 0 upgraded, 2 newly installed, 0 to remove and 1 not upgraded. 212s 1 not fully installed or removed. 212s Need to get 206 kB of archives. 212s After this operation, 486 kB of additional disk space will be used. 212s Get:1 http://ftpmaster.internal/ubuntu noble/universe armhf stunnel4 armhf 3:5.70-2 [205 kB] 212s Get:2 http://ftpmaster.internal/ubuntu noble/main armhf python3-all armhf 3.12.1-0ubuntu2 [906 B] 213s Fetched 206 kB in 1s (357 kB/s) 214s Selecting previously unselected package stunnel4. 214s (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 ... 58620 files and directories currently installed.) 214s Preparing to unpack .../stunnel4_3%3a5.70-2_armhf.deb ... 214s Unpacking stunnel4 (3:5.70-2) ... 214s Selecting previously unselected package python3-all. 214s Preparing to unpack .../python3-all_3.12.1-0ubuntu2_armhf.deb ... 214s Unpacking python3-all (3.12.1-0ubuntu2) ... 214s Setting up stunnel4 (3:5.70-2) ... 214s Creating group 'stunnel4' with GID 988. 214s Creating user 'stunnel4' (stunnel service system account) with UID 988 and GID 988. 215s Created symlink /etc/systemd/system/multi-user.target.wants/stunnel.target → /usr/lib/systemd/system/stunnel.target. 216s Setting up python3-all (3.12.1-0ubuntu2) ... 216s Setting up autopkgtest-satdep (0) ... 216s Processing triggers for man-db (2.12.0-3) ... 232s (Reading database ... 58665 files and directories currently installed.) 232s Removing autopkgtest-satdep (0) ... 242s autopkgtest [22:50:33]: test debian-python: set -e; for py in $(py3versions -i); do printf -- '\n\n====== %s\n\n' "$py"; env PYTHONPATH="$(pwd)/debian/tests/python" "$py" -B -u -m struntime --certdir "$(pwd)/debian/tests/certs"; done 242s autopkgtest [22:50:33]: test debian-python: [----------------------- 244s 244s 244s ====== python3.12 244s 245s Using /tmp/struntime.rkkfbw_i as a temporary directory 245s Trying to obtain the version of /usr/bin/stunnel4 245s Started `/usr/bin/stunnel4 -version` as process 856 245s Got stunnel version 5.70 245s [main] Starting to do things 245s [main] Awaiting the 'listener started' event 245s [find_listening_port] Looking for a port to listen on 245s [find_listening_port] Trying localhost port 6502 245s [listener] Telling the main thread about [127.0.0.1]:6502 245s [listener] Awaiting client connections... 245s [main] Apparently we are listening on [127.0.0.1]:6502 245s [main] Testing cleartext connections 245s [test_connect [127.0.0.1]:6502 0] Trying port 6502 encrypted False 245s [test_connect [127.0.0.1]:6502 1] Trying port 6502 encrypted False 245s [test_connect [127.0.0.1]:6502 2] Trying port 6502 encrypted False 245s [test_connect [127.0.0.1]:6502 3] Trying port 6502 encrypted False 245s [test_connect [127.0.0.1]:6502 4] Trying port 6502 encrypted False 245s [test_connect [127.0.0.1]:6502 5] Trying port 6502 encrypted False 245s [test_connect [127.0.0.1]:6502 6] Trying port 6502 encrypted False 245s [test_connect [127.0.0.1]:6502 7] Trying port 6502 encrypted False 245s [test_connect [127.0.0.1]:6502 8] Trying port 6502 encrypted False 245s [test_connect [127.0.0.1]:6502 9] Trying port 6502 encrypted False 245s [test_connect [127.0.0.1]:6502 3] Opening an unencrypted connection 245s [listener] A client connected from somewhere 245s [[127.0.0.1]:42102] New connection 245s [[127.0.0.1]:42102] Telling the main thread 245s [[127.0.0.1]:42102] Let them tell us something... 245s [test_connect [127.0.0.1]:6502 3] Connected to the server: [127.0.0.1]:42102 245s [test_connect [127.0.0.1]:6502 7] Opening an unencrypted connection 245s [test_connect [127.0.0.1]:6502 9] Opening an unencrypted connection 245s [listener] A client connected from somewhere 245s [[127.0.0.1]:42116] New connection 245s [[127.0.0.1]:42116] Telling the main thread 245s [[127.0.0.1]:42116] Let them tell us something... 245s [listener] A client connected from somewhere 245s [[127.0.0.1]:42120] New connection 245s [[127.0.0.1]:42120] Telling the main thread 245s [[127.0.0.1]:42120] Let them tell us something... 245s [test_connect [127.0.0.1]:6502 7] Connected to the server: [127.0.0.1]:42116 245s [test_connect [127.0.0.1]:6502 9] Connected to the server: [127.0.0.1]:42120 245s [test_connect [127.0.0.1]:6502 6] Opening an unencrypted connection 245s [listener] A client connected from somewhere 245s [[127.0.0.1]:42130] New connection 245s [[127.0.0.1]:42130] Telling the main thread 245s [[127.0.0.1]:42130] Let them tell us something... 245s [test_connect [127.0.0.1]:6502 6] Connected to the server: [127.0.0.1]:42130 246s [test_connect [127.0.0.1]:6502 4] Opening an unencrypted connection 246s [listener] A client connected from somewhere 246s [[127.0.0.1]:42134] New connection 246s [[127.0.0.1]:42134] Telling the main thread 246s [[127.0.0.1]:42134] Let them tell us something... 246s [test_connect [127.0.0.1]:6502 4] Connected to the server: [127.0.0.1]:42134 246s [test_connect [127.0.0.1]:6502 8] Opening an unencrypted connection 246s [listener] A client connected from somewhere 246s [[127.0.0.1]:42138] New connection 246s [[127.0.0.1]:42138] Telling the main thread 246s [[127.0.0.1]:42138] Let them tell us something... 246s [test_connect [127.0.0.1]:6502 8] Connected to the server: [127.0.0.1]:42138 246s [test_connect [127.0.0.1]:6502 7] Sending something... 246s [test_connect [127.0.0.1]:6502 7] Waiting for the main thread to figure it out 246s [[127.0.0.1]:42116] Telling the main thread about b'Hello 7\n' 246s [[127.0.0.1]:42116] Writing something back... 246s [[127.0.0.1]:42116] Telling the main thread about b'There!\n' 246s [[127.0.0.1]:42116] Closing down the writer socket 246s [test_connect [127.0.0.1]:6502 7] The listener acknowledged [127.0.0.1]:42116 246s [test_connect [127.0.0.1]:6502 7] Waiting for the server to receive it... 246s [test_connect [127.0.0.1]:6502 7] Waiting for the server to send something 246s [test_connect [127.0.0.1]:6502 7] Trying to receive the actual data 246s [test_connect [127.0.0.1]:6502 7] Waiting for the server to close the connection 246s [[127.0.0.1]:42116] Telling the main thread done 246s [test_connect [127.0.0.1]:6502 7] Waiting for an EOF on the reader socket 246s [test_connect [127.0.0.1]:6502 7] Closing our writer socket, too 246s [test_connect [127.0.0.1]:6502 7] Letting the main thread know we're done 246s [test_connect [127.0.0.1]:6502 7] Done 246s [process_connections] Fetching task plain-7 246s [process_connections] Waiting for task plain-7 246s [process_connections] Done with task plain-7 246s [test_connect [127.0.0.1]:6502 0] Opening an unencrypted connection 246s [test_connect [127.0.0.1]:6502 1] Opening an unencrypted connection 246s [test_connect [127.0.0.1]:6502 2] Opening an unencrypted connection 246s [test_connect [127.0.0.1]:6502 5] Opening an unencrypted connection 246s [listener] A client connected from somewhere 246s [[127.0.0.1]:42150] New connection 246s [[127.0.0.1]:42150] Telling the main thread 246s [[127.0.0.1]:42150] Let them tell us something... 246s [listener] A client connected from somewhere 246s [[127.0.0.1]:42160] New connection 246s [[127.0.0.1]:42160] Telling the main thread 246s [[127.0.0.1]:42160] Let them tell us something... 246s [listener] A client connected from somewhere 246s [[127.0.0.1]:42162] New connection 246s [[127.0.0.1]:42162] Telling the main thread 246s [[127.0.0.1]:42162] Let them tell us something... 246s [listener] A client connected from somewhere 246s [[127.0.0.1]:42174] New connection 246s [[127.0.0.1]:42174] Telling the main thread 246s [[127.0.0.1]:42174] Let them tell us something... 246s [test_connect [127.0.0.1]:6502 0] Connected to the server: [127.0.0.1]:42150 246s [test_connect [127.0.0.1]:6502 1] Connected to the server: [127.0.0.1]:42160 246s [test_connect [127.0.0.1]:6502 2] Connected to the server: [127.0.0.1]:42162 246s [test_connect [127.0.0.1]:6502 5] Connected to the server: [127.0.0.1]:42174 246s [test_connect [127.0.0.1]:6502 8] Sending something... 246s [test_connect [127.0.0.1]:6502 8] Waiting for the main thread to figure it out 246s [[127.0.0.1]:42138] Telling the main thread about b'Hello 8\n' 246s [[127.0.0.1]:42138] Writing something back... 246s [[127.0.0.1]:42138] Telling the main thread about b'There!\n' 246s [[127.0.0.1]:42138] Closing down the writer socket 246s [test_connect [127.0.0.1]:6502 9] Sending something... 246s [test_connect [127.0.0.1]:6502 9] Waiting for the main thread to figure it out 246s [test_connect [127.0.0.1]:6502 8] The listener acknowledged [127.0.0.1]:42138 246s [test_connect [127.0.0.1]:6502 8] Waiting for the server to receive it... 246s [test_connect [127.0.0.1]:6502 8] Waiting for the server to send something 246s [test_connect [127.0.0.1]:6502 8] Trying to receive the actual data 246s [test_connect [127.0.0.1]:6502 8] Waiting for the server to close the connection 246s [[127.0.0.1]:42138] Telling the main thread done 246s [[127.0.0.1]:42120] Telling the main thread about b'Hello 9\n' 246s [[127.0.0.1]:42120] Writing something back... 246s [[127.0.0.1]:42120] Telling the main thread about b'There!\n' 246s [[127.0.0.1]:42120] Closing down the writer socket 246s [test_connect [127.0.0.1]:6502 8] Waiting for an EOF on the reader socket 246s [test_connect [127.0.0.1]:6502 8] Closing our writer socket, too 246s [test_connect [127.0.0.1]:6502 9] The listener acknowledged [127.0.0.1]:42120 246s [test_connect [127.0.0.1]:6502 9] Waiting for the server to receive it... 246s [test_connect [127.0.0.1]:6502 9] Waiting for the server to send something 246s [test_connect [127.0.0.1]:6502 9] Trying to receive the actual data 246s [test_connect [127.0.0.1]:6502 9] Waiting for the server to close the connection 246s [[127.0.0.1]:42120] Telling the main thread done 246s [test_connect [127.0.0.1]:6502 8] Letting the main thread know we're done 246s [test_connect [127.0.0.1]:6502 8] Done 246s [test_connect [127.0.0.1]:6502 9] Waiting for an EOF on the reader socket 246s [test_connect [127.0.0.1]:6502 9] Closing our writer socket, too 246s [process_connections] Fetching task plain-8 246s [process_connections] Waiting for task plain-8 246s [process_connections] Done with task plain-8 246s [test_connect [127.0.0.1]:6502 9] Letting the main thread know we're done 246s [test_connect [127.0.0.1]:6502 9] Done 246s [process_connections] Fetching task plain-9 246s [process_connections] Waiting for task plain-9 246s [process_connections] Done with task plain-9 246s [test_connect [127.0.0.1]:6502 6] Sending something... 246s [test_connect [127.0.0.1]:6502 6] Waiting for the main thread to figure it out 246s [[127.0.0.1]:42130] Telling the main thread about b'Hello 6\n' 246s [[127.0.0.1]:42130] Writing something back... 246s [[127.0.0.1]:42130] Telling the main thread about b'There!\n' 246s [[127.0.0.1]:42130] Closing down the writer socket 246s [test_connect [127.0.0.1]:6502 6] The listener acknowledged [127.0.0.1]:42130 246s [test_connect [127.0.0.1]:6502 6] Waiting for the server to receive it... 246s [test_connect [127.0.0.1]:6502 6] Waiting for the server to send something 246s [test_connect [127.0.0.1]:6502 6] Trying to receive the actual data 246s [test_connect [127.0.0.1]:6502 6] Waiting for the server to close the connection 246s [[127.0.0.1]:42130] Telling the main thread done 246s [test_connect [127.0.0.1]:6502 6] Waiting for an EOF on the reader socket 246s [test_connect [127.0.0.1]:6502 6] Closing our writer socket, too 246s [test_connect [127.0.0.1]:6502 6] Letting the main thread know we're done 246s [test_connect [127.0.0.1]:6502 6] Done 246s [process_connections] Fetching task plain-6 246s [process_connections] Waiting for task plain-6 246s [process_connections] Done with task plain-6 246s [test_connect [127.0.0.1]:6502 3] Sending something... 246s [test_connect [127.0.0.1]:6502 3] Waiting for the main thread to figure it out 246s [[127.0.0.1]:42102] Telling the main thread about b'Hello 3\n' 246s [[127.0.0.1]:42102] Writing something back... 246s [[127.0.0.1]:42102] Telling the main thread about b'There!\n' 246s [[127.0.0.1]:42102] Closing down the writer socket 246s [test_connect [127.0.0.1]:6502 3] The listener acknowledged [127.0.0.1]:42102 246s [test_connect [127.0.0.1]:6502 3] Waiting for the server to receive it... 246s [test_connect [127.0.0.1]:6502 3] Waiting for the server to send something 246s [test_connect [127.0.0.1]:6502 3] Trying to receive the actual data 246s [test_connect [127.0.0.1]:6502 3] Waiting for the server to close the connection 246s [[127.0.0.1]:42102] Telling the main thread done 246s [test_connect [127.0.0.1]:6502 5] Sending something... 246s [test_connect [127.0.0.1]:6502 5] Waiting for the main thread to figure it out 246s [test_connect [127.0.0.1]:6502 3] Waiting for an EOF on the reader socket 246s [test_connect [127.0.0.1]:6502 3] Closing our writer socket, too 246s [[127.0.0.1]:42174] Telling the main thread about b'Hello 5\n' 246s [[127.0.0.1]:42174] Writing something back... 246s [[127.0.0.1]:42174] Telling the main thread about b'There!\n' 246s [[127.0.0.1]:42174] Closing down the writer socket 246s [test_connect [127.0.0.1]:6502 3] Letting the main thread know we're done 246s [test_connect [127.0.0.1]:6502 3] Done 246s [process_connections] Fetching task plain-3 246s [process_connections] Waiting for task plain-3 246s [process_connections] Done with task plain-3 246s [test_connect [127.0.0.1]:6502 5] The listener acknowledged [127.0.0.1]:42174 246s [test_connect [127.0.0.1]:6502 5] Waiting for the server to receive it... 246s [test_connect [127.0.0.1]:6502 5] Waiting for the server to send something 246s [test_connect [127.0.0.1]:6502 5] Trying to receive the actual data 246s [test_connect [127.0.0.1]:6502 5] Waiting for the server to close the connection 246s [[127.0.0.1]:42174] Telling the main thread done 246s [test_connect [127.0.0.1]:6502 5] Waiting for an EOF on the reader socket 246s [test_connect [127.0.0.1]:6502 5] Closing our writer socket, too 246s [test_connect [127.0.0.1]:6502 5] Letting the main thread know we're done 246s [test_connect [127.0.0.1]:6502 5] Done 246s [process_connections] Fetching task plain-5 246s [process_connections] Waiting for task plain-5 246s [process_connections] Done with task plain-5 246s [test_connect [127.0.0.1]:6502 4] Sending something... 246s [test_connect [127.0.0.1]:6502 4] Waiting for the main thread to figure it out 246s [[127.0.0.1]:42134] Telling the main thread about b'Hello 4\n' 246s [[127.0.0.1]:42134] Writing something back... 246s [[127.0.0.1]:42134] Telling the main thread about b'There!\n' 246s [[127.0.0.1]:42134] Closing down the writer socket 246s [test_connect [127.0.0.1]:6502 4] The listener acknowledged [127.0.0.1]:42134 246s [test_connect [127.0.0.1]:6502 4] Waiting for the server to receive it... 246s [test_connect [127.0.0.1]:6502 4] Waiting for the server to send something 246s [test_connect [127.0.0.1]:6502 4] Trying to receive the actual data 246s [test_connect [127.0.0.1]:6502 4] Waiting for the server to close the connection 246s [[127.0.0.1]:42134] Telling the main thread done 246s [test_connect [127.0.0.1]:6502 4] Waiting for an EOF on the reader socket 246s [test_connect [127.0.0.1]:6502 4] Closing our writer socket, too 246s [test_connect [127.0.0.1]:6502 4] Letting the main thread know we're done 246s [test_connect [127.0.0.1]:6502 4] Done 246s [process_connections] Fetching task plain-4 246s [process_connections] Waiting for task plain-4 246s [process_connections] Done with task plain-4 246s [test_connect [127.0.0.1]:6502 1] Sending something... 246s [test_connect [127.0.0.1]:6502 1] Waiting for the main thread to figure it out 246s [[127.0.0.1]:42160] Telling the main thread about b'Hello 1\n' 246s [[127.0.0.1]:42160] Writing something back... 246s [[127.0.0.1]:42160] Telling the main thread about b'There!\n' 246s [[127.0.0.1]:42160] Closing down the writer socket 246s [test_connect [127.0.0.1]:6502 1] The listener acknowledged [127.0.0.1]:42160 246s [test_connect [127.0.0.1]:6502 1] Waiting for the server to receive it... 246s [test_connect [127.0.0.1]:6502 1] Waiting for the server to send something 246s [test_connect [127.0.0.1]:6502 1] Trying to receive the actual data 246s [test_connect [127.0.0.1]:6502 1] Waiting for the server to close the connection 246s [[127.0.0.1]:42160] Telling the main thread done 246s [test_connect [127.0.0.1]:6502 1] Waiting for an EOF on the reader socket 246s [test_connect [127.0.0.1]:6502 1] Closing our writer socket, too 246s [test_connect [127.0.0.1]:6502 1] Letting the main thread know we're done 246s [test_connect [127.0.0.1]:6502 1] Done 246s [process_connections] Fetching task plain-1 246s [process_connections] Waiting for task plain-1 246s [process_connections] Done with task plain-1 247s [test_connect [127.0.0.1]:6502 0] Sending something... 247s [test_connect [127.0.0.1]:6502 0] Waiting for the main thread to figure it out 247s [test_connect [127.0.0.1]:6502 2] Sending something... 247s [test_connect [127.0.0.1]:6502 2] Waiting for the main thread to figure it out 247s [[127.0.0.1]:42150] Telling the main thread about b'Hello 0\n' 247s [[127.0.0.1]:42150] Writing something back... 247s [[127.0.0.1]:42150] Telling the main thread about b'There!\n' 247s [[127.0.0.1]:42150] Closing down the writer socket 247s [[127.0.0.1]:42162] Telling the main thread about b'Hello 2\n' 247s [[127.0.0.1]:42162] Writing something back... 247s [[127.0.0.1]:42162] Telling the main thread about b'There!\n' 247s [[127.0.0.1]:42162] Closing down the writer socket 247s [test_connect [127.0.0.1]:6502 0] The listener acknowledged [127.0.0.1]:42150 247s [test_connect [127.0.0.1]:6502 0] Waiting for the server to receive it... 247s [test_connect [127.0.0.1]:6502 0] Waiting for the server to send something 247s [test_connect [127.0.0.1]:6502 0] Trying to receive the actual data 247s [test_connect [127.0.0.1]:6502 0] Waiting for the server to close the connection 247s [test_connect [127.0.0.1]:6502 2] The listener acknowledged [127.0.0.1]:42162 247s [test_connect [127.0.0.1]:6502 2] Waiting for the server to receive it... 247s [test_connect [127.0.0.1]:6502 2] Waiting for the server to send something 247s [test_connect [127.0.0.1]:6502 2] Trying to receive the actual data 247s [test_connect [127.0.0.1]:6502 2] Waiting for the server to close the connection 247s [[127.0.0.1]:42150] Telling the main thread done 247s [[127.0.0.1]:42162] Telling the main thread done 247s [test_connect [127.0.0.1]:6502 0] Waiting for an EOF on the reader socket 247s [test_connect [127.0.0.1]:6502 0] Closing our writer socket, too 247s [test_connect [127.0.0.1]:6502 2] Waiting for an EOF on the reader socket 247s [test_connect [127.0.0.1]:6502 2] Closing our writer socket, too 247s [test_connect [127.0.0.1]:6502 0] Letting the main thread know we're done 247s [test_connect [127.0.0.1]:6502 0] Done 247s [test_connect [127.0.0.1]:6502 2] Letting the main thread know we're done 247s [test_connect [127.0.0.1]:6502 2] Done 247s [process_connections] Fetching task plain-0 247s [process_connections] Waiting for task plain-0 247s [process_connections] Done with task plain-0 247s [process_connections] Fetching task plain-2 247s [process_connections] Waiting for task plain-2 247s [process_connections] Done with task plain-2 247s [main] Picking a listen address:port for stunnel 247s [find_listening_port] Looking for a port to listen on 247s [find_listening_port] Trying 127.0.0.1 port 6503 247s [find_listening_port] got 6503, shutting down the listener 247s [main] Will put stunnel at 127.0.0.1:6503 247s [main] Preparing the stunnel config file 247s [main] Using config file /tmp/struntime.rkkfbw_i/stunnel.conf 247s [main] 247s [main] pid = /tmp/struntime.rkkfbw_i/stunnel.pid 247s [main] foreground = yes 247s [main] 247s [main] cert = /tmp/autopkgtest.gFbPuo/build.Q2u/src/debian/tests/certs/certificate.pem 247s [main] key = /tmp/struntime.rkkfbw_i/key.pem 247s [main] 247s [main] [test] 247s [main] accept = 127.0.0.1:6503 247s [main] connect = 127.0.0.1:6502 247s [main] End of the config file 247s [main] Launching the stunnel server 247s [main] - got pid 860 247s [main] Launching the stunnel output pipe thread 247s [main] Waiting for stunnel to start up 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[ui]: stunnel 5.70 on arm-unknown-linux-gnueabihf platform' 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[ui]: Compiled/running with OpenSSL 3.0.10 1 Aug 2023' 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[ui]: Threading:PTHREAD Sockets:POLL,IPv6,SYSTEMD TLS:ENGINE,OCSP,PSK,SNI Auth:LIBWRAP' 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[ui]: Reading configuration from file /tmp/struntime.rkkfbw_i/stunnel.conf' 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[ui]: UTF-8 byte order mark not detected' 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[ui]: FIPS mode disabled' 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[ui]: Configuration successful' 247s [stunnel_output] The main thread ought to know 247s [main] Testing the encrypted connections 247s [test_connect [127.0.0.1]:6503 0] Trying port 6503 encrypted True 247s [test_connect [127.0.0.1]:6503 1] Trying port 6503 encrypted True 247s [test_connect [127.0.0.1]:6503 2] Trying port 6503 encrypted True 247s [test_connect [127.0.0.1]:6503 3] Trying port 6503 encrypted True 247s [test_connect [127.0.0.1]:6503 4] Trying port 6503 encrypted True 247s [test_connect [127.0.0.1]:6503 5] Trying port 6503 encrypted True 247s [test_connect [127.0.0.1]:6503 6] Trying port 6503 encrypted True 247s [test_connect [127.0.0.1]:6503 7] Trying port 6503 encrypted True 247s [test_connect [127.0.0.1]:6503 8] Trying port 6503 encrypted True 247s [test_connect [127.0.0.1]:6503 9] Trying port 6503 encrypted True 247s [test_connect [127.0.0.1]:6503 6] Creating an SSL context 247s [test_connect [127.0.0.1]:6503 6] - cert required 247s [test_connect [127.0.0.1]:6503 6] - load_verify_locations() 247s [test_connect [127.0.0.1]:6503 6] Opening an SSL connection 247s [test_connect [127.0.0.1]:6503 8] Creating an SSL context 247s [test_connect [127.0.0.1]:6503 8] - cert required 247s [test_connect [127.0.0.1]:6503 8] - load_verify_locations() 247s [test_connect [127.0.0.1]:6503 8] Opening an SSL connection 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[0]: Service [test] accepted connection from 127.0.0.1:52768' 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[1]: Service [test] accepted connection from 127.0.0.1:52782' 247s [test_connect [127.0.0.1]:6503 6] Connected to the server: [127.0.0.1]:52768 247s [test_connect [127.0.0.1]:6503 8] Connected to the server: [127.0.0.1]:52782 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[0]: s_connect: connected 127.0.0.1:6502' 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[0]: Service [test] connected remote server from 127.0.0.1:42186' 247s [listener] A client connected from somewhere 247s [[127.0.0.1]:42186] New connection 247s [[127.0.0.1]:42186] Telling the main thread 247s [[127.0.0.1]:42186] Let them tell us something... 247s [listener] A client connected from somewhere 247s [[127.0.0.1]:42200] New connection 247s [[127.0.0.1]:42200] Telling the main thread 247s [[127.0.0.1]:42200] Let them tell us something... 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[1]: s_connect: connected 127.0.0.1:6502' 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[1]: Service [test] connected remote server from 127.0.0.1:42200' 247s [test_connect [127.0.0.1]:6503 4] Creating an SSL context 247s [test_connect [127.0.0.1]:6503 4] - cert required 247s [test_connect [127.0.0.1]:6503 4] - load_verify_locations() 247s [test_connect [127.0.0.1]:6503 4] Opening an SSL connection 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[2]: Service [test] accepted connection from 127.0.0.1:52794' 247s [test_connect [127.0.0.1]:6503 4] Connected to the server: [127.0.0.1]:52794 247s [listener] A client connected from somewhere 247s [[127.0.0.1]:42206] New connection 247s [[127.0.0.1]:42206] Telling the main thread 247s [[127.0.0.1]:42206] Let them tell us something... 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[2]: s_connect: connected 127.0.0.1:6502' 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[2]: Service [test] connected remote server from 127.0.0.1:42206' 247s [test_connect [127.0.0.1]:6503 0] Creating an SSL context 247s [test_connect [127.0.0.1]:6503 0] - cert required 247s [test_connect [127.0.0.1]:6503 0] - load_verify_locations() 247s [test_connect [127.0.0.1]:6503 0] Opening an SSL connection 247s [test_connect [127.0.0.1]:6503 3] Creating an SSL context 247s [test_connect [127.0.0.1]:6503 3] - cert required 247s [test_connect [127.0.0.1]:6503 3] - load_verify_locations() 247s [test_connect [127.0.0.1]:6503 3] Opening an SSL connection 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[3]: Service [test] accepted connection from 127.0.0.1:52802' 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[4]: Service [test] accepted connection from 127.0.0.1:52812' 247s [test_connect [127.0.0.1]:6503 0] Connected to the server: [127.0.0.1]:52802 247s [test_connect [127.0.0.1]:6503 3] Connected to the server: [127.0.0.1]:52812 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[3]: s_connect: connected 127.0.0.1:6502' 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[3]: Service [test] connected remote server from 127.0.0.1:42220' 247s [listener] A client connected from somewhere 247s [[127.0.0.1]:42220] New connection 247s [[127.0.0.1]:42220] Telling the main thread 247s [[127.0.0.1]:42220] Let them tell us something... 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[4]: s_connect: connected 127.0.0.1:6502' 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[4]: Service [test] connected remote server from 127.0.0.1:42232' 247s [listener] A client connected from somewhere 247s [[127.0.0.1]:42232] New connection 247s [[127.0.0.1]:42232] Telling the main thread 247s [[127.0.0.1]:42232] Let them tell us something... 247s [test_connect [127.0.0.1]:6503 9] Creating an SSL context 247s [test_connect [127.0.0.1]:6503 9] - cert required 247s [test_connect [127.0.0.1]:6503 9] - load_verify_locations() 247s [test_connect [127.0.0.1]:6503 9] Opening an SSL connection 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[5]: Service [test] accepted connection from 127.0.0.1:52820' 247s [test_connect [127.0.0.1]:6503 9] Connected to the server: [127.0.0.1]:52820 247s [listener] A client connected from somewhere 247s [[127.0.0.1]:42238] New connection 247s [[127.0.0.1]:42238] Telling the main thread 247s [[127.0.0.1]:42238] Let them tell us something... 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[5]: s_connect: connected 127.0.0.1:6502' 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[5]: Service [test] connected remote server from 127.0.0.1:42238' 247s [test_connect [127.0.0.1]:6503 6] Sending something... 247s [test_connect [127.0.0.1]:6503 6] Waiting for the main thread to figure it out 247s [[127.0.0.1]:42186] Telling the main thread about b'Hello 6\n' 247s [[127.0.0.1]:42186] Writing something back... 247s [[127.0.0.1]:42186] Telling the main thread about b'There!\n' 247s [[127.0.0.1]:42186] Closing down the writer socket 247s [test_connect [127.0.0.1]:6503 6] The listener acknowledged [127.0.0.1]:42186 247s [test_connect [127.0.0.1]:6503 6] Waiting for the server to receive it... 247s [test_connect [127.0.0.1]:6503 6] Waiting for the server to send something 247s [test_connect [127.0.0.1]:6503 6] Trying to receive the actual data 247s [test_connect [127.0.0.1]:6503 6] Waiting for the server to close the connection 247s [[127.0.0.1]:42186] Telling the main thread done 247s [test_connect [127.0.0.1]:6503 6] Waiting for an EOF on the reader socket 247s [test_connect [127.0.0.1]:6503 6] Closing our writer socket, too 247s [test_connect [127.0.0.1]:6503 6] Letting the main thread know we're done 247s [test_connect [127.0.0.1]:6503 6] Done 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[0]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 247s [process_connections] Fetching task encr-6 247s [process_connections] Waiting for task encr-6 247s [process_connections] Done with task encr-6 247s [test_connect [127.0.0.1]:6503 2] Creating an SSL context 247s [test_connect [127.0.0.1]:6503 2] - cert required 247s [test_connect [127.0.0.1]:6503 2] - load_verify_locations() 247s [test_connect [127.0.0.1]:6503 2] Opening an SSL connection 247s [test_connect [127.0.0.1]:6503 5] Creating an SSL context 247s [test_connect [127.0.0.1]:6503 5] - cert required 247s [test_connect [127.0.0.1]:6503 5] - load_verify_locations() 247s [test_connect [127.0.0.1]:6503 5] Opening an SSL connection 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[6]: Service [test] accepted connection from 127.0.0.1:52824' 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[7]: Service [test] accepted connection from 127.0.0.1:52836' 247s [test_connect [127.0.0.1]:6503 2] Connected to the server: [127.0.0.1]:52824 247s [test_connect [127.0.0.1]:6503 5] Connected to the server: [127.0.0.1]:52836 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[6]: s_connect: connected 127.0.0.1:6502' 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[6]: Service [test] connected remote server from 127.0.0.1:42250' 247s [listener] A client connected from somewhere 247s [[127.0.0.1]:42250] New connection 247s [[127.0.0.1]:42250] Telling the main thread 247s [[127.0.0.1]:42250] Let them tell us something... 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[7]: s_connect: connected 127.0.0.1:6502' 247s [stunnel_output] Read '2024.03.18 22:50:38 LOG5[7]: Service [test] connected remote server from 127.0.0.1:42266' 247s [listener] A client connected from somewhere 247s [[127.0.0.1]:42266] New connection 247s [[127.0.0.1]:42266] Telling the main thread 247s [[127.0.0.1]:42266] Let them tell us something... 248s [test_connect [127.0.0.1]:6503 1] Creating an SSL context 248s [test_connect [127.0.0.1]:6503 1] - cert required 248s [test_connect [127.0.0.1]:6503 1] - load_verify_locations() 248s [test_connect [127.0.0.1]:6503 1] Opening an SSL connection 248s [test_connect [127.0.0.1]:6503 7] Creating an SSL context 248s [test_connect [127.0.0.1]:6503 7] - cert required 248s [test_connect [127.0.0.1]:6503 7] - load_verify_locations() 248s [test_connect [127.0.0.1]:6503 7] Opening an SSL connection 248s [stunnel_output] Read '2024.03.18 22:50:39 LOG5[8]: Service [test] accepted connection from 127.0.0.1:52840' 248s [stunnel_output] Read '2024.03.18 22:50:39 LOG5[9]: Service [test] accepted connection from 127.0.0.1:52846' 248s [test_connect [127.0.0.1]:6503 1] Connected to the server: [127.0.0.1]:52840 248s [test_connect [127.0.0.1]:6503 7] Connected to the server: [127.0.0.1]:52846 248s [stunnel_output] Read '2024.03.18 22:50:39 LOG5[8]: s_connect: connected 127.0.0.1:6502' 248s [stunnel_output] Read '2024.03.18 22:50:39 LOG5[8]: Service [test] connected remote server from 127.0.0.1:42270' 248s [listener] A client connected from somewhere 248s [[127.0.0.1]:42270] New connection 248s [[127.0.0.1]:42270] Telling the main thread 248s [[127.0.0.1]:42270] Let them tell us something... 248s [stunnel_output] Read '2024.03.18 22:50:39 LOG5[9]: s_connect: connected 127.0.0.1:6502' 248s [stunnel_output] Read '2024.03.18 22:50:39 LOG5[9]: Service [test] connected remote server from 127.0.0.1:42274' 248s [listener] A client connected from somewhere 248s [[127.0.0.1]:42274] New connection 248s [[127.0.0.1]:42274] Telling the main thread 248s [[127.0.0.1]:42274] Let them tell us something... 248s [test_connect [127.0.0.1]:6503 3] Sending something... 248s [test_connect [127.0.0.1]:6503 3] Waiting for the main thread to figure it out 248s [[127.0.0.1]:42232] Telling the main thread about b'Hello 3\n' 248s [[127.0.0.1]:42232] Writing something back... 248s [[127.0.0.1]:42232] Telling the main thread about b'There!\n' 248s [[127.0.0.1]:42232] Closing down the writer socket 248s [test_connect [127.0.0.1]:6503 3] The listener acknowledged [127.0.0.1]:42232 248s [test_connect [127.0.0.1]:6503 3] Waiting for the server to receive it... 248s [test_connect [127.0.0.1]:6503 3] Waiting for the server to send something 248s [test_connect [127.0.0.1]:6503 3] Trying to receive the actual data 248s [test_connect [127.0.0.1]:6503 3] Waiting for the server to close the connection 248s [[127.0.0.1]:42232] Telling the main thread done 248s [test_connect [127.0.0.1]:6503 3] Waiting for an EOF on the reader socket 248s [test_connect [127.0.0.1]:6503 3] Closing our writer socket, too 248s [test_connect [127.0.0.1]:6503 3] Letting the main thread know we're done 248s [test_connect [127.0.0.1]:6503 3] Done 248s [stunnel_output] Read '2024.03.18 22:50:39 LOG5[4]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 248s [process_connections] Fetching task encr-3 248s [process_connections] Waiting for task encr-3 248s [process_connections] Done with task encr-3 248s [test_connect [127.0.0.1]:6503 4] Sending something... 248s [test_connect [127.0.0.1]:6503 4] Waiting for the main thread to figure it out 248s [[127.0.0.1]:42206] Telling the main thread about b'Hello 4\n' 248s [[127.0.0.1]:42206] Writing something back... 248s [[127.0.0.1]:42206] Telling the main thread about b'There!\n' 248s [[127.0.0.1]:42206] Closing down the writer socket 248s [test_connect [127.0.0.1]:6503 4] The listener acknowledged [127.0.0.1]:42206 248s [test_connect [127.0.0.1]:6503 4] Waiting for the server to receive it... 248s [test_connect [127.0.0.1]:6503 4] Waiting for the server to send something 248s [test_connect [127.0.0.1]:6503 4] Trying to receive the actual data 248s [test_connect [127.0.0.1]:6503 4] Waiting for the server to close the connection 248s [[127.0.0.1]:42206] Telling the main thread done 248s [test_connect [127.0.0.1]:6503 4] Waiting for an EOF on the reader socket 248s [test_connect [127.0.0.1]:6503 4] Closing our writer socket, too 248s [test_connect [127.0.0.1]:6503 4] Letting the main thread know we're done 248s [test_connect [127.0.0.1]:6503 4] Done 248s [stunnel_output] Read '2024.03.18 22:50:39 LOG5[2]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 248s [process_connections] Fetching task encr-4 248s [process_connections] Waiting for task encr-4 248s [process_connections] Done with task encr-4 248s [test_connect [127.0.0.1]:6503 8] Sending something... 248s [test_connect [127.0.0.1]:6503 8] Waiting for the main thread to figure it out 248s [[127.0.0.1]:42200] Telling the main thread about b'Hello 8\n' 248s [[127.0.0.1]:42200] Writing something back... 248s [[127.0.0.1]:42200] Telling the main thread about b'There!\n' 248s [[127.0.0.1]:42200] Closing down the writer socket 248s [test_connect [127.0.0.1]:6503 8] The listener acknowledged [127.0.0.1]:42200 248s [test_connect [127.0.0.1]:6503 8] Waiting for the server to receive it... 248s [test_connect [127.0.0.1]:6503 8] Waiting for the server to send something 248s [test_connect [127.0.0.1]:6503 8] Trying to receive the actual data 248s [test_connect [127.0.0.1]:6503 8] Waiting for the server to close the connection 248s [[127.0.0.1]:42200] Telling the main thread done 248s [test_connect [127.0.0.1]:6503 8] Waiting for an EOF on the reader socket 248s [test_connect [127.0.0.1]:6503 8] Closing our writer socket, too 248s [test_connect [127.0.0.1]:6503 8] Letting the main thread know we're done 248s [test_connect [127.0.0.1]:6503 8] Done 248s [stunnel_output] Read '2024.03.18 22:50:39 LOG5[1]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 248s [process_connections] Fetching task encr-8 248s [process_connections] Waiting for task encr-8 248s [process_connections] Done with task encr-8 248s [test_connect [127.0.0.1]:6503 0] Sending something... 248s [test_connect [127.0.0.1]:6503 0] Waiting for the main thread to figure it out 248s [[127.0.0.1]:42220] Telling the main thread about b'Hello 0\n' 248s [[127.0.0.1]:42220] Writing something back... 248s [[127.0.0.1]:42220] Telling the main thread about b'There!\n' 248s [[127.0.0.1]:42220] Closing down the writer socket 248s [test_connect [127.0.0.1]:6503 1] Sending something... 248s [test_connect [127.0.0.1]:6503 1] Waiting for the main thread to figure it out 248s [test_connect [127.0.0.1]:6503 0] The listener acknowledged [127.0.0.1]:42220 248s [test_connect [127.0.0.1]:6503 0] Waiting for the server to receive it... 248s [test_connect [127.0.0.1]:6503 0] Waiting for the server to send something 248s [test_connect [127.0.0.1]:6503 0] Trying to receive the actual data 248s [test_connect [127.0.0.1]:6503 0] Waiting for the server to close the connection 248s [[127.0.0.1]:42220] Telling the main thread done 248s [[127.0.0.1]:42270] Telling the main thread about b'Hello 1\n' 248s [[127.0.0.1]:42270] Writing something back... 248s [[127.0.0.1]:42270] Telling the main thread about b'There!\n' 248s [[127.0.0.1]:42270] Closing down the writer socket 248s [test_connect [127.0.0.1]:6503 2] Sending something... 248s [test_connect [127.0.0.1]:6503 2] Waiting for the main thread to figure it out 248s [test_connect [127.0.0.1]:6503 0] Waiting for an EOF on the reader socket 248s [test_connect [127.0.0.1]:6503 0] Closing our writer socket, too 248s [test_connect [127.0.0.1]:6503 1] The listener acknowledged [127.0.0.1]:42270 248s [test_connect [127.0.0.1]:6503 1] Waiting for the server to receive it... 248s [test_connect [127.0.0.1]:6503 1] Waiting for the server to send something 248s [test_connect [127.0.0.1]:6503 1] Trying to receive the actual data 248s [test_connect [127.0.0.1]:6503 1] Waiting for the server to close the connection 248s [[127.0.0.1]:42270] Telling the main thread done 248s [[127.0.0.1]:42250] Telling the main thread about b'Hello 2\n' 248s [[127.0.0.1]:42250] Writing something back... 248s [[127.0.0.1]:42250] Telling the main thread about b'There!\n' 248s [[127.0.0.1]:42250] Closing down the writer socket 248s [test_connect [127.0.0.1]:6503 1] Waiting for an EOF on the reader socket 248s [test_connect [127.0.0.1]:6503 1] Closing our writer socket, too 248s [test_connect [127.0.0.1]:6503 2] The listener acknowledged [127.0.0.1]:42250 248s [test_connect [127.0.0.1]:6503 2] Waiting for the server to receive it... 248s [test_connect [127.0.0.1]:6503 2] Waiting for the server to send something 248s [test_connect [127.0.0.1]:6503 2] Trying to receive the actual data 248s [test_connect [127.0.0.1]:6503 2] Waiting for the server to close the connection 248s [test_connect [127.0.0.1]:6503 0] Letting the main thread know we're done 248s [test_connect [127.0.0.1]:6503 0] Done 248s [[127.0.0.1]:42250] Telling the main thread done 248s [stunnel_output] Read '2024.03.18 22:50:39 LOG5[3]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 248s [process_connections] Fetching task encr-0 248s [process_connections] Waiting for task encr-0 248s [process_connections] Done with task encr-0 248s [test_connect [127.0.0.1]:6503 2] Waiting for an EOF on the reader socket 248s [test_connect [127.0.0.1]:6503 2] Closing our writer socket, too 248s [test_connect [127.0.0.1]:6503 1] Letting the main thread know we're done 248s [test_connect [127.0.0.1]:6503 1] Done 248s [stunnel_output] Read '2024.03.18 22:50:39 LOG5[8]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 248s [stunnel_output] Read '2024.03.18 22:50:39 LOG5[6]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 248s [process_connections] Fetching task encr-1 248s [process_connections] Waiting for task encr-1 248s [process_connections] Done with task encr-1 248s [test_connect [127.0.0.1]:6503 2] Letting the main thread know we're done 248s [test_connect [127.0.0.1]:6503 2] Done 248s [process_connections] Fetching task encr-2 248s [process_connections] Waiting for task encr-2 248s [process_connections] Done with task encr-2 248s [test_connect [127.0.0.1]:6503 9] Sending something... 248s [test_connect [127.0.0.1]:6503 9] Waiting for the main thread to figure it out 248s [[127.0.0.1]:42238] Telling the main thread about b'Hello 9\n' 248s [[127.0.0.1]:42238] Writing something back... 248s [[127.0.0.1]:42238] Telling the main thread about b'There!\n' 248s [[127.0.0.1]:42238] Closing down the writer socket 248s [test_connect [127.0.0.1]:6503 9] The listener acknowledged [127.0.0.1]:42238 248s [test_connect [127.0.0.1]:6503 9] Waiting for the server to receive it... 248s [test_connect [127.0.0.1]:6503 9] Waiting for the server to send something 248s [test_connect [127.0.0.1]:6503 9] Trying to receive the actual data 248s [test_connect [127.0.0.1]:6503 9] Waiting for the server to close the connection 248s [[127.0.0.1]:42238] Telling the main thread done 248s [test_connect [127.0.0.1]:6503 9] Waiting for an EOF on the reader socket 248s [test_connect [127.0.0.1]:6503 9] Closing our writer socket, too 248s [test_connect [127.0.0.1]:6503 9] Letting the main thread know we're done 248s [test_connect [127.0.0.1]:6503 9] Done 248s [stunnel_output] Read '2024.03.18 22:50:39 LOG5[5]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 248s [process_connections] Fetching task encr-9 248s [process_connections] Waiting for task encr-9 248s [process_connections] Done with task encr-9 248s [test_connect [127.0.0.1]:6503 5] Sending something... 248s [test_connect [127.0.0.1]:6503 5] Waiting for the main thread to figure it out 248s [[127.0.0.1]:42266] Telling the main thread about b'Hello 5\n' 248s [[127.0.0.1]:42266] Writing something back... 248s [[127.0.0.1]:42266] Telling the main thread about b'There!\n' 248s [[127.0.0.1]:42266] Closing down the writer socket 248s [test_connect [127.0.0.1]:6503 5] The listener acknowledged [127.0.0.1]:42266 248s [test_connect [127.0.0.1]:6503 5] Waiting for the server to receive it... 248s [test_connect [127.0.0.1]:6503 5] Waiting for the server to send something 248s [test_connect [127.0.0.1]:6503 5] Trying to receive the actual data 248s [test_connect [127.0.0.1]:6503 5] Waiting for the server to close the connection 248s [[127.0.0.1]:42266] Telling the main thread done 248s [test_connect [127.0.0.1]:6503 5] Waiting for an EOF on the reader socket 248s [test_connect [127.0.0.1]:6503 5] Closing our writer socket, too 248s [test_connect [127.0.0.1]:6503 5] Letting the main thread know we're done 248s [test_connect [127.0.0.1]:6503 5] Done 248s [stunnel_output] Read '2024.03.18 22:50:39 LOG5[7]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 248s [process_connections] Fetching task encr-5 248s [process_connections] Waiting for task encr-5 248s [process_connections] Done with task encr-5 248s [test_connect [127.0.0.1]:6503 7] Sending something... 248s [test_connect [127.0.0.1]:6503 7] Waiting for the main thread to figure it out 248s [[127.0.0.1]:42274] Telling the main thread about b'Hello 7\n' 248s [[127.0.0.1]:42274] Writing something back... 248s [[127.0.0.1]:42274] Telling the main thread about b'There!\n' 248s [[127.0.0.1]:42274] Closing down the writer socket 248s [test_connect [127.0.0.1]:6503 7] The listener acknowledged [127.0.0.1]:42274 248s [test_connect [127.0.0.1]:6503 7] Waiting for the server to receive it... 248s [test_connect [127.0.0.1]:6503 7] Waiting for the server to send something 248s [test_connect [127.0.0.1]:6503 7] Trying to receive the actual data 248s [test_connect [127.0.0.1]:6503 7] Waiting for the server to close the connection 248s [[127.0.0.1]:42274] Telling the main thread done 248s [test_connect [127.0.0.1]:6503 7] Waiting for an EOF on the reader socket 248s [test_connect [127.0.0.1]:6503 7] Closing our writer socket, too 248s [test_connect [127.0.0.1]:6503 7] Letting the main thread know we're done 248s [test_connect [127.0.0.1]:6503 7] Done 248s [process_connections] Fetching task encr-7 248s [process_connections] Waiting for task encr-7 248s [process_connections] Done with task encr-7 248s [main] Everything seems to be all right! 248s About to cancel 2 remaining task(s) 248s - listen 248s - output 248s Waiting for the tasks to hopefully finish 248s About to kill and wait for 1 child process(es) 248s - pid 860 248s Waiting for the processes to exit... 248s Got processes' exit status: [-9] 249s autopkgtest [22:50:40]: test debian-python: -----------------------] 253s autopkgtest [22:50:44]: test debian-python: - - - - - - - - - - results - - - - - - - - - - 253s debian-python PASS 256s autopkgtest [22:50:47]: test upstream: preparing testbed 307s autopkgtest [22:51:38]: @@@@@@@@@@@@@@@@@@@@ test bed setup 308s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [117 kB] 309s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [6540 B] 309s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/multiverse Sources [52.0 kB] 309s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [485 kB] 310s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [3720 kB] 312s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main armhf Packages [586 kB] 312s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main armhf c-n-f Metadata [2492 B] 312s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/restricted armhf Packages [1372 B] 312s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/restricted armhf c-n-f Metadata [116 B] 312s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/universe armhf Packages [3580 kB] 313s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/universe armhf c-n-f Metadata [7776 B] 313s Get:12 http://ftpmaster.internal/ubuntu noble-proposed/multiverse armhf Packages [35.6 kB] 313s Get:13 http://ftpmaster.internal/ubuntu noble-proposed/multiverse armhf c-n-f Metadata [116 B] 323s Fetched 8593 kB in 6s (1561 kB/s) 323s Reading package lists... 336s tee: /proc/self/fd/2: Permission denied 372s Hit:1 http://ftpmaster.internal/ubuntu noble InRelease 372s Hit:2 http://ports.ubuntu.com/ubuntu-ports noble InRelease 372s Hit:3 http://ftpmaster.internal/ubuntu noble-updates InRelease 372s Hit:4 http://ports.ubuntu.com/ubuntu-ports noble-updates InRelease 373s Hit:5 http://ftpmaster.internal/ubuntu noble-security InRelease 373s Hit:6 http://ports.ubuntu.com/ubuntu-ports noble-backports InRelease 373s Hit:7 http://ftpmaster.internal/ubuntu noble-proposed InRelease 373s Hit:8 http://ports.ubuntu.com/ubuntu-ports noble-security InRelease 379s Reading package lists... 379s Reading package lists... 380s Building dependency tree... 380s Reading state information... 382s Calculating upgrade... 383s The following packages have been kept back: 383s openssl 383s 0 upgraded, 0 newly installed, 0 to remove and 1 not upgraded. 383s Reading package lists... 384s Building dependency tree... 384s Reading state information... 386s 0 upgraded, 0 newly installed, 0 to remove and 1 not upgraded. 388s autopkgtest [22:52:59]: rebooting testbed after setup commands that affected boot 420s autopkgtest [22:53:31]: testbed dpkg architecture: armhf 448s Reading package lists... 449s Building dependency tree... 449s Reading state information... 450s Correcting dependencies...Starting pkgProblemResolver with broken count: 0 451s Starting 2 pkgProblemResolver with broken count: 0 451s Done 451s Done 453s Starting pkgProblemResolver with broken count: 0 453s Starting 2 pkgProblemResolver with broken count: 0 453s Done 455s The following additional packages will be installed: 455s net-tools stunnel4 455s Suggested packages: 455s logcheck-database 455s The following NEW packages will be installed: 455s net-tools stunnel4 455s 0 upgraded, 2 newly installed, 0 to remove and 1 not upgraded. 455s 1 not fully installed or removed. 455s Need to get 397 kB of archives. 455s After this operation, 1566 kB of additional disk space will be used. 455s Get:1 http://ftpmaster.internal/ubuntu noble/universe armhf stunnel4 armhf 3:5.70-2 [205 kB] 456s Get:2 http://ftpmaster.internal/ubuntu noble/main armhf net-tools armhf 2.10-0.1ubuntu3 [192 kB] 457s Fetched 397 kB in 1s (575 kB/s) 457s Selecting previously unselected package stunnel4. 458s (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 ... 58620 files and directories currently installed.) 458s Preparing to unpack .../stunnel4_3%3a5.70-2_armhf.deb ... 458s Unpacking stunnel4 (3:5.70-2) ... 458s Selecting previously unselected package net-tools. 458s Preparing to unpack .../net-tools_2.10-0.1ubuntu3_armhf.deb ... 458s Unpacking net-tools (2.10-0.1ubuntu3) ... 458s Setting up stunnel4 (3:5.70-2) ... 458s Creating group 'stunnel4' with GID 988. 458s Creating user 'stunnel4' (stunnel service system account) with UID 988 and GID 988. 459s Created symlink /etc/systemd/system/multi-user.target.wants/stunnel.target → /usr/lib/systemd/system/stunnel.target. 460s Setting up net-tools (2.10-0.1ubuntu3) ... 460s Setting up autopkgtest-satdep (0) ... 460s Processing triggers for man-db (2.12.0-3) ... 479s (Reading database ... 58713 files and directories currently installed.) 479s Removing autopkgtest-satdep (0) ... 501s autopkgtest [22:54:52]: test upstream: debian/tests/upstream 501s autopkgtest [22:54:52]: test upstream: [----------------------- 529s keys & certificates successfully generated 529s ./maketestcert.sh finished 529s 011. Test "cert" option 530s ...................................................................... succeeded 530s 012. Test no "cert" option 530s ...................................................................... succeeded 530s 021. Test "requireCert" option 530s ...................................................................... succeeded 530s 022. Failure test "requireCert" option 530s ...................................................................... succeeded 530s 031. Test "verifyPeer" option 530s ...................................................................... succeeded 530s 032. Failure test "verifyPeer" option 530s ...................................................................... succeeded 530s 041. Test "verifyChain" option 530s ...................................................................... succeeded 530s 042. Failure test "verifyChain" option 532s ...................................................................... succeeded 532s 051. CRL file with valid certificate 532s ...................................................................... succeeded 532s 052. CRL file with revoked certificate 532s ...................................................................... succeeded 532s 061. Test "PSKsecrets" option 532s ...................................................................... succeeded 532s 062. Failure test "PSKsecrets" option 532s ...................................................................... succeeded 532s 071. Test PKCS#12 certificate 532s ...................................................................... succeeded 532s 081. Test IPv6 support 532s ...................................................................... succeeded 532s 091. Binding server 532s ...................................................................... succeeded 532s 101. Test FIPS mode 532s child process pid 912 exit status already read: will report returncode 255 532s ...................................................................... skipped 532s 111. Failure FIPS mode with unavailable cipher 532s ...................................................................... skipped 532s 112. Failure FIPS mode with unavailable ciphersuite 532s ...................................................................... skipped 532s 113. Failure FIPS mode with unavailable elliptic curve 532s ...................................................................... skipped 532s 121. Test "sni" option 532s ...................................................................... succeeded 532s 122. Failure test "sni" option 532s ...................................................................... succeeded 532s 131. Resume session with PSK authentication 532s ...................................................................... succeeded 532s 132. Cache session resumption with TLSv1.2 533s ...................................................................... succeeded 533s 133. Test enabled "sessionResume" option 533s ...................................................................... succeeded 533s 134. Test disabled "sessionResume" option 533s ...................................................................... succeeded 533s 141. Stateless session ticket resumption with TLSv1.2 535s ...................................................................... succeeded 535s 142. Stateless session ticket resumption with TLSv1.3 536s ...................................................................... succeeded 536s 151. Session resumption with secret keys 537s ...................................................................... succeeded 537s 161. Redirect connection (wrong peer certificate) 537s ...................................................................... succeeded 537s 162. Redirect connection (no peer certificate) 537s ...................................................................... succeeded 537s 163. Not redirected connection (valid peer certificate) 537s ...................................................................... succeeded 537s 164. Redirect connection (wrong chain) 538s ...................................................................... succeeded 538s 165. Redirect connection (no chain) 538s ...................................................................... succeeded 538s 166. Not redirected connection (valid chain) 538s ...................................................................... succeeded 538s 171. Redirect proxy connection (wrong peer certificate) 538s ...................................................................... succeeded 538s 172. Redirect proxy connection (no peer certificate) 538s ...................................................................... succeeded 538s 173. Not redirected proxy connection (valid peer certificate) 538s ...................................................................... succeeded 538s 181. Session resumption and redirect (wrong certificate) 538s ...................................................................... succeeded 538s 182. Session resumption and redirect (no certificate) 539s ...................................................................... succeeded 539s 183. Session resumption and no redirect (valid certificate) 539s ...................................................................... succeeded 539s 191. Reload configuration 539s ...................................................................... succeeded 539s 201. Failover round robin (rr) strategy 539s ...................................................................... succeeded 539s 202. Failover priority (prio) strategy 540s ...................................................................... succeeded 540s 211. Included configuration files 540s ...................................................................... succeeded 540s 221. Client inetd mode 540s ...................................................................... succeeded 540s 231. Test exec+connect service 540s ...................................................................... succeeded 540s 241. Resume session with delay option 541s ...................................................................... succeeded 541s 242. Resume session with disable delay option 542s ...................................................................... succeeded 542s 251. Wrong client configuration 542s ...................................................................... succeeded 542s 261. Wrong server configuration 542s ...................................................................... succeeded 542s 542s Summary: 542s succeeded: 46 542s failed: 0 542s skipped: 4 542s 542s Testing results: /tmp/autopkgtest.gFbPuo/build.Q2u/src/tests/logs/results.log 543s autopkgtest [22:55:34]: test upstream: -----------------------] 547s autopkgtest [22:55:38]: test upstream: - - - - - - - - - - results - - - - - - - - - - 547s upstream PASS 551s autopkgtest [22:55:42]: @@@@@@@@@@@@@@@@@@@@ summary 551s debian-python PASS 551s upstream PASS