0s autopkgtest [04:29:36]: starting date and time: 2024-08-16 04:29:36+0000 0s autopkgtest [04:29:36]: git checkout: fd3bed09 nova: allow more retries for quota issues 0s autopkgtest [04:29:36]: host juju-7f2275-prod-proposed-migration-environment-3; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.sbuql7qm/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-4ubuntu1 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest-big --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-3@bos01-ppc64el-17.secgroup --name adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f2275-prod-proposed-migration-environment-3-c98f137b-a772-4d72-8d34-1aef6ab37c38 --image adt/ubuntu-oracular-ppc64el-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-3 --net-id=net_prod-proposed-migration -e TERM=linux -e ''"'"'http_proxy=http://squid.internal:3128'"'"'' -e ''"'"'https_proxy=http://squid.internal:3128'"'"'' -e ''"'"'no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,keyserver.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com'"'"'' --mirror=http://us.ports.ubuntu.com/ubuntu-ports/ 98s autopkgtest [04:31:14]: testbed dpkg architecture: ppc64el 98s autopkgtest [04:31:14]: testbed apt version: 2.9.7 98s autopkgtest [04:31:14]: @@@@@@@@@@@@@@@@@@@@ test bed setup 99s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [126 kB] 99s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [8452 B] 99s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [10.4 kB] 99s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [829 kB] 101s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [99.5 kB] 102s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el Packages [138 kB] 102s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el c-n-f Metadata [6800 B] 102s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el Packages [1692 B] 102s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el c-n-f Metadata [120 B] 102s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el Packages [878 kB] 104s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el c-n-f Metadata [22.9 kB] 104s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el Packages [5620 B] 104s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el c-n-f Metadata [372 B] 105s Fetched 2126 kB in 5s (419 kB/s) 105s Reading package lists... 108s Reading package lists... 108s Building dependency tree... 108s Reading state information... 108s Calculating upgrade... 108s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 108s Reading package lists... 109s Building dependency tree... 109s Reading state information... 109s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 109s Hit:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease 109s Hit:2 http://ftpmaster.internal/ubuntu oracular InRelease 109s Hit:3 http://ftpmaster.internal/ubuntu oracular-updates InRelease 109s Hit:4 http://ftpmaster.internal/ubuntu oracular-security InRelease 110s Reading package lists... 110s Reading package lists... 110s Building dependency tree... 110s Reading state information... 111s Calculating upgrade... 111s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 111s Reading package lists... 111s Building dependency tree... 111s Reading state information... 111s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 114s autopkgtest [04:31:30]: testbed running kernel: Linux 6.8.0-31-generic #31-Ubuntu SMP Sat Apr 20 00:05:55 UTC 2024 114s autopkgtest [04:31:30]: @@@@@@@@@@@@@@@@@@@@ apt-source multipath-tools 118s Get:1 http://ftpmaster.internal/ubuntu oracular/main multipath-tools 0.9.9-1ubuntu2 (dsc) [2772 B] 118s Get:2 http://ftpmaster.internal/ubuntu oracular/main multipath-tools 0.9.9-1ubuntu2 (tar) [588 kB] 118s Get:3 http://ftpmaster.internal/ubuntu oracular/main multipath-tools 0.9.9-1ubuntu2 (diff) [42.4 kB] 118s gpgv: Signature made Tue Jul 23 21:24:22 2024 UTC 118s gpgv: using RSA key D09F8A854F1055BCFC482C4B23566B906047AFC8 118s gpgv: Can't check signature: No public key 118s dpkg-source: warning: cannot verify inline signature for ./multipath-tools_0.9.9-1ubuntu2.dsc: no acceptable signature found 118s autopkgtest [04:31:34]: testing package multipath-tools version 0.9.9-1ubuntu2 119s initramfs SKIP Test lists explicitly supported architectures, but the current architecture ppc64el isn't listed. 119s autopkgtest [04:31:35]: build not needed 120s initramfs SKIP Test lists explicitly supported architectures, but the current architecture ppc64el isn't listed. 120s autopkgtest [04:31:36]: test kpartx-file-loopback: preparing testbed 121s Reading package lists... 121s Building dependency tree... 121s Reading state information... 121s Starting pkgProblemResolver with broken count: 0 121s Starting 2 pkgProblemResolver with broken count: 0 121s Done 121s The following additional packages will be installed: 121s liburing2 qemu-utils 121s Recommended packages: 121s qemu-block-extra 121s The following NEW packages will be installed: 121s autopkgtest-satdep liburing2 qemu-utils 121s 0 upgraded, 3 newly installed, 0 to remove and 0 not upgraded. 121s Need to get 2432 kB/2433 kB of archives. 121s After this operation, 16.9 MB of additional disk space will be used. 121s Get:1 /tmp/autopkgtest.Glpwae/1-autopkgtest-satdep.deb autopkgtest-satdep ppc64el 0 [720 B] 122s Get:2 http://ftpmaster.internal/ubuntu oracular/main ppc64el liburing2 ppc64el 2.6-1 [26.9 kB] 122s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el qemu-utils ppc64el 1:9.0.2+ds-4ubuntu1 [2405 kB] 125s Fetched 2432 kB in 3s (775 kB/s) 125s Selecting previously unselected package liburing2:ppc64el. 125s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 72499 files and directories currently installed.) 125s Preparing to unpack .../liburing2_2.6-1_ppc64el.deb ... 125s Unpacking liburing2:ppc64el (2.6-1) ... 125s Selecting previously unselected package qemu-utils. 125s Preparing to unpack .../qemu-utils_1%3a9.0.2+ds-4ubuntu1_ppc64el.deb ... 125s Unpacking qemu-utils (1:9.0.2+ds-4ubuntu1) ... 125s Selecting previously unselected package autopkgtest-satdep. 125s Preparing to unpack .../1-autopkgtest-satdep.deb ... 125s Unpacking autopkgtest-satdep (0) ... 125s Setting up liburing2:ppc64el (2.6-1) ... 125s Setting up qemu-utils (1:9.0.2+ds-4ubuntu1) ... 125s Setting up autopkgtest-satdep (0) ... 125s Processing triggers for man-db (2.12.1-3) ... 126s Processing triggers for libc-bin (2.39-0ubuntu9) ... 128s (Reading database ... 72523 files and directories currently installed.) 128s Removing autopkgtest-satdep (0) ... 129s autopkgtest [04:31:45]: test kpartx-file-loopback: [----------------------- 129s Formatting 'foo.img', fmt=raw size=20971520 130s Creating new GPT entries in memory. 130s Warning: The kernel is still using the old partition table. 130s The new table will be used at the next reboot or after you 130s run partprobe(8) or kpartx(8) 130s The operation has completed successfully. 130s add map loop0p1 (252:0): 0 38879 linear 7:0 2048 130s standard_filename: OK 130s del devmap : loop0p1 130s No devices found 130s standard_filename_cleanup: OK 130s Formatting 'fou du FaFa.img', fmt=raw size=20971520 131s Creating new GPT entries in memory. 131s Warning: The kernel is still using the old partition table. 131s The new table will be used at the next reboot or after you 131s run partprobe(8) or kpartx(8) 131s The operation has completed successfully. 131s add map loop0p1 (252:0): 0 38879 linear 7:0 2048 131s filename_with_spaces: OK 131s del devmap : loop0p1 131s No devices found 131s filename_with_spaces_cleanup: OK 132s autopkgtest [04:31:48]: test kpartx-file-loopback: -----------------------] 132s autopkgtest [04:31:48]: test kpartx-file-loopback: - - - - - - - - - - results - - - - - - - - - - 132s kpartx-file-loopback PASS 133s autopkgtest [04:31:49]: test tgtbasedmpaths: preparing testbed 244s autopkgtest [04:33:40]: testbed dpkg architecture: ppc64el 244s autopkgtest [04:33:40]: testbed apt version: 2.9.7 244s autopkgtest [04:33:40]: @@@@@@@@@@@@@@@@@@@@ test bed setup 245s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [126 kB] 245s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [10.4 kB] 245s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [829 kB] 246s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [8452 B] 246s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [99.5 kB] 246s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el Packages [138 kB] 246s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el c-n-f Metadata [6800 B] 246s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el Packages [1692 B] 246s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el c-n-f Metadata [120 B] 246s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el Packages [878 kB] 246s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el c-n-f Metadata [22.9 kB] 246s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el Packages [5620 B] 246s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el c-n-f Metadata [372 B] 248s Fetched 2126 kB in 1s (1810 kB/s) 248s Reading package lists... 250s Reading package lists... 250s Building dependency tree... 250s 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... 253s Calculating upgrade... 253s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 253s Reading package lists... 254s Building dependency tree... 254s Reading state information... 254s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 259s Reading package lists... 259s Building dependency tree... 259s 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 260s 0 upgraded, 22 newly installed, 0 to remove and 0 not upgraded. 260s Need to get 10.9 MB/10.9 MB of archives. 260s After this operation, 49.6 MB of additional disk space will be used. 260s Get:1 /tmp/autopkgtest.Glpwae/2-autopkgtest-satdep.deb autopkgtest-satdep ppc64el 0 [736 B] 260s Get:2 http://ftpmaster.internal/ubuntu oracular/main ppc64el libopeniscsiusr ppc64el 2.1.10-1ubuntu1 [54.9 kB] 260s Get:3 http://ftpmaster.internal/ubuntu oracular/main ppc64el libisns0t64 ppc64el 0.101-1 [117 kB] 260s 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] 261s Get:19 http://ftpmaster.internal/ubuntu oracular/main ppc64el libpmemobj1 ppc64el 1.13.1-1.1ubuntu2 [143 kB] 261s Get:20 http://ftpmaster.internal/ubuntu oracular/main ppc64el librbd1 ppc64el 19.2.0~is.really.19.1.0-0ubuntu2 [3684 kB] 261s Get:21 http://ftpmaster.internal/ubuntu oracular/universe ppc64el fio ppc64el 3.37-1 [716 kB] 261s Get:22 http://ftpmaster.internal/ubuntu oracular/main ppc64el lsscsi ppc64el 0.32-1build1 [54.0 kB] 261s Preconfiguring packages ... 261s Fetched 10.9 MB in 2s (7276 kB/s) 261s Selecting previously unselected package libopeniscsiusr. 261s (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 ... 72499 files and directories currently installed.) 261s Preparing to unpack .../00-libopeniscsiusr_2.1.10-1ubuntu1_ppc64el.deb ... 261s Unpacking libopeniscsiusr (2.1.10-1ubuntu1) ... 261s Selecting previously unselected package libisns0t64:ppc64el. 261s Preparing to unpack .../01-libisns0t64_0.101-1_ppc64el.deb ... 261s Unpacking libisns0t64:ppc64el (0.101-1) ... 261s Selecting previously unselected package open-iscsi. 261s Preparing to unpack .../02-open-iscsi_2.1.10-1ubuntu1_ppc64el.deb ... 262s Unpacking open-iscsi (2.1.10-1ubuntu1) ... 262s Selecting previously unselected package librdmacm1t64:ppc64el. 262s Preparing to unpack .../03-librdmacm1t64_52.0-2_ppc64el.deb ... 262s Unpacking librdmacm1t64:ppc64el (52.0-2) ... 262s Selecting previously unselected package libconfig-general-perl. 262s Preparing to unpack .../04-libconfig-general-perl_2.65-2_all.deb ... 262s Unpacking libconfig-general-perl (2.65-2) ... 262s Selecting previously unselected package tgt. 262s Preparing to unpack .../05-tgt_1%3a1.0.85-1.2ubuntu1_ppc64el.deb ... 262s Unpacking tgt (1:1.0.85-1.2ubuntu1) ... 262s Selecting previously unselected package libgfxdr0:ppc64el. 262s Preparing to unpack .../06-libgfxdr0_11.1-5ubuntu1_ppc64el.deb ... 262s Unpacking libgfxdr0:ppc64el (11.1-5ubuntu1) ... 262s Selecting previously unselected package libglusterfs0:ppc64el. 262s Preparing to unpack .../07-libglusterfs0_11.1-5ubuntu1_ppc64el.deb ... 262s Unpacking libglusterfs0:ppc64el (11.1-5ubuntu1) ... 262s Selecting previously unselected package libgfrpc0:ppc64el. 262s Preparing to unpack .../08-libgfrpc0_11.1-5ubuntu1_ppc64el.deb ... 262s Unpacking libgfrpc0:ppc64el (11.1-5ubuntu1) ... 262s Selecting previously unselected package libgfapi0:ppc64el. 262s Preparing to unpack .../09-libgfapi0_11.1-5ubuntu1_ppc64el.deb ... 262s Unpacking libgfapi0:ppc64el (11.1-5ubuntu1) ... 262s Selecting previously unselected package libnbd0. 262s Preparing to unpack .../10-libnbd0_1.20.2-2_ppc64el.deb ... 262s Unpacking libnbd0 (1.20.2-2) ... 262s Selecting previously unselected package libdaxctl1:ppc64el. 262s Preparing to unpack .../11-libdaxctl1_77-2.2ubuntu1_ppc64el.deb ... 262s Unpacking libdaxctl1:ppc64el (77-2.2ubuntu1) ... 262s Selecting previously unselected package libndctl6:ppc64el. 262s Preparing to unpack .../12-libndctl6_77-2.2ubuntu1_ppc64el.deb ... 262s Unpacking libndctl6:ppc64el (77-2.2ubuntu1) ... 262s Selecting previously unselected package libpmem1:ppc64el. 262s Preparing to unpack .../13-libpmem1_1.13.1-1.1ubuntu2_ppc64el.deb ... 262s Unpacking libpmem1:ppc64el (1.13.1-1.1ubuntu2) ... 262s Selecting previously unselected package libboost-iostreams1.83.0:ppc64el. 262s Preparing to unpack .../14-libboost-iostreams1.83.0_1.83.0-3.1ubuntu1_ppc64el.deb ... 262s Unpacking libboost-iostreams1.83.0:ppc64el (1.83.0-3.1ubuntu1) ... 262s Selecting previously unselected package libboost-thread1.83.0:ppc64el. 262s Preparing to unpack .../15-libboost-thread1.83.0_1.83.0-3.1ubuntu1_ppc64el.deb ... 262s Unpacking libboost-thread1.83.0:ppc64el (1.83.0-3.1ubuntu1) ... 262s Selecting previously unselected package librados2. 262s Preparing to unpack .../16-librados2_19.2.0~is.really.19.1.0-0ubuntu2_ppc64el.deb ... 262s Unpacking librados2 (19.2.0~is.really.19.1.0-0ubuntu2) ... 262s Selecting previously unselected package libpmemobj1:ppc64el. 262s Preparing to unpack .../17-libpmemobj1_1.13.1-1.1ubuntu2_ppc64el.deb ... 262s Unpacking libpmemobj1:ppc64el (1.13.1-1.1ubuntu2) ... 262s Selecting previously unselected package librbd1. 262s Preparing to unpack .../18-librbd1_19.2.0~is.really.19.1.0-0ubuntu2_ppc64el.deb ... 262s Unpacking librbd1 (19.2.0~is.really.19.1.0-0ubuntu2) ... 262s Selecting previously unselected package fio. 262s Preparing to unpack .../19-fio_3.37-1_ppc64el.deb ... 262s Unpacking fio (3.37-1) ... 262s Selecting previously unselected package lsscsi. 262s Preparing to unpack .../20-lsscsi_0.32-1build1_ppc64el.deb ... 262s Unpacking lsscsi (0.32-1build1) ... 262s Selecting previously unselected package autopkgtest-satdep. 262s Preparing to unpack .../21-2-autopkgtest-satdep.deb ... 262s Unpacking autopkgtest-satdep (0) ... 262s Setting up libconfig-general-perl (2.65-2) ... 262s Setting up libisns0t64:ppc64el (0.101-1) ... 262s Setting up libboost-thread1.83.0:ppc64el (1.83.0-3.1ubuntu1) ... 262s Setting up libnbd0 (1.20.2-2) ... 262s Setting up libopeniscsiusr (2.1.10-1ubuntu1) ... 262s Setting up libglusterfs0:ppc64el (11.1-5ubuntu1) ... 262s Setting up libboost-iostreams1.83.0:ppc64el (1.83.0-3.1ubuntu1) ... 262s Setting up lsscsi (0.32-1build1) ... 262s Setting up libdaxctl1:ppc64el (77-2.2ubuntu1) ... 262s Setting up libndctl6:ppc64el (77-2.2ubuntu1) ... 262s Setting up librdmacm1t64:ppc64el (52.0-2) ... 262s Setting up tgt (1:1.0.85-1.2ubuntu1) ... 263s Created symlink '/etc/systemd/system/multi-user.target.wants/tgt.service' → '/usr/lib/systemd/system/tgt.service'. 263s Setting up libpmem1:ppc64el (1.13.1-1.1ubuntu2) ... 263s Setting up libgfxdr0:ppc64el (11.1-5ubuntu1) ... 263s Setting up librados2 (19.2.0~is.really.19.1.0-0ubuntu2) ... 263s Setting up open-iscsi (2.1.10-1ubuntu1) ... 264s Created symlink '/etc/systemd/system/sockets.target.wants/iscsid.socket' → '/usr/lib/systemd/system/iscsid.socket'. 264s Created symlink '/etc/systemd/system/iscsi.service' → '/usr/lib/systemd/system/open-iscsi.service'. 264s Created symlink '/etc/systemd/system/sysinit.target.wants/open-iscsi.service' → '/usr/lib/systemd/system/open-iscsi.service'. 264s Setting up libpmemobj1:ppc64el (1.13.1-1.1ubuntu2) ... 264s Setting up librbd1 (19.2.0~is.really.19.1.0-0ubuntu2) ... 264s Setting up libgfrpc0:ppc64el (11.1-5ubuntu1) ... 265s Setting up libgfapi0:ppc64el (11.1-5ubuntu1) ... 265s Setting up fio (3.37-1) ... 265s Setting up autopkgtest-satdep (0) ... 265s Processing triggers for man-db (2.12.1-3) ... 266s Processing triggers for initramfs-tools (0.142ubuntu32) ... 266s update-initramfs: Generating /boot/initrd.img-6.8.0-31-generic 266s W: No lz4 in /usr/bin:/sbin:/bin, using gzip 273s Processing triggers for libc-bin (2.39-0ubuntu9) ... 276s (Reading database ... 72740 files and directories currently installed.) 276s Removing autopkgtest-satdep (0) ... 284s autopkgtest [04:34:20]: test tgtbasedmpaths: [----------------------- 284s + targetname=iqn.2016-11.foo.com:target.iscsi 284s + pwd 284s + cwd=/tmp/autopkgtest.Glpwae/build.6gc/src 284s + testdir=/mnt/tgtmpathtest 284s + localhost=127.0.0.1 284s + portal=127.0.0.1:3260 284s + maxpaths=4 284s + backfn=backingfile 284s + expectwwid=60000000000000000e00000000010001 284s + testdisk=/dev/disk/by-id/wwn-0x60000000000000000e00000000010001 284s + bglog=/tmp/autopkgtest.Glpwae/tgtbasedmpaths-artifacts/test-background.log 284s + fioprep=/tmp/autopkgtest.Glpwae/tgtbasedmpaths-artifacts/path-change-prep.fio 284s + fiovrfy=/tmp/autopkgtest.Glpwae/tgtbasedmpaths-artifacts/path-change-check.fio 284s + mkdir -p /etc/multipath 284s + echo /360000000000000000e00000000010001/ 284s + service tgt restart 284s + truncate --size 100M backingfile 284s + tgtadm --lld iscsi --op new --mode target --tid 1 -T iqn.2016-11.foo.com:target.iscsi 284s + tgtadm --lld iscsi --op bind --mode target --tid 1 -I ALL 284s + tgtadm --lld iscsi --op new --mode logicalunit --tid 1 --lun 1 -b /tmp/autopkgtest.Glpwae/build.6gc/src/backingfile 284s + iscsiadm --mode discovery --type sendtargets --portal 127.0.0.1 284s 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi 284s login #1 284s + echo login #1 284s + iscsiadm --mode node --targetname iqn.2016-11.foo.com:target.iscsi --portal 127.0.0.1:3260 --login 284s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 284s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 284s + seq 2 4 284s extra login #2 284s + echo extra login #2 284s + iscsiadm --mode session -r 1 --op new 284s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 284s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 284s extra login #3 284s + echo extra login #3 284s + iscsiadm --mode session -r 1 --op new 284s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 284s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 284s extra login #4 284s + echo extra login #4 284s + iscsiadm --mode session -r 1 --op new 284s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 284s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 284s + udevadm settle 285s + sleep 5 290s Status after initial setup 290s + echo Status after initial setup 290s + tgtadm --lld iscsi --mode target --op show 290s Target 1: iqn.2016-11.foo.com:target.iscsi 290s System information: 290s Driver: iscsi 290s State: ready 290s I_T nexus information: 290s I_T nexus: 1 290s Initiator: iqn.2004-10.com.ubuntu:01:b58c7d304395 alias: autopkgtest 290s Connection: 0 290s IP Address: 127.0.0.1 290s I_T nexus: 2 290s Initiator: iqn.2004-10.com.ubuntu:01:b58c7d304395 alias: autopkgtest 290s Connection: 0 290s IP Address: 127.0.0.1 290s I_T nexus: 3 290s Initiator: iqn.2004-10.com.ubuntu:01:b58c7d304395 alias: autopkgtest 290s Connection: 0 290s IP Address: 127.0.0.1 290s I_T nexus: 4 290s Initiator: iqn.2004-10.com.ubuntu:01:b58c7d304395 alias: autopkgtest 290s Connection: 0 290s IP Address: 127.0.0.1 290s LUN information: 290s LUN: 0 290s Type: controller 290s SCSI ID: IET 00010000 290s SCSI SN: beaf10 290s Size: 0 MB, Block size: 1 290s Online: Yes 290s Removable media: No 290s Prevent removal: No 290s Readonly: No 290s SWP: No 290s Thin-provisioning: No 290s Backing store type: null 290s Backing store path: None 290s Backing store flags: 290s LUN: 1 290s Type: disk 290s SCSI ID: IET 00010001 290s SCSI SN: beaf11 290s Size: 105 MB, Block size: 512 290s Online: Yes 290s Removable media: No 290s Prevent removal: No 290s Readonly: No 290s SWP: No 290s Thin-provisioning: No 290s Backing store type: rdwr 290s Backing store path: /tmp/autopkgtest.Glpwae/build.6gc/src/backingfile 290s Backing store flags: 290s Account information: 290s ACL information: 290s ALL 290s + tgtadm --lld iscsi --op show --mode conn --tid 1 290s Session: 4 290s Connection: 0 290s Initiator: iqn.2004-10.com.ubuntu:01:b58c7d304395 290s IP Address: 127.0.0.1 290s Session: 3 290s Connection: 0 290s Initiator: iqn.2004-10.com.ubuntu:01:b58c7d304395 290s IP Address: 127.0.0.1 290s Session: 2 290s Connection: 0 290s Initiator: iqn.2004-10.com.ubuntu:01:b58c7d304395 290s IP Address: 127.0.0.1 290s Session: 1 290s Connection: 0 290s Initiator: iqn.2004-10.com.ubuntu:01:b58c7d304395 290s IP Address: 127.0.0.1 290s + iscsiadm --mode session -P 1 290s Target: iqn.2016-11.foo.com:target.iscsi (non-flash) 290s Current Portal: 127.0.0.1:3260,1 290s Persistent Portal: 127.0.0.1:3260,1 290s ********** 290s Interface: 290s ********** 290s Iface Name: default 290s Iface Transport: tcp 290s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:b58c7d304395 290s Iface IPaddress: 127.0.0.1 290s Iface HWaddress: default 290s Iface Netdev: default 290s SID: 1 290s iSCSI Connection State: LOGGED IN 290s iSCSI Session State: LOGGED_IN 290s Internal iscsid Session State: NO CHANGE 290s 290s ********** 290s Interface: 290s ********** 290s Iface Name: default 290s Iface Transport: tcp 290s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:b58c7d304395 290s Iface IPaddress: 127.0.0.1 290s Iface HWaddress: default 290s Iface Netdev: default 290s SID: 2 290s iSCSI Connection State: LOGGED IN 290s iSCSI Session State: LOGGED_IN 290s Internal iscsid Session State: NO CHANGE 290s 290s ********** 290s Interface: 290s ********** 290s Iface Name: default 290s Iface Transport: tcp 290s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:b58c7d304395 290s Iface IPaddress: 127.0.0.1 290s Iface HWaddress: default 290s Iface Netdev: default 290s SID: 3 290s iSCSI Connection State: LOGGED IN 290s iSCSI Session State: LOGGED_IN 290s Internal iscsid Session State: NO CHANGE 290s 290s ********** 290s Interface: 290s ********** 290s Iface Name: default 290s Iface Transport: tcp 290s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:b58c7d304395 290s Iface IPaddress: 127.0.0.1 290s Iface HWaddress: default 290s Iface Netdev: default 290s SID: 4 290s iSCSI Connection State: LOGGED IN 290s iSCSI Session State: LOGGED_IN 290s Internal iscsid Session State: NO CHANGE 290s + lsscsi -liv 290s [0:0:0:0] disk QEMU QEMU HARDDISK 2.5+ /dev/sda 0QEMU_QEMU_HARDDISK_drive-scsi0-0-0-0 290s state=running queue_depth=128 scsi_level=6 type=0 device_blocked=0 timeout=30 290s dir: /sys/bus/scsi/devices/0:0:0:0 [/sys/devices/pci0000:00/0000:00:02.0/virtio1/host0/target0:0:0/0:0:0:0] 290s [1:0:0:0] storage IET Controller 0001 - - 290s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 290s dir: /sys/bus/scsi/devices/1:0:0:0 [/sys/devices/platform/host1/session1/target1:0:0/1:0:0:0] 290s [1:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdb 360000000000000000e00000000010001 290s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 290s dir: /sys/bus/scsi/devices/1:0:0:1 [/sys/devices/platform/host1/session1/target1:0:0/1:0:0:1] 290s [2:0:0:0] storage IET Controller 0001 - - 290s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 290s dir: /sys/bus/scsi/devices/2:0:0:0 [/sys/devices/platform/host2/session2/target2:0:0/2:0:0:0] 290s [2:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdc 360000000000000000e00000000010001 290s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 290s dir: /sys/bus/scsi/devices/2:0:0:1 [/sys/devices/platform/host2/session2/target2:0:0/2:0:0:1] 290s [3:0:0:0] storage IET Controller 0001 - - 290s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 290s dir: /sys/bus/scsi/devices/3:0:0:0 [/sys/devices/platform/host3/session3/target3:0:0/3:0:0:0] 290s [3:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdd 360000000000000000e00000000010001 290s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 290s dir: /sys/bus/scsi/devices/3:0:0:1 [/sys/devices/platform/host3/session3/target3:0:0/3:0:0:1] 290s [4:0:0:0] storage IET Controller 0001 - - 290s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 290s dir: /sys/bus/scsi/devices/4:0:0:0 [/sys/devices/platform/host4/session4/target4:0:0/4:0:0:0] 290s [4:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sde 33000000100000001 290s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 290s dir: /sys/bus/scsi/devices/4:0:0:1 [/sys/devices/platform/host4/session4/target4:0:0/4:0:0:1] 290s NVMe module may not be loaded 290s list_ndevices: scandir: /sys/class/nvme/: No such file or directory 290s + multipath -v3 -ll 290s 75.775913 | set open fds limit to 1073741816/1073741816 290s 75.775961 | _read_bindings_file: reading /etc/multipath/bindings 290s 75.775995 | loading /usr/lib/multipath/libchecktur.so checker 290s 75.776166 | checker tur: message table size = 4 290s 75.776203 | loading /usr/lib/multipath/libprioconst.so prioritizer 290s 75.776328 | _init_foreign: foreign library "nvme" is not enabled 290s 75.781973 | sda: size = 167772160 290s 75.782143 | sda: vendor = QEMU 290s 75.782167 | sda: product = QEMU HARDDISK 290s 75.782190 | sda: rev = 2.5+ 290s 75.782809 | sda: h:b:t:l = 0:0:0:0 290s 75.783130 | sda: tgt_node_name = 290s 75.783156 | sda: uid_attribute = ID_SERIAL (setting: multipath internal) 290s 75.783159 | sda: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 290s 75.783317 | sda: 10443 cyl, 255 heads, 63 sectors/track, start at 0 290s 75.783341 | sda: vpd_vendor_id = 0 "undef" (setting: multipath internal) 290s 75.783356 | __sysfs_attr_get_value: attribute '/sys/devices/pci0000:00/0000:00:02.0/virtio1/host0/target0:0:0/0:0:0:0/vpd_pg80' cannot be opened: No such file or directory 290s 75.783361 | failed to read sysfs vpd pg80: No such file or directory 290s 75.783613 | sda: fail to get serial 290s 75.783636 | sda: detect_checker = yes (setting: multipath internal) 290s 75.783669 | sda checker timeout = 30 s (setting: kernel sysfs) 290s 75.783833 | sda: path_checker = tur (setting: multipath internal) 290s 75.783916 | sda: tur state = up 290s 75.784278 | sdb: size = 204800 290s 75.784437 | sdb: vendor = IET 290s 75.784480 | sdb: product = VIRTUAL-DISK 290s 75.784502 | sdb: rev = 0001 290s 75.785122 | sdb: h:b:t:l = 1:0:0:1 290s 75.785506 | sdb: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 290s 75.785509 | sdb: uid_attribute = ID_SERIAL (setting: multipath internal) 290s 75.785511 | sdb: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 290s 75.785668 | sdb: 1024 cyl, 4 heads, 50 sectors/track, start at 0 290s 75.785692 | sdb: vpd_vendor_id = 0 "undef" (setting: multipath internal) 290s 75.785709 | sdb: serial = beaf11 290s 75.785712 | sdb: detect_checker = yes (setting: multipath internal) 290s 75.785741 | sdb checker timeout = 30 s (setting: kernel sysfs) 290s 75.786022 | sdb: path_checker = tur (setting: multipath internal) 290s 75.786359 | sdb: tur state = up 290s 75.786501 | sdc: size = 204800 290s 75.786634 | sdc: vendor = IET 290s 75.786679 | sdc: product = VIRTUAL-DISK 290s 75.786701 | sdc: rev = 0001 290s 75.787380 | sdc: h:b:t:l = 2:0:0:1 290s 75.787766 | sdc: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 290s 75.787790 | sdc: uid_attribute = ID_SERIAL (setting: multipath internal) 290s 75.787793 | sdc: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 290s 75.787943 | sdc: 1024 cyl, 4 heads, 50 sectors/track, start at 0 290s 75.787966 | sdc: vpd_vendor_id = 0 "undef" (setting: multipath internal) 290s 75.787981 | sdc: serial = beaf11 290s 75.787983 | sdc: detect_checker = yes (setting: multipath internal) 290s 75.788018 | sdc checker timeout = 30 s (setting: kernel sysfs) 290s 75.788250 | sdc: path_checker = tur (setting: multipath internal) 290s 75.788497 | sdc: tur state = up 290s 75.788659 | sdd: size = 204800 290s 75.788817 | sdd: vendor = IET 290s 75.788860 | sdd: product = VIRTUAL-DISK 290s 75.788882 | sdd: rev = 0001 290s 75.789570 | sdd: h:b:t:l = 3:0:0:1 290s 75.789940 | sdd: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 290s 75.789963 | sdd: uid_attribute = ID_SERIAL (setting: multipath internal) 290s 75.789966 | sdd: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 290s 75.790118 | sdd: 1024 cyl, 4 heads, 50 sectors/track, start at 0 290s 75.790141 | sdd: vpd_vendor_id = 0 "undef" (setting: multipath internal) 290s 75.790155 | sdd: serial = beaf11 290s 75.790157 | sdd: detect_checker = yes (setting: multipath internal) 290s 75.790195 | sdd checker timeout = 30 s (setting: kernel sysfs) 290s 75.790384 | sdd: path_checker = tur (setting: multipath internal) 290s 75.790562 | sdd: tur state = up 290s 75.790712 | sde: size = 204800 290s 75.790877 | sde: vendor = IET 290s 75.790921 | sde: product = VIRTUAL-DISK 290s 75.790943 | sde: rev = 0001 290s 75.791626 | sde: h:b:t:l = 4:0:0:1 290s 75.791993 | sde: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 290s 75.792031 | sde: uid_attribute = ID_SERIAL (setting: multipath internal) 290s 75.792034 | sde: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 290s 75.792202 | sde: 1024 cyl, 4 heads, 50 sectors/track, start at 0 290s 75.792226 | sde: vpd_vendor_id = 0 "undef" (setting: multipath internal) 290s 75.792241 | sde: serial = beaf11 290s 75.792243 | sde: detect_checker = yes (setting: multipath internal) 290s 75.792272 | sde checker timeout = 30 s (setting: kernel sysfs) 290s 75.792465 | sde: path_checker = tur (setting: multipath internal) 290s 75.792668 | sde: tur state = up 290s 75.792830 | loop0: device node name blacklisted 290s 75.792986 | loop1: device node name blacklisted 290s 75.793132 | loop2: device node name blacklisted 290s 75.793277 | loop3: device node name blacklisted 290s 75.793426 | loop4: device node name blacklisted 290s 75.793574 | loop5: device node name blacklisted 290s 75.793718 | loop6: device node name blacklisted 290s 75.793866 | loop7: device node name blacklisted 290s 75.794022 | dm-0: device node name blacklisted 290s 75.795343 | multipath-tools v0.9.9 (05/03, 2024) 290s 75.795375 | libdevmapper version 1.02.196 290s 75.795535 | kernel device mapper v4.48.0 290s 75.795568 | DM multipath kernel driver v1.14.0 290s 75.795691 | sdb: size = 204800 290s 75.795716 | sdb: vendor = IET 290s 75.795719 | sdb: product = VIRTUAL-DISK 290s 75.795721 | sdb: rev = 0001 290s 75.796406 | sdb: h:b:t:l = 1:0:0:1 290s 75.796551 | sdb: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 290s 75.796591 | sdb: 1024 cyl, 4 heads, 50 sectors/track, start at 0 290s 75.796594 | sdb: vpd_vendor_id = 0 "undef" (setting: multipath internal) 290s 75.796606 | sdb: serial = beaf11 290s 75.796773 | sdb: tur state = up 290s 75.796795 | sdb: uid = 360000000000000000e00000000010001 (udev) 290s 75.796798 | sdb: detect_prio = yes (setting: multipath internal) 290s 75.796802 | sdb: prio = const (setting: multipath internal) 290s 75.796804 | sdb: prio args = "" (setting: multipath internal) 290s 75.796806 | sdb: const prio = 1 290s 75.796828 | sdc: size = 204800 290s 75.796832 | sdc: vendor = IET 290s 75.796835 | sdc: product = VIRTUAL-DISK 290s 75.796838 | sdc: rev = 0001 290s 75.797442 | sdc: h:b:t:l = 2:0:0:1 290s 75.797574 | sdc: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 290s 75.797616 | sdc: 1024 cyl, 4 heads, 50 sectors/track, start at 0 290s 75.797619 | sdc: vpd_vendor_id = 0 "undef" (setting: multipath internal) 290s 75.797631 | sdc: serial = beaf11 290s 75.797791 | sdc: tur state = up 290s 75.797814 | sdc: uid = 360000000000000000e00000000010001 (udev) 290s 75.797816 | sdc: detect_prio = yes (setting: multipath internal) 290s 75.797819 | sdc: prio = const (setting: multipath internal) 290s 75.797821 | sdc: prio args = "" (setting: multipath internal) 290s 75.797823 | sdc: const prio = 1 290s 75.797846 | sdd: size = 204800 290s 75.797851 | sdd: vendor = IET 290s 75.797854 | sdd: product = VIRTUAL-DISK 290s 75.797856 | sdd: rev = 0001 290s 75.798462 | sdd: h:b:t:l = 3:0:0:1 290s 75.798593 | sdd: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 290s 75.798634 | sdd: 1024 cyl, 4 heads, 50 sectors/track, start at 0 290s 75.798637 | sdd: vpd_vendor_id = 0 "undef" (setting: multipath internal) 290s 75.798648 | sdd: serial = beaf11 290s ===== paths list ===== 290s uuid hcil dev dev_t pri dm_st chk_st vend/prod/rev dev_st 290s 0:0:0:0 sda 8:0 -1 undef undef QEMU,QEMU HARDDISK,2.5+ unknown 290s 1:0:0:1 sdb 8:16 -1 undef undef IET,VIRTUAL-DISK,0001 unknown 290s 2:0:0:1 sdc 8:32 -1 undef undef IET,VIRTUAL-DISK,0001 unknown 290s 3:0:0:1 sdd 8:48 -1 undef undef IET,VIRTUAL-DISK,0001 unknown 290s 4:0:0:1 sde 8:64 -1 undef undef IET,VIRTUAL-DISK,0001 unknown 290s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 290s size=100M features='0' hwhandler='0' wp=rw 290s |-+- policy='service-time 0' prio=1 status=active 290s | `- 1:0:0:1 sdb 8:16 active ready running 290s |-+- policy='service-time 0' prio=1 status=enabled 290s | `- 2:0:0:1 sdc 8:32 active ready running 290s |-+- policy='service-time 0' prio=1 status=enabled 290s | `- 3:0:0:1 sdd 8:48 active ready running 290s `-+- policy='service-time 0' prio=1 status=enabled 290s `- 4:0:0:1 sde 8:64 active ready running 290s mpatha: 0 204800 multipath 0 0 4 1 service-time 0 1 2 8:16 1 1 service-time 0 1 2 8:32 1 1 service-time 0 1 2 8:48 1 1 service-time 0 1 2 8:64 1 1 290s /etc/multipath/bindings:# Multipath bindings, Version : 1.0 290s /etc/multipath/bindings:# NOTE: this file is automatically maintained by the multipath program. 290s /etc/multipath/bindings:# You should not need to edit this file in normal circumstances. 290s /etc/multipath/bindings:# 290s /etc/multipath/bindings:# Format: 290s /etc/multipath/bindings:# alias wwid 290s /etc/multipath/bindings:# 290s /etc/multipath/bindings:mpatha 360000000000000000e00000000010001 290s /etc/multipath/wwids:/360000000000000000e00000000010001/ 290s ● multipathd.service - Device-Mapper Multipath Device Controller 290s Loaded: loaded (/usr/lib/systemd/system/multipathd.service; enabled; preset: enabled) 290s Active: active (running) since Fri 2024-08-16 04:33:13 UTC; 1min 12s ago 290s Invocation: ddeaf6cf856847ecb506cca41cda949e 290s TriggeredBy: ● multipathd.socket 290s Main PID: 341 (multipathd) 290s Status: "up" 290s Tasks: 7 290s Memory: 28.3M (peak: 35.8M) 290s CPU: 60ms 290s CGroup: /system.slice/multipathd.service 290s └─341 /sbin/multipathd -d -s 290s 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 multipathd[341]: multipathd v0.9.9: start up 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 multipathd[341]: reconfigure: setting up paths and maps 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 290s Aug 16 04:34:20 autopkgtest multipathd[341]: updated bindings file /etc/multipath/bindings 290s Aug 16 04:34:20 autopkgtest multipathd[341]: mpatha: addmap [0 204800 multipath 0 0 1 1 service-time 0 1 1 8:16 1] 290s Aug 16 04:34:20 autopkgtest multipathd[341]: sdb [8:16]: path added to devmap mpatha 290s Aug 16 04:34:20 autopkgtest multipathd[341]: mpatha: performing delayed actions 290s Aug 16 04:34:20 autopkgtest multipathd[341]: mpatha: reload [0 204800 multipath 0 0 4 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:64 1] 290s ● multipathd.socket - multipathd control socket 290s Loaded: loaded (/usr/lib/systemd/system/multipathd.socket; enabled; preset: enabled) 290s Active: active (running) since Fri 2024-08-16 04:33:13 UTC; 1min 12s ago 290s Invocation: 9f01539392eb44fca55e312c7d70a73c 290s Triggers: ● multipathd.service 290s Listen: @/org/kernel/linux/storage/multipathd (Stream) 290s CGroup: /system.slice/multipathd.socket 290s 290s Notice: journal has been rotated since unit was started, output may be incomplete. 290s total 0 290s drwxr-xr-x 2 root root 80 Aug 16 04:34 . 290s drwxr-xr-x 18 root root 4260 Aug 16 04:34 .. 290s crw------- 1 root root 10, 236 Aug 16 04:33 control 290s lrwxrwxrwx 1 root root 7 Aug 16 04:34 mpatha -> ../dm-0 290s journal 290s 75.798754 | sdd: tur state = up 290s 75.798776 | sdd: uid = 360000000000000000e00000000010001 (udev) 290s 75.798778 | sdd: detect_prio = yes (setting: multipath internal) 290s 75.798781 | sdd: prio = const (setting: multipath internal) 290s 75.798783 | sdd: prio args = "" (setting: multipath internal) 290s 75.798785 | sdd: const prio = 1 290s 75.798807 | sde: size = 204800 290s 75.798812 | sde: vendor = IET 290s 75.798814 | sde: product = VIRTUAL-DISK 290s 75.798817 | sde: rev = 0001 290s 75.799421 | sde: h:b:t:l = 4:0:0:1 290s 75.799554 | sde: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 290s 75.799593 | sde: 1024 cyl, 4 heads, 50 sectors/track, start at 0 290s 75.799596 | sde: vpd_vendor_id = 0 "undef" (setting: multipath internal) 290s 75.799608 | sde: serial = beaf11 290s 75.799773 | sde: tur state = up 290s 75.799798 | sde: uid = 360000000000000000e00000000010001 (udev) 290s 75.799800 | sde: detect_prio = yes (setting: multipath internal) 290s 75.799803 | sde: prio = const (setting: multipath internal) 290s 75.799805 | sde: prio args = "" (setting: multipath internal) 290s 75.799807 | sde: const prio = 1 290s 75.800723 | unloading tur checker 290s 75.800805 | unloading const prioritizer 290s + dmsetup table 290s + grep . /etc/multipath/bindings /etc/multipath/wwids 290s + systemctl status multipathd.service 290s + systemctl status multipathd.socket 290s + ls -la /dev/mapper/ 290s + echo journal 290s + journalctl -b 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: radix-mmu: Page sizes from device-tree: 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: radix-mmu: Page size shift = 12 AP=0x0 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: radix-mmu: Page size shift = 16 AP=0x5 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: radix-mmu: Page size shift = 21 AP=0x1 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: radix-mmu: Page size shift = 30 AP=0x2 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Activating Kernel Userspace Access Prevention 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Activating Kernel Userspace Execution Prevention 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: radix-mmu: Mapped 0x0000000000000000-0x00000000038a0000 with 64.0 KiB pages (exec) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: radix-mmu: Mapped 0x00000000038a0000-0x0000000200000000 with 64.0 KiB pages 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: lpar: Using radix MMU under hypervisor 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 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) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Secure boot mode disabled 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Found initrd at 0xc000000006200000:0xc0000000093eb432 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Hardware name: IBM pSeries (emulated by qemu) POWER9 (raw) 0x4e1203 0xf000005 of:SLOF,HEAD hv:linux,kvm pSeries 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: printk: legacy bootconsole [udbg0] enabled 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Partition configured for 4 cpus. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: CPU maps initialized for 1 thread per core 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: (thread shift is 0) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Allocated 3360 bytes for 4 pacas 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: numa: Partition configured for 1 NUMA nodes. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: ----------------------------------------------------- 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: phys_mem_size = 0x200000000 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: dcache_bsize = 0x80 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: icache_bsize = 0x80 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: cpu_features = 0x0001c06b8f4f9187 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: possible = 0x001ffbfbcf5fb187 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: always = 0x0000000380008181 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: cpu_user_features = 0xdc0065c2 0xaef00000 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: mmu_features = 0x3c007641 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: firmware_features = 0x00000085455a445f 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: vmalloc start = 0xc008000000000000 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: IO start = 0xc00a000000000000 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: vmemmap start = 0xc00c000000000000 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: ----------------------------------------------------- 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: numa: NODE_DATA [mem 0x1eff10280-0x1eff17fff] 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: rfi-flush: fallback displacement flush available 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: rfi-flush: ori type flush available 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: rfi-flush: mttrig type flush available 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: rfi-flush: patched 12 locations (ori+mttrig type flush) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: count-cache-flush: software flush enabled. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: link-stack-flush: software flush enabled. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: entry-flush: patched 61 locations (ori+mttrig type flush) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: uaccess-flush: patched 1 locations (ori+mttrig type flush) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: stf-barrier: eieio barrier available 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: stf-barrier: patched 61 entry locations (eieio barrier) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: stf-barrier: patched 12 exit locations (eieio barrier) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: PPC64 nvram contains 65536 bytes 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: barrier-nospec: using ORI speculation barrier 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: barrier-nospec: patched 269 locations 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Top of RAM: 0x200000000, Total RAM: 0x200000000 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Memory hole size: 0MB 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Zone ranges: 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Normal [mem 0x0000000000000000-0x00000001ffffffff] 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Device empty 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Movable zone start for each node 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Early memory node ranges 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: node 0: [mem 0x0000000000000000-0x00000001ffffffff] 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Initmem setup node 0 [mem 0x0000000000000000-0x00000001ffffffff] 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: percpu: Embedded 12 pages/cpu s609960 r0 d176472 u786432 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: pcpu-alloc: s609960 r0 d176472 u786432 alloc=12*65536 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Kernel command line: BOOT_IMAGE=/boot/vmlinux-6.8.0-31-generic root=UUID=f999abd5-af41-40ac-8675-cf1e7d4878fb ro console=hvc0 earlyprintk 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Unknown kernel command line parameters "earlyprintk BOOT_IMAGE=/boot/vmlinux-6.8.0-31-generic", will be passed to user space. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Dentry cache hash table entries: 1048576 (order: 7, 8388608 bytes, linear) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Inode-cache hash table entries: 524288 (order: 6, 4194304 bytes, linear) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Fallback order for Node 0: 0 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Built 1 zonelists, mobility grouping on. Total pages: 130944 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Policy zone: Normal 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: mem auto-init: stack:all(zero), heap alloc:on, heap free:off 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Memory: 7969152K/8388608K available (23680K kernel code, 4096K rwdata, 25472K rodata, 8832K init, 1901K bss, 419456K reserved, 0K cma-reserved) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: SLUB: HWalign=128, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: ftrace: allocating 51717 entries in 19 pages 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: ftrace: allocated 19 pages with 3 groups 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: trace event string verifier disabled 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: rcu: Hierarchical RCU implementation. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: rcu: RCU restricting CPUs from NR_CPUS=2048 to nr_cpu_ids=4. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Rude variant of Tasks RCU enabled. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Tracing variant of Tasks RCU enabled. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: NR_IRQS: 512, nr_irqs: 512, preallocated irqs: 16 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: xive: Using IRQ range [0-3] 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: xive: Interrupt handling initialized with spapr backend 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: xive: Using priority 6 for all interrupts 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: xive: Using 64kB queues 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: rcu: srcu_init: Setting srcu_struct sizes based on contention. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: time_init: decrementer frequency = 512.000000 MHz 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: time_init: processor frequency = 2700.000000 MHz 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: time_init: 56 bit decrementer (max: 7fffffffffffff) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: clocksource: timebase: mask: 0xffffffffffffffff max_cycles: 0x761537d007, max_idle_ns: 440795202126 ns 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: clocksource: timebase mult[1f40000] shift[24] registered 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: clockevent: decrementer mult[83126f] shift[24] cpu[0] 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Console: colour dummy device 80x25 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: printk: legacy console [hvc0] enabled 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: printk: legacy bootconsole [udbg0] disabled 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: pid_max: default: 32768 minimum: 301 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: LSM: initializing lsm=lockdown,capability,landlock,yama,apparmor,integrity 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: landlock: Up and running. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Yama: becoming mindful. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: AppArmor: AppArmor initialized 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Mount-cache hash table entries: 16384 (order: 1, 131072 bytes, linear) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Mountpoint-cache hash table entries: 16384 (order: 1, 131072 bytes, linear) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: RCU Tasks Rude: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: RCU Tasks Trace: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: POWER9 performance monitor hardware support registered 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: rcu: Hierarchical SRCU implementation. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: rcu: Max phase no-delay instances is 1000. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: smp: Bringing up secondary CPUs ... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: smp: Brought up 1 node, 4 CPUs 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: numa: Node 0 CPUs: 0-3 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: devtmpfs: initialized 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: PCI host bridge /pci@800000020000000 ranges: 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: IO 0x0000200000000000..0x000020000000ffff -> 0x0000000000000000 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: MEM 0x0000200080000000..0x00002000ffffffff -> 0x0000000080000000 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: MEM 0x0000210000000000..0x000021ffffffffff -> 0x0000210000000000 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: PCI: OF: PROBE_ONLY disabled 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: futex hash table entries: 1024 (order: 1, 131072 bytes, linear) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: pinctrl core: initialized pinctrl subsystem 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: NET: Registered PF_NETLINK/PF_ROUTE protocol family 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: audit: initializing netlink subsys (disabled) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: audit: type=2000 audit(1723782790.040:1): state=initialized audit_enabled=0 res=1 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: thermal_sys: Registered thermal governor 'fair_share' 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: thermal_sys: Registered thermal governor 'bang_bang' 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: thermal_sys: Registered thermal governor 'step_wise' 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: thermal_sys: Registered thermal governor 'user_space' 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: thermal_sys: Registered thermal governor 'power_allocator' 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: cpuidle: using governor ladder 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: cpuidle: using governor menu 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: RTAS daemon started 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: pstore: Using crash dump compression: deflate 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: pstore: Registered nvram as persistent store backend 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: EEH: pSeries platform initialized 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: iommu: Default domain type: Translated 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: iommu: DMA domain TLB invalidation policy: strict mode 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: SCSI subsystem initialized 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: libata version 3.00 loaded. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: usbcore: registered new interface driver usbfs 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: usbcore: registered new interface driver hub 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: usbcore: registered new device driver usb 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: pps_core: LinuxPPS API ver. 1 registered 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: PTP clock support registered 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: EDAC MC: Ver: 3.0.0 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: NetLabel: Initializing 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: NetLabel: domain hash size = 128 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: NetLabel: unlabeled traffic allowed by default 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: mctp: management component transport protocol core 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: NET: Registered PF_MCTP protocol family 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: PCI: Probing PCI hardware 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: PCI host bridge to bus 0000:00 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: pci_bus 0000:00: root bus resource [io 0x10000-0x1ffff] (bus address [0x0000-0xffff]) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: pci_bus 0000:00: root bus resource [mem 0x200080000000-0x2000ffffffff] (bus address [0x80000000-0xffffffff]) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: pci_bus 0000:00: root bus resource [mem 0x210000000000-0x21ffffffffff 64bit] 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: pci_bus 0000:00: root bus resource [bus 00-ff] 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: pci 0000:00:01.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: pci 0000:00:02.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: pci 0000:00:03.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: pci 0000:00:04.0: No hypervisor support for SR-IOV on this device, IOV BARs disabled. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: IOMMU table initialized, virtual merging enabled 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: PCI 0000:00 Cannot reserve Legacy IO [io 0x10000-0x10fff] 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: pci_bus 0000:00: resource 4 [io 0x10000-0x1ffff] 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: pci_bus 0000:00: resource 5 [mem 0x200080000000-0x2000ffffffff] 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: pci_bus 0000:00: resource 6 [mem 0x210000000000-0x21ffffffffff 64bit] 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: pci 0000:00:01.0: Adding to iommu group 0 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: pci 0000:00:02.0: Adding to iommu group 0 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: pci 0000:00:03.0: Adding to iommu group 0 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: pci 0000:00:04.0: Adding to iommu group 0 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: EEH: No capable adapters found: recovery disabled. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: PCI: Probing PCI hardware done 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: vgaarb: loaded 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: clocksource: Switched to clocksource timebase 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: VFS: Disk quotas dquot_6.6.0 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: VFS: Dquot-cache hash table entries: 8192 (order 0, 65536 bytes) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: AppArmor: AppArmor Filesystem Enabled 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: NET: Registered PF_INET protocol family 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: IP idents hash table entries: 131072 (order: 4, 1048576 bytes, linear) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: tcp_listen_portaddr_hash hash table entries: 4096 (order: 0, 65536 bytes, linear) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Table-perturb hash table entries: 65536 (order: 2, 262144 bytes, linear) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: TCP established hash table entries: 65536 (order: 3, 524288 bytes, linear) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: TCP bind hash table entries: 65536 (order: 5, 2097152 bytes, linear) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: TCP: Hash tables configured (established 65536 bind 65536) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: MPTCP token hash table entries: 8192 (order: 1, 196608 bytes, linear) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: UDP hash table entries: 4096 (order: 1, 131072 bytes, linear) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: UDP-Lite hash table entries: 4096 (order: 1, 131072 bytes, linear) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: NET: Registered PF_UNIX/PF_LOCAL protocol family 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: NET: Registered PF_XDP protocol family 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: PCI: CLS 0 bytes, default 128 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Trying to unpack rootfs image as initramfs... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Initialise system trusted keyrings 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Key type blacklist registered 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: workingset: timestamp_bits=38 max_order=17 bucket_order=0 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: zbud: loaded 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: fuse: init (API version 7.39) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: integrity: Platform Keyring initialized 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: integrity: Machine keyring initialized 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Key type asymmetric registered 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Asymmetric key parser 'x509' registered 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 243) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: io scheduler mq-deadline registered 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: virtio-pci 0000:00:01.0: enabling device (0100 -> 0103) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: virtio-pci 0000:00:01.0: ibm,query-pe-dma-windows(2026) 800 8000000 20000000 returned 0, lb=80000000 ps=7 wn=1 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 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) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: virtio-pci 0000:00:02.0: enabling device (0100 -> 0103) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: virtio-pci 0000:00:04.0: enabling device (0100 -> 0103) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Non-volatile memory driver v1.3 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Linux agpgart interface v0.103 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: loop: module loaded 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: virtio_scsi virtio1: 1/0/0 default/read/poll queues 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: scsi host0: Virtio SCSI HBA 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: tun: Universal TUN/TAP device driver, 1.6 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: scsi 0:0:0:0: Direct-Access QEMU QEMU HARDDISK 2.5+ PQ: 0 ANSI: 5 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: PPP generic driver version 2.4.2 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: mousedev: PS/2 mouse device common for all mice 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: rtc-generic rtc-generic: registered as rtc0 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: rtc-generic rtc-generic: setting system clock to 2024-08-16T04:33:10 UTC (1723782790) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: i2c_dev: i2c /dev entries driver 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: device-mapper: uevent: version 1.0.3 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@redhat.com 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: pseries_idle_driver registered 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: ledtrig-cpu: registered to indicate activity on CPUs 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: drop_monitor: Initializing network drop monitor service 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: NET: Registered PF_INET6 protocol family 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: scsi 0:0:0:0: Attached scsi generic sg0 type 0 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: sd 0:0:0:0: Power-on or device reset occurred 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: sd 0:0:0:0: [sda] 167772160 512-byte logical blocks: (85.9 GB/80.0 GiB) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: sd 0:0:0:0: [sda] Write Protect is off 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: sd 0:0:0:0: [sda] Mode Sense: 63 00 00 08 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: GPT:Primary header thinks Alt. header is not at the end of the disk. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: GPT:41943039 != 167772159 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: GPT:Alternate GPT header not at the end of the disk. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: GPT:41943039 != 167772159 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: GPT: Use GNU Parted to correct GPT errors. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: sda: sda1 sda2 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: sd 0:0:0:0: [sda] Attached SCSI disk 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Freeing initrd memory: 51072K 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Segment Routing with IPv6 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: In-situ OAM (IOAM) with IPv6 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: NET: Registered PF_PACKET protocol family 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Key type dns_resolver registered 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: secvar-sysfs: Failed to retrieve secvar operations 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: drmem: No dynamic reconfiguration memory found 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: registered taskstats version 1 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Loading compiled-in X.509 certificates 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Loaded X.509 cert 'Build time autogenerated kernel key: d20be259617023e52b002c562b3536c6f73da543' 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Loaded X.509 cert 'Canonical Ltd. Live Patch Signing: 14df34d1a87cf37625abec039ef2bf521249b969' 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Loaded X.509 cert 'Canonical Ltd. Kernel Module Signing: 88f752e560a1e0737e31163a466ad7b70a850c19' 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: blacklist: Loading compiled-in revocation X.509 certificates 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing: 61482aa2830d0ab2ad5af10b7250da9033ddcef0' 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2017): 242ade75ac4a15e50d50c84b0d45ff3eae707a03' 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (ESM 2018): 365188c1d374d6b07c3c8f240f8ef722433d6a8b' 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2019): c0746fd6c5da3ae827864651ad66ae47fe24b3e8' 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2021 v1): a8d54bbb3825cfb94fa13c9f8a594a195c107b8d' 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2021 v2): 4cf046892d6fd3c9a5b03f98d845f90851dc6a8c' 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (2021 v3): 100437bb6de6e469b581e61cd66bce3ef4ed53af' 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Loaded X.509 cert 'Canonical Ltd. Secure Boot Signing (Ubuntu Core 2019): c1d57b8f6b743f23ee41f4f7ee292f06eecadfb9' 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Key type .fscrypt registered 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Key type fscrypt-provisioning registered 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Key type encrypted registered 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: AppArmor: AppArmor sha256 policy hashing enabled 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Secure boot mode disabled 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: ima: No TPM chip found, activating TPM-bypass! 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Loading compiled-in module X.509 certificates 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Loaded X.509 cert 'Build time autogenerated kernel key: d20be259617023e52b002c562b3536c6f73da543' 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: ima: Allocated hash algorithm: sha256 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Secure boot mode disabled 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Trusted boot mode disabled 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: ima: No architecture policies found 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: evm: Initialising EVM extended attributes: 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: evm: security.selinux 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: evm: security.SMACK64 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: evm: security.SMACK64EXEC 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: evm: security.SMACK64TRANSMUTE 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: evm: security.SMACK64MMAP 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: evm: security.apparmor 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: evm: security.ima 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: evm: security.capability 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: evm: HMAC attrs: 0x1 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: SED: plpks not available 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: clk: Disabling unused clocks 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: integrity: Unable to open file: /etc/keys/x509_evm.der (-2) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Freeing unused kernel image (initmem) memory: 8832K 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Checked W+X mappings: passed, no W+X pages found 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Run /init as init process 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: with arguments: 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: /init 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: earlyprintk 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: with environment: 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: HOME=/ 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: TERM=linux 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: BOOT_IMAGE=/boot/vmlinux-6.8.0-31-generic 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: virtio_net virtio0 enp0s1: renamed from eth0 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: xhci_hcd 0000:00:03.0: xHCI Host Controller 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: xhci_hcd 0000:00:03.0: new USB bus registered, assigned bus number 1 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: xhci_hcd 0000:00:03.0: hcc params 0x00087001 hci version 0x100 quirks 0x0000000000000010 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: xhci_hcd 0000:00:03.0: xHCI Host Controller 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: xhci_hcd 0000:00:03.0: new USB bus registered, assigned bus number 2 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: xhci_hcd 0000:00:03.0: Host supports USB 3.0 SuperSpeed 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.08 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: usb usb1: Product: xHCI Host Controller 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: usb usb1: Manufacturer: Linux 6.8.0-31-generic xhci-hcd 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: usb usb1: SerialNumber: 0000:00:03.0 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: hub 1-0:1.0: USB hub found 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: hub 1-0:1.0: 4 ports detected 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: usb usb2: We don't know the algorithms for LPM for this host, disabling LPM. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 6.08 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: usb usb2: Product: xHCI Host Controller 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: usb usb2: Manufacturer: Linux 6.8.0-31-generic xhci-hcd 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: usb usb2: SerialNumber: 0000:00:03.0 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: hub 2-0:1.0: USB hub found 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: hub 2-0:1.0: 4 ports detected 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: raid6: vpermxor8 gen() 22728 MB/s 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: raid6: vpermxor4 gen() 19792 MB/s 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: raid6: vpermxor2 gen() 15960 MB/s 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: raid6: vpermxor1 gen() 13476 MB/s 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: raid6: altivecx8 gen() 13939 MB/s 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: raid6: altivecx4 gen() 13705 MB/s 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: raid6: altivecx2 gen() 11167 MB/s 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: raid6: altivecx1 gen() 8677 MB/s 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: raid6: int64x8 gen() 7289 MB/s 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: raid6: int64x4 gen() 8683 MB/s 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: raid6: int64x2 gen() 6662 MB/s 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: raid6: int64x1 gen() 5150 MB/s 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: raid6: using algorithm vpermxor8 gen() 22728 MB/s 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: raid6: using intx1 recovery algorithm 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: xor: measuring software checksum speed 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: 8regs : 17364 MB/sec 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: 8regs_prefetch : 15561 MB/sec 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: 32regs : 17368 MB/sec 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: 32regs_prefetch : 15567 MB/sec 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: altivec : 19394 MB/sec 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: xor: using function: altivec (19394 MB/sec) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: Btrfs loaded, zoned=yes, fsverity=yes 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: EXT4-fs (sda1): mounted filesystem f999abd5-af41-40ac-8675-cf1e7d4878fb ro with ordered data mode. Quota mode: none. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Inserted module 'autofs4' 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 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) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Detected virtualization kvm. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Detected architecture ppc64-le. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Hostname set to . 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: bpf-restrict-fs: BPF LSM hook not enabled in the kernel, BPF LSM not supported. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: NET: Registered PF_VSOCK protocol family 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 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. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 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. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Queued start job for default target graphical.target. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Created slice system-autopkgtest.slice - Slice /system/autopkgtest. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Created slice system-modprobe.slice - Slice /system/modprobe. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Created slice system-serial\x2dgetty.slice - Slice /system/serial-getty. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Created slice user.slice - User and Session Slice. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Started systemd-ask-password-wall.path - Forward Password Requests to Wall Directory Watch. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Set up automount proc-sys-fs-binfmt_misc.automount - Arbitrary Executable File Formats File System Automount Point. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Expecting device dev-hvc0.device - /dev/hvc0... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Reached target integritysetup.target - Local Integrity Protected Volumes. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Reached target remote-fs.target - Remote File Systems. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Reached target slices.target - Slice Units. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Reached target swap.target - Swaps. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Reached target veritysetup.target - Local Verity Protected Volumes. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Listening on multipathd.socket - multipathd control socket. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Listening on syslog.socket - Syslog Socket. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Listening on systemd-creds.socket - Credential Encryption/Decryption. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Listening on systemd-fsckd.socket - fsck to fsckd communication Socket. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Listening on systemd-initctl.socket - initctl Compatibility Named Pipe. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Listening on systemd-journald-dev-log.socket - Journal Socket (/dev/log). 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Listening on systemd-journald.socket - Journal Sockets. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Listening on systemd-networkd.socket - Network Service Netlink Socket. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Listening on systemd-udevd-control.socket - udev Control Socket. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Listening on systemd-udevd-kernel.socket - udev Kernel Socket. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Mounting dev-hugepages.mount - Huge Pages File System... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Mounting dev-mqueue.mount - POSIX Message Queue File System... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Mounting run-lock.mount - Legacy Locks Directory /run/lock... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Mounting sys-kernel-debug.mount - Kernel Debug File System... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Mounting sys-kernel-tracing.mount - Kernel Trace File System... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting systemd-journald.service - Journal Service... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting keyboard-setup.service - Set the console keyboard layout... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting kmod-static-nodes.service - Create List of Static Device Nodes... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting modprobe@configfs.service - Load Kernel Module configfs... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting modprobe@dm_multipath.service - Load Kernel Module dm_multipath... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting modprobe@drm.service - Load Kernel Module drm... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting modprobe@fuse.service - Load Kernel Module fuse... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: netplan-ovs-cleanup.service - OpenVSwitch configuration for cleanup was skipped because of an unmet condition check (ConditionFileIsExecutable=/usr/bin/ovs-vsctl). 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 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). 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 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). 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting systemd-modules-load.service - Load Kernel Modules... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd-journald[288]: Collecting audit messages is disabled. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting systemd-remount-fs.service - Remount Root and Kernel File Systems... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting systemd-udev-load-credentials.service - Load udev Rules from Credentials... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting systemd-udev-trigger.service - Coldplug All udev Devices... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Mounted dev-hugepages.mount - Huge Pages File System. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Mounted dev-mqueue.mount - POSIX Message Queue File System. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Mounted run-lock.mount - Legacy Locks Directory /run/lock. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Mounted sys-kernel-debug.mount - Kernel Debug File System. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Mounted sys-kernel-tracing.mount - Kernel Trace File System. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Finished kmod-static-nodes.service - Create List of Static Device Nodes. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: modprobe@configfs.service: Deactivated successfully. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Finished modprobe@configfs.service - Load Kernel Module configfs. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: modprobe@dm_multipath.service: Deactivated successfully. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Finished modprobe@dm_multipath.service - Load Kernel Module dm_multipath. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd-journald[288]: Journal started 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd-journald[288]: Runtime Journal (/run/log/journal/f2b026c9c820405b87839afd42a274c3) is 8M, max 78.4M, 70.4M free. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: modprobe@drm.service: Deactivated successfully. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Finished modprobe@drm.service - Load Kernel Module drm. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: modprobe@fuse.service: Deactivated successfully. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Finished modprobe@fuse.service - Load Kernel Module fuse. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Started systemd-journald.service - Journal Service. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Finished systemd-modules-load.service - Load Kernel Modules. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Finished systemd-udev-load-credentials.service - Load udev Rules from Credentials. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Mounting sys-fs-fuse-connections.mount - FUSE Control File System... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Mounting sys-kernel-config.mount - Kernel Configuration File System... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting systemd-sysctl.service - Apply Kernel Variables... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Finished keyboard-setup.service - Set the console keyboard layout. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Mounted sys-fs-fuse-connections.mount - FUSE Control File System. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Mounted sys-kernel-config.mount - Kernel Configuration File System. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Finished systemd-sysctl.service - Apply Kernel Variables. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Finished systemd-remount-fs.service - Remount Root and Kernel File Systems. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: EXT4-fs (sda1): re-mounted f999abd5-af41-40ac-8675-cf1e7d4878fb r/w. Quota mode: none. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting cloud-init-main.service - Cloud-init: Single Process... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: systemd-hwdb-update.service - Rebuild Hardware Database was skipped because of an unmet condition check (ConditionNeedsUpdate=/etc). 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting systemd-journal-flush.service - Flush Journal to Persistent Storage... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore). 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting systemd-random-seed.service - Load/Save OS Random Seed... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Finished systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: systemd-sysusers.service - Create System Users was skipped because no trigger condition checks were met. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd-journald[288]: Time spent on flushing to /var/log/journal/f2b026c9c820405b87839afd42a274c3 is 23.728ms for 438 entries. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd-journald[288]: System Journal (/var/log/journal/f2b026c9c820405b87839afd42a274c3) is 16M, max 1.9G, 1.9G free. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd-journald[288]: Received client request to flush runtime journal. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 multipathd[341]: multipathd v0.9.9: start up 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 multipathd[341]: reconfigure: setting up paths and maps 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd-random-seed[345]: Kernel entropy pool is not initialized yet, waiting until it is. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Finished systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Reached target local-fs-pre.target - Preparation for Local File Systems. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Reached target local-fs.target - Local File Systems. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Listening on systemd-sysext.socket - System Extension Image Management. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting apparmor.service - Load AppArmor profiles... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting console-setup.service - Set console font and keymap... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: ldconfig.service - Rebuild Dynamic Linker Cache was skipped because no trigger condition checks were met. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting plymouth-read-write.service - Tell Plymouth To Write Out Runtime Data... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting systemd-binfmt.service - Set Up Additional Binary Formats... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting systemd-udevd.service - Rule-based Manager for Device Events and Files... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting ufw.service - Uncomplicated firewall... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Finished systemd-udev-trigger.service - Coldplug All udev Devices. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Finished systemd-journal-flush.service - Flush Journal to Persistent Storage. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: proc-sys-fs-binfmt_misc.automount: Got automount request for /proc/sys/fs/binfmt_misc, triggered by 362 (systemd-binfmt) 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Finished plymouth-read-write.service - Tell Plymouth To Write Out Runtime Data. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 apparmor.systemd[359]: Restarting AppArmor 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Finished console-setup.service - Set console font and keymap. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Finished ufw.service - Uncomplicated firewall. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting systemd-tmpfiles-setup.service - Create System Files and Directories... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 apparmor.systemd[359]: Reloading AppArmor profiles 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd-tmpfiles[379]: /usr/lib/tmpfiles.d/legacy.conf:13: Duplicate line for path "/run/lock", ignoring. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: audit: type=1400 audit(1723782793.440:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="Discord" pid=384 comm="apparmor_parser" 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: audit: type=1400 audit(1723782793.440:3): apparmor="STATUS" operation="profile_load" profile="unconfined" name=4D6F6E676F444220436F6D70617373 pid=385 comm="apparmor_parser" 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: audit: type=1400 audit(1723782793.440:4): apparmor="STATUS" operation="profile_load" profile="unconfined" name="QtWebEngineProcess" pid=386 comm="apparmor_parser" 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: audit: type=1400 audit(1723782793.444:5): apparmor="STATUS" operation="profile_load" profile="unconfined" name="1password" pid=383 comm="apparmor_parser" 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: audit: type=1400 audit(1723782793.444:6): apparmor="STATUS" operation="profile_load" profile="unconfined" name="balena-etcher" pid=387 comm="apparmor_parser" 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: audit: type=1400 audit(1723782793.444:7): apparmor="STATUS" operation="profile_load" profile="unconfined" name="brave" pid=388 comm="apparmor_parser" 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: audit: type=1400 audit(1723782793.448:8): apparmor="STATUS" operation="profile_load" profile="unconfined" name="buildah" pid=389 comm="apparmor_parser" 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: audit: type=1400 audit(1723782793.452:9): apparmor="STATUS" operation="profile_load" profile="unconfined" name="busybox" pid=390 comm="apparmor_parser" 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: audit: type=1400 audit(1723782793.452:10): apparmor="STATUS" operation="profile_load" profile="unconfined" name="cam" pid=391 comm="apparmor_parser" 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Finished systemd-tmpfiles-setup.service - Create System Files and Directories. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: systemd-firstboot.service - First Boot Wizard was skipped because of an unmet condition check (ConditionFirstBoot=yes). 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: systemd-journal-catalog-update.service - Rebuild Journal Catalog was skipped because of an unmet condition check (ConditionNeedsUpdate=/var). 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting systemd-resolved.service - Network Name Resolution... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting systemd-timesyncd.service - Network Time Synchronization... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: systemd-update-done.service - Update is Completed was skipped because no trigger condition checks were met. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting systemd-update-utmp.service - Record System Boot/Shutdown in UTMP... 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd-udevd[364]: Using default interface naming scheme 'v255'. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Finished systemd-update-utmp.service - Record System Boot/Shutdown in UTMP. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Started systemd-udevd.service - Rule-based Manager for Device Events and Files. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: plymouth-start.service - Show Plymouth Boot Screen was skipped because of an unmet condition check (ConditionKernelCommandLine=splash). 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Started systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 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). 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Reached target cryptsetup.target - Local Encrypted Volumes. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Found device dev-hvc0.device - /dev/hvc0. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Finished apparmor.service - Load AppArmor profiles. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 kernel: random: crng init done 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Listening on systemd-rfkill.socket - Load/Save RF Kill Switch Status /dev/rfkill Watch. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Finished systemd-random-seed.service - Load/Save OS Random Seed. 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: first-boot-complete.target - First Boot Complete was skipped because of an unmet condition check (ConditionFirstBoot=yes). 290s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 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). 290s Aug 16 04:33:14 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Started cloud-init-main.service - Cloud-init: Single Process. 290s Aug 16 04:33:14 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting cloud-init-local.service - Cloud-init: Local Stage (pre-network)... 290s Aug 16 04:33:14 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Mounting proc-sys-fs-binfmt_misc.mount - Arbitrary Executable File Formats File System... 290s Aug 16 04:33:14 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Mounted proc-sys-fs-binfmt_misc.mount - Arbitrary Executable File Formats File System. 290s Aug 16 04:33:14 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Finished systemd-binfmt.service - Set Up Additional Binary Formats. 290s Aug 16 04:33:14 adtubuntu-oracular-ppc64el-server-20240815 cloud-init[669]: Cloud-init v. 24.4~2g2e4c39b7-0ubuntu1 running 'init-local' at Fri, 16 Aug 2024 04:33:14 +0000. Up 4.01 seconds. 290s Aug 16 04:33:14 adtubuntu-oracular-ppc64el-server-20240815 systemd-resolved[410]: Positive Trust Anchors: 290s Aug 16 04:33:14 adtubuntu-oracular-ppc64el-server-20240815 systemd-resolved[410]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d 290s Aug 16 04:33:14 adtubuntu-oracular-ppc64el-server-20240815 systemd-resolved[410]: 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 290s Aug 16 04:33:14 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Started systemd-timesyncd.service - Network Time Synchronization. 290s Aug 16 04:33:14 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Reached target time-set.target - System Time Set. 290s Aug 16 04:33:14 adtubuntu-oracular-ppc64el-server-20240815 dhcpcd[673]: dhcpcd-10.0.8 starting 290s Aug 16 04:33:14 adtubuntu-oracular-ppc64el-server-20240815 dhcpcd[676]: DUID 00:01:00:01:2d:c3:64:c3:fa:16:3e:9f:5d:b2 290s Aug 16 04:33:14 adtubuntu-oracular-ppc64el-server-20240815 systemd-resolved[410]: Using system hostname 'adtubuntu-oracular-ppc64el-server-20240815'. 290s Aug 16 04:33:14 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Started systemd-resolved.service - Network Name Resolution. 290s Aug 16 04:33:14 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Reached target nss-lookup.target - Host and Network Name Lookups. 290s Aug 16 04:33:14 adtubuntu-oracular-ppc64el-server-20240815 kernel: 8021q: 802.1Q VLAN Support v1.8 290s Aug 16 04:33:14 adtubuntu-oracular-ppc64el-server-20240815 kernel: 8021q: adding VLAN 0 to HW filter on device enp0s1 290s Aug 16 04:33:14 adtubuntu-oracular-ppc64el-server-20240815 kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database 290s Aug 16 04:33:14 adtubuntu-oracular-ppc64el-server-20240815 kernel: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' 290s Aug 16 04:33:14 adtubuntu-oracular-ppc64el-server-20240815 kernel: Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600' 290s Aug 16 04:33:14 adtubuntu-oracular-ppc64el-server-20240815 dhcpcd[676]: enp0s1: IAID 3e:35:b4:f2 290s Aug 16 04:33:15 adtubuntu-oracular-ppc64el-server-20240815 dhcpcd[676]: enp0s1: rebinding lease of 10.43.136.46 290s Aug 16 04:33:20 adtubuntu-oracular-ppc64el-server-20240815 dhcpcd[676]: enp0s1: DHCP lease expired 290s Aug 16 04:33:20 adtubuntu-oracular-ppc64el-server-20240815 dhcpcd[676]: enp0s1: soliciting a DHCP lease 290s Aug 16 04:33:20 adtubuntu-oracular-ppc64el-server-20240815 dhcpcd[676]: enp0s1: offered 10.43.136.16 from 10.43.136.8 290s Aug 16 04:33:20 adtubuntu-oracular-ppc64el-server-20240815 dhcpcd[676]: enp0s1: leased 10.43.136.16 for 86400 seconds 290s Aug 16 04:33:20 adtubuntu-oracular-ppc64el-server-20240815 dhcpcd[676]: enp0s1: adding route to 10.43.136.0/24 290s Aug 16 04:33:20 adtubuntu-oracular-ppc64el-server-20240815 dhcpcd[676]: enp0s1: adding host route to 169.254.169.254 via 10.43.136.1 290s Aug 16 04:33:20 adtubuntu-oracular-ppc64el-server-20240815 dhcpcd[676]: enp0s1: adding default route via 10.43.136.1 290s Aug 16 04:33:20 adtubuntu-oracular-ppc64el-server-20240815 dhcpcd[676]: control command: /usr/sbin/dhcpcd --dumplease --ipv4only enp0s1 290s Aug 16 04:33:27 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd-resolved[410]: System hostname changed to 'adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227'. 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-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). 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-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). 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-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). 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd[1]: Reload requested from client PID 716 ('systemctl') (unit cloud-init-main.service)... 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd[1]: Reloading... 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-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. 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-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. 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd[1]: Reloading finished in 166 ms. 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 sh[661]: Completed socket interaction for boot stage local 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd[1]: Finished cloud-init-local.service - Cloud-init: Local Stage (pre-network). 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd[1]: Reached target network-pre.target - Preparation for Network. 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd[1]: Starting systemd-networkd.service - Network Configuration... 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd-networkd[751]: /run/systemd/network/10-netplan-enp0s1.network: MTUBytes= in [Link] section and UseMTU= in [DHCP] section are set. Disabling UseMTU=. 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd-networkd[751]: lo: Link UP 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd-networkd[751]: lo: Gained carrier 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd-networkd[751]: Enumeration completed 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd-networkd[751]: enp0s1: Link UP 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd-networkd[751]: enp0s1: Gained carrier 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd[1]: Started systemd-networkd.service - Network Configuration. 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd-networkd[751]: enp0s1: Gained IPv6LL 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd-timesyncd[415]: Network configuration changed, trying to establish connection. 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd-networkd[751]: enp0s1: Link DOWN 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd-networkd[751]: enp0s1: Lost carrier 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd-timesyncd[415]: No network connectivity, watching for changes. 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd[1]: Reached target network.target - Network. 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd-networkd[751]: enp0s1: Configuring with /run/systemd/network/10-netplan-enp0s1.network. 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 kernel: 8021q: adding VLAN 0 to HW filter on device enp0s1 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd-networkd[751]: enp0s1: Link UP 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd-networkd[751]: enp0s1: Gained carrier 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd[1]: Starting systemd-networkd-persistent-storage.service - Enable Persistent Storage in systemd-networkd... 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd[1]: Starting systemd-networkd-wait-online.service - Wait for Network to be Configured... 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd-networkd[751]: enp0s1: DHCPv4 address 10.43.136.16/24, gateway 10.43.136.1 acquired from 10.43.136.8 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd-timesyncd[415]: Network configuration changed, trying to establish connection. 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd[1]: Finished systemd-networkd-persistent-storage.service - Enable Persistent Storage in systemd-networkd. 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd-timesyncd[415]: Contacted time server 91.189.91.157:123 (ntp.ubuntu.com). 290s Aug 16 04:33:28 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd-timesyncd[415]: Initial clock synchronization to Fri 2024-08-16 04:33:28.904917 UTC. 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd-networkd[751]: enp0s1: Gained IPv6LL 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd[1]: Finished systemd-networkd-wait-online.service - Wait for Network to be Configured. 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 systemd[1]: Starting cloud-init-network.service - Cloud-init: Network Stage... 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: Cloud-init v. 24.4~2g2e4c39b7-0ubuntu1 running 'init' at Fri, 16 Aug 2024 04:33:30 +0000. Up 20.10 seconds. 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: +++++++++++++++++++++++++++++++++++++++Net device info+++++++++++++++++++++++++++++++++++++++ 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: +--------+------+------------------------------+---------------+--------+-------------------+ 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: | Device | Up | Address | Mask | Scope | Hw-Address | 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: +--------+------+------------------------------+---------------+--------+-------------------+ 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: | enp0s1 | True | 10.43.136.16 | 255.255.255.0 | global | fa:16:3e:35:b4:f2 | 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: | enp0s1 | True | fe80::f816:3eff:fe35:b4f2/64 | . | link | fa:16:3e:35:b4:f2 | 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: | lo | True | 127.0.0.1 | 255.0.0.0 | host | . | 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: | lo | True | ::1/128 | . | host | . | 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: +--------+------+------------------------------+---------------+--------+-------------------+ 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: ++++++++++++++++++++++++++++++++Route IPv4 info++++++++++++++++++++++++++++++++ 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: +-------+-----------------+-------------+-----------------+-----------+-------+ 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: | Route | Destination | Gateway | Genmask | Interface | Flags | 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: +-------+-----------------+-------------+-----------------+-----------+-------+ 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: | 0 | 0.0.0.0 | 10.43.136.1 | 0.0.0.0 | enp0s1 | UG | 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: | 1 | 10.43.136.0 | 0.0.0.0 | 255.255.255.0 | enp0s1 | U | 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: | 2 | 10.43.136.1 | 0.0.0.0 | 255.255.255.255 | enp0s1 | UH | 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: | 3 | 91.189.91.130 | 10.43.136.1 | 255.255.255.255 | enp0s1 | UGH | 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: | 4 | 169.254.169.254 | 10.43.136.1 | 255.255.255.255 | enp0s1 | UGH | 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: +-------+-----------------+-------------+-----------------+-----------+-------+ 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: +++++++++++++++++++Route IPv6 info+++++++++++++++++++ 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: +-------+-------------+---------+-----------+-------+ 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: | Route | Destination | Gateway | Interface | Flags | 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: +-------+-------------+---------+-----------+-------+ 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: | 0 | fe80::/64 | :: | enp0s1 | U | 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: | 2 | local | :: | enp0s1 | U | 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: | 3 | multicast | :: | enp0s1 | U | 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: ci-info: +-------+-------------+---------+-----------+-------+ 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: 2024-08-16 04:33:30,568 - 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. 290s Aug 16 04:33:30 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 cloud-init[669]: 2024-08-16 04:33:30,568 - schema.py[WARNING]: cloud-config failed schema validation! You may run 'sudo cloud-init schema --system' to check the details. 290s Aug 16 04:33:31 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 kernel: EXT4-fs (sda1): resizing filesystem from 5240560 to 20969200 blocks 290s Aug 16 04:33:31 adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f227 kernel: EXT4-fs (sda1): resized filesystem to 20969200 290s Aug 16 04:33:31 autopkgtest systemd-resolved[410]: System hostname changed to 'autopkgtest'. 290s Aug 16 04:33:31 autopkgtest sh[762]: Completed socket interaction for boot stage network 290s Aug 16 04:33:31 autopkgtest systemd[1]: Finished cloud-init-network.service - Cloud-init: Network Stage. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Reached target cloud-config.target - Cloud-config availability. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Reached target network-online.target - Network is Online. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Reached target sysinit.target - System Initialization. 290s Aug 16 04:33:31 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). 290s Aug 16 04:33:31 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). 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started apt-daily.timer - Daily apt download activities. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started apt-daily-upgrade.timer - Daily apt upgrade and clean activities. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started dpkg-db-backup.timer - Daily dpkg database backup timer. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started e2scrub_all.timer - Periodic ext4 Online Metadata Check for All Filesystems. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started fstrim.timer - Discard unused filesystem blocks once a week. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started fwupd-refresh.timer - Refresh fwupd metadata regularly. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started logrotate.timer - Daily rotation of log files. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started man-db.timer - Daily man-db regeneration. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started motd-news.timer - Message of the Day. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started systemd-tmpfiles-clean.timer - Daily Cleanup of Temporary Directories. 290s Aug 16 04:33:31 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). 290s Aug 16 04:33:31 autopkgtest systemd[1]: Reached target boot-complete.target - Boot Completion Check. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Reached target paths.target - Path Units. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Reached target timers.target - Timer Units. 290s Aug 16 04:33:31 autopkgtest systemd[1]: apport-forward.socket - Unix socket for apport crash forwarding was skipped because of an unmet condition check (ConditionVirtualization=container). 290s Aug 16 04:33:31 autopkgtest systemd[1]: Listening on cloud-init-hotplugd.socket - cloud-init hotplug hook socket. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Listening on dbus.socket - D-Bus System Message Bus Socket. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Starting lxd-installer.socket - Helper to install lxd snap on demand... 290s Aug 16 04:33:31 autopkgtest systemd[1]: Listening on ssh.socket - OpenBSD Secure Shell server socket. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Listening on sshd-unix-local.socket - OpenSSH Server Socket (systemd-ssh-generator, AF_UNIX Local). 290s Aug 16 04:33:31 autopkgtest systemd[1]: Listening on sshd-vsock.socket - OpenSSH Server Socket (systemd-ssh-generator, AF_VSOCK). 290s Aug 16 04:33:31 autopkgtest systemd[1]: Reached target ssh-access.target - SSH Access Available. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Listening on systemd-hostnamed.socket - Hostname Service Socket. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Listening on uuidd.socket - UUID daemon activation socket. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Listening on lxd-installer.socket - Helper to install lxd snap on demand. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Reached target sockets.target - Socket Units. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Reached target basic.target - Basic System. 290s Aug 16 04:33:31 autopkgtest systemd[1]: System is tainted: unmerged-bin 290s Aug 16 04:33:31 autopkgtest systemd[1]: Starting apport.service - automatic crash report generation... 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started autopkgtest@hvc1.service - autopkgtest root shell on hvc1. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started autopkgtest@ttyS1.service - autopkgtest root shell on ttyS1. 290s Aug 16 04:33:31 autopkgtest (sh)[852]: autopkgtest@hvc1.service: Failed to set up standard input: No such device 290s Aug 16 04:33:31 autopkgtest (sh)[852]: autopkgtest@hvc1.service: Failed at step STDIN spawning /bin/sh: No such device 290s Aug 16 04:33:31 autopkgtest systemd[1]: Starting cloud-config.service - Cloud-init: Config Stage... 290s Aug 16 04:33:31 autopkgtest (sh)[853]: autopkgtest@ttyS1.service: Failed to set up standard input: Input/output error 290s Aug 16 04:33:31 autopkgtest (sh)[853]: autopkgtest@ttyS1.service: Failed at step STDIN spawning /bin/sh: Input/output error 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started cron.service - Regular background program processing daemon. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Starting dbus.service - D-Bus System Message Bus... 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started dmesg.service - Save initial kernel messages after boot. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Starting e2scrub_reap.service - Remove Stale Online ext4 Metadata Check Snapshots... 290s Aug 16 04:33:31 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). 290s Aug 16 04:33:31 autopkgtest (cron)[855]: cron.service: Referenced but unset environment variable evaluates to an empty string: EXTRA_OPTS 290s Aug 16 04:33:31 autopkgtest cron[855]: (CRON) INFO (pidfile fd = 3) 290s Aug 16 04:33:31 autopkgtest systemd[1]: Starting grub-common.service - Record successful boot for GRUB... 290s Aug 16 04:33:31 autopkgtest systemd[1]: Starting iprdump.service - IBM Power Raid dump daemon... 290s Aug 16 04:33:31 autopkgtest cron[855]: (CRON) INFO (Running @reboot jobs) 290s Aug 16 04:33:31 autopkgtest systemd[1]: networkd-dispatcher.service - Dispatcher daemon for systemd-networkd was skipped because no trigger condition checks were met. 290s Aug 16 04:33:31 autopkgtest systemd[1]: opal_errd.service - opal_errd (PowerNV platform error handling) Service was skipped because of an unmet condition check (ConditionVirtualization=false). 290s Aug 16 04:33:31 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). 290s Aug 16 04:33:31 autopkgtest systemd[1]: Starting rc-local.service - /etc/rc.local Compatibility... 290s Aug 16 04:33:31 autopkgtest systemd[1]: Starting rng-tools-debian.service - LSB: rng-tools (Debian variant)... 290s Aug 16 04:33:31 autopkgtest systemd[1]: Starting rsyslog.service - System Logging Service... 290s Aug 16 04:33:31 autopkgtest systemd[1]: Starting rtas_errd.service - ppc64-diag rtas_errd (platform error handling) Service... 290s Aug 16 04:33:31 autopkgtest systemd[1]: Starting systemd-logind.service - User Login Management... 290s Aug 16 04:33:31 autopkgtest dbus-daemon[856]: [system] AppArmor D-Bus mediation is enabled 290s Aug 16 04:33:31 autopkgtest systemd[1]: Starting systemd-user-sessions.service - Permit User Sessions... 290s Aug 16 04:33:31 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). 290s Aug 16 04:33:31 autopkgtest dbus-daemon[856]: [system] Activating systemd to hand-off: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.2' (uid=998 pid=751 comm="/usr/lib/systemd/systemd-networkd" label="unconfined") 290s Aug 16 04:33:31 autopkgtest systemd[1]: ubuntu-advantage.service - Ubuntu Pro Background Auto Attach was skipped because no trigger condition checks were met. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Starting udisks2.service - Disk Manager... 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started dbus.service - D-Bus System Message Bus. 290s Aug 16 04:33:31 autopkgtest systemd[1]: autopkgtest@hvc1.service: Deactivated successfully. 290s Aug 16 04:33:31 autopkgtest systemd[1]: autopkgtest@ttyS1.service: Deactivated successfully. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started iprdump.service - IBM Power Raid dump daemon. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Finished systemd-user-sessions.service - Permit User Sessions. 290s Aug 16 04:33:31 autopkgtest dbus-daemon[856]: [system] Successfully activated service 'org.freedesktop.systemd1' 290s Aug 16 04:33:31 autopkgtest systemd[1]: Starting iprinit.service - IBM Power Raid init daemon... 290s Aug 16 04:33:31 autopkgtest systemd[1]: Starting iprupdate.service - IBM Power Raid update daemon... 290s Aug 16 04:33:31 autopkgtest systemd[1]: Starting systemd-hostnamed.service - Hostname Service... 290s Aug 16 04:33:31 autopkgtest udisksd[874]: udisks daemon version 2.10.1 starting 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started iprinit.service - IBM Power Raid init daemon. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started iprupdate.service - IBM Power Raid update daemon. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Reached target iprutils.target - IBM Power Raid utilities. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started rc-local.service - /etc/rc.local Compatibility. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started rtas_errd.service - ppc64-diag rtas_errd (platform error handling) Service. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Starting plymouth-quit-wait.service - Hold until boot process finishes up... 290s Aug 16 04:33:31 autopkgtest systemd[1]: Starting plymouth-quit.service - Terminate Plymouth Boot Screen... 290s Aug 16 04:33:31 autopkgtest rng-tools-debian[914]: found /dev/hwrng but could not use it 290s Aug 16 04:33:31 autopkgtest rng-tools-debian[916]: not starting: no hardware RNG device found 290s Aug 16 04:33:31 autopkgtest rng-tools-debian[865]: * Configuring Hardware RNG entropy gatherer daemon 290s Aug 16 04:33:31 autopkgtest rng-tools-debian[865]: ...fail! 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started rng-tools-debian.service - LSB: rng-tools (Debian variant). 290s Aug 16 04:33:31 autopkgtest systemd[1]: grub-common.service: Deactivated successfully. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Finished grub-common.service - Record successful boot for GRUB. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Starting grub-initrd-fallback.service - GRUB failed boot detection... 290s Aug 16 04:33:31 autopkgtest systemd-logind[870]: New seat seat0. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started serial-getty@hvc0.service - Serial Getty on hvc0. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Starting setvtrgb.service - Set console scheme... 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started systemd-logind.service - User Login Management. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Finished plymouth-quit.service - Terminate Plymouth Boot Screen. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Finished setvtrgb.service - Set console scheme. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Created slice system-getty.slice - Slice /system/getty. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started getty@tty1.service - Getty on tty1. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Reached target getty.target - Login Prompts. 290s Aug 16 04:33:31 autopkgtest dbus-daemon[856]: [system] Successfully activated service 'org.freedesktop.hostname1' 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started systemd-hostnamed.service - Hostname Service. 290s Aug 16 04:33:31 autopkgtest systemd[1]: grub-initrd-fallback.service: Deactivated successfully. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Finished grub-initrd-fallback.service - GRUB failed boot detection. 290s Aug 16 04:33:31 autopkgtest systemd-networkd[751]: Could not set hostname: Access denied 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started udisks2.service - Disk Manager. 290s Aug 16 04:33:31 autopkgtest udisksd[874]: Acquired the name org.freedesktop.UDisks2 on the system message bus 290s Aug 16 04:33:31 autopkgtest kernel: kauditd_printk_skb: 108 callbacks suppressed 290s Aug 16 04:33:31 autopkgtest kernel: audit: type=1400 audit(1723782811.602:119): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="rsyslogd" pid=919 comm="apparmor_parser" 290s Aug 16 04:33:31 autopkgtest systemd[1]: e2scrub_reap.service: Deactivated successfully. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Finished e2scrub_reap.service - Remove Stale Online ext4 Metadata Check Snapshots. 290s Aug 16 04:33:31 autopkgtest cloud-init[669]: Cloud-init v. 24.4~2g2e4c39b7-0ubuntu1 running 'modules:config' at Fri, 16 Aug 2024 04:33:31 +0000. Up 21.28 seconds. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Finished apport.service - automatic crash report generation. 290s Aug 16 04:33:31 autopkgtest rsyslogd[934]: imuxsock: Acquired UNIX socket '/run/systemd/journal/syslog' (fd 3) from systemd. [v8.2406.0] 290s Aug 16 04:33:31 autopkgtest systemd[1]: Started rsyslog.service - System Logging Service. 290s Aug 16 04:33:31 autopkgtest rsyslogd[934]: rsyslogd's groupid changed to 102 290s Aug 16 04:33:31 autopkgtest rsyslogd[934]: rsyslogd's userid changed to 102 290s Aug 16 04:33:31 autopkgtest rsyslogd[934]: [origin software="rsyslogd" swVersion="8.2406.0" x-pid="934" x-info="https://www.rsyslog.com"] start 290s Aug 16 04:33:31 autopkgtest systemd[1]: Reached target multi-user.target - Multi-User System. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Reached target graphical.target - Graphical Interface. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... 290s Aug 16 04:33:31 autopkgtest systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. 290s Aug 16 04:33:31 autopkgtest cloud-init[669]: 2024-08-16 04:33:31,919 - 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. 290s Aug 16 04:33:31 autopkgtest cloud-init[669]: 2024-08-16 04:33:31,919 - 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. 290s Aug 16 04:33:31 autopkgtest sh[860]: Completed socket interaction for boot stage config 290s Aug 16 04:33:31 autopkgtest systemd[1]: Finished cloud-config.service - Cloud-init: Config Stage. 290s Aug 16 04:33:31 autopkgtest systemd[1]: Starting cloud-final.service - Cloud-init: Final Stage... 290s Aug 16 04:33:32 autopkgtest cloud-init[669]: Cloud-init v. 24.4~2g2e4c39b7-0ubuntu1 running 'modules:final' at Fri, 16 Aug 2024 04:33:32 +0000. Up 21.76 seconds. 290s Aug 16 04:33:32 autopkgtest systemd[1]: Starting apt-news.service - Update APT News... 290s Aug 16 04:33:32 autopkgtest systemd[1]: Starting esm-cache.service - Update the local ESM caches... 290s Aug 16 04:33:32 autopkgtest systemd[1]: esm-cache.service: Deactivated successfully. 290s Aug 16 04:33:32 autopkgtest systemd[1]: Finished esm-cache.service - Update the local ESM caches. 290s Aug 16 04:33:32 autopkgtest cloud-init[669]: Hit:1 http://ftpmaster.internal/ubuntu oracular InRelease 290s Aug 16 04:33:32 autopkgtest cloud-init[669]: Hit:2 http://ftpmaster.internal/ubuntu oracular-updates InRelease 290s Aug 16 04:33:32 autopkgtest cloud-init[669]: Hit:3 http://ftpmaster.internal/ubuntu oracular-security InRelease 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: Reading package lists... 290s Aug 16 04:33:33 autopkgtest cloud-init[1101]: ############################################################# 290s Aug 16 04:33:33 autopkgtest cloud-init[1102]: -----BEGIN SSH HOST KEY FINGERPRINTS----- 290s Aug 16 04:33:33 autopkgtest cloud-init[1104]: 256 SHA256:ioYuKzbe5UdQuSiCiOSf/9gwTpGUYDGGhL56l+/SDxY root@autopkgtest (ECDSA) 290s Aug 16 04:33:33 autopkgtest cloud-init[1106]: 256 SHA256:3cHecd/SrqbogaVyN357qC7LDKtT/qdCGiQ1HSAlgXo root@autopkgtest (ED25519) 290s Aug 16 04:33:33 autopkgtest cloud-init[1108]: 3072 SHA256:YvccqRftc58evXDdtpknezOnJvUoFJ6qwyWw69NbuyI root@autopkgtest (RSA) 290s Aug 16 04:33:33 autopkgtest cloud-init[1109]: -----END SSH HOST KEY FINGERPRINTS----- 290s Aug 16 04:33:33 autopkgtest cloud-init[1110]: ############################################################# 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: Cloud-init v. 24.4~2g2e4c39b7-0ubuntu1 finished at Fri, 16 Aug 2024 04:33:33 +0000. Datasource DataSourceOpenStackLocal [net,ver=2]. Up 23.31 seconds 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: Generating public/private rsa key pair. 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: Your identification has been saved in /etc/ssh/ssh_host_rsa_key 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: Your public key has been saved in /etc/ssh/ssh_host_rsa_key.pub 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: The key fingerprint is: 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: SHA256:YvccqRftc58evXDdtpknezOnJvUoFJ6qwyWw69NbuyI root@autopkgtest 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: The key's randomart image is: 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: +---[RSA 3072]----+ 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: | | 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: | | 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: | | 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: | . o. | 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: | ooS +..o | 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: | ..o.+.++ . +| 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: | +.o=ooo.==| 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: | E =o..oo*=%| 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: | ..oo=o. ++%*| 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: +----[SHA256]-----+ 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: Generating public/private ecdsa key pair. 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: Your identification has been saved in /etc/ssh/ssh_host_ecdsa_key 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: Your public key has been saved in /etc/ssh/ssh_host_ecdsa_key.pub 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: The key fingerprint is: 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: SHA256:ioYuKzbe5UdQuSiCiOSf/9gwTpGUYDGGhL56l+/SDxY root@autopkgtest 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: The key's randomart image is: 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: +---[ECDSA 256]---+ 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: |o..*. . | 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: |.oo o .o | 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: |B oo . | 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: |++ ..o.. | 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: | + ooE S | 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: | . + ..+ | 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: |. . +B= | 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: |++o.Oo*o | 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: |==oo B=+. | 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: +----[SHA256]-----+ 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: Generating public/private ed25519 key pair. 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: Your identification has been saved in /etc/ssh/ssh_host_ed25519_key 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: Your public key has been saved in /etc/ssh/ssh_host_ed25519_key.pub 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: The key fingerprint is: 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: SHA256:3cHecd/SrqbogaVyN357qC7LDKtT/qdCGiQ1HSAlgXo root@autopkgtest 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: The key's randomart image is: 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: +--[ED25519 256]--+ 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: | .+ooo.. | 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: |. oo . . | 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: |. . . o . .| 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: |. E . . o o +o| 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: | . o S o o o +| 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: | . o + o | 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: | *o + + . .| 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: | o oB.o.+o o. | 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: | .o.o*B*oo=. | 290s Aug 16 04:33:33 autopkgtest cloud-init[669]: +----[SHA256]-----+ 290s Aug 16 04:33:33 autopkgtest sh[971]: Completed socket interaction for boot stage final 290s Aug 16 04:33:33 autopkgtest systemd[1]: Finished cloud-final.service - Cloud-init: Final Stage. 290s Aug 16 04:33:33 autopkgtest systemd[1]: Reached target cloud-init.target - Cloud-init target. 290s Aug 16 04:33:33 autopkgtest systemd[1]: cloud-init-main.service: Deactivated successfully. 290s Aug 16 04:33:33 autopkgtest systemd[1]: cloud-init-main.service: Unit process 668 (sh) remains running after unit stopped. 290s Aug 16 04:33:33 autopkgtest systemd[1]: cloud-init-main.service: Consumed 3.666s CPU time, 366.9M memory peak. 290s Aug 16 04:33:34 autopkgtest systemd[1]: Starting ssh.service - OpenBSD Secure Shell server... 290s Aug 16 04:33:34 autopkgtest sshd[1117]: Server listening on :: port 22. 290s Aug 16 04:33:34 autopkgtest systemd[1]: Started ssh.service - OpenBSD Secure Shell server. 290s Aug 16 04:33:35 autopkgtest sshd[1119]: Accepted publickey for ubuntu from 10.136.6.201 port 54434 ssh2: RSA SHA256:YaYyKWTl9zFJEBK5G3u+MRj3WPJt+vEplFd0J96PUBw 290s Aug 16 04:33:35 autopkgtest sshd[1119]: pam_unix(sshd:session): session opened for user ubuntu(uid=1000) by ubuntu(uid=0) 290s Aug 16 04:33:35 autopkgtest sshd[1119]: pam_systemd(sshd:session): New sd-bus connection (system-bus-pam-systemd-1119) opened. 290s Aug 16 04:33:35 autopkgtest systemd[1]: Created slice user-1000.slice - User Slice of UID 1000. 290s Aug 16 04:33:35 autopkgtest systemd[1]: Starting user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... 290s Aug 16 04:33:35 autopkgtest systemd-logind[870]: New session 1 of user ubuntu. 290s Aug 16 04:33:35 autopkgtest systemd[1]: Finished user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. 290s Aug 16 04:33:35 autopkgtest systemd[1]: Starting user@1000.service - User Manager for UID 1000... 290s Aug 16 04:33:35 autopkgtest (systemd)[1123]: pam_unix(systemd-user:session): session opened for user ubuntu(uid=1000) by ubuntu(uid=0) 290s Aug 16 04:33:35 autopkgtest systemd-logind[870]: New session 2 of user ubuntu. 290s Aug 16 04:33:35 autopkgtest systemd[1123]: Queued start job for default target default.target. 290s Aug 16 04:33:35 autopkgtest systemd[1123]: Created slice app.slice - User Application Slice. 290s Aug 16 04:33:35 autopkgtest systemd[1123]: Started launchpadlib-cache-clean.timer - Clean up old files in the Launchpadlib cache. 290s Aug 16 04:33:35 autopkgtest systemd[1123]: Reached target paths.target - Paths. 290s Aug 16 04:33:35 autopkgtest systemd[1123]: Reached target timers.target - Timers. 290s Aug 16 04:33:35 autopkgtest systemd[1123]: Starting dbus.socket - D-Bus User Message Bus Socket... 290s Aug 16 04:33:35 autopkgtest systemd[1123]: Listening on dirmngr.socket - GnuPG network certificate management daemon. 290s Aug 16 04:33:35 autopkgtest systemd[1123]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). 290s Aug 16 04:33:35 autopkgtest systemd[1123]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). 290s Aug 16 04:33:35 autopkgtest systemd[1123]: Starting gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation)... 290s Aug 16 04:33:35 autopkgtest systemd[1123]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. 290s Aug 16 04:33:35 autopkgtest systemd[1123]: Listening on keyboxd.socket - GnuPG public key management service. 290s Aug 16 04:33:35 autopkgtest systemd[1123]: Listening on dbus.socket - D-Bus User Message Bus Socket. 290s Aug 16 04:33:35 autopkgtest systemd[1123]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). 290s Aug 16 04:33:35 autopkgtest systemd[1123]: Reached target sockets.target - Sockets. 290s Aug 16 04:33:35 autopkgtest systemd[1123]: Reached target basic.target - Basic System. 290s Aug 16 04:33:35 autopkgtest systemd[1123]: Reached target default.target - Main User Target. 290s Aug 16 04:33:35 autopkgtest systemd[1123]: Startup finished in 133ms. 290s Aug 16 04:33:35 autopkgtest systemd[1]: Started user@1000.service - User Manager for UID 1000. 290s Aug 16 04:33:35 autopkgtest systemd[1]: Started session-1.scope - Session 1 of User ubuntu. 290s Aug 16 04:33:35 autopkgtest sshd[1149]: Received disconnect from 10.136.6.201 port 54434:11: disconnected by user 290s Aug 16 04:33:35 autopkgtest sshd[1149]: Disconnected from user ubuntu 10.136.6.201 port 54434 290s Aug 16 04:33:35 autopkgtest sshd[1119]: pam_unix(sshd:session): session closed for user ubuntu 290s Aug 16 04:33:35 autopkgtest sshd[1119]: pam_systemd(sshd:session): New sd-bus connection (system-bus-pam-systemd-1119) opened. 290s Aug 16 04:33:35 autopkgtest systemd[1]: session-1.scope: Deactivated successfully. 290s Aug 16 04:33:35 autopkgtest systemd-logind[870]: Session 1 logged out. Waiting for processes to exit. 290s Aug 16 04:33:35 autopkgtest systemd-logind[870]: Removed session 1. 290s Aug 16 04:33:36 autopkgtest kernel: fbcon: Taking over console 290s Aug 16 04:33:36 autopkgtest systemd[1]: dmesg.service: Deactivated successfully. 290s Aug 16 04:33:36 autopkgtest sshd[1152]: Accepted publickey for ubuntu from 10.136.6.201 port 54450 ssh2: RSA SHA256:YaYyKWTl9zFJEBK5G3u+MRj3WPJt+vEplFd0J96PUBw 290s Aug 16 04:33:36 autopkgtest sshd[1152]: pam_unix(sshd:session): session opened for user ubuntu(uid=1000) by ubuntu(uid=0) 290s Aug 16 04:33:36 autopkgtest sshd[1152]: pam_systemd(sshd:session): New sd-bus connection (system-bus-pam-systemd-1152) opened. 290s Aug 16 04:33:36 autopkgtest systemd-logind[870]: New session 3 of user ubuntu. 290s Aug 16 04:33:36 autopkgtest systemd[1]: Started session-3.scope - Session 3 of User ubuntu. 290s Aug 16 04:33:37 autopkgtest sshd[1192]: Received disconnect from 10.136.6.201 port 54450:11: disconnected by user 290s Aug 16 04:33:37 autopkgtest sshd[1192]: Disconnected from user ubuntu 10.136.6.201 port 54450 290s Aug 16 04:33:37 autopkgtest sshd[1152]: pam_unix(sshd:session): session closed for user ubuntu 290s Aug 16 04:33:37 autopkgtest sshd[1152]: pam_systemd(sshd:session): New sd-bus connection (system-bus-pam-systemd-1152) opened. 290s Aug 16 04:33:37 autopkgtest systemd[1]: session-3.scope: Deactivated successfully. 290s Aug 16 04:33:37 autopkgtest systemd-logind[870]: Session 3 logged out. Waiting for processes to exit. 290s Aug 16 04:33:37 autopkgtest systemd-logind[870]: Removed session 3. 290s Aug 16 04:33:37 autopkgtest sshd[1195]: Accepted publickey for ubuntu from 10.136.6.201 port 54452 ssh2: RSA SHA256:YaYyKWTl9zFJEBK5G3u+MRj3WPJt+vEplFd0J96PUBw 290s Aug 16 04:33:37 autopkgtest sshd[1195]: pam_unix(sshd:session): session opened for user ubuntu(uid=1000) by ubuntu(uid=0) 290s Aug 16 04:33:37 autopkgtest sshd[1195]: pam_systemd(sshd:session): New sd-bus connection (system-bus-pam-systemd-1195) opened. 290s Aug 16 04:33:37 autopkgtest systemd-logind[870]: New session 4 of user ubuntu. 290s Aug 16 04:33:37 autopkgtest systemd[1]: Started session-4.scope - Session 4 of User ubuntu. 290s Aug 16 04:33:38 autopkgtest sudo[1213]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/bin/true 290s Aug 16 04:33:38 autopkgtest sudo[1213]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:38 autopkgtest sudo[1213]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:38 autopkgtest sudo[1218]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper /bin/mkdir --mode=1777 --parents /tmp/autopkgtest.Glpwae 290s Aug 16 04:33:38 autopkgtest sudo[1218]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:38 autopkgtest sudo[1218]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:39 autopkgtest sudo[1228]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper mkdir -p /tmp/autopkgtest.Glpwae 290s Aug 16 04:33:39 autopkgtest sudo[1228]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:39 autopkgtest sudo[1228]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:39 autopkgtest sudo[1238]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat >/tmp/autopkgtest.Glpwae/wrapper.sh; chmod +x -- /tmp/autopkgtest.Glpwae/wrapper.sh' 290s Aug 16 04:33:39 autopkgtest sudo[1238]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:39 autopkgtest sudo[1238]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:39 autopkgtest sudo[1250]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chmod -R 0755 -- /tmp/autopkgtest.Glpwae/wrapper.sh 290s Aug 16 04:33:39 autopkgtest sudo[1250]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:39 autopkgtest sudo[1250]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:39 autopkgtest sudo[1260]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper dpkg --print-architecture 290s Aug 16 04:33:39 autopkgtest sudo[1260]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:39 autopkgtest sudo[1260]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:40 autopkgtest sudo[1270]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper dpkg-query -W -f ${Version} apt 290s Aug 16 04:33:40 autopkgtest sudo[1270]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:40 autopkgtest sudo[1270]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:40 autopkgtest sudo[1280]: 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 290s Aug 16 04:33:40 autopkgtest sudo[1280]: 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 290s Aug 16 04:33:40 autopkgtest sudo[1280]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:40 autopkgtest sudo[1280]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:40 autopkgtest sudo[1292]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'ls -1 /etc/apt/sources.list.d/*.sources' 290s Aug 16 04:33:40 autopkgtest sudo[1292]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:40 autopkgtest sudo[1292]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:40 autopkgtest python3[981]: /usr/lib/python3/dist-packages/uaclient/apt_news.py:207: Warning: W:Download is performed unsandboxed as root as file '/run/ubuntu-advantage/aptnews.json' couldn't be accessed by user '_apt'. - pkgAcquire::Run (13: Permission denied) 290s Aug 16 04:33:40 autopkgtest python3[981]: acq.run() 290s Aug 16 04:33:40 autopkgtest systemd[1]: apt-news.service: Deactivated successfully. 290s Aug 16 04:33:40 autopkgtest systemd[1]: Finished apt-news.service - Update APT News. 290s Aug 16 04:33:40 autopkgtest systemd[1]: Startup finished in 2.660s (kernel) + 27.803s (userspace) = 30.463s. 290s Aug 16 04:33:40 autopkgtest sudo[1306]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper cat /etc/apt/sources.list.d/ubuntu.sources 290s Aug 16 04:33:40 autopkgtest sudo[1306]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:40 autopkgtest sudo[1306]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:41 autopkgtest sudo[1316]: 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 290s Aug 16 04:33:41 autopkgtest sudo[1316]: 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 290s Aug 16 04:33:41 autopkgtest sudo[1316]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:41 autopkgtest systemd[1]: Starting apt-news.service - Update APT News... 290s Aug 16 04:33:41 autopkgtest systemd[1]: Starting esm-cache.service - Update the local ESM caches... 290s Aug 16 04:33:41 autopkgtest systemd[1]: esm-cache.service: Deactivated successfully. 290s Aug 16 04:33:41 autopkgtest systemd[1]: Finished esm-cache.service - Update the local ESM caches. 290s Aug 16 04:33:44 autopkgtest sudo[1316]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:44 autopkgtest sudo[1402]: 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;' 290s Aug 16 04:33:44 autopkgtest sudo[1402]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:44 autopkgtest sudo[1402]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:44 autopkgtest sudo[1413]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper mkdir -p /etc/apt/preferences.d 290s Aug 16 04:33:44 autopkgtest sudo[1413]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:44 autopkgtest sudo[1413]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:44 autopkgtest sudo[1423]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat >/etc/apt/preferences.d/autopkgtest-oracular-proposed' 290s Aug 16 04:33:44 autopkgtest sudo[1423]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:44 autopkgtest sudo[1423]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:45 autopkgtest sudo[1434]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chmod -R 0644 -- /etc/apt/preferences.d/autopkgtest-oracular-proposed 290s Aug 16 04:33:45 autopkgtest sudo[1434]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:45 autopkgtest sudo[1434]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:45 autopkgtest sudo[1444]: 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' 290s Aug 16 04:33:45 autopkgtest sudo[1444]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:45 autopkgtest sudo[1444]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:45 autopkgtest python3[1327]: /usr/lib/python3/dist-packages/uaclient/apt_news.py:207: Warning: W:Download is performed unsandboxed as root as file '/run/ubuntu-advantage/aptnews.json' couldn't be accessed by user '_apt'. - pkgAcquire::Run (13: Permission denied) 290s Aug 16 04:33:45 autopkgtest python3[1327]: acq.run() 290s Aug 16 04:33:45 autopkgtest systemd[1]: apt-news.service: Deactivated successfully. 290s Aug 16 04:33:45 autopkgtest systemd[1]: Finished apt-news.service - Update APT News. 290s Aug 16 04:33:45 autopkgtest sudo[1458]: 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.Glpwae/${d//\\//_}.stamp; done' 290s Aug 16 04:33:45 autopkgtest sudo[1458]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:45 autopkgtest sudo[1458]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:45 autopkgtest sudo[1472]: 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 290s Aug 16 04:33:45 autopkgtest sudo[1472]: 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 290s Aug 16 04:33:45 autopkgtest sudo[1472]: 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 290s Aug 16 04:33:45 autopkgtest sudo[1472]: 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' 290s Aug 16 04:33:45 autopkgtest sudo[1472]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:47 autopkgtest sudo[1472]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:47 autopkgtest sudo[1526]: 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' 290s Aug 16 04:33:47 autopkgtest sudo[1526]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:47 autopkgtest systemd[1]: Starting apt-news.service - Update APT News... 290s Aug 16 04:33:47 autopkgtest systemd[1]: Starting esm-cache.service - Update the local ESM caches... 290s Aug 16 04:33:48 autopkgtest systemd[1]: esm-cache.service: Deactivated successfully. 290s Aug 16 04:33:48 autopkgtest systemd[1]: Finished esm-cache.service - Update the local ESM caches. 290s Aug 16 04:33:50 autopkgtest sudo[1526]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:50 autopkgtest sudo[1710]: 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.Glpwae/${d//\\//_}.stamp; [ ! -d $d ] || [ `stat -c %Y $d` = `stat -c %Y $s` ]; done' 290s Aug 16 04:33:50 autopkgtest sudo[1710]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:50 autopkgtest sudo[1710]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:50 autopkgtest sudo[1728]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'command -v eatmydata' 290s Aug 16 04:33:50 autopkgtest sudo[1728]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:50 autopkgtest sudo[1728]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:51 autopkgtest sudo[1738]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'dpkg-query --show -f \'${Package}\\t${Version}\\n\' > /tmp/autopkgtest.Glpwae/testbed-packages' 290s Aug 16 04:33:51 autopkgtest sudo[1738]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:51 autopkgtest sudo[1738]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:51 autopkgtest sudo[1749]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat /tmp/autopkgtest.Glpwae/autopkgtest-reboot; chmod +x -- /tmp/autopkgtest.Glpwae/autopkgtest-reboot' 290s Aug 16 04:33:51 autopkgtest sudo[1770]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:51 autopkgtest sudo[1770]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:52 autopkgtest sudo[1782]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chmod -R 0755 -- /tmp/autopkgtest.Glpwae/autopkgtest-reboot 290s Aug 16 04:33:52 autopkgtest sudo[1782]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:52 autopkgtest sudo[1782]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:52 autopkgtest sudo[1792]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper ln -fns /tmp/autopkgtest.Glpwae/autopkgtest-reboot /tmp/autopkgtest-reboot 290s Aug 16 04:33:52 autopkgtest sudo[1792]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:52 autopkgtest sudo[1792]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:52 autopkgtest sudo[1802]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper ln -fns /tmp/autopkgtest.Glpwae/autopkgtest-reboot /sbin/autopkgtest-reboot 290s Aug 16 04:33:52 autopkgtest sudo[1802]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:52 autopkgtest sudo[1802]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:52 autopkgtest sudo[1812]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper mkdir -p /tmp/autopkgtest.Glpwae 290s Aug 16 04:33:52 autopkgtest sudo[1812]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:52 autopkgtest sudo[1812]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:53 autopkgtest sudo[1822]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat >/tmp/autopkgtest.Glpwae/autopkgtest-reboot-prepare; chmod +x -- /tmp/autopkgtest.Glpwae/autopkgtest-reboot-prepare' 290s Aug 16 04:33:53 autopkgtest sudo[1822]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:53 autopkgtest sudo[1822]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:53 autopkgtest sudo[1834]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chmod -R 0755 -- /tmp/autopkgtest.Glpwae/autopkgtest-reboot-prepare 290s Aug 16 04:33:53 autopkgtest sudo[1834]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:53 autopkgtest sudo[1834]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:53 autopkgtest sudo[1844]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper ln -fns /tmp/autopkgtest.Glpwae/autopkgtest-reboot-prepare /tmp/autopkgtest-reboot-prepare 290s Aug 16 04:33:53 autopkgtest sudo[1844]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:53 autopkgtest sudo[1844]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:53 autopkgtest sudo[1854]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper uname -srv 290s Aug 16 04:33:53 autopkgtest sudo[1854]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:53 autopkgtest sudo[1854]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:54 autopkgtest sudo[1864]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper test -w /var/lib/dpkg/status 290s Aug 16 04:33:54 autopkgtest sudo[1864]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:54 autopkgtest sudo[1864]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:54 autopkgtest sudo[1873]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper mkdir -p /tmp/autopkgtest.Glpwae 290s Aug 16 04:33:54 autopkgtest sudo[1873]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:54 autopkgtest sudo[1873]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:54 autopkgtest sudo[1883]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat >/tmp/autopkgtest.Glpwae/2-autopkgtest-satdep.deb' 290s Aug 16 04:33:54 autopkgtest sudo[1883]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:54 autopkgtest sudo[1883]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:55 autopkgtest sudo[1894]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper chown -R ubuntu -- /tmp/autopkgtest.Glpwae/2-autopkgtest-satdep.deb 290s Aug 16 04:33:55 autopkgtest sudo[1894]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:55 autopkgtest sudo[1894]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:33:55 autopkgtest sudo[1904]: 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.Glpwae/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' 290s Aug 16 04:33:55 autopkgtest sudo[1904]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:33:58 autopkgtest systemd[1]: Reload requested from client PID 2144 ('systemctl') (unit session-4.scope)... 290s Aug 16 04:33:58 autopkgtest systemd[1]: Reloading... 290s Aug 16 04:33:58 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. 290s Aug 16 04:33:58 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. 290s Aug 16 04:33:58 autopkgtest systemd[1]: Reloading finished in 187 ms. 290s Aug 16 04:33:59 autopkgtest systemd[1]: Reload requested from client PID 2195 ('systemctl') (unit session-4.scope)... 290s Aug 16 04:33:59 autopkgtest systemd[1]: Reloading... 290s Aug 16 04:33:59 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. 290s Aug 16 04:33:59 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. 290s Aug 16 04:33:59 autopkgtest systemd[1]: Reloading finished in 188 ms. 290s Aug 16 04:33:59 autopkgtest systemd[1]: Starting tgt.service - (i)SCSI target daemon... 290s Aug 16 04:33:59 autopkgtest tgtd[2242]: tgtd: iser_ib_init(3431) Failed to initialize RDMA; load kernel modules? 290s Aug 16 04:33:59 autopkgtest tgtd[2242]: tgtd: work_timer_start(146) use timer_fd based scheduler 290s Aug 16 04:33:59 autopkgtest tgtd[2242]: tgtd: bs_init(387) use signalfd notification 290s Aug 16 04:33:59 autopkgtest systemd[1]: Started tgt.service - (i)SCSI target daemon. 290s Aug 16 04:33:59 autopkgtest systemd[1]: Reload requested from client PID 2270 ('systemctl') (unit session-4.scope)... 290s Aug 16 04:33:59 autopkgtest systemd[1]: Reloading... 290s Aug 16 04:33:59 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. 290s Aug 16 04:33:59 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. 290s Aug 16 04:33:59 autopkgtest systemd[1]: Reloading finished in 201 ms. 290s Aug 16 04:33:59 autopkgtest systemd[1]: Reload requested from client PID 2315 ('systemctl') (unit session-4.scope)... 290s Aug 16 04:33:59 autopkgtest systemd[1]: Reloading... 290s Aug 16 04:33:59 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. 290s Aug 16 04:33:59 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. 290s Aug 16 04:34:00 autopkgtest systemd[1]: Reloading finished in 184 ms. 290s Aug 16 04:34:00 autopkgtest systemd[1]: Reload requested from client PID 2362 ('systemctl') (unit session-4.scope)... 290s Aug 16 04:34:00 autopkgtest systemd[1]: Reloading... 290s Aug 16 04:34:00 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. 290s Aug 16 04:34:00 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. 290s Aug 16 04:34:00 autopkgtest systemd[1]: Reloading finished in 216 ms. 290s Aug 16 04:34:00 autopkgtest systemd[1]: Listening on iscsid.socket - Open-iSCSI iscsid Socket. 290s Aug 16 04:34:00 autopkgtest systemd[1]: Reload requested from client PID 2414 ('systemctl') (unit session-4.scope)... 290s Aug 16 04:34:00 autopkgtest systemd[1]: Reloading... 290s Aug 16 04:34:00 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. 290s Aug 16 04:34:00 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. 290s Aug 16 04:34:00 autopkgtest systemd[1]: Reloading finished in 184 ms. 290s Aug 16 04:34:00 autopkgtest systemd[1]: open-iscsi.service - Login to default iSCSI targets was skipped because no trigger condition checks were met. 290s Aug 16 04:34:00 autopkgtest systemd[1]: Reached target remote-fs-pre.target - Preparation for Remote File Systems. 290s Aug 16 04:34:00 autopkgtest systemd[1]: Reload requested from client PID 2470 ('systemctl') (unit session-4.scope)... 290s Aug 16 04:34:00 autopkgtest systemd[1]: Reloading... 290s Aug 16 04:34:01 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. 290s Aug 16 04:34:01 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. 290s Aug 16 04:34:01 autopkgtest systemd[1]: Reloading finished in 220 ms. 290s Aug 16 04:34:01 autopkgtest systemd[1]: systemd-hostnamed.service: Deactivated successfully. 290s Aug 16 04:34:09 autopkgtest sudo[1904]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:34:10 autopkgtest sudo[5918]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper dpkg-query --show -f ${Status} multipath-tools 290s Aug 16 04:34:10 autopkgtest sudo[5918]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:34:10 autopkgtest sudo[5918]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:34:10 autopkgtest sudo[5928]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper dpkg --status autopkgtest-satdep 290s Aug 16 04:34:10 autopkgtest sudo[5928]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:34:10 autopkgtest sudo[5928]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:34:10 autopkgtest sudo[5938]: 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 290s Aug 16 04:34:10 autopkgtest sudo[5938]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:34:11 autopkgtest sudo[5938]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:34:11 autopkgtest sudo[5951]: 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 290s Aug 16 04:34:11 autopkgtest sudo[5951]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:34:11 autopkgtest sudo[5951]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:34:12 autopkgtest sudo[5963]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper apt-mark manual -qq lsscsi 290s Aug 16 04:34:12 autopkgtest sudo[5963]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:34:12 autopkgtest sudo[5963]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:34:12 autopkgtest sudo[5975]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper dpkg --purge autopkgtest-satdep 290s Aug 16 04:34:12 autopkgtest sudo[5975]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:34:12 autopkgtest sudo[5975]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:34:12 autopkgtest sudo[5985]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'dpkg-query --show -f \'${Package}\\t${Version}\\n\' > /tmp/autopkgtest.Glpwae/tgtbasedmpaths-packages.all' 290s Aug 16 04:34:12 autopkgtest sudo[5985]: pam_unix(sudo:session): session opened for user root(uid=0) by ubuntu(uid=1000) 290s Aug 16 04:34:12 autopkgtest sudo[5985]: pam_unix(sudo:session): session closed for user root 290s Aug 16 04:34:12 autopkgtest sudo[5996]: ubuntu : PWD=/home/ubuntu ; USER=root ; COMMAND=/var/tmp/autopkgtest-run-wrapper sh -ec 'cat =64=0.0% 294s submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 294s complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 294s issued rwts: total=0,1401,0,0 short=0,0,0,0 dropped=0,0,0,0 294s latency : target=0, window=0, percentile=100.00%, depth=1 294s 294s Run status group 0 (all jobs): 294s WRITE: bw=128MiB/s (134MB/s), 128MiB/s-128MiB/s (134MB/s-134MB/s), io=87.5MiB (91.8MB), run=684-684msec 294s 294s Disk stats (read/write): 294s dm-0: ios=1/1295, sectors=8/165760, merge=0/0, ticks=1/585, in_queue=585, util=87.03%, aggrios=0/350, aggsectors=2/44820, aggrmerge=0/0, aggrticks=0/154, aggrin_queue=154, aggrutil=86.22% 294s sdd: ios=0/0, sectors=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 294s sdb: ios=1/1402, sectors=8/179280, merge=0/0, ticks=1/616, in_queue=617, util=86.22% 294s sde: ios=0/0, sectors=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 294s sdc: ios=0/0, sectors=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 294s Starting the path changes in background 294s + echo Starting the path changes in background 294s + date +Pre FIO %H:%M:%S.%N 294s + fio --max-jobs=4 /tmp/autopkgtest.Glpwae/tgtbasedmpaths-artifacts/path-change-check.fio 294s Pre FIO 04:34:30.307988230 294s 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 294s fio-3.37 294s Starting 1 thread 474s 474s verify-phase: (groupid=0, jobs=1): err= 0: pid=6340: Fri Aug 16 04:37:30 2024 474s read: IOPS=3434, BW=215MiB/s (225MB/s)(37.7GiB/180001msec) 474s clat (usec): min=88, max=65425, avg=268.47, stdev=232.94 474s lat (usec): min=88, max=65425, avg=268.58, stdev=232.95 474s clat percentiles (usec): 474s | 1.00th=[ 147], 5.00th=[ 178], 10.00th=[ 190], 20.00th=[ 202], 474s | 30.00th=[ 212], 40.00th=[ 223], 50.00th=[ 235], 60.00th=[ 262], 474s | 70.00th=[ 297], 80.00th=[ 330], 90.00th=[ 375], 95.00th=[ 408], 474s | 99.00th=[ 537], 99.50th=[ 717], 99.90th=[ 1729], 99.95th=[ 2474], 474s | 99.99th=[ 4752] 474s bw ( KiB/s): min=131200, max=326272, per=100.00%, avg=220013.72, stdev=44234.37, samples=359 474s iops : min= 2050, max= 5098, avg=3437.68, stdev=691.16, samples=359 474s lat (usec) : 100=0.12%, 250=56.64%, 500=41.97%, 750=0.80%, 1000=0.19% 474s lat (msec) : 2=0.20%, 4=0.06%, 10=0.02%, 50=0.01%, 100=0.01% 474s cpu : usr=9.13%, sys=7.93%, ctx=618200, majf=0, minf=1 474s IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0% 474s submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 474s complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 474s issued rwts: total=618124,0,0,0 short=0,0,0,0 dropped=0,0,0,0 474s latency : target=0, window=0, percentile=100.00%, depth=1 474s 474s Run status group 0 (all jobs): 474s READ: bw=215MiB/s (225MB/s), 215MiB/s-215MiB/s (225MB/s-225MB/s), io=37.7GiB (40.5GB), run=180001-180001msec 474s 474s Disk stats (read/write): 474s dm-0: ios=618236/11, sectors=79076024/12944, merge=21/10, ticks=164782/81, in_queue=164907, util=100.00%, aggrios=44519/2, aggsectors=5693934/3236, aggrmerge=0/0, aggrticks=10677/9, aggrin_queue=10685, aggrutil=99.15% 474s sdd: ios=35821/0, sectors=4581888/0, merge=0/0, ticks=8468/0, in_queue=8467, util=32.86% 474s sdb: ios=36498/10, sectors=4668160/12944, merge=0/0, ticks=8259/38, in_queue=8296, util=99.15% 474s sde: ios=71430/0, sectors=9136512/0, merge=0/0, ticks=17348/0, in_queue=17348, util=39.89% 474s sdc: ios=34329/0, sectors=4389176/0, merge=0/0, ticks=8633/0, in_queue=8632, util=49.98% 474s + date +Post FIO %H:%M:%S.%N 474s + echo FIO verify test with changing paths - OK 474s + echo Report log of background activity 474s + cat /tmp/autopkgtest.Glpwae/tgtbasedmpaths-artifacts/test-background.log 474s Post FIO 04:37:30.651289091 474s FIO verify test with changing paths - OK 474s Report log of background activity 474s + iscsiadm --mode session 474s tcp: [1] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 474s tcp: [2] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 474s tcp: [3] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 474s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 474s + sleep 10s 474s + date +MP report (expect 4) %H:%M:%S.%N 474s MP report (expect 4) 04:34:40.317437698 474s + multipath -ll 474s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 474s size=100M features='0' hwhandler='0' wp=rw 474s |-+- policy='service-time 0' prio=1 status=active 474s | `- 1:0:0:1 sdb 8:16 active ready running 474s |-+- policy='service-time 0' prio=1 status=enabled 474s | `- 2:0:0:1 sdc 8:32 active ready running 474s |-+- policy='service-time 0' prio=1 status=enabled 474s | `- 3:0:0:1 sdd 8:48 active ready running 474s `-+- policy='service-time 0' prio=1 status=enabled 474s `- 4:0:0:1 sde 8:64 active ready running 474s + date +UN-plug path 1 %H:%M:%S.%N 474s UN-plug path 1 04:34:40.345375633 474s + iscsiadm --mode session -r 1 -u 474s Logging out of session [sid: 1, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 474s Logout of [sid: 1, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 474s + iscsiadm --mode session 474s tcp: [2] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 474s tcp: [3] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 474s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 474s + sleep 10s 474s + date +MP report (expect 3) %H:%M:%S.%N 474s MP report (expect 3) 04:34:50.464334865 474s + multipath -ll 474s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 474s size=100M features='0' hwhandler='0' wp=rw 474s |-+- policy='service-time 0' prio=1 status=active 474s | `- 2:0:0:1 sdc 8:32 active ready running 474s |-+- policy='service-time 0' prio=1 status=enabled 474s | `- 3:0:0:1 sdd 8:48 active ready running 474s `-+- policy='service-time 0' prio=1 status=enabled 474s `- 4:0:0:1 sde 8:64 active ready running 474s + date +UN-plug path 2 %H:%M:%S.%N 474s UN-plug path 2 04:34:50.489132945 474s + iscsiadm --mode session -r 2 -u 474s Logging out of session [sid: 2, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 474s Logout of [sid: 2, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 474s + iscsiadm --mode session 474s tcp: [3] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 474s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 474s + sleep 10s 474s + date +MP report (expect 2) %H:%M:%S.%N 474s MP report (expect 2) 04:35:00.558446542 474s + multipath -ll 474s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 474s size=100M features='0' hwhandler='0' wp=rw 474s |-+- policy='service-time 0' prio=1 status=active 474s | `- 3:0:0:1 sdd 8:48 active ready running 474s `-+- policy='service-time 0' prio=1 status=enabled 474s `- 4:0:0:1 sde 8:64 active ready running 474s + date +UN-plug path 3 %H:%M:%S.%N 474s UN-plug path 3 04:35:00.579139765 474s + iscsiadm --mode session -r 3 -u 474s Logging out of session [sid: 3, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 474s Logout of [sid: 3, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 474s + iscsiadm --mode session 474s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 474s + sleep 10s 474s + date +MP report (expect 1) %H:%M:%S.%N 474s MP report (expect 1) 04:35:10.680701590 474s + multipath -ll 474s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 474s size=100M features='0' hwhandler='0' wp=rw 474s `-+- policy='service-time 0' prio=1 status=active 474s `- 4:0:0:1 sde 8:64 active ready running 474s + date +Add paths 5/6/7/8 %H:%M:%S.%N 474s Add paths 5/6/7/8 04:35:10.695558896 474s + iscsiadm --mode session -r 4 --op new 474s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 474s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 474s + iscsiadm --mode session -r 4 --op new 474s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 474s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 474s + iscsiadm --mode session -r 4 --op new 474s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 474s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 474s + iscsiadm --mode session -r 4 --op new 474s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 474s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 474s + iscsiadm --mode session 474s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 474s tcp: [5] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 474s tcp: [6] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 474s tcp: [7] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 474s tcp: [8] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 474s + sleep 10s 474s + date +MP report (expect 5) %H:%M:%S.%N 474s MP report (expect 5) 04:35:20.839908306 474s + multipath -ll 474s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 474s size=100M features='0' hwhandler='0' wp=rw 474s |-+- policy='service-time 0' prio=1 status=active 474s | `- 4:0:0:1 sde 8:64 active ready running 474s |-+- policy='service-time 0' prio=1 status=enabled 474s | `- 1:0:0:1 sdb 8:16 active ready running 474s |-+- policy='service-time 0' prio=1 status=enabled 474s | `- 2:0:0:1 sdc 8:32 active ready running 474s |-+- policy='service-time 0' prio=1 status=enabled 474s | `- 3:0:0:1 sdd 8:48 active ready running 474s `-+- policy='service-time 0' prio=1 status=enabled 474s `- 5:0:0:1 sdf 8:80 active ready running 474s + date +UN-plug multiple paths 4/7/8 %H:%M:%S.%N 474s UN-plug multiple paths 4/7/8 04:35:20.874327927 474s + iscsiadm --mode session -r 4 -u 474s Logging out of session [sid: 4, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 474s Logout of [sid: 4, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 474s + iscsiadm --mode session -r 7 -u 474s Logging out of session [sid: 7, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 474s Logout of [sid: 7, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 474s + iscsiadm --mode session -r 8 -u 474s Logging out of session [sid: 8, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 474s Logout of [sid: 8, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 474s + iscsiadm --mode session 474s tcp: [5] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 474s tcp: [6] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 474s + sleep 10s 474s + date +Restart multipath daemon %H:%M:%S.%N 474s Restart multipath daemon 04:35:31.138751513 474s + systemctl restart multipathd 474s + sleep 10s 474s + date +Final background report (expect 2) %H:%M:%S.%N 474s Final background report (expect 2) 04:35:41.232685311 474s + multipath -ll 474s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 474s size=100M features='0' hwhandler='0' wp=rw 474s |-+- policy='service-time 0' prio=1 status=active 474s | `- 1:0:0:1 sdb 8:16 active ready running 474s `-+- policy='service-time 0' prio=1 status=enabled 474s `- 2:0:0:1 sdc 8:32 active ready running 474s Final stats 474s Stats for session [sid: 5, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 474s iSCSI SNMP: 474s txdata_octets: 21085176 474s rxdata_octets: 28765229156 474s noptx_pdus: 0 474s scsicmd_pdus: 439007 474s tmfcmd_pdus: 0 474s login_pdus: 0 474s text_pdus: 0 474s dataout_pdus: 0 474s logout_pdus: 0 474s snack_pdus: 0 474s noprx_pdus: 0 474s scsirsp_pdus: 439007 474s tmfrsp_pdus: 0 474s textrsp_pdus: 0 474s datain_pdus: 438974 474s logoutrsp_pdus: 0 474s r2t_pdus: 0 474s async_pdus: 0 474s rjt_pdus: 0 474s digest_err: 0 474s timeout_err: 0 474s iSCSI Extended: 474s tx_sendpage_failures: 0 474s rx_discontiguous_hdr: 0 474s eh_abort_cnt: 0 474s Stats for session [sid: 6, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 474s iSCSI SNMP: 474s txdata_octets: 6456 474s rxdata_octets: 1514916 474s noptx_pdus: 0 474s scsicmd_pdus: 105 474s tmfcmd_pdus: 0 474s login_pdus: 0 474s text_pdus: 0 474s dataout_pdus: 0 474s logout_pdus: 0 474s snack_pdus: 0 474s noprx_pdus: 0 474s scsirsp_pdus: 105 474s tmfrsp_pdus: 0 474s textrsp_pdus: 0 474s datain_pdus: 83 474s logoutrsp_pdus: 0 474s r2t_pdus: 0 474s async_pdus: 0 474s rjt_pdus: 0 474s digest_err: 0 474s timeout_err: 0 474s iSCSI Extended: 474s tx_sendpage_failures: 0 474s rx_discontiguous_hdr: 0 474s eh_abort_cnt: 0 474s Aug 16 04:27:05 adtubuntu-oracular-ppc64el-server-20240815 multipathd[271]: multipathd: shut down 474s Aug 16 04:27:05 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Stopping multipathd.service - Device-Mapper Multipath Device Controller... 474s Aug 16 04:27:05 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: multipathd.service: Deactivated successfully. 474s Aug 16 04:27:05 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Stopped multipathd.service - Device-Mapper Multipath Device Controller. 474s -- Boot 0cffedc9b2e54ab4b60c16151633ec19 -- 474s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 474s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 multipathd[341]: multipathd v0.9.9: start up 474s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 multipathd[341]: reconfigure: setting up paths and maps 474s Aug 16 04:33:13 adtubuntu-oracular-ppc64el-server-20240815 systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 474s Aug 16 04:34:20 autopkgtest multipathd[341]: updated bindings file /etc/multipath/bindings 474s Aug 16 04:34:20 autopkgtest multipathd[341]: mpatha: addmap [0 204800 multipath 0 0 1 1 service-time 0 1 1 8:16 1] 474s Aug 16 04:34:20 autopkgtest multipathd[341]: sdb [8:16]: path added to devmap mpatha 474s Aug 16 04:34:20 autopkgtest multipathd[341]: mpatha: performing delayed actions 474s Aug 16 04:34:20 autopkgtest multipathd[341]: mpatha: reload [0 204800 multipath 0 0 4 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:64 1] 474s Aug 16 04:34:40 autopkgtest multipathd[341]: mpatha: reload [0 204800 multipath 0 0 3 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:64 1] 474s Aug 16 04:34:40 autopkgtest multipathd[341]: check_removed_paths: sdb: freeing path in removed state 474s Aug 16 04:34:40 autopkgtest multipathd[341]: 8:16: path removed from map mpatha 474s Aug 16 04:34:50 autopkgtest multipathd[341]: mpatha: reload [0 204800 multipath 0 0 2 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:64 1] 474s Aug 16 04:34:50 autopkgtest multipathd[341]: check_removed_paths: sdc: freeing path in removed state 474s Aug 16 04:34:50 autopkgtest multipathd[341]: 8:32: path removed from map mpatha 474s Aug 16 04:35:00 autopkgtest multipathd[341]: mpatha: reload [0 204800 multipath 0 0 1 1 service-time 0 1 1 8:64 1] 474s Aug 16 04:35:00 autopkgtest multipathd[341]: check_removed_paths: sdd: freeing path in removed state 474s Aug 16 04:35:00 autopkgtest multipathd[341]: 8:48: path removed from map mpatha 474s Aug 16 04:35:10 autopkgtest multipathd[341]: mpatha: reload [0 204800 multipath 0 0 2 1 service-time 0 1 1 8:64 1 service-time 0 1 1 8:16 1] 474s Aug 16 04:35:10 autopkgtest multipathd[341]: sdb [8:16]: path added to devmap mpatha 474s Aug 16 04:35:10 autopkgtest multipathd[341]: mpatha: reload [0 204800 multipath 0 0 3 1 service-time 0 1 1 8:64 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:32 1] 474s Aug 16 04:35:10 autopkgtest multipathd[341]: sdc [8:32]: path added to devmap mpatha 474s Aug 16 04:35:10 autopkgtest multipathd[341]: mpatha: reload [0 204800 multipath 0 0 4 1 service-time 0 1 1 8:64 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] 474s Aug 16 04:35:10 autopkgtest multipathd[341]: sdd [8:48]: path added to devmap mpatha 474s Aug 16 04:35:10 autopkgtest multipathd[341]: mpatha: reload [0 204800 multipath 0 0 5 1 service-time 0 1 1 8:64 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:80 1] 474s Aug 16 04:35:10 autopkgtest multipathd[341]: sdf [8:80]: path added to devmap mpatha 474s Aug 16 04:35:20 autopkgtest multipathd[341]: mpatha: reload [0 204800 multipath 0 0 4 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:80 1] 474s Aug 16 04:35:20 autopkgtest multipathd[341]: check_removed_paths: sde: freeing path in removed state 474s Aug 16 04:35:20 autopkgtest multipathd[341]: 8:64: path removed from map mpatha 474s Aug 16 04:35:20 autopkgtest multipathd[341]: mpatha: reload [0 204800 multip+ sync 474s + umount /dev/disk/by-id/wwn-0x60000000000000000e00000000010001 474s + echo Final stats 474s + iscsiadm --mode session --stats 474s + journalctl --no-pager -u multipathd 474s + echo Check final path status 474s + multipath -ll 474s + multipath -ll 474s + grep --count status= 474s + diskc=2 474s + multipath -ll 474s + grep --count status=active 474s + diska=1 474s + multipath -ll 474s + grep --count status=enabled 474s ath 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:80 1] 474s Aug 16 04:35:21 autopkgtest multipathd[341]: check_removed_paths: sdd: freeing path in removed state 474s Aug 16 04:35:21 autopkgtest multipathd[341]: 8:48: path removed from map mpatha 474s Aug 16 04:35:21 autopkgtest multipathd[341]: mpatha: reload [0 204800 multipath 0 0 2 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:32 1] 474s Aug 16 04:35:21 autopkgtest multipathd[341]: check_removed_paths: sdf: freeing path in removed state 474s Aug 16 04:35:21 autopkgtest multipathd[341]: 8:80: path removed from map mpatha 474s Aug 16 04:35:31 autopkgtest multipathd[341]: multipathd: shut down 474s Aug 16 04:35:31 autopkgtest systemd[1]: Stopping multipathd.service - Device-Mapper Multipath Device Controller... 474s Aug 16 04:35:31 autopkgtest systemd[1]: multipathd.service: Deactivated successfully. 474s Aug 16 04:35:31 autopkgtest systemd[1]: Stopped multipathd.service - Device-Mapper Multipath Device Controller. 474s Aug 16 04:35:31 autopkgtest systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 474s Aug 16 04:35:31 autopkgtest multipathd[6705]: multipathd v0.9.9: start up 474s Aug 16 04:35:31 autopkgtest multipathd[6705]: reconfigure: setting up paths and maps 474s Aug 16 04:35:31 autopkgtest systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 474s Check final path status 474s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 474s size=100M features='0' hwhandler='0' wp=rw 474s |-+- policy='service-time 0' prio=1 status=active 474s | `- 1:0:0:1 sdb 8:16 active ready running 474s `-+- policy='service-time 0' prio=1 status=enabled 474s `- 2:0:0:1 sdc 8:32 active ready running 474s + diske=1 474s + [ 2 -ne 2 -o 1 -ne 1 -o 1 -ne 1 ] 474s + echo OK 474s + iscsiadm --mode node --targetname iqn.2016-11.foo.com:target.iscsi --portal 127.0.0.1:3260 --logout 474s OK 474s Logging out of session [sid: 5, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 474s Logging out of session [sid: 6, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 474s Logout of [sid: 5, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 474s Logout of [sid: 6, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 474s + tgtadm --lld iscsi --op delete --mode logicalunit --tid 1 --lun 1 475s autopkgtest [04:37:31]: test tgtbasedmpaths: -----------------------] 475s tgtbasedmpaths PASS 475s autopkgtest [04:37:31]: test tgtbasedmpaths: - - - - - - - - - - results - - - - - - - - - - 476s autopkgtest [04:37:32]: @@@@@@@@@@@@@@@@@@@@ summary 476s initramfs SKIP Test lists explicitly supported architectures, but the current architecture ppc64el isn't listed. 476s initramfs SKIP Test lists explicitly supported architectures, but the current architecture ppc64el isn't listed. 476s kpartx-file-loopback PASS 476s tgtbasedmpaths PASS 490s nova [W] Using flock in scalingstack-bos01-ppc64el 490s Creating nova instance adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f2275-prod-proposed-migration-environment-3-c98f137b-a772-4d72-8d34-1aef6ab37c38 from image adt/ubuntu-oracular-ppc64el-server-20240816.img (UUID 5776f3bb-b9e5-43b7-af84-92abf39a977c)... 490s nova [W] Using flock in scalingstack-bos01-ppc64el 490s Creating nova instance adt-oracular-ppc64el-multipath-tools-20240816-042936-juju-7f2275-prod-proposed-migration-environment-3-c98f137b-a772-4d72-8d34-1aef6ab37c38 from image adt/ubuntu-oracular-ppc64el-server-20240816.img (UUID 5776f3bb-b9e5-43b7-af84-92abf39a977c)...