0s autopkgtest [00:49:04]: starting date and time: 2025-10-20 00:49:04+0000 0s autopkgtest [00:49:04]: git checkout: 4b346b80 nova: make wait_reboot return success even when a no-op 0s autopkgtest [00:49:04]: host juju-7f2275-prod-proposed-migration-environment-15; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.598xe7fu/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:node-jquery --apt-upgrade knot-resolver --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 '--env=ADT_TEST_TRIGGERS=node-jquery/3.7.1+dfsg+~3.5.33-1build1' -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-15@bos03-arm64-20.secgroup --name adt-resolute-arm64-knot-resolver-20251020-004904-juju-7f2275-prod-proposed-migration-environment-15-17e7fa36-5886-4931-8563-b932cb37d522 --image adt/ubuntu-resolute-arm64-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-15 --net-id=net_prod-proposed-migration -e TERM=linux --mirror=http://ftpmaster.internal/ubuntu/ 4s Creating nova instance adt-resolute-arm64-knot-resolver-20251020-004904-juju-7f2275-prod-proposed-migration-environment-15-17e7fa36-5886-4931-8563-b932cb37d522 from image adt/ubuntu-resolute-arm64-server-20251019.img (UUID 66624775-bb7d-402f-bbba-489c1d649d18)... 72s autopkgtest [00:50:16]: testbed dpkg architecture: arm64 72s autopkgtest [00:50:16]: testbed apt version: 3.1.8ubuntu1 72s autopkgtest [00:50:16]: @@@@@@@@@@@@@@@@@@@@ test bed setup 73s autopkgtest [00:50:17]: testbed release detected to be: None 74s autopkgtest [00:50:18]: updating testbed package index (apt update) 74s Get:1 http://ftpmaster.internal/ubuntu resolute-proposed InRelease [83.3 kB] 74s Hit:2 http://ftpmaster.internal/ubuntu resolute InRelease 74s Hit:3 http://ftpmaster.internal/ubuntu resolute-updates InRelease 74s Hit:4 http://ftpmaster.internal/ubuntu resolute-security InRelease 74s Get:5 http://ftpmaster.internal/ubuntu resolute-proposed/universe Sources [396 kB] 75s Get:6 http://ftpmaster.internal/ubuntu resolute-proposed/restricted Sources [5028 B] 75s Get:7 http://ftpmaster.internal/ubuntu resolute-proposed/main Sources [47.8 kB] 75s Get:8 http://ftpmaster.internal/ubuntu resolute-proposed/multiverse Sources [15.8 kB] 75s Get:9 http://ftpmaster.internal/ubuntu resolute-proposed/main arm64 Packages [110 kB] 75s Get:10 http://ftpmaster.internal/ubuntu resolute-proposed/restricted arm64 Packages [43.8 kB] 75s Get:11 http://ftpmaster.internal/ubuntu resolute-proposed/universe arm64 Packages [274 kB] 75s Get:12 http://ftpmaster.internal/ubuntu resolute-proposed/multiverse arm64 Packages [8020 B] 75s Fetched 984 kB in 1s (1029 kB/s) 76s Reading package lists... 77s Hit:1 http://ftpmaster.internal/ubuntu resolute-proposed InRelease 77s Hit:2 http://ftpmaster.internal/ubuntu resolute InRelease 77s Hit:3 http://ftpmaster.internal/ubuntu resolute-updates InRelease 77s Hit:4 http://ftpmaster.internal/ubuntu resolute-security InRelease 78s Reading package lists... 78s Reading package lists... 79s Building dependency tree... 79s Reading state information... 80s Calculating upgrade... 80s The following packages will be upgraded: 80s distro-info-data dpkg dpkg-dev libaudit-common libaudit1 libdpkg-perl 80s libp11-kit0 libseccomp2 python-apt-common python3-apt 81s 10 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 81s Need to get 3273 kB of archives. 81s After this operation, 503 kB of additional disk space will be used. 81s Get:1 http://ftpmaster.internal/ubuntu resolute/main arm64 dpkg arm64 1.22.21ubuntu4 [1274 kB] 82s Get:2 http://ftpmaster.internal/ubuntu resolute/main arm64 libaudit-common all 1:4.0.5-1build2 [6596 B] 82s Get:3 http://ftpmaster.internal/ubuntu resolute/main arm64 libaudit1 arm64 1:4.0.5-1build2 [58.6 kB] 82s Get:4 http://ftpmaster.internal/ubuntu resolute/main arm64 distro-info-data all 0.68 [7378 B] 82s Get:5 http://ftpmaster.internal/ubuntu resolute/main arm64 libp11-kit0 arm64 0.25.9-2 [283 kB] 82s Get:6 http://ftpmaster.internal/ubuntu resolute/main arm64 libseccomp2 arm64 2.6.0-2ubuntu3 [56.1 kB] 82s Get:7 http://ftpmaster.internal/ubuntu resolute/main arm64 python-apt-common all 3.0.0ubuntu2 [21.7 kB] 82s Get:8 http://ftpmaster.internal/ubuntu resolute/main arm64 python3-apt arm64 3.0.0ubuntu2 [197 kB] 82s Get:9 http://ftpmaster.internal/ubuntu resolute/main arm64 dpkg-dev all 1.22.21ubuntu4 [1088 kB] 83s Get:10 http://ftpmaster.internal/ubuntu resolute/main arm64 libdpkg-perl all 1.22.21ubuntu4 [280 kB] 84s dpkg-preconfigure: unable to re-open stdin: No such file or directory 84s Fetched 3273 kB in 3s (1258 kB/s) 84s (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 ... 83359 files and directories currently installed.) 84s Preparing to unpack .../dpkg_1.22.21ubuntu4_arm64.deb ... 84s Unpacking dpkg (1.22.21ubuntu4) over (1.22.21ubuntu3) ... 84s Setting up dpkg (1.22.21ubuntu4) ... 85s (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 ... 83359 files and directories currently installed.) 85s Preparing to unpack .../libaudit-common_1%3a4.0.5-1build2_all.deb ... 85s Unpacking libaudit-common (1:4.0.5-1build2) over (1:4.0.5-1build1) ... 85s Setting up libaudit-common (1:4.0.5-1build2) ... 85s (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 ... 83359 files and directories currently installed.) 85s Preparing to unpack .../libaudit1_1%3a4.0.5-1build2_arm64.deb ... 85s Unpacking libaudit1:arm64 (1:4.0.5-1build2) over (1:4.0.5-1build1) ... 85s Setting up libaudit1:arm64 (1:4.0.5-1build2) ... 85s (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 ... 83359 files and directories currently installed.) 85s Preparing to unpack .../0-distro-info-data_0.68_all.deb ... 85s Unpacking distro-info-data (0.68) over (0.67~ubuntu1) ... 85s Preparing to unpack .../1-libp11-kit0_0.25.9-2_arm64.deb ... 85s Unpacking libp11-kit0:arm64 (0.25.9-2) over (0.25.5-3ubuntu1) ... 86s Preparing to unpack .../2-libseccomp2_2.6.0-2ubuntu3_arm64.deb ... 86s Unpacking libseccomp2:arm64 (2.6.0-2ubuntu3) over (2.6.0-2ubuntu2) ... 86s Preparing to unpack .../3-python-apt-common_3.0.0ubuntu2_all.deb ... 86s Unpacking python-apt-common (3.0.0ubuntu2) over (3.0.0ubuntu1) ... 86s Preparing to unpack .../4-python3-apt_3.0.0ubuntu2_arm64.deb ... 86s Unpacking python3-apt (3.0.0ubuntu2) over (3.0.0ubuntu1) ... 86s Preparing to unpack .../5-dpkg-dev_1.22.21ubuntu4_all.deb ... 86s Unpacking dpkg-dev (1.22.21ubuntu4) over (1.22.21ubuntu3) ... 86s Preparing to unpack .../6-libdpkg-perl_1.22.21ubuntu4_all.deb ... 86s Unpacking libdpkg-perl (1.22.21ubuntu4) over (1.22.21ubuntu3) ... 86s Setting up distro-info-data (0.68) ... 86s Setting up libseccomp2:arm64 (2.6.0-2ubuntu3) ... 86s Setting up libp11-kit0:arm64 (0.25.9-2) ... 86s Setting up libdpkg-perl (1.22.21ubuntu4) ... 86s Setting up python-apt-common (3.0.0ubuntu2) ... 86s Setting up python3-apt (3.0.0ubuntu2) ... 87s Setting up dpkg-dev (1.22.21ubuntu4) ... 87s Processing triggers for man-db (2.13.1-1) ... 89s Processing triggers for libc-bin (2.42-0ubuntu3) ... 89s autopkgtest [00:50:33]: upgrading testbed (apt dist-upgrade and autopurge) 89s Reading package lists... 90s Building dependency tree... 90s Reading state information... 90s Calculating upgrade... 90s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 91s Reading package lists... 91s Building dependency tree... 91s Reading state information... 91s Solving dependencies... 91s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 92s autopkgtest [00:50:36]: rebooting testbed after setup commands that affected boot 121s autopkgtest [00:51:05]: testbed running kernel: Linux 6.17.0-5-generic #5-Ubuntu SMP PREEMPT_DYNAMIC Mon Sep 22 09:50:31 UTC 2025 124s autopkgtest [00:51:08]: @@@@@@@@@@@@@@@@@@@@ apt-source knot-resolver 129s Get:1 http://ftpmaster.internal/ubuntu resolute/universe knot-resolver 5.7.5-1 (dsc) [3178 B] 129s Get:2 http://ftpmaster.internal/ubuntu resolute/universe knot-resolver 5.7.5-1 (tar) [1925 kB] 129s Get:3 http://ftpmaster.internal/ubuntu resolute/universe knot-resolver 5.7.5-1 (asc) [833 B] 129s Get:4 http://ftpmaster.internal/ubuntu resolute/universe knot-resolver 5.7.5-1 (diff) [402 kB] 130s gpgv: Signature made Thu Apr 24 17:32:48 2025 UTC 130s gpgv: using RSA key 23EBCF7E8FC47556787100DFA4254072E373042C 130s gpgv: Can't check signature: No public key 130s dpkg-source: warning: cannot verify inline signature for ./knot-resolver_5.7.5-1.dsc: no acceptable signature found 130s autopkgtest [00:51:14]: testing package knot-resolver version 5.7.5-1 131s autopkgtest [00:51:15]: build not needed 131s autopkgtest [00:51:15]: test roundtrip: preparing testbed 132s Reading package lists... 132s Building dependency tree... 132s Reading state information... 132s Solving dependencies... 133s The following NEW packages will be installed: 133s dns-root-data gnutls-bin knot-dnsutils knot-resolver libdnssec9t64 133s libevent-2.1-7t64 libfstrm0 libgnutls-dane0t64 libknot15 libluajit-5.1-2 133s libluajit-5.1-common libngtcp2-16 libngtcp2-crypto-gnutls8 libprotobuf-c1 133s libunbound8 libxdp1 libzscanner4t64 lua-sec lua-socket socat 133s 0 upgraded, 20 newly installed, 0 to remove and 0 not upgraded. 133s Need to get 2746 kB of archives. 133s After this operation, 11.3 MB of additional disk space will be used. 133s Get:1 http://ftpmaster.internal/ubuntu resolute/main arm64 dns-root-data all 2025080400 [5908 B] 133s Get:2 http://ftpmaster.internal/ubuntu resolute/main arm64 libevent-2.1-7t64 arm64 2.1.12-stable-10build1 [152 kB] 133s Get:3 http://ftpmaster.internal/ubuntu resolute/main arm64 libunbound8 arm64 1.22.0-2ubuntu2 [448 kB] 134s Get:4 http://ftpmaster.internal/ubuntu resolute/main arm64 libgnutls-dane0t64 arm64 3.8.9-3ubuntu2 [25.0 kB] 134s Get:5 http://ftpmaster.internal/ubuntu resolute/universe arm64 gnutls-bin arm64 3.8.9-3ubuntu2 [273 kB] 134s Get:6 http://ftpmaster.internal/ubuntu resolute/universe arm64 libdnssec9t64 arm64 3.4.6-2 [31.3 kB] 134s Get:7 http://ftpmaster.internal/ubuntu resolute/universe arm64 libngtcp2-16 arm64 1.11.0-1 [123 kB] 134s Get:8 http://ftpmaster.internal/ubuntu resolute/universe arm64 libngtcp2-crypto-gnutls8 arm64 1.11.0-1 [16.8 kB] 134s Get:9 http://ftpmaster.internal/ubuntu resolute/main arm64 libxdp1 arm64 1.5.6-1 [63.7 kB] 134s Get:10 http://ftpmaster.internal/ubuntu resolute/universe arm64 libknot15 arm64 3.4.6-2 [113 kB] 134s Get:11 http://ftpmaster.internal/ubuntu resolute/universe arm64 libzscanner4t64 arm64 3.4.6-2 [137 kB] 134s Get:12 http://ftpmaster.internal/ubuntu resolute/universe arm64 libfstrm0 arm64 0.6.1-1build4 [20.6 kB] 134s Get:13 http://ftpmaster.internal/ubuntu resolute/main arm64 libprotobuf-c1 arm64 1.5.1-1ubuntu1 [21.1 kB] 134s Get:14 http://ftpmaster.internal/ubuntu resolute/universe arm64 knot-dnsutils arm64 3.4.6-2 [123 kB] 134s Get:15 http://ftpmaster.internal/ubuntu resolute/universe arm64 lua-socket arm64 3.1.0-2 [77.5 kB] 134s Get:16 http://ftpmaster.internal/ubuntu resolute/universe arm64 lua-sec arm64 1.3.2-3 [38.0 kB] 134s Get:17 http://ftpmaster.internal/ubuntu resolute/universe arm64 libluajit-5.1-common all 2.1.0+openresty20250117-2ubuntu1 [54.6 kB] 134s Get:18 http://ftpmaster.internal/ubuntu resolute/universe arm64 libluajit-5.1-2 arm64 2.1.0+openresty20250117-2ubuntu1 [295 kB] 134s Get:19 http://ftpmaster.internal/ubuntu resolute/universe arm64 knot-resolver arm64 5.7.5-1 [333 kB] 135s Get:20 http://ftpmaster.internal/ubuntu resolute/main arm64 socat arm64 1.8.0.3-1build1 [394 kB] 135s Preconfiguring packages ... 136s Fetched 2746 kB in 2s (1371 kB/s) 136s Selecting previously unselected package dns-root-data. 136s (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 ... 83363 files and directories currently installed.) 136s Preparing to unpack .../00-dns-root-data_2025080400_all.deb ... 136s Unpacking dns-root-data (2025080400) ... 136s Selecting previously unselected package libevent-2.1-7t64:arm64. 136s Preparing to unpack .../01-libevent-2.1-7t64_2.1.12-stable-10build1_arm64.deb ... 136s Unpacking libevent-2.1-7t64:arm64 (2.1.12-stable-10build1) ... 136s Selecting previously unselected package libunbound8:arm64. 136s Preparing to unpack .../02-libunbound8_1.22.0-2ubuntu2_arm64.deb ... 136s Unpacking libunbound8:arm64 (1.22.0-2ubuntu2) ... 136s Selecting previously unselected package libgnutls-dane0t64:arm64. 136s Preparing to unpack .../03-libgnutls-dane0t64_3.8.9-3ubuntu2_arm64.deb ... 136s Unpacking libgnutls-dane0t64:arm64 (3.8.9-3ubuntu2) ... 136s Selecting previously unselected package gnutls-bin. 136s Preparing to unpack .../04-gnutls-bin_3.8.9-3ubuntu2_arm64.deb ... 136s Unpacking gnutls-bin (3.8.9-3ubuntu2) ... 136s Selecting previously unselected package libdnssec9t64. 136s Preparing to unpack .../05-libdnssec9t64_3.4.6-2_arm64.deb ... 136s Unpacking libdnssec9t64 (3.4.6-2) ... 136s Selecting previously unselected package libngtcp2-16:arm64. 136s Preparing to unpack .../06-libngtcp2-16_1.11.0-1_arm64.deb ... 136s Unpacking libngtcp2-16:arm64 (1.11.0-1) ... 136s Selecting previously unselected package libngtcp2-crypto-gnutls8:arm64. 136s Preparing to unpack .../07-libngtcp2-crypto-gnutls8_1.11.0-1_arm64.deb ... 136s Unpacking libngtcp2-crypto-gnutls8:arm64 (1.11.0-1) ... 136s Selecting previously unselected package libxdp1:arm64. 136s Preparing to unpack .../08-libxdp1_1.5.6-1_arm64.deb ... 136s Unpacking libxdp1:arm64 (1.5.6-1) ... 136s Selecting previously unselected package libknot15. 136s Preparing to unpack .../09-libknot15_3.4.6-2_arm64.deb ... 136s Unpacking libknot15 (3.4.6-2) ... 136s Selecting previously unselected package libzscanner4t64. 136s Preparing to unpack .../10-libzscanner4t64_3.4.6-2_arm64.deb ... 136s Unpacking libzscanner4t64 (3.4.6-2) ... 136s Selecting previously unselected package libfstrm0:arm64. 136s Preparing to unpack .../11-libfstrm0_0.6.1-1build4_arm64.deb ... 136s Unpacking libfstrm0:arm64 (0.6.1-1build4) ... 136s Selecting previously unselected package libprotobuf-c1:arm64. 136s Preparing to unpack .../12-libprotobuf-c1_1.5.1-1ubuntu1_arm64.deb ... 136s Unpacking libprotobuf-c1:arm64 (1.5.1-1ubuntu1) ... 136s Selecting previously unselected package knot-dnsutils. 136s Preparing to unpack .../13-knot-dnsutils_3.4.6-2_arm64.deb ... 136s Unpacking knot-dnsutils (3.4.6-2) ... 137s Selecting previously unselected package lua-socket:arm64. 137s Preparing to unpack .../14-lua-socket_3.1.0-2_arm64.deb ... 137s Unpacking lua-socket:arm64 (3.1.0-2) ... 137s Selecting previously unselected package lua-sec:arm64. 137s Preparing to unpack .../15-lua-sec_1.3.2-3_arm64.deb ... 137s Unpacking lua-sec:arm64 (1.3.2-3) ... 137s Selecting previously unselected package libluajit-5.1-common. 137s Preparing to unpack .../16-libluajit-5.1-common_2.1.0+openresty20250117-2ubuntu1_all.deb ... 137s Unpacking libluajit-5.1-common (2.1.0+openresty20250117-2ubuntu1) ... 137s Selecting previously unselected package libluajit-5.1-2:arm64. 137s Preparing to unpack .../17-libluajit-5.1-2_2.1.0+openresty20250117-2ubuntu1_arm64.deb ... 137s Unpacking libluajit-5.1-2:arm64 (2.1.0+openresty20250117-2ubuntu1) ... 137s Selecting previously unselected package knot-resolver. 137s Preparing to unpack .../18-knot-resolver_5.7.5-1_arm64.deb ... 137s Unpacking knot-resolver (5.7.5-1) ... 137s Selecting previously unselected package socat. 137s Preparing to unpack .../19-socat_1.8.0.3-1build1_arm64.deb ... 137s Unpacking socat (1.8.0.3-1build1) ... 137s Setting up libzscanner4t64 (3.4.6-2) ... 137s Setting up libfstrm0:arm64 (0.6.1-1build4) ... 137s Setting up libevent-2.1-7t64:arm64 (2.1.12-stable-10build1) ... 137s Setting up lua-socket:arm64 (3.1.0-2) ... 137s Setting up libprotobuf-c1:arm64 (1.5.1-1ubuntu1) ... 137s Setting up dns-root-data (2025080400) ... 137s Setting up libxdp1:arm64 (1.5.6-1) ... 137s Setting up libunbound8:arm64 (1.22.0-2ubuntu2) ... 137s Setting up libgnutls-dane0t64:arm64 (3.8.9-3ubuntu2) ... 137s Setting up socat (1.8.0.3-1build1) ... 137s Setting up libdnssec9t64 (3.4.6-2) ... 137s Setting up libluajit-5.1-common (2.1.0+openresty20250117-2ubuntu1) ... 137s Setting up libngtcp2-16:arm64 (1.11.0-1) ... 137s Setting up libngtcp2-crypto-gnutls8:arm64 (1.11.0-1) ... 137s Setting up gnutls-bin (3.8.9-3ubuntu2) ... 137s Setting up lua-sec:arm64 (1.3.2-3) ... 137s Setting up libknot15 (3.4.6-2) ... 137s Setting up libluajit-5.1-2:arm64 (2.1.0+openresty20250117-2ubuntu1) ... 137s Setting up knot-resolver (5.7.5-1) ... 138s Created symlink '/etc/systemd/system/kresd.target.wants/kres-cache-gc.service' → '/usr/lib/systemd/system/kres-cache-gc.service'. 138s Created symlink '/etc/systemd/system/multi-user.target.wants/kresd.target' → '/usr/lib/systemd/system/kresd.target'. 138s Setting up knot-dnsutils (3.4.6-2) ... 138s Processing triggers for man-db (2.13.1-1) ... 139s Processing triggers for libc-bin (2.42-0ubuntu3) ... 141s autopkgtest [00:51:25]: test roundtrip: [----------------------- 141s /usr/sbin/kresd + /usr/bin/kdig roundtrip tests 141s ------------ 141s workdir: /tmp/autopkgtest.r3bBfW/roundtrip-artifacts 141s IP addr: 127.227.238.88 141s kresd args: --addr=127.227.238.88@8053 --tls=127.227.238.88@8853 --noninteractive --config=/tmp/autopkgtest.r3bBfW/roundtrip-artifacts/kresd.conf --verbose --verbose --verbose 141s 141s make Certificate Authority key and certificate 141s ---------------------------------------------- 141s Generating a 3072 bit RSA private key... 141s Generating a self signed certificate... 141s X.509 Certificate Information: 141s Version: 3 141s Serial Number (hex): 5bd734ad9519b83d9d94281bda0171e04332a511 141s Validity: 141s Not Before: Mon Oct 20 00:51:25 UTC 2025 141s Not After: Sat Nov 01 00:51:25 UTC 2025 141s Subject: CN=testing certificate authority (NOT FOR PRODUCTION) 141s Subject Public Key Algorithm: RSA 141s Algorithm Security Level: High (3072 bits) 141s Modulus (bits 3072): 141s 00:ac:cc:da:62:10:d7:37:03:c1:81:ea:fa:e1:33:f2 141s d1:7a:10:ed:9f:6a:eb:82:cb:7d:de:ec:06:e4:7f:d6 141s c2:d0:9d:7b:5a:f8:f0:cc:71:88:91:5a:d8:76:fd:ab 141s 4b:61:e5:99:65:cf:53:4e:3b:ec:25:f7:5c:4a:ce:2b 141s 05:d9:43:98:22:84:4b:45:1b:58:b3:e0:99:90:7c:5b 141s 63:36:9e:cb:37:f6:0d:d8:d2:9d:a0:d4:cd:b2:8f:ea 141s 65:50:97:e3:27:4b:92:07:fc:49:88:ef:34:1b:a0:68 141s 1e:8a:94:2f:69:d2:bf:00:54:1a:b7:dc:20:4f:81:18 141s 34:d9:6a:37:47:9c:21:c2:00:37:12:6f:03:3b:b9:dc 141s 2a:a6:c6:16:26:d4:03:ed:93:33:db:5c:05:16:55:a3 141s fa:0f:fb:5a:47:e9:54:47:13:f8:7f:e9:f4:a6:3c:93 141s a9:69:d2:a4:10:a4:c7:d8:44:04:6e:19:3a:78:cc:6c 141s e1:70:9b:60:e4:50:5e:8f:4c:43:da:37:a5:52:88:e1 141s fc:d5:09:04:4e:10:08:c6:ea:c4:92:6d:a9:f3:aa:48 141s 52:7d:48:c6:f9:c6:35:bd:bc:a5:90:94:c9:c6:f2:86 141s 85:1d:9d:cc:bb:93:51:7f:89:e0:0e:f4:0e:e1:96:bd 141s ce:70:f1:23:18:47:a7:c1:45:1b:e4:57:cf:f4:a4:6a 141s e9:e3:57:99:7e:4c:ed:03:5a:9a:5a:04:d6:26:99:16 141s c7:d1:75:ad:62:87:1b:5c:78:8a:e3:35:c6:8b:7f:ed 141s bc:2b:57:cd:ae:3c:8d:66:93:96:88:f9:f5:51:57:f6 141s f8:f0:19:55:fe:d8:0b:4e:d7:ef:1f:b4:62:f7:16:39 141s 8b:92:56:cb:be:20:f8:4f:71:d3:be:ff:bc:b8:ca:bc 141s a4:cf:a9:db:93:9d:a4:a1:fc:53:0f:47:a4:cb:e1:6d 141s 04:2f:33:e8:d8:b3:83:e4:d4:95:c3:f1:c3:cd:d0:64 141s 19 141s Exponent (bits 24): 141s 01:00:01 141s Extensions: 141s Basic Constraints (critical): 141s Certificate Authority (CA): TRUE 141s Path Length Constraint: 1 141s Name Constraints (critical): 141s Permitted: 141s DNSname: example 141s Key Usage (critical): 141s Certificate signing. 141s Subject Key Identifier (not critical): 141s 9633491d54eb2d74eb802538ae079a126a4656f5 141s Other Information: 141s Public Key ID: 141s sha1:9633491d54eb2d74eb802538ae079a126a4656f5 141s sha256:9bf4350eb6960c98aa3bb49657d9cd98d42f2e880fbf27866db841f8ca332cf2 141s Public Key PIN: 141s pin-sha256:m/Q1DraWDJiqO7SWV9nNmNQvLogPvyeGbbhB+MozLPI= 141s 141s 141s 141s Signing certificate... 141s 141s make Bogus Certificate Authority key and certificate 141s ---------------------------------------------------- 142s Generating a 3072 bit RSA private key... 142s Generating a self signed certificate... 142s X.509 Certificate Information: 142s Version: 3 142s Serial Number (hex): 0322d796ae090bdf290fe3faf7ec29450cd57062 142s Validity: 142s Not Before: Mon Oct 20 00:51:26 UTC 2025 142s Not After: Sat Nov 01 00:51:26 UTC 2025 142s Subject: CN=testing certificate authority (NOT FOR PRODUCTION) 142s Subject Public Key Algorithm: RSA 142s Algorithm Security Level: High (3072 bits) 142s Modulus (bits 3072): 142s 00:c3:c5:4f:a5:9b:71:37:58:e5:ea:07:2e:7e:b3:5d 142s 5a:4e:a6:c0:9d:29:21:cb:78:a4:2c:a3:e0:cf:5b:1b 142s 0e:f7:10:b6:7e:b6:ad:4d:73:95:e5:1e:40:0f:04:49 142s fd:81:6f:4a:16:10:0a:29:01:2e:ac:c4:6e:bc:c7:8b 142s 5f:c4:98:58:12:23:6d:63:58:63:45:4f:6b:7b:95:68 142s f9:cb:d7:72:b5:3f:89:a7:57:6a:c8:db:a9:86:7c:df 142s 7b:ab:2b:42:19:ff:45:6a:15:60:8c:ba:26:92:6e:91 142s d8:d3:7f:62:a7:d6:90:86:ae:96:48:81:e5:0a:09:4d 142s b5:51:3b:a3:aa:30:30:5e:41:18:3c:98:4f:ab:63:a7 142s 8c:02:28:af:b2:eb:2c:ee:56:e5:35:54:9f:6d:f2:df 142s d5:8e:49:76:1d:c0:a4:8e:28:fc:dc:07:51:c0:fe:46 142s 47:0d:c5:ac:5a:06:95:59:6b:0b:ad:e6:20:09:1b:37 142s 02:9b:81:b2:d6:e8:dd:c3:27:4c:2e:4c:1c:77:e2:6d 142s 9e:a7:67:63:9e:50:81:62:76:e5:43:00:68:2f:fa:3d 142s e7:ef:36:c0:16:0f:1d:2d:a2:44:01:13:a2:8b:43:3d 142s 5e:e9:9f:b8:98:99:21:19:6f:28:9c:60:37:bc:f6:60 142s 0f:59:e5:35:21:40:85:83:e5:f8:4a:7d:f1:5c:f0:d4 142s 72:4e:7b:ba:77:cf:bc:09:f3:a9:ba:b2:99:da:f3:d5 142s b7:f0:ab:6c:e5:11:8b:70:aa:68:af:13:d0:7c:25:d8 142s 76:d8:6a:35:9d:1e:d2:d6:a2:9b:29:ea:66:73:07:b6 142s ff:15:c7:ad:80:7f:e7:d6:84:e3:17:f6:3e:c5:19:14 142s be:21:e8:73:e0:f9:1b:78:25:c1:79:30:74:e2:f3:62 142s 26:33:dc:cc:9f:77:12:44:e3:82:fa:cb:51:fd:1c:4a 142s f7:a3:86:f2:b3:b8:16:22:77:97:35:56:eb:f1:3c:a9 142s 69 142s Exponent (bits 24): 142s 01:00:01 142s Extensions: 142s Basic Constraints (critical): 142s Certificate Authority (CA): TRUE 142s Path Length Constraint: 1 142s Name Constraints (critical): 142s Permitted: 142s DNSname: example 142s Key Usage (critical): 142s Certificate signing. 142s Subject Key Identifier (not critical): 142s 03696852ab116750e7545264a215f3b1ee0deca7 142s Other Information: 142s Public Key ID: 142s sha1:03696852ab116750e7545264a215f3b1ee0deca7 142s sha256:c454d9c03b703b9f8af2cfb529aa9dfae46e73bc2700e5fb7b985d89d8de9481 142s Public Key PIN: 142s pin-sha256:xFTZwDtwO5+K8s+1Kaqd+uRuc7wnAOX7e5hdidjelIE= 142s 142s 142s 142s Signing certificate... 142s 142s make End Entity key and certificate 142s ----------------------------------- 143s Generating a 3072 bit RSA private key... 143s Generating a signed certificate... 143s X.509 Certificate Information: 143s Version: 3 143s Serial Number (hex): 177a5d40f1f2b5032605688c59a08daed28e3e77 143s Validity: 143s Not Before: Mon Oct 20 00:51:27 UTC 2025 143s Not After: Thu Oct 30 00:51:27 UTC 2025 143s Subject: CN=test.example 143s Subject Public Key Algorithm: RSA 143s Algorithm Security Level: High (3072 bits) 143s Modulus (bits 3072): 143s 00:c2:46:db:5a:00:39:f0:58:4e:13:5d:40:33:a1:64 143s bf:bf:bf:bd:94:51:bb:92:24:80:5e:9f:05:ee:6c:9e 143s bc:42:20:0c:92:2a:0b:50:ca:5e:66:dc:92:aa:33:cb 143s 6e:a8:1e:92:a3:ab:53:6d:b8:ef:5e:51:36:bf:62:e8 143s 8a:e5:e4:bd:ab:50:47:ae:2f:2f:f4:24:3a:9d:2c:97 143s a3:ca:ba:76:1e:be:6a:b5:da:6d:c2:b0:f9:11:bb:54 143s 5f:5e:9e:ce:ff:88:29:7c:d5:7f:a0:bf:5d:27:93:98 143s 90:81:e9:27:db:71:3e:94:61:79:a9:07:12:81:90:9f 143s 7c:84:09:7c:80:b6:11:44:ba:75:ad:c4:0d:81:bc:84 143s 42:05:8e:e5:72:87:f0:9d:12:14:9d:8b:d1:17:24:95 143s 3d:59:db:a8:9e:12:9a:8d:6f:41:9a:a7:4b:a5:31:04 143s c4:a6:ca:0b:fa:9f:a7:7c:61:d3:65:90:81:3f:36:92 143s d1:b1:58:e2:8e:9d:d7:8b:9c:6b:97:8c:5a:f2:64:d4 143s 34:7c:7e:9e:41:4e:33:e8:cd:66:45:e1:20:78:0a:8b 143s 66:04:b0:6b:32:c2:8f:dd:47:d2:bf:a2:4b:7c:a8:65 143s e4:bc:60:bb:4d:62:87:47:ef:3c:ed:e8:cf:72:58:2e 143s 4f:df:7b:51:65:aa:7a:48:59:58:ae:71:8f:b1:65:1c 143s 19:6f:69:dd:cc:72:8a:bd:c2:45:77:14:00:c8:35:81 143s 92:d5:7c:a2:64:ce:f1:a2:e3:98:49:bf:0f:d5:c6:92 143s c1:83:db:a3:3e:47:0d:6d:43:4a:6d:e8:25:19:72:ee 143s 27:4a:b3:ec:bf:5c:e4:cc:ab:e7:ed:ab:51:c9:c1:da 143s 50:17:26:58:74:c4:41:f4:34:06:a1:d5:96:52:cb:46 143s 23:20:0c:7e:13:12:e2:a7:27:3e:75:98:b1:93:98:f5 143s b6:85:58:a8:a2:4d:ae:a1:f8:93:db:94:1c:69:dc:fc 143s eb 143s Exponent (bits 24): 143s 01:00:01 143s Extensions: 143s Basic Constraints (critical): 143s Certificate Authority (CA): FALSE 143s Subject Alternative Name (not critical): 143s DNSname: test.example 143s Key Purpose (not critical): 143s TLS WWW Server. 143s Key Usage (critical): 143s Digital signature. 143s Subject Key Identifier (not critical): 143s 238615ca85b122211d9db499d71d083f60a3834b 143s Authority Key Identifier (not critical): 143s 9633491d54eb2d74eb802538ae079a126a4656f5 143s Other Information: 143s Public Key ID: 143s sha1:238615ca85b122211d9db499d71d083f60a3834b 143s sha256:4115db3114c536b7132cb85bf6195701685e9bae3e6a94e5d8fc1d2f154e72df 143s Public Key PIN: 143s pin-sha256:QRXbMRTFNrcTLLhb9hlXAWhem64+apTl2PwdLxVOct8= 143s 143s 143s 143s Signing certificate... 143s 143s set up kresd daemon on 127.227.238.88 on ports 8053 (UDP, TCP) and 8853 (TLS) 143s ----------------------------------------------------------------------------- 144s 144s test UDP with kdig 144s ------------------ 144s successful UDP request to 127.227.238.88 on port 8053 144s 144s test TCP with kdig 144s ------------------ 144s successful TCP request to 127.227.238.88 on port 8053 144s 144s test opportunistic DNS-over-TLS with kdig 144s ----------------------------------------- 144s successful opportunistic DNS-over-TLS request to 127.227.238.88 on port 8853 144s 144s test strict DNS-over-TLS with kdig 144s ---------------------------------- 144s successful strict DNS-over-TLS request to 127.227.238.88 on port 8853 144s 144s test invalid name with strict DNS-over-TLS with kdig 144s ---------------------------------------------------- 144s successful strict DNS-over-TLS request failure when name mismatch to 127.227.238.88 on port 8853 144s 144s test bad authority with strict DNS-over-TLS with kdig 144s ----------------------------------------------------- 144s successful strict DNS-over-TLS request failure to 127.227.238.88 on port 8853 144s 144s cleaning up 144s ----------- 144s 264766 4 drwxr-xr-x 2 root root 4096 Oct 20 00:51 /tmp/autopkgtest.r3bBfW/roundtrip-artifacts 144s 264779 8 -rw------- 1 root root 8170 Oct 20 00:51 /tmp/autopkgtest.r3bBfW/roundtrip-artifacts/ee-key.pem 144s 264780 4 -rw-r--r-- 1 root root 2218 Oct 20 00:51 /tmp/autopkgtest.r3bBfW/roundtrip-artifacts/ee-pubkey.pem 144s 264776 8 -rw------- 1 root root 8167 Oct 20 00:51 /tmp/autopkgtest.r3bBfW/roundtrip-artifacts/bogus-key.pem 144s 265120 4 -rw-r--r-- 1 root root 120 Oct 20 00:51 /tmp/autopkgtest.r3bBfW/roundtrip-artifacts/badname.err 144s 264775 4 -rw-r--r-- 1 root root 1590 Oct 20 00:51 /tmp/autopkgtest.r3bBfW/roundtrip-artifacts/ca-cert.pem 144s 264774 8 -rw------- 1 root root 8170 Oct 20 00:51 /tmp/autopkgtest.r3bBfW/roundtrip-artifacts/ca-key.pem 144s 264781 4 -rw-r--r-- 1 root root 1602 Oct 20 00:51 /tmp/autopkgtest.r3bBfW/roundtrip-artifacts/ee-cert.pem 144s 265119 102400 -rw-r----- 1 root root 104857600 Oct 20 00:51 /tmp/autopkgtest.r3bBfW/roundtrip-artifacts/data.mdb 144s 265017 4 -rw-r--r-- 1 root root 387 Oct 20 00:51 /tmp/autopkgtest.r3bBfW/roundtrip-artifacts/kresd.conf 144s 264777 4 -rw-r--r-- 1 root root 1590 Oct 20 00:51 /tmp/autopkgtest.r3bBfW/roundtrip-artifacts/bogus-cert.pem 144s 264778 4 -rw-r--r-- 1 root root 92 Oct 20 00:51 /tmp/autopkgtest.r3bBfW/roundtrip-artifacts/ee.template 144s 265121 4 -rw-r--r-- 1 root root 120 Oct 20 00:51 /tmp/autopkgtest.r3bBfW/roundtrip-artifacts/badca.err 144s 265117 68 -rw-r--r-- 1 root root 69361 Oct 20 00:51 /tmp/autopkgtest.r3bBfW/roundtrip-artifacts/kresd.err 144s 265118 4 -rw-r----- 1 root root 8256 Oct 20 00:51 /tmp/autopkgtest.r3bBfW/roundtrip-artifacts/lock.mdb 144s 264773 4 -rw-r--r-- 1 root root 136 Oct 20 00:51 /tmp/autopkgtest.r3bBfW/roundtrip-artifacts/ca.template 144s ==> /tmp/autopkgtest.r3bBfW/roundtrip-artifacts/badca.err <== 144s ;; WARNING: TLS, handshake failed (Error in the certificate.) 144s ;; ERROR: failed to query server 127.227.238.88@8853(TCP) 144s 144s ==> /tmp/autopkgtest.r3bBfW/roundtrip-artifacts/badname.err <== 144s ;; WARNING: TLS, handshake failed (Error in the certificate.) 144s ;; ERROR: failed to query server 127.227.238.88@8853(TCP) 144s 144s ==> /tmp/autopkgtest.r3bBfW/roundtrip-artifacts/kresd.err <== 144s [system] increasing file-descriptor limit: 1024 -> 524288 144s [tls ] session ticket: epoch 429912, scheduling rotation check in 2160762 ms 144s [wtchdg] disabled in systemd (WatchdogSec= not specified) 144s [ta ] installed trust anchors for domain . are: 144s . 3600 DNSKEY 257 3 8 AwEAAaz/tAm8yTn4Mfeh5eyI96WSVexTBAvkMgJzkKTOiW1vkIbzxeF3+/4RgWOq7HrxRixHlFlExOLAJr5emLvN7SWXgnLh4+B5xQlNVz8Og8kvArMtNROxVQuCaSnIDdD5LKyWbRd2n9WGe2R8PzgCmr3EgVLrjyBxWezF0jLHwVN8efS3rCj/EWgvIWgb9tarpVUDK/b58Da+sqqls3eNbuv7pr+eoZG+SrDK6nWeL3c6H5Apxz7LjVc1uTIdsIXxuOLYA4/ilBmSVIzuDWfdRUfhHdY6+cn8HFRm+2hM8AnXGXws9555KrUB5qihylGa8subX2Nn6UwNR1AkUTV74bU= ; Valid: ; KeyTag:20326 144s . 3600 DNSKEY 257 3 8 AwEAAa96jeuknZlaeSrvyAJj6ZHv28hhOKkx3rLGXVaC6rXTsDc449/cidltpkyGwCJNnOAlFNKF2jBosZBU5eeHspaQWOmOElZsjICMQMC3aeHbGiShvZsx4wMYSjH8e7Vrhbu6irwCzVBApESjbUdpWWmEnhathWu1jo+siFUiRAAxm9qyJNg/wOZqqzL/dL/q8PkcRU5oUKEpUge71M3ej2/7CPqpdVwuMoTvoB+ZOT4YeGyxMvHmbrxlFzGOHOijtzN+u1TQNatX2XBuzZNQ1K+s2CXkPIZo7s6JgZyvaBevYtxPvYLw4z9mR7K2vaF18UYH9Z9GNUUeayffKC73PYc= ; Valid: ; KeyTag:38696 144s 144s [system] loading config '/tmp/autopkgtest.r3bBfW/roundtrip-artifacts/kresd.conf' (workdir '/tmp/autopkgtest.r3bBfW/roundtrip-artifacts') 144s [system] deprecation WARNING: use log_level() instead of verbose() 144s [gnutls] (3) ASSERT: ../../../lib/x509/x509_ext.c[gnutls_subject_alt_names_get]:107 144s [gnutls] (3) ASSERT: ../../../lib/x509/x509.c[get_alt_name]:2012 144s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 144s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 144s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 144s [tls ] RFC 7858 OOB key-pin (0): pin-sha256="" 144s [gnutls] (3) ASSERT: ../../lib/cert-cred-x509.c[gnutls_certificate_get_x509_crt]:872 144s [system] loading config '/usr/lib/aarch64-linux-gnu/knot-resolver/postconfig.lua' (workdir '/tmp/autopkgtest.r3bBfW/roundtrip-artifacts') 144s [plan ][00000.00] plan '.' type 'NS' uid [65536.00] 144s [iterat][65536.00] '.' type 'NS' new uid was assigned .01, parent uid .00 144s [resolv][65536.01] => using root hints 144s [iterat][65536.01] '.' type 'NS' new uid was assigned .02, parent uid .00 144s [resolv][65536.02] >< TA: '.' 144s [plan ][65536.02] plan '.' type 'DNSKEY' uid [65536.03] 144s [iterat][65536.03] '.' type 'DNSKEY' new uid was assigned .04, parent uid .02 144s [select][65536.04] => id: '40864' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 144s [select][65536.04] => id: '40864' choosing: 'H.ROOT-SERVERS.NET.'@'198.97.190.53#00053' with timeout 400 ms zone cut: '.' 144s [resolv][65536.04] => id: '40864' querying: 'H.ROOT-SERVERS.NET.'@'198.97.190.53#00053' zone cut: '.' qname: '.' qtype: 'DNSKEY' proto: 'udp' 144s [plan ][00000.00] plan '.' type 'NS' uid [65537.00] 144s [iterat][65537.00] '.' type 'NS' new uid was assigned .01, parent uid .00 144s [resolv][65537.01] => using root hints 144s [iterat][65537.01] '.' type 'NS' new uid was assigned .02, parent uid .00 144s [select][65537.02] => id: '57322' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 144s [select][65537.02] => id: '57322' choosing: 'E.ROOT-SERVERS.NET.'@'192.203.230.10#00053' with timeout 400 ms zone cut: '.' 144s [resolv][65537.02] => id: '57322' querying: 'E.ROOT-SERVERS.NET.'@'192.203.230.10#00053' zone cut: '.' qname: '.' qtype: 'NS' proto: 'udp' 144s [taupd ] refreshing TA for . 144s [plan ][00000.00] plan '.' type 'DNSKEY' uid [65538.00] 144s [iterat][65538.00] '.' type 'DNSKEY' new uid was assigned .01, parent uid .00 144s [resolv][65538.01] => using root hints 144s [iterat][65538.01] '.' type 'DNSKEY' new uid was assigned .02, parent uid .00 144s [resolv][65538.02] >< TA: '.' 144s [select][65538.02] => id: '62739' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 144s [select][65538.02] => id: '62739' choosing: 'D.ROOT-SERVERS.NET.'@'199.7.91.13#00053' with timeout 400 ms zone cut: '.' 144s [select][65536.04] => id: '40864' noting selection error: 'H.ROOT-SERVERS.NET.'@'198.97.190.53#00053' zone cut: '.' error: 1 QUERY_TIMEOUT 144s [iterat][65538.02] '.' type 'DNSKEY' new uid was assigned .03, parent uid .00 144s [select][65538.03] => id: '17632' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 144s [select][65538.03] => id: '17632' choosing: 'H.ROOT-SERVERS.NET.'@'2001:500:1::53#00053' with timeout 400 ms zone cut: '.' 144s [resolv][65538.03] => id: '17632' querying: 'H.ROOT-SERVERS.NET.'@'2001:500:1::53#00053' zone cut: '.' qname: '.' qtype: 'DNSKEY' proto: 'udp' 144s [iterat][65536.04] '.' type 'DNSKEY' new uid was assigned .05, parent uid .02 144s [select][65536.05] => id: '59422' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 144s [select][65536.05] => id: '59422' choosing: 'B.ROOT-SERVERS.NET.'@'2801:1b8:10::b#00053' with timeout 800 ms zone cut: '.' 144s [select][65537.02] => id: '57322' noting selection error: 'E.ROOT-SERVERS.NET.'@'192.203.230.10#00053' zone cut: '.' error: 1 QUERY_TIMEOUT 144s [iterat][65537.02] '.' type 'NS' new uid was assigned .03, parent uid .00 144s [select][65537.03] => id: '32225' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 144s [select][65537.03] => id: '32225' choosing: 'C.ROOT-SERVERS.NET.'@'2001:500:2::c#00053' with timeout 800 ms zone cut: '.' 144s [resolv][65537.03] => id: '32225' querying: 'C.ROOT-SERVERS.NET.'@'2001:500:2::c#00053' zone cut: '.' qname: '.' qtype: 'NS' proto: 'udp' 144s [select][65538.03] NO6: timed out, appended, timeouts 1/6 144s [select][65538.03] => id: '17632' noting selection error: 'H.ROOT-SERVERS.NET.'@'2001:500:1::53#00053' zone cut: '.' error: 1 QUERY_TIMEOUT 144s [iterat][65536.05] '.' type 'DNSKEY' new uid was assigned .06, parent uid .02 144s [select][65536.06] => id: '48088' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 144s [select][65536.06] => id: '48088' choosing: 'D.ROOT-SERVERS.NET.'@'2001:500:2d::d#00053' with timeout 800 ms zone cut: '.' 144s [resolv][65536.06] => id: '48088' querying: 'D.ROOT-SERVERS.NET.'@'2001:500:2d::d#00053' zone cut: '.' qname: '.' qtype: 'DNSKEY' proto: 'udp' 144s [iterat][65538.03] '.' type 'DNSKEY' new uid was assigned .04, parent uid .00 144s [select][65538.04] => id: '11101' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 144s [select][65538.04] => id: '11101' choosing: 'E.ROOT-SERVERS.NET.'@'2001:500:a8::e#00053' with timeout 800 ms zone cut: '.' 144s [plan ][00000.00] plan 'monkeys.example.' type 'A' uid [37642.00] 144s [iterat][37642.00] 'monkeys.example.' type 'A' new uid was assigned .01, parent uid .00 144s [hint ][37642.01] <= answered from hints 144s [iterat][37642.01] <= rcode: NOERROR 144s [resolv][37642.01] AD: request NOT classified as SECURE 144s [resolv][37642.01] finished in state: 4, queries: 1, mempool: 16400 B 144s [plan ][00000.00] plan 'monkeys.example.' type 'A' uid [43149.00] 144s [iterat][43149.00] 'monkeys.example.' type 'A' new uid was assigned .01, parent uid .00 144s [hint ][43149.01] <= answered from hints 144s [iterat][43149.01] <= rcode: NOERROR 144s [resolv][43149.01] AD: request NOT classified as SECURE 144s [resolv][43149.01] finished in state: 4, queries: 1, mempool: 81952 B 144s [io ] => connection to '127.0.0.1#46539' closed by peer (end of file) 144s [gnutls] (5) REC[0xf1622a3f0000]: Allocating epoch #0 144s [gnutls] (2) added 3 protocols, 29 ciphersuites, 19 sig algos and 10 groups into priority list 144s [gnutls] (5) REC[0xf1622a3f0000]: Allocating epoch #1 144s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 144s [gnutls] (5) REC[0xf1622a3f0000]: SSL 3.1 Handshake packet received. Epoch 0, length: 278 144s [gnutls] (5) REC[0xf1622a3f0000]: Expected Packet Handshake(22) 144s [gnutls] (5) REC[0xf1622a3f0000]: Received Packet Handshake(22) with length: 278 144s [gnutls] (5) REC[0xf1622a3f0000]: Decrypted Packet[0] Handshake(22) with length: 278 144s [gnutls] (4) HSK[0xf1622a3f0000]: CLIENT HELLO (1) was received. Length 274[274], frag offset 0, frag length: 274, sequence: 0 144s [gnutls] (4) HSK[0xf1622a3f0000]: Client's version: 3.3 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Supported Versions/43' (3 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Found version: 3.4 144s [gnutls] (4) EXT[0xf1622a3f0000]: Negotiated version: 3.4 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Record Size Limit/28' (2 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: record_size_limit 16385 negotiated 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Encrypt-then-MAC/22' (0 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Extended Master Secret/23' (0 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'ALPN/16' (6 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Safe Renegotiation/65281' (1 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Supported Groups/10' (10 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Received group X25519 (0x1d) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Received group SECP256R1 (0x17) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Received group SECP384R1 (0x18) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Received group SECP521R1 (0x19) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Selected group X25519 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Signature Algorithms/13' (34 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (4.1) RSA-SHA256 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.9) RSA-PSS-SHA256 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.4) RSA-PSS-RSAE-SHA256 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (4.3) ECDSA-SECP256R1-SHA256 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.7) EdDSA-Ed25519 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (5.1) RSA-SHA384 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.10) RSA-PSS-SHA384 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.5) RSA-PSS-RSAE-SHA384 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (5.3) ECDSA-SECP384R1-SHA384 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.8) EdDSA-Ed448 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (6.1) RSA-SHA512 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.11) RSA-PSS-SHA512 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.6) RSA-PSS-RSAE-SHA512 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (6.3) ECDSA-SECP521R1-SHA512 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (2.1) RSA-SHA1 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (2.3) ECDSA-SHA1 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Supported EC Point Formats/11' (2 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Session Ticket/35' (0 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'PSK Key Exchange Modes/45' (3 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: PSK KE mode 01 received 144s [gnutls] (4) EXT[0xf1622a3f0000]: PSK KE mode 00 received 144s [gnutls] (2) checking 13.02 (GNUTLS_AES_256_GCM_SHA384) for compatibility 144s [gnutls] (3) ASSERT: ../../../lib/ext/server_name.c[gnutls_server_name_get]:234 144s [gnutls] (4) HSK[0xf1622a3f0000]: Requested server name: '' 144s [gnutls] (4) HSK[0xf1622a3f0000]: checking compat of GNUTLS_AES_256_GCM_SHA384 with certificate[0] (RSA/X.509) 144s [gnutls] (4) checking cert compat with RSA-SHA256 144s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 144s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 144s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 144s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 144s [gnutls] (4) Selected signature algorithm: RSA-PSS-RSAE-SHA256 144s [gnutls] (2) Selected (RSA) cert based on ciphersuite 13.2: GNUTLS_AES_256_GCM_SHA384 144s [gnutls] (4) HSK[0xf1622a3f0000]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384 144s [gnutls] (4) HSK[0xf1622a3f0000]: Selected version TLS1.3 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Key Share/51' (107 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Received key share for X25519 144s [gnutls] (4) HSK[0xf1622a3f0000]: Selected group X25519 (6) 144s [gnutls] (2) EXT[0xf1622a3f0000]: server generated X25519 shared key 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'OCSP Status Request/5' (5 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: OCSP status was requested 144s [gnutls] (4) HSK[0xf1622a3f0000]: Safe renegotiation succeeded 144s [gnutls] (4) HSK[0xf1622a3f0000]: SessionID: 00 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (OCSP Status Request/5) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Client Certificate Type/19) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Server Certificate Type/20) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Supported Groups/10) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Supported EC Point Formats/11) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Signature Algorithms/13) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (SRTP/14) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (ALPN/16) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Encrypt-then-MAC/22) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Extended Master Secret/23) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Session Ticket/35) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Key Share/51) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: sending key share for X25519 144s [gnutls] (4) EXT[0xf1622a3f0000]: Sending extension Key Share/51 (36 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Supported Versions/43) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Sending extension Supported Versions/43 (2 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Post Handshake Auth/49) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Safe Renegotiation/65281) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Server Name Indication/0) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Cookie/44) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Early Data/42) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (PSK Key Exchange Modes/45) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Record Size Limit/28) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Maximum Record Size/1) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Compress Certificate/27) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (ClientHello Padding/21) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Pre Shared Key/41) for 'TLS 1.3 server hello' 144s [gnutls] (4) HSK[0xf1622a3f0000]: SERVER HELLO was queued [90 bytes] 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 90 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 95 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6 144s [gnutls] (4) REC[0xf1622a3f0000]: Sent ChangeCipherSpec 144s [gnutls] (5) REC[0xf1622a3f0000]: Initializing epoch #1 144s [gnutls] (5) REC[0xf1622a3f0000]: Epoch #1 ready 144s [gnutls] (4) HSK[0xf1622a3f0000]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (OCSP Status Request/5) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Client Certificate Type/19) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Server Certificate Type/20) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Supported Groups/10) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Supported EC Point Formats/11) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Signature Algorithms/13) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (SRTP/14) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (ALPN/16) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Sending extension ALPN/16 (6 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Encrypt-then-MAC/22) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Extended Master Secret/23) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Session Ticket/35) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Key Share/51) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Supported Versions/43) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Post Handshake Auth/49) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Safe Renegotiation/65281) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Server Name Indication/0) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Cookie/44) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Early Data/42) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (PSK Key Exchange Modes/45) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Record Size Limit/28) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Sending extension Record Size Limit/28 (2 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Maximum Record Size/1) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Compress Certificate/27) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (ClientHello Padding/21) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Pre Shared Key/41) for 'encrypted extensions' 144s [gnutls] (4) HSK[0xf1622a3f0000]: ENCRYPTED EXTENSIONS was queued [22 bytes] 144s [gnutls] (4) HSK[0xf1622a3f0000]: CERTIFICATE was queued [1155 bytes] 144s [gnutls] (4) checking cert compat with RSA-SHA256 144s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 144s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 144s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 144s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 144s [gnutls] (4) HSK[0xf1622a3f0000]: signing TLS 1.3 handshake data: using RSA-PSS-RSAE-SHA256 and PRF: SHA384 144s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 144s [gnutls] (4) HSK[0xf1622a3f0000]: CERTIFICATE VERIFY was queued [392 bytes] 144s [gnutls] (4) HSK[0xf1622a3f0000]: sending finished 144s [gnutls] (4) HSK[0xf1622a3f0000]: FINISHED was queued [52 bytes] 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 22 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 44 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 1155 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[2] Handshake(22) in epoch 1 and length: 1177 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 392 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[3] Handshake(22) in epoch 1 and length: 414 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 52 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[4] Handshake(22) in epoch 1 and length: 74 144s [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:965 144s [gnutls] (5) REC[0xf1622a3f0000]: Allocating epoch #2 144s [gnutls] (4) HSK[0xf1622a3f0000]: unauthenticated session eligible for early start 144s [gnutls] (5) REC[0xf1622a3f0000]: Initializing epoch #2 144s [gnutls] (5) REC[0xf1622a3f0000]: Epoch #2 ready 144s [gnutls] (4) HSK[0xf1622a3f0000]: TLS 1.3 set write key with cipher suite: GNUTLS_AES_256_GCM_SHA384 144s [gnutls] (4) HSK[0xf1622a3f0000]: switching early to application traffic keys 144s [gnutls] (4) HSK[0xf1622a3f0000]: NEW SESSION TICKET was queued [251 bytes] 144s [gnutls] (4) HSK[0xf1622a3f0000]: NEW SESSION TICKET was queued [251 bytes] 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[1] Handshake(22) in epoch 2 and length: 273 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[2] Handshake(22) in epoch 2 and length: 273 144s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 144s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 144s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 144s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 144s [gnutls] (5) REC[0xf1622a3f0000]: SSL 3.3 Application Data packet received. Epoch 1, length: 69 144s [gnutls] (5) REC[0xf1622a3f0000]: Expected Packet Handshake(22) 144s [gnutls] (5) REC[0xf1622a3f0000]: Received Packet Application Data(23) with length: 69 144s [gnutls] (5) REC[0xf1622a3f0000]: Decrypted Packet[0] Handshake(22) with length: 52 144s [gnutls] (4) HSK[0xf1622a3f0000]: FINISHED (20) was received. Length 48[48], frag offset 0, frag length: 48, sequence: 0 144s [gnutls] (4) HSK[0xf1622a3f0000]: parsing finished 144s [gnutls] (4) HSK[0xf1622a3f0000]: TLS 1.3 set read key with cipher suite: GNUTLS_AES_256_GCM_SHA384 144s [gnutls] (5) REC[0xf1622a3f0000]: Start of epoch cleanup 144s [gnutls] (5) REC[0xf1622a3f0000]: Epoch #0 freed 144s [gnutls] (5) REC[0xf1622a3f0000]: Epoch #1 freed 144s [gnutls] (5) REC[0xf1622a3f0000]: End of epoch cleanup 144s [tls ] TLS handshake with 127.0.0.1#52927 has completed 144s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 144s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1759 144s [gnutls] (5) REC[0xf1622a3f0000]: SSL 3.3 Application Data packet received. Epoch 2, length: 147 144s [gnutls] (5) REC[0xf1622a3f0000]: Expected Packet Application Data(23) 144s [gnutls] (5) REC[0xf1622a3f0000]: Received Packet Application Data(23) with length: 147 144s [gnutls] (5) REC[0xf1622a3f0000]: Decrypted Packet[0] Application Data(23) with length: 130 144s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 144s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1759 144s [plan ][00000.00] plan 'monkeys.example.' type 'A' uid [23094.00] 144s [iterat][23094.00] 'monkeys.example.' type 'A' new uid was assigned .01, parent uid .00 144s [hint ][23094.01] <= answered from hints 144s [iterat][23094.01] <= rcode: NOERROR 144s [resolv][23094.01] AD: request NOT classified as SECURE 144s [resolv][23094.01] finished in state: 4, queries: 1, mempool: 81952 B 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Application Data(23) with length: 470 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[3] Application Data(23) in epoch 2 and length: 492 144s [gnutls] (5) REC[0xf1622a3f0000]: SSL 3.3 Application Data packet received. Epoch 2, length: 19 144s [gnutls] (5) REC[0xf1622a3f0000]: Expected Packet Application Data(23) 144s [gnutls] (5) REC[0xf1622a3f0000]: Received Packet Application Data(23) with length: 19 144s [gnutls] (5) REC[0xf1622a3f0000]: Decrypted Packet[1] Alert(21) with length: 2 144s [gnutls] (5) REC[0xf1622a3f0000]: Alert[1|0] - Close notify - was received 144s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_in_buffers]:1565 144s [io ] => connection to '127.0.0.1#52927' closed by peer (end of file) 144s [gnutls] (5) REC[0xf1622a3f0000]: Start of epoch cleanup 144s [gnutls] (5) REC[0xf1622a3f0000]: End of epoch cleanup 144s [gnutls] (5) REC[0xf1622a3f0000]: Epoch #2 freed 144s [gnutls] (5) REC[0xf1622a3f0000]: Allocating epoch #0 144s [gnutls] (2) added 3 protocols, 29 ciphersuites, 19 sig algos and 10 groups into priority list 144s [gnutls] (5) REC[0xf1622a3f0000]: Allocating epoch #1 144s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 144s [gnutls] (5) REC[0xf1622a3f0000]: SSL 3.1 Handshake packet received. Epoch 0, length: 299 144s [gnutls] (5) REC[0xf1622a3f0000]: Expected Packet Handshake(22) 144s [gnutls] (5) REC[0xf1622a3f0000]: Received Packet Handshake(22) with length: 299 144s [gnutls] (5) REC[0xf1622a3f0000]: Decrypted Packet[0] Handshake(22) with length: 299 144s [gnutls] (4) HSK[0xf1622a3f0000]: CLIENT HELLO (1) was received. Length 295[295], frag offset 0, frag length: 295, sequence: 0 144s [gnutls] (4) HSK[0xf1622a3f0000]: Client's version: 3.3 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Supported Versions/43' (3 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Found version: 3.4 144s [gnutls] (4) EXT[0xf1622a3f0000]: Negotiated version: 3.4 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Record Size Limit/28' (2 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: record_size_limit 16385 negotiated 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Encrypt-then-MAC/22' (0 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Extended Master Secret/23' (0 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'ALPN/16' (6 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Server Name Indication/0' (17 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Safe Renegotiation/65281' (1 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'PSK Key Exchange Modes/45' (3 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: PSK KE mode 01 received 144s [gnutls] (4) EXT[0xf1622a3f0000]: PSK KE mode 00 received 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Supported EC Point Formats/11' (2 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Session Ticket/35' (0 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Supported Groups/10' (10 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Received group X25519 (0x1d) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Received group SECP256R1 (0x17) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Received group SECP384R1 (0x18) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Received group SECP521R1 (0x19) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Selected group X25519 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Signature Algorithms/13' (34 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (4.1) RSA-SHA256 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.9) RSA-PSS-SHA256 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.4) RSA-PSS-RSAE-SHA256 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (4.3) ECDSA-SECP256R1-SHA256 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.7) EdDSA-Ed25519 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (5.1) RSA-SHA384 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.10) RSA-PSS-SHA384 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.5) RSA-PSS-RSAE-SHA384 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (5.3) ECDSA-SECP384R1-SHA384 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.8) EdDSA-Ed448 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (6.1) RSA-SHA512 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.11) RSA-PSS-SHA512 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.6) RSA-PSS-RSAE-SHA512 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (6.3) ECDSA-SECP521R1-SHA512 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (2.1) RSA-SHA1 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (2.3) ECDSA-SHA1 144s [gnutls] (2) checking 13.02 (GNUTLS_AES_256_GCM_SHA384) for compatibility 144s [gnutls] (4) HSK[0xf1622a3f0000]: Requested server name: 'test.example' 144s [gnutls] (4) checking cert compat with RSA-SHA256 144s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 144s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 144s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 144s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 144s [gnutls] (4) Selected signature algorithm: RSA-PSS-RSAE-SHA256 144s [gnutls] (2) Selected (RSA) cert based on ciphersuite 13.2: GNUTLS_AES_256_GCM_SHA384 144s [gnutls] (4) HSK[0xf1622a3f0000]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384 144s [gnutls] (4) HSK[0xf1622a3f0000]: Selected version TLS1.3 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Key Share/51' (107 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Received key share for X25519 144s [gnutls] (4) HSK[0xf1622a3f0000]: Selected group X25519 (6) 144s [gnutls] (2) EXT[0xf1622a3f0000]: server generated X25519 shared key 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'OCSP Status Request/5' (5 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: OCSP status was requested 144s [gnutls] (4) HSK[0xf1622a3f0000]: Safe renegotiation succeeded 144s [gnutls] (4) HSK[0xf1622a3f0000]: SessionID: 00 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (OCSP Status Request/5) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Client Certificate Type/19) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Server Certificate Type/20) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Supported Groups/10) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Supported EC Point Formats/11) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Signature Algorithms/13) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (SRTP/14) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (ALPN/16) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Encrypt-then-MAC/22) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Extended Master Secret/23) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Session Ticket/35) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Key Share/51) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: sending key share for X25519 144s [gnutls] (4) EXT[0xf1622a3f0000]: Sending extension Key Share/51 (36 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Supported Versions/43) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Sending extension Supported Versions/43 (2 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Post Handshake Auth/49) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Safe Renegotiation/65281) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Server Name Indication/0) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Cookie/44) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Early Data/42) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (PSK Key Exchange Modes/45) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Record Size Limit/28) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Maximum Record Size/1) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Compress Certificate/27) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (ClientHello Padding/21) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Pre Shared Key/41) for 'TLS 1.3 server hello' 144s [gnutls] (4) HSK[0xf1622a3f0000]: SERVER HELLO was queued [90 bytes] 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 90 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 95 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6 144s [gnutls] (4) REC[0xf1622a3f0000]: Sent ChangeCipherSpec 144s [gnutls] (5) REC[0xf1622a3f0000]: Initializing epoch #1 144s [gnutls] (5) REC[0xf1622a3f0000]: Epoch #1 ready 144s [gnutls] (4) HSK[0xf1622a3f0000]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (OCSP Status Request/5) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Client Certificate Type/19) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Server Certificate Type/20) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Supported Groups/10) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Supported EC Point Formats/11) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Signature Algorithms/13) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (SRTP/14) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (ALPN/16) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Sending extension ALPN/16 (6 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Encrypt-then-MAC/22) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Extended Master Secret/23) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Session Ticket/35) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Key Share/51) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Supported Versions/43) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Post Handshake Auth/49) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Safe Renegotiation/65281) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Server Name Indication/0) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Cookie/44) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Early Data/42) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (PSK Key Exchange Modes/45) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Record Size Limit/28) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Sending extension Record Size Limit/28 (2 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Maximum Record Size/1) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Compress Certificate/27) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (ClientHello Padding/21) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Pre Shared Key/41) for 'encrypted extensions' 144s [gnutls] (4) HSK[0xf1622a3f0000]: ENCRYPTED EXTENSIONS was queued [22 bytes] 144s [gnutls] (4) HSK[0xf1622a3f0000]: CERTIFICATE was queued [1155 bytes] 144s [gnutls] (4) checking cert compat with RSA-SHA256 144s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 144s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 144s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 144s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 144s [gnutls] (4) HSK[0xf1622a3f0000]: signing TLS 1.3 handshake data: using RSA-PSS-RSAE-SHA256 and PRF: SHA384 144s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 144s [gnutls] (4) HSK[0xf1622a3f0000]: CERTIFICATE VERIFY was queued [392 bytes] 144s [gnutls] (4) HSK[0xf1622a3f0000]: sending finished 144s [gnutls] (4) HSK[0xf1622a3f0000]: FINISHED was queued [52 bytes] 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 22 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 44 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 1155 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[2] Handshake(22) in epoch 1 and length: 1177 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 392 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[3] Handshake(22) in epoch 1 and length: 414 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 52 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[4] Handshake(22) in epoch 1 and length: 74 144s [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:965 144s [gnutls] (5) REC[0xf1622a3f0000]: Allocating epoch #2 144s [gnutls] (4) HSK[0xf1622a3f0000]: unauthenticated session eligible for early start 144s [gnutls] (5) REC[0xf1622a3f0000]: Initializing epoch #2 144s [gnutls] (5) REC[0xf1622a3f0000]: Epoch #2 ready 144s [gnutls] (4) HSK[0xf1622a3f0000]: TLS 1.3 set write key with cipher suite: GNUTLS_AES_256_GCM_SHA384 144s [gnutls] (4) HSK[0xf1622a3f0000]: switching early to application traffic keys 144s [gnutls] (4) HSK[0xf1622a3f0000]: NEW SESSION TICKET was queued [251 bytes] 144s [gnutls] (4) HSK[0xf1622a3f0000]: NEW SESSION TICKET was queued [251 bytes] 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[1] Handshake(22) in epoch 2 and length: 273 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[2] Handshake(22) in epoch 2 and length: 273 144s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 144s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 144s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 144s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 144s [gnutls] (5) REC[0xf1622a3f0000]: SSL 3.3 Application Data packet received. Epoch 1, length: 69 144s [gnutls] (5) REC[0xf1622a3f0000]: Expected Packet Handshake(22) 144s [gnutls] (5) REC[0xf1622a3f0000]: Received Packet Application Data(23) with length: 69 144s [gnutls] (5) REC[0xf1622a3f0000]: Decrypted Packet[0] Handshake(22) with length: 52 144s [gnutls] (4) HSK[0xf1622a3f0000]: FINISHED (20) was received. Length 48[48], frag offset 0, frag length: 48, sequence: 0 144s [gnutls] (4) HSK[0xf1622a3f0000]: parsing finished 144s [gnutls] (4) HSK[0xf1622a3f0000]: TLS 1.3 set read key with cipher suite: GNUTLS_AES_256_GCM_SHA384 144s [gnutls] (5) REC[0xf1622a3f0000]: Start of epoch cleanup 144s [gnutls] (5) REC[0xf1622a3f0000]: Epoch #0 freed 144s [gnutls] (5) REC[0xf1622a3f0000]: Epoch #1 freed 144s [gnutls] (5) REC[0xf1622a3f0000]: End of epoch cleanup 144s [tls ] TLS handshake with 127.0.0.1#53001 has completed 144s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 144s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1759 144s [gnutls] (5) REC[0xf1622a3f0000]: SSL 3.3 Application Data packet received. Epoch 2, length: 147 144s [gnutls] (5) REC[0xf1622a3f0000]: Expected Packet Application Data(23) 144s [gnutls] (5) REC[0xf1622a3f0000]: Received Packet Application Data(23) with length: 147 144s [gnutls] (5) REC[0xf1622a3f0000]: Decrypted Packet[0] Application Data(23) with length: 130 144s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 144s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1759 144s [plan ][00000.00] plan 'monkeys.example.' type 'A' uid [38449.00] 144s [iterat][38449.00] 'monkeys.example.' type 'A' new uid was assigned .01, parent uid .00 144s [hint ][38449.01] <= answered from hints 144s [iterat][38449.01] <= rcode: NOERROR 144s [resolv][38449.01] AD: request NOT classified as SECURE 144s [resolv][38449.01] finished in state: 4, queries: 1, mempool: 81952 B 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Application Data(23) with length: 470 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[3] Application Data(23) in epoch 2 and length: 492 144s [gnutls] (5) REC[0xf1622a3f0000]: SSL 3.3 Application Data packet received. Epoch 2, length: 19 144s [gnutls] (5) REC[0xf1622a3f0000]: Expected Packet Application Data(23) 144s [gnutls] (5) REC[0xf1622a3f0000]: Received Packet Application Data(23) with length: 19 144s [gnutls] (5) REC[0xf1622a3f0000]: Decrypted Packet[1] Alert(21) with length: 2 144s [gnutls] (5) REC[0xf1622a3f0000]: Alert[1|0] - Close notify - was received 144s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_in_buffers]:1565 144s [io ] => connection to '127.0.0.1#53001' closed by peer (end of file) 144s [gnutls] (5) REC[0xf1622a3f0000]: Start of epoch cleanup 144s [gnutls] (5) REC[0xf1622a3f0000]: End of epoch cleanup 144s [gnutls] (5) REC[0xf1622a3f0000]: Epoch #2 freed 144s [gnutls] (5) REC[0xf1622a3f0000]: Allocating epoch #0 144s [gnutls] (2) added 3 protocols, 29 ciphersuites, 19 sig algos and 10 groups into priority list 144s [gnutls] (5) REC[0xf1622a3f0000]: Allocating epoch #1 144s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 144s [gnutls] (5) REC[0xf1622a3f0000]: SSL 3.1 Handshake packet received. Epoch 0, length: 303 144s [gnutls] (5) REC[0xf1622a3f0000]: Expected Packet Handshake(22) 144s [gnutls] (5) REC[0xf1622a3f0000]: Received Packet Handshake(22) with length: 303 144s [gnutls] (5) REC[0xf1622a3f0000]: Decrypted Packet[0] Handshake(22) with length: 303 144s [gnutls] (4) HSK[0xf1622a3f0000]: CLIENT HELLO (1) was received. Length 299[299], frag offset 0, frag length: 299, sequence: 0 144s [gnutls] (4) HSK[0xf1622a3f0000]: Client's version: 3.3 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Supported Versions/43' (3 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Found version: 3.4 144s [gnutls] (4) EXT[0xf1622a3f0000]: Negotiated version: 3.4 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'ALPN/16' (6 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Safe Renegotiation/65281' (1 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Server Name Indication/0' (21 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Encrypt-then-MAC/22' (0 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Extended Master Secret/23' (0 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Record Size Limit/28' (2 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: record_size_limit 16385 negotiated 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Supported EC Point Formats/11' (2 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Supported Groups/10' (10 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Received group X25519 (0x1d) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Received group SECP256R1 (0x17) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Received group SECP384R1 (0x18) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Received group SECP521R1 (0x19) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Selected group X25519 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'PSK Key Exchange Modes/45' (3 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: PSK KE mode 01 received 144s [gnutls] (4) EXT[0xf1622a3f0000]: PSK KE mode 00 received 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Signature Algorithms/13' (34 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (4.1) RSA-SHA256 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.9) RSA-PSS-SHA256 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.4) RSA-PSS-RSAE-SHA256 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (4.3) ECDSA-SECP256R1-SHA256 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.7) EdDSA-Ed25519 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (5.1) RSA-SHA384 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.10) RSA-PSS-SHA384 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.5) RSA-PSS-RSAE-SHA384 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (5.3) ECDSA-SECP384R1-SHA384 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.8) EdDSA-Ed448 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (6.1) RSA-SHA512 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.11) RSA-PSS-SHA512 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.6) RSA-PSS-RSAE-SHA512 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (6.3) ECDSA-SECP521R1-SHA512 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (2.1) RSA-SHA1 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (2.3) ECDSA-SHA1 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Session Ticket/35' (0 bytes) 144s [gnutls] (2) checking 13.02 (GNUTLS_AES_256_GCM_SHA384) for compatibility 144s [gnutls] (4) HSK[0xf1622a3f0000]: Requested server name: 'notright.example' 144s [gnutls] (4) HSK[0xf1622a3f0000]: checking compat of GNUTLS_AES_256_GCM_SHA384 with certificate[0] (RSA/X.509) 144s [gnutls] (4) checking cert compat with RSA-SHA256 144s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 144s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 144s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 144s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 144s [gnutls] (4) Selected signature algorithm: RSA-PSS-RSAE-SHA256 144s [gnutls] (2) Selected (RSA) cert based on ciphersuite 13.2: GNUTLS_AES_256_GCM_SHA384 144s [gnutls] (4) HSK[0xf1622a3f0000]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384 144s [gnutls] (4) HSK[0xf1622a3f0000]: Selected version TLS1.3 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Key Share/51' (107 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Received key share for X25519 144s [gnutls] (4) HSK[0xf1622a3f0000]: Selected group X25519 (6) 144s [gnutls] (2) EXT[0xf1622a3f0000]: server generated X25519 shared key 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'OCSP Status Request/5' (5 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: OCSP status was requested 144s [gnutls] (4) HSK[0xf1622a3f0000]: Safe renegotiation succeeded 144s [gnutls] (4) HSK[0xf1622a3f0000]: SessionID: 00 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (OCSP Status Request/5) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Client Certificate Type/19) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Server Certificate Type/20) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Supported Groups/10) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Supported EC Point Formats/11) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Signature Algorithms/13) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (SRTP/14) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (ALPN/16) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Encrypt-then-MAC/22) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Extended Master Secret/23) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Session Ticket/35) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Key Share/51) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: sending key share for X25519 144s [gnutls] (4) EXT[0xf1622a3f0000]: Sending extension Key Share/51 (36 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Supported Versions/43) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Sending extension Supported Versions/43 (2 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Post Handshake Auth/49) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Safe Renegotiation/65281) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Server Name Indication/0) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Cookie/44) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Early Data/42) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (PSK Key Exchange Modes/45) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Record Size Limit/28) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Maximum Record Size/1) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Compress Certificate/27) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (ClientHello Padding/21) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Pre Shared Key/41) for 'TLS 1.3 server hello' 144s [gnutls] (4) HSK[0xf1622a3f0000]: SERVER HELLO was queued [90 bytes] 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 90 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 95 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6 144s [gnutls] (4) REC[0xf1622a3f0000]: Sent ChangeCipherSpec 144s [gnutls] (5) REC[0xf1622a3f0000]: Initializing epoch #1 144s [gnutls] (5) REC[0xf1622a3f0000]: Epoch #1 ready 144s [gnutls] (4) HSK[0xf1622a3f0000]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (OCSP Status Request/5) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Client Certificate Type/19) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Server Certificate Type/20) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Supported Groups/10) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Supported EC Point Formats/11) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Signature Algorithms/13) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (SRTP/14) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (ALPN/16) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Sending extension ALPN/16 (6 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Encrypt-then-MAC/22) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Extended Master Secret/23) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Session Ticket/35) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Key Share/51) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Supported Versions/43) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Post Handshake Auth/49) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Safe Renegotiation/65281) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Server Name Indication/0) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Cookie/44) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Early Data/42) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (PSK Key Exchange Modes/45) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Record Size Limit/28) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Sending extension Record Size Limit/28 (2 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Maximum Record Size/1) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Compress Certificate/27) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (ClientHello Padding/21) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Pre Shared Key/41) for 'encrypted extensions' 144s [gnutls] (4) HSK[0xf1622a3f0000]: ENCRYPTED EXTENSIONS was queued [22 bytes] 144s [gnutls] (4) HSK[0xf1622a3f0000]: CERTIFICATE was queued [1155 bytes] 144s [gnutls] (4) checking cert compat with RSA-SHA256 144s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 144s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 144s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 144s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 144s [gnutls] (4) HSK[0xf1622a3f0000]: signing TLS 1.3 handshake data: using RSA-PSS-RSAE-SHA256 and PRF: SHA384 144s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 144s [gnutls] (4) HSK[0xf1622a3f0000]: CERTIFICATE VERIFY was queued [392 bytes] 144s [gnutls] (4) HSK[0xf1622a3f0000]: sending finished 144s [gnutls] (4) HSK[0xf1622a3f0000]: FINISHED was queued [52 bytes] 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 22 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 44 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 1155 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[2] Handshake(22) in epoch 1 and length: 1177 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 392 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[3] Handshake(22) in epoch 1 and length: 414 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 52 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[4] Handshake(22) in epoch 1 and length: 74 144s [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:965 144s [gnutls] (5) REC[0xf1622a3f0000]: Allocating epoch #2 144s [gnutls] (4) HSK[0xf1622a3f0000]: unauthenticated session eligible for early start 144s [gnutls] (5) REC[0xf1622a3f0000]: Initializing epoch #2 144s [gnutls] (5) REC[0xf1622a3f0000]: Epoch #2 ready 144s [gnutls] (4) HSK[0xf1622a3f0000]: TLS 1.3 set write key with cipher suite: GNUTLS_AES_256_GCM_SHA384 144s [gnutls] (4) HSK[0xf1622a3f0000]: switching early to application traffic keys 144s [gnutls] (4) HSK[0xf1622a3f0000]: NEW SESSION TICKET was queued [251 bytes] 144s [gnutls] (4) HSK[0xf1622a3f0000]: NEW SESSION TICKET was queued [251 bytes] 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[1] Handshake(22) in epoch 2 and length: 273 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[2] Handshake(22) in epoch 2 and length: 273 144s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 144s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 144s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 144s [io ] => connection to '127.0.0.1#39779' closed by peer (connection reset by peer) 144s [gnutls] (5) REC[0xf1622a3f0000]: Start of epoch cleanup 144s [gnutls] (5) REC[0xf1622a3f0000]: Epoch #0 freed 144s [gnutls] (5) REC[0xf1622a3f0000]: End of epoch cleanup 144s [gnutls] (5) REC[0xf1622a3f0000]: Epoch #1 freed 144s [gnutls] (5) REC[0xf1622a3f0000]: Epoch #2 freed 144s [gnutls] (5) REC[0xf1622a3f0000]: Allocating epoch #0 144s [gnutls] (2) added 3 protocols, 29 ciphersuites, 19 sig algos and 10 groups into priority list 144s [gnutls] (5) REC[0xf1622a3f0000]: Allocating epoch #1 144s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 144s [gnutls] (5) REC[0xf1622a3f0000]: SSL 3.1 Handshake packet received. Epoch 0, length: 299 144s [gnutls] (5) REC[0xf1622a3f0000]: Expected Packet Handshake(22) 144s [gnutls] (5) REC[0xf1622a3f0000]: Received Packet Handshake(22) with length: 299 144s [gnutls] (5) REC[0xf1622a3f0000]: Decrypted Packet[0] Handshake(22) with length: 299 144s [gnutls] (4) HSK[0xf1622a3f0000]: CLIENT HELLO (1) was received. Length 295[295], frag offset 0, frag length: 295, sequence: 0 144s [gnutls] (4) HSK[0xf1622a3f0000]: Client's version: 3.3 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Supported Versions/43' (3 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Found version: 3.4 144s [gnutls] (4) EXT[0xf1622a3f0000]: Negotiated version: 3.4 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Encrypt-then-MAC/22' (0 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'ALPN/16' (6 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Server Name Indication/0' (17 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Extended Master Secret/23' (0 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Record Size Limit/28' (2 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: record_size_limit 16385 negotiated 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Safe Renegotiation/65281' (1 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Supported Groups/10' (10 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Received group X25519 (0x1d) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Received group SECP256R1 (0x17) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Received group SECP384R1 (0x18) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Received group SECP521R1 (0x19) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Selected group X25519 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Session Ticket/35' (0 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'PSK Key Exchange Modes/45' (3 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: PSK KE mode 01 received 144s [gnutls] (4) EXT[0xf1622a3f0000]: PSK KE mode 00 received 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Supported EC Point Formats/11' (2 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Signature Algorithms/13' (34 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (4.1) RSA-SHA256 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.9) RSA-PSS-SHA256 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.4) RSA-PSS-RSAE-SHA256 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (4.3) ECDSA-SECP256R1-SHA256 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.7) EdDSA-Ed25519 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (5.1) RSA-SHA384 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.10) RSA-PSS-SHA384 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.5) RSA-PSS-RSAE-SHA384 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (5.3) ECDSA-SECP384R1-SHA384 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.8) EdDSA-Ed448 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (6.1) RSA-SHA512 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.11) RSA-PSS-SHA512 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (8.6) RSA-PSS-RSAE-SHA512 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (6.3) ECDSA-SECP521R1-SHA512 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (2.1) RSA-SHA1 144s [gnutls] (4) EXT[0xf1622a3f0000]: rcvd signature algo (2.3) ECDSA-SHA1 144s [gnutls] (2) checking 13.02 (GNUTLS_AES_256_GCM_SHA384) for compatibility 144s [gnutls] (4) HSK[0xf1622a3f0000]: Requested server name: 'test.example' 144s [gnutls] (4) checking cert compat with RSA-SHA256 144s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 144s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 144s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 144s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 144s [gnutls] (4) Selected signature algorithm: RSA-PSS-RSAE-SHA256 144s [gnutls] (2) Selected (RSA) cert based on ciphersuite 13.2: GNUTLS_AES_256_GCM_SHA384 144s [gnutls] (4) HSK[0xf1622a3f0000]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384 144s [gnutls] (4) HSK[0xf1622a3f0000]: Selected version TLS1.3 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'OCSP Status Request/5' (5 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: OCSP status was requested 144s [gnutls] (4) EXT[0xf1622a3f0000]: Parsing extension 'Key Share/51' (107 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Received key share for X25519 144s [gnutls] (4) HSK[0xf1622a3f0000]: Selected group X25519 (6) 144s [gnutls] (2) EXT[0xf1622a3f0000]: server generated X25519 shared key 144s [gnutls] (4) HSK[0xf1622a3f0000]: Safe renegotiation succeeded 144s [gnutls] (4) HSK[0xf1622a3f0000]: SessionID: 00 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (OCSP Status Request/5) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Client Certificate Type/19) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Server Certificate Type/20) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Supported Groups/10) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Supported EC Point Formats/11) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Signature Algorithms/13) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (SRTP/14) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (ALPN/16) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Encrypt-then-MAC/22) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Extended Master Secret/23) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Session Ticket/35) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Key Share/51) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: sending key share for X25519 144s [gnutls] (4) EXT[0xf1622a3f0000]: Sending extension Key Share/51 (36 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Supported Versions/43) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Sending extension Supported Versions/43 (2 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Post Handshake Auth/49) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Safe Renegotiation/65281) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Server Name Indication/0) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Cookie/44) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Early Data/42) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (PSK Key Exchange Modes/45) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Record Size Limit/28) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Maximum Record Size/1) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Compress Certificate/27) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (ClientHello Padding/21) for 'TLS 1.3 server hello' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Pre Shared Key/41) for 'TLS 1.3 server hello' 144s [gnutls] (4) HSK[0xf1622a3f0000]: SERVER HELLO was queued [90 bytes] 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 90 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 95 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6 144s [gnutls] (4) REC[0xf1622a3f0000]: Sent ChangeCipherSpec 144s [gnutls] (5) REC[0xf1622a3f0000]: Initializing epoch #1 144s [gnutls] (5) REC[0xf1622a3f0000]: Epoch #1 ready 144s [gnutls] (4) HSK[0xf1622a3f0000]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (OCSP Status Request/5) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Client Certificate Type/19) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Server Certificate Type/20) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Supported Groups/10) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Supported EC Point Formats/11) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Signature Algorithms/13) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (SRTP/14) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (ALPN/16) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Sending extension ALPN/16 (6 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Encrypt-then-MAC/22) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Extended Master Secret/23) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Session Ticket/35) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Key Share/51) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Supported Versions/43) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Post Handshake Auth/49) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Safe Renegotiation/65281) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Server Name Indication/0) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Cookie/44) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Early Data/42) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (PSK Key Exchange Modes/45) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Record Size Limit/28) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Sending extension Record Size Limit/28 (2 bytes) 144s [gnutls] (4) EXT[0xf1622a3f0000]: Preparing extension (Maximum Record Size/1) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Compress Certificate/27) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (ClientHello Padding/21) for 'encrypted extensions' 144s [gnutls] (4) EXT[0xf1622a3f0000]: Not sending extension (Pre Shared Key/41) for 'encrypted extensions' 144s [gnutls] (4) HSK[0xf1622a3f0000]: ENCRYPTED EXTENSIONS was queued [22 bytes] 144s [gnutls] (4) HSK[0xf1622a3f0000]: CERTIFICATE was queued [1155 bytes] 144s [gnutls] (4) checking cert compat with RSA-SHA256 144s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 144s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 144s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 144s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 144s [gnutls] (4) HSK[0xf1622a3f0000]: signing TLS 1.3 handshake data: using RSA-PSS-RSAE-SHA256 and PRF: SHA384 144s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 144s [gnutls] (4) HSK[0xf1622a3f0000]: CERTIFICATE VERIFY was queued [392 bytes] 144s [gnutls] (4) HSK[0xf1622a3f0000]: sending finished 144s [gnutls] (4) HSK[0xf1622a3f0000]: FINISHED was queued [52 bytes] 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 22 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 44 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 1155 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[2] Handshake(22) in epoch 1 and length: 1177 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 392 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[3] Handshake(22) in epoch 1 and length: 414 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 52 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[4] Handshake(22) in epoch 1 and length: 74 144s [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:965 144s [gnutls] (5) REC[0xf1622a3f0000]: Allocating epoch #2 144s [gnutls] (4) HSK[0xf1622a3f0000]: unauthenticated session eligible for early start 144s [gnutls] (5) REC[0xf1622a3f0000]: Initializing epoch #2 144s [gnutls] (5) REC[0xf1622a3f0000]: Epoch #2 ready 144s [gnutls] (4) HSK[0xf1622a3f0000]: TLS 1.3 set write key with cipher suite: GNUTLS_AES_256_GCM_SHA384 144s [gnutls] (4) HSK[0xf1622a3f0000]: switching early to application traffic keys 144s [gnutls] (4) HSK[0xf1622a3f0000]: NEW SESSION TICKET was queued [251 bytes] 144s [gnutls] (4) HSK[0xf1622a3f0000]: NEW SESSION TICKET was queued [251 bytes] 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[1] Handshake(22) in epoch 2 and length: 273 144s [gnutls] (5) REC[0xf1622a3f0000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 144s [gnutls] (5) REC[0xf1622a3f0000]: Sent Packet[2] Handshake(22) in epoch 2 and length: 273 144s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 144s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 144s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 144s [io ] => connection to '127.0.0.1#52363' closed by peer (connection reset by peer) 144s [gnutls] (5) REC[0xf1622a3f0000]: Start of epoch cleanup 144s [gnutls] (5) REC[0xf1622a3f0000]: Epoch #0 freed 144s [gnutls] (5) REC[0xf1622a3f0000]: End of epoch cleanup 144s [gnutls] (5) REC[0xf1622a3f0000]: Epoch #1 freed 144s [gnutls] (5) REC[0xf1622a3f0000]: Epoch #2 freed 144s > 144s > autopkgtest [00:51:28]: test roundtrip: -----------------------] 145s roundtrip PASS 145s autopkgtest [00:51:29]: test roundtrip: - - - - - - - - - - results - - - - - - - - - - 149s autopkgtest [00:51:33]: @@@@@@@@@@@@@@@@@@@@ summary 149s roundtrip PASS