0s autopkgtest [21:22:58]: starting date and time: 2026-02-03 21:22:58+0000 0s autopkgtest [21:22:58]: git checkout: 4b346b80 nova: make wait_reboot return success even when a no-op 0s autopkgtest [21:22:58]: host juju-7f2275-prod-proposed-migration-environment-2; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.nvktji1e/out --timeout-copy=6000 --needs-internet=try --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:pam --apt-upgrade at --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=pam/1.7.0-5ubuntu3 -- 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-4.secgroup --name adt-resolute-arm64-at-20260203-212258-juju-7f2275-prod-proposed-migration-environment-2-40443b65-ffd7-48d0-ba44-89092b111a33 --image adt/ubuntu-resolute-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/ 4s Creating nova instance adt-resolute-arm64-at-20260203-212258-juju-7f2275-prod-proposed-migration-environment-2-40443b65-ffd7-48d0-ba44-89092b111a33 from image adt/ubuntu-resolute-arm64-server-20260203.img (UUID fd4bac28-a946-4216-8755-72db0faf84da)... 112s autopkgtest [21:24:50]: testbed dpkg architecture: arm64 112s autopkgtest [21:24:50]: testbed apt version: 3.1.14 112s autopkgtest [21:24:50]: @@@@@@@@@@@@@@@@@@@@ test bed setup 113s autopkgtest [21:24:51]: testbed release detected to be: None 113s autopkgtest [21:24:51]: updating testbed package index (apt update) 114s Get:1 http://ftpmaster.internal/ubuntu resolute-proposed InRelease [124 kB] 114s Hit:2 http://ftpmaster.internal/ubuntu resolute InRelease 114s Hit:3 http://ftpmaster.internal/ubuntu resolute-updates InRelease 114s Hit:4 http://ftpmaster.internal/ubuntu resolute-security InRelease 114s Get:5 http://ftpmaster.internal/ubuntu resolute-proposed/universe Sources [1343 kB] 114s Get:6 http://ftpmaster.internal/ubuntu resolute-proposed/restricted Sources [5260 B] 114s Get:7 http://ftpmaster.internal/ubuntu resolute-proposed/main Sources [242 kB] 114s Get:8 http://ftpmaster.internal/ubuntu resolute-proposed/multiverse Sources [27.9 kB] 114s Get:9 http://ftpmaster.internal/ubuntu resolute-proposed/main arm64 Packages [300 kB] 114s Get:10 http://ftpmaster.internal/ubuntu resolute-proposed/main arm64 c-n-f Metadata [6864 B] 114s Get:11 http://ftpmaster.internal/ubuntu resolute-proposed/restricted arm64 Packages [52.9 kB] 114s Get:12 http://ftpmaster.internal/ubuntu resolute-proposed/restricted arm64 c-n-f Metadata [328 B] 114s Get:13 http://ftpmaster.internal/ubuntu resolute-proposed/universe arm64 Packages [1188 kB] 114s Get:14 http://ftpmaster.internal/ubuntu resolute-proposed/universe arm64 c-n-f Metadata [27.8 kB] 114s Get:15 http://ftpmaster.internal/ubuntu resolute-proposed/multiverse arm64 Packages [21.5 kB] 115s Get:16 http://ftpmaster.internal/ubuntu resolute-proposed/multiverse arm64 c-n-f Metadata [744 B] 117s Fetched 3340 kB in 1s (3133 kB/s) 118s Reading package lists... 119s Hit:1 http://ftpmaster.internal/ubuntu resolute-proposed InRelease 119s Hit:2 http://ftpmaster.internal/ubuntu resolute InRelease 119s Hit:3 http://ftpmaster.internal/ubuntu resolute-updates InRelease 119s Hit:4 http://ftpmaster.internal/ubuntu resolute-security InRelease 120s Reading package lists... 120s Reading package lists... 120s Building dependency tree... 120s Reading state information... 120s Calculating upgrade... 120s The following packages will be upgraded: 120s firmware-sof-signed libpam-modules libpam-modules-bin libpam-runtime 120s libpam0g mtd-utils powermgmt-base 121s 7 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 121s Need to get 2622 kB of archives. 121s After this operation, 2048 B of additional disk space will be used. 121s Get:1 http://ftpmaster.internal/ubuntu resolute-proposed/main arm64 libpam-runtime all 1.7.0-5ubuntu3 [149 kB] 121s Get:2 http://ftpmaster.internal/ubuntu resolute-proposed/main arm64 libpam0g arm64 1.7.0-5ubuntu3 [69.5 kB] 121s Get:3 http://ftpmaster.internal/ubuntu resolute-proposed/main arm64 libpam-modules-bin arm64 1.7.0-5ubuntu3 [43.6 kB] 121s Get:4 http://ftpmaster.internal/ubuntu resolute-proposed/main arm64 libpam-modules arm64 1.7.0-5ubuntu3 [191 kB] 121s Get:5 http://ftpmaster.internal/ubuntu resolute/main arm64 firmware-sof-signed all 2025.05.1-1build1 [1696 kB] 121s Get:6 http://ftpmaster.internal/ubuntu resolute/main arm64 powermgmt-base all 1.38ubuntu2 [7878 B] 121s Get:7 http://ftpmaster.internal/ubuntu resolute/main arm64 mtd-utils arm64 1:2.3.0-1ubuntu2 [466 kB] 122s dpkg-preconfigure: unable to re-open stdin: No such file or directory 122s Fetched 2622 kB in 1s (3014 kB/s) 122s (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 ... 89360 files and directories currently installed.) 122s Preparing to unpack .../libpam-runtime_1.7.0-5ubuntu3_all.deb ... 122s Unpacking libpam-runtime (1.7.0-5ubuntu3) over (1.7.0-5ubuntu2) ... 122s Setting up libpam-runtime (1.7.0-5ubuntu3) ... 122s (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 ... 89360 files and directories currently installed.) 122s Preparing to unpack .../libpam0g_1.7.0-5ubuntu3_arm64.deb ... 122s Unpacking libpam0g:arm64 (1.7.0-5ubuntu3) over (1.7.0-5ubuntu2) ... 122s Setting up libpam0g:arm64 (1.7.0-5ubuntu3) ... 123s (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 ... 89360 files and directories currently installed.) 123s Preparing to unpack .../libpam-modules-bin_1.7.0-5ubuntu3_arm64.deb ... 123s Unpacking libpam-modules-bin (1.7.0-5ubuntu3) over (1.7.0-5ubuntu2) ... 123s Setting up libpam-modules-bin (1.7.0-5ubuntu3) ... 123s pam_namespace.service is a disabled or a static unit not running, not starting it. 123s (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 ... 89360 files and directories currently installed.) 123s Preparing to unpack .../libpam-modules_1.7.0-5ubuntu3_arm64.deb ... 123s Unpacking libpam-modules:arm64 (1.7.0-5ubuntu3) over (1.7.0-5ubuntu2) ... 123s Setting up libpam-modules:arm64 (1.7.0-5ubuntu3) ... 123s (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 ... 89360 files and directories currently installed.) 123s Preparing to unpack .../firmware-sof-signed_2025.05.1-1build1_all.deb ... 124s Unpacking firmware-sof-signed (2025.05.1-1build1) over (2025.05.1-1) ... 124s Preparing to unpack .../powermgmt-base_1.38ubuntu2_all.deb ... 124s Unpacking powermgmt-base (1.38ubuntu2) over (1.38ubuntu1) ... 124s Preparing to unpack .../mtd-utils_1%3a2.3.0-1ubuntu2_arm64.deb ... 124s Unpacking mtd-utils (1:2.3.0-1ubuntu2) over (1:2.3.0-1ubuntu1) ... 124s Setting up powermgmt-base (1.38ubuntu2) ... 124s Setting up firmware-sof-signed (2025.05.1-1build1) ... 124s Setting up mtd-utils (1:2.3.0-1ubuntu2) ... 124s Processing triggers for man-db (2.13.1-1) ... 125s Processing triggers for libc-bin (2.42-2ubuntu4) ... 125s autopkgtest [21:25:03]: upgrading testbed (apt dist-upgrade and autopurge) 125s Reading package lists... 126s Building dependency tree... 126s Reading state information... 126s Calculating upgrade... 126s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 127s Reading package lists... 127s Building dependency tree... 127s Reading state information... 127s Solving dependencies... 127s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 128s autopkgtest [21:25:06]: rebooting testbed after setup commands that affected boot 166s autopkgtest [21:25:44]: testbed running kernel: Linux 6.18.0-9-generic #9-Ubuntu SMP PREEMPT_DYNAMIC Mon Jan 12 16:41:39 UTC 2026 168s autopkgtest [21:25:46]: @@@@@@@@@@@@@@@@@@@@ apt-source at 170s Get:1 http://ftpmaster.internal/ubuntu resolute/universe at 3.2.5-2.2ubuntu1 (dsc) [2078 B] 170s Get:2 http://ftpmaster.internal/ubuntu resolute/universe at 3.2.5-2.2ubuntu1 (tar) [133 kB] 170s Get:3 http://ftpmaster.internal/ubuntu resolute/universe at 3.2.5-2.2ubuntu1 (diff) [22.2 kB] 170s gpgv: Signature made Tue Jun 3 20:24:40 2025 UTC 170s gpgv: using RSA key B8340990283D8D9BC1949AC74799A35146D12B35 170s gpgv: Can't check signature: No public key 170s dpkg-source: warning: cannot verify inline signature for ./at_3.2.5-2.2ubuntu1.dsc: no acceptable signature found 170s autopkgtest [21:25:48]: testing package at version 3.2.5-2.2ubuntu1 170s autopkgtest [21:25:48]: build not needed 170s autopkgtest [21:25:48]: test basic-usage: preparing testbed 171s Reading package lists... 171s Building dependency tree... 171s Reading state information... 171s Solving dependencies... 171s The following NEW packages will be installed: 171s at 171s 0 upgraded, 1 newly installed, 0 to remove and 0 not upgraded. 171s Need to get 39.7 kB of archives. 171s After this operation, 208 kB of additional disk space will be used. 171s Get:1 http://ftpmaster.internal/ubuntu resolute/universe arm64 at arm64 3.2.5-2.2ubuntu1 [39.7 kB] 172s Fetched 39.7 kB in 0s (667 kB/s) 172s Selecting previously unselected package at. 172s (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 ... 89360 files and directories currently installed.) 172s Preparing to unpack .../at_3.2.5-2.2ubuntu1_arm64.deb ... 172s Unpacking at (3.2.5-2.2ubuntu1) ... 172s Setting up at (3.2.5-2.2ubuntu1) ... 172s Created symlink '/etc/systemd/system/multi-user.target.wants/atd.service' → '/usr/lib/systemd/system/atd.service'. 172s Processing triggers for man-db (2.13.1-1) ... 175s autopkgtest [21:25:53]: test basic-usage: [----------------------- 175s + TMPFILE=at.32162 175s ++ mktemp -d 175s + WORKDIR=/tmp/tmp.mRvtyUnIrg 175s + trap 'rm -rf /tmp/tmp.mRvtyUnIrg' 0 INT QUIT ABRT PIPE TERM 175s ++ atq 175s ++ wc -l 175s + JOBS_BEFORE=0 175s + at now + 2 minutes 175s ++ date -u 175s warning: commands will be executed using /bin/sh 175s + echo 'echo Tue Feb 3 21:25:53 UTC 2026 > /tmp/tmp.mRvtyUnIrg/at.32162' 175s job 1 at Tue Feb 3 21:27:00 2026 175s + sleep 2 177s + test -f /tmp/tmp.mRvtyUnIrg/at.32162 177s + echo 'OK, /tmp/tmp.mRvtyUnIrg/at.32162 doesn'\''t exist yet; expected..' 177s OK, /tmp/tmp.mRvtyUnIrg/at.32162 doesn't exist yet; expected.. 177s ++ atq 177s ++ wc -l 177s + JOBS_AFTER=1 177s + [[ 1 -eq 1 ]] 177s + echo 'OK, 1 new queued job exists..' 177s OK, 1 new queued job exists.. 177s + sleep 120 297s OK, /tmp/tmp.mRvtyUnIrg/at.32162 exists and everything looks in order.. 297s OK; PASS. 297s + grep -Fq UTC /tmp/tmp.mRvtyUnIrg/at.32162 297s + echo 'OK, /tmp/tmp.mRvtyUnIrg/at.32162 exists and everything looks in order..' 297s + echo 'OK; PASS.' 297s + rm -rf /tmp/tmp.mRvtyUnIrg 297s autopkgtest [21:27:55]: test basic-usage: -----------------------] 298s autopkgtest [21:27:56]: test basic-usage: - - - - - - - - - - results - - - - - - - - - - 298s basic-usage PASS 298s autopkgtest [21:27:56]: @@@@@@@@@@@@@@@@@@@@ summary 298s basic-usage PASS