0s autopkgtest [07:27:21]: starting date and time: 2025-05-03 07:27:21+0000 0s autopkgtest [07:27:21]: git checkout: 9986aa8c Merge branch 'skia/fix_network_interface' into 'ubuntu/production' 0s autopkgtest [07:27:21]: host juju-7f2275-prod-proposed-migration-environment-9; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.3vbdsecp/out --timeout-copy=6000 --setup-commands 'ln -s /dev/null /etc/systemd/system/bluetooth.service; printf "http_proxy=http://squid.internal:3128\nhttps_proxy=http://squid.internal:3128\nno_proxy=127.0.0.1,127.0.1.1,localhost,localdomain,internal,login.ubuntu.com,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,keyserver.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com,radosgw.ps5.canonical.com\n" >> /etc/environment' --apt-pocket=proposed=src:twitter-bootstrap3 --apt-upgrade knot-resolver --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=twitter-bootstrap3/3.4.1+dfsg-4 -- lxd -r lxd-armhf-10.145.243.239 lxd-armhf-10.145.243.239:autopkgtest/ubuntu/questing/armhf 19s autopkgtest [07:27:40]: testbed dpkg architecture: armhf 21s autopkgtest [07:27:42]: testbed apt version: 3.0.0 25s autopkgtest [07:27:46]: @@@@@@@@@@@@@@@@@@@@ test bed setup 26s autopkgtest [07:27:47]: testbed release detected to be: None 34s autopkgtest [07:27:55]: updating testbed package index (apt update) 35s Get:1 http://ftpmaster.internal/ubuntu questing-proposed InRelease [110 kB] 36s Get:2 http://ftpmaster.internal/ubuntu questing InRelease [110 kB] 36s Get:3 http://ftpmaster.internal/ubuntu questing-updates InRelease [110 kB] 36s Get:4 http://ftpmaster.internal/ubuntu questing-security InRelease [110 kB] 36s Get:5 http://ftpmaster.internal/ubuntu questing-proposed/multiverse Sources [43.3 kB] 36s Get:6 http://ftpmaster.internal/ubuntu questing-proposed/main Sources [156 kB] 36s Get:7 http://ftpmaster.internal/ubuntu questing-proposed/universe Sources [1722 kB] 36s Get:8 http://ftpmaster.internal/ubuntu questing-proposed/main armhf Packages [172 kB] 36s Get:9 http://ftpmaster.internal/ubuntu questing-proposed/universe armhf Packages [1271 kB] 36s Get:10 http://ftpmaster.internal/ubuntu questing-proposed/multiverse armhf Packages [12.2 kB] 36s Get:11 http://ftpmaster.internal/ubuntu questing/main Sources [1387 kB] 36s Get:12 http://ftpmaster.internal/ubuntu questing/universe Sources [21.2 MB] 37s Get:13 http://ftpmaster.internal/ubuntu questing/multiverse Sources [299 kB] 37s Get:14 http://ftpmaster.internal/ubuntu questing/main armhf Packages [1358 kB] 37s Get:15 http://ftpmaster.internal/ubuntu questing/universe armhf Packages [15.3 MB] 37s Get:16 http://ftpmaster.internal/ubuntu questing/multiverse armhf Packages [173 kB] 41s Fetched 43.5 MB in 5s (8438 kB/s) 42s Reading package lists... 47s autopkgtest [07:28:08]: upgrading testbed (apt dist-upgrade and autopurge) 49s Reading package lists... 49s Building dependency tree... 49s Reading state information... 50s Calculating upgrade...Starting pkgProblemResolver with broken count: 0 50s Starting 2 pkgProblemResolver with broken count: 0 50s Done 50s Entering ResolveByKeep 51s 51s Calculating upgrade... 51s The following packages will be upgraded: 51s base-files debianutils distro-info-data dpkg dpkg-dev ed fwupd htop 51s libdpkg-perl libftdi1-2 libfwupd3 libnftnl11 libnpth0t64 libnvme1t64 51s libsensors-config libsensors5 liburcu8t64 motd-news-config nano 51s ubuntu-pro-client ubuntu-pro-client-l10n usb.ids 51s 22 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 51s Need to get 5576 kB of archives. 51s After this operation, 3534 kB disk space will be freed. 51s Get:1 http://ftpmaster.internal/ubuntu questing/main armhf motd-news-config all 13.7ubuntu1 [5260 B] 52s Get:2 http://ftpmaster.internal/ubuntu questing/main armhf base-files armhf 13.7ubuntu1 [75.4 kB] 52s Get:3 http://ftpmaster.internal/ubuntu questing/main armhf debianutils armhf 5.22 [92.2 kB] 52s Get:4 http://ftpmaster.internal/ubuntu questing/main armhf dpkg armhf 1.22.18ubuntu3 [1254 kB] 52s Get:5 http://ftpmaster.internal/ubuntu questing/main armhf libnpth0t64 armhf 1.8-3 [7716 B] 52s Get:6 http://ftpmaster.internal/ubuntu questing/main armhf distro-info-data all 0.64 [6664 B] 52s Get:7 http://ftpmaster.internal/ubuntu questing/main armhf ubuntu-pro-client-l10n armhf 35.1ubuntu0 [19.7 kB] 52s Get:8 http://ftpmaster.internal/ubuntu questing/main armhf ubuntu-pro-client armhf 35.1ubuntu0 [258 kB] 52s Get:9 http://ftpmaster.internal/ubuntu questing/main armhf ed armhf 1.21.1-1 [53.0 kB] 52s Get:10 http://ftpmaster.internal/ubuntu questing/main armhf libnftnl11 armhf 1.2.9-1 [53.3 kB] 52s Get:11 http://ftpmaster.internal/ubuntu questing/main armhf libsensors-config all 1:3.6.2-2 [6756 B] 52s Get:12 http://ftpmaster.internal/ubuntu questing/main armhf libsensors5 armhf 1:3.6.2-2 [26.8 kB] 52s Get:13 http://ftpmaster.internal/ubuntu questing/main armhf liburcu8t64 armhf 0.15.2-2 [57.3 kB] 52s Get:14 http://ftpmaster.internal/ubuntu questing/main armhf nano armhf 8.4-1 [278 kB] 52s Get:15 http://ftpmaster.internal/ubuntu questing/main armhf usb.ids all 2025.04.01-1 [223 kB] 52s Get:16 http://ftpmaster.internal/ubuntu questing/main armhf dpkg-dev all 1.22.18ubuntu3 [1089 kB] 52s Get:17 http://ftpmaster.internal/ubuntu questing/main armhf libdpkg-perl all 1.22.18ubuntu3 [281 kB] 52s Get:18 http://ftpmaster.internal/ubuntu questing/main armhf fwupd armhf 2.0.8-3 [1414 kB] 52s Get:19 http://ftpmaster.internal/ubuntu questing/main armhf libfwupd3 armhf 2.0.8-3 [126 kB] 52s Get:20 http://ftpmaster.internal/ubuntu questing/main armhf htop armhf 3.4.1-4 [147 kB] 52s Get:21 http://ftpmaster.internal/ubuntu questing/main armhf libftdi1-2 armhf 1.5-10 [27.8 kB] 52s Get:22 http://ftpmaster.internal/ubuntu questing/main armhf libnvme1t64 armhf 1.13-2 [74.3 kB] 53s Fetched 5576 kB in 1s (6393 kB/s) 53s (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 ... 63953 files and directories currently installed.) 53s Preparing to unpack .../motd-news-config_13.7ubuntu1_all.deb ... 53s Unpacking motd-news-config (13.7ubuntu1) over (13.6ubuntu2) ... 53s Preparing to unpack .../base-files_13.7ubuntu1_armhf.deb ... 53s Unpacking base-files (13.7ubuntu1) over (13.6ubuntu2) ... 53s Setting up base-files (13.7ubuntu1) ... 53s Installing new version of config file /etc/issue ... 53s Installing new version of config file /etc/issue.net ... 53s Installing new version of config file /etc/lsb-release ... 54s motd-news.service is a disabled or a static unit not running, not starting it. 54s (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 ... 63953 files and directories currently installed.) 54s Preparing to unpack .../debianutils_5.22_armhf.deb ... 54s Unpacking debianutils (5.22) over (5.21) ... 54s Setting up debianutils (5.22) ... 54s (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 ... 63953 files and directories currently installed.) 54s Preparing to unpack .../dpkg_1.22.18ubuntu3_armhf.deb ... 54s Unpacking dpkg (1.22.18ubuntu3) over (1.22.18ubuntu2) ... 54s Setting up dpkg (1.22.18ubuntu3) ... 54s (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 ... 63953 files and directories currently installed.) 54s Preparing to unpack .../libnpth0t64_1.8-3_armhf.deb ... 54s Unpacking libnpth0t64:armhf (1.8-3) over (1.8-2) ... 54s Setting up libnpth0t64:armhf (1.8-3) ... 54s (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 ... 63953 files and directories currently installed.) 54s Preparing to unpack .../00-distro-info-data_0.64_all.deb ... 54s Unpacking distro-info-data (0.64) over (0.63) ... 54s Preparing to unpack .../01-ubuntu-pro-client-l10n_35.1ubuntu0_armhf.deb ... 54s Unpacking ubuntu-pro-client-l10n (35.1ubuntu0) over (35) ... 54s Preparing to unpack .../02-ubuntu-pro-client_35.1ubuntu0_armhf.deb ... 55s Unpacking ubuntu-pro-client (35.1ubuntu0) over (35) ... 55s Preparing to unpack .../03-ed_1.21.1-1_armhf.deb ... 55s Unpacking ed (1.21.1-1) over (1.21-1) ... 55s Preparing to unpack .../04-libnftnl11_1.2.9-1_armhf.deb ... 55s Unpacking libnftnl11:armhf (1.2.9-1) over (1.2.8-1) ... 55s Preparing to unpack .../05-libsensors-config_1%3a3.6.2-2_all.deb ... 55s Unpacking libsensors-config (1:3.6.2-2) over (1:3.6.0-10) ... 55s Preparing to unpack .../06-libsensors5_1%3a3.6.2-2_armhf.deb ... 55s Unpacking libsensors5:armhf (1:3.6.2-2) over (1:3.6.0-10) ... 55s Preparing to unpack .../07-liburcu8t64_0.15.2-2_armhf.deb ... 55s Unpacking liburcu8t64:armhf (0.15.2-2) over (0.15.1-1) ... 55s Preparing to unpack .../08-nano_8.4-1_armhf.deb ... 55s Unpacking nano (8.4-1) over (8.3-1) ... 55s Preparing to unpack .../09-usb.ids_2025.04.01-1_all.deb ... 55s Unpacking usb.ids (2025.04.01-1) over (2025.01.14-1) ... 55s Preparing to unpack .../10-dpkg-dev_1.22.18ubuntu3_all.deb ... 55s Unpacking dpkg-dev (1.22.18ubuntu3) over (1.22.18ubuntu2) ... 55s Preparing to unpack .../11-libdpkg-perl_1.22.18ubuntu3_all.deb ... 55s Unpacking libdpkg-perl (1.22.18ubuntu3) over (1.22.18ubuntu2) ... 55s Preparing to unpack .../12-fwupd_2.0.8-3_armhf.deb ... 55s Unpacking fwupd (2.0.8-3) over (2.0.7-1) ... 55s dpkg: warning: unable to delete old directory '/etc/grub.d': Directory not empty 55s Preparing to unpack .../13-libfwupd3_2.0.8-3_armhf.deb ... 55s Unpacking libfwupd3:armhf (2.0.8-3) over (2.0.7-1) ... 55s Preparing to unpack .../14-htop_3.4.1-4_armhf.deb ... 55s Unpacking htop (3.4.1-4) over (3.4.0-2) ... 56s Preparing to unpack .../15-libftdi1-2_1.5-10_armhf.deb ... 56s Unpacking libftdi1-2:armhf (1.5-10) over (1.5-8build1) ... 56s Preparing to unpack .../16-libnvme1t64_1.13-2_armhf.deb ... 56s Unpacking libnvme1t64 (1.13-2) over (1.11.1-2) ... 56s Setting up motd-news-config (13.7ubuntu1) ... 56s Setting up liburcu8t64:armhf (0.15.2-2) ... 56s Setting up distro-info-data (0.64) ... 56s Setting up htop (3.4.1-4) ... 56s Setting up libsensors-config (1:3.6.2-2) ... 56s Installing new version of config file /etc/sensors3.conf ... 56s Setting up libnftnl11:armhf (1.2.9-1) ... 56s Setting up libfwupd3:armhf (2.0.8-3) ... 56s Setting up libftdi1-2:armhf (1.5-10) ... 56s Setting up libnvme1t64 (1.13-2) ... 56s Setting up ed (1.21.1-1) ... 56s Setting up usb.ids (2025.04.01-1) ... 56s Setting up libsensors5:armhf (1:3.6.2-2) ... 56s Setting up libdpkg-perl (1.22.18ubuntu3) ... 56s Setting up nano (8.4-1) ... 56s Installing new version of config file /etc/nanorc ... 56s Setting up ubuntu-pro-client (35.1ubuntu0) ... 56s apparmor_parser: Unable to replace "ubuntu_pro_apt_news". apparmor_parser: Access denied. You need policy admin privileges to manage profiles. 56s 56s apparmor_parser: Unable to replace "apt_methods". apparmor_parser: Access denied. You need policy admin privileges to manage profiles. 56s 56s apparmor_parser: Unable to replace "ubuntu_pro_esm_cache". apparmor_parser: Access denied. You need policy admin privileges to manage profiles. 56s 57s Setting up fwupd (2.0.8-3) ... 58s fwupd-refresh.service is a disabled or a static unit not running, not starting it. 58s fwupd.service is a disabled or a static unit not running, not starting it. 58s Setting up ubuntu-pro-client-l10n (35.1ubuntu0) ... 58s Setting up dpkg-dev (1.22.18ubuntu3) ... 58s Processing triggers for dbus (1.16.2-2ubuntu1) ... 58s Processing triggers for install-info (7.1.1-1) ... 58s Processing triggers for libc-bin (2.41-6ubuntu1) ... 58s Processing triggers for man-db (2.13.0-1) ... 60s Processing triggers for plymouth-theme-ubuntu-text (24.004.60-2ubuntu7) ... 60s Processing triggers for initramfs-tools (0.147ubuntu1) ... 62s Reading package lists... 62s Building dependency tree... 62s Reading state information... 63s Starting pkgProblemResolver with broken count: 0 63s Starting 2 pkgProblemResolver with broken count: 0 63s Done 63s Solving dependencies... 64s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 66s autopkgtest [07:28:27]: rebooting testbed after setup commands that affected boot 105s autopkgtest [07:29:06]: testbed running kernel: Linux 6.8.0-58-generic #60~22.04.1-Ubuntu SMP PREEMPT_DYNAMIC Fri Mar 28 14:48:37 UTC 2 130s autopkgtest [07:29:31]: @@@@@@@@@@@@@@@@@@@@ apt-source knot-resolver 147s Get:1 http://ftpmaster.internal/ubuntu questing/universe knot-resolver 5.7.4-2build1 (dsc) [3202 B] 147s Get:2 http://ftpmaster.internal/ubuntu questing/universe knot-resolver 5.7.4-2build1 (tar) [1931 kB] 147s Get:3 http://ftpmaster.internal/ubuntu questing/universe knot-resolver 5.7.4-2build1 (asc) [833 B] 147s Get:4 http://ftpmaster.internal/ubuntu questing/universe knot-resolver 5.7.4-2build1 (diff) [402 kB] 148s gpgv: Signature made Tue Nov 12 20:24:39 2024 UTC 148s gpgv: using RSA key B8340990283D8D9BC1949AC74799A35146D12B35 148s gpgv: Can't check signature: No public key 148s dpkg-source: warning: cannot verify inline signature for ./knot-resolver_5.7.4-2build1.dsc: no acceptable signature found 148s autopkgtest [07:29:49]: testing package knot-resolver version 5.7.4-2build1 150s autopkgtest [07:29:51]: build not needed 153s autopkgtest [07:29:54]: test roundtrip: preparing testbed 154s Reading package lists... 155s Building dependency tree... 155s Reading state information... 155s Starting pkgProblemResolver with broken count: 0 155s Starting 2 pkgProblemResolver with broken count: 0 155s Done 156s The following NEW packages will be installed: 156s dns-root-data gnutls-bin knot-dnsutils knot-resolver libdnssec9t64 156s libevent-2.1-7t64 libfstrm0 libgnutls-dane0t64 libknot15 libluajit-5.1-2 156s libluajit-5.1-common libngtcp2-16 libngtcp2-crypto-gnutls8 libunbound8 156s libxdp1 libzscanner4t64 lua-sec lua-socket socat 156s 0 upgraded, 19 newly installed, 0 to remove and 0 not upgraded. 156s Need to get 2594 kB of archives. 156s After this operation, 9479 kB of additional disk space will be used. 156s Get:1 http://ftpmaster.internal/ubuntu questing/main armhf dns-root-data all 2024071801 [5802 B] 156s Get:2 http://ftpmaster.internal/ubuntu questing/main armhf libevent-2.1-7t64 armhf 2.1.12-stable-10 [127 kB] 156s Get:3 http://ftpmaster.internal/ubuntu questing/main armhf libunbound8 armhf 1.22.0-1ubuntu1 [423 kB] 157s Get:4 http://ftpmaster.internal/ubuntu questing/main armhf libgnutls-dane0t64 armhf 3.8.9-2ubuntu3 [35.0 kB] 157s Get:5 http://ftpmaster.internal/ubuntu questing/universe armhf gnutls-bin armhf 3.8.9-2ubuntu3 [278 kB] 157s Get:6 http://ftpmaster.internal/ubuntu questing/universe armhf libdnssec9t64 armhf 3.4.4-1 [50.5 kB] 157s Get:7 http://ftpmaster.internal/ubuntu questing/universe armhf libngtcp2-16 armhf 1.11.0-1 [125 kB] 157s Get:8 http://ftpmaster.internal/ubuntu questing/universe armhf libngtcp2-crypto-gnutls8 armhf 1.11.0-1 [15.1 kB] 157s Get:9 http://ftpmaster.internal/ubuntu questing/main armhf libxdp1 armhf 1.5.1-1ubuntu2 [55.6 kB] 157s Get:10 http://ftpmaster.internal/ubuntu questing/universe armhf libknot15 armhf 3.4.4-1 [110 kB] 157s Get:11 http://ftpmaster.internal/ubuntu questing/universe armhf libzscanner4t64 armhf 3.4.4-1 [147 kB] 157s Get:12 http://ftpmaster.internal/ubuntu questing/universe armhf libfstrm0 armhf 0.6.1-1build4 [17.5 kB] 157s Get:13 http://ftpmaster.internal/ubuntu questing/universe armhf knot-dnsutils armhf 3.4.4-1 [121 kB] 157s Get:14 http://ftpmaster.internal/ubuntu questing/universe armhf lua-socket armhf 3.1.0-1 [80.3 kB] 157s Get:15 http://ftpmaster.internal/ubuntu questing/universe armhf lua-sec armhf 1.3.2-2 [36.2 kB] 157s Get:16 http://ftpmaster.internal/ubuntu questing/universe armhf libluajit-5.1-common all 2.1.0+openresty20250117-2 [54.4 kB] 157s Get:17 http://ftpmaster.internal/ubuntu questing/universe armhf libluajit-5.1-2 armhf 2.1.0+openresty20250117-2 [232 kB] 157s Get:18 http://ftpmaster.internal/ubuntu questing/universe armhf knot-resolver armhf 5.7.4-2build1 [310 kB] 157s Get:19 http://ftpmaster.internal/ubuntu questing/main armhf socat armhf 1.8.0.2-1 [369 kB] 157s Preconfiguring packages ... 157s Fetched 2594 kB in 1s (3380 kB/s) 157s Selecting previously unselected package dns-root-data. 157s (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 ... 63951 files and directories currently installed.) 157s Preparing to unpack .../00-dns-root-data_2024071801_all.deb ... 157s Unpacking dns-root-data (2024071801) ... 157s Selecting previously unselected package libevent-2.1-7t64:armhf. 157s Preparing to unpack .../01-libevent-2.1-7t64_2.1.12-stable-10_armhf.deb ... 157s Unpacking libevent-2.1-7t64:armhf (2.1.12-stable-10) ... 157s Selecting previously unselected package libunbound8:armhf. 157s Preparing to unpack .../02-libunbound8_1.22.0-1ubuntu1_armhf.deb ... 157s Unpacking libunbound8:armhf (1.22.0-1ubuntu1) ... 157s Selecting previously unselected package libgnutls-dane0t64:armhf. 157s Preparing to unpack .../03-libgnutls-dane0t64_3.8.9-2ubuntu3_armhf.deb ... 157s Unpacking libgnutls-dane0t64:armhf (3.8.9-2ubuntu3) ... 157s Selecting previously unselected package gnutls-bin. 157s Preparing to unpack .../04-gnutls-bin_3.8.9-2ubuntu3_armhf.deb ... 157s Unpacking gnutls-bin (3.8.9-2ubuntu3) ... 157s Selecting previously unselected package libdnssec9t64. 157s Preparing to unpack .../05-libdnssec9t64_3.4.4-1_armhf.deb ... 157s Unpacking libdnssec9t64 (3.4.4-1) ... 157s Selecting previously unselected package libngtcp2-16:armhf. 157s Preparing to unpack .../06-libngtcp2-16_1.11.0-1_armhf.deb ... 157s Unpacking libngtcp2-16:armhf (1.11.0-1) ... 157s Selecting previously unselected package libngtcp2-crypto-gnutls8:armhf. 157s Preparing to unpack .../07-libngtcp2-crypto-gnutls8_1.11.0-1_armhf.deb ... 158s Unpacking libngtcp2-crypto-gnutls8:armhf (1.11.0-1) ... 158s Selecting previously unselected package libxdp1:armhf. 158s Preparing to unpack .../08-libxdp1_1.5.1-1ubuntu2_armhf.deb ... 158s Unpacking libxdp1:armhf (1.5.1-1ubuntu2) ... 158s Selecting previously unselected package libknot15. 158s Preparing to unpack .../09-libknot15_3.4.4-1_armhf.deb ... 158s Unpacking libknot15 (3.4.4-1) ... 158s Selecting previously unselected package libzscanner4t64. 158s Preparing to unpack .../10-libzscanner4t64_3.4.4-1_armhf.deb ... 158s Unpacking libzscanner4t64 (3.4.4-1) ... 158s Selecting previously unselected package libfstrm0:armhf. 158s Preparing to unpack .../11-libfstrm0_0.6.1-1build4_armhf.deb ... 158s Unpacking libfstrm0:armhf (0.6.1-1build4) ... 158s Selecting previously unselected package knot-dnsutils. 158s Preparing to unpack .../12-knot-dnsutils_3.4.4-1_armhf.deb ... 158s Unpacking knot-dnsutils (3.4.4-1) ... 158s Selecting previously unselected package lua-socket:armhf. 158s Preparing to unpack .../13-lua-socket_3.1.0-1_armhf.deb ... 158s Unpacking lua-socket:armhf (3.1.0-1) ... 158s Selecting previously unselected package lua-sec:armhf. 158s Preparing to unpack .../14-lua-sec_1.3.2-2_armhf.deb ... 158s Unpacking lua-sec:armhf (1.3.2-2) ... 158s Selecting previously unselected package libluajit-5.1-common. 158s Preparing to unpack .../15-libluajit-5.1-common_2.1.0+openresty20250117-2_all.deb ... 158s Unpacking libluajit-5.1-common (2.1.0+openresty20250117-2) ... 158s Selecting previously unselected package libluajit-5.1-2:armhf. 158s Preparing to unpack .../16-libluajit-5.1-2_2.1.0+openresty20250117-2_armhf.deb ... 158s Unpacking libluajit-5.1-2:armhf (2.1.0+openresty20250117-2) ... 158s Selecting previously unselected package knot-resolver. 158s Preparing to unpack .../17-knot-resolver_5.7.4-2build1_armhf.deb ... 158s Unpacking knot-resolver (5.7.4-2build1) ... 158s Selecting previously unselected package socat. 158s Preparing to unpack .../18-socat_1.8.0.2-1_armhf.deb ... 158s Unpacking socat (1.8.0.2-1) ... 158s Setting up libzscanner4t64 (3.4.4-1) ... 158s Setting up libfstrm0:armhf (0.6.1-1build4) ... 158s Setting up libevent-2.1-7t64:armhf (2.1.12-stable-10) ... 158s Setting up lua-socket:armhf (3.1.0-1) ... 158s Setting up dns-root-data (2024071801) ... 158s Setting up libxdp1:armhf (1.5.1-1ubuntu2) ... 158s Setting up libunbound8:armhf (1.22.0-1ubuntu1) ... 158s Setting up libgnutls-dane0t64:armhf (3.8.9-2ubuntu3) ... 158s Setting up socat (1.8.0.2-1) ... 158s Setting up libdnssec9t64 (3.4.4-1) ... 158s Setting up libluajit-5.1-common (2.1.0+openresty20250117-2) ... 158s Setting up libngtcp2-16:armhf (1.11.0-1) ... 158s Setting up libngtcp2-crypto-gnutls8:armhf (1.11.0-1) ... 158s Setting up gnutls-bin (3.8.9-2ubuntu3) ... 158s Setting up lua-sec:armhf (1.3.2-2) ... 158s Setting up libknot15 (3.4.4-1) ... 158s Setting up libluajit-5.1-2:armhf (2.1.0+openresty20250117-2) ... 158s Setting up knot-resolver (5.7.4-2build1) ... 159s Created symlink '/etc/systemd/system/kresd.target.wants/kres-cache-gc.service' → '/usr/lib/systemd/system/kres-cache-gc.service'. 159s Created symlink '/etc/systemd/system/multi-user.target.wants/kresd.target' → '/usr/lib/systemd/system/kresd.target'. 159s Setting up knot-dnsutils (3.4.4-1) ... 159s Processing triggers for man-db (2.13.0-1) ... 160s Processing triggers for libc-bin (2.41-6ubuntu1) ... 168s autopkgtest [07:30:09]: test roundtrip: [----------------------- 169s /usr/sbin/kresd + /usr/bin/kdig roundtrip tests 169s ------------ 169s workdir: /tmp/autopkgtest.gjYC4b/roundtrip-artifacts 169s IP addr: 127.70.61.5 169s kresd args: --addr=127.70.61.5@8053 --tls=127.70.61.5@8853 --noninteractive --config=/tmp/autopkgtest.gjYC4b/roundtrip-artifacts/kresd.conf --verbose --verbose --verbose 169s 169s make Certificate Authority key and certificate 169s ---------------------------------------------- 170s Generating a 3072 bit RSA private key... 170s Generating a self signed certificate... 170s X.509 Certificate Information: 170s Version: 3 170s Serial Number (hex): 1ea9b0bd7501e6848d1bbc975087107646162a07 170s Validity: 170s Not Before: Sat May 03 07:30:11 UTC 2025 170s Not After: Thu May 15 07:30:11 UTC 2025 170s Subject: CN=testing certificate authority (NOT FOR PRODUCTION) 170s Subject Public Key Algorithm: RSA 170s Algorithm Security Level: High (3072 bits) 170s Modulus (bits 3072): 170s 00:9d:c5:27:c6:af:89:7c:b9:f3:a7:b2:1c:9b:67:d2 170s bd:d7:82:be:8b:ad:6a:3b:41:a1:04:aa:0b:ca:9e:01 170s d7:74:d0:ab:15:43:6e:09:e7:bc:54:0a:f9:1b:1f:40 170s 87:3d:83:73:f8:0c:91:27:22:58:d4:7f:1d:5f:f1:ad 170s 97:d2:d6:32:ae:06:ad:ec:9a:73:25:0a:7f:73:49:64 170s 9e:c0:da:db:94:0d:1c:27:12:da:74:03:02:f8:b3:07 170s a6:7d:e8:94:94:e0:2e:21:4a:e2:20:c4:fd:f9:a5:0b 170s 63:d7:9f:6b:f7:0d:5e:55:a6:de:39:2f:67:00:fb:59 170s e7:68:88:00:68:7d:54:31:fd:8b:21:89:41:02:e9:28 170s 58:5a:73:79:2d:c4:9d:59:2c:d3:0c:5b:df:f5:5c:03 170s bd:9c:db:b6:d8:d3:1e:c5:55:83:d0:81:6a:4e:1f:94 170s 34:ac:8e:43:7e:59:6d:01:b6:13:d0:17:a4:70:8b:aa 170s e6:0b:e3:97:6f:0d:a2:6f:d9:ed:45:08:ad:97:d2:85 170s e3:e1:04:70:e6:9d:49:0e:b5:4f:da:61:e2:5b:f8:6e 170s 9a:7a:04:73:a8:da:39:56:e1:91:5f:fc:f1:00:e7:ac 170s 0b:11:24:49:0b:67:9b:03:14:e3:a9:b0:09:ea:68:ac 170s 99:2f:da:9e:1a:d2:08:ea:42:21:2a:c7:37:cb:62:db 170s f0:4d:df:bf:11:96:d9:68:06:1c:89:37:71:09:8b:80 170s 5f:d2:89:7c:ce:93:70:ce:e6:47:ec:b0:4c:e5:c4:11 170s 16:69:0c:6d:66:66:9c:70:cf:00:8e:43:1c:ec:43:c4 170s 8d:b6:64:81:2f:18:3e:87:1b:e5:0e:c3:ae:fd:b4:d1 170s d0:06:3b:f8:a6:30:fc:a4:4d:a5:d7:a0:2e:13:2e:28 170s db:3f:02:d5:8f:a7:fc:d7:10:12:90:3d:67:c5:3d:f2 170s 15:d3:9c:79:26:91:97:46:6f:2e:a2:66:19:22:95:4f 170s cd 170s Exponent (bits 24): 170s 01:00:01 170s Extensions: 170s Basic Constraints (critical): 170s Certificate Authority (CA): TRUE 170s Path Length Constraint: 1 170s Name Constraints (critical): 170s Permitted: 170s DNSname: example 170s Key Usage (critical): 170s Certificate signing. 170s Subject Key Identifier (not critical): 170s 8c198f783bc9c84ac20e5ed9ac45bc8ea2cb8861 170s Other Information: 170s Public Key ID: 170s sha1:8c198f783bc9c84ac20e5ed9ac45bc8ea2cb8861 170s sha256:94adfdeeb192d134b17b73fbc18ae5d8181eaf5774babcc49286699a3e629628 170s Public Key PIN: 170s pin-sha256:lK397rGS0TSxe3P7wYrl2Bger1d0urzEkoZpmj5ilig= 170s 170s 170s 170s Signing certificate... 170s 170s make Bogus Certificate Authority key and certificate 170s ---------------------------------------------------- 171s Generating a 3072 bit RSA private key... 171s Generating a self signed certificate... 171s X.509 Certificate Information: 171s Version: 3 171s Serial Number (hex): 0c8b19fcff6dd23690a657bba33ac712d7dd478d 171s Validity: 171s Not Before: Sat May 03 07:30:12 UTC 2025 171s Not After: Thu May 15 07:30:12 UTC 2025 171s Subject: CN=testing certificate authority (NOT FOR PRODUCTION) 171s Subject Public Key Algorithm: RSA 171s Algorithm Security Level: High (3072 bits) 171s Modulus (bits 3072): 171s 00:dd:17:ee:da:f9:98:ef:94:eb:5b:8d:18:d9:ea:65 171s ff:41:9c:2f:84:63:14:90:ca:5c:19:79:fa:87:98:13 171s 8f:fe:1f:a4:06:69:1b:db:ff:3d:8d:2b:e6:7b:d4:c1 171s ec:f3:c6:40:18:c2:47:b3:f4:b5:11:dd:f3:14:dc:8d 171s 7a:62:22:61:fa:75:89:ad:34:3d:46:45:3a:5a:9e:41 171s 76:f2:7b:40:8b:09:20:30:76:23:e4:75:83:6e:fa:d4 171s 1f:f5:e6:73:87:74:89:99:a1:f0:95:5e:dc:01:fb:a8 171s 05:31:df:4c:16:aa:37:23:8f:76:e4:c7:96:2b:dc:be 171s 5e:3e:66:22:1b:c6:71:be:cd:1a:1b:76:a1:c5:12:9e 171s 81:89:aa:78:f0:1c:c5:8d:b5:39:02:dd:cc:c7:0a:69 171s 29:52:8e:d7:ec:d5:30:18:78:b6:02:e7:75:99:b8:1f 171s 8c:a4:ad:d7:af:f1:8d:3e:3a:ca:9e:19:28:9b:00:63 171s 3d:e9:ef:99:9f:fc:3f:82:7c:cf:fa:38:a6:55:70:44 171s 30:b8:a6:be:69:1e:61:6a:8b:70:f2:b6:4c:20:4e:3a 171s b1:99:ba:7a:a2:99:c2:43:3c:d1:f1:c0:c9:8f:db:dc 171s 88:ad:ac:1f:8d:1e:15:d7:62:ed:f5:de:fa:c2:03:06 171s 8d:67:21:e8:30:3d:3a:70:ed:3f:53:71:73:52:d3:a9 171s ad:66:28:10:9c:24:45:c4:ee:6e:9e:b6:a7:f5:93:13 171s 2d:7b:5c:77:5a:af:73:75:03:de:e8:d1:d7:f0:98:71 171s 35:f8:fb:79:28:69:b8:fe:dc:db:91:b0:16:59:95:af 171s be:0b:b2:0e:32:1b:8f:a7:9f:f7:95:9c:26:7a:32:32 171s cf:05:1b:f6:29:47:a5:03:44:6d:b4:30:f8:be:f6:35 171s 08:d6:2a:bc:b8:5b:10:3b:7d:91:23:6b:0e:d8:b1:6a 171s 7a:7b:e5:33:db:94:77:8c:e0:9c:6c:eb:fd:ea:9c:ad 171s 37 171s Exponent (bits 24): 171s 01:00:01 171s Extensions: 171s Basic Constraints (critical): 171s Certificate Authority (CA): TRUE 171s Path Length Constraint: 1 171s Name Constraints (critical): 171s Permitted: 171s DNSname: example 171s Key Usage (critical): 171s Certificate signing. 171s Subject Key Identifier (not critical): 171s cd9833fa5b6187cdb01ef689cb31de053c37d209 171s Other Information: 171s Public Key ID: 171s sha1:cd9833fa5b6187cdb01ef689cb31de053c37d209 171s sha256:8caa2d4edeb9a8078bdf8744177232a31eb7e9fd52565735f374377894dcb43e 171s Public Key PIN: 171s pin-sha256:jKotTt65qAeL34dEF3Iyox636f1SVlc183Q3eJTctD4= 171s 171s 171s 171s Signing certificate... 171s 171s make End Entity key and certificate 171s ----------------------------------- 173s Generating a 3072 bit RSA private key... 173s Generating a signed certificate... 173s X.509 Certificate Information: 173s Version: 3 173s Serial Number (hex): 5823c3b617056a5e9ab47b6d416399e28cc9cfc6 173s Validity: 173s Not Before: Sat May 03 07:30:14 UTC 2025 173s Not After: Tue May 13 07:30:14 UTC 2025 173s Subject: CN=test.example 173s Subject Public Key Algorithm: RSA 173s Algorithm Security Level: High (3072 bits) 173s Modulus (bits 3072): 173s 00:f5:fc:f9:3f:e7:9d:ba:ce:a6:8f:21:0e:1b:d7:16 173s f0:41:39:61:6b:6b:e6:82:37:69:1d:6b:35:85:58:62 173s 59:09:a2:e2:d3:45:d2:a4:d9:7b:c4:98:3f:ee:ff:2a 173s e0:56:d6:f8:93:ee:36:6c:0d:05:68:82:a9:57:10:ae 173s c2:91:16:ac:35:44:a8:31:6f:86:53:a6:d4:2e:7e:91 173s f3:54:73:53:76:14:b9:c9:f5:68:6f:ad:fa:87:e7:39 173s af:9e:3d:83:a1:f8:a1:dc:fa:78:1c:51:d9:56:85:a0 173s 87:b6:58:62:12:1e:06:87:f4:6c:35:c4:bb:db:2d:0a 173s 60:c2:78:f6:1d:a7:1d:de:33:6c:ac:08:1a:2e:6b:45 173s 44:d6:b2:76:e1:70:22:d7:b4:2f:a6:0f:c2:f4:70:2c 173s 60:f9:56:02:5b:21:04:63:3c:29:a2:07:7c:50:ed:1c 173s 16:dc:23:a8:b4:f5:7c:9b:d3:2d:14:db:1d:34:67:7e 173s d7:ef:65:43:3a:81:15:1c:3a:82:14:7c:6e:d0:69:7d 173s 01:7d:f6:8e:4b:39:0a:fe:3e:fc:86:d0:e7:c3:10:63 173s 1a:5e:91:1b:21:e8:4a:4c:5c:fc:8e:73:90:54:02:be 173s b8:b7:bb:a0:d6:e8:df:39:9c:76:76:07:c6:46:de:54 173s 1e:94:92:86:41:35:5f:f7:34:39:3f:6a:8e:a7:62:95 173s f9:67:b4:60:75:d8:b3:6b:6e:80:70:72:16:b4:a8:1c 173s 69:26:7b:04:bc:05:b0:29:32:c7:64:d0:d2:c6:11:67 173s c4:16:da:07:64:b0:81:fd:f6:76:22:5d:45:5d:f7:6e 173s 6b:74:a3:60:36:0d:cf:c1:a6:51:70:86:4a:fb:3c:48 173s 13:10:10:88:6a:9b:61:f2:c7:96:e2:10:60:6f:cb:18 173s aa:73:08:83:3d:aa:ed:4b:0e:dc:81:bd:9f:6b:b3:98 173s 74:2c:a4:d0:20:f6:4b:14:3a:8e:c4:52:95:82:a1:c9 173s 23 173s Exponent (bits 24): 173s 01:00:01 173s Extensions: 173s Basic Constraints (critical): 173s Certificate Authority (CA): FALSE 173s Subject Alternative Name (not critical): 173s DNSname: test.example 173s Key Purpose (not critical): 173s TLS WWW Server. 173s Key Usage (critical): 173s Digital signature. 173s Subject Key Identifier (not critical): 173s ed45b3cbff3c8ca01a5723b9947cfbf139fab2af 173s Authority Key Identifier (not critical): 173s 8c198f783bc9c84ac20e5ed9ac45bc8ea2cb8861 173s Other Information: 173s Public Key ID: 173s sha1:ed45b3cbff3c8ca01a5723b9947cfbf139fab2af 173s sha256:7ae34aa3923157ee75d4b2883d6808c65ece87d08aa1e77fb974e63577288361 173s Public Key PIN: 173s pin-sha256:euNKo5IxV+511LKIPWgIxl7Oh9CKoed/uXTmNXcog2E= 173s 173s 173s 173s Signing certificate... 173s 173s set up kresd daemon on 127.70.61.5 on ports 8053 (UDP, TCP) and 8853 (TLS) 173s -------------------------------------------------------------------------- 174s 174s test UDP with kdig 174s ------------------ 174s successful UDP request to 127.70.61.5 on port 8053 174s 174s test TCP with kdig 174s ------------------ 174s successful TCP request to 127.70.61.5 on port 8053 174s 174s test opportunistic DNS-over-TLS with kdig 174s ----------------------------------------- 174s successful opportunistic DNS-over-TLS request to 127.70.61.5 on port 8853 174s 174s test strict DNS-over-TLS with kdig 174s ---------------------------------- 174s successful strict DNS-over-TLS request to 127.70.61.5 on port 8853 174s 174s test invalid name with strict DNS-over-TLS with kdig 174s ---------------------------------------------------- 174s successful strict DNS-over-TLS request failure when name mismatch to 127.70.61.5 on port 8853 174s 174s test bad authority with strict DNS-over-TLS with kdig 174s ----------------------------------------------------- 175s successful strict DNS-over-TLS request failure to 127.70.61.5 on port 8853 175s 175s cleaning up 175s ----------- 175s 78916 0 drwxrwxrwt 1 root root 318 May 3 07:30 /tmp/autopkgtest.gjYC4b/roundtrip-artifacts 175s 78924 4 -rw-r--r-- 1 root root 136 May 3 07:30 /tmp/autopkgtest.gjYC4b/roundtrip-artifacts/ca.template 175s 78925 8 -rw------- 1 root root 8180 May 3 07:30 /tmp/autopkgtest.gjYC4b/roundtrip-artifacts/ca-key.pem 175s 78926 4 -rw-r--r-- 1 root root 1590 May 3 07:30 /tmp/autopkgtest.gjYC4b/roundtrip-artifacts/ca-cert.pem 175s 78927 8 -rw------- 1 root root 8177 May 3 07:30 /tmp/autopkgtest.gjYC4b/roundtrip-artifacts/bogus-key.pem 175s 78928 4 -rw-r--r-- 1 root root 1590 May 3 07:30 /tmp/autopkgtest.gjYC4b/roundtrip-artifacts/bogus-cert.pem 175s 78929 4 -rw-r--r-- 1 root root 92 May 3 07:30 /tmp/autopkgtest.gjYC4b/roundtrip-artifacts/ee.template 175s 78930 8 -rw------- 1 root root 8180 May 3 07:30 /tmp/autopkgtest.gjYC4b/roundtrip-artifacts/ee-key.pem 175s 78931 4 -rw-r--r-- 1 root root 2218 May 3 07:30 /tmp/autopkgtest.gjYC4b/roundtrip-artifacts/ee-pubkey.pem 175s 78932 4 -rw-r--r-- 1 root root 1602 May 3 07:30 /tmp/autopkgtest.gjYC4b/roundtrip-artifacts/ee-cert.pem 175s 78933 4 -rw-r--r-- 1 root root 387 May 3 07:30 /tmp/autopkgtest.gjYC4b/roundtrip-artifacts/kresd.conf 175s 78934 68 -rw-r--r-- 1 root root 68881 May 3 07:30 /tmp/autopkgtest.gjYC4b/roundtrip-artifacts/kresd.err 175s 78935 4 -rw-r----- 1 root root 8192 May 3 07:30 /tmp/autopkgtest.gjYC4b/roundtrip-artifacts/lock.mdb 175s 78936 102400 -rw-r----- 1 root root 104857600 May 3 07:30 /tmp/autopkgtest.gjYC4b/roundtrip-artifacts/data.mdb 175s 78937 4 -rw-r--r-- 1 root root 117 May 3 07:30 /tmp/autopkgtest.gjYC4b/roundtrip-artifacts/badname.err 175s 78938 4 -rw-r--r-- 1 root root 117 May 3 07:30 /tmp/autopkgtest.gjYC4b/roundtrip-artifacts/badca.err 175s ==> /tmp/autopkgtest.gjYC4b/roundtrip-artifacts/badca.err <== 175s ;; WARNING: TLS, handshake failed (Error in the certificate.) 175s ;; ERROR: failed to query server 127.70.61.5@8853(TCP) 175s 175s ==> /tmp/autopkgtest.gjYC4b/roundtrip-artifacts/badname.err <== 175s ;; WARNING: TLS, handshake failed (Error in the certificate.) 175s ;; ERROR: failed to query server 127.70.61.5@8853(TCP) 175s 175s ==> /tmp/autopkgtest.gjYC4b/roundtrip-artifacts/kresd.err <== 175s [system] increasing file-descriptor limit: 1024 -> 1048576 175s [tls ] session ticket: epoch 426332, scheduling rotation check in 2553168 ms 175s [wtchdg] disabled in systemd (WatchdogSec= not specified) 175s [ta ] installed trust anchors for domain . are: 175s . 3600 DNSKEY 257 3 8 AwEAAaz/tAm8yTn4Mfeh5eyI96WSVexTBAvkMgJzkKTOiW1vkIbzxeF3+/4RgWOq7HrxRixHlFlExOLAJr5emLvN7SWXgnLh4+B5xQlNVz8Og8kvArMtNROxVQuCaSnIDdD5LKyWbRd2n9WGe2R8PzgCmr3EgVLrjyBxWezF0jLHwVN8efS3rCj/EWgvIWgb9tarpVUDK/b58Da+sqqls3eNbuv7pr+eoZG+SrDK6nWeL3c6H5Apxz7LjVc1uTIdsIXxuOLYA4/ilBmSVIzuDWfdRUfhHdY6+cn8HFRm+2hM8AnXGXws9555KrUB5qihylGa8subX2Nn6UwNR1AkUTV74bU= ; Valid: ; KeyTag:20326 175s . 3600 DNSKEY 257 3 8 AwEAAa96jeuknZlaeSrvyAJj6ZHv28hhOKkx3rLGXVaC6rXTsDc449/cidltpkyGwCJNnOAlFNKF2jBosZBU5eeHspaQWOmOElZsjICMQMC3aeHbGiShvZsx4wMYSjH8e7Vrhbu6irwCzVBApESjbUdpWWmEnhathWu1jo+siFUiRAAxm9qyJNg/wOZqqzL/dL/q8PkcRU5oUKEpUge71M3ej2/7CPqpdVwuMoTvoB+ZOT4YeGyxMvHmbrxlFzGOHOijtzN+u1TQNatX2XBuzZNQ1K+s2CXkPIZo7s6JgZyvaBevYtxPvYLw4z9mR7K2vaF18UYH9Z9GNUUeayffKC73PYc= ; Valid: ; KeyTag:38696 175s 175s [system] loading config '/tmp/autopkgtest.gjYC4b/roundtrip-artifacts/kresd.conf' (workdir '/tmp/autopkgtest.gjYC4b/roundtrip-artifacts') 175s [system] deprecation WARNING: use log_level() instead of verbose() 175s [gnutls] (3) ASSERT: ../../../lib/x509/x509_ext.c[gnutls_subject_alt_names_get]:107 175s [gnutls] (3) ASSERT: ../../../lib/x509/x509.c[get_alt_name]:2012 175s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 175s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 175s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 175s [tls ] RFC 7858 OOB key-pin (0): pin-sha256="" 175s [gnutls] (3) ASSERT: ../../lib/cert-cred-x509.c[gnutls_certificate_get_x509_crt]:872 175s [system] loading config '/usr/lib/arm-linux-gnueabihf/knot-resolver/postconfig.lua' (workdir '/tmp/autopkgtest.gjYC4b/roundtrip-artifacts') 175s [plan ][00000.00] plan '.' type 'NS' uid [65536.00] 175s [iterat][65536.00] '.' type 'NS' new uid was assigned .01, parent uid .00 175s [resolv][65536.01] => using root hints 175s [iterat][65536.01] '.' type 'NS' new uid was assigned .02, parent uid .00 175s [resolv][65536.02] >< TA: '.' 175s [plan ][65536.02] plan '.' type 'DNSKEY' uid [65536.03] 175s [iterat][65536.03] '.' type 'DNSKEY' new uid was assigned .04, parent uid .02 175s [select][65536.04] => id: '16060' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 175s [select][65536.04] => id: '16060' choosing: 'C.ROOT-SERVERS.NET.'@'2001:500:2::c#00053' with timeout 400 ms zone cut: '.' 175s [resolv][65536.04] => id: '16060' querying: 'C.ROOT-SERVERS.NET.'@'2001:500:2::c#00053' zone cut: '.' qname: '.' qtype: 'DNSKEY' proto: 'udp' 175s [plan ][00000.00] plan '.' type 'NS' uid [65537.00] 175s [iterat][65537.00] '.' type 'NS' new uid was assigned .01, parent uid .00 175s [resolv][65537.01] => using root hints 175s [iterat][65537.01] '.' type 'NS' new uid was assigned .02, parent uid .00 175s [select][65537.02] => id: '20825' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 175s [select][65537.02] => id: '20825' choosing: 'D.ROOT-SERVERS.NET.'@'2001:500:2d::d#00053' with timeout 400 ms zone cut: '.' 175s [resolv][65537.02] => id: '20825' querying: 'D.ROOT-SERVERS.NET.'@'2001:500:2d::d#00053' zone cut: '.' qname: '.' qtype: 'NS' proto: 'udp' 175s [taupd ] refreshing TA for . 175s [plan ][00000.00] plan '.' type 'DNSKEY' uid [65538.00] 175s [iterat][65538.00] '.' type 'DNSKEY' new uid was assigned .01, parent uid .00 175s [resolv][65538.01] => using root hints 175s [iterat][65538.01] '.' type 'DNSKEY' new uid was assigned .02, parent uid .00 175s [resolv][65538.02] >< TA: '.' 175s [select][65538.02] => id: '13364' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 175s [select][65538.02] => id: '13364' choosing: 'G.ROOT-SERVERS.NET.'@'2001:500:12::d0d#00053' with timeout 400 ms zone cut: '.' 175s [select][65536.04] NO6: timed out, appended, timeouts 1/6 175s [select][65536.04] => id: '16060' noting selection error: 'C.ROOT-SERVERS.NET.'@'2001:500:2::c#00053' zone cut: '.' error: 1 QUERY_TIMEOUT 175s [iterat][65538.02] '.' type 'DNSKEY' new uid was assigned .03, parent uid .00 175s [select][65538.03] => id: '16034' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 175s [select][65538.03] => id: '16034' choosing: 'D.ROOT-SERVERS.NET.'@'199.7.91.13#00053' with timeout 400 ms zone cut: '.' 175s [resolv][65538.03] => id: '16034' querying: 'D.ROOT-SERVERS.NET.'@'199.7.91.13#00053' zone cut: '.' qname: '.' qtype: 'DNSKEY' proto: 'udp' 175s [iterat][65536.04] '.' type 'DNSKEY' new uid was assigned .05, parent uid .02 175s [select][65536.05] => id: '17749' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 175s [select][65536.05] => id: '17749' choosing: 'J.ROOT-SERVERS.NET.'@'192.58.128.30#00053' with timeout 800 ms zone cut: '.' 175s [select][65537.02] NO6: timed out, appended, timeouts 2/6 175s [select][65537.02] => id: '20825' noting selection error: 'D.ROOT-SERVERS.NET.'@'2001:500:2d::d#00053' zone cut: '.' error: 1 QUERY_TIMEOUT 175s [iterat][65537.02] '.' type 'NS' new uid was assigned .03, parent uid .00 175s [select][65537.03] => id: '24563' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 175s [select][65537.03] => id: '24563' choosing: 'M.ROOT-SERVERS.NET.'@'2001:dc3::35#00053' with timeout 800 ms zone cut: '.' 175s [resolv][65537.03] => id: '24563' querying: 'M.ROOT-SERVERS.NET.'@'2001:dc3::35#00053' zone cut: '.' qname: '.' qtype: 'NS' proto: 'udp' 175s [select][65538.03] => id: '16034' noting selection error: 'D.ROOT-SERVERS.NET.'@'199.7.91.13#00053' zone cut: '.' error: 1 QUERY_TIMEOUT 175s [iterat][65536.05] '.' type 'DNSKEY' new uid was assigned .06, parent uid .02 175s [select][65536.06] => id: '35916' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 175s [select][65536.06] => id: '35916' choosing: 'M.ROOT-SERVERS.NET.'@'202.12.27.33#00053' with timeout 800 ms zone cut: '.' 175s [resolv][65536.06] => id: '35916' querying: 'M.ROOT-SERVERS.NET.'@'202.12.27.33#00053' zone cut: '.' qname: '.' qtype: 'DNSKEY' proto: 'udp' 175s [iterat][65538.03] '.' type 'DNSKEY' new uid was assigned .04, parent uid .00 175s [select][65538.04] => id: '44514' choosing from addresses: 13 v4 + 13 v6; names to resolve: 0 v4 + 0 v6; force_resolve: 0; NO6: IPv6 is OK 175s [select][65538.04] => id: '44514' choosing: 'M.ROOT-SERVERS.NET.'@'2001:dc3::35#00053' with timeout 800 ms zone cut: '.' 175s [plan ][00000.00] plan 'monkeys.example.' type 'A' uid [35520.00] 175s [iterat][35520.00] 'monkeys.example.' type 'A' new uid was assigned .01, parent uid .00 175s [hint ][35520.01] <= answered from hints 175s [iterat][35520.01] <= rcode: NOERROR 175s [resolv][35520.01] AD: request NOT classified as SECURE 175s [resolv][35520.01] finished in state: 4, queries: 1, mempool: 16392 B 175s [plan ][00000.00] plan 'monkeys.example.' type 'A' uid [38359.00] 175s [iterat][38359.00] 'monkeys.example.' type 'A' new uid was assigned .01, parent uid .00 175s [hint ][38359.01] <= answered from hints 175s [iterat][38359.01] <= rcode: NOERROR 175s [resolv][38359.01] AD: request NOT classified as SECURE 175s [resolv][38359.01] finished in state: 4, queries: 1, mempool: 81936 B 175s [io ] => connection to '127.0.0.1#33887' closed by peer (end of file) 175s [gnutls] (5) REC[0xf4590000]: Allocating epoch #0 175s [gnutls] (2) added 3 protocols, 29 ciphersuites, 19 sig algos and 10 groups into priority list 175s [gnutls] (5) REC[0xf4590000]: Allocating epoch #1 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 175s [gnutls] (5) REC[0xf4590000]: SSL 3.1 Handshake packet received. Epoch 0, length: 310 175s [gnutls] (5) REC[0xf4590000]: Expected Packet Handshake(22) 175s [gnutls] (5) REC[0xf4590000]: Received Packet Handshake(22) with length: 310 175s [gnutls] (5) REC[0xf4590000]: Decrypted Packet[0] Handshake(22) with length: 310 175s [gnutls] (4) HSK[0xf4590000]: CLIENT HELLO (1) was received. Length 306[306], frag offset 0, frag length: 306, sequence: 0 175s [gnutls] (4) HSK[0xf4590000]: Client's version: 3.3 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Supported Versions/43' (3 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Found version: 3.4 175s [gnutls] (4) EXT[0xf4590000]: Negotiated version: 3.4 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Safe Renegotiation/65281' (1 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'ALPN/16' (6 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Record Size Limit/28' (2 bytes) 175s [gnutls] (4) EXT[0xf4590000]: record_size_limit 16385 negotiated 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Encrypt-then-MAC/22' (0 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Extended Master Secret/23' (0 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Supported EC Point Formats/11' (2 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'PSK Key Exchange Modes/45' (3 bytes) 175s [gnutls] (4) EXT[0xf4590000]: PSK KE mode 01 received 175s [gnutls] (4) EXT[0xf4590000]: PSK KE mode 00 received 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Supported Groups/10' (10 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Received group X25519 (0x1d) 175s [gnutls] (4) EXT[0xf4590000]: Received group SECP256R1 (0x17) 175s [gnutls] (4) EXT[0xf4590000]: Received group SECP384R1 (0x18) 175s [gnutls] (4) EXT[0xf4590000]: Received group SECP521R1 (0x19) 175s [gnutls] (4) EXT[0xf4590000]: Selected group X25519 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Session Ticket/35' (0 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Signature Algorithms/13' (34 bytes) 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (4.1) RSA-SHA256 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.9) RSA-PSS-SHA256 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.4) RSA-PSS-RSAE-SHA256 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (4.3) ECDSA-SECP256R1-SHA256 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.7) EdDSA-Ed25519 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (5.1) RSA-SHA384 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.10) RSA-PSS-SHA384 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.5) RSA-PSS-RSAE-SHA384 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (5.3) ECDSA-SECP384R1-SHA384 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.8) EdDSA-Ed448 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (6.1) RSA-SHA512 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.11) RSA-PSS-SHA512 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.6) RSA-PSS-RSAE-SHA512 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (6.3) ECDSA-SECP521R1-SHA512 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (2.1) RSA-SHA1 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (2.3) ECDSA-SHA1 175s [gnutls] (2) checking 13.02 (GNUTLS_AES_256_GCM_SHA384) for compatibility 175s [gnutls] (3) ASSERT: ../../../lib/ext/server_name.c[gnutls_server_name_get]:234 175s [gnutls] (4) HSK[0xf4590000]: Requested server name: '' 175s [gnutls] (4) HSK[0xf4590000]: checking compat of GNUTLS_AES_256_GCM_SHA384 with certificate[0] (RSA/X.509) 175s [gnutls] (4) checking cert compat with RSA-SHA256 175s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 175s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 175s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 175s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 175s [gnutls] (4) Selected signature algorithm: RSA-PSS-RSAE-SHA256 175s [gnutls] (2) Selected (RSA) cert based on ciphersuite 13.2: GNUTLS_AES_256_GCM_SHA384 175s [gnutls] (4) HSK[0xf4590000]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384 175s [gnutls] (4) HSK[0xf4590000]: Selected version TLS1.3 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Key Share/51' (107 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Received key share for X25519 175s [gnutls] (4) HSK[0xf4590000]: Selected group X25519 (6) 175s [gnutls] (2) EXT[0xf4590000]: server generated X25519 shared key 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'OCSP Status Request/5' (5 bytes) 175s [gnutls] (4) EXT[0xf4590000]: OCSP status was requested 175s [gnutls] (4) HSK[0xf4590000]: Safe renegotiation succeeded 175s [gnutls] (4) HSK[0xf4590000]: SessionID: 57f822a6cd35c729d1257eabd05a30cd647b62aa4d1f884888a3d9f11a1bcf80 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (OCSP Status Request/5) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Client Certificate Type/19) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Server Certificate Type/20) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Supported Groups/10) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Supported EC Point Formats/11) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Signature Algorithms/13) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (SRTP/14) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (ALPN/16) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Encrypt-then-MAC/22) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Extended Master Secret/23) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Session Ticket/35) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Key Share/51) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: sending key share for X25519 175s [gnutls] (4) EXT[0xf4590000]: Sending extension Key Share/51 (36 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Supported Versions/43) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Sending extension Supported Versions/43 (2 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Post Handshake Auth/49) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Safe Renegotiation/65281) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Server Name Indication/0) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Cookie/44) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Early Data/42) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (PSK Key Exchange Modes/45) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Record Size Limit/28) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Maximum Record Size/1) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Compress Certificate/27) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (ClientHello Padding/21) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Pre Shared Key/41) for 'TLS 1.3 server hello' 175s [gnutls] (4) HSK[0xf4590000]: SERVER HELLO was queued [122 bytes] 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 122 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 127 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6 175s [gnutls] (4) REC[0xf4590000]: Sent ChangeCipherSpec 175s [gnutls] (5) REC[0xf4590000]: Initializing epoch #1 175s [gnutls] (5) REC[0xf4590000]: Epoch #1 ready 175s [gnutls] (4) HSK[0xf4590000]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (OCSP Status Request/5) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Client Certificate Type/19) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Server Certificate Type/20) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Supported Groups/10) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Supported EC Point Formats/11) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Signature Algorithms/13) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (SRTP/14) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (ALPN/16) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Sending extension ALPN/16 (6 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Encrypt-then-MAC/22) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Extended Master Secret/23) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Session Ticket/35) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Key Share/51) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Supported Versions/43) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Post Handshake Auth/49) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Safe Renegotiation/65281) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Server Name Indication/0) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Cookie/44) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Early Data/42) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (PSK Key Exchange Modes/45) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Record Size Limit/28) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Sending extension Record Size Limit/28 (2 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Maximum Record Size/1) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Compress Certificate/27) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (ClientHello Padding/21) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Pre Shared Key/41) for 'encrypted extensions' 175s [gnutls] (4) HSK[0xf4590000]: ENCRYPTED EXTENSIONS was queued [22 bytes] 175s [gnutls] (4) HSK[0xf4590000]: CERTIFICATE was queued [1155 bytes] 175s [gnutls] (4) checking cert compat with RSA-SHA256 175s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 175s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 175s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 175s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 175s [gnutls] (4) HSK[0xf4590000]: signing TLS 1.3 handshake data: using RSA-PSS-RSAE-SHA256 and PRF: SHA384 175s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 175s [gnutls] (4) HSK[0xf4590000]: CERTIFICATE VERIFY was queued [392 bytes] 175s [gnutls] (4) HSK[0xf4590000]: sending finished 175s [gnutls] (4) HSK[0xf4590000]: FINISHED was queued [52 bytes] 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 22 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 44 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 1155 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[2] Handshake(22) in epoch 1 and length: 1177 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 392 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[3] Handshake(22) in epoch 1 and length: 414 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 52 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[4] Handshake(22) in epoch 1 and length: 74 175s [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:965 175s [gnutls] (5) REC[0xf4590000]: Allocating epoch #2 175s [gnutls] (4) HSK[0xf4590000]: unauthenticated session eligible for early start 175s [gnutls] (5) REC[0xf4590000]: Initializing epoch #2 175s [gnutls] (5) REC[0xf4590000]: Epoch #2 ready 175s [gnutls] (4) HSK[0xf4590000]: TLS 1.3 set write key with cipher suite: GNUTLS_AES_256_GCM_SHA384 175s [gnutls] (4) HSK[0xf4590000]: switching early to application traffic keys 175s [gnutls] (4) HSK[0xf4590000]: NEW SESSION TICKET was queued [251 bytes] 175s [gnutls] (4) HSK[0xf4590000]: NEW SESSION TICKET was queued [251 bytes] 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[1] Handshake(22) in epoch 2 and length: 273 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[2] Handshake(22) in epoch 2 and length: 273 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 175s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 175s [gnutls] (5) REC[0xf4590000]: SSL 3.3 ChangeCipherSpec packet received. Epoch 1, length: 1 175s [gnutls] (5) REC[0xf4590000]: Expected Packet Handshake(22) 175s [gnutls] (5) REC[0xf4590000]: Received Packet ChangeCipherSpec(20) with length: 1 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 175s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 175s [gnutls] (5) REC[0xf4590000]: SSL 3.3 Application Data packet received. Epoch 1, length: 69 175s [gnutls] (5) REC[0xf4590000]: Expected Packet Handshake(22) 175s [gnutls] (5) REC[0xf4590000]: Received Packet Application Data(23) with length: 69 175s [gnutls] (5) REC[0xf4590000]: Decrypted Packet[0] Handshake(22) with length: 52 175s [gnutls] (4) HSK[0xf4590000]: FINISHED (20) was received. Length 48[48], frag offset 0, frag length: 48, sequence: 0 175s [gnutls] (4) HSK[0xf4590000]: parsing finished 175s [gnutls] (4) HSK[0xf4590000]: TLS 1.3 set read key with cipher suite: GNUTLS_AES_256_GCM_SHA384 175s [gnutls] (5) REC[0xf4590000]: Start of epoch cleanup 175s [gnutls] (5) REC[0xf4590000]: Epoch #0 freed 175s [gnutls] (5) REC[0xf4590000]: Epoch #1 freed 175s [gnutls] (5) REC[0xf4590000]: End of epoch cleanup 175s [tls ] TLS handshake with 127.0.0.1#42645 has completed 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 175s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1759 175s [gnutls] (5) REC[0xf4590000]: SSL 3.3 Application Data packet received. Epoch 2, length: 147 175s [gnutls] (5) REC[0xf4590000]: Expected Packet Application Data(23) 175s [gnutls] (5) REC[0xf4590000]: Received Packet Application Data(23) with length: 147 175s [gnutls] (5) REC[0xf4590000]: Decrypted Packet[0] Application Data(23) with length: 130 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 175s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1759 175s [plan ][00000.00] plan 'monkeys.example.' type 'A' uid [57541.00] 175s [iterat][57541.00] 'monkeys.example.' type 'A' new uid was assigned .01, parent uid .00 175s [hint ][57541.01] <= answered from hints 175s [iterat][57541.01] <= rcode: NOERROR 175s [resolv][57541.01] AD: request NOT classified as SECURE 175s [resolv][57541.01] finished in state: 4, queries: 1, mempool: 81936 B 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Application Data(23) with length: 470 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[3] Application Data(23) in epoch 2 and length: 492 175s [gnutls] (5) REC[0xf4590000]: SSL 3.3 Application Data packet received. Epoch 2, length: 19 175s [gnutls] (5) REC[0xf4590000]: Expected Packet Application Data(23) 175s [gnutls] (5) REC[0xf4590000]: Received Packet Application Data(23) with length: 19 175s [gnutls] (5) REC[0xf4590000]: Decrypted Packet[1] Alert(21) with length: 2 175s [gnutls] (5) REC[0xf4590000]: Alert[1|0] - Close notify - was received 175s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_in_buffers]:1565 175s [io ] => connection to '127.0.0.1#42645' closed by peer (end of file) 175s [gnutls] (5) REC[0xf4590000]: Start of epoch cleanup 175s [gnutls] (5) REC[0xf4590000]: End of epoch cleanup 175s [gnutls] (5) REC[0xf4590000]: Epoch #2 freed 175s [gnutls] (5) REC[0xf4590000]: Allocating epoch #0 175s [gnutls] (2) added 3 protocols, 29 ciphersuites, 19 sig algos and 10 groups into priority list 175s [gnutls] (5) REC[0xf4590000]: Allocating epoch #1 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 175s [gnutls] (5) REC[0xf4590000]: SSL 3.1 Handshake packet received. Epoch 0, length: 331 175s [gnutls] (5) REC[0xf4590000]: Expected Packet Handshake(22) 175s [gnutls] (5) REC[0xf4590000]: Received Packet Handshake(22) with length: 331 175s [gnutls] (5) REC[0xf4590000]: Decrypted Packet[0] Handshake(22) with length: 331 175s [gnutls] (4) HSK[0xf4590000]: CLIENT HELLO (1) was received. Length 327[327], frag offset 0, frag length: 327, sequence: 0 175s [gnutls] (4) HSK[0xf4590000]: Client's version: 3.3 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Supported Versions/43' (3 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Found version: 3.4 175s [gnutls] (4) EXT[0xf4590000]: Negotiated version: 3.4 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'ALPN/16' (6 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Extended Master Secret/23' (0 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Server Name Indication/0' (17 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Encrypt-then-MAC/22' (0 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Safe Renegotiation/65281' (1 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Record Size Limit/28' (2 bytes) 175s [gnutls] (4) EXT[0xf4590000]: record_size_limit 16385 negotiated 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Supported Groups/10' (10 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Received group X25519 (0x1d) 175s [gnutls] (4) EXT[0xf4590000]: Received group SECP256R1 (0x17) 175s [gnutls] (4) EXT[0xf4590000]: Received group SECP384R1 (0x18) 175s [gnutls] (4) EXT[0xf4590000]: Received group SECP521R1 (0x19) 175s [gnutls] (4) EXT[0xf4590000]: Selected group X25519 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Session Ticket/35' (0 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Signature Algorithms/13' (34 bytes) 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (4.1) RSA-SHA256 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.9) RSA-PSS-SHA256 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.4) RSA-PSS-RSAE-SHA256 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (4.3) ECDSA-SECP256R1-SHA256 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.7) EdDSA-Ed25519 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (5.1) RSA-SHA384 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.10) RSA-PSS-SHA384 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.5) RSA-PSS-RSAE-SHA384 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (5.3) ECDSA-SECP384R1-SHA384 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.8) EdDSA-Ed448 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (6.1) RSA-SHA512 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.11) RSA-PSS-SHA512 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.6) RSA-PSS-RSAE-SHA512 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (6.3) ECDSA-SECP521R1-SHA512 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (2.1) RSA-SHA1 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (2.3) ECDSA-SHA1 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'PSK Key Exchange Modes/45' (3 bytes) 175s [gnutls] (4) EXT[0xf4590000]: PSK KE mode 01 received 175s [gnutls] (4) EXT[0xf4590000]: PSK KE mode 00 received 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Supported EC Point Formats/11' (2 bytes) 175s [gnutls] (2) checking 13.02 (GNUTLS_AES_256_GCM_SHA384) for compatibility 175s [gnutls] (4) HSK[0xf4590000]: Requested server name: 'test.example' 175s [gnutls] (4) checking cert compat with RSA-SHA256 175s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 175s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 175s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 175s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 175s [gnutls] (4) Selected signature algorithm: RSA-PSS-RSAE-SHA256 175s [gnutls] (2) Selected (RSA) cert based on ciphersuite 13.2: GNUTLS_AES_256_GCM_SHA384 175s [gnutls] (4) HSK[0xf4590000]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384 175s [gnutls] (4) HSK[0xf4590000]: Selected version TLS1.3 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Key Share/51' (107 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Received key share for X25519 175s [gnutls] (4) HSK[0xf4590000]: Selected group X25519 (6) 175s [gnutls] (2) EXT[0xf4590000]: server generated X25519 shared key 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'OCSP Status Request/5' (5 bytes) 175s [gnutls] (4) EXT[0xf4590000]: OCSP status was requested 175s [gnutls] (4) HSK[0xf4590000]: Safe renegotiation succeeded 175s [gnutls] (4) HSK[0xf4590000]: SessionID: f830eaf9759b10266bba1a41d6522bd779ea1062b7ffc70cb00f5e12cd80aa2f 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (OCSP Status Request/5) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Client Certificate Type/19) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Server Certificate Type/20) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Supported Groups/10) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Supported EC Point Formats/11) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Signature Algorithms/13) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (SRTP/14) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (ALPN/16) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Encrypt-then-MAC/22) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Extended Master Secret/23) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Session Ticket/35) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Key Share/51) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: sending key share for X25519 175s [gnutls] (4) EXT[0xf4590000]: Sending extension Key Share/51 (36 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Supported Versions/43) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Sending extension Supported Versions/43 (2 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Post Handshake Auth/49) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Safe Renegotiation/65281) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Server Name Indication/0) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Cookie/44) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Early Data/42) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (PSK Key Exchange Modes/45) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Record Size Limit/28) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Maximum Record Size/1) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Compress Certificate/27) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (ClientHello Padding/21) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Pre Shared Key/41) for 'TLS 1.3 server hello' 175s [gnutls] (4) HSK[0xf4590000]: SERVER HELLO was queued [122 bytes] 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 122 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 127 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6 175s [gnutls] (4) REC[0xf4590000]: Sent ChangeCipherSpec 175s [gnutls] (5) REC[0xf4590000]: Initializing epoch #1 175s [gnutls] (5) REC[0xf4590000]: Epoch #1 ready 175s [gnutls] (4) HSK[0xf4590000]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (OCSP Status Request/5) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Client Certificate Type/19) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Server Certificate Type/20) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Supported Groups/10) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Supported EC Point Formats/11) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Signature Algorithms/13) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (SRTP/14) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (ALPN/16) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Sending extension ALPN/16 (6 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Encrypt-then-MAC/22) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Extended Master Secret/23) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Session Ticket/35) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Key Share/51) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Supported Versions/43) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Post Handshake Auth/49) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Safe Renegotiation/65281) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Server Name Indication/0) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Cookie/44) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Early Data/42) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (PSK Key Exchange Modes/45) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Record Size Limit/28) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Sending extension Record Size Limit/28 (2 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Maximum Record Size/1) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Compress Certificate/27) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (ClientHello Padding/21) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Pre Shared Key/41) for 'encrypted extensions' 175s [gnutls] (4) HSK[0xf4590000]: ENCRYPTED EXTENSIONS was queued [22 bytes] 175s [gnutls] (4) HSK[0xf4590000]: CERTIFICATE was queued [1155 bytes] 175s [gnutls] (4) checking cert compat with RSA-SHA256 175s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 175s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 175s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 175s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 175s [gnutls] (4) HSK[0xf4590000]: signing TLS 1.3 handshake data: using RSA-PSS-RSAE-SHA256 and PRF: SHA384 175s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 175s [gnutls] (4) HSK[0xf4590000]: CERTIFICATE VERIFY was queued [392 bytes] 175s [gnutls] (4) HSK[0xf4590000]: sending finished 175s [gnutls] (4) HSK[0xf4590000]: FINISHED was queued [52 bytes] 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 22 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 44 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 1155 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[2] Handshake(22) in epoch 1 and length: 1177 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 392 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[3] Handshake(22) in epoch 1 and length: 414 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 52 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[4] Handshake(22) in epoch 1 and length: 74 175s [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:965 175s [gnutls] (5) REC[0xf4590000]: Allocating epoch #2 175s [gnutls] (4) HSK[0xf4590000]: unauthenticated session eligible for early start 175s [gnutls] (5) REC[0xf4590000]: Initializing epoch #2 175s [gnutls] (5) REC[0xf4590000]: Epoch #2 ready 175s [gnutls] (4) HSK[0xf4590000]: TLS 1.3 set write key with cipher suite: GNUTLS_AES_256_GCM_SHA384 175s [gnutls] (4) HSK[0xf4590000]: switching early to application traffic keys 175s [gnutls] (4) HSK[0xf4590000]: NEW SESSION TICKET was queued [251 bytes] 175s [gnutls] (4) HSK[0xf4590000]: NEW SESSION TICKET was queued [251 bytes] 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[1] Handshake(22) in epoch 2 and length: 273 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[2] Handshake(22) in epoch 2 and length: 273 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 175s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 175s [gnutls] (5) REC[0xf4590000]: SSL 3.3 ChangeCipherSpec packet received. Epoch 1, length: 1 175s [gnutls] (5) REC[0xf4590000]: Expected Packet Handshake(22) 175s [gnutls] (5) REC[0xf4590000]: Received Packet ChangeCipherSpec(20) with length: 1 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 175s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 175s [gnutls] (5) REC[0xf4590000]: SSL 3.3 Application Data packet received. Epoch 1, length: 69 175s [gnutls] (5) REC[0xf4590000]: Expected Packet Handshake(22) 175s [gnutls] (5) REC[0xf4590000]: Received Packet Application Data(23) with length: 69 175s [gnutls] (5) REC[0xf4590000]: Decrypted Packet[0] Handshake(22) with length: 52 175s [gnutls] (4) HSK[0xf4590000]: FINISHED (20) was received. Length 48[48], frag offset 0, frag length: 48, sequence: 0 175s [gnutls] (4) HSK[0xf4590000]: parsing finished 175s [gnutls] (4) HSK[0xf4590000]: TLS 1.3 set read key with cipher suite: GNUTLS_AES_256_GCM_SHA384 175s [gnutls] (5) REC[0xf4590000]: Start of epoch cleanup 175s [gnutls] (5) REC[0xf4590000]: Epoch #0 freed 175s [gnutls] (5) REC[0xf4590000]: Epoch #1 freed 175s [gnutls] (5) REC[0xf4590000]: End of epoch cleanup 175s [tls ] TLS handshake with 127.0.0.1#39721 has completed 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 175s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1759 175s [gnutls] (5) REC[0xf4590000]: SSL 3.3 Application Data packet received. Epoch 2, length: 147 175s [gnutls] (5) REC[0xf4590000]: Expected Packet Application Data(23) 175s [gnutls] (5) REC[0xf4590000]: Received Packet Application Data(23) with length: 147 175s [gnutls] (5) REC[0xf4590000]: Decrypted Packet[0] Application Data(23) with length: 130 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 175s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1759 175s [plan ][00000.00] plan 'monkeys.example.' type 'A' uid [07023.00] 175s [iterat][07023.00] 'monkeys.example.' type 'A' new uid was assigned .01, parent uid .00 175s [hint ][07023.01] <= answered from hints 175s [iterat][07023.01] <= rcode: NOERROR 175s [resolv][07023.01] AD: request NOT classified as SECURE 175s [resolv][07023.01] finished in state: 4, queries: 1, mempool: 81936 B 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Application Data(23) with length: 470 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[3] Application Data(23) in epoch 2 and length: 492 175s [gnutls] (5) REC[0xf4590000]: SSL 3.3 Application Data packet received. Epoch 2, length: 19 175s [gnutls] (5) REC[0xf4590000]: Expected Packet Application Data(23) 175s [gnutls] (5) REC[0xf4590000]: Received Packet Application Data(23) with length: 19 175s [gnutls] (5) REC[0xf4590000]: Decrypted Packet[1] Alert(21) with length: 2 175s [gnutls] (5) REC[0xf4590000]: Alert[1|0] - Close notify - was received 175s [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_in_buffers]:1565 175s [io ] => connection to '127.0.0.1#39721' closed by peer (end of file) 175s [gnutls] (5) REC[0xf4590000]: Start of epoch cleanup 175s [gnutls] (5) REC[0xf4590000]: End of epoch cleanup 175s [gnutls] (5) REC[0xf4590000]: Epoch #2 freed 175s [gnutls] (5) REC[0xf4590000]: Allocating epoch #0 175s [gnutls] (2) added 3 protocols, 29 ciphersuites, 19 sig algos and 10 groups into priority list 175s [gnutls] (5) REC[0xf4590000]: Allocating epoch #1 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 175s [gnutls] (5) REC[0xf4590000]: SSL 3.1 Handshake packet received. Epoch 0, length: 335 175s [gnutls] (5) REC[0xf4590000]: Expected Packet Handshake(22) 175s [gnutls] (5) REC[0xf4590000]: Received Packet Handshake(22) with length: 335 175s [gnutls] (5) REC[0xf4590000]: Decrypted Packet[0] Handshake(22) with length: 335 175s [gnutls] (4) HSK[0xf4590000]: CLIENT HELLO (1) was received. Length 331[331], frag offset 0, frag length: 331, sequence: 0 175s [gnutls] (4) HSK[0xf4590000]: Client's version: 3.3 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Supported Versions/43' (3 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Found version: 3.4 175s [gnutls] (4) EXT[0xf4590000]: Negotiated version: 3.4 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Encrypt-then-MAC/22' (0 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Extended Master Secret/23' (0 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'ALPN/16' (6 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Record Size Limit/28' (2 bytes) 175s [gnutls] (4) EXT[0xf4590000]: record_size_limit 16385 negotiated 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Safe Renegotiation/65281' (1 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Server Name Indication/0' (21 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'PSK Key Exchange Modes/45' (3 bytes) 175s [gnutls] (4) EXT[0xf4590000]: PSK KE mode 01 received 175s [gnutls] (4) EXT[0xf4590000]: PSK KE mode 00 received 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Signature Algorithms/13' (34 bytes) 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (4.1) RSA-SHA256 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.9) RSA-PSS-SHA256 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.4) RSA-PSS-RSAE-SHA256 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (4.3) ECDSA-SECP256R1-SHA256 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.7) EdDSA-Ed25519 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (5.1) RSA-SHA384 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.10) RSA-PSS-SHA384 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.5) RSA-PSS-RSAE-SHA384 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (5.3) ECDSA-SECP384R1-SHA384 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.8) EdDSA-Ed448 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (6.1) RSA-SHA512 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.11) RSA-PSS-SHA512 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.6) RSA-PSS-RSAE-SHA512 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (6.3) ECDSA-SECP521R1-SHA512 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (2.1) RSA-SHA1 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (2.3) ECDSA-SHA1 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Supported EC Point Formats/11' (2 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Session Ticket/35' (0 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Supported Groups/10' (10 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Received group X25519 (0x1d) 175s [gnutls] (4) EXT[0xf4590000]: Received group SECP256R1 (0x17) 175s [gnutls] (4) EXT[0xf4590000]: Received group SECP384R1 (0x18) 175s [gnutls] (4) EXT[0xf4590000]: Received group SECP521R1 (0x19) 175s [gnutls] (4) EXT[0xf4590000]: Selected group X25519 175s [gnutls] (2) checking 13.02 (GNUTLS_AES_256_GCM_SHA384) for compatibility 175s [gnutls] (4) HSK[0xf4590000]: Requested server name: 'notright.example' 175s [gnutls] (4) HSK[0xf4590000]: checking compat of GNUTLS_AES_256_GCM_SHA384 with certificate[0] (RSA/X.509) 175s [gnutls] (4) checking cert compat with RSA-SHA256 175s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 175s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 175s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 175s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 175s [gnutls] (4) Selected signature algorithm: RSA-PSS-RSAE-SHA256 175s [gnutls] (2) Selected (RSA) cert based on ciphersuite 13.2: GNUTLS_AES_256_GCM_SHA384 175s [gnutls] (4) HSK[0xf4590000]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384 175s [gnutls] (4) HSK[0xf4590000]: Selected version TLS1.3 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'OCSP Status Request/5' (5 bytes) 175s [gnutls] (4) EXT[0xf4590000]: OCSP status was requested 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Key Share/51' (107 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Received key share for X25519 175s [gnutls] (4) HSK[0xf4590000]: Selected group X25519 (6) 175s [gnutls] (2) EXT[0xf4590000]: server generated X25519 shared key 175s [gnutls] (4) HSK[0xf4590000]: Safe renegotiation succeeded 175s [gnutls] (4) HSK[0xf4590000]: SessionID: 459a78a0bd3b23911a3370e7e7afa49ef86e9df0a78b86bfe868b5c18eca232f 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (OCSP Status Request/5) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Client Certificate Type/19) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Server Certificate Type/20) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Supported Groups/10) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Supported EC Point Formats/11) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Signature Algorithms/13) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (SRTP/14) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (ALPN/16) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Encrypt-then-MAC/22) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Extended Master Secret/23) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Session Ticket/35) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Key Share/51) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: sending key share for X25519 175s [gnutls] (4) EXT[0xf4590000]: Sending extension Key Share/51 (36 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Supported Versions/43) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Sending extension Supported Versions/43 (2 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Post Handshake Auth/49) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Safe Renegotiation/65281) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Server Name Indication/0) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Cookie/44) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Early Data/42) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (PSK Key Exchange Modes/45) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Record Size Limit/28) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Maximum Record Size/1) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Compress Certificate/27) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (ClientHello Padding/21) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Pre Shared Key/41) for 'TLS 1.3 server hello' 175s [gnutls] (4) HSK[0xf4590000]: SERVER HELLO was queued [122 bytes] 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 122 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 127 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6 175s [gnutls] (4) REC[0xf4590000]: Sent ChangeCipherSpec 175s [gnutls] (5) REC[0xf4590000]: Initializing epoch #1 175s [gnutls] (5) REC[0xf4590000]: Epoch #1 ready 175s [gnutls] (4) HSK[0xf4590000]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (OCSP Status Request/5) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Client Certificate Type/19) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Server Certificate Type/20) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Supported Groups/10) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Supported EC Point Formats/11) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Signature Algorithms/13) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (SRTP/14) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (ALPN/16) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Sending extension ALPN/16 (6 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Encrypt-then-MAC/22) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Extended Master Secret/23) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Session Ticket/35) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Key Share/51) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Supported Versions/43) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Post Handshake Auth/49) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Safe Renegotiation/65281) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Server Name Indication/0) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Cookie/44) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Early Data/42) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (PSK Key Exchange Modes/45) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Record Size Limit/28) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Sending extension Record Size Limit/28 (2 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Maximum Record Size/1) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Compress Certificate/27) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (ClientHello Padding/21) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Pre Shared Key/41) for 'encrypted extensions' 175s [gnutls] (4) HSK[0xf4590000]: ENCRYPTED EXTENSIONS was queued [22 bytes] 175s [gnutls] (4) HSK[0xf4590000]: CERTIFICATE was queued [1155 bytes] 175s [gnutls] (4) checking cert compat with RSA-SHA256 175s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 175s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 175s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 175s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 175s [gnutls] (4) HSK[0xf4590000]: signing TLS 1.3 handshake data: using RSA-PSS-RSAE-SHA256 and PRF: SHA384 175s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 175s [gnutls] (4) HSK[0xf4590000]: CERTIFICATE VERIFY was queued [392 bytes] 175s [gnutls] (4) HSK[0xf4590000]: sending finished 175s [gnutls] (4) HSK[0xf4590000]: FINISHED was queued [52 bytes] 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 22 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 44 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 1155 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[2] Handshake(22) in epoch 1 and length: 1177 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 392 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[3] Handshake(22) in epoch 1 and length: 414 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 52 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[4] Handshake(22) in epoch 1 and length: 74 175s [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:965 175s [gnutls] (5) REC[0xf4590000]: Allocating epoch #2 175s [gnutls] (4) HSK[0xf4590000]: unauthenticated session eligible for early start 175s [gnutls] (5) REC[0xf4590000]: Initializing epoch #2 175s [gnutls] (5) REC[0xf4590000]: Epoch #2 ready 175s [gnutls] (4) HSK[0xf4590000]: TLS 1.3 set write key with cipher suite: GNUTLS_AES_256_GCM_SHA384 175s [gnutls] (4) HSK[0xf4590000]: switching early to application traffic keys 175s [gnutls] (4) HSK[0xf4590000]: NEW SESSION TICKET was queued [251 bytes] 175s [gnutls] (4) HSK[0xf4590000]: NEW SESSION TICKET was queued [251 bytes] 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[1] Handshake(22) in epoch 2 and length: 273 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[2] Handshake(22) in epoch 2 and length: 273 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 175s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 175s [gnutls] (5) REC[0xf4590000]: SSL 3.3 ChangeCipherSpec packet received. Epoch 1, length: 1 175s [gnutls] (5) REC[0xf4590000]: Expected Packet Handshake(22) 175s [gnutls] (5) REC[0xf4590000]: Received Packet ChangeCipherSpec(20) with length: 1 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 175s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 175s [io ] => connection to '127.0.0.1#37153' closed by peer (connection reset by peer) 175s [gnutls] (5) REC[0xf4590000]: Start of epoch cleanup 175s [gnutls] (5) REC[0xf4590000]: Epoch #0 freed 175s [gnutls] (5) REC[0xf4590000]: End of epoch cleanup 175s [gnutls] (5) REC[0xf4590000]: Epoch #1 freed 175s [gnutls] (5) REC[0xf4590000]: Epoch #2 freed 175s [gnutls] (5) REC[0xf4590000]: Allocating epoch #0 175s [gnutls] (2) added 3 protocols, 29 ciphersuites, 19 sig algos and 10 groups into priority list 175s [gnutls] (5) REC[0xf4590000]: Allocating epoch #1 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 175s [gnutls] (5) REC[0xf4590000]: SSL 3.1 Handshake packet received. Epoch 0, length: 331 175s [gnutls] (5) REC[0xf4590000]: Expected Packet Handshake(22) 175s [gnutls] (5) REC[0xf4590000]: Received Packet Handshake(22) with length: 331 175s [gnutls] (5) REC[0xf4590000]: Decrypted Packet[0] Handshake(22) with length: 331 175s [gnutls] (4) HSK[0xf4590000]: CLIENT HELLO (1) was received. Length 327[327], frag offset 0, frag length: 327, sequence: 0 175s [gnutls] (4) HSK[0xf4590000]: Client's version: 3.3 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Supported Versions/43' (3 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Found version: 3.4 175s [gnutls] (4) EXT[0xf4590000]: Negotiated version: 3.4 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Encrypt-then-MAC/22' (0 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Record Size Limit/28' (2 bytes) 175s [gnutls] (4) EXT[0xf4590000]: record_size_limit 16385 negotiated 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'ALPN/16' (6 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Safe Renegotiation/65281' (1 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Extended Master Secret/23' (0 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Server Name Indication/0' (17 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'PSK Key Exchange Modes/45' (3 bytes) 175s [gnutls] (4) EXT[0xf4590000]: PSK KE mode 01 received 175s [gnutls] (4) EXT[0xf4590000]: PSK KE mode 00 received 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Signature Algorithms/13' (34 bytes) 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (4.1) RSA-SHA256 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.9) RSA-PSS-SHA256 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.4) RSA-PSS-RSAE-SHA256 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (4.3) ECDSA-SECP256R1-SHA256 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.7) EdDSA-Ed25519 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (5.1) RSA-SHA384 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.10) RSA-PSS-SHA384 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.5) RSA-PSS-RSAE-SHA384 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (5.3) ECDSA-SECP384R1-SHA384 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.8) EdDSA-Ed448 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (6.1) RSA-SHA512 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.11) RSA-PSS-SHA512 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (8.6) RSA-PSS-RSAE-SHA512 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (6.3) ECDSA-SECP521R1-SHA512 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (2.1) RSA-SHA1 175s [gnutls] (4) EXT[0xf4590000]: rcvd signature algo (2.3) ECDSA-SHA1 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Supported Groups/10' (10 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Received group X25519 (0x1d) 175s [gnutls] (4) EXT[0xf4590000]: Received group SECP256R1 (0x17) 175s [gnutls] (4) EXT[0xf4590000]: Received group SECP384R1 (0x18) 175s [gnutls] (4) EXT[0xf4590000]: Received group SECP521R1 (0x19) 175s [gnutls] (4) EXT[0xf4590000]: Selected group X25519 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Session Ticket/35' (0 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Supported EC Point Formats/11' (2 bytes) 175s [gnutls] (2) checking 13.02 (GNUTLS_AES_256_GCM_SHA384) for compatibility 175s [gnutls] (4) HSK[0xf4590000]: Requested server name: 'test.example' 175s [gnutls] (4) checking cert compat with RSA-SHA256 175s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 175s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 175s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 175s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 175s [gnutls] (4) Selected signature algorithm: RSA-PSS-RSAE-SHA256 175s [gnutls] (2) Selected (RSA) cert based on ciphersuite 13.2: GNUTLS_AES_256_GCM_SHA384 175s [gnutls] (4) HSK[0xf4590000]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384 175s [gnutls] (4) HSK[0xf4590000]: Selected version TLS1.3 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'OCSP Status Request/5' (5 bytes) 175s [gnutls] (4) EXT[0xf4590000]: OCSP status was requested 175s [gnutls] (4) EXT[0xf4590000]: Parsing extension 'Key Share/51' (107 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Received key share for X25519 175s [gnutls] (4) HSK[0xf4590000]: Selected group X25519 (6) 175s [gnutls] (2) EXT[0xf4590000]: server generated X25519 shared key 175s [gnutls] (4) HSK[0xf4590000]: Safe renegotiation succeeded 175s [gnutls] (4) HSK[0xf4590000]: SessionID: b49ab576fb77a6d244f1b5bbae087216aaab867468119f935055cefd0a3f13eb 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (OCSP Status Request/5) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Client Certificate Type/19) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Server Certificate Type/20) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Supported Groups/10) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Supported EC Point Formats/11) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Signature Algorithms/13) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (SRTP/14) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (ALPN/16) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Encrypt-then-MAC/22) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Extended Master Secret/23) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Session Ticket/35) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Key Share/51) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: sending key share for X25519 175s [gnutls] (4) EXT[0xf4590000]: Sending extension Key Share/51 (36 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Supported Versions/43) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Sending extension Supported Versions/43 (2 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Post Handshake Auth/49) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Safe Renegotiation/65281) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Server Name Indication/0) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Cookie/44) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Early Data/42) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (PSK Key Exchange Modes/45) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Record Size Limit/28) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Maximum Record Size/1) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Compress Certificate/27) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (ClientHello Padding/21) for 'TLS 1.3 server hello' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Pre Shared Key/41) for 'TLS 1.3 server hello' 175s [gnutls] (4) HSK[0xf4590000]: SERVER HELLO was queued [122 bytes] 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 122 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 127 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6 175s [gnutls] (4) REC[0xf4590000]: Sent ChangeCipherSpec 175s [gnutls] (5) REC[0xf4590000]: Initializing epoch #1 175s [gnutls] (5) REC[0xf4590000]: Epoch #1 ready 175s [gnutls] (4) HSK[0xf4590000]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (OCSP Status Request/5) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Client Certificate Type/19) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Server Certificate Type/20) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Supported Groups/10) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Supported EC Point Formats/11) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Signature Algorithms/13) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (SRTP/14) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (ALPN/16) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Sending extension ALPN/16 (6 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Encrypt-then-MAC/22) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Extended Master Secret/23) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Session Ticket/35) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Key Share/51) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Supported Versions/43) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Post Handshake Auth/49) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Safe Renegotiation/65281) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Server Name Indication/0) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Cookie/44) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Early Data/42) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (PSK Key Exchange Modes/45) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Record Size Limit/28) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Sending extension Record Size Limit/28 (2 bytes) 175s [gnutls] (4) EXT[0xf4590000]: Preparing extension (Maximum Record Size/1) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Compress Certificate/27) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (ClientHello Padding/21) for 'encrypted extensions' 175s [gnutls] (4) EXT[0xf4590000]: Not sending extension (Pre Shared Key/41) for 'encrypted extensions' 175s [gnutls] (4) HSK[0xf4590000]: ENCRYPTED EXTENSIONS was queued [22 bytes] 175s [gnutls] (4) HSK[0xf4590000]: CERTIFICATE was queued [1155 bytes] 175s [gnutls] (4) checking cert compat with RSA-SHA256 175s [gnutls] (3) ASSERT: ../../../lib/ext/signature.c[_gnutls_session_sign_algo_enabled]:428 175s [gnutls] (4) Signature algorithm RSA-SHA256 is not enabled 175s [gnutls] (4) checking cert compat with RSA-PSS-SHA256 175s [gnutls] (4) checking cert compat with RSA-PSS-RSAE-SHA256 175s [gnutls] (4) HSK[0xf4590000]: signing TLS 1.3 handshake data: using RSA-PSS-RSAE-SHA256 and PRF: SHA384 175s [gnutls] (3) ASSERT: ../../../lib/nettle/mpi.c[wrap_nettle_mpi_print]:59 175s [gnutls] (4) HSK[0xf4590000]: CERTIFICATE VERIFY was queued [392 bytes] 175s [gnutls] (4) HSK[0xf4590000]: sending finished 175s [gnutls] (4) HSK[0xf4590000]: FINISHED was queued [52 bytes] 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 22 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 44 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 1155 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[2] Handshake(22) in epoch 1 and length: 1177 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 392 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[3] Handshake(22) in epoch 1 and length: 414 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 52 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[4] Handshake(22) in epoch 1 and length: 74 175s [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:965 175s [gnutls] (5) REC[0xf4590000]: Allocating epoch #2 175s [gnutls] (4) HSK[0xf4590000]: unauthenticated session eligible for early start 175s [gnutls] (5) REC[0xf4590000]: Initializing epoch #2 175s [gnutls] (5) REC[0xf4590000]: Epoch #2 ready 175s [gnutls] (4) HSK[0xf4590000]: TLS 1.3 set write key with cipher suite: GNUTLS_AES_256_GCM_SHA384 175s [gnutls] (4) HSK[0xf4590000]: switching early to application traffic keys 175s [gnutls] (4) HSK[0xf4590000]: NEW SESSION TICKET was queued [251 bytes] 175s [gnutls] (4) HSK[0xf4590000]: NEW SESSION TICKET was queued [251 bytes] 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[1] Handshake(22) in epoch 2 and length: 273 175s [gnutls] (5) REC[0xf4590000]: Preparing Packet Handshake(22) with length: 251 and min pad: 0 175s [gnutls] (5) REC[0xf4590000]: Sent Packet[2] Handshake(22) in epoch 2 and length: 273 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 175s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1138 175s [gnutls] (5) REC[0xf4590000]: SSL 3.3 ChangeCipherSpec packet received. Epoch 1, length: 1 175s [gnutls] (5) REC[0xf4590000]: Expected Packet Handshake(22) 175s [gnutls] (5) REC[0xf4590000]: Received Packet ChangeCipherSpec(20) with length: 1 175s [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:568 175s [gnutls] (3) ASSERT: ../../lib/tls13/finished.c[_gnutls13_recv_finished]:91 175s [io ] => connection to '127.0.0.1#36367' closed by peer (connection reset by peer) 175s [gnutls] (5) REC[0xf4590000]: Start of epoch cleanup 175s [gnutls] (5) REC[0xf4590000]: Epoch #0 freed 175s [gnutls] (5) REC[0xf4590000]: End of epoch cleanup 175s [gnutls] (5) REC[0xf4590000]: Epoch #1 freed 175s [gnutls] (5) REC[0xf4590000]: Epoch #2 freed 175s > 175s > autopkgtest [07:30:16]: test roundtrip: -----------------------] 179s autopkgtest [07:30:20]: test roundtrip: - - - - - - - - - - results - - - - - - - - - - 179s roundtrip PASS 185s autopkgtest [07:30:26]: @@@@@@@@@@@@@@@@@@@@ summary 185s roundtrip PASS