0s autopkgtest [18:08:40]: starting date and time: 2024-09-30 18:08:40+0000 0s autopkgtest [18:08:40]: git checkout: fd3bed09 nova: allow more retries for quota issues 0s autopkgtest [18:08:40]: host juju-7f2275-prod-proposed-migration-environment-2; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.t6aljuzu/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:dracut --apt-upgrade multipath-tools --timeout-short=300 --timeout-copy=20000 --timeout-test=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=dracut/103-1ubuntu3 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest-big-ppc64el --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@bos03-ppc64el-10.secgroup --name adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f2275-prod-proposed-migration-environment-2-0934278a-c961-4bc6-9ced-0a33e4f4d54c --image adt/ubuntu-oracular-ppc64el-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-2 --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/ 65s autopkgtest [18:09:45]: testbed dpkg architecture: ppc64el 65s autopkgtest [18:09:45]: testbed apt version: 2.9.8 65s autopkgtest [18:09:45]: @@@@@@@@@@@@@@@@@@@@ test bed setup 66s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [126 kB] 66s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [180 kB] 66s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [18.0 kB] 66s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [3692 B] 66s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [3548 B] 66s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el Packages [14.7 kB] 66s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el c-n-f Metadata [680 B] 66s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el c-n-f Metadata [120 B] 66s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el Packages [112 kB] 66s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el c-n-f Metadata [4292 B] 66s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el Packages [756 B] 66s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el c-n-f Metadata [120 B] 68s Fetched 464 kB in 1s (722 kB/s) 68s Reading package lists... 71s Reading package lists... 71s Building dependency tree... 71s Reading state information... 71s Calculating upgrade... 71s The following packages will be upgraded: 71s dracut-install 71s 1 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 71s Need to get 37.2 kB of archives. 71s After this operation, 0 B of additional disk space will be used. 71s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el dracut-install ppc64el 103-1ubuntu3 [37.2 kB] 71s Fetched 37.2 kB in 0s (176 kB/s) 72s (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 ... 73552 files and directories currently installed.) 72s Preparing to unpack .../dracut-install_103-1ubuntu3_ppc64el.deb ... 72s Unpacking dracut-install (103-1ubuntu3) over (103-1ubuntu2) ... 72s Setting up dracut-install (103-1ubuntu3) ... 72s Reading package lists... 72s Building dependency tree... 72s Reading state information... 72s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 73s Hit:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease 73s Hit:2 http://ftpmaster.internal/ubuntu oracular InRelease 73s Hit:3 http://ftpmaster.internal/ubuntu oracular-updates InRelease 73s Hit:4 http://ftpmaster.internal/ubuntu oracular-security InRelease 74s Reading package lists... 74s Reading package lists... 74s Building dependency tree... 74s Reading state information... 74s Calculating upgrade... 74s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 74s Reading package lists... 74s Building dependency tree... 74s Reading state information... 75s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 77s autopkgtest [18:09:57]: testbed running kernel: Linux 6.11.0-8-generic #8-Ubuntu SMP Mon Sep 16 13:49:23 UTC 2024 77s autopkgtest [18:09:57]: @@@@@@@@@@@@@@@@@@@@ apt-source multipath-tools 80s Get:1 http://ftpmaster.internal/ubuntu oracular/main multipath-tools 0.9.9-1ubuntu3 (dsc) [2772 B] 80s Get:2 http://ftpmaster.internal/ubuntu oracular/main multipath-tools 0.9.9-1ubuntu3 (tar) [588 kB] 80s Get:3 http://ftpmaster.internal/ubuntu oracular/main multipath-tools 0.9.9-1ubuntu3 (diff) [42.7 kB] 80s gpgv: Signature made Thu Sep 5 17:42:16 2024 UTC 80s gpgv: using RSA key 63EEFC3DE14D5146CE7F24BF34B8AD7D9529E793 80s gpgv: Can't check signature: No public key 80s dpkg-source: warning: cannot verify inline signature for ./multipath-tools_0.9.9-1ubuntu3.dsc: no acceptable signature found 80s autopkgtest [18:10:00]: testing package multipath-tools version 0.9.9-1ubuntu3 81s initramfs SKIP Test lists explicitly supported architectures, but the current architecture ppc64el isn't listed. 81s autopkgtest [18:10:01]: build not needed 82s autopkgtest [18:10:02]: test kpartx-file-loopback: preparing testbed 82s initramfs SKIP Test lists explicitly supported architectures, but the current architecture ppc64el isn't listed. 83s Reading package lists... 83s Building dependency tree... 83s Reading state information... 83s Starting pkgProblemResolver with broken count: 0 84s Starting 2 pkgProblemResolver with broken count: 0 84s Done 84s The following additional packages will be installed: 84s liburing2 qemu-utils 84s Recommended packages: 84s qemu-block-extra 84s The following NEW packages will be installed: 84s autopkgtest-satdep liburing2 qemu-utils 84s 0 upgraded, 3 newly installed, 0 to remove and 0 not upgraded. 84s Need to get 2431 kB/2432 kB of archives. 84s After this operation, 16.9 MB of additional disk space will be used. 84s Get:1 /tmp/autopkgtest.WisOmh/1-autopkgtest-satdep.deb autopkgtest-satdep ppc64el 0 [724 B] 84s Get:2 http://ftpmaster.internal/ubuntu oracular/main ppc64el liburing2 ppc64el 2.6-1 [26.9 kB] 84s Get:3 http://ftpmaster.internal/ubuntu oracular/main ppc64el qemu-utils ppc64el 1:9.0.2+ds-4ubuntu5 [2404 kB] 85s Fetched 2431 kB in 1s (3587 kB/s) 85s Selecting previously unselected package liburing2:ppc64el. 85s (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 ... 73552 files and directories currently installed.) 85s Preparing to unpack .../liburing2_2.6-1_ppc64el.deb ... 85s Unpacking liburing2:ppc64el (2.6-1) ... 85s Selecting previously unselected package qemu-utils. 85s Preparing to unpack .../qemu-utils_1%3a9.0.2+ds-4ubuntu5_ppc64el.deb ... 85s Unpacking qemu-utils (1:9.0.2+ds-4ubuntu5) ... 85s Selecting previously unselected package autopkgtest-satdep. 85s Preparing to unpack .../1-autopkgtest-satdep.deb ... 85s Unpacking autopkgtest-satdep (0) ... 85s Setting up liburing2:ppc64el (2.6-1) ... 85s Setting up qemu-utils (1:9.0.2+ds-4ubuntu5) ... 85s Setting up autopkgtest-satdep (0) ... 85s Processing triggers for man-db (2.12.1-3) ... 86s Processing triggers for libc-bin (2.40-1ubuntu3) ... 88s (Reading database ... 73576 files and directories currently installed.) 88s Removing autopkgtest-satdep (0) ... 89s autopkgtest [18:10:09]: test kpartx-file-loopback: [----------------------- 89s Formatting 'foo.img', fmt=raw size=20971520 90s Creating new GPT entries in memory. 90s Warning: The kernel is still using the old partition table. 90s The new table will be used at the next reboot or after you 90s run partprobe(8) or kpartx(8) 90s The operation has completed successfully. 90s add map loop0p1 (252:0): 0 38879 linear 7:0 2048 90s standard_filename: OK 90s del devmap : loop0p1 90s No devices found 90s standard_filename_cleanup: OK 90s Formatting 'fou du FaFa.img', fmt=raw size=20971520 91s Creating new GPT entries in memory. 91s Warning: The kernel is still using the old partition table. 91s The new table will be used at the next reboot or after you 91s run partprobe(8) or kpartx(8) 91s The operation has completed successfully. 91s add map loop0p1 (252:0): 0 38879 linear 7:0 2048 91s filename_with_spaces: OK 91s del devmap : loop0p1 91s No devices found 91s filename_with_spaces_cleanup: OK 91s autopkgtest [18:10:11]: test kpartx-file-loopback: -----------------------] 92s autopkgtest [18:10:12]: test kpartx-file-loopback: - - - - - - - - - - results - - - - - - - - - - 92s kpartx-file-loopback PASS 92s autopkgtest [18:10:12]: test tgtbasedmpaths: preparing testbed 150s autopkgtest [18:11:10]: testbed dpkg architecture: ppc64el 151s autopkgtest [18:11:11]: testbed apt version: 2.9.8 151s autopkgtest [18:11:11]: @@@@@@@@@@@@@@@@@@@@ test bed setup 151s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [126 kB] 152s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [3692 B] 152s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [180 kB] 152s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [18.0 kB] 152s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [3548 B] 152s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el Packages [14.7 kB] 152s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el c-n-f Metadata [680 B] 152s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el c-n-f Metadata [120 B] 152s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el Packages [112 kB] 152s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el c-n-f Metadata [4292 B] 152s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el Packages [756 B] 152s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el c-n-f Metadata [120 B] 154s Fetched 464 kB in 1s (698 kB/s) 154s Reading package lists... 156s Reading package lists... 156s Building dependency tree... 156s Reading state information... 156s Calculating upgrade... 156s The following packages will be upgraded: 156s dracut-install 156s 1 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 156s Need to get 37.2 kB of archives. 156s After this operation, 0 B of additional disk space will be used. 156s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el dracut-install ppc64el 103-1ubuntu3 [37.2 kB] 157s Fetched 37.2 kB in 0s (177 kB/s) 157s (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 ... 73552 files and directories currently installed.) 157s Preparing to unpack .../dracut-install_103-1ubuntu3_ppc64el.deb ... 157s Unpacking dracut-install (103-1ubuntu3) over (103-1ubuntu2) ... 157s Setting up dracut-install (103-1ubuntu3) ... 157s Reading package lists... 157s Building dependency tree... 157s Reading state information... 158s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 158s Hit:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease 158s Hit:2 http://ftpmaster.internal/ubuntu oracular InRelease 158s Hit:3 http://ftpmaster.internal/ubuntu oracular-updates InRelease 158s Hit:4 http://ftpmaster.internal/ubuntu oracular-security InRelease 159s Reading package lists... 159s Reading package lists... 159s Building dependency tree... 159s Reading state information... 159s Calculating upgrade... 159s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 159s Reading package lists... 160s Building dependency tree... 160s Reading state information... 160s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 164s Reading package lists... 164s Building dependency tree... 164s Reading state information... 164s Starting pkgProblemResolver with broken count: 0 164s Starting 2 pkgProblemResolver with broken count: 0 164s Done 164s The following additional packages will be installed: 164s fio libboost-iostreams1.83.0 libboost-thread1.83.0 libconfig-general-perl 164s libdaxctl1 libgfapi0 libgfrpc0 libgfxdr0 libglusterfs0 libisns0t64 libnbd0 164s libndctl6 libopeniscsiusr libpmem1 libpmemobj1 librados2 librbd1 164s librdmacm1t64 lsscsi open-iscsi tgt 164s Suggested packages: 164s fio-examples gnuplot tgt-glusterfs tgt-rbd 164s Recommended packages: 164s finalrd 164s The following NEW packages will be installed: 164s autopkgtest-satdep fio libboost-iostreams1.83.0 libboost-thread1.83.0 164s libconfig-general-perl libdaxctl1 libgfapi0 libgfrpc0 libgfxdr0 164s libglusterfs0 libisns0t64 libnbd0 libndctl6 libopeniscsiusr libpmem1 164s libpmemobj1 librados2 librbd1 librdmacm1t64 lsscsi open-iscsi tgt 164s 0 upgraded, 22 newly installed, 0 to remove and 0 not upgraded. 164s Need to get 11.0 MB/11.0 MB of archives. 164s After this operation, 50.0 MB of additional disk space will be used. 164s Get:1 /tmp/autopkgtest.WisOmh/2-autopkgtest-satdep.deb autopkgtest-satdep ppc64el 0 [736 B] 164s Get:2 http://ftpmaster.internal/ubuntu oracular/main ppc64el libopeniscsiusr ppc64el 2.1.10-1ubuntu1 [54.9 kB] 165s Get:3 http://ftpmaster.internal/ubuntu oracular/main ppc64el libisns0t64 ppc64el 0.101-1 [117 kB] 165s Get:4 http://ftpmaster.internal/ubuntu oracular/main ppc64el open-iscsi ppc64el 2.1.10-1ubuntu1 [385 kB] 165s Get:5 http://ftpmaster.internal/ubuntu oracular/main ppc64el librdmacm1t64 ppc64el 52.0-2ubuntu1 [80.6 kB] 165s Get:6 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libconfig-general-perl all 2.65-2 [57.1 kB] 165s Get:7 http://ftpmaster.internal/ubuntu oracular/universe ppc64el tgt ppc64el 1:1.0.85-1.2ubuntu1 [254 kB] 165s Get:8 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libgfxdr0 ppc64el 11.1-5ubuntu1 [21.7 kB] 165s Get:9 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libglusterfs0 ppc64el 11.1-5ubuntu1 [308 kB] 165s Get:10 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libgfrpc0 ppc64el 11.1-5ubuntu1 [46.3 kB] 165s Get:11 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libgfapi0 ppc64el 11.1-5ubuntu1 [99.1 kB] 165s Get:12 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libnbd0 ppc64el 1.20.3-1 [99.2 kB] 165s Get:13 http://ftpmaster.internal/ubuntu oracular/main ppc64el libdaxctl1 ppc64el 77-2.2ubuntu1 [23.7 kB] 165s Get:14 http://ftpmaster.internal/ubuntu oracular/main ppc64el libndctl6 ppc64el 77-2.2ubuntu1 [73.4 kB] 165s Get:15 http://ftpmaster.internal/ubuntu oracular/main ppc64el libpmem1 ppc64el 1.13.1-1.1ubuntu2 [41.1 kB] 165s Get:16 http://ftpmaster.internal/ubuntu oracular/main ppc64el libboost-iostreams1.83.0 ppc64el 1.83.0-3.2ubuntu2 [260 kB] 165s Get:17 http://ftpmaster.internal/ubuntu oracular/main ppc64el libboost-thread1.83.0 ppc64el 1.83.0-3.2ubuntu2 [281 kB] 165s Get:18 http://ftpmaster.internal/ubuntu oracular/main ppc64el librados2 ppc64el 19.2.0-0ubuntu1 [4193 kB] 165s Get:19 http://ftpmaster.internal/ubuntu oracular/main ppc64el libpmemobj1 ppc64el 1.13.1-1.1ubuntu2 [143 kB] 165s Get:20 http://ftpmaster.internal/ubuntu oracular/main ppc64el librbd1 ppc64el 19.2.0-0ubuntu1 [3714 kB] 165s Get:21 http://ftpmaster.internal/ubuntu oracular/universe ppc64el fio ppc64el 3.37-1 [716 kB] 165s Get:22 http://ftpmaster.internal/ubuntu oracular/main ppc64el lsscsi ppc64el 0.32-1build1 [54.0 kB] 165s Preconfiguring packages ... 166s Fetched 11.0 MB in 1s (11.1 MB/s) 166s Selecting previously unselected package libopeniscsiusr. 166s (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 ... 73552 files and directories currently installed.) 166s Preparing to unpack .../00-libopeniscsiusr_2.1.10-1ubuntu1_ppc64el.deb ... 166s Unpacking libopeniscsiusr (2.1.10-1ubuntu1) ... 166s Selecting previously unselected package libisns0t64:ppc64el. 166s Preparing to unpack .../01-libisns0t64_0.101-1_ppc64el.deb ... 166s Unpacking libisns0t64:ppc64el (0.101-1) ... 166s Selecting previously unselected package open-iscsi. 166s Preparing to unpack .../02-open-iscsi_2.1.10-1ubuntu1_ppc64el.deb ... 166s Unpacking open-iscsi (2.1.10-1ubuntu1) ... 166s Selecting previously unselected package librdmacm1t64:ppc64el. 166s Preparing to unpack .../03-librdmacm1t64_52.0-2ubuntu1_ppc64el.deb ... 166s Unpacking librdmacm1t64:ppc64el (52.0-2ubuntu1) ... 166s Selecting previously unselected package libconfig-general-perl. 166s Preparing to unpack .../04-libconfig-general-perl_2.65-2_all.deb ... 166s Unpacking libconfig-general-perl (2.65-2) ... 166s Selecting previously unselected package tgt. 166s Preparing to unpack .../05-tgt_1%3a1.0.85-1.2ubuntu1_ppc64el.deb ... 166s Unpacking tgt (1:1.0.85-1.2ubuntu1) ... 166s Selecting previously unselected package libgfxdr0:ppc64el. 166s Preparing to unpack .../06-libgfxdr0_11.1-5ubuntu1_ppc64el.deb ... 166s Unpacking libgfxdr0:ppc64el (11.1-5ubuntu1) ... 166s Selecting previously unselected package libglusterfs0:ppc64el. 166s Preparing to unpack .../07-libglusterfs0_11.1-5ubuntu1_ppc64el.deb ... 166s Unpacking libglusterfs0:ppc64el (11.1-5ubuntu1) ... 166s Selecting previously unselected package libgfrpc0:ppc64el. 166s Preparing to unpack .../08-libgfrpc0_11.1-5ubuntu1_ppc64el.deb ... 166s Unpacking libgfrpc0:ppc64el (11.1-5ubuntu1) ... 166s Selecting previously unselected package libgfapi0:ppc64el. 166s Preparing to unpack .../09-libgfapi0_11.1-5ubuntu1_ppc64el.deb ... 166s Unpacking libgfapi0:ppc64el (11.1-5ubuntu1) ... 166s Selecting previously unselected package libnbd0. 166s Preparing to unpack .../10-libnbd0_1.20.3-1_ppc64el.deb ... 166s Unpacking libnbd0 (1.20.3-1) ... 166s Selecting previously unselected package libdaxctl1:ppc64el. 166s Preparing to unpack .../11-libdaxctl1_77-2.2ubuntu1_ppc64el.deb ... 166s Unpacking libdaxctl1:ppc64el (77-2.2ubuntu1) ... 166s Selecting previously unselected package libndctl6:ppc64el. 166s Preparing to unpack .../12-libndctl6_77-2.2ubuntu1_ppc64el.deb ... 166s Unpacking libndctl6:ppc64el (77-2.2ubuntu1) ... 166s Selecting previously unselected package libpmem1:ppc64el. 166s Preparing to unpack .../13-libpmem1_1.13.1-1.1ubuntu2_ppc64el.deb ... 166s Unpacking libpmem1:ppc64el (1.13.1-1.1ubuntu2) ... 166s Selecting previously unselected package libboost-iostreams1.83.0:ppc64el. 166s Preparing to unpack .../14-libboost-iostreams1.83.0_1.83.0-3.2ubuntu2_ppc64el.deb ... 166s Unpacking libboost-iostreams1.83.0:ppc64el (1.83.0-3.2ubuntu2) ... 166s Selecting previously unselected package libboost-thread1.83.0:ppc64el. 166s Preparing to unpack .../15-libboost-thread1.83.0_1.83.0-3.2ubuntu2_ppc64el.deb ... 166s Unpacking libboost-thread1.83.0:ppc64el (1.83.0-3.2ubuntu2) ... 166s Selecting previously unselected package librados2. 166s Preparing to unpack .../16-librados2_19.2.0-0ubuntu1_ppc64el.deb ... 166s Unpacking librados2 (19.2.0-0ubuntu1) ... 166s Selecting previously unselected package libpmemobj1:ppc64el. 166s Preparing to unpack .../17-libpmemobj1_1.13.1-1.1ubuntu2_ppc64el.deb ... 166s Unpacking libpmemobj1:ppc64el (1.13.1-1.1ubuntu2) ... 166s Selecting previously unselected package librbd1. 166s Preparing to unpack .../18-librbd1_19.2.0-0ubuntu1_ppc64el.deb ... 166s Unpacking librbd1 (19.2.0-0ubuntu1) ... 166s Selecting previously unselected package fio. 166s Preparing to unpack .../19-fio_3.37-1_ppc64el.deb ... 166s Unpacking fio (3.37-1) ... 166s Selecting previously unselected package lsscsi. 166s Preparing to unpack .../20-lsscsi_0.32-1build1_ppc64el.deb ... 166s Unpacking lsscsi (0.32-1build1) ... 166s Selecting previously unselected package autopkgtest-satdep. 166s Preparing to unpack .../21-2-autopkgtest-satdep.deb ... 166s Unpacking autopkgtest-satdep (0) ... 166s Setting up libconfig-general-perl (2.65-2) ... 166s Setting up libisns0t64:ppc64el (0.101-1) ... 166s Setting up libboost-thread1.83.0:ppc64el (1.83.0-3.2ubuntu2) ... 166s Setting up libnbd0 (1.20.3-1) ... 166s Setting up libopeniscsiusr (2.1.10-1ubuntu1) ... 166s Setting up libglusterfs0:ppc64el (11.1-5ubuntu1) ... 166s Setting up libboost-iostreams1.83.0:ppc64el (1.83.0-3.2ubuntu2) ... 166s Setting up lsscsi (0.32-1build1) ... 166s Setting up libdaxctl1:ppc64el (77-2.2ubuntu1) ... 166s Setting up libndctl6:ppc64el (77-2.2ubuntu1) ... 166s Setting up librdmacm1t64:ppc64el (52.0-2ubuntu1) ... 166s Setting up tgt (1:1.0.85-1.2ubuntu1) ... 167s Created symlink '/etc/systemd/system/multi-user.target.wants/tgt.service' → '/usr/lib/systemd/system/tgt.service'. 167s Setting up libpmem1:ppc64el (1.13.1-1.1ubuntu2) ... 167s Setting up libgfxdr0:ppc64el (11.1-5ubuntu1) ... 167s Setting up librados2 (19.2.0-0ubuntu1) ... 167s Setting up open-iscsi (2.1.10-1ubuntu1) ... 168s Created symlink '/etc/systemd/system/sockets.target.wants/iscsid.socket' → '/usr/lib/systemd/system/iscsid.socket'. 168s Created symlink '/etc/systemd/system/iscsi.service' → '/usr/lib/systemd/system/open-iscsi.service'. 168s Created symlink '/etc/systemd/system/sysinit.target.wants/open-iscsi.service' → '/usr/lib/systemd/system/open-iscsi.service'. 169s Setting up libpmemobj1:ppc64el (1.13.1-1.1ubuntu2) ... 169s Setting up librbd1 (19.2.0-0ubuntu1) ... 169s Setting up libgfrpc0:ppc64el (11.1-5ubuntu1) ... 169s Setting up libgfapi0:ppc64el (11.1-5ubuntu1) ... 169s Setting up fio (3.37-1) ... 169s Setting up autopkgtest-satdep (0) ... 169s Processing triggers for man-db (2.12.1-3) ... 171s Processing triggers for initramfs-tools (0.142ubuntu34) ... 171s update-initramfs: Generating /boot/initrd.img-6.11.0-8-generic 171s W: No lz4 in /usr/bin:/sbin:/bin, using gzip 178s Processing triggers for libc-bin (2.40-1ubuntu3) ... 180s (Reading database ... 73793 files and directories currently installed.) 180s Removing autopkgtest-satdep (0) ... 182s autopkgtest [18:11:42]: test tgtbasedmpaths: [----------------------- 182s + targetname=iqn.2016-11.foo.com:target.iscsi 182s + pwd 182s + cwd=/tmp/autopkgtest.WisOmh/build.IG4/src 182s + testdir=/mnt/tgtmpathtest 182s + localhost=127.0.0.1 182s + portal=127.0.0.1:3260 182s + maxpaths=4 182s + backfn=backingfile 182s + expectwwid=60000000000000000e00000000010001 182s + testdisk=/dev/disk/by-id/wwn-0x60000000000000000e00000000010001 182s + bglog=/tmp/autopkgtest.WisOmh/tgtbasedmpaths-artifacts/test-background.log 182s + fioprep=/tmp/autopkgtest.WisOmh/tgtbasedmpaths-artifacts/path-change-prep.fio 182s + fiovrfy=/tmp/autopkgtest.WisOmh/tgtbasedmpaths-artifacts/path-change-check.fio 182s + mkdir -p /etc/multipath 182s + echo /360000000000000000e00000000010001/ 182s + service tgt restart 182s + truncate --size 100M backingfile 182s + tgtadm --lld iscsi --op new --mode target --tid 1 -T iqn.2016-11.foo.com:target.iscsi 182s + tgtadm --lld iscsi --op bind --mode target --tid 1 -I ALL 182s + tgtadm --lld iscsi --op new --mode logicalunit --tid 1 --lun 1 -b /tmp/autopkgtest.WisOmh/build.IG4/src/backingfile 182s + iscsiadm --mode discovery --type sendtargets --portal 127.0.0.1 182s 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi 182s login #1 182s + echo login #1 182s + iscsiadm --mode node --targetname iqn.2016-11.foo.com:target.iscsi --portal 127.0.0.1:3260 --login 182s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 182s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 182s + seq 2 4 182s extra login #2 182s + echo extra login #2 182s + iscsiadm --mode session -r 1 --op new 182s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 182s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 182s extra login #3 182s + echo extra login #3 182s + iscsiadm --mode session -r 1 --op new 182s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 182s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 182s extra login #4 182s + echo extra login #4 182s + iscsiadm --mode session -r 1 --op new 182s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 182s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 182s + udevadm settle 182s + sleep 5 187s Status after initial setup 187s Target 1: iqn.2016-11.foo.com:target.iscsi 187s System information: 187s Driver: iscsi 187s State: ready 187s I_T nexus information: 187s I_T nexus: 1 187s Initiator: iqn.2004-10.com.ubuntu:01:3c30872170f3 alias: autopkgtest 187s Connection: 0 187s IP Address: 127.0.0.1 187s I_T nexus: 2 187s Initiator: iqn.2004-10.com.ubuntu:01:3c30872170f3 alias: autopkgtest 187s Connection: 0 187s IP Address: 127.0.0.1 187s I_T nexus: 3 187s Initiator: iqn.2004-10.com.ubuntu:01:3c30872170f3 alias: autopkgtest 187s Connection: 0 187s IP Address: 127.0.0.1 187s I_T nexus: 4 187s Initiator: iqn.2004-10.com.ubuntu:01:3c30872170f3 alias: autopkgtest 187s Connection: 0 187s IP Address: 127.0.0.1 187s LUN information: 187s LUN: 0 187s Type: controller 187s SCSI ID: IET 00010000 187s SCSI SN: beaf10 187s Size: 0 MB, Block size: 1 187s Online: Yes 187s Removable media: No 187s Prevent removal: No 187s Readonly: No 187s SWP: No 187s Thin-provisioning: No 187s Backing store type: null 187s Backing store path: None 187s Backing store flags: 187s LUN: 1 187s Type: disk 187s SCSI ID: IET 00010001 187s SCSI SN: beaf11 187s Size: 105 MB, Block size: 512 187s Online: Yes 187s Removable media: No 187s Prevent removal: No 187s Readonly: No 187s SWP: No 187s Thin-provisioning: No 187s Backing store type: rdwr 187s Backing store path: /tmp/autopkgtest.WisOmh/build.IG4/src/backingfile 187s Backing store flags: 187s Account information: 187s ACL information: 187s ALL 187s + echo Status after initial setup 187s + tgtadm --lld iscsi --mode target --op show 187s + tgtadm --lld iscsi --op show --mode conn --tid 1 187s Session: 4 187s Connection: 0 187s Initiator: iqn.2004-10.com.ubuntu:01:3c30872170f3 187s IP Address: 127.0.0.1 187s Session: 3 187s Connection: 0 187s Initiator: iqn.2004-10.com.ubuntu:01:3c30872170f3 187s IP Address: 127.0.0.1 187s Session: 2 187s Connection: 0 187s Initiator: iqn.2004-10.com.ubuntu:01:3c30872170f3 187s IP Address: 127.0.0.1 187s Session: 1 187s Connection: 0 187s Initiator: iqn.2004-10.com.ubuntu:01:3c30872170f3 187s IP Address: 127.0.0.1 187s + iscsiadm --mode session -P 1 187s + lsscsi -liv 187s Target: iqn.2016-11.foo.com:target.iscsi (non-flash) 187s Current Portal: 127.0.0.1:3260,1 187s Persistent Portal: 127.0.0.1:3260,1 187s ********** 187s Interface: 187s ********** 187s Iface Name: default 187s Iface Transport: tcp 187s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:3c30872170f3 187s Iface IPaddress: 127.0.0.1 187s Iface HWaddress: default 187s Iface Netdev: default 187s SID: 1 187s iSCSI Connection State: LOGGED IN 187s iSCSI Session State: LOGGED_IN 187s Internal iscsid Session State: NO CHANGE 187s 187s ********** 187s Interface: 187s ********** 187s Iface Name: default 187s Iface Transport: tcp 187s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:3c30872170f3 187s Iface IPaddress: 127.0.0.1 187s Iface HWaddress: default 187s Iface Netdev: default 187s SID: 2 187s iSCSI Connection State: LOGGED IN 187s iSCSI Session State: LOGGED_IN 187s Internal iscsid Session State: NO CHANGE 187s 187s ********** 187s Interface: 187s ********** 187s Iface Name: default 187s Iface Transport: tcp 187s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:3c30872170f3 187s Iface IPaddress: 127.0.0.1 187s Iface HWaddress: default 187s Iface Netdev: default 187s SID: 3 187s iSCSI Connection State: LOGGED IN 187s iSCSI Session State: LOGGED_IN 187s Internal iscsid Session State: NO CHANGE 187s 187s ********** 187s Interface: 187s ********** 187s Iface Name: default 187s Iface Transport: tcp 187s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:3c30872170f3 187s Iface IPaddress: 127.0.0.1 187s Iface HWaddress: default 187s Iface Netdev: default 187s SID: 4 187s iSCSI Connection State: LOGGED IN 187s iSCSI Session State: LOGGED_IN 187s Internal iscsid Session State: NO CHANGE 187s list_ndevices: scandir: /sys/class/nvme/: No such file or directory 187s + multipath -v3 -ll 187s 62.665880 | set open fds limit to 1073741816/1073741816 187s 62.665911 | _read_bindings_file: reading /etc/multipath/bindings 187s 62.665935 | loading /usr/lib/multipath/libchecktur.so checker 187s 62.666015 | checker tur: message table size = 4 187s 62.666022 | loading /usr/lib/multipath/libprioconst.so prioritizer 187s 62.666126 | _init_foreign: foreign library "nvme" is not enabled 187s [0:0:0:0] storage IET Controller 0001 - - 187s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 187s dir: /sys/bus/scsi/devices/0:0:0:0 [/sys/devices/platform/host0/session1/target0:0:0/0:0:0:0] 187s [0:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sda 360000000000000000e00000000010001 187s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 187s dir: /sys/bus/scsi/devices/0:0:0:1 [/sys/devices/platform/host0/session1/target0:0:0/0:0:0:1] 187s [1:0:0:0] storage IET Controller 0001 - - 187s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 187s dir: /sys/bus/scsi/devices/1:0:0:0 [/sys/devices/platform/host1/session2/target1:0:0/1:0:0:0] 187s [1:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdb 360000000000000000e00000000010001 187s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 187s dir: /sys/bus/scsi/devices/1:0:0:1 [/sys/devices/platform/host1/session2/target1:0:0/1:0:0:1] 187s [2:0:0:0] storage IET Controller 0001 - - 187s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 187s dir: /sys/bus/scsi/devices/2:0:0:0 [/sys/devices/platform/host2/session3/target2:0:0/2:0:0:0] 187s [2:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdc 360000000000000000e00000000010001 187s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 187s dir: /sys/bus/scsi/devices/2:0:0:1 [/sys/devices/platform/host2/session3/target2:0:0/2:0:0:1] 187s [3:0:0:0] storage IET Controller 0001 - - 187s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 187s dir: /sys/bus/scsi/devices/3:0:0:0 [/sys/devices/platform/host3/session4/target3:0:0/3:0:0:0] 187s [3:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdd 33000000100000001 187s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 187s dir: /sys/bus/scsi/devices/3:0:0:1 [/sys/devices/platform/host3/session4/target3:0:0/3:0:0:1] 187s NVMe module may not be loaded 187s 62.670673 | vda: device node name blacklisted 187s 62.670957 | sda: size = 204800 187s 62.671102 | sda: vendor = IET 187s 62.671145 | sda: product = VIRTUAL-DISK 187s 62.671188 | sda: rev = 0001 187s 62.671849 | sda: h:b:t:l = 0:0:0:1 187s 62.672194 | sda: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 187s 62.672224 | sda: uid_attribute = ID_SERIAL (setting: multipath internal) 187s 62.672244 | sda: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 187s 62.672433 | sda: 1024 cyl, 4 heads, 50 sectors/track, start at 0 187s 62.672456 | sda: vpd_vendor_id = 0 "undef" (setting: multipath internal) 187s 62.672489 | sda: serial = beaf11 187s 62.672511 | sda: detect_checker = yes (setting: multipath internal) 187s 62.672555 | sda checker timeout = 30 s (setting: kernel sysfs) 187s 62.672744 | sda: path_checker = tur (setting: multipath internal) 187s 62.672829 | sda: tur state = up 187s 62.672966 | sdb: size = 204800 187s 62.673111 | sdb: vendor = IET 187s 62.673153 | sdb: product = VIRTUAL-DISK 187s 62.673196 | sdb: rev = 0001 187s 62.673833 | sdb: h:b:t:l = 1:0:0:1 187s 62.674174 | sdb: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 187s 62.674197 | sdb: uid_attribute = ID_SERIAL (setting: multipath internal) 187s 62.674217 | sdb: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 187s 62.674375 | sdb: 1024 cyl, 4 heads, 50 sectors/track, start at 0 187s 62.674397 | sdb: vpd_vendor_id = 0 "undef" (setting: multipath internal) 187s 62.674428 | sdb: serial = beaf11 187s 62.674448 | sdb: detect_checker = yes (setting: multipath internal) 187s 62.674493 | sdb checker timeout = 30 s (setting: kernel sysfs) 187s 62.674596 | sdb: path_checker = tur (setting: multipath internal) 187s 62.674679 | sdb: tur state = up 187s 62.674813 | sdc: size = 204800 187s 62.674957 | sdc: vendor = IET 187s 62.674998 | sdc: product = VIRTUAL-DISK 187s 62.675040 | sdc: rev = 0001 187s 62.675680 | sdc: h:b:t:l = 2:0:0:1 187s 62.676041 | sdc: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 187s 62.676071 | sdc: uid_attribute = ID_SERIAL (setting: multipath internal) 187s 62.676090 | sdc: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 187s 62.676245 | sdc: 1024 cyl, 4 heads, 50 sectors/track, start at 0 187s 62.676267 | sdc: vpd_vendor_id = 0 "undef" (setting: multipath internal) 187s 62.676305 | sdc: serial = beaf11 187s 62.676326 | sdc: detect_checker = yes (setting: multipath internal) 187s 62.676383 | sdc checker timeout = 30 s (setting: kernel sysfs) 187s 62.676484 | sdc: path_checker = tur (setting: multipath internal) 187s 62.676566 | sdc: tur state = up 187s 62.676702 | sdd: size = 204800 187s 62.676848 | sdd: vendor = IET 187s 62.676890 | sdd: product = VIRTUAL-DISK 187s 62.676933 | sdd: rev = 0001 187s 62.677576 | sdd: h:b:t:l = 3:0:0:1 187s 62.677915 | sdd: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 187s 62.677937 | sdd: uid_attribute = ID_SERIAL (setting: multipath internal) 187s 62.677957 | sdd: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 187s 62.678115 | sdd: 1024 cyl, 4 heads, 50 sectors/track, start at 0 187s 62.678137 | sdd: vpd_vendor_id = 0 "undef" (setting: multipath internal) 187s 62.678167 | sdd: serial = beaf11 187s 62.678187 | sdd: detect_checker = yes (setting: multipath internal) 187s 62.678231 | sdd checker timeout = 30 s (setting: kernel sysfs) 187s 62.678331 | sdd: path_checker = tur (setting: multipath internal) 187s 62.678411 | sdd: tur state = up 187s 62.678515 | loop0: device node name blacklisted 187s 62.678617 | loop1: device node name blacklisted 187s 62.678719 | loop2: device node name blacklisted 187s 62.678820 | loop3: device node name blacklisted 187s 62.678921 | loop4: device node name blacklisted 187s 62.679021 | loop5: device node name blacklisted 187s 62.679121 | loop6: device node name blacklisted 187s 62.679220 | loop7: device node name blacklisted 187s 62.679324 | dm-0: device node name blacklisted 187s 62.680338 | multipath-tools v0.9.9 (05/03, 2024) 187s 62.680387 | libdevmapper version 1.02.196 187s 62.680533 | kernel device mapper v4.48.0 187s 62.680565 | DM multipath kernel driver v1.14.0 187s 62.680688 | sda: size = 204800 187s 62.680712 | sda: vendor = IET 187s 62.680732 | sda: product = VIRTUAL-DISK 187s 62.680752 | sda: rev = 0001 187s 62.681353 | sda: h:b:t:l = 0:0:0:1 187s 62.681481 | sda: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 187s 62.681518 | sda: 1024 cyl, 4 heads, 50 sectors/track, start at 0 187s 62.681540 | sda: vpd_vendor_id = 0 "undef" (setting: multipath internal) 187s 62.681569 | sda: serial = beaf11 187s 62.681648 | sda: tur state = up 187s 62.681671 | sda: uid = 360000000000000000e00000000010001 (udev) 187s 62.681692 | sda: detect_prio = yes (setting: multipath internal) 187s 62.681712 | sda: prio = const (setting: multipath internal) 187s 62.681732 | sda: prio args = "" (setting: multipath internal) 187s 62.681751 | sda: const prio = 1 187s 62.681789 | sdb: size = 204800 187s 62.681811 | sdb: vendor = IET 187s 62.681832 | sdb: product = VIRTUAL-DISK 187s 62.681852 | sdb: rev = 0001 187s 62.682442 | sdb: h:b:t:l = 1:0:0:1 187s 62.682568 | sdb: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 187s 62.682606 | sdb: 1024 cyl, 4 heads, 50 sectors/track, start at 0 187s 62.682627 | sdb: vpd_vendor_id = 0 "undef" (setting: multipath internal) 187s 62.682657 | sdb: serial = beaf11 187s 62.682734 | sdb: tur state = up 187s 62.682755 | sdb: uid = 360000000000000000e00000000010001 (udev) 187s 62.682775 | sdb: detect_prio = yes (setting: multipath internal) 187s 62.682795 | sdb: prio = const (setting: multipath internal) 187s 62.682814 | sdb: prio args = "" (setting: multipath internal) 187s 62.682833 | sdb: const prio = 1 187s 62.682870 | sdc: size = 204800 187s 62.682893 | sdc: vendor = IET 187s 62.682913 | sdc: product = VIRTUAL-DISK 187s 62.682933 | sdc: rev = 0001 187s 62.683520 | sdc: h:b:t:l = 2:0:0:1 187s 62.683644 | sdc: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 187s 62.683681 | sdc: 1024 cyl, 4 heads, 50 sectors/track, start at 0 187s 62.683703 | sdc: vpd_vendor_id = 0 "undef" (setting: multipath internal) 187s 62.683733 | sdc: serial = beaf11 187s 62.683808 | sdc: tur state = up 187s 62.683831 | sdc: uid = 360000000000000000e00000000010001 (udev) 187s 62.683851 | sdc: detect_prio = yes (setting: multipath internal) 187s 62.683870 | sdc: prio = const (setting: multipath internal) 187s 62.683889 | sdc: prio args = "" (setting: multipath internal) 187s 62.683908 | sdc: const prio = 1 187s 62.683944 | sdd: size = 204800 187s 62.683967 | sdd: vendor = IET 187s 62.683986 | sdd: product = VIRTUAL-DISK 187s 62.684040 | sdd: rev = 0001 187s 62.684640 | sdd: h:b:t:l = 3:0:0:1 187s 62.684768 | sdd: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 187s 62.684806 | sdd: 1024 cyl, 4 heads, 50 sectors/track, start at 0 187s 62.684830 | sdd: vpd_vendor_id = 0 "undef" (setting: multipath internal) 187s 62.684859 | sdd: serial = beaf11 187s 62.684938 | sdd: tur state = up 187s 62.684960 | sdd: uid = 360000000000000000e00000000010001 (udev) 187s 62.684980 | sdd: detect_prio = yes (setting: multipath internal) 187s 62.684999 | sdd: prio = const (setting: multipath internal) 187s 62.685018 | sdd: prio args = "" (setting: multipath internal) 187s 62.685036 | sdd: const prio = 1 187s 62.685808 | unloading tur checker 187s 62.685854 | unloading const prioritizer 187s + dmsetup table 187s + grep . /etc/multipath/bindings /etc/multipath/wwids 187s + systemctl status multipathd.service 187s + ret_code=0 187s + systemctl status multipathd.socket 187s ===== paths list ===== 187s uuid hcil dev dev_t pri dm_st chk_st vend/prod/rev dev_st 187s 0:0:0:1 sda 8:0 -1 undef undef IET,VIRTUAL-DISK,0001 unknown 187s 1:0:0:1 sdb 8:16 -1 undef undef IET,VIRTUAL-DISK,0001 unknown 187s 2:0:0:1 sdc 8:32 -1 undef undef IET,VIRTUAL-DISK,0001 unknown 187s 3:0:0:1 sdd 8:48 -1 undef undef IET,VIRTUAL-DISK,0001 unknown 187s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 187s size=100M features='0' hwhandler='0' wp=rw 187s |-+- policy='service-time 0' prio=1 status=active 187s | `- 0:0:0:1 sda 8:0 active ready running 187s |-+- policy='service-time 0' prio=1 status=enabled 187s | `- 1:0:0:1 sdb 8:16 active ready running 187s |-+- policy='service-time 0' prio=1 status=enabled 187s | `- 2:0:0:1 sdc 8:32 active ready running 187s `-+- policy='service-time 0' prio=1 status=enabled 187s `- 3:0:0:1 sdd 8:48 active ready running 187s 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:32 1 1 service-time 0 1 2 8:48 1 1 187s /etc/multipath/bindings:# Multipath bindings, Version : 1.0 187s /etc/multipath/bindings:# NOTE: this file is automatically maintained by the multipath program. 187s /etc/multipath/bindings:# You should not need to edit this file in normal circumstances. 187s /etc/multipath/bindings:# 187s /etc/multipath/bindings:# Format: 187s /etc/multipath/bindings:# alias wwid 187s /etc/multipath/bindings:# 187s /etc/multipath/bindings:mpatha 360000000000000000e00000000010001 187s /etc/multipath/wwids:/360000000000000000e00000000010001/ 187s ● multipathd.service - Device-Mapper Multipath Device Controller 187s Loaded: loaded (/usr/lib/systemd/system/multipathd.service; enabled; preset: enabled) 187s Active: active (running) since Mon 2024-09-30 18:10:47 UTC; 1min 0s ago 187s Invocation: 734802c9d1914c5d94a542cfe7161a62 187s TriggeredBy: ○ multipathd.socket 187s Main PID: 317 (multipathd) 187s Status: "up" 187s Tasks: 7 187s Memory: 28M (peak: 35.1M) 187s CPU: 35ms 187s CGroup: /system.slice/multipathd.service 187s └─317 /sbin/multipathd -d -s 187s 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i multipathd[317]: multipathd v0.9.9: start up 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i multipathd[317]: reconfigure: setting up paths and maps 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 187s Sep 30 18:11:42 autopkgtest multipathd[317]: updated bindings file /etc/multipath/bindings 187s Sep 30 18:11:42 autopkgtest multipathd[317]: mpatha: addmap [0 204800 multipath 0 0 1 1 service-time 0 1 1 8:0 1] 187s Sep 30 18:11:42 autopkgtest multipathd[317]: sda [8:0]: path added to devmap mpatha 187s Sep 30 18:11:42 autopkgtest multipathd[317]: mpatha: performing delayed actions 187s Sep 30 18:11:42 autopkgtest multipathd[317]: 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:48 1] 187s + ret_code=3 187s + [ 3 -eq 0 ] 187s + [ 3 -eq 3 ] 187s + ls -la /dev/mapper/ 187s + echo journal 187s + journalctl -b 187s ○ multipathd.socket - multipathd control socket 187s Loaded: loaded (/usr/lib/systemd/system/multipathd.socket; static) 187s Active: inactive (dead) 187s Triggers: ● multipathd.service 187s Listen: @/org/kernel/linux/storage/multipathd (Stream) 187s total 0 187s drwxr-xr-x 2 root root 80 Sep 30 18:11 . 187s drwxr-xr-x 20 root root 4360 Sep 30 18:11 .. 187s crw------- 1 root root 10, 236 Sep 30 18:10 control 187s lrwxrwxrwx 1 root root 7 Sep 30 18:11 mpatha -> ../dm-0 187s journal 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: radix-mmu: Page sizes from device-tree: 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: radix-mmu: Page size shift = 12 AP=0x0 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: radix-mmu: Page size shift = 16 AP=0x5 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: radix-mmu: Page size shift = 21 AP=0x1 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: radix-mmu: Page size shift = 30 AP=0x2 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Activating Kernel Userspace Access Prevention 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Activating Kernel Userspace Execution Prevention 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: radix-mmu: Mapped 0x0000000000000000-0x0000000003a00000 with 2.00 MiB pages (exec) 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: radix-mmu: Mapped 0x0000000003a00000-0x0000000040000000 with 2.00 MiB pages 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: radix-mmu: Mapped 0x0000000040000000-0x0000000200000000 with 1.00 GiB pages 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: lpar: Using radix MMU under hypervisor 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Linux version 6.11.0-8-generic (buildd@bos01-ppc64el-009) (powerpc64le-linux-gnu-gcc-14 (Ubuntu 14.2.0-4ubuntu2) 14.2.0, GNU ld (GNU Binutils for Ubuntu) 2.43.1) #8-Ubuntu SMP Mon Sep 16 13:49:23 UTC 2024 (Ubuntu 6.11.0-8.8-generic 6.11.0) 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Secure boot mode disabled 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Found initrd at 0xc000000006200000:0xc00000000955bd54 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Hardware name: IBM pSeries (emulated by qemu) POWER9 (architected) 0x4e1203 0xf000005 of:SLOF,HEAD hv:linux,kvm pSeries 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Partition configured for 4 cpus. 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: CPU maps initialized for 1 thread per core 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: (thread shift is 0) 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Allocated 3360 bytes for 4 pacas 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: numa: Partition configured for 1 NUMA nodes. 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: ----------------------------------------------------- 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: phys_mem_size = 0x200000000 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: dcache_bsize = 0x80 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: icache_bsize = 0x80 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: cpu_features = 0x0001c06b8f4f9187 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: possible = 0x001ffbfbcf5fb187 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: always = 0x0000000380008181 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: cpu_user_features = 0xdc0065c2 0xaef00000 187s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: mmu_features = 0x3c007641 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: firmware_features = 0x00000285455a445f 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: vmalloc start = 0xc008000000000000 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: IO start = 0xc00a000000000000 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: vmemmap start = 0xc00c000000000000 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: ----------------------------------------------------- 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: numa: NODE_DATA [mem 0x1fff7c280-0x1fff83fff] 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: rfi-flush: fallback displacement flush available 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: rfi-flush: ori type flush available 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: rfi-flush: mttrig type flush available 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: rfi-flush: patched 12 locations (ori+mttrig type flush) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: count-cache-flush: hardware flush enabled. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: link-stack-flush: software flush enabled. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: entry-flush: patched 61 locations (ori+mttrig type flush) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: uaccess-flush: patched 1 locations (ori+mttrig type flush) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: stf-barrier: eieio barrier available 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: stf-barrier: patched 61 entry locations (eieio barrier) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: stf-barrier: patched 12 exit locations (eieio barrier) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: PPC64 nvram contains 65536 bytes 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: barrier-nospec: using ORI speculation barrier 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: barrier-nospec: patched 275 locations 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Top of RAM: 0x200000000, Total RAM: 0x200000000 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Memory hole size: 0MB 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Zone ranges: 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Normal [mem 0x0000000000000000-0x00000001ffffffff] 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Device empty 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Movable zone start for each node 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Early memory node ranges 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: node 0: [mem 0x0000000000000000-0x00000001ffffffff] 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Initmem setup node 0 [mem 0x0000000000000000-0x00000001ffffffff] 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: percpu: Embedded 12 pages/cpu s619032 r0 d167400 u786432 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pcpu-alloc: s619032 r0 d167400 u786432 alloc=12*65536 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Kernel command line: BOOT_IMAGE=/boot/vmlinux-6.11.0-8-generic root=UUID=f3996c9c-8948-455c-b9ae-42041c08b247 ro console=hvc0 earlyprintk 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Unknown kernel command line parameters "earlyprintk BOOT_IMAGE=/boot/vmlinux-6.11.0-8-generic", will be passed to user space. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Dentry cache hash table entries: 1048576 (order: 7, 8388608 bytes, linear) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Inode-cache hash table entries: 524288 (order: 6, 4194304 bytes, linear) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Fallback order for Node 0: 0 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Built 1 zonelists, mobility grouping on. Total pages: 131072 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Policy zone: Normal 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: mem auto-init: stack:all(zero), heap alloc:on, heap free:off 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: SLUB: HWalign=128, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: ftrace: allocating 52900 entries in 20 pages 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: ftrace: allocated 20 pages with 2 groups 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: trace event string verifier disabled 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: rcu: Hierarchical RCU implementation. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: rcu: RCU restricting CPUs from NR_CPUS=2048 to nr_cpu_ids=4. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Rude variant of Tasks RCU enabled. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Tracing variant of Tasks RCU enabled. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: RCU Tasks Rude: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: RCU Tasks Trace: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: NR_IRQS: 512, nr_irqs: 512, preallocated irqs: 16 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: xive: Using IRQ range [0-3] 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: xive: Interrupt handling initialized with spapr backend 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: xive: Using priority 6 for all interrupts 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: xive: Using 64kB queues 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: rcu: srcu_init: Setting srcu_struct sizes based on contention. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: time_init: decrementer frequency = 512.000000 MHz 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: time_init: processor frequency = 2700.000000 MHz 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: time_init: 56 bit decrementer (max: 7fffffffffffff) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: clocksource: timebase: mask: 0xffffffffffffffff max_cycles: 0x761537d007, max_idle_ns: 440795202126 ns 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: clocksource: timebase mult[1f40000] shift[24] registered 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: clockevent: decrementer mult[83126f] shift[24] cpu[0] 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Console: colour dummy device 80x25 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pid_max: default: 32768 minimum: 301 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: LSM: initializing lsm=lockdown,capability,landlock,yama,apparmor,ima,evm 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: landlock: Up and running. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Yama: becoming mindful. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: AppArmor: AppArmor initialized 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Mount-cache hash table entries: 16384 (order: 1, 131072 bytes, linear) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Mountpoint-cache hash table entries: 16384 (order: 1, 131072 bytes, linear) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: POWER9 performance monitor hardware support registered 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: rcu: Hierarchical SRCU implementation. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: rcu: Max phase no-delay instances is 1000. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Timer migration: 1 hierarchy levels; 8 children per group; 1 crossnode level 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: smp: Bringing up secondary CPUs ... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: smp: Brought up 1 node, 4 CPUs 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: numa: Node 0 CPUs: 0-3 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Memory: 8201152K/8388608K available (24384K kernel code, 4160K rwdata, 24768K rodata, 8768K init, 1851K bss, 158272K reserved, 0K cma-reserved) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: devtmpfs: initialized 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: PCI host bridge /pci@800000020000000 ranges: 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: IO 0x0000200000000000..0x000020000000ffff -> 0x0000000000000000 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: MEM 0x0000200080000000..0x00002000ffffffff -> 0x0000000080000000 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: MEM 0x0000210000000000..0x000021ffffffffff -> 0x0000210000000000 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: futex hash table entries: 1024 (order: 1, 131072 bytes, linear) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pinctrl core: initialized pinctrl subsystem 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: NET: Registered PF_NETLINK/PF_ROUTE protocol family 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: audit: initializing netlink subsys (disabled) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: audit: type=2000 audit(1727719844.040:1): state=initialized audit_enabled=0 res=1 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: thermal_sys: Registered thermal governor 'fair_share' 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: thermal_sys: Registered thermal governor 'bang_bang' 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: thermal_sys: Registered thermal governor 'step_wise' 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: thermal_sys: Registered thermal governor 'user_space' 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: thermal_sys: Registered thermal governor 'power_allocator' 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: cpuidle: using governor ladder 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: cpuidle: using governor menu 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: RTAS daemon started 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pstore: Using crash dump compression: deflate 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pstore: Registered nvram as persistent store backend 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: EEH: pSeries platform initialized 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: iommu: Default domain type: Translated 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: iommu: DMA domain TLB invalidation policy: strict mode 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: SCSI subsystem initialized 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: libata version 3.00 loaded. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usbcore: registered new interface driver usbfs 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usbcore: registered new interface driver hub 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usbcore: registered new device driver usb 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pps_core: LinuxPPS API ver. 1 registered 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: PTP clock support registered 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: EDAC MC: Ver: 3.0.0 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: NetLabel: Initializing 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: NetLabel: domain hash size = 128 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: NetLabel: unlabeled traffic allowed by default 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: mctp: management component transport protocol core 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: NET: Registered PF_MCTP protocol family 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: PCI: Probing PCI hardware 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: PCI host bridge to bus 0000:00 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci_bus 0000:00: root bus resource [io 0x10000-0x1ffff] (bus address [0x0000-0xffff]) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci_bus 0000:00: root bus resource [mem 0x200080000000-0x2000ffffffff] (bus address [0x80000000-0xffffffff]) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci_bus 0000:00: root bus resource [mem 0x210000000000-0x21ffffffffff 64bit] 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci_bus 0000:00: root bus resource [bus 00-ff] 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci 0000:00:01.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci 0000:00:02.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci 0000:00:03.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci 0000:00:04.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci 0000:00:05.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci 0000:00:06.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci 0000:00:07.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: IOMMU table initialized, virtual merging enabled 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: PCI 0000:00 Cannot reserve Legacy IO [io 0x10000-0x10fff] 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci_bus 0000:00: resource 4 [io 0x10000-0x1ffff] 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci_bus 0000:00: resource 5 [mem 0x200080000000-0x2000ffffffff] 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci_bus 0000:00: resource 6 [mem 0x210000000000-0x21ffffffffff 64bit] 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci 0000:00:01.0: ibm,query-pe-dma-windows(2026) 800 8000000 20000000 returned 0, lb=80000000 ps=7 wn=1 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci 0000:00:01.0: Adding to iommu group 0 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci 0000:00:02.0: Adding to iommu group 0 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci 0000:00:03.0: Adding to iommu group 0 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci 0000:00:04.0: Adding to iommu group 0 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci 0000:00:05.0: Adding to iommu group 0 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci 0000:00:06.0: Adding to iommu group 0 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci 0000:00:07.0: Adding to iommu group 0 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: EEH: No capable adapters found: recovery disabled. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: PCI: Probing PCI hardware done 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci 0000:00:07.0: vgaarb: setting as boot VGA device 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci 0000:00:07.0: vgaarb: bridge control possible 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pci 0000:00:07.0: vgaarb: VGA device added: decodes=io+mem,owns=mem,locks=none 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: vgaarb: loaded 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: clocksource: Switched to clocksource timebase 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: VFS: Disk quotas dquot_6.6.0 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: VFS: Dquot-cache hash table entries: 8192 (order 0, 65536 bytes) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: AppArmor: AppArmor Filesystem Enabled 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: NET: Registered PF_INET protocol family 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: IP idents hash table entries: 131072 (order: 4, 1048576 bytes, linear) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: tcp_listen_portaddr_hash hash table entries: 4096 (order: 0, 65536 bytes, linear) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Table-perturb hash table entries: 65536 (order: 2, 262144 bytes, linear) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: TCP established hash table entries: 65536 (order: 3, 524288 bytes, linear) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: TCP bind hash table entries: 65536 (order: 5, 2097152 bytes, linear) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: TCP: Hash tables configured (established 65536 bind 65536) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: MPTCP token hash table entries: 8192 (order: 1, 196608 bytes, linear) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: UDP hash table entries: 4096 (order: 1, 131072 bytes, linear) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: UDP-Lite hash table entries: 4096 (order: 1, 131072 bytes, linear) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: NET: Registered PF_UNIX/PF_LOCAL protocol family 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: NET: Registered PF_XDP protocol family 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: PCI: CLS 0 bytes, default 128 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Trying to unpack rootfs image as initramfs... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Initialise system trusted keyrings 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Key type blacklist registered 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: workingset: timestamp_bits=38 max_order=17 bucket_order=0 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: zbud: loaded 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: fuse: init (API version 7.40) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: integrity: Platform Keyring initialized 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: integrity: Machine keyring initialized 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Key type asymmetric registered 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Asymmetric key parser 'x509' registered 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 243) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: io scheduler mq-deadline registered 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: virtio-pci 0000:00:01.0: enabling device (0100 -> 0103) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-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 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-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) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: virtio-pci 0000:00:03.0: enabling device (0100 -> 0103) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: virtio-pci 0000:00:04.0: enabling device (0100 -> 0103) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: virtio-pci 0000:00:05.0: enabling device (0100 -> 0103) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: virtio-pci 0000:00:06.0: enabling device (0100 -> 0103) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: printk: legacy console [hvc0] enabled 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Freeing initrd memory: 52544K 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Non-volatile memory driver v1.3 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Linux agpgart interface v0.103 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: loop: module loaded 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: virtio_blk virtio2: 4/0/0 default/read/poll queues 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: virtio_blk virtio2: [vda] 209715200 512-byte logical blocks (107 GB/100 GiB) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: GPT:Primary header thinks Alt. header is not at the end of the disk. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: GPT:41943039 != 209715199 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: GPT:Alternate GPT header not at the end of the disk. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: GPT:41943039 != 209715199 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: GPT: Use GNU Parted to correct GPT errors. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: vda: vda1 vda2 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: tun: Universal TUN/TAP device driver, 1.6 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: PPP generic driver version 2.4.2 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: mousedev: PS/2 mouse device common for all mice 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: rtc-generic rtc-generic: registered as rtc0 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: rtc-generic rtc-generic: setting system clock to 2024-09-30T18:10:45 UTC (1727719845) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: i2c_dev: i2c /dev entries driver 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: device-mapper: uevent: version 1.0.3 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@lists.linux.dev 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: pseries_idle_driver registered 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: ledtrig-cpu: registered to indicate activity on CPUs 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: drop_monitor: Initializing network drop monitor service 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: NET: Registered PF_INET6 protocol family 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Segment Routing with IPv6 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: In-situ OAM (IOAM) with IPv6 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: NET: Registered PF_PACKET protocol family 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Key type dns_resolver registered 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: secvar-sysfs: Failed to retrieve secvar operations 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: registered taskstats version 1 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Loading compiled-in X.509 certificates 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Loaded X.509 cert 'Build time autogenerated kernel key: d43630f15d3f0c00f59e22a0c5131b4ebd804093' 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Live Patch Signing: 14df34d1a87cf37625abec039ef2bf521249b969' 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Kernel Module Signing: 88f752e560a1e0737e31163a466ad7b70a850c19' 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: blacklist: Loading compiled-in revocation X.509 certificates 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing: 61482aa2830d0ab2ad5af10b7250da9033ddcef0' 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2017): 242ade75ac4a15e50d50c84b0d45ff3eae707a03' 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (ESM 2018): 365188c1d374d6b07c3c8f240f8ef722433d6a8b' 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2019): c0746fd6c5da3ae827864651ad66ae47fe24b3e8' 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2021 v1): a8d54bbb3825cfb94fa13c9f8a594a195c107b8d' 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2021 v2): 4cf046892d6fd3c9a5b03f98d845f90851dc6a8c' 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2021 v3): 100437bb6de6e469b581e61cd66bce3ef4ed53af' 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (Ubuntu Core 2019): c1d57b8f6b743f23ee41f4f7ee292f06eecadfb9' 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Demotion targets for Node 0: null 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Key type .fscrypt registered 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Key type fscrypt-provisioning registered 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Key type encrypted registered 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: AppArmor: AppArmor sha256 policy hashing enabled 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Secure boot mode disabled 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: ima: No TPM chip found, activating TPM-bypass! 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Loading compiled-in module X.509 certificates 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Loaded X.509 cert 'Build time autogenerated kernel key: d43630f15d3f0c00f59e22a0c5131b4ebd804093' 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: ima: Allocated hash algorithm: sha256 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Secure boot mode disabled 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Trusted boot mode disabled 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: ima: No architecture policies found 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: evm: Initialising EVM extended attributes: 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: evm: security.selinux 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: evm: security.SMACK64 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: evm: security.SMACK64EXEC 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: evm: security.SMACK64TRANSMUTE 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: evm: security.SMACK64MMAP 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: evm: security.apparmor 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: evm: security.ima 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: evm: security.capability 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: evm: HMAC attrs: 0x1 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: SED: plpks not available 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: clk: Disabling unused clocks 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: PM: genpd: Disabling unused power domains 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: integrity: Unable to open file: /etc/keys/x509_evm.der (-2) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Freeing unused kernel image (initmem) memory: 8768K 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Checked W+X mappings: passed, no W+X pages found 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Run /init as init process 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: with arguments: 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: /init 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: earlyprintk 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: with environment: 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: HOME=/ 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: TERM=linux 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: BOOT_IMAGE=/boot/vmlinux-6.11.0-8-generic 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: virtio_net virtio0 enp0s1: renamed from eth0 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: xhci_hcd 0000:00:02.0: xHCI Host Controller 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: xhci_hcd 0000:00:02.0: new USB bus registered, assigned bus number 1 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: xhci_hcd 0000:00:02.0: hcc params 0x00087001 hci version 0x100 quirks 0x0000000000000010 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: xhci_hcd 0000:00:02.0: xHCI Host Controller 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: xhci_hcd 0000:00:02.0: new USB bus registered, assigned bus number 2 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: xhci_hcd 0000:00:02.0: Host supports USB 3.0 SuperSpeed 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.11 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usb usb1: Product: xHCI Host Controller 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usb usb1: Manufacturer: Linux 6.11.0-8-generic xhci-hcd 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usb usb1: SerialNumber: 0000:00:02.0 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: hub 1-0:1.0: USB hub found 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: hub 1-0:1.0: 4 ports detected 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: random: crng init done 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usb usb2: We don't know the algorithms for LPM for this host, disabling LPM. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 6.11 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usb usb2: Product: xHCI Host Controller 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usb usb2: Manufacturer: Linux 6.11.0-8-generic xhci-hcd 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usb usb2: SerialNumber: 0000:00:02.0 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: hub 2-0:1.0: USB hub found 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: hub 2-0:1.0: 4 ports detected 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: [drm] Found bochs VGA, ID 0xb0c5. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: [drm] Framebuffer size 16384 kB @ 0x200081000000, mmio @ 0x200082000000. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: [drm] Found EDID data blob. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: [drm] Initialized bochs-drm 1.0.0 for 0000:00:07.0 on minor 0 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: fbcon: Deferring console take-over 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: bochs-drm 0000:00:07.0: [drm] fb0: bochs-drmdrmfb frame buffer device 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: raid6: vpermxor8 gen() 22974 MB/s 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: raid6: vpermxor4 gen() 20384 MB/s 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usb 1-1: new high-speed USB device number 2 using xhci_hcd 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: raid6: vpermxor2 gen() 16136 MB/s 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: raid6: vpermxor1 gen() 13804 MB/s 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usb 1-1: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usb 1-1: New USB device strings: Mfr=1, Product=4, SerialNumber=11 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usb 1-1: Product: QEMU USB Keyboard 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usb 1-1: Manufacturer: QEMU 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usb 1-1: SerialNumber: 68284-pci@800000020000000:02.0-1 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: raid6: altivecx8 gen() 13927 MB/s 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: hid: raw HID events driver (C) Jiri Kosina 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usbcore: registered new interface driver usbhid 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usbhid: USB HID core driver 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-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 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: raid6: altivecx4 gen() 13710 MB/s 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-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 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usb 1-2: new high-speed USB device number 3 using xhci_hcd 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: raid6: altivecx2 gen() 11355 MB/s 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: raid6: altivecx1 gen() 8718 MB/s 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usb 1-2: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=9 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usb 1-2: Product: QEMU USB Mouse 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usb 1-2: Manufacturer: QEMU 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: usb 1-2: SerialNumber: 89126-pci@800000020000000:02.0-2 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-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 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-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 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: raid6: int64x8 gen() 7212 MB/s 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: raid6: int64x4 gen() 8806 MB/s 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: raid6: int64x2 gen() 6697 MB/s 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: raid6: int64x1 gen() 5337 MB/s 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: raid6: using algorithm vpermxor8 gen() 22974 MB/s 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: raid6: using intx1 recovery algorithm 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: xor: measuring software checksum speed 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: 8regs : 17861 MB/sec 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: 8regs_prefetch : 15588 MB/sec 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: 32regs : 17911 MB/sec 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: 32regs_prefetch : 16090 MB/sec 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: altivec : 19993 MB/sec 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: xor: using function: altivec (19993 MB/sec) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Btrfs loaded, zoned=yes, fsverity=yes 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: EXT4-fs (vda1): orphan cleanup on readonly fs 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: EXT4-fs (vda1): mounted filesystem f3996c9c-8948-455c-b9ae-42041c08b247 ro with ordered data mode. Quota mode: none. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Inserted module 'autofs4' 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: systemd 256.5-2ubuntu2 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) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Detected virtualization kvm. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Detected architecture ppc64-le. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Hostname set to . 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: bpf-restrict-fs: BPF LSM hook not enabled in the kernel, BPF LSM not supported. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: NET: Registered PF_VSOCK protocol family 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-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. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-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. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Queued start job for default target graphical.target. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Created slice system-autopkgtest.slice - Slice /system/autopkgtest. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Created slice system-modprobe.slice - Slice /system/modprobe. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Created slice system-serial\x2dgetty.slice - Slice /system/serial-getty. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Created slice user.slice - User and Session Slice. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Started systemd-ask-password-wall.path - Forward Password Requests to Wall Directory Watch. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Set up automount proc-sys-fs-binfmt_misc.automount - Arbitrary Executable File Formats File System Automount Point. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Expecting device dev-hvc0.device - /dev/hvc0... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Reached target integritysetup.target - Local Integrity Protected Volumes. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Reached target remote-fs.target - Remote File Systems. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Reached target slices.target - Slice Units. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Reached target swap.target - Swaps. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Reached target veritysetup.target - Local Verity Protected Volumes. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Listening on syslog.socket - Syslog Socket. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Listening on systemd-creds.socket - Credential Encryption/Decryption. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Listening on systemd-fsckd.socket - fsck to fsckd communication Socket. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Listening on systemd-initctl.socket - initctl Compatibility Named Pipe. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Listening on systemd-journald-dev-log.socket - Journal Socket (/dev/log). 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Listening on systemd-journald.socket - Journal Sockets. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Listening on systemd-networkd.socket - Network Service Netlink Socket. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Listening on systemd-udevd-control.socket - udev Control Socket. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Listening on systemd-udevd-kernel.socket - udev Kernel Socket. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Mounting dev-hugepages.mount - Huge Pages File System... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Mounting dev-mqueue.mount - POSIX Message Queue File System... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Mounting run-lock.mount - Legacy Locks Directory /run/lock... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Mounting sys-kernel-debug.mount - Kernel Debug File System... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Mounting sys-kernel-tracing.mount - Kernel Trace File System... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting systemd-journald.service - Journal Service... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting keyboard-setup.service - Set the console keyboard layout... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting kmod-static-nodes.service - Create List of Static Device Nodes... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting modprobe@configfs.service - Load Kernel Module configfs... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting modprobe@dm_multipath.service - Load Kernel Module dm_multipath... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting modprobe@drm.service - Load Kernel Module drm... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting modprobe@fuse.service - Load Kernel Module fuse... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-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). 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-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). 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-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). 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting systemd-modules-load.service - Load Kernel Modules... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting systemd-remount-fs.service - Remount Root and Kernel File Systems... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting systemd-udev-load-credentials.service - Load udev Rules from Credentials... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting systemd-udev-trigger.service - Coldplug All udev Devices... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Mounted dev-hugepages.mount - Huge Pages File System. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Mounted dev-mqueue.mount - POSIX Message Queue File System. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Mounted run-lock.mount - Legacy Locks Directory /run/lock. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Mounted sys-kernel-debug.mount - Kernel Debug File System. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Mounted sys-kernel-tracing.mount - Kernel Trace File System. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Finished kmod-static-nodes.service - Create List of Static Device Nodes. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: modprobe@configfs.service: Deactivated successfully. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Finished modprobe@configfs.service - Load Kernel Module configfs. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: modprobe@drm.service: Deactivated successfully. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Finished modprobe@drm.service - Load Kernel Module drm. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: modprobe@fuse.service: Deactivated successfully. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Finished modprobe@fuse.service - Load Kernel Module fuse. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Finished systemd-modules-load.service - Load Kernel Modules. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Mounting sys-fs-fuse-connections.mount - FUSE Control File System... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Mounting sys-kernel-config.mount - Kernel Configuration File System... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting systemd-sysctl.service - Apply Kernel Variables... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: modprobe@dm_multipath.service: Deactivated successfully. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Finished modprobe@dm_multipath.service - Load Kernel Module dm_multipath. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd-journald[285]: Collecting audit messages is disabled. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Finished systemd-udev-load-credentials.service - Load udev Rules from Credentials. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Mounted sys-fs-fuse-connections.mount - FUSE Control File System. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Mounted sys-kernel-config.mount - Kernel Configuration File System. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Finished systemd-sysctl.service - Apply Kernel Variables. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: EXT4-fs (vda1): re-mounted f3996c9c-8948-455c-b9ae-42041c08b247 r/w. Quota mode: none. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Finished systemd-remount-fs.service - Remount Root and Kernel File Systems. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting cloud-init-main.service - Cloud-init: Single Process... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: systemd-hwdb-update.service - Rebuild Hardware Database was skipped because of an unmet condition check (ConditionNeedsUpdate=/etc). 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore). 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd-journald[285]: Journal started 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd-journald[285]: Runtime Journal (/run/log/journal/32eb35eda0e245d9a62da135ae822cc4) is 8M, max 81M, 73M free. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting systemd-random-seed.service - Load/Save OS Random Seed... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Started systemd-journald.service - Journal Service. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Finished keyboard-setup.service - Set the console keyboard layout. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Finished systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting systemd-journal-flush.service - Flush Journal to Persistent Storage... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: systemd-sysusers.service - Create System Users was skipped because no trigger condition checks were met. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd-journald[285]: Time spent on flushing to /var/log/journal/32eb35eda0e245d9a62da135ae822cc4 is 17.731ms for 469 entries. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd-journald[285]: System Journal (/var/log/journal/32eb35eda0e245d9a62da135ae822cc4) is 18.8M, max 1.9G, 1.9G free. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd-journald[285]: Received client request to flush runtime journal. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Finished systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i multipathd[317]: multipathd v0.9.9: start up 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i multipathd[317]: reconfigure: setting up paths and maps 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting systemd-udevd.service - Rule-based Manager for Device Events and Files... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Reached target local-fs-pre.target - Preparation for Local File Systems. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Reached target local-fs.target - Local File Systems. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Listening on systemd-sysext.socket - System Extension Image Management. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting apparmor.service - Load AppArmor profiles... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting console-setup.service - Set console font and keymap... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: ldconfig.service - Rebuild Dynamic Linker Cache was skipped because no trigger condition checks were met. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting plymouth-read-write.service - Tell Plymouth To Write Out Runtime Data... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting systemd-binfmt.service - Set Up Additional Binary Formats... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting ufw.service - Uncomplicated firewall... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Finished systemd-udev-trigger.service - Coldplug All udev Devices. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Finished systemd-random-seed.service - Load/Save OS Random Seed. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Finished console-setup.service - Set console font and keymap. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Finished systemd-journal-flush.service - Flush Journal to Persistent Storage. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Finished ufw.service - Uncomplicated firewall. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting systemd-tmpfiles-setup.service - Create System Files and Directories... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i apparmor.systemd[354]: Restarting AppArmor 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: proc-sys-fs-binfmt_misc.automount: Got automount request for /proc/sys/fs/binfmt_misc, triggered by 359 (systemd-binfmt) 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Mounting proc-sys-fs-binfmt_misc.mount - Arbitrary Executable File Formats File System... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i apparmor.systemd[354]: Reloading AppArmor profiles 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd-tmpfiles[370]: /usr/lib/tmpfiles.d/legacy.conf:13: Duplicate line for path "/run/lock", ignoring. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Finished plymouth-read-write.service - Tell Plymouth To Write Out Runtime Data. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Mounted proc-sys-fs-binfmt_misc.mount - Arbitrary Executable File Formats File System. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Finished systemd-binfmt.service - Set Up Additional Binary Formats. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Finished systemd-tmpfiles-setup.service - Create System Files and Directories. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: audit: type=1400 audit(1727719847.420:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name=4D6F6E676F444220436F6D70617373 pid=384 comm="apparmor_parser" 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: audit: type=1400 audit(1727719847.420:3): apparmor="STATUS" operation="profile_load" profile="unconfined" name="Discord" pid=383 comm="apparmor_parser" 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: audit: type=1400 audit(1727719847.420:4): apparmor="STATUS" operation="profile_load" profile="unconfined" name="1password" pid=382 comm="apparmor_parser" 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: audit: type=1400 audit(1727719847.420:5): apparmor="STATUS" operation="profile_load" profile="unconfined" name="QtWebEngineProcess" pid=385 comm="apparmor_parser" 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: systemd-firstboot.service - First Boot Wizard was skipped because of an unmet condition check (ConditionFirstBoot=yes). 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: first-boot-complete.target - First Boot Complete was skipped because of an unmet condition check (ConditionFirstBoot=yes). 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: systemd-journal-catalog-update.service - Rebuild Journal Catalog was skipped because of an unmet condition check (ConditionNeedsUpdate=/var). 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-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). 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting systemd-resolved.service - Network Name Resolution... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: audit: type=1400 audit(1727719847.424:6): apparmor="STATUS" operation="profile_load" profile="unconfined" name="balena-etcher" pid=387 comm="apparmor_parser" 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: audit: type=1400 audit(1727719847.424:7): apparmor="STATUS" operation="profile_load" profile="unconfined" name="brave" pid=389 comm="apparmor_parser" 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: audit: type=1400 audit(1727719847.424:8): apparmor="STATUS" operation="profile_load" profile="unconfined" name="buildah" pid=390 comm="apparmor_parser" 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: audit: type=1400 audit(1727719847.424:9): apparmor="STATUS" operation="profile_load" profile="unconfined" name="busybox" pid=391 comm="apparmor_parser" 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: audit: type=1400 audit(1727719847.424:10): apparmor="STATUS" operation="profile_load" profile="unconfined" name="cam" pid=392 comm="apparmor_parser" 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting systemd-timesyncd.service - Network Time Synchronization... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: systemd-update-done.service - Update is Completed was skipped because no trigger condition checks were met. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting systemd-update-utmp.service - Record System Boot/Shutdown in UTMP... 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd-udevd[353]: Using default interface naming scheme 'v255'. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Finished systemd-update-utmp.service - Record System Boot/Shutdown in UTMP. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Started systemd-udevd.service - Rule-based Manager for Device Events and Files. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: plymouth-start.service - Show Plymouth Boot Screen was skipped because of an unmet condition check (ConditionKernelCommandLine=splash). 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Started systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-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). 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Reached target cryptsetup.target - Local Encrypted Volumes. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Started systemd-timesyncd.service - Network Time Synchronization. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Reached target time-set.target - System Time Set. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Found device dev-hvc0.device - /dev/hvc0. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd-resolved[395]: Positive Trust Anchors: 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd-resolved[395]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd-resolved[395]: 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 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Finished apparmor.service - Load AppArmor profiles. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd-resolved[395]: Using system hostname 'auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i'. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Started systemd-resolved.service - Network Name Resolution. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Reached target nss-lookup.target - Host and Network Name Lookups. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Listening on systemd-rfkill.socket - Load/Save RF Kill Switch Status /dev/rfkill Watch. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Started cloud-init-main.service - Cloud-init: Single Process. 188s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Starting cloud-init-local.service - Cloud-init: Local Stage (pre-network)... 188s Sep 30 18:10:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i cloud-init[690]: Cloud-init v. 24.4~3+really24.3.1-0ubuntu4 running 'init-local' at Mon, 30 Sep 2024 18:10:48 +0000. Up 2.79 seconds. 188s Sep 30 18:10:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i dhcpcd[693]: dhcpcd-10.0.8 starting 188s Sep 30 18:10:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i dhcpcd[696]: DUID 00:01:00:01:2e:8c:c3:9d:fa:16:3e:b4:aa:8a 188s Sep 30 18:10:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: 8021q: 802.1Q VLAN Support v1.8 188s Sep 30 18:10:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: 8021q: adding VLAN 0 to HW filter on device enp0s1 188s Sep 30 18:10:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i dhcpcd[696]: enp0s1: IAID 3e:13:77:04 188s Sep 30 18:10:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database 188s Sep 30 18:10:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' 188s Sep 30 18:10:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i kernel: Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600' 188s Sep 30 18:10:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i dhcpcd[696]: enp0s1: soliciting a DHCP lease 188s Sep 30 18:10:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i dhcpcd[696]: enp0s1: offered 10.145.227.179 from 10.145.227.1 188s Sep 30 18:10:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i dhcpcd[696]: enp0s1: leased 10.145.227.179 for 43200 seconds 188s Sep 30 18:10:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i dhcpcd[696]: enp0s1: adding route to 10.145.227.0/24 188s Sep 30 18:10:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i dhcpcd[696]: enp0s1: adding host route to 169.254.169.254 via 10.145.227.2 188s Sep 30 18:10:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i dhcpcd[696]: enp0s1: adding default route via 10.145.227.1 188s Sep 30 18:10:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i dhcpcd[696]: control command: /usr/sbin/dhcpcd --dumplease --ipv4only enp0s1 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd-resolved[395]: System hostname changed to 'adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227'. 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-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). 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-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). 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-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). 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd[1]: Reload requested from client PID 733 ('systemctl') (unit cloud-init-main.service)... 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd[1]: Reloading... 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-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. 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-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. 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd[1]: Reloading finished in 159 ms. 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 sh[686]: Completed socket interaction for boot stage local 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd[1]: Finished cloud-init-local.service - Cloud-init: Local Stage (pre-network). 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd[1]: Reached target network-pre.target - Preparation for Network. 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd[1]: Starting systemd-networkd.service - Network Configuration... 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd-networkd[768]: /run/systemd/network/10-netplan-enp0s1.network: MTUBytes= in [Link] section and UseMTU= in [DHCP] section are set. Disabling UseMTU=. 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd-networkd[768]: lo: Link UP 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd-networkd[768]: lo: Gained carrier 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd-networkd[768]: Enumeration completed 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd-networkd[768]: enp0s1: Link UP 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd-networkd[768]: enp0s1: Gained carrier 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd[1]: Started systemd-networkd.service - Network Configuration. 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd-timesyncd[399]: Network configuration changed, trying to establish connection. 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd-networkd[768]: enp0s1: Gained IPv6LL 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd[1]: Reached target network.target - Network. 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd-networkd[768]: enp0s1: Link DOWN 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd-networkd[768]: enp0s1: Lost carrier 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd-timesyncd[399]: Network configuration changed, trying to establish connection. 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd[1]: Starting systemd-networkd-persistent-storage.service - Enable Persistent Storage in systemd-networkd... 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd-networkd[768]: enp0s1: Configuring with /run/systemd/network/10-netplan-enp0s1.network. 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd[1]: Starting systemd-networkd-wait-online.service - Wait for Network to be Configured... 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd-networkd[768]: enp0s1: Link UP 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd-networkd[768]: enp0s1: Gained carrier 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 kernel: 8021q: adding VLAN 0 to HW filter on device enp0s1 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd-networkd[768]: enp0s1: DHCPv4 address 10.145.227.179/24, gateway 10.145.227.1 acquired from 10.145.227.1 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd-timesyncd[399]: Network configuration changed, trying to establish connection. 188s Sep 30 18:10:55 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd[1]: Finished systemd-networkd-persistent-storage.service - Enable Persistent Storage in systemd-networkd. 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd-networkd[768]: enp0s1: Gained IPv6LL 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd-timesyncd[399]: Network configuration changed, trying to establish connection. 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd[1]: Finished systemd-networkd-wait-online.service - Wait for Network to be Configured. 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd[1]: Starting cloud-init-network.service - Cloud-init: Network Stage... 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd-timesyncd[399]: Contacted time server 185.125.190.56:123 (ntp.ubuntu.com). 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 systemd-timesyncd[399]: Initial clock synchronization to Mon 2024-09-30 18:10:57.600245 UTC. 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: Cloud-init v. 24.4~3+really24.3.1-0ubuntu4 running 'init' at Mon, 30 Sep 2024 18:10:57 +0000. Up 12.40 seconds. 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: +++++++++++++++++++++++++++++++++++++++Net device info+++++++++++++++++++++++++++++++++++++++ 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: +--------+------+------------------------------+---------------+--------+-------------------+ 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: | Device | Up | Address | Mask | Scope | Hw-Address | 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: +--------+------+------------------------------+---------------+--------+-------------------+ 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: | enp0s1 | True | 10.145.227.179 | 255.255.255.0 | global | fa:16:3e:13:77:04 | 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: | enp0s1 | True | fe80::f816:3eff:fe13:7704/64 | . | link | fa:16:3e:13:77:04 | 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: | lo | True | 127.0.0.1 | 255.0.0.0 | host | . | 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: | lo | True | ::1/128 | . | host | . | 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: +--------+------+------------------------------+---------------+--------+-------------------+ 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: ++++++++++++++++++++++++++++++++Route IPv4 info+++++++++++++++++++++++++++++++++ 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: +-------+-----------------+--------------+-----------------+-----------+-------+ 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: | Route | Destination | Gateway | Genmask | Interface | Flags | 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: +-------+-----------------+--------------+-----------------+-----------+-------+ 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: | 0 | 0.0.0.0 | 10.145.227.1 | 0.0.0.0 | enp0s1 | UG | 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: | 1 | 10.145.227.0 | 0.0.0.0 | 255.255.255.0 | enp0s1 | U | 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: | 2 | 10.145.227.1 | 0.0.0.0 | 255.255.255.255 | enp0s1 | UH | 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: | 3 | 10.145.227.2 | 0.0.0.0 | 255.255.255.255 | enp0s1 | UH | 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: | 4 | 91.189.91.131 | 10.145.227.1 | 255.255.255.255 | enp0s1 | UGH | 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: | 5 | 91.189.91.132 | 10.145.227.1 | 255.255.255.255 | enp0s1 | UGH | 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: | 6 | 169.254.169.254 | 10.145.227.2 | 255.255.255.255 | enp0s1 | UGH | 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: +-------+-----------------+--------------+-----------------+-----------+-------+ 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: +++++++++++++++++++Route IPv6 info+++++++++++++++++++ 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: +-------+-------------+---------+-----------+-------+ 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: | Route | Destination | Gateway | Interface | Flags | 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: +-------+-------------+---------+-----------+-------+ 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: | 0 | fe80::/64 | :: | enp0s1 | U | 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: | 2 | local | :: | enp0s1 | U | 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: | 3 | multicast | :: | enp0s1 | U | 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: ci-info: +-------+-------------+---------+-----------+-------+ 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: 2024-09-30 18:10:57,748 - 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. 188s Sep 30 18:10:57 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 cloud-init[690]: 2024-09-30 18:10:57,748 - schema.py[WARNING]: cloud-config failed schema validation! You may run 'sudo cloud-init schema --system' to check the details. 188s Sep 30 18:10:58 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 kernel: EXT4-fs (vda1): resizing filesystem from 5240560 to 26212080 blocks 188s Sep 30 18:10:58 adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f227 kernel: EXT4-fs (vda1): resized filesystem to 26212080 188s Sep 30 18:10:58 autopkgtest systemd-resolved[395]: System hostname changed to 'autopkgtest'. 188s Sep 30 18:10:58 autopkgtest passwd[855]: password for 'ubuntu' changed by 'root' 188s Sep 30 18:10:58 autopkgtest sh[779]: Completed socket interaction for boot stage network 188s Sep 30 18:10:58 autopkgtest systemd[1]: Finished cloud-init-network.service - Cloud-init: Network Stage. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Reached target cloud-config.target - Cloud-config availability. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Reached target network-online.target - Network is Online. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Reached target sysinit.target - System Initialization. 188s Sep 30 18:10:58 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). 188s Sep 30 18:10:58 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). 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started apt-daily.timer - Daily apt download activities. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started apt-daily-upgrade.timer - Daily apt upgrade and clean activities. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started dpkg-db-backup.timer - Daily dpkg database backup timer. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started e2scrub_all.timer - Periodic ext4 Online Metadata Check for All Filesystems. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started fstrim.timer - Discard unused filesystem blocks once a week. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started fwupd-refresh.timer - Refresh fwupd metadata regularly. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started logrotate.timer - Daily rotation of log files. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started man-db.timer - Daily man-db regeneration. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started motd-news.timer - Message of the Day. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started sysstat-collect.timer - Run system activity accounting tool every 10 minutes. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started sysstat-rotate.timer - Rotate daily system activity data file at midnight. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started sysstat-summary.timer - Generate summary of yesterday's process accounting. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started systemd-tmpfiles-clean.timer - Daily Cleanup of Temporary Directories. 188s Sep 30 18:10:58 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). 188s Sep 30 18:10:58 autopkgtest systemd[1]: Reached target boot-complete.target - Boot Completion Check. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Reached target paths.target - Path Units. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Reached target timers.target - Timer Units. 188s Sep 30 18:10:58 autopkgtest systemd[1]: apport-forward.socket - Unix socket for apport crash forwarding was skipped because of an unmet condition check (ConditionVirtualization=container). 188s Sep 30 18:10:58 autopkgtest systemd[1]: Listening on cloud-init-hotplugd.socket - cloud-init hotplug hook socket. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Listening on dbus.socket - D-Bus System Message Bus Socket. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Starting lxd-installer.socket - Helper to install lxd snap on demand... 188s Sep 30 18:10:58 autopkgtest systemd[1]: Listening on ssh.socket - OpenBSD Secure Shell server socket. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Listening on sshd-unix-local.socket - OpenSSH Server Socket (systemd-ssh-generator, AF_UNIX Local). 188s Sep 30 18:10:58 autopkgtest systemd[1]: Listening on sshd-vsock.socket - OpenSSH Server Socket (systemd-ssh-generator, AF_VSOCK). 188s Sep 30 18:10:58 autopkgtest systemd[1]: Reached target ssh-access.target - SSH Access Available. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Listening on systemd-hostnamed.socket - Hostname Service Socket. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Listening on uuidd.socket - UUID daemon activation socket. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Listening on lxd-installer.socket - Helper to install lxd snap on demand. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Reached target sockets.target - Socket Units. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Reached target basic.target - Basic System. 188s Sep 30 18:10:58 autopkgtest systemd[1]: System is tainted: unmerged-bin 188s Sep 30 18:10:58 autopkgtest systemd[1]: Starting apport.service - automatic crash report generation... 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started autopkgtest@hvc1.service - autopkgtest root shell on hvc1. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started autopkgtest@ttyS1.service - autopkgtest root shell on ttyS1. 188s Sep 30 18:10:58 autopkgtest (sh)[867]: autopkgtest@hvc1.service: Failed to set up standard input: No such device 188s Sep 30 18:10:58 autopkgtest (sh)[867]: autopkgtest@hvc1.service: Failed at step STDIN spawning /bin/sh: No such device 188s Sep 30 18:10:58 autopkgtest (sh)[868]: autopkgtest@ttyS1.service: Failed to set up standard input: Input/output error 188s Sep 30 18:10:58 autopkgtest (sh)[868]: autopkgtest@ttyS1.service: Failed at step STDIN spawning /bin/sh: Input/output error 188s Sep 30 18:10:58 autopkgtest systemd[1]: Starting cloud-config.service - Cloud-init: Config Stage... 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started cron.service - Regular background program processing daemon. 188s Sep 30 18:10:58 autopkgtest (cron)[870]: cron.service: Referenced but unset environment variable evaluates to an empty string: EXTRA_OPTS 188s Sep 30 18:10:58 autopkgtest systemd[1]: Starting dbus.service - D-Bus System Message Bus... 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started dmesg.service - Save initial kernel messages after boot. 188s Sep 30 18:10:58 autopkgtest cron[870]: (CRON) INFO (pidfile fd = 3) 188s Sep 30 18:10:58 autopkgtest cron[870]: (CRON) INFO (Running @reboot jobs) 188s Sep 30 18:10:58 autopkgtest systemd[1]: Starting e2scrub_reap.service - Remove Stale Online ext4 Metadata Check Snapshots... 188s Sep 30 18:10:58 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). 188s Sep 30 18:10:58 autopkgtest systemd[1]: Starting grub-common.service - Record successful boot for GRUB... 188s Sep 30 18:10:58 autopkgtest systemd[1]: Starting iprdump.service - IBM Power Raid dump daemon... 188s Sep 30 18:10:58 autopkgtest systemd[1]: networkd-dispatcher.service - Dispatcher daemon for systemd-networkd was skipped because no trigger condition checks were met. 188s Sep 30 18:10:58 autopkgtest systemd[1]: opal_errd.service - opal_errd (PowerNV platform error handling) Service was skipped because of an unmet condition check (ConditionVirtualization=false). 188s Sep 30 18:10:58 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). 188s Sep 30 18:10:58 autopkgtest systemd[1]: Starting rc-local.service - /etc/rc.local Compatibility... 188s Sep 30 18:10:58 autopkgtest systemd[1]: Starting rng-tools-debian.service - LSB: rng-tools (Debian variant)... 188s Sep 30 18:10:58 autopkgtest systemd[1]: Starting rsyslog.service - System Logging Service... 188s Sep 30 18:10:58 autopkgtest dbus-daemon[874]: [system] AppArmor D-Bus mediation is enabled 188s Sep 30 18:10:58 autopkgtest systemd[1]: Starting rtas_errd.service - ppc64-diag rtas_errd (platform error handling) Service... 188s Sep 30 18:10:58 autopkgtest systemd[1]: Starting sysstat.service - Resets System Activity Logs... 188s Sep 30 18:10:58 autopkgtest systemd[1]: Starting systemd-logind.service - User Login Management... 188s Sep 30 18:10:58 autopkgtest systemd[1]: Starting systemd-user-sessions.service - Permit User Sessions... 188s Sep 30 18:10:58 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). 188s Sep 30 18:10:58 autopkgtest systemd[1]: ubuntu-advantage.service - Ubuntu Pro Background Auto Attach was skipped because no trigger condition checks were met. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Starting udisks2.service - Disk Manager... 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started dbus.service - D-Bus System Message Bus. 188s Sep 30 18:10:58 autopkgtest systemd[1]: autopkgtest@hvc1.service: Deactivated successfully. 188s Sep 30 18:10:58 autopkgtest systemd[1]: autopkgtest@ttyS1.service: Deactivated successfully. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started iprdump.service - IBM Power Raid dump daemon. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Finished systemd-user-sessions.service - Permit User Sessions. 188s Sep 30 18:10:58 autopkgtest udisksd[889]: udisks daemon version 2.10.1 starting 188s Sep 30 18:10:58 autopkgtest systemd[1]: Starting iprinit.service - IBM Power Raid init daemon... 188s Sep 30 18:10:58 autopkgtest systemd[1]: Starting iprupdate.service - IBM Power Raid update daemon... 188s Sep 30 18:10:58 autopkgtest systemd[1]: e2scrub_reap.service: Deactivated successfully. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Finished e2scrub_reap.service - Remove Stale Online ext4 Metadata Check Snapshots. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started rtas_errd.service - ppc64-diag rtas_errd (platform error handling) Service. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started iprinit.service - IBM Power Raid init daemon. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Finished sysstat.service - Resets System Activity Logs. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started iprupdate.service - IBM Power Raid update daemon. 188s Sep 30 18:10:58 autopkgtest systemd[1]: grub-common.service: Deactivated successfully. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Finished grub-common.service - Record successful boot for GRUB. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started rc-local.service - /etc/rc.local Compatibility. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Reached target iprutils.target - IBM Power Raid utilities. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Starting grub-initrd-fallback.service - GRUB failed boot detection... 188s Sep 30 18:10:58 autopkgtest systemd[1]: Starting plymouth-quit-wait.service - Hold until boot process finishes up... 188s Sep 30 18:10:58 autopkgtest systemd-logind[887]: New seat seat0. 188s Sep 30 18:10:58 autopkgtest rngd[945]: rngd 2.4 starting up... 188s Sep 30 18:10:58 autopkgtest systemd-logind[887]: Watching system buttons on /dev/input/event0 (QEMU QEMU USB Keyboard) 188s Sep 30 18:10:58 autopkgtest rngd[945]: entropy feed to the kernel ready 188s Sep 30 18:10:58 autopkgtest systemd[1]: Starting plymouth-quit.service - Terminate Plymouth Boot Screen... 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started systemd-logind.service - User Login Management. 188s Sep 30 18:10:58 autopkgtest systemd[1]: Started rng-tools-debian.service - LSB: rng-tools (Debian variant). 188s Sep 30 18:10:59 autopkgtest systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up. 188s Sep 30 18:10:59 autopkgtest cloud-init[690]: Cloud-init v. 24.4~3+really24.3.1-0ubuntu4 running 'modules:config' at Mon, 30 Sep 2024 18:10:58 +0000. Up 13.65 seconds. 188s Sep 30 18:10:59 autopkgtest systemd[1]: Started serial-getty@hvc0.service - Serial Getty on hvc0. 188s Sep 30 18:10:59 autopkgtest systemd[1]: Starting setvtrgb.service - Set console scheme... 188s Sep 30 18:10:59 autopkgtest systemd[1]: grub-initrd-fallback.service: Deactivated successfully. 188s Sep 30 18:10:59 autopkgtest systemd[1]: Finished grub-initrd-fallback.service - GRUB failed boot detection. 188s Sep 30 18:10:59 autopkgtest systemd[1]: Finished plymouth-quit.service - Terminate Plymouth Boot Screen. 188s Sep 30 18:10:59 autopkgtest systemd[1]: Finished setvtrgb.service - Set console scheme. 188s Sep 30 18:10:59 autopkgtest systemd[1]: Created slice system-getty.slice - Slice /system/getty. 188s Sep 30 18:10:59 autopkgtest systemd[1]: Started getty@tty1.service - Getty on tty1. 188s Sep 30 18:10:59 autopkgtest systemd[1]: Reached target getty.target - Login Prompts. 188s Sep 30 18:10:59 autopkgtest kernel: kauditd_printk_skb: 110 callbacks suppressed 188s Sep 30 18:10:59 autopkgtest kernel: audit: type=1400 audit(1727719859.025:121): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="rsyslogd" pid=938 comm="apparmor_parser" 188s Sep 30 18:10:59 autopkgtest systemd[1]: Started udisks2.service - Disk Manager. 188s Sep 30 18:10:59 autopkgtest udisksd[889]: Acquired the name org.freedesktop.UDisks2 on the system message bus 188s Sep 30 18:10:59 autopkgtest rsyslogd[974]: imuxsock: Acquired UNIX socket '/run/systemd/journal/syslog' (fd 3) from systemd. [v8.2406.0] 188s Sep 30 18:10:59 autopkgtest rsyslogd[974]: rsyslogd's groupid changed to 102 188s Sep 30 18:10:59 autopkgtest systemd[1]: Started rsyslog.service - System Logging Service. 188s Sep 30 18:10:59 autopkgtest rsyslogd[974]: rsyslogd's userid changed to 102 188s Sep 30 18:10:59 autopkgtest rsyslogd[974]: [origin software="rsyslogd" swVersion="8.2406.0" x-pid="974" x-info="https://www.rsyslog.com"] start 188s Sep 30 18:10:59 autopkgtest systemd[1]: Finished apport.service - automatic crash report generation. 188s Sep 30 18:10:59 autopkgtest systemd[1]: Reached target multi-user.target - Multi-User System. 188s Sep 30 18:10:59 autopkgtest systemd[1]: Reached target graphical.target - Graphical Interface. 188s Sep 30 18:10:59 autopkgtest systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... 188s Sep 30 18:10:59 autopkgtest systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. 188s Sep 30 18:10:59 autopkgtest systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. 188s Sep 30 18:10:59 autopkgtest cloud-init[690]: 2024-09-30 18:10:59,215 - 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. 188s Sep 30 18:10:59 autopkgtest cloud-init[690]: 2024-09-30 18:10:59,215 - 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. 188s Sep 30 18:10:59 autopkgtest sh[873]: Completed socket interaction for boot stage config 188s Sep 30 18:10:59 autopkgtest systemd[1]: Finished cloud-config.service - Cloud-init: Config Stage. 188s Sep 30 18:10:59 autopkgtest systemd[1]: Starting cloud-final.service - Cloud-init: Final Stage... 188s Sep 30 18:10:59 autopkgtest cloud-init[690]: Cloud-init v. 24.4~3+really24.3.1-0ubuntu4 running 'modules:final' at Mon, 30 Sep 2024 18:10:59 +0000. Up 14.04 seconds. 188s Sep 30 18:10:59 autopkgtest systemd[1]: Starting apt-news.service - Update APT News... 188s Sep 30 18:10:59 autopkgtest systemd[1]: Starting esm-cache.service - Update the local ESM caches... 188s Sep 30 18:10:59 autopkgtest systemd[1]: esm-cache.service: Deactivated successfully. 188s Sep 30 18:10:59 autopkgtest systemd[1]: Finished esm-cache.service - Update the local ESM caches. 188s Sep 30 18:10:59 autopkgtest systemd[1]: apt-news.service: Deactivated successfully. 188s Sep 30 18:10:59 autopkgtest systemd[1]: Finished apt-news.service - Update APT News. 188s Sep 30 18:10:59 autopkgtest cloud-init[690]: Get:1 http://ftpmaster.internal/ubuntu oracular InRelease [126 kB] 188s Sep 30 18:10:59 autopkgtest systemd[1]: Starting ssh.service - OpenBSD Secure Shell server... 188s Sep 30 18:10:59 autopkgtest sshd[1028]: Server listening on :: port 22. 188s Sep 30 18:10:59 autopkgtest systemd[1]: Started ssh.service - OpenBSD Secure Shell server. 188s Sep 30 18:10:59 autopkgtest cloud-init[690]: Hit:2 http://ftpmaster.internal/ubuntu oracular-updates InRelease 188s Sep 30 18:10:59 autopkgtest cloud-init[690]: Hit:3 http://ftpmaster.internal/ubuntu oracular-security InRelease 188s Sep 30 18:10:59 autopkgtest cloud-init[690]: Get:4 http://ftpmaster.internal/ubuntu oracular/main Sources [1371 kB] 188s Sep 30 18:11:00 autopkgtest cloud-init[690]: Get:5 http://ftpmaster.internal/ubuntu oracular/universe Sources [20.5 MB] 188s Sep 30 18:11:00 autopkgtest sshd[1030]: Accepted publickey for ubuntu from 10.136.6.184 port 40878 ssh2: RSA SHA256:h+sR5tlNZDfTFbz7cAH7wlRKfPAD8MpCdKJaoGeL2vg 188s Sep 30 18:11:00 autopkgtest sshd[1030]: pam_unix(sshd:session): session opened for user ubuntu(uid=1000) by ubuntu(uid=0) 188s Sep 30 18:11:00 autopkgtest sshd[1030]: pam_systemd(sshd:session): New sd-bus connection (system-bus-pam-systemd-1030) opened. 188s Sep 30 18:11:00 autopkgtest systemd[1]: Created slice user-1000.slice - User Slice of UID 1000. 188s Sep 30 18:11:00 autopkgtest systemd[1]: Starting user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... 188s Sep 30 18:11:00 autopkgtest systemd-logind[887]: New session 1 of user ubuntu. 188s Sep 30 18:11:00 autopkgtest systemd[1]: Finished user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. 188s Sep 30 18:11:00 autopkgtest systemd[1]: Starting user@1000.service - User Manager for UID 1000... 188s Sep 30 18:11:00 autopkgtest (systemd)[1137]: pam_unix(systemd-user:session): session opened for user ubuntu(uid=1000) by ubuntu(uid=0) 188s Sep 30 18:11:00 autopkgtest systemd-logind[887]: New session 2 of user ubuntu. 188s Sep 30 18:11:00 autopkgtest systemd[1137]: Queued start job for default target default.target. 188s Sep 30 18:11:00 autopkgtest systemd[1137]: Created slice app.slice - User Application Slice. 188s Sep 30 18:11:00 autopkgtest systemd[1137]: Started launchpadlib-cache-clean.timer - Clean up old files in the Launchpadlib cache. 188s Sep 30 18:11:00 autopkgtest systemd[1137]: Reached target paths.target - Paths. 188s Sep 30 18:11:00 autopkgtest systemd[1137]: Reached target timers.target - Timers. 188s Sep 30 18:11:00 autopkgtest systemd[1137]: Starting dbus.socket - D-Bus User Message Bus Socket... 188s Sep 30 18:11:00 autopkgtest systemd[1137]: Listening on dirmngr.socket - GnuPG network certificate management daemon. 188s Sep 30 18:11:00 autopkgtest systemd[1137]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). 188s Sep 30 18:11:00 autopkgtest systemd[1137]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). 188s Sep 30 18:11:00 autopkgtest systemd[1137]: Starting gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation)... 188s Sep 30 18:11:00 autopkgtest systemd[1137]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. 188s Sep 30 18:11:00 autopkgtest systemd[1137]: Listening on keyboxd.socket - GnuPG public key management service. 188s Sep 30 18:11:00 autopkgtest systemd[1137]: Listening on dbus.socket - D-Bus User Message Bus Socket. 188s Sep 30 18:11:00 autopkgtest systemd[1137]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). 188s Sep 30 18:11:00 autopkgtest systemd[1137]: Reached target sockets.target - Sockets. 188s Sep 30 18:11:00 autopkgtest systemd[1137]: Reached target basic.target - Basic System. 188s Sep 30 18:11:00 autopkgtest systemd[1137]: Reached target default.target - Main User Target. 188s Sep 30 18:11:00 autopkgtest systemd[1137]: Startup finished in 126ms. 188s Sep 30 18:11:00 autopkgtest systemd[1]: Started user@1000.service - User Manager for UID 1000. 188s Sep 30 18:11:00 autopkgtest systemd[1]: Started session-1.scope - Session 1 of User ubuntu. 188s Sep 30 18:11:00 autopkgtest sshd[1163]: Received disconnect from 10.136.6.184 port 40878:11: disconnected by user 188s Sep 30 18:11:00 autopkgtest sshd[1163]: Disconnected from user ubuntu 10.136.6.184 port 40878 188s Sep 30 18:11:00 autopkgtest sshd[1030]: pam_unix(sshd:session): session closed for user ubuntu 188s Sep 30 18:11:00 autopkgtest sshd[1030]: pam_systemd(sshd:session): New sd-bus connection (system-bus-pam-systemd-1030) opened. 188s Sep 30 18:11:00 autopkgtest systemd[1]: session-1.scope: Deactivated successfully. 188s Sep 30 18:11:00 autopkgtest systemd-logind[887]: Session 1 logged out. Waiting for processes to exit. 188s Sep 30 18:11:00 autopkgtest systemd-logind[887]: Removed session 1. 188s Sep 30 18:11:00 autopkgtest cloud-init[690]: Get:6 http://ftpmaster.internal/ubuntu oracular/main ppc64el Packages [1385 kB] 188s Sep 30 18:11:00 autopkgtest cloud-init[690]: Get:7 http://ftpmaster.internal/ubuntu oracular/universe ppc64el Packages [15.0 MB] 188s Sep 30 18:11:01 autopkgtest cloud-init[690]: Get:8 http://ftpmaster.internal/ubuntu oracular/universe ppc64el c-n-f Metadata [297 kB] 188s Sep 30 18:11:01 autopkgtest sshd[1166]: Accepted publickey for ubuntu from 10.136.6.184 port 40882 ssh2: RSA SHA256:h+sR5tlNZDfTFbz7cAH7wlRKfPAD8MpCdKJaoGeL2vg 188s Sep 30 18:11:01 autopkgtest sshd[1166]: pam_unix(sshd:session): session opened for user ubuntu(uid=1000) by ubuntu(uid=0) 188s Sep 30 18:11:01 autopkgtest sshd[1166]: pam_systemd(sshd:session): New sd-bus connection (system-bus-pam-systemd-1166) opened. 188s Sep 30 18:11:01 autopkgtest systemd-logind[887]: New session 3 of user ubuntu. 188s Sep 30 18:11:01 autopkgtest systemd[1]: Started session-3.scope - Session 3 of User ubuntu. 188s Sep 30 18:11:03 autopkgtest kernel: fbcon: Taking over console 188s Sep 30 18:11:03 autopkgtest kernel: Console: switching to colour frame buffer device 128x48 188s Sep 30 18:11:03 autopkgtest systemd[1]: dmesg.service: Deactivated successfully. 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: Fetched 38.7 MB in 6s (6165 kB/s) 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: Reading package lists... 188s Sep 30 18:11:07 autopkgtest cloud-init[1258]: ############################################################# 188s Sep 30 18:11:07 autopkgtest cloud-init[1259]: -----BEGIN SSH HOST KEY FINGERPRINTS----- 188s Sep 30 18:11:07 autopkgtest cloud-init[1261]: 256 SHA256:78oYZtXNDQ/lGx62Pewkfy03rDg2jkKVpRP4gI5lLCE root@autopkgtest (ECDSA) 188s Sep 30 18:11:07 autopkgtest cloud-init[1263]: 256 SHA256:bzyClvKRtu7owJDDt5dOQp8dHFvnRFio06D+33E5k4E root@autopkgtest (ED25519) 188s Sep 30 18:11:07 autopkgtest cloud-init[1265]: 3072 SHA256:dPbeGBavc/WZflffuo4I1x7KqoLeuqIOGadlCBqWvms root@autopkgtest (RSA) 188s Sep 30 18:11:07 autopkgtest cloud-init[1266]: -----END SSH HOST KEY FINGERPRINTS----- 188s Sep 30 18:11:07 autopkgtest cloud-init[1267]: ############################################################# 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: Cloud-init v. 24.4~3+really24.3.1-0ubuntu4 finished at Mon, 30 Sep 2024 18:11:07 +0000. Datasource DataSourceOpenStackLocal [net,ver=2]. Up 22.72 seconds 188s Sep 30 18:11:07 autopkgtest sh[1007]: Completed socket interaction for boot stage final 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: Generating public/private rsa key pair. 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: Your identification has been saved in /etc/ssh/ssh_host_rsa_key 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: Your public key has been saved in /etc/ssh/ssh_host_rsa_key.pub 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: The key fingerprint is: 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: SHA256:dPbeGBavc/WZflffuo4I1x7KqoLeuqIOGadlCBqWvms root@autopkgtest 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: The key's randomart image is: 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: +---[RSA 3072]----+ 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: | | 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: | . | 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: |oo . o . | 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: |=o . o . o | 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: |+.+ S + . .| 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: | B. + = .=| 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: |+. . . . B oo=| 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: |oEo.. + + =. =| 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: |==+o......+ o.++o| 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: +----[SHA256]-----+ 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: Generating public/private ecdsa key pair. 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: Your identification has been saved in /etc/ssh/ssh_host_ecdsa_key 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: Your public key has been saved in /etc/ssh/ssh_host_ecdsa_key.pub 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: The key fingerprint is: 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: SHA256:78oYZtXNDQ/lGx62Pewkfy03rDg2jkKVpRP4gI5lLCE root@autopkgtest 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: The key's randomart image is: 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: +---[ECDSA 256]---+ 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: | E .o . . . | 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: | .. = o . . o | 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: | * o = o = | 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: | . . B o B.* | 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: | S o o.*+.| 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: | o . * o| 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: | = . .=+| 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: | o = ..+. .oo| 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: | . +o+oo. | 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: +----[SHA256]-----+ 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: Generating public/private ed25519 key pair. 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: Your identification has been saved in /etc/ssh/ssh_host_ed25519_key 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: Your public key has been saved in /etc/ssh/ssh_host_ed25519_key.pub 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: The key fingerprint is: 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: SHA256:bzyClvKRtu7owJDDt5dOQp8dHFvnRFio06D+33E5k4E root@autopkgtest 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: The key's randomart image is: 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: +--[ED25519 256]--+ 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: | +o | 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: | . o. | 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: | ..+. o | 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: |.. ..o+.+ . | 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: |+. o. +S E . | 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: | +o o.++.o + | 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: | oo.*O.. =. * | 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: | .=* + o..o o | 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: | .o+= .. . | 188s Sep 30 18:11:07 autopkgtest cloud-init[690]: +----[SHA256]-----+ 188s Sep 30 18:11:07 autopkgtest systemd[1]: Finished cloud-final.service - Cloud-init: Final Stage. 188s Sep 30 18:11:07 autopkgtest systemd[1]: Reached target cloud-init.target - Cloud-init target. 188s Sep 30 18:11:07 autopkgtest systemd[1]: Startup finished in 1.616s (kernel) + 21.118s (userspace) = 22.735s. 188s Sep 30 18:11:08 autopkgtest systemd[1]: cloud-init-main.service: Deactivated successfully. 188s Sep 30 18:11:08 autopkgtest systemd[1]: cloud-init-main.service: Consumed 9.758s CPU time, 453.7M memory peak. 188s Sep 30 18:11:08 autopkgtest sshd[1182]: Received disconnect from 10.136.6.184 port 40882:11: disconnected by user 188s Sep 30 18:11:08 autopkgtest sshd[1182]: Disconnected from user ubuntu 10.136.6.184 port 40882 188s Sep 30 18:11:08 autopkgtest sshd[1166]: pam_unix(sshd:session): session closed for user ubuntu 188s Sep 30 18:11:08 autopkgtest sshd[1166]: pam_systemd(sshd:session): New sd-bus connection (system-bus-pam-systemd-1166) opened. 188s Sep 30 18:11:08 autopkgtest systemd[1]: session-3.scope: Deactivated successfully. 188s Sep 30 18:11:08 autopkgtest systemd-logind[887]: Session 3 logged out. Waiting for processes to exit. 188s Sep 30 18:11:08 autopkgtest systemd-logind[887]: Removed session 3. 188s Sep 30 18:11:09 autopkgtest sshd[1274]: Accepted publickey for ubuntu from 10.136.6.184 port 36140 ssh2: RSA SHA256:h+sR5tlNZDfTFbz7cAH7wlRKfPAD8MpCdKJaoGeL2vg 188s Sep 30 18:11:09 autopkgtest sshd[1274]: pam_unix(sshd:session): session opened for user ubuntu(uid=1000) by ubuntu(uid=0) 188s Sep 30 18:11:09 autopkgtest sshd[1274]: pam_systemd(sshd:session): New sd-bus connection (system-bus-pam-systemd-1274) opened. 188s Sep 30 18:11:09 autopkgtest systemd-logind[887]: New session 4 of user ubuntu. 188s Sep 30 18:11:09 autopkgtest systemd[1]: Started session-4.scope - Session 4 of User ubuntu. 188s Sep 30 18:11:09 autopkgtest sudo[1292]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/bin/true 188s Sep 30 18:11:09 autopkgtest sudo[1292]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:09 autopkgtest sudo[1292]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:09 autopkgtest sudo[1297]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper /bin/mkdir --mode=1777 --parents /tmp/autopkgtest.WisOmh 188s Sep 30 18:11:09 autopkgtest sudo[1297]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:10 autopkgtest sudo[1297]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:10 autopkgtest sudo[1307]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper mkdir -p /tmp/autopkgtest.WisOmh 188s Sep 30 18:11:10 autopkgtest sudo[1307]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:10 autopkgtest sudo[1307]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:10 autopkgtest sudo[1317]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat >/tmp/autopkgtest.WisOmh/wrapper.sh; chmod +x -- /tmp/autopkgtest.WisOmh/wrapper.sh' 188s Sep 30 18:11:10 autopkgtest sudo[1317]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:10 autopkgtest sudo[1317]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:10 autopkgtest sudo[1329]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chmod -R 0755 -- /tmp/autopkgtest.WisOmh/wrapper.sh 188s Sep 30 18:11:10 autopkgtest sudo[1329]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:10 autopkgtest sudo[1329]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:10 autopkgtest sudo[1339]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper dpkg --print-architecture 188s Sep 30 18:11:10 autopkgtest sudo[1339]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:10 autopkgtest sudo[1339]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:11 autopkgtest sudo[1349]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper dpkg-query -W -f ${Version} apt 188s Sep 30 18:11:11 autopkgtest sudo[1349]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:11 autopkgtest sudo[1349]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:11 autopkgtest sudo[1359]: 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 188s Sep 30 18:11:11 autopkgtest sudo[1359]: 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 188s Sep 30 18:11:11 autopkgtest sudo[1359]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:11 autopkgtest sudo[1359]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:11 autopkgtest sudo[1371]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'ls -1 /etc/apt/sources.list.d/*.sources' 188s Sep 30 18:11:11 autopkgtest sudo[1371]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:11 autopkgtest sudo[1371]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:11 autopkgtest sudo[1382]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper cat /etc/apt/sources.list.d/ubuntu.sources 188s Sep 30 18:11:11 autopkgtest sudo[1382]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:11 autopkgtest sudo[1382]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:11 autopkgtest sudo[1392]: 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 188s Sep 30 18:11:11 autopkgtest sudo[1392]: 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 188s Sep 30 18:11:11 autopkgtest sudo[1392]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:11 autopkgtest systemd[1]: Starting apt-news.service - Update APT News... 188s Sep 30 18:11:11 autopkgtest systemd[1]: Starting esm-cache.service - Update the local ESM caches... 188s Sep 30 18:11:11 autopkgtest systemd[1]: esm-cache.service: Deactivated successfully. 188s Sep 30 18:11:11 autopkgtest systemd[1]: Finished esm-cache.service - Update the local ESM caches. 188s Sep 30 18:11:11 autopkgtest systemd[1]: apt-news.service: Deactivated successfully. 188s Sep 30 18:11:11 autopkgtest systemd[1]: Finished apt-news.service - Update APT News. 188s Sep 30 18:11:14 autopkgtest sudo[1392]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:14 autopkgtest sudo[1479]: 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;' 188s Sep 30 18:11:14 autopkgtest sudo[1479]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:14 autopkgtest sudo[1479]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:14 autopkgtest sudo[1490]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper mkdir -p /etc/apt/preferences.d 188s Sep 30 18:11:14 autopkgtest sudo[1490]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:14 autopkgtest sudo[1490]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:14 autopkgtest sudo[1500]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat >/etc/apt/preferences.d/autopkgtest-oracular-proposed' 188s Sep 30 18:11:14 autopkgtest sudo[1500]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:14 autopkgtest sudo[1500]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:14 autopkgtest sudo[1511]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chmod -R 0644 -- /etc/apt/preferences.d/autopkgtest-oracular-proposed 188s Sep 30 18:11:14 autopkgtest sudo[1511]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:14 autopkgtest sudo[1511]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:15 autopkgtest sudo[1521]: 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' 188s Sep 30 18:11:15 autopkgtest sudo[1521]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:15 autopkgtest sudo[1521]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:15 autopkgtest sudo[1532]: 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.WisOmh/${d//\\//_}.stamp; done' 188s Sep 30 18:11:15 autopkgtest sudo[1532]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:15 autopkgtest sudo[1532]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:15 autopkgtest sudo[1546]: 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 188s Sep 30 18:11:15 autopkgtest sudo[1546]: 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 188s Sep 30 18:11:15 autopkgtest sudo[1546]: 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#012if type iptables >/dev/null 2>&1; then#012 cat < /etc/rc.local#012#!/bin/sh#012#012# work around broken PTMU; LP: #1572026, RT#90771#012iptables -w -t mangle -A FORWARD -p tcp --tcp-flags SYN,RST SYN -j TCPMSS --clamp-mss-to-pmtu || true#012#012# These addresses are used at least by rust-reqwest and should not be reachable#012# See https://bugs.launchpad.net/ubuntu/+source/rust-reqwest/+bug/2080346#012iptables -A OUTPUT -d 10.255.255.1/32 -p tcp -j DROP#012iptables -A OUTPUT -d 10.255.255.2/32 -p tcp -j DROP#012EOF#012 chmod 755 /etc/rc.local#012 # shellcheck 188s Sep 30 18:11:15 autopkgtest sudo[1546]: ubuntu : (command continued) 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 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 188s Sep 30 18:11:15 autopkgtest sudo[1546]: ubuntu : (command continued) 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' 188s Sep 30 18:11:15 autopkgtest sudo[1546]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:18 autopkgtest sudo[1546]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:18 autopkgtest sudo[1628]: 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' 188s Sep 30 18:11:18 autopkgtest sudo[1628]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:18 autopkgtest systemd[1]: Starting apt-news.service - Update APT News... 188s Sep 30 18:11:18 autopkgtest systemd[1]: Starting esm-cache.service - Update the local ESM caches... 188s Sep 30 18:11:18 autopkgtest systemd[1]: esm-cache.service: Deactivated successfully. 188s Sep 30 18:11:18 autopkgtest systemd[1]: Finished esm-cache.service - Update the local ESM caches. 188s Sep 30 18:11:18 autopkgtest systemd[1]: apt-news.service: Deactivated successfully. 188s Sep 30 18:11:18 autopkgtest systemd[1]: Finished apt-news.service - Update APT News. 188s Sep 30 18:11:20 autopkgtest sudo[1628]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:20 autopkgtest sudo[1813]: 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.WisOmh/${d//\\//_}.stamp; [ ! -d $d ] || [ `stat -c %Y $d` = `stat -c %Y $s` ]; done' 188s Sep 30 18:11:20 autopkgtest sudo[1813]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:20 autopkgtest sudo[1813]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:20 autopkgtest sudo[1831]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'command -v eatmydata' 188s Sep 30 18:11:20 autopkgtest sudo[1831]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:20 autopkgtest sudo[1831]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:20 autopkgtest sudo[1841]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'dpkg-query --show -f \'${Package}\\t${Version}\\n\' > /tmp/autopkgtest.WisOmh/testbed-packages' 188s Sep 30 18:11:20 autopkgtest sudo[1841]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:20 autopkgtest sudo[1841]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:20 autopkgtest sudo[1852]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat /tmp/autopkgtest.WisOmh/autopkgtest-reboot; chmod +x -- /tmp/autopkgtest.WisOmh/autopkgtest-reboot' 188s Sep 30 18:11:21 autopkgtest sudo[1873]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:21 autopkgtest sudo[1873]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:21 autopkgtest sudo[1885]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chmod -R 0755 -- /tmp/autopkgtest.WisOmh/autopkgtest-reboot 188s Sep 30 18:11:21 autopkgtest sudo[1885]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:21 autopkgtest sudo[1885]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:21 autopkgtest sudo[1895]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper ln -fns /tmp/autopkgtest.WisOmh/autopkgtest-reboot /tmp/autopkgtest-reboot 188s Sep 30 18:11:21 autopkgtest sudo[1895]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:21 autopkgtest sudo[1895]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:21 autopkgtest sudo[1905]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper ln -fns /tmp/autopkgtest.WisOmh/autopkgtest-reboot /sbin/autopkgtest-reboot 188s Sep 30 18:11:21 autopkgtest sudo[1905]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:21 autopkgtest sudo[1905]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:22 autopkgtest sudo[1915]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper mkdir -p /tmp/autopkgtest.WisOmh 188s Sep 30 18:11:22 autopkgtest sudo[1915]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:22 autopkgtest sudo[1915]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:22 autopkgtest sudo[1925]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat >/tmp/autopkgtest.WisOmh/autopkgtest-reboot-prepare; chmod +x -- /tmp/autopkgtest.WisOmh/autopkgtest-reboot-prepare' 188s Sep 30 18:11:22 autopkgtest sudo[1925]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:22 autopkgtest sudo[1925]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:22 autopkgtest sudo[1937]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chmod -R 0755 -- /tmp/autopkgtest.WisOmh/autopkgtest-reboot-prepare 188s Sep 30 18:11:22 autopkgtest sudo[1937]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:22 autopkgtest sudo[1937]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:22 autopkgtest sudo[1947]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper ln -fns /tmp/autopkgtest.WisOmh/autopkgtest-reboot-prepare /tmp/autopkgtest-reboot-prepare 188s Sep 30 18:11:22 autopkgtest sudo[1947]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:22 autopkgtest sudo[1947]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:22 autopkgtest sudo[1957]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper uname -srv 188s Sep 30 18:11:22 autopkgtest sudo[1957]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:22 autopkgtest sudo[1957]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:23 autopkgtest sudo[1967]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper test -w /var/lib/dpkg/status 188s Sep 30 18:11:23 autopkgtest sudo[1967]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:23 autopkgtest sudo[1967]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:23 autopkgtest sudo[1976]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper mkdir -p /tmp/autopkgtest.WisOmh 188s Sep 30 18:11:23 autopkgtest sudo[1976]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:23 autopkgtest sudo[1976]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:23 autopkgtest sudo[1986]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat >/tmp/autopkgtest.WisOmh/2-autopkgtest-satdep.deb' 188s Sep 30 18:11:23 autopkgtest sudo[1986]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:23 autopkgtest sudo[1986]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:23 autopkgtest sudo[1997]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chown -R ubuntu -- /tmp/autopkgtest.WisOmh/2-autopkgtest-satdep.deb 188s Sep 30 18:11:23 autopkgtest sudo[1997]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:23 autopkgtest sudo[1997]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:24 autopkgtest sudo[2007]: 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.WisOmh/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' 188s Sep 30 18:11:24 autopkgtest sudo[2007]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:26 autopkgtest systemd[1]: Reload requested from client PID 2247 ('systemctl') (unit session-4.scope)... 188s Sep 30 18:11:26 autopkgtest systemd[1]: Reloading... 188s Sep 30 18:11: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. 188s Sep 30 18:11: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. 188s Sep 30 18:11:27 autopkgtest systemd[1]: Reloading finished in 205 ms. 188s Sep 30 18:11:27 autopkgtest systemd[1]: Starting fwupd-refresh.service - Refresh fwupd metadata and update motd... 188s Sep 30 18:11:27 autopkgtest dbus-daemon[874]: [system] Activating via systemd: service name='org.freedesktop.fwupd' unit='fwupd.service' requested by ':1.16' (uid=990 pid=2289 comm="/usr/bin/fwupdmgr refresh" label="unconfined") 188s Sep 30 18:11:27 autopkgtest systemd[1]: Starting fwupd.service - Firmware update daemon... 188s Sep 30 18:11:27 autopkgtest systemd[1]: Reload requested from client PID 2303 ('systemctl') (unit session-4.scope)... 188s Sep 30 18:11:27 autopkgtest systemd[1]: Reloading... 188s Sep 30 18:11: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. 188s Sep 30 18:11: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. 188s Sep 30 18:11:27 autopkgtest systemd[1]: Reloading finished in 191 ms. 188s Sep 30 18:11:27 autopkgtest systemd[1]: Starting tgt.service - (i)SCSI target daemon... 188s Sep 30 18:11:27 autopkgtest tgtd[2350]: tgtd: iser_ib_init(3431) Failed to initialize RDMA; load kernel modules? 188s Sep 30 18:11:27 autopkgtest tgtd[2350]: tgtd: work_timer_start(146) use timer_fd based scheduler 188s Sep 30 18:11:27 autopkgtest tgtd[2350]: tgtd: bs_init(387) use signalfd notification 188s Sep 30 18:11:27 autopkgtest systemd[1]: Started tgt.service - (i)SCSI target daemon. 188s Sep 30 18:11:27 autopkgtest systemd[1]: Reload requested from client PID 2377 ('systemctl') (unit session-4.scope)... 188s Sep 30 18:11:27 autopkgtest systemd[1]: Reloading... 188s Sep 30 18:11: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. 188s Sep 30 18:11: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. 188s Sep 30 18:11:28 autopkgtest systemd[1]: Reloading finished in 227 ms. 188s Sep 30 18:11:28 autopkgtest systemd[1]: Reload requested from client PID 2426 ('systemctl') (unit session-4.scope)... 188s Sep 30 18:11:28 autopkgtest systemd[1]: Reloading... 188s Sep 30 18:11:28 autopkgtest fwupd[2299]: 18:11:28.123 FuMain Daemon ready for requests (locale C.UTF-8) 188s Sep 30 18:11:28 autopkgtest dbus-daemon[874]: [system] Successfully activated service 'org.freedesktop.fwupd' 188s Sep 30 18:11:28 autopkgtest fwupdmgr[2289]: Updating lvfs 188s Sep 30 18:11: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. 188s Sep 30 18:11: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. 188s Sep 30 18:11:28 autopkgtest systemd[1]: Reloading finished in 213 ms. 188s Sep 30 18:11:28 autopkgtest systemd[1]: fwupd-refresh.service: Main process exited, code=exited, status=1/FAILURE 188s Sep 30 18:11:28 autopkgtest systemd[1]: fwupd-refresh.service: Failed with result 'exit-code'. 188s Sep 30 18:11:28 autopkgtest systemd[1]: Failed to start fwupd-refresh.service - Refresh fwupd metadata and update motd. 188s Sep 30 18:11:28 autopkgtest systemd[1]: Started fwupd.service - Firmware update daemon. 188s Sep 30 18:11:28 autopkgtest systemd[1]: Reload requested from client PID 2476 ('systemctl') (unit session-4.scope)... 188s Sep 30 18:11:28 autopkgtest systemd[1]: Reloading... 188s Sep 30 18:11: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. 188s Sep 30 18:11: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. 188s Sep 30 18:11:28 autopkgtest systemd[1]: Reloading finished in 249 ms. 188s Sep 30 18:11:28 autopkgtest systemd[1]: Listening on iscsid.socket - Open-iSCSI iscsid Socket. 188s Sep 30 18:11:28 autopkgtest systemd[1]: Reload requested from client PID 2527 ('systemctl') (unit session-4.scope)... 188s Sep 30 18:11:28 autopkgtest systemd[1]: Reloading... 188s Sep 30 18:11: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. 188s Sep 30 18:11: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. 188s Sep 30 18:11:29 autopkgtest systemd[1]: Reloading finished in 188 ms. 188s Sep 30 18:11:29 autopkgtest systemd[1]: open-iscsi.service - Login to default iSCSI targets was skipped because no trigger condition checks were met. 188s Sep 30 18:11:29 autopkgtest systemd[1]: Reached target remote-fs-pre.target - Preparation for Remote File Systems. 188s Sep 30 18:11:29 autopkgtest systemd[1]: Reload requested from client PID 2582 ('systemctl') (unit session-4.scope)... 188s Sep 30 18:11:29 autopkgtest systemd[1]: Reloading... 188s Sep 30 18:11: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. 188s Sep 30 18:11: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. 188s Sep 30 18:11:29 autopkgtest systemd[1]: Reloading finished in 203 ms. 188s Sep 30 18:11:38 autopkgtest sudo[2007]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:38 autopkgtest sudo[6454]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper dpkg-query --show -f ${Status} multipath-tools 188s Sep 30 18:11:38 autopkgtest sudo[6454]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:38 autopkgtest sudo[6454]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:38 autopkgtest sudo[6464]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper dpkg --status autopkgtest-satdep 188s Sep 30 18:11:38 autopkgtest sudo[6464]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:38 autopkgtest sudo[6464]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:38 autopkgtest sudo[6474]: 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 188s Sep 30 18:11:38 autopkgtest sudo[6474]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:39 autopkgtest sudo[6474]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:39 autopkgtest sudo[6487]: 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 188s Sep 30 18:11:39 autopkgtest sudo[6487]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:39 autopkgtest sudo[6487]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:40 autopkgtest sudo[6499]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper apt-mark manual -qq lsscsi 188s Sep 30 18:11:40 autopkgtest sudo[6499]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:40 autopkgtest sudo[6499]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:40 autopkgtest sudo[6511]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper dpkg --purge autopkgtest-satdep 188s Sep 30 18:11:40 autopkgtest sudo[6511]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:40 autopkgtest sudo[6511]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:40 autopkgtest sudo[6521]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'dpkg-query --show -f \'${Package}\\t${Version}\\n\' > /tmp/autopkgtest.WisOmh/tgtbasedmpaths-packages.all' 188s Sep 30 18:11:40 autopkgtest sudo[6521]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 188s Sep 30 18:11:40 autopkgtest sudo[6521]: pam_unix(sudo:session): session closed for user root 188s Sep 30 18:11:40 autopkgtest sudo[6532]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat =64=0.0% 191s submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 191s complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 191s issued rwts: total=0,1401,0,0 short=0,0,0,0 dropped=0,0,0,0 191s latency : target=0, window=0, percentile=100.00%, depth=1 191s 191s Run status group 0 (all jobs): 191s WRITE: bw=179MiB/s (188MB/s), 179MiB/s-179MiB/s (188MB/s-188MB/s), io=87.5MiB (91.8MB), run=489-489msec 191s 191s Disk stats (read/write): 191s dm-0: ios=1/1089, sectors=8/139392, merge=0/0, ticks=1/362, in_queue=363, util=68.57%, aggrios=0/350, aggsectors=2/44820, aggrmerge=0/0, aggrticks=0/110, aggrin_queue=110, aggrutil=67.75% 191s sdd: ios=0/0, sectors=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 191s sdb: ios=0/0, sectors=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 191s sdc: ios=0/0, sectors=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 191s sda: ios=1/1402, sectors=8/179280, merge=0/0, ticks=1/440, in_queue=441, util=67.75% 191s + echo Starting the path changes in background 191s + date +Pre FIO %H:%M:%S.%N 191s Starting the path changes in background 191s + fio --max-jobs=4 /tmp/autopkgtest.WisOmh/tgtbasedmpaths-artifacts/path-change-check.fio 191s Pre FIO 18:11:51.896530764 192s 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 192s fio-3.37 192s Starting 1 thread 372s 372s verify-phase: (groupid=0, jobs=1): err= 0: pid=6874: Mon Sep 30 18:14:52 2024 372s read: IOPS=5303, BW=331MiB/s (348MB/s)(58.3GiB/180001msec) 372s clat (usec): min=70, max=43489, avg=166.12, stdev=173.23 372s lat (usec): min=70, max=43489, avg=166.22, stdev=173.24 372s clat percentiles (usec): 372s | 1.00th=[ 88], 5.00th=[ 98], 10.00th=[ 106], 20.00th=[ 116], 372s | 30.00th=[ 123], 40.00th=[ 131], 50.00th=[ 141], 60.00th=[ 151], 372s | 70.00th=[ 161], 80.00th=[ 172], 90.00th=[ 192], 95.00th=[ 221], 372s | 99.00th=[ 840], 99.50th=[ 955], 99.90th=[ 1614], 99.95th=[ 1975], 372s | 99.99th=[ 2802] 372s bw ( KiB/s): min=113437, max=490752, per=100.00%, avg=339837.87, stdev=63816.32, samples=359 372s iops : min= 1772, max= 7668, avg=5309.96, stdev=997.15, samples=359 372s lat (usec) : 100=5.86%, 250=90.17%, 500=0.84%, 750=1.06%, 1000=1.63% 372s lat (msec) : 2=0.39%, 4=0.05%, 10=0.01%, 20=0.01%, 50=0.01% 372s cpu : usr=12.61%, sys=5.99%, ctx=954833, majf=0, minf=1 372s IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0% 372s submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 372s complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 372s issued rwts: total=954718,0,0,0 short=0,0,0,0 dropped=0,0,0,0 372s latency : target=0, window=0, percentile=100.00%, depth=1 372s 372s Run status group 0 (all jobs): 372s READ: bw=331MiB/s (348MB/s), 331MiB/s-331MiB/s (348MB/s-348MB/s), io=58.3GiB (62.6GB), run=180001-180001msec 372s 372s Disk stats (read/write): 372s dm-0: ios=955030/10, sectors=122152248/12928, merge=0/9, ticks=156646/60, in_queue=156734, util=81.52%, aggrios=72111/2, aggsectors=9222510/3232, aggrmerge=0/0, aggrticks=10112/8, aggrin_queue=10120, aggrutil=70.87% 372s sdd: ios=115677/0, sectors=14796160/0, merge=0/0, ticks=16272/0, in_queue=16272, util=29.51% 372s sdb: ios=49505/0, sectors=6327608/0, merge=0/0, ticks=8398/0, in_queue=8398, util=37.74% 372s sdc: ios=60353/0, sectors=7719680/0, merge=0/0, ticks=8015/0, in_queue=8015, util=22.86% 372s sda: ios=62910/9, sectors=8046592/12928, merge=0/0, ticks=7765/32, in_queue=7797, util=70.87% 372s + date +Post FIO %H:%M:%S.%N 372s Post FIO 18:14:52.235515249 372s FIO verify test with changing paths - OK 372s Report log of background activity 372s + echo FIO verify test with changing paths - OK 372s + echo Report log of background activity 372s + cat /tmp/autopkgtest.WisOmh/tgtbasedmpaths-artifacts/test-background.log 372s + iscsiadm --mode session 372s tcp: [1] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 372s tcp: [2] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 372s tcp: [3] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 372s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 372s + sleep 10s 372s + date +MP report (expect 4) %H:%M:%S.%N 372s MP report (expect 4) 18:12:01.906227602 372s + multipath -ll 372s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 372s size=100M features='0' hwhandler='0' wp=rw 372s |-+- policy='service-time 0' prio=1 status=active 372s | `- 0:0:0:1 sda 8:0 active ready running 372s |-+- policy='service-time 0' prio=1 status=enabled 372s | `- 1:0:0:1 sdb 8:16 active ready running 372s |-+- policy='service-time 0' prio=1 status=enabled 372s | `- 2:0:0:1 sdc 8:32 active ready running 372s `-+- policy='service-time 0' prio=1 status=enabled 372s `- 3:0:0:1 sdd 8:48 active ready running 372s + date +UN-plug path 1 %H:%M:%S.%N 372s UN-plug path 1 18:12:01.929119634 372s + iscsiadm --mode session -r 1 -u 372s Logging out of session [sid: 1, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 372s Logout of [sid: 1, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 372s + iscsiadm --mode session 372s tcp: [2] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 372s tcp: [3] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 372s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 372s + sleep 10s 372s + date +MP report (expect 3) %H:%M:%S.%N 372s MP report (expect 3) 18:12:12.030152491 372s + multipath -ll 372s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 372s size=100M features='0' hwhandler='0' wp=rw 372s |-+- policy='service-time 0' prio=1 status=active 372s | `- 1:0:0:1 sdb 8:16 active ready running 372s |-+- policy='service-time 0' prio=1 status=enabled 372s | `- 2:0:0:1 sdc 8:32 active ready running 372s `-+- policy='service-time 0' prio=1 status=enabled 372s `- 3:0:0:1 sdd 8:48 active ready running 372s + date +UN-plug path 2 %H:%M:%S.%N 372s UN-plug path 2 18:12:12.048017925 372s + iscsiadm --mode session -r 2 -u 372s Logging out of session [sid: 2, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 372s Logout of [sid: 2, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 372s + iscsiadm --mode session 372s tcp: [3] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 372s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 372s + sleep 10s 372s + date +MP report (expect 2) %H:%M:%S.%N 372s MP report (expect 2) 18:12:22.149792881 372s + multipath -ll 372s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 372s size=100M features='0' hwhandler='0' wp=rw 372s |-+- policy='service-time 0' prio=1 status=active 372s | `- 2:0:0:1 sdc 8:32 active ready running 372s `-+- policy='service-time 0' prio=1 status=enabled 372s `- 3:0:0:1 sdd 8:48 active ready running 372s + date +UN-plug path 3 %H:%M:%S.%N 372s UN-plug path 3 18:12:22.164247409 372s + iscsiadm --mode session -r 3 -u 372s Logging out of session [sid: 3, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 372s Logout of [sid: 3, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 372s + iscsiadm --mode session 372s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 372s + sleep 10s 372s + date +MP report (expect 1) %H:%M:%S.%N 372s MP report (expect 1) 18:12:32.260928517 372s + multipath -ll 372s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 372s size=100M features='0' hwhandler='0' wp=rw 372s `-+- policy='service-time 0' prio=1 status=active 372s `- 3:0:0:1 sdd 8:48 active ready running 372s + date +Add paths 5/6/7/8 %H:%M:%S.%N 372s Add paths 5/6/7/8 18:12:32.275266477 372s + iscsiadm --mode session -r 4 --op new 372s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 372s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 372s + iscsiadm --mode session -r 4 --op new 372s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 372s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 372s + iscsiadm --mode session -r 4 --op new 372s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 372s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 372s + iscsiadm --mode session -r 4 --op new 372s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 372s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 372s + iscsiadm --mode session 372s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 372s tcp: [5] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 372s tcp: [6] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 372s tcp: [7] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 372s tcp: [8] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 372s + sleep 10s 372s + date +MP report (expect 5) %H:%M:%S.%N 372s MP report (expect 5) 18:12:42.346853727 372s + multipath -ll 372s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 372s size=100M features='0' hwhandler='0' wp=rw 372s |-+- policy='service-time 0' prio=1 status=active 372s | `- 3:0:0:1 sdd 8:48 active ready running 372s |-+- policy='service-time 0' prio=1 status=enabled 372s | `- 0:0:0:1 sda 8:0 active ready running 372s |-+- policy='service-time 0' prio=1 status=enabled 372s | `- 1:0:0:1 sdb 8:16 active ready running 372s |-+- policy='service-time 0' prio=1 status=enabled 372s | `- 2:0:0:1 sdc 8:32 active ready running 372s `-+- policy='service-time 0' prio=1 status=enabled 372s `- 4:0:0:1 sde 8:64 active ready running 372s + date +UN-plug multiple paths 4/7/8 %H:%M:%S.%N 372s UN-plug multiple paths 4/7/8 18:12:42.370320582 372s + iscsiadm --mode session -r 4 -u 372s Logging out of session [sid: 4, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 372s Logout of [sid: 4, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 372s + iscsiadm --mode session -r 7 -u 372s Logging out of session [sid: 7, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 372s Logout of [sid: 7, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 372s + iscsiadm --mode session -r 8 -u 372s Logging out of session [sid: 8, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 372s Logout of [sid: 8, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 372s + iscsiadm --mode session 372s tcp: [5] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 372s tcp: [6] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 372s + sleep 10s 372s + date +Restart multipath daemon %H:%M:%S.%N 372s Restart multipath daemon 18:12:52.633997099 372s + systemctl restart multipathd 372s + sleep 10s 372s + date +Final background report (expect 2) %H:%M:%S.%N 372s Final background report (expect 2) 18:13:02.711608175 372s + multipath -ll 372s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 372s size=100M features='0' hwhandler='0' wp=rw 372s |-+- policy='service-time 0' prio=1 status=active 372s | `- 0:0:0:1 sda 8:0 active ready running 372s `-+- policy='service-time 0' prio=1 status=enabled 372s `- 1:0:0:1 sdb 8:16 active ready running 372s Final stats 372s Stats for session [sid: 5, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 372s iSCSI SNMP: 372s txdata_octets: 31862664 372s rxdata_octets: 43479991408 372s noptx_pdus: 0 372s scsicmd_pdus: 663538 372s tmfcmd_pdus: 0 372s login_pdus: 0 372s text_pdus: 0 372s dataout_pdus: 0 372s logout_pdus: 0 372s snack_pdus: 0 372s noprx_pdus: 0 372s scsirsp_pdus: 663538 372s tmfrsp_pdus: 0 372s textrsp_pdus: 0 372s datain_pdus: 663503 372s logoutrsp_pdus: 0 372s r2t_pdus: 0 372s async_pdus: 0 372s rjt_pdus: 0 372s digest_err: 0 372s timeout_err: 0 372s iSCSI Extended: 372s tx_sendpage_failures: 0 372s rx_discontiguous_hdr: 0 372s eh_abort_cnt: 0 372s Stats for session [sid: 6, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 372s iSCSI SNMP: 372s txdata_octets: 6744 372s rxdata_octets: 1515328 372s noptx_pdus: 0 372s scsicmd_pdus: 110 372s tmfcmd_pdus: 0 372s login_pdus: 0 372s text_pdus: 0 372s dataout_pdus: 0 372s logout_pdus: 0 372s snack_pdus: 0 372s noprx_pdus: 0 372s scsirsp_pdus: 110 372s tmfrsp_pdus: 0 372s textrsp_pdus: 0 372s datain_pdus: 87 372s logoutrsp_pdus: 0 372s r2t_pdus: 0 372s async_pdus: 0 372s rjt_pdus: 0 372s digest_err: 0 372s timeout_err: 0 372s iSCSI Extended: 372s tx_sendpage_failures: 0 372s rx_discontiguous_hdr: 0 372s eh_abort_cnt: 0 372s Sep 30 02:04:12 ubuntu systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 372s Sep 30 02:04:12 ubuntu multipathd[361]: multipathd v0.9.9: start up 372s Sep 30 02:04:12 ubuntu multipathd[361]: reconfigure: setting up paths and maps 372s Sep 30 02:04:12 ubuntu multipathd[361]: _check_bindings_file: failed to read header from /etc/multipath/bindings 372s Sep 30 02:04:12 ubuntu multipathd[361]: updated bindings file /etc/multipath/bindings 372s Sep 30 02:04:12 ubuntu systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 372s Sep 30 02:06:44 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i multipathd[361]: multipathd: shut down 372s Sep 30 02:06:44 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Stopping multipathd.service - Device-Mapper Multipath Device Controller... 372s Sep 30 02:06:44 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: multipathd.service: Deactivated successfully. 372s Sep 30 02:06:44 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Stopped multipathd.service - Device-Mapper Multipath Device Controller. 372s -- Boot 238c6e4ec21e49968d9d7521c8c7c1d1 -- 372s Sep 30 02:06:56 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i multipathd[286]: multipathd v0.9.9: start up 372s Sep 30 02:06:56 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i multipathd[286]: reconfigure: setting up paths and maps 372s Sep 30 02:06:56 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 372s Sep 30 02:07:12 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i multipathd[286]: multipathd: shut down 372s Sep 30 02:07:12 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Stopping multipathd.service - Device-Mapper Multipath Device Controller... 372s Sep 30 02:07:12 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: multipathd.service: Deactivated successfully. 372s Sep 30 02:07:12 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Stopped multipathd.service - Device-Mapper Multipath Device Controller. 372s -- Boot 5155807fcf25442ab54204d1575a7adb -- 372s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i multipathd[317]: multipathd v0.9.9: start up 372s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i multipathd[317]: reconfigure: setting up paths and maps 372s Sep 30 18:10:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240928-disk1-i systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 372s Sep 30 18:11:42 autopkgtest multipathd[317]: updated bindings file /etc/multipath/bindings 372s Sep 30 18:11:42 autopkgtest multipathd[317]: mpatha: addmap [0 204800 multipath 0 0 1 1 service-time 0 1 1 8:0 1] 372s Sep 30 18:11:42 autopkgtest multipathd[317]: sda [8:0]: path added to devmap mpatha 372s Sep 30 18:11:42 autopkgtest multipathd[317]: mpatha: performing delayed actions 372s Sep 30 18:11:42 autopkgtest multipathd[317]: 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:48 1] 372s Sep 30 18:12:01 autopkgtest multipathd[317]: mpatha: reload [0 204800 multipath 0 0 3 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:48 1] 372s Sep 30 18:12:01 autopkgtest multipathd[317]: check_removed_paths: sda: freeing path in removed state 372s Sep 30 18:12:01 autopkgtest multipathd[317]: 8:0: path removed from map mpatha 372s Sep 30 18:12:12 autopkgtest multipathd[317]: mpatha: reload [0 204800 multipath 0 0 2 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:48 1] 372s Sep 30 18:12:12 autopkgtest multipathd[317]: check_removed_paths: sdb: freeing path in removed state 372s Sep 30 18:12:12 autopkgtest multipathd[317]: 8:16: path removed from map mpatha 372s Sep 30 18:12:22 autopkgtest multipathd[317]: mpatha: reload [0 204800 multipath 0 0 1 1 service-time 0 1 1 8:48 1] 372s Sep 30 18:12:22 autopkgtest multipathd[317]: check_removed_paths: sdc: freeing path in removed state 372s Sep 30 18:12:22 autopkgtest multipathd[317]: 8:32: path removed from map mpatha 372s Sep 30 18:12:32 autopkgtest multipathd[317]: 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] 372s Sep 30 18:12:32 autopkgtest multipathd[317]: sda [8:0]: path added to devmap mpatha 372s Sep 30 18:12:32 autopkgtest multipathd[317]: 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] 372s Sep 30 18:12:32 autopkgtest multipathd[317]: sdb [8:16]: path added to devmap mpatha 372s Sep 30 18:12:32 autopkgtest multipathd[317]: 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] 372s Sep 30 18:12:32 autopkgtest multipathd[317]: sdc [8:32]: path added to devmap mpatha 372s Sep 30 18:12:32 autopkgtest multipathd[317]: 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] 372s Sep 30 18:12:32 autopkgtest multipathd[317]: sde [8:64]: path added to devmap mpatha 372s Sep 30 18:12:42 autopkgtest multipathd[317]: 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] 372s Sep 30 18:12:42 autopkgtest multipathd[317]: check_removed_paths: sdd: freeing path in removed state 372s Sep 30 18:12:42 autopkgtest multipathd[317]: 8:48: path removed from map mpatha 372s Sep 30 18:12:42 autopkgtest multipathd[317]: 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] 372s Sep 30 18:12:42 autopkgtest multipathd[317]: check_removed_paths: sdc: freeing path in removed state 372s Sep 30 18:12:42 autopkgtest multipathd[317]: 8:32: path removed from map mpatha 372s Sep 30 18:12:42 autopkgtest multipathd[317]: 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] 372s Sep 30 18:12:42 autopkgtest multipathd[317]: check_removed_paths: sde: freeing path in removed state 372s Sep 30 18:12:42 autopkgtest multipathd[317]: 8:64: path removed from map mpatha 372s Sep 30 18:12:52 autopkgtest multipathd[317]: multipathd: shut down 372s Sep 30 18:12:52 autopkgtest systemd[1]: Stopping multipathd.service - Device-Mapper Multipath Device Controller... 372s Sep 30 18:12:52 autopkgtest systemd[1]: multipathd.service: Deactivated successfully. 372s Sep 30 18:12:52 autopkgtest systemd[1]: Stopped multipathd.service - Device-Mapper Multipath Device Controller. 372s Sep 30 18:12:52 autopkgtest systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 372s Sep 30 18:12:52 autopkgtest multipathd[7226]: multipathd v0.9.9: start up 372s Sep 30 18:12:52 autopkgtest multipathd[7226]: reconfigure: setting up paths and maps 372s Sep 30 18:12:52 autopkgtest systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 372s Check final path status 372s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 372s size=100M features='0' hwhandler='0' wp=rw 372s |-+- policy='service-time 0' prio=1 status=active 372s | `- 0:0:0:1 sda 8:0 active ready running 372s `-+- policy='service-time 0' prio=1 status=enabled 372s `- 1:0:0:1 sdb 8:16 active ready running 372s + sync 372s + umount /dev/disk/by-id/wwn-0x60000000000000000e00000000010001 372s + echo Final stats 372s + iscsiadm --mode session --stats 372s + journalctl --no-pager -u multipathd 372s + echo Check final path status 372s + multipath -ll 372s + multipath -ll 372s + grep --count status= 372s + diskc=2 372s + multipath -ll 372s + grep --count status=active 372s + diska=1 372s + multipath -ll 372s + grep --count status=enabled 372s OK 372s + diske=1 372s + [ 2 -ne 2 -o 1 -ne 1 -o 1 -ne 1 ] 372s + echo OK 372s + iscsiadm --mode node --targetname iqn.2016-11.foo.com:target.iscsi --portal 127.0.0.1:3260 --logout 372s Logging out of session [sid: 5, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 372s Logging out of session [sid: 6, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 372s Logout of [sid: 5, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 372s Logout of [sid: 6, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 372s + tgtadm --lld iscsi --op delete --mode logicalunit --tid 1 --lun 1 372s autopkgtest [18:14:52]: test tgtbasedmpaths: -----------------------] 373s autopkgtest [18:14:53]: test tgtbasedmpaths: - - - - - - - - - - results - - - - - - - - - - 373s tgtbasedmpaths PASS 373s autopkgtest [18:14:53]: @@@@@@@@@@@@@@@@@@@@ summary 373s initramfs SKIP Test lists explicitly supported architectures, but the current architecture ppc64el isn't listed. 373s initramfs SKIP Test lists explicitly supported architectures, but the current architecture ppc64el isn't listed. 373s kpartx-file-loopback PASS 373s tgtbasedmpaths PASS 378s nova [W] Using flock in prodstack6-ppc64el 378s Creating nova instance adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f2275-prod-proposed-migration-environment-2-0934278a-c961-4bc6-9ced-0a33e4f4d54c from image adt/ubuntu-oracular-ppc64el-server-20240930.img (UUID ffe806c2-12d1-4896-b5bc-f6686fc1693a)... 378s nova [W] Using flock in prodstack6-ppc64el 378s Creating nova instance adt-oracular-ppc64el-multipath-tools-20240930-180840-juju-7f2275-prod-proposed-migration-environment-2-0934278a-c961-4bc6-9ced-0a33e4f4d54c from image adt/ubuntu-oracular-ppc64el-server-20240930.img (UUID ffe806c2-12d1-4896-b5bc-f6686fc1693a)...