0s autopkgtest [13:41:31]: starting date and time: 2025-07-11 13:41:31+0000 0s autopkgtest [13:41:31]: git checkout: 508d4a25 a-v-ssh wait_for_ssh: demote "ssh connection failed" to a debug message 0s autopkgtest [13:41:31]: host juju-7f2275-prod-proposed-migration-environment-20; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.zg01e88n/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --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 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest-cpu2-ram4-disk20-amd64 --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-20@sto01-30.secgroup --name adt-questing-amd64-keychain-20250711-134131-juju-7f2275-prod-proposed-migration-environment-20-06428a11-3709-4f79-ac15-f002aca4b154 --image adt/ubuntu-questing-amd64-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-20 --net-id=net_prod-autopkgtest-workers-amd64 -e TERM=linux --mirror=http://ftpmaster.internal/ubuntu/ 3s Creating nova instance adt-questing-amd64-keychain-20250711-134131-juju-7f2275-prod-proposed-migration-environment-20-06428a11-3709-4f79-ac15-f002aca4b154 from image adt/ubuntu-questing-amd64-server-20250711.img (UUID 0957a5f8-1328-4bf4-9630-67e41bd0820f)... 29s autopkgtest [13:42:00]: testbed dpkg architecture: amd64 30s autopkgtest [13:42:01]: testbed apt version: 3.1.3 30s autopkgtest [13:42:01]: @@@@@@@@@@@@@@@@@@@@ test bed setup 30s autopkgtest [13:42:01]: testbed release detected to be: None 31s autopkgtest [13:42:02]: updating testbed package index (apt update) 31s Get:1 http://ftpmaster.internal/ubuntu questing-proposed InRelease [249 kB] 31s Hit:2 http://ftpmaster.internal/ubuntu questing InRelease 31s Hit:3 http://ftpmaster.internal/ubuntu questing-updates InRelease 31s Hit:4 http://ftpmaster.internal/ubuntu questing-security InRelease 31s Get:5 http://ftpmaster.internal/ubuntu questing-proposed/main Sources [36.9 kB] 31s Get:6 http://ftpmaster.internal/ubuntu questing-proposed/universe Sources [179 kB] 31s Get:7 http://ftpmaster.internal/ubuntu questing-proposed/multiverse Sources [15.4 kB] 31s Get:8 http://ftpmaster.internal/ubuntu questing-proposed/main amd64 Packages [56.9 kB] 31s Get:9 http://ftpmaster.internal/ubuntu questing-proposed/main i386 Packages [39.1 kB] 31s Get:10 http://ftpmaster.internal/ubuntu questing-proposed/universe amd64 Packages [178 kB] 31s Get:11 http://ftpmaster.internal/ubuntu questing-proposed/universe i386 Packages [105 kB] 31s Get:12 http://ftpmaster.internal/ubuntu questing-proposed/multiverse i386 Packages [8592 B] 31s Get:13 http://ftpmaster.internal/ubuntu questing-proposed/multiverse amd64 Packages [16.6 kB] 31s Fetched 886 kB in 0s (1872 kB/s) 32s Reading package lists... 32s autopkgtest [13:42:03]: upgrading testbed (apt dist-upgrade and autopurge) 32s Reading package lists... 33s Building dependency tree... 33s Reading state information... 33s Calculating upgrade... 33s The following packages will be upgraded: 33s openssh-client openssh-server openssh-sftp-server 33s 3 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 33s Need to get 1595 kB of archives. 33s After this operation, 549 kB disk space will be freed. 33s Get:1 http://ftpmaster.internal/ubuntu questing-proposed/main amd64 openssh-sftp-server amd64 1:10.0p1-5ubuntu2 [37.4 kB] 33s Get:2 http://ftpmaster.internal/ubuntu questing-proposed/main amd64 openssh-server amd64 1:10.0p1-5ubuntu2 [614 kB] 33s Get:3 http://ftpmaster.internal/ubuntu questing-proposed/main amd64 openssh-client amd64 1:10.0p1-5ubuntu2 [943 kB] 33s Preconfiguring packages ... 33s Fetched 1595 kB in 0s (5760 kB/s) 33s (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 ... 121132 files and directories currently installed.) 33s Preparing to unpack .../openssh-sftp-server_1%3a10.0p1-5ubuntu2_amd64.deb ... 33s Unpacking openssh-sftp-server (1:10.0p1-5ubuntu2) over (1:9.9p1-3ubuntu3.1) ... 33s Preparing to unpack .../openssh-server_1%3a10.0p1-5ubuntu2_amd64.deb ... 33s Unpacking openssh-server (1:10.0p1-5ubuntu2) over (1:9.9p1-3ubuntu3.1) ... 34s Preparing to unpack .../openssh-client_1%3a10.0p1-5ubuntu2_amd64.deb ... 34s Unpacking openssh-client (1:10.0p1-5ubuntu2) over (1:9.9p1-3ubuntu3.1) ... 34s Setting up openssh-client (1:10.0p1-5ubuntu2) ... 34s Installing new version of config file /etc/ssh/ssh_config ... 34s Created symlink '/etc/systemd/user/sockets.target.wants/ssh-agent.socket' → '/usr/lib/systemd/user/ssh-agent.socket'. 34s Setting up openssh-sftp-server (1:10.0p1-5ubuntu2) ... 34s Setting up openssh-server (1:10.0p1-5ubuntu2) ... 34s Installing new version of config file /etc/ssh/moduli ... 34s Replacing config file /etc/ssh/sshd_config with new version 35s Created symlink '/etc/systemd/system/ssh.service.wants/sshd-keygen.service' → '/usr/lib/systemd/system/sshd-keygen.service'. 35s Created symlink '/etc/systemd/system/sshd.service.wants/sshd-keygen.service' → '/usr/lib/systemd/system/sshd-keygen.service'. 35s Created symlink '/etc/systemd/system/sshd@.service.wants/sshd-keygen.service' → '/usr/lib/systemd/system/sshd-keygen.service'. 35s Created symlink '/etc/systemd/system/ssh.socket.wants/sshd-keygen.service' → '/usr/lib/systemd/system/sshd-keygen.service'. 35s Processing triggers for man-db (2.13.1-1) ... 36s Processing triggers for ufw (0.36.2-9) ... 36s Reading package lists... 36s Building dependency tree... 36s Reading state information... 36s Solving dependencies... 36s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 36s autopkgtest [13:42:07]: rebooting testbed after setup commands that affected boot 53s autopkgtest [13:42:24]: testbed running kernel: Linux 6.15.0-4-generic #4-Ubuntu SMP PREEMPT_DYNAMIC Fri Jul 4 14:41:53 UTC 2025 55s autopkgtest [13:42:26]: @@@@@@@@@@@@@@@@@@@@ apt-source keychain 56s Get:1 http://ftpmaster.internal/ubuntu questing/universe keychain 2.8.5-5 (dsc) [2024 B] 56s Get:2 http://ftpmaster.internal/ubuntu questing/universe keychain 2.8.5-5 (tar) [66.4 kB] 56s Get:3 http://ftpmaster.internal/ubuntu questing/universe keychain 2.8.5-5 (diff) [9128 B] 56s gpgv: Signature made Tue Dec 31 09:51:29 2024 UTC 56s gpgv: using RSA key 2EE7A7A517FC124CF115C354651EEFB02527DF13 56s gpgv: issuer "roam@debian.org" 56s gpgv: Can't check signature: No public key 56s dpkg-source: warning: cannot verify inline signature for ./keychain_2.8.5-5.dsc: no acceptable signature found 56s autopkgtest [13:42:27]: testing package keychain version 2.8.5-5 57s autopkgtest [13:42:28]: build not needed 57s autopkgtest [13:42:28]: test ssh.sh: preparing testbed 57s Reading package lists... 57s Building dependency tree... 57s Reading state information... 57s Solving dependencies... 57s The following NEW packages will be installed: 57s keychain 57s 0 upgraded, 1 newly installed, 0 to remove and 0 not upgraded. 57s Need to get 37.0 kB of archives. 57s After this operation, 82.9 kB of additional disk space will be used. 57s Get:1 http://ftpmaster.internal/ubuntu questing/universe amd64 keychain all 2.8.5-5 [37.0 kB] 58s Fetched 37.0 kB in 0s (1994 kB/s) 58s Selecting previously unselected package keychain. 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 ... 121133 files and directories currently installed.) 58s Preparing to unpack .../keychain_2.8.5-5_all.deb ... 58s Unpacking keychain (2.8.5-5) ... 58s Setting up keychain (2.8.5-5) ... 58s Processing triggers for man-db (2.13.1-1) ... 59s autopkgtest [13:42:30]: test ssh.sh: [----------------------- 59s + export LC_ALL=C 59s + id -un 59s + uid=ubuntu 59s + id 59s + 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) 59s + echo Process list: 59s + ps uwwx 59s 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) 59s Process list: 59s USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND 59s ubuntu 888 0.6 0.3 21788 12464 ? Ss 13:42 0:00 /usr/lib/systemd/systemd --user 59s ubuntu 889 0.0 0.0 21644 3580 ? S 13:42 0:00 (sd-pam) 59s ubuntu 921 0.3 0.1 17660 7752 ? S 13:42 0:00 sshd-session: ubuntu@notty 59s ubuntu 1395 0.0 0.0 2896 1968 ? Ss 13:42 0:00 /bin/sh /tmp/autopkgtest.3Llt9s/wrapper.sh --artifacts=/tmp/autopkgtest.3Llt9s/ssh.sh-artifacts --chdir=/tmp/autopkgtest.3Llt9s/build.CGx/src --env=AUTOPKGTEST_TESTBED_ARCH=amd64 --env=AUTOPKGTEST_TEST_ARCH=amd64 --env=DEB_BUILD_OPTIONS=parallel=2 --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.3Llt9s/ssh.sh-stderr --stdout=/tmp/autopkgtest.3Llt9s/ssh.sh-stdout --tmp=/tmp/autopkgtest.3Llt9s/autopkgtest_tmp --env=ADT_TEST_TRIGGERS=openssh/1:10.0p1-5ubuntu2 --make-executable=/tmp/autopkgtest.3Llt9s/build.CGx/src/debian/tests/ssh.sh -- /tmp/autopkgtest.3Llt9s/build.CGx/src/debian/tests/ssh.sh 59s ubuntu 1420 0.0 0.0 6204 1756 ? S 13:42 0:00 tee -a -- /tmp/autopkgtest.3Llt9s/ssh.sh-stdout 59s ubuntu 1422 0.0 0.0 6204 1884 ? S 13:42 0:00 tee -a -- /tmp/autopkgtest.3Llt9s/ssh.sh-stderr 59s ubuntu 1424 0.0 0.0 2896 1724 ? S 13:42 0:00 /bin/sh /tmp/autopkgtest.3Llt9s/build.CGx/src/debian/tests/ssh.sh 59s ubuntu 1427 0.0 0.1 6612 4048 ? R 13:42 0:00 ps uwwx 59s No SSH agent variables in the environment, right? 59s And ssh-add cannot see anything, either 59s + unset SSH_AUTH_SOCK 59s + unset SSH_AGENT_PID 59s + echo No SSH agent variables in the environment, right? 59s + printenv 59s + egrep -e ^SSH_ 59s + echo And ssh-add cannot see anything, either 59s + ssh-add -l 59s Could not open a connection to your authentication agent. 59s + mktemp -d 59s + tempd=/tmp/tmp.EvNJ9q67Qx 59s + echo Using our tempdir /tmp/tmp.EvNJ9q67Qx 59s + echo OK, let us start an SSH agent... 59s + ssh-agent -s 59s Using our tempdir /tmp/tmp.EvNJ9q67Qx 59s OK, let us start an SSH agent... 59s + echo Output: 59s + cat -- /tmp/tmp.EvNJ9q67Qx/ssh-agent.out 59s + echo Loading it: 59s + . /tmp/tmp.EvNJ9q67Qx/ssh-agent.out 59s + SSH_AUTH_SOCK=/tmp/ssh-RHOHnI2hwFdY/agent.1432 59s + export SSH_AUTH_SOCK 59s + SSH_AGENT_PID=1433 59s + export SSH_AGENT_PID 59s + echo Agent pid 1433 59s + echo Environment: 59s + printenv+ egrep -e ^SSH_ 59s 59s Output: 59s SSH_AUTH_SOCK=/tmp/ssh-RHOHnI2hwFdY/agent.1432; export SSH_AUTH_SOCK; 59s SSH_AGENT_PID=1433; export SSH_AGENT_PID; 59s echo Agent pid 1433; 59s Loading it: 59s Agent pid 1433 59s Environment: 59s SSH_AGENT_PID=1433 59s SSH_AUTH_SOCK=/tmp/ssh-RHOHnI2hwFdY/agent.1432 59s + echo Query it - no identities expected 59s + res=0 59s + ssh-add -l 59s Query it - no identities expected 59s - standard output: 59s + res=1 59s + echo - standard output: 59s + cat -- /tmp/tmp.EvNJ9q67Qx/ssh-add.out 59s The agent has no identities. 59s - standard error: 59s + echo - standard error: 59s + cat -- /tmp/tmp.EvNJ9q67Qx/ssh-add.err 59s - make sure it did not output the key 59s + echo - make sure it did not output the key 59s + fgrep -e tanj@straylight -- /tmp/tmp.EvNJ9q67Qx/ssh-add.out 59s - make sure it failed 59s Now add a key 59s + echo - make sure it failed 59s + [ 1 != 0 ] 59s + echo Now add a key 59s + install -m 600 -- debian/tests/data/id_tanj /tmp/tmp.EvNJ9q67Qx/ 59s + install -m 644 -- debian/tests/data/id_tanj.pub /tmp/tmp.EvNJ9q67Qx/ 59s + ssh-add -- /tmp/tmp.EvNJ9q67Qx/id_tanj 59s Identity added: /tmp/tmp.EvNJ9q67Qx/id_tanj (tanj@straylight) 59s But did it work? 59s + echo But did it work? 59s + res=0 59s + ssh-add -l 59s - standard output: 59s + echo - standard output: 59s + cat -- /tmp/tmp.EvNJ9q67Qx/ssh-add.out 59s + echo - standard error: 59s + cat -- /tmp/tmp.EvNJ9q67Qx/ssh-add.err 59s + echo - make sure it succeeded 59s + [ 0 = 0 ] 59s + echo - make sure it output some info about the key 59s + fgrep -e tanj@straylight -- /tmp/tmp.EvNJ9q67Qx/ssh-add.out 59s 2048 SHA256:Jj81+RS4yFX0l59QjgwtDwSgsItAynP6ioIjD4RA2kQ tanj@straylight (RSA) 59s - standard error: 59s - make sure it succeeded 59s - make sure it output some info about the key 59s 2048 SHA256:Jj81+RS4yFX0l59QjgwtDwSgsItAynP6ioIjD4RA2kQ tanj@straylight (RSA) 59s Let us stop the agent 59s + echo Let us stop the agent 59s + ssh-agent -s -k 59s - output: 59s unset SSH_AUTH_SOCK; 59s unset SSH_AGENT_PID; 59s echo Agent pid 1433 killed; 59s + echo - output: 59s + cat -- /tmp/tmp.EvNJ9q67Qx/ssh-agent.out 59s - load it... 59s Agent pid 1433 killed 59s - environment: 59s + echo - load it... 59s + . /tmp/tmp.EvNJ9q67Qx/ssh-agent.out 59s + unset SSH_AUTH_SOCK 59s + unset SSH_AGENT_PID 59s + echo Agent pid 1433 killed 59s + echo - environment: 59s + printenv 59s + egrep -e ^SSH_ 59s + mktemp -d 59s Using keychain home directory /tmp/tmp.zCgCRv5fnk and our tempdir /tmp/tmp.EvNJ9q67Qx 59s + kchome=/tmp/tmp.zCgCRv5fnk 59s + echo Using keychain home directory /tmp/tmp.zCgCRv5fnk and our tempdir /tmp/tmp.EvNJ9q67Qx 59s + keychain -q --dir /tmp/tmp.zCgCRv5fnk --eval /tmp/tmp.EvNJ9q67Qx/id_tanj 59s ssh-keygen: /tmp/tmp.EvNJ9q67Qx/id_tanj.pub: Permission denied 59s * Warning: Unable to extract fingerprint from keyfile /tmp/tmp.EvNJ9q67Qx/id_tanj.pub, skipping 59s The output: 59s + echo The output: 59s + cat -- /tmp/tmp.EvNJ9q67Qx/1.out 59s SSH_AUTH_SOCK=/tmp/ssh-JE4YKPVHCszz/agent.1473; export SSH_AUTH_SOCK; 59s SSH_AGENT_PID=1474; export SSH_AGENT_PID; 59s 59s Loading it... 59s + echo Loading it... 59s + cat -- /tmp/tmp.EvNJ9q67Qx/1.out 59s + eval SSH_AUTH_SOCK=/tmp/ssh-JE4YKPVHCszz/agent.1473; export SSH_AUTH_SOCK; 59s SSH_AGENT_PID=1474; export SSH_AGENT_PID; 59s + SSH_AUTH_SOCK=/tmp/ssh-JE4YKPVHCszz/agent.1473 59s + export SSH_AUTH_SOCK 59s + SSH_AGENT_PID=1474 59s + export SSH_AGENT_PID 59s + echo Let us take a look at the environment now... 59s Let us take a look at the environment now... 59s + printenv 59s + egrep -e ^SSH_ 59s SSH_AGENT_PID=1474 59s SSH_AUTH_SOCK=/tmp/ssh-JE4YKPVHCszz/agent.1473 59s + [ -z /tmp/ssh-JE4YKPVHCszz/agent.1473 ] 59s + ssh-add -l 59s The agent has no identities. 60s autopkgtest [13:42:31]: test ssh.sh: -----------------------] 60s autopkgtest [13:42:31]: test ssh.sh: - - - - - - - - - - results - - - - - - - - - - 60s ssh.sh FAIL non-zero exit status 1 60s autopkgtest [13:42:31]: @@@@@@@@@@@@@@@@@@@@ summary 60s ssh.sh FAIL non-zero exit status 1