networking-calico

Bug #1668916
Comment #2

Comment 2 for bug 1668916

Revision history for this message

Nell Jerram (neil-jerram) wrote on 2017-03-03:

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 flush
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource self._flush(objects)
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 2037, in _flush
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource transaction.rollback(_capture_exception=True)
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 2001, in _flush
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource flush_context.execute()
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 372, in execute
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource rec.execute(self)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 526, in execute
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource uow
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 60, in save_obj
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource mapper, table, update)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 518, in _emit_update_statements
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource execute(statement, params)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 729, in execute
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource return meth(self, multiparams, params)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/sql/elements.py", line 322, in _execute_on_connection
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource return connection._execute_clauseelement(self, multiparams, params)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 826, in _execute_clauseelement
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource compiled_sql, distilled_params
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 958, in _execute_context
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource context)
2017-03-03 12:07:31.212 19359 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-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource e, statement, parameters, cursor, context)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1155, in _handle_dbapi_exception
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource util.raise_from_cause(newraise, exc_info)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource reraise(type(exception), exception, tb=exc_tb)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 951, in _execute_context
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource context)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 436, in do_execute
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource cursor.execute(statement, parameters)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/MySQLdb/cursors.py", line 174, in execute
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource self.errorhandler(self, exc, value)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource raise errorclass, errorvalue
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource DBDeadlock: (OperationalError) (1213, 'Deadlock found when trying to get lock; try restarting transaction') 'UPDATE ipavailabilityranges SET first_ip=%s WHERE ipavailabilityranges.allocation_pool_id = %s AND ipavailabilityranges.first_ip = %s AND ipavailabilityranges.last_ip = %s' ('fd5f:5d21:845:1c2e:2::27', '9f12d336-bb1b-4098-94ab-a61293277d28', 'fd5f:5d21:845:1c2e:2::26', 'fd5f:5d21:845:1c2e:2:ffff:ffff:fffe')
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource

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 flush
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource     self._flush(objects)
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 2037, in _flush
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource     transaction.rollback(_capture_exception=True)
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 2001, in _flush
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource     flush_context.execute()
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 372, in execute
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource     rec.execute(self)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 526, in execute
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource     uow
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 60, in save_obj
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource     mapper, table, update)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 518, in _emit_update_statements
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource     execute(statement, params)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 729, in execute
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource     return meth(self, multiparams, params)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource   File "/usr/lib/python2.7/dist-packages/sqlalchemy/sql/elements.py", line 322, in _execute_on_connection
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource     return connection._execute_clauseelement(self, multiparams, params)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 826, in _execute_clauseelement
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource     compiled_sql, distilled_params
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 958, in _execute_context
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource     context)
2017-03-03 12:07:31.212 19359 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-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource     e, statement, parameters, cursor, context)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1155, in _handle_dbapi_exception
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource     util.raise_from_cause(newraise, exc_info)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource   File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource     reraise(type(exception), exception, tb=exc_tb)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 951, in _execute_context
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource     context)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 436, in do_execute
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource     cursor.execute(statement, parameters)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource   File "/usr/lib/python2.7/dist-packages/MySQLdb/cursors.py", line 174, in execute
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource     self.errorhandler(self, exc, value)
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource   File "/usr/lib/python2.7/dist-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource     raise errorclass, errorvalue
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource DBDeadlock: (OperationalError) (1213, 'Deadlock found when trying to get lock; try restarting transaction') 'UPDATE ipavailabilityranges SET first_ip=%s WHERE ipavailabilityranges.allocation_pool_id = %s AND ipavailabilityranges.first_ip = %s AND ipavailabilityranges.last_ip = %s' ('fd5f:5d21:845:1c2e:2::27', '9f12d336-bb1b-4098-94ab-a61293277d28', 'fd5f:5d21:845:1c2e:2::26', 'fd5f:5d21:845:1c2e:2:ffff:ffff:fffe')
2017-03-03 12:07:31.212 19359 TRACE neutron.api.v2.resource