0s autopkgtest [00:14:07]: starting date and time: 2024-08-22 00:14:07+0000 1s autopkgtest [00:14:08]: git checkout: fd3bed09 nova: allow more retries for quota issues 1s autopkgtest [00:14:08]: host juju-7f2275-prod-proposed-migration-environment-3; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.ew9u50bp/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:qemu --apt-upgrade multipath-tools --timeout-short=300 --timeout-copy=20000 --timeout-test=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=qemu/1:9.0.2+ds-4ubuntu2 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest-big-ppc64el --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-3@bos03-ppc64el-36.secgroup --name adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f2275-prod-proposed-migration-environment-3-dbf9ef1f-aafb-448c-b0cf-96081f475010 --image adt/ubuntu-oracular-ppc64el-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-3 --net-id=net_prod-proposed-migration-ppc64el -e TERM=linux -e ''"'"'http_proxy=http://squid.internal:3128'"'"'' -e ''"'"'https_proxy=http://squid.internal:3128'"'"'' -e ''"'"'no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,keyserver.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com'"'"'' --mirror=http://ftpmaster.internal/ubuntu/ 121s autopkgtest [00:16:08]: testbed dpkg architecture: ppc64el 121s autopkgtest [00:16:08]: testbed apt version: 2.9.8 121s autopkgtest [00:16:08]: @@@@@@@@@@@@@@@@@@@@ test bed setup 122s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [126 kB] 123s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [8452 B] 123s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [71.7 kB] 123s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [830 kB] 123s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [11.1 kB] 123s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el Packages [97.6 kB] 123s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el c-n-f Metadata [3240 B] 123s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el Packages [1376 B] 123s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el c-n-f Metadata [120 B] 123s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el Packages [744 kB] 123s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el c-n-f Metadata [20.3 kB] 123s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el Packages [5956 B] 123s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el c-n-f Metadata [372 B] 127s Fetched 1921 kB in 1s (1464 kB/s) 127s Reading package lists... 129s Reading package lists... 130s Building dependency tree... 130s Reading state information... 130s Calculating upgrade... 130s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 130s Reading package lists... 130s Building dependency tree... 130s Reading state information... 130s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 131s Hit:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease 131s Hit:2 http://ftpmaster.internal/ubuntu oracular InRelease 131s Hit:3 http://ftpmaster.internal/ubuntu oracular-updates InRelease 131s Hit:4 http://ftpmaster.internal/ubuntu oracular-security InRelease 132s Reading package lists... 132s Reading package lists... 132s Building dependency tree... 132s Reading state information... 132s Calculating upgrade... 133s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 133s Reading package lists... 133s Building dependency tree... 133s Reading state information... 133s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 137s autopkgtest [00:16:24]: testbed running kernel: Linux 6.8.0-31-generic #31-Ubuntu SMP Sat Apr 20 00:05:55 UTC 2024 137s autopkgtest [00:16:24]: @@@@@@@@@@@@@@@@@@@@ apt-source multipath-tools 140s Get:1 http://ftpmaster.internal/ubuntu oracular/main multipath-tools 0.9.9-1ubuntu2 (dsc) [2772 B] 140s Get:2 http://ftpmaster.internal/ubuntu oracular/main multipath-tools 0.9.9-1ubuntu2 (tar) [588 kB] 140s Get:3 http://ftpmaster.internal/ubuntu oracular/main multipath-tools 0.9.9-1ubuntu2 (diff) [42.4 kB] 140s gpgv: Signature made Tue Jul 23 21:24:22 2024 UTC 140s gpgv: using RSA key D09F8A854F1055BCFC482C4B23566B906047AFC8 140s gpgv: Can't check signature: No public key 140s dpkg-source: warning: cannot verify inline signature for ./multipath-tools_0.9.9-1ubuntu2.dsc: no acceptable signature found 140s autopkgtest [00:16:27]: testing package multipath-tools version 0.9.9-1ubuntu2 141s initramfs SKIP Test lists explicitly supported architectures, but the current architecture ppc64el isn't listed. 141s autopkgtest [00:16:28]: build not needed 142s initramfs SKIP Test lists explicitly supported architectures, but the current architecture ppc64el isn't listed. 142s autopkgtest [00:16:29]: test kpartx-file-loopback: preparing testbed 144s Reading package lists... 144s Building dependency tree... 144s Reading state information... 144s Starting pkgProblemResolver with broken count: 0 144s Starting 2 pkgProblemResolver with broken count: 0 144s Done 144s The following additional packages will be installed: 144s liburing2 qemu-utils 144s Recommended packages: 144s qemu-block-extra 144s The following NEW packages will be installed: 144s autopkgtest-satdep liburing2 qemu-utils 144s 0 upgraded, 3 newly installed, 0 to remove and 0 not upgraded. 144s Need to get 2432 kB/2433 kB of archives. 144s After this operation, 16.9 MB of additional disk space will be used. 144s Get:1 /tmp/autopkgtest.gLtNOa/1-autopkgtest-satdep.deb autopkgtest-satdep ppc64el 0 [720 B] 145s Get:2 http://ftpmaster.internal/ubuntu oracular/main ppc64el liburing2 ppc64el 2.6-1 [26.9 kB] 145s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el qemu-utils ppc64el 1:9.0.2+ds-4ubuntu2 [2405 kB] 146s Fetched 2432 kB in 1s (1646 kB/s) 146s Selecting previously unselected package liburing2:ppc64el. 146s (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 ... 72506 files and directories currently installed.) 146s Preparing to unpack .../liburing2_2.6-1_ppc64el.deb ... 146s Unpacking liburing2:ppc64el (2.6-1) ... 147s Selecting previously unselected package qemu-utils. 147s Preparing to unpack .../qemu-utils_1%3a9.0.2+ds-4ubuntu2_ppc64el.deb ... 147s Unpacking qemu-utils (1:9.0.2+ds-4ubuntu2) ... 147s Selecting previously unselected package autopkgtest-satdep. 147s Preparing to unpack .../1-autopkgtest-satdep.deb ... 147s Unpacking autopkgtest-satdep (0) ... 147s Setting up liburing2:ppc64el (2.6-1) ... 147s Setting up qemu-utils (1:9.0.2+ds-4ubuntu2) ... 147s Setting up autopkgtest-satdep (0) ... 147s Processing triggers for man-db (2.12.1-3) ... 148s Processing triggers for libc-bin (2.39-0ubuntu9) ... 151s (Reading database ... 72530 files and directories currently installed.) 151s Removing autopkgtest-satdep (0) ... 152s autopkgtest [00:16:39]: test kpartx-file-loopback: [----------------------- 152s Formatting 'foo.img', fmt=raw size=20971520 153s Creating new GPT entries in memory. 153s Warning: The kernel is still using the old partition table. 153s The new table will be used at the next reboot or after you 153s run partprobe(8) or kpartx(8) 153s The operation has completed successfully. 153s add map loop0p1 (252:0): 0 38879 linear 7:0 2048 153s standard_filename: OK 153s del devmap : loop0p1 153s No devices found 153s standard_filename_cleanup: OK 153s Formatting 'fou du FaFa.img', fmt=raw size=20971520 154s Creating new GPT entries in memory. 154s Warning: The kernel is still using the old partition table. 154s The new table will be used at the next reboot or after you 154s run partprobe(8) or kpartx(8) 154s The operation has completed successfully. 154s add map loop0p1 (252:0): 0 38879 linear 7:0 2048 154s filename_with_spaces: OK 154s del devmap : loop0p1 154s No devices found 154s filename_with_spaces_cleanup: OK 155s autopkgtest [00:16:42]: test kpartx-file-loopback: -----------------------] 155s autopkgtest [00:16:42]: test kpartx-file-loopback: - - - - - - - - - - results - - - - - - - - - - 155s kpartx-file-loopback PASS 156s autopkgtest [00:16:43]: test tgtbasedmpaths: preparing testbed 243s autopkgtest [00:18:10]: testbed dpkg architecture: ppc64el 243s autopkgtest [00:18:10]: testbed apt version: 2.9.8 243s autopkgtest [00:18:10]: @@@@@@@@@@@@@@@@@@@@ test bed setup 244s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [126 kB] 245s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [71.7 kB] 245s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [8452 B] 245s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [830 kB] 245s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [11.1 kB] 245s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el Packages [97.6 kB] 245s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el c-n-f Metadata [3240 B] 245s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el Packages [1376 B] 245s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el c-n-f Metadata [120 B] 245s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el Packages [744 kB] 245s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el c-n-f Metadata [20.3 kB] 245s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el Packages [5956 B] 245s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el c-n-f Metadata [372 B] 248s Fetched 1921 kB in 1s (1893 kB/s) 248s Reading package lists... 251s Reading package lists... 251s Building dependency tree... 251s Reading state information... 251s Calculating upgrade... 251s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 251s Reading package lists... 251s Building dependency tree... 251s Reading state information... 251s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 252s Hit:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease 252s Hit:2 http://ftpmaster.internal/ubuntu oracular InRelease 252s Hit:3 http://ftpmaster.internal/ubuntu oracular-updates InRelease 252s Hit:4 http://ftpmaster.internal/ubuntu oracular-security InRelease 253s Reading package lists... 253s Reading package lists... 253s Building dependency tree... 253s Reading state information... 254s Calculating upgrade... 254s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 254s Reading package lists... 254s Building dependency tree... 254s Reading state information... 254s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 258s Reading package lists... 258s Building dependency tree... 258s Reading state information... 259s Starting pkgProblemResolver with broken count: 0 259s Starting 2 pkgProblemResolver with broken count: 0 259s Done 259s The following additional packages will be installed: 259s fio libboost-iostreams1.83.0 libboost-thread1.83.0 libconfig-general-perl 259s libdaxctl1 libgfapi0 libgfrpc0 libgfxdr0 libglusterfs0 libisns0t64 libnbd0 259s libndctl6 libopeniscsiusr libpmem1 libpmemobj1 librados2 librbd1 259s librdmacm1t64 lsscsi open-iscsi tgt 259s Suggested packages: 259s fio-examples gnuplot tgt-glusterfs tgt-rbd 259s Recommended packages: 259s finalrd 259s The following NEW packages will be installed: 259s autopkgtest-satdep fio libboost-iostreams1.83.0 libboost-thread1.83.0 259s libconfig-general-perl libdaxctl1 libgfapi0 libgfrpc0 libgfxdr0 259s libglusterfs0 libisns0t64 libnbd0 libndctl6 libopeniscsiusr libpmem1 259s libpmemobj1 librados2 librbd1 librdmacm1t64 lsscsi open-iscsi tgt 259s 0 upgraded, 22 newly installed, 0 to remove and 0 not upgraded. 259s Need to get 10.9 MB/10.9 MB of archives. 259s After this operation, 49.6 MB of additional disk space will be used. 259s Get:1 /tmp/autopkgtest.gLtNOa/2-autopkgtest-satdep.deb autopkgtest-satdep ppc64el 0 [732 B] 259s Get:2 http://ftpmaster.internal/ubuntu oracular/main ppc64el libopeniscsiusr ppc64el 2.1.10-1ubuntu1 [54.9 kB] 259s Get:3 http://ftpmaster.internal/ubuntu oracular/main ppc64el libisns0t64 ppc64el 0.101-1 [117 kB] 259s Get:4 http://ftpmaster.internal/ubuntu oracular/main ppc64el open-iscsi ppc64el 2.1.10-1ubuntu1 [385 kB] 260s Get:5 http://ftpmaster.internal/ubuntu oracular/main ppc64el librdmacm1t64 ppc64el 52.0-2 [80.5 kB] 260s Get:6 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libconfig-general-perl all 2.65-2 [57.1 kB] 260s Get:7 http://ftpmaster.internal/ubuntu oracular/universe ppc64el tgt ppc64el 1:1.0.85-1.2ubuntu1 [254 kB] 260s Get:8 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libgfxdr0 ppc64el 11.1-5ubuntu1 [21.7 kB] 260s Get:9 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libglusterfs0 ppc64el 11.1-5ubuntu1 [308 kB] 260s Get:10 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libgfrpc0 ppc64el 11.1-5ubuntu1 [46.3 kB] 260s Get:11 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libgfapi0 ppc64el 11.1-5ubuntu1 [99.1 kB] 260s Get:12 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libnbd0 ppc64el 1.20.2-2 [98.5 kB] 260s Get:13 http://ftpmaster.internal/ubuntu oracular/main ppc64el libdaxctl1 ppc64el 77-2.2ubuntu1 [23.7 kB] 260s Get:14 http://ftpmaster.internal/ubuntu oracular/main ppc64el libndctl6 ppc64el 77-2.2ubuntu1 [73.4 kB] 260s Get:15 http://ftpmaster.internal/ubuntu oracular/main ppc64el libpmem1 ppc64el 1.13.1-1.1ubuntu2 [41.1 kB] 260s Get:16 http://ftpmaster.internal/ubuntu oracular/main ppc64el libboost-iostreams1.83.0 ppc64el 1.83.0-3.1ubuntu1 [259 kB] 260s Get:17 http://ftpmaster.internal/ubuntu oracular/main ppc64el libboost-thread1.83.0 ppc64el 1.83.0-3.1ubuntu1 [281 kB] 260s Get:18 http://ftpmaster.internal/ubuntu oracular/main ppc64el librados2 ppc64el 19.2.0~is.really.19.1.0-0ubuntu2 [4151 kB] 264s Get:19 http://ftpmaster.internal/ubuntu oracular/main ppc64el libpmemobj1 ppc64el 1.13.1-1.1ubuntu2 [143 kB] 264s Get:20 http://ftpmaster.internal/ubuntu oracular/main ppc64el librbd1 ppc64el 19.2.0~is.really.19.1.0-0ubuntu2 [3684 kB] 267s Get:21 http://ftpmaster.internal/ubuntu oracular/universe ppc64el fio ppc64el 3.37-1 [716 kB] 268s Get:22 http://ftpmaster.internal/ubuntu oracular/main ppc64el lsscsi ppc64el 0.32-1build1 [54.0 kB] 268s Preconfiguring packages ... 268s Fetched 10.9 MB in 9s (1209 kB/s) 268s Selecting previously unselected package libopeniscsiusr. 268s (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 ... 72506 files and directories currently installed.) 268s Preparing to unpack .../00-libopeniscsiusr_2.1.10-1ubuntu1_ppc64el.deb ... 268s Unpacking libopeniscsiusr (2.1.10-1ubuntu1) ... 268s Selecting previously unselected package libisns0t64:ppc64el. 268s Preparing to unpack .../01-libisns0t64_0.101-1_ppc64el.deb ... 268s Unpacking libisns0t64:ppc64el (0.101-1) ... 268s Selecting previously unselected package open-iscsi. 268s Preparing to unpack .../02-open-iscsi_2.1.10-1ubuntu1_ppc64el.deb ... 269s Unpacking open-iscsi (2.1.10-1ubuntu1) ... 269s Selecting previously unselected package librdmacm1t64:ppc64el. 269s Preparing to unpack .../03-librdmacm1t64_52.0-2_ppc64el.deb ... 269s Unpacking librdmacm1t64:ppc64el (52.0-2) ... 269s Selecting previously unselected package libconfig-general-perl. 269s Preparing to unpack .../04-libconfig-general-perl_2.65-2_all.deb ... 269s Unpacking libconfig-general-perl (2.65-2) ... 269s Selecting previously unselected package tgt. 269s Preparing to unpack .../05-tgt_1%3a1.0.85-1.2ubuntu1_ppc64el.deb ... 269s Unpacking tgt (1:1.0.85-1.2ubuntu1) ... 269s Selecting previously unselected package libgfxdr0:ppc64el. 269s Preparing to unpack .../06-libgfxdr0_11.1-5ubuntu1_ppc64el.deb ... 269s Unpacking libgfxdr0:ppc64el (11.1-5ubuntu1) ... 269s Selecting previously unselected package libglusterfs0:ppc64el. 269s Preparing to unpack .../07-libglusterfs0_11.1-5ubuntu1_ppc64el.deb ... 269s Unpacking libglusterfs0:ppc64el (11.1-5ubuntu1) ... 269s Selecting previously unselected package libgfrpc0:ppc64el. 269s Preparing to unpack .../08-libgfrpc0_11.1-5ubuntu1_ppc64el.deb ... 269s Unpacking libgfrpc0:ppc64el (11.1-5ubuntu1) ... 269s Selecting previously unselected package libgfapi0:ppc64el. 269s Preparing to unpack .../09-libgfapi0_11.1-5ubuntu1_ppc64el.deb ... 269s Unpacking libgfapi0:ppc64el (11.1-5ubuntu1) ... 269s Selecting previously unselected package libnbd0. 269s Preparing to unpack .../10-libnbd0_1.20.2-2_ppc64el.deb ... 269s Unpacking libnbd0 (1.20.2-2) ... 269s Selecting previously unselected package libdaxctl1:ppc64el. 269s Preparing to unpack .../11-libdaxctl1_77-2.2ubuntu1_ppc64el.deb ... 269s Unpacking libdaxctl1:ppc64el (77-2.2ubuntu1) ... 269s Selecting previously unselected package libndctl6:ppc64el. 269s Preparing to unpack .../12-libndctl6_77-2.2ubuntu1_ppc64el.deb ... 269s Unpacking libndctl6:ppc64el (77-2.2ubuntu1) ... 269s Selecting previously unselected package libpmem1:ppc64el. 269s Preparing to unpack .../13-libpmem1_1.13.1-1.1ubuntu2_ppc64el.deb ... 269s Unpacking libpmem1:ppc64el (1.13.1-1.1ubuntu2) ... 269s Selecting previously unselected package libboost-iostreams1.83.0:ppc64el. 269s Preparing to unpack .../14-libboost-iostreams1.83.0_1.83.0-3.1ubuntu1_ppc64el.deb ... 269s Unpacking libboost-iostreams1.83.0:ppc64el (1.83.0-3.1ubuntu1) ... 269s Selecting previously unselected package libboost-thread1.83.0:ppc64el. 269s Preparing to unpack .../15-libboost-thread1.83.0_1.83.0-3.1ubuntu1_ppc64el.deb ... 269s Unpacking libboost-thread1.83.0:ppc64el (1.83.0-3.1ubuntu1) ... 269s Selecting previously unselected package librados2. 269s Preparing to unpack .../16-librados2_19.2.0~is.really.19.1.0-0ubuntu2_ppc64el.deb ... 269s Unpacking librados2 (19.2.0~is.really.19.1.0-0ubuntu2) ... 269s Selecting previously unselected package libpmemobj1:ppc64el. 269s Preparing to unpack .../17-libpmemobj1_1.13.1-1.1ubuntu2_ppc64el.deb ... 269s Unpacking libpmemobj1:ppc64el (1.13.1-1.1ubuntu2) ... 269s Selecting previously unselected package librbd1. 269s Preparing to unpack .../18-librbd1_19.2.0~is.really.19.1.0-0ubuntu2_ppc64el.deb ... 269s Unpacking librbd1 (19.2.0~is.really.19.1.0-0ubuntu2) ... 269s Selecting previously unselected package fio. 269s Preparing to unpack .../19-fio_3.37-1_ppc64el.deb ... 269s Unpacking fio (3.37-1) ... 269s Selecting previously unselected package lsscsi. 269s Preparing to unpack .../20-lsscsi_0.32-1build1_ppc64el.deb ... 269s Unpacking lsscsi (0.32-1build1) ... 269s Selecting previously unselected package autopkgtest-satdep. 269s Preparing to unpack .../21-2-autopkgtest-satdep.deb ... 269s Unpacking autopkgtest-satdep (0) ... 269s Setting up libconfig-general-perl (2.65-2) ... 269s Setting up libisns0t64:ppc64el (0.101-1) ... 269s Setting up libboost-thread1.83.0:ppc64el (1.83.0-3.1ubuntu1) ... 269s Setting up libnbd0 (1.20.2-2) ... 269s Setting up libopeniscsiusr (2.1.10-1ubuntu1) ... 269s Setting up libglusterfs0:ppc64el (11.1-5ubuntu1) ... 269s Setting up libboost-iostreams1.83.0:ppc64el (1.83.0-3.1ubuntu1) ... 269s Setting up lsscsi (0.32-1build1) ... 269s Setting up libdaxctl1:ppc64el (77-2.2ubuntu1) ... 269s Setting up libndctl6:ppc64el (77-2.2ubuntu1) ... 269s Setting up librdmacm1t64:ppc64el (52.0-2) ... 269s Setting up tgt (1:1.0.85-1.2ubuntu1) ... 270s Created symlink '/etc/systemd/system/multi-user.target.wants/tgt.service' → '/usr/lib/systemd/system/tgt.service'. 270s Setting up libpmem1:ppc64el (1.13.1-1.1ubuntu2) ... 270s Setting up libgfxdr0:ppc64el (11.1-5ubuntu1) ... 270s Setting up librados2 (19.2.0~is.really.19.1.0-0ubuntu2) ... 270s Setting up open-iscsi (2.1.10-1ubuntu1) ... 271s Created symlink '/etc/systemd/system/sockets.target.wants/iscsid.socket' → '/usr/lib/systemd/system/iscsid.socket'. 271s Created symlink '/etc/systemd/system/iscsi.service' → '/usr/lib/systemd/system/open-iscsi.service'. 271s Created symlink '/etc/systemd/system/sysinit.target.wants/open-iscsi.service' → '/usr/lib/systemd/system/open-iscsi.service'. 271s Setting up libpmemobj1:ppc64el (1.13.1-1.1ubuntu2) ... 271s Setting up librbd1 (19.2.0~is.really.19.1.0-0ubuntu2) ... 271s Setting up libgfrpc0:ppc64el (11.1-5ubuntu1) ... 271s Setting up libgfapi0:ppc64el (11.1-5ubuntu1) ... 271s Setting up fio (3.37-1) ... 272s Setting up autopkgtest-satdep (0) ... 272s Processing triggers for man-db (2.12.1-3) ... 274s Processing triggers for initramfs-tools (0.142ubuntu32) ... 274s update-initramfs: Generating /boot/initrd.img-6.8.0-31-generic 274s W: No lz4 in /usr/bin:/sbin:/bin, using gzip 281s Processing triggers for libc-bin (2.39-0ubuntu9) ... 284s (Reading database ... 72747 files and directories currently installed.) 284s Removing autopkgtest-satdep (0) ... 363s autopkgtest [00:20:10]: test tgtbasedmpaths: [----------------------- 363s + targetname=iqn.2016-11.foo.com:target.iscsi 363s + pwd 363s + cwd=/tmp/autopkgtest.gLtNOa/build.OGg/src 363s + testdir=/mnt/tgtmpathtest 363s + localhost=127.0.0.1 363s + portal=127.0.0.1:3260 363s + maxpaths=4 363s + backfn=backingfile 363s + expectwwid=60000000000000000e00000000010001 363s + testdisk=/dev/disk/by-id/wwn-0x60000000000000000e00000000010001 363s + bglog=/tmp/autopkgtest.gLtNOa/tgtbasedmpaths-artifacts/test-background.log 363s + fioprep=/tmp/autopkgtest.gLtNOa/tgtbasedmpaths-artifacts/path-change-prep.fio 363s + fiovrfy=/tmp/autopkgtest.gLtNOa/tgtbasedmpaths-artifacts/path-change-check.fio 363s + mkdir -p /etc/multipath 363s + echo /360000000000000000e00000000010001/ 363s + service tgt restart 364s + truncate --size 100M backingfile 364s + tgtadm --lld iscsi --op new --mode target --tid 1 -T iqn.2016-11.foo.com:target.iscsi 364s + tgtadm --lld iscsi --op bind --mode target --tid 1 -I ALL 364s + tgtadm --lld iscsi --op new --mode logicalunit --tid 1 --lun 1 -b /tmp/autopkgtest.gLtNOa/build.OGg/src/backingfile 364s + iscsiadm --mode discovery --type sendtargets --portal 127.0.0.1 364s 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi 364s login #1 364s + echo login #1 364s + iscsiadm --mode node --targetname iqn.2016-11.foo.com:target.iscsi --portal 127.0.0.1:3260 --login 364s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 364s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 364s + seq 2 4 364s extra login #2 364s + echo extra login #2 364s + iscsiadm --mode session -r 1 --op new 364s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 364s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 364s extra login #3 364s + echo extra login #3 364s + iscsiadm --mode session -r 1 --op new 364s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 364s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 364s extra login #4 364s + echo extra login #4 364s + iscsiadm --mode session -r 1 --op new 364s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 364s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 364s + udevadm settle 364s + sleep 5 369s + echo Status after initial setup 369s + tgtadm --lld iscsi --mode target --op show 369s Status after initial setup 369s + tgtadm --lld iscsi --op show --mode conn --tid 1 369s Target 1: iqn.2016-11.foo.com:target.iscsi 369s System information: 369s Driver: iscsi 369s State: ready 369s I_T nexus information: 369s I_T nexus: 1 369s Initiator: iqn.2004-10.com.ubuntu:01:e176be10d111 alias: autopkgtest 369s Connection: 0 369s IP Address: 127.0.0.1 369s I_T nexus: 2 369s Initiator: iqn.2004-10.com.ubuntu:01:e176be10d111 alias: autopkgtest 369s Connection: 0 369s IP Address: 127.0.0.1 369s I_T nexus: 3 369s Initiator: iqn.2004-10.com.ubuntu:01:e176be10d111 alias: autopkgtest 369s Connection: 0 369s IP Address: 127.0.0.1 369s I_T nexus: 4 369s Initiator: iqn.2004-10.com.ubuntu:01:e176be10d111 alias: autopkgtest 369s Connection: 0 369s IP Address: 127.0.0.1 369s LUN information: 369s LUN: 0 369s Type: controller 369s SCSI ID: IET 00010000 369s SCSI SN: beaf10 369s Size: 0 MB, Block size: 1 369s Online: Yes 369s Removable media: No 369s Prevent removal: No 369s Readonly: No 369s SWP: No 369s Thin-provisioning: No 369s Backing store type: null 369s Backing store path: None 369s Backing store flags: 369s LUN: 1 369s Type: disk 369s SCSI ID: IET 00010001 369s SCSI SN: beaf11 369s Size: 105 MB, Block size: 512 369s Online: Yes 369s Removable media: No 369s Prevent removal: No 369s Readonly: No 369s SWP: No 369s Thin-provisioning: No 369s Backing store type: rdwr 369s Backing store path: /tmp/autopkgtest.gLtNOa/build.OGg/src/backingfile 369s Backing store flags: 369s Account information: 369s ACL information: 369s ALL 369s + iscsiadm --mode session -P 1 369s Session: 4 369s Connection: 0 369s Initiator: iqn.2004-10.com.ubuntu:01:e176be10d111 369s IP Address: 127.0.0.1 369s Session: 3 369s Connection: 0 369s Initiator: iqn.2004-10.com.ubuntu:01:e176be10d111 369s IP Address: 127.0.0.1 369s Session: 2 369s Connection: 0 369s Initiator: iqn.2004-10.com.ubuntu:01:e176be10d111 369s IP Address: 127.0.0.1 369s Session: 1 369s Connection: 0 369s Initiator: iqn.2004-10.com.ubuntu:01:e176be10d111 369s IP Address: 127.0.0.1 369s Target: iqn.2016-11.foo.com:target.iscsi (non-flash) 369s Current Portal: 127.0.0.1:3260,1 369s Persistent Portal: 127.0.0.1:3260,1 369s ********** 369s Interface: 369s ********** 369s Iface Name: default 369s Iface Transport: tcp 369s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:e176be10d111 369s Iface IPaddress: 127.0.0.1 369s Iface HWaddress: default 369s Iface Netdev: default 369s SID: 1 369s iSCSI Connection State: LOGGED IN 369s iSCSI Session State: LOGGED_IN 369s Internal iscsid Session State: NO CHANGE 369s 369s ********** 369s Interface: 369s ********** 369s Iface Name: default 369s Iface Transport: tcp 369s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:e176be10d111 369s Iface IPaddress: 127.0.0.1 369s Iface HWaddress: default 369s Iface Netdev: default 369s SID: 2 369s iSCSI Connection State: LOGGED IN 369s iSCSI Session State: LOGGED_IN 369s Internal iscsid Session State: NO CHANGE 369s 369s ********** 369s Interface: 369s ********** 369s Iface Name: default 369s Iface Transport: tcp 369s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:e176be10d111 369s Iface IPaddress: 127.0.0.1 369s Iface HWaddress: default 369s Iface Netdev: default 369s SID: 3 369s iSCSI Connection State: LOGGED IN 369s iSCSI Session State: LOGGED_IN 369s Internal iscsid Session State: NO CHANGE 369s 369s ********** 369s Interface: 369s ********** 369s Iface Name: default 369s Iface Transport: tcp 369s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:e176be10d111 369s Iface IPaddress: 127.0.0.1 369s Iface HWaddress: default 369s Iface Netdev: default 369s SID: 4 369s iSCSI Connection State: LOGGED IN 369s iSCSI Session State: LOGGED_IN 369s Internal iscsid Session State: NO CHANGE 369s + lsscsi -liv 369s [0:0:0:0] storage IET Controller 0001 - - 369s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 369s dir: /sys/bus/scsi/devices/0:0:0:0 [/sys/devices/platform/host0/session1/target0:0:0/0:0:0:0] 369s [0:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sda 360000000000000000e00000000010001 369s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 369s dir: /sys/bus/scsi/devices/0:0:0:1 [/sys/devices/platform/host0/session1/target0:0:0/0:0:0:1] 369s [1:0:0:0] storage IET Controller 0001 - - 369s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 369s dir: /sys/bus/scsi/devices/1:0:0:0 [/sys/devices/platform/host1/session2/target1:0:0/1:0:0:0] 369s [1:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdb 360000000000000000e00000000010001 369s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 369s dir: /sys/bus/scsi/devices/1:0:0:1 [/sys/devices/platform/host1/session2/target1:0:0/1:0:0:1] 369s [2:0:0:0] storage IET Controller 0001 - - 369s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 369s dir: /sys/bus/scsi/devices/2:0:0:0 [/sys/devices/platform/host2/session3/target2:0:0/2:0:0:0] 369s [2:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdc 360000000000000000e00000000010001 369s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 369s dir: /sys/bus/scsi/devices/2:0:0:1 [/sys/devices/platform/host2/session3/target2:0:0/2:0:0:1] 369s [3:0:0:0] storage IET Controller 0001 - - 369s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 369s dir: /sys/bus/scsi/devices/3:0:0:0 [/sys/devices/platform/host3/session4/target3:0:0/3:0:0:0] 369s [3:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdd 33000000100000001 369s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 369s dir: /sys/bus/scsi/devices/3:0:0:1 [/sys/devices/platform/host3/session4/target3:0:0/3:0:0:1] 369s NVMe module may not be loaded 369s list_ndevices: scandir: /sys/class/nvme/: No such file or directory 369s + multipath -v3 -ll 369s 151.333354 | set open fds limit to 1073741816/1073741816 369s 151.333395 | _read_bindings_file: reading /etc/multipath/bindings 369s 151.333419 | loading /usr/lib/multipath/libchecktur.so checker 369s 151.333504 | checker tur: message table size = 4 369s 151.333513 | loading /usr/lib/multipath/libprioconst.so prioritizer 369s 151.333621 | _init_foreign: foreign library "nvme" is not enabled 369s 151.338458 | vda: device node name blacklisted 369s 151.338742 | sda: size = 204800 369s 151.338879 | sda: vendor = IET 369s 151.338903 | sda: product = VIRTUAL-DISK 369s 151.338926 | sda: rev = 0001 369s 151.339627 | sda: h:b:t:l = 0:0:0:1 369s 151.339978 | sda: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 369s 151.339982 | sda: uid_attribute = ID_SERIAL (setting: multipath internal) 369s 151.339985 | sda: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 369s 151.340177 | sda: 1024 cyl, 4 heads, 50 sectors/track, start at 0 369s 151.340186 | sda: vpd_vendor_id = 0 "undef" (setting: multipath internal) 369s 151.340201 | sda: serial = beaf11 369s 151.340204 | sda: detect_checker = yes (setting: multipath internal) 369s 151.340230 | sda checker timeout = 30 s (setting: kernel sysfs) 369s 151.340437 | sda: path_checker = tur (setting: multipath internal) 369s 151.340545 | sda: tur state = up 369s 151.340669 | sdb: size = 204800 369s 151.340812 | sdb: vendor = IET 369s 151.340835 | sdb: product = VIRTUAL-DISK 369s 151.340857 | sdb: rev = 0001 369s 151.341512 | sdb: h:b:t:l = 1:0:0:1 369s 151.341881 | sdb: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 369s 151.341885 | sdb: uid_attribute = ID_SERIAL (setting: multipath internal) 369s 151.341888 | sdb: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 369s 151.342031 | sdb: 1024 cyl, 4 heads, 50 sectors/track, start at 0 369s 151.342036 | sdb: vpd_vendor_id = 0 "undef" (setting: multipath internal) 369s 151.342048 | sdb: serial = beaf11 369s 151.342051 | sdb: detect_checker = yes (setting: multipath internal) 369s 151.342077 | sdb checker timeout = 30 s (setting: kernel sysfs) 369s 151.342158 | sdb: path_checker = tur (setting: multipath internal) 369s 151.342216 | sdb: tur state = up 369s 151.342335 | sdc: size = 204800 369s 151.342466 | sdc: vendor = IET 369s 151.342488 | sdc: product = VIRTUAL-DISK 369s 151.342510 | sdc: rev = 0001 369s 151.343174 | sdc: h:b:t:l = 2:0:0:1 369s 151.343527 | sdc: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 369s 151.343531 | sdc: uid_attribute = ID_SERIAL (setting: multipath internal) 369s 151.343533 | sdc: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 369s 151.343672 | sdc: 1024 cyl, 4 heads, 50 sectors/track, start at 0 369s 151.343676 | sdc: vpd_vendor_id = 0 "undef" (setting: multipath internal) 369s 151.343688 | sdc: serial = beaf11 369s 151.343691 | sdc: detect_checker = yes (setting: multipath internal) 369s 151.343717 | sdc checker timeout = 30 s (setting: kernel sysfs) 369s 151.343795 | sdc: path_checker = tur (setting: multipath internal) 369s 151.343845 | sdc: tur state = up 369s 151.343977 | sdd: size = 204800 369s 151.344113 | sdd: vendor = IET 369s 151.344139 | sdd: product = VIRTUAL-DISK 369s 151.344160 | sdd: rev = 0001 369s 151.344822 | sdd: h:b:t:l = 3:0:0:1 369s 151.345149 | sdd: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 369s 151.345153 | sdd: uid_attribute = ID_SERIAL (setting: multipath internal) 369s 151.345155 | sdd: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 369s 151.345288 | sdd: 1024 cyl, 4 heads, 50 sectors/track, start at 0 369s 151.345292 | sdd: vpd_vendor_id = 0 "undef" (setting: multipath internal) 369s 151.345304 | sdd: serial = beaf11 369s 151.345307 | sdd: detect_checker = yes (setting: multipath internal) 369s 151.345333 | sdd checker timeout = 30 s (setting: kernel sysfs) 369s 151.345453 | sdd: path_checker = tur (setting: multipath internal) 369s 151.345508 | sdd: tur state = up 369s 151.345600 | loop0: device node name blacklisted 369s 151.345684 | loop1: device node name blacklisted 369s 151.345777 | loop2: device node name blacklisted 369s 151.345859 | loop3: device node name blacklisted 369s 151.345940 | loop4: device node name blacklisted 369s 151.346020 | loop5: device node name blacklisted 369s 151.346099 | loop6: device node name blacklisted 369s 151.346177 | loop7: device node name blacklisted 369s 151.346261 | dm-0: device node name blacklisted 369s 151.347276 | multipath-tools v0.9.9 (05/03, 2024) 369s 151.347286 | libdevmapper version 1.02.196 369s 151.347426 | kernel device mapper v4.48.0 369s 151.347439 | DM multipath kernel driver v1.14.0 369s 151.347548 | sdb: size = 204800 369s 151.347554 | sdb: vendor = IET 369s 151.347557 | sdb: product = VIRTUAL-DISK 369s 151.347559 | sdb: rev = 0001 369s 151.348195 | sdb: h:b:t:l = 1:0:0:1 369s 151.348313 | sdb: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 369s 151.348333 | sdb: 1024 cyl, 4 heads, 50 sectors/track, start at 0 369s 151.348336 | sdb: vpd_vendor_id = 0 "undef" (setting: multipath internal) 369s 151.348349 | sdb: serial = beaf11 369s 151.348412 | sdb: tur state = up 369s 151.348438 | sdb: uid = 360000000000000000e00000000010001 (udev) 369s 151.348442 | sdb: detect_prio = yes (setting: multipath internal) 369s 151.348446 | sdb: prio = const (setting: multipath internal) 369s 151.348448 | sdb: prio args = "" (setting: multipath internal) 369s 151.348451 | sdb: const prio = 1 369s 151.348476 | sda: size = 204800 369s 151.348482 | sda: vendor = IET 369s 151.348484 | sda: product = VIRTUAL-DISK 369s 151.348487 | sda: rev = 0001 369s 151.349085 | sda: h:b:t:l = 0:0:0:1 369s 151.349198 | sda: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 369s 151.349218 | sda: 1024 cyl, 4 heads, 50 sectors/track, start at 0 369s 151.349221 | sda: vpd_vendor_id = 0 "undef" (setting: multipath internal) 369s 151.349238 | sda: serial = beaf11 369s 151.349362 | sda: tur state = up 369s 151.349368 | sda: uid = 360000000000000000e00000000010001 (udev) 369s 151.349371 | sda: detect_prio = yes (setting: multipath internal) 369s 151.349373 | sda: prio = const (setting: multipath internal) 369s 151.349375 | sda: prio args = "" (setting: multipath internal) 369s 151.349377 | sda: const prio = 1 369s 151.349400 | sdc: size = 204800 369s 151.349405 | sdc: vendor = IET 369s 151.349408 | sdc: product = VIRTUAL-DISK 369s 151.349410 | sdc: rev = 0001 369s 151.350043 | sdc: h:b:t:l = 2:0:0:1 369s 151.350153 | sdc: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 369s 151.350172 | sdc: 1024 cyl, 4 heads, 50 sectors/track, start at 0 369s 151.350174 | sdc: vpd_vendor_id = 0 "undef" (setting: multipath internal) 369s 151.350186 | sdc: serial = beaf11 369s 151.350286 | sdc: tur state = up 369s 151.350290 | sdc: uid = 360000000000000000e00000000010001 (udev) 369s 151.350293 | sdc: detect_prio = yes (setting: multipath internal) 369s 151.350295 | sdc: prio = const (setting: multipath internal) 369s 151.350297 | sdc: prio args = "" (setting: multipath internal) 369s 151.350300 | sdc: const prio = 1 369s 151.350321 | sdd: size = 204800 369s 151.350326 | sdd: vendor = IET 369s 151.350328 | sdd: product = VIRTUAL-DISK 369s 151.350330 | sdd: rev = 0001 369s 151.350916 | sdd: h:b:t:l = 3:0:0:1 369s 151.351022 | sdd: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 369s 151.351040 | sdd: 1024 cyl, 4 heads, 50 sectors/track, start at 0 369s 151.351044 | sdd: vpd_vendor_id = 0 "undef" (setting: multipath internal) 369s 151.351055 | sdd: serial = beaf11 369s 151.351129 | sdd: tur state = up 369s 151.351134 | sdd: uid = 360000000000000000e00000000010001 (udev) 369s 151.351136 | sdd: detect_prio = yes (setting: multipath internal) 369s 151.351139 | sdd: prio = const (setting: multipath internal) 369s 151.351141 | sdd: prio args = "" (setting: multipath internal) 369s 151.351143 | sdd: const prio = 1 369s 151.351866 | unloading tur checker 369s 151.351897 | unloading const prioritizer 369s + dmsetup table 369s + grep . /etc/multipath/bindings /etc/multipath/wwids 369s ===== paths list ===== 369s uuid hcil dev dev_t pri dm_st chk_st vend/prod/rev dev_st 369s 0:0:0:1 sda 8:0 -1 undef undef IET,VIRTUAL-DISK,0001 unknown 369s 1:0:0:1 sdb 8:16 -1 undef undef IET,VIRTUAL-DISK,0001 unknown 369s 2:0:0:1 sdc 8:32 -1 undef undef IET,VIRTUAL-DISK,0001 unknown 369s 3:0:0:1 sdd 8:48 -1 undef undef IET,VIRTUAL-DISK,0001 unknown 369s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 369s size=100M features='0' hwhandler='0' wp=rw 369s |-+- policy='service-time 0' prio=1 status=active 369s | `- 1:0:0:1 sdb 8:16 active ready running 369s |-+- policy='service-time 0' prio=1 status=enabled 369s | `- 0:0:0:1 sda 8:0 active ready running 369s |-+- policy='service-time 0' prio=1 status=enabled 369s | `- 2:0:0:1 sdc 8:32 active ready running 369s `-+- policy='service-time 0' prio=1 status=enabled 369s `- 3:0:0:1 sdd 8:48 active ready running 369s mpatha: 0 204800 multipath 0 0 4 1 service-time 0 1 2 8:16 1 1 service-time 0 1 2 8:0 1 1 service-time 0 1 2 8:32 1 1 service-time 0 1 2 8:48 1 1 369s + systemctl status multipathd.service 369s + systemctl status multipathd.socket 369s + ls -la /dev/mapper/ 369s + echo journal 369s + journalctl -b 369s /etc/multipath/bindings:# Multipath bindings, Version : 1.0 369s /etc/multipath/bindings:# NOTE: this file is automatically maintained by the multipath program. 369s /etc/multipath/bindings:# You should not need to edit this file in normal circumstances. 369s /etc/multipath/bindings:# 369s /etc/multipath/bindings:# Format: 369s /etc/multipath/bindings:# alias wwid 369s /etc/multipath/bindings:# 369s /etc/multipath/bindings:mpatha 360000000000000000e00000000010001 369s /etc/multipath/wwids:/360000000000000000e00000000010001/ 369s ● multipathd.service - Device-Mapper Multipath Device Controller 369s Loaded: loaded (/usr/lib/systemd/system/multipathd.service; enabled; preset: enabled) 369s Active: active (running) since Thu 2024-08-22 00:17:47 UTC; 2min 29s ago 369s Invocation: d74ea0b33332406293ebf80499de71b7 369s TriggeredBy: ● multipathd.socket 369s Main PID: 328 (multipathd) 369s Status: "up" 369s Tasks: 7 369s Memory: 28.2M (peak: 36.6M) 369s CPU: 53ms 369s CGroup: /system.slice/multipathd.service 369s └─328 /sbin/multipathd -d -s 369s 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i multipathd[328]: multipathd v0.9.9: start up 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i multipathd[328]: reconfigure: setting up paths and maps 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 369s Aug 22 00:20:11 autopkgtest multipathd[328]: updated bindings file /etc/multipath/bindings 369s Aug 22 00:20:11 autopkgtest multipathd[328]: mpatha: addmap [0 204800 multipath 0 0 1 1 service-time 0 1 1 8:16 1] 369s Aug 22 00:20:11 autopkgtest multipathd[328]: sdb [8:16]: path added to devmap mpatha 369s Aug 22 00:20:11 autopkgtest multipathd[328]: mpatha: performing delayed actions 369s Aug 22 00:20:11 autopkgtest multipathd[328]: mpatha: reload [0 204800 multipath 0 0 4 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:48 1] 369s ● multipathd.socket - multipathd control socket 369s Loaded: loaded (/usr/lib/systemd/system/multipathd.socket; enabled; preset: enabled) 369s Active: active (running) since Thu 2024-08-22 00:17:47 UTC; 2min 29s ago 369s Invocation: 1c0846e2ad2a4fde9f11d087e9c7c64b 369s Triggers: ● multipathd.service 369s Listen: @/org/kernel/linux/storage/multipathd (Stream) 369s CGroup: /system.slice/multipathd.socket 369s 369s Notice: journal has been rotated since unit was started, output may be incomplete. 369s total 0 369s drwxr-xr-x 2 root root 80 Aug 22 00:20 . 369s drwxr-xr-x 20 root root 4360 Aug 22 00:20 .. 369s crw------- 1 root root 10, 236 Aug 22 00:17 control 369s lrwxrwxrwx 1 root root 7 Aug 22 00:20 mpatha -> ../dm-0 369s journal 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: radix-mmu: Page sizes from device-tree: 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: radix-mmu: Page size shift = 12 AP=0x0 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: radix-mmu: Page size shift = 16 AP=0x5 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: radix-mmu: Page size shift = 21 AP=0x1 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: radix-mmu: Page size shift = 30 AP=0x2 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Activating Kernel Userspace Access Prevention 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Activating Kernel Userspace Execution Prevention 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: radix-mmu: Mapped 0x0000000000000000-0x00000000038a0000 with 64.0 KiB pages (exec) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: radix-mmu: Mapped 0x00000000038a0000-0x0000000200000000 with 64.0 KiB pages 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: lpar: Using radix MMU under hypervisor 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Linux version 6.8.0-31-generic (buildd@bos02-ppc64el-018) (powerpc64le-linux-gnu-gcc-13 (Ubuntu 13.2.0-23ubuntu4) 13.2.0, GNU ld (GNU Binutils for Ubuntu) 2.42) #31-Ubuntu SMP Sat Apr 20 00:05:55 UTC 2024 (Ubuntu 6.8.0-31.31-generic 6.8.1) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Secure boot mode disabled 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Found initrd at 0xc000000006200000:0xc0000000094f4fe3 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Hardware name: IBM pSeries (emulated by qemu) POWER9 (raw) 0x4e1203 0xf000005 of:SLOF,HEAD hv:linux,kvm pSeries 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Partition configured for 4 cpus. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: CPU maps initialized for 1 thread per core 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: (thread shift is 0) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Allocated 3360 bytes for 4 pacas 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: numa: Partition configured for 1 NUMA nodes. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: ----------------------------------------------------- 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: phys_mem_size = 0x200000000 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: dcache_bsize = 0x80 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: icache_bsize = 0x80 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: cpu_features = 0x0001c06b8f4f9187 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: possible = 0x001ffbfbcf5fb187 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: always = 0x0000000380008181 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: cpu_user_features = 0xdc0065c2 0xaef00000 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: mmu_features = 0x3c007641 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: firmware_features = 0x00000285455a445f 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: vmalloc start = 0xc008000000000000 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: IO start = 0xc00a000000000000 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: vmemmap start = 0xc00c000000000000 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: ----------------------------------------------------- 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: numa: NODE_DATA [mem 0x1eff0c280-0x1eff13fff] 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: rfi-flush: fallback displacement flush available 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: rfi-flush: ori type flush available 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: rfi-flush: mttrig type flush available 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: rfi-flush: patched 12 locations (ori+mttrig type flush) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: count-cache-flush: hardware flush enabled. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: link-stack-flush: software flush enabled. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: entry-flush: patched 61 locations (ori+mttrig type flush) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: uaccess-flush: patched 1 locations (ori+mttrig type flush) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: stf-barrier: eieio barrier available 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: stf-barrier: patched 61 entry locations (eieio barrier) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: stf-barrier: patched 12 exit locations (eieio barrier) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: PPC64 nvram contains 65536 bytes 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: barrier-nospec: using ORI speculation barrier 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: barrier-nospec: patched 269 locations 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Top of RAM: 0x200000000, Total RAM: 0x200000000 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Memory hole size: 0MB 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Zone ranges: 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Normal [mem 0x0000000000000000-0x00000001ffffffff] 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Device empty 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Movable zone start for each node 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Early memory node ranges 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: node 0: [mem 0x0000000000000000-0x00000001ffffffff] 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Initmem setup node 0 [mem 0x0000000000000000-0x00000001ffffffff] 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: percpu: Embedded 12 pages/cpu s609960 r0 d176472 u786432 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pcpu-alloc: s609960 r0 d176472 u786432 alloc=12*65536 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Kernel command line: BOOT_IMAGE=/boot/vmlinux-6.8.0-31-generic root=UUID=55f4738b-dbc7-4aef-90fe-6bd3178557bc ro console=hvc0 earlyprintk 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Unknown kernel command line parameters "earlyprintk BOOT_IMAGE=/boot/vmlinux-6.8.0-31-generic", will be passed to user space. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Dentry cache hash table entries: 1048576 (order: 7, 8388608 bytes, linear) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Inode-cache hash table entries: 524288 (order: 6, 4194304 bytes, linear) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Fallback order for Node 0: 0 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Built 1 zonelists, mobility grouping on. Total pages: 130944 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Policy zone: Normal 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: mem auto-init: stack:all(zero), heap alloc:on, heap free:off 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Memory: 7968064K/8388608K available (23680K kernel code, 4096K rwdata, 25472K rodata, 8832K init, 1901K bss, 420544K reserved, 0K cma-reserved) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: SLUB: HWalign=128, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: ftrace: allocating 51717 entries in 19 pages 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: ftrace: allocated 19 pages with 3 groups 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: trace event string verifier disabled 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: rcu: Hierarchical RCU implementation. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: rcu: RCU restricting CPUs from NR_CPUS=2048 to nr_cpu_ids=4. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Rude variant of Tasks RCU enabled. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Tracing variant of Tasks RCU enabled. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: NR_IRQS: 512, nr_irqs: 512, preallocated irqs: 16 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: xive: Using IRQ range [0-3] 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: xive: Interrupt handling initialized with spapr backend 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: xive: Using priority 6 for all interrupts 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: xive: Using 64kB queues 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: rcu: srcu_init: Setting srcu_struct sizes based on contention. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: time_init: decrementer frequency = 512.000000 MHz 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: time_init: processor frequency = 2700.000000 MHz 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: time_init: 56 bit decrementer (max: 7fffffffffffff) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: clocksource: timebase: mask: 0xffffffffffffffff max_cycles: 0x761537d007, max_idle_ns: 440795202126 ns 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: clocksource: timebase mult[1f40000] shift[24] registered 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: clockevent: decrementer mult[83126f] shift[24] cpu[0] 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Console: colour dummy device 80x25 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pid_max: default: 32768 minimum: 301 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: LSM: initializing lsm=lockdown,capability,landlock,yama,apparmor,integrity 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: landlock: Up and running. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Yama: becoming mindful. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: AppArmor: AppArmor initialized 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Mount-cache hash table entries: 16384 (order: 1, 131072 bytes, linear) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Mountpoint-cache hash table entries: 16384 (order: 1, 131072 bytes, linear) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: RCU Tasks Rude: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: RCU Tasks Trace: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: POWER9 performance monitor hardware support registered 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: rcu: Hierarchical SRCU implementation. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: rcu: Max phase no-delay instances is 1000. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: smp: Bringing up secondary CPUs ... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: smp: Brought up 1 node, 4 CPUs 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: numa: Node 0 CPUs: 0-3 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: devtmpfs: initialized 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: PCI host bridge /pci@800000020000000 ranges: 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: IO 0x0000200000000000..0x000020000000ffff -> 0x0000000000000000 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: MEM 0x0000200080000000..0x00002000ffffffff -> 0x0000000080000000 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: MEM 0x0000210000000000..0x000021ffffffffff -> 0x0000210000000000 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: PCI: OF: PROBE_ONLY disabled 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: futex hash table entries: 1024 (order: 1, 131072 bytes, linear) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pinctrl core: initialized pinctrl subsystem 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: NET: Registered PF_NETLINK/PF_ROUTE protocol family 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: audit: initializing netlink subsys (disabled) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: audit: type=2000 audit(1724285865.040:1): state=initialized audit_enabled=0 res=1 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: thermal_sys: Registered thermal governor 'fair_share' 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: thermal_sys: Registered thermal governor 'bang_bang' 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: thermal_sys: Registered thermal governor 'step_wise' 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: thermal_sys: Registered thermal governor 'user_space' 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: thermal_sys: Registered thermal governor 'power_allocator' 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: cpuidle: using governor ladder 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: cpuidle: using governor menu 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: RTAS daemon started 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pstore: Using crash dump compression: deflate 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pstore: Registered nvram as persistent store backend 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: EEH: pSeries platform initialized 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: iommu: Default domain type: Translated 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: iommu: DMA domain TLB invalidation policy: strict mode 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: SCSI subsystem initialized 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: libata version 3.00 loaded. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usbcore: registered new interface driver usbfs 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usbcore: registered new interface driver hub 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usbcore: registered new device driver usb 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pps_core: LinuxPPS API ver. 1 registered 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: PTP clock support registered 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: EDAC MC: Ver: 3.0.0 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: NetLabel: Initializing 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: NetLabel: domain hash size = 128 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: NetLabel: unlabeled traffic allowed by default 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: mctp: management component transport protocol core 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: NET: Registered PF_MCTP protocol family 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: PCI: Probing PCI hardware 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: PCI host bridge to bus 0000:00 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pci_bus 0000:00: root bus resource [io 0x10000-0x1ffff] (bus address [0x0000-0xffff]) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pci_bus 0000:00: root bus resource [mem 0x200080000000-0x2000ffffffff] (bus address [0x80000000-0xffffffff]) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pci_bus 0000:00: root bus resource [mem 0x210000000000-0x21ffffffffff 64bit] 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pci_bus 0000:00: root bus resource [bus 00-ff] 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pci 0000:00:01.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pci 0000:00:02.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pci 0000:00:03.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pci 0000:00:04.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pci 0000:00:05.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pci 0000:00:06.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pci 0000:00:07.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: IOMMU table initialized, virtual merging enabled 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: PCI 0000:00 Cannot reserve Legacy IO [io 0x10000-0x10fff] 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pci_bus 0000:00: resource 4 [io 0x10000-0x1ffff] 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pci_bus 0000:00: resource 5 [mem 0x200080000000-0x2000ffffffff] 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pci_bus 0000:00: resource 6 [mem 0x210000000000-0x21ffffffffff 64bit] 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pci 0000:00:01.0: Adding to iommu group 0 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pci 0000:00:02.0: Adding to iommu group 0 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pci 0000:00:03.0: Adding to iommu group 0 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pci 0000:00:04.0: Adding to iommu group 0 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pci 0000:00:05.0: Adding to iommu group 0 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pci 0000:00:06.0: Adding to iommu group 0 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pci 0000:00:07.0: Adding to iommu group 0 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: EEH: No capable adapters found: recovery disabled. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: PCI: Probing PCI hardware done 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pci 0000:00:07.0: vgaarb: setting as boot VGA device 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pci 0000:00:07.0: vgaarb: bridge control possible 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pci 0000:00:07.0: vgaarb: VGA device added: decodes=io+mem,owns=mem,locks=none 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: vgaarb: loaded 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: clocksource: Switched to clocksource timebase 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: VFS: Disk quotas dquot_6.6.0 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: VFS: Dquot-cache hash table entries: 8192 (order 0, 65536 bytes) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: AppArmor: AppArmor Filesystem Enabled 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: NET: Registered PF_INET protocol family 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: IP idents hash table entries: 131072 (order: 4, 1048576 bytes, linear) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: tcp_listen_portaddr_hash hash table entries: 4096 (order: 0, 65536 bytes, linear) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Table-perturb hash table entries: 65536 (order: 2, 262144 bytes, linear) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: TCP established hash table entries: 65536 (order: 3, 524288 bytes, linear) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: TCP bind hash table entries: 65536 (order: 5, 2097152 bytes, linear) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: TCP: Hash tables configured (established 65536 bind 65536) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: MPTCP token hash table entries: 8192 (order: 1, 196608 bytes, linear) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: UDP hash table entries: 4096 (order: 1, 131072 bytes, linear) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: UDP-Lite hash table entries: 4096 (order: 1, 131072 bytes, linear) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: NET: Registered PF_UNIX/PF_LOCAL protocol family 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: NET: Registered PF_XDP protocol family 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: PCI: CLS 0 bytes, default 128 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Trying to unpack rootfs image as initramfs... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Initialise system trusted keyrings 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Key type blacklist registered 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: workingset: timestamp_bits=38 max_order=17 bucket_order=0 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: zbud: loaded 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: fuse: init (API version 7.39) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: integrity: Platform Keyring initialized 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: integrity: Machine keyring initialized 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Key type asymmetric registered 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Asymmetric key parser 'x509' registered 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 243) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: io scheduler mq-deadline registered 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: virtio-pci 0000:00:01.0: enabling device (0100 -> 0103) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-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 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-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) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: virtio-pci 0000:00:03.0: enabling device (0100 -> 0103) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: virtio-pci 0000:00:04.0: enabling device (0100 -> 0103) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: virtio-pci 0000:00:05.0: enabling device (0100 -> 0103) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: virtio-pci 0000:00:06.0: enabling device (0100 -> 0103) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: printk: legacy console [hvc0] enabled 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Freeing initrd memory: 52160K 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Non-volatile memory driver v1.3 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Linux agpgart interface v0.103 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: loop: module loaded 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: virtio_blk virtio2: 4/0/0 default/read/poll queues 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: virtio_blk virtio2: [vda] 209715200 512-byte logical blocks (107 GB/100 GiB) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: GPT:Primary header thinks Alt. header is not at the end of the disk. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: GPT:41943039 != 209715199 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: GPT:Alternate GPT header not at the end of the disk. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: GPT:41943039 != 209715199 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: GPT: Use GNU Parted to correct GPT errors. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: vda: vda1 vda2 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: tun: Universal TUN/TAP device driver, 1.6 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: PPP generic driver version 2.4.2 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: mousedev: PS/2 mouse device common for all mice 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: rtc-generic rtc-generic: registered as rtc0 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: rtc-generic rtc-generic: setting system clock to 2024-08-22T00:17:45 UTC (1724285865) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: i2c_dev: i2c /dev entries driver 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: device-mapper: uevent: version 1.0.3 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@redhat.com 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: pseries_idle_driver registered 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: ledtrig-cpu: registered to indicate activity on CPUs 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: drop_monitor: Initializing network drop monitor service 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: NET: Registered PF_INET6 protocol family 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Segment Routing with IPv6 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: In-situ OAM (IOAM) with IPv6 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: NET: Registered PF_PACKET protocol family 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Key type dns_resolver registered 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: secvar-sysfs: Failed to retrieve secvar operations 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: drmem: No dynamic reconfiguration memory found 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: registered taskstats version 1 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Loading compiled-in X.509 certificates 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Loaded X.509 cert 'Build time autogenerated kernel key: d20be259617023e52b002c562b3536c6f73da543' 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Live Patch Signing: 14df34d1a87cf37625abec039ef2bf521249b969' 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Kernel Module Signing: 88f752e560a1e0737e31163a466ad7b70a850c19' 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: blacklist: Loading compiled-in revocation X.509 certificates 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing: 61482aa2830d0ab2ad5af10b7250da9033ddcef0' 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2017): 242ade75ac4a15e50d50c84b0d45ff3eae707a03' 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (ESM 2018): 365188c1d374d6b07c3c8f240f8ef722433d6a8b' 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2019): c0746fd6c5da3ae827864651ad66ae47fe24b3e8' 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2021 v1): a8d54bbb3825cfb94fa13c9f8a594a195c107b8d' 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2021 v2): 4cf046892d6fd3c9a5b03f98d845f90851dc6a8c' 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2021 v3): 100437bb6de6e469b581e61cd66bce3ef4ed53af' 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (Ubuntu Core 2019): c1d57b8f6b743f23ee41f4f7ee292f06eecadfb9' 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Key type .fscrypt registered 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Key type fscrypt-provisioning registered 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Key type encrypted registered 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: AppArmor: AppArmor sha256 policy hashing enabled 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Secure boot mode disabled 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: ima: No TPM chip found, activating TPM-bypass! 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Loading compiled-in module X.509 certificates 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Loaded X.509 cert 'Build time autogenerated kernel key: d20be259617023e52b002c562b3536c6f73da543' 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: ima: Allocated hash algorithm: sha256 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Secure boot mode disabled 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Trusted boot mode disabled 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: ima: No architecture policies found 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: evm: Initialising EVM extended attributes: 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: evm: security.selinux 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: evm: security.SMACK64 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: evm: security.SMACK64EXEC 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: evm: security.SMACK64TRANSMUTE 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: evm: security.SMACK64MMAP 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: evm: security.apparmor 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: evm: security.ima 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: evm: security.capability 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: evm: HMAC attrs: 0x1 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: SED: plpks not available 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: clk: Disabling unused clocks 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: integrity: Unable to open file: /etc/keys/x509_evm.der (-2) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Freeing unused kernel image (initmem) memory: 8832K 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Checked W+X mappings: passed, no W+X pages found 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Run /init as init process 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: with arguments: 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: /init 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: earlyprintk 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: with environment: 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: HOME=/ 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: TERM=linux 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: BOOT_IMAGE=/boot/vmlinux-6.8.0-31-generic 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: virtio_net virtio0 enp0s1: renamed from eth0 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: xhci_hcd 0000:00:02.0: xHCI Host Controller 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: xhci_hcd 0000:00:02.0: new USB bus registered, assigned bus number 1 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: xhci_hcd 0000:00:02.0: hcc params 0x00087001 hci version 0x100 quirks 0x0000000000000010 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: random: crng init done 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: xhci_hcd 0000:00:02.0: xHCI Host Controller 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: xhci_hcd 0000:00:02.0: new USB bus registered, assigned bus number 2 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: xhci_hcd 0000:00:02.0: Host supports USB 3.0 SuperSpeed 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.08 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usb usb1: Product: xHCI Host Controller 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usb usb1: Manufacturer: Linux 6.8.0-31-generic xhci-hcd 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usb usb1: SerialNumber: 0000:00:02.0 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: hub 1-0:1.0: USB hub found 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: hub 1-0:1.0: 4 ports detected 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usb usb2: We don't know the algorithms for LPM for this host, disabling LPM. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 6.08 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usb usb2: Product: xHCI Host Controller 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usb usb2: Manufacturer: Linux 6.8.0-31-generic xhci-hcd 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usb usb2: SerialNumber: 0000:00:02.0 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: hub 2-0:1.0: USB hub found 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: hub 2-0:1.0: 4 ports detected 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: [drm] Found bochs VGA, ID 0xb0c5. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: [drm] Framebuffer size 16384 kB @ 0x200081000000, mmio @ 0x200082000000. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: [drm] Found EDID data blob. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: [drm] Initialized bochs-drm 1.0.0 20130925 for 0000:00:07.0 on minor 0 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: fbcon: Deferring console take-over 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: bochs-drm 0000:00:07.0: [drm] fb0: bochs-drmdrmfb frame buffer device 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: raid6: vpermxor8 gen() 22810 MB/s 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: raid6: vpermxor4 gen() 19646 MB/s 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usb 1-1: new high-speed USB device number 2 using xhci_hcd 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: raid6: vpermxor2 gen() 15837 MB/s 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: raid6: vpermxor1 gen() 13628 MB/s 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usb 1-1: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usb 1-1: New USB device strings: Mfr=1, Product=4, SerialNumber=11 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usb 1-1: Product: QEMU USB Keyboard 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usb 1-1: Manufacturer: QEMU 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usb 1-1: SerialNumber: 68284-pci@800000020000000:02.0-1 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: hid: raw HID events driver (C) Jiri Kosina 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usbcore: registered new interface driver usbhid 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usbhid: USB HID core driver 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-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 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: raid6: altivecx8 gen() 14003 MB/s 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-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 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: raid6: altivecx4 gen() 13763 MB/s 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usb 1-2: new high-speed USB device number 3 using xhci_hcd 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: raid6: altivecx2 gen() 11208 MB/s 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: raid6: altivecx1 gen() 8320 MB/s 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usb 1-2: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=9 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usb 1-2: Product: QEMU USB Mouse 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usb 1-2: Manufacturer: QEMU 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: usb 1-2: SerialNumber: 89126-pci@800000020000000:02.0-2 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-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 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-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 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: raid6: int64x8 gen() 6169 MB/s 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: raid6: int64x4 gen() 7916 MB/s 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: raid6: int64x2 gen() 6234 MB/s 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: raid6: int64x1 gen() 5003 MB/s 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: raid6: using algorithm vpermxor8 gen() 22810 MB/s 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: raid6: using intx1 recovery algorithm 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: xor: measuring software checksum speed 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: 8regs : 17923 MB/sec 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: 8regs_prefetch : 16003 MB/sec 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: 32regs : 17902 MB/sec 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: 32regs_prefetch : 16181 MB/sec 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: altivec : 19977 MB/sec 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: xor: using function: altivec (19977 MB/sec) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Btrfs loaded, zoned=yes, fsverity=yes 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: EXT4-fs (vda1): orphan cleanup on readonly fs 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: EXT4-fs (vda1): mounted filesystem 55f4738b-dbc7-4aef-90fe-6bd3178557bc ro with ordered data mode. Quota mode: none. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Inserted module 'autofs4' 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: systemd 256.4-2ubuntu1 running in system mode (+PAM +AUDIT +SELINUX +APPARMOR +IMA +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -XKBCOMMON +UTMP +SYSVINIT +LIBARCHIVE) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Detected virtualization kvm. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Detected architecture ppc64-le. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Hostname set to . 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: bpf-restrict-fs: BPF LSM hook not enabled in the kernel, BPF LSM not supported. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: NET: Registered PF_VSOCK protocol family 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-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. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-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. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Queued start job for default target graphical.target. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Created slice system-autopkgtest.slice - Slice /system/autopkgtest. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Created slice system-modprobe.slice - Slice /system/modprobe. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Created slice system-serial\x2dgetty.slice - Slice /system/serial-getty. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Created slice user.slice - User and Session Slice. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Started systemd-ask-password-wall.path - Forward Password Requests to Wall Directory Watch. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Set up automount proc-sys-fs-binfmt_misc.automount - Arbitrary Executable File Formats File System Automount Point. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Expecting device dev-hvc0.device - /dev/hvc0... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Reached target integritysetup.target - Local Integrity Protected Volumes. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Reached target remote-fs.target - Remote File Systems. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Reached target slices.target - Slice Units. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Reached target swap.target - Swaps. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Reached target veritysetup.target - Local Verity Protected Volumes. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Listening on multipathd.socket - multipathd control socket. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Listening on syslog.socket - Syslog Socket. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Listening on systemd-creds.socket - Credential Encryption/Decryption. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Listening on systemd-fsckd.socket - fsck to fsckd communication Socket. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Listening on systemd-initctl.socket - initctl Compatibility Named Pipe. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Listening on systemd-journald-dev-log.socket - Journal Socket (/dev/log). 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Listening on systemd-journald.socket - Journal Sockets. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Listening on systemd-networkd.socket - Network Service Netlink Socket. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Listening on systemd-udevd-control.socket - udev Control Socket. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Listening on systemd-udevd-kernel.socket - udev Kernel Socket. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Mounting dev-hugepages.mount - Huge Pages File System... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Mounting dev-mqueue.mount - POSIX Message Queue File System... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Mounting run-lock.mount - Legacy Locks Directory /run/lock... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Mounting sys-kernel-debug.mount - Kernel Debug File System... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Mounting sys-kernel-tracing.mount - Kernel Trace File System... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting systemd-journald.service - Journal Service... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting keyboard-setup.service - Set the console keyboard layout... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting kmod-static-nodes.service - Create List of Static Device Nodes... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting modprobe@configfs.service - Load Kernel Module configfs... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting modprobe@dm_multipath.service - Load Kernel Module dm_multipath... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting modprobe@drm.service - Load Kernel Module drm... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting modprobe@fuse.service - Load Kernel Module fuse... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-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). 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-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). 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-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). 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting systemd-modules-load.service - Load Kernel Modules... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting systemd-remount-fs.service - Remount Root and Kernel File Systems... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting systemd-udev-load-credentials.service - Load udev Rules from Credentials... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting systemd-udev-trigger.service - Coldplug All udev Devices... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Mounted dev-hugepages.mount - Huge Pages File System. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Mounted dev-mqueue.mount - POSIX Message Queue File System. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Mounted run-lock.mount - Legacy Locks Directory /run/lock. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Mounted sys-kernel-debug.mount - Kernel Debug File System. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Mounted sys-kernel-tracing.mount - Kernel Trace File System. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd-journald[281]: Collecting audit messages is disabled. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Finished kmod-static-nodes.service - Create List of Static Device Nodes. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: modprobe@configfs.service: Deactivated successfully. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Finished modprobe@configfs.service - Load Kernel Module configfs. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: modprobe@dm_multipath.service: Deactivated successfully. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Finished modprobe@dm_multipath.service - Load Kernel Module dm_multipath. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: modprobe@drm.service: Deactivated successfully. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Finished modprobe@drm.service - Load Kernel Module drm. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: modprobe@fuse.service: Deactivated successfully. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Finished modprobe@fuse.service - Load Kernel Module fuse. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Finished systemd-modules-load.service - Load Kernel Modules. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Finished systemd-udev-load-credentials.service - Load udev Rules from Credentials. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: EXT4-fs (vda1): re-mounted 55f4738b-dbc7-4aef-90fe-6bd3178557bc r/w. Quota mode: none. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Mounting sys-fs-fuse-connections.mount - FUSE Control File System... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Mounting sys-kernel-config.mount - Kernel Configuration File System... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd-journald[281]: Journal started 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd-journald[281]: Runtime Journal (/run/log/journal/5fbf7c16e2c0466eb586813a84147576) is 8M, max 78.4M, 70.4M free. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting systemd-sysctl.service - Apply Kernel Variables... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Finished keyboard-setup.service - Set the console keyboard layout. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Finished systemd-remount-fs.service - Remount Root and Kernel File Systems. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Started systemd-journald.service - Journal Service. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Mounted sys-fs-fuse-connections.mount - FUSE Control File System. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Mounted sys-kernel-config.mount - Kernel Configuration File System. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting cloud-init-main.service - Cloud-init: Single Process... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: systemd-hwdb-update.service - Rebuild Hardware Database was skipped because of an unmet condition check (ConditionNeedsUpdate=/etc). 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting systemd-journal-flush.service - Flush Journal to Persistent Storage... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore). 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting systemd-random-seed.service - Load/Save OS Random Seed... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Finished systemd-sysctl.service - Apply Kernel Variables. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Finished systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd-journald[281]: Time spent on flushing to /var/log/journal/5fbf7c16e2c0466eb586813a84147576 is 21.544ms for 465 entries. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd-journald[281]: System Journal (/var/log/journal/5fbf7c16e2c0466eb586813a84147576) is 19.1M, max 1.9G, 1.9G free. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd-journald[281]: Received client request to flush runtime journal. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: systemd-sysusers.service - Create System Users was skipped because no trigger condition checks were met. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i multipathd[328]: multipathd v0.9.9: start up 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i multipathd[328]: reconfigure: setting up paths and maps 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Finished systemd-udev-trigger.service - Coldplug All udev Devices. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Finished systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting systemd-udevd.service - Rule-based Manager for Device Events and Files... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Reached target local-fs-pre.target - Preparation for Local File Systems. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Reached target local-fs.target - Local File Systems. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Listening on systemd-sysext.socket - System Extension Image Management. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting apparmor.service - Load AppArmor profiles... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting console-setup.service - Set console font and keymap... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: ldconfig.service - Rebuild Dynamic Linker Cache was skipped because no trigger condition checks were met. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting plymouth-read-write.service - Tell Plymouth To Write Out Runtime Data... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting systemd-binfmt.service - Set Up Additional Binary Formats... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting ufw.service - Uncomplicated firewall... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Finished systemd-journal-flush.service - Flush Journal to Persistent Storage. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Finished systemd-random-seed.service - Load/Save OS Random Seed. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Finished console-setup.service - Set console font and keymap. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting systemd-tmpfiles-setup.service - Create System Files and Directories... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i apparmor.systemd[351]: Restarting AppArmor 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: proc-sys-fs-binfmt_misc.automount: Got automount request for /proc/sys/fs/binfmt_misc, triggered by 355 (systemd-binfmt) 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Mounting proc-sys-fs-binfmt_misc.mount - Arbitrary Executable File Formats File System... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd-tmpfiles[364]: /usr/lib/tmpfiles.d/legacy.conf:13: Duplicate line for path "/run/lock", ignoring. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i apparmor.systemd[351]: Reloading AppArmor profiles 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Finished ufw.service - Uncomplicated firewall. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Finished plymouth-read-write.service - Tell Plymouth To Write Out Runtime Data. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Mounted proc-sys-fs-binfmt_misc.mount - Arbitrary Executable File Formats File System. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Finished systemd-binfmt.service - Set Up Additional Binary Formats. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Finished systemd-tmpfiles-setup.service - Create System Files and Directories. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: systemd-firstboot.service - First Boot Wizard was skipped because of an unmet condition check (ConditionFirstBoot=yes). 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: first-boot-complete.target - First Boot Complete was skipped because of an unmet condition check (ConditionFirstBoot=yes). 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: systemd-journal-catalog-update.service - Rebuild Journal Catalog was skipped because of an unmet condition check (ConditionNeedsUpdate=/var). 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-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). 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting systemd-resolved.service - Network Name Resolution... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: audit: type=1400 audit(1724285867.592:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="Discord" pid=380 comm="apparmor_parser" 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: audit: type=1400 audit(1724285867.592:3): apparmor="STATUS" operation="profile_load" profile="unconfined" name="1password" pid=379 comm="apparmor_parser" 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: audit: type=1400 audit(1724285867.592:4): apparmor="STATUS" operation="profile_load" profile="unconfined" name=4D6F6E676F444220436F6D70617373 pid=381 comm="apparmor_parser" 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: audit: type=1400 audit(1724285867.592:5): apparmor="STATUS" operation="profile_load" profile="unconfined" name="QtWebEngineProcess" pid=382 comm="apparmor_parser" 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting systemd-timesyncd.service - Network Time Synchronization... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: systemd-update-done.service - Update is Completed was skipped because no trigger condition checks were met. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: audit: type=1400 audit(1724285867.596:6): apparmor="STATUS" operation="profile_load" profile="unconfined" name="brave" pid=388 comm="apparmor_parser" 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: audit: type=1400 audit(1724285867.600:7): apparmor="STATUS" operation="profile_load" profile="unconfined" name="balena-etcher" pid=386 comm="apparmor_parser" 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting systemd-update-utmp.service - Record System Boot/Shutdown in UTMP... 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: audit: type=1400 audit(1724285867.600:8): apparmor="STATUS" operation="profile_load" profile="unconfined" name="busybox" pid=390 comm="apparmor_parser" 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: audit: type=1400 audit(1724285867.604:9): apparmor="STATUS" operation="profile_load" profile="unconfined" name="buildah" pid=389 comm="apparmor_parser" 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: audit: type=1400 audit(1724285867.604:10): apparmor="STATUS" operation="profile_load" profile="unconfined" name="cam" pid=392 comm="apparmor_parser" 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Finished systemd-update-utmp.service - Record System Boot/Shutdown in UTMP. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd-udevd[349]: Using default interface naming scheme 'v255'. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Started systemd-udevd.service - Rule-based Manager for Device Events and Files. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: plymouth-start.service - Show Plymouth Boot Screen was skipped because of an unmet condition check (ConditionKernelCommandLine=splash). 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Started systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-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). 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Reached target cryptsetup.target - Local Encrypted Volumes. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd-resolved[384]: Positive Trust Anchors: 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd-resolved[384]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd-resolved[384]: Negative trust anchors: home.arpa 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 170.0.0.192.in-addr.arpa 171.0.0.192.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa ipv4only.arpa resolver.arpa corp home internal intranet lan local private test 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Started systemd-timesyncd.service - Network Time Synchronization. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Reached target time-set.target - System Time Set. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd-resolved[384]: Using system hostname 'auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i'. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Started systemd-resolved.service - Network Name Resolution. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Reached target nss-lookup.target - Host and Network Name Lookups. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Found device dev-hvc0.device - /dev/hvc0. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Finished apparmor.service - Load AppArmor profiles. 369s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Listening on systemd-rfkill.socket - Load/Save RF Kill Switch Status /dev/rfkill Watch. 369s Aug 22 00:17:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Started cloud-init-main.service - Cloud-init: Single Process. 369s Aug 22 00:17:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting cloud-init-local.service - Cloud-init: Local Stage (pre-network)... 369s Aug 22 00:17:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i cloud-init[686]: Cloud-init v. 24.4~2g2e4c39b7-0ubuntu1 running 'init-local' at Thu, 22 Aug 2024 00:17:48 +0000. Up 3.02 seconds. 369s Aug 22 00:17:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i dhcpcd[689]: dhcpcd-10.0.8 starting 369s Aug 22 00:17:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i dhcpcd[692]: DUID 00:01:00:01:2e:58:5c:20:fa:16:3e:40:66:3a 369s Aug 22 00:17:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: 8021q: 802.1Q VLAN Support v1.8 369s Aug 22 00:17:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: 8021q: adding VLAN 0 to HW filter on device enp0s1 369s Aug 22 00:17:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database 369s Aug 22 00:17:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' 369s Aug 22 00:17:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i kernel: Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600' 369s Aug 22 00:17:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i dhcpcd[692]: enp0s1: IAID 3e:a1:70:e4 369s Aug 22 00:17:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i dhcpcd[692]: enp0s1: soliciting a DHCP lease 369s Aug 22 00:17:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i dhcpcd[692]: enp0s1: offered 10.145.227.145 from 10.145.227.1 369s Aug 22 00:17:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i dhcpcd[692]: enp0s1: leased 10.145.227.145 for 43200 seconds 369s Aug 22 00:17:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i dhcpcd[692]: enp0s1: adding route to 10.145.227.0/24 369s Aug 22 00:17:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i dhcpcd[692]: enp0s1: adding host route to 169.254.169.254 via 10.145.227.2 369s Aug 22 00:17:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i dhcpcd[692]: enp0s1: adding default route via 10.145.227.1 369s Aug 22 00:17:48 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i dhcpcd[692]: control command: /usr/sbin/dhcpcd --dumplease --ipv4only enp0s1 369s Aug 22 00:17:53 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd-resolved[384]: System hostname changed to 'adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227'. 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-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). 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-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). 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-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). 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd[1]: Reload requested from client PID 729 ('systemctl') (unit cloud-init-main.service)... 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd[1]: Reloading... 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-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. 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-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. 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd[1]: Reloading finished in 187 ms. 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 sh[682]: Completed socket interaction for boot stage local 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd[1]: Finished cloud-init-local.service - Cloud-init: Local Stage (pre-network). 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd[1]: Reached target network-pre.target - Preparation for Network. 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd[1]: Starting systemd-networkd.service - Network Configuration... 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd-networkd[764]: /run/systemd/network/10-netplan-enp0s1.network: MTUBytes= in [Link] section and UseMTU= in [DHCP] section are set. Disabling UseMTU=. 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd-networkd[764]: lo: Link UP 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd-networkd[764]: lo: Gained carrier 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd-networkd[764]: Enumeration completed 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd-networkd[764]: enp0s1: Link UP 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd-networkd[764]: enp0s1: Gained carrier 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd[1]: Started systemd-networkd.service - Network Configuration. 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd[1]: Reached target network.target - Network. 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd-timesyncd[387]: Network configuration changed, trying to establish connection. 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd-networkd[764]: enp0s1: Gained IPv6LL 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd-networkd[764]: enp0s1: Link DOWN 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd-networkd[764]: enp0s1: Lost carrier 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd[1]: Starting systemd-networkd-persistent-storage.service - Enable Persistent Storage in systemd-networkd... 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd-networkd[764]: enp0s1: Configuring with /run/systemd/network/10-netplan-enp0s1.network. 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd[1]: Starting systemd-networkd-wait-online.service - Wait for Network to be Configured... 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd-networkd[764]: enp0s1: Link UP 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd-networkd[764]: enp0s1: Gained carrier 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 kernel: 8021q: adding VLAN 0 to HW filter on device enp0s1 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd-networkd[764]: enp0s1: DHCPv4 address 10.145.227.145/24, gateway 10.145.227.1 acquired from 10.145.227.1 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd-timesyncd[387]: Network configuration changed, trying to establish connection. 369s Aug 22 00:17:54 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd[1]: Finished systemd-networkd-persistent-storage.service - Enable Persistent Storage in systemd-networkd. 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd-networkd[764]: enp0s1: Gained IPv6LL 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd-timesyncd[387]: Network configuration changed, trying to establish connection. 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd[1]: Finished systemd-networkd-wait-online.service - Wait for Network to be Configured. 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 systemd[1]: Starting cloud-init-network.service - Cloud-init: Network Stage... 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: Cloud-init v. 24.4~2g2e4c39b7-0ubuntu1 running 'init' at Thu, 22 Aug 2024 00:17:56 +0000. Up 10.96 seconds. 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: +++++++++++++++++++++++++++++++++++++++Net device info+++++++++++++++++++++++++++++++++++++++ 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: +--------+------+------------------------------+---------------+--------+-------------------+ 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: | Device | Up | Address | Mask | Scope | Hw-Address | 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: +--------+------+------------------------------+---------------+--------+-------------------+ 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: | enp0s1 | True | 10.145.227.145 | 255.255.255.0 | global | fa:16:3e:a1:70:e4 | 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: | enp0s1 | True | fe80::f816:3eff:fea1:70e4/64 | . | link | fa:16:3e:a1:70:e4 | 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: | lo | True | 127.0.0.1 | 255.0.0.0 | host | . | 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: | lo | True | ::1/128 | . | host | . | 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: +--------+------+------------------------------+---------------+--------+-------------------+ 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: ++++++++++++++++++++++++++++++++Route IPv4 info+++++++++++++++++++++++++++++++++ 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: +-------+-----------------+--------------+-----------------+-----------+-------+ 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: | Route | Destination | Gateway | Genmask | Interface | Flags | 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: +-------+-----------------+--------------+-----------------+-----------+-------+ 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: | 0 | 0.0.0.0 | 10.145.227.1 | 0.0.0.0 | enp0s1 | UG | 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: | 1 | 10.145.227.0 | 0.0.0.0 | 255.255.255.0 | enp0s1 | U | 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: | 2 | 10.145.227.1 | 0.0.0.0 | 255.255.255.255 | enp0s1 | UH | 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: | 3 | 10.145.227.2 | 0.0.0.0 | 255.255.255.255 | enp0s1 | UH | 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: | 4 | 91.189.91.131 | 10.145.227.1 | 255.255.255.255 | enp0s1 | UGH | 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: | 5 | 91.189.91.132 | 10.145.227.1 | 255.255.255.255 | enp0s1 | UGH | 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: | 6 | 169.254.169.254 | 10.145.227.2 | 255.255.255.255 | enp0s1 | UGH | 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: +-------+-----------------+--------------+-----------------+-----------+-------+ 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: +++++++++++++++++++Route IPv6 info+++++++++++++++++++ 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: +-------+-------------+---------+-----------+-------+ 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: | Route | Destination | Gateway | Interface | Flags | 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: +-------+-------------+---------+-----------+-------+ 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: | 0 | fe80::/64 | :: | enp0s1 | U | 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: | 2 | local | :: | enp0s1 | U | 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: | 3 | multicast | :: | enp0s1 | U | 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: ci-info: +-------+-------------+---------+-----------+-------+ 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: 2024-08-22 00:17:56,303 - 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. 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 cloud-init[686]: 2024-08-22 00:17:56,303 - schema.py[WARNING]: cloud-config failed schema validation! You may run 'sudo cloud-init schema --system' to check the details. 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 kernel: EXT4-fs (vda1): resizing filesystem from 5240560 to 26212080 blocks 369s Aug 22 00:17:56 adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f227 kernel: EXT4-fs (vda1): resized filesystem to 26212080 369s Aug 22 00:17:57 autopkgtest systemd-resolved[384]: System hostname changed to 'autopkgtest'. 369s Aug 22 00:17:57 autopkgtest sh[776]: Completed socket interaction for boot stage network 369s Aug 22 00:17:57 autopkgtest systemd[1]: Finished cloud-init-network.service - Cloud-init: Network Stage. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Reached target cloud-config.target - Cloud-config availability. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Reached target network-online.target - Network is Online. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Reached target sysinit.target - System Initialization. 369s Aug 22 00:17:57 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). 369s Aug 22 00:17:57 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). 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started apt-daily.timer - Daily apt download activities. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started apt-daily-upgrade.timer - Daily apt upgrade and clean activities. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started dpkg-db-backup.timer - Daily dpkg database backup timer. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started e2scrub_all.timer - Periodic ext4 Online Metadata Check for All Filesystems. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started fstrim.timer - Discard unused filesystem blocks once a week. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started fwupd-refresh.timer - Refresh fwupd metadata regularly. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started logrotate.timer - Daily rotation of log files. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started man-db.timer - Daily man-db regeneration. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started motd-news.timer - Message of the Day. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started sysstat-collect.timer - Run system activity accounting tool every 10 minutes. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started sysstat-rotate.timer - Rotate daily system activity data file at midnight. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started sysstat-summary.timer - Generate summary of yesterday's process accounting. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started systemd-tmpfiles-clean.timer - Daily Cleanup of Temporary Directories. 369s Aug 22 00:17:57 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). 369s Aug 22 00:17:57 autopkgtest systemd[1]: Reached target boot-complete.target - Boot Completion Check. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Reached target paths.target - Path Units. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Reached target timers.target - Timer Units. 369s Aug 22 00:17:57 autopkgtest systemd[1]: apport-forward.socket - Unix socket for apport crash forwarding was skipped because of an unmet condition check (ConditionVirtualization=container). 369s Aug 22 00:17:57 autopkgtest systemd[1]: Listening on cloud-init-hotplugd.socket - cloud-init hotplug hook socket. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Listening on dbus.socket - D-Bus System Message Bus Socket. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting lxd-installer.socket - Helper to install lxd snap on demand... 369s Aug 22 00:17:57 autopkgtest systemd[1]: Listening on ssh.socket - OpenBSD Secure Shell server socket. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Listening on sshd-unix-local.socket - OpenSSH Server Socket (systemd-ssh-generator, AF_UNIX Local). 369s Aug 22 00:17:57 autopkgtest systemd[1]: Listening on sshd-vsock.socket - OpenSSH Server Socket (systemd-ssh-generator, AF_VSOCK). 369s Aug 22 00:17:57 autopkgtest systemd[1]: Reached target ssh-access.target - SSH Access Available. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Listening on systemd-hostnamed.socket - Hostname Service Socket. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Listening on uuidd.socket - UUID daemon activation socket. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Listening on lxd-installer.socket - Helper to install lxd snap on demand. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Reached target sockets.target - Socket Units. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Reached target basic.target - Basic System. 369s Aug 22 00:17:57 autopkgtest systemd[1]: System is tainted: unmerged-bin 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting apport.service - automatic crash report generation... 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started autopkgtest@hvc1.service - autopkgtest root shell on hvc1. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started autopkgtest@ttyS1.service - autopkgtest root shell on ttyS1. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting cloud-config.service - Cloud-init: Config Stage... 369s Aug 22 00:17:57 autopkgtest (sh)[859]: autopkgtest@hvc1.service: Failed to set up standard input: No such device 369s Aug 22 00:17:57 autopkgtest (sh)[859]: autopkgtest@hvc1.service: Failed at step STDIN spawning /bin/sh: No such device 369s Aug 22 00:17:57 autopkgtest (sh)[860]: autopkgtest@ttyS1.service: Failed to set up standard input: Input/output error 369s Aug 22 00:17:57 autopkgtest (sh)[860]: autopkgtest@ttyS1.service: Failed at step STDIN spawning /bin/sh: Input/output error 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started cron.service - Regular background program processing daemon. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting dbus.service - D-Bus System Message Bus... 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started dmesg.service - Save initial kernel messages after boot. 369s Aug 22 00:17:57 autopkgtest (cron)[862]: cron.service: Referenced but unset environment variable evaluates to an empty string: EXTRA_OPTS 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting e2scrub_reap.service - Remove Stale Online ext4 Metadata Check Snapshots... 369s Aug 22 00:17:57 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). 369s Aug 22 00:17:57 autopkgtest cron[862]: (CRON) INFO (pidfile fd = 3) 369s Aug 22 00:17:57 autopkgtest cron[862]: (CRON) INFO (Running @reboot jobs) 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting grub-common.service - Record successful boot for GRUB... 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting iprdump.service - IBM Power Raid dump daemon... 369s Aug 22 00:17:57 autopkgtest systemd[1]: networkd-dispatcher.service - Dispatcher daemon for systemd-networkd was skipped because no trigger condition checks were met. 369s Aug 22 00:17:57 autopkgtest systemd[1]: opal_errd.service - opal_errd (PowerNV platform error handling) Service was skipped because of an unmet condition check (ConditionVirtualization=false). 369s Aug 22 00:17:57 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). 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting rc-local.service - /etc/rc.local Compatibility... 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting rng-tools-debian.service - LSB: rng-tools (Debian variant)... 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting rsyslog.service - System Logging Service... 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting rtas_errd.service - ppc64-diag rtas_errd (platform error handling) Service... 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting sysstat.service - Resets System Activity Logs... 369s Aug 22 00:17:57 autopkgtest dbus-daemon[866]: [system] AppArmor D-Bus mediation is enabled 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting systemd-logind.service - User Login Management... 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting systemd-user-sessions.service - Permit User Sessions... 369s Aug 22 00:17:57 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). 369s Aug 22 00:17:57 autopkgtest systemd[1]: ubuntu-advantage.service - Ubuntu Pro Background Auto Attach was skipped because no trigger condition checks were met. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting udisks2.service - Disk Manager... 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started dbus.service - D-Bus System Message Bus. 369s Aug 22 00:17:57 autopkgtest systemd[1]: autopkgtest@hvc1.service: Deactivated successfully. 369s Aug 22 00:17:57 autopkgtest systemd[1]: autopkgtest@ttyS1.service: Deactivated successfully. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started iprdump.service - IBM Power Raid dump daemon. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Finished systemd-user-sessions.service - Permit User Sessions. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting iprinit.service - IBM Power Raid init daemon... 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting iprupdate.service - IBM Power Raid update daemon... 369s Aug 22 00:17:57 autopkgtest udisksd[888]: udisks daemon version 2.10.1 starting 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started rc-local.service - /etc/rc.local Compatibility. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting plymouth-quit-wait.service - Hold until boot process finishes up... 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting plymouth-quit.service - Terminate Plymouth Boot Screen... 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started rtas_errd.service - ppc64-diag rtas_errd (platform error handling) Service. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started iprinit.service - IBM Power Raid init daemon. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started iprupdate.service - IBM Power Raid update daemon. 369s Aug 22 00:17:57 autopkgtest systemd[1]: grub-common.service: Deactivated successfully. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Finished grub-common.service - Record successful boot for GRUB. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Reached target iprutils.target - IBM Power Raid utilities. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting grub-initrd-fallback.service - GRUB failed boot detection... 369s Aug 22 00:17:57 autopkgtest rngd[934]: rngd 2.4 starting up... 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started rng-tools-debian.service - LSB: rng-tools (Debian variant). 369s Aug 22 00:17:57 autopkgtest systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up. 369s Aug 22 00:17:57 autopkgtest rngd[934]: entropy feed to the kernel ready 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started serial-getty@hvc0.service - Serial Getty on hvc0. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting setvtrgb.service - Set console scheme... 369s Aug 22 00:17:57 autopkgtest systemd[1]: Finished sysstat.service - Resets System Activity Logs. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Finished plymouth-quit.service - Terminate Plymouth Boot Screen. 369s Aug 22 00:17:57 autopkgtest cloud-init[686]: Cloud-init v. 24.4~2g2e4c39b7-0ubuntu1 running 'modules:config' at Thu, 22 Aug 2024 00:17:57 +0000. Up 12.12 seconds. 369s Aug 22 00:17:57 autopkgtest systemd[1]: e2scrub_reap.service: Deactivated successfully. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Finished e2scrub_reap.service - Remove Stale Online ext4 Metadata Check Snapshots. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Finished setvtrgb.service - Set console scheme. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Created slice system-getty.slice - Slice /system/getty. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started getty@tty1.service - Getty on tty1. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Reached target getty.target - Login Prompts. 369s Aug 22 00:17:57 autopkgtest systemd[1]: grub-initrd-fallback.service: Deactivated successfully. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Finished grub-initrd-fallback.service - GRUB failed boot detection. 369s Aug 22 00:17:57 autopkgtest systemd-logind[886]: New seat seat0. 369s Aug 22 00:17:57 autopkgtest systemd-logind[886]: Watching system buttons on /dev/input/event0 (QEMU QEMU USB Keyboard) 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started systemd-logind.service - User Login Management. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started udisks2.service - Disk Manager. 369s Aug 22 00:17:57 autopkgtest udisksd[888]: Acquired the name org.freedesktop.UDisks2 on the system message bus 369s Aug 22 00:17:57 autopkgtest kernel: kauditd_printk_skb: 110 callbacks suppressed 369s Aug 22 00:17:57 autopkgtest kernel: audit: type=1400 audit(1724285877.540:121): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="rsyslogd" pid=947 comm="apparmor_parser" 369s Aug 22 00:17:57 autopkgtest systemd[1]: dpkg-db-backup.service: Deactivated successfully. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. 369s Aug 22 00:17:57 autopkgtest rsyslogd[1011]: imuxsock: Acquired UNIX socket '/run/systemd/journal/syslog' (fd 3) from systemd. [v8.2406.0] 369s Aug 22 00:17:57 autopkgtest rsyslogd[1011]: rsyslogd's groupid changed to 102 369s Aug 22 00:17:57 autopkgtest rsyslogd[1011]: rsyslogd's userid changed to 102 369s Aug 22 00:17:57 autopkgtest systemd[1]: Started rsyslog.service - System Logging Service. 369s Aug 22 00:17:57 autopkgtest rsyslogd[1011]: [origin software="rsyslogd" swVersion="8.2406.0" x-pid="1011" x-info="https://www.rsyslog.com"] start 369s Aug 22 00:17:57 autopkgtest systemd[1]: Finished apport.service - automatic crash report generation. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Reached target multi-user.target - Multi-User System. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Reached target graphical.target - Graphical Interface. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... 369s Aug 22 00:17:57 autopkgtest systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. 369s Aug 22 00:17:57 autopkgtest cloud-init[686]: 2024-08-22 00:17:57,713 - 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. 369s Aug 22 00:17:57 autopkgtest cloud-init[686]: 2024-08-22 00:17:57,713 - 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. 369s Aug 22 00:17:57 autopkgtest sh[865]: Completed socket interaction for boot stage config 369s Aug 22 00:17:57 autopkgtest systemd[1]: Finished cloud-config.service - Cloud-init: Config Stage. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting cloud-final.service - Cloud-init: Final Stage... 369s Aug 22 00:17:57 autopkgtest cloud-init[686]: Cloud-init v. 24.4~2g2e4c39b7-0ubuntu1 running 'modules:final' at Thu, 22 Aug 2024 00:17:57 +0000. Up 12.55 seconds. 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting apt-news.service - Update APT News... 369s Aug 22 00:17:57 autopkgtest systemd[1]: Starting esm-cache.service - Update the local ESM caches... 369s Aug 22 00:17:58 autopkgtest systemd[1]: apt-news.service: Deactivated successfully. 369s Aug 22 00:17:58 autopkgtest systemd[1]: Finished apt-news.service - Update APT News. 369s Aug 22 00:17:58 autopkgtest cloud-init[686]: Get:1 http://ftpmaster.internal/ubuntu oracular InRelease [126 kB] 369s Aug 22 00:17:58 autopkgtest systemd[1]: esm-cache.service: Deactivated successfully. 369s Aug 22 00:17:58 autopkgtest systemd[1]: Finished esm-cache.service - Update the local ESM caches. 369s Aug 22 00:17:58 autopkgtest cloud-init[686]: Hit:2 http://ftpmaster.internal/ubuntu oracular-updates InRelease 369s Aug 22 00:17:58 autopkgtest cloud-init[686]: Hit:3 http://ftpmaster.internal/ubuntu oracular-security InRelease 369s Aug 22 00:17:58 autopkgtest cloud-init[686]: Get:4 http://ftpmaster.internal/ubuntu oracular/universe Sources [20.4 MB] 369s Aug 22 00:17:59 autopkgtest cloud-init[686]: Get:5 http://ftpmaster.internal/ubuntu oracular/main Sources [1385 kB] 369s Aug 22 00:17:59 autopkgtest cloud-init[686]: Get:6 http://ftpmaster.internal/ubuntu oracular/main ppc64el Packages [1395 kB] 369s Aug 22 00:17:59 autopkgtest cloud-init[686]: Get:7 http://ftpmaster.internal/ubuntu oracular/main ppc64el c-n-f Metadata [31.4 kB] 369s Aug 22 00:17:59 autopkgtest cloud-init[686]: Get:8 http://ftpmaster.internal/ubuntu oracular/universe ppc64el Packages [15.0 MB] 369s Aug 22 00:17:59 autopkgtest cloud-init[686]: Get:9 http://ftpmaster.internal/ubuntu oracular/universe ppc64el c-n-f Metadata [298 kB] 369s Aug 22 00:18:00 autopkgtest systemd[1]: Starting ssh.service - OpenBSD Secure Shell server... 369s Aug 22 00:18:00 autopkgtest sshd[1175]: Server listening on :: port 22. 369s Aug 22 00:18:00 autopkgtest systemd[1]: Started ssh.service - OpenBSD Secure Shell server. 369s Aug 22 00:18:01 autopkgtest sshd[1176]: Accepted publickey for ubuntu from 10.136.6.201 port 35798 ssh2: RSA SHA256:YaYyKWTl9zFJEBK5G3u+MRj3WPJt+vEplFd0J96PUBw 369s Aug 22 00:18:01 autopkgtest sshd[1176]: pam_unix(sshd:session): session opened for user ubuntu(uid=1000) by ubuntu(uid=0) 369s Aug 22 00:18:01 autopkgtest sshd[1176]: pam_systemd(sshd:session): New sd-bus connection (system-bus-pam-systemd-1176) opened. 369s Aug 22 00:18:01 autopkgtest systemd[1]: Created slice user-1000.slice - User Slice of UID 1000. 369s Aug 22 00:18:01 autopkgtest systemd[1]: Starting user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... 369s Aug 22 00:18:01 autopkgtest systemd-logind[886]: New session 1 of user ubuntu. 369s Aug 22 00:18:01 autopkgtest systemd[1]: Finished user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. 369s Aug 22 00:18:01 autopkgtest systemd[1]: Starting user@1000.service - User Manager for UID 1000... 369s Aug 22 00:18:01 autopkgtest (systemd)[1180]: pam_unix(systemd-user:session): session opened for user ubuntu(uid=1000) by ubuntu(uid=0) 369s Aug 22 00:18:01 autopkgtest systemd-logind[886]: New session 2 of user ubuntu. 369s Aug 22 00:18:01 autopkgtest systemd[1180]: Queued start job for default target default.target. 369s Aug 22 00:18:01 autopkgtest systemd[1180]: Created slice app.slice - User Application Slice. 369s Aug 22 00:18:01 autopkgtest systemd[1180]: Started launchpadlib-cache-clean.timer - Clean up old files in the Launchpadlib cache. 369s Aug 22 00:18:01 autopkgtest systemd[1180]: Reached target paths.target - Paths. 369s Aug 22 00:18:01 autopkgtest systemd[1180]: Reached target timers.target - Timers. 369s Aug 22 00:18:01 autopkgtest systemd[1180]: Starting dbus.socket - D-Bus User Message Bus Socket... 369s Aug 22 00:18:01 autopkgtest systemd[1180]: Listening on dirmngr.socket - GnuPG network certificate management daemon. 369s Aug 22 00:18:01 autopkgtest systemd[1180]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). 369s Aug 22 00:18:01 autopkgtest systemd[1180]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). 369s Aug 22 00:18:01 autopkgtest systemd[1180]: Starting gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation)... 369s Aug 22 00:18:01 autopkgtest systemd[1180]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. 369s Aug 22 00:18:01 autopkgtest systemd[1180]: Listening on keyboxd.socket - GnuPG public key management service. 369s Aug 22 00:18:01 autopkgtest systemd[1180]: Listening on dbus.socket - D-Bus User Message Bus Socket. 369s Aug 22 00:18:01 autopkgtest systemd[1180]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). 369s Aug 22 00:18:01 autopkgtest systemd[1180]: Reached target sockets.target - Sockets. 369s Aug 22 00:18:01 autopkgtest systemd[1180]: Reached target basic.target - Basic System. 369s Aug 22 00:18:01 autopkgtest systemd[1180]: Reached target default.target - Main User Target. 369s Aug 22 00:18:01 autopkgtest systemd[1180]: Startup finished in 236ms. 369s Aug 22 00:18:01 autopkgtest systemd[1]: Started user@1000.service - User Manager for UID 1000. 369s Aug 22 00:18:01 autopkgtest systemd[1]: Started session-1.scope - Session 1 of User ubuntu. 369s Aug 22 00:18:01 autopkgtest sshd[1206]: Received disconnect from 10.136.6.201 port 35798:11: disconnected by user 369s Aug 22 00:18:01 autopkgtest sshd[1206]: Disconnected from user ubuntu 10.136.6.201 port 35798 369s Aug 22 00:18:01 autopkgtest sshd[1176]: pam_unix(sshd:session): session closed for user ubuntu 369s Aug 22 00:18:01 autopkgtest sshd[1176]: pam_systemd(sshd:session): New sd-bus connection (system-bus-pam-systemd-1176) opened. 369s Aug 22 00:18:01 autopkgtest systemd[1]: session-1.scope: Deactivated successfully. 369s Aug 22 00:18:01 autopkgtest systemd-logind[886]: Session 1 logged out. Waiting for processes to exit. 369s Aug 22 00:18:01 autopkgtest systemd-logind[886]: Removed session 1. 369s Aug 22 00:18:02 autopkgtest kernel: fbcon: Taking over console 369s Aug 22 00:18:02 autopkgtest kernel: Console: switching to colour frame buffer device 128x48 369s Aug 22 00:18:02 autopkgtest systemd[1]: dmesg.service: Deactivated successfully. 369s Aug 22 00:18:02 autopkgtest sshd[1210]: Accepted publickey for ubuntu from 10.136.6.201 port 35508 ssh2: RSA SHA256:YaYyKWTl9zFJEBK5G3u+MRj3WPJt+vEplFd0J96PUBw 369s Aug 22 00:18:02 autopkgtest sshd[1210]: pam_unix(sshd:session): session opened for user ubuntu(uid=1000) by ubuntu(uid=0) 369s Aug 22 00:18:02 autopkgtest sshd[1210]: pam_systemd(sshd:session): New sd-bus connection (system-bus-pam-systemd-1210) opened. 369s Aug 22 00:18:02 autopkgtest systemd-logind[886]: New session 3 of user ubuntu. 369s Aug 22 00:18:02 autopkgtest systemd[1]: Started session-3.scope - Session 3 of User ubuntu. 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: Fetched 38.7 MB in 7s (5791 kB/s) 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: Reading package lists... 369s Aug 22 00:18:06 autopkgtest cloud-init[1300]: ############################################################# 369s Aug 22 00:18:06 autopkgtest cloud-init[1301]: -----BEGIN SSH HOST KEY FINGERPRINTS----- 369s Aug 22 00:18:06 autopkgtest cloud-init[1303]: 256 SHA256:lNRO8F8LTeAI+EqvXEI7VmHPtNnZWTt3Zi433WHgumM root@autopkgtest (ECDSA) 369s Aug 22 00:18:06 autopkgtest cloud-init[1305]: 256 SHA256:RksCxM/4HgX/zd2WI2IXPIqXptEOW4WeCzXeFU1HKyg root@autopkgtest (ED25519) 369s Aug 22 00:18:06 autopkgtest cloud-init[1307]: 3072 SHA256:5Kp46adhnucvujmfbRg1LT22+xfeCZ14zIaSodonQYQ root@autopkgtest (RSA) 369s Aug 22 00:18:06 autopkgtest cloud-init[1308]: -----END SSH HOST KEY FINGERPRINTS----- 369s Aug 22 00:18:06 autopkgtest cloud-init[1309]: ############################################################# 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: Cloud-init v. 24.4~2g2e4c39b7-0ubuntu1 finished at Thu, 22 Aug 2024 00:18:06 +0000. Datasource DataSourceOpenStackLocal [net,ver=2]. Up 21.70 seconds 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: Generating public/private rsa key pair. 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: Your identification has been saved in /etc/ssh/ssh_host_rsa_key 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: Your public key has been saved in /etc/ssh/ssh_host_rsa_key.pub 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: The key fingerprint is: 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: SHA256:5Kp46adhnucvujmfbRg1LT22+xfeCZ14zIaSodonQYQ root@autopkgtest 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: The key's randomart image is: 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: +---[RSA 3072]----+ 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | . | 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | E . | 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | oo | 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | o+.=. | 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | .S+.oo * .| 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | .. o.o +.B | 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | o..oo ....+o.| 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | ++==+.o.. o..| 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | .oXX++o o... | 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: +----[SHA256]-----+ 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: Generating public/private ecdsa key pair. 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: Your identification has been saved in /etc/ssh/ssh_host_ecdsa_key 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: Your public key has been saved in /etc/ssh/ssh_host_ecdsa_key.pub 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: The key fingerprint is: 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: SHA256:lNRO8F8LTeAI+EqvXEI7VmHPtNnZWTt3Zi433WHgumM root@autopkgtest 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: The key's randomart image is: 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: +---[ECDSA 256]---+ 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | .+o ... | 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | ..o++o + .| 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | ooBo++o+o.| 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | o.o *.o+o*=| 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | o =S o o+B| 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | * o . ..=| 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | o = . o.| 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | o E | 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | . . | 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: +----[SHA256]-----+ 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: Generating public/private ed25519 key pair. 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: Your identification has been saved in /etc/ssh/ssh_host_ed25519_key 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: Your public key has been saved in /etc/ssh/ssh_host_ed25519_key.pub 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: The key fingerprint is: 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: SHA256:RksCxM/4HgX/zd2WI2IXPIqXptEOW4WeCzXeFU1HKyg root@autopkgtest 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: The key's randomart image is: 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: +--[ED25519 256]--+ 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | oo o=| 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | ... . .+| 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | +.ooE .o. ..| 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | . o+o..+ =.. | 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | . .S.*oB.+..| 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | o. =.&o+.oo| 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | . . % + ...| 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | . o o | 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: | | 369s Aug 22 00:18:06 autopkgtest cloud-init[686]: +----[SHA256]-----+ 369s Aug 22 00:18:06 autopkgtest sh[1050]: Completed socket interaction for boot stage final 369s Aug 22 00:18:06 autopkgtest systemd[1]: Finished cloud-final.service - Cloud-init: Final Stage. 369s Aug 22 00:18:06 autopkgtest systemd[1]: Reached target cloud-init.target - Cloud-init target. 369s Aug 22 00:18:06 autopkgtest systemd[1]: Startup finished in 1.698s (kernel) + 20.020s (userspace) = 21.719s. 369s Aug 22 00:18:06 autopkgtest systemd[1]: cloud-init-main.service: Deactivated successfully. 369s Aug 22 00:18:06 autopkgtest systemd[1]: cloud-init-main.service: Consumed 10.158s CPU time, 452.5M memory peak. 369s Aug 22 00:18:07 autopkgtest sshd[1271]: Received disconnect from 10.136.6.201 port 35508:11: disconnected by user 369s Aug 22 00:18:07 autopkgtest sshd[1271]: Disconnected from user ubuntu 10.136.6.201 port 35508 369s Aug 22 00:18:07 autopkgtest sshd[1210]: pam_unix(sshd:session): session closed for user ubuntu 369s Aug 22 00:18:07 autopkgtest sshd[1210]: pam_systemd(sshd:session): New sd-bus connection (system-bus-pam-systemd-1210) opened. 369s Aug 22 00:18:07 autopkgtest systemd[1]: session-3.scope: Deactivated successfully. 369s Aug 22 00:18:07 autopkgtest systemd-logind[886]: Session 3 logged out. Waiting for processes to exit. 369s Aug 22 00:18:07 autopkgtest systemd-logind[886]: Removed session 3. 369s Aug 22 00:18:08 autopkgtest sshd[1316]: Accepted publickey for ubuntu from 10.136.6.201 port 35518 ssh2: RSA SHA256:YaYyKWTl9zFJEBK5G3u+MRj3WPJt+vEplFd0J96PUBw 369s Aug 22 00:18:08 autopkgtest sshd[1316]: pam_unix(sshd:session): session opened for user ubuntu(uid=1000) by ubuntu(uid=0) 369s Aug 22 00:18:08 autopkgtest sshd[1316]: pam_systemd(sshd:session): New sd-bus connection (system-bus-pam-systemd-1316) opened. 369s Aug 22 00:18:08 autopkgtest systemd-logind[886]: New session 4 of user ubuntu. 369s Aug 22 00:18:08 autopkgtest systemd[1]: Started session-4.scope - Session 4 of User ubuntu. 369s Aug 22 00:18:09 autopkgtest sudo[1334]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/bin/true 369s Aug 22 00:18:09 autopkgtest sudo[1334]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:09 autopkgtest sudo[1334]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:09 autopkgtest sudo[1339]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper /bin/mkdir --mode=1777 --parents /tmp/autopkgtest.gLtNOa 369s Aug 22 00:18:09 autopkgtest sudo[1339]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:09 autopkgtest sudo[1339]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:09 autopkgtest sudo[1349]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper mkdir -p /tmp/autopkgtest.gLtNOa 369s Aug 22 00:18:09 autopkgtest sudo[1349]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:09 autopkgtest sudo[1349]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:09 autopkgtest sudo[1359]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat >/tmp/autopkgtest.gLtNOa/wrapper.sh; chmod +x -- /tmp/autopkgtest.gLtNOa/wrapper.sh' 369s Aug 22 00:18:09 autopkgtest sudo[1359]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:09 autopkgtest sudo[1359]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:10 autopkgtest sudo[1371]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chmod -R 0755 -- /tmp/autopkgtest.gLtNOa/wrapper.sh 369s Aug 22 00:18:10 autopkgtest sudo[1371]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:10 autopkgtest sudo[1371]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:10 autopkgtest sudo[1381]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper dpkg --print-architecture 369s Aug 22 00:18:10 autopkgtest sudo[1381]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:10 autopkgtest sudo[1381]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:10 autopkgtest sudo[1391]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper dpkg-query -W -f ${Version} apt 369s Aug 22 00:18:10 autopkgtest sudo[1391]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:10 autopkgtest sudo[1391]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:10 autopkgtest sudo[1401]: 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 369s Aug 22 00:18:10 autopkgtest sudo[1401]: 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 369s Aug 22 00:18:10 autopkgtest sudo[1401]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:10 autopkgtest sudo[1401]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:10 autopkgtest sudo[1413]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'ls -1 /etc/apt/sources.list.d/*.sources' 369s Aug 22 00:18:10 autopkgtest sudo[1413]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:10 autopkgtest sudo[1413]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:11 autopkgtest sudo[1424]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper cat /etc/apt/sources.list.d/ubuntu.sources 369s Aug 22 00:18:11 autopkgtest sudo[1424]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:11 autopkgtest sudo[1424]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:11 autopkgtest sudo[1434]: 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 369s Aug 22 00:18:11 autopkgtest sudo[1434]: 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 369s Aug 22 00:18:11 autopkgtest sudo[1434]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:11 autopkgtest systemd[1]: Starting apt-news.service - Update APT News... 369s Aug 22 00:18:11 autopkgtest systemd[1]: Starting esm-cache.service - Update the local ESM caches... 369s Aug 22 00:18:11 autopkgtest systemd[1]: esm-cache.service: Deactivated successfully. 369s Aug 22 00:18:11 autopkgtest systemd[1]: Finished esm-cache.service - Update the local ESM caches. 369s Aug 22 00:18:11 autopkgtest systemd[1]: apt-news.service: Deactivated successfully. 369s Aug 22 00:18:11 autopkgtest systemd[1]: Finished apt-news.service - Update APT News. 369s Aug 22 00:18:15 autopkgtest sudo[1434]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18: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-proposed\\nPin-Priority: 500\\n" > /etc/apt/preferences.d/autopkgtest-oracular-proposed-baseline;' 369s Aug 22 00:18:15 autopkgtest sudo[1521]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:15 autopkgtest sudo[1521]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:15 autopkgtest sudo[1532]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper mkdir -p /etc/apt/preferences.d 369s Aug 22 00:18:15 autopkgtest sudo[1532]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:15 autopkgtest sudo[1532]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:16 autopkgtest sudo[1542]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat >/etc/apt/preferences.d/autopkgtest-oracular-proposed' 369s Aug 22 00:18:16 autopkgtest sudo[1542]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:16 autopkgtest sudo[1542]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:16 autopkgtest sudo[1553]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chmod -R 0644 -- /etc/apt/preferences.d/autopkgtest-oracular-proposed 369s Aug 22 00:18:16 autopkgtest sudo[1553]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:16 autopkgtest sudo[1553]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:16 autopkgtest sudo[1563]: 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' 369s Aug 22 00:18:16 autopkgtest sudo[1563]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:16 autopkgtest sudo[1563]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:16 autopkgtest sudo[1574]: 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.gLtNOa/${d//\\//_}.stamp; done' 369s Aug 22 00:18:16 autopkgtest sudo[1574]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:16 autopkgtest sudo[1574]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:16 autopkgtest sudo[1588]: 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 369s Aug 22 00:18:16 autopkgtest sudo[1588]: 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 369s Aug 22 00:18:16 autopkgtest sudo[1588]: ubuntu : (command continued) apt-get update || (sleep 10; apt-get update); apt-get install -y build-essential; fi#012#012# these packages really break tests, purge them if we use standard cloud images#012# (on lcy01)#012for p in unattended-upgrades lxd lxd-client snapd; do#012 [ ! -d /usr/share/doc/$p ] || $(which eatmydata || true) apt-get purge --auto-remove -y $p#012done#012#012# work around broken PTMU; LP: #1572026, RT#90771#012if type iptables >/dev/null 2>&1; then#012 cat < /etc/rc.local#012#!/bin/sh#012iptables -w -t mangle -A FORWARD -p tcp --tcp-flags SYN,RST SYN -j TCPMSS --clamp-mss-to-pmtu || true#012EOF#012 chmod 755 /etc/rc.local#012 # shellcheck disable=SC1091#012 . /etc/rc.local#012fi#012#012# work around broken tty on ppc64el instances (LP: #1607075)#012if [ "$(uname -m)" = ppc64le ] && [ "$(systemctl is-active keyboard-setup.service 2>/dev/null|| true)" = failed ]; then#012 systemctl reset-failed 369s Aug 22 00:18:16 autopkgtest sudo[1588]: ubuntu : (command continued) keyboard-setup.service#012 systemctl mask keyboard-setup.service#012fi#012#012# work around late urandom pool initialization (LP: #1622893)#012if [ -d /run/systemd/system ] && systemd-detect-virt --quiet --vm; then#012 mkdir -p /etc/systemd/system/systemd-random-seed.service.d/#012 cat < /etc/systemd/system/systemd-random-seed.service.d/fakeentropy.conf#012[Service]#012ExecStart=/usr/bin/perl -E \'open \\$\\$f, "/bin/bash" or die; open \\$\\$rnd, ">/dev/random" or die; for (\\$\\$i = 0; \\$\\$i < 10; ++\\$\\$i) {read \\$\\$f, \\$\\$d, 64; ioctl \\$\\$rnd, 0x40085203, pack("ii", 64*8, 64) . \\$\\$d}\'#012EOF#012fi#012#012# set compressor to lz4 where supported, we care about compression speed#012if grep -q lz4 /etc/initramfs-tools/initramfs.conf; then#012 echo COMPRESS=lz4 > /etc/initramfs-tools/conf.d/lz4#012fi' 369s Aug 22 00:18:16 autopkgtest sudo[1588]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:18 autopkgtest sudo[1588]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:18 autopkgtest sudo[1642]: 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' 369s Aug 22 00:18:18 autopkgtest sudo[1642]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:18 autopkgtest systemd[1]: Starting apt-news.service - Update APT News... 369s Aug 22 00:18:18 autopkgtest systemd[1]: Starting esm-cache.service - Update the local ESM caches... 369s Aug 22 00:18:18 autopkgtest systemd[1]: apt-news.service: Deactivated successfully. 369s Aug 22 00:18:18 autopkgtest systemd[1]: Finished apt-news.service - Update APT News. 369s Aug 22 00:18:18 autopkgtest systemd[1]: esm-cache.service: Deactivated successfully. 369s Aug 22 00:18:18 autopkgtest systemd[1]: Finished esm-cache.service - Update the local ESM caches. 369s Aug 22 00:18:21 autopkgtest sudo[1642]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:21 autopkgtest sudo[1827]: 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.gLtNOa/${d//\\//_}.stamp; [ ! -d $d ] || [ `stat -c %Y $d` = `stat -c %Y $s` ]; done' 369s Aug 22 00:18:21 autopkgtest sudo[1827]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:21 autopkgtest sudo[1827]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:21 autopkgtest sudo[1845]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'command -v eatmydata' 369s Aug 22 00:18:21 autopkgtest sudo[1845]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:21 autopkgtest sudo[1845]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:21 autopkgtest sudo[1855]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'dpkg-query --show -f \'${Package}\\t${Version}\\n\' > /tmp/autopkgtest.gLtNOa/testbed-packages' 369s Aug 22 00:18:21 autopkgtest sudo[1855]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:21 autopkgtest sudo[1855]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:22 autopkgtest sudo[1866]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat /tmp/autopkgtest.gLtNOa/autopkgtest-reboot; chmod +x -- /tmp/autopkgtest.gLtNOa/autopkgtest-reboot' 369s Aug 22 00:18:22 autopkgtest sudo[1887]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:22 autopkgtest sudo[1887]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:22 autopkgtest sudo[1899]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chmod -R 0755 -- /tmp/autopkgtest.gLtNOa/autopkgtest-reboot 369s Aug 22 00:18:22 autopkgtest sudo[1899]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:22 autopkgtest sudo[1899]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:23 autopkgtest sudo[1909]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper ln -fns /tmp/autopkgtest.gLtNOa/autopkgtest-reboot /tmp/autopkgtest-reboot 369s Aug 22 00:18:23 autopkgtest sudo[1909]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:23 autopkgtest sudo[1909]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:23 autopkgtest sudo[1919]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper ln -fns /tmp/autopkgtest.gLtNOa/autopkgtest-reboot /sbin/autopkgtest-reboot 369s Aug 22 00:18:23 autopkgtest sudo[1919]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:23 autopkgtest sudo[1919]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:23 autopkgtest sudo[1929]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper mkdir -p /tmp/autopkgtest.gLtNOa 369s Aug 22 00:18:23 autopkgtest sudo[1929]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:23 autopkgtest sudo[1929]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:23 autopkgtest sudo[1939]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat >/tmp/autopkgtest.gLtNOa/autopkgtest-reboot-prepare; chmod +x -- /tmp/autopkgtest.gLtNOa/autopkgtest-reboot-prepare' 369s Aug 22 00:18:23 autopkgtest sudo[1939]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:23 autopkgtest sudo[1939]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:23 autopkgtest sudo[1951]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chmod -R 0755 -- /tmp/autopkgtest.gLtNOa/autopkgtest-reboot-prepare 369s Aug 22 00:18:23 autopkgtest sudo[1951]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:23 autopkgtest sudo[1951]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:24 autopkgtest sudo[1961]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper ln -fns /tmp/autopkgtest.gLtNOa/autopkgtest-reboot-prepare /tmp/autopkgtest-reboot-prepare 369s Aug 22 00:18:24 autopkgtest sudo[1961]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:24 autopkgtest sudo[1961]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:24 autopkgtest sudo[1971]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper uname -srv 369s Aug 22 00:18:24 autopkgtest sudo[1971]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:24 autopkgtest sudo[1971]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:24 autopkgtest sudo[1981]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper test -w /var/lib/dpkg/status 369s Aug 22 00:18:24 autopkgtest sudo[1981]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:24 autopkgtest sudo[1981]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:24 autopkgtest sudo[1990]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper mkdir -p /tmp/autopkgtest.gLtNOa 369s Aug 22 00:18:24 autopkgtest sudo[1990]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:24 autopkgtest sudo[1990]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:25 autopkgtest sudo[2000]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat >/tmp/autopkgtest.gLtNOa/2-autopkgtest-satdep.deb' 369s Aug 22 00:18:25 autopkgtest sudo[2000]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:25 autopkgtest sudo[2000]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:25 autopkgtest sudo[2011]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chown -R ubuntu -- /tmp/autopkgtest.gLtNOa/2-autopkgtest-satdep.deb 369s Aug 22 00:18:25 autopkgtest sudo[2011]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:25 autopkgtest sudo[2011]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:25 autopkgtest sudo[2021]: 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.gLtNOa/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' 369s Aug 22 00:18:25 autopkgtest sudo[2021]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:26 autopkgtest systemd-timesyncd[387]: Contacted time server 185.125.190.58:123 (ntp.ubuntu.com). 369s Aug 22 00:18:26 autopkgtest systemd-timesyncd[387]: Initial clock synchronization to Thu 2024-08-22 00:18:26.681180 UTC. 369s Aug 22 00:18:36 autopkgtest systemd[1]: Reload requested from client PID 2261 ('systemctl') (unit session-4.scope)... 369s Aug 22 00:18:36 autopkgtest systemd[1]: Reloading... 369s Aug 22 00:18:36 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. 369s Aug 22 00:18:36 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. 369s Aug 22 00:18:36 autopkgtest systemd[1]: Reloading finished in 188 ms. 369s Aug 22 00:18:36 autopkgtest systemd[1]: Reload requested from client PID 2310 ('systemctl') (unit session-4.scope)... 369s Aug 22 00:18:36 autopkgtest systemd[1]: Reloading... 369s Aug 22 00:18:37 autopkgtest systemd[1]: Configuration file /run/systemd/system/systemd-networkd-wait-online.service.d/10-netplan.conf is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. 369s Aug 22 00:18:37 autopkgtest systemd[1]: Configuration file /run/systemd/system/netplan-ovs-cleanup.service is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. 369s Aug 22 00:18:37 autopkgtest systemd[1]: Reloading finished in 204 ms. 369s Aug 22 00:18:37 autopkgtest systemd[1]: Starting tgt.service - (i)SCSI target daemon... 369s Aug 22 00:18:37 autopkgtest tgtd[2355]: tgtd: iser_ib_init(3431) Failed to initialize RDMA; load kernel modules? 369s Aug 22 00:18:37 autopkgtest tgtd[2355]: tgtd: work_timer_start(146) use timer_fd based scheduler 369s Aug 22 00:18:37 autopkgtest tgtd[2355]: tgtd: bs_init(387) use signalfd notification 369s Aug 22 00:18:37 autopkgtest systemd[1]: Started tgt.service - (i)SCSI target daemon. 369s Aug 22 00:18:37 autopkgtest systemd[1]: Reload requested from client PID 2383 ('systemctl') (unit session-4.scope)... 369s Aug 22 00:18:37 autopkgtest systemd[1]: Reloading... 369s Aug 22 00:18:37 autopkgtest systemd[1]: Configuration file /run/systemd/system/systemd-networkd-wait-online.service.d/10-netplan.conf is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. 369s Aug 22 00:18:37 autopkgtest systemd[1]: Configuration file /run/systemd/system/netplan-ovs-cleanup.service is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. 369s Aug 22 00:18:37 autopkgtest systemd[1]: Reloading finished in 196 ms. 369s Aug 22 00:18:37 autopkgtest systemd[1]: Reload requested from client PID 2425 ('systemctl') (unit session-4.scope)... 369s Aug 22 00:18:37 autopkgtest systemd[1]: Reloading... 369s Aug 22 00:18:37 autopkgtest systemd[1]: Configuration file /run/systemd/system/systemd-networkd-wait-online.service.d/10-netplan.conf is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. 369s Aug 22 00:18:37 autopkgtest systemd[1]: Configuration file /run/systemd/system/netplan-ovs-cleanup.service is marked world-inaccessible. This has no effect as configuration data is accessible via APIs without restrictions. Proceeding anyway. 369s Aug 22 00:18:37 autopkgtest systemd[1]: Reloading finished in 209 ms. 369s Aug 22 00:18:38 autopkgtest systemd[1]: Reload requested from client PID 2470 ('systemctl') (unit session-4.scope)... 369s Aug 22 00:18:38 autopkgtest systemd[1]: Reloading... 369s Aug 22 00:18:38 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. 369s Aug 22 00:18:38 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. 369s Aug 22 00:18:38 autopkgtest systemd[1]: Reloading finished in 187 ms. 369s Aug 22 00:18:38 autopkgtest systemd[1]: Starting logrotate.service - Rotate log files... 369s Aug 22 00:18:38 autopkgtest systemd[1]: Listening on iscsid.socket - Open-iSCSI iscsid Socket. 369s Aug 22 00:18:38 autopkgtest systemd[1]: logrotate.service: Deactivated successfully. 369s Aug 22 00:18:38 autopkgtest systemd[1]: Finished logrotate.service - Rotate log files. 369s Aug 22 00:18:38 autopkgtest systemd[1]: Reload requested from client PID 2524 ('systemctl') (unit session-4.scope)... 369s Aug 22 00:18:38 autopkgtest systemd[1]: Reloading... 369s Aug 22 00:18:38 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. 369s Aug 22 00:18:38 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. 369s Aug 22 00:18:38 autopkgtest systemd[1]: Reloading finished in 201 ms. 369s Aug 22 00:18:38 autopkgtest systemd[1]: open-iscsi.service - Login to default iSCSI targets was skipped because no trigger condition checks were met. 369s Aug 22 00:18:38 autopkgtest systemd[1]: Reached target remote-fs-pre.target - Preparation for Remote File Systems. 369s Aug 22 00:18:38 autopkgtest systemd[1]: Reload requested from client PID 2578 ('systemctl') (unit session-4.scope)... 369s Aug 22 00:18:38 autopkgtest systemd[1]: Reloading... 369s Aug 22 00:18:38 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. 369s Aug 22 00:18:38 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. 369s Aug 22 00:18:39 autopkgtest systemd[1]: Reloading finished in 183 ms. 369s Aug 22 00:18:48 autopkgtest sudo[2021]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:48 autopkgtest sudo[6020]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper dpkg-query --show -f ${Status} multipath-tools 369s Aug 22 00:18:48 autopkgtest sudo[6020]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:48 autopkgtest sudo[6020]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:48 autopkgtest sudo[6030]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper dpkg --status autopkgtest-satdep 369s Aug 22 00:18:48 autopkgtest sudo[6030]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:48 autopkgtest sudo[6030]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:49 autopkgtest sudo[6040]: 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 369s Aug 22 00:18:49 autopkgtest sudo[6040]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:50 autopkgtest sudo[6040]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:50 autopkgtest sudo[6053]: 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 369s Aug 22 00:18:50 autopkgtest sudo[6053]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:50 autopkgtest sudo[6053]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:50 autopkgtest sudo[6065]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper apt-mark manual -qq lsscsi 369s Aug 22 00:18:50 autopkgtest sudo[6065]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:50 autopkgtest sudo[6065]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:51 autopkgtest sudo[6077]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper dpkg --purge autopkgtest-satdep 369s Aug 22 00:18:51 autopkgtest sudo[6077]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:51 autopkgtest sudo[6077]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:51 autopkgtest sudo[6087]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'dpkg-query --show -f \'${Package}\\t${Version}\\n\' > /tmp/autopkgtest.gLtNOa/tgtbasedmpaths-packages.all' 369s Aug 22 00:18:51 autopkgtest sudo[6087]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 369s Aug 22 00:18:51 autopkgtest sudo[6087]: pam_unix(sudo:session): session closed for user root 369s Aug 22 00:18:51 autopkgtest sudo[6098]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat =64=0.0% 373s submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 373s complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 373s issued rwts: total=0,1401,0,0 short=0,0,0,0 dropped=0,0,0,0 373s latency : target=0, window=0, percentile=100.00%, depth=1 373s 373s Run status group 0 (all jobs): 373s WRITE: bw=179MiB/s (187MB/s), 179MiB/s-179MiB/s (187MB/s-187MB/s), io=87.5MiB (91.8MB), run=490-490msec 373s 373s Disk stats (read/write): 373s dm-0: ios=1/1121, sectors=8/143616, merge=0/0, ticks=2/389, in_queue=391, util=80.16%, aggrios=0/350, aggsectors=2/44820, aggrmerge=0/0, aggrticks=0/104, aggrin_queue=105, aggrutil=81.46% 373s sdd: ios=0/0, sectors=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 373s sdb: ios=1/1402, sectors=8/179280, merge=0/0, ticks=1/419, in_queue=420, util=81.46% 373s sdc: ios=0/0, sectors=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 373s sda: ios=0/0, sectors=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 373s Starting the path changes in background 373s Pre FIO 00:20:20.563794354 373s + echo Starting the path changes in background 373s + date +Pre FIO %H:%M:%S.%N 373s + fio --max-jobs=4 /tmp/autopkgtest.gLtNOa/tgtbasedmpaths-artifacts/path-change-check.fio 373s 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 373s fio-3.37 373s Starting 1 thread 553s 553s verify-phase: (groupid=0, jobs=1): err= 0: pid=6467: Thu Aug 22 00:23:20 2024 553s read: IOPS=5282, BW=330MiB/s (346MB/s)(58.0GiB/180001msec) 553s clat (usec): min=79, max=60125, avg=166.26, stdev=152.77 553s lat (usec): min=79, max=60125, avg=166.37, stdev=152.77 553s clat percentiles (usec): 553s | 1.00th=[ 100], 5.00th=[ 114], 10.00th=[ 121], 20.00th=[ 131], 553s | 30.00th=[ 139], 40.00th=[ 145], 50.00th=[ 153], 60.00th=[ 161], 553s | 70.00th=[ 172], 80.00th=[ 186], 90.00th=[ 210], 95.00th=[ 237], 553s | 99.00th=[ 457], 99.50th=[ 791], 99.90th=[ 1057], 99.95th=[ 1500], 553s | 99.99th=[ 2245] 553s bw ( KiB/s): min=162304, max=459392, per=100.00%, avg=338512.06, stdev=49318.57, samples=359 553s iops : min= 2536, max= 7178, avg=5289.22, stdev=770.60, samples=359 553s lat (usec) : 100=1.02%, 250=95.49%, 500=2.53%, 750=0.33%, 1000=0.51% 553s lat (msec) : 2=0.11%, 4=0.01%, 10=0.01%, 20=0.01%, 50=0.01% 553s lat (msec) : 100=0.01% 553s cpu : usr=13.20%, sys=7.37%, ctx=951097, majf=0, minf=1 553s IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0% 553s submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 553s complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 553s issued rwts: total=950942,0,0,0 short=0,0,0,0 dropped=0,0,0,0 553s latency : target=0, window=0, percentile=100.00%, depth=1 553s 553s Run status group 0 (all jobs): 553s READ: bw=330MiB/s (346MB/s), 330MiB/s-330MiB/s (346MB/s-346MB/s), io=58.0GiB (62.3GB), run=180001-180001msec 553s 553s Disk stats (read/write): 553s dm-0: ios=951159/10, sectors=121661240/12928, merge=31/9, ticks=158539/73, in_queue=158660, util=100.00%, aggrios=68963/2, aggsectors=8820878/3232, aggrmerge=0/0, aggrticks=9915/6, aggrin_queue=9921, aggrutil=99.52% 553s sdd: ios=102428/0, sectors=13101440/0, merge=0/0, ticks=16116/0, in_queue=16116, util=39.67% 553s sdb: ios=113517/9, sectors=14519096/12928, merge=0/0, ticks=15858/24, in_queue=15882, util=99.52% 553s sdc: ios=59910/0, sectors=7662976/0, merge=0/0, ticks=7686/0, in_queue=7686, util=32.94% 553s sda: ios=0/0, sectors=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 553s + date +Post FIO %H:%M:%S.%N 553s Post FIO 00:23:20.907095523 553s FIO verify test with changing paths - OK 553s Report log of background activity 553s + echo FIO verify test with changing paths - OK 553s + echo Report log of background activity 553s + cat /tmp/autopkgtest.gLtNOa/tgtbasedmpaths-artifacts/test-background.log 554s + iscsiadm --mode session 554s tcp: [1] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 554s tcp: [2] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 554s tcp: [3] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 554s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 554s + sleep 10s 554s + date +MP report (expect 4) %H:%M:%S.%N 554s MP report (expect 4) 00:20:30.571028251 554s + multipath -ll 554s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 554s size=100M features='0' hwhandler='0' wp=rw 554s |-+- policy='service-time 0' prio=1 status=active 554s | `- 1:0:0:1 sdb 8:16 active ready running 554s |-+- policy='service-time 0' prio=1 status=enabled 554s | `- 0:0:0:1 sda 8:0 active ready running 554s |-+- policy='service-time 0' prio=1 status=enabled 554s | `- 2:0:0:1 sdc 8:32 active ready running 554s `-+- policy='service-time 0' prio=1 status=enabled 554s `- 3:0:0:1 sdd 8:48 active ready running 554s + date +UN-plug path 1 %H:%M:%S.%N 554s UN-plug path 1 00:20:30.597972644 554s + iscsiadm --mode session -r 1 -u 554s Logging out of session [sid: 1, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 554s Logout of [sid: 1, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 554s + iscsiadm --mode session 554s tcp: [2] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 554s tcp: [3] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 554s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 554s + sleep 10s 554s + date +MP report (expect 3) %H:%M:%S.%N 554s MP report (expect 3) 00:20:40.693420985 554s + multipath -ll 554s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 554s size=100M features='0' hwhandler='0' wp=rw 554s |-+- policy='service-time 0' prio=1 status=active 554s | `- 1:0:0:1 sdb 8:16 active ready running 554s |-+- policy='service-time 0' prio=1 status=enabled 554s | `- 2:0:0:1 sdc 8:32 active ready running 554s `-+- policy='service-time 0' prio=1 status=enabled 554s `- 3:0:0:1 sdd 8:48 active ready running 554s + date +UN-plug path 2 %H:%M:%S.%N 554s UN-plug path 2 00:20:40.711198465 554s + iscsiadm --mode session -r 2 -u 554s Logging out of session [sid: 2, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 554s Logout of [sid: 2, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 554s + iscsiadm --mode session 554s tcp: [3] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 554s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 554s + sleep 10s 554s + date +MP report (expect 2) %H:%M:%S.%N 554s MP report (expect 2) 00:20:50.806441571 554s + multipath -ll 554s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 554s size=100M features='0' hwhandler='0' wp=rw 554s |-+- policy='service-time 0' prio=1 status=active 554s | `- 2:0:0:1 sdc 8:32 active ready running 554s `-+- policy='service-time 0' prio=1 status=enabled 554s `- 3:0:0:1 sdd 8:48 active ready running 554s + date +UN-plug path 3 %H:%M:%S.%N 554s UN-plug path 3 00:20:50.820909068 554s + iscsiadm --mode session -r 3 -u 554s Logging out of session [sid: 3, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 554s Logout of [sid: 3, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 554s + iscsiadm --mode session 554s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 554s + sleep 10s 554s + date +MP report (expect 1) %H:%M:%S.%N 554s MP report (expect 1) 00:21:00.924736434 554s + multipath -ll 554s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 554s size=100M features='0' hwhandler='0' wp=rw 554s `-+- policy='service-time 0' prio=1 status=active 554s `- 3:0:0:1 sdd 8:48 active ready running 554s + date +Add paths 5/6/7/8 %H:%M:%S.%N 554s Add paths 5/6/7/8 00:21:00.935931734 554s + iscsiadm --mode session -r 4 --op new 554s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 554s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 554s + iscsiadm --mode session -r 4 --op new 554s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 554s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 554s + iscsiadm --mode session -r 4 --op new 554s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 554s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 554s + iscsiadm --mode session -r 4 --op new 554s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 554s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 554s + iscsiadm --mode session 554s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 554s tcp: [5] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 554s tcp: [6] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 554s tcp: [7] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 554s tcp: [8] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 554s + sleep 10s 554s + date +MP report (expect 5) %H:%M:%S.%N 554s MP report (expect 5) 00:21:11.026543547 554s + multipath -ll 554s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 554s size=100M features='0' hwhandler='0' wp=rw 554s |-+- policy='service-time 0' prio=1 status=active 554s | `- 3:0:0:1 sdd 8:48 active ready running 554s |-+- policy='service-time 0' prio=1 status=enabled 554s | `- 0:0:0:1 sda 8:0 active ready running 554s |-+- policy='service-time 0' prio=1 status=enabled 554s | `- 1:0:0:1 sdb 8:16 active ready running 554s |-+- policy='service-time 0' prio=1 status=enabled 554s | `- 2:0:0:1 sdc 8:32 active ready running 554s `-+- policy='service-time 0' prio=1 status=enabled 554s `- 4:0:0:1 sde 8:64 active ready running 554s + date +UN-plug multiple paths 4/7/8 %H:%M:%S.%N 554s UN-plug multiple paths 4/7/8 00:21:11.068509286 554s + iscsiadm --mode session -r 4 -u 554s Logging out of session [sid: 4, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 554s Logout of [sid: 4, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 554s + iscsiadm --mode session -r 7 -u 554s Logging out of session [sid: 7, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 554s Logout of [sid: 7, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 554s + iscsiadm --mode session -r 8 -u 554s Logging out of session [sid: 8, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 554s Logout of [sid: 8, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 554s + iscsiadm --mode session 554s tcp: [5] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 554s tcp: [6] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 554s + sleep 10s 554s + date +Restart multipath daemon %H:%M:%S.%N 554s Restart multipath daemon 00:21:21.335292413 554s + systemctl restart multipathd 554s + sleep 10s 554s + date +Final background report (expect 2) %H:%M:%S.%N 554s Final background report (expect 2) 00:21:31.418088999 554s + multipath -ll 554s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 554s size=100M features='0' hwhandler='0' wp=rw 554s |-+- policy='service-time 0' prio=1 status=active 554s | `- 0:0:0:1 sda 8:0 active ready running 554s `-+- policy='service-time 0' prio=1 status=enabled 554s `- 1:0:0:1 sdb 8:16 active ready running 554s Final stats 554s Stats for session [sid: 5, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 554s iSCSI SNMP: 554s txdata_octets: 32368440 554s rxdata_octets: 44170918820 554s noptx_pdus: 0 554s scsicmd_pdus: 674075 554s tmfcmd_pdus: 0 554s login_pdus: 0 554s text_pdus: 0 554s dataout_pdus: 0 554s logout_pdus: 0 554s snack_pdus: 0 554s noprx_pdus: 0 554s scsirsp_pdus: 674075 554s tmfrsp_pdus: 0 554s textrsp_pdus: 0 554s datain_pdus: 674042 554s logoutrsp_pdus: 0 554s r2t_pdus: 0 554s async_pdus: 0 554s rjt_pdus: 0 554s digest_err: 0 554s timeout_err: 0 554s iSCSI Extended: 554s tx_sendpage_failures: 0 554s rx_discontiguous_hdr: 0 554s eh_abort_cnt: 0 554s Stats for session [sid: 6, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 554s iSCSI SNMP: 554s txdata_octets: 6504 554s rxdata_octets: 1580500 554s noptx_pdus: 0 554s scsicmd_pdus: 106 554s tmfcmd_pdus: 0 554s login_pdus: 0 554s text_pdus: 0 554s dataout_pdus: 0 554s logout_pdus: 0 554s snack_pdus: 0 554s noprx_pdus: 0 554s scsirsp_pdus: 106 554s tmfrsp_pdus: 0 554s textrsp_pdus: 0 554s datain_pdus: 84 554s logoutrsp_pdus: 0 554s r2t_pdus: 0 554s async_pdus: 0 554s rjt_pdus: 0 554s digest_err: 0 554s timeout_err: 0 554s iSCSI Extended: 554s tx_sendpage_failures: 0 554s rx_discontiguous_hdr: 0 554s eh_abort_cnt: 0 554s + sync 554s + umount /dev/disk/by-id/wwn-0x60000000000000000e00000000010001 554s + echo Final stats 554s + iscsiadm --mode session --stats 554s + journalctl --no-pager -u multipathd 554s + echo Check final path status 554s + multipath -ll 554s Aug 21 08:04:47 ubuntu systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 554s Aug 21 08:04:47 ubuntu multipathd[361]: multipathd v0.9.4: start up 554s Aug 21 08:04:47 ubuntu multipathd[361]: reconfigure: setting up paths and maps 554s Aug 21 08:04:47 ubuntu systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 554s Aug 21 08:06:56 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Stopping multipathd.service - Device-Mapper Multipath Device Controller... 554s Aug 21 08:06:56 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i multipathd[361]: multipathd: shut down 554s Aug 21 08:06:56 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: multipathd.service: Deactivated successfully. 554s Aug 21 08:06:56 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Stopped multipathd.service - Device-Mapper Multipath Device Controller. 554s Aug 21 08:06:56 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 554s Aug 21 08:06:56 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i multipathd[11826]: multipathd v0.9.4: start up 554s Aug 21 08:06:56 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i multipathd[11826]: reconfigure: setting up paths and maps 554s Aug 21 08:06:56 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 554s Aug 21 08:09:16 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i multipathd[11826]: multipathd: shut down 554s Aug 21 08:09:16 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Stopping multipathd.service - Device-Mapper Multipath Device Controller... 554s Aug 21 08:09:16 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: multipathd.service: Deactivated successfully. 554s Aug 21 08:09:16 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Stopped multipathd.service - Device-Mapper Multipath Device Controller. 554s -- Boot 9dd0068bb09345b9ae31ddfa05dba3cb -- 554s Aug 21 08:09:28 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 554s Aug 21 08:09:29 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i multipathd[300]: multipathd v0.9.9: start up 554s Aug 21 08:09:29 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i multipathd[300]: reconfigure: setting up paths and maps 554s Aug 21 08:09:29 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 554s Aug 21 08:09:44 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i multipathd[300]: multipathd: shut down 554s Aug 21 08:09:44 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Stopping multipathd.service - Device-Mapper Multipath Device Controller... 554s Aug 21 08:09:44 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: multipathd.service: Deactivated successfully. 554s Aug 21 08:09:44 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Stopped multipathd.service - Device-Mapper Multipath Device Controller. 554s -- Boot ee1fac4e0ce34e4ab6e2f3483b2fd142 -- 554s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 554s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i multipathd[328]: multipathd v0.9.9: start up 554s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i multipathd[328]: reconfigure: setting up paths and maps 554s Aug 22 00:17:47 auto-syncubuntu-oracular-daily-ppc64el-server-20240719-disk1-i systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 554s Aug 22 00:20:11 autopkgtest multipathd[328]: updated bindings file /etc/multipath/bindings 554s Aug 22 00:20:11 autopkgtest multipathd[328]: mpatha: addmap [0 204800 multipath 0 0 1 1 service-time 0 1 1 8:16 1] 554s Aug 22 00:20:11 autopkgtest multipathd[328]: sdb [8:16]: path added to devmap mpatha 554s Aug 22 00:20:11 autopkgtest multipathd[328]: mpatha: performing delayed actions 554s Aug 22 00:20:11 autopkgtest multipathd[328]: mpatha: reload [0 204800 multipath 0 0 4 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:48 1] 554s Aug 22 00:20:30 autopkgtest multipathd[328]: mpatha: reload [0 204800 multipath 0 0 3 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:48 1] 554s Aug 22 00:20:30 autopkgtest multipathd[328]: check_removed_paths: sda: freeing path in removed state 554s Aug 22 00:20:30 autopkgtest multipathd[328]: 8:0: path removed from map mpatha 554s Aug 22 00:20:40 autopkgtest multipathd[328]: 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] 554s Aug 22 00:20:40 autopkgtest multipathd[328]: check_removed_paths: sdb: freeing path in removed state 554s Aug 22 00:20:40 autopkgtest multipathd[328]: 8:16: path removed from map mpatha 554s Aug 22 00:20:50 autopkgtest multipathd[328]: sdc: mark as failed 554s Aug 22 00:20:50 autopkgtest multipathd[328]: mpatha: remaining active paths: 1 554s Aug 22 00:20:50 autopkgtest multipathd[328]: mpatha: reload [0 204800 multipath 0 0 1 1 service-time 0 1 1 8:48 1] 554s Aug 22 00:20:50 autopkgtest multipathd[328]: check_removed_paths: sdc: freeing path in removed state 554s Aug 22 00:20:50 autopkgtest multipathd[328]: 8:32: path removed from map mpatha 554s Aug 22 00:21:01 autopkgtest multipathd[328]: mpatha: reload [0 204800 multipath 0 0 2 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:0 1] 554s Aug 22 00:21:01 autopkgtest multipathd[328]: sda [8:0]: path added to devmap mpatha 554s Aug 22 00:21:01 autopkgtest multipathd[328]: mpatha: reload [0 204800 multipath 0 0 3 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:16 1] 554s Aug 22 00:21:01 autopkgtest multipathd[328]: sdb [8:16]: path added to devmap mpatha 554s Aug 22 00:21:01 autopkgtest multipathd[328]: mpatha: reload [0 204800 multipath 0 0 4 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:32 1] 554s Aug 22 00:21:01 autopkgtest multipathd[328]: sdc [8:32]: path added to devmap mpatha 554s Aug 22 00:21:01 autopkgtest multipathd[328]: mpatha: reload [0 204800 multipath 0 0 5 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:64 1] 554s Aug 22 00:21:01 autopkgtest multipathd[328]: sde [8:64]: path added to devmap mpatha 554s Aug 22 00:21:11 autopkgtest multipathd[328]: sdd: mark as failed 554s Aug 22 00:21:11 autopkgtest multipathd[328]: mpatha: remaining active paths: 4 554s Aug 22 00:21:11 autopkgtest multipathd[328]: mpatha: reload [0 204800 multipath 0 0 4 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:64 1] 554s Aug 22 00:21:11 autopkgtest multipathd[328]: check_removed_paths: sdd: freeing path in removed state 554s Aug 22 00:21:11 autopkgtest multipathd[328]: 8:48: path removed from map mpatha 554s Aug 22 00:21:11 autopkgtest multipathd[328]: mpatha: reload [0 204800 multipath 0 0 3 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:64 1] 554s Aug 22 00:21:11 autopkgtest multipathd[328]: check_removed_paths: sdc: freeing path in removed state 554s Aug 22 00:21:11 autopkgtest multipathd[328]: 8:32: path removed from map mpatha 554s Aug 22 00:21:11 autopkgtest multipathd[328]: mpatha: reload [0 204800 multipath 0 0 2 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:16 1] 554s Aug 22 00:21:11 autopkgtest multipathd[328]: check_removed_paths: sde: freeing path in removed state 554s Aug 22 00:21:11 autopkgtest multipathd[328]: 8:64: path removed from map mpatha 554s Aug 22 00:21:21 autopkgtest multipathd[328]: multipathd: shut down 554s Aug 22 00:21:21 autopkgtest systemd[1]: Stopping multipathd.service - Device-Mapper Multipath Device Controller... 554s Aug 22 00:21:21 autopkgtest systemd[1]: multipathd.service: Deactivated successfully. 554s Aug 22 00:21:21 autopkgtest systemd[1]: Stopped multipathd.service - Device-Mapper Multipath Device Controller. 554s Aug 22 00:21:21 autopkgtest systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 554s Aug 22 00:21:21 autopkgtest multipathd[6855]: multipathd v0.9.9: start up 554s Aug 22 00:21:21 autopkgtest multipathd[6855]: reconfigure: setting up paths and maps 554s Aug 22 00:21:21 autopkgtest systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 554s Check final path status 554s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 554s size=100M features='0' hwhandler='0' wp=rw 554s |-+- policy='service-time 0' prio=1 status=active 554s | `- 0:0:0:1 sda 8:0 active ready running 554s `-+- policy='service-time 0' prio=1 status=enabled 554s `- 1:0:0:1 sdb 8:16 active ready running 554s + multipath -ll 554s + grep --count status= 554s + diskc=2 554s + multipath -ll 554s + grep --count status=active 554s + diska=1 554s + multipath -ll 554s + grep --count status=enabled 554s OK 554s + diske=1 554s + [ 2 -ne 2 -o 1 -ne 1 -o 1 -ne 1 ] 554s + echo OK 554s + iscsiadm --mode node --targetname iqn.2016-11.foo.com:target.iscsi --portal 127.0.0.1:3260 --logout 554s Logging out of session [sid: 5, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 554s Logging out of session [sid: 6, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 554s Logout of [sid: 5, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 554s Logout of [sid: 6, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 554s + tgtadm --lld iscsi --op delete --mode logicalunit --tid 1 --lun 1 554s autopkgtest [00:23:21]: test tgtbasedmpaths: -----------------------] 555s tgtbasedmpaths PASS 555s autopkgtest [00:23:22]: test tgtbasedmpaths: - - - - - - - - - - results - - - - - - - - - - 555s autopkgtest [00:23:22]: @@@@@@@@@@@@@@@@@@@@ summary 555s initramfs SKIP Test lists explicitly supported architectures, but the current architecture ppc64el isn't listed. 555s initramfs SKIP Test lists explicitly supported architectures, but the current architecture ppc64el isn't listed. 555s kpartx-file-loopback PASS 555s tgtbasedmpaths PASS 561s nova [W] Using flock in prodstack6-ppc64el 561s flock: timeout while waiting to get lock 561s Creating nova instance adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f2275-prod-proposed-migration-environment-3-dbf9ef1f-aafb-448c-b0cf-96081f475010 from image adt/ubuntu-oracular-ppc64el-server-20240821.img (UUID 91e9e30d-7902-4623-8bb0-efb7d99da26f)... 561s nova [W] Using flock in prodstack6-ppc64el 561s Creating nova instance adt-oracular-ppc64el-multipath-tools-20240822-001405-juju-7f2275-prod-proposed-migration-environment-3-dbf9ef1f-aafb-448c-b0cf-96081f475010 from image adt/ubuntu-oracular-ppc64el-server-20240821.img (UUID 91e9e30d-7902-4623-8bb0-efb7d99da26f)...