0s autopkgtest [20:34:58]: starting date and time: 2024-07-19 20:34:58+0000 0s autopkgtest [20:34:58]: git checkout: fd3bed09 nova: allow more retries for quota issues 0s autopkgtest [20:34:58]: host juju-7f2275-prod-proposed-migration-environment-3; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.m5obpq27/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:systemd,src:dpdk,src:nftables --apt-upgrade multipath-tools --timeout-short=300 --timeout-copy=20000 --timeout-test=20000 --timeout-build=20000 '--env=ADT_TEST_TRIGGERS=systemd/256.2-1ubuntu1 dpdk/23.11.1-2 nftables/1.1.0-1' -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest-big --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-3@bos01-ppc64el-19.secgroup --name adt-oracular-ppc64el-multipath-tools-20240719-203458-juju-7f2275-prod-proposed-migration-environment-3-200fc45d-fed1-4c1c-a99c-a1b333989ee1 --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/ 178s autopkgtest [20:37:56]: testbed dpkg architecture: ppc64el 178s autopkgtest [20:37:56]: testbed apt version: 2.9.6 178s autopkgtest [20:37:56]: @@@@@@@@@@@@@@@@@@@@ test bed setup 179s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [126 kB] 179s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [60.7 kB] 179s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [381 kB] 179s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [8548 B] 179s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [3232 B] 179s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el Packages [91.0 kB] 179s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el c-n-f Metadata [2116 B] 179s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el Packages [1368 B] 179s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el c-n-f Metadata [120 B] 179s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el Packages [434 kB] 179s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el c-n-f Metadata [8952 B] 179s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el Packages [1840 B] 179s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el c-n-f Metadata [120 B] 181s Fetched 1119 kB in 1s (1307 kB/s) 181s Reading package lists... 184s Reading package lists... 184s Building dependency tree... 184s Reading state information... 184s Calculating upgrade... 184s The following NEW packages will be installed: 184s systemd-cryptsetup 184s The following packages will be upgraded: 184s libnftables1 libnss-systemd libpam-systemd libsystemd-shared libsystemd0 184s libudev1 nftables systemd systemd-resolved systemd-sysv systemd-timesyncd 184s udev 184s 12 upgraded, 1 newly installed, 0 to remove and 0 not upgraded. 184s Need to get 10.6 MB of archives. 184s After this operation, 505 kB disk space will be freed. 184s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el systemd-timesyncd ppc64el 256.2-1ubuntu1 [37.9 kB] 185s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el systemd-resolved ppc64el 256.2-1ubuntu1 [363 kB] 185s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el libsystemd-shared ppc64el 256.2-1ubuntu1 [2468 kB] 185s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el libsystemd0 ppc64el 256.2-1ubuntu1 [547 kB] 185s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el systemd-sysv ppc64el 256.2-1ubuntu1 [11.9 kB] 185s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el libnss-systemd ppc64el 256.2-1ubuntu1 [210 kB] 185s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el libpam-systemd ppc64el 256.2-1ubuntu1 [318 kB] 185s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el systemd ppc64el 256.2-1ubuntu1 [3696 kB] 186s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el udev ppc64el 256.2-1ubuntu1 [2105 kB] 186s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el libudev1 ppc64el 256.2-1ubuntu1 [219 kB] 186s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el nftables ppc64el 1.1.0-1 [70.9 kB] 186s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el libnftables1 ppc64el 1.1.0-1 [451 kB] 186s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el systemd-cryptsetup ppc64el 256.2-1ubuntu1 [125 kB] 187s Fetched 10.6 MB in 2s (4810 kB/s) 187s (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 ... 72764 files and directories currently installed.) 187s Preparing to unpack .../systemd-timesyncd_256.2-1ubuntu1_ppc64el.deb ... 187s Unpacking systemd-timesyncd (256.2-1ubuntu1) over (256-1ubuntu1) ... 187s Preparing to unpack .../systemd-resolved_256.2-1ubuntu1_ppc64el.deb ... 187s Unpacking systemd-resolved (256.2-1ubuntu1) over (256-1ubuntu1) ... 187s Preparing to unpack .../libsystemd-shared_256.2-1ubuntu1_ppc64el.deb ... 187s Unpacking libsystemd-shared:ppc64el (256.2-1ubuntu1) over (256-1ubuntu1) ... 187s Preparing to unpack .../libsystemd0_256.2-1ubuntu1_ppc64el.deb ... 187s Unpacking libsystemd0:ppc64el (256.2-1ubuntu1) over (256-1ubuntu1) ... 187s Setting up libsystemd0:ppc64el (256.2-1ubuntu1) ... 187s (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 ... 72764 files and directories currently installed.) 187s Preparing to unpack .../0-systemd-sysv_256.2-1ubuntu1_ppc64el.deb ... 187s Unpacking systemd-sysv (256.2-1ubuntu1) over (256-1ubuntu1) ... 187s Preparing to unpack .../1-libnss-systemd_256.2-1ubuntu1_ppc64el.deb ... 187s Unpacking libnss-systemd:ppc64el (256.2-1ubuntu1) over (256-1ubuntu1) ... 187s Preparing to unpack .../2-libpam-systemd_256.2-1ubuntu1_ppc64el.deb ... 187s Unpacking libpam-systemd:ppc64el (256.2-1ubuntu1) over (256-1ubuntu1) ... 187s Preparing to unpack .../3-systemd_256.2-1ubuntu1_ppc64el.deb ... 187s Unpacking systemd (256.2-1ubuntu1) over (256-1ubuntu1) ... 188s Preparing to unpack .../4-udev_256.2-1ubuntu1_ppc64el.deb ... 188s Unpacking udev (256.2-1ubuntu1) over (256-1ubuntu1) ... 188s Preparing to unpack .../5-libudev1_256.2-1ubuntu1_ppc64el.deb ... 188s Unpacking libudev1:ppc64el (256.2-1ubuntu1) over (256-1ubuntu1) ... 188s Setting up libudev1:ppc64el (256.2-1ubuntu1) ... 188s (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 ... 72688 files and directories currently installed.) 188s Preparing to unpack .../nftables_1.1.0-1_ppc64el.deb ... 188s Unpacking nftables (1.1.0-1) over (1.0.9-2) ... 188s Preparing to unpack .../libnftables1_1.1.0-1_ppc64el.deb ... 188s Unpacking libnftables1:ppc64el (1.1.0-1) over (1.0.9-2) ... 188s Selecting previously unselected package systemd-cryptsetup. 188s Preparing to unpack .../systemd-cryptsetup_256.2-1ubuntu1_ppc64el.deb ... 188s Unpacking systemd-cryptsetup (256.2-1ubuntu1) ... 188s Setting up libnftables1:ppc64el (1.1.0-1) ... 188s Setting up nftables (1.1.0-1) ... 188s Setting up libsystemd-shared:ppc64el (256.2-1ubuntu1) ... 188s Setting up systemd (256.2-1ubuntu1) ... 188s /usr/lib/tmpfiles.d/legacy.conf:13: Duplicate line for path "/run/lock", ignoring. 188s Created symlink '/run/systemd/system/tmp.mount' → '/dev/null'. 189s /usr/lib/tmpfiles.d/legacy.conf:13: Duplicate line for path "/run/lock", ignoring. 189s Setting up systemd-cryptsetup (256.2-1ubuntu1) ... 189s Setting up systemd-timesyncd (256.2-1ubuntu1) ... 190s Setting up udev (256.2-1ubuntu1) ... 191s Setting up systemd-resolved (256.2-1ubuntu1) ... 191s Setting up systemd-sysv (256.2-1ubuntu1) ... 191s Setting up libnss-systemd:ppc64el (256.2-1ubuntu1) ... 191s Setting up libpam-systemd:ppc64el (256.2-1ubuntu1) ... 192s Processing triggers for libc-bin (2.39-0ubuntu9) ... 192s Processing triggers for man-db (2.12.1-2) ... 193s Processing triggers for dbus (1.14.10-4ubuntu4) ... 193s Processing triggers for shared-mime-info (2.4-5) ... 193s Warning: program compiled against libxml 212 using older 209 194s Processing triggers for initramfs-tools (0.142ubuntu30) ... 194s update-initramfs: Generating /boot/initrd.img-6.8.0-31-generic 194s W: No lz4 in /usr/bin:/sbin:/bin, using gzip 203s Reading package lists... 203s Building dependency tree... 203s Reading state information... 204s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 204s Hit:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease 204s Get:2 http://ftpmaster.internal/ubuntu oracular InRelease [121 kB] 204s Hit:3 http://ftpmaster.internal/ubuntu oracular-updates InRelease 204s Hit:4 http://ftpmaster.internal/ubuntu oracular-security InRelease 204s Get:5 http://ftpmaster.internal/ubuntu oracular/multiverse Sources [301 kB] 205s Get:6 http://ftpmaster.internal/ubuntu oracular/main Sources [1377 kB] 205s Get:7 http://ftpmaster.internal/ubuntu oracular/universe Sources [20.3 MB] 214s Get:8 http://ftpmaster.internal/ubuntu oracular/main ppc64el Packages [1354 kB] 215s Get:9 http://ftpmaster.internal/ubuntu oracular/universe ppc64el Packages [14.9 MB] 226s Get:10 http://ftpmaster.internal/ubuntu oracular/multiverse ppc64el Packages [186 kB] 228s Fetched 38.5 MB in 24s (1579 kB/s) 229s Reading package lists... 229s Reading package lists... 229s Building dependency tree... 229s Reading state information... 230s Calculating upgrade... 230s The following packages will be upgraded: 230s libxml2 230s 1 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 230s Need to get 728 kB of archives. 230s After this operation, 516 kB disk space will be freed. 230s Get:1 http://ftpmaster.internal/ubuntu oracular/main ppc64el libxml2 ppc64el 2.12.7+dfsg-3 [728 kB] 231s Fetched 728 kB in 1s (1368 kB/s) 231s (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 ... 72734 files and directories currently installed.) 231s Preparing to unpack .../libxml2_2.12.7+dfsg-3_ppc64el.deb ... 231s Unpacking libxml2:ppc64el (2.12.7+dfsg-3) over (2.9.14+dfsg-1.3ubuntu3) ... 231s Setting up libxml2:ppc64el (2.12.7+dfsg-3) ... 231s Processing triggers for libc-bin (2.39-0ubuntu9) ... 231s Reading package lists... 231s Building dependency tree... 231s Reading state information... 231s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 232s autopkgtest [20:38:50]: rebooting testbed after setup commands that affected boot 236s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 269s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 288s autopkgtest [20:39:46]: testbed running kernel: Linux 6.8.0-31-generic #31-Ubuntu SMP Sat Apr 20 00:05:55 UTC 2024 291s autopkgtest [20:39:49]: @@@@@@@@@@@@@@@@@@@@ apt-source multipath-tools 294s Get:1 http://ftpmaster.internal/ubuntu oracular/main multipath-tools 0.9.4-5ubuntu8 (dsc) [2770 B] 294s Get:2 http://ftpmaster.internal/ubuntu oracular/main multipath-tools 0.9.4-5ubuntu8 (tar) [554 kB] 294s Get:3 http://ftpmaster.internal/ubuntu oracular/main multipath-tools 0.9.4-5ubuntu8 (diff) [42.7 kB] 294s gpgv: Signature made Sun Apr 7 00:31:08 2024 UTC 294s gpgv: using RSA key AC483F68DE728F43F2202FCA568D30F321B2133D 294s gpgv: issuer "steve.langasek@ubuntu.com" 294s gpgv: Can't check signature: No public key 294s dpkg-source: warning: cannot verify inline signature for ./multipath-tools_0.9.4-5ubuntu8.dsc: no acceptable signature found 294s autopkgtest [20:39:52]: testing package multipath-tools version 0.9.4-5ubuntu8 294s autopkgtest [20:39:52]: build not needed 295s autopkgtest [20:39:53]: test kpartx-file-loopback: preparing testbed 296s Reading package lists... 297s Building dependency tree... 297s Reading state information... 297s Starting pkgProblemResolver with broken count: 0 297s Starting 2 pkgProblemResolver with broken count: 0 297s Done 297s The following additional packages will be installed: 297s liburing2 qemu-utils 297s Recommended packages: 297s qemu-block-extra 297s The following NEW packages will be installed: 297s autopkgtest-satdep liburing2 qemu-utils 297s 0 upgraded, 3 newly installed, 0 to remove and 0 not upgraded. 297s Need to get 2330 kB/2331 kB of archives. 297s After this operation, 15.4 MB of additional disk space will be used. 297s Get:1 /tmp/autopkgtest.3VCfNc/1-autopkgtest-satdep.deb autopkgtest-satdep ppc64el 0 [724 B] 298s Get:2 http://ftpmaster.internal/ubuntu oracular/main ppc64el liburing2 ppc64el 2.6-1 [26.9 kB] 298s Get:3 http://ftpmaster.internal/ubuntu oracular/main ppc64el qemu-utils ppc64el 1:8.2.2+ds-0ubuntu1 [2303 kB] 299s Fetched 2330 kB in 1s (2662 kB/s) 299s Selecting previously unselected package liburing2:ppc64el. 299s (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 ... 72734 files and directories currently installed.) 299s Preparing to unpack .../liburing2_2.6-1_ppc64el.deb ... 299s Unpacking liburing2:ppc64el (2.6-1) ... 299s Selecting previously unselected package qemu-utils. 299s Preparing to unpack .../qemu-utils_1%3a8.2.2+ds-0ubuntu1_ppc64el.deb ... 299s Unpacking qemu-utils (1:8.2.2+ds-0ubuntu1) ... 299s Selecting previously unselected package autopkgtest-satdep. 299s Preparing to unpack .../1-autopkgtest-satdep.deb ... 299s Unpacking autopkgtest-satdep (0) ... 299s Setting up liburing2:ppc64el (2.6-1) ... 299s Setting up qemu-utils (1:8.2.2+ds-0ubuntu1) ... 299s Setting up autopkgtest-satdep (0) ... 299s Processing triggers for man-db (2.12.1-2) ... 300s Processing triggers for libc-bin (2.39-0ubuntu9) ... 303s (Reading database ... 72754 files and directories currently installed.) 303s Removing autopkgtest-satdep (0) ... 304s autopkgtest [20:40:02]: test kpartx-file-loopback: [----------------------- 304s Formatting 'foo.img', fmt=raw size=20971520 305s Creating new GPT entries in memory. 305s Warning: The kernel is still using the old partition table. 305s The new table will be used at the next reboot or after you 305s run partprobe(8) or kpartx(8) 305s The operation has completed successfully. 305s add map loop0p1 (252:0): 0 38879 linear 7:0 2048 305s standard_filename: OK 305s del devmap : loop0p1 305s No devices found 305s standard_filename_cleanup: OK 305s Formatting 'fou du FaFa.img', fmt=raw size=20971520 306s Creating new GPT entries in memory. 306s Warning: The kernel is still using the old partition table. 306s The new table will be used at the next reboot or after you 306s run partprobe(8) or kpartx(8) 306s The operation has completed successfully. 306s add map loop0p1 (252:0): 0 38879 linear 7:0 2048 306s filename_with_spaces: OK 306s del devmap : loop0p1 306s No devices found 306s filename_with_spaces_cleanup: OK 306s autopkgtest [20:40:04]: test kpartx-file-loopback: -----------------------] 307s autopkgtest [20:40:05]: test kpartx-file-loopback: - - - - - - - - - - results - - - - - - - - - - 307s kpartx-file-loopback PASS 307s autopkgtest [20:40:05]: test tgtbasedmpaths: preparing testbed 430s autopkgtest [20:42:08]: testbed dpkg architecture: ppc64el 430s autopkgtest [20:42:08]: testbed apt version: 2.9.6 430s autopkgtest [20:42:08]: @@@@@@@@@@@@@@@@@@@@ test bed setup 431s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [126 kB] 432s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [60.7 kB] 432s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [8548 B] 432s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [381 kB] 432s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [3232 B] 432s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el Packages [91.0 kB] 432s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el c-n-f Metadata [2116 B] 432s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el Packages [1368 B] 432s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el c-n-f Metadata [120 B] 432s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el Packages [434 kB] 432s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el c-n-f Metadata [8952 B] 432s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el Packages [1840 B] 432s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el c-n-f Metadata [120 B] 434s Fetched 1119 kB in 1s (1344 kB/s) 434s Reading package lists... 436s Reading package lists... 436s Building dependency tree... 436s Reading state information... 437s Calculating upgrade... 437s The following NEW packages will be installed: 437s systemd-cryptsetup 437s The following packages will be upgraded: 437s libnftables1 libnss-systemd libpam-systemd libsystemd-shared libsystemd0 437s libudev1 libxml2 nftables systemd systemd-resolved systemd-sysv 437s systemd-timesyncd udev 437s 13 upgraded, 1 newly installed, 0 to remove and 0 not upgraded. 437s Need to get 11.4 MB of archives. 437s After this operation, 1021 kB disk space will be freed. 437s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el systemd-timesyncd ppc64el 256.2-1ubuntu1 [37.9 kB] 437s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el systemd-resolved ppc64el 256.2-1ubuntu1 [363 kB] 437s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el libsystemd-shared ppc64el 256.2-1ubuntu1 [2468 kB] 438s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el libsystemd0 ppc64el 256.2-1ubuntu1 [547 kB] 438s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el systemd-sysv ppc64el 256.2-1ubuntu1 [11.9 kB] 438s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el libnss-systemd ppc64el 256.2-1ubuntu1 [210 kB] 438s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el libpam-systemd ppc64el 256.2-1ubuntu1 [318 kB] 438s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el systemd ppc64el 256.2-1ubuntu1 [3696 kB] 438s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el udev ppc64el 256.2-1ubuntu1 [2105 kB] 439s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el libudev1 ppc64el 256.2-1ubuntu1 [219 kB] 439s Get:11 http://ftpmaster.internal/ubuntu oracular/main ppc64el libxml2 ppc64el 2.12.7+dfsg-3 [728 kB] 439s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el nftables ppc64el 1.1.0-1 [70.9 kB] 439s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el libnftables1 ppc64el 1.1.0-1 [451 kB] 439s Get:14 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el systemd-cryptsetup ppc64el 256.2-1ubuntu1 [125 kB] 439s Fetched 11.4 MB in 2s (4829 kB/s) 440s (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 ... 72764 files and directories currently installed.) 440s Preparing to unpack .../systemd-timesyncd_256.2-1ubuntu1_ppc64el.deb ... 440s Unpacking systemd-timesyncd (256.2-1ubuntu1) over (256-1ubuntu1) ... 440s Preparing to unpack .../systemd-resolved_256.2-1ubuntu1_ppc64el.deb ... 440s Unpacking systemd-resolved (256.2-1ubuntu1) over (256-1ubuntu1) ... 440s Preparing to unpack .../libsystemd-shared_256.2-1ubuntu1_ppc64el.deb ... 440s Unpacking libsystemd-shared:ppc64el (256.2-1ubuntu1) over (256-1ubuntu1) ... 440s Preparing to unpack .../libsystemd0_256.2-1ubuntu1_ppc64el.deb ... 440s Unpacking libsystemd0:ppc64el (256.2-1ubuntu1) over (256-1ubuntu1) ... 440s Setting up libsystemd0:ppc64el (256.2-1ubuntu1) ... 440s (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 ... 72764 files and directories currently installed.) 440s Preparing to unpack .../0-systemd-sysv_256.2-1ubuntu1_ppc64el.deb ... 440s Unpacking systemd-sysv (256.2-1ubuntu1) over (256-1ubuntu1) ... 440s Preparing to unpack .../1-libnss-systemd_256.2-1ubuntu1_ppc64el.deb ... 440s Unpacking libnss-systemd:ppc64el (256.2-1ubuntu1) over (256-1ubuntu1) ... 440s Preparing to unpack .../2-libpam-systemd_256.2-1ubuntu1_ppc64el.deb ... 440s Unpacking libpam-systemd:ppc64el (256.2-1ubuntu1) over (256-1ubuntu1) ... 440s Preparing to unpack .../3-systemd_256.2-1ubuntu1_ppc64el.deb ... 440s Unpacking systemd (256.2-1ubuntu1) over (256-1ubuntu1) ... 440s Preparing to unpack .../4-udev_256.2-1ubuntu1_ppc64el.deb ... 440s Unpacking udev (256.2-1ubuntu1) over (256-1ubuntu1) ... 440s Preparing to unpack .../5-libudev1_256.2-1ubuntu1_ppc64el.deb ... 440s Unpacking libudev1:ppc64el (256.2-1ubuntu1) over (256-1ubuntu1) ... 440s Setting up libudev1:ppc64el (256.2-1ubuntu1) ... 440s (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 ... 72688 files and directories currently installed.) 440s Preparing to unpack .../libxml2_2.12.7+dfsg-3_ppc64el.deb ... 440s Unpacking libxml2:ppc64el (2.12.7+dfsg-3) over (2.9.14+dfsg-1.3ubuntu3) ... 440s Preparing to unpack .../nftables_1.1.0-1_ppc64el.deb ... 440s Unpacking nftables (1.1.0-1) over (1.0.9-2) ... 440s Preparing to unpack .../libnftables1_1.1.0-1_ppc64el.deb ... 440s Unpacking libnftables1:ppc64el (1.1.0-1) over (1.0.9-2) ... 441s Selecting previously unselected package systemd-cryptsetup. 441s Preparing to unpack .../systemd-cryptsetup_256.2-1ubuntu1_ppc64el.deb ... 441s Unpacking systemd-cryptsetup (256.2-1ubuntu1) ... 441s Setting up libnftables1:ppc64el (1.1.0-1) ... 441s Setting up nftables (1.1.0-1) ... 441s Setting up libsystemd-shared:ppc64el (256.2-1ubuntu1) ... 441s Setting up libxml2:ppc64el (2.12.7+dfsg-3) ... 441s Setting up systemd (256.2-1ubuntu1) ... 441s /usr/lib/tmpfiles.d/legacy.conf:13: Duplicate line for path "/run/lock", ignoring. 441s Created symlink '/run/systemd/system/tmp.mount' → '/dev/null'. 441s /usr/lib/tmpfiles.d/legacy.conf:13: Duplicate line for path "/run/lock", ignoring. 442s Setting up systemd-cryptsetup (256.2-1ubuntu1) ... 442s Setting up systemd-timesyncd (256.2-1ubuntu1) ... 443s Setting up udev (256.2-1ubuntu1) ... 444s Setting up systemd-resolved (256.2-1ubuntu1) ... 444s Setting up systemd-sysv (256.2-1ubuntu1) ... 444s Setting up libnss-systemd:ppc64el (256.2-1ubuntu1) ... 444s Setting up libpam-systemd:ppc64el (256.2-1ubuntu1) ... 444s Processing triggers for libc-bin (2.39-0ubuntu9) ... 444s Processing triggers for man-db (2.12.1-2) ... 446s Processing triggers for dbus (1.14.10-4ubuntu4) ... 446s Processing triggers for shared-mime-info (2.4-5) ... 446s Processing triggers for initramfs-tools (0.142ubuntu30) ... 446s update-initramfs: Generating /boot/initrd.img-6.8.0-31-generic 446s W: No lz4 in /usr/bin:/sbin:/bin, using gzip 455s Reading package lists... 455s Building dependency tree... 455s Reading state information... 455s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 456s Hit:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease 456s Hit:2 http://ftpmaster.internal/ubuntu oracular InRelease 456s Hit:3 http://ftpmaster.internal/ubuntu oracular-updates InRelease 456s Hit:4 http://ftpmaster.internal/ubuntu oracular-security InRelease 457s Reading package lists... 457s Reading package lists... 457s Building dependency tree... 457s Reading state information... 457s Calculating upgrade... 457s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 457s Reading package lists... 458s Building dependency tree... 458s Reading state information... 458s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 458s autopkgtest [20:42:36]: rebooting testbed after setup commands that affected boot 462s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 495s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 519s Reading package lists... 520s Building dependency tree... 520s Reading state information... 520s Starting pkgProblemResolver with broken count: 0 520s Starting 2 pkgProblemResolver with broken count: 0 520s Done 520s The following additional packages will be installed: 520s fio libboost-iostreams1.83.0 libboost-thread1.83.0 libconfig-general-perl 520s libdaxctl1 libgfapi0 libgfrpc0 libgfxdr0 libglusterfs0 libisns0t64 libnbd0 520s libndctl6 libopeniscsiusr libpmem1 libpmemobj1 librados2 librbd1 520s librdmacm1t64 lsscsi open-iscsi tgt 520s Suggested packages: 520s fio-examples gnuplot tgt-glusterfs tgt-rbd 520s Recommended packages: 520s finalrd 520s The following NEW packages will be installed: 521s autopkgtest-satdep fio libboost-iostreams1.83.0 libboost-thread1.83.0 521s libconfig-general-perl libdaxctl1 libgfapi0 libgfrpc0 libgfxdr0 521s libglusterfs0 libisns0t64 libnbd0 libndctl6 libopeniscsiusr libpmem1 521s libpmemobj1 librados2 librbd1 librdmacm1t64 lsscsi open-iscsi tgt 521s 0 upgraded, 22 newly installed, 0 to remove and 0 not upgraded. 521s Need to get 10.7 MB/10.7 MB of archives. 521s After this operation, 49.0 MB of additional disk space will be used. 521s Get:1 /tmp/autopkgtest.3VCfNc/2-autopkgtest-satdep.deb autopkgtest-satdep ppc64el 0 [732 B] 521s Get:2 http://ftpmaster.internal/ubuntu oracular/main ppc64el libopeniscsiusr ppc64el 2.1.10-1ubuntu1 [54.9 kB] 521s Get:3 http://ftpmaster.internal/ubuntu oracular/main ppc64el libisns0t64 ppc64el 0.101-1 [117 kB] 521s Get:4 http://ftpmaster.internal/ubuntu oracular/main ppc64el open-iscsi ppc64el 2.1.10-1ubuntu1 [385 kB] 521s Get:5 http://ftpmaster.internal/ubuntu oracular/main ppc64el librdmacm1t64 ppc64el 52.0-2 [80.5 kB] 521s Get:6 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libconfig-general-perl all 2.65-2 [57.1 kB] 521s Get:7 http://ftpmaster.internal/ubuntu oracular/universe ppc64el tgt ppc64el 1:1.0.85-1.2ubuntu1 [254 kB] 521s Get:8 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libgfxdr0 ppc64el 11.1-4ubuntu1 [21.5 kB] 521s Get:9 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libglusterfs0 ppc64el 11.1-4ubuntu1 [311 kB] 521s Get:10 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libgfrpc0 ppc64el 11.1-4ubuntu1 [46.5 kB] 521s Get:11 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libgfapi0 ppc64el 11.1-4ubuntu1 [99.2 kB] 521s Get:12 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libnbd0 ppc64el 1.20.2-1 [97.4 kB] 521s Get:13 http://ftpmaster.internal/ubuntu oracular/main ppc64el libdaxctl1 ppc64el 77-2ubuntu2 [23.7 kB] 521s Get:14 http://ftpmaster.internal/ubuntu oracular/main ppc64el libndctl6 ppc64el 77-2ubuntu2 [74.9 kB] 521s Get:15 http://ftpmaster.internal/ubuntu oracular/main ppc64el libpmem1 ppc64el 1.13.1-1.1ubuntu2 [41.1 kB] 521s Get:16 http://ftpmaster.internal/ubuntu oracular/main ppc64el libboost-iostreams1.83.0 ppc64el 1.83.0-3ubuntu1 [259 kB] 521s Get:17 http://ftpmaster.internal/ubuntu oracular/main ppc64el libboost-thread1.83.0 ppc64el 1.83.0-3ubuntu1 [279 kB] 521s Get:18 http://ftpmaster.internal/ubuntu oracular/main ppc64el librados2 ppc64el 19.2.0~git20240301.4c76c50-0ubuntu7 [4026 kB] 522s Get:19 http://ftpmaster.internal/ubuntu oracular/main ppc64el libpmemobj1 ppc64el 1.13.1-1.1ubuntu2 [143 kB] 522s Get:20 http://ftpmaster.internal/ubuntu oracular/main ppc64el librbd1 ppc64el 19.2.0~git20240301.4c76c50-0ubuntu7 [3581 kB] 523s Get:21 http://ftpmaster.internal/ubuntu oracular/universe ppc64el fio ppc64el 3.37-1 [716 kB] 523s Get:22 http://ftpmaster.internal/ubuntu oracular/main ppc64el lsscsi ppc64el 0.32-1build1 [54.0 kB] 523s Preconfiguring packages ... 523s Fetched 10.7 MB in 2s (5121 kB/s) 523s Selecting previously unselected package libopeniscsiusr. 523s (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 ... 72734 files and directories currently installed.) 523s Preparing to unpack .../00-libopeniscsiusr_2.1.10-1ubuntu1_ppc64el.deb ... 523s Unpacking libopeniscsiusr (2.1.10-1ubuntu1) ... 523s Selecting previously unselected package libisns0t64:ppc64el. 523s Preparing to unpack .../01-libisns0t64_0.101-1_ppc64el.deb ... 523s Unpacking libisns0t64:ppc64el (0.101-1) ... 523s Selecting previously unselected package open-iscsi. 523s Preparing to unpack .../02-open-iscsi_2.1.10-1ubuntu1_ppc64el.deb ... 524s Unpacking open-iscsi (2.1.10-1ubuntu1) ... 524s Selecting previously unselected package librdmacm1t64:ppc64el. 524s Preparing to unpack .../03-librdmacm1t64_52.0-2_ppc64el.deb ... 524s Unpacking librdmacm1t64:ppc64el (52.0-2) ... 524s Selecting previously unselected package libconfig-general-perl. 524s Preparing to unpack .../04-libconfig-general-perl_2.65-2_all.deb ... 524s Unpacking libconfig-general-perl (2.65-2) ... 524s Selecting previously unselected package tgt. 524s Preparing to unpack .../05-tgt_1%3a1.0.85-1.2ubuntu1_ppc64el.deb ... 524s Unpacking tgt (1:1.0.85-1.2ubuntu1) ... 524s Selecting previously unselected package libgfxdr0:ppc64el. 524s Preparing to unpack .../06-libgfxdr0_11.1-4ubuntu1_ppc64el.deb ... 524s Unpacking libgfxdr0:ppc64el (11.1-4ubuntu1) ... 524s Selecting previously unselected package libglusterfs0:ppc64el. 524s Preparing to unpack .../07-libglusterfs0_11.1-4ubuntu1_ppc64el.deb ... 524s Unpacking libglusterfs0:ppc64el (11.1-4ubuntu1) ... 524s Selecting previously unselected package libgfrpc0:ppc64el. 524s Preparing to unpack .../08-libgfrpc0_11.1-4ubuntu1_ppc64el.deb ... 524s Unpacking libgfrpc0:ppc64el (11.1-4ubuntu1) ... 524s Selecting previously unselected package libgfapi0:ppc64el. 524s Preparing to unpack .../09-libgfapi0_11.1-4ubuntu1_ppc64el.deb ... 524s Unpacking libgfapi0:ppc64el (11.1-4ubuntu1) ... 524s Selecting previously unselected package libnbd0. 524s Preparing to unpack .../10-libnbd0_1.20.2-1_ppc64el.deb ... 524s Unpacking libnbd0 (1.20.2-1) ... 524s Selecting previously unselected package libdaxctl1:ppc64el. 524s Preparing to unpack .../11-libdaxctl1_77-2ubuntu2_ppc64el.deb ... 524s Unpacking libdaxctl1:ppc64el (77-2ubuntu2) ... 524s Selecting previously unselected package libndctl6:ppc64el. 524s Preparing to unpack .../12-libndctl6_77-2ubuntu2_ppc64el.deb ... 524s Unpacking libndctl6:ppc64el (77-2ubuntu2) ... 524s Selecting previously unselected package libpmem1:ppc64el. 524s Preparing to unpack .../13-libpmem1_1.13.1-1.1ubuntu2_ppc64el.deb ... 524s Unpacking libpmem1:ppc64el (1.13.1-1.1ubuntu2) ... 524s Selecting previously unselected package libboost-iostreams1.83.0:ppc64el. 524s Preparing to unpack .../14-libboost-iostreams1.83.0_1.83.0-3ubuntu1_ppc64el.deb ... 524s Unpacking libboost-iostreams1.83.0:ppc64el (1.83.0-3ubuntu1) ... 524s Selecting previously unselected package libboost-thread1.83.0:ppc64el. 524s Preparing to unpack .../15-libboost-thread1.83.0_1.83.0-3ubuntu1_ppc64el.deb ... 524s Unpacking libboost-thread1.83.0:ppc64el (1.83.0-3ubuntu1) ... 524s Selecting previously unselected package librados2. 524s Preparing to unpack .../16-librados2_19.2.0~git20240301.4c76c50-0ubuntu7_ppc64el.deb ... 524s Unpacking librados2 (19.2.0~git20240301.4c76c50-0ubuntu7) ... 524s Selecting previously unselected package libpmemobj1:ppc64el. 524s Preparing to unpack .../17-libpmemobj1_1.13.1-1.1ubuntu2_ppc64el.deb ... 524s Unpacking libpmemobj1:ppc64el (1.13.1-1.1ubuntu2) ... 524s Selecting previously unselected package librbd1. 524s Preparing to unpack .../18-librbd1_19.2.0~git20240301.4c76c50-0ubuntu7_ppc64el.deb ... 524s Unpacking librbd1 (19.2.0~git20240301.4c76c50-0ubuntu7) ... 524s Selecting previously unselected package fio. 524s Preparing to unpack .../19-fio_3.37-1_ppc64el.deb ... 524s Unpacking fio (3.37-1) ... 524s Selecting previously unselected package lsscsi. 524s Preparing to unpack .../20-lsscsi_0.32-1build1_ppc64el.deb ... 524s Unpacking lsscsi (0.32-1build1) ... 524s Selecting previously unselected package autopkgtest-satdep. 524s Preparing to unpack .../21-2-autopkgtest-satdep.deb ... 524s Unpacking autopkgtest-satdep (0) ... 524s Setting up libconfig-general-perl (2.65-2) ... 524s Setting up libisns0t64:ppc64el (0.101-1) ... 524s Setting up libboost-thread1.83.0:ppc64el (1.83.0-3ubuntu1) ... 524s Setting up libnbd0 (1.20.2-1) ... 524s Setting up libopeniscsiusr (2.1.10-1ubuntu1) ... 524s Setting up libglusterfs0:ppc64el (11.1-4ubuntu1) ... 524s Setting up libboost-iostreams1.83.0:ppc64el (1.83.0-3ubuntu1) ... 524s Setting up lsscsi (0.32-1build1) ... 524s Setting up libdaxctl1:ppc64el (77-2ubuntu2) ... 524s Setting up libndctl6:ppc64el (77-2ubuntu2) ... 524s Setting up librdmacm1t64:ppc64el (52.0-2) ... 524s Setting up tgt (1:1.0.85-1.2ubuntu1) ... 525s Created symlink '/etc/systemd/system/multi-user.target.wants/tgt.service' → '/usr/lib/systemd/system/tgt.service'. 525s Setting up libpmem1:ppc64el (1.13.1-1.1ubuntu2) ... 525s Setting up libgfxdr0:ppc64el (11.1-4ubuntu1) ... 525s Setting up librados2 (19.2.0~git20240301.4c76c50-0ubuntu7) ... 525s Setting up open-iscsi (2.1.10-1ubuntu1) ... 526s Created symlink '/etc/systemd/system/sockets.target.wants/iscsid.socket' → '/usr/lib/systemd/system/iscsid.socket'. 527s Created symlink '/etc/systemd/system/iscsi.service' → '/usr/lib/systemd/system/open-iscsi.service'. 527s Created symlink '/etc/systemd/system/sysinit.target.wants/open-iscsi.service' → '/usr/lib/systemd/system/open-iscsi.service'. 527s Setting up libpmemobj1:ppc64el (1.13.1-1.1ubuntu2) ... 527s Setting up librbd1 (19.2.0~git20240301.4c76c50-0ubuntu7) ... 527s Setting up libgfrpc0:ppc64el (11.1-4ubuntu1) ... 527s Setting up libgfapi0:ppc64el (11.1-4ubuntu1) ... 527s Setting up fio (3.37-1) ... 527s Setting up autopkgtest-satdep (0) ... 527s Processing triggers for man-db (2.12.1-2) ... 528s Processing triggers for initramfs-tools (0.142ubuntu30) ... 528s update-initramfs: Generating /boot/initrd.img-6.8.0-31-generic 529s W: No lz4 in /usr/bin:/sbin:/bin, using gzip 538s Processing triggers for libc-bin (2.39-0ubuntu9) ... 541s (Reading database ... 72975 files and directories currently installed.) 541s Removing autopkgtest-satdep (0) ... 546s autopkgtest [20:44:04]: test tgtbasedmpaths: [----------------------- 547s + targetname=iqn.2016-11.foo.com:target.iscsi 547s + pwd 547s + cwd=/tmp/autopkgtest.3VCfNc/build.fgR/src 547s + testdir=/mnt/tgtmpathtest 547s + localhost=127.0.0.1 547s + portal=127.0.0.1:3260 547s + maxpaths=4 547s + backfn=backingfile 547s + expectwwid=60000000000000000e00000000010001 547s + testdisk=/dev/disk/by-id/wwn-0x60000000000000000e00000000010001 547s + bglog=/tmp/autopkgtest.3VCfNc/tgtbasedmpaths-artifacts/test-background.log 547s + fioprep=/tmp/autopkgtest.3VCfNc/tgtbasedmpaths-artifacts/path-change-prep.fio 547s + fiovrfy=/tmp/autopkgtest.3VCfNc/tgtbasedmpaths-artifacts/path-change-check.fio 547s + service tgt restart 547s + truncate --size 100M backingfile 547s + tgtadm --lld iscsi --op new --mode target --tid 1 -T iqn.2016-11.foo.com:target.iscsi 547s + tgtadm --lld iscsi --op bind --mode target --tid 1 -I ALL 547s + tgtadm --lld iscsi --op new --mode logicalunit --tid 1 --lun 1 -b /tmp/autopkgtest.3VCfNc/build.fgR/src/backingfile 547s + iscsiadm --mode discovery --type sendtargets --portal 127.0.0.1 547s 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi 547s + echo login #1 547s + iscsiadm --mode node --targetname iqn.2016-11.foo.com:target.iscsi --portal 127.0.0.1:3260 --login 547s login #1 547s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 547s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 547s + seq 2 4 547s + echo extra login #2 547s + iscsiadm --mode session -r 1 --op new 547s extra login #2 547s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 547s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 547s + echo extra login #3 547s + iscsiadm --mode session -r 1 --op new 547s extra login #3 547s + echo extra login #4 547s + iscsiadm --mode session -r 1 --op new 547s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 547s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 547s extra login #4 547s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 547s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 547s + udevadm settle 548s + sleep 5 553s Status after initial setup 553s + echo Status after initial setup 553s + tgtadm --lld iscsi --mode target --op show 553s Target 1: iqn.2016-11.foo.com:target.iscsi 553s System information: 553s Driver: iscsi 553s State: ready 553s I_T nexus information: 553s I_T nexus: 1 553s Initiator: iqn.2004-10.com.ubuntu:01:76b7d826e14 alias: autopkgtest 553s Connection: 0 553s IP Address: 127.0.0.1 553s I_T nexus: 2 553s Initiator: iqn.2004-10.com.ubuntu:01:76b7d826e14 alias: autopkgtest 553s Connection: 0 553s IP Address: 127.0.0.1 553s I_T nexus: 3 553s Initiator: iqn.2004-10.com.ubuntu:01:76b7d826e14 alias: autopkgtest 553s Connection: 0 553s IP Address: 127.0.0.1 553s I_T nexus: 4 553s Initiator: iqn.2004-10.com.ubuntu:01:76b7d826e14 alias: autopkgtest 553s Connection: 0 553s IP Address: 127.0.0.1 553s LUN information: 553s LUN: 0 553s Type: controller 553s SCSI ID: IET 00010000 553s SCSI SN: beaf10 553s Size: 0 MB, Block size: 1 553s Online: Yes 553s Removable media: No 553s Prevent removal: No 553s Readonly: No 553s SWP: No 553s Thin-provisioning: No 553s Backing store type: null 553s Backing store path: None 553s Backing store flags: 553s LUN: 1 553s Type: disk 553s SCSI ID: IET 00010001 553s SCSI SN: beaf11 553s Size: 105 MB, Block size: 512 553s Online: Yes 553s Removable media: No 553s Prevent removal: No 553s Readonly: No 553s SWP: No 553s Thin-provisioning: No 553s Backing store type: rdwr 553s Backing store path: /tmp/autopkgtest.3VCfNc/build.fgR/src/backingfile 553s Backing store flags: 553s Account information: 553s ACL information: 553s ALL 553s + tgtadm --lld iscsi --op show --mode conn --tid 1 553s + iscsiadm --mode session -P 1 553s Session: 4 553s Connection: 0 553s Initiator: iqn.2004-10.com.ubuntu:01:76b7d826e14 553s IP Address: 127.0.0.1 553s Session: 3 553s Connection: 0 553s Initiator: iqn.2004-10.com.ubuntu:01:76b7d826e14 553s IP Address: 127.0.0.1 553s Session: 2 553s Connection: 0 553s Initiator: iqn.2004-10.com.ubuntu:01:76b7d826e14 553s IP Address: 127.0.0.1 553s Session: 1 553s Connection: 0 553s Initiator: iqn.2004-10.com.ubuntu:01:76b7d826e14 553s IP Address: 127.0.0.1 553s Target: iqn.2016-11.foo.com:target.iscsi (non-flash) 553s Current Portal: 127.0.0.1:3260,1 553s Persistent Portal: 127.0.0.1:3260,1 553s ********** 553s Interface: 553s ********** 553s Iface Name: default 553s Iface Transport: tcp 553s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:76b7d826e14 553s Iface IPaddress: 127.0.0.1 553s Iface HWaddress: default 553s Iface Netdev: default 553s SID: 1 553s iSCSI Connection State: LOGGED IN 553s iSCSI Session State: LOGGED_IN 553s Internal iscsid Session State: NO CHANGE 553s 553s ********** 553s Interface: 553s ********** 553s Iface Name: default 553s Iface Transport: tcp 553s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:76b7d826e14 553s Iface IPaddress: 127.0.0.1 553s Iface HWaddress: default 553s Iface Netdev: default 553s SID: 2 553s iSCSI Connection State: LOGGED IN 553s iSCSI Session State: LOGGED_IN 553s Internal iscsid Session State: NO CHANGE 553s 553s ********** 553s Interface: 553s ********** 553s Iface Name: default 553s Iface Transport: tcp 553s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:76b7d826e14 553s Iface IPaddress: 127.0.0.1 553s Iface HWaddress: default 553s Iface Netdev: default 553s SID: 3 553s iSCSI Connection State: LOGGED IN 553s iSCSI Session State: LOGGED_IN 553s Internal iscsid Session State: NO CHANGE 553s 553s ********** 553s Interface: 553s ********** 553s Iface Name: default 553s Iface Transport: tcp 553s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:76b7d826e14 553s Iface IPaddress: 127.0.0.1 553s Iface HWaddress: default 553s Iface Netdev: default 553s SID: 4 553s iSCSI Connection State: LOGGED IN 553s iSCSI Session State: LOGGED_IN 553s Internal iscsid Session State: NO CHANGE 553s + lsscsi -liv 553s [0:0:0:0] disk QEMU QEMU HARDDISK 2.5+ /dev/sda 0QEMU_QEMU_HARDDISK_drive-scsi0-0-0-0 553s state=running queue_depth=128 scsi_level=6 type=0 device_blocked=0 timeout=30 553s 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] 553s [1:0:0:0] storage IET Controller 0001 - - 553s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 553s dir: /sys/bus/scsi/devices/1:0:0:0 [/sys/devices/platform/host1/session1/target1:0:0/1:0:0:0] 553s [1:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdb 360000000000000000e00000000010001 553s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 553s dir: /sys/bus/scsi/devices/1:0:0:1 [/sys/devices/platform/host1/session1/target1:0:0/1:0:0:1] 553s [2:0:0:0] storage IET Controller 0001 - - 553s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 553s dir: /sys/bus/scsi/devices/2:0:0:0 [/sys/devices/platform/host2/session2/target2:0:0/2:0:0:0] 553s [2:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdc 360000000000000000e00000000010001 553s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 553s dir: /sys/bus/scsi/devices/2:0:0:1 [/sys/devices/platform/host2/session2/target2:0:0/2:0:0:1] 553s [3:0:0:0] storage IET Controller 0001 - - 553s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 553s dir: /sys/bus/scsi/devices/3:0:0:0 [/sys/devices/platform/host3/session3/target3:0:0/3:0:0:0] 553s [3:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdd 360000000000000000e00000000010001 553s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 553s dir: /sys/bus/scsi/devices/3:0:0:1 [/sys/devices/platform/host3/session3/target3:0:0/3:0:0:1] 553s [4:0:0:0] storage IET Controller 0001 - - 553s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 553s dir: /sys/bus/scsi/devices/4:0:0:0 [/sys/devices/platform/host4/session4/target4:0:0/4:0:0:0] 553s [4:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sde 33000000100000001 553s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 553s dir: /sys/bus/scsi/devices/4:0:0:1 [/sys/devices/platform/host4/session4/target4:0:0/4:0:0:1] 553s NVMe module may not be loaded 553s list_ndevices: scandir: /sys/class/nvme/: No such file or directory 553s + multipath -v3 -ll 553s 69.888175 | set open fds limit to 1073741816/1073741816 553s 69.888276 | loading /lib/multipath/libchecktur.so checker 553s 69.888389 | checker tur: message table size = 3 553s 69.888417 | loading /lib/multipath/libprioconst.so prioritizer 553s 69.888572 | _init_foreign: foreign library "nvme" is not enabled 553s 69.895100 | sda: size = 167772160 553s 69.895283 | sda: vendor = QEMU 553s 69.895330 | sda: product = QEMU HARDDISK 553s 69.895355 | sda: rev = 2.5+ 553s 69.895976 | sda: h:b:t:l = 0:0:0:0 553s 69.896323 | sda: tgt_node_name = 553s 69.896349 | sda: uid_attribute = ID_SERIAL (setting: multipath internal) 553s 69.896352 | sda: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 553s 69.896514 | sda: 10443 cyl, 255 heads, 63 sectors/track, start at 0 553s 69.896537 | sda: vpd_vendor_id = 0 "undef" (setting: multipath internal) 553s 69.896551 | __sysfs_attr_get_value: attribute '/sys/devices/pci0000:00/0000:00:02.0/virtio1/host0/target0:0:0/0:0:0:0/vpd_pg80' can not be opened: No such file or directory 553s 69.896556 | failed to read sysfs vpd pg80: No such file or directory 553s 69.896776 | sda: fail to get serial 553s 69.896800 | sda: detect_checker = yes (setting: multipath internal) 553s 69.896977 | sda: path_checker = tur (setting: multipath internal) 553s 69.897001 | sda: checker timeout = 30 s (setting: kernel sysfs) 553s 69.897127 | sda: tur state = up 553s 69.897466 | sdb: size = 204800 553s 69.897623 | sdb: vendor = IET 553s 69.897666 | sdb: product = VIRTUAL-DISK 553s 69.897689 | sdb: rev = 0001 553s 69.898332 | sdb: h:b:t:l = 1:0:0:1 553s 69.898738 | sdb: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 553s 69.898760 | sdb: uid_attribute = ID_SERIAL (setting: multipath internal) 553s 69.898763 | sdb: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 553s 69.898926 | sdb: 1024 cyl, 4 heads, 50 sectors/track, start at 0 553s 69.898948 | sdb: vpd_vendor_id = 0 "undef" (setting: multipath internal) 553s 69.898967 | sdb: serial = beaf11 553s 69.898969 | sdb: detect_checker = yes (setting: multipath internal) 553s 69.899431 | sdb: path_checker = tur (setting: multipath internal) 553s 69.899455 | sdb: checker timeout = 30 s (setting: kernel sysfs) 553s 69.899691 | sdb: tur state = up 553s 69.899852 | sdc: size = 204800 553s 69.900026 | sdc: vendor = IET 553s 69.900079 | sdc: product = VIRTUAL-DISK 553s 69.900103 | sdc: rev = 0001 553s 69.900818 | sdc: h:b:t:l = 2:0:0:1 553s 69.901217 | sdc: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 553s 69.901240 | sdc: uid_attribute = ID_SERIAL (setting: multipath internal) 553s 69.901242 | sdc: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 553s 69.901401 | sdc: 1024 cyl, 4 heads, 50 sectors/track, start at 0 553s 69.901422 | sdc: vpd_vendor_id = 0 "undef" (setting: multipath internal) 553s 69.901438 | sdc: serial = beaf11 553s 69.901440 | sdc: detect_checker = yes (setting: multipath internal) 553s 69.901696 | sdc: path_checker = tur (setting: multipath internal) 553s 69.901719 | sdc: checker timeout = 30 s (setting: kernel sysfs) 553s 69.901916 | sdc: tur state = up 553s 69.902085 | sdd: size = 204800 553s 69.902246 | sdd: vendor = IET 553s 69.902289 | sdd: product = VIRTUAL-DISK 553s 69.902314 | sdd: rev = 0001 553s 69.903011 | sdd: h:b:t:l = 3:0:0:1 553s 69.903400 | sdd: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 553s 69.903422 | sdd: uid_attribute = ID_SERIAL (setting: multipath internal) 553s 69.903424 | sdd: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 553s 69.903581 | sdd: 1024 cyl, 4 heads, 50 sectors/track, start at 0 553s 69.903603 | sdd: vpd_vendor_id = 0 "undef" (setting: multipath internal) 553s 69.903619 | sdd: serial = beaf11 553s 69.903621 | sdd: detect_checker = yes (setting: multipath internal) 553s 69.903902 | sdd: path_checker = tur (setting: multipath internal) 553s 69.903924 | sdd: checker timeout = 30 s (setting: kernel sysfs) 553s 69.904159 | sdd: tur state = up 553s 69.904330 | sde: size = 204800 553s 69.904489 | sde: vendor = IET 553s 69.904532 | sde: product = VIRTUAL-DISK 553s 69.904556 | sde: rev = 0001 553s 69.905266 | sde: h:b:t:l = 4:0:0:1 553s 69.905656 | sde: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 553s 69.905677 | sde: uid_attribute = ID_SERIAL (setting: multipath internal) 553s 69.905679 | sde: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 553s 69.905839 | sde: 1024 cyl, 4 heads, 50 sectors/track, start at 0 553s 69.905861 | sde: vpd_vendor_id = 0 "undef" (setting: multipath internal) 553s 69.905876 | sde: serial = beaf11 553s 69.905879 | sde: detect_checker = yes (setting: multipath internal) 553s 69.906134 | sde: path_checker = tur (setting: multipath internal) 553s 69.906156 | sde: checker timeout = 30 s (setting: kernel sysfs) 553s 69.906362 | sde: tur state = up 553s 69.906485 | loop0: device node name blacklisted 553s 69.906598 | loop1: device node name blacklisted 553s 69.906713 | loop2: device node name blacklisted 553s 69.906824 | loop3: device node name blacklisted 553s 69.906933 | loop4: device node name blacklisted 553s 69.907041 | loop5: device node name blacklisted 553s 69.907147 | loop6: device node name blacklisted 553s 69.907255 | loop7: device node name blacklisted 553s 69.907372 | dm-0: device node name blacklisted 553s 69.908452 | multipath-tools v0.9.4 (12/19, 2022) 553s 69.908498 | libdevmapper version 1.02.185 553s 69.908654 | kernel device mapper v4.48.0 553s 69.908687 | DM multipath kernel driver v1.14.0 553s 69.908828 | sdc: size = 204800 553s 69.908853 | sdc: vendor = IET 553s 69.908856 | sdc: product = VIRTUAL-DISK 553s 69.908858 | sdc: rev = 0001 553s 69.909505 | sdc: h:b:t:l = 2:0:0:1 553s 69.909649 | sdc: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 553s 69.909689 | sdc: 1024 cyl, 4 heads, 50 sectors/track, start at 0 553s 69.909692 | sdc: vpd_vendor_id = 0 "undef" (setting: multipath internal) 553s 69.909705 | sdc: serial = beaf11 553s 69.909910 | sdc: tur state = up 553s 69.909933 | sdc: uid = 360000000000000000e00000000010001 (udev) 553s 69.909936 | sdc: detect_prio = yes (setting: multipath internal) 553s 69.909940 | sdc: prio = const (setting: multipath internal) 553s 69.909942 | sdc: prio args = "" (setting: multipath internal) 553s 69.909945 | sdc: const prio = 1 553s 69.909974 | sdb: size = 204800 553s 69.909978 | sdb: vendor = IET 553s 69.909981 | sdb: product = VIRTUAL-DISK 553s 69.909983 | sdb: rev = 0001 553s 69.910602 | sdb: h:b:t:l = 1:0:0:1 553s 69.910739 | sdb: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 553s 69.910778 | sdb: 1024 cyl, 4 heads, 50 sectors/track, start at 0 553s 69.910781 | sdb: vpd_vendor_id = 0 "undef" (setting: multipath internal) 553s 69.910794 | sdb: serial = beaf11 553s 69.910930 | sdb: tur state = up 553s 69.910951 | sdb: uid = 360000000000000000e00000000010001 (udev) 553s 69.910954 | sdb: detect_prio = yes (setting: multipath internal) 553s 69.910957 | sdb: prio = const (setting: multipath internal) 553s 69.910959 | sdb: prio args = "" (setting: multipath internal) 553s 69.910961 | sdb: const prio = 1 553s 69.910987 | sdd: size = 204800 553s 69.910992 | sdd: vendor = IET 553s 69.910994 | sdd: product = VIRTUAL-DISK 553s 69.910997 | sdd: rev = 0001 553s 69.911613 | sdd: h:b:t:l = 3:0:0:1 553s 69.911749 | sdd: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 553s 69.911787 | sdd: 1024 cyl, 4 heads, 50 sectors/track, start at 0 553s 69.911790 | sdd: vpd_vendor_id = 0 "undef" (setting: multipath internal) 553s 69.911803 | sdd: serial = beaf11 553s 69.911931 | sdd: tur state = up 553s 69.911936 | sdd: uid = 360000000000000000e00000000010001 (udev) 553s 69.911939 | sdd: detect_prio = yes (setting: multipath internal) 553s 69.911942 | sdd: prio = const (setting: multipath internal) 553s 69.911944 | sdd: prio args = "" (setting: multipath internal) 553s 69.911947 | sdd: const prio = 1 553s 69.911972 | sde: size = 204800 553s 69.911977 | sde: vendor = IET 553s 69.911980 | sde: product = VIRTUAL-DISK 553s 69.911983 | sde: rev = 0001 553s 69.912634 | sde: h:b:t:l = 4:0:0:1 553s 69.912798 | sde: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 553s 69.912837 | sde: 1024 cyl, 4 heads, 50 sectors/track, start at 0 553s 69.912840 | sde: vpd_vendor_id = 0 "undef" (setting: multipath internal) 553s 69.912852 | sde: serial = beaf11 553s 69.913038 | sde: tur state = up 553s 69.913060 | sde: uid = 360000000000000000e00000000010001 (udev) 553s 69.913063 | sde: detect_prio = yes (setting: multipath internal) 553s 69.913066 | sde: prio = const (setting: multipath internal) 553s 69.913068 | sde: prio args = "" (setting: multipath internal) 553s 69.913070 | sde: const prio = 1 553s 69.913977 | unloading tur checker 553s 69.914067 | unloading const prioritizer 553s + dmsetup table 553s + echo Test WWN should now point to DM 553s + readlink /dev/disk/by-id/wwn-0x60000000000000000e00000000010001 553s + grep dm 553s + mkfs.ext4 -F /dev/disk/by-id/wwn-0x60000000000000000e00000000010001 553s mke2fs 1.47.1 (20-May-2024) 553s ===== paths list ===== 553s uuid hcil dev dev_t pri dm_st chk_st vend/prod/rev dev_st 553s 0:0:0:0 sda 8:0 -1 undef undef QEMU,QEMU HARDDISK unknown 553s 1:0:0:1 sdb 8:16 -1 undef undef IET,VIRTUAL-DISK unknown 553s 2:0:0:1 sdc 8:32 -1 undef undef IET,VIRTUAL-DISK unknown 553s 3:0:0:1 sdd 8:48 -1 undef undef IET,VIRTUAL-DISK unknown 553s 4:0:0:1 sde 8:64 -1 undef undef IET,VIRTUAL-DISK unknown 553s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 553s size=100M features='0' hwhandler='0' wp=rw 553s |-+- policy='service-time 0' prio=1 status=active 553s | `- 2:0:0:1 sdc 8:32 active ready running 553s |-+- policy='service-time 0' prio=1 status=enabled 553s | `- 1:0:0:1 sdb 8:16 active ready running 553s |-+- policy='service-time 0' prio=1 status=enabled 553s | `- 3:0:0:1 sdd 8:48 active ready running 553s `-+- policy='service-time 0' prio=1 status=enabled 553s `- 4:0:0:1 sde 8:64 active ready running 553s mpatha: 0 204800 multipath 0 0 4 1 service-time 0 1 2 8:32 1 1 service-time 0 1 2 8:16 1 1 service-time 0 1 2 8:48 1 1 service-time 0 1 2 8:64 1 1 553s Test WWN should now point to DM 553s ../../dm-0 553s Creating filesystem with 25600 4k blocks and 25600 inodes 553s 553s Allocating group tables: 0/1 done 553s Writing inode tables: 0/1 done 553s Creating journal (1024 blocks): done 553s Writing superblocks and filesystem accounting information: 0/1 done 553s 553s + udevadm settle 553s + sleep 3s 556s + mkdir -p /mnt/tgtmpathtest 556s + mount /dev/disk/by-id/wwn-0x60000000000000000e00000000010001 /mnt/tgtmpathtest 556s + cat 556s + cat 556s + fio --max-jobs=4 /tmp/autopkgtest.3VCfNc/tgtbasedmpaths-artifacts/path-change-prep.fio 556s write-phase: (g=0): rw=write, bs=(R) 64.0KiB-64.0KiB, (W) 64.0KiB-64.0KiB, (T) 64.0KiB-64.0KiB, ioengine=sync, iodepth=1 556s fio-3.37 556s Starting 1 thread 556s write-phase: Laying out IO file (1 file / 17592186044415MiB) 557s fio: io_u error on file /mnt/tgtmpathtest/datafile.tmp: No space left on device: write offset=91750400, buflen=65536 557s 557s write-phase: (groupid=0, jobs=1): err= 0: pid=5702: Fri Jul 19 20:44:15 2024 557s write: IOPS=1667, BW=104MiB/s (109MB/s)(87.5MiB/840msec); 0 zone resets 557s clat (usec): min=294, max=9471, avg=583.48, stdev=502.31 557s lat (usec): min=307, max=9484, avg=597.83, stdev=503.28 557s clat percentiles (usec): 557s | 1.00th=[ 330], 5.00th=[ 359], 10.00th=[ 375], 20.00th=[ 396], 557s | 30.00th=[ 429], 40.00th=[ 457], 50.00th=[ 490], 60.00th=[ 529], 557s | 70.00th=[ 578], 80.00th=[ 627], 90.00th=[ 734], 95.00th=[ 922], 557s | 99.00th=[ 2900], 99.50th=[ 4424], 99.90th=[ 6194], 99.95th=[ 9503], 557s | 99.99th=[ 9503] 557s bw ( KiB/s): min=98560, max=98560, per=92.40%, avg=98560.00, stdev= 0.00, samples=1 557s iops : min= 1540, max= 1540, avg=1540.00, stdev= 0.00, samples=1 557s lat (usec) : 500=53.10%, 750=37.83%, 1000=5.21% 557s lat (msec) : 2=2.14%, 4=0.93%, 10=0.71% 557s cpu : usr=5.13%, sys=4.53%, ctx=1402, majf=0, minf=0 557s IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0% 557s submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 557s complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 557s issued rwts: total=0,1401,0,0 short=0,0,0,0 dropped=0,0,0,0 557s latency : target=0, window=0, percentile=100.00%, depth=1 557s 557s Run status group 0 (all jobs): 557s WRITE: bw=104MiB/s (109MB/s), 104MiB/s-104MiB/s (109MB/s-109MB/s), io=87.5MiB (91.8MB), run=840-840msec 557s 557s Disk stats (read/write): 557s dm-0: ios=1/1043, sectors=8/133504, merge=0/0, ticks=1/595, in_queue=595, util=86.91%, aggrios=0/350, aggsectors=2/44820, aggrmerge=0/0, aggrticks=0/192, aggrin_queue=193, aggrutil=87.92% 557s sdd: ios=0/0, sectors=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 557s sdb: ios=0/0, sectors=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 557s sde: ios=0/0, sectors=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 557s sdc: ios=1/1402, sectors=8/179280, merge=0/0, ticks=0/771, in_queue=772, util=87.92% 557s Starting the path changes in background 557s + echo Starting the path changes in background 557s + date +Pre FIO %H:%M:%S.%N 557s Pre FIO 20:44:15.356794937 557s + fio --max-jobs=4 /tmp/autopkgtest.3VCfNc/tgtbasedmpaths-artifacts/path-change-check.fio 557s 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 557s fio-3.37 557s Starting 1 thread 737s 737s verify-phase: (groupid=0, jobs=1): err= 0: pid=5709: Fri Jul 19 20:47:15 2024 737s read: IOPS=2310, BW=144MiB/s (151MB/s)(25.4GiB/180001msec) 737s clat (usec): min=91, max=79077, avg=408.79, stdev=544.27 737s lat (usec): min=91, max=79077, avg=408.92, stdev=544.29 737s clat percentiles (usec): 737s | 1.00th=[ 155], 5.00th=[ 198], 10.00th=[ 217], 20.00th=[ 241], 737s | 30.00th=[ 285], 40.00th=[ 322], 50.00th=[ 347], 60.00th=[ 375], 737s | 70.00th=[ 396], 80.00th=[ 424], 90.00th=[ 502], 95.00th=[ 668], 737s | 99.00th=[ 2245], 99.50th=[ 3621], 99.90th=[ 7242], 99.95th=[ 8848], 737s | 99.99th=[15401] 737s bw ( KiB/s): min=83760, max=273920, per=100.00%, avg=147890.69, stdev=33626.60, samples=359 737s iops : min= 1308, max= 4280, avg=2310.70, stdev=525.43, samples=359 737s lat (usec) : 100=0.05%, 250=22.48%, 500=67.25%, 750=6.08%, 1000=1.28% 737s lat (msec) : 2=1.70%, 4=0.76%, 10=0.37%, 20=0.03%, 50=0.01% 737s lat (msec) : 100=0.01% 737s cpu : usr=6.28%, sys=8.02%, ctx=415886, majf=0, minf=1 737s IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0% 737s submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 737s complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 737s issued rwts: total=415834,0,0,0 short=0,0,0,0 dropped=0,0,0,0 737s latency : target=0, window=0, percentile=100.00%, depth=1 737s 737s Run status group 0 (all jobs): 737s READ: bw=144MiB/s (151MB/s), 144MiB/s-144MiB/s (151MB/s-151MB/s), io=25.4GiB (27.3GB), run=180001-180001msec 737s 737s Disk stats (read/write): 737s dm-0: ios=415956/11, sectors=53203000/12944, merge=23/10, ticks=174878/106, in_queue=175052, util=99.31%, aggrios=27390/2, aggsectors=3502990/3236, aggrmerge=0/0, aggrticks=11349/9, aggrin_queue=11358, aggrutil=99.57% 737s sdd: ios=21788/0, sectors=2786816/0, merge=0/0, ticks=9128/0, in_queue=9128, util=33.33% 737s sdb: ios=0/0, sectors=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 737s sde: ios=44712/0, sectors=5719040/0, merge=0/0, ticks=18097/0, in_queue=18097, util=39.76% 737s sdc: ios=43060/10, sectors=5506104/12944, merge=0/0, ticks=18172/38, in_queue=18209, util=99.57% 737s + date +Post FIO %H:%M:%S.%N 737s Post FIO 20:47:15.757954925 737s + echo FIO verify test with changing paths - OK 737s + echo Report log of background activity 737s + cat /tmp/autopkgtest.3VCfNc/tgtbasedmpaths-artifacts/test-background.log 737s FIO verify test with changing paths - OK 737s Report log of background activity 737s + iscsiadm --mode session 737s tcp: [1] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 737s tcp: [2] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 737s tcp: [3] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 737s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 737s + sleep 10s 737s + date +MP report (expect 4) %H:%M:%S.%N 737s MP report (expect 4) 20:44:25.369754047 737s + multipath -ll 737s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 737s size=100M features='0' hwhandler='0' wp=rw 737s |-+- policy='service-time 0' prio=1 status=active 737s | `- 2:0:0:1 sdc 8:32 active ready running 737s |-+- policy='service-time 0' prio=1 status=enabled 737s | `- 1:0:0:1 sdb 8:16 active ready running 737s |-+- policy='service-time 0' prio=1 status=enabled 737s | `- 3:0:0:1 sdd 8:48 active ready running 737s `-+- policy='service-time 0' prio=1 status=enabled 737s `- 4:0:0:1 sde 8:64 active ready running 737s + date +UN-plug path 1 %H:%M:%S.%N 737s UN-plug path 1 20:44:25.407875941 737s + iscsiadm --mode session -r 1 -u 737s Logging out of session [sid: 1, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 737s Logout of [sid: 1, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 737s + iscsiadm --mode session 737s tcp: [2] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 737s tcp: [3] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 737s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 737s + sleep 10s 737s + date +MP report (expect 3) %H:%M:%S.%N 737s MP report (expect 3) 20:44:35.508482918 737s + multipath -ll 737s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 737s size=100M features='0' hwhandler='0' wp=rw 737s |-+- policy='service-time 0' prio=1 status=active 737s | `- 2:0:0:1 sdc 8:32 active ready running 737s |-+- policy='service-time 0' prio=1 status=enabled 737s | `- 3:0:0:1 sdd 8:48 active ready running 737s `-+- policy='service-time 0' prio=1 status=enabled 737s `- 4:0:0:1 sde 8:64 active ready running 737s + date +UN-plug path 2 %H:%M:%S.%N 737s UN-plug path 2 20:44:35.554957544 737s + iscsiadm --mode session -r 2 -u 737s Logging out of session [sid: 2, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 737s Logout of [sid: 2, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 737s + iscsiadm --mode session 737s tcp: [3] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 737s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 737s + sleep 10s 737s + date +MP report (expect 2) %H:%M:%S.%N 737s MP report (expect 2) 20:44:45.641298818 737s + multipath -ll 737s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 737s size=100M features='0' hwhandler='0' wp=rw 737s |-+- policy='service-time 0' prio=1 status=active 737s | `- 3:0:0:1 sdd 8:48 active ready running 737s `-+- policy='service-time 0' prio=1 status=enabled 737s `- 4:0:0:1 sde 8:64 active ready running 737s + date +UN-plug path 3 %H:%M:%S.%N 737s UN-plug path 3 20:44:45.692946336 737s + iscsiadm --mode session -r 3 -u 737s Logging out of session [sid: 3, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 737s Logout of [sid: 3, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 737s + iscsiadm --mode session 737s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 737s + sleep 10s 737s + date +MP report (expect 1) %H:%M:%S.%N 737s MP report (expect 1) 20:44:55.787384233 737s + multipath -ll 737s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 737s size=100M features='0' hwhandler='0' wp=rw 737s `-+- policy='service-time 0' prio=1 status=active 737s `- 4:0:0:1 sde 8:64 active ready running 737s + date +Add paths 5/6/7/8 %H:%M:%S.%N 737s Add paths 5/6/7/8 20:44:55.810847000 737s + iscsiadm --mode session -r 4 --op new 737s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 737s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 737s + iscsiadm --mode session -r 4 --op new 737s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 737s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 737s + iscsiadm --mode session -r 4 --op new 737s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 737s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 737s + iscsiadm --mode session -r 4 --op new 737s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 737s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 737s + iscsiadm --mode session 737s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 737s tcp: [5] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 737s tcp: [6] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 737s tcp: [7] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 737s tcp: [8] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 737s + sleep 10s 737s + date +MP report (expect 5) %H:%M:%S.%N 737s MP report (expect 5) 20:45:05.972790385 737s + multipath -ll 737s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 737s size=100M features='0' hwhandler='0' wp=rw 737s |-+- policy='service-time 0' prio=1 status=active 737s | `- 4:0:0:1 sde 8:64 active ready running 737s |-+- policy='service-time 0' prio=1 status=enabled 737s | `- 1:0:0:1 sdb 8:16 active ready running 737s |-+- policy='service-time 0' prio=1 status=enabled 737s | `- 2:0:0:1 sdc 8:32 active ready running 737s |-+- policy='service-time 0' prio=1 status=enabled 737s | `- 3:0:0:1 sdd 8:48 active ready running 737s `-+- policy='service-time 0' prio=1 status=enabled 737s `- 5:0:0:1 sdf 8:80 active ready running 737s + date +UN-plug multiple paths 4/7/8 %H:%M:%S.%N 737s UN-plug multiple paths 4/7/8 20:45:06.027510267 737s + iscsiadm --mode session -r 4 -u 737s Logging out of session [sid: 4, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 737s Logout of [sid: 4, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 737s + iscsiadm --mode session -r 7 -u 737s Logging out of session [sid: 7, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 737s Logout of [sid: 7, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 737s + iscsiadm --mode session -r 8 -u 737s Logging out of session [sid: 8, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 737s Logout of [sid: 8, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 737s + iscsiadm --mode session 737s tcp: [5] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 737s tcp: [6] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 737s + sleep 10s 737s + date +Restart multipath daemon %H:%M:%S.%N 737s Restart multipath daemon 20:45:16.359597649 737s + systemctl restart multipathd 737s + sleep 10s 737s + date +Final background report (expect 2) %H:%M:%S.%N 737s Final background report (expect 2) 20:45:26.465350352 737s + multipath -ll 737s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 737s size=100M features='0' hwhandler='0' wp=rw 737s |-+- policy='service-time 0' prio=1 status=active 737s | `- 1:0:0:1 sdb 8:16 active ready running 737s `-+- policy='service-time 0' prio=1 status=enabled 737s `- 2:0:0:1 sdc 8:32 active ready running 737s Final stats 737s Stats for session [sid: 5, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 737s iSCSI SNMP: 737s txdata_octets: 14725080 737s rxdata_octets: 20081378372 737s noptx_pdus: 0 737s scsicmd_pdus: 306505 737s tmfcmd_pdus: 0 737s login_pdus: 0 737s text_pdus: 0 737s dataout_pdus: 0 737s logout_pdus: 0 737s snack_pdus: 0 737s noprx_pdus: 0 737s scsirsp_pdus: 306505 737s tmfrsp_pdus: 0 737s textrsp_pdus: 0 737s datain_pdus: 306472 737s logoutrsp_pdus: 0 737s r2t_pdus: 0 737s async_pdus: 0 737s rjt_pdus: 0 737s digest_err: 0 737s timeout_err: 0 737s iSCSI Extended: 737s tx_sendpage_failures: 0 737s rx_discontiguous_hdr: 0 737s eh_abort_cnt: 0 737s Stats for session [sid: 6, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 737s iSCSI SNMP: 737s txdata_octets: 6408 737s rxdata_octets: 1514868 737s noptx_pdus: 0 737s scsicmd_pdus: 104 737s tmfcmd_pdus: 0 737s login_pdus: 0 737s text_pdus: 0 737s dataout_pdus: 0 737s logout_pdus: 0 737s snack_pdus: 0 737s noprx_pdus: 0 737s scsirsp_pdus: 104 737s tmfrsp_pdus: 0 737s textrsp_pdus: 0 737s datain_pdus: 83 737s logoutrsp_pdus: 0 737s r2t_pdus: 0 737s async_pdus: 0 737s rjt_pdus: 0 737s digest_err: 0 737s timeout_err: 0 737s iSCSI Extended: 737s tx_sendpage_failures: 0 737s rx_discontiguous_hdr: 0 737s eh_abort_cnt: 0 737s + sync 737s + umount /dev/disk/by-id/wwn-0x60000000000000000e00000000010001 737s + echo Final stats 737s + iscsiadm --mode session --stats 737s + journalctl --no-pager -u multipathd 737s Jul 19 08:17:32 adtubuntu-oracular-ppc64el-server-20240718 multipathd[291]: multipathd: shut down 737s Jul 19 08:17:32 adtubuntu-oracular-ppc64el-server-20240718 systemd[1]: Stopping multipathd.service - Device-Mapper Multipath Device Controller... 737s Jul 19 08:17:32 adtubuntu-oracular-ppc64el-server-20240718 systemd[1]: multipathd.service: Deactivated successfully. 737s Jul 19 08:17:32 adtubuntu-oracular-ppc64el-server-20240718 systemd[1]: Stopped multipathd.service - Device-Mapper Multipath Device Controller. 737s -- Boot 25cc71e4ace14bec8d6f904093492d21 -- 737s Jul 19 20:41:27 adtubuntu-oracular-ppc64el-server-20240718 systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 737s Jul 19 20:41:27 adtubuntu-oracular-ppc64el-server-20240718 multipathd[349]: multipathd v0.9.4: start up 737s Jul 19 20:41:27 adtubuntu-oracular-ppc64el-server-20240718 multipathd[349]: reconfigure: setting up paths and maps 737s Jul 19 20:41:27 adtubuntu-oracular-ppc64el-server-20240718 systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 737s Jul 19 20:42:40 autopkgtest systemd[1]: Stopping multipathd.service - Device-Mapper Multipath Device Controller... 737s Jul 19 20:42:40 autopkgtest multipathd[349]: multipathd: shut down 737s Jul 19 20:42:40 autopkgtest systemd[1]: multipathd.service: Deactivated successfully. 737s Jul 19 20:42:40 autopkgtest systemd[1]: Stopped multipathd.service - Device-Mapper Multipath Device Controller. 737s -- Boot 277befdda03943e495325befd32cefba -- 737s Jul 19 20:43:04 autopkgtest systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 737s Jul 19 20:43:04 autopkgtest multipathd[340]: multipathd v0.9.4: start up 737s Jul 19 20:43:04 autopkgtest multipathd[340]: reconfigure: setting up paths and maps 737s Jul 19 20:43:04 autopkgtest systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 737s Jul 19 20:44:05 autopkgtest multipathd[340]: mpatha: addmap [0 204800 multipath 0 0 2 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:16 1] 737s Jul 19 20:44:05 autopkgtest multipathd[340]: sdb [8:16]: path added to devmap mpatha 737s Jul 19 20:44:06 autopkgtest multipathd[340]: mpatha: performing delayed actions 737s Jul 19 20:44:06 autopkgtest multipathd[340]: mpatha: reload [0 204800 multipath 0 0 4 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:64 1] 737s Jul 19 20:44:25 autopkgtest multipathd[340]: 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] 737s Jul 19 20:44:25 autopkgtest multipathd[340]: check_removed_paths: sdb: freeing path in removed state 737s Jul 19 20:44:25 autopkgtest multipathd[340]: 8:16: path removed from map mpatha 737s Jul 19 20:44:35 autopkgtest multipathd[340]: 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] 737s Jul 19 20:44:35 autopkgtest multipathd[340]: check_removed_paths: sdc: freeing path in removed state 737s Jul 19 20:44:35 autopkgtest multipathd[340]: 8:32: path removed from map mpatha 737s Jul 19 20:44:45 autopkgtest multipathd[340]: sdd: mark as failed 737s Jul 19 20:44:45 autopkgtest multipathd[340]: mpatha: remaining active paths: 1 737s Jul 19 20:44:45 autopkgtest multipathd[340]: mpatha: reload [0 204800 multipath 0 0 1 1 service-time 0 1 1 8:64 1] 737s Jul 19 20:44:45 autopkgtest multipathd[340]: check_removed_paths: sdd: freeing path in removed state 737s Jul 19 20:44:45 autopkgtest multipathd[340]: 8:48: path removed from map mpatha 737s Jul 19 20:44:55 autopkgtest multipathd[340]: 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] 737s Jul 19 20:44:55 autopkgtest multipathd[340]: sdb [8:16]: path added to devmap mpatha 737s Jul 19 20:44:55 autopkgtest multipathd[340]: 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] 737s Jul 19 20:44:55 autopkgtest multipathd[340]: sdc [8:32]: path added to devmap mpatha 737s Jul 19 20:44:55 autopkgtest multipathd[340]: 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] 737s Jul 19 20:44:56 autopkgtest multipathd[340]: sdd [8:48]: path added to devmap mpatha 737s Jul 19 20:44:56 autopkgtest multipathd[340]: 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] 737s Jul 19 20:44:56 autopkgtest multipathd[340]: sdf [8:80]: path added to devmap mpatha 737s Jul 19 20:45:06 autopkgtest multipathd[340]: sde: mark as failed 737s Jul 19 20:45:06 autopkgtest multipathd[340]: mpatha: remaining active paths: 4 737s Jul 19 20:45:06 autopkgtest multipathd[340]: 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] 737s Jul 19 20:45:06 autopkgtest multipathd[340]: check_removed_paths: sde: freeing path in removed state 737s Jul 19 20:45:06 autopkgtest multipathd[340]: 8:64: path removed from map mpatha 737s Jul 19 20:45:06 autopkgtest multipathd[340]: mpatha: reload [0 204800 multipath 0 0 3 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:80 1] 737s Jul 19 20:45:06 autopkgtest multipathd[340]: check_removed_paths: sdd: freeing path in removed state 737s Jul 19 20:45:06 autopkgtest multipathd[340]: 8:48: path removed from map mpatha 737s Jul 19 20:45:06 autopkgtest multipathd[340]: 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] 737s Jul 19 20:45:06 autopkgtest multipathd[340]: check_removed_paths: sdf: freeing path in removed state 737s Jul 19 20:45:06 autopkgtest multipathd[340]: 8:80: path removed from map mpatha 737s Jul 19 20:45:16 autopkgtest multipathd[340]: multipathd: shut down 737s Jul 19 20:45:16 autopkgtest systemd[1]: Stopping multipathd.service - Device-Mapper Multipath Device Controller... 737s Jul 19 20:45:16 autopkgtest systemd[1]: multipathd.service: Deactivated successfully. 737s Jul 19 20:45:16 autopkgtest systemd[1]: Stopped multipathd.service - Device-Mapper Multipath Device Controller. 737s Jul 19 20:45:16 autopkgtest systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 737s Jul 19 20:45:16 autopkgtest multipathd[6087]: multipathd v0.9.4: start up 737s Jul 19 20:45:16 autopkgtest multipathd[6087]: reconfigure: setting up paths and maps 737s Jul 19 20:45:16 autopkgtest systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 737s Check final path status 737s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 737s size=100M features='0' hwhandler='0' wp=rw 737s |-+- policy='service-time 0' prio=1 status=active 737s | `- 1:0:0:1 sdb 8:16 active ready running 737s `-+- policy='service-time 0' prio=1 status=enabled 737s `- 2:0:0:1 sdc 8:32 active ready running 737s OK 737s + echo Check final path status 737s + multipath -ll 737s + multipath -ll 737s + grep --count status= 737s + diskc=2 737s + multipath -ll 737s + grep --count status=active 737s + diska=1 737s + multipath -ll 737s + grep --count status=enabled 737s + diske=1 737s + [ 2 -ne 2 -o 1 -ne 1 -o 1 -ne 1 ] 737s + echo OK 737s + iscsiadm --mode node --targetname iqn.2016-11.foo.com:target.iscsi --portal 127.0.0.1:3260 --logout 738s Logging out of session [sid: 5, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 738s Logging out of session [sid: 6, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 738s Logout of [sid: 5, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 738s Logout of [sid: 6, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 738s + tgtadm --lld iscsi --op delete --mode logicalunit --tid 1 --lun 1 738s autopkgtest [20:47:16]: test tgtbasedmpaths: -----------------------] 739s tgtbasedmpaths PASS 739s autopkgtest [20:47:17]: test tgtbasedmpaths: - - - - - - - - - - results - - - - - - - - - - 739s autopkgtest [20:47:17]: @@@@@@@@@@@@@@@@@@@@ summary 739s kpartx-file-loopback PASS 739s tgtbasedmpaths PASS 755s nova [W] Using flock in scalingstack-bos01-ppc64el 755s Creating nova instance adt-oracular-ppc64el-multipath-tools-20240719-203458-juju-7f2275-prod-proposed-migration-environment-3-200fc45d-fed1-4c1c-a99c-a1b333989ee1 from image adt/ubuntu-oracular-ppc64el-server-20240719.img (UUID b078106a-a8d5-43f1-87e4-4cec4d145870)... 755s nova [W] Using flock in scalingstack-bos01-ppc64el 755s Creating nova instance adt-oracular-ppc64el-multipath-tools-20240719-203458-juju-7f2275-prod-proposed-migration-environment-3-200fc45d-fed1-4c1c-a99c-a1b333989ee1 from image adt/ubuntu-oracular-ppc64el-server-20240719.img (UUID b078106a-a8d5-43f1-87e4-4cec4d145870)...