Deadlock in update_port_precommit

Bug #1668916 reported by Shaun Crampton
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
networking-calico
New
Undecided
Unassigned

Bug Description

Saw the following traceback in a CI run (Ubuntu kilo). Calico's driver doesn't seem to be in the traceback.

2017-02-28 23:44:36.671 19759 ERROR neutron.api.v2.resource [req-58b493ae-3169-4cfd-aa66-2df110168956 ] create failed
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource Traceback (most recent call last):
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron/api/v2/resource.py", line 83, in resource
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource result = method(request=request, **args)
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron/api/v2/base.py", line 464, in create
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource obj = obj_creator(request.context, **kwargs)
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/oslo_db/api.py", line 131, in wrapper
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource return f(*args, **kwargs)
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron/plugins/ml2/plugin.py", line 988, in create_port
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource bound_context = self._bind_port_if_needed(mech_context)
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron/plugins/ml2/plugin.py", line 291, in _bind_port_if_needed
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource plugin_context, port_id, binding, bind_context)
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron/plugins/ml2/plugin.py", line 412, in _commit_port_binding
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource self.mechanism_manager.update_port_precommit(cur_context)
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource self.gen.next()
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/contextlib.py", line 121, in nested
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource if exit(*exc):
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 470, in __exit__
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource self.rollback()
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource compat.reraise(exc_type, exc_value, exc_tb)
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 467, in __exit__
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource self.commit()
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 377, in commit
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource self._prepare_impl()
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 357, in _prepare_impl
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource self.session.flush()
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1919, in flush
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource self._flush(objects)
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2037, in _flush
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource transaction.rollback(_capture_exception=True)
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource compat.reraise(exc_type, exc_value, exc_tb)
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2001, in _flush
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource flush_context.execute()
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 372, in execute
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource rec.execute(self)
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 526, in execute
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource uow
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 65, in save_obj
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource mapper, table, insert)
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 570, in _emit_insert_statements
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource execute(statement, multiparams)
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 729, in execute
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource return meth(self, multiparams, params)
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/sql/elements.py", line 322, in _execute_on_connection
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource return connection._execute_clauseelement(self, multiparams, params)
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 826, in _execute_clauseelement
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource compiled_sql, distilled_params
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 958, in _execute_context
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource context)
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/oslo_db/sqlalchemy/compat/handle_error.py", line 261, in _handle_dbapi_exception
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource e, statement, parameters, cursor, context)
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1155, in _handle_dbapi_exception
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource util.raise_from_cause(newraise, exc_info)
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource reraise(type(exception), exception, tb=exc_tb)
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 951, in _execute_context
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource context)
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 436, in do_execute
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource cursor.execute(statement, parameters)
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/MySQLdb/cursors.py", line 174, in execute
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource self.errorhandler(self, exc, value)
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource raise errorclass, errorvalue
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource DBDeadlock: (OperationalError) (1213, 'Deadlock found when trying to get lock; try restarting transaction') 'INSERT INTO ml2_port_binding_levels (port_id, host, level, driver, segment_id) VALUES (%s, %s, %s, %s, %s)' ('8fe3d811-92d9-48dd-87c2-bd25b37e7fff', 'jenkins-fv-prb-1051-ubuntu-kilo-compute-node01', 0, 'calico', 'e2119c82-6e59-4258-87fb-2f3a0679cd07')
2017-02-28 23:44:36.671 19759 TRACE neutron.api.v2.resource

Revision history for this message
Nell Jerram (neil-jerram) wrote :
Download full text (8.7 KiB)

Another instance, with Kilo on Ubuntu:

2017-03-03 00:52:23.799 19437 WARNING networking_calico.plugins.ml2.drivers.calico.mech_calico [req-14b3e0a3-e85f-4107-8099-75ecc653892c ] Missing ports: set([])
2017-03-03 00:52:23.799 19437 WARNING networking_calico.plugins.ml2.drivers.calico.mech_calico [req-14b3e0a3-e85f-4107-8099-75ecc653892c ] Extra ports: set([u'e13902a4-eb8a-48d3-8214-10fd7da6b3e8'])
2017-03-03 00:52:25.398 19437 WARNING neutron.plugins.ml2.plugin [req-f2ae6591-69f9-428e-9305-1b2f62f6613c ] Port e13902a4-eb8a-48d3-8214-10fd7da6b3e8 updated up by agent not found
2017-03-03 00:52:28.063 19456 ERROR neutron.api.v2.resource [req-7d3cf55c-097d-4b57-ad60-e51edae1f901 ] create failed
2017-03-03 00:52:28.063 19456 TRACE neutron.api.v2.resource Traceback (most recent call last):
2017-03-03 00:52:28.063 19456 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron/api/v2/resource.py", line 83, in resource
2017-03-03 00:52:28.063 19456 TRACE neutron.api.v2.resource result = method(request=request, **args)
2017-03-03 00:52:28.063 19456 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron/api/v2/base.py", line 464, in create
2017-03-03 00:52:28.063 19456 TRACE neutron.api.v2.resource obj = obj_creator(request.context, **kwargs)
2017-03-03 00:52:28.063 19456 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/oslo_db/api.py", line 131, in wrapper
2017-03-03 00:52:28.063 19456 TRACE neutron.api.v2.resource return f(*args, **kwargs)
2017-03-03 00:52:28.063 19456 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron/plugins/ml2/plugin.py", line 970, in create_port
2017-03-03 00:52:28.063 19456 TRACE neutron.api.v2.resource result, mech_context = self._create_port_db(context, port)
2017-03-03 00:52:28.063 19456 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron/plugins/ml2/plugin.py", line 944, in _create_port_db
2017-03-03 00:52:28.063 19456 TRACE neutron.api.v2.resource result = super(Ml2Plugin, self).create_port(context, port)
2017-03-03 00:52:28.063 19456 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron/db/db_base_plugin_v2.py", line 1850, in create_port
2017-03-03 00:52:28.063 19456 TRACE neutron.api.v2.resource context, ip_address, network_id, subnet_id, port_id)
2017-03-03 00:52:28.063 19456 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 470, in __exit__
2017-03-03 00:52:28.063 19456 TRACE neutron.api.v2.resource self.rollback()
2017-03-03 00:52:28.063 19456 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
2017-03-03 00:52:28.063 19456 TRACE neutron.api.v2.resource compat.reraise(exc_type, exc_value, exc_tb)
2017-03-03 00:52:28.063 19456 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 467, in __exit__
2017-03-03 00:52:28.063 19456 TRACE neutron.api.v2.resource self.commit()
2017-03-03 00:52:28.063 19456 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packag...

Read more...

Revision history for this message
Nell Jerram (neil-jerram) wrote :
Download full text (8.2 KiB)

And another occurrence (again with Kilo on Ubuntu Trusty):

2017-03-03 12:07:31.212 19359 ERROR neutron.api.v2.resource [req-1537ba93-5ce8-443e-bfa9-cceb1c9a4039 ] create failed
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource Traceback (most recent call last):
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron/api/v2/resource.py", line 83, in resource
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource result = method(request=request, **args)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron/api/v2/base.py", line 464, in create
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource obj = obj_creator(request.context, **kwargs)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/oslo_db/api.py", line 131, in wrapper
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource return f(*args, **kwargs)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron/plugins/ml2/plugin.py", line 970, in create_port
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource result, mech_context = self._create_port_db(context, port)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron/plugins/ml2/plugin.py", line 944, in _create_port_db
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource result = super(Ml2Plugin, self).create_port(context, port)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron/db/db_base_plugin_v2.py", line 1850, in create_port
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource context, ip_address, network_id, subnet_id, port_id)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 470, in __exit__
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource self.rollback()
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource compat.reraise(exc_type, exc_value, exc_tb)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 467, in __exit__
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource self.commit()
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 377, in commit
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource self._prepare_impl()
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 357, in _prepare_impl
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource self.session.flush()
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1919, in fl...

Read more...

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

Other bug subscribers

Remote bug watches

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