0s autopkgtest [13:43:16]: starting date and time: 2025-07-11 13:43:16+0000 0s autopkgtest [13:43:16]: git checkout: 508d4a25 a-v-ssh wait_for_ssh: demote "ssh connection failed" to a debug message 0s autopkgtest [13:43:16]: host juju-7f2275-prod-proposed-migration-environment-21; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.xeeezbh5/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-ppc64el --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-21@sto01-ppc64el-22.secgroup --name adt-questing-ppc64el-keychain-20250711-134315-juju-7f2275-prod-proposed-migration-environment-21-e543f30f-88e3-42df-a7fd-06df39e133c6 --image adt/ubuntu-questing-ppc64el-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-21 --net-id=net_prod-autopkgtest-workers-ppc64el -e TERM=linux --mirror=http://ftpmaster.internal/ubuntu/ 2s Creating nova instance adt-questing-ppc64el-keychain-20250711-134315-juju-7f2275-prod-proposed-migration-environment-21-e543f30f-88e3-42df-a7fd-06df39e133c6 from image adt/ubuntu-questing-ppc64el-server-20250711.img (UUID e5e64b17-c7df-4b38-905e-d20a7e1e8268)... 86s autopkgtest [13:44:42]: testbed dpkg architecture: ppc64el 86s autopkgtest [13:44:42]: testbed apt version: 3.1.3 86s autopkgtest [13:44:42]: @@@@@@@@@@@@@@@@@@@@ test bed setup 86s autopkgtest [13:44:42]: testbed release detected to be: None 87s autopkgtest [13:44:43]: updating testbed package index (apt update) 87s Get:1 http://ftpmaster.internal/ubuntu questing-proposed InRelease [249 kB] 87s Hit:2 http://ftpmaster.internal/ubuntu questing InRelease 87s Hit:3 http://ftpmaster.internal/ubuntu questing-updates InRelease 87s Hit:4 http://ftpmaster.internal/ubuntu questing-security InRelease 87s Get:5 http://ftpmaster.internal/ubuntu questing-proposed/multiverse Sources [15.4 kB] 87s Get:6 http://ftpmaster.internal/ubuntu questing-proposed/universe Sources [179 kB] 87s Get:7 http://ftpmaster.internal/ubuntu questing-proposed/main Sources [36.9 kB] 87s Get:8 http://ftpmaster.internal/ubuntu questing-proposed/main ppc64el Packages [53.6 kB] 87s Get:9 http://ftpmaster.internal/ubuntu questing-proposed/universe ppc64el Packages [155 kB] 87s Get:10 http://ftpmaster.internal/ubuntu questing-proposed/multiverse ppc64el Packages [4452 B] 87s Fetched 694 kB in 0s (1856 kB/s) 88s Reading package lists... 89s autopkgtest [13:44:45]: upgrading testbed (apt dist-upgrade and autopurge) 89s Reading package lists... 89s Building dependency tree... 89s Reading state information... 89s Calculating upgrade... 89s The following packages will be upgraded: 89s openssh-client openssh-server openssh-sftp-server 89s 3 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 89s Need to get 1993 kB of archives. 89s After this operation, 721 kB of additional disk space will be used. 89s Get:1 http://ftpmaster.internal/ubuntu questing-proposed/main ppc64el openssh-sftp-server ppc64el 1:10.0p1-5ubuntu2 [43.5 kB] 89s Get:2 http://ftpmaster.internal/ubuntu questing-proposed/main ppc64el openssh-server ppc64el 1:10.0p1-5ubuntu2 [776 kB] 89s Get:3 http://ftpmaster.internal/ubuntu questing-proposed/main ppc64el openssh-client ppc64el 1:10.0p1-5ubuntu2 [1174 kB] 90s Preconfiguring packages ... 90s Fetched 1993 kB in 1s (3005 kB/s) 91s (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 ... 117998 files and directories currently installed.) 91s Preparing to unpack .../openssh-sftp-server_1%3a10.0p1-5ubuntu2_ppc64el.deb ... 91s Unpacking openssh-sftp-server (1:10.0p1-5ubuntu2) over (1:9.9p1-3ubuntu3.1) ... 91s Preparing to unpack .../openssh-server_1%3a10.0p1-5ubuntu2_ppc64el.deb ... 91s Unpacking openssh-server (1:10.0p1-5ubuntu2) over (1:9.9p1-3ubuntu3.1) ... 91s Preparing to unpack .../openssh-client_1%3a10.0p1-5ubuntu2_ppc64el.deb ... 91s Unpacking openssh-client (1:10.0p1-5ubuntu2) over (1:9.9p1-3ubuntu3.1) ... 91s Setting up openssh-client (1:10.0p1-5ubuntu2) ... 91s Installing new version of config file /etc/ssh/ssh_config ... 91s Created symlink '/etc/systemd/user/sockets.target.wants/ssh-agent.socket' → '/usr/lib/systemd/user/ssh-agent.socket'. 91s Setting up openssh-sftp-server (1:10.0p1-5ubuntu2) ... 91s Setting up openssh-server (1:10.0p1-5ubuntu2) ... 91s Installing new version of config file /etc/ssh/moduli ... 91s Replacing config file /etc/ssh/sshd_config with new version 93s Created symlink '/etc/systemd/system/ssh.service.wants/sshd-keygen.service' → '/usr/lib/systemd/system/sshd-keygen.service'. 93s Created symlink '/etc/systemd/system/sshd.service.wants/sshd-keygen.service' → '/usr/lib/systemd/system/sshd-keygen.service'. 93s Created symlink '/etc/systemd/system/sshd@.service.wants/sshd-keygen.service' → '/usr/lib/systemd/system/sshd-keygen.service'. 93s Created symlink '/etc/systemd/system/ssh.socket.wants/sshd-keygen.service' → '/usr/lib/systemd/system/sshd-keygen.service'. 93s Processing triggers for man-db (2.13.1-1) ... 95s Processing triggers for ufw (0.36.2-9) ... 95s Reading package lists... 95s Building dependency tree... 95s Reading state information... 95s Solving dependencies... 95s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 95s autopkgtest [13:44:51]: rebooting testbed after setup commands that affected boot 123s autopkgtest [13:45:19]: testbed running kernel: Linux 6.15.0-4-generic #4-Ubuntu SMP Fri Jul 4 14:38:10 UTC 2025 125s autopkgtest [13:45:21]: @@@@@@@@@@@@@@@@@@@@ apt-source keychain 127s Get:1 http://ftpmaster.internal/ubuntu questing/universe keychain 2.8.5-5 (dsc) [2024 B] 127s Get:2 http://ftpmaster.internal/ubuntu questing/universe keychain 2.8.5-5 (tar) [66.4 kB] 127s Get:3 http://ftpmaster.internal/ubuntu questing/universe keychain 2.8.5-5 (diff) [9128 B] 127s gpgv: Signature made Tue Dec 31 09:51:29 2024 UTC 127s gpgv: using RSA key 2EE7A7A517FC124CF115C354651EEFB02527DF13 127s gpgv: issuer "roam@debian.org" 127s gpgv: Can't check signature: No public key 127s dpkg-source: warning: cannot verify inline signature for ./keychain_2.8.5-5.dsc: no acceptable signature found 127s autopkgtest [13:45:23]: testing package keychain version 2.8.5-5 128s autopkgtest [13:45:24]: build not needed 128s autopkgtest [13:45:24]: test ssh.sh: preparing testbed 128s Reading package lists... 128s Building dependency tree... 128s Reading state information... 128s Solving dependencies... 128s The following NEW packages will be installed: 128s keychain 128s 0 upgraded, 1 newly installed, 0 to remove and 0 not upgraded. 128s Need to get 37.0 kB of archives. 128s After this operation, 82.9 kB of additional disk space will be used. 128s Get:1 http://ftpmaster.internal/ubuntu questing/universe ppc64el keychain all 2.8.5-5 [37.0 kB] 129s Fetched 37.0 kB in 0s (2197 kB/s) 129s Selecting previously unselected package keychain. 129s (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 ... 117999 files and directories currently installed.) 129s Preparing to unpack .../keychain_2.8.5-5_all.deb ... 129s Unpacking keychain (2.8.5-5) ... 129s Setting up keychain (2.8.5-5) ... 129s Processing triggers for man-db (2.13.1-1) ... 131s autopkgtest [13:45:27]: test ssh.sh: [----------------------- 131s + export LC_ALL=C 131s + id -un 131s + uid=ubuntu 131s + id 131s + 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),102(lxd) 131s + echo Process list: 131s + ps uwwx 131s 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),102(lxd) 131s Process list: 131s + unset SSH_AUTH_SOCK 131s + unset SSH_AGENT_PID 131s + echo No SSH agent variables in the environment, right? 131s + printenv 131s + egrep -e ^SSH_ 131s USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND 131s ubuntu 1028 0.5 0.3 29760 14336 ? Ss 13:45 0:00 /usr/lib/systemd/systemd --user 131s ubuntu 1029 0.0 0.1 31744 6144 ? S 13:45 0:00 (sd-pam) 131s ubuntu 1062 0.1 0.3 26688 12672 ? S 13:45 0:00 sshd-session: ubuntu@notty 131s ubuntu 1538 0.0 0.0 4032 2048 ? Ss 13:45 0:00 /bin/sh /tmp/autopkgtest.p6thpM/wrapper.sh --artifacts=/tmp/autopkgtest.p6thpM/ssh.sh-artifacts --chdir=/tmp/autopkgtest.p6thpM/build.dVI/src --env=AUTOPKGTEST_TESTBED_ARCH=ppc64el --env=AUTOPKGTEST_TEST_ARCH=ppc64el --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.p6thpM/ssh.sh-stderr --stdout=/tmp/autopkgtest.p6thpM/ssh.sh-stdout --tmp=/tmp/autopkgtest.p6thpM/autopkgtest_tmp --env=ADT_TEST_TRIGGERS=openssh/1:10.0p1-5ubuntu2 --make-executable=/tmp/autopkgtest.p6thpM/build.dVI/src/debian/tests/ssh.sh -- /tmp/autopkgtest.p6thpM/build.dVI/src/debian/tests/ssh.sh 131s ubuntu 1563 0.0 0.0 8064 2048 ? S 13:45 0:00 tee -a -- /tmp/autopkgtest.p6thpM/ssh.sh-stdout 131s ubuntu 1565 0.0 0.0 8064 2048 ? S 13:45 0:00 tee -a -- /tmp/autopkgtest.p6thpM/ssh.sh-stderr 131s ubuntu 1567 0.0 0.0 4032 2048 ? S 13:45 0:00 /bin/sh /tmp/autopkgtest.p6thpM/build.dVI/src/debian/tests/ssh.sh 131s ubuntu 1570 0.0 0.0 9344 4096 ? R 13:45 0:00 ps uwwx 131s No SSH agent variables in the environment, right? 131s + echo And ssh-add cannot see anything, either 131s + ssh-add -l 131s And ssh-add cannot see anything, either 131s Could not open a connection to your authentication agent. 131s + mktemp -d 131s + tempd=/tmp/tmp.RfBxSMzySO 131s + echo Using our tempdir /tmp/tmp.RfBxSMzySO 131s + echo OK, let us start an SSH agent... 131s + ssh-agent -s 131s Using our tempdir /tmp/tmp.RfBxSMzySO 131s OK, let us start an SSH agent... 131s + echo Output: 131s + cat -- /tmp/tmp.RfBxSMzySO/ssh-agent.out 131s Output: 131s + echo Loading it: 131s + . /tmp/tmp.RfBxSMzySO/ssh-agent.out 131s + SSH_AUTH_SOCK=/tmp/ssh-8Pjon7d9KzHC/agent.1575 131s + export SSH_AUTH_SOCK 131s + SSH_AGENT_PID=1576 131s + export SSH_AGENT_PID 131s + echo Agent pid 1576 131s + echo Environment: 131s SSH_AUTH_SOCK=/tmp/ssh-8Pjon7d9KzHC/agent.1575; export SSH_AUTH_SOCK; 131s SSH_AGENT_PID=1576; export SSH_AGENT_PID; 131s echo Agent pid 1576; 131s Loading it: 131s Agent pid 1576 131s Environment: 131s + printenv 131s + egrep -e ^SSH_ 131s SSH_AGENT_PID=1576 131s SSH_AUTH_SOCK=/tmp/ssh-8Pjon7d9KzHC/agent.1575 131s + echo Query it - no identities expected 131s + res=0 131s + ssh-add -l 131s Query it - no identities expected 131s + res=1 131s + echo - standard output: 131s + cat -- /tmp/tmp.RfBxSMzySO/ssh-add.out 131s + echo - standard error: 131s + cat -- /tmp/tmp.RfBxSMzySO/ssh-add.err 131s + echo - make sure it did not output the key 131s + fgrep -e tanj@straylight -- /tmp/tmp.RfBxSMzySO/ssh-add.out 131s - standard output: 131s The agent has no identities. 131s - standard error: 131s - make sure it did not output the key 131s + echo - make sure it failed 131s + [ 1 != 0 ] 131s + echo Now add a key 131s + install -m 600 -- debian/tests/data/id_tanj /tmp/tmp.RfBxSMzySO/ 131s - make sure it failed 131s Now add a key 131s + install -m 644 -- debian/tests/data/id_tanj.pub /tmp/tmp.RfBxSMzySO/ 131s + ssh-add -- /tmp/tmp.RfBxSMzySO/id_tanj 131s Identity added: /tmp/tmp.RfBxSMzySO/id_tanj (tanj@straylight) 131s + echo But did it work? 131s + res=0 131s But did it work? 131s + ssh-add -l 131s + echo - standard output: 131s + cat -- /tmp/tmp.RfBxSMzySO/ssh-add.out 131s - standard output: 131s 2048 SHA256:Jj81+RS4yFX0l59QjgwtDwSgsItAynP6ioIjD4RA2kQ tanj@straylight (RSA) 131s + echo - standard error: 131s + cat -- /tmp/tmp.RfBxSMzySO/ssh-add.err 131s + echo - make sure it succeeded 131s + [ 0 = 0 ] 131s + echo - make sure it output some info about the key 131s + fgrep -e tanj@straylight -- /tmp/tmp.RfBxSMzySO/ssh-add.out 131s + echo Let us stop the agent 131s + ssh-agent -s -k 131s + - standard error: 131s - make sure it succeeded 131s - make sure it output some info about the key 131s 2048 SHA256:Jj81+RS4yFX0l59QjgwtDwSgsItAynP6ioIjD4RA2kQ tanj@straylight (RSA) 131s Let us stop the agent 131s - output: 131s unset SSH_AUTH_SOCK; 131s unset SSH_AGENT_PID; 131s echo Agent pid 1576 killed; 131s echo - output: 131s + cat -- /tmp/tmp.RfBxSMzySO/ssh-agent.out 131s + echo - load it... 131s + . /tmp/tmp.RfBxSMzySO/ssh-agent.out 131s + unset SSH_AUTH_SOCK 131s + unset SSH_AGENT_PID 131s + echo Agent pid 1576 killed 131s + echo - environment: 131s + printenv 131s + egrep -e ^SSH_ 131s + mktemp -d 131s + kchome=/tmp/tmp.vDVPxFJ6bD 131s + echo Using keychain home directory /tmp/tmp.vDVPxFJ6bD and our tempdir /tmp/tmp.RfBxSMzySO 131s + keychain -q --dir /tmp/tmp.vDVPxFJ6bD --eval /tmp/tmp.RfBxSMzySO/id_tanj 131s - load it... 131s Agent pid 1576 killed 131s - environment: 131s Using keychain home directory /tmp/tmp.vDVPxFJ6bD and our tempdir /tmp/tmp.RfBxSMzySO 131s ssh-keygen: /tmp/tmp.RfBxSMzySO/id_tanj.pub: Permission denied 131s * Warning: Unable to extract fingerprint from keyfile /tmp/tmp.RfBxSMzySO/id_tanj.pub, skipping 131s + echo The output: 131s + cat -- /tmp/tmp.RfBxSMzySO/1.out 131s + echo Loading it... 131s + cat -- /tmp/tmp.RfBxSMzySO/1.out 131s The output: 131s SSH_AUTH_SOCK=/tmp/ssh-4G3KQ3mbINCD/agent.1616; export SSH_AUTH_SOCK; 131s SSH_AGENT_PID=1617; export SSH_AGENT_PID; 131s 131s Loading it... 131s + eval SSH_AUTH_SOCK=/tmp/ssh-4G3KQ3mbINCD/agent.1616; export SSH_AUTH_SOCK; 131s SSH_AGENT_PID=1617; export SSH_AGENT_PID; 131s + SSH_AUTH_SOCK=/tmp/ssh-4G3KQ3mbINCD/agent.1616 131s + export SSH_AUTH_SOCK 131s + SSH_AGENT_PID=1617 131s + export SSH_AGENT_PID 131s + echo Let us take a look at the environment now... 131s Let us take a look at the environment now... 131s + printenv 131s + egrep -e ^SSH_ 131s + [ -z /tmp/ssh-4G3KQ3mbINCD/agent.1616 ] 131s + ssh-add -l 131s SSH_AGENT_PID=1617 131s SSH_AUTH_SOCK=/tmp/ssh-4G3KQ3mbINCD/agent.1616 131s The agent has no identities. 131s autopkgtest [13:45:27]: test ssh.sh: -----------------------] 132s autopkgtest [13:45:28]: test ssh.sh: - - - - - - - - - - results - - - - - - - - - - 132s ssh.sh FAIL non-zero exit status 1 132s autopkgtest [13:45:28]: @@@@@@@@@@@@@@@@@@@@ summary 132s ssh.sh FAIL non-zero exit status 1