0s autopkgtest [10:08:47]: starting date and time: 2024-04-16 10:08:47+0000 1s autopkgtest [10:08:48]: git checkout: 43bc6cdf gitlab-ci: do not include the salsa pipeline 1s autopkgtest [10:08:48]: host juju-7f2275-prod-proposed-migration-environment-2; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.f4ipwo0d/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:debconf --apt-upgrade openssh --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=debconf/1.5.86ubuntu1 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@bos01-s390x-3.secgroup --name adt-noble-s390x-openssh-20240416-100847-juju-7f2275-prod-proposed-migration-environment-2-91ba491c-d753-447a-9956-4f72d91f1948 --image adt/ubuntu-noble-s390x-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-2 --net-id=net_prod-proposed-migration -e TERM=linux -e ''"'"'http_proxy=http://squid.internal:3128'"'"'' -e ''"'"'https_proxy=http://squid.internal:3128'"'"'' -e ''"'"'no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com'"'"'' --mirror=http://us.ports.ubuntu.com/ubuntu-ports/ 138s autopkgtest [10:11:05]: testbed dpkg architecture: s390x 138s autopkgtest [10:11:05]: testbed apt version: 2.7.14build2 138s autopkgtest [10:11:05]: @@@@@@@@@@@@@@@@@@@@ test bed setup 138s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [117 kB] 139s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [331 kB] 139s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/multiverse Sources [2340 B] 139s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [239 kB] 139s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [7736 B] 139s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main s390x Packages [268 kB] 139s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main s390x c-n-f Metadata [3032 B] 139s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/restricted s390x Packages [976 B] 139s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/restricted s390x c-n-f Metadata [116 B] 139s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/universe s390x Packages [371 kB] 139s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/universe s390x c-n-f Metadata [7292 B] 139s Get:12 http://ftpmaster.internal/ubuntu noble-proposed/multiverse s390x c-n-f Metadata [116 B] 141s Fetched 1348 kB in 1s (1322 kB/s) 141s Reading package lists... 145s Reading package lists... 146s Building dependency tree... 146s Reading state information... 146s Calculating upgrade... 146s The following packages will be upgraded: 146s debconf debconf-i18n ftp python3-cffi-backend python3-debconf tcpdump tnftp 146s 7 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 146s Need to get 1016 kB of archives. 146s After this operation, 199 kB disk space will be freed. 146s Get:1 http://ftpmaster.internal/ubuntu noble-proposed/main s390x python3-debconf all 1.5.86ubuntu1 [4158 B] 146s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/main s390x debconf-i18n all 1.5.86ubuntu1 [205 kB] 147s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/main s390x debconf all 1.5.86ubuntu1 [124 kB] 147s Get:4 http://ftpmaster.internal/ubuntu noble/main s390x python3-cffi-backend s390x 1.16.0-2build1 [81.4 kB] 147s Get:5 http://ftpmaster.internal/ubuntu noble/main s390x tnftp s390x 20230507-2build3 [107 kB] 147s Get:6 http://ftpmaster.internal/ubuntu noble/main s390x ftp all 20230507-2build3 [4728 B] 147s Get:7 http://ftpmaster.internal/ubuntu noble/main s390x tcpdump s390x 4.99.4-3ubuntu4 [490 kB] 148s Preconfiguring packages ... 148s Fetched 1016 kB in 1s (1429 kB/s) 148s (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 ... 78332 files and directories currently installed.) 148s Preparing to unpack .../python3-debconf_1.5.86ubuntu1_all.deb ... 148s Unpacking python3-debconf (1.5.86ubuntu1) over (1.5.86) ... 148s Preparing to unpack .../debconf-i18n_1.5.86ubuntu1_all.deb ... 148s Unpacking debconf-i18n (1.5.86ubuntu1) over (1.5.86) ... 148s Preparing to unpack .../debconf_1.5.86ubuntu1_all.deb ... 148s Unpacking debconf (1.5.86ubuntu1) over (1.5.86) ... 148s Setting up debconf (1.5.86ubuntu1) ... 149s (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 ... 78332 files and directories currently installed.) 149s Preparing to unpack .../python3-cffi-backend_1.16.0-2build1_s390x.deb ... 149s Unpacking python3-cffi-backend:s390x (1.16.0-2build1) over (1.16.0-2) ... 149s Preparing to unpack .../tnftp_20230507-2build3_s390x.deb ... 149s Unpacking tnftp (20230507-2build3) over (20230507-2build2) ... 149s Preparing to unpack .../ftp_20230507-2build3_all.deb ... 149s Unpacking ftp (20230507-2build3) over (20230507-2build2) ... 149s Preparing to unpack .../tcpdump_4.99.4-3ubuntu4_s390x.deb ... 149s Unpacking tcpdump (4.99.4-3ubuntu4) over (4.99.4-3ubuntu3) ... 149s Setting up tcpdump (4.99.4-3ubuntu4) ... 149s Setting up python3-debconf (1.5.86ubuntu1) ... 149s Setting up debconf-i18n (1.5.86ubuntu1) ... 149s Setting up tnftp (20230507-2build3) ... 149s Setting up python3-cffi-backend:s390x (1.16.0-2build1) ... 149s Setting up ftp (20230507-2build3) ... 149s Processing triggers for man-db (2.12.0-4build1) ... 151s Reading package lists... 152s Building dependency tree... 152s Reading state information... 152s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 153s Hit:1 http://ftpmaster.internal/ubuntu noble InRelease 153s Hit:2 http://ftpmaster.internal/ubuntu noble-updates InRelease 153s Hit:3 http://ftpmaster.internal/ubuntu noble-security InRelease 153s Hit:4 http://ftpmaster.internal/ubuntu noble-proposed InRelease 155s Reading package lists... 155s Reading package lists... 156s Building dependency tree... 156s Reading state information... 156s Calculating upgrade... 156s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 156s Reading package lists... 157s Building dependency tree... 157s Reading state information... 157s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 160s autopkgtest [10:11:27]: testbed running kernel: Linux 6.8.0-22-generic #22-Ubuntu SMP Thu Apr 4 21:54:17 UTC 2024 161s autopkgtest [10:11:28]: @@@@@@@@@@@@@@@@@@@@ apt-source openssh 168s Get:1 http://ftpmaster.internal/ubuntu noble/main openssh 1:9.6p1-3ubuntu13 (dsc) [3334 B] 168s Get:2 http://ftpmaster.internal/ubuntu noble/main openssh 1:9.6p1-3ubuntu13 (tar) [1858 kB] 168s Get:3 http://ftpmaster.internal/ubuntu noble/main openssh 1:9.6p1-3ubuntu13 (asc) [833 B] 168s Get:4 http://ftpmaster.internal/ubuntu noble/main openssh 1:9.6p1-3ubuntu13 (diff) [203 kB] 168s gpgv: Signature made Mon Apr 8 16:02:01 2024 UTC 168s gpgv: using RSA key CED62F17BB727A48FC50762E2A15898770574541 168s gpgv: Can't check signature: No public key 168s dpkg-source: warning: cannot verify inline signature for ./openssh_9.6p1-3ubuntu13.dsc: no acceptable signature found 169s autopkgtest [10:11:36]: testing package openssh version 1:9.6p1-3ubuntu13 169s autopkgtest [10:11:36]: build not needed 170s autopkgtest [10:11:37]: test regress: preparing testbed 171s Reading package lists... 172s Building dependency tree... 172s Reading state information... 172s Starting pkgProblemResolver with broken count: 0 172s Starting 2 pkgProblemResolver with broken count: 0 172s Done 173s The following additional packages will be installed: 173s devscripts dropbear dropbear-bin libb-hooks-op-check-perl 173s libclass-method-modifiers-perl libclass-xsaccessor-perl libclone-perl 173s libdevel-callchecker-perl libdynaloader-functions-perl libencode-locale-perl 173s libfile-dirlist-perl libfile-homedir-perl libfile-listing-perl 173s libfile-touch-perl libfile-which-perl libhtml-parser-perl 173s libhtml-tagset-perl libhtml-tree-perl libhttp-cookies-perl libhttp-date-perl 173s libhttp-message-perl libhttp-negotiate-perl libimport-into-perl 173s libio-html-perl libio-pty-perl libio-socket-ssl-perl libipc-run-perl 173s liblwp-mediatypes-perl liblwp-protocol-https-perl libmodule-runtime-perl 173s libmoo-perl libnet-http-perl libnet-ssleay-perl libparams-classify-perl 173s librole-tiny-perl libsub-quote-perl libtimedate-perl libtomcrypt1 173s libtommath1 libtry-tiny-perl liburi-perl libwww-perl libwww-robotrules-perl 173s openssh-tests patchutils perl-openssl-defaults putty-tools python3-automat 173s python3-bcrypt python3-constantly python3-hamcrest python3-hyperlink 173s python3-incremental python3-pyasn1 python3-pyasn1-modules 173s python3-service-identity python3-twisted python3-zope.interface wdiff 173s Suggested packages: 173s adequate at autopkgtest bls-standalone bsd-mailx | mailx build-essential 173s check-all-the-things cvs-buildpackage debhelper diffoscope disorderfs 173s dose-extra duck elpa-devscripts faketime gnuplot how-can-i-help 173s libauthen-sasl-perl libdbd-pg-perl libfile-desktopentry-perl 173s libterm-size-perl libyaml-syck-perl mmdebstrap mutt piuparts 173s postgresql-client pristine-lfs quilt ratt reprotest svn-buildpackage w3m 173s debian-keyring equivs libgitlab-api-v4-perl libsoap-lite-perl pristine-tar 173s dropbear-initramfs runit libdata-dump-perl libio-compress-brotli-perl 173s libcrypt-ssleay-perl libscalar-number-perl libxstring-perl libsub-name-perl 173s libbusiness-isbn-perl libregexp-ipv6-perl libauthen-ntlm-perl putty-doc 173s python3-pampy python3-tk python3-wxgtk4.0 wdiff-doc 173s Recommended packages: 173s dctrl-tools dput | dupload libdistro-info-perl libgit-wrapper-perl 173s libjson-perl liblist-compare-perl libstring-shellquote-perl licensecheck 173s lintian python3-debian python3-magic python3-unidiff python3-xdg unzip 173s libhtml-format-perl libnamespace-clean-perl libdata-dump-perl 173s libhtml-form-perl libhttp-daemon-perl libmailtools-perl python3-click 173s The following NEW packages will be installed: 173s autopkgtest-satdep devscripts dropbear dropbear-bin libb-hooks-op-check-perl 173s libclass-method-modifiers-perl libclass-xsaccessor-perl libclone-perl 173s libdevel-callchecker-perl libdynaloader-functions-perl libencode-locale-perl 173s libfile-dirlist-perl libfile-homedir-perl libfile-listing-perl 173s libfile-touch-perl libfile-which-perl libhtml-parser-perl 173s libhtml-tagset-perl libhtml-tree-perl libhttp-cookies-perl libhttp-date-perl 173s libhttp-message-perl libhttp-negotiate-perl libimport-into-perl 173s libio-html-perl libio-pty-perl libio-socket-ssl-perl libipc-run-perl 173s liblwp-mediatypes-perl liblwp-protocol-https-perl libmodule-runtime-perl 173s libmoo-perl libnet-http-perl libnet-ssleay-perl libparams-classify-perl 173s librole-tiny-perl libsub-quote-perl libtimedate-perl libtomcrypt1 173s libtommath1 libtry-tiny-perl liburi-perl libwww-perl libwww-robotrules-perl 173s openssh-tests patchutils perl-openssl-defaults putty-tools python3-automat 173s python3-bcrypt python3-constantly python3-hamcrest python3-hyperlink 173s python3-incremental python3-pyasn1 python3-pyasn1-modules 173s python3-service-identity python3-twisted python3-zope.interface wdiff 173s 0 upgraded, 60 newly installed, 0 to remove and 0 not upgraded. 173s Need to get 8230 kB/8230 kB of archives. 173s After this operation, 36.8 MB of additional disk space will be used. 173s Get:1 /tmp/autopkgtest.KeoRc6/1-autopkgtest-satdep.deb autopkgtest-satdep s390x 0 [772 B] 173s Get:2 http://ftpmaster.internal/ubuntu noble/main s390x libtommath1 s390x 1.2.1-2 [56.4 kB] 173s Get:3 http://ftpmaster.internal/ubuntu noble/universe s390x libtomcrypt1 s390x 1.18.2+dfsg-7 [427 kB] 174s Get:4 http://ftpmaster.internal/ubuntu noble/universe s390x dropbear-bin s390x 2022.83-4 [156 kB] 175s Get:5 http://ftpmaster.internal/ubuntu noble/universe s390x dropbear all 2022.83-4 [9150 B] 175s Get:6 http://ftpmaster.internal/ubuntu noble/main s390x libfile-dirlist-perl all 0.05-3 [7286 B] 175s Get:7 http://ftpmaster.internal/ubuntu noble/main s390x libfile-which-perl all 1.27-2 [12.5 kB] 175s Get:8 http://ftpmaster.internal/ubuntu noble/main s390x libfile-homedir-perl all 1.006-2 [37.0 kB] 175s Get:9 http://ftpmaster.internal/ubuntu noble/main s390x libfile-touch-perl all 0.12-2 [7498 B] 175s Get:10 http://ftpmaster.internal/ubuntu noble/main s390x libio-pty-perl s390x 1:1.20-1build2 [31.3 kB] 175s Get:11 http://ftpmaster.internal/ubuntu noble/main s390x libipc-run-perl all 20231003.0-1 [92.1 kB] 175s Get:12 http://ftpmaster.internal/ubuntu noble/main s390x libclass-method-modifiers-perl all 2.15-1 [16.1 kB] 175s Get:13 http://ftpmaster.internal/ubuntu noble/main s390x libclass-xsaccessor-perl s390x 1.19-4build4 [35.0 kB] 175s Get:14 http://ftpmaster.internal/ubuntu noble/main s390x libb-hooks-op-check-perl s390x 0.22-3build1 [9458 B] 175s Get:15 http://ftpmaster.internal/ubuntu noble/main s390x libdynaloader-functions-perl all 0.003-3 [12.1 kB] 175s Get:16 http://ftpmaster.internal/ubuntu noble/main s390x libdevel-callchecker-perl s390x 0.008-2build3 [13.2 kB] 175s Get:17 http://ftpmaster.internal/ubuntu noble/main s390x libparams-classify-perl s390x 0.015-2build5 [20.6 kB] 175s Get:18 http://ftpmaster.internal/ubuntu noble/main s390x libmodule-runtime-perl all 0.016-2 [16.4 kB] 175s Get:19 http://ftpmaster.internal/ubuntu noble/main s390x libimport-into-perl all 1.002005-2 [10.7 kB] 175s Get:20 http://ftpmaster.internal/ubuntu noble/main s390x librole-tiny-perl all 2.002004-1 [16.3 kB] 175s Get:21 http://ftpmaster.internal/ubuntu noble/main s390x libsub-quote-perl all 2.006008-1ubuntu1 [20.7 kB] 175s Get:22 http://ftpmaster.internal/ubuntu noble/main s390x libmoo-perl all 2.005005-1 [47.4 kB] 175s Get:23 http://ftpmaster.internal/ubuntu noble/main s390x libencode-locale-perl all 1.05-3 [11.6 kB] 175s Get:24 http://ftpmaster.internal/ubuntu noble/main s390x libtimedate-perl all 2.3300-2 [34.0 kB] 176s Get:25 http://ftpmaster.internal/ubuntu noble/main s390x libhttp-date-perl all 6.06-1 [10.2 kB] 176s Get:26 http://ftpmaster.internal/ubuntu noble/main s390x libfile-listing-perl all 6.16-1 [11.3 kB] 176s Get:27 http://ftpmaster.internal/ubuntu noble/main s390x libhtml-tagset-perl all 3.20-6 [11.3 kB] 176s Get:28 http://ftpmaster.internal/ubuntu noble/main s390x liburi-perl all 5.27-1 [88.0 kB] 176s Get:29 http://ftpmaster.internal/ubuntu noble/main s390x libhtml-parser-perl s390x 3.81-1build3 [87.9 kB] 176s Get:30 http://ftpmaster.internal/ubuntu noble/main s390x libhtml-tree-perl all 5.07-3 [200 kB] 176s Get:31 http://ftpmaster.internal/ubuntu noble/main s390x libclone-perl s390x 0.46-1build3 [10.8 kB] 176s Get:32 http://ftpmaster.internal/ubuntu noble/main s390x libio-html-perl all 1.004-3 [15.9 kB] 176s Get:33 http://ftpmaster.internal/ubuntu noble/main s390x liblwp-mediatypes-perl all 6.04-2 [20.1 kB] 177s Get:34 http://ftpmaster.internal/ubuntu noble/main s390x libhttp-message-perl all 6.45-1ubuntu1 [78.2 kB] 177s Get:35 http://ftpmaster.internal/ubuntu noble/main s390x libhttp-cookies-perl all 6.11-1 [18.2 kB] 177s Get:36 http://ftpmaster.internal/ubuntu noble/main s390x libhttp-negotiate-perl all 6.01-2 [12.4 kB] 177s Get:37 http://ftpmaster.internal/ubuntu noble/main s390x perl-openssl-defaults s390x 7build3 [6628 B] 177s Get:38 http://ftpmaster.internal/ubuntu noble/main s390x libnet-ssleay-perl s390x 1.94-1build4 [319 kB] 177s Get:39 http://ftpmaster.internal/ubuntu noble/main s390x libio-socket-ssl-perl all 2.085-1 [195 kB] 178s Get:40 http://ftpmaster.internal/ubuntu noble/main s390x libnet-http-perl all 6.23-1 [22.3 kB] 178s Get:41 http://ftpmaster.internal/ubuntu noble/main s390x liblwp-protocol-https-perl all 6.13-1 [9006 B] 178s Get:42 http://ftpmaster.internal/ubuntu noble/main s390x libtry-tiny-perl all 0.31-2 [20.8 kB] 178s Get:43 http://ftpmaster.internal/ubuntu noble/main s390x libwww-robotrules-perl all 6.02-1 [12.6 kB] 178s Get:44 http://ftpmaster.internal/ubuntu noble/main s390x libwww-perl all 6.76-1 [138 kB] 178s Get:45 http://ftpmaster.internal/ubuntu noble/main s390x patchutils s390x 0.4.2-1build2 [77.3 kB] 178s Get:46 http://ftpmaster.internal/ubuntu noble/main s390x wdiff s390x 1.2.2-6 [29.1 kB] 178s Get:47 http://ftpmaster.internal/ubuntu noble/main s390x devscripts all 2.23.7 [1069 kB] 180s Get:48 http://ftpmaster.internal/ubuntu noble/universe s390x putty-tools s390x 0.80-1build3 [716 kB] 181s Get:49 http://ftpmaster.internal/ubuntu noble/main s390x python3-bcrypt s390x 3.2.2-1 [28.3 kB] 181s Get:50 http://ftpmaster.internal/ubuntu noble/main s390x python3-hamcrest all 2.1.0-1 [28.1 kB] 181s Get:51 http://ftpmaster.internal/ubuntu noble/main s390x python3-pyasn1 all 0.4.8-4 [51.2 kB] 181s Get:52 http://ftpmaster.internal/ubuntu noble/main s390x python3-pyasn1-modules all 0.2.8-1 [68.0 kB] 182s Get:53 http://ftpmaster.internal/ubuntu noble/main s390x python3-service-identity all 24.1.0-1 [11.2 kB] 182s Get:54 http://ftpmaster.internal/ubuntu noble/main s390x python3-automat all 22.10.0-2 [27.5 kB] 182s Get:55 http://ftpmaster.internal/ubuntu noble/main s390x python3-constantly all 23.10.4-1 [13.7 kB] 182s Get:56 http://ftpmaster.internal/ubuntu noble/main s390x python3-hyperlink all 21.0.0-5 [68.0 kB] 182s Get:57 http://ftpmaster.internal/ubuntu noble/main s390x python3-incremental all 22.10.0-1 [17.6 kB] 182s Get:58 http://ftpmaster.internal/ubuntu noble/main s390x python3-zope.interface s390x 6.1-1 [181 kB] 182s Get:59 http://ftpmaster.internal/ubuntu noble/main s390x python3-twisted all 24.3.0-1 [2057 kB] 185s Get:60 http://ftpmaster.internal/ubuntu noble/universe s390x openssh-tests s390x 1:9.6p1-3ubuntu13 [1400 kB] 188s Fetched 8230 kB in 15s (563 kB/s) 189s Selecting previously unselected package libtommath1:s390x. 189s (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 ... 78331 files and directories currently installed.) 189s Preparing to unpack .../00-libtommath1_1.2.1-2_s390x.deb ... 189s Unpacking libtommath1:s390x (1.2.1-2) ... 189s Selecting previously unselected package libtomcrypt1:s390x. 189s Preparing to unpack .../01-libtomcrypt1_1.18.2+dfsg-7_s390x.deb ... 189s Unpacking libtomcrypt1:s390x (1.18.2+dfsg-7) ... 189s Selecting previously unselected package dropbear-bin. 189s Preparing to unpack .../02-dropbear-bin_2022.83-4_s390x.deb ... 189s Unpacking dropbear-bin (2022.83-4) ... 189s Selecting previously unselected package dropbear. 189s Preparing to unpack .../03-dropbear_2022.83-4_all.deb ... 189s Unpacking dropbear (2022.83-4) ... 189s Selecting previously unselected package libfile-dirlist-perl. 189s Preparing to unpack .../04-libfile-dirlist-perl_0.05-3_all.deb ... 189s Unpacking libfile-dirlist-perl (0.05-3) ... 189s Selecting previously unselected package libfile-which-perl. 189s Preparing to unpack .../05-libfile-which-perl_1.27-2_all.deb ... 189s Unpacking libfile-which-perl (1.27-2) ... 189s Selecting previously unselected package libfile-homedir-perl. 189s Preparing to unpack .../06-libfile-homedir-perl_1.006-2_all.deb ... 189s Unpacking libfile-homedir-perl (1.006-2) ... 189s Selecting previously unselected package libfile-touch-perl. 189s Preparing to unpack .../07-libfile-touch-perl_0.12-2_all.deb ... 189s Unpacking libfile-touch-perl (0.12-2) ... 189s Selecting previously unselected package libio-pty-perl. 189s Preparing to unpack .../08-libio-pty-perl_1%3a1.20-1build2_s390x.deb ... 189s Unpacking libio-pty-perl (1:1.20-1build2) ... 189s Selecting previously unselected package libipc-run-perl. 189s Preparing to unpack .../09-libipc-run-perl_20231003.0-1_all.deb ... 189s Unpacking libipc-run-perl (20231003.0-1) ... 189s Selecting previously unselected package libclass-method-modifiers-perl. 189s Preparing to unpack .../10-libclass-method-modifiers-perl_2.15-1_all.deb ... 189s Unpacking libclass-method-modifiers-perl (2.15-1) ... 189s Selecting previously unselected package libclass-xsaccessor-perl. 189s Preparing to unpack .../11-libclass-xsaccessor-perl_1.19-4build4_s390x.deb ... 189s Unpacking libclass-xsaccessor-perl (1.19-4build4) ... 189s Selecting previously unselected package libb-hooks-op-check-perl:s390x. 189s Preparing to unpack .../12-libb-hooks-op-check-perl_0.22-3build1_s390x.deb ... 189s Unpacking libb-hooks-op-check-perl:s390x (0.22-3build1) ... 189s Selecting previously unselected package libdynaloader-functions-perl. 189s Preparing to unpack .../13-libdynaloader-functions-perl_0.003-3_all.deb ... 189s Unpacking libdynaloader-functions-perl (0.003-3) ... 189s Selecting previously unselected package libdevel-callchecker-perl:s390x. 189s Preparing to unpack .../14-libdevel-callchecker-perl_0.008-2build3_s390x.deb ... 189s Unpacking libdevel-callchecker-perl:s390x (0.008-2build3) ... 189s Selecting previously unselected package libparams-classify-perl:s390x. 189s Preparing to unpack .../15-libparams-classify-perl_0.015-2build5_s390x.deb ... 189s Unpacking libparams-classify-perl:s390x (0.015-2build5) ... 189s Selecting previously unselected package libmodule-runtime-perl. 189s Preparing to unpack .../16-libmodule-runtime-perl_0.016-2_all.deb ... 189s Unpacking libmodule-runtime-perl (0.016-2) ... 189s Selecting previously unselected package libimport-into-perl. 189s Preparing to unpack .../17-libimport-into-perl_1.002005-2_all.deb ... 189s Unpacking libimport-into-perl (1.002005-2) ... 189s Selecting previously unselected package librole-tiny-perl. 189s Preparing to unpack .../18-librole-tiny-perl_2.002004-1_all.deb ... 189s Unpacking librole-tiny-perl (2.002004-1) ... 189s Selecting previously unselected package libsub-quote-perl. 189s Preparing to unpack .../19-libsub-quote-perl_2.006008-1ubuntu1_all.deb ... 189s Unpacking libsub-quote-perl (2.006008-1ubuntu1) ... 189s Selecting previously unselected package libmoo-perl. 189s Preparing to unpack .../20-libmoo-perl_2.005005-1_all.deb ... 189s Unpacking libmoo-perl (2.005005-1) ... 189s Selecting previously unselected package libencode-locale-perl. 189s Preparing to unpack .../21-libencode-locale-perl_1.05-3_all.deb ... 189s Unpacking libencode-locale-perl (1.05-3) ... 189s Selecting previously unselected package libtimedate-perl. 189s Preparing to unpack .../22-libtimedate-perl_2.3300-2_all.deb ... 189s Unpacking libtimedate-perl (2.3300-2) ... 189s Selecting previously unselected package libhttp-date-perl. 189s Preparing to unpack .../23-libhttp-date-perl_6.06-1_all.deb ... 189s Unpacking libhttp-date-perl (6.06-1) ... 189s Selecting previously unselected package libfile-listing-perl. 189s Preparing to unpack .../24-libfile-listing-perl_6.16-1_all.deb ... 189s Unpacking libfile-listing-perl (6.16-1) ... 189s Selecting previously unselected package libhtml-tagset-perl. 189s Preparing to unpack .../25-libhtml-tagset-perl_3.20-6_all.deb ... 189s Unpacking libhtml-tagset-perl (3.20-6) ... 189s Selecting previously unselected package liburi-perl. 189s Preparing to unpack .../26-liburi-perl_5.27-1_all.deb ... 189s Unpacking liburi-perl (5.27-1) ... 189s Selecting previously unselected package libhtml-parser-perl:s390x. 189s Preparing to unpack .../27-libhtml-parser-perl_3.81-1build3_s390x.deb ... 189s Unpacking libhtml-parser-perl:s390x (3.81-1build3) ... 189s Selecting previously unselected package libhtml-tree-perl. 189s Preparing to unpack .../28-libhtml-tree-perl_5.07-3_all.deb ... 189s Unpacking libhtml-tree-perl (5.07-3) ... 189s Selecting previously unselected package libclone-perl:s390x. 189s Preparing to unpack .../29-libclone-perl_0.46-1build3_s390x.deb ... 189s Unpacking libclone-perl:s390x (0.46-1build3) ... 189s Selecting previously unselected package libio-html-perl. 189s Preparing to unpack .../30-libio-html-perl_1.004-3_all.deb ... 189s Unpacking libio-html-perl (1.004-3) ... 189s Selecting previously unselected package liblwp-mediatypes-perl. 189s Preparing to unpack .../31-liblwp-mediatypes-perl_6.04-2_all.deb ... 189s Unpacking liblwp-mediatypes-perl (6.04-2) ... 189s Selecting previously unselected package libhttp-message-perl. 189s Preparing to unpack .../32-libhttp-message-perl_6.45-1ubuntu1_all.deb ... 189s Unpacking libhttp-message-perl (6.45-1ubuntu1) ... 189s Selecting previously unselected package libhttp-cookies-perl. 189s Preparing to unpack .../33-libhttp-cookies-perl_6.11-1_all.deb ... 189s Unpacking libhttp-cookies-perl (6.11-1) ... 189s Selecting previously unselected package libhttp-negotiate-perl. 189s Preparing to unpack .../34-libhttp-negotiate-perl_6.01-2_all.deb ... 189s Unpacking libhttp-negotiate-perl (6.01-2) ... 189s Selecting previously unselected package perl-openssl-defaults:s390x. 189s Preparing to unpack .../35-perl-openssl-defaults_7build3_s390x.deb ... 189s Unpacking perl-openssl-defaults:s390x (7build3) ... 189s Selecting previously unselected package libnet-ssleay-perl:s390x. 189s Preparing to unpack .../36-libnet-ssleay-perl_1.94-1build4_s390x.deb ... 189s Unpacking libnet-ssleay-perl:s390x (1.94-1build4) ... 189s Selecting previously unselected package libio-socket-ssl-perl. 189s Preparing to unpack .../37-libio-socket-ssl-perl_2.085-1_all.deb ... 189s Unpacking libio-socket-ssl-perl (2.085-1) ... 189s Selecting previously unselected package libnet-http-perl. 189s Preparing to unpack .../38-libnet-http-perl_6.23-1_all.deb ... 189s Unpacking libnet-http-perl (6.23-1) ... 189s Selecting previously unselected package liblwp-protocol-https-perl. 189s Preparing to unpack .../39-liblwp-protocol-https-perl_6.13-1_all.deb ... 189s Unpacking liblwp-protocol-https-perl (6.13-1) ... 190s Selecting previously unselected package libtry-tiny-perl. 190s Preparing to unpack .../40-libtry-tiny-perl_0.31-2_all.deb ... 190s Unpacking libtry-tiny-perl (0.31-2) ... 190s Selecting previously unselected package libwww-robotrules-perl. 190s Preparing to unpack .../41-libwww-robotrules-perl_6.02-1_all.deb ... 190s Unpacking libwww-robotrules-perl (6.02-1) ... 190s Selecting previously unselected package libwww-perl. 190s Preparing to unpack .../42-libwww-perl_6.76-1_all.deb ... 190s Unpacking libwww-perl (6.76-1) ... 190s Selecting previously unselected package patchutils. 190s Preparing to unpack .../43-patchutils_0.4.2-1build2_s390x.deb ... 190s Unpacking patchutils (0.4.2-1build2) ... 190s Selecting previously unselected package wdiff. 190s Preparing to unpack .../44-wdiff_1.2.2-6_s390x.deb ... 190s Unpacking wdiff (1.2.2-6) ... 190s Selecting previously unselected package devscripts. 190s Preparing to unpack .../45-devscripts_2.23.7_all.deb ... 190s Unpacking devscripts (2.23.7) ... 190s Selecting previously unselected package putty-tools. 190s Preparing to unpack .../46-putty-tools_0.80-1build3_s390x.deb ... 190s Unpacking putty-tools (0.80-1build3) ... 190s Selecting previously unselected package python3-bcrypt. 190s Preparing to unpack .../47-python3-bcrypt_3.2.2-1_s390x.deb ... 190s Unpacking python3-bcrypt (3.2.2-1) ... 190s Selecting previously unselected package python3-hamcrest. 190s Preparing to unpack .../48-python3-hamcrest_2.1.0-1_all.deb ... 190s Unpacking python3-hamcrest (2.1.0-1) ... 190s Selecting previously unselected package python3-pyasn1. 190s Preparing to unpack .../49-python3-pyasn1_0.4.8-4_all.deb ... 190s Unpacking python3-pyasn1 (0.4.8-4) ... 190s Selecting previously unselected package python3-pyasn1-modules. 190s Preparing to unpack .../50-python3-pyasn1-modules_0.2.8-1_all.deb ... 190s Unpacking python3-pyasn1-modules (0.2.8-1) ... 190s Selecting previously unselected package python3-service-identity. 190s Preparing to unpack .../51-python3-service-identity_24.1.0-1_all.deb ... 190s Unpacking python3-service-identity (24.1.0-1) ... 190s Selecting previously unselected package python3-automat. 190s Preparing to unpack .../52-python3-automat_22.10.0-2_all.deb ... 190s Unpacking python3-automat (22.10.0-2) ... 190s Selecting previously unselected package python3-constantly. 190s Preparing to unpack .../53-python3-constantly_23.10.4-1_all.deb ... 190s Unpacking python3-constantly (23.10.4-1) ... 190s Selecting previously unselected package python3-hyperlink. 190s Preparing to unpack .../54-python3-hyperlink_21.0.0-5_all.deb ... 190s Unpacking python3-hyperlink (21.0.0-5) ... 190s Selecting previously unselected package python3-incremental. 190s Preparing to unpack .../55-python3-incremental_22.10.0-1_all.deb ... 190s Unpacking python3-incremental (22.10.0-1) ... 190s Selecting previously unselected package python3-zope.interface. 190s Preparing to unpack .../56-python3-zope.interface_6.1-1_s390x.deb ... 190s Unpacking python3-zope.interface (6.1-1) ... 190s Selecting previously unselected package python3-twisted. 190s Preparing to unpack .../57-python3-twisted_24.3.0-1_all.deb ... 190s Unpacking python3-twisted (24.3.0-1) ... 191s Selecting previously unselected package openssh-tests. 191s Preparing to unpack .../58-openssh-tests_1%3a9.6p1-3ubuntu13_s390x.deb ... 191s Unpacking openssh-tests (1:9.6p1-3ubuntu13) ... 191s Selecting previously unselected package autopkgtest-satdep. 191s Preparing to unpack .../59-1-autopkgtest-satdep.deb ... 191s Unpacking autopkgtest-satdep (0) ... 191s Setting up wdiff (1.2.2-6) ... 191s Setting up libfile-which-perl (1.27-2) ... 191s Setting up libdynaloader-functions-perl (0.003-3) ... 191s Setting up libclass-method-modifiers-perl (2.15-1) ... 191s Setting up libio-pty-perl (1:1.20-1build2) ... 191s Setting up python3-zope.interface (6.1-1) ... 191s Setting up libclone-perl:s390x (0.46-1build3) ... 191s Setting up libtommath1:s390x (1.2.1-2) ... 191s Setting up libhtml-tagset-perl (3.20-6) ... 191s Setting up python3-bcrypt (3.2.2-1) ... 192s Setting up python3-automat (22.10.0-2) ... 192s Setting up liblwp-mediatypes-perl (6.04-2) ... 192s Setting up libtry-tiny-perl (0.31-2) ... 192s Setting up perl-openssl-defaults:s390x (7build3) ... 192s Setting up libencode-locale-perl (1.05-3) ... 192s Setting up python3-hamcrest (2.1.0-1) ... 192s Setting up putty-tools (0.80-1build3) ... 192s Setting up patchutils (0.4.2-1build2) ... 192s Setting up python3-incremental (22.10.0-1) ... 192s Setting up python3-hyperlink (21.0.0-5) ... 193s Setting up libio-html-perl (1.004-3) ... 193s Setting up libb-hooks-op-check-perl:s390x (0.22-3build1) ... 193s Setting up libipc-run-perl (20231003.0-1) ... 193s Setting up libtimedate-perl (2.3300-2) ... 193s Setting up librole-tiny-perl (2.002004-1) ... 193s Setting up python3-pyasn1 (0.4.8-4) ... 193s Setting up python3-constantly (23.10.4-1) ... 193s Setting up libsub-quote-perl (2.006008-1ubuntu1) ... 193s Setting up libclass-xsaccessor-perl (1.19-4build4) ... 193s Setting up libfile-dirlist-perl (0.05-3) ... 193s Setting up libfile-homedir-perl (1.006-2) ... 193s Setting up liburi-perl (5.27-1) ... 193s Setting up libfile-touch-perl (0.12-2) ... 193s Setting up libnet-ssleay-perl:s390x (1.94-1build4) ... 193s Setting up libtomcrypt1:s390x (1.18.2+dfsg-7) ... 193s Setting up libhttp-date-perl (6.06-1) ... 193s Setting up dropbear-bin (2022.83-4) ... 193s Setting up libfile-listing-perl (6.16-1) ... 193s Setting up libnet-http-perl (6.23-1) ... 193s Setting up libdevel-callchecker-perl:s390x (0.008-2build3) ... 193s Setting up dropbear (2022.83-4) ... 193s Converting existing OpenSSH RSA host key to Dropbear format. 193s Key is a ssh-rsa key 193s Wrote key to '/etc/dropbear/dropbear_rsa_host_key' 193s 3072 SHA256:XTO1ZVrm0hRvBfQNbqp4yd+3JnDVnHWBUvlajHCh44k /etc/dropbear/dropbear_rsa_host_key (RSA) 193s +---[RSA 3072]----+ 193s | .+O+X| 193s | o.* &*| 193s | oB X.%| 193s | .o.o* Oo| 193s | SE.o. + | 193s | o + o | 193s | . = o | 193s | . . o ..| 193s | . +o.| 193s +----[SHA256]-----+ 193s Converting existing OpenSSH ECDSA host key to Dropbear format. 193s Key is a ecdsa-sha2-nistp256 key 193s Wrote key to '/etc/dropbear/dropbear_ecdsa_host_key' 193s 256 SHA256:vP0QuFbKHA6MQr9YooRyVGMzZ2r5L/OyZMGAe9vwxYA /etc/dropbear/dropbear_ecdsa_host_key (ECDSA) 193s +---[ECDSA 256]---+ 193s | * o | 193s | + X | 193s | + E . | 193s |.o + * + . | 193s |o.= * * S o | 193s |oo * * O B . | 193s |. . o B X o | 193s | o.= o | 193s | .o. . | 193s +----[SHA256]-----+ 193s Converting existing OpenSSH ED25519 host key to Dropbear format. 193s Key is a ssh-ed25519 key 193s Wrote key to '/etc/dropbear/dropbear_ed25519_host_key' 193s 256 SHA256:RfaXFOTAcXjgvpmgalliHRhOGwOkCMObPM1t96N78UU /etc/dropbear/dropbear_ed25519_host_key (ED25519) 193s +--[ED25519 256]--+ 193s |+ .o. o.+==. | 193s |.+ . = o oo=.. | 193s |o * .o * . o.+ | 193s | = o o+... . E | 193s | . . ..S.. o | 193s | o o= . = | 193s | . +o + = | 193s | oo . . | 193s | ...o | 193s +----[SHA256]-----+ 194s Created symlink /etc/systemd/system/multi-user.target.wants/dropbear.service → /usr/lib/systemd/system/dropbear.service. 194s Setting up python3-pyasn1-modules (0.2.8-1) ... 195s Setting up python3-service-identity (24.1.0-1) ... 195s Setting up libwww-robotrules-perl (6.02-1) ... 195s Setting up libhtml-parser-perl:s390x (3.81-1build3) ... 195s Setting up libio-socket-ssl-perl (2.085-1) ... 195s Setting up libhttp-message-perl (6.45-1ubuntu1) ... 195s Setting up libhttp-negotiate-perl (6.01-2) ... 195s Setting up libhttp-cookies-perl (6.11-1) ... 195s Setting up libhtml-tree-perl (5.07-3) ... 195s Setting up libparams-classify-perl:s390x (0.015-2build5) ... 195s Setting up libmodule-runtime-perl (0.016-2) ... 195s Setting up python3-twisted (24.3.0-1) ... 199s Setting up libimport-into-perl (1.002005-2) ... 199s Setting up libmoo-perl (2.005005-1) ... 199s Setting up openssh-tests (1:9.6p1-3ubuntu13) ... 199s Setting up liblwp-protocol-https-perl (6.13-1) ... 199s Setting up libwww-perl (6.76-1) ... 199s Setting up devscripts (2.23.7) ... 199s Setting up autopkgtest-satdep (0) ... 199s Processing triggers for libc-bin (2.39-0ubuntu8) ... 199s Processing triggers for man-db (2.12.0-4build1) ... 201s Processing triggers for install-info (7.1-3build2) ... 205s (Reading database ... 81453 files and directories currently installed.) 205s Removing autopkgtest-satdep (0) ... 206s autopkgtest [10:12:13]: test regress: [----------------------- 206s info: Adding user `openssh-tests' ... 206s info: Selecting UID/GID from range 1000 to 59999 ... 206s info: Adding new group `openssh-tests' (1001) ... 206s info: Adding new user `openssh-tests' (1001) with group `openssh-tests (1001)' ... 206s info: Creating home directory `/home/openssh-tests' ... 206s info: Copying files from `/etc/skel' ... 206s info: Adding new user `openssh-tests' to supplemental / extra groups `users' ... 206s info: Adding user `openssh-tests' to group `users' ... 207s Synchronizing state of haveged.service with SysV service script with /usr/lib/systemd/systemd-sysv-install. 207s Executing: /usr/lib/systemd/systemd-sysv-install enable haveged 208s 10:12:15.454676488 I: Started /usr/lib/openssh/regress/run-tests /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user 208s 10:12:15.511768691 O: make: Entering directory '/tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress' 208s 10:12:15.522055925 O: test "x" = "x" || mkdir -p /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/valgrind-out 208s 10:12:15.523723051 O: ssh-keygen -if /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/rsa_ssh2.prv | diff - /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/rsa_openssh.prv 208s 10:12:15.530038869 O: tr '\n' '\r' /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/rsa_ssh2_cr.prv 208s 10:12:15.534325362 O: ssh-keygen -if /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/rsa_ssh2_cr.prv | diff - /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/rsa_openssh.prv 208s 10:12:15.547407050 O: awk '{print $0 "\r"}' /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/rsa_ssh2.prv > /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/rsa_ssh2_crnl.prv 208s 10:12:15.563254489 O: ssh-keygen -if /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/rsa_ssh2_crnl.prv | diff - /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/rsa_openssh.prv 208s 10:12:15.568859490 O: cat /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/rsa_openssh.prv > /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t2.out 208s 10:12:15.576514551 O: chmod 600 /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t2.out 208s 10:12:15.583410364 O: ssh-keygen -yf /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t2.out | diff - /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/rsa_openssh.pub 208s 10:12:15.599514117 O: ssh-keygen -ef /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/rsa_openssh.pub >/tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t3.out 208s 10:12:15.616647241 O: ssh-keygen -if /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t3.out | diff - /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/rsa_openssh.pub 208s 10:12:15.626021989 O: ssh-keygen -E md5 -lf /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/rsa_openssh.pub |\ 208s 10:12:15.628014175 O: awk '{print $2}' | diff - /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t4.ok 208s 10:12:15.637134809 O: ssh-keygen -Bf /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/rsa_openssh.pub |\ 208s 10:12:15.641740238 O: awk '{print $2}' | diff - /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t5.ok 208s 10:12:15.648456738 O: ssh-keygen -if /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/dsa_ssh2.prv > /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t6.out1 208s 10:12:15.657034800 O: ssh-keygen -if /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/dsa_ssh2.pub > /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t6.out2 208s 10:12:15.663015181 O: chmod 600 /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t6.out1 208s 10:12:15.670283862 O: ssh-keygen -yf /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t6.out1 | diff - /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t6.out2 208s 10:12:15.673697122 O: ssh-keygen -q -t rsa -N '' -f /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t7.out 211s 10:12:18.582347553 O: ssh-keygen -lf /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t7.out > /dev/null 211s 10:12:18.593254616 O: ssh-keygen -Bf /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t7.out > /dev/null 211s 10:12:18.604520990 O: ssh-keygen -q -t dsa -N '' -f /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t8.out 211s 10:12:18.925197182 O: ssh-keygen -lf /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t8.out > /dev/null 211s 10:12:18.939982927 O: ssh-keygen -Bf /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t8.out > /dev/null 211s 10:12:18.952410678 O: ! /usr/bin/ssh -Q key-plain | grep ecdsa >/dev/null || \ 211s 10:12:18.957500176 O: ssh-keygen -q -t ecdsa -N '' -f /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t9.out 212s 10:12:18.977185677 O: ! /usr/bin/ssh -Q key-plain | grep ecdsa >/dev/null || \ 212s 10:12:18.983228302 O: ssh-keygen -lf /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t9.out > /dev/null 212s 10:12:19.003567301 O: ! /usr/bin/ssh -Q key-plain | grep ecdsa >/dev/null || \ 212s 10:12:19.011965490 O: ssh-keygen -Bf /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t9.out > /dev/null 212s 10:12:19.027595240 O: ssh-keygen -q -t ed25519 -N '' -f /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t10.out 212s 10:12:19.037660993 O: ssh-keygen -lf /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t10.out > /dev/null 212s 10:12:19.045959555 O: ssh-keygen -Bf /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t10.out > /dev/null 212s 10:12:19.059705057 O: ssh-keygen -E sha256 -lf /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/rsa_openssh.pub |\ 212s 10:12:19.074439933 O: awk '{print $2}' | diff - /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t11.ok 212s 10:12:19.083543186 O: ssh-keygen -q -t ed25519 -N '' -C 'test-comment-1234' -f /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t12.out 212s 10:12:19.093680364 O: ssh-keygen -lf /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/t12.out.pub | grep test-comment-1234 >/dev/null 212s 10:12:19.105970489 E: run test connect.sh ... 216s 10:12:23.814133094 O: ok simple connect 216s 10:12:23.817563023 E: run test proxy-connect.sh ... 217s 10:12:24.082631334 O: plain username comp=no 217s 10:12:24.521766147 O: plain username comp=yes 217s 10:12:24.940415236 O: username with style 218s 10:12:25.399481399 O: ok proxy connect 218s 10:12:25.402248274 E: run test sshfp-connect.sh ... 218s 10:12:25.728586024 O: SKIPPED: TEST_SSH_SSHFP_DOMAIN not set. 218s 10:12:25.732799211 E: run test connect-privsep.sh ... 224s 10:12:31.403400971 O: ok proxy connect with privsep 224s 10:12:31.404921845 E: run test connect-uri.sh ... 224s 10:12:31.780769595 O: uri connect: no trailing slash 225s 10:12:32.198751658 O: uri connect: trailing slash 225s 10:12:32.588239661 O: uri connect: with path name 225s 10:12:32.638575099 E: run test proto-version.sh ... 225s 10:12:32.640210472 O: ok uri connect 225s 10:12:32.954666534 O: ok sshd version with different protocol combinations 225s 10:12:32.957493534 E: run test proto-mismatch.sh ... 226s 10:12:33.202059786 O: ok protocol version mismatch 226s 10:12:33.205154785 E: run test exit-status.sh ... 226s 10:12:33.452780601 O: test remote exit status: status 0 232s 10:12:39.403816861 O: test remote exit status: status 1 238s 10:12:45.516605924 O: test remote exit status: status 4 244s 10:12:51.151571111 O: test remote exit status: status 5 249s 10:12:56.850066394 O: test remote exit status: status 44 255s 10:13:02.782691882 O: ok remote exit status 255s 10:13:02.785385506 E: run test exit-status-signal.sh ... 257s 10:13:04.060901674 O: ok exit status on signal 257s 10:13:04.063512172 E: run test envpass.sh ... 257s 10:13:04.379409048 O: test environment passing: pass env, don't accept 257s 10:13:04.858923670 O: test environment passing: setenv, don't accept 258s 10:13:05.264358986 O: test environment passing: don't pass env, accept 258s 10:13:05.678223367 O: test environment passing: pass single env, accept single env 259s 10:13:06.123331545 O: test environment passing: pass multiple env, accept multiple env 259s 10:13:06.482821438 O: test environment passing: setenv, accept 259s 10:13:06.913178564 O: test environment passing: setenv, first match wins 260s 10:13:07.344788814 O: test environment passing: server setenv wins 260s 10:13:07.741765213 O: test environment passing: server setenv wins 261s 10:13:08.161654999 O: ok environment passing 261s 10:13:08.164766000 E: run test transfer.sh ... 265s 10:13:11.973330945 O: ok transfer data 265s 10:13:11.979342994 E: run test banner.sh ... 265s 10:13:12.323421056 O: test banner: missing banner file 265s 10:13:12.766754252 O: test banner: size 0 266s 10:13:13.224596556 O: test banner: size 10 266s 10:13:13.618080554 O: test banner: size 100 266s 10:13:13.965639868 O: test banner: size 1000 267s 10:13:14.388488117 O: test banner: size 10000 267s 10:13:14.740532118 O: test banner: size 100000 268s 10:13:15.179068052 O: test banner: suppress banner (-q) 268s 10:13:15.572389065 O: ok banner 268s 10:13:15.574180866 E: run test rekey.sh ... 268s 10:13:15.875353491 O: client rekey KexAlgorithms=diffie-hellman-group1-sha1 270s 10:13:17.944512550 O: client rekey KexAlgorithms=diffie-hellman-group14-sha1 273s 10:13:19.980669372 O: client rekey KexAlgorithms=diffie-hellman-group14-sha256 275s 10:13:22.442469156 O: ssh failed (-oRekeyLimit=256k) 275s 10:13:22.445905281 E: cmp: EOF on /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/copy after byte 262144, in line 290 275s 10:13:22.518443915 O: corrupted copy (-oRekeyLimit=256k) 275s 10:13:22.527480793 O: client rekey KexAlgorithms=diffie-hellman-group16-sha512 277s 10:13:24.524905512 O: client rekey KexAlgorithms=diffie-hellman-group18-sha512 279s 10:13:26.542519576 O: client rekey KexAlgorithms=diffie-hellman-group-exchange-sha1 281s 10:13:28.648834760 O: client rekey KexAlgorithms=diffie-hellman-group-exchange-sha256 283s 10:13:30.827234321 O: client rekey KexAlgorithms=ecdh-sha2-nistp256 285s 10:13:32.921440632 O: client rekey KexAlgorithms=ecdh-sha2-nistp384 287s 10:13:34.953829005 O: client rekey KexAlgorithms=ecdh-sha2-nistp521 289s 10:13:36.813194063 O: client rekey KexAlgorithms=curve25519-sha256 291s 10:13:38.827339750 O: client rekey KexAlgorithms=curve25519-sha256@libssh.org 294s 10:13:41.013012628 O: client rekey KexAlgorithms=sntrup761x25519-sha512@openssh.com 296s 10:13:43.198345436 O: client rekey Ciphers=3des-cbc 298s 10:13:45.305882439 O: client rekey Ciphers=aes128-cbc 300s 10:13:47.591865558 O: client rekey Ciphers=aes192-cbc 303s 10:13:50.563900941 O: client rekey Ciphers=aes256-cbc 306s 10:13:53.364571266 O: client rekey Ciphers=aes128-ctr 309s 10:13:56.166878980 O: client rekey Ciphers=aes192-ctr 311s 10:13:58.785944477 O: client rekey Ciphers=aes256-ctr 314s 10:14:01.278165222 O: client rekey Ciphers=aes128-gcm@openssh.com 316s 10:14:03.576344895 O: client rekey Ciphers=aes256-gcm@openssh.com 319s 10:14:06.226964916 O: client rekey Ciphers=chacha20-poly1305@openssh.com 321s 10:14:08.497802230 O: client rekey MACs=hmac-sha1 323s 10:14:10.707987851 O: client rekey MACs=hmac-sha1-96 325s 10:14:12.580780727 O: client rekey MACs=hmac-sha2-256 327s 10:14:14.563665856 O: client rekey MACs=hmac-sha2-512 330s 10:14:17.466025560 O: client rekey MACs=hmac-md5 333s 10:14:20.062171232 O: client rekey MACs=hmac-md5-96 335s 10:14:22.313692774 O: client rekey MACs=umac-64@openssh.com 337s 10:14:24.559987407 O: client rekey MACs=umac-128@openssh.com 339s 10:14:26.783607701 O: client rekey MACs=hmac-sha1-etm@openssh.com 341s 10:14:28.957855993 O: client rekey MACs=hmac-sha1-96-etm@openssh.com 344s 10:14:31.292374913 O: client rekey MACs=hmac-sha2-256-etm@openssh.com 346s 10:14:33.544563035 O: client rekey MACs=hmac-sha2-512-etm@openssh.com 348s 10:14:35.793482886 O: client rekey MACs=hmac-md5-etm@openssh.com 350s 10:14:37.746544054 O: client rekey MACs=hmac-md5-96-etm@openssh.com 352s 10:14:39.620317044 O: client rekey MACs=umac-64-etm@openssh.com 354s 10:14:41.653279591 O: client rekey MACs=umac-128-etm@openssh.com 356s 10:14:43.769079313 O: client rekey aes128-gcm@openssh.com diffie-hellman-group1-sha1 359s 10:14:45.989928626 O: client rekey aes128-gcm@openssh.com diffie-hellman-group14-sha1 361s 10:14:48.458655891 O: client rekey aes128-gcm@openssh.com diffie-hellman-group14-sha256 364s 10:14:51.212202522 O: client rekey aes128-gcm@openssh.com diffie-hellman-group16-sha512 366s 10:14:53.689977043 O: client rekey aes128-gcm@openssh.com diffie-hellman-group18-sha512 368s 10:14:55.949783330 O: client rekey aes128-gcm@openssh.com diffie-hellman-group-exchange-sha1 371s 10:14:58.257363309 O: client rekey aes128-gcm@openssh.com diffie-hellman-group-exchange-sha256 373s 10:15:00.433950737 O: client rekey aes128-gcm@openssh.com ecdh-sha2-nistp256 375s 10:15:02.676868154 O: client rekey aes128-gcm@openssh.com ecdh-sha2-nistp384 377s 10:15:04.847995902 O: client rekey aes128-gcm@openssh.com ecdh-sha2-nistp521 380s 10:15:07.342469875 O: client rekey aes128-gcm@openssh.com curve25519-sha256 382s 10:15:09.859869361 O: client rekey aes128-gcm@openssh.com curve25519-sha256@libssh.org 385s 10:15:12.413788268 O: client rekey aes128-gcm@openssh.com sntrup761x25519-sha512@openssh.com 387s 10:15:14.864479756 O: client rekey aes256-gcm@openssh.com diffie-hellman-group1-sha1 390s 10:15:17.156329415 O: client rekey aes256-gcm@openssh.com diffie-hellman-group14-sha1 392s 10:15:19.484439777 O: client rekey aes256-gcm@openssh.com diffie-hellman-group14-sha256 394s 10:15:21.886735124 O: client rekey aes256-gcm@openssh.com diffie-hellman-group16-sha512 397s 10:15:24.251669896 O: client rekey aes256-gcm@openssh.com diffie-hellman-group18-sha512 399s 10:15:26.532417382 O: client rekey aes256-gcm@openssh.com diffie-hellman-group-exchange-sha1 401s 10:15:28.877018757 O: client rekey aes256-gcm@openssh.com diffie-hellman-group-exchange-sha256 404s 10:15:31.143096250 O: client rekey aes256-gcm@openssh.com ecdh-sha2-nistp256 406s 10:15:33.404160120 O: client rekey aes256-gcm@openssh.com ecdh-sha2-nistp384 408s 10:15:35.622775926 O: client rekey aes256-gcm@openssh.com ecdh-sha2-nistp521 410s 10:15:37.796129671 O: client rekey aes256-gcm@openssh.com curve25519-sha256 413s 10:15:40.127962049 O: client rekey aes256-gcm@openssh.com curve25519-sha256@libssh.org 415s 10:15:42.558639668 O: client rekey aes256-gcm@openssh.com sntrup761x25519-sha512@openssh.com 417s 10:15:44.870206766 O: client rekey chacha20-poly1305@openssh.com diffie-hellman-group1-sha1 419s 10:15:46.907369020 O: client rekey chacha20-poly1305@openssh.com diffie-hellman-group14-sha1 421s 10:15:48.936380945 O: client rekey chacha20-poly1305@openssh.com diffie-hellman-group14-sha256 423s 10:15:50.964382133 O: client rekey chacha20-poly1305@openssh.com diffie-hellman-group16-sha512 425s 10:15:52.949518997 O: client rekey chacha20-poly1305@openssh.com diffie-hellman-group18-sha512 427s 10:15:54.950734613 O: client rekey chacha20-poly1305@openssh.com diffie-hellman-group-exchange-sha1 430s 10:15:57.202876732 O: client rekey chacha20-poly1305@openssh.com diffie-hellman-group-exchange-sha256 432s 10:15:59.283732371 O: client rekey chacha20-poly1305@openssh.com ecdh-sha2-nistp256 434s 10:16:01.528114099 O: client rekey chacha20-poly1305@openssh.com ecdh-sha2-nistp384 436s 10:16:03.792552104 O: client rekey chacha20-poly1305@openssh.com ecdh-sha2-nistp521 438s 10:16:05.899311665 O: client rekey chacha20-poly1305@openssh.com curve25519-sha256 441s 10:16:08.148709840 O: client rekey chacha20-poly1305@openssh.com curve25519-sha256@libssh.org 443s 10:16:10.425686466 O: client rekey chacha20-poly1305@openssh.com sntrup761x25519-sha512@openssh.com 445s 10:16:12.707937394 O: client rekeylimit 16 449s 10:16:16.175679123 O: client rekeylimit 1k 451s 10:16:18.966378812 O: client rekeylimit 128k 454s 10:16:21.606931502 O: client rekeylimit 256k 457s 10:16:24.071604180 O: client rekeylimit default 5 472s 10:16:39.899705024 O: client rekeylimit default 10 493s 10:17:00.516193099 O: client rekeylimit default 5 no data 509s 10:17:16.120674404 O: client rekeylimit default 10 no data 529s 10:17:36.572343738 O: server rekeylimit 16 532s 10:17:39.562237800 O: server rekeylimit 1k 535s 10:17:42.542609947 O: server rekeylimit 128k 537s 10:17:44.949947868 O: server rekeylimit 256k 540s 10:17:47.028179547 O: server rekeylimit default 5 no data 555s 10:18:02.589048309 O: server rekeylimit default 10 no data 576s 10:18:23.132865359 O: rekeylimit parsing 589s 10:18:36.578083383 E: make: *** [Makefile:231: t-exec] Error 1 589s 10:18:36.577092373 O: failed rekey 589s 10:18:36.579668567 O: make: Leaving directory '/tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress' 589s 10:18:36.581874622 O: ==> /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/failed-regress.log <== 589s 10:18:36.584385809 O: Executing: /usr/bin/ssh -Q key-plain log /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/log/20240416T101315.607581.ssh.6552.log 589s 10:18:36.585559063 E: tail: error writing 'standard output': Resource temporarily unavailable 589s 10:18:36.586322997 O: Executing: /usr/bin/ssh -Q key-plain log /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/log/20240416T101315.621794.ssh.6559.log 589s 10:18:36.587472373 O: trace: using cached key type ssh-ed25519 589s 10:18:36.588427446 O: trace: using cached key type sk-ssh-ed25519@openssh.com 589s 10:18:36.589602070 O: trace: using cached key type ecdsa-sha2-nistp256 589s 10:18:36.590406372 O: trace: using cached key type ecdsa-sha2-nistp384 589s 10:18:36.591231621 O: trace: using cached key type ecdsa-sha2-nistp521 589s 10:18:36.592032560 O: trace: using cached key type sk-ecdsa-sha2-nistp256@openssh.com 589s 10:18:36.592820435 O: trace: using cached key type ssh-dss 589s 10:18:36.594598559 O: trace: using cached key type ssh-rsa 589s 10:18:36.596426746 O: Executing: /usr/bin/ssh -Q kex log /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/log/20240416T101315.844051.ssh.6619.log 589s 10:18:36.597750818 O: Executing: /usr/bin/ssh -Q cipher log /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/log/20240416T101315.854999.ssh.6623.log 589s 10:18:36.598999810 O: Executing: /usr/bin/ssh -Q mac log /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/log/20240416T101315.864582.ssh.6627.log 589s 10:18:36.600163434 O: trace: client rekey KexAlgorithms=diffie-hellman-group1-sha1 589s 10:18:36.602206125 O: Executing: /usr/bin/ssh -oRekeyLimit=256k -oCompression=no -v -F /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh_proxy somehost cat > /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/copy log /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/log/20240416T101315.877444.ssh.6635.log 589s 10:18:36.603151828 O: Executing: /usr/sbin/sshd -i -f /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/sshd_proxy log /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/log/20240416T101315.911969.sshd.6640.log 589s 10:18:36.604003189 O: trace: 9 rekeying(s) 589s 10:18:36.604841134 O: trace: client rekey KexAlgorithms=diffie-hellman-group14-sha1 589s 10:18:36.605796199 O: Executing: /usr/bin/ssh -oRekeyLimit=256k -oCompression=no -v -F /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh_proxy somehost cat > /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/copy log /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/log/20240416T101317.946387.ssh.6674.log 589s 10:18:36.606696640 O: Executing: /usr/sbin/sshd -i -f /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/sshd_proxy log /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/log/20240416T101317.973527.sshd.6679.log 589s 10:18:36.607512872 O: trace: 9 rekeying(s) 589s 10:18:36.608363891 O: trace: client rekey KexAlgorithms=diffie-hellman-group14-sha256 589s 10:18:36.609318382 O: Executing: /usr/bin/ssh -oRekeyLimit=256k -oCompression=no -v -F /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh_proxy somehost cat > /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/copy log /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/log/20240416T101319.983868.ssh.6713.log 589s 10:18:36.610336184 O: Executing: /usr/sbin/sshd -i -f /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/sshd_proxy log /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/log/20240416T101320.074510.sshd.6718.log 589s 10:18:36.611280809 O: FAIL: ssh failed (-oRekeyLimit=256k) 589s 10:18:36.612244747 O: Saving debug logs to /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/failed-rekey-logs.tar 589s 10:18:36.613144122 O: 589s 10:18:36.614262621 O: Executing: /usr/bin/ssh -Q key-plain log /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/log/20240416T101315.607581.ssh.6552.log 589s 10:18:36.615409690 O: Executing: /usr/bin/ssh -Q key-plain log /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/log/20240416T101315.621794.ssh.6559.log 589s 10:18:36.616457808 O: trace: using cached key type ssh-ed25519 589s 10:18:36.617473372 O: trace: using cached key type sk-ssh-ed25519@openssh.com 589s 10:18:36.618469059 O: trace: using cached key type ecdsa-sha2-nistp256 589s 10:18:36.619472060 O: trace: using cached key type ecdsa-sha2-nistp384 589s 10:18:36.620530310 O: trace: using cached key type ecdsa-sha2-nistp521 589s 10:18:36.621934871 O: trace: using cached key type sk-ecdsa-sha2-nistp256@openssh.com 589s 10:18:36.622927883 O: trace: using cached key type ssh-dss 589s 10:18:36.624319191 O: trace: using cached key type ssh-rsa 589s 10:18:36.625891873 O: Executing: /usr/bin/ssh -Q kex log /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/log/20240416T101315.844051.ssh.6619.log 589s 10:18:36.627508434 O: Executing: /usr/bin/ssh -Q cipher log /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/log/20240416T101315.854999.ssh.6623.log 589s 10:18:36.629364934 O: Executing: /usr/bin/ssh -Q mac log /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/log/20240416T101315.864582.ssh.6627.log 589s 10:18:36.631289385 O: trace: client rekey KexAlgorithms=diffie-hellman-group1-sha1 589s 10:18:36.633091246 O: Executing: /usr/bin/ssh -oRekeyLimit=256k -oCompression=no -v -F /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh_proxy somehost cat > /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/copy log /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/log/20240416T101315.877444.ssh.6635.log 589s 10:18:36.634871247 O: Executing: /usr/sbin/sshd -i -f /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/sshd_proxy log /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/log/20240416T101315.911969.sshd.6640.log 589s 10:18:36.638003246 O: trace: 9 rekeying(s) 589s 10:18:36.639785123 O: trace: client rekey KexAlgorithms=diffie-hellman-group14-sha1 589s 10:18:36.642148059 O: Executing: /usr/bin/ssh -oRekeyLimit=256k -oCompression=no -v -F /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh_proxy somehost cat > /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/copy log /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/log/20240416T101317.946387.ssh.6674.log 589s 10:18:36.643502872 O: Executing: /usr/sbin/sshd -i -f /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/sshd_proxy log /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/log/20240416T101317.973527.sshd.6679.log 589s 10:18:36.644528997 O: trace: 9 rekeying(s) 589s 10:18:36.645884934 O: trace: client rekey KexAlgorithms=diffie-hellman-group14-sha256 589s 10:18:36.648986060 O: Executing: /usr/bin/ssh -oRekeyLimit=256k -oCompression=no -v -F /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh_proxy somehost cat > /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/copy log /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/log/20240416T101319.983868.ssh.6713.log 589s 10:18:36.650139684 O: Executing: /usr/sbin/sshd -i -f /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/sshd_proxy log /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/log/20240416T101320.074510.sshd.6718.log 589s 10:18:36.651395874 O: FAIL: ssh failed (-oRekeyLimit=256k) 589s 10:18:36.652474693 O: Saving debug logs to /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/failed-rekey-logs.tar 589s 10:18:36.653698059 O: FAIL: corrupted copy (-oRekeyLimit=256k) 589s 10:18:36.654818183 O: Saving debug logs to /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/failed-rekey-logs.tar 589s 10:18:36.656118246 O: 589s 10:18:36.658093818 O: ==> /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/failed-ssh.log <== 589s 10:18:36.659269246 O: Executing: /usr/bin/ssh -oRekeyLimit=256k -oCompression=no -v -F /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh_proxy somehost cat > /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/copy 589s 10:18:36.661882748 O: OpenSSH_9.6p1 Ubuntu-3ubuntu13, OpenSSL 3.0.13 30 Jan 2024 589s 10:18:36.662918060 O: debug1: Reading configuration data /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh_proxy 589s 10:18:36.664068933 O: debug1: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh_proxy line 1: Applying options for * 589s 10:18:36.665249187 O: debug1: Executing proxy command: exec sudo env SSH_SK_HELPER="" /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/sshd-log-wrapper.sh -i -f /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/sshd_proxy 589s 10:18:36.666390012 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh-ed25519 type 3 589s 10:18:36.667545997 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh-ed25519-cert type -1 589s 10:18:36.668671134 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/sk-ssh-ed25519@openssh.com type 12 589s 10:18:36.669791934 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/sk-ssh-ed25519@openssh.com-cert type -1 589s 10:18:36.671102685 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ecdsa-sha2-nistp256 type 2 589s 10:18:36.672234696 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ecdsa-sha2-nistp256-cert type -1 589s 10:18:36.673682809 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ecdsa-sha2-nistp384 type 2 589s 10:18:36.676623685 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ecdsa-sha2-nistp384-cert type -1 589s 10:18:36.677796622 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ecdsa-sha2-nistp521 type 2 589s 10:18:36.678919194 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ecdsa-sha2-nistp521-cert type -1 589s 10:18:36.680021998 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/sk-ecdsa-sha2-nistp256@openssh.com type 10 589s 10:18:36.681554372 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/sk-ecdsa-sha2-nistp256@openssh.com-cert type -1 589s 10:18:36.682851934 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh-dss type 1 589s 10:18:36.683987872 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh-dss-cert type -1 589s 10:18:36.685053871 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh-rsa type 0 589s 10:18:36.686133933 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh-rsa-cert type -1 589s 10:18:36.687223998 O: debug1: Local version string SSH-2.0-OpenSSH_9.6p1 Ubuntu-3ubuntu13 589s 10:18:36.691515747 O: debug1: Remote protocol version 2.0, remote software version OpenSSH_9.6p1 Ubuntu-3ubuntu13 589s 10:18:36.694852433 O: debug1: compat_banner: match: OpenSSH_9.6p1 Ubuntu-3ubuntu13 pat OpenSSH* compat 0x04000000 589s 10:18:36.696582012 O: debug1: Authenticating to 127.0.0.1:4242 as 'openssh-tests' 589s 10:18:36.697702122 O: debug1: using hostkeyalias: localhost-with-alias 589s 10:18:36.698799621 O: debug1: SSH2_MSG_KEXINIT sent 589s 10:18:36.700658935 O: debug1: SSH2_MSG_KEXINIT received 589s 10:18:36.702183435 O: debug1: kex: algorithm: sntrup761x25519-sha512@openssh.com 589s 10:18:36.703732445 O: debug1: kex: host key algorithm: ssh-ed25519 589s 10:18:36.704827755 O: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: compression: none 589s 10:18:36.705898435 O: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: compression: none 589s 10:18:36.706935246 O: debug1: expecting SSH2_MSG_KEX_ECDH_REPLY 589s 10:18:36.708781872 O: debug1: SSH2_MSG_KEX_ECDH_REPLY received 589s 10:18:36.710576435 O: debug1: Server host key: ssh-ed25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs 589s 10:18:36.713298253 O: debug1: using hostkeyalias: localhost-with-alias 589s 10:18:36.714686058 O: debug1: Host 'localhost-with-alias' is known and matches the ED25519 host key. 589s 10:18:36.715988497 O: debug1: Found key in /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/known_hosts:1 589s 10:18:36.717606818 O: debug1: ssh_packet_send2_wrapped: resetting send seqnr 3 589s 10:18:36.718825623 O: debug1: rekey out after 32768 blocks 589s 10:18:36.720655496 O: debug1: SSH2_MSG_NEWKEYS sent 589s 10:18:36.722327184 O: debug1: Sending SSH2_MSG_EXT_INFO 589s 10:18:36.723887746 O: debug1: expecting SSH2_MSG_NEWKEYS 589s 10:18:36.725008319 O: debug1: ssh_packet_read_poll2: resetting read seqnr 3 589s 10:18:36.726057497 O: debug1: SSH2_MSG_NEWKEYS received 589s 10:18:36.729053502 O: debug1: rekey in after 32768 blocks 589s 10:18:36.731229997 O: debug1: SSH2_MSG_EXT_INFO received 589s 10:18:36.735750808 O: debug1: kex_ext_info_client_parse: server-sig-algs= 589s 10:18:36.740158809 O: debug1: kex_ext_info_check_ver: publickey-hostbound@openssh.com=<0> 589s 10:18:36.743468880 O: debug1: kex_ext_info_check_ver: ping@openssh.com=<0> 589s 10:18:36.745151933 O: debug1: SSH2_MSG_SERVICE_ACCEPT received 589s 10:18:36.747129193 O: debug1: SSH2_MSG_EXT_INFO received 589s 10:18:36.748758747 O: debug1: kex_ext_info_client_parse: server-sig-algs= 589s 10:18:36.751020996 O: debug1: Authentications that can continue: publickey,password,keyboard-interactive 589s 10:18:36.752781184 O: debug1: Next authentication method: publickey 589s 10:18:36.754892996 O: debug1: Skipping ssh-dss key /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh-dss - corresponding algorithm not in PubkeyAcceptedAlgorithms 589s 10:18:36.757661998 O: debug1: Will attempt key: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh-ed25519 ED25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs explicit 589s 10:18:36.759583434 O: debug1: Will attempt key: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/sk-ssh-ed25519@openssh.com ED25519-SK SHA256:tn0wEXzlEcLUgQoyfSoSUpH8UzuhpQ99pCIIVQ7DXHU explicit authenticator 589s 10:18:36.761434560 O: debug1: Will attempt key: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ecdsa-sha2-nistp256 ECDSA SHA256:Ai8soqn3wWZbkyZRzWtItCxVLWIdReaWVbXYiHyGKVg explicit 589s 10:18:36.763130058 O: debug1: Will attempt key: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ecdsa-sha2-nistp384 ECDSA SHA256:+BnanonMkSiGYDqIJZpmzvcawERi33cp1ohdd0WfLYU explicit 589s 10:18:36.764829810 O: debug1: Will attempt key: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ecdsa-sha2-nistp521 ECDSA SHA256:5HbT8Q5SUj/JPu1U5l6dsU+ywpgIgquHq9GbUUHdHpA explicit 589s 10:18:36.767160564 O: debug1: Will attempt key: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/sk-ecdsa-sha2-nistp256@openssh.com ECDSA-SK SHA256:75VjGZMXkX3c+2CW2W+4DoQXLO1lnsKTk85WWP9FoQo explicit authenticator 589s 10:18:36.769065061 O: debug1: Will attempt key: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh-rsa RSA SHA256:H1J1FUVg/SKwD7ejw44/fymuaKKMAr9aigfpTfPtucg explicit 589s 10:18:36.771619122 O: debug1: Offering public key: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh-ed25519 ED25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs explicit 589s 10:18:36.773714685 O: debug1: Server accepts key: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh-ed25519 ED25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs explicit 589s 10:18:36.775342374 O: Authenticated to 127.0.0.1 (via proxy) using "publickey". 589s 10:18:36.777184060 O: debug1: channel 0: new session [client-session] (inactive timeout: 0) 589s 10:18:36.778912997 O: debug1: Requesting no-more-sessions@openssh.com 589s 10:18:36.779980248 O: debug1: Entering interactive session. 589s 10:18:36.782156185 O: debug1: pledge: proc 589s 10:18:36.785093684 O: debug1: client_input_global_request: rtype hostkeys-00@openssh.com want_reply 0 589s 10:18:36.788199746 O: debug1: Remote: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/authorized_keys_openssh-tests:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding 589s 10:18:36.789926384 O: debug1: Remote: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/authorized_keys_openssh-tests:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding 589s 10:18:36.791606685 O: debug1: Sending command: cat > /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/copy 589s 10:18:36.793110309 O: debug1: pledge: fork 589s 10:18:36.794930935 O: debug1: enqueue packet: 94 589s 10:18:36.796054569 O: debug1: SSH2_MSG_KEXINIT sent 589s 10:18:36.797700122 O: debug1: rekeying in progress 589s 10:18:36.799772065 O: debug1: rekeying in progress 589s 10:18:36.802190872 O: debug1: rekeying in progress 589s 10:18:36.804581747 O: debug1: rekeying in progress 589s 10:18:36.806318249 O: debug1: rekeying in progress 589s 10:18:36.807641371 O: debug1: rekeying in progress 589s 10:18:36.808752686 O: debug1: rekeying in progress 589s 10:18:36.810347247 O: debug1: rekeying in progress 589s 10:18:36.812138560 O: debug1: rekeying in progress 589s 10:18:36.814219997 O: debug1: rekeying in progress 589s 10:18:36.815798622 O: debug1: SSH2_MSG_KEXINIT received 589s 10:18:36.817186506 O: debug1: kex: algorithm: sntrup761x25519-sha512@openssh.com 589s 10:18:36.819347693 O: debug1: kex: host key algorithm: ssh-ed25519 589s 10:18:36.822707435 O: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: compression: none 589s 10:18:36.826077434 O: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: compression: none 589s 10:18:36.827623872 O: debug1: expecting SSH2_MSG_KEX_ECDH_REPLY 589s 10:18:36.828948070 O: debug1: rekeying in progress 589s 10:18:36.831580496 O: debug1: rekeying in progress 589s 10:18:36.832962757 O: debug1: SSH2_MSG_KEX_ECDH_REPLY received 589s 10:18:36.834583558 O: debug1: Server host key: ssh-ed25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs 589s 10:18:36.835945135 O: debug1: ssh_packet_send2_wrapped: resetting send seqnr 11 589s 10:18:36.837952121 O: debug1: ssh_set_newkeys: rekeying out, input 7576 bytes 631 blocks, output 6220 bytes 427 blocks 589s 10:18:36.839763497 O: debug1: rekey out after 32768 blocks 589s 10:18:36.841643372 O: debug1: dequeue packet: 94 589s 10:18:36.843626560 O: debug1: SSH2_MSG_NEWKEYS sent 589s 10:18:36.846710814 O: debug1: expecting SSH2_MSG_NEWKEYS 589s 10:18:36.848400371 O: debug1: ssh_packet_read_poll2: resetting read seqnr 15 589s 10:18:36.850379560 O: debug1: SSH2_MSG_NEWKEYS received 589s 10:18:36.854956197 O: debug1: ssh_set_newkeys: rekeying in, input 7588 bytes 632 blocks, output 39008 bytes 4098 blocks 589s 10:18:36.856266871 O: debug1: rekey in after 32768 blocks 589s 10:18:36.857443133 O: debug1: enqueue packet: 94 589s 10:18:36.858510996 O: debug1: SSH2_MSG_KEXINIT sent 589s 10:18:36.859585560 O: debug1: rekeying in progress 589s 10:18:36.860678373 O: debug1: SSH2_MSG_KEXINIT received 589s 10:18:36.862022185 O: debug1: kex: algorithm: sntrup761x25519-sha512@openssh.com 589s 10:18:36.863271183 O: debug1: kex: host key algorithm: ssh-ed25519 589s 10:18:36.864400248 O: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: compression: none 589s 10:18:36.865561059 O: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: compression: none 589s 10:18:36.870167631 O: debug1: expecting SSH2_MSG_KEX_ECDH_REPLY 589s 10:18:36.873566435 O: debug1: rekeying in progress 589s 10:18:36.874701060 O: debug1: rekeying in progress 589s 10:18:36.875908809 O: debug1: SSH2_MSG_KEX_ECDH_REPLY received 589s 10:18:36.877207246 O: debug1: Server host key: ssh-ed25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs 589s 10:18:36.878330059 O: debug1: ssh_packet_send2_wrapped: resetting send seqnr 4 589s 10:18:36.879427059 O: debug1: ssh_set_newkeys: rekeying out, input 10036 bytes 305 blocks, output 41724 bytes 4436 blocks 589s 10:18:36.880476934 O: debug1: rekey out after 32768 blocks 589s 10:18:36.881708506 O: debug1: dequeue packet: 94 589s 10:18:36.882758309 O: debug1: SSH2_MSG_NEWKEYS sent 589s 10:18:36.883797374 O: debug1: expecting SSH2_MSG_NEWKEYS 589s 10:18:36.886408058 O: debug1: ssh_packet_read_poll2: resetting read seqnr 3 589s 10:18:36.887599501 O: debug1: SSH2_MSG_NEWKEYS received 589s 10:18:36.888935820 O: debug1: ssh_set_newkeys: rekeying in, input 10048 bytes 306 blocks, output 74512 bytes 4098 blocks 589s 10:18:36.890048372 O: debug1: rekey in after 32768 blocks 589s 10:18:36.891309371 O: debug1: enqueue packet: 94 589s 10:18:36.904522121 O: debug1: SSH2_MSG_KEXINIT sent 589s 10:18:36.905876810 O: debug1: rekeying in progress 589s 10:18:36.906949622 O: debug1: SSH2_MSG_KEXINIT received 589s 10:18:36.907990502 O: debug1: kex: algorithm: sntrup761x25519-sha512@openssh.com 589s 10:18:36.913998685 O: debug1: kex: host key algorithm: ssh-ed25519 589s 10:18:36.916418999 O: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: compression: none 589s 10:18:36.917660000 O: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: compression: none 589s 10:18:36.918745816 O: debug1: expecting SSH2_MSG_KEX_ECDH_REPLY 589s 10:18:36.919764075 O: debug1: rekeying in progress 589s 10:18:36.920842371 O: debug1: rekeying in progress 589s 10:18:36.922220321 O: debug1: SSH2_MSG_KEX_ECDH_REPLY received 589s 10:18:36.923442435 O: debug1: Server host key: ssh-ed25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs 589s 10:18:36.924479996 O: debug1: ssh_packet_send2_wrapped: resetting send seqnr 4 589s 10:18:36.925717379 O: debug1: ssh_set_newkeys: rekeying out, input 12496 bytes 305 blocks, output 77228 bytes 4436 blocks 589s 10:18:36.926797183 O: debug1: rekey out after 32768 blocks 589s 10:18:36.929451498 O: debug1: dequeue packet: 94 589s 10:18:36.930594560 O: debug1: SSH2_MSG_NEWKEYS sent 589s 10:18:36.931718688 O: debug1: expecting SSH2_MSG_NEWKEYS 589s 10:18:36.932756871 O: debug1: ssh_packet_read_poll2: resetting read seqnr 3 589s 10:18:36.933942060 O: debug1: SSH2_MSG_NEWKEYS received 589s 10:18:36.935174871 O: debug1: ssh_set_newkeys: rekeying in, input 12508 bytes 306 blocks, output 110016 bytes 4098 blocks 589s 10:18:36.936239820 O: debug1: rekey in after 32768 blocks 589s 10:18:36.937278372 O: debug1: enqueue packet: 94 589s 10:18:36.938293821 O: debug1: SSH2_MSG_KEXINIT sent 589s 10:18:36.940765808 O: debug1: rekeying in progress 589s 10:18:36.943916622 O: debug1: SSH2_MSG_KEXINIT received 589s 10:18:36.945292813 O: debug1: kex: algorithm: sntrup761x25519-sha512@openssh.com 589s 10:18:36.946324996 O: debug1: kex: host key algorithm: ssh-ed25519 589s 10:18:36.947396435 O: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: compression: none 589s 10:18:36.948451184 O: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: compression: none 589s 10:18:36.950844250 O: debug1: expecting SSH2_MSG_KEX_ECDH_REPLY 589s 10:18:36.952735747 O: debug1: rekeying in progress 589s 10:18:36.954278247 O: debug1: rekeying in progress 589s 10:18:36.955796189 O: debug1: SSH2_MSG_KEX_ECDH_REPLY received 589s 10:18:36.956948822 O: debug1: Server host key: ssh-ed25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs 589s 10:18:36.958345998 O: debug1: ssh_packet_send2_wrapped: resetting send seqnr 4 589s 10:18:36.960192634 O: debug1: ssh_set_newkeys: rekeying out, input 14956 bytes 305 blocks, output 112732 bytes 4436 blocks 589s 10:18:36.961914997 O: debug1: rekey out after 32768 blocks 589s 10:18:36.963307317 O: debug1: dequeue packet: 94 589s 10:18:36.964872746 O: debug1: SSH2_MSG_NEWKEYS sent 589s 10:18:36.966414059 O: debug1: expecting SSH2_MSG_NEWKEYS 589s 10:18:36.967592184 O: debug1: ssh_packet_read_poll2: resetting read seqnr 3 590s 10:18:36.968823623 O: debug1: SSH2_MSG_NEWKEYS received 590s 10:18:36.970797621 O: debug1: ssh_set_newkeys: rekeying in, input 14968 bytes 306 blocks, output 145520 bytes 4098 blocks 590s 10:18:36.972525891 O: debug1: rekey in after 32768 blocks 590s 10:18:36.973816242 O: debug1: enqueue packet: 94 590s 10:18:36.974890078 O: debug1: SSH2_MSG_KEXINIT sent 590s 10:18:36.975907144 O: debug1: rekeying in progress 590s 10:18:36.977086320 O: debug1: SSH2_MSG_KEXINIT received 590s 10:18:36.978701872 O: debug1: kex: algorithm: sntrup761x25519-sha512@openssh.com 590s 10:18:36.980401007 O: debug1: kex: host key algorithm: ssh-ed25519 590s 10:18:36.981805682 O: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:36.983826245 O: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:36.985004456 O: debug1: expecting SSH2_MSG_KEX_ECDH_REPLY 590s 10:18:36.986066007 O: debug1: rekeying in progress 590s 10:18:36.987120870 O: debug1: rekeying in progress 590s 10:18:36.988169559 O: debug1: SSH2_MSG_KEX_ECDH_REPLY received 590s 10:18:36.989244870 O: debug1: Server host key: ssh-ed25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs 590s 10:18:36.990374495 O: debug1: ssh_packet_send2_wrapped: resetting send seqnr 4 590s 10:18:36.991792497 O: debug1: ssh_set_newkeys: rekeying out, input 17416 bytes 305 blocks, output 148236 bytes 4436 blocks 590s 10:18:36.992917561 O: debug1: rekey out after 32768 blocks 590s 10:18:36.994135569 O: debug1: dequeue packet: 94 590s 10:18:36.995271558 O: debug1: SSH2_MSG_NEWKEYS sent 590s 10:18:36.997599571 O: debug1: expecting SSH2_MSG_NEWKEYS 590s 10:18:37.002199559 O: debug1: ssh_packet_read_poll2: resetting read seqnr 3 590s 10:18:37.004140063 O: debug1: SSH2_MSG_NEWKEYS received 590s 10:18:37.005195995 O: debug1: ssh_set_newkeys: rekeying in, input 17428 bytes 306 blocks, output 181024 bytes 4098 blocks 590s 10:18:37.006207308 O: debug1: rekey in after 32768 blocks 590s 10:18:37.007485184 O: debug1: enqueue packet: 94 590s 10:18:37.009828121 O: debug1: SSH2_MSG_KEXINIT sent 590s 10:18:37.010969558 O: debug1: rekeying in progress 590s 10:18:37.012034309 O: debug1: SSH2_MSG_KEXINIT received 590s 10:18:37.013113745 O: debug1: kex: algorithm: sntrup761x25519-sha512@openssh.com 590s 10:18:37.014328058 O: debug1: kex: host key algorithm: ssh-ed25519 590s 10:18:37.015636871 O: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.016831807 O: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.019102434 O: debug1: expecting SSH2_MSG_KEX_ECDH_REPLY 590s 10:18:37.020654414 O: debug1: rekeying in progress 590s 10:18:37.027953496 O: debug1: rekeying in progress 590s 10:18:37.029590933 O: debug1: SSH2_MSG_KEX_ECDH_REPLY received 590s 10:18:37.031654943 O: debug1: Server host key: ssh-ed25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs 590s 10:18:37.032789246 O: debug1: ssh_packet_send2_wrapped: resetting send seqnr 4 590s 10:18:37.034535245 O: debug1: ssh_set_newkeys: rekeying out, input 19896 bytes 307 blocks, output 183740 bytes 4436 blocks 590s 10:18:37.036464310 O: debug1: rekey out after 32768 blocks 590s 10:18:37.037795996 O: debug1: dequeue packet: 94 590s 10:18:37.039181432 O: debug1: SSH2_MSG_NEWKEYS sent 590s 10:18:37.040287495 O: debug1: expecting SSH2_MSG_NEWKEYS 590s 10:18:37.042497874 O: debug1: ssh_packet_read_poll2: resetting read seqnr 4 590s 10:18:37.045794058 O: debug1: SSH2_MSG_NEWKEYS received 590s 10:18:37.046975308 O: debug1: ssh_set_newkeys: rekeying in, input 19908 bytes 308 blocks, output 216528 bytes 4098 blocks 590s 10:18:37.050291433 O: debug1: rekey in after 32768 blocks 590s 10:18:37.051821622 O: debug1: enqueue packet: 94 590s 10:18:37.052858371 O: debug1: SSH2_MSG_KEXINIT sent 590s 10:18:37.054489372 O: debug1: rekeying in progress 590s 10:18:37.055534371 O: debug1: SSH2_MSG_KEXINIT received 590s 10:18:37.056703745 O: debug1: kex: algorithm: sntrup761x25519-sha512@openssh.com 590s 10:18:37.058030558 O: debug1: kex: host key algorithm: ssh-ed25519 590s 10:18:37.059208308 O: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.061487870 O: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.062958199 O: debug1: expecting SSH2_MSG_KEX_ECDH_REPLY 590s 10:18:37.064201872 O: debug1: rekeying in progress 590s 10:18:37.067116495 O: debug1: rekeying in progress 590s 10:18:37.068608750 O: debug1: SSH2_MSG_KEX_ECDH_REPLY received 590s 10:18:37.069839059 O: debug1: Server host key: ssh-ed25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs 590s 10:18:37.070876996 O: debug1: ssh_packet_send2_wrapped: resetting send seqnr 4 590s 10:18:37.072167870 O: debug1: ssh_set_newkeys: rekeying out, input 22356 bytes 305 blocks, output 219244 bytes 4436 blocks 590s 10:18:37.073186621 O: debug1: rekey out after 32768 blocks 590s 10:18:37.075785621 O: debug1: dequeue packet: 94 590s 10:18:37.077199316 O: debug1: SSH2_MSG_NEWKEYS sent 590s 10:18:37.079637372 O: debug1: expecting SSH2_MSG_NEWKEYS 590s 10:18:37.082713064 O: debug1: ssh_packet_read_poll2: resetting read seqnr 3 590s 10:18:37.083782809 O: debug1: SSH2_MSG_NEWKEYS received 590s 10:18:37.085066870 O: debug1: ssh_set_newkeys: rekeying in, input 22368 bytes 306 blocks, output 252032 bytes 4098 blocks 590s 10:18:37.086255308 O: debug1: rekey in after 32768 blocks 590s 10:18:37.087315682 O: debug1: enqueue packet: 94 590s 10:18:37.088333684 O: debug1: SSH2_MSG_KEXINIT sent 590s 10:18:37.089393059 O: debug1: rekeying in progress 590s 10:18:37.090754631 O: debug1: SSH2_MSG_KEXINIT received 590s 10:18:37.092454684 O: debug1: kex: algorithm: sntrup761x25519-sha512@openssh.com 590s 10:18:37.093595809 O: debug1: kex: host key algorithm: ssh-ed25519 590s 10:18:37.095129872 O: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.096308693 O: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.097805558 O: debug1: expecting SSH2_MSG_KEX_ECDH_REPLY 590s 10:18:37.099498808 O: debug1: rekeying in progress 590s 10:18:37.100850809 O: debug1: rekeying in progress 590s 10:18:37.102325057 O: debug1: SSH2_MSG_KEX_ECDH_REPLY received 590s 10:18:37.103555246 O: debug1: Server host key: ssh-ed25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs 590s 10:18:37.104941184 O: debug1: ssh_packet_send2_wrapped: resetting send seqnr 4 590s 10:18:37.106358746 O: debug1: ssh_set_newkeys: rekeying out, input 24816 bytes 305 blocks, output 254748 bytes 4436 blocks 590s 10:18:37.108087808 O: debug1: rekey out after 32768 blocks 590s 10:18:37.109791557 O: debug1: dequeue packet: 94 590s 10:18:37.111653434 O: debug1: SSH2_MSG_NEWKEYS sent 590s 10:18:37.115359245 O: debug1: expecting SSH2_MSG_NEWKEYS 590s 10:18:37.116468120 O: debug1: ssh_packet_read_poll2: resetting read seqnr 3 590s 10:18:37.117771996 O: debug1: SSH2_MSG_NEWKEYS received 590s 10:18:37.120100122 O: debug1: ssh_set_newkeys: rekeying in, input 24828 bytes 306 blocks, output 287536 bytes 4098 blocks 590s 10:18:37.122097620 O: debug1: rekey in after 32768 blocks 590s 10:18:37.123420683 O: debug1: enqueue packet: 94 590s 10:18:37.124765683 O: debug1: SSH2_MSG_KEXINIT sent 590s 10:18:37.125768557 O: debug1: rekeying in progress 590s 10:18:37.126885505 O: debug1: SSH2_MSG_KEXINIT received 590s 10:18:37.128787259 O: debug1: kex: algorithm: sntrup761x25519-sha512@openssh.com 590s 10:18:37.130669620 O: debug1: kex: host key algorithm: ssh-ed25519 590s 10:18:37.131948309 O: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.133707808 O: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.137783506 O: debug1: expecting SSH2_MSG_KEX_ECDH_REPLY 590s 10:18:37.139711746 O: debug1: rekeying in progress 590s 10:18:37.141938933 O: debug1: rekeying in progress 590s 10:18:37.143689187 O: debug1: SSH2_MSG_KEX_ECDH_REPLY received 590s 10:18:37.145581308 O: debug1: Server host key: ssh-ed25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs 590s 10:18:37.147816569 O: ssh_dispatch_run_fatal: Connection to UNKNOWN port 65535: incorrect signature 590s 10:18:37.149287058 O: FAIL: ssh failed (-oRekeyLimit=256k) 590s 10:18:37.151875495 O: 590s 10:18:37.153883622 O: Executing: /usr/bin/ssh -oRekeyLimit=256k -oCompression=no -v -F /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh_proxy somehost cat > /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/copy 590s 10:18:37.155628447 O: OpenSSH_9.6p1 Ubuntu-3ubuntu13, OpenSSL 3.0.13 30 Jan 2024 590s 10:18:37.157080183 O: debug1: Reading configuration data /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh_proxy 590s 10:18:37.158153058 O: debug1: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh_proxy line 1: Applying options for * 590s 10:18:37.160025621 O: debug1: Executing proxy command: exec sudo env SSH_SK_HELPER="" /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/sshd-log-wrapper.sh -i -f /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/sshd_proxy 590s 10:18:37.162239620 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh-ed25519 type 3 590s 10:18:37.164010870 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh-ed25519-cert type -1 590s 10:18:37.165152871 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/sk-ssh-ed25519@openssh.com type 12 590s 10:18:37.168290183 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/sk-ssh-ed25519@openssh.com-cert type -1 590s 10:18:37.170104434 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ecdsa-sha2-nistp256 type 2 590s 10:18:37.172303495 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ecdsa-sha2-nistp256-cert type -1 590s 10:18:37.174629495 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ecdsa-sha2-nistp384 type 2 590s 10:18:37.176298995 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ecdsa-sha2-nistp384-cert type -1 590s 10:18:37.178849372 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ecdsa-sha2-nistp521 type 2 590s 10:18:37.181266444 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ecdsa-sha2-nistp521-cert type -1 590s 10:18:37.182943497 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/sk-ecdsa-sha2-nistp256@openssh.com type 10 590s 10:18:37.184811070 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/sk-ecdsa-sha2-nistp256@openssh.com-cert type -1 590s 10:18:37.186806435 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh-dss type 1 590s 10:18:37.188038621 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh-dss-cert type -1 590s 10:18:37.189844309 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh-rsa type 0 590s 10:18:37.191651570 O: debug1: identity file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh-rsa-cert type -1 590s 10:18:37.193315995 O: debug1: Local version string SSH-2.0-OpenSSH_9.6p1 Ubuntu-3ubuntu13 590s 10:18:37.194989934 O: debug1: Remote protocol version 2.0, remote software version OpenSSH_9.6p1 Ubuntu-3ubuntu13 590s 10:18:37.197719996 O: debug1: compat_banner: match: OpenSSH_9.6p1 Ubuntu-3ubuntu13 pat OpenSSH* compat 0x04000000 590s 10:18:37.198877372 O: debug1: Authenticating to 127.0.0.1:4242 as 'openssh-tests' 590s 10:18:37.200026557 O: debug1: using hostkeyalias: localhost-with-alias 590s 10:18:37.201342945 O: debug1: SSH2_MSG_KEXINIT sent 590s 10:18:37.202592434 O: debug1: SSH2_MSG_KEXINIT received 590s 10:18:37.203728064 O: debug1: kex: algorithm: sntrup761x25519-sha512@openssh.com 590s 10:18:37.204771184 O: debug1: kex: host key algorithm: ssh-ed25519 590s 10:18:37.205821934 O: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.206841120 O: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.207858059 O: debug1: expecting SSH2_MSG_KEX_ECDH_REPLY 590s 10:18:37.211536246 O: debug1: SSH2_MSG_KEX_ECDH_REPLY received 590s 10:18:37.216073995 O: debug1: Server host key: ssh-ed25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs 590s 10:18:37.217060497 O: debug1: using hostkeyalias: localhost-with-alias 590s 10:18:37.218039495 O: debug1: Host 'localhost-with-alias' is known and matches the ED25519 host key. 590s 10:18:37.219199809 O: debug1: Found key in /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/known_hosts:1 590s 10:18:37.220871747 O: debug1: ssh_packet_send2_wrapped: resetting send seqnr 3 590s 10:18:37.222098058 O: debug1: rekey out after 32768 blocks 590s 10:18:37.223101370 O: debug1: SSH2_MSG_NEWKEYS sent 590s 10:18:37.224077433 O: debug1: Sending SSH2_MSG_EXT_INFO 590s 10:18:37.225043335 O: debug1: expecting SSH2_MSG_NEWKEYS 590s 10:18:37.226068808 O: debug1: ssh_packet_read_poll2: resetting read seqnr 3 590s 10:18:37.227083308 O: debug1: SSH2_MSG_NEWKEYS received 590s 10:18:37.231766696 O: debug1: rekey in after 32768 blocks 590s 10:18:37.233258745 O: debug1: SSH2_MSG_EXT_INFO received 590s 10:18:37.234499621 O: debug1: kex_ext_info_client_parse: server-sig-algs= 590s 10:18:37.235722870 O: debug1: kex_ext_info_check_ver: publickey-hostbound@openssh.com=<0> 590s 10:18:37.237001370 O: debug1: kex_ext_info_check_ver: ping@openssh.com=<0> 590s 10:18:37.238100622 O: debug1: SSH2_MSG_SERVICE_ACCEPT received 590s 10:18:37.239194371 O: debug1: SSH2_MSG_EXT_INFO received 590s 10:18:37.240320314 O: debug1: kex_ext_info_client_parse: server-sig-algs= 590s 10:18:37.241569433 O: debug1: Authentications that can continue: publickey,password,keyboard-interactive 590s 10:18:37.242623760 O: debug1: Next authentication method: publickey 590s 10:18:37.244779816 O: debug1: Skipping ssh-dss key /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh-dss - corresponding algorithm not in PubkeyAcceptedAlgorithms 590s 10:18:37.245947121 O: debug1: Will attempt key: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh-ed25519 ED25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs explicit 590s 10:18:37.247069935 O: debug1: Will attempt key: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/sk-ssh-ed25519@openssh.com ED25519-SK SHA256:tn0wEXzlEcLUgQoyfSoSUpH8UzuhpQ99pCIIVQ7DXHU explicit authenticator 590s 10:18:37.248162442 O: debug1: Will attempt key: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ecdsa-sha2-nistp256 ECDSA SHA256:Ai8soqn3wWZbkyZRzWtItCxVLWIdReaWVbXYiHyGKVg explicit 590s 10:18:37.249343434 O: debug1: Will attempt key: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ecdsa-sha2-nistp384 ECDSA SHA256:+BnanonMkSiGYDqIJZpmzvcawERi33cp1ohdd0WfLYU explicit 590s 10:18:37.250496746 O: debug1: Will attempt key: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ecdsa-sha2-nistp521 ECDSA SHA256:5HbT8Q5SUj/JPu1U5l6dsU+ywpgIgquHq9GbUUHdHpA explicit 590s 10:18:37.251819996 O: debug1: Will attempt key: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/sk-ecdsa-sha2-nistp256@openssh.com ECDSA-SK SHA256:75VjGZMXkX3c+2CW2W+4DoQXLO1lnsKTk85WWP9FoQo explicit authenticator 590s 10:18:37.252884621 O: debug1: Will attempt key: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh-rsa RSA SHA256:H1J1FUVg/SKwD7ejw44/fymuaKKMAr9aigfpTfPtucg explicit 590s 10:18:37.253987122 O: debug1: Offering public key: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh-ed25519 ED25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs explicit 590s 10:18:37.255060870 O: debug1: Server accepts key: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/ssh-ed25519 ED25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs explicit 590s 10:18:37.256088248 O: Authenticated to 127.0.0.1 (via proxy) using "publickey". 590s 10:18:37.258689813 O: debug1: channel 0: new session [client-session] (inactive timeout: 0) 590s 10:18:37.259888809 O: debug1: Requesting no-more-sessions@openssh.com 590s 10:18:37.261549620 O: debug1: Entering interactive session. 590s 10:18:37.262589058 O: debug1: pledge: proc 590s 10:18:37.264672057 O: debug1: client_input_global_request: rtype hostkeys-00@openssh.com want_reply 0 590s 10:18:37.269921808 O: debug1: Remote: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/authorized_keys_openssh-tests:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding 590s 10:18:37.272626809 O: debug1: Remote: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/authorized_keys_openssh-tests:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding 590s 10:18:37.275544933 O: debug1: Sending command: cat > /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/copy 590s 10:18:37.277706747 O: debug1: pledge: fork 590s 10:18:37.280194434 O: debug1: enqueue packet: 94 590s 10:18:37.282800433 O: debug1: SSH2_MSG_KEXINIT sent 590s 10:18:37.284852933 O: debug1: rekeying in progress 590s 10:18:37.286087308 O: debug1: rekeying in progress 590s 10:18:37.287150995 O: debug1: rekeying in progress 590s 10:18:37.289234683 O: debug1: rekeying in progress 590s 10:18:37.290197434 O: debug1: rekeying in progress 590s 10:18:37.291489558 O: debug1: rekeying in progress 590s 10:18:37.292511194 O: debug1: rekeying in progress 590s 10:18:37.293570622 O: debug1: rekeying in progress 590s 10:18:37.294614183 O: debug1: rekeying in progress 590s 10:18:37.295668372 O: debug1: rekeying in progress 590s 10:18:37.298806311 O: debug1: SSH2_MSG_KEXINIT received 590s 10:18:37.299939309 O: debug1: kex: algorithm: sntrup761x25519-sha512@openssh.com 590s 10:18:37.302183182 O: debug1: kex: host key algorithm: ssh-ed25519 590s 10:18:37.303482433 O: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.306267559 O: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.308379871 O: debug1: expecting SSH2_MSG_KEX_ECDH_REPLY 590s 10:18:37.312766436 O: debug1: rekeying in progress 590s 10:18:37.313892121 O: debug1: rekeying in progress 590s 10:18:37.315002184 O: debug1: SSH2_MSG_KEX_ECDH_REPLY received 590s 10:18:37.316893443 O: debug1: Server host key: ssh-ed25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs 590s 10:18:37.317911309 O: debug1: ssh_packet_send2_wrapped: resetting send seqnr 11 590s 10:18:37.318931559 O: debug1: ssh_set_newkeys: rekeying out, input 7576 bytes 631 blocks, output 6220 bytes 427 blocks 590s 10:18:37.320001245 O: debug1: rekey out after 32768 blocks 590s 10:18:37.321178995 O: debug1: dequeue packet: 94 590s 10:18:37.322247372 O: debug1: SSH2_MSG_NEWKEYS sent 590s 10:18:37.323291500 O: debug1: expecting SSH2_MSG_NEWKEYS 590s 10:18:37.326325182 O: debug1: ssh_packet_read_poll2: resetting read seqnr 15 590s 10:18:37.327407061 O: debug1: SSH2_MSG_NEWKEYS received 590s 10:18:37.328502934 O: debug1: ssh_set_newkeys: rekeying in, input 7588 bytes 632 blocks, output 39008 bytes 4098 blocks 590s 10:18:37.329491248 O: debug1: rekey in after 32768 blocks 590s 10:18:37.330492495 O: debug1: enqueue packet: 94 590s 10:18:37.331728870 O: debug1: SSH2_MSG_KEXINIT sent 590s 10:18:37.332770313 O: debug1: rekeying in progress 590s 10:18:37.334297684 O: debug1: SSH2_MSG_KEXINIT received 590s 10:18:37.336309808 O: debug1: kex: algorithm: sntrup761x25519-sha512@openssh.com 590s 10:18:37.337966059 O: debug1: kex: host key algorithm: ssh-ed25519 590s 10:18:37.339638745 O: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.342135933 O: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.344016933 O: debug1: expecting SSH2_MSG_KEX_ECDH_REPLY 590s 10:18:37.345804309 O: debug1: rekeying in progress 590s 10:18:37.347042821 O: debug1: rekeying in progress 590s 10:18:37.348692945 O: debug1: SSH2_MSG_KEX_ECDH_REPLY received 590s 10:18:37.350622870 O: debug1: Server host key: ssh-ed25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs 590s 10:18:37.353292809 O: debug1: ssh_packet_send2_wrapped: resetting send seqnr 4 590s 10:18:37.354750120 O: debug1: ssh_set_newkeys: rekeying out, input 10036 bytes 305 blocks, output 41724 bytes 4436 blocks 590s 10:18:37.356356308 O: debug1: rekey out after 32768 blocks 590s 10:18:37.358078121 O: debug1: dequeue packet: 94 590s 10:18:37.360524434 O: debug1: SSH2_MSG_NEWKEYS sent 590s 10:18:37.363034745 O: debug1: expecting SSH2_MSG_NEWKEYS 590s 10:18:37.364692069 O: debug1: ssh_packet_read_poll2: resetting read seqnr 3 590s 10:18:37.365883309 O: debug1: SSH2_MSG_NEWKEYS received 590s 10:18:37.367820372 O: debug1: ssh_set_newkeys: rekeying in, input 10048 bytes 306 blocks, output 74512 bytes 4098 blocks 590s 10:18:37.370181688 O: debug1: rekey in after 32768 blocks 590s 10:18:37.372648882 O: debug1: enqueue packet: 94 590s 10:18:37.375078308 O: debug1: SSH2_MSG_KEXINIT sent 590s 10:18:37.376604623 O: debug1: rekeying in progress 590s 10:18:37.378228683 O: debug1: SSH2_MSG_KEXINIT received 590s 10:18:37.380226882 O: debug1: kex: algorithm: sntrup761x25519-sha512@openssh.com 590s 10:18:37.381845620 O: debug1: kex: host key algorithm: ssh-ed25519 590s 10:18:37.383558434 O: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.385351620 O: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.387258870 O: debug1: expecting SSH2_MSG_KEX_ECDH_REPLY 590s 10:18:37.389169746 O: debug1: rekeying in progress 590s 10:18:37.391387620 O: debug1: rekeying in progress 590s 10:18:37.393115807 O: debug1: SSH2_MSG_KEX_ECDH_REPLY received 590s 10:18:37.394907308 O: debug1: Server host key: ssh-ed25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs 590s 10:18:37.396363996 O: debug1: ssh_packet_send2_wrapped: resetting send seqnr 4 590s 10:18:37.397845933 O: debug1: ssh_set_newkeys: rekeying out, input 12496 bytes 305 blocks, output 77228 bytes 4436 blocks 590s 10:18:37.398927495 O: debug1: rekey out after 32768 blocks 590s 10:18:37.399925558 O: debug1: dequeue packet: 94 590s 10:18:37.401091317 O: debug1: SSH2_MSG_NEWKEYS sent 590s 10:18:37.402117620 O: debug1: expecting SSH2_MSG_NEWKEYS 590s 10:18:37.403185620 O: debug1: ssh_packet_read_poll2: resetting read seqnr 3 590s 10:18:37.404197566 O: debug1: SSH2_MSG_NEWKEYS received 590s 10:18:37.405704693 O: debug1: ssh_set_newkeys: rekeying in, input 12508 bytes 306 blocks, output 110016 bytes 4098 blocks 590s 10:18:37.407254433 O: debug1: rekey in after 32768 blocks 590s 10:18:37.408771127 O: debug1: enqueue packet: 94 590s 10:18:37.409902184 O: debug1: SSH2_MSG_KEXINIT sent 590s 10:18:37.411235121 O: debug1: rekeying in progress 590s 10:18:37.412304870 O: debug1: SSH2_MSG_KEXINIT received 590s 10:18:37.414459871 O: debug1: kex: algorithm: sntrup761x25519-sha512@openssh.com 590s 10:18:37.415598059 O: debug1: kex: host key algorithm: ssh-ed25519 590s 10:18:37.417319687 O: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.418516507 O: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.419557684 O: debug1: expecting SSH2_MSG_KEX_ECDH_REPLY 590s 10:18:37.424654128 O: debug1: rekeying in progress 590s 10:18:37.425969747 O: debug1: rekeying in progress 590s 10:18:37.427330246 O: debug1: SSH2_MSG_KEX_ECDH_REPLY received 590s 10:18:37.428528769 O: debug1: Server host key: ssh-ed25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs 590s 10:18:37.429750003 O: debug1: ssh_packet_send2_wrapped: resetting send seqnr 4 590s 10:18:37.431445308 O: debug1: ssh_set_newkeys: rekeying out, input 14956 bytes 305 blocks, output 112732 bytes 4436 blocks 590s 10:18:37.432389694 O: debug1: rekey out after 32768 blocks 590s 10:18:37.433328871 O: debug1: dequeue packet: 94 590s 10:18:37.434274808 O: debug1: SSH2_MSG_NEWKEYS sent 590s 10:18:37.435202558 O: debug1: expecting SSH2_MSG_NEWKEYS 590s 10:18:37.436298933 O: debug1: ssh_packet_read_poll2: resetting read seqnr 3 590s 10:18:37.437359323 O: debug1: SSH2_MSG_NEWKEYS received 590s 10:18:37.438333188 O: debug1: ssh_set_newkeys: rekeying in, input 14968 bytes 306 blocks, output 145520 bytes 4098 blocks 590s 10:18:37.439266871 O: debug1: rekey in after 32768 blocks 590s 10:18:37.440390251 O: debug1: enqueue packet: 94 590s 10:18:37.441797434 O: debug1: SSH2_MSG_KEXINIT sent 590s 10:18:37.442797370 O: debug1: rekeying in progress 590s 10:18:37.443718308 O: debug1: SSH2_MSG_KEXINIT received 590s 10:18:37.444944371 O: debug1: kex: algorithm: sntrup761x25519-sha512@openssh.com 590s 10:18:37.446559684 O: debug1: kex: host key algorithm: ssh-ed25519 590s 10:18:37.447567745 O: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.449893002 O: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.452068996 O: debug1: expecting SSH2_MSG_KEX_ECDH_REPLY 590s 10:18:37.453344872 O: debug1: rekeying in progress 590s 10:18:37.455489620 O: debug1: rekeying in progress 590s 10:18:37.457928558 O: debug1: SSH2_MSG_KEX_ECDH_REPLY received 590s 10:18:37.460196371 O: debug1: Server host key: ssh-ed25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs 590s 10:18:37.462948121 O: debug1: ssh_packet_send2_wrapped: resetting send seqnr 4 590s 10:18:37.468541871 O: debug1: ssh_set_newkeys: rekeying out, input 17416 bytes 305 blocks, output 148236 bytes 4436 blocks 590s 10:18:37.473019057 O: debug1: rekey out after 32768 blocks 590s 10:18:37.475906872 O: debug1: dequeue packet: 94 590s 10:18:37.478892433 O: debug1: SSH2_MSG_NEWKEYS sent 590s 10:18:37.481754121 O: debug1: expecting SSH2_MSG_NEWKEYS 590s 10:18:37.484019131 O: debug1: ssh_packet_read_poll2: resetting read seqnr 3 590s 10:18:37.486587309 O: debug1: SSH2_MSG_NEWKEYS received 590s 10:18:37.489322621 O: debug1: ssh_set_newkeys: rekeying in, input 17428 bytes 306 blocks, output 181024 bytes 4098 blocks 590s 10:18:37.492245996 O: debug1: rekey in after 32768 blocks 590s 10:18:37.494101059 O: debug1: enqueue packet: 94 590s 10:18:37.496504058 O: debug1: SSH2_MSG_KEXINIT sent 590s 10:18:37.498321371 O: debug1: rekeying in progress 590s 10:18:37.500049245 O: debug1: SSH2_MSG_KEXINIT received 590s 10:18:37.502097809 O: debug1: kex: algorithm: sntrup761x25519-sha512@openssh.com 590s 10:18:37.503931069 O: debug1: kex: host key algorithm: ssh-ed25519 590s 10:18:37.505445195 O: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.506662003 O: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.510086816 O: debug1: expecting SSH2_MSG_KEX_ECDH_REPLY 590s 10:18:37.512251816 O: debug1: rekeying in progress 590s 10:18:37.513507183 O: debug1: rekeying in progress 590s 10:18:37.514524807 O: debug1: SSH2_MSG_KEX_ECDH_REPLY received 590s 10:18:37.515678871 O: debug1: Server host key: ssh-ed25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs 590s 10:18:37.517148069 O: debug1: ssh_packet_send2_wrapped: resetting send seqnr 4 590s 10:18:37.518440558 O: debug1: ssh_set_newkeys: rekeying out, input 19896 bytes 307 blocks, output 183740 bytes 4436 blocks 590s 10:18:37.519610745 O: debug1: rekey out after 32768 blocks 590s 10:18:37.520688370 O: debug1: dequeue packet: 94 590s 10:18:37.522809879 O: debug1: SSH2_MSG_NEWKEYS sent 590s 10:18:37.524079245 O: debug1: expecting SSH2_MSG_NEWKEYS 590s 10:18:37.525391120 O: debug1: ssh_packet_read_poll2: resetting read seqnr 4 590s 10:18:37.526517433 O: debug1: SSH2_MSG_NEWKEYS received 590s 10:18:37.527661308 O: debug1: ssh_set_newkeys: rekeying in, input 19908 bytes 308 blocks, output 216528 bytes 4098 blocks 590s 10:18:37.528823995 O: debug1: rekey in after 32768 blocks 590s 10:18:37.529957434 O: debug1: enqueue packet: 94 590s 10:18:37.531111064 O: debug1: SSH2_MSG_KEXINIT sent 590s 10:18:37.532273433 O: debug1: rekeying in progress 590s 10:18:37.533383772 O: debug1: SSH2_MSG_KEXINIT received 590s 10:18:37.534521939 O: debug1: kex: algorithm: sntrup761x25519-sha512@openssh.com 590s 10:18:37.536705496 O: debug1: kex: host key algorithm: ssh-ed25519 590s 10:18:37.537845071 O: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.539051621 O: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.540156870 O: debug1: expecting SSH2_MSG_KEX_ECDH_REPLY 590s 10:18:37.541509497 O: debug1: rekeying in progress 590s 10:18:37.542657003 O: debug1: rekeying in progress 590s 10:18:37.543731682 O: debug1: SSH2_MSG_KEX_ECDH_REPLY received 590s 10:18:37.544812436 O: debug1: Server host key: ssh-ed25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs 590s 10:18:37.545903621 O: debug1: ssh_packet_send2_wrapped: resetting send seqnr 4 590s 10:18:37.546956246 O: debug1: ssh_set_newkeys: rekeying out, input 22356 bytes 305 blocks, output 219244 bytes 4436 blocks 590s 10:18:37.548025881 O: debug1: rekey out after 32768 blocks 590s 10:18:37.550128809 O: debug1: dequeue packet: 94 590s 10:18:37.551424439 O: debug1: SSH2_MSG_NEWKEYS sent 590s 10:18:37.552516433 O: debug1: expecting SSH2_MSG_NEWKEYS 590s 10:18:37.553628558 O: debug1: ssh_packet_read_poll2: resetting read seqnr 3 590s 10:18:37.554626496 O: debug1: SSH2_MSG_NEWKEYS received 590s 10:18:37.555803557 O: debug1: ssh_set_newkeys: rekeying in, input 22368 bytes 306 blocks, output 252032 bytes 4098 blocks 590s 10:18:37.557531870 O: debug1: rekey in after 32768 blocks 590s 10:18:37.558601139 O: debug1: enqueue packet: 94 590s 10:18:37.559703934 O: debug1: SSH2_MSG_KEXINIT sent 590s 10:18:37.560797872 O: debug1: rekeying in progress 590s 10:18:37.563099871 O: debug1: SSH2_MSG_KEXINIT received 590s 10:18:37.564177059 O: debug1: kex: algorithm: sntrup761x25519-sha512@openssh.com 590s 10:18:37.565212132 O: debug1: kex: host key algorithm: ssh-ed25519 590s 10:18:37.566260253 O: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.567341995 O: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.568377131 O: debug1: expecting SSH2_MSG_KEX_ECDH_REPLY 590s 10:18:37.569425184 O: debug1: rekeying in progress 590s 10:18:37.570464190 O: debug1: rekeying in progress 590s 10:18:37.571844188 O: debug1: SSH2_MSG_KEX_ECDH_REPLY received 590s 10:18:37.572893682 O: debug1: Server host key: ssh-ed25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs 590s 10:18:37.573956434 O: debug1: ssh_packet_send2_wrapped: resetting send seqnr 4 590s 10:18:37.574999376 O: debug1: ssh_set_newkeys: rekeying out, input 24816 bytes 305 blocks, output 254748 bytes 4436 blocks 590s 10:18:37.578724933 O: debug1: rekey out after 32768 blocks 590s 10:18:37.580063497 O: debug1: dequeue packet: 94 590s 10:18:37.581386565 O: debug1: SSH2_MSG_NEWKEYS sent 590s 10:18:37.582422683 O: debug1: expecting SSH2_MSG_NEWKEYS 590s 10:18:37.584693682 O: debug1: ssh_packet_read_poll2: resetting read seqnr 3 590s 10:18:37.586273120 O: debug1: SSH2_MSG_NEWKEYS received 590s 10:18:37.588066446 O: debug1: ssh_set_newkeys: rekeying in, input 24828 bytes 306 blocks, output 287536 bytes 4098 blocks 590s 10:18:37.589734245 O: debug1: rekey in after 32768 blocks 590s 10:18:37.592790745 O: debug1: enqueue packet: 94 590s 10:18:37.595118871 O: debug1: SSH2_MSG_KEXINIT sent 590s 10:18:37.596130934 O: debug1: rekeying in progress 590s 10:18:37.597236433 O: debug1: SSH2_MSG_KEXINIT received 590s 10:18:37.598278433 O: debug1: kex: algorithm: sntrup761x25519-sha512@openssh.com 590s 10:18:37.600633496 O: debug1: kex: host key algorithm: ssh-ed25519 590s 10:18:37.601986683 O: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.603006182 O: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: compression: none 590s 10:18:37.604110504 O: debug1: expecting SSH2_MSG_KEX_ECDH_REPLY 590s 10:18:37.605193121 O: debug1: rekeying in progress 590s 10:18:37.606266871 O: debug1: rekeying in progress 590s 10:18:37.607313184 O: debug1: SSH2_MSG_KEX_ECDH_REPLY received 590s 10:18:37.608360371 O: debug1: Server host key: ssh-ed25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs 590s 10:18:37.609348247 O: ssh_dispatch_run_fatal: Connection to UNKNOWN port 65535: incorrect signature 590s 10:18:37.610324184 O: FAIL: ssh failed (-oRekeyLimit=256k) 590s 10:18:37.611476808 O: FAIL: corrupted copy (-oRekeyLimit=256k) 590s 10:18:37.614565621 O: 590s 10:18:37.617709121 O: ==> /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/failed-sshd.log <== 590s 10:18:37.619209745 O: Executing: /usr/sbin/sshd -i -f /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/sshd_proxy 590s 10:18:37.620468308 O: debug1: inetd sockets after dupping: 4, 5 590s 10:18:37.621859808 O: debug3: process_channel_timeouts: setting 0 timeouts 590s 10:18:37.623018811 O: debug3: channel_clear_timeouts: clearing 590s 10:18:37.625428558 O: Connection from UNKNOWN port 65535 on UNKNOWN port 65535 590s 10:18:37.626680184 O: debug1: Local version string SSH-2.0-OpenSSH_9.6p1 Ubuntu-3ubuntu13 590s 10:18:37.630255318 O: debug1: Remote protocol version 2.0, remote software version OpenSSH_9.6p1 Ubuntu-3ubuntu13 590s 10:18:37.633116684 O: debug1: compat_banner: match: OpenSSH_9.6p1 Ubuntu-3ubuntu13 pat OpenSSH* compat 0x04000000 590s 10:18:37.635083433 O: debug2: fd 4 setting O_NONBLOCK 590s 10:18:37.636421682 O: debug2: fd 5 setting O_NONBLOCK 590s 10:18:37.638373999 O: debug3: ssh_sandbox_init: preparing seccomp filter sandbox 590s 10:18:37.639975245 O: debug2: Network child is on pid 6724 590s 10:18:37.642615684 O: debug3: preauth child monitor started 590s 10:18:37.643922747 O: debug3: privsep user:group 109:65534 [preauth] 590s 10:18:37.645220808 O: debug1: permanently_set_uid: 109/65534 [preauth] 590s 10:18:37.647024371 O: debug3: ssh_sandbox_child: setting PR_SET_NO_NEW_PRIVS [preauth] 590s 10:18:37.649991246 O: debug3: ssh_sandbox_child: attaching seccomp filter program [preauth] 590s 10:18:37.651302183 O: debug3: append_hostkey_type: ssh-dss key not permitted by HostkeyAlgorithms [preauth] 590s 10:18:37.652375640 O: debug3: append_hostkey_type: ssh-rsa key not permitted by HostkeyAlgorithms [preauth] 590s 10:18:37.653850995 O: debug1: list_hostkey_types: ssh-ed25519,sk-ssh-ed25519@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,sk-ecdsa-sha2-nistp256@openssh.com,rsa-sha2-512,rsa-sha2-256 [preauth] 590s 10:18:37.656903370 O: debug3: send packet: type 20 [preauth] 590s 10:18:37.660073308 O: debug1: SSH2_MSG_KEXINIT sent [preauth] 590s 10:18:37.662752683 O: debug3: receive packet: type 20 [preauth] 590s 10:18:37.663966946 O: debug1: SSH2_MSG_KEXINIT received [preauth] 590s 10:18:37.665116308 O: debug2: local server KEXINIT proposal [preauth] 590s 10:18:37.666374809 O: debug2: KEX algorithms: sntrup761x25519-sha512@openssh.com,curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group14-sha256,ext-info-s,kex-strict-s-v00@openssh.com [preauth] 590s 10:18:37.667571809 O: debug2: host key algorithms: ssh-ed25519,sk-ssh-ed25519@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,sk-ecdsa-sha2-nistp256@openssh.com,rsa-sha2-512,rsa-sha2-256 [preauth] 590s 10:18:37.668686871 O: debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth] 590s 10:18:37.669772372 O: debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth] 590s 10:18:37.671337995 O: debug2: MACs ctos: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth] 590s 10:18:37.672583371 O: debug2: MACs stoc: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth] 590s 10:18:37.673869246 O: debug2: compression ctos: none,zlib@openssh.com [preauth] 590s 10:18:37.676229745 O: debug2: compression stoc: none,zlib@openssh.com [preauth] 590s 10:18:37.677260684 O: debug2: languages ctos: [preauth] 590s 10:18:37.678240120 O: debug2: languages stoc: [preauth] 590s 10:18:37.679251634 O: debug2: first_kex_follows 0 [preauth] 590s 10:18:37.680305747 O: debug2: reserved 0 [preauth] 590s 10:18:37.681576434 O: debug2: peer client KEXINIT proposal [preauth] 590s 10:18:37.686236876 O: debug2: KEX algorithms: sntrup761x25519-sha512@openssh.com,curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group14-sha256,ext-info-c,kex-strict-c-v00@openssh.com [preauth] 590s 10:18:37.687747372 O: debug2: host key algorithms: ssh-ed25519-cert-v01@openssh.com,ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,sk-ssh-ed25519-cert-v01@openssh.com,sk-ecdsa-sha2-nistp256-cert-v01@openssh.com,rsa-sha2-512-cert-v01@openssh.com,rsa-sha2-256-cert-v01@openssh.com,ssh-ed25519,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,sk-ssh-ed25519@openssh.com,sk-ecdsa-sha2-nistp256@openssh.com,rsa-sha2-512,rsa-sha2-256 [preauth] 590s 10:18:37.688846685 O: debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth] 590s 10:18:37.689976828 O: debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth] 590s 10:18:37.691370371 O: debug2: MACs ctos: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth] 590s 10:18:37.692551882 O: debug2: MACs stoc: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth] 590s 10:18:37.693614432 O: debug2: compression ctos: none,zlib@openssh.com,zlib [preauth] 590s 10:18:37.694629872 O: debug2: compression stoc: none,zlib@openssh.com,zlib [preauth] 590s 10:18:37.695616881 O: debug2: languages ctos: [preauth] 590s 10:18:37.696595807 O: debug2: languages stoc: [preauth] 590s 10:18:37.697564309 O: debug2: first_kex_follows 0 [preauth] 590s 10:18:37.700748495 O: debug2: reserved 0 [preauth] 590s 10:18:37.702411683 O: debug3: kex_choose_conf: will use strict KEX ordering [preauth] 590s 10:18:37.703550497 O: debug1: kex: algorithm: sntrup761x25519-sha512@openssh.com [preauth] 590s 10:18:37.704623747 O: debug1: kex: host key algorithm: ssh-ed25519 [preauth] 590s 10:18:37.705942184 O: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: compression: none [preauth] 590s 10:18:37.707005569 O: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: compression: none [preauth] 590s 10:18:37.708091434 O: debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth] 590s 10:18:37.709144694 O: debug3: receive packet: type 30 [preauth] 590s 10:18:37.710143870 O: debug1: SSH2_MSG_KEX_ECDH_INIT received [preauth] 590s 10:18:37.711313816 O: debug3: mm_sshkey_sign: entering [preauth] 590s 10:18:37.713601746 O: debug3: mm_request_send: entering, type 6 [preauth] 590s 10:18:37.714862247 O: debug3: mm_request_receive: entering 590s 10:18:37.715856683 O: debug3: monitor_read: checking request 6 590s 10:18:37.717019750 O: debug3: mm_answer_sign: entering 590s 10:18:37.718071826 O: debug3: mm_answer_sign: ssh-ed25519 KEX signature len=83 590s 10:18:37.723036996 O: debug3: mm_request_send: entering, type 7 590s 10:18:37.724275934 O: debug2: monitor_read: 6 used once, disabling now 590s 10:18:37.725317120 O: debug3: mm_sshkey_sign: waiting for MONITOR_ANS_SIGN [preauth] 590s 10:18:37.726342934 O: debug3: mm_request_receive_expect: entering, type 7 [preauth] 590s 10:18:37.727383122 O: debug3: mm_request_receive: entering [preauth] 590s 10:18:37.728439997 O: debug3: send packet: type 31 [preauth] 590s 10:18:37.729501558 O: debug3: send packet: type 21 [preauth] 590s 10:18:37.730673700 O: debug1: ssh_packet_send2_wrapped: resetting send seqnr 3 [preauth] 590s 10:18:37.731734247 O: debug2: ssh_set_newkeys: mode 1 [preauth] 590s 10:18:37.733110131 O: debug1: rekey out after 134217728 blocks [preauth] 590s 10:18:37.737292373 O: debug1: SSH2_MSG_NEWKEYS sent [preauth] 590s 10:18:37.738348137 O: debug1: Sending SSH2_MSG_EXT_INFO [preauth] 590s 10:18:37.739461683 O: debug3: send packet: type 7 [preauth] 590s 10:18:37.740502245 O: debug1: expecting SSH2_MSG_NEWKEYS [preauth] 590s 10:18:37.741556997 O: debug3: receive packet: type 21 [preauth] 590s 10:18:37.742625995 O: debug1: ssh_packet_read_poll2: resetting read seqnr 3 [preauth] 590s 10:18:37.743711746 O: debug1: SSH2_MSG_NEWKEYS received [preauth] 590s 10:18:37.744793310 O: debug2: ssh_set_newkeys: mode 0 [preauth] 590s 10:18:37.745827440 O: debug1: rekey in after 134217728 blocks [preauth] 590s 10:18:37.746848933 O: debug1: KEX done [preauth] 590s 10:18:37.747899811 O: debug3: receive packet: type 7 [preauth] 590s 10:18:37.748941371 O: debug1: SSH2_MSG_EXT_INFO received [preauth] 590s 10:18:37.751753120 O: debug3: kex_input_ext_info: extension ext-info-in-auth@openssh.com [preauth] 590s 10:18:37.754853058 O: debug1: kex_ext_info_check_ver: ext-info-in-auth@openssh.com=<0> [preauth] 590s 10:18:37.755821058 O: debug3: receive packet: type 5 [preauth] 590s 10:18:37.756868684 O: debug3: send packet: type 6 [preauth] 590s 10:18:37.757845434 O: debug3: receive packet: type 50 [preauth] 590s 10:18:37.758844933 O: debug1: userauth-request for user openssh-tests service ssh-connection method none [preauth] 590s 10:18:37.759834495 O: debug1: attempt 0 failures 0 [preauth] 590s 10:18:37.760807746 O: debug3: mm_getpwnamallow: entering [preauth] 590s 10:18:37.762008942 O: debug3: mm_request_send: entering, type 8 [preauth] 590s 10:18:37.762996935 O: debug3: mm_request_receive: entering 590s 10:18:37.764233509 O: debug3: monitor_read: checking request 8 590s 10:18:37.765242183 O: debug3: mm_answer_pwnamallow: entering 590s 10:18:37.766244871 O: debug2: parse_server_config_depth: config reprocess config len 1141 590s 10:18:37.768290433 O: debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1 590s 10:18:37.769260245 O: debug3: mm_request_send: entering, type 9 590s 10:18:37.770294809 O: debug2: monitor_read: 8 used once, disabling now 590s 10:18:37.771856370 O: debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM [preauth] 590s 10:18:37.772882434 O: debug3: mm_request_receive_expect: entering, type 9 [preauth] 590s 10:18:37.773932503 O: debug3: mm_request_receive: entering [preauth] 590s 10:18:37.774965938 O: debug3: process_channel_timeouts: setting 0 timeouts [preauth] 590s 10:18:37.775995870 O: debug3: channel_clear_timeouts: clearing [preauth] 590s 10:18:37.777018745 O: debug2: input_userauth_request: setting up authctxt for openssh-tests [preauth] 590s 10:18:37.778040184 O: debug3: mm_start_pam entering [preauth] 590s 10:18:37.779050059 O: debug3: mm_request_send: entering, type 100 [preauth] 590s 10:18:37.781142307 O: debug3: mm_request_receive: entering 590s 10:18:37.782204620 O: debug3: monitor_read: checking request 100 590s 10:18:37.783259682 O: debug1: PAM: initializing for "openssh-tests" 590s 10:18:37.784277245 O: debug1: PAM: setting PAM_TTY to "ssh" 590s 10:18:37.785294620 O: debug2: monitor_read: 100 used once, disabling now 590s 10:18:37.786305807 O: debug3: mm_inform_authserv: entering [preauth] 590s 10:18:37.787314434 O: debug3: mm_request_send: entering, type 4 [preauth] 590s 10:18:37.788355372 O: debug3: mm_request_receive: entering 590s 10:18:37.789378058 O: debug3: monitor_read: checking request 4 590s 10:18:37.793136870 O: debug3: mm_answer_authserv: service=ssh-connection, style=, role= 590s 10:18:37.794977621 O: debug2: monitor_read: 4 used once, disabling now 590s 10:18:37.796010745 O: debug1: kex_server_update_ext_info: Sending SSH2_MSG_EXT_INFO [preauth] 590s 10:18:37.798394059 O: debug3: send packet: type 7 [preauth] 590s 10:18:37.801920620 O: debug2: input_userauth_request: try method none [preauth] 590s 10:18:37.803842496 O: debug3: userauth_finish: failure partial=0 next methods="publickey,password,keyboard-interactive" [preauth] 590s 10:18:37.805574682 O: debug3: send packet: type 51 [preauth] 590s 10:18:37.806679194 O: debug3: receive packet: type 50 [preauth] 590s 10:18:37.807775622 O: debug1: userauth-request for user openssh-tests service ssh-connection method publickey [preauth] 590s 10:18:37.808782432 O: debug1: attempt 1 failures 0 [preauth] 590s 10:18:37.809829558 O: debug2: input_userauth_request: try method publickey [preauth] 590s 10:18:37.811326371 O: debug2: userauth_pubkey: valid user openssh-tests querying public key ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIMGrmADzkTmbYpbjUB6jSObf60LBA2XOFdJAnEuDFkgO [preauth] 590s 10:18:37.812515370 O: debug1: userauth_pubkey: publickey test pkalg ssh-ed25519 pkblob ED25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs [preauth] 590s 10:18:37.813596182 O: debug3: mm_key_allowed: entering [preauth] 590s 10:18:37.814661314 O: debug3: mm_request_send: entering, type 22 [preauth] 590s 10:18:37.815719373 O: debug3: mm_request_receive: entering 590s 10:18:37.818105746 O: debug3: monitor_read: checking request 22 590s 10:18:37.819082621 O: debug3: mm_answer_keyallowed: entering 590s 10:18:37.821869501 O: debug1: temporarily_use_uid: 1001/1001 (e=0/0) 590s 10:18:37.822957182 O: debug1: trying public key file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/authorized_keys_openssh-tests 590s 10:18:37.824097747 O: debug1: fd 6 clearing O_NONBLOCK 590s 10:18:37.825570121 O: debug1: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/authorized_keys_openssh-tests:1: matching key found: ED25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs 590s 10:18:37.826758870 O: debug1: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/authorized_keys_openssh-tests:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding 590s 10:18:37.827899621 O: debug3: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/authorized_keys_openssh-tests:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding 590s 10:18:37.829031559 O: Accepted key ED25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs found at /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/authorized_keys_openssh-tests:1 590s 10:18:37.831899496 O: debug2: auth_check_authkeys_file: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/authorized_keys_openssh-tests: processed 1/8 lines 590s 10:18:37.832973809 O: debug1: restore_uid: 0/0 590s 10:18:37.835327745 O: debug3: mm_answer_keyallowed: publickey authentication test: ED25519 key is allowed 590s 10:18:37.836457558 O: debug3: mm_request_send: entering, type 23 590s 10:18:37.837540309 O: debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth] 590s 10:18:37.838540997 O: debug3: mm_request_receive_expect: entering, type 23 [preauth] 590s 10:18:37.839557307 O: debug3: mm_request_receive: entering [preauth] 590s 10:18:37.840610760 O: debug3: send packet: type 60 [preauth] 590s 10:18:37.841923246 O: debug2: userauth_pubkey: authenticated 0 pkalg ssh-ed25519 [preauth] 590s 10:18:37.842980433 O: debug3: user_specific_delay: user specific delay 0.000ms [preauth] 590s 10:18:37.844120745 O: debug3: ensure_minimum_time_since: elapsed 3.785ms, delaying 1.811ms (requested 5.596ms) [preauth] 590s 10:18:37.845199370 O: Postponed publickey for openssh-tests from UNKNOWN port 65535 ssh2 [preauth] 590s 10:18:37.846305246 O: debug3: receive packet: type 50 [preauth] 590s 10:18:37.848521183 O: debug1: userauth-request for user openssh-tests service ssh-connection method publickey-hostbound-v00@openssh.com [preauth] 590s 10:18:37.849653630 O: debug1: attempt 2 failures 0 [preauth] 590s 10:18:37.850771246 O: debug2: input_userauth_request: try method publickey-hostbound-v00@openssh.com [preauth] 590s 10:18:37.852030939 O: debug2: userauth_pubkey: valid user openssh-tests attempting public key ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIMGrmADzkTmbYpbjUB6jSObf60LBA2XOFdJAnEuDFkgO [preauth] 590s 10:18:37.853114558 O: debug3: userauth_pubkey: publickey-hostbound-v00@openssh.com have ssh-ed25519 signature for ED25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs [preauth] 590s 10:18:37.854149683 O: debug3: mm_key_allowed: entering [preauth] 590s 10:18:37.855165870 O: debug3: mm_request_send: entering, type 22 [preauth] 590s 10:18:37.856226887 O: debug3: mm_request_receive: entering 590s 10:18:37.857411246 O: debug3: monitor_read: checking request 22 590s 10:18:37.858570683 O: debug3: mm_answer_keyallowed: entering 590s 10:18:37.863101496 O: debug1: temporarily_use_uid: 1001/1001 (e=0/0) 590s 10:18:37.864621620 O: debug1: trying public key file /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/authorized_keys_openssh-tests 590s 10:18:37.865990373 O: debug1: fd 6 clearing O_NONBLOCK 590s 10:18:37.867374378 O: debug1: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/authorized_keys_openssh-tests:1: matching key found: ED25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs 590s 10:18:37.868698562 O: debug1: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/authorized_keys_openssh-tests:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding 590s 10:18:37.869924376 O: debug3: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/authorized_keys_openssh-tests:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding 590s 10:18:37.874705187 O: Accepted key ED25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs found at /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/authorized_keys_openssh-tests:1 590s 10:18:37.876092255 O: debug2: auth_check_authkeys_file: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/authorized_keys_openssh-tests: processed 1/8 lines 590s 10:18:37.877179381 O: debug1: restore_uid: 0/0 590s 10:18:37.878363377 O: debug3: mm_answer_keyallowed: publickey authentication: ED25519 key is allowed 590s 10:18:37.879406121 O: debug3: mm_request_send: entering, type 23 590s 10:18:37.880569434 O: debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth] 590s 10:18:37.881709246 O: debug3: mm_request_receive_expect: entering, type 23 [preauth] 590s 10:18:37.882877495 O: debug3: mm_request_receive: entering [preauth] 590s 10:18:37.883967182 O: debug3: mm_sshkey_verify: entering [preauth] 590s 10:18:37.885141871 O: debug3: mm_request_send: entering, type 24 [preauth] 590s 10:18:37.888345810 O: debug3: mm_request_receive: entering 590s 10:18:37.889733813 O: debug3: monitor_read: checking request 24 590s 10:18:37.891421746 O: debug3: mm_answer_keyverify: publickey ED25519 signature using ssh-ed25519 verified 590s 10:18:37.893790059 O: debug1: auth_activate_options: setting new authentication options 590s 10:18:37.895083495 O: debug3: mm_request_send: entering, type 25 590s 10:18:37.896348432 O: debug3: mm_request_receive_expect: entering, type 102 590s 10:18:37.897460557 O: debug3: mm_request_receive: entering 590s 10:18:37.898593807 O: debug1: do_pam_account: called 590s 10:18:37.899799496 O: debug2: do_pam_account: auth information in SSH_AUTH_INFO_0 590s 10:18:37.901268497 O: debug3: PAM: do_pam_account pam_acct_mgmt = 0 (Success) 590s 10:18:37.902476195 O: debug3: mm_request_send: entering, type 103 590s 10:18:37.903678310 O: Accepted publickey for openssh-tests from UNKNOWN port 65535 ssh2: ED25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs 590s 10:18:37.904957059 O: debug1: monitor_child_preauth: user openssh-tests authenticated by privileged process 590s 10:18:37.907205995 O: debug3: mm_get_keystate: Waiting for new keys 590s 10:18:37.908375445 O: debug3: mm_request_receive_expect: entering, type 26 590s 10:18:37.909706245 O: debug3: mm_request_receive: entering 590s 10:18:37.911171183 O: debug3: mm_get_keystate: GOT new keys 590s 10:18:37.912312818 O: debug3: mm_sshkey_verify: waiting for MONITOR_ANS_KEYVERIFY [preauth] 590s 10:18:37.913495319 O: debug3: mm_request_receive_expect: entering, type 25 [preauth] 590s 10:18:37.914743183 O: debug3: mm_request_receive: entering [preauth] 590s 10:18:37.915989933 O: debug1: auth_activate_options: setting new authentication options [preauth] 590s 10:18:37.917183881 O: debug2: userauth_pubkey: authenticated 1 pkalg ssh-ed25519 [preauth] 590s 10:18:37.918344247 O: debug3: user_specific_delay: user specific delay 0.000ms [preauth] 590s 10:18:37.920556683 O: debug3: ensure_minimum_time_since: elapsed 6.866ms, delaying 4.325ms (requested 5.596ms) [preauth] 590s 10:18:37.921882683 O: debug3: mm_do_pam_account entering [preauth] 590s 10:18:37.923243121 O: debug3: mm_request_send: entering, type 102 [preauth] 590s 10:18:37.932814372 O: debug3: mm_request_receive_expect: entering, type 103 [preauth] 590s 10:18:37.934496933 O: debug3: mm_request_receive: entering [preauth] 590s 10:18:37.935684746 O: debug3: mm_do_pam_account returning 1 [preauth] 590s 10:18:37.936872623 O: debug3: send packet: type 52 [preauth] 590s 10:18:37.938074557 O: debug3: mm_request_send: entering, type 26 [preauth] 590s 10:18:37.939610559 O: debug3: mm_send_keystate: Finished sending state [preauth] 590s 10:18:37.940681933 O: debug1: monitor_read_log: child log fd closed 590s 10:18:37.942413817 O: debug3: ssh_sandbox_parent_finish: finished 590s 10:18:37.943683683 O: debug1: PAM: establishing credentials 590s 10:18:37.946016933 O: debug3: PAM: opening session 590s 10:18:37.947416621 O: debug2: do_pam_session: auth information in SSH_AUTH_INFO_0 590s 10:18:37.948788122 O: debug3: PAM: sshpam_store_conv called with 1 messages 590s 10:18:37.950167057 O: User child is on pid 6739 590s 10:18:37.951468434 O: debug1: SELinux support disabled 590s 10:18:37.952793006 O: debug1: PAM: establishing credentials 590s 10:18:37.953922121 O: debug1: permanently_set_uid: 1001/1001 590s 10:18:37.955169323 O: debug3: monitor_apply_keystate: packet_set_state 590s 10:18:37.956344745 O: debug2: ssh_set_newkeys: mode 0 590s 10:18:37.957502314 O: debug1: rekey in after 134217728 blocks 590s 10:18:37.961169256 O: debug2: ssh_set_newkeys: mode 1 590s 10:18:37.962529069 O: debug1: rekey out after 134217728 blocks 590s 10:18:37.963471932 O: debug1: ssh_packet_set_postauth: called 590s 10:18:37.964389872 O: debug3: ssh_packet_set_state: done 590s 10:18:37.965356187 O: debug3: notify_hostkeys: key 0: ssh-ed25519 SHA256:cgszqUlvTk/HHaRu646xmIXdUTCX1L4E7uiPb18vbBs 590s 10:18:37.966320895 O: debug3: notify_hostkeys: key 1: sk-ssh-ed25519@openssh.com SHA256:tn0wEXzlEcLUgQoyfSoSUpH8UzuhpQ99pCIIVQ7DXHU 590s 10:18:37.967346872 O: debug3: notify_hostkeys: key 2: ecdsa-sha2-nistp256 SHA256:Ai8soqn3wWZbkyZRzWtItCxVLWIdReaWVbXYiHyGKVg 591s 10:18:37.969496684 O: debug3: notify_hostkeys: key 3: ecdsa-sha2-nistp384 SHA256:+BnanonMkSiGYDqIJZpmzvcawERi33cp1ohdd0WfLYU 591s 10:18:37.970475933 O: debug3: notify_hostkeys: key 4: ecdsa-sha2-nistp521 SHA256:5HbT8Q5SUj/JPu1U5l6dsU+ywpgIgquHq9GbUUHdHpA 591s 10:18:37.971856997 O: debug3: notify_hostkeys: key 5: sk-ecdsa-sha2-nistp256@openssh.com SHA256:75VjGZMXkX3c+2CW2W+4DoQXLO1lnsKTk85WWP9FoQo 591s 10:18:37.972850810 O: debug3: notify_hostkeys: key 6: ssh-dss SHA256:GjUAr2mka11mhOhPdx+MKL6RtB3yg8XSHdsln2OkWo8 591s 10:18:37.973864062 O: debug3: notify_hostkeys: key 7: ssh-rsa SHA256:H1J1FUVg/SKwD7ejw44/fymuaKKMAr9aigfpTfPtucg 591s 10:18:37.975075871 O: debug3: notify_hostkeys: sent 8 hostkeys 591s 10:18:37.976206182 O: debug3: send packet: type 80 591s 10:18:37.977338558 O: debug1: active: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding 591s 10:18:37.978539558 O: debug3: sending debug message: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/authorized_keys_openssh-tests:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding 591s 10:18:37.979615871 O: debug3: send packet: type 4 591s 10:18:37.980847121 O: debug3: sending debug message: /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/authorized_keys_openssh-tests:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding 591s 10:18:37.983354496 O: debug3: send packet: type 4 591s 10:18:37.984424371 O: debug1: Entering interactive session for SSH2. 591s 10:18:37.985515370 O: debug1: server_init_dispatch 591s 10:18:37.986547245 O: debug3: receive packet: type 90 591s 10:18:37.987582808 O: debug1: server_input_channel_open: ctype session rchan 0 win 2097152 max 32768 591s 10:18:37.988596557 O: debug1: input_session_request 591s 10:18:37.989610682 O: debug1: channel 0: new session [server-session] (inactive timeout: 0) 591s 10:18:37.990794808 O: debug2: session_new: allocate (allocated 0 max 10) 591s 10:18:37.994779183 O: debug3: session_unused: session id 0 unused 591s 10:18:37.996407996 O: debug1: session_new: session 0 591s 10:18:37.997835807 O: debug1: session_open: channel 0 591s 10:18:37.999411878 O: debug1: session_open: session 0: link with channel 0 591s 10:18:38.003572372 O: debug1: server_input_channel_open: confirm session 591s 10:18:38.004826183 O: debug3: send packet: type 91 591s 10:18:38.005949121 O: debug3: receive packet: type 80 591s 10:18:38.007134559 O: debug1: server_input_global_request: rtype no-more-sessions@openssh.com want_reply 0 591s 10:18:38.008215995 O: debug3: receive packet: type 98 591s 10:18:38.009296183 O: debug1: server_input_channel_req: channel 0 request exec reply 1 591s 10:18:38.010313121 O: debug1: session_by_channel: session 0 channel 0 591s 10:18:38.011363745 O: debug1: session_input_channel_req: session 0 req exec 591s 10:18:38.012400939 O: debug2: channel_set_xtype: labeled channel 0 as session:command (inactive timeout 0) 591s 10:18:38.023634684 O: Starting session: command for openssh-tests from UNKNOWN port 65535 id 0 591s 10:18:38.025054808 O: debug3: mm_audit_run_command entering command cat > /tmp/autopkgtest.KeoRc6/autopkgtest_tmp/user/regress/copy 591s 10:18:38.026159247 O: debug3: mm_request_send: entering, type 113 591s 10:18:38.027252194 O: debug3: mm_request_receive: entering 591s 10:18:38.032024870 O: debug3: monitor_read: checking request 113 591s 10:18:38.035093995 O: debug3: mm_answer_audit_command entering 591s 10:18:38.036210701 O: debug3: Copy environment: PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin 591s 10:18:38.037266370 O: debug3: Copy environment: TERM=linux 591s 10:18:38.038271495 O: debug3: Copy environment: http_proxy=http://squid.internal:3128 591s 10:18:38.039286756 O: debug3: Copy environment: https_proxy=http://squid.internal:3128 591s 10:18:38.040638574 O: debug3: Copy environment: no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com 591s 10:18:38.041975130 O: debug3: Copy environment: LANG=C.UTF-8 591s 10:18:38.043086195 O: debug2: fd 11 setting O_NONBLOCK 591s 10:18:38.044248872 O: debug2: fd 10 setting O_NONBLOCK 591s 10:18:38.045406566 O: debug2: fd 13 setting O_NONBLOCK 591s 10:18:38.048436308 O: debug3: send packet: type 99 591s 10:18:38.051370756 O: debug3: receive packet: type 20 591s 10:18:38.052330812 O: debug1: SSH2_MSG_KEXINIT received 591s 10:18:38.053395503 O: debug3: send packet: type 20 591s 10:18:38.055475061 O: debug1: SSH2_MSG_KEXINIT sent 591s 10:18:38.056438996 O: debug2: local server KEXINIT proposal 591s 10:18:38.057504120 O: debug2: KEX algorithms: sntrup761x25519-sha512@openssh.com,curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha210:18:38.058985383 I: Finished with exitcode 2 591s Synchronizing state of haveged.service with SysV service script with /usr/lib/systemd/systemd-sysv-install. 591s Executing: /usr/lib/systemd/systemd-sysv-install disable haveged 592s Removed "/etc/systemd/system/sysinit.target.wants/haveged.service". 592s info: Looking for files to backup/remove ... 592s info: Removing files ... 592s info: Removing crontab ... 592s info: Removing user `openssh-tests' ... 592s userdel: user openssh-tests is currently used by process 5392 592s fatal: `/usr/sbin/userdel openssh-tests' returned error code 8. Exiting. 592s autopkgtest [10:18:39]: test regress: -----------------------] 593s regress FAIL non-zero exit status 82 593s autopkgtest [10:18:40]: test regress: - - - - - - - - - - results - - - - - - - - - - 594s autopkgtest [10:18:41]: test systemd-socket-activation: preparing testbed 708s autopkgtest [10:20:35]: testbed dpkg architecture: s390x 708s autopkgtest [10:20:35]: testbed apt version: 2.7.14build2 708s autopkgtest [10:20:35]: @@@@@@@@@@@@@@@@@@@@ test bed setup 708s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [117 kB] 709s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [331 kB] 709s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [7736 B] 709s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [239 kB] 709s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/multiverse Sources [2340 B] 709s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main s390x Packages [268 kB] 709s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main s390x c-n-f Metadata [3032 B] 709s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/restricted s390x Packages [976 B] 709s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/restricted s390x c-n-f Metadata [116 B] 709s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/universe s390x Packages [371 kB] 709s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/universe s390x c-n-f Metadata [7292 B] 709s Get:12 http://ftpmaster.internal/ubuntu noble-proposed/multiverse s390x c-n-f Metadata [116 B] 711s Fetched 1348 kB in 1s (1086 kB/s) 711s Reading package lists... 715s Reading package lists... 715s Building dependency tree... 715s Reading state information... 715s Calculating upgrade... 716s The following packages will be upgraded: 716s debconf debconf-i18n ftp python3-cffi-backend python3-debconf tcpdump tnftp 716s 7 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 716s Need to get 1016 kB of archives. 716s After this operation, 199 kB disk space will be freed. 716s Get:1 http://ftpmaster.internal/ubuntu noble-proposed/main s390x python3-debconf all 1.5.86ubuntu1 [4158 B] 716s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/main s390x debconf-i18n all 1.5.86ubuntu1 [205 kB] 716s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/main s390x debconf all 1.5.86ubuntu1 [124 kB] 716s Get:4 http://ftpmaster.internal/ubuntu noble/main s390x python3-cffi-backend s390x 1.16.0-2build1 [81.4 kB] 716s Get:5 http://ftpmaster.internal/ubuntu noble/main s390x tnftp s390x 20230507-2build3 [107 kB] 716s Get:6 http://ftpmaster.internal/ubuntu noble/main s390x ftp all 20230507-2build3 [4728 B] 716s Get:7 http://ftpmaster.internal/ubuntu noble/main s390x tcpdump s390x 4.99.4-3ubuntu4 [490 kB] 717s Preconfiguring packages ... 717s Fetched 1016 kB in 1s (1462 kB/s) 717s (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 ... 78332 files and directories currently installed.) 717s Preparing to unpack .../python3-debconf_1.5.86ubuntu1_all.deb ... 717s Unpacking python3-debconf (1.5.86ubuntu1) over (1.5.86) ... 718s Preparing to unpack .../debconf-i18n_1.5.86ubuntu1_all.deb ... 718s Unpacking debconf-i18n (1.5.86ubuntu1) over (1.5.86) ... 718s Preparing to unpack .../debconf_1.5.86ubuntu1_all.deb ... 718s Unpacking debconf (1.5.86ubuntu1) over (1.5.86) ... 718s Setting up debconf (1.5.86ubuntu1) ... 718s (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 ... 78332 files and directories currently installed.) 718s Preparing to unpack .../python3-cffi-backend_1.16.0-2build1_s390x.deb ... 718s Unpacking python3-cffi-backend:s390x (1.16.0-2build1) over (1.16.0-2) ... 718s Preparing to unpack .../tnftp_20230507-2build3_s390x.deb ... 718s Unpacking tnftp (20230507-2build3) over (20230507-2build2) ... 718s Preparing to unpack .../ftp_20230507-2build3_all.deb ... 718s Unpacking ftp (20230507-2build3) over (20230507-2build2) ... 718s Preparing to unpack .../tcpdump_4.99.4-3ubuntu4_s390x.deb ... 718s Unpacking tcpdump (4.99.4-3ubuntu4) over (4.99.4-3ubuntu3) ... 718s Setting up tcpdump (4.99.4-3ubuntu4) ... 719s Setting up python3-debconf (1.5.86ubuntu1) ... 719s Setting up debconf-i18n (1.5.86ubuntu1) ... 719s Setting up tnftp (20230507-2build3) ... 719s Setting up python3-cffi-backend:s390x (1.16.0-2build1) ... 719s Setting up ftp (20230507-2build3) ... 719s Processing triggers for man-db (2.12.0-4build1) ... 721s Reading package lists... 721s Building dependency tree... 721s Reading state information... 722s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 722s Hit:1 http://ftpmaster.internal/ubuntu noble InRelease 722s Hit:2 http://ftpmaster.internal/ubuntu noble-updates InRelease 722s Hit:3 http://ftpmaster.internal/ubuntu noble-security InRelease 722s Hit:4 http://ftpmaster.internal/ubuntu noble-proposed InRelease 725s Reading package lists... 725s Reading package lists... 726s Building dependency tree... 726s Reading state information... 726s Calculating upgrade... 726s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 727s Reading package lists... 727s Building dependency tree... 727s Reading state information... 727s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 732s Reading package lists... 732s Building dependency tree... 732s Reading state information... 732s Starting pkgProblemResolver with broken count: 0 733s Starting 2 pkgProblemResolver with broken count: 0 733s Done 733s The following NEW packages will be installed: 733s autopkgtest-satdep 733s 0 upgraded, 1 newly installed, 0 to remove and 0 not upgraded. 733s Need to get 0 B/728 B of archives. 733s After this operation, 0 B of additional disk space will be used. 733s Get:1 /tmp/autopkgtest.KeoRc6/2-autopkgtest-satdep.deb autopkgtest-satdep s390x 0 [728 B] 733s Selecting previously unselected package autopkgtest-satdep. 733s (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 ... 78331 files and directories currently installed.) 733s Preparing to unpack .../2-autopkgtest-satdep.deb ... 733s Unpacking autopkgtest-satdep (0) ... 733s Setting up autopkgtest-satdep (0) ... 737s (Reading database ... 78331 files and directories currently installed.) 737s Removing autopkgtest-satdep (0) ... 740s autopkgtest [10:21:07]: test systemd-socket-activation: [----------------------- 747s Stopping ssh.service... 747s Checking that ssh.socket is active and listening... 747s Checking that ssh.service is inactive/dead... 747s Checking that a connection attempt activates ssh.service... 747s Warning: Permanently added 'localhost' (ED25519) to the list of known hosts. 748s Checking that sshd can be re-executed... 748s Checking sshd can run in debug mode... 748s debug1: SELinux support disabled 748s debug1: PAM: reinitializing credentials 748s debug1: permanently_set_uid: 0/0 748s debug3: Copy environment: XDG_SESSION_ID=7 748s debug3: Copy environment: XDG_RUNTIME_DIR=/run/user/0 748s debug3: Copy environment: DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/0/bus 748s debug3: Copy environment: XDG_SESSION_TYPE=tty 748s debug3: Copy environment: XDG_SESSION_CLASS=user 748s debug3: Copy environment: PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin 748s debug3: Copy environment: TERM=linux 748s debug3: Copy environment: http_proxy=http://squid.internal:3128 748s debug3: Copy environment: https_proxy=http://squid.internal:3128 748s debug3: Copy environment: no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com 748s debug3: Copy environment: LANG=C.UTF-8 748s Environment: 748s LANG=C.UTF-8 748s USER=root 748s LOGNAME=root 748s HOME=/root 748s PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin 748s SHELL=/bin/bash 748s XDG_SESSION_ID=7 748s XDG_RUNTIME_DIR=/run/user/0 748s DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/0/bus 748s XDG_SESSION_TYPE=tty 748s XDG_SESSION_CLASS=user 748s TERM=linux 748s http_proxy=http://squid.internal:3128 748s https_proxy=http://squid.internal:3128 748s no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,launchpadlibrarian 748s SSH_CLIENT=::1 53416 22 748s SSH_CONNECTION=::1 53416 ::1 22 748s Done. 749s autopkgtest [10:21:16]: test systemd-socket-activation: -----------------------] 749s autopkgtest [10:21:16]: test systemd-socket-activation: - - - - - - - - - - results - - - - - - - - - - 749s systemd-socket-activation PASS 750s autopkgtest [10:21:17]: test sshd-socket-generator: preparing testbed 751s Reading package lists... 752s Building dependency tree... 752s Reading state information... 752s Starting pkgProblemResolver with broken count: 0 752s Starting 2 pkgProblemResolver with broken count: 0 752s Done 753s The following NEW packages will be installed: 753s autopkgtest-satdep 753s 0 upgraded, 1 newly installed, 0 to remove and 0 not upgraded. 753s Need to get 0 B/720 B of archives. 753s After this operation, 0 B of additional disk space will be used. 753s Get:1 /tmp/autopkgtest.KeoRc6/3-autopkgtest-satdep.deb autopkgtest-satdep s390x 0 [720 B] 754s Selecting previously unselected package autopkgtest-satdep. 754s (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 ... 78331 files and directories currently installed.) 754s Preparing to unpack .../3-autopkgtest-satdep.deb ... 754s Unpacking autopkgtest-satdep (0) ... 754s Setting up autopkgtest-satdep (0) ... 758s (Reading database ... 78331 files and directories currently installed.) 758s Removing autopkgtest-satdep (0) ... 759s autopkgtest [10:21:26]: test sshd-socket-generator: [----------------------- 759s test_default...PASS 759s test_custom_port...PASS 759s test_default_and_custom_port...PASS 759s test_mutiple_custom_ports...PASS 759s test_custom_listenaddress...PASS 759s test_custom_listenaddress_and_port...PASS 759s test_custom_ipv6_listenaddress...PASS 759s autopkgtest [10:21:26]: test sshd-socket-generator: -----------------------] 760s autopkgtest [10:21:27]: test sshd-socket-generator: - - - - - - - - - - results - - - - - - - - - - 760s sshd-socket-generator PASS 760s autopkgtest [10:21:27]: test ssh-gssapi: preparing testbed 903s autopkgtest [10:23:50]: testbed dpkg architecture: s390x 903s autopkgtest [10:23:50]: testbed apt version: 2.7.14build2 903s autopkgtest [10:23:50]: @@@@@@@@@@@@@@@@@@@@ test bed setup 903s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [117 kB] 904s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [239 kB] 904s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [7736 B] 904s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [331 kB] 904s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/multiverse Sources [2340 B] 904s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main s390x Packages [268 kB] 905s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main s390x c-n-f Metadata [3032 B] 905s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/restricted s390x Packages [976 B] 905s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/restricted s390x c-n-f Metadata [116 B] 905s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/universe s390x Packages [371 kB] 905s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/universe s390x c-n-f Metadata [7292 B] 905s Get:12 http://ftpmaster.internal/ubuntu noble-proposed/multiverse s390x c-n-f Metadata [116 B] 907s Fetched 1348 kB in 2s (682 kB/s) 907s Reading package lists... 910s Reading package lists... 911s Building dependency tree... 911s Reading state information... 911s Calculating upgrade... 911s The following packages will be upgraded: 911s debconf debconf-i18n ftp python3-cffi-backend python3-debconf tcpdump tnftp 911s 7 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 911s Need to get 1016 kB of archives. 911s After this operation, 199 kB disk space will be freed. 911s Get:1 http://ftpmaster.internal/ubuntu noble-proposed/main s390x python3-debconf all 1.5.86ubuntu1 [4158 B] 912s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/main s390x debconf-i18n all 1.5.86ubuntu1 [205 kB] 912s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/main s390x debconf all 1.5.86ubuntu1 [124 kB] 912s Get:4 http://ftpmaster.internal/ubuntu noble/main s390x python3-cffi-backend s390x 1.16.0-2build1 [81.4 kB] 912s Get:5 http://ftpmaster.internal/ubuntu noble/main s390x tnftp s390x 20230507-2build3 [107 kB] 912s Get:6 http://ftpmaster.internal/ubuntu noble/main s390x ftp all 20230507-2build3 [4728 B] 912s Get:7 http://ftpmaster.internal/ubuntu noble/main s390x tcpdump s390x 4.99.4-3ubuntu4 [490 kB] 913s Preconfiguring packages ... 913s Fetched 1016 kB in 1s (892 kB/s) 913s (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 ... 78332 files and directories currently installed.) 913s Preparing to unpack .../python3-debconf_1.5.86ubuntu1_all.deb ... 913s Unpacking python3-debconf (1.5.86ubuntu1) over (1.5.86) ... 914s Preparing to unpack .../debconf-i18n_1.5.86ubuntu1_all.deb ... 914s Unpacking debconf-i18n (1.5.86ubuntu1) over (1.5.86) ... 914s Preparing to unpack .../debconf_1.5.86ubuntu1_all.deb ... 914s Unpacking debconf (1.5.86ubuntu1) over (1.5.86) ... 914s Setting up debconf (1.5.86ubuntu1) ... 914s (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 ... 78332 files and directories currently installed.) 914s Preparing to unpack .../python3-cffi-backend_1.16.0-2build1_s390x.deb ... 914s Unpacking python3-cffi-backend:s390x (1.16.0-2build1) over (1.16.0-2) ... 914s Preparing to unpack .../tnftp_20230507-2build3_s390x.deb ... 914s Unpacking tnftp (20230507-2build3) over (20230507-2build2) ... 914s Preparing to unpack .../ftp_20230507-2build3_all.deb ... 914s Unpacking ftp (20230507-2build3) over (20230507-2build2) ... 914s Preparing to unpack .../tcpdump_4.99.4-3ubuntu4_s390x.deb ... 914s Unpacking tcpdump (4.99.4-3ubuntu4) over (4.99.4-3ubuntu3) ... 914s Setting up tcpdump (4.99.4-3ubuntu4) ... 915s Setting up python3-debconf (1.5.86ubuntu1) ... 915s Setting up debconf-i18n (1.5.86ubuntu1) ... 915s Setting up tnftp (20230507-2build3) ... 915s Setting up python3-cffi-backend:s390x (1.16.0-2build1) ... 915s Setting up ftp (20230507-2build3) ... 915s Processing triggers for man-db (2.12.0-4build1) ... 917s Reading package lists... 918s Building dependency tree... 918s Reading state information... 918s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 919s Hit:1 http://ftpmaster.internal/ubuntu noble InRelease 919s Hit:2 http://ftpmaster.internal/ubuntu noble-updates InRelease 919s Hit:3 http://ftpmaster.internal/ubuntu noble-security InRelease 919s Hit:4 http://ftpmaster.internal/ubuntu noble-proposed InRelease 921s Reading package lists... 922s Reading package lists... 922s Building dependency tree... 922s Reading state information... 922s Calculating upgrade... 923s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 923s Reading package lists... 923s Building dependency tree... 923s Reading state information... 924s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 928s Reading package lists... 929s Building dependency tree... 929s Reading state information... 929s Starting pkgProblemResolver with broken count: 0 929s Starting 2 pkgProblemResolver with broken count: 0 929s Done 930s The following additional packages will be installed: 930s krb5-admin-server krb5-config krb5-kdc krb5-user libevent-2.1-7t64 930s libgssrpc4t64 libkadm5clnt-mit12 libkadm5srv-mit12 libkdb5-10t64 930s libverto-libevent1t64 libverto1t64 930s Suggested packages: 930s krb5-kdc-ldap krb5-kpropd krb5-k5tls krb5-doc 930s The following NEW packages will be installed: 930s autopkgtest-satdep krb5-admin-server krb5-config krb5-kdc krb5-user 930s libevent-2.1-7t64 libgssrpc4t64 libkadm5clnt-mit12 libkadm5srv-mit12 930s libkdb5-10t64 libverto-libevent1t64 libverto1t64 930s 0 upgraded, 12 newly installed, 0 to remove and 0 not upgraded. 930s Need to get 784 kB/785 kB of archives. 930s After this operation, 2604 kB of additional disk space will be used. 930s Get:1 /tmp/autopkgtest.KeoRc6/4-autopkgtest-satdep.deb autopkgtest-satdep s390x 0 [728 B] 930s Get:2 http://ftpmaster.internal/ubuntu noble/main s390x krb5-config all 2.7 [22.0 kB] 930s Get:3 http://ftpmaster.internal/ubuntu noble/main s390x libgssrpc4t64 s390x 1.20.1-6ubuntu2 [60.5 kB] 930s Get:4 http://ftpmaster.internal/ubuntu noble/main s390x libkadm5clnt-mit12 s390x 1.20.1-6ubuntu2 [40.9 kB] 930s Get:5 http://ftpmaster.internal/ubuntu noble/main s390x libkdb5-10t64 s390x 1.20.1-6ubuntu2 [42.4 kB] 930s Get:6 http://ftpmaster.internal/ubuntu noble/main s390x libkadm5srv-mit12 s390x 1.20.1-6ubuntu2 [55.9 kB] 930s Get:7 http://ftpmaster.internal/ubuntu noble/universe s390x krb5-user s390x 1.20.1-6ubuntu2 [110 kB] 931s Get:8 http://ftpmaster.internal/ubuntu noble/main s390x libevent-2.1-7t64 s390x 2.1.12-stable-9ubuntu2 [147 kB] 931s Get:9 http://ftpmaster.internal/ubuntu noble/main s390x libverto1t64 s390x 0.3.1-1.2ubuntu3 [11.0 kB] 931s Get:10 http://ftpmaster.internal/ubuntu noble/main s390x libverto-libevent1t64 s390x 0.3.1-1.2ubuntu3 [6384 B] 931s Get:11 http://ftpmaster.internal/ubuntu noble/universe s390x krb5-kdc s390x 1.20.1-6ubuntu2 [191 kB] 931s Get:12 http://ftpmaster.internal/ubuntu noble/universe s390x krb5-admin-server s390x 1.20.1-6ubuntu2 [96.9 kB] 931s Preconfiguring packages ... 932s Fetched 784 kB in 1s (785 kB/s) 932s Selecting previously unselected package krb5-config. 932s (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 ... 78331 files and directories currently installed.) 932s Preparing to unpack .../00-krb5-config_2.7_all.deb ... 932s Unpacking krb5-config (2.7) ... 932s Selecting previously unselected package libgssrpc4t64:s390x. 932s Preparing to unpack .../01-libgssrpc4t64_1.20.1-6ubuntu2_s390x.deb ... 932s Unpacking libgssrpc4t64:s390x (1.20.1-6ubuntu2) ... 932s Selecting previously unselected package libkadm5clnt-mit12:s390x. 932s Preparing to unpack .../02-libkadm5clnt-mit12_1.20.1-6ubuntu2_s390x.deb ... 932s Unpacking libkadm5clnt-mit12:s390x (1.20.1-6ubuntu2) ... 932s Selecting previously unselected package libkdb5-10t64:s390x. 932s Preparing to unpack .../03-libkdb5-10t64_1.20.1-6ubuntu2_s390x.deb ... 932s Unpacking libkdb5-10t64:s390x (1.20.1-6ubuntu2) ... 932s Selecting previously unselected package libkadm5srv-mit12:s390x. 932s Preparing to unpack .../04-libkadm5srv-mit12_1.20.1-6ubuntu2_s390x.deb ... 932s Unpacking libkadm5srv-mit12:s390x (1.20.1-6ubuntu2) ... 932s Selecting previously unselected package krb5-user. 932s Preparing to unpack .../05-krb5-user_1.20.1-6ubuntu2_s390x.deb ... 932s Unpacking krb5-user (1.20.1-6ubuntu2) ... 932s Selecting previously unselected package libevent-2.1-7t64:s390x. 932s Preparing to unpack .../06-libevent-2.1-7t64_2.1.12-stable-9ubuntu2_s390x.deb ... 932s Unpacking libevent-2.1-7t64:s390x (2.1.12-stable-9ubuntu2) ... 932s Selecting previously unselected package libverto1t64:s390x. 932s Preparing to unpack .../07-libverto1t64_0.3.1-1.2ubuntu3_s390x.deb ... 932s Unpacking libverto1t64:s390x (0.3.1-1.2ubuntu3) ... 932s Selecting previously unselected package libverto-libevent1t64:s390x. 933s Preparing to unpack .../08-libverto-libevent1t64_0.3.1-1.2ubuntu3_s390x.deb ... 933s Unpacking libverto-libevent1t64:s390x (0.3.1-1.2ubuntu3) ... 933s Selecting previously unselected package krb5-kdc. 933s Preparing to unpack .../09-krb5-kdc_1.20.1-6ubuntu2_s390x.deb ... 933s Unpacking krb5-kdc (1.20.1-6ubuntu2) ... 933s Selecting previously unselected package krb5-admin-server. 933s Preparing to unpack .../10-krb5-admin-server_1.20.1-6ubuntu2_s390x.deb ... 933s Unpacking krb5-admin-server (1.20.1-6ubuntu2) ... 933s Selecting previously unselected package autopkgtest-satdep. 933s Preparing to unpack .../11-4-autopkgtest-satdep.deb ... 933s Unpacking autopkgtest-satdep (0) ... 933s Setting up libevent-2.1-7t64:s390x (2.1.12-stable-9ubuntu2) ... 933s Setting up libgssrpc4t64:s390x (1.20.1-6ubuntu2) ... 933s Setting up krb5-config (2.7) ... 933s Setting up libkadm5clnt-mit12:s390x (1.20.1-6ubuntu2) ... 933s Setting up libkdb5-10t64:s390x (1.20.1-6ubuntu2) ... 933s Setting up libkadm5srv-mit12:s390x (1.20.1-6ubuntu2) ... 933s Setting up krb5-user (1.20.1-6ubuntu2) ... 933s update-alternatives: using /usr/bin/kinit.mit to provide /usr/bin/kinit (kinit) in auto mode 933s update-alternatives: using /usr/bin/klist.mit to provide /usr/bin/klist (klist) in auto mode 933s update-alternatives: using /usr/bin/kswitch.mit to provide /usr/bin/kswitch (kswitch) in auto mode 933s update-alternatives: using /usr/bin/ksu.mit to provide /usr/bin/ksu (ksu) in auto mode 933s update-alternatives: using /usr/bin/kpasswd.mit to provide /usr/bin/kpasswd (kpasswd) in auto mode 933s update-alternatives: using /usr/bin/kdestroy.mit to provide /usr/bin/kdestroy (kdestroy) in auto mode 933s update-alternatives: using /usr/bin/kadmin.mit to provide /usr/bin/kadmin (kadmin) in auto mode 933s update-alternatives: using /usr/bin/ktutil.mit to provide /usr/bin/ktutil (ktutil) in auto mode 933s Setting up libverto1t64:s390x (0.3.1-1.2ubuntu3) ... 933s Setting up libverto-libevent1t64:s390x (0.3.1-1.2ubuntu3) ... 933s Setting up krb5-kdc (1.20.1-6ubuntu2) ... 934s Created symlink /etc/systemd/system/multi-user.target.wants/krb5-kdc.service → /usr/lib/systemd/system/krb5-kdc.service. 934s Could not execute systemctl: at /usr/bin/deb-systemd-invoke line 148. 934s Setting up krb5-admin-server (1.20.1-6ubuntu2) ... 935s Created symlink /etc/systemd/system/multi-user.target.wants/krb5-admin-server.service → /usr/lib/systemd/system/krb5-admin-server.service. 936s Setting up autopkgtest-satdep (0) ... 936s Processing triggers for libc-bin (2.39-0ubuntu8) ... 936s Processing triggers for man-db (2.12.0-4build1) ... 941s (Reading database ... 78444 files and directories currently installed.) 941s Removing autopkgtest-satdep (0) ... 956s autopkgtest [10:24:43]: test ssh-gssapi: [----------------------- 956s ## Setting up test environment 956s ## Creating Kerberos realm EXAMPLE.FAKE 956s Initializing database '/var/lib/krb5kdc/principal' for realm 'EXAMPLE.FAKE', 956s master key name 'K/M@EXAMPLE.FAKE' 956s ## Creating principals 956s Authenticating as principal root/admin@EXAMPLE.FAKE with password. 956s Principal "testuser2572@EXAMPLE.FAKE" created. 956s Authenticating as principal root/admin@EXAMPLE.FAKE with password. 956s Principal "host/sshd-gssapi.example.fake@EXAMPLE.FAKE" created. 956s ## Extracting service principal host/sshd-gssapi.example.fake 956s Authenticating as principal root/admin@EXAMPLE.FAKE with password. 956s Entry for principal host/sshd-gssapi.example.fake with kvno 2, encryption type aes256-cts-hmac-sha1-96 added to keytab WRFILE:/etc/krb5.keytab. 956s Entry for principal host/sshd-gssapi.example.fake with kvno 2, encryption type aes128-cts-hmac-sha1-96 added to keytab WRFILE:/etc/krb5.keytab. 956s ## Adjusting /etc/krb5.conf 956s ## TESTS 956s 956s ## TEST test_gssapi_login 956s ## Configuring sshd for gssapi-with-mic authentication 956s ## Restarting ssh 956s ## Obtaining TGT 956s Password for testuser2572@EXAMPLE.FAKE: 956s Ticket cache: FILE:/tmp/krb5cc_0 956s Default principal: testuser2572@EXAMPLE.FAKE 956s 956s Valid starting Expires Service principal 956s 04/16/24 10:24:43 04/16/24 20:24:43 krbtgt/EXAMPLE.FAKE@EXAMPLE.FAKE 956s renew until 04/17/24 10:24:43 956s 956s ## ssh'ing into localhost using gssapi-with-mic auth 957s Warning: Permanently added 'sshd-gssapi.example.fake' (ED25519) to the list of known hosts. 957s Tue Apr 16 10:24:44 UTC 2024 957s 957s ## checking that we got a service ticket for ssh (host/) 957s 04/16/24 10:24:44 04/16/24 20:24:43 host/sshd-gssapi.example.fake@ 957s Ticket server: host/sshd-gssapi.example.fake@EXAMPLE.FAKE 957s 957s ## Checking ssh logs to confirm gssapi-with-mic auth was used 957s Apr 16 10:24:44 sshd-gssapi.example.fake sshd[2642]: Accepted gssapi-with-mic for testuser2572 from 127.0.0.1 port 39314 ssh2: testuser2572@EXAMPLE.FAKE 957s ## PASS test_gssapi_login 957s 957s ## TEST test_gssapi_keyex_login 957s ## Configuring sshd for gssapi-keyex authentication 957s ## Restarting ssh 957s ## Obtaining TGT 957s Password for testuser2572@EXAMPLE.FAKE: 957s Ticket cache: FILE:/tmp/krb5cc_0 957s Default principal: testuser2572@EXAMPLE.FAKE 957s 957s Valid starting Expires Service principal 957s 04/16/24 10:24:44 04/16/24 20:24:44 krbtgt/EXAMPLE.FAKE@EXAMPLE.FAKE 957s renew until 04/17/24 10:24:44 957s 957s ## ssh'ing into localhost using gssapi-keyex auth 957s Tue Apr 16 10:24:44 UTC 2024 957s 957s ## checking that we got a service ticket for ssh (host/) 957s 04/16/24 10:24:44 04/16/24 20:24:44 host/sshd-gssapi.example.fake@ 957s Ticket server: host/sshd-gssapi.example.fake@EXAMPLE.FAKE 957s 957s ## Checking ssh logs to confirm gssapi-keyex auth was used 957s Apr 16 10:24:44 sshd-gssapi.example.fake sshd[2691]: Accepted gssapi-keyex for testuser2572 from 127.0.0.1 port 39318 ssh2: testuser2572@EXAMPLE.FAKE 957s ## PASS test_gssapi_keyex_login 957s 957s ## ALL TESTS PASSED 957s ## Cleaning up 958s autopkgtest [10:24:45]: test ssh-gssapi: -----------------------] 958s ssh-gssapi PASS 958s autopkgtest [10:24:45]: test ssh-gssapi: - - - - - - - - - - results - - - - - - - - - - 959s autopkgtest [10:24:46]: @@@@@@@@@@@@@@@@@@@@ summary 959s regress FAIL non-zero exit status 82 959s systemd-socket-activation PASS 959s sshd-socket-generator PASS 959s ssh-gssapi PASS 972s Creating nova instance adt-noble-s390x-openssh-20240416-100847-juju-7f2275-prod-proposed-migration-environment-2-91ba491c-d753-447a-9956-4f72d91f1948 from image adt/ubuntu-noble-s390x-server-20240416.img (UUID 45f0d7c3-e9b2-45f6-9438-038de6cdf052)... 972s Creating nova instance adt-noble-s390x-openssh-20240416-100847-juju-7f2275-prod-proposed-migration-environment-2-91ba491c-d753-447a-9956-4f72d91f1948 from image adt/ubuntu-noble-s390x-server-20240416.img (UUID 45f0d7c3-e9b2-45f6-9438-038de6cdf052)... 972s Creating nova instance adt-noble-s390x-openssh-20240416-100847-juju-7f2275-prod-proposed-migration-environment-2-91ba491c-d753-447a-9956-4f72d91f1948 from image adt/ubuntu-noble-s390x-server-20240416.img (UUID 45f0d7c3-e9b2-45f6-9438-038de6cdf052)...