0s autopkgtest [10:37:10]: starting date and time: 2024-09-10 10:37:10+0000 0s autopkgtest [10:37:10]: git checkout: fd3bed09 nova: allow more retries for quota issues 0s autopkgtest [10:37:10]: host juju-7f2275-prod-proposed-migration-environment-3; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.2kww9pu6/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:qemu --apt-upgrade multipath-tools --timeout-short=300 --timeout-copy=20000 --timeout-test=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=qemu/1:9.0.2+ds-4ubuntu4 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest-big-ppc64el --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-3@bos03-ppc64el-12.secgroup --name adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f2275-prod-proposed-migration-environment-3-fa7e7b7f-cef9-4c0b-b59c-2e76e27367e4 --image adt/ubuntu-oracular-ppc64el-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-3 --net-id=net_prod-proposed-migration-ppc64el -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/ 117s autopkgtest [10:39:07]: testbed dpkg architecture: ppc64el 117s autopkgtest [10:39:07]: testbed apt version: 2.9.8 117s autopkgtest [10:39:07]: @@@@@@@@@@@@@@@@@@@@ test bed setup 118s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [126 kB] 119s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [6600 B] 119s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [44.6 kB] 119s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [632 kB] 119s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [8424 B] 119s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el Packages [69.2 kB] 119s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el c-n-f Metadata [1928 B] 119s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el Packages [1372 B] 119s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el c-n-f Metadata [120 B] 119s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el Packages [618 kB] 119s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el c-n-f Metadata [15.0 kB] 119s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el Packages [3280 B] 119s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el c-n-f Metadata [340 B] 121s Fetched 1527 kB in 1s (1700 kB/s) 121s Reading package lists... 124s Reading package lists... 124s Building dependency tree... 124s Reading state information... 124s Calculating upgrade... 124s The following packages will be upgraded: 124s libselinux1 libsemanage-common libsemanage2 124s 3 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 124s Need to get 224 kB of archives. 124s After this operation, 0 B of additional disk space will be used. 124s Get:1 http://ftpmaster.internal/ubuntu oracular/main ppc64el libselinux1 ppc64el 3.5-2ubuntu5 [99.0 kB] 125s Get:2 http://ftpmaster.internal/ubuntu oracular/main ppc64el libsemanage-common all 3.5-1build6 [10.2 kB] 125s Get:3 http://ftpmaster.internal/ubuntu oracular/main ppc64el libsemanage2 ppc64el 3.5-1build6 [115 kB] 125s Fetched 224 kB in 0s (463 kB/s) 125s (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 ... 72411 files and directories currently installed.) 125s Preparing to unpack .../libselinux1_3.5-2ubuntu5_ppc64el.deb ... 125s Unpacking libselinux1:ppc64el (3.5-2ubuntu5) over (3.5-2ubuntu2) ... 125s Setting up libselinux1:ppc64el (3.5-2ubuntu5) ... 125s (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 ... 72411 files and directories currently installed.) 125s Preparing to unpack .../libsemanage-common_3.5-1build6_all.deb ... 125s Unpacking libsemanage-common (3.5-1build6) over (3.5-1build5) ... 125s Setting up libsemanage-common (3.5-1build6) ... 125s (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 ... 72411 files and directories currently installed.) 125s Preparing to unpack .../libsemanage2_3.5-1build6_ppc64el.deb ... 125s Unpacking libsemanage2:ppc64el (3.5-1build6) over (3.5-1build5) ... 125s Setting up libsemanage2:ppc64el (3.5-1build6) ... 125s Processing triggers for man-db (2.12.1-3) ... 126s Processing triggers for libc-bin (2.40-1ubuntu1) ... 126s Reading package lists... 126s Building dependency tree... 126s Reading state information... 126s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 127s Hit:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease 127s Hit:2 http://ftpmaster.internal/ubuntu oracular InRelease 127s Hit:3 http://ftpmaster.internal/ubuntu oracular-updates InRelease 127s Hit:4 http://ftpmaster.internal/ubuntu oracular-security InRelease 128s Reading package lists... 128s Reading package lists... 128s Building dependency tree... 128s Reading state information... 128s Calculating upgrade... 128s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 128s Reading package lists... 128s Building dependency tree... 128s Reading state information... 129s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 132s autopkgtest [10:39:22]: testbed running kernel: Linux 6.8.0-31-generic #31-Ubuntu SMP Sat Apr 20 00:05:55 UTC 2024 132s autopkgtest [10:39:22]: @@@@@@@@@@@@@@@@@@@@ apt-source multipath-tools 134s Get:1 http://ftpmaster.internal/ubuntu oracular/main multipath-tools 0.9.9-1ubuntu3 (dsc) [2772 B] 134s Get:2 http://ftpmaster.internal/ubuntu oracular/main multipath-tools 0.9.9-1ubuntu3 (tar) [588 kB] 134s Get:3 http://ftpmaster.internal/ubuntu oracular/main multipath-tools 0.9.9-1ubuntu3 (diff) [42.7 kB] 135s gpgv: Signature made Thu Sep 5 17:42:16 2024 UTC 135s gpgv: using RSA key 63EEFC3DE14D5146CE7F24BF34B8AD7D9529E793 135s gpgv: Can't check signature: No public key 135s dpkg-source: warning: cannot verify inline signature for ./multipath-tools_0.9.9-1ubuntu3.dsc: no acceptable signature found 135s autopkgtest [10:39:25]: testing package multipath-tools version 0.9.9-1ubuntu3 135s initramfs SKIP Test lists explicitly supported architectures, but the current architecture ppc64el isn't listed. 135s autopkgtest [10:39:25]: build not needed 136s autopkgtest [10:39:26]: test kpartx-file-loopback: preparing testbed 136s initramfs SKIP Test lists explicitly supported architectures, but the current architecture ppc64el isn't listed. 137s Reading package lists... 137s Building dependency tree... 137s Reading state information... 137s Starting pkgProblemResolver with broken count: 0 137s Starting 2 pkgProblemResolver with broken count: 0 137s Done 137s The following additional packages will be installed: 137s liburing2 qemu-utils 137s Recommended packages: 137s qemu-block-extra 137s The following NEW packages will be installed: 137s autopkgtest-satdep liburing2 qemu-utils 137s 0 upgraded, 3 newly installed, 0 to remove and 0 not upgraded. 137s Need to get 2432 kB/2433 kB of archives. 137s After this operation, 16.9 MB of additional disk space will be used. 137s Get:1 /tmp/autopkgtest.2MkHZe/1-autopkgtest-satdep.deb autopkgtest-satdep ppc64el 0 [720 B] 138s Get:2 http://ftpmaster.internal/ubuntu oracular/main ppc64el liburing2 ppc64el 2.6-1 [26.9 kB] 138s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el qemu-utils ppc64el 1:9.0.2+ds-4ubuntu4 [2405 kB] 138s Fetched 2432 kB in 1s (3528 kB/s) 138s Selecting previously unselected package liburing2:ppc64el. 138s (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 ... 72411 files and directories currently installed.) 138s Preparing to unpack .../liburing2_2.6-1_ppc64el.deb ... 138s Unpacking liburing2:ppc64el (2.6-1) ... 138s Selecting previously unselected package qemu-utils. 138s Preparing to unpack .../qemu-utils_1%3a9.0.2+ds-4ubuntu4_ppc64el.deb ... 138s Unpacking qemu-utils (1:9.0.2+ds-4ubuntu4) ... 139s Selecting previously unselected package autopkgtest-satdep. 139s Preparing to unpack .../1-autopkgtest-satdep.deb ... 139s Unpacking autopkgtest-satdep (0) ... 139s Setting up liburing2:ppc64el (2.6-1) ... 139s Setting up qemu-utils (1:9.0.2+ds-4ubuntu4) ... 139s Setting up autopkgtest-satdep (0) ... 139s Processing triggers for man-db (2.12.1-3) ... 140s Processing triggers for libc-bin (2.40-1ubuntu1) ... 142s (Reading database ... 72435 files and directories currently installed.) 142s Removing autopkgtest-satdep (0) ... 142s autopkgtest [10:39:32]: test kpartx-file-loopback: [----------------------- 143s Formatting 'foo.img', fmt=raw size=20971520 144s Creating new GPT entries in memory. 144s Warning: The kernel is still using the old partition table. 144s The new table will be used at the next reboot or after you 144s run partprobe(8) or kpartx(8) 144s The operation has completed successfully. 144s add map loop0p1 (252:0): 0 38879 linear 7:0 2048 144s standard_filename: OK 144s del devmap : loop0p1 144s No devices found 144s standard_filename_cleanup: OK 144s Formatting 'fou du FaFa.img', fmt=raw size=20971520 145s Creating new GPT entries in memory. 145s Warning: The kernel is still using the old partition table. 145s The new table will be used at the next reboot or after you 145s run partprobe(8) or kpartx(8) 145s The operation has completed successfully. 145s add map loop0p1 (252:0): 0 38879 linear 7:0 2048 145s filename_with_spaces: OK 145s del devmap : loop0p1 145s No devices found 145s filename_with_spaces_cleanup: OK 145s autopkgtest [10:39:35]: test kpartx-file-loopback: -----------------------] 146s autopkgtest [10:39:36]: test kpartx-file-loopback: - - - - - - - - - - results - - - - - - - - - - 146s kpartx-file-loopback PASS 146s autopkgtest [10:39:36]: test tgtbasedmpaths: preparing testbed 292s autopkgtest [10:42:02]: testbed dpkg architecture: ppc64el 292s autopkgtest [10:42:02]: testbed apt version: 2.9.8 292s autopkgtest [10:42:02]: @@@@@@@@@@@@@@@@@@@@ test bed setup 293s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [126 kB] 293s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [6600 B] 293s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [8424 B] 293s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [44.6 kB] 293s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [632 kB] 293s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el Packages [69.2 kB] 293s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el c-n-f Metadata [1928 B] 293s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el Packages [1372 B] 293s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el c-n-f Metadata [120 B] 293s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el Packages [618 kB] 293s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el c-n-f Metadata [15.0 kB] 293s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el Packages [3280 B] 293s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el c-n-f Metadata [340 B] 296s Fetched 1527 kB in 1s (1481 kB/s) 296s Reading package lists... 299s Reading package lists... 299s Building dependency tree... 299s Reading state information... 300s Calculating upgrade... 300s The following packages will be upgraded: 300s libselinux1 libsemanage-common libsemanage2 300s 3 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 300s Need to get 224 kB of archives. 300s After this operation, 0 B of additional disk space will be used. 300s Get:1 http://ftpmaster.internal/ubuntu oracular/main ppc64el libselinux1 ppc64el 3.5-2ubuntu5 [99.0 kB] 300s Get:2 http://ftpmaster.internal/ubuntu oracular/main ppc64el libsemanage-common all 3.5-1build6 [10.2 kB] 300s Get:3 http://ftpmaster.internal/ubuntu oracular/main ppc64el libsemanage2 ppc64el 3.5-1build6 [115 kB] 301s Fetched 224 kB in 0s (464 kB/s) 301s (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 ... 72411 files and directories currently installed.) 301s Preparing to unpack .../libselinux1_3.5-2ubuntu5_ppc64el.deb ... 301s Unpacking libselinux1:ppc64el (3.5-2ubuntu5) over (3.5-2ubuntu2) ... 301s Setting up libselinux1:ppc64el (3.5-2ubuntu5) ... 301s (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 ... 72411 files and directories currently installed.) 301s Preparing to unpack .../libsemanage-common_3.5-1build6_all.deb ... 301s Unpacking libsemanage-common (3.5-1build6) over (3.5-1build5) ... 301s Setting up libsemanage-common (3.5-1build6) ... 301s (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 ... 72411 files and directories currently installed.) 302s Preparing to unpack .../libsemanage2_3.5-1build6_ppc64el.deb ... 302s Unpacking libsemanage2:ppc64el (3.5-1build6) over (3.5-1build5) ... 302s Setting up libsemanage2:ppc64el (3.5-1build6) ... 302s Processing triggers for man-db (2.12.1-3) ... 302s Processing triggers for libc-bin (2.40-1ubuntu1) ... 302s Reading package lists... 302s Building dependency tree... 302s Reading state information... 303s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 304s Hit:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease 304s Hit:2 http://ftpmaster.internal/ubuntu oracular InRelease 304s Hit:3 http://ftpmaster.internal/ubuntu oracular-updates InRelease 304s Hit:4 http://ftpmaster.internal/ubuntu oracular-security InRelease 305s Reading package lists... 305s Reading package lists... 305s Building dependency tree... 305s Reading state information... 306s Calculating upgrade... 306s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 306s Reading package lists... 306s Building dependency tree... 306s Reading state information... 307s 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 Starting pkgProblemResolver with broken count: 0 311s Starting 2 pkgProblemResolver with broken count: 0 311s Done 312s The following additional packages will be installed: 312s fio libboost-iostreams1.83.0 libboost-thread1.83.0 libconfig-general-perl 312s libdaxctl1 libgfapi0 libgfrpc0 libgfxdr0 libglusterfs0 libisns0t64 libnbd0 312s libndctl6 libopeniscsiusr libpmem1 libpmemobj1 librados2 librbd1 312s librdmacm1t64 lsscsi open-iscsi tgt 312s Suggested packages: 312s fio-examples gnuplot tgt-glusterfs tgt-rbd 312s Recommended packages: 312s finalrd 312s The following NEW packages will be installed: 312s autopkgtest-satdep fio libboost-iostreams1.83.0 libboost-thread1.83.0 312s libconfig-general-perl libdaxctl1 libgfapi0 libgfrpc0 libgfxdr0 312s libglusterfs0 libisns0t64 libnbd0 libndctl6 libopeniscsiusr libpmem1 312s libpmemobj1 librados2 librbd1 librdmacm1t64 lsscsi open-iscsi tgt 312s 0 upgraded, 22 newly installed, 0 to remove and 0 not upgraded. 312s Need to get 11.0 MB/11.0 MB of archives. 312s After this operation, 50.0 MB of additional disk space will be used. 312s Get:1 /tmp/autopkgtest.2MkHZe/2-autopkgtest-satdep.deb autopkgtest-satdep ppc64el 0 [732 B] 312s Get:2 http://ftpmaster.internal/ubuntu oracular/main ppc64el libopeniscsiusr ppc64el 2.1.10-1ubuntu1 [54.9 kB] 312s Get:3 http://ftpmaster.internal/ubuntu oracular/main ppc64el libisns0t64 ppc64el 0.101-1 [117 kB] 312s Get:4 http://ftpmaster.internal/ubuntu oracular/main ppc64el open-iscsi ppc64el 2.1.10-1ubuntu1 [385 kB] 312s Get:5 http://ftpmaster.internal/ubuntu oracular/main ppc64el librdmacm1t64 ppc64el 52.0-2ubuntu1 [80.6 kB] 312s Get:6 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libconfig-general-perl all 2.65-2 [57.1 kB] 312s Get:7 http://ftpmaster.internal/ubuntu oracular/universe ppc64el tgt ppc64el 1:1.0.85-1.2ubuntu1 [254 kB] 312s Get:8 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libgfxdr0 ppc64el 11.1-5ubuntu1 [21.7 kB] 312s Get:9 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libglusterfs0 ppc64el 11.1-5ubuntu1 [308 kB] 312s Get:10 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libgfrpc0 ppc64el 11.1-5ubuntu1 [46.3 kB] 312s Get:11 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libgfapi0 ppc64el 11.1-5ubuntu1 [99.1 kB] 312s Get:12 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libnbd0 ppc64el 1.20.2-2 [98.5 kB] 312s Get:13 http://ftpmaster.internal/ubuntu oracular/main ppc64el libdaxctl1 ppc64el 77-2.2ubuntu1 [23.7 kB] 312s Get:14 http://ftpmaster.internal/ubuntu oracular/main ppc64el libndctl6 ppc64el 77-2.2ubuntu1 [73.4 kB] 312s Get:15 http://ftpmaster.internal/ubuntu oracular/main ppc64el libpmem1 ppc64el 1.13.1-1.1ubuntu2 [41.1 kB] 312s Get:16 http://ftpmaster.internal/ubuntu oracular/main ppc64el libboost-iostreams1.83.0 ppc64el 1.83.0-3.2ubuntu2 [260 kB] 312s Get:17 http://ftpmaster.internal/ubuntu oracular/main ppc64el libboost-thread1.83.0 ppc64el 1.83.0-3.2ubuntu2 [281 kB] 313s Get:18 http://ftpmaster.internal/ubuntu oracular/main ppc64el librados2 ppc64el 19.2.0~rc2-0ubuntu1 [4194 kB] 313s Get:19 http://ftpmaster.internal/ubuntu oracular/main ppc64el libpmemobj1 ppc64el 1.13.1-1.1ubuntu2 [143 kB] 313s Get:20 http://ftpmaster.internal/ubuntu oracular/main ppc64el librbd1 ppc64el 19.2.0~rc2-0ubuntu1 [3714 kB] 313s Get:21 http://ftpmaster.internal/ubuntu oracular/universe ppc64el fio ppc64el 3.37-1 [716 kB] 313s Get:22 http://ftpmaster.internal/ubuntu oracular/main ppc64el lsscsi ppc64el 0.32-1build1 [54.0 kB] 313s Preconfiguring packages ... 313s Fetched 11.0 MB in 1s (11.3 MB/s) 313s Selecting previously unselected package libopeniscsiusr. 313s (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 ... 72411 files and directories currently installed.) 313s Preparing to unpack .../00-libopeniscsiusr_2.1.10-1ubuntu1_ppc64el.deb ... 313s Unpacking libopeniscsiusr (2.1.10-1ubuntu1) ... 314s Selecting previously unselected package libisns0t64:ppc64el. 314s Preparing to unpack .../01-libisns0t64_0.101-1_ppc64el.deb ... 314s Unpacking libisns0t64:ppc64el (0.101-1) ... 314s Selecting previously unselected package open-iscsi. 314s Preparing to unpack .../02-open-iscsi_2.1.10-1ubuntu1_ppc64el.deb ... 314s Unpacking open-iscsi (2.1.10-1ubuntu1) ... 314s Selecting previously unselected package librdmacm1t64:ppc64el. 314s Preparing to unpack .../03-librdmacm1t64_52.0-2ubuntu1_ppc64el.deb ... 314s Unpacking librdmacm1t64:ppc64el (52.0-2ubuntu1) ... 314s Selecting previously unselected package libconfig-general-perl. 314s Preparing to unpack .../04-libconfig-general-perl_2.65-2_all.deb ... 314s Unpacking libconfig-general-perl (2.65-2) ... 314s Selecting previously unselected package tgt. 314s Preparing to unpack .../05-tgt_1%3a1.0.85-1.2ubuntu1_ppc64el.deb ... 314s Unpacking tgt (1:1.0.85-1.2ubuntu1) ... 314s Selecting previously unselected package libgfxdr0:ppc64el. 314s Preparing to unpack .../06-libgfxdr0_11.1-5ubuntu1_ppc64el.deb ... 314s Unpacking libgfxdr0:ppc64el (11.1-5ubuntu1) ... 314s Selecting previously unselected package libglusterfs0:ppc64el. 314s Preparing to unpack .../07-libglusterfs0_11.1-5ubuntu1_ppc64el.deb ... 314s Unpacking libglusterfs0:ppc64el (11.1-5ubuntu1) ... 314s Selecting previously unselected package libgfrpc0:ppc64el. 314s Preparing to unpack .../08-libgfrpc0_11.1-5ubuntu1_ppc64el.deb ... 314s Unpacking libgfrpc0:ppc64el (11.1-5ubuntu1) ... 314s Selecting previously unselected package libgfapi0:ppc64el. 314s Preparing to unpack .../09-libgfapi0_11.1-5ubuntu1_ppc64el.deb ... 314s Unpacking libgfapi0:ppc64el (11.1-5ubuntu1) ... 314s Selecting previously unselected package libnbd0. 314s Preparing to unpack .../10-libnbd0_1.20.2-2_ppc64el.deb ... 314s Unpacking libnbd0 (1.20.2-2) ... 314s Selecting previously unselected package libdaxctl1:ppc64el. 314s Preparing to unpack .../11-libdaxctl1_77-2.2ubuntu1_ppc64el.deb ... 314s Unpacking libdaxctl1:ppc64el (77-2.2ubuntu1) ... 314s Selecting previously unselected package libndctl6:ppc64el. 314s Preparing to unpack .../12-libndctl6_77-2.2ubuntu1_ppc64el.deb ... 314s Unpacking libndctl6:ppc64el (77-2.2ubuntu1) ... 314s Selecting previously unselected package libpmem1:ppc64el. 314s Preparing to unpack .../13-libpmem1_1.13.1-1.1ubuntu2_ppc64el.deb ... 314s Unpacking libpmem1:ppc64el (1.13.1-1.1ubuntu2) ... 314s Selecting previously unselected package libboost-iostreams1.83.0:ppc64el. 314s Preparing to unpack .../14-libboost-iostreams1.83.0_1.83.0-3.2ubuntu2_ppc64el.deb ... 314s Unpacking libboost-iostreams1.83.0:ppc64el (1.83.0-3.2ubuntu2) ... 314s Selecting previously unselected package libboost-thread1.83.0:ppc64el. 314s Preparing to unpack .../15-libboost-thread1.83.0_1.83.0-3.2ubuntu2_ppc64el.deb ... 314s Unpacking libboost-thread1.83.0:ppc64el (1.83.0-3.2ubuntu2) ... 314s Selecting previously unselected package librados2. 314s Preparing to unpack .../16-librados2_19.2.0~rc2-0ubuntu1_ppc64el.deb ... 314s Unpacking librados2 (19.2.0~rc2-0ubuntu1) ... 314s Selecting previously unselected package libpmemobj1:ppc64el. 314s Preparing to unpack .../17-libpmemobj1_1.13.1-1.1ubuntu2_ppc64el.deb ... 314s Unpacking libpmemobj1:ppc64el (1.13.1-1.1ubuntu2) ... 315s Selecting previously unselected package librbd1. 315s Preparing to unpack .../18-librbd1_19.2.0~rc2-0ubuntu1_ppc64el.deb ... 315s Unpacking librbd1 (19.2.0~rc2-0ubuntu1) ... 315s Selecting previously unselected package fio. 315s Preparing to unpack .../19-fio_3.37-1_ppc64el.deb ... 315s Unpacking fio (3.37-1) ... 315s Selecting previously unselected package lsscsi. 315s Preparing to unpack .../20-lsscsi_0.32-1build1_ppc64el.deb ... 315s Unpacking lsscsi (0.32-1build1) ... 315s Selecting previously unselected package autopkgtest-satdep. 315s Preparing to unpack .../21-2-autopkgtest-satdep.deb ... 315s Unpacking autopkgtest-satdep (0) ... 315s Setting up libconfig-general-perl (2.65-2) ... 315s Setting up libisns0t64:ppc64el (0.101-1) ... 315s Setting up libboost-thread1.83.0:ppc64el (1.83.0-3.2ubuntu2) ... 315s Setting up libnbd0 (1.20.2-2) ... 315s Setting up libopeniscsiusr (2.1.10-1ubuntu1) ... 315s Setting up libglusterfs0:ppc64el (11.1-5ubuntu1) ... 315s Setting up libboost-iostreams1.83.0:ppc64el (1.83.0-3.2ubuntu2) ... 315s Setting up lsscsi (0.32-1build1) ... 315s Setting up libdaxctl1:ppc64el (77-2.2ubuntu1) ... 315s Setting up libndctl6:ppc64el (77-2.2ubuntu1) ... 315s Setting up librdmacm1t64:ppc64el (52.0-2ubuntu1) ... 315s Setting up tgt (1:1.0.85-1.2ubuntu1) ... 315s Created symlink '/etc/systemd/system/multi-user.target.wants/tgt.service' → '/usr/lib/systemd/system/tgt.service'. 316s Setting up libpmem1:ppc64el (1.13.1-1.1ubuntu2) ... 316s Setting up libgfxdr0:ppc64el (11.1-5ubuntu1) ... 316s Setting up librados2 (19.2.0~rc2-0ubuntu1) ... 316s Setting up open-iscsi (2.1.10-1ubuntu1) ... 317s Created symlink '/etc/systemd/system/sockets.target.wants/iscsid.socket' → '/usr/lib/systemd/system/iscsid.socket'. 318s Created symlink '/etc/systemd/system/iscsi.service' → '/usr/lib/systemd/system/open-iscsi.service'. 318s Created symlink '/etc/systemd/system/sysinit.target.wants/open-iscsi.service' → '/usr/lib/systemd/system/open-iscsi.service'. 318s Setting up libpmemobj1:ppc64el (1.13.1-1.1ubuntu2) ... 318s Setting up librbd1 (19.2.0~rc2-0ubuntu1) ... 318s Setting up libgfrpc0:ppc64el (11.1-5ubuntu1) ... 318s Setting up libgfapi0:ppc64el (11.1-5ubuntu1) ... 318s Setting up fio (3.37-1) ... 319s Setting up autopkgtest-satdep (0) ... 319s Processing triggers for man-db (2.12.1-3) ... 321s Processing triggers for initramfs-tools (0.142ubuntu33) ... 321s update-initramfs: Generating /boot/initrd.img-6.8.0-31-generic 321s W: No lz4 in /usr/bin:/sbin:/bin, using gzip 333s Processing triggers for libc-bin (2.40-1ubuntu1) ... 337s (Reading database ... 72652 files and directories currently installed.) 337s Removing autopkgtest-satdep (0) ... 339s autopkgtest [10:42:49]: test tgtbasedmpaths: [----------------------- 339s + targetname=iqn.2016-11.foo.com:target.iscsi 339s + pwd 339s + cwd=/tmp/autopkgtest.2MkHZe/build.TvW/src 339s + testdir=/mnt/tgtmpathtest 339s + localhost=127.0.0.1 339s + portal=127.0.0.1:3260 339s + maxpaths=4 339s + backfn=backingfile 339s + expectwwid=60000000000000000e00000000010001 339s + testdisk=/dev/disk/by-id/wwn-0x60000000000000000e00000000010001 339s + bglog=/tmp/autopkgtest.2MkHZe/tgtbasedmpaths-artifacts/test-background.log 339s + fioprep=/tmp/autopkgtest.2MkHZe/tgtbasedmpaths-artifacts/path-change-prep.fio 339s + fiovrfy=/tmp/autopkgtest.2MkHZe/tgtbasedmpaths-artifacts/path-change-check.fio 339s + mkdir -p /etc/multipath 339s + echo /360000000000000000e00000000010001/ 339s + service tgt restart 339s + truncate --size 100M backingfile 339s + tgtadm --lld iscsi --op new --mode target --tid 1 -T iqn.2016-11.foo.com:target.iscsi 339s + tgtadm --lld iscsi --op bind --mode target --tid 1 -I ALL 339s + tgtadm --lld iscsi --op new --mode logicalunit --tid 1 --lun 1 -b /tmp/autopkgtest.2MkHZe/build.TvW/src/backingfile 339s + iscsiadm --mode discovery --type sendtargets --portal 127.0.0.1 340s 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi 340s login #1 340s + echo login #1 340s + iscsiadm --mode node --targetname iqn.2016-11.foo.com:target.iscsi --portal 127.0.0.1:3260 --login 340s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 340s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 340s + seq 2 4 340s extra login #2 340s + echo extra login #2 340s + iscsiadm --mode session -r 1 --op new 340s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 340s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 340s extra login #3 340s + echo extra login #3 340s + iscsiadm --mode session -r 1 --op new 340s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 340s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 340s extra login #4 340s + echo extra login #4 340s + iscsiadm --mode session -r 1 --op new 340s + udevadm settle 340s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 340s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 340s + sleep 5 345s Status after initial setup 345s + echo Status after initial setup 345s + tgtadm --lld iscsi --mode target --op show 345s + tgtadm --lld iscsi --op show --mode conn --tid 1 345s Target 1: iqn.2016-11.foo.com:target.iscsi 345s System information: 345s Driver: iscsi 345s State: ready 345s I_T nexus information: 345s I_T nexus: 1 345s Initiator: iqn.2004-10.com.ubuntu:01:8c5665923ad8 alias: autopkgtest 345s Connection: 0 345s IP Address: 127.0.0.1 345s I_T nexus: 2 345s Initiator: iqn.2004-10.com.ubuntu:01:8c5665923ad8 alias: autopkgtest 345s Connection: 0 345s IP Address: 127.0.0.1 345s I_T nexus: 3 345s Initiator: iqn.2004-10.com.ubuntu:01:8c5665923ad8 alias: autopkgtest 345s Connection: 0 345s IP Address: 127.0.0.1 345s I_T nexus: 4 345s Initiator: iqn.2004-10.com.ubuntu:01:8c5665923ad8 alias: autopkgtest 345s Connection: 0 345s IP Address: 127.0.0.1 345s LUN information: 345s LUN: 0 345s Type: controller 345s SCSI ID: IET 00010000 345s SCSI SN: beaf10 345s Size: 0 MB, Block size: 1 345s Online: Yes 345s Removable media: No 345s Prevent removal: No 345s Readonly: No 345s SWP: No 345s Thin-provisioning: No 345s Backing store type: null 345s Backing store path: None 345s Backing store flags: 345s LUN: 1 345s Type: disk 345s SCSI ID: IET 00010001 345s SCSI SN: beaf11 345s Size: 105 MB, Block size: 512 345s Online: Yes 345s Removable media: No 345s Prevent removal: No 345s Readonly: No 345s SWP: No 345s Thin-provisioning: No 345s Backing store type: rdwr 345s Backing store path: /tmp/autopkgtest.2MkHZe/build.TvW/src/backingfile 345s Backing store flags: 345s Account information: 345s ACL information: 345s ALL 345s + iscsiadm --mode session -P 1 345s Session: 4 345s Connection: 0 345s Initiator: iqn.2004-10.com.ubuntu:01:8c5665923ad8 345s IP Address: 127.0.0.1 345s Session: 3 345s Connection: 0 345s Initiator: iqn.2004-10.com.ubuntu:01:8c5665923ad8 345s IP Address: 127.0.0.1 345s Session: 2 345s Connection: 0 345s Initiator: iqn.2004-10.com.ubuntu:01:8c5665923ad8 345s IP Address: 127.0.0.1 345s Session: 1 345s Connection: 0 345s Initiator: iqn.2004-10.com.ubuntu:01:8c5665923ad8 345s IP Address: 127.0.0.1 345s + lsscsi -liv 345s Target: iqn.2016-11.foo.com:target.iscsi (non-flash) 345s Current Portal: 127.0.0.1:3260,1 345s Persistent Portal: 127.0.0.1:3260,1 345s ********** 345s Interface: 345s ********** 345s Iface Name: default 345s Iface Transport: tcp 345s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:8c5665923ad8 345s Iface IPaddress: 127.0.0.1 345s Iface HWaddress: default 345s Iface Netdev: default 345s SID: 1 345s iSCSI Connection State: LOGGED IN 345s iSCSI Session State: LOGGED_IN 345s Internal iscsid Session State: NO CHANGE 345s 345s ********** 345s Interface: 345s ********** 345s Iface Name: default 345s Iface Transport: tcp 345s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:8c5665923ad8 345s Iface IPaddress: 127.0.0.1 345s Iface HWaddress: default 345s Iface Netdev: default 345s SID: 2 345s iSCSI Connection State: LOGGED IN 345s iSCSI Session State: LOGGED_IN 345s Internal iscsid Session State: NO CHANGE 345s 345s ********** 345s Interface: 345s ********** 345s Iface Name: default 345s Iface Transport: tcp 345s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:8c5665923ad8 345s Iface IPaddress: 127.0.0.1 345s Iface HWaddress: default 345s Iface Netdev: default 345s SID: 3 345s iSCSI Connection State: LOGGED IN 345s iSCSI Session State: LOGGED_IN 345s Internal iscsid Session State: NO CHANGE 345s 345s ********** 345s Interface: 345s ********** 345s Iface Name: default 345s Iface Transport: tcp 345s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:8c5665923ad8 345s Iface IPaddress: 127.0.0.1 345s Iface HWaddress: default 345s Iface Netdev: default 345s SID: 4 345s iSCSI Connection State: LOGGED IN 345s iSCSI Session State: LOGGED_IN 345s Internal iscsid Session State: NO CHANGE 345s list_ndevices: scandir: /sys/class/nvme/: No such file or directory 345s + multipath -v3 -ll 345s 83.564398 | set open fds limit to 1073741816/1073741816 345s 83.564482 | _read_bindings_file: reading /etc/multipath/bindings 345s 83.564527 | loading /usr/lib/multipath/libchecktur.so checker 345s 83.564619 | checker tur: message table size = 4 345s 83.564629 | loading /usr/lib/multipath/libprioconst.so prioritizer 345s [0:0:0:0] storage IET Controller 0001 - - 345s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 345s dir: /sys/bus/scsi/devices/0:0:0:0 [/sys/devices/platform/host0/session1/target0:0:0/0:0:0:0] 345s [0:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sda 360000000000000000e00000000010001 345s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 345s dir: /sys/bus/scsi/devices/0:0:0:1 [/sys/devices/platform/host0/session1/target0:0:0/0:0:0:1] 345s [1:0:0:0] storage IET Controller 0001 - - 345s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 345s dir: /sys/bus/scsi/devices/1:0:0:0 [/sys/devices/platform/host1/session2/target1:0:0/1:0:0:0] 345s [1:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdb 360000000000000000e00000000010001 345s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 345s dir: /sys/bus/scsi/devices/1:0:0:1 [/sys/devices/platform/host1/session2/target1:0:0/1:0:0:1] 345s [2:0:0:0] storage IET Controller 0001 - - 345s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 345s dir: /sys/bus/scsi/devices/2:0:0:0 [/sys/devices/platform/host2/session3/target2:0:0/2:0:0:0] 345s [2:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdc 33000000100000001 345s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 345s dir: /sys/bus/scsi/devices/2:0:0:1 [/sys/devices/platform/host2/session3/target2:0:0/2:0:0:1] 345s [3:0:0:0] storage IET Controller 0001 - - 345s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 345s dir: /sys/bus/scsi/devices/3:0:0:0 [/sys/devices/platform/host3/session4/target3:0:0/3:0:0:0] 345s [3:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdd 360000000000000000e00000000010001 345s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 345s dir: /sys/bus/scsi/devices/3:0:0:1 [/sys/devices/platform/host3/session4/target3:0:0/3:0:0:1] 345s NVMe module may not be loaded 345s 83.564756 | _init_foreign: foreign library "nvme" is not enabled 345s 83.570910 | vda: device node name blacklisted 345s 83.571250 | sda: size = 204800 345s 83.571409 | sda: vendor = IET 345s 83.571434 | sda: product = VIRTUAL-DISK 345s 83.571459 | sda: rev = 0001 345s 83.572309 | sda: h:b:t:l = 0:0:0:1 345s 83.572706 | sda: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 345s 83.572712 | sda: uid_attribute = ID_SERIAL (setting: multipath internal) 345s 83.572715 | sda: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 345s 83.572911 | sda: 1024 cyl, 4 heads, 50 sectors/track, start at 0 345s 83.572916 | sda: vpd_vendor_id = 0 "undef" (setting: multipath internal) 345s 83.572935 | sda: serial = beaf11 345s 83.572938 | sda: detect_checker = yes (setting: multipath internal) 345s 83.572970 | sda checker timeout = 30 s (setting: kernel sysfs) 345s 83.573425 | sda: path_checker = tur (setting: multipath internal) 345s 83.573583 | sda: tur state = up 345s 83.573735 | sdb: size = 204800 345s 83.573879 | sdb: vendor = IET 345s 83.573903 | sdb: product = VIRTUAL-DISK 345s 83.573929 | sdb: rev = 0001 345s 83.574576 | sdb: h:b:t:l = 1:0:0:1 345s 83.574954 | sdb: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 345s 83.574958 | sdb: uid_attribute = ID_SERIAL (setting: multipath internal) 345s 83.574961 | sdb: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 345s 83.575122 | sdb: 1024 cyl, 4 heads, 50 sectors/track, start at 0 345s 83.575127 | sdb: vpd_vendor_id = 0 "undef" (setting: multipath internal) 345s 83.575142 | sdb: serial = beaf11 345s 83.575145 | sdb: detect_checker = yes (setting: multipath internal) 345s 83.575176 | sdb checker timeout = 30 s (setting: kernel sysfs) 345s 83.575390 | sdb: path_checker = tur (setting: multipath internal) 345s 83.575522 | sdb: tur state = up 345s 83.575773 | sdc: size = 204800 345s 83.575980 | sdc: vendor = IET 345s 83.576024 | sdc: product = VIRTUAL-DISK 345s 83.576050 | sdc: rev = 0001 345s 83.576735 | sdc: h:b:t:l = 2:0:0:1 345s 83.577195 | sdc: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 345s 83.577201 | sdc: uid_attribute = ID_SERIAL (setting: multipath internal) 345s 83.577203 | sdc: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 345s 83.577370 | sdc: 1024 cyl, 4 heads, 50 sectors/track, start at 0 345s 83.577375 | sdc: vpd_vendor_id = 0 "undef" (setting: multipath internal) 345s 83.577390 | sdc: serial = beaf11 345s 83.577392 | sdc: detect_checker = yes (setting: multipath internal) 345s 83.577421 | sdc checker timeout = 30 s (setting: kernel sysfs) 345s 83.577647 | sdc: path_checker = tur (setting: multipath internal) 345s 83.577782 | sdc: tur state = up 345s 83.577947 | sdd: size = 204800 345s 83.578101 | sdd: vendor = IET 345s 83.578126 | sdd: product = VIRTUAL-DISK 345s 83.578151 | sdd: rev = 0001 345s 83.578838 | sdd: h:b:t:l = 3:0:0:1 345s 83.579222 | sdd: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 345s 83.579227 | sdd: uid_attribute = ID_SERIAL (setting: multipath internal) 345s 83.579229 | sdd: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 345s 83.579404 | sdd: 1024 cyl, 4 heads, 50 sectors/track, start at 0 345s 83.579409 | sdd: vpd_vendor_id = 0 "undef" (setting: multipath internal) 345s 83.579425 | sdd: serial = beaf11 345s 83.579428 | sdd: detect_checker = yes (setting: multipath internal) 345s 83.579459 | sdd checker timeout = 30 s (setting: kernel sysfs) 345s 83.579726 | sdd: path_checker = tur (setting: multipath internal) 345s 83.579838 | sdd: tur state = up 345s 83.579992 | loop0: device node name blacklisted 345s 83.580143 | loop1: device node name blacklisted 345s 83.580262 | loop2: device node name blacklisted 345s 83.580363 | loop3: device node name blacklisted 345s 83.580457 | loop4: device node name blacklisted 345s 83.580547 | loop5: device node name blacklisted 345s 83.580637 | loop6: device node name blacklisted 345s 83.580729 | loop7: device node name blacklisted 345s ===== paths list ===== 345s uuid hcil dev dev_t pri dm_st chk_st vend/prod/rev dev_st 345s 0:0:0:1 sda 8:0 -1 undef undef IET,VIRTUAL-DISK,0001 unknown 345s 1:0:0:1 sdb 8:16 -1 undef undef IET,VIRTUAL-DISK,0001 unknown 345s 2:0:0:1 sdc 8:32 -1 undef undef IET,VIRTUAL-DISK,0001 unknown 345s 3:0:0:1 sdd 8:48 -1 undef undef IET,VIRTUAL-DISK,0001 unknown 345s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 345s size=100M features='0' hwhandler='0' wp=rw 345s |-+- policy='service-time 0' prio=1 status=active 345s | `- 0:0:0:1 sda 8:0 active ready running 345s |-+- policy='service-time 0' prio=1 status=enabled 345s | `- 1:0:0:1 sdb 8:16 active ready running 345s |-+- policy='service-time 0' prio=1 status=enabled 345s | `- 3:0:0:1 sdd 8:48 active ready running 345s `-+- policy='service-time 0' prio=1 status=enabled 345s `- 2:0:0:1 sdc 8:32 active ready running 345s mpatha: 0 204800 multipath 0 0 4 1 service-time 0 1 2 8:0 1 1 service-time 0 1 2 8:16 1 1 service-time 0 1 2 8:48 1 1 service-time 0 1 2 8:32 1 1 345s 83.580834 | dm-0: device node name blacklisted 345s 83.582116 | multipath-tools v0.9.9 (05/03, 2024) 345s 83.582131 | libdevmapper version 1.02.196 345s 83.582304 | kernel device mapper v4.48.0 345s 83.582321 | DM multipath kernel driver v1.14.0 345s 83.582452 | sda: size = 204800 345s 83.582459 | sda: vendor = IET 345s 83.582462 | sda: product = VIRTUAL-DISK 345s 83.582465 | sda: rev = 0001 345s 83.583084 | sda: h:b:t:l = 0:0:0:1 345s 83.583212 | sda: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 345s 83.583239 | sda: 1024 cyl, 4 heads, 50 sectors/track, start at 0 345s 83.583242 | sda: vpd_vendor_id = 0 "undef" (setting: multipath internal) 345s 83.583259 | sda: serial = beaf11 345s 83.583455 | sda: tur state = up 345s 83.583463 | sda: uid = 360000000000000000e00000000010001 (udev) 345s 83.583466 | sda: detect_prio = yes (setting: multipath internal) 345s 83.583470 | sda: prio = const (setting: multipath internal) 345s 83.583472 | sda: prio args = "" (setting: multipath internal) 345s 83.583474 | sda: const prio = 1 345s 83.583501 | sdb: size = 204800 345s 83.583507 | sdb: vendor = IET 345s 83.583510 | sdb: product = VIRTUAL-DISK 345s 83.583513 | sdb: rev = 0001 345s 83.584161 | sdb: h:b:t:l = 1:0:0:1 345s 83.584314 | sdb: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 345s 83.584340 | sdb: 1024 cyl, 4 heads, 50 sectors/track, start at 0 345s 83.584344 | sdb: vpd_vendor_id = 0 "undef" (setting: multipath internal) 345s 83.584359 | sdb: serial = beaf11 345s 83.584512 | sdb: tur state = up 345s 83.584519 | sdb: uid = 360000000000000000e00000000010001 (udev) 345s 83.584522 | sdb: detect_prio = yes (setting: multipath internal) 345s 83.584525 | sdb: prio = const (setting: multipath internal) 345s 83.584527 | sdb: prio args = "" (setting: multipath internal) 345s 83.584529 | sdb: const prio = 1 345s 83.584555 | sdd: size = 204800 345s 83.584562 | sdd: vendor = IET 345s 83.584566 | sdd: product = VIRTUAL-DISK 345s 83.584569 | sdd: rev = 0001 345s 83.585148 | sdd: h:b:t:l = 3:0:0:1 345s 83.585273 | sdd: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 345s 83.585296 | sdd: 1024 cyl, 4 heads, 50 sectors/track, start at 0 345s 83.585299 | sdd: vpd_vendor_id = 0 "undef" (setting: multipath internal) 345s 83.585314 | sdd: serial = beaf11 345s 83.585464 | sdd: tur state = up 345s 83.585472 | sdd: uid = 360000000000000000e00000000010001 (udev) 345s 83.585474 | sdd: detect_prio = yes (setting: multipath internal) 345s 83.585477 | sdd: prio = const (setting: multipath internal) 345s 83.585479 | sdd: prio args = "" (setting: multipath internal) 345s 83.585481 | sdd: const prio = 1 345s 83.585512 | sdc: size = 204800 345s 83.585519 | sdc: vendor = IET 345s 83.585522 | sdc: product = VIRTUAL-DISK 345s 83.585525 | sdc: rev = 0001 345s 83.586127 | sdc: h:b:t:l = 2:0:0:1 345s 83.586253 | sdc: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 345s 83.586282 | sdc: 1024 cyl, 4 heads, 50 sectors/track, start at 0 345s 83.586286 | sdc: vpd_vendor_id = 0 "undef" (setting: multipath internal) 345s 83.586301 | sdc: serial = beaf11 345s 83.586433 | sdc: tur state = up 345s 83.586442 | sdc: uid = 360000000000000000e00000000010001 (udev) 345s 83.586446 | sdc: detect_prio = yes (setting: multipath internal) 345s 83.586450 | sdc: prio = const (setting: multipath internal) 345s 83.586453 | sdc: prio args = "" (setting: multipath internal) 345s 83.586456 | sdc: const prio = 1 345s 83.587668 | unloading tur checker 345s 83.587763 | unloading const prioritizer 345s + dmsetup table 345s + grep . /etc/multipath/bindings /etc/multipath/wwids 345s /etc/multipath/bindings:# Multipath bindings, Version : 1.0 345s /etc/multipath/bindings:# NOTE: this file is automatically maintained by the multipath program. 345s /etc/multipath/bindings:# You should not need to edit this file in normal circumstances. 345s /etc/multipath/bindings:# 345s /etc/multipath/bindings:# Format: 345s /etc/multipath/bindings:# alias wwid 345s /etc/multipath/bindings:# 345s /etc/multipath/bindings:mpatha 360000000000000000e00000000010001 345s /etc/multipath/wwids:/360000000000000000e00000000010001/ 345s + systemctl status multipathd.service 345s + ret_code=0 345s + systemctl status multipathd.socket 345s ● multipathd.service - Device-Mapper Multipath Device Controller 345s Loaded: loaded (/usr/lib/systemd/system/multipathd.service; enabled; preset: enabled) 345s Active: active (running) since Tue 2024-09-10 10:41:33 UTC; 1min 21s ago 345s Invocation: a076626758184301ac13e9c1e4e2ac10 345s TriggeredBy: ○ multipathd.socket 345s Main PID: 328 (multipathd) 345s Status: "up" 345s Tasks: 7 345s Memory: 27.9M (peak: 37.9M) 345s CPU: 65ms 345s CGroup: /system.slice/multipathd.service 345s └─328 /sbin/multipathd -d -s 345s 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i multipathd[328]: multipathd v0.9.9: start up 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i multipathd[328]: reconfigure: setting up paths and maps 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 345s Sep 10 10:42:50 autopkgtest multipathd[328]: updated bindings file /etc/multipath/bindings 345s Sep 10 10:42:50 autopkgtest multipathd[328]: mpatha: addmap [0 204800 multipath 0 0 1 1 service-time 0 1 1 8:0 1] 345s Sep 10 10:42:50 autopkgtest multipathd[328]: sda [8:0]: path added to devmap mpatha 345s Sep 10 10:42:50 autopkgtest multipathd[328]: mpatha: performing delayed actions 345s Sep 10 10:42:50 autopkgtest multipathd[328]: mpatha: reload [0 204800 multipath 0 0 4 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:32 1] 345s ○ multipathd.socket - multipathd control socket 345s Loaded: loaded (/usr/lib/systemd/system/multipathd.socket; static) 345s Active: inactive (dead) 345s Triggers: ● multipathd.service 345s Listen: @/org/kernel/linux/storage/multipathd (Stream) 345s + ret_code=3 345s + [ 3 -eq 0 ] 345s + [ 3 -eq 3 ] 345s + ls -la /dev/mapper/ 345s total 0 345s drwxr-xr-x 2 root root 80 Sep 10 10:42 . 345s drwxr-xr-x 20 root root 4360 Sep 10 10:42 .. 345s crw------- 1 root root 10, 236 Sep 10 10:41 control 345s lrwxrwxrwx 1 root root 7 Sep 10 10:42 mpatha -> ../dm-0 345s + echo journal 345s + journalctl -b 345s journal 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: radix-mmu: Page sizes from device-tree: 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: radix-mmu: Page size shift = 12 AP=0x0 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: radix-mmu: Page size shift = 16 AP=0x5 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: radix-mmu: Page size shift = 21 AP=0x1 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: radix-mmu: Page size shift = 30 AP=0x2 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Activating Kernel Userspace Access Prevention 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Activating Kernel Userspace Execution Prevention 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: radix-mmu: Mapped 0x0000000000000000-0x00000000038a0000 with 64.0 KiB pages (exec) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: radix-mmu: Mapped 0x00000000038a0000-0x0000000200000000 with 64.0 KiB pages 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: lpar: Using radix MMU under hypervisor 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i 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) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Secure boot mode disabled 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Found initrd at 0xc000000006200000:0xc0000000094dba3e 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Hardware name: IBM pSeries (emulated by qemu) POWER9 (raw) 0x4e1203 0xf000005 of:SLOF,HEAD hv:linux,kvm pSeries 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Partition configured for 4 cpus. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: CPU maps initialized for 1 thread per core 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: (thread shift is 0) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Allocated 3360 bytes for 4 pacas 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: numa: Partition configured for 1 NUMA nodes. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: ----------------------------------------------------- 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: phys_mem_size = 0x200000000 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: dcache_bsize = 0x80 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: icache_bsize = 0x80 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: cpu_features = 0x0001c06b8f4f9187 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: possible = 0x001ffbfbcf5fb187 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: always = 0x0000000380008181 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: cpu_user_features = 0xdc0065c2 0xaef00000 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: mmu_features = 0x3c007641 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: firmware_features = 0x00000285455a445f 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: vmalloc start = 0xc008000000000000 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: IO start = 0xc00a000000000000 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: vmemmap start = 0xc00c000000000000 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: ----------------------------------------------------- 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: numa: NODE_DATA [mem 0x1eff0c280-0x1eff13fff] 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: rfi-flush: fallback displacement flush available 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: rfi-flush: ori type flush available 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: rfi-flush: mttrig type flush available 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: rfi-flush: patched 12 locations (ori+mttrig type flush) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: count-cache-flush: hardware flush enabled. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: link-stack-flush: software flush enabled. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: entry-flush: patched 61 locations (ori+mttrig type flush) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: uaccess-flush: patched 1 locations (ori+mttrig type flush) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: stf-barrier: eieio barrier available 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: stf-barrier: patched 61 entry locations (eieio barrier) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: stf-barrier: patched 12 exit locations (eieio barrier) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: PPC64 nvram contains 65536 bytes 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: barrier-nospec: using ORI speculation barrier 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: barrier-nospec: patched 269 locations 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Top of RAM: 0x200000000, Total RAM: 0x200000000 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Memory hole size: 0MB 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Zone ranges: 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Normal [mem 0x0000000000000000-0x00000001ffffffff] 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Device empty 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Movable zone start for each node 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Early memory node ranges 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: node 0: [mem 0x0000000000000000-0x00000001ffffffff] 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Initmem setup node 0 [mem 0x0000000000000000-0x00000001ffffffff] 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: percpu: Embedded 12 pages/cpu s609960 r0 d176472 u786432 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pcpu-alloc: s609960 r0 d176472 u786432 alloc=12*65536 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Kernel command line: BOOT_IMAGE=/boot/vmlinux-6.8.0-31-generic root=UUID=b421051a-5f17-47ac-ade0-d9d9c5a5c13f ro console=hvc0 earlyprintk 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Unknown kernel command line parameters "earlyprintk BOOT_IMAGE=/boot/vmlinux-6.8.0-31-generic", will be passed to user space. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Dentry cache hash table entries: 1048576 (order: 7, 8388608 bytes, linear) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Inode-cache hash table entries: 524288 (order: 6, 4194304 bytes, linear) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Fallback order for Node 0: 0 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Built 1 zonelists, mobility grouping on. Total pages: 130944 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Policy zone: Normal 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: mem auto-init: stack:all(zero), heap alloc:on, heap free:off 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Memory: 7968192K/8388608K available (23680K kernel code, 4096K rwdata, 25472K rodata, 8832K init, 1901K bss, 420416K reserved, 0K cma-reserved) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: SLUB: HWalign=128, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: ftrace: allocating 51717 entries in 19 pages 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: ftrace: allocated 19 pages with 3 groups 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: trace event string verifier disabled 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: rcu: Hierarchical RCU implementation. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: rcu: RCU restricting CPUs from NR_CPUS=2048 to nr_cpu_ids=4. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Rude variant of Tasks RCU enabled. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Tracing variant of Tasks RCU enabled. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: NR_IRQS: 512, nr_irqs: 512, preallocated irqs: 16 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: xive: Using IRQ range [0-3] 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: xive: Interrupt handling initialized with spapr backend 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: xive: Using priority 6 for all interrupts 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: xive: Using 64kB queues 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: rcu: srcu_init: Setting srcu_struct sizes based on contention. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: time_init: decrementer frequency = 512.000000 MHz 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: time_init: processor frequency = 2700.000000 MHz 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: time_init: 56 bit decrementer (max: 7fffffffffffff) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: clocksource: timebase: mask: 0xffffffffffffffff max_cycles: 0x761537d007, max_idle_ns: 440795202126 ns 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: clocksource: timebase mult[1f40000] shift[24] registered 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: clockevent: decrementer mult[83126f] shift[24] cpu[0] 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Console: colour dummy device 80x25 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pid_max: default: 32768 minimum: 301 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: LSM: initializing lsm=lockdown,capability,landlock,yama,apparmor,integrity 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: landlock: Up and running. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Yama: becoming mindful. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: AppArmor: AppArmor initialized 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Mount-cache hash table entries: 16384 (order: 1, 131072 bytes, linear) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Mountpoint-cache hash table entries: 16384 (order: 1, 131072 bytes, linear) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: RCU Tasks Rude: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: RCU Tasks Trace: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: POWER9 performance monitor hardware support registered 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: rcu: Hierarchical SRCU implementation. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: rcu: Max phase no-delay instances is 1000. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: smp: Bringing up secondary CPUs ... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: smp: Brought up 1 node, 4 CPUs 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: numa: Node 0 CPUs: 0-3 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: devtmpfs: initialized 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: PCI host bridge /pci@800000020000000 ranges: 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: IO 0x0000200000000000..0x000020000000ffff -> 0x0000000000000000 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: MEM 0x0000200080000000..0x00002000ffffffff -> 0x0000000080000000 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: MEM 0x0000210000000000..0x000021ffffffffff -> 0x0000210000000000 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: PCI: OF: PROBE_ONLY disabled 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: futex hash table entries: 1024 (order: 1, 131072 bytes, linear) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pinctrl core: initialized pinctrl subsystem 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: NET: Registered PF_NETLINK/PF_ROUTE protocol family 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: audit: initializing netlink subsys (disabled) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: audit: type=2000 audit(1725964891.048:1): state=initialized audit_enabled=0 res=1 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: thermal_sys: Registered thermal governor 'fair_share' 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: thermal_sys: Registered thermal governor 'bang_bang' 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: thermal_sys: Registered thermal governor 'step_wise' 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: thermal_sys: Registered thermal governor 'user_space' 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: thermal_sys: Registered thermal governor 'power_allocator' 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: cpuidle: using governor ladder 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: cpuidle: using governor menu 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: RTAS daemon started 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pstore: Using crash dump compression: deflate 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pstore: Registered nvram as persistent store backend 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: EEH: pSeries platform initialized 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: iommu: Default domain type: Translated 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: iommu: DMA domain TLB invalidation policy: strict mode 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: SCSI subsystem initialized 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: libata version 3.00 loaded. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usbcore: registered new interface driver usbfs 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usbcore: registered new interface driver hub 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usbcore: registered new device driver usb 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pps_core: LinuxPPS API ver. 1 registered 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: PTP clock support registered 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: EDAC MC: Ver: 3.0.0 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: NetLabel: Initializing 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: NetLabel: domain hash size = 128 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: NetLabel: unlabeled traffic allowed by default 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: mctp: management component transport protocol core 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: NET: Registered PF_MCTP protocol family 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: PCI: Probing PCI hardware 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: PCI host bridge to bus 0000:00 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pci_bus 0000:00: root bus resource [io 0x10000-0x1ffff] (bus address [0x0000-0xffff]) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pci_bus 0000:00: root bus resource [mem 0x200080000000-0x2000ffffffff] (bus address [0x80000000-0xffffffff]) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pci_bus 0000:00: root bus resource [mem 0x210000000000-0x21ffffffffff 64bit] 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pci_bus 0000:00: root bus resource [bus 00-ff] 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pci 0000:00:01.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pci 0000:00:02.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pci 0000:00:03.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pci 0000:00:04.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pci 0000:00:05.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pci 0000:00:06.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pci 0000:00:07.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: IOMMU table initialized, virtual merging enabled 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: PCI 0000:00 Cannot reserve Legacy IO [io 0x10000-0x10fff] 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pci_bus 0000:00: resource 4 [io 0x10000-0x1ffff] 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pci_bus 0000:00: resource 5 [mem 0x200080000000-0x2000ffffffff] 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pci_bus 0000:00: resource 6 [mem 0x210000000000-0x21ffffffffff 64bit] 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pci 0000:00:01.0: Adding to iommu group 0 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pci 0000:00:02.0: Adding to iommu group 0 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pci 0000:00:03.0: Adding to iommu group 0 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pci 0000:00:04.0: Adding to iommu group 0 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pci 0000:00:05.0: Adding to iommu group 0 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pci 0000:00:06.0: Adding to iommu group 0 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pci 0000:00:07.0: Adding to iommu group 0 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: EEH: No capable adapters found: recovery disabled. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: PCI: Probing PCI hardware done 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pci 0000:00:07.0: vgaarb: setting as boot VGA device 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pci 0000:00:07.0: vgaarb: bridge control possible 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pci 0000:00:07.0: vgaarb: VGA device added: decodes=io+mem,owns=mem,locks=none 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: vgaarb: loaded 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: clocksource: Switched to clocksource timebase 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: VFS: Disk quotas dquot_6.6.0 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: VFS: Dquot-cache hash table entries: 8192 (order 0, 65536 bytes) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: AppArmor: AppArmor Filesystem Enabled 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: NET: Registered PF_INET protocol family 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: IP idents hash table entries: 131072 (order: 4, 1048576 bytes, linear) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: tcp_listen_portaddr_hash hash table entries: 4096 (order: 0, 65536 bytes, linear) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Table-perturb hash table entries: 65536 (order: 2, 262144 bytes, linear) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: TCP established hash table entries: 65536 (order: 3, 524288 bytes, linear) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: TCP bind hash table entries: 65536 (order: 5, 2097152 bytes, linear) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: TCP: Hash tables configured (established 65536 bind 65536) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: MPTCP token hash table entries: 8192 (order: 1, 196608 bytes, linear) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: UDP hash table entries: 4096 (order: 1, 131072 bytes, linear) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: UDP-Lite hash table entries: 4096 (order: 1, 131072 bytes, linear) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: NET: Registered PF_UNIX/PF_LOCAL protocol family 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: NET: Registered PF_XDP protocol family 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: PCI: CLS 0 bytes, default 128 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Trying to unpack rootfs image as initramfs... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Initialise system trusted keyrings 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Key type blacklist registered 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: workingset: timestamp_bits=38 max_order=17 bucket_order=0 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: zbud: loaded 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: fuse: init (API version 7.39) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: integrity: Platform Keyring initialized 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: integrity: Machine keyring initialized 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Key type asymmetric registered 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Asymmetric key parser 'x509' registered 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 243) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: io scheduler mq-deadline registered 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: virtio-pci 0000:00:01.0: enabling device (0100 -> 0103) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: virtio-pci 0000:00:01.0: ibm,query-pe-dma-windows(2026) 800 8000000 20000000 returned 0, lb=80000000 ps=7 wn=1 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i 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) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: virtio-pci 0000:00:03.0: enabling device (0100 -> 0103) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: virtio-pci 0000:00:04.0: enabling device (0100 -> 0103) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: virtio-pci 0000:00:05.0: enabling device (0100 -> 0103) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: virtio-pci 0000:00:06.0: enabling device (0100 -> 0103) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: printk: legacy console [hvc0] enabled 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Freeing initrd memory: 52032K 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Non-volatile memory driver v1.3 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Linux agpgart interface v0.103 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: loop: module loaded 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: virtio_blk virtio2: 4/0/0 default/read/poll queues 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: virtio_blk virtio2: [vda] 209715200 512-byte logical blocks (107 GB/100 GiB) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: GPT:Primary header thinks Alt. header is not at the end of the disk. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: GPT:41943039 != 209715199 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: GPT:Alternate GPT header not at the end of the disk. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: GPT:41943039 != 209715199 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: GPT: Use GNU Parted to correct GPT errors. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: vda: vda1 vda2 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: tun: Universal TUN/TAP device driver, 1.6 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: PPP generic driver version 2.4.2 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: mousedev: PS/2 mouse device common for all mice 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: rtc-generic rtc-generic: registered as rtc0 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: rtc-generic rtc-generic: setting system clock to 2024-09-10T10:41:31 UTC (1725964891) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: i2c_dev: i2c /dev entries driver 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: device-mapper: uevent: version 1.0.3 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@redhat.com 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: pseries_idle_driver registered 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: ledtrig-cpu: registered to indicate activity on CPUs 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: drop_monitor: Initializing network drop monitor service 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: NET: Registered PF_INET6 protocol family 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Segment Routing with IPv6 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: In-situ OAM (IOAM) with IPv6 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: NET: Registered PF_PACKET protocol family 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Key type dns_resolver registered 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: secvar-sysfs: Failed to retrieve secvar operations 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: drmem: No dynamic reconfiguration memory found 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: registered taskstats version 1 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Loading compiled-in X.509 certificates 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Loaded X.509 cert 'Build time autogenerated kernel key: d20be259617023e52b002c562b3536c6f73da543' 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Live Patch Signing: 14df34d1a87cf37625abec039ef2bf521249b969' 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Kernel Module Signing: 88f752e560a1e0737e31163a466ad7b70a850c19' 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: blacklist: Loading compiled-in revocation X.509 certificates 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing: 61482aa2830d0ab2ad5af10b7250da9033ddcef0' 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2017): 242ade75ac4a15e50d50c84b0d45ff3eae707a03' 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (ESM 2018): 365188c1d374d6b07c3c8f240f8ef722433d6a8b' 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2019): c0746fd6c5da3ae827864651ad66ae47fe24b3e8' 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2021 v1): a8d54bbb3825cfb94fa13c9f8a594a195c107b8d' 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2021 v2): 4cf046892d6fd3c9a5b03f98d845f90851dc6a8c' 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2021 v3): 100437bb6de6e469b581e61cd66bce3ef4ed53af' 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (Ubuntu Core 2019): c1d57b8f6b743f23ee41f4f7ee292f06eecadfb9' 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Key type .fscrypt registered 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Key type fscrypt-provisioning registered 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Key type encrypted registered 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: AppArmor: AppArmor sha256 policy hashing enabled 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Secure boot mode disabled 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: ima: No TPM chip found, activating TPM-bypass! 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Loading compiled-in module X.509 certificates 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Loaded X.509 cert 'Build time autogenerated kernel key: d20be259617023e52b002c562b3536c6f73da543' 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: ima: Allocated hash algorithm: sha256 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Secure boot mode disabled 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Trusted boot mode disabled 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: ima: No architecture policies found 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: evm: Initialising EVM extended attributes: 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: evm: security.selinux 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: evm: security.SMACK64 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: evm: security.SMACK64EXEC 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: evm: security.SMACK64TRANSMUTE 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: evm: security.SMACK64MMAP 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: evm: security.apparmor 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: evm: security.ima 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: evm: security.capability 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: evm: HMAC attrs: 0x1 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: SED: plpks not available 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: clk: Disabling unused clocks 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: integrity: Unable to open file: /etc/keys/x509_evm.der (-2) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Freeing unused kernel image (initmem) memory: 8832K 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Checked W+X mappings: passed, no W+X pages found 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Run /init as init process 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: with arguments: 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: /init 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: earlyprintk 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: with environment: 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: HOME=/ 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: TERM=linux 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: BOOT_IMAGE=/boot/vmlinux-6.8.0-31-generic 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: virtio_net virtio0 enp0s1: renamed from eth0 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: xhci_hcd 0000:00:02.0: xHCI Host Controller 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: xhci_hcd 0000:00:02.0: new USB bus registered, assigned bus number 1 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: xhci_hcd 0000:00:02.0: hcc params 0x00087001 hci version 0x100 quirks 0x0000000000000010 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: xhci_hcd 0000:00:02.0: xHCI Host Controller 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: xhci_hcd 0000:00:02.0: new USB bus registered, assigned bus number 2 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: xhci_hcd 0000:00:02.0: Host supports USB 3.0 SuperSpeed 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.08 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usb usb1: Product: xHCI Host Controller 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usb usb1: Manufacturer: Linux 6.8.0-31-generic xhci-hcd 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usb usb1: SerialNumber: 0000:00:02.0 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: hub 1-0:1.0: USB hub found 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: hub 1-0:1.0: 4 ports detected 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usb usb2: We don't know the algorithms for LPM for this host, disabling LPM. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 6.08 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usb usb2: Product: xHCI Host Controller 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usb usb2: Manufacturer: Linux 6.8.0-31-generic xhci-hcd 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usb usb2: SerialNumber: 0000:00:02.0 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: hub 2-0:1.0: USB hub found 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: hub 2-0:1.0: 4 ports detected 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: random: crng init done 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: [drm] Found bochs VGA, ID 0xb0c5. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: [drm] Framebuffer size 16384 kB @ 0x200081000000, mmio @ 0x200082000000. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: [drm] Found EDID data blob. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: [drm] Initialized bochs-drm 1.0.0 20130925 for 0000:00:07.0 on minor 0 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: fbcon: Deferring console take-over 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: bochs-drm 0000:00:07.0: [drm] fb0: bochs-drmdrmfb frame buffer device 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: raid6: vpermxor8 gen() 13347 MB/s 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: raid6: vpermxor4 gen() 11015 MB/s 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usb 1-1: new high-speed USB device number 2 using xhci_hcd 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: raid6: vpermxor2 gen() 9052 MB/s 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: raid6: vpermxor1 gen() 8970 MB/s 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usb 1-1: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usb 1-1: New USB device strings: Mfr=1, Product=4, SerialNumber=11 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usb 1-1: Product: QEMU USB Keyboard 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usb 1-1: Manufacturer: QEMU 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usb 1-1: SerialNumber: 68284-pci@800000020000000:02.0-1 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: hid: raw HID events driver (C) Jiri Kosina 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usbcore: registered new interface driver usbhid 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usbhid: USB HID core driver 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: input: QEMU QEMU USB Keyboard as /devices/pci0000:00/0000:00:02.0/usb1/1-1/1-1:1.0/0003:0627:0001.0001/input/input0 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: raid6: altivecx8 gen() 13464 MB/s 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v1.11 Keyboard [QEMU QEMU USB Keyboard] on usb-0000:00:02.0-1/input0 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: raid6: altivecx4 gen() 13054 MB/s 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usb 1-2: new high-speed USB device number 3 using xhci_hcd 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: raid6: altivecx2 gen() 10541 MB/s 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: raid6: altivecx1 gen() 8056 MB/s 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usb 1-2: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=9 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usb 1-2: Product: QEMU USB Mouse 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usb 1-2: Manufacturer: QEMU 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: usb 1-2: SerialNumber: 89126-pci@800000020000000:02.0-2 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: input: QEMU QEMU USB Mouse as /devices/pci0000:00/0000:00:02.0/usb1/1-2/1-2:1.0/0003:0627:0001.0002/input/input1 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: hid-generic 0003:0627:0001.0002: input,hidraw1: USB HID v0.01 Mouse [QEMU QEMU USB Mouse] on usb-0000:00:02.0-2/input0 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: raid6: int64x8 gen() 6814 MB/s 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: raid6: int64x4 gen() 7933 MB/s 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: raid6: int64x2 gen() 5654 MB/s 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: raid6: int64x1 gen() 5074 MB/s 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: raid6: using algorithm altivecx8 gen() 13464 MB/s 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: raid6: using intx1 recovery algorithm 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: xor: measuring software checksum speed 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: 8regs : 17311 MB/sec 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: 8regs_prefetch : 15954 MB/sec 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: 32regs : 17285 MB/sec 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: 32regs_prefetch : 15510 MB/sec 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: altivec : 19174 MB/sec 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: xor: using function: altivec (19174 MB/sec) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Btrfs loaded, zoned=yes, fsverity=yes 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: EXT4-fs (vda1): orphan cleanup on readonly fs 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: EXT4-fs (vda1): mounted filesystem b421051a-5f17-47ac-ade0-d9d9c5a5c13f ro with ordered data mode. Quota mode: none. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Inserted module 'autofs4' 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: systemd 256.4-2ubuntu1 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) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Detected virtualization kvm. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Detected architecture ppc64-le. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Hostname set to . 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: bpf-restrict-fs: BPF LSM hook not enabled in the kernel, BPF LSM not supported. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: NET: Registered PF_VSOCK protocol family 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i 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. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i 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. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Queued start job for default target graphical.target. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Created slice system-autopkgtest.slice - Slice /system/autopkgtest. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Created slice system-modprobe.slice - Slice /system/modprobe. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Created slice system-serial\x2dgetty.slice - Slice /system/serial-getty. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Created slice user.slice - User and Session Slice. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Started systemd-ask-password-wall.path - Forward Password Requests to Wall Directory Watch. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Set up automount proc-sys-fs-binfmt_misc.automount - Arbitrary Executable File Formats File System Automount Point. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Expecting device dev-hvc0.device - /dev/hvc0... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Reached target integritysetup.target - Local Integrity Protected Volumes. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Reached target remote-fs.target - Remote File Systems. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Reached target slices.target - Slice Units. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Reached target swap.target - Swaps. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Reached target veritysetup.target - Local Verity Protected Volumes. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Listening on syslog.socket - Syslog Socket. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Listening on systemd-creds.socket - Credential Encryption/Decryption. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Listening on systemd-fsckd.socket - fsck to fsckd communication Socket. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Listening on systemd-initctl.socket - initctl Compatibility Named Pipe. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Listening on systemd-journald-dev-log.socket - Journal Socket (/dev/log). 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Listening on systemd-journald.socket - Journal Sockets. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Listening on systemd-networkd.socket - Network Service Netlink Socket. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Listening on systemd-udevd-control.socket - udev Control Socket. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Listening on systemd-udevd-kernel.socket - udev Kernel Socket. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Mounting dev-hugepages.mount - Huge Pages File System... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Mounting dev-mqueue.mount - POSIX Message Queue File System... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Mounting run-lock.mount - Legacy Locks Directory /run/lock... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Mounting sys-kernel-debug.mount - Kernel Debug File System... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Mounting sys-kernel-tracing.mount - Kernel Trace File System... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting systemd-journald.service - Journal Service... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting keyboard-setup.service - Set the console keyboard layout... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting kmod-static-nodes.service - Create List of Static Device Nodes... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting modprobe@configfs.service - Load Kernel Module configfs... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting modprobe@dm_multipath.service - Load Kernel Module dm_multipath... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting modprobe@drm.service - Load Kernel Module drm... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting modprobe@fuse.service - Load Kernel Module fuse... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: netplan-ovs-cleanup.service - OpenVSwitch configuration for cleanup was skipped because of an unmet condition check (ConditionFileIsExecutable=/usr/bin/ovs-vsctl). 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i 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). 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i 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). 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting systemd-modules-load.service - Load Kernel Modules... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting systemd-remount-fs.service - Remount Root and Kernel File Systems... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting systemd-udev-load-credentials.service - Load udev Rules from Credentials... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting systemd-udev-trigger.service - Coldplug All udev Devices... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Mounted dev-hugepages.mount - Huge Pages File System. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Mounted dev-mqueue.mount - POSIX Message Queue File System. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Mounted run-lock.mount - Legacy Locks Directory /run/lock. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Mounted sys-kernel-debug.mount - Kernel Debug File System. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Mounted sys-kernel-tracing.mount - Kernel Trace File System. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Finished kmod-static-nodes.service - Create List of Static Device Nodes. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: modprobe@configfs.service: Deactivated successfully. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Finished modprobe@configfs.service - Load Kernel Module configfs. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: modprobe@dm_multipath.service: Deactivated successfully. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Finished modprobe@dm_multipath.service - Load Kernel Module dm_multipath. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: modprobe@drm.service: Deactivated successfully. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Finished modprobe@drm.service - Load Kernel Module drm. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd-journald[280]: Collecting audit messages is disabled. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: modprobe@fuse.service: Deactivated successfully. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Finished modprobe@fuse.service - Load Kernel Module fuse. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Finished systemd-modules-load.service - Load Kernel Modules. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Finished systemd-udev-load-credentials.service - Load udev Rules from Credentials. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Mounting sys-fs-fuse-connections.mount - FUSE Control File System... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: EXT4-fs (vda1): re-mounted b421051a-5f17-47ac-ade0-d9d9c5a5c13f r/w. Quota mode: none. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Mounting sys-kernel-config.mount - Kernel Configuration File System... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting systemd-sysctl.service - Apply Kernel Variables... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd-journald[280]: Journal started 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd-journald[280]: Runtime Journal (/run/log/journal/dfe3593ae176490a978a99e3bcd2119a) is 8M, max 78.4M, 70.4M free. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Started systemd-journald.service - Journal Service. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Finished keyboard-setup.service - Set the console keyboard layout. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Finished systemd-remount-fs.service - Remount Root and Kernel File Systems. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Mounted sys-fs-fuse-connections.mount - FUSE Control File System. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Mounted sys-kernel-config.mount - Kernel Configuration File System. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting cloud-init-main.service - Cloud-init: Single Process... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: systemd-hwdb-update.service - Rebuild Hardware Database was skipped because of an unmet condition check (ConditionNeedsUpdate=/etc). 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting systemd-journal-flush.service - Flush Journal to Persistent Storage... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore). 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting systemd-random-seed.service - Load/Save OS Random Seed... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Finished systemd-sysctl.service - Apply Kernel Variables. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd-journald[280]: Time spent on flushing to /var/log/journal/dfe3593ae176490a978a99e3bcd2119a is 32.037ms for 463 entries. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd-journald[280]: System Journal (/var/log/journal/dfe3593ae176490a978a99e3bcd2119a) is 18.9M, max 1.9G, 1.9G free. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd-journald[280]: Received client request to flush runtime journal. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i multipathd[328]: multipathd v0.9.9: start up 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i multipathd[328]: reconfigure: setting up paths and maps 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Finished systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: systemd-sysusers.service - Create System Users was skipped because no trigger condition checks were met. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Finished systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting systemd-udevd.service - Rule-based Manager for Device Events and Files... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Reached target local-fs-pre.target - Preparation for Local File Systems. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Reached target local-fs.target - Local File Systems. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Listening on systemd-sysext.socket - System Extension Image Management. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting apparmor.service - Load AppArmor profiles... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting console-setup.service - Set console font and keymap... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: ldconfig.service - Rebuild Dynamic Linker Cache was skipped because no trigger condition checks were met. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting plymouth-read-write.service - Tell Plymouth To Write Out Runtime Data... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting systemd-binfmt.service - Set Up Additional Binary Formats... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting ufw.service - Uncomplicated firewall... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Finished systemd-journal-flush.service - Flush Journal to Persistent Storage. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Finished systemd-random-seed.service - Load/Save OS Random Seed. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Finished console-setup.service - Set console font and keymap. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting systemd-tmpfiles-setup.service - Create System Files and Directories... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: proc-sys-fs-binfmt_misc.automount: Got automount request for /proc/sys/fs/binfmt_misc, triggered by 352 (systemd-binfmt) 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i apparmor.systemd[348]: Restarting AppArmor 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Finished plymouth-read-write.service - Tell Plymouth To Write Out Runtime Data. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Finished ufw.service - Uncomplicated firewall. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd-udevd[340]: Using default interface naming scheme 'v255'. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i apparmor.systemd[348]: Reloading AppArmor profiles 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd-tmpfiles[362]: /usr/lib/tmpfiles.d/legacy.conf:13: Duplicate line for path "/run/lock", ignoring. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: audit: type=1400 audit(1725964893.676:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="QtWebEngineProcess" pid=375 comm="apparmor_parser" 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: audit: type=1400 audit(1725964893.676:3): apparmor="STATUS" operation="profile_load" profile="unconfined" name="Discord" pid=373 comm="apparmor_parser" 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: audit: type=1400 audit(1725964893.676:4): apparmor="STATUS" operation="profile_load" profile="unconfined" name="1password" pid=372 comm="apparmor_parser" 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: audit: type=1400 audit(1725964893.676:5): apparmor="STATUS" operation="profile_load" profile="unconfined" name=4D6F6E676F444220436F6D70617373 pid=374 comm="apparmor_parser" 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Finished systemd-tmpfiles-setup.service - Create System Files and Directories. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: systemd-firstboot.service - First Boot Wizard was skipped because of an unmet condition check (ConditionFirstBoot=yes). 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: first-boot-complete.target - First Boot Complete was skipped because of an unmet condition check (ConditionFirstBoot=yes). 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: systemd-journal-catalog-update.service - Rebuild Journal Catalog was skipped because of an unmet condition check (ConditionNeedsUpdate=/var). 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i 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). 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting systemd-resolved.service - Network Name Resolution... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: audit: type=1400 audit(1725964893.684:6): apparmor="STATUS" operation="profile_load" profile="unconfined" name="buildah" pid=379 comm="apparmor_parser" 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: audit: type=1400 audit(1725964893.684:7): apparmor="STATUS" operation="profile_load" profile="unconfined" name="brave" pid=378 comm="apparmor_parser" 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: audit: type=1400 audit(1725964893.684:8): apparmor="STATUS" operation="profile_load" profile="unconfined" name="balena-etcher" pid=377 comm="apparmor_parser" 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: audit: type=1400 audit(1725964893.684:9): apparmor="STATUS" operation="profile_load" profile="unconfined" name="busybox" pid=381 comm="apparmor_parser" 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: audit: type=1400 audit(1725964893.684:10): apparmor="STATUS" operation="profile_load" profile="unconfined" name="cam" pid=382 comm="apparmor_parser" 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting systemd-timesyncd.service - Network Time Synchronization... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: systemd-update-done.service - Update is Completed was skipped because no trigger condition checks were met. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting systemd-update-utmp.service - Record System Boot/Shutdown in UTMP... 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Finished systemd-udev-trigger.service - Coldplug All udev Devices. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Started systemd-udevd.service - Rule-based Manager for Device Events and Files. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: plymouth-start.service - Show Plymouth Boot Screen was skipped because of an unmet condition check (ConditionKernelCommandLine=splash). 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Started systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i 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). 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Reached target cryptsetup.target - Local Encrypted Volumes. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Finished systemd-update-utmp.service - Record System Boot/Shutdown in UTMP. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Found device dev-hvc0.device - /dev/hvc0. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Finished apparmor.service - Load AppArmor profiles. 345s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Listening on systemd-rfkill.socket - Load/Save RF Kill Switch Status /dev/rfkill Watch. 345s Sep 10 10:41:34 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Started cloud-init-main.service - Cloud-init: Single Process. 345s Sep 10 10:41:34 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting cloud-init-local.service - Cloud-init: Local Stage (pre-network)... 345s Sep 10 10:41:34 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i cloud-init[682]: Cloud-init v. 24.4~3+really24.3.1-0ubuntu1 running 'init-local' at Tue, 10 Sep 2024 10:41:34 +0000. Up 3.14 seconds. 345s Sep 10 10:41:34 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i dhcpcd[685]: dhcpcd-10.0.8 starting 345s Sep 10 10:41:34 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i dhcpcd[688]: DUID 00:01:00:01:2e:71:cd:c1:fa:16:3e:e7:13:df 345s Sep 10 10:41:34 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: 8021q: 802.1Q VLAN Support v1.8 345s Sep 10 10:41:34 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: 8021q: adding VLAN 0 to HW filter on device enp0s1 345s Sep 10 10:41:34 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Mounting proc-sys-fs-binfmt_misc.mount - Arbitrary Executable File Formats File System... 345s Sep 10 10:41:34 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database 345s Sep 10 10:41:34 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' 345s Sep 10 10:41:34 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i kernel: Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600' 345s Sep 10 10:41:34 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i dhcpcd[688]: enp0s1: IAID 3e:7d:91:36 345s Sep 10 10:41:34 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Mounted proc-sys-fs-binfmt_misc.mount - Arbitrary Executable File Formats File System. 345s Sep 10 10:41:34 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Finished systemd-binfmt.service - Set Up Additional Binary Formats. 345s Sep 10 10:41:34 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Started systemd-timesyncd.service - Network Time Synchronization. 345s Sep 10 10:41:34 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Reached target time-set.target - System Time Set. 345s Sep 10 10:41:34 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd-resolved[384]: Positive Trust Anchors: 345s Sep 10 10:41:34 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd-resolved[384]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d 345s Sep 10 10:41:34 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd-resolved[384]: 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 345s Sep 10 10:41:34 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd-resolved[384]: Using system hostname 'auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i'. 345s Sep 10 10:41:34 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Started systemd-resolved.service - Network Name Resolution. 345s Sep 10 10:41:34 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Reached target nss-lookup.target - Host and Network Name Lookups. 345s Sep 10 10:41:36 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i dhcpcd[688]: enp0s1: soliciting a DHCP lease 345s Sep 10 10:41:36 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i dhcpcd[688]: enp0s1: offered 10.145.227.123 from 10.145.227.1 345s Sep 10 10:41:36 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i dhcpcd[688]: enp0s1: leased 10.145.227.123 for 43200 seconds 345s Sep 10 10:41:36 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i dhcpcd[688]: enp0s1: adding route to 10.145.227.0/24 345s Sep 10 10:41:36 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i dhcpcd[688]: enp0s1: adding host route to 169.254.169.254 via 10.145.227.2 345s Sep 10 10:41:36 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i dhcpcd[688]: enp0s1: adding default route via 10.145.227.1 345s Sep 10 10:41:36 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i dhcpcd[688]: control command: /usr/sbin/dhcpcd --dumplease --ipv4only enp0s1 345s Sep 10 10:41:43 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd-resolved[384]: System hostname changed to 'adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227'. 345s Sep 10 10:41:43 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd[1]: netplan-ovs-cleanup.service - OpenVSwitch configuration for cleanup was skipped because of an unmet condition check (ConditionFileIsExecutable=/usr/bin/ovs-vsctl). 345s Sep 10 10:41:43 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd[1]: netplan-ovs-cleanup.service - OpenVSwitch configuration for cleanup was skipped because of an unmet condition check (ConditionFileIsExecutable=/usr/bin/ovs-vsctl). 345s Sep 10 10:41:43 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd[1]: netplan-ovs-cleanup.service - OpenVSwitch configuration for cleanup was skipped because of an unmet condition check (ConditionFileIsExecutable=/usr/bin/ovs-vsctl). 345s Sep 10 10:41:43 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd[1]: Reload requested from client PID 731 ('systemctl') (unit cloud-init-main.service)... 345s Sep 10 10:41:43 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd[1]: Reloading... 345s Sep 10 10:41:43 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 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. 345s Sep 10 10:41:43 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 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. 345s Sep 10 10:41:43 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd[1]: Reloading finished in 256 ms. 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 sh[678]: Completed socket interaction for boot stage local 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd[1]: Finished cloud-init-local.service - Cloud-init: Local Stage (pre-network). 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd[1]: Reached target network-pre.target - Preparation for Network. 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd[1]: Starting systemd-networkd.service - Network Configuration... 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd-networkd[766]: /run/systemd/network/10-netplan-enp0s1.network: MTUBytes= in [Link] section and UseMTU= in [DHCP] section are set. Disabling UseMTU=. 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd-networkd[766]: lo: Link UP 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd-networkd[766]: lo: Gained carrier 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd-networkd[766]: Enumeration completed 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd-networkd[766]: enp0s1: Link UP 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd-networkd[766]: enp0s1: Gained carrier 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd[1]: Started systemd-networkd.service - Network Configuration. 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd-networkd[766]: enp0s1: Gained IPv6LL 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd-timesyncd[387]: Network configuration changed, trying to establish connection. 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd[1]: Reached target network.target - Network. 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd-timesyncd[387]: Network configuration changed, trying to establish connection. 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd-networkd[766]: enp0s1: Link DOWN 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd-networkd[766]: enp0s1: Lost carrier 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd[1]: Starting systemd-networkd-persistent-storage.service - Enable Persistent Storage in systemd-networkd... 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd[1]: Starting systemd-networkd-wait-online.service - Wait for Network to be Configured... 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd-networkd[766]: enp0s1: Configuring with /run/systemd/network/10-netplan-enp0s1.network. 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 kernel: 8021q: adding VLAN 0 to HW filter on device enp0s1 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd-networkd[766]: enp0s1: Link UP 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd-networkd[766]: enp0s1: Gained carrier 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd[1]: Finished systemd-networkd-persistent-storage.service - Enable Persistent Storage in systemd-networkd. 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd-networkd[766]: enp0s1: DHCPv4 address 10.145.227.123/24, gateway 10.145.227.1 acquired from 10.145.227.1 345s Sep 10 10:41:44 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd-timesyncd[387]: Network configuration changed, trying to establish connection. 345s Sep 10 10:41:45 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd-networkd[766]: enp0s1: Gained IPv6LL 345s Sep 10 10:41:45 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd-timesyncd[387]: Network configuration changed, trying to establish connection. 345s Sep 10 10:41:45 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd[1]: Finished systemd-networkd-wait-online.service - Wait for Network to be Configured. 345s Sep 10 10:41:45 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd[1]: Starting cloud-init-network.service - Cloud-init: Network Stage... 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd-resolved[384]: Clock change detected. Flushing caches. 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd-timesyncd[387]: Contacted time server 185.125.190.56:123 (ntp.ubuntu.com). 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 systemd-timesyncd[387]: Initial clock synchronization to Tue 2024-09-10 10:41:46.284320 UTC. 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: Cloud-init v. 24.4~3+really24.3.1-0ubuntu1 running 'init' at Tue, 10 Sep 2024 10:41:45 +0000. Up 14.57 seconds. 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: +++++++++++++++++++++++++++++++++++++++Net device info+++++++++++++++++++++++++++++++++++++++ 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: +--------+------+------------------------------+---------------+--------+-------------------+ 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: | Device | Up | Address | Mask | Scope | Hw-Address | 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: +--------+------+------------------------------+---------------+--------+-------------------+ 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: | enp0s1 | True | 10.145.227.123 | 255.255.255.0 | global | fa:16:3e:7d:91:36 | 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: | enp0s1 | True | fe80::f816:3eff:fe7d:9136/64 | . | link | fa:16:3e:7d:91:36 | 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: | lo | True | 127.0.0.1 | 255.0.0.0 | host | . | 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: | lo | True | ::1/128 | . | host | . | 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: +--------+------+------------------------------+---------------+--------+-------------------+ 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: ++++++++++++++++++++++++++++++++Route IPv4 info+++++++++++++++++++++++++++++++++ 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: +-------+-----------------+--------------+-----------------+-----------+-------+ 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: | Route | Destination | Gateway | Genmask | Interface | Flags | 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: +-------+-----------------+--------------+-----------------+-----------+-------+ 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: | 0 | 0.0.0.0 | 10.145.227.1 | 0.0.0.0 | enp0s1 | UG | 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: | 1 | 10.145.227.0 | 0.0.0.0 | 255.255.255.0 | enp0s1 | U | 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: | 2 | 10.145.227.1 | 0.0.0.0 | 255.255.255.255 | enp0s1 | UH | 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: | 3 | 10.145.227.2 | 0.0.0.0 | 255.255.255.255 | enp0s1 | UH | 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: | 4 | 91.189.91.131 | 10.145.227.1 | 255.255.255.255 | enp0s1 | UGH | 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: | 5 | 91.189.91.132 | 10.145.227.1 | 255.255.255.255 | enp0s1 | UGH | 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: | 6 | 169.254.169.254 | 10.145.227.2 | 255.255.255.255 | enp0s1 | UGH | 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: +-------+-----------------+--------------+-----------------+-----------+-------+ 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: +++++++++++++++++++Route IPv6 info+++++++++++++++++++ 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: +-------+-------------+---------+-----------+-------+ 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: | Route | Destination | Gateway | Interface | Flags | 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: +-------+-------------+---------+-----------+-------+ 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: | 0 | fe80::/64 | :: | enp0s1 | U | 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: | 2 | local | :: | enp0s1 | U | 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: | 3 | multicast | :: | enp0s1 | U | 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: ci-info: +-------+-------------+---------+-----------+-------+ 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: 2024-09-10 10:41:46,467 - 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. 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 cloud-init[682]: 2024-09-10 10:41:46,467 - schema.py[WARNING]: cloud-config failed schema validation! You may run 'sudo cloud-init schema --system' to check the details. 345s Sep 10 10:41:46 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 kernel: EXT4-fs (vda1): resizing filesystem from 5240560 to 26212080 blocks 345s Sep 10 10:41:47 adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f227 kernel: EXT4-fs (vda1): resized filesystem to 26212080 345s Sep 10 10:41:47 autopkgtest systemd-resolved[384]: System hostname changed to 'autopkgtest'. 345s Sep 10 10:41:47 autopkgtest passwd[853]: password for 'ubuntu' changed by 'root' 345s Sep 10 10:41:47 autopkgtest sh[777]: Completed socket interaction for boot stage network 345s Sep 10 10:41:47 autopkgtest systemd[1]: Finished cloud-init-network.service - Cloud-init: Network Stage. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Reached target cloud-config.target - Cloud-config availability. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Reached target network-online.target - Network is Online. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Reached target sysinit.target - System Initialization. 345s Sep 10 10:41:47 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). 345s Sep 10 10:41:47 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). 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started apt-daily.timer - Daily apt download activities. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started apt-daily-upgrade.timer - Daily apt upgrade and clean activities. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started dpkg-db-backup.timer - Daily dpkg database backup timer. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started e2scrub_all.timer - Periodic ext4 Online Metadata Check for All Filesystems. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started fstrim.timer - Discard unused filesystem blocks once a week. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started fwupd-refresh.timer - Refresh fwupd metadata regularly. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started logrotate.timer - Daily rotation of log files. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started man-db.timer - Daily man-db regeneration. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started motd-news.timer - Message of the Day. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started sysstat-collect.timer - Run system activity accounting tool every 10 minutes. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started sysstat-rotate.timer - Rotate daily system activity data file at midnight. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started sysstat-summary.timer - Generate summary of yesterday's process accounting. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started systemd-tmpfiles-clean.timer - Daily Cleanup of Temporary Directories. 345s Sep 10 10:41:47 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). 345s Sep 10 10:41:47 autopkgtest systemd[1]: Reached target boot-complete.target - Boot Completion Check. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Reached target paths.target - Path Units. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Reached target timers.target - Timer Units. 345s Sep 10 10:41:47 autopkgtest systemd[1]: apport-forward.socket - Unix socket for apport crash forwarding was skipped because of an unmet condition check (ConditionVirtualization=container). 345s Sep 10 10:41:47 autopkgtest systemd[1]: Listening on cloud-init-hotplugd.socket - cloud-init hotplug hook socket. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Listening on dbus.socket - D-Bus System Message Bus Socket. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Starting lxd-installer.socket - Helper to install lxd snap on demand... 345s Sep 10 10:41:47 autopkgtest systemd[1]: Listening on ssh.socket - OpenBSD Secure Shell server socket. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Listening on sshd-unix-local.socket - OpenSSH Server Socket (systemd-ssh-generator, AF_UNIX Local). 345s Sep 10 10:41:47 autopkgtest systemd[1]: Listening on sshd-vsock.socket - OpenSSH Server Socket (systemd-ssh-generator, AF_VSOCK). 345s Sep 10 10:41:47 autopkgtest systemd[1]: Reached target ssh-access.target - SSH Access Available. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Listening on systemd-hostnamed.socket - Hostname Service Socket. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Listening on uuidd.socket - UUID daemon activation socket. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Listening on lxd-installer.socket - Helper to install lxd snap on demand. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Reached target sockets.target - Socket Units. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Reached target basic.target - Basic System. 345s Sep 10 10:41:47 autopkgtest systemd[1]: System is tainted: unmerged-bin 345s Sep 10 10:41:47 autopkgtest systemd[1]: Starting apport.service - automatic crash report generation... 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started autopkgtest@hvc1.service - autopkgtest root shell on hvc1. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started autopkgtest@ttyS1.service - autopkgtest root shell on ttyS1. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Starting cloud-config.service - Cloud-init: Config Stage... 345s Sep 10 10:41:47 autopkgtest (sh)[866]: autopkgtest@hvc1.service: Failed to set up standard input: No such device 345s Sep 10 10:41:47 autopkgtest (sh)[867]: autopkgtest@ttyS1.service: Failed to set up standard input: Input/output error 345s Sep 10 10:41:47 autopkgtest (sh)[867]: autopkgtest@ttyS1.service: Failed at step STDIN spawning /bin/sh: Input/output error 345s Sep 10 10:41:47 autopkgtest (sh)[866]: autopkgtest@hvc1.service: Failed at step STDIN spawning /bin/sh: No such device 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started cron.service - Regular background program processing daemon. 345s Sep 10 10:41:47 autopkgtest (cron)[869]: cron.service: Referenced but unset environment variable evaluates to an empty string: EXTRA_OPTS 345s Sep 10 10:41:47 autopkgtest systemd[1]: Starting dbus.service - D-Bus System Message Bus... 345s Sep 10 10:41:47 autopkgtest cron[869]: (CRON) INFO (pidfile fd = 3) 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started dmesg.service - Save initial kernel messages after boot. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... 345s Sep 10 10:41:47 autopkgtest cron[869]: (CRON) INFO (Running @reboot jobs) 345s Sep 10 10:41:47 autopkgtest systemd[1]: Starting e2scrub_reap.service - Remove Stale Online ext4 Metadata Check Snapshots... 345s Sep 10 10:41:47 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). 345s Sep 10 10:41:47 autopkgtest systemd[1]: Starting grub-common.service - Record successful boot for GRUB... 345s Sep 10 10:41:47 autopkgtest systemd[1]: Starting iprdump.service - IBM Power Raid dump daemon... 345s Sep 10 10:41:47 autopkgtest systemd[1]: networkd-dispatcher.service - Dispatcher daemon for systemd-networkd was skipped because no trigger condition checks were met. 345s Sep 10 10:41:47 autopkgtest systemd[1]: opal_errd.service - opal_errd (PowerNV platform error handling) Service was skipped because of an unmet condition check (ConditionVirtualization=false). 345s Sep 10 10:41:47 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). 345s Sep 10 10:41:47 autopkgtest systemd[1]: Starting rc-local.service - /etc/rc.local Compatibility... 345s Sep 10 10:41:47 autopkgtest systemd[1]: Starting rng-tools-debian.service - LSB: rng-tools (Debian variant)... 345s Sep 10 10:41:47 autopkgtest systemd[1]: Starting rsyslog.service - System Logging Service... 345s Sep 10 10:41:47 autopkgtest systemd[1]: Starting rtas_errd.service - ppc64-diag rtas_errd (platform error handling) Service... 345s Sep 10 10:41:47 autopkgtest dbus-daemon[873]: [system] AppArmor D-Bus mediation is enabled 345s Sep 10 10:41:47 autopkgtest systemd[1]: Starting sysstat.service - Resets System Activity Logs... 345s Sep 10 10:41:47 autopkgtest systemd[1]: Starting systemd-logind.service - User Login Management... 345s Sep 10 10:41:47 autopkgtest systemd[1]: Starting systemd-user-sessions.service - Permit User Sessions... 345s Sep 10 10:41:47 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). 345s Sep 10 10:41:47 autopkgtest systemd[1]: ubuntu-advantage.service - Ubuntu Pro Background Auto Attach was skipped because no trigger condition checks were met. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Starting udisks2.service - Disk Manager... 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started dbus.service - D-Bus System Message Bus. 345s Sep 10 10:41:47 autopkgtest systemd[1]: autopkgtest@hvc1.service: Deactivated successfully. 345s Sep 10 10:41:47 autopkgtest systemd[1]: autopkgtest@ttyS1.service: Deactivated successfully. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started iprdump.service - IBM Power Raid dump daemon. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Starting iprinit.service - IBM Power Raid init daemon... 345s Sep 10 10:41:47 autopkgtest systemd[1]: Starting iprupdate.service - IBM Power Raid update daemon... 345s Sep 10 10:41:47 autopkgtest udisksd[891]: udisks daemon version 2.10.1 starting 345s Sep 10 10:41:47 autopkgtest systemd[1]: Finished systemd-user-sessions.service - Permit User Sessions. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started iprinit.service - IBM Power Raid init daemon. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started rc-local.service - /etc/rc.local Compatibility. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started iprupdate.service - IBM Power Raid update daemon. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Reached target iprutils.target - IBM Power Raid utilities. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Starting plymouth-quit-wait.service - Hold until boot process finishes up... 345s Sep 10 10:41:47 autopkgtest systemd[1]: Starting plymouth-quit.service - Terminate Plymouth Boot Screen... 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started rtas_errd.service - ppc64-diag rtas_errd (platform error handling) Service. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Finished sysstat.service - Resets System Activity Logs. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started serial-getty@hvc0.service - Serial Getty on hvc0. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Starting setvtrgb.service - Set console scheme... 345s Sep 10 10:41:47 autopkgtest systemd[1]: Finished plymouth-quit.service - Terminate Plymouth Boot Screen. 345s Sep 10 10:41:47 autopkgtest rngd[950]: rngd 2.4 starting up... 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started rng-tools-debian.service - LSB: rng-tools (Debian variant). 345s Sep 10 10:41:47 autopkgtest systemd[1]: Finished setvtrgb.service - Set console scheme. 345s Sep 10 10:41:47 autopkgtest rngd[950]: entropy feed to the kernel ready 345s Sep 10 10:41:47 autopkgtest systemd[1]: Created slice system-getty.slice - Slice /system/getty. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started getty@tty1.service - Getty on tty1. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Reached target getty.target - Login Prompts. 345s Sep 10 10:41:47 autopkgtest systemd[1]: grub-common.service: Deactivated successfully. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Finished grub-common.service - Record successful boot for GRUB. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Starting grub-initrd-fallback.service - GRUB failed boot detection... 345s Sep 10 10:41:47 autopkgtest cloud-init[682]: Cloud-init v. 24.4~3+really24.3.1-0ubuntu1 running 'modules:config' at Tue, 10 Sep 2024 10:41:47 +0000. Up 15.94 seconds. 345s Sep 10 10:41:47 autopkgtest systemd-logind[887]: New seat seat0. 345s Sep 10 10:41:47 autopkgtest systemd[1]: e2scrub_reap.service: Deactivated successfully. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Finished e2scrub_reap.service - Remove Stale Online ext4 Metadata Check Snapshots. 345s Sep 10 10:41:47 autopkgtest systemd-logind[887]: Watching system buttons on /dev/input/event0 (QEMU QEMU USB Keyboard) 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started systemd-logind.service - User Login Management. 345s Sep 10 10:41:47 autopkgtest systemd[1]: grub-initrd-fallback.service: Deactivated successfully. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Finished grub-initrd-fallback.service - GRUB failed boot detection. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started udisks2.service - Disk Manager. 345s Sep 10 10:41:47 autopkgtest udisksd[891]: Acquired the name org.freedesktop.UDisks2 on the system message bus 345s Sep 10 10:41:47 autopkgtest kernel: kauditd_printk_skb: 110 callbacks suppressed 345s Sep 10 10:41:47 autopkgtest kernel: audit: type=1400 audit(1725964907.816:121): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="rsyslogd" pid=969 comm="apparmor_parser" 345s Sep 10 10:41:47 autopkgtest systemd[1]: dpkg-db-backup.service: Deactivated successfully. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. 345s Sep 10 10:41:47 autopkgtest rsyslogd[1015]: imuxsock: Acquired UNIX socket '/run/systemd/journal/syslog' (fd 3) from systemd. [v8.2406.0] 345s Sep 10 10:41:47 autopkgtest rsyslogd[1015]: rsyslogd's groupid changed to 102 345s Sep 10 10:41:47 autopkgtest systemd[1]: Started rsyslog.service - System Logging Service. 345s Sep 10 10:41:47 autopkgtest rsyslogd[1015]: rsyslogd's userid changed to 102 345s Sep 10 10:41:47 autopkgtest rsyslogd[1015]: [origin software="rsyslogd" swVersion="8.2406.0" x-pid="1015" x-info="https://www.rsyslog.com"] start 345s Sep 10 10:41:47 autopkgtest systemd[1]: Finished apport.service - automatic crash report generation. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Reached target multi-user.target - Multi-User System. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Reached target graphical.target - Graphical Interface. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... 345s Sep 10 10:41:47 autopkgtest systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. 345s Sep 10 10:41:47 autopkgtest systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. 345s Sep 10 10:41:48 autopkgtest cloud-init[682]: 2024-09-10 10:41:48,044 - lifecycle.py[DEPRECATED]: The following config key(s): ['apt_mirror', 'apt_preserve_sources_list'] is deprecated in 22.1 and scheduled to be removed in 27.1. 345s Sep 10 10:41:48 autopkgtest cloud-init[682]: 2024-09-10 10:41:48,044 - lifecycle.py[DEPRECATED]: Support for combined old and new apt module keys is deprecated in 22.1 and scheduled to be removed in 27.1. 345s Sep 10 10:41:48 autopkgtest sh[872]: Completed socket interaction for boot stage config 345s Sep 10 10:41:48 autopkgtest systemd[1]: Finished cloud-config.service - Cloud-init: Config Stage. 345s Sep 10 10:41:48 autopkgtest systemd[1]: Starting cloud-final.service - Cloud-init: Final Stage... 345s Sep 10 10:41:48 autopkgtest cloud-init[682]: Cloud-init v. 24.4~3+really24.3.1-0ubuntu1 running 'modules:final' at Tue, 10 Sep 2024 10:41:48 +0000. Up 16.42 seconds. 345s Sep 10 10:41:48 autopkgtest systemd[1]: Starting apt-news.service - Update APT News... 345s Sep 10 10:41:48 autopkgtest systemd[1]: Starting esm-cache.service - Update the local ESM caches... 345s Sep 10 10:41:48 autopkgtest cloud-init[682]: Get:1 http://ftpmaster.internal/ubuntu oracular InRelease [126 kB] 345s Sep 10 10:41:48 autopkgtest systemd[1]: esm-cache.service: Deactivated successfully. 345s Sep 10 10:41:48 autopkgtest systemd[1]: Finished esm-cache.service - Update the local ESM caches. 345s Sep 10 10:41:48 autopkgtest systemd[1]: apt-news.service: Deactivated successfully. 345s Sep 10 10:41:48 autopkgtest systemd[1]: Finished apt-news.service - Update APT News. 345s Sep 10 10:41:48 autopkgtest cloud-init[682]: Hit:2 http://ftpmaster.internal/ubuntu oracular-updates InRelease 345s Sep 10 10:41:48 autopkgtest cloud-init[682]: Hit:3 http://ftpmaster.internal/ubuntu oracular-security InRelease 345s Sep 10 10:41:48 autopkgtest cloud-init[682]: Get:4 http://ftpmaster.internal/ubuntu oracular/universe Sources [20.4 MB] 345s Sep 10 10:41:49 autopkgtest cloud-init[682]: Get:5 http://ftpmaster.internal/ubuntu oracular/main Sources [1375 kB] 345s Sep 10 10:41:49 autopkgtest cloud-init[682]: Get:6 http://ftpmaster.internal/ubuntu oracular/multiverse Sources [300 kB] 345s Sep 10 10:41:49 autopkgtest cloud-init[682]: Get:7 http://ftpmaster.internal/ubuntu oracular/main ppc64el Packages [1395 kB] 345s Sep 10 10:41:50 autopkgtest cloud-init[682]: Get:8 http://ftpmaster.internal/ubuntu oracular/main ppc64el c-n-f Metadata [31.3 kB] 345s Sep 10 10:41:50 autopkgtest cloud-init[682]: Get:9 http://ftpmaster.internal/ubuntu oracular/universe ppc64el Packages [15.5 MB] 345s Sep 10 10:41:50 autopkgtest cloud-init[682]: Get:10 http://ftpmaster.internal/ubuntu oracular/universe ppc64el c-n-f Metadata [298 kB] 345s Sep 10 10:41:50 autopkgtest cloud-init[682]: Get:11 http://ftpmaster.internal/ubuntu oracular/multiverse ppc64el Packages [188 kB] 345s Sep 10 10:41:50 autopkgtest systemd[1]: Starting ssh.service - OpenBSD Secure Shell server... 345s Sep 10 10:41:50 autopkgtest sshd[1180]: Server listening on :: port 22. 345s Sep 10 10:41:50 autopkgtest systemd[1]: Started ssh.service - OpenBSD Secure Shell server. 345s Sep 10 10:41:51 autopkgtest sshd[1182]: Accepted publickey for ubuntu from 10.136.6.201 port 44030 ssh2: RSA SHA256:YaYyKWTl9zFJEBK5G3u+MRj3WPJt+vEplFd0J96PUBw 345s Sep 10 10:41:51 autopkgtest sshd[1182]: pam_unix(sshd:session): session opened for user ubuntu(uid=1000) by ubuntu(uid=0) 345s Sep 10 10:41:51 autopkgtest sshd[1182]: pam_systemd(sshd:session): New sd-bus connection (system-bus-pam-systemd-1182) opened. 345s Sep 10 10:41:51 autopkgtest systemd[1]: Created slice user-1000.slice - User Slice of UID 1000. 345s Sep 10 10:41:51 autopkgtest systemd[1]: Starting user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... 345s Sep 10 10:41:51 autopkgtest systemd-logind[887]: New session 1 of user ubuntu. 345s Sep 10 10:41:51 autopkgtest systemd[1]: Finished user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. 345s Sep 10 10:41:51 autopkgtest systemd[1]: Starting user@1000.service - User Manager for UID 1000... 345s Sep 10 10:41:51 autopkgtest (systemd)[1186]: pam_unix(systemd-user:session): session opened for user ubuntu(uid=1000) by ubuntu(uid=0) 345s Sep 10 10:41:51 autopkgtest systemd-logind[887]: New session 2 of user ubuntu. 345s Sep 10 10:41:51 autopkgtest systemd[1186]: Queued start job for default target default.target. 345s Sep 10 10:41:51 autopkgtest systemd[1186]: Created slice app.slice - User Application Slice. 345s Sep 10 10:41:51 autopkgtest systemd[1186]: Started launchpadlib-cache-clean.timer - Clean up old files in the Launchpadlib cache. 345s Sep 10 10:41:51 autopkgtest systemd[1186]: Reached target paths.target - Paths. 345s Sep 10 10:41:51 autopkgtest systemd[1186]: Reached target timers.target - Timers. 345s Sep 10 10:41:51 autopkgtest systemd[1186]: Starting dbus.socket - D-Bus User Message Bus Socket... 345s Sep 10 10:41:51 autopkgtest systemd[1186]: Listening on dirmngr.socket - GnuPG network certificate management daemon. 345s Sep 10 10:41:51 autopkgtest systemd[1186]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). 345s Sep 10 10:41:51 autopkgtest systemd[1186]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). 345s Sep 10 10:41:51 autopkgtest systemd[1186]: Starting gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation)... 345s Sep 10 10:41:51 autopkgtest systemd[1186]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. 345s Sep 10 10:41:51 autopkgtest systemd[1186]: Listening on keyboxd.socket - GnuPG public key management service. 345s Sep 10 10:41:51 autopkgtest systemd[1186]: Listening on dbus.socket - D-Bus User Message Bus Socket. 345s Sep 10 10:41:51 autopkgtest systemd[1186]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). 345s Sep 10 10:41:51 autopkgtest systemd[1186]: Reached target sockets.target - Sockets. 345s Sep 10 10:41:51 autopkgtest systemd[1186]: Reached target basic.target - Basic System. 345s Sep 10 10:41:51 autopkgtest systemd[1186]: Reached target default.target - Main User Target. 345s Sep 10 10:41:51 autopkgtest systemd[1186]: Startup finished in 165ms. 345s Sep 10 10:41:51 autopkgtest systemd[1]: Started user@1000.service - User Manager for UID 1000. 345s Sep 10 10:41:51 autopkgtest systemd[1]: Started session-1.scope - Session 1 of User ubuntu. 345s Sep 10 10:41:51 autopkgtest sshd[1212]: Received disconnect from 10.136.6.201 port 44030:11: disconnected by user 345s Sep 10 10:41:51 autopkgtest sshd[1212]: Disconnected from user ubuntu 10.136.6.201 port 44030 345s Sep 10 10:41:51 autopkgtest sshd[1182]: pam_unix(sshd:session): session closed for user ubuntu 345s Sep 10 10:41:51 autopkgtest sshd[1182]: pam_systemd(sshd:session): New sd-bus connection (system-bus-pam-systemd-1182) opened. 345s Sep 10 10:41:51 autopkgtest systemd[1]: session-1.scope: Deactivated successfully. 345s Sep 10 10:41:51 autopkgtest systemd-logind[887]: Session 1 logged out. Waiting for processes to exit. 345s Sep 10 10:41:51 autopkgtest systemd-logind[887]: Removed session 1. 345s Sep 10 10:41:52 autopkgtest sshd[1215]: Accepted publickey for ubuntu from 10.136.6.201 port 39808 ssh2: RSA SHA256:YaYyKWTl9zFJEBK5G3u+MRj3WPJt+vEplFd0J96PUBw 345s Sep 10 10:41:52 autopkgtest sshd[1215]: pam_unix(sshd:session): session opened for user ubuntu(uid=1000) by ubuntu(uid=0) 345s Sep 10 10:41:52 autopkgtest sshd[1215]: pam_systemd(sshd:session): New sd-bus connection (system-bus-pam-systemd-1215) opened. 345s Sep 10 10:41:52 autopkgtest systemd-logind[887]: New session 3 of user ubuntu. 345s Sep 10 10:41:52 autopkgtest systemd[1]: Started session-3.scope - Session 3 of User ubuntu. 345s Sep 10 10:41:52 autopkgtest kernel: fbcon: Taking over console 345s Sep 10 10:41:52 autopkgtest kernel: Console: switching to colour frame buffer device 128x48 345s Sep 10 10:41:52 autopkgtest systemd[1]: dmesg.service: Deactivated successfully. 345s Sep 10 10:41:57 autopkgtest cloud-init[682]: Fetched 39.7 MB in 7s (5364 kB/s) 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: Reading package lists... 345s Sep 10 10:41:58 autopkgtest cloud-init[1306]: ############################################################# 345s Sep 10 10:41:58 autopkgtest cloud-init[1307]: -----BEGIN SSH HOST KEY FINGERPRINTS----- 345s Sep 10 10:41:58 autopkgtest cloud-init[1309]: 256 SHA256:H5h/cPfEsTWhNRE5w/pRyxHeRQ/jZhLww3L3buiQrpQ root@autopkgtest (ECDSA) 345s Sep 10 10:41:58 autopkgtest cloud-init[1311]: 256 SHA256:L2vohwROwexx3NGWBcCuz/ROv/uqZXycnM67F/ohAvU root@autopkgtest (ED25519) 345s Sep 10 10:41:58 autopkgtest cloud-init[1313]: 3072 SHA256:cDu+C6BwowR4kxDWsxBMQketo7DzFPpSu+XXlF0q6is root@autopkgtest (RSA) 345s Sep 10 10:41:58 autopkgtest cloud-init[1314]: -----END SSH HOST KEY FINGERPRINTS----- 345s Sep 10 10:41:58 autopkgtest cloud-init[1315]: ############################################################# 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: Cloud-init v. 24.4~3+really24.3.1-0ubuntu1 finished at Tue, 10 Sep 2024 10:41:58 +0000. Datasource DataSourceOpenStackLocal [net,ver=2]. Up 26.80 seconds 345s Sep 10 10:41:58 autopkgtest sh[1056]: Completed socket interaction for boot stage final 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: Generating public/private rsa key pair. 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: Your identification has been saved in /etc/ssh/ssh_host_rsa_key 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: Your public key has been saved in /etc/ssh/ssh_host_rsa_key.pub 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: The key fingerprint is: 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: SHA256:cDu+C6BwowR4kxDWsxBMQketo7DzFPpSu+XXlF0q6is root@autopkgtest 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: The key's randomart image is: 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: +---[RSA 3072]----+ 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: |B*+o. | 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: |++.+ . | 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: |o = + . . | 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: |o..= o . . | 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: |o++.o So o | 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: |==oo . .+.o | 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: |.*... .+.. | 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: |. +oE o... | 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: | ....+o.o. | 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: +----[SHA256]-----+ 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: Generating public/private ecdsa key pair. 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: Your identification has been saved in /etc/ssh/ssh_host_ecdsa_key 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: Your public key has been saved in /etc/ssh/ssh_host_ecdsa_key.pub 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: The key fingerprint is: 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: SHA256:H5h/cPfEsTWhNRE5w/pRyxHeRQ/jZhLww3L3buiQrpQ root@autopkgtest 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: The key's randomart image is: 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: +---[ECDSA 256]---+ 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: | ... +OB| 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: | o o+OB| 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: | . *.B+X| 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: | o o B *=| 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: | S o . o.=| 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: | o = o * | 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: | E + . +| 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: | . o o . | 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: | ... . | 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: +----[SHA256]-----+ 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: Generating public/private ed25519 key pair. 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: Your identification has been saved in /etc/ssh/ssh_host_ed25519_key 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: Your public key has been saved in /etc/ssh/ssh_host_ed25519_key.pub 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: The key fingerprint is: 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: SHA256:L2vohwROwexx3NGWBcCuz/ROv/uqZXycnM67F/ohAvU root@autopkgtest 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: The key's randomart image is: 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: +--[ED25519 256]--+ 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: | o . oo+.+. | 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: | = o o + | 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: | . + . . . | 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: | + . . . | 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: | o . .S. E | 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: | . o .... o + | 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: | . *..o.+.B..| 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: | o =+.+.=. o| 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: | ..o..o.==B= | 345s Sep 10 10:41:58 autopkgtest cloud-init[682]: +----[SHA256]-----+ 345s Sep 10 10:41:58 autopkgtest systemd[1]: Finished cloud-final.service - Cloud-init: Final Stage. 345s Sep 10 10:41:58 autopkgtest systemd[1]: Reached target cloud-init.target - Cloud-init target. 345s Sep 10 10:41:58 autopkgtest systemd[1]: Startup finished in 1.771s (kernel) + 25.043s (userspace) = 26.815s. 345s Sep 10 10:41:58 autopkgtest systemd[1]: cloud-init-main.service: Deactivated successfully. 345s Sep 10 10:41:58 autopkgtest systemd[1]: cloud-init-main.service: Consumed 11.690s CPU time, 460.5M memory peak. 345s Sep 10 10:41:59 autopkgtest sshd[1231]: Received disconnect from 10.136.6.201 port 39808:11: disconnected by user 345s Sep 10 10:41:59 autopkgtest sshd[1231]: Disconnected from user ubuntu 10.136.6.201 port 39808 345s Sep 10 10:41:59 autopkgtest sshd[1215]: pam_unix(sshd:session): session closed for user ubuntu 345s Sep 10 10:41:59 autopkgtest sshd[1215]: pam_systemd(sshd:session): New sd-bus connection (system-bus-pam-systemd-1215) opened. 345s Sep 10 10:41:59 autopkgtest systemd[1]: session-3.scope: Deactivated successfully. 345s Sep 10 10:41:59 autopkgtest systemd-logind[887]: Session 3 logged out. Waiting for processes to exit. 345s Sep 10 10:41:59 autopkgtest systemd-logind[887]: Removed session 3. 345s Sep 10 10:42:00 autopkgtest sshd[1323]: Accepted publickey for ubuntu from 10.136.6.201 port 39816 ssh2: RSA SHA256:YaYyKWTl9zFJEBK5G3u+MRj3WPJt+vEplFd0J96PUBw 345s Sep 10 10:42:00 autopkgtest sshd[1323]: pam_unix(sshd:session): session opened for user ubuntu(uid=1000) by ubuntu(uid=0) 345s Sep 10 10:42:00 autopkgtest sshd[1323]: pam_systemd(sshd:session): New sd-bus connection (system-bus-pam-systemd-1323) opened. 345s Sep 10 10:42:00 autopkgtest systemd-logind[887]: New session 4 of user ubuntu. 345s Sep 10 10:42:00 autopkgtest systemd[1]: Started session-4.scope - Session 4 of User ubuntu. 345s Sep 10 10:42:00 autopkgtest sudo[1341]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/bin/true 345s Sep 10 10:42:00 autopkgtest sudo[1341]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:00 autopkgtest sudo[1341]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:01 autopkgtest sudo[1346]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper /bin/mkdir --mode=1777 --parents /tmp/autopkgtest.2MkHZe 345s Sep 10 10:42:01 autopkgtest sudo[1346]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:01 autopkgtest sudo[1346]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:01 autopkgtest sudo[1356]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper mkdir -p /tmp/autopkgtest.2MkHZe 345s Sep 10 10:42:01 autopkgtest sudo[1356]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:01 autopkgtest sudo[1356]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:01 autopkgtest sudo[1366]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat >/tmp/autopkgtest.2MkHZe/wrapper.sh; chmod +x -- /tmp/autopkgtest.2MkHZe/wrapper.sh' 345s Sep 10 10:42:01 autopkgtest sudo[1366]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:01 autopkgtest sudo[1366]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:01 autopkgtest sudo[1378]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chmod -R 0755 -- /tmp/autopkgtest.2MkHZe/wrapper.sh 345s Sep 10 10:42:01 autopkgtest sudo[1378]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:01 autopkgtest sudo[1378]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:01 autopkgtest sudo[1388]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper dpkg --print-architecture 345s Sep 10 10:42:01 autopkgtest sudo[1388]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:01 autopkgtest sudo[1388]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:02 autopkgtest sudo[1398]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper dpkg-query -W -f ${Version} apt 345s Sep 10 10:42:02 autopkgtest sudo[1398]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:02 autopkgtest sudo[1398]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:02 autopkgtest sudo[1408]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -euc '#!/bin/sh#012# Copyright 2014-2016 Martin Pitt#012# Copyright 2017-2023 Paul Gevers#012# SPDX-License-Identifier: GPL-2.0-or-later#012#012# This script is ment to be used as Template by adt_testbed, where#012# \'$pocket\' is replaced, but calling it with one input argument#012# achieves the same results: This script builds a source.list.d entry#012# for the requested pocket for each main suite (lacking a hypen (-))#012# in all sources.lists.#012#012# TODO: Debian is moving towards deb822 based sources, this isn\'t#012# supported yet.#012#012set -eu#012#012usage () {#012 echo "Usage: create-sources.list-for-pocket [POCKET]" >&2#012 exit 2#012}#012#012if [ "$#" -ne 1 ]; then#012 usage#012fi#012#012pocket=$1#012#012SRCS=$(ls /etc/apt/sources.list /etc/apt/sources.list.d/telegraf-devs-ubuntu-ppa-focal.list 345s Sep 10 10:42:02 autopkgtest sudo[1408]: ubuntu : (command continued) /etc/apt/sources.list.d/ua-client-ubuntu-stable-focal.list /etc/apt/sources.list.d/ubuntu-esm-apps.list /etc/apt/sources.list.d/ubuntu-esm-infra.list 2>/dev/null || true)#012if [ -z "$SRCS" ]; then#012 exit 0#012fi#012# Deliberately word-splitting $SRCS#012# shellcheck disable=SC2086#012sed -rn \'s/^(deb|deb-src) +(\\[.*\\] *)?((http|https|file):[^ ]*) +([^ -]+) +(.*)$/\\1 \\2\\3 \\5-\'"$pocket"\' \\6/p\' \\#012$SRCS > /etc/apt/sources.list.d/"$pocket".list#012# retry only needed before Debian 9 (buster) and Ubuntu 18.04 (bionic)#012# testbed has \'Acquire::Retries "10";\' apt config#012for retry in 1 2 3; do#012 apt-get --no-list-cleanup \\#012#011 -o Dir::Etc::sourcelist=/etc/apt/sources.list.d/"$pocket".list \\#012#011 -o Dir::Etc::sourceparts=/dev/null \\#012#011 update 2>&1 && break#012 if [ $retry = 3 ] ; then#012 return 1#012 else#012 sleep 15#012 fi#012done#012' sh proposed 345s Sep 10 10:42:02 autopkgtest sudo[1408]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:02 autopkgtest sudo[1408]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:02 autopkgtest sudo[1420]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'ls -1 /etc/apt/sources.list.d/*.sources' 345s Sep 10 10:42:02 autopkgtest sudo[1420]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:02 autopkgtest sudo[1420]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:02 autopkgtest sudo[1431]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper cat /etc/apt/sources.list.d/ubuntu.sources 345s Sep 10 10:42:02 autopkgtest sudo[1431]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:02 autopkgtest sudo[1431]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:03 autopkgtest sudo[1441]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec '#!/bin/sh#012# Copyright © 2006-2018 Canonical Ltd.#012# Copyright © 2022 Paul Gevers#012# Copyright © 2022 Simon McVittie#012# SPDX-License-Identifier: GPL-2.0-or-later#012#012# This script writes the requested apt_source_line to the#012# apt_source_filename and updates the apt index for just added entry#012# (and only that one)#012#012# Usage $0 #012#012set -eu#012#012usage () {#012 echo "Usage: $0 APT_SOURCE_LINE APT_SOURCE_FILENAME" >&2#012 exit 2#012}#012#012if [ "$#" -lt 2 ]; then#012 usage#012fi#012#012# Check for options for future-proofing, but none are actually accepted#012case "${1-}" in#012 (--)#012 shift#012 ;;#012#012 (-*)#012 usage#012 ;;#012esac#012#012echo "$1" >> /etc/apt/sources.list.d/"$2"#012# retry only needed before Debian 9 (buster) and Ubuntu 18.04 (bionic)#012# testbed has \'Acquire::Retries 345s Sep 10 10:42:03 autopkgtest sudo[1441]: ubuntu : (command continued) "10";\' apt config#012for retry in 1 2 3; do#012 apt-get --no-list-cleanup \\#012 -o Dir::Etc::sourcelist=/etc/apt/sources.list.d/"$2" \\#012 -o Dir::Etc::sourceparts=/dev/null \\#012 update 2>&1 && break#012 if [ $retry = 3 ] ; then#012 return 1#012 else#012 sleep 15#012 fi#012done#012' sh 'Types: deb deb-src#012URIs: http://ftpmaster.internal/ubuntu/#012Suites: oracular-proposed#012Components: main restricted universe multiverse#012Signed-By: /usr/share/keyrings/ubuntu-archive-keyring.gpg' proposed.sources 345s Sep 10 10:42:03 autopkgtest sudo[1441]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:03 autopkgtest systemd[1]: Starting apt-news.service - Update APT News... 345s Sep 10 10:42:03 autopkgtest systemd[1]: Starting esm-cache.service - Update the local ESM caches... 345s Sep 10 10:42:03 autopkgtest systemd[1]: esm-cache.service: Deactivated successfully. 345s Sep 10 10:42:03 autopkgtest systemd[1]: Finished esm-cache.service - Update the local ESM caches. 345s Sep 10 10:42:03 autopkgtest systemd[1]: apt-news.service: Deactivated successfully. 345s Sep 10 10:42:03 autopkgtest systemd[1]: Finished apt-news.service - Update APT News. 345s Sep 10 10:42:06 autopkgtest sudo[1441]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:06 autopkgtest sudo[1528]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'mkdir -p /etc/apt/preferences.d; printf "Package: *\\nPin: release a=oracular-proposed\\nPin-Priority: 500\\n" > /etc/apt/preferences.d/autopkgtest-oracular-proposed-baseline;' 345s Sep 10 10:42:06 autopkgtest sudo[1528]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:06 autopkgtest sudo[1528]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:07 autopkgtest sudo[1539]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper mkdir -p /etc/apt/preferences.d 345s Sep 10 10:42:07 autopkgtest sudo[1539]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:07 autopkgtest sudo[1539]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:07 autopkgtest sudo[1549]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat >/etc/apt/preferences.d/autopkgtest-oracular-proposed' 345s Sep 10 10:42:07 autopkgtest sudo[1549]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:07 autopkgtest sudo[1549]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:07 autopkgtest sudo[1560]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chmod -R 0644 -- /etc/apt/preferences.d/autopkgtest-oracular-proposed 345s Sep 10 10:42:07 autopkgtest sudo[1560]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:07 autopkgtest sudo[1560]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:07 autopkgtest sudo[1570]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'mkdir -p /etc/apt/preferences.d; printf "Package: *\\nPin: release a=oracular\\nPin-Priority: 990\\n" > /etc/apt/preferences.d/autopkgtest-default-release' 345s Sep 10 10:42:07 autopkgtest sudo[1570]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:07 autopkgtest sudo[1570]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:07 autopkgtest sudo[1581]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper bash -ec 'for d in /boot /etc/init /etc/init.d /etc/systemd/system /lib/systemd/system; do [ ! -d $d ] || touch -r $d /tmp/autopkgtest.2MkHZe/${d//\\//_}.stamp; done' 345s Sep 10 10:42:07 autopkgtest sudo[1581]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:08 autopkgtest sudo[1581]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:08 autopkgtest sudo[1595]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper env AUTOPKGTEST_IS_SETUP_COMMAND=1 AUTOPKGTEST_NORMAL_USER=ubuntu ADT_NORMAL_USER=ubuntu DEBIAN_FRONTEND=noninteractive APT_LISTBUGS_FRONTEND=none APT_LISTCHANGES_FRONTEND=none sh -ec '#!/bin/sh#012# Canonical/Ubuntu specific testbed setup#012#012RELEASE=$(lsb_release --codename --short 2>/dev/null)#012#012# Make the installed package versions match what is available from the configured#012# repositories, even if a downgrade is required.#012##012# We may end up with images with packages newer than those available from the#012# repositories when opening a new release (images are created using the#012# previous release dailies as a base, which may include 0-day SRUs, or#012# Launchpad may fail to copy packages, see openssl 3.0.8-1ubuntu2), or when#012# package versions are pulled from the archive.#012##012# Note: \'release a=\' matches the Suite field in the 345s Sep 10 10:42:08 autopkgtest sudo[1595]: ubuntu : (command continued) repository Release file.#012cat >/etc/apt/preferences.d/force-downgrade-to-release.pref <= Focal).#012##012# Note: autoremove/--autoremove always runs on the entire set of installed#012# packages. Together with --autopurge/purge each removal becomes a purge.#012##012# Removing \'?obsolete\' packages may remove the running kernel. This is not#012# expected to be an issue.#012if /usr/lib/apt/apt-helper analyze-pattern \'?true\' >/dev/null 2>&1; then#012 DEBIAN_FRONTEND=noninteractive eatmydata apt-get -y purge --autoremove \'?obsolete\'#012else#012 # We\'re on an older release (analyze-pattern is not available).#012 # Still do an autopurge to get rid of packages that got orphaned#012 # by downgrades.#012 eatmydata apt-get -y autoremove --purge#012fi#012#012# compatibility with old Jenkins testbeds for trusty#012if grep -q trusty /etc/lsb-release; then 345s Sep 10 10:42:08 autopkgtest sudo[1595]: ubuntu : (command continued) apt-get update || (sleep 10; apt-get update); apt-get install -y build-essential; fi#012#012# these packages really break tests, purge them if we use standard cloud images#012# (on lcy01)#012for p in unattended-upgrades lxd lxd-client snapd; do#012 [ ! -d /usr/share/doc/$p ] || $(which eatmydata || true) apt-get purge --auto-remove -y $p#012done#012#012# work around broken PTMU; LP: #1572026, RT#90771#012if type iptables >/dev/null 2>&1; then#012 cat < /etc/rc.local#012#!/bin/sh#012iptables -w -t mangle -A FORWARD -p tcp --tcp-flags SYN,RST SYN -j TCPMSS --clamp-mss-to-pmtu || true#012EOF#012 chmod 755 /etc/rc.local#012 # shellcheck disable=SC1091#012 . /etc/rc.local#012fi#012#012# work around broken tty on ppc64el instances (LP: #1607075)#012if [ "$(uname -m)" = ppc64le ] && [ "$(systemctl is-active keyboard-setup.service 2>/dev/null|| true)" = failed ]; then#012 systemctl reset-failed 345s Sep 10 10:42:08 autopkgtest sudo[1595]: ubuntu : (command continued) keyboard-setup.service#012 systemctl mask keyboard-setup.service#012fi#012#012# work around late urandom pool initialization (LP: #1622893)#012if [ -d /run/systemd/system ] && systemd-detect-virt --quiet --vm; then#012 mkdir -p /etc/systemd/system/systemd-random-seed.service.d/#012 cat < /etc/systemd/system/systemd-random-seed.service.d/fakeentropy.conf#012[Service]#012ExecStart=/usr/bin/perl -E \'open \\$\\$f, "/bin/bash" or die; open \\$\\$rnd, ">/dev/random" or die; for (\\$\\$i = 0; \\$\\$i < 10; ++\\$\\$i) {read \\$\\$f, \\$\\$d, 64; ioctl \\$\\$rnd, 0x40085203, pack("ii", 64*8, 64) . \\$\\$d}\'#012EOF#012fi#012#012# set compressor to lz4 where supported, we care about compression speed#012if grep -q lz4 /etc/initramfs-tools/initramfs.conf; then#012 echo COMPRESS=lz4 > /etc/initramfs-tools/conf.d/lz4#012fi' 345s Sep 10 10:42:08 autopkgtest sudo[1595]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:13 autopkgtest sudo[1595]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:13 autopkgtest sudo[1705]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper env AUTOPKGTEST_IS_SETUP_COMMAND=1 AUTOPKGTEST_NORMAL_USER=ubuntu ADT_NORMAL_USER=ubuntu DEBIAN_FRONTEND=noninteractive APT_LISTBUGS_FRONTEND=none APT_LISTCHANGES_FRONTEND=none sh -ec '(O=$(bash -o pipefail -ec \'apt-get update | tee /proc/self/fd/2\') ||{ [ "${O%404*Not Found*}" = "$O" ] || exit 100; sleep 15; apt-get update; } || { sleep 60; apt-get update; } || false) && $(command -v eatmydata || true) apt-get dist-upgrade -y -o Dpkg::Options::="--force-confnew" && $(command -v eatmydata || true) apt-get --purge autoremove -y' 345s Sep 10 10:42:13 autopkgtest sudo[1705]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:13 autopkgtest systemd[1]: Starting apt-news.service - Update APT News... 345s Sep 10 10:42:13 autopkgtest systemd[1]: Starting esm-cache.service - Update the local ESM caches... 345s Sep 10 10:42:14 autopkgtest systemd[1]: apt-news.service: Deactivated successfully. 345s Sep 10 10:42:14 autopkgtest systemd[1]: Finished apt-news.service - Update APT News. 345s Sep 10 10:42:14 autopkgtest systemd[1]: esm-cache.service: Deactivated successfully. 345s Sep 10 10:42:14 autopkgtest systemd[1]: Finished esm-cache.service - Update the local ESM caches. 345s Sep 10 10:42:17 autopkgtest sudo[1705]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:17 autopkgtest sudo[1890]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper bash -ec '[ ! -e /run/autopkgtest_no_reboot.stamp ] || exit 0;for d in /boot /etc/init /etc/init.d /etc/systemd/system /lib/systemd/system; do s=/tmp/autopkgtest.2MkHZe/${d//\\//_}.stamp; [ ! -d $d ] || [ `stat -c %Y $d` = `stat -c %Y $s` ]; done' 345s Sep 10 10:42:17 autopkgtest sudo[1890]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:17 autopkgtest sudo[1890]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:17 autopkgtest sudo[1908]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'command -v eatmydata' 345s Sep 10 10:42:17 autopkgtest sudo[1908]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:17 autopkgtest sudo[1908]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:17 autopkgtest sudo[1918]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'dpkg-query --show -f \'${Package}\\t${Version}\\n\' > /tmp/autopkgtest.2MkHZe/testbed-packages' 345s Sep 10 10:42:17 autopkgtest sudo[1918]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:17 autopkgtest sudo[1918]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:17 autopkgtest sudo[1929]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat /tmp/autopkgtest.2MkHZe/autopkgtest-reboot; chmod +x -- /tmp/autopkgtest.2MkHZe/autopkgtest-reboot' 345s Sep 10 10:42:18 autopkgtest sudo[1950]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:18 autopkgtest sudo[1950]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:18 autopkgtest sudo[1962]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chmod -R 0755 -- /tmp/autopkgtest.2MkHZe/autopkgtest-reboot 345s Sep 10 10:42:18 autopkgtest sudo[1962]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:18 autopkgtest sudo[1962]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:18 autopkgtest sudo[1972]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper ln -fns /tmp/autopkgtest.2MkHZe/autopkgtest-reboot /tmp/autopkgtest-reboot 345s Sep 10 10:42:18 autopkgtest sudo[1972]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:18 autopkgtest sudo[1972]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:18 autopkgtest sudo[1982]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper ln -fns /tmp/autopkgtest.2MkHZe/autopkgtest-reboot /sbin/autopkgtest-reboot 345s Sep 10 10:42:18 autopkgtest sudo[1982]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:18 autopkgtest sudo[1982]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:19 autopkgtest sudo[1992]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper mkdir -p /tmp/autopkgtest.2MkHZe 345s Sep 10 10:42:19 autopkgtest sudo[1992]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:19 autopkgtest sudo[1992]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:19 autopkgtest sudo[2002]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat >/tmp/autopkgtest.2MkHZe/autopkgtest-reboot-prepare; chmod +x -- /tmp/autopkgtest.2MkHZe/autopkgtest-reboot-prepare' 345s Sep 10 10:42:19 autopkgtest sudo[2002]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:19 autopkgtest sudo[2002]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:19 autopkgtest sudo[2014]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chmod -R 0755 -- /tmp/autopkgtest.2MkHZe/autopkgtest-reboot-prepare 345s Sep 10 10:42:19 autopkgtest sudo[2014]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:19 autopkgtest sudo[2014]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:19 autopkgtest sudo[2024]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper ln -fns /tmp/autopkgtest.2MkHZe/autopkgtest-reboot-prepare /tmp/autopkgtest-reboot-prepare 345s Sep 10 10:42:19 autopkgtest sudo[2024]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:19 autopkgtest sudo[2024]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:19 autopkgtest sudo[2034]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper uname -srv 345s Sep 10 10:42:19 autopkgtest sudo[2034]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:19 autopkgtest sudo[2034]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:20 autopkgtest sudo[2044]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper test -w /var/lib/dpkg/status 345s Sep 10 10:42:20 autopkgtest sudo[2044]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:20 autopkgtest sudo[2044]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:20 autopkgtest sudo[2053]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper mkdir -p /tmp/autopkgtest.2MkHZe 345s Sep 10 10:42:20 autopkgtest sudo[2053]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:20 autopkgtest sudo[2053]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:20 autopkgtest sudo[2063]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat >/tmp/autopkgtest.2MkHZe/2-autopkgtest-satdep.deb' 345s Sep 10 10:42:20 autopkgtest sudo[2063]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:20 autopkgtest sudo[2063]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:20 autopkgtest sudo[2074]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chown -R ubuntu -- /tmp/autopkgtest.2MkHZe/2-autopkgtest-satdep.deb 345s Sep 10 10:42:20 autopkgtest sudo[2074]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:20 autopkgtest sudo[2074]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:21 autopkgtest sudo[2084]: 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.2MkHZe/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' 345s Sep 10 10:42:21 autopkgtest sudo[2084]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:25 autopkgtest systemd[1]: Reload requested from client PID 2324 ('systemctl') (unit session-4.scope)... 345s Sep 10 10:42:25 autopkgtest systemd[1]: Reloading... 345s Sep 10 10:42:25 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. 345s Sep 10 10:42:25 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. 345s Sep 10 10:42:25 autopkgtest systemd[1]: Reloading finished in 314 ms. 345s Sep 10 10:42:25 autopkgtest systemd[1]: Reload requested from client PID 2373 ('systemctl') (unit session-4.scope)... 345s Sep 10 10:42:25 autopkgtest systemd[1]: Reloading... 345s Sep 10 10:42:26 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. 345s Sep 10 10:42:26 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. 345s Sep 10 10:42:26 autopkgtest systemd[1]: Reloading finished in 420 ms. 345s Sep 10 10:42:26 autopkgtest systemd[1]: Starting tgt.service - (i)SCSI target daemon... 345s Sep 10 10:42:26 autopkgtest tgtd[2418]: tgtd: iser_ib_init(3431) Failed to initialize RDMA; load kernel modules? 345s Sep 10 10:42:26 autopkgtest tgtd[2418]: tgtd: work_timer_start(146) use timer_fd based scheduler 345s Sep 10 10:42:26 autopkgtest tgtd[2418]: tgtd: bs_init(387) use signalfd notification 345s Sep 10 10:42:26 autopkgtest systemd[1]: Started tgt.service - (i)SCSI target daemon. 345s Sep 10 10:42:26 autopkgtest systemd[1]: Reload requested from client PID 2446 ('systemctl') (unit session-4.scope)... 345s Sep 10 10:42:26 autopkgtest systemd[1]: Reloading... 345s Sep 10 10:42:27 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. 345s Sep 10 10:42:27 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. 345s Sep 10 10:42:27 autopkgtest systemd[1]: Reloading finished in 260 ms. 345s Sep 10 10:42:27 autopkgtest systemd[1]: Reload requested from client PID 2489 ('systemctl') (unit session-4.scope)... 345s Sep 10 10:42:27 autopkgtest systemd[1]: Reloading... 345s Sep 10 10:42:27 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. 345s Sep 10 10:42:27 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. 345s Sep 10 10:42:27 autopkgtest systemd[1]: Reloading finished in 262 ms. 345s Sep 10 10:42:27 autopkgtest systemd[1]: Starting fwupd-refresh.service - Refresh fwupd metadata and update motd... 345s Sep 10 10:42:27 autopkgtest dbus-daemon[873]: [system] Activating via systemd: service name='org.freedesktop.fwupd' unit='fwupd.service' requested by ':1.16' (uid=990 pid=2531 comm="/usr/bin/fwupdmgr refresh" label="unconfined") 345s Sep 10 10:42:27 autopkgtest systemd[1]: Starting fwupd.service - Firmware update daemon... 345s Sep 10 10:42:27 autopkgtest systemd[1]: Reload requested from client PID 2541 ('systemctl') (unit session-4.scope)... 345s Sep 10 10:42:27 autopkgtest systemd[1]: Reloading... 345s Sep 10 10:42:27 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. 345s Sep 10 10:42:27 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. 345s Sep 10 10:42:28 autopkgtest systemd[1]: Reloading finished in 295 ms. 345s Sep 10 10:42:28 autopkgtest systemd[1]: Listening on iscsid.socket - Open-iSCSI iscsid Socket. 345s Sep 10 10:42:28 autopkgtest fwupd[2537]: 10:42:28.406 FuMain Daemon ready for requests (locale C.UTF-8) 345s Sep 10 10:42:28 autopkgtest dbus-daemon[873]: [system] Successfully activated service 'org.freedesktop.fwupd' 345s Sep 10 10:42:28 autopkgtest systemd[1]: Started fwupd.service - Firmware update daemon. 345s Sep 10 10:42:28 autopkgtest fwupdmgr[2531]: Updating lvfs 345s Sep 10 10:42:28 autopkgtest systemd[1]: Reload requested from client PID 2598 ('systemctl') (unit session-4.scope)... 345s Sep 10 10:42:28 autopkgtest systemd[1]: Reloading... 345s Sep 10 10:42:28 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. 345s Sep 10 10:42:28 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. 345s Sep 10 10:42:28 autopkgtest systemd[1]: Reloading finished in 285 ms. 345s Sep 10 10:42:28 autopkgtest systemd[1]: fwupd-refresh.service: Main process exited, code=exited, status=1/FAILURE 345s Sep 10 10:42:28 autopkgtest systemd[1]: fwupd-refresh.service: Failed with result 'exit-code'. 345s Sep 10 10:42:28 autopkgtest systemd[1]: Failed to start fwupd-refresh.service - Refresh fwupd metadata and update motd. 345s Sep 10 10:42:28 autopkgtest systemd[1]: open-iscsi.service - Login to default iSCSI targets was skipped because no trigger condition checks were met. 345s Sep 10 10:42:28 autopkgtest systemd[1]: Reached target remote-fs-pre.target - Preparation for Remote File Systems. 345s Sep 10 10:42:28 autopkgtest systemd[1]: Reload requested from client PID 2656 ('systemctl') (unit session-4.scope)... 345s Sep 10 10:42:28 autopkgtest systemd[1]: Reloading... 345s Sep 10 10:42:29 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. 345s Sep 10 10:42:29 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. 345s Sep 10 10:42:29 autopkgtest systemd[1]: Reloading finished in 427 ms. 345s Sep 10 10:42:43 autopkgtest sudo[2084]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:43 autopkgtest sudo[6505]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper dpkg-query --show -f ${Status} multipath-tools 345s Sep 10 10:42:43 autopkgtest sudo[6505]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:43 autopkgtest sudo[6505]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:44 autopkgtest sudo[6515]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper dpkg --status autopkgtest-satdep 345s Sep 10 10:42:44 autopkgtest sudo[6515]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:44 autopkgtest sudo[6515]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:44 autopkgtest sudo[6525]: 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 345s Sep 10 10:42:44 autopkgtest sudo[6525]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:45 autopkgtest sudo[6525]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:46 autopkgtest sudo[6538]: 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 345s Sep 10 10:42:46 autopkgtest sudo[6538]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:46 autopkgtest sudo[6538]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:46 autopkgtest sudo[6550]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper apt-mark manual -qq lsscsi 345s Sep 10 10:42:46 autopkgtest sudo[6550]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:46 autopkgtest sudo[6550]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:47 autopkgtest sudo[6562]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper dpkg --purge autopkgtest-satdep 345s Sep 10 10:42:47 autopkgtest sudo[6562]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:47 autopkgtest sudo[6562]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:47 autopkgtest sudo[6572]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'dpkg-query --show -f \'${Package}\\t${Version}\\n\' > /tmp/autopkgtest.2MkHZe/tgtbasedmpaths-packages.all' 345s Sep 10 10:42:47 autopkgtest sudo[6572]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 345s Sep 10 10:42:47 autopkgtest sudo[6572]: pam_unix(sudo:session): session closed for user root 345s Sep 10 10:42:47 autopkgtest sudo[6583]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat =64=0.0% 349s submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 349s complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 349s issued rwts: total=0,1401,0,0 short=0,0,0,0 dropped=0,0,0,0 349s latency : target=0, window=0, percentile=100.00%, depth=1 349s 349s Run status group 0 (all jobs): 349s WRITE: bw=108MiB/s (113MB/s), 108MiB/s-108MiB/s (113MB/s-113MB/s), io=87.5MiB (91.8MB), run=810-810msec 349s 349s Disk stats (read/write): 349s dm-0: ios=1/1092, sectors=8/139776, merge=0/0, ticks=0/639, in_queue=640, util=87.26%, aggrios=0/350, aggsectors=2/44820, aggrmerge=0/0, aggrticks=0/175, aggrin_queue=175, aggrutil=87.41% 349s sdd: ios=0/0, sectors=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 349s sdb: ios=0/0, sectors=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 349s sdc: ios=0/0, sectors=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 349s sda: ios=1/1402, sectors=8/179280, merge=0/0, ticks=1/702, in_queue=703, util=87.41% 349s + echo Starting the path changes in background 349s + date +Pre FIO %H:%M:%S.%N 349s Starting the path changes in background 349s Pre FIO 10:42:59.636448555 349s + fio --max-jobs=4 /tmp/autopkgtest.2MkHZe/tgtbasedmpaths-artifacts/path-change-check.fio 349s verify-phase: (g=0): rw=read, bs=(R) 64.0KiB-64.0KiB, (W) 64.0KiB-64.0KiB, (T) 64.0KiB-64.0KiB, ioengine=sync, iodepth=1 349s fio-3.37 349s Starting 1 thread 530s 530s verify-phase: (groupid=0, jobs=1): err= 0: pid=6933: Tue Sep 10 10:45:59 2024 530s read: IOPS=4693, BW=293MiB/s (308MB/s)(51.6GiB/180001msec) 530s clat (usec): min=88, max=52124, avg=186.45, stdev=123.07 530s lat (usec): min=88, max=52124, avg=186.59, stdev=123.08 530s clat percentiles (usec): 530s | 1.00th=[ 116], 5.00th=[ 130], 10.00th=[ 139], 20.00th=[ 149], 530s | 30.00th=[ 157], 40.00th=[ 163], 50.00th=[ 174], 60.00th=[ 188], 530s | 70.00th=[ 204], 80.00th=[ 221], 90.00th=[ 247], 95.00th=[ 269], 530s | 99.00th=[ 330], 99.50th=[ 367], 99.90th=[ 635], 99.95th=[ 799], 530s | 99.99th=[ 1565] 530s bw ( KiB/s): min=184320, max=400801, per=100.00%, avg=300602.43, stdev=45204.28, samples=359 530s iops : min= 2880, max= 6262, avg=4696.82, stdev=706.34, samples=359 530s lat (usec) : 100=0.15%, 250=90.91%, 500=8.77%, 750=0.11%, 1000=0.04% 530s lat (msec) : 2=0.02%, 4=0.01%, 10=0.01%, 20=0.01%, 50=0.01% 530s lat (msec) : 100=0.01% 530s cpu : usr=13.54%, sys=8.40%, ctx=845036, majf=0, minf=1 530s IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0% 530s submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 530s complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 530s issued rwts: total=844914,0,0,0 short=0,0,0,0 dropped=0,0,0,0 530s latency : target=0, window=0, percentile=100.00%, depth=1 530s 530s Run status group 0 (all jobs): 530s READ: bw=293MiB/s (308MB/s), 293MiB/s-293MiB/s (308MB/s-308MB/s), io=51.6GiB (55.4GB), run=180001-180001msec 530s 530s Disk stats (read/write): 530s dm-0: ios=844935/10, sectors=108074168/12928, merge=32/9, ticks=151316/205, in_queue=151693, util=100.00%, aggrios=43472/4611686018427387550, aggsectors=5561692/4611686018427340742, aggrmerge=0/0, aggrticks=1073749673/1073741639, aggrin_queue=1073749488, aggrutil=100.00% 530s sdd: ios=135946/0, sectors=17388672/0, merge=0/0, ticks=23667/0, in_queue=23668, util=60.00% 530s sdb: ios=38151/0, sectors=4879544/0, merge=0/0, ticks=7808/0, in_queue=7809, util=49.94% 530s sdc: ios=0/0, sectors=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 530s sda: ios=18446744073709551410/18446744073709550202, sectors=18446744073709530170/18446744073709362968, merge=0/0, ticks=4294967220/4294966557, in_queue=4294966475, util=100.00% 530s + date +Post FIO %H:%M:%S.%N 530s Post FIO 10:45:59.990072260 530s + echo FIO verify test with changing paths - OK 530s + echo Report log of background activity 530s + cat /tmp/autopkgtest.2MkHZe/tgtbasedmpaths-artifacts/test-background.log 530s FIO verify test with changing paths - OK 530s Report log of background activity 530s + iscsiadm --mode session 530s tcp: [1] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 530s tcp: [2] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 530s tcp: [3] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 530s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 530s + sleep 10s 530s + date +MP report (expect 4) %H:%M:%S.%N 530s MP report (expect 4) 10:43:09.651597161 530s + multipath -ll 530s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 530s size=100M features='0' hwhandler='0' wp=rw 530s |-+- policy='service-time 0' prio=1 status=active 530s | `- 0:0:0:1 sda 8:0 active ready running 530s |-+- policy='service-time 0' prio=1 status=enabled 530s | `- 1:0:0:1 sdb 8:16 active ready running 530s |-+- policy='service-time 0' prio=1 status=enabled 530s | `- 3:0:0:1 sdd 8:48 active ready running 530s `-+- policy='service-time 0' prio=1 status=enabled 530s `- 2:0:0:1 sdc 8:32 active ready running 530s + date +UN-plug path 1 %H:%M:%S.%N 530s UN-plug path 1 10:43:09.701916744 530s + iscsiadm --mode session -r 1 -u 530s Logging out of session [sid: 1, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 530s Logout of [sid: 1, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 530s + iscsiadm --mode session 530s tcp: [2] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 530s tcp: [3] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 530s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 530s + sleep 10s 530s + date +MP report (expect 3) %H:%M:%S.%N 530s MP report (expect 3) 10:43:19.802400001 530s + multipath -ll 530s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 530s size=100M features='0' hwhandler='0' wp=rw 530s |-+- policy='service-time 0' prio=1 status=active 530s | `- 1:0:0:1 sdb 8:16 active ready running 530s |-+- policy='service-time 0' prio=1 status=enabled 530s | `- 3:0:0:1 sdd 8:48 active ready running 530s `-+- policy='service-time 0' prio=1 status=enabled 530s `- 2:0:0:1 sdc 8:32 active ready running 530s + date +UN-plug path 2 %H:%M:%S.%N 530s UN-plug path 2 10:43:19.833538468 530s + iscsiadm --mode session -r 2 -u 530s Logging out of session [sid: 2, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 530s Logout of [sid: 2, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 530s + iscsiadm --mode session 530s tcp: [3] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 530s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 530s + sleep 10s 530s + date +MP report (expect 2) %H:%M:%S.%N 530s MP report (expect 2) 10:43:29.934994013 530s + multipath -ll 530s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 530s size=100M features='0' hwhandler='0' wp=rw 530s |-+- policy='service-time 0' prio=1 status=active 530s | `- 3:0:0:1 sdd 8:48 active ready running 530s `-+- policy='service-time 0' prio=1 status=enabled 530s `- 2:0:0:1 sdc 8:32 active ready running 530s + date +UN-plug path 3 %H:%M:%S.%N 530s UN-plug path 3 10:43:29.959039318 530s + iscsiadm --mode session -r 3 -u 530s Logging out of session [sid: 3, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 530s Logout of [sid: 3, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 530s + iscsiadm --mode session 530s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 530s + sleep 10s 530s + date +MP report (expect 1) %H:%M:%S.%N 530s MP report (expect 1) 10:43:40.067945854 530s + multipath -ll 530s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 530s size=100M features='0' hwhandler='0' wp=rw 530s `-+- policy='service-time 0' prio=1 status=active 530s `- 3:0:0:1 sdd 8:48 active ready running 530s + date +Add paths 5/6/7/8 %H:%M:%S.%N 530s Add paths 5/6/7/8 10:43:40.090217711 530s + iscsiadm --mode session -r 4 --op new 530s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 530s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 530s + iscsiadm --mode session -r 4 --op new 530s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 530s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 530s + iscsiadm --mode session -r 4 --op new 530s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 530s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 530s + iscsiadm --mode session -r 4 --op new 530s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 530s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 530s + iscsiadm --mode session 530s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 530s tcp: [5] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 530s tcp: [6] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 530s tcp: [7] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 530s tcp: [8] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 530s + sleep 10s 530s + date +MP report (expect 5) %H:%M:%S.%N 530s MP report (expect 5) 10:43:50.189864762 530s + multipath -ll 530s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 530s size=100M features='0' hwhandler='0' wp=rw 530s |-+- policy='service-time 0' prio=1 status=active 530s | `- 3:0:0:1 sdd 8:48 active ready running 530s |-+- policy='service-time 0' prio=1 status=enabled 530s | `- 0:0:0:1 sda 8:0 active ready running 530s |-+- policy='service-time 0' prio=1 status=enabled 530s | `- 1:0:0:1 sdb 8:16 active ready running 530s |-+- policy='service-time 0' prio=1 status=enabled 530s | `- 2:0:0:1 sdc 8:32 active ready running 530s `-+- policy='service-time 0' prio=1 status=enabled 530s `- 4:0:0:1 sde 8:64 active ready running 530s + date +UN-plug multiple paths 4/7/8 %H:%M:%S.%N 530s UN-plug multiple paths 4/7/8 10:43:50.227513880 530s + iscsiadm --mode session -r 4 -u 530s Logging out of session [sid: 4, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 530s Logout of [sid: 4, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 530s + iscsiadm --mode session -r 7 -u 530s Logging out of session [sid: 7, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 530s Logout of [sid: 7, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 530s + iscsiadm --mode session -r 8 -u 530s Logging out of session [sid: 8, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 530s Logout of [sid: 8, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 530s + iscsiadm --mode session 530s tcp: [5] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 530s tcp: [6] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 530s + sleep 10s 530s + date +Restart multipath daemon %H:%M:%S.%N 530s Restart multipath daemon 10:44:00.529915647 530s + systemctl restart multipathd 530s + sleep 10s 530s + date +Final background report (expect 2) %H:%M:%S.%N 530s Final background report (expect 2) 10:44:10.620342009 530s + multipath -ll 530s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 530s size=100M features='0' hwhandler='0' wp=rw 530s |-+- policy='service-time 0' prio=1 status=active 530s | `- 0:0:0:1 sda 8:0 active ready running 530s `-+- policy='service-time 0' prio=1 status=enabled 530s `- 1:0:0:1 sdb 8:16 active ready running 530s Final stats 530s Stats for session [sid: 5, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 530s iSCSI SNMP: 530s txdata_octets: 30138264 530s rxdata_octets: 41125917700 530s noptx_pdus: 0 530s scsicmd_pdus: 627613 530s tmfcmd_pdus: 0 530s login_pdus: 0 530s text_pdus: 0 530s dataout_pdus: 0 530s logout_pdus: 0 530s snack_pdus: 0 530s noprx_pdus: 0 530s scsirsp_pdus: 627613 530s tmfrsp_pdus: 0 530s textrsp_pdus: 0 530s datain_pdus: 627580 530s logoutrsp_pdus: 0 530s r2t_pdus: 0 530s async_pdus: 0 530s rjt_pdus: 0 530s digest_err: 0 530s timeout_err: 0 530s iSCSI Extended: 530s tx_sendpage_failures: 0 530s rx_discontiguous_hdr: 0 530s eh_abort_cnt: 0 530s Stats for session [sid: 6, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 530s iSCSI SNMP: 530s txdata_octets: 7368 530s rxdata_octets: 2957620 530s noptx_pdus: 0 530s scsicmd_pdus: 124 530s tmfcmd_pdus: 0 530s login_pdus: 0 530s text_pdus: 0 530s dataout_pdus: 0 530s logout_pdus: 0 530s snack_pdus: 0 530s noprx_pdus: 0 530s scsirsp_pdus: 124 530s tmfrsp_pdus: 0 530s textrsp_pdus: 0 530s datain_pdus: 103 530s logoutrsp_pdus: 0 530s r2t_pdus: 0 530s async_pdus: 0 530s rjt_pdus: 0 530s digest_err: 0 530s timeout_err: 0 530s iSCSI Extended: 530s tx_sendpage_failures: 0 530s rx_discontiguous_hdr: 0 530s eh_abort_cnt: 0 530s + sync 530s + umount /dev/disk/by-id/wwn-0x60000000000000000e00000000010001 530s + echo Final stats 530s + iscsiadm --mode session --stats 530s + journalctl --no-pager -u multipathd 530s Sep 09 15:16:16 ubuntu multipathd[335]: multipathd v0.9.9: start up 530s Sep 09 15:16:16 ubuntu multipathd[335]: reconfigure: setting up paths and maps 530s Sep 09 15:16:16 ubuntu multipathd[335]: _check_bindings_file: failed to read header from /etc/multipath/bindings 530s Sep 09 15:16:16 ubuntu multipathd[335]: updated bindings file /etc/multipath/bindings 530s Sep 09 15:16:16 ubuntu systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 530s Sep 09 15:18:57 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Stopping multipathd.service - Device-Mapper Multipath Device Controller... 530s Sep 09 15:18:57 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i multipathd[335]: multipathd: shut down 530s Sep 09 15:18:57 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: multipathd.service: Deactivated successfully. 530s Sep 09 15:18:57 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Stopped multipathd.service - Device-Mapper Multipath Device Controller. 530s -- Boot 5d97a3f9531d45eeacad9f45ba3ff199 -- 530s Sep 09 15:19:09 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i multipathd[280]: multipathd v0.9.9: start up 530s Sep 09 15:19:09 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i multipathd[280]: reconfigure: setting up paths and maps 530s Sep 09 15:19:09 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 530s Sep 09 15:19:25 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i multipathd[280]: multipathd: shut down 530s Sep 09 15:19:25 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Stopping multipathd.service - Device-Mapper Multipath Device Controller... 530s Sep 09 15:19:25 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: multipathd.service: Deactivated successfully. 530s Sep 09 15:19:25 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Stopped multipathd.service - Device-Mapper Multipath Device Controller. 530s -- Boot c563910c53984f55b403ba8a1f400887 -- 530s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 530s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i multipathd[328]: multipathd v0.9.9: start up 530s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i multipathd[328]: reconfigure: setting up paths and maps 530s Sep 10 10:41:33 auto-syncubuntu-oracular-daily-ppc64el-server-20240908-disk1-i systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 530s Sep 10 10:42:50 autopkgtest multipathd[328]: updated bindings file /etc/multipath/bindings 530s Sep 10 10:42:50 autopkgtest multipathd[328]: mpatha: addmap [0 204800 multipath 0 0 1 1 service-time 0 1 1 8:0 1] 530s Sep 10 10:42:50 autopkgtest multipathd[328]: sda [8:0]: path added to devmap mpatha 530s Sep 10 10:42:50 autopkgtest multipathd[328]: mpatha: performing delayed actions 530s Sep 10 10:42:50 autopkgtest multipathd[328]: mpatha: reload [0 204800 multipath 0 0 4 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:32 1] 530s Sep 10 10:43:09 autopkgtest multipathd[328]: mpatha: reload [0 204800 multipath 0 0 3 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:32 1] 530s Sep 10 10:43:09 autopkgtest multipathd[328]: check_removed_paths: sda: freeing path in removed state 530s Sep 10 10:43:09 autopkgtest multipathd[328]: 8:0: path removed from map mpatha 530s Sep 10 10:43:19 autopkgtest multipathd[328]: mpatha: reload [0 204800 multipath 0 0 2 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:32 1] 530s Sep 10 10:43:19 autopkgtest multipathd[328]: check_removed_paths: sdb: freeing path in removed state 530s Sep 10 10:43:19 autopkgtest multipathd[328]: 8:16: path removed from map mpatha 530s Sep 10 10:43:29 autopkgtest multipathd[328]: mpatha: reload [0 204800 multipath 0 0 1 1 service-time 0 1 1 8:48 1] 530s Sep 10 10:43:30 autopkgtest multipathd[328]: check_removed_paths: sdc: freeing path in removed state 530s Sep 10 10:43:30 autopkgtest multipathd[328]: 8:32: path removed from map mpatha 530s Sep 10 10:43:40 autopkgtest multipathd[328]: mpatha: reload [0 204800 multipath 0 0 2 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:0 1] 530s Sep 10 10:43:40 autopkgtest multipathd[328]: sda [8:0]: path added to devmap mpatha 530s Sep 10 10:43:40 autopkgtest multipathd[328]: mpatha: reload [0 204800 multipath 0 0 3 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:16 1] 530s Sep 10 10:43:40 autopkgtest multipathd[328]: sdb [8:16]: path added to devmap mpatha 530s Sep 10 10:43:40 autopkgtest multipathd[328]: mpatha: reload [0 204800 multipath 0 0 4 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:32 1] 530s Sep 10 10:43:40 autopkgtest multipathd[328]: sdc [8:32]: path added to devmap mpatha 530s Sep 10 10:43:40 autopkgtest multipathd[328]: mpatha: reload [0 204800 multipath 0 0 5 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:64 1] 530s Sep 10 10:43:40 autopkgtest multipathd[328]: sde [8:64]: path added to devmap mpatha 530s Sep 10 10:43:50 autopkgtest multipathd[328]: mpatha: reload [0 204800 multipath 0 0 4 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:64 1] 530s Sep 10 10:43:50 autopkgtest multipathd[328]: check_removed_paths: sdd: freeing path in removed state 530s Sep 10 10:43:50 autopkgtest multipathd[328]: 8:48: path removed from map mpatha 530s Sep 10 10:43:50 autopkgtest multipathd[328]: mpatha: reload [0 204800 multipath 0 0 3 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:64 1] 530s Sep 10 10:43:50 autopkgtest multipathd[328]: check_removed_paths: sdc: freeing path in removed state 530s Sep 10 10:43:50 autopkgtest multipathd[328]: 8:32: path removed from map mpatha 530s Sep 10 10:43:50 autopkgtest multipathd[328]: mpatha: reload [0 204800 multipath 0 0 2 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:16 1] 530s Sep 10 10:43:50 autopkgtest multipathd[328]: check_removed_paths: sde: freeing path in removed state 530s Sep 10 10:43:50 autopkgtest multipathd[328]: 8:64: path removed from map mpatha 530s Sep 10 10:44:00 autopkgtest multipathd[328]: multipathd: shut down 530s Sep 10 10:44:00 autopkgtest systemd[1]: Stopping multipathd.service - Device-Mapper Multipath Device Controller... 530s Sep 10 10:44:00 autopkgtest systemd[1]: multipathd.service: Deactivated successfully. 530s Sep 10 10:44:00 autopkgtest systemd[1]: Stopped multipathd.service - Device-Mapper Multipath Device Controller. 530s Sep 10 10:44:00 autopkgtest systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 530s Sep 10 10:44:00 autopkgtest multipathd[7319]: multipathd v0.9.9: start up 530s Sep 10 10:44:00 autopkgtest multipathd[7319]: reconfigure: setting up paths and maps 530s Sep 10 10:44:00 autopkgtest systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 530s Check final path status 530s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 530s size=100M features='0' hwhandler='0' wp=rw 530s |-+- policy='service-time 0' prio=1 status=active 530s | `- 0:0:0:1 sda 8:0 active ready running 530s `-+- policy='service-time 0' prio=1 status=enabled 530s `- 1:0:0:1 sdb 8:16 active ready running 530s + echo Check final path status 530s + multipath -ll 530s + + multipath -ll 530s grep --count status= 530s + diskc=2 530s + multipath -ll 530s + grep --count status=active 530s + diska=1 530s + multipath -ll 530s + grep --count status=enabled 530s + diske=1 530s + [ 2 -ne 2 -o 1 -ne 1 -o 1 -ne 1 ] 530s + echo OK 530s + iscsiadm --mode node --targetname iqn.2016-11.foo.com:target.iscsi --portal 127.0.0.1:3260 --logout 530s OK 530s Logging out of session [sid: 5, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 530s Logging out of session [sid: 6, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 530s Logout of [sid: 5, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 530s Logout of [sid: 6, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 530s + tgtadm --lld iscsi --op delete --mode logicalunit --tid 1 --lun 1 530s autopkgtest [10:46:00]: test tgtbasedmpaths: -----------------------] 531s autopkgtest [10:46:01]: test tgtbasedmpaths: - - - - - - - - - - results - - - - - - - - - - 531s tgtbasedmpaths PASS 531s autopkgtest [10:46:01]: @@@@@@@@@@@@@@@@@@@@ summary 531s initramfs SKIP Test lists explicitly supported architectures, but the current architecture ppc64el isn't listed. 531s initramfs SKIP Test lists explicitly supported architectures, but the current architecture ppc64el isn't listed. 531s kpartx-file-loopback PASS 531s tgtbasedmpaths PASS 536s nova [W] Using flock in prodstack6-ppc64el 536s flock: timeout while waiting to get lock 536s Creating nova instance adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f2275-prod-proposed-migration-environment-3-fa7e7b7f-cef9-4c0b-b59c-2e76e27367e4 from image adt/ubuntu-oracular-ppc64el-server-20240909.img (UUID 15f8af18-895e-46e8-b444-c48790acc71b)... 536s nova [W] Using flock in prodstack6-ppc64el 536s Creating nova instance adt-oracular-ppc64el-multipath-tools-20240910-103709-juju-7f2275-prod-proposed-migration-environment-3-fa7e7b7f-cef9-4c0b-b59c-2e76e27367e4 from image adt/ubuntu-oracular-ppc64el-server-20240909.img (UUID 15f8af18-895e-46e8-b444-c48790acc71b)...