0s autopkgtest [13:41:37]: starting date and time: 2025-07-11 13:41:37+0000 0s autopkgtest [13:41:37]: git checkout: 508d4a25 a-v-ssh wait_for_ssh: demote "ssh connection failed" to a debug message 0s autopkgtest [13:41:37]: host juju-7f2275-prod-proposed-migration-environment-2; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.wj0pjq4l/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-arm64 --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@sto01-arm64-13.secgroup --name adt-questing-arm64-keychain-20250711-134136-juju-7f2275-prod-proposed-migration-environment-2-5b2f0e32-35a3-4614-b0fa-abb2b63c2057 --image adt/ubuntu-questing-arm64-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-2 --net-id=net_prod-autopkgtest-workers-arm64 -e TERM=linux --mirror=http://ftpmaster.internal/ubuntu/ 3s Creating nova instance adt-questing-arm64-keychain-20250711-134136-juju-7f2275-prod-proposed-migration-environment-2-5b2f0e32-35a3-4614-b0fa-abb2b63c2057 from image adt/ubuntu-questing-arm64-server-20250711.img (UUID 8dea51ee-6a89-44d3-a2e5-01ec0db52f59)... 39s autopkgtest [13:42:16]: testbed dpkg architecture: arm64 39s autopkgtest [13:42:16]: testbed apt version: 3.1.3 40s autopkgtest [13:42:17]: @@@@@@@@@@@@@@@@@@@@ test bed setup 40s autopkgtest [13:42:17]: testbed release detected to be: None 40s autopkgtest [13:42:17]: updating testbed package index (apt update) 41s Get:1 http://ftpmaster.internal/ubuntu questing-proposed InRelease [249 kB] 41s Hit:2 http://ftpmaster.internal/ubuntu questing InRelease 41s Hit:3 http://ftpmaster.internal/ubuntu questing-updates InRelease 41s Hit:4 http://ftpmaster.internal/ubuntu questing-security InRelease 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 [179 kB] 41s Get:7 http://ftpmaster.internal/ubuntu questing-proposed/main Sources [36.9 kB] 41s Get:8 http://ftpmaster.internal/ubuntu questing-proposed/main arm64 Packages [55.0 kB] 41s Get:9 http://ftpmaster.internal/ubuntu questing-proposed/universe arm64 Packages [178 kB] 41s Get:10 http://ftpmaster.internal/ubuntu questing-proposed/multiverse arm64 Packages [15.7 kB] 41s Fetched 730 kB in 0s (1985 kB/s) 42s Reading package lists... 42s autopkgtest [13:42:19]: upgrading testbed (apt dist-upgrade and autopurge) 42s Reading package lists... 42s Building dependency tree... 42s Reading state information... 43s Calculating upgrade... 43s The following packages will be upgraded: 43s openssh-client openssh-server openssh-sftp-server 43s 3 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 43s Need to get 1567 kB of archives. 43s After this operation, 590 kB of additional disk space will be used. 43s Get:1 http://ftpmaster.internal/ubuntu questing-proposed/main arm64 openssh-sftp-server arm64 1:10.0p1-5ubuntu2 [36.8 kB] 43s Get:2 http://ftpmaster.internal/ubuntu questing-proposed/main arm64 openssh-server arm64 1:10.0p1-5ubuntu2 [603 kB] 43s Get:3 http://ftpmaster.internal/ubuntu questing-proposed/main arm64 openssh-client arm64 1:10.0p1-5ubuntu2 [927 kB] 43s Preconfiguring packages ... 44s Fetched 1567 kB in 0s (5272 kB/s) 44s (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 ... 131053 files and directories currently installed.) 44s Preparing to unpack .../openssh-sftp-server_1%3a10.0p1-5ubuntu2_arm64.deb ... 44s Unpacking openssh-sftp-server (1:10.0p1-5ubuntu2) over (1:9.9p1-3ubuntu3.1) ... 44s Preparing to unpack .../openssh-server_1%3a10.0p1-5ubuntu2_arm64.deb ... 44s Unpacking openssh-server (1:10.0p1-5ubuntu2) over (1:9.9p1-3ubuntu3.1) ... 44s Preparing to unpack .../openssh-client_1%3a10.0p1-5ubuntu2_arm64.deb ... 44s Unpacking openssh-client (1:10.0p1-5ubuntu2) over (1:9.9p1-3ubuntu3.1) ... 44s Setting up openssh-client (1:10.0p1-5ubuntu2) ... 44s Installing new version of config file /etc/ssh/ssh_config ... 44s Created symlink '/etc/systemd/user/sockets.target.wants/ssh-agent.socket' → '/usr/lib/systemd/user/ssh-agent.socket'. 44s Setting up openssh-sftp-server (1:10.0p1-5ubuntu2) ... 44s Setting up openssh-server (1:10.0p1-5ubuntu2) ... 44s Installing new version of config file /etc/ssh/moduli ... 44s Replacing config file /etc/ssh/sshd_config with new version 45s Created symlink '/etc/systemd/system/ssh.service.wants/sshd-keygen.service' → '/usr/lib/systemd/system/sshd-keygen.service'. 45s Created symlink '/etc/systemd/system/sshd.service.wants/sshd-keygen.service' → '/usr/lib/systemd/system/sshd-keygen.service'. 45s Created symlink '/etc/systemd/system/sshd@.service.wants/sshd-keygen.service' → '/usr/lib/systemd/system/sshd-keygen.service'. 45s Created symlink '/etc/systemd/system/ssh.socket.wants/sshd-keygen.service' → '/usr/lib/systemd/system/sshd-keygen.service'. 46s Processing triggers for man-db (2.13.1-1) ... 47s Processing triggers for ufw (0.36.2-9) ... 47s Reading package lists... 47s Building dependency tree... 47s Reading state information... 47s Solving dependencies... 47s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 48s autopkgtest [13:42:25]: rebooting testbed after setup commands that affected boot 72s autopkgtest [13:42:49]: testbed running kernel: Linux 6.15.0-4-generic #4-Ubuntu SMP PREEMPT_DYNAMIC Fri Jul 4 14:27:49 UTC 2025 74s autopkgtest [13:42:51]: @@@@@@@@@@@@@@@@@@@@ apt-source keychain 75s Get:1 http://ftpmaster.internal/ubuntu questing/universe keychain 2.8.5-5 (dsc) [2024 B] 75s Get:2 http://ftpmaster.internal/ubuntu questing/universe keychain 2.8.5-5 (tar) [66.4 kB] 75s Get:3 http://ftpmaster.internal/ubuntu questing/universe keychain 2.8.5-5 (diff) [9128 B] 75s gpgv: Signature made Tue Dec 31 09:51:29 2024 UTC 75s gpgv: using RSA key 2EE7A7A517FC124CF115C354651EEFB02527DF13 75s gpgv: issuer "roam@debian.org" 75s gpgv: Can't check signature: No public key 75s dpkg-source: warning: cannot verify inline signature for ./keychain_2.8.5-5.dsc: no acceptable signature found 75s autopkgtest [13:42:52]: testing package keychain version 2.8.5-5 75s autopkgtest [13:42:52]: build not needed 76s autopkgtest [13:42:53]: test ssh.sh: preparing testbed 76s Reading package lists... 76s Building dependency tree... 76s Reading state information... 76s Solving dependencies... 76s The following NEW packages will be installed: 76s keychain 76s 0 upgraded, 1 newly installed, 0 to remove and 0 not upgraded. 76s Need to get 37.0 kB of archives. 76s After this operation, 82.9 kB of additional disk space will be used. 76s Get:1 http://ftpmaster.internal/ubuntu questing/universe arm64 keychain all 2.8.5-5 [37.0 kB] 77s Fetched 37.0 kB in 0s (2744 kB/s) 77s Selecting previously unselected package keychain. 77s (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 ... 131054 files and directories currently installed.) 77s Preparing to unpack .../keychain_2.8.5-5_all.deb ... 77s Unpacking keychain (2.8.5-5) ... 77s Setting up keychain (2.8.5-5) ... 77s Processing triggers for man-db (2.13.1-1) ... 78s autopkgtest [13:42:55]: test ssh.sh: [----------------------- 78s + export LC_ALL=C 78s + id -un 78s + uid=ubuntu 78s + id 78s 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) 78s Process list: 78s + 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) 78s + echo Process list: 78s + ps uwwx 78s USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND 78s ubuntu 886 0.6 0.2 22804 11848 ? Ss 13:42 0:00 /usr/lib/systemd/systemd --user 78s ubuntu 887 0.0 0.0 23412 3712 ? S 13:42 0:00 (sd-pam) 78s ubuntu 919 0.3 0.1 19544 7412 ? S 13:42 0:00 sshd-session: ubuntu@notty 78s ubuntu 1390 0.0 0.0 2472 1568 ? Ss 13:42 0:00 /bin/sh /tmp/autopkgtest.qx2Sv1/wrapper.sh --artifacts=/tmp/autopkgtest.qx2Sv1/ssh.sh-artifacts --chdir=/tmp/autopkgtest.qx2Sv1/build.yJp/src --env=AUTOPKGTEST_TESTBED_ARCH=arm64 --env=AUTOPKGTEST_TEST_ARCH=arm64 --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.qx2Sv1/ssh.sh-stderr --stdout=/tmp/autopkgtest.qx2Sv1/ssh.sh-stdout --tmp=/tmp/autopkgtest.qx2Sv1/autopkgtest_tmp --env=ADT_TEST_TRIGGERS=openssh/1:10.0p1-5ubuntu2 --make-executable=/tmp/autopkgtest.qx2Sv1/build.yJp/src/debian/tests/ssh.sh -- /tmp/autopkgtest.qx2Sv1/build.yJp/src/debian/tests/ssh.sh 78s ubuntu 1415 0.0 0.0 5792 1424 ? S 13:42 0:00 tee -a -- /tmp/autopkgtest.qx2Sv1/ssh.sh-stdout 78s ubuntu 1417 0.0 0.0 5792 1424 ? S 13:42 0:00 tee -a -- /tmp/autopkgtest.qx2Sv1/ssh.sh-stderr 78s ubuntu 1419 0.0 0.0 2472 1444 ? S 13:42 0:00 /bin/sh /tmp/autopkgtest.qx2Sv1/build.yJp/src/debian/tests/ssh.sh 78s ubuntu 1422 0.0 0.0 6240 3380 ? R 13:42 0:00 ps uwwx 78s + No SSH agent variables in the environment, right? 78s unset SSH_AUTH_SOCK 78s + unset SSH_AGENT_PID 78s + echo No SSH agent variables in the environment, right? 78s + printenv 78s + egrep -e ^SSH_ 78s And ssh-add cannot see anything, either 78s + echo And ssh-add cannot see anything, either 78s + ssh-add -l 78s Could not open a connection to your authentication agent. 78s + mktemp -d 78s + Using our tempdir /tmp/tmp.6QmogZ7fPl 78s OK, let us start an SSH agent... 78s tempd=/tmp/tmp.6QmogZ7fPl 78s + echo Using our tempdir /tmp/tmp.6QmogZ7fPl 78s + echo OK, let us start an SSH agent... 78s + ssh-agent -s 78s Output: 78s + echo Output: 78s + cat -- /tmp/tmp.6QmogZ7fPl/ssh-agent.out 78s SSH_AUTH_SOCK=/tmp/ssh-NmtxnRAFZEyc/agent.1427; export SSH_AUTH_SOCK; 78s SSH_AGENT_PID=1428; export SSH_AGENT_PID; 78s echo Agent pid 1428; 78s + echo Loading it:Loading it: 78s Agent pid 1428 78s Environment: 78s 78s + . /tmp/tmp.6QmogZ7fPl/ssh-agent.out 78s + SSH_AUTH_SOCK=/tmp/ssh-NmtxnRAFZEyc/agent.1427 78s + export SSH_AUTH_SOCK 78s + SSH_AGENT_PID=1428 78s + export SSH_AGENT_PID 78s + echo Agent pid 1428 78s + echo Environment: 78s + printenv 78s + egrep -e ^SSH_ 78s SSH_AGENT_PID=1428 78s SSH_AUTH_SOCK=/tmp/ssh-NmtxnRAFZEyc/agent.1427 78s Query it - no identities expected 78s + echo Query it - no identities expected 78s + res=0 78s + ssh-add -l 78s - standard output: 78s + res=1 78s + echo - standard output: 78s The agent has no identities. 78s - standard error: 78s + cat -- /tmp/tmp.6QmogZ7fPl/ssh-add.out 78s + echo - standard error: 78s + cat -- /tmp/tmp.6QmogZ7fPl/ssh-add.err 78s - make sure it did not output the key 78s + echo - make sure it did not output the key 78s + fgrep -e tanj@straylight -- /tmp/tmp.6QmogZ7fPl/ssh-add.out 78s - make sure it failed 78s Now add a key 78s + echo - make sure it failed 78s + [ 1 != 0 ] 78s + echo Now add a key 78s + install -m 600 -- debian/tests/data/id_tanj /tmp/tmp.6QmogZ7fPl/ 78s + install -m 644 -- debian/tests/data/id_tanj.pub /tmp/tmp.6QmogZ7fPl/ 78s + ssh-add -- /tmp/tmp.6QmogZ7fPl/id_tanj 78s Identity added: /tmp/tmp.6QmogZ7fPl/id_tanj (tanj@straylight) 78s But did it work? 78s + echo But did it work? 78s + res=0 78s + ssh-add -l 78s - standard output: 78s + echo - standard output: 78s + cat -- /tmp/tmp.6QmogZ7fPl/ssh-add.out 78s 2048 SHA256:Jj81+RS4yFX0l59QjgwtDwSgsItAynP6ioIjD4RA2kQ tanj@straylight (RSA) 78s - standard error: 78s + echo - standard error: 78s + cat -- /tmp/tmp.6QmogZ7fPl/ssh-add.err 78s - make sure it succeeded 78s - make sure it output some info about the key 78s + echo - make sure it succeeded 78s + [ 0 = 0 ] 78s + echo - make sure it output some info about the key 78s + fgrep -e tanj@straylight -- /tmp/tmp.6QmogZ7fPl/ssh-add.out 78s 2048 SHA256:Jj81+RS4yFX0l59QjgwtDwSgsItAynP6ioIjD4RA2kQ tanj@straylight (RSA) 78s Let us stop the agent 78s + echo Let us stop the agent 78s + ssh-agent -s -k 78s - output: 78s + echo - output: 78s + cat -- /tmp/tmp.6QmogZ7fPl/ssh-agent.out 78s unset SSH_AUTH_SOCK; 78s unset SSH_AGENT_PID; 78s echo Agent pid 1428 killed; 78s + echo - load it... 78s + . /tmp/tmp.6QmogZ7fPl/ssh-agent.out 78s - load it... 78s Agent pid 1428 killed 78s - environment: 78s + unset SSH_AUTH_SOCK 78s + unset SSH_AGENT_PID 78s + echo Agent pid 1428 killed 78s + echo - environment: 78s + printenv 78s + egrep -e ^SSH_ 78s + mktemp -d 78s Using keychain home directory /tmp/tmp.4xgoTIy1Ch and our tempdir /tmp/tmp.6QmogZ7fPl 78s + kchome=/tmp/tmp.4xgoTIy1Ch 78s + echo Using keychain home directory /tmp/tmp.4xgoTIy1Ch and our tempdir /tmp/tmp.6QmogZ7fPl 78s + keychain -q --dir /tmp/tmp.4xgoTIy1Ch --eval /tmp/tmp.6QmogZ7fPl/id_tanj 79s ssh-keygen: /tmp/tmp.6QmogZ7fPl/id_tanj.pub: Permission denied 79s * Warning: Unable to extract fingerprint from keyfile /tmp/tmp.6QmogZ7fPl/id_tanj.pub, skipping 79s The output: 79s + echo The output: 79s + cat -- /tmp/tmp.6QmogZ7fPl/1.out 79s SSH_AUTH_SOCK=/tmp/ssh-OpbiJt7I0HBM/agent.1468; export SSH_AUTH_SOCK; 79s SSH_AGENT_PID=1469; export SSH_AGENT_PID; 79s 79s Loading it... 79s + echo Loading it... 79s Let us take a look at the environment now... 79s SSH_AGENT_PID=1469 79s SSH_AUTH_SOCK=/tmp/ssh-OpbiJt7I0HBM/agent.1468 79s The agent has no identities. 79s + cat -- /tmp/tmp.6QmogZ7fPl/1.out 79s + eval SSH_AUTH_SOCK=/tmp/ssh-OpbiJt7I0HBM/agent.1468; export SSH_AUTH_SOCK; 79s SSH_AGENT_PID=1469; export SSH_AGENT_PID; 79s + SSH_AUTH_SOCK=/tmp/ssh-OpbiJt7I0HBM/agent.1468 79s + export SSH_AUTH_SOCK 79s + SSH_AGENT_PID=1469 79s + export SSH_AGENT_PID 79s + echo Let us take a look at the environment now... 79s + printenv 79s + egrep -e ^SSH_ 79s + [ -z /tmp/ssh-OpbiJt7I0HBM/agent.1468 ] 79s + ssh-add -l 79s autopkgtest [13:42:56]: test ssh.sh: -----------------------] 79s autopkgtest [13:42:56]: test ssh.sh: - - - - - - - - - - results - - - - - - - - - - 79s ssh.sh FAIL non-zero exit status 1 79s autopkgtest [13:42:56]: @@@@@@@@@@@@@@@@@@@@ summary 79s ssh.sh FAIL non-zero exit status 1