Ask Your Question

Revision history [back]

click to hide/show revision 1
initial version

Instances fail to start failed to allocate network

Hi,

All our instance creations are currently failing with the following error :

Message
Exceeded maximum number of retries. Exhausted all hosts available for retrying build failures for instance 23e172ea-a13f-4bb4-9ae4-5f694644d9c1.
Code
500
Details
File "/usr/lib/python2.7/site-packages/nova/conductor/manager.py", line 580, in build_instances raise exception.MaxRetriesExceeded(reason=msg)
Created
Nov. 29, 2018, 9:12 a.m.

We are running Queens on Centos 7 with KVM and OpenVSwitch, we have both vlan and vxlan tenant networks, neither of which are working.

Config files are as follows Neutron.conf (controller):

[DEFAULT]
allow_automatic_l3agent_failover=True
allow_overlapping_ips=True
auth_strategy=keystone
core_plugin=ml2
debug=True
dhcp_agents_per_network=5
dhcp_domain=
dvr_base_mac=FA:CA:FF:02:00:00
memcached_servers=keystone1.nubes.rl.ac.uk:11211,keystone2.nubes.rl.ac.uk:11211,keystone3.nubes.rl.ac.uk:11211
notification_driver=messagingv2
notify_nova_on_port_data_changes=True
notify_nova_on_port_status_changes=True
nova_url=https://openstack.nubes.rl.ac.uk:8774/v2
router_distributed=True
rpc_backend=rabbit
rpc_response_timeout=60
service_plugins=router
transport_url=rabbit://openstack:<rabbitpass>@rabbit1.nubes.rl.ac.uk:5672,openstack:<rabbitpass@rabbit2.nubes.rl.ac.uk:5672,openstack:<rabbitpass@rabbit3.nubes.rl.ac.uk:5672/
verbose=True

[cache]
backend=oslo_cache.memcache_pool
enabled=True
memcache_servers=keystone1.nubes.rl.ac.uk:11211,keystone2.nubes.rl.ac.uk:11211,keystone3.nubes.rl.ac.uk:11211

[database]
connection=mysql+pymysql://neutron:<neutrondbpass>@openstack.nubes.rl.ac.uk:3306/neutron
max_overflow=200
max_pool_size=200

[keystone_authtoken]
auth_plugin=password
auth_type=password
auth_uri=https://openstack.nubes.rl.ac.uk:5000
auth_url=https://openstack.nubes.rl.ac.uk:35357
password=<neutronpassword>
project_domain_name=default
project_name=service
user_domain_name=default
username=neutron

[nova]
auth_plugin=password
auth_type=password
auth_url=https://openstack.nubes.rl.ac.uk:35357
password=<novapassword>
project_domain_name=default
project_name=service
region_name=RegionOne
user_domain_name=default
username=nova

[oslo_concurrency]
lock_path=/var/lib/neutron/tmp

Neutron.conf (compute):

[DEFAULT]
auth_strategy=keystone
debug=True
rpc_backend=rabbit
rpc_response_timeout=600
transport_url=rabbit://openstack::<rabbitpass>@rabbit1.nubes.rl.ac.uk:5672,openstack::<rabbitpass>@rabbit2.nubes.rl.ac.uk:5672,openstack::<rabbitpass>@rabbit3.nubes.rl.ac.uk:5672/
verbose=True

[keystone_authtoken]
auth_plugin=password
auth_type=password
auth_uri=https://openstack.nubes.rl.ac.uk:5000
auth_url=https://openstack.nubes.rl.ac.uk:35357
password=<neutronpassword>
project_domain_name=default
project_name=service
user_domain_name=default
username=neutron

[oslo_concurency]
lock_path=/var/lib/neutron/tmp

openvswitchagent.ini (compute):

[agent]
arp_responder=True
enable_distributed_routing=True
l2_population=True
prevent_arp_spoofing=False
tunnel_types=vxlan
debug=True

[ovs]
bridge_mappings=provider:br0
local_ip=130.246.208.89

[securitygroup]
enable_security_group=True
firewall_driver=iptables_hybrid

Log files are as follows:

nova-compute (compute)

2018-11-29 09:11:39.252 4860 DEBUG nova.scheduler.client.report [req-a81f40e4-8a44-452e-82c0-99d1d11dab5d - - - - -] Instance 23e172ea-a13f-4bb4-9ae4-5f694644d9c1 allocations are unchanged:
VCPU=1,MEMORY_MB=1024,DISK_GB=10 _allocate_for_instance /usr/lib/python2.7/site-packages/nova/scheduler/client/report.py:1419
2018-11-29 09:11:39.261 4860 DEBUG nova.compute.resource_tracker [req-a81f40e4-8a44-452e-82c0-99d1d11dab5d - - - - -] Auto-correcting allocations. _update_usage_from_instance /usr/lib/python
2.7/site-packages/nova/compute/resource_tracker.py:1121
2018-11-29 09:11:39.340 4860 DEBUG nova.scheduler.client.report [req-a81f40e4-8a44-452e-82c0-99d1d11dab5d - - - - -] Instance 373ecd6a-8b10-4486-b3af-b6a4953dfb1c allocations are unchanged:
VCPU=4,MEMORY_MB=16384,DISK_GB=100 _allocate_for_instance /usr/lib/python2.7/site-packages/nova/scheduler/client/report.py:1419
2018-11-29 09:11:39.536 4860 DEBUG nova.compute.resource_tracker [req-a81f40e4-8a44-452e-82c0-99d1d11dab5d - - - - -] Instance 373ecd6a-8b10-4486-b3af-b6a4953dfb1c actively managed on this c
ompute host and has allocations in placement: {u'resources': {u'VCPU': 4, u'MEMORY_MB': 16384, u'DISK_GB': 100}}. _remove_deleted_instances_allocations /usr/lib/python2.7/site-packages/nova/
compute/resource_tracker.py:1252
2018-11-29 09:11:39.537 4860 DEBUG nova.compute.resource_tracker [req-a81f40e4-8a44-452e-82c0-99d1d11dab5d - - - - -] Instance 23e172ea-a13f-4bb4-9ae4-5f694644d9c1 actively managed on this c
ompute host and has allocations in placement: {u'resources': {u'VCPU': 1, u'MEMORY_MB': 1024, u'DISK_GB': 10}}. _remove_deleted_instances_allocations /usr/lib/python2.7/site-packages/nova/co
mpute/resource_tracker.py:1252
2018-11-29 09:11:39.538 4860 DEBUG nova.compute.resource_tracker [req-a81f40e4-8a44-452e-82c0-99d1d11dab5d - - - - -] Total usable vcpus: 30, total allocated vcpus: 5 _report_final_resource_
view /usr/lib/python2.7/site-packages/nova/compute/resource_tracker.py:827
2018-11-29 09:11:39.539 4860 INFO nova.compute.resource_tracker [req-a81f40e4-8a44-452e-82c0-99d1d11dab5d - - - - -] Final resource view: name=hv82.nubes.rl.ac.uk phys_ram=95294MB used_ram=1
7920MB phys_disk=484302GB used_disk=110GB total_vcpus=30 used_vcpus=5 pci_stats=[]
2018-11-29 09:11:39.888 4860 DEBUG nova.compute.resource_tracker [req-a81f40e4-8a44-452e-82c0-99d1d11dab5d - - - - -] Compute_service record updated for hv82.nubes.rl.ac.uk:hv82.nubes.rl.ac.uk _update_available_resource /usr/lib/python2.7/site-packages/nova/compute/resource_tracker.py:767
2018-11-29 09:11:39.889 4860 DEBUG oslo_concurrency.lockutils [req-a81f40e4-8a44-452e-82c0-99d1d11dab5d - - - - -] Lock "compute_resources" released by "nova.compute.resource_tracker._update_available_resource" :: held 0.973s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285
2018-11-29 09:11:39.890 4860 DEBUG oslo_service.periodic_task [req-a81f40e4-8a44-452e-82c0-99d1d11dab5d - - - - -] Running periodic task ComputeManager._poll_unconfirmed_resizes run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2018-11-29 09:11:39.891 4860 DEBUG oslo_service.periodic_task [req-a81f40e4-8a44-452e-82c0-99d1d11dab5d - - - - -] Running periodic task ComputeManager._poll_rescued_instances run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2018-11-29 09:11:40.798 4860 DEBUG oslo_service.periodic_task [req-a81f40e4-8a44-452e-82c0-99d1d11dab5d - - - - -] Running periodic task ComputeManager._instance_usage_audit run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2018-11-29 09:11:40.814 4860 DEBUG oslo_service.periodic_task [req-a81f40e4-8a44-452e-82c0-99d1d11dab5d - - - - -] Running periodic task ComputeManager._poll_rebooting_instances run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2018-11-29 09:11:40.815 4860 DEBUG oslo_service.periodic_task [req-a81f40e4-8a44-452e-82c0-99d1d11dab5d - - - - -] Running periodic task ComputeManager._poll_volume_usage run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2018-11-29 09:11:40.815 4860 DEBUG oslo_service.periodic_task [req-a81f40e4-8a44-452e-82c0-99d1d11dab5d - - - - -] Running periodic task ComputeManager._reclaim_queued_deletes run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2018-11-29 09:11:40.816 4860 DEBUG nova.compute.manager [req-a81f40e4-8a44-452e-82c0-99d1d11dab5d - - - - -] CONF.reclaim_instance_interval <= 0, skipping... _reclaim_queued_deletes /usr/lib/python2.7/site-packages/nova/compute/manager.py:7309
2018-11-29 09:11:40.816 4860 DEBUG oslo_service.periodic_task [req-a81f40e4-8a44-452e-82c0-99d1d11dab5d - - - - -] Running periodic task ComputeManager._check_instance_build_time run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2018-11-29 09:11:48.657 4860 DEBUG nova.network.base_api [req-a59c6452-5db3-4dd7-861f-4ae95bf0f34c 19aefdc837c24889b2155043f1492f2d d4f684583ab54a0187d5d7b40f52cd6a - 38372510d9bb4ac7916178b062d387de 38372510d9bb4ac7916178b062d387de] [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1] Updating instance_info_cache with network_info: [] update_instance_cache_with_nw_info /usr/lib/python2.7/site-packages/nova/network/base_api.py:48
2018-11-29 09:11:48.678 4860 DEBUG oslo_concurrency.lockutils [req-a59c6452-5db3-4dd7-861f-4ae95bf0f34c 19aefdc837c24889b2155043f1492f2d d4f684583ab54a0187d5d7b40f52cd6a - 38372510d9bb4ac7916178b062d387de 38372510d9bb4ac7916178b062d387de] Releasing semaphore "refresh_cache-23e172ea-a13f-4bb4-9ae4-5f694644d9c1" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:228
2018-11-29 09:11:49.765 4860 DEBUG nova.network.neutronv2.api [req-f739b258-e056-459b-9300-3122a3d466b0 504126d7693441be82bcceed9cd65fae 1cb430293a4549bd829a0347fbfaddc1 - 38372510d9bb4ac7916178b062d387de 38372510d9bb4ac7916178b062d387de] [instance: 373ecd6a-8b10-4486-b3af-b6a4953dfb1c] Instance cache missing network info. _get_preexisting_port_ids /usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:2302
2018-11-29 09:12:11.213 4860 DEBUG nova.compute.manager [req-f56d00a3-e36e-4243-b2ee-ad9b01014db2 19aefdc837c24889b2155043f1492f2d d4f684583ab54a0187d5d7b40f52cd6a - 38372510d9bb4ac7916178b062d387de 38372510d9bb4ac7916178b062d387de] [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1] Received event network-vif-deleted-0d31ca61-130c-484a-9821-ebee10e05e6c external_instance_event /usr/lib/python2.7/site-packages/nova/compute/manager.py:7691
2018-11-29 09:12:11.948 4860 ERROR nova.compute.manager [req-8ff3bc5e-1ff7-494c-bc06-c17d018d1a0a 27be800439c244c1bd742ff056cf700c 2c142cf404c8430a997616e03ef45aa5 - 38372510d9bb4ac7916178b062d387de 38372510d9bb4ac7916178b062d387de] Instance failed network setup after 1 attempt(s): PortBindingFailed: Binding failed for port 0d31ca61-130c-484a-9821-ebee10e05e6c, please check neutron logs for more information.
2018-11-29 09:12:11.948 4860 ERROR nova.compute.manager Traceback (most recent call last):
2018-11-29 09:12:11.948 4860 ERROR nova.compute.manager   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1401, in _allocate_network_async
2018-11-29 09:12:11.948 4860 ERROR nova.compute.manager     bind_host_id=bind_host_id)
2018-11-29 09:12:11.948 4860 ERROR nova.compute.manager   File "/usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py", line 954, in allocate_for_instance
2018-11-29 09:12:11.948 4860 ERROR nova.compute.manager     bind_host_id, available_macs, requested_ports_dict)
2018-11-29 09:12:11.948 4860 ERROR nova.compute.manager   File "/usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py", line 1087, in _update_ports_for_instance
2018-11-29 09:12:11.948 4860 ERROR nova.compute.manager     vif.destroy()
2018-11-29 09:12:11.948 4860 ERROR nova.compute.manager   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2018-11-29 09:12:11.948 4860 ERROR nova.compute.manager     self.force_reraise()
2018-11-29 09:12:11.948 4860 ERROR nova.compute.manager   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2018-11-29 09:12:11.948 4860 ERROR nova.compute.manager     six.reraise(self.type_, self.value, self.tb)
2018-11-29 09:12:11.948 4860 ERROR nova.compute.manager   File "/usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py", line 1057, in _update_ports_for_instance
2018-11-29 09:12:11.948 4860 ERROR nova.compute.manager     port_client, instance, port_id, port_req_body)
2018-11-29 09:12:11.948 4860 ERROR nova.compute.manager   File "/usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py", line 470, in _update_port
2018-11-29 09:12:11.948 4860 ERROR nova.compute.manager     _ensure_no_port_binding_failure(port)
2018-11-29 09:12:11.948 4860 ERROR nova.compute.manager   File "/usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py", line 215, in _ensure_no_port_binding_failure
2018-11-29 09:12:11.948 4860 ERROR nova.compute.manager     raise exception.PortBindingFailed(port_id=port['id'])
2018-11-29 09:12:11.948 4860 ERROR nova.compute.manager PortBindingFailed: Binding failed for port 0d31ca61-130c-484a-9821-ebee10e05e6c, please check neutron logs for more information.
2018-11-29 09:12:11.948 4860 ERROR nova.compute.manager
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [req-8ff3bc5e-1ff7-494c-bc06-c17d018d1a0a 27be800439c244c1bd742ff056cf700c 2c142cf404c8430a997616e03ef45aa5 - 38372510d9bb4ac7916178b062d387de 38372510d9bb4ac7916178b062d387de] [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1] Instance failed to spawn: PortBindingFailed: Binding failed for port 0d31ca61-130c-484a-9821-ebee10e05e6c, please check neutron logs for more information.
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1] Traceback (most recent call last):
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2239, in _build_resources
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]     yield resources
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2019, in _build_and_run_instance
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]     block_device_info=block_device_info)
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 3102, in spawn
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]     mdevs=mdevs)
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 5386, in _get_guest_xml
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]     network_info_str = str(network_info)
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]   File "/usr/lib/python2.7/site-packages/nova/network/model.py", line 568, in __str__
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]     return self._sync_wrapper(fn, *args, **kwargs)
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]   File "/usr/lib/python2.7/site-packages/nova/network/model.py", line 551, in _sync_wrapper
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]     self.wait()
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]   File "/usr/lib/python2.7/site-packages/nova/network/model.py", line 583, in wait
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]     self[:] = self._gt.wait()
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]   File "/usr/lib/python2.7/site-packages/eventlet/greenthread.py", line 175, in wait
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]     return self._exit_event.wait()
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]   File "/usr/lib/python2.7/site-packages/eventlet/event.py", line 121, in wait
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]     return hubs.get_hub().switch()
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]   File "/usr/lib/python2.7/site-packages/eventlet/hubs/hub.py", line 294, in switch
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]     return self.greenlet.switch()
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]   File "/usr/lib/python2.7/site-packages/eventlet/greenthread.py", line 214, in main
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]     result = function(*args, **kwargs)
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]   File "/usr/lib/python2.7/site-packages/nova/utils.py", line 906, in context_wrapper
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]     return func(*args, **kwargs)
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1418, in _allocate_network_async
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]     six.reraise(*exc_info)
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1401, in _allocate_network_async
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]     bind_host_id=bind_host_id)
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]   File "/usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py", line 954, in allocate_for_instance
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]     bind_host_id, available_macs, requested_ports_dict)
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]   File "/usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py", line 1087, in _update_ports_for_instance
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]     vif.destroy()
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]     self.force_reraise()
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]     six.reraise(self.type_, self.value, self.tb)
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]   File "/usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py", line 1057, i
n _update_ports_for_instance
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]     port_client, instance, port_id, port_req_body)
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]   File "/usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py", line 470, in _update_port
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]     _ensure_no_port_binding_failure(port)
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]   File "/usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py", line 215, in _ensure_no_port_binding_failure
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]     raise exception.PortBindingFailed(port_id=port['id'])
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1] PortBindingFailed: Binding failed for port 0d31ca61-130c-484a-9821-ebee10e05e6c, please check neutron logs for more information.
2018-11-29 09:12:11.951 4860 ERROR nova.compute.manager [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1]
2018-11-29 09:12:11.954 4860 INFO nova.compute.manager [req-8ff3bc5e-1ff7-494c-bc06-c17d018d1a0a 27be800439c244c1bd742ff056cf700c 2c142cf404c8430a997616e03ef45aa5 - 38372510d9bb4ac7916178b062d387de 38372510d9bb4ac7916178b062d387de] [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1] Terminating instance
2018-11-29 09:12:11.970 4860 DEBUG nova.compute.manager [req-8ff3bc5e-1ff7-494c-bc06-c17d018d1a0a 27be800439c244c1bd742ff056cf700c 2c142cf404c8430a997616e03ef45aa5 - 38372510d9bb4ac7916178b062d387de 38372510d9bb4ac7916178b062d387de] [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1] Start destroying the instance on the hypervisor. _shutdown_instance /usr/lib/python2.7/site-packages/nova/compute/manager.py:2353
2018-11-29 09:12:11.973 4860 DEBUG nova.virt.libvirt.driver [-] [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1] During wait destroy, instance disappeared. _wait_for_destroy /usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:959
2018-11-29 09:12:11.973 4860 INFO nova.virt.libvirt.driver [-] [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1] Instance destroyed successfully.
2018-11-29 09:12:12.154 4860 DEBUG oslo_concurrency.processutils [req-8ff3bc5e-1ff7-494c-bc06-c17d018d1a0a 27be800439c244c1bd742ff056cf700c 2c142cf404c8430a997616e03ef45aa5 - 38372510d9bb4ac7916178b062d387de 38372510d9bb4ac7916178b062d387de] Running cmd (subprocess): mv /var/lib/nova/instances/23e172ea-a13f-4bb4-9ae4-5f694644d9c1 /var/lib/nova/instances/23e172ea-a13f-4bb4-9ae4-5f694644d9c1_del execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:372
2018-11-29 09:12:12.176 4860 DEBUG oslo_concurrency.processutils [req-8ff3bc5e-1ff7-494c-bc06-c17d018d1a0a 27be800439c244c1bd742ff056cf700c 2c142cf404c8430a997616e03ef45aa5 - 38372510d9bb4ac7916178b062d387de 38372510d9bb4ac7916178b062d387de] CMD "mv /var/lib/nova/instances/23e172ea-a13f-4bb4-9ae4-5f694644d9c1 /var/lib/nova/instances/23e172ea-a13f-4bb4-9ae4-5f694644d9c1_del" returned: 0 in 0.022s execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:409
2018-11-29 09:12:12.179 4860 INFO nova.virt.libvirt.driver [req-8ff3bc5e-1ff7-494c-bc06-c17d018d1a0a 27be800439c244c1bd742ff056cf700c 2c142cf404c8430a997616e03ef45aa5 - 38372510d9bb4ac7916178b062d387de 38372510d9bb4ac7916178b062d387de] [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1] Deleting instance files /var/lib/nova/instances/23e172ea-a13f-4bb4-9ae4-5f694644d9c1_del
2018-11-29 09:12:12.180 4860 INFO nova.virt.libvirt.driver [req-8ff3bc5e-1ff7-494c-bc06-c17d018d1a0a 27be800439c244c1bd742ff056cf700c 2c142cf404c8430a997616e03ef45aa5 - 38372510d9bb4ac7916178b062d387de 38372510d9bb4ac7916178b062d387de] [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1] Deletion of /var/lib/nova/instances/23e172ea-a13f-4bb4-9ae4-5f694644d9c1_del complete
2018-11-29 09:12:12.317 4860 INFO nova.compute.manager [req-8ff3bc5e-1ff7-494c-bc06-c17d018d1a0a 27be800439c244c1bd742ff056cf700c 2c142cf404c8430a997616e03ef45aa5 - 38372510d9bb4ac7916178b062d387de 38372510d9bb4ac7916178b062d387de] [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1] Took 0.35 seconds to destroy the instance on the hypervisor.
2018-11-29 09:12:12.318 4860 DEBUG nova.compute.manager [req-8ff3bc5e-1ff7-494c-bc06-c17d018d1a0a 27be800439c244c1bd742ff056cf700c 2c142cf404c8430a997616e03ef45aa5 - 38372510d9bb4ac7916178b062d387de 38372510d9bb4ac7916178b062d387de] [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1] Deallocating network for instance _deallocate_network /usr/lib/python2.7/site-packages/nova/compute/manager.py:1662
2018-11-29 09:12:12.318 4860 DEBUG nova.network.neutronv2.api [req-8ff3bc5e-1ff7-494c-bc06-c17d018d1a0a 27be800439c244c1bd742ff056cf700c 2c142cf404c8430a997616e03ef45aa5 - 38372510d9bb4ac7916178b062d387de 38372510d9bb4ac7916178b062d387de] [instance: 23e172ea-a13f-4bb4-9ae4-5f694644d9c1] deallocate_for_instance() deallocate_for_instance /usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:1250

openvswitch-agent.log (compute)

2018-11-29 09:10:20.416 4725 DEBUG neutron.agent.resource_cache [req-d2734b7a-f37f-466e-af66-e1032241a137 27be800439c244c1bd742ff056cf700c 2c142cf404c8430a997616e03ef45aa5 - - -] Received new resource Port: Port(admin_state_up=True,allowed_address_pairs=[],binding=PortBinding,binding_levels=[],created_at=2018-11-29T09:09:49Z,data_plane_status=<?>,description='',device_id='23e172ea-a13f-4bb4-9ae4-5f694644d9c1',device_owner='',dhcp_options=[],distributed_binding=None,dns=None,fixed_ips=[IPAllocation],id=0d31ca61-130c-484a-9821-ebee10e05e6c,mac_address=fa:16:3e:6d:03:5c,name='',network_id=5be315b7-7ebd-4254-97fe-18c1df501538,project_id='2c142cf404c8430a997616e03ef45aa5',qos_policy_id=None,revision_number=6,security=PortSecurity(0d31ca61-130c-484a-9821-ebee10e05e6c),security_group_ids=set([099f2a1f-f59f-4db1-b0ef-37a621c01af8]),status='DOWN',updated_at=2018-11-29T09:10:02Z) record_resource_update /usr/lib/python2.7/site-packages/neutron/agent/resource_cache.py:187
2018-11-29 09:10:20.417 4725 DEBUG neutron_lib.callbacks.manager [req-d2734b7a-f37f-466e-af66-e1032241a137 27be800439c244c1bd742ff056cf700c 2c142cf404c8430a997616e03ef45aa5 - - -] Notify callbacks ['neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent.OVSPluginApi._legacy_notifier-1964303'] for Port, after_update _notify_loop /usr/lib/python2.7/site-packages/neutron_lib/callbacks/manager.py:167
2018-11-29 09:10:28.178 4725 DEBUG neutron.agent.resource_cache [req-7c9c26cd-3626-4cae-8816-9f4adfb4a2aa - - - - -] Received new resource Port: Port(admin_state_up=True,allowed_address_pairs=[],binding=PortBinding,binding_levels=[PortBindingLevel],created_at=2018-07-23T18:33:25Z,data_plane_status=<?>,description='',device_id='dhcpa8b8bf76-2a94-5db3-8962-5916b8fb203f-e88af4dc-afe6-4dea-861a-5280726f0d9d',device_owner='network:dhcp',dhcp_options=[],distributed_binding=None,dns=None,fixed_ips=[IPAllocation],id=622733a5-b1f9-4d6a-afa1-3f401199352b,mac_address=fa:16:3e:6e:65:79,name='',network_id=e88af4dc-afe6-4dea-861a-5280726f0d9d,project_id='1460bc1a28094793b4d413f67140e285',qos_policy_id=None,revision_number=207,security=PortSecurity(622733a5-b1f9-4d6a-afa1-3f401199352b),security_group_ids=set([]),status='ACTIVE',updated_at=2018-11-29T08:59:31Z) record_resource_update /usr/lib/python2.7/site-packages/neutron/agent/resource_cache.py:187
2018-11-29 09:10:28.180 4725 DEBUG neutron_lib.callbacks.manager [req-7c9c26cd-3626-4cae-8816-9f4adfb4a2aa - - - - -] Notify callbacks ['neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent.OVSPluginApi._legacy_notifier-1964303'] for Port, after_update _notify_loop /usr/lib/python2.7/site-packages/neutron_lib/callbacks/manager.py:167
2018-11-29 09:10:55.603 4725 DEBUG neutron.agent.resource_cache [req-5041d4ad-ec9d-4611-b399-19349a600ea6 9cb9950891f3402a9cbf5c199c1244e3 d4f684583ab54a0187d5d7b40f52cd6a - - -] Resource Port 0d31ca61-130c-484a-9821-ebee10e05e6c updated (revision_number 6->8). Old fields: {'device_owner': u'', 'binding': PortBinding(host='',port_id=0d31ca61-130c-484a-9821-ebee10e05e6c,profile={},status='ACTIVE',vif_details=None,vif_type='unbound',vnic_type='normal')} New fields: {'device_owner': u'compute:ceph', 'binding': PortBinding(host='hv82.nubes.rl.ac.uk',port_id=0d31ca61-130c-484a-9821-ebee10e05e6c,profile={},status='ACTIVE',vif_details=None,vif_type='unbound',vnic_type='normal')} record_resource_update /usr/lib/python2.7/site-packages/neutron/agent/resource_cache.py:185
2018-11-29 09:10:55.605 4725 DEBUG neutron_lib.callbacks.manager [req-5041d4ad-ec9d-4611-b399-19349a600ea6 9cb9950891f3402a9cbf5c199c1244e3 d4f684583ab54a0187d5d7b40f52cd6a - - -] Notify callbacks ['neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent.OVSPluginApi._legacy_notifier-1964303'] for Port, after_update _notify_loop /usr/lib/python2.7/site-packages/neutron_lib/callbacks/manager.py:167
2018-11-29 09:11:00.963 4725 DEBUG neutron.agent.resource_cache [req-3beab571-9a95-4571-8e74-03c0d375cb7b 504126d7693441be82bcceed9cd65fae 1cb430293a4549bd829a0347fbfaddc1 - - -] Received new resource Port: Port(admin_state_up=True,allowed_address_pairs=[],binding=PortBinding,binding_levels=[],created_at=2018-11-29T09:10:19Z,data_plane_status=<?>,description='',device_id='373ecd6a-8b10-4486-b3af-b6a4953dfb1c',device_owner='',dhcp_options=[],distributed_binding=None,dns=None,fixed_ips=[IPAllocation],id=9d6a3227-aac3-47a5-a6d3-163360efef54,mac_address=fa:16:3e:bb:e0:59,name='',network_id=5be315b7-7ebd-4254-97fe-18c1df501538,project_id='1cb430293a4549bd829a0347fbfaddc1',qos_policy_id=None,revision_number=6,security=PortSecurity(9d6a3227-aac3-47a5-a6d3-163360efef54),security_group_ids=set([d6f86a96-6ce9-4b6c-8189-0855f6f454f5]),status='DOWN',updated_at=2018-11-29T09:10:49Z) record_resource_update /usr/lib/python2.7/site-packages/neutron/agent/resource_cache.py:187
2018-11-29 09:11:00.965 4725 DEBUG neutron_lib.callbacks.manager [req-3beab571-9a95-4571-8e74-03c0d375cb7b 504126d7693441be82bcceed9cd65fae 1cb430293a4549bd829a0347fbfaddc1 - - -] Notify callbacks ['neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent.OVSPluginApi._legacy_notifier-1964303'] for Port, after_update _notify_loop /usr/lib/python2.7/site-packages/neutron_lib/callbacks/manager.py:167
2018-11-29 09:11:05.726 4725 DEBUG neutron.agent.resource_cache [req-5041d4ad-ec9d-4611-b399-19349a600ea6 9cb9950891f3402a9cbf5c199c1244e3 d4f684583ab54a0187d5d7b40f52cd6a - - -] Resource Port 0d31ca61-130c-484a-9821-ebee10e05e6c updated (revision_number 8->9). Old fields: {'binding': PortBinding(host='hv82.nubes.rl.ac.uk',port_id=0d31ca61-130c-484a-9821-ebee10e05e6c,profile={},status='ACTIVE',vif_details=None,vif_type='unbound',vnic_type='normal')} New fields: {'binding': PortBinding(host='hv82.nubes.rl.ac.uk',port_id=0d31ca61-130c-484a-9821-ebee10e05e6c,profile={},status='ACTIVE',vif_details=None,vif_type='binding_failed',vnic_type='normal')} record_resource_update /usr/lib/python2.7/site-packages/neutron/agent/resource_cache.py:185
2018-11-29 09:11:05.728 4725 DEBUG neutron_lib.callbacks.manager [req-5041d4ad-ec9d-4611-b399-19349a600ea6 9cb9950891f3402a9cbf5c199c1244e3 d4f684583ab54a0187d5d7b40f52cd6a - - -] Notify callbacks ['neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent.OVSPluginApi._legacy_notifier-1964303'] for Port, after_update _notify_loop /usr/lib/python2.7/site-packages/neutron_lib/callbacks/manager.py:167
2018-11-29 09:12:07.021 4725 DEBUG neutron.agent.resource_cache [req-fcb07691-f8d5-4d75-91e9-2f5d523060f9 27be800439c244c1bd742ff056cf700c 2c142cf404c8430a997616e03ef45aa5 - - -] Resource Port deleted: 0d31ca61-130c-484a-9821-ebee10e05e6c record_resource_delete /usr/lib/python2.7/site-packages/neutron/agent/resource_cache.py:197
2018-11-29 09:12:07.023 4725 DEBUG neutron_lib.callbacks.manager [req-fcb07691-f8d5-4d75-91e9-2f5d523060f9 27be800439c244c1bd742ff056cf700c 2c142cf404c8430a997616e03ef45aa5 - - -] Notify callbacks ['neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent.OVSPluginApi._legacy_notifier-1964303'] for Port, after_delete _notify_loop /usr/lib/python2.7/site-packages/neutron_lib/callbacks/manager.py:16

ovs-vswitchd.log

No entries during that time window

neutron-server (controller) - Attached