Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 1710128

Summary: [RHOS 15] Tempest test failure: test_volume_backed_live_migration
Product: Red Hat OpenStack Reporter: Archit Modi <amodi>
Component: openstack-novaAssignee: Artom Lifshitz <alifshit>
Status: CLOSED DUPLICATE QA Contact: OSP DFG:Compute <osp-dfg-compute>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 15.0 (Stein)CC: dasmith, eglynn, jhakimra, kchamart, lyarwood, mbooth, sbauza, sgordon, vromanso
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2019-06-07 14:25:13 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
tempest-run.log none

Description Archit Modi 2019-05-14 23:25:19 UTC
Created attachment 1568722 [details]
tempest-run.log

Description of problem: Deploy RHOS 15 with Nova NFS as a storage backend, 1 controller, 2 compute and 3 ceph and run the following tempest tests which fails:

tempest.api.compute.admin.test_live_migration.LiveAutoBlockMigrationV225Test.test_volume_backed_live_migration
tempest.api.compute.admin.test_live_migration.LiveMigrationTest.test_volume_backed_live_migration

core_puddle: RHOS_TRUNK-15.0-RHEL-8-20190509.n.1

How reproducible: always

Topology: 1 controller, 2 compute, 3 ceph, Nova NFS storage backend

Steps to Reproduce:
1. Deploy RHOS 15 with the mentioned topology
2. Run the following tempest tests
tempest.api.compute.admin.test_live_migration.LiveAutoBlockMigrationV225Test.test_volume_backed_live_migration
tempest.api.compute.admin.test_live_migration.LiveMigrationTest.test_volume_backed_live_migration

Actual results:
Response - Headers: {'date': 'Tue, 14 May 2019 21:22:50 GMT', 'server': 'Apache', 'content-length': '1537', 'openstack-api-version': 'compute 2.25', 'x-openstack-nova-api-version': '2.25', 'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version,Accept-Encoding', 'x-openstack-request-id': 'req-5e1ae81a-b246-4b94-9cd9-3eaf06be2fc7', 'x-compute-request-id': 'req-5e1ae81a-b246-4b94-9cd9-3eaf06be2fc7', 'connection': 'close', 'content-type': 'application/json', 'status': '200', 'content-location': 'http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665'}
        Body: b'{"server": {"id": "190a9d1f-5425-4672-b95a-4476334cc665", "name": "tempest-LiveAutoBlockMigrationV225Test-server-1086666822", "status": "MIGRATING", "tenant_id": "a442cb02c0ea44b69eec2fd782491a03", "user_id": "e352a8e1ec8146029fc44af42c10741d", "metadata": {}, "hostId": "0034a5f3c349315c8c878f6eef8d345888b5071fe5becc2d7b80c087", "image": "", "flavor": {"id": "8319d5ab-0f88-4ecf-805c-24863727f8ad", "links": [{"rel": "bookmark", "href": "http://10.0.0.132:8774/flavors/8319d5ab-0f88-4ecf-805c-24863727f8ad"}]}, "created": "2019-05-14T21:17:29Z", "updated": "2019-05-14T21:18:01Z", "addresses": {"tempest-LiveAutoBlockMigrationV225Test-818925055-network": [{"version": 4, "addr": "10.100.0.14", "OS-EXT-IPS:type": "fixed", "OS-EXT-IPS-MAC:mac_addr": "fa:16:3e:8a:18:c3"}]}, "accessIPv4": "", "accessIPv6": "", "links": [{"rel": "self", "href": "http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665"}, {"rel": "bookmark", "href": "http://10.0.0.132:8774/servers/190a9d1f-5425-4672-b95a-4476334cc665"}], "OS-DCF:diskConfig": "MANUAL", "progress": 0, "OS-EXT-AZ:availability_zone": "nova", "config_drive": "", "key_name": null, "OS-SRV-USG:launched_at": "2019-05-14T21:17:55.000000", "OS-SRV-USG:terminated_at": null, "security_groups": [{"name": "default"}], "OS-EXT-STS:task_state": "migrating", "OS-EXT-STS:vm_state": "active", "OS-EXT-STS:power_state": 1, "os-extended-volumes:volumes_attached": [{"id": "975f122c-4110-4378-8950-d8c338e2da30", "delete_on_termination": true}], "locked": false, "description": null}}'
2019-05-14 21:22:52,501 263134 INFO     [tempest.lib.common.rest_client] Request (LiveAutoBlockMigrationV225Test:test_volume_backed_live_migration): 200 GET http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665 0.359s
2019-05-14 21:22:52,501 263134 DEBUG    [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-OpenStack-Nova-API-Version': '2.25', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {'date': 'Tue, 14 May 2019 21:22:52 GMT', 'server': 'Apache', 'content-length': '1537', 'openstack-api-version': 'compute 2.25', 'x-openstack-nova-api-version': '2.25', 'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version,Accept-Encoding', 'x-openstack-request-id': 'req-f8a0b6c8-b135-45f3-a682-056f813e0261', 'x-compute-request-id': 'req-f8a0b6c8-b135-45f3-a682-056f813e0261', 'connection': 'close', 'content-type': 'application/json', 'status': '200', 'content-location': 'http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665'}
        Body: b'{"server": {"id": "190a9d1f-5425-4672-b95a-4476334cc665", "name": "tempest-LiveAutoBlockMigrationV225Test-server-1086666822", "status": "MIGRATING", "tenant_id": "a442cb02c0ea44b69eec2fd782491a03", "user_id": "e352a8e1ec8146029fc44af42c10741d", "metadata": {}, "hostId": "0034a5f3c349315c8c878f6eef8d345888b5071fe5becc2d7b80c087", "image": "", "flavor": {"id": "8319d5ab-0f88-4ecf-805c-24863727f8ad", "links": [{"rel": "bookmark", "href": "http://10.0.0.132:8774/flavors/8319d5ab-0f88-4ecf-805c-24863727f8ad"}]}, "created": "2019-05-14T21:17:29Z", "updated": "2019-05-14T21:18:01Z", "addresses": {"tempest-LiveAutoBlockMigrationV225Test-818925055-network": [{"version": 4, "addr": "10.100.0.14", "OS-EXT-IPS:type": "fixed", "OS-EXT-IPS-MAC:mac_addr": "fa:16:3e:8a:18:c3"}]}, "accessIPv4": "", "accessIPv6": "", "links": [{"rel": "self", "href": "http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665"}, {"rel": "bookmark", "href": "http://10.0.0.132:8774/servers/190a9d1f-5425-4672-b95a-4476334cc665"}], "OS-DCF:diskConfig": "MANUAL", "progress": 0, "OS-EXT-AZ:availability_zone": "nova", "config_drive": "", "key_name": null, "OS-SRV-USG:launched_at": "2019-05-14T21:17:55.000000", "OS-SRV-USG:terminated_at": null, "security_groups": [{"name": "default"}], "OS-EXT-STS:task_state": "migrating", "OS-EXT-STS:vm_state": "active", "OS-EXT-STS:power_state": 1, "os-extended-volumes:volumes_attached": [{"id": "975f122c-4110-4378-8950-d8c338e2da30", "delete_on_termination": true}], "locked": false, "description": null}}'
2019-05-14 21:22:53,858 263134 INFO     [tempest.lib.common.rest_client] Request (LiveAutoBlockMigrationV225Test:test_volume_backed_live_migration): 200 GET http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665 0.349s
2019-05-14 21:22:53,858 263134 DEBUG    [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-OpenStack-Nova-API-Version': '2.25', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {'date': 'Tue, 14 May 2019 21:22:53 GMT', 'server': 'Apache', 'content-length': '1537', 'openstack-api-version': 'compute 2.25', 'x-openstack-nova-api-version': '2.25', 'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version,Accept-Encoding', 'x-openstack-request-id': 'req-aadcc1ad-057d-4bdd-a1b0-9797ced44c1d', 'x-compute-request-id': 'req-aadcc1ad-057d-4bdd-a1b0-9797ced44c1d', 'connection': 'close', 'content-type': 'application/json', 'status': '200', 'content-location': 'http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665'}
        Body: b'{"server": {"id": "190a9d1f-5425-4672-b95a-4476334cc665", "name": "tempest-LiveAutoBlockMigrationV225Test-server-1086666822", "status": "MIGRATING", "tenant_id": "a442cb02c0ea44b69eec2fd782491a03", "user_id": "e352a8e1ec8146029fc44af42c10741d", "metadata": {}, "hostId": "0034a5f3c349315c8c878f6eef8d345888b5071fe5becc2d7b80c087", "image": "", "flavor": {"id": "8319d5ab-0f88-4ecf-805c-24863727f8ad", "links": [{"rel": "bookmark", "href": "http://10.0.0.132:8774/flavors/8319d5ab-0f88-4ecf-805c-24863727f8ad"}]}, "created": "2019-05-14T21:17:29Z", "updated": "2019-05-14T21:18:01Z", "addresses": {"tempest-LiveAutoBlockMigrationV225Test-818925055-network": [{"version": 4, "addr": "10.100.0.14", "OS-EXT-IPS:type": "fixed", "OS-EXT-IPS-MAC:mac_addr": "fa:16:3e:8a:18:c3"}]}, "accessIPv4": "", "accessIPv6": "", "links": [{"rel": "self", "href": "http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665"}, {"rel": "bookmark", "href": "http://10.0.0.132:8774/servers/190a9d1f-5425-4672-b95a-4476334cc665"}], "OS-DCF:diskConfig": "MANUAL", "progress": 0, "OS-EXT-AZ:availability_zone": "nova", "config_drive": "", "key_name": null, "OS-SRV-USG:launched_at": "2019-05-14T21:17:55.000000", "OS-SRV-USG:terminated_at": null, "security_groups": [{"name": "default"}], "OS-EXT-STS:task_state": "migrating", "OS-EXT-STS:vm_state": "active", "OS-EXT-STS:power_state": 1, "os-extended-volumes:volumes_attached": [{"id": "975f122c-4110-4378-8950-d8c338e2da30", "delete_on_termination": true}], "locked": false, "description": null}}'
2019-05-14 21:22:55,229 263134 INFO     [tempest.lib.common.rest_client] Request (LiveAutoBlockMigrationV225Test:test_volume_backed_live_migration): 200 GET http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665 0.363s
2019-05-14 21:22:55,230 263134 DEBUG    [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-OpenStack-Nova-API-Version': '2.25', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {'date': 'Tue, 14 May 2019 21:22:54 GMT', 'server': 'Apache', 'content-length': '1537', 'openstack-api-version': 'compute 2.25', 'x-openstack-nova-api-version': '2.25', 'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version,Accept-Encoding', 'x-openstack-request-id': 'req-32b8c2a4-c484-40c2-a251-92503055af6d', 'x-compute-request-id': 'req-32b8c2a4-c484-40c2-a251-92503055af6d', 'connection': 'close', 'content-type': 'application/json', 'status': '200', 'content-location': 'http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665'}
        Body: b'{"server": {"id": "190a9d1f-5425-4672-b95a-4476334cc665", "name": "tempest-LiveAutoBlockMigrationV225Test-server-1086666822", "status": "MIGRATING", "tenant_id": "a442cb02c0ea44b69eec2fd782491a03", "user_id": "e352a8e1ec8146029fc44af42c10741d", "metadata": {}, "hostId": "0034a5f3c349315c8c878f6eef8d345888b5071fe5becc2d7b80c087", "image": "", "flavor": {"id": "8319d5ab-0f88-4ecf-805c-24863727f8ad", "links": [{"rel": "bookmark", "href": "http://10.0.0.132:8774/flavors/8319d5ab-0f88-4ecf-805c-24863727f8ad"}]}, "created": "2019-05-14T21:17:29Z", "updated": "2019-05-14T21:18:01Z", "addresses": {"tempest-LiveAutoBlockMigrationV225Test-818925055-network": [{"version": 4, "addr": "10.100.0.14", "OS-EXT-IPS:type": "fixed", "OS-EXT-IPS-MAC:mac_addr": "fa:16:3e:8a:18:c3"}]}, "accessIPv4": "", "accessIPv6": "", "links": [{"rel": "self", "href": "http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665"}, {"rel": "bookmark", "href": "http://10.0.0.132:8774/servers/190a9d1f-5425-4672-b95a-4476334cc665"}], "OS-DCF:diskConfig": "MANUAL", "progress": 0, "OS-EXT-AZ:availability_zone": "nova", "config_drive": "", "key_name": null, "OS-SRV-USG:launched_at": "2019-05-14T21:17:55.000000", "OS-SRV-USG:terminated_at": null, "security_groups": [{"name": "default"}], "OS-EXT-STS:task_state": "migrating", "OS-EXT-STS:vm_state": "active", "OS-EXT-STS:power_state": 1, "os-extended-volumes:volumes_attached": [{"id": "975f122c-4110-4378-8950-d8c338e2da30", "delete_on_termination": true}], "locked": false, "description": null}}'
2019-05-14 21:22:56,642 263134 INFO     [tempest.lib.common.rest_client] Request (LiveAutoBlockMigrationV225Test:test_volume_backed_live_migration): 200 GET http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665 0.405s
2019-05-14 21:22:56,643 263134 DEBUG    [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-OpenStack-Nova-API-Version': '2.25', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {'date': 'Tue, 14 May 2019 21:22:56 GMT', 'server': 'Apache', 'content-length': '1537', 'openstack-api-version': 'compute 2.25', 'x-openstack-nova-api-version': '2.25', 'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version,Accept-Encoding', 'x-openstack-request-id': 'req-4834c96c-b854-4b74-a990-77329843c8d0', 'x-compute-request-id': 'req-4834c96c-b854-4b74-a990-77329843c8d0', 'connection': 'close', 'content-type': 'application/json', 'status': '200', 'content-location': 'http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665'}
        Body: b'{"server": {"id": "190a9d1f-5425-4672-b95a-4476334cc665", "name": "tempest-LiveAutoBlockMigrationV225Test-server-1086666822", "status": "MIGRATING", "tenant_id": "a442cb02c0ea44b69eec2fd782491a03", "user_id": "e352a8e1ec8146029fc44af42c10741d", "metadata": {}, "hostId": "0034a5f3c349315c8c878f6eef8d345888b5071fe5becc2d7b80c087", "image": "", "flavor": {"id": "8319d5ab-0f88-4ecf-805c-24863727f8ad", "links": [{"rel": "bookmark", "href": "http://10.0.0.132:8774/flavors/8319d5ab-0f88-4ecf-805c-24863727f8ad"}]}, "created": "2019-05-14T21:17:29Z", "updated": "2019-05-14T21:18:01Z", "addresses": {"tempest-LiveAutoBlockMigrationV225Test-818925055-network": [{"version": 4, "addr": "10.100.0.14", "OS-EXT-IPS:type": "fixed", "OS-EXT-IPS-MAC:mac_addr": "fa:16:3e:8a:18:c3"}]}, "accessIPv4": "", "accessIPv6": "", "links": [{"rel": "self", "href": "http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665"}, {"rel": "bookmark", "href": "http://10.0.0.132:8774/servers/190a9d1f-5425-4672-b95a-4476334cc665"}], "OS-DCF:diskConfig": "MANUAL", "progress": 0, "OS-EXT-AZ:availability_zone": "nova", "config_drive": "", "key_name": null, "OS-SRV-USG:launched_at": "2019-05-14T21:17:55.000000", "OS-SRV-USG:terminated_at": null, "security_groups": [{"name": "default"}], "OS-EXT-STS:task_state": "migrating", "OS-EXT-STS:vm_state": "active", "OS-EXT-STS:power_state": 1, "os-extended-volumes:volumes_attached": [{"id": "975f122c-4110-4378-8950-d8c338e2da30", "delete_on_termination": true}], "locked": false, "description": null}}'
2019-05-14 21:22:58,214 263134 INFO     [tempest.lib.common.rest_client] Request (LiveAutoBlockMigrationV225Test:test_volume_backed_live_migration): 200 GET http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665 0.565s
2019-05-14 21:22:58,214 263134 DEBUG    [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-OpenStack-Nova-API-Version': '2.25', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {'date': 'Tue, 14 May 2019 21:22:57 GMT', 'server': 'Apache', 'content-length': '1537', 'openstack-api-version': 'compute 2.25', 'x-openstack-nova-api-version': '2.25', 'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version,Accept-Encoding', 'x-openstack-request-id': 'req-5a828949-996c-42b1-a980-115cfbad8f18', 'x-compute-request-id': 'req-5a828949-996c-42b1-a980-115cfbad8f18', 'connection': 'close', 'content-type': 'application/json', 'status': '200', 'content-location': 'http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665'}
        Body: b'{"server": {"id": "190a9d1f-5425-4672-b95a-4476334cc665", "name": "tempest-LiveAutoBlockMigrationV225Test-server-1086666822", "status": "MIGRATING", "tenant_id": "a442cb02c0ea44b69eec2fd782491a03", "user_id": "e352a8e1ec8146029fc44af42c10741d", "metadata": {}, "hostId": "0034a5f3c349315c8c878f6eef8d345888b5071fe5becc2d7b80c087", "image": "", "flavor": {"id": "8319d5ab-0f88-4ecf-805c-24863727f8ad", "links": [{"rel": "bookmark", "href": "http://10.0.0.132:8774/flavors/8319d5ab-0f88-4ecf-805c-24863727f8ad"}]}, "created": "2019-05-14T21:17:29Z", "updated": "2019-05-14T21:18:01Z", "addresses": {"tempest-LiveAutoBlockMigrationV225Test-818925055-network": [{"version": 4, "addr": "10.100.0.14", "OS-EXT-IPS:type": "fixed", "OS-EXT-IPS-MAC:mac_addr": "fa:16:3e:8a:18:c3"}]}, "accessIPv4": "", "accessIPv6": "", "links": [{"rel": "self", "href": "http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665"}, {"rel": "bookmark", "href": "http://10.0.0.132:8774/servers/190a9d1f-5425-4672-b95a-4476334cc665"}], "OS-DCF:diskConfig": "MANUAL", "progress": 0, "OS-EXT-AZ:availability_zone": "nova", "config_drive": "", "key_name": null, "OS-SRV-USG:launched_at": "2019-05-14T21:17:55.000000", "OS-SRV-USG:terminated_at": null, "security_groups": [{"name": "default"}], "OS-EXT-STS:task_state": "migrating", "OS-EXT-STS:vm_state": "active", "OS-EXT-STS:power_state": 1, "os-extended-volumes:volumes_attached": [{"id": "975f122c-4110-4378-8950-d8c338e2da30", "delete_on_termination": true}], "locked": false, "description": null}}'
2019-05-14 21:22:59,526 263134 INFO     [tempest.lib.common.rest_client] Request (LiveAutoBlockMigrationV225Test:test_volume_backed_live_migration): 200 GET http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665 0.305s
2019-05-14 21:22:59,526 263134 DEBUG    [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-OpenStack-Nova-API-Version': '2.25', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {'date': 'Tue, 14 May 2019 21:22:59 GMT', 'server': 'Apache', 'content-length': '1537', 'openstack-api-version': 'compute 2.25', 'x-openstack-nova-api-version': '2.25', 'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version,Accept-Encoding', 'x-openstack-request-id': 'req-9499237a-ebdc-44dd-9a71-c3a2bce39123', 'x-compute-request-id': 'req-9499237a-ebdc-44dd-9a71-c3a2bce39123', 'connection': 'close', 'content-type': 'application/json', 'status': '200', 'content-location': 'http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665'}
        Body: b'{"server": {"id": "190a9d1f-5425-4672-b95a-4476334cc665", "name": "tempest-LiveAutoBlockMigrationV225Test-server-1086666822", "status": "MIGRATING", "tenant_id": "a442cb02c0ea44b69eec2fd782491a03", "user_id": "e352a8e1ec8146029fc44af42c10741d", "metadata": {}, "hostId": "0034a5f3c349315c8c878f6eef8d345888b5071fe5becc2d7b80c087", "image": "", "flavor": {"id": "8319d5ab-0f88-4ecf-805c-24863727f8ad", "links": [{"rel": "bookmark", "href": "http://10.0.0.132:8774/flavors/8319d5ab-0f88-4ecf-805c-24863727f8ad"}]}, "created": "2019-05-14T21:17:29Z", "updated": "2019-05-14T21:18:01Z", "addresses": {"tempest-LiveAutoBlockMigrationV225Test-818925055-network": [{"version": 4, "addr": "10.100.0.14", "OS-EXT-IPS:type": "fixed", "OS-EXT-IPS-MAC:mac_addr": "fa:16:3e:8a:18:c3"}]}, "accessIPv4": "", "accessIPv6": "", "links": [{"rel": "self", "href": "http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665"}, {"rel": "bookmark", "href": "http://10.0.0.132:8774/servers/190a9d1f-5425-4672-b95a-4476334cc665"}], "OS-DCF:diskConfig": "MANUAL", "progress": 0, "OS-EXT-AZ:availability_zone": "nova", "config_drive": "", "key_name": null, "OS-SRV-USG:launched_at": "2019-05-14T21:17:55.000000", "OS-SRV-USG:terminated_at": null, "security_groups": [{"name": "default"}], "OS-EXT-STS:task_state": "migrating", "OS-EXT-STS:vm_state": "active", "OS-EXT-STS:power_state": 1, "os-extended-volumes:volumes_attached": [{"id": "975f122c-4110-4378-8950-d8c338e2da30", "delete_on_termination": true}], "locked": false, "description": null}}'
2019-05-14 21:23:00,889 263134 INFO     [tempest.lib.common.rest_client] Request (LiveAutoBlockMigrationV225Test:test_volume_backed_live_migration): 200 GET http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665 0.356s
2019-05-14 21:23:00,890 263134 DEBUG    [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-OpenStack-Nova-API-Version': '2.25', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {'date': 'Tue, 14 May 2019 21:23:00 GMT', 'server': 'Apache', 'content-length': '1537', 'openstack-api-version': 'compute 2.25', 'x-openstack-nova-api-version': '2.25', 'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version,Accept-Encoding', 'x-openstack-request-id': 'req-2de13b95-d8f1-47d1-a935-8b11f0844c5b', 'x-compute-request-id': 'req-2de13b95-d8f1-47d1-a935-8b11f0844c5b', 'connection': 'close', 'content-type': 'application/json', 'status': '200', 'content-location': 'http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665'}
        Body: b'{"server": {"id": "190a9d1f-5425-4672-b95a-4476334cc665", "name": "tempest-LiveAutoBlockMigrationV225Test-server-1086666822", "status": "MIGRATING", "tenant_id": "a442cb02c0ea44b69eec2fd782491a03", "user_id": "e352a8e1ec8146029fc44af42c10741d", "metadata": {}, "hostId": "0034a5f3c349315c8c878f6eef8d345888b5071fe5becc2d7b80c087", "image": "", "flavor": {"id": "8319d5ab-0f88-4ecf-805c-24863727f8ad", "links": [{"rel": "bookmark", "href": "http://10.0.0.132:8774/flavors/8319d5ab-0f88-4ecf-805c-24863727f8ad"}]}, "created": "2019-05-14T21:17:29Z", "updated": "2019-05-14T21:18:01Z", "addresses": {"tempest-LiveAutoBlockMigrationV225Test-818925055-network": [{"version": 4, "addr": "10.100.0.14", "OS-EXT-IPS:type": "fixed", "OS-EXT-IPS-MAC:mac_addr": "fa:16:3e:8a:18:c3"}]}, "accessIPv4": "", "accessIPv6": "", "links": [{"rel": "self", "href": "http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665"}, {"rel": "bookmark", "href": "http://10.0.0.132:8774/servers/190a9d1f-5425-4672-b95a-4476334cc665"}], "OS-DCF:diskConfig": "MANUAL", "progress": 0, "OS-EXT-AZ:availability_zone": "nova", "config_drive": "", "key_name": null, "OS-SRV-USG:launched_at": "2019-05-14T21:17:55.000000", "OS-SRV-USG:terminated_at": null, "security_groups": [{"name": "default"}], "OS-EXT-STS:task_state": "migrating", "OS-EXT-STS:vm_state": "active", "OS-EXT-STS:power_state": 1, "os-extended-volumes:volumes_attached": [{"id": "975f122c-4110-4378-8950-d8c338e2da30", "delete_on_termination": true}], "locked": false, "description": null}}'
2019-05-14 21:23:02,497 263134 INFO     [tempest.lib.common.rest_client] Request (LiveAutoBlockMigrationV225Test:test_volume_backed_live_migration): 200 GET http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665 0.602s
2019-05-14 21:23:02,498 263134 DEBUG    [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-OpenStack-Nova-API-Version': '2.25', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {'date': 'Tue, 14 May 2019 21:23:01 GMT', 'server': 'Apache', 'content-length': '1537', 'openstack-api-version': 'compute 2.25', 'x-openstack-nova-api-version': '2.25', 'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version,Accept-Encoding', 'x-openstack-request-id': 'req-43543071-a7e3-4f33-b300-579fa95bb7b8', 'x-compute-request-id': 'req-43543071-a7e3-4f33-b300-579fa95bb7b8', 'connection': 'close', 'content-type': 'application/json', 'status': '200', 'content-location': 'http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665'}
        Body: b'{"server": {"id": "190a9d1f-5425-4672-b95a-4476334cc665", "name": "tempest-LiveAutoBlockMigrationV225Test-server-1086666822", "status": "MIGRATING", "tenant_id": "a442cb02c0ea44b69eec2fd782491a03", "user_id": "e352a8e1ec8146029fc44af42c10741d", "metadata": {}, "hostId": "0034a5f3c349315c8c878f6eef8d345888b5071fe5becc2d7b80c087", "image": "", "flavor": {"id": "8319d5ab-0f88-4ecf-805c-24863727f8ad", "links": [{"rel": "bookmark", "href": "http://10.0.0.132:8774/flavors/8319d5ab-0f88-4ecf-805c-24863727f8ad"}]}, "created": "2019-05-14T21:17:29Z", "updated": "2019-05-14T21:18:01Z", "addresses": {"tempest-LiveAutoBlockMigrationV225Test-818925055-network": [{"version": 4, "addr": "10.100.0.14", "OS-EXT-IPS:type": "fixed", "OS-EXT-IPS-MAC:mac_addr": "fa:16:3e:8a:18:c3"}]}, "accessIPv4": "", "accessIPv6": "", "links": [{"rel": "self", "href": "http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665"}, {"rel": "bookmark", "href": "http://10.0.0.132:8774/servers/190a9d1f-5425-4672-b95a-4476334cc665"}], "OS-DCF:diskConfig": "MANUAL", "progress": 0, "OS-EXT-AZ:availability_zone": "nova", "config_drive": "", "key_name": null, "OS-SRV-USG:launched_at": "2019-05-14T21:17:55.000000", "OS-SRV-USG:terminated_at": null, "security_groups": [{"name": "default"}], "OS-EXT-STS:task_state": "migrating", "OS-EXT-STS:vm_state": "active", "OS-EXT-STS:power_state": 1, "os-extended-volumes:volumes_attached": [{"id": "975f122c-4110-4378-8950-d8c338e2da30", "delete_on_termination": true}], "locked": false, "description": null}}'
2019-05-14 21:23:03,834 263134 INFO     [tempest.lib.common.rest_client] Request (LiveAutoBlockMigrationV225Test:test_volume_backed_live_migration): 200 GET http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665 0.329s
2019-05-14 21:23:03,834 263134 DEBUG    [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-OpenStack-Nova-API-Version': '2.25', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {'date': 'Tue, 14 May 2019 21:23:03 GMT', 'server': 'Apache', 'content-length': '1537', 'openstack-api-version': 'compute 2.25', 'x-openstack-nova-api-version': '2.25', 'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version,Accept-Encoding', 'x-openstack-request-id': 'req-39081a25-1851-4fd7-b128-3a685c8443e8', 'x-compute-request-id': 'req-39081a25-1851-4fd7-b128-3a685c8443e8', 'connection': 'close', 'content-type': 'application/json', 'status': '200', 'content-location': 'http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665'}
        Body: b'{"server": {"id": "190a9d1f-5425-4672-b95a-4476334cc665", "name": "tempest-LiveAutoBlockMigrationV225Test-server-1086666822", "status": "MIGRATING", "tenant_id": "a442cb02c0ea44b69eec2fd782491a03", "user_id": "e352a8e1ec8146029fc44af42c10741d", "metadata": {}, "hostId": "0034a5f3c349315c8c878f6eef8d345888b5071fe5becc2d7b80c087", "image": "", "flavor": {"id": "8319d5ab-0f88-4ecf-805c-24863727f8ad", "links": [{"rel": "bookmark", "href": "http://10.0.0.132:8774/flavors/8319d5ab-0f88-4ecf-805c-24863727f8ad"}]}, "created": "2019-05-14T21:17:29Z", "updated": "2019-05-14T21:18:01Z", "addresses": {"tempest-LiveAutoBlockMigrationV225Test-818925055-network": [{"version": 4, "addr": "10.100.0.14", "OS-EXT-IPS:type": "fixed", "OS-EXT-IPS-MAC:mac_addr": "fa:16:3e:8a:18:c3"}]}, "accessIPv4": "", "accessIPv6": "", "links": [{"rel": "self", "href": "http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665"}, {"rel": "bookmark", "href": "http://10.0.0.132:8774/servers/190a9d1f-5425-4672-b95a-4476334cc665"}], "OS-DCF:diskConfig": "MANUAL", "progress": 0, "OS-EXT-AZ:availability_zone": "nova", "config_drive": "", "key_name": null, "OS-SRV-USG:launched_at": "2019-05-14T21:17:55.000000", "OS-SRV-USG:terminated_at": null, "security_groups": [{"name": "default"}], "OS-EXT-STS:task_state": "migrating", "OS-EXT-STS:vm_state": "active", "OS-EXT-STS:power_state": 1, "os-extended-volumes:volumes_attached": [{"id": "975f122c-4110-4378-8950-d8c338e2da30", "delete_on_termination": true}], "locked": false, "description": null}}'
2019-05-14 21:23:05,223 263134 INFO     [tempest.lib.common.rest_client] Request (LiveAutoBlockMigrationV225Test:test_volume_backed_live_migration): 200 GET http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665 0.382s
2019-05-14 21:23:05,223 263134 DEBUG    [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-OpenStack-Nova-API-Version': '2.25', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {'date': 'Tue, 14 May 2019 21:23:04 GMT', 'server': 'Apache', 'content-length': '1537', 'openstack-api-version': 'compute 2.25', 'x-openstack-nova-api-version': '2.25', 'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version,Accept-Encoding', 'x-openstack-request-id': 'req-e65e0235-0552-4602-9937-8bd03a73c6eb', 'x-compute-request-id': 'req-e65e0235-0552-4602-9937-8bd03a73c6eb', 'connection': 'close', 'content-type': 'application/json', 'status': '200', 'content-location': 'http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665'}
        Body: b'{"server": {"id": "190a9d1f-5425-4672-b95a-4476334cc665", "name": "tempest-LiveAutoBlockMigrationV225Test-server-1086666822", "status": "MIGRATING", "tenant_id": "a442cb02c0ea44b69eec2fd782491a03", "user_id": "e352a8e1ec8146029fc44af42c10741d", "metadata": {}, "hostId": "0034a5f3c349315c8c878f6eef8d345888b5071fe5becc2d7b80c087", "image": "", "flavor": {"id": "8319d5ab-0f88-4ecf-805c-24863727f8ad", "links": [{"rel": "bookmark", "href": "http://10.0.0.132:8774/flavors/8319d5ab-0f88-4ecf-805c-24863727f8ad"}]}, "created": "2019-05-14T21:17:29Z", "updated": "2019-05-14T21:18:01Z", "addresses": {"tempest-LiveAutoBlockMigrationV225Test-818925055-network": [{"version": 4, "addr": "10.100.0.14", "OS-EXT-IPS:type": "fixed", "OS-EXT-IPS-MAC:mac_addr": "fa:16:3e:8a:18:c3"}]}, "accessIPv4": "", "accessIPv6": "", "links": [{"rel": "self", "href": "http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665"}, {"rel": "bookmark", "href": "http://10.0.0.132:8774/servers/190a9d1f-5425-4672-b95a-4476334cc665"}], "OS-DCF:diskConfig": "MANUAL", "progress": 0, "OS-EXT-AZ:availability_zone": "nova", "config_drive": "", "key_name": null, "OS-SRV-USG:launched_at": "2019-05-14T21:17:55.000000", "OS-SRV-USG:terminated_at": null, "security_groups": [{"name": "default"}], "OS-EXT-STS:task_state": "migrating", "OS-EXT-STS:vm_state": "active", "OS-EXT-STS:power_state": 1, "os-extended-volumes:volumes_attached": [{"id": "975f122c-4110-4378-8950-d8c338e2da30", "delete_on_termination": true}], "locked": false, "description": null}}'
2019-05-14 21:23:06,771 263134 INFO     [tempest.lib.common.rest_client] Request (LiveAutoBlockMigrationV225Test:test_volume_backed_live_migration): 200 GET http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665 0.541s
2019-05-14 21:23:06,772 263134 DEBUG    [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-OpenStack-Nova-API-Version': '2.25', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {'date': 'Tue, 14 May 2019 21:23:06 GMT', 'server': 'Apache', 'content-length': '1537', 'openstack-api-version': 'compute 2.25', 'x-openstack-nova-api-version': '2.25', 'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version,Accept-Encoding', 'x-openstack-request-id': 'req-1bc158c8-f2bf-40f1-abdf-1e05bf93c6e6', 'x-compute-request-id': 'req-1bc158c8-f2bf-40f1-abdf-1e05bf93c6e6', 'connection': 'close', 'content-type': 'application/json', 'status': '200', 'content-location': 'http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665'}
        Body: b'{"server": {"id": "190a9d1f-5425-4672-b95a-4476334cc665", "name": "tempest-LiveAutoBlockMigrationV225Test-server-1086666822", "status": "MIGRATING", "tenant_id": "a442cb02c0ea44b69eec2fd782491a03", "user_id": "e352a8e1ec8146029fc44af42c10741d", "metadata": {}, "hostId": "0034a5f3c349315c8c878f6eef8d345888b5071fe5becc2d7b80c087", "image": "", "flavor": {"id": "8319d5ab-0f88-4ecf-805c-24863727f8ad", "links": [{"rel": "bookmark", "href": "http://10.0.0.132:8774/flavors/8319d5ab-0f88-4ecf-805c-24863727f8ad"}]}, "created": "2019-05-14T21:17:29Z", "updated": "2019-05-14T21:18:01Z", "addresses": {"tempest-LiveAutoBlockMigrationV225Test-818925055-network": [{"version": 4, "addr": "10.100.0.14", "OS-EXT-IPS:type": "fixed", "OS-EXT-IPS-MAC:mac_addr": "fa:16:3e:8a:18:c3"}]}, "accessIPv4": "", "accessIPv6": "", "links": [{"rel": "self", "href": "http://10.0.0.132:8774/v2.1/servers/190a9d1f-5425-4672-b95a-4476334cc665"}, {"rel": "bookmark", "href": "http://10.0.0.132:8774/servers/190a9d1f-5425-4672-b95a-4476334cc665"}], "OS-DCF:diskConfig": "MANUAL", "progress": 0, "OS-EXT-AZ:availability_zone": "nova", "config_drive": "", "key_name": null, "OS-SRV-USG:launched_at": "2019-05-14T21:17:55.000000", "OS-SRV-USG:terminated_at": null, "security_groups": [{"name": "default"}], "OS-EXT-STS:task_state": "migrating", "OS-EXT-STS:vm_state": "active", "OS-EXT-STS:power_state": 1, "os-extended-volumes:volumes_attached": [{"id": "975f122c-4110-4378-8950-d8c338e2da30", "delete_on_termination": true}], "locked": false, "description": null}}'
}}}

Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/tempest/common/utils/__init__.py", line 89, in wrapper
    return f(*func_args, **func_kwargs)
  File "/usr/lib/python3.6/site-packages/tempest/api/compute/admin/test_live_migration.py", line 143, in test_volume_backed_live_migration
    self._test_live_migration(volume_backed=True)
  File "/usr/lib/python3.6/site-packages/tempest/api/compute/admin/test_live_migration.py", line 119, in _test_live_migration
    self._live_migrate(server_id, destination_host, state, volume_backed)
  File "/usr/lib/python3.6/site-packages/tempest/api/compute/admin/test_live_migration.py", line 77, in _live_migrate
    waiters.wait_for_server_status(self.servers_client, server_id, state)
  File "/usr/lib/python3.6/site-packages/tempest/common/waiters.py", line 96, in wait_for_server_status
    raise lib_exc.TimeoutException(message)
tempest.lib.exceptions.TimeoutException: Request timed out
Details: (LiveAutoBlockMigrationV225Test:test_volume_backed_live_migration) Server 190a9d1f-5425-4672-b95a-4476334cc665 failed to reach ACTIVE status and task state "None" within the required time (300 s). Current status: MIGRATING. Current task state: migrating.



Expected results:
Test passed

Additional info:

Comment 4 Artom Lifshitz 2019-06-07 03:26:07 UTC
Notes:

Instance: 190a9d1f-5425-4672-b95a-4476334cc665
Port:     4399f6d0-cf33-428d-b73d-3fe0808e763e

Migration request arrives:

2019-05-14 21:18:00.440 [./controller-0/var/log/containers/nova/nova-api.log] 22 DEBUG nova.api.openstack.wsgi [req-b9a709aa-766f-4f65-85aa-76f8ef993be1 fe18893c777943169c2972dda825ee58 972c8b8078e94ee7ba51c9550befcb3c - default default] Action: 'action', calling method: <bound method MigrateServerController._migrate_live of <nova.api.openstack.compute.migrate_server.MigrateServerController object at 0x7ffa48ce7128>>, body: {"os-migrateLive": {"host": "compute-1.localdomain", "block_migration": "auto"}} _process_stack /usr/lib/python3.6/site-packages/nova/api/openstack/wsgi.py:520

Confirmation that pre_live_migration will wait for external event:

2019-05-14 21:18:13.668 [./compute-1/var/log/containers/nova/nova-compute.log] 9 DEBUG nova.compute.manager [req-b9a709aa-766f-4f65-85aa-76f8ef993be1 fe18893c777943169c2972dda825ee58 972c8b8078e94ee7ba51c9550befcb3c - default default] pre_live_migration result data is LibvirtLiveMigrateData(bdms=[LibvirtLiveMigrateBDMInfo],block_migration=False,disk_available_mb=137216,disk_over_commit=<?>,dst_wants_file_backed_memory=False,file_backed_memory_discard=False,filename='tmpo7tol5rw',graphics_listen_addr_spice=127.0.0.1,graphics_listen_addr_vnc=172.17.1.145,image_type='rbd',instance_relative_path='190a9d1f-5425-4672-b95a-4476334cc665',is_shared_block_storage=True,is_shared_instance_path=False,is_volume_backed=True,migration=<?>,old_vol_attachment_ids={975f122c-4110-4378-8950-d8c338e2da30='924a7b15-7fe8-492f-b0c4-5a6a84c50da5'},serial_listen_addr=None,serial_listen_ports=[],src_supports_native_luks=True,supported_perf_events=[],target_connect_addr='compute-1.internalapi.localdomain',vifs=[VIFMigrateData],wait_for_vif_plugged=True) pre_live_migration /usr/lib/python3.6/site-packages/nova/compute/manager.py:6386

Preparing to wait for event:

2019-05-14 21:18:05.727 [./compute-0/var/log/containers/nova/nova-compute.log] 9 DEBUG nova.compute.manager [-] [instance: 190a9d1f-5425-4672-b95a-4476334cc665] Preparing to wait for external event network-vif-plugged-4399f6d0-cf33-428d-b73d-3fe0808e763e prepare_for_instance_event /usr/lib/python3.6/site-packages/nova/compute/manager.py:326

Timed out waiting for event:

2019-05-14 21:23:13.730 [./compute-0/var/log/containers/nova/nova-compute.log] 9 WARNING nova.compute.manager [-] [instance: 190a9d1f-5425-4672-b95a-4476334cc665] Timed out waiting for events: [('network-vif-plugged', '4399f6d0-cf33-428d-b73d-3fe0808e763e')]. If these timeouts are a persistent issue it could mean the networking backend on host compute-1.localdomain does not support sending these events unless there are port binding host changes which does not happen at this point in the live migration process. You may need to disable the live_migration_wait_for_vif_plug option on host compute-1.localdomain.: eventlet.timeout.Timeout: 300 seconds

But VIF does get plugged on dest:

2019-05-14 21:18:09.160 [./compute-1/var/log/containers/nova/nova-compute.log] 9 INFO os_vif [req-b9a709aa-766f-4f65-85aa-76f8ef993be1 fe18893c777943169c2972dda825ee58 972c8b8078e94ee7ba51c9550befcb3c - default 
default] Successfully plugged vif VIFOpenVSwitch(active=False,address=fa:16:3e:8a:18:c3,bridge_name='br-int',has_traffic_filtering=True,id=4399f6d0-cf33-428d-b73d-3fe0808e763e,network=Network(a0a43665-a694-44ed-
9d07-c4132eb5dc8d),plugin='ovs',port_profile=VIFPortProfileOpenVSwitch,preserve_on_delete=False,vif_name='tap4399f6d0-cf')

Event is still pending when instance gets cleaned up:

2019-05-14 21:23:07.054 [./compute-0/var/log/containers/nova/nova-compute.log] 9 DEBUG nova.compute.manager [req-5882a82e-6061-4d4b-8290-5afec3ce5b45 e352a8e1ec8146029fc44af42c10741d a442cb02c0ea44b69eec2fd782491a03 - default default] [instance: 190a9d1f-5425-4672-b95a-4476334cc665] Events pending at deletion: network-vif-plugged-4399f6d0-cf33-428d-b73d-3fe0808e763e _delete_instance /usr/lib/python3.6/site-packages/nova/compute/manager.py:2723

... and an unexpected event is received *before* the timeout:

2019-05-14 21:23:07.436 [./compute-0/var/log/containers/nova/nova-compute.log] 9 WARNING nova.compute.manager [req-c348055b-1081-4abe-a9dc-7fa25cb50315 90e421559099465cb0f9771e0459b17f 1acceed079604cef97a539e381
103cc8 - default default] [instance: 190a9d1f-5425-4672-b95a-4476334cc665] Received unexpected event network-vif-plugged-4399f6d0-cf33-428d-b73d-3fe0808e763e for instance with vm_state active and task_state dele
ting.

I think the timestamp on the time out waiting for the event happening *after* an unexpected event is received is due to the following sequence of events:

1. tempest live migrates the instance
2. nova starts waiting for the external event
3. tempest polls the instance, waiting for it to become ACTIVE
4. tempest "times out", moves to clean up
5. tempest deletes the instance
6. nova, while deleting the instance, removes the event waiter
7. the event arrives

Comment 5 Artom Lifshitz 2019-06-07 14:25:13 UTC
Despite the Tempest race weirdness, I think this is the same bug as 1710038.

*** This bug has been marked as a duplicate of bug 1710038 ***