0s autopkgtest [19:24:21]: starting date and time: 2024-07-12 19:24:21+0000 0s autopkgtest [19:24:21]: git checkout: fd3bed09 nova: allow more retries for quota issues 0s autopkgtest [19:24:21]: host juju-7f2275-prod-proposed-migration-environment-9; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.ojsryid_/out --timeout-copy=6000 --setup-commands 'ln -s /dev/null /etc/systemd/system/bluetooth.service; printf "http_proxy=http://squid.internal:3128\nhttps_proxy=http://squid.internal:3128\nno_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,keyserver.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com\n" >> /etc/environment' --apt-pocket=proposed=src:glibc --apt-upgrade knot-resolver --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=glibc/2.39-3.1ubuntu3 -- lxd -r lxd-armhf-10.145.243.183 lxd-armhf-10.145.243.183:autopkgtest/ubuntu/oracular/armhf 54s autopkgtest [19:25:15]: testbed dpkg architecture: armhf 56s autopkgtest [19:25:17]: testbed apt version: 2.9.6 56s autopkgtest [19:25:17]: @@@@@@@@@@@@@@@@@@@@ test bed setup 65s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [126 kB] 65s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [8548 B] 65s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [327 kB] 65s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [2576 B] 65s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [48.0 kB] 65s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main armhf Packages [60.3 kB] 65s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main armhf c-n-f Metadata [1444 B] 65s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/restricted armhf Packages [1368 B] 65s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/restricted armhf c-n-f Metadata [120 B] 65s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/universe armhf Packages [287 kB] 65s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/universe armhf c-n-f Metadata [6176 B] 65s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse armhf Packages [1448 B] 65s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse armhf c-n-f Metadata [120 B] 67s Fetched 869 kB in 1s (1057 kB/s) 67s Reading package lists... 85s tee: /proc/self/fd/2: Permission denied 108s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [126 kB] 108s Get:2 http://ftpmaster.internal/ubuntu oracular InRelease [121 kB] 109s Hit:3 http://ftpmaster.internal/ubuntu oracular-updates InRelease 109s Hit:4 http://ftpmaster.internal/ubuntu oracular-security InRelease 109s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [3288 B] 109s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [371 kB] 109s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/universe armhf Packages [317 kB] 109s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse armhf Packages [1796 B] 109s Get:9 http://ftpmaster.internal/ubuntu oracular/universe Sources [20.3 MB] 109s Get:10 http://ftpmaster.internal/ubuntu oracular/universe armhf Packages [15.0 MB] 113s Fetched 36.2 MB in 5s (7350 kB/s) 114s Reading package lists... 114s Reading package lists... 114s Building dependency tree... 114s Reading state information... 115s Calculating upgrade... 115s The following packages will be upgraded: 115s inetutils-telnet libc-bin libc6 libssl3t64 locales openssh-client 115s openssh-server openssh-sftp-server openssl telnet 115s 10 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 115s Need to get 11.9 MB of archives. 115s After this operation, 285 kB of additional disk space will be used. 115s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed/main armhf libc6 armhf 2.39-3.1ubuntu3 [2825 kB] 116s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/main armhf libc-bin armhf 2.39-3.1ubuntu3 [527 kB] 116s Get:3 http://ftpmaster.internal/ubuntu oracular/main armhf libssl3t64 armhf 3.2.2-1ubuntu1 [1729 kB] 116s Get:4 http://ftpmaster.internal/ubuntu oracular/main armhf openssh-sftp-server armhf 1:9.6p1-3ubuntu17 [35.6 kB] 116s Get:5 http://ftpmaster.internal/ubuntu oracular/main armhf openssh-server armhf 1:9.6p1-3ubuntu17 [502 kB] 116s Get:6 http://ftpmaster.internal/ubuntu oracular/main armhf openssh-client armhf 1:9.6p1-3ubuntu17 [888 kB] 116s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main armhf locales all 2.39-3.1ubuntu3 [4220 kB] 116s Get:8 http://ftpmaster.internal/ubuntu oracular/main armhf openssl armhf 3.2.2-1ubuntu1 [1095 kB] 116s Get:9 http://ftpmaster.internal/ubuntu oracular/main armhf inetutils-telnet armhf 2:2.5-5ubuntu1 [94.4 kB] 116s Get:10 http://ftpmaster.internal/ubuntu oracular/main armhf telnet all 0.17+2.5-5ubuntu1 [3688 B] 117s Preconfiguring packages ... 117s Fetched 11.9 MB in 1s (12.2 MB/s) 117s (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 ... 58437 files and directories currently installed.) 117s Preparing to unpack .../libc6_2.39-3.1ubuntu3_armhf.deb ... 117s Unpacking libc6:armhf (2.39-3.1ubuntu3) over (2.39-0ubuntu9) ... 118s Setting up libc6:armhf (2.39-3.1ubuntu3) ... 118s Error: Could not restart systemd, systemd binary not working 118s (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 ... 58437 files and directories currently installed.) 118s Preparing to unpack .../libc-bin_2.39-3.1ubuntu3_armhf.deb ... 118s Unpacking libc-bin (2.39-3.1ubuntu3) over (2.39-0ubuntu9) ... 118s Setting up libc-bin (2.39-3.1ubuntu3) ... 118s (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 ... 58437 files and directories currently installed.) 118s Preparing to unpack .../libssl3t64_3.2.2-1ubuntu1_armhf.deb ... 118s Unpacking libssl3t64:armhf (3.2.2-1ubuntu1) over (3.2.1-3ubuntu1) ... 118s Setting up libssl3t64:armhf (3.2.2-1ubuntu1) ... 118s (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 ... 58437 files and directories currently installed.) 118s Preparing to unpack .../0-openssh-sftp-server_1%3a9.6p1-3ubuntu17_armhf.deb ... 118s Unpacking openssh-sftp-server (1:9.6p1-3ubuntu17) over (1:9.6p1-3ubuntu15) ... 118s Preparing to unpack .../1-openssh-server_1%3a9.6p1-3ubuntu17_armhf.deb ... 118s Unpacking openssh-server (1:9.6p1-3ubuntu17) over (1:9.6p1-3ubuntu15) ... 119s Preparing to unpack .../2-openssh-client_1%3a9.6p1-3ubuntu17_armhf.deb ... 119s Unpacking openssh-client (1:9.6p1-3ubuntu17) over (1:9.6p1-3ubuntu15) ... 119s Preparing to unpack .../3-locales_2.39-3.1ubuntu3_all.deb ... 119s Unpacking locales (2.39-3.1ubuntu3) over (2.39-0ubuntu9) ... 119s Preparing to unpack .../4-openssl_3.2.2-1ubuntu1_armhf.deb ... 119s Unpacking openssl (3.2.2-1ubuntu1) over (3.2.1-3ubuntu1) ... 119s Preparing to unpack .../5-inetutils-telnet_2%3a2.5-5ubuntu1_armhf.deb ... 119s Unpacking inetutils-telnet (2:2.5-5ubuntu1) over (2:2.5-3ubuntu4) ... 119s Preparing to unpack .../6-telnet_0.17+2.5-5ubuntu1_all.deb ... 119s Unpacking telnet (0.17+2.5-5ubuntu1) over (0.17+2.5-3ubuntu4) ... 119s Setting up openssh-client (1:9.6p1-3ubuntu17) ... 119s Setting up inetutils-telnet (2:2.5-5ubuntu1) ... 119s Setting up locales (2.39-3.1ubuntu3) ... 120s Generating locales (this might take a while)... 122s en_US.UTF-8... done 122s Generation complete. 122s Setting up openssl (3.2.2-1ubuntu1) ... 122s Installing new version of config file /etc/ssl/openssl.cnf ... 122s Setting up openssh-sftp-server (1:9.6p1-3ubuntu17) ... 123s Setting up telnet (0.17+2.5-5ubuntu1) ... 123s Setting up openssh-server (1:9.6p1-3ubuntu17) ... 123s Installing new version of config file /etc/pam.d/sshd ... 125s Processing triggers for ufw (0.36.2-6) ... 126s Processing triggers for systemd (256-1ubuntu1) ... 127s Processing triggers for man-db (2.12.1-2) ... 128s Processing triggers for libc-bin (2.39-3.1ubuntu3) ... 128s Reading package lists... 129s Building dependency tree... 129s Reading state information... 129s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 132s autopkgtest [19:26:33]: rebooting testbed after setup commands that affected boot 202s autopkgtest [19:27:43]: testbed running kernel: Linux 6.5.0-41-generic #41~22.04.2-Ubuntu SMP PREEMPT_DYNAMIC Mon Jun 3 16:28:24 UTC 2 229s autopkgtest [19:28:10]: @@@@@@@@@@@@@@@@@@@@ apt-source knot-resolver 248s Get:1 http://ftpmaster.internal/ubuntu oracular/universe knot-resolver 5.7.3-1 (dsc) [3184 B] 248s Get:2 http://ftpmaster.internal/ubuntu oracular/universe knot-resolver 5.7.3-1 (tar) [1931 kB] 248s Get:3 http://ftpmaster.internal/ubuntu oracular/universe knot-resolver 5.7.3-1 (asc) [833 B] 248s Get:4 http://ftpmaster.internal/ubuntu oracular/universe knot-resolver 5.7.3-1 (diff) [401 kB] 248s gpgv: Signature made Tue Jun 4 18:13:51 2024 UTC 248s gpgv: using RSA key 23EBCF7E8FC47556787100DFA4254072E373042C 248s gpgv: Can't check signature: No public key 248s dpkg-source: warning: cannot verify inline signature for ./knot-resolver_5.7.3-1.dsc: no acceptable signature found 249s autopkgtest [19:28:30]: testing package knot-resolver version 5.7.3-1 251s autopkgtest [19:28:32]: build not needed 255s autopkgtest [19:28:36]: test roundtrip: preparing testbed 266s Reading package lists... 266s Building dependency tree... 266s Reading state information... 267s Starting pkgProblemResolver with broken count: 0 267s Starting 2 pkgProblemResolver with broken count: 0 267s Done 267s The following additional packages will be installed: 267s dns-root-data gnutls-bin knot-dnsutils knot-resolver libdnssec9t64 267s libevent-2.1-7t64 libfstrm0 libgnutls-dane0t64 libjemalloc2 libknot14t64 267s libluajit-5.1-2 libluajit-5.1-common libunbound8 libxdp1 libzscanner4t64 267s lua-sec lua-socket socat 267s Recommended packages: 267s knot-resolver-module-http lua-basexx lua-cqueues 267s The following NEW packages will be installed: 267s autopkgtest-satdep dns-root-data gnutls-bin knot-dnsutils knot-resolver 267s libdnssec9t64 libevent-2.1-7t64 libfstrm0 libgnutls-dane0t64 libjemalloc2 267s libknot14t64 libluajit-5.1-2 libluajit-5.1-common libunbound8 libxdp1 267s libzscanner4t64 lua-sec lua-socket socat 267s 0 upgraded, 19 newly installed, 0 to remove and 0 not upgraded. 267s Need to get 2812 kB/2813 kB of archives. 267s After this operation, 9144 kB of additional disk space will be used. 267s Get:1 /tmp/autopkgtest.w6NUpx/1-autopkgtest-satdep.deb autopkgtest-satdep armhf 0 [728 B] 268s Get:2 http://ftpmaster.internal/ubuntu oracular/main armhf dns-root-data all 2024041801 [4330 B] 268s Get:3 http://ftpmaster.internal/ubuntu oracular/main armhf libevent-2.1-7t64 armhf 2.1.12-stable-10 [127 kB] 268s Get:4 http://ftpmaster.internal/ubuntu oracular/main armhf libunbound8 armhf 1.19.2-1ubuntu3 [408 kB] 268s Get:5 http://ftpmaster.internal/ubuntu oracular/main armhf libgnutls-dane0t64 armhf 3.8.6-2ubuntu1 [33.8 kB] 268s Get:6 http://ftpmaster.internal/ubuntu oracular/universe armhf gnutls-bin armhf 3.8.6-2ubuntu1 [278 kB] 268s Get:7 http://ftpmaster.internal/ubuntu oracular/universe armhf libdnssec9t64 armhf 3.3.7-1 [48.0 kB] 268s Get:8 http://ftpmaster.internal/ubuntu oracular/main armhf libxdp1 armhf 1.4.2-1ubuntu4 [57.7 kB] 268s Get:9 http://ftpmaster.internal/ubuntu oracular/universe armhf libknot14t64 armhf 3.3.7-1 [207 kB] 268s Get:10 http://ftpmaster.internal/ubuntu oracular/universe armhf libzscanner4t64 armhf 3.3.7-1 [145 kB] 268s Get:11 http://ftpmaster.internal/ubuntu oracular/universe armhf libfstrm0 armhf 0.6.1-1build4 [17.5 kB] 268s Get:12 http://ftpmaster.internal/ubuntu oracular/universe armhf knot-dnsutils armhf 3.3.7-1 [223 kB] 268s Get:13 http://ftpmaster.internal/ubuntu oracular/universe armhf lua-socket armhf 3.1.0-1 [80.3 kB] 268s Get:14 http://ftpmaster.internal/ubuntu oracular/universe armhf lua-sec armhf 1.3.2-2 [36.2 kB] 268s Get:15 http://ftpmaster.internal/ubuntu oracular/universe armhf libjemalloc2 armhf 5.3.0-2build1 [200 kB] 268s Get:16 http://ftpmaster.internal/ubuntu oracular/universe armhf libluajit-5.1-common all 2.1.0+openresty20240626-1 [48.3 kB] 268s Get:17 http://ftpmaster.internal/ubuntu oracular/universe armhf libluajit-5.1-2 armhf 2.1.0+openresty20240626-1 [231 kB] 268s Get:18 http://ftpmaster.internal/ubuntu oracular/universe armhf knot-resolver armhf 5.7.3-1 [309 kB] 268s Get:19 http://ftpmaster.internal/ubuntu oracular/main armhf socat armhf 1.8.0.0-4build3 [359 kB] 268s Preconfiguring packages ... 269s Fetched 2812 kB in 1s (3562 kB/s) 269s Selecting previously unselected package dns-root-data. 269s (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 ... 58436 files and directories currently installed.) 269s Preparing to unpack .../00-dns-root-data_2024041801_all.deb ... 269s Unpacking dns-root-data (2024041801) ... 269s Selecting previously unselected package libevent-2.1-7t64:armhf. 269s Preparing to unpack .../01-libevent-2.1-7t64_2.1.12-stable-10_armhf.deb ... 269s Unpacking libevent-2.1-7t64:armhf (2.1.12-stable-10) ... 269s Selecting previously unselected package libunbound8:armhf. 269s Preparing to unpack .../02-libunbound8_1.19.2-1ubuntu3_armhf.deb ... 269s Unpacking libunbound8:armhf (1.19.2-1ubuntu3) ... 269s Selecting previously unselected package libgnutls-dane0t64:armhf. 269s Preparing to unpack .../03-libgnutls-dane0t64_3.8.6-2ubuntu1_armhf.deb ... 269s Unpacking libgnutls-dane0t64:armhf (3.8.6-2ubuntu1) ... 269s Selecting previously unselected package gnutls-bin. 269s Preparing to unpack .../04-gnutls-bin_3.8.6-2ubuntu1_armhf.deb ... 269s Unpacking gnutls-bin (3.8.6-2ubuntu1) ... 269s Selecting previously unselected package libdnssec9t64. 269s Preparing to unpack .../05-libdnssec9t64_3.3.7-1_armhf.deb ... 269s Unpacking libdnssec9t64 (3.3.7-1) ... 269s Selecting previously unselected package libxdp1:armhf. 269s Preparing to unpack .../06-libxdp1_1.4.2-1ubuntu4_armhf.deb ... 269s Unpacking libxdp1:armhf (1.4.2-1ubuntu4) ... 269s Selecting previously unselected package libknot14t64. 269s Preparing to unpack .../07-libknot14t64_3.3.7-1_armhf.deb ... 269s Unpacking libknot14t64 (3.3.7-1) ... 269s Selecting previously unselected package libzscanner4t64. 269s Preparing to unpack .../08-libzscanner4t64_3.3.7-1_armhf.deb ... 269s Unpacking libzscanner4t64 (3.3.7-1) ... 269s Selecting previously unselected package libfstrm0:armhf. 269s Preparing to unpack .../09-libfstrm0_0.6.1-1build4_armhf.deb ... 269s Unpacking libfstrm0:armhf (0.6.1-1build4) ... 269s Selecting previously unselected package knot-dnsutils. 269s Preparing to unpack .../10-knot-dnsutils_3.3.7-1_armhf.deb ... 269s Unpacking knot-dnsutils (3.3.7-1) ... 269s Selecting previously unselected package lua-socket:armhf. 269s Preparing to unpack .../11-lua-socket_3.1.0-1_armhf.deb ... 269s Unpacking lua-socket:armhf (3.1.0-1) ... 269s Selecting previously unselected package lua-sec:armhf. 269s Preparing to unpack .../12-lua-sec_1.3.2-2_armhf.deb ... 269s Unpacking lua-sec:armhf (1.3.2-2) ... 269s Selecting previously unselected package libjemalloc2:armhf. 269s Preparing to unpack .../13-libjemalloc2_5.3.0-2build1_armhf.deb ... 269s Unpacking libjemalloc2:armhf (5.3.0-2build1) ... 269s Selecting previously unselected package libluajit-5.1-common. 269s Preparing to unpack .../14-libluajit-5.1-common_2.1.0+openresty20240626-1_all.deb ... 269s Unpacking libluajit-5.1-common (2.1.0+openresty20240626-1) ... 269s Selecting previously unselected package libluajit-5.1-2:armhf. 269s Preparing to unpack .../15-libluajit-5.1-2_2.1.0+openresty20240626-1_armhf.deb ... 269s Unpacking libluajit-5.1-2:armhf (2.1.0+openresty20240626-1) ... 269s Selecting previously unselected package knot-resolver. 269s Preparing to unpack .../16-knot-resolver_5.7.3-1_armhf.deb ... 269s Unpacking knot-resolver (5.7.3-1) ... 269s Selecting previously unselected package socat. 269s Preparing to unpack .../17-socat_1.8.0.0-4build3_armhf.deb ... 269s Unpacking socat (1.8.0.0-4build3) ... 269s Selecting previously unselected package autopkgtest-satdep. 270s Preparing to unpack .../18-1-autopkgtest-satdep.deb ... 270s Unpacking autopkgtest-satdep (0) ... 270s Setting up libzscanner4t64 (3.3.7-1) ... 270s Setting up libfstrm0:armhf (0.6.1-1build4) ... 270s Setting up libevent-2.1-7t64:armhf (2.1.12-stable-10) ... 270s Setting up lua-socket:armhf (3.1.0-1) ... 270s Setting up libjemalloc2:armhf (5.3.0-2build1) ... 270s Setting up dns-root-data (2024041801) ... 270s Setting up libxdp1:armhf (1.4.2-1ubuntu4) ... 270s Setting up libunbound8:armhf (1.19.2-1ubuntu3) ... 270s Setting up libgnutls-dane0t64:armhf (3.8.6-2ubuntu1) ... 270s Setting up socat (1.8.0.0-4build3) ... 270s Setting up libdnssec9t64 (3.3.7-1) ... 270s Setting up libluajit-5.1-common (2.1.0+openresty20240626-1) ... 270s Setting up libknot14t64 (3.3.7-1) ... 270s Setting up gnutls-bin (3.8.6-2ubuntu1) ... 270s Setting up lua-sec:armhf (1.3.2-2) ... 270s Setting up knot-dnsutils (3.3.7-1) ... 270s Setting up libluajit-5.1-2:armhf (2.1.0+openresty20240626-1) ... 270s Setting up knot-resolver (5.7.3-1) ... 270s Created symlink '/etc/systemd/system/kresd.target.wants/kres-cache-gc.service' → '/usr/lib/systemd/system/kres-cache-gc.service'. 270s Created symlink '/etc/systemd/system/multi-user.target.wants/kresd.target' → '/usr/lib/systemd/system/kresd.target'. 271s Setting up autopkgtest-satdep (0) ... 271s Processing triggers for man-db (2.12.1-2) ... 271s Processing triggers for libc-bin (2.39-3.1ubuntu3) ... 283s (Reading database ... 58836 files and directories currently installed.) 283s Removing autopkgtest-satdep (0) ... 289s autopkgtest [19:29:10]: test roundtrip: [----------------------- 291s /usr/sbin/kresd + /usr/bin/kdig roundtrip tests 291s ------------ 291s workdir: /tmp/autopkgtest.w6NUpx/roundtrip-artifacts 291s IP addr: 127.202.188.160 291s kresd args: --addr=127.202.188.160@8053 --tls=127.202.188.160@8853 --noninteractive --config=/tmp/autopkgtest.w6NUpx/roundtrip-artifacts/kresd.conf --verbose --verbose --verbose 291s 291s make Certificate Authority key and certificate 291s ---------------------------------------------- 292s Generating a 3072 bit RSA private key... 292s Generating a self signed certificate... 292s X.509 Certificate Information: 292s Version: 3 292s Serial Number (hex): 2d44b2664ee7942076a702f6e961370cbb6a55fe 292s Validity: 292s Not Before: Fri Jul 12 19:29:13 UTC 2024 292s Not After: Wed Jul 24 19:29:13 UTC 2024 292s Subject: CN=testing certificate authority (NOT FOR PRODUCTION) 292s Subject Public Key Algorithm: RSA 292s Algorithm Security Level: High (3072 bits) 292s Modulus (bits 3072): 292s 00:c9:0d:8f:dd:90:ee:8d:bc:5e:ee:60:b7:ce:bf:8b 292s 21:78:7f:bf:9b:46:3f:33:b2:d2:e4:c1:54:35:75:fe 292s 12:6d:ea:a7:f8:93:75:b1:bd:03:61:53:88:50:e5:a0 292s bb:95:b2:16:bc:33:fc:58:4e:2b:f3:1f:ea:11:e0:bc 292s 59:84:3e:d5:03:22:2e:ee:af:80:07:11:6a:05:4c:60 292s 71:0c:42:fb:b4:8b:03:3c:3c:05:20:ee:f1:bd:37:df 292s b5:35:b2:a1:ee:f5:48:0e:88:b4:25:64:bc:3e:b2:b9 292s aa:10:88:29:dc:96:b2:aa:b2:47:e9:bf:b3:63:6c:db 292s 5b:e4:02:65:98:e7:84:d1:9d:ef:33:63:5e:61:9d:75 292s 0b:b0:1d:31:ef:b6:17:74:59:b8:8e:76:96:96:50:5d 292s 9e:7b:4d:ef:7e:6a:7f:f6:a0:c6:21:d7:0a:15:42:46 292s 39:ae:ee:91:48:98:34:45:09:fb:e4:49:1e:2f:4a:ef 292s cc:2b:07:b8:b1:78:1f:71:80:43:42:bf:78:56:1d:75 292s 4f:f2:9d:32:13:8b:29:3d:e7:b8:e0:79:8c:07:b9:97 292s 61:ed:ee:39:93:e7:f2:42:43:bd:59:5f:0d:db:dd:95 292s a0:9d:e5:23:9e:a5:19:86:78:14:77:f8:24:75:85:11 292s a8:6c:56:29:1d:f5:47:4f:56:62:58:46:bc:eb:2c:d8 292s 84:17:ba:5d:da:bf:77:d2:5a:44:3c:18:7c:07:68:eb 292s 26:b3:fb:f4:be:03:8e:87:59:c3:c5:ef:a4:3f:d9:41 292s f2:3a:3f:0b:c0:9f:9a:e6:83:81:d0:ca:be:82:2e:dc 292s 25:59:81:dd:c1:7d:2c:2f:2f:7c:a1:a0:2f:70:6a:3d 292s af:92:b8:70:87:03:67:31:e2:02:bc:84:80:ea:7a:16 292s 4b:ef:4f:32:cb:a0:3c:ef:bd:b7:3c:bb:b1:5b:91:4b 292s 75:dc:61:17:e8:29:45:24:81:74:de:31:f9:26:c2:be 292s d5 292s Exponent (bits 24): 292s 01:00:01 292s Extensions: 292s Basic Constraints (critical): 292s Certificate Authority (CA): TRUE 292s Path Length Constraint: 1 292s Name Constraints (critical): 292s Permitted: 292s DNSname: example 292s Key Usage (critical): 292s Certificate signing. 292s Subject Key Identifier (not critical): 292s e45a1328b5a61a3959e1bdaf0f912e113b976b85 292s Other Information: 292s Public Key ID: 292s sha1:e45a1328b5a61a3959e1bdaf0f912e113b976b85 292s sha256:c9549f82367ca6e662cb92cf1f3a044059e7b39ba87debd706f5b39e33d3c28b 292s Public Key PIN: 292s pin-sha256:yVSfgjZ8puZiy5LPHzoEQFnns5uofevXBvWznjPTwos= 292s 292s 292s 292s Signing certificate... 292s 292s make Bogus Certificate Authority key and certificate 292s ---------------------------------------------------- 293s Generating a 3072 bit RSA private key... 293s Generating a self signed certificate... 293s X.509 Certificate Information: 293s Version: 3 293s Serial Number (hex): 11f17015fbbe7809c0639a7fa8e4e1b8202522a5 293s Validity: 293s Not Before: Fri Jul 12 19:29:14 UTC 2024 293s Not After: Wed Jul 24 19:29:14 UTC 2024 293s Subject: CN=testing certificate authority (NOT FOR PRODUCTION) 293s Subject Public Key Algorithm: RSA 293s Algorithm Security Level: High (3072 bits) 293s Modulus (bits 3072): 293s 00:b6:b5:c8:e7:89:44:59:39:d2:7b:99:21:13:ad:b0 293s e8:f9:dd:90:f9:12:aa:38:f1:1b:0c:8a:af:64:11:df 293s 25:36:2b:e9:33:55:3c:8d:c3:93:19:0f:c2:9e:39:49 293s 9f:11:2f:91:42:55:83:44:eb:49:0a:37:f9:f0:e7:52 293s e3:65:5e:f9:fc:23:29:14:93:56:80:2c:74:4b:ca:fb 293s aa:4b:06:4a:75:30:59:03:95:87:e3:b9:21:a8:50:26 293s d3:8d:72:b4:fe:17:58:6a:6b:82:14:e3:36:43:35:20 293s b5:7b:34:fe:bd:e9:67:3f:29:5f:d1:8e:88:1d:41:5d 293s 97:dc:10:ed:7e:3b:6f:97:73:47:fb:b8:c4:4f:45:9a 293s fa:91:46:e3:4a:42:0c:e2:38:5d:ad:ab:8e:b9:41:11 293s 6f:a1:d6:39:a6:1d:89:59:93:60:b4:d5:30:6b:01:12 293s 8b:8e:82:bb:8a:85:30:54:60:47:86:98:79:dc:f7:a0 293s 4f:cb:74:a2:17:e3:0d:85:ed:d3:68:91:b7:fc:f8:b9 293s 05:f9:5b:0d:68:d1:de:42:35:10:6c:64:8c:e9:8b:0d 293s b9:62:24:46:30:8b:76:dd:e9:d3:5c:4e:10:81:13:91 293s 15:1c:6d:85:4f:81:24:2e:2c:b1:c6:9e:27:c0:bc:ec 293s 51:0e:3c:89:43:0b:1f:1c:43:00:53:03:69:35:8a:be 293s be:6b:40:3f:fb:bf:6f:ac:58:7c:db:c4:a2:61:fe:ed 293s 15:af:fa:99:b0:c5:a3:71:1c:ff:8f:37:1e:30:b7:96 293s 15:c9:33:a8:2a:88:d1:26:5e:47:ad:c6:46:e2:bc:7a 293s ff:fc:8e:8f:a2:7c:43:2f:2e:25:db:55:83:74:64:75 293s 5e:d7:9f:e2:9a:85:72:4d:2f:60:ec:d8:23:7d:f7:9a 293s d5:83:8e:b2:4e:65:ab:77:f8:67:73:06:d5:38:70:13 293s 37:ae:7b:ac:bd:66:d2:1a:76:86:e8:99:d2:85:b4:9b 293s c1 293s Exponent (bits 24): 293s 01:00:01 293s Extensions: 293s Basic Constraints (critical): 293s Certificate Authority (CA): TRUE 293s Path Length Constraint: 1 293s Name Constraints (critical): 293s Permitted: 293s DNSname: example 293s Key Usage (critical): 293s Certificate signing. 293s Subject Key Identifier (not critical): 293s 3db0d3dfcc8046c2b07b963d641fbf27a3daf0d7 293s Other Information: 293s Public Key ID: 293s sha1:3db0d3dfcc8046c2b07b963d641fbf27a3daf0d7 293s sha256:2bd29ed54c7b59fa4eff4f6e979d6c279f3e4758351ce7d52179f64b0d2b165a 293s Public Key PIN: 293s pin-sha256:K9Ke1Ux7WfpO/09ul51sJ58+R1g1HOfVIXn2Sw0rFlo= 293s 293s 293s 293s Signing certificate... 293s 293s make End Entity key and certificate 293s ----------------------------------- 294s Generating a 3072 bit RSA private key... 294s Generating a signed certificate... 294s X.509 Certificate Information: 294s Version: 3 294s Serial Number (hex): 50a2ca7d205479e4a9027d6b41c4f2db556eb4af 294s Validity: 294s Not Before: Fri Jul 12 19:29:15 UTC 2024 294s Not After: Mon Jul 22 19:29:15 UTC 2024 294s Subject: CN=test.example 294s Subject Public Key Algorithm: RSA 294s Algorithm Security Level: High (3072 bits) 294s Modulus (bits 3072): 294s 00:d6:5f:57:28:c4:59:3a:76:63:55:94:22:6d:a3:9a 294s 14:74:6b:fd:6f:1a:8d:a6:b8:75:7f:55:8e:e4:56:6b 294s d2:68:e3:73:e3:46:dc:57:eb:e0:26:cc:2f:00:6a:bc 294s 9a:6c:25:8c:8f:de:d0:f0:d4:23:bf:fd:fb:4e:62:59 294s d7:a0:ff:5e:c2:ff:49:8c:99:60:df:8b:39:df:1e:70 294s cc:61:15:de:bc:5d:2c:dd:99:85:e4:68:ac:60:9d:b4 294s 28:2c:45:d6:52:65:71:95:86:fa:22:08:43:d8:0c:a5 294s 20:64:52:39:50:c0:98:5e:10:90:b9:88:0e:58:9f:e9 294s 3b:e9:85:99:19:2b:db:63:14:7d:70:f3:10:b1:92:98 294s e6:67:e7:ce:d8:1d:4c:9c:17:3a:67:bd:fd:53:72:a5 294s 8a:62:a7:77:01:a1:7a:5b:cd:e4:ae:1e:e4:54:96:b2 294s 0f:5b:37:13:9f:b4:22:31:9b:69:8f:a4:73:b9:1e:1a 294s 0d:d6:66:df:2a:55:b3:5c:66:82:a4:b9:3c:e4:bb:b2 294s 8f:8f:a9:54:bf:58:43:b4:b7:05:97:da:47:5a:6d:5a 294s b6:7c:28:a1:17:f1:f1:d5:4d:7b:34:0f:04:13:ce:35 294s 28:b4:7a:3b:5e:4c:1b:45:3c:23:a3:3e:05:a2:6e:13 294s 8b:d2:c3:73:fb:7a:62:0d:b5:5d:b1:2e:5a:62:9c:00 294s ad:e0:d7:b7:45:5e:7a:7e:90:4e:97:7b:7b:16:b6:75 294s c6:97:b8:b2:16:3f:09:da:a6:1a:af:14:8b:27:06:60 294s 76:7b:84:b6:8e:b3:b9:2a:b6:0b:43:85:98:1a:bc:2e 294s fc:a0:ff:3e:aa:11:86:53:32:76:9b:c3:c9:43:ef:30 294s 21:33:16:13:76:1a:e1:7f:c4:8f:bd:02:41:49:da:e4 294s fa:62:31:82:1b:10:e5:11:fb:48:e1:ad:c4:f1:43:27 294s 8b:95:f3:02:53:44:61:c6:ae:d1:11:63:33:9a:af:68 294s 9f 294s Exponent (bits 24): 294s 01:00:01 294s Extensions: 294s Basic Constraints (critical): 294s Certificate Authority (CA): FALSE 294s Subject Alternative Name (not critical): 294s DNSname: test.example 294s Key Purpose (not critical): 294s TLS WWW Server. 294s Key Usage (critical): 294s Digital signature. 294s Subject Key Identifier (not critical): 294s 6bc62029b586e09f4f811fd4c1cedcd64bf8654e 294s Authority Key Identifier (not critical): 294s e45a1328b5a61a3959e1bdaf0f912e113b976b85 294s Other Information: 294s Public Key ID: 294s sha1:6bc62029b586e09f4f811fd4c1cedcd64bf8654e 294s sha256:61b0cd88df9f746a6a5670f2baa476104b5c62cc7a0ead8991503f20482d94ce 294s Public Key PIN: 294s pin-sha256:YbDNiN+fdGpqVnDyuqR2EEtcYsx6Dq2JkVA/IEgtlM4= 294s 294s 294s 294s Signing certificate... 294s 294s set up kresd daemon on 127.202.188.160 on ports 8053 (UDP, TCP) and 8853 (TLS) 294s ------------------------------------------------------------------------------ 295s 295s test UDP with kdig 295s ------------------ 295s successful UDP request to 127.202.188.160 on port 8053 295s 295s test TCP with kdig 295s ------------------ 295s successful TCP request to 127.202.188.160 on port 8053 295s 295s test opportunistic DNS-over-TLS with kdig 295s ----------------------------------------- 295s successful opportunistic DNS-over-TLS request to 127.202.188.160 on port 8853 295s 295s test strict DNS-over-TLS with kdig 295s ---------------------------------- 295s successful strict DNS-over-TLS request to 127.202.188.160 on port 8853 295s 295s test invalid name with strict DNS-over-TLS with kdig 295s ---------------------------------------------------- 295s successful strict DNS-over-TLS request failure when name mismatch to 127.202.188.160 on port 8853 295s 295s test bad authority with strict DNS-over-TLS with kdig 295s ----------------------------------------------------- 295s successful strict DNS-over-TLS request failure to 127.202.188.160 on port 8853 295s 295s cleaning up 295s ----------- 295s 1933 0 drwxrwxrwt 2 root root 340 Jul 12 19:29 /tmp/autopkgtest.w6NUpx/roundtrip-artifacts 295s 1955 4 -rw-r--r-- 1 root root 121 Jul 12 19:29 /tmp/autopkgtest.w6NUpx/roundtrip-artifacts/badca.err 295s 1954 4 -rw-r--r-- 1 root root 121 Jul 12 19:29 /tmp/autopkgtest.w6NUpx/roundtrip-artifacts/badname.err 295s 1953 102400 -rw-r----- 1 root root 104857600 Jul 12 19:29 /tmp/autopkgtest.w6NUpx/roundtrip-artifacts/data.mdb 295s 1952 4 -rw-r----- 1 root root 8192 Jul 12 19:29 /tmp/autopkgtest.w6NUpx/roundtrip-artifacts/lock.mdb 295s 1951 72 -rw-r--r-- 1 root root 70142 Jul 12 19:29 /tmp/autopkgtest.w6NUpx/roundtrip-artifacts/kresd.err 295s 1950 4 -rw-r--r-- 1 root root 387 Jul 12 19:29 /tmp/autopkgtest.w6NUpx/roundtrip-artifacts/kresd.conf 295s 1949 4 -rw-r--r-- 1 root root 1602 Jul 12 19:29 /tmp/autopkgtest.w6NUpx/roundtrip-artifacts/ee-cert.pem 295s 1948 4 -rw-r--r-- 1 root root 2218 Jul 12 19:29 /tmp/autopkgtest.w6NUpx/roundtrip-artifacts/ee-pubkey.pem 295s 1947 8 -rw------- 1 root root 8177 Jul 12 19:29 /tmp/autopkgtest.w6NUpx/roundtrip-artifacts/ee-key.pem 295s 1946 4 -rw-r--r-- 1 root root 92 Jul 12 19:29 /tmp/autopkgtest.w6NUpx/roundtrip-artifacts/ee.template 295s 1945 4 -rw-r--r-- 1 root root 1590 Jul 12 19:29 /tmp/autopkgtest.w6NUpx/roundtrip-artifacts/bogus-cert.pem 295s 1944 8 -rw------- 1 root root 8177 Jul 12 19:29 /tmp/autopkgtest.w6NUpx/roundtrip-artifacts/bogus-key.pem 295s 1943 4 -rw-r--r-- 1 root root 1590 Jul 12 19:29 /tmp/autopkgtest.w6NUpx/roundtrip-artifacts/ca-cert.pem 295s 1942 8 -rw------- 1 root root 8180 Jul 12 19:29 /tmp/autopkgtest.w6NUpx/roundtrip-artifacts/ca-key.pem 295s 1941 4 -rw-r--r-- 1 root root 136 Jul 12 19:29 /tmp/autopkgtest.w6NUpx/roundtrip-artifacts/ca.template 295s ==> /tmp/autopkgtest.w6NUpx/roundtrip-artifacts/badca.err <== 295s ;; WARNING: TLS, handshake failed (Error in the certificate.) 295s ;; ERROR: failed to query server 127.202.188.160@8853(TCP) 295s 295s ==> /tmp/autopkgtest.w6NUpx/roundtrip-artifacts/badname.err <== 295s ;; WARNING: TLS, handshake failed (Error in the certificate.) 295s ;; ERROR: failed to query server 127.202.188.160@8853(TCP) 295s 295s ==> /tmp/autopkgtest.w6NUpx/roundtrip-artifacts/kresd.err <== 295s [system] increasing file-descriptor limit: 1024 -> 1048576 295s [tls ] session ticket: epoch 420120, scheduling rotation check in 3060281 ms 295s [wtchdg] disabled in systemd (WatchdogSec= not specified) 295s [ta ] installed trust anchors for domain . are: 295s . 86400 DNSKEY 257 3 8 AwEAAaz/tAm8yTn4Mfeh5eyI96WSVexTBAvkMgJzkKTOiW1vkIbzxeF3+/4RgWOq7HrxRixHlFlExOLAJr5emLvN7SWXgnLh4+B5xQlNVz8Og8kvArMtNROxVQuCaSnIDdD5LKyWbRd2n9WGe2R8PzgCmr3EgVLrjyBxWezF0jLHwVN8efS3rCj/EWgvIWgb9tarpVUDK/b58Da+sqqls3eNbuv7pr+eoZG+SrDK6nWeL3c6H5Apxz7LjVc1uTIdsIXxuOLYA4/ilBmSVIzuDWfdRUfhHdY6+cn8HFRm+2hM8AnXGXws9555KrUB5qihylGa8subX2Nn6UwNR1AkUTV74bU= ; Valid: ; KeyTag:20326 295s 295s [system] loading config '/tmp/autopkgtest.w6NUpx/roundtrip-artifacts/kresd.conf' (workdir '/tmp/autopkgtest.w6NUpx/roundtrip-artifacts') 295s [system] deprecation WARNING: use log_level() instead of verbose() 295s [gnutls] (3) ASSERT: ../../../lib/x509/x509_ext.c[gnutls_subject_alt_names_get]:111 295s [gnutls] (3) ASSERT: ../../../lib/x509/x509.c[get_alt_name]:2012 295s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 295s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 295s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 295s [tls ] RFC 7858 OOB key-pin (0): pin-sha256="" 295s [gnutls] (3) ASSERT: ../../lib/cert-cred-x509.c[gnutls_certificate_get_x509_crt]:872 295s [system] loading config '/usr/lib/arm-linux-gnueabihf/knot-resolver/postconfig.lua' (workdir '/tmp/autopkgtest.w6NUpx/roundtrip-artifacts') 295s [plan ][00000.00] plan '.' type 'NS' uid [65536.00] 295s [iterat][65536.00] '.' type 'NS' new uid was assigned .01, parent uid .00 295s [resolv][65536.01] => using root hints 295s [iterat][65536.01] '.' type 'NS' new uid was assigned .02, parent uid .00 295s [resolv][65536.02] >< TA: '.' 295s [plan ][65536.02] plan '.' type 'DNSKEY' uid [65536.03] 295s [iterat][65536.03] '.' type 'DNSKEY' new uid was assigned .04, parent uid .02 295s [select][65536.04] => id: '53282' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 295s [select][65536.04] => id: '53282' choosing: 'A.ROOT-SERVERS.NET.'@'198.41.0.4#00053' with timeout 400 ms zone cut: '.' 295s [resolv][65536.04] => id: '53282' querying: 'A.ROOT-SERVERS.NET.'@'198.41.0.4#00053' zone cut: '.' qname: '.' qtype: 'DNSKEY' proto: 'udp' 295s [plan ][00000.00] plan '.' type 'NS' uid [65537.00] 295s [iterat][65537.00] '.' type 'NS' new uid was assigned .01, parent uid .00 295s [resolv][65537.01] => using root hints 295s [iterat][65537.01] '.' type 'NS' new uid was assigned .02, parent uid .00 295s [select][65537.02] => id: '65517' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 295s [select][65537.02] => id: '65517' choosing: 'K.ROOT-SERVERS.NET.'@'193.0.14.129#00053' with timeout 400 ms zone cut: '.' 295s [resolv][65537.02] => id: '65517' querying: 'K.ROOT-SERVERS.NET.'@'193.0.14.129#00053' zone cut: '.' qname: '.' qtype: 'NS' proto: 'udp' 295s [taupd ] refreshing TA for . 295s [plan ][00000.00] plan '.' type 'DNSKEY' uid [65538.00] 295s [iterat][65538.00] '.' type 'DNSKEY' new uid was assigned .01, parent uid .00 295s [resolv][65538.01] => using root hints 295s [iterat][65538.01] '.' type 'DNSKEY' new uid was assigned .02, parent uid .00 295s [resolv][65538.02] >< TA: '.' 295s [select][65538.02] => id: '54312' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 295s [select][65538.02] => id: '54312' choosing: 'J.ROOT-SERVERS.NET.'@'2001:503:c27::2:30#00053' with timeout 400 ms zone cut: '.' 295s [select][65536.04] => id: '53282' noting selection error: 'A.ROOT-SERVERS.NET.'@'198.41.0.4#00053' zone cut: '.' error: 1 QUERY_TIMEOUT 295s [iterat][65538.02] '.' type 'DNSKEY' new uid was assigned .03, parent uid .00 295s [select][65538.03] => id: '21594' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 295s [select][65538.03] => id: '21594' choosing: 'D.ROOT-SERVERS.NET.'@'2001:500:2d::d#00053' with timeout 400 ms zone cut: '.' 295s [resolv][65538.03] => id: '21594' querying: 'D.ROOT-SERVERS.NET.'@'2001:500:2d::d#00053' zone cut: '.' qname: '.' qtype: 'DNSKEY' proto: 'udp' 295s [iterat][65536.04] '.' type 'DNSKEY' new uid was assigned .05, parent uid .02 295s [select][65536.05] => id: '55583' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 295s [select][65536.05] => id: '55583' choosing: 'D.ROOT-SERVERS.NET.'@'2001:500:2d::d#00053' with timeout 800 ms zone cut: '.' 295s [select][65537.02] => id: '65517' noting selection error: 'K.ROOT-SERVERS.NET.'@'193.0.14.129#00053' zone cut: '.' error: 1 QUERY_TIMEOUT 295s [iterat][65537.02] '.' type 'NS' new uid was assigned .03, parent uid .00 295s [select][65537.03] => id: '63090' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 295s [select][65537.03] => id: '63090' choosing: 'D.ROOT-SERVERS.NET.'@'199.7.91.13#00053' with timeout 800 ms zone cut: '.' 295s [resolv][65537.03] => id: '63090' querying: 'D.ROOT-SERVERS.NET.'@'199.7.91.13#00053' zone cut: '.' qname: '.' qtype: 'NS' proto: 'udp' 295s [select][65538.03] NO6: timed out, appended, timeouts 1/6 295s [select][65538.03] => id: '21594' noting selection error: 'D.ROOT-SERVERS.NET.'@'2001:500:2d::d#00053' zone cut: '.' error: 1 QUERY_TIMEOUT 295s [iterat][65536.05] '.' type 'DNSKEY' new uid was assigned .06, parent uid .02 295s [select][65536.06] => id: '09435' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 295s [select][65536.06] => id: '09435' choosing: 'F.ROOT-SERVERS.NET.'@'192.5.5.241#00053' with timeout 800 ms zone cut: '.' 295s [resolv][65536.06] => id: '09435' querying: 'F.ROOT-SERVERS.NET.'@'192.5.5.241#00053' zone cut: '.' qname: '.' qtype: 'DNSKEY' proto: 'udp' 295s [iterat][65538.03] '.' type 'DNSKEY' new uid was assigned .04, parent uid .00 295s [select][65538.04] => id: '06761' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 295s [select][65538.04] => id: '06761' choosing: 'D.ROOT-SERVERS.NET.'@'199.7.91.13#00053' with timeout 800 ms zone cut: '.' 295s [plan ][00000.00] plan 'monkeys.example.' type 'A' uid [31157.00] 295s [iterat][31157.00] 'monkeys.example.' type 'A' new uid was assigned .01, parent uid .00 295s [hint ][31157.01] <= answered from hints 295s [iterat][31157.01] <= rcode: NOERROR 295s [resolv][31157.01] AD: request NOT classified as SECURE 295s [resolv][31157.01] finished in state: 4, queries: 1, mempool: 16392 B 295s [plan ][00000.00] plan 'monkeys.example.' type 'A' uid [12637.00] 295s [iterat][12637.00] 'monkeys.example.' type 'A' new uid was assigned .01, parent uid .00 295s [hint ][12637.01] <= answered from hints 295s [iterat][12637.01] <= rcode: NOERROR 295s [resolv][12637.01] AD: request NOT classified as SECURE 295s [resolv][12637.01] finished in state: 4, queries: 1, mempool: 81936 B 295s [io ] => connection to '127.0.0.1#34459' closed by peer (end of file) 295s [gnutls] (5) REC[0xe66b0000]: Allocating epoch #0 295s [gnutls] (2) added 3 protocols, 29 ciphersuites, 19 sig algos and 10 groups into priority list 295s [gnutls] (5) REC[0xe66b0000]: Allocating epoch #1 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 295s [gnutls] (5) REC[0xe66b0000]: SSL 3.3 Handshake packet received. Epoch 0, length: 374 295s [gnutls] (5) REC[0xe66b0000]: Expected Packet Handshake(22) 295s [gnutls] (5) REC[0xe66b0000]: Received Packet Handshake(22) with length: 374 295s [gnutls] (5) REC[0xe66b0000]: Decrypted Packet[0] Handshake(22) with length: 374 295s [gnutls] (4) HSK[0xe66b0000]: CLIENT HELLO (1) was received. Length 370[370], frag offset 0, frag length: 370, sequence: 0 295s [gnutls] (4) HSK[0xe66b0000]: Client's version: 3.3 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Supported Versions/43' (5 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Found version: 3.4 295s [gnutls] (4) EXT[0xe66b0000]: Found version: 3.3 295s [gnutls] (4) EXT[0xe66b0000]: Negotiated version: 3.4 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'ALPN/16' (6 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Record Size Limit/28' (2 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: record_size_limit 16385 negotiated 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Encrypt-then-MAC/22' (0 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Extended Master Secret/23' (0 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Safe Renegotiation/65281' (1 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'PSK Key Exchange Modes/45' (3 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: PSK KE mode 01 received 295s [gnutls] (4) EXT[0xe66b0000]: PSK KE mode 00 received 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Supported Groups/10' (22 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Received group SECP256R1 (0x17) 295s [gnutls] (4) EXT[0xe66b0000]: Received group SECP384R1 (0x18) 295s [gnutls] (4) EXT[0xe66b0000]: Received group SECP521R1 (0x19) 295s [gnutls] (4) EXT[0xe66b0000]: Received group X25519 (0x1d) 295s [gnutls] (4) EXT[0xe66b0000]: Received group X448 (0x1e) 295s [gnutls] (4) EXT[0xe66b0000]: Received group FFDHE2048 (0x100) 295s [gnutls] (4) EXT[0xe66b0000]: Received group FFDHE3072 (0x101) 295s [gnutls] (4) EXT[0xe66b0000]: Received group FFDHE4096 (0x102) 295s [gnutls] (4) EXT[0xe66b0000]: Received group FFDHE6144 (0x103) 295s [gnutls] (4) EXT[0xe66b0000]: Received group FFDHE8192 (0x104) 295s [gnutls] (4) EXT[0xe66b0000]: Selected group SECP256R1 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Supported EC Point Formats/11' (2 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Session Ticket/35' (0 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Signature Algorithms/13' (34 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (4.1) RSA-SHA256 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.9) RSA-PSS-SHA256 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.4) RSA-PSS-RSAE-SHA256 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (4.3) ECDSA-SECP256R1-SHA256 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.7) EdDSA-Ed25519 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (5.1) RSA-SHA384 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.10) RSA-PSS-SHA384 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.5) RSA-PSS-RSAE-SHA384 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (5.3) ECDSA-SECP384R1-SHA384 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.8) EdDSA-Ed448 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (6.1) RSA-SHA512 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.11) RSA-PSS-SHA512 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.6) RSA-PSS-RSAE-SHA512 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (6.3) ECDSA-SECP521R1-SHA512 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (2.1) RSA-SHA1 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (2.3) ECDSA-SHA1 295s [gnutls] (2) checking 13.02 (GNUTLS_AES_256_GCM_SHA384) for compatibility 295s [gnutls] (3) ASSERT: ../../../lib/ext/server_name.c[gnutls_server_name_get]:234 295s [gnutls] (4) HSK[0xe66b0000]: Requested server name: '' 295s [gnutls] (4) HSK[0xe66b0000]: checking compat of GNUTLS_AES_256_GCM_SHA384 with certificate[0] (RSA/X.509) 295s [gnutls] (4) checking cert compat with RSA-SHA256 295s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 295s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 295s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 295s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 295s [gnutls] (4) Selected signature algorithm: RSA-PSS-RSAE-SHA256 295s [gnutls] (2) Selected (RSA) cert based on ciphersuite 13.2: GNUTLS_AES_256_GCM_SHA384 295s [gnutls] (4) HSK[0xe66b0000]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384 295s [gnutls] (4) HSK[0xe66b0000]: Selected version TLS1.3 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'OCSP Status Request/5' (5 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: OCSP status was requested 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Key Share/51' (107 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Received key share for SECP256R1 295s [gnutls] (4) HSK[0xe66b0000]: Selected group SECP256R1 (2) 295s [gnutls] (2) EXT[0xe66b0000]: server generated SECP256R1 shared key 295s [gnutls] (4) HSK[0xe66b0000]: Safe renegotiation succeeded 295s [gnutls] (4) HSK[0xe66b0000]: SessionID: a57f23a74e8209d6c51f19ea91abf0366f912cc644baaef62da3268f02a514e6 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (ALPN/16) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Server Name Indication/0) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Server Certificate Type/20) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Early Data/42) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (OCSP Status Request/5) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Maximum Record Size/1) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Session Ticket/35) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (PSK Key Exchange Modes/45) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Compress Certificate/27) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Encrypt-then-MAC/22) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Supported Versions/43) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Sending extension Supported Versions/43 (2 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Key Share/51) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: sending key share for SECP256R1 295s [gnutls] (4) EXT[0xe66b0000]: Sending extension Key Share/51 (69 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Supported Groups/10) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Cookie/44) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Supported EC Point Formats/11) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Record Size Limit/28) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (SRTP/14) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Extended Master Secret/23) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Signature Algorithms/13) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Client Certificate Type/19) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Post Handshake Auth/49) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Safe Renegotiation/65281) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (ClientHello Padding/21) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Pre Shared Key/41) for 'TLS 1.3 server hello' 295s [gnutls] (4) HSK[0xe66b0000]: SERVER HELLO was queued [155 bytes] 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 155 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 160 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6 295s [gnutls] (4) REC[0xe66b0000]: Sent ChangeCipherSpec 295s [gnutls] (5) REC[0xe66b0000]: Initializing epoch #1 295s [gnutls] (5) REC[0xe66b0000]: Epoch #1 ready 295s [gnutls] (4) HSK[0xe66b0000]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Supported Groups/10) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Post Handshake Auth/49) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (PSK Key Exchange Modes/45) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Safe Renegotiation/65281) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Session Ticket/35) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Encrypt-then-MAC/22) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Supported Versions/43) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Key Share/51) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Server Certificate Type/20) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Maximum Record Size/1) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (ALPN/16) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Sending extension ALPN/16 (6 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Cookie/44) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Client Certificate Type/19) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (SRTP/14) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Server Name Indication/0) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Early Data/42) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Signature Algorithms/13) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Record Size Limit/28) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Sending extension Record Size Limit/28 (2 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (OCSP Status Request/5) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Compress Certificate/27) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Extended Master Secret/23) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Supported EC Point Formats/11) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (ClientHello Padding/21) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Pre Shared Key/41) for 'encrypted extensions' 295s [gnutls] (4) HSK[0xe66b0000]: ENCRYPTED EXTENSIONS was queued [22 bytes] 295s [gnutls] (4) HSK[0xe66b0000]: CERTIFICATE was queued [1155 bytes] 295s [gnutls] (4) checking cert compat with RSA-SHA256 295s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 295s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 295s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 295s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 295s [gnutls] (4) HSK[0xe66b0000]: signing TLS 1.3 handshake data: using RSA-PSS-RSAE-SHA256 and PRF: SHA384 295s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 295s [gnutls] (4) HSK[0xe66b0000]: CERTIFICATE VERIFY was queued [392 bytes] 295s [gnutls] (4) HSK[0xe66b0000]: sending finished 295s [gnutls] (4) HSK[0xe66b0000]: FINISHED was queued [52 bytes] 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 22 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 44 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 1155 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[2] Handshake(22) in epoch 1 and length: 1177 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 392 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[3] Handshake(22) in epoch 1 and length: 414 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 52 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[4] Handshake(22) in epoch 1 and length: 74 295s [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:965 295s [gnutls] (5) REC[0xe66b0000]: Allocating epoch #2 295s [gnutls] (4) HSK[0xe66b0000]: unauthenticated session eligible for early start 295s [gnutls] (5) REC[0xe66b0000]: Initializing epoch #2 295s [gnutls] (5) REC[0xe66b0000]: Epoch #2 ready 295s [gnutls] (4) HSK[0xe66b0000]: TLS 1.3 set write key with cipher suite: GNUTLS_AES_256_GCM_SHA384 295s [gnutls] (4) HSK[0xe66b0000]: switching early to application traffic keys 295s [gnutls] (4) HSK[0xe66b0000]: NEW SESSION TICKET was queued [251 bytes] 295s [gnutls] (4) HSK[0xe66b0000]: NEW SESSION TICKET was queued [251 bytes] 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[1] Handshake(22) in epoch 2 and length: 273 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[2] Handshake(22) in epoch 2 and length: 273 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 295s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 295s [gnutls] (5) REC[0xe66b0000]: SSL 3.3 ChangeCipherSpec packet received. Epoch 1, length: 1 295s [gnutls] (5) REC[0xe66b0000]: Expected Packet Handshake(22) 295s [gnutls] (5) REC[0xe66b0000]: Received Packet ChangeCipherSpec(20) with length: 1 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 295s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 295s [gnutls] (5) REC[0xe66b0000]: SSL 3.3 Application Data packet received. Epoch 1, length: 69 295s [gnutls] (5) REC[0xe66b0000]: Expected Packet Handshake(22) 295s [gnutls] (5) REC[0xe66b0000]: Received Packet Application Data(23) with length: 69 295s [gnutls] (5) REC[0xe66b0000]: Decrypted Packet[0] Handshake(22) with length: 52 295s [gnutls] (4) HSK[0xe66b0000]: FINISHED (20) was received. Length 48[48], frag offset 0, frag length: 48, sequence: 0 295s [gnutls] (4) HSK[0xe66b0000]: parsing finished 295s [gnutls] (4) HSK[0xe66b0000]: TLS 1.3 set read key with cipher suite: GNUTLS_AES_256_GCM_SHA384 295s [gnutls] (5) REC[0xe66b0000]: Start of epoch cleanup 295s [gnutls] (5) REC[0xe66b0000]: Epoch #0 freed 295s [gnutls] (5) REC[0xe66b0000]: Epoch #1 freed 295s [gnutls] (5) REC[0xe66b0000]: End of epoch cleanup 295s [tls ] TLS handshake with 127.0.0.1#40847 has completed 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 295s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1759 295s [gnutls] (5) REC[0xe66b0000]: SSL 3.3 Application Data packet received. Epoch 2, length: 147 295s [gnutls] (5) REC[0xe66b0000]: Expected Packet Application Data(23) 295s [gnutls] (5) REC[0xe66b0000]: Received Packet Application Data(23) with length: 147 295s [gnutls] (5) REC[0xe66b0000]: Decrypted Packet[0] Application Data(23) with length: 130 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 295s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1759 295s [plan ][00000.00] plan 'monkeys.example.' type 'A' uid [19964.00] 295s [iterat][19964.00] 'monkeys.example.' type 'A' new uid was assigned .01, parent uid .00 295s [hint ][19964.01] <= answered from hints 295s [iterat][19964.01] <= rcode: NOERROR 295s [resolv][19964.01] AD: request NOT classified as SECURE 295s [resolv][19964.01] finished in state: 4, queries: 1, mempool: 81936 B 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Application Data(23) with length: 470 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[3] Application Data(23) in epoch 2 and length: 492 295s [gnutls] (5) REC[0xe66b0000]: SSL 3.3 Application Data packet received. Epoch 2, length: 19 295s [gnutls] (5) REC[0xe66b0000]: Expected Packet Application Data(23) 295s [gnutls] (5) REC[0xe66b0000]: Received Packet Application Data(23) with length: 19 295s [gnutls] (5) REC[0xe66b0000]: Decrypted Packet[1] Alert(21) with length: 2 295s [gnutls] (5) REC[0xe66b0000]: Alert[1|0] - Close notify - was received 295s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_in_buffers]:1565 295s [io ] => connection to '127.0.0.1#40847' closed by peer (end of file) 295s [gnutls] (5) REC[0xe66b0000]: Start of epoch cleanup 295s [gnutls] (5) REC[0xe66b0000]: End of epoch cleanup 295s [gnutls] (5) REC[0xe66b0000]: Epoch #2 freed 295s [gnutls] (5) REC[0xe66b0000]: Allocating epoch #0 295s [gnutls] (2) added 3 protocols, 29 ciphersuites, 19 sig algos and 10 groups into priority list 295s [gnutls] (5) REC[0xe66b0000]: Allocating epoch #1 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 295s [gnutls] (5) REC[0xe66b0000]: SSL 3.3 Handshake packet received. Epoch 0, length: 395 295s [gnutls] (5) REC[0xe66b0000]: Expected Packet Handshake(22) 295s [gnutls] (5) REC[0xe66b0000]: Received Packet Handshake(22) with length: 395 295s [gnutls] (5) REC[0xe66b0000]: Decrypted Packet[0] Handshake(22) with length: 395 295s [gnutls] (4) HSK[0xe66b0000]: CLIENT HELLO (1) was received. Length 391[391], frag offset 0, frag length: 391, sequence: 0 295s [gnutls] (4) HSK[0xe66b0000]: Client's version: 3.3 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Supported Versions/43' (5 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Found version: 3.4 295s [gnutls] (4) EXT[0xe66b0000]: Found version: 3.3 295s [gnutls] (4) EXT[0xe66b0000]: Negotiated version: 3.4 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'ALPN/16' (6 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Safe Renegotiation/65281' (1 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Encrypt-then-MAC/22' (0 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Server Name Indication/0' (17 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Extended Master Secret/23' (0 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Record Size Limit/28' (2 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: record_size_limit 16385 negotiated 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Supported Groups/10' (22 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Received group SECP256R1 (0x17) 295s [gnutls] (4) EXT[0xe66b0000]: Received group SECP384R1 (0x18) 295s [gnutls] (4) EXT[0xe66b0000]: Received group SECP521R1 (0x19) 295s [gnutls] (4) EXT[0xe66b0000]: Received group X25519 (0x1d) 295s [gnutls] (4) EXT[0xe66b0000]: Received group X448 (0x1e) 295s [gnutls] (4) EXT[0xe66b0000]: Received group FFDHE2048 (0x100) 295s [gnutls] (4) EXT[0xe66b0000]: Received group FFDHE3072 (0x101) 295s [gnutls] (4) EXT[0xe66b0000]: Received group FFDHE4096 (0x102) 295s [gnutls] (4) EXT[0xe66b0000]: Received group FFDHE6144 (0x103) 295s [gnutls] (4) EXT[0xe66b0000]: Received group FFDHE8192 (0x104) 295s [gnutls] (4) EXT[0xe66b0000]: Selected group SECP256R1 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Supported EC Point Formats/11' (2 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Signature Algorithms/13' (34 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (4.1) RSA-SHA256 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.9) RSA-PSS-SHA256 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.4) RSA-PSS-RSAE-SHA256 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (4.3) ECDSA-SECP256R1-SHA256 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.7) EdDSA-Ed25519 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (5.1) RSA-SHA384 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.10) RSA-PSS-SHA384 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.5) RSA-PSS-RSAE-SHA384 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (5.3) ECDSA-SECP384R1-SHA384 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.8) EdDSA-Ed448 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (6.1) RSA-SHA512 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.11) RSA-PSS-SHA512 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.6) RSA-PSS-RSAE-SHA512 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (6.3) ECDSA-SECP521R1-SHA512 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (2.1) RSA-SHA1 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (2.3) ECDSA-SHA1 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Session Ticket/35' (0 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'PSK Key Exchange Modes/45' (3 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: PSK KE mode 01 received 295s [gnutls] (4) EXT[0xe66b0000]: PSK KE mode 00 received 295s [gnutls] (2) checking 13.02 (GNUTLS_AES_256_GCM_SHA384) for compatibility 295s [gnutls] (4) HSK[0xe66b0000]: Requested server name: 'test.example' 295s [gnutls] (4) checking cert compat with RSA-SHA256 295s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 295s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 295s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 295s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 295s [gnutls] (4) Selected signature algorithm: RSA-PSS-RSAE-SHA256 295s [gnutls] (2) Selected (RSA) cert based on ciphersuite 13.2: GNUTLS_AES_256_GCM_SHA384 295s [gnutls] (4) HSK[0xe66b0000]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384 295s [gnutls] (4) HSK[0xe66b0000]: Selected version TLS1.3 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Key Share/51' (107 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Received key share for SECP256R1 295s [gnutls] (4) HSK[0xe66b0000]: Selected group SECP256R1 (2) 295s [gnutls] (2) EXT[0xe66b0000]: server generated SECP256R1 shared key 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'OCSP Status Request/5' (5 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: OCSP status was requested 295s [gnutls] (4) HSK[0xe66b0000]: Safe renegotiation succeeded 295s [gnutls] (4) HSK[0xe66b0000]: SessionID: 3d392f6c6c9734d354af81035489f15b50d205a17ebcd244177fbc2260ba1e71 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Safe Renegotiation/65281) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Encrypt-then-MAC/22) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Extended Master Secret/23) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Record Size Limit/28) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Server Name Indication/0) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Early Data/42) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Post Handshake Auth/49) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Compress Certificate/27) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Supported EC Point Formats/11) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (SRTP/14) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Signature Algorithms/13) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Supported Groups/10) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Cookie/44) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Server Certificate Type/20) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Session Ticket/35) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Client Certificate Type/19) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Maximum Record Size/1) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (ALPN/16) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Supported Versions/43) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Sending extension Supported Versions/43 (2 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Key Share/51) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: sending key share for SECP256R1 295s [gnutls] (4) EXT[0xe66b0000]: Sending extension Key Share/51 (69 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (OCSP Status Request/5) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (PSK Key Exchange Modes/45) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (ClientHello Padding/21) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Pre Shared Key/41) for 'TLS 1.3 server hello' 295s [gnutls] (4) HSK[0xe66b0000]: SERVER HELLO was queued [155 bytes] 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 155 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 160 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6 295s [gnutls] (4) REC[0xe66b0000]: Sent ChangeCipherSpec 295s [gnutls] (5) REC[0xe66b0000]: Initializing epoch #1 295s [gnutls] (5) REC[0xe66b0000]: Epoch #1 ready 295s [gnutls] (4) HSK[0xe66b0000]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Server Certificate Type/20) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Compress Certificate/27) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Session Ticket/35) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Key Share/51) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Record Size Limit/28) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Sending extension Record Size Limit/28 (2 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Supported Groups/10) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Server Name Indication/0) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (PSK Key Exchange Modes/45) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Supported EC Point Formats/11) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (SRTP/14) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (OCSP Status Request/5) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (ALPN/16) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Sending extension ALPN/16 (6 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Client Certificate Type/19) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Maximum Record Size/1) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Early Data/42) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Cookie/44) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Signature Algorithms/13) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Safe Renegotiation/65281) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Supported Versions/43) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Extended Master Secret/23) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Post Handshake Auth/49) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Encrypt-then-MAC/22) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (ClientHello Padding/21) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Pre Shared Key/41) for 'encrypted extensions' 295s [gnutls] (4) HSK[0xe66b0000]: ENCRYPTED EXTENSIONS was queued [22 bytes] 295s [gnutls] (4) HSK[0xe66b0000]: CERTIFICATE was queued [1155 bytes] 295s [gnutls] (4) checking cert compat with RSA-SHA256 295s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 295s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 295s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 295s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 295s [gnutls] (4) HSK[0xe66b0000]: signing TLS 1.3 handshake data: using RSA-PSS-RSAE-SHA256 and PRF: SHA384 295s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 295s [gnutls] (4) HSK[0xe66b0000]: CERTIFICATE VERIFY was queued [392 bytes] 295s [gnutls] (4) HSK[0xe66b0000]: sending finished 295s [gnutls] (4) HSK[0xe66b0000]: FINISHED was queued [52 bytes] 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 22 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 44 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 1155 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[2] Handshake(22) in epoch 1 and length: 1177 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 392 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[3] Handshake(22) in epoch 1 and length: 414 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 52 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[4] Handshake(22) in epoch 1 and length: 74 295s [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:965 295s [gnutls] (5) REC[0xe66b0000]: Allocating epoch #2 295s [gnutls] (4) HSK[0xe66b0000]: unauthenticated session eligible for early start 295s [gnutls] (5) REC[0xe66b0000]: Initializing epoch #2 295s [gnutls] (5) REC[0xe66b0000]: Epoch #2 ready 295s [gnutls] (4) HSK[0xe66b0000]: TLS 1.3 set write key with cipher suite: GNUTLS_AES_256_GCM_SHA384 295s [gnutls] (4) HSK[0xe66b0000]: switching early to application traffic keys 295s [gnutls] (4) HSK[0xe66b0000]: NEW SESSION TICKET was queued [251 bytes] 295s [gnutls] (4) HSK[0xe66b0000]: NEW SESSION TICKET was queued [251 bytes] 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[1] Handshake(22) in epoch 2 and length: 273 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[2] Handshake(22) in epoch 2 and length: 273 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 295s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 295s [gnutls] (5) REC[0xe66b0000]: SSL 3.3 ChangeCipherSpec packet received. Epoch 1, length: 1 295s [gnutls] (5) REC[0xe66b0000]: Expected Packet Handshake(22) 295s [gnutls] (5) REC[0xe66b0000]: Received Packet ChangeCipherSpec(20) with length: 1 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 295s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 295s [gnutls] (5) REC[0xe66b0000]: SSL 3.3 Application Data packet received. Epoch 1, length: 69 295s [gnutls] (5) REC[0xe66b0000]: Expected Packet Handshake(22) 295s [gnutls] (5) REC[0xe66b0000]: Received Packet Application Data(23) with length: 69 295s [gnutls] (5) REC[0xe66b0000]: Decrypted Packet[0] Handshake(22) with length: 52 295s [gnutls] (4) HSK[0xe66b0000]: FINISHED (20) was received. Length 48[48], frag offset 0, frag length: 48, sequence: 0 295s [gnutls] (4) HSK[0xe66b0000]: parsing finished 295s [gnutls] (4) HSK[0xe66b0000]: TLS 1.3 set read key with cipher suite: GNUTLS_AES_256_GCM_SHA384 295s [gnutls] (5) REC[0xe66b0000]: Start of epoch cleanup 295s [gnutls] (5) REC[0xe66b0000]: Epoch #0 freed 295s [gnutls] (5) REC[0xe66b0000]: Epoch #1 freed 295s [gnutls] (5) REC[0xe66b0000]: End of epoch cleanup 295s [tls ] TLS handshake with 127.0.0.1#34809 has completed 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 295s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1759 295s [gnutls] (5) REC[0xe66b0000]: SSL 3.3 Application Data packet received. Epoch 2, length: 147 295s [gnutls] (5) REC[0xe66b0000]: Expected Packet Application Data(23) 295s [gnutls] (5) REC[0xe66b0000]: Received Packet Application Data(23) with length: 147 295s [gnutls] (5) REC[0xe66b0000]: Decrypted Packet[0] Application Data(23) with length: 130 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 295s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1759 295s [plan ][00000.00] plan 'monkeys.example.' type 'A' uid [03889.00] 295s [iterat][03889.00] 'monkeys.example.' type 'A' new uid was assigned .01, parent uid .00 295s [hint ][03889.01] <= answered from hints 295s [iterat][03889.01] <= rcode: NOERROR 295s [resolv][03889.01] AD: request NOT classified as SECURE 295s [resolv][03889.01] finished in state: 4, queries: 1, mempool: 81936 B 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Application Data(23) with length: 470 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[3] Application Data(23) in epoch 2 and length: 492 295s [gnutls] (5) REC[0xe66b0000]: SSL 3.3 Application Data packet received. Epoch 2, length: 19 295s [gnutls] (5) REC[0xe66b0000]: Expected Packet Application Data(23) 295s [gnutls] (5) REC[0xe66b0000]: Received Packet Application Data(23) with length: 19 295s [gnutls] (5) REC[0xe66b0000]: Decrypted Packet[1] Alert(21) with length: 2 295s [gnutls] (5) REC[0xe66b0000]: Alert[1|0] - Close notify - was received 295s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_in_buffers]:1565 295s [io ] => connection to '127.0.0.1#34809' closed by peer (end of file) 295s [gnutls] (5) REC[0xe66b0000]: Start of epoch cleanup 295s [gnutls] (5) REC[0xe66b0000]: End of epoch cleanup 295s [gnutls] (5) REC[0xe66b0000]: Epoch #2 freed 295s [gnutls] (5) REC[0xe66b0000]: Allocating epoch #0 295s [gnutls] (2) added 3 protocols, 29 ciphersuites, 19 sig algos and 10 groups into priority list 295s [gnutls] (5) REC[0xe66b0000]: Allocating epoch #1 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 295s [gnutls] (5) REC[0xe66b0000]: SSL 3.3 Handshake packet received. Epoch 0, length: 399 295s [gnutls] (5) REC[0xe66b0000]: Expected Packet Handshake(22) 295s [gnutls] (5) REC[0xe66b0000]: Received Packet Handshake(22) with length: 399 295s [gnutls] (5) REC[0xe66b0000]: Decrypted Packet[0] Handshake(22) with length: 399 295s [gnutls] (4) HSK[0xe66b0000]: CLIENT HELLO (1) was received. Length 395[395], frag offset 0, frag length: 395, sequence: 0 295s [gnutls] (4) HSK[0xe66b0000]: Client's version: 3.3 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Supported Versions/43' (5 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Found version: 3.4 295s [gnutls] (4) EXT[0xe66b0000]: Found version: 3.3 295s [gnutls] (4) EXT[0xe66b0000]: Negotiated version: 3.4 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Server Name Indication/0' (21 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Safe Renegotiation/65281' (1 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Record Size Limit/28' (2 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: record_size_limit 16385 negotiated 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'ALPN/16' (6 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Encrypt-then-MAC/22' (0 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Extended Master Secret/23' (0 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Session Ticket/35' (0 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'PSK Key Exchange Modes/45' (3 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: PSK KE mode 01 received 295s [gnutls] (4) EXT[0xe66b0000]: PSK KE mode 00 received 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Signature Algorithms/13' (34 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (4.1) RSA-SHA256 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.9) RSA-PSS-SHA256 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.4) RSA-PSS-RSAE-SHA256 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (4.3) ECDSA-SECP256R1-SHA256 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.7) EdDSA-Ed25519 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (5.1) RSA-SHA384 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.10) RSA-PSS-SHA384 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.5) RSA-PSS-RSAE-SHA384 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (5.3) ECDSA-SECP384R1-SHA384 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.8) EdDSA-Ed448 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (6.1) RSA-SHA512 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.11) RSA-PSS-SHA512 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.6) RSA-PSS-RSAE-SHA512 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (6.3) ECDSA-SECP521R1-SHA512 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (2.1) RSA-SHA1 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (2.3) ECDSA-SHA1 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Supported EC Point Formats/11' (2 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Supported Groups/10' (22 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Received group SECP256R1 (0x17) 295s [gnutls] (4) EXT[0xe66b0000]: Received group SECP384R1 (0x18) 295s [gnutls] (4) EXT[0xe66b0000]: Received group SECP521R1 (0x19) 295s [gnutls] (4) EXT[0xe66b0000]: Received group X25519 (0x1d) 295s [gnutls] (4) EXT[0xe66b0000]: Received group X448 (0x1e) 295s [gnutls] (4) EXT[0xe66b0000]: Received group FFDHE2048 (0x100) 295s [gnutls] (4) EXT[0xe66b0000]: Received group FFDHE3072 (0x101) 295s [gnutls] (4) EXT[0xe66b0000]: Received group FFDHE4096 (0x102) 295s [gnutls] (4) EXT[0xe66b0000]: Received group FFDHE6144 (0x103) 295s [gnutls] (4) EXT[0xe66b0000]: Received group FFDHE8192 (0x104) 295s [gnutls] (4) EXT[0xe66b0000]: Selected group SECP256R1 295s [gnutls] (2) checking 13.02 (GNUTLS_AES_256_GCM_SHA384) for compatibility 295s [gnutls] (4) HSK[0xe66b0000]: Requested server name: 'notright.example' 295s [gnutls] (4) HSK[0xe66b0000]: checking compat of GNUTLS_AES_256_GCM_SHA384 with certificate[0] (RSA/X.509) 295s [gnutls] (4) checking cert compat with RSA-SHA256 295s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 295s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 295s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 295s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 295s [gnutls] (4) Selected signature algorithm: RSA-PSS-RSAE-SHA256 295s [gnutls] (2) Selected (RSA) cert based on ciphersuite 13.2: GNUTLS_AES_256_GCM_SHA384 295s [gnutls] (4) HSK[0xe66b0000]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384 295s [gnutls] (4) HSK[0xe66b0000]: Selected version TLS1.3 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Key Share/51' (107 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Received key share for SECP256R1 295s [gnutls] (4) HSK[0xe66b0000]: Selected group SECP256R1 (2) 295s [gnutls] (2) EXT[0xe66b0000]: server generated SECP256R1 shared key 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'OCSP Status Request/5' (5 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: OCSP status was requested 295s [gnutls] (4) HSK[0xe66b0000]: Safe renegotiation succeeded 295s [gnutls] (4) HSK[0xe66b0000]: SessionID: 519e15fdb7d4f2340aff5e736a3d7636816f933610b794c801de2b851c51000b 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Server Name Indication/0) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Post Handshake Auth/49) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (OCSP Status Request/5) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Supported Groups/10) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Signature Algorithms/13) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (ALPN/16) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Extended Master Secret/23) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Supported EC Point Formats/11) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Server Certificate Type/20) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Compress Certificate/27) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Client Certificate Type/19) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Cookie/44) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Early Data/42) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Safe Renegotiation/65281) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (SRTP/14) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Record Size Limit/28) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Supported Versions/43) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Sending extension Supported Versions/43 (2 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Encrypt-then-MAC/22) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Maximum Record Size/1) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Session Ticket/35) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (PSK Key Exchange Modes/45) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Key Share/51) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: sending key share for SECP256R1 295s [gnutls] (4) EXT[0xe66b0000]: Sending extension Key Share/51 (69 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (ClientHello Padding/21) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Pre Shared Key/41) for 'TLS 1.3 server hello' 295s [gnutls] (4) HSK[0xe66b0000]: SERVER HELLO was queued [155 bytes] 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 155 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 160 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6 295s [gnutls] (4) REC[0xe66b0000]: Sent ChangeCipherSpec 295s [gnutls] (5) REC[0xe66b0000]: Initializing epoch #1 295s [gnutls] (5) REC[0xe66b0000]: Epoch #1 ready 295s [gnutls] (4) HSK[0xe66b0000]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (OCSP Status Request/5) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Record Size Limit/28) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Sending extension Record Size Limit/28 (2 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (SRTP/14) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Encrypt-then-MAC/22) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Key Share/51) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Supported Versions/43) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Supported Groups/10) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Post Handshake Auth/49) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Compress Certificate/27) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Server Name Indication/0) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (PSK Key Exchange Modes/45) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Session Ticket/35) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (ALPN/16) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Sending extension ALPN/16 (6 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Maximum Record Size/1) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Early Data/42) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Server Certificate Type/20) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Safe Renegotiation/65281) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Signature Algorithms/13) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Client Certificate Type/19) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Supported EC Point Formats/11) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Cookie/44) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Extended Master Secret/23) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (ClientHello Padding/21) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Pre Shared Key/41) for 'encrypted extensions' 295s [gnutls] (4) HSK[0xe66b0000]: ENCRYPTED EXTENSIONS was queued [22 bytes] 295s [gnutls] (4) HSK[0xe66b0000]: CERTIFICATE was queued [1155 bytes] 295s [gnutls] (4) checking cert compat with RSA-SHA256 295s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 295s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 295s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 295s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 295s [gnutls] (4) HSK[0xe66b0000]: signing TLS 1.3 handshake data: using RSA-PSS-RSAE-SHA256 and PRF: SHA384 295s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 295s [gnutls] (4) HSK[0xe66b0000]: CERTIFICATE VERIFY was queued [392 bytes] 295s [gnutls] (4) HSK[0xe66b0000]: sending finished 295s [gnutls] (4) HSK[0xe66b0000]: FINISHED was queued [52 bytes] 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 22 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 44 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 1155 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[2] Handshake(22) in epoch 1 and length: 1177 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 392 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[3] Handshake(22) in epoch 1 and length: 414 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 52 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[4] Handshake(22) in epoch 1 and length: 74 295s [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:965 295s [gnutls] (5) REC[0xe66b0000]: Allocating epoch #2 295s [gnutls] (4) HSK[0xe66b0000]: unauthenticated session eligible for early start 295s [gnutls] (5) REC[0xe66b0000]: Initializing epoch #2 295s [gnutls] (5) REC[0xe66b0000]: Epoch #2 ready 295s [gnutls] (4) HSK[0xe66b0000]: TLS 1.3 set write key with cipher suite: GNUTLS_AES_256_GCM_SHA384 295s [gnutls] (4) HSK[0xe66b0000]: switching early to application traffic keys 295s [gnutls] (4) HSK[0xe66b0000]: NEW SESSION TICKET was queued [251 bytes] 295s [gnutls] (4) HSK[0xe66b0000]: NEW SESSION TICKET was queued [251 bytes] 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[1] Handshake(22) in epoch 2 and length: 273 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[2] Handshake(22) in epoch 2 and length: 273 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 295s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 295s [gnutls] (5) REC[0xe66b0000]: SSL 3.3 ChangeCipherSpec packet received. Epoch 1, length: 1 295s [gnutls] (5) REC[0xe66b0000]: Expected Packet Handshake(22) 295s [gnutls] (5) REC[0xe66b0000]: Received Packet ChangeCipherSpec(20) with length: 1 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 295s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 295s [io ] => connection to '127.0.0.1#39539' closed by peer (connection reset by peer) 295s [gnutls] (5) REC[0xe66b0000]: Start of epoch cleanup 295s [gnutls] (5) REC[0xe66b0000]: Epoch #0 freed 295s [gnutls] (5) REC[0xe66b0000]: End of epoch cleanup 295s [gnutls] (5) REC[0xe66b0000]: Epoch #1 freed 295s [gnutls] (5) REC[0xe66b0000]: Epoch #2 freed 295s [gnutls] (5) REC[0xe66b0000]: Allocating epoch #0 295s [gnutls] (2) added 3 protocols, 29 ciphersuites, 19 sig algos and 10 groups into priority list 295s [gnutls] (5) REC[0xe66b0000]: Allocating epoch #1 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 295s [gnutls] (5) REC[0xe66b0000]: SSL 3.3 Handshake packet received. Epoch 0, length: 395 295s [gnutls] (5) REC[0xe66b0000]: Expected Packet Handshake(22) 295s [gnutls] (5) REC[0xe66b0000]: Received Packet Handshake(22) with length: 395 295s [gnutls] (5) REC[0xe66b0000]: Decrypted Packet[0] Handshake(22) with length: 395 295s [gnutls] (4) HSK[0xe66b0000]: CLIENT HELLO (1) was received. Length 391[391], frag offset 0, frag length: 391, sequence: 0 295s [gnutls] (4) HSK[0xe66b0000]: Client's version: 3.3 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Supported Versions/43' (5 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Found version: 3.4 295s [gnutls] (4) EXT[0xe66b0000]: Found version: 3.3 295s [gnutls] (4) EXT[0xe66b0000]: Negotiated version: 3.4 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Server Name Indication/0' (17 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Extended Master Secret/23' (0 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Encrypt-then-MAC/22' (0 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Record Size Limit/28' (2 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: record_size_limit 16385 negotiated 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Safe Renegotiation/65281' (1 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'ALPN/16' (6 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Supported EC Point Formats/11' (2 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Session Ticket/35' (0 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Signature Algorithms/13' (34 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (4.1) RSA-SHA256 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.9) RSA-PSS-SHA256 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.4) RSA-PSS-RSAE-SHA256 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (4.3) ECDSA-SECP256R1-SHA256 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.7) EdDSA-Ed25519 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (5.1) RSA-SHA384 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.10) RSA-PSS-SHA384 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.5) RSA-PSS-RSAE-SHA384 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (5.3) ECDSA-SECP384R1-SHA384 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.8) EdDSA-Ed448 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (6.1) RSA-SHA512 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.11) RSA-PSS-SHA512 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (8.6) RSA-PSS-RSAE-SHA512 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (6.3) ECDSA-SECP521R1-SHA512 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (2.1) RSA-SHA1 295s [gnutls] (4) EXT[0xe66b0000]: rcvd signature algo (2.3) ECDSA-SHA1 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'PSK Key Exchange Modes/45' (3 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: PSK KE mode 01 received 295s [gnutls] (4) EXT[0xe66b0000]: PSK KE mode 00 received 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Supported Groups/10' (22 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Received group SECP256R1 (0x17) 295s [gnutls] (4) EXT[0xe66b0000]: Received group SECP384R1 (0x18) 295s [gnutls] (4) EXT[0xe66b0000]: Received group SECP521R1 (0x19) 295s [gnutls] (4) EXT[0xe66b0000]: Received group X25519 (0x1d) 295s [gnutls] (4) EXT[0xe66b0000]: Received group X448 (0x1e) 295s [gnutls] (4) EXT[0xe66b0000]: Received group FFDHE2048 (0x100) 295s [gnutls] (4) EXT[0xe66b0000]: Received group FFDHE3072 (0x101) 295s [gnutls] (4) EXT[0xe66b0000]: Received group FFDHE4096 (0x102) 295s [gnutls] (4) EXT[0xe66b0000]: Received group FFDHE6144 (0x103) 295s [gnutls] (4) EXT[0xe66b0000]: Received group FFDHE8192 (0x104) 295s [gnutls] (4) EXT[0xe66b0000]: Selected group SECP256R1 295s [gnutls] (2) checking 13.02 (GNUTLS_AES_256_GCM_SHA384) for compatibility 295s [gnutls] (4) HSK[0xe66b0000]: Requested server name: 'test.example' 295s [gnutls] (4) checking cert compat with RSA-SHA256 295s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 295s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 295s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 295s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 295s [gnutls] (4) Selected signature algorithm: RSA-PSS-RSAE-SHA256 295s [gnutls] (2) Selected (RSA) cert based on ciphersuite 13.2: GNUTLS_AES_256_GCM_SHA384 295s [gnutls] (4) HSK[0xe66b0000]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384 295s [gnutls] (4) HSK[0xe66b0000]: Selected version TLS1.3 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'OCSP Status Request/5' (5 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: OCSP status was requested 295s [gnutls] (4) EXT[0xe66b0000]: Parsing extension 'Key Share/51' (107 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Received key share for SECP256R1 295s [gnutls] (4) HSK[0xe66b0000]: Selected group SECP256R1 (2) 295s [gnutls] (2) EXT[0xe66b0000]: server generated SECP256R1 shared key 295s [gnutls] (4) HSK[0xe66b0000]: Safe renegotiation succeeded 295s [gnutls] (4) HSK[0xe66b0000]: SessionID: e95c90ff56be6a3cd92354a5934d7326281f810646de1e529b8b23add085dbf0 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Session Ticket/35) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Cookie/44) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Server Name Indication/0) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Supported Versions/43) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Sending extension Supported Versions/43 (2 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (ALPN/16) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Key Share/51) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: sending key share for SECP256R1 295s [gnutls] (4) EXT[0xe66b0000]: Sending extension Key Share/51 (69 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Compress Certificate/27) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (SRTP/14) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Server Certificate Type/20) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Maximum Record Size/1) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (OCSP Status Request/5) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Signature Algorithms/13) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Supported Groups/10) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Safe Renegotiation/65281) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Early Data/42) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Extended Master Secret/23) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (PSK Key Exchange Modes/45) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Record Size Limit/28) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Supported EC Point Formats/11) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Post Handshake Auth/49) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Encrypt-then-MAC/22) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Client Certificate Type/19) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (ClientHello Padding/21) for 'TLS 1.3 server hello' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Pre Shared Key/41) for 'TLS 1.3 server hello' 295s [gnutls] (4) HSK[0xe66b0000]: SERVER HELLO was queued [155 bytes] 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 155 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 160 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6 295s [gnutls] (4) REC[0xe66b0000]: Sent ChangeCipherSpec 295s [gnutls] (5) REC[0xe66b0000]: Initializing epoch #1 295s [gnutls] (5) REC[0xe66b0000]: Epoch #1 ready 295s [gnutls] (4) HSK[0xe66b0000]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (OCSP Status Request/5) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Signature Algorithms/13) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Maximum Record Size/1) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Early Data/42) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Key Share/51) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Encrypt-then-MAC/22) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Cookie/44) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Compress Certificate/27) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Record Size Limit/28) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Sending extension Record Size Limit/28 (2 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (PSK Key Exchange Modes/45) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Session Ticket/35) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Supported EC Point Formats/11) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Server Certificate Type/20) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Safe Renegotiation/65281) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Client Certificate Type/19) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Server Name Indication/0) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Post Handshake Auth/49) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Extended Master Secret/23) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (SRTP/14) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (ALPN/16) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Sending extension ALPN/16 (6 bytes) 295s [gnutls] (4) EXT[0xe66b0000]: Preparing extension (Supported Groups/10) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Supported Versions/43) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (ClientHello Padding/21) for 'encrypted extensions' 295s [gnutls] (4) EXT[0xe66b0000]: Not sending extension (Pre Shared Key/41) for 'encrypted extensions' 295s [gnutls] (4) HSK[0xe66b0000]: ENCRYPTED EXTENSIONS was queued [22 bytes] 295s [gnutls] (4) HSK[0xe66b0000]: CERTIFICATE was queued [1155 bytes] 295s [gnutls] (4) checking cert compat with RSA-SHA256 295s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 295s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 295s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 295s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 295s [gnutls] (4) HSK[0xe66b0000]: signing TLS 1.3 handshake data: using RSA-PSS-RSAE-SHA256 and PRF: SHA384 295s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 295s [gnutls] (4) HSK[0xe66b0000]: CERTIFICATE VERIFY was queued [392 bytes] 295s [gnutls] (4) HSK[0xe66b0000]: sending finished 295s [gnutls] (4) HSK[0xe66b0000]: FINISHED was queued [52 bytes] 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 22 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 44 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 1155 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[2] Handshake(22) in epoch 1 and length: 1177 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 392 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[3] Handshake(22) in epoch 1 and length: 414 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 52 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[4] Handshake(22) in epoch 1 and length: 74 295s [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:965 295s [gnutls] (5) REC[0xe66b0000]: Allocating epoch #2 295s [gnutls] (4) HSK[0xe66b0000]: unauthenticated session eligible for early start 295s [gnutls] (5) REC[0xe66b0000]: Initializing epoch #2 295s [gnutls] (5) REC[0xe66b0000]: Epoch #2 ready 295s [gnutls] (4) HSK[0xe66b0000]: TLS 1.3 set write key with cipher suite: GNUTLS_AES_256_GCM_SHA384 295s [gnutls] (4) HSK[0xe66b0000]: switching early to application traffic keys 295s [gnutls] (4) HSK[0xe66b0000]: NEW SESSION TICKET was queued [251 bytes] 295s [gnutls] (4) HSK[0xe66b0000]: NEW SESSION TICKET was queued [251 bytes] 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[1] Handshake(22) in epoch 2 and length: 273 295s [gnutls] (5) REC[0xe66b0000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 295s [gnutls] (5) REC[0xe66b0000]: Sent Packet[2] Handshake(22) in epoch 2 and length: 273 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 295s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 295s [gnutls] (5) REC[0xe66b0000]: SSL 3.3 ChangeCipherSpec packet received. Epoch 1, length: 1 295s [gnutls] (5) REC[0xe66b0000]: Expected Packet Handshake(22) 295s [gnutls] (5) REC[0xe66b0000]: Received Packet ChangeCipherSpec(20) with length: 1 295s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 295s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 295s [io ] => connection to '127.0.0.1#53329' closed by peer (connection reset by peer) 295s [gnutls] (5) REC[0xe66b0000]: Start of epoch cleanup 295s [gnutls] (5) REC[0xe66b0000]: Epoch #0 freed 295s [gnutls] (5) REC[0xe66b0000]: End of epoch cleanup 295s [gnutls] (5) REC[0xe66b0000]: Epoch #1 freed 295s [gnutls] (5) REC[0xe66b0000]: Epoch #2 freed 295s > 296s > autopkgtest [19:29:17]: test roundtrip: -----------------------] 300s autopkgtest [19:29:21]: test roundtrip: - - - - - - - - - - results - - - - - - - - - - 300s roundtrip PASS 307s autopkgtest [19:29:28]: @@@@@@@@@@@@@@@@@@@@ summary 307s roundtrip PASS