0s autopkgtest [13:41:36]: starting date and time: 2025-07-11 13:41:36+0000 0s autopkgtest [13:41:36]: git checkout: 508d4a25 a-v-ssh wait_for_ssh: demote "ssh connection failed" to a debug message 0s autopkgtest [13:41:36]: host juju-7f2275-prod-proposed-migration-environment-2; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.pf9yjfwx/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-s390x --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@bos03-s390x-10.secgroup --name adt-questing-s390x-keychain-20250711-134136-juju-7f2275-prod-proposed-migration-environment-2-c3408d04-00fa-4d68-aa2d-37c2efac3e60 --image adt/ubuntu-questing-s390x-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-2 --net-id=net_prod-proposed-migration-s390x -e TERM=linux --mirror=http://ftpmaster.internal/ubuntu/ 3s Creating nova instance adt-questing-s390x-keychain-20250711-134136-juju-7f2275-prod-proposed-migration-environment-2-c3408d04-00fa-4d68-aa2d-37c2efac3e60 from image adt/ubuntu-questing-s390x-server-20250711.img (UUID c5c71746-41c7-48a3-a212-e68c6cc91b9b)... 46s autopkgtest [13:42:22]: testbed dpkg architecture: s390x 46s autopkgtest [13:42:22]: testbed apt version: 3.1.3 46s autopkgtest [13:42:22]: @@@@@@@@@@@@@@@@@@@@ test bed setup 47s autopkgtest [13:42:23]: testbed release detected to be: None 47s autopkgtest [13:42:23]: updating testbed package index (apt update) 48s Get:1 http://ftpmaster.internal/ubuntu questing-proposed InRelease [249 kB] 48s Hit:2 http://ftpmaster.internal/ubuntu questing InRelease 48s Hit:3 http://ftpmaster.internal/ubuntu questing-updates InRelease 48s Hit:4 http://ftpmaster.internal/ubuntu questing-security InRelease 48s Get:5 http://ftpmaster.internal/ubuntu questing-proposed/multiverse Sources [15.4 kB] 48s Get:6 http://ftpmaster.internal/ubuntu questing-proposed/main Sources [36.9 kB] 48s Get:7 http://ftpmaster.internal/ubuntu questing-proposed/universe Sources [179 kB] 48s Get:8 http://ftpmaster.internal/ubuntu questing-proposed/main s390x Packages [52.7 kB] 48s Get:9 http://ftpmaster.internal/ubuntu questing-proposed/universe s390x Packages [162 kB] 48s Get:10 http://ftpmaster.internal/ubuntu questing-proposed/multiverse s390x Packages [4452 B] 48s Fetched 701 kB in 1s (934 kB/s) 49s Reading package lists... 49s autopkgtest [13:42:25]: upgrading testbed (apt dist-upgrade and autopurge) 49s Reading package lists... 50s Building dependency tree... 50s Reading state information... 50s Calculating upgrade... 50s The following packages will be upgraded: 50s openssh-client openssh-server openssh-sftp-server 50s 3 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 50s Need to get 1632 kB of archives. 50s After this operation, 620 kB of additional disk space will be used. 50s Get:1 http://ftpmaster.internal/ubuntu questing-proposed/main s390x openssh-sftp-server s390x 1:10.0p1-5ubuntu2 [38.3 kB] 50s Get:2 http://ftpmaster.internal/ubuntu questing-proposed/main s390x openssh-server s390x 1:10.0p1-5ubuntu2 [635 kB] 50s Get:3 http://ftpmaster.internal/ubuntu questing-proposed/main s390x openssh-client s390x 1:10.0p1-5ubuntu2 [959 kB] 50s Preconfiguring packages ... 50s Fetched 1632 kB in 1s (2890 kB/s) 51s (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 ... 82585 files and directories currently installed.) 51s Preparing to unpack .../openssh-sftp-server_1%3a10.0p1-5ubuntu2_s390x.deb ... 51s Unpacking openssh-sftp-server (1:10.0p1-5ubuntu2) over (1:9.9p1-3ubuntu3.1) ... 51s Preparing to unpack .../openssh-server_1%3a10.0p1-5ubuntu2_s390x.deb ... 51s Unpacking openssh-server (1:10.0p1-5ubuntu2) over (1:9.9p1-3ubuntu3.1) ... 51s Preparing to unpack .../openssh-client_1%3a10.0p1-5ubuntu2_s390x.deb ... 51s Unpacking openssh-client (1:10.0p1-5ubuntu2) over (1:9.9p1-3ubuntu3.1) ... 51s Setting up openssh-client (1:10.0p1-5ubuntu2) ... 51s Installing new version of config file /etc/ssh/ssh_config ... 51s Created symlink '/etc/systemd/user/sockets.target.wants/ssh-agent.socket' → '/usr/lib/systemd/user/ssh-agent.socket'. 51s Setting up openssh-sftp-server (1:10.0p1-5ubuntu2) ... 51s Setting up openssh-server (1:10.0p1-5ubuntu2) ... 51s Installing new version of config file /etc/ssh/moduli ... 51s Replacing config file /etc/ssh/sshd_config with new version 52s Created symlink '/etc/systemd/system/ssh.service.wants/sshd-keygen.service' → '/usr/lib/systemd/system/sshd-keygen.service'. 52s Created symlink '/etc/systemd/system/sshd.service.wants/sshd-keygen.service' → '/usr/lib/systemd/system/sshd-keygen.service'. 52s Created symlink '/etc/systemd/system/sshd@.service.wants/sshd-keygen.service' → '/usr/lib/systemd/system/sshd-keygen.service'. 52s Created symlink '/etc/systemd/system/ssh.socket.wants/sshd-keygen.service' → '/usr/lib/systemd/system/sshd-keygen.service'. 52s Processing triggers for man-db (2.13.1-1) ... 53s Processing triggers for ufw (0.36.2-9) ... 53s Reading package lists... 53s Building dependency tree... 53s Reading state information... 53s Solving dependencies... 53s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 54s autopkgtest [13:42:30]: rebooting testbed after setup commands that affected boot 74s autopkgtest [13:42:50]: testbed running kernel: Linux 6.15.0-4-generic #4-Ubuntu SMP Fri Jul 4 13:27:29 UTC 2025 76s autopkgtest [13:42:52]: @@@@@@@@@@@@@@@@@@@@ apt-source keychain 77s Get:1 http://ftpmaster.internal/ubuntu questing/universe keychain 2.8.5-5 (dsc) [2024 B] 77s Get:2 http://ftpmaster.internal/ubuntu questing/universe keychain 2.8.5-5 (tar) [66.4 kB] 77s Get:3 http://ftpmaster.internal/ubuntu questing/universe keychain 2.8.5-5 (diff) [9128 B] 78s gpgv: Signature made Tue Dec 31 09:51:29 2024 UTC 78s gpgv: using RSA key 2EE7A7A517FC124CF115C354651EEFB02527DF13 78s gpgv: issuer "roam@debian.org" 78s gpgv: Can't check signature: No public key 78s dpkg-source: warning: cannot verify inline signature for ./keychain_2.8.5-5.dsc: no acceptable signature found 78s autopkgtest [13:42:54]: testing package keychain version 2.8.5-5 78s autopkgtest [13:42:54]: build not needed 78s autopkgtest [13:42:54]: test ssh.sh: preparing testbed 78s Reading package lists... 79s Building dependency tree... 79s Reading state information... 79s Solving dependencies... 79s The following NEW packages will be installed: 79s keychain 79s 0 upgraded, 1 newly installed, 0 to remove and 0 not upgraded. 79s Need to get 37.0 kB of archives. 79s After this operation, 82.9 kB of additional disk space will be used. 79s Get:1 http://ftpmaster.internal/ubuntu questing/universe s390x keychain all 2.8.5-5 [37.0 kB] 79s Fetched 37.0 kB in 0s (183 kB/s) 79s Selecting previously unselected package keychain. 79s (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 ... 82586 files and directories currently installed.) 79s Preparing to unpack .../keychain_2.8.5-5_all.deb ... 79s Unpacking keychain (2.8.5-5) ... 79s Setting up keychain (2.8.5-5) ... 79s Processing triggers for man-db (2.13.1-1) ... 80s autopkgtest [13:42:56]: test ssh.sh: [----------------------- 81s + export LC_ALL=C 81s + id -un 81s + uid=ubuntu 81s + id 81s 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),107(cpacfstats) 81s Process list: 81s + 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),107(cpacfstats) 81s + echo Process list: 81s + ps uwwx 81s USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND 81s ubuntu 852 0.3 0.2 20352 12052 ? Ss 13:44 0:00 /usr/lib/systemd/systemd --user 81s ubuntu 853 0.0 0.0 20280 3896 ? S 13:44 0:00 (sd-pam) 81s ubuntu 885 0.0 0.1 16528 8068 ? S 13:44 0:00 sshd-session: ubuntu@notty 81s ubuntu 1353 0.0 0.0 2668 1656 ? Ss 13:44 0:00 /bin/sh /tmp/autopkgtest.UwmXjF/wrapper.sh --artifacts=/tmp/autopkgtest.UwmXjF/ssh.sh-artifacts --chdir=/tmp/autopkgtest.UwmXjF/build.3ui/src --env=AUTOPKGTEST_TESTBED_ARCH=s390x --env=AUTOPKGTEST_TEST_ARCH=s390x --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.UwmXjF/ssh.sh-stderr --stdout=/tmp/autopkgtest.UwmXjF/ssh.sh-stdout --tmp=/tmp/autopkgtest.UwmXjF/autopkgtest_tmp --env=ADT_TEST_TRIGGERS=openssh/1:10.0p1-5ubuntu2 --make-executable=/tmp/autopkgtest.UwmXjF/build.3ui/src/debian/tests/ssh.sh -- /tmp/autopkgtest.UwmXjF/build.3ui/src/debian/tests/ssh.sh 81s ubuntu 1378 0.0 0.0 5984 1636 ? S 13:44 0:00 tee -a -- /tmp/autopkgtest.UwmXjF/ssh.sh-stdout 81s ubuntu 1380 0.0 0.0 5984 1636 ? S 13:44 0:00 tee -a -- /tmp/autopkgtest.UwmXjF/ssh.sh-stderr 81s ubuntu 1382 0.0 0.0 2668 1528 ? S 13:44 0:00 /bin/sh /tmp/autopkgtest.UwmXjF/build.3ui/src/debian/tests/ssh.sh 81s ubuntu 1385 0.0 0.0 6048 3528 ? R 13:44 0:00 ps uwwx 81s No SSH agent variables in the environment, right? 81s + unset SSH_AUTH_SOCK 81s + unset SSH_AGENT_PID 81s + echo No SSH agent variables in the environment, right? 81s + printenv 81s + egrep -e ^SSH_ 81s + echoAnd ssh-add cannot see anything, either 81s And ssh-add cannot see anything, either 81s + ssh-add -l 81s Could not open a connection to your authentication agent. 81s + mktemp -d 81s Using our tempdir /tmp/tmp.XkTFC9J5l6 81s OK, let us start an SSH agent... 81s + tempd=/tmp/tmp.XkTFC9J5l6 81s + echo Using our tempdir /tmp/tmp.XkTFC9J5l6 81s + echo OK, let us start an SSH agent... 81s + ssh-agent -s 81s Output: 81s SSH_AUTH_SOCK=/tmp/ssh-tJKnYQl25toI/agent.1390; export SSH_AUTH_SOCK; 81s SSH_AGENT_PID=1391; export SSH_AGENT_PID; 81s echo Agent pid 1391; 81s + echo Output: 81s + cat -- /tmp/tmp.XkTFC9J5l6/ssh-agent.out 81s + echo Loading it:Loading it: 81s Agent pid 1391 81s Environment: 81s 81s + . /tmp/tmp.XkTFC9J5l6/ssh-agent.out 81s + SSH_AUTH_SOCK=/tmp/ssh-tJKnYQl25toI/agent.1390 81s + export SSH_AUTH_SOCK 81s + SSH_AGENT_PID=1391 81s + export SSH_AGENT_PID 81s + echo Agent pid 1391 81s + echo Environment: 81s + printenv 81s + egrep -e ^SSH_ 81s SSH_AGENT_PID=1391 81s SSH_AUTH_SOCK=/tmp/ssh-tJKnYQl25toI/agent.1390 81s + echo Query it - no identities expectedQuery it - no identities expected 81s 81s + res=0 81s + ssh-add -l 81s + res=1- standard output: 81s 81s + echo - standard output: 81s + cat -- /tmp/tmp.XkTFC9J5l6/ssh-add.out 81s The agent has no identities. 81s + - standard error: 81s - make sure it did not output the key 81s echo - standard error: 81s + cat -- /tmp/tmp.XkTFC9J5l6/ssh-add.err 81s + echo - make sure it did not output the key 81s + fgrep -e tanj@straylight -- /tmp/tmp.XkTFC9J5l6/ssh-add.out 81s + echo- make sure it failed 81s Now add a key 81s - make sure it failed 81s + [ 1 != 0 ] 81s + echo Now add a key 81s + install -m 600 -- debian/tests/data/id_tanj /tmp/tmp.XkTFC9J5l6/ 81s + install -m 644 -- debian/tests/data/id_tanj.pub /tmp/tmp.XkTFC9J5l6/ 81s + ssh-add -- /tmp/tmp.XkTFC9J5l6/id_tanj 81s But did it work? 81s Identity added: /tmp/tmp.XkTFC9J5l6/id_tanj (tanj@straylight) 81s + echo But did it work? 81s + res=0 81s + ssh-add -l 81s - standard output: 81s 2048 SHA256:Jj81+RS4yFX0l59QjgwtDwSgsItAynP6ioIjD4RA2kQ tanj@straylight (RSA) 81s + echo - standard output: 81s + cat -- /tmp/tmp.XkTFC9J5l6/ssh-add.out 81s + echo - standard error: 81s - standard error: 81s - make sure it succeeded 81s - make sure it output some info about the key 81s + cat -- /tmp/tmp.XkTFC9J5l6/ssh-add.err 81s + echo - make sure it succeeded 81s + [ 0 = 0 ] 81s + echo - make sure it output some info about the key 81s + fgrep -e tanj@straylight -- /tmp/tmp.XkTFC9J5l6/ssh-add.out 81s 2048 SHA256:Jj81+RS4yFX0l59QjgwtDwSgsItAynP6ioIjD4RA2kQ tanj@straylight (RSA) 81s + echo Let us stop the agent 81s Let us stop the agent 81s + ssh-agent -s -k 81s - output: 81s + echo - output: 81s + cat -- /tmp/tmp.XkTFC9J5l6/ssh-agent.out 81s unset SSH_AUTH_SOCK; 81s unset SSH_AGENT_PID; 81s echo Agent pid 1391 killed; 81s + echo - load it... 81s + . /tmp/tmp.XkTFC9J5l6/ssh-agent.out 81s + unset SSH_AUTH_SOCK 81s + unset SSH_AGENT_PID 81s + echo Agent pid 1391 killed 81s + echo - environment: 81s + printenv 81s + egrep -e ^SSH_ 81s - load it... 81s Agent pid 1391 killed 81s - environment: 81s + mktemp -d 81s Using keychain home directory /tmp/tmp.xCH8zfe7ej and our tempdir /tmp/tmp.XkTFC9J5l6 81s + kchome=/tmp/tmp.xCH8zfe7ej 81s + echo Using keychain home directory /tmp/tmp.xCH8zfe7ej and our tempdir /tmp/tmp.XkTFC9J5l6 81s + keychain -q --dir /tmp/tmp.xCH8zfe7ej --eval /tmp/tmp.XkTFC9J5l6/id_tanj 81s ssh-keygen: /tmp/tmp.XkTFC9J5l6/id_tanj.pub: Permission denied 81s * Warning: Unable to extract fingerprint from keyfile /tmp/tmp.XkTFC9J5l6/id_tanj.pub, skipping 81s + The output: 81s echo The output: 81s + cat -- /tmp/tmp.XkTFC9J5l6/1.out 81s SSH_AUTH_SOCK=/tmp/ssh-8FIjU39ZOOIF/agent.1431; export SSH_AUTH_SOCK; 81s SSH_AGENT_PID=1432; export SSH_AGENT_PID; 81s 81s Loading it... 81s + echo Loading it... 81s + cat -- /tmp/tmp.XkTFC9J5l6/1.out 81s Let us take a look at the environment now... 81s + eval SSH_AUTH_SOCK=/tmp/ssh-8FIjU39ZOOIF/agent.1431; export SSH_AUTH_SOCK; 81s SSH_AGENT_PID=1432; export SSH_AGENT_PID; 81s + SSH_AUTH_SOCK=/tmp/ssh-8FIjU39ZOOIF/agent.1431 81s + export SSH_AUTH_SOCK 81s + SSH_AGENT_PID=1432 81s + export SSH_AGENT_PID 81s + echo Let us take a look at the environment now... 81s + printenv 81s + egrep -e ^SSH_ 81s SSH_AGENT_PID=1432 81s SSH_AUTH_SOCK=/tmp/ssh-8FIjU39ZOOIF/agent.1431 81s + [ -z /tmp/ssh-8FIjU39ZOOIF/agent.1431 ] 81s + ssh-add -l 81s The agent has no identities. 81s autopkgtest [13:42:57]: test ssh.sh: -----------------------] 81s autopkgtest [13:42:57]: test ssh.sh: - - - - - - - - - - results - - - - - - - - - - 81s ssh.sh FAIL non-zero exit status 1 82s autopkgtest [13:42:58]: @@@@@@@@@@@@@@@@@@@@ summary 82s ssh.sh FAIL non-zero exit status 1