0s autopkgtest [18:07:58]: starting date and time: 2024-04-19 18:07:58+0000 0s autopkgtest [18:07:58]: git checkout: 43bc6cdf gitlab-ci: do not include the salsa pipeline 0s autopkgtest [18:07:58]: host juju-7f2275-prod-proposed-migration-environment-2; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.2ykiln71/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:systemd --apt-upgrade knot-resolver --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=systemd/255.4-1ubuntu8 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@bos01-arm64-45.secgroup --name adt-noble-arm64-knot-resolver-20240419-180758-juju-7f2275-prod-proposed-migration-environment-2-ed23f394-e61e-4cf4-bc42-c707cb2bc490 --image adt/ubuntu-noble-arm64-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-2 --net-id=net_prod-proposed-migration -e TERM=linux -e ''"'"'http_proxy=http://squid.internal:3128'"'"'' -e ''"'"'https_proxy=http://squid.internal:3128'"'"'' -e ''"'"'no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com'"'"'' --mirror=http://us.ports.ubuntu.com/ubuntu-ports/ 169s autopkgtest [18:10:47]: testbed dpkg architecture: arm64 169s autopkgtest [18:10:47]: testbed apt version: 2.7.14build2 169s autopkgtest [18:10:47]: @@@@@@@@@@@@@@@@@@@@ test bed setup 170s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [117 kB] 170s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/multiverse Sources [2340 B] 170s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [12.3 kB] 170s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [48.6 kB] 170s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [264 kB] 170s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 Packages [118 kB] 170s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 c-n-f Metadata [3144 B] 170s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/restricted arm64 Packages [98.2 kB] 170s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/restricted arm64 c-n-f Metadata [116 B] 170s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/universe arm64 Packages [238 kB] 170s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/universe arm64 c-n-f Metadata [8528 B] 170s Get:12 http://ftpmaster.internal/ubuntu noble-proposed/multiverse arm64 Packages [756 B] 170s Get:13 http://ftpmaster.internal/ubuntu noble-proposed/multiverse arm64 c-n-f Metadata [116 B] 172s Fetched 911 kB in 1s (976 kB/s) 172s Reading package lists... 173s sh: 4: dhclient: not found 174s Reading package lists... 174s Building dependency tree... 174s Reading state information... 175s Calculating upgrade... 175s The following packages will be upgraded: 175s libnss-systemd libpam-systemd libsystemd-shared libsystemd0 libudev1 systemd 175s systemd-dev systemd-resolved systemd-sysv systemd-timesyncd udev 175s 11 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 175s Need to get 8695 kB of archives. 175s After this operation, 10.2 kB of additional disk space will be used. 175s Get:1 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 systemd-dev all 255.4-1ubuntu8 [104 kB] 176s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 systemd-timesyncd arm64 255.4-1ubuntu8 [34.8 kB] 176s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 systemd-resolved arm64 255.4-1ubuntu8 [291 kB] 176s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 libsystemd-shared arm64 255.4-1ubuntu8 [2016 kB] 176s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 libsystemd0 arm64 255.4-1ubuntu8 [424 kB] 176s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 systemd-sysv arm64 255.4-1ubuntu8 [11.9 kB] 176s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 libnss-systemd arm64 255.4-1ubuntu8 [155 kB] 176s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 libpam-systemd arm64 255.4-1ubuntu8 [232 kB] 176s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 systemd arm64 255.4-1ubuntu8 [3403 kB] 177s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 udev arm64 255.4-1ubuntu8 [1852 kB] 177s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 libudev1 arm64 255.4-1ubuntu8 [173 kB] 178s Fetched 8695 kB in 2s (3774 kB/s) 178s (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 ... 77768 files and directories currently installed.) 178s Preparing to unpack .../systemd-dev_255.4-1ubuntu8_all.deb ... 178s Unpacking systemd-dev (255.4-1ubuntu8) over (255.4-1ubuntu7) ... 178s Preparing to unpack .../systemd-timesyncd_255.4-1ubuntu8_arm64.deb ... 178s Unpacking systemd-timesyncd (255.4-1ubuntu8) over (255.4-1ubuntu7) ... 178s Preparing to unpack .../systemd-resolved_255.4-1ubuntu8_arm64.deb ... 178s Unpacking systemd-resolved (255.4-1ubuntu8) over (255.4-1ubuntu7) ... 178s Preparing to unpack .../libsystemd-shared_255.4-1ubuntu8_arm64.deb ... 178s Unpacking libsystemd-shared:arm64 (255.4-1ubuntu8) over (255.4-1ubuntu7) ... 178s Preparing to unpack .../libsystemd0_255.4-1ubuntu8_arm64.deb ... 178s Unpacking libsystemd0:arm64 (255.4-1ubuntu8) over (255.4-1ubuntu7) ... 178s Setting up libsystemd0:arm64 (255.4-1ubuntu8) ... 178s (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 ... 77768 files and directories currently installed.) 178s Preparing to unpack .../0-systemd-sysv_255.4-1ubuntu8_arm64.deb ... 178s Unpacking systemd-sysv (255.4-1ubuntu8) over (255.4-1ubuntu7) ... 178s Preparing to unpack .../1-libnss-systemd_255.4-1ubuntu8_arm64.deb ... 178s Unpacking libnss-systemd:arm64 (255.4-1ubuntu8) over (255.4-1ubuntu7) ... 178s Preparing to unpack .../2-libpam-systemd_255.4-1ubuntu8_arm64.deb ... 178s Unpacking libpam-systemd:arm64 (255.4-1ubuntu8) over (255.4-1ubuntu7) ... 178s Preparing to unpack .../3-systemd_255.4-1ubuntu8_arm64.deb ... 178s Unpacking systemd (255.4-1ubuntu8) over (255.4-1ubuntu7) ... 179s Preparing to unpack .../4-udev_255.4-1ubuntu8_arm64.deb ... 179s Unpacking udev (255.4-1ubuntu8) over (255.4-1ubuntu7) ... 179s Preparing to unpack .../5-libudev1_255.4-1ubuntu8_arm64.deb ... 179s Unpacking libudev1:arm64 (255.4-1ubuntu8) over (255.4-1ubuntu7) ... 179s Setting up libudev1:arm64 (255.4-1ubuntu8) ... 179s Setting up systemd-dev (255.4-1ubuntu8) ... 179s Setting up libsystemd-shared:arm64 (255.4-1ubuntu8) ... 179s Setting up systemd (255.4-1ubuntu8) ... 179s Setting up systemd-timesyncd (255.4-1ubuntu8) ... 180s Setting up udev (255.4-1ubuntu8) ... 180s Setting up systemd-resolved (255.4-1ubuntu8) ... 181s Setting up systemd-sysv (255.4-1ubuntu8) ... 181s Setting up libnss-systemd:arm64 (255.4-1ubuntu8) ... 181s Setting up libpam-systemd:arm64 (255.4-1ubuntu8) ... 181s Processing triggers for libc-bin (2.39-0ubuntu8) ... 181s Processing triggers for man-db (2.12.0-4build2) ... 182s Processing triggers for dbus (1.14.10-4ubuntu4) ... 182s Processing triggers for initramfs-tools (0.142ubuntu25) ... 182s update-initramfs: Generating /boot/initrd.img-6.8.0-22-generic 182s W: No lz4 in /usr/bin:/sbin:/bin, using gzip 191s System running in EFI mode, skipping. 191s Reading package lists... 192s Building dependency tree... 192s Reading state information... 192s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 192s Hit:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease 193s Hit:2 http://ftpmaster.internal/ubuntu noble InRelease 193s Hit:3 http://ftpmaster.internal/ubuntu noble-updates InRelease 193s Hit:4 http://ftpmaster.internal/ubuntu noble-security InRelease 194s Reading package lists... 194s Reading package lists... 194s Building dependency tree... 194s Reading state information... 194s Calculating upgrade... 195s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 195s Reading package lists... 195s Building dependency tree... 195s Reading state information... 196s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 196s autopkgtest [18:11:14]: rebooting testbed after setup commands that affected boot 350s autopkgtest [18:13:48]: testbed running kernel: Linux 6.8.0-22-generic #22-Ubuntu SMP PREEMPT_DYNAMIC Fri Apr 5 02:52:09 UTC 2024 353s autopkgtest [18:13:51]: @@@@@@@@@@@@@@@@@@@@ apt-source knot-resolver 358s Get:1 http://ftpmaster.internal/ubuntu noble/universe knot-resolver 5.7.2-1 (dsc) [3184 B] 358s Get:2 http://ftpmaster.internal/ubuntu noble/universe knot-resolver 5.7.2-1 (tar) [1928 kB] 358s Get:3 http://ftpmaster.internal/ubuntu noble/universe knot-resolver 5.7.2-1 (asc) [833 B] 358s Get:4 http://ftpmaster.internal/ubuntu noble/universe knot-resolver 5.7.2-1 (diff) [402 kB] 358s gpgv: Signature made Tue Apr 2 05:46:43 2024 UTC 358s gpgv: using RSA key 23EBCF7E8FC47556787100DFA4254072E373042C 358s gpgv: Can't check signature: No public key 358s dpkg-source: warning: cannot verify inline signature for ./knot-resolver_5.7.2-1.dsc: no acceptable signature found 358s autopkgtest [18:13:56]: testing package knot-resolver version 5.7.2-1 361s autopkgtest [18:13:59]: build not needed 392s autopkgtest [18:14:30]: test roundtrip: preparing testbed 393s Reading package lists... 394s Building dependency tree... 394s Reading state information... 394s Starting pkgProblemResolver with broken count: 0 394s Starting 2 pkgProblemResolver with broken count: 0 394s Done 395s The following additional packages will be installed: 395s dns-root-data gnutls-bin knot-dnsutils knot-resolver libdnssec9t64 395s libevent-2.1-7t64 libfstrm0 libgnutls-dane0t64 libjemalloc2 libknot14t64 395s libluajit-5.1-2 libluajit-5.1-common libunbound8 libxdp1 libzscanner4t64 395s lua-sec lua-socket socat 395s Recommended packages: 395s knot-resolver-module-http lua-basexx lua-cqueues 395s The following NEW packages will be installed: 395s autopkgtest-satdep dns-root-data gnutls-bin knot-dnsutils knot-resolver 395s libdnssec9t64 libevent-2.1-7t64 libfstrm0 libgnutls-dane0t64 libjemalloc2 395s libknot14t64 libluajit-5.1-2 libluajit-5.1-common libunbound8 libxdp1 395s libzscanner4t64 lua-sec lua-socket socat 395s 0 upgraded, 19 newly installed, 0 to remove and 0 not upgraded. 395s Need to get 2885 kB/2886 kB of archives. 395s After this operation, 12.0 MB of additional disk space will be used. 395s Get:1 /tmp/autopkgtest.2zJl3s/1-autopkgtest-satdep.deb autopkgtest-satdep arm64 0 [728 B] 395s Get:2 http://ftpmaster.internal/ubuntu noble/main arm64 dns-root-data all 2023112702~willsync1 [4450 B] 395s Get:3 http://ftpmaster.internal/ubuntu noble/main arm64 libevent-2.1-7t64 arm64 2.1.12-stable-9ubuntu2 [140 kB] 395s Get:4 http://ftpmaster.internal/ubuntu noble/main arm64 libunbound8 arm64 1.19.2-1ubuntu3 [424 kB] 396s Get:5 http://ftpmaster.internal/ubuntu noble/main arm64 libgnutls-dane0t64 arm64 3.8.3-1.1ubuntu3 [23.5 kB] 396s Get:6 http://ftpmaster.internal/ubuntu noble/universe arm64 gnutls-bin arm64 3.8.3-1.1ubuntu3 [267 kB] 396s Get:7 http://ftpmaster.internal/ubuntu noble/universe arm64 libdnssec9t64 arm64 3.3.4-1.1build2 [30.5 kB] 396s Get:8 http://ftpmaster.internal/ubuntu noble/main arm64 libxdp1 arm64 1.4.2-1ubuntu4 [62.8 kB] 396s Get:9 http://ftpmaster.internal/ubuntu noble/universe arm64 libknot14t64 arm64 3.3.4-1.1build2 [203 kB] 396s Get:10 http://ftpmaster.internal/ubuntu noble/universe arm64 libzscanner4t64 arm64 3.3.4-1.1build2 [135 kB] 396s Get:11 http://ftpmaster.internal/ubuntu noble/universe arm64 libfstrm0 arm64 0.6.1-1build4 [20.6 kB] 396s Get:12 http://ftpmaster.internal/ubuntu noble/universe arm64 knot-dnsutils arm64 3.3.4-1.1build2 [222 kB] 397s Get:13 http://ftpmaster.internal/ubuntu noble/universe arm64 lua-socket arm64 3.1.0-1 [88.9 kB] 397s Get:14 http://ftpmaster.internal/ubuntu noble/universe arm64 lua-sec arm64 1.3.2-1build2 [43.5 kB] 397s Get:15 http://ftpmaster.internal/ubuntu noble/universe arm64 libjemalloc2 arm64 5.3.0-2build1 [204 kB] 397s Get:16 http://ftpmaster.internal/ubuntu noble/universe arm64 libluajit-5.1-common all 2.1.0+git20231223.c525bcb+dfsg-1 [49.2 kB] 397s Get:17 http://ftpmaster.internal/ubuntu noble/universe arm64 libluajit-5.1-2 arm64 2.1.0+git20231223.c525bcb+dfsg-1 [274 kB] 397s Get:18 http://ftpmaster.internal/ubuntu noble/universe arm64 knot-resolver arm64 5.7.2-1 [322 kB] 397s Get:19 http://ftpmaster.internal/ubuntu noble/main arm64 socat arm64 1.8.0.0-4build3 [372 kB] 398s Preconfiguring packages ... 398s Fetched 2885 kB in 3s (1033 kB/s) 398s Selecting previously unselected package dns-root-data. 398s (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 ... 77768 files and directories currently installed.) 398s Preparing to unpack .../00-dns-root-data_2023112702~willsync1_all.deb ... 398s Unpacking dns-root-data (2023112702~willsync1) ... 398s Selecting previously unselected package libevent-2.1-7t64:arm64. 398s Preparing to unpack .../01-libevent-2.1-7t64_2.1.12-stable-9ubuntu2_arm64.deb ... 398s Unpacking libevent-2.1-7t64:arm64 (2.1.12-stable-9ubuntu2) ... 398s Selecting previously unselected package libunbound8:arm64. 398s Preparing to unpack .../02-libunbound8_1.19.2-1ubuntu3_arm64.deb ... 398s Unpacking libunbound8:arm64 (1.19.2-1ubuntu3) ... 398s Selecting previously unselected package libgnutls-dane0t64:arm64. 398s Preparing to unpack .../03-libgnutls-dane0t64_3.8.3-1.1ubuntu3_arm64.deb ... 398s Unpacking libgnutls-dane0t64:arm64 (3.8.3-1.1ubuntu3) ... 398s Selecting previously unselected package gnutls-bin. 398s Preparing to unpack .../04-gnutls-bin_3.8.3-1.1ubuntu3_arm64.deb ... 398s Unpacking gnutls-bin (3.8.3-1.1ubuntu3) ... 398s Selecting previously unselected package libdnssec9t64. 398s Preparing to unpack .../05-libdnssec9t64_3.3.4-1.1build2_arm64.deb ... 398s Unpacking libdnssec9t64 (3.3.4-1.1build2) ... 398s Selecting previously unselected package libxdp1:arm64. 398s Preparing to unpack .../06-libxdp1_1.4.2-1ubuntu4_arm64.deb ... 398s Unpacking libxdp1:arm64 (1.4.2-1ubuntu4) ... 398s Selecting previously unselected package libknot14t64. 398s Preparing to unpack .../07-libknot14t64_3.3.4-1.1build2_arm64.deb ... 398s Unpacking libknot14t64 (3.3.4-1.1build2) ... 398s Selecting previously unselected package libzscanner4t64. 398s Preparing to unpack .../08-libzscanner4t64_3.3.4-1.1build2_arm64.deb ... 398s Unpacking libzscanner4t64 (3.3.4-1.1build2) ... 398s Selecting previously unselected package libfstrm0:arm64. 398s Preparing to unpack .../09-libfstrm0_0.6.1-1build4_arm64.deb ... 398s Unpacking libfstrm0:arm64 (0.6.1-1build4) ... 398s Selecting previously unselected package knot-dnsutils. 398s Preparing to unpack .../10-knot-dnsutils_3.3.4-1.1build2_arm64.deb ... 398s Unpacking knot-dnsutils (3.3.4-1.1build2) ... 398s Selecting previously unselected package lua-socket:arm64. 398s Preparing to unpack .../11-lua-socket_3.1.0-1_arm64.deb ... 398s Unpacking lua-socket:arm64 (3.1.0-1) ... 398s Selecting previously unselected package lua-sec:arm64. 398s Preparing to unpack .../12-lua-sec_1.3.2-1build2_arm64.deb ... 398s Unpacking lua-sec:arm64 (1.3.2-1build2) ... 398s Selecting previously unselected package libjemalloc2:arm64. 398s Preparing to unpack .../13-libjemalloc2_5.3.0-2build1_arm64.deb ... 398s Unpacking libjemalloc2:arm64 (5.3.0-2build1) ... 398s Selecting previously unselected package libluajit-5.1-common. 398s Preparing to unpack .../14-libluajit-5.1-common_2.1.0+git20231223.c525bcb+dfsg-1_all.deb ... 398s Unpacking libluajit-5.1-common (2.1.0+git20231223.c525bcb+dfsg-1) ... 398s Selecting previously unselected package libluajit-5.1-2:arm64. 398s Preparing to unpack .../15-libluajit-5.1-2_2.1.0+git20231223.c525bcb+dfsg-1_arm64.deb ... 398s Unpacking libluajit-5.1-2:arm64 (2.1.0+git20231223.c525bcb+dfsg-1) ... 398s Selecting previously unselected package knot-resolver. 398s Preparing to unpack .../16-knot-resolver_5.7.2-1_arm64.deb ... 398s Unpacking knot-resolver (5.7.2-1) ... 398s Selecting previously unselected package socat. 398s Preparing to unpack .../17-socat_1.8.0.0-4build3_arm64.deb ... 398s Unpacking socat (1.8.0.0-4build3) ... 398s Selecting previously unselected package autopkgtest-satdep. 398s Preparing to unpack .../18-1-autopkgtest-satdep.deb ... 398s Unpacking autopkgtest-satdep (0) ... 398s Setting up libzscanner4t64 (3.3.4-1.1build2) ... 398s Setting up libfstrm0:arm64 (0.6.1-1build4) ... 398s Setting up libevent-2.1-7t64:arm64 (2.1.12-stable-9ubuntu2) ... 398s Setting up lua-socket:arm64 (3.1.0-1) ... 398s Setting up libjemalloc2:arm64 (5.3.0-2build1) ... 398s Setting up dns-root-data (2023112702~willsync1) ... 398s Setting up libxdp1:arm64 (1.4.2-1ubuntu4) ... 398s Setting up libunbound8:arm64 (1.19.2-1ubuntu3) ... 398s Setting up libgnutls-dane0t64:arm64 (3.8.3-1.1ubuntu3) ... 398s Setting up socat (1.8.0.0-4build3) ... 398s Setting up libdnssec9t64 (3.3.4-1.1build2) ... 398s Setting up libluajit-5.1-common (2.1.0+git20231223.c525bcb+dfsg-1) ... 398s Setting up libknot14t64 (3.3.4-1.1build2) ... 398s Setting up gnutls-bin (3.8.3-1.1ubuntu3) ... 398s Setting up lua-sec:arm64 (1.3.2-1build2) ... 398s Setting up knot-dnsutils (3.3.4-1.1build2) ... 398s Setting up libluajit-5.1-2:arm64 (2.1.0+git20231223.c525bcb+dfsg-1) ... 398s Setting up knot-resolver (5.7.2-1) ... 399s Created symlink /etc/systemd/system/kresd.target.wants/kres-cache-gc.service → /usr/lib/systemd/system/kres-cache-gc.service. 399s Created symlink /etc/systemd/system/multi-user.target.wants/kresd.target → /usr/lib/systemd/system/kresd.target. 399s Setting up autopkgtest-satdep (0) ... 399s Processing triggers for man-db (2.12.0-4build2) ... 400s Processing triggers for libc-bin (2.39-0ubuntu8) ... 403s (Reading database ... 78167 files and directories currently installed.) 403s Removing autopkgtest-satdep (0) ... 404s autopkgtest [18:14:42]: test roundtrip: [----------------------- 404s /usr/sbin/kresd + /usr/bin/kdig roundtrip tests 404s ------------ 404s workdir: /tmp/autopkgtest.2zJl3s/roundtrip-artifacts 404s IP addr: 127.160.229.20 404s kresd args: --addr=127.160.229.20@8053 --tls=127.160.229.20@8853 --noninteractive --config=/tmp/autopkgtest.2zJl3s/roundtrip-artifacts/kresd.conf --verbose --verbose --verbose 404s 404s make Certificate Authority key and certificate 404s ---------------------------------------------- 404s Generating a 3072 bit RSA private key... 404s Generating a self signed certificate... 404s X.509 Certificate Information: 404s Version: 3 404s Serial Number (hex): 55a107fa5ed74af105e2cd7757f8c6e9538348eb 404s Validity: 404s Not Before: Fri Apr 19 18:14:42 UTC 2024 404s Not After: Wed May 01 18:14:42 UTC 2024 404s Subject: CN=testing certificate authority (NOT FOR PRODUCTION) 404s Subject Public Key Algorithm: RSA 404s Algorithm Security Level: High (3072 bits) 404s Modulus (bits 3072): 404s 00:c1:64:00:6a:5a:ba:50:6c:a0:03:60:4d:92:81:a9 404s 9b:d7:4e:5c:ab:74:d1:2d:c3:1d:c4:0c:fd:80:81:07 404s ff:40:cb:69:03:f9:dd:1e:e3:16:e9:03:b4:d4:45:dc 404s fb:56:51:e1:1c:fe:b1:77:02:de:aa:e3:c3:d9:d9:e2 404s 65:6e:14:41:70:1f:ba:ce:f5:ce:69:b8:68:8d:6d:d3 404s 89:bf:48:fd:b5:cf:54:c9:48:d6:80:81:56:e1:3d:f3 404s 7c:5f:17:d2:ef:99:79:0e:3f:d7:0e:93:ac:9e:de:79 404s a5:42:8e:55:c3:99:be:05:91:a2:fd:c3:34:b2:24:0a 404s 76:71:e8:65:18:b2:f7:b0:e1:9a:0a:57:c1:55:21:0c 404s 8f:ed:fa:e5:ff:61:ed:1e:3e:cb:a7:13:5f:1d:85:7c 404s d9:53:5e:e9:03:35:71:fb:89:3c:d5:fb:ba:4a:a1:56 404s 1f:bf:b2:c7:a1:00:f8:29:8f:62:f5:63:8b:04:02:c6 404s 49:2d:c7:38:00:b0:0a:39:d6:2a:e4:13:ea:fd:d9:f4 404s 30:21:91:ee:be:ff:37:ec:38:92:f1:5b:3d:f4:76:7d 404s ce:5a:31:41:88:5b:f3:f4:ef:f4:a8:a5:9c:6d:9c:72 404s af:fb:3f:66:c8:16:d4:61:e7:9d:86:03:f9:1c:e3:c2 404s 79:8e:1a:90:15:3f:0a:ef:39:56:d1:91:21:c7:48:d8 404s 16:11:ad:17:f9:23:5d:a6:f4:08:25:cc:0f:32:4f:4e 404s c8:03:03:82:86:2c:8f:43:8c:49:b5:2f:15:e0:65:16 404s b6:53:a4:4b:a6:09:97:04:60:75:10:f6:54:3e:69:41 404s 90:d4:8c:a6:6d:ad:de:fd:54:2c:2a:09:34:1d:dc:c1 404s d1:10:68:99:cf:46:8f:5d:b8:b5:b8:05:5b:07:c5:19 404s 5b:ab:8d:e5:93:6c:f8:73:d1:6a:cf:2b:ee:67:07:23 404s 36:d6:5b:f2:0f:c6:91:df:7c:4d:ed:53:18:75:9d:fe 404s ad 404s Exponent (bits 24): 404s 01:00:01 404s Extensions: 404s Basic Constraints (critical): 404s Certificate Authority (CA): TRUE 404s Path Length Constraint: 1 404s Name Constraints (critical): 404s Permitted: 404s DNSname: example 404s Key Usage (critical): 404s Certificate signing. 404s Subject Key Identifier (not critical): 404s cdb9fa5c7382822e062295e69cfc6ba1ecdc7a8d 404s Other Information: 404s Public Key ID: 404s sha1:cdb9fa5c7382822e062295e69cfc6ba1ecdc7a8d 404s sha256:7fbcc61970878b33864de3d32687018bdbc01e9eb2b4bb30592420f6243caa75 404s Public Key PIN: 404s pin-sha256:f7zGGXCHizOGTePTJocBi9vAHp6ytLswWSQg9iQ8qnU= 404s 404s 404s 404s Signing certificate... 404s 404s make Bogus Certificate Authority key and certificate 404s ---------------------------------------------------- 406s Generating a 3072 bit RSA private key... 406s Generating a self signed certificate... 406s X.509 Certificate Information: 406s Version: 3 406s Serial Number (hex): 2ad006fd47a59a7cdeacc5cab3f39e49135d2ee1 406s Validity: 406s Not Before: Fri Apr 19 18:14:44 UTC 2024 406s Not After: Wed May 01 18:14:44 UTC 2024 406s Subject: CN=testing certificate authority (NOT FOR PRODUCTION) 406s Subject Public Key Algorithm: RSA 406s Algorithm Security Level: High (3072 bits) 406s Modulus (bits 3072): 406s 00:ac:7a:eb:cb:2a:0a:d1:25:56:49:6c:b8:e0:b0:d0 406s 3d:2f:1b:e5:4f:b6:1e:02:38:44:0f:2f:23:4f:b5:98 406s 57:d8:f5:85:ee:ce:eb:f7:4d:33:43:11:68:80:95:a2 406s d2:ae:60:0c:5f:bd:7a:aa:1c:2b:2d:35:da:5a:31:50 406s 78:02:d0:bd:26:06:00:f4:d1:64:6e:97:e0:99:63:29 406s 5d:e9:23:de:0a:74:79:50:52:4d:16:d0:af:05:9f:11 406s ea:04:37:7a:51:19:05:df:8f:f7:a3:9d:5f:38:9d:5b 406s 08:af:f6:da:8d:c3:b2:e0:6f:07:97:cb:e3:d1:ed:db 406s 9e:5a:27:e0:9e:dd:ae:71:e8:3c:48:06:a8:dd:65:87 406s ee:f2:fe:a6:43:7d:42:2a:dd:00:8d:9d:12:bf:e1:e8 406s 86:23:b0:ed:f1:c7:f5:8c:27:87:36:b1:d8:28:52:a6 406s 6a:8b:5e:6f:77:c9:1c:f5:94:79:a2:b2:68:c7:a6:62 406s 8f:12:d3:65:7b:59:ac:ad:eb:61:92:bb:23:9d:61:9f 406s 32:d4:63:1d:35:fe:2c:75:ed:84:f6:28:b8:b6:27:a0 406s d1:b3:81:d8:48:61:c7:64:f0:dc:51:36:d8:52:66:8a 406s 27:30:17:c4:4a:ba:03:f0:0d:ab:27:32:48:3c:53:ff 406s 62:10:9b:ea:7c:a2:80:78:46:cc:04:dd:40:f0:8a:ea 406s 2c:6c:c3:b9:3d:92:22:06:bf:cf:43:68:bb:8a:ad:78 406s 1b:d4:26:06:4e:de:29:31:de:83:56:29:8f:e0:5f:cb 406s 29:a8:18:05:0b:b4:a3:59:7b:05:18:93:1e:f0:9d:57 406s 99:6d:5f:16:80:2a:ec:67:9e:c0:8e:49:dd:1e:40:de 406s 9d:71:07:be:e2:03:fe:76:bf:33:fe:d6:8d:d8:ec:ca 406s 7c:94:2f:70:4b:f0:0b:f1:ea:c4:9d:46:06:55:fe:c0 406s 8b:7e:fb:af:c4:38:6d:23:7e:4c:fa:42:a7:60:36:50 406s 79 406s Exponent (bits 24): 406s 01:00:01 406s Extensions: 406s Basic Constraints (critical): 406s Certificate Authority (CA): TRUE 406s Path Length Constraint: 1 406s Name Constraints (critical): 406s Permitted: 406s DNSname: example 406s Key Usage (critical): 406s Certificate signing. 406s Subject Key Identifier (not critical): 406s 773bf85f35cb0022b1557e2df6f9cb9cb70ce131 406s Other Information: 406s Public Key ID: 406s sha1:773bf85f35cb0022b1557e2df6f9cb9cb70ce131 406s sha256:ab69b56d1f774a2e3b9cc0aeb532ca9dec77a642ba3c3a9384d0dc3b06427d7f 406s Public Key PIN: 406s pin-sha256:q2m1bR93Si47nMCutTLKnex3pkK6PDqThNDcOwZCfX8= 406s 406s 406s 406s Signing certificate... 406s 406s make End Entity key and certificate 406s ----------------------------------- 406s Generating a 3072 bit RSA private key... 406s Generating a signed certificate... 406s X.509 Certificate Information: 406s Version: 3 406s Serial Number (hex): 2b4878a6e4ed95bf73d9ad3291556cc641b530db 406s Validity: 406s Not Before: Fri Apr 19 18:14:44 UTC 2024 406s Not After: Mon Apr 29 18:14:44 UTC 2024 406s Subject: CN=test.example 406s Subject Public Key Algorithm: RSA 406s Algorithm Security Level: High (3072 bits) 406s Modulus (bits 3072): 406s 00:bc:86:f4:9c:55:11:72:a2:f4:60:c5:90:cd:d2:73 406s 05:b5:9b:2b:43:6a:b6:f4:90:59:02:5d:bd:92:30:75 406s 32:c1:74:6e:d3:ba:80:3d:63:83:22:e3:70:43:31:13 406s aa:28:12:36:da:14:f7:12:c8:a5:38:7e:52:27:6c:bc 406s 98:8f:fe:40:24:ec:fc:01:10:fb:3b:72:87:85:18:1b 406s e5:7f:53:76:e8:dc:8c:7b:13:b9:33:a0:7a:14:77:6f 406s 81:cc:da:9e:8f:9b:35:1e:8e:cd:0a:13:e0:84:37:36 406s 9d:f1:38:24:a8:86:1e:05:a9:d9:7b:f2:e4:e1:fd:51 406s 94:0f:3c:08:06:1f:0e:25:21:6a:a1:6d:d8:3c:0d:54 406s 3f:15:fd:4d:5e:66:ea:a2:62:29:50:3b:70:9f:46:96 406s 72:ce:ad:6b:b8:65:65:18:9f:b4:a9:2c:a3:49:f9:8a 406s df:90:5e:97:0d:47:4f:b0:3d:40:3b:88:7a:c8:40:58 406s de:95:a3:3b:bd:27:ba:8b:e3:6a:39:e9:4b:a7:60:17 406s bb:6d:2c:ef:19:cb:04:96:b9:bd:94:62:d1:1a:09:33 406s 35:8d:a7:5e:26:a1:fd:52:ca:fb:30:be:ef:49:03:3e 406s 5d:eb:3b:2d:b0:95:32:6e:9f:81:fe:71:30:e8:1f:fe 406s 95:49:4c:e6:82:05:2e:1f:43:ca:1b:ac:80:90:33:67 406s 6e:f5:71:d6:97:c2:cf:45:47:44:e1:c5:5b:f9:0b:81 406s 60:3a:ca:c8:ee:f7:72:dc:51:fd:fa:f5:c0:33:4a:f3 406s a9:5d:90:0f:5d:b2:cc:b1:09:11:ed:24:10:96:38:ba 406s 05:ae:2e:42:0a:e8:03:fe:c8:b8:10:a5:2e:53:3c:27 406s 37:89:db:1a:1f:8b:2e:46:a4:ec:44:01:6a:1d:94:49 406s db:cd:af:a7:04:70:80:12:d1:51:c4:a1:13:95:c3:2c 406s 85:83:c2:f4:32:4d:23:7e:23:7e:89:ca:36:e3:f0:45 406s 6b 406s Exponent (bits 24): 406s 01:00:01 406s Extensions: 406s Basic Constraints (critical): 406s Certificate Authority (CA): FALSE 406s Subject Alternative Name (not critical): 406s DNSname: test.example 406s Key Purpose (not critical): 406s TLS WWW Server. 406s Key Usage (critical): 406s Digital signature. 406s Subject Key Identifier (not critical): 406s e7b2ddd336c7c742d546bb56cc3b02973a07ad92 406s Authority Key Identifier (not critical): 406s cdb9fa5c7382822e062295e69cfc6ba1ecdc7a8d 406s Other Information: 406s Public Key ID: 406s sha1:e7b2ddd336c7c742d546bb56cc3b02973a07ad92 406s sha256:366429bf76543bb00c5400101c7ef03cecbe3ed0969f0cf3c6122eec4007b72d 406s Public Key PIN: 406s pin-sha256:NmQpv3ZUO7AMVAAQHH7wPOy+PtCWnwzzxhIu7EAHty0= 406s 406s 406s 406s Signing certificate... 406s 406s set up kresd daemon on 127.160.229.20 on ports 8053 (UDP, TCP) and 8853 (TLS) 406s ----------------------------------------------------------------------------- 407s 407s test UDP with kdig 407s ------------------ 407s successful UDP request to 127.160.229.20 on port 8053 407s 407s test TCP with kdig 407s ------------------ 407s successful TCP request to 127.160.229.20 on port 8053 407s 407s test opportunistic DNS-over-TLS with kdig 407s ----------------------------------------- 407s successful opportunistic DNS-over-TLS request to 127.160.229.20 on port 8853 407s 407s test strict DNS-over-TLS with kdig 407s ---------------------------------- 407s successful strict DNS-over-TLS request to 127.160.229.20 on port 8853 407s 407s test invalid name with strict DNS-over-TLS with kdig 407s ---------------------------------------------------- 407s successful strict DNS-over-TLS request failure when name mismatch to 127.160.229.20 on port 8853 407s 407s test bad authority with strict DNS-over-TLS with kdig 407s ----------------------------------------------------- 407s successful strict DNS-over-TLS request failure to 127.160.229.20 on port 8853 407s 407s cleaning up 407s ----------- 407s 264155 4 drwxrwxrwt 2 root root 4096 Apr 19 18:14 /tmp/autopkgtest.2zJl3s/roundtrip-artifacts 407s 264162 4 -rw-r--r-- 1 root root 136 Apr 19 18:14 /tmp/autopkgtest.2zJl3s/roundtrip-artifacts/ca.template 407s 264169 4 -rw-r--r-- 1 root root 2218 Apr 19 18:14 /tmp/autopkgtest.2zJl3s/roundtrip-artifacts/ee-pubkey.pem 407s 264167 4 -rw-r--r-- 1 root root 92 Apr 19 18:14 /tmp/autopkgtest.2zJl3s/roundtrip-artifacts/ee.template 407s 264165 8 -rw------- 1 root root 8170 Apr 19 18:14 /tmp/autopkgtest.2zJl3s/roundtrip-artifacts/bogus-key.pem 407s 264518 4 -rw-r--r-- 1 root root 120 Apr 19 18:14 /tmp/autopkgtest.2zJl3s/roundtrip-artifacts/badca.err 407s 264164 4 -rw-r--r-- 1 root root 1590 Apr 19 18:14 /tmp/autopkgtest.2zJl3s/roundtrip-artifacts/ca-cert.pem 407s 264166 4 -rw-r--r-- 1 root root 1590 Apr 19 18:14 /tmp/autopkgtest.2zJl3s/roundtrip-artifacts/bogus-cert.pem 407s 264517 4 -rw-r--r-- 1 root root 120 Apr 19 18:14 /tmp/autopkgtest.2zJl3s/roundtrip-artifacts/badname.err 407s 264513 4 -rw-r--r-- 1 root root 387 Apr 19 18:14 /tmp/autopkgtest.2zJl3s/roundtrip-artifacts/kresd.conf 407s 264163 8 -rw------- 1 root root 8177 Apr 19 18:14 /tmp/autopkgtest.2zJl3s/roundtrip-artifacts/ca-key.pem 407s 264514 72 -rw-r--r-- 1 root root 72751 Apr 19 18:14 /tmp/autopkgtest.2zJl3s/roundtrip-artifacts/kresd.err 407s 264413 4 -rw-r--r-- 1 root root 1602 Apr 19 18:14 /tmp/autopkgtest.2zJl3s/roundtrip-artifacts/ee-cert.pem 407s 264515 4 -rw-r----- 1 root root 8256 Apr 19 18:14 /tmp/autopkgtest.2zJl3s/roundtrip-artifacts/lock.mdb 407s 264168 8 -rw------- 1 root root 8170 Apr 19 18:14 /tmp/autopkgtest.2zJl3s/roundtrip-artifacts/ee-key.pem 407s 264516 102400 -rw-r----- 1 root root 104857600 Apr 19 18:14 /tmp/autopkgtest.2zJl3s/roundtrip-artifacts/data.mdb 407s ==> /tmp/autopkgtest.2zJl3s/roundtrip-artifacts/badca.err <== 407s ;; WARNING: TLS, handshake failed (Error in the certificate.) 407s ;; ERROR: failed to query server 127.160.229.20@8853(TCP) 407s 407s ==> /tmp/autopkgtest.2zJl3s/roundtrip-artifacts/badname.err <== 407s ;; WARNING: TLS, handshake failed (Error in the certificate.) 407s ;; ERROR: failed to query server 127.160.229.20@8853(TCP) 407s 407s ==> /tmp/autopkgtest.2zJl3s/roundtrip-artifacts/kresd.err <== 407s [system] increasing file-descriptor limit: 1024 -> 1048576 407s [tls ] session ticket: epoch 418347, scheduling rotation check in 2923468 ms 407s [wtchdg] disabled in systemd (WatchdogSec= not specified) 407s [ta ] installed trust anchors for domain . are: 407s . 86400 DNSKEY 257 3 8 AwEAAaz/tAm8yTn4Mfeh5eyI96WSVexTBAvkMgJzkKTOiW1vkIbzxeF3+/4RgWOq7HrxRixHlFlExOLAJr5emLvN7SWXgnLh4+B5xQlNVz8Og8kvArMtNROxVQuCaSnIDdD5LKyWbRd2n9WGe2R8PzgCmr3EgVLrjyBxWezF0jLHwVN8efS3rCj/EWgvIWgb9tarpVUDK/b58Da+sqqls3eNbuv7pr+eoZG+SrDK6nWeL3c6H5Apxz7LjVc1uTIdsIXxuOLYA4/ilBmSVIzuDWfdRUfhHdY6+cn8HFRm+2hM8AnXGXws9555KrUB5qihylGa8subX2Nn6UwNR1AkUTV74bU= ; Valid: ; KeyTag:20326 407s 407s [system] loading config '/tmp/autopkgtest.2zJl3s/roundtrip-artifacts/kresd.conf' (workdir '/tmp/autopkgtest.2zJl3s/roundtrip-artifacts') 407s [system] deprecation WARNING: use log_level() instead of verbose() 407s [gnutls] (3) ASSERT: ../../../lib/x509/dn.c[_gnutls_x509_compare_raw_dn]:974 407s [gnutls] (3) ASSERT: ../../../lib/x509/dn.c[_gnutls_x509_compare_raw_dn]:974 407s [gnutls] (3) ASSERT: ../../../lib/x509/x509_ext.c[gnutls_subject_alt_names_get]:111 407s [gnutls] (3) ASSERT: ../../../lib/x509/x509.c[get_alt_name]:2011 407s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 407s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 407s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 407s [tls ] RFC 7858 OOB key-pin (0): pin-sha256="" 407s [gnutls] (3) ASSERT: ../../lib/cert-cred-x509.c[gnutls_certificate_get_x509_crt]:872 407s [system] loading config '/usr/lib/aarch64-linux-gnu/knot-resolver/postconfig.lua' (workdir '/tmp/autopkgtest.2zJl3s/roundtrip-artifacts') 407s [plan ][00000.00] plan '.' type 'NS' uid [65536.00] 407s [iterat][65536.00] '.' type 'NS' new uid was assigned .01, parent uid .00 407s [resolv][65536.01] => using root hints 407s [iterat][65536.01] '.' type 'NS' new uid was assigned .02, parent uid .00 407s [resolv][65536.02] >< TA: '.' 407s [plan ][65536.02] plan '.' type 'DNSKEY' uid [65536.03] 407s [iterat][65536.03] '.' type 'DNSKEY' new uid was assigned .04, parent uid .02 407s [select][65536.04] => id: '29917' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 407s [select][65536.04] => id: '29917' choosing: 'B.ROOT-SERVERS.NET.'@'170.247.170.2#00053' with timeout 400 ms zone cut: '.' 407s [resolv][65536.04] => id: '29917' querying: 'B.ROOT-SERVERS.NET.'@'170.247.170.2#00053' zone cut: '.' qname: '.' qtype: 'DNSKEY' proto: 'udp' 407s [plan ][00000.00] plan '.' type 'NS' uid [65537.00] 407s [iterat][65537.00] '.' type 'NS' new uid was assigned .01, parent uid .00 407s [resolv][65537.01] => using root hints 407s [iterat][65537.01] '.' type 'NS' new uid was assigned .02, parent uid .00 407s [select][65537.02] => id: '58017' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 407s [select][65537.02] => id: '58017' choosing: 'K.ROOT-SERVERS.NET.'@'193.0.14.129#00053' with timeout 400 ms zone cut: '.' 407s [resolv][65537.02] => id: '58017' querying: 'K.ROOT-SERVERS.NET.'@'193.0.14.129#00053' zone cut: '.' qname: '.' qtype: 'NS' proto: 'udp' 407s [taupd ] refreshing TA for . 407s [plan ][00000.00] plan '.' type 'DNSKEY' uid [65538.00] 407s [iterat][65538.00] '.' type 'DNSKEY' new uid was assigned .01, parent uid .00 407s [resolv][65538.01] => using root hints 407s [iterat][65538.01] '.' type 'DNSKEY' new uid was assigned .02, parent uid .00 407s [resolv][65538.02] >< TA: '.' 407s [select][65538.02] => id: '26910' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 407s [select][65538.02] => id: '26910' choosing: 'E.ROOT-SERVERS.NET.'@'2001:500:a8::e#00053' with timeout 400 ms zone cut: '.' 407s [select][65536.04] => id: '29917' noting selection error: 'B.ROOT-SERVERS.NET.'@'170.247.170.2#00053' zone cut: '.' error: 1 QUERY_TIMEOUT 407s [iterat][65538.02] '.' type 'DNSKEY' new uid was assigned .03, parent uid .00 407s [select][65538.03] => id: '38118' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 407s [select][65538.03] => id: '38118' choosing: 'E.ROOT-SERVERS.NET.'@'2001:500:a8::e#00053' with timeout 400 ms zone cut: '.' 407s [resolv][65538.03] => id: '38118' querying: 'E.ROOT-SERVERS.NET.'@'2001:500:a8::e#00053' zone cut: '.' qname: '.' qtype: 'DNSKEY' proto: 'udp' 407s [iterat][65536.04] '.' type 'DNSKEY' new uid was assigned .05, parent uid .02 407s [select][65536.05] => id: '42184' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 407s [select][65536.05] => id: '42184' choosing: 'K.ROOT-SERVERS.NET.'@'2001:7fd::1#00053' with timeout 800 ms zone cut: '.' 407s [select][65537.02] => id: '58017' noting selection error: 'K.ROOT-SERVERS.NET.'@'193.0.14.129#00053' zone cut: '.' error: 1 QUERY_TIMEOUT 407s [iterat][65537.02] '.' type 'NS' new uid was assigned .03, parent uid .00 407s [select][65537.03] => id: '41439' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 407s [select][65537.03] => id: '41439' choosing: 'F.ROOT-SERVERS.NET.'@'192.5.5.241#00053' with timeout 800 ms zone cut: '.' 407s [resolv][65537.03] => id: '41439' querying: 'F.ROOT-SERVERS.NET.'@'192.5.5.241#00053' zone cut: '.' qname: '.' qtype: 'NS' proto: 'udp' 407s [select][65538.03] NO6: timed out, appended, timeouts 1/6 407s [select][65538.03] => id: '38118' noting selection error: 'E.ROOT-SERVERS.NET.'@'2001:500:a8::e#00053' zone cut: '.' error: 1 QUERY_TIMEOUT 407s [iterat][65536.05] '.' type 'DNSKEY' new uid was assigned .06, parent uid .02 407s [select][65536.06] => id: '07933' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 407s [select][65536.06] => id: '07933' choosing: 'D.ROOT-SERVERS.NET.'@'2001:500:2d::d#00053' with timeout 800 ms zone cut: '.' 407s [resolv][65536.06] => id: '07933' querying: 'D.ROOT-SERVERS.NET.'@'2001:500:2d::d#00053' zone cut: '.' qname: '.' qtype: 'DNSKEY' proto: 'udp' 407s [iterat][65538.03] '.' type 'DNSKEY' new uid was assigned .04, parent uid .00 407s [select][65538.04] => id: '26361' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 407s [select][65538.04] => id: '26361' choosing: 'C.ROOT-SERVERS.NET.'@'2001:500:2::c#00053' with timeout 800 ms zone cut: '.' 407s [plan ][00000.00] plan 'monkeys.example.' type 'A' uid [57191.00] 407s [iterat][57191.00] 'monkeys.example.' type 'A' new uid was assigned .01, parent uid .00 407s [hint ][57191.01] <= answered from hints 407s [iterat][57191.01] <= rcode: NOERROR 407s [resolv][57191.01] AD: request NOT classified as SECURE 407s [resolv][57191.01] finished in state: 4, queries: 1, mempool: 16400 B 407s [plan ][00000.00] plan 'monkeys.example.' type 'A' uid [61097.00] 407s [iterat][61097.00] 'monkeys.example.' type 'A' new uid was assigned .01, parent uid .00 407s [hint ][61097.01] <= answered from hints 407s [iterat][61097.01] <= rcode: NOERROR 407s [resolv][61097.01] AD: request NOT classified as SECURE 407s [resolv][61097.01] finished in state: 4, queries: 1, mempool: 81952 B 407s [io ] => connection to '127.0.0.1#35367' closed by peer (end of file) 407s [gnutls] (5) REC[0xeb94f6660000]: Allocating epoch #0 407s [gnutls] (2) added 3 protocols, 29 ciphersuites, 19 sig algos and 10 groups into priority list 407s [gnutls] (5) REC[0xeb94f6660000]: Allocating epoch #1 407s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 407s [gnutls] (5) REC[0xeb94f6660000]: SSL 3.3 Handshake packet received. Epoch 0, length: 374 407s [gnutls] (5) REC[0xeb94f6660000]: Expected Packet Handshake(22) 407s [gnutls] (5) REC[0xeb94f6660000]: Received Packet Handshake(22) with length: 374 407s [gnutls] (5) REC[0xeb94f6660000]: Decrypted Packet[0] Handshake(22) with length: 374 407s [gnutls] (4) HSK[0xeb94f6660000]: CLIENT HELLO (1) was received. Length 370[370], frag offset 0, frag length: 370, sequence: 0 407s [gnutls] (4) HSK[0xeb94f6660000]: Client's version: 3.3 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Supported Versions/43' (5 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Found version: 3.4 407s [gnutls] (4) EXT[0xeb94f6660000]: Found version: 3.3 407s [gnutls] (4) EXT[0xeb94f6660000]: Negotiated version: 3.4 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Record Size Limit/28' (2 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: record_size_limit 16385 negotiated 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Extended Master Secret/23' (0 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Safe Renegotiation/65281' (1 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'ALPN/16' (6 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Encrypt-then-MAC/22' (0 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'PSK Key Exchange Modes/45' (3 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: PSK KE mode 01 received 407s [gnutls] (4) EXT[0xeb94f6660000]: PSK KE mode 00 received 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Session Ticket/35' (0 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Signature Algorithms/13' (34 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (4.1) RSA-SHA256 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.9) RSA-PSS-SHA256 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.4) RSA-PSS-RSAE-SHA256 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (4.3) ECDSA-SECP256R1-SHA256 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.7) EdDSA-Ed25519 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (5.1) RSA-SHA384 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.10) RSA-PSS-SHA384 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.5) RSA-PSS-RSAE-SHA384 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (5.3) ECDSA-SECP384R1-SHA384 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.8) EdDSA-Ed448 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (6.1) RSA-SHA512 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.11) RSA-PSS-SHA512 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.6) RSA-PSS-RSAE-SHA512 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (6.3) ECDSA-SECP521R1-SHA512 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (2.1) RSA-SHA1 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (2.3) ECDSA-SHA1 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Supported EC Point Formats/11' (2 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Supported Groups/10' (22 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Received group SECP256R1 (0x17) 407s [gnutls] (4) EXT[0xeb94f6660000]: Received group SECP384R1 (0x18) 407s [gnutls] (4) EXT[0xeb94f6660000]: Received group SECP521R1 (0x19) 407s [gnutls] (4) EXT[0xeb94f6660000]: Received group X25519 (0x1d) 407s [gnutls] (4) EXT[0xeb94f6660000]: Received group X448 (0x1e) 407s [gnutls] (4) EXT[0xeb94f6660000]: Received group FFDHE2048 (0x100) 407s [gnutls] (4) EXT[0xeb94f6660000]: Received group FFDHE3072 (0x101) 407s [gnutls] (4) EXT[0xeb94f6660000]: Received group FFDHE4096 (0x102) 407s [gnutls] (4) EXT[0xeb94f6660000]: Received group FFDHE6144 (0x103) 407s [gnutls] (4) EXT[0xeb94f6660000]: Received group FFDHE8192 (0x104) 407s [gnutls] (4) EXT[0xeb94f6660000]: Selected group SECP256R1 407s [gnutls] (2) checking 13.02 (GNUTLS_AES_256_GCM_SHA384) for compatibility 407s [gnutls] (3) ASSERT: ../../../lib/ext/server_name.c[gnutls_server_name_get]:234 407s [gnutls] (4) HSK[0xeb94f6660000]: Requested server name: '' 407s [gnutls] (4) HSK[0xeb94f6660000]: checking compat of GNUTLS_AES_256_GCM_SHA384 with certificate[0] (RSA/X.509) 407s [gnutls] (4) checking cert compat with RSA-SHA256 407s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 407s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 407s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 407s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 407s [gnutls] (4) Selected signature algorithm: RSA-PSS-RSAE-SHA256 407s [gnutls] (2) Selected (RSA) cert based on ciphersuite 13.2: GNUTLS_AES_256_GCM_SHA384 407s [gnutls] (4) HSK[0xeb94f6660000]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384 407s [gnutls] (4) HSK[0xeb94f6660000]: Selected version TLS1.3 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'OCSP Status Request/5' (5 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: OCSP status was requested 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Key Share/51' (107 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Received key share for SECP256R1 407s [gnutls] (4) HSK[0xeb94f6660000]: Selected group SECP256R1 (2) 407s [gnutls] (2) EXT[0xeb94f6660000]: server generated SECP256R1 shared key 407s [gnutls] (4) HSK[0xeb94f6660000]: Safe renegotiation succeeded 407s [gnutls] (4) HSK[0xeb94f6660000]: SessionID: d033465b085be22b1c7a097f2b4b92f26b37ba9c7d12eef3ab90e448658dbe25 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Supported Groups/10) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Maximum Record Size/1) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Cookie/44) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (ALPN/16) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Post Handshake Auth/49) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (PSK Key Exchange Modes/45) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Session Ticket/35) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Record Size Limit/28) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Compress Certificate/27) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Safe Renegotiation/65281) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Encrypt-then-MAC/22) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Client Certificate Type/19) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Extended Master Secret/23) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (SRTP/14) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Supported Versions/43) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Sending extension Supported Versions/43 (2 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Key Share/51) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: sending key share for SECP256R1 407s [gnutls] (4) EXT[0xeb94f6660000]: Sending extension Key Share/51 (69 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Server Certificate Type/20) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Signature Algorithms/13) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Supported EC Point Formats/11) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (OCSP Status Request/5) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Early Data/42) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Server Name Indication/0) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (ClientHello Padding/21) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Pre Shared Key/41) for 'TLS 1.3 server hello' 407s [gnutls] (4) HSK[0xeb94f6660000]: SERVER HELLO was queued [155 bytes] 407s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 155 and min pad: 0 407s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 160 407s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0 407s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6 407s [gnutls] (4) REC[0xeb94f6660000]: Sent ChangeCipherSpec 407s [gnutls] (5) REC[0xeb94f6660000]: Initializing epoch #1 407s [gnutls] (5) REC[0xeb94f6660000]: Epoch #1 ready 407s [gnutls] (4) HSK[0xeb94f6660000]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (ALPN/16) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Sending extension ALPN/16 (6 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Maximum Record Size/1) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Supported EC Point Formats/11) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Supported Groups/10) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Extended Master Secret/23) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Early Data/42) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Server Name Indication/0) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Supported Versions/43) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Server Certificate Type/20) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (SRTP/14) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Key Share/51) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Record Size Limit/28) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Sending extension Record Size Limit/28 (2 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Cookie/44) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (OCSP Status Request/5) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Post Handshake Auth/49) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Session Ticket/35) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Encrypt-then-MAC/22) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (PSK Key Exchange Modes/45) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Signature Algorithms/13) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Client Certificate Type/19) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Safe Renegotiation/65281) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Compress Certificate/27) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (ClientHello Padding/21) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Pre Shared Key/41) for 'encrypted extensions' 407s [gnutls] (4) HSK[0xeb94f6660000]: ENCRYPTED EXTENSIONS was queued [22 bytes] 407s [gnutls] (4) HSK[0xeb94f6660000]: CERTIFICATE was queued [1155 bytes] 407s [gnutls] (4) checking cert compat with RSA-SHA256 407s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 407s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 407s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 407s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 407s [gnutls] (4) HSK[0xeb94f6660000]: signing TLS 1.3 handshake data: using RSA-PSS-RSAE-SHA256 and PRF: SHA384 407s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 407s [gnutls] (4) HSK[0xeb94f6660000]: CERTIFICATE VERIFY was queued [392 bytes] 407s [gnutls] (4) HSK[0xeb94f6660000]: sending finished 407s [gnutls] (4) HSK[0xeb94f6660000]: FINISHED was queued [52 bytes] 407s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 22 and min pad: 0 407s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 44 407s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 1155 and min pad: 0 407s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[2] Handshake(22) in epoch 1 and length: 1177 407s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 392 and min pad: 0 407s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[3] Handshake(22) in epoch 1 and length: 414 407s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 52 and min pad: 0 407s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[4] Handshake(22) in epoch 1 and length: 74 407s [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:965 407s [gnutls] (5) REC[0xeb94f6660000]: Allocating epoch #2 407s [gnutls] (4) HSK[0xeb94f6660000]: unauthenticated session eligible for early start 407s [gnutls] (5) REC[0xeb94f6660000]: Initializing epoch #2 407s [gnutls] (5) REC[0xeb94f6660000]: Epoch #2 ready 407s [gnutls] (4) HSK[0xeb94f6660000]: TLS 1.3 set write key with cipher suite: GNUTLS_AES_256_GCM_SHA384 407s [gnutls] (4) HSK[0xeb94f6660000]: switching early to application traffic keys 407s [gnutls] (4) HSK[0xeb94f6660000]: NEW SESSION TICKET was queued [251 bytes] 407s [gnutls] (4) HSK[0xeb94f6660000]: NEW SESSION TICKET was queued [251 bytes] 407s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 407s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[1] Handshake(22) in epoch 2 and length: 273 407s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 407s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[2] Handshake(22) in epoch 2 and length: 273 407s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 407s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 407s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:93 407s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 407s [gnutls] (5) REC[0xeb94f6660000]: SSL 3.3 ChangeCipherSpec packet received. Epoch 1, length: 1 407s [gnutls] (5) REC[0xeb94f6660000]: Expected Packet Handshake(22) 407s [gnutls] (5) REC[0xeb94f6660000]: Received Packet ChangeCipherSpec(20) with length: 1 407s [gnutls] (5) REC[0xeb94f6660000]: SSL 3.3 Application Data packet received. Epoch 1, length: 69 407s [gnutls] (5) REC[0xeb94f6660000]: Expected Packet Handshake(22) 407s [gnutls] (5) REC[0xeb94f6660000]: Received Packet Application Data(23) with length: 69 407s [gnutls] (5) REC[0xeb94f6660000]: Decrypted Packet[0] Handshake(22) with length: 52 407s [gnutls] (4) HSK[0xeb94f6660000]: FINISHED (20) was received. Length 48[48], frag offset 0, frag length: 48, sequence: 0 407s [gnutls] (4) HSK[0xeb94f6660000]: parsing finished 407s [gnutls] (4) HSK[0xeb94f6660000]: TLS 1.3 set read key with cipher suite: GNUTLS_AES_256_GCM_SHA384 407s [gnutls] (5) REC[0xeb94f6660000]: Start of epoch cleanup 407s [gnutls] (5) REC[0xeb94f6660000]: Epoch #0 freed 407s [gnutls] (5) REC[0xeb94f6660000]: Epoch #1 freed 407s [gnutls] (5) REC[0xeb94f6660000]: End of epoch cleanup 407s [tls ] TLS handshake with 127.0.0.1#51829 has completed 407s [gnutls] (5) REC[0xeb94f6660000]: SSL 3.3 Application Data packet received. Epoch 2, length: 147 407s [gnutls] (5) REC[0xeb94f6660000]: Expected Packet Application Data(23) 407s [gnutls] (5) REC[0xeb94f6660000]: Received Packet Application Data(23) with length: 147 407s [gnutls] (5) REC[0xeb94f6660000]: Decrypted Packet[0] Application Data(23) with length: 130 407s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 407s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1759 407s [plan ][00000.00] plan 'monkeys.example.' type 'A' uid [22484.00] 407s [iterat][22484.00] 'monkeys.example.' type 'A' new uid was assigned .01, parent uid .00 407s [hint ][22484.01] <= answered from hints 407s [iterat][22484.01] <= rcode: NOERROR 407s [resolv][22484.01] AD: request NOT classified as SECURE 407s [resolv][22484.01] finished in state: 4, queries: 1, mempool: 81952 B 407s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Application Data(23) with length: 470 and min pad: 0 407s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[3] Application Data(23) in epoch 2 and length: 492 407s [gnutls] (5) REC[0xeb94f6660000]: SSL 3.3 Application Data packet received. Epoch 2, length: 19 407s [gnutls] (5) REC[0xeb94f6660000]: Expected Packet Application Data(23) 407s [gnutls] (5) REC[0xeb94f6660000]: Received Packet Application Data(23) with length: 19 407s [gnutls] (5) REC[0xeb94f6660000]: Decrypted Packet[1] Alert(21) with length: 2 407s [gnutls] (5) REC[0xeb94f6660000]: Alert[1|0] - Close notify - was received 407s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_in_buffers]:1565 407s [io ] => connection to '127.0.0.1#51829' closed by peer (end of file) 407s [gnutls] (5) REC[0xeb94f6660000]: Start of epoch cleanup 407s [gnutls] (5) REC[0xeb94f6660000]: End of epoch cleanup 407s [gnutls] (5) REC[0xeb94f6660000]: Epoch #2 freed 407s [gnutls] (5) REC[0xeb94f6660000]: Allocating epoch #0 407s [gnutls] (2) added 3 protocols, 29 ciphersuites, 19 sig algos and 10 groups into priority list 407s [gnutls] (5) REC[0xeb94f6660000]: Allocating epoch #1 407s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 407s [gnutls] (5) REC[0xeb94f6660000]: SSL 3.3 Handshake packet received. Epoch 0, length: 395 407s [gnutls] (5) REC[0xeb94f6660000]: Expected Packet Handshake(22) 407s [gnutls] (5) REC[0xeb94f6660000]: Received Packet Handshake(22) with length: 395 407s [gnutls] (5) REC[0xeb94f6660000]: Decrypted Packet[0] Handshake(22) with length: 395 407s [gnutls] (4) HSK[0xeb94f6660000]: CLIENT HELLO (1) was received. Length 391[391], frag offset 0, frag length: 391, sequence: 0 407s [gnutls] (4) HSK[0xeb94f6660000]: Client's version: 3.3 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Supported Versions/43' (5 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Found version: 3.4 407s [gnutls] (4) EXT[0xeb94f6660000]: Found version: 3.3 407s [gnutls] (4) EXT[0xeb94f6660000]: Negotiated version: 3.4 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Extended Master Secret/23' (0 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Safe Renegotiation/65281' (1 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Encrypt-then-MAC/22' (0 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Server Name Indication/0' (17 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'ALPN/16' (6 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Record Size Limit/28' (2 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: record_size_limit 16385 negotiated 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Supported Groups/10' (22 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Received group SECP256R1 (0x17) 407s [gnutls] (4) EXT[0xeb94f6660000]: Received group SECP384R1 (0x18) 407s [gnutls] (4) EXT[0xeb94f6660000]: Received group SECP521R1 (0x19) 407s [gnutls] (4) EXT[0xeb94f6660000]: Received group X25519 (0x1d) 407s [gnutls] (4) EXT[0xeb94f6660000]: Received group X448 (0x1e) 407s [gnutls] (4) EXT[0xeb94f6660000]: Received group FFDHE2048 (0x100) 407s [gnutls] (4) EXT[0xeb94f6660000]: Received group FFDHE3072 (0x101) 407s [gnutls] (4) EXT[0xeb94f6660000]: Received group FFDHE4096 (0x102) 407s [gnutls] (4) EXT[0xeb94f6660000]: Received group FFDHE6144 (0x103) 407s [gnutls] (4) EXT[0xeb94f6660000]: Received group FFDHE8192 (0x104) 407s [gnutls] (4) EXT[0xeb94f6660000]: Selected group SECP256R1 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Supported EC Point Formats/11' (2 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Session Ticket/35' (0 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'PSK Key Exchange Modes/45' (3 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: PSK KE mode 01 received 407s [gnutls] (4) EXT[0xeb94f6660000]: PSK KE mode 00 received 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Signature Algorithms/13' (34 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (4.1) RSA-SHA256 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.9) RSA-PSS-SHA256 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.4) RSA-PSS-RSAE-SHA256 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (4.3) ECDSA-SECP256R1-SHA256 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.7) EdDSA-Ed25519 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (5.1) RSA-SHA384 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.10) RSA-PSS-SHA384 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.5) RSA-PSS-RSAE-SHA384 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (5.3) ECDSA-SECP384R1-SHA384 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.8) EdDSA-Ed448 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (6.1) RSA-SHA512 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.11) RSA-PSS-SHA512 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.6) RSA-PSS-RSAE-SHA512 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (6.3) ECDSA-SECP521R1-SHA512 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (2.1) RSA-SHA1 407s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (2.3) ECDSA-SHA1 407s [gnutls] (2) checking 13.02 (GNUTLS_AES_256_GCM_SHA384) for compatibility 407s [gnutls] (4) HSK[0xeb94f6660000]: Requested server name: 'test.example' 407s [gnutls] (4) checking cert compat with RSA-SHA256 407s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 407s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 407s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 407s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 407s [gnutls] (4) Selected signature algorithm: RSA-PSS-RSAE-SHA256 407s [gnutls] (2) Selected (RSA) cert based on ciphersuite 13.2: GNUTLS_AES_256_GCM_SHA384 407s [gnutls] (4) HSK[0xeb94f6660000]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384 407s [gnutls] (4) HSK[0xeb94f6660000]: Selected version TLS1.3 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'OCSP Status Request/5' (5 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: OCSP status was requested 407s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Key Share/51' (107 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Received key share for SECP256R1 407s [gnutls] (4) HSK[0xeb94f6660000]: Selected group SECP256R1 (2) 407s [gnutls] (2) EXT[0xeb94f6660000]: server generated SECP256R1 shared key 407s [gnutls] (4) HSK[0xeb94f6660000]: Safe renegotiation succeeded 407s [gnutls] (4) HSK[0xeb94f6660000]: SessionID: ead1b07eff80359bca6504d00c45bfd488fc4f634fc122fddbce90601c3eaae0 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Signature Algorithms/13) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Extended Master Secret/23) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (SRTP/14) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (PSK Key Exchange Modes/45) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Record Size Limit/28) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (ALPN/16) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Maximum Record Size/1) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Session Ticket/35) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Compress Certificate/27) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Client Certificate Type/19) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Supported Groups/10) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Supported Versions/43) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Sending extension Supported Versions/43 (2 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Server Name Indication/0) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Encrypt-then-MAC/22) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Server Certificate Type/20) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Post Handshake Auth/49) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (OCSP Status Request/5) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Safe Renegotiation/65281) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Supported EC Point Formats/11) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Key Share/51) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: sending key share for SECP256R1 407s [gnutls] (4) EXT[0xeb94f6660000]: Sending extension Key Share/51 (69 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Early Data/42) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Cookie/44) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (ClientHello Padding/21) for 'TLS 1.3 server hello' 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Pre Shared Key/41) for 'TLS 1.3 server hello' 407s [gnutls] (4) HSK[0xeb94f6660000]: SERVER HELLO was queued [155 bytes] 407s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 155 and min pad: 0 407s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 160 407s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0 407s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6 407s [gnutls] (4) REC[0xeb94f6660000]: Sent ChangeCipherSpec 407s [gnutls] (5) REC[0xeb94f6660000]: Initializing epoch #1 407s [gnutls] (5) REC[0xeb94f6660000]: Epoch #1 ready 407s [gnutls] (4) HSK[0xeb94f6660000]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Client Certificate Type/19) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Session Ticket/35) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Supported Groups/10) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Key Share/51) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Signature Algorithms/13) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Post Handshake Auth/49) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Server Name Indication/0) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (OCSP Status Request/5) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (ALPN/16) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Sending extension ALPN/16 (6 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (SRTP/14) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Safe Renegotiation/65281) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Cookie/44) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Server Certificate Type/20) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Record Size Limit/28) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Sending extension Record Size Limit/28 (2 bytes) 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Extended Master Secret/23) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Maximum Record Size/1) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Early Data/42) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Compress Certificate/27) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (PSK Key Exchange Modes/45) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Encrypt-then-MAC/22) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Supported Versions/43) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Supported EC Point Formats/11) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (ClientHello Padding/21) for 'encrypted extensions' 407s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Pre Shared Key/41) for 'encrypted extensions' 407s [gnutls] (4) HSK[0xeb94f6660000]: ENCRYPTED EXTENSIONS was queued [22 bytes] 407s [gnutls] (4) HSK[0xeb94f6660000]: CERTIFICATE was queued [1155 bytes] 407s [gnutls] (4) checking cert compat with RSA-SHA256 408s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 408s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 408s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 408s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 408s [gnutls] (4) HSK[0xeb94f6660000]: signing TLS 1.3 handshake data: using RSA-PSS-RSAE-SHA256 and PRF: SHA384 408s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 408s [gnutls] (4) HSK[0xeb94f6660000]: CERTIFICATE VERIFY was queued [392 bytes] 408s [gnutls] (4) HSK[0xeb94f6660000]: sending finished 408s [gnutls] (4) HSK[0xeb94f6660000]: FINISHED was queued [52 bytes] 408s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 22 and min pad: 0 408s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 44 408s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 1155 and min pad: 0 408s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[2] Handshake(22) in epoch 1 and length: 1177 408s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 392 and min pad: 0 408s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[3] Handshake(22) in epoch 1 and length: 414 408s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 52 and min pad: 0 408s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[4] Handshake(22) in epoch 1 and length: 74 408s [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:965 408s [gnutls] (5) REC[0xeb94f6660000]: Allocating epoch #2 408s [gnutls] (4) HSK[0xeb94f6660000]: unauthenticated session eligible for early start 408s [gnutls] (5) REC[0xeb94f6660000]: Initializing epoch #2 408s [gnutls] (5) REC[0xeb94f6660000]: Epoch #2 ready 408s [gnutls] (4) HSK[0xeb94f6660000]: TLS 1.3 set write key with cipher suite: GNUTLS_AES_256_GCM_SHA384 408s [gnutls] (4) HSK[0xeb94f6660000]: switching early to application traffic keys 408s [gnutls] (4) HSK[0xeb94f6660000]: NEW SESSION TICKET was queued [251 bytes] 408s [gnutls] (4) HSK[0xeb94f6660000]: NEW SESSION TICKET was queued [251 bytes] 408s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 408s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[1] Handshake(22) in epoch 2 and length: 273 408s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 408s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[2] Handshake(22) in epoch 2 and length: 273 408s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 408s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 408s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:93 408s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 408s [gnutls] (5) REC[0xeb94f6660000]: SSL 3.3 ChangeCipherSpec packet received. Epoch 1, length: 1 408s [gnutls] (5) REC[0xeb94f6660000]: Expected Packet Handshake(22) 408s [gnutls] (5) REC[0xeb94f6660000]: Received Packet ChangeCipherSpec(20) with length: 1 408s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 408s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:93 408s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 408s [gnutls] (5) REC[0xeb94f6660000]: SSL 3.3 Application Data packet received. Epoch 1, length: 69 408s [gnutls] (5) REC[0xeb94f6660000]: Expected Packet Handshake(22) 408s [gnutls] (5) REC[0xeb94f6660000]: Received Packet Application Data(23) with length: 69 408s [gnutls] (5) REC[0xeb94f6660000]: Decrypted Packet[0] Handshake(22) with length: 52 408s [gnutls] (4) HSK[0xeb94f6660000]: FINISHED (20) was received. Length 48[48], frag offset 0, frag length: 48, sequence: 0 408s [gnutls] (4) HSK[0xeb94f6660000]: parsing finished 408s [gnutls] (4) HSK[0xeb94f6660000]: TLS 1.3 set read key with cipher suite: GNUTLS_AES_256_GCM_SHA384 408s [gnutls] (5) REC[0xeb94f6660000]: Start of epoch cleanup 408s [gnutls] (5) REC[0xeb94f6660000]: Epoch #0 freed 408s [gnutls] (5) REC[0xeb94f6660000]: Epoch #1 freed 408s [gnutls] (5) REC[0xeb94f6660000]: End of epoch cleanup 408s [tls ] TLS handshake with 127.0.0.1#43123 has completed 408s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 408s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1759 408s [gnutls] (5) REC[0xeb94f6660000]: SSL 3.3 Application Data packet received. Epoch 2, length: 147 408s [gnutls] (5) REC[0xeb94f6660000]: Expected Packet Application Data(23) 408s [gnutls] (5) REC[0xeb94f6660000]: Received Packet Application Data(23) with length: 147 408s [gnutls] (5) REC[0xeb94f6660000]: Decrypted Packet[0] Application Data(23) with length: 130 408s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 408s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1759 408s [plan ][00000.00] plan 'monkeys.example.' type 'A' uid [09697.00] 408s [iterat][09697.00] 'monkeys.example.' type 'A' new uid was assigned .01, parent uid .00 408s [hint ][09697.01] <= answered from hints 408s [iterat][09697.01] <= rcode: NOERROR 408s [resolv][09697.01] AD: request NOT classified as SECURE 408s [resolv][09697.01] finished in state: 4, queries: 1, mempool: 81952 B 408s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Application Data(23) with length: 470 and min pad: 0 408s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[3] Application Data(23) in epoch 2 and length: 492 408s [gnutls] (5) REC[0xeb94f6660000]: SSL 3.3 Application Data packet received. Epoch 2, length: 19 408s [gnutls] (5) REC[0xeb94f6660000]: Expected Packet Application Data(23) 408s [gnutls] (5) REC[0xeb94f6660000]: Received Packet Application Data(23) with length: 19 408s [gnutls] (5) REC[0xeb94f6660000]: Decrypted Packet[1] Alert(21) with length: 2 408s [gnutls] (5) REC[0xeb94f6660000]: Alert[1|0] - Close notify - was received 408s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_in_buffers]:1565 408s [io ] => connection to '127.0.0.1#43123' closed by peer (end of file) 408s [gnutls] (5) REC[0xeb94f6660000]: Start of epoch cleanup 408s [gnutls] (5) REC[0xeb94f6660000]: End of epoch cleanup 408s [gnutls] (5) REC[0xeb94f6660000]: Epoch #2 freed 408s [gnutls] (5) REC[0xeb94f6660000]: Allocating epoch #0 408s [gnutls] (2) added 3 protocols, 29 ciphersuites, 19 sig algos and 10 groups into priority list 408s [gnutls] (5) REC[0xeb94f6660000]: Allocating epoch #1 408s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 408s [gnutls] (5) REC[0xeb94f6660000]: SSL 3.3 Handshake packet received. Epoch 0, length: 399 408s [gnutls] (5) REC[0xeb94f6660000]: Expected Packet Handshake(22) 408s [gnutls] (5) REC[0xeb94f6660000]: Received Packet Handshake(22) with length: 399 408s [gnutls] (5) REC[0xeb94f6660000]: Decrypted Packet[0] Handshake(22) with length: 399 408s [gnutls] (4) HSK[0xeb94f6660000]: CLIENT HELLO (1) was received. Length 395[395], frag offset 0, frag length: 395, sequence: 0 408s [gnutls] (4) HSK[0xeb94f6660000]: Client's version: 3.3 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Supported Versions/43' (5 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Found version: 3.4 408s [gnutls] (4) EXT[0xeb94f6660000]: Found version: 3.3 408s [gnutls] (4) EXT[0xeb94f6660000]: Negotiated version: 3.4 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Encrypt-then-MAC/22' (0 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Safe Renegotiation/65281' (1 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Extended Master Secret/23' (0 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Record Size Limit/28' (2 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: record_size_limit 16385 negotiated 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Server Name Indication/0' (21 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'ALPN/16' (6 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'PSK Key Exchange Modes/45' (3 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: PSK KE mode 01 received 408s [gnutls] (4) EXT[0xeb94f6660000]: PSK KE mode 00 received 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Session Ticket/35' (0 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Supported Groups/10' (22 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Received group SECP256R1 (0x17) 408s [gnutls] (4) EXT[0xeb94f6660000]: Received group SECP384R1 (0x18) 408s [gnutls] (4) EXT[0xeb94f6660000]: Received group SECP521R1 (0x19) 408s [gnutls] (4) EXT[0xeb94f6660000]: Received group X25519 (0x1d) 408s [gnutls] (4) EXT[0xeb94f6660000]: Received group X448 (0x1e) 408s [gnutls] (4) EXT[0xeb94f6660000]: Received group FFDHE2048 (0x100) 408s [gnutls] (4) EXT[0xeb94f6660000]: Received group FFDHE3072 (0x101) 408s [gnutls] (4) EXT[0xeb94f6660000]: Received group FFDHE4096 (0x102) 408s [gnutls] (4) EXT[0xeb94f6660000]: Received group FFDHE6144 (0x103) 408s [gnutls] (4) EXT[0xeb94f6660000]: Received group FFDHE8192 (0x104) 408s [gnutls] (4) EXT[0xeb94f6660000]: Selected group SECP256R1 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Supported EC Point Formats/11' (2 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Signature Algorithms/13' (34 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (4.1) RSA-SHA256 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.9) RSA-PSS-SHA256 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.4) RSA-PSS-RSAE-SHA256 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (4.3) ECDSA-SECP256R1-SHA256 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.7) EdDSA-Ed25519 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (5.1) RSA-SHA384 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.10) RSA-PSS-SHA384 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.5) RSA-PSS-RSAE-SHA384 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (5.3) ECDSA-SECP384R1-SHA384 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.8) EdDSA-Ed448 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (6.1) RSA-SHA512 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.11) RSA-PSS-SHA512 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.6) RSA-PSS-RSAE-SHA512 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (6.3) ECDSA-SECP521R1-SHA512 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (2.1) RSA-SHA1 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (2.3) ECDSA-SHA1 408s [gnutls] (2) checking 13.02 (GNUTLS_AES_256_GCM_SHA384) for compatibility 408s [gnutls] (4) HSK[0xeb94f6660000]: Requested server name: 'notright.example' 408s [gnutls] (4) HSK[0xeb94f6660000]: checking compat of GNUTLS_AES_256_GCM_SHA384 with certificate[0] (RSA/X.509) 408s [gnutls] (4) checking cert compat with RSA-SHA256 408s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 408s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 408s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 408s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 408s [gnutls] (4) Selected signature algorithm: RSA-PSS-RSAE-SHA256 408s [gnutls] (2) Selected (RSA) cert based on ciphersuite 13.2: GNUTLS_AES_256_GCM_SHA384 408s [gnutls] (4) HSK[0xeb94f6660000]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384 408s [gnutls] (4) HSK[0xeb94f6660000]: Selected version TLS1.3 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'OCSP Status Request/5' (5 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: OCSP status was requested 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Key Share/51' (107 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Received key share for SECP256R1 408s [gnutls] (4) HSK[0xeb94f6660000]: Selected group SECP256R1 (2) 408s [gnutls] (2) EXT[0xeb94f6660000]: server generated SECP256R1 shared key 408s [gnutls] (4) HSK[0xeb94f6660000]: Safe renegotiation succeeded 408s [gnutls] (4) HSK[0xeb94f6660000]: SessionID: fb62941fd0d5ce35205e5944ed6a3224f4f6afcbee4602908b69b0c036392ad3 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Supported Groups/10) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Key Share/51) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: sending key share for SECP256R1 408s [gnutls] (4) EXT[0xeb94f6660000]: Sending extension Key Share/51 (69 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Encrypt-then-MAC/22) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Safe Renegotiation/65281) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (SRTP/14) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Session Ticket/35) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Post Handshake Auth/49) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (PSK Key Exchange Modes/45) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Signature Algorithms/13) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Server Certificate Type/20) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Cookie/44) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Extended Master Secret/23) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Supported EC Point Formats/11) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Early Data/42) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Client Certificate Type/19) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Server Name Indication/0) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Maximum Record Size/1) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Supported Versions/43) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Sending extension Supported Versions/43 (2 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (OCSP Status Request/5) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (ALPN/16) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Record Size Limit/28) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Compress Certificate/27) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (ClientHello Padding/21) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Pre Shared Key/41) for 'TLS 1.3 server hello' 408s [gnutls] (4) HSK[0xeb94f6660000]: SERVER HELLO was queued [155 bytes] 408s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 155 and min pad: 0 408s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 160 408s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0 408s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6 408s [gnutls] (4) REC[0xeb94f6660000]: Sent ChangeCipherSpec 408s [gnutls] (5) REC[0xeb94f6660000]: Initializing epoch #1 408s [gnutls] (5) REC[0xeb94f6660000]: Epoch #1 ready 408s [gnutls] (4) HSK[0xeb94f6660000]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Supported EC Point Formats/11) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Server Name Indication/0) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Maximum Record Size/1) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (PSK Key Exchange Modes/45) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (SRTP/14) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Record Size Limit/28) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Sending extension Record Size Limit/28 (2 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Signature Algorithms/13) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (OCSP Status Request/5) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Early Data/42) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Server Certificate Type/20) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (ALPN/16) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Sending extension ALPN/16 (6 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Extended Master Secret/23) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Post Handshake Auth/49) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Encrypt-then-MAC/22) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Compress Certificate/27) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Client Certificate Type/19) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Key Share/51) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Supported Groups/10) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Session Ticket/35) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Safe Renegotiation/65281) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Supported Versions/43) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Cookie/44) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (ClientHello Padding/21) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Pre Shared Key/41) for 'encrypted extensions' 408s [gnutls] (4) HSK[0xeb94f6660000]: ENCRYPTED EXTENSIONS was queued [22 bytes] 408s [gnutls] (4) HSK[0xeb94f6660000]: CERTIFICATE was queued [1155 bytes] 408s [gnutls] (4) checking cert compat with RSA-SHA256 408s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 408s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 408s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 408s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 408s [gnutls] (4) HSK[0xeb94f6660000]: signing TLS 1.3 handshake data: using RSA-PSS-RSAE-SHA256 and PRF: SHA384 408s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 408s [gnutls] (4) HSK[0xeb94f6660000]: CERTIFICATE VERIFY was queued [392 bytes] 408s [gnutls] (4) HSK[0xeb94f6660000]: sending finished 408s [gnutls] (4) HSK[0xeb94f6660000]: FINISHED was queued [52 bytes] 408s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 22 and min pad: 0 408s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 44 408s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 1155 and min pad: 0 408s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[2] Handshake(22) in epoch 1 and length: 1177 408s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 392 and min pad: 0 408s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[3] Handshake(22) in epoch 1 and length: 414 408s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 52 and min pad: 0 408s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[4] Handshake(22) in epoch 1 and length: 74 408s [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:965 408s [gnutls] (5) REC[0xeb94f6660000]: Allocating epoch #2 408s [gnutls] (4) HSK[0xeb94f6660000]: unauthenticated session eligible for early start 408s [gnutls] (5) REC[0xeb94f6660000]: Initializing epoch #2 408s [gnutls] (5) REC[0xeb94f6660000]: Epoch #2 ready 408s [gnutls] (4) HSK[0xeb94f6660000]: TLS 1.3 set write key with cipher suite: GNUTLS_AES_256_GCM_SHA384 408s [gnutls] (4) HSK[0xeb94f6660000]: switching early to application traffic keys 408s [gnutls] (4) HSK[0xeb94f6660000]: NEW SESSION TICKET was queued [251 bytes] 408s [gnutls] (4) HSK[0xeb94f6660000]: NEW SESSION TICKET was queued [251 bytes] 408s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 408s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[1] Handshake(22) in epoch 2 and length: 273 408s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 408s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[2] Handshake(22) in epoch 2 and length: 273 408s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 408s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 408s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:93 408s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 408s [gnutls] (5) REC[0xeb94f6660000]: SSL 3.3 ChangeCipherSpec packet received. Epoch 1, length: 1 408s [gnutls] (5) REC[0xeb94f6660000]: Expected Packet Handshake(22) 408s [gnutls] (5) REC[0xeb94f6660000]: Received Packet ChangeCipherSpec(20) with length: 1 408s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 408s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:93 408s [io ] => connection to '127.0.0.1#50819' closed by peer (connection reset by peer) 408s [gnutls] (5) REC[0xeb94f6660000]: Start of epoch cleanup 408s [gnutls] (5) REC[0xeb94f6660000]: Epoch #0 freed 408s [gnutls] (5) REC[0xeb94f6660000]: End of epoch cleanup 408s [gnutls] (5) REC[0xeb94f6660000]: Epoch #1 freed 408s [gnutls] (5) REC[0xeb94f6660000]: Epoch #2 freed 408s [gnutls] (5) REC[0xeb94f6660000]: Allocating epoch #0 408s [gnutls] (2) added 3 protocols, 29 ciphersuites, 19 sig algos and 10 groups into priority list 408s [gnutls] (5) REC[0xeb94f6660000]: Allocating epoch #1 408s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 408s [gnutls] (5) REC[0xeb94f6660000]: SSL 3.3 Handshake packet received. Epoch 0, length: 395 408s [gnutls] (5) REC[0xeb94f6660000]: Expected Packet Handshake(22) 408s [gnutls] (5) REC[0xeb94f6660000]: Received Packet Handshake(22) with length: 395 408s [gnutls] (5) REC[0xeb94f6660000]: Decrypted Packet[0] Handshake(22) with length: 395 408s [gnutls] (4) HSK[0xeb94f6660000]: CLIENT HELLO (1) was received. Length 391[391], frag offset 0, frag length: 391, sequence: 0 408s [gnutls] (4) HSK[0xeb94f6660000]: Client's version: 3.3 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Supported Versions/43' (5 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Found version: 3.4 408s [gnutls] (4) EXT[0xeb94f6660000]: Found version: 3.3 408s [gnutls] (4) EXT[0xeb94f6660000]: Negotiated version: 3.4 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Extended Master Secret/23' (0 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Record Size Limit/28' (2 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: record_size_limit 16385 negotiated 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'ALPN/16' (6 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Server Name Indication/0' (17 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Encrypt-then-MAC/22' (0 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Safe Renegotiation/65281' (1 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Signature Algorithms/13' (34 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (4.1) RSA-SHA256 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.9) RSA-PSS-SHA256 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.4) RSA-PSS-RSAE-SHA256 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (4.3) ECDSA-SECP256R1-SHA256 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.7) EdDSA-Ed25519 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (5.1) RSA-SHA384 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.10) RSA-PSS-SHA384 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.5) RSA-PSS-RSAE-SHA384 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (5.3) ECDSA-SECP384R1-SHA384 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.8) EdDSA-Ed448 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (6.1) RSA-SHA512 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.11) RSA-PSS-SHA512 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (8.6) RSA-PSS-RSAE-SHA512 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (6.3) ECDSA-SECP521R1-SHA512 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (2.1) RSA-SHA1 408s [gnutls] (4) EXT[0xeb94f6660000]: rcvd signature algo (2.3) ECDSA-SHA1 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Supported EC Point Formats/11' (2 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'PSK Key Exchange Modes/45' (3 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: PSK KE mode 01 received 408s [gnutls] (4) EXT[0xeb94f6660000]: PSK KE mode 00 received 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Supported Groups/10' (22 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Received group SECP256R1 (0x17) 408s [gnutls] (4) EXT[0xeb94f6660000]: Received group SECP384R1 (0x18) 408s [gnutls] (4) EXT[0xeb94f6660000]: Received group SECP521R1 (0x19) 408s [gnutls] (4) EXT[0xeb94f6660000]: Received group X25519 (0x1d) 408s [gnutls] (4) EXT[0xeb94f6660000]: Received group X448 (0x1e) 408s [gnutls] (4) EXT[0xeb94f6660000]: Received group FFDHE2048 (0x100) 408s [gnutls] (4) EXT[0xeb94f6660000]: Received group FFDHE3072 (0x101) 408s [gnutls] (4) EXT[0xeb94f6660000]: Received group FFDHE4096 (0x102) 408s [gnutls] (4) EXT[0xeb94f6660000]: Received group FFDHE6144 (0x103) 408s [gnutls] (4) EXT[0xeb94f6660000]: Received group FFDHE8192 (0x104) 408s [gnutls] (4) EXT[0xeb94f6660000]: Selected group SECP256R1 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Session Ticket/35' (0 bytes) 408s [gnutls] (2) checking 13.02 (GNUTLS_AES_256_GCM_SHA384) for compatibility 408s [gnutls] (4) HSK[0xeb94f6660000]: Requested server name: 'test.example' 408s [gnutls] (4) checking cert compat with RSA-SHA256 408s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 408s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 408s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 408s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 408s [gnutls] (4) Selected signature algorithm: RSA-PSS-RSAE-SHA256 408s [gnutls] (2) Selected (RSA) cert based on ciphersuite 13.2: GNUTLS_AES_256_GCM_SHA384 408s [gnutls] (4) HSK[0xeb94f6660000]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384 408s [gnutls] (4) HSK[0xeb94f6660000]: Selected version TLS1.3 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'Key Share/51' (107 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Received key share for SECP256R1 408s [gnutls] (4) HSK[0xeb94f6660000]: Selected group SECP256R1 (2) 408s [gnutls] (2) EXT[0xeb94f6660000]: server generated SECP256R1 shared key 408s [gnutls] (4) EXT[0xeb94f6660000]: Parsing extension 'OCSP Status Request/5' (5 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: OCSP status was requested 408s [gnutls] (4) HSK[0xeb94f6660000]: Safe renegotiation succeeded 408s [gnutls] (4) HSK[0xeb94f6660000]: SessionID: 5972ba22613e6171856a80278520a11339e1591612428d2bb50d9c2e06df68de 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (OCSP Status Request/5) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Client Certificate Type/19) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Compress Certificate/27) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Extended Master Secret/23) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Supported Versions/43) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Sending extension Supported Versions/43 (2 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Server Certificate Type/20) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Encrypt-then-MAC/22) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (PSK Key Exchange Modes/45) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Session Ticket/35) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Post Handshake Auth/49) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (SRTP/14) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Signature Algorithms/13) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Supported EC Point Formats/11) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Key Share/51) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: sending key share for SECP256R1 408s [gnutls] (4) EXT[0xeb94f6660000]: Sending extension Key Share/51 (69 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Server Name Indication/0) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (ALPN/16) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Supported Groups/10) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Cookie/44) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Safe Renegotiation/65281) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Record Size Limit/28) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Maximum Record Size/1) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Early Data/42) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (ClientHello Padding/21) for 'TLS 1.3 server hello' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Pre Shared Key/41) for 'TLS 1.3 server hello' 408s [gnutls] (4) HSK[0xeb94f6660000]: SERVER HELLO was queued [155 bytes] 408s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 155 and min pad: 0 408s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 160 408s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0 408s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6 408s [gnutls] (4) REC[0xeb94f6660000]: Sent ChangeCipherSpec 408s [gnutls] (5) REC[0xeb94f6660000]: Initializing epoch #1 408s [gnutls] (5) REC[0xeb94f6660000]: Epoch #1 ready 408s [gnutls] (4) HSK[0xeb94f6660000]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (PSK Key Exchange Modes/45) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Supported Versions/43) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Record Size Limit/28) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Sending extension Record Size Limit/28 (2 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Server Name Indication/0) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Client Certificate Type/19) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Key Share/51) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Session Ticket/35) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Cookie/44) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Supported Groups/10) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Encrypt-then-MAC/22) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Maximum Record Size/1) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Early Data/42) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Post Handshake Auth/49) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Safe Renegotiation/65281) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Supported EC Point Formats/11) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (Server Certificate Type/20) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (OCSP Status Request/5) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (SRTP/14) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Compress Certificate/27) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Preparing extension (ALPN/16) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Sending extension ALPN/16 (6 bytes) 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Extended Master Secret/23) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Signature Algorithms/13) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (ClientHello Padding/21) for 'encrypted extensions' 408s [gnutls] (4) EXT[0xeb94f6660000]: Not sending extension (Pre Shared Key/41) for 'encrypted extensions' 408s [gnutls] (4) HSK[0xeb94f6660000]: ENCRYPTED EXTENSIONS was queued [22 bytes] 408s [gnutls] (4) HSK[0xeb94f6660000]: CERTIFICATE was queued [1155 bytes] 408s [gnutls] (4) checking cert compat with RSA-SHA256 408s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 408s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 408s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 408s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 408s [gnutls] (4) HSK[0xeb94f6660000]: signing TLS 1.3 handshake data: using RSA-PSS-RSAE-SHA256 and PRF: SHA384 408s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 408s [gnutls] (4) HSK[0xeb94f6660000]: CERTIFICATE VERIFY was queued [392 bytes] 408s [gnutls] (4) HSK[0xeb94f6660000]: sending finished 408s [gnutls] (4) HSK[0xeb94f6660000]: FINISHED was queued [52 bytes] 408s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 22 and min pad: 0 408s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 44 408s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 1155 and min pad: 0 408s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[2] Handshake(22) in epoch 1 and length: 1177 408s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 392 and min pad: 0 408s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[3] Handshake(22) in epoch 1 and length: 414 408s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 52 and min pad: 0 408s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[4] Handshake(22) in epoch 1 and length: 74 408s [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:965 408s [gnutls] (5) REC[0xeb94f6660000]: Allocating epoch #2 408s [gnutls] (4) HSK[0xeb94f6660000]: unauthenticated session eligible for early start 408s [gnutls] (5) REC[0xeb94f6660000]: Initializing epoch #2 408s [gnutls] (5) REC[0xeb94f6660000]: Epoch #2 ready 408s [gnutls] (4) HSK[0xeb94f6660000]: TLS 1.3 set write key with cipher suite: GNUTLS_AES_256_GCM_SHA384 408s [gnutls] (4) HSK[0xeb94f6660000]: switching early to application traffic keys 408s [gnutls] (4) HSK[0xeb94f6660000]: NEW SESSION TICKET was queued [251 bytes] 408s [gnutls] (4) HSK[0xeb94f6660000]: NEW SESSION TICKET was queued [251 bytes] 408s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 408s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[1] Handshake(22) in epoch 2 and length: 273 408s [gnutls] (5) REC[0xeb94f6660000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 408s [gnutls] (5) REC[0xeb94f6660000]: Sent Packet[2] Handshake(22) in epoch 2 and length: 273 408s [tls ] uv_try_write error: connection reset by peer 408s [gnutls] (2) WRITE: -1 returned from 0xeb94f60ce000, errno: 5 408s [gnutls] (3) ASSERT: ../../lib/buffers.c[errno_to_gerr]:218 408s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_write_flush]:693 408s [gnutls] (3) ASSERT: ../../lib/handshake-tls13.c[_gnutls13_handshake_server]:536 408s [tls ] gnutls_handshake failed: GNUTLS_E_PUSH_ERROR (-53) 408s [gnutls] (5) REC: Sending Alert[2|80] - Internal error 408s [tls ] uv_try_write error: broken pipe 408s [gnutls] (2) WRITE: -1 returned from 0xeb94f60ce000, errno: 5 408s [gnutls] (3) ASSERT: ../../lib/buffers.c[errno_to_gerr]:218 408s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_write_flush]:693 408s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_send_tlen_int]:586 408s [io ] => connection to '127.0.0.1#37767': error processing TLS data, close 408s [gnutls] (5) REC[0xeb94f6660000]: Start of epoch cleanup 408s [gnutls] (5) REC[0xeb94f6660000]: Epoch #0 freed 408s [gnutls] (5) REC[0xeb94f6660000]: End of epoch cleanup 408s [gnutls] (5) REC[0xeb94f6660000]: Epoch #1 freed 408s [gnutls] (5) REC[0xeb94f6660000]: Epoch #2 freed 408s > 408s > autopkgtest [18:14:46]: test roundtrip: -----------------------] 409s autopkgtest [18:14:47]: test roundtrip: - - - - - - - - - - results - - - - - - - - - - 409s roundtrip PASS 660s autopkgtest [18:18:58]: @@@@@@@@@@@@@@@@@@@@ summary 660s roundtrip PASS 691s Creating nova instance adt-noble-arm64-knot-resolver-20240419-180758-juju-7f2275-prod-proposed-migration-environment-2-ed23f394-e61e-4cf4-bc42-c707cb2bc490 from image adt/ubuntu-noble-arm64-server-20240419.img (UUID 76458b5c-765e-49d7-9847-fbb8979c4c50)...