0s autopkgtest [06:17:10]: starting date and time: 2024-11-14 06:17:10+0000 0s autopkgtest [06:17:10]: git checkout: 6f3be7a8 Fix armhf LXD image generation for plucky 0s autopkgtest [06:17:10]: host juju-7f2275-prod-proposed-migration-environment-9; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.6igrqd3n/out --timeout-copy=6000 --setup-commands '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,keyserver.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:python3-defaults,src:python3-stdlib-extensions --apt-upgrade stunnel4 --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 '--env=ADT_TEST_TRIGGERS=python3-defaults/3.12.7-1 python3-stdlib-extensions/3.12.7-1' -- lxd -r lxd-armhf-10.145.243.51 lxd-armhf-10.145.243.51:autopkgtest/ubuntu/plucky/armhf 53s autopkgtest [06:18:03]: testbed dpkg architecture: armhf 55s autopkgtest [06:18:05]: testbed apt version: 2.9.8 55s autopkgtest [06:18:05]: @@@@@@@@@@@@@@@@@@@@ test bed setup 63s Get:1 http://ftpmaster.internal/ubuntu plucky-proposed InRelease [73.9 kB] 63s Get:2 http://ftpmaster.internal/ubuntu plucky-proposed/universe Sources [987 kB] 64s Get:3 http://ftpmaster.internal/ubuntu plucky-proposed/restricted Sources [7016 B] 64s Get:4 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse Sources [15.4 kB] 64s Get:5 http://ftpmaster.internal/ubuntu plucky-proposed/main Sources [98.6 kB] 64s Get:6 http://ftpmaster.internal/ubuntu plucky-proposed/main armhf Packages [103 kB] 64s Get:7 http://ftpmaster.internal/ubuntu plucky-proposed/universe armhf Packages [684 kB] 64s Get:8 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse armhf Packages [5040 B] 64s Fetched 1973 kB in 1s (2001 kB/s) 64s Reading package lists... 81s tee: /proc/self/fd/2: Permission denied 104s Hit:1 http://ftpmaster.internal/ubuntu plucky-proposed InRelease 104s Hit:2 http://ftpmaster.internal/ubuntu plucky InRelease 105s Hit:3 http://ftpmaster.internal/ubuntu plucky-updates InRelease 105s Hit:4 http://ftpmaster.internal/ubuntu plucky-security InRelease 106s Reading package lists... 106s Reading package lists... 106s Building dependency tree... 106s Reading state information... 107s Calculating upgrade... 107s The following NEW packages will be installed: 107s python3.13-gdbm 107s The following packages will be upgraded: 107s libpython3-stdlib python3 python3-gdbm python3-minimal 107s 4 upgraded, 1 newly installed, 0 to remove and 0 not upgraded. 107s Need to get 99.6 kB of archives. 107s After this operation, 91.1 kB of additional disk space will be used. 107s Get:1 http://ftpmaster.internal/ubuntu plucky-proposed/main armhf python3-minimal armhf 3.12.7-1 [27.4 kB] 107s Get:2 http://ftpmaster.internal/ubuntu plucky-proposed/main armhf python3 armhf 3.12.7-1 [24.0 kB] 107s Get:3 http://ftpmaster.internal/ubuntu plucky-proposed/main armhf libpython3-stdlib armhf 3.12.7-1 [10.0 kB] 107s Get:4 http://ftpmaster.internal/ubuntu plucky/main armhf python3.13-gdbm armhf 3.13.0-2 [29.5 kB] 107s Get:5 http://ftpmaster.internal/ubuntu plucky-proposed/main armhf python3-gdbm armhf 3.12.7-1 [8642 B] 108s Fetched 99.6 kB in 0s (295 kB/s) 108s (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 ... 59560 files and directories currently installed.) 108s Preparing to unpack .../python3-minimal_3.12.7-1_armhf.deb ... 108s Unpacking python3-minimal (3.12.7-1) over (3.12.6-0ubuntu1) ... 108s Setting up python3-minimal (3.12.7-1) ... 108s (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 ... 59560 files and directories currently installed.) 108s Preparing to unpack .../python3_3.12.7-1_armhf.deb ... 108s Unpacking python3 (3.12.7-1) over (3.12.6-0ubuntu1) ... 108s Preparing to unpack .../libpython3-stdlib_3.12.7-1_armhf.deb ... 108s Unpacking libpython3-stdlib:armhf (3.12.7-1) over (3.12.6-0ubuntu1) ... 108s Selecting previously unselected package python3.13-gdbm. 108s Preparing to unpack .../python3.13-gdbm_3.13.0-2_armhf.deb ... 108s Unpacking python3.13-gdbm (3.13.0-2) ... 108s Preparing to unpack .../python3-gdbm_3.12.7-1_armhf.deb ... 108s Unpacking python3-gdbm:armhf (3.12.7-1) over (3.12.6-1ubuntu1) ... 108s Setting up python3.13-gdbm (3.13.0-2) ... 108s Setting up libpython3-stdlib:armhf (3.12.7-1) ... 108s Setting up python3 (3.12.7-1) ... 109s Setting up python3-gdbm:armhf (3.12.7-1) ... 109s Processing triggers for man-db (2.12.1-3) ... 110s Reading package lists... 110s Building dependency tree... 110s Reading state information... 110s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 112s autopkgtest [06:19:02]: rebooting testbed after setup commands that affected boot 181s autopkgtest [06:20:11]: testbed running kernel: Linux 6.8.0-48-generic #48~22.04.1-Ubuntu SMP PREEMPT_DYNAMIC Mon Oct 7 11:49:53 UTC 2 209s autopkgtest [06:20:39]: @@@@@@@@@@@@@@@@@@@@ apt-source stunnel4 220s Get:1 http://ftpmaster.internal/ubuntu plucky/universe stunnel4 3:5.73-1 (dsc) [2845 B] 220s Get:2 http://ftpmaster.internal/ubuntu plucky/universe stunnel4 3:5.73-1 (tar) [907 kB] 220s Get:3 http://ftpmaster.internal/ubuntu plucky/universe stunnel4 3:5.73-1 (asc) [833 B] 220s Get:4 http://ftpmaster.internal/ubuntu plucky/universe stunnel4 3:5.73-1 (diff) [54.6 kB] 220s gpgv: Signature made Thu Oct 24 09:16:08 2024 UTC 220s gpgv: using RSA key 2EE7A7A517FC124CF115C354651EEFB02527DF13 220s gpgv: issuer "roam@debian.org" 220s gpgv: Can't check signature: No public key 220s dpkg-source: warning: cannot verify inline signature for ./stunnel4_5.73-1.dsc: no acceptable signature found 221s autopkgtest [06:20:51]: testing package stunnel4 version 3:5.73-1 223s autopkgtest [06:20:53]: build not needed 225s autopkgtest [06:20:55]: test debian-python: preparing testbed 236s Reading package lists... 236s Building dependency tree... 236s Reading state information... 236s Starting pkgProblemResolver with broken count: 0 237s Starting 2 pkgProblemResolver with broken count: 0 237s Done 237s The following additional packages will be installed: 237s libpython3.13-minimal libpython3.13-stdlib python3-all python3.13 237s python3.13-minimal stunnel4 237s Suggested packages: 237s python3.13-venv python3.13-doc binfmt-support logcheck-database 237s The following NEW packages will be installed: 237s autopkgtest-satdep libpython3.13-minimal libpython3.13-stdlib python3-all 237s python3.13 python3.13-minimal stunnel4 237s 0 upgraded, 7 newly installed, 0 to remove and 0 not upgraded. 237s Need to get 5623 kB/5623 kB of archives. 237s After this operation, 19.5 MB of additional disk space will be used. 237s Get:1 /tmp/autopkgtest.QyYqGA/1-autopkgtest-satdep.deb autopkgtest-satdep armhf 0 [716 B] 237s Get:2 http://ftpmaster.internal/ubuntu plucky/main armhf libpython3.13-minimal armhf 3.13.0-2 [866 kB] 238s Get:3 http://ftpmaster.internal/ubuntu plucky/main armhf python3.13-minimal armhf 3.13.0-2 [1854 kB] 238s Get:4 http://ftpmaster.internal/ubuntu plucky/universe armhf stunnel4 armhf 3:5.73-1 [211 kB] 238s Get:5 http://ftpmaster.internal/ubuntu plucky/main armhf libpython3.13-stdlib armhf 3.13.0-2 [1972 kB] 238s Get:6 http://ftpmaster.internal/ubuntu plucky/main armhf python3.13 armhf 3.13.0-2 [719 kB] 238s Get:7 http://ftpmaster.internal/ubuntu plucky-proposed/main armhf python3-all armhf 3.12.7-1 [890 B] 238s Fetched 5623 kB in 1s (7189 kB/s) 238s Selecting previously unselected package libpython3.13-minimal:armhf. 238s (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 ... 59567 files and directories currently installed.) 238s Preparing to unpack .../0-libpython3.13-minimal_3.13.0-2_armhf.deb ... 238s Unpacking libpython3.13-minimal:armhf (3.13.0-2) ... 238s Selecting previously unselected package python3.13-minimal. 238s Preparing to unpack .../1-python3.13-minimal_3.13.0-2_armhf.deb ... 239s Unpacking python3.13-minimal (3.13.0-2) ... 239s Selecting previously unselected package stunnel4. 239s Preparing to unpack .../2-stunnel4_3%3a5.73-1_armhf.deb ... 239s Unpacking stunnel4 (3:5.73-1) ... 239s Selecting previously unselected package libpython3.13-stdlib:armhf. 239s Preparing to unpack .../3-libpython3.13-stdlib_3.13.0-2_armhf.deb ... 239s Unpacking libpython3.13-stdlib:armhf (3.13.0-2) ... 239s Selecting previously unselected package python3.13. 239s Preparing to unpack .../4-python3.13_3.13.0-2_armhf.deb ... 239s Unpacking python3.13 (3.13.0-2) ... 239s Selecting previously unselected package python3-all. 239s Preparing to unpack .../5-python3-all_3.12.7-1_armhf.deb ... 239s Unpacking python3-all (3.12.7-1) ... 239s Selecting previously unselected package autopkgtest-satdep. 239s Preparing to unpack .../6-1-autopkgtest-satdep.deb ... 239s Unpacking autopkgtest-satdep (0) ... 239s Setting up stunnel4 (3:5.73-1) ... 239s Creating group 'stunnel4' with GID 988. 239s Creating user 'stunnel4' (stunnel service system account) with UID 988 and GID 988. 239s Created symlink '/etc/systemd/system/multi-user.target.wants/stunnel.target' → '/usr/lib/systemd/system/stunnel.target'. 239s Setting up libpython3.13-minimal:armhf (3.13.0-2) ... 239s Setting up python3.13-minimal (3.13.0-2) ... 240s Setting up libpython3.13-stdlib:armhf (3.13.0-2) ... 240s Setting up python3.13 (3.13.0-2) ... 242s Setting up python3-all (3.12.7-1) ... 242s Setting up autopkgtest-satdep (0) ... 242s Processing triggers for man-db (2.12.1-3) ... 242s Processing triggers for systemd (256.5-2ubuntu4) ... 254s (Reading database ... 60346 files and directories currently installed.) 254s Removing autopkgtest-satdep (0) ... 260s autopkgtest [06:21:30]: 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 260s autopkgtest [06:21:30]: test debian-python: [----------------------- 262s 262s 262s ====== python3.12 262s 262s Using /tmp/struntime.nxd4tfd_ as a temporary directory 262s Trying to obtain the version of /usr/bin/stunnel4 262s Started `/usr/bin/stunnel4 -version` as process 1147 262s Got stunnel version 5.73 262s [main] Starting to do things 262s [main] Awaiting the 'listener started' event 262s [find_listening_port] Looking for a port to listen on 262s [find_listening_port] Trying localhost port 6502 262s [listener] Telling the main thread about [127.0.0.1]:6502 262s [listener] Awaiting client connections... 262s [main] Apparently we are listening on [127.0.0.1]:6502 262s [main] Testing cleartext connections 262s [test_connect [127.0.0.1]:6502 0] Trying port 6502 encrypted False 262s [test_connect [127.0.0.1]:6502 1] Trying port 6502 encrypted False 262s [test_connect [127.0.0.1]:6502 2] Trying port 6502 encrypted False 262s [test_connect [127.0.0.1]:6502 3] Trying port 6502 encrypted False 262s [test_connect [127.0.0.1]:6502 4] Trying port 6502 encrypted False 262s [test_connect [127.0.0.1]:6502 5] Trying port 6502 encrypted False 262s [test_connect [127.0.0.1]:6502 6] Trying port 6502 encrypted False 262s [test_connect [127.0.0.1]:6502 7] Trying port 6502 encrypted False 262s [test_connect [127.0.0.1]:6502 8] Trying port 6502 encrypted False 262s [test_connect [127.0.0.1]:6502 9] Trying port 6502 encrypted False 262s [test_connect [127.0.0.1]:6502 4] Opening an unencrypted connection 262s [test_connect [127.0.0.1]:6502 9] Opening an unencrypted connection 262s [listener] A client connected from somewhere 262s [[127.0.0.1]:41068] New connection 262s [[127.0.0.1]:41068] Telling the main thread 262s [[127.0.0.1]:41068] Let them tell us something... 262s [listener] A client connected from somewhere 262s [[127.0.0.1]:41084] New connection 262s [[127.0.0.1]:41084] Telling the main thread 262s [[127.0.0.1]:41084] Let them tell us something... 262s [test_connect [127.0.0.1]:6502 4] Connected to the server: [127.0.0.1]:41068 262s [test_connect [127.0.0.1]:6502 9] Connected to the server: [127.0.0.1]:41084 263s [test_connect [127.0.0.1]:6502 3] Opening an unencrypted connection 263s [test_connect [127.0.0.1]:6502 7] Opening an unencrypted connection 263s [listener] A client connected from somewhere 263s [[127.0.0.1]:41100] New connection 263s [[127.0.0.1]:41100] Telling the main thread 263s [[127.0.0.1]:41100] Let them tell us something... 263s [listener] A client connected from somewhere 263s [[127.0.0.1]:41114] New connection 263s [[127.0.0.1]:41114] Telling the main thread 263s [[127.0.0.1]:41114] Let them tell us something... 263s [test_connect [127.0.0.1]:6502 3] Connected to the server: [127.0.0.1]:41100 263s [test_connect [127.0.0.1]:6502 7] Connected to the server: [127.0.0.1]:41114 263s [test_connect [127.0.0.1]:6502 8] Opening an unencrypted connection 263s [listener] A client connected from somewhere 263s [[127.0.0.1]:41116] New connection 263s [[127.0.0.1]:41116] Telling the main thread 263s [[127.0.0.1]:41116] Let them tell us something... 263s [test_connect [127.0.0.1]:6502 8] Connected to the server: [127.0.0.1]:41116 263s [test_connect [127.0.0.1]:6502 5] Opening an unencrypted connection 263s [test_connect [127.0.0.1]:6502 6] Opening an unencrypted connection 263s [listener] A client connected from somewhere 263s [[127.0.0.1]:41130] New connection 263s [[127.0.0.1]:41130] Telling the main thread 263s [[127.0.0.1]:41130] Let them tell us something... 263s [listener] A client connected from somewhere 263s [[127.0.0.1]:41142] New connection 263s [[127.0.0.1]:41142] Telling the main thread 263s [[127.0.0.1]:41142] Let them tell us something... 263s [test_connect [127.0.0.1]:6502 5] Connected to the server: [127.0.0.1]:41130 263s [test_connect [127.0.0.1]:6502 6] Connected to the server: [127.0.0.1]:41142 263s [test_connect [127.0.0.1]:6502 9] Sending something... 263s [test_connect [127.0.0.1]:6502 9] Waiting for the main thread to figure it out 263s [[127.0.0.1]:41084] Telling the main thread about b'Hello 9\n' 263s [[127.0.0.1]:41084] Writing something back... 263s [[127.0.0.1]:41084] Telling the main thread about b'There!\n' 263s [[127.0.0.1]:41084] Closing down the writer socket 263s [test_connect [127.0.0.1]:6502 9] The listener acknowledged [127.0.0.1]:41084 263s [test_connect [127.0.0.1]:6502 9] Waiting for the server to receive it... 263s [test_connect [127.0.0.1]:6502 9] Waiting for the server to send something 263s [test_connect [127.0.0.1]:6502 9] Trying to receive the actual data 263s [test_connect [127.0.0.1]:6502 9] Waiting for the server to close the connection 263s [[127.0.0.1]:41084] Telling the main thread done 263s [test_connect [127.0.0.1]:6502 9] Waiting for an EOF on the reader socket 263s [test_connect [127.0.0.1]:6502 9] Closing our writer socket, too 263s [test_connect [127.0.0.1]:6502 9] Letting the main thread know we're done 263s [test_connect [127.0.0.1]:6502 9] Done 263s [process_connections] Fetching task plain-9 263s [process_connections] Waiting for task plain-9 263s [process_connections] Done with task plain-9 263s [test_connect [127.0.0.1]:6502 1] Opening an unencrypted connection 263s [listener] A client connected from somewhere 263s [[127.0.0.1]:41146] New connection 263s [[127.0.0.1]:41146] Telling the main thread 263s [[127.0.0.1]:41146] Let them tell us something... 263s [test_connect [127.0.0.1]:6502 1] Connected to the server: [127.0.0.1]:41146 263s [test_connect [127.0.0.1]:6502 4] Sending something... 263s [test_connect [127.0.0.1]:6502 4] Waiting for the main thread to figure it out 263s [[127.0.0.1]:41068] Telling the main thread about b'Hello 4\n' 263s [[127.0.0.1]:41068] Writing something back... 263s [[127.0.0.1]:41068] Telling the main thread about b'There!\n' 263s [[127.0.0.1]:41068] Closing down the writer socket 263s [test_connect [127.0.0.1]:6502 4] The listener acknowledged [127.0.0.1]:41068 263s [test_connect [127.0.0.1]:6502 4] Waiting for the server to receive it... 263s [test_connect [127.0.0.1]:6502 4] Waiting for the server to send something 263s [test_connect [127.0.0.1]:6502 4] Trying to receive the actual data 263s [test_connect [127.0.0.1]:6502 4] Waiting for the server to close the connection 263s [[127.0.0.1]:41068] Telling the main thread done 263s [test_connect [127.0.0.1]:6502 4] Waiting for an EOF on the reader socket 263s [test_connect [127.0.0.1]:6502 4] Closing our writer socket, too 263s [test_connect [127.0.0.1]:6502 4] Letting the main thread know we're done 263s [test_connect [127.0.0.1]:6502 4] Done 263s [process_connections] Fetching task plain-4 263s [process_connections] Waiting for task plain-4 263s [process_connections] Done with task plain-4 263s [test_connect [127.0.0.1]:6502 0] Opening an unencrypted connection 263s [test_connect [127.0.0.1]:6502 2] Opening an unencrypted connection 263s [test_connect [127.0.0.1]:6502 8] Sending something... 263s [test_connect [127.0.0.1]:6502 8] Waiting for the main thread to figure it out 263s [listener] A client connected from somewhere 263s [[127.0.0.1]:41148] New connection 263s [[127.0.0.1]:41148] Telling the main thread 263s [[127.0.0.1]:41148] Let them tell us something... 263s [listener] A client connected from somewhere 263s [[127.0.0.1]:41154] New connection 263s [[127.0.0.1]:41154] Telling the main thread 263s [[127.0.0.1]:41154] Let them tell us something... 263s [test_connect [127.0.0.1]:6502 0] Connected to the server: [127.0.0.1]:41148 263s [test_connect [127.0.0.1]:6502 2] Connected to the server: [127.0.0.1]:41154 263s [[127.0.0.1]:41116] Telling the main thread about b'Hello 8\n' 263s [[127.0.0.1]:41116] Writing something back... 263s [[127.0.0.1]:41116] Telling the main thread about b'There!\n' 263s [[127.0.0.1]:41116] Closing down the writer socket 263s [test_connect [127.0.0.1]:6502 8] The listener acknowledged [127.0.0.1]:41116 263s [test_connect [127.0.0.1]:6502 8] Waiting for the server to receive it... 263s [test_connect [127.0.0.1]:6502 8] Waiting for the server to send something 263s [test_connect [127.0.0.1]:6502 8] Trying to receive the actual data 263s [test_connect [127.0.0.1]:6502 8] Waiting for the server to close the connection 263s [[127.0.0.1]:41116] Telling the main thread done 263s [test_connect [127.0.0.1]:6502 8] Waiting for an EOF on the reader socket 263s [test_connect [127.0.0.1]:6502 8] Closing our writer socket, too 263s [test_connect [127.0.0.1]:6502 8] Letting the main thread know we're done 263s [test_connect [127.0.0.1]:6502 8] Done 263s [process_connections] Fetching task plain-8 263s [process_connections] Waiting for task plain-8 263s [process_connections] Done with task plain-8 263s [test_connect [127.0.0.1]:6502 6] Sending something... 263s [test_connect [127.0.0.1]:6502 6] Waiting for the main thread to figure it out 263s [[127.0.0.1]:41142] Telling the main thread about b'Hello 6\n' 263s [[127.0.0.1]:41142] Writing something back... 263s [[127.0.0.1]:41142] Telling the main thread about b'There!\n' 263s [[127.0.0.1]:41142] Closing down the writer socket 263s [test_connect [127.0.0.1]:6502 6] The listener acknowledged [127.0.0.1]:41142 263s [test_connect [127.0.0.1]:6502 6] Waiting for the server to receive it... 263s [test_connect [127.0.0.1]:6502 6] Waiting for the server to send something 263s [test_connect [127.0.0.1]:6502 6] Trying to receive the actual data 263s [test_connect [127.0.0.1]:6502 6] Waiting for the server to close the connection 263s [[127.0.0.1]:41142] Telling the main thread done 263s [test_connect [127.0.0.1]:6502 6] Waiting for an EOF on the reader socket 263s [test_connect [127.0.0.1]:6502 6] Closing our writer socket, too 263s [test_connect [127.0.0.1]:6502 6] Letting the main thread know we're done 263s [test_connect [127.0.0.1]:6502 6] Done 263s [process_connections] Fetching task plain-6 263s [process_connections] Waiting for task plain-6 263s [process_connections] Done with task plain-6 263s [test_connect [127.0.0.1]:6502 7] Sending something... 263s [test_connect [127.0.0.1]:6502 7] Waiting for the main thread to figure it out 263s [[127.0.0.1]:41114] Telling the main thread about b'Hello 7\n' 263s [[127.0.0.1]:41114] Writing something back... 263s [[127.0.0.1]:41114] Telling the main thread about b'There!\n' 263s [[127.0.0.1]:41114] Closing down the writer socket 263s [test_connect [127.0.0.1]:6502 7] The listener acknowledged [127.0.0.1]:41114 263s [test_connect [127.0.0.1]:6502 7] Waiting for the server to receive it... 263s [test_connect [127.0.0.1]:6502 7] Waiting for the server to send something 263s [test_connect [127.0.0.1]:6502 7] Trying to receive the actual data 263s [test_connect [127.0.0.1]:6502 7] Waiting for the server to close the connection 263s [[127.0.0.1]:41114] Telling the main thread done 263s [test_connect [127.0.0.1]:6502 7] Waiting for an EOF on the reader socket 263s [test_connect [127.0.0.1]:6502 7] Closing our writer socket, too 263s [test_connect [127.0.0.1]:6502 7] Letting the main thread know we're done 263s [test_connect [127.0.0.1]:6502 7] Done 263s [process_connections] Fetching task plain-7 263s [process_connections] Waiting for task plain-7 263s [process_connections] Done with task plain-7 263s [test_connect [127.0.0.1]:6502 5] Sending something... 263s [test_connect [127.0.0.1]:6502 5] Waiting for the main thread to figure it out 263s [[127.0.0.1]:41130] Telling the main thread about b'Hello 5\n' 263s [[127.0.0.1]:41130] Writing something back... 263s [[127.0.0.1]:41130] Telling the main thread about b'There!\n' 263s [[127.0.0.1]:41130] Closing down the writer socket 263s [test_connect [127.0.0.1]:6502 5] The listener acknowledged [127.0.0.1]:41130 263s [test_connect [127.0.0.1]:6502 5] Waiting for the server to receive it... 263s [test_connect [127.0.0.1]:6502 5] Waiting for the server to send something 263s [test_connect [127.0.0.1]:6502 5] Trying to receive the actual data 263s [test_connect [127.0.0.1]:6502 5] Waiting for the server to close the connection 263s [[127.0.0.1]:41130] Telling the main thread done 263s [test_connect [127.0.0.1]:6502 5] Waiting for an EOF on the reader socket 263s [test_connect [127.0.0.1]:6502 5] Closing our writer socket, too 263s [test_connect [127.0.0.1]:6502 5] Letting the main thread know we're done 263s [test_connect [127.0.0.1]:6502 5] Done 263s [process_connections] Fetching task plain-5 263s [process_connections] Waiting for task plain-5 263s [process_connections] Done with task plain-5 263s [test_connect [127.0.0.1]:6502 2] Sending something... 263s [test_connect [127.0.0.1]:6502 2] Waiting for the main thread to figure it out 263s [[127.0.0.1]:41154] Telling the main thread about b'Hello 2\n' 263s [[127.0.0.1]:41154] Writing something back... 263s [[127.0.0.1]:41154] Telling the main thread about b'There!\n' 263s [[127.0.0.1]:41154] Closing down the writer socket 263s [test_connect [127.0.0.1]:6502 2] The listener acknowledged [127.0.0.1]:41154 263s [test_connect [127.0.0.1]:6502 2] Waiting for the server to receive it... 263s [test_connect [127.0.0.1]:6502 2] Waiting for the server to send something 263s [test_connect [127.0.0.1]:6502 2] Trying to receive the actual data 263s [test_connect [127.0.0.1]:6502 2] Waiting for the server to close the connection 263s [[127.0.0.1]:41154] Telling the main thread done 263s [test_connect [127.0.0.1]:6502 2] Waiting for an EOF on the reader socket 263s [test_connect [127.0.0.1]:6502 2] Closing our writer socket, too 263s [test_connect [127.0.0.1]:6502 2] Letting the main thread know we're done 263s [test_connect [127.0.0.1]:6502 2] Done 263s [process_connections] Fetching task plain-2 263s [process_connections] Waiting for task plain-2 263s [process_connections] Done with task plain-2 264s [test_connect [127.0.0.1]:6502 3] Sending something... 264s [test_connect [127.0.0.1]:6502 3] Waiting for the main thread to figure it out 264s [test_connect [127.0.0.1]:6502 0] Sending something... 264s [test_connect [127.0.0.1]:6502 0] Waiting for the main thread to figure it out 264s [[127.0.0.1]:41100] Telling the main thread about b'Hello 3\n' 264s [[127.0.0.1]:41100] Writing something back... 264s [[127.0.0.1]:41100] Telling the main thread about b'There!\n' 264s [[127.0.0.1]:41100] Closing down the writer socket 264s [[127.0.0.1]:41148] Telling the main thread about b'Hello 0\n' 264s [[127.0.0.1]:41148] Writing something back... 264s [[127.0.0.1]:41148] Telling the main thread about b'There!\n' 264s [[127.0.0.1]:41148] Closing down the writer socket 264s [test_connect [127.0.0.1]:6502 3] The listener acknowledged [127.0.0.1]:41100 264s [test_connect [127.0.0.1]:6502 3] Waiting for the server to receive it... 264s [test_connect [127.0.0.1]:6502 3] Waiting for the server to send something 264s [test_connect [127.0.0.1]:6502 3] Trying to receive the actual data 264s [test_connect [127.0.0.1]:6502 3] Waiting for the server to close the connection 264s [test_connect [127.0.0.1]:6502 0] The listener acknowledged [127.0.0.1]:41148 264s [test_connect [127.0.0.1]:6502 0] Waiting for the server to receive it... 264s [test_connect [127.0.0.1]:6502 0] Waiting for the server to send something 264s [test_connect [127.0.0.1]:6502 0] Trying to receive the actual data 264s [test_connect [127.0.0.1]:6502 0] Waiting for the server to close the connection 264s [[127.0.0.1]:41100] Telling the main thread done 264s [[127.0.0.1]:41148] Telling the main thread done 264s [test_connect [127.0.0.1]:6502 3] Waiting for an EOF on the reader socket 264s [test_connect [127.0.0.1]:6502 3] Closing our writer socket, too 264s [test_connect [127.0.0.1]:6502 0] Waiting for an EOF on the reader socket 264s [test_connect [127.0.0.1]:6502 0] Closing our writer socket, too 264s [test_connect [127.0.0.1]:6502 3] Letting the main thread know we're done 264s [test_connect [127.0.0.1]:6502 3] Done 264s [test_connect [127.0.0.1]:6502 0] Letting the main thread know we're done 264s [test_connect [127.0.0.1]:6502 0] Done 264s [process_connections] Fetching task plain-3 264s [process_connections] Waiting for task plain-3 264s [process_connections] Done with task plain-3 264s [process_connections] Fetching task plain-0 264s [process_connections] Waiting for task plain-0 264s [process_connections] Done with task plain-0 264s [test_connect [127.0.0.1]:6502 1] Sending something... 264s [test_connect [127.0.0.1]:6502 1] Waiting for the main thread to figure it out 264s [[127.0.0.1]:41146] Telling the main thread about b'Hello 1\n' 264s [[127.0.0.1]:41146] Writing something back... 264s [[127.0.0.1]:41146] Telling the main thread about b'There!\n' 264s [[127.0.0.1]:41146] Closing down the writer socket 264s [test_connect [127.0.0.1]:6502 1] The listener acknowledged [127.0.0.1]:41146 264s [test_connect [127.0.0.1]:6502 1] Waiting for the server to receive it... 264s [test_connect [127.0.0.1]:6502 1] Waiting for the server to send something 264s [test_connect [127.0.0.1]:6502 1] Trying to receive the actual data 264s [test_connect [127.0.0.1]:6502 1] Waiting for the server to close the connection 264s [[127.0.0.1]:41146] Telling the main thread done 264s [test_connect [127.0.0.1]:6502 1] Waiting for an EOF on the reader socket 264s [test_connect [127.0.0.1]:6502 1] Closing our writer socket, too 264s [test_connect [127.0.0.1]:6502 1] Letting the main thread know we're done 264s [test_connect [127.0.0.1]:6502 1] Done 264s [process_connections] Fetching task plain-1 264s [process_connections] Waiting for task plain-1 264s [process_connections] Done with task plain-1 264s [main] Picking a listen address:port for stunnel 264s [find_listening_port] Looking for a port to listen on 264s [find_listening_port] Trying 127.0.0.1 port 6503 264s [find_listening_port] got 6503, shutting down the listener 264s [main] Will put stunnel at 127.0.0.1:6503 264s [main] Preparing the stunnel config file 264s [main] Using config file /tmp/struntime.nxd4tfd_/stunnel.conf 264s [main] 264s [main] pid = /tmp/struntime.nxd4tfd_/stunnel.pid 264s [main] foreground = yes 264s [main] 264s [main] cert = /tmp/autopkgtest.QyYqGA/build.Xop/src/debian/tests/certs/certificate.pem 264s [main] key = /tmp/struntime.nxd4tfd_/key.pem 264s [main] 264s [main] [test] 264s [main] accept = 127.0.0.1:6503 264s [main] connect = 127.0.0.1:6502 264s [main] End of the config file 264s [main] Launching the stunnel server 264s [main] - got pid 1151 264s [main] Launching the stunnel output pipe thread 264s [main] Waiting for stunnel to start up 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[ui]: stunnel 5.73 on arm-unknown-linux-gnueabihf platform' 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[ui]: Compiled/running with OpenSSL 3.3.1 4 Jun 2024' 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[ui]: Threading:PTHREAD Sockets:POLL,IPv6,SYSTEMD TLS:ENGINE,OCSP,PSK,SNI Auth:LIBWRAP' 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[ui]: Reading configuration from file /tmp/struntime.nxd4tfd_/stunnel.conf' 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[ui]: UTF-8 byte order mark not detected' 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[ui]: FIPS mode disabled' 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[ui]: Configuration successful' 264s [stunnel_output] The main thread ought to know 264s [main] Testing the encrypted connections 264s [test_connect [127.0.0.1]:6503 0] Trying port 6503 encrypted True 264s [test_connect [127.0.0.1]:6503 1] Trying port 6503 encrypted True 264s [test_connect [127.0.0.1]:6503 2] Trying port 6503 encrypted True 264s [test_connect [127.0.0.1]:6503 3] Trying port 6503 encrypted True 264s [test_connect [127.0.0.1]:6503 4] Trying port 6503 encrypted True 264s [test_connect [127.0.0.1]:6503 5] Trying port 6503 encrypted True 264s [test_connect [127.0.0.1]:6503 6] Trying port 6503 encrypted True 264s [test_connect [127.0.0.1]:6503 7] Trying port 6503 encrypted True 264s [test_connect [127.0.0.1]:6503 8] Trying port 6503 encrypted True 264s [test_connect [127.0.0.1]:6503 9] Trying port 6503 encrypted True 264s [test_connect [127.0.0.1]:6503 4] Creating an SSL context 264s [test_connect [127.0.0.1]:6503 4] - cert required 264s [test_connect [127.0.0.1]:6503 4] - load_verify_locations() 264s [test_connect [127.0.0.1]:6503 4] Opening an SSL connection 264s [test_connect [127.0.0.1]:6503 6] Creating an SSL context 264s [test_connect [127.0.0.1]:6503 6] - cert required 264s [test_connect [127.0.0.1]:6503 6] - load_verify_locations() 264s [test_connect [127.0.0.1]:6503 6] Opening an SSL connection 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[0]: Service [test] accepted connection from 127.0.0.1:51002' 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[1]: Service [test] accepted connection from 127.0.0.1:51014' 264s [test_connect [127.0.0.1]:6503 6] Connected to the server: [127.0.0.1]:51014 264s [test_connect [127.0.0.1]:6503 4] Connected to the server: [127.0.0.1]:51002 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[1]: s_connect: connected 127.0.0.1:6502' 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[1]: Service [test] connected remote server from 127.0.0.1:41164' 264s [listener] A client connected from somewhere 264s [[127.0.0.1]:41164] New connection 264s [[127.0.0.1]:41164] Telling the main thread 264s [[127.0.0.1]:41164] Let them tell us something... 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[0]: s_connect: connected 127.0.0.1:6502' 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[0]: Service [test] connected remote server from 127.0.0.1:41172' 264s [listener] A client connected from somewhere 264s [[127.0.0.1]:41172] New connection 264s [[127.0.0.1]:41172] Telling the main thread 264s [[127.0.0.1]:41172] Let them tell us something... 264s [test_connect [127.0.0.1]:6503 0] Creating an SSL context 264s [test_connect [127.0.0.1]:6503 0] - cert required 264s [test_connect [127.0.0.1]:6503 0] - load_verify_locations() 264s [test_connect [127.0.0.1]:6503 0] Opening an SSL connection 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[2]: Service [test] accepted connection from 127.0.0.1:51018' 264s [test_connect [127.0.0.1]:6503 0] Connected to the server: [127.0.0.1]:51018 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[2]: s_connect: connected 127.0.0.1:6502' 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[2]: Service [test] connected remote server from 127.0.0.1:41184' 264s [listener] A client connected from somewhere 264s [[127.0.0.1]:41184] New connection 264s [[127.0.0.1]:41184] Telling the main thread 264s [[127.0.0.1]:41184] Let them tell us something... 264s [test_connect [127.0.0.1]:6503 8] Creating an SSL context 264s [test_connect [127.0.0.1]:6503 8] - cert required 264s [test_connect [127.0.0.1]:6503 8] - load_verify_locations() 264s [test_connect [127.0.0.1]:6503 8] Opening an SSL connection 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[3]: Service [test] accepted connection from 127.0.0.1:51034' 264s [test_connect [127.0.0.1]:6503 8] Connected to the server: [127.0.0.1]:51034 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[3]: s_connect: connected 127.0.0.1:6502' 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[3]: Service [test] connected remote server from 127.0.0.1:41196' 264s [listener] A client connected from somewhere 264s [[127.0.0.1]:41196] New connection 264s [[127.0.0.1]:41196] Telling the main thread 264s [[127.0.0.1]:41196] Let them tell us something... 264s [test_connect [127.0.0.1]:6503 6] Sending something... 264s [test_connect [127.0.0.1]:6503 6] Waiting for the main thread to figure it out 264s [[127.0.0.1]:41164] Telling the main thread about b'Hello 6\n' 264s [[127.0.0.1]:41164] Writing something back... 264s [[127.0.0.1]:41164] Telling the main thread about b'There!\n' 264s [[127.0.0.1]:41164] Closing down the writer socket 264s [test_connect [127.0.0.1]:6503 6] The listener acknowledged [127.0.0.1]:41164 264s [test_connect [127.0.0.1]:6503 6] Waiting for the server to receive it... 264s [test_connect [127.0.0.1]:6503 6] Waiting for the server to send something 264s [test_connect [127.0.0.1]:6503 6] Trying to receive the actual data 264s [[127.0.0.1]:41164] Telling the main thread done 264s [test_connect [127.0.0.1]:6503 6] Waiting for the server to close the connection 264s [test_connect [127.0.0.1]:6503 6] Waiting for an EOF on the reader socket 264s [test_connect [127.0.0.1]:6503 6] Closing our writer socket, too 264s [test_connect [127.0.0.1]:6503 6] Letting the main thread know we're done 264s [test_connect [127.0.0.1]:6503 6] Done 264s [process_connections] Fetching task encr-6 264s [process_connections] Waiting for task encr-6 264s [process_connections] Done with task encr-6 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[1]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 264s [test_connect [127.0.0.1]:6503 3] Creating an SSL context 264s [test_connect [127.0.0.1]:6503 3] - cert required 264s [test_connect [127.0.0.1]:6503 3] - load_verify_locations() 264s [test_connect [127.0.0.1]:6503 3] Opening an SSL connection 264s [test_connect [127.0.0.1]:6503 7] Creating an SSL context 264s [test_connect [127.0.0.1]:6503 7] - cert required 264s [test_connect [127.0.0.1]:6503 7] - load_verify_locations() 264s [test_connect [127.0.0.1]:6503 7] Opening an SSL connection 264s [test_connect [127.0.0.1]:6503 9] Creating an SSL context 264s [test_connect [127.0.0.1]:6503 9] - cert required 264s [test_connect [127.0.0.1]:6503 9] - load_verify_locations() 264s [test_connect [127.0.0.1]:6503 9] Opening an SSL connection 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[4]: Service [test] accepted connection from 127.0.0.1:51036' 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[5]: Service [test] accepted connection from 127.0.0.1:51044' 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[6]: Service [test] accepted connection from 127.0.0.1:51058' 264s [test_connect [127.0.0.1]:6503 3] Connected to the server: [127.0.0.1]:51036 264s [test_connect [127.0.0.1]:6503 7] Connected to the server: [127.0.0.1]:51044 264s [test_connect [127.0.0.1]:6503 9] Connected to the server: [127.0.0.1]:51058 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[4]: s_connect: connected 127.0.0.1:6502' 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[4]: Service [test] connected remote server from 127.0.0.1:41202' 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[5]: s_connect: connected 127.0.0.1:6502' 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[5]: Service [test] connected remote server from 127.0.0.1:41212' 264s [listener] A client connected from somewhere 264s [[127.0.0.1]:41202] New connection 264s [[127.0.0.1]:41202] Telling the main thread 264s [[127.0.0.1]:41202] Let them tell us something... 264s [listener] A client connected from somewhere 264s [[127.0.0.1]:41212] New connection 264s [[127.0.0.1]:41212] Telling the main thread 264s [[127.0.0.1]:41212] Let them tell us something... 264s [listener] A client connected from somewhere 264s [[127.0.0.1]:41222] New connection 264s [[127.0.0.1]:41222] Telling the main thread 264s [[127.0.0.1]:41222] Let them tell us something... 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[6]: s_connect: connected 127.0.0.1:6502' 264s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[6]: Service [test] connected remote server from 127.0.0.1:41222' 265s [test_connect [127.0.0.1]:6503 2] Creating an SSL context 265s [test_connect [127.0.0.1]:6503 2] - cert required 265s [test_connect [127.0.0.1]:6503 2] - load_verify_locations() 265s [test_connect [127.0.0.1]:6503 2] Opening an SSL connection 265s [test_connect [127.0.0.1]:6503 5] Creating an SSL context 265s [test_connect [127.0.0.1]:6503 5] - cert required 265s [test_connect [127.0.0.1]:6503 5] - load_verify_locations() 265s [test_connect [127.0.0.1]:6503 5] Opening an SSL connection 265s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[7]: Service [test] accepted connection from 127.0.0.1:51068' 265s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[8]: Service [test] accepted connection from 127.0.0.1:51072' 265s [test_connect [127.0.0.1]:6503 2] Connected to the server: [127.0.0.1]:51068 265s [test_connect [127.0.0.1]:6503 5] Connected to the server: [127.0.0.1]:51072 265s [test_connect [127.0.0.1]:6503 0] Sending something... 265s [test_connect [127.0.0.1]:6503 0] Waiting for the main thread to figure it out 265s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[7]: s_connect: connected 127.0.0.1:6502' 265s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[7]: Service [test] connected remote server from 127.0.0.1:41228' 265s [[127.0.0.1]:41184] Telling the main thread about b'Hello 0\n' 265s [[127.0.0.1]:41184] Writing something back... 265s [[127.0.0.1]:41184] Telling the main thread about b'There!\n' 265s [[127.0.0.1]:41184] Closing down the writer socket 265s [listener] A client connected from somewhere 265s [[127.0.0.1]:41228] New connection 265s [[127.0.0.1]:41228] Telling the main thread 265s [[127.0.0.1]:41228] Let them tell us something... 265s [listener] A client connected from somewhere 265s [[127.0.0.1]:41242] New connection 265s [[127.0.0.1]:41242] Telling the main thread 265s [[127.0.0.1]:41242] Let them tell us something... 265s [test_connect [127.0.0.1]:6503 0] The listener acknowledged [127.0.0.1]:41184 265s [test_connect [127.0.0.1]:6503 0] Waiting for the server to receive it... 265s [test_connect [127.0.0.1]:6503 0] Waiting for the server to send something 265s [test_connect [127.0.0.1]:6503 0] Trying to receive the actual data 265s [test_connect [127.0.0.1]:6503 0] Waiting for the server to close the connection 265s [[127.0.0.1]:41184] Telling the main thread done 265s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[8]: s_connect: connected 127.0.0.1:6502' 265s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[8]: Service [test] connected remote server from 127.0.0.1:41242' 265s [test_connect [127.0.0.1]:6503 0] Waiting for an EOF on the reader socket 265s [test_connect [127.0.0.1]:6503 0] Closing our writer socket, too 265s [test_connect [127.0.0.1]:6503 0] Letting the main thread know we're done 265s [test_connect [127.0.0.1]:6503 0] Done 265s [stunnel_output] Read '2024.11.14 06:21:34 LOG5[2]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 265s [process_connections] Fetching task encr-0 265s [process_connections] Waiting for task encr-0 265s [process_connections] Done with task encr-0 265s [test_connect [127.0.0.1]:6503 1] Creating an SSL context 265s [test_connect [127.0.0.1]:6503 1] - cert required 265s [test_connect [127.0.0.1]:6503 1] - load_verify_locations() 265s [test_connect [127.0.0.1]:6503 1] Opening an SSL connection 265s [stunnel_output] Read '2024.11.14 06:21:35 LOG5[9]: Service [test] accepted connection from 127.0.0.1:51082' 265s [test_connect [127.0.0.1]:6503 1] Connected to the server: [127.0.0.1]:51082 265s [test_connect [127.0.0.1]:6503 8] Sending something... 265s [test_connect [127.0.0.1]:6503 8] Waiting for the main thread to figure it out 265s [listener] A client connected from somewhere 265s [[127.0.0.1]:41244] New connection 265s [[127.0.0.1]:41244] Telling the main thread 265s [[127.0.0.1]:41244] Let them tell us something... 265s [stunnel_output] Read '2024.11.14 06:21:35 LOG5[9]: s_connect: connected 127.0.0.1:6502' 265s [stunnel_output] Read '2024.11.14 06:21:35 LOG5[9]: Service [test] connected remote server from 127.0.0.1:41244' 265s [[127.0.0.1]:41196] Telling the main thread about b'Hello 8\n' 265s [[127.0.0.1]:41196] Writing something back... 265s [[127.0.0.1]:41196] Telling the main thread about b'There!\n' 265s [[127.0.0.1]:41196] Closing down the writer socket 265s [test_connect [127.0.0.1]:6503 8] The listener acknowledged [127.0.0.1]:41196 265s [test_connect [127.0.0.1]:6503 8] Waiting for the server to receive it... 265s [test_connect [127.0.0.1]:6503 8] Waiting for the server to send something 265s [test_connect [127.0.0.1]:6503 8] Trying to receive the actual data 265s [[127.0.0.1]:41196] Telling the main thread done 265s [test_connect [127.0.0.1]:6503 8] Waiting for the server to close the connection 265s [test_connect [127.0.0.1]:6503 8] Waiting for an EOF on the reader socket 265s [test_connect [127.0.0.1]:6503 8] Closing our writer socket, too 265s [test_connect [127.0.0.1]:6503 8] Letting the main thread know we're done 265s [test_connect [127.0.0.1]:6503 8] Done 265s [stunnel_output] Read '2024.11.14 06:21:35 LOG5[3]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 265s [process_connections] Fetching task encr-8 265s [process_connections] Waiting for task encr-8 265s [process_connections] Done with task encr-8 265s [test_connect [127.0.0.1]:6503 4] Sending something... 265s [test_connect [127.0.0.1]:6503 4] Waiting for the main thread to figure it out 265s [[127.0.0.1]:41172] Telling the main thread about b'Hello 4\n' 265s [[127.0.0.1]:41172] Writing something back... 265s [[127.0.0.1]:41172] Telling the main thread about b'There!\n' 265s [[127.0.0.1]:41172] Closing down the writer socket 265s [test_connect [127.0.0.1]:6503 4] The listener acknowledged [127.0.0.1]:41172 265s [test_connect [127.0.0.1]:6503 4] Waiting for the server to receive it... 265s [test_connect [127.0.0.1]:6503 4] Waiting for the server to send something 265s [test_connect [127.0.0.1]:6503 4] Trying to receive the actual data 265s [test_connect [127.0.0.1]:6503 4] Waiting for the server to close the connection 265s [[127.0.0.1]:41172] Telling the main thread done 265s [test_connect [127.0.0.1]:6503 4] Waiting for an EOF on the reader socket 265s [test_connect [127.0.0.1]:6503 4] Closing our writer socket, too 265s [test_connect [127.0.0.1]:6503 4] Letting the main thread know we're done 265s [test_connect [127.0.0.1]:6503 4] Done 265s [process_connections] Fetching task encr-4 265s [process_connections] Waiting for task encr-4 265s [process_connections] Done with task encr-4 265s [stunnel_output] Read '2024.11.14 06:21:35 LOG5[0]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 265s [test_connect [127.0.0.1]:6503 5] Sending something... 265s [test_connect [127.0.0.1]:6503 5] Waiting for the main thread to figure it out 265s [[127.0.0.1]:41242] Telling the main thread about b'Hello 5\n' 265s [[127.0.0.1]:41242] Writing something back... 265s [[127.0.0.1]:41242] Telling the main thread about b'There!\n' 265s [[127.0.0.1]:41242] Closing down the writer socket 265s [test_connect [127.0.0.1]:6503 5] The listener acknowledged [127.0.0.1]:41242 265s [test_connect [127.0.0.1]:6503 5] Waiting for the server to receive it... 265s [test_connect [127.0.0.1]:6503 5] Waiting for the server to send something 265s [test_connect [127.0.0.1]:6503 5] Trying to receive the actual data 265s [[127.0.0.1]:41242] Telling the main thread done 265s [test_connect [127.0.0.1]:6503 5] Waiting for the server to close the connection 265s [test_connect [127.0.0.1]:6503 5] Waiting for an EOF on the reader socket 265s [test_connect [127.0.0.1]:6503 5] Closing our writer socket, too 265s [test_connect [127.0.0.1]:6503 5] Letting the main thread know we're done 265s [test_connect [127.0.0.1]:6503 5] Done 265s [stunnel_output] Read '2024.11.14 06:21:35 LOG5[8]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 265s [process_connections] Fetching task encr-5 265s [process_connections] Waiting for task encr-5 265s [process_connections] Done with task encr-5 265s [test_connect [127.0.0.1]:6503 7] Sending something... 265s [test_connect [127.0.0.1]:6503 7] Waiting for the main thread to figure it out 265s [test_connect [127.0.0.1]:6503 9] Sending something... 265s [test_connect [127.0.0.1]:6503 9] Waiting for the main thread to figure it out 265s [[127.0.0.1]:41212] Telling the main thread about b'Hello 7\n' 265s [[127.0.0.1]:41212] Writing something back... 265s [[127.0.0.1]:41212] Telling the main thread about b'There!\n' 265s [[127.0.0.1]:41212] Closing down the writer socket 265s [[127.0.0.1]:41222] Telling the main thread about b'Hello 9\n' 265s [[127.0.0.1]:41222] Writing something back... 265s [[127.0.0.1]:41222] Telling the main thread about b'There!\n' 265s [[127.0.0.1]:41222] Closing down the writer socket 265s [test_connect [127.0.0.1]:6503 7] The listener acknowledged [127.0.0.1]:41212 265s [test_connect [127.0.0.1]:6503 7] Waiting for the server to receive it... 265s [test_connect [127.0.0.1]:6503 7] Waiting for the server to send something 265s [test_connect [127.0.0.1]:6503 7] Trying to receive the actual data 265s [test_connect [127.0.0.1]:6503 9] The listener acknowledged [127.0.0.1]:41222 265s [test_connect [127.0.0.1]:6503 9] Waiting for the server to receive it... 265s [test_connect [127.0.0.1]:6503 9] Waiting for the server to send something 265s [test_connect [127.0.0.1]:6503 9] Trying to receive the actual data 265s [test_connect [127.0.0.1]:6503 9] Waiting for the server to close the connection 265s [[127.0.0.1]:41212] Telling the main thread done 265s [[127.0.0.1]:41222] Telling the main thread done 265s [test_connect [127.0.0.1]:6503 7] Waiting for the server to close the connection 265s [test_connect [127.0.0.1]:6503 7] Waiting for an EOF on the reader socket 265s [test_connect [127.0.0.1]:6503 7] Closing our writer socket, too 265s [test_connect [127.0.0.1]:6503 9] Waiting for an EOF on the reader socket 265s [test_connect [127.0.0.1]:6503 9] Closing our writer socket, too 265s [test_connect [127.0.0.1]:6503 9] Letting the main thread know we're done 265s [test_connect [127.0.0.1]:6503 9] Done 265s [test_connect [127.0.0.1]:6503 7] Letting the main thread know we're done 265s [test_connect [127.0.0.1]:6503 7] Done 265s [stunnel_output] Read '2024.11.14 06:21:35 LOG5[6]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 265s [stunnel_output] Read '2024.11.14 06:21:35 LOG5[5]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 265s [process_connections] Fetching task encr-9 265s [process_connections] Waiting for task encr-9 265s [process_connections] Done with task encr-9 265s [process_connections] Fetching task encr-7 265s [process_connections] Waiting for task encr-7 265s [process_connections] Done with task encr-7 265s [test_connect [127.0.0.1]:6503 3] Sending something... 265s [test_connect [127.0.0.1]:6503 3] Waiting for the main thread to figure it out 265s [[127.0.0.1]:41202] Telling the main thread about b'Hello 3\n' 265s [[127.0.0.1]:41202] Writing something back... 265s [[127.0.0.1]:41202] Telling the main thread about b'There!\n' 265s [[127.0.0.1]:41202] Closing down the writer socket 265s [test_connect [127.0.0.1]:6503 3] The listener acknowledged [127.0.0.1]:41202 265s [test_connect [127.0.0.1]:6503 3] Waiting for the server to receive it... 265s [test_connect [127.0.0.1]:6503 3] Waiting for the server to send something 265s [test_connect [127.0.0.1]:6503 3] Trying to receive the actual data 265s [test_connect [127.0.0.1]:6503 3] Waiting for the server to close the connection 265s [[127.0.0.1]:41202] Telling the main thread done 265s [test_connect [127.0.0.1]:6503 3] Waiting for an EOF on the reader socket 265s [test_connect [127.0.0.1]:6503 3] Closing our writer socket, too 265s [test_connect [127.0.0.1]:6503 3] Letting the main thread know we're done 265s [test_connect [127.0.0.1]:6503 3] Done 265s [process_connections] Fetching task encr-3 265s [process_connections] Waiting for task encr-3 265s [process_connections] Done with task encr-3 265s [stunnel_output] Read '2024.11.14 06:21:35 LOG5[4]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 265s [test_connect [127.0.0.1]:6503 1] Sending something... 265s [test_connect [127.0.0.1]:6503 1] Waiting for the main thread to figure it out 265s [[127.0.0.1]:41244] Telling the main thread about b'Hello 1\n' 265s [[127.0.0.1]:41244] Writing something back... 265s [[127.0.0.1]:41244] Telling the main thread about b'There!\n' 265s [[127.0.0.1]:41244] Closing down the writer socket 265s [test_connect [127.0.0.1]:6503 2] Sending something... 265s [test_connect [127.0.0.1]:6503 2] Waiting for the main thread to figure it out 265s [test_connect [127.0.0.1]:6503 1] The listener acknowledged [127.0.0.1]:41244 265s [test_connect [127.0.0.1]:6503 1] Waiting for the server to receive it... 265s [test_connect [127.0.0.1]:6503 1] Waiting for the server to send something 265s [test_connect [127.0.0.1]:6503 1] Trying to receive the actual data 265s [test_connect [127.0.0.1]:6503 1] Waiting for the server to close the connection 265s [[127.0.0.1]:41244] Telling the main thread done 265s [[127.0.0.1]:41228] Telling the main thread about b'Hello 2\n' 265s [[127.0.0.1]:41228] Writing something back... 265s [[127.0.0.1]:41228] Telling the main thread about b'There!\n' 265s [[127.0.0.1]:41228] Closing down the writer socket 265s [test_connect [127.0.0.1]:6503 1] Waiting for an EOF on the reader socket 265s [test_connect [127.0.0.1]:6503 1] Closing our writer socket, too 265s [test_connect [127.0.0.1]:6503 2] The listener acknowledged [127.0.0.1]:41228 265s [test_connect [127.0.0.1]:6503 2] Waiting for the server to receive it... 265s [test_connect [127.0.0.1]:6503 2] Waiting for the server to send something 265s [test_connect [127.0.0.1]:6503 2] Trying to receive the actual data 265s [[127.0.0.1]:41228] Telling the main thread done 265s [test_connect [127.0.0.1]:6503 1] Letting the main thread know we're done 265s [test_connect [127.0.0.1]:6503 1] Done 265s [process_connections] Fetching task encr-1 265s [process_connections] Waiting for task encr-1 265s [process_connections] Done with task encr-1 265s [stunnel_output] Read '2024.11.14 06:21:35 LOG5[9]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 265s [test_connect [127.0.0.1]:6503 2] Waiting for the server to close the connection 265s [test_connect [127.0.0.1]:6503 2] Waiting for an EOF on the reader socket 265s [test_connect [127.0.0.1]:6503 2] Closing our writer socket, too 265s [test_connect [127.0.0.1]:6503 2] Letting the main thread know we're done 265s [test_connect [127.0.0.1]:6503 2] Done 265s [stunnel_output] Read '2024.11.14 06:21:35 LOG5[7]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 265s [process_connections] Fetching task encr-2 265s [process_connections] Waiting for task encr-2 265s [process_connections] Done with task encr-2 265s [main] Everything seems to be all right! 265s About to cancel 2 remaining task(s) 265s - listen 265s - output 265s Waiting for the tasks to hopefully finish 265s About to kill and wait for 1 child process(es) 265s - pid 1151 265s Waiting for the processes to exit... 265s Got processes' exit status: [-9] 265s 265s 265s ====== python3.13 265s 266s Using /tmp/struntime.qg90q2_u as a temporary directory 266s Trying to obtain the version of /usr/bin/stunnel4 266s Started `/usr/bin/stunnel4 -version` as process 1170 266s Got stunnel version 5.73 266s [main] Starting to do things 266s [main] Awaiting the 'listener started' event 266s [find_listening_port] Looking for a port to listen on 266s [find_listening_port] Trying localhost port 6502 266s [listener] Telling the main thread about [127.0.0.1]:6502 266s [listener] Awaiting client connections... 266s [main] Apparently we are listening on [127.0.0.1]:6502 266s [main] Testing cleartext connections 266s [test_connect [127.0.0.1]:6502 0] Trying port 6502 encrypted False 266s [test_connect [127.0.0.1]:6502 1] Trying port 6502 encrypted False 266s [test_connect [127.0.0.1]:6502 2] Trying port 6502 encrypted False 266s [test_connect [127.0.0.1]:6502 3] Trying port 6502 encrypted False 266s [test_connect [127.0.0.1]:6502 4] Trying port 6502 encrypted False 266s [test_connect [127.0.0.1]:6502 5] Trying port 6502 encrypted False 266s [test_connect [127.0.0.1]:6502 6] Trying port 6502 encrypted False 266s [test_connect [127.0.0.1]:6502 7] Trying port 6502 encrypted False 266s [test_connect [127.0.0.1]:6502 8] Trying port 6502 encrypted False 266s [test_connect [127.0.0.1]:6502 9] Trying port 6502 encrypted False 266s [test_connect [127.0.0.1]:6502 8] Opening an unencrypted connection 266s [listener] A client connected from somewhere 266s [[127.0.0.1]:41246] New connection 266s [[127.0.0.1]:41246] Telling the main thread 266s [[127.0.0.1]:41246] Let them tell us something... 266s [test_connect [127.0.0.1]:6502 8] Connected to the server: [127.0.0.1]:41246 266s [test_connect [127.0.0.1]:6502 0] Opening an unencrypted connection 266s [test_connect [127.0.0.1]:6502 2] Opening an unencrypted connection 266s [test_connect [127.0.0.1]:6502 7] Opening an unencrypted connection 266s [listener] A client connected from somewhere 266s [[127.0.0.1]:41260] New connection 266s [[127.0.0.1]:41260] Telling the main thread 266s [[127.0.0.1]:41260] Let them tell us something... 266s [listener] A client connected from somewhere 266s [[127.0.0.1]:41262] New connection 266s [[127.0.0.1]:41262] Telling the main thread 266s [[127.0.0.1]:41262] Let them tell us something... 266s [listener] A client connected from somewhere 266s [[127.0.0.1]:41272] New connection 266s [[127.0.0.1]:41272] Telling the main thread 266s [[127.0.0.1]:41272] Let them tell us something... 266s [test_connect [127.0.0.1]:6502 0] Connected to the server: [127.0.0.1]:41260 266s [test_connect [127.0.0.1]:6502 2] Connected to the server: [127.0.0.1]:41262 266s [test_connect [127.0.0.1]:6502 7] Connected to the server: [127.0.0.1]:41272 266s [test_connect [127.0.0.1]:6502 8] Sending something... 266s [test_connect [127.0.0.1]:6502 8] Waiting for the main thread to figure it out 266s [[127.0.0.1]:41246] Telling the main thread about b'Hello 8\n' 266s [[127.0.0.1]:41246] Writing something back... 266s [[127.0.0.1]:41246] Telling the main thread about b'There!\n' 266s [[127.0.0.1]:41246] Closing down the writer socket 266s [test_connect [127.0.0.1]:6502 8] The listener acknowledged [127.0.0.1]:41246 266s [test_connect [127.0.0.1]:6502 8] Waiting for the server to receive it... 266s [test_connect [127.0.0.1]:6502 8] Waiting for the server to send something 266s [test_connect [127.0.0.1]:6502 8] Trying to receive the actual data 266s [test_connect [127.0.0.1]:6502 8] Waiting for the server to close the connection 266s [[127.0.0.1]:41246] Telling the main thread done 266s [test_connect [127.0.0.1]:6502 8] Waiting for an EOF on the reader socket 266s [test_connect [127.0.0.1]:6502 8] Closing our writer socket, too 266s [test_connect [127.0.0.1]:6502 8] Letting the main thread know we're done 266s [test_connect [127.0.0.1]:6502 8] Done 266s [process_connections] Fetching task plain-8 266s [process_connections] Waiting for task plain-8 266s [process_connections] Done with task plain-8 266s [test_connect [127.0.0.1]:6502 9] Opening an unencrypted connection 266s [listener] A client connected from somewhere 266s [[127.0.0.1]:41286] New connection 266s [[127.0.0.1]:41286] Telling the main thread 266s [[127.0.0.1]:41286] Let them tell us something... 266s [test_connect [127.0.0.1]:6502 9] Connected to the server: [127.0.0.1]:41286 266s [test_connect [127.0.0.1]:6502 2] Sending something... 266s [test_connect [127.0.0.1]:6502 2] Waiting for the main thread to figure it out 266s [[127.0.0.1]:41262] Telling the main thread about b'Hello 2\n' 266s [[127.0.0.1]:41262] Writing something back... 266s [[127.0.0.1]:41262] Telling the main thread about b'There!\n' 266s [[127.0.0.1]:41262] Closing down the writer socket 266s [test_connect [127.0.0.1]:6502 2] The listener acknowledged [127.0.0.1]:41262 266s [test_connect [127.0.0.1]:6502 2] Waiting for the server to receive it... 266s [test_connect [127.0.0.1]:6502 2] Waiting for the server to send something 266s [test_connect [127.0.0.1]:6502 2] Trying to receive the actual data 266s [test_connect [127.0.0.1]:6502 2] Waiting for the server to close the connection 266s [[127.0.0.1]:41262] Telling the main thread done 266s [test_connect [127.0.0.1]:6502 2] Waiting for an EOF on the reader socket 266s [test_connect [127.0.0.1]:6502 2] Closing our writer socket, too 266s [test_connect [127.0.0.1]:6502 2] Letting the main thread know we're done 266s [test_connect [127.0.0.1]:6502 2] Done 266s [process_connections] Fetching task plain-2 266s [process_connections] Waiting for task plain-2 266s [process_connections] Done with task plain-2 266s [test_connect [127.0.0.1]:6502 5] Opening an unencrypted connection 266s [test_connect [127.0.0.1]:6502 6] Opening an unencrypted connection 266s [listener] A client connected from somewhere 266s [[127.0.0.1]:41300] New connection 266s [[127.0.0.1]:41300] Telling the main thread 266s [[127.0.0.1]:41300] Let them tell us something... 266s [listener] A client connected from somewhere 266s [[127.0.0.1]:41310] New connection 266s [[127.0.0.1]:41310] Telling the main thread 266s [[127.0.0.1]:41310] Let them tell us something... 266s [test_connect [127.0.0.1]:6502 5] Connected to the server: [127.0.0.1]:41300 266s [test_connect [127.0.0.1]:6502 6] Connected to the server: [127.0.0.1]:41310 267s [test_connect [127.0.0.1]:6502 1] Opening an unencrypted connection 267s [test_connect [127.0.0.1]:6502 3] Opening an unencrypted connection 267s [test_connect [127.0.0.1]:6502 4] Opening an unencrypted connection 267s [listener] A client connected from somewhere 267s [[127.0.0.1]:41320] New connection 267s [[127.0.0.1]:41320] Telling the main thread 267s [[127.0.0.1]:41320] Let them tell us something... 267s [listener] A client connected from somewhere 267s [[127.0.0.1]:41336] New connection 267s [[127.0.0.1]:41336] Telling the main thread 267s [[127.0.0.1]:41336] Let them tell us something... 267s [listener] A client connected from somewhere 267s [[127.0.0.1]:41352] New connection 267s [[127.0.0.1]:41352] Telling the main thread 267s [[127.0.0.1]:41352] Let them tell us something... 267s [test_connect [127.0.0.1]:6502 1] Connected to the server: [127.0.0.1]:41320 267s [test_connect [127.0.0.1]:6502 3] Connected to the server: [127.0.0.1]:41336 267s [test_connect [127.0.0.1]:6502 4] Connected to the server: [127.0.0.1]:41352 267s [test_connect [127.0.0.1]:6502 0] Sending something... 267s [test_connect [127.0.0.1]:6502 0] Waiting for the main thread to figure it out 267s [test_connect [127.0.0.1]:6502 7] Sending something... 267s [test_connect [127.0.0.1]:6502 7] Waiting for the main thread to figure it out 267s [[127.0.0.1]:41260] Telling the main thread about b'Hello 0\n' 267s [[127.0.0.1]:41260] Writing something back... 267s [[127.0.0.1]:41260] Telling the main thread about b'There!\n' 267s [[127.0.0.1]:41260] Closing down the writer socket 267s [[127.0.0.1]:41272] Telling the main thread about b'Hello 7\n' 267s [[127.0.0.1]:41272] Writing something back... 267s [[127.0.0.1]:41272] Telling the main thread about b'There!\n' 267s [[127.0.0.1]:41272] Closing down the writer socket 267s [test_connect [127.0.0.1]:6502 0] The listener acknowledged [127.0.0.1]:41260 267s [test_connect [127.0.0.1]:6502 0] Waiting for the server to receive it... 267s [test_connect [127.0.0.1]:6502 0] Waiting for the server to send something 267s [test_connect [127.0.0.1]:6502 0] Trying to receive the actual data 267s [test_connect [127.0.0.1]:6502 0] Waiting for the server to close the connection 267s [test_connect [127.0.0.1]:6502 7] The listener acknowledged [127.0.0.1]:41272 267s [test_connect [127.0.0.1]:6502 7] Waiting for the server to receive it... 267s [test_connect [127.0.0.1]:6502 7] Waiting for the server to send something 267s [test_connect [127.0.0.1]:6502 7] Trying to receive the actual data 267s [test_connect [127.0.0.1]:6502 7] Waiting for the server to close the connection 267s [[127.0.0.1]:41260] Telling the main thread done 267s [[127.0.0.1]:41272] Telling the main thread done 267s [test_connect [127.0.0.1]:6502 0] Waiting for an EOF on the reader socket 267s [test_connect [127.0.0.1]:6502 0] Closing our writer socket, too 267s [test_connect [127.0.0.1]:6502 7] Waiting for an EOF on the reader socket 267s [test_connect [127.0.0.1]:6502 7] Closing our writer socket, too 267s [test_connect [127.0.0.1]:6502 0] Letting the main thread know we're done 267s [test_connect [127.0.0.1]:6502 0] Done 267s [test_connect [127.0.0.1]:6502 7] Letting the main thread know we're done 267s [test_connect [127.0.0.1]:6502 7] Done 267s [process_connections] Fetching task plain-0 267s [process_connections] Waiting for task plain-0 267s [process_connections] Done with task plain-0 267s [process_connections] Fetching task plain-7 267s [process_connections] Waiting for task plain-7 267s [process_connections] Done with task plain-7 267s [test_connect [127.0.0.1]:6502 9] Sending something... 267s [test_connect [127.0.0.1]:6502 9] Waiting for the main thread to figure it out 267s [[127.0.0.1]:41286] Telling the main thread about b'Hello 9\n' 267s [[127.0.0.1]:41286] Writing something back... 267s [[127.0.0.1]:41286] Telling the main thread about b'There!\n' 267s [[127.0.0.1]:41286] Closing down the writer socket 267s [test_connect [127.0.0.1]:6502 9] The listener acknowledged [127.0.0.1]:41286 267s [test_connect [127.0.0.1]:6502 9] Waiting for the server to receive it... 267s [test_connect [127.0.0.1]:6502 9] Waiting for the server to send something 267s [test_connect [127.0.0.1]:6502 9] Trying to receive the actual data 267s [test_connect [127.0.0.1]:6502 9] Waiting for the server to close the connection 267s [[127.0.0.1]:41286] Telling the main thread done 267s [test_connect [127.0.0.1]:6502 9] Waiting for an EOF on the reader socket 267s [test_connect [127.0.0.1]:6502 9] Closing our writer socket, too 267s [test_connect [127.0.0.1]:6502 9] Letting the main thread know we're done 267s [test_connect [127.0.0.1]:6502 9] Done 267s [process_connections] Fetching task plain-9 267s [process_connections] Waiting for task plain-9 267s [process_connections] Done with task plain-9 267s [test_connect [127.0.0.1]:6502 3] Sending something... 267s [test_connect [127.0.0.1]:6502 3] Waiting for the main thread to figure it out 267s [[127.0.0.1]:41336] Telling the main thread about b'Hello 3\n' 267s [[127.0.0.1]:41336] Writing something back... 267s [[127.0.0.1]:41336] Telling the main thread about b'There!\n' 267s [[127.0.0.1]:41336] Closing down the writer socket 267s [test_connect [127.0.0.1]:6502 3] The listener acknowledged [127.0.0.1]:41336 267s [test_connect [127.0.0.1]:6502 3] Waiting for the server to receive it... 267s [test_connect [127.0.0.1]:6502 3] Waiting for the server to send something 267s [test_connect [127.0.0.1]:6502 3] Trying to receive the actual data 267s [test_connect [127.0.0.1]:6502 3] Waiting for the server to close the connection 267s [[127.0.0.1]:41336] Telling the main thread done 267s [test_connect [127.0.0.1]:6502 3] Waiting for an EOF on the reader socket 267s [test_connect [127.0.0.1]:6502 3] Closing our writer socket, too 267s [test_connect [127.0.0.1]:6502 3] Letting the main thread know we're done 267s [test_connect [127.0.0.1]:6502 3] Done 267s [process_connections] Fetching task plain-3 267s [process_connections] Waiting for task plain-3 267s [process_connections] Done with task plain-3 267s [test_connect [127.0.0.1]:6502 6] Sending something... 267s [test_connect [127.0.0.1]:6502 6] Waiting for the main thread to figure it out 267s [[127.0.0.1]:41310] Telling the main thread about b'Hello 6\n' 267s [[127.0.0.1]:41310] Writing something back... 267s [[127.0.0.1]:41310] Telling the main thread about b'There!\n' 267s [[127.0.0.1]:41310] Closing down the writer socket 267s [test_connect [127.0.0.1]:6502 6] The listener acknowledged [127.0.0.1]:41310 267s [test_connect [127.0.0.1]:6502 6] Waiting for the server to receive it... 267s [test_connect [127.0.0.1]:6502 6] Waiting for the server to send something 267s [test_connect [127.0.0.1]:6502 6] Trying to receive the actual data 267s [test_connect [127.0.0.1]:6502 6] Waiting for the server to close the connection 267s [[127.0.0.1]:41310] Telling the main thread done 267s [test_connect [127.0.0.1]:6502 6] Waiting for an EOF on the reader socket 267s [test_connect [127.0.0.1]:6502 6] Closing our writer socket, too 267s [test_connect [127.0.0.1]:6502 6] Letting the main thread know we're done 267s [test_connect [127.0.0.1]:6502 6] Done 267s [process_connections] Fetching task plain-6 267s [process_connections] Waiting for task plain-6 267s [process_connections] Done with task plain-6 267s [test_connect [127.0.0.1]:6502 4] Sending something... 267s [test_connect [127.0.0.1]:6502 4] Waiting for the main thread to figure it out 267s [test_connect [127.0.0.1]:6502 5] Sending something... 267s [test_connect [127.0.0.1]:6502 5] Waiting for the main thread to figure it out 267s [[127.0.0.1]:41352] Telling the main thread about b'Hello 4\n' 267s [[127.0.0.1]:41352] Writing something back... 267s [[127.0.0.1]:41352] Telling the main thread about b'There!\n' 267s [[127.0.0.1]:41352] Closing down the writer socket 267s [[127.0.0.1]:41300] Telling the main thread about b'Hello 5\n' 267s [[127.0.0.1]:41300] Writing something back... 267s [[127.0.0.1]:41300] Telling the main thread about b'There!\n' 267s [[127.0.0.1]:41300] Closing down the writer socket 267s [test_connect [127.0.0.1]:6502 4] The listener acknowledged [127.0.0.1]:41352 267s [test_connect [127.0.0.1]:6502 4] Waiting for the server to receive it... 267s [test_connect [127.0.0.1]:6502 4] Waiting for the server to send something 267s [test_connect [127.0.0.1]:6502 4] Trying to receive the actual data 267s [test_connect [127.0.0.1]:6502 4] Waiting for the server to close the connection 267s [test_connect [127.0.0.1]:6502 5] The listener acknowledged [127.0.0.1]:41300 267s [test_connect [127.0.0.1]:6502 5] Waiting for the server to receive it... 267s [test_connect [127.0.0.1]:6502 5] Waiting for the server to send something 267s [test_connect [127.0.0.1]:6502 5] Trying to receive the actual data 267s [test_connect [127.0.0.1]:6502 5] Waiting for the server to close the connection 267s [[127.0.0.1]:41352] Telling the main thread done 267s [[127.0.0.1]:41300] Telling the main thread done 267s [test_connect [127.0.0.1]:6502 4] Waiting for an EOF on the reader socket 267s [test_connect [127.0.0.1]:6502 4] Closing our writer socket, too 267s [test_connect [127.0.0.1]:6502 5] Waiting for an EOF on the reader socket 267s [test_connect [127.0.0.1]:6502 5] Closing our writer socket, too 267s [test_connect [127.0.0.1]:6502 4] Letting the main thread know we're done 267s [test_connect [127.0.0.1]:6502 4] Done 267s [test_connect [127.0.0.1]:6502 5] Letting the main thread know we're done 267s [test_connect [127.0.0.1]:6502 5] Done 267s [process_connections] Fetching task plain-4 267s [process_connections] Waiting for task plain-4 267s [process_connections] Done with task plain-4 268s [process_connections] Fetching task plain-5 268s [process_connections] Waiting for task plain-5 268s [process_connections] Done with task plain-5 268s [test_connect [127.0.0.1]:6502 1] Sending something... 268s [test_connect [127.0.0.1]:6502 1] Waiting for the main thread to figure it out 268s [[127.0.0.1]:41320] Telling the main thread about b'Hello 1\n' 268s [[127.0.0.1]:41320] Writing something back... 268s [[127.0.0.1]:41320] Telling the main thread about b'There!\n' 268s [[127.0.0.1]:41320] Closing down the writer socket 268s [test_connect [127.0.0.1]:6502 1] The listener acknowledged [127.0.0.1]:41320 268s [test_connect [127.0.0.1]:6502 1] Waiting for the server to receive it... 268s [test_connect [127.0.0.1]:6502 1] Waiting for the server to send something 268s [test_connect [127.0.0.1]:6502 1] Trying to receive the actual data 268s [test_connect [127.0.0.1]:6502 1] Waiting for the server to close the connection 268s [[127.0.0.1]:41320] Telling the main thread done 268s [test_connect [127.0.0.1]:6502 1] Waiting for an EOF on the reader socket 268s [test_connect [127.0.0.1]:6502 1] Closing our writer socket, too 268s [test_connect [127.0.0.1]:6502 1] Letting the main thread know we're done 268s [test_connect [127.0.0.1]:6502 1] Done 268s [process_connections] Fetching task plain-1 268s [process_connections] Waiting for task plain-1 268s [process_connections] Done with task plain-1 268s [main] Picking a listen address:port for stunnel 268s [find_listening_port] Looking for a port to listen on 268s [find_listening_port] Trying 127.0.0.1 port 6503 268s [find_listening_port] got 6503, shutting down the listener 268s [main] Will put stunnel at 127.0.0.1:6503 268s [main] Preparing the stunnel config file 268s [main] Using config file /tmp/struntime.qg90q2_u/stunnel.conf 268s [main] 268s [main] pid = /tmp/struntime.qg90q2_u/stunnel.pid 268s [main] foreground = yes 268s [main] 268s [main] cert = /tmp/autopkgtest.QyYqGA/build.Xop/src/debian/tests/certs/certificate.pem 268s [main] key = /tmp/struntime.qg90q2_u/key.pem 268s [main] 268s [main] [test] 268s [main] accept = 127.0.0.1:6503 268s [main] connect = 127.0.0.1:6502 268s [main] End of the config file 268s [main] Launching the stunnel server 268s [main] - got pid 1174 268s [main] Launching the stunnel output pipe thread 268s [main] Waiting for stunnel to start up 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[ui]: stunnel 5.73 on arm-unknown-linux-gnueabihf platform' 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[ui]: Compiled/running with OpenSSL 3.3.1 4 Jun 2024' 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[ui]: Threading:PTHREAD Sockets:POLL,IPv6,SYSTEMD TLS:ENGINE,OCSP,PSK,SNI Auth:LIBWRAP' 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[ui]: Reading configuration from file /tmp/struntime.qg90q2_u/stunnel.conf' 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[ui]: UTF-8 byte order mark not detected' 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[ui]: FIPS mode disabled' 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[ui]: Configuration successful' 268s [stunnel_output] The main thread ought to know 268s [main] Testing the encrypted connections 268s [test_connect [127.0.0.1]:6503 0] Trying port 6503 encrypted True 268s [test_connect [127.0.0.1]:6503 1] Trying port 6503 encrypted True 268s [test_connect [127.0.0.1]:6503 2] Trying port 6503 encrypted True 268s [test_connect [127.0.0.1]:6503 3] Trying port 6503 encrypted True 268s [test_connect [127.0.0.1]:6503 4] Trying port 6503 encrypted True 268s [test_connect [127.0.0.1]:6503 5] Trying port 6503 encrypted True 268s [test_connect [127.0.0.1]:6503 6] Trying port 6503 encrypted True 268s [test_connect [127.0.0.1]:6503 7] Trying port 6503 encrypted True 268s [test_connect [127.0.0.1]:6503 8] Trying port 6503 encrypted True 268s [test_connect [127.0.0.1]:6503 9] Trying port 6503 encrypted True 268s [test_connect [127.0.0.1]:6503 4] Creating an SSL context 268s [test_connect [127.0.0.1]:6503 4] - cert required 268s [test_connect [127.0.0.1]:6503 4] - load_verify_locations() 268s [test_connect [127.0.0.1]:6503 4] Opening an SSL connection 268s [test_connect [127.0.0.1]:6503 5] Creating an SSL context 268s [test_connect [127.0.0.1]:6503 5] - cert required 268s [test_connect [127.0.0.1]:6503 5] - load_verify_locations() 268s [test_connect [127.0.0.1]:6503 5] Opening an SSL connection 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[0]: Service [test] accepted connection from 127.0.0.1:51094' 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[1]: Service [test] accepted connection from 127.0.0.1:51104' 268s [test_connect [127.0.0.1]:6503 5] Connected to the server: [127.0.0.1]:51104 268s [test_connect [127.0.0.1]:6503 4] Connected to the server: [127.0.0.1]:51094 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[1]: s_connect: connected 127.0.0.1:6502' 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[1]: Service [test] connected remote server from 127.0.0.1:41368' 268s [listener] A client connected from somewhere 268s [[127.0.0.1]:41368] New connection 268s [[127.0.0.1]:41368] Telling the main thread 268s [[127.0.0.1]:41368] Let them tell us something... 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[0]: s_connect: connected 127.0.0.1:6502' 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[0]: Service [test] connected remote server from 127.0.0.1:41382' 268s [listener] A client connected from somewhere 268s [[127.0.0.1]:41382] New connection 268s [[127.0.0.1]:41382] Telling the main thread 268s [[127.0.0.1]:41382] Let them tell us something... 268s [test_connect [127.0.0.1]:6503 6] Creating an SSL context 268s [test_connect [127.0.0.1]:6503 6] - cert required 268s [test_connect [127.0.0.1]:6503 6] - load_verify_locations() 268s [test_connect [127.0.0.1]:6503 6] Opening an SSL connection 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[2]: Service [test] accepted connection from 127.0.0.1:38958' 268s [test_connect [127.0.0.1]:6503 6] Connected to the server: [127.0.0.1]:38958 268s [listener] A client connected from somewhere 268s [[127.0.0.1]:33406] New connection 268s [[127.0.0.1]:33406] Telling the main thread 268s [[127.0.0.1]:33406] Let them tell us something... 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[2]: s_connect: connected 127.0.0.1:6502' 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[2]: Service [test] connected remote server from 127.0.0.1:33406' 268s [test_connect [127.0.0.1]:6503 1] Creating an SSL context 268s [test_connect [127.0.0.1]:6503 1] - cert required 268s [test_connect [127.0.0.1]:6503 1] - load_verify_locations() 268s [test_connect [127.0.0.1]:6503 1] Opening an SSL connection 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[3]: Service [test] accepted connection from 127.0.0.1:38972' 268s [test_connect [127.0.0.1]:6503 1] Connected to the server: [127.0.0.1]:38972 268s [listener] A client connected from somewhere 268s [[127.0.0.1]:33408] New connection 268s [[127.0.0.1]:33408] Telling the main thread 268s [[127.0.0.1]:33408] Let them tell us something... 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[3]: s_connect: connected 127.0.0.1:6502' 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[3]: Service [test] connected remote server from 127.0.0.1:33408' 268s [test_connect [127.0.0.1]:6503 6] Sending something... 268s [test_connect [127.0.0.1]:6503 6] Waiting for the main thread to figure it out 268s [[127.0.0.1]:33406] Telling the main thread about b'Hello 6\n' 268s [[127.0.0.1]:33406] Writing something back... 268s [[127.0.0.1]:33406] Telling the main thread about b'There!\n' 268s [[127.0.0.1]:33406] Closing down the writer socket 268s [test_connect [127.0.0.1]:6503 6] The listener acknowledged [127.0.0.1]:33406 268s [test_connect [127.0.0.1]:6503 6] Waiting for the server to receive it... 268s [test_connect [127.0.0.1]:6503 6] Waiting for the server to send something 268s [test_connect [127.0.0.1]:6503 6] Trying to receive the actual data 268s [[127.0.0.1]:33406] Telling the main thread done 268s [test_connect [127.0.0.1]:6503 6] Waiting for the server to close the connection 268s [test_connect [127.0.0.1]:6503 6] Waiting for an EOF on the reader socket 268s [test_connect [127.0.0.1]:6503 6] Closing our writer socket, too 268s [test_connect [127.0.0.1]:6503 6] Letting the main thread know we're done 268s [test_connect [127.0.0.1]:6503 6] Done 268s [process_connections] Fetching task encr-6 268s [process_connections] Waiting for task encr-6 268s [process_connections] Done with task encr-6 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[2]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 268s [test_connect [127.0.0.1]:6503 0] Creating an SSL context 268s [test_connect [127.0.0.1]:6503 0] - cert required 268s [test_connect [127.0.0.1]:6503 0] - load_verify_locations() 268s [test_connect [127.0.0.1]:6503 0] Opening an SSL connection 268s [test_connect [127.0.0.1]:6503 3] Creating an SSL context 268s [test_connect [127.0.0.1]:6503 3] - cert required 268s [test_connect [127.0.0.1]:6503 3] - load_verify_locations() 268s [test_connect [127.0.0.1]:6503 3] Opening an SSL connection 268s [test_connect [127.0.0.1]:6503 8] Creating an SSL context 268s [test_connect [127.0.0.1]:6503 8] - cert required 268s [test_connect [127.0.0.1]:6503 8] - load_verify_locations() 268s [test_connect [127.0.0.1]:6503 8] Opening an SSL connection 268s [test_connect [127.0.0.1]:6503 9] Creating an SSL context 268s [test_connect [127.0.0.1]:6503 9] - cert required 268s [test_connect [127.0.0.1]:6503 9] - load_verify_locations() 268s [test_connect [127.0.0.1]:6503 9] Opening an SSL connection 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[4]: Service [test] accepted connection from 127.0.0.1:38980' 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[5]: Service [test] accepted connection from 127.0.0.1:38992' 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[6]: Service [test] accepted connection from 127.0.0.1:39002' 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[7]: Service [test] accepted connection from 127.0.0.1:39014' 268s [test_connect [127.0.0.1]:6503 0] Connected to the server: [127.0.0.1]:38980 268s [test_connect [127.0.0.1]:6503 3] Connected to the server: [127.0.0.1]:38992 268s [test_connect [127.0.0.1]:6503 8] Connected to the server: [127.0.0.1]:39002 268s [test_connect [127.0.0.1]:6503 9] Connected to the server: [127.0.0.1]:39014 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[4]: s_connect: connected 127.0.0.1:6502' 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[4]: Service [test] connected remote server from 127.0.0.1:33422' 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[5]: s_connect: connected 127.0.0.1:6502' 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[5]: Service [test] connected remote server from 127.0.0.1:33426' 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[6]: s_connect: connected 127.0.0.1:6502' 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[6]: Service [test] connected remote server from 127.0.0.1:33428' 268s [listener] A client connected from somewhere 268s [[127.0.0.1]:33422] New connection 268s [[127.0.0.1]:33422] Telling the main thread 268s [[127.0.0.1]:33422] Let them tell us something... 268s [listener] A client connected from somewhere 268s [[127.0.0.1]:33426] New connection 268s [[127.0.0.1]:33426] Telling the main thread 268s [[127.0.0.1]:33426] Let them tell us something... 268s [listener] A client connected from somewhere 268s [[127.0.0.1]:33428] New connection 268s [[127.0.0.1]:33428] Telling the main thread 268s [[127.0.0.1]:33428] Let them tell us something... 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[7]: s_connect: connected 127.0.0.1:6502' 268s [stunnel_output] Read '2024.11.14 06:21:38 LOG5[7]: Service [test] connected remote server from 127.0.0.1:33436' 268s [listener] A client connected from somewhere 268s [[127.0.0.1]:33436] New connection 268s [[127.0.0.1]:33436] Telling the main thread 268s [[127.0.0.1]:33436] Let them tell us something... 269s [test_connect [127.0.0.1]:6503 2] Creating an SSL context 269s [test_connect [127.0.0.1]:6503 2] - cert required 269s [test_connect [127.0.0.1]:6503 2] - load_verify_locations() 269s [test_connect [127.0.0.1]:6503 2] Opening an SSL connection 269s [test_connect [127.0.0.1]:6503 7] Creating an SSL context 269s [test_connect [127.0.0.1]:6503 7] - cert required 269s [test_connect [127.0.0.1]:6503 7] - load_verify_locations() 269s [test_connect [127.0.0.1]:6503 7] Opening an SSL connection 269s [stunnel_output] Read '2024.11.14 06:21:39 LOG5[8]: Service [test] accepted connection from 127.0.0.1:39020' 269s [stunnel_output] Read '2024.11.14 06:21:39 LOG5[9]: Service [test] accepted connection from 127.0.0.1:39034' 269s [test_connect [127.0.0.1]:6503 2] Connected to the server: [127.0.0.1]:39020 269s [test_connect [127.0.0.1]:6503 7] Connected to the server: [127.0.0.1]:39034 269s [stunnel_output] Read '2024.11.14 06:21:39 LOG5[8]: s_connect: connected 127.0.0.1:6502' 269s [stunnel_output] Read '2024.11.14 06:21:39 LOG5[8]: Service [test] connected remote server from 127.0.0.1:33440' 269s [listener] A client connected from somewhere 269s [[127.0.0.1]:33440] New connection 269s [[127.0.0.1]:33440] Telling the main thread 269s [[127.0.0.1]:33440] Let them tell us something... 269s [listener] A client connected from somewhere 269s [[127.0.0.1]:33442] New connection 269s [[127.0.0.1]:33442] Telling the main thread 269s [[127.0.0.1]:33442] Let them tell us something... 269s [stunnel_output] Read '2024.11.14 06:21:39 LOG5[9]: s_connect: connected 127.0.0.1:6502' 269s [stunnel_output] Read '2024.11.14 06:21:39 LOG5[9]: Service [test] connected remote server from 127.0.0.1:33442' 269s [test_connect [127.0.0.1]:6503 4] Sending something... 269s [test_connect [127.0.0.1]:6503 4] Waiting for the main thread to figure it out 269s [[127.0.0.1]:41382] Telling the main thread about b'Hello 4\n' 269s [[127.0.0.1]:41382] Writing something back... 269s [[127.0.0.1]:41382] Telling the main thread about b'There!\n' 269s [[127.0.0.1]:41382] Closing down the writer socket 269s [test_connect [127.0.0.1]:6503 4] The listener acknowledged [127.0.0.1]:41382 269s [test_connect [127.0.0.1]:6503 4] Waiting for the server to receive it... 269s [test_connect [127.0.0.1]:6503 4] Waiting for the server to send something 269s [test_connect [127.0.0.1]:6503 4] Trying to receive the actual data 269s [test_connect [127.0.0.1]:6503 4] Waiting for the server to close the connection 269s [[127.0.0.1]:41382] Telling the main thread done 269s [test_connect [127.0.0.1]:6503 4] Waiting for an EOF on the reader socket 269s [test_connect [127.0.0.1]:6503 4] Closing our writer socket, too 269s [test_connect [127.0.0.1]:6503 4] Letting the main thread know we're done 269s [test_connect [127.0.0.1]:6503 4] Done 269s [stunnel_output] Read '2024.11.14 06:21:39 LOG5[0]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 269s [process_connections] Fetching task encr-4 269s [process_connections] Waiting for task encr-4 269s [process_connections] Done with task encr-4 269s [test_connect [127.0.0.1]:6503 5] Sending something... 269s [test_connect [127.0.0.1]:6503 5] Waiting for the main thread to figure it out 269s [[127.0.0.1]:41368] Telling the main thread about b'Hello 5\n' 269s [[127.0.0.1]:41368] Writing something back... 269s [[127.0.0.1]:41368] Telling the main thread about b'There!\n' 269s [[127.0.0.1]:41368] Closing down the writer socket 269s [test_connect [127.0.0.1]:6503 5] The listener acknowledged [127.0.0.1]:41368 269s [test_connect [127.0.0.1]:6503 5] Waiting for the server to receive it... 269s [test_connect [127.0.0.1]:6503 5] Waiting for the server to send something 269s [test_connect [127.0.0.1]:6503 5] Trying to receive the actual data 269s [[127.0.0.1]:41368] Telling the main thread done 269s [test_connect [127.0.0.1]:6503 5] Waiting for the server to close the connection 269s [test_connect [127.0.0.1]:6503 5] Waiting for an EOF on the reader socket 269s [test_connect [127.0.0.1]:6503 5] Closing our writer socket, too 269s [test_connect [127.0.0.1]:6503 5] Letting the main thread know we're done 269s [test_connect [127.0.0.1]:6503 5] Done 269s [process_connections] Fetching task encr-5 269s [process_connections] Waiting for task encr-5 269s [process_connections] Done with task encr-5 269s [stunnel_output] Read '2024.11.14 06:21:39 LOG5[1]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 269s [test_connect [127.0.0.1]:6503 0] Sending something... 269s [test_connect [127.0.0.1]:6503 0] Waiting for the main thread to figure it out 269s [[127.0.0.1]:33422] Telling the main thread about b'Hello 0\n' 269s [[127.0.0.1]:33422] Writing something back... 269s [[127.0.0.1]:33422] Telling the main thread about b'There!\n' 269s [[127.0.0.1]:33422] Closing down the writer socket 269s [test_connect [127.0.0.1]:6503 0] The listener acknowledged [127.0.0.1]:33422 269s [test_connect [127.0.0.1]:6503 0] Waiting for the server to receive it... 269s [test_connect [127.0.0.1]:6503 0] Waiting for the server to send something 269s [test_connect [127.0.0.1]:6503 0] Trying to receive the actual data 269s [[127.0.0.1]:33422] Telling the main thread done 269s [test_connect [127.0.0.1]:6503 0] Waiting for the server to close the connection 269s [test_connect [127.0.0.1]:6503 0] Waiting for an EOF on the reader socket 269s [test_connect [127.0.0.1]:6503 0] Closing our writer socket, too 269s [test_connect [127.0.0.1]:6503 0] Letting the main thread know we're done 269s [test_connect [127.0.0.1]:6503 0] Done 269s [process_connections] Fetching task encr-0 269s [process_connections] Waiting for task encr-0 269s [process_connections] Done with task encr-0 269s [stunnel_output] Read '2024.11.14 06:21:39 LOG5[4]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 269s [test_connect [127.0.0.1]:6503 1] Sending something... 269s [test_connect [127.0.0.1]:6503 1] Waiting for the main thread to figure it out 269s [[127.0.0.1]:33408] Telling the main thread about b'Hello 1\n' 269s [[127.0.0.1]:33408] Writing something back... 269s [[127.0.0.1]:33408] Telling the main thread about b'There!\n' 269s [[127.0.0.1]:33408] Closing down the writer socket 269s [test_connect [127.0.0.1]:6503 1] The listener acknowledged [127.0.0.1]:33408 269s [test_connect [127.0.0.1]:6503 1] Waiting for the server to receive it... 269s [test_connect [127.0.0.1]:6503 1] Waiting for the server to send something 269s [test_connect [127.0.0.1]:6503 1] Trying to receive the actual data 269s [test_connect [127.0.0.1]:6503 1] Waiting for the server to close the connection 269s [[127.0.0.1]:33408] Telling the main thread done 269s [test_connect [127.0.0.1]:6503 1] Waiting for an EOF on the reader socket 269s [test_connect [127.0.0.1]:6503 1] Closing our writer socket, too 269s [test_connect [127.0.0.1]:6503 1] Letting the main thread know we're done 269s [test_connect [127.0.0.1]:6503 1] Done 269s [process_connections] Fetching task encr-1 269s [process_connections] Waiting for task encr-1 269s [process_connections] Done with task encr-1 269s [stunnel_output] Read '2024.11.14 06:21:39 LOG5[3]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 269s [test_connect [127.0.0.1]:6503 9] Sending something... 269s [test_connect [127.0.0.1]:6503 9] Waiting for the main thread to figure it out 269s [[127.0.0.1]:33436] Telling the main thread about b'Hello 9\n' 269s [[127.0.0.1]:33436] Writing something back... 269s [[127.0.0.1]:33436] Telling the main thread about b'There!\n' 269s [[127.0.0.1]:33436] Closing down the writer socket 269s [test_connect [127.0.0.1]:6503 9] The listener acknowledged [127.0.0.1]:33436 269s [test_connect [127.0.0.1]:6503 9] Waiting for the server to receive it... 269s [test_connect [127.0.0.1]:6503 9] Waiting for the server to send something 269s [test_connect [127.0.0.1]:6503 9] Trying to receive the actual data 269s [test_connect [127.0.0.1]:6503 9] Waiting for the server to close the connection 269s [[127.0.0.1]:33436] Telling the main thread done 269s [test_connect [127.0.0.1]:6503 9] Waiting for an EOF on the reader socket 269s [test_connect [127.0.0.1]:6503 9] Closing our writer socket, too 269s [test_connect [127.0.0.1]:6503 9] Letting the main thread know we're done 269s [test_connect [127.0.0.1]:6503 9] Done 269s [process_connections] Fetching task encr-9 269s [process_connections] Waiting for task encr-9 269s [process_connections] Done with task encr-9 269s [stunnel_output] Read '2024.11.14 06:21:39 LOG5[7]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 269s [test_connect [127.0.0.1]:6503 3] Sending something... 269s [test_connect [127.0.0.1]:6503 3] Waiting for the main thread to figure it out 269s [[127.0.0.1]:33426] Telling the main thread about b'Hello 3\n' 269s [[127.0.0.1]:33426] Writing something back... 269s [[127.0.0.1]:33426] Telling the main thread about b'There!\n' 269s [[127.0.0.1]:33426] Closing down the writer socket 269s [test_connect [127.0.0.1]:6503 3] The listener acknowledged [127.0.0.1]:33426 269s [test_connect [127.0.0.1]:6503 3] Waiting for the server to receive it... 269s [test_connect [127.0.0.1]:6503 3] Waiting for the server to send something 269s [test_connect [127.0.0.1]:6503 3] Trying to receive the actual data 269s [test_connect [127.0.0.1]:6503 3] Waiting for the server to close the connection 269s [[127.0.0.1]:33426] Telling the main thread done 269s [test_connect [127.0.0.1]:6503 3] Waiting for an EOF on the reader socket 269s [test_connect [127.0.0.1]:6503 3] Closing our writer socket, too 269s [test_connect [127.0.0.1]:6503 3] Letting the main thread know we're done 269s [test_connect [127.0.0.1]:6503 3] Done 269s [process_connections] Fetching task encr-3 269s [process_connections] Waiting for task encr-3 269s [process_connections] Done with task encr-3 269s [stunnel_output] Read '2024.11.14 06:21:39 LOG5[5]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 269s [test_connect [127.0.0.1]:6503 7] Sending something... 269s [test_connect [127.0.0.1]:6503 7] Waiting for the main thread to figure it out 269s [[127.0.0.1]:33442] Telling the main thread about b'Hello 7\n' 269s [[127.0.0.1]:33442] Writing something back... 269s [[127.0.0.1]:33442] Telling the main thread about b'There!\n' 269s [[127.0.0.1]:33442] Closing down the writer socket 269s [test_connect [127.0.0.1]:6503 7] The listener acknowledged [127.0.0.1]:33442 269s [test_connect [127.0.0.1]:6503 7] Waiting for the server to receive it... 269s [test_connect [127.0.0.1]:6503 7] Waiting for the server to send something 269s [test_connect [127.0.0.1]:6503 7] Trying to receive the actual data 269s [[127.0.0.1]:33442] Telling the main thread done 269s [test_connect [127.0.0.1]:6503 7] Waiting for the server to close the connection 269s [test_connect [127.0.0.1]:6503 7] Waiting for an EOF on the reader socket 269s [test_connect [127.0.0.1]:6503 7] Closing our writer socket, too 269s [test_connect [127.0.0.1]:6503 7] Letting the main thread know we're done 269s [test_connect [127.0.0.1]:6503 7] Done 269s [test_connect [127.0.0.1]:6503 8] Sending something... 269s [test_connect [127.0.0.1]:6503 8] Waiting for the main thread to figure it out 269s [process_connections] Fetching task encr-7 269s [process_connections] Waiting for task encr-7 269s [process_connections] Done with task encr-7 269s [stunnel_output] Read '2024.11.14 06:21:39 LOG5[9]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 269s [[127.0.0.1]:33428] Telling the main thread about b'Hello 8\n' 269s [[127.0.0.1]:33428] Writing something back... 269s [[127.0.0.1]:33428] Telling the main thread about b'There!\n' 269s [[127.0.0.1]:33428] Closing down the writer socket 269s [test_connect [127.0.0.1]:6503 8] The listener acknowledged [127.0.0.1]:33428 269s [test_connect [127.0.0.1]:6503 8] Waiting for the server to receive it... 269s [test_connect [127.0.0.1]:6503 8] Waiting for the server to send something 269s [test_connect [127.0.0.1]:6503 8] Trying to receive the actual data 269s [test_connect [127.0.0.1]:6503 8] Waiting for the server to close the connection 269s [[127.0.0.1]:33428] Telling the main thread done 269s [test_connect [127.0.0.1]:6503 8] Waiting for an EOF on the reader socket 269s [test_connect [127.0.0.1]:6503 8] Closing our writer socket, too 269s [test_connect [127.0.0.1]:6503 8] Letting the main thread know we're done 269s [test_connect [127.0.0.1]:6503 8] Done 269s [process_connections] Fetching task encr-8 269s [process_connections] Waiting for task encr-8 269s [process_connections] Done with task encr-8 269s [stunnel_output] Read '2024.11.14 06:21:39 LOG5[6]: Connection closed: 7 byte(s) sent to TLS, 8 byte(s) sent to socket' 270s [test_connect [127.0.0.1]:6503 2] Sending something... 270s [test_connect [127.0.0.1]:6503 2] Waiting for the main thread to figure it out 270s [[127.0.0.1]:33440] Telling the main thread about b'Hello 2\n' 270s [[127.0.0.1]:33440] Writing something back... 270s [[127.0.0.1]:33440] Telling the main thread about b'There!\n' 270s [[127.0.0.1]:33440] Closing down the writer socket 270s [test_connect [127.0.0.1]:6503 2] The listener acknowledged [127.0.0.1]:33440 270s [test_connect [127.0.0.1]:6503 2] Waiting for the server to receive it... 270s [test_connect [127.0.0.1]:6503 2] Waiting for the server to send something 270s [test_connect [127.0.0.1]:6503 2] Trying to receive the actual data 270s [test_connect [127.0.0.1]:6503 2] Waiting for the server to close the connection 270s [[127.0.0.1]:33440] Telling the main thread done 270s [test_connect [127.0.0.1]:6503 2] Waiting for an EOF on the reader socket 270s [test_connect [127.0.0.1]:6503 2] Closing our writer socket, too 270s [test_connect [127.0.0.1]:6503 2] Letting the main thread know we're done 270s [test_connect [127.0.0.1]:6503 2] Done 270s [process_connections] Fetching task encr-2 270s [process_connections] Waiting for task encr-2 270s [process_connections] Done with task encr-2 270s [main] Everything seems to be all right! 270s About to cancel 2 remaining task(s) 270s - listen 270s - output 270s Waiting for the tasks to hopefully finish 270s About to kill and wait for 1 child process(es) 270s - pid 1174 270s Waiting for the processes to exit... 270s Got processes' exit status: [-9] 270s autopkgtest [06:21:40]: test debian-python: -----------------------] 274s autopkgtest [06:21:44]: test debian-python: - - - - - - - - - - results - - - - - - - - - - 274s debian-python PASS 278s autopkgtest [06:21:48]: test upstream: preparing testbed 332s autopkgtest [06:22:42]: testbed dpkg architecture: armhf 334s autopkgtest [06:22:44]: testbed apt version: 2.9.8 334s autopkgtest [06:22:44]: @@@@@@@@@@@@@@@@@@@@ test bed setup 342s Get:1 http://ftpmaster.internal/ubuntu plucky-proposed InRelease [73.9 kB] 343s Get:2 http://ftpmaster.internal/ubuntu plucky-proposed/universe Sources [987 kB] 343s Get:3 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse Sources [15.4 kB] 343s Get:4 http://ftpmaster.internal/ubuntu plucky-proposed/restricted Sources [7016 B] 343s Get:5 http://ftpmaster.internal/ubuntu plucky-proposed/main Sources [98.6 kB] 343s Get:6 http://ftpmaster.internal/ubuntu plucky-proposed/main armhf Packages [103 kB] 343s Get:7 http://ftpmaster.internal/ubuntu plucky-proposed/universe armhf Packages [684 kB] 343s Get:8 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse armhf Packages [5040 B] 343s Fetched 1973 kB in 1s (2404 kB/s) 343s Reading package lists... 359s tee: /proc/self/fd/2: Permission denied 382s Hit:1 http://ftpmaster.internal/ubuntu plucky-proposed InRelease 382s Hit:2 http://ftpmaster.internal/ubuntu plucky InRelease 382s Hit:3 http://ftpmaster.internal/ubuntu plucky-updates InRelease 382s Hit:4 http://ftpmaster.internal/ubuntu plucky-security InRelease 383s Reading package lists... 383s Reading package lists... 384s Building dependency tree... 384s Reading state information... 385s Calculating upgrade... 387s The following NEW packages will be installed: 387s python3.13-gdbm 387s The following packages will be upgraded: 387s libpython3-stdlib python3 python3-gdbm python3-minimal 387s 4 upgraded, 1 newly installed, 0 to remove and 0 not upgraded. 387s Need to get 99.6 kB of archives. 387s After this operation, 91.1 kB of additional disk space will be used. 387s Get:1 http://ftpmaster.internal/ubuntu plucky-proposed/main armhf python3-minimal armhf 3.12.7-1 [27.4 kB] 387s Get:2 http://ftpmaster.internal/ubuntu plucky-proposed/main armhf python3 armhf 3.12.7-1 [24.0 kB] 387s Get:3 http://ftpmaster.internal/ubuntu plucky-proposed/main armhf libpython3-stdlib armhf 3.12.7-1 [10.0 kB] 387s Get:4 http://ftpmaster.internal/ubuntu plucky/main armhf python3.13-gdbm armhf 3.13.0-2 [29.5 kB] 387s Get:5 http://ftpmaster.internal/ubuntu plucky-proposed/main armhf python3-gdbm armhf 3.12.7-1 [8642 B] 388s Fetched 99.6 kB in 0s (271 kB/s) 388s (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 ... 59560 files and directories currently installed.) 388s Preparing to unpack .../python3-minimal_3.12.7-1_armhf.deb ... 388s Unpacking python3-minimal (3.12.7-1) over (3.12.6-0ubuntu1) ... 388s Setting up python3-minimal (3.12.7-1) ... 388s (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 ... 59560 files and directories currently installed.) 388s Preparing to unpack .../python3_3.12.7-1_armhf.deb ... 388s Unpacking python3 (3.12.7-1) over (3.12.6-0ubuntu1) ... 388s Preparing to unpack .../libpython3-stdlib_3.12.7-1_armhf.deb ... 388s Unpacking libpython3-stdlib:armhf (3.12.7-1) over (3.12.6-0ubuntu1) ... 388s Selecting previously unselected package python3.13-gdbm. 388s Preparing to unpack .../python3.13-gdbm_3.13.0-2_armhf.deb ... 388s Unpacking python3.13-gdbm (3.13.0-2) ... 388s Preparing to unpack .../python3-gdbm_3.12.7-1_armhf.deb ... 388s Unpacking python3-gdbm:armhf (3.12.7-1) over (3.12.6-1ubuntu1) ... 388s Setting up python3.13-gdbm (3.13.0-2) ... 388s Setting up libpython3-stdlib:armhf (3.12.7-1) ... 388s Setting up python3 (3.12.7-1) ... 389s Setting up python3-gdbm:armhf (3.12.7-1) ... 389s Processing triggers for man-db (2.12.1-3) ... 390s Reading package lists... 390s Building dependency tree... 390s Reading state information... 390s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 392s autopkgtest [06:23:42]: rebooting testbed after setup commands that affected boot 499s Reading package lists... 500s Building dependency tree... 500s Reading state information... 501s Starting pkgProblemResolver with broken count: 0 501s Starting 2 pkgProblemResolver with broken count: 0 501s Done 503s The following additional packages will be installed: 503s net-tools stunnel4 503s Suggested packages: 503s logcheck-database 503s The following NEW packages will be installed: 503s autopkgtest-satdep net-tools stunnel4 503s 0 upgraded, 3 newly installed, 0 to remove and 0 not upgraded. 503s Need to get 403 kB/404 kB of archives. 503s After this operation, 1109 kB of additional disk space will be used. 503s Get:1 /tmp/autopkgtest.QyYqGA/2-autopkgtest-satdep.deb autopkgtest-satdep armhf 0 [744 B] 504s Get:2 http://ftpmaster.internal/ubuntu plucky/universe armhf stunnel4 armhf 3:5.73-1 [211 kB] 504s Get:3 http://ftpmaster.internal/ubuntu plucky/main armhf net-tools armhf 2.10-1.1ubuntu1 [192 kB] 505s Fetched 403 kB in 1s (564 kB/s) 505s Selecting previously unselected package stunnel4. 505s (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 ... 59567 files and directories currently installed.) 505s Preparing to unpack .../stunnel4_3%3a5.73-1_armhf.deb ... 505s Unpacking stunnel4 (3:5.73-1) ... 505s Selecting previously unselected package net-tools. 505s Preparing to unpack .../net-tools_2.10-1.1ubuntu1_armhf.deb ... 505s Unpacking net-tools (2.10-1.1ubuntu1) ... 505s Selecting previously unselected package autopkgtest-satdep. 505s Preparing to unpack .../2-autopkgtest-satdep.deb ... 505s Unpacking autopkgtest-satdep (0) ... 505s Setting up stunnel4 (3:5.73-1) ... 505s Creating group 'stunnel4' with GID 988. 505s Creating user 'stunnel4' (stunnel service system account) with UID 988 and GID 988. 505s Created symlink '/etc/systemd/system/multi-user.target.wants/stunnel.target' → '/usr/lib/systemd/system/stunnel.target'. 506s Setting up net-tools (2.10-1.1ubuntu1) ... 506s Setting up autopkgtest-satdep (0) ... 506s Processing triggers for man-db (2.12.1-3) ... 518s (Reading database ... 59659 files and directories currently installed.) 518s Removing autopkgtest-satdep (0) ... 530s autopkgtest [06:26:00]: test upstream: debian/tests/upstream 530s autopkgtest [06:26:00]: test upstream: [----------------------- 535s keys & certificates successfully generated 535s ./maketestcert.sh finished 536s 011. Test "cert" option 536s ...................................................................... succeeded 536s 012. Test no "cert" option 536s ...................................................................... succeeded 536s 021. Test "requireCert" option 536s ...................................................................... succeeded 536s 022. Failure test "requireCert" option 536s ...................................................................... succeeded 536s 031. Test "verifyPeer" option 536s ...................................................................... succeeded 536s 032. Failure test "verifyPeer" option 536s ...................................................................... succeeded 536s 041. Test "verifyChain" option 536s ...................................................................... succeeded 536s 042. Failure test "verifyChain" option 536s ...................................................................... succeeded 536s 051. CRL file with valid certificate 536s ...................................................................... succeeded 536s 052. CRL file with revoked certificate 536s ...................................................................... succeeded 536s 061. Test "PSKsecrets" option 536s ...................................................................... succeeded 536s 062. Failure test "PSKsecrets" option 536s ...................................................................... succeeded 536s 071. Test PKCS#12 certificate 536s ...................................................................... succeeded 536s 081. Test IPv6 support 536s ...................................................................... succeeded 536s 091. Binding server 536s ...................................................................... succeeded 536s 101. Test FIPS mode 536s ...................................................................... skipped 536s 111. Failure FIPS mode with unavailable cipher 536s ...................................................................... skipped 536s 112. Failure FIPS mode with unavailable ciphersuite 536s ...................................................................... skipped 536s 113. Failure FIPS mode with unavailable elliptic curve 536s ...................................................................... skipped 536s 121. Test "sni" option 536s ...................................................................... succeeded 536s 122. Failure test "sni" option 536s ...................................................................... succeeded 536s 131. Resume session with PSK authentication 537s ...................................................................... succeeded 537s 132. Cache session resumption with TLSv1.2 537s ...................................................................... succeeded 537s 133. Test enabled "sessionResume" option 537s ...................................................................... succeeded 537s 134. Test disabled "sessionResume" option 537s ...................................................................... succeeded 537s 141. Stateless session ticket resumption with TLSv1.2 537s ...................................................................... succeeded 537s 142. Stateless session ticket resumption with TLSv1.3 537s ...................................................................... succeeded 537s 151. Session resumption with secret keys 538s ...................................................................... succeeded 538s 161. Redirect connection (wrong peer certificate) 538s ...................................................................... succeeded 538s 162. Redirect connection (no peer certificate) 538s ...................................................................... succeeded 538s 163. Not redirected connection (valid peer certificate) 538s ...................................................................... succeeded 538s 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) 538s ...................................................................... succeeded 538s 183. Session resumption and no redirect (valid certificate) 538s ...................................................................... succeeded 538s 191. Reload configuration 538s ...................................................................... succeeded 538s 201. Failover round robin (rr) strategy 539s ...................................................................... succeeded 539s 202. Failover priority (prio) strategy 539s ...................................................................... succeeded 539s 211. Included configuration files 539s ...................................................................... succeeded 539s 221. Client inetd mode 539s ...................................................................... succeeded 539s 231. Test exec+connect service 539s ...................................................................... succeeded 539s 241. Resume session with delay option 539s ...................................................................... succeeded 539s 242. Resume session with disable delay option 540s ...................................................................... succeeded 540s 251. Wrong client configuration 540s ...................................................................... succeeded 540s 261. Wrong server configuration 540s ...................................................................... succeeded 540s 271. Test OCSP stapling 540s ...................................................................... succeeded 540s 272. Test OCSP client-driven 540s ...................................................................... succeeded 540s 273. Failure test OCSP stapling 540s ...................................................................... succeeded 540s 274. Failure test OCSP client-driven 540s ...................................................................... succeeded 540s 540s Summary: 540s succeeded: 50 540s failed: 0 540s skipped: 4 540s 540s Testing results: /tmp/autopkgtest.QyYqGA/build.Xop/src/tests/logs/results.log 541s autopkgtest [06:26:11]: test upstream: -----------------------] 545s autopkgtest [06:26:15]: test upstream: - - - - - - - - - - results - - - - - - - - - - 545s upstream PASS 549s autopkgtest [06:26:19]: @@@@@@@@@@@@@@@@@@@@ summary 549s debian-python PASS 549s upstream PASS