0s autopkgtest [08:42:54]: starting date and time: 2025-10-21 08:42:54+0000 0s autopkgtest [08:42:54]: git checkout: 4b346b80 nova: make wait_reboot return success even when a no-op 0s autopkgtest [08:42:54]: host juju-7f2275-prod-proposed-migration-environment-15; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.tetk2usw/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-cpu2-ram4-disk20-amd64 --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-15@sto01-2.secgroup --name adt-resolute-amd64-knot-resolver-20251021-084254-juju-7f2275-prod-proposed-migration-environment-15-99655604-d82d-43a5-b8ab-037a6a933c5d --image adt/ubuntu-resolute-amd64-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-15 --net-id=net_prod-autopkgtest-workers-amd64 -e TERM=linux --mirror=http://ftpmaster.internal/ubuntu/ 3s Creating nova instance adt-resolute-amd64-knot-resolver-20251021-084254-juju-7f2275-prod-proposed-migration-environment-15-99655604-d82d-43a5-b8ab-037a6a933c5d from image adt/ubuntu-resolute-amd64-server-20251020.img (UUID 058eb65a-2f1f-4603-be3f-91b3fbc0088c)... 31s autopkgtest [08:43:25]: testbed dpkg architecture: amd64 31s autopkgtest [08:43:25]: testbed apt version: 3.1.8ubuntu1 31s autopkgtest [08:43:25]: @@@@@@@@@@@@@@@@@@@@ test bed setup 31s autopkgtest [08:43:25]: testbed release detected to be: None 32s autopkgtest [08:43:26]: updating testbed package index (apt update) 32s Get:1 http://ftpmaster.internal/ubuntu resolute-proposed InRelease [83.3 kB] 32s Hit:2 http://ftpmaster.internal/ubuntu resolute InRelease 32s Hit:3 http://ftpmaster.internal/ubuntu resolute-updates InRelease 32s Hit:4 http://ftpmaster.internal/ubuntu resolute-security InRelease 32s Get:5 http://ftpmaster.internal/ubuntu resolute-proposed/multiverse Sources [15.0 kB] 32s Get:6 http://ftpmaster.internal/ubuntu resolute-proposed/universe Sources [560 kB] 33s Get:7 http://ftpmaster.internal/ubuntu resolute-proposed/main Sources [59.1 kB] 33s Get:8 http://ftpmaster.internal/ubuntu resolute-proposed/restricted Sources [5028 B] 33s Get:9 http://ftpmaster.internal/ubuntu resolute-proposed/main amd64 Packages [124 kB] 33s Get:10 http://ftpmaster.internal/ubuntu resolute-proposed/main i386 Packages [75.4 kB] 33s Get:11 http://ftpmaster.internal/ubuntu resolute-proposed/restricted i386 Packages [3208 B] 33s Get:12 http://ftpmaster.internal/ubuntu resolute-proposed/restricted amd64 Packages [28.0 kB] 33s Get:13 http://ftpmaster.internal/ubuntu resolute-proposed/universe amd64 Packages [379 kB] 33s Get:14 http://ftpmaster.internal/ubuntu resolute-proposed/universe i386 Packages [130 kB] 33s Get:15 http://ftpmaster.internal/ubuntu resolute-proposed/multiverse amd64 Packages [6744 B] 33s Get:16 http://ftpmaster.internal/ubuntu resolute-proposed/multiverse i386 Packages [3156 B] 33s Fetched 1472 kB in 1s (1875 kB/s) 33s Reading package lists... 34s Hit:1 http://ftpmaster.internal/ubuntu resolute-proposed InRelease 34s Hit:2 http://ftpmaster.internal/ubuntu resolute InRelease 34s Hit:3 http://ftpmaster.internal/ubuntu resolute-updates InRelease 34s Hit:4 http://ftpmaster.internal/ubuntu resolute-security InRelease 34s Reading package lists... 34s Reading package lists... 35s Building dependency tree... 35s Reading state information... 35s Calculating upgrade... 35s The following packages will be upgraded: 35s libbrotli1 libjson-c5 libpython3.13 libpython3.13-minimal 35s libpython3.13-stdlib libxml2-16 python3-bcrypt python3-dbus python3-inflect 35s python3-markupsafe python3-oauthlib python3-zipp python3.13 python3.13-gdbm 35s python3.13-minimal 35s 15 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 35s Need to get 10.0 MB of archives. 35s After this operation, 181 kB disk space will be freed. 35s Get:1 http://ftpmaster.internal/ubuntu resolute/main amd64 python3.13 amd64 3.13.9-1 [753 kB] 35s Get:2 http://ftpmaster.internal/ubuntu resolute/main amd64 python3.13-minimal amd64 3.13.9-1 [2408 kB] 35s Get:3 http://ftpmaster.internal/ubuntu resolute/main amd64 libpython3.13 amd64 3.13.9-1 [2367 kB] 35s Get:4 http://ftpmaster.internal/ubuntu resolute/main amd64 libpython3.13-stdlib amd64 3.13.9-1 [2078 kB] 35s Get:5 http://ftpmaster.internal/ubuntu resolute/main amd64 libpython3.13-minimal amd64 3.13.9-1 [887 kB] 35s Get:6 http://ftpmaster.internal/ubuntu resolute/main amd64 libjson-c5 amd64 0.18+ds-1.1 [37.7 kB] 35s Get:7 http://ftpmaster.internal/ubuntu resolute/main amd64 libxml2-16 amd64 2.14.5+dfsg-0.2build1 [616 kB] 35s Get:8 http://ftpmaster.internal/ubuntu resolute/main amd64 python3-dbus amd64 1.4.0-1build1 [118 kB] 35s Get:9 http://ftpmaster.internal/ubuntu resolute/main amd64 python3.13-gdbm amd64 3.13.9-1 [32.6 kB] 35s Get:10 http://ftpmaster.internal/ubuntu resolute/main amd64 libbrotli1 amd64 1.1.0-2build6 [334 kB] 35s Get:11 http://ftpmaster.internal/ubuntu resolute/main amd64 python3-inflect all 7.5.0-1 [33.9 kB] 35s Get:12 http://ftpmaster.internal/ubuntu resolute/main amd64 python3-markupsafe amd64 2.1.5-1build5 [13.8 kB] 35s Get:13 http://ftpmaster.internal/ubuntu resolute/main amd64 python3-oauthlib all 3.3.1-1 [93.5 kB] 35s Get:14 http://ftpmaster.internal/ubuntu resolute/main amd64 python3-zipp all 3.23.0-1 [10.4 kB] 35s Get:15 http://ftpmaster.internal/ubuntu resolute/main amd64 python3-bcrypt amd64 4.3.0-2 [253 kB] 35s dpkg-preconfigure: unable to re-open stdin: No such file or directory 35s Fetched 10.0 MB in 1s (17.2 MB/s) 36s (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 ... 78444 files and directories currently installed.) 36s Preparing to unpack .../00-python3.13_3.13.9-1_amd64.deb ... 36s Unpacking python3.13 (3.13.9-1) over (3.13.7-1) ... 36s Preparing to unpack .../01-python3.13-minimal_3.13.9-1_amd64.deb ... 36s Unpacking python3.13-minimal (3.13.9-1) over (3.13.7-1) ... 36s Preparing to unpack .../02-libpython3.13_3.13.9-1_amd64.deb ... 36s Unpacking libpython3.13:amd64 (3.13.9-1) over (3.13.7-1) ... 36s Preparing to unpack .../03-libpython3.13-stdlib_3.13.9-1_amd64.deb ... 36s Unpacking libpython3.13-stdlib:amd64 (3.13.9-1) over (3.13.7-1) ... 36s Preparing to unpack .../04-libpython3.13-minimal_3.13.9-1_amd64.deb ... 36s Unpacking libpython3.13-minimal:amd64 (3.13.9-1) over (3.13.7-1) ... 36s Preparing to unpack .../05-libjson-c5_0.18+ds-1.1_amd64.deb ... 36s Unpacking libjson-c5:amd64 (0.18+ds-1.1) over (0.18+ds-1) ... 36s Preparing to unpack .../06-libxml2-16_2.14.5+dfsg-0.2build1_amd64.deb ... 36s Unpacking libxml2-16:amd64 (2.14.5+dfsg-0.2build1) over (2.14.5+dfsg-0.2) ... 36s Preparing to unpack .../07-python3-dbus_1.4.0-1build1_amd64.deb ... 36s Unpacking python3-dbus (1.4.0-1build1) over (1.4.0-1) ... 36s Preparing to unpack .../08-python3.13-gdbm_3.13.9-1_amd64.deb ... 36s Unpacking python3.13-gdbm (3.13.9-1) over (3.13.7-1) ... 36s Preparing to unpack .../09-libbrotli1_1.1.0-2build6_amd64.deb ... 36s Unpacking libbrotli1:amd64 (1.1.0-2build6) over (1.1.0-2build5) ... 36s Preparing to unpack .../10-python3-inflect_7.5.0-1_all.deb ... 36s Unpacking python3-inflect (7.5.0-1) over (7.3.1-2) ... 36s Preparing to unpack .../11-python3-markupsafe_2.1.5-1build5_amd64.deb ... 36s Unpacking python3-markupsafe (2.1.5-1build5) over (2.1.5-1build4) ... 36s Preparing to unpack .../12-python3-oauthlib_3.3.1-1_all.deb ... 36s Unpacking python3-oauthlib (3.3.1-1) over (3.2.2-3) ... 36s Preparing to unpack .../13-python3-zipp_3.23.0-1_all.deb ... 37s Unpacking python3-zipp (3.23.0-1) over (3.21.0-1) ... 37s Preparing to unpack .../14-python3-bcrypt_4.3.0-2_amd64.deb ... 37s Unpacking python3-bcrypt (4.3.0-2) over (4.2.0-2.1build1) ... 37s Setting up python3-dbus (1.4.0-1build1) ... 37s Setting up libxml2-16:amd64 (2.14.5+dfsg-0.2build1) ... 37s Setting up python3-bcrypt (4.3.0-2) ... 37s Setting up libbrotli1:amd64 (1.1.0-2build6) ... 37s Setting up python3-zipp (3.23.0-1) ... 37s Setting up python3-markupsafe (2.1.5-1build5) ... 37s Setting up libpython3.13-minimal:amd64 (3.13.9-1) ... 37s Setting up python3-inflect (7.5.0-1) ... 37s Setting up python3-oauthlib (3.3.1-1) ... 37s Setting up python3.13-minimal (3.13.9-1) ... 37s Setting up libpython3.13-stdlib:amd64 (3.13.9-1) ... 38s Setting up libjson-c5:amd64 (0.18+ds-1.1) ... 38s Setting up python3.13-gdbm (3.13.9-1) ... 38s Setting up libpython3.13:amd64 (3.13.9-1) ... 38s Setting up python3.13 (3.13.9-1) ... 38s Processing triggers for systemd (257.9-0ubuntu2) ... 38s Processing triggers for man-db (2.13.1-1) ... 38s Processing triggers for libc-bin (2.42-0ubuntu3) ... 39s autopkgtest [08:43:33]: upgrading testbed (apt dist-upgrade and autopurge) 39s Reading package lists... 39s Building dependency tree... 39s Reading state information... 39s Calculating upgrade... 39s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 39s Reading package lists... 39s Building dependency tree... 39s Reading state information... 39s Solving dependencies... 39s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 42s autopkgtest [08:43:36]: testbed running kernel: Linux 6.17.0-5-generic #5-Ubuntu SMP PREEMPT_DYNAMIC Mon Sep 22 10:00:33 UTC 2025 42s autopkgtest [08:43:36]: @@@@@@@@@@@@@@@@@@@@ apt-source knot-resolver 44s Get:1 http://ftpmaster.internal/ubuntu resolute/universe knot-resolver 5.7.5-1 (dsc) [3178 B] 44s Get:2 http://ftpmaster.internal/ubuntu resolute/universe knot-resolver 5.7.5-1 (tar) [1925 kB] 44s Get:3 http://ftpmaster.internal/ubuntu resolute/universe knot-resolver 5.7.5-1 (asc) [833 B] 44s Get:4 http://ftpmaster.internal/ubuntu resolute/universe knot-resolver 5.7.5-1 (diff) [402 kB] 44s gpgv: Signature made Thu Apr 24 17:32:48 2025 UTC 44s gpgv: using RSA key 23EBCF7E8FC47556787100DFA4254072E373042C 44s gpgv: Can't check signature: No public key 44s dpkg-source: warning: cannot verify inline signature for ./knot-resolver_5.7.5-1.dsc: no acceptable signature found 44s autopkgtest [08:43:38]: testing package knot-resolver version 5.7.5-1 45s autopkgtest [08:43:39]: build not needed 46s autopkgtest [08:43:40]: test roundtrip: preparing testbed 46s Reading package lists... 46s Building dependency tree... 46s Reading state information... 46s Solving dependencies... 46s The following NEW packages will be installed: 46s dns-root-data gnutls-bin knot-dnsutils knot-resolver libdnssec9t64 46s libevent-2.1-7t64 libfstrm0 libgnutls-dane0t64 libknot15 libluajit-5.1-2 46s libluajit-5.1-common libngtcp2-16 libngtcp2-crypto-gnutls8 libprotobuf-c1 46s libunbound8 libxdp1 libzscanner4t64 lua-sec lua-socket socat 46s 0 upgraded, 20 newly installed, 0 to remove and 0 not upgraded. 46s Need to get 2815 kB of archives. 46s After this operation, 10.1 MB of additional disk space will be used. 46s Get:1 http://ftpmaster.internal/ubuntu resolute/main amd64 dns-root-data all 2025080400 [5908 B] 46s Get:2 http://ftpmaster.internal/ubuntu resolute/main amd64 libevent-2.1-7t64 amd64 2.1.12-stable-10build1 [155 kB] 46s Get:3 http://ftpmaster.internal/ubuntu resolute/main amd64 libunbound8 amd64 1.22.0-2ubuntu2 [468 kB] 46s Get:4 http://ftpmaster.internal/ubuntu resolute/main amd64 libgnutls-dane0t64 amd64 3.8.9-3ubuntu2 [24.8 kB] 46s Get:5 http://ftpmaster.internal/ubuntu resolute/universe amd64 gnutls-bin amd64 3.8.9-3ubuntu2 [278 kB] 46s Get:6 http://ftpmaster.internal/ubuntu resolute/universe amd64 libdnssec9t64 amd64 3.4.6-2 [31.0 kB] 46s Get:7 http://ftpmaster.internal/ubuntu resolute/universe amd64 libngtcp2-16 amd64 1.11.0-1 [147 kB] 46s Get:8 http://ftpmaster.internal/ubuntu resolute/universe amd64 libngtcp2-crypto-gnutls8 amd64 1.11.0-1 [17.9 kB] 46s Get:9 http://ftpmaster.internal/ubuntu resolute/main amd64 libxdp1 amd64 1.5.6-1 [62.0 kB] 46s Get:10 http://ftpmaster.internal/ubuntu resolute/universe amd64 libknot15 amd64 3.4.6-2 [112 kB] 46s Get:11 http://ftpmaster.internal/ubuntu resolute/universe amd64 libzscanner4t64 amd64 3.4.6-2 [142 kB] 46s Get:12 http://ftpmaster.internal/ubuntu resolute/universe amd64 libfstrm0 amd64 0.6.1-1build4 [21.0 kB] 46s Get:13 http://ftpmaster.internal/ubuntu resolute/main amd64 libprotobuf-c1 amd64 1.5.1-1ubuntu1 [23.2 kB] 46s Get:14 http://ftpmaster.internal/ubuntu resolute/universe amd64 knot-dnsutils amd64 3.4.6-2 [123 kB] 46s Get:15 http://ftpmaster.internal/ubuntu resolute/universe amd64 lua-socket amd64 3.1.0-2 [81.0 kB] 47s Get:16 http://ftpmaster.internal/ubuntu resolute/universe amd64 lua-sec amd64 1.3.2-3 [37.3 kB] 47s Get:17 http://ftpmaster.internal/ubuntu resolute/universe amd64 libluajit-5.1-common all 2.1.0+openresty20250117-2ubuntu1 [54.6 kB] 47s Get:18 http://ftpmaster.internal/ubuntu resolute/universe amd64 libluajit-5.1-2 amd64 2.1.0+openresty20250117-2ubuntu1 [299 kB] 47s Get:19 http://ftpmaster.internal/ubuntu resolute/universe amd64 knot-resolver amd64 5.7.5-1 [339 kB] 47s Get:20 http://ftpmaster.internal/ubuntu resolute/main amd64 socat amd64 1.8.0.3-1build1 [394 kB] 47s Preconfiguring packages ... 47s Fetched 2815 kB in 1s (4485 kB/s) 47s Selecting previously unselected package dns-root-data. 47s (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 ... 78458 files and directories currently installed.) 47s Preparing to unpack .../00-dns-root-data_2025080400_all.deb ... 47s Unpacking dns-root-data (2025080400) ... 47s Selecting previously unselected package libevent-2.1-7t64:amd64. 47s Preparing to unpack .../01-libevent-2.1-7t64_2.1.12-stable-10build1_amd64.deb ... 47s Unpacking libevent-2.1-7t64:amd64 (2.1.12-stable-10build1) ... 47s Selecting previously unselected package libunbound8:amd64. 47s Preparing to unpack .../02-libunbound8_1.22.0-2ubuntu2_amd64.deb ... 47s Unpacking libunbound8:amd64 (1.22.0-2ubuntu2) ... 47s Selecting previously unselected package libgnutls-dane0t64:amd64. 47s Preparing to unpack .../03-libgnutls-dane0t64_3.8.9-3ubuntu2_amd64.deb ... 47s Unpacking libgnutls-dane0t64:amd64 (3.8.9-3ubuntu2) ... 47s Selecting previously unselected package gnutls-bin. 47s Preparing to unpack .../04-gnutls-bin_3.8.9-3ubuntu2_amd64.deb ... 47s Unpacking gnutls-bin (3.8.9-3ubuntu2) ... 47s Selecting previously unselected package libdnssec9t64. 47s Preparing to unpack .../05-libdnssec9t64_3.4.6-2_amd64.deb ... 47s Unpacking libdnssec9t64 (3.4.6-2) ... 47s Selecting previously unselected package libngtcp2-16:amd64. 47s Preparing to unpack .../06-libngtcp2-16_1.11.0-1_amd64.deb ... 47s Unpacking libngtcp2-16:amd64 (1.11.0-1) ... 47s Selecting previously unselected package libngtcp2-crypto-gnutls8:amd64. 47s Preparing to unpack .../07-libngtcp2-crypto-gnutls8_1.11.0-1_amd64.deb ... 47s Unpacking libngtcp2-crypto-gnutls8:amd64 (1.11.0-1) ... 47s Selecting previously unselected package libxdp1:amd64. 47s Preparing to unpack .../08-libxdp1_1.5.6-1_amd64.deb ... 47s Unpacking libxdp1:amd64 (1.5.6-1) ... 47s Selecting previously unselected package libknot15. 47s Preparing to unpack .../09-libknot15_3.4.6-2_amd64.deb ... 47s Unpacking libknot15 (3.4.6-2) ... 47s Selecting previously unselected package libzscanner4t64. 47s Preparing to unpack .../10-libzscanner4t64_3.4.6-2_amd64.deb ... 47s Unpacking libzscanner4t64 (3.4.6-2) ... 47s Selecting previously unselected package libfstrm0:amd64. 47s Preparing to unpack .../11-libfstrm0_0.6.1-1build4_amd64.deb ... 47s Unpacking libfstrm0:amd64 (0.6.1-1build4) ... 47s Selecting previously unselected package libprotobuf-c1:amd64. 47s Preparing to unpack .../12-libprotobuf-c1_1.5.1-1ubuntu1_amd64.deb ... 47s Unpacking libprotobuf-c1:amd64 (1.5.1-1ubuntu1) ... 47s Selecting previously unselected package knot-dnsutils. 47s Preparing to unpack .../13-knot-dnsutils_3.4.6-2_amd64.deb ... 47s Unpacking knot-dnsutils (3.4.6-2) ... 47s Selecting previously unselected package lua-socket:amd64. 47s Preparing to unpack .../14-lua-socket_3.1.0-2_amd64.deb ... 47s Unpacking lua-socket:amd64 (3.1.0-2) ... 47s Selecting previously unselected package lua-sec:amd64. 47s Preparing to unpack .../15-lua-sec_1.3.2-3_amd64.deb ... 47s Unpacking lua-sec:amd64 (1.3.2-3) ... 47s Selecting previously unselected package libluajit-5.1-common. 47s Preparing to unpack .../16-libluajit-5.1-common_2.1.0+openresty20250117-2ubuntu1_all.deb ... 47s Unpacking libluajit-5.1-common (2.1.0+openresty20250117-2ubuntu1) ... 47s Selecting previously unselected package libluajit-5.1-2:amd64. 47s Preparing to unpack .../17-libluajit-5.1-2_2.1.0+openresty20250117-2ubuntu1_amd64.deb ... 47s Unpacking libluajit-5.1-2:amd64 (2.1.0+openresty20250117-2ubuntu1) ... 47s Selecting previously unselected package knot-resolver. 47s Preparing to unpack .../18-knot-resolver_5.7.5-1_amd64.deb ... 47s Unpacking knot-resolver (5.7.5-1) ... 47s Selecting previously unselected package socat. 47s Preparing to unpack .../19-socat_1.8.0.3-1build1_amd64.deb ... 47s Unpacking socat (1.8.0.3-1build1) ... 47s Setting up libzscanner4t64 (3.4.6-2) ... 47s Setting up libfstrm0:amd64 (0.6.1-1build4) ... 47s Setting up libevent-2.1-7t64:amd64 (2.1.12-stable-10build1) ... 47s Setting up lua-socket:amd64 (3.1.0-2) ... 47s Setting up libprotobuf-c1:amd64 (1.5.1-1ubuntu1) ... 47s Setting up dns-root-data (2025080400) ... 47s Setting up libxdp1:amd64 (1.5.6-1) ... 47s Setting up libunbound8:amd64 (1.22.0-2ubuntu2) ... 47s Setting up libgnutls-dane0t64:amd64 (3.8.9-3ubuntu2) ... 47s Setting up socat (1.8.0.3-1build1) ... 47s Setting up libdnssec9t64 (3.4.6-2) ... 47s Setting up libluajit-5.1-common (2.1.0+openresty20250117-2ubuntu1) ... 47s Setting up libngtcp2-16:amd64 (1.11.0-1) ... 47s Setting up libngtcp2-crypto-gnutls8:amd64 (1.11.0-1) ... 47s Setting up gnutls-bin (3.8.9-3ubuntu2) ... 47s Setting up lua-sec:amd64 (1.3.2-3) ... 47s Setting up libknot15 (3.4.6-2) ... 47s Setting up libluajit-5.1-2:amd64 (2.1.0+openresty20250117-2ubuntu1) ... 47s Setting up knot-resolver (5.7.5-1) ... 47s Created symlink '/etc/systemd/system/kresd.target.wants/kres-cache-gc.service' → '/usr/lib/systemd/system/kres-cache-gc.service'. 47s Created symlink '/etc/systemd/system/multi-user.target.wants/kresd.target' → '/usr/lib/systemd/system/kresd.target'. 48s Setting up knot-dnsutils (3.4.6-2) ... 48s Processing triggers for man-db (2.13.1-1) ... 48s Processing triggers for libc-bin (2.42-0ubuntu3) ... 49s autopkgtest [08:43:43]: test roundtrip: [----------------------- 49s /usr/sbin/kresd + /usr/bin/kdig roundtrip tests 49s ------------ 49s workdir: /tmp/autopkgtest.WQN86S/roundtrip-artifacts 49s IP addr: 127.181.196.194 49s kresd args: --addr=127.181.196.194@8053 --tls=127.181.196.194@8853 --noninteractive --config=/tmp/autopkgtest.WQN86S/roundtrip-artifacts/kresd.conf --verbose --verbose --verbose 49s 49s make Certificate Authority key and certificate 49s ---------------------------------------------- 49s Generating a 3072 bit RSA private key... 49s Generating a self signed certificate... 49s X.509 Certificate Information: 49s Version: 3 49s Serial Number (hex): 28ceb5d39e6bce36e3dca291b9f872d79d176c99 49s Validity: 49s Not Before: Tue Oct 21 08:43:43 UTC 2025 49s Not After: Sun Nov 02 08:43:43 UTC 2025 49s Subject: CN=testing certificate authority (NOT FOR PRODUCTION) 49s Subject Public Key Algorithm: RSA 49s Algorithm Security Level: High (3072 bits) 49s Modulus (bits 3072): 49s 00:ad:e1:e2:38:3b:d9:96:81:25:76:28:db:66:1d:5d 49s 2c:f4:a2:5e:04:35:16:03:0f:59:ef:7d:83:0f:9f:32 49s 02:5e:a0:5a:fd:90:a7:e1:b7:64:2d:2a:59:d1:cc:76 49s fb:a9:ea:21:7c:cd:3c:f1:50:b6:16:0c:13:e6:8c:70 49s c5:54:60:95:26:57:a6:49:a7:6a:89:99:0e:0f:0b:94 49s bd:7f:7e:1e:79:88:f1:f4:49:79:93:9a:4e:3c:87:ba 49s b1:cf:a9:a4:34:c4:1f:c1:b9:1d:1a:c1:6c:63:1e:9c 49s 99:d5:c9:b2:e6:17:02:fe:47:dd:e8:48:12:1d:9a:93 49s 48:7a:db:e2:ec:69:53:85:bd:f8:90:00:be:82:b7:82 49s ba:f4:92:e9:ac:bc:79:66:c8:47:4e:61:41:07:7a:23 49s ce:a2:ce:e8:13:29:9a:5c:df:26:67:cf:6f:aa:e1:8a 49s e2:b8:07:ba:c1:10:77:18:e0:a5:27:b8:17:91:95:3f 49s 91:54:1a:f5:51:24:16:8f:21:b7:ad:0d:35:b6:d0:d0 49s 3d:93:81:49:70:f6:02:04:b7:3d:e3:68:a0:c4:f9:25 49s c2:b8:1d:4a:89:33:ea:65:41:ac:2a:06:36:d8:7c:12 49s f4:36:4e:00:9d:ff:53:b0:25:65:13:db:d1:72:f9:b8 49s 34:14:6f:fd:bd:d5:44:63:21:09:36:16:f5:14:c8:4f 49s 82:69:2f:f7:bc:07:15:30:20:de:40:9b:95:06:b0:cc 49s 67:17:a9:7d:9e:25:c2:fe:01:6f:e8:e3:d6:bc:94:82 49s c8:41:73:57:0a:7e:4f:18:89:70:15:eb:9c:e7:3d:78 49s 16:be:38:31:1e:59:4b:4e:54:34:e6:5b:1b:3e:48:de 49s 8d:e5:43:f4:aa:61:08:3b:22:fd:c7:77:7a:18:ae:07 49s 8b:c3:ac:2e:a9:6d:49:8f:91:d5:5f:88:cf:fd:15:17 49s 09:ef:96:d2:48:a2:04:83:19:96:a6:9b:e1:85:2a:0a 49s 57 49s Exponent (bits 24): 49s 01:00:01 49s Extensions: 49s Basic Constraints (critical): 49s Certificate Authority (CA): TRUE 49s Path Length Constraint: 1 49s Name Constraints (critical): 49s Permitted: 49s DNSname: example 49s Key Usage (critical): 49s Certificate signing. 49s Subject Key Identifier (not critical): 49s b6338e258acc6951a00e629031edc8ce76cc27b4 49s Other Information: 49s Public Key ID: 49s sha1:b6338e258acc6951a00e629031edc8ce76cc27b4 49s sha256:7587eb1af8d7b98888ad5832bf9d2cd17e48411b210d68a3dbdff3bb0bb1b656 49s Public Key PIN: 49s pin-sha256:dYfrGvjXuYiIrVgyv50s0X5IQRshDWij29/zuwuxtlY= 49s 49s 49s 49s Signing certificate... 49s 49s make Bogus Certificate Authority key and certificate 49s ---------------------------------------------------- 49s Generating a 3072 bit RSA private key... 49s Generating a self signed certificate... 49s X.509 Certificate Information: 49s Version: 3 49s Serial Number (hex): 1b73dc13390a4bef63162a797078e69d65a5ce77 49s Validity: 49s Not Before: Tue Oct 21 08:43:43 UTC 2025 49s Not After: Sun Nov 02 08:43:43 UTC 2025 49s Subject: CN=testing certificate authority (NOT FOR PRODUCTION) 49s Subject Public Key Algorithm: RSA 49s Algorithm Security Level: High (3072 bits) 49s Modulus (bits 3072): 49s 00:d4:30:6c:e1:1c:2e:fa:ed:a4:22:c6:b9:5f:72:50 49s da:54:8e:2a:fd:33:89:6b:cb:cc:f9:f2:fb:e6:89:25 49s bf:49:3e:68:58:3c:9e:21:ed:90:05:17:98:dd:5a:19 49s ea:96:35:a7:ff:e3:df:ae:8b:3b:56:28:da:97:7c:14 49s f2:6f:9a:d6:c6:7e:1d:a2:3e:a1:3c:d2:c5:ac:00:76 49s 74:86:7c:ad:f0:cb:4a:6b:b4:b0:4f:81:66:f6:78:db 49s e8:0f:60:49:74:5c:42:1a:8a:50:45:ee:b3:67:e1:f5 49s c2:22:83:75:0e:22:5d:66:ee:c2:74:f8:d1:39:4a:25 49s 0a:c8:f8:96:04:cf:98:9d:a7:fd:2e:a1:ef:d8:cb:c1 49s 7a:18:3f:9e:a5:51:c6:f1:68:32:65:a8:0b:ce:83:56 49s 36:92:c3:16:a1:c5:c9:42:f1:de:2d:d8:0c:b7:3c:b6 49s d8:a1:fa:97:fc:e9:59:36:9e:17:23:f8:d5:3b:74:b3 49s 2a:9a:d0:43:ff:83:c4:55:67:41:de:f2:83:74:10:b6 49s ed:73:67:fe:4e:1c:dd:38:8a:83:5c:b7:09:4f:41:0d 49s 7d:78:4b:53:84:a1:d9:79:f2:28:78:81:bf:c2:2e:ea 49s f7:87:d7:c9:36:42:96:c3:a6:19:5a:67:5e:31:93:d9 49s ec:cd:62:d6:97:67:cf:cd:46:1b:a0:24:7f:de:f8:c8 49s a5:b1:e0:f6:e4:77:f4:ee:01:a1:3c:bd:81:4b:8d:33 49s 96:1f:64:b7:9b:6a:79:b4:8c:f9:be:dc:5c:75:1f:6b 49s 80:a2:b1:19:2c:15:d2:9f:86:f0:2f:f8:92:39:be:2d 49s 89:cd:02:4e:0a:a3:67:c0:e3:55:cd:16:42:58:2e:e6 49s 57:be:cc:54:27:18:80:4b:e7:33:57:c7:39:98:f0:53 49s 10:85:53:41:ad:82:9d:7c:31:50:6f:a1:76:49:1a:c6 49s bc:e3:bc:10:63:a6:83:40:11:e0:c6:49:78:55:91:a5 49s 87 49s Exponent (bits 24): 49s 01:00:01 49s Extensions: 49s Basic Constraints (critical): 49s Certificate Authority (CA): TRUE 49s Path Length Constraint: 1 49s Name Constraints (critical): 49s Permitted: 49s DNSname: example 49s Key Usage (critical): 49s Certificate signing. 49s Subject Key Identifier (not critical): 49s d545c304653403ec5f7c7560928e62bfb1de57aa 49s Other Information: 49s Public Key ID: 49s sha1:d545c304653403ec5f7c7560928e62bfb1de57aa 49s sha256:fa7beebf4714d83b3661ed422df8c61fe0ba29e14145b47521b5a166e6452c0b 49s Public Key PIN: 49s pin-sha256:+nvuv0cU2Ds2Ye1CLfjGH+C6KeFBRbR1IbWhZuZFLAs= 49s 49s 49s 49s Signing certificate... 49s 49s make End Entity key and certificate 49s ----------------------------------- 49s Generating a 3072 bit RSA private key... 49s Generating a signed certificate... 49s X.509 Certificate Information: 49s Version: 3 49s Serial Number (hex): 770bf914fef00235c1621666c05f5fa7ec1f839b 49s Validity: 49s Not Before: Tue Oct 21 08:43:43 UTC 2025 49s Not After: Fri Oct 31 08:43:43 UTC 2025 49s Subject: CN=test.example 49s Subject Public Key Algorithm: RSA 49s Algorithm Security Level: High (3072 bits) 49s Modulus (bits 3072): 49s 00:b1:eb:6e:9f:2a:7e:6b:cd:d2:7d:51:ef:f5:1e:4b 49s fa:c5:a7:c2:62:ae:f9:7f:48:0d:bb:97:c3:7e:9a:0e 49s 9a:77:58:9f:7a:f0:55:57:e3:01:12:0e:f5:5a:de:b6 49s 9d:9b:27:66:65:e6:31:de:48:96:e3:dc:29:33:ab:0e 49s da:2e:d6:b7:fa:af:21:6f:1a:43:7c:f8:41:d9:7a:9b 49s fe:40:a8:e6:df:c3:31:fe:b0:92:70:0d:06:20:30:e8 49s f5:6e:1a:59:50:a2:1d:3b:56:50:d5:19:f7:4d:19:e0 49s 80:35:5e:32:79:11:93:55:7e:ec:5e:bb:b8:c9:27:8b 49s 24:39:6b:fa:59:9c:e4:59:50:df:6b:5a:72:65:f3:d3 49s 45:0c:a7:02:c7:d7:3b:1b:db:4a:5b:07:7d:68:94:2b 49s 17:76:04:80:08:0a:d3:48:c0:db:e2:d8:e6:52:89:70 49s 11:dc:ad:c8:77:8d:8c:5e:b0:17:64:b5:fe:a4:6d:d5 49s 25:45:bc:36:5c:58:cc:3c:41:8a:41:f3:a5:a3:3d:0e 49s fb:d7:41:b0:8d:fe:31:47:f9:54:7a:4b:f2:2c:52:c3 49s 55:ea:ec:5d:cb:ae:7e:35:8c:80:b0:53:c7:7a:76:ad 49s 9e:89:1c:e5:2c:07:bc:36:40:b5:cf:2f:e7:46:a2:9c 49s a9:d8:28:4f:18:db:5c:a8:18:48:b1:90:a2:e2:c2:a3 49s 1f:52:95:54:f4:19:07:99:e1:d7:d4:d2:71:7c:64:f6 49s fb:99:c6:12:86:8c:4c:bd:2e:79:09:1a:35:2e:0b:46 49s 67:82:4c:6c:6f:f7:63:6e:68:a6:89:d1:7e:32:20:d7 49s b8:ee:60:c4:41:3b:53:97:61:c1:27:46:ae:16:42:52 49s 78:6d:bb:78:9d:58:5d:6a:1a:02:fa:24:49:07:c0:13 49s 51:24:16:fa:bf:45:04:5d:17:da:23:d1:c5:e4:38:4c 49s 50:07:f1:1e:80:ba:56:c7:87:04:1e:9a:08:f4:07:b6 49s 03 49s Exponent (bits 24): 49s 01:00:01 49s Extensions: 49s Basic Constraints (critical): 49s Certificate Authority (CA): FALSE 49s Subject Alternative Name (not critical): 49s DNSname: test.example 49s Key Purpose (not critical): 49s TLS WWW Server. 49s Key Usage (critical): 49s Digital signature. 49s Subject Key Identifier (not critical): 49s 892fe96771658c5a636ee53db7ba5ba279771520 49s Authority Key Identifier (not critical): 49s b6338e258acc6951a00e629031edc8ce76cc27b4 49s Other Information: 49s Public Key ID: 49s sha1:892fe96771658c5a636ee53db7ba5ba279771520 49s sha256:8a4c8da02085c745cf384bd6ff3dd29669da94368da535d8c5e27fb78c953140 49s Public Key PIN: 49s pin-sha256:ikyNoCCFx0XPOEvW/z3SlmnalDaNpTXYxeJ/t4yVMUA= 49s 49s 49s 49s Signing certificate... 49s 49s set up kresd daemon on 127.181.196.194 on ports 8053 (UDP, TCP) and 8853 (TLS) 49s ------------------------------------------------------------------------------ 50s 50s test UDP with kdig 51s ------------------ 51s successful UDP request to 127.181.196.194 on port 8053 51s 51s test TCP with kdig 51s ------------------ 51s successful TCP request to 127.181.196.194 on port 8053 51s 51s test opportunistic DNS-over-TLS with kdig 51s ----------------------------------------- 51s successful opportunistic DNS-over-TLS request to 127.181.196.194 on port 8853 51s 51s test strict DNS-over-TLS with kdig 51s ---------------------------------- 51s successful strict DNS-over-TLS request to 127.181.196.194 on port 8853 51s 51s test invalid name with strict DNS-over-TLS with kdig 51s ---------------------------------------------------- 51s successful strict DNS-over-TLS request failure when name mismatch to 127.181.196.194 on port 8853 51s 51s test bad authority with strict DNS-over-TLS with kdig 51s ----------------------------------------------------- 51s successful strict DNS-over-TLS request failure to 127.181.196.194 on port 8853 51s 51s cleaning up 51s ----------- 51s 254857 4 drwxr-xr-x 2 root root 4096 Oct 21 08:43 /tmp/autopkgtest.WQN86S/roundtrip-artifacts 51s 257853 68 -rw-r--r-- 1 root root 69595 Oct 21 08:43 /tmp/autopkgtest.WQN86S/roundtrip-artifacts/kresd.err 51s 257859 4 -rw-r--r-- 1 root root 121 Oct 21 08:43 /tmp/autopkgtest.WQN86S/roundtrip-artifacts/badname.err 51s 254872 4 -rw-r--r-- 1 root root 1602 Oct 21 08:43 /tmp/autopkgtest.WQN86S/roundtrip-artifacts/ee-cert.pem 51s 257855 4 -rw-r----- 1 root root 8192 Oct 21 08:43 /tmp/autopkgtest.WQN86S/roundtrip-artifacts/lock.mdb 51s 254868 4 -rw-r--r-- 1 root root 1590 Oct 21 08:43 /tmp/autopkgtest.WQN86S/roundtrip-artifacts/bogus-cert.pem 51s 257861 4 -rw-r--r-- 1 root root 121 Oct 21 08:43 /tmp/autopkgtest.WQN86S/roundtrip-artifacts/badca.err 51s 254866 4 -rw-r--r-- 1 root root 1590 Oct 21 08:43 /tmp/autopkgtest.WQN86S/roundtrip-artifacts/ca-cert.pem 51s 257650 4 -rw-r--r-- 1 root root 387 Oct 21 08:43 /tmp/autopkgtest.WQN86S/roundtrip-artifacts/kresd.conf 51s 254870 8 -rw------- 1 root root 8170 Oct 21 08:43 /tmp/autopkgtest.WQN86S/roundtrip-artifacts/ee-key.pem 51s 254864 4 -rw-r--r-- 1 root root 136 Oct 21 08:43 /tmp/autopkgtest.WQN86S/roundtrip-artifacts/ca.template 51s 257857 102400 -rw-r----- 1 root root 104857600 Oct 21 08:43 /tmp/autopkgtest.WQN86S/roundtrip-artifacts/data.mdb 51s 254867 8 -rw------- 1 root root 8170 Oct 21 08:43 /tmp/autopkgtest.WQN86S/roundtrip-artifacts/bogus-key.pem 51s 254869 4 -rw-r--r-- 1 root root 92 Oct 21 08:43 /tmp/autopkgtest.WQN86S/roundtrip-artifacts/ee.template 51s 254865 8 -rw------- 1 root root 8177 Oct 21 08:43 /tmp/autopkgtest.WQN86S/roundtrip-artifacts/ca-key.pem 51s 254871 4 -rw-r--r-- 1 root root 2218 Oct 21 08:43 /tmp/autopkgtest.WQN86S/roundtrip-artifacts/ee-pubkey.pem 51s ==> /tmp/autopkgtest.WQN86S/roundtrip-artifacts/badca.err <== 51s ;; WARNING: TLS, handshake failed (Error in the certificate.) 51s ;; ERROR: failed to query server 127.181.196.194@8853(TCP) 51s 51s ==> /tmp/autopkgtest.WQN86S/roundtrip-artifacts/badname.err <== 51s ;; WARNING: TLS, handshake failed (Error in the certificate.) 51s ;; ERROR: failed to query server 127.181.196.194@8853(TCP) 51s 51s ==> /tmp/autopkgtest.WQN86S/roundtrip-artifacts/kresd.err <== 51s [system] increasing file-descriptor limit: 1024 -> 524288 51s [tls ] session ticket: epoch 429940, scheduling rotation check in 2112029 ms 51s [wtchdg] disabled in systemd (WatchdogSec= not specified) 51s [ta ] installed trust anchors for domain . are: 51s . 3600 DNSKEY 257 3 8 AwEAAaz/tAm8yTn4Mfeh5eyI96WSVexTBAvkMgJzkKTOiW1vkIbzxeF3+/4RgWOq7HrxRixHlFlExOLAJr5emLvN7SWXgnLh4+B5xQlNVz8Og8kvArMtNROxVQuCaSnIDdD5LKyWbRd2n9WGe2R8PzgCmr3EgVLrjyBxWezF0jLHwVN8efS3rCj/EWgvIWgb9tarpVUDK/b58Da+sqqls3eNbuv7pr+eoZG+SrDK6nWeL3c6H5Apxz7LjVc1uTIdsIXxuOLYA4/ilBmSVIzuDWfdRUfhHdY6+cn8HFRm+2hM8AnXGXws9555KrUB5qihylGa8subX2Nn6UwNR1AkUTV74bU= ; Valid: ; KeyTag:20326 51s . 3600 DNSKEY 257 3 8 AwEAAa96jeuknZlaeSrvyAJj6ZHv28hhOKkx3rLGXVaC6rXTsDc449/cidltpkyGwCJNnOAlFNKF2jBosZBU5eeHspaQWOmOElZsjICMQMC3aeHbGiShvZsx4wMYSjH8e7Vrhbu6irwCzVBApESjbUdpWWmEnhathWu1jo+siFUiRAAxm9qyJNg/wOZqqzL/dL/q8PkcRU5oUKEpUge71M3ej2/7CPqpdVwuMoTvoB+ZOT4YeGyxMvHmbrxlFzGOHOijtzN+u1TQNatX2XBuzZNQ1K+s2CXkPIZo7s6JgZyvaBevYtxPvYLw4z9mR7K2vaF18UYH9Z9GNUUeayffKC73PYc= ; Valid: ; KeyTag:38696 51s 51s [system] loading config '/tmp/autopkgtest.WQN86S/roundtrip-artifacts/kresd.conf' (workdir '/tmp/autopkgtest.WQN86S/roundtrip-artifacts') 51s [system] deprecation WARNING: use log_level() instead of verbose() 51s [gnutls] (3) ASSERT: ../../../lib/x509/x509_ext.c[gnutls_subject_alt_names_get]:107 51s [gnutls] (3) ASSERT: ../../../lib/x509/x509.c[get_alt_name]:2012 51s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 51s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 51s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 51s [tls ] RFC 7858 OOB key-pin (0): pin-sha256="" 51s [gnutls] (3) ASSERT: ../../lib/cert-cred-x509.c[gnutls_certificate_get_x509_crt]:872 51s [system] loading config '/usr/lib/x86_64-linux-gnu/knot-resolver/postconfig.lua' (workdir '/tmp/autopkgtest.WQN86S/roundtrip-artifacts') 51s [plan ][00000.00] plan '.' type 'NS' uid [65536.00] 51s [iterat][65536.00] '.' type 'NS' new uid was assigned .01, parent uid .00 51s [resolv][65536.01] => using root hints 51s [iterat][65536.01] '.' type 'NS' new uid was assigned .02, parent uid .00 51s [resolv][65536.02] >< TA: '.' 51s [plan ][65536.02] plan '.' type 'DNSKEY' uid [65536.03] 51s [iterat][65536.03] '.' type 'DNSKEY' new uid was assigned .04, parent uid .02 51s [select][65536.04] => id: '15318' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 51s [select][65536.04] => id: '15318' choosing: 'F.ROOT-SERVERS.NET.'@'2001:500:2f::f#00053' with timeout 400 ms zone cut: '.' 51s [resolv][65536.04] => id: '15318' querying: 'F.ROOT-SERVERS.NET.'@'2001:500:2f::f#00053' zone cut: '.' qname: '.' qtype: 'DNSKEY' proto: 'udp' 51s [plan ][00000.00] plan '.' type 'NS' uid [65537.00] 51s [iterat][65537.00] '.' type 'NS' new uid was assigned .01, parent uid .00 51s [resolv][65537.01] => using root hints 51s [iterat][65537.01] '.' type 'NS' new uid was assigned .02, parent uid .00 51s [select][65537.02] => id: '21642' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 51s [select][65537.02] => id: '21642' choosing: 'G.ROOT-SERVERS.NET.'@'192.112.36.4#00053' with timeout 400 ms zone cut: '.' 51s [resolv][65537.02] => id: '21642' querying: 'G.ROOT-SERVERS.NET.'@'192.112.36.4#00053' zone cut: '.' qname: '.' qtype: 'NS' proto: 'udp' 51s [taupd ] refreshing TA for . 51s [plan ][00000.00] plan '.' type 'DNSKEY' uid [65538.00] 51s [iterat][65538.00] '.' type 'DNSKEY' new uid was assigned .01, parent uid .00 51s [resolv][65538.01] => using root hints 51s [iterat][65538.01] '.' type 'DNSKEY' new uid was assigned .02, parent uid .00 51s [resolv][65538.02] >< TA: '.' 51s [select][65538.02] => id: '49118' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 51s [select][65538.02] => id: '49118' choosing: 'C.ROOT-SERVERS.NET.'@'192.33.4.12#00053' with timeout 400 ms zone cut: '.' 51s [select][65536.04] NO6: timed out, appended, timeouts 1/6 51s [select][65536.04] => id: '15318' noting selection error: 'F.ROOT-SERVERS.NET.'@'2001:500:2f::f#00053' zone cut: '.' error: 1 QUERY_TIMEOUT 51s [iterat][65538.02] '.' type 'DNSKEY' new uid was assigned .03, parent uid .00 51s [select][65538.03] => id: '24500' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 51s [select][65538.03] => id: '24500' choosing: 'C.ROOT-SERVERS.NET.'@'192.33.4.12#00053' with timeout 400 ms zone cut: '.' 51s [resolv][65538.03] => id: '24500' querying: 'C.ROOT-SERVERS.NET.'@'192.33.4.12#00053' zone cut: '.' qname: '.' qtype: 'DNSKEY' proto: 'udp' 51s [iterat][65536.04] '.' type 'DNSKEY' new uid was assigned .05, parent uid .02 51s [select][65536.05] => id: '15334' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 51s [select][65536.05] => id: '15334' choosing: 'C.ROOT-SERVERS.NET.'@'192.33.4.12#00053' with timeout 800 ms zone cut: '.' 51s [select][65537.02] => id: '21642' noting selection error: 'G.ROOT-SERVERS.NET.'@'192.112.36.4#00053' zone cut: '.' error: 1 QUERY_TIMEOUT 51s [iterat][65537.02] '.' type 'NS' new uid was assigned .03, parent uid .00 51s [select][65537.03] => id: '61918' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 51s [select][65537.03] => id: '61918' choosing: 'C.ROOT-SERVERS.NET.'@'2001:500:2::c#00053' with timeout 800 ms zone cut: '.' 51s [resolv][65537.03] => id: '61918' querying: 'C.ROOT-SERVERS.NET.'@'2001:500:2::c#00053' zone cut: '.' qname: '.' qtype: 'NS' proto: 'udp' 51s [select][65538.03] => id: '24500' noting selection error: 'C.ROOT-SERVERS.NET.'@'192.33.4.12#00053' zone cut: '.' error: 1 QUERY_TIMEOUT 51s [iterat][65536.05] '.' type 'DNSKEY' new uid was assigned .06, parent uid .02 51s [select][65536.06] => id: '16399' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 51s [select][65536.06] => id: '16399' choosing: 'M.ROOT-SERVERS.NET.'@'202.12.27.33#00053' with timeout 800 ms zone cut: '.' 51s [resolv][65536.06] => id: '16399' querying: 'M.ROOT-SERVERS.NET.'@'202.12.27.33#00053' zone cut: '.' qname: '.' qtype: 'DNSKEY' proto: 'udp' 51s [iterat][65538.03] '.' type 'DNSKEY' new uid was assigned .04, parent uid .00 51s [select][65538.04] => id: '54318' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 51s [select][65538.04] => id: '54318' choosing: 'M.ROOT-SERVERS.NET.'@'202.12.27.33#00053' with timeout 800 ms zone cut: '.' 51s [plan ][00000.00] plan 'monkeys.example.' type 'A' uid [11878.00] 51s [iterat][11878.00] 'monkeys.example.' type 'A' new uid was assigned .01, parent uid .00 51s [hint ][11878.01] <= answered from hints 51s [iterat][11878.01] <= rcode: NOERROR 51s [resolv][11878.01] AD: request NOT classified as SECURE 51s [resolv][11878.01] finished in state: 4, queries: 1, mempool: 16400 B 51s [plan ][00000.00] plan 'monkeys.example.' type 'A' uid [18150.00] 51s [iterat][18150.00] 'monkeys.example.' type 'A' new uid was assigned .01, parent uid .00 51s [hint ][18150.01] <= answered from hints 51s [iterat][18150.01] <= rcode: NOERROR 51s [resolv][18150.01] AD: request NOT classified as SECURE 51s [resolv][18150.01] finished in state: 4, queries: 1, mempool: 81952 B 51s [io ] => connection to '127.0.0.1#32955' closed by peer (end of file) 51s [gnutls] (5) REC[0x7c6ab04f2000]: Allocating epoch #0 51s [gnutls] (2) added 3 protocols, 29 ciphersuites, 19 sig algos and 10 groups into priority list 51s [gnutls] (5) REC[0x7c6ab04f2000]: Allocating epoch #1 51s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 51s [gnutls] (5) REC[0x7c6ab04f2000]: SSL 3.1 Handshake packet received. Epoch 0, length: 278 51s [gnutls] (5) REC[0x7c6ab04f2000]: Expected Packet Handshake(22) 51s [gnutls] (5) REC[0x7c6ab04f2000]: Received Packet Handshake(22) with length: 278 51s [gnutls] (5) REC[0x7c6ab04f2000]: Decrypted Packet[0] Handshake(22) with length: 278 51s [gnutls] (4) HSK[0x7c6ab04f2000]: CLIENT HELLO (1) was received. Length 274[274], frag offset 0, frag length: 274, sequence: 0 51s [gnutls] (4) HSK[0x7c6ab04f2000]: Client's version: 3.3 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Supported Versions/43' (3 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Found version: 3.4 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Negotiated version: 3.4 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Safe Renegotiation/65281' (1 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Encrypt-then-MAC/22' (0 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'ALPN/16' (6 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Extended Master Secret/23' (0 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Record Size Limit/28' (2 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: record_size_limit 16385 negotiated 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Supported Groups/10' (10 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Received group X25519 (0x1d) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Received group SECP256R1 (0x17) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Received group SECP384R1 (0x18) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Received group SECP521R1 (0x19) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Selected group X25519 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Supported EC Point Formats/11' (2 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Session Ticket/35' (0 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'PSK Key Exchange Modes/45' (3 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: PSK KE mode 01 received 51s [gnutls] (4) EXT[0x7c6ab04f2000]: PSK KE mode 00 received 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Signature Algorithms/13' (34 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (4.1) RSA-SHA256 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.9) RSA-PSS-SHA256 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.4) RSA-PSS-RSAE-SHA256 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (4.3) ECDSA-SECP256R1-SHA256 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.7) EdDSA-Ed25519 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (5.1) RSA-SHA384 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.10) RSA-PSS-SHA384 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.5) RSA-PSS-RSAE-SHA384 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (5.3) ECDSA-SECP384R1-SHA384 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.8) EdDSA-Ed448 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (6.1) RSA-SHA512 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.11) RSA-PSS-SHA512 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.6) RSA-PSS-RSAE-SHA512 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (6.3) ECDSA-SECP521R1-SHA512 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (2.1) RSA-SHA1 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (2.3) ECDSA-SHA1 51s [gnutls] (2) checking 13.02 (GNUTLS_AES_256_GCM_SHA384) for compatibility 51s [gnutls] (3) ASSERT: ../../../lib/ext/server_name.c[gnutls_server_name_get]:234 51s [gnutls] (4) HSK[0x7c6ab04f2000]: Requested server name: '' 51s [gnutls] (4) HSK[0x7c6ab04f2000]: checking compat of GNUTLS_AES_256_GCM_SHA384 with certificate[0] (RSA/X.509) 51s [gnutls] (4) checking cert compat with RSA-SHA256 51s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 51s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 51s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 51s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 51s [gnutls] (4) Selected signature algorithm: RSA-PSS-RSAE-SHA256 51s [gnutls] (2) Selected (RSA) cert based on ciphersuite 13.2: GNUTLS_AES_256_GCM_SHA384 51s [gnutls] (4) HSK[0x7c6ab04f2000]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384 51s [gnutls] (4) HSK[0x7c6ab04f2000]: Selected version TLS1.3 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'OCSP Status Request/5' (5 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: OCSP status was requested 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Key Share/51' (107 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Received key share for X25519 51s [gnutls] (4) HSK[0x7c6ab04f2000]: Selected group X25519 (6) 51s [gnutls] (2) EXT[0x7c6ab04f2000]: server generated X25519 shared key 51s [gnutls] (4) HSK[0x7c6ab04f2000]: Safe renegotiation succeeded 51s [gnutls] (4) HSK[0x7c6ab04f2000]: SessionID: 00 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (OCSP Status Request/5) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Client Certificate Type/19) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Server Certificate Type/20) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Supported Groups/10) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Supported EC Point Formats/11) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Signature Algorithms/13) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (SRTP/14) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (ALPN/16) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Encrypt-then-MAC/22) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Extended Master Secret/23) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Session Ticket/35) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Key Share/51) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: sending key share for X25519 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Sending extension Key Share/51 (36 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Supported Versions/43) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Sending extension Supported Versions/43 (2 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Post Handshake Auth/49) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Safe Renegotiation/65281) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Server Name Indication/0) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Cookie/44) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Early Data/42) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (PSK Key Exchange Modes/45) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Record Size Limit/28) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Maximum Record Size/1) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Compress Certificate/27) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (ClientHello Padding/21) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Pre Shared Key/41) for 'TLS 1.3 server hello' 51s [gnutls] (4) HSK[0x7c6ab04f2000]: SERVER HELLO was queued [90 bytes] 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 90 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 95 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6 51s [gnutls] (4) REC[0x7c6ab04f2000]: Sent ChangeCipherSpec 51s [gnutls] (5) REC[0x7c6ab04f2000]: Initializing epoch #1 51s [gnutls] (5) REC[0x7c6ab04f2000]: Epoch #1 ready 51s [gnutls] (4) HSK[0x7c6ab04f2000]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (OCSP Status Request/5) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Client Certificate Type/19) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Server Certificate Type/20) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Supported Groups/10) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Supported EC Point Formats/11) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Signature Algorithms/13) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (SRTP/14) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (ALPN/16) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Sending extension ALPN/16 (6 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Encrypt-then-MAC/22) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Extended Master Secret/23) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Session Ticket/35) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Key Share/51) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Supported Versions/43) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Post Handshake Auth/49) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Safe Renegotiation/65281) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Server Name Indication/0) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Cookie/44) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Early Data/42) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (PSK Key Exchange Modes/45) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Record Size Limit/28) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Sending extension Record Size Limit/28 (2 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Maximum Record Size/1) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Compress Certificate/27) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (ClientHello Padding/21) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Pre Shared Key/41) for 'encrypted extensions' 51s [gnutls] (4) HSK[0x7c6ab04f2000]: ENCRYPTED EXTENSIONS was queued [22 bytes] 51s [gnutls] (4) HSK[0x7c6ab04f2000]: CERTIFICATE was queued [1155 bytes] 51s [gnutls] (4) checking cert compat with RSA-SHA256 51s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 51s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 51s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 51s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 51s [gnutls] (4) HSK[0x7c6ab04f2000]: signing TLS 1.3 handshake data: using RSA-PSS-RSAE-SHA256 and PRF: SHA384 51s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 51s [gnutls] (4) HSK[0x7c6ab04f2000]: CERTIFICATE VERIFY was queued [392 bytes] 51s [gnutls] (4) HSK[0x7c6ab04f2000]: sending finished 51s [gnutls] (4) HSK[0x7c6ab04f2000]: FINISHED was queued [52 bytes] 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 22 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 44 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 1155 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[2] Handshake(22) in epoch 1 and length: 1177 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 392 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[3] Handshake(22) in epoch 1 and length: 414 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 52 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[4] Handshake(22) in epoch 1 and length: 74 51s [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:965 51s [gnutls] (5) REC[0x7c6ab04f2000]: Allocating epoch #2 51s [gnutls] (4) HSK[0x7c6ab04f2000]: unauthenticated session eligible for early start 51s [gnutls] (5) REC[0x7c6ab04f2000]: Initializing epoch #2 51s [gnutls] (5) REC[0x7c6ab04f2000]: Epoch #2 ready 51s [gnutls] (4) HSK[0x7c6ab04f2000]: TLS 1.3 set write key with cipher suite: GNUTLS_AES_256_GCM_SHA384 51s [gnutls] (4) HSK[0x7c6ab04f2000]: switching early to application traffic keys 51s [gnutls] (4) HSK[0x7c6ab04f2000]: NEW SESSION TICKET was queued [251 bytes] 51s [gnutls] (4) HSK[0x7c6ab04f2000]: NEW SESSION TICKET was queued [251 bytes] 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[1] Handshake(22) in epoch 2 and length: 273 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[2] Handshake(22) in epoch 2 and length: 273 51s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 51s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 51s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 51s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 51s [gnutls] (5) REC[0x7c6ab04f2000]: SSL 3.3 Application Data packet received. Epoch 1, length: 69 51s [gnutls] (5) REC[0x7c6ab04f2000]: Expected Packet Handshake(22) 51s [gnutls] (5) REC[0x7c6ab04f2000]: Received Packet Application Data(23) with length: 69 51s [gnutls] (5) REC[0x7c6ab04f2000]: Decrypted Packet[0] Handshake(22) with length: 52 51s [gnutls] (4) HSK[0x7c6ab04f2000]: FINISHED (20) was received. Length 48[48], frag offset 0, frag length: 48, sequence: 0 51s [gnutls] (4) HSK[0x7c6ab04f2000]: parsing finished 51s [gnutls] (4) HSK[0x7c6ab04f2000]: TLS 1.3 set read key with cipher suite: GNUTLS_AES_256_GCM_SHA384 51s [gnutls] (5) REC[0x7c6ab04f2000]: Start of epoch cleanup 51s [gnutls] (5) REC[0x7c6ab04f2000]: Epoch #0 freed 51s [gnutls] (5) REC[0x7c6ab04f2000]: Epoch #1 freed 51s [gnutls] (5) REC[0x7c6ab04f2000]: End of epoch cleanup 51s [tls ] TLS handshake with 127.0.0.1#49449 has completed 51s [gnutls] (5) REC[0x7c6ab04f2000]: SSL 3.3 Application Data packet received. Epoch 2, length: 147 51s [gnutls] (5) REC[0x7c6ab04f2000]: Expected Packet Application Data(23) 51s [gnutls] (5) REC[0x7c6ab04f2000]: Received Packet Application Data(23) with length: 147 51s [gnutls] (5) REC[0x7c6ab04f2000]: Decrypted Packet[0] Application Data(23) with length: 130 51s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 51s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1759 51s [plan ][00000.00] plan 'monkeys.example.' type 'A' uid [45618.00] 51s [iterat][45618.00] 'monkeys.example.' type 'A' new uid was assigned .01, parent uid .00 51s [hint ][45618.01] <= answered from hints 51s [iterat][45618.01] <= rcode: NOERROR 51s [resolv][45618.01] AD: request NOT classified as SECURE 51s [resolv][45618.01] finished in state: 4, queries: 1, mempool: 81952 B 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Application Data(23) with length: 470 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[3] Application Data(23) in epoch 2 and length: 492 51s [gnutls] (5) REC[0x7c6ab04f2000]: SSL 3.3 Application Data packet received. Epoch 2, length: 19 51s [gnutls] (5) REC[0x7c6ab04f2000]: Expected Packet Application Data(23) 51s [gnutls] (5) REC[0x7c6ab04f2000]: Received Packet Application Data(23) with length: 19 51s [gnutls] (5) REC[0x7c6ab04f2000]: Decrypted Packet[1] Alert(21) with length: 2 51s [gnutls] (5) REC[0x7c6ab04f2000]: Alert[1|0] - Close notify - was received 51s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_in_buffers]:1565 51s [io ] => connection to '127.0.0.1#49449' closed by peer (end of file) 51s [gnutls] (5) REC[0x7c6ab04f2000]: Start of epoch cleanup 51s [gnutls] (5) REC[0x7c6ab04f2000]: End of epoch cleanup 51s [gnutls] (5) REC[0x7c6ab04f2000]: Epoch #2 freed 51s [gnutls] (5) REC[0x7c6ab04f2000]: Allocating epoch #0 51s [gnutls] (2) added 3 protocols, 29 ciphersuites, 19 sig algos and 10 groups into priority list 51s [gnutls] (5) REC[0x7c6ab04f2000]: Allocating epoch #1 51s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 51s [gnutls] (5) REC[0x7c6ab04f2000]: SSL 3.1 Handshake packet received. Epoch 0, length: 299 51s [gnutls] (5) REC[0x7c6ab04f2000]: Expected Packet Handshake(22) 51s [gnutls] (5) REC[0x7c6ab04f2000]: Received Packet Handshake(22) with length: 299 51s [gnutls] (5) REC[0x7c6ab04f2000]: Decrypted Packet[0] Handshake(22) with length: 299 51s [gnutls] (4) HSK[0x7c6ab04f2000]: CLIENT HELLO (1) was received. Length 295[295], frag offset 0, frag length: 295, sequence: 0 51s [gnutls] (4) HSK[0x7c6ab04f2000]: Client's version: 3.3 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Supported Versions/43' (3 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Found version: 3.4 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Negotiated version: 3.4 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Extended Master Secret/23' (0 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Server Name Indication/0' (17 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Safe Renegotiation/65281' (1 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Encrypt-then-MAC/22' (0 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'ALPN/16' (6 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Record Size Limit/28' (2 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: record_size_limit 16385 negotiated 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Supported Groups/10' (10 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Received group X25519 (0x1d) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Received group SECP256R1 (0x17) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Received group SECP384R1 (0x18) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Received group SECP521R1 (0x19) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Selected group X25519 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Supported EC Point Formats/11' (2 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Signature Algorithms/13' (34 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (4.1) RSA-SHA256 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.9) RSA-PSS-SHA256 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.4) RSA-PSS-RSAE-SHA256 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (4.3) ECDSA-SECP256R1-SHA256 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.7) EdDSA-Ed25519 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (5.1) RSA-SHA384 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.10) RSA-PSS-SHA384 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.5) RSA-PSS-RSAE-SHA384 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (5.3) ECDSA-SECP384R1-SHA384 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.8) EdDSA-Ed448 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (6.1) RSA-SHA512 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.11) RSA-PSS-SHA512 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.6) RSA-PSS-RSAE-SHA512 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (6.3) ECDSA-SECP521R1-SHA512 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (2.1) RSA-SHA1 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (2.3) ECDSA-SHA1 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'PSK Key Exchange Modes/45' (3 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: PSK KE mode 01 received 51s [gnutls] (4) EXT[0x7c6ab04f2000]: PSK KE mode 00 received 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Session Ticket/35' (0 bytes) 51s [gnutls] (2) checking 13.02 (GNUTLS_AES_256_GCM_SHA384) for compatibility 51s [gnutls] (4) HSK[0x7c6ab04f2000]: Requested server name: 'test.example' 51s [gnutls] (4) checking cert compat with RSA-SHA256 51s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 51s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 51s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 51s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 51s [gnutls] (4) Selected signature algorithm: RSA-PSS-RSAE-SHA256 51s [gnutls] (2) Selected (RSA) cert based on ciphersuite 13.2: GNUTLS_AES_256_GCM_SHA384 51s [gnutls] (4) HSK[0x7c6ab04f2000]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384 51s [gnutls] (4) HSK[0x7c6ab04f2000]: Selected version TLS1.3 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'OCSP Status Request/5' (5 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: OCSP status was requested 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Key Share/51' (107 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Received key share for X25519 51s [gnutls] (4) HSK[0x7c6ab04f2000]: Selected group X25519 (6) 51s [gnutls] (2) EXT[0x7c6ab04f2000]: server generated X25519 shared key 51s [gnutls] (4) HSK[0x7c6ab04f2000]: Safe renegotiation succeeded 51s [gnutls] (4) HSK[0x7c6ab04f2000]: SessionID: 00 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (OCSP Status Request/5) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Client Certificate Type/19) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Server Certificate Type/20) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Supported Groups/10) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Supported EC Point Formats/11) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Signature Algorithms/13) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (SRTP/14) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (ALPN/16) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Encrypt-then-MAC/22) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Extended Master Secret/23) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Session Ticket/35) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Key Share/51) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: sending key share for X25519 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Sending extension Key Share/51 (36 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Supported Versions/43) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Sending extension Supported Versions/43 (2 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Post Handshake Auth/49) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Safe Renegotiation/65281) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Server Name Indication/0) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Cookie/44) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Early Data/42) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (PSK Key Exchange Modes/45) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Record Size Limit/28) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Maximum Record Size/1) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Compress Certificate/27) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (ClientHello Padding/21) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Pre Shared Key/41) for 'TLS 1.3 server hello' 51s [gnutls] (4) HSK[0x7c6ab04f2000]: SERVER HELLO was queued [90 bytes] 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 90 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 95 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6 51s [gnutls] (4) REC[0x7c6ab04f2000]: Sent ChangeCipherSpec 51s [gnutls] (5) REC[0x7c6ab04f2000]: Initializing epoch #1 51s [gnutls] (5) REC[0x7c6ab04f2000]: Epoch #1 ready 51s [gnutls] (4) HSK[0x7c6ab04f2000]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (OCSP Status Request/5) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Client Certificate Type/19) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Server Certificate Type/20) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Supported Groups/10) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Supported EC Point Formats/11) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Signature Algorithms/13) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (SRTP/14) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (ALPN/16) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Sending extension ALPN/16 (6 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Encrypt-then-MAC/22) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Extended Master Secret/23) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Session Ticket/35) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Key Share/51) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Supported Versions/43) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Post Handshake Auth/49) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Safe Renegotiation/65281) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Server Name Indication/0) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Cookie/44) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Early Data/42) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (PSK Key Exchange Modes/45) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Record Size Limit/28) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Sending extension Record Size Limit/28 (2 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Maximum Record Size/1) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Compress Certificate/27) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (ClientHello Padding/21) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Pre Shared Key/41) for 'encrypted extensions' 51s [gnutls] (4) HSK[0x7c6ab04f2000]: ENCRYPTED EXTENSIONS was queued [22 bytes] 51s [gnutls] (4) HSK[0x7c6ab04f2000]: CERTIFICATE was queued [1155 bytes] 51s [gnutls] (4) checking cert compat with RSA-SHA256 51s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 51s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 51s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 51s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 51s [gnutls] (4) HSK[0x7c6ab04f2000]: signing TLS 1.3 handshake data: using RSA-PSS-RSAE-SHA256 and PRF: SHA384 51s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 51s [gnutls] (4) HSK[0x7c6ab04f2000]: CERTIFICATE VERIFY was queued [392 bytes] 51s [gnutls] (4) HSK[0x7c6ab04f2000]: sending finished 51s [gnutls] (4) HSK[0x7c6ab04f2000]: FINISHED was queued [52 bytes] 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 22 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 44 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 1155 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[2] Handshake(22) in epoch 1 and length: 1177 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 392 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[3] Handshake(22) in epoch 1 and length: 414 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 52 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[4] Handshake(22) in epoch 1 and length: 74 51s [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:965 51s [gnutls] (5) REC[0x7c6ab04f2000]: Allocating epoch #2 51s [gnutls] (4) HSK[0x7c6ab04f2000]: unauthenticated session eligible for early start 51s [gnutls] (5) REC[0x7c6ab04f2000]: Initializing epoch #2 51s [gnutls] (5) REC[0x7c6ab04f2000]: Epoch #2 ready 51s [gnutls] (4) HSK[0x7c6ab04f2000]: TLS 1.3 set write key with cipher suite: GNUTLS_AES_256_GCM_SHA384 51s [gnutls] (4) HSK[0x7c6ab04f2000]: switching early to application traffic keys 51s [gnutls] (4) HSK[0x7c6ab04f2000]: NEW SESSION TICKET was queued [251 bytes] 51s [gnutls] (4) HSK[0x7c6ab04f2000]: NEW SESSION TICKET was queued [251 bytes] 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[1] Handshake(22) in epoch 2 and length: 273 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[2] Handshake(22) in epoch 2 and length: 273 51s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 51s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 51s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 51s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 51s [gnutls] (5) REC[0x7c6ab04f2000]: SSL 3.3 Application Data packet received. Epoch 1, length: 69 51s [gnutls] (5) REC[0x7c6ab04f2000]: Expected Packet Handshake(22) 51s [gnutls] (5) REC[0x7c6ab04f2000]: Received Packet Application Data(23) with length: 69 51s [gnutls] (5) REC[0x7c6ab04f2000]: Decrypted Packet[0] Handshake(22) with length: 52 51s [gnutls] (4) HSK[0x7c6ab04f2000]: FINISHED (20) was received. Length 48[48], frag offset 0, frag length: 48, sequence: 0 51s [gnutls] (4) HSK[0x7c6ab04f2000]: parsing finished 51s [gnutls] (4) HSK[0x7c6ab04f2000]: TLS 1.3 set read key with cipher suite: GNUTLS_AES_256_GCM_SHA384 51s [gnutls] (5) REC[0x7c6ab04f2000]: Start of epoch cleanup 51s [gnutls] (5) REC[0x7c6ab04f2000]: Epoch #0 freed 51s [gnutls] (5) REC[0x7c6ab04f2000]: Epoch #1 freed 51s [gnutls] (5) REC[0x7c6ab04f2000]: End of epoch cleanup 51s [tls ] TLS handshake with 127.0.0.1#58473 has completed 51s [gnutls] (5) REC[0x7c6ab04f2000]: SSL 3.3 Application Data packet received. Epoch 2, length: 147 51s [gnutls] (5) REC[0x7c6ab04f2000]: Expected Packet Application Data(23) 51s [gnutls] (5) REC[0x7c6ab04f2000]: Received Packet Application Data(23) with length: 147 51s [gnutls] (5) REC[0x7c6ab04f2000]: Decrypted Packet[0] Application Data(23) with length: 130 51s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 51s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1759 51s [plan ][00000.00] plan 'monkeys.example.' type 'A' uid [57685.00] 51s [iterat][57685.00] 'monkeys.example.' type 'A' new uid was assigned .01, parent uid .00 51s [hint ][57685.01] <= answered from hints 51s [iterat][57685.01] <= rcode: NOERROR 51s [resolv][57685.01] AD: request NOT classified as SECURE 51s [resolv][57685.01] finished in state: 4, queries: 1, mempool: 81952 B 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Application Data(23) with length: 470 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[3] Application Data(23) in epoch 2 and length: 492 51s [gnutls] (5) REC[0x7c6ab04f2000]: SSL 3.3 Application Data packet received. Epoch 2, length: 19 51s [gnutls] (5) REC[0x7c6ab04f2000]: Expected Packet Application Data(23) 51s [gnutls] (5) REC[0x7c6ab04f2000]: Received Packet Application Data(23) with length: 19 51s [gnutls] (5) REC[0x7c6ab04f2000]: Decrypted Packet[1] Alert(21) with length: 2 51s [gnutls] (5) REC[0x7c6ab04f2000]: Alert[1|0] - Close notify - was received 51s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_in_buffers]:1565 51s [io ] => connection to '127.0.0.1#58473' closed by peer (end of file) 51s [gnutls] (5) REC[0x7c6ab04f2000]: Start of epoch cleanup 51s [gnutls] (5) REC[0x7c6ab04f2000]: End of epoch cleanup 51s [gnutls] (5) REC[0x7c6ab04f2000]: Epoch #2 freed 51s [gnutls] (5) REC[0x7c6ab04f2000]: Allocating epoch #0 51s [gnutls] (2) added 3 protocols, 29 ciphersuites, 19 sig algos and 10 groups into priority list 51s [gnutls] (5) REC[0x7c6ab04f2000]: Allocating epoch #1 51s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 51s [gnutls] (5) REC[0x7c6ab04f2000]: SSL 3.1 Handshake packet received. Epoch 0, length: 303 51s [gnutls] (5) REC[0x7c6ab04f2000]: Expected Packet Handshake(22) 51s [gnutls] (5) REC[0x7c6ab04f2000]: Received Packet Handshake(22) with length: 303 51s [gnutls] (5) REC[0x7c6ab04f2000]: Decrypted Packet[0] Handshake(22) with length: 303 51s [gnutls] (4) HSK[0x7c6ab04f2000]: CLIENT HELLO (1) was received. Length 299[299], frag offset 0, frag length: 299, sequence: 0 51s [gnutls] (4) HSK[0x7c6ab04f2000]: Client's version: 3.3 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Supported Versions/43' (3 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Found version: 3.4 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Negotiated version: 3.4 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Extended Master Secret/23' (0 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Encrypt-then-MAC/22' (0 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Safe Renegotiation/65281' (1 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'ALPN/16' (6 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Server Name Indication/0' (21 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Record Size Limit/28' (2 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: record_size_limit 16385 negotiated 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Supported Groups/10' (10 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Received group X25519 (0x1d) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Received group SECP256R1 (0x17) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Received group SECP384R1 (0x18) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Received group SECP521R1 (0x19) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Selected group X25519 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Signature Algorithms/13' (34 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (4.1) RSA-SHA256 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.9) RSA-PSS-SHA256 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.4) RSA-PSS-RSAE-SHA256 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (4.3) ECDSA-SECP256R1-SHA256 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.7) EdDSA-Ed25519 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (5.1) RSA-SHA384 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.10) RSA-PSS-SHA384 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.5) RSA-PSS-RSAE-SHA384 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (5.3) ECDSA-SECP384R1-SHA384 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.8) EdDSA-Ed448 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (6.1) RSA-SHA512 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.11) RSA-PSS-SHA512 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.6) RSA-PSS-RSAE-SHA512 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (6.3) ECDSA-SECP521R1-SHA512 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (2.1) RSA-SHA1 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (2.3) ECDSA-SHA1 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Supported EC Point Formats/11' (2 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Session Ticket/35' (0 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'PSK Key Exchange Modes/45' (3 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: PSK KE mode 01 received 51s [gnutls] (4) EXT[0x7c6ab04f2000]: PSK KE mode 00 received 51s [gnutls] (2) checking 13.02 (GNUTLS_AES_256_GCM_SHA384) for compatibility 51s [gnutls] (4) HSK[0x7c6ab04f2000]: Requested server name: 'notright.example' 51s [gnutls] (4) HSK[0x7c6ab04f2000]: checking compat of GNUTLS_AES_256_GCM_SHA384 with certificate[0] (RSA/X.509) 51s [gnutls] (4) checking cert compat with RSA-SHA256 51s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 51s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 51s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 51s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 51s [gnutls] (4) Selected signature algorithm: RSA-PSS-RSAE-SHA256 51s [gnutls] (2) Selected (RSA) cert based on ciphersuite 13.2: GNUTLS_AES_256_GCM_SHA384 51s [gnutls] (4) HSK[0x7c6ab04f2000]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384 51s [gnutls] (4) HSK[0x7c6ab04f2000]: Selected version TLS1.3 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Key Share/51' (107 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Received key share for X25519 51s [gnutls] (4) HSK[0x7c6ab04f2000]: Selected group X25519 (6) 51s [gnutls] (2) EXT[0x7c6ab04f2000]: server generated X25519 shared key 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'OCSP Status Request/5' (5 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: OCSP status was requested 51s [gnutls] (4) HSK[0x7c6ab04f2000]: Safe renegotiation succeeded 51s [gnutls] (4) HSK[0x7c6ab04f2000]: SessionID: 00 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (OCSP Status Request/5) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Client Certificate Type/19) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Server Certificate Type/20) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Supported Groups/10) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Supported EC Point Formats/11) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Signature Algorithms/13) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (SRTP/14) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (ALPN/16) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Encrypt-then-MAC/22) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Extended Master Secret/23) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Session Ticket/35) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Key Share/51) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: sending key share for X25519 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Sending extension Key Share/51 (36 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Supported Versions/43) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Sending extension Supported Versions/43 (2 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Post Handshake Auth/49) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Safe Renegotiation/65281) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Server Name Indication/0) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Cookie/44) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Early Data/42) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (PSK Key Exchange Modes/45) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Record Size Limit/28) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Maximum Record Size/1) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Compress Certificate/27) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (ClientHello Padding/21) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Pre Shared Key/41) for 'TLS 1.3 server hello' 51s [gnutls] (4) HSK[0x7c6ab04f2000]: SERVER HELLO was queued [90 bytes] 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 90 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 95 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6 51s [gnutls] (4) REC[0x7c6ab04f2000]: Sent ChangeCipherSpec 51s [gnutls] (5) REC[0x7c6ab04f2000]: Initializing epoch #1 51s [gnutls] (5) REC[0x7c6ab04f2000]: Epoch #1 ready 51s [gnutls] (4) HSK[0x7c6ab04f2000]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (OCSP Status Request/5) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Client Certificate Type/19) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Server Certificate Type/20) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Supported Groups/10) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Supported EC Point Formats/11) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Signature Algorithms/13) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (SRTP/14) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (ALPN/16) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Sending extension ALPN/16 (6 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Encrypt-then-MAC/22) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Extended Master Secret/23) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Session Ticket/35) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Key Share/51) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Supported Versions/43) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Post Handshake Auth/49) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Safe Renegotiation/65281) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Server Name Indication/0) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Cookie/44) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Early Data/42) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (PSK Key Exchange Modes/45) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Record Size Limit/28) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Sending extension Record Size Limit/28 (2 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Maximum Record Size/1) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Compress Certificate/27) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (ClientHello Padding/21) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Pre Shared Key/41) for 'encrypted extensions' 51s [gnutls] (4) HSK[0x7c6ab04f2000]: ENCRYPTED EXTENSIONS was queued [22 bytes] 51s [gnutls] (4) HSK[0x7c6ab04f2000]: CERTIFICATE was queued [1155 bytes] 51s [gnutls] (4) checking cert compat with RSA-SHA256 51s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 51s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 51s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 51s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 51s [gnutls] (4) HSK[0x7c6ab04f2000]: signing TLS 1.3 handshake data: using RSA-PSS-RSAE-SHA256 and PRF: SHA384 51s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 51s [gnutls] (4) HSK[0x7c6ab04f2000]: CERTIFICATE VERIFY was queued [392 bytes] 51s [gnutls] (4) HSK[0x7c6ab04f2000]: sending finished 51s [gnutls] (4) HSK[0x7c6ab04f2000]: FINISHED was queued [52 bytes] 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 22 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 44 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 1155 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[2] Handshake(22) in epoch 1 and length: 1177 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 392 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[3] Handshake(22) in epoch 1 and length: 414 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 52 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[4] Handshake(22) in epoch 1 and length: 74 51s [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:965 51s [gnutls] (5) REC[0x7c6ab04f2000]: Allocating epoch #2 51s [gnutls] (4) HSK[0x7c6ab04f2000]: unauthenticated session eligible for early start 51s [gnutls] (5) REC[0x7c6ab04f2000]: Initializing epoch #2 51s [gnutls] (5) REC[0x7c6ab04f2000]: Epoch #2 ready 51s [gnutls] (4) HSK[0x7c6ab04f2000]: TLS 1.3 set write key with cipher suite: GNUTLS_AES_256_GCM_SHA384 51s [gnutls] (4) HSK[0x7c6ab04f2000]: switching early to application traffic keys 51s [gnutls] (4) HSK[0x7c6ab04f2000]: NEW SESSION TICKET was queued [251 bytes] 51s [gnutls] (4) HSK[0x7c6ab04f2000]: NEW SESSION TICKET was queued [251 bytes] 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[1] Handshake(22) in epoch 2 and length: 273 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[2] Handshake(22) in epoch 2 and length: 273 51s [tls ] uv_try_write error: connection reset by peer 51s [gnutls] (2) WRITE: -1 returned from 0x7c6ab04e7900, errno: 5 51s [gnutls] (3) ASSERT: ../../lib/buffers.c[errno_to_gerr]:218 51s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_write_flush]:693 51s [gnutls] (3) ASSERT: ../../lib/handshake-tls13.c[_gnutls13_handshake_server]:536 51s [tls ] gnutls_handshake failed: GNUTLS_E_PUSH_ERROR (-53) 51s [gnutls] (5) REC: Sending Alert[2|80] - Internal error 51s [tls ] uv_try_write error: broken pipe 51s [gnutls] (2) WRITE: -1 returned from 0x7c6ab04e7900, errno: 5 51s [gnutls] (3) ASSERT: ../../lib/buffers.c[errno_to_gerr]:218 51s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_write_flush]:693 51s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_send_tlen_int]:586 51s [io ] => connection to '127.0.0.1#41843': error processing TLS data, close 51s [gnutls] (5) REC[0x7c6ab04f2000]: Start of epoch cleanup 51s [gnutls] (5) REC[0x7c6ab04f2000]: Epoch #0 freed 51s [gnutls] (5) REC[0x7c6ab04f2000]: End of epoch cleanup 51s [gnutls] (5) REC[0x7c6ab04f2000]: Epoch #1 freed 51s [gnutls] (5) REC[0x7c6ab04f2000]: Epoch #2 freed 51s [gnutls] (5) REC[0x7c6ab04f2000]: Allocating epoch #0 51s [gnutls] (2) added 3 protocols, 29 ciphersuites, 19 sig algos and 10 groups into priority list 51s [gnutls] (5) REC[0x7c6ab04f2000]: Allocating epoch #1 51s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 51s [gnutls] (5) REC[0x7c6ab04f2000]: SSL 3.1 Handshake packet received. Epoch 0, length: 299 51s [gnutls] (5) REC[0x7c6ab04f2000]: Expected Packet Handshake(22) 51s [gnutls] (5) REC[0x7c6ab04f2000]: Received Packet Handshake(22) with length: 299 51s [gnutls] (5) REC[0x7c6ab04f2000]: Decrypted Packet[0] Handshake(22) with length: 299 51s [gnutls] (4) HSK[0x7c6ab04f2000]: CLIENT HELLO (1) was received. Length 295[295], frag offset 0, frag length: 295, sequence: 0 51s [gnutls] (4) HSK[0x7c6ab04f2000]: Client's version: 3.3 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Supported Versions/43' (3 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Found version: 3.4 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Negotiated version: 3.4 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Server Name Indication/0' (17 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'ALPN/16' (6 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Encrypt-then-MAC/22' (0 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Extended Master Secret/23' (0 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Record Size Limit/28' (2 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: record_size_limit 16385 negotiated 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Safe Renegotiation/65281' (1 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Supported EC Point Formats/11' (2 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'PSK Key Exchange Modes/45' (3 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: PSK KE mode 01 received 51s [gnutls] (4) EXT[0x7c6ab04f2000]: PSK KE mode 00 received 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Signature Algorithms/13' (34 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (4.1) RSA-SHA256 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.9) RSA-PSS-SHA256 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.4) RSA-PSS-RSAE-SHA256 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (4.3) ECDSA-SECP256R1-SHA256 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.7) EdDSA-Ed25519 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (5.1) RSA-SHA384 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.10) RSA-PSS-SHA384 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.5) RSA-PSS-RSAE-SHA384 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (5.3) ECDSA-SECP384R1-SHA384 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.8) EdDSA-Ed448 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (6.1) RSA-SHA512 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.11) RSA-PSS-SHA512 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (8.6) RSA-PSS-RSAE-SHA512 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (6.3) ECDSA-SECP521R1-SHA512 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (2.1) RSA-SHA1 51s [gnutls] (4) EXT[0x7c6ab04f2000]: rcvd signature algo (2.3) ECDSA-SHA1 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Session Ticket/35' (0 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Supported Groups/10' (10 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Received group X25519 (0x1d) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Received group SECP256R1 (0x17) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Received group SECP384R1 (0x18) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Received group SECP521R1 (0x19) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Selected group X25519 51s [gnutls] (2) checking 13.02 (GNUTLS_AES_256_GCM_SHA384) for compatibility 51s [gnutls] (4) HSK[0x7c6ab04f2000]: Requested server name: 'test.example' 51s [gnutls] (4) checking cert compat with RSA-SHA256 51s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 51s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 51s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 51s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 51s [gnutls] (4) Selected signature algorithm: RSA-PSS-RSAE-SHA256 51s [gnutls] (2) Selected (RSA) cert based on ciphersuite 13.2: GNUTLS_AES_256_GCM_SHA384 51s [gnutls] (4) HSK[0x7c6ab04f2000]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384 51s [gnutls] (4) HSK[0x7c6ab04f2000]: Selected version TLS1.3 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'OCSP Status Request/5' (5 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: OCSP status was requested 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Parsing extension 'Key Share/51' (107 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Received key share for X25519 51s [gnutls] (4) HSK[0x7c6ab04f2000]: Selected group X25519 (6) 51s [gnutls] (2) EXT[0x7c6ab04f2000]: server generated X25519 shared key 51s [gnutls] (4) HSK[0x7c6ab04f2000]: Safe renegotiation succeeded 51s [gnutls] (4) HSK[0x7c6ab04f2000]: SessionID: 00 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (OCSP Status Request/5) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Client Certificate Type/19) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Server Certificate Type/20) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Supported Groups/10) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Supported EC Point Formats/11) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Signature Algorithms/13) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (SRTP/14) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (ALPN/16) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Encrypt-then-MAC/22) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Extended Master Secret/23) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Session Ticket/35) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Key Share/51) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: sending key share for X25519 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Sending extension Key Share/51 (36 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Supported Versions/43) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Sending extension Supported Versions/43 (2 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Post Handshake Auth/49) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Safe Renegotiation/65281) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Server Name Indication/0) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Cookie/44) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Early Data/42) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (PSK Key Exchange Modes/45) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Record Size Limit/28) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Maximum Record Size/1) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Compress Certificate/27) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (ClientHello Padding/21) for 'TLS 1.3 server hello' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Pre Shared Key/41) for 'TLS 1.3 server hello' 51s [gnutls] (4) HSK[0x7c6ab04f2000]: SERVER HELLO was queued [90 bytes] 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 90 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 95 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6 51s [gnutls] (4) REC[0x7c6ab04f2000]: Sent ChangeCipherSpec 51s [gnutls] (5) REC[0x7c6ab04f2000]: Initializing epoch #1 51s [gnutls] (5) REC[0x7c6ab04f2000]: Epoch #1 ready 51s [gnutls] (4) HSK[0x7c6ab04f2000]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (OCSP Status Request/5) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Client Certificate Type/19) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Server Certificate Type/20) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Supported Groups/10) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Supported EC Point Formats/11) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Signature Algorithms/13) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (SRTP/14) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (ALPN/16) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Sending extension ALPN/16 (6 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Encrypt-then-MAC/22) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Extended Master Secret/23) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Session Ticket/35) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Key Share/51) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Supported Versions/43) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Post Handshake Auth/49) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Safe Renegotiation/65281) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Server Name Indication/0) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Cookie/44) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Early Data/42) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (PSK Key Exchange Modes/45) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Record Size Limit/28) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Sending extension Record Size Limit/28 (2 bytes) 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Preparing extension (Maximum Record Size/1) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Compress Certificate/27) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (ClientHello Padding/21) for 'encrypted extensions' 51s [gnutls] (4) EXT[0x7c6ab04f2000]: Not sending extension (Pre Shared Key/41) for 'encrypted extensions' 51s [gnutls] (4) HSK[0x7c6ab04f2000]: ENCRYPTED EXTENSIONS was queued [22 bytes] 51s [gnutls] (4) HSK[0x7c6ab04f2000]: CERTIFICATE was queued [1155 bytes] 51s [gnutls] (4) checking cert compat with RSA-SHA256 51s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 51s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 51s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 51s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 51s [gnutls] (4) HSK[0x7c6ab04f2000]: signing TLS 1.3 handshake data: using RSA-PSS-RSAE-SHA256 and PRF: SHA384 51s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 51s [gnutls] (4) HSK[0x7c6ab04f2000]: CERTIFICATE VERIFY was queued [392 bytes] 51s [gnutls] (4) HSK[0x7c6ab04f2000]: sending finished 51s [gnutls] (4) HSK[0x7c6ab04f2000]: FINISHED was queued [52 bytes] 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 22 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 44 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 1155 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[2] Handshake(22) in epoch 1 and length: 1177 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 392 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[3] Handshake(22) in epoch 1 and length: 414 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 52 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[4] Handshake(22) in epoch 1 and length: 74 51s [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:965 51s [gnutls] (5) REC[0x7c6ab04f2000]: Allocating epoch #2 51s [gnutls] (4) HSK[0x7c6ab04f2000]: unauthenticated session eligible for early start 51s [gnutls] (5) REC[0x7c6ab04f2000]: Initializing epoch #2 51s [gnutls] (5) REC[0x7c6ab04f2000]: Epoch #2 ready 51s [gnutls] (4) HSK[0x7c6ab04f2000]: TLS 1.3 set write key with cipher suite: GNUTLS_AES_256_GCM_SHA384 51s [gnutls] (4) HSK[0x7c6ab04f2000]: switching early to application traffic keys 51s [gnutls] (4) HSK[0x7c6ab04f2000]: NEW SESSION TICKET was queued [251 bytes] 51s [gnutls] (4) HSK[0x7c6ab04f2000]: NEW SESSION TICKET was queued [251 bytes] 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[1] Handshake(22) in epoch 2 and length: 273 51s [gnutls] (5) REC[0x7c6ab04f2000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 51s [gnutls] (5) REC[0x7c6ab04f2000]: Sent Packet[2] Handshake(22) in epoch 2 and length: 273 51s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 51s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 51s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 51s [io ] => connection to '127.0.0.1#43413' closed by peer (connection reset by peer) 51s [gnutls] (5) REC[0x7c6ab04f2000]: Start of epoch cleanup 51s [gnutls] (5) REC[0x7c6ab04f2000]: Epoch #0 freed 51s [gnutls] (5) REC[0x7c6ab04f2000]: End of epoch cleanup 51s [gnutls] (5) REC[0x7c6ab04f2000]: Epoch #1 freed 51s [gnutls] (5) REC[0x7c6ab04f2000]: Epoch #2 freed 51s > 51s > autopkgtest [08:43:45]: test roundtrip: -----------------------] 51s autopkgtest [08:43:45]: test roundtrip: - - - - - - - - - - results - - - - - - - - - - 51s roundtrip PASS 56s autopkgtest [08:43:50]: @@@@@@@@@@@@@@@@@@@@ summary 56s roundtrip PASS