0s autopkgtest [00:13:03]: starting date and time: 2024-07-22 00:13:03+0000
  0s autopkgtest [00:13:03]: git checkout: fd3bed09 nova: allow more retries for quota issues
  0s autopkgtest [00:13:03]: host juju-7f2275-prod-proposed-migration-environment-2; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.nwsj100z/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:lvm2 --apt-upgrade multipath-tools --timeout-short=300 --timeout-copy=20000 --timeout-test=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=lvm2/2.03.22-1ubuntu1 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest-big --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@bos02-ppc64el-11.secgroup --name adt-oracular-ppc64el-multipath-tools-20240722-001302-juju-7f2275-prod-proposed-migration-environment-2-56140ac4-6a17-4aa8-8724-4b9b08374a2f --image adt/ubuntu-oracular-ppc64el-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-2 --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://ftpmaster.internal/ubuntu/
206s autopkgtest [00:16:29]: testbed dpkg architecture: ppc64el
206s autopkgtest [00:16:29]: testbed apt version: 2.9.6
206s autopkgtest [00:16:29]: @@@@@@@@@@@@@@@@@@@@ test bed setup
208s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [126 kB]
208s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [3440 B]
208s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [62.0 kB]
208s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [392 kB]
208s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [8548 B]
208s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el Packages [102 kB]
208s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el c-n-f Metadata [2116 B]
208s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el Packages [1368 B]
208s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el c-n-f Metadata [120 B]
208s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el Packages [404 kB]
208s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el c-n-f Metadata [8952 B]
208s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el Packages [1448 B]
208s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el c-n-f Metadata [120 B]
211s Fetched 1113 kB in 1s (1266 kB/s)
211s Reading package lists...
215s Reading package lists...
215s Building dependency tree...
215s Reading state information...
215s Calculating upgrade...
215s The following packages will be upgraded:
215s   dmsetup gdisk libdevmapper1.02.1 netcat-openbsd
215s 4 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
215s Need to get 576 kB of archives.
215s After this operation, 0 B of additional disk space will be used.
215s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el libdevmapper1.02.1 ppc64el 2:1.02.196-1ubuntu1 [181 kB]
215s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el dmsetup ppc64el 2:1.02.196-1ubuntu1 [91.6 kB]
215s Get:3 http://ftpmaster.internal/ubuntu oracular/main ppc64el netcat-openbsd ppc64el 1.226-1.1 [45.3 kB]
215s Get:4 http://ftpmaster.internal/ubuntu oracular/main ppc64el gdisk ppc64el 1.0.10-2 [258 kB]
216s Fetched 576 kB in 0s (1163 kB/s)
216s (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 ... 72787 files and directories currently installed.)
216s Preparing to unpack .../libdevmapper1.02.1_2%3a1.02.196-1ubuntu1_ppc64el.deb ...
216s Unpacking libdevmapper1.02.1:ppc64el (2:1.02.196-1ubuntu1) over (2:1.02.185-3ubuntu4) ...
216s Preparing to unpack .../dmsetup_2%3a1.02.196-1ubuntu1_ppc64el.deb ...
216s Unpacking dmsetup (2:1.02.196-1ubuntu1) over (2:1.02.185-3ubuntu4) ...
216s Preparing to unpack .../netcat-openbsd_1.226-1.1_ppc64el.deb ...
216s Unpacking netcat-openbsd (1.226-1.1) over (1.226-1ubuntu2) ...
216s Preparing to unpack .../gdisk_1.0.10-2_ppc64el.deb ...
216s Unpacking gdisk (1.0.10-2) over (1.0.10-1build1) ...
216s Setting up netcat-openbsd (1.226-1.1) ...
216s Setting up gdisk (1.0.10-2) ...
216s Setting up libdevmapper1.02.1:ppc64el (2:1.02.196-1ubuntu1) ...
216s Setting up dmsetup (2:1.02.196-1ubuntu1) ...
216s Processing triggers for libc-bin (2.39-0ubuntu9) ...
216s Processing triggers for man-db (2.12.1-2) ...
217s Processing triggers for initramfs-tools (0.142ubuntu30) ...
217s update-initramfs: Generating /boot/initrd.img-6.8.0-31-generic
217s W: No lz4 in /usr/bin:/sbin:/bin, using gzip
224s Reading package lists...
225s Building dependency tree...
225s Reading state information...
225s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
225s Hit:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease
225s Hit:2 http://ftpmaster.internal/ubuntu oracular InRelease
225s Hit:3 http://ftpmaster.internal/ubuntu oracular-updates InRelease
225s Hit:4 http://ftpmaster.internal/ubuntu oracular-security InRelease
226s Reading package lists...
226s Reading package lists...
227s Building dependency tree...
227s Reading state information...
227s Calculating upgrade...
227s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
227s Reading package lists...
227s Building dependency tree...
227s Reading state information...
227s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
228s autopkgtest [00:16:51]: rebooting testbed after setup commands that affected boot
262s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds...
274s autopkgtest [00:17:37]: testbed running kernel: Linux 6.8.0-31-generic #31-Ubuntu SMP Sat Apr 20 00:05:55 UTC 2024
287s autopkgtest [00:17:50]: @@@@@@@@@@@@@@@@@@@@ apt-source multipath-tools
308s Get:1 http://ftpmaster.internal/ubuntu oracular/main multipath-tools 0.9.4-5ubuntu8 (dsc) [2770 B]
308s Get:2 http://ftpmaster.internal/ubuntu oracular/main multipath-tools 0.9.4-5ubuntu8 (tar) [554 kB]
308s Get:3 http://ftpmaster.internal/ubuntu oracular/main multipath-tools 0.9.4-5ubuntu8 (diff) [42.7 kB]
308s gpgv: Signature made Sun Apr  7 00:31:08 2024 UTC
308s gpgv:                using RSA key AC483F68DE728F43F2202FCA568D30F321B2133D
308s gpgv:                issuer "steve.langasek@ubuntu.com"
308s gpgv: Can't check signature: No public key
308s dpkg-source: warning: cannot verify inline signature for ./multipath-tools_0.9.4-5ubuntu8.dsc: no acceptable signature found
308s autopkgtest [00:18:11]: testing package multipath-tools version 0.9.4-5ubuntu8
309s autopkgtest [00:18:12]: build not needed
310s autopkgtest [00:18:13]: test kpartx-file-loopback: preparing testbed
317s Reading package lists...
317s Building dependency tree...
317s Reading state information...
317s Starting pkgProblemResolver with broken count: 0
317s Starting 2 pkgProblemResolver with broken count: 0
317s Done
318s The following additional packages will be installed:
318s   liburing2 qemu-utils
318s Recommended packages:
318s   qemu-block-extra
318s The following NEW packages will be installed:
318s   autopkgtest-satdep liburing2 qemu-utils
318s 0 upgraded, 3 newly installed, 0 to remove and 0 not upgraded.
318s Need to get 2330 kB/2331 kB of archives.
318s After this operation, 15.4 MB of additional disk space will be used.
318s Get:1 /tmp/autopkgtest.2T29gI/1-autopkgtest-satdep.deb autopkgtest-satdep ppc64el 0 [720 B]
318s Get:2 http://ftpmaster.internal/ubuntu oracular/main ppc64el liburing2 ppc64el 2.6-1 [26.9 kB]
318s Get:3 http://ftpmaster.internal/ubuntu oracular/main ppc64el qemu-utils ppc64el 1:8.2.2+ds-0ubuntu1 [2303 kB]
319s Fetched 2330 kB in 1s (3463 kB/s)
319s Selecting previously unselected package liburing2:ppc64el.
319s (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 ... 72787 files and directories currently installed.)
319s Preparing to unpack .../liburing2_2.6-1_ppc64el.deb ...
319s Unpacking liburing2:ppc64el (2.6-1) ...
319s Selecting previously unselected package qemu-utils.
319s Preparing to unpack .../qemu-utils_1%3a8.2.2+ds-0ubuntu1_ppc64el.deb ...
319s Unpacking qemu-utils (1:8.2.2+ds-0ubuntu1) ...
319s Selecting previously unselected package autopkgtest-satdep.
319s Preparing to unpack .../1-autopkgtest-satdep.deb ...
319s Unpacking autopkgtest-satdep (0) ...
319s Setting up liburing2:ppc64el (2.6-1) ...
319s Setting up qemu-utils (1:8.2.2+ds-0ubuntu1) ...
319s Setting up autopkgtest-satdep (0) ...
319s Processing triggers for man-db (2.12.1-2) ...
320s Processing triggers for libc-bin (2.39-0ubuntu9) ...
324s (Reading database ... 72807 files and directories currently installed.)
324s Removing autopkgtest-satdep (0) ...
333s autopkgtest [00:18:36]: test kpartx-file-loopback: [-----------------------
339s Formatting 'foo.img', fmt=raw size=20971520
340s Creating new GPT entries in memory.
340s Warning: The kernel is still using the old partition table.
340s The new table will be used at the next reboot or after you
340s run partprobe(8) or kpartx(8)
340s The operation has completed successfully.
340s add map loop0p1 (252:0): 0 38879 linear 7:0 2048
340s standard_filename: OK
340s del devmap : loop0p1
340s No devices found
340s standard_filename_cleanup: OK
340s Formatting 'fou du FaFa.img', fmt=raw size=20971520
341s Creating new GPT entries in memory.
341s Warning: The kernel is still using the old partition table.
341s The new table will be used at the next reboot or after you
341s run partprobe(8) or kpartx(8)
341s The operation has completed successfully.
341s add map loop0p1 (252:0): 0 38879 linear 7:0 2048
341s filename_with_spaces: OK
341s del devmap : loop0p1
341s No devices found
341s filename_with_spaces_cleanup: OK
341s autopkgtest [00:18:44]: test kpartx-file-loopback: -----------------------]
342s kpartx-file-loopback PASS
342s autopkgtest [00:18:45]: test kpartx-file-loopback:  - - - - - - - - - - results - - - - - - - - - -
344s autopkgtest [00:18:47]: test tgtbasedmpaths: preparing testbed
472s autopkgtest [00:20:55]: testbed dpkg architecture: ppc64el
473s autopkgtest [00:20:56]: testbed apt version: 2.9.6
473s autopkgtest [00:20:56]: @@@@@@@@@@@@@@@@@@@@ test bed setup
474s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [126 kB]
474s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [392 kB]
474s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [3440 B]
474s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [62.0 kB]
474s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [8548 B]
474s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el Packages [102 kB]
474s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el c-n-f Metadata [2116 B]
474s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el Packages [1368 B]
474s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/restricted ppc64el c-n-f Metadata [120 B]
474s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el Packages [404 kB]
475s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el c-n-f Metadata [8952 B]
475s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el Packages [1448 B]
475s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el c-n-f Metadata [120 B]
478s Fetched 1113 kB in 1s (913 kB/s)
478s Reading package lists...
480s Reading package lists...
481s Building dependency tree...
481s Reading state information...
481s Calculating upgrade...
481s The following packages will be upgraded:
481s   dmsetup gdisk libdevmapper1.02.1 netcat-openbsd
481s 4 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
481s Need to get 576 kB of archives.
481s After this operation, 0 B of additional disk space will be used.
481s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el libdevmapper1.02.1 ppc64el 2:1.02.196-1ubuntu1 [181 kB]
482s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el dmsetup ppc64el 2:1.02.196-1ubuntu1 [91.6 kB]
482s Get:3 http://ftpmaster.internal/ubuntu oracular/main ppc64el netcat-openbsd ppc64el 1.226-1.1 [45.3 kB]
482s Get:4 http://ftpmaster.internal/ubuntu oracular/main ppc64el gdisk ppc64el 1.0.10-2 [258 kB]
482s Fetched 576 kB in 1s (925 kB/s)
482s (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 ... 72787 files and directories currently installed.)
482s Preparing to unpack .../libdevmapper1.02.1_2%3a1.02.196-1ubuntu1_ppc64el.deb ...
482s Unpacking libdevmapper1.02.1:ppc64el (2:1.02.196-1ubuntu1) over (2:1.02.185-3ubuntu4) ...
482s Preparing to unpack .../dmsetup_2%3a1.02.196-1ubuntu1_ppc64el.deb ...
482s Unpacking dmsetup (2:1.02.196-1ubuntu1) over (2:1.02.185-3ubuntu4) ...
482s Preparing to unpack .../netcat-openbsd_1.226-1.1_ppc64el.deb ...
482s Unpacking netcat-openbsd (1.226-1.1) over (1.226-1ubuntu2) ...
482s Preparing to unpack .../gdisk_1.0.10-2_ppc64el.deb ...
482s Unpacking gdisk (1.0.10-2) over (1.0.10-1build1) ...
482s Setting up netcat-openbsd (1.226-1.1) ...
482s Setting up gdisk (1.0.10-2) ...
482s Setting up libdevmapper1.02.1:ppc64el (2:1.02.196-1ubuntu1) ...
482s Setting up dmsetup (2:1.02.196-1ubuntu1) ...
482s Processing triggers for libc-bin (2.39-0ubuntu9) ...
482s Processing triggers for man-db (2.12.1-2) ...
483s Processing triggers for initramfs-tools (0.142ubuntu30) ...
483s update-initramfs: Generating /boot/initrd.img-6.8.0-31-generic
483s W: No lz4 in /usr/bin:/sbin:/bin, using gzip
493s Reading package lists...
493s Building dependency tree...
493s Reading state information...
493s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
494s Hit:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease
494s Hit:2 http://ftpmaster.internal/ubuntu oracular InRelease
494s Hit:3 http://ftpmaster.internal/ubuntu oracular-updates InRelease
494s Hit:4 http://ftpmaster.internal/ubuntu oracular-security InRelease
495s Reading package lists...
495s Reading package lists...
495s Building dependency tree...
495s Reading state information...
496s Calculating upgrade...
496s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
496s Reading package lists...
496s Building dependency tree...
496s Reading state information...
496s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
497s autopkgtest [00:21:20]: rebooting testbed after setup commands that affected boot
530s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds...
549s Reading package lists...
550s Building dependency tree...
550s Reading state information...
550s Starting pkgProblemResolver with broken count: 0
550s Starting 2 pkgProblemResolver with broken count: 0
550s Done
550s The following additional packages will be installed:
550s   fio libboost-iostreams1.83.0 libboost-thread1.83.0 libconfig-general-perl
550s   libdaxctl1 libgfapi0 libgfrpc0 libgfxdr0 libglusterfs0 libisns0t64 libnbd0
550s   libndctl6 libopeniscsiusr libpmem1 libpmemobj1 librados2 librbd1
550s   librdmacm1t64 lsscsi open-iscsi tgt
550s Suggested packages:
550s   fio-examples gnuplot tgt-glusterfs tgt-rbd
550s Recommended packages:
550s   finalrd
550s The following NEW packages will be installed:
550s   autopkgtest-satdep fio libboost-iostreams1.83.0 libboost-thread1.83.0
550s   libconfig-general-perl libdaxctl1 libgfapi0 libgfrpc0 libgfxdr0
550s   libglusterfs0 libisns0t64 libnbd0 libndctl6 libopeniscsiusr libpmem1
550s   libpmemobj1 librados2 librbd1 librdmacm1t64 lsscsi open-iscsi tgt
550s 0 upgraded, 22 newly installed, 0 to remove and 0 not upgraded.
550s Need to get 10.7 MB/10.7 MB of archives.
550s After this operation, 49.0 MB of additional disk space will be used.
550s Get:1 /tmp/autopkgtest.2T29gI/2-autopkgtest-satdep.deb autopkgtest-satdep ppc64el 0 [736 B]
550s Get:2 http://ftpmaster.internal/ubuntu oracular/main ppc64el libopeniscsiusr ppc64el 2.1.10-1ubuntu1 [54.9 kB]
551s Get:3 http://ftpmaster.internal/ubuntu oracular/main ppc64el libisns0t64 ppc64el 0.101-1 [117 kB]
551s Get:4 http://ftpmaster.internal/ubuntu oracular/main ppc64el open-iscsi ppc64el 2.1.10-1ubuntu1 [385 kB]
551s Get:5 http://ftpmaster.internal/ubuntu oracular/main ppc64el librdmacm1t64 ppc64el 52.0-2 [80.5 kB]
551s Get:6 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libconfig-general-perl all 2.65-2 [57.1 kB]
551s Get:7 http://ftpmaster.internal/ubuntu oracular/universe ppc64el tgt ppc64el 1:1.0.85-1.2ubuntu1 [254 kB]
551s Get:8 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libgfxdr0 ppc64el 11.1-4ubuntu1 [21.5 kB]
551s Get:9 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libglusterfs0 ppc64el 11.1-4ubuntu1 [311 kB]
551s Get:10 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libgfrpc0 ppc64el 11.1-4ubuntu1 [46.5 kB]
551s Get:11 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libgfapi0 ppc64el 11.1-4ubuntu1 [99.2 kB]
551s Get:12 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libnbd0 ppc64el 1.20.2-1 [97.4 kB]
551s Get:13 http://ftpmaster.internal/ubuntu oracular/main ppc64el libdaxctl1 ppc64el 77-2ubuntu2 [23.7 kB]
551s Get:14 http://ftpmaster.internal/ubuntu oracular/main ppc64el libndctl6 ppc64el 77-2ubuntu2 [74.9 kB]
551s Get:15 http://ftpmaster.internal/ubuntu oracular/main ppc64el libpmem1 ppc64el 1.13.1-1.1ubuntu2 [41.1 kB]
551s Get:16 http://ftpmaster.internal/ubuntu oracular/main ppc64el libboost-iostreams1.83.0 ppc64el 1.83.0-3ubuntu1 [259 kB]
551s Get:17 http://ftpmaster.internal/ubuntu oracular/main ppc64el libboost-thread1.83.0 ppc64el 1.83.0-3ubuntu1 [279 kB]
551s Get:18 http://ftpmaster.internal/ubuntu oracular/main ppc64el librados2 ppc64el 19.2.0~git20240301.4c76c50-0ubuntu7 [4026 kB]
552s Get:19 http://ftpmaster.internal/ubuntu oracular/main ppc64el libpmemobj1 ppc64el 1.13.1-1.1ubuntu2 [143 kB]
552s Get:20 http://ftpmaster.internal/ubuntu oracular/main ppc64el librbd1 ppc64el 19.2.0~git20240301.4c76c50-0ubuntu7 [3581 kB]
553s Get:21 http://ftpmaster.internal/ubuntu oracular/universe ppc64el fio ppc64el 3.37-1 [716 kB]
553s Get:22 http://ftpmaster.internal/ubuntu oracular/main ppc64el lsscsi ppc64el 0.32-1build1 [54.0 kB]
553s Preconfiguring packages ...
553s Fetched 10.7 MB in 3s (4233 kB/s)
553s Selecting previously unselected package libopeniscsiusr.
553s (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 ... 72787 files and directories currently installed.)
553s Preparing to unpack .../00-libopeniscsiusr_2.1.10-1ubuntu1_ppc64el.deb ...
553s Unpacking libopeniscsiusr (2.1.10-1ubuntu1) ...
553s Selecting previously unselected package libisns0t64:ppc64el.
553s Preparing to unpack .../01-libisns0t64_0.101-1_ppc64el.deb ...
553s Unpacking libisns0t64:ppc64el (0.101-1) ...
553s Selecting previously unselected package open-iscsi.
553s Preparing to unpack .../02-open-iscsi_2.1.10-1ubuntu1_ppc64el.deb ...
554s Unpacking open-iscsi (2.1.10-1ubuntu1) ...
554s Selecting previously unselected package librdmacm1t64:ppc64el.
554s Preparing to unpack .../03-librdmacm1t64_52.0-2_ppc64el.deb ...
554s Unpacking librdmacm1t64:ppc64el (52.0-2) ...
554s Selecting previously unselected package libconfig-general-perl.
554s Preparing to unpack .../04-libconfig-general-perl_2.65-2_all.deb ...
554s Unpacking libconfig-general-perl (2.65-2) ...
554s Selecting previously unselected package tgt.
554s Preparing to unpack .../05-tgt_1%3a1.0.85-1.2ubuntu1_ppc64el.deb ...
554s Unpacking tgt (1:1.0.85-1.2ubuntu1) ...
554s Selecting previously unselected package libgfxdr0:ppc64el.
554s Preparing to unpack .../06-libgfxdr0_11.1-4ubuntu1_ppc64el.deb ...
554s Unpacking libgfxdr0:ppc64el (11.1-4ubuntu1) ...
554s Selecting previously unselected package libglusterfs0:ppc64el.
554s Preparing to unpack .../07-libglusterfs0_11.1-4ubuntu1_ppc64el.deb ...
554s Unpacking libglusterfs0:ppc64el (11.1-4ubuntu1) ...
554s Selecting previously unselected package libgfrpc0:ppc64el.
554s Preparing to unpack .../08-libgfrpc0_11.1-4ubuntu1_ppc64el.deb ...
554s Unpacking libgfrpc0:ppc64el (11.1-4ubuntu1) ...
554s Selecting previously unselected package libgfapi0:ppc64el.
554s Preparing to unpack .../09-libgfapi0_11.1-4ubuntu1_ppc64el.deb ...
554s Unpacking libgfapi0:ppc64el (11.1-4ubuntu1) ...
554s Selecting previously unselected package libnbd0.
554s Preparing to unpack .../10-libnbd0_1.20.2-1_ppc64el.deb ...
554s Unpacking libnbd0 (1.20.2-1) ...
554s Selecting previously unselected package libdaxctl1:ppc64el.
554s Preparing to unpack .../11-libdaxctl1_77-2ubuntu2_ppc64el.deb ...
554s Unpacking libdaxctl1:ppc64el (77-2ubuntu2) ...
554s Selecting previously unselected package libndctl6:ppc64el.
554s Preparing to unpack .../12-libndctl6_77-2ubuntu2_ppc64el.deb ...
554s Unpacking libndctl6:ppc64el (77-2ubuntu2) ...
554s Selecting previously unselected package libpmem1:ppc64el.
554s Preparing to unpack .../13-libpmem1_1.13.1-1.1ubuntu2_ppc64el.deb ...
554s Unpacking libpmem1:ppc64el (1.13.1-1.1ubuntu2) ...
554s Selecting previously unselected package libboost-iostreams1.83.0:ppc64el.
554s Preparing to unpack .../14-libboost-iostreams1.83.0_1.83.0-3ubuntu1_ppc64el.deb ...
554s Unpacking libboost-iostreams1.83.0:ppc64el (1.83.0-3ubuntu1) ...
554s Selecting previously unselected package libboost-thread1.83.0:ppc64el.
554s Preparing to unpack .../15-libboost-thread1.83.0_1.83.0-3ubuntu1_ppc64el.deb ...
554s Unpacking libboost-thread1.83.0:ppc64el (1.83.0-3ubuntu1) ...
554s Selecting previously unselected package librados2.
554s Preparing to unpack .../16-librados2_19.2.0~git20240301.4c76c50-0ubuntu7_ppc64el.deb ...
554s Unpacking librados2 (19.2.0~git20240301.4c76c50-0ubuntu7) ...
554s Selecting previously unselected package libpmemobj1:ppc64el.
554s Preparing to unpack .../17-libpmemobj1_1.13.1-1.1ubuntu2_ppc64el.deb ...
554s Unpacking libpmemobj1:ppc64el (1.13.1-1.1ubuntu2) ...
554s Selecting previously unselected package librbd1.
554s Preparing to unpack .../18-librbd1_19.2.0~git20240301.4c76c50-0ubuntu7_ppc64el.deb ...
554s Unpacking librbd1 (19.2.0~git20240301.4c76c50-0ubuntu7) ...
554s Selecting previously unselected package fio.
554s Preparing to unpack .../19-fio_3.37-1_ppc64el.deb ...
554s Unpacking fio (3.37-1) ...
554s Selecting previously unselected package lsscsi.
554s Preparing to unpack .../20-lsscsi_0.32-1build1_ppc64el.deb ...
554s Unpacking lsscsi (0.32-1build1) ...
554s Selecting previously unselected package autopkgtest-satdep.
554s Preparing to unpack .../21-2-autopkgtest-satdep.deb ...
554s Unpacking autopkgtest-satdep (0) ...
554s Setting up libconfig-general-perl (2.65-2) ...
554s Setting up libisns0t64:ppc64el (0.101-1) ...
554s Setting up libboost-thread1.83.0:ppc64el (1.83.0-3ubuntu1) ...
554s Setting up libnbd0 (1.20.2-1) ...
554s Setting up libopeniscsiusr (2.1.10-1ubuntu1) ...
554s Setting up libglusterfs0:ppc64el (11.1-4ubuntu1) ...
554s Setting up libboost-iostreams1.83.0:ppc64el (1.83.0-3ubuntu1) ...
554s Setting up lsscsi (0.32-1build1) ...
554s Setting up libdaxctl1:ppc64el (77-2ubuntu2) ...
554s Setting up libndctl6:ppc64el (77-2ubuntu2) ...
554s Setting up librdmacm1t64:ppc64el (52.0-2) ...
554s Setting up tgt (1:1.0.85-1.2ubuntu1) ...
555s Created symlink '/etc/systemd/system/multi-user.target.wants/tgt.service' → '/usr/lib/systemd/system/tgt.service'.

555s Setting up libpmem1:ppc64el (1.13.1-1.1ubuntu2) ...
555s Setting up libgfxdr0:ppc64el (11.1-4ubuntu1) ...
555s Setting up librados2 (19.2.0~git20240301.4c76c50-0ubuntu7) ...
555s Setting up open-iscsi (2.1.10-1ubuntu1) ...
556s Created symlink '/etc/systemd/system/sockets.target.wants/iscsid.socket' → '/usr/lib/systemd/system/iscsid.socket'.

557s Created symlink '/etc/systemd/system/iscsi.service' → '/usr/lib/systemd/system/open-iscsi.service'.

557s Created symlink '/etc/systemd/system/sysinit.target.wants/open-iscsi.service' → '/usr/lib/systemd/system/open-iscsi.service'.

557s Setting up libpmemobj1:ppc64el (1.13.1-1.1ubuntu2) ...
557s Setting up librbd1 (19.2.0~git20240301.4c76c50-0ubuntu7) ...
557s Setting up libgfrpc0:ppc64el (11.1-4ubuntu1) ...
557s Setting up libgfapi0:ppc64el (11.1-4ubuntu1) ...
557s Setting up fio (3.37-1) ...
557s Setting up autopkgtest-satdep (0) ...
557s Processing triggers for man-db (2.12.1-2) ...
559s Processing triggers for initramfs-tools (0.142ubuntu30) ...
559s update-initramfs: Generating /boot/initrd.img-6.8.0-31-generic
559s W: No lz4 in /usr/bin:/sbin:/bin, using gzip
568s Processing triggers for libc-bin (2.39-0ubuntu9) ...
571s (Reading database ... 73028 files and directories currently installed.)
571s Removing autopkgtest-satdep (0) ...
573s autopkgtest [00:22:36]: test tgtbasedmpaths: [-----------------------
573s + targetname=iqn.2016-11.foo.com:target.iscsi
573s + pwd
573s + cwd=/tmp/autopkgtest.2T29gI/build.oE6/src
573s + testdir=/mnt/tgtmpathtest
573s + localhost=127.0.0.1
573s + portal=127.0.0.1:3260
573s + maxpaths=4
573s + backfn=backingfile
573s + expectwwid=60000000000000000e00000000010001
573s + testdisk=/dev/disk/by-id/wwn-0x60000000000000000e00000000010001
573s + bglog=/tmp/autopkgtest.2T29gI/tgtbasedmpaths-artifacts/test-background.log
573s + fioprep=/tmp/autopkgtest.2T29gI/tgtbasedmpaths-artifacts/path-change-prep.fio
573s + fiovrfy=/tmp/autopkgtest.2T29gI/tgtbasedmpaths-artifacts/path-change-check.fio
573s + service tgt restart
573s + truncate --size 100M backingfile
573s + tgtadm --lld iscsi --op new --mode target --tid 1 -T iqn.2016-11.foo.com:target.iscsi
573s + tgtadm --lld iscsi --op bind --mode target --tid 1 -I ALL
573s + tgtadm --lld iscsi --op new --mode logicalunit --tid 1 --lun 1 -b /tmp/autopkgtest.2T29gI/build.oE6/src/backingfile
573s + iscsiadm --mode discovery --type sendtargets --portal 127.0.0.1
573s 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi
573s login #1
573s + echo login #1
573s + iscsiadm --mode node --targetname iqn.2016-11.foo.com:target.iscsi --portal 127.0.0.1:3260 --login
573s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260]
573s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful.
573s + seq 2 4
573s + echo extra login #2
573s + iscsiadm --mode session -r 1 --op new
573s extra login #2
574s + echo extra login #3
574s + iscsiadm --mode session -r 1 --op new
574s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple)
574s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful.
574s extra login #3
574s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple)
574s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful.
574s extra login #4
574s + echo extra login #4
574s + iscsiadm --mode session -r 1 --op new
574s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple)
574s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful.
574s + udevadm settle
574s + sleep 5
579s Status after initial setup
579s + echo Status after initial setup
579s + tgtadm --lld iscsi --mode target --op show
579s + tgtadm --lld iscsi --op show --mode conn --tid 1
579s Target 1: iqn.2016-11.foo.com:target.iscsi
579s     System information:
579s         Driver: iscsi
579s         State: ready
579s     I_T nexus information:
579s         I_T nexus: 1
579s             Initiator: iqn.2004-10.com.ubuntu:01:c95684436565 alias: autopkgtest
579s             Connection: 0
579s                 IP Address: 127.0.0.1
579s         I_T nexus: 2
579s             Initiator: iqn.2004-10.com.ubuntu:01:c95684436565 alias: autopkgtest
579s             Connection: 0
579s                 IP Address: 127.0.0.1
579s         I_T nexus: 3
579s             Initiator: iqn.2004-10.com.ubuntu:01:c95684436565 alias: autopkgtest
579s             Connection: 0
579s                 IP Address: 127.0.0.1
579s         I_T nexus: 4
579s             Initiator: iqn.2004-10.com.ubuntu:01:c95684436565 alias: autopkgtest
579s             Connection: 0
579s                 IP Address: 127.0.0.1
579s     LUN information:
579s         LUN: 0
579s             Type: controller
579s             SCSI ID: IET     00010000
579s             SCSI SN: beaf10
579s             Size: 0 MB, Block size: 1
579s             Online: Yes
579s             Removable media: No
579s             Prevent removal: No
579s             Readonly: No
579s             SWP: No
579s             Thin-provisioning: No
579s             Backing store type: null
579s             Backing store path: None
579s             Backing store flags: 
579s         LUN: 1
579s             Type: disk
579s             SCSI ID: IET     00010001
579s             SCSI SN: beaf11
579s             Size: 105 MB, Block size: 512
579s             Online: Yes
579s             Removable media: No
579s             Prevent removal: No
579s             Readonly: No
579s             SWP: No
579s             Thin-provisioning: No
579s             Backing store type: rdwr
579s             Backing store path: /tmp/autopkgtest.2T29gI/build.oE6/src/backingfile
579s             Backing store flags: 
579s     Account information:
579s     ACL information:
579s         ALL
579s Session: 4
579s     Connection: 0
579s         Initiator: iqn.2004-10.com.ubuntu:01:c95684436565
579s         IP Address: 127.0.0.1
579s Session: 3
579s     Connection: 0
579s         Initiator: iqn.2004-10.com.ubuntu:01:c95684436565
579s         IP Address: 127.0.0.1
579s Session: 2
579s     Connection: 0
579s         Initiator: iqn.2004-10.com.ubuntu:01:c95684436565
579s         IP Address: 127.0.0.1
579s Session: 1
579s     Connection: 0
579s         Initiator: iqn.2004-10.com.ubuntu:01:c95684436565
579s         IP Address: 127.0.0.1
579s + iscsiadm --mode session -P 1
579s Target: iqn.2016-11.foo.com:target.iscsi (non-flash)
579s 	Current Portal: 127.0.0.1:3260,1
579s 	Persistent Portal: 127.0.0.1:3260,1
579s 		**********
579s 		Interface:
579s 		**********
579s 		Iface Name: default
579s 		Iface Transport: tcp
579s 		Iface Initiatorname: iqn.2004-10.com.ubuntu:01:c95684436565
579s 		Iface IPaddress: 127.0.0.1
579s 		Iface HWaddress: default
579s 		Iface Netdev: default
579s 		SID: 1
579s 		iSCSI Connection State: LOGGED IN
579s 		iSCSI Session State: LOGGED_IN
579s 		Internal iscsid Session State: NO CHANGE
579s 
579s 		**********
579s 		Interface:
579s 		**********
579s 		Iface Name: default
579s 		Iface Transport: tcp
579s 		Iface Initiatorname: iqn.2004-10.com.ubuntu:01:c95684436565
579s 		Iface IPaddress: 127.0.0.1
579s 		Iface HWaddress: default
579s 		Iface Netdev: default
579s 		SID: 2
579s 		iSCSI Connection State: LOGGED IN
579s 		iSCSI Session State: LOGGED_IN
579s 		Internal iscsid Session State: NO CHANGE
579s 
579s 		**********
579s 		Interface:
579s 		**********
579s 		Iface Name: default
579s 		Iface Transport: tcp
579s 		Iface Initiatorname: iqn.2004-10.com.ubuntu:01:c95684436565
579s 		Iface IPaddress: 127.0.0.1
579s 		Iface HWaddress: default
579s 		Iface Netdev: default
579s 		SID: 3
579s 		iSCSI Connection State: LOGGED IN
579s 		iSCSI Session State: LOGGED_IN
579s 		Internal iscsid Session State: NO CHANGE
579s 
579s 		**********
579s 		Interface:
579s 		**********
579s 		Iface Name: default
579s 		Iface Transport: tcp
579s 		Iface Initiatorname: iqn.2004-10.com.ubuntu:01:c95684436565
579s 		Iface IPaddress: 127.0.0.1
579s 		Iface HWaddress: default
579s 		Iface Netdev: default
579s 		SID: 4
579s 		iSCSI Connection State: LOGGED IN
579s 		iSCSI Session State: LOGGED_IN
579s 		Internal iscsid Session State: NO CHANGE
579s + lsscsi -liv
579s list_ndevices: scandir: /sys/class/nvme/: No such file or directory
579s + multipath -v3 -ll
579s 55.820648 | set open fds limit to 1073741816/1073741816
579s 55.820752 | loading /lib/multipath/libchecktur.so checker
579s [0:0:0:0]    disk    QEMU     QEMU HARDDISK    2.5+  /dev/sda   0QEMU_QEMU_HARDDISK_drive-scsi0-0-0-0
579s   state=running queue_depth=128 scsi_level=6 type=0 device_blocked=0 timeout=30
579s   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]
579s [1:0:0:0]    storage IET      Controller       0001  -          -
579s   state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30
579s   dir: /sys/bus/scsi/devices/1:0:0:0  [/sys/devices/platform/host1/session1/target1:0:0/1:0:0:0]
579s [1:0:0:1]    disk    IET      VIRTUAL-DISK     0001  /dev/sdb   360000000000000000e00000000010001
579s   state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30
579s   dir: /sys/bus/scsi/devices/1:0:0:1  [/sys/devices/platform/host1/session1/target1:0:0/1:0:0:1]
579s [2:0:0:0]    storage IET      Controller       0001  -          -
579s   state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30
579s   dir: /sys/bus/scsi/devices/2:0:0:0  [/sys/devices/platform/host2/session2/target2:0:0/2:0:0:0]
579s [2:0:0:1]    disk    IET      VIRTUAL-DISK     0001  /dev/sdc   360000000000000000e00000000010001
579s   state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30
579s   dir: /sys/bus/scsi/devices/2:0:0:1  [/sys/devices/platform/host2/session2/target2:0:0/2:0:0:1]
579s [3:0:0:0]    storage IET      Controller       0001  -          -
579s   state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30
579s   dir: /sys/bus/scsi/devices/3:0:0:0  [/sys/devices/platform/host3/session3/target3:0:0/3:0:0:0]
579s [3:0:0:1]    disk    IET      VIRTUAL-DISK     0001  /dev/sdd   33000000100000001
579s   state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30
579s   dir: /sys/bus/scsi/devices/3:0:0:1  [/sys/devices/platform/host3/session3/target3:0:0/3:0:0:1]
579s [4:0:0:0]    storage IET      Controller       0001  -          -
579s   state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30
579s   dir: /sys/bus/scsi/devices/4:0:0:0  [/sys/devices/platform/host4/session4/target4:0:0/4:0:0:0]
579s [4:0:0:1]    disk    IET      VIRTUAL-DISK     0001  /dev/sde   360000000000000000e00000000010001
579s   state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30
579s   dir: /sys/bus/scsi/devices/4:0:0:1  [/sys/devices/platform/host4/session4/target4:0:0/4:0:0:1]
579s NVMe module may not be loaded
579s 55.820847 | checker tur: message table size = 3
579s 55.820879 | loading /lib/multipath/libprioconst.so prioritizer
579s 55.821010 | _init_foreign: foreign library "nvme" is not enabled
579s 55.827265 | sda: size = 167772160
579s 55.827508 | sda: vendor = QEMU
579s 55.827556 | sda: product = QEMU HARDDISK
579s 55.827581 | sda: rev = 2.5+
579s 55.828330 | sda: h:b:t:l = 0:0:0:0
579s 55.828696 | sda: tgt_node_name = 
579s 55.828722 | sda: uid_attribute = ID_SERIAL (setting: multipath internal)
579s 55.828725 | sda: recheck_wwid = 1 (setting: multipath.conf defaults/devices section)
579s 55.828897 | sda: 10443 cyl, 255 heads, 63 sectors/track, start at 0
579s 55.828921 | sda: vpd_vendor_id = 0 "undef" (setting: multipath internal)
579s 55.828936 | __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
579s 55.828941 | failed to read sysfs vpd pg80: No such file or directory
579s 55.829211 | sda: fail to get serial
579s 55.829237 | sda: detect_checker = yes (setting: multipath internal)
579s 55.830282 | sda: path_checker = tur (setting: multipath internal)
579s 55.830308 | sda: checker timeout = 30 s (setting: kernel sysfs)
579s 55.830532 | sda: tur state = up
579s 55.830881 | sdb: size = 204800
579s 55.831050 | sdb: vendor = IET
579s 55.831097 | sdb: product = VIRTUAL-DISK
579s 55.831121 | sdb: rev = 0001
579s 55.831815 | sdb: h:b:t:l = 1:0:0:1
579s 55.832251 | sdb: tgt_node_name = iqn.2016-11.foo.com:target.iscsi
579s 55.832281 | sdb: uid_attribute = ID_SERIAL (setting: multipath internal)
579s 55.832283 | sdb: recheck_wwid = 1 (setting: multipath.conf defaults/devices section)
579s 55.832460 | sdb: 1024 cyl, 4 heads, 50 sectors/track, start at 0
579s 55.832484 | sdb: vpd_vendor_id = 0 "undef" (setting: multipath internal)
579s 55.832506 | sdb: serial = beaf11
579s 55.832509 | sdb: detect_checker = yes (setting: multipath internal)
579s 55.833663 | sdb: path_checker = tur (setting: multipath internal)
579s 55.833688 | sdb: checker timeout = 30 s (setting: kernel sysfs)
579s 55.833968 | sdb: tur state = up
579s 55.834131 | sdc: size = 204800
579s 55.834298 | sdc: vendor = IET
579s 55.834343 | sdc: product = VIRTUAL-DISK
579s 55.834368 | sdc: rev = 0001
579s 55.835122 | sdc: h:b:t:l = 2:0:0:1
579s 55.835525 | sdc: tgt_node_name = iqn.2016-11.foo.com:target.iscsi
579s 55.835548 | sdc: uid_attribute = ID_SERIAL (setting: multipath internal)
579s 55.835551 | sdc: recheck_wwid = 1 (setting: multipath.conf defaults/devices section)
579s 55.835719 | sdc: 1024 cyl, 4 heads, 50 sectors/track, start at 0
579s 55.835742 | sdc: vpd_vendor_id = 0 "undef" (setting: multipath internal)
579s 55.835758 | sdc: serial = beaf11
579s 55.835761 | sdc: detect_checker = yes (setting: multipath internal)
579s 55.836853 | sdc: path_checker = tur (setting: multipath internal)
579s 55.836885 | sdc: checker timeout = 30 s (setting: kernel sysfs)
579s 55.837172 | sdc: tur state = up
579s 55.837337 | sdd: size = 204800
579s 55.837506 | sdd: vendor = IET
579s 55.837551 | sdd: product = VIRTUAL-DISK
579s 55.837575 | sdd: rev = 0001
579s 55.838330 | sdd: h:b:t:l = 3:0:0:1
579s 55.838732 | sdd: tgt_node_name = iqn.2016-11.foo.com:target.iscsi
579s 55.838756 | sdd: uid_attribute = ID_SERIAL (setting: multipath internal)
579s 55.838759 | sdd: recheck_wwid = 1 (setting: multipath.conf defaults/devices section)
579s 55.838922 | sdd: 1024 cyl, 4 heads, 50 sectors/track, start at 0
579s 55.838946 | sdd: vpd_vendor_id = 0 "undef" (setting: multipath internal)
579s 55.838962 | sdd: serial = beaf11
579s 55.838965 | sdd: detect_checker = yes (setting: multipath internal)
579s 55.839306 | sdd: path_checker = tur (setting: multipath internal)
579s 55.839331 | sdd: checker timeout = 30 s (setting: kernel sysfs)
579s 55.839595 | sdd: tur state = up
579s 55.839759 | sde: size = 204800
579s 55.839928 | sde: vendor = IET
579s 55.839975 | sde: product = VIRTUAL-DISK
579s 55.840029 | sde: rev = 0001
579s 55.840801 | sde: h:b:t:l = 4:0:0:1
579s 55.841204 | sde: tgt_node_name = iqn.2016-11.foo.com:target.iscsi
579s 55.841229 | sde: uid_attribute = ID_SERIAL (setting: multipath internal)
579s 55.841232 | sde: recheck_wwid = 1 (setting: multipath.conf defaults/devices section)
579s 55.841407 | sde: 1024 cyl, 4 heads, 50 sectors/track, start at 0
579s 55.841431 | sde: vpd_vendor_id = 0 "undef" (setting: multipath internal)
579s 55.841447 | sde: serial = beaf11
579s 55.841450 | sde: detect_checker = yes (setting: multipath internal)
579s 55.841772 | sde: path_checker = tur (setting: multipath internal)
579s 55.841797 | sde: checker timeout = 30 s (setting: kernel sysfs)
579s 55.842059 | sde: tur state = up
579s 55.842183 | loop0: device node name blacklisted
579s 55.842300 | loop1: device node name blacklisted
579s 55.842415 | loop2: device node name blacklisted
579s 55.842529 | loop3: device node name blacklisted
579s 55.842643 | loop4: device node name blacklisted
579s 55.842756 | loop5: device node name blacklisted
579s 55.842868 | loop6: device node name blacklisted
579s 55.842980 | loop7: device node name blacklisted
579s 55.843103 | dm-0: device node name blacklisted
579s ===== paths list =====
579s uuid hcil    dev dev_t pri dm_st chk_st vend/prod/rev      dev_st 
579s      0:0:0:0 sda 8:0   -1  undef undef  QEMU,QEMU HARDDISK unknown
579s      1:0:0:1 sdb 8:16  -1  undef undef  IET,VIRTUAL-DISK   unknown
579s      2:0:0:1 sdc 8:32  -1  undef undef  IET,VIRTUAL-DISK   unknown
579s      3:0:0:1 sdd 8:48  -1  undef undef  IET,VIRTUAL-DISK   unknown
579s      4:0:0:1 sde 8:64  -1  undef undef  IET,VIRTUAL-DISK   unknown
579s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK
579s size=100M features='0' hwhandler='0' wp=rw
579s |-+- policy='service-time 0' prio=1 status=active
579s | `- 1:0:0:1 sdb 8:16 active ready running
579s |-+- policy='service-time 0' prio=1 status=enabled
579s | `- 2:0:0:1 sdc 8:32 active ready running
579s |-+- policy='service-time 0' prio=1 status=enabled
579s | `- 3:0:0:1 sdd 8:48 active ready running
579s `-+- policy='service-time 0' prio=1 status=enabled
579s   `- 4:0:0:1 sde 8:64 active ready running
579s 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 
579s Test WWN should now point to DM
579s 55.844250 | multipath-tools v0.9.4 (12/19, 2022)
579s 55.844286 | libdevmapper version 1.02.196
579s 55.844444 | kernel device mapper v4.48.0
579s 55.844479 | DM multipath kernel driver v1.14.0
579s 55.844605 | sdb: size = 204800
579s 55.844630 | sdb: vendor = IET
579s 55.844633 | sdb: product = VIRTUAL-DISK
579s 55.844636 | sdb: rev = 0001
579s 55.845325 | sdb: h:b:t:l = 1:0:0:1
579s 55.845472 | sdb: tgt_node_name = iqn.2016-11.foo.com:target.iscsi
579s 55.845513 | sdb: 1024 cyl, 4 heads, 50 sectors/track, start at 0
579s 55.845516 | sdb: vpd_vendor_id = 0 "undef" (setting: multipath internal)
579s 55.845530 | sdb: serial = beaf11
579s 55.845807 | sdb: tur state = up
579s 55.845831 | sdb: uid = 360000000000000000e00000000010001 (udev)
579s 55.845835 | sdb: detect_prio = yes (setting: multipath internal)
579s 55.845839 | sdb: prio = const (setting: multipath internal)
579s 55.845841 | sdb: prio args = "" (setting: multipath internal)
579s 55.845844 | sdb: const prio = 1
579s 55.845870 | sdc: size = 204800
579s 55.845874 | sdc: vendor = IET
579s 55.845877 | sdc: product = VIRTUAL-DISK
579s 55.845882 | sdc: rev = 0001
579s 55.846560 | sdc: h:b:t:l = 2:0:0:1
579s 55.846704 | sdc: tgt_node_name = iqn.2016-11.foo.com:target.iscsi
579s 55.846746 | sdc: 1024 cyl, 4 heads, 50 sectors/track, start at 0
579s 55.846749 | sdc: vpd_vendor_id = 0 "undef" (setting: multipath internal)
579s 55.846762 | sdc: serial = beaf11
579s 55.847019 | sdc: tur state = up
579s 55.847043 | sdc: uid = 360000000000000000e00000000010001 (udev)
579s 55.847046 | sdc: detect_prio = yes (setting: multipath internal)
579s 55.847048 | sdc: prio = const (setting: multipath internal)
579s 55.847050 | sdc: prio args = "" (setting: multipath internal)
579s 55.847053 | sdc: const prio = 1
579s 55.847079 | sdd: size = 204800
579s 55.847083 | sdd: vendor = IET
579s 55.847086 | sdd: product = VIRTUAL-DISK
579s 55.847088 | sdd: rev = 0001
579s 55.847763 | sdd: h:b:t:l = 3:0:0:1
579s 55.847907 | sdd: tgt_node_name = iqn.2016-11.foo.com:target.iscsi
579s 55.847948 | sdd: 1024 cyl, 4 heads, 50 sectors/track, start at 0
579s 55.847952 | sdd: vpd_vendor_id = 0 "undef" (setting: multipath internal)
579s 55.847964 | sdd: serial = beaf11
579s 55.848235 | sdd: tur state = up
579s 55.848264 | sdd: uid = 360000000000000000e00000000010001 (udev)
579s 55.848267 | sdd: detect_prio = yes (setting: multipath internal)
579s 55.848270 | sdd: prio = const (setting: multipath internal)
579s 55.848272 | sdd: prio args = "" (setting: multipath internal)
579s 55.848275 | sdd: const prio = 1
579s 55.848300 | sde: size = 204800
579s 55.848304 | sde: vendor = IET
579s 55.848307 | sde: product = VIRTUAL-DISK
579s 55.848311 | sde: rev = 0001
579s 55.848983 | sde: h:b:t:l = 4:0:0:1
579s 55.849128 | sde: tgt_node_name = iqn.2016-11.foo.com:target.iscsi
579s 55.849169 | sde: 1024 cyl, 4 heads, 50 sectors/track, start at 0
579s 55.849172 | sde: vpd_vendor_id = 0 "undef" (setting: multipath internal)
579s 55.849185 | sde: serial = beaf11
579s 55.849442 | sde: tur state = up
579s 55.849466 | sde: uid = 360000000000000000e00000000010001 (udev)
579s 55.849469 | sde: detect_prio = yes (setting: multipath internal)
579s 55.849472 | sde: prio = const (setting: multipath internal)
579s 55.849474 | sde: prio args = "" (setting: multipath internal)
579s 55.849476 | sde: const prio = 1
579s 55.850455 | unloading tur checker
579s 55.850513 | unloading const prioritizer
579s + dmsetup table
579s + echo Test WWN should now point to DM
579s + readlink /dev/disk/by-id/wwn-0x60000000000000000e00000000010001
579s + grep dm
579s autopkgtest [00:22:42]: test tgtbasedmpaths: -----------------------]
580s autopkgtest [00:22:43]: test tgtbasedmpaths:  - - - - - - - - - - results - - - - - - - - - -
580s tgtbasedmpaths       FAIL non-zero exit status 1
580s autopkgtest [00:22:43]: @@@@@@@@@@@@@@@@@@@@ summary
580s kpartx-file-loopback PASS
580s tgtbasedmpaths       FAIL non-zero exit status 1
592s nova [W] Using flock in scalingstack-bos02-ppc64el
592s Creating nova instance adt-oracular-ppc64el-multipath-tools-20240722-001302-juju-7f2275-prod-proposed-migration-environment-2-56140ac4-6a17-4aa8-8724-4b9b08374a2f from image adt/ubuntu-oracular-ppc64el-server-20240721.img (UUID bca807b7-7ac5-4e24-89c8-36614d402191)...
592s nova [W] Using flock in scalingstack-bos02-ppc64el
592s Creating nova instance adt-oracular-ppc64el-multipath-tools-20240722-001302-juju-7f2275-prod-proposed-migration-environment-2-56140ac4-6a17-4aa8-8724-4b9b08374a2f from image adt/ubuntu-oracular-ppc64el-server-20240721.img (UUID bca807b7-7ac5-4e24-89c8-36614d402191)...