6s autopkgtest [18:55:57]: starting date and time: 2024-07-12 18:55:57+0000 6s autopkgtest [18:55:57]: git checkout: fd3bed09 nova: allow more retries for quota issues 6s autopkgtest [18:55:57]: host juju-7f2275-prod-proposed-migration-environment-2; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.npxmw7_4/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --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 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@bos03-arm64-35.secgroup --name adt-oracular-arm64-knot-resolver-20240712-185532-juju-7f2275-prod-proposed-migration-environment-2-5fea7693-5720-446e-bb8c-f26936a53e89 --image adt/ubuntu-oracular-arm64-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-2 --net-id=net_prod-proposed-migration -e TERM=linux -e ''"'"'http_proxy=http://squid.internal:3128'"'"'' -e ''"'"'https_proxy=http://squid.internal:3128'"'"'' -e ''"'"'no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,keyserver.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com'"'"'' --mirror=http://ftpmaster.internal/ubuntu/ 347s autopkgtest [19:01:38]: testbed dpkg architecture: arm64 348s autopkgtest [19:01:39]: testbed apt version: 2.9.6 348s autopkgtest [19:01:39]: @@@@@@@@@@@@@@@@@@@@ test bed setup 351s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [126 kB] 352s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [8548 B] 352s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [327 kB] 353s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [2576 B] 353s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [48.0 kB] 353s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 Packages [92.1 kB] 353s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 c-n-f Metadata [2104 B] 353s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/restricted arm64 Packages [43.9 kB] 353s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/restricted arm64 c-n-f Metadata [364 B] 353s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/universe arm64 Packages [338 kB] 353s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/universe arm64 c-n-f Metadata [7988 B] 353s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse arm64 Packages [7596 B] 353s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse arm64 c-n-f Metadata [276 B] 358s Fetched 1004 kB in 4s (276 kB/s) 358s Reading package lists... 393s Reading package lists... 393s Building dependency tree... 393s Reading state information... 394s Calculating upgrade... 394s The following packages will be upgraded: 394s inetutils-telnet libc-bin libc-dev-bin libc-devtools libc6 libc6-dev locales 394s openssh-client openssh-server openssh-sftp-server telnet 395s 11 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 395s Need to get 10.7 MB of archives. 395s After this operation, 28.7 kB disk space will be freed. 395s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 libc-devtools arm64 2.39-3.1ubuntu3 [27.7 kB] 395s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 libc6-dev arm64 2.39-3.1ubuntu3 [1591 kB] 395s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 libc-dev-bin arm64 2.39-3.1ubuntu3 [19.7 kB] 395s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 libc6 arm64 2.39-3.1ubuntu3 [2770 kB] 396s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 libc-bin arm64 2.39-3.1ubuntu3 [579 kB] 396s Get:6 http://ftpmaster.internal/ubuntu oracular/main arm64 openssh-sftp-server arm64 1:9.6p1-3ubuntu17 [36.7 kB] 396s Get:7 http://ftpmaster.internal/ubuntu oracular/main arm64 openssh-server arm64 1:9.6p1-3ubuntu17 [502 kB] 396s Get:8 http://ftpmaster.internal/ubuntu oracular/main arm64 openssh-client arm64 1:9.6p1-3ubuntu17 [888 kB] 396s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 locales all 2.39-3.1ubuntu3 [4220 kB] 396s Get:10 http://ftpmaster.internal/ubuntu oracular/main arm64 inetutils-telnet arm64 2:2.5-5ubuntu1 [103 kB] 396s Get:11 http://ftpmaster.internal/ubuntu oracular/main arm64 telnet all 0.17+2.5-5ubuntu1 [3688 B] 424s Preconfiguring packages ... 427s Fetched 10.7 MB in 1s (8816 kB/s) 428s (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 ... 78392 files and directories currently installed.) 428s Preparing to unpack .../libc-devtools_2.39-3.1ubuntu3_arm64.deb ... 428s Unpacking libc-devtools (2.39-3.1ubuntu3) over (2.39-0ubuntu9) ... 429s Preparing to unpack .../libc6-dev_2.39-3.1ubuntu3_arm64.deb ... 429s Unpacking libc6-dev:arm64 (2.39-3.1ubuntu3) over (2.39-0ubuntu9) ... 430s Preparing to unpack .../libc-dev-bin_2.39-3.1ubuntu3_arm64.deb ... 430s Unpacking libc-dev-bin (2.39-3.1ubuntu3) over (2.39-0ubuntu9) ... 430s Preparing to unpack .../libc6_2.39-3.1ubuntu3_arm64.deb ... 431s Unpacking libc6:arm64 (2.39-3.1ubuntu3) over (2.39-0ubuntu9) ... 431s Setting up libc6:arm64 (2.39-3.1ubuntu3) ... 431s Error: Could not restart systemd, systemd binary not working 431s (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 ... 78392 files and directories currently installed.) 431s Preparing to unpack .../libc-bin_2.39-3.1ubuntu3_arm64.deb ... 431s Unpacking libc-bin (2.39-3.1ubuntu3) over (2.39-0ubuntu9) ... 431s Setting up libc-bin (2.39-3.1ubuntu3) ... 432s (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 ... 78392 files and directories currently installed.) 432s Preparing to unpack .../0-openssh-sftp-server_1%3a9.6p1-3ubuntu17_arm64.deb ... 432s Unpacking openssh-sftp-server (1:9.6p1-3ubuntu17) over (1:9.6p1-3ubuntu15) ... 432s Preparing to unpack .../1-openssh-server_1%3a9.6p1-3ubuntu17_arm64.deb ... 432s Unpacking openssh-server (1:9.6p1-3ubuntu17) over (1:9.6p1-3ubuntu15) ... 432s Preparing to unpack .../2-openssh-client_1%3a9.6p1-3ubuntu17_arm64.deb ... 432s Unpacking openssh-client (1:9.6p1-3ubuntu17) over (1:9.6p1-3ubuntu15) ... 432s Preparing to unpack .../3-locales_2.39-3.1ubuntu3_all.deb ... 432s Unpacking locales (2.39-3.1ubuntu3) over (2.39-0ubuntu9) ... 432s Preparing to unpack .../4-inetutils-telnet_2%3a2.5-5ubuntu1_arm64.deb ... 432s Unpacking inetutils-telnet (2:2.5-5ubuntu1) over (2:2.5-3ubuntu4) ... 432s Preparing to unpack .../5-telnet_0.17+2.5-5ubuntu1_all.deb ... 432s Unpacking telnet (0.17+2.5-5ubuntu1) over (0.17+2.5-3ubuntu4) ... 432s Setting up openssh-client (1:9.6p1-3ubuntu17) ... 433s Setting up inetutils-telnet (2:2.5-5ubuntu1) ... 433s Setting up locales (2.39-3.1ubuntu3) ... 434s Generating locales (this might take a while)... 436s en_US.UTF-8... done 436s Generation complete. 436s Setting up libc-dev-bin (2.39-3.1ubuntu3) ... 436s Setting up libc-devtools (2.39-3.1ubuntu3) ... 436s Setting up openssh-sftp-server (1:9.6p1-3ubuntu17) ... 436s Setting up telnet (0.17+2.5-5ubuntu1) ... 436s Setting up openssh-server (1:9.6p1-3ubuntu17) ... 436s Installing new version of config file /etc/pam.d/sshd ... 438s Setting up libc6-dev:arm64 (2.39-3.1ubuntu3) ... 438s Processing triggers for systemd (256-1ubuntu1) ... 438s Processing triggers for man-db (2.12.1-2) ... 440s Processing triggers for ufw (0.36.2-6) ... 441s Reading package lists... 441s Building dependency tree... 441s Reading state information... 442s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 442s Hit:1 http://ftpmaster.internal/ubuntu oracular InRelease 442s Hit:2 http://ftpmaster.internal/ubuntu oracular-updates InRelease 442s Hit:3 http://ftpmaster.internal/ubuntu oracular-security InRelease 443s Hit:4 http://ftpmaster.internal/ubuntu oracular-proposed InRelease 444s Reading package lists... 445s Reading package lists... 445s Building dependency tree... 445s Reading state information... 445s Calculating upgrade... 446s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 446s Reading package lists... 446s Building dependency tree... 446s Reading state information... 446s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 450s autopkgtest [19:03:21]: rebooting testbed after setup commands that affected boot 504s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 562s autopkgtest [19:05:13]: testbed running kernel: Linux 6.8.0-31-generic #31-Ubuntu SMP PREEMPT_DYNAMIC Sat Apr 20 02:32:42 UTC 2024 607s autopkgtest [19:05:58]: @@@@@@@@@@@@@@@@@@@@ apt-source knot-resolver 646s Get:1 http://ftpmaster.internal/ubuntu oracular/universe knot-resolver 5.7.3-1 (dsc) [3184 B] 646s Get:2 http://ftpmaster.internal/ubuntu oracular/universe knot-resolver 5.7.3-1 (tar) [1931 kB] 646s Get:3 http://ftpmaster.internal/ubuntu oracular/universe knot-resolver 5.7.3-1 (asc) [833 B] 646s Get:4 http://ftpmaster.internal/ubuntu oracular/universe knot-resolver 5.7.3-1 (diff) [401 kB] 647s gpgv: Signature made Tue Jun 4 18:13:51 2024 UTC 647s gpgv: using RSA key 23EBCF7E8FC47556787100DFA4254072E373042C 647s gpgv: Can't check signature: No public key 647s dpkg-source: warning: cannot verify inline signature for ./knot-resolver_5.7.3-1.dsc: no acceptable signature found 647s autopkgtest [19:06:38]: testing package knot-resolver version 5.7.3-1 663s autopkgtest [19:06:54]: build not needed 675s autopkgtest [19:07:06]: test roundtrip: preparing testbed 699s Reading package lists... 700s Building dependency tree... 700s Reading state information... 700s Starting pkgProblemResolver with broken count: 0 700s Starting 2 pkgProblemResolver with broken count: 0 700s Done 701s The following additional packages will be installed: 701s dns-root-data gnutls-bin knot-dnsutils knot-resolver libdnssec9t64 701s libevent-2.1-7t64 libfstrm0 libgnutls-dane0t64 libjemalloc2 libknot14t64 701s libluajit-5.1-2 libluajit-5.1-common libunbound8 libxdp1 libzscanner4t64 701s lua-sec lua-socket socat 701s Recommended packages: 701s knot-resolver-module-http lua-basexx lua-cqueues 701s The following NEW packages will be installed: 701s autopkgtest-satdep dns-root-data gnutls-bin knot-dnsutils knot-resolver 701s libdnssec9t64 libevent-2.1-7t64 libfstrm0 libgnutls-dane0t64 libjemalloc2 701s libknot14t64 libluajit-5.1-2 libluajit-5.1-common libunbound8 libxdp1 701s libzscanner4t64 lua-sec lua-socket socat 701s 0 upgraded, 19 newly installed, 0 to remove and 0 not upgraded. 701s Need to get 2897 kB/2897 kB of archives. 701s After this operation, 12.0 MB of additional disk space will be used. 701s Get:1 /tmp/autopkgtest.fgkSUv/1-autopkgtest-satdep.deb autopkgtest-satdep arm64 0 [728 B] 701s Get:2 http://ftpmaster.internal/ubuntu oracular/main arm64 dns-root-data all 2024041801 [4330 B] 701s Get:3 http://ftpmaster.internal/ubuntu oracular/main arm64 libevent-2.1-7t64 arm64 2.1.12-stable-10 [140 kB] 702s Get:4 http://ftpmaster.internal/ubuntu oracular/main arm64 libunbound8 arm64 1.19.2-1ubuntu3 [424 kB] 702s Get:5 http://ftpmaster.internal/ubuntu oracular/main arm64 libgnutls-dane0t64 arm64 3.8.6-2ubuntu1 [24.0 kB] 702s Get:6 http://ftpmaster.internal/ubuntu oracular/universe arm64 gnutls-bin arm64 3.8.6-2ubuntu1 [267 kB] 702s Get:7 http://ftpmaster.internal/ubuntu oracular/universe arm64 libdnssec9t64 arm64 3.3.7-1 [30.5 kB] 702s Get:8 http://ftpmaster.internal/ubuntu oracular/main arm64 libxdp1 arm64 1.4.2-1ubuntu4 [62.8 kB] 702s Get:9 http://ftpmaster.internal/ubuntu oracular/universe arm64 libknot14t64 arm64 3.3.7-1 [203 kB] 702s Get:10 http://ftpmaster.internal/ubuntu oracular/universe arm64 libzscanner4t64 arm64 3.3.7-1 [135 kB] 702s Get:11 http://ftpmaster.internal/ubuntu oracular/universe arm64 libfstrm0 arm64 0.6.1-1build4 [20.6 kB] 702s Get:12 http://ftpmaster.internal/ubuntu oracular/universe arm64 knot-dnsutils arm64 3.3.7-1 [222 kB] 702s Get:13 http://ftpmaster.internal/ubuntu oracular/universe arm64 lua-socket arm64 3.1.0-1 [88.9 kB] 702s Get:14 http://ftpmaster.internal/ubuntu oracular/universe arm64 lua-sec arm64 1.3.2-2 [43.5 kB] 702s Get:15 http://ftpmaster.internal/ubuntu oracular/universe arm64 libjemalloc2 arm64 5.3.0-2build1 [204 kB] 702s Get:16 http://ftpmaster.internal/ubuntu oracular/universe arm64 libluajit-5.1-common all 2.1.0+openresty20240626-1 [48.3 kB] 702s Get:17 http://ftpmaster.internal/ubuntu oracular/universe arm64 libluajit-5.1-2 arm64 2.1.0+openresty20240626-1 [276 kB] 702s Get:18 http://ftpmaster.internal/ubuntu oracular/universe arm64 knot-resolver arm64 5.7.3-1 [330 kB] 702s Get:19 http://ftpmaster.internal/ubuntu oracular/main arm64 socat arm64 1.8.0.0-4build3 [372 kB] 704s Preconfiguring packages ... 704s Fetched 2897 kB in 1s (3102 kB/s) 705s Selecting previously unselected package dns-root-data. 705s (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 ... 78392 files and directories currently installed.) 705s Preparing to unpack .../00-dns-root-data_2024041801_all.deb ... 705s Unpacking dns-root-data (2024041801) ... 706s Selecting previously unselected package libevent-2.1-7t64:arm64. 706s Preparing to unpack .../01-libevent-2.1-7t64_2.1.12-stable-10_arm64.deb ... 706s Unpacking libevent-2.1-7t64:arm64 (2.1.12-stable-10) ... 706s Selecting previously unselected package libunbound8:arm64. 707s Preparing to unpack .../02-libunbound8_1.19.2-1ubuntu3_arm64.deb ... 707s Unpacking libunbound8:arm64 (1.19.2-1ubuntu3) ... 707s Selecting previously unselected package libgnutls-dane0t64:arm64. 707s Preparing to unpack .../03-libgnutls-dane0t64_3.8.6-2ubuntu1_arm64.deb ... 707s Unpacking libgnutls-dane0t64:arm64 (3.8.6-2ubuntu1) ... 707s Selecting previously unselected package gnutls-bin. 707s Preparing to unpack .../04-gnutls-bin_3.8.6-2ubuntu1_arm64.deb ... 707s Unpacking gnutls-bin (3.8.6-2ubuntu1) ... 707s Selecting previously unselected package libdnssec9t64. 708s Preparing to unpack .../05-libdnssec9t64_3.3.7-1_arm64.deb ... 708s Unpacking libdnssec9t64 (3.3.7-1) ... 708s Selecting previously unselected package libxdp1:arm64. 710s Preparing to unpack .../06-libxdp1_1.4.2-1ubuntu4_arm64.deb ... 710s Unpacking libxdp1:arm64 (1.4.2-1ubuntu4) ... 711s Selecting previously unselected package libknot14t64. 712s Preparing to unpack .../07-libknot14t64_3.3.7-1_arm64.deb ... 712s Unpacking libknot14t64 (3.3.7-1) ... 712s Selecting previously unselected package libzscanner4t64. 717s Preparing to unpack .../08-libzscanner4t64_3.3.7-1_arm64.deb ... 718s Unpacking libzscanner4t64 (3.3.7-1) ... 718s Selecting previously unselected package libfstrm0:arm64. 718s Preparing to unpack .../09-libfstrm0_0.6.1-1build4_arm64.deb ... 718s Unpacking libfstrm0:arm64 (0.6.1-1build4) ... 718s Selecting previously unselected package knot-dnsutils. 718s Preparing to unpack .../10-knot-dnsutils_3.3.7-1_arm64.deb ... 718s Unpacking knot-dnsutils (3.3.7-1) ... 718s Selecting previously unselected package lua-socket:arm64. 719s Preparing to unpack .../11-lua-socket_3.1.0-1_arm64.deb ... 719s Unpacking lua-socket:arm64 (3.1.0-1) ... 719s Selecting previously unselected package lua-sec:arm64. 719s Preparing to unpack .../12-lua-sec_1.3.2-2_arm64.deb ... 719s Unpacking lua-sec:arm64 (1.3.2-2) ... 719s Selecting previously unselected package libjemalloc2:arm64. 719s Preparing to unpack .../13-libjemalloc2_5.3.0-2build1_arm64.deb ... 719s Unpacking libjemalloc2:arm64 (5.3.0-2build1) ... 719s Selecting previously unselected package libluajit-5.1-common. 720s Preparing to unpack .../14-libluajit-5.1-common_2.1.0+openresty20240626-1_all.deb ... 720s Unpacking libluajit-5.1-common (2.1.0+openresty20240626-1) ... 720s Selecting previously unselected package libluajit-5.1-2:arm64. 720s Preparing to unpack .../15-libluajit-5.1-2_2.1.0+openresty20240626-1_arm64.deb ... 720s Unpacking libluajit-5.1-2:arm64 (2.1.0+openresty20240626-1) ... 720s Selecting previously unselected package knot-resolver. 720s Preparing to unpack .../16-knot-resolver_5.7.3-1_arm64.deb ... 720s Unpacking knot-resolver (5.7.3-1) ... 720s Selecting previously unselected package socat. 720s Preparing to unpack .../17-socat_1.8.0.0-4build3_arm64.deb ... 720s Unpacking socat (1.8.0.0-4build3) ... 720s Selecting previously unselected package autopkgtest-satdep. 721s Preparing to unpack .../18-1-autopkgtest-satdep.deb ... 721s Unpacking autopkgtest-satdep (0) ... 721s Setting up libzscanner4t64 (3.3.7-1) ... 721s Setting up libfstrm0:arm64 (0.6.1-1build4) ... 721s Setting up libevent-2.1-7t64:arm64 (2.1.12-stable-10) ... 721s Setting up lua-socket:arm64 (3.1.0-1) ... 721s Setting up libjemalloc2:arm64 (5.3.0-2build1) ... 721s Setting up dns-root-data (2024041801) ... 721s Setting up libxdp1:arm64 (1.4.2-1ubuntu4) ... 721s Setting up libunbound8:arm64 (1.19.2-1ubuntu3) ... 721s Setting up libgnutls-dane0t64:arm64 (3.8.6-2ubuntu1) ... 721s Setting up socat (1.8.0.0-4build3) ... 721s Setting up libdnssec9t64 (3.3.7-1) ... 721s Setting up libluajit-5.1-common (2.1.0+openresty20240626-1) ... 721s Setting up libknot14t64 (3.3.7-1) ... 721s Setting up gnutls-bin (3.8.6-2ubuntu1) ... 721s Setting up lua-sec:arm64 (1.3.2-2) ... 721s Setting up knot-dnsutils (3.3.7-1) ... 721s Setting up libluajit-5.1-2:arm64 (2.1.0+openresty20240626-1) ... 721s Setting up knot-resolver (5.7.3-1) ... 724s Created symlink '/etc/systemd/system/kresd.target.wants/kres-cache-gc.service' → '/usr/lib/systemd/system/kres-cache-gc.service'. 724s Created symlink '/etc/systemd/system/multi-user.target.wants/kresd.target' → '/usr/lib/systemd/system/kresd.target'. 725s Setting up autopkgtest-satdep (0) ... 725s Processing triggers for man-db (2.12.1-2) ... 726s Processing triggers for libc-bin (2.39-3.1ubuntu3) ... 741s (Reading database ... 78792 files and directories currently installed.) 741s Removing autopkgtest-satdep (0) ... 744s autopkgtest [19:08:15]: test roundtrip: [----------------------- 744s /usr/sbin/kresd + /usr/bin/kdig roundtrip tests 744s ------------ 744s workdir: /tmp/autopkgtest.fgkSUv/roundtrip-artifacts 744s IP addr: 127.155.31.73 744s kresd args: --addr=127.155.31.73@8053 --tls=127.155.31.73@8853 --noninteractive --config=/tmp/autopkgtest.fgkSUv/roundtrip-artifacts/kresd.conf --verbose --verbose --verbose 744s 744s make Certificate Authority key and certificate 744s ---------------------------------------------- 745s Generating a 3072 bit RSA private key... 746s Generating a self signed certificate... 746s X.509 Certificate Information: 746s Version: 3 746s Serial Number (hex): 4df1d421a4e82ac5faaccf817ad025f1f3cc3881 746s Validity: 746s Not Before: Fri Jul 12 19:08:16 UTC 2024 746s Not After: Wed Jul 24 19:08:16 UTC 2024 746s Subject: CN=testing certificate authority (NOT FOR PRODUCTION) 746s Subject Public Key Algorithm: RSA 746s Algorithm Security Level: High (3072 bits) 746s Modulus (bits 3072): 746s 00:a7:96:a3:4b:f9:42:95:fc:2a:67:c5:19:fb:27:ea 746s 44:47:1f:15:80:72:5a:2d:58:14:d2:e8:9c:53:89:6f 746s be:b5:ed:97:fe:53:08:56:f0:cf:a4:89:43:08:99:8c 746s f7:59:30:65:61:1f:86:02:25:2e:11:0c:d7:98:c8:e7 746s 5d:14:eb:51:92:30:f5:de:68:3d:7d:06:07:8b:06:0d 746s c6:3a:1f:d7:fd:fc:70:e2:39:86:75:a6:83:7e:39:eb 746s fe:2c:e2:ce:0c:2f:90:0d:d0:7d:f5:e3:d1:b5:e2:20 746s bc:8c:f2:4a:80:2b:c2:b9:72:53:96:ab:f6:bc:8c:7d 746s 69:11:4f:ee:99:28:8b:22:b4:0c:77:99:6a:03:46:2b 746s 25:fa:eb:67:5a:51:83:d8:8b:db:46:72:52:2f:50:f5 746s 7e:ec:d9:ba:d9:b4:fa:3e:74:16:59:90:ca:3c:76:da 746s 35:3e:d1:cf:ee:c7:22:03:55:95:2d:35:9c:99:38:15 746s bd:d5:af:ce:06:d4:d6:cc:1d:75:6f:fe:bd:21:d3:dc 746s e5:a3:ba:44:97:34:16:e4:9a:2f:4a:96:d3:f3:4e:c4 746s 21:cc:e7:65:99:ea:a7:7d:b4:5a:4b:ff:6d:e9:4d:da 746s ba:53:04:a6:30:24:53:f9:f5:06:a3:ca:c8:19:04:79 746s ec:6c:84:46:56:47:ed:d2:04:d4:84:4d:ea:a6:45:d2 746s 3d:97:73:c3:28:40:53:18:96:18:a4:13:00:15:e4:82 746s 5f:32:f9:5c:cf:66:dd:f6:b3:0d:fa:c4:89:86:68:26 746s a8:ed:80:58:71:91:c5:03:9b:01:44:41:2c:a7:5c:88 746s 39:f7:1a:43:84:32:7d:e3:75:c0:75:07:e7:ea:02:78 746s 7a:1b:56:7c:d4:d6:e5:ca:b9:ec:60:eb:df:82:6c:b7 746s 1f:94:54:cf:9f:c7:a5:65:98:81:9a:57:7f:7e:b0:35 746s 8f:35:f6:3e:00:e3:8a:b5:06:eb:53:f0:5a:7b:35:bf 746s ad 746s Exponent (bits 24): 746s 01:00:01 746s Extensions: 746s Basic Constraints (critical): 746s Certificate Authority (CA): TRUE 746s Path Length Constraint: 1 746s Name Constraints (critical): 746s Permitted: 746s DNSname: example 746s Key Usage (critical): 746s Certificate signing. 746s Subject Key Identifier (not critical): 746s 5da2eca6222e213b0f8fbec53a3fc74c3dd2bc68 746s Other Information: 746s Public Key ID: 746s sha1:5da2eca6222e213b0f8fbec53a3fc74c3dd2bc68 746s sha256:32c5bc2bfbc175f41027c9907ab2645f8d5417c464462f7e3ec628a09750614e 746s Public Key PIN: 746s pin-sha256:MsW8K/vBdfQQJ8mQerJkX41UF8RkRi9+PsYooJdQYU4= 746s 746s 746s 746s Signing certificate... 746s 746s make Bogus Certificate Authority key and certificate 746s ---------------------------------------------------- 746s Generating a 3072 bit RSA private key... 746s Generating a self signed certificate... 746s X.509 Certificate Information: 746s Version: 3 746s Serial Number (hex): 08c68953760a3bc183321834eec44650a9853891 746s Validity: 746s Not Before: Fri Jul 12 19:08:17 UTC 2024 746s Not After: Wed Jul 24 19:08:17 UTC 2024 746s Subject: CN=testing certificate authority (NOT FOR PRODUCTION) 746s Subject Public Key Algorithm: RSA 746s Algorithm Security Level: High (3072 bits) 746s Modulus (bits 3072): 746s 00:cf:8a:4b:e2:02:50:6e:e8:80:3c:9a:1b:f8:07:8a 746s a4:ff:53:0b:4d:6f:68:18:c2:e6:bb:84:e2:42:44:cc 746s 49:37:f7:e3:7b:eb:25:b2:98:4e:90:0e:e1:c6:4e:6f 746s 92:e2:ba:30:f7:d6:24:b4:d0:c7:bc:45:2d:cc:f0:22 746s e5:8e:f0:59:c5:19:a8:f0:e7:fa:37:5b:c0:56:d9:9d 746s 2d:c7:24:e6:a1:9d:e7:d0:45:8e:58:40:df:58:f3:54 746s 71:ef:6d:d2:68:32:2b:d5:7d:89:e6:ba:6c:9c:b4:8a 746s 1c:3d:fd:98:24:69:a7:62:17:8b:8e:a9:89:76:8d:63 746s 05:43:5d:15:53:1b:6a:80:cb:fc:21:d3:c6:8f:44:ae 746s 7e:31:d0:f2:9a:a9:18:98:05:57:34:c6:66:09:f1:92 746s 98:9a:80:8e:60:cf:dd:27:46:b4:bc:70:0c:d8:e3:f1 746s e7:55:a6:df:45:2b:01:51:6f:a8:48:32:73:57:d2:ca 746s 6a:24:09:a7:e4:d8:58:1c:b0:2e:e9:17:ba:3a:8d:dc 746s 76:82:c6:c6:c6:f4:d5:11:d9:6b:b4:80:47:ae:f4:ae 746s 32:ad:e1:ea:3d:52:a1:b5:68:d9:4b:50:95:35:ba:6f 746s 21:4f:d2:0b:5e:83:70:47:3f:6c:6f:22:e1:82:e7:dd 746s f6:3a:2b:71:ff:e3:b6:0d:1d:70:39:35:ba:c8:0e:1c 746s 75:b6:f1:0d:3e:09:50:47:c4:a6:12:87:b5:d0:54:92 746s 83:54:2c:b6:79:ab:04:07:af:bf:45:82:6a:25:3c:e6 746s 69:00:03:02:c1:20:26:d4:84:d0:b5:a2:9c:46:4c:a7 746s 6e:3f:51:76:a1:ed:3b:7f:bc:a0:03:34:35:2a:56:16 746s cf:6c:58:4b:0a:ef:84:1f:bb:26:52:d6:26:ea:a9:d8 746s 2b:75:7d:22:48:4d:10:78:e9:f1:b3:75:8a:49:2f:d7 746s 29:fb:12:d5:7d:db:55:0b:0d:ad:76:a1:42:de:96:bf 746s 81 746s Exponent (bits 24): 746s 01:00:01 746s Extensions: 746s Basic Constraints (critical): 746s Certificate Authority (CA): TRUE 746s Path Length Constraint: 1 746s Name Constraints (critical): 746s Permitted: 746s DNSname: example 746s Key Usage (critical): 746s Certificate signing. 746s Subject Key Identifier (not critical): 746s 74e42020d7ff8212705727da1170fa120fefdeca 746s Other Information: 746s Public Key ID: 746s sha1:74e42020d7ff8212705727da1170fa120fefdeca 746s sha256:95d3c34ffe14281201d4759c0db79683ce1da700d4525fb23dcab71199cdd2db 746s Public Key PIN: 746s pin-sha256:ldPDT/4UKBIB1HWcDbeWg84dpwDUUl+yPcq3EZnN0ts= 746s 746s 746s 746s Signing certificate... 746s 746s make End Entity key and certificate 746s ----------------------------------- 746s Generating a 3072 bit RSA private key... 746s Generating a signed certificate... 746s X.509 Certificate Information: 746s Version: 3 746s Serial Number (hex): 7bbe2469cd376f184a34a7b93f64dba0bb3610bf 746s Validity: 746s Not Before: Fri Jul 12 19:08:17 UTC 2024 746s Not After: Mon Jul 22 19:08:17 UTC 2024 746s Subject: CN=test.example 746s Subject Public Key Algorithm: RSA 746s Algorithm Security Level: High (3072 bits) 746s Modulus (bits 3072): 746s 00:ed:87:89:9e:5e:aa:02:c1:0a:17:ea:08:20:1d:c1 746s 40:03:94:4f:e7:8f:b6:52:4f:5f:99:a0:3b:55:b8:78 746s 35:29:79:6e:06:a7:ee:a5:80:44:47:93:a5:31:d2:29 746s 92:7e:6c:6d:33:83:bb:bd:91:af:cb:96:63:b5:81:f3 746s 27:ce:59:75:59:a3:29:c3:b3:aa:d3:2c:fe:c2:a8:8d 746s 04:79:ef:1b:78:60:6a:d6:49:3e:b0:4e:b7:c9:03:19 746s ae:85:0f:77:ae:d9:ee:04:5b:b0:df:ad:0f:76:37:db 746s 2b:05:b1:15:b3:0c:ac:1f:14:6f:7e:6e:f7:0a:e3:f5 746s 9b:35:18:db:43:8a:63:1e:0a:45:9b:88:19:7d:4e:35 746s 2d:21:36:af:fe:95:40:50:f5:b5:15:55:20:9b:11:f5 746s 84:91:cd:86:43:9d:89:5b:ab:5f:e8:d7:b0:35:77:7c 746s 36:a6:e2:e9:94:d2:e5:65:87:8a:44:be:c4:21:1a:91 746s 89:50:67:db:9b:62:bf:90:4b:f9:aa:84:c3:96:25:84 746s 23:03:e4:46:b8:58:c5:fb:26:f6:43:ea:c6:4f:b7:91 746s 14:f2:c7:43:30:b6:b6:6a:92:d5:bd:db:8d:e5:32:9c 746s a7:1c:77:a4:77:ca:42:2f:01:59:d6:f0:96:f2:17:52 746s 86:11:78:3e:49:25:59:fc:c4:6e:ad:0b:0e:d5:2e:4e 746s 70:71:a6:3e:f9:ec:c9:e9:51:42:85:77:38:9f:6f:1d 746s ce:f1:37:1f:0c:c6:76:96:92:33:e9:bb:7d:11:1d:b0 746s 38:9d:ca:2b:38:2c:95:53:30:d1:c2:3a:80:f1:e2:0a 746s be:8b:8b:d4:78:49:a1:ef:b6:d1:f2:d0:0b:d6:7b:f2 746s 42:0d:75:cb:bd:f7:7c:f5:e4:53:9e:a7:f6:60:72:4b 746s f0:73:d8:e4:2e:e3:7b:18:1a:4c:dd:f0:00:d5:e1:51 746s e9:86:70:5a:15:26:91:51:23:82:78:ac:9b:a4:3a:34 746s 47 746s Exponent (bits 24): 746s 01:00:01 746s Extensions: 746s Basic Constraints (critical): 746s Certificate Authority (CA): FALSE 746s Subject Alternative Name (not critical): 746s DNSname: test.example 746s Key Purpose (not critical): 746s TLS WWW Server. 746s Key Usage (critical): 746s Digital signature. 746s Subject Key Identifier (not critical): 746s 1f536dd88da1bb17aa6aa674d2ffd0b6edc67d9b 746s Authority Key Identifier (not critical): 746s 5da2eca6222e213b0f8fbec53a3fc74c3dd2bc68 746s Other Information: 746s Public Key ID: 746s sha1:1f536dd88da1bb17aa6aa674d2ffd0b6edc67d9b 746s sha256:65fafb2e24b2deb70bcc27d01d23e78bb2219e68d94798b718f066044928a028 746s Public Key PIN: 746s pin-sha256:Zfr7LiSy3rcLzCfQHSPni7IhnmjZR5i3GPBmBEkooCg= 746s 746s 746s 746s Signing certificate... 746s 746s set up kresd daemon on 127.155.31.73 on ports 8053 (UDP, TCP) and 8853 (TLS) 746s ---------------------------------------------------------------------------- 747s 747s test UDP with kdig 747s ------------------ 747s successful UDP request to 127.155.31.73 on port 8053 747s 747s test TCP with kdig 747s ------------------ 747s successful TCP request to 127.155.31.73 on port 8053 747s 747s test opportunistic DNS-over-TLS with kdig 747s ----------------------------------------- 747s successful opportunistic DNS-over-TLS request to 127.155.31.73 on port 8853 747s 747s test strict DNS-over-TLS with kdig 747s ---------------------------------- 747s successful strict DNS-over-TLS request to 127.155.31.73 on port 8853 747s 747s test invalid name with strict DNS-over-TLS with kdig 747s ---------------------------------------------------- 747s successful strict DNS-over-TLS request failure when name mismatch to 127.155.31.73 on port 8853 747s 747s test bad authority with strict DNS-over-TLS with kdig 747s ----------------------------------------------------- 747s successful strict DNS-over-TLS request failure to 127.155.31.73 on port 8853 747s 747s cleaning up 747s ----------- 747s 299331 4 drwxrwxrwt 2 root root 4096 Jul 12 19:08 /tmp/autopkgtest.fgkSUv/roundtrip-artifacts 747s 299341 8 -rw------- 1 root root 8177 Jul 12 19:08 /tmp/autopkgtest.fgkSUv/roundtrip-artifacts/bogus-key.pem 747s 299689 4 -rw-r--r-- 1 root root 387 Jul 12 19:08 /tmp/autopkgtest.fgkSUv/roundtrip-artifacts/kresd.conf 747s 299339 8 -rw------- 1 root root 8177 Jul 12 19:08 /tmp/autopkgtest.fgkSUv/roundtrip-artifacts/ca-key.pem 747s 299340 4 -rw-r--r-- 1 root root 1590 Jul 12 19:08 /tmp/autopkgtest.fgkSUv/roundtrip-artifacts/ca-cert.pem 747s 299691 4 -rw-r----- 1 root root 8256 Jul 12 19:08 /tmp/autopkgtest.fgkSUv/roundtrip-artifacts/lock.mdb 747s 299687 4 -rw-r--r-- 1 root root 2218 Jul 12 19:08 /tmp/autopkgtest.fgkSUv/roundtrip-artifacts/ee-pubkey.pem 747s 299690 72 -rw-r--r-- 1 root root 73093 Jul 12 19:08 /tmp/autopkgtest.fgkSUv/roundtrip-artifacts/kresd.err 747s 299692 102400 -rw-r----- 1 root root 104857600 Jul 12 19:08 /tmp/autopkgtest.fgkSUv/roundtrip-artifacts/data.mdb 747s 299693 4 -rw-r--r-- 1 root root 119 Jul 12 19:08 /tmp/autopkgtest.fgkSUv/roundtrip-artifacts/badname.err 747s 299694 4 -rw-r--r-- 1 root root 119 Jul 12 19:08 /tmp/autopkgtest.fgkSUv/roundtrip-artifacts/badca.err 747s 299585 4 -rw-r--r-- 1 root root 1590 Jul 12 19:08 /tmp/autopkgtest.fgkSUv/roundtrip-artifacts/bogus-cert.pem 747s 299688 4 -rw-r--r-- 1 root root 1602 Jul 12 19:08 /tmp/autopkgtest.fgkSUv/roundtrip-artifacts/ee-cert.pem 747s 299686 8 -rw------- 1 root root 8170 Jul 12 19:08 /tmp/autopkgtest.fgkSUv/roundtrip-artifacts/ee-key.pem 747s 299338 4 -rw-r--r-- 1 root root 136 Jul 12 19:08 /tmp/autopkgtest.fgkSUv/roundtrip-artifacts/ca.template 747s 299685 4 -rw-r--r-- 1 root root 92 Jul 12 19:08 /tmp/autopkgtest.fgkSUv/roundtrip-artifacts/ee.template 747s ==> /tmp/autopkgtest.fgkSUv/roundtrip-artifacts/badca.err <== 747s ;; WARNING: TLS, handshake failed (Error in the certificate.) 747s ;; ERROR: failed to query server 127.155.31.73@8853(TCP) 747s 747s ==> /tmp/autopkgtest.fgkSUv/roundtrip-artifacts/badname.err <== 747s ;; WARNING: TLS, handshake failed (Error in the certificate.) 747s ;; ERROR: failed to query server 127.155.31.73@8853(TCP) 747s 747s ==> /tmp/autopkgtest.fgkSUv/roundtrip-artifacts/kresd.err <== 747s [system] increasing file-descriptor limit: 1024 -> 1073741816 747s [tls ] session ticket: epoch 420119, scheduling rotation check in 222433 ms 747s [wtchdg] disabled in systemd (WatchdogSec= not specified) 747s [ta ] installed trust anchors for domain . are: 747s . 86400 DNSKEY 257 3 8 AwEAAaz/tAm8yTn4Mfeh5eyI96WSVexTBAvkMgJzkKTOiW1vkIbzxeF3+/4RgWOq7HrxRixHlFlExOLAJr5emLvN7SWXgnLh4+B5xQlNVz8Og8kvArMtNROxVQuCaSnIDdD5LKyWbRd2n9WGe2R8PzgCmr3EgVLrjyBxWezF0jLHwVN8efS3rCj/EWgvIWgb9tarpVUDK/b58Da+sqqls3eNbuv7pr+eoZG+SrDK6nWeL3c6H5Apxz7LjVc1uTIdsIXxuOLYA4/ilBmSVIzuDWfdRUfhHdY6+cn8HFRm+2hM8AnXGXws9555KrUB5qihylGa8subX2Nn6UwNR1AkUTV74bU= ; Valid: ; KeyTag:20326 747s 747s [system] loading config '/tmp/autopkgtest.fgkSUv/roundtrip-artifacts/kresd.conf' (workdir '/tmp/autopkgtest.fgkSUv/roundtrip-artifacts') 747s [system] deprecation WARNING: use log_level() instead of verbose() 747s [gnutls] (3) ASSERT: ../../../lib/x509/dn.c[_gnutls_x509_compare_raw_dn]:974 747s [gnutls] (3) ASSERT: ../../../lib/x509/dn.c[_gnutls_x509_compare_raw_dn]:974 747s [gnutls] (3) ASSERT: ../../../lib/x509/x509_ext.c[gnutls_subject_alt_names_get]:111 747s [gnutls] (3) ASSERT: ../../../lib/x509/x509.c[get_alt_name]:2012 747s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 747s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 747s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 747s [tls ] RFC 7858 OOB key-pin (0): pin-sha256="" 747s [gnutls] (3) ASSERT: ../../lib/cert-cred-x509.c[gnutls_certificate_get_x509_crt]:872 747s [system] loading config '/usr/lib/aarch64-linux-gnu/knot-resolver/postconfig.lua' (workdir '/tmp/autopkgtest.fgkSUv/roundtrip-artifacts') 747s [plan ][00000.00] plan '.' type 'NS' uid [65536.00] 747s [iterat][65536.00] '.' type 'NS' new uid was assigned .01, parent uid .00 747s [resolv][65536.01] => using root hints 747s [iterat][65536.01] '.' type 'NS' new uid was assigned .02, parent uid .00 747s [resolv][65536.02] >< TA: '.' 747s [plan ][65536.02] plan '.' type 'DNSKEY' uid [65536.03] 747s [iterat][65536.03] '.' type 'DNSKEY' new uid was assigned .04, parent uid .02 747s [select][65536.04] => id: '02599' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 747s [select][65536.04] => id: '02599' choosing: 'C.ROOT-SERVERS.NET.'@'2001:500:2::c#00053' with timeout 400 ms zone cut: '.' 747s [resolv][65536.04] => id: '02599' querying: 'C.ROOT-SERVERS.NET.'@'2001:500:2::c#00053' zone cut: '.' qname: '.' qtype: 'DNSKEY' proto: 'udp' 747s [plan ][00000.00] plan '.' type 'NS' uid [65537.00] 747s [iterat][65537.00] '.' type 'NS' new uid was assigned .01, parent uid .00 747s [resolv][65537.01] => using root hints 747s [iterat][65537.01] '.' type 'NS' new uid was assigned .02, parent uid .00 747s [select][65537.02] => id: '60668' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 747s [select][65537.02] => id: '60668' choosing: 'D.ROOT-SERVERS.NET.'@'199.7.91.13#00053' with timeout 400 ms zone cut: '.' 747s [resolv][65537.02] => id: '60668' querying: 'D.ROOT-SERVERS.NET.'@'199.7.91.13#00053' zone cut: '.' qname: '.' qtype: 'NS' proto: 'udp' 747s [taupd ] refreshing TA for . 747s [plan ][00000.00] plan '.' type 'DNSKEY' uid [65538.00] 747s [iterat][65538.00] '.' type 'DNSKEY' new uid was assigned .01, parent uid .00 747s [resolv][65538.01] => using root hints 747s [iterat][65538.01] '.' type 'DNSKEY' new uid was assigned .02, parent uid .00 747s [resolv][65538.02] >< TA: '.' 747s [select][65538.02] => id: '15202' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 747s [select][65538.02] => id: '15202' choosing: 'H.ROOT-SERVERS.NET.'@'2001:500:1::53#00053' with timeout 400 ms zone cut: '.' 747s [select][65536.04] NO6: timed out, appended, timeouts 1/6 747s [select][65536.04] => id: '02599' noting selection error: 'C.ROOT-SERVERS.NET.'@'2001:500:2::c#00053' zone cut: '.' error: 1 QUERY_TIMEOUT 747s [iterat][65538.02] '.' type 'DNSKEY' new uid was assigned .03, parent uid .00 747s [select][65538.03] => id: '18946' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 747s [select][65538.03] => id: '18946' choosing: 'M.ROOT-SERVERS.NET.'@'2001:dc3::35#00053' with timeout 400 ms zone cut: '.' 747s [resolv][65538.03] => id: '18946' querying: 'M.ROOT-SERVERS.NET.'@'2001:dc3::35#00053' zone cut: '.' qname: '.' qtype: 'DNSKEY' proto: 'udp' 747s [iterat][65536.04] '.' type 'DNSKEY' new uid was assigned .05, parent uid .02 747s [select][65536.05] => id: '39220' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 747s [select][65536.05] => id: '39220' choosing: 'G.ROOT-SERVERS.NET.'@'2001:500:12::d0d#00053' with timeout 800 ms zone cut: '.' 747s [select][65537.02] => id: '60668' noting selection error: 'D.ROOT-SERVERS.NET.'@'199.7.91.13#00053' zone cut: '.' error: 1 QUERY_TIMEOUT 747s [iterat][65537.02] '.' type 'NS' new uid was assigned .03, parent uid .00 747s [select][65537.03] => id: '16971' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 747s [select][65537.03] => id: '16971' choosing: 'H.ROOT-SERVERS.NET.'@'198.97.190.53#00053' with timeout 800 ms zone cut: '.' 747s [resolv][65537.03] => id: '16971' querying: 'H.ROOT-SERVERS.NET.'@'198.97.190.53#00053' zone cut: '.' qname: '.' qtype: 'NS' proto: 'udp' 747s [select][65538.03] NO6: timed out, appended, timeouts 2/6 747s [select][65538.03] => id: '18946' noting selection error: 'M.ROOT-SERVERS.NET.'@'2001:dc3::35#00053' zone cut: '.' error: 1 QUERY_TIMEOUT 747s [iterat][65536.05] '.' type 'DNSKEY' new uid was assigned .06, parent uid .02 747s [select][65536.06] => id: '44116' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 747s [select][65536.06] => id: '44116' choosing: 'H.ROOT-SERVERS.NET.'@'2001:500:1::53#00053' with timeout 800 ms zone cut: '.' 747s [resolv][65536.06] => id: '44116' querying: 'H.ROOT-SERVERS.NET.'@'2001:500:1::53#00053' zone cut: '.' qname: '.' qtype: 'DNSKEY' proto: 'udp' 747s [iterat][65538.03] '.' type 'DNSKEY' new uid was assigned .04, parent uid .00 747s [select][65538.04] => id: '46222' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 747s [select][65538.04] => id: '46222' choosing: 'B.ROOT-SERVERS.NET.'@'2801:1b8:10::b#00053' with timeout 800 ms zone cut: '.' 747s [plan ][00000.00] plan 'monkeys.example.' type 'A' uid [03749.00] 747s [iterat][03749.00] 'monkeys.example.' type 'A' new uid was assigned .01, parent uid .00 747s [hint ][03749.01] <= answered from hints 747s [iterat][03749.01] <= rcode: NOERROR 747s [resolv][03749.01] AD: request NOT classified as SECURE 747s [resolv][03749.01] finished in state: 4, queries: 1, mempool: 16400 B 747s [plan ][00000.00] plan 'monkeys.example.' type 'A' uid [07908.00] 747s [iterat][07908.00] 'monkeys.example.' type 'A' new uid was assigned .01, parent uid .00 747s [hint ][07908.01] <= answered from hints 747s [iterat][07908.01] <= rcode: NOERROR 747s [resolv][07908.01] AD: request NOT classified as SECURE 747s [resolv][07908.01] finished in state: 4, queries: 1, mempool: 81952 B 747s [io ] => connection to '127.0.0.1#42331' closed by peer (end of file) 747s [gnutls] (5) REC[0xf77d0d460000]: Allocating epoch #0 747s [gnutls] (2) added 3 protocols, 29 ciphersuites, 19 sig algos and 10 groups into priority list 747s [gnutls] (5) REC[0xf77d0d460000]: Allocating epoch #1 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 747s [gnutls] (5) REC[0xf77d0d460000]: SSL 3.3 Handshake packet received. Epoch 0, length: 374 747s [gnutls] (5) REC[0xf77d0d460000]: Expected Packet Handshake(22) 747s [gnutls] (5) REC[0xf77d0d460000]: Received Packet Handshake(22) with length: 374 747s [gnutls] (5) REC[0xf77d0d460000]: Decrypted Packet[0] Handshake(22) with length: 374 747s [gnutls] (4) HSK[0xf77d0d460000]: CLIENT HELLO (1) was received. Length 370[370], frag offset 0, frag length: 370, sequence: 0 747s [gnutls] (4) HSK[0xf77d0d460000]: Client's version: 3.3 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Supported Versions/43' (5 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Found version: 3.4 747s [gnutls] (4) EXT[0xf77d0d460000]: Found version: 3.3 747s [gnutls] (4) EXT[0xf77d0d460000]: Negotiated version: 3.4 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'ALPN/16' (6 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Encrypt-then-MAC/22' (0 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Record Size Limit/28' (2 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: record_size_limit 16385 negotiated 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Extended Master Secret/23' (0 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Safe Renegotiation/65281' (1 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Signature Algorithms/13' (34 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (4.1) RSA-SHA256 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.9) RSA-PSS-SHA256 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.4) RSA-PSS-RSAE-SHA256 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (4.3) ECDSA-SECP256R1-SHA256 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.7) EdDSA-Ed25519 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (5.1) RSA-SHA384 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.10) RSA-PSS-SHA384 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.5) RSA-PSS-RSAE-SHA384 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (5.3) ECDSA-SECP384R1-SHA384 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.8) EdDSA-Ed448 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (6.1) RSA-SHA512 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.11) RSA-PSS-SHA512 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.6) RSA-PSS-RSAE-SHA512 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (6.3) ECDSA-SECP521R1-SHA512 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (2.1) RSA-SHA1 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (2.3) ECDSA-SHA1 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Supported EC Point Formats/11' (2 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Supported Groups/10' (22 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group SECP256R1 (0x17) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group SECP384R1 (0x18) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group SECP521R1 (0x19) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group X25519 (0x1d) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group X448 (0x1e) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group FFDHE2048 (0x100) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group FFDHE3072 (0x101) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group FFDHE4096 (0x102) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group FFDHE6144 (0x103) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group FFDHE8192 (0x104) 747s [gnutls] (4) EXT[0xf77d0d460000]: Selected group SECP256R1 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'PSK Key Exchange Modes/45' (3 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: PSK KE mode 01 received 747s [gnutls] (4) EXT[0xf77d0d460000]: PSK KE mode 00 received 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Session Ticket/35' (0 bytes) 747s [gnutls] (2) checking 13.02 (GNUTLS_AES_256_GCM_SHA384) for compatibility 747s [gnutls] (3) ASSERT: ../../../lib/ext/server_name.c[gnutls_server_name_get]:234 747s [gnutls] (4) HSK[0xf77d0d460000]: Requested server name: '' 747s [gnutls] (4) HSK[0xf77d0d460000]: checking compat of GNUTLS_AES_256_GCM_SHA384 with certificate[0] (RSA/X.509) 747s [gnutls] (4) checking cert compat with RSA-SHA256 747s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 747s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 747s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 747s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 747s [gnutls] (4) Selected signature algorithm: RSA-PSS-RSAE-SHA256 747s [gnutls] (2) Selected (RSA) cert based on ciphersuite 13.2: GNUTLS_AES_256_GCM_SHA384 747s [gnutls] (4) HSK[0xf77d0d460000]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384 747s [gnutls] (4) HSK[0xf77d0d460000]: Selected version TLS1.3 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'OCSP Status Request/5' (5 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: OCSP status was requested 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Key Share/51' (107 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received key share for SECP256R1 747s [gnutls] (4) HSK[0xf77d0d460000]: Selected group SECP256R1 (2) 747s [gnutls] (2) EXT[0xf77d0d460000]: server generated SECP256R1 shared key 747s [gnutls] (4) HSK[0xf77d0d460000]: Safe renegotiation succeeded 747s [gnutls] (4) HSK[0xf77d0d460000]: SessionID: 05d892898848e118bf0698937076aaae759389b3882c3f36350267fff065723f 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Safe Renegotiation/65281) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Extended Master Secret/23) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (PSK Key Exchange Modes/45) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Session Ticket/35) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Client Certificate Type/19) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Supported EC Point Formats/11) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Server Name Indication/0) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Encrypt-then-MAC/22) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Record Size Limit/28) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (ALPN/16) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Signature Algorithms/13) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Maximum Record Size/1) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Compress Certificate/27) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (OCSP Status Request/5) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (SRTP/14) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Server Certificate Type/20) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Post Handshake Auth/49) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Supported Groups/10) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Cookie/44) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Early Data/42) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Key Share/51) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: sending key share for SECP256R1 747s [gnutls] (4) EXT[0xf77d0d460000]: Sending extension Key Share/51 (69 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Supported Versions/43) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Sending extension Supported Versions/43 (2 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (ClientHello Padding/21) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Pre Shared Key/41) for 'TLS 1.3 server hello' 747s [gnutls] (4) HSK[0xf77d0d460000]: SERVER HELLO was queued [155 bytes] 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 155 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 160 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6 747s [gnutls] (4) REC[0xf77d0d460000]: Sent ChangeCipherSpec 747s [gnutls] (5) REC[0xf77d0d460000]: Initializing epoch #1 747s [gnutls] (5) REC[0xf77d0d460000]: Epoch #1 ready 747s [gnutls] (4) HSK[0xf77d0d460000]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Record Size Limit/28) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Sending extension Record Size Limit/28 (2 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (PSK Key Exchange Modes/45) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Key Share/51) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Extended Master Secret/23) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Client Certificate Type/19) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (ALPN/16) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Sending extension ALPN/16 (6 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Supported Groups/10) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (OCSP Status Request/5) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Cookie/44) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (SRTP/14) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Maximum Record Size/1) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Compress Certificate/27) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Safe Renegotiation/65281) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Supported Versions/43) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Encrypt-then-MAC/22) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Early Data/42) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Supported EC Point Formats/11) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Post Handshake Auth/49) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Server Certificate Type/20) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Session Ticket/35) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Signature Algorithms/13) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Server Name Indication/0) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (ClientHello Padding/21) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Pre Shared Key/41) for 'encrypted extensions' 747s [gnutls] (4) HSK[0xf77d0d460000]: ENCRYPTED EXTENSIONS was queued [22 bytes] 747s [gnutls] (4) HSK[0xf77d0d460000]: CERTIFICATE was queued [1155 bytes] 747s [gnutls] (4) checking cert compat with RSA-SHA256 747s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 747s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 747s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 747s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 747s [gnutls] (4) HSK[0xf77d0d460000]: signing TLS 1.3 handshake data: using RSA-PSS-RSAE-SHA256 and PRF: SHA384 747s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 747s [gnutls] (4) HSK[0xf77d0d460000]: CERTIFICATE VERIFY was queued [392 bytes] 747s [gnutls] (4) HSK[0xf77d0d460000]: sending finished 747s [gnutls] (4) HSK[0xf77d0d460000]: FINISHED was queued [52 bytes] 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 22 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 44 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 1155 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[2] Handshake(22) in epoch 1 and length: 1177 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 392 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[3] Handshake(22) in epoch 1 and length: 414 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 52 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[4] Handshake(22) in epoch 1 and length: 74 747s [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:965 747s [gnutls] (5) REC[0xf77d0d460000]: Allocating epoch #2 747s [gnutls] (4) HSK[0xf77d0d460000]: unauthenticated session eligible for early start 747s [gnutls] (5) REC[0xf77d0d460000]: Initializing epoch #2 747s [gnutls] (5) REC[0xf77d0d460000]: Epoch #2 ready 747s [gnutls] (4) HSK[0xf77d0d460000]: TLS 1.3 set write key with cipher suite: GNUTLS_AES_256_GCM_SHA384 747s [gnutls] (4) HSK[0xf77d0d460000]: switching early to application traffic keys 747s [gnutls] (4) HSK[0xf77d0d460000]: NEW SESSION TICKET was queued [251 bytes] 747s [gnutls] (4) HSK[0xf77d0d460000]: NEW SESSION TICKET was queued [251 bytes] 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[1] Handshake(22) in epoch 2 and length: 273 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[2] Handshake(22) in epoch 2 and length: 273 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 747s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 747s [gnutls] (5) REC[0xf77d0d460000]: SSL 3.3 ChangeCipherSpec packet received. Epoch 1, length: 1 747s [gnutls] (5) REC[0xf77d0d460000]: Expected Packet Handshake(22) 747s [gnutls] (5) REC[0xf77d0d460000]: Received Packet ChangeCipherSpec(20) with length: 1 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 747s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 747s [gnutls] (5) REC[0xf77d0d460000]: SSL 3.3 Application Data packet received. Epoch 1, length: 69 747s [gnutls] (5) REC[0xf77d0d460000]: Expected Packet Handshake(22) 747s [gnutls] (5) REC[0xf77d0d460000]: Received Packet Application Data(23) with length: 69 747s [gnutls] (5) REC[0xf77d0d460000]: Decrypted Packet[0] Handshake(22) with length: 52 747s [gnutls] (4) HSK[0xf77d0d460000]: FINISHED (20) was received. Length 48[48], frag offset 0, frag length: 48, sequence: 0 747s [gnutls] (4) HSK[0xf77d0d460000]: parsing finished 747s [gnutls] (4) HSK[0xf77d0d460000]: TLS 1.3 set read key with cipher suite: GNUTLS_AES_256_GCM_SHA384 747s [gnutls] (5) REC[0xf77d0d460000]: Start of epoch cleanup 747s [gnutls] (5) REC[0xf77d0d460000]: Epoch #0 freed 747s [gnutls] (5) REC[0xf77d0d460000]: Epoch #1 freed 747s [gnutls] (5) REC[0xf77d0d460000]: End of epoch cleanup 747s [tls ] TLS handshake with 127.0.0.1#53611 has completed 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 747s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1759 747s [gnutls] (5) REC[0xf77d0d460000]: SSL 3.3 Application Data packet received. Epoch 2, length: 147 747s [gnutls] (5) REC[0xf77d0d460000]: Expected Packet Application Data(23) 747s [gnutls] (5) REC[0xf77d0d460000]: Received Packet Application Data(23) with length: 147 747s [gnutls] (5) REC[0xf77d0d460000]: Decrypted Packet[0] Application Data(23) with length: 130 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 747s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1759 747s [plan ][00000.00] plan 'monkeys.example.' type 'A' uid [49070.00] 747s [iterat][49070.00] 'monkeys.example.' type 'A' new uid was assigned .01, parent uid .00 747s [hint ][49070.01] <= answered from hints 747s [iterat][49070.01] <= rcode: NOERROR 747s [resolv][49070.01] AD: request NOT classified as SECURE 747s [resolv][49070.01] finished in state: 4, queries: 1, mempool: 81952 B 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Application Data(23) with length: 470 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[3] Application Data(23) in epoch 2 and length: 492 747s [gnutls] (5) REC[0xf77d0d460000]: SSL 3.3 Application Data packet received. Epoch 2, length: 19 747s [gnutls] (5) REC[0xf77d0d460000]: Expected Packet Application Data(23) 747s [gnutls] (5) REC[0xf77d0d460000]: Received Packet Application Data(23) with length: 19 747s [gnutls] (5) REC[0xf77d0d460000]: Decrypted Packet[1] Alert(21) with length: 2 747s [gnutls] (5) REC[0xf77d0d460000]: Alert[1|0] - Close notify - was received 747s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_in_buffers]:1565 747s [io ] => connection to '127.0.0.1#53611' closed by peer (end of file) 747s [gnutls] (5) REC[0xf77d0d460000]: Start of epoch cleanup 747s [gnutls] (5) REC[0xf77d0d460000]: End of epoch cleanup 747s [gnutls] (5) REC[0xf77d0d460000]: Epoch #2 freed 747s [gnutls] (5) REC[0xf77d0d460000]: Allocating epoch #0 747s [gnutls] (2) added 3 protocols, 29 ciphersuites, 19 sig algos and 10 groups into priority list 747s [gnutls] (5) REC[0xf77d0d460000]: Allocating epoch #1 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 747s [gnutls] (5) REC[0xf77d0d460000]: SSL 3.3 Handshake packet received. Epoch 0, length: 395 747s [gnutls] (5) REC[0xf77d0d460000]: Expected Packet Handshake(22) 747s [gnutls] (5) REC[0xf77d0d460000]: Received Packet Handshake(22) with length: 395 747s [gnutls] (5) REC[0xf77d0d460000]: Decrypted Packet[0] Handshake(22) with length: 395 747s [gnutls] (4) HSK[0xf77d0d460000]: CLIENT HELLO (1) was received. Length 391[391], frag offset 0, frag length: 391, sequence: 0 747s [gnutls] (4) HSK[0xf77d0d460000]: Client's version: 3.3 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Supported Versions/43' (5 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Found version: 3.4 747s [gnutls] (4) EXT[0xf77d0d460000]: Found version: 3.3 747s [gnutls] (4) EXT[0xf77d0d460000]: Negotiated version: 3.4 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'ALPN/16' (6 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Server Name Indication/0' (17 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Safe Renegotiation/65281' (1 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Record Size Limit/28' (2 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: record_size_limit 16385 negotiated 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Encrypt-then-MAC/22' (0 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Extended Master Secret/23' (0 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Session Ticket/35' (0 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Supported Groups/10' (22 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group SECP256R1 (0x17) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group SECP384R1 (0x18) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group SECP521R1 (0x19) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group X25519 (0x1d) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group X448 (0x1e) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group FFDHE2048 (0x100) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group FFDHE3072 (0x101) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group FFDHE4096 (0x102) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group FFDHE6144 (0x103) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group FFDHE8192 (0x104) 747s [gnutls] (4) EXT[0xf77d0d460000]: Selected group SECP256R1 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Signature Algorithms/13' (34 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (4.1) RSA-SHA256 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.9) RSA-PSS-SHA256 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.4) RSA-PSS-RSAE-SHA256 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (4.3) ECDSA-SECP256R1-SHA256 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.7) EdDSA-Ed25519 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (5.1) RSA-SHA384 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.10) RSA-PSS-SHA384 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.5) RSA-PSS-RSAE-SHA384 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (5.3) ECDSA-SECP384R1-SHA384 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.8) EdDSA-Ed448 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (6.1) RSA-SHA512 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.11) RSA-PSS-SHA512 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.6) RSA-PSS-RSAE-SHA512 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (6.3) ECDSA-SECP521R1-SHA512 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (2.1) RSA-SHA1 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (2.3) ECDSA-SHA1 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'PSK Key Exchange Modes/45' (3 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: PSK KE mode 01 received 747s [gnutls] (4) EXT[0xf77d0d460000]: PSK KE mode 00 received 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Supported EC Point Formats/11' (2 bytes) 747s [gnutls] (2) checking 13.02 (GNUTLS_AES_256_GCM_SHA384) for compatibility 747s [gnutls] (4) HSK[0xf77d0d460000]: Requested server name: 'test.example' 747s [gnutls] (4) checking cert compat with RSA-SHA256 747s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 747s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 747s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 747s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 747s [gnutls] (4) Selected signature algorithm: RSA-PSS-RSAE-SHA256 747s [gnutls] (2) Selected (RSA) cert based on ciphersuite 13.2: GNUTLS_AES_256_GCM_SHA384 747s [gnutls] (4) HSK[0xf77d0d460000]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384 747s [gnutls] (4) HSK[0xf77d0d460000]: Selected version TLS1.3 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'OCSP Status Request/5' (5 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: OCSP status was requested 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Key Share/51' (107 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received key share for SECP256R1 747s [gnutls] (4) HSK[0xf77d0d460000]: Selected group SECP256R1 (2) 747s [gnutls] (2) EXT[0xf77d0d460000]: server generated SECP256R1 shared key 747s [gnutls] (4) HSK[0xf77d0d460000]: Safe renegotiation succeeded 747s [gnutls] (4) HSK[0xf77d0d460000]: SessionID: d20d53b6901f190be283d7b11a5a90aedef7310cf96a60ffa26de62119c541a2 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Supported Groups/10) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Server Certificate Type/20) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Client Certificate Type/19) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Extended Master Secret/23) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Key Share/51) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: sending key share for SECP256R1 747s [gnutls] (4) EXT[0xf77d0d460000]: Sending extension Key Share/51 (69 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (ALPN/16) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (OCSP Status Request/5) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Maximum Record Size/1) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Supported Versions/43) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Sending extension Supported Versions/43 (2 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (SRTP/14) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Record Size Limit/28) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Post Handshake Auth/49) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Signature Algorithms/13) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Early Data/42) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Session Ticket/35) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (PSK Key Exchange Modes/45) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Cookie/44) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Compress Certificate/27) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Supported EC Point Formats/11) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Safe Renegotiation/65281) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Server Name Indication/0) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Encrypt-then-MAC/22) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (ClientHello Padding/21) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Pre Shared Key/41) for 'TLS 1.3 server hello' 747s [gnutls] (4) HSK[0xf77d0d460000]: SERVER HELLO was queued [155 bytes] 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 155 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 160 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6 747s [gnutls] (4) REC[0xf77d0d460000]: Sent ChangeCipherSpec 747s [gnutls] (5) REC[0xf77d0d460000]: Initializing epoch #1 747s [gnutls] (5) REC[0xf77d0d460000]: Epoch #1 ready 747s [gnutls] (4) HSK[0xf77d0d460000]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Client Certificate Type/19) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (OCSP Status Request/5) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Cookie/44) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Signature Algorithms/13) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (PSK Key Exchange Modes/45) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Supported EC Point Formats/11) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (SRTP/14) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Session Ticket/35) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Compress Certificate/27) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Server Name Indication/0) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Extended Master Secret/23) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Early Data/42) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Encrypt-then-MAC/22) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (ALPN/16) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Sending extension ALPN/16 (6 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Maximum Record Size/1) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Post Handshake Auth/49) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Server Certificate Type/20) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Record Size Limit/28) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Sending extension Record Size Limit/28 (2 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Supported Groups/10) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Key Share/51) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Supported Versions/43) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Safe Renegotiation/65281) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (ClientHello Padding/21) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Pre Shared Key/41) for 'encrypted extensions' 747s [gnutls] (4) HSK[0xf77d0d460000]: ENCRYPTED EXTENSIONS was queued [22 bytes] 747s [gnutls] (4) HSK[0xf77d0d460000]: CERTIFICATE was queued [1155 bytes] 747s [gnutls] (4) checking cert compat with RSA-SHA256 747s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 747s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 747s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 747s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 747s [gnutls] (4) HSK[0xf77d0d460000]: signing TLS 1.3 handshake data: using RSA-PSS-RSAE-SHA256 and PRF: SHA384 747s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 747s [gnutls] (4) HSK[0xf77d0d460000]: CERTIFICATE VERIFY was queued [392 bytes] 747s [gnutls] (4) HSK[0xf77d0d460000]: sending finished 747s [gnutls] (4) HSK[0xf77d0d460000]: FINISHED was queued [52 bytes] 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 22 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 44 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 1155 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[2] Handshake(22) in epoch 1 and length: 1177 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 392 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[3] Handshake(22) in epoch 1 and length: 414 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 52 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[4] Handshake(22) in epoch 1 and length: 74 747s [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:965 747s [gnutls] (5) REC[0xf77d0d460000]: Allocating epoch #2 747s [gnutls] (4) HSK[0xf77d0d460000]: unauthenticated session eligible for early start 747s [gnutls] (5) REC[0xf77d0d460000]: Initializing epoch #2 747s [gnutls] (5) REC[0xf77d0d460000]: Epoch #2 ready 747s [gnutls] (4) HSK[0xf77d0d460000]: TLS 1.3 set write key with cipher suite: GNUTLS_AES_256_GCM_SHA384 747s [gnutls] (4) HSK[0xf77d0d460000]: switching early to application traffic keys 747s [gnutls] (4) HSK[0xf77d0d460000]: NEW SESSION TICKET was queued [251 bytes] 747s [gnutls] (4) HSK[0xf77d0d460000]: NEW SESSION TICKET was queued [251 bytes] 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[1] Handshake(22) in epoch 2 and length: 273 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[2] Handshake(22) in epoch 2 and length: 273 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 747s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 747s [gnutls] (5) REC[0xf77d0d460000]: SSL 3.3 ChangeCipherSpec packet received. Epoch 1, length: 1 747s [gnutls] (5) REC[0xf77d0d460000]: Expected Packet Handshake(22) 747s [gnutls] (5) REC[0xf77d0d460000]: Received Packet ChangeCipherSpec(20) with length: 1 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 747s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 747s [gnutls] (5) REC[0xf77d0d460000]: SSL 3.3 Application Data packet received. Epoch 1, length: 69 747s [gnutls] (5) REC[0xf77d0d460000]: Expected Packet Handshake(22) 747s [gnutls] (5) REC[0xf77d0d460000]: Received Packet Application Data(23) with length: 69 747s [gnutls] (5) REC[0xf77d0d460000]: Decrypted Packet[0] Handshake(22) with length: 52 747s [gnutls] (4) HSK[0xf77d0d460000]: FINISHED (20) was received. Length 48[48], frag offset 0, frag length: 48, sequence: 0 747s [gnutls] (4) HSK[0xf77d0d460000]: parsing finished 747s [gnutls] (4) HSK[0xf77d0d460000]: TLS 1.3 set read key with cipher suite: GNUTLS_AES_256_GCM_SHA384 747s [gnutls] (5) REC[0xf77d0d460000]: Start of epoch cleanup 747s [gnutls] (5) REC[0xf77d0d460000]: Epoch #0 freed 747s [gnutls] (5) REC[0xf77d0d460000]: Epoch #1 freed 747s [gnutls] (5) REC[0xf77d0d460000]: End of epoch cleanup 747s [tls ] TLS handshake with 127.0.0.1#56017 has completed 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 747s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1759 747s [gnutls] (5) REC[0xf77d0d460000]: SSL 3.3 Application Data packet received. Epoch 2, length: 147 747s [gnutls] (5) REC[0xf77d0d460000]: Expected Packet Application Data(23) 747s [gnutls] (5) REC[0xf77d0d460000]: Received Packet Application Data(23) with length: 147 747s [gnutls] (5) REC[0xf77d0d460000]: Decrypted Packet[0] Application Data(23) with length: 130 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 747s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1759 747s [plan ][00000.00] plan 'monkeys.example.' type 'A' uid [26759.00] 747s [iterat][26759.00] 'monkeys.example.' type 'A' new uid was assigned .01, parent uid .00 747s [hint ][26759.01] <= answered from hints 747s [iterat][26759.01] <= rcode: NOERROR 747s [resolv][26759.01] AD: request NOT classified as SECURE 747s [resolv][26759.01] finished in state: 4, queries: 1, mempool: 81952 B 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Application Data(23) with length: 470 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[3] Application Data(23) in epoch 2 and length: 492 747s [gnutls] (5) REC[0xf77d0d460000]: SSL 3.3 Application Data packet received. Epoch 2, length: 19 747s [gnutls] (5) REC[0xf77d0d460000]: Expected Packet Application Data(23) 747s [gnutls] (5) REC[0xf77d0d460000]: Received Packet Application Data(23) with length: 19 747s [gnutls] (5) REC[0xf77d0d460000]: Decrypted Packet[1] Alert(21) with length: 2 747s [gnutls] (5) REC[0xf77d0d460000]: Alert[1|0] - Close notify - was received 747s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_in_buffers]:1565 747s [io ] => connection to '127.0.0.1#56017' closed by peer (end of file) 747s [gnutls] (5) REC[0xf77d0d460000]: Start of epoch cleanup 747s [gnutls] (5) REC[0xf77d0d460000]: End of epoch cleanup 747s [gnutls] (5) REC[0xf77d0d460000]: Epoch #2 freed 747s [gnutls] (5) REC[0xf77d0d460000]: Allocating epoch #0 747s [gnutls] (2) added 3 protocols, 29 ciphersuites, 19 sig algos and 10 groups into priority list 747s [gnutls] (5) REC[0xf77d0d460000]: Allocating epoch #1 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 747s [gnutls] (5) REC[0xf77d0d460000]: SSL 3.3 Handshake packet received. Epoch 0, length: 399 747s [gnutls] (5) REC[0xf77d0d460000]: Expected Packet Handshake(22) 747s [gnutls] (5) REC[0xf77d0d460000]: Received Packet Handshake(22) with length: 399 747s [gnutls] (5) REC[0xf77d0d460000]: Decrypted Packet[0] Handshake(22) with length: 399 747s [gnutls] (4) HSK[0xf77d0d460000]: CLIENT HELLO (1) was received. Length 395[395], frag offset 0, frag length: 395, sequence: 0 747s [gnutls] (4) HSK[0xf77d0d460000]: Client's version: 3.3 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Supported Versions/43' (5 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Found version: 3.4 747s [gnutls] (4) EXT[0xf77d0d460000]: Found version: 3.3 747s [gnutls] (4) EXT[0xf77d0d460000]: Negotiated version: 3.4 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Record Size Limit/28' (2 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: record_size_limit 16385 negotiated 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Safe Renegotiation/65281' (1 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Encrypt-then-MAC/22' (0 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Extended Master Secret/23' (0 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Server Name Indication/0' (21 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'ALPN/16' (6 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'PSK Key Exchange Modes/45' (3 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: PSK KE mode 01 received 747s [gnutls] (4) EXT[0xf77d0d460000]: PSK KE mode 00 received 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Signature Algorithms/13' (34 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (4.1) RSA-SHA256 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.9) RSA-PSS-SHA256 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.4) RSA-PSS-RSAE-SHA256 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (4.3) ECDSA-SECP256R1-SHA256 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.7) EdDSA-Ed25519 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (5.1) RSA-SHA384 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.10) RSA-PSS-SHA384 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.5) RSA-PSS-RSAE-SHA384 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (5.3) ECDSA-SECP384R1-SHA384 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.8) EdDSA-Ed448 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (6.1) RSA-SHA512 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.11) RSA-PSS-SHA512 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.6) RSA-PSS-RSAE-SHA512 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (6.3) ECDSA-SECP521R1-SHA512 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (2.1) RSA-SHA1 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (2.3) ECDSA-SHA1 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Supported Groups/10' (22 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group SECP256R1 (0x17) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group SECP384R1 (0x18) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group SECP521R1 (0x19) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group X25519 (0x1d) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group X448 (0x1e) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group FFDHE2048 (0x100) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group FFDHE3072 (0x101) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group FFDHE4096 (0x102) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group FFDHE6144 (0x103) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group FFDHE8192 (0x104) 747s [gnutls] (4) EXT[0xf77d0d460000]: Selected group SECP256R1 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Session Ticket/35' (0 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Supported EC Point Formats/11' (2 bytes) 747s [gnutls] (2) checking 13.02 (GNUTLS_AES_256_GCM_SHA384) for compatibility 747s [gnutls] (4) HSK[0xf77d0d460000]: Requested server name: 'notright.example' 747s [gnutls] (4) HSK[0xf77d0d460000]: checking compat of GNUTLS_AES_256_GCM_SHA384 with certificate[0] (RSA/X.509) 747s [gnutls] (4) checking cert compat with RSA-SHA256 747s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 747s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 747s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 747s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 747s [gnutls] (4) Selected signature algorithm: RSA-PSS-RSAE-SHA256 747s [gnutls] (2) Selected (RSA) cert based on ciphersuite 13.2: GNUTLS_AES_256_GCM_SHA384 747s [gnutls] (4) HSK[0xf77d0d460000]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384 747s [gnutls] (4) HSK[0xf77d0d460000]: Selected version TLS1.3 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Key Share/51' (107 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received key share for SECP256R1 747s [gnutls] (4) HSK[0xf77d0d460000]: Selected group SECP256R1 (2) 747s [gnutls] (2) EXT[0xf77d0d460000]: server generated SECP256R1 shared key 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'OCSP Status Request/5' (5 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: OCSP status was requested 747s [gnutls] (4) HSK[0xf77d0d460000]: Safe renegotiation succeeded 747s [gnutls] (4) HSK[0xf77d0d460000]: SessionID: 598fdfd0438254e3341dc3e4797b97eb5c980885bc9a429096a8578c52f0825d 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (PSK Key Exchange Modes/45) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Extended Master Secret/23) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Compress Certificate/27) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (ALPN/16) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Maximum Record Size/1) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Post Handshake Auth/49) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Supported Versions/43) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Sending extension Supported Versions/43 (2 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Supported Groups/10) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Early Data/42) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Key Share/51) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: sending key share for SECP256R1 747s [gnutls] (4) EXT[0xf77d0d460000]: Sending extension Key Share/51 (69 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Supported EC Point Formats/11) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Client Certificate Type/19) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Signature Algorithms/13) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Safe Renegotiation/65281) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Record Size Limit/28) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (SRTP/14) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Cookie/44) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Encrypt-then-MAC/22) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Server Name Indication/0) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Server Certificate Type/20) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (OCSP Status Request/5) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Session Ticket/35) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (ClientHello Padding/21) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Pre Shared Key/41) for 'TLS 1.3 server hello' 747s [gnutls] (4) HSK[0xf77d0d460000]: SERVER HELLO was queued [155 bytes] 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 155 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 160 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6 747s [gnutls] (4) REC[0xf77d0d460000]: Sent ChangeCipherSpec 747s [gnutls] (5) REC[0xf77d0d460000]: Initializing epoch #1 747s [gnutls] (5) REC[0xf77d0d460000]: Epoch #1 ready 747s [gnutls] (4) HSK[0xf77d0d460000]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (ALPN/16) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Sending extension ALPN/16 (6 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (SRTP/14) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Supported Versions/43) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Session Ticket/35) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Server Name Indication/0) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Maximum Record Size/1) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Supported Groups/10) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Extended Master Secret/23) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Early Data/42) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (OCSP Status Request/5) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Supported EC Point Formats/11) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Record Size Limit/28) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Sending extension Record Size Limit/28 (2 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (PSK Key Exchange Modes/45) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Safe Renegotiation/65281) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Post Handshake Auth/49) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Encrypt-then-MAC/22) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Signature Algorithms/13) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Client Certificate Type/19) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Cookie/44) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Compress Certificate/27) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Server Certificate Type/20) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Key Share/51) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (ClientHello Padding/21) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Pre Shared Key/41) for 'encrypted extensions' 747s [gnutls] (4) HSK[0xf77d0d460000]: ENCRYPTED EXTENSIONS was queued [22 bytes] 747s [gnutls] (4) HSK[0xf77d0d460000]: CERTIFICATE was queued [1155 bytes] 747s [gnutls] (4) checking cert compat with RSA-SHA256 747s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 747s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 747s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 747s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 747s [gnutls] (4) HSK[0xf77d0d460000]: signing TLS 1.3 handshake data: using RSA-PSS-RSAE-SHA256 and PRF: SHA384 747s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 747s [gnutls] (4) HSK[0xf77d0d460000]: CERTIFICATE VERIFY was queued [392 bytes] 747s [gnutls] (4) HSK[0xf77d0d460000]: sending finished 747s [gnutls] (4) HSK[0xf77d0d460000]: FINISHED was queued [52 bytes] 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 22 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 44 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 1155 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[2] Handshake(22) in epoch 1 and length: 1177 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 392 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[3] Handshake(22) in epoch 1 and length: 414 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 52 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[4] Handshake(22) in epoch 1 and length: 74 747s [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:965 747s [gnutls] (5) REC[0xf77d0d460000]: Allocating epoch #2 747s [gnutls] (4) HSK[0xf77d0d460000]: unauthenticated session eligible for early start 747s [gnutls] (5) REC[0xf77d0d460000]: Initializing epoch #2 747s [gnutls] (5) REC[0xf77d0d460000]: Epoch #2 ready 747s [gnutls] (4) HSK[0xf77d0d460000]: TLS 1.3 set write key with cipher suite: GNUTLS_AES_256_GCM_SHA384 747s [gnutls] (4) HSK[0xf77d0d460000]: switching early to application traffic keys 747s [gnutls] (4) HSK[0xf77d0d460000]: NEW SESSION TICKET was queued [251 bytes] 747s [gnutls] (4) HSK[0xf77d0d460000]: NEW SESSION TICKET was queued [251 bytes] 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[1] Handshake(22) in epoch 2 and length: 273 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[2] Handshake(22) in epoch 2 and length: 273 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 747s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 747s [gnutls] (5) REC[0xf77d0d460000]: SSL 3.3 ChangeCipherSpec packet received. Epoch 1, length: 1 747s [gnutls] (5) REC[0xf77d0d460000]: Expected Packet Handshake(22) 747s [gnutls] (5) REC[0xf77d0d460000]: Received Packet ChangeCipherSpec(20) with length: 1 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 747s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 747s [io ] => connection to '127.0.0.1#39537' closed by peer (connection reset by peer) 747s [gnutls] (5) REC[0xf77d0d460000]: Start of epoch cleanup 747s [gnutls] (5) REC[0xf77d0d460000]: Epoch #0 freed 747s [gnutls] (5) REC[0xf77d0d460000]: End of epoch cleanup 747s [gnutls] (5) REC[0xf77d0d460000]: Epoch #1 freed 747s [gnutls] (5) REC[0xf77d0d460000]: Epoch #2 freed 747s [gnutls] (5) REC[0xf77d0d460000]: Allocating epoch #0 747s [gnutls] (2) added 3 protocols, 29 ciphersuites, 19 sig algos and 10 groups into priority list 747s [gnutls] (5) REC[0xf77d0d460000]: Allocating epoch #1 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 747s [gnutls] (5) REC[0xf77d0d460000]: SSL 3.3 Handshake packet received. Epoch 0, length: 395 747s [gnutls] (5) REC[0xf77d0d460000]: Expected Packet Handshake(22) 747s [gnutls] (5) REC[0xf77d0d460000]: Received Packet Handshake(22) with length: 395 747s [gnutls] (5) REC[0xf77d0d460000]: Decrypted Packet[0] Handshake(22) with length: 395 747s [gnutls] (4) HSK[0xf77d0d460000]: CLIENT HELLO (1) was received. Length 391[391], frag offset 0, frag length: 391, sequence: 0 747s [gnutls] (4) HSK[0xf77d0d460000]: Client's version: 3.3 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Supported Versions/43' (5 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Found version: 3.4 747s [gnutls] (4) EXT[0xf77d0d460000]: Found version: 3.3 747s [gnutls] (4) EXT[0xf77d0d460000]: Negotiated version: 3.4 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Server Name Indication/0' (17 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Encrypt-then-MAC/22' (0 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'ALPN/16' (6 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Extended Master Secret/23' (0 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Safe Renegotiation/65281' (1 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Record Size Limit/28' (2 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: record_size_limit 16385 negotiated 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Signature Algorithms/13' (34 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (4.1) RSA-SHA256 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.9) RSA-PSS-SHA256 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.4) RSA-PSS-RSAE-SHA256 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (4.3) ECDSA-SECP256R1-SHA256 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.7) EdDSA-Ed25519 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (5.1) RSA-SHA384 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.10) RSA-PSS-SHA384 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.5) RSA-PSS-RSAE-SHA384 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (5.3) ECDSA-SECP384R1-SHA384 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.8) EdDSA-Ed448 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (6.1) RSA-SHA512 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.11) RSA-PSS-SHA512 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (8.6) RSA-PSS-RSAE-SHA512 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (6.3) ECDSA-SECP521R1-SHA512 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (2.1) RSA-SHA1 747s [gnutls] (4) EXT[0xf77d0d460000]: rcvd signature algo (2.3) ECDSA-SHA1 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Session Ticket/35' (0 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'PSK Key Exchange Modes/45' (3 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: PSK KE mode 01 received 747s [gnutls] (4) EXT[0xf77d0d460000]: PSK KE mode 00 received 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Supported EC Point Formats/11' (2 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Supported Groups/10' (22 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group SECP256R1 (0x17) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group SECP384R1 (0x18) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group SECP521R1 (0x19) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group X25519 (0x1d) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group X448 (0x1e) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group FFDHE2048 (0x100) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group FFDHE3072 (0x101) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group FFDHE4096 (0x102) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group FFDHE6144 (0x103) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received group FFDHE8192 (0x104) 747s [gnutls] (4) EXT[0xf77d0d460000]: Selected group SECP256R1 747s [gnutls] (2) checking 13.02 (GNUTLS_AES_256_GCM_SHA384) for compatibility 747s [gnutls] (4) HSK[0xf77d0d460000]: Requested server name: 'test.example' 747s [gnutls] (4) checking cert compat with RSA-SHA256 747s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 747s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 747s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 747s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 747s [gnutls] (4) Selected signature algorithm: RSA-PSS-RSAE-SHA256 747s [gnutls] (2) Selected (RSA) cert based on ciphersuite 13.2: GNUTLS_AES_256_GCM_SHA384 747s [gnutls] (4) HSK[0xf77d0d460000]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384 747s [gnutls] (4) HSK[0xf77d0d460000]: Selected version TLS1.3 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'Key Share/51' (107 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Received key share for SECP256R1 747s [gnutls] (4) HSK[0xf77d0d460000]: Selected group SECP256R1 (2) 747s [gnutls] (2) EXT[0xf77d0d460000]: server generated SECP256R1 shared key 747s [gnutls] (4) EXT[0xf77d0d460000]: Parsing extension 'OCSP Status Request/5' (5 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: OCSP status was requested 747s [gnutls] (4) HSK[0xf77d0d460000]: Safe renegotiation succeeded 747s [gnutls] (4) HSK[0xf77d0d460000]: SessionID: d4001af912e8c64973881faddfb6856c1e634d063fa92d4251040ebdf7c39aa2 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Early Data/42) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Server Certificate Type/20) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Session Ticket/35) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Server Name Indication/0) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Compress Certificate/27) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Encrypt-then-MAC/22) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Maximum Record Size/1) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Key Share/51) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: sending key share for SECP256R1 747s [gnutls] (4) EXT[0xf77d0d460000]: Sending extension Key Share/51 (69 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Supported Groups/10) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Cookie/44) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (ALPN/16) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Supported Versions/43) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Sending extension Supported Versions/43 (2 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Record Size Limit/28) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Extended Master Secret/23) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (SRTP/14) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Client Certificate Type/19) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Signature Algorithms/13) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (OCSP Status Request/5) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Safe Renegotiation/65281) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (PSK Key Exchange Modes/45) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Supported EC Point Formats/11) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Post Handshake Auth/49) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (ClientHello Padding/21) for 'TLS 1.3 server hello' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Pre Shared Key/41) for 'TLS 1.3 server hello' 747s [gnutls] (4) HSK[0xf77d0d460000]: SERVER HELLO was queued [155 bytes] 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 155 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 160 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6 747s [gnutls] (4) REC[0xf77d0d460000]: Sent ChangeCipherSpec 747s [gnutls] (5) REC[0xf77d0d460000]: Initializing epoch #1 747s [gnutls] (5) REC[0xf77d0d460000]: Epoch #1 ready 747s [gnutls] (4) HSK[0xf77d0d460000]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Server Name Indication/0) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Early Data/42) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Session Ticket/35) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Client Certificate Type/19) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Cookie/44) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Safe Renegotiation/65281) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Encrypt-then-MAC/22) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Record Size Limit/28) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Sending extension Record Size Limit/28 (2 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (SRTP/14) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Maximum Record Size/1) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (ALPN/16) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Sending extension ALPN/16 (6 bytes) 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Extended Master Secret/23) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Key Share/51) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Supported Groups/10) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Supported Versions/43) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Supported EC Point Formats/11) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (OCSP Status Request/5) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Signature Algorithms/13) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Preparing extension (Server Certificate Type/20) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Compress Certificate/27) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (PSK Key Exchange Modes/45) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Post Handshake Auth/49) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (ClientHello Padding/21) for 'encrypted extensions' 747s [gnutls] (4) EXT[0xf77d0d460000]: Not sending extension (Pre Shared Key/41) for 'encrypted extensions' 747s [gnutls] (4) HSK[0xf77d0d460000]: ENCRYPTED EXTENSIONS was queued [22 bytes] 747s [gnutls] (4) HSK[0xf77d0d460000]: CERTIFICATE was queued [1155 bytes] 747s [gnutls] (4) checking cert compat with RSA-SHA256 747s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 747s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 747s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 747s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 747s [gnutls] (4) HSK[0xf77d0d460000]: signing TLS 1.3 handshake data: using RSA-PSS-RSAE-SHA256 and PRF: SHA384 747s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 747s [gnutls] (4) HSK[0xf77d0d460000]: CERTIFICATE VERIFY was queued [392 bytes] 747s [gnutls] (4) HSK[0xf77d0d460000]: sending finished 747s [gnutls] (4) HSK[0xf77d0d460000]: FINISHED was queued [52 bytes] 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 22 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 44 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 1155 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[2] Handshake(22) in epoch 1 and length: 1177 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 392 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[3] Handshake(22) in epoch 1 and length: 414 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 52 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[4] Handshake(22) in epoch 1 and length: 74 747s [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:965 747s [gnutls] (5) REC[0xf77d0d460000]: Allocating epoch #2 747s [gnutls] (4) HSK[0xf77d0d460000]: unauthenticated session eligible for early start 747s [gnutls] (5) REC[0xf77d0d460000]: Initializing epoch #2 747s [gnutls] (5) REC[0xf77d0d460000]: Epoch #2 ready 747s [gnutls] (4) HSK[0xf77d0d460000]: TLS 1.3 set write key with cipher suite: GNUTLS_AES_256_GCM_SHA384 747s [gnutls] (4) HSK[0xf77d0d460000]: switching early to application traffic keys 747s [gnutls] (4) HSK[0xf77d0d460000]: NEW SESSION TICKET was queued [251 bytes] 747s [gnutls] (4) HSK[0xf77d0d460000]: NEW SESSION TICKET was queued [251 bytes] 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[1] Handshake(22) in epoch 2 and length: 273 747s [gnutls] (5) REC[0xf77d0d460000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 747s [gnutls] (5) REC[0xf77d0d460000]: Sent Packet[2] Handshake(22) in epoch 2 and length: 273 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 747s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 747s [gnutls] (5) REC[0xf77d0d460000]: SSL 3.3 ChangeCipherSpec packet received. Epoch 1, length: 1 747s [gnutls] (5) REC[0xf77d0d460000]: Expected Packet Handshake(22) 747s [gnutls] (5) REC[0xf77d0d460000]: Received Packet ChangeCipherSpec(20) with length: 1 747s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 747s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 747s [io ] => connection to '127.0.0.1#50537' closed by peer (connection reset by peer) 747s [gnutls] (5) REC[0xf77d0d460000]: Start of epoch cleanup 747s [gnutls] (5) REC[0xf77d0d460000]: Epoch #0 freed 747s [gnutls] (5) REC[0xf77d0d460000]: End of epoch cleanup 747s [gnutls] (5) REC[0xf77d0d460000]: Epoch #1 freed 747s [gnutls] (5) REC[0xf77d0d460000]: Epoch #2 freed 747s > 748s > autopkgtest [19:08:19]: test roundtrip: -----------------------] 749s autopkgtest [19:08:20]: test roundtrip: - - - - - - - - - - results - - - - - - - - - - 749s roundtrip PASS 802s autopkgtest [19:09:13]: @@@@@@@@@@@@@@@@@@@@ summary 802s roundtrip PASS 853s nova [W] Skipping flock in bos03-arm64 853s Creating nova instance adt-oracular-arm64-knot-resolver-20240712-185532-juju-7f2275-prod-proposed-migration-environment-2-5fea7693-5720-446e-bb8c-f26936a53e89 from image adt/ubuntu-oracular-arm64-server-20240712.img (UUID a9c53646-2a41-49d7-a14b-d40262a2cb6c)...