| 2020-12-03 15:54:20 |
loudgefly |
bug |
|
|
added bug |
| 2020-12-03 16:01:19 |
loudgefly |
attachment added |
|
nova-compute.log https://bugs.launchpad.net/neutron/+bug/1906683/+attachment/5440653/+files/nova-compute.log |
|
| 2020-12-03 16:02:12 |
loudgefly |
attachment added |
|
neutron-server.log https://bugs.launchpad.net/neutron/+bug/1906683/+attachment/5440654/+files/neutron-server.log |
|
| 2020-12-03 16:03:03 |
loudgefly |
attachment added |
|
neutron-openvswitch-agent.log https://bugs.launchpad.net/neutron/+bug/1906683/+attachment/5440655/+files/neutron-openvswitch-agent.log |
|
| 2020-12-03 16:06:26 |
loudgefly |
affects |
neutron |
ubuntu |
|
| 2020-12-03 16:06:31 |
loudgefly |
description |
I'm experiencing a problem when spawning a VM, it fails after hitting a timeout while waiting for VIF plugged
From nova-compute.log:
Failed to allocate network(s): nova.exception.VirtualInterfaceCreateException: Virtual Interface creation failed
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] Traceback (most recent call last):
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 6707, in _create_guest_with_network
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] post_xml_callback=post_xml_callback)
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/usr/lib64/python3.6/contextlib.py", line 88, in __exit__
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] next(self.gen)
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py", line 484, in wait_for_instance_event
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] actual_event = event.wait()
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/eventlet/event.py", line 125, in wait
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] result = hub.switch()
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/eventlet/hubs/hub.py", line 298, in switch
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] return self.greenlet.switch()
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] eventlet.timeout.Timeout: 300 seconds
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2]
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] During handling of the above exception, another exception occurred:
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2]
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] Traceback (most recent call last):
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py", line 2398, in _build_and_run_instance
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] accel_info=accel_info)
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 3748, in spawn
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] cleanup_instance_disks=created_disks)
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 6730, in _create_guest_with_network
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] raise exception.VirtualInterfaceCreateException()
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] nova.exception.VirtualInterfaceCreateException: Virtual Interface creation failed
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2]
2020-12-03 13:18:32.771 6 DEBUG nova.compute.utils [req-c9081063-e0a9-4562-9f87-907926001481 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] Virtual Interface creation failed notify_about_instance_usage /var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/utils.py:429
2020-12-03 13:18:32.779 6 ERROR nova.compute.manager [req-c9081063-e0a9-4562-9f87-907926001481 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] Build of instance 04b615d1-e911-48f9-bdb1-cf950ec49ef2 aborted: Failed to allocate the network(s), not rescheduling.: nova.exception.BuildAbortException: Build of instance 04b615d1-e911-48f9-bdb1-cf950ec49ef2 aborted: Failed to allocate the network(s), not rescheduling.
If I check neutron-serve.log I can see:
2020-12-03 13:13:16.247 24 INFO neutron.wsgi [req-605a087b-f708-4e92-a258-5314fa9ffb84 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.2,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 186 time: 0.1332297
2020-12-03 13:13:17.408 23 INFO neutron.wsgi [req-cb46f45f-5a53-4536-ab29-a7858c3a8bbc 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2&device_id=4fd42ea9-1a62-43ae-a926-53dd6bc65e2a&device_id=fb8d26c2-1994-4319-9c73-f09f1d66fe5e&device_id=f27e5057-9ef0-46ba-86e0-b5899b8cf190&device_id=fd1a8729-533c-4188-835b-6be050cf2dc0&device_id=fd26c490-8312-4933-ab15-18cbdd57ddff&device_id=37583344-e791-453f-b502-72a5e9fd38d6&device_id=eb28cae5-01c8-4e45-845e-12eaa7513189&device_id=2f31d00d-be44-429b-b6a4-cd0c98629c76&device_id=3818a1c8-eb76-46c6-9956-58cbaf5ea315&device_id=237cb2f0-6be6-4584-8ed8-0898b7fd4441&device_id=12606f42-4bd4-4c46-869a-034d53d6e431&device_id=a4e73fe7-cf28-4d45-ad4f-ba65977536de&device_id=a1cd5b9c-26b5-413f-8af6-e2fb9f3d8697&device_id=43362a64-7c50-48f8-b7e2-97a6f3ab6ba6 HTTP/1.1" status: 200 len: 11610 time: 0.0993841
2020-12-03 13:13:20.040 22 INFO neutron.wsgi [req-9f9c61e2-b030-4353-bffa-8f382ca6bff8 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1220 time: 0.0751448
2020-12-03 13:13:20.928 21 INFO neutron.notifiers.nova [-] Nova event response: {'name': 'network-changed', 'server_uuid': '04b615d1-e911-48f9-bdb1-cf950ec49ef2', 'tag': '1c8b47f1-417f-489c-851c-6c0324d33530', 'status': 'completed', 'code': 200}
2020-12-03 13:13:24.141 21 INFO neutron.wsgi [req-2d01b0f2-ff0f-4cf5-a809-4c925e61302f 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0739219
2020-12-03 13:13:31.035 23 INFO neutron.wsgi [req-eff438ac-e970-4da6-a1ca-7c1e091baba2 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0786879
2020-12-03 13:13:43.172 24 INFO neutron.wsgi [req-3873bf33-8b3d-49ea-afcf-a2275e3ebf73 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.1577692
2020-12-03 13:13:50.324 25 INFO neutron.wsgi [req-d7083594-4283-4e93-9d38-86218115d5b2 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0720606
2020-12-03 13:14:10.886 22 INFO neutron.wsgi [req-729dceb9-a192-4c3d-9391-d12b1f87caf7 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0701275
2020-12-03 13:14:24.924 23 INFO neutron.wsgi [req-ad7e2c13-d1da-413c-8717-b833a0ec9ee2 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0735121
2020-12-03 13:15:00.409 23 INFO neutron.wsgi [req-7be099b7-2cbe-4b6f-afb2-8b705a95ebe7 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0840647
2020-12-03 13:15:22.562 22 INFO neutron.wsgi [req-1793182a-c23a-4ef9-92bd-996977254d6c 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0728426
2020-12-03 13:15:55.513 21 INFO neutron.wsgi [req-1b7101eb-1e8e-4aed-b104-5fb8f5bd7f11 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0759442
2020-12-03 13:15:55.964 21 INFO neutron.wsgi [req-312f46f9-b8cb-4728-b355-e746bfca0ce4 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.3001685
2020-12-03 13:15:56.960 21 INFO neutron.wsgi [req-fa65fcf3-3462-4921-9106-5a0e21d9818c 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0778949
2020-12-03 13:18:32.887 22 INFO neutron.wsgi [req-df84343a-cc95-474f-85d8-a9b7ff4c38f6 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.20,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0886633
2020-12-03 13:18:36.410 22 INFO neutron.wsgi [req-9105f6aa-857c-41aa-9355-b69d6d12a0b1 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 186 time: 0.0458112
2020-12-03 13:41:07.999 24 INFO neutron.wsgi [req-9d63c9db-6f54-4add-87eb-5e3e6e53e698 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.2,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2&device_id=4fd42ea9-1a62-43ae-a926-53dd6bc65e2a&device_id=fb8d26c2-1994-4319-9c73-f09f1d66fe5e&device_id=f27e5057-9ef0-46ba-86e0-b5899b8cf190&device_id=fd1a8729-533c-4188-835b-6be050cf2dc0&device_id=fd26c490-8312-4933-ab15-18cbdd57ddff&device_id=37583344-e791-453f-b502-72a5e9fd38d6&device_id=eb28cae5-01c8-4e45-845e-12eaa7513189&device_id=2f31d00d-be44-429b-b6a4-cd0c98629c76&device_id=3818a1c8-eb76-46c6-9956-58cbaf5ea315&device_id=237cb2f0-6be6-4584-8ed8-0898b7fd4441&device_id=12606f42-4bd4-4c46-869a-034d53d6e431&device_id=a4e73fe7-cf28-4d45-ad4f-ba65977536de&device_id=a1cd5b9c-26b5-413f-8af6-e2fb9f3d8697&device_id=43362a64-7c50-48f8-b7e2-97a6f3ab6ba6 HTTP/1.1" status: 200 len: 11610 time: 0.1755400
2020-12-03 13:41:10.122 22 INFO neutron.wsgi [req-3bd33e0c-2501-4e9c-869c-1ec2bc60c108 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.2,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2&device_id=4fd42ea9-1a62-43ae-a926-53dd6bc65e2a&device_id=fb8d26c2-1994-4319-9c73-f09f1d66fe5e&device_id=f27e5057-9ef0-46ba-86e0-b5899b8cf190&device_id=fd1a8729-533c-4188-835b-6be050cf2dc0&device_id=fd26c490-8312-4933-ab15-18cbdd57ddff&device_id=37583344-e791-453f-b502-72a5e9fd38d6&device_id=eb28cae5-01c8-4e45-845e-12eaa7513189&device_id=2f31d00d-be44-429b-b6a4-cd0c98629c76&device_id=3818a1c8-eb76-46c6-9956-58cbaf5ea315&device_id=237cb2f0-6be6-4584-8ed8-0898b7fd4441&device_id=12606f42-4bd4-4c46-869a-034d53d6e431&device_id=a4e73fe7-cf28-4d45-ad4f-ba65977536de&device_id=a1cd5b9c-26b5-413f-8af6-e2fb9f3d8697&device_id=43362a64-7c50-48f8-b7e2-97a6f3ab6ba6 HTTP/1.1" status: 200 len: 11610 time: 0.0958652
2020-12-03 14:00:14.210 22 INFO neutron.wsgi [req-c8acbe0a-1521-42a6-8b87-31cadefc6146 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 186 time: 0.1293921
2020-12-03 14:00:18.245 21 INFO neutron.wsgi [req-6444cb10-83be-4021-94d9-bbb1ea54cbd7 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.20,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 186 time: 0.0402567
2020-12-03 14:00:19.818 23 INFO neutron.wsgi [req-6f84e814-cb45-4ba6-af33-eef58898fc80 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 186 time: 0.0474041
2020-12-03 14:00:21.362 25 INFO neutron.wsgi [req-b2ee3b57-066c-4838-aa4c-6620408f102a 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 186 time: 0.0458882
So I think neutron is responding something back to nova.
I had a look to neutron-openvswitch-agent.log too:
2020-12-03 13:13:29.534 6 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Port 1c8b47f1-417f-489c-851c-6c0324d33530 updated. Details: {'device': '1c8b47f1-417f-489c-851c-6c0324d33530', 'device_id': '04b615d1-e911-48f9-bdb1-cf950ec49ef2', 'network_id': '306e8fb3-d50e-4143-81f2-41735483335a', 'port_id': '1c8b47f1-417f-489c-851c-6c0324d33530', 'mac_address': 'fa:16:3e:fc:fa:ee', 'admin_state_up': True, 'network_type': 'vxlan', 'segmentation_id': 13, 'physical_network': None, 'fixed_ips': [{'subnet_id': '864f5694-7c20-460a-be52-5911df0f0699', 'ip_address': '192.168.6.37'}], 'device_owner': 'compute:nova', 'allowed_address_pairs': [], 'port_security_enabled': True, 'qos_policy_id': None, 'network_qos_policy_id': None, 'profile': {}, 'vif_type': 'ovs', 'vnic_type': 'normal', 'security_groups': ['b92ca6e7-6354-4c1e-a781-6be287e270a3']}
2020-12-03 13:13:29.577 6 INFO neutron.agent.securitygroups_rpc [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Preparing filters for devices {'1c8b47f1-417f-489c-851c-6c0324d33530'}
2020-12-03 13:13:31.122 6 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Configuration for devices up ['1c8b47f1-417f-489c-851c-6c0324d33530'] and devices down [] completed.
2020-12-03 13:18:31.815 6 INFO neutron.agent.securitygroups_rpc [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Remove device filter for {'1c8b47f1-417f-489c-851c-6c0324d33530'}
2020-12-03 13:18:32.914 6 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Ports {'1c8b47f1-417f-489c-851c-6c0324d33530'} removed
2020-12-03 13:18:33.762 6 INFO neutron.agent.common.ovs_lib [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Port 1c8b47f1-417f-489c-851c-6c0324d33530 not present in bridge br-int
2020-12-03 13:18:33.763 6 INFO neutron.agent.securitygroups_rpc [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Remove device filter for ['1c8b47f1-417f-489c-851c-6c0324d33530']
And again I can't understand where the culprit is...
It happens on specific networks, like they are blocked/frozen/malfunctioning, if I create instance on them , all the VMs fail; by the way, I'm creating all the networks, blocked or not, in the same manner.
Please find attached some additional log content |
I'm experiencing a problem when spawning a VM, it fails after hitting a timeout while waiting for VIF plugged
From nova-compute.log:
Failed to allocate network(s): nova.exception.VirtualInterfaceCreateException: Virtual Interface creation failed
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] Traceback (most recent call last):
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 6707, in _create_guest_with_network
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] post_xml_callback=post_xml_callback)
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/usr/lib64/python3.6/contextlib.py", line 88, in __exit__
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] next(self.gen)
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py", line 484, in wait_for_instance_event
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] actual_event = event.wait()
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/eventlet/event.py", line 125, in wait
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] result = hub.switch()
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/eventlet/hubs/hub.py", line 298, in switch
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] return self.greenlet.switch()
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] eventlet.timeout.Timeout: 300 seconds
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2]
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] During handling of the above exception, another exception occurred:
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2]
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] Traceback (most recent call last):
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py", line 2398, in _build_and_run_instance
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] accel_info=accel_info)
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 3748, in spawn
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] cleanup_instance_disks=created_disks)
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 6730, in _create_guest_with_network
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] raise exception.VirtualInterfaceCreateException()
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] nova.exception.VirtualInterfaceCreateException: Virtual Interface creation failed
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2]
2020-12-03 13:18:32.771 6 DEBUG nova.compute.utils [req-c9081063-e0a9-4562-9f87-907926001481 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] Virtual Interface creation failed notify_about_instance_usage /var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/utils.py:429
2020-12-03 13:18:32.779 6 ERROR nova.compute.manager [req-c9081063-e0a9-4562-9f87-907926001481 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] Build of instance 04b615d1-e911-48f9-bdb1-cf950ec49ef2 aborted: Failed to allocate the network(s), not rescheduling.: nova.exception.BuildAbortException: Build of instance 04b615d1-e911-48f9-bdb1-cf950ec49ef2 aborted: Failed to allocate the network(s), not rescheduling.
If I check neutron-serve.log I can see:
2020-12-03 13:13:16.247 24 INFO neutron.wsgi [req-605a087b-f708-4e92-a258-5314fa9ffb84 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.2,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 186 time: 0.1332297
2020-12-03 13:13:17.408 23 INFO neutron.wsgi [req-cb46f45f-5a53-4536-ab29-a7858c3a8bbc 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2&device_id=4fd42ea9-1a62-43ae-a926-53dd6bc65e2a&device_id=fb8d26c2-1994-4319-9c73-f09f1d66fe5e&device_id=f27e5057-9ef0-46ba-86e0-b5899b8cf190&device_id=fd1a8729-533c-4188-835b-6be050cf2dc0&device_id=fd26c490-8312-4933-ab15-18cbdd57ddff&device_id=37583344-e791-453f-b502-72a5e9fd38d6&device_id=eb28cae5-01c8-4e45-845e-12eaa7513189&device_id=2f31d00d-be44-429b-b6a4-cd0c98629c76&device_id=3818a1c8-eb76-46c6-9956-58cbaf5ea315&device_id=237cb2f0-6be6-4584-8ed8-0898b7fd4441&device_id=12606f42-4bd4-4c46-869a-034d53d6e431&device_id=a4e73fe7-cf28-4d45-ad4f-ba65977536de&device_id=a1cd5b9c-26b5-413f-8af6-e2fb9f3d8697&device_id=43362a64-7c50-48f8-b7e2-97a6f3ab6ba6 HTTP/1.1" status: 200 len: 11610 time: 0.0993841
2020-12-03 13:13:20.040 22 INFO neutron.wsgi [req-9f9c61e2-b030-4353-bffa-8f382ca6bff8 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1220 time: 0.0751448
2020-12-03 13:13:20.928 21 INFO neutron.notifiers.nova [-] Nova event response: {'name': 'network-changed', 'server_uuid': '04b615d1-e911-48f9-bdb1-cf950ec49ef2', 'tag': '1c8b47f1-417f-489c-851c-6c0324d33530', 'status': 'completed', 'code': 200}
2020-12-03 13:13:24.141 21 INFO neutron.wsgi [req-2d01b0f2-ff0f-4cf5-a809-4c925e61302f 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0739219
2020-12-03 13:13:31.035 23 INFO neutron.wsgi [req-eff438ac-e970-4da6-a1ca-7c1e091baba2 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0786879
2020-12-03 13:13:43.172 24 INFO neutron.wsgi [req-3873bf33-8b3d-49ea-afcf-a2275e3ebf73 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.1577692
2020-12-03 13:13:50.324 25 INFO neutron.wsgi [req-d7083594-4283-4e93-9d38-86218115d5b2 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0720606
2020-12-03 13:14:10.886 22 INFO neutron.wsgi [req-729dceb9-a192-4c3d-9391-d12b1f87caf7 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0701275
2020-12-03 13:14:24.924 23 INFO neutron.wsgi [req-ad7e2c13-d1da-413c-8717-b833a0ec9ee2 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0735121
2020-12-03 13:15:00.409 23 INFO neutron.wsgi [req-7be099b7-2cbe-4b6f-afb2-8b705a95ebe7 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0840647
2020-12-03 13:15:22.562 22 INFO neutron.wsgi [req-1793182a-c23a-4ef9-92bd-996977254d6c 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0728426
2020-12-03 13:15:55.513 21 INFO neutron.wsgi [req-1b7101eb-1e8e-4aed-b104-5fb8f5bd7f11 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0759442
2020-12-03 13:15:55.964 21 INFO neutron.wsgi [req-312f46f9-b8cb-4728-b355-e746bfca0ce4 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.3001685
2020-12-03 13:15:56.960 21 INFO neutron.wsgi [req-fa65fcf3-3462-4921-9106-5a0e21d9818c 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0778949
2020-12-03 13:18:32.887 22 INFO neutron.wsgi [req-df84343a-cc95-474f-85d8-a9b7ff4c38f6 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.20,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0886633
2020-12-03 13:18:36.410 22 INFO neutron.wsgi [req-9105f6aa-857c-41aa-9355-b69d6d12a0b1 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 186 time: 0.0458112
2020-12-03 13:41:07.999 24 INFO neutron.wsgi [req-9d63c9db-6f54-4add-87eb-5e3e6e53e698 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.2,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2&device_id=4fd42ea9-1a62-43ae-a926-53dd6bc65e2a&device_id=fb8d26c2-1994-4319-9c73-f09f1d66fe5e&device_id=f27e5057-9ef0-46ba-86e0-b5899b8cf190&device_id=fd1a8729-533c-4188-835b-6be050cf2dc0&device_id=fd26c490-8312-4933-ab15-18cbdd57ddff&device_id=37583344-e791-453f-b502-72a5e9fd38d6&device_id=eb28cae5-01c8-4e45-845e-12eaa7513189&device_id=2f31d00d-be44-429b-b6a4-cd0c98629c76&device_id=3818a1c8-eb76-46c6-9956-58cbaf5ea315&device_id=237cb2f0-6be6-4584-8ed8-0898b7fd4441&device_id=12606f42-4bd4-4c46-869a-034d53d6e431&device_id=a4e73fe7-cf28-4d45-ad4f-ba65977536de&device_id=a1cd5b9c-26b5-413f-8af6-e2fb9f3d8697&device_id=43362a64-7c50-48f8-b7e2-97a6f3ab6ba6 HTTP/1.1" status: 200 len: 11610 time: 0.1755400
2020-12-03 13:41:10.122 22 INFO neutron.wsgi [req-3bd33e0c-2501-4e9c-869c-1ec2bc60c108 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.2,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2&device_id=4fd42ea9-1a62-43ae-a926-53dd6bc65e2a&device_id=fb8d26c2-1994-4319-9c73-f09f1d66fe5e&device_id=f27e5057-9ef0-46ba-86e0-b5899b8cf190&device_id=fd1a8729-533c-4188-835b-6be050cf2dc0&device_id=fd26c490-8312-4933-ab15-18cbdd57ddff&device_id=37583344-e791-453f-b502-72a5e9fd38d6&device_id=eb28cae5-01c8-4e45-845e-12eaa7513189&device_id=2f31d00d-be44-429b-b6a4-cd0c98629c76&device_id=3818a1c8-eb76-46c6-9956-58cbaf5ea315&device_id=237cb2f0-6be6-4584-8ed8-0898b7fd4441&device_id=12606f42-4bd4-4c46-869a-034d53d6e431&device_id=a4e73fe7-cf28-4d45-ad4f-ba65977536de&device_id=a1cd5b9c-26b5-413f-8af6-e2fb9f3d8697&device_id=43362a64-7c50-48f8-b7e2-97a6f3ab6ba6 HTTP/1.1" status: 200 len: 11610 time: 0.0958652
2020-12-03 14:00:14.210 22 INFO neutron.wsgi [req-c8acbe0a-1521-42a6-8b87-31cadefc6146 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 186 time: 0.1293921
2020-12-03 14:00:18.245 21 INFO neutron.wsgi [req-6444cb10-83be-4021-94d9-bbb1ea54cbd7 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.20,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 186 time: 0.0402567
2020-12-03 14:00:19.818 23 INFO neutron.wsgi [req-6f84e814-cb45-4ba6-af33-eef58898fc80 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 186 time: 0.0474041
2020-12-03 14:00:21.362 25 INFO neutron.wsgi [req-b2ee3b57-066c-4838-aa4c-6620408f102a 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 186 time: 0.0458882
So I think neutron is responding something back to nova.
I had a look to neutron-openvswitch-agent.log too:
2020-12-03 13:13:29.534 6 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Port 1c8b47f1-417f-489c-851c-6c0324d33530 updated. Details: {'device': '1c8b47f1-417f-489c-851c-6c0324d33530', 'device_id': '04b615d1-e911-48f9-bdb1-cf950ec49ef2', 'network_id': '306e8fb3-d50e-4143-81f2-41735483335a', 'port_id': '1c8b47f1-417f-489c-851c-6c0324d33530', 'mac_address': 'fa:16:3e:fc:fa:ee', 'admin_state_up': True, 'network_type': 'vxlan', 'segmentation_id': 13, 'physical_network': None, 'fixed_ips': [{'subnet_id': '864f5694-7c20-460a-be52-5911df0f0699', 'ip_address': '192.168.6.37'}], 'device_owner': 'compute:nova', 'allowed_address_pairs': [], 'port_security_enabled': True, 'qos_policy_id': None, 'network_qos_policy_id': None, 'profile': {}, 'vif_type': 'ovs', 'vnic_type': 'normal', 'security_groups': ['b92ca6e7-6354-4c1e-a781-6be287e270a3']}
2020-12-03 13:13:29.577 6 INFO neutron.agent.securitygroups_rpc [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Preparing filters for devices {'1c8b47f1-417f-489c-851c-6c0324d33530'}
2020-12-03 13:13:31.122 6 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Configuration for devices up ['1c8b47f1-417f-489c-851c-6c0324d33530'] and devices down [] completed.
2020-12-03 13:18:31.815 6 INFO neutron.agent.securitygroups_rpc [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Remove device filter for {'1c8b47f1-417f-489c-851c-6c0324d33530'}
2020-12-03 13:18:32.914 6 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Ports {'1c8b47f1-417f-489c-851c-6c0324d33530'} removed
2020-12-03 13:18:33.762 6 INFO neutron.agent.common.ovs_lib [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Port 1c8b47f1-417f-489c-851c-6c0324d33530 not present in bridge br-int
2020-12-03 13:18:33.763 6 INFO neutron.agent.securitygroups_rpc [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Remove device filter for ['1c8b47f1-417f-489c-851c-6c0324d33530']
And again I can't understand where the culprit is...
It happens on specific networks, like they are blocked/frozen/malfunctioning, if I create instance on them , all the VMs fail; by the way, I'm creating all the networks, blocked or not, in the same manner.
I'm using Victoria installed by Kolla-Ansible, 3 nodes working as controller+compute+ceph
Please find attached some additional log content |
|
| 2020-12-03 16:07:57 |
loudgefly |
description |
I'm experiencing a problem when spawning a VM, it fails after hitting a timeout while waiting for VIF plugged
From nova-compute.log:
Failed to allocate network(s): nova.exception.VirtualInterfaceCreateException: Virtual Interface creation failed
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] Traceback (most recent call last):
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 6707, in _create_guest_with_network
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] post_xml_callback=post_xml_callback)
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/usr/lib64/python3.6/contextlib.py", line 88, in __exit__
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] next(self.gen)
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py", line 484, in wait_for_instance_event
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] actual_event = event.wait()
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/eventlet/event.py", line 125, in wait
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] result = hub.switch()
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/eventlet/hubs/hub.py", line 298, in switch
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] return self.greenlet.switch()
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] eventlet.timeout.Timeout: 300 seconds
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2]
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] During handling of the above exception, another exception occurred:
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2]
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] Traceback (most recent call last):
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py", line 2398, in _build_and_run_instance
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] accel_info=accel_info)
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 3748, in spawn
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] cleanup_instance_disks=created_disks)
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 6730, in _create_guest_with_network
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] raise exception.VirtualInterfaceCreateException()
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] nova.exception.VirtualInterfaceCreateException: Virtual Interface creation failed
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2]
2020-12-03 13:18:32.771 6 DEBUG nova.compute.utils [req-c9081063-e0a9-4562-9f87-907926001481 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] Virtual Interface creation failed notify_about_instance_usage /var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/utils.py:429
2020-12-03 13:18:32.779 6 ERROR nova.compute.manager [req-c9081063-e0a9-4562-9f87-907926001481 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] Build of instance 04b615d1-e911-48f9-bdb1-cf950ec49ef2 aborted: Failed to allocate the network(s), not rescheduling.: nova.exception.BuildAbortException: Build of instance 04b615d1-e911-48f9-bdb1-cf950ec49ef2 aborted: Failed to allocate the network(s), not rescheduling.
If I check neutron-serve.log I can see:
2020-12-03 13:13:16.247 24 INFO neutron.wsgi [req-605a087b-f708-4e92-a258-5314fa9ffb84 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.2,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 186 time: 0.1332297
2020-12-03 13:13:17.408 23 INFO neutron.wsgi [req-cb46f45f-5a53-4536-ab29-a7858c3a8bbc 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2&device_id=4fd42ea9-1a62-43ae-a926-53dd6bc65e2a&device_id=fb8d26c2-1994-4319-9c73-f09f1d66fe5e&device_id=f27e5057-9ef0-46ba-86e0-b5899b8cf190&device_id=fd1a8729-533c-4188-835b-6be050cf2dc0&device_id=fd26c490-8312-4933-ab15-18cbdd57ddff&device_id=37583344-e791-453f-b502-72a5e9fd38d6&device_id=eb28cae5-01c8-4e45-845e-12eaa7513189&device_id=2f31d00d-be44-429b-b6a4-cd0c98629c76&device_id=3818a1c8-eb76-46c6-9956-58cbaf5ea315&device_id=237cb2f0-6be6-4584-8ed8-0898b7fd4441&device_id=12606f42-4bd4-4c46-869a-034d53d6e431&device_id=a4e73fe7-cf28-4d45-ad4f-ba65977536de&device_id=a1cd5b9c-26b5-413f-8af6-e2fb9f3d8697&device_id=43362a64-7c50-48f8-b7e2-97a6f3ab6ba6 HTTP/1.1" status: 200 len: 11610 time: 0.0993841
2020-12-03 13:13:20.040 22 INFO neutron.wsgi [req-9f9c61e2-b030-4353-bffa-8f382ca6bff8 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1220 time: 0.0751448
2020-12-03 13:13:20.928 21 INFO neutron.notifiers.nova [-] Nova event response: {'name': 'network-changed', 'server_uuid': '04b615d1-e911-48f9-bdb1-cf950ec49ef2', 'tag': '1c8b47f1-417f-489c-851c-6c0324d33530', 'status': 'completed', 'code': 200}
2020-12-03 13:13:24.141 21 INFO neutron.wsgi [req-2d01b0f2-ff0f-4cf5-a809-4c925e61302f 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0739219
2020-12-03 13:13:31.035 23 INFO neutron.wsgi [req-eff438ac-e970-4da6-a1ca-7c1e091baba2 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0786879
2020-12-03 13:13:43.172 24 INFO neutron.wsgi [req-3873bf33-8b3d-49ea-afcf-a2275e3ebf73 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.1577692
2020-12-03 13:13:50.324 25 INFO neutron.wsgi [req-d7083594-4283-4e93-9d38-86218115d5b2 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0720606
2020-12-03 13:14:10.886 22 INFO neutron.wsgi [req-729dceb9-a192-4c3d-9391-d12b1f87caf7 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0701275
2020-12-03 13:14:24.924 23 INFO neutron.wsgi [req-ad7e2c13-d1da-413c-8717-b833a0ec9ee2 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0735121
2020-12-03 13:15:00.409 23 INFO neutron.wsgi [req-7be099b7-2cbe-4b6f-afb2-8b705a95ebe7 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0840647
2020-12-03 13:15:22.562 22 INFO neutron.wsgi [req-1793182a-c23a-4ef9-92bd-996977254d6c 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0728426
2020-12-03 13:15:55.513 21 INFO neutron.wsgi [req-1b7101eb-1e8e-4aed-b104-5fb8f5bd7f11 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0759442
2020-12-03 13:15:55.964 21 INFO neutron.wsgi [req-312f46f9-b8cb-4728-b355-e746bfca0ce4 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.3001685
2020-12-03 13:15:56.960 21 INFO neutron.wsgi [req-fa65fcf3-3462-4921-9106-5a0e21d9818c 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0778949
2020-12-03 13:18:32.887 22 INFO neutron.wsgi [req-df84343a-cc95-474f-85d8-a9b7ff4c38f6 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.20,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0886633
2020-12-03 13:18:36.410 22 INFO neutron.wsgi [req-9105f6aa-857c-41aa-9355-b69d6d12a0b1 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 186 time: 0.0458112
2020-12-03 13:41:07.999 24 INFO neutron.wsgi [req-9d63c9db-6f54-4add-87eb-5e3e6e53e698 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.2,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2&device_id=4fd42ea9-1a62-43ae-a926-53dd6bc65e2a&device_id=fb8d26c2-1994-4319-9c73-f09f1d66fe5e&device_id=f27e5057-9ef0-46ba-86e0-b5899b8cf190&device_id=fd1a8729-533c-4188-835b-6be050cf2dc0&device_id=fd26c490-8312-4933-ab15-18cbdd57ddff&device_id=37583344-e791-453f-b502-72a5e9fd38d6&device_id=eb28cae5-01c8-4e45-845e-12eaa7513189&device_id=2f31d00d-be44-429b-b6a4-cd0c98629c76&device_id=3818a1c8-eb76-46c6-9956-58cbaf5ea315&device_id=237cb2f0-6be6-4584-8ed8-0898b7fd4441&device_id=12606f42-4bd4-4c46-869a-034d53d6e431&device_id=a4e73fe7-cf28-4d45-ad4f-ba65977536de&device_id=a1cd5b9c-26b5-413f-8af6-e2fb9f3d8697&device_id=43362a64-7c50-48f8-b7e2-97a6f3ab6ba6 HTTP/1.1" status: 200 len: 11610 time: 0.1755400
2020-12-03 13:41:10.122 22 INFO neutron.wsgi [req-3bd33e0c-2501-4e9c-869c-1ec2bc60c108 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.2,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2&device_id=4fd42ea9-1a62-43ae-a926-53dd6bc65e2a&device_id=fb8d26c2-1994-4319-9c73-f09f1d66fe5e&device_id=f27e5057-9ef0-46ba-86e0-b5899b8cf190&device_id=fd1a8729-533c-4188-835b-6be050cf2dc0&device_id=fd26c490-8312-4933-ab15-18cbdd57ddff&device_id=37583344-e791-453f-b502-72a5e9fd38d6&device_id=eb28cae5-01c8-4e45-845e-12eaa7513189&device_id=2f31d00d-be44-429b-b6a4-cd0c98629c76&device_id=3818a1c8-eb76-46c6-9956-58cbaf5ea315&device_id=237cb2f0-6be6-4584-8ed8-0898b7fd4441&device_id=12606f42-4bd4-4c46-869a-034d53d6e431&device_id=a4e73fe7-cf28-4d45-ad4f-ba65977536de&device_id=a1cd5b9c-26b5-413f-8af6-e2fb9f3d8697&device_id=43362a64-7c50-48f8-b7e2-97a6f3ab6ba6 HTTP/1.1" status: 200 len: 11610 time: 0.0958652
2020-12-03 14:00:14.210 22 INFO neutron.wsgi [req-c8acbe0a-1521-42a6-8b87-31cadefc6146 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 186 time: 0.1293921
2020-12-03 14:00:18.245 21 INFO neutron.wsgi [req-6444cb10-83be-4021-94d9-bbb1ea54cbd7 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.20,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 186 time: 0.0402567
2020-12-03 14:00:19.818 23 INFO neutron.wsgi [req-6f84e814-cb45-4ba6-af33-eef58898fc80 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 186 time: 0.0474041
2020-12-03 14:00:21.362 25 INFO neutron.wsgi [req-b2ee3b57-066c-4838-aa4c-6620408f102a 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 186 time: 0.0458882
So I think neutron is responding something back to nova.
I had a look to neutron-openvswitch-agent.log too:
2020-12-03 13:13:29.534 6 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Port 1c8b47f1-417f-489c-851c-6c0324d33530 updated. Details: {'device': '1c8b47f1-417f-489c-851c-6c0324d33530', 'device_id': '04b615d1-e911-48f9-bdb1-cf950ec49ef2', 'network_id': '306e8fb3-d50e-4143-81f2-41735483335a', 'port_id': '1c8b47f1-417f-489c-851c-6c0324d33530', 'mac_address': 'fa:16:3e:fc:fa:ee', 'admin_state_up': True, 'network_type': 'vxlan', 'segmentation_id': 13, 'physical_network': None, 'fixed_ips': [{'subnet_id': '864f5694-7c20-460a-be52-5911df0f0699', 'ip_address': '192.168.6.37'}], 'device_owner': 'compute:nova', 'allowed_address_pairs': [], 'port_security_enabled': True, 'qos_policy_id': None, 'network_qos_policy_id': None, 'profile': {}, 'vif_type': 'ovs', 'vnic_type': 'normal', 'security_groups': ['b92ca6e7-6354-4c1e-a781-6be287e270a3']}
2020-12-03 13:13:29.577 6 INFO neutron.agent.securitygroups_rpc [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Preparing filters for devices {'1c8b47f1-417f-489c-851c-6c0324d33530'}
2020-12-03 13:13:31.122 6 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Configuration for devices up ['1c8b47f1-417f-489c-851c-6c0324d33530'] and devices down [] completed.
2020-12-03 13:18:31.815 6 INFO neutron.agent.securitygroups_rpc [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Remove device filter for {'1c8b47f1-417f-489c-851c-6c0324d33530'}
2020-12-03 13:18:32.914 6 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Ports {'1c8b47f1-417f-489c-851c-6c0324d33530'} removed
2020-12-03 13:18:33.762 6 INFO neutron.agent.common.ovs_lib [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Port 1c8b47f1-417f-489c-851c-6c0324d33530 not present in bridge br-int
2020-12-03 13:18:33.763 6 INFO neutron.agent.securitygroups_rpc [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Remove device filter for ['1c8b47f1-417f-489c-851c-6c0324d33530']
And again I can't understand where the culprit is...
It happens on specific networks, like they are blocked/frozen/malfunctioning, if I create instance on them , all the VMs fail; by the way, I'm creating all the networks, blocked or not, in the same manner.
I'm using Victoria installed by Kolla-Ansible, 3 nodes working as controller+compute+ceph
Please find attached some additional log content |
I'm experiencing a problem when spawning a VM, it fails after hitting a timeout while waiting for VIF plugged
From nova-compute.log:
Failed to allocate network(s): nova.exception.VirtualInterfaceCreateException: Virtual Interface creation failed
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] Traceback (most recent call last):
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 6707, in _create_guest_with_network
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] post_xml_callback=post_xml_callback)
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/usr/lib64/python3.6/contextlib.py", line 88, in __exit__
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] next(self.gen)
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py", line 484, in wait_for_instance_event
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] actual_event = event.wait()
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/eventlet/event.py", line 125, in wait
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] result = hub.switch()
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/eventlet/hubs/hub.py", line 298, in switch
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] return self.greenlet.switch()
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] eventlet.timeout.Timeout: 300 seconds
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2]
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] During handling of the above exception, another exception occurred:
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2]
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] Traceback (most recent call last):
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py", line 2398, in _build_and_run_instance
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] accel_info=accel_info)
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 3748, in spawn
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] cleanup_instance_disks=created_disks)
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 6730, in _create_guest_with_network
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] raise exception.VirtualInterfaceCreateException()
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] nova.exception.VirtualInterfaceCreateException: Virtual Interface creation failed
2020-12-03 13:18:32.769 6 ERROR nova.compute.manager [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2]
2020-12-03 13:18:32.771 6 DEBUG nova.compute.utils [req-c9081063-e0a9-4562-9f87-907926001481 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] Virtual Interface creation failed notify_about_instance_usage /var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/utils.py:429
2020-12-03 13:18:32.779 6 ERROR nova.compute.manager [req-c9081063-e0a9-4562-9f87-907926001481 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] [instance: 04b615d1-e911-48f9-bdb1-cf950ec49ef2] Build of instance 04b615d1-e911-48f9-bdb1-cf950ec49ef2 aborted: Failed to allocate the network(s), not rescheduling.: nova.exception.BuildAbortException: Build of instance 04b615d1-e911-48f9-bdb1-cf950ec49ef2 aborted: Failed to allocate the network(s), not rescheduling.
If I check neutron-serve.log I can see:
2020-12-03 13:13:16.247 24 INFO neutron.wsgi [req-605a087b-f708-4e92-a258-5314fa9ffb84 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.2,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 186 time: 0.1332297
2020-12-03 13:13:17.408 23 INFO neutron.wsgi [req-cb46f45f-5a53-4536-ab29-a7858c3a8bbc 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2&device_id=4fd42ea9-1a62-43ae-a926-53dd6bc65e2a&device_id=fb8d26c2-1994-4319-9c73-f09f1d66fe5e&device_id=f27e5057-9ef0-46ba-86e0-b5899b8cf190&device_id=fd1a8729-533c-4188-835b-6be050cf2dc0&device_id=fd26c490-8312-4933-ab15-18cbdd57ddff&device_id=37583344-e791-453f-b502-72a5e9fd38d6&device_id=eb28cae5-01c8-4e45-845e-12eaa7513189&device_id=2f31d00d-be44-429b-b6a4-cd0c98629c76&device_id=3818a1c8-eb76-46c6-9956-58cbaf5ea315&device_id=237cb2f0-6be6-4584-8ed8-0898b7fd4441&device_id=12606f42-4bd4-4c46-869a-034d53d6e431&device_id=a4e73fe7-cf28-4d45-ad4f-ba65977536de&device_id=a1cd5b9c-26b5-413f-8af6-e2fb9f3d8697&device_id=43362a64-7c50-48f8-b7e2-97a6f3ab6ba6 HTTP/1.1" status: 200 len: 11610 time: 0.0993841
2020-12-03 13:13:20.040 22 INFO neutron.wsgi [req-9f9c61e2-b030-4353-bffa-8f382ca6bff8 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1220 time: 0.0751448
2020-12-03 13:13:20.928 21 INFO neutron.notifiers.nova [-] Nova event response: {'name': 'network-changed', 'server_uuid': '04b615d1-e911-48f9-bdb1-cf950ec49ef2', 'tag': '1c8b47f1-417f-489c-851c-6c0324d33530', 'status': 'completed', 'code': 200}
2020-12-03 13:13:24.141 21 INFO neutron.wsgi [req-2d01b0f2-ff0f-4cf5-a809-4c925e61302f 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0739219
2020-12-03 13:13:31.035 23 INFO neutron.wsgi [req-eff438ac-e970-4da6-a1ca-7c1e091baba2 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0786879
2020-12-03 13:13:43.172 24 INFO neutron.wsgi [req-3873bf33-8b3d-49ea-afcf-a2275e3ebf73 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.1577692
2020-12-03 13:13:50.324 25 INFO neutron.wsgi [req-d7083594-4283-4e93-9d38-86218115d5b2 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0720606
2020-12-03 13:14:10.886 22 INFO neutron.wsgi [req-729dceb9-a192-4c3d-9391-d12b1f87caf7 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0701275
2020-12-03 13:14:24.924 23 INFO neutron.wsgi [req-ad7e2c13-d1da-413c-8717-b833a0ec9ee2 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0735121
2020-12-03 13:15:00.409 23 INFO neutron.wsgi [req-7be099b7-2cbe-4b6f-afb2-8b705a95ebe7 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0840647
2020-12-03 13:15:22.562 22 INFO neutron.wsgi [req-1793182a-c23a-4ef9-92bd-996977254d6c 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0728426
2020-12-03 13:15:55.513 21 INFO neutron.wsgi [req-1b7101eb-1e8e-4aed-b104-5fb8f5bd7f11 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0759442
2020-12-03 13:15:55.964 21 INFO neutron.wsgi [req-312f46f9-b8cb-4728-b355-e746bfca0ce4 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.3001685
2020-12-03 13:15:56.960 21 INFO neutron.wsgi [req-fa65fcf3-3462-4921-9106-5a0e21d9818c 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0778949
2020-12-03 13:18:32.887 22 INFO neutron.wsgi [req-df84343a-cc95-474f-85d8-a9b7ff4c38f6 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.20,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 1325 time: 0.0886633
2020-12-03 13:18:36.410 22 INFO neutron.wsgi [req-9105f6aa-857c-41aa-9355-b69d6d12a0b1 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 186 time: 0.0458112
2020-12-03 13:41:07.999 24 INFO neutron.wsgi [req-9d63c9db-6f54-4add-87eb-5e3e6e53e698 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.2,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2&device_id=4fd42ea9-1a62-43ae-a926-53dd6bc65e2a&device_id=fb8d26c2-1994-4319-9c73-f09f1d66fe5e&device_id=f27e5057-9ef0-46ba-86e0-b5899b8cf190&device_id=fd1a8729-533c-4188-835b-6be050cf2dc0&device_id=fd26c490-8312-4933-ab15-18cbdd57ddff&device_id=37583344-e791-453f-b502-72a5e9fd38d6&device_id=eb28cae5-01c8-4e45-845e-12eaa7513189&device_id=2f31d00d-be44-429b-b6a4-cd0c98629c76&device_id=3818a1c8-eb76-46c6-9956-58cbaf5ea315&device_id=237cb2f0-6be6-4584-8ed8-0898b7fd4441&device_id=12606f42-4bd4-4c46-869a-034d53d6e431&device_id=a4e73fe7-cf28-4d45-ad4f-ba65977536de&device_id=a1cd5b9c-26b5-413f-8af6-e2fb9f3d8697&device_id=43362a64-7c50-48f8-b7e2-97a6f3ab6ba6 HTTP/1.1" status: 200 len: 11610 time: 0.1755400
2020-12-03 13:41:10.122 22 INFO neutron.wsgi [req-3bd33e0c-2501-4e9c-869c-1ec2bc60c108 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.2,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2&device_id=4fd42ea9-1a62-43ae-a926-53dd6bc65e2a&device_id=fb8d26c2-1994-4319-9c73-f09f1d66fe5e&device_id=f27e5057-9ef0-46ba-86e0-b5899b8cf190&device_id=fd1a8729-533c-4188-835b-6be050cf2dc0&device_id=fd26c490-8312-4933-ab15-18cbdd57ddff&device_id=37583344-e791-453f-b502-72a5e9fd38d6&device_id=eb28cae5-01c8-4e45-845e-12eaa7513189&device_id=2f31d00d-be44-429b-b6a4-cd0c98629c76&device_id=3818a1c8-eb76-46c6-9956-58cbaf5ea315&device_id=237cb2f0-6be6-4584-8ed8-0898b7fd4441&device_id=12606f42-4bd4-4c46-869a-034d53d6e431&device_id=a4e73fe7-cf28-4d45-ad4f-ba65977536de&device_id=a1cd5b9c-26b5-413f-8af6-e2fb9f3d8697&device_id=43362a64-7c50-48f8-b7e2-97a6f3ab6ba6 HTTP/1.1" status: 200 len: 11610 time: 0.0958652
2020-12-03 14:00:14.210 22 INFO neutron.wsgi [req-c8acbe0a-1521-42a6-8b87-31cadefc6146 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 186 time: 0.1293921
2020-12-03 14:00:18.245 21 INFO neutron.wsgi [req-6444cb10-83be-4021-94d9-bbb1ea54cbd7 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.20,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 186 time: 0.0402567
2020-12-03 14:00:19.818 23 INFO neutron.wsgi [req-6f84e814-cb45-4ba6-af33-eef58898fc80 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 186 time: 0.0474041
2020-12-03 14:00:21.362 25 INFO neutron.wsgi [req-b2ee3b57-066c-4838-aa4c-6620408f102a 0da1bc1a3acc45d0aca57e504c04ea17 63be5b4f4d784088b73cd36e6114f00e - default default] 10.31.10.3,10.31.10.1 "GET /v2.0/ports?device_id=04b615d1-e911-48f9-bdb1-cf950ec49ef2 HTTP/1.1" status: 200 len: 186 time: 0.0458882
So I think neutron is responding something back to nova.
I had a look to neutron-openvswitch-agent.log too:
2020-12-03 13:13:29.534 6 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Port 1c8b47f1-417f-489c-851c-6c0324d33530 updated. Details: {'device': '1c8b47f1-417f-489c-851c-6c0324d33530', 'device_id': '04b615d1-e911-48f9-bdb1-cf950ec49ef2', 'network_id': '306e8fb3-d50e-4143-81f2-41735483335a', 'port_id': '1c8b47f1-417f-489c-851c-6c0324d33530', 'mac_address': 'fa:16:3e:fc:fa:ee', 'admin_state_up': True, 'network_type': 'vxlan', 'segmentation_id': 13, 'physical_network': None, 'fixed_ips': [{'subnet_id': '864f5694-7c20-460a-be52-5911df0f0699', 'ip_address': '192.168.6.37'}], 'device_owner': 'compute:nova', 'allowed_address_pairs': [], 'port_security_enabled': True, 'qos_policy_id': None, 'network_qos_policy_id': None, 'profile': {}, 'vif_type': 'ovs', 'vnic_type': 'normal', 'security_groups': ['b92ca6e7-6354-4c1e-a781-6be287e270a3']}
2020-12-03 13:13:29.577 6 INFO neutron.agent.securitygroups_rpc [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Preparing filters for devices {'1c8b47f1-417f-489c-851c-6c0324d33530'}
2020-12-03 13:13:31.122 6 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Configuration for devices up ['1c8b47f1-417f-489c-851c-6c0324d33530'] and devices down [] completed.
2020-12-03 13:18:31.815 6 INFO neutron.agent.securitygroups_rpc [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Remove device filter for {'1c8b47f1-417f-489c-851c-6c0324d33530'}
2020-12-03 13:18:32.914 6 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Ports {'1c8b47f1-417f-489c-851c-6c0324d33530'} removed
2020-12-03 13:18:33.762 6 INFO neutron.agent.common.ovs_lib [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Port 1c8b47f1-417f-489c-851c-6c0324d33530 not present in bridge br-int
2020-12-03 13:18:33.763 6 INFO neutron.agent.securitygroups_rpc [req-27ce6155-24f3-4afa-aa96-d02f25555e13 - - - - -] Remove device filter for ['1c8b47f1-417f-489c-851c-6c0324d33530']
And again I can't understand where the culprit is...
It happens on specific networks, like they are blocked/frozen/malfunctioning, if I create instance on them , all the VMs fail; by the way, I'm creating all the networks, blocked or not, in the same manner.
Please find attached some additional log content
I'm using Victoria installed by Kolla-Ansible on 3 nodes acting as controller+compute+ceph node |
|
