0s autopkgtest [03:39:41]: starting date and time: 2024-03-21 03:39:41+0000 1s autopkgtest [03:39:42]: git checkout: 4a1cd702 l/adt_testbed: don't blame the testbed for unsolvable build deps 1s autopkgtest [03:39:42]: host juju-7f2275-prod-proposed-migration-environment-2; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.b_2gaub_/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --setup-commands /home/ubuntu/autopkgtest/setup-commands/setup-testbed --apt-pocket=proposed=src:e2fsprogs,src:borgbackup,src:borgbackup2,src:fuse --apt-upgrade libpam-mount --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 '--env=ADT_TEST_TRIGGERS=e2fsprogs/1.47.0-2.4~exp1ubuntu2 borgbackup/1.2.7-2build2 borgbackup2/2.0.0b8-2build1 fuse/2.9.9-8.1' -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@bos02-s390x-15.secgroup --name adt-noble-s390x-libpam-mount-20240321-033941-juju-7f2275-prod-proposed-migration-environment-2 --image adt/ubuntu-noble-s390x-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-2 --net-id=net_prod-proposed-migration -e TERM=linux -e ''"'"'http_proxy=http://squid.internal:3128'"'"'' -e ''"'"'https_proxy=http://squid.internal:3128'"'"'' -e ''"'"'no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com'"'"'' --mirror=http://ftpmaster.internal/ubuntu/ 72s autopkgtest [03:40:53]: testbed dpkg architecture: s390x 72s autopkgtest [03:40:53]: testbed apt version: 2.7.12 72s autopkgtest [03:40:53]: @@@@@@@@@@@@@@@@@@@@ test bed setup 73s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [117 kB] 73s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [3809 kB] 74s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/multiverse Sources [53.9 kB] 74s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [6540 B] 74s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [498 kB] 74s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main s390x Packages [674 kB] 74s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main s390x c-n-f Metadata [3032 B] 74s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/restricted s390x Packages [1372 B] 74s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/restricted s390x c-n-f Metadata [116 B] 74s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/universe s390x Packages [4054 kB] 74s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/universe s390x c-n-f Metadata [7292 B] 74s Get:12 http://ftpmaster.internal/ubuntu noble-proposed/multiverse s390x Packages [45.1 kB] 74s Get:13 http://ftpmaster.internal/ubuntu noble-proposed/multiverse s390x c-n-f Metadata [116 B] 76s Fetched 9269 kB in 2s (3931 kB/s) 76s Reading package lists... 78s Reading package lists... 79s Building dependency tree... 79s Reading state information... 79s Calculating upgrade... 79s The following packages will be REMOVED: 79s libext2fs2 79s The following NEW packages will be installed: 79s libext2fs2t64 79s The following packages will be upgraded: 79s e2fsprogs e2fsprogs-l10n libcom-err2 libss2 logsave 79s 5 upgraded, 1 newly installed, 1 to remove and 0 not upgraded. 79s Need to get 918 kB of archives. 79s After this operation, 52.2 kB of additional disk space will be used. 79s Get:1 http://ftpmaster.internal/ubuntu noble-proposed/main s390x e2fsprogs-l10n all 1.47.0-2.4~exp1ubuntu2 [5996 B] 79s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/main s390x logsave s390x 1.47.0-2.4~exp1ubuntu2 [22.5 kB] 79s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/main s390x libext2fs2t64 s390x 1.47.0-2.4~exp1ubuntu2 [235 kB] 80s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/main s390x e2fsprogs s390x 1.47.0-2.4~exp1ubuntu2 [615 kB] 80s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/main s390x libcom-err2 s390x 1.47.0-2.4~exp1ubuntu2 [22.9 kB] 80s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main s390x libss2 s390x 1.47.0-2.4~exp1ubuntu2 [17.2 kB] 80s Fetched 918 kB in 1s (1198 kB/s) 80s (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 ... 52171 files and directories currently installed.) 80s Preparing to unpack .../e2fsprogs-l10n_1.47.0-2.4~exp1ubuntu2_all.deb ... 80s Unpacking e2fsprogs-l10n (1.47.0-2.4~exp1ubuntu2) over (1.47.0-2ubuntu1) ... 80s Preparing to unpack .../logsave_1.47.0-2.4~exp1ubuntu2_s390x.deb ... 80s Unpacking logsave (1.47.0-2.4~exp1ubuntu2) over (1.47.0-2ubuntu1) ... 80s dpkg: libext2fs2:s390x: dependency problems, but removing anyway as you requested: 80s libblockdev-fs3:s390x depends on libext2fs2 (>= 1.42.11). 80s e2fsprogs depends on libext2fs2 (= 1.47.0-2ubuntu1). 80s btrfs-progs depends on libext2fs2 (>= 1.42). 80s 80s (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 ... 52171 files and directories currently installed.) 80s Removing libext2fs2:s390x (1.47.0-2ubuntu1) ... 80s Selecting previously unselected package libext2fs2t64:s390x. 80s (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 ... 52164 files and directories currently installed.) 80s Preparing to unpack .../libext2fs2t64_1.47.0-2.4~exp1ubuntu2_s390x.deb ... 80s Adding 'diversion of /lib/s390x-linux-gnu/libe2p.so.2 to /lib/s390x-linux-gnu/libe2p.so.2.usr-is-merged by libext2fs2t64' 80s Adding 'diversion of /lib/s390x-linux-gnu/libe2p.so.2.3 to /lib/s390x-linux-gnu/libe2p.so.2.3.usr-is-merged by libext2fs2t64' 80s Adding 'diversion of /lib/s390x-linux-gnu/libext2fs.so.2 to /lib/s390x-linux-gnu/libext2fs.so.2.usr-is-merged by libext2fs2t64' 80s Adding 'diversion of /lib/s390x-linux-gnu/libext2fs.so.2.4 to /lib/s390x-linux-gnu/libext2fs.so.2.4.usr-is-merged by libext2fs2t64' 80s Unpacking libext2fs2t64:s390x (1.47.0-2.4~exp1ubuntu2) ... 80s Setting up libext2fs2t64:s390x (1.47.0-2.4~exp1ubuntu2) ... 80s (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 ... 52180 files and directories currently installed.) 80s Preparing to unpack .../e2fsprogs_1.47.0-2.4~exp1ubuntu2_s390x.deb ... 80s Unpacking e2fsprogs (1.47.0-2.4~exp1ubuntu2) over (1.47.0-2ubuntu1) ... 80s Preparing to unpack .../libcom-err2_1.47.0-2.4~exp1ubuntu2_s390x.deb ... 80s Unpacking libcom-err2:s390x (1.47.0-2.4~exp1ubuntu2) over (1.47.0-2ubuntu1) ... 80s Preparing to unpack .../libss2_1.47.0-2.4~exp1ubuntu2_s390x.deb ... 80s Unpacking libss2:s390x (1.47.0-2.4~exp1ubuntu2) over (1.47.0-2ubuntu1) ... 80s Setting up libcom-err2:s390x (1.47.0-2.4~exp1ubuntu2) ... 80s Setting up libss2:s390x (1.47.0-2.4~exp1ubuntu2) ... 80s Setting up logsave (1.47.0-2.4~exp1ubuntu2) ... 80s Setting up e2fsprogs (1.47.0-2.4~exp1ubuntu2) ... 80s update-initramfs: deferring update (trigger activated) 81s e2scrub_all.service is a disabled or a static unit not running, not starting it. 81s Setting up e2fsprogs-l10n (1.47.0-2.4~exp1ubuntu2) ... 81s Processing triggers for man-db (2.12.0-3) ... 82s Processing triggers for libc-bin (2.39-0ubuntu2) ... 82s Processing triggers for initramfs-tools (0.142ubuntu20) ... 82s update-initramfs: Generating /boot/initrd.img-6.8.0-11-generic 82s W: No lz4 in /usr/bin:/sbin:/bin, using gzip 85s Using config file '/etc/zipl.conf' 85s Building bootmap in '/boot' 85s Adding IPL section 'ubuntu' (default) 85s Preparing boot device for LD-IPL: vda (0000). 85s Done. 86s Reading package lists... 86s Building dependency tree... 86s Reading state information... 86s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 86s Unknown architecture, assuming PC-style ttyS0 86s sh: Attempting to set up Debian/Ubuntu apt sources automatically 86s sh: Distribution appears to be Ubuntu 87s Reading package lists... 87s Building dependency tree... 87s Reading state information... 87s eatmydata is already the newest version (131-1). 87s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 87s Reading package lists... 88s Building dependency tree... 88s Reading state information... 88s dbus is already the newest version (1.14.10-4ubuntu1). 88s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 88s Reading package lists... 88s Building dependency tree... 88s Reading state information... 88s rng-tools-debian is already the newest version (2.4). 88s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 88s Reading package lists... 88s Building dependency tree... 88s Reading state information... 88s The following packages will be REMOVED: 88s cloud-init* python3-configobj* python3-debconf* 89s 0 upgraded, 0 newly installed, 3 to remove and 0 not upgraded. 89s After this operation, 3252 kB disk space will be freed. 89s (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 ... 52180 files and directories currently installed.) 89s Removing cloud-init (24.1.1-0ubuntu1) ... 89s Removing python3-configobj (5.0.8-3) ... 89s Removing python3-debconf (1.5.86) ... 89s Processing triggers for man-db (2.12.0-3) ... 89s (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 ... 51791 files and directories currently installed.) 89s Purging configuration files for cloud-init (24.1.1-0ubuntu1) ... 90s dpkg: warning: while removing cloud-init, directory '/etc/cloud/cloud.cfg.d' not empty so not removed 90s Processing triggers for rsyslog (8.2312.0-3ubuntu3) ... 90s invoke-rc.d: policy-rc.d denied execution of try-restart. 90s Reading package lists... 90s Building dependency tree... 90s Reading state information... 90s linux-generic is already the newest version (6.8.0-11.11+1). 90s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 91s Hit:1 http://ftpmaster.internal/ubuntu noble InRelease 91s Hit:2 http://ftpmaster.internal/ubuntu noble-updates InRelease 91s Hit:3 http://ftpmaster.internal/ubuntu noble-security InRelease 93s Reading package lists... 93s Reading package lists... 93s Building dependency tree... 93s Reading state information... 93s Calculating upgrade... 93s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 93s Reading package lists... 93s Building dependency tree... 93s Reading state information... 93s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 94s autopkgtest [03:41:15]: rebooting testbed after setup commands that affected boot 107s autopkgtest [03:41:28]: testbed running kernel: Linux 6.8.0-11-generic #11-Ubuntu SMP Tue Feb 13 23:45:46 UTC 2024 109s autopkgtest [03:41:30]: @@@@@@@@@@@@@@@@@@@@ apt-source libpam-mount 112s Get:1 http://ftpmaster.internal/ubuntu noble/main libpam-mount 2.20-3 (dsc) [2196 B] 112s Get:2 http://ftpmaster.internal/ubuntu noble/main libpam-mount 2.20-3 (tar) [325 kB] 112s Get:3 http://ftpmaster.internal/ubuntu noble/main libpam-mount 2.20-3 (diff) [29.0 kB] 112s gpgv: Signature made Sun Dec 17 05:49:05 2023 UTC 112s gpgv: using RSA key 73B299CBD4EEADDCC017E87A5BFFDCC258E69433 112s gpgv: Can't check signature: No public key 112s dpkg-source: warning: cannot verify inline signature for ./libpam-mount_2.20-3.dsc: no acceptable signature found 112s autopkgtest [03:41:33]: testing package libpam-mount version 2.20-3 112s autopkgtest [03:41:33]: build not needed 113s autopkgtest [03:41:34]: test local-luks: preparing testbed 118s Reading package lists... 118s Building dependency tree... 118s Reading state information... 118s Starting pkgProblemResolver with broken count: 0 118s Starting 2 pkgProblemResolver with broken count: 0 118s Done 118s The following additional packages will be installed: 118s cryptsetup hxtools libhx32 libpam-mount libpam-mount-bin 118s Suggested packages: 118s keyutils cifs-utils davfs2 sshfs 118s Recommended packages: 118s cryptsetup-initramfs 118s The following NEW packages will be installed: 118s autopkgtest-satdep cryptsetup hxtools libhx32 libpam-mount libpam-mount-bin 118s 0 upgraded, 6 newly installed, 0 to remove and 0 not upgraded. 118s Need to get 447 kB/448 kB of archives. 118s After this operation, 1258 kB of additional disk space will be used. 118s Get:1 /tmp/autopkgtest.VvvTKy/1-autopkgtest-satdep.deb autopkgtest-satdep s390x 0 [764 B] 118s Get:2 http://ftpmaster.internal/ubuntu noble/main s390x cryptsetup s390x 2:2.7.0-1ubuntu1 [208 kB] 119s Get:3 http://ftpmaster.internal/ubuntu noble/main s390x libhx32 s390x 4.19-1 [47.0 kB] 119s Get:4 http://ftpmaster.internal/ubuntu noble/universe s390x hxtools s390x 20231224-2 [99.8 kB] 119s Get:5 http://ftpmaster.internal/ubuntu noble/main s390x libpam-mount s390x 2.20-3 [61.9 kB] 119s Get:6 http://ftpmaster.internal/ubuntu noble/main s390x libpam-mount-bin s390x 2.20-3 [30.2 kB] 119s Preconfiguring packages ... 119s Fetched 447 kB in 1s (804 kB/s) 119s Selecting previously unselected package cryptsetup. 119s (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 ... 51736 files and directories currently installed.) 119s Preparing to unpack .../0-cryptsetup_2%3a2.7.0-1ubuntu1_s390x.deb ... 119s Unpacking cryptsetup (2:2.7.0-1ubuntu1) ... 119s Selecting previously unselected package libhx32:s390x. 119s Preparing to unpack .../1-libhx32_4.19-1_s390x.deb ... 119s Unpacking libhx32:s390x (4.19-1) ... 119s Selecting previously unselected package hxtools. 119s Preparing to unpack .../2-hxtools_20231224-2_s390x.deb ... 119s Unpacking hxtools (20231224-2) ... 119s Selecting previously unselected package libpam-mount:s390x. 119s Preparing to unpack .../3-libpam-mount_2.20-3_s390x.deb ... 119s Unpacking libpam-mount:s390x (2.20-3) ... 119s Selecting previously unselected package libpam-mount-bin. 119s Preparing to unpack .../4-libpam-mount-bin_2.20-3_s390x.deb ... 119s Unpacking libpam-mount-bin (2.20-3) ... 119s Selecting previously unselected package autopkgtest-satdep. 119s Preparing to unpack .../5-1-autopkgtest-satdep.deb ... 119s Unpacking autopkgtest-satdep (0) ... 119s Setting up libhx32:s390x (4.19-1) ... 119s Setting up cryptsetup (2:2.7.0-1ubuntu1) ... 120s Setting up hxtools (20231224-2) ... 120s Setting up libpam-mount:s390x (2.20-3) ... 120s Setting up libpam-mount-bin (2.20-3) ... 120s Setting up autopkgtest-satdep (0) ... 120s Processing triggers for man-db (2.12.0-3) ... 121s Processing triggers for libc-bin (2.39-0ubuntu2) ... 123s (Reading database ... 51987 files and directories currently installed.) 123s Removing autopkgtest-satdep (0) ... 123s autopkgtest [03:41:44]: test local-luks: [----------------------- 123s + echo libpam-mount is working 123s + openssl passwd -1 alice 124s + useradd -m --password $1$er8ToYl7$J0p5ek6fTBVhYpCrZH0w30 alice 124s + printf alice 124s + ssh-keygen -t rsa -N -f test.key 126s Generating public/private rsa key pair. 126s Your identification has been saved in test.key 126s Your public key has been saved in test.key.pub 126s The key fingerprint is: 126s SHA256:P+h3X1XkCm7hTj6YfKHSRTFnce/R0LLbbQmwFIUIeLE root@autopkgtest 126s The key's randomart image is: 126s +---[RSA 3072]----+ 126s | .oo ..*.=oo| 126s | . ... + =.=+| 126s | .E . * +=| 126s | = +.oo| 126s | S B oo=| 126s | = X ...=| 126s | o O = ..| 126s | . ..o.. . | 126s | .. . .. | 126s +----[SHA256]-----+ 126s + mkdir -p /home/alice/.ssh 126s + chown alice:alice /home/alice/.ssh 126s + cp test.key.pub /home/alice/.ssh/authorized_keys 126s + mkdir -p /home/alice/img-luks1 /home/alice/img-luks2 126s + chown alice:alice /home/alice/.ssh/authorized_keys /home/alice/img-luks1 /home/alice/img-luks2 126s + createluks 1 luks 126s + id=1 126s + type=luks 126s + mktemp --directory 126s + tdir=/tmp/tmp.XckMw9nthW 126s + fallocate -l 32M /tmp/disk-l1.img 126s + cryptsetup luksFormat --batch-mode --verbose --force-password --key-file=/home/alice/alice.key --type luks /tmp/disk-l1.img 136s Key slot 0 created. 136s Command successful. 136s + cryptsetup open --type luks --batch-mode --verbose --key-file=/home/alice/alice.key /tmp/disk-l1.img img-luks1 139s No usable token is available. 139s Key slot 0 unlocked. 139s Command successful. 139s + mkfs.ext4 -L IMG-LUKS1 /dev/mapper/img-luks1 139s mke2fs 1.47.0 (5-Feb-2023) 139s Creating filesystem with 4096 4k blocks and 4096 inodes 139s 139s Allocating group tables: 0/1 done 139s Writing inode tables: 0/1 done 139s Creating journal (1024 blocks): done 139s Writing superblocks and filesystem accounting information: 0/1 done 139s 139s + mount /dev/mapper/img-luks1 /tmp/tmp.XckMw9nthW 139s + echo libpam-mount is working 139s + umount /dev/mapper/img-luks1 139s + cryptsetup close img-luks1 139s + createluks 2 luks2 139s + id=2 139s + type=luks2 139s + mktemp --directory 139s + tdir=/tmp/tmp.Plt69JJtPK 139s + fallocate -l 32M /tmp/disk-l2.img 139s + cryptsetup luksFormat --batch-mode --verbose --force-password --key-file=/home/alice/alice.key --type luks2 /tmp/disk-l2.img 147s Key slot 0 created. 147s Command successful. 147s + cryptsetup open --type luks2 --batch-mode --verbose --key-file=/home/alice/alice.key /tmp/disk-l2.img img-luks2 149s No usable token is available. 149s Key slot 0 unlocked. 149s Command successful. 149s + mkfs.ext4 -L IMG-LUKS2 /dev/mapper/img-luks2 149s Creating filesystem with 4096 4k blocks and 4096 inodes 149s 149s Allocating group tables: 0/1 mke2fs 1.47.0 (5-Feb-2023) 149s done 149s Writing inode tables: 0/1 done 149s Creating journal (1024 blocks): done 149s Writing superblocks and filesystem accounting information: 0/1 done 149s 149s + mount /dev/mapper/img-luks2 /tmp/tmp.Plt69JJtPK 149s + echo libpam-mount is working 149s + umount /dev/mapper/img-luks2 149s + cryptsetup close img-luks2 149s + checkluks 1 149s + id=1 149s + mktemp 149s + bckp=/tmp/tmp.dNr3iL7Why 149s + cp /etc/security/pam_mount.conf.xml /tmp/tmp.dNr3iL7Why 149s + sed -i -e s/debug enable="0"/debug enable="1"/ /etc/security/pam_mount.conf.xml 149s + sed -i -e //a /etc/security/pam_mount.conf.xml 149s + ssh -o StrictHostKeyChecking=no -i test.key alice@localhost ls -laF ~/img-luks1/testfile 150s Warning: Permanently added 'localhost' (ED25519) to the list of known hosts. 152s -rw-r--r-- 1 root root 24 Mar 21 03:42 /home/alice/img-luks1/testfile 152s + sleep 5s 157s + ssh -o StrictHostKeyChecking=no -i test.key alice@localhost mount 157s + grep img-luks1 159s /dev/mapper/_tmp_disk_l1_img on /home/alice/img-luks1 type ext4 (rw,relatime,helper=crypt) 159s + sleep 5s 164s + sed -i -e s/pam_mount.so\s*$/pam_mount.so disable_interactive/ /etc/pam.d/common-auth 164s + sed -i -e s/pam_mount.so\s*$/pam_mount.so disable_interactive/ /etc/pam.d/common-session 164s + su --login --command cat ~/img-luks1/testfile alice 164s (pam_mount.c:568): pam_mount 2.20: entering session stage 164s (mount.c:264): Mount info: globalconf, user=alice 164s (mount.c:678): Password will be sent to helper as-is. 164s command: 'mount' '-t' 'crypt' '-ofsk_cipher=none' '-ofsk_hash=md5' '-okeyfile=/home/alice/alice.key' '/tmp/disk-l1.img' '/home/alice/img-luks1' 167s (mount.c:567): 23 28 0:21 / /sys rw,nosuid,nodev,noexec,relatime shared:7 - sysfs sysfs rw 167s (mount.c:567): 24 28 0:22 / /proc rw,nosuid,nodev,noexec,relatime shared:11 - proc proc rw 167s (mount.c:567): 25 28 0:5 / /dev rw,nosuid,relatime shared:2 - devtmpfs udev rw,size=747236k,nr_inodes=186809,mode=755,inode64 167s (mount.c:567): 26 25 0:23 / /dev/pts rw,nosuid,noexec,relatime shared:3 - devpts devpts rw,gid=5,mode=620,ptmxmode=000 167s (mount.c:567): 27 28 0:24 / /run rw,nosuid,nodev,noexec,relatime shared:5 - tmpfs tmpfs rw,size=151640k,mode=755,inode64 167s (mount.c:567): 28 1 253:1 / / rw,relatime shared:1 - ext4 /dev/vda1 rw,discard,errors=remount-ro,commit=30 167s (mount.c:567): 29 23 0:6 / /sys/kernel/security rw,nosuid,nodev,noexec,relatime shared:8 - securityfs securityfs rw 167s (mount.c:567): 30 25 0:25 / /dev/shm rw,nosuid,nodev shared:4 - tmpfs tmpfs rw,inode64 167s (mount.c:567): 31 27 0:26 / /run/lock rw,nosuid,nodev,noexec,relatime shared:6 - tmpfs tmpfs rw,size=5120k,inode64 167s (mount.c:567): 32 23 0:27 / /sys/fs/cgroup rw,nosuid,nodev,noexec,relatime shared:9 - cgroup2 cgroup2 rw,nsdelegate,memory_recursiveprot 167s (mount.c:567): 33 23 0:28 / /sys/fs/bpf rw,nosuid,nodev,noexec,relatime shared:10 - bpf bpf rw,mode=700 167s (mount.c:567): 34 24 0:29 / /proc/sys/fs/binfmt_misc rw,relatime shared:12 - autofs systemd-1 rw,fd=31,pgrp=1,timeout=0,minproto=5,maxproto=5,direct,pipe_ino=1747 167s (mount.c:567): 35 25 0:30 / /dev/hugepages rw,nosuid,nodev,relatime shared:13 - hugetlbfs hugetlbfs rw,pagesize=1M 167s (mount.c:567): 36 25 0:19 / /dev/mqueue rw,nosuid,nodev,noexec,relatime shared:14 - mqueue mqueue rw 167s (mount.c:567): 37 23 0:7 / /sys/kernel/debug rw,nosuid,nodev,noexec,relatime shared:15 - debugfs debugfs rw 167s (mount.c:567): 38 23 0:12 / /sys/kernel/tracing rw,nosuid,nodev,noexec,relatime shared:16 - tracefs tracefs rw 167s (mount.c:567): 39 23 0:31 / /sys/fs/fuse/connections rw,nosuid,nodev,noexec,relatime shared:17 - fusectl fusectl rw 167s (mount.c:567): 59 23 0:20 / /sys/kernel/config rw,nosuid,nodev,noexec,relatime shared:18 - configfs configfs rw 167s (mount.c:567): 84 34 0:33 / /proc/sys/fs/binfmt_misc rw,nosuid,nodev,noexec,relatime shared:28 - binfmt_misc binfmt_misc rw 167s (mount.c:567): 45 27 0:43 / /run/user/1000 rw,nosuid,nodev,relatime shared:182 - tmpfs tmpfs rw,size=151636k,nr_inodes=37909,mode=700,uid=1000,gid=1000,inode64 167s (mount.c:567): 56 27 0:40 / /run/user/1001 rw,nosuid,nodev,relatime shared:184 - tmpfs tmpfs rw,size=151636k,nr_inodes=37909,mode=700,uid=1001,gid=1001,inode64 167s (mount.c:567): 44 28 252:0 / /home/alice/img-luks1 rw,relatime shared:151 - ext4 /dev/mapper/_tmp_disk_l1_img rw 167s command: 'pmvarrun' '-u' 'alice' '-o' '1' 167s (pmvarrun.c:261): parsed count value 0 167s (pam_mount.c:441): pmvarrun says login count is 1 167s (pam_mount.c:660): done opening session (ret=0) 167s (pam_mount.c:116): Clean global config (1073741824) 167s (pam_mount.c:706): received order to close things 167s command: 'pmvarrun' '-u' 'alice' '-o' '-1' 167s (pmvarrun.c:261): parsed count value 1 167s (pam_mount.c:441): pmvarrun says login count is 0 167s (mount.c:904): going to unmount 167s (mount.c:264): Mount info: globalconf, user=alice 167s command: 'ofl' '-k0' '/home/alice/img-luks1' 167s command: 'umount' '/home/alice/img-luks1' 167s (pam_mount.c:743): pam_mount execution complete 167s (pam_mount.c:116): Clean global config (0) 167s + sleep 5s 172s + cmp expected luks1 172s + ssh -o StrictHostKeyChecking=no -i test.key alice@localhost cat ~/img-luks1/testfile 174s + sleep 5s 179s + cmp expected luks1 179s + cp /tmp/tmp.dNr3iL7Why /etc/security/pam_mount.conf.xml 179s + checkluks 2 179s + id=2 179s + mktemp 179s + bckp=/tmp/tmp.8s5gTuI9Pg 179s + cp /etc/security/pam_mount.conf.xml /tmp/tmp.8s5gTuI9Pg 179s + sed -i -e s/debug enable="0"/debug enable="1"/ /etc/security/pam_mount.conf.xml 179s + sed -i -e //a /etc/security/pam_mount.conf.xml 179s + ssh -o StrictHostKeyChecking=no -i test.key alice@localhost ls -laF ~/img-luks2/testfile 182s -rw-r--r-- 1 root root 24 Mar 21 03:42 /home/alice/img-luks2/testfile 182s + sleep 5s 187s + + grep img-luks2 187s ssh -o StrictHostKeyChecking=no -i test.key alice@localhost mount 189s /dev/mapper/_tmp_disk_l2_img on /home/alice/img-luks2 type ext4 (rw,relatime,helper=crypt) 189s + sleep 5s 194s + sed -i -e s/pam_mount.so\s*$/pam_mount.so disable_interactive/ /etc/pam.d/common-auth 194s + sed -i -e s/pam_mount.so\s*$/pam_mount.so disable_interactive/ /etc/pam.d/common-session 194s + su --login --command cat ~/img-luks2/testfile alice 194s (pam_mount.c:568): pam_mount 2.20: entering session stage 194s (mount.c:264): Mount info: globalconf, user=alice 194s (mount.c:678): Password will be sent to helper as-is. 194s command: 'mount' '-t' 'crypt' '-ofsk_cipher=none' '-ofsk_hash=md5' '-okeyfile=/home/alice/alice.key' '/tmp/disk-l2.img' '/home/alice/img-luks2' 197s (mount.c:567): 23 28 0:21 / /sys rw,nosuid,nodev,noexec,relatime shared:7 - sysfs sysfs rw 197s (mount.c:567): 24 28 0:22 / /proc rw,nosuid,nodev,noexec,relatime shared:11 - proc proc rw 197s (mount.c:567): 25 28 0:5 / /dev rw,nosuid,relatime shared:2 - devtmpfs udev rw,size=747236k,nr_inodes=186809,mode=755,inode64 197s (mount.c:567): 26 25 0:23 / /dev/pts rw,nosuid,noexec,relatime shared:3 - devpts devpts rw,gid=5,mode=620,ptmxmode=000 197s (mount.c:567): 27 28 0:24 / /run rw,nosuid,nodev,noexec,relatime shared:5 - tmpfs tmpfs rw,size=151640k,mode=755,inode64 197s (mount.c:567): 28 1 253:1 / / rw,relatime shared:1 - ext4 /dev/vda1 rw,discard,errors=remount-ro,commit=30 197s (mount.c:567): 29 23 0:6 / /sys/kernel/security rw,nosuid,nodev,noexec,relatime shared:8 - securityfs securityfs rw 197s (mount.c:567): 30 25 0:25 / /dev/shm rw,nosuid,nodev shared:4 - tmpfs tmpfs rw,inode64 197s (mount.c:567): 31 27 0:26 / /run/lock rw,nosuid,nodev,noexec,relatime shared:6 - tmpfs tmpfs rw,size=5120k,inode64 197s (mount.c:567): 32 23 0:27 / /sys/fs/cgroup rw,nosuid,nodev,noexec,relatime shared:9 - cgroup2 cgroup2 rw,nsdelegate,memory_recursiveprot 197s (mount.c:567): 33 23 0:28 / /sys/fs/bpf rw,nosuid,nodev,noexec,relatime shared:10 - bpf bpf rw,mode=700 197s (mount.c:567): 34 24 0:29 / /proc/sys/fs/binfmt_misc rw,relatime shared:12 - autofs systemd-1 rw,fd=31,pgrp=1,timeout=0,minproto=5,maxproto=5,direct,pipe_ino=1747 197s (mount.c:567): 35 25 0:30 / /dev/hugepages rw,nosuid,nodev,relatime shared:13 - hugetlbfs hugetlbfs rw,pagesize=1M 197s (mount.c:567): 36 25 0:19 / /dev/mqueue rw,nosuid,nodev,noexec,relatime shared:14 - mqueue mqueue rw 197s (mount.c:567): 37 23 0:7 / /sys/kernel/debug rw,nosuid,nodev,noexec,relatime shared:15 - debugfs debugfs rw 197s (mount.c:567): 38 23 0:12 / /sys/kernel/tracing rw,nosuid,nodev,noexec,relatime shared:16 - tracefs tracefs rw 197s (mount.c:567): 39 23 0:31 / /sys/fs/fuse/connections rw,nosuid,nodev,noexec,relatime shared:17 - fusectl fusectl rw 197s (mount.c:567): 59 23 0:20 / /sys/kernel/config rw,nosuid,nodev,noexec,relatime shared:18 - configfs configfs rw 197s (mount.c:567): 84 34 0:33 / /proc/sys/fs/binfmt_misc rw,nosuid,nodev,noexec,relatime shared:28 - binfmt_misc binfmt_misc rw 197s (mount.c:567): 45 27 0:43 / /run/user/1000 rw,nosuid,nodev,relatime shared:182 - tmpfs tmpfs rw,size=151636k,nr_inodes=37909,mode=700,uid=1000,gid=1000,inode64 197s (mount.c:567): 56 27 0:40 / /run/user/1001 rw,nosuid,nodev,relatime shared:184 - tmpfs tmpfs rw,size=151636k,nr_inodes=37909,mode=700,uid=1001,gid=1001,inode64 197s (mount.c:567): 44 28 252:0 / /home/alice/img-luks2 rw,relatime shared:151 - ext4 /dev/mapper/_tmp_disk_l2_img rw 197s command: 'pmvarrun' '-u' 'alice' '-o' '1' 197s (pmvarrun.c:261): parsed count value 0 197s (pam_mount.c:441): pmvarrun says login count is 1 197s (pam_mount.c:660): done opening session (ret=0) 197s (pam_mount.c:116): Clean global config (1073741824) 197s (pam_mount.c:706): received order to close things 197s command: 'pmvarrun' '-u' 'alice' '-o' '-1' 197s (pmvarrun.c:261): parsed count value 1 197s (pam_mount.c:441): pmvarrun says login count is 0 197s (mount.c:904): going to unmount 197s (mount.c:264): Mount info: globalconf, user=alice 197s command: 'ofl' '-k0' '/home/alice/img-luks2' 197s command: 'umount' '/home/alice/img-luks2' 197s (pam_mount.c:743): pam_mount execution complete 197s (pam_mount.c:116): Clean global config (0) 197s + sleep 5s 202s + cmp expected luks2 202s + ssh -o StrictHostKeyChecking=no -i test.key alice@localhost cat ~/img-luks2/testfile 205s + sleep 5s 210s + cmp expected luks2 210s + cp /tmp/tmp.8s5gTuI9Pg /etc/security/pam_mount.conf.xml 210s autopkgtest [03:43:11]: test local-luks: -----------------------] 211s autopkgtest [03:43:12]: test local-luks: - - - - - - - - - - results - - - - - - - - - - 211s local-luks PASS 211s autopkgtest [03:43:12]: @@@@@@@@@@@@@@@@@@@@ summary 211s local-luks PASS 216s Creating nova instance adt-noble-s390x-libpam-mount-20240321-033941-juju-7f2275-prod-proposed-migration-environment-2 from image adt/ubuntu-noble-s390x-server-20240320.img (UUID 6569a0ff-4984-4a4c-a4d0-b93f21cb5de9)...