0s autopkgtest [18:10:02]: starting date and time: 2024-07-19 18:10:02+0000 0s autopkgtest [18:10:02]: git checkout: fd3bed09 nova: allow more retries for quota issues 0s autopkgtest [18:10:02]: host juju-7f2275-prod-proposed-migration-environment-2; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.n3aod8fw/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:linux-meta,src:linux-signed,src:linux --apt-upgrade multipath-tools --timeout-short=300 --timeout-copy=20000 --timeout-test=20000 --timeout-build=20000 '--env=ADT_TEST_TRIGGERS=linux-meta/6.10.0-15.15 linux-signed/6.10.0-15.15 linux/6.10.0-15.15' --setup-commands 'apt-get install -y ^kernel-testing--linux--full--preferred$ || apt-get install -y ^linux-image$ ^linux-headers$ || apt-get install -y ^linux-image-generic$ ^linux-headers-generic$' --setup-commands 'apt-get install -y ^kernel-testing--linux--modules-extra--preferred$ || apt-get install -y ^linux-modules-extra$ || :' -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest-big --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@bos03-arm64-19.secgroup --name adt-oracular-arm64-multipath-tools-20240719-181001-juju-7f2275-prod-proposed-migration-environment-2-6816d8f0-d73c-42ef-ab54-0fc2d822d9cb --image adt/ubuntu-oracular-arm64-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-2 --net-id=net_prod-proposed-migration -e TERM=linux -e ''"'"'http_proxy=http://squid.internal:3128'"'"'' -e ''"'"'https_proxy=http://squid.internal:3128'"'"'' -e ''"'"'no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,keyserver.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com'"'"'' --mirror=http://ftpmaster.internal/ubuntu/ 384s nova [W] Skipping flock in bos03-arm64 384s Creating nova instance adt-oracular-arm64-multipath-tools-20240719-181001-juju-7f2275-prod-proposed-migration-environment-2-6816d8f0-d73c-42ef-ab54-0fc2d822d9cb from image adt/ubuntu-oracular-arm64-server-20240718.img (UUID a9c28202-db65-432a-996d-c43c7d6f5c5e)... 384s nova [E] nova boot failed (attempt #0): 384s nova [E] DEBUG (extension:189) found extension EntryPoint.parse('v1password = swiftclient.authv1:PasswordLoader') 384s DEBUG (extension:189) found extension EntryPoint.parse('noauth = cinderclient.contrib.noauth:CinderNoAuthLoader') 384s DEBUG (extension:189) found extension EntryPoint.parse('admin_token = keystoneauth1.loading._plugins.admin_token:AdminToken') 384s DEBUG (extension:189) found extension EntryPoint.parse('none = keystoneauth1.loading._plugins.noauth:NoAuth') 384s DEBUG (extension:189) found extension EntryPoint.parse('password = keystoneauth1.loading._plugins.identity.generic:Password') 384s DEBUG (extension:189) found extension EntryPoint.parse('token = keystoneauth1.loading._plugins.identity.generic:Token') 384s DEBUG (extension:189) found extension EntryPoint.parse('v2password = keystoneauth1.loading._plugins.identity.v2:Password') 384s DEBUG (extension:189) found extension EntryPoint.parse('v2token = keystoneauth1.loading._plugins.identity.v2:Token') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3adfspassword = keystoneauth1.extras._saml2._loading:ADFSPassword') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3applicationcredential = keystoneauth1.loading._plugins.identity.v3:ApplicationCredential') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3fedkerb = keystoneauth1.extras.kerberos._loading:MappedKerberos') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3kerberos = keystoneauth1.extras.kerberos._loading:Kerberos') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3multifactor = keystoneauth1.loading._plugins.identity.v3:MultiFactor') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3oauth1 = keystoneauth1.extras.oauth1._loading:V3OAuth1') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcaccesstoken = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAccessToken') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcauthcode = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAuthorizationCode') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcclientcredentials = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectClientCredentials') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcpassword = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectPassword') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3password = keystoneauth1.loading._plugins.identity.v3:Password') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3samlpassword = keystoneauth1.extras._saml2._loading:Saml2Password') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3token = keystoneauth1.loading._plugins.identity.v3:Token') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3tokenlessauth = keystoneauth1.loading._plugins.identity.v3:TokenlessAuth') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3totp = keystoneauth1.loading._plugins.identity.v3:TOTP') 384s DEBUG (session:517) REQ: curl -g -i -X GET https://keystone.ps6.canonical.com:5000/v3 -H "Accept: application/json" -H "User-Agent: nova keystoneauth1/4.0.0 python-requests/2.22.0 CPython/3.8.10" 384s DEBUG (connectionpool:962) Starting new HTTPS connection (1): keystone.ps6.canonical.com:5000 384s DEBUG (connectionpool:429) https://keystone.ps6.canonical.com:5000 "GET /v3 HTTP/1.1" 200 267 384s DEBUG (session:548) RESP: [200] Connection: Keep-Alive Content-Length: 267 Content-Type: application/json Date: Fri, 19 Jul 2024 18:10:08 GMT Keep-Alive: timeout=75, max=1000 Server: Apache/2.4.52 (Ubuntu) Vary: X-Auth-Token x-openstack-request-id: req-35ea1803-0282-47a2-9d8b-32bf9485a660 384s DEBUG (session:580) RESP BODY: {"version": {"id": "v3.14", "status": "stable", "updated": "2020-04-07T00:00:00Z", "links": [{"rel": "self", "href": "https://keystone.ps6.canonical.com:5000/v3/"}], "media-types": [{"base": "application/json", "type": "application/vnd.openstack.identity-v3+json"}]}} 384s DEBUG (session:946) GET call to https://keystone.ps6.canonical.com:5000/v3 used request id req-35ea1803-0282-47a2-9d8b-32bf9485a660 384s DEBUG (base:182) Making authentication request to https://keystone.ps6.canonical.com:5000/v3/auth/tokens 384s DEBUG (connectionpool:429) https://keystone.ps6.canonical.com:5000 "POST /v3/auth/tokens HTTP/1.1" 201 12445 384s DEBUG (base:187) {"token": {"methods": ["password"], "user": {"domain": {"id": "default", "name": "Default"}, "id": "369f50a481564a2c9433776a4ebd224d", "name": "prod-proposed-migration-arm64", "password_expires_at": null}, "audit_ids": ["m0xZD_-6SKWw-uFdRiNj4A"], "expires_at": "2024-07-20T18:10:08.000000Z", "issued_at": "2024-07-19T18:10:08.000000Z", "project": {"domain": {"id": "default", "name": "Default"}, "id": "bd8b3df3f03d43a0a9303b7c0434fdab", "name": "prod-proposed-migration-arm64_project"}, "is_domain": false, "roles": [{"id": "86bf3043974746c2bf52c2a9f362f986", "name": "reader"}, {"id": "15cf997650e345b7b21c02b5cdb7d84a", "name": "member"}], "is_admin_project": false, "catalog": [{"endpoints": [{"id": "213cdf38198c4581bd5b7d6d0836923b", "interface": "internal", "region_id": "prodstack6", "url": "https://radosgw-internal.ps6.canonical.com:443/", "region": "prodstack6"}, {"id": "67061eee26944a1a8009f9d07be19738", "interface": "public", "region_id": "prodstack6", "url": "https://radosgw.ps6.canonical.com:443/", "region": "prodstack6"}, {"id": "fc88c52c749a47d08a24a2c7efbde01b", "interface": "admin", "region_id": "prodstack6", "url": "https://radosgw-admin.ps6.canonical.com:443/", "region": "prodstack6"}], "id": "06e4714942634054bf9aa11715312b4e", "type": "s3", "name": "s3"}, {"endpoints": [{"id": "8aa44c94b63746bd9b37f1008ad55fa8", "interface": "admin", "region_id": "prodstack6", "url": "https://aodh-admin.ps6.canonical.com:8042", "region": "prodstack6"}, {"id": "92cf08a80a0242ebbca8ec893cf332b1", "interface": "public", "region_id": "prodstack6", "url": "https://aodh.ps6.canonical.com:8042", "region": "prodstack6"}, {"id": "d8139c6e11ae4edcb78981c12bd53212", "interface": "internal", "region_id": "prodstack6", "url": "https://aodh-internal.ps6.canonical.com:8042", "region": "prodstack6"}], "id": "2fb939b0b969435c8f0c5fa4edb4de94", "type": "alarming", "name": "aodh"}, {"endpoints": [{"id": "a49fcc80e658411885f88cdd8432a571", "interface": "internal", "region_id": "prodstack6", "url": "https://heat-internal.ps6.canonical.com:8000/v1", "region": "prodstack6"}, {"id": "b23866fddba8415885b06c064c34b94b", "interface": "public", "region_id": "prodstack6", "url": "https://heat.ps6.canonical.com:8000/v1", "region": "prodstack6"}, {"id": "f84ae55197f94b8392a678f35c82ca26", "interface": "admin", "region_id": "prodstack6", "url": "https://heat-admin.ps6.canonical.com:8000/v1", "region": "prodstack6"}], "id": "3d4b59f7dab644b2b527e8e96b697545", "type": "cloudformation", "name": "heat-cfn"}, {"endpoints": [{"id": "2e0143334c6241169f45f1c11970c6bc", "interface": "public", "region_id": "prodstack6", "url": "https://heat.ps6.canonical.com:8004/v1/bd8b3df3f03d43a0a9303b7c0434fdab", "region": "prodstack6"}, {"id": "5e19c32243c04a3faf1e5f9ab900c260", "interface": "internal", "region_id": "prodstack6", "url": "https://heat-internal.ps6.canonical.com:8004/v1/bd8b3df3f03d43a0a9303b7c0434fdab", "region": "prodstack6"}, {"id": "b3fc5c88ec8543a691fec75726b86967", "interface": "admin", "region_id": "prodstack6", "url": "https://heat-admin.ps6.canonical.com:8004/v1/bd8b3df3f03d43a0a9303b7c0434fdab", "region": "prodstack6"}], "id": "43b926205044476b8093b18d8ce0a9e4", "type": "orchestration", "name": "heat"}, {"endpoints": [{"id": "a47569b96e5b4146a312e4673504557c", "interface": "public", "region_id": "prodstack6", "url": "https://glance.ps6.canonical.com:9292", "region": "prodstack6"}, {"id": "bba35c4ab04f4114a2a34e65568537bd", "interface": "internal", "region_id": "prodstack6", "url": "https://glance-internal.ps6.canonical.com:9292", "region": "prodstack6"}, {"id": "ef769f1117c74a62a279131486c89628", "interface": "admin", "region_id": "prodstack6", "url": "https://glance-admin.ps6.canonical.com:9292", "region": "prodstack6"}], "id": "49de724549524bd78e9cd46a4477226f", "type": "image", "name": "glance"}, {"endpoints": [{"id": "a1a41e9a1e2d42e5b6cd5380cd1e21bf", "interface": "admin", "region_id": "prodstack6", "url": "https://cinder-admin.ps6.canonical.com:8776/v3/bd8b3df3f03d43a0a9303b7c0434fdab", "region": "prodstack6"}, {"id": "d2309a99724b4111827482c68a832c0c", "interface": "public", "region_id": "prodstack6", "url": "https://cinder.ps6.canonical.com:8776/v3/bd8b3df3f03d43a0a9303b7c0434fdab", "region": "prodstack6"}, {"id": "f8a02e3949ff42afa772eb5e74dbef9f", "interface": "internal", "region_id": "prodstack6", "url": "https://cinder-internal.ps6.canonical.com:8776/v3/bd8b3df3f03d43a0a9303b7c0434fdab", "region": "prodstack6"}], "id": "5bf6578a631349e3af4bf36d7adb18e1", "type": "volumev3", "name": "cinderv3"}, {"endpoints": [{"id": "01d84128f36444e9b01549b86bd69116", "interface": "admin", "region_id": "prodstack6", "url": "https://barbican-admin.ps6.canonical.com:9312", "region": "prodstack6"}, {"id": "0ce4a8777e0b40a88f7fc0f77e34a605", "interface": "public", "region_id": "prodstack6", "url": "https://barbican.ps6.canonical.com:9311", "region": "prodstack6"}, {"id": "f507ba49e4a7435cb330234217c92449", "interface": "internal", "region_id": "prodstack6", "url": "https://barbican-internal.ps6.canonical.com:9311", "region": "prodstack6"}], "id": "62cb1c3d9f6c45979c13516a6b3ff114", "type": "key-manager", "name": "barbican"}, {"endpoints": [{"id": "3cb6121bd8f14da8aa2fba7be823a2b4", "interface": "internal", "region_id": "prodstack6", "url": "https://neutron-internal.ps6.canonical.com:9696", "region": "prodstack6"}, {"id": "46ba11d133fe4e8f9e8f9097ba737682", "interface": "admin", "region_id": "prodstack6", "url": "https://neutron-admin.ps6.canonical.com:9696", "region": "prodstack6"}, {"id": "d872eb6aa23d40009165aa3dcdce3948", "interface": "public", "region_id": "prodstack6", "url": "https://neutron.ps6.canonical.com:9696", "region": "prodstack6"}], "id": "759cb6fdfbc146dd8b9d1ba444c4b9db", "type": "network", "name": "neutron"}, {"endpoints": [{"id": "4349d565f72446da9699269f85df5e8b", "interface": "internal", "region_id": "prodstack6", "url": "https://manila-internal.ps6.canonical.com:8786/v2/bd8b3df3f03d43a0a9303b7c0434fdab", "region": "prodstack6"}, {"id": "a483dcc58f5e415e9ec739c94474e609", "interface": "public", "region_id": "prodstack6", "url": "https://manila.ps6.canonical.com:8786/v2/bd8b3df3f03d43a0a9303b7c0434fdab", "region": "prodstack6"}, {"id": "c1f14236723e42878562d8dd63d5a6a0", "interface": "admin", "region_id": "prodstack6", "url": "https://manila-admin.ps6.canonical.com:8786/v2/bd8b3df3f03d43a0a9303b7c0434fdab", "region": "prodstack6"}], "id": "93fc4008035946deb1f433c2dd905a5d", "type": "sharev2", "name": "manilav2"}, {"endpoints": [{"id": "0fa148793c7249c8b187b6b4ff425731", "interface": "internal", "region_id": "prodstack6", "url": "https://radosgw-internal.ps6.canonical.com:443/swift/v1/AUTH_e4b04ca58d734ed0aa29e306adad4f79/simplestreams/data", "region": "prodstack6"}, {"id": "555ade266a6b4bcc81b6e5abf607aec5", "interface": "public", "region_id": "prodstack6", "url": "https://radosgw.ps6.canonical.com:443/swift/v1/AUTH_e4b04ca58d734ed0aa29e306adad4f79/simplestreams/data", "region": "prodstack6"}, {"id": "7dad1a7b1552465686424fc014463173", "interface": "admin", "region_id": "prodstack6", "url": "https://radosgw-admin.ps6.canonical.com:443/swift/simplestreams/data", "region": "prodstack6"}], "id": "977dd359af1a4fcc91a9daf4dc33b0f3", "type": "product-streams", "name": "image-stream"}, {"endpoints": [{"id": "12d30eabcdec4831bd15273d55b1cbab", "interface": "internal", "region_id": "prodstack6", "url": "https://manila-internal.ps6.canonical.com:8786/v1/bd8b3df3f03d43a0a9303b7c0434fdab", "region": "prodstack6"}, {"id": "29d35b2b483346479f1ff1a13604d50e", "interface": "admin", "region_id": "prodstack6", "url": "https://manila-admin.ps6.canonical.com:8786/v1/bd8b3df3f03d43a0a9303b7c0434fdab", "region": "prodstack6"}, {"id": "4aa1422b8f5945d8aed9ba6a8d670e5c", "interface": "public", "region_id": "prodstack6", "url": "https://manila.ps6.canonical.com:8786/v1/bd8b3df3f03d43a0a9303b7c0434fdab", "region": "prodstack6"}], "id": "ac5e4f28fa794cde99f1d7ffc1b664e5", "type": "share", "name": "manila"}, {"endpoints": [{"id": "c7db93d54a684d8caeae1d9e18a59118", "interface": "admin", "region_id": "prodstack6", "url": "https://nova-admin.ps6.canonical.com:8774/v2.1", "region": "prodstack6"}, {"id": "dd7a796f401b477f9f1b5bbc05747d8d", "interface": "public", "region_id": "prodstack6", "url": "https://nova.ps6.canonical.com:8774/v2.1", "region": "prodstack6"}, {"id": "e7ecb038d830462ea67b0b463af5e013", "interface": "internal", "region_id": "prodstack6", "url": "https://nova-internal.ps6.canonical.com:8774/v2.1", "region": "prodstack6"}], "id": "b4519af08e174d4a8333a2d14ac3ba3b", "type": "compute", "name": "nova"}, {"endpoints": [{"id": "02ef5b6154934ffd97d8b5b8e4d70d2a", "interface": "internal", "region_id": "prodstack6", "url": "https://radosgw-internal.ps6.canonical.com:443/swift/v1/AUTH_bd8b3df3f03d43a0a9303b7c0434fdab", "region": "prodstack6"}, {"id": "2741abe526e94842a4fa801423ba1ef0", "interface": "public", "region_id": "prodstack6", "url": "https://radosgw.ps6.canonical.com:443/swift/v1/AUTH_bd8b3df3f03d43a0a9303b7c0434fdab", "region": "prodstack6"}, {"id": "3742f9406c604516933d6fd8c29e0880", "interface": "admin", "region_id": "prodstack6", "url": "https://radosgw-admin.ps6.canonical.com:443/swift", "region": "prodstack6"}], "id": "c7f07a7b3b3c408c96200dfd1d1a0f6f", "type": "object-store", "name": "swift"}, {"endpoints": [{"id": "06d4ed6c160a43f2b7fa7f80ad1dc709", "interface": "internal", "region_id": "prodstack6", "url": "https://designate-internal.ps6.canonical.com:9001", "region": "prodstack6"}, {"id": "1e240624a50c4ca0aaa6ef63cbc94f1b", "interface": "admin", "region_id": "prodstack6", "url": "https://designate-admin.ps6.canonical.com:9001", "region": "prodstack6"}, {"id": "f94d7d17997a43fd9c63b34c43301c6e", "interface": "public", "region_id": "prodstack6", "url": "https://designate.ps6.canonical.com:9001", "region": "prodstack6"}], "id": "cf82013d63844fedbe96bcacb6bd1fef", "type": "dns", "name": "designate"}, {"endpoints": [{"id": "4a688340be464710bfa60bf3f88f41c4", "interface": "admin", "region_id": "prodstack6", "url": "https://gnocchi-admin.ps6.canonical.com:8041", "region": "prodstack6"}, {"id": "a5a95506c96d4716adb4efc3ac9051be", "interface": "public", "region_id": "prodstack6", "url": "https://gnocchi.ps6.canonical.com:8041", "region": "prodstack6"}, {"id": "eebc17a086834f8fa8bb6b35c8061a8c", "interface": "internal", "region_id": "prodstack6", "url": "https://gnocchi-internal.ps6.canonical.com:8041", "region": "prodstack6"}], "id": "d10589e854a446a5b852593f33f170a7", "type": "metric", "name": "gnocchi"}, {"endpoints": [{"id": "08f66df28d0f47f3bec12f29e06d85ac", "interface": "admin", "region_id": "prodstack6", "url": "https://keystone-admin.ps6.canonical.com:35357/v3", "region": "prodstack6"}, {"id": "46d270b45ceb42db902f4d241afa6a70", "interface": "public", "region_id": "prodstack6", "url": "https://keystone.ps6.canonical.com:5000/v3", "region": "prodstack6"}, {"id": "a4addee11d9349cfa46ec6660dbad947", "interface": "internal", "region_id": "prodstack6", "url": "https://keystone-internal.ps6.canonical.com:5000/v3", "region": "prodstack6"}], "id": "deb38a775a9b4e87a8de9e3eed779882", "type": "identity", "name": "keystone"}, {"endpoints": [{"id": "18b4af5f40664babb94e884c6a53ccf3", "interface": "admin", "region_id": "prodstack6", "url": "https://octavia-admin.ps6.canonical.com:9876", "region": "prodstack6"}, {"id": "2b6f7ba7f9944ee1aebd6dccc5223b2d", "interface": "internal", "region_id": "prodstack6", "url": "https://octavia-internal.ps6.canonical.com:9876", "region": "prodstack6"}, {"id": "5e3012e9c79e4890be4d964b6208f5c6", "interface": "public", "region_id": "prodstack6", "url": "https://octavia.ps6.canonical.com:9876", "region": "prodstack6"}], "id": "e00337be20d54948b66a1c3109b885c6", "type": "load-balancer", "name": "octavia"}, {"endpoints": [{"id": "2d2942b35f3041389ad810f679d02f22", "interface": "public", "region_id": "prodstack6", "url": "https://placement.ps6.canonical.com:8778", "region": "prodstack6"}, {"id": "2e3beaac7ac14284b72e2592820ad725", "interface": "admin", "region_id": "prodstack6", "url": "https://placement-admin.ps6.canonical.com:8778", "region": "prodstack6"}, {"id": "91060f6df9ae444f81808adf40540d94", "interface": "internal", "region_id": "prodstack6", "url": "https://placement-internal.ps6.canonical.com:8778", "region": "prodstack6"}], "id": "edc6e37f154f4c0ab3dd4d52b82bf873", "type": "placement", "name": "placement"}]}} 384s REQ: curl -g -i -X GET https://nova.ps6.canonical.com:8774/v2.1 -H "Accept: application/json" -H "User-Agent: python-novaclient" -H "X-Auth-Token: {SHA256}b723a345ce782b99581fe710aa2d51dde1481bc3104fb8bf87996a00d0f55cb1" 384s DEBUG (session:517) REQ: curl -g -i -X GET https://nova.ps6.canonical.com:8774/v2.1 -H "Accept: application/json" -H "User-Agent: python-novaclient" -H "X-Auth-Token: {SHA256}b723a345ce782b99581fe710aa2d51dde1481bc3104fb8bf87996a00d0f55cb1" 384s DEBUG (connectionpool:962) Starting new HTTPS connection (1): nova.ps6.canonical.com:8774 384s DEBUG (connectionpool:429) https://nova.ps6.canonical.com:8774 "GET /v2.1 HTTP/1.1" 302 0 384s RESP: [302] Connection: Keep-Alive Content-Length: 0 Content-Type: text/plain; charset=utf8 Date: Fri, 19 Jul 2024 18:10:08 GMT Keep-Alive: timeout=75, max=1000 Location: https://nova.ps6.canonical.com:8774/v2.1/ Server: Apache/2.4.52 (Ubuntu) x-compute-request-id: req-29cb4441-fcf5-4fa3-81f9-4d80a1b2c49c x-openstack-request-id: req-29cb4441-fcf5-4fa3-81f9-4d80a1b2c49c 384s DEBUG (session:548) RESP: [302] Connection: Keep-Alive Content-Length: 0 Content-Type: text/plain; charset=utf8 Date: Fri, 19 Jul 2024 18:10:08 GMT Keep-Alive: timeout=75, max=1000 Location: https://nova.ps6.canonical.com:8774/v2.1/ Server: Apache/2.4.52 (Ubuntu) x-compute-request-id: req-29cb4441-fcf5-4fa3-81f9-4d80a1b2c49c x-openstack-request-id: req-29cb4441-fcf5-4fa3-81f9-4d80a1b2c49c 384s RESP BODY: Omitted, Content-Type is set to text/plain; charset=utf8. Only application/json responses have their bodies logged. 384s DEBUG (session:580) RESP BODY: Omitted, Content-Type is set to text/plain; charset=utf8. Only application/json responses have their bodies logged. 384s DEBUG (connectionpool:429) https://nova.ps6.canonical.com:8774 "GET /v2.1/ HTTP/1.1" 200 397 384s RESP: [200] Connection: Keep-Alive Content-Length: 397 Content-Type: application/json Date: Fri, 19 Jul 2024 18:10:08 GMT Keep-Alive: timeout=75, max=999 OpenStack-API-Version: compute 2.1 Server: Apache/2.4.52 (Ubuntu) Vary: OpenStack-API-Version,X-OpenStack-Nova-API-Version X-OpenStack-Nova-API-Version: 2.1 x-compute-request-id: req-c3ed4a5f-2767-4cf5-977c-14c85e5a5373 x-openstack-request-id: req-c3ed4a5f-2767-4cf5-977c-14c85e5a5373 384s DEBUG (session:548) RESP: [200] Connection: Keep-Alive Content-Length: 397 Content-Type: application/json Date: Fri, 19 Jul 2024 18:10:08 GMT Keep-Alive: timeout=75, max=999 OpenStack-API-Version: compute 2.1 Server: Apache/2.4.52 (Ubuntu) Vary: OpenStack-API-Version,X-OpenStack-Nova-API-Version X-OpenStack-Nova-API-Version: 2.1 x-compute-request-id: req-c3ed4a5f-2767-4cf5-977c-14c85e5a5373 x-openstack-request-id: req-c3ed4a5f-2767-4cf5-977c-14c85e5a5373 384s RESP BODY: {"version": {"id": "v2.1", "status": "CURRENT", "version": "2.90", "min_version": "2.1", "updated": "2013-07-23T11:33:21Z", "links": [{"rel": "self", "href": "https://nova.ps6.canonical.com:8774/v2.1/"}, {"rel": "describedby", "type": "text/html", "href": "http://docs.openstack.org/"}], "media-types": [{"base": "application/json", "type": "application/vnd.openstack.compute+json;version=2.1"}]}} 384s DEBUG (session:580) RESP BODY: {"version": {"id": "v2.1", "status": "CURRENT", "version": "2.90", "min_version": "2.1", "updated": "2013-07-23T11:33:21Z", "links": [{"rel": "self", "href": "https://nova.ps6.canonical.com:8774/v2.1/"}, {"rel": "describedby", "type": "text/html", "href": "http://docs.openstack.org/"}], "media-types": [{"base": "application/json", "type": "application/vnd.openstack.compute+json;version=2.1"}]}} 384s GET call to compute for https://nova.ps6.canonical.com:8774/v2.1/ used request id req-c3ed4a5f-2767-4cf5-977c-14c85e5a5373 384s DEBUG (session:936) GET call to compute for https://nova.ps6.canonical.com:8774/v2.1/ used request id req-c3ed4a5f-2767-4cf5-977c-14c85e5a5373 384s DEBUG (extension:189) found extension EntryPoint.parse('v1password = swiftclient.authv1:PasswordLoader') 384s DEBUG (extension:189) found extension EntryPoint.parse('noauth = cinderclient.contrib.noauth:CinderNoAuthLoader') 384s DEBUG (extension:189) found extension EntryPoint.parse('admin_token = keystoneauth1.loading._plugins.admin_token:AdminToken') 384s DEBUG (extension:189) found extension EntryPoint.parse('none = keystoneauth1.loading._plugins.noauth:NoAuth') 384s DEBUG (extension:189) found extension EntryPoint.parse('password = keystoneauth1.loading._plugins.identity.generic:Password') 384s DEBUG (extension:189) found extension EntryPoint.parse('token = keystoneauth1.loading._plugins.identity.generic:Token') 384s DEBUG (extension:189) found extension EntryPoint.parse('v2password = keystoneauth1.loading._plugins.identity.v2:Password') 384s DEBUG (extension:189) found extension EntryPoint.parse('v2token = keystoneauth1.loading._plugins.identity.v2:Token') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3adfspassword = keystoneauth1.extras._saml2._loading:ADFSPassword') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3applicationcredential = keystoneauth1.loading._plugins.identity.v3:ApplicationCredential') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3fedkerb = keystoneauth1.extras.kerberos._loading:MappedKerberos') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3kerberos = keystoneauth1.extras.kerberos._loading:Kerberos') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3multifactor = keystoneauth1.loading._plugins.identity.v3:MultiFactor') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3oauth1 = keystoneauth1.extras.oauth1._loading:V3OAuth1') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcaccesstoken = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAccessToken') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcauthcode = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAuthorizationCode') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcclientcredentials = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectClientCredentials') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3oidcpassword = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectPassword') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3password = keystoneauth1.loading._plugins.identity.v3:Password') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3samlpassword = keystoneauth1.extras._saml2._loading:Saml2Password') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3token = keystoneauth1.loading._plugins.identity.v3:Token') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3tokenlessauth = keystoneauth1.loading._plugins.identity.v3:TokenlessAuth') 384s DEBUG (extension:189) found extension EntryPoint.parse('v3totp = keystoneauth1.loading._plugins.identity.v3:TOTP') 384s DEBUG (session:517) REQ: curl -g -i -X GET https://glance.ps6.canonical.com:9292/v2/images/a9c28202-db65-432a-996d-c43c7d6f5c5e -H "Accept: application/json" -H "OpenStack-API-Version: compute 2.87" -H "User-Agent: python-novaclient" -H "X-Auth-Token: {SHA256}b723a345ce782b99581fe710aa2d51dde1481bc3104fb8bf87996a00d0f55cb1" -H "X-OpenStack-Nova-API-Version: 2.87" 384s DEBUG (connectionpool:962) Starting new HTTPS connection (1): glance.ps6.canonical.com:9292 384s DEBUG (connectionpool:429) https://glance.ps6.canonical.com:9292 "GET /v2/images/a9c28202-db65-432a-996d-c43c7d6f5c5e HTTP/1.1" 200 1938 384s DEBUG (session:548) RESP: [200] Connection: Keep-Alive Content-Length: 1938 Content-Type: application/json Date: Fri, 19 Jul 2024 18:10:09 GMT Keep-Alive: timeout=75, max=1000 Server: Apache/2.4.52 (Ubuntu) X-Openstack-Request-Id: req-ba6fee87-974d-4c20-93b1-05f58de7179d 384s DEBUG (session:580) RESP BODY: {"base_image_ref": "09c3944a-cd0d-425d-b22f-cde7ec51d155", "boot_roles": "reader,member", "hw_cdrom_bus": "scsi", "hw_disk_bus": "virtio", "hw_machine_type": "virt", "hw_video_model": "virtio", "hw_vif_model": "virtio", "image_location": "snapshot", "image_state": "available", "image_type": "snapshot", "instance_uuid": "dfd98cf6-ea10-4180-95b6-b9ec46eb8782", "owner_id": "bd8b3df3f03d43a0a9303b7c0434fdab", "owner_project_name": "prod-proposed-migration-arm64_project", "owner_specified.openstack.md5": "087a26f2222dab8516c553374a9d1b4d", "owner_specified.openstack.object": "images/adt/ubuntu-noble-arm64-server-20240201.img", "owner_specified.openstack.sha256": "095b278df09de76f01843de514daf3f8eb0a0cc67fee4b3491161913153619db", "owner_user_name": "prod-proposed-migration-arm64", "user_id": "369f50a481564a2c9433776a4ebd224d", "name": "adt/ubuntu-oracular-arm64-server-20240718.img", "disk_format": "qcow2", "container_format": "bare", "visibility": "private", "size": 2708471808, "virtual_size": 21474836480, "status": "active", "checksum": "05453c460531d2bc431706e606a36633", "protected": false, "min_ram": 0, "min_disk": 20, "owner": "bd8b3df3f03d43a0a9303b7c0434fdab", "os_hidden": false, "os_hash_algo": "sha512", "os_hash_value": "4098689623ab9a64f5bc842d27bbf64b0ec4fdd911203de7a719dff91d9d9276f2fa4c7893f7dd12747299ad9ffbab1f2ff3022f47330682e1a5fd91527b0541", "id": "a9c28202-db65-432a-996d-c43c7d6f5c5e", "created_at": "2024-07-18T18:16:18Z", "updated_at": "2024-07-18T18:16:46Z", "locations": [{"url": "rbd://eea9d068-c18c-11ed-8dc0-013aacb71b80/glance/a9c28202-db65-432a-996d-c43c7d6f5c5e/snap", "metadata": {"store": "ceph"}}], "direct_url": "rbd://eea9d068-c18c-11ed-8dc0-013aacb71b80/glance/a9c28202-db65-432a-996d-c43c7d6f5c5e/snap", "tags": [], "self": "/v2/images/a9c28202-db65-432a-996d-c43c7d6f5c5e", "file": "/v2/images/a9c28202-db65-432a-996d-c43c7d6f5c5e/file", "schema": "/v2/schemas/image", "stores": "ceph"} 384s DEBUG (session:936) GET call to image for https://glance.ps6.canonical.com:9292/v2/images/a9c28202-db65-432a-996d-c43c7d6f5c5e used request id req-ba6fee87-974d-4c20-93b1-05f58de7179d 384s DEBUG (session:517) REQ: curl -g -i -X GET https://nova.ps6.canonical.com:8774/v2.1/flavors/autopkgtest-big -H "Accept: application/json" -H "OpenStack-API-Version: compute 2.87" -H "User-Agent: python-novaclient" -H "X-Auth-Token: {SHA256}b723a345ce782b99581fe710aa2d51dde1481bc3104fb8bf87996a00d0f55cb1" -H "X-OpenStack-Nova-API-Version: 2.87" 384s DEBUG (connectionpool:429) https://nova.ps6.canonical.com:8774 "GET /v2.1/flavors/autopkgtest-big HTTP/1.1" 404 88 384s DEBUG (session:548) RESP: [404] Connection: Keep-Alive Content-Length: 88 Content-Type: application/json; charset=UTF-8 Date: Fri, 19 Jul 2024 18:10:09 GMT Keep-Alive: timeout=75, max=998 OpenStack-API-Version: compute 2.87 Server: Apache/2.4.52 (Ubuntu) Vary: OpenStack-API-Version,X-OpenStack-Nova-API-Version X-OpenStack-Nova-API-Version: 2.87 x-compute-request-id: req-03cd513a-4cab-4178-8e81-8609dd91a261 x-openstack-request-id: req-03cd513a-4cab-4178-8e81-8609dd91a261 384s DEBUG (session:580) RESP BODY: {"itemNotFound": {"code": 404, "message": "Flavor autopkgtest-big could not be found."}} 384s DEBUG (session:936) GET call to compute for https://nova.ps6.canonical.com:8774/v2.1/flavors/autopkgtest-big used request id req-03cd513a-4cab-4178-8e81-8609dd91a261 384s DEBUG (session:517) REQ: curl -g -i -X GET https://nova.ps6.canonical.com:8774/v2.1/flavors?is_public=None -H "Accept: application/json" -H "OpenStack-API-Version: compute 2.87" -H "User-Agent: python-novaclient" -H "X-Auth-Token: {SHA256}b723a345ce782b99581fe710aa2d51dde1481bc3104fb8bf87996a00d0f55cb1" -H "X-OpenStack-Nova-API-Version: 2.87" 384s DEBUG (connectionpool:429) https://nova.ps6.canonical.com:8774 "GET /v2.1/flavors?is_public=None HTTP/1.1" 200 1739 384s DEBUG (session:548) RESP: [200] Connection: Keep-Alive Content-Length: 1739 Content-Type: application/json Date: Fri, 19 Jul 2024 18:10:09 GMT Keep-Alive: timeout=75, max=997 OpenStack-API-Version: compute 2.87 Server: Apache/2.4.52 (Ubuntu) Vary: OpenStack-API-Version,X-OpenStack-Nova-API-Version X-OpenStack-Nova-API-Version: 2.87 x-compute-request-id: req-7e1ba747-dc98-470f-a957-d0535c6b33e8 x-openstack-request-id: req-7e1ba747-dc98-470f-a957-d0535c6b33e8 384s DEBUG (session:580) RESP BODY: {"flavors": [{"id": "062428d9-35a1-461f-a33a-38436ed516b4", "name": "autopkgtest-cpu8-ram16-disk160-arm64", "links": [{"rel": "self", "href": "https://nova.ps6.canonical.com:8774/v2.1/flavors/062428d9-35a1-461f-a33a-38436ed516b4"}, {"rel": "bookmark", "href": "https://nova.ps6.canonical.com:8774/flavors/062428d9-35a1-461f-a33a-38436ed516b4"}], "description": null}, {"id": "8d27c5f0-65c7-4018-b3f7-50463875ab09", "name": "autopkgtest", "links": [{"rel": "self", "href": "https://nova.ps6.canonical.com:8774/v2.1/flavors/8d27c5f0-65c7-4018-b3f7-50463875ab09"}, {"rel": "bookmark", "href": "https://nova.ps6.canonical.com:8774/flavors/8d27c5f0-65c7-4018-b3f7-50463875ab09"}], "description": null}, {"id": "8ebe34fb-1390-4cc7-bbe5-0d38c80f2fb4", "name": "autopkgtest-cpu2-ram4-disk20-arm64", "links": [{"rel": "self", "href": "https://nova.ps6.canonical.com:8774/v2.1/flavors/8ebe34fb-1390-4cc7-bbe5-0d38c80f2fb4"}, {"rel": "bookmark", "href": "https://nova.ps6.canonical.com:8774/flavors/8ebe34fb-1390-4cc7-bbe5-0d38c80f2fb4"}], "description": null}, {"id": "a8256f9e-53ee-4584-ad7f-60e088825b83", "name": "autopkgtest-big", "links": [{"rel": "self", "href": "https://nova.ps6.canonical.com:8774/v2.1/flavors/a8256f9e-53ee-4584-ad7f-60e088825b83"}, {"rel": "bookmark", "href": "https://nova.ps6.canonical.com:8774/flavors/a8256f9e-53ee-4584-ad7f-60e088825b83"}], "description": null}, {"id": "cfc564ac-9f6e-4477-91c4-a89ccb4b744e", "name": "autopkgtest-cpu4-ram8-disk100-arm64", "links": [{"rel": "self", "href": "https://nova.ps6.canonical.com:8774/v2.1/flavors/cfc564ac-9f6e-4477-91c4-a89ccb4b744e"}, {"rel": "bookmark", "href": "https://nova.ps6.canonical.com:8774/flavors/cfc564ac-9f6e-4477-91c4-a89ccb4b744e"}], "description": null}]} 384s DEBUG (session:936) GET call to compute for https://nova.ps6.canonical.com:8774/v2.1/flavors?is_public=None used request id req-7e1ba747-dc98-470f-a957-d0535c6b33e8 384s DEBUG (session:517) REQ: curl -g -i -X GET https://nova.ps6.canonical.com:8774/v2.1/flavors/a8256f9e-53ee-4584-ad7f-60e088825b83 -H "Accept: application/json" -H "OpenStack-API-Version: compute 2.87" -H "User-Agent: python-novaclient" -H "X-Auth-Token: {SHA256}b723a345ce782b99581fe710aa2d51dde1481bc3104fb8bf87996a00d0f55cb1" -H "X-OpenStack-Nova-API-Version: 2.87" 384s DEBUG (connectionpool:429) https://nova.ps6.canonical.com:8774 "GET /v2.1/flavors/a8256f9e-53ee-4584-ad7f-60e088825b83 HTTP/1.1" 200 618 384s DEBUG (session:548) RESP: [200] Connection: Keep-Alive Content-Length: 618 Content-Type: application/json Date: Fri, 19 Jul 2024 18:10:09 GMT Keep-Alive: timeout=75, max=996 OpenStack-API-Version: compute 2.87 Server: Apache/2.4.52 (Ubuntu) Vary: OpenStack-API-Version,X-OpenStack-Nova-API-Version X-OpenStack-Nova-API-Version: 2.87 x-compute-request-id: req-8d472405-dccb-4772-85fe-b2dd5ec3250c x-openstack-request-id: req-8d472405-dccb-4772-85fe-b2dd5ec3250c 384s DEBUG (session:580) RESP BODY: {"flavor": {"id": "a8256f9e-53ee-4584-ad7f-60e088825b83", "name": "autopkgtest-big", "ram": 8192, "disk": 100, "swap": 0, "OS-FLV-EXT-DATA:ephemeral": 0, "OS-FLV-DISABLED:disabled": false, "vcpus": 4, "os-flavor-access:is_public": false, "rxtx_factor": 1.0, "links": [{"rel": "self", "href": "https://nova.ps6.canonical.com:8774/v2.1/flavors/a8256f9e-53ee-4584-ad7f-60e088825b83"}, {"rel": "bookmark", "href": "https://nova.ps6.canonical.com:8774/flavors/a8256f9e-53ee-4584-ad7f-60e088825b83"}], "description": null, "extra_specs": {"aggregate_instance_extra_specs:commit": "builder-arm64", "hw_rng:allowed": "True"}}} 384s DEBUG (session:936) GET call to compute for https://nova.ps6.canonical.com:8774/v2.1/flavors/a8256f9e-53ee-4584-ad7f-60e088825b83 used request id req-8d472405-dccb-4772-85fe-b2dd5ec3250c 384s DEBUG (session:517) REQ: curl -g -i -X POST https://nova.ps6.canonical.com:8774/v2.1/servers -H "Accept: application/json" -H "Content-Type: application/json" -H "OpenStack-API-Version: compute 2.87" -H "User-Agent: python-novaclient" -H "X-Auth-Token: {SHA256}b723a345ce782b99581fe710aa2d51dde1481bc3104fb8bf87996a00d0f55cb1" -H "X-OpenStack-Nova-API-Version: 2.87" -d '{"server": {"name": "adt-oracular-arm64-multipath-tools-20240719-181001-juju-7f2275-prod-proposed-migration-environment-2-6816d8f0-d73c-42ef-ab54-0fc2d822d9cb", "imageRef": "a9c28202-db65-432a-996d-c43c7d6f5c5e", "flavorRef": "a8256f9e-53ee-4584-ad7f-60e088825b83", "user_data": "I2Nsb3VkLWNvbmZpZwpob3N0bmFtZTogYXV0b3BrZ3Rlc3QKZnFkbjogYXV0b3BrZ3Rlc3QubG9jYWwKbWFuYWdlX2V0Y19ob3N0czogdHJ1ZQphcHRfdXBkYXRlOiB0cnVlCmFwdF91cGdyYWRlOiBmYWxzZQphcHRfbWlycm9yOiBodHRwOi8vZnRwbWFzdGVyLmludGVybmFsL3VidW50dS8KCnJ1bmNtZDoKIC0gZWNobyAnQWNxdWlyZTo6TGFuZ3VhZ2VzICJub25lIjsnID4gL2V0Yy9hcHQvYXB0LmNvbmYuZC85MG5vbGFuZ3VhZ2VzCiAtIGVjaG8gJ2ZvcmNlLXVuc2FmZS1pbycgPiAvZXRjL2Rwa2cvZHBrZy5jZmcuZC9hdXRvcGtndGVzdAogLSBwcmludGYgJ1xuVEVSTT1saW51eFxuJ2h0dHBfcHJveHk9aHR0cDovL3NxdWlkLmludGVybmFsOjMxMjgnXG4naHR0cHNfcHJveHk9aHR0cDovL3NxdWlkLmludGVybmFsOjMxMjgnXG4nbm9fcHJveHk9MTI3LjAuMC4xLDEyNy4wLjEuMSxsb2dpbi51YnVudHUuY29tLGxvY2FsaG9zdCxsb2NhbGRvbWFpbixub3ZhbG9jYWwsaW50ZXJuYWwsYXJjaGl2ZS51YnVudHUuY29tLHBvcnRzLnVidW50dS5jb20sc2VjdXJpdHkudWJ1bnR1LmNvbSxkZGVicy51YnVudHUuY29tLGNoYW5nZWxvZ3MudWJ1bnR1LmNvbSxrZXlzZXJ2ZXIudWJ1bnR1LmNvbSxsYXVuY2hwYWRsaWJyYXJpYW4ubmV0LGxhdW5jaHBhZGNvbnRlbnQubmV0LGxhdW5jaHBhZC5uZXQsMTAuMjQuMC4wLzI0LGtleXN0b25lLnBzNS5jYW5vbmljYWwuY29tLG9iamVjdHN0b3JhZ2UucHJvZHN0YWNrNS5jYW5vbmljYWwuY29tJ1xuJyA+PiAvZXRjL2Vudmlyb25tZW50CiAtIHNlZCAtaSAtciAnL14xMjcuMC4xLjEvIHMvYXV0b3BrZ3Rlc3QtW14gXStcLi9hdXRvcGtndGVzdFwuLycgL2V0Yy9ob3N0cwo=", "key_name": "testbed-juju-7f2275-prod-proposed-migration-environment-2", "min_count": 1, "max_count": 1, "security_groups": [{"name": "autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@bos03-arm64-19.secgroup"}], "networks": [{"uuid": "6ea4839c-9760-4b54-ab7d-70a6312667d1"}]}}' 384s DEBUG (connectionpool:429) https://nova.ps6.canonical.com:8774 "POST /v2.1/servers HTTP/1.1" 202 476 384s DEBUG (session:548) RESP: [202] Connection: Keep-Alive Content-Length: 476 Content-Type: application/json Date: Fri, 19 Jul 2024 18:10:09 GMT Keep-Alive: timeout=75, max=995 OpenStack-API-Version: compute 2.87 Server: Apache/2.4.52 (Ubuntu) Vary: OpenStack-API-Version,X-OpenStack-Nova-API-Version X-OpenStack-Nova-API-Version: 2.87 location: https://nova.ps6.canonical.com:8774/v2.1/servers/f9c12418-184c-4734-9a5d-e6c92a3c23eb x-compute-request-id: req-581e0e14-12c6-40a7-bfc6-9992adeea8fb x-openstack-request-id: req-581e0e14-12c6-40a7-bfc6-9992adeea8fb 384s DEBUG (session:580) RESP BODY: {"server": {"id": "f9c12418-184c-4734-9a5d-e6c92a3c23eb", "links": [{"rel": "self", "href": "https://nova.ps6.canonical.com:8774/v2.1/servers/f9c12418-184c-4734-9a5d-e6c92a3c23eb"}, {"rel": "bookmark", "href": "https://nova.ps6.canonical.com:8774/servers/f9c12418-184c-4734-9a5d-e6c92a3c23eb"}], "OS-DCF:diskConfig": "MANUAL", "security_groups": [{"name": "autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@bos03-arm64-19.secgroup"}], "adminPass": "54SMdfLiDN83"}} 384s DEBUG (session:936) POST call to compute for https://nova.ps6.canonical.com:8774/v2.1/servers used request id req-581e0e14-12c6-40a7-bfc6-9992adeea8fb 384s DEBUG (session:517) REQ: curl -g -i -X GET https://nova.ps6.canonical.com:8774/v2.1/servers/f9c12418-184c-4734-9a5d-e6c92a3c23eb -H "Accept: application/json" -H "OpenStack-API-Version: compute 2.87" -H "User-Agent: python-novaclient" -H "X-Auth-Token: {SHA256}b723a345ce782b99581fe710aa2d51dde1481bc3104fb8bf87996a00d0f55cb1" -H "X-OpenStack-Nova-API-Version: 2.87" 384s DEBUG (connectionpool:429) https://nova.ps6.canonical.com:8774 "GET /v2.1/servers/f9c12418-184c-4734-9a5d-e6c92a3c23eb HTTP/1.1" 200 3199 384s DEBUG (session:548) RESP: [200] Connection: Keep-Alive Content-Length: 3199 Content-Type: application/json Date: Fri, 19 Jul 2024 18:10:10 GMT Keep-Alive: timeout=75, max=994 OpenStack-API-Version: compute 2.87 Server: Apache/2.4.52 (Ubuntu) Vary: OpenStack-API-Version,X-OpenStack-Nova-API-Version X-OpenStack-Nova-API-Version: 2.87 x-compute-request-id: req-4e28bbbe-5e3f-413a-9069-e9226e838386 x-openstack-request-id: req-4e28bbbe-5e3f-413a-9069-e9226e838386 384s DEBUG (session:580) RESP BODY: {"server": {"id": "f9c12418-184c-4734-9a5d-e6c92a3c23eb", "name": "adt-oracular-arm64-multipath-tools-20240719-181001-juju-7f2275-prod-proposed-migration-environment-2-6816d8f0-d73c-42ef-ab54-0fc2d822d9cb", "status": "BUILD", "tenant_id": "bd8b3df3f03d43a0a9303b7c0434fdab", "user_id": "369f50a481564a2c9433776a4ebd224d", "metadata": {}, "hostId": "", "image": {"id": "a9c28202-db65-432a-996d-c43c7d6f5c5e", "links": [{"rel": "bookmark", "href": "https://nova.ps6.canonical.com:8774/images/a9c28202-db65-432a-996d-c43c7d6f5c5e"}]}, "flavor": {"vcpus": 4, "ram": 8192, "disk": 100, "ephemeral": 0, "swap": 0, "original_name": "autopkgtest-big", "extra_specs": {"aggregate_instance_extra_specs:commit": "builder-arm64", "hw_rng:allowed": "True"}}, "created": "2024-07-19T18:10:10Z", "updated": "2024-07-19T18:10:10Z", "addresses": {}, "accessIPv4": "", "accessIPv6": "", "links": [{"rel": "self", "href": "https://nova.ps6.canonical.com:8774/v2.1/servers/f9c12418-184c-4734-9a5d-e6c92a3c23eb"}, {"rel": "bookmark", "href": "https://nova.ps6.canonical.com:8774/servers/f9c12418-184c-4734-9a5d-e6c92a3c23eb"}], "OS-DCF:diskConfig": "MANUAL", "progress": 0, "OS-EXT-AZ:availability_zone": "", "config_drive": "", "key_name": "testbed-juju-7f2275-prod-proposed-migration-environment-2", "OS-SRV-USG:launched_at": null, "OS-SRV-USG:terminated_at": null, "OS-EXT-SRV-ATTR:host": null, "OS-EXT-SRV-ATTR:instance_name": "", "OS-EXT-SRV-ATTR:hypervisor_hostname": null, "OS-EXT-SRV-ATTR:reservation_id": "r-gsts4fqe", "OS-EXT-SRV-ATTR:launch_index": 0, "OS-EXT-SRV-ATTR:hostname": "adt-oracular-arm64-multipath-tools-20240719-181001-juju-7f2275", "OS-EXT-SRV-ATTR:kernel_id": "", "OS-EXT-SRV-ATTR:ramdisk_id": "", "OS-EXT-SRV-ATTR:root_device_name": null, "OS-EXT-SRV-ATTR:user_data": "I2Nsb3VkLWNvbmZpZwpob3N0bmFtZTogYXV0b3BrZ3Rlc3QKZnFkbjogYXV0b3BrZ3Rlc3QubG9jYWwKbWFuYWdlX2V0Y19ob3N0czogdHJ1ZQphcHRfdXBkYXRlOiB0cnVlCmFwdF91cGdyYWRlOiBmYWxzZQphcHRfbWlycm9yOiBodHRwOi8vZnRwbWFzdGVyLmludGVybmFsL3VidW50dS8KCnJ1bmNtZDoKIC0gZWNobyAnQWNxdWlyZTo6TGFuZ3VhZ2VzICJub25lIjsnID4gL2V0Yy9hcHQvYXB0LmNvbmYuZC85MG5vbGFuZ3VhZ2VzCiAtIGVjaG8gJ2ZvcmNlLXVuc2FmZS1pbycgPiAvZXRjL2Rwa2cvZHBrZy5jZmcuZC9hdXRvcGtndGVzdAogLSBwcmludGYgJ1xuVEVSTT1saW51eFxuJ2h0dHBfcHJveHk9aHR0cDovL3NxdWlkLmludGVybmFsOjMxMjgnXG4naHR0cHNfcHJveHk9aHR0cDovL3NxdWlkLmludGVybmFsOjMxMjgnXG4nbm9fcHJveHk9MTI3LjAuMC4xLDEyNy4wLjEuMSxsb2dpbi51YnVudHUuY29tLGxvY2FsaG9zdCxsb2NhbGRvbWFpbixub3ZhbG9jYWwsaW50ZXJuYWwsYXJjaGl2ZS51YnVudHUuY29tLHBvcnRzLnVidW50dS5jb20sc2VjdXJpdHkudWJ1bnR1LmNvbSxkZGVicy51YnVudHUuY29tLGNoYW5nZWxvZ3MudWJ1bnR1LmNvbSxrZXlzZXJ2ZXIudWJ1bnR1LmNvbSxsYXVuY2hwYWRsaWJyYXJpYW4ubmV0LGxhdW5jaHBhZGNvbnRlbnQubmV0LGxhdW5jaHBhZC5uZXQsMTAuMjQuMC4wLzI0LGtleXN0b25lLnBzNS5jYW5vbmljYWwuY29tLG9iamVjdHN0b3JhZ2UucHJvZHN0YWNrNS5jYW5vbmljYWwuY29tJ1xuJyA+PiAvZXRjL2Vudmlyb25tZW50CiAtIHNlZCAtaSAtciAnL14xMjcuMC4xLjEvIHMvYXV0b3BrZ3Rlc3QtW14gXStcLi9hdXRvcGtndGVzdFwuLycgL2V0Yy9ob3N0cwo=", "OS-EXT-STS:task_state": "scheduling", "OS-EXT-STS:vm_state": "building", "OS-EXT-STS:power_state": 0, "os-extended-volumes:volumes_attached": [], "locked": false, "locked_reason": null, "description": null, "tags": [], "trusted_image_certificates": null, "server_groups": []}} 384s DEBUG (session:936) GET call to compute for https://nova.ps6.canonical.com:8774/v2.1/servers/f9c12418-184c-4734-9a5d-e6c92a3c23eb used request id req-4e28bbbe-5e3f-413a-9069-e9226e838386 384s DEBUG (session:517) REQ: curl -g -i -X GET https://glance.ps6.canonical.com:9292/v2/images/a9c28202-db65-432a-996d-c43c7d6f5c5e -H "Accept: application/json" -H "OpenStack-API-Version: compute 2.87" -H "User-Agent: python-novaclient" -H "X-Auth-Token: {SHA256}b723a345ce782b99581fe710aa2d51dde1481bc3104fb8bf87996a00d0f55cb1" -H "X-OpenStack-Nova-API-Version: 2.87" 384s DEBUG (connectionpool:429) https://glance.ps6.canonical.com:9292 "GET /v2/images/a9c28202-db65-432a-996d-c43c7d6f5c5e HTTP/1.1" 200 1938 384s DEBUG (session:548) RESP: [200] Connection: Keep-Alive Content-Length: 1938 Content-Type: application/json Date: Fri, 19 Jul 2024 18:10:10 GMT Keep-Alive: timeout=75, max=999 Server: Apache/2.4.52 (Ubuntu) X-Openstack-Request-Id: req-6ebdd1e0-705e-442a-940f-f638aacc59a7 384s DEBUG (session:580) RESP BODY: {"base_image_ref": "09c3944a-cd0d-425d-b22f-cde7ec51d155", "boot_roles": "reader,member", "hw_cdrom_bus": "scsi", "hw_disk_bus": "virtio", "hw_machine_type": "virt", "hw_video_model": "virtio", "hw_vif_model": "virtio", "image_location": "snapshot", "image_state": "available", "image_type": "snapshot", "instance_uuid": "dfd98cf6-ea10-4180-95b6-b9ec46eb8782", "owner_id": "bd8b3df3f03d43a0a9303b7c0434fdab", "owner_project_name": "prod-proposed-migration-arm64_project", "owner_specified.openstack.md5": "087a26f2222dab8516c553374a9d1b4d", "owner_specified.openstack.object": "images/adt/ubuntu-noble-arm64-server-20240201.img", "owner_specified.openstack.sha256": "095b278df09de76f01843de514daf3f8eb0a0cc67fee4b3491161913153619db", "owner_user_name": "prod-proposed-migration-arm64", "user_id": "369f50a481564a2c9433776a4ebd224d", "name": "adt/ubuntu-oracular-arm64-server-20240718.img", "disk_format": "qcow2", "container_format": "bare", "visibility": "private", "size": 2708471808, "virtual_size": 21474836480, "status": "active", "checksum": "05453c460531d2bc431706e606a36633", "protected": false, "min_ram": 0, "min_disk": 20, "owner": "bd8b3df3f03d43a0a9303b7c0434fdab", "os_hidden": false, "os_hash_algo": "sha512", "os_hash_value": "4098689623ab9a64f5bc842d27bbf64b0ec4fdd911203de7a719dff91d9d9276f2fa4c7893f7dd12747299ad9ffbab1f2ff3022f47330682e1a5fd91527b0541", "id": "a9c28202-db65-432a-996d-c43c7d6f5c5e", "created_at": "2024-07-18T18:16:18Z", "updated_at": "2024-07-18T18:16:46Z", "locations": [{"url": "rbd://eea9d068-c18c-11ed-8dc0-013aacb71b80/glance/a9c28202-db65-432a-996d-c43c7d6f5c5e/snap", "metadata": {"store": "ceph"}}], "direct_url": "rbd://eea9d068-c18c-11ed-8dc0-013aacb71b80/glance/a9c28202-db65-432a-996d-c43c7d6f5c5e/snap", "tags": [], "self": "/v2/images/a9c28202-db65-432a-996d-c43c7d6f5c5e", "file": "/v2/images/a9c28202-db65-432a-996d-c43c7d6f5c5e/file", "schema": "/v2/schemas/image", "stores": "ceph"} 384s DEBUG (session:936) GET call to image for https://glance.ps6.canonical.com:9292/v2/images/a9c28202-db65-432a-996d-c43c7d6f5c5e used request id req-6ebdd1e0-705e-442a-940f-f638aacc59a7 384s +--------------------------------------+-------------------------------------------------------------------------------------------------------------------------------------------+ 384s | Property | Value | 384s +--------------------------------------+-------------------------------------------------------------------------------------------------------------------------------------------+ 384s | OS-DCF:diskConfig | MANUAL | 384s | OS-EXT-AZ:availability_zone | | 384s | OS-EXT-SRV-ATTR:host | - | 384s | OS-EXT-SRV-ATTR:hostname | adt-oracular-arm64-multipath-tools-20240719-181001-juju-7f2275 | 384s | OS-EXT-SRV-ATTR:hypervisor_hostname | - | 384s | OS-EXT-SRV-ATTR:instance_name | | 384s | OS-EXT-SRV-ATTR:kernel_id | | 384s | OS-EXT-SRV-ATTR:launch_index | 0 | 384s | OS-EXT-SRV-ATTR:ramdisk_id | | 384s | OS-EXT-SRV-ATTR:reservation_id | r-gsts4fqe | 384s | OS-EXT-SRV-ATTR:root_device_name | - | 384s | OS-EXT-STS:power_state | 0 | 384s | OS-EXT-STS:task_state | scheduling | 384s | OS-EXT-STS:vm_state | building | 384s | OS-SRV-USG:launched_at | - | 384s | OS-SRV-USG:terminated_at | - | 384s | accessIPv4 | | 384s | accessIPv6 | | 384s | adminPass | 54SMdfLiDN83 | 384s | config_drive | | 384s | created | 2024-07-19T18:10:10Z | 384s | description | - | 384s | flavor:disk | 100 | 384s | flavor:ephemeral | 0 | 384s | flavor:extra_specs | {"aggregate_instance_extra_specs:commit": "builder-arm64", "hw_rng:allowed": "True"} | 384s | flavor:original_name | autopkgtest-big | 384s | flavor:ram | 8192 | 384s | flavor:swap | 0 | 384s | flavor:vcpus | 4 | 384s | hostId | | 384s | id | f9c12418-184c-4734-9a5d-e6c92a3c23eb | 384s | image | adt/ubuntu-oracular-arm64-server-20240718.img (a9c28202-db65-432a-996d-c43c7d6f5c5e) | 384s | key_name | testbed-juju-7f2275-prod-proposed-migration-environment-2 | 384s | locked | False | 384s | locked_reason | - | 384s | metadata | {} | 384s | name | adt-oracular-arm64-multipath-tools-20240719-181001-juju-7f2275-prod-proposed-migration-environment-2-6816d8f0-d73c-42ef-ab54-0fc2d822d9cb | 384s | os-extended-volumes:volumes_attached | [] | 384s | progress | 0 | 384s | security_groups | autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@bos03-arm64-19.secgroup | 384s | server_groups | [] | 384s | status | BUILD | 384s | tags | [] | 384s | tenant_id | bd8b3df3f03d43a0a9303b7c0434fdab | 384s | trusted_image_certificates | - | 384s | updated | 2024-07-19T18:10:10Z | 384s | user_id | 369f50a481564a2c9433776a4ebd224d | 384s +--------------------------------------+-------------------------------------------------------------------------------------------------------------------------------------------+DEBUG (session:517) REQ: curl -g -i -X GET https://nova.ps6.canonical.com:8774/v2.1/servers/f9c12418-184c-4734-9a5d-e6c92a3c23eb -H "Accept: application/json" -H "OpenStack-API-Version: compute 2.87" -H "User-Agent: python-novaclient" -H "X-Auth-Token: {SHA256}b723a345ce782b99581fe710aa2d51dde1481bc3104fb8bf87996a00d0f55cb1" -H "X-OpenStack-Nova-API-Version: 2.87" 384s DEBUG (connectionpool:429) https://nova.ps6.canonical.com:8774 "GET /v2.1/servers/f9c12418-184c-4734-9a5d-e6c92a3c23eb HTTP/1.1" 200 3326 384s DEBUG (session:548) RESP: [200] Connection: Keep-Alive Content-Length: 3326 Content-Type: application/json Date: Fri, 19 Jul 2024 18:10:10 GMT Keep-Alive: timeout=75, max=993 OpenStack-API-Version: compute 2.87 Server: Apache/2.4.52 (Ubuntu) Vary: OpenStack-API-Version,X-OpenStack-Nova-API-Version X-OpenStack-Nova-API-Version: 2.87 x-compute-request-id: req-15bdf839-071e-4f4c-81a5-07f758df454d x-openstack-request-id: req-15bdf839-071e-4f4c-81a5-07f758df454d 384s DEBUG (session:580) RESP BODY: {"server": {"id": "f9c12418-184c-4734-9a5d-e6c92a3c23eb", "name": "adt-oracular-arm64-multipath-tools-20240719-181001-juju-7f2275-prod-proposed-migration-environment-2-6816d8f0-d73c-42ef-ab54-0fc2d822d9cb", "status": "ERROR", "tenant_id": "bd8b3df3f03d43a0a9303b7c0434fdab", "user_id": "369f50a481564a2c9433776a4ebd224d", "metadata": {}, "hostId": "", "image": {"id": "a9c28202-db65-432a-996d-c43c7d6f5c5e", "links": [{"rel": "bookmark", "href": "https://nova.ps6.canonical.com:8774/images/a9c28202-db65-432a-996d-c43c7d6f5c5e"}]}, "flavor": {"vcpus": 4, "ram": 8192, "disk": 100, "ephemeral": 0, "swap": 0, "original_name": "autopkgtest-big", "extra_specs": {"aggregate_instance_extra_specs:commit": "builder-arm64", "hw_rng:allowed": "True"}}, "created": "2024-07-19T18:10:10Z", "updated": "2024-07-19T18:10:10Z", "addresses": {}, "accessIPv4": "", "accessIPv6": "", "links": [{"rel": "self", "href": "https://nova.ps6.canonical.com:8774/v2.1/servers/f9c12418-184c-4734-9a5d-e6c92a3c23eb"}, {"rel": "bookmark", "href": "https://nova.ps6.canonical.com:8774/servers/f9c12418-184c-4734-9a5d-e6c92a3c23eb"}], "OS-DCF:diskConfig": "MANUAL", "fault": {"code": 500, "created": "2024-07-19T18:10:10Z", "message": "No valid host was found. There are not enough hosts available."}, "OS-EXT-AZ:availability_zone": "", "config_drive": "", "key_name": "testbed-juju-7f2275-prod-proposed-migration-environment-2", "OS-SRV-USG:launched_at": null, "OS-SRV-USG:terminated_at": null, "OS-EXT-SRV-ATTR:host": null, "OS-EXT-SRV-ATTR:instance_name": "instance-00035d79", "OS-EXT-SRV-ATTR:hypervisor_hostname": null, "OS-EXT-SRV-ATTR:reservation_id": "r-gsts4fqe", "OS-EXT-SRV-ATTR:launch_index": 0, "OS-EXT-SRV-ATTR:hostname": "adt-oracular-arm64-multipath-tools-20240719-181001-juju-7f2275", "OS-EXT-SRV-ATTR:kernel_id": "", "OS-EXT-SRV-ATTR:ramdisk_id": "", "OS-EXT-SRV-ATTR:root_device_name": null, "OS-EXT-SRV-ATTR:user_data": "I2Nsb3VkLWNvbmZpZwpob3N0bmFtZTogYXV0b3BrZ3Rlc3QKZnFkbjogYXV0b3BrZ3Rlc3QubG9jYWwKbWFuYWdlX2V0Y19ob3N0czogdHJ1ZQphcHRfdXBkYXRlOiB0cnVlCmFwdF91cGdyYWRlOiBmYWxzZQphcHRfbWlycm9yOiBodHRwOi8vZnRwbWFzdGVyLmludGVybmFsL3VidW50dS8KCnJ1bmNtZDoKIC0gZWNobyAnQWNxdWlyZTo6TGFuZ3VhZ2VzICJub25lIjsnID4gL2V0Yy9hcHQvYXB0LmNvbmYuZC85MG5vbGFuZ3VhZ2VzCiAtIGVjaG8gJ2ZvcmNlLXVuc2FmZS1pbycgPiAvZXRjL2Rwa2cvZHBrZy5jZmcuZC9hdXRvcGtndGVzdAogLSBwcmludGYgJ1xuVEVSTT1saW51eFxuJ2h0dHBfcHJveHk9aHR0cDovL3NxdWlkLmludGVybmFsOjMxMjgnXG4naHR0cHNfcHJveHk9aHR0cDovL3NxdWlkLmludGVybmFsOjMxMjgnXG4nbm9fcHJveHk9MTI3LjAuMC4xLDEyNy4wLjEuMSxsb2dpbi51YnVudHUuY29tLGxvY2FsaG9zdCxsb2NhbGRvbWFpbixub3ZhbG9jYWwsaW50ZXJuYWwsYXJjaGl2ZS51YnVudHUuY29tLHBvcnRzLnVidW50dS5jb20sc2VjdXJpdHkudWJ1bnR1LmNvbSxkZGVicy51YnVudHUuY29tLGNoYW5nZWxvZ3MudWJ1bnR1LmNvbSxrZXlzZXJ2ZXIudWJ1bnR1LmNvbSxsYXVuY2hwYWRsaWJyYXJpYW4ubmV0LGxhdW5jaHBhZGNvbnRlbnQubmV0LGxhdW5jaHBhZC5uZXQsMTAuMjQuMC4wLzI0LGtleXN0b25lLnBzNS5jYW5vbmljYWwuY29tLG9iamVjdHN0b3JhZ2UucHJvZHN0YWNrNS5jYW5vbmljYWwuY29tJ1xuJyA+PiAvZXRjL2Vudmlyb25tZW50CiAtIHNlZCAtaSAtciAnL14xMjcuMC4xLjEvIHMvYXV0b3BrZ3Rlc3QtW14gXStcLi9hdXRvcGtndGVzdFwuLycgL2V0Yy9ob3N0cwo=", "OS-EXT-STS:task_state": null, "OS-EXT-STS:vm_state": "error", "OS-EXT-STS:power_state": 0, "os-extended-volumes:volumes_attached": [], "locked": false, "locked_reason": null, "description": null, "tags": [], "trusted_image_certificates": null, "server_groups": []}} 384s DEBUG (session:936) GET call to compute for https://nova.ps6.canonical.com:8774/v2.1/servers/f9c12418-184c-4734-9a5d-e6c92a3c23eb used request id req-15bdf839-071e-4f4c-81a5-07f758df454d 384s DEBUG (shell:822) 384s Traceback (most recent call last): 384s File "/usr/lib/python3/dist-packages/novaclient/shell.py", line 820, in main 384s OpenStackComputeShell().main(argv) 384s File "/usr/lib/python3/dist-packages/novaclient/shell.py", line 742, in main 384s args.func(self.cs, args) 384s File "/usr/lib/python3/dist-packages/novaclient/v2/shell.py", line 980, in do_boot 384s _poll_for_status(cs.servers.get, server.id, 'building', ['active']) 384s File "/usr/lib/python3/dist-packages/novaclient/v2/shell.py", line 1019, in _poll_for_status 384s raise exceptions.ResourceInErrorState(obj) 384s novaclient.exceptions.ResourceInErrorState: 384s ERROR (ResourceInErrorState): 384s 384s 384s 384s Error building server 388s autopkgtest [18:16:30]: testbed dpkg architecture: arm64 389s autopkgtest [18:16:31]: testbed apt version: 2.9.6 389s autopkgtest [18:16:31]: @@@@@@@@@@@@@@@@@@@@ test bed setup 390s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [126 kB] 391s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [8548 B] 391s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [3232 B] 391s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [372 kB] 391s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [52.7 kB] 391s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 Packages [79.8 kB] 391s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 c-n-f Metadata [2116 B] 391s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/restricted arm64 Packages [43.9 kB] 391s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/restricted arm64 c-n-f Metadata [364 B] 391s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/universe arm64 Packages [328 kB] 391s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/universe arm64 c-n-f Metadata [8752 B] 391s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse arm64 Packages [7596 B] 391s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse arm64 c-n-f Metadata [276 B] 394s Fetched 1034 kB in 1s (742 kB/s) 394s Reading package lists... 398s Reading package lists... 398s Building dependency tree... 398s Reading state information... 399s Calculating upgrade... 399s The following NEW packages will be installed: 399s libpython3.12t64 linux-headers-6.10.0-15 linux-headers-6.10.0-15-generic 399s linux-image-6.10.0-15-generic linux-modules-6.10.0-15-generic 399s linux-modules-extra-6.10.0-15-generic linux-tools-6.10.0-15 399s linux-tools-6.10.0-15-generic 399s The following packages will be upgraded: 399s linux-generic linux-headers-generic linux-headers-virtual 399s linux-image-generic linux-image-virtual linux-libc-dev linux-tools-common 399s linux-virtual 400s 8 upgraded, 8 newly installed, 0 to remove and 0 not upgraded. 400s Need to get 258 MB of archives. 400s After this operation, 363 MB of additional disk space will be used. 400s Get:1 http://ftpmaster.internal/ubuntu oracular/main arm64 libpython3.12t64 arm64 3.12.4-1ubuntu1 [2279 kB] 400s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-modules-6.10.0-15-generic arm64 6.10.0-15.15 [92.4 MB] 403s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-image-6.10.0-15-generic arm64 6.10.0-15.15 [18.3 MB] 404s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-modules-extra-6.10.0-15-generic arm64 6.10.0-15.15 [122 MB] 407s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-generic arm64 6.10.0-15.15 [1728 B] 407s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-image-generic arm64 6.10.0-15.15 [10.5 kB] 407s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-virtual arm64 6.10.0-15.15 [1722 B] 407s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-image-virtual arm64 6.10.0-15.15 [10.4 kB] 407s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-headers-virtual arm64 6.10.0-15.15 [1644 B] 407s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-headers-6.10.0-15 all 6.10.0-15.15 [13.8 MB] 408s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-headers-6.10.0-15-generic arm64 6.10.0-15.15 [3310 kB] 408s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-headers-generic arm64 6.10.0-15.15 [10.3 kB] 408s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-libc-dev arm64 6.10.0-15.15 [1615 kB] 408s Get:14 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-tools-common all 6.10.0-15.15 [474 kB] 408s Get:15 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-tools-6.10.0-15 arm64 6.10.0-15.15 [3687 kB] 408s Get:16 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-tools-6.10.0-15-generic arm64 6.10.0-15.15 [1730 B] 409s Fetched 258 MB in 8s (30.5 MB/s) 409s Selecting previously unselected package libpython3.12t64:arm64. 410s (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 ... 78392 files and directories currently installed.) 410s Preparing to unpack .../00-libpython3.12t64_3.12.4-1ubuntu1_arm64.deb ... 410s Unpacking libpython3.12t64:arm64 (3.12.4-1ubuntu1) ... 410s Selecting previously unselected package linux-modules-6.10.0-15-generic. 410s Preparing to unpack .../01-linux-modules-6.10.0-15-generic_6.10.0-15.15_arm64.deb ... 410s Unpacking linux-modules-6.10.0-15-generic (6.10.0-15.15) ... 411s Selecting previously unselected package linux-image-6.10.0-15-generic. 411s Preparing to unpack .../02-linux-image-6.10.0-15-generic_6.10.0-15.15_arm64.deb ... 411s Unpacking linux-image-6.10.0-15-generic (6.10.0-15.15) ... 411s Selecting previously unselected package linux-modules-extra-6.10.0-15-generic. 412s Preparing to unpack .../03-linux-modules-extra-6.10.0-15-generic_6.10.0-15.15_arm64.deb ... 412s Unpacking linux-modules-extra-6.10.0-15-generic (6.10.0-15.15) ... 417s Preparing to unpack .../04-linux-generic_6.10.0-15.15_arm64.deb ... 417s Unpacking linux-generic (6.10.0-15.15) over (6.8.0-31.31) ... 420s Preparing to unpack .../05-linux-image-generic_6.10.0-15.15_arm64.deb ... 420s Unpacking linux-image-generic (6.10.0-15.15) over (6.8.0-31.31) ... 423s Preparing to unpack .../06-linux-virtual_6.10.0-15.15_arm64.deb ... 423s Unpacking linux-virtual (6.10.0-15.15) over (6.8.0-31.31) ... 425s Preparing to unpack .../07-linux-image-virtual_6.10.0-15.15_arm64.deb ... 425s Unpacking linux-image-virtual (6.10.0-15.15) over (6.8.0-31.31) ... 426s Preparing to unpack .../08-linux-headers-virtual_6.10.0-15.15_arm64.deb ... 426s Unpacking linux-headers-virtual (6.10.0-15.15) over (6.8.0-31.31) ... 427s Selecting previously unselected package linux-headers-6.10.0-15. 428s Preparing to unpack .../09-linux-headers-6.10.0-15_6.10.0-15.15_all.deb ... 428s Unpacking linux-headers-6.10.0-15 (6.10.0-15.15) ... 431s Selecting previously unselected package linux-headers-6.10.0-15-generic. 432s Preparing to unpack .../10-linux-headers-6.10.0-15-generic_6.10.0-15.15_arm64.deb ... 432s Unpacking linux-headers-6.10.0-15-generic (6.10.0-15.15) ... 435s Preparing to unpack .../11-linux-headers-generic_6.10.0-15.15_arm64.deb ... 435s Unpacking linux-headers-generic (6.10.0-15.15) over (6.8.0-31.31) ... 438s Preparing to unpack .../12-linux-libc-dev_6.10.0-15.15_arm64.deb ... 438s Unpacking linux-libc-dev:arm64 (6.10.0-15.15) over (6.8.0-31.31) ... 441s Preparing to unpack .../13-linux-tools-common_6.10.0-15.15_all.deb ... 441s Unpacking linux-tools-common (6.10.0-15.15) over (6.8.0-31.31) ... 441s Selecting previously unselected package linux-tools-6.10.0-15. 442s Preparing to unpack .../14-linux-tools-6.10.0-15_6.10.0-15.15_arm64.deb ... 442s Unpacking linux-tools-6.10.0-15 (6.10.0-15.15) ... 442s Selecting previously unselected package linux-tools-6.10.0-15-generic. 443s Preparing to unpack .../15-linux-tools-6.10.0-15-generic_6.10.0-15.15_arm64.deb ... 443s Unpacking linux-tools-6.10.0-15-generic (6.10.0-15.15) ... 444s Setting up linux-headers-6.10.0-15 (6.10.0-15.15) ... 444s Setting up linux-headers-6.10.0-15-generic (6.10.0-15.15) ... 444s Setting up linux-libc-dev:arm64 (6.10.0-15.15) ... 444s Setting up linux-headers-generic (6.10.0-15.15) ... 444s Setting up libpython3.12t64:arm64 (3.12.4-1ubuntu1) ... 444s Setting up linux-modules-6.10.0-15-generic (6.10.0-15.15) ... 446s Setting up linux-tools-common (6.10.0-15.15) ... 446s Setting up linux-modules-extra-6.10.0-15-generic (6.10.0-15.15) ... 449s Setting up linux-image-6.10.0-15-generic (6.10.0-15.15) ... 452s I: /boot/vmlinuz is now a symlink to vmlinuz-6.10.0-15-generic 452s I: /boot/initrd.img is now a symlink to initrd.img-6.10.0-15-generic 452s Setting up linux-headers-virtual (6.10.0-15.15) ... 452s Setting up linux-tools-6.10.0-15 (6.10.0-15.15) ... 452s Setting up linux-image-virtual (6.10.0-15.15) ... 452s Setting up linux-image-generic (6.10.0-15.15) ... 452s Setting up linux-generic (6.10.0-15.15) ... 452s Setting up linux-virtual (6.10.0-15.15) ... 452s Setting up linux-tools-6.10.0-15-generic (6.10.0-15.15) ... 452s Processing triggers for man-db (2.12.1-2) ... 453s Processing triggers for libc-bin (2.39-0ubuntu9) ... 453s Processing triggers for linux-image-6.10.0-15-generic (6.10.0-15.15) ... 453s /etc/kernel/postinst.d/initramfs-tools: 453s update-initramfs: Generating /boot/initrd.img-6.10.0-15-generic 453s W: No lz4 in /usr/bin:/sbin:/bin, using gzip 494s flash-kernel: deferring update (trigger activated) 494s /etc/kernel/postinst.d/zz-flash-kernel: 494s flash-kernel: deferring update (trigger activated) 495s /etc/kernel/postinst.d/zz-update-grub: 495s Sourcing file `/etc/default/grub' 495s Sourcing file `/etc/default/grub.d/50-cloudimg-settings.cfg' 495s Generating grub configuration file ... 496s Found linux image: /boot/vmlinuz-6.10.0-15-generic 496s Found initrd image: /boot/initrd.img-6.10.0-15-generic 496s Found linux image: /boot/vmlinuz-6.8.0-31-generic 496s Found initrd image: /boot/initrd.img-6.8.0-31-generic 497s Warning: os-prober will not be executed to detect other bootable partitions. 497s Systems on them will not be added to the GRUB boot configuration. 497s Check GRUB_DISABLE_OS_PROBER documentation entry. 497s Adding boot menu entry for UEFI Firmware Settings ... 497s done 497s Processing triggers for flash-kernel (3.107ubuntu9) ... 497s System running in EFI mode, skipping. 498s Reading package lists... 498s Building dependency tree... 498s Reading state information... 499s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 499s Get:1 http://ftpmaster.internal/ubuntu oracular InRelease [121 kB] 500s Hit:2 http://ftpmaster.internal/ubuntu oracular-updates InRelease 500s Hit:3 http://ftpmaster.internal/ubuntu oracular-security InRelease 500s Hit:4 http://ftpmaster.internal/ubuntu oracular-proposed InRelease 500s Get:5 http://ftpmaster.internal/ubuntu oracular/main Sources [1377 kB] 501s Get:6 http://ftpmaster.internal/ubuntu oracular/universe Sources [20.2 MB] 502s Get:7 http://ftpmaster.internal/ubuntu oracular/multiverse Sources [301 kB] 502s Get:8 http://ftpmaster.internal/ubuntu oracular/main arm64 Packages [1394 kB] 502s Get:9 http://ftpmaster.internal/ubuntu oracular/universe arm64 Packages [15.1 MB] 502s Get:10 http://ftpmaster.internal/ubuntu oracular/multiverse arm64 Packages [224 kB] 506s Fetched 38.7 MB in 5s (7105 kB/s) 509s Reading package lists... 511s Reading package lists... 512s Building dependency tree... 512s Reading state information... 512s Calculating upgrade... 513s The following packages will be upgraded: 513s dash libudisks2-0 libxml2 udisks2 514s 4 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 514s Need to get 1180 kB of archives. 514s After this operation, 385 kB disk space will be freed. 514s Get:1 http://ftpmaster.internal/ubuntu oracular/main arm64 dash arm64 0.5.12-9ubuntu1 [90.8 kB] 514s Get:2 http://ftpmaster.internal/ubuntu oracular/main arm64 libxml2 arm64 2.12.7+dfsg-3 [627 kB] 514s Get:3 http://ftpmaster.internal/ubuntu oracular/main arm64 udisks2 arm64 2.10.1-9ubuntu1 [291 kB] 514s Get:4 http://ftpmaster.internal/ubuntu oracular/main arm64 libudisks2-0 arm64 2.10.1-9ubuntu1 [171 kB] 529s Fetched 1180 kB in 1s (1299 kB/s) 529s (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 ... 121252 files and directories currently installed.) 529s Preparing to unpack .../dash_0.5.12-9ubuntu1_arm64.deb ... 529s Unpacking dash (0.5.12-9ubuntu1) over (0.5.12-6ubuntu5) ... 530s Setting up dash (0.5.12-9ubuntu1) ... 530s (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 ... 121252 files and directories currently installed.) 530s Preparing to unpack .../libxml2_2.12.7+dfsg-3_arm64.deb ... 530s Unpacking libxml2:arm64 (2.12.7+dfsg-3) over (2.9.14+dfsg-1.3ubuntu3) ... 531s Preparing to unpack .../udisks2_2.10.1-9ubuntu1_arm64.deb ... 531s Unpacking udisks2 (2.10.1-9ubuntu1) over (2.10.1-9) ... 532s Preparing to unpack .../libudisks2-0_2.10.1-9ubuntu1_arm64.deb ... 532s Unpacking libudisks2-0:arm64 (2.10.1-9ubuntu1) over (2.10.1-9) ... 532s Setting up libxml2:arm64 (2.12.7+dfsg-3) ... 532s Setting up libudisks2-0:arm64 (2.10.1-9ubuntu1) ... 532s Setting up udisks2 (2.10.1-9ubuntu1) ... 534s Processing triggers for man-db (2.12.1-2) ... 535s Processing triggers for dbus (1.14.10-4ubuntu4) ... 535s Processing triggers for debianutils (5.20) ... 535s Processing triggers for libc-bin (2.39-0ubuntu9) ... 536s Reading package lists... 536s Building dependency tree... 536s Reading state information... 537s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 537s Reading package lists... 537s Building dependency tree... 537s Reading state information... 538s linux-generic is already the newest version (6.10.0-15.15). 538s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 538s Reading package lists... 538s Building dependency tree... 538s Reading state information... 538s E: Unable to locate package ^kernel-testing--linux--modules-extra--preferred$ 538s E: Couldn't find any package by regex '^kernel-testing--linux--modules-extra--preferred$' 539s Reading package lists... 539s Building dependency tree... 539s Reading state information... 539s E: Unable to locate package ^linux-modules-extra$ 539s E: Couldn't find any package by regex '^linux-modules-extra$' 539s autopkgtest [18:19:01]: rebooting testbed after setup commands that affected boot 544s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 577s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 585s autopkgtest [18:19:47]: testbed running kernel: Linux 6.10.0-15-generic #15-Ubuntu SMP PREEMPT_DYNAMIC Thu Jul 4 12:16:56 UTC 2024 591s autopkgtest [18:19:53]: @@@@@@@@@@@@@@@@@@@@ apt-source multipath-tools 596s Get:1 http://ftpmaster.internal/ubuntu oracular/main multipath-tools 0.9.4-5ubuntu8 (dsc) [2770 B] 596s Get:2 http://ftpmaster.internal/ubuntu oracular/main multipath-tools 0.9.4-5ubuntu8 (tar) [554 kB] 596s Get:3 http://ftpmaster.internal/ubuntu oracular/main multipath-tools 0.9.4-5ubuntu8 (diff) [42.7 kB] 596s gpgv: Signature made Sun Apr 7 00:31:08 2024 UTC 596s gpgv: using RSA key AC483F68DE728F43F2202FCA568D30F321B2133D 596s gpgv: issuer "steve.langasek@ubuntu.com" 596s gpgv: Can't check signature: No public key 596s dpkg-source: warning: cannot verify inline signature for ./multipath-tools_0.9.4-5ubuntu8.dsc: no acceptable signature found 598s autopkgtest [18:20:00]: testing package multipath-tools version 0.9.4-5ubuntu8 598s autopkgtest [18:20:00]: build not needed 599s autopkgtest [18:20:01]: test kpartx-file-loopback: preparing testbed 601s Reading package lists... 601s Building dependency tree... 601s Reading state information... 601s Starting pkgProblemResolver with broken count: 0 602s Starting 2 pkgProblemResolver with broken count: 0 602s Done 602s The following additional packages will be installed: 602s liburing2 qemu-utils 602s Recommended packages: 602s qemu-block-extra 602s The following NEW packages will be installed: 602s autopkgtest-satdep liburing2 qemu-utils 602s 0 upgraded, 3 newly installed, 0 to remove and 0 not upgraded. 602s Need to get 2069 kB/2070 kB of archives. 602s After this operation, 11.8 MB of additional disk space will be used. 602s Get:1 /tmp/autopkgtest.gRUmZi/1-autopkgtest-satdep.deb autopkgtest-satdep arm64 0 [720 B] 603s Get:2 http://ftpmaster.internal/ubuntu oracular/main arm64 liburing2 arm64 2.6-1 [22.9 kB] 603s Get:3 http://ftpmaster.internal/ubuntu oracular/main arm64 qemu-utils arm64 1:8.2.2+ds-0ubuntu1 [2046 kB] 612s Fetched 2069 kB in 1s (2188 kB/s) 615s Selecting previously unselected package liburing2:arm64. 617s (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 ... 121252 files and directories currently installed.) 617s Preparing to unpack .../liburing2_2.6-1_arm64.deb ... 617s Unpacking liburing2:arm64 (2.6-1) ... 618s Selecting previously unselected package qemu-utils. 624s Preparing to unpack .../qemu-utils_1%3a8.2.2+ds-0ubuntu1_arm64.deb ... 624s Unpacking qemu-utils (1:8.2.2+ds-0ubuntu1) ... 625s Selecting previously unselected package autopkgtest-satdep. 628s Preparing to unpack .../1-autopkgtest-satdep.deb ... 628s Unpacking autopkgtest-satdep (0) ... 629s Setting up liburing2:arm64 (2.6-1) ... 629s Setting up qemu-utils (1:8.2.2+ds-0ubuntu1) ... 629s Setting up autopkgtest-satdep (0) ... 629s Processing triggers for man-db (2.12.1-2) ... 630s Processing triggers for libc-bin (2.39-0ubuntu9) ... 635s (Reading database ... 121272 files and directories currently installed.) 635s Removing autopkgtest-satdep (0) ... 636s autopkgtest [18:20:38]: test kpartx-file-loopback: [----------------------- 637s Formatting 'foo.img', fmt=raw size=20971520 638s Creating new GPT entries in memory. 638s Warning: The kernel is still using the old partition table. 638s The new table will be used at the next reboot or after you 638s run partprobe(8) or kpartx(8) 638s The operation has completed successfully. 638s add map loop0p1 (252:0): 0 38879 linear 7:0 2048 638s standard_filename: OK 638s del devmap : loop0p1 638s No devices found 638s standard_filename_cleanup: OK 638s Formatting 'fou du FaFa.img', fmt=raw size=20971520 639s Creating new GPT entries in memory. 639s Warning: The kernel is still using the old partition table. 639s The new table will be used at the next reboot or after you 639s run partprobe(8) or kpartx(8) 639s The operation has completed successfully. 639s add map loop0p1 (252:0): 0 38879 linear 7:0 2048 639s filename_with_spaces: OK 639s del devmap : loop0p1 639s No devices found 639s filename_with_spaces_cleanup: OK 639s autopkgtest [18:20:41]: test kpartx-file-loopback: -----------------------] 640s autopkgtest [18:20:42]: test kpartx-file-loopback: - - - - - - - - - - results - - - - - - - - - - 640s kpartx-file-loopback PASS 640s autopkgtest [18:20:42]: test tgtbasedmpaths: preparing testbed 1394s autopkgtest [18:33:16]: testbed dpkg architecture: arm64 1394s autopkgtest [18:33:16]: testbed apt version: 2.9.6 1394s autopkgtest [18:33:16]: @@@@@@@@@@@@@@@@@@@@ test bed setup 1396s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [126 kB] 1399s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [378 kB] 1400s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [8548 B] 1400s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [3232 B] 1400s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [59.2 kB] 1400s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 Packages [80.3 kB] 1400s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 c-n-f Metadata [2116 B] 1400s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/restricted arm64 Packages [43.9 kB] 1400s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/restricted arm64 c-n-f Metadata [364 B] 1400s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/universe arm64 Packages [328 kB] 1400s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/universe arm64 c-n-f Metadata [8752 B] 1400s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse arm64 Packages [7596 B] 1400s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse arm64 c-n-f Metadata [276 B] 1406s Fetched 1047 kB in 5s (217 kB/s) 1407s Reading package lists... 1423s Reading package lists... 1423s Building dependency tree... 1423s Reading state information... 1424s Calculating upgrade... 1425s The following NEW packages will be installed: 1425s libpython3.12t64 linux-headers-6.10.0-15 linux-headers-6.10.0-15-generic 1425s linux-image-6.10.0-15-generic linux-modules-6.10.0-15-generic 1425s linux-modules-extra-6.10.0-15-generic linux-tools-6.10.0-15 1425s linux-tools-6.10.0-15-generic 1425s The following packages will be upgraded: 1425s dash libudisks2-0 libxml2 linux-generic linux-headers-generic 1425s linux-headers-virtual linux-image-generic linux-image-virtual linux-libc-dev 1425s linux-tools-common linux-virtual udisks2 1425s 12 upgraded, 8 newly installed, 0 to remove and 0 not upgraded. 1425s Need to get 260 MB of archives. 1425s After this operation, 363 MB of additional disk space will be used. 1425s Get:1 http://ftpmaster.internal/ubuntu oracular/main arm64 dash arm64 0.5.12-9ubuntu1 [90.8 kB] 1425s Get:2 http://ftpmaster.internal/ubuntu oracular/main arm64 libxml2 arm64 2.12.7+dfsg-3 [627 kB] 1426s Get:3 http://ftpmaster.internal/ubuntu oracular/main arm64 libpython3.12t64 arm64 3.12.4-1ubuntu1 [2279 kB] 1426s Get:4 http://ftpmaster.internal/ubuntu oracular/main arm64 udisks2 arm64 2.10.1-9ubuntu1 [291 kB] 1426s Get:5 http://ftpmaster.internal/ubuntu oracular/main arm64 libudisks2-0 arm64 2.10.1-9ubuntu1 [171 kB] 1426s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-modules-6.10.0-15-generic arm64 6.10.0-15.15 [92.4 MB] 1432s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-image-6.10.0-15-generic arm64 6.10.0-15.15 [18.3 MB] 1432s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-modules-extra-6.10.0-15-generic arm64 6.10.0-15.15 [122 MB] 1436s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-generic arm64 6.10.0-15.15 [1728 B] 1436s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-image-generic arm64 6.10.0-15.15 [10.5 kB] 1436s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-virtual arm64 6.10.0-15.15 [1722 B] 1436s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-image-virtual arm64 6.10.0-15.15 [10.4 kB] 1436s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-headers-virtual arm64 6.10.0-15.15 [1644 B] 1436s Get:14 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-headers-6.10.0-15 all 6.10.0-15.15 [13.8 MB] 1436s Get:15 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-headers-6.10.0-15-generic arm64 6.10.0-15.15 [3310 kB] 1436s Get:16 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-headers-generic arm64 6.10.0-15.15 [10.3 kB] 1436s Get:17 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-libc-dev arm64 6.10.0-15.15 [1615 kB] 1437s Get:18 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-tools-common all 6.10.0-15.15 [474 kB] 1437s Get:19 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-tools-6.10.0-15 arm64 6.10.0-15.15 [3687 kB] 1437s Get:20 http://ftpmaster.internal/ubuntu oracular-proposed/main arm64 linux-tools-6.10.0-15-generic arm64 6.10.0-15.15 [1730 B] 1446s Fetched 260 MB in 12s (22.1 MB/s) 1448s (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 ... 78392 files and directories currently installed.) 1448s Preparing to unpack .../dash_0.5.12-9ubuntu1_arm64.deb ... 1448s Unpacking dash (0.5.12-9ubuntu1) over (0.5.12-6ubuntu5) ... 1449s Setting up dash (0.5.12-9ubuntu1) ... 1451s (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 ... 78392 files and directories currently installed.) 1451s Preparing to unpack .../00-libxml2_2.12.7+dfsg-3_arm64.deb ... 1451s Unpacking libxml2:arm64 (2.12.7+dfsg-3) over (2.9.14+dfsg-1.3ubuntu3) ... 1451s Selecting previously unselected package libpython3.12t64:arm64. 1454s Preparing to unpack .../01-libpython3.12t64_3.12.4-1ubuntu1_arm64.deb ... 1454s Unpacking libpython3.12t64:arm64 (3.12.4-1ubuntu1) ... 1456s Preparing to unpack .../02-udisks2_2.10.1-9ubuntu1_arm64.deb ... 1456s Unpacking udisks2 (2.10.1-9ubuntu1) over (2.10.1-9) ... 1460s Preparing to unpack .../03-libudisks2-0_2.10.1-9ubuntu1_arm64.deb ... 1460s Unpacking libudisks2-0:arm64 (2.10.1-9ubuntu1) over (2.10.1-9) ... 1460s Selecting previously unselected package linux-modules-6.10.0-15-generic. 1465s Preparing to unpack .../04-linux-modules-6.10.0-15-generic_6.10.0-15.15_arm64.deb ... 1465s Unpacking linux-modules-6.10.0-15-generic (6.10.0-15.15) ... 1468s Selecting previously unselected package linux-image-6.10.0-15-generic. 1472s Preparing to unpack .../05-linux-image-6.10.0-15-generic_6.10.0-15.15_arm64.deb ... 1473s Unpacking linux-image-6.10.0-15-generic (6.10.0-15.15) ... 1473s Selecting previously unselected package linux-modules-extra-6.10.0-15-generic. 1478s Preparing to unpack .../06-linux-modules-extra-6.10.0-15-generic_6.10.0-15.15_arm64.deb ... 1478s Unpacking linux-modules-extra-6.10.0-15-generic (6.10.0-15.15) ... 1494s Preparing to unpack .../07-linux-generic_6.10.0-15.15_arm64.deb ... 1494s Unpacking linux-generic (6.10.0-15.15) over (6.8.0-31.31) ... 1501s Preparing to unpack .../08-linux-image-generic_6.10.0-15.15_arm64.deb ... 1501s Unpacking linux-image-generic (6.10.0-15.15) over (6.8.0-31.31) ... 1509s Preparing to unpack .../09-linux-virtual_6.10.0-15.15_arm64.deb ... 1509s Unpacking linux-virtual (6.10.0-15.15) over (6.8.0-31.31) ... 1516s Preparing to unpack .../10-linux-image-virtual_6.10.0-15.15_arm64.deb ... 1516s Unpacking linux-image-virtual (6.10.0-15.15) over (6.8.0-31.31) ... 1523s Preparing to unpack .../11-linux-headers-virtual_6.10.0-15.15_arm64.deb ... 1523s Unpacking linux-headers-virtual (6.10.0-15.15) over (6.8.0-31.31) ... 1523s Selecting previously unselected package linux-headers-6.10.0-15. 1529s Preparing to unpack .../12-linux-headers-6.10.0-15_6.10.0-15.15_all.deb ... 1529s Unpacking linux-headers-6.10.0-15 (6.10.0-15.15) ... 1541s Selecting previously unselected package linux-headers-6.10.0-15-generic. 1545s Preparing to unpack .../13-linux-headers-6.10.0-15-generic_6.10.0-15.15_arm64.deb ... 1546s Unpacking linux-headers-6.10.0-15-generic (6.10.0-15.15) ... 1553s Preparing to unpack .../14-linux-headers-generic_6.10.0-15.15_arm64.deb ... 1553s Unpacking linux-headers-generic (6.10.0-15.15) over (6.8.0-31.31) ... 1556s Preparing to unpack .../15-linux-libc-dev_6.10.0-15.15_arm64.deb ... 1556s Unpacking linux-libc-dev:arm64 (6.10.0-15.15) over (6.8.0-31.31) ... 1559s Preparing to unpack .../16-linux-tools-common_6.10.0-15.15_all.deb ... 1559s Unpacking linux-tools-common (6.10.0-15.15) over (6.8.0-31.31) ... 1560s Selecting previously unselected package linux-tools-6.10.0-15. 1563s Preparing to unpack .../17-linux-tools-6.10.0-15_6.10.0-15.15_arm64.deb ... 1563s Unpacking linux-tools-6.10.0-15 (6.10.0-15.15) ... 1564s Selecting previously unselected package linux-tools-6.10.0-15-generic. 1570s Preparing to unpack .../18-linux-tools-6.10.0-15-generic_6.10.0-15.15_arm64.deb ... 1570s Unpacking linux-tools-6.10.0-15-generic (6.10.0-15.15) ... 1577s Setting up linux-headers-6.10.0-15 (6.10.0-15.15) ... 1577s Setting up linux-headers-6.10.0-15-generic (6.10.0-15.15) ... 1577s Setting up linux-libc-dev:arm64 (6.10.0-15.15) ... 1577s Setting up linux-headers-generic (6.10.0-15.15) ... 1577s Setting up libpython3.12t64:arm64 (3.12.4-1ubuntu1) ... 1577s Setting up linux-modules-6.10.0-15-generic (6.10.0-15.15) ... 1582s Setting up linux-tools-common (6.10.0-15.15) ... 1582s Setting up libxml2:arm64 (2.12.7+dfsg-3) ... 1582s Setting up libudisks2-0:arm64 (2.10.1-9ubuntu1) ... 1582s Setting up linux-modules-extra-6.10.0-15-generic (6.10.0-15.15) ... 1586s Setting up udisks2 (2.10.1-9ubuntu1) ... 1601s Setting up linux-image-6.10.0-15-generic (6.10.0-15.15) ... 1603s I: /boot/vmlinuz is now a symlink to vmlinuz-6.10.0-15-generic 1603s I: /boot/initrd.img is now a symlink to initrd.img-6.10.0-15-generic 1604s Setting up linux-headers-virtual (6.10.0-15.15) ... 1604s Setting up linux-tools-6.10.0-15 (6.10.0-15.15) ... 1604s Setting up linux-image-virtual (6.10.0-15.15) ... 1604s Setting up linux-image-generic (6.10.0-15.15) ... 1604s Setting up linux-generic (6.10.0-15.15) ... 1604s Setting up linux-virtual (6.10.0-15.15) ... 1604s Setting up linux-tools-6.10.0-15-generic (6.10.0-15.15) ... 1604s Processing triggers for debianutils (5.20) ... 1606s Processing triggers for libc-bin (2.39-0ubuntu9) ... 1606s Processing triggers for man-db (2.12.1-2) ... 1611s Processing triggers for dbus (1.14.10-4ubuntu4) ... 1612s Processing triggers for linux-image-6.10.0-15-generic (6.10.0-15.15) ... 1612s /etc/kernel/postinst.d/initramfs-tools: 1612s update-initramfs: Generating /boot/initrd.img-6.10.0-15-generic 1613s W: No lz4 in /usr/bin:/sbin:/bin, using gzip 1935s flash-kernel: deferring update (trigger activated) 1936s /etc/kernel/postinst.d/zz-flash-kernel: 1936s flash-kernel: deferring update (trigger activated) 1937s /etc/kernel/postinst.d/zz-update-grub: 1937s Sourcing file `/etc/default/grub' 1937s Sourcing file `/etc/default/grub.d/50-cloudimg-settings.cfg' 1937s Generating grub configuration file ... 1939s Found linux image: /boot/vmlinuz-6.10.0-15-generic 1940s Found initrd image: /boot/initrd.img-6.10.0-15-generic 1942s Found linux image: /boot/vmlinuz-6.8.0-31-generic 1942s Found initrd image: /boot/initrd.img-6.8.0-31-generic 1944s Warning: os-prober will not be executed to detect other bootable partitions. 1944s Systems on them will not be added to the GRUB boot configuration. 1944s Check GRUB_DISABLE_OS_PROBER documentation entry. 1944s Adding boot menu entry for UEFI Firmware Settings ... 1944s done 1945s Processing triggers for flash-kernel (3.107ubuntu9) ... 1949s System running in EFI mode, skipping. 1951s Reading package lists... 1952s Building dependency tree... 1952s Reading state information... 1953s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 1957s Hit:1 http://ftpmaster.internal/ubuntu oracular InRelease 1957s Hit:2 http://ftpmaster.internal/ubuntu oracular-updates InRelease 1957s Hit:3 http://ftpmaster.internal/ubuntu oracular-security InRelease 1957s Hit:4 http://ftpmaster.internal/ubuntu oracular-proposed InRelease 1978s Reading package lists... 1979s Reading package lists... 1979s Building dependency tree... 1979s Reading state information... 1980s Calculating upgrade... 1980s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 1982s Reading package lists... 1982s Building dependency tree... 1982s Reading state information... 1983s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 1985s Reading package lists... 1986s Building dependency tree... 1986s Reading state information... 1987s linux-generic is already the newest version (6.10.0-15.15). 1987s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 1991s Reading package lists... 1992s Building dependency tree... 1992s Reading state information... 1992s E: Unable to locate package ^kernel-testing--linux--modules-extra--preferred$ 1992s E: Couldn't find any package by regex '^kernel-testing--linux--modules-extra--preferred$' 1993s Reading package lists... 1993s Building dependency tree... 1993s Reading state information... 1993s E: Unable to locate package ^linux-modules-extra$ 1993s E: Couldn't find any package by regex '^linux-modules-extra$' 1997s autopkgtest [18:43:19]: rebooting testbed after setup commands that affected boot 2007s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 2040s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 2073s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 2106s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 2139s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 2172s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 2205s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 2238s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 2271s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 2326s Reading package lists... 2326s Building dependency tree... 2326s Reading state information... 2327s Starting pkgProblemResolver with broken count: 0 2327s Starting 2 pkgProblemResolver with broken count: 0 2327s Done 2328s The following additional packages will be installed: 2328s fio libboost-iostreams1.83.0 libboost-thread1.83.0 libconfig-general-perl 2328s libdaxctl1 libgfapi0 libgfrpc0 libgfxdr0 libglusterfs0 libisns0t64 libnbd0 2328s libndctl6 libopeniscsiusr libpmem1 libpmemobj1 librados2 librbd1 2328s librdmacm1t64 lsscsi open-iscsi tgt 2328s Suggested packages: 2328s fio-examples gnuplot tgt-glusterfs tgt-rbd 2328s Recommended packages: 2328s finalrd 2328s The following NEW packages will be installed: 2328s autopkgtest-satdep fio libboost-iostreams1.83.0 libboost-thread1.83.0 2328s libconfig-general-perl libdaxctl1 libgfapi0 libgfrpc0 libgfxdr0 2328s libglusterfs0 libisns0t64 libnbd0 libndctl6 libopeniscsiusr libpmem1 2328s libpmemobj1 librados2 librbd1 librdmacm1t64 lsscsi open-iscsi tgt 2328s 0 upgraded, 22 newly installed, 0 to remove and 0 not upgraded. 2328s Need to get 9773 kB/9773 kB of archives. 2328s After this operation, 43.3 MB of additional disk space will be used. 2328s Get:1 /tmp/autopkgtest.gRUmZi/2-autopkgtest-satdep.deb autopkgtest-satdep arm64 0 [732 B] 2329s Get:2 http://ftpmaster.internal/ubuntu oracular/main arm64 libopeniscsiusr arm64 2.1.10-1ubuntu1 [47.9 kB] 2329s Get:3 http://ftpmaster.internal/ubuntu oracular/main arm64 libisns0t64 arm64 0.101-1 [95.0 kB] 2329s Get:4 http://ftpmaster.internal/ubuntu oracular/main arm64 open-iscsi arm64 2.1.10-1ubuntu1 [336 kB] 2329s Get:5 http://ftpmaster.internal/ubuntu oracular/main arm64 librdmacm1t64 arm64 52.0-2 [70.8 kB] 2329s Get:6 http://ftpmaster.internal/ubuntu oracular/universe arm64 libconfig-general-perl all 2.65-2 [57.1 kB] 2329s Get:7 http://ftpmaster.internal/ubuntu oracular/universe arm64 tgt arm64 1:1.0.85-1.2ubuntu1 [233 kB] 2329s Get:8 http://ftpmaster.internal/ubuntu oracular/universe arm64 libgfxdr0 arm64 11.1-4ubuntu1 [19.6 kB] 2329s Get:9 http://ftpmaster.internal/ubuntu oracular/universe arm64 libglusterfs0 arm64 11.1-4ubuntu1 [267 kB] 2329s Get:10 http://ftpmaster.internal/ubuntu oracular/universe arm64 libgfrpc0 arm64 11.1-4ubuntu1 [41.0 kB] 2329s Get:11 http://ftpmaster.internal/ubuntu oracular/universe arm64 libgfapi0 arm64 11.1-4ubuntu1 [78.4 kB] 2329s Get:12 http://ftpmaster.internal/ubuntu oracular/universe arm64 libnbd0 arm64 1.20.2-1 [90.0 kB] 2329s Get:13 http://ftpmaster.internal/ubuntu oracular/main arm64 libdaxctl1 arm64 77-2ubuntu2 [21.2 kB] 2329s Get:14 http://ftpmaster.internal/ubuntu oracular/main arm64 libndctl6 arm64 77-2ubuntu2 [63.1 kB] 2329s Get:15 http://ftpmaster.internal/ubuntu oracular/main arm64 libpmem1 arm64 1.13.1-1.1ubuntu2 [36.2 kB] 2329s Get:16 http://ftpmaster.internal/ubuntu oracular/main arm64 libboost-iostreams1.83.0 arm64 1.83.0-3ubuntu1 [258 kB] 2329s Get:17 http://ftpmaster.internal/ubuntu oracular/main arm64 libboost-thread1.83.0 arm64 1.83.0-3ubuntu1 [275 kB] 2329s Get:18 http://ftpmaster.internal/ubuntu oracular/main arm64 librados2 arm64 19.2.0~git20240301.4c76c50-0ubuntu7 [3781 kB] 2329s Get:19 http://ftpmaster.internal/ubuntu oracular/main arm64 libpmemobj1 arm64 1.13.1-1.1ubuntu2 [117 kB] 2329s Get:20 http://ftpmaster.internal/ubuntu oracular/main arm64 librbd1 arm64 19.2.0~git20240301.4c76c50-0ubuntu7 [3240 kB] 2329s Get:21 http://ftpmaster.internal/ubuntu oracular/universe arm64 fio arm64 3.37-1 [597 kB] 2329s Get:22 http://ftpmaster.internal/ubuntu oracular/main arm64 lsscsi arm64 0.32-1build1 [48.5 kB] 2332s Preconfiguring packages ... 2332s Fetched 9773 kB in 1s (8838 kB/s) 2332s Selecting previously unselected package libopeniscsiusr. 2333s (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 ... 121252 files and directories currently installed.) 2333s Preparing to unpack .../00-libopeniscsiusr_2.1.10-1ubuntu1_arm64.deb ... 2333s Unpacking libopeniscsiusr (2.1.10-1ubuntu1) ... 2333s Selecting previously unselected package libisns0t64:arm64. 2333s Preparing to unpack .../01-libisns0t64_0.101-1_arm64.deb ... 2333s Unpacking libisns0t64:arm64 (0.101-1) ... 2333s Selecting previously unselected package open-iscsi. 2333s Preparing to unpack .../02-open-iscsi_2.1.10-1ubuntu1_arm64.deb ... 2333s Unpacking open-iscsi (2.1.10-1ubuntu1) ... 2333s Selecting previously unselected package librdmacm1t64:arm64. 2333s Preparing to unpack .../03-librdmacm1t64_52.0-2_arm64.deb ... 2333s Unpacking librdmacm1t64:arm64 (52.0-2) ... 2333s Selecting previously unselected package libconfig-general-perl. 2333s Preparing to unpack .../04-libconfig-general-perl_2.65-2_all.deb ... 2333s Unpacking libconfig-general-perl (2.65-2) ... 2333s Selecting previously unselected package tgt. 2333s Preparing to unpack .../05-tgt_1%3a1.0.85-1.2ubuntu1_arm64.deb ... 2333s Unpacking tgt (1:1.0.85-1.2ubuntu1) ... 2334s Selecting previously unselected package libgfxdr0:arm64. 2334s Preparing to unpack .../06-libgfxdr0_11.1-4ubuntu1_arm64.deb ... 2334s Unpacking libgfxdr0:arm64 (11.1-4ubuntu1) ... 2334s Selecting previously unselected package libglusterfs0:arm64. 2334s Preparing to unpack .../07-libglusterfs0_11.1-4ubuntu1_arm64.deb ... 2334s Unpacking libglusterfs0:arm64 (11.1-4ubuntu1) ... 2334s Selecting previously unselected package libgfrpc0:arm64. 2334s Preparing to unpack .../08-libgfrpc0_11.1-4ubuntu1_arm64.deb ... 2334s Unpacking libgfrpc0:arm64 (11.1-4ubuntu1) ... 2334s Selecting previously unselected package libgfapi0:arm64. 2334s Preparing to unpack .../09-libgfapi0_11.1-4ubuntu1_arm64.deb ... 2334s Unpacking libgfapi0:arm64 (11.1-4ubuntu1) ... 2334s Selecting previously unselected package libnbd0. 2334s Preparing to unpack .../10-libnbd0_1.20.2-1_arm64.deb ... 2334s Unpacking libnbd0 (1.20.2-1) ... 2334s Selecting previously unselected package libdaxctl1:arm64. 2334s Preparing to unpack .../11-libdaxctl1_77-2ubuntu2_arm64.deb ... 2334s Unpacking libdaxctl1:arm64 (77-2ubuntu2) ... 2334s Selecting previously unselected package libndctl6:arm64. 2334s Preparing to unpack .../12-libndctl6_77-2ubuntu2_arm64.deb ... 2334s Unpacking libndctl6:arm64 (77-2ubuntu2) ... 2334s Selecting previously unselected package libpmem1:arm64. 2335s Preparing to unpack .../13-libpmem1_1.13.1-1.1ubuntu2_arm64.deb ... 2335s Unpacking libpmem1:arm64 (1.13.1-1.1ubuntu2) ... 2335s Selecting previously unselected package libboost-iostreams1.83.0:arm64. 2335s Preparing to unpack .../14-libboost-iostreams1.83.0_1.83.0-3ubuntu1_arm64.deb ... 2335s Unpacking libboost-iostreams1.83.0:arm64 (1.83.0-3ubuntu1) ... 2335s Selecting previously unselected package libboost-thread1.83.0:arm64. 2335s Preparing to unpack .../15-libboost-thread1.83.0_1.83.0-3ubuntu1_arm64.deb ... 2335s Unpacking libboost-thread1.83.0:arm64 (1.83.0-3ubuntu1) ... 2335s Selecting previously unselected package librados2. 2335s Preparing to unpack .../16-librados2_19.2.0~git20240301.4c76c50-0ubuntu7_arm64.deb ... 2335s Unpacking librados2 (19.2.0~git20240301.4c76c50-0ubuntu7) ... 2335s Selecting previously unselected package libpmemobj1:arm64. 2335s Preparing to unpack .../17-libpmemobj1_1.13.1-1.1ubuntu2_arm64.deb ... 2335s Unpacking libpmemobj1:arm64 (1.13.1-1.1ubuntu2) ... 2335s Selecting previously unselected package librbd1. 2335s Preparing to unpack .../18-librbd1_19.2.0~git20240301.4c76c50-0ubuntu7_arm64.deb ... 2335s Unpacking librbd1 (19.2.0~git20240301.4c76c50-0ubuntu7) ... 2335s Selecting previously unselected package fio. 2335s Preparing to unpack .../19-fio_3.37-1_arm64.deb ... 2335s Unpacking fio (3.37-1) ... 2335s Selecting previously unselected package lsscsi. 2335s Preparing to unpack .../20-lsscsi_0.32-1build1_arm64.deb ... 2335s Unpacking lsscsi (0.32-1build1) ... 2336s Selecting previously unselected package autopkgtest-satdep. 2336s Preparing to unpack .../21-2-autopkgtest-satdep.deb ... 2336s Unpacking autopkgtest-satdep (0) ... 2336s Setting up libconfig-general-perl (2.65-2) ... 2336s Setting up libisns0t64:arm64 (0.101-1) ... 2336s Setting up libboost-thread1.83.0:arm64 (1.83.0-3ubuntu1) ... 2336s Setting up libnbd0 (1.20.2-1) ... 2336s Setting up libopeniscsiusr (2.1.10-1ubuntu1) ... 2336s Setting up libglusterfs0:arm64 (11.1-4ubuntu1) ... 2336s Setting up libboost-iostreams1.83.0:arm64 (1.83.0-3ubuntu1) ... 2336s Setting up lsscsi (0.32-1build1) ... 2336s Setting up libdaxctl1:arm64 (77-2ubuntu2) ... 2336s Setting up libndctl6:arm64 (77-2ubuntu2) ... 2336s Setting up librdmacm1t64:arm64 (52.0-2) ... 2336s Setting up tgt (1:1.0.85-1.2ubuntu1) ... 2339s Created symlink '/etc/systemd/system/multi-user.target.wants/tgt.service' → '/usr/lib/systemd/system/tgt.service'. 2341s Setting up libpmem1:arm64 (1.13.1-1.1ubuntu2) ... 2341s Setting up libgfxdr0:arm64 (11.1-4ubuntu1) ... 2341s Setting up librados2 (19.2.0~git20240301.4c76c50-0ubuntu7) ... 2341s Setting up open-iscsi (2.1.10-1ubuntu1) ... 2342s Created symlink '/etc/systemd/system/sockets.target.wants/iscsid.socket' → '/usr/lib/systemd/system/iscsid.socket'. 2344s Created symlink '/etc/systemd/system/iscsi.service' → '/usr/lib/systemd/system/open-iscsi.service'. 2344s Created symlink '/etc/systemd/system/sysinit.target.wants/open-iscsi.service' → '/usr/lib/systemd/system/open-iscsi.service'. 2344s Setting up libpmemobj1:arm64 (1.13.1-1.1ubuntu2) ... 2344s Setting up librbd1 (19.2.0~git20240301.4c76c50-0ubuntu7) ... 2344s Setting up libgfrpc0:arm64 (11.1-4ubuntu1) ... 2344s Setting up libgfapi0:arm64 (11.1-4ubuntu1) ... 2344s Setting up fio (3.37-1) ... 2345s Setting up autopkgtest-satdep (0) ... 2345s Processing triggers for man-db (2.12.1-2) ... 2346s Processing triggers for initramfs-tools (0.142ubuntu30) ... 2347s update-initramfs: Generating /boot/initrd.img-6.10.0-15-generic 2347s W: No lz4 in /usr/bin:/sbin:/bin, using gzip 2465s System running in EFI mode, skipping. 2465s Processing triggers for libc-bin (2.39-0ubuntu9) ... 2475s (Reading database ... 121493 files and directories currently installed.) 2475s Removing autopkgtest-satdep (0) ... 2478s autopkgtest [18:51:20]: test tgtbasedmpaths: [----------------------- 2479s + targetname=iqn.2016-11.foo.com:target.iscsi 2479s + pwd 2479s + cwd=/tmp/autopkgtest.gRUmZi/build.KHj/src 2479s + testdir=/mnt/tgtmpathtest 2479s + localhost=127.0.0.1 2479s + portal=127.0.0.1:3260 2479s + maxpaths=4 2479s + backfn=backingfile 2479s + expectwwid=60000000000000000e00000000010001 2479s + testdisk=/dev/disk/by-id/wwn-0x60000000000000000e00000000010001 2479s + bglog=/tmp/autopkgtest.gRUmZi/tgtbasedmpaths-artifacts/test-background.log 2479s + fioprep=/tmp/autopkgtest.gRUmZi/tgtbasedmpaths-artifacts/path-change-prep.fio 2479s + fiovrfy=/tmp/autopkgtest.gRUmZi/tgtbasedmpaths-artifacts/path-change-check.fio 2479s + service tgt restart 2481s + truncate --size 100M backingfile 2481s + tgtadm --lld iscsi --op new --mode target --tid 1 -T iqn.2016-11.foo.com:target.iscsi 2481s + tgtadm --lld iscsi --op bind --mode target --tid 1 -I ALL 2481s + tgtadm --lld iscsi --op new --mode logicalunit --tid 1 --lun 1 -b /tmp/autopkgtest.gRUmZi/build.KHj/src/backingfile 2481s + iscsiadm --mode discovery --type sendtargets --portal 127.0.0.1 2482s 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi 2482s login #1 2482s + echo login #1 2482s + iscsiadm --mode node --targetname iqn.2016-11.foo.com:target.iscsi --portal 127.0.0.1:3260 --login 2482s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 2482s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 2482s + seq 2 4 2483s + echo extra login #2 2483s + iscsiadm --mode session -r 1 --op new 2483s extra login #2 2483s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 2483s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 2483s extra login #3 2483s + echo extra login #3 2483s + iscsiadm --mode session -r 1 --op new 2483s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 2483s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 2483s + echo extra login #4 2483s + iscsiadm --mode session -r 1 --op new 2483s extra login #4 2483s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 2483s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 2483s + udevadm settle 2484s + sleep 5 2490s Status after initial setup 2490s + echo Status after initial setup 2490s + tgtadm --lld iscsi --mode target --op show 2490s Target 1: iqn.2016-11.foo.com:target.iscsi 2490s System information: 2490s Driver: iscsi 2490s State: ready 2490s I_T nexus information: 2490s I_T nexus: 1 2490s Initiator: iqn.2004-10.com.ubuntu:01:6752459399a2 alias: autopkgtest 2490s Connection: 0 2490s IP Address: 127.0.0.1 2490s I_T nexus: 2 2490s Initiator: iqn.2004-10.com.ubuntu:01:6752459399a2 alias: autopkgtest 2490s Connection: 0 2490s IP Address: 127.0.0.1 2490s I_T nexus: 3 2490s Initiator: iqn.2004-10.com.ubuntu:01:6752459399a2 alias: autopkgtest 2490s Connection: 0 2490s IP Address: 127.0.0.1 2490s I_T nexus: 4 2490s Initiator: iqn.2004-10.com.ubuntu:01:6752459399a2 alias: autopkgtest 2490s Connection: 0 2490s IP Address: 127.0.0.1 2490s LUN information: 2490s LUN: 0 2490s Type: controller 2490s SCSI ID: IET 00010000 2490s SCSI SN: beaf10 2490s Size: 0 MB, Block size: 1 2490s Online: Yes 2490s Removable media: No 2490s Prevent removal: No 2490s Readonly: No 2490s SWP: No 2490s Thin-provisioning: No 2490s Backing store type: null 2490s Backing store path: None 2490s Backing store flags: 2490s LUN: 1 2490s Type: disk 2490s SCSI ID: IET 00010001 2490s SCSI SN: beaf11 2490s Size: 105 MB, Block size: 512 2490s Online: Yes 2490s Removable media: No 2490s Prevent removal: No 2490s Readonly: No 2490s SWP: No 2490s Thin-provisioning: No 2490s Backing store type: rdwr 2490s Backing store path: /tmp/autopkgtest.gRUmZi/build.KHj/src/backingfile 2490s Backing store flags: 2490s Account information: 2490s ACL information: 2490s ALL 2490s + tgtadm --lld iscsi --op show --mode conn --tid 1 2490s Session: 4 2490s Connection: 0 2490s Initiator: iqn.2004-10.com.ubuntu:01:6752459399a2 2490s IP Address: 127.0.0.1 2490s Session: 3 2490s Connection: 0 2490s Initiator: iqn.2004-10.com.ubuntu:01:6752459399a2 2490s IP Address: 127.0.0.1 2490s Session: 2 2490s Connection: 0 2490s Initiator: iqn.2004-10.com.ubuntu:01:6752459399a2 2490s IP Address: 127.0.0.1 2490s Session: 1 2490s Connection: 0 2490s Initiator: iqn.2004-10.com.ubuntu:01:6752459399a2 2490s IP Address: 127.0.0.1 2490s + iscsiadm --mode session -P 1 2490s Target: iqn.2016-11.foo.com:target.iscsi (non-flash) 2490s Current Portal: 127.0.0.1:3260,1 2490s Persistent Portal: 127.0.0.1:3260,1 2490s ********** 2490s Interface: 2490s ********** 2490s Iface Name: default 2490s Iface Transport: tcp 2490s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:6752459399a2 2490s Iface IPaddress: 127.0.0.1 2490s Iface HWaddress: default 2490s Iface Netdev: default 2490s SID: 1 2490s iSCSI Connection State: LOGGED IN 2490s iSCSI Session State: LOGGED_IN 2490s Internal iscsid Session State: NO CHANGE 2490s 2490s ********** 2490s Interface: 2490s ********** 2490s Iface Name: default 2490s Iface Transport: tcp 2490s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:6752459399a2 2490s Iface IPaddress: 127.0.0.1 2490s Iface HWaddress: default 2490s Iface Netdev: default 2490s SID: 2 2490s iSCSI Connection State: LOGGED IN 2490s iSCSI Session State: LOGGED_IN 2490s Internal iscsid Session State: NO CHANGE 2490s 2490s ********** 2490s Interface: 2490s ********** 2490s Iface Name: default 2490s Iface Transport: tcp 2490s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:6752459399a2 2490s Iface IPaddress: 127.0.0.1 2490s Iface HWaddress: default 2490s Iface Netdev: default 2490s SID: 3 2490s iSCSI Connection State: LOGGED IN 2490s iSCSI Session State: LOGGED_IN 2490s Internal iscsid Session State: NO CHANGE 2490s 2490s ********** 2490s Interface: 2490s ********** 2490s Iface Name: default 2490s Iface Transport: tcp 2490s Iface Initiatorname: iqn.2004-10.com.ubuntu:01:6752459399a2 2490s Iface IPaddress: 127.0.0.1 2490s Iface HWaddress: default 2490s Iface Netdev: default 2490s SID: 4 2490s iSCSI Connection State: LOGGED IN 2490s iSCSI Session State: LOGGED_IN 2490s Internal iscsid Session State: NO CHANGE 2490s + lsscsi -liv 2490s [0:0:0:0] storage IET Controller 0001 - - 2490s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 2490s dir: /sys/bus/scsi/devices/0:0:0:0 [/sys/devices/platform/host0/session1/target0:0:0/0:0:0:0] 2490s [0:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sda 360000000000000000e00000000010001 2490s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 2490s dir: /sys/bus/scsi/devices/0:0:0:1 [/sys/devices/platform/host0/session1/target0:0:0/0:0:0:1] 2490s [1:0:0:0] storage IET Controller 0001 - - 2490s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 2490s dir: /sys/bus/scsi/devices/1:0:0:0 [/sys/devices/platform/host1/session2/target1:0:0/1:0:0:0] 2490s [1:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdb 360000000000000000e00000000010001 2490s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 2490s dir: /sys/bus/scsi/devices/1:0:0:1 [/sys/devices/platform/host1/session2/target1:0:0/1:0:0:1] 2490s [2:0:0:0] storage IET Controller 0001 - - 2490s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 2490s dir: /sys/bus/scsi/devices/2:0:0:0 [/sys/devices/platform/host2/session3/target2:0:0/2:0:0:0] 2490s [2:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdc 360000000000000000e00000000010001 2490s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 2490s dir: /sys/bus/scsi/devices/2:0:0:1 [/sys/devices/platform/host2/session3/target2:0:0/2:0:0:1] 2490s [3:0:0:0] storage IET Controller 0001 - - 2490s state=running queue_depth=32 scsi_level=6 type=12 device_blocked=0 timeout=30 2490s dir: /sys/bus/scsi/devices/3:0:0:0 [/sys/devices/platform/host3/session4/target3:0:0/3:0:0:0] 2490s [3:0:0:1] disk IET VIRTUAL-DISK 0001 /dev/sdd 33000000100000001 2490s state=running queue_depth=32 scsi_level=6 type=0 device_blocked=0 timeout=30 2490s dir: /sys/bus/scsi/devices/3:0:0:1 [/sys/devices/platform/host3/session4/target3:0:0/3:0:0:1] 2490s NVMe module may not be loaded 2490s list_ndevices: scandir: /sys/class/nvme/: No such file or directory 2490s + multipath -v3 -ll 2490s 257.452729 | set open fds limit to 1073741816/1073741816 2490s 257.452814 | loading /lib/multipath/libchecktur.so checker 2490s 257.453286 | checker tur: message table size = 3 2490s 257.453313 | loading /lib/multipath/libprioconst.so prioritizer 2490s 257.453770 | _init_foreign: foreign library "nvme" is not enabled 2490s 257.457407 | vda: device node name blacklisted 2490s 257.457681 | sda: size = 204800 2490s 257.457811 | sda: vendor = IET 2490s 257.457831 | sda: product = VIRTUAL-DISK 2490s 257.457843 | sda: rev = 0001 2490s 257.458419 | sda: h:b:t:l = 0:0:0:1 2490s 257.458652 | sda: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 2490s 257.458663 | sda: uid_attribute = ID_SERIAL (setting: multipath internal) 2490s 257.458665 | sda: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 2490s 257.458845 | sda: 1024 cyl, 4 heads, 50 sectors/track, start at 0 2490s 257.458856 | sda: vpd_vendor_id = 0 "undef" (setting: multipath internal) 2490s 257.458869 | sda: serial = beaf11 2490s 257.458871 | sda: detect_checker = yes (setting: multipath internal) 2490s 257.459106 | sda: path_checker = tur (setting: multipath internal) 2490s 257.459123 | sda: checker timeout = 30 s (setting: kernel sysfs) 2490s 257.459220 | sda: tur state = up 2490s 257.459340 | sdb: size = 204800 2490s 257.459428 | sdb: vendor = IET 2490s 257.459443 | sdb: product = VIRTUAL-DISK 2490s 257.459458 | sdb: rev = 0001 2490s 257.460045 | sdb: h:b:t:l = 1:0:0:1 2490s 257.460279 | sdb: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 2490s 257.460289 | sdb: uid_attribute = ID_SERIAL (setting: multipath internal) 2490s 257.460291 | sdb: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 2490s 257.460428 | sdb: 1024 cyl, 4 heads, 50 sectors/track, start at 0 2490s 257.460437 | sdb: vpd_vendor_id = 0 "undef" (setting: multipath internal) 2490s 257.460449 | sdb: serial = beaf11 2490s 257.460452 | sdb: detect_checker = yes (setting: multipath internal) 2490s 257.460587 | sdb: path_checker = tur (setting: multipath internal) 2490s 257.460599 | sdb: checker timeout = 30 s (setting: kernel sysfs) 2490s 257.460716 | sdb: tur state = up 2490s 257.460827 | sdc: size = 204800 2490s 257.460913 | sdc: vendor = IET 2490s 257.460926 | sdc: product = VIRTUAL-DISK 2490s 257.460940 | sdc: rev = 0001 2490s 257.461508 | sdc: h:b:t:l = 2:0:0:1 2490s 257.461780 | sdc: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 2490s 257.461791 | sdc: uid_attribute = ID_SERIAL (setting: multipath internal) 2490s 257.461793 | sdc: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 2490s 257.461925 | sdc: 1024 cyl, 4 heads, 50 sectors/track, start at 0 2490s 257.461934 | sdc: vpd_vendor_id = 0 "undef" (setting: multipath internal) 2490s 257.461945 | sdc: serial = beaf11 2490s 257.461947 | sdc: detect_checker = yes (setting: multipath internal) 2490s 257.462086 | sdc: path_checker = tur (setting: multipath internal) 2490s 257.462102 | sdc: checker timeout = 30 s (setting: kernel sysfs) 2490s 257.462168 | sdc: tur state = up 2490s 257.462278 | sdd: size = 204800 2490s 257.462367 | sdd: vendor = IET 2490s 257.462382 | sdd: product = VIRTUAL-DISK 2490s 257.462393 | sdd: rev = 0001 2490s 257.462900 | sdd: h:b:t:l = 3:0:0:1 2490s 257.463141 | sdd: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 2490s 257.463156 | sdd: uid_attribute = ID_SERIAL (setting: multipath internal) 2490s 257.463157 | sdd: recheck_wwid = 1 (setting: multipath.conf defaults/devices section) 2490s 257.463286 | sdd: 1024 cyl, 4 heads, 50 sectors/track, start at 0 2490s 257.463292 | sdd: vpd_vendor_id = 0 "undef" (setting: multipath internal) 2490s 257.463302 | sdd: serial = beaf11 2490s 257.463305 | sdd: detect_checker = yes (setting: multipath internal) 2490s 257.463443 | sdd: path_checker = tur (setting: multipath internal) 2490s 257.463451 | sdd: checker timeout = 30 s (setting: kernel sysfs) 2490s 257.463512 | sdd: tur state = up 2490s 257.463591 | loop0: device node name blacklisted 2490s 257.463649 | loop1: device node name blacklisted 2490s 257.463700 | loop2: device node name blacklisted 2490s 257.463750 | loop3: device node name blacklisted 2490s 257.463801 | loop4: device node name blacklisted 2490s 257.463851 | loop5: device node name blacklisted 2490s 257.463900 | loop6: device node name blacklisted 2490s 257.463950 | loop7: device node name blacklisted 2490s 257.464022 | dm-0: device node name blacklisted 2490s 257.464677 | multipath-tools v0.9.4 (12/19, 2022) 2490s 257.464702 | libdevmapper version 1.02.185 2490s 257.464973 | kernel device mapper v4.48.0 2490s 257.464992 | DM multipath kernel driver v1.14.0 2490s 257.465131 | sda: size = 204800 2490s 257.465150 | sda: vendor = IET 2490s 257.465152 | sda: product = VIRTUAL-DISK 2490s 257.465155 | sda: rev = 0001 2490s 257.465670 | sda: h:b:t:l = 0:0:0:1 2490s 257.465788 | sda: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 2490s 257.465812 | sda: 1024 cyl, 4 heads, 50 sectors/track, start at 0 2490s 257.465814 | sda: vpd_vendor_id = 0 "undef" (setting: multipath internal) 2490s 257.465824 | sda: serial = beaf11 2490s 257.465931 | sda: tur state = up 2490s 257.465940 | sda: uid = 360000000000000000e00000000010001 (udev) 2490s 257.465942 | sda: detect_prio = yes (setting: multipath internal) 2490s 257.465944 | sda: prio = const (setting: multipath internal) 2490s 257.465945 | sda: prio args = "" (setting: multipath internal) 2490s 257.465947 | sda: const prio = 1 2490s 257.465971 | sdb: size = 204800 2490s 257.465979 | sdb: vendor = IET 2490s 257.465981 | sdb: product = VIRTUAL-DISK 2490s 257.465983 | sdb: rev = 0001 2490s 257.466509 | sdb: h:b:t:l = 1:0:0:1 2490s 257.466605 | sdb: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 2490s 257.466626 | sdb: 1024 cyl, 4 heads, 50 sectors/track, start at 0 2490s 257.466632 | sdb: vpd_vendor_id = 0 "undef" (setting: multipath internal) 2490s 257.466645 | sdb: serial = beaf11 2490s 257.466738 | sdb: tur state = up 2490s 257.466746 | sdb: uid = 360000000000000000e00000000010001 (udev) 2490s 257.466748 | sdb: detect_prio = yes (setting: multipath internal) 2490s 257.466750 | sdb: prio = const (setting: multipath internal) 2490s 257.466751 | sdb: prio args = "" (setting: multipath internal) 2490s 257.466752 | sdb: const prio = 1 2490s 257.466777 | sdc: size = 204800 2490s 257.466784 | sdc: vendor = IET 2490s 257.466786 | sdc: product = VIRTUAL-DISK 2490s 257.466788 | sdc: rev = 0001 2490s 257.467301 | sdc: h:b:t:l = 2:0:0:1 2490s 257.467395 | sdc: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 2490s 257.467417 | sdc: 1024 cyl, 4 heads, 50 sectors/track, start at 0 2490s 257.467419 | sdc: vpd_vendor_id = 0 "undef" (setting: multipath internal) 2490s 257.467430 | sdc: serial = beaf11 2490s 257.467516 | sdc: tur state = up 2490s 257.467527 | sdc: uid = 360000000000000000e00000000010001 (udev) 2490s 257.467529 | sdc: detect_prio = yes (setting: multipath internal) 2490s 257.467530 | sdc: prio = const (setting: multipath internal) 2490s 257.467532 | sdc: prio args = "" (setting: multipath internal) 2490s 257.467534 | sdc: const prio = 1 2490s 257.467556 | sdd: size = 204800 2490s 257.467564 | sdd: vendor = IET 2490s 257.467566 | sdd: product = VIRTUAL-DISK 2490s 257.467567 | sdd: rev = 0001 2490s 257.468077 | sdd: h:b:t:l = 3:0:0:1 2490s 257.468172 | sdd: tgt_node_name = iqn.2016-11.foo.com:target.iscsi 2490s 257.468194 | sdd: 1024 cyl, 4 heads, 50 sectors/track, start at 0 2490s 257.468196 | sdd: vpd_vendor_id = 0 "undef" (setting: multipath internal) 2490s 257.468205 | sdd: serial = beaf11 2490s 257.468287 | sdd: tur state = up 2490s 257.468294 | sdd: uid = 360000000000000000e00000000010001 (udev) 2490s 257.468297 | sdd: detect_prio = yes (setting: multipath internal) 2490s 257.468299 | sdd: prio = const (setting: multipath internal) 2490s 257.468300 | sdd: prio args = "" (setting: multipath internal) 2490s 257.468301 | sdd: const prio = 1 2490s 257.469035 | unloading tur checker 2490s 257.469422 | unloading const prioritizer 2490s ===== paths list ===== 2490s uuid hcil dev dev_t pri dm_st chk_st vend/prod/rev dev_st 2490s 0:0:0:1 sda 8:0 -1 undef undef IET,VIRTUAL-DISK unknown 2490s 1:0:0:1 sdb 8:16 -1 undef undef IET,VIRTUAL-DISK unknown 2490s 2:0:0:1 sdc 8:32 -1 undef undef IET,VIRTUAL-DISK unknown 2490s 3:0:0:1 sdd 8:48 -1 undef undef IET,VIRTUAL-DISK unknown 2490s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 2490s size=100M features='0' hwhandler='0' wp=rw 2490s |-+- policy='service-time 0' prio=1 status=active 2490s | `- 0:0:0:1 sda 8:0 active ready running 2490s |-+- policy='service-time 0' prio=1 status=enabled 2490s | `- 1:0:0:1 sdb 8:16 active ready running 2490s |-+- policy='service-time 0' prio=1 status=enabled 2490s | `- 2:0:0:1 sdc 8:32 active ready running 2490s `-+- policy='service-time 0' prio=1 status=enabled 2490s `- 3:0:0:1 sdd 8:48 active ready running 2490s 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 2490s Test WWN should now point to DM 2490s ../../dm-0 2490s + dmsetup table 2490s + echo Test WWN should now point to DM 2490s + readlink /dev/disk/by-id/wwn-0x60000000000000000e00000000010001 2490s + grep dm 2490s + mkfs.ext4 -F /dev/disk/by-id/wwn-0x60000000000000000e00000000010001 2490s mke2fs 1.47.1 (20-May-2024) 2490s Creating filesystem with 25600 4k blocks and 25600 inodes 2490s 2490s Allocating group tables: 0/1 done 2490s Writing inode tables: 0/1 done 2490s Creating journal (1024 blocks): done 2490s Writing superblocks and filesystem accounting information: 0/1 done 2490s 2490s + udevadm settle 2490s + sleep 3s 2493s + mkdir -p /mnt/tgtmpathtest 2494s + mount /dev/disk/by-id/wwn-0x60000000000000000e00000000010001 /mnt/tgtmpathtest 2494s + cat 2494s + cat 2494s + fio --max-jobs=4 /tmp/autopkgtest.gRUmZi/tgtbasedmpaths-artifacts/path-change-prep.fio 2498s 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 2498s fio-3.37 2498s Starting 1 thread 2498s write-phase: Laying out IO file (1 file / 17592186044415MiB) 2498s fio: io_u error on file /mnt/tgtmpathtest/datafile.tmp: No space left on device: write offset=91750400, buflen=65536 2498s 2498s write-phase: (groupid=0, jobs=1): err= 0: pid=7256: Fri Jul 19 18:51:40 2024 2498s write: IOPS=3528, BW=220MiB/s (231MB/s)(87.5MiB/397msec); 0 zone resets 2498s clat (usec): min=205, max=1017, avg=277.94, stdev=45.01 2498s lat (usec): min=207, max=1020, avg=281.69, stdev=45.17 2498s clat percentiles (usec): 2498s | 1.00th=[ 221], 5.00th=[ 237], 10.00th=[ 247], 20.00th=[ 253], 2498s | 30.00th=[ 262], 40.00th=[ 265], 50.00th=[ 273], 60.00th=[ 277], 2498s | 70.00th=[ 285], 80.00th=[ 293], 90.00th=[ 310], 95.00th=[ 326], 2498s | 99.00th=[ 424], 99.50th=[ 498], 99.90th=[ 824], 99.95th=[ 1020], 2498s | 99.99th=[ 1020] 2498s lat (usec) : 250=15.42%, 500=84.01%, 750=0.36%, 1000=0.07% 2498s lat (msec) : 2=0.07% 2498s cpu : usr=2.78%, sys=7.58%, ctx=1401, majf=0, minf=0 2498s IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0% 2498s submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 2498s complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 2498s issued rwts: total=0,1401,0,0 short=0,0,0,0 dropped=0,0,0,0 2498s latency : target=0, window=0, percentile=100.00%, depth=1 2498s 2498s Run status group 0 (all jobs): 2498s WRITE: bw=220MiB/s (231MB/s), 220MiB/s-220MiB/s (231MB/s-231MB/s), io=87.5MiB (91.8MB), run=397-397msec 2498s 2498s Disk stats (read/write): 2498s dm-0: ios=0/1393, sectors=0/178176, merge=0/0, ticks=0/362, in_queue=362, util=74.34%, aggrios=0/350, aggsectors=0/44820, aggrmerge=0/0, aggrticks=0/90, aggrin_queue=90, aggrutil=67.84% 2498s sdd: ios=0/0, sectors=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 2498s sdb: ios=0/0, sectors=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 2498s sdc: ios=0/0, sectors=0/0, merge=0/0, ticks=0/0, in_queue=0, util=0.00% 2498s sda: ios=0/1402, sectors=0/179280, merge=0/0, ticks=0/360, in_queue=360, util=67.84% 2499s Starting the path changes in background 2499s + echo Starting the path changes in background 2499s + date +Pre FIO %H:%M:%S.%N 2499s Pre FIO 18:51:40.989316391 2499s + fio --max-jobs=4 /tmp/autopkgtest.gRUmZi/tgtbasedmpaths-artifacts/path-change-check.fio 2499s 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 2499s fio-3.37 2499s Starting 1 thread 2679s 2679s verify-phase: (groupid=0, jobs=1): err= 0: pid=7267: Fri Jul 19 18:54:41 2024 2679s read: IOPS=5678, BW=355MiB/s (372MB/s)(62.4GiB/180001msec) 2679s clat (usec): min=81, max=640174, avg=167.07, stdev=1529.15 2679s lat (usec): min=81, max=640174, avg=167.25, stdev=1529.15 2679s clat percentiles (usec): 2679s | 1.00th=[ 108], 5.00th=[ 116], 10.00th=[ 122], 20.00th=[ 131], 2679s | 30.00th=[ 139], 40.00th=[ 145], 50.00th=[ 149], 60.00th=[ 153], 2679s | 70.00th=[ 161], 80.00th=[ 169], 90.00th=[ 188], 95.00th=[ 223], 2679s | 99.00th=[ 330], 99.50th=[ 359], 99.90th=[ 889], 99.95th=[ 2024], 2679s | 99.99th=[17171] 2679s bw ( KiB/s): min= 615, max=507520, per=100.00%, avg=364593.05, stdev=85964.79, samples=357 2679s iops : min= 9, max= 7930, avg=5696.63, stdev=1343.25, samples=357 2679s lat (usec) : 100=0.11%, 250=96.26%, 500=3.46%, 750=0.05%, 1000=0.03% 2679s lat (msec) : 2=0.04%, 4=0.03%, 10=0.01%, 20=0.01%, 50=0.01% 2679s lat (msec) : 100=0.01%, 250=0.01%, 500=0.01%, 750=0.01% 2679s cpu : usr=5.92%, sys=8.87%, ctx=1022286, majf=0, minf=16 2679s IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0% 2679s submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 2679s complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 2679s issued rwts: total=1022177,0,0,0 short=0,0,0,0 dropped=0,0,0,0 2679s latency : target=0, window=0, percentile=100.00%, depth=1 2679s 2679s Run status group 0 (all jobs): 2679s READ: bw=355MiB/s (372MB/s), 355MiB/s-355MiB/s (372MB/s-372MB/s), io=62.4GiB (67.0GB), run=180001-180001msec 2679s 2679s Disk stats (read/write): 2679s dm-0: ios=1021778/11, sectors=130690272/168, merge=0/10, ticks=164980/96, in_queue=165169, util=90.61%, aggrios=76382/2, aggsectors=9768888/42, aggrmerge=0/0, aggrticks=11146/0, aggrin_queue=11146, aggrutil=84.26% 2679s sdd: ios=119083/7, sectors=15231744/72, merge=0/0, ticks=17552/2, in_queue=17554, util=32.19% 2679s sdb: ios=60016/0, sectors=7672544/0, merge=0/0, ticks=9120/0, in_queue=9121, util=41.45% 2679s sdc: ios=69609/0, sectors=8903552/0, merge=0/0, ticks=8655/0, in_queue=8654, util=26.22% 2679s sda: ios=56820/4, sectors=7267712/96, merge=0/0, ticks=9257/1, in_queue=9258, util=84.26% 2680s + date +Post FIO %H:%M:%S.%N 2680s + echo FIO verify test with changing paths - OK 2680s + echo Report log of background activity 2680s + cat /tmp/autopkgtest.gRUmZi/tgtbasedmpaths-artifacts/test-background.log 2680s Post FIO 18:54:42.233230550 2680s FIO verify test with changing paths - OK 2680s Report log of background activity 2680s + iscsiadm --mode session 2680s tcp: [1] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 2680s tcp: [2] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 2680s tcp: [3] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 2680s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 2680s + sleep 10s 2680s + date +MP report (expect 4) %H:%M:%S.%N 2680s MP report (expect 4) 18:51:51.230988175 2680s + multipath -ll 2680s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 2680s size=100M features='0' hwhandler='0' wp=rw 2680s |-+- policy='service-time 0' prio=1 status=active 2680s | `- 0:0:0:1 sda 8:0 active ready running 2680s |-+- policy='service-time 0' prio=1 status=enabled 2680s | `- 1:0:0:1 sdb 8:16 active ready running 2680s |-+- policy='service-time 0' prio=1 status=enabled 2680s | `- 2:0:0:1 sdc 8:32 active ready running 2680s `-+- policy='service-time 0' prio=1 status=enabled 2680s `- 3:0:0:1 sdd 8:48 active ready running 2680s + date +UN-plug path 1 %H:%M:%S.%N 2680s UN-plug path 1 18:51:51.562795503 2680s + iscsiadm --mode session -r 1 -u 2680s Logging out of session [sid: 1, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 2680s Logout of [sid: 1, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 2680s + iscsiadm --mode session 2680s tcp: [2] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 2680s tcp: [3] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 2680s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 2680s + sleep 10s 2680s + date +MP report (expect 3) %H:%M:%S.%N 2680s MP report (expect 3) 18:52:02.456688646 2680s + multipath -ll 2680s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 2680s size=100M features='0' hwhandler='0' wp=rw 2680s |-+- policy='service-time 0' prio=1 status=active 2680s | `- 1:0:0:1 sdb 8:16 active ready running 2680s |-+- policy='service-time 0' prio=1 status=enabled 2680s | `- 2:0:0:1 sdc 8:32 active ready running 2680s `-+- policy='service-time 0' prio=1 status=enabled 2680s `- 3:0:0:1 sdd 8:48 active ready running 2680s + date +UN-plug path 2 %H:%M:%S.%N 2680s UN-plug path 2 18:52:02.487933121 2680s + iscsiadm --mode session -r 2 -u 2680s Logging out of session [sid: 2, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 2680s Logout of [sid: 2, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 2680s + iscsiadm --mode session 2680s tcp: [3] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 2680s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 2680s + sleep 10s 2680s + date +MP report (expect 2) %H:%M:%S.%N 2680s MP report (expect 2) 18:52:12.547863393 2680s + multipath -ll 2680s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 2680s size=100M features='0' hwhandler='0' wp=rw 2680s |-+- policy='service-time 0' prio=1 status=active 2680s | `- 2:0:0:1 sdc 8:32 active ready running 2680s `-+- policy='service-time 0' prio=1 status=enabled 2680s `- 3:0:0:1 sdd 8:48 active ready running 2680s + date +UN-plug path 3 %H:%M:%S.%N 2680s UN-plug path 3 18:52:12.590296646 2680s + iscsiadm --mode session -r 3 -u 2680s Logging out of session [sid: 3, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 2680s Logout of [sid: 3, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 2680s + iscsiadm --mode session 2680s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 2680s + sleep 10s 2680s + date +MP report (expect 1) %H:%M:%S.%N 2680s MP report (expect 1) 18:52:22.718144787 2680s + multipath -ll 2680s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 2680s size=100M features='0' hwhandler='0' wp=rw 2680s `-+- policy='service-time 0' prio=1 status=active 2680s `- 3:0:0:1 sdd 8:48 active ready running 2680s + date +Add paths 5/6/7/8 %H:%M:%S.%N 2680s Add paths 5/6/7/8 18:52:22.746748097 2680s + iscsiadm --mode session -r 4 --op new 2680s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 2680s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 2680s + iscsiadm --mode session -r 4 --op new 2680s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 2680s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 2680s + iscsiadm --mode session -r 4 --op new 2680s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 2680s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 2680s + iscsiadm --mode session -r 4 --op new 2680s Logging in to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] (multiple) 2680s Login to [iface: default, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 2680s + iscsiadm --mode session 2680s tcp: [4] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 2680s tcp: [5] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 2680s tcp: [6] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 2680s tcp: [7] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 2680s tcp: [8] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 2680s + sleep 10s 2680s + date +MP report (expect 5) %H:%M:%S.%N 2680s MP report (expect 5) 18:52:33.304919822 2680s + multipath -ll 2680s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 2680s size=100M features='0' hwhandler='0' wp=rw 2680s |-+- policy='service-time 0' prio=1 status=active 2680s | `- 3:0:0:1 sdd 8:48 active ready running 2680s |-+- policy='service-time 0' prio=1 status=enabled 2680s | `- 0:0:0:1 sda 8:0 active ready running 2680s |-+- policy='service-time 0' prio=1 status=enabled 2680s | `- 2:0:0:1 sdc 8:32 active ready running 2680s |-+- policy='service-time 0' prio=1 status=enabled 2680s | `- 1:0:0:1 sdb 8:16 active ready running 2680s `-+- policy='service-time 0' prio=1 status=enabled 2680s `- 4:0:0:1 sde 8:64 active ready running 2680s + date +UN-plug multiple paths 4/7/8 %H:%M:%S.%N 2680s UN-plug multiple paths 4/7/8 18:52:33.347043196 2680s + iscsiadm --mode session -r 4 -u 2680s Logging out of session [sid: 4, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 2680s Logout of [sid: 4, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 2680s + iscsiadm --mode session -r 7 -u 2680s Logging out of session [sid: 7, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 2680s Logout of [sid: 7, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 2680s + iscsiadm --mode session -r 8 -u 2680s Logging out of session [sid: 8, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 2680s Logout of [sid: 8, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 2680s + iscsiadm --mode session 2680s tcp: [5] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 2680s tcp: [6] 127.0.0.1:3260,1 iqn.2016-11.foo.com:target.iscsi (non-flash) 2680s + sleep 10s 2680s + date +Restart multipath daemon %H:%M:%S.%N 2680s Restart multipath daemon 18:52:43.614563890 2680s + systemctl restart multipathd 2680s + sleep 10s 2680s + date +Final background report (expect 2) %H:%M:%S.%N 2680s Final background report (expect 2) 18:52:54.177601461 2680s + multipath -ll 2680s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 2680s size=100M features='0' hwhandler='0' wp=rw 2680s |-+- policy='service-time 0' prio=1 status=active 2680s | `- 0:0:0:1 sda 8:0 active ready running 2680s `-+- policy='service-time 0' prio=1 status=enabled 2680s `- 1:0:0:1 sdb 8:16 active ready running 2680s + sync 2680s + umount /dev/disk/by-id/wwn-0x60000000000000000e00000000010001 2680s + echo Final stats 2680s + iscsiadm --mode session --stats 2680s Final stats 2680s Stats for session [sid: 5, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 2680s iSCSI SNMP: 2680s txdata_octets: 34370760 2680s rxdata_octets: 46899992996 2680s noptx_pdus: 0 2680s scsicmd_pdus: 715790 2680s tmfcmd_pdus: 0 2680s login_pdus: 0 2680s text_pdus: 0 2680s dataout_pdus: 0 2680s logout_pdus: 0 2680s snack_pdus: 0 2680s noprx_pdus: 0 2680s scsirsp_pdus: 715790 2680s tmfrsp_pdus: 0 2680s textrsp_pdus: 0 2680s datain_pdus: 715755 2680s logoutrsp_pdus: 0 2680s r2t_pdus: 0 2680s async_pdus: 0 2680s rjt_pdus: 0 2680s digest_err: 0 2680s timeout_err: 0 2680s iSCSI Extended: 2680s tx_sendpage_failures: 0 2680s rx_discontiguous_hdr: 0 2680s eh_abort_cnt: 0 2680s Stats for session [sid: 6, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 2680s iSCSI SNMP: 2680s txdata_octets: 10392 2680s rxdata_octets: 2162036 2680s noptx_pdus: 0 2680s scsicmd_pdus: 187 2680s tmfcmd_pdus: 0 2680s login_pdus: 0 2680s text_pdus: 0 2680s dataout_pdus: 0 2680s logout_pdus: 0 2680s snack_pdus: 0 2680s noprx_pdus: 0 2680s scsirsp_pdus: 187 2680s tmfrsp_pdus: 0 2680s textrsp_pdus: 0 2680s datain_pdus: 164 2680s logoutrsp_pdus: 0 2680s r2t_pdus: 0 2680s async_pdus: 0 2680s rjt_pdus: 0 2680s digest_err: 0 2680s timeout_err: 0 2680s iSCSI Extended: 2680s tx_sendpage_failures: 0 2680s rx_discontiguous_hdr: 0 2680s eh_abort_cnt: 0 2680s + journalctl --no-pager -u multipathd 2680s + echo Check final path status 2680s + multipath -ll 2680s Jul 18 18:15:53 adtubuntu-oracular-arm64-server-20240717-img-adt-prepare multipathd[326]: multipathd: shut down 2680s Jul 18 18:15:53 adtubuntu-oracular-arm64-server-20240717-img-adt-prepare systemd[1]: Stopping multipathd.service - Device-Mapper Multipath Device Controller... 2680s Jul 18 18:15:53 adtubuntu-oracular-arm64-server-20240717-img-adt-prepare systemd[1]: multipathd.service: Deactivated successfully. 2680s Jul 18 18:15:53 adtubuntu-oracular-arm64-server-20240717-img-adt-prepare systemd[1]: Stopped multipathd.service - Device-Mapper Multipath Device Controller. 2680s -- Boot 8a44d8ddd80948c3a2d1f9dd45972eb8 -- 2680s Jul 19 18:31:46 adtubuntu-oracular-arm64-server-20240717-img-adt-prepare systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 2680s Jul 19 18:31:47 adtubuntu-oracular-arm64-server-20240717-img-adt-prepare multipathd[356]: multipathd v0.9.4: start up 2680s Jul 19 18:31:47 adtubuntu-oracular-arm64-server-20240717-img-adt-prepare multipathd[356]: reconfigure: setting up paths and maps 2680s Jul 19 18:31:47 adtubuntu-oracular-arm64-server-20240717-img-adt-prepare systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 2680s Jul 19 18:43:34 autopkgtest multipathd[356]: multipathd: shut down 2680s Jul 19 18:43:34 autopkgtest systemd[1]: Stopping multipathd.service - Device-Mapper Multipath Device Controller... 2680s Jul 19 18:43:34 autopkgtest systemd[1]: multipathd.service: Deactivated successfully. 2680s Jul 19 18:43:34 autopkgtest systemd[1]: Stopped multipathd.service - Device-Mapper Multipath Device Controller. 2680s -- Boot a55db4235e684a77a983d511246a0fc7 -- 2680s Jul 19 18:47:41 autopkgtest systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 2680s Jul 19 18:47:43 autopkgtest multipathd[364]: multipathd v0.9.4: start up 2680s Jul 19 18:47:43 autopkgtest multipathd[364]: reconfigure: setting up paths and maps 2680s Jul 19 18:47:43 autopkgtest systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 2680s Jul 19 18:51:25 autopkgtest multipathd[364]: mpatha: addmap [0 204800 multipath 0 0 2 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:16 1] 2680s Jul 19 18:51:25 autopkgtest multipathd[364]: sdb [8:16]: path added to devmap mpatha 2680s Jul 19 18:51:26 autopkgtest multipathd[364]: mpatha: performing delayed actions 2680s Jul 19 18:51:26 autopkgtest multipathd[364]: mpatha: reload [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] 2680s Jul 19 18:51:27 autopkgtest multipathd[364]: mpatha: sdd - tur checker reports path is up 2680s Jul 19 18:51:27 autopkgtest multipathd[364]: 8:48: reinstated 2680s Jul 19 18:51:27 autopkgtest multipathd[364]: mpatha: remaining active paths: 4 2680s Jul 19 18:51:51 autopkgtest multipathd[364]: sda: mark as failed 2680s Jul 19 18:51:51 autopkgtest multipathd[364]: mpatha: remaining active paths: 3 2680s Jul 19 18:51:52 autopkgtest multipathd[364]: mpatha: reload [0 204800 multipath 0 0 3 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:48 1] 2680s Jul 19 18:51:52 autopkgtest multipathd[364]: check_removed_paths: sda: freeing path in removed state 2680s Jul 19 18:51:52 autopkgtest multipathd[364]: 8:0: path removed from map mpatha 2680s Jul 19 18:52:02 autopkgtest multipathd[364]: sdb: mark as failed 2680s Jul 19 18:52:02 autopkgtest multipathd[364]: mpatha: remaining active paths: 2 2680s Jul 19 18:52:02 autopkgtest multipathd[364]: mpatha: reload [0 204800 multipath 0 0 2 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:48 1] 2680s Jul 19 18:52:02 autopkgtest multipathd[364]: check_removed_paths: sdb: freeing path in removed state 2680s Jul 19 18:52:02 autopkgtest multipathd[364]: 8:16: path removed from map mpatha 2680s Jul 19 18:52:12 autopkgtest multipathd[364]: sdc: mark as failed 2680s Jul 19 18:52:12 autopkgtest multipathd[364]: mpatha: remaining active paths: 1 2680s Jul 19 18:52:12 autopkgtest multipathd[364]: mpatha: reload [0 204800 multipath 0 0 1 1 service-time 0 1 1 8:48 1] 2680s Jul 19 18:52:12 autopkgtest multipathd[364]: check_removed_paths: sdc: freeing path in removed state 2680s Jul 19 18:52:12 autopkgtest multipathd[364]: 8:32: path removed from map mpatha 2680s Jul 19 18:52:23 autopkgtest multipathd[364]: mpatha: reload [0 204800 multipath 0 0 2 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:0 1] 2680s Jul 19 18:52:23 autopkgtest multipathd[364]: sda [8:0]: path added to devmap mpatha 2680s Jul 19 18:52:23 autopkgtest multipathd[364]: mpatha: reload [0 204800 multipath 0 0 3 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:32 1] 2680s Jul 19 18:52:23 autopkgtest multipathd[364]: sdc [8:32]: path added to devmap mpatha 2680s Jul 19 18:52:23 autopkgtest multipathd[364]: mpatha: reload [0 204800 multipath 0 0 4 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:16 1] 2680s Jul 19 18:52:23 autopkgtest multipathd[364]: sdb [8:16]: path added to devmap mpatha 2680s Jul 19 18:52:23 autopkgtest multipathd[364]: mpatha: reload [0 204800 multipath 0 0 5 1 service-time 0 1 1 8:48 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:64 1] 2680s Jul 19 18:52:23 autopkgtest multipathd[364]: sde [8:64]: path added to devmap mpatha 2680s Jul 19 18:52:33 autopkgtest multipathd[364]: sdd: mark as failed 2680s Jul 19 18:52:33 autopkgtest multipathd[364]: mpatha: remaining active paths: 4 2680s Jul 19 18:52:33 autopkgtest multipathd[364]: mpatha: reload [0 204800 multipath 0 0 4 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:32 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:64 1] 2680s Jul 19 18:52:33 autopkgtest multipathd[364]: check_removed_paths: sdd: freeing path in removed state 2680s Jul 19 18:52:33 autopkgtest multipathd[364]: 8:48: path removed from map mpatha 2680s Jul 19 18:52:33 autopkgtest multipathd[364]: mpatha: reload [0 204800 multipath 0 0 3 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:16 1 service-time 0 1 1 8:64 1] 2680s Jul 19 18:52:33 autopkgtest multipathd[364]: check_removed_paths: sdc: freeing path in removed state 2680s Jul 19 18:52:33 autopkgtest multipathd[364]: 8:32: path removed from map mpatha 2680s Jul 19 18:52:33 autopkgtest multipathd[364]: mpatha: reload [0 204800 multipath 0 0 2 1 service-time 0 1 1 8:0 1 service-time 0 1 1 8:16 1] 2680s Jul 19 18:52:33 autopkgtest multipathd[364]: check_removed_paths: sde: freeing path in removed state 2680s Jul 19 18:52:33 autopkgtest multipathd[364]: 8:64: path removed from map mpatha 2680s Jul 19 18:52:43 autopkgtest multipathd[364]: multipathd: shut down 2680s Jul 19 18:52:43 autopkgtest systemd[1]: Stopping multipathd.service - Device-Mapper Multipath Device Controller... 2680s Jul 19 18:52:43 autopkgtest systemd[1]: multipathd.service: Deactivated successfully. 2680s Jul 19 18:52:43 autopkgtest systemd[1]: Stopped multipathd.service - Device-Mapper Multipath Device Controller. 2680s Jul 19 18:52:43 autopkgtest systemd[1]: Starting multipathd.service - Device-Mapper Multipath Device Controller... 2680s Jul 19 18:52:44 autopkgtest multipathd[7652]: multipathd v0.9.4: start up 2680s Jul 19 18:52:44 autopkgtest multipathd[7652]: reconfigure: setting up paths and maps 2680s Jul 19 18:52:44 autopkgtest systemd[1]: Started multipathd.service - Device-Mapper Multipath Device Controller. 2680s Check final path status 2680s mpatha (360000000000000000e00000000010001) dm-0 IET,VIRTUAL-DISK 2680s size=100M features='0' hwhandler='0' wp=rw 2680s |-+- policy='service-time 0' prio=1 status=active 2680s | `- 0:0:0:1 sda 8:0 active ready running 2680s `-+- policy='service-time 0' prio=1 status=enabled 2680s `- 1:0:0:1 sdb 8:16 active ready running 2680s + multipath -ll 2680s + grep --count status= 2680s + diskc=2 2680s + multipath -ll 2680s + grep --count status=active 2680s + diska=1 2680s + multipath -ll 2680s + grep --count status=enabled 2680s OK 2680s + diske=1 2680s + [ 2 -ne 2 -o 1 -ne 1 -o 1 -ne 1 ] 2680s + echo OK 2680s + iscsiadm --mode node --targetname iqn.2016-11.foo.com:target.iscsi --portal 127.0.0.1:3260 --logout 2680s Logging out of session [sid: 5, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 2680s Logging out of session [sid: 6, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] 2680s Logout of [sid: 5, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 2680s Logout of [sid: 6, target: iqn.2016-11.foo.com:target.iscsi, portal: 127.0.0.1,3260] successful. 2680s + tgtadm --lld iscsi --op delete --mode logicalunit --tid 1 --lun 1 2681s autopkgtest [18:54:43]: test tgtbasedmpaths: -----------------------] 2682s autopkgtest [18:54:44]: test tgtbasedmpaths: - - - - - - - - - - results - - - - - - - - - - 2682s tgtbasedmpaths PASS 2682s autopkgtest [18:54:44]: @@@@@@@@@@@@@@@@@@@@ summary 2682s kpartx-file-loopback PASS 2682s tgtbasedmpaths PASS 2708s nova [W] Skipping flock in bos03-arm64 2708s Creating nova instance adt-oracular-arm64-multipath-tools-20240719-181001-juju-7f2275-prod-proposed-migration-environment-2-6816d8f0-d73c-42ef-ab54-0fc2d822d9cb from image adt/ubuntu-oracular-arm64-server-20240718.img (UUID a9c28202-db65-432a-996d-c43c7d6f5c5e)...