0s autopkgtest [10:36:23]: starting date and time: 2024-04-03 10:36:23+0000 0s autopkgtest [10:36:23]: git checkout: 31124158 autopkgtest: take Paride's WIP change regarding wrong src pkg selection 0s autopkgtest [10:36:23]: host juju-7f2275-prod-proposed-migration-environment-3; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.ek_78h6z/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:initramfs-tools --apt-upgrade multipath-tools --timeout-short=300 --timeout-copy=20000 --timeout-test=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=initramfs-tools/0.136ubuntu6.8 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest-big --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-3@bos01-s390x-13.secgroup --name adt-focal-s390x-multipath-tools-20240403-103623-juju-7f2275-prod-proposed-migration-environment-3-1a526e0d-1a3a-4bbe-95c7-ac217e3078a9 --image adt/ubuntu-focal-s390x-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://us.ports.ubuntu.com/ubuntu-ports/ 376s autopkgtest [10:42:39]: testbed dpkg architecture: s390x 376s autopkgtest [10:42:39]: testbed apt version: 2.0.10 376s autopkgtest [10:42:39]: @@@@@@@@@@@@@@@@@@@@ test bed setup 377s Get:1 http://ftpmaster.internal/ubuntu focal-proposed InRelease [267 kB] 377s Get:2 http://ftpmaster.internal/ubuntu focal-proposed/main Sources [72.0 kB] 377s Get:3 http://ftpmaster.internal/ubuntu focal-proposed/restricted Sources [19.7 kB] 377s Get:4 http://ftpmaster.internal/ubuntu focal-proposed/universe Sources [14.2 kB] 377s Get:5 http://ftpmaster.internal/ubuntu focal-proposed/main s390x Packages [125 kB] 377s Get:6 http://ftpmaster.internal/ubuntu focal-proposed/main s390x c-n-f Metadata [1580 B] 377s Get:7 http://ftpmaster.internal/ubuntu focal-proposed/restricted s390x Packages [1188 B] 377s Get:8 http://ftpmaster.internal/ubuntu focal-proposed/restricted s390x c-n-f Metadata [116 B] 377s Get:9 http://ftpmaster.internal/ubuntu focal-proposed/universe s390x Packages [43.0 kB] 377s Get:10 http://ftpmaster.internal/ubuntu focal-proposed/universe s390x c-n-f Metadata [2316 B] 377s Get:11 http://ftpmaster.internal/ubuntu focal-proposed/multiverse s390x c-n-f Metadata [116 B] 379s Fetched 546 kB in 1s (565 kB/s) 379s Reading package lists... 382s Reading package lists... 382s Building dependency tree... 382s Reading state information... 382s Calculating upgrade... 382s The following packages will be upgraded: 382s initramfs-tools initramfs-tools-bin initramfs-tools-core 382s 3 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 382s Need to get 67.5 kB of archives. 382s After this operation, 0 B of additional disk space will be used. 382s Get:1 http://ftpmaster.internal/ubuntu focal-proposed/main s390x initramfs-tools all 0.136ubuntu6.8 [9212 B] 382s Get:2 http://ftpmaster.internal/ubuntu focal-proposed/main s390x initramfs-tools-core all 0.136ubuntu6.8 [47.8 kB] 383s Get:3 http://ftpmaster.internal/ubuntu focal-proposed/main s390x initramfs-tools-bin s390x 0.136ubuntu6.8 [10.5 kB] 383s Fetched 67.5 kB in 1s (130 kB/s) 383s (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 ... 71235 files and directories currently installed.) 383s Preparing to unpack .../initramfs-tools_0.136ubuntu6.8_all.deb ... 383s Unpacking initramfs-tools (0.136ubuntu6.8) over (0.136ubuntu6.7) ... 383s Preparing to unpack .../initramfs-tools-core_0.136ubuntu6.8_all.deb ... 383s Unpacking initramfs-tools-core (0.136ubuntu6.8) over (0.136ubuntu6.7) ... 383s Preparing to unpack .../initramfs-tools-bin_0.136ubuntu6.8_s390x.deb ... 383s Unpacking initramfs-tools-bin (0.136ubuntu6.8) over (0.136ubuntu6.7) ... 383s Setting up initramfs-tools-bin (0.136ubuntu6.8) ... 383s Setting up initramfs-tools-core (0.136ubuntu6.8) ... 383s Setting up initramfs-tools (0.136ubuntu6.8) ... 383s update-initramfs: deferring update (trigger activated) 383s Processing triggers for man-db (2.9.1-1) ... 383s Processing triggers for initramfs-tools (0.136ubuntu6.8) ... 383s update-initramfs: Generating /boot/initrd.img-5.4.0-174-generic 389s Using config file '/etc/zipl.conf' 389s Building bootmap in '/boot' 389s Adding IPL section 'ubuntu' (default) 389s Preparing boot device: vda (0000). 389s Done. 390s Reading package lists... 390s Building dependency tree... 390s Reading state information... 390s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 391s Hit:1 http://ftpmaster.internal/ubuntu focal InRelease 391s Hit:2 http://ftpmaster.internal/ubuntu focal-updates InRelease 391s Hit:3 http://ftpmaster.internal/ubuntu focal-security InRelease 391s Hit:4 http://ftpmaster.internal/ubuntu focal-proposed InRelease 392s Reading package lists... 392s Reading package lists... 392s Building dependency tree... 392s Reading state information... 392s Calculating upgrade... 393s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 393s Reading package lists... 393s Building dependency tree... 393s Reading state information... 393s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 393s autopkgtest [10:42:56]: rebooting testbed after setup commands that affected boot 427s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 433s autopkgtest [10:43:36]: testbed running kernel: Linux 5.4.0-174-generic #193-Ubuntu SMP Thu Mar 7 14:28:54 UTC 2024 437s autopkgtest [10:43:40]: @@@@@@@@@@@@@@@@@@@@ apt-source multipath-tools 443s Get:1 http://ftpmaster.internal/ubuntu focal-updates/main multipath-tools 0.8.3-1ubuntu2.3 (dsc) [2882 B] 443s Get:2 http://ftpmaster.internal/ubuntu focal-updates/main multipath-tools 0.8.3-1ubuntu2.3 (tar) [465 kB] 443s Get:3 http://ftpmaster.internal/ubuntu focal-updates/main multipath-tools 0.8.3-1ubuntu2.3 (diff) [53.9 kB] 443s gpgv: Signature made Tue Nov 7 21:58:20 2023 UTC 443s gpgv: using RSA key 8F8D83B5270649A080648255EAF23F4A0BD34BF0 443s gpgv: issuer "mfo@canonical.com" 443s gpgv: Can't check signature: No public key 443s dpkg-source: warning: failed to verify signature on ./multipath-tools_0.8.3-1ubuntu2.3.dsc 443s autopkgtest [10:43:46]: testing package multipath-tools version 0.8.3-1ubuntu2.3 445s autopkgtest [10:43:48]: build not needed 448s autopkgtest [10:43:51]: test kpartx-file-loopback: preparing testbed 452s Reading package lists... 452s Building dependency tree... 452s Reading state information... 452s Starting pkgProblemResolver with broken count: 0 452s Starting 2 pkgProblemResolver with broken count: 0 452s Done 452s The following additional packages will be installed: 452s libatomic1 libboost-iostreams1.71.0 libboost-thread1.71.0 libibverbs1 452s libiscsi7 libnl-route-3-200 librados2 librbd1 librdmacm1 qemu-block-extra 452s qemu-utils 452s Suggested packages: 452s debootstrap 452s Recommended packages: 452s ibverbs-providers sharutils 452s The following NEW packages will be installed: 452s autopkgtest-satdep libatomic1 libboost-iostreams1.71.0 libboost-thread1.71.0 452s libibverbs1 libiscsi7 libnl-route-3-200 librados2 librbd1 librdmacm1 452s qemu-block-extra qemu-utils 452s 0 upgraded, 12 newly installed, 0 to remove and 0 not upgraded. 452s Need to get 6042 kB/6043 kB of archives. 452s After this operation, 32.5 MB of additional disk space will be used. 452s Get:1 /tmp/autopkgtest.bKMOuX/1-autopkgtest-satdep.deb autopkgtest-satdep s390x 0 [720 B] 453s Get:2 http://ftpmaster.internal/ubuntu focal-updates/main s390x libatomic1 s390x 10.5.0-1ubuntu1~20.04 [8524 B] 453s Get:3 http://ftpmaster.internal/ubuntu focal/main s390x libboost-iostreams1.71.0 s390x 1.71.0-6ubuntu6 [236 kB] 453s Get:4 http://ftpmaster.internal/ubuntu focal/main s390x libboost-thread1.71.0 s390x 1.71.0-6ubuntu6 [245 kB] 453s Get:5 http://ftpmaster.internal/ubuntu focal-updates/main s390x libnl-route-3-200 s390x 3.4.0-1ubuntu0.1 [136 kB] 453s Get:6 http://ftpmaster.internal/ubuntu focal/main s390x libibverbs1 s390x 28.0-1ubuntu1 [51.1 kB] 453s Get:7 http://ftpmaster.internal/ubuntu focal/main s390x librdmacm1 s390x 28.0-1ubuntu1 [65.4 kB] 453s Get:8 http://ftpmaster.internal/ubuntu focal/main s390x libiscsi7 s390x 1.18.0-2 [60.0 kB] 454s Get:9 http://ftpmaster.internal/ubuntu focal-updates/main s390x librados2 s390x 15.2.17-0ubuntu0.20.04.6 [2890 kB] 455s Get:10 http://ftpmaster.internal/ubuntu focal-updates/main s390x librbd1 s390x 15.2.17-0ubuntu0.20.04.6 [1419 kB] 455s Get:11 http://ftpmaster.internal/ubuntu focal-updates/main s390x qemu-block-extra s390x 1:4.2-3ubuntu6.28 [50.1 kB] 455s Get:12 http://ftpmaster.internal/ubuntu focal-updates/main s390x qemu-utils s390x 1:4.2-3ubuntu6.28 [881 kB] 456s Fetched 6042 kB in 3s (1890 kB/s) 456s Selecting previously unselected package libatomic1:s390x. 456s (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 ... 71235 files and directories currently installed.) 456s Preparing to unpack .../00-libatomic1_10.5.0-1ubuntu1~20.04_s390x.deb ... 456s Unpacking libatomic1:s390x (10.5.0-1ubuntu1~20.04) ... 456s Selecting previously unselected package libboost-iostreams1.71.0:s390x. 456s Preparing to unpack .../01-libboost-iostreams1.71.0_1.71.0-6ubuntu6_s390x.deb ... 456s Unpacking libboost-iostreams1.71.0:s390x (1.71.0-6ubuntu6) ... 456s Selecting previously unselected package libboost-thread1.71.0:s390x. 456s Preparing to unpack .../02-libboost-thread1.71.0_1.71.0-6ubuntu6_s390x.deb ... 456s Unpacking libboost-thread1.71.0:s390x (1.71.0-6ubuntu6) ... 456s Selecting previously unselected package libnl-route-3-200:s390x. 456s Preparing to unpack .../03-libnl-route-3-200_3.4.0-1ubuntu0.1_s390x.deb ... 456s Unpacking libnl-route-3-200:s390x (3.4.0-1ubuntu0.1) ... 456s Selecting previously unselected package libibverbs1:s390x. 456s Preparing to unpack .../04-libibverbs1_28.0-1ubuntu1_s390x.deb ... 456s Unpacking libibverbs1:s390x (28.0-1ubuntu1) ... 456s Selecting previously unselected package librdmacm1:s390x. 456s Preparing to unpack .../05-librdmacm1_28.0-1ubuntu1_s390x.deb ... 456s Unpacking librdmacm1:s390x (28.0-1ubuntu1) ... 456s Selecting previously unselected package libiscsi7:s390x. 456s Preparing to unpack .../06-libiscsi7_1.18.0-2_s390x.deb ... 456s Unpacking libiscsi7:s390x (1.18.0-2) ... 456s Selecting previously unselected package librados2. 456s Preparing to unpack .../07-librados2_15.2.17-0ubuntu0.20.04.6_s390x.deb ... 456s Unpacking librados2 (15.2.17-0ubuntu0.20.04.6) ... 457s Selecting previously unselected package librbd1. 457s Preparing to unpack .../08-librbd1_15.2.17-0ubuntu0.20.04.6_s390x.deb ... 457s Unpacking librbd1 (15.2.17-0ubuntu0.20.04.6) ... 457s Selecting previously unselected package qemu-block-extra:s390x. 457s Preparing to unpack .../09-qemu-block-extra_1%3a4.2-3ubuntu6.28_s390x.deb ... 457s Unpacking qemu-block-extra:s390x (1:4.2-3ubuntu6.28) ... 457s Selecting previously unselected package qemu-utils. 457s Preparing to unpack .../10-qemu-utils_1%3a4.2-3ubuntu6.28_s390x.deb ... 457s Unpacking qemu-utils (1:4.2-3ubuntu6.28) ... 457s Selecting previously unselected package autopkgtest-satdep. 457s Preparing to unpack .../11-1-autopkgtest-satdep.deb ... 457s Unpacking autopkgtest-satdep (0) ... 457s Setting up libboost-iostreams1.71.0:s390x (1.71.0-6ubuntu6) ... 457s Setting up libnl-route-3-200:s390x (3.4.0-1ubuntu0.1) ... 457s Setting up libatomic1:s390x (10.5.0-1ubuntu1~20.04) ... 457s Setting up libboost-thread1.71.0:s390x (1.71.0-6ubuntu6) ... 457s Setting up libibverbs1:s390x (28.0-1ubuntu1) ... 457s Setting up librdmacm1:s390x (28.0-1ubuntu1) ... 457s Setting up librados2 (15.2.17-0ubuntu0.20.04.6) ... 457s Setting up librbd1 (15.2.17-0ubuntu0.20.04.6) ... 457s Setting up libiscsi7:s390x (1.18.0-2) ... 457s Setting up qemu-block-extra:s390x (1:4.2-3ubuntu6.28) ... 457s Setting up qemu-utils (1:4.2-3ubuntu6.28) ... 457s Setting up autopkgtest-satdep (0) ... 457s Processing triggers for man-db (2.9.1-1) ... 457s Processing triggers for libc-bin (2.31-0ubuntu9.14) ... 460s (Reading database ... 71308 files and directories currently installed.) 460s Removing autopkgtest-satdep (0) ... 461s autopkgtest [10:44:04]: test kpartx-file-loopback: [----------------------- 461s Formatting 'foo.img', fmt=raw size=20971520 462s Creating new GPT entries in memory. 462s Warning: The kernel is still using the old partition table. 462s The new table will be used at the next reboot or after you 462s run partprobe(8) or kpartx(8) 462s The operation has completed successfully. 462s add map loop0p1 (253:0): 0 38879 linear 7:0 2048 462s standard_filename: OK 462s del devmap : loop0p1 462s loop deleted : /dev/loop0 462s No devices found 462s standard_filename_cleanup: OK 462s Formatting 'fou du FaFa.img', fmt=raw size=20971520 463s Creating new GPT entries in memory. 463s Warning: The kernel is still using the old partition table. 463s The new table will be used at the next reboot or after you 463s run partprobe(8) or kpartx(8) 463s The operation has completed successfully. 463s add map loop0p1 (253:0): 0 38879 linear 7:0 2048 463s filename_with_spaces: OK 463s del devmap : loop0p1 463s loop deleted : /dev/loop0 463s No devices found 463s filename_with_spaces_cleanup: OK 464s autopkgtest [10:44:07]: test kpartx-file-loopback: -----------------------] 464s autopkgtest [10:44:07]: test kpartx-file-loopback: - - - - - - - - - - results - - - - - - - - - - 464s kpartx-file-loopback PASS 465s autopkgtest [10:44:08]: test tgtbasedmpaths: preparing testbed 1343s Creating nova instance adt-focal-s390x-multipath-tools-20240403-103623-juju-7f2275-prod-proposed-migration-environment-3-1a526e0d-1a3a-4bbe-95c7-ac217e3078a9 from image adt/ubuntu-focal-s390x-server-20240402.img (UUID c1bb6987-89e3-4d3b-9d03-9c84efaa0753)... 1343s Creating nova instance adt-focal-s390x-multipath-tools-20240403-103623-juju-7f2275-prod-proposed-migration-environment-3-1a526e0d-1a3a-4bbe-95c7-ac217e3078a9 from image adt/ubuntu-focal-s390x-server-20240402.img (UUID c1bb6987-89e3-4d3b-9d03-9c84efaa0753)... 1343s nova boot failed (attempt #1): 1343s DEBUG (extension:189) found extension EntryPoint.parse('v1password = swiftclient.authv1:PasswordLoader') 1343s DEBUG (extension:189) found extension EntryPoint.parse('noauth = cinderclient.contrib.noauth:CinderNoAuthLoader') 1343s DEBUG (extension:189) found extension EntryPoint.parse('admin_token = keystoneauth1.loading._plugins.admin_token:AdminToken') 1343s DEBUG (extension:189) found extension EntryPoint.parse('none = keystoneauth1.loading._plugins.noauth:NoAuth') 1343s DEBUG (extension:189) found extension EntryPoint.parse('password = keystoneauth1.loading._plugins.identity.generic:Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('token = keystoneauth1.loading._plugins.identity.generic:Token') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v2password = keystoneauth1.loading._plugins.identity.v2:Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v2token = keystoneauth1.loading._plugins.identity.v2:Token') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3adfspassword = keystoneauth1.extras._saml2._loading:ADFSPassword') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3applicationcredential = keystoneauth1.loading._plugins.identity.v3:ApplicationCredential') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3fedkerb = keystoneauth1.extras.kerberos._loading:MappedKerberos') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3kerberos = keystoneauth1.extras.kerberos._loading:Kerberos') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3multifactor = keystoneauth1.loading._plugins.identity.v3:MultiFactor') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oauth1 = keystoneauth1.extras.oauth1._loading:V3OAuth1') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcaccesstoken = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAccessToken') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcauthcode = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAuthorizationCode') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcclientcredentials = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectClientCredentials') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcpassword = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectPassword') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3password = keystoneauth1.loading._plugins.identity.v3:Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3samlpassword = keystoneauth1.extras._saml2._loading:Saml2Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3token = keystoneauth1.loading._plugins.identity.v3:Token') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3tokenlessauth = keystoneauth1.loading._plugins.identity.v3:TokenlessAuth') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3totp = keystoneauth1.loading._plugins.identity.v3:TOTP') 1343s DEBUG (session:517) REQ: curl -g -i -X GET http://keystone.infra.bos01.scalingstack:5000/v3/ -H "Accept: application/json" -H "User-Agent: nova keystoneauth1/4.0.0 python-requests/2.22.0 CPython/3.8.10" 1343s DEBUG (connectionpool:222) Starting new HTTP connection (1): keystone.infra.bos01.scalingstack:5000 1343s DEBUG (connectionpool:429) http://keystone.infra.bos01.scalingstack:5000 "GET /v3/ HTTP/1.1" 200 273 1343s DEBUG (session:548) RESP: [200] Connection: Keep-Alive Content-Length: 273 Content-Type: application/json Date: Wed, 03 Apr 2024 10:46:12 GMT Keep-Alive: timeout=5, max=100 Server: Apache/2.4.18 (Ubuntu) Vary: X-Auth-Token X-Distribution: Ubuntu x-openstack-request-id: req-d39cf56f-1e9b-4b40-8174-14bddbd9510c 1343s DEBUG (session:580) RESP BODY: {"version": {"status": "stable", "updated": "2018-02-28T00:00:00Z", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.identity-v3+json"}], "id": "v3.10", "links": [{"href": "http://keystone.infra.bos01.scalingstack:5000/v3/", "rel": "self"}]}} 1343s DEBUG (session:946) GET call to http://keystone.infra.bos01.scalingstack:5000/v3/ used request id req-d39cf56f-1e9b-4b40-8174-14bddbd9510c 1343s DEBUG (base:182) Making authentication request to http://keystone.infra.bos01.scalingstack:5000/v3/auth/tokens 1343s DEBUG (connectionpool:429) http://keystone.infra.bos01.scalingstack:5000 "POST /v3/auth/tokens HTTP/1.1" 201 4363 1343s DEBUG (base:187) {"token": {"is_domain": false, "methods": ["password"], "roles": [{"id": "9fe2ff9ee4384b1894a90878d3e92bab", "name": "_member_"}], "is_admin_project": false, "project": {"domain": {"id": "default", "name": "Default"}, "id": "3f3b771a247746688951a4c90bf16631", "name": "prod-proposed-migration_project"}, "catalog": [{"endpoints": [{"url": "http://10.189.0.40", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "7d31d2904b56461cb46c735fc00850b0"}, {"url": "http://10.189.0.40", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "931e03b1033c4992ac8d223599983801"}, {"url": "http://10.189.0.40", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "c703b3c5e7224cfd893f622a7def99d7"}], "type": "product-streams", "id": "6723640fcf314f1c84ab92b0b7b7d343", "name": "image-stream"}, {"endpoints": [{"url": "http://neutron-api.infra.bos01.scalingstack:9696", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "13475a253aba4a63883ad9da9631b1d3"}, {"url": "http://10.189.0.22:9696", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "63b2334803a742048e95cd48d39f1674"}, {"url": "http://10.189.0.22:9696", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "9d19ce3dbfd544ef90e7694049018957"}], "type": "network", "id": "6a80a28849da43ce9839207bb1e98bfc", "name": "neutron"}, {"endpoints": [{"url": "http://10.189.0.20:5000/v3", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "51d5e1cea07c4644b44a8bf114268a27"}, {"url": "http://10.189.0.20:35357/v3", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "79c780094b2f40e5a70ee3a6353760a0"}, {"url": "http://keystone.infra.bos01.scalingstack:5000/v3", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "9cdf3486e4a94ca0a181e87bc1ff344f"}], "type": "identity", "id": "ad3a88bc8df3470b938f685304ad3ae9", "name": "keystone"}, {"endpoints": [{"url": "http://nova-api.infra.bos01.scalingstack:8778", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "83e5577919844e47bbf3dffc39f71e5f"}, {"url": "http://10.189.0.23:8778", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "86cd7636126b4214a0c0de3c50936bb9"}, {"url": "http://10.189.0.23:8778", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "eb918cef1bd546fcaafc28133e511d6c"}], "type": "placement", "id": "af7144bdc8404803a159883c31910f75", "name": "placement"}, {"endpoints": [{"url": "http://10.189.0.23:8774/v2.1", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "202b55f38ce646fe8ec9e2b956672f07"}, {"url": "http://10.189.0.23:8774/v2.1", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "b29375d70fd748e699859503279177e3"}, {"url": "http://nova-api.infra.bos01.scalingstack:8774/v2.1", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "ff7b759bc23341fe911fedfc2cd9ae07"}], "type": "compute", "id": "e34360be9bc6484eb95832a381a2d650", "name": "nova"}, {"endpoints": [{"url": "http://glance.infra.bos01.scalingstack:9292", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "0bacddbfbda545f087dab7ef5745707d"}, {"url": "http://10.189.0.19:9292", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "0f69442c439d471b9761ccd46fc6ca2e"}, {"url": "http://10.189.0.19:9292", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "9cd58aadc9e94eea8783da595c3474f3"}], "type": "image", "id": "f29a943021f34b6682d21957ddc8acac", "name": "glance"}], "expires_at": "2024-04-03T11:46:13.000000Z", "user": {"password_expires_at": null, "domain": {"id": "default", "name": "Default"}, "id": "3afbd64474684647986f8a196316be34", "name": "prod-proposed-migration-s390x"}, "audit_ids": ["gKTakyTRSiGz0itlGX8Gaw"], "issued_at": "2024-04-03T10:46:13.000000Z"}} 1343s REQ: curl -g -i -X GET http://nova-api.infra.bos01.scalingstack:8774/v2.1 -H "Accept: application/json" -H "User-Agent: python-novaclient" -H "X-Auth-Token: {SHA256}114f79fda022886cc1f6154626eb9287ce7d716fab6c1ee2259935bef0a0fde8" 1343s DEBUG (session:517) REQ: curl -g -i -X GET http://nova-api.infra.bos01.scalingstack:8774/v2.1 -H "Accept: application/json" -H "User-Agent: python-novaclient" -H "X-AuCreating nova instance adt-focal-s390x-multipath-tools-20240403-103623-juju-7f2275-prod-proposed-migration-environment-3-1a526e0d-1a3a-4bbe-95c7-ac217e3078a9 from image adt/ubuntu-focal-s390x-server-20240402.img (UUID c1bb6987-89e3-4d3b-9d03-9c84efaa0753)... 1343s nova boot failed (attempt #1): 1343s DEBUG (extension:189) found extension EntryPoint.parse('v1password = swiftclient.authv1:PasswordLoader') 1343s DEBUG (extension:189) found extension EntryPoint.parse('noauth = cinderclient.contrib.noauth:CinderNoAuthLoader') 1343s DEBUG (extension:189) found extension EntryPoint.parse('admin_token = keystoneauth1.loading._plugins.admin_token:AdminToken') 1343s DEBUG (extension:189) found extension EntryPoint.parse('none = keystoneauth1.loading._plugins.noauth:NoAuth') 1343s DEBUG (extension:189) found extension EntryPoint.parse('password = keystoneauth1.loading._plugins.identity.generic:Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('token = keystoneauth1.loading._plugins.identity.generic:Token') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v2password = keystoneauth1.loading._plugins.identity.v2:Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v2token = keystoneauth1.loading._plugins.identity.v2:Token') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3adfspassword = keystoneauth1.extras._saml2._loading:ADFSPassword') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3applicationcredential = keystoneauth1.loading._plugins.identity.v3:ApplicationCredential') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3fedkerb = keystoneauth1.extras.kerberos._loading:MappedKerberos') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3kerberos = keystoneauth1.extras.kerberos._loading:Kerberos') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3multifactor = keystoneauth1.loading._plugins.identity.v3:MultiFactor') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oauth1 = keystoneauth1.extras.oauth1._loading:V3OAuth1') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcaccesstoken = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAccessToken') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcauthcode = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAuthorizationCode') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcclientcredentials = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectClientCredentials') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcpassword = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectPassword') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3password = keystoneauth1.loading._plugins.identity.v3:Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3samlpassword = keystoneauth1.extras._saml2._loading:Saml2Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3token = keystoneauth1.loading._plugins.identity.v3:Token') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3tokenlessauth = keystoneauth1.loading._plugins.identity.v3:TokenlessAuth') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3totp = keystoneauth1.loading._plugins.identity.v3:TOTP') 1343s DEBUG (session:517) REQ: curl -g -i -X GET http://keystone.infra.bos01.scalingstack:5000/v3/ -H "Accept: application/json" -H "User-Agent: nova keystoneauth1/4.0.0 python-requests/2.22.0 CPython/3.8.10" 1343s DEBUG (connectionpool:222) Starting new HTTP connection (1): keystone.infra.bos01.scalingstack:5000 1343s DEBUG (connectionpool:429) http://keystone.infra.bos01.scalingstack:5000 "GET /v3/ HTTP/1.1" 200 273 1343s DEBUG (session:548) RESP: [200] Connection: Keep-Alive Content-Length: 273 Content-Type: application/json Date: Wed, 03 Apr 2024 10:46:12 GMT Keep-Alive: timeout=5, max=100 Server: Apache/2.4.18 (Ubuntu) Vary: X-Auth-Token X-Distribution: Ubuntu x-openstack-request-id: req-d39cf56f-1e9b-4b40-8174-14bddbd9510c 1343s DEBUG (session:580) RESP BODY: {"version": {"status": "stable", "updated": "2018-02-28T00:00:00Z", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.identity-v3+json"}], "id": "v3.10", "links": [{"href": "http://keystone.infra.bos01.scalingstack:5000/v3/", "rel": "self"}]}} 1343s DEBUG (session:946) GET call to http://keystone.infra.bos01.scalingstack:5000/v3/ used request id req-d39cf56f-1e9b-4b40-8174-14bddbd9510c 1343s DEBUG (base:182) Making authentication request to http://keystone.infra.bos01.scalingstack:5000/v3/auth/tokens 1343s DEBUG (connectionpool:429) http://keystone.infra.bos01.scalingstack:5000 "POST /v3/auth/tokens HTTP/1.1" 201 4363 1343s DEBUG (base:187) {"token": {"is_domain": false, "methods": ["password"], "roles": [{"id": "9fe2ff9ee4384b1894a90878d3e92bab", "name": "_member_"}], "is_admin_project": false, "project": {"domain": {"id": "default", "name": "Default"}, "id": "3f3b771a247746688951a4c90bf16631", "name": "prod-proposed-migration_project"}, "catalog": [{"endpoints": [{"url": "http://10.189.0.40", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "7d31d2904b56461cb46c735fc00850b0"}, {"url": "http://10.189.0.40", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "931e03b1033c4992ac8d223599983801"}, {"url": "http://10.189.0.40", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "c703b3c5e7224cfd893f622a7def99d7"}], "type": "product-streams", "id": "6723640fcf314f1c84ab92b0b7b7d343", "name": "image-stream"}, {"endpoints": [{"url": "http://neutron-api.infra.bos01.scalingstack:9696", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "13475a253aba4a63883ad9da9631b1d3"}, {"url": "http://10.189.0.22:9696", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "63b2334803a742048e95cd48d39f1674"}, {"url": "http://10.189.0.22:9696", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "9d19ce3dbfd544ef90e7694049018957"}], "type": "network", "id": "6a80a28849da43ce9839207bb1e98bfc", "name": "neutron"}, {"endpoints": [{"url": "http://10.189.0.20:5000/v3", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "51d5e1cea07c4644b44a8bf114268a27"}, {"url": "http://10.189.0.20:35357/v3", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "79c780094b2f40e5a70ee3a6353760a0"}, {"url": "http://keystone.infra.bos01.scalingstack:5000/v3", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "9cdf3486e4a94ca0a181e87bc1ff344f"}], "type": "identity", "id": "ad3a88bc8df3470b938f685304ad3ae9", "name": "keystone"}, {"endpoints": [{"url": "http://nova-api.infra.bos01.scalingstack:8778", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "83e5577919844e47bbf3dffc39f71e5f"}, {"url": "http://10.189.0.23:8778", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "86cd7636126b4214a0c0de3c50936bb9"}, {"url": "http://10.189.0.23:8778", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "eb918cef1bd546fcaafc28133e511d6c"}], "type": "placement", "id": "af7144bdc8404803a159883c31910f75", "name": "placement"}, {"endpoints": [{"url": "http://10.189.0.23:8774/v2.1", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "202b55f38ce646fe8ec9e2b956672f07"}, {"url": "http://10.189.0.23:8774/v2.1", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "b29375d70fd748e699859503279177e3"}, {"url": "http://nova-api.infra.bos01.scalingstack:8774/v2.1", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "ff7b759bc23341fe911fedfc2cd9ae07"}], "type": "compute", "id": "e34360be9bc6484eb95832a381a2d650", "name": "nova"}, {"endpoints": [{"url": "http://glance.infra.bos01.scalingstack:9292", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstaCreating nova instance adt-focal-s390x-multipath-tools-20240403-103623-juju-7f2275-prod-proposed-migration-environment-3-1a526e0d-1a3a-4bbe-95c7-ac217e3078a9 from image adt/ubuntu-focal-s390x-server-20240402.img (UUID c1bb6987-89e3-4d3b-9d03-9c84efaa0753)... 1343s nova boot failed (attempt #1): 1343s DEBUG (extension:189) found extension EntryPoint.parse('v1password = swiftclient.authv1:PasswordLoader') 1343s DEBUG (extension:189) found extension EntryPoint.parse('noauth = cinderclient.contrib.noauth:CinderNoAuthLoader') 1343s DEBUG (extension:189) found extension EntryPoint.parse('admin_token = keystoneauth1.loading._plugins.admin_token:AdminToken') 1343s DEBUG (extension:189) found extension EntryPoint.parse('none = keystoneauth1.loading._plugins.noauth:NoAuth') 1343s DEBUG (extension:189) found extension EntryPoint.parse('password = keystoneauth1.loading._plugins.identity.generic:Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('token = keystoneauth1.loading._plugins.identity.generic:Token') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v2password = keystoneauth1.loading._plugins.identity.v2:Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v2token = keystoneauth1.loading._plugins.identity.v2:Token') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3adfspassword = keystoneauth1.extras._saml2._loading:ADFSPassword') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3applicationcredential = keystoneauth1.loading._plugins.identity.v3:ApplicationCredential') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3fedkerb = keystoneauth1.extras.kerberos._loading:MappedKerberos') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3kerberos = keystoneauth1.extras.kerberos._loading:Kerberos') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3multifactor = keystoneauth1.loading._plugins.identity.v3:MultiFactor') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oauth1 = keystoneauth1.extras.oauth1._loading:V3OAuth1') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcaccesstoken = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAccessToken') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcauthcode = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAuthorizationCode') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcclientcredentials = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectClientCredentials') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcpassword = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectPassword') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3password = keystoneauth1.loading._plugins.identity.v3:Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3samlpassword = keystoneauth1.extras._saml2._loading:Saml2Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3token = keystoneauth1.loading._plugins.identity.v3:Token') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3tokenlessauth = keystoneauth1.loading._plugins.identity.v3:TokenlessAuth') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3totp = keystoneauth1.loading._plugins.identity.v3:TOTP') 1343s DEBUG (session:517) REQ: curl -g -i -X GET http://keystone.infra.bos01.scalingstack:5000/v3/ -H "Accept: application/json" -H "User-Agent: nova keystoneauth1/4.0.0 python-requests/2.22.0 CPython/3.8.10" 1343s DEBUG (connectionpool:222) Starting new HTTP connection (1): keystone.infra.bos01.scalingstack:5000 1343s DEBUG (connectionpool:429) http://keystone.infra.bos01.scalingstack:5000 "GET /v3/ HTTP/1.1" 200 273 1343s DEBUG (session:548) RESP: [200] Connection: Keep-Alive Content-Length: 273 Content-Type: application/json Date: Wed, 03 Apr 2024 10:46:12 GMT Keep-Alive: timeout=5, max=100 Server: Apache/2.4.18 (Ubuntu) Vary: X-Auth-Token X-Distribution: Ubuntu x-openstack-request-id: req-d39cf56f-1e9b-4b40-8174-14bddbd9510c 1343s DEBUG (session:580) RESP BODY: {"version": {"status": "stable", "updated": "2018-02-28T00:00:00Z", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.identity-v3+json"}], "id": "v3.10", "links": [{"href": "http://keystone.infra.bos01.scalingstack:5000/v3/", "rel": "self"}]}} 1343s DEBUG (session:946) GET call to http://keystone.infra.bos01.scalingstack:5000/v3/ used request id req-d39cf56f-1e9b-4b40-8174-14bddbd9510c 1343s DEBUG (base:182) Making authentication request to http://keystone.infra.bos01.scalingstack:5000/v3/auth/tokens 1343s DEBUG (connectionpool:429) http://keystone.infra.bos01.scalingstack:5000 "POST /v3/auth/tokens HTTP/1.1" 201 4363 1343s DEBUG (base:187) {"token": {"is_domain": false, "methods": ["password"], "roles": [{"id": "9fe2ff9ee4384b1894a90878d3e92bab", "name": "_member_"}], "is_admin_project": false, "project": {"domain": {"id": "default", "name": "Default"}, "id": "3f3b771a247746688951a4c90bf16631", "name": "prod-proposed-migration_project"}, "catalog": [{"endpoints": [{"url": "http://10.189.0.40", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "7d31d2904b56461cb46c735fc00850b0"}, {"url": "http://10.189.0.40", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "931e03b1033c4992ac8d223599983801"}, {"url": "http://10.189.0.40", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "c703b3c5e7224cfd893f622a7def99d7"}], "type": "product-streams", "id": "6723640fcf314f1c84ab92b0b7b7d343", "name": "image-stream"}, {"endpoints": [{"url": "http://neutron-api.infra.bos01.scalingstack:9696", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "13475a253aba4a63883ad9da9631b1d3"}, {"url": "http://10.189.0.22:9696", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "63b2334803a742048e95cd48d39f1674"}, {"url": "http://10.189.0.22:9696", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "9d19ce3dbfd544ef90e7694049018957"}], "type": "network", "id": "6a80a28849da43ce9839207bb1e98bfc", "name": "neutron"}, {"endpoints": [{"url": "http://10.189.0.20:5000/v3", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "51d5e1cea07c4644b44a8bf114268a27"}, {"url": "http://10.189.0.20:35357/v3", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "79c780094b2f40e5a70ee3a6353760a0"}, {"url": "http://keystone.infra.bos01.scalingstack:5000/v3", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "9cdf3486e4a94ca0a181e87bc1ff344f"}], "type": "identity", "id": "ad3a88bc8df3470b938f685304ad3ae9", "name": "keystone"}, {"endpoints": [{"url": "http://nova-api.infra.bos01.scalingstack:8778", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "83e5577919844e47bbf3dffc39f71e5f"}, {"url": "http://10.189.0.23:8778", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "86cd7636126b4214a0c0de3c50936bb9"}, {"url": "http://10.189.0.23:8778", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "eb918cef1bd546fcaafc28133e511d6c"}], "type": "placement", "id": "af7144bdc8404803a159883c31910f75", "name": "placement"}, {"endpoints": [{"url": "http://10.189.0.23:8774/v2.1", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "202b55f38ce646fe8ec9e2b956672f07"}, {"url": "http://10.189.0.23:8774/v2.1", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "b29375d70fd748e699859503279177e3"}, {"url": "http://nova-api.infra.bos01.scalingstack:8774/v2.1", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "ff7b759bc23341fe911fedfc2cd9ae07"}], "type": "compute", "id": "e34360be9bc6484eb95832a381a2d650", "name": "nova"}, {"endpoints": [{"url": "http://glance.infra.bos01.scalingstack:9292", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstaCreating nova instance adt-focal-s390x-multipath-tools-20240403-103623-juju-7f2275-prod-proposed-migration-environment-3-1a526e0d-1a3a-4bbe-95c7-ac217e3078a9 from image adt/ubuntu-focal-s390x-server-20240402.img (UUID c1bb6987-89e3-4d3b-9d03-9c84efaa0753)... 1343s nova boot failed (attempt #1): 1343s DEBUG (extension:189) found extension EntryPoint.parse('v1password = swiftclient.authv1:PasswordLoader') 1343s DEBUG (extension:189) found extension EntryPoint.parse('noauth = cinderclient.contrib.noauth:CinderNoAuthLoader') 1343s DEBUG (extension:189) found extension EntryPoint.parse('admin_token = keystoneauth1.loading._plugins.admin_token:AdminToken') 1343s DEBUG (extension:189) found extension EntryPoint.parse('none = keystoneauth1.loading._plugins.noauth:NoAuth') 1343s DEBUG (extension:189) found extension EntryPoint.parse('password = keystoneauth1.loading._plugins.identity.generic:Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('token = keystoneauth1.loading._plugins.identity.generic:Token') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v2password = keystoneauth1.loading._plugins.identity.v2:Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v2token = keystoneauth1.loading._plugins.identity.v2:Token') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3adfspassword = keystoneauth1.extras._saml2._loading:ADFSPassword') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3applicationcredential = keystoneauth1.loading._plugins.identity.v3:ApplicationCredential') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3fedkerb = keystoneauth1.extras.kerberos._loading:MappedKerberos') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3kerberos = keystoneauth1.extras.kerberos._loading:Kerberos') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3multifactor = keystoneauth1.loading._plugins.identity.v3:MultiFactor') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oauth1 = keystoneauth1.extras.oauth1._loading:V3OAuth1') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcaccesstoken = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAccessToken') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcauthcode = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAuthorizationCode') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcclientcredentials = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectClientCredentials') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcpassword = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectPassword') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3password = keystoneauth1.loading._plugins.identity.v3:Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3samlpassword = keystoneauth1.extras._saml2._loading:Saml2Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3token = keystoneauth1.loading._plugins.identity.v3:Token') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3tokenlessauth = keystoneauth1.loading._plugins.identity.v3:TokenlessAuth') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3totp = keystoneauth1.loading._plugins.identity.v3:TOTP') 1343s DEBUG (session:517) REQ: curl -g -i -X GET http://keystone.infra.bos01.scalingstack:5000/v3/ -H "Accept: application/json" -H "User-Agent: nova keystoneauth1/4.0.0 python-requests/2.22.0 CPython/3.8.10" 1343s DEBUG (connectionpool:222) Starting new HTTP connection (1): keystone.infra.bos01.scalingstack:5000 1343s DEBUG (connectionpool:429) http://keystone.infra.bos01.scalingstack:5000 "GET /v3/ HTTP/1.1" 200 273 1343s DEBUG (session:548) RESP: [200] Connection: Keep-Alive Content-Length: 273 Content-Type: application/json Date: Wed, 03 Apr 2024 10:46:12 GMT Keep-Alive: timeout=5, max=100 Server: Apache/2.4.18 (Ubuntu) Vary: X-Auth-Token X-Distribution: Ubuntu x-openstack-request-id: req-d39cf56f-1e9b-4b40-8174-14bddbd9510c 1343s DEBUG (session:580) RESP BODY: {"version": {"status": "stable", "updated": "2018-02-28T00:00:00Z", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.identity-v3+json"}], "id": "v3.10", "links": [{"href": "http://keystone.infra.bos01.scalingstack:5000/v3/", "rel": "self"}]}} 1343s DEBUG (session:946) GET call to http://keystone.infra.bos01.scalingstack:5000/v3/ used request id req-d39cf56f-1e9b-4b40-8174-14bddbd9510c 1343s DEBUG (base:182) Making authentication request to http://keystone.infra.bos01.scalingstack:5000/v3/auth/tokens 1343s DEBUG (connectionpool:429) http://keystone.infra.bos01.scalingstack:5000 "POST /v3/auth/tokens HTTP/1.1" 201 4363 1343s DEBUG (base:187) {"token": {"is_domain": false, "methods": ["password"], "roles": [{"id": "9fe2ff9ee4384b1894a90878d3e92bab", "name": "_member_"}], "is_admin_project": false, "project": {"domain": {"id": "default", "name": "Default"}, "id": "3f3b771a247746688951a4c90bf16631", "name": "prod-proposed-migration_project"}, "catalog": [{"endpoints": [{"url": "http://10.189.0.40", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "7d31d2904b56461cb46c735fc00850b0"}, {"url": "http://10.189.0.40", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "931e03b1033c4992ac8d223599983801"}, {"url": "http://10.189.0.40", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "c703b3c5e7224cfd893f622a7def99d7"}], "type": "product-streams", "id": "6723640fcf314f1c84ab92b0b7b7d343", "name": "image-stream"}, {"endpoints": [{"url": "http://neutron-api.infra.bos01.scalingstack:9696", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "13475a253aba4a63883ad9da9631b1d3"}, {"url": "http://10.189.0.22:9696", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "63b2334803a742048e95cd48d39f1674"}, {"url": "http://10.189.0.22:9696", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "9d19ce3dbfd544ef90e7694049018957"}], "type": "network", "id": "6a80a28849da43ce9839207bb1e98bfc", "name": "neutron"}, {"endpoints": [{"url": "http://10.189.0.20:5000/v3", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "51d5e1cea07c4644b44a8bf114268a27"}, {"url": "http://10.189.0.20:35357/v3", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "79c780094b2f40e5a70ee3a6353760a0"}, {"url": "http://keystone.infra.bos01.scalingstack:5000/v3", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "9cdf3486e4a94ca0a181e87bc1ff344f"}], "type": "identity", "id": "ad3a88bc8df3470b938f685304ad3ae9", "name": "keystone"}, {"endpoints": [{"url": "http://nova-api.infra.bos01.scalingstack:8778", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "83e5577919844e47bbf3dffc39f71e5f"}, {"url": "http://10.189.0.23:8778", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "86cd7636126b4214a0c0de3c50936bb9"}, {"url": "http://10.189.0.23:8778", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "eb918cef1bd546fcaafc28133e511d6c"}], "type": "placement", "id": "af7144bdc8404803a159883c31910f75", "name": "placement"}, {"endpoints": [{"url": "http://10.189.0.23:8774/v2.1", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "202b55f38ce646fe8ec9e2b956672f07"}, {"url": "http://10.189.0.23:8774/v2.1", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "b29375d70fd748e699859503279177e3"}, {"url": "http://nova-api.infra.bos01.scalingstack:8774/v2.1", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "ff7b759bc23341fe911fedfc2cd9ae07"}], "type": "compute", "id": "e34360be9bc6484eb95832a381a2d650", "name": "nova"}, {"endpoints": [{"url": "http://glance.infra.bos01.scalingstack:9292", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstaCreating nova instance adt-focal-s390x-multipath-tools-20240403-103623-juju-7f2275-prod-proposed-migration-environment-3-1a526e0d-1a3a-4bbe-95c7-ac217e3078a9 from image adt/ubuntu-focal-s390x-server-20240402.img (UUID c1bb6987-89e3-4d3b-9d03-9c84efaa0753)... 1343s nova boot failed (attempt #1): 1343s DEBUG (extension:189) found extension EntryPoint.parse('v1password = swiftclient.authv1:PasswordLoader') 1343s DEBUG (extension:189) found extension EntryPoint.parse('noauth = cinderclient.contrib.noauth:CinderNoAuthLoader') 1343s DEBUG (extension:189) found extension EntryPoint.parse('admin_token = keystoneauth1.loading._plugins.admin_token:AdminToken') 1343s DEBUG (extension:189) found extension EntryPoint.parse('none = keystoneauth1.loading._plugins.noauth:NoAuth') 1343s DEBUG (extension:189) found extension EntryPoint.parse('password = keystoneauth1.loading._plugins.identity.generic:Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('token = keystoneauth1.loading._plugins.identity.generic:Token') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v2password = keystoneauth1.loading._plugins.identity.v2:Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v2token = keystoneauth1.loading._plugins.identity.v2:Token') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3adfspassword = keystoneauth1.extras._saml2._loading:ADFSPassword') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3applicationcredential = keystoneauth1.loading._plugins.identity.v3:ApplicationCredential') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3fedkerb = keystoneauth1.extras.kerberos._loading:MappedKerberos') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3kerberos = keystoneauth1.extras.kerberos._loading:Kerberos') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3multifactor = keystoneauth1.loading._plugins.identity.v3:MultiFactor') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oauth1 = keystoneauth1.extras.oauth1._loading:V3OAuth1') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcaccesstoken = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAccessToken') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcauthcode = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAuthorizationCode') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcclientcredentials = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectClientCredentials') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcpassword = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectPassword') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3password = keystoneauth1.loading._plugins.identity.v3:Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3samlpassword = keystoneauth1.extras._saml2._loading:Saml2Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3token = keystoneauth1.loading._plugins.identity.v3:Token') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3tokenlessauth = keystoneauth1.loading._plugins.identity.v3:TokenlessAuth') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3totp = keystoneauth1.loading._plugins.identity.v3:TOTP') 1343s DEBUG (session:517) REQ: curl -g -i -X GET http://keystone.infra.bos01.scalingstack:5000/v3/ -H "Accept: application/json" -H "User-Agent: nova keystoneauth1/4.0.0 python-requests/2.22.0 CPython/3.8.10" 1343s DEBUG (connectionpool:222) Starting new HTTP connection (1): keystone.infra.bos01.scalingstack:5000 1343s DEBUG (connectionpool:429) http://keystone.infra.bos01.scalingstack:5000 "GET /v3/ HTTP/1.1" 200 273 1343s DEBUG (session:548) RESP: [200] Connection: Keep-Alive Content-Length: 273 Content-Type: application/json Date: Wed, 03 Apr 2024 10:46:12 GMT Keep-Alive: timeout=5, max=100 Server: Apache/2.4.18 (Ubuntu) Vary: X-Auth-Token X-Distribution: Ubuntu x-openstack-request-id: req-d39cf56f-1e9b-4b40-8174-14bddbd9510c 1343s DEBUG (session:580) RESP BODY: {"version": {"status": "stable", "updated": "2018-02-28T00:00:00Z", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.identity-v3+json"}], "id": "v3.10", "links": [{"href": "http://keystone.infra.bos01.scalingstack:5000/v3/", "rel": "self"}]}} 1343s DEBUG (session:946) GET call to http://keystone.infra.bos01.scalingstack:5000/v3/ used request id req-d39cf56f-1e9b-4b40-8174-14bddbd9510c 1343s DEBUG (base:182) Making authentication request to http://keystone.infra.bos01.scalingstack:5000/v3/auth/tokens 1343s DEBUG (connectionpool:429) http://keystone.infra.bos01.scalingstack:5000 "POST /v3/auth/tokens HTTP/1.1" 201 4363 1343s DEBUG (base:187) {"token": {"is_domain": false, "methods": ["password"], "roles": [{"id": "9fe2ff9ee4384b1894a90878d3e92bab", "name": "_member_"}], "is_admin_project": false, "project": {"domain": {"id": "default", "name": "Default"}, "id": "3f3b771a247746688951a4c90bf16631", "name": "prod-proposed-migration_project"}, "catalog": [{"endpoints": [{"url": "http://10.189.0.40", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "7d31d2904b56461cb46c735fc00850b0"}, {"url": "http://10.189.0.40", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "931e03b1033c4992ac8d223599983801"}, {"url": "http://10.189.0.40", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "c703b3c5e7224cfd893f622a7def99d7"}], "type": "product-streams", "id": "6723640fcf314f1c84ab92b0b7b7d343", "name": "image-stream"}, {"endpoints": [{"url": "http://neutron-api.infra.bos01.scalingstack:9696", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "13475a253aba4a63883ad9da9631b1d3"}, {"url": "http://10.189.0.22:9696", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "63b2334803a742048e95cd48d39f1674"}, {"url": "http://10.189.0.22:9696", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "9d19ce3dbfd544ef90e7694049018957"}], "type": "network", "id": "6a80a28849da43ce9839207bb1e98bfc", "name": "neutron"}, {"endpoints": [{"url": "http://10.189.0.20:5000/v3", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "51d5e1cea07c4644b44a8bf114268a27"}, {"url": "http://10.189.0.20:35357/v3", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "79c780094b2f40e5a70ee3a6353760a0"}, {"url": "http://keystone.infra.bos01.scalingstack:5000/v3", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "9cdf3486e4a94ca0a181e87bc1ff344f"}], "type": "identity", "id": "ad3a88bc8df3470b938f685304ad3ae9", "name": "keystone"}, {"endpoints": [{"url": "http://nova-api.infra.bos01.scalingstack:8778", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "83e5577919844e47bbf3dffc39f71e5f"}, {"url": "http://10.189.0.23:8778", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "86cd7636126b4214a0c0de3c50936bb9"}, {"url": "http://10.189.0.23:8778", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "eb918cef1bd546fcaafc28133e511d6c"}], "type": "placement", "id": "af7144bdc8404803a159883c31910f75", "name": "placement"}, {"endpoints": [{"url": "http://10.189.0.23:8774/v2.1", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "202b55f38ce646fe8ec9e2b956672f07"}, {"url": "http://10.189.0.23:8774/v2.1", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "b29375d70fd748e699859503279177e3"}, {"url": "http://nova-api.infra.bos01.scalingstack:8774/v2.1", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "ff7b759bc23341fe911fedfc2cd9ae07"}], "type": "compute", "id": "e34360be9bc6484eb95832a381a2d650", "name": "nova"}, {"endpoints": [{"url": "http://glance.infra.bos01.scalingstack:9292", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstaCreating nova instance adt-focal-s390x-multipath-tools-20240403-103623-juju-7f2275-prod-proposed-migration-environment-3-1a526e0d-1a3a-4bbe-95c7-ac217e3078a9 from image adt/ubuntu-focal-s390x-server-20240402.img (UUID c1bb6987-89e3-4d3b-9d03-9c84efaa0753)... 1343s nova boot failed (attempt #1): 1343s DEBUG (extension:189) found extension EntryPoint.parse('v1password = swiftclient.authv1:PasswordLoader') 1343s DEBUG (extension:189) found extension EntryPoint.parse('noauth = cinderclient.contrib.noauth:CinderNoAuthLoader') 1343s DEBUG (extension:189) found extension EntryPoint.parse('admin_token = keystoneauth1.loading._plugins.admin_token:AdminToken') 1343s DEBUG (extension:189) found extension EntryPoint.parse('none = keystoneauth1.loading._plugins.noauth:NoAuth') 1343s DEBUG (extension:189) found extension EntryPoint.parse('password = keystoneauth1.loading._plugins.identity.generic:Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('token = keystoneauth1.loading._plugins.identity.generic:Token') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v2password = keystoneauth1.loading._plugins.identity.v2:Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v2token = keystoneauth1.loading._plugins.identity.v2:Token') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3adfspassword = keystoneauth1.extras._saml2._loading:ADFSPassword') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3applicationcredential = keystoneauth1.loading._plugins.identity.v3:ApplicationCredential') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3fedkerb = keystoneauth1.extras.kerberos._loading:MappedKerberos') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3kerberos = keystoneauth1.extras.kerberos._loading:Kerberos') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3multifactor = keystoneauth1.loading._plugins.identity.v3:MultiFactor') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oauth1 = keystoneauth1.extras.oauth1._loading:V3OAuth1') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcaccesstoken = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAccessToken') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcauthcode = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAuthorizationCode') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcclientcredentials = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectClientCredentials') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcpassword = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectPassword') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3password = keystoneauth1.loading._plugins.identity.v3:Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3samlpassword = keystoneauth1.extras._saml2._loading:Saml2Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3token = keystoneauth1.loading._plugins.identity.v3:Token') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3tokenlessauth = keystoneauth1.loading._plugins.identity.v3:TokenlessAuth') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3totp = keystoneauth1.loading._plugins.identity.v3:TOTP') 1343s DEBUG (session:517) REQ: curl -g -i -X GET http://keystone.infra.bos01.scalingstack:5000/v3/ -H "Accept: application/json" -H "User-Agent: nova keystoneauth1/4.0.0 python-requests/2.22.0 CPython/3.8.10" 1343s DEBUG (connectionpool:222) Starting new HTTP connection (1): keystone.infra.bos01.scalingstack:5000 1343s DEBUG (connectionpool:429) http://keystone.infra.bos01.scalingstack:5000 "GET /v3/ HTTP/1.1" 200 273 1343s DEBUG (session:548) RESP: [200] Connection: Keep-Alive Content-Length: 273 Content-Type: application/json Date: Wed, 03 Apr 2024 10:46:12 GMT Keep-Alive: timeout=5, max=100 Server: Apache/2.4.18 (Ubuntu) Vary: X-Auth-Token X-Distribution: Ubuntu x-openstack-request-id: req-d39cf56f-1e9b-4b40-8174-14bddbd9510c 1343s DEBUG (session:580) RESP BODY: {"version": {"status": "stable", "updated": "2018-02-28T00:00:00Z", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.identity-v3+json"}], "id": "v3.10", "links": [{"href": "http://keystone.infra.bos01.scalingstack:5000/v3/", "rel": "self"}]}} 1343s DEBUG (session:946) GET call to http://keystone.infra.bos01.scalingstack:5000/v3/ used request id req-d39cf56f-1e9b-4b40-8174-14bddbd9510c 1343s DEBUG (base:182) Making authentication request to http://keystone.infra.bos01.scalingstack:5000/v3/auth/tokens 1343s DEBUG (connectionpool:429) http://keystone.infra.bos01.scalingstack:5000 "POST /v3/auth/tokens HTTP/1.1" 201 4363 1343s DEBUG (base:187) {"token": {"is_domain": false, "methods": ["password"], "roles": [{"id": "9fe2ff9ee4384b1894a90878d3e92bab", "name": "_member_"}], "is_admin_project": false, "project": {"domain": {"id": "default", "name": "Default"}, "id": "3f3b771a247746688951a4c90bf16631", "name": "prod-proposed-migration_project"}, "catalog": [{"endpoints": [{"url": "http://10.189.0.40", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "7d31d2904b56461cb46c735fc00850b0"}, {"url": "http://10.189.0.40", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "931e03b1033c4992ac8d223599983801"}, {"url": "http://10.189.0.40", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "c703b3c5e7224cfd893f622a7def99d7"}], "type": "product-streams", "id": "6723640fcf314f1c84ab92b0b7b7d343", "name": "image-stream"}, {"endpoints": [{"url": "http://neutron-api.infra.bos01.scalingstack:9696", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "13475a253aba4a63883ad9da9631b1d3"}, {"url": "http://10.189.0.22:9696", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "63b2334803a742048e95cd48d39f1674"}, {"url": "http://10.189.0.22:9696", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "9d19ce3dbfd544ef90e7694049018957"}], "type": "network", "id": "6a80a28849da43ce9839207bb1e98bfc", "name": "neutron"}, {"endpoints": [{"url": "http://10.189.0.20:5000/v3", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "51d5e1cea07c4644b44a8bf114268a27"}, {"url": "http://10.189.0.20:35357/v3", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "79c780094b2f40e5a70ee3a6353760a0"}, {"url": "http://keystone.infra.bos01.scalingstack:5000/v3", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "9cdf3486e4a94ca0a181e87bc1ff344f"}], "type": "identity", "id": "ad3a88bc8df3470b938f685304ad3ae9", "name": "keystone"}, {"endpoints": [{"url": "http://nova-api.infra.bos01.scalingstack:8778", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "83e5577919844e47bbf3dffc39f71e5f"}, {"url": "http://10.189.0.23:8778", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "86cd7636126b4214a0c0de3c50936bb9"}, {"url": "http://10.189.0.23:8778", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "eb918cef1bd546fcaafc28133e511d6c"}], "type": "placement", "id": "af7144bdc8404803a159883c31910f75", "name": "placement"}, {"endpoints": [{"url": "http://10.189.0.23:8774/v2.1", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "202b55f38ce646fe8ec9e2b956672f07"}, {"url": "http://10.189.0.23:8774/v2.1", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "b29375d70fd748e699859503279177e3"}, {"url": "http://nova-api.infra.bos01.scalingstack:8774/v2.1", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "ff7b759bc23341fe911fedfc2cd9ae07"}], "type": "compute", "id": "e34360be9bc6484eb95832a381a2d650", "name": "nova"}, {"endpoints": [{"url": "http://glance.infra.bos01.scalingstack:9292", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstaCreating nova instance adt-focal-s390x-multipath-tools-20240403-103623-juju-7f2275-prod-proposed-migration-environment-3-1a526e0d-1a3a-4bbe-95c7-ac217e3078a9 from image adt/ubuntu-focal-s390x-server-20240402.img (UUID c1bb6987-89e3-4d3b-9d03-9c84efaa0753)... 1343s nova boot failed (attempt #1): 1343s DEBUG (extension:189) found extension EntryPoint.parse('v1password = swiftclient.authv1:PasswordLoader') 1343s DEBUG (extension:189) found extension EntryPoint.parse('noauth = cinderclient.contrib.noauth:CinderNoAuthLoader') 1343s DEBUG (extension:189) found extension EntryPoint.parse('admin_token = keystoneauth1.loading._plugins.admin_token:AdminToken') 1343s DEBUG (extension:189) found extension EntryPoint.parse('none = keystoneauth1.loading._plugins.noauth:NoAuth') 1343s DEBUG (extension:189) found extension EntryPoint.parse('password = keystoneauth1.loading._plugins.identity.generic:Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('token = keystoneauth1.loading._plugins.identity.generic:Token') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v2password = keystoneauth1.loading._plugins.identity.v2:Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v2token = keystoneauth1.loading._plugins.identity.v2:Token') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3adfspassword = keystoneauth1.extras._saml2._loading:ADFSPassword') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3applicationcredential = keystoneauth1.loading._plugins.identity.v3:ApplicationCredential') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3fedkerb = keystoneauth1.extras.kerberos._loading:MappedKerberos') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3kerberos = keystoneauth1.extras.kerberos._loading:Kerberos') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3multifactor = keystoneauth1.loading._plugins.identity.v3:MultiFactor') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oauth1 = keystoneauth1.extras.oauth1._loading:V3OAuth1') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcaccesstoken = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAccessToken') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcauthcode = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAuthorizationCode') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcclientcredentials = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectClientCredentials') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcpassword = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectPassword') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3password = keystoneauth1.loading._plugins.identity.v3:Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3samlpassword = keystoneauth1.extras._saml2._loading:Saml2Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3token = keystoneauth1.loading._plugins.identity.v3:Token') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3tokenlessauth = keystoneauth1.loading._plugins.identity.v3:TokenlessAuth') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3totp = keystoneauth1.loading._plugins.identity.v3:TOTP') 1343s DEBUG (session:517) REQ: curl -g -i -X GET http://keystone.infra.bos01.scalingstack:5000/v3/ -H "Accept: application/json" -H "User-Agent: nova keystoneauth1/4.0.0 python-requests/2.22.0 CPython/3.8.10" 1343s DEBUG (connectionpool:222) Starting new HTTP connection (1): keystone.infra.bos01.scalingstack:5000 1343s DEBUG (connectionpool:429) http://keystone.infra.bos01.scalingstack:5000 "GET /v3/ HTTP/1.1" 200 273 1343s DEBUG (session:548) RESP: [200] Connection: Keep-Alive Content-Length: 273 Content-Type: application/json Date: Wed, 03 Apr 2024 10:46:12 GMT Keep-Alive: timeout=5, max=100 Server: Apache/2.4.18 (Ubuntu) Vary: X-Auth-Token X-Distribution: Ubuntu x-openstack-request-id: req-d39cf56f-1e9b-4b40-8174-14bddbd9510c 1343s DEBUG (session:580) RESP BODY: {"version": {"status": "stable", "updated": "2018-02-28T00:00:00Z", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.identity-v3+json"}], "id": "v3.10", "links": [{"href": "http://keystone.infra.bos01.scalingstack:5000/v3/", "rel": "self"}]}} 1343s DEBUG (session:946) GET call to http://keystone.infra.bos01.scalingstack:5000/v3/ used request id req-d39cf56f-1e9b-4b40-8174-14bddbd9510c 1343s DEBUG (base:182) Making authentication request to http://keystone.infra.bos01.scalingstack:5000/v3/auth/tokens 1343s DEBUG (connectionpool:429) http://keystone.infra.bos01.scalingstack:5000 "POST /v3/auth/tokens HTTP/1.1" 201 4363 1343s DEBUG (base:187) {"token": {"is_domain": false, "methods": ["password"], "roles": [{"id": "9fe2ff9ee4384b1894a90878d3e92bab", "name": "_member_"}], "is_admin_project": false, "project": {"domain": {"id": "default", "name": "Default"}, "id": "3f3b771a247746688951a4c90bf16631", "name": "prod-proposed-migration_project"}, "catalog": [{"endpoints": [{"url": "http://10.189.0.40", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "7d31d2904b56461cb46c735fc00850b0"}, {"url": "http://10.189.0.40", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "931e03b1033c4992ac8d223599983801"}, {"url": "http://10.189.0.40", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "c703b3c5e7224cfd893f622a7def99d7"}], "type": "product-streams", "id": "6723640fcf314f1c84ab92b0b7b7d343", "name": "image-stream"}, {"endpoints": [{"url": "http://neutron-api.infra.bos01.scalingstack:9696", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "13475a253aba4a63883ad9da9631b1d3"}, {"url": "http://10.189.0.22:9696", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "63b2334803a742048e95cd48d39f1674"}, {"url": "http://10.189.0.22:9696", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "9d19ce3dbfd544ef90e7694049018957"}], "type": "network", "id": "6a80a28849da43ce9839207bb1e98bfc", "name": "neutron"}, {"endpoints": [{"url": "http://10.189.0.20:5000/v3", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "51d5e1cea07c4644b44a8bf114268a27"}, {"url": "http://10.189.0.20:35357/v3", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "79c780094b2f40e5a70ee3a6353760a0"}, {"url": "http://keystone.infra.bos01.scalingstack:5000/v3", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "9cdf3486e4a94ca0a181e87bc1ff344f"}], "type": "identity", "id": "ad3a88bc8df3470b938f685304ad3ae9", "name": "keystone"}, {"endpoints": [{"url": "http://nova-api.infra.bos01.scalingstack:8778", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "83e5577919844e47bbf3dffc39f71e5f"}, {"url": "http://10.189.0.23:8778", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "86cd7636126b4214a0c0de3c50936bb9"}, {"url": "http://10.189.0.23:8778", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "eb918cef1bd546fcaafc28133e511d6c"}], "type": "placement", "id": "af7144bdc8404803a159883c31910f75", "name": "placement"}, {"endpoints": [{"url": "http://10.189.0.23:8774/v2.1", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "202b55f38ce646fe8ec9e2b956672f07"}, {"url": "http://10.189.0.23:8774/v2.1", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "b29375d70fd748e699859503279177e3"}, {"url": "http://nova-api.infra.bos01.scalingstack:8774/v2.1", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "ff7b759bc23341fe911fedfc2cd9ae07"}], "type": "compute", "id": "e34360be9bc6484eb95832a381a2d650", "name": "nova"}, {"endpoints": [{"url": "http://glance.infra.bos01.scalingstack:9292", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstaCreating nova instance adt-focal-s390x-multipath-tools-20240403-103623-juju-7f2275-prod-proposed-migration-environment-3-1a526e0d-1a3a-4bbe-95c7-ac217e3078a9 from image adt/ubuntu-focal-s390x-server-20240402.img (UUID c1bb6987-89e3-4d3b-9d03-9c84efaa0753)... 1343s nova boot failed (attempt #1): 1343s DEBUG (extension:189) found extension EntryPoint.parse('v1password = swiftclient.authv1:PasswordLoader') 1343s DEBUG (extension:189) found extension EntryPoint.parse('noauth = cinderclient.contrib.noauth:CinderNoAuthLoader') 1343s DEBUG (extension:189) found extension EntryPoint.parse('admin_token = keystoneauth1.loading._plugins.admin_token:AdminToken') 1343s DEBUG (extension:189) found extension EntryPoint.parse('none = keystoneauth1.loading._plugins.noauth:NoAuth') 1343s DEBUG (extension:189) found extension EntryPoint.parse('password = keystoneauth1.loading._plugins.identity.generic:Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('token = keystoneauth1.loading._plugins.identity.generic:Token') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v2password = keystoneauth1.loading._plugins.identity.v2:Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v2token = keystoneauth1.loading._plugins.identity.v2:Token') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3adfspassword = keystoneauth1.extras._saml2._loading:ADFSPassword') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3applicationcredential = keystoneauth1.loading._plugins.identity.v3:ApplicationCredential') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3fedkerb = keystoneauth1.extras.kerberos._loading:MappedKerberos') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3kerberos = keystoneauth1.extras.kerberos._loading:Kerberos') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3multifactor = keystoneauth1.loading._plugins.identity.v3:MultiFactor') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oauth1 = keystoneauth1.extras.oauth1._loading:V3OAuth1') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcaccesstoken = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAccessToken') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcauthcode = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAuthorizationCode') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcclientcredentials = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectClientCredentials') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcpassword = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectPassword') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3password = keystoneauth1.loading._plugins.identity.v3:Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3samlpassword = keystoneauth1.extras._saml2._loading:Saml2Password') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3token = keystoneauth1.loading._plugins.identity.v3:Token') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3tokenlessauth = keystoneauth1.loading._plugins.identity.v3:TokenlessAuth') 1343s DEBUG (extension:189) found extension EntryPoint.parse('v3totp = keystoneauth1.loading._plugins.identity.v3:TOTP') 1343s DEBUG (session:517) REQ: curl -g -i -X GET http://keystone.infra.bos01.scalingstack:5000/v3/ -H "Accept: application/json" -H "User-Agent: nova keystoneauth1/4.0.0 python-requests/2.22.0 CPython/3.8.10" 1343s DEBUG (connectionpool:222) Starting new HTTP connection (1): keystone.infra.bos01.scalingstack:5000 1343s DEBUG (connectionpool:429) http://keystone.infra.bos01.scalingstack:5000 "GET /v3/ HTTP/1.1" 200 273 1343s DEBUG (session:548) RESP: [200] Connection: Keep-Alive Content-Length: 273 Content-Type: application/json Date: Wed, 03 Apr 2024 10:46:12 GMT Keep-Alive: timeout=5, max=100 Server: Apache/2.4.18 (Ubuntu) Vary: X-Auth-Token X-Distribution: Ubuntu x-openstack-request-id: req-d39cf56f-1e9b-4b40-8174-14bddbd9510c 1344s DEBUG (session:580) RESP BODY: {"version": {"status": "stable", "updated": "2018-02-28T00:00:00Z", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.identity-v3+json"}], "id": "v3.10", "links": [{"href": "http://keystone.infra.bos01.scalingstack:5000/v3/", "rel": "self"}]}} 1344s DEBUG (session:946) GET call to http://keystone.infra.bos01.scalingstack:5000/v3/ used request id req-d39cf56f-1e9b-4b40-8174-14bddbd9510c 1344s DEBUG (base:182) Making authentication request to http://keystone.infra.bos01.scalingstack:5000/v3/auth/tokens 1344s DEBUG (connectionpool:429) http://keystone.infra.bos01.scalingstack:5000 "POST /v3/auth/tokens HTTP/1.1" 201 4363 1344s DEBUG (base:187) {"token": {"is_domain": false, "methods": ["password"], "roles": [{"id": "9fe2ff9ee4384b1894a90878d3e92bab", "name": "_member_"}], "is_admin_project": false, "project": {"domain": {"id": "default", "name": "Default"}, "id": "3f3b771a247746688951a4c90bf16631", "name": "prod-proposed-migration_project"}, "catalog": [{"endpoints": [{"url": "http://10.189.0.40", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "7d31d2904b56461cb46c735fc00850b0"}, {"url": "http://10.189.0.40", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "931e03b1033c4992ac8d223599983801"}, {"url": "http://10.189.0.40", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "c703b3c5e7224cfd893f622a7def99d7"}], "type": "product-streams", "id": "6723640fcf314f1c84ab92b0b7b7d343", "name": "image-stream"}, {"endpoints": [{"url": "http://neutron-api.infra.bos01.scalingstack:9696", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "13475a253aba4a63883ad9da9631b1d3"}, {"url": "http://10.189.0.22:9696", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "63b2334803a742048e95cd48d39f1674"}, {"url": "http://10.189.0.22:9696", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "9d19ce3dbfd544ef90e7694049018957"}], "type": "network", "id": "6a80a28849da43ce9839207bb1e98bfc", "name": "neutron"}, {"endpoints": [{"url": "http://10.189.0.20:5000/v3", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "51d5e1cea07c4644b44a8bf114268a27"}, {"url": "http://10.189.0.20:35357/v3", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "79c780094b2f40e5a70ee3a6353760a0"}, {"url": "http://keystone.infra.bos01.scalingstack:5000/v3", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "9cdf3486e4a94ca0a181e87bc1ff344f"}], "type": "identity", "id": "ad3a88bc8df3470b938f685304ad3ae9", "name": "keystone"}, {"endpoints": [{"url": "http://nova-api.infra.bos01.scalingstack:8778", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "83e5577919844e47bbf3dffc39f71e5f"}, {"url": "http://10.189.0.23:8778", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "86cd7636126b4214a0c0de3c50936bb9"}, {"url": "http://10.189.0.23:8778", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "eb918cef1bd546fcaafc28133e511d6c"}], "type": "placement", "id": "af7144bdc8404803a159883c31910f75", "name": "placement"}, {"endpoints": [{"url": "http://10.189.0.23:8774/v2.1", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "202b55f38ce646fe8ec9e2b956672f07"}, {"url": "http://10.189.0.23:8774/v2.1", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "b29375d70fd748e699859503279177e3"}, {"url": "http://nova-api.infra.bos01.scalingstack:8774/v2.1", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "ff7b759bc23341fe911fedfc2cd9ae07"}], "type": "compute", "id": "e34360be9bc6484eb95832a381a2d650", "name": "nova"}, {"endpoints": [{"url": "http://glance.infra.bos01.scalingstack:9292", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstaCreating nova instance adt-focal-s390x-multipath-tools-20240403-103623-juju-7f2275-prod-proposed-migration-environment-3-1a526e0d-1a3a-4bbe-95c7-ac217e3078a9 from image adt/ubuntu-focal-s390x-server-20240402.img (UUID c1bb6987-89e3-4d3b-9d03-9c84efaa0753)... 1344s nova boot failed (attempt #1): 1344s DEBUG (extension:189) found extension EntryPoint.parse('v1password = swiftclient.authv1:PasswordLoader') 1344s DEBUG (extension:189) found extension EntryPoint.parse('noauth = cinderclient.contrib.noauth:CinderNoAuthLoader') 1344s DEBUG (extension:189) found extension EntryPoint.parse('admin_token = keystoneauth1.loading._plugins.admin_token:AdminToken') 1344s DEBUG (extension:189) found extension EntryPoint.parse('none = keystoneauth1.loading._plugins.noauth:NoAuth') 1344s DEBUG (extension:189) found extension EntryPoint.parse('password = keystoneauth1.loading._plugins.identity.generic:Password') 1344s DEBUG (extension:189) found extension EntryPoint.parse('token = keystoneauth1.loading._plugins.identity.generic:Token') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v2password = keystoneauth1.loading._plugins.identity.v2:Password') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v2token = keystoneauth1.loading._plugins.identity.v2:Token') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3adfspassword = keystoneauth1.extras._saml2._loading:ADFSPassword') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3applicationcredential = keystoneauth1.loading._plugins.identity.v3:ApplicationCredential') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3fedkerb = keystoneauth1.extras.kerberos._loading:MappedKerberos') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3kerberos = keystoneauth1.extras.kerberos._loading:Kerberos') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3multifactor = keystoneauth1.loading._plugins.identity.v3:MultiFactor') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3oauth1 = keystoneauth1.extras.oauth1._loading:V3OAuth1') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcaccesstoken = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAccessToken') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcauthcode = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAuthorizationCode') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcclientcredentials = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectClientCredentials') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcpassword = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectPassword') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3password = keystoneauth1.loading._plugins.identity.v3:Password') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3samlpassword = keystoneauth1.extras._saml2._loading:Saml2Password') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3token = keystoneauth1.loading._plugins.identity.v3:Token') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3tokenlessauth = keystoneauth1.loading._plugins.identity.v3:TokenlessAuth') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3totp = keystoneauth1.loading._plugins.identity.v3:TOTP') 1344s DEBUG (session:517) REQ: curl -g -i -X GET http://keystone.infra.bos01.scalingstack:5000/v3/ -H "Accept: application/json" -H "User-Agent: nova keystoneauth1/4.0.0 python-requests/2.22.0 CPython/3.8.10" 1344s DEBUG (connectionpool:222) Starting new HTTP connection (1): keystone.infra.bos01.scalingstack:5000 1344s DEBUG (connectionpool:429) http://keystone.infra.bos01.scalingstack:5000 "GET /v3/ HTTP/1.1" 200 273 1344s DEBUG (session:548) RESP: [200] Connection: Keep-Alive Content-Length: 273 Content-Type: application/json Date: Wed, 03 Apr 2024 10:46:12 GMT Keep-Alive: timeout=5, max=100 Server: Apache/2.4.18 (Ubuntu) Vary: X-Auth-Token X-Distribution: Ubuntu x-openstack-request-id: req-d39cf56f-1e9b-4b40-8174-14bddbd9510c 1344s DEBUG (session:580) RESP BODY: {"version": {"status": "stable", "updated": "2018-02-28T00:00:00Z", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.identity-v3+json"}], "id": "v3.10", "links": [{"href": "http://keystone.infra.bos01.scalingstack:5000/v3/", "rel": "self"}]}} 1344s DEBUG (session:946) GET call to http://keystone.infra.bos01.scalingstack:5000/v3/ used request id req-d39cf56f-1e9b-4b40-8174-14bddbd9510c 1344s DEBUG (base:182) Making authentication request to http://keystone.infra.bos01.scalingstack:5000/v3/auth/tokens 1344s DEBUG (connectionpool:429) http://keystone.infra.bos01.scalingstack:5000 "POST /v3/auth/tokens HTTP/1.1" 201 4363 1344s DEBUG (base:187) {"token": {"is_domain": false, "methods": ["password"], "roles": [{"id": "9fe2ff9ee4384b1894a90878d3e92bab", "name": "_member_"}], "is_admin_project": false, "project": {"domain": {"id": "default", "name": "Default"}, "id": "3f3b771a247746688951a4c90bf16631", "name": "prod-proposed-migration_project"}, "catalog": [{"endpoints": [{"url": "http://10.189.0.40", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "7d31d2904b56461cb46c735fc00850b0"}, {"url": "http://10.189.0.40", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "931e03b1033c4992ac8d223599983801"}, {"url": "http://10.189.0.40", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "c703b3c5e7224cfd893f622a7def99d7"}], "type": "product-streams", "id": "6723640fcf314f1c84ab92b0b7b7d343", "name": "image-stream"}, {"endpoints": [{"url": "http://neutron-api.infra.bos01.scalingstack:9696", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "13475a253aba4a63883ad9da9631b1d3"}, {"url": "http://10.189.0.22:9696", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "63b2334803a742048e95cd48d39f1674"}, {"url": "http://10.189.0.22:9696", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "9d19ce3dbfd544ef90e7694049018957"}], "type": "network", "id": "6a80a28849da43ce9839207bb1e98bfc", "name": "neutron"}, {"endpoints": [{"url": "http://10.189.0.20:5000/v3", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "51d5e1cea07c4644b44a8bf114268a27"}, {"url": "http://10.189.0.20:35357/v3", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "79c780094b2f40e5a70ee3a6353760a0"}, {"url": "http://keystone.infra.bos01.scalingstack:5000/v3", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "9cdf3486e4a94ca0a181e87bc1ff344f"}], "type": "identity", "id": "ad3a88bc8df3470b938f685304ad3ae9", "name": "keystone"}, {"endpoints": [{"url": "http://nova-api.infra.bos01.scalingstack:8778", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "83e5577919844e47bbf3dffc39f71e5f"}, {"url": "http://10.189.0.23:8778", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "86cd7636126b4214a0c0de3c50936bb9"}, {"url": "http://10.189.0.23:8778", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "eb918cef1bd546fcaafc28133e511d6c"}], "type": "placement", "id": "af7144bdc8404803a159883c31910f75", "name": "placement"}, {"endpoints": [{"url": "http://10.189.0.23:8774/v2.1", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "202b55f38ce646fe8ec9e2b956672f07"}, {"url": "http://10.189.0.23:8774/v2.1", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "b29375d70fd748e699859503279177e3"}, {"url": "http://nova-api.infra.bos01.scalingstack:8774/v2.1", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "ff7b759bc23341fe911fedfc2cd9ae07"}], "type": "compute", "id": "e34360be9bc6484eb95832a381a2d650", "name": "nova"}, {"endpoints": [{"url": "http://glance.infra.bos01.scalingstack:9292", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstaCreating nova instance adt-focal-s390x-multipath-tools-20240403-103623-juju-7f2275-prod-proposed-migration-environment-3-1a526e0d-1a3a-4bbe-95c7-ac217e3078a9 from image adt/ubuntu-focal-s390x-server-20240402.img (UUID c1bb6987-89e3-4d3b-9d03-9c84efaa0753)... 1344s nova boot failed (attempt #1): 1344s DEBUG (extension:189) found extension EntryPoint.parse('v1password = swiftclient.authv1:PasswordLoader') 1344s DEBUG (extension:189) found extension EntryPoint.parse('noauth = cinderclient.contrib.noauth:CinderNoAuthLoader') 1344s DEBUG (extension:189) found extension EntryPoint.parse('admin_token = keystoneauth1.loading._plugins.admin_token:AdminToken') 1344s DEBUG (extension:189) found extension EntryPoint.parse('none = keystoneauth1.loading._plugins.noauth:NoAuth') 1344s DEBUG (extension:189) found extension EntryPoint.parse('password = keystoneauth1.loading._plugins.identity.generic:Password') 1344s DEBUG (extension:189) found extension EntryPoint.parse('token = keystoneauth1.loading._plugins.identity.generic:Token') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v2password = keystoneauth1.loading._plugins.identity.v2:Password') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v2token = keystoneauth1.loading._plugins.identity.v2:Token') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3adfspassword = keystoneauth1.extras._saml2._loading:ADFSPassword') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3applicationcredential = keystoneauth1.loading._plugins.identity.v3:ApplicationCredential') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3fedkerb = keystoneauth1.extras.kerberos._loading:MappedKerberos') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3kerberos = keystoneauth1.extras.kerberos._loading:Kerberos') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3multifactor = keystoneauth1.loading._plugins.identity.v3:MultiFactor') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3oauth1 = keystoneauth1.extras.oauth1._loading:V3OAuth1') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcaccesstoken = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAccessToken') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcauthcode = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAuthorizationCode') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcclientcredentials = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectClientCredentials') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcpassword = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectPassword') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3password = keystoneauth1.loading._plugins.identity.v3:Password') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3samlpassword = keystoneauth1.extras._saml2._loading:Saml2Password') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3token = keystoneauth1.loading._plugins.identity.v3:Token') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3tokenlessauth = keystoneauth1.loading._plugins.identity.v3:TokenlessAuth') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3totp = keystoneauth1.loading._plugins.identity.v3:TOTP') 1344s DEBUG (session:517) REQ: curl -g -i -X GET http://keystone.infra.bos01.scalingstack:5000/v3/ -H "Accept: application/json" -H "User-Agent: nova keystoneauth1/4.0.0 python-requests/2.22.0 CPython/3.8.10" 1344s DEBUG (connectionpool:222) Starting new HTTP connection (1): keystone.infra.bos01.scalingstack:5000 1344s DEBUG (connectionpool:429) http://keystone.infra.bos01.scalingstack:5000 "GET /v3/ HTTP/1.1" 200 273 1344s DEBUG (session:548) RESP: [200] Connection: Keep-Alive Content-Length: 273 Content-Type: application/json Date: Wed, 03 Apr 2024 10:46:12 GMT Keep-Alive: timeout=5, max=100 Server: Apache/2.4.18 (Ubuntu) Vary: X-Auth-Token X-Distribution: Ubuntu x-openstack-request-id: req-d39cf56f-1e9b-4b40-8174-14bddbd9510c 1344s DEBUG (session:580) RESP BODY: {"version": {"status": "stable", "updated": "2018-02-28T00:00:00Z", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.identity-v3+json"}], "id": "v3.10", "links": [{"href": "http://keystone.infra.bos01.scalingstack:5000/v3/", "rel": "self"}]}} 1344s DEBUG (session:946) GET call to http://keystone.infra.bos01.scalingstack:5000/v3/ used request id req-d39cf56f-1e9b-4b40-8174-14bddbd9510c 1344s DEBUG (base:182) Making authentication request to http://keystone.infra.bos01.scalingstack:5000/v3/auth/tokens 1344s DEBUG (connectionpool:429) http://keystone.infra.bos01.scalingstack:5000 "POST /v3/auth/tokens HTTP/1.1" 201 4363 1344s DEBUG (base:187) {"token": {"is_domain": false, "methods": ["password"], "roles": [{"id": "9fe2ff9ee4384b1894a90878d3e92bab", "name": "_member_"}], "is_admin_project": false, "project": {"domain": {"id": "default", "name": "Default"}, "id": "3f3b771a247746688951a4c90bf16631", "name": "prod-proposed-migration_project"}, "catalog": [{"endpoints": [{"url": "http://10.189.0.40", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "7d31d2904b56461cb46c735fc00850b0"}, {"url": "http://10.189.0.40", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "931e03b1033c4992ac8d223599983801"}, {"url": "http://10.189.0.40", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "c703b3c5e7224cfd893f622a7def99d7"}], "type": "product-streams", "id": "6723640fcf314f1c84ab92b0b7b7d343", "name": "image-stream"}, {"endpoints": [{"url": "http://neutron-api.infra.bos01.scalingstack:9696", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "13475a253aba4a63883ad9da9631b1d3"}, {"url": "http://10.189.0.22:9696", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "63b2334803a742048e95cd48d39f1674"}, {"url": "http://10.189.0.22:9696", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "9d19ce3dbfd544ef90e7694049018957"}], "type": "network", "id": "6a80a28849da43ce9839207bb1e98bfc", "name": "neutron"}, {"endpoints": [{"url": "http://10.189.0.20:5000/v3", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "51d5e1cea07c4644b44a8bf114268a27"}, {"url": "http://10.189.0.20:35357/v3", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "79c780094b2f40e5a70ee3a6353760a0"}, {"url": "http://keystone.infra.bos01.scalingstack:5000/v3", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "9cdf3486e4a94ca0a181e87bc1ff344f"}], "type": "identity", "id": "ad3a88bc8df3470b938f685304ad3ae9", "name": "keystone"}, {"endpoints": [{"url": "http://nova-api.infra.bos01.scalingstack:8778", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "83e5577919844e47bbf3dffc39f71e5f"}, {"url": "http://10.189.0.23:8778", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "86cd7636126b4214a0c0de3c50936bb9"}, {"url": "http://10.189.0.23:8778", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "eb918cef1bd546fcaafc28133e511d6c"}], "type": "placement", "id": "af7144bdc8404803a159883c31910f75", "name": "placement"}, {"endpoints": [{"url": "http://10.189.0.23:8774/v2.1", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "202b55f38ce646fe8ec9e2b956672f07"}, {"url": "http://10.189.0.23:8774/v2.1", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "b29375d70fd748e699859503279177e3"}, {"url": "http://nova-api.infra.bos01.scalingstack:8774/v2.1", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "ff7b759bc23341fe911fedfc2cd9ae07"}], "type": "compute", "id": "e34360be9bc6484eb95832a381a2d650", "name": "nova"}, {"endpoints": [{"url": "http://glance.infra.bos01.scalingstack:9292", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstaCreating nova instance adt-focal-s390x-multipath-tools-20240403-103623-juju-7f2275-prod-proposed-migration-environment-3-1a526e0d-1a3a-4bbe-95c7-ac217e3078a9 from image adt/ubuntu-focal-s390x-server-20240402.img (UUID c1bb6987-89e3-4d3b-9d03-9c84efaa0753)... 1344s nova boot failed (attempt #1): 1344s DEBUG (extension:189) found extension EntryPoint.parse('v1password = swiftclient.authv1:PasswordLoader') 1344s DEBUG (extension:189) found extension EntryPoint.parse('noauth = cinderclient.contrib.noauth:CinderNoAuthLoader') 1344s DEBUG (extension:189) found extension EntryPoint.parse('admin_token = keystoneauth1.loading._plugins.admin_token:AdminToken') 1344s DEBUG (extension:189) found extension EntryPoint.parse('none = keystoneauth1.loading._plugins.noauth:NoAuth') 1344s DEBUG (extension:189) found extension EntryPoint.parse('password = keystoneauth1.loading._plugins.identity.generic:Password') 1344s DEBUG (extension:189) found extension EntryPoint.parse('token = keystoneauth1.loading._plugins.identity.generic:Token') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v2password = keystoneauth1.loading._plugins.identity.v2:Password') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v2token = keystoneauth1.loading._plugins.identity.v2:Token') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3adfspassword = keystoneauth1.extras._saml2._loading:ADFSPassword') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3applicationcredential = keystoneauth1.loading._plugins.identity.v3:ApplicationCredential') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3fedkerb = keystoneauth1.extras.kerberos._loading:MappedKerberos') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3kerberos = keystoneauth1.extras.kerberos._loading:Kerberos') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3multifactor = keystoneauth1.loading._plugins.identity.v3:MultiFactor') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3oauth1 = keystoneauth1.extras.oauth1._loading:V3OAuth1') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcaccesstoken = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAccessToken') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcauthcode = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAuthorizationCode') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcclientcredentials = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectClientCredentials') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcpassword = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectPassword') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3password = keystoneauth1.loading._plugins.identity.v3:Password') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3samlpassword = keystoneauth1.extras._saml2._loading:Saml2Password') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3token = keystoneauth1.loading._plugins.identity.v3:Token') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3tokenlessauth = keystoneauth1.loading._plugins.identity.v3:TokenlessAuth') 1344s DEBUG (extension:189) found extension EntryPoint.parse('v3totp = keystoneauth1.loading._plugins.identity.v3:TOTP') 1344s DEBUG (session:517) REQ: curl -g -i -X GET http://keystone.infra.bos01.scalingstack:5000/v3/ -H "Accept: application/json" -H "User-Agent: nova keystoneauth1/4.0.0 python-requests/2.22.0 CPython/3.8.10" 1344s DEBUG (connectionpool:222) Starting new HTTP connection (1): keystone.infra.bos01.scalingstack:5000 1344s DEBUG (connectionpool:429) http://keystone.infra.bos01.scalingstack:5000 "GET /v3/ HTTP/1.1" 200 273 1344s DEBUG (session:548) RESP: [200] Connection: Keep-Alive Content-Length: 273 Content-Type: application/json Date: Wed, 03 Apr 2024 10:46:12 GMT Keep-Alive: timeout=5, max=100 Server: Apache/2.4.18 (Ubuntu) Vary: X-Auth-Token X-Distribution: Ubuntu x-openstack-request-id: req-d39cf56f-1e9b-4b40-8174-14bddbd9510c 1346s DEBUG (session:580) RESP BODY: {"version": {"status": "stable", "updated": "2018-02-28T00:00:00Z", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.ideautopkgtest [10:58:49]: testbed dpkg architecture: s390x 1346s autopkgtest [10:58:49]: testbed apt version: 2.0.10 1346s autopkgtest [10:58:49]: @@@@@@@@@@@@@@@@@@@@ test bed setup 1347s Get:1 http://ftpmaster.internal/ubuntu focal-proposed InRelease [267 kB] 1347s Get:2 http://ftpmaster.internal/ubuntu focal-proposed/main Sources [72.0 kB] 1347s Get:3 http://ftpmaster.internal/ubuntu focal-proposed/restricted Sources [19.7 kB] 1347s Get:4 http://ftpmaster.internal/ubuntu focal-proposed/universe Sources [14.2 kB] 1347s Get:5 http://ftpmaster.internal/ubuntu focal-proposed/main s390x Packages [125 kB] 1348s Get:6 http://ftpmaster.internal/ubuntu focal-proposed/main s390x c-n-f Metadata [1580 B] 1348s Get:7 http://ftpmaster.internal/ubuntu focal-proposed/restricted s390x Packages [1188 B] 1348s Get:8 http://ftpmaster.internal/ubuntu focal-proposed/restricted s390x c-n-f Metadata [116 B] 1348s Get:9 http://ftpmaster.internal/ubuntu focal-proposed/universe s390x Packages [43.0 kB] 1348s Get:10 http://ftpmaster.internal/ubuntu focal-proposed/universe s390x c-n-f Metadata [2316 B] 1348s Get:11 http://ftpmaster.internal/ubuntu focal-proposed/multiverse s390x c-n-f Metadata [116 B] 1349s Fetched 546 kB in 1s (477 kB/s) 1349s Reading package lists... 1352s Reading package lists... 1352s Building dependency tree... 1352s Reading state information... 1352s Calculating upgrade... 1352s The following packages will be upgraded: 1352s initramfs-tools initramfs-tools-bin initramfs-tools-core 1353s 3 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 1353s Need to get 67.5 kB of archives. 1353s After this operation, 0 B of additional disk space will be used. 1353s Get:1 http://ftpmaster.internal/ubuntu focal-proposed/main s390x initramfs-tools all 0.136ubuntu6.8 [9212 B] 1353s Get:2 http://ftpmaster.internal/ubuntu focal-proposed/main s390x initramfs-tools-core all 0.136ubuntu6.8 [47.8 kB] 1353s Get:3 http://ftpmaster.internal/ubuntu focal-proposed/main s390x initramfs-tools-bin s390x 0.136ubuntu6.8 [10.5 kB] 1353s Fetched 67.5 kB in 0s (183 kB/s) 1354s (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 ... 71235 files and directories currently installed.) 1354s Preparing to unpack .../initramfs-tools_0.136ubuntu6.8_all.deb ... 1354s Unpacking initramfs-tools (0.136ubuntu6.8) over (0.136ubuntu6.7) ... 1354s Preparing to unpack .../initramfs-tools-core_0.136ubuntu6.8_all.deb ... 1354s Unpacking initramfs-tools-core (0.136ubuntu6.8) over (0.136ubuntu6.7) ... 1354s Preparing to unpack .../initramfs-tools-bin_0.136ubuntu6.8_s390x.deb ... 1354s Unpacking initramfs-tools-bin (0.136ubuntu6.8) over (0.136ubuntu6.7) ... 1354s Setting up initramfs-tools-bin (0.136ubuntu6.8) ... 1354s Setting up initramfs-tools-core (0.136ubuntu6.8) ... 1354s Setting up initramfs-tools (0.136ubuntu6.8) ... 1354s update-initramfs: deferring update (trigger activated) 1354s Processing triggers for man-db (2.9.1-1) ... 1354s Processing triggers for initramfs-tools (0.136ubuntu6.8) ... 1354s update-initramfs: Generating /boot/initrd.img-5.4.0-174-generic 1362s Using config file '/etc/zipl.conf' 1362s Building bootmap in '/boot' 1362s Adding IPL section 'ubuntu' (default) 1362s Preparing boot device: vda (0000). 1362s Done. 1362s Reading package lists... 1362s Building dependency tree... 1362s Reading state information... 1363s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 1363s Hit:1 http://ftpmaster.internal/ubuntu focal InRelease 1363s Hit:2 http://ftpmaster.internal/ubuntu focal-updates InRelease 1363s Hit:3 http://ftpmaster.internal/ubuntu focal-security InRelease 1364s Hit:4 http://ftpmaster.internal/ubuntu focal-proposed InRelease 1365s Reading package lists... 1365s Reading package lists... 1365s Building dependency tree... 1365s Reading state information... 1365s Calculating upgrade... 1365s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 1365s Reading package lists... 1366s Building dependency tree... 1366s Reading state information... 1366s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 1366s autopkgtest [10:59:09]: rebooting testbed after setup commands that affected boot 1411s ntity-v3+json"}], "id": "v3.10", "links": [{"href": "http://keystone.infra.bos01.scalingstack:5000/v3/", "rel": "self"}]}} 1411s DEBUG (session:946) GET call to http://keystone.infra.bos01.scalingstack:5000/v3/ used request id req-d39cf56f-1e9b-4b40-8174-14bddbd9510c 1411s DEBUG (base:182) Making authentication request to http://keystone.infra.bos01.scalingstack:5000/v3/auth/tokens 1411s DEBUG (connectionpool:429) http://keystone.infra.bos01.scalingstack:5000 "POST /v3/auth/tokens HTTP/1.1" 201 4363 1411s DEBUG (base:187) {"token": {"is_domain": false, "methods": ["password"], "roles": [{"id": "9fe2ff9ee4384b1894a90878d3e92bab", "name": "_member_"}], "is_admin_project": false, "project": {"domain": {"id": "default", "name": "Default"}, "id": "3f3b771a247746688951a4c90bf16631", "name": "prod-proposed-migration_project"}, "catalog": [{"endpoints": [{"url": "http://10.189.0.40", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "7d31d2904b56461cb46c735fc00850b0"}, {"url": "http://10.189.0.40", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "931e03b1033c4992ac8d223599983801"}, {"url": "http://10.189.0.40", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "c703b3c5e7224cfd893f622a7def99d7"}], "type": "product-streams", "id": "6723640fcf314f1c84ab92b0b7b7d343", "name": "image-stream"}, {"endpoints": [{"url": "http://neutron-api.infra.bos01.scalingstack:9696", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "13475a253aba4a63883ad9da9631b1d3"}, {"url": "http://10.189.0.22:9696", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "63b2334803a742048e95cd48d39f1674"}, {"url": "http://10.189.0.22:9696", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "9d19ce3dbfd544ef90e7694049018957"}], "type": "network", "id": "6a80a28849da43ce9839207bb1e98bfc", "name": "neutron"}, {"endpoints": [{"url": "http://10.189.0.20:5000/v3", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "51d5e1cea07c4644b44a8bf114268a27"}, {"url": "http://10.189.0.20:35357/v3", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "79c780094b2f40e5a70ee3a6353760a0"}, {"url": "http://keystone.infra.bos01.scalingstack:5000/v3", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "9cdf3486e4a94ca0a181e87bc1ff344f"}], "type": "identity", "id": "ad3a88bc8df3470b938f685304ad3ae9", "name": "keystone"}, {"endpoints": [{"url": "http://nova-api.infra.bos01.scalingstack:8778", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "83e5577919844e47bbf3dffc39f71e5f"}, {"url": "http://10.189.0.23:8778", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "86cd7636126b4214a0c0de3c50936bb9"}, {"url": "http://10.189.0.23:8778", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "eb918cef1bd546fcaafc28133e511d6c"}], "type": "placement", "id": "af7144bdc8404803a159883c31910f75", "name": "placement"}, {"endpoints": [{"url": "http://10.189.0.23:8774/v2.1", "interface": "internal", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "202b55f38ce646fe8ec9e2b956672f07"}, {"url": "http://10.189.0.23:8774/v2.1", "interface": "admin", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "b29375d70fd748e699859503279177e3"}, {"url": "http://nova-api.infra.bos01.scalingstack:8774/v2.1", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstack-bos01", "id": "ff7b759bc23341fe911fedfc2cd9ae07"}], "type": "compute", "id": "e34360be9bc6484eb95832a381a2d650", "name": "nova"}, {"endpoints": [{"url": "http://glance.infra.bos01.scalingstack:9292", "interface": "public", "region": "scalingstack-bos01", "region_id": "scalingstaautopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 1425s Reading package lists... 1426s Building dependency tree... 1426s Reading state information... 1426s Starting pkgProblemResolver with broken count: 0 1426s Starting 2 pkgProblemResolver with broken count: 0 1426s Done 1426s The following additional packages will be installed: 1426s fio libatomic1 libboost-iostreams1.71.0 libboost-thread1.71.0 1426s libconfig-general-perl libgfapi0 libgfrpc0 libgfxdr0 libglusterfs0 1426s libibverbs1 libisns0 libnl-route-3-200 libpython2.7-minimal 1426s libpython2.7-stdlib librados2 librbd1 librdmacm1 libtirpc-common libtirpc3 1426s lsscsi open-iscsi python2.7 python2.7-minimal tgt 1426s Suggested packages: 1426s gnuplot gfio python-scipy python2.7-doc binfmt-support tgt-rbd 1426s Recommended packages: 1426s ibverbs-providers finalrd 1426s The following NEW packages will be installed: 1426s autopkgtest-satdep fio libatomic1 libboost-iostreams1.71.0 1426s libboost-thread1.71.0 libconfig-general-perl libgfapi0 libgfrpc0 libgfxdr0 1426s libglusterfs0 libibverbs1 libisns0 libnl-route-3-200 libpython2.7-minimal 1426s libpython2.7-stdlib librados2 librbd1 librdmacm1 libtirpc-common libtirpc3 1426s lsscsi open-iscsi python2.7 python2.7-minimal tgt 1426s 0 upgraded, 25 newly installed, 0 to remove and 0 not upgraded. 1426s Need to get 10.2 MB/10.2 MB of archives. 1426s After this operation, 49.7 MB of additional disk space will be used. 1426s Get:1 /tmp/autopkgtest.bKMOuX/2-autopkgtest-satdep.deb autopkgtest-satdep s390x 0 [736 B] 1426s Get:2 http://ftpmaster.internal/ubuntu focal/main s390x libisns0 s390x 0.97-3 [102 kB] 1427s Get:3 http://ftpmaster.internal/ubuntu focal-updates/main s390x open-iscsi s390x 2.0.874-7.1ubuntu6.4 [262 kB] 1427s Get:4 http://ftpmaster.internal/ubuntu focal-updates/universe s390x libpython2.7-minimal s390x 2.7.18-1~20.04.4 [335 kB] 1427s Get:5 http://ftpmaster.internal/ubuntu focal-updates/universe s390x python2.7-minimal s390x 2.7.18-1~20.04.4 [1191 kB] 1428s Get:6 http://ftpmaster.internal/ubuntu focal-updates/main s390x libnl-route-3-200 s390x 3.4.0-1ubuntu0.1 [136 kB] 1428s Get:7 http://ftpmaster.internal/ubuntu focal/main s390x libibverbs1 s390x 28.0-1ubuntu1 [51.1 kB] 1428s Get:8 http://ftpmaster.internal/ubuntu focal/main s390x librdmacm1 s390x 28.0-1ubuntu1 [65.4 kB] 1428s Get:9 http://ftpmaster.internal/ubuntu focal/main s390x libconfig-general-perl all 2.63-1 [53.9 kB] 1428s Get:10 http://ftpmaster.internal/ubuntu focal/main s390x tgt s390x 1:1.0.79-2ubuntu1 [199 kB] 1428s Get:11 http://ftpmaster.internal/ubuntu focal/universe s390x libglusterfs0 s390x 7.2-2build1 [250 kB] 1428s Get:12 http://ftpmaster.internal/ubuntu focal-updates/main s390x libtirpc-common all 1.2.5-1ubuntu0.1 [7712 B] 1428s Get:13 http://ftpmaster.internal/ubuntu focal-updates/main s390x libtirpc3 s390x 1.2.5-1ubuntu0.1 [72.0 kB] 1429s Get:14 http://ftpmaster.internal/ubuntu focal/universe s390x libgfxdr0 s390x 7.2-2build1 [23.8 kB] 1429s Get:15 http://ftpmaster.internal/ubuntu focal/universe s390x libgfrpc0 s390x 7.2-2build1 [40.6 kB] 1429s Get:16 http://ftpmaster.internal/ubuntu focal/universe s390x libgfapi0 s390x 7.2-2build1 [63.2 kB] 1429s Get:17 http://ftpmaster.internal/ubuntu focal/main s390x libboost-iostreams1.71.0 s390x 1.71.0-6ubuntu6 [236 kB] 1429s Get:18 http://ftpmaster.internal/ubuntu focal/main s390x libboost-thread1.71.0 s390x 1.71.0-6ubuntu6 [245 kB] 1429s Get:19 http://ftpmaster.internal/ubuntu focal-updates/main s390x librados2 s390x 15.2.17-0ubuntu0.20.04.6 [2890 kB] 1431s Get:20 http://ftpmaster.internal/ubuntu focal-updates/main s390x libatomic1 s390x 10.5.0-1ubuntu1~20.04 [8524 B] 1431s Get:21 http://ftpmaster.internal/ubuntu focal-updates/main s390x librbd1 s390x 15.2.17-0ubuntu0.20.04.6 [1419 kB] 1431s Get:22 http://ftpmaster.internal/ubuntu focal-updates/universe s390x libpython2.7-stdlib s390x 2.7.18-1~20.04.4 [1832 kB] 1432s Get:23 http://ftpmaster.internal/ubuntu focal-updates/universe s390x python2.7 s390x 2.7.18-1~20.04.4 [248 kB] 1432s Get:24 http://ftpmaster.internal/ubuntu focal/universe s390x fio s390x 3.16-1 [464 kB] 1433s Get:25 http://ftpmaster.internal/ubuntu focal/main s390x lsscsi s390x 0.30-0.1 [41.9 kB] 1433s Preconfiguring packages ... 1433s Fetched 10.2 MB in 7s (1490 kB/s) 1433s Selecting previously unselected package libisns0:s390x. 1433s (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 ... 71235 files and directories currently installed.) 1433s Preparing to unpack .../00-libisns0_0.97-3_s390x.deb ... 1433s Unpacking libisns0:s390x (0.97-3) ... 1433s Selecting previously unselected package open-iscsi. 1433s Preparing to unpack .../01-open-iscsi_2.0.874-7.1ubuntu6.4_s390x.deb ... 1433s Unpacking open-iscsi (2.0.874-7.1ubuntu6.4) ... 1434s Selecting previously unselected package libpython2.7-minimal:s390x. 1434s Preparing to unpack .../02-libpython2.7-minimal_2.7.18-1~20.04.4_s390x.deb ... 1434s Unpacking libpython2.7-minimal:s390x (2.7.18-1~20.04.4) ... 1434s Selecting previously unselected package python2.7-minimal. 1434s Preparing to unpack .../03-python2.7-minimal_2.7.18-1~20.04.4_s390x.deb ... 1434s Unpacking python2.7-minimal (2.7.18-1~20.04.4) ... 1434s Selecting previously unselected package libnl-route-3-200:s390x. 1434s Preparing to unpack .../04-libnl-route-3-200_3.4.0-1ubuntu0.1_s390x.deb ... 1434s Unpacking libnl-route-3-200:s390x (3.4.0-1ubuntu0.1) ... 1434s Selecting previously unselected package libibverbs1:s390x. 1434s Preparing to unpack .../05-libibverbs1_28.0-1ubuntu1_s390x.deb ... 1434s Unpacking libibverbs1:s390x (28.0-1ubuntu1) ... 1434s Selecting previously unselected package librdmacm1:s390x. 1434s Preparing to unpack .../06-librdmacm1_28.0-1ubuntu1_s390x.deb ... 1434s Unpacking librdmacm1:s390x (28.0-1ubuntu1) ... 1434s Selecting previously unselected package libconfig-general-perl. 1434s Preparing to unpack .../07-libconfig-general-perl_2.63-1_all.deb ... 1434s Unpacking libconfig-general-perl (2.63-1) ... 1434s Selecting previously unselected package tgt. 1434s Preparing to unpack .../08-tgt_1%3a1.0.79-2ubuntu1_s390x.deb ... 1434s Unpacking tgt (1:1.0.79-2ubuntu1) ... 1434s Selecting previously unselected package libglusterfs0:s390x. 1434s Preparing to unpack .../09-libglusterfs0_7.2-2build1_s390x.deb ... 1434s Unpacking libglusterfs0:s390x (7.2-2build1) ... 1434s Selecting previously unselected package libtirpc-common. 1434s Preparing to unpack .../10-libtirpc-common_1.2.5-1ubuntu0.1_all.deb ... 1434s Unpacking libtirpc-common (1.2.5-1ubuntu0.1) ... 1434s Selecting previously unselected package libtirpc3:s390x. 1434s Preparing to unpack .../11-libtirpc3_1.2.5-1ubuntu0.1_s390x.deb ... 1434s Unpacking libtirpc3:s390x (1.2.5-1ubuntu0.1) ... 1434s Selecting previously unselected package libgfxdr0:s390x. 1434s Preparing to unpack .../12-libgfxdr0_7.2-2build1_s390x.deb ... 1434s Unpacking libgfxdr0:s390x (7.2-2build1) ... 1434s Selecting previously unselected package libgfrpc0:s390x. 1434s Preparing to unpack .../13-libgfrpc0_7.2-2build1_s390x.deb ... 1434s Unpacking libgfrpc0:s390x (7.2-2build1) ... 1434s Selecting previously unselected package libgfapi0:s390x. 1434s Preparing to unpack .../14-libgfapi0_7.2-2build1_s390x.deb ... 1434s Unpacking libgfapi0:s390x (7.2-2build1) ... 1434s Selecting previously unselected package libboost-iostreams1.71.0:s390x. 1434s Preparing to unpack .../15-libboost-iostreams1.71.0_1.71.0-6ubuntu6_s390x.deb ... 1434s Unpacking libboost-iostreams1.71.0:s390x (1.71.0-6ubuntu6) ... 1434s Selecting previously unselected package libboost-thread1.71.0:s390x. 1434s Preparing to unpack .../16-libboost-thread1.71.0_1.71.0-6ubuntu6_s390x.deb ... 1434s Unpacking libboost-thread1.71.0:s390x (1.71.0-6ubuntu6) ... 1434s Selecting previously unselected package librados2. 1434s Preparing to unpack .../17-librados2_15.2.17-0ubuntu0.20.04.6_s390x.deb ... 1434s Unpacking librados2 (15.2.17-0ubuntu0.20.04.6) ... 1435s Selecting previously unselected package libatomic1:s390x. 1435s Preparing to unpack .../18-libatomic1_10.5.0-1ubuntu1~20.04_s390x.deb ... 1435s Unpacking libatomic1:s390x (10.5.0-1ubuntu1~20.04) ... 1435s Selecting previously unselected package librbd1. 1435s Preparing to unpack .../19-librbd1_15.2.17-0ubuntu0.20.04.6_s390x.deb ... 1435s Unpacking librbd1 (15.2.17-0ubuntu0.20.04.6) ... 1435s Selecting previously unselected package libpython2.7-stdlib:s390x. 1435s Preparing to unpack .../20-libpython2.7-stdlib_2.7.18-1~20.04.4_s390x.deb ... 1435s Unpacking libpython2.7-stdlib:s390x (2.7.18-1~20.04.4) ... 1435s Selecting previously unselected package python2.7. 1435s Preparing to unpack .../21-python2.7_2.7.18-1~20.04.4_s390x.deb ... 1435s Unpacking python2.7 (2.7.18-1~20.04.4) ... 1435s Selecting previously unselected package fio. 1435s Preparing to unpack .../22-fio_3.16-1_s390x.deb ... 1435s Unpacking fio (3.16-1) ... 1435s Selecting previously unselected package lsscsi. 1435s Preparing to unpack .../23-lsscsi_0.30-0.1_s390x.deb ... 1435s Unpacking lsscsi (0.30-0.1) ... 1435s Selecting previously unselected package autopkgtest-satdep. 1435s Preparing to unpack .../24-2-autopkgtest-satdep.deb ... 1435s Unpacking autopkgtest-satdep (0) ... 1435s Setting up libconfig-general-perl (2.63-1) ... 1435s Setting up libtirpc-common (1.2.5-1ubuntu0.1) ... 1435s Setting up libboost-iostreams1.71.0:s390x (1.71.0-6ubuntu6) ... 1435s Setting up libnl-route-3-200:s390x (3.4.0-1ubuntu0.1) ... 1435s Setting up libglusterfs0:s390x (7.2-2build1) ... 1435s Setting up libpython2.7-minimal:s390x (2.7.18-1~20.04.4) ... 1435s Setting up python2.7-minimal (2.7.18-1~20.04.4) ... 1436s Setting up libatomic1:s390x (10.5.0-1ubuntu1~20.04) ... 1436s Setting up lsscsi (0.30-0.1) ... 1436s Setting up libisns0:s390x (0.97-3) ... 1436s Setting up libboost-thread1.71.0:s390x (1.71.0-6ubuntu6) ... 1436s Setting up libtirpc3:s390x (1.2.5-1ubuntu0.1) ... 1436s Setting up libibverbs1:s390x (28.0-1ubuntu1) ... 1436s Setting up open-iscsi (2.0.874-7.1ubuntu6.4) ... 1436s grep: /lib/modules-load.d/open-iscsi.conf: No such file or directory 1436s Created symlink /etc/systemd/system/sockets.target.wants/iscsid.socket → /lib/systemd/system/iscsid.socket. 1436s Created symlink /etc/systemd/system/iscsi.service → /lib/systemd/system/open-iscsi.service. 1436s Created symlink /etc/systemd/system/sysinit.target.wants/open-iscsi.service → /lib/systemd/system/open-iscsi.service. 1437s Setting up libpython2.7-stdlib:s390x (2.7.18-1~20.04.4) ... 1437s Setting up libgfxdr0:s390x (7.2-2build1) ... 1437s Setting up librdmacm1:s390x (28.0-1ubuntu1) ... 1437s Setting up librados2 (15.2.17-0ubuntu0.20.04.6) ... 1437s Setting up python2.7 (2.7.18-1~20.04.4) ... 1438s Setting up librbd1 (15.2.17-0ubuntu0.20.04.6) ... 1438s Setting up tgt (1:1.0.79-2ubuntu1) ... 1439s Created symlink /etc/systemd/system/multi-user.target.wants/tgt.service → /lib/systemd/system/tgt.service. 1439s Setting up libgfrpc0:s390x (7.2-2build1) ... 1439s Setting up libgfapi0:s390x (7.2-2build1) ... 1439s Setting up fio (3.16-1) ... 1440s Processing triggers for libc-bin (2.31-0ubuntu9.14) ... 1440s Processing triggers for systemd (245.4-4ubuntu3.23) ... 1440s Processing triggers for man-db (2.9.1-1) ... 1440s Processing triggers for mime-support (3.64ubuntu1) ... 1440s Processing triggers for initramfs-tools (0.136ubuntu6.8) ... 1440s update-initramfs: Generating /boot/initrd.img-5.4.0-174-generic 1447s Using config file '/etc/zipl.conf' 1447s Building bootmap in '/boot' 1447s Adding IPL section 'ubuntu' (default) 1447s Preparing boot device: vda (0000). 1447s Done. 1447s Setting up autopkgtest-satdep (0) ... 1451s (Reading database ... 72230 files and directories currently installed.) 1451s Removing autopkgtest-satdep (0) ... 1453s autopkgtest [11:00:36]: test tgtbasedmpaths: [----------------------- 1453s + targetname=iqn.2016-11.foo.com:target.iscsi 1453s + pwd 1453s + cwd=/tmp/autopkgtest.bKMOuX/build.NmX/src 1453s + testdir=/mnt/tgtmpathtest 1453s + localhost=127.0.0.1 1453s + portal=127.0.0.1:3260 1453s + maxpaths=4 1453s + backfn=backingfile 1453s + expectwwid=60000000000000000e00000000010001 1453s + testdisk=/dev/disk/by-id/wwn-0x60000000000000000e00000000010001 1453s + bglog=/tmp/autopkgtest.bKMOuX/tgtbasedmpaths-artifacts/test-background.log 1453s + fioprep=/tmp/autopkgtest.bKMOuX/tgtbasedmpaths-artifacts/path-change-prep.fio 1453s + fiovrfy=/tmp/autopkgtest.bKMOuX/tgtbasedmpaths-artifacts/path-change-check.fio 1453s + service tgt restart 1453s + truncate --size 100M backingfile 1453s + tgtadm --lld iscsi --op new --mode target --tid 1 -T iqn.2016-11.foo.com:target.iscsi 1453s + tgtadm --lld iscsi --op bind --mode target --tid 1 -I ALL 1453s + tgtadm --lld iscsi --op new --mode logicalunit --tid 1 --lun 1 -b /tmp/autopkgtest.bKMOuX/build.NmX/src/backingfile 1453s + iscsiadm --mode discovery --type sendtargets --portal 127.0.0.1 1453s 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi 1453s login #1 1453s + echo login #1 1453s + iscsiadm --mode node --targetname iqn.2016-11.foo.com:target.iscsi --portal 127.0.0.1:3260 --login 1453s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 1453s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 1453s + seq 2 4 1453s + echo extra login #2 1453s + iscsiadm --mode session -r 1 --op new 1453s extra login #2 1453s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 1453s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 1453s extra login #3 1453s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 1453s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 1453s extra login #4 1453s + echo extra login #3 1453s + iscsiadm --mode session -r 1 --op new 1453s + echo extra login #4 1453s + iscsiadm --mode session -r 1 --op new 1453s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 1453s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 1453s + udevadm settle 1454s + sleep 5 1459s Status after initial setup 1459s Target 1: iqn.2016-11.foo.com:target.iscsi 1459s System information: 1459s Driver: iscsi 1459s State: ready 1459s I_T nexus information: 1459s I_T nexus: 1 1459s Initiator: iqn.1993-08.org.debian:01:74468eeb018 alias: autopkgtest 1459s Connection: 0 1459s IP Address: 127.0.0.1 1459s I_T nexus: 2 1459s Initiator: iqn.1993-08.org.debian:01:74468eeb018 alias: autopkgtest 1459s Connection: 0 1459s IP Address: 127.0.0.1 1459s I_T nexus: 3 1459s Initiator: iqn.1993-08.org.debian:01:74468eeb018 alias: autopkgtest 1459s Connection: 0 1459s IP Address: 127.0.0.1 1459s I_T nexus: 4 1459s Initiator: iqn.1993-08.org.debian:01:74468eeb018 alias: autopkgtest 1459s Connection: 0 1459s IP Address: 127.0.0.1 1459s LUN information: 1459s LUN: 0 1459s Type: controller 1459s SCSI ID: IET 00010000 1459s SCSI SN: beaf10 1459s Size: 0 MB, Block size: 1 1459s Online: Yes 1459s Removable media: No 1459s Prevent removal: No 1459s Readonly: No 1459s SWP: No 1459s Thin-provisioning: No 1459s Backing store type: null 1459s Backing store path: None 1459s Backing store flags: 1459s LUN: 1 1459s Type: disk 1459s SCSI ID: IET 00010001 1459s SCSI SN: beaf11 1459s Size: 105 MB, Block size: 512 1459s Online: Yes 1459s Removable media: No 1459s Prevent removal: No 1459s Readonly: No 1459s SWP: No 1459s Thin-provisioning: No 1459s Backing store type: rdwr 1459s Backing store path: /tmp/autopkgtest.bKMOuX/build.NmX/src/backingfile 1459s Backing store flags: 1459s Account information: 1459s ACL information: 1459s ALL 1459s + echo Status after initial setup 1459s + tgtadm --lld iscsi --mode target --op show 1459s + tgtadm --lld iscsi --op show --mode conn --tid 1 1459s Session: 4 1459s Connection: 0 1459s Initiator: iqn.1993-08.org.debian:01:74468eeb018 1459s IP Address: 127.0.0.1 1459s Session: 3 1459s Connection: 0 1459s Initiator: iqn.1993-08.org.debian:01:74468eeb018 1459s IP Address: 127.0.0.1 1459s Session: 2 1459s Connection: 0 1459s Initiator: iqn.1993-08.org.debian:01:74468eeb018 1459s IP Address: 127.0.0.1 1459s Session: 1 1459s Connection: 0 1459s Initiator: iqn.1993-08.org.debian:01:74468eeb018 1459s IP Address: 127.0.0.1 1459s + iscsiadm --mode session -P 1 1459s Target: iqn.2016-11.foo.com:target.iscsi (non-flash) 1459s Current Portal: 127.0.0.1:3260,1 1459s Persistent Portal: 127.0.0.1:3260,1 1459s ********** 1459s Interface: 1459s ********** 1459s Iface Name: default 1459s Iface Transport: tcp 1459s Iface Initiatorname: iqn.1993-08.org.debian:01:74468eeb018 1459s Iface IPaddress: 127.0.0.1 1459s Iface HWaddress: 1459s Iface Netdev: 1459s SID: 1 1459s iSCSI Connection State: LOGGED IN 1459s iSCSI Session State: LOGGED_IN 1459s Internal iscsid Session State: NO CHANGE 1459s 1459s ********** 1459s Interface: 1459s ********** 1459s Iface Name: default 1459s Iface Transport: tcp 1459s Iface Initiatorname: iqn.1993-08.org.debian:01:74468eeb018 1459s Iface IPaddress: 127.0.0.1 1459s Iface HWaddress: 1459s Iface Netdev: 1459s SID: 4 1459s iSCSI Connection State: LOGGED IN 1459s iSCSI Session State: LOGGED_IN 1459s Internal iscsid Session State: NO CHANGE 1459s 1459s ********** 1459s Interface: 1459s ********** 1459s Iface Name: default 1459s Iface Transport: tcp 1459s Iface Initiatorname: iqn.1993-08.org.debian:01:74468eeb018 1459s Iface IPaddress: 127.0.0.1 1459s Iface HWaddress: 1459s Iface Netdev: 1459s SID: 3 1459s iSCSI Connection State: LOGGED IN 1459s iSCSI Session State: LOGGED_IN 1459s Internal iscsid Session State: NO CHANGE 1459s 1459s ********** 1459s Interface: 1459s ********** 1459s Iface Name: default 1459s Iface Transport: tcp 1459s Iface Initiatorname: iqn.1993-08.org.debian:01:74468eeb018 1459s Iface IPaddress: 127.0.0.1 1459s Iface HWaddress: 1459s Iface Netdev: 1459s SID: 2 1459s iSCSI Connection State: LOGGED IN 1459s iSCSI Session State: LOGGED_IN 1459s Internal iscsid Session State: NO CHANGE 1459s + lsscsi -liv 1459s [0:0:0:0] storage IET Controller 0001 - - 1459s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 1459s dir: /sys/bus/scsi/devices/0:0:0:0 [/sys/devices/platform/host0/session1/target0:0:0/0:0:0:0] 1459s [0:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sda 360000000000000000e00000000010001 1459s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 1459s dir: /sys/bus/scsi/devices/0:0:0:1 [/sys/devices/platform/host0/session1/target0:0:0/0:0:0:1] 1459s [1:0:0:0] storage IET Controller 0001 - - 1459s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 1459s dir: /sys/bus/scsi/devices/1:0:0:0 [/sys/devices/platform/host1/session2/target1:0:0/1:0:0:0] 1459s [1:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdb 1IET_00010001 1459s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 1459s dir: /sys/bus/scsi/devices/1:0:0:1 [/sys/devices/platform/host1/session2/target1:0:0/1:0:0:1] 1459s [2:0:0:0] storage IET Controller 0001 - - 1459s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 1459s dir: /sys/bus/scsi/devices/2:0:0:0 [/sys/devices/platform/host2/session3/target2:0:0/2:0:0:0] 1459s [2:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdc 360000000000000000e00000000010001 1459s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 1459s dir: /sys/bus/scsi/devices/2:0:0:1 [/sys/devices/platform/host2/session3/target2:0:0/2:0:0:1] 1459s [3:0:0:0] storage IET Controller 0001 - - 1459s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 1459s dir: /sys/bus/scsi/devices/3:0:0:0 [/sys/devices/platform/host3/session4/target3:0:0/3:0:0:0] 1459s [3:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdd 360000000000000000e00000000010001 1459s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 1459s dir: /sys/bus/scsi/devices/3:0:0:1 [/sys/devices/platform/host3/session4/target3:0:0/3:0:0:1] 1459s NVMe module may not be loaded 1459s list_ndevices: scandir: /sys/class/nvme/: No such file or directory 1459s + multipath -v3 -ll 1459s Apr 03 11:00:42 | set open fds limit to 1048576/1048576 1459s Apr 03 11:00:42 | loading //lib/multipath/libchecktur.so checker 1459s Apr 03 11:00:42 | checker tur: message table size = 3 1459s Apr 03 11:00:42 | loading //lib/multipath/libprioconst.so prioritizer 1459s Apr 03 11:00:42 | foreign library "nvme" loaded successfully 1459s Apr 03 11:00:42 | vda: device node name blacklisted 1459s Apr 03 11:00:42 | sda: size = 204800 1459s Apr 03 11:00:42 | sda: vendor = IET 1459s Apr 03 11:00:42 | sda: product = VIRTUAL-DISK 1459s Apr 03 11:00:42 | sda: rev = 0001 1459s Apr 03 11:00:42 | sda: h:b:t:l = 0:0:0:1 1459s Apr 03 11:00:42 | sda: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 1459s Apr 03 11:00:42 | sda: 1024 cyl, 4 heads, 50 sectors/track, start at 0 1459s Apr 03 11:00:42 | sda: serial = beaf11 1459s Apr 03 11:00:42 | sda: detect_checker = yes (setting: multipath internal) 1459s Apr 03 11:00:42 | sda: path_checker = tur (setting: multipath internal) 1459s Apr 03 11:00:42 | sda: checker timeout = 30 s (setting: kernel sysfs) 1459s Apr 03 11:00:42 | sda: tur state = up 1459s Apr 03 11:00:42 | sdb: size = 204800 1459s Apr 03 11:00:42 | sdb: vendor = IET 1459s Apr 03 11:00:42 | sdb: product = VIRTUAL-DISK 1459s Apr 03 11:00:42 | sdb: rev = 0001 1459s Apr 03 11:00:42 | sdb: h:b:t:l = 1:0:0:1 1459s Apr 03 11:00:42 | sdb: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 1459s Apr 03 11:00:42 | sdb: 1024 cyl, 4 heads, 50 sectors/track, start at 0 1459s Apr 03 11:00:42 | sdb: serial = beaf11 1459s Apr 03 11:00:42 | sdb: detect_checker = yes (setting: multipath internal) 1459s Apr 03 11:00:42 | sdb: path_checker = tur (setting: multipath internal) 1459s Apr 03 11:00:42 | sdb: checker timeout = 30 s (setting: kernel sysfs) 1459s Apr 03 11:00:42 | sdb: tur state = up 1459s Apr 03 11:00:42 | sdc: size = 204800 1459s Apr 03 11:00:42 | sdc: vendor = IET 1459s Apr 03 11:00:42 | sdc: product = VIRTUAL-DISK 1459s Apr 03 11:00:42 | sdc: rev = 0001 1459s Apr 03 11:00:42 | sdc: h:b:t:l = 2:0:0:1 1459s Apr 03 11:00:42 | sdc: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 1459s Apr 03 11:00:42 | sdc: 1024 cyl, 4 heads, 50 sectors/track, start at 0 1459s Apr 03 11:00:42 | sdc: serial = beaf11 1459s Apr 03 11:00:42 | sdc: detect_checker = yes (setting: multipath internal) 1459s Apr 03 11:00:42 | sdc: path_checker = tur (setting: multipath internal) 1459s Apr 03 11:00:42 | sdc: checker timeout = 30 s (setting: kernel sysfs) 1459s Apr 03 11:00:42 | sdc: tur state = up 1459s Apr 03 11:00:42 | sdd: size = 204800 1459s Apr 03 11:00:42 | sdd: vendor = IET 1459s Apr 03 11:00:42 | sdd: product = VIRTUAL-DISK 1459s Apr 03 11:00:42 | sdd: rev = 0001 1459s Apr 03 11:00:42 | sdd: h:b:t:l = 3:0:0:1 1459s Apr 03 11:00:42 | sdd: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 1459s Apr 03 11:00:42 | sdd: 1024 cyl, 4 heads, 50 sectors/track, start at 0 1459s Apr 03 11:00:42 | sdd: serial = beaf11 1459s Apr 03 11:00:42 | sdd: detect_checker = yes (setting: multipath internal) 1459s Apr 03 11:00:42 | sdd: path_checker = tur (setting: multipath internal) 1459s Apr 03 11:00:42 | sdd: checker timeout = 30 s (setting: kernel sysfs) 1459s Apr 03 11:00:42 | sdd: tur state = up 1459s Apr 03 11:00:42 | loop0: device node name blacklisted 1459s Apr 03 11:00:42 | loop1: device node name blacklisted 1459s Apr 03 11:00:42 | loop2: device node name blacklisted 1459s Apr 03 11:00:42 | loop3: device node name blacklisted 1459s Apr 03 11:00:42 | loop4: device node name blacklisted 1459s Apr 03 11:00:42 | loop5: device node name blacklisted 1459s Apr 03 11:00:42 | loop6: device node name blacklisted 1459s Apr 03 11:00:42 | loop7: device node name blacklisted 1459s Apr 03 11:00:42 | dm-0: device node name blacklisted 1459s Apr 03 11:00:42 | libdevmapper version 1.02.167 (2019-11-30) 1459s Apr 03 11:00:42 | DM multipath kernel driver v1.13.0 1459s Apr 03 11:00:42 | params = 0 0 4 1 service-time 0 1 2 8:0 1 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 1459s Apr 03 11:00:42 | status = 2 0 0 0 4 1 A 0 1 2 8:0 A 0 0 1 E 0 1 2 8:16 A 0 0 1 E 0 1 2 8:32 A 0 0 1 E 0 1 2 8:48 A 0 0 1 1459s Apr 03 11:00:42 | sda: detect_prio = yes (setting: multipath internal) 1459s Apr 03 11:00:42 | sda: prio = const (setting: multipath internal) 1459s Apr 03 11:00:42 | sda: prio args = "" (setting: multipath internal) 1459s Apr 03 11:00:42 | sda: const prio = 1 1459s Apr 03 11:00:42 | sdb: detect_prio = yes (setting: multipath internal) 1459s Apr 03 11:00:42 | sdb: prio = const (setting: multipath internal) 1459s Apr 03 11:00:42 | sdb: prio args = "" (setting: multipath internal) 1459s Apr 03 11:00:42 | sdb: const prio = 1 1459s Apr 03 11:00:42 | sdc: detect_prio = yes (setting: multipath internal) 1459s Apr 03 11:00:42 | sdc: prio = const (setting: multipath internal) 1459s Apr 03 11:00:42 | sdc: prio args = "" (setting: multipath internal) 1459s Apr 03 11:00:42 | sdc: const prio = 1 1459s Apr 03 11:00:42 | sdd: detect_prio = yes (setting: multipath internal) 1459s Apr 03 11:00:42 | sdd: prio = const (setting: multipath internal) 1459s Apr 03 11:00:42 | sdd: prio args = "" (setting: multipath internal) 1459s Apr 03 11:00:42 | sdd: const prio = 1 1459s Apr 03 11:00:42 | unloading const prioritizer 1459s Apr 03 11:00:42 | unloading tur checker 1459s ===== paths list ===== 1459s uuid hcil dev dev_t pri dm_st chk_st vend/prod/rev dev_st 1459s 0:0:0:1 sda 8:0 -1 undef undef IET,VIRTUAL-DISK unknown 1459s 1:0:0:1 sdb 8:16 -1 undef undef IET,VIRTUAL-DISK unknown 1459s 2:0:0:1 sdc 8:32 -1 undef undef IET,VIRTUAL-DISK unknown 1459s 3:0:0:1 sdd 8:48 -1 undef undef IET,VIRTUAL-DISK unknown 1459s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 1459s size=100M features='0' hwhandler='0' wp=rw 1459s |-+- policy='service-time 0' prio=1 status=active 1459s | `- 0:0:0:1 sda 8:0 active ready running 1459s |-+- policy='service-time 0' prio=1 status=enabled 1459s | `- 1:0:0:1 sdb 8:16 active ready running 1459s |-+- policy='service-time 0' prio=1 status=enabled 1459s | `- 2:0:0:1 sdc 8:32 active ready running 1459s `-+- policy='service-time 0' prio=1 status=enabled 1459s `- 3:0:0:1 sdd 8:48 active ready running 1459s mpatha: 0 204800 multipath 0 0 4 1 service-time 0 1 2 8:0 1 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 1459s Test WWN should now point to DM 1459s ../../dm-0 1459s Creating filesystem with 25600 4k blocks and 25600 inodes 1459s 1459s Allocating group tables: 0/1 done 1459s Writing inode tables: 0/1 done 1459s Creating journal (1024 blocks): + dmsetup table 1459s + echo Test WWN should now point to DM 1459s + grep dm 1459s + readlink /dev/disk/by-id/wwn-0x60000000000000000e00000000010001 1459s + mkfs.ext4 -F /dev/disk/by-id/wwn-0x60000000000000000e00000000010001 1459s mke2fs 1.45.5 (07-Jan-2020) 1459s done 1459s Writing superblocks and filesystem accounting information: 0/1 + udevadm settle 1459s done 1459s 1459s + sleep 3s 1462s + mkdir -p /mnt/tgtmpathtest 1462s + mount /dev/disk/by-id/wwn-0x60000000000000000e00000000010001 /mnt/tgtmpathtest 1462s + cat 1462s + cat 1462s + fio /tmp/autopkgtest.bKMOuX/tgtbasedmpaths-artifacts/path-change-prep.fio 1462s 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 1462s fio-3.16 1462s Starting 1 thread 1462s write-phase: Laying out IO file (1 file / 17592186044415MiB) 1463s fio: io_u error on file /mnt/tgtmpathtest/datafile.tmp: No space left on device: write offset=95158272, buflen=65536 1463s 1463s write-phase: (groupid=0, jobs=1): err= 0: pid=4800: Wed Apr 3 11:00:46 2024 1463s write: IOPS=1670, BW=104MiB/s (109MB/s)(90.8MiB/870msec); 0 zone resets 1463s clat (usec): min=205, max=16480, avg=572.16, stdev=817.66 1463s lat (usec): min=219, max=16509, avg=596.70, stdev=821.11 1463s clat percentiles (usec): 1463s | 1.00th=[ 231], 5.00th=[ 247], 10.00th=[ 289], 20.00th=[ 338], 1463s | 30.00th=[ 367], 40.00th=[ 392], 50.00th=[ 420], 60.00th=[ 449], 1463s | 70.00th=[ 486], 80.00th=[ 545], 90.00th=[ 709], 95.00th=[ 1205], 1463s | 99.00th=[ 3982], 99.50th=[ 5604], 99.90th=[13173], 99.95th=[16450], 1463s | 99.99th=[16450] 1463s bw ( KiB/s): min=103296, max=103296, per=96.71%, avg=103296.00, stdev= 0.00, samples=1 1463s iops : min= 1614, max= 1614, avg=1614.00, stdev= 0.00, samples=1 1463s lat (usec) : 250=5.30%, 500=68.13%, 750=17.34%, 1000=2.82% 1463s lat (msec) : 2=3.58%, 4=1.79%, 10=0.83%, 20=0.14% 1463s cpu : usr=4.03%, sys=5.29%, ctx=1455, majf=0, minf=2 1463s IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0% 1463s submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 1463s complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 1463s issued rwts: total=0,1453,0,0 short=0,0,0,0 dropped=0,0,0,0 1463s latency : target=0, window=0, percentile=100.00%, depth=1 1463s 1463s Run status group 0 (all jobs): 1463s WRITE: bw=104MiB/s (109MB/s), 104MiB/s-104MiB/s (109MB/s-109MB/s), io=90.8MiB (95.2MB), run=870-870msec 1463s 1463s Disk stats (read/write): 1463s dm-0: ios=1/1055, merge=0/0, ticks=0/644, in_queue=20, util=87.13%, aggrios=0/363, aggrmerge=0/0, aggrticks=0/194, aggrin_queue=5, aggrutil=89.07% 1463s sdd: ios=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 1463s sdb: ios=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 1463s sdc: ios=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 1463s sda: ios=1/1453, merge=0/0, ticks=0/778, in_queue=20, util=89.07% 1463s Starting the path changes in background 1463s + echo Starting the path changes in background 1463s + date +Pre FIO %H:%M:%S.%N 1463s + fio /tmp/autopkgtest.bKMOuX/tgtbasedmpaths-artifacts/path-change-check.fio 1463s Pre FIO 11:00:46.875550672 1464s 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 1464s fio-3.16 1464s Starting 1 thread 1644s 1644s verify-phase: (groupid=0, jobs=1): err= 0: pid=4811: Wed Apr 3 11:03:47 2024 1644s read: IOPS=3697, BW=231MiB/s (242MB/s)(40.6GiB/180001msec) 1644s clat (usec): min=67, max=168106, avg=244.76, stdev=554.31 1644s lat (usec): min=67, max=168106, avg=244.91, stdev=554.34 1644s clat percentiles (usec): 1644s | 1.00th=[ 84], 5.00th=[ 104], 10.00th=[ 125], 20.00th=[ 149], 1644s | 30.00th=[ 167], 40.00th=[ 182], 50.00th=[ 198], 60.00th=[ 217], 1644s | 70.00th=[ 237], 80.00th=[ 265], 90.00th=[ 310], 95.00th=[ 383], 1644s | 99.00th=[ 1418], 99.50th=[ 2245], 99.90th=[ 4883], 99.95th=[ 7046], 1644s | 99.99th=[10814] 1644s bw ( KiB/s): min=84439, max=437504, per=99.91%, avg=236456.87, stdev=55526.91, samples=359 1644s iops : min= 1319, max= 6836, avg=3694.59, stdev=867.61, samples=359 1644s lat (usec) : 100=4.46%, 250=70.89%, 500=21.63%, 750=1.07%, 1000=0.38% 1644s lat (msec) : 2=0.96%, 4=0.46%, 10=0.13%, 20=0.02%, 50=0.01% 1644s lat (msec) : 100=0.01%, 250=0.01% 1644s cpu : usr=9.27%, sys=6.35%, ctx=666612, majf=0, minf=16 1644s IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0% 1644s submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 1644s complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 1644s issued rwts: total=665618,0,0,0 short=0,0,0,0 dropped=0,0,0,0 1644s latency : target=0, window=0, percentile=100.00%, depth=1 1644s 1644s Run status group 0 (all jobs): 1644s READ: bw=231MiB/s (242MB/s), 231MiB/s-231MiB/s (242MB/s-242MB/s), io=40.6GiB (43.6GB), run=180001-180001msec 1644s 1644s Disk stats (read/write): 1644s dm-0: ios=665252/25, merge=0/7, ticks=158118/515, in_queue=2760, util=99.86%, aggrios=42462/2, aggrmerge=0/0, aggrticks=10047/5, aggrin_queue=135, aggrutil=99.10% 1644s sdd: ios=73192/0, merge=0/0, ticks=15957/0, in_queue=130, util=39.34% 1644s sdb: ios=33508/5, merge=0/0, ticks=8220/1, in_queue=80, util=50.20% 1644s sdc: ios=30951/0, merge=0/0, ticks=8137/0, in_queue=70, util=32.85% 1644s sda: ios=32198/4, merge=0/0, ticks=7876/20, in_queue=260, util=99.10% 1644s + date +Post FIO %H:%M:%S.%N 1644s Post FIO 11:03:47.531185515 1644s FIO verify test with changing paths - OK 1644s Report log of background activity 1644s + echo FIO verify test with changing paths - OK 1644s + echo Report log of background activity 1644s + cat /tmp/autopkgtest.bKMOuX/tgtbasedmpaths-artifacts/test-background.log 1644s + iscsiadm --mode session 1644s tcp: [1] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 1644s tcp: [2] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 1644s tcp: [3] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 1644s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 1644s + sleep 10s 1644s + date +MP report (expect 4) %H:%M:%S.%N 1644s MP report (expect 4) 11:00:56.882977913 1644s + multipath -ll 1644s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 1644s size=100M features='0' hwhandler='0' wp=rw 1644s |-+- policy='service-time 0' prio=1 status=active 1644s | `- 0:0:0:1 sda 8:0 active ready running 1644s |-+- policy='service-time 0' prio=1 status=enabled 1644s | `- 1:0:0:1 sdb 8:16 active ready running 1644s |-+- policy='service-time 0' prio=1 status=enabled 1644s | `- 2:0:0:1 sdc 8:32 active ready running 1644s `-+- policy='service-time 0' prio=1 status=enabled 1644s `- 3:0:0:1 sdd 8:48 active ready running 1644s + date +UN-plug path 1 %H:%M:%S.%N 1644s UN-plug path 1 11:00:56.918593354 1644s + iscsiadm --mode session -r 1 -u 1644s Logging out of session [sid: 1, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 1644s Logout of [sid: 1, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 1644s + iscsiadm --mode session 1644s tcp: [2] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 1644s tcp: [3] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 1644s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 1644s + sleep 10s 1644s + date +MP report (expect 3) %H:%M:%S.%N 1644s MP report (expect 3) 11:01:07.033874644 1644s + multipath -ll 1644s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 1644s size=100M features='0' hwhandler='0' wp=rw 1644s |-+- policy='service-time 0' prio=1 status=active 1644s | `- 1:0:0:1 sdb 8:16 active ready running 1644s |-+- policy='service-time 0' prio=1 status=enabled 1644s | `- 2:0:0:1 sdc 8:32 active ready running 1644s `-+- policy='service-time 0' prio=1 status=enabled 1644s `- 3:0:0:1 sdd 8:48 active ready running 1644s + date +UN-plug path 2 %H:%M:%S.%N 1644s UN-plug path 2 11:01:07.049833552 1644s + iscsiadm --mode session -r 2 -u 1644s Logging out of session [sid: 2, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 1644s Logout of [sid: 2, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 1644s + iscsiadm --mode session 1644s tcp: [3] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 1644s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 1644s + sleep 10s 1644s + date +MP report (expect 2) %H:%M:%S.%N 1644s MP report (expect 2) 11:01:17.152310345 1644s + multipath -ll 1644s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 1644s size=100M features='0' hwhandler='0' wp=rw 1644s |-+- policy='service-time 0' prio=1 status=active 1644s | `- 2:0:0:1 sdc 8:32 active ready running 1644s `-+- policy='service-time 0' prio=1 status=enabled 1644s `- 3:0:0:1 sdd 8:48 active ready running 1644s + date +UN-plug path 3 %H:%M:%S.%N 1644s UN-plug path 3 11:01:17.172328844 1644s + iscsiadm --mode session -r 3 -u 1644s Logging out of session [sid: 3, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 1644s Logout of [sid: 3, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 1644s + iscsiadm --mode session 1644s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 1644s + sleep 10s 1644s + date +MP report (expect 1) %H:%M:%S.%N 1644s MP report (expect 1) 11:01:27.253745362 1644s + multipath -ll 1644s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 1644s size=100M features='0' hwhandler='0' wp=rw 1644s `-+- policy='service-time 0' prio=1 status=active 1644s `- 3:0:0:1 sdd 8:48 active ready running 1644s + date +Add paths 5/6/7/8 %H:%M:%S.%N 1644s Add paths 5/6/7/8 11:01:27.267428187 1644s + iscsiadm --mode session -r 4 --op new 1644s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 1644s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 1644s + iscsiadm --mode session -r 4 --op new 1644s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 1644s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 1644s + iscsiadm --mode session -r 4 --op new 1644s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 1644s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 1644s + iscsiadm --mode session -r 4 --op new 1644s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 1644s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 1644s + iscsiadm --mode session 1644s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 1644s tcp: [5] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 1644s tcp: [6] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 1644s tcp: [7] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 1644s tcp: [8] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 1644s + sleep 10s 1644s + date +MP report (expect 5) %H:%M:%S.%N 1644s MP report (expect 5) 11:01:37.350153422 1644s + multipath -ll 1644s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 1644s size=100M features='0' hwhandler='0' wp=rw 1644s |-+- policy='service-time 0' prio=1 status=active 1644s | `- 3:0:0:1 sdd 8:48 active ready running 1644s |-+- policy='service-time 0' prio=1 status=enabled 1644s | `- 1:0:0:1 sdb 8:16 active ready running 1644s |-+- policy='service-time 0' prio=1 status=enabled 1644s | `- 2:0:0:1 sdc 8:32 active ready running 1644s |-+- policy='service-time 0' prio=1 status=enabled 1644s | `- 0:0:0:1 sda 8:0 active ready running 1644s `-+- policy='service-time 0' prio=1 status=enabled 1644s `- 4:0:0:1 sde 8:64 active ready running 1644s + date +UN-plug multiple paths 4/7/8 %H:%M:%S.%N 1644s UN-plug multiple paths 4/7/8 11:01:37.380966976 1644s + iscsiadm --mode session -r 4 -u 1644s Logging out of session [sid: 4, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 1644s Logout of [sid: 4, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 1644s + iscsiadm --mode session -r 7 -u 1644s Logging out of session [sid: 7, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 1644s Logout of [sid: 7, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 1644s + iscsiadm --mode session -r 8 -u 1644s Logging out of session [sid: 8, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 1644s Logout of [sid: 8, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 1644s + iscsiadm --mode session 1644s tcp: [5] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 1644s tcp: [6] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 1644s + sleep 10s 1644s + date +Restart multipath daemon %H:%M:%S.%N 1644s Restart multipath daemon 11:01:47.805356703 1644s + systemctl restart multipathd 1644s + sleep 10s 1644s + date +Final background report (expect 2) %H:%M:%S.%N 1644s Final background report (expect 2) 11:01:57.867393305 1644s + multipath -ll 1644s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 1644s size=100M features='0' hwhandler='0' wp=rw 1644s |-+- policy='service-time 0' prio=1 status=active 1644s | `- 1:0:0:1 sdb 8:16 active ready running 1644s `-+- policy='service-time 0' prio=1 status=enabled 1644s `- 0:0:0:1 sda 8:0 active ready running 1644s + sync 1644s Final stats 1644s Stats for session [sid: 5, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 1644s iSCSI SNMP: 1644s txdata_octets: 7368 1644s rxdata_octets: 1147304 1644s noptx_pdus: 0 1644s scsicmd_pdus: 124 1644s tmfcmd_pdus: 0 1644s login_pdus: 0 1644s text_pdus: 0 1644s dataout_pdus: 0 1644s logout_pdus: 0 1644s snack_pdus: 0 1644s noprx_pdus: 0 1644s scsirsp_pdus: 124 1644s tmfrsp_pdus: 0 1644s textrsp_pdus: 0 1644s datain_pdus: 99 1644s logoutrsp_pdus: 0 1644s r2t_pdus: 0 1644s async_pdus: 0 1644s rjt_pdus: 0 1644s digest_err: 0 1644s timeout_err: 0 1644s iSCSI Extended: 1644s tx_sendpage_failures: 0 1644s rx_discontiguous_hdr: 0 1644s eh_abort_cnt: 0 1644s Stats for session [sid: 6, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 1644s iSCSI SNMP: 1644s txdata_octets: 23747448 1644s rxdata_octets: 32421314648 1644s noptx_pdus: 0 1644s scsicmd_pdus: 494471 1644s tmfcmd_pdus: 0 1644s login_pdus: 0 1644s text_pdus: 0 1644s dataout_pdus: 0 1644s logout_pdus: 0 1644s snack_pdus: 0 1644s noprx_pdus: 0 1644s scsirsp_pdus: 494471 1644s tmfrsp_pdus: 0 1644s textrsp_pdus: 0 1644s datain_pdus: 494428 1644s logoutrsp_pdus: 0 1644s r2t_pdus: 0 1644s async_pdus: 0 1644s rjt_pdus: 0 1644s digest_err: 0 1644s timeout_err: 0 1644s iSCSI Extended: 1644s tx_sendpage_failures: 0 1644s rx_discontiguous_hdr: 0 1644s eh_abort_cnt: 0 1644s + umount /dev/disk/by-id/wwn-0x60000000000000000e00000000010001 1644s + echo Final stats 1644s + iscsiadm --mode session --stats 1644s + journalctl --no-pager -u multipathd 1644s -- Logs begin at Tue 2024-04-02 16:54:10 UTC, end at Wed 2024-04-03 11:03:47 UTC. -- 1644s Apr 02 16:54:11 ubuntu systemd[1]: Starting Device-Mapper Multipath Device Controller... 1644s Apr 02 16:54:11 ubuntu multipathd[450]: --------start up-------- 1644s Apr 02 16:54:11 ubuntu multipathd[450]: read /etc/multipath.conf 1644s Apr 02 16:54:11 ubuntu multipathd[450]: path checkers start up 1644s Apr 02 16:54:11 ubuntu systemd[1]: Started Device-Mapper Multipath Device Controller. 1644s Apr 02 16:59:11 ubuntuubuntu-focal-daily-s390x-server-20220829-disk1 multipathd[450]: exit (signal) 1644s Apr 02 16:59:11 ubuntuubuntu-focal-daily-s390x-server-20220829-disk1 multipathd[450]: --------shut down------- 1644s Apr 02 16:59:11 ubuntuubuntu-focal-daily-s390x-server-20220829-disk1 systemd[1]: Stopping Device-Mapper Multipath Device Controller... 1644s -- Reboot -- 1644s Apr 02 16:59:16 ubuntuubuntu-focal-daily-s390x-server-20220829-disk1 systemd[1]: Starting Device-Mapper Multipath Device Controller... 1644s Apr 02 16:59:16 ubuntuubuntu-focal-daily-s390x-server-20220829-disk1 multipathd[377]: --------start up-------- 1644s Apr 02 16:59:16 ubuntuubuntu-focal-daily-s390x-server-20220829-disk1 multipathd[377]: read /etc/multipath.conf 1644s Apr 02 16:59:16 ubuntuubuntu-focal-daily-s390x-server-20220829-disk1 multipathd[377]: path checkers start up 1644s Apr 02 16:59:16 ubuntuubuntu-focal-daily-s390x-server-20220829-disk1 systemd[1]: Started Device-Mapper Multipath Device Controller. 1644s Apr 02 17:00:19 ubuntuubuntu-focal-daily-s390x-server-20220829-disk1 multipathd[377]: exit (signal) 1644s Apr 02 17:00:19 ubuntuubuntu-focal-daily-s390x-server-20220829-disk1 multipathd[377]: --------shut down------- 1644s Apr 02 17:00:19 ubuntuubuntu-focal-daily-s390x-server-20220829-disk1 systemd[1]: Stopping Device-Mapper Multipath Device Controller... 1644s Apr 02 17:00:19 ubuntuubuntu-focal-daily-s390x-server-20220829-disk1 systemd[1]: multipathd.service: Succeeded. 1644s Apr 02 17:00:19 ubuntuubuntu-focal-daily-s390x-server-20220829-disk1 systemd[1]: Stopped Device-Mapper Multipath Device Controller. 1644s -- Reboot -- 1644s Apr 03 10:56:51 ubuntuubuntu-focal-daily-s390x-server-20220829-disk1 systemd[1]: Starting Device-Mapper Multipath Device Controller... 1644s Apr 03 10:56:51 ubuntuubuntu-focal-daily-s390x-server-20220829-disk1 multipathd[441]: --------start up-------- 1644s Apr 03 10:56:51 ubuntuubuntu-focal-daily-s390x-server-20220829-disk1 multipathd[441]: read /etc/multipath.conf 1644s Apr 03 10:56:51 ubuntuubuntu-focal-daily-s390x-server-20220829-disk1 multipathd[441]: path checkers start up 1644s Apr 03 10:56:51 ubuntuubuntu-focal-daily-s390x-server-20220829-disk1 systemd[1]: Started Device-Mapper Multipath Device Controller. 1644s Apr 03 10:59:13 autopkgtest multipathd[441]: exit (signal) 1644s Apr 03 10:59:13 autopkgtest systemd[1]: Stopping Device-Mapper Multipath Device Controller... 1644s Apr 03 10:59:13 autopkgtest multipathd[441]: --------shut down------- 1644s -- Reboot -- 1644s Apr 03 10:59:15 autopkgtest systemd[1]: Starting Device-Mapper Multipath Device Controller... 1644s Apr 03 10:59:15 autopkgtest multipathd[442]: --------start up-------- 1644s Apr 03 10:59:15 autopkgtest multipathd[442]: read /etc/multipath.conf 1644s Apr 03 10:59:15 autopkgtest multipathd[442]: path checkers start up 1644s Apr 03 10:59:15 autopkgtest systemd[1]: Started Device-Mapper Multipath Device Controller. 1644s Apr 03 10:59:23 autopkgtest multipathd[442]: exit (signal) 1644s Apr 03 10:59:23 autopkgtest systemd[1]: Stopping Device-Mapper Multipath Device Controller... 1644s Apr 03 10:59:23 autopkgtest multipathd[442]: --------shut down------- 1644s Apr 03 10:59:23 autopkgtest systemd[1]: multipathd.service: Succeeded. 1644s Apr 03 10:59:23 autopkgtest systemd[1]: Stopped Device-Mapper Multipath Device Controller. 1644s -- Reboot -- 1644s Apr 03 10:59:30 autopkgtest systemd[1]: Starting Device-Mapper Multipath Device Controller... 1644s Apr 03 10:59:30 autopkgtest multipathd[449]: --------start up-------- 1644s Apr 03 10:59:30 autopkgtest multipathd[449]: read /etc/multipath.conf 1644s Apr 03 10:59:30 autopkgtest multipathd[449]: path checkers start up 1644s Apr 03 10:59:30 autopkgtest systemd[1]: Started Device-Mapper Multipath Device Controller. 1644s Apr 03 11:00:38 autopkgtest multipathd[449]: mpatha: load table [0 204800 multipath 0 0 2 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:16 1] 1644s Apr 03 11:00:38 autopkgtest multipathd[449]: sdb [8:16]: path added to devmap mpatha 1644s Apr 03 11:00:39 autopkgtest multipathd[449]: mpatha: performing delayed actions 1644s Apr 03 11:00:39 autopkgtest multipathd[449]: mpatha: load table [0 204800 multipath 0 0 4 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:48 1] 1644s Apr 03 11:00:56 autopkgtest multipathd[449]: sda: mark as failed 1644s Apr 03 11:00:56 autopkgtest multipathd[449]: mpatha: remaining active paths: 3 1644s Apr 03 11:00:57 autopkgtest multipathd[449]: mpatha: load table [0 204800 multipath 0 0 3 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:48 1] 1644s Apr 03 11:00:57 autopkgtest multipathd[449]: sda [8:0]: path removed from map mpatha 1644s Apr 03 11:01:07 autopkgtest multipathd[449]: mpatha: load table [0 204800 multipath 0 0 2 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:48 1] 1644s Apr 03 11:01:07 autopkgtest multipathd[449]: sdb [8:16]: path removed from map mpatha 1644s Apr 03 11:01:17 autopkgtest multipathd[449]: mpatha: load table [0 204800 multipath 0 0 1 1 service-time 0 1 1 8:48 1] 1644s Apr 03 11:01:17 autopkgtest multipathd[449]: sdc [8:32]: path removed from map mpatha 1644s Apr 03 11:01:27 autopkgtest multipathd[449]: mpatha: load table [0 204800 multipath 0 0 2 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:16 1] 1644s Apr 03 11:01:27 autopkgtest multipathd[449]: sdb [8:16]: path added to devmap mpatha 1644s Apr 03 11:01:28 autopkgtest multipathd[449]: mpatha: load table [0 204800 multipath 0 0 3 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:32 1] 1644s Apr 03 11:01:28 autopkgtest multipathd[449]: sdc [8:32]: path added to devmap mpatha 1644s Apr 03 11:01:28 autopkgtest multipathd[449]: mpatha: load table [0 204800 multipath 0 0 4 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:0 1] 1644s Apr 03 11:01:28 autopkgtest multipathd[449]: sda [8:0]: path added to devmap mpatha 1644s Apr 03 11:01:28 autopkgtest multipathd[449]: mpatha: load table [0 204800 multipath 0 0 5 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:64 1] 1644s Apr 03 11:01:28 autopkgtest multipathd[449]: sde [8:64]: path added to devmap mpatha 1644s Apr 03 11:01:37 autopkgtest multipathd[449]: mpatha: load table [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:0 1 service-time 0 1 1 8:64 1] 1644s Apr 03 11:01:37 autopkgtest multipathd[449]: sdd [8:48]: path removed from map mpatha 1644s Apr 03 11:01:37 autopkgtest multipathd[449]: 8:32: cannot find block device 1644s Apr 03 11:01:38 autopkgtest multipathd[449]: 8:32: cannot find block device 1644s Apr 03 11:01:38 autopkgtest multipathd[449]: 8:64: cannot find block device 1644s Apr 03 11:01:38 autopkgtest multipathd[449]: sde: No iscsi session for 'session8' 1644s Apr 03 11:01:38 autopkgtest multipathd[449]: mpatha: load table [0 204800 multipath 0 0 3 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:64 1] 1644s Apr 03 11:01:38 autopkgtest multipathd[449]: 8:64: cannot find block device 1644s Apr 03 11:01:38 autopkgtest multipathd[449]: sdc [8:32]: path removed from map mpatha 1644s Apr 03 11:01:38 autopkgtest multipathd[449]: mpatha: load table [0 204800 multipath 0 0 2 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:0 1] 1644s Apr 03 11:01:38 autopkgtest multipathd[449]: sde [8:64]: path removed from map mpatha 1644s Apr 03 11:01:47 autopkgtest multipathd[449]: exit (signal) 1644s Apr 03 11:01:47 autopkgtest multipathd[449]: --------shut down------- 1644s Apr 03 11:01:47 autopkgtest systemd[1]: Stopping Device-Mapper Multipath Device Controller... 1644s Apr 03 11:01:47 autopkgtest systemd[1]: multipathd.service: Succeeded. 1644s Apr 03 11:01:47 autopkgtest systemd[1]: Stopped Device-Mapper Multipath Device Controller. 1644s Apr 03 11:01:47 autopkgtest systemd[1]: Starting Device-Mapper Multipath Device Controller... 1644s Apr 03 11:01:47 autopkgtest multipathd[5218]: --------start up-------- 1644s Apr 03 11:01:47 autopkgtest multipathd[5218]: read /etc/multipath.conf 1644s Apr 03 11:01:47 autopkgtest multipathd[5218]: path checkers start up 1644s Apr 03 11:01:47 autopkgtest systemd[1]: Started Device-Mapper Multipath Device Controller. 1644s Check final path status 1644s + echo Check final path status 1644s + multipath -ll 1644s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 1644s size=100M features='0' hwhandler='0' wp=rw 1644s |-+- policy='service-time 0' prio=1 status=active 1644s | `- 1:0:0:1 sdb 8:16 active ready running 1644s `-+- policy='service-time 0' prio=1 status=enabled 1644s `- 0:0:0:1 sda 8:0 active ready running 1644s + + multipathgrep --count status= 1644s -ll 1644s + diskc=2 1644s + + grep --count status=active 1644s multipath -ll 1644s + diska=1 1644s + multipath -ll 1644s + grep --count status=enabledOK 1644s 1644s + diske=1 1644s + [ 2 -ne 2 -o 1 -ne 1 -o 1 -ne 1 ] 1644s + echo OK 1644s + iscsiadm --mode node --targetname iqn.2016-11.foo.com:target.iscsi --portal 127.0.0.1:3260 --logout 1644s Logging out of session [sid: 5, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 1644s Logging out of session [sid: 6, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 1644s Logout of [sid: 5, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 1644s Logout of [sid: 6, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 1644s + tgtadm --lld iscsi --op delete --mode logicalunit --tid 1 --lun 1 1645s autopkgtest [11:03:48]: test tgtbasedmpaths: -----------------------] 1645s tgtbasedmpaths PASS 1645s autopkgtest [11:03:48]: test tgtbasedmpaths: - - - - - - - - - - results - - - - - - - - - - 1646s autopkgtest [11:03:49]: @@@@@@@@@@@@@@@@@@@@ summary 1646s kpartx-file-loopback PASS 1646s tgtbasedmpaths PASS