0s autopkgtest [04:54:32]: starting date and time: 2024-04-20 04:54:32+0000 0s autopkgtest [04:54:32]: git checkout: 43bc6cdf gitlab-ci: do not include the salsa pipeline 0s autopkgtest [04:54:32]: host juju-7f2275-prod-proposed-migration-environment-3; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.r2ls0rva/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:qemu,src:ceph,src:liburing --apt-upgrade multipath-tools --timeout-short=300 --timeout-copy=20000 --timeout-test=20000 --timeout-build=20000 '--env=ADT_TEST_TRIGGERS=qemu/1:8.2.2+ds-0ubuntu2 ceph/19.2.0~git20240301.4c76c50-0ubuntu6 liburing/2.5-1ubuntu3' -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest-big --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-3@bos02-ppc64el-10.secgroup --name adt-noble-ppc64el-multipath-tools-20240420-045432-juju-7f2275-prod-proposed-migration-environment-3-55b286b2-febc-4433-9450-972889da9387 --image adt/ubuntu-noble-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,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com'"'"'' --mirror=http://ftpmaster.internal/ubuntu/ 84s autopkgtest [04:55:56]: testbed dpkg architecture: ppc64el 84s autopkgtest [04:55:56]: testbed apt version: 2.7.14build2 84s autopkgtest [04:55:56]: @@@@@@@@@@@@@@@@@@@@ test bed setup 85s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [117 kB] 86s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [1964 B] 86s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [267 kB] 86s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [36.1 kB] 86s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/multiverse Sources [2340 B] 86s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el Packages [63.4 kB] 86s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el c-n-f Metadata [3116 B] 86s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/restricted ppc64el c-n-f Metadata [116 B] 86s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/universe ppc64el Packages [202 kB] 86s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/universe ppc64el c-n-f Metadata [8652 B] 86s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/multiverse ppc64el Packages [1376 B] 86s Get:12 http://ftpmaster.internal/ubuntu noble-proposed/multiverse ppc64el c-n-f Metadata [116 B] 88s Fetched 703 kB in 1s (875 kB/s) 88s Reading package lists... 89s sh: 4: dhclient: not found 90s Reading package lists... 90s Building dependency tree... 90s Reading state information... 90s Calculating upgrade... 90s The following NEW packages will be installed: 90s libtraceevent1 libtraceevent1-plugin libtracefs1 linux-headers-6.8.0-28 90s linux-headers-6.8.0-28-generic linux-image-6.8.0-28-generic 90s linux-modules-6.8.0-28-generic linux-modules-extra-6.8.0-28-generic 90s linux-tools-6.8.0-28 linux-tools-6.8.0-28-generic trace-cmd 90s The following packages will be upgraded: 90s distro-info linux-generic linux-headers-generic linux-headers-virtual 90s linux-image-generic linux-image-virtual linux-libc-dev linux-tools-common 90s linux-virtual ubuntu-kernel-accessories ubuntu-minimal ubuntu-standard 90s 12 upgraded, 11 newly installed, 0 to remove and 0 not upgraded. 90s Need to get 221 MB of archives. 90s After this operation, 322 MB of additional disk space will be used. 90s Get:1 http://ftpmaster.internal/ubuntu noble/main ppc64el distro-info ppc64el 1.7build1 [20.1 kB] 91s Get:2 http://ftpmaster.internal/ubuntu noble/main ppc64el ubuntu-minimal ppc64el 1.539 [11.0 kB] 91s Get:3 http://ftpmaster.internal/ubuntu noble/main ppc64el ubuntu-standard ppc64el 1.539 [11.0 kB] 91s Get:4 http://ftpmaster.internal/ubuntu noble/main ppc64el libtraceevent1 ppc64el 1:1.8.2-1ubuntu2 [56.4 kB] 91s Get:5 http://ftpmaster.internal/ubuntu noble/main ppc64el libtraceevent1-plugin ppc64el 1:1.8.2-1ubuntu2 [20.3 kB] 91s Get:6 http://ftpmaster.internal/ubuntu noble/main ppc64el libtracefs1 ppc64el 1.8.0-1ubuntu1 [86.1 kB] 91s Get:7 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-modules-6.8.0-28-generic ppc64el 6.8.0-28.28 [31.3 MB] 92s Get:8 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-image-6.8.0-28-generic ppc64el 6.8.0-28.28 [63.9 MB] 94s Get:9 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-modules-extra-6.8.0-28-generic ppc64el 6.8.0-28.28 [103 MB] 96s Get:10 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-generic ppc64el 6.8.0-28.28 [1736 B] 96s Get:11 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-image-generic ppc64el 6.8.0-28.28 [9870 B] 96s Get:12 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-virtual ppc64el 6.8.0-28.28 [1684 B] 96s Get:13 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-image-virtual ppc64el 6.8.0-28.28 [9874 B] 96s Get:14 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-headers-virtual ppc64el 6.8.0-28.28 [1650 B] 96s Get:15 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-headers-6.8.0-28 all 6.8.0-28.28 [13.6 MB] 97s Get:16 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-headers-6.8.0-28-generic ppc64el 6.8.0-28.28 [3732 kB] 97s Get:17 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-headers-generic ppc64el 6.8.0-28.28 [9788 B] 97s Get:18 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-libc-dev ppc64el 6.8.0-28.28 [1587 kB] 97s Get:19 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-tools-common all 6.8.0-28.28 [439 kB] 97s Get:20 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-tools-6.8.0-28 ppc64el 6.8.0-28.28 [2927 kB] 97s Get:21 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-tools-6.8.0-28-generic ppc64el 6.8.0-28.28 [1726 B] 97s Get:22 http://ftpmaster.internal/ubuntu noble/main ppc64el trace-cmd ppc64el 3.2-1ubuntu2 [400 kB] 97s Get:23 http://ftpmaster.internal/ubuntu noble/main ppc64el ubuntu-kernel-accessories ppc64el 1.539 [10.8 kB] 97s Fetched 221 MB in 7s (33.2 MB/s) 97s (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 ... 72009 files and directories currently installed.) 97s Preparing to unpack .../00-distro-info_1.7build1_ppc64el.deb ... 97s Unpacking distro-info (1.7build1) over (1.7) ... 97s Preparing to unpack .../01-ubuntu-minimal_1.539_ppc64el.deb ... 97s Unpacking ubuntu-minimal (1.539) over (1.538build1) ... 97s Preparing to unpack .../02-ubuntu-standard_1.539_ppc64el.deb ... 97s Unpacking ubuntu-standard (1.539) over (1.538build1) ... 97s Selecting previously unselected package libtraceevent1:ppc64el. 97s Preparing to unpack .../03-libtraceevent1_1%3a1.8.2-1ubuntu2_ppc64el.deb ... 97s Unpacking libtraceevent1:ppc64el (1:1.8.2-1ubuntu2) ... 97s Selecting previously unselected package libtraceevent1-plugin:ppc64el. 97s Preparing to unpack .../04-libtraceevent1-plugin_1%3a1.8.2-1ubuntu2_ppc64el.deb ... 97s Unpacking libtraceevent1-plugin:ppc64el (1:1.8.2-1ubuntu2) ... 97s Selecting previously unselected package libtracefs1:ppc64el. 97s Preparing to unpack .../05-libtracefs1_1.8.0-1ubuntu1_ppc64el.deb ... 97s Unpacking libtracefs1:ppc64el (1.8.0-1ubuntu1) ... 97s Selecting previously unselected package linux-modules-6.8.0-28-generic. 97s Preparing to unpack .../06-linux-modules-6.8.0-28-generic_6.8.0-28.28_ppc64el.deb ... 97s Unpacking linux-modules-6.8.0-28-generic (6.8.0-28.28) ... 98s Selecting previously unselected package linux-image-6.8.0-28-generic. 98s Preparing to unpack .../07-linux-image-6.8.0-28-generic_6.8.0-28.28_ppc64el.deb ... 98s Unpacking linux-image-6.8.0-28-generic (6.8.0-28.28) ... 98s Selecting previously unselected package linux-modules-extra-6.8.0-28-generic. 98s Preparing to unpack .../08-linux-modules-extra-6.8.0-28-generic_6.8.0-28.28_ppc64el.deb ... 98s Unpacking linux-modules-extra-6.8.0-28-generic (6.8.0-28.28) ... 99s Preparing to unpack .../09-linux-generic_6.8.0-28.28_ppc64el.deb ... 99s Unpacking linux-generic (6.8.0-28.28) over (6.8.0-22.22) ... 99s Preparing to unpack .../10-linux-image-generic_6.8.0-28.28_ppc64el.deb ... 99s Unpacking linux-image-generic (6.8.0-28.28) over (6.8.0-22.22) ... 99s Preparing to unpack .../11-linux-virtual_6.8.0-28.28_ppc64el.deb ... 99s Unpacking linux-virtual (6.8.0-28.28) over (6.8.0-22.22) ... 99s Preparing to unpack .../12-linux-image-virtual_6.8.0-28.28_ppc64el.deb ... 99s Unpacking linux-image-virtual (6.8.0-28.28) over (6.8.0-22.22) ... 99s Preparing to unpack .../13-linux-headers-virtual_6.8.0-28.28_ppc64el.deb ... 99s Unpacking linux-headers-virtual (6.8.0-28.28) over (6.8.0-22.22) ... 99s Selecting previously unselected package linux-headers-6.8.0-28. 99s Preparing to unpack .../14-linux-headers-6.8.0-28_6.8.0-28.28_all.deb ... 99s Unpacking linux-headers-6.8.0-28 (6.8.0-28.28) ... 102s Selecting previously unselected package linux-headers-6.8.0-28-generic. 102s Preparing to unpack .../15-linux-headers-6.8.0-28-generic_6.8.0-28.28_ppc64el.deb ... 102s Unpacking linux-headers-6.8.0-28-generic (6.8.0-28.28) ... 103s Preparing to unpack .../16-linux-headers-generic_6.8.0-28.28_ppc64el.deb ... 103s Unpacking linux-headers-generic (6.8.0-28.28) over (6.8.0-22.22) ... 103s Preparing to unpack .../17-linux-libc-dev_6.8.0-28.28_ppc64el.deb ... 103s Unpacking linux-libc-dev:ppc64el (6.8.0-28.28) over (6.8.0-22.22) ... 103s Preparing to unpack .../18-linux-tools-common_6.8.0-28.28_all.deb ... 103s Unpacking linux-tools-common (6.8.0-28.28) over (6.8.0-22.22) ... 103s Selecting previously unselected package linux-tools-6.8.0-28. 103s Preparing to unpack .../19-linux-tools-6.8.0-28_6.8.0-28.28_ppc64el.deb ... 103s Unpacking linux-tools-6.8.0-28 (6.8.0-28.28) ... 103s Selecting previously unselected package linux-tools-6.8.0-28-generic. 103s Preparing to unpack .../20-linux-tools-6.8.0-28-generic_6.8.0-28.28_ppc64el.deb ... 103s Unpacking linux-tools-6.8.0-28-generic (6.8.0-28.28) ... 103s Selecting previously unselected package trace-cmd. 103s Preparing to unpack .../21-trace-cmd_3.2-1ubuntu2_ppc64el.deb ... 103s Unpacking trace-cmd (3.2-1ubuntu2) ... 103s Preparing to unpack .../22-ubuntu-kernel-accessories_1.539_ppc64el.deb ... 103s Unpacking ubuntu-kernel-accessories (1.539) over (1.538build1) ... 103s Setting up distro-info (1.7build1) ... 103s Setting up ubuntu-kernel-accessories (1.539) ... 103s Setting up ubuntu-minimal (1.539) ... 103s Setting up linux-libc-dev:ppc64el (6.8.0-28.28) ... 103s Setting up ubuntu-standard (1.539) ... 103s Setting up linux-modules-6.8.0-28-generic (6.8.0-28.28) ... 105s Setting up linux-headers-6.8.0-28 (6.8.0-28.28) ... 105s Setting up libtraceevent1:ppc64el (1:1.8.2-1ubuntu2) ... 105s Setting up linux-modules-extra-6.8.0-28-generic (6.8.0-28.28) ... 107s Setting up linux-tools-common (6.8.0-28.28) ... 107s Setting up linux-image-6.8.0-28-generic (6.8.0-28.28) ... 109s I: /boot/vmlinux is now a symlink to vmlinux-6.8.0-28-generic 109s I: /boot/initrd.img is now a symlink to initrd.img-6.8.0-28-generic 109s Setting up linux-headers-6.8.0-28-generic (6.8.0-28.28) ... 109s Setting up libtracefs1:ppc64el (1.8.0-1ubuntu1) ... 109s Setting up libtraceevent1-plugin:ppc64el (1:1.8.2-1ubuntu2) ... 109s Setting up linux-tools-6.8.0-28 (6.8.0-28.28) ... 109s Setting up linux-image-virtual (6.8.0-28.28) ... 109s Setting up linux-tools-6.8.0-28-generic (6.8.0-28.28) ... 109s Setting up linux-image-generic (6.8.0-28.28) ... 109s Setting up trace-cmd (3.2-1ubuntu2) ... 109s Setting up linux-headers-generic (6.8.0-28.28) ... 109s Setting up linux-headers-virtual (6.8.0-28.28) ... 109s Setting up linux-generic (6.8.0-28.28) ... 109s Setting up linux-virtual (6.8.0-28.28) ... 109s Processing triggers for man-db (2.12.0-4build2) ... 110s Processing triggers for libc-bin (2.39-0ubuntu8) ... 110s Processing triggers for linux-image-6.8.0-28-generic (6.8.0-28.28) ... 110s /etc/kernel/postinst.d/initramfs-tools: 110s update-initramfs: Generating /boot/initrd.img-6.8.0-28-generic 110s W: No lz4 in /usr/bin:/sbin:/bin, using gzip 116s /etc/kernel/postinst.d/zz-update-grub: 116s Sourcing file `/etc/default/grub' 116s Sourcing file `/etc/default/grub.d/50-cloudimg-settings.cfg' 116s Generating grub configuration file ... 116s Found linux image: /boot/vmlinux-6.8.0-28-generic 116s Found initrd image: /boot/initrd.img-6.8.0-28-generic 116s Found linux image: /boot/vmlinux-6.8.0-22-generic 116s Found initrd image: /boot/initrd.img-6.8.0-22-generic 116s Warning: os-prober will not be executed to detect other bootable partitions. 116s Systems on them will not be added to the GRUB boot configuration. 116s Check GRUB_DISABLE_OS_PROBER documentation entry. 116s Adding boot menu entry for UEFI Firmware Settings ... 117s done 117s Reading package lists... 117s Building dependency tree... 117s Reading state information... 117s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 117s Hit:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease 117s Hit:2 http://ftpmaster.internal/ubuntu noble InRelease 117s Hit:3 http://ftpmaster.internal/ubuntu noble-updates InRelease 118s Hit:4 http://ftpmaster.internal/ubuntu noble-security InRelease 118s Reading package lists... 118s Reading package lists... 119s Building dependency tree... 119s Reading state information... 119s Calculating upgrade... 119s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 119s Reading package lists... 119s Building dependency tree... 119s Reading state information... 119s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 120s autopkgtest [04:56:32]: rebooting testbed after setup commands that affected boot 158s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 166s autopkgtest [04:57:18]: testbed running kernel: Linux 6.8.0-28-generic #28-Ubuntu SMP Tue Apr 16 19:02:21 UTC 2024 169s autopkgtest [04:57:21]: @@@@@@@@@@@@@@@@@@@@ apt-source multipath-tools 172s Get:1 http://ftpmaster.internal/ubuntu noble/main multipath-tools 0.9.4-5ubuntu8 (dsc) [2770 B] 172s Get:2 http://ftpmaster.internal/ubuntu noble/main multipath-tools 0.9.4-5ubuntu8 (tar) [554 kB] 172s Get:3 http://ftpmaster.internal/ubuntu noble/main multipath-tools 0.9.4-5ubuntu8 (diff) [42.7 kB] 172s gpgv: Signature made Sun Apr 7 00:31:08 2024 UTC 172s gpgv: using RSA key AC483F68DE728F43F2202FCA568D30F321B2133D 172s gpgv: issuer "steve.langasek@ubuntu.com" 172s gpgv: Can't check signature: No public key 172s dpkg-source: warning: cannot verify inline signature for ./multipath-tools_0.9.4-5ubuntu8.dsc: no acceptable signature found 172s autopkgtest [04:57:24]: testing package multipath-tools version 0.9.4-5ubuntu8 173s autopkgtest [04:57:25]: build not needed 173s autopkgtest [04:57:25]: test kpartx-file-loopback: preparing testbed 174s Reading package lists... 174s Building dependency tree... 174s Reading state information... 174s Starting pkgProblemResolver with broken count: 0 175s Starting 2 pkgProblemResolver with broken count: 0 175s Done 175s The following additional packages will be installed: 175s liburing2t64 qemu-utils 175s Recommended packages: 175s qemu-block-extra 175s The following NEW packages will be installed: 175s autopkgtest-satdep liburing2t64 qemu-utils 175s 0 upgraded, 3 newly installed, 0 to remove and 0 not upgraded. 175s Need to get 2330 kB/2330 kB of archives. 175s After this operation, 15.4 MB of additional disk space will be used. 175s Get:1 /tmp/autopkgtest.uQ2WGA/1-autopkgtest-satdep.deb autopkgtest-satdep ppc64el 0 [720 B] 175s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el liburing2t64 ppc64el 2.5-1ubuntu3 [26.3 kB] 175s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el qemu-utils ppc64el 1:8.2.2+ds-0ubuntu2 [2303 kB] 176s Fetched 2330 kB in 1s (1738 kB/s) 176s Selecting previously unselected package liburing2t64:ppc64el. 177s (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 ... 108886 files and directories currently installed.) 177s Preparing to unpack .../liburing2t64_2.5-1ubuntu3_ppc64el.deb ... 177s Unpacking liburing2t64:ppc64el (2.5-1ubuntu3) ... 177s Selecting previously unselected package qemu-utils. 177s Preparing to unpack .../qemu-utils_1%3a8.2.2+ds-0ubuntu2_ppc64el.deb ... 177s Unpacking qemu-utils (1:8.2.2+ds-0ubuntu2) ... 177s Selecting previously unselected package autopkgtest-satdep. 177s Preparing to unpack .../1-autopkgtest-satdep.deb ... 177s Unpacking autopkgtest-satdep (0) ... 177s Setting up liburing2t64:ppc64el (2.5-1ubuntu3) ... 177s Setting up qemu-utils (1:8.2.2+ds-0ubuntu2) ... 177s Setting up autopkgtest-satdep (0) ... 177s Processing triggers for man-db (2.12.0-4build2) ... 178s Processing triggers for libc-bin (2.39-0ubuntu8) ... 180s (Reading database ... 108907 files and directories currently installed.) 180s Removing autopkgtest-satdep (0) ... 180s autopkgtest [04:57:32]: test kpartx-file-loopback: [----------------------- 180s Formatting 'foo.img', fmt=raw size=20971520 181s Creating new GPT entries in memory. 181s Warning: The kernel is still using the old partition table. 181s The new table will be used at the next reboot or after you 181s run partprobe(8) or kpartx(8) 181s The operation has completed successfully. 182s add map loop0p1 (252:0): 0 38879 linear 7:0 2048 182s standard_filename: OK 182s del devmap : loop0p1 182s No devices found 182s standard_filename_cleanup: OK 182s Formatting 'fou du FaFa.img', fmt=raw size=20971520 183s Creating new GPT entries in memory. 183s Warning: The kernel is still using the old partition table. 183s The new table will be used at the next reboot or after you 183s run partprobe(8) or kpartx(8) 183s The operation has completed successfully. 183s add map loop0p1 (252:0): 0 38879 linear 7:0 2048 183s filename_with_spaces: OK 183s del devmap : loop0p1 183s No devices found 183s filename_with_spaces_cleanup: OK 183s autopkgtest [04:57:35]: test kpartx-file-loopback: -----------------------] 183s kpartx-file-loopback PASS 183s autopkgtest [04:57:35]: test kpartx-file-loopback: - - - - - - - - - - results - - - - - - - - - - 184s autopkgtest [04:57:36]: test tgtbasedmpaths: preparing testbed 338s autopkgtest [05:00:10]: testbed dpkg architecture: ppc64el 338s autopkgtest [05:00:10]: testbed apt version: 2.7.14build2 338s autopkgtest [05:00:10]: @@@@@@@@@@@@@@@@@@@@ test bed setup 339s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [117 kB] 339s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [1964 B] 339s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [36.1 kB] 339s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/multiverse Sources [2340 B] 339s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [267 kB] 340s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el Packages [63.4 kB] 340s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el c-n-f Metadata [3116 B] 340s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/restricted ppc64el c-n-f Metadata [116 B] 340s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/universe ppc64el Packages [202 kB] 340s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/universe ppc64el c-n-f Metadata [8652 B] 340s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/multiverse ppc64el Packages [1376 B] 340s Get:12 http://ftpmaster.internal/ubuntu noble-proposed/multiverse ppc64el c-n-f Metadata [116 B] 341s Fetched 703 kB in 1s (820 kB/s) 341s Reading package lists... 343s sh: 4: dhclient: not found 344s Reading package lists... 344s Building dependency tree... 344s Reading state information... 344s Calculating upgrade... 344s The following NEW packages will be installed: 344s libtraceevent1 libtraceevent1-plugin libtracefs1 linux-headers-6.8.0-28 344s linux-headers-6.8.0-28-generic linux-image-6.8.0-28-generic 344s linux-modules-6.8.0-28-generic linux-modules-extra-6.8.0-28-generic 344s linux-tools-6.8.0-28 linux-tools-6.8.0-28-generic trace-cmd 344s The following packages will be upgraded: 344s distro-info linux-generic linux-headers-generic linux-headers-virtual 344s linux-image-generic linux-image-virtual linux-libc-dev linux-tools-common 344s linux-virtual ubuntu-kernel-accessories ubuntu-minimal ubuntu-standard 344s 12 upgraded, 11 newly installed, 0 to remove and 0 not upgraded. 344s Need to get 221 MB of archives. 344s After this operation, 322 MB of additional disk space will be used. 344s Get:1 http://ftpmaster.internal/ubuntu noble/main ppc64el distro-info ppc64el 1.7build1 [20.1 kB] 344s Get:2 http://ftpmaster.internal/ubuntu noble/main ppc64el ubuntu-minimal ppc64el 1.539 [11.0 kB] 344s Get:3 http://ftpmaster.internal/ubuntu noble/main ppc64el ubuntu-standard ppc64el 1.539 [11.0 kB] 344s Get:4 http://ftpmaster.internal/ubuntu noble/main ppc64el libtraceevent1 ppc64el 1:1.8.2-1ubuntu2 [56.4 kB] 344s Get:5 http://ftpmaster.internal/ubuntu noble/main ppc64el libtraceevent1-plugin ppc64el 1:1.8.2-1ubuntu2 [20.3 kB] 345s Get:6 http://ftpmaster.internal/ubuntu noble/main ppc64el libtracefs1 ppc64el 1.8.0-1ubuntu1 [86.1 kB] 345s Get:7 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-modules-6.8.0-28-generic ppc64el 6.8.0-28.28 [31.3 MB] 346s Get:8 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-image-6.8.0-28-generic ppc64el 6.8.0-28.28 [63.9 MB] 348s Get:9 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-modules-extra-6.8.0-28-generic ppc64el 6.8.0-28.28 [103 MB] 352s Get:10 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-generic ppc64el 6.8.0-28.28 [1736 B] 352s Get:11 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-image-generic ppc64el 6.8.0-28.28 [9870 B] 352s Get:12 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-virtual ppc64el 6.8.0-28.28 [1684 B] 352s Get:13 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-image-virtual ppc64el 6.8.0-28.28 [9874 B] 352s Get:14 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-headers-virtual ppc64el 6.8.0-28.28 [1650 B] 352s Get:15 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-headers-6.8.0-28 all 6.8.0-28.28 [13.6 MB] 352s Get:16 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-headers-6.8.0-28-generic ppc64el 6.8.0-28.28 [3732 kB] 352s Get:17 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-headers-generic ppc64el 6.8.0-28.28 [9788 B] 352s Get:18 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-libc-dev ppc64el 6.8.0-28.28 [1587 kB] 352s Get:19 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-tools-common all 6.8.0-28.28 [439 kB] 352s Get:20 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-tools-6.8.0-28 ppc64el 6.8.0-28.28 [2927 kB] 352s Get:21 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-tools-6.8.0-28-generic ppc64el 6.8.0-28.28 [1726 B] 352s Get:22 http://ftpmaster.internal/ubuntu noble/main ppc64el trace-cmd ppc64el 3.2-1ubuntu2 [400 kB] 352s Get:23 http://ftpmaster.internal/ubuntu noble/main ppc64el ubuntu-kernel-accessories ppc64el 1.539 [10.8 kB] 353s Fetched 221 MB in 8s (26.9 MB/s) 353s (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 ... 72009 files and directories currently installed.) 353s Preparing to unpack .../00-distro-info_1.7build1_ppc64el.deb ... 353s Unpacking distro-info (1.7build1) over (1.7) ... 353s Preparing to unpack .../01-ubuntu-minimal_1.539_ppc64el.deb ... 353s Unpacking ubuntu-minimal (1.539) over (1.538build1) ... 353s Preparing to unpack .../02-ubuntu-standard_1.539_ppc64el.deb ... 353s Unpacking ubuntu-standard (1.539) over (1.538build1) ... 353s Selecting previously unselected package libtraceevent1:ppc64el. 353s Preparing to unpack .../03-libtraceevent1_1%3a1.8.2-1ubuntu2_ppc64el.deb ... 353s Unpacking libtraceevent1:ppc64el (1:1.8.2-1ubuntu2) ... 353s Selecting previously unselected package libtraceevent1-plugin:ppc64el. 353s Preparing to unpack .../04-libtraceevent1-plugin_1%3a1.8.2-1ubuntu2_ppc64el.deb ... 353s Unpacking libtraceevent1-plugin:ppc64el (1:1.8.2-1ubuntu2) ... 353s Selecting previously unselected package libtracefs1:ppc64el. 353s Preparing to unpack .../05-libtracefs1_1.8.0-1ubuntu1_ppc64el.deb ... 353s Unpacking libtracefs1:ppc64el (1.8.0-1ubuntu1) ... 353s Selecting previously unselected package linux-modules-6.8.0-28-generic. 353s Preparing to unpack .../06-linux-modules-6.8.0-28-generic_6.8.0-28.28_ppc64el.deb ... 353s Unpacking linux-modules-6.8.0-28-generic (6.8.0-28.28) ... 353s Selecting previously unselected package linux-image-6.8.0-28-generic. 353s Preparing to unpack .../07-linux-image-6.8.0-28-generic_6.8.0-28.28_ppc64el.deb ... 353s Unpacking linux-image-6.8.0-28-generic (6.8.0-28.28) ... 353s Selecting previously unselected package linux-modules-extra-6.8.0-28-generic. 353s Preparing to unpack .../08-linux-modules-extra-6.8.0-28-generic_6.8.0-28.28_ppc64el.deb ... 353s Unpacking linux-modules-extra-6.8.0-28-generic (6.8.0-28.28) ... 355s Preparing to unpack .../09-linux-generic_6.8.0-28.28_ppc64el.deb ... 355s Unpacking linux-generic (6.8.0-28.28) over (6.8.0-22.22) ... 355s Preparing to unpack .../10-linux-image-generic_6.8.0-28.28_ppc64el.deb ... 355s Unpacking linux-image-generic (6.8.0-28.28) over (6.8.0-22.22) ... 355s Preparing to unpack .../11-linux-virtual_6.8.0-28.28_ppc64el.deb ... 355s Unpacking linux-virtual (6.8.0-28.28) over (6.8.0-22.22) ... 355s Preparing to unpack .../12-linux-image-virtual_6.8.0-28.28_ppc64el.deb ... 355s Unpacking linux-image-virtual (6.8.0-28.28) over (6.8.0-22.22) ... 355s Preparing to unpack .../13-linux-headers-virtual_6.8.0-28.28_ppc64el.deb ... 355s Unpacking linux-headers-virtual (6.8.0-28.28) over (6.8.0-22.22) ... 355s Selecting previously unselected package linux-headers-6.8.0-28. 355s Preparing to unpack .../14-linux-headers-6.8.0-28_6.8.0-28.28_all.deb ... 355s Unpacking linux-headers-6.8.0-28 (6.8.0-28.28) ... 357s Selecting previously unselected package linux-headers-6.8.0-28-generic. 357s Preparing to unpack .../15-linux-headers-6.8.0-28-generic_6.8.0-28.28_ppc64el.deb ... 357s Unpacking linux-headers-6.8.0-28-generic (6.8.0-28.28) ... 358s Preparing to unpack .../16-linux-headers-generic_6.8.0-28.28_ppc64el.deb ... 358s Unpacking linux-headers-generic (6.8.0-28.28) over (6.8.0-22.22) ... 358s Preparing to unpack .../17-linux-libc-dev_6.8.0-28.28_ppc64el.deb ... 358s Unpacking linux-libc-dev:ppc64el (6.8.0-28.28) over (6.8.0-22.22) ... 359s Preparing to unpack .../18-linux-tools-common_6.8.0-28.28_all.deb ... 359s Unpacking linux-tools-common (6.8.0-28.28) over (6.8.0-22.22) ... 359s Selecting previously unselected package linux-tools-6.8.0-28. 359s Preparing to unpack .../19-linux-tools-6.8.0-28_6.8.0-28.28_ppc64el.deb ... 359s Unpacking linux-tools-6.8.0-28 (6.8.0-28.28) ... 359s Selecting previously unselected package linux-tools-6.8.0-28-generic. 359s Preparing to unpack .../20-linux-tools-6.8.0-28-generic_6.8.0-28.28_ppc64el.deb ... 359s Unpacking linux-tools-6.8.0-28-generic (6.8.0-28.28) ... 359s Selecting previously unselected package trace-cmd. 359s Preparing to unpack .../21-trace-cmd_3.2-1ubuntu2_ppc64el.deb ... 359s Unpacking trace-cmd (3.2-1ubuntu2) ... 359s Preparing to unpack .../22-ubuntu-kernel-accessories_1.539_ppc64el.deb ... 359s Unpacking ubuntu-kernel-accessories (1.539) over (1.538build1) ... 359s Setting up distro-info (1.7build1) ... 359s Setting up ubuntu-kernel-accessories (1.539) ... 359s Setting up ubuntu-minimal (1.539) ... 359s Setting up linux-libc-dev:ppc64el (6.8.0-28.28) ... 359s Setting up ubuntu-standard (1.539) ... 359s Setting up linux-modules-6.8.0-28-generic (6.8.0-28.28) ... 361s Setting up linux-headers-6.8.0-28 (6.8.0-28.28) ... 361s Setting up libtraceevent1:ppc64el (1:1.8.2-1ubuntu2) ... 361s Setting up linux-modules-extra-6.8.0-28-generic (6.8.0-28.28) ... 362s Setting up linux-tools-common (6.8.0-28.28) ... 362s Setting up linux-image-6.8.0-28-generic (6.8.0-28.28) ... 364s I: /boot/vmlinux is now a symlink to vmlinux-6.8.0-28-generic 364s I: /boot/initrd.img is now a symlink to initrd.img-6.8.0-28-generic 364s Setting up linux-headers-6.8.0-28-generic (6.8.0-28.28) ... 364s Setting up libtracefs1:ppc64el (1.8.0-1ubuntu1) ... 364s Setting up libtraceevent1-plugin:ppc64el (1:1.8.2-1ubuntu2) ... 364s Setting up linux-tools-6.8.0-28 (6.8.0-28.28) ... 364s Setting up linux-image-virtual (6.8.0-28.28) ... 364s Setting up linux-tools-6.8.0-28-generic (6.8.0-28.28) ... 364s Setting up linux-image-generic (6.8.0-28.28) ... 364s Setting up trace-cmd (3.2-1ubuntu2) ... 364s Setting up linux-headers-generic (6.8.0-28.28) ... 364s Setting up linux-headers-virtual (6.8.0-28.28) ... 364s Setting up linux-generic (6.8.0-28.28) ... 364s Setting up linux-virtual (6.8.0-28.28) ... 364s Processing triggers for man-db (2.12.0-4build2) ... 365s Processing triggers for libc-bin (2.39-0ubuntu8) ... 365s Processing triggers for linux-image-6.8.0-28-generic (6.8.0-28.28) ... 365s /etc/kernel/postinst.d/initramfs-tools: 365s update-initramfs: Generating /boot/initrd.img-6.8.0-28-generic 365s W: No lz4 in /usr/bin:/sbin:/bin, using gzip 372s /etc/kernel/postinst.d/zz-update-grub: 372s Sourcing file `/etc/default/grub' 372s Sourcing file `/etc/default/grub.d/50-cloudimg-settings.cfg' 372s Generating grub configuration file ... 372s Found linux image: /boot/vmlinux-6.8.0-28-generic 372s Found initrd image: /boot/initrd.img-6.8.0-28-generic 373s Found linux image: /boot/vmlinux-6.8.0-22-generic 373s Found initrd image: /boot/initrd.img-6.8.0-22-generic 373s Warning: os-prober will not be executed to detect other bootable partitions. 373s Systems on them will not be added to the GRUB boot configuration. 373s Check GRUB_DISABLE_OS_PROBER documentation entry. 373s Adding boot menu entry for UEFI Firmware Settings ... 373s done 373s Reading package lists... 373s Building dependency tree... 373s Reading state information... 373s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 374s Hit:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease 374s Hit:2 http://ftpmaster.internal/ubuntu noble InRelease 374s Hit:3 http://ftpmaster.internal/ubuntu noble-updates InRelease 374s Hit:4 http://ftpmaster.internal/ubuntu noble-security InRelease 375s Reading package lists... 375s Reading package lists... 375s Building dependency tree... 375s Reading state information... 375s Calculating upgrade... 375s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 376s Reading package lists... 376s Building dependency tree... 376s Reading state information... 376s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 376s autopkgtest [05:00:48]: rebooting testbed after setup commands that affected boot 419s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 429s Reading package lists... 429s Building dependency tree... 429s Reading state information... 429s Starting pkgProblemResolver with broken count: 0 429s Starting 2 pkgProblemResolver with broken count: 0 429s Done 429s The following additional packages will be installed: 429s fio libboost-iostreams1.83.0 libboost-thread1.83.0 libconfig-general-perl 429s libdaxctl1 libgfapi0 libgfrpc0 libgfxdr0 libglusterfs0 libisns0t64 libnbd0 429s libndctl6 libopeniscsiusr libpmem1 libpmemobj1 librados2 librbd1 429s librdmacm1t64 lsscsi open-iscsi tgt 429s Suggested packages: 429s fio-examples gnuplot tgt-glusterfs tgt-rbd 429s Recommended packages: 429s finalrd 429s The following NEW packages will be installed: 429s autopkgtest-satdep fio libboost-iostreams1.83.0 libboost-thread1.83.0 429s libconfig-general-perl libdaxctl1 libgfapi0 libgfrpc0 libgfxdr0 429s libglusterfs0 libisns0t64 libnbd0 libndctl6 libopeniscsiusr libpmem1 429s libpmemobj1 librados2 librbd1 librdmacm1t64 lsscsi open-iscsi tgt 429s 0 upgraded, 22 newly installed, 0 to remove and 0 not upgraded. 429s Need to get 10.8 MB/10.8 MB of archives. 429s After this operation, 49.9 MB of additional disk space will be used. 429s Get:1 /tmp/autopkgtest.uQ2WGA/2-autopkgtest-satdep.deb autopkgtest-satdep ppc64el 0 [732 B] 430s Get:2 http://ftpmaster.internal/ubuntu noble/main ppc64el libopeniscsiusr ppc64el 2.1.9-3ubuntu4 [54.4 kB] 430s Get:3 http://ftpmaster.internal/ubuntu noble/main ppc64el libisns0t64 ppc64el 0.101-0.3build3 [119 kB] 430s Get:4 http://ftpmaster.internal/ubuntu noble/main ppc64el open-iscsi ppc64el 2.1.9-3ubuntu4 [389 kB] 430s Get:5 http://ftpmaster.internal/ubuntu noble/main ppc64el librdmacm1t64 ppc64el 50.0-2build2 [80.9 kB] 430s Get:6 http://ftpmaster.internal/ubuntu noble/universe ppc64el libconfig-general-perl all 2.65-2 [57.1 kB] 430s Get:7 http://ftpmaster.internal/ubuntu noble/universe ppc64el tgt ppc64el 1:1.0.85-1.1ubuntu6 [256 kB] 430s Get:8 http://ftpmaster.internal/ubuntu noble/universe ppc64el libgfxdr0 ppc64el 11.1-4build3 [21.5 kB] 430s Get:9 http://ftpmaster.internal/ubuntu noble/universe ppc64el libglusterfs0 ppc64el 11.1-4build3 [311 kB] 430s Get:10 http://ftpmaster.internal/ubuntu noble/universe ppc64el libgfrpc0 ppc64el 11.1-4build3 [47.0 kB] 430s Get:11 http://ftpmaster.internal/ubuntu noble/universe ppc64el libgfapi0 ppc64el 11.1-4build3 [100 kB] 430s Get:12 http://ftpmaster.internal/ubuntu noble/universe ppc64el libnbd0 ppc64el 1.20.0-1 [97.3 kB] 430s Get:13 http://ftpmaster.internal/ubuntu noble/main ppc64el libdaxctl1 ppc64el 77-2ubuntu2 [23.7 kB] 430s Get:14 http://ftpmaster.internal/ubuntu noble/main ppc64el libndctl6 ppc64el 77-2ubuntu2 [74.9 kB] 430s Get:15 http://ftpmaster.internal/ubuntu noble/main ppc64el libpmem1 ppc64el 1.13.1-1.1ubuntu2 [41.1 kB] 430s Get:16 http://ftpmaster.internal/ubuntu noble/main ppc64el libboost-iostreams1.83.0 ppc64el 1.83.0-2.1ubuntu3 [260 kB] 430s Get:17 http://ftpmaster.internal/ubuntu noble/main ppc64el libboost-thread1.83.0 ppc64el 1.83.0-2.1ubuntu3 [280 kB] 430s Get:18 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el librados2 ppc64el 19.2.0~git20240301.4c76c50-0ubuntu6 [4050 kB] 430s Get:19 http://ftpmaster.internal/ubuntu noble/main ppc64el libpmemobj1 ppc64el 1.13.1-1.1ubuntu2 [143 kB] 430s Get:20 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el librbd1 ppc64el 19.2.0~git20240301.4c76c50-0ubuntu6 [3612 kB] 431s Get:21 http://ftpmaster.internal/ubuntu noble/universe ppc64el fio ppc64el 3.36-1build2 [716 kB] 431s Get:22 http://ftpmaster.internal/ubuntu noble/main ppc64el lsscsi ppc64el 0.32-1build1 [54.0 kB] 431s Preconfiguring packages ... 431s Fetched 10.8 MB in 1s (9353 kB/s) 431s Selecting previously unselected package libopeniscsiusr. 431s (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 ... 108886 files and directories currently installed.) 431s Preparing to unpack .../00-libopeniscsiusr_2.1.9-3ubuntu4_ppc64el.deb ... 431s Unpacking libopeniscsiusr (2.1.9-3ubuntu4) ... 431s Selecting previously unselected package libisns0t64:ppc64el. 431s Preparing to unpack .../01-libisns0t64_0.101-0.3build3_ppc64el.deb ... 431s Unpacking libisns0t64:ppc64el (0.101-0.3build3) ... 431s Selecting previously unselected package open-iscsi. 431s Preparing to unpack .../02-open-iscsi_2.1.9-3ubuntu4_ppc64el.deb ... 431s Unpacking open-iscsi (2.1.9-3ubuntu4) ... 431s Selecting previously unselected package librdmacm1t64:ppc64el. 431s Preparing to unpack .../03-librdmacm1t64_50.0-2build2_ppc64el.deb ... 431s Unpacking librdmacm1t64:ppc64el (50.0-2build2) ... 431s Selecting previously unselected package libconfig-general-perl. 431s Preparing to unpack .../04-libconfig-general-perl_2.65-2_all.deb ... 431s Unpacking libconfig-general-perl (2.65-2) ... 431s Selecting previously unselected package tgt. 431s Preparing to unpack .../05-tgt_1%3a1.0.85-1.1ubuntu6_ppc64el.deb ... 431s Unpacking tgt (1:1.0.85-1.1ubuntu6) ... 431s Selecting previously unselected package libgfxdr0:ppc64el. 431s Preparing to unpack .../06-libgfxdr0_11.1-4build3_ppc64el.deb ... 431s Unpacking libgfxdr0:ppc64el (11.1-4build3) ... 431s Selecting previously unselected package libglusterfs0:ppc64el. 431s Preparing to unpack .../07-libglusterfs0_11.1-4build3_ppc64el.deb ... 431s Unpacking libglusterfs0:ppc64el (11.1-4build3) ... 431s Selecting previously unselected package libgfrpc0:ppc64el. 431s Preparing to unpack .../08-libgfrpc0_11.1-4build3_ppc64el.deb ... 431s Unpacking libgfrpc0:ppc64el (11.1-4build3) ... 431s Selecting previously unselected package libgfapi0:ppc64el. 431s Preparing to unpack .../09-libgfapi0_11.1-4build3_ppc64el.deb ... 431s Unpacking libgfapi0:ppc64el (11.1-4build3) ... 431s Selecting previously unselected package libnbd0. 431s Preparing to unpack .../10-libnbd0_1.20.0-1_ppc64el.deb ... 431s Unpacking libnbd0 (1.20.0-1) ... 431s Selecting previously unselected package libdaxctl1:ppc64el. 431s Preparing to unpack .../11-libdaxctl1_77-2ubuntu2_ppc64el.deb ... 431s Unpacking libdaxctl1:ppc64el (77-2ubuntu2) ... 431s Selecting previously unselected package libndctl6:ppc64el. 431s Preparing to unpack .../12-libndctl6_77-2ubuntu2_ppc64el.deb ... 431s Unpacking libndctl6:ppc64el (77-2ubuntu2) ... 431s Selecting previously unselected package libpmem1:ppc64el. 431s Preparing to unpack .../13-libpmem1_1.13.1-1.1ubuntu2_ppc64el.deb ... 431s Unpacking libpmem1:ppc64el (1.13.1-1.1ubuntu2) ... 432s Selecting previously unselected package libboost-iostreams1.83.0:ppc64el. 432s Preparing to unpack .../14-libboost-iostreams1.83.0_1.83.0-2.1ubuntu3_ppc64el.deb ... 432s Unpacking libboost-iostreams1.83.0:ppc64el (1.83.0-2.1ubuntu3) ... 432s Selecting previously unselected package libboost-thread1.83.0:ppc64el. 432s Preparing to unpack .../15-libboost-thread1.83.0_1.83.0-2.1ubuntu3_ppc64el.deb ... 432s Unpacking libboost-thread1.83.0:ppc64el (1.83.0-2.1ubuntu3) ... 432s Selecting previously unselected package librados2. 432s Preparing to unpack .../16-librados2_19.2.0~git20240301.4c76c50-0ubuntu6_ppc64el.deb ... 432s Unpacking librados2 (19.2.0~git20240301.4c76c50-0ubuntu6) ... 432s Selecting previously unselected package libpmemobj1:ppc64el. 432s Preparing to unpack .../17-libpmemobj1_1.13.1-1.1ubuntu2_ppc64el.deb ... 432s Unpacking libpmemobj1:ppc64el (1.13.1-1.1ubuntu2) ... 432s Selecting previously unselected package librbd1. 432s Preparing to unpack .../18-librbd1_19.2.0~git20240301.4c76c50-0ubuntu6_ppc64el.deb ... 432s Unpacking librbd1 (19.2.0~git20240301.4c76c50-0ubuntu6) ... 432s Selecting previously unselected package fio. 432s Preparing to unpack .../19-fio_3.36-1build2_ppc64el.deb ... 432s Unpacking fio (3.36-1build2) ... 432s Selecting previously unselected package lsscsi. 432s Preparing to unpack .../20-lsscsi_0.32-1build1_ppc64el.deb ... 432s Unpacking lsscsi (0.32-1build1) ... 432s Selecting previously unselected package autopkgtest-satdep. 432s Preparing to unpack .../21-2-autopkgtest-satdep.deb ... 432s Unpacking autopkgtest-satdep (0) ... 432s Setting up libconfig-general-perl (2.65-2) ... 432s Setting up libisns0t64:ppc64el (0.101-0.3build3) ... 432s Setting up libboost-thread1.83.0:ppc64el (1.83.0-2.1ubuntu3) ... 432s Setting up libnbd0 (1.20.0-1) ... 432s Setting up libopeniscsiusr (2.1.9-3ubuntu4) ... 432s Setting up libglusterfs0:ppc64el (11.1-4build3) ... 432s Setting up libboost-iostreams1.83.0:ppc64el (1.83.0-2.1ubuntu3) ... 432s Setting up lsscsi (0.32-1build1) ... 432s Setting up libdaxctl1:ppc64el (77-2ubuntu2) ... 432s Setting up libndctl6:ppc64el (77-2ubuntu2) ... 432s Setting up librdmacm1t64:ppc64el (50.0-2build2) ... 432s Setting up tgt (1:1.0.85-1.1ubuntu6) ... 432s Created symlink /etc/systemd/system/multi-user.target.wants/tgt.service → /usr/lib/systemd/system/tgt.service. 433s Setting up libpmem1:ppc64el (1.13.1-1.1ubuntu2) ... 433s Setting up libgfxdr0:ppc64el (11.1-4build3) ... 433s Setting up librados2 (19.2.0~git20240301.4c76c50-0ubuntu6) ... 433s Setting up open-iscsi (2.1.9-3ubuntu4) ... 434s Created symlink /etc/systemd/system/sockets.target.wants/iscsid.socket → /usr/lib/systemd/system/iscsid.socket. 434s Created symlink /etc/systemd/system/iscsi.service → /usr/lib/systemd/system/open-iscsi.service. 434s Created symlink /etc/systemd/system/sysinit.target.wants/open-iscsi.service → /usr/lib/systemd/system/open-iscsi.service. 434s Setting up libpmemobj1:ppc64el (1.13.1-1.1ubuntu2) ... 434s Setting up librbd1 (19.2.0~git20240301.4c76c50-0ubuntu6) ... 434s Setting up libgfrpc0:ppc64el (11.1-4build3) ... 434s Setting up libgfapi0:ppc64el (11.1-4build3) ... 434s Setting up fio (3.36-1build2) ... 435s Setting up autopkgtest-satdep (0) ... 435s Processing triggers for man-db (2.12.0-4build2) ... 436s Processing triggers for initramfs-tools (0.142ubuntu25) ... 436s update-initramfs: Generating /boot/initrd.img-6.8.0-28-generic 436s W: No lz4 in /usr/bin:/sbin:/bin, using gzip 443s Processing triggers for libc-bin (2.39-0ubuntu8) ... 446s (Reading database ... 109127 files and directories currently installed.) 446s Removing autopkgtest-satdep (0) ... 449s autopkgtest [05:02:01]: test tgtbasedmpaths: [----------------------- 449s + targetname=iqn.2016-11.foo.com:target.iscsi 449s + pwd 449s + cwd=/tmp/autopkgtest.uQ2WGA/build.6tB/src 449s + testdir=/mnt/tgtmpathtest 449s + localhost=127.0.0.1 449s + portal=127.0.0.1:3260 449s + maxpaths=4 449s + backfn=backingfile 449s + expectwwid=60000000000000000e00000000010001 449s + testdisk=/dev/disk/by-id/wwn-0x60000000000000000e00000000010001 449s + bglog=/tmp/autopkgtest.uQ2WGA/tgtbasedmpaths-artifacts/test-background.log 449s + fioprep=/tmp/autopkgtest.uQ2WGA/tgtbasedmpaths-artifacts/path-change-prep.fio 449s + fiovrfy=/tmp/autopkgtest.uQ2WGA/tgtbasedmpaths-artifacts/path-change-check.fio 449s + service tgt restart 450s + truncate --size 100M backingfile 450s + tgtadm --lld iscsi --op new --mode target --tid 1 -T iqn.2016-11.foo.com:target.iscsi 450s + tgtadm --lld iscsi --op bind --mode target --tid 1 -I ALL 450s + tgtadm --lld iscsi --op new --mode logicalunit --tid 1 --lun 1 -b /tmp/autopkgtest.uQ2WGA/build.6tB/src/backingfile 450s + iscsiadm --mode discovery --type sendtargets --portal 127.0.0.1 450s 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi 450s + echo login #1 450s + iscsiadm --mode node --targetname iqn.2016-11.foo.com:target.iscsi --portal 127.0.0.1:3260 --login 450s login #1 450s + seq 2 4 450s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 450s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 450s extra login #2 450s + echo extra login #2 450s + iscsiadm --mode session -r 1 --op new 450s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 450s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 450s extra login #3 450s + echo extra login #3 450s + iscsiadm --mode session -r 1 --op new 450s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 450s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 450s + echo extra login #4 450s + iscsiadm --mode session -r 1 --op new 450s extra login #4 450s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 450s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 450s + udevadm settle 450s + sleep 5 455s Status after initial setup 455s + echo Status after initial setup 455s + tgtadm --lld iscsi --mode target --op show 455s Target 1: iqn.2016-11.foo.com:target.iscsi 455s System information: 455s Driver: iscsi 455s State: ready 455s I_T nexus information: 455s I_T nexus: 1 455s Initiator: iqn.2004-10.com.ubuntu:01:cfbebca95b30 alias: autopkgtest 455s Connection: 0 455s IP Address: 127.0.0.1 455s I_T nexus: 2 455s Initiator: iqn.2004-10.com.ubuntu:01:cfbebca95b30 alias: autopkgtest 455s Connection: 0 455s IP Address: 127.0.0.1 455s I_T nexus: 3 455s Initiator: iqn.2004-10.com.ubuntu:01:cfbebca95b30 alias: autopkgtest 455s Connection: 0 455s IP Address: 127.0.0.1 455s I_T nexus: 4 455s Initiator: iqn.2004-10.com.ubuntu:01:cfbebca95b30 alias: autopkgtest 455s Connection: 0 455s IP Address: 127.0.0.1 455s LUN information: 455s LUN: 0 455s Type: controller 455s SCSI ID: IET 00010000 455s SCSI SN: beaf10 455s Size: 0 MB, Block size: 1 455s Online: Yes 455s Removable media: No 455s Prevent removal: No 455s Readonly: No 455s SWP: No 455s Thin-provisioning: No 455s Backing store type: null 455s Backing store path: None 455s Backing store flags: 455s LUN: 1 455s Type: disk 455s SCSI ID: IET 00010001 455s SCSI SN: beaf11 455s Size: 105 MB, Block size: 512 455s Online: Yes 455s Removable media: No 455s Prevent removal: No 455s Readonly: No 455s SWP: No 455s Thin-provisioning: No 455s Backing store type: rdwr 455s Backing store path: /tmp/autopkgtest.uQ2WGA/build.6tB/src/backingfile 455s Backing store flags: 455s Account information: 455s ACL information: 455s ALL 455s Session: 4 455s Connection: 0 455s Initiator: iqn.2004-10.com.ubuntu:01:cfbebca95b30 455s IP Address: 127.0.0.1 455s Session: 3 455s Connection: 0 455s Initiator: iqn.2004-10.com.ubuntu:01:cfbebca95b30 455s IP Address: 127.0.0.1 455s Session: 2 455s Connection: 0 455s Initiator: iqn.2004-10.com.ubuntu:01:cfbebca95b30 455s IP Address: 127.0.0.1 455s Session: 1 455s Connection: 0 455s Initiator: iqn.2004-10.com.ubuntu:01:cfbebca95b30 455s IP Address: 127.0.0.1 455s + tgtadm --lld iscsi --op show --mode conn --tid 1 455s + iscsiadm --mode session -P 1 455s Target: iqn.2016-11.foo.com:target.iscsi (non-flash) 455s Current Portal: 127.0.0.1:3260,1 455s Persistent Portal: 127.0.0.1:3260,1 455s ********** 455s Interface: 455s ********** 455s Iface Name: default 455s Iface Transport: tcp 455s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:cfbebca95b30 455s Iface IPaddress: 127.0.0.1 455s Iface HWaddress: default 455s Iface Netdev: default 455s SID: 1 455s iSCSI Connection State: LOGGED IN 455s iSCSI Session State: LOGGED_IN 455s Internal iscsid Session State: NO CHANGE 455s 455s ********** 455s Interface: 455s ********** 455s Iface Name: default 455s Iface Transport: tcp 455s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:cfbebca95b30 455s Iface IPaddress: 127.0.0.1 455s Iface HWaddress: default 455s Iface Netdev: default 455s SID: 2 455s iSCSI Connection State: LOGGED IN 455s iSCSI Session State: LOGGED_IN 455s Internal iscsid Session State: NO CHANGE 455s 455s ********** 455s Interface: 455s ********** 455s Iface Name: default 455s Iface Transport: tcp 455s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:cfbebca95b30 455s Iface IPaddress: 127.0.0.1 455s Iface HWaddress: default 455s Iface Netdev: default 455s SID: 3 455s iSCSI Connection State: LOGGED IN 455s iSCSI Session State: LOGGED_IN 455s Internal iscsid Session State: NO CHANGE 455s 455s ********** 455s Interface: 455s ********** 455s Iface Name: default 455s Iface Transport: tcp 455s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:cfbebca95b30 455s Iface IPaddress: 127.0.0.1 455s Iface HWaddress: default 455s Iface Netdev: default 455s SID: 4 455s iSCSI Connection State: LOGGED IN 455s iSCSI Session State: LOGGED_IN 455s Internal iscsid Session State: NO CHANGE 455s + lsscsi -liv 455s [0:0:0:0] disk QEMU QEMU HARDDISK 2.5+ /dev/sda 0QEMU_QEMU_HARDDISK_drive-scsi0-0-0-0 455s state=running queue_depth=128 scsi_level=6 type=0 device_blocked=0 timeout=30 455s 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] 455s [1:0:0:0] storage IET Controller 0001 - - 455s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 455s dir: /sys/bus/scsi/devices/1:0:0:0 [/sys/devices/platform/host1/session1/target1:0:0/1:0:0:0] 455s [1:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdb 360000000000000000e00000000010001 455s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 455s dir: /sys/bus/scsi/devices/1:0:0:1 [/sys/devices/platform/host1/session1/target1:0:0/1:0:0:1] 455s [2:0:0:0] storage IET Controller 0001 - - 455s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 455s dir: /sys/bus/scsi/devices/2:0:0:0 [/sys/devices/platform/host2/session2/target2:0:0/2:0:0:0] 455s [2:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdc 360000000000000000e00000000010001 455s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 455s dir: /sys/bus/scsi/devices/2:0:0:1 [/sys/devices/platform/host2/session2/target2:0:0/2:0:0:1] 455s [3:0:0:0] storage IET Controller 0001 - - 455s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 455s dir: /sys/bus/scsi/devices/3:0:0:0 [/sys/devices/platform/host3/session3/target3:0:0/3:0:0:0] 455s [3:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdd 360000000000000000e00000000010001 455s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 455s dir: /sys/bus/scsi/devices/3:0:0:1 [/sys/devices/platform/host3/session3/target3:0:0/3:0:0:1] 455s [4:0:0:0] storage IET Controller 0001 - - 455s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 455s dir: /sys/bus/scsi/devices/4:0:0:0 [/sys/devices/platform/host4/session4/target4:0:0/4:0:0:0] 455s [4:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sde 33000000100000001 455s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 455s dir: /sys/bus/scsi/devices/4:0:0:1 [/sys/devices/platform/host4/session4/target4:0:0/4:0:0:1] 455s NVMe module may not be loaded 455s list_ndevices: scandir: /sys/class/nvme/: No such file or directory 455s + multipath -v3 -ll 455s 51.734558 | set open fds limit to 1048576/1048576 455s 51.734642 | loading /lib/multipath/libchecktur.so checker 455s 51.734727 | checker tur: message table size = 3 455s 51.734753 | loading /lib/multipath/libprioconst.so prioritizer 455s 51.734869 | _init_foreign: foreign library "nvme" is not enabled 455s 51.741418 | sda: size = 167772160 455s 51.741624 | sda: vendor = QEMU 455s 51.741668 | sda: product = QEMU HARDDISK 455s 51.741691 | sda: rev = 2.5+ 455s 51.742330 | sda: h:b:t:l = 0:0:0:0 455s 51.742649 | sda: tgt_node_name = 455s 51.742670 | sda: uid_attribute = ID_SERIAL (setting: multipath internal) 455s 51.742673 | sda: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 455s 51.742828 | sda: 10443 cyl, 255 heads, 63 sectors/track, start at 0 455s 51.742849 | sda: vpd_vendor_id = 0 "undef" (setting: multipath internal) 455s 51.742862 | __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 455s 51.742867 | failed to read sysfs vpd pg80: No such file or directory 455s 51.743079 | sda: fail to get serial 455s 51.743100 | sda: detect_checker = yes (setting: multipath internal) 455s 51.743294 | sda: path_checker = tur (setting: multipath internal) 455s 51.743316 | sda: checker timeout = 30 s (setting: kernel sysfs) 455s 51.743470 | sda: tur state = up 455s 51.743890 | sdb: size = 204800 455s 51.744129 | sdb: vendor = IET 455s 51.744196 | sdb: product = VIRTUAL-DISK 455s 51.744227 | sdb: rev = 0001 455s 51.744885 | sdb: h:b:t:l = 1:0:0:1 455s 51.745253 | sdb: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 455s 51.745274 | sdb: uid_attribute = ID_SERIAL (setting: multipath internal) 455s 51.745276 | sdb: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 455s 51.745436 | sdb: 1024 cyl, 4 heads, 50 sectors/track, start at 0 455s 51.745457 | sdb: vpd_vendor_id = 0 "undef" (setting: multipath internal) 455s 51.745476 | sdb: serial = beaf11 455s 51.745479 | sdb: detect_checker = yes (setting: multipath internal) 455s 51.745892 | sdb: path_checker = tur (setting: multipath internal) 455s 51.745914 | sdb: checker timeout = 30 s (setting: kernel sysfs) 455s 51.746160 | sdb: tur state = up 455s 51.746307 | sdc: size = 204800 455s 51.746456 | sdc: vendor = IET 455s 51.746497 | sdc: product = VIRTUAL-DISK 455s 51.746519 | sdc: rev = 0001 455s 51.747222 | sdc: h:b:t:l = 2:0:0:1 455s 51.747609 | sdc: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 455s 51.747633 | sdc: uid_attribute = ID_SERIAL (setting: multipath internal) 455s 51.747636 | sdc: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 455s 51.747803 | sdc: 1024 cyl, 4 heads, 50 sectors/track, start at 0 455s 51.747824 | sdc: vpd_vendor_id = 0 "undef" (setting: multipath internal) 455s 51.747839 | sdc: serial = beaf11 455s 51.747841 | sdc: detect_checker = yes (setting: multipath internal) 455s 51.748096 | sdc: path_checker = tur (setting: multipath internal) 455s 51.748125 | sdc: checker timeout = 30 s (setting: kernel sysfs) 455s 51.748396 | sdc: tur state = up 455s 51.748550 | sdd: size = 204800 455s 51.748706 | sdd: vendor = IET 455s 51.748748 | sdd: product = VIRTUAL-DISK 455s 51.748770 | sdd: rev = 0001 455s 51.749465 | sdd: h:b:t:l = 3:0:0:1 455s 51.749854 | sdd: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 455s 51.749875 | sdd: uid_attribute = ID_SERIAL (setting: multipath internal) 455s 51.749877 | sdd: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 455s 51.750029 | sdd: 1024 cyl, 4 heads, 50 sectors/track, start at 0 455s 51.750050 | sdd: vpd_vendor_id = 0 "undef" (setting: multipath internal) 455s 51.750064 | sdd: serial = beaf11 455s 51.750066 | sdd: detect_checker = yes (setting: multipath internal) 455s 51.750369 | sdd: path_checker = tur (setting: multipath internal) 455s 51.750391 | sdd: checker timeout = 30 s (setting: kernel sysfs) 455s 51.750625 | sdd: tur state = up 455s 51.750774 | sde: size = 204800 455s 51.750931 | sde: vendor = IET 455s 51.750972 | sde: product = VIRTUAL-DISK 455s 51.750994 | sde: rev = 0001 455s 51.751699 | sde: h:b:t:l = 4:0:0:1 455s 51.752101 | sde: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 455s 51.752128 | sde: uid_attribute = ID_SERIAL (setting: multipath internal) 455s 51.752130 | sde: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 455s 51.752276 | sde: 1024 cyl, 4 heads, 50 sectors/track, start at 0 455s 51.752296 | sde: vpd_vendor_id = 0 "undef" (setting: multipath internal) 455s 51.752311 | sde: serial = beaf11 455s 51.752313 | sde: detect_checker = yes (setting: multipath internal) 455s 51.752595 | sde: path_checker = tur (setting: multipath internal) 455s 51.752616 | sde: checker timeout = 30 s (setting: kernel sysfs) 455s 51.752863 | sde: tur state = up 455s 51.752982 | loop0: device node name blacklisted 455s 51.753091 | loop1: device node name blacklisted 455s 51.753194 | loop2: device node name blacklisted 455s 51.753300 | loop3: device node name blacklisted 455s 51.753401 | loop4: device node name blacklisted 455s 51.753502 | loop5: device node name blacklisted 455s 51.753607 | loop6: device node name blacklisted 455s 51.753708 | loop7: device node name blacklisted 455s 51.753822 | dm-0: device node name blacklisted 455s 51.754860 | multipath-tools v0.9.4 (12/19, 2022) 455s 51.754894 | libdevmapper version 1.02.185 455s 51.755030 | kernel device mapper v4.48.0 455s 51.755060 | DM multipath kernel driver v1.14.0 455s 51.755178 | sdb: size = 204800 455s 51.755201 | sdb: vendor = IET 455s 51.755203 | sdb: product = VIRTUAL-DISK 455s 51.755206 | sdb: rev = 0001 455s 51.755847 | sdb: h:b:t:l = 1:0:0:1 455s 51.755989 | sdb: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 455s 51.756028 | sdb: 1024 cyl, 4 heads, 50 sectors/track, start at 0 455s 51.756055 | sdb: vpd_vendor_id = 0 "undef" (setting: multipath internal) 455s 51.756070 | sdb: serial = beaf11 455s 51.756254 | sdb: tur state = up 455s 51.756276 | sdb: uid = 360000000000000000e00000000010001 (udev) 455s 51.756279 | sdb: detect_prio = yes (setting: multipath internal) 455s 51.756283 | sdb: prio = const (setting: multipath internal) 455s 51.756285 | sdb: prio args = "" (setting: multipath internal) 455s 51.756287 | sdb: const prio = 1 455s 51.756315 | sdc: size = 204800 455s 51.756320 | sdc: vendor = IET 455s 51.756323 | sdc: product = VIRTUAL-DISK 455s 51.756326 | sdc: rev = 0001 455s 51.756943 | sdc: h:b:t:l = 2:0:0:1 455s 51.757092 | sdc: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 455s 51.757128 | sdc: 1024 cyl, 4 heads, 50 sectors/track, start at 0 455s 51.757131 | sdc: vpd_vendor_id = 0 "undef" (setting: multipath internal) 455s 51.757144 | sdc: serial = beaf11 455s 51.757221 | sdc: tur state = up 455s 51.757247 | sdc: uid = 360000000000000000e00000000010001 (udev) 455s 51.757249 | sdc: detect_prio = yes (setting: multipath internal) 455s 51.757252 | sdc: prio = const (setting: multipath internal) 455s 51.757254 | sdc: prio args = "" (setting: multipath internal) 455s 51.757256 | sdc: const prio = 1 455s 51.757280 | sdd: size = 204800 455s 51.757284 | sdd: vendor = IET 455s 51.757287 | sdd: product = VIRTUAL-DISK 455s 51.757289 | sdd: rev = 0001 455s 51.757911 | sdd: h:b:t:l = 3:0:0:1 455s 51.758038 | sdd: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 455s 51.758075 | sdd: 1024 cyl, 4 heads, 50 sectors/track, start at 0 455s 51.758078 | sdd: vpd_vendor_id = 0 "undef" (setting: multipath internal) 455s 51.758090 | sdd: serial = beaf11 455s 51.758217 | sdd: tur state = up 455s 51.758236 | sdd: uid = 360000000000000000e00000000010001 (udev) 455s 51.758239 | sdd: detect_prio = yes (setting: multipath internal) 455s 51.758241 | sdd: prio = const (setting: multipath internal) 455s 51.758243 | sdd: prio args = "" (setting: multipath internal) 455s 51.758246 | sdd: const prio = 1 455s 51.758268 | sde: size = 204800 455s 51.758272 | sde: vendor = IET 455s 51.758275 | sde: product = VIRTUAL-DISK 455s 51.758277 | sde: rev = 0001 455s 51.758888 | sde: h:b:t:l = 4:0:0:1 455s 51.759022 | sde: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 455s 51.759060 | sde: 1024 cyl, 4 heads, 50 sectors/track, start at 0 455s 51.759062 | sde: vpd_vendor_id = 0 "undef" (setting: multipath internal) 455s 51.759075 | sde: serial = beaf11 455s 51.759200 | sde: tur state = up 455s 51.759221 | sde: uid = 360000000000000000e00000000010001 (udev) 455s 51.759223 | sde: detect_prio = yes (setting: multipath internal) 455s 51.759226 | sde: prio = const (setting: multipath internal) 455s 51.759228 | sde: prio args = "" (setting: multipath internal) 455s 51.759230 | sde: const prio = 1 455s 51.760104 | unloading tur checker 455s 51.760178 | unloading const prioritizer 455s + dmsetup table 455s + echo Test WWN should now point to DM 455s + readlink /dev/disk/by-id/wwn-0x60000000000000000e00000000010001 455s + grep dm 455s + mkfs.ext4 -F /dev/disk/by-id/wwn-0x60000000000000000e00000000010001 455s mke2fs 1.47.0 (5-Feb-2023) 455s ===== paths list ===== 455s uuid hcil dev dev_t pri dm_st chk_st vend/prod/rev dev_st 455s 0:0:0:0 sda 8:0 -1 undef undef QEMU,QEMU HARDDISK unknown 455s 1:0:0:1 sdb 8:16 -1 undef undef IET,VIRTUAL-DISK unknown 455s 2:0:0:1 sdc 8:32 -1 undef undef IET,VIRTUAL-DISK unknown 455s 3:0:0:1 sdd 8:48 -1 undef undef IET,VIRTUAL-DISK unknown 455s 4:0:0:1 sde 8:64 -1 undef undef IET,VIRTUAL-DISK unknown 455s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 455s size=100M features='0' hwhandler='0' wp=rw 455s |-+- policy='service-time 0' prio=1 status=active 455s | `- 1:0:0:1 sdb 8:16 active ready running 455s |-+- policy='service-time 0' prio=1 status=enabled 455s | `- 2:0:0:1 sdc 8:32 active ready running 455s |-+- policy='service-time 0' prio=1 status=enabled 455s | `- 3:0:0:1 sdd 8:48 active ready running 455s `-+- policy='service-time 0' prio=1 status=enabled 455s `- 4:0:0:1 sde 8:64 active ready running 455s 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 455s Test WWN should now point to DM 455s ../../dm-0 455s Creating filesystem with 25600 4k blocks and 25600 inodes 455s 455s Allocating group tables: 0/1 done 455s Writing inode tables: 0/1 done 455s Creating journal (1024 blocks): done 455s Writing superblocks and filesystem accounting information: 0/1 done 455s 455s + udevadm settle 455s + sleep 3s 458s + mkdir -p /mnt/tgtmpathtest 458s + mount /dev/disk/by-id/wwn-0x60000000000000000e00000000010001 /mnt/tgtmpathtest 458s + cat 458s + cat 458s + fio --max-jobs=4 /tmp/autopkgtest.uQ2WGA/tgtbasedmpaths-artifacts/path-change-prep.fio 458s 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 458s fio-3.36 458s Starting 1 thread 458s write-phase: Laying out IO file (1 file / 17592186044415MiB) 459s fio: io_u error on file /mnt/tgtmpathtest/datafile.tmp: No space left on device: write offset=91881472, buflen=65536 459s 459s write-phase: (groupid=0, jobs=1): err= 0: pid=5621: Sat Apr 20 05:02:11 2024 459s write: IOPS=1824, BW=114MiB/s (119MB/s)(87.6MiB/769msec); 0 zone resets 459s clat (usec): min=299, max=4696, avg=526.26, stdev=168.69 459s lat (usec): min=318, max=4716, avg=546.90, stdev=169.65 459s clat percentiles (usec): 459s | 1.00th=[ 330], 5.00th=[ 375], 10.00th=[ 412], 20.00th=[ 457], 459s | 30.00th=[ 494], 40.00th=[ 519], 50.00th=[ 537], 60.00th=[ 545], 459s | 70.00th=[ 562], 80.00th=[ 570], 90.00th=[ 594], 95.00th=[ 619], 459s | 99.00th=[ 742], 99.50th=[ 938], 99.90th=[ 3982], 99.95th=[ 4686], 459s | 99.99th=[ 4686] 459s bw ( KiB/s): min=118912, max=118912, per=100.00%, avg=118912.00, stdev= 0.00, samples=1 459s iops : min= 1858, max= 1858, avg=1858.00, stdev= 0.00, samples=1 459s lat (usec) : 500=31.93%, 750=67.00%, 1000=0.57% 459s lat (msec) : 2=0.29%, 4=0.07%, 10=0.07% 459s cpu : usr=5.60%, sys=6.90%, ctx=1404, majf=0, minf=0 459s IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0% 459s submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 459s complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 459s issued rwts: total=0,1403,0,0 short=0,0,0,0 dropped=0,0,0,0 459s latency : target=0, window=0, percentile=100.00%, depth=1 459s 459s Run status group 0 (all jobs): 459s WRITE: bw=114MiB/s (119MB/s), 114MiB/s-114MiB/s (119MB/s-119MB/s), io=87.6MiB (91.9MB), run=769-769msec 459s 459s Disk stats (read/write): 459s dm-0: ios=1/1179, sectors=8/150912, merge=0/0, ticks=0/612, in_queue=613, util=86.91%, aggrios=0/351, aggsectors=2/44884, aggrmerge=0/0, aggrticks=0/174, aggrin_queue=174, aggrutil=87.43% 459s sdd: ios=0/0, sectors=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 459s sdb: ios=1/1404, sectors=8/179536, merge=0/0, ticks=0/696, in_queue=697, util=87.43% 459s sde: ios=0/0, sectors=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 459s sdc: ios=0/0, sectors=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 459s Starting the path changes in background 459s + echo Starting the path changes in background 459s + date +Pre FIO %H:%M:%S.%N 459s + fio --max-jobs=4 /tmp/autopkgtest.uQ2WGA/tgtbasedmpaths-artifacts/path-change-check.fio 459s Pre FIO 05:02:11.573448516 459s 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 459s fio-3.36 459s Starting 1 thread 639s 639s verify-phase: (groupid=0, jobs=1): err= 0: pid=5628: Sat Apr 20 05:05:11 2024 639s read: IOPS=3510, BW=219MiB/s (230MB/s)(38.6GiB/180001msec) 639s clat (usec): min=85, max=61633, avg=261.65, stdev=226.83 639s lat (usec): min=86, max=61633, avg=261.76, stdev=226.83 639s clat percentiles (usec): 639s | 1.00th=[ 104], 5.00th=[ 149], 10.00th=[ 165], 20.00th=[ 194], 639s | 30.00th=[ 206], 40.00th=[ 217], 50.00th=[ 239], 60.00th=[ 281], 639s | 70.00th=[ 302], 80.00th=[ 326], 90.00th=[ 363], 95.00th=[ 396], 639s | 99.00th=[ 478], 99.50th=[ 586], 99.90th=[ 1369], 99.95th=[ 1958], 639s | 99.99th=[ 3621] 639s bw ( KiB/s): min=125184, max=390912, per=100.00%, avg=224802.66, stdev=49846.06, samples=359 639s iops : min= 1956, max= 6108, avg=3512.51, stdev=778.86, samples=359 639s lat (usec) : 100=0.81%, 250=51.40%, 500=47.01%, 750=0.47%, 1000=0.13% 639s lat (msec) : 2=0.15%, 4=0.04%, 10=0.01%, 20=0.01%, 50=0.01% 639s lat (msec) : 100=0.01% 639s cpu : usr=9.65%, sys=7.16%, ctx=631941, majf=0, minf=1 639s IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0% 639s submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 639s complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 639s issued rwts: total=631840,0,0,0 short=0,0,0,0 dropped=0,0,0,0 639s latency : target=0, window=0, percentile=100.00%, depth=1 639s 639s Run status group 0 (all jobs): 639s READ: bw=219MiB/s (230MB/s), 219MiB/s-219MiB/s (230MB/s-230MB/s), io=38.6GiB (41.4GB), run=180001-180001msec 639s 639s Disk stats (read/write): 639s dm-0: ios=631870/9, sectors=80821048/12912, merge=29/8, ticks=166282/69, in_queue=166393, util=100.00%, aggrios=43036/2, aggsectors=5504558/3228, aggrmerge=0/0, aggrticks=10663/6, aggrin_queue=10669, aggrutil=99.14% 639s sdd: ios=32285/0, sectors=4129536/0, merge=0/0, ticks=8577/0, in_queue=8577, util=33.00% 639s sdb: ios=28829/8, sectors=3687296/12912, merge=0/0, ticks=8567/26, in_queue=8593, util=99.14% 639s sde: ios=76215/0, sectors=9748608/0, merge=0/0, ticks=16884/0, in_queue=16883, util=39.54% 639s sdc: ios=34818/0, sectors=4452792/0, merge=0/0, ticks=8624/0, in_queue=8624, util=49.96% 639s + date +Post FIO %H:%M:%S.%N 639s Post FIO 05:05:11.782050451 639s FIO verify test with changing paths - OK 639s Report log of background activity 639s + echo FIO verify test with changing paths - OK 639s + echo Report log of background activity 639s + cat /tmp/autopkgtest.uQ2WGA/tgtbasedmpaths-artifacts/test-background.log 639s + sync 639s + umount /dev/disk/by-id/wwn-0x60000000000000000e00000000010001 639s + echo Final stats 639s + iscsiadm --mode session --stats 639s + journalctl --no-pager -u multipathd 639s + echo Check final path status 639s + multipath -ll 639s + multipath -ll 639s + grep --count status= 639s + diskc=2 639s + multipath -ll 639s + grep --count status=active 639s + iscsiadm --mode session 639s tcp: [1] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 639s tcp: [2] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 639s tcp: [3] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 639s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 639s + sleep 10s 639s + date +MP report (expect 4) %H:%M:%S.%N 639s MP report (expect 4) 05:02:21.580990499 639s + multipath -ll 639s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 639s size=100M features='0' hwhandler='0' wp=rw 639s |-+- policy='service-time 0' prio=1 status=active 639s | `- 1:0:0:1 sdb 8:16 active ready running 639s |-+- policy='service-time 0' prio=1 status=enabled 639s | `- 2:0:0:1 sdc 8:32 active ready running 639s |-+- policy='service-time 0' prio=1 status=enabled 639s | `- 3:0:0:1 sdd 8:48 active ready running 639s `-+- policy='service-time 0' prio=1 status=enabled 639s `- 4:0:0:1 sde 8:64 active ready running 639s + date +UN-plug path 1 %H:%M:%S.%N 639s UN-plug path 1 05:02:21.609816645 639s + iscsiadm --mode session -r 1 -u 639s Logging out of session [sid: 1, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 639s Logout of [sid: 1, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 639s + iscsiadm --mode session 639s tcp: [2] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 639s tcp: [3] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 639s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 639s + sleep 10s 639s + date +MP report (expect 3) %H:%M:%S.%N 639s MP report (expect 3) 05:02:31.689033083 639s + multipath -ll 639s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 639s size=100M features='0' hwhandler='0' wp=rw 639s |-+- policy='service-time 0' prio=1 status=active 639s | `- 2:0:0:1 sdc 8:32 active ready running 639s |-+- policy='service-time 0' prio=1 status=enabled 639s | `- 3:0:0:1 sdd 8:48 active ready running 639s `-+- policy='service-time 0' prio=1 status=enabled 639s `- 4:0:0:1 sde 8:64 active ready running 639s + date +UN-plug path 2 %H:%M:%S.%N 639s UN-plug path 2 05:02:31.712569502 639s + iscsiadm --mode session -r 2 -u 639s Logging out of session [sid: 2, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 639s Logout of [sid: 2, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 639s + iscsiadm --mode session 639s tcp: [3] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 639s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 639s + sleep 10s 639s + date +MP report (expect 2) %H:%M:%S.%N 639s MP report (expect 2) 05:02:41.812232680 639s + multipath -ll 639s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 639s size=100M features='0' hwhandler='0' wp=rw 639s |-+- policy='service-time 0' prio=1 status=active 639s | `- 3:0:0:1 sdd 8:48 active ready running 639s `-+- policy='service-time 0' prio=1 status=enabled 639s `- 4:0:0:1 sde 8:64 active ready running 639s + date +UN-plug path 3 %H:%M:%S.%N 639s UN-plug path 3 05:02:41.830952455 639s + iscsiadm --mode session -r 3 -u 639s Logging out of session [sid: 3, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 639s Logout of [sid: 3, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 639s + iscsiadm --mode session 639s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 639s + sleep 10s 639s + date +MP report (expect 1) %H:%M:%S.%N 639s MP report (expect 1) 05:02:51.927057808 639s + multipath -ll 639s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 639s size=100M features='0' hwhandler='0' wp=rw 639s `-+- policy='service-time 0' prio=1 status=active 639s `- 4:0:0:1 sde 8:64 active ready running 639s + date +Add paths 5/6/7/8 %H:%M:%S.%N 639s Add paths 5/6/7/8 05:02:51.944729471 639s + iscsiadm --mode session -r 4 --op new 639s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 639s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 639s + iscsiadm --mode session -r 4 --op new 639s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 639s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 639s + iscsiadm --mode session -r 4 --op new 639s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 639s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 639s + iscsiadm --mode session -r 4 --op new 639s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 639s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 639s + iscsiadm --mode session 639s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 639s tcp: [5] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 639s tcp: [6] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 639s tcp: [7] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 639s tcp: [8] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 639s + sleep 10s 639s + date +MP report (expect 5) %H:%M:%S.%N 639s MP report (expect 5) 05:03:02.069969846 639s + multipath -ll 639s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 639s size=100M features='0' hwhandler='0' wp=rw 639s |-+- policy='service-time 0' prio=1 status=active 639s | `- 4:0:0:1 sde 8:64 active ready running 639s |-+- policy='service-time 0' prio=1 status=enabled 639s | `- 1:0:0:1 sdb 8:16 active ready running 639s |-+- policy='service-time 0' prio=1 status=enabled 639s | `- 2:0:0:1 sdc 8:32 active ready running 639s |-+- policy='service-time 0' prio=1 status=enabled 639s | `- 3:0:0:1 sdd 8:48 active ready running 639s `-+- policy='service-time 0' prio=1 status=enabled 639s `- 5:0:0:1 sdf 8:80 active ready running 639s + date +UN-plug multiple paths 4/7/8 %H:%M:%S.%N 639s UN-plug multiple paths 4/7/8 05:03:02.103527599 639s + iscsiadm --mode session -r 4 -u 639s Logging out of session [sid: 4, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 639s Logout of [sid: 4, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 639s + iscsiadm --mode session -r 7 -u 639s Logging out of session [sid: 7, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 639s Logout of [sid: 7, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 639s + iscsiadm --mode session -r 8 -u 639s Logging out of session [sid: 8, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 639s Logout of [sid: 8, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 639s + iscsiadm --mode session 639s tcp: [5] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 639s tcp: [6] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 639s + sleep 10s 639s + date +Restart multipath daemon %H:%M:%S.%N 639s Restart multipath daemon 05:03:12.325234978 639s + systemctl restart multipathd 639s + sleep 10s 639s + date +Final background report (expect 2) %H:%M:%S.%N 639s Final background report (expect 2) 05:03:22.411611803 639s + multipath -ll 639s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 639s size=100M features='0' hwhandler='0' wp=rw 639s |-+- policy='service-time 0' prio=1 status=active 639s | `- 1:0:0:1 sdb 8:16 active ready running 639s `-+- policy='service-time 0' prio=1 status=enabled 639s `- 2:0:0:1 sdc 8:32 active ready running 639s Final stats 639s Stats for session [sid: 5, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 639s iSCSI SNMP: 639s txdata_octets: 22017432 639s rxdata_octets: 30038084100 639s noptx_pdus: 0 639s scsicmd_pdus: 458429 639s tmfcmd_pdus: 0 639s login_pdus: 0 639s text_pdus: 0 639s dataout_pdus: 0 639s logout_pdus: 0 639s snack_pdus: 0 639s noprx_pdus: 0 639s scsirsp_pdus: 458429 639s tmfrsp_pdus: 0 639s textrsp_pdus: 0 639s datain_pdus: 458395 639s logoutrsp_pdus: 0 639s r2t_pdus: 0 639s async_pdus: 0 639s rjt_pdus: 0 639s digest_err: 0 639s timeout_err: 0 639s iSCSI Extended: 639s tx_sendpage_failures: 0 639s rx_discontiguous_hdr: 0 639s eh_abort_cnt: 0 639s Stats for session [sid: 6, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 639s iSCSI SNMP: 639s txdata_octets: 6504 639s rxdata_octets: 1514964 639s noptx_pdus: 0 639s scsicmd_pdus: 106 639s tmfcmd_pdus: 0 639s login_pdus: 0 639s text_pdus: 0 639s dataout_pdus: 0 639s logout_pdus: 0 639s snack_pdus: 0 639s noprx_pdus: 0 639s scsirsp_pdus: 106 639s tmfrsp_pdus: 0 639s textrsp_pdus: 0 639s datain_pdus: 83 639s logoutrsp_pdus: 0 639s r2t_pdus: 0 639s async_pdus: 0 639s rjt_pdus: 0 639s digest_err: 0 639s timeout_err: 0 639s iSCSI Extended: 639s tx_sendpage_failures: 0 639s rx_discontiguous_hdr: 0 639s eh_abort_cnt: 0 639s Apr 19 17:06:48 ubuntu systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 639s Apr 19 17:06:48 ubuntu multipathd[326]: multipathd v0.9.4: start up 639s Apr 19 17:06:48 ubuntu multipathd[326]: reconfigure: setting up paths and maps 639s Apr 19 17:06:48 ubuntu systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 639s Apr 19 17:09:48 auto-syncubuntu-noble-daily-ppc64el-server-20240416-disk1 multipathd[326]: multipathd: shut down 639s Apr 19 17:09:48 auto-syncubuntu-noble-daily-ppc64el-server-20240416-disk1 systemd[1]: Stopping multipathd.service - Device-Mapper Multipath Device Controller... 639s Apr 19 17:09:48 auto-syncubuntu-noble-daily-ppc64el-server-20240416-disk1 systemd[1]: multipathd.service: Deactivated successfully. 639s Apr 19 17:09:48 auto-syncubuntu-noble-daily-ppc64el-server-20240416-disk1 systemd[1]: Stopped multipathd.service - Device-Mapper Multipath Device Controller. 639s -- Boot a8846aa352cb4d7e962b6076db740ad2 -- 639s Apr 19 17:10:14 auto-syncubuntu-noble-daily-ppc64el-server-20240416-disk1 systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 639s Apr 19 17:10:14 auto-syncubuntu-noble-daily-ppc64el-server-20240416-disk1 multipathd[276]: multipathd v0.9.4: start up 639s Apr 19 17:10:14 auto-syncubuntu-noble-daily-ppc64el-server-20240416-disk1 multipathd[276]: reconfigure: setting up paths and maps 639s Apr 19 17:10:14 auto-syncubuntu-noble-daily-ppc64el-server-20240416-disk1 systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 639s Apr 19 17:10:33 auto-syncubuntu-noble-daily-ppc64el-server-20240416-disk1 multipathd[276]: multipathd: shut down 639s Apr 19 17:10:33 auto-syncubuntu-noble-daily-ppc64el-server-20240416-disk1 systemd[1]: Stopping multipathd.service - Device-Mapper Multipath Device Controller... 639s Apr 19 17:10:33 auto-syncubuntu-noble-daily-ppc64el-server-20240416-disk1 systemd[1]: multipathd.service: Deactivated successfully. 639s Apr 19 17:10:33 auto-syncubuntu-noble-daily-ppc64el-server-20240416-disk1 systemd[1]: Stopped multipathd.service - Device-Mapper Multipath Device Controller. 639s -- Boot 644678bd5dc9445fb8a59fa572b3ab6d -- 639s Apr 20 04:58:46 auto-syncubuntu-noble-daily-ppc64el-server-20240416-disk1 systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 639s Apr 20 04:58:46 auto-syncubuntu-noble-daily-ppc64el-server-20240416-disk1 multipathd[327]: multipathd v0.9.4: start up 639s Apr 20 04:58:46 auto-syncubuntu-noble-daily-ppc64el-server-20240416-disk1 multipathd[327]: reconfigure: setting up paths and maps 639s Apr 20 04:58:46 auto-syncubuntu-noble-daily-ppc64el-server-20240416-disk1 systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 639s Apr 20 05:00:52 autopkgtest systemd[1]: Stopping multipathd.service - Device-Mapper Multipath Device Controller... 639s Apr 20 05:00:52 autopkgtest multipathd[327]: multipathd: shut down 639s Apr 20 05:00:52 autopkgtest systemd[1]: multipathd.service: Deactivated successfully. 639s Apr 20 05:00:52 autopkgtest systemd[1]: Stopped multipathd.service - Device-Mapper Multipath Device Controller. 639s -- Boot 5bdd483c91b64c6e9968d2c1cd94d32d -- 639s Apr 20 05:01:19 autopkgtest multipathd[310]: multipathd v0.9.4: start up 639s Apr 20 05:01:19 autopkgtest multipathd[310]: reconfigure: setting up paths and maps 639s Apr 20 05:01:19 autopkgtest systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 639s Apr 20 05:02:02 autopkgtest multipathd[310]: mpatha: addmap [0 204800 multipath 0 0 2 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:32 1] 639s Apr 20 05:02:02 autopkgtest multipathd[310]: sdc [8:32]: path added to devmap mpatha 639s Apr 20 05:02:02 autopkgtest multipathd[310]: mpatha: performing delayed actions 639s Apr 20 05:02:02 autopkgtest multipathd[310]: mpatha: reload [0 204800 multipath 0 0 4 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:64 1] 639s Apr 20 05:02:21 autopkgtest multipathd[310]: 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] 639s Apr 20 05:02:21 autopkgtest multipathd[310]: check_removed_paths: sdb: freeing path in removed state 639s Apr 20 05:02:21 autopkgtest multipathd[310]: 8:16: path removed from map mpatha 639s Apr 20 05:02:31 autopkgtest multipathd[310]: 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] 639s Apr 20 05:02:31 autopkgtest multipathd[310]: check_removed_paths: sdc: freeing path in removed state 639s Apr 20 05:02:31 autopkgtest multipathd[310]: 8:32: path removed from map mpatha 639s Apr 20 05:02:41 autopkgtest multipathd[310]: mpatha: reload [0 204800 multipath 0 0 1 1 service-time 0 1 1 8:64 1] 639s Apr 20 05:02:41 autopkgtest multipathd[310]: check_removed_paths: sdd: freeing path in removed state 639s Apr 20 05:02:41 autopkgtest multipathd[310]: 8:48: path removed from map mpatha 639s Apr 20 05:02:52 autopkgtest multipathd[310]: 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] 639s Apr 20 05:02:52 autopkgtest multipathd[310]: sdb [8:16]: path added to devmap mpatha 639s Apr 20 05:02:52 autopkgtest multipathd[310]: 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] 639s Apr 20 05:02:52 autopkgtest multipathd[310]: sdc [8:32]: path added to devmap mpatha 639s Apr 20 05:02:52 autopkgtest multipathd[310]: 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] 639s Apr 20 05:02:52 autopkgtest multipathd[310]: sdd [8:48]: path added to devmap mpatha 639s Apr 20 05:02:52 autopkgtest multipathd[310]: 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] 639s Apr 20 05:02:52 autopkgtest multipathd[310]: sdf [8:80]: path added to devmap mpatha 639s Apr 20 05:03:02 autopkgtest multipathd[310]: 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] 639s Apr 20 05:03:02 autopkgtest multipathd[310]: check_removed_paths: sde: freeing path in removed state 639s Apr 20 05:03:02 autopkgtest multipathd[310]: 8:64: path removed from map mpatha 639s Apr 20 05:03:02 autopkgtest multipathd[310]: 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] 639s Apr 20 05:03:02 autopkgtest multipathd[310]: check_removed_paths: sdd: freeing path in removed state 639s Apr 20 05:03:02 autopkgtest multipathd[310]: 8:48: path removed from map mpatha 639s Apr 20 05:03:02 autopkgtest multipathd[310]: 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] 639s Apr 20 05:03:02 autopkgtest multipathd[310]: check_removed_paths: sdf: freeing path in removed state 639s Apr 20 05:03:02 autopkgtest multipathd[310]: 8:80: path removed from map mpatha 639s Apr 20 05:03:12 autopkgtest multipathd[310]: multipathd: shut down 639s Apr 20 05:03:12 autopkgtest systemd[1]: Stopping multipathd.service - Device-Mapper Multipath Device Controller... 639s Apr 20 05:03:12 autopkgtest systemd[1]: multipathd.service: Deactivated successfully. 639s Apr 20 05:03:12 autopkgtest systemd[1]: Stopped multipathd.service - Device-Mapper Multipath Device Controller. 639s Apr 20 05:03:12 autopkgtest systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 639s Apr 20 05:03:12 autopkgtest multipathd[5980]: multipathd v0.9.4: start up 639s Apr 20 05:03:12 autopkgtest multipathd[5980]: reconfigure: setting up paths and maps 639s Apr 20 05:03:12 autopkgtest systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 639s Check final path status 639s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 639s size=100M features='0' hwhandler='0' wp=rw 639s |-+- policy='service-time 0' prio=1 status=active 639s | `- 1:0:0:1 sdb 8:16 active ready running 639s `-+- policy='service-time 0' prio=1 status=enabled 639s `- 2:0:0:1 sdc 8:32 active ready running 639s + diska=1 639s + multipath -ll 639s + grep --count status=enabled 639s OK 639s + diske=1 639s + [ 2 -ne 2 -o 1 -ne 1 -o 1 -ne 1 ] 639s + echo OK 639s + iscsiadm --mode node --targetname iqn.2016-11.foo.com:target.iscsi --portal 127.0.0.1:3260 --logout 640s Logging out of session [sid: 5, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 640s Logging out of session [sid: 6, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 640s Logout of [sid: 5, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 640s Logout of [sid: 6, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 640s + tgtadm --lld iscsi --op delete --mode logicalunit --tid 1 --lun 1 640s autopkgtest [05:05:12]: test tgtbasedmpaths: -----------------------] 640s tgtbasedmpaths PASS 640s autopkgtest [05:05:12]: test tgtbasedmpaths: - - - - - - - - - - results - - - - - - - - - - 641s autopkgtest [05:05:13]: @@@@@@@@@@@@@@@@@@@@ summary 641s kpartx-file-loopback PASS 641s tgtbasedmpaths PASS 652s Creating nova instance adt-noble-ppc64el-multipath-tools-20240420-045432-juju-7f2275-prod-proposed-migration-environment-3-55b286b2-febc-4433-9450-972889da9387 from image adt/ubuntu-noble-ppc64el-server-20240419.img (UUID b7a0af62-4a88-423a-a98e-eb9a30e958ea)... 652s Creating nova instance adt-noble-ppc64el-multipath-tools-20240420-045432-juju-7f2275-prod-proposed-migration-environment-3-55b286b2-febc-4433-9450-972889da9387 from image adt/ubuntu-noble-ppc64el-server-20240419.img (UUID b7a0af62-4a88-423a-a98e-eb9a30e958ea)...