0s autopkgtest [11:55:55]: starting date and time: 2024-07-22 11:55:55+0000 0s autopkgtest [11:55:55]: git checkout: fd3bed09 nova: allow more retries for quota issues 0s autopkgtest [11:55:55]: host juju-7f2275-prod-proposed-migration-environment-3; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.36f_oyau/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:lvm2,src:multipath-tools --apt-upgrade multipath-tools --timeout-short=300 --timeout-copy=20000 --timeout-test=20000 --timeout-build=20000 '--env=ADT_TEST_TRIGGERS=lvm2/2.03.22-1ubuntu1 multipath-tools/0.9.9-1ubuntu1' -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest-big --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-3@bos02-ppc64el-12.secgroup --name adt-oracular-ppc64el-multipath-tools-20240722-115554-juju-7f2275-prod-proposed-migration-environment-3-de8da9b0-2251-4da4-a027-40435a09e0b5 --image adt/ubuntu-oracular-ppc64el-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-3 --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,keyserver.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/ 93s autopkgtest [11:57:28]: testbed dpkg architecture: ppc64el 93s autopkgtest [11:57:28]: testbed apt version: 2.9.6 93s autopkgtest [11:57:28]: @@@@@@@@@@@@@@@@@@@@ test bed setup 94s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [126 kB] 95s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [58.8 kB] 95s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [8548 B] 95s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [4220 B] 95s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [398 kB] 95s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el Packages [99.4 kB] 95s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el c-n-f Metadata [2116 B] 95s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el Packages [1368 B] 95s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el c-n-f Metadata [120 B] 95s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el Packages [468 kB] 95s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el c-n-f Metadata [8952 B] 95s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el Packages [2072 B] 95s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el c-n-f Metadata [120 B] 98s Fetched 1178 kB in 1s (1406 kB/s) 98s Reading package lists... 100s Reading package lists... 100s Building dependency tree... 100s Reading state information... 100s Calculating upgrade... 100s The following packages will be upgraded: 100s dmsetup gcc-14-base kpartx libdevmapper1.02.1 libgcc-s1 libstdc++6 100s multipath-tools 101s 7 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 101s Need to get 1637 kB of archives. 101s After this operation, 97.3 kB of additional disk space will be used. 101s Get:1 http://ftpmaster.internal/ubuntu oracular/main ppc64el gcc-14-base ppc64el 14.1.0-5ubuntu1 [49.9 kB] 101s Get:2 http://ftpmaster.internal/ubuntu oracular/main ppc64el libstdc++6 ppc64el 14.1.0-5ubuntu1 [886 kB] 101s Get:3 http://ftpmaster.internal/ubuntu oracular/main ppc64el libgcc-s1 ppc64el 14.1.0-5ubuntu1 [39.1 kB] 101s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el libdevmapper1.02.1 ppc64el 2:1.02.196-1ubuntu1 [181 kB] 101s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el dmsetup ppc64el 2:1.02.196-1ubuntu1 [91.6 kB] 101s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el kpartx ppc64el 0.9.9-1ubuntu1 [37.1 kB] 101s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el multipath-tools ppc64el 0.9.9-1ubuntu1 [352 kB] 101s Fetched 1637 kB in 1s (2502 kB/s) 102s (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 ... 72787 files and directories currently installed.) 102s Preparing to unpack .../gcc-14-base_14.1.0-5ubuntu1_ppc64el.deb ... 102s Unpacking gcc-14-base:ppc64el (14.1.0-5ubuntu1) over (14.1.0-4ubuntu2) ... 102s Setting up gcc-14-base:ppc64el (14.1.0-5ubuntu1) ... 102s (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 ... 72787 files and directories currently installed.) 102s Preparing to unpack .../libstdc++6_14.1.0-5ubuntu1_ppc64el.deb ... 102s Unpacking libstdc++6:ppc64el (14.1.0-5ubuntu1) over (14.1.0-4ubuntu2) ... 102s Setting up libstdc++6:ppc64el (14.1.0-5ubuntu1) ... 102s (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 ... 72787 files and directories currently installed.) 102s Preparing to unpack .../libgcc-s1_14.1.0-5ubuntu1_ppc64el.deb ... 102s Unpacking libgcc-s1:ppc64el (14.1.0-5ubuntu1) over (14.1.0-4ubuntu2) ... 102s Setting up libgcc-s1:ppc64el (14.1.0-5ubuntu1) ... 102s (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 ... 72787 files and directories currently installed.) 102s Preparing to unpack .../libdevmapper1.02.1_2%3a1.02.196-1ubuntu1_ppc64el.deb ... 102s Unpacking libdevmapper1.02.1:ppc64el (2:1.02.196-1ubuntu1) over (2:1.02.185-3ubuntu4) ... 102s Preparing to unpack .../dmsetup_2%3a1.02.196-1ubuntu1_ppc64el.deb ... 102s Unpacking dmsetup (2:1.02.196-1ubuntu1) over (2:1.02.185-3ubuntu4) ... 102s Preparing to unpack .../kpartx_0.9.9-1ubuntu1_ppc64el.deb ... 102s Unpacking kpartx (0.9.9-1ubuntu1) over (0.9.4-5ubuntu8) ... 102s Preparing to unpack .../multipath-tools_0.9.9-1ubuntu1_ppc64el.deb ... 102s Unpacking multipath-tools (0.9.9-1ubuntu1) over (0.9.4-5ubuntu8) ... 102s dpkg: warning: unable to delete old directory '/lib/multipath': Directory not empty 102s Setting up libdevmapper1.02.1:ppc64el (2:1.02.196-1ubuntu1) ... 102s Setting up dmsetup (2:1.02.196-1ubuntu1) ... 102s Setting up kpartx (0.9.9-1ubuntu1) ... 102s Setting up multipath-tools (0.9.9-1ubuntu1) ... 103s Processing triggers for libc-bin (2.39-0ubuntu9) ... 103s Processing triggers for man-db (2.12.1-2) ... 104s Processing triggers for initramfs-tools (0.142ubuntu30) ... 104s update-initramfs: Generating /boot/initrd.img-6.8.0-31-generic 104s W: No lz4 in /usr/bin:/sbin:/bin, using gzip 113s Reading package lists... 113s Building dependency tree... 113s Reading state information... 113s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 114s Hit:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease 114s Hit:2 http://ftpmaster.internal/ubuntu oracular InRelease 114s Hit:3 http://ftpmaster.internal/ubuntu oracular-updates InRelease 114s Hit:4 http://ftpmaster.internal/ubuntu oracular-security InRelease 115s Reading package lists... 115s Reading package lists... 115s Building dependency tree... 115s Reading state information... 115s Calculating upgrade... 115s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 115s Reading package lists... 115s Building dependency tree... 115s Reading state information... 116s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 116s autopkgtest [11:57:51]: rebooting testbed after setup commands that affected boot 120s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 153s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 165s autopkgtest [11:58:40]: testbed running kernel: Linux 6.8.0-31-generic #31-Ubuntu SMP Sat Apr 20 00:05:55 UTC 2024 168s autopkgtest [11:58:43]: @@@@@@@@@@@@@@@@@@@@ apt-source multipath-tools 171s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed/main multipath-tools 0.9.9-1ubuntu1 (dsc) [2772 B] 171s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/main multipath-tools 0.9.9-1ubuntu1 (tar) [588 kB] 171s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/main multipath-tools 0.9.9-1ubuntu1 (diff) [42.6 kB] 172s gpgv: Signature made Fri Jul 19 16:08:28 2024 UTC 172s gpgv: using RSA key 92978A6E195E4921825F7FF0F34F09744E9F5DD9 172s gpgv: Can't check signature: No public key 172s dpkg-source: warning: cannot verify inline signature for ./multipath-tools_0.9.9-1ubuntu1.dsc: no acceptable signature found 172s autopkgtest [11:58:47]: testing package multipath-tools version 0.9.9-1ubuntu1 172s autopkgtest [11:58:47]: build not needed 172s initramfs SKIP Test lists explicitly supported architectures, but the current architecture ppc64el isn't listed. 173s initramfs SKIP Test lists explicitly supported architectures, but the current architecture ppc64el isn't listed. 173s autopkgtest [11:58:48]: test kpartx-file-loopback: preparing testbed 174s Reading package lists... 174s Building dependency tree... 174s Reading state information... 174s Starting pkgProblemResolver with broken count: 0 174s Starting 2 pkgProblemResolver with broken count: 0 174s Done 175s The following additional packages will be installed: 175s liburing2 qemu-utils 175s Recommended packages: 175s qemu-block-extra 175s The following NEW packages will be installed: 175s autopkgtest-satdep liburing2 qemu-utils 175s 0 upgraded, 3 newly installed, 0 to remove and 0 not upgraded. 175s Need to get 2330 kB/2331 kB of archives. 175s After this operation, 15.4 MB of additional disk space will be used. 175s Get:1 /tmp/autopkgtest.HPnGkO/1-autopkgtest-satdep.deb autopkgtest-satdep ppc64el 0 [720 B] 175s Get:2 http://ftpmaster.internal/ubuntu oracular/main ppc64el liburing2 ppc64el 2.6-1 [26.9 kB] 175s Get:3 http://ftpmaster.internal/ubuntu oracular/main ppc64el qemu-utils ppc64el 1:8.2.2+ds-0ubuntu1 [2303 kB] 176s Fetched 2330 kB in 1s (3272 kB/s) 176s Selecting previously unselected package liburing2:ppc64el. 176s (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 ... 72787 files and directories currently installed.) 176s Preparing to unpack .../liburing2_2.6-1_ppc64el.deb ... 176s Unpacking liburing2:ppc64el (2.6-1) ... 176s Selecting previously unselected package qemu-utils. 176s Preparing to unpack .../qemu-utils_1%3a8.2.2+ds-0ubuntu1_ppc64el.deb ... 176s Unpacking qemu-utils (1:8.2.2+ds-0ubuntu1) ... 176s Selecting previously unselected package autopkgtest-satdep. 176s Preparing to unpack .../1-autopkgtest-satdep.deb ... 176s Unpacking autopkgtest-satdep (0) ... 176s Setting up liburing2:ppc64el (2.6-1) ... 176s Setting up qemu-utils (1:8.2.2+ds-0ubuntu1) ... 176s Setting up autopkgtest-satdep (0) ... 176s Processing triggers for man-db (2.12.1-2) ... 178s Processing triggers for libc-bin (2.39-0ubuntu9) ... 180s (Reading database ... 72807 files and directories currently installed.) 180s Removing autopkgtest-satdep (0) ... 181s autopkgtest [11:58:56]: test kpartx-file-loopback: [----------------------- 181s Formatting 'foo.img', fmt=raw size=20971520 182s Creating new GPT entries in memory. 182s Warning: The kernel is still using the old partition table. 182s The new table will be used at the next reboot or after you 182s run partprobe(8) or kpartx(8) 182s The operation has completed successfully. 182s add map loop0p1 (252:0): 0 38879 linear 7:0 2048 182s standard_filename: OK 182s del devmap : loop0p1 182s No devices found 182s standard_filename_cleanup: OK 182s Formatting 'fou du FaFa.img', fmt=raw size=20971520 183s Creating new GPT entries in memory. 183s Warning: The kernel is still using the old partition table. 183s The new table will be used at the next reboot or after you 183s run partprobe(8) or kpartx(8) 183s The operation has completed successfully. 183s add map loop0p1 (252:0): 0 38879 linear 7:0 2048 183s filename_with_spaces: OK 183s del devmap : loop0p1 183s No devices found 183s filename_with_spaces_cleanup: OK 184s autopkgtest [11:58:59]: test kpartx-file-loopback: -----------------------] 184s kpartx-file-loopback PASS 184s autopkgtest [11:58:59]: test kpartx-file-loopback: - - - - - - - - - - results - - - - - - - - - - 185s autopkgtest [11:59:00]: test tgtbasedmpaths: preparing testbed 290s autopkgtest [12:00:45]: testbed dpkg architecture: ppc64el 290s autopkgtest [12:00:45]: testbed apt version: 2.9.6 290s autopkgtest [12:00:45]: @@@@@@@@@@@@@@@@@@@@ test bed setup 291s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [126 kB] 291s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [8548 B] 291s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [58.8 kB] 291s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [4220 B] 291s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [398 kB] 291s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el Packages [99.4 kB] 291s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el c-n-f Metadata [2116 B] 291s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el Packages [1368 B] 291s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el c-n-f Metadata [120 B] 291s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el Packages [468 kB] 291s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el c-n-f Metadata [8952 B] 291s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el Packages [2072 B] 291s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el c-n-f Metadata [120 B] 294s Fetched 1178 kB in 1s (1306 kB/s) 294s Reading package lists... 296s Reading package lists... 296s Building dependency tree... 296s Reading state information... 297s Calculating upgrade... 297s The following packages will be upgraded: 297s dmsetup gcc-14-base kpartx libdevmapper1.02.1 libgcc-s1 libstdc++6 297s multipath-tools 297s 7 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 297s Need to get 1637 kB of archives. 297s After this operation, 97.3 kB of additional disk space will be used. 297s Get:1 http://ftpmaster.internal/ubuntu oracular/main ppc64el gcc-14-base ppc64el 14.1.0-5ubuntu1 [49.9 kB] 297s Get:2 http://ftpmaster.internal/ubuntu oracular/main ppc64el libstdc++6 ppc64el 14.1.0-5ubuntu1 [886 kB] 297s Get:3 http://ftpmaster.internal/ubuntu oracular/main ppc64el libgcc-s1 ppc64el 14.1.0-5ubuntu1 [39.1 kB] 297s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el libdevmapper1.02.1 ppc64el 2:1.02.196-1ubuntu1 [181 kB] 297s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el dmsetup ppc64el 2:1.02.196-1ubuntu1 [91.6 kB] 297s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el kpartx ppc64el 0.9.9-1ubuntu1 [37.1 kB] 297s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el multipath-tools ppc64el 0.9.9-1ubuntu1 [352 kB] 298s Fetched 1637 kB in 1s (2538 kB/s) 298s (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 ... 72787 files and directories currently installed.) 298s Preparing to unpack .../gcc-14-base_14.1.0-5ubuntu1_ppc64el.deb ... 298s Unpacking gcc-14-base:ppc64el (14.1.0-5ubuntu1) over (14.1.0-4ubuntu2) ... 298s Setting up gcc-14-base:ppc64el (14.1.0-5ubuntu1) ... 298s (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 ... 72787 files and directories currently installed.) 298s Preparing to unpack .../libstdc++6_14.1.0-5ubuntu1_ppc64el.deb ... 298s Unpacking libstdc++6:ppc64el (14.1.0-5ubuntu1) over (14.1.0-4ubuntu2) ... 298s Setting up libstdc++6:ppc64el (14.1.0-5ubuntu1) ... 298s (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 ... 72787 files and directories currently installed.) 298s Preparing to unpack .../libgcc-s1_14.1.0-5ubuntu1_ppc64el.deb ... 298s Unpacking libgcc-s1:ppc64el (14.1.0-5ubuntu1) over (14.1.0-4ubuntu2) ... 298s Setting up libgcc-s1:ppc64el (14.1.0-5ubuntu1) ... 298s (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 ... 72787 files and directories currently installed.) 298s Preparing to unpack .../libdevmapper1.02.1_2%3a1.02.196-1ubuntu1_ppc64el.deb ... 298s Unpacking libdevmapper1.02.1:ppc64el (2:1.02.196-1ubuntu1) over (2:1.02.185-3ubuntu4) ... 298s Preparing to unpack .../dmsetup_2%3a1.02.196-1ubuntu1_ppc64el.deb ... 298s Unpacking dmsetup (2:1.02.196-1ubuntu1) over (2:1.02.185-3ubuntu4) ... 299s Preparing to unpack .../kpartx_0.9.9-1ubuntu1_ppc64el.deb ... 299s Unpacking kpartx (0.9.9-1ubuntu1) over (0.9.4-5ubuntu8) ... 299s Preparing to unpack .../multipath-tools_0.9.9-1ubuntu1_ppc64el.deb ... 299s Unpacking multipath-tools (0.9.9-1ubuntu1) over (0.9.4-5ubuntu8) ... 299s dpkg: warning: unable to delete old directory '/lib/multipath': Directory not empty 299s Setting up libdevmapper1.02.1:ppc64el (2:1.02.196-1ubuntu1) ... 299s Setting up dmsetup (2:1.02.196-1ubuntu1) ... 299s Setting up kpartx (0.9.9-1ubuntu1) ... 299s Setting up multipath-tools (0.9.9-1ubuntu1) ... 299s Processing triggers for libc-bin (2.39-0ubuntu9) ... 299s Processing triggers for man-db (2.12.1-2) ... 301s Processing triggers for initramfs-tools (0.142ubuntu30) ... 301s update-initramfs: Generating /boot/initrd.img-6.8.0-31-generic 301s W: No lz4 in /usr/bin:/sbin:/bin, using gzip 309s Reading package lists... 309s Building dependency tree... 309s Reading state information... 309s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 309s Hit:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease 309s Hit:2 http://ftpmaster.internal/ubuntu oracular InRelease 309s Hit:3 http://ftpmaster.internal/ubuntu oracular-updates InRelease 310s Hit:4 http://ftpmaster.internal/ubuntu oracular-security InRelease 310s Reading package lists... 311s Reading package lists... 311s Building dependency tree... 311s Reading state information... 311s Calculating upgrade... 311s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 311s Reading package lists... 311s Building dependency tree... 311s Reading state information... 311s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 312s autopkgtest [12:01:07]: rebooting testbed after setup commands that affected boot 345s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 363s Reading package lists... 364s Building dependency tree... 364s Reading state information... 364s Starting pkgProblemResolver with broken count: 0 364s Starting 2 pkgProblemResolver with broken count: 0 364s Done 364s The following additional packages will be installed: 364s fio libboost-iostreams1.83.0 libboost-thread1.83.0 libconfig-general-perl 364s libdaxctl1 libgfapi0 libgfrpc0 libgfxdr0 libglusterfs0 libisns0t64 libnbd0 364s libndctl6 libopeniscsiusr libpmem1 libpmemobj1 librados2 librbd1 364s librdmacm1t64 lsscsi open-iscsi tgt 364s Suggested packages: 364s fio-examples gnuplot tgt-glusterfs tgt-rbd 364s Recommended packages: 364s finalrd 364s The following NEW packages will be installed: 364s autopkgtest-satdep fio libboost-iostreams1.83.0 libboost-thread1.83.0 364s libconfig-general-perl libdaxctl1 libgfapi0 libgfrpc0 libgfxdr0 364s libglusterfs0 libisns0t64 libnbd0 libndctl6 libopeniscsiusr libpmem1 364s libpmemobj1 librados2 librbd1 librdmacm1t64 lsscsi open-iscsi tgt 364s 0 upgraded, 22 newly installed, 0 to remove and 0 not upgraded. 364s Need to get 10.7 MB/10.7 MB of archives. 364s After this operation, 49.0 MB of additional disk space will be used. 364s Get:1 /tmp/autopkgtest.HPnGkO/2-autopkgtest-satdep.deb autopkgtest-satdep ppc64el 0 [736 B] 364s Get:2 http://ftpmaster.internal/ubuntu oracular/main ppc64el libopeniscsiusr ppc64el 2.1.10-1ubuntu1 [54.9 kB] 365s Get:3 http://ftpmaster.internal/ubuntu oracular/main ppc64el libisns0t64 ppc64el 0.101-1 [117 kB] 365s Get:4 http://ftpmaster.internal/ubuntu oracular/main ppc64el open-iscsi ppc64el 2.1.10-1ubuntu1 [385 kB] 365s Get:5 http://ftpmaster.internal/ubuntu oracular/main ppc64el librdmacm1t64 ppc64el 52.0-2 [80.5 kB] 365s Get:6 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libconfig-general-perl all 2.65-2 [57.1 kB] 365s Get:7 http://ftpmaster.internal/ubuntu oracular/universe ppc64el tgt ppc64el 1:1.0.85-1.2ubuntu1 [254 kB] 365s Get:8 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libgfxdr0 ppc64el 11.1-4ubuntu1 [21.5 kB] 365s Get:9 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libglusterfs0 ppc64el 11.1-4ubuntu1 [311 kB] 365s Get:10 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libgfrpc0 ppc64el 11.1-4ubuntu1 [46.5 kB] 365s Get:11 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libgfapi0 ppc64el 11.1-4ubuntu1 [99.2 kB] 365s Get:12 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libnbd0 ppc64el 1.20.2-1 [97.4 kB] 365s Get:13 http://ftpmaster.internal/ubuntu oracular/main ppc64el libdaxctl1 ppc64el 77-2ubuntu2 [23.7 kB] 365s Get:14 http://ftpmaster.internal/ubuntu oracular/main ppc64el libndctl6 ppc64el 77-2ubuntu2 [74.9 kB] 365s Get:15 http://ftpmaster.internal/ubuntu oracular/main ppc64el libpmem1 ppc64el 1.13.1-1.1ubuntu2 [41.1 kB] 365s Get:16 http://ftpmaster.internal/ubuntu oracular/main ppc64el libboost-iostreams1.83.0 ppc64el 1.83.0-3ubuntu1 [259 kB] 365s Get:17 http://ftpmaster.internal/ubuntu oracular/main ppc64el libboost-thread1.83.0 ppc64el 1.83.0-3ubuntu1 [279 kB] 365s Get:18 http://ftpmaster.internal/ubuntu oracular/main ppc64el librados2 ppc64el 19.2.0~git20240301.4c76c50-0ubuntu7 [4026 kB] 365s Get:19 http://ftpmaster.internal/ubuntu oracular/main ppc64el libpmemobj1 ppc64el 1.13.1-1.1ubuntu2 [143 kB] 365s Get:20 http://ftpmaster.internal/ubuntu oracular/main ppc64el librbd1 ppc64el 19.2.0~git20240301.4c76c50-0ubuntu7 [3581 kB] 365s Get:21 http://ftpmaster.internal/ubuntu oracular/universe ppc64el fio ppc64el 3.37-1 [716 kB] 365s Get:22 http://ftpmaster.internal/ubuntu oracular/main ppc64el lsscsi ppc64el 0.32-1build1 [54.0 kB] 365s Preconfiguring packages ... 366s Fetched 10.7 MB in 1s (10.6 MB/s) 366s Selecting previously unselected package libopeniscsiusr. 366s (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 ... 72787 files and directories currently installed.) 366s Preparing to unpack .../00-libopeniscsiusr_2.1.10-1ubuntu1_ppc64el.deb ... 366s Unpacking libopeniscsiusr (2.1.10-1ubuntu1) ... 366s Selecting previously unselected package libisns0t64:ppc64el. 366s Preparing to unpack .../01-libisns0t64_0.101-1_ppc64el.deb ... 366s Unpacking libisns0t64:ppc64el (0.101-1) ... 366s Selecting previously unselected package open-iscsi. 366s Preparing to unpack .../02-open-iscsi_2.1.10-1ubuntu1_ppc64el.deb ... 366s Unpacking open-iscsi (2.1.10-1ubuntu1) ... 366s Selecting previously unselected package librdmacm1t64:ppc64el. 366s Preparing to unpack .../03-librdmacm1t64_52.0-2_ppc64el.deb ... 366s Unpacking librdmacm1t64:ppc64el (52.0-2) ... 366s Selecting previously unselected package libconfig-general-perl. 366s Preparing to unpack .../04-libconfig-general-perl_2.65-2_all.deb ... 366s Unpacking libconfig-general-perl (2.65-2) ... 366s Selecting previously unselected package tgt. 366s Preparing to unpack .../05-tgt_1%3a1.0.85-1.2ubuntu1_ppc64el.deb ... 366s Unpacking tgt (1:1.0.85-1.2ubuntu1) ... 366s Selecting previously unselected package libgfxdr0:ppc64el. 366s Preparing to unpack .../06-libgfxdr0_11.1-4ubuntu1_ppc64el.deb ... 366s Unpacking libgfxdr0:ppc64el (11.1-4ubuntu1) ... 366s Selecting previously unselected package libglusterfs0:ppc64el. 366s Preparing to unpack .../07-libglusterfs0_11.1-4ubuntu1_ppc64el.deb ... 366s Unpacking libglusterfs0:ppc64el (11.1-4ubuntu1) ... 366s Selecting previously unselected package libgfrpc0:ppc64el. 366s Preparing to unpack .../08-libgfrpc0_11.1-4ubuntu1_ppc64el.deb ... 366s Unpacking libgfrpc0:ppc64el (11.1-4ubuntu1) ... 366s Selecting previously unselected package libgfapi0:ppc64el. 366s Preparing to unpack .../09-libgfapi0_11.1-4ubuntu1_ppc64el.deb ... 366s Unpacking libgfapi0:ppc64el (11.1-4ubuntu1) ... 366s Selecting previously unselected package libnbd0. 366s Preparing to unpack .../10-libnbd0_1.20.2-1_ppc64el.deb ... 366s Unpacking libnbd0 (1.20.2-1) ... 366s Selecting previously unselected package libdaxctl1:ppc64el. 366s Preparing to unpack .../11-libdaxctl1_77-2ubuntu2_ppc64el.deb ... 366s Unpacking libdaxctl1:ppc64el (77-2ubuntu2) ... 366s Selecting previously unselected package libndctl6:ppc64el. 366s Preparing to unpack .../12-libndctl6_77-2ubuntu2_ppc64el.deb ... 366s Unpacking libndctl6:ppc64el (77-2ubuntu2) ... 366s Selecting previously unselected package libpmem1:ppc64el. 366s Preparing to unpack .../13-libpmem1_1.13.1-1.1ubuntu2_ppc64el.deb ... 366s Unpacking libpmem1:ppc64el (1.13.1-1.1ubuntu2) ... 366s Selecting previously unselected package libboost-iostreams1.83.0:ppc64el. 366s Preparing to unpack .../14-libboost-iostreams1.83.0_1.83.0-3ubuntu1_ppc64el.deb ... 366s Unpacking libboost-iostreams1.83.0:ppc64el (1.83.0-3ubuntu1) ... 366s Selecting previously unselected package libboost-thread1.83.0:ppc64el. 366s Preparing to unpack .../15-libboost-thread1.83.0_1.83.0-3ubuntu1_ppc64el.deb ... 366s Unpacking libboost-thread1.83.0:ppc64el (1.83.0-3ubuntu1) ... 366s Selecting previously unselected package librados2. 366s Preparing to unpack .../16-librados2_19.2.0~git20240301.4c76c50-0ubuntu7_ppc64el.deb ... 366s Unpacking librados2 (19.2.0~git20240301.4c76c50-0ubuntu7) ... 366s Selecting previously unselected package libpmemobj1:ppc64el. 366s Preparing to unpack .../17-libpmemobj1_1.13.1-1.1ubuntu2_ppc64el.deb ... 366s Unpacking libpmemobj1:ppc64el (1.13.1-1.1ubuntu2) ... 366s Selecting previously unselected package librbd1. 366s Preparing to unpack .../18-librbd1_19.2.0~git20240301.4c76c50-0ubuntu7_ppc64el.deb ... 366s Unpacking librbd1 (19.2.0~git20240301.4c76c50-0ubuntu7) ... 366s Selecting previously unselected package fio. 366s Preparing to unpack .../19-fio_3.37-1_ppc64el.deb ... 366s Unpacking fio (3.37-1) ... 366s Selecting previously unselected package lsscsi. 366s Preparing to unpack .../20-lsscsi_0.32-1build1_ppc64el.deb ... 366s Unpacking lsscsi (0.32-1build1) ... 367s Selecting previously unselected package autopkgtest-satdep. 367s Preparing to unpack .../21-2-autopkgtest-satdep.deb ... 367s Unpacking autopkgtest-satdep (0) ... 367s Setting up libconfig-general-perl (2.65-2) ... 367s Setting up libisns0t64:ppc64el (0.101-1) ... 367s Setting up libboost-thread1.83.0:ppc64el (1.83.0-3ubuntu1) ... 367s Setting up libnbd0 (1.20.2-1) ... 367s Setting up libopeniscsiusr (2.1.10-1ubuntu1) ... 367s Setting up libglusterfs0:ppc64el (11.1-4ubuntu1) ... 367s Setting up libboost-iostreams1.83.0:ppc64el (1.83.0-3ubuntu1) ... 367s Setting up lsscsi (0.32-1build1) ... 367s Setting up libdaxctl1:ppc64el (77-2ubuntu2) ... 367s Setting up libndctl6:ppc64el (77-2ubuntu2) ... 367s Setting up librdmacm1t64:ppc64el (52.0-2) ... 367s Setting up tgt (1:1.0.85-1.2ubuntu1) ... 367s Created symlink '/etc/systemd/system/multi-user.target.wants/tgt.service' → '/usr/lib/systemd/system/tgt.service'. 368s Setting up libpmem1:ppc64el (1.13.1-1.1ubuntu2) ... 368s Setting up libgfxdr0:ppc64el (11.1-4ubuntu1) ... 368s Setting up librados2 (19.2.0~git20240301.4c76c50-0ubuntu7) ... 368s Setting up open-iscsi (2.1.10-1ubuntu1) ... 368s Created symlink '/etc/systemd/system/sockets.target.wants/iscsid.socket' → '/usr/lib/systemd/system/iscsid.socket'. 369s Created symlink '/etc/systemd/system/iscsi.service' → '/usr/lib/systemd/system/open-iscsi.service'. 369s Created symlink '/etc/systemd/system/sysinit.target.wants/open-iscsi.service' → '/usr/lib/systemd/system/open-iscsi.service'. 369s Setting up libpmemobj1:ppc64el (1.13.1-1.1ubuntu2) ... 369s Setting up librbd1 (19.2.0~git20240301.4c76c50-0ubuntu7) ... 369s Setting up libgfrpc0:ppc64el (11.1-4ubuntu1) ... 369s Setting up libgfapi0:ppc64el (11.1-4ubuntu1) ... 369s Setting up fio (3.37-1) ... 370s Setting up autopkgtest-satdep (0) ... 370s Processing triggers for man-db (2.12.1-2) ... 372s Processing triggers for initramfs-tools (0.142ubuntu30) ... 372s update-initramfs: Generating /boot/initrd.img-6.8.0-31-generic 372s W: No lz4 in /usr/bin:/sbin:/bin, using gzip 381s Processing triggers for libc-bin (2.39-0ubuntu9) ... 384s (Reading database ... 73028 files and directories currently installed.) 384s Removing autopkgtest-satdep (0) ... 386s autopkgtest [12:02:21]: test tgtbasedmpaths: [----------------------- 386s + targetname=iqn.2016-11.foo.com:target.iscsi 386s + pwd 386s + cwd=/tmp/autopkgtest.HPnGkO/build.m3P/src 386s + testdir=/mnt/tgtmpathtest 386s + localhost=127.0.0.1 386s + portal=127.0.0.1:3260 386s + maxpaths=4 386s + backfn=backingfile 386s + expectwwid=60000000000000000e00000000010001 386s + testdisk=/dev/disk/by-id/wwn-0x60000000000000000e00000000010001 386s + bglog=/tmp/autopkgtest.HPnGkO/tgtbasedmpaths-artifacts/test-background.log 386s + fioprep=/tmp/autopkgtest.HPnGkO/tgtbasedmpaths-artifacts/path-change-prep.fio 386s + fiovrfy=/tmp/autopkgtest.HPnGkO/tgtbasedmpaths-artifacts/path-change-check.fio 386s + mkdir -p /etc/multipath 386s + echo /360000000000000000e00000000010001/ 386s + service tgt restart 387s + truncate --size 100M backingfile 387s + tgtadm --lld iscsi --op new --mode target --tid 1 -T iqn.2016-11.foo.com:target.iscsi 387s + tgtadm --lld iscsi --op bind --mode target --tid 1 -I ALL 387s + tgtadm --lld iscsi --op new --mode logicalunit --tid 1 --lun 1 -b /tmp/autopkgtest.HPnGkO/build.m3P/src/backingfile 387s + iscsiadm --mode discovery --type sendtargets --portal 127.0.0.1 387s + echo login #1 387s + iscsiadm --mode node --targetname iqn.2016-11.foo.com:target.iscsi --portal 127.0.0.1:3260 --login 387s 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi 387s login #1 387s + seq 2 4 387s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 387s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 387s + echo extra login #2 387s + iscsiadm --mode session -r 1 --op new 387s extra login #2 387s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 387s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 387s extra login #3 387s + echo extra login #3 387s + iscsiadm --mode session -r 1 --op new 387s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 387s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 387s extra login #4 387s + echo extra login #4 387s + iscsiadm --mode session -r 1 --op new 387s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 387s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 387s + udevadm settle 387s + sleep 5 392s + echo Status after initial setup 392s + tgtadm --lld iscsi --mode target --op show 392s Status after initial setup 392s Target 1: iqn.2016-11.foo.com:target.iscsi 392s System information: 392s Driver: iscsi 392s State: ready 392s I_T nexus information: 392s I_T nexus: 1 392s Initiator: iqn.2004-10.com.ubuntu:01:cae2d481f475 alias: autopkgtest 392s Connection: 0 392s IP Address: 127.0.0.1 392s I_T nexus: 2 392s Initiator: iqn.2004-10.com.ubuntu:01:cae2d481f475 alias: autopkgtest 392s Connection: 0 392s IP Address: 127.0.0.1 392s I_T nexus: 3 392s Initiator: iqn.2004-10.com.ubuntu:01:cae2d481f475 alias: autopkgtest 392s Connection: 0 392s IP Address: 127.0.0.1 392s I_T nexus: 4 392s Initiator: iqn.2004-10.com.ubuntu:01:cae2d481f475 alias: autopkgtest 392s Connection: 0 392s IP Address: 127.0.0.1 392s LUN information: 392s LUN: 0 392s Type: controller 392s SCSI ID: IET 00010000 392s SCSI SN: beaf10 392s Size: 0 MB, Block size: 1 392s Online: Yes 392s Removable media: No 392s Prevent removal: No 392s Readonly: No 392s SWP: No 392s Thin-provisioning: No 392s Backing store type: null 392s Backing store path: None 392s Backing store flags: 392s LUN: 1 392s Type: disk 392s SCSI ID: IET 00010001 392s SCSI SN: beaf11 392s Size: 105 MB, Block size: 512 392s Online: Yes 392s Removable media: No 392s Prevent removal: No 392s Readonly: No 392s SWP: No 392s Thin-provisioning: No 392s Backing store type: rdwr 392s Backing store path: /tmp/autopkgtest.HPnGkO/build.m3P/src/backingfile 392s Backing store flags: 392s Account information: 392s ACL information: 392s ALL 392s Session: 4 392s Connection: 0 392s Initiator: iqn.2004-10.com.ubuntu:01:cae2d481f475 392s IP Address: 127.0.0.1 392s Session: 3 392s Connection: 0 392s Initiator: iqn.2004-10.com.ubuntu:01:cae2d481f475 392s IP Address: 127.0.0.1 392s Session: 2 392s Connection: 0 392s Initiator: iqn.2004-10.com.ubuntu:01:cae2d481f475 392s IP Address: 127.0.0.1 392s Session: 1 392s Connection: 0 392s Initiator: iqn.2004-10.com.ubuntu:01:cae2d481f475 392s IP Address: 127.0.0.1 392s + tgtadm --lld iscsi --op show --mode conn --tid 1 392s + iscsiadm --mode session -P 1 392s Target: iqn.2016-11.foo.com:target.iscsi (non-flash) 392s Current Portal: 127.0.0.1:3260,1 392s Persistent Portal: 127.0.0.1:3260,1 392s ********** 392s Interface: 392s ********** 392s Iface Name: default 392s Iface Transport: tcp 392s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:cae2d481f475 392s Iface IPaddress: 127.0.0.1 392s Iface HWaddress: default 392s Iface Netdev: default 392s SID: 1 392s iSCSI Connection State: LOGGED IN 392s iSCSI Session State: LOGGED_IN 392s Internal iscsid Session State: NO CHANGE 392s 392s ********** 392s Interface: 392s ********** 392s Iface Name: default 392s Iface Transport: tcp 392s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:cae2d481f475 392s Iface IPaddress: 127.0.0.1 392s Iface HWaddress: default 392s Iface Netdev: default 392s SID: 2 392s iSCSI Connection State: LOGGED IN 392s iSCSI Session State: LOGGED_IN 392s Internal iscsid Session State: NO CHANGE 392s 392s ********** 392s Interface: 392s ********** 392s Iface Name: default 392s Iface Transport: tcp 392s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:cae2d481f475 392s Iface IPaddress: 127.0.0.1 392s Iface HWaddress: default 392s Iface Netdev: default 392s SID: 3 392s iSCSI Connection State: LOGGED IN 392s iSCSI Session State: LOGGED_IN 392s Internal iscsid Session State: NO CHANGE 392s 392s ********** 392s Interface: 392s ********** 392s Iface Name: default 392s Iface Transport: tcp 392s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:cae2d481f475 392s Iface IPaddress: 127.0.0.1 392s Iface HWaddress: default 392s Iface Netdev: default 392s SID: 4 392s iSCSI Connection State: LOGGED IN 392s iSCSI Session State: LOGGED_IN 392s Internal iscsid Session State: NO CHANGE 392s + lsscsi -liv 392s [0:0:0:0] disk QEMU QEMU HARDDISK 2.5+ /dev/sda 0QEMU_QEMU_HARDDISK_drive-scsi0-0-0-0 392s state=running queue_depth=128 scsi_level=6 type=0 device_blocked=0 timeout=30 392s dir: /sys/bus/scsi/devices/0:0:0:0 [/sys/devices/pci0000:00/0000:00:02.0/virtio1/host0/target0:0:0/0:0:0:0] 392s [1:0:0:0] storage IET Controller 0001 - - 392s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 392s dir: /sys/bus/scsi/devices/1:0:0:0 [/sys/devices/platform/host1/session1/target1:0:0/1:0:0:0] 392s [1:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdb 360000000000000000e00000000010001 392s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 392s dir: /sys/bus/scsi/devices/1:0:0:1 [/sys/devices/platform/host1/session1/target1:0:0/1:0:0:1] 392s [2:0:0:0] storage IET Controller 0001 - - 392s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 392s dir: /sys/bus/scsi/devices/2:0:0:0 [/sys/devices/platform/host2/session2/target2:0:0/2:0:0:0] 392s [2:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdc 360000000000000000e00000000010001 392s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 392s dir: /sys/bus/scsi/devices/2:0:0:1 [/sys/devices/platform/host2/session2/target2:0:0/2:0:0:1] 392s [3:0:0:0] storage IET Controller 0001 - - 392s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 392s dir: /sys/bus/scsi/devices/3:0:0:0 [/sys/devices/platform/host3/session3/target3:0:0/3:0:0:0] 392s [3:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdd 360000000000000000e00000000010001 392s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 392s dir: /sys/bus/scsi/devices/3:0:0:1 [/sys/devices/platform/host3/session3/target3:0:0/3:0:0:1] 392s [4:0:0:0] storage IET Controller 0001 - - 392s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 392s dir: /sys/bus/scsi/devices/4:0:0:0 [/sys/devices/platform/host4/session4/target4:0:0/4:0:0:0] 392s [4:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sde 360000000000000000e00000000010001 392s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 392s dir: /sys/bus/scsi/devices/4:0:0:1 [/sys/devices/platform/host4/session4/target4:0:0/4:0:0:1] 392s NVMe module may not be loaded 392s list_ndevices: scandir: /sys/class/nvme/: No such file or directory 392s + multipath -v3 -ll 392s 53.344806 | set open fds limit to 1073741816/1073741816 392s 53.344859 | _read_bindings_file: reading /etc/multipath/bindings 392s 53.344882 | loading /usr/lib/multipath/libchecktur.so checker 392s 53.344963 | checker tur: message table size = 4 392s 53.344987 | loading /usr/lib/multipath/libprioconst.so prioritizer 392s 53.345092 | _init_foreign: foreign library "nvme" is not enabled 392s 53.350460 | sda: size = 167772160 392s 53.350619 | sda: vendor = QEMU 392s 53.350659 | sda: product = QEMU HARDDISK 392s 53.350680 | sda: rev = 2.5+ 392s 53.351267 | sda: h:b:t:l = 0:0:0:0 392s 53.351574 | sda: tgt_node_name = 392s 53.351594 | sda: uid_attribute = ID_SERIAL (setting: multipath internal) 392s 53.351597 | sda: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 392s 53.351736 | sda: 10443 cyl, 255 heads, 63 sectors/track, start at 0 392s 53.351757 | sda: vpd_vendor_id = 0 "undef" (setting: multipath internal) 392s 53.351768 | __sysfs_attr_get_value: attribute '/sys/devices/pci0000:00/0000:00:02.0/virtio1/host0/target0:0:0/0:0:0:0/vpd_pg80' cannot be opened: No such file or directory 392s 53.351772 | failed to read sysfs vpd pg80: No such file or directory 392s 53.351970 | sda: fail to get serial 392s 53.351990 | sda: detect_checker = yes (setting: multipath internal) 392s 53.352026 | sda checker timeout = 30 s (setting: kernel sysfs) 392s 53.352197 | sda: path_checker = tur (setting: multipath internal) 392s 53.352346 | sda: tur state = up 392s 53.352627 | sdb: size = 204800 392s 53.352749 | sdb: vendor = IET 392s 53.352769 | sdb: product = VIRTUAL-DISK 392s 53.352789 | sdb: rev = 0001 392s 53.353390 | sdb: h:b:t:l = 1:0:0:1 392s 53.353756 | sdb: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 392s 53.353776 | sdb: uid_attribute = ID_SERIAL (setting: multipath internal) 392s 53.353778 | sdb: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 392s 53.353923 | sdb: 1024 cyl, 4 heads, 50 sectors/track, start at 0 392s 53.353943 | sdb: vpd_vendor_id = 0 "undef" (setting: multipath internal) 392s 53.353957 | sdb: serial = beaf11 392s 53.353959 | sdb: detect_checker = yes (setting: multipath internal) 392s 53.354000 | sdb checker timeout = 30 s (setting: kernel sysfs) 392s 53.354305 | sdb: path_checker = tur (setting: multipath internal) 392s 53.354549 | sdb: tur state = up 392s 53.354683 | sdc: size = 204800 392s 53.354826 | sdc: vendor = IET 392s 53.354866 | sdc: product = VIRTUAL-DISK 392s 53.354886 | sdc: rev = 0001 392s 53.355534 | sdc: h:b:t:l = 2:0:0:1 392s 53.355881 | sdc: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 392s 53.355901 | sdc: uid_attribute = ID_SERIAL (setting: multipath internal) 392s 53.355903 | sdc: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 392s 53.356065 | sdc: 1024 cyl, 4 heads, 50 sectors/track, start at 0 392s 53.356088 | sdc: vpd_vendor_id = 0 "undef" (setting: multipath internal) 392s 53.356102 | sdc: serial = beaf11 392s 53.356104 | sdc: detect_checker = yes (setting: multipath internal) 392s 53.356130 | sdc checker timeout = 30 s (setting: kernel sysfs) 392s 53.356369 | sdc: path_checker = tur (setting: multipath internal) 392s 53.356605 | sdc: tur state = up 392s 53.356741 | sdd: size = 204800 392s 53.356884 | sdd: vendor = IET 392s 53.356922 | sdd: product = VIRTUAL-DISK 392s 53.356942 | sdd: rev = 0001 392s 53.357596 | sdd: h:b:t:l = 3:0:0:1 392s 53.357944 | sdd: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 392s 53.357963 | sdd: uid_attribute = ID_SERIAL (setting: multipath internal) 392s 53.357965 | sdd: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 392s 53.358103 | sdd: 1024 cyl, 4 heads, 50 sectors/track, start at 0 392s 53.358123 | sdd: vpd_vendor_id = 0 "undef" (setting: multipath internal) 392s 53.358136 | sdd: serial = beaf11 392s 53.358138 | sdd: detect_checker = yes (setting: multipath internal) 392s 53.358171 | sdd checker timeout = 30 s (setting: kernel sysfs) 392s 53.358430 | sdd: path_checker = tur (setting: multipath internal) 392s 53.359489 | sdd: tur state = up 392s 53.359627 | sde: size = 204800 392s 53.359770 | sde: vendor = IET 392s 53.359808 | sde: product = VIRTUAL-DISK 392s 53.359829 | sde: rev = 0001 392s 53.360483 | sde: h:b:t:l = 4:0:0:1 392s 53.360833 | sde: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 392s 53.360853 | sde: uid_attribute = ID_SERIAL (setting: multipath internal) 392s 53.360855 | sde: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 392s 53.360992 | sde: 1024 cyl, 4 heads, 50 sectors/track, start at 0 392s 53.361011 | sde: vpd_vendor_id = 0 "undef" (setting: multipath internal) 392s 53.361024 | sde: serial = beaf11 392s 53.361027 | sde: detect_checker = yes (setting: multipath internal) 392s 53.361052 | sde checker timeout = 30 s (setting: kernel sysfs) 392s 53.361300 | sde: path_checker = tur (setting: multipath internal) 392s 53.361551 | sde: tur state = up 392s 53.361659 | loop0: device node name blacklisted 392s 53.361759 | loop1: device node name blacklisted 392s 53.361857 | loop2: device node name blacklisted 392s 53.361937 | loop3: device node name blacklisted 392s 53.362035 | loop4: device node name blacklisted 392s 53.362132 | loop5: device node name blacklisted 392s 53.362229 | loop6: device node name blacklisted 392s 53.362326 | loop7: device node name blacklisted 392s 53.362426 | dm-0: device node name blacklisted 392s 53.363502 | multipath-tools v0.9.9 (05/03, 2024) 392s 53.363529 | libdevmapper version 1.02.196 392s 53.363650 | kernel device mapper v4.48.0 392s 53.363676 | DM multipath kernel driver v1.14.0 392s 53.363775 | sdb: size = 204800 392s 53.363796 | sdb: vendor = IET 392s 53.363799 | sdb: product = VIRTUAL-DISK 392s 53.363801 | sdb: rev = 0001 392s 53.364434 | sdb: h:b:t:l = 1:0:0:1 392s 53.364564 | sdb: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 392s 53.364599 | sdb: 1024 cyl, 4 heads, 50 sectors/track, start at 0 392s 53.364602 | sdb: vpd_vendor_id = 0 "undef" (setting: multipath internal) 392s 53.364613 | sdb: serial = beaf11 392s 53.364843 | sdb: tur state = up 392s 53.364864 | sdb: uid = 360000000000000000e00000000010001 (udev) 392s 53.364867 | sdb: detect_prio = yes (setting: multipath internal) 392s 53.364870 | sdb: prio = const (setting: multipath internal) 392s 53.364872 | sdb: prio args = "" (setting: multipath internal) 392s 53.364874 | sdb: const prio = 1 392s 53.364897 | sdc: size = 204800 392s 53.364901 | sdc: vendor = IET 392s 53.364903 | sdc: product = VIRTUAL-DISK 392s 53.364906 | sdc: rev = 0001 392s 53.365489 | sdc: h:b:t:l = 2:0:0:1 392s 53.365622 | sdc: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 392s 53.365657 | sdc: 1024 cyl, 4 heads, 50 sectors/track, start at 0 392s 53.365660 | sdc: vpd_vendor_id = 0 "undef" (setting: multipath internal) 392s 53.365671 | sdc: serial = beaf11 392s 53.365887 | sdc: tur state = up 392s 53.365907 | sdc: uid = 360000000000000000e00000000010001 (udev) 392s 53.365909 | sdc: detect_prio = yes (setting: multipath internal) 392s 53.365912 | sdc: prio = const (setting: multipath internal) 392s 53.365914 | sdc: prio args = "" (setting: multipath internal) 392s 53.365916 | sdc: const prio = 1 392s 53.365938 | sdd: size = 204800 392s 53.365942 | sdd: vendor = IET 392s 53.365944 | sdd: product = VIRTUAL-DISK 392s 53.365947 | sdd: rev = 0001 392s 53.366529 | sdd: h:b:t:l = 3:0:0:1 392s 53.366653 | sdd: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 392s 53.366688 | sdd: 1024 cyl, 4 heads, 50 sectors/track, start at 0 392s 53.366690 | sdd: vpd_vendor_id = 0 "undef" (setting: multipath internal) 392s 53.366701 | sdd: serial = beaf11 392s 53.366931 | sdd: tur state = up 392s 53.366950 | sdd: uid = 360000000000000000e00000000010001 (udev) 392s 53.366953 | sdd: detect_prio = yes (setting: multipath internal) 392s 53.366955 | sdd: prio = const (setting: multipath internal) 392s 53.366957 | sdd: prio args = "" (setting: multipath internal) 392s 53.366959 | sdd: const prio = 1 392s 53.366981 | sde: size = 204800 392s 53.366985 | sde: vendor = IET 392s 53.366988 | sde: product = VIRTUAL-DISK 392s 53.366990 | sde: rev = 0001 392s 53.367569 | sde: h:b:t:l = 4:0:0:1 392s 53.367692 | sde: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 392s 53.367726 | sde: 1024 cyl, 4 heads, 50 sectors/track, start at 0 392s 53.367729 | sde: vpd_vendor_id = 0 "undef" (setting: multipath internal) 392s 53.367740 | sde: serial = beaf11 392s 53.367964 | sde: tur state = up 392s 53.367984 | sde: uid = 360000000000000000e00000000010001 (udev) 392s 53.367986 | sde: detect_prio = yes (setting: multipath internal) 392s 53.367989 | sde: prio = const (setting: multipath internal) 392s 53.367991 | sde: prio args = "" (setting: multipath internal) 392s 53.367993 | sde: const prio = 1 392s 53.368805 | unloading tur checker 392s 53.368846 | unloading const prioritizer 392s ===== paths list ===== 392s uuid hcil dev dev_t pri dm_st chk_st vend/prod/rev dev_st 392s 0:0:0:0 sda 8:0 -1 undef undef QEMU,QEMU HARDDISK,2.5+ unknown 392s 1:0:0:1 sdb 8:16 -1 undef undef IET,VIRTUAL-DISK,0001 unknown 392s 2:0:0:1 sdc 8:32 -1 undef undef IET,VIRTUAL-DISK,0001 unknown 392s 3:0:0:1 sdd 8:48 -1 undef undef IET,VIRTUAL-DISK,0001 unknown 392s 4:0:0:1 sde 8:64 -1 undef undef IET,VIRTUAL-DISK,0001 unknown 392s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 392s size=100M features='0' hwhandler='0' wp=rw 392s |-+- policy='service-time 0' prio=1 status=active 392s | `- 1:0:0:1 sdb 8:16 active ready running 392s |-+- policy='service-time 0' prio=1 status=enabled 392s | `- 2:0:0:1 sdc 8:32 active ready running 392s |-+- policy='service-time 0' prio=1 status=enabled 392s | `- 3:0:0:1 sdd 8:48 active ready running 392s `-+- policy='service-time 0' prio=1 status=enabled 392s `- 4:0:0:1 sde 8:64 active ready running 392s mpatha: 0 204800 multipath 0 0 4 1 service-time 0 1 2 8:16 1 1 service-time 0 1 2 8:32 1 1 service-time 0 1 2 8:48 1 1 service-time 0 1 2 8:64 1 1 392s /etc/multipath/bindings:# Multipath bindings, Version : 1.0 392s /etc/multipath/bindings:# NOTE: this file is automatically maintained by the multipath program. 392s /etc/multipath/bindings:# You should not need to edit this file in normal circumstances. 392s /etc/multipath/bindings:# 392s /etc/multipath/bindings:# Format: 392s /etc/multipath/bindings:# alias wwid 392s /etc/multipath/bindings:# 392s /etc/multipath/bindings:mpatha 360000000000000000e00000000010001 392s /etc/multipath/wwids:/360000000000000000e00000000010001/ 392s ● multipathd.service - Device-Mapper Multipath Device Controller 392s Loaded: loaded (/usr/lib/systemd/system/multipathd.service; enabled; preset: enabled) 392s Active: active (running) since Mon 2024-07-22 12:01:37 UTC; 49s ago 392s Invocation: 14adebeed344467e875ac0ac3bca3b5e 392s TriggeredBy: ● multipathd.socket 392s Main PID: 337 (multipathd) 392s Status: "up" 392s Tasks: 7 392s Memory: 28.1M (peak: 38.4M) 392s CPU: 61ms 392s CGroup: /system.slice/multipathd.service 392s └─337 /sbin/multipathd -d -s 392s 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 392s Jul 22 12:01:37 autopkgtest multipathd[337]: multipathd v0.9.9: start up 392s Jul 22 12:01:37 autopkgtest multipathd[337]: reconfigure: setting up paths and maps 392s Jul 22 12:01:37 autopkgtest systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 392s Jul 22 12:02:22 autopkgtest multipathd[337]: updated bindings file /etc/multipath/bindings 392s Jul 22 12:02:22 autopkgtest multipathd[337]: mpatha: addmap [0 204800 multipath 0 0 1 1 service-time 0 1 1 8:16 1] 392s Jul 22 12:02:22 autopkgtest multipathd[337]: sdb [8:16]: path added to devmap mpatha 392s Jul 22 12:02:22 autopkgtest multipathd[337]: mpatha: performing delayed actions 392s Jul 22 12:02:22 autopkgtest multipathd[337]: mpatha: reload [0 204800 multipath 0 0 4 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:64 1] 392s ● multipathd.socket - multipathd control socket 392s Loaded: loaded (/usr/lib/systemd/system/multipathd.socket; enabled; preset: enabled) 392s Active: active (running) since Mon 2024-07-22 12:01:37 UTC; 49s ago 392s Invocation: 97723796bc214848920f6bc29665a5f6 392s Triggers: ● multipathd.service 392s Listen: @/org/kernel/linux/storage/multipathd (Stream) 392s CGroup: /system.slice/multipathd.socket 392s 392s Notice: journal has been rotated since unit was started, output may be incomplete. 392s total 0 392s drwxr-xr-x 2 root root 80 Jul 22 12:02 . 392s drwxr-xr-x 18 root root 4260 Jul 22 12:02 .. 392s crw------- 1 root root 10, 236 Jul 22 12:01 control 392s lrwxrwxrwx 1 root root 7 Jul 22 12:02 mpatha -> ../dm-0 392s journal 392s + dmsetup table 392s + grep . /etc/multipath/bindings /etc/multipath/wwids 392s + systemctl status multipathd.service 392s + systemctl status multipathd.socket 392s + ls -la /dev/mapper/ 392s + echo journal 392s + journalctl -b 392s Jul 22 12:01:34 autopkgtest kernel: radix-mmu: Page sizes from device-tree: 392s Jul 22 12:01:34 autopkgtest kernel: radix-mmu: Page size shift = 12 AP=0x0 392s Jul 22 12:01:34 autopkgtest kernel: radix-mmu: Page size shift = 16 AP=0x5 392s Jul 22 12:01:34 autopkgtest kernel: radix-mmu: Page size shift = 21 AP=0x1 392s Jul 22 12:01:34 autopkgtest kernel: radix-mmu: Page size shift = 30 AP=0x2 392s Jul 22 12:01:34 autopkgtest kernel: Activating Kernel Userspace Access Prevention 392s Jul 22 12:01:34 autopkgtest kernel: Activating Kernel Userspace Execution Prevention 392s Jul 22 12:01:34 autopkgtest kernel: radix-mmu: Mapped 0x0000000000000000-0x00000000038a0000 with 64.0 KiB pages (exec) 392s Jul 22 12:01:34 autopkgtest kernel: radix-mmu: Mapped 0x00000000038a0000-0x0000000200000000 with 64.0 KiB pages 392s Jul 22 12:01:34 autopkgtest kernel: lpar: Using radix MMU under hypervisor 392s Jul 22 12:01:34 autopkgtest kernel: Linux version 6.8.0-31-generic (buildd@bos02-ppc64el-018) (powerpc64le-linux-gnu-gcc-13 (Ubuntu 13.2.0-23ubuntu4) 13.2.0, GNU ld (GNU Binutils for Ubuntu) 2.42) #31-Ubuntu SMP Sat Apr 20 00:05:55 UTC 2024 (Ubuntu 6.8.0-31.31-generic 6.8.1) 392s Jul 22 12:01:34 autopkgtest kernel: Secure boot mode disabled 392s Jul 22 12:01:34 autopkgtest kernel: Found initrd at 0xc000000006200000:0xc0000000093e2a25 392s Jul 22 12:01:34 autopkgtest kernel: Hardware name: IBM pSeries (emulated by qemu) POWER9 (raw) 0x4e1203 0xf000005 of:SLOF,HEAD hv:linux,kvm pSeries 392s Jul 22 12:01:34 autopkgtest kernel: printk: legacy bootconsole [udbg0] enabled 392s Jul 22 12:01:34 autopkgtest kernel: Partition configured for 4 cpus. 392s Jul 22 12:01:34 autopkgtest kernel: CPU maps initialized for 1 thread per core 392s Jul 22 12:01:34 autopkgtest kernel: (thread shift is 0) 392s Jul 22 12:01:34 autopkgtest kernel: Allocated 3360 bytes for 4 pacas 392s Jul 22 12:01:34 autopkgtest kernel: numa: Partition configured for 1 NUMA nodes. 392s Jul 22 12:01:34 autopkgtest kernel: ----------------------------------------------------- 392s Jul 22 12:01:34 autopkgtest kernel: phys_mem_size = 0x200000000 392s Jul 22 12:01:34 autopkgtest kernel: dcache_bsize = 0x80 392s Jul 22 12:01:34 autopkgtest kernel: icache_bsize = 0x80 392s Jul 22 12:01:34 autopkgtest kernel: cpu_features = 0x0001c06b8f4f9187 392s Jul 22 12:01:34 autopkgtest kernel: possible = 0x001ffbfbcf5fb187 392s Jul 22 12:01:34 autopkgtest kernel: always = 0x0000000380008181 392s Jul 22 12:01:34 autopkgtest kernel: cpu_user_features = 0xdc0065c2 0xaef00000 392s Jul 22 12:01:34 autopkgtest kernel: mmu_features = 0x3c007641 392s Jul 22 12:01:34 autopkgtest kernel: firmware_features = 0x00000085455a445f 392s Jul 22 12:01:34 autopkgtest kernel: vmalloc start = 0xc008000000000000 392s Jul 22 12:01:34 autopkgtest kernel: IO start = 0xc00a000000000000 392s Jul 22 12:01:34 autopkgtest kernel: vmemmap start = 0xc00c000000000000 392s Jul 22 12:01:34 autopkgtest kernel: ----------------------------------------------------- 392s Jul 22 12:01:34 autopkgtest kernel: numa: NODE_DATA [mem 0x1eff10280-0x1eff17fff] 392s Jul 22 12:01:34 autopkgtest kernel: rfi-flush: fallback displacement flush available 392s Jul 22 12:01:34 autopkgtest kernel: rfi-flush: ori type flush available 392s Jul 22 12:01:34 autopkgtest kernel: rfi-flush: mttrig type flush available 392s Jul 22 12:01:34 autopkgtest kernel: rfi-flush: patched 12 locations (ori+mttrig type flush) 392s Jul 22 12:01:34 autopkgtest kernel: count-cache-flush: software flush enabled. 392s Jul 22 12:01:34 autopkgtest kernel: link-stack-flush: software flush enabled. 392s Jul 22 12:01:34 autopkgtest kernel: entry-flush: patched 61 locations (ori+mttrig type flush) 392s Jul 22 12:01:34 autopkgtest kernel: uaccess-flush: patched 1 locations (ori+mttrig type flush) 392s Jul 22 12:01:34 autopkgtest kernel: stf-barrier: eieio barrier available 392s Jul 22 12:01:34 autopkgtest kernel: stf-barrier: patched 61 entry locations (eieio barrier) 392s Jul 22 12:01:34 autopkgtest kernel: stf-barrier: patched 12 exit locations (eieio barrier) 392s Jul 22 12:01:34 autopkgtest kernel: PPC64 nvram contains 65536 bytes 392s Jul 22 12:01:34 autopkgtest kernel: barrier-nospec: using ORI speculation barrier 392s Jul 22 12:01:34 autopkgtest kernel: barrier-nospec: patched 269 locations 392s Jul 22 12:01:34 autopkgtest kernel: Top of RAM: 0x200000000, Total RAM: 0x200000000 392s Jul 22 12:01:34 autopkgtest kernel: Memory hole size: 0MB 392s Jul 22 12:01:34 autopkgtest kernel: Zone ranges: 392s Jul 22 12:01:34 autopkgtest kernel: Normal [mem 0x0000000000000000-0x00000001ffffffff] 392s Jul 22 12:01:34 autopkgtest kernel: Device empty 392s Jul 22 12:01:34 autopkgtest kernel: Movable zone start for each node 392s Jul 22 12:01:34 autopkgtest kernel: Early memory node ranges 392s Jul 22 12:01:34 autopkgtest kernel: node 0: [mem 0x0000000000000000-0x00000001ffffffff] 392s Jul 22 12:01:34 autopkgtest kernel: Initmem setup node 0 [mem 0x0000000000000000-0x00000001ffffffff] 392s Jul 22 12:01:34 autopkgtest kernel: percpu: Embedded 12 pages/cpu s609960 r0 d176472 u786432 392s Jul 22 12:01:34 autopkgtest kernel: pcpu-alloc: s609960 r0 d176472 u786432 alloc=12*65536 392s Jul 22 12:01:34 autopkgtest kernel: pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 392s Jul 22 12:01:34 autopkgtest kernel: Kernel command line: BOOT_IMAGE=/boot/vmlinux-6.8.0-31-generic root=UUID=55f4738b-dbc7-4aef-90fe-6bd3178557bc ro console=hvc0 earlyprintk 392s Jul 22 12:01:34 autopkgtest kernel: Unknown kernel command line parameters "earlyprintk BOOT_IMAGE=/boot/vmlinux-6.8.0-31-generic", will be passed to user space. 392s Jul 22 12:01:34 autopkgtest kernel: Dentry cache hash table entries: 1048576 (order: 7, 8388608 bytes, linear) 392s Jul 22 12:01:34 autopkgtest kernel: Inode-cache hash table entries: 524288 (order: 6, 4194304 bytes, linear) 392s Jul 22 12:01:34 autopkgtest kernel: Fallback order for Node 0: 0 392s Jul 22 12:01:34 autopkgtest kernel: Built 1 zonelists, mobility grouping on. Total pages: 130944 392s Jul 22 12:01:34 autopkgtest kernel: Policy zone: Normal 392s Jul 22 12:01:34 autopkgtest kernel: mem auto-init: stack:all(zero), heap alloc:on, heap free:off 392s Jul 22 12:01:34 autopkgtest kernel: Memory: 7969152K/8388608K available (23680K kernel code, 4096K rwdata, 25472K rodata, 8832K init, 1901K bss, 419456K reserved, 0K cma-reserved) 392s Jul 22 12:01:34 autopkgtest kernel: SLUB: HWalign=128, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 392s Jul 22 12:01:34 autopkgtest kernel: ftrace: allocating 51717 entries in 19 pages 392s Jul 22 12:01:34 autopkgtest kernel: ftrace: allocated 19 pages with 3 groups 392s Jul 22 12:01:34 autopkgtest kernel: trace event string verifier disabled 392s Jul 22 12:01:34 autopkgtest kernel: rcu: Hierarchical RCU implementation. 392s Jul 22 12:01:34 autopkgtest kernel: rcu: RCU restricting CPUs from NR_CPUS=2048 to nr_cpu_ids=4. 392s Jul 22 12:01:34 autopkgtest kernel: Rude variant of Tasks RCU enabled. 392s Jul 22 12:01:34 autopkgtest kernel: Tracing variant of Tasks RCU enabled. 392s Jul 22 12:01:34 autopkgtest kernel: rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies. 392s Jul 22 12:01:34 autopkgtest kernel: rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 392s Jul 22 12:01:34 autopkgtest kernel: NR_IRQS: 512, nr_irqs: 512, preallocated irqs: 16 392s Jul 22 12:01:34 autopkgtest kernel: xive: Using IRQ range [0-3] 392s Jul 22 12:01:34 autopkgtest kernel: xive: Interrupt handling initialized with spapr backend 392s Jul 22 12:01:34 autopkgtest kernel: xive: Using priority 6 for all interrupts 392s Jul 22 12:01:34 autopkgtest kernel: xive: Using 64kB queues 392s Jul 22 12:01:34 autopkgtest kernel: rcu: srcu_init: Setting srcu_struct sizes based on contention. 392s Jul 22 12:01:34 autopkgtest kernel: time_init: decrementer frequency = 512.000000 MHz 392s Jul 22 12:01:34 autopkgtest kernel: time_init: processor frequency = 2700.000000 MHz 392s Jul 22 12:01:34 autopkgtest kernel: time_init: 56 bit decrementer (max: 7fffffffffffff) 392s Jul 22 12:01:34 autopkgtest kernel: clocksource: timebase: mask: 0xffffffffffffffff max_cycles: 0x761537d007, max_idle_ns: 440795202126 ns 392s Jul 22 12:01:34 autopkgtest kernel: clocksource: timebase mult[1f40000] shift[24] registered 392s Jul 22 12:01:34 autopkgtest kernel: clockevent: decrementer mult[83126f] shift[24] cpu[0] 392s Jul 22 12:01:34 autopkgtest kernel: Console: colour dummy device 80x25 392s Jul 22 12:01:34 autopkgtest kernel: printk: legacy console [hvc0] enabled 392s Jul 22 12:01:34 autopkgtest kernel: printk: legacy bootconsole [udbg0] disabled 392s Jul 22 12:01:34 autopkgtest kernel: pid_max: default: 32768 minimum: 301 392s Jul 22 12:01:34 autopkgtest kernel: LSM: initializing lsm=lockdown,capability,landlock,yama,apparmor,integrity 392s Jul 22 12:01:34 autopkgtest kernel: landlock: Up and running. 392s Jul 22 12:01:34 autopkgtest kernel: Yama: becoming mindful. 392s Jul 22 12:01:34 autopkgtest kernel: AppArmor: AppArmor initialized 392s Jul 22 12:01:34 autopkgtest kernel: Mount-cache hash table entries: 16384 (order: 1, 131072 bytes, linear) 392s Jul 22 12:01:34 autopkgtest kernel: Mountpoint-cache hash table entries: 16384 (order: 1, 131072 bytes, linear) 392s Jul 22 12:01:34 autopkgtest kernel: RCU Tasks Rude: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1. 392s Jul 22 12:01:34 autopkgtest kernel: RCU Tasks Trace: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1. 392s Jul 22 12:01:34 autopkgtest kernel: POWER9 performance monitor hardware support registered 392s Jul 22 12:01:34 autopkgtest kernel: rcu: Hierarchical SRCU implementation. 392s Jul 22 12:01:34 autopkgtest kernel: rcu: Max phase no-delay instances is 1000. 392s Jul 22 12:01:34 autopkgtest kernel: smp: Bringing up secondary CPUs ... 392s Jul 22 12:01:34 autopkgtest kernel: smp: Brought up 1 node, 4 CPUs 392s Jul 22 12:01:34 autopkgtest kernel: numa: Node 0 CPUs: 0-3 392s Jul 22 12:01:34 autopkgtest kernel: devtmpfs: initialized 392s Jul 22 12:01:34 autopkgtest kernel: PCI host bridge /pci@800000020000000 ranges: 392s Jul 22 12:01:34 autopkgtest kernel: IO 0x0000200000000000..0x000020000000ffff -> 0x0000000000000000 392s Jul 22 12:01:34 autopkgtest kernel: MEM 0x0000200080000000..0x00002000ffffffff -> 0x0000000080000000 392s Jul 22 12:01:34 autopkgtest kernel: MEM 0x0000210000000000..0x000021ffffffffff -> 0x0000210000000000 392s Jul 22 12:01:34 autopkgtest kernel: PCI: OF: PROBE_ONLY disabled 392s Jul 22 12:01:34 autopkgtest kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns 392s Jul 22 12:01:34 autopkgtest kernel: futex hash table entries: 1024 (order: 1, 131072 bytes, linear) 392s Jul 22 12:01:34 autopkgtest kernel: pinctrl core: initialized pinctrl subsystem 392s Jul 22 12:01:34 autopkgtest kernel: NET: Registered PF_NETLINK/PF_ROUTE protocol family 392s Jul 22 12:01:34 autopkgtest kernel: audit: initializing netlink subsys (disabled) 392s Jul 22 12:01:34 autopkgtest kernel: audit: type=2000 audit(1721649694.040:1): state=initialized audit_enabled=0 res=1 392s Jul 22 12:01:34 autopkgtest kernel: thermal_sys: Registered thermal governor 'fair_share' 392s Jul 22 12:01:34 autopkgtest kernel: thermal_sys: Registered thermal governor 'bang_bang' 392s Jul 22 12:01:34 autopkgtest kernel: thermal_sys: Registered thermal governor 'step_wise' 392s Jul 22 12:01:34 autopkgtest kernel: thermal_sys: Registered thermal governor 'user_space' 392s Jul 22 12:01:34 autopkgtest kernel: thermal_sys: Registered thermal governor 'power_allocator' 392s Jul 22 12:01:34 autopkgtest kernel: cpuidle: using governor ladder 392s Jul 22 12:01:34 autopkgtest kernel: cpuidle: using governor menu 392s Jul 22 12:01:34 autopkgtest kernel: RTAS daemon started 392s Jul 22 12:01:34 autopkgtest kernel: pstore: Using crash dump compression: deflate 392s Jul 22 12:01:34 autopkgtest kernel: pstore: Registered nvram as persistent store backend 392s Jul 22 12:01:34 autopkgtest kernel: EEH: pSeries platform initialized 392s Jul 22 12:01:34 autopkgtest kernel: kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible. 392s Jul 22 12:01:34 autopkgtest kernel: HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages 392s Jul 22 12:01:34 autopkgtest kernel: HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page 392s Jul 22 12:01:34 autopkgtest kernel: HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages 392s Jul 22 12:01:34 autopkgtest kernel: HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page 392s Jul 22 12:01:34 autopkgtest kernel: iommu: Default domain type: Translated 392s Jul 22 12:01:34 autopkgtest kernel: iommu: DMA domain TLB invalidation policy: strict mode 392s Jul 22 12:01:34 autopkgtest kernel: SCSI subsystem initialized 392s Jul 22 12:01:34 autopkgtest kernel: libata version 3.00 loaded. 392s Jul 22 12:01:34 autopkgtest kernel: usbcore: registered new interface driver usbfs 392s Jul 22 12:01:34 autopkgtest kernel: usbcore: registered new interface driver hub 392s Jul 22 12:01:34 autopkgtest kernel: usbcore: registered new device driver usb 392s Jul 22 12:01:34 autopkgtest kernel: pps_core: LinuxPPS API ver. 1 registered 392s Jul 22 12:01:34 autopkgtest kernel: pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti 392s Jul 22 12:01:34 autopkgtest kernel: PTP clock support registered 392s Jul 22 12:01:34 autopkgtest kernel: EDAC MC: Ver: 3.0.0 392s Jul 22 12:01:34 autopkgtest kernel: NetLabel: Initializing 392s Jul 22 12:01:34 autopkgtest kernel: NetLabel: domain hash size = 128 392s Jul 22 12:01:34 autopkgtest kernel: NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO 392s Jul 22 12:01:34 autopkgtest kernel: NetLabel: unlabeled traffic allowed by default 392s Jul 22 12:01:34 autopkgtest kernel: mctp: management component transport protocol core 392s Jul 22 12:01:34 autopkgtest kernel: NET: Registered PF_MCTP protocol family 392s Jul 22 12:01:34 autopkgtest kernel: PCI: Probing PCI hardware 392s Jul 22 12:01:34 autopkgtest kernel: PCI host bridge to bus 0000:00 392s Jul 22 12:01:34 autopkgtest kernel: pci_bus 0000:00: root bus resource [io 0x10000-0x1ffff] (bus address [0x0000-0xffff]) 392s Jul 22 12:01:34 autopkgtest kernel: pci_bus 0000:00: root bus resource [mem 0x200080000000-0x2000ffffffff] (bus address [0x80000000-0xffffffff]) 392s Jul 22 12:01:34 autopkgtest kernel: pci_bus 0000:00: root bus resource [mem 0x210000000000-0x21ffffffffff 64bit] 392s Jul 22 12:01:34 autopkgtest kernel: pci_bus 0000:00: root bus resource [bus 00-ff] 392s Jul 22 12:01:34 autopkgtest kernel: pci 0000:00:01.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 392s Jul 22 12:01:34 autopkgtest kernel: pci 0000:00:02.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 392s Jul 22 12:01:34 autopkgtest kernel: pci 0000:00:03.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 392s Jul 22 12:01:34 autopkgtest kernel: pci 0000:00:04.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 392s Jul 22 12:01:34 autopkgtest kernel: IOMMU table initialized, virtual merging enabled 392s Jul 22 12:01:34 autopkgtest kernel: PCI 0000:00 Cannot reserve Legacy IO [io 0x10000-0x10fff] 392s Jul 22 12:01:34 autopkgtest kernel: pci_bus 0000:00: resource 4 [io 0x10000-0x1ffff] 392s Jul 22 12:01:34 autopkgtest kernel: pci_bus 0000:00: resource 5 [mem 0x200080000000-0x2000ffffffff] 392s Jul 22 12:01:34 autopkgtest kernel: pci_bus 0000:00: resource 6 [mem 0x210000000000-0x21ffffffffff 64bit] 392s Jul 22 12:01:34 autopkgtest kernel: pci 0000:00:01.0: Adding to iommu group 0 392s Jul 22 12:01:34 autopkgtest kernel: pci 0000:00:02.0: Adding to iommu group 0 392s Jul 22 12:01:34 autopkgtest kernel: pci 0000:00:03.0: Adding to iommu group 0 392s Jul 22 12:01:34 autopkgtest kernel: pci 0000:00:04.0: Adding to iommu group 0 392s Jul 22 12:01:34 autopkgtest kernel: EEH: No capable adapters found: recovery disabled. 392s Jul 22 12:01:34 autopkgtest kernel: PCI: Probing PCI hardware done 392s Jul 22 12:01:34 autopkgtest kernel: vgaarb: loaded 392s Jul 22 12:01:34 autopkgtest kernel: clocksource: Switched to clocksource timebase 392s Jul 22 12:01:34 autopkgtest kernel: VFS: Disk quotas dquot_6.6.0 392s Jul 22 12:01:34 autopkgtest kernel: VFS: Dquot-cache hash table entries: 8192 (order 0, 65536 bytes) 392s Jul 22 12:01:34 autopkgtest kernel: AppArmor: AppArmor Filesystem Enabled 392s Jul 22 12:01:34 autopkgtest kernel: NET: Registered PF_INET protocol family 392s Jul 22 12:01:34 autopkgtest kernel: IP idents hash table entries: 131072 (order: 4, 1048576 bytes, linear) 392s Jul 22 12:01:34 autopkgtest kernel: tcp_listen_portaddr_hash hash table entries: 4096 (order: 0, 65536 bytes, linear) 392s Jul 22 12:01:34 autopkgtest kernel: Table-perturb hash table entries: 65536 (order: 2, 262144 bytes, linear) 392s Jul 22 12:01:34 autopkgtest kernel: TCP established hash table entries: 65536 (order: 3, 524288 bytes, linear) 392s Jul 22 12:01:34 autopkgtest kernel: TCP bind hash table entries: 65536 (order: 5, 2097152 bytes, linear) 392s Jul 22 12:01:34 autopkgtest kernel: TCP: Hash tables configured (established 65536 bind 65536) 392s Jul 22 12:01:34 autopkgtest kernel: MPTCP token hash table entries: 8192 (order: 1, 196608 bytes, linear) 392s Jul 22 12:01:34 autopkgtest kernel: UDP hash table entries: 4096 (order: 1, 131072 bytes, linear) 392s Jul 22 12:01:34 autopkgtest kernel: UDP-Lite hash table entries: 4096 (order: 1, 131072 bytes, linear) 392s Jul 22 12:01:34 autopkgtest kernel: NET: Registered PF_UNIX/PF_LOCAL protocol family 392s Jul 22 12:01:34 autopkgtest kernel: NET: Registered PF_XDP protocol family 392s Jul 22 12:01:34 autopkgtest kernel: PCI: CLS 0 bytes, default 128 392s Jul 22 12:01:34 autopkgtest kernel: Trying to unpack rootfs image as initramfs... 392s Jul 22 12:01:34 autopkgtest kernel: Initialise system trusted keyrings 392s Jul 22 12:01:34 autopkgtest kernel: Key type blacklist registered 392s Jul 22 12:01:34 autopkgtest kernel: workingset: timestamp_bits=38 max_order=17 bucket_order=0 392s Jul 22 12:01:34 autopkgtest kernel: zbud: loaded 392s Jul 22 12:01:34 autopkgtest kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher 392s Jul 22 12:01:34 autopkgtest kernel: fuse: init (API version 7.39) 392s Jul 22 12:01:34 autopkgtest kernel: integrity: Platform Keyring initialized 392s Jul 22 12:01:34 autopkgtest kernel: integrity: Machine keyring initialized 392s Jul 22 12:01:34 autopkgtest kernel: Key type asymmetric registered 392s Jul 22 12:01:34 autopkgtest kernel: Asymmetric key parser 'x509' registered 392s Jul 22 12:01:34 autopkgtest kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 243) 392s Jul 22 12:01:34 autopkgtest kernel: io scheduler mq-deadline registered 392s Jul 22 12:01:34 autopkgtest kernel: virtio-pci 0000:00:01.0: enabling device (0100 -> 0103) 392s Jul 22 12:01:34 autopkgtest kernel: virtio-pci 0000:00:01.0: ibm,query-pe-dma-windows(2026) 800 8000000 20000000 returned 0, lb=80000000 ps=7 wn=1 392s Jul 22 12:01:34 autopkgtest kernel: virtio-pci 0000:00:01.0: ibm,create-pe-dma-window(2027) 800 8000000 20000000 18 21 returned 0 (liobn = 0x80000001 starting addr = 8000000 0) 392s Jul 22 12:01:34 autopkgtest kernel: virtio-pci 0000:00:02.0: enabling device (0100 -> 0103) 392s Jul 22 12:01:34 autopkgtest kernel: virtio-pci 0000:00:04.0: enabling device (0100 -> 0103) 392s Jul 22 12:01:34 autopkgtest kernel: Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled 392s Jul 22 12:01:34 autopkgtest kernel: Non-volatile memory driver v1.3 392s Jul 22 12:01:34 autopkgtest kernel: Linux agpgart interface v0.103 392s Jul 22 12:01:34 autopkgtest kernel: loop: module loaded 392s Jul 22 12:01:34 autopkgtest kernel: virtio_scsi virtio1: 1/0/0 default/read/poll queues 392s Jul 22 12:01:34 autopkgtest kernel: scsi host0: Virtio SCSI HBA 392s Jul 22 12:01:34 autopkgtest kernel: tun: Universal TUN/TAP device driver, 1.6 392s Jul 22 12:01:34 autopkgtest kernel: scsi 0:0:0:0: Direct-Access QEMU QEMU HARDDISK 2.5+ PQ: 0 ANSI: 5 392s Jul 22 12:01:34 autopkgtest kernel: PPP generic driver version 2.4.2 392s Jul 22 12:01:34 autopkgtest kernel: ohci-pci 0000:00:03.0: OHCI PCI host controller 392s Jul 22 12:01:34 autopkgtest kernel: ohci-pci 0000:00:03.0: new USB bus registered, assigned bus number 1 392s Jul 22 12:01:34 autopkgtest kernel: ohci-pci 0000:00:03.0: irq 20, io mem 0x200080090000 392s Jul 22 12:01:34 autopkgtest kernel: sd 0:0:0:0: Attached scsi generic sg0 type 0 392s Jul 22 12:01:34 autopkgtest kernel: sd 0:0:0:0: Power-on or device reset occurred 392s Jul 22 12:01:34 autopkgtest kernel: sd 0:0:0:0: [sda] 167772160 512-byte logical blocks: (85.9 GB/80.0 GiB) 392s Jul 22 12:01:34 autopkgtest kernel: sd 0:0:0:0: [sda] Write Protect is off 392s Jul 22 12:01:34 autopkgtest kernel: sd 0:0:0:0: [sda] Mode Sense: 63 00 00 08 392s Jul 22 12:01:34 autopkgtest kernel: sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA 392s Jul 22 12:01:34 autopkgtest kernel: sda: sda1 sda2 392s Jul 22 12:01:34 autopkgtest kernel: sd 0:0:0:0: [sda] Attached SCSI disk 392s Jul 22 12:01:34 autopkgtest kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 6.08 392s Jul 22 12:01:34 autopkgtest kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 392s Jul 22 12:01:34 autopkgtest kernel: usb usb1: Product: OHCI PCI host controller 392s Jul 22 12:01:34 autopkgtest kernel: usb usb1: Manufacturer: Linux 6.8.0-31-generic ohci_hcd 392s Jul 22 12:01:34 autopkgtest kernel: usb usb1: SerialNumber: 0000:00:03.0 392s Jul 22 12:01:34 autopkgtest kernel: hub 1-0:1.0: USB hub found 392s Jul 22 12:01:34 autopkgtest kernel: hub 1-0:1.0: 3 ports detected 392s Jul 22 12:01:34 autopkgtest kernel: mousedev: PS/2 mouse device common for all mice 392s Jul 22 12:01:34 autopkgtest kernel: rtc-generic rtc-generic: registered as rtc0 392s Jul 22 12:01:34 autopkgtest kernel: rtc-generic rtc-generic: setting system clock to 2024-07-22T12:01:34 UTC (1721649694) 392s Jul 22 12:01:34 autopkgtest kernel: i2c_dev: i2c /dev entries driver 392s Jul 22 12:01:34 autopkgtest kernel: device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log. 392s Jul 22 12:01:34 autopkgtest kernel: device-mapper: uevent: version 1.0.3 392s Jul 22 12:01:34 autopkgtest kernel: device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@redhat.com 392s Jul 22 12:01:34 autopkgtest kernel: pseries_idle_driver registered 392s Jul 22 12:01:34 autopkgtest kernel: ledtrig-cpu: registered to indicate activity on CPUs 392s Jul 22 12:01:34 autopkgtest kernel: drop_monitor: Initializing network drop monitor service 392s Jul 22 12:01:34 autopkgtest kernel: NET: Registered PF_INET6 protocol family 392s Jul 22 12:01:34 autopkgtest kernel: Freeing initrd memory: 51072K 392s Jul 22 12:01:34 autopkgtest kernel: Segment Routing with IPv6 392s Jul 22 12:01:34 autopkgtest kernel: In-situ OAM (IOAM) with IPv6 392s Jul 22 12:01:34 autopkgtest kernel: NET: Registered PF_PACKET protocol family 392s Jul 22 12:01:34 autopkgtest kernel: Key type dns_resolver registered 392s Jul 22 12:01:34 autopkgtest kernel: secvar-sysfs: Failed to retrieve secvar operations 392s Jul 22 12:01:34 autopkgtest kernel: drmem: No dynamic reconfiguration memory found 392s Jul 22 12:01:34 autopkgtest kernel: registered taskstats version 1 392s Jul 22 12:01:34 autopkgtest kernel: Loading compiled-in X.509 certificates 392s Jul 22 12:01:34 autopkgtest kernel: Loaded X.509 cert 'Build time autogenerated kernel key: d20be259617023e52b002c562b3536c6f73da543' 392s Jul 22 12:01:34 autopkgtest kernel: Loaded X.509 cert 'Canonical Ltd. Live Patch Signing: 14df34d1a87cf37625abec039ef2bf521249b969' 392s Jul 22 12:01:34 autopkgtest kernel: Loaded X.509 cert 'Canonical Ltd. Kernel Module Signing: 88f752e560a1e0737e31163a466ad7b70a850c19' 392s Jul 22 12:01:34 autopkgtest kernel: blacklist: Loading compiled-in revocation X.509 certificates 392s Jul 22 12:01:34 autopkgtest kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing: 61482aa2830d0ab2ad5af10b7250da9033ddcef0' 392s Jul 22 12:01:34 autopkgtest kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2017): 242ade75ac4a15e50d50c84b0d45ff3eae707a03' 392s Jul 22 12:01:34 autopkgtest kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (ESM 2018): 365188c1d374d6b07c3c8f240f8ef722433d6a8b' 392s Jul 22 12:01:34 autopkgtest kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2019): c0746fd6c5da3ae827864651ad66ae47fe24b3e8' 392s Jul 22 12:01:34 autopkgtest kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2021 v1): a8d54bbb3825cfb94fa13c9f8a594a195c107b8d' 392s Jul 22 12:01:34 autopkgtest kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2021 v2): 4cf046892d6fd3c9a5b03f98d845f90851dc6a8c' 392s Jul 22 12:01:34 autopkgtest kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2021 v3): 100437bb6de6e469b581e61cd66bce3ef4ed53af' 392s Jul 22 12:01:34 autopkgtest kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (Ubuntu Core 2019): c1d57b8f6b743f23ee41f4f7ee292f06eecadfb9' 392s Jul 22 12:01:34 autopkgtest kernel: Key type .fscrypt registered 392s Jul 22 12:01:34 autopkgtest kernel: Key type fscrypt-provisioning registered 392s Jul 22 12:01:34 autopkgtest kernel: Key type encrypted registered 392s Jul 22 12:01:34 autopkgtest kernel: AppArmor: AppArmor sha256 policy hashing enabled 392s Jul 22 12:01:34 autopkgtest kernel: Secure boot mode disabled 392s Jul 22 12:01:34 autopkgtest kernel: ima: No TPM chip found, activating TPM-bypass! 392s Jul 22 12:01:34 autopkgtest kernel: Loading compiled-in module X.509 certificates 392s Jul 22 12:01:34 autopkgtest kernel: Loaded X.509 cert 'Build time autogenerated kernel key: d20be259617023e52b002c562b3536c6f73da543' 392s Jul 22 12:01:34 autopkgtest kernel: ima: Allocated hash algorithm: sha256 392s Jul 22 12:01:34 autopkgtest kernel: Secure boot mode disabled 392s Jul 22 12:01:34 autopkgtest kernel: Trusted boot mode disabled 392s Jul 22 12:01:34 autopkgtest kernel: ima: No architecture policies found 392s Jul 22 12:01:34 autopkgtest kernel: evm: Initialising EVM extended attributes: 392s Jul 22 12:01:34 autopkgtest kernel: evm: security.selinux 392s Jul 22 12:01:34 autopkgtest kernel: evm: security.SMACK64 392s Jul 22 12:01:34 autopkgtest kernel: evm: security.SMACK64EXEC 392s Jul 22 12:01:34 autopkgtest kernel: evm: security.SMACK64TRANSMUTE 392s Jul 22 12:01:34 autopkgtest kernel: evm: security.SMACK64MMAP 392s Jul 22 12:01:34 autopkgtest kernel: evm: security.apparmor 392s Jul 22 12:01:34 autopkgtest kernel: evm: security.ima 392s Jul 22 12:01:34 autopkgtest kernel: evm: security.capability 392s Jul 22 12:01:34 autopkgtest kernel: evm: HMAC attrs: 0x1 392s Jul 22 12:01:34 autopkgtest kernel: SED: plpks not available 392s Jul 22 12:01:34 autopkgtest kernel: clk: Disabling unused clocks 392s Jul 22 12:01:34 autopkgtest kernel: integrity: Unable to open file: /etc/keys/x509_evm.der (-2) 392s Jul 22 12:01:34 autopkgtest kernel: Freeing unused kernel image (initmem) memory: 8832K 392s Jul 22 12:01:34 autopkgtest kernel: Checked W+X mappings: passed, no W+X pages found 392s Jul 22 12:01:34 autopkgtest kernel: Run /init as init process 392s Jul 22 12:01:34 autopkgtest kernel: with arguments: 392s Jul 22 12:01:34 autopkgtest kernel: /init 392s Jul 22 12:01:34 autopkgtest kernel: earlyprintk 392s Jul 22 12:01:34 autopkgtest kernel: with environment: 392s Jul 22 12:01:34 autopkgtest kernel: HOME=/ 392s Jul 22 12:01:34 autopkgtest kernel: TERM=linux 392s Jul 22 12:01:34 autopkgtest kernel: BOOT_IMAGE=/boot/vmlinux-6.8.0-31-generic 392s Jul 22 12:01:34 autopkgtest kernel: virtio_net virtio0 enp0s1: renamed from eth0 392s Jul 22 12:01:35 autopkgtest kernel: raid6: vpermxor8 gen() 23255 MB/s 392s Jul 22 12:01:35 autopkgtest kernel: raid6: vpermxor4 gen() 20642 MB/s 392s Jul 22 12:01:36 autopkgtest kernel: raid6: vpermxor2 gen() 16570 MB/s 392s Jul 22 12:01:36 autopkgtest kernel: raid6: vpermxor1 gen() 13962 MB/s 392s Jul 22 12:01:36 autopkgtest kernel: raid6: altivecx8 gen() 14291 MB/s 392s Jul 22 12:01:36 autopkgtest kernel: raid6: altivecx4 gen() 14273 MB/s 392s Jul 22 12:01:36 autopkgtest kernel: raid6: altivecx2 gen() 11583 MB/s 392s Jul 22 12:01:36 autopkgtest kernel: raid6: altivecx1 gen() 8958 MB/s 392s Jul 22 12:01:36 autopkgtest kernel: raid6: int64x8 gen() 7529 MB/s 392s Jul 22 12:01:36 autopkgtest kernel: raid6: int64x4 gen() 8970 MB/s 392s Jul 22 12:01:36 autopkgtest kernel: raid6: int64x2 gen() 6884 MB/s 392s Jul 22 12:01:36 autopkgtest kernel: raid6: int64x1 gen() 5431 MB/s 392s Jul 22 12:01:36 autopkgtest kernel: raid6: using algorithm vpermxor8 gen() 23255 MB/s 392s Jul 22 12:01:36 autopkgtest kernel: raid6: using intx1 recovery algorithm 392s Jul 22 12:01:36 autopkgtest kernel: xor: measuring software checksum speed 392s Jul 22 12:01:36 autopkgtest kernel: 8regs : 17922 MB/sec 392s Jul 22 12:01:36 autopkgtest kernel: 8regs_prefetch : 16003 MB/sec 392s Jul 22 12:01:36 autopkgtest kernel: 32regs : 17930 MB/sec 392s Jul 22 12:01:36 autopkgtest kernel: 32regs_prefetch : 16039 MB/sec 392s Jul 22 12:01:36 autopkgtest kernel: altivec : 19995 MB/sec 392s Jul 22 12:01:36 autopkgtest kernel: xor: using function: altivec (19995 MB/sec) 392s Jul 22 12:01:36 autopkgtest kernel: Btrfs loaded, zoned=yes, fsverity=yes 392s Jul 22 12:01:36 autopkgtest kernel: EXT4-fs (sda1): orphan cleanup on readonly fs 392s Jul 22 12:01:36 autopkgtest kernel: EXT4-fs (sda1): mounted filesystem 55f4738b-dbc7-4aef-90fe-6bd3178557bc ro with ordered data mode. Quota mode: none. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Inserted module 'autofs4' 392s Jul 22 12:01:37 autopkgtest systemd[1]: systemd 256-1ubuntu1 running in system mode (+PAM +AUDIT +SELINUX +APPARMOR +IMA +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -XKBCOMMON +UTMP +SYSVINIT +LIBARCHIVE) 392s Jul 22 12:01:37 autopkgtest systemd[1]: Detected virtualization kvm. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Detected architecture ppc64-le. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Hostname set to . 392s Jul 22 12:01:37 autopkgtest systemd[1]: bpf-restrict-fs: BPF LSM hook not enabled in the kernel, BPF LSM not supported. 392s Jul 22 12:01:37 autopkgtest kernel: NET: Registered PF_VSOCK protocol family 392s Jul 22 12:01:37 autopkgtest systemd[1]: Configuration file /run/systemd/system/systemd-networkd-wait-online.service.d/10-netplan.conf is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Configuration file /run/systemd/system/netplan-ovs-cleanup.service is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Queued start job for default target graphical.target. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Created slice system-autopkgtest.slice - Slice /system/autopkgtest. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Created slice system-modprobe.slice - Slice /system/modprobe. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Created slice system-serial\x2dgetty.slice - Slice /system/serial-getty. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Created slice user.slice - User and Session Slice. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Started systemd-ask-password-wall.path - Forward Password Requests to Wall Directory Watch. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Set up automount proc-sys-fs-binfmt_misc.automount - Arbitrary Executable File Formats File System Automount Point. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Expecting device dev-hvc0.device - /dev/hvc0... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Reached target integritysetup.target - Local Integrity Protected Volumes. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Reached target remote-fs.target - Remote File Systems. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Reached target slices.target - Slice Units. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Reached target swap.target - Swaps. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Reached target veritysetup.target - Local Verity Protected Volumes. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Listening on multipathd.socket - multipathd control socket. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Listening on syslog.socket - Syslog Socket. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Listening on systemd-creds.socket - Credential Encryption/Decryption. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Listening on systemd-fsckd.socket - fsck to fsckd communication Socket. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Listening on systemd-initctl.socket - initctl Compatibility Named Pipe. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Listening on systemd-journald-dev-log.socket - Journal Socket (/dev/log). 392s Jul 22 12:01:37 autopkgtest systemd[1]: Listening on systemd-journald.socket - Journal Sockets. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Listening on systemd-networkd.socket - Network Service Netlink Socket. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Listening on systemd-udevd-control.socket - udev Control Socket. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Listening on systemd-udevd-kernel.socket - udev Kernel Socket. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Mounting dev-hugepages.mount - Huge Pages File System... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Mounting dev-mqueue.mount - POSIX Message Queue File System... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Mounting run-lock.mount - Legacy Locks Directory /run/lock... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Mounting sys-kernel-debug.mount - Kernel Debug File System... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Mounting sys-kernel-tracing.mount - Kernel Trace File System... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting systemd-journald.service - Journal Service... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting keyboard-setup.service - Set the console keyboard layout... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting kmod-static-nodes.service - Create List of Static Device Nodes... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting modprobe@configfs.service - Load Kernel Module configfs... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting modprobe@dm_multipath.service - Load Kernel Module dm_multipath... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting modprobe@drm.service - Load Kernel Module drm... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting modprobe@fuse.service - Load Kernel Module fuse... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... 392s Jul 22 12:01:37 autopkgtest systemd[1]: netplan-ovs-cleanup.service - OpenVSwitch configuration for cleanup was skipped because of an unmet condition check (ConditionFileIsExecutable=/usr/bin/ovs-vsctl). 392s Jul 22 12:01:37 autopkgtest systemd[1]: systemd-fsck-root.service - File System Check on Root Device was skipped because of an unmet condition check (ConditionPathExists=!/run/initramfs/fsck-root). 392s Jul 22 12:01:37 autopkgtest systemd[1]: systemd-hibernate-clear.service - Clear Stale Hibernate Storage Info was skipped because of an unmet condition check (ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67). 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting systemd-modules-load.service - Load Kernel Modules... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting systemd-remount-fs.service - Remount Root and Kernel File Systems... 392s Jul 22 12:01:37 autopkgtest systemd-journald[287]: Collecting audit messages is disabled. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting systemd-udev-load-credentials.service - Load udev Rules from Credentials... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting systemd-udev-trigger.service - Coldplug All udev Devices... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Mounted dev-hugepages.mount - Huge Pages File System. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Mounted dev-mqueue.mount - POSIX Message Queue File System. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Mounted run-lock.mount - Legacy Locks Directory /run/lock. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Mounted sys-kernel-debug.mount - Kernel Debug File System. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Mounted sys-kernel-tracing.mount - Kernel Trace File System. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Finished kmod-static-nodes.service - Create List of Static Device Nodes. 392s Jul 22 12:01:37 autopkgtest systemd-journald[287]: Journal started 392s Jul 22 12:01:37 autopkgtest systemd-journald[287]: Runtime Journal (/run/log/journal/da25b03490ef4f3e9e9f8bbee5d573a3) is 8M, max 78.4M, 70.4M free. 392s Jul 22 12:01:37 autopkgtest systemd[1]: modprobe@configfs.service: Deactivated successfully. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Finished modprobe@configfs.service - Load Kernel Module configfs. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Started systemd-journald.service - Journal Service. 392s Jul 22 12:01:37 autopkgtest systemd[1]: modprobe@dm_mod.service: Deactivated successfully. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. 392s Jul 22 12:01:37 autopkgtest systemd[1]: modprobe@dm_multipath.service: Deactivated successfully. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Finished modprobe@dm_multipath.service - Load Kernel Module dm_multipath. 392s Jul 22 12:01:37 autopkgtest systemd[1]: modprobe@drm.service: Deactivated successfully. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Finished modprobe@drm.service - Load Kernel Module drm. 392s Jul 22 12:01:37 autopkgtest systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. 392s Jul 22 12:01:37 autopkgtest systemd[1]: modprobe@fuse.service: Deactivated successfully. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Finished modprobe@fuse.service - Load Kernel Module fuse. 392s Jul 22 12:01:37 autopkgtest systemd[1]: modprobe@loop.service: Deactivated successfully. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Finished systemd-modules-load.service - Load Kernel Modules. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Finished systemd-udev-load-credentials.service - Load udev Rules from Credentials. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Mounting sys-fs-fuse-connections.mount - FUSE Control File System... 392s Jul 22 12:01:37 autopkgtest kernel: EXT4-fs (sda1): re-mounted 55f4738b-dbc7-4aef-90fe-6bd3178557bc r/w. Quota mode: none. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Mounting sys-kernel-config.mount - Kernel Configuration File System... 392s Jul 22 12:01:37 autopkgtest systemd[1]: systemd-repart.service - Repartition Root Disk was skipped because no trigger condition checks were met. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting systemd-sysctl.service - Apply Kernel Variables... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Finished keyboard-setup.service - Set the console keyboard layout. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Finished systemd-remount-fs.service - Remount Root and Kernel File Systems. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Mounted sys-fs-fuse-connections.mount - FUSE Control File System. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Mounted sys-kernel-config.mount - Kernel Configuration File System. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting cloud-init-local.service - Cloud-init: Local Stage (pre-network)... 392s Jul 22 12:01:37 autopkgtest systemd[1]: systemd-hwdb-update.service - Rebuild Hardware Database was skipped because of an unmet condition check (ConditionNeedsUpdate=/etc). 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting systemd-journal-flush.service - Flush Journal to Persistent Storage... 392s Jul 22 12:01:37 autopkgtest systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore). 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting systemd-random-seed.service - Load/Save OS Random Seed... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Finished systemd-sysctl.service - Apply Kernel Variables. 392s Jul 22 12:01:37 autopkgtest systemd-journald[287]: Time spent on flushing to /var/log/journal/da25b03490ef4f3e9e9f8bbee5d573a3 is 26.667ms for 428 entries. 392s Jul 22 12:01:37 autopkgtest systemd-journald[287]: System Journal (/var/log/journal/da25b03490ef4f3e9e9f8bbee5d573a3) is 19M, max 4G, 3.9G free. 392s Jul 22 12:01:37 autopkgtest systemd-journald[287]: Received client request to flush runtime journal. 392s Jul 22 12:01:37 autopkgtest systemd-random-seed[340]: Kernel entropy pool is not initialized yet, waiting until it is. 392s Jul 22 12:01:37 autopkgtest multipathd[337]: multipathd v0.9.9: start up 392s Jul 22 12:01:37 autopkgtest multipathd[337]: reconfigure: setting up paths and maps 392s Jul 22 12:01:37 autopkgtest systemd[1]: Finished systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully. 392s Jul 22 12:01:37 autopkgtest systemd[1]: systemd-sysusers.service - Create System Users was skipped because no trigger condition checks were met. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Finished systemd-journal-flush.service - Flush Journal to Persistent Storage. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Finished systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Reached target local-fs-pre.target - Preparation for Local File Systems. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Reached target local-fs.target - Local File Systems. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Listening on systemd-sysext.socket - System Extension Image Management. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting apparmor.service - Load AppArmor profiles... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting console-setup.service - Set console font and keymap... 392s Jul 22 12:01:37 autopkgtest systemd[1]: ldconfig.service - Rebuild Dynamic Linker Cache was skipped because no trigger condition checks were met. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting plymouth-read-write.service - Tell Plymouth To Write Out Runtime Data... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting systemd-binfmt.service - Set Up Additional Binary Formats... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting systemd-tmpfiles-setup.service - Create Volatile Files and Directories... 392s Jul 22 12:01:37 autopkgtest apparmor.systemd[358]: Restarting AppArmor 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting systemd-udevd.service - Rule-based Manager for Device Events and Files... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting ufw.service - Uncomplicated firewall... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Finished systemd-udev-trigger.service - Coldplug All udev Devices. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Finished console-setup.service - Set console font and keymap. 392s Jul 22 12:01:37 autopkgtest systemd[1]: proc-sys-fs-binfmt_misc.automount: Got automount request for /proc/sys/fs/binfmt_misc, triggered by 362 (systemd-binfmt) 392s Jul 22 12:01:37 autopkgtest systemd[1]: Finished plymouth-read-write.service - Tell Plymouth To Write Out Runtime Data. 392s Jul 22 12:01:37 autopkgtest apparmor.systemd[358]: Reloading AppArmor profiles 392s Jul 22 12:01:37 autopkgtest systemd-tmpfiles[363]: /usr/lib/tmpfiles.d/legacy.conf:13: Duplicate line for path "/run/lock", ignoring. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Finished ufw.service - Uncomplicated firewall. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Finished systemd-tmpfiles-setup.service - Create Volatile Files and Directories. 392s Jul 22 12:01:37 autopkgtest systemd[1]: systemd-firstboot.service - First Boot Wizard was skipped because of an unmet condition check (ConditionFirstBoot=yes). 392s Jul 22 12:01:37 autopkgtest systemd[1]: systemd-journal-catalog-update.service - Rebuild Journal Catalog was skipped because of an unmet condition check (ConditionNeedsUpdate=/var). 392s Jul 22 12:01:37 autopkgtest kernel: audit: type=1400 audit(1721649697.848:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="1password" pid=380 comm="apparmor_parser" 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting systemd-resolved.service - Network Name Resolution... 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting systemd-timesyncd.service - Network Time Synchronization... 392s Jul 22 12:01:37 autopkgtest systemd[1]: systemd-update-done.service - Update is Completed was skipped because no trigger condition checks were met. 392s Jul 22 12:01:37 autopkgtest kernel: audit: type=1400 audit(1721649697.852:3): apparmor="STATUS" operation="profile_load" profile="unconfined" name="QtWebEngineProcess" pid=383 comm="apparmor_parser" 392s Jul 22 12:01:37 autopkgtest kernel: audit: type=1400 audit(1721649697.852:4): apparmor="STATUS" operation="profile_load" profile="unconfined" name=4D6F6E676F444220436F6D70617373 pid=382 comm="apparmor_parser" 392s Jul 22 12:01:37 autopkgtest kernel: audit: type=1400 audit(1721649697.852:5): apparmor="STATUS" operation="profile_load" profile="unconfined" name="Discord" pid=381 comm="apparmor_parser" 392s Jul 22 12:01:37 autopkgtest systemd[1]: Starting systemd-update-utmp.service - Record System Boot/Shutdown in UTMP... 392s Jul 22 12:01:37 autopkgtest kernel: audit: type=1400 audit(1721649697.860:6): apparmor="STATUS" operation="profile_load" profile="unconfined" name="balena-etcher" pid=388 comm="apparmor_parser" 392s Jul 22 12:01:37 autopkgtest kernel: audit: type=1400 audit(1721649697.864:7): apparmor="STATUS" operation="profile_load" profile="unconfined" name="brave" pid=389 comm="apparmor_parser" 392s Jul 22 12:01:37 autopkgtest kernel: audit: type=1400 audit(1721649697.864:8): apparmor="STATUS" operation="profile_load" profile="unconfined" name="busybox" pid=391 comm="apparmor_parser" 392s Jul 22 12:01:37 autopkgtest kernel: audit: type=1400 audit(1721649697.864:9): apparmor="STATUS" operation="profile_load" profile="unconfined" name="buildah" pid=390 comm="apparmor_parser" 392s Jul 22 12:01:37 autopkgtest kernel: audit: type=1400 audit(1721649697.864:10): apparmor="STATUS" operation="profile_load" profile="unconfined" name="ch-checkns" pid=394 comm="apparmor_parser" 392s Jul 22 12:01:37 autopkgtest systemd-udevd[366]: Using default interface naming scheme 'v255'. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Finished systemd-update-utmp.service - Record System Boot/Shutdown in UTMP. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Started systemd-udevd.service - Rule-based Manager for Device Events and Files. 392s Jul 22 12:01:37 autopkgtest systemd[1]: plymouth-start.service - Show Plymouth Boot Screen was skipped because of an unmet condition check (ConditionKernelCommandLine=splash). 392s Jul 22 12:01:37 autopkgtest systemd[1]: Started systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. 392s Jul 22 12:01:37 autopkgtest systemd[1]: systemd-ask-password-plymouth.path - Forward Password Requests to Plymouth Directory Watch was skipped because of an unmet condition check (ConditionPathExists=/run/plymouth/pid). 392s Jul 22 12:01:37 autopkgtest systemd[1]: Reached target cryptsetup.target - Local Encrypted Volumes. 392s Jul 22 12:01:37 autopkgtest systemd[1]: Found device dev-hvc0.device - /dev/hvc0. 392s Jul 22 12:01:38 autopkgtest systemd[1]: Finished apparmor.service - Load AppArmor profiles. 392s Jul 22 12:01:38 autopkgtest (udev-worker)[523]: enp0s1: Could not set WakeOnLan to off, ignoring: Operation not supported 392s Jul 22 12:01:38 autopkgtest kernel: random: crng init done 392s Jul 22 12:01:38 autopkgtest systemd[1]: Finished systemd-random-seed.service - Load/Save OS Random Seed. 392s Jul 22 12:01:38 autopkgtest systemd[1]: first-boot-complete.target - First Boot Complete was skipped because of an unmet condition check (ConditionFirstBoot=yes). 392s Jul 22 12:01:38 autopkgtest systemd[1]: Listening on systemd-rfkill.socket - Load/Save RF Kill Switch Status /dev/rfkill Watch. 392s Jul 22 12:01:38 autopkgtest systemd[1]: systemd-machine-id-commit.service - Save Transient machine-id to Disk was skipped because of an unmet condition check (ConditionPathIsMountPoint=/etc/machine-id). 392s Jul 22 12:01:38 autopkgtest systemd[1]: Mounting proc-sys-fs-binfmt_misc.mount - Arbitrary Executable File Formats File System... 392s Jul 22 12:01:38 autopkgtest systemd[1]: Mounted proc-sys-fs-binfmt_misc.mount - Arbitrary Executable File Formats File System. 392s Jul 22 12:01:38 autopkgtest systemd[1]: Finished systemd-binfmt.service - Set Up Additional Binary Formats. 392s Jul 22 12:01:38 autopkgtest systemd[1]: Started systemd-timesyncd.service - Network Time Synchronization. 392s Jul 22 12:01:38 autopkgtest systemd[1]: Reached target time-set.target - System Time Set. 392s Jul 22 12:01:38 autopkgtest systemd-resolved[385]: Positive Trust Anchors: 392s Jul 22 12:01:38 autopkgtest systemd-resolved[385]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d 392s Jul 22 12:01:38 autopkgtest systemd-resolved[385]: Negative trust anchors: home.arpa 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 170.0.0.192.in-addr.arpa 171.0.0.192.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa ipv4only.arpa resolver.arpa corp home internal intranet lan local private test 392s Jul 22 12:01:38 autopkgtest systemd-resolved[385]: Using system hostname 'autopkgtest'. 392s Jul 22 12:01:38 autopkgtest systemd[1]: Started systemd-resolved.service - Network Name Resolution. 392s Jul 22 12:01:38 autopkgtest systemd[1]: Reached target nss-lookup.target - Host and Network Name Lookups. 392s Jul 22 12:01:38 autopkgtest cloud-init[664]: Cloud-init v. 24.3~1g6e4153b3-0ubuntu1 running 'init-local' at Mon, 22 Jul 2024 12:01:38 +0000. Up 4.66 seconds. 392s Jul 22 12:01:38 autopkgtest dhcpcd[667]: dhcpcd-10.0.8 starting 392s Jul 22 12:01:38 autopkgtest dhcpcd[670]: DUID 00:01:00:01:2e:30:ce:25:fa:16:3e:69:80:76 392s Jul 22 12:01:38 autopkgtest kernel: 8021q: 802.1Q VLAN Support v1.8 392s Jul 22 12:01:38 autopkgtest kernel: 8021q: adding VLAN 0 to HW filter on device enp0s1 392s Jul 22 12:01:39 autopkgtest kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database 392s Jul 22 12:01:39 autopkgtest kernel: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' 392s Jul 22 12:01:39 autopkgtest kernel: Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600' 392s Jul 22 12:01:39 autopkgtest dhcpcd[670]: enp0s1: IAID 3e:46:aa:7d 392s Jul 22 12:01:40 autopkgtest dhcpcd[670]: enp0s1: rebinding lease of 10.44.124.47 392s Jul 22 12:01:45 autopkgtest dhcpcd[670]: enp0s1: DHCP lease expired 392s Jul 22 12:01:45 autopkgtest dhcpcd[670]: enp0s1: soliciting a DHCP lease 392s Jul 22 12:01:45 autopkgtest dhcpcd[670]: enp0s1: offered 10.44.124.47 from 10.44.124.241 392s Jul 22 12:01:45 autopkgtest dhcpcd[670]: enp0s1: leased 10.44.124.47 for 86400 seconds 392s Jul 22 12:01:45 autopkgtest dhcpcd[670]: enp0s1: adding route to 10.44.124.0/24 392s Jul 22 12:01:45 autopkgtest dhcpcd[670]: enp0s1: adding host route to 169.254.169.254 via 10.44.124.1 392s Jul 22 12:01:45 autopkgtest dhcpcd[670]: enp0s1: adding default route via 10.44.124.1 392s Jul 22 12:01:45 autopkgtest dhcpcd[670]: control command: /usr/sbin/dhcpcd --dumplease --ipv4only enp0s1 392s Jul 22 12:01:48 autopkgtest systemd[1]: Finished cloud-init-local.service - Cloud-init: Local Stage (pre-network). 392s Jul 22 12:01:48 autopkgtest systemd[1]: Reached target network-pre.target - Preparation for Network. 392s Jul 22 12:01:48 autopkgtest systemd[1]: Starting systemd-networkd.service - Network Configuration... 392s Jul 22 12:01:48 autopkgtest systemd-networkd[700]: /run/systemd/network/10-netplan-enp0s1.network: MTUBytes= in [Link] section and UseMTU= in [DHCP] section are set. Disabling UseMTU=. 392s Jul 22 12:01:48 autopkgtest systemd-networkd[700]: lo: Link UP 392s Jul 22 12:01:48 autopkgtest systemd-networkd[700]: lo: Gained carrier 392s Jul 22 12:01:48 autopkgtest systemd-networkd[700]: Enumeration completed 392s Jul 22 12:01:48 autopkgtest systemd-networkd[700]: enp0s1: Link UP 392s Jul 22 12:01:48 autopkgtest systemd-networkd[700]: enp0s1: Gained carrier 392s Jul 22 12:01:48 autopkgtest systemd[1]: Started systemd-networkd.service - Network Configuration. 392s Jul 22 12:01:48 autopkgtest systemd-networkd[700]: enp0s1: Gained IPv6LL 392s Jul 22 12:01:48 autopkgtest systemd-networkd[700]: enp0s1: Link DOWN 392s Jul 22 12:01:48 autopkgtest systemd-networkd[700]: enp0s1: Lost carrier 392s Jul 22 12:01:48 autopkgtest systemd[1]: Reached target network.target - Network. 392s Jul 22 12:01:48 autopkgtest systemd-networkd[700]: enp0s1: Configuring with /run/systemd/network/10-netplan-enp0s1.network. 392s Jul 22 12:01:48 autopkgtest systemd[1]: Starting systemd-networkd-persistent-storage.service - Enable Persistent Storage in systemd-networkd... 392s Jul 22 12:01:48 autopkgtest systemd-networkd[700]: enp0s1: Link UP 392s Jul 22 12:01:48 autopkgtest systemd-networkd[700]: enp0s1: Gained carrier 392s Jul 22 12:01:48 autopkgtest kernel: 8021q: adding VLAN 0 to HW filter on device enp0s1 392s Jul 22 12:01:48 autopkgtest systemd[1]: Starting systemd-networkd-wait-online.service - Wait for Network to be Configured... 392s Jul 22 12:01:48 autopkgtest systemd[1]: Finished systemd-networkd-persistent-storage.service - Enable Persistent Storage in systemd-networkd. 392s Jul 22 12:01:48 autopkgtest systemd-networkd[700]: enp0s1: DHCPv4 address 10.44.124.47/24, gateway 10.44.124.1 acquired from 10.44.124.241 392s Jul 22 12:01:48 autopkgtest systemd-timesyncd[386]: Network configuration changed, trying to establish connection. 392s Jul 22 12:01:49 autopkgtest systemd-networkd[700]: enp0s1: Gained IPv6LL 392s Jul 22 12:01:49 autopkgtest systemd-timesyncd[386]: Network configuration changed, trying to establish connection. 392s Jul 22 12:01:49 autopkgtest systemd[1]: Finished systemd-networkd-wait-online.service - Wait for Network to be Configured. 392s Jul 22 12:01:49 autopkgtest systemd[1]: Starting cloud-init.service - Cloud-init: Network Stage... 392s Jul 22 12:01:49 autopkgtest systemd-timesyncd[386]: Contacted time server 185.125.190.57:123 (ntp.ubuntu.com). 392s Jul 22 12:01:49 autopkgtest systemd-timesyncd[386]: Initial clock synchronization to Mon 2024-07-22 12:01:49.719057 UTC. 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: Cloud-init v. 24.3~1g6e4153b3-0ubuntu1 running 'init' at Mon, 22 Jul 2024 12:01:50 +0000. Up 15.98 seconds. 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: +++++++++++++++++++++++++++++++++++++++Net device info+++++++++++++++++++++++++++++++++++++++ 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: +--------+------+------------------------------+---------------+--------+-------------------+ 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: | Device | Up | Address | Mask | Scope | Hw-Address | 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: +--------+------+------------------------------+---------------+--------+-------------------+ 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: | enp0s1 | True | 10.44.124.47 | 255.255.255.0 | global | fa:16:3e:46:aa:7d | 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: | enp0s1 | True | fe80::f816:3eff:fe46:aa7d/64 | . | link | fa:16:3e:46:aa:7d | 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: | lo | True | 127.0.0.1 | 255.0.0.0 | host | . | 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: | lo | True | ::1/128 | . | host | . | 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: +--------+------+------------------------------+---------------+--------+-------------------+ 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: ++++++++++++++++++++++++++++++++Route IPv4 info++++++++++++++++++++++++++++++++ 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: +-------+-----------------+-------------+-----------------+-----------+-------+ 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: | Route | Destination | Gateway | Genmask | Interface | Flags | 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: +-------+-----------------+-------------+-----------------+-----------+-------+ 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: | 0 | 0.0.0.0 | 10.44.124.1 | 0.0.0.0 | enp0s1 | UG | 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: | 1 | 10.44.124.0 | 0.0.0.0 | 255.255.255.0 | enp0s1 | U | 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: | 2 | 10.44.124.1 | 0.0.0.0 | 255.255.255.255 | enp0s1 | UH | 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: | 3 | 91.189.91.130 | 10.44.124.1 | 255.255.255.255 | enp0s1 | UGH | 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: | 4 | 169.254.169.254 | 10.44.124.1 | 255.255.255.255 | enp0s1 | UGH | 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: +-------+-----------------+-------------+-----------------+-----------+-------+ 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: +++++++++++++++++++Route IPv6 info+++++++++++++++++++ 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: +-------+-------------+---------+-----------+-------+ 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: | Route | Destination | Gateway | Interface | Flags | 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: +-------+-------------+---------+-----------+-------+ 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: | 0 | fe80::/64 | :: | enp0s1 | U | 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: | 2 | local | :: | enp0s1 | U | 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: | 3 | multicast | :: | enp0s1 | U | 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: ci-info: +-------+-------------+---------+-----------+-------+ 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: 2024-07-22 12:01:50,305 - log.py[DEPRECATED]: Deprecated cloud-config provided: apt_update: Deprecated in version 22.2. Use ``package_update`` instead., apt_upgrade: Deprecated in version 22.2. Use ``package_upgrade`` instead. 392s Jul 22 12:01:50 autopkgtest cloud-init[711]: 2024-07-22 12:01:50,305 - schema.py[WARNING]: cloud-config failed schema validation! You may run 'sudo cloud-init schema --system' to check the details. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Finished cloud-init.service - Cloud-init: Network Stage. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Reached target cloud-config.target - Cloud-config availability. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Reached target network-online.target - Network is Online. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Reached target sysinit.target - System Initialization. 392s Jul 22 12:01:50 autopkgtest systemd[1]: apport-autoreport.path - Process error reports when automatic reporting is enabled (file watch) was skipped because of an unmet condition check (ConditionPathExists=/var/lib/apport/autoreport). 392s Jul 22 12:01:50 autopkgtest systemd[1]: apport-autoreport.timer - Process error reports when automatic reporting is enabled (timer based) was skipped because of an unmet condition check (ConditionPathExists=/var/lib/apport/autoreport). 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started apt-daily.timer - Daily apt download activities. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started apt-daily-upgrade.timer - Daily apt upgrade and clean activities. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started dpkg-db-backup.timer - Daily dpkg database backup timer. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started e2scrub_all.timer - Periodic ext4 Online Metadata Check for All Filesystems. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started fstrim.timer - Discard unused filesystem blocks once a week. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started fwupd-refresh.timer - Refresh fwupd metadata regularly. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started logrotate.timer - Daily rotation of log files. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started man-db.timer - Daily man-db regeneration. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started motd-news.timer - Message of the Day. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started sysstat-collect.timer - Run system activity accounting tool every 10 minutes. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started sysstat-rotate.timer - Rotate daily system activity data file at midnight. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started sysstat-summary.timer - Generate summary of yesterday's process accounting. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started systemd-tmpfiles-clean.timer - Daily Cleanup of Temporary Directories. 392s Jul 22 12:01:50 autopkgtest systemd[1]: ua-timer.timer - Ubuntu Pro Timer for running repeated jobs was skipped because of an unmet condition check (ConditionPathExists=/var/lib/ubuntu-advantage/private/machine-token.json). 392s Jul 22 12:01:50 autopkgtest systemd[1]: Reached target boot-complete.target - Boot Completion Check. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Reached target paths.target - Path Units. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Reached target timers.target - Timer Units. 392s Jul 22 12:01:50 autopkgtest systemd[1]: apport-forward.socket - Unix socket for apport crash forwarding was skipped because of an unmet condition check (ConditionVirtualization=container). 392s Jul 22 12:01:50 autopkgtest systemd[1]: Listening on cloud-init-hotplugd.socket - cloud-init hotplug hook socket. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Listening on dbus.socket - D-Bus System Message Bus Socket. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Starting lxd-installer.socket - Helper to install lxd snap on demand... 392s Jul 22 12:01:50 autopkgtest systemd[1]: Listening on ssh.socket - OpenBSD Secure Shell server socket. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Listening on sshd-unix-local.socket - OpenSSH Server Socket (systemd-ssh-generator, AF_UNIX Local). 392s Jul 22 12:01:50 autopkgtest systemd[1]: Listening on sshd-vsock.socket - OpenSSH Server Socket (systemd-ssh-generator, AF_VSOCK). 392s Jul 22 12:01:50 autopkgtest systemd[1]: Reached target ssh-access.target - SSH Access Available. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Listening on systemd-hostnamed.socket - Hostname Service Socket. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Listening on uuidd.socket - UUID daemon activation socket. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Listening on lxd-installer.socket - Helper to install lxd snap on demand. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Reached target sockets.target - Socket Units. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Reached target basic.target - Basic System. 392s Jul 22 12:01:50 autopkgtest systemd[1]: System is tainted: unmerged-bin 392s Jul 22 12:01:50 autopkgtest systemd[1]: Starting apport.service - automatic crash report generation... 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started autopkgtest@hvc1.service - autopkgtest root shell on hvc1. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started autopkgtest@ttyS1.service - autopkgtest root shell on ttyS1. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Starting cloud-config.service - Cloud-init: Config Stage... 392s Jul 22 12:01:50 autopkgtest (sh)[747]: autopkgtest@ttyS1.service: Failed to set up standard input: Input/output error 392s Jul 22 12:01:50 autopkgtest (sh)[747]: autopkgtest@ttyS1.service: Failed at step STDIN spawning /bin/sh: Input/output error 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started cron.service - Regular background program processing daemon. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Starting dbus.service - D-Bus System Message Bus... 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started dmesg.service - Save initial kernel messages after boot. 392s Jul 22 12:01:50 autopkgtest (cron)[749]: cron.service: Referenced but unset environment variable evaluates to an empty string: EXTRA_OPTS 392s Jul 22 12:01:50 autopkgtest systemd[1]: Starting e2scrub_reap.service - Remove Stale Online ext4 Metadata Check Snapshots... 392s Jul 22 12:01:50 autopkgtest systemd[1]: getty-static.service - getty on tty2-tty6 if dbus and logind are not available was skipped because of an unmet condition check (ConditionPathExists=!/usr/bin/dbus-daemon). 392s Jul 22 12:01:50 autopkgtest cron[749]: (CRON) INFO (pidfile fd = 3) 392s Jul 22 12:01:50 autopkgtest systemd[1]: Starting grub-common.service - Record successful boot for GRUB... 392s Jul 22 12:01:50 autopkgtest systemd[1]: Starting iprdump.service - IBM Power Raid dump daemon... 392s Jul 22 12:01:50 autopkgtest cron[749]: (CRON) INFO (Running @reboot jobs) 392s Jul 22 12:01:50 autopkgtest systemd[1]: networkd-dispatcher.service - Dispatcher daemon for systemd-networkd was skipped because no trigger condition checks were met. 392s Jul 22 12:01:50 autopkgtest systemd[1]: opal_errd.service - opal_errd (PowerNV platform error handling) Service was skipped because of an unmet condition check (ConditionVirtualization=false). 392s Jul 22 12:01:50 autopkgtest systemd[1]: pollinate.service - Pollinate to seed the pseudo random number generator was skipped because of an unmet condition check (ConditionPathExists=!/var/cache/pollinate/seeded). 392s Jul 22 12:01:50 autopkgtest systemd[1]: Starting rc-local.service - /etc/rc.local Compatibility... 392s Jul 22 12:01:50 autopkgtest systemd[1]: Starting rng-tools-debian.service - LSB: rng-tools (Debian variant)... 392s Jul 22 12:01:50 autopkgtest systemd[1]: Starting rsyslog.service - System Logging Service... 392s Jul 22 12:01:50 autopkgtest systemd[1]: Starting rtas_errd.service - ppc64-diag rtas_errd (platform error handling) Service... 392s Jul 22 12:01:50 autopkgtest dbus-daemon[750]: [system] AppArmor D-Bus mediation is enabled 392s Jul 22 12:01:50 autopkgtest dbus-daemon[750]: [system] Activating systemd to hand-off: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.1' (uid=998 pid=700 comm="/usr/lib/systemd/systemd-networkd" label="unconfined") 392s Jul 22 12:01:50 autopkgtest systemd[1]: Starting sysstat.service - Resets System Activity Logs... 392s Jul 22 12:01:50 autopkgtest systemd[1]: Starting systemd-logind.service - User Login Management... 392s Jul 22 12:01:50 autopkgtest systemd[1]: Starting systemd-user-sessions.service - Permit User Sessions... 392s Jul 22 12:01:50 autopkgtest systemd[1]: ua-reboot-cmds.service - Ubuntu Pro reboot cmds was skipped because of an unmet condition check (ConditionPathExists=/var/lib/ubuntu-advantage/private/machine-token.json). 392s Jul 22 12:01:50 autopkgtest systemd[1]: ubuntu-advantage.service - Ubuntu Pro Background Auto Attach was skipped because no trigger condition checks were met. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Starting udisks2.service - Disk Manager... 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started dbus.service - D-Bus System Message Bus. 392s Jul 22 12:01:50 autopkgtest systemd[1]: autopkgtest@ttyS1.service: Deactivated successfully. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started iprdump.service - IBM Power Raid dump daemon. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Finished sysstat.service - Resets System Activity Logs. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Finished systemd-user-sessions.service - Permit User Sessions. 392s Jul 22 12:01:50 autopkgtest dbus-daemon[750]: [system] Successfully activated service 'org.freedesktop.systemd1' 392s Jul 22 12:01:50 autopkgtest systemd[1]: Starting iprinit.service - IBM Power Raid init daemon... 392s Jul 22 12:01:50 autopkgtest systemd[1]: Starting iprupdate.service - IBM Power Raid update daemon... 392s Jul 22 12:01:50 autopkgtest systemd[1]: Starting systemd-hostnamed.service - Hostname Service... 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started iprinit.service - IBM Power Raid init daemon. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started rc-local.service - /etc/rc.local Compatibility. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Starting plymouth-quit-wait.service - Hold until boot process finishes up... 392s Jul 22 12:01:50 autopkgtest systemd[1]: Starting plymouth-quit.service - Terminate Plymouth Boot Screen... 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started rtas_errd.service - ppc64-diag rtas_errd (platform error handling) Service. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started iprupdate.service - IBM Power Raid update daemon. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Reached target iprutils.target - IBM Power Raid utilities. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started serial-getty@hvc0.service - Serial Getty on hvc0. 392s Jul 22 12:01:50 autopkgtest udisksd[767]: udisks daemon version 2.10.1 starting 392s Jul 22 12:01:50 autopkgtest systemd[1]: Starting setvtrgb.service - Set console scheme... 392s Jul 22 12:01:50 autopkgtest systemd[1]: grub-common.service: Deactivated successfully. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Finished grub-common.service - Record successful boot for GRUB. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Starting grub-initrd-fallback.service - GRUB failed boot detection... 392s Jul 22 12:01:50 autopkgtest rng-tools-debian[809]: found /dev/hwrng but could not use it 392s Jul 22 12:01:50 autopkgtest systemd[1]: Finished plymouth-quit.service - Terminate Plymouth Boot Screen. 392s Jul 22 12:01:50 autopkgtest rng-tools-debian[810]: not starting: no hardware RNG device found 392s Jul 22 12:01:50 autopkgtest rng-tools-debian[758]: * Configuring Hardware RNG entropy gatherer daemon 392s Jul 22 12:01:50 autopkgtest rng-tools-debian[758]: ...fail! 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started rng-tools-debian.service - LSB: rng-tools (Debian variant). 392s Jul 22 12:01:50 autopkgtest systemd[1]: Finished setvtrgb.service - Set console scheme. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Created slice system-getty.slice - Slice /system/getty. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started getty@tty1.service - Getty on tty1. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Reached target getty.target - Login Prompts. 392s Jul 22 12:01:50 autopkgtest systemd-logind[764]: New seat seat0. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started systemd-logind.service - User Login Management. 392s Jul 22 12:01:50 autopkgtest systemd[1]: grub-initrd-fallback.service: Deactivated successfully. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Finished grub-initrd-fallback.service - GRUB failed boot detection. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started systemd-hostnamed.service - Hostname Service. 392s Jul 22 12:01:50 autopkgtest dbus-daemon[750]: [system] Successfully activated service 'org.freedesktop.hostname1' 392s Jul 22 12:01:50 autopkgtest systemd-networkd[700]: Could not set hostname: Access denied 392s Jul 22 12:01:50 autopkgtest udisksd[767]: Acquired the name org.freedesktop.UDisks2 on the system message bus 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started udisks2.service - Disk Manager. 392s Jul 22 12:01:50 autopkgtest kernel: kauditd_printk_skb: 110 callbacks suppressed 392s Jul 22 12:01:50 autopkgtest kernel: audit: type=1400 audit(1721649710.795:121): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="rsyslogd" pid=815 comm="apparmor_parser" 392s Jul 22 12:01:50 autopkgtest systemd[1]: e2scrub_reap.service: Deactivated successfully. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Finished e2scrub_reap.service - Remove Stale Online ext4 Metadata Check Snapshots. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Finished apport.service - automatic crash report generation. 392s Jul 22 12:01:50 autopkgtest rsyslogd[836]: imuxsock: Acquired UNIX socket '/run/systemd/journal/syslog' (fd 3) from systemd. [v8.2312.0] 392s Jul 22 12:01:50 autopkgtest systemd[1]: Started rsyslog.service - System Logging Service. 392s Jul 22 12:01:50 autopkgtest rsyslogd[836]: rsyslogd's groupid changed to 102 392s Jul 22 12:01:50 autopkgtest rsyslogd[836]: rsyslogd's userid changed to 102 392s Jul 22 12:01:50 autopkgtest rsyslogd[836]: [origin software="rsyslogd" swVersion="8.2312.0" x-pid="836" x-info="https://www.rsyslog.com"] start 392s Jul 22 12:01:50 autopkgtest systemd[1]: Reached target multi-user.target - Multi-User System. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Reached target graphical.target - Graphical Interface. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... 392s Jul 22 12:01:50 autopkgtest systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. 392s Jul 22 12:01:50 autopkgtest systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. 392s Jul 22 12:01:50 autopkgtest cloud-init[851]: Cloud-init v. 24.3~1g6e4153b3-0ubuntu1 running 'modules:config' at Mon, 22 Jul 2024 12:01:50 +0000. Up 16.71 seconds. 392s Jul 22 12:01:51 autopkgtest systemd[1]: Finished cloud-config.service - Cloud-init: Config Stage. 392s Jul 22 12:01:51 autopkgtest systemd[1]: Starting cloud-final.service - Cloud-init: Final Stage... 392s Jul 22 12:01:51 autopkgtest systemd[1]: Starting ssh.service - OpenBSD Secure Shell server... 392s Jul 22 12:01:51 autopkgtest sshd[856]: Server listening on :: port 22. 392s Jul 22 12:01:51 autopkgtest systemd[1]: Started ssh.service - OpenBSD Secure Shell server. 392s Jul 22 12:01:51 autopkgtest cloud-init[863]: Cloud-init v. 24.3~1g6e4153b3-0ubuntu1 running 'modules:final' at Mon, 22 Jul 2024 12:01:51 +0000. Up 17.17 seconds. 392s Jul 22 12:01:51 autopkgtest cloud-init[863]: Cloud-init v. 24.3~1g6e4153b3-0ubuntu1 finished at Mon, 22 Jul 2024 12:01:51 +0000. Datasource DataSourceOpenStackLocal [net,ver=2]. Up 17.28 seconds 392s Jul 22 12:01:51 autopkgtest systemd[1]: Finished cloud-final.service - Cloud-init: Final Stage. 392s Jul 22 12:01:51 autopkgtest systemd[1]: Reached target cloud-init.target - Cloud-init target. 392s Jul 22 12:01:51 autopkgtest systemd[1]: Startup finished in 2.868s (kernel) + 14.460s (userspace) = 17.328s. 392s Jul 22 12:01:51 autopkgtest kernel: fbcon: Taking over console 392s Jul 22 12:01:51 autopkgtest systemd[1]: dmesg.service: Deactivated successfully. 392s Jul 22 12:01:51 autopkgtest sshd[858]: Accepted publickey for ubuntu from 10.136.6.201 port 59938 ssh2: RSA SHA256:YaYyKWTl9zFJEBK5G3u+MRj3WPJt+vEplFd0J96PUBw 392s Jul 22 12:01:51 autopkgtest sshd[858]: pam_unix(sshd:session): session opened for user ubuntu(uid=1000) by ubuntu(uid=0) 392s Jul 22 12:01:51 autopkgtest sshd[858]: pam_systemd(sshd:session): New sd-bus connection (system-bus-pam-systemd-858) opened. 392s Jul 22 12:01:51 autopkgtest systemd[1]: Created slice user-1000.slice - User Slice of UID 1000. 392s Jul 22 12:01:51 autopkgtest systemd[1]: Starting user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... 392s Jul 22 12:01:51 autopkgtest systemd-logind[764]: New session 1 of user ubuntu. 392s Jul 22 12:01:51 autopkgtest systemd[1]: Finished user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. 392s Jul 22 12:01:51 autopkgtest systemd[1]: Starting user@1000.service - User Manager for UID 1000... 392s Jul 22 12:01:51 autopkgtest (systemd)[888]: pam_unix(systemd-user:session): session opened for user ubuntu(uid=1000) by ubuntu(uid=0) 392s Jul 22 12:01:51 autopkgtest systemd-logind[764]: New session 2 of user ubuntu. 392s Jul 22 12:01:52 autopkgtest systemd[888]: Queued start job for default target default.target. 392s Jul 22 12:01:52 autopkgtest systemd[888]: Created slice app.slice - User Application Slice. 392s Jul 22 12:01:52 autopkgtest systemd[888]: Started launchpadlib-cache-clean.timer - Clean up old files in the Launchpadlib cache. 392s Jul 22 12:01:52 autopkgtest systemd[888]: Reached target paths.target - Paths. 392s Jul 22 12:01:52 autopkgtest systemd[888]: Reached target timers.target - Timers. 392s Jul 22 12:01:52 autopkgtest systemd[888]: Starting dbus.socket - D-Bus User Message Bus Socket... 392s Jul 22 12:01:52 autopkgtest systemd[888]: Listening on dirmngr.socket - GnuPG network certificate management daemon. 392s Jul 22 12:01:52 autopkgtest systemd[888]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). 392s Jul 22 12:01:52 autopkgtest systemd[888]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). 392s Jul 22 12:01:52 autopkgtest systemd[888]: Starting gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation)... 392s Jul 22 12:01:52 autopkgtest systemd[888]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. 392s Jul 22 12:01:52 autopkgtest systemd[888]: Listening on keyboxd.socket - GnuPG public key management service. 392s Jul 22 12:01:52 autopkgtest systemd[888]: Listening on dbus.socket - D-Bus User Message Bus Socket. 392s Jul 22 12:01:52 autopkgtest systemd[888]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). 392s Jul 22 12:01:52 autopkgtest systemd[888]: Reached target sockets.target - Sockets. 392s Jul 22 12:01:52 autopkgtest systemd[888]: Reached target basic.target - Basic System. 392s Jul 22 12:01:52 autopkgtest systemd[888]: Reached target default.target - Main User Target. 392s Jul 22 12:01:52 autopkgtest systemd[888]: Startup finished in 228ms. 392s Jul 22 12:01:52 autopkgtest systemd[1]: Started user@1000.service - User Manager for UID 1000. 392s Jul 22 12:01:52 autopkgtest systemd[1]: Started session-1.scope - Session 1 of User ubuntu. 392s Jul 22 12:01:52 autopkgtest sudo[916]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/bin/true 392s Jul 22 12:01:52 autopkgtest sudo[916]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:52 autopkgtest sudo[916]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:52 autopkgtest sudo[921]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper /bin/sh -ec 'for d in /var/cache /home; do if [ -e $d/autopkgtest-tmpdir.tar ]; then /bin/tar --warning=none --extract --absolute-names -f $d/autopkgtest-tmpdir.tar; /bin/rm $d/autopkgtest-tmpdir.tar; exit 0; fi; done; exit 1' 392s Jul 22 12:01:52 autopkgtest sudo[921]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:52 autopkgtest sudo[921]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:53 autopkgtest sudo[933]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper mkdir -p /tmp/autopkgtest.HPnGkO 392s Jul 22 12:01:53 autopkgtest sudo[933]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:53 autopkgtest sudo[933]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:53 autopkgtest sudo[943]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat >/tmp/autopkgtest.HPnGkO/autopkgtest-reboot; chmod +x -- /tmp/autopkgtest.HPnGkO/autopkgtest-reboot' 392s Jul 22 12:01:53 autopkgtest sudo[943]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:53 autopkgtest sudo[943]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:53 autopkgtest sudo[955]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chmod -R 0755 -- /tmp/autopkgtest.HPnGkO/autopkgtest-reboot 392s Jul 22 12:01:53 autopkgtest sudo[955]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:53 autopkgtest sudo[955]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:53 autopkgtest sudo[965]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper ln -fns /tmp/autopkgtest.HPnGkO/autopkgtest-reboot /tmp/autopkgtest-reboot 392s Jul 22 12:01:53 autopkgtest sudo[965]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:53 autopkgtest sudo[965]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:53 autopkgtest sudo[975]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper ln -fns /tmp/autopkgtest.HPnGkO/autopkgtest-reboot /sbin/autopkgtest-reboot 392s Jul 22 12:01:53 autopkgtest sudo[975]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:53 autopkgtest sudo[975]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:54 autopkgtest sudo[985]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper mkdir -p /tmp/autopkgtest.HPnGkO 392s Jul 22 12:01:54 autopkgtest sudo[985]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:54 autopkgtest sudo[985]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:54 autopkgtest sudo[995]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat >/tmp/autopkgtest.HPnGkO/autopkgtest-reboot-prepare; chmod +x -- /tmp/autopkgtest.HPnGkO/autopkgtest-reboot-prepare' 392s Jul 22 12:01:54 autopkgtest sudo[995]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:54 autopkgtest sudo[995]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:54 autopkgtest sudo[1007]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chmod -R 0755 -- /tmp/autopkgtest.HPnGkO/autopkgtest-reboot-prepare 392s Jul 22 12:01:54 autopkgtest sudo[1007]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:54 autopkgtest sudo[1007]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:54 autopkgtest sudo[1017]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper ln -fns /tmp/autopkgtest.HPnGkO/autopkgtest-reboot-prepare /tmp/autopkgtest-reboot-prepare 392s Jul 22 12:01:54 autopkgtest sudo[1017]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:54 autopkgtest sudo[1017]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:54 autopkgtest sudo[1027]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper uname -srv 392s Jul 22 12:01:54 autopkgtest sudo[1027]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:54 autopkgtest sudo[1027]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:55 autopkgtest sudo[1037]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'command -v eatmydata' 392s Jul 22 12:01:55 autopkgtest sudo[1037]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:55 autopkgtest sudo[1037]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:55 autopkgtest sudo[1047]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'dpkg-query --show -f \'${Package}\\t${Version}\\n\' > /tmp/autopkgtest.HPnGkO/testbed-packages' 392s Jul 22 12:01:55 autopkgtest sudo[1047]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:55 autopkgtest sudo[1047]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:55 autopkgtest sudo[1058]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat /tmp/autopkgtest.HPnGkO/autopkgtest-reboot; chmod +x -- /tmp/autopkgtest.HPnGkO/autopkgtest-reboot' 392s Jul 22 12:01:55 autopkgtest sudo[1079]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:55 autopkgtest sudo[1079]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:56 autopkgtest sudo[1092]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chmod -R 0755 -- /tmp/autopkgtest.HPnGkO/autopkgtest-reboot 392s Jul 22 12:01:56 autopkgtest sudo[1092]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:56 autopkgtest sudo[1092]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:56 autopkgtest sudo[1102]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper ln -fns /tmp/autopkgtest.HPnGkO/autopkgtest-reboot /tmp/autopkgtest-reboot 392s Jul 22 12:01:56 autopkgtest sudo[1102]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:56 autopkgtest sudo[1102]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:56 autopkgtest sudo[1112]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper ln -fns /tmp/autopkgtest.HPnGkO/autopkgtest-reboot /sbin/autopkgtest-reboot 392s Jul 22 12:01:56 autopkgtest sudo[1112]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:56 autopkgtest sudo[1112]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:56 autopkgtest sudo[1122]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper mkdir -p /tmp/autopkgtest.HPnGkO 392s Jul 22 12:01:56 autopkgtest sudo[1122]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:56 autopkgtest sudo[1122]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:56 autopkgtest sudo[1132]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat >/tmp/autopkgtest.HPnGkO/autopkgtest-reboot-prepare; chmod +x -- /tmp/autopkgtest.HPnGkO/autopkgtest-reboot-prepare' 392s Jul 22 12:01:56 autopkgtest sudo[1132]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:56 autopkgtest sudo[1132]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:57 autopkgtest sudo[1144]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chmod -R 0755 -- /tmp/autopkgtest.HPnGkO/autopkgtest-reboot-prepare 392s Jul 22 12:01:57 autopkgtest sudo[1144]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:57 autopkgtest sudo[1144]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:57 autopkgtest sudo[1154]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper ln -fns /tmp/autopkgtest.HPnGkO/autopkgtest-reboot-prepare /tmp/autopkgtest-reboot-prepare 392s Jul 22 12:01:57 autopkgtest sudo[1154]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:57 autopkgtest sudo[1154]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:57 autopkgtest sudo[1164]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper uname -srv 392s Jul 22 12:01:57 autopkgtest sudo[1164]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:57 autopkgtest sudo[1164]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:57 autopkgtest sudo[1174]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper test -w /var/lib/dpkg/status 392s Jul 22 12:01:57 autopkgtest sudo[1174]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:57 autopkgtest sudo[1174]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:57 autopkgtest sudo[1183]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper mkdir -p /tmp/autopkgtest.HPnGkO 392s Jul 22 12:01:57 autopkgtest sudo[1183]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:57 autopkgtest sudo[1183]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:57 autopkgtest sudo[1193]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat >/tmp/autopkgtest.HPnGkO/2-autopkgtest-satdep.deb' 392s Jul 22 12:01:57 autopkgtest sudo[1193]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:58 autopkgtest sudo[1193]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:58 autopkgtest sudo[1204]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chown -R ubuntu -- /tmp/autopkgtest.HPnGkO/2-autopkgtest-satdep.deb 392s Jul 22 12:01:58 autopkgtest sudo[1204]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:01:58 autopkgtest sudo[1204]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:01:58 autopkgtest sudo[1214]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper env DEBIAN_FRONTEND=noninteractive APT_LISTBUGS_FRONTEND=none APT_LISTCHANGES_FRONTEND=none /bin/sh -ec '/usr/bin/eatmydata apt-get install --assume-yes /tmp/autopkgtest.HPnGkO/2-autopkgtest-satdep.deb -o APT::Status-Fd=3 -o APT::Install-Recommends=false -o Dpkg::Options::=--force-confnew -o Debug::pkgProblemResolver=true 3>&2 2>&1' 392s Jul 22 12:01:58 autopkgtest sudo[1214]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:02:02 autopkgtest systemd[1]: Reload requested from client PID 1454 ('systemctl') (unit session-1.scope)... 392s Jul 22 12:02:02 autopkgtest systemd[1]: Reloading... 392s Jul 22 12:02:02 autopkgtest systemd[1]: Configuration file /run/systemd/system/systemd-networkd-wait-online.service.d/10-netplan.conf is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. 392s Jul 22 12:02:02 autopkgtest systemd[1]: Configuration file /run/systemd/system/netplan-ovs-cleanup.service is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. 392s Jul 22 12:02:02 autopkgtest systemd[1]: Reloading finished in 258 ms. 392s Jul 22 12:02:02 autopkgtest systemd[1]: Reload requested from client PID 1504 ('systemctl') (unit session-1.scope)... 392s Jul 22 12:02:02 autopkgtest systemd[1]: Reloading... 392s Jul 22 12:02:02 autopkgtest systemd[1]: Configuration file /run/systemd/system/systemd-networkd-wait-online.service.d/10-netplan.conf is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. 392s Jul 22 12:02:02 autopkgtest systemd[1]: Configuration file /run/systemd/system/netplan-ovs-cleanup.service is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. 392s Jul 22 12:02:02 autopkgtest systemd[1]: Reloading finished in 230 ms. 392s Jul 22 12:02:02 autopkgtest systemd[1]: Starting tgt.service - (i)SCSI target daemon... 392s Jul 22 12:02:02 autopkgtest tgtd[1550]: tgtd: iser_ib_init(3431) Failed to initialize RDMA; load kernel modules? 392s Jul 22 12:02:02 autopkgtest tgtd[1550]: tgtd: work_timer_start(146) use timer_fd based scheduler 392s Jul 22 12:02:02 autopkgtest tgtd[1550]: tgtd: bs_init(387) use signalfd notification 392s Jul 22 12:02:03 autopkgtest systemd[1]: Started tgt.service - (i)SCSI target daemon. 392s Jul 22 12:02:03 autopkgtest systemd[1]: Reload requested from client PID 1577 ('systemctl') (unit session-1.scope)... 392s Jul 22 12:02:03 autopkgtest systemd[1]: Reloading... 392s Jul 22 12:02:03 autopkgtest systemd[1]: Configuration file /run/systemd/system/systemd-networkd-wait-online.service.d/10-netplan.conf is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. 392s Jul 22 12:02:03 autopkgtest systemd[1]: Configuration file /run/systemd/system/netplan-ovs-cleanup.service is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. 392s Jul 22 12:02:03 autopkgtest systemd[1]: Reloading finished in 230 ms. 392s Jul 22 12:02:03 autopkgtest systemd[1]: Reload requested from client PID 1620 ('systemctl') (unit session-1.scope)... 392s Jul 22 12:02:03 autopkgtest systemd[1]: Reloading... 392s Jul 22 12:02:03 autopkgtest systemd[1]: Configuration file /run/systemd/system/systemd-networkd-wait-online.service.d/10-netplan.conf is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. 392s Jul 22 12:02:03 autopkgtest systemd[1]: Configuration file /run/systemd/system/netplan-ovs-cleanup.service is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. 392s Jul 22 12:02:03 autopkgtest systemd[1]: Reloading finished in 322 ms. 392s Jul 22 12:02:03 autopkgtest systemd[1]: Reload requested from client PID 1666 ('systemctl') (unit session-1.scope)... 392s Jul 22 12:02:03 autopkgtest systemd[1]: Reloading... 392s Jul 22 12:02:04 autopkgtest systemd[1]: Configuration file /run/systemd/system/systemd-networkd-wait-online.service.d/10-netplan.conf is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. 392s Jul 22 12:02:04 autopkgtest systemd[1]: Configuration file /run/systemd/system/netplan-ovs-cleanup.service is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. 392s Jul 22 12:02:04 autopkgtest systemd[1]: Reloading finished in 229 ms. 392s Jul 22 12:02:04 autopkgtest systemd[1]: Listening on iscsid.socket - Open-iSCSI iscsid Socket. 392s Jul 22 12:02:04 autopkgtest systemd[1]: Reload requested from client PID 1717 ('systemctl') (unit session-1.scope)... 392s Jul 22 12:02:04 autopkgtest systemd[1]: Reloading... 392s Jul 22 12:02:04 autopkgtest systemd[1]: Configuration file /run/systemd/system/systemd-networkd-wait-online.service.d/10-netplan.conf is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. 392s Jul 22 12:02:04 autopkgtest systemd[1]: Configuration file /run/systemd/system/netplan-ovs-cleanup.service is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. 392s Jul 22 12:02:04 autopkgtest systemd[1]: Reloading finished in 216 ms. 392s Jul 22 12:02:04 autopkgtest systemd[1]: open-iscsi.service - Login to default iSCSI targets was skipped because no trigger condition checks were met. 392s Jul 22 12:02:04 autopkgtest systemd[1]: Reached target remote-fs-pre.target - Preparation for Remote File Systems. 392s Jul 22 12:02:04 autopkgtest systemd[1]: Reload requested from client PID 1772 ('systemctl') (unit session-1.scope)... 392s Jul 22 12:02:04 autopkgtest systemd[1]: Reloading... 392s Jul 22 12:02:04 autopkgtest systemd[1]: Configuration file /run/systemd/system/systemd-networkd-wait-online.service.d/10-netplan.conf is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. 392s Jul 22 12:02:04 autopkgtest systemd[1]: Configuration file /run/systemd/system/netplan-ovs-cleanup.service is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. 392s Jul 22 12:02:04 autopkgtest systemd[1]: Reloading finished in 247 ms. 392s Jul 22 12:02:17 autopkgtest sudo[1214]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:02:17 autopkgtest sudo[5253]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper dpkg-query --show -f ${Status} multipath-tools 392s Jul 22 12:02:17 autopkgtest sudo[5253]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:02:17 autopkgtest sudo[5253]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:02:17 autopkgtest sudo[5263]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper dpkg --status autopkgtest-satdep 392s Jul 22 12:02:17 autopkgtest sudo[5263]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:02:17 autopkgtest sudo[5263]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:02:18 autopkgtest sudo[5273]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper apt-get --simulate --quiet -o APT::Get::Show-User-Simulation-Note=False --auto-remove purge autopkgtest-satdep 392s Jul 22 12:02:18 autopkgtest sudo[5273]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:02:18 autopkgtest sudo[5273]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:02:19 autopkgtest sudo[5286]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper apt-mark manual -qq fio librbd1 librados2 libboost-iostreams1.83.0 libboost-thread1.83.0 tgt libconfig-general-perl libpmemobj1 libpmem1 libndctl6 libdaxctl1 libgfapi0 libgfrpc0 libgfxdr0 libglusterfs0 open-iscsi libisns0t64 libnbd0 libopeniscsiusr librdmacm1t64 392s Jul 22 12:02:19 autopkgtest sudo[5286]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:02:19 autopkgtest sudo[5286]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:02:19 autopkgtest sudo[5298]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper apt-mark manual -qq lsscsi 392s Jul 22 12:02:19 autopkgtest sudo[5298]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:02:19 autopkgtest sudo[5298]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:02:19 autopkgtest sudo[5310]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper dpkg --purge autopkgtest-satdep 392s Jul 22 12:02:19 autopkgtest sudo[5310]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:02:19 autopkgtest sudo[5310]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:02:20 autopkgtest sudo[5320]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'dpkg-query --show -f \'${Package}\\t${Version}\\n\' > /tmp/autopkgtest.HPnGkO/tgtbasedmpaths-packages.all' 392s Jul 22 12:02:20 autopkgtest sudo[5320]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 392s Jul 22 12:02:20 autopkgtest sudo[5320]: pam_unix(sudo:session): session closed for user root 392s Jul 22 12:02:20 autopkgtest sudo[5331]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat