Bug 1710128
| Summary: | [RHOS 15] Tempest test failure: test_volume_backed_live_migration | ||||||
|---|---|---|---|---|---|---|---|
| Product: | Red Hat OpenStack | Reporter: | Archit Modi <amodi> | ||||
| Component: | openstack-nova | Assignee: | 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
Archit Modi
2019-05-14 23:25:19 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
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 *** |