Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 1204483

Summary:	HA \| Duplicate entry exception for vxlan-allocation cause to neutron-server fail to start. VXLAN.
Product:	Red Hat OpenStack	Reporter:	Leonid Natapov <lnatapov>
Component:	openstack-foreman-installer	Assignee:	Crag Wolfe <cwolfe>
Status:	CLOSED ERRATA	QA Contact:	Leonid Natapov <lnatapov>
Severity:	urgent	Docs Contact:
Priority:	urgent
Version:	unspecified	CC:	aberezin, cwolfe, dmacpher, jguiditt, mburns, morazi, oblaut, ohochman, rhos-maint, yeylon
Target Milestone:	z2	Keywords:	Regression, ZStream
Target Release:	Installer
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:	openstack-foreman-installer-3.0.20-1.el7ost	Doc Type:	Bug Fix
Doc Text:	During a high-availability Neutron environment installation, multiple nodes started neutron-server at the same time, which caused a database race condition and resulted in an error. This fix starts neutron-server on the neutron-vip node to take care of database initialization before neutron-server becomes a cloned resource. This resolves the race condition and the error no longer appears.	Story Points:	---
Clone Of:		Environment:
Last Closed:	2015-04-07 15:09:02 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:

Description Leonid Natapov 2015-03-22 14:05:36 UTC

openstack-neutron-openvswitch-2014.2.2-5.el7ost.noarch
python-neutronclient-2.3.9-1.el7ost.noarch
openstack-neutron-2014.2.2-5.el7ost.noarch
openstack-neutron-ml2-2014.2.2-5.el7ost.noarch
python-neutron-2014.2.2-5.el7ost.noarch
puppet-3.6.2-2.el7.noarch
openstack-foreman-installer-3.0.19-1.el7ost.noarch
ruby193-rubygem-foreman_discovery-1.3.0-2.3.el7ost.noarch
foreman-1.6.0.49-6.el7ost.noarch
foreman-postgresql-1.6.0.49-6.el7ost.noarch
foreman-selinux-1.6.0.14-1.el7sat.noarch
foreman-installer-1.6.0-0.3.RC1.el7ost.noarch
foreman-discovery-image-7.0-20150227.0.el7ost.noarch
ruby193-rubygem-foreman-tasks-0.6.9-1.1.1.el7ost.noarch
foreman-proxy-1.6.0.30-6.el7ost.noarch
rubygem-foreman_api-0.1.11-6.el7sat.noarch
ruby193-rubygem-foreman_openstack_simplify-0.0.6-8.el7ost.noarch
-----------------------------------------------------------------------------
After installing HA +Neutron VXLAN configuration,neutron-server on one of the controllers failed to start. Only manual start of neutron server solved the problem. Neutron server log shows the following:
-----------------------------------------------------------------------------
2015-03-22 14:54:20.360 56863 INFO neutron.common.config [-] Logging enabled!
2015-03-22 14:54:20.366 56863 INFO neutron.common.config [-] Config paste file: /usr/share/neutron/api-paste.ini
2015-03-22 14:54:20.471 56863 INFO neutron.manager [-] Loading core plugin: neutron.plugins.ml2.plugin.Ml2Plugin
2015-03-22 14:54:20.555 56863 INFO neutron.plugins.ml2.managers [-] Configured type driver names: ['local', 'flat', 'vlan', 'gre', 'vxlan']
2015-03-22 14:54:20.558 56863 INFO neutron.plugins.ml2.drivers.type_flat [-] Arbitrary flat physical_network names allowed
2015-03-22 14:54:20.561 56863 INFO neutron.plugins.ml2.drivers.type_vlan [-] Network VLAN ranges: {'physnet-external': []}
2015-03-22 14:54:20.561 56863 INFO neutron.plugins.ml2.drivers.type_local [-] ML2 LocalTypeDriver initialization complete
2015-03-22 14:54:20.570 56863 INFO neutron.plugins.ml2.managers [-] Loaded type driver names: ['flat', 'vlan', 'local', 'gre', 'vxlan']
2015-03-22 14:54:20.570 56863 INFO neutron.plugins.ml2.managers [-] Registered types: ['flat', 'vlan', 'local', 'gre', 'vxlan']
2015-03-22 14:54:20.571 56863 INFO neutron.plugins.ml2.managers [-] Tenant network_types: ['vxlan']
2015-03-22 14:54:20.571 56863 INFO neutron.plugins.ml2.managers [-] Configured extension driver names: []
2015-03-22 14:54:20.572 56863 INFO neutron.plugins.ml2.managers [-] Loaded extension driver names: []
2015-03-22 14:54:20.572 56863 INFO neutron.plugins.ml2.managers [-] Registered extension drivers: []
2015-03-22 14:54:20.572 56863 INFO neutron.plugins.ml2.managers [-] Configured mechanism driver names: ['openvswitch', 'l2population']
2015-03-22 14:54:20.575 56863 WARNING neutron.agent.securitygroups_rpc [-] Driver configuration doesn't match with enable_security_group
2015-03-22 14:54:20.575 56863 INFO neutron.plugins.ml2.managers [-] Loaded mechanism driver names: ['openvswitch', 'l2population']
2015-03-22 14:54:20.575 56863 INFO neutron.plugins.ml2.managers [-] Registered mechanism drivers: ['openvswitch', 'l2population']
2015-03-22 14:54:20.588 56863 INFO neutron.plugins.ml2.managers [-] Initializing driver for type 'flat'
2015-03-22 14:54:20.589 56863 INFO neutron.plugins.ml2.drivers.type_flat [-] ML2 FlatTypeDriver initialization complete
2015-03-22 14:54:20.589 56863 INFO neutron.plugins.ml2.managers [-] Initializing driver for type 'vlan'
2015-03-22 14:54:20.669 56863 INFO neutron.plugins.ml2.drivers.type_vlan [-] VlanTypeDriver initialization complete
2015-03-22 14:54:20.669 56863 INFO neutron.plugins.ml2.managers [-] Initializing driver for type 'local'
2015-03-22 14:54:20.670 56863 INFO neutron.plugins.ml2.managers [-] Initializing driver for type 'gre'
2015-03-22 14:54:20.670 56863 INFO neutron.plugins.ml2.drivers.type_tunnel [-] gre ID ranges: [(10, 1000)]
2015-03-22 14:54:20.901 56863 WARNING neutron.plugins.ml2.drivers.type_gre [-] Gre allocations were already created.
2015-03-22 14:54:20.902 56863 INFO neutron.plugins.ml2.managers [-] Initializing driver for type 'vxlan'
2015-03-22 14:54:20.903 56863 INFO neutron.plugins.ml2.drivers.type_tunnel [-] vxlan ID ranges: [(10, 100)]
2015-03-22 14:54:20.931 56863 ERROR neutron.service [-] Unrecoverable error: please check log for details.
2015-03-22 14:54:20.931 56863 TRACE neutron.service Traceback (most recent call last):
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/neutron/service.py", line 102, in serve_wsgi
2015-03-22 14:54:20.931 56863 TRACE neutron.service     service.start()
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/neutron/service.py", line 73, in start
2015-03-22 14:54:20.931 56863 TRACE neutron.service     self.wsgi_app = _run_wsgi(self.app_name)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/neutron/service.py", line 168, in _run_wsgi
2015-03-22 14:54:20.931 56863 TRACE neutron.service     app = config.load_paste_app(app_name)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/neutron/common/config.py", line 183, in load_paste_app
2015-03-22 14:54:20.931 56863 TRACE neutron.service     app = deploy.loadapp("config:%s" % config_path, name=app_name)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/paste/deploy/loadwsgi.py", line 247, in loadapp
2015-03-22 14:54:20.931 56863 TRACE neutron.service     return loadobj(APP, uri, name=name, **kw)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/paste/deploy/loadwsgi.py", line 272, in loadobj
2015-03-22 14:54:20.931 56863 TRACE neutron.service     return context.create()
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/paste/deploy/loadwsgi.py", line 710, in create
2015-03-22 14:54:20.931 56863 TRACE neutron.service     return self.object_type.invoke(self)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/paste/deploy/loadwsgi.py", line 144, in invoke
2015-03-22 14:54:20.931 56863 TRACE neutron.service     **context.local_conf)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/paste/deploy/util.py", line 56, in fix_call
2015-03-22 14:54:20.931 56863 TRACE neutron.service     val = callable(*args, **kw)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/paste/urlmap.py", line 25, in urlmap_factory
2015-03-22 14:54:20.931 56863 TRACE neutron.service     app = loader.get_app(app_name, global_conf=global_conf)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/paste/deploy/loadwsgi.py", line 350, in get_app
2015-03-22 14:54:20.931 56863 TRACE neutron.service     name=name, global_conf=global_conf).create()
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/paste/deploy/loadwsgi.py", line 710, in create
2015-03-22 14:54:20.931 56863 TRACE neutron.service     return self.object_type.invoke(self)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/paste/deploy/loadwsgi.py", line 144, in invoke
2015-03-22 14:54:20.931 56863 TRACE neutron.service     **context.local_conf)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/paste/deploy/util.py", line 56, in fix_call
2015-03-22 14:54:20.931 56863 TRACE neutron.service     val = callable(*args, **kw)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/neutron/auth.py", line 71, in pipeline_factory
2015-03-22 14:54:20.931 56863 TRACE neutron.service     app = loader.get_app(pipeline[-1])
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/paste/deploy/loadwsgi.py", line 350, in get_app
2015-03-22 14:54:20.931 56863 TRACE neutron.service     name=name, global_conf=global_conf).create()
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/paste/deploy/loadwsgi.py", line 710, in create
2015-03-22 14:54:20.931 56863 TRACE neutron.service     return self.object_type.invoke(self)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/paste/deploy/loadwsgi.py", line 144, in invoke
2015-03-22 14:54:20.931 56863 TRACE neutron.service     **context.local_conf)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/paste/deploy/util.py", line 56, in fix_call
2015-03-22 14:54:20.931 56863 TRACE neutron.service     val = callable(*args, **kw)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/neutron/auth.py", line 71, in pipeline_factory
2015-03-22 14:54:20.931 56863 TRACE neutron.service     app = loader.get_app(pipeline[-1])
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/paste/deploy/loadwsgi.py", line 350, in get_app
2015-03-22 14:54:20.931 56863 TRACE neutron.service     name=name, global_conf=global_conf).create()
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/paste/deploy/loadwsgi.py", line 710, in create
2015-03-22 14:54:20.931 56863 TRACE neutron.service     return self.object_type.invoke(self)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/paste/deploy/loadwsgi.py", line 146, in invoke
2015-03-22 14:54:20.931 56863 TRACE neutron.service     return fix_call(context.object, context.global_conf, **context.local_conf)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/paste/deploy/util.py", line 56, in fix_call
2015-03-22 14:54:20.931 56863 TRACE neutron.service     val = callable(*args, **kw)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/neutron/api/v2/router.py", line 72, in factory
2015-03-22 14:54:20.931 56863 TRACE neutron.service     return cls(**local_config)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/neutron/api/v2/router.py", line 76, in __init__
2015-03-22 14:54:20.931 56863 TRACE neutron.service     plugin = manager.NeutronManager.get_plugin()
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/neutron/manager.py", line 219, in get_plugin
2015-03-22 14:54:20.931 56863 TRACE neutron.service     return weakref.proxy(cls.get_instance().plugin)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/neutron/manager.py", line 213, in get_instance
2015-03-22 14:54:20.931 56863 TRACE neutron.service     cls._create_instance()
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/neutron/openstack/common/lockutils.py", line 249, in inner
2015-03-22 14:54:20.931 56863 TRACE neutron.service     return f(*args, **kwargs)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/neutron/manager.py", line 199, in _create_instance
2015-03-22 14:54:20.931 56863 TRACE neutron.service     cls._instance = cls()
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/neutron/manager.py", line 114, in __init__
2015-03-22 14:54:20.931 56863 TRACE neutron.service     plugin_provider)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/neutron/manager.py", line 140, in _get_plugin_instance
2015-03-22 14:54:20.931 56863 TRACE neutron.service     return plugin_class()
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/plugin.py", line 124, in __init__
2015-03-22 14:54:20.931 56863 TRACE neutron.service     self.type_manager.initialize()
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/managers.py", line 146, in initialize
2015-03-22 14:54:20.931 56863 TRACE neutron.service     driver.obj.initialize()
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/type_vxlan.py", line 80, in initialize
2015-03-22 14:54:20.931 56863 TRACE neutron.service     self._initialize(cfg.CONF.ml2_type_vxlan.vni_ranges)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/type_tunnel.py", line 65, in _initialize
2015-03-22 14:54:20.931 56863 TRACE neutron.service     self.sync_allocations()
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/type_vxlan.py", line 127, in sync_allocations
2015-03-22 14:54:20.931 56863 TRACE neutron.service     session.execute(VxlanAllocation.__table__.insert(), bulk)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 991, in execute
2015-03-22 14:54:20.931 56863 TRACE neutron.service     bind, close_with_result=True).execute(clause, params or {})
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 729, in execute
2015-03-22 14:54:20.931 56863 TRACE neutron.service     return meth(self, multiparams, params)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib64/python2.7/site-packages/sqlalchemy/sql/elements.py", line 321, in _execute_on_connection
2015-03-22 14:54:20.931 56863 TRACE neutron.service     return connection._execute_clauseelement(self, multiparams, params)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 826, in _execute_clauseelement
2015-03-22 14:54:20.931 56863 TRACE neutron.service     compiled_sql, distilled_params
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 958, in _execute_context
2015-03-22 14:54:20.931 56863 TRACE neutron.service     context)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1156, in _handle_dbapi_exception
2015-03-22 14:54:20.931 56863 TRACE neutron.service     util.raise_from_cause(newraise, exc_info)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause
2015-03-22 14:54:20.931 56863 TRACE neutron.service     reraise(type(exception), exception, tb=exc_tb)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 928, in _execute_context
2015-03-22 14:54:20.931 56863 TRACE neutron.service     context)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib64/python2.7/site-packages/sqlalchemy/connectors/mysqldb.py", line 68, in do_executemany
2015-03-22 14:54:20.931 56863 TRACE neutron.service     rowcount = cursor.executemany(statement, parameters)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib64/python2.7/site-packages/MySQLdb/cursors.py", line 206, in executemany
2015-03-22 14:54:20.931 56863 TRACE neutron.service     r = r + self.execute(query, a)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib64/python2.7/site-packages/MySQLdb/cursors.py", line 174, in execute
2015-03-22 14:54:20.931 56863 TRACE neutron.service     self.errorhandler(self, exc, value)
2015-03-22 14:54:20.931 56863 TRACE neutron.service   File "/usr/lib64/python2.7/site-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
2015-03-22 14:54:20.931 56863 TRACE neutron.service     raise errorclass, errorvalue
2015-03-22 14:54:20.931 56863 TRACE neutron.service DBDuplicateEntry: (IntegrityError) (1062, "Duplicate entry '10' for key 'PRIMARY'") 'INSERT INTO ml2_vxlan_allocations (vxlan_vni, allocated) VALUES (%s, %s)' ((10, 0), (11, 0), (12, 0), (13, 0), (14, 0), (15, 0), (16, 0), (17, 0)  ... displaying 10 of 91 total bound parameter sets ...  (99, 0), (100, 0))
2015-03-22 14:54:20.931 56863 TRACE neutron.service
2015-03-22 14:54:20.936 56863 CRITICAL neutron [-] DBDuplicateEntry: (IntegrityError) (1062, "Duplicate entry '10' for key 'PRIMARY'") 'INSERT INTO ml2_vxlan_allocations (vxlan_vni, allocated) VALUES (%s, %s)' ((10, 0), (11, 0), (12, 0), (13, 0), (14, 0), (15, 0), (16, 0), (17, 0)  ... displaying 10 of 91 total bound parameter sets ...  (99, 0), (100, 0))

Comment 8 Leonid Natapov 2015-03-23 17:11:30 UTC

Not every time but it reproduced several times on bare metals HA+Neutron VXLAN.

Comment 10 Crag Wolfe 2015-03-23 18:18:25 UTC

Also, please include yaml for one of the hosts so we can try to reproduce in dev.

Comment 11 Leonid Natapov 2015-03-23 18:57:31 UTC

Yes,it happens on the first run.

Comment 12 Leonid Natapov 2015-03-23 19:19:09 UTC

YUML: http://fpaste.org/201680/38305142/

Comment 13 Crag Wolfe 2015-03-24 00:35:44 UTC

Patch posted:
https://github.com/redhat-openstack/astapor/pull/498

Pasting the explanation from above:
Previously, a race condition existed where multiple nodes starting
neutron-server at the same time (by pacemaker) could cause a DB error
such as the one reported in this BZ (in this case, multiple nodes
attempted to update the table ml2_vxlan_allocations and then found it
in an unexpected state). To avoid the issue, neutron-server is
started and then stopped on the neutron-vip node, thereby taking care
of any db-initialization tasks (one of which may be inserting into the
ml2_vxlan_allocations table), before neutron-server is added as a
cloned resource.

Comment 15 Jason Guiditta 2015-03-24 17:54:10 UTC

Merged

Comment 17 Leonid Natapov 2015-03-30 06:47:52 UTC

openstack-foreman-installer-3.0.21-1.el7ost.noarch

Doesn't reproduce.

Comment 19 errata-xmlrpc 2015-04-07 15:09:02 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, 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://rhn.redhat.com/errata/RHSA-2015-0791.html