_sync_vlan_allocations thowing DBDuplicateEntry with postgres HA

Bug #1421626 reported by Rossella Sblendido on 2015-02-13
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
neutron
Medium
ding bo

Bug Description

_sync_vlan_allocations is thowing DBDuplicateEntry when 2 neutron servers are rebooted at the same time. Postgres is HA, the FOR UPDATE lock is not working and both server try to write the data in the DB at the same time.

2014-12-15 14:20:39.644 14746 TRACE neutron Traceback (most recent call last):
2014-12-15 14:20:39.644 14746 TRACE neutron File "/usr/bin/neutron-server", line 10, in <module>
2014-12-15 14:20:39.644 14746 TRACE neutron sys.exit(main())
2014-12-15 14:20:39.644 14746 TRACE neutron File "/usr/lib64/python2.6/site-packages/neutron/server/__init__.py", line 48, in main
2014-12-15 14:20:39.644 14746 TRACE neutron neutron_api = service.serve_wsgi(service.NeutronApiService)
2014-12-15 14:20:39.644 14746 TRACE neutron File "/usr/lib64/python2.6/site-packages/neutron/service.py", line 112, in serve_wsgi
2014-12-15 14:20:39.644 14746 TRACE neutron LOG.exception(_('Unrecoverable error: please check log '
2014-12-15 14:20:39.644 14746 TRACE neutron File "/usr/lib64/python2.6/site-packages/neutron/openstack/common/excutils.py", line 82, in __exit__
2014-12-15 14:20:39.644 14746 TRACE neutron six.reraise(self.type_, self.value, self.tb)
2014-12-15 14:20:39.644 14746 TRACE neutron File "/usr/lib64/python2.6/site-packages/neutron/service.py", line 105, in serve_wsgi
2014-12-15 14:20:39.644 14746 TRACE neutron service.start()
2014-12-15 14:20:39.644 14746 TRACE neutron File "/usr/lib64/python2.6/site-packages/neutron/service.py", line 74, in start
2014-12-15 14:20:39.644 14746 TRACE neutron self.wsgi_app = _run_wsgi(self.app_name)
2014-12-15 14:20:39.644 14746 TRACE neutron File "/usr/lib64/python2.6/site-packages/neutron/service.py", line 173, in _run_wsgi
2014-12-15 14:20:39.644 14746 TRACE neutron app = config.load_paste_app(app_name)
2014-12-15 14:20:39.644 14746 TRACE neutron File "/usr/lib64/python2.6/site-packages/neutron/common/config.py", line 170, in load_paste_app
2014-12-15 14:20:39.644 14746 TRACE neutron app = deploy.loadapp("config:%s" % config_path, name=app_name)
2014-12-15 14:20:39.644 14746 TRACE neutron File "/usr/lib64/python2.6/site-packages/paste/deploy/loadwsgi.py", line 247, in loadapp
2014-12-15 14:20:39.644 14746 TRACE neutron return loadobj(APP, uri, name=name, **kw)
2014-12-15 14:20:39.644 14746 TRACE neutron File "/usr/lib64/python2.6/site-packages/paste/deploy/loadwsgi.py", line 272, in loadobj
2014-12-15 14:20:39.644 14746 TRACE neutron return context.create()
2014-12-15 14:20:39.644 14746 TRACE neutron File "/usr/lib64/python2.6/site-packages/paste/deploy/loadwsgi.py", line 710, in create
2014-12-15 14:20:39.644 14746 TRACE neutron return self.object_type.invoke(self)
2014-12-15 14:20:39.644 14746 TRACE neutron File "/usr/lib64/python2.6/site-packages/paste/deploy/loadwsgi.py", line 144, in invoke
2014-12-15 14:20:39.644 14746 TRACE neutron **context.local_conf)
2014-12-15 14:20:39.644 14746 TRACE neutron File "/usr/lib64/python2.6/site-packages/paste/deploy/util.py", line 55, in fix_call
...skipping...
2014-12-15 14:20:39.644 14746 TRACE neutron File "/usr/lib64/python2.6/site-packages/neutron/plugins/ml2/drivers/type_vlan.py", line 160, in initialize
2014-12-15 14:20:39.644 14746 TRACE neutron self._sync_vlan_allocations()
2014-12-15 14:20:39.644 14746 TRACE neutron File "/usr/lib64/python2.6/site-packages/neutron/plugins/ml2/drivers/type_vlan.py", line 154, in _sync_vlan_alloc
ations
2014-12-15 14:20:39.644 14746 TRACE neutron session.delete(alloc)
2014-12-15 14:20:39.644 14746 TRACE neutron File "/usr/lib64/python2.6/site-packages/sqlalchemy/orm/session.py", line 447, in __exit__
2014-12-15 14:20:39.644 14746 TRACE neutron self.rollback()
2014-12-15 14:20:39.644 14746 TRACE neutron File "/usr/lib64/python2.6/site-packages/sqlalchemy/util/langhelpers.py", line 58, in __exit__
2014-12-15 14:20:39.644 14746 TRACE neutron compat.reraise(exc_type, exc_value, exc_tb)
2014-12-15 14:20:39.644 14746 TRACE neutron File "/usr/lib64/python2.6/site-packages/sqlalchemy/orm/session.py", line 444, in __exit__
2014-12-15 14:20:39.644 14746 TRACE neutron self.commit()
2014-12-15 14:20:39.644 14746 TRACE neutron File "/usr/lib64/python2.6/site-packages/sqlalchemy/orm/session.py", line 354, in commit
2014-12-15 14:20:39.644 14746 TRACE neutron self._prepare_impl()
2014-12-15 14:20:39.644 14746 TRACE neutron File "/usr/lib64/python2.6/site-packages/sqlalchemy/orm/session.py", line 334, in _prepare_impl
2014-12-15 14:20:39.644 14746 TRACE neutron self.session.flush()
2014-12-15 14:20:39.644 14746 TRACE neutron File "/usr/lib64/python2.6/site-packages/neutron/openstack/common/db/sqlalchemy/session.py", line 615, in _wrap
2014-12-15 14:20:39.644 14746 TRACE neutron _raise_if_duplicate_entry_error(e, get_engine().name)
2014-12-15 14:20:39.644 14746 TRACE neutron File "/usr/lib64/python2.6/site-packages/neutron/openstack/common/db/sqlalchemy/session.py", line 559, in _raise_
if_duplicate_entry_error
2014-12-15 14:20:39.644 14746 TRACE neutron raise exception.DBDuplicateEntry(columns, integrity_error)
2014-12-15 14:20:39.644 14746 TRACE neutron DBDuplicateEntry: (IntegrityError) duplicate key value violates unique constraint "ml2_vlan_allocations_pkey"
2014-12-15 14:20:39.644 14746 TRACE neutron DETAIL: Key (physical_network, vlan_id)=(physnet1, 3156) already exists.
2014-12-15 14:20:39.644 14746 TRACE neutron 'INSERT INTO ml2_vlan_allocations (physical_network, vlan_id, allocated) VALUES (%(physical_network)s, %(vlan_id)s
, %(allocated)s)' ({'allocated': False, 'physical_network': 'physnet1', 'vlan_id': 3156}, {'allocated': False, 'physical_network': 'physnet1', 'vlan_id': 3158}
, {'allocated': False, 'physical_network': 'physnet1', 'vlan_id': 3160}, {'allocated': False, 'physical_network': 'physnet1', 'vlan_id': 3162}, {'allocated': F
alse, 'physical_network': 'physnet1', 'vlan_id': 3164}, {'allocated': False, 'physical_network': 'physnet1', 'vlan_id': 3165}, {'allocated': False, 'physical_n
etwork': 'physnet1', 'vlan_id': 3167}, {'allocated': False, 'physical_network': 'physnet1', 'vlan_id': 3169} ... displaying 10 of 486 total bound parameter se
ts ... {'allocated': False, 'physical_network': 'physnet1', 'vlan_id': 3648}, {'allocated': False, 'physical_network': 'physnet1', 'vlan_id': 3649})

Changed in neutron:
assignee: nobody → Rossella Sblendido (rossella-o)
tags: added: db
Changed in neutron:
importance: Undecided → Medium
status: New → Confirmed

Fix proposed to branch: master
Review: https://review.openstack.org/276384

Changed in neutron:
status: Confirmed → In Progress

Change abandoned by Armando Migliaccio (<email address hidden>) on branch: master
Review: https://review.openstack.org/276384
Reason: This review is > 4 weeks without comment, and failed Jenkins the last time it was checked. We are abandoning this for now. Feel free to reactivate the review by pressing the restore button and leaving a 'recheck' comment to get fresh test results.

Changed in neutron:
status: In Progress → Confirmed
assignee: Rossella Sblendido (rossella-o) → nobody
Changed in neutron:
status: Confirmed → Incomplete
tags: added: low-hanging-fruit
ding bo (longddropt) on 2016-07-06
Changed in neutron:
assignee: nobody → ding bo (longddropt)
Bernard Cafarelli (bcafarel) wrote :

In this report, there are DBDuplicateEntry (same backtrace) with Galera backend:
https://bugzilla.redhat.com/show_bug.cgi?id=1383700

ding bo, are you working on this? Else I'd like to restore and push for Rossella's fix

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.