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-15; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.m0o3nyh1/out --timeout-copy=6000 -a i386 --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-15@sto01-13.secgroup --name adt-questing-i386-keychain-20250711-134136-juju-7f2275-prod-proposed-migration-environment-15-874fa6e1-32ee-44b4-b63b-a49764a90dbe --image adt/ubuntu-questing-amd64-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-15 --net-id=net_prod-autopkgtest-workers-amd64 -e TERM=linux --mirror=http://ftpmaster.internal/ubuntu/ 3s Creating nova instance adt-questing-i386-keychain-20250711-134136-juju-7f2275-prod-proposed-migration-environment-15-874fa6e1-32ee-44b4-b63b-a49764a90dbe from image adt/ubuntu-questing-amd64-server-20250711.img (UUID 0957a5f8-1328-4bf4-9630-67e41bd0820f)... 28s autopkgtest [13:42:05]: testbed dpkg architecture: amd64 28s autopkgtest [13:42:05]: testbed apt version: 3.1.3 29s autopkgtest [13:42:06]: @@@@@@@@@@@@@@@@@@@@ test bed setup 29s autopkgtest [13:42:06]: testbed release detected to be: None 29s autopkgtest [13:42:06]: updating testbed package index (apt update) 30s Get:1 http://ftpmaster.internal/ubuntu questing-proposed InRelease [249 kB] 30s Hit:2 http://ftpmaster.internal/ubuntu questing InRelease 30s Hit:3 http://ftpmaster.internal/ubuntu questing-updates InRelease 30s Hit:4 http://ftpmaster.internal/ubuntu questing-security InRelease 30s Get:5 http://ftpmaster.internal/ubuntu questing-proposed/universe Sources [179 kB] 30s Get:6 http://ftpmaster.internal/ubuntu questing-proposed/main Sources [36.9 kB] 30s Get:7 http://ftpmaster.internal/ubuntu questing-proposed/multiverse Sources [15.4 kB] 30s Get:8 http://ftpmaster.internal/ubuntu questing-proposed/main i386 Packages [39.1 kB] 30s Get:9 http://ftpmaster.internal/ubuntu questing-proposed/main amd64 Packages [56.9 kB] 30s Get:10 http://ftpmaster.internal/ubuntu questing-proposed/universe i386 Packages [105 kB] 30s Get:11 http://ftpmaster.internal/ubuntu questing-proposed/universe amd64 Packages [178 kB] 30s Get:12 http://ftpmaster.internal/ubuntu questing-proposed/multiverse amd64 Packages [16.6 kB] 30s Get:13 http://ftpmaster.internal/ubuntu questing-proposed/multiverse i386 Packages [8592 B] 30s Fetched 886 kB in 1s (1739 kB/s) 31s Reading package lists... 31s autopkgtest [13:42:08]: upgrading testbed (apt dist-upgrade and autopurge) 31s Reading package lists... 32s Building dependency tree... 32s Reading state information... 32s Calculating upgrade... 32s The following packages will be upgraded: 32s openssh-client openssh-server openssh-sftp-server 32s 3 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 32s Need to get 1595 kB of archives. 32s After this operation, 549 kB disk space will be freed. 32s Get:1 http://ftpmaster.internal/ubuntu questing-proposed/main amd64 openssh-sftp-server amd64 1:10.0p1-5ubuntu2 [37.4 kB] 32s Get:2 http://ftpmaster.internal/ubuntu questing-proposed/main amd64 openssh-server amd64 1:10.0p1-5ubuntu2 [614 kB] 32s Get:3 http://ftpmaster.internal/ubuntu questing-proposed/main amd64 openssh-client amd64 1:10.0p1-5ubuntu2 [943 kB] 32s Preconfiguring packages ... 32s Fetched 1595 kB in 0s (4687 kB/s) 32s (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.) 32s Preparing to unpack .../openssh-sftp-server_1%3a10.0p1-5ubuntu2_amd64.deb ... 32s 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) ... 33s Preparing to unpack .../openssh-client_1%3a10.0p1-5ubuntu2_amd64.deb ... 33s Unpacking openssh-client (1:10.0p1-5ubuntu2) over (1:9.9p1-3ubuntu3.1) ... 33s Setting up openssh-client (1:10.0p1-5ubuntu2) ... 33s Installing new version of config file /etc/ssh/ssh_config ... 33s Created symlink '/etc/systemd/user/sockets.target.wants/ssh-agent.socket' → '/usr/lib/systemd/user/ssh-agent.socket'. 33s Setting up openssh-sftp-server (1:10.0p1-5ubuntu2) ... 33s Setting up openssh-server (1:10.0p1-5ubuntu2) ... 33s Installing new version of config file /etc/ssh/moduli ... 33s Replacing config file /etc/ssh/sshd_config with new version 34s Created symlink '/etc/systemd/system/ssh.service.wants/sshd-keygen.service' → '/usr/lib/systemd/system/sshd-keygen.service'. 34s Created symlink '/etc/systemd/system/sshd.service.wants/sshd-keygen.service' → '/usr/lib/systemd/system/sshd-keygen.service'. 34s Created symlink '/etc/systemd/system/sshd@.service.wants/sshd-keygen.service' → '/usr/lib/systemd/system/sshd-keygen.service'. 34s Created symlink '/etc/systemd/system/ssh.socket.wants/sshd-keygen.service' → '/usr/lib/systemd/system/sshd-keygen.service'. 34s Processing triggers for man-db (2.13.1-1) ... 35s Processing triggers for ufw (0.36.2-9) ... 35s Reading package lists... 35s Building dependency tree... 35s Reading state information... 35s Solving dependencies... 35s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 36s autopkgtest [13:42:13]: rebooting testbed after setup commands that affected boot 53s autopkgtest [13:42:30]: 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:32]: @@@@@@@@@@@@@@@@@@@@ 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] 57s gpgv: Signature made Tue Dec 31 09:51:29 2024 UTC 57s gpgv: using RSA key 2EE7A7A517FC124CF115C354651EEFB02527DF13 57s gpgv: issuer "roam@debian.org" 57s gpgv: Can't check signature: No public key 57s dpkg-source: warning: cannot verify inline signature for ./keychain_2.8.5-5.dsc: no acceptable signature found 57s autopkgtest [13:42:34]: testing package keychain version 2.8.5-5 57s autopkgtest [13:42:34]: build not needed 57s autopkgtest [13:42:34]: 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 (2257 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:36]: test environment configured for cross building 59s autopkgtest [13:42:36]: test ssh.sh: [----------------------- 59s + export LC_ALL=C 59s + id -un 59s + uid=ubuntu 59s + id 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 + 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 USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND 59s ubuntu 888 0.6 0.2 21532 11960 ? Ss 13:42 0:00 /usr/lib/systemd/systemd --user 59s ubuntu 889 0.0 0.0 21648 3584 ? S 13:42 0:00 (sd-pam) 59s ubuntu 937 0.3 0.1 17652 7800 ? S 13:42 0:00 sshd-session: ubuntu@notty 59s ubuntu 1420 0.0 0.0 2896 1968 ? Ss 13:42 0:00 /bin/sh /tmp/autopkgtest.F1vZHr/wrapper.sh --artifacts=/tmp/autopkgtest.F1vZHr/ssh.sh-artifacts --chdir=/tmp/autopkgtest.F1vZHr/build.HL4/src --env=AUTOPKGTEST_TESTBED_ARCH=amd64 --env=AUTOPKGTEST_TEST_ARCH=i386 --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.F1vZHr/ssh.sh-stderr --stdout=/tmp/autopkgtest.F1vZHr/ssh.sh-stdout --tmp=/tmp/autopkgtest.F1vZHr/autopkgtest_tmp --env=DEB_BUILD_ARCH=amd64 --env=DEB_BUILD_ARCH_ABI=base --env=DEB_BUILD_ARCH_BITS=64 --env=DEB_BUILD_ARCH_CPU=amd64 --env=DEB_BUILD_ARCH_ENDIAN=little --env=DEB_BUILD_ARCH_LIBC=gnu --env=DEB_BUILD_ARCH_OS=linux --env=DEB_BUILD_GNU_CPU=x86_64 --env=DEB_BUILD_GNU_SYSTEM=linux-gnu --env=DEB_BUILD_GNU_TYPE=x86_64-linux-gnu --env=DEB_BUILD_MULTIARCH=x86_64-linux-gnu --env=DEB_HOST_ARCH=i386 --env=DEB_HOST_ARCH_ABI=base --env=DEB_HOST_ARCH_BITS=32 --env=DEB_HOST_ARCH_CPU=i386 --env=DEB_HOST_ARCH_ENDIAN=little --env=DEB_HOST_ARCH_LIBC=gnu --env=DEB_HOST_ARCH_OS=linux --env=DEB_HOST_GNU_CPU=i686 --env=DEB_HOST_GNU_SYSTEM=linux-gnu --env=DEB_HOST_GNU_TYPE=i686-linux-gnu --env=DEB_HOST_MULTIARCH=i386-linux-gnu --env=ADT_TEST_TRIGGERS=openssh/1:10.0p1-5ubuntu2 --make-executable=/tmp/autopkgtest.F1vZHr/build.HL4/src/debian/tests/ssh.sh -- /tmp/autopkgtest.F1vZHr/build.HL4/src/debian/tests/ssh.sh 59s ubuntu 1445 0.0 0.0 6204 1820 ? S 13:42 0:00 tee -a -- /tmp/autopkgtest.F1vZHr/ssh.sh-stdout 59s ubuntu 1447 0.0 0.0 6204 1756 ? S 13:42 0:00 tee -a -- /tmp/autopkgtest.F1vZHr/ssh.sh-stderr 59s ubuntu 1449 0.0 0.0 2896 1840 ? S 13:42 0:00 /bin/sh /tmp/autopkgtest.F1vZHr/build.HL4/src/debian/tests/ssh.sh 59s ubuntu 1452 0.0 0.1 6612 4036 ? R 13:42 0:00 ps uwwx 59s No SSH agent variables in the environment, right? 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 + And ssh-add cannot see anything, either 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 Using our tempdir /tmp/tmp.smttiKu2sR 59s OK, let us start an SSH agent... 59s + tempd=/tmp/tmp.smttiKu2sR 59s + echo Using our tempdir /tmp/tmp.smttiKu2sR 59s + echo OK, let us start an SSH agent... 59s + ssh-agent -s 59s Output: 59s + echo Output: 59s + cat -- /tmp/tmp.smttiKu2sR/ssh-agent.out 59s SSH_AUTH_SOCK=/tmp/ssh-lHWDntZmupBu/agent.1457; export SSH_AUTH_SOCK; 59s SSH_AGENT_PID=1458; export SSH_AGENT_PID; 59s echo Agent pid 1458; 59s + echo Loading it:Loading it: 59s Agent pid 1458 59s Environment: 59s 59s + . /tmp/tmp.smttiKu2sR/ssh-agent.out 59s + SSH_AUTH_SOCK=/tmp/ssh-lHWDntZmupBu/agent.1457 59s + export SSH_AUTH_SOCK 59s + SSH_AGENT_PID=1458 59s + export SSH_AGENT_PID 59s + echo Agent pid 1458 59s + echo Environment: 59s + printenv 59s + egrep -e ^SSH_ 59s SSH_AGENT_PID=1458 59s SSH_AUTH_SOCK=/tmp/ssh-lHWDntZmupBu/agent.1457 59s Query it - no identities expected 59s + echo Query it - no identities expected 59s + res=0 59s + ssh-add -l 59s - standard output: 59s + res=1 59s + echo - standard output: 59s + cat -- /tmp/tmp.smttiKu2sR/ssh-add.out 59s The agent has no identities. 59s - standard error: 59s + echo - standard error: 59s + cat -- /tmp/tmp.smttiKu2sR/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.smttiKu2sR/ssh-add.out 59s - make sure it failed 59s + echo - make sure it failed 59s + Now add a key 59s [ 1 != 0 ] 59s + echo Now add a key 59s + install -m 600 -- debian/tests/data/id_tanj /tmp/tmp.smttiKu2sR/ 59s + install -m 644 -- debian/tests/data/id_tanj.pub /tmp/tmp.smttiKu2sR/ 59s + ssh-add -- /tmp/tmp.smttiKu2sR/id_tanj 59s Identity added: /tmp/tmp.smttiKu2sR/id_tanj (tanj@straylight) 59s But did it work? 59s + echo But did it work? 59s + res=0 59s + ssh-add -l 59s + echo - standard output:- standard output: 59s 59s + cat -- /tmp/tmp.smttiKu2sR/ssh-add.out 59s 2048 SHA256:Jj81+RS4yFX0l59QjgwtDwSgsItAynP6ioIjD4RA2kQ tanj@straylight (RSA) 59s - standard error: 59s + echo - standard error: 59s + cat -- /tmp/tmp.smttiKu2sR/ssh-add.err 59s - make sure it succeeded 59s - make sure it output some info about the key 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.smttiKu2sR/ssh-add.out 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 + echo - output: 59s + cat -- /tmp/tmp.smttiKu2sR/ssh-agent.out 59s unset SSH_AUTH_SOCK; 59s unset SSH_AGENT_PID; 59s echo Agent pid 1458 killed; 59s + echo - load it... 59s + . /tmp/tmp.smttiKu2sR/ssh-agent.out 59s + unset SSH_AUTH_SOCK 59s + unset SSH_AGENT_PID 59s + echo Agent pid 1458 killed 59s + echo - environment: 59s + printenv 59s + egrep -e ^SSH_ 59s - load it... 59s Agent pid 1458 killed 59s - environment: 60s Using keychain home directory /tmp/tmp.vVncLdRyR0 and our tempdir /tmp/tmp.smttiKu2sR 60s + mktemp -d 60s + kchome=/tmp/tmp.vVncLdRyR0 60s + echo Using keychain home directory /tmp/tmp.vVncLdRyR0 and our tempdir /tmp/tmp.smttiKu2sR 60s + keychain -q --dir /tmp/tmp.vVncLdRyR0 --eval /tmp/tmp.smttiKu2sR/id_tanj 60s ssh-keygen: /tmp/tmp.smttiKu2sR/id_tanj.pub: Permission denied 60s * Warning: Unable to extract fingerprint from keyfile /tmp/tmp.smttiKu2sR/id_tanj.pub, skipping 60s The output: 60s + echo The output: 60s + cat -- /tmp/tmp.smttiKu2sR/1.out 60s SSH_AUTH_SOCK=/tmp/ssh-h4rdVDMUZrke/agent.1498; export SSH_AUTH_SOCK; 60s SSH_AGENT_PID=1499; export SSH_AGENT_PID; 60s 60s Loading it... 60s + echo Loading it... 60s + cat -- /tmp/tmp.smttiKu2sR/1.out 60s Let us take a look at the environment now... 60s + eval SSH_AUTH_SOCK=/tmp/ssh-h4rdVDMUZrke/agent.1498; export SSH_AUTH_SOCK; 60s SSH_AGENT_PID=1499; export SSH_AGENT_PID; 60s + SSH_AUTH_SOCK=/tmp/ssh-h4rdVDMUZrke/agent.1498 60s + export SSH_AUTH_SOCK 60s + SSH_AGENT_PID=1499 60s + export SSH_AGENT_PID 60s + echo Let us take a look at the environment now... 60s + printenv 60s + egrep -e ^SSH_ 60s SSH_AGENT_PID=1499 60s SSH_AUTH_SOCK=/tmp/ssh-h4rdVDMUZrke/agent.1498 60s + [ -z /tmp/ssh-h4rdVDMUZrke/agent.1498 ] 60s + ssh-add -l 60s The agent has no identities. 60s autopkgtest [13:42:37]: test ssh.sh: -----------------------] 60s ssh.sh FAIL non-zero exit status 1 60s autopkgtest [13:42:37]: test ssh.sh: - - - - - - - - - - results - - - - - - - - - - 60s autopkgtest [13:42:37]: @@@@@@@@@@@@@@@@@@@@ summary 60s ssh.sh FAIL non-zero exit status 1