0s autopkgtest [02:40:47]: starting date and time: 2025-07-11 02:40:47+0000 0s autopkgtest [02:40:47]: git checkout: 508d4a25 a-v-ssh wait_for_ssh: demote "ssh connection failed" to a debug message 0s autopkgtest [02:40:47]: host juju-7f2275-prod-proposed-migration-environment-9; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.wukoksmz/out --timeout-copy=6000 --setup-commands 'ln -s /dev/null /etc/systemd/system/bluetooth.service; printf "http_proxy=http://squid.internal:3128\nhttps_proxy=http://squid.internal:3128\nno_proxy=127.0.0.1,127.0.1.1,localhost,localdomain,internal,login.ubuntu.com,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,keyserver.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com,radosgw.ps5.canonical.com\n" >> /etc/environment' --apt-pocket=proposed=src:openssh --apt-upgrade keychain --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=openssh/1:10.0p1-5ubuntu2 -- lxd -r lxd-armhf-10.145.243.46 lxd-armhf-10.145.243.46:autopkgtest/ubuntu/questing/armhf 23s autopkgtest [02:41:10]: testbed dpkg architecture: armhf 25s autopkgtest [02:41:12]: testbed apt version: 3.1.3 29s autopkgtest [02:41:16]: @@@@@@@@@@@@@@@@@@@@ test bed setup 31s autopkgtest [02:41:18]: testbed release detected to be: None 38s autopkgtest [02:41:25]: updating testbed package index (apt update) 40s Get:1 http://ftpmaster.internal/ubuntu questing-proposed InRelease [249 kB] 40s Get:2 http://ftpmaster.internal/ubuntu questing InRelease [249 kB] 40s Get:3 http://ftpmaster.internal/ubuntu questing-updates InRelease [110 kB] 40s Get:4 http://ftpmaster.internal/ubuntu questing-security InRelease [110 kB] 41s Get:5 http://ftpmaster.internal/ubuntu questing-proposed/multiverse Sources [15.4 kB] 41s Get:6 http://ftpmaster.internal/ubuntu questing-proposed/universe Sources [183 kB] 41s Get:7 http://ftpmaster.internal/ubuntu questing-proposed/main Sources [35.6 kB] 41s Get:8 http://ftpmaster.internal/ubuntu questing-proposed/main armhf Packages [49.2 kB] 41s Get:9 http://ftpmaster.internal/ubuntu questing-proposed/universe armhf Packages [158 kB] 41s Get:10 http://ftpmaster.internal/ubuntu questing-proposed/multiverse armhf Packages [3452 B] 41s Get:11 http://ftpmaster.internal/ubuntu questing/universe Sources [21.1 MB] 42s Get:12 http://ftpmaster.internal/ubuntu questing/main Sources [1387 kB] 42s Get:13 http://ftpmaster.internal/ubuntu questing/main armhf Packages [1361 kB] 42s Get:14 http://ftpmaster.internal/ubuntu questing/universe armhf Packages [15.2 MB] 46s Fetched 40.2 MB in 7s (6192 kB/s) 47s Reading package lists... 52s autopkgtest [02:41:39]: upgrading testbed (apt dist-upgrade and autopurge) 54s Reading package lists... 54s Building dependency tree... 54s Reading state information... 55s Calculating upgrade... 55s The following packages will be upgraded: 55s openssh-client openssh-server openssh-sftp-server 55s 3 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 55s Need to get 1579 kB of archives. 55s After this operation, 458 kB of additional disk space will be used. 55s Get:1 http://ftpmaster.internal/ubuntu questing-proposed/main armhf openssh-sftp-server armhf 1:10.0p1-5ubuntu2 [35.8 kB] 55s Get:2 http://ftpmaster.internal/ubuntu questing-proposed/main armhf openssh-server armhf 1:10.0p1-5ubuntu2 [612 kB] 56s Get:3 http://ftpmaster.internal/ubuntu questing-proposed/main armhf openssh-client armhf 1:10.0p1-5ubuntu2 [931 kB] 57s Preconfiguring packages ... 57s Fetched 1579 kB in 2s (812 kB/s) 58s (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 ... 59841 files and directories currently installed.) 58s Preparing to unpack .../openssh-sftp-server_1%3a10.0p1-5ubuntu2_armhf.deb ... 58s Unpacking openssh-sftp-server (1:10.0p1-5ubuntu2) over (1:9.9p1-3ubuntu3.1) ... 58s Preparing to unpack .../openssh-server_1%3a10.0p1-5ubuntu2_armhf.deb ... 58s Unpacking openssh-server (1:10.0p1-5ubuntu2) over (1:9.9p1-3ubuntu3.1) ... 58s Preparing to unpack .../openssh-client_1%3a10.0p1-5ubuntu2_armhf.deb ... 58s Unpacking openssh-client (1:10.0p1-5ubuntu2) over (1:9.9p1-3ubuntu3.1) ... 58s Setting up openssh-client (1:10.0p1-5ubuntu2) ... 58s Installing new version of config file /etc/ssh/ssh_config ... 58s Created symlink '/etc/systemd/user/sockets.target.wants/ssh-agent.socket' → '/usr/lib/systemd/user/ssh-agent.socket'. 58s Setting up openssh-sftp-server (1:10.0p1-5ubuntu2) ... 58s Setting up openssh-server (1:10.0p1-5ubuntu2) ... 58s Installing new version of config file /etc/ssh/moduli ... 58s Replacing config file /etc/ssh/sshd_config with new version 59s Created symlink '/etc/systemd/system/ssh.service.wants/sshd-keygen.service' → '/usr/lib/systemd/system/sshd-keygen.service'. 59s Created symlink '/etc/systemd/system/sshd.service.wants/sshd-keygen.service' → '/usr/lib/systemd/system/sshd-keygen.service'. 59s Created symlink '/etc/systemd/system/sshd@.service.wants/sshd-keygen.service' → '/usr/lib/systemd/system/sshd-keygen.service'. 59s Created symlink '/etc/systemd/system/ssh.socket.wants/sshd-keygen.service' → '/usr/lib/systemd/system/sshd-keygen.service'. 60s Processing triggers for man-db (2.13.1-1) ... 61s Processing triggers for ufw (0.36.2-9) ... 63s Reading package lists... 63s Building dependency tree... 63s Reading state information... 63s Solving dependencies... 64s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 66s autopkgtest [02:41:53]: rebooting testbed after setup commands that affected boot 104s autopkgtest [02:42:31]: testbed running kernel: Linux 6.8.0-58-generic #60~22.04.1-Ubuntu SMP PREEMPT_DYNAMIC Fri Mar 28 14:48:37 UTC 2 127s autopkgtest [02:42:54]: @@@@@@@@@@@@@@@@@@@@ apt-source keychain 137s Get:1 http://ftpmaster.internal/ubuntu questing/universe keychain 2.8.5-5 (dsc) [2024 B] 137s Get:2 http://ftpmaster.internal/ubuntu questing/universe keychain 2.8.5-5 (tar) [66.4 kB] 137s Get:3 http://ftpmaster.internal/ubuntu questing/universe keychain 2.8.5-5 (diff) [9128 B] 137s gpgv: Signature made Tue Dec 31 09:51:29 2024 UTC 137s gpgv: using RSA key 2EE7A7A517FC124CF115C354651EEFB02527DF13 137s gpgv: issuer "roam@debian.org" 137s gpgv: Can't check signature: No public key 137s dpkg-source: warning: cannot verify inline signature for ./keychain_2.8.5-5.dsc: no acceptable signature found 137s autopkgtest [02:43:04]: testing package keychain version 2.8.5-5 139s autopkgtest [02:43:06]: build not needed 141s autopkgtest [02:43:08]: test ssh.sh: preparing testbed 142s Reading package lists... 143s Building dependency tree... 143s Reading state information... 143s Solving dependencies... 143s The following NEW packages will be installed: 143s keychain 144s 0 upgraded, 1 newly installed, 0 to remove and 0 not upgraded. 144s Need to get 37.0 kB of archives. 144s After this operation, 82.9 kB of additional disk space will be used. 144s Get:1 http://ftpmaster.internal/ubuntu questing/universe armhf keychain all 2.8.5-5 [37.0 kB] 144s Fetched 37.0 kB in 0s (117 kB/s) 144s Selecting previously unselected package keychain. 144s (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 ... 59842 files and directories currently installed.) 144s Preparing to unpack .../keychain_2.8.5-5_all.deb ... 144s Unpacking keychain (2.8.5-5) ... 144s Setting up keychain (2.8.5-5) ... 144s Processing triggers for man-db (2.13.1-1) ... 152s autopkgtest [02:43:19]: test ssh.sh: [----------------------- 154s + export LC_ALL=C 154s + id -un 154s + uid=ubuntu 154s + id 154s Starting up as uid ubuntu, full id output: uid=1000(ubuntu) gid=1000(ubuntu) groups=1000(ubuntu),4(adm),24(cdrom),27(sudo),30(dip),103(lxd) 154s Process list: 154s + echo Starting up as uid ubuntu, full id output: uid=1000(ubuntu) gid=1000(ubuntu) groups=1000(ubuntu),4(adm),24(cdrom),27(sudo),30(dip),103(lxd) 154s + echo Process list: 154s + ps uwwx 154s USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND 154s ubuntu 852 50.0 0.0 14064 8064 ? Ss 02:43 0:00 /usr/lib/systemd/systemd --user 154s ubuntu 853 0.0 0.0 15840 2616 ? S 02:43 0:00 (sd-pam) 154s ubuntu 871 0.0 0.0 1752 1152 ? Ss 02:43 0:00 /bin/sh /tmp/autopkgtest.eJ1ACU/wrapper.sh --artifacts=/tmp/autopkgtest.eJ1ACU/ssh.sh-artifacts --chdir=/tmp/autopkgtest.eJ1ACU/build.Rxs/src --env=AUTOPKGTEST_TESTBED_ARCH=armhf --env=AUTOPKGTEST_TEST_ARCH=armhf --env=DEB_BUILD_OPTIONS=parallel=8 --env=DEBIAN_FRONTEND=noninteractive --env=LANG=C.UTF-8 --unset-env=LANGUAGE --unset-env=LC_ADDRESS --unset-env=LC_ALL --unset-env=LC_COLLATE --unset-env=LC_CTYPE --unset-env=LC_IDENTIFICATION --unset-env=LC_MEASUREMENT --unset-env=LC_MESSAGES --unset-env=LC_MONETARY --unset-env=LC_NAME --unset-env=LC_NUMERIC --unset-env=LC_PAPER --unset-env=LC_TELEPHONE --unset-env=LC_TIME --script-pid-file=/tmp/autopkgtest_script_pid --source-profile --stderr=/tmp/autopkgtest.eJ1ACU/ssh.sh-stderr --stdout=/tmp/autopkgtest.eJ1ACU/ssh.sh-stdout --tmp=/tmp/autopkgtest.eJ1ACU/autopkgtest_tmp --env=ADT_TEST_TRIGGERS=openssh/1:10.0p1-5ubuntu2 --make-executable=/tmp/autopkgtest.eJ1ACU/build.Rxs/src/debian/tests/ssh.sh -- /tmp/autopkgtest.eJ1ACU/build.Rxs/src/debian/tests/ssh.sh 154s ubuntu 886 0.0 0.0 4180 1152 ? S 02:43 0:00 tee -a -- /tmp/autopkgtest.eJ1ACU/ssh.sh-stdout 154s ubuntu 888 0.0 0.0 4180 1152 ? S 02:43 0:00 tee -a -- /tmp/autopkgtest.eJ1ACU/ssh.sh-stderr 154s ubuntu 890 0.0 0.0 1752 1024 ? S 02:43 0:00 /bin/sh /tmp/autopkgtest.eJ1ACU/build.Rxs/src/debian/tests/ssh.sh 154s ubuntu 893 0.0 0.0 4708 2432 ? R 02:43 0:00 ps uwwx 154s No SSH agent variables in the environment, right? 154s + unset SSH_AUTH_SOCK 154s + unset SSH_AGENT_PID 154s + echo No SSH agent variables in the environment, right? 154s + printenv 154s + egrep -e ^SSH_ 154s + echo And ssh-add cannot see anything, either 154s + ssh-add -l 154s And ssh-add cannot see anything, either 154s Could not open a connection to your authentication agent. 154s + mktemp -d 154s Using our tempdir /tmp/tmp.nc4DcduVG8 154s OK, let us start an SSH agent... 154s + tempd=/tmp/tmp.nc4DcduVG8 154s + echo Using our tempdir /tmp/tmp.nc4DcduVG8 154s + echo OK, let us start an SSH agent... 154s Output: 154s SSH_AUTH_SOCK=/tmp/ssh-fKmogR0ipAFN/agent.898; export SSH_AUTH_SOCK; 154s SSH_AGENT_PID=899; export SSH_AGENT_PID; 154s echo Agent pid 899; 154s Loading it: 154s + ssh-agent -s 154s + echo Output: 154s + cat -- /tmp/tmp.nc4DcduVG8/ssh-agent.out 154s + echo Loading it: 154s + . /tmp/tmp.nc4DcduVG8/ssh-agent.out 154s + SSH_AUTH_SOCK=/tmp/ssh-fKmogR0ipAFN/agent.898 154s + export SSH_AUTH_SOCK 154s + SSH_AGENT_PID=899 154s + export SSH_AGENT_PID 154s + echo Agent pid 899 154s + echo Environment: 154s + printenv 154s + egrep -e ^SSH_ 154s + echo Query it - no identities expected 154s + res=0 154s + ssh-add -l 154s + res=1 154s + echo - standard output: 154s + cat -- /tmp/tmp.nc4DcduVG8/ssh-add.out 154s + echo - standard error: 154s + cat -- /tmp/tmp.nc4DcduVG8/ssh-add.err 154s + echo - make sure it did not output the key 154s + fgrep -e tanj@straylight -- /tmp/tmp.nc4DcduVG8/ssh-add.out 154s + echo - make sure it failed 154s + [ 1 != 0 ] 154s + echo Now add a key 154s + install -m 600 -- debian/tests/data/id_tanj /tmp/tmp.nc4DcduVG8/ 154s + install -m 644 -- debian/tests/data/id_tanj.pub /tmp/tmp.nc4DcduVG8/ 154s + ssh-add -- /tmp/tmp.nc4DcduVG8/id_tanj 154s Identity added: /tmp/tmp.nc4DcduVG8/id_tanj (tanj@straylight) 154s + echo But did it work? 154s + res=0 154s + ssh-add -l 154s + echo - standard output: 154s + cat -- /tmp/tmp.nc4DcduVG8/ssh-add.out 154s + echo - standard error: 154s + cat -- /tmp/tmp.nc4DcduVG8/ssh-add.err 154s + echo - make sure it succeeded 154s + [ 0 = 0 ] 154s + echo - make sure it output some info about the key 154s + fgrep -e tanj@straylight -- /tmp/tmp.nc4DcduVG8/ssh-add.out 154s + echo Let us stop the agent 154s + ssh-agent -s -k 154s + echo - output: 154s + cat -- /tmp/tmp.nc4DcduVG8/ssh-agent.out 154s + echo - load it... 154s + . /tmp/tmp.nc4DcduVG8/ssh-agent.out 154s + unset SSH_AUTH_SOCK 154s + unset SSH_AGENT_PID 154s + echo Agent pid 899 killed 154s + echo - environment: 154s + printenv 154s + egrep -e ^SSH_ 154s + mktemp -d 154s Agent pid 899 154s Environment: 154s SSH_AGENT_PID=899 154s SSH_AUTH_SOCK=/tmp/ssh-fKmogR0ipAFN/agent.898 154s Query it - no identities expected 154s - standard output: 154s The agent has no identities. 154s - standard error: 154s - make sure it did not output the key 154s - make sure it failed 154s Now add a key 154s But did it work? 154s - standard output: 154s 2048 SHA256:Jj81+RS4yFX0l59QjgwtDwSgsItAynP6ioIjD4RA2kQ tanj@straylight (RSA) 154s - standard error: 154s - make sure it succeeded 154s - make sure it output some info about the key 154s 2048 SHA256:Jj81+RS4yFX0l59QjgwtDwSgsItAynP6ioIjD4RA2kQ tanj@straylight (RSA) 154s Let us stop the agent 154s - output: 154s + kchome=/tmp/tmp.lFIhdHhF72 154s + echo Using keychain home directory /tmp/tmp.lFIhdHhF72 and our tempdir /tmp/tmp.nc4DcduVG8 154s + keychain -q --dir /tmp/tmp.lFIhdHhF72 --eval /tmp/tmp.nc4DcduVG8/id_tanj 154s unset SSH_AUTH_SOCK; 154s unset SSH_AGENT_PID; 154s echo Agent pid 899 killed; 154s - load it... 154s Agent pid 899 killed 154s - environment: 154s Using keychain home directory /tmp/tmp.lFIhdHhF72 and our tempdir /tmp/tmp.nc4DcduVG8 154s + echo The output: 154s + cat -- /tmp/tmp.nc4DcduVG8/1.out 154s The output: 154s SSH_AUTH_SOCK=/tmp/ssh-P1AH8HyvRWlO/agent.939; export SSH_AUTH_SOCK; 154s SSH_AGENT_PID=940; export SSH_AGENT_PID; 154s 154s + echo Loading it... 154s Loading it... 154s + cat -- /tmp/tmp.nc4DcduVG8/1.out 154s + eval SSH_AUTH_SOCK=/tmp/ssh-P1AH8HyvRWlO/agent.939; export SSH_AUTH_SOCK; 154s SSH_AGENT_PID=940; export SSH_AGENT_PID; 154s + SSH_AUTH_SOCK=/tmp/ssh-P1AH8HyvRWlO/agent.939 154s + export SSH_AUTH_SOCK 154s + SSH_AGENT_PID=940 154s + export SSH_AGENT_PID 154s + echo Let us take a look at the environment now... 154s Let us take a look at the environment now... 154s + printenv 154s + egrep -e ^SSH_ 154s + [ -z /tmp/ssh-P1AH8HyvRWlO/agent.939 ] 154s + ssh-add -l 154s SSH_AGENT_PID=940 154s SSH_AUTH_SOCK=/tmp/ssh-P1AH8HyvRWlO/agent.939 154s 2048 SHA256:Jj81+RS4yFX0l59QjgwtDwSgsItAynP6ioIjD4RA2kQ tanj@straylight (RSA) 154s + ssh-add -l 154s + fgrep -e tanj@straylight 154s 2048 SHA256:Jj81+RS4yFX0l59QjgwtDwSgsItAynP6ioIjD4RA2kQ tanj@straylight (RSA) 154s So what does keychain think is running? 154s + echo So what does keychain think is running? 154s + keychain -q --dir /tmp/tmp.lFIhdHhF72 --query 154s SSH_AUTH_SOCK=/tmp/ssh-P1AH8HyvRWlO/agent.939 154s SSH_AGENT_PID=940 154s 154s And now --eval 154s + echo And now --eval 154s + keychain -q --dir /tmp/tmp.lFIhdHhF72 --eval 154s SSH_AUTH_SOCK=/tmp/ssh-P1AH8HyvRWlO/agent.939; export SSH_AUTH_SOCK; 154s SSH_AGENT_PID=940; export SSH_AGENT_PID; 154s 154s + echo So let us try to add the OpenSSH key again... 154s So let us try to add the OpenSSH key again... 154s + keychain -q --dir /tmp/tmp.lFIhdHhF72 --eval debian/tests/data/id_tanj 154s Environment... 154s + eval SSH_AUTH_SOCK=/tmp/ssh-P1AH8HyvRWlO/agent.939; export SSH_AUTH_SOCK; SSH_AGENT_PID=940; export SSH_AGENT_PID; 154s + SSH_AUTH_SOCK=/tmp/ssh-P1AH8HyvRWlO/agent.939 154s + export SSH_AUTH_SOCK 154s + SSH_AGENT_PID=940 154s + export SSH_AGENT_PID 154s + echo Environment... 154s + printenv 154s + egrep -qe ^SSH_ 154s + echo ssh-add... 154s + ssh-add -l 154s ssh-add... 154s 2048 SHA256:Jj81+RS4yFX0l59QjgwtDwSgsItAynP6ioIjD4RA2kQ tanj@straylight (RSA) 154s Query... 154s + echo Query... 154s + keychain -q --dir /tmp/tmp.lFIhdHhF72 --query 154s SSH_AUTH_SOCK=/tmp/ssh-P1AH8HyvRWlO/agent.939 154s SSH_AGENT_PID=940 154s 154s Eval... 154s + echo Eval... 154s + keychain -q --dir /tmp/tmp.lFIhdHhF72 --eval 154s SSH_AUTH_SOCK=/tmp/ssh-P1AH8HyvRWlO/agent.939; export SSH_AUTH_SOCK; 154s SSH_AGENT_PID=940; export SSH_AGENT_PID; 154s 154s + echo All done, it seems 154s All done, it seems 154s autopkgtest [02:43:21]: test ssh.sh: -----------------------] 158s autopkgtest [02:43:25]: test ssh.sh: - - - - - - - - - - results - - - - - - - - - - 158s ssh.sh PASS 161s autopkgtest [02:43:28]: @@@@@@@@@@@@@@@@@@@@ summary 161s ssh.sh PASS