Bug 1633759 - VM fails to spawn. VIF creation failed with a database error. Duplicate entry 'fa:16:3e:2b:7c:fe/0a57d046-03a3-413a-b7ba-dc948204824c-0' for key 'uniq_virtual_interfaces0address0deleted'
Summary: VM fails to spawn. VIF creation failed with a database error. Duplicate entry...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat OpenStack
Classification: Red Hat
Component: openstack-nova
Version: 10.0 (Newton)
Hardware: x86_64
OS: Linux
high
high
Target Milestone: z9
: 16.1 (Train on RHEL 8.2)
Assignee: René Ribaud
QA Contact: James Parker
URL:
Whiteboard:
Depends On:
Blocks: 2051653 2051880
TreeView+ depends on / blocked
 
Reported: 2018-09-27 16:40 UTC by Mircea Vutcovici
Modified: 2023-09-18 00:14 UTC (History)
19 users (show)

Fixed In Version: openstack-nova-20.4.1-1.20220307123812.1ee93b9
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
: 2051653 2051880 (view as bug list)
Environment:
Last Closed: 2022-12-07 20:24:45 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Launchpad 1821088 0 None None None 2022-01-31 12:33:30 UTC
OpenStack gerrit 827070 0 None MERGED api: Reject duplicate port IDs in server create 2022-11-01 14:27:21 UTC
Red Hat Issue Tracker OSP-12379 0 None None None 2022-01-31 12:26:49 UTC
Red Hat Product Errata RHBA-2022:8795 0 None None None 2022-12-07 20:25:20 UTC

Description Mircea Vutcovici 2018-09-27 16:40:34 UTC
Description of problem:
VM is failing to spawn. Here are relevant errors:
nova-compute.log
Error: Build of instance ecd66ca0-e67a-4a68-9b04-5b592dcb6f42 aborted: Failed to allocate the network(s), not rescheduling
nova-conductor.log
Duplicate entry 'fa:16:3e:2b:7c:fe/0a57d046-03a3-413a-b7ba-dc948204824c-0' for key 'uniq_virtual_interfaces0address0deleted'

Version-Release number of selected component (if applicable):
OpenStack 10

How reproducible:
all the time

Steps to Reproduce:
1. openstack stack create -t f5fw.yaml. f5fw
2.
3.

Actual results:
nova-compute.log:
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [req-f72ffc80-a908-4f85-84a9-fe64b76e69d0 29a29f239503979667b63a45b276b7c0950620f6ccc462d1a659b0f54f7d0455 572ea77207944299ae64edffb856c5d6 - - -] [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1] Failed to allocate network(s)
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1] Traceback (most recent call last):
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1928, in _build_and_run_instance
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     block_device_info=block_device_info)
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 2669, in spawn
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     block_device_info=block_device_info)
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4769, in _get_guest_xml
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     network_info_str = str(network_info)
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/nova/network/model.py", line 538, in __str__
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     return self._sync_wrapper(fn, *args, **kwargs)
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/nova/network/model.py", line 521, in _sync_wrapper
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     self.wait()
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/nova/network/model.py", line 553, in wait
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     self[:] = self._gt.wait()
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/eventlet/greenthread.py", line 175, in wait
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     return self._exit_event.wait()
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/eventlet/event.py", line 125, in wait
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     current.throw(*self._exc)
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/eventlet/greenthread.py", line 214, in main
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     result = function(*args, **kwargs)
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/nova/utils.py", line 1066, in context_wrapper
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     return func(*args, **kwargs)
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1418, in _allocate_network_async
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     six.reraise(*exc_info)
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1401, in _allocate_network_async
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     bind_host_id=bind_host_id)
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py", line 894, in allocate_for_instance
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     bind_host_id, dhcp_opts, available_macs)
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py", line 1013, in _update_ports_for_instance
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     vif.destroy()
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     self.force_reraise()
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     six.reraise(self.type_, self.value, self.tb)
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py", line 996, in _update_ports_for_instance
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     vifobj.create()
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/oslo_versionedobjects/base.py", line 210, in wrapper
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     ctxt, self, fn.__name__, args, kwargs)
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/nova/conductor/rpcapi.py", line 241, in object_action
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     objmethod=objmethod, args=args, kwargs=kwargs)
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/client.py", line 169, in call
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     retry=self.retry)
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/oslo_messaging/transport.py", line 97, in _send
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     timeout=timeout, retry=retry)
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 584, in send
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     retry=retry)
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 575, in _send
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     raise result
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1] VirtualInterfaceCreateException_Remote: Virtual Interface creation failed
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1] Traceback (most recent call last):
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1] 
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/nova/conductor/manager.py", line 87, in _object_dispatch
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     return getattr(target, method)(*args, **kwargs)
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1] 
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/oslo_versionedobjects/base.py", line 226, in wrapper
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     return fn(self, *args, **kwargs)
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1] 
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/nova/objects/virtual_interface.py", line 97, in create
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     db_vif = db.virtual_interface_create(self._context, updates)
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1] 
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/nova/db/api.py", line 659, in virtual_interface_create
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     return IMPL.virtual_interface_create(context, values)
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1] 
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 169, in wrapper
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     return f(*args, **kwargs)
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1] 
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 240, in wrapped
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     return f(context, *args, **kwargs)
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1] 
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 1556, in virtual_interface_create
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     raise exception.VirtualInterfaceCreateException()
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1] 
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1] VirtualInterfaceCreateException: Virtual Interface creation failed
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1] 
2018-09-26 16:53:05.171 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1] 
2018-09-26 16:53:05.174 79276 ERROR nova.compute.manager [req-f72ffc80-a908-4f85-84a9-fe64b76e69d0 29a29f239503979667b63a45b276b7c0950620f6ccc462d1a659b0f54f7d0455 572ea77207944299ae64edffb856c5d6 - - -] [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1] Build of instance fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1 aborted: Failed to allocate the network(s), not rescheduling.
2018-09-26 16:53:05.174 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1] Traceback (most recent call last):
2018-09-26 16:53:05.174 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1787, in _do_build_and_run_instance
2018-09-26 16:53:05.174 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     filter_properties)
2018-09-26 16:53:05.174 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1968, in _build_and_run_instance
2018-09-26 16:53:05.174 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1]     reason=msg)
2018-09-26 16:53:05.174 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1] BuildAbortException: Build of instance fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1 aborted: Failed to allocate the network(s), not rescheduling.
2018-09-26 16:53:05.174 79276 ERROR nova.compute.manager [instance: fd51cc14-dd35-4ed9-89c5-6e6aac1c49c1] 

nova-conductor.log:
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api [req-1c4a0038-0c66-47b7-ba49-b735925f163f 29a29f239503979667b63a45b276b7c0950620f6ccc462d1a659b0f54f7d0455 572ea77207944299ae64edffb856c5d6 - - -] VIF creation failed with a database error.
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api Traceback (most recent call last):
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 1553, in virtual_interface_create
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     vif_ref.save(context.session)
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/models.py", line 48, in save
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     session.flush()
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2027, in flush
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     self._flush(objects)
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2145, in _flush
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     transaction.rollback(_capture_exception=True)
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     compat.reraise(exc_type, exc_value, exc_tb)
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2109, in _flush
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     flush_context.execute()
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 373, in execute
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     rec.execute(self)
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 532, in execute
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     uow
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 174, in save_obj
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     mapper, table, insert)
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 800, in _emit_insert_statements
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     execute(statement, params)
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 914, in execute
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     return meth(self, multiparams, params)
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/sql/elements.py", line 323, in _execute_on_connection
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     return connection._execute_clauseelement(self, multiparams, params)
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1010, in _execute_clauseelement
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     compiled_sql, distilled_params
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1146, in _execute_context
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     context)
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1337, in _handle_dbapi_exception
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     util.raise_from_cause(newraise, exc_info)
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/compat.py", line 200, in raise_from_cause
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     reraise(type(exception), exception, tb=exc_tb)
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1139, in _execute_context
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     context)
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py", line 450, in do_execute
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     cursor.execute(statement, parameters)
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 166, in execute
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     result = self._query(query)
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 322, in _query
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     conn.query(q)
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 841, in query
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1029, in _read_query_result
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     result.read()
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1312, in read
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     first_packet = self.connection._read_packet()
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 991, in _read_packet
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     packet.check_error()
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 393, in check_error
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     err.raise_mysql_exception(self._data)
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api   File "/usr/lib/python2.7/site-packages/pymysql/err.py", line 107, in raise_mysql_exception
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api     raise errorclass(errno, errval)
2018-08-15 20:20:06.969 5179 ERROR nova.db.sqlalchemy.api DBDuplicateEntry: (pymysql.err.IntegrityError) (1062, u"Duplicate entry 'fa:16:3e:1a:c3:39/0904bbe4-7075-430e-84c4-5768b6decd9d-0' for key 'uniq_virtual_interfaces0address0deleted'") [SQL: u'INSERT INTO virtual_interfaces (created_at, updated_at, deleted_at, deleted, address, network_id, instance_uuid, uuid, tag) VALUES (%(created_at)s, %(updated_at)s, %(deleted_at)s, %(deleted)s, %(address)s, %(network_id)s, %(instance_uuid)s, %(uuid)s, %(tag)s)'] [parameters: {'instance_uuid': '52181b43-4833-433a-95d6-d7e065d326b0', 'uuid': '0904bbe4-7075-430e-84c4-5768b6decd9d', 'network_id': None, 'created_at': datetime.datetime(2018, 8, 15, 20, 20, 6, 968583), 'updated_at': None, 'deleted': 0, 'tag': None, 'address': u'fa:16:3e:1a:c3:39/0904bbe4-7075-430e-84c4-5768b6decd9d', 'deleted_at': None}]



Expected results:


Additional info:

Comment 3 smooney 2018-10-02 23:15:14 UTC
from the inital tracback the error would appear to be related to how the 
f5 vnf was deployedn using heat.

can the f5fw.yaml and a full set of SOSReport logs be provided to confirm.

The traceback indicate that the instance failed becasue the uniqueness constraint on mac address was violated. In this case i belive it failed because the heat stack attempted to create two interfaces with the same mac on a singel network or
the template is using a hardcoded mac and that mac fa:16:3e:1a:c3:39 is already in use by another port on the 0904bbe4-7075-430e-84c4-5768b6decd9d neutron network.

this could happen if the mac is set staticly in the f5fw.yaml and you attempeted to launch multiple instaces of the heat template.

regards
sean

Comment 5 Mircea Vutcovici 2018-10-03 15:28:09 UTC
The template contains no hard-coded MAC addresses. I do not understand why it tries to create a port with the same MAC address.

Comment 9 Bob Fournier 2018-11-01 17:25:09 UTC
One thing I noticed in the f5fw.yaml template that Harald added is that there are ports defined here with the same name, I believe this is a mistake:
       - port: VMAS_vzw.wsn-v6.net1_SOLKTXESW0VvVVMx-Z-F5-FWx-01
       - port: VMAS_vzw.wsn-v6.net1_SOLKTXESW0VvVVMx-Z-F5-FWx-01

The port is here with this name:
MariaDB [ovs_neutron]> select * from ml2_port_bindings left join ports on ports.id = ml2_port_bindings.port_id left join networks on networks.id = ports.network_id left join ipallocations on ipallocations.port_id = ports.id where ports.id = '0a57d046-03a3-413a-b7ba-dc948204824c'\G
*************************** 1. row ***************************
                port_id: 0a57d046-03a3-413a-b7ba-dc948204824c
                   host: 
               vif_type: unbound
              vnic_type: direct
                profile: {}
            vif_details: 
             project_id: 572ea77207944299ae64edffb856c5d6
                     id: 0a57d046-03a3-413a-b7ba-dc948204824c
                   name: VMAS_vzw.wsn-v6.net1_SOLKTXESW0VvVVMx-Z-F5-FWx-01
             network_id: fc6740c1-780e-40b1-8dbe-12bd912474d8

And the port_id above matches the error:
Duplicate entry 'fa:16:3e:2b:7c:fe/0a57d046-03a3-413a-b7ba-dc948204824c-0' for key 'uniq_virtual_interfaces0address0deleted'

Comment 15 Mircea Vutcovici 2019-02-05 20:22:52 UTC
It is solved. I confirm that the duplicate port VMAS_vzw.wsn-v6.net1_SOLKTXESW0VvVVMx-Z-F5-FWx-01 was the root cause.

Comment 17 Stephen Finucane 2022-01-31 12:23:27 UTC
Reopening this. There's clearly a bug here in nova's API: it doesn't reject duplicate port IDs during server creation. For example:

  $ openstack port create --network private test-port
  $ openstack server create --flavor m1.small --image fedora-iso --port test-port --port test-port --wait test-server
  Error creating server: test-server
  Error creating server

Looking at the logs, we see the traceback:

  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e] oslo_db.exception.DBDuplicateEntry: (pymysql.err.IntegrityError) (1062, "Duplicate entry 'fa:16:3e:62:88:38/e3caceae-2c74-4114-9f3f-262a37fc1971-0' for key 'virtual_interfaces.uniq_virtual_interfaces0address0deleted'")
  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e] [SQL: INSERT INTO virtual_interfaces (created_at, updated_at, deleted_at, deleted, address, network_id, instance_uuid, uuid, tag) VALUES (%(created_at)s, %(updated_at)s, %(deleted_at)s, %(deleted)s, %(address)s, %(network_id)s, %(instance_uuid)s, %(uuid)s, %(tag)s)]
  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e] [parameters: {'created_at': datetime.datetime(2022, 1, 31, 12, 16, 53, 467871), 'updated_at': None, 'deleted_at': None, 'deleted': 0, 'address': 'fa:16:3e:62:88:38/e3caceae-2c74-4114-9f3f-262a37fc1971', 'network_id': None, 'instance_uuid': '6cb9e513-0650-41a9-9a85-0d647e8b556e', 'uuid': 'e3caceae-2c74-4114-9f3f-262a37fc1971', 'tag': None}]
  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e] (Background on this error at: https://sqlalche.me/e/14/gkpj)
  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e]
  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e]
  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e] During handling of the above exception, another exception occurred:
  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e]
  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e]
  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e] Traceback (most recent call last):
  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e]
  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e]   File "/opt/stack/nova/nova/conductor/manager.py", line 137, in _object_dispatch
  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e]
  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e]   File "/usr/local/lib/python3.8/dist-packages/oslo_versionedobjects/base.py", line 226, in wrapper
  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e]     return fn(self, *args, **kwargs)
  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e]
  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e]   File "/opt/stack/nova/nova/objects/virtual_interface.py", line 103, in create
  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e]
  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e]   File "/opt/stack/nova/nova/db/utils.py", line 35, in wrapper
  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e]
  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e]   File "/opt/stack/nova/nova/db/main/api.py", line 190, in wrapper
  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e]
  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e]   File "/opt/stack/nova/nova/db/main/api.py", line 1037, in virtual_interface_create
  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e]
  ERROR nova.compute.manager [instance: 6cb9e513-0650-41a9-9a85-0d647e8b556e] nova.exception.VirtualInterfaceCreateException: Virtual Interface creation failed

This is nothing to do with ports with duplicate MACs: neutron won't allow you to set the same MAC on two ports on the same interface and things work fine if the same MAC is used for ports on different networks.

Comment 32 errata-xmlrpc 2022-12-07 20:24:45 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (Red Hat OpenStack Platform 16.1.9 bug fix and enhancement advisory), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2022:8795

Comment 33 Red Hat Bugzilla 2023-09-18 00:14:32 UTC
The needinfo request[s] on this closed bug have been removed as they have been unresolved for 120 days


Note You need to log in before you can comment on or make changes to this bug.