Bug 1716564

Summary: [osp15] test_resize_server_revert_with_volume_attached_id and test_resize_server_revert_id are failing with timeout
Product: Red Hat OpenStack Reporter: Michele Baldessari <michele>
Component: openstack-novaAssignee: OSP DFG:Compute <osp-dfg-compute>
Status: CLOSED DUPLICATE QA Contact: OSP DFG:Compute <osp-dfg-compute>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 15.0 (Stein)CC: bcafarel, dasmith, eglynn, jhakimra, kchamart, sbauza, sgordon, vromanso
Target Milestone: beta   
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-04 14:18: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:

Description Michele Baldessari 2019-06-03 15:56:42 UTC
Description of problem:
There are two failures that are in need of extra eyes:
A) https://rhos-qe-jenkins.rhev-ci-vms.eng.rdu2.redhat.com/view/ReleaseDelivery/view/OSP15/job/phase2-15_director-rhel-8.0-virthost-3cont_2comp-ipv4-gre-lvm/lastCompletedBuild/testReport/tempest.api.compute.servers.test_server_actions/ServerActionsTestJSON/test_resize_server_revert_id_c03aab19_adb1_44f5_917d_c419577e9e68_/

B) https://rhos-qe-jenkins.rhev-ci-vms.eng.rdu2.redhat.com/view/ReleaseDelivery/view/OSP15/job/phase2-15_director-rhel-8.0-virthost-3cont_2comp-ipv4-gre-lvm/lastCompletedBuild/testReport/tempest.api.compute.servers.test_server_actions/ServerActionsTestJSON/test_resize_server_revert_with_volume_attached_id_fbbf075f_a812_4022_bc5c_ccb8047eef12_volume_/

Build logs for both failing tests are here: https://rhos-qe-jenkins.rhev-ci-vms.eng.rdu2.redhat.com/view/ReleaseDelivery/view/OSP15/job/phase2-15_director-rhel-8.0-virthost-3cont_2comp-ipv4-gre-lvm/lastCompletedBuild/artifact/


It seems that both operations did not finish within 300 seconds:
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:14.803 7 WARNING nova.virt.libvirt.driver [req-623c5938-a627-45ee-a4f3-5a9c50d24427 b8061e1ac13f47c89b1fd43135f5faa7 cc4d8282e2404626a9ab3665e99e23b6 - default default] [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16] Timeout waiting for [('network-vif-plugged', 'cda91cc1-3670-4395-99b3-41db9fcf3f89')] for instance with vm_state resized and task_state resize_reverting.: eventlet.timeout.Timeout: 300 seconds
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.015 7 DEBUG nova.virt.libvirt.vif [req-623c5938-a627-45ee-a4f3-5a9c50d24427 b8061e1ac13f47c89b1fd43135f5faa7 cc4d8282e2404626a9ab3665e99e23b6 - default default] vif_type=ovs instance=Instance(access_ip_v4=None,access_ip_v6=None,architecture=None,auto_disk_config=False,availability_zone='nova',cell_name=None,cleaned=True,config_drive='',created_at=2019-05-31T21:42:39Z,default_ephemeral_device=None,default_swap_device=None,deleted=False,deleted_at=None,device_metadata=<?>,disable_terminate=False,display_description='tempest-ServerActionsTestJSON-server-1685251309',display_name='tempest-ServerActionsTestJSON-server-1685251309',ec2_ids=<?>,ephemeral_gb=0,ephemeral_key_uuid=None,fault=<?>,flavor=Flavor(4),host='compute-0.localdomain',hostname='tempest-serveractionstestjson-server-1685251309',id=241,image_ref='81cd9857-dd4d-434e-92c4-9965140128fd',info_cache=InstanceInfoCache,instance_type_id=4,kernel_id='',key_data='ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDbFJUY1uwDfUeoGqixOLpRv4881hNWckkzYFNilkUz5gjwtgk+udzgJ0qVOv4KsYDMSnXFhhXJ6qHWLK9ICCfVM5NlWf6/YW2Tr+rb9L3MWWONv979yKBLDp18F6lS9Vrl1Rm6lBuv4PlSvNhMpUo6SPqhd25GbIMCs7MbS4apvv2SHDDMrZVwKDpVscD+rC6A1uSG6mkvEIUvWWgYis3HJNhec8rhIB5HQgk9E0EXewQZ4IUanwQ37KZn9OpMhBFfNOK2dU14wsWAnyzwfHlVGjlM1l/7iERm7FXiqQ6D8NsmYxfudLSakazhT5w0J+CQ14BI7OXWlRNaSJDvpF3b Generated-by-Nova',key_name='tempest-keypair-1236916207',keypairs=<?>,launch_index=0,launched_at=2019-05-31T21:43:56Z,launched_on='compute-0.localdomain',locked=False,locked_by=None,memory_mb=64,metadata={},migration_context=MigrationContext,new_flavor=None,node='compute-0.localdomain',numa_topology=None,old_flavor=None,os_type=None,pci_devices=PciDeviceList,pci_requests=InstancePCIRequests,power_state=1,progress=0,project_id='cc4d8282e2404626a9ab3665e99e23b6',ramdisk_id='',reservation_id='r-29isfkuy',root_device_name='/dev/vda',root_gb=1,security_groups=SecurityGroupList,services=<?>,shutdown_terminate=False,system_metadata={boot_roles='swiftoperator',clean_attempts='1',image_base_image_ref='81cd9857-dd4d-434e-92c4-9965140128fd',image_container_format='bare',image_disk_format='qcow2',image_hw_rng_model='virtio',image_min_disk='1',image_min_ram='0',owner_project_name='tempest-ServerActionsTestJSON-48830335',owner_user_name='tempest-ServerActionsTestJSON-48830335'},tags=<?>,task_state='resize_reverting',terminated_at=None,trusted_certs=<?>,updated_at=2019-05-31T21:44:04Z,user_data='IyEvYmluL3NoCmVjaG8gIlByaW50aW5nIGNpcnJvcyB1c2VyIGF1dGhvcml6ZWQga2V5cyIKY2F0IH5jaXJyb3MvLnNzaC9hdXRob3JpemVkX2tleXMgfHwgdHJ1ZQo=',user_id='b8061e1ac13f47c89b1fd43135f5faa7',uuid=9105a18d-832a-4810-8f1a-266fcfe70a16,vcpu_model=VirtCPUModel,vcpus=1,vm_mode=None,vm_state='resized') vif={"id": "cda91cc1-3670-4395-99b3-41db9fcf3f89", "address": "fa:16:3e:9e:4a:2b", "network": {"id": "cf81cca7-d7b1-486c-be1d-06706ec29502", "bridge": "br-int", "label": "tempest-ServerActionsTestJSON-2109835598-network", "subnets": [{"cidr": "10.100.0.0/28", "dns": [], "gateway": {"address": "10.100.0.1", "type": "gateway", "version": 4, "meta": {}}, "ips": [{"address": "10.100.0.9", "type": "fixed", "version": 4, "meta": {}, "floating_ips": [{"address": "10.0.0.249", "type": "floating", "version": 4, "meta": {}}]}], "routes": [], "version": 4, "meta": {"dhcp_server": "10.100.0.4"}}], "meta": {"injected": false, "tenant_id": "cc4d8282e2404626a9ab3665e99e23b6", "mtu": 1458, "physical_network": null, "tunneled": true}}, "type": "ovs", "details": {"port_filter": true, "ovs_hybrid_plug": true, "datapath_type": "system", "bridge_name": "br-int"}, "devname": "tapcda91cc1-36", "ovs_interfaceid": "cda91cc1-3670-4395-99b3-41db9fcf3f89", "qbh_params": null, "qbg_params": null, "active": false, "vnic_type": "normal", "profile": {}, "preserve_on_delete": false, "meta": {}} unplug /usr/lib/python3.6/site-packages/nova/virt/libvirt/vif.py:840
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [req-623c5938-a627-45ee-a4f3-5a9c50d24427 b8061e1ac13f47c89b1fd43135f5faa7 cc4d8282e2404626a9ab3665e99e23b6 - default default] [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16] Setting instance vm_state to ERROR: nova.exception.VirtualInterfaceCreateException: Virtual Interface creation failed
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16] Traceback (most recent call last):
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16]   File "/usr/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 5701, in _create_domain_and_network
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16]     network_info)
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16]   File "/usr/lib64/python3.6/contextlib.py", line 88, in __exit__
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16]     next(self.gen)
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16]   File "/usr/lib/python3.6/site-packages/nova/compute/manager.py", line 480, in wait_for_instance_event
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16]     actual_event = event.wait()
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16]   File "/usr/lib/python3.6/site-packages/eventlet/event.py", line 125, in wait
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16]     result = hub.switch()
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16]   File "/usr/lib/python3.6/site-packages/eventlet/hubs/hub.py", line 297, in switch
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16]     return self.greenlet.switch()
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16] eventlet.timeout.Timeout: 300 seconds
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16]
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16] During handling of the above exception, another exception occurred:
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16]
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16] Traceback (most recent call last):
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16]   File "/usr/lib/python3.6/site-packages/nova/compute/manager.py", line 8201, in _error_out_instance_on_exception
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16]     yield                                                                                                                                                                                                                          
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16]   File "/usr/lib/python3.6/site-packages/nova/compute/manager.py", line 4226, in finish_revert_resize
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16]     block_device_info, power_on)
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16]   File "/usr/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 9028, in finish_revert_migration
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16]     power_on=power_on)
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16]   File "/usr/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 5722, in _create_domain_and_network
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16]     raise exception.VirtualInterfaceCreateException()
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16] nova.exception.VirtualInterfaceCreateException: Virtual Interface creation failed
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.172 7 ERROR nova.compute.manager [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16]
compute-0/var/log/containers/nova/nova-compute.log:2019-05-31 21:49:15.749 7 INFO nova.compute.manager [req-623c5938-a627-45ee-a4f3-5a9c50d24427 b8061e1ac13f47c89b1fd43135f5faa7 cc4d8282e2404626a9ab3665e99e23b6 - default default] [instance: 9105a18d-832a-4810-8f1a-266fcfe70a16] Successfully reverted task state from resize_reverting on failure for instance.

Comment 2 Michele Baldessari 2019-06-04 14:18:13 UTC

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