yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1480305] Re: DBDeadlock inserting into instance_extra

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Matt Riedemann <mriedem@xxxxxxxxxx>
Date: Thu, 08 Sep 2016 16:07:48 -0000
Reply-to: Bug 1480305 <1480305@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
** Changed in: nova
     Assignee: (unassigned) => John Garbutt (johngarbutt)

** Also affects: nova/mitaka
   Importance: Undecided
       Status: New

** Changed in: nova/mitaka
       Status: New => Confirmed

** Changed in: nova/mitaka
   Importance: Undecided => Medium

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1480305

Title:
  DBDeadlock inserting into instance_extra

Status in OpenStack Compute (nova):
  Triaged
Status in OpenStack Compute (nova) mitaka series:
  Confirmed

Bug description:
  http://logs.openstack.org/78/193278/15/check/gate-tempest-dsvm-
  full/7e16644/logs/screen-n-api.txt.gz?level=TRACE#_2015-07-31_01_52_20_792

  2015-07-31 01:52:20.792 ERROR nova.api.openstack [req-ea281178-5948-47a1-815d-e97f12b2412b tempest-FloatingIPsTestJSON-1949129213 tempest-FloatingIPsTestJSON-96720078] Caught error: (pymysql.err.InternalError) (1213, u'Deadlock found when trying to get lock; try restarting transaction') [SQL: u'INSERT INTO instance_extra (created_at, updated_at, deleted_at, deleted, instance_uuid, numa_topology, pci_requests, flavor, vcpu_model) VALUES (%s, %s, %s, %s, %s, %s, %s, %s, %s)'] [parameters: (datetime.datetime(2015, 7, 31, 1, 52, 20, 772556), None, None, 0, '645dcef8-0852-40b5-ac1f-e422b7909e90', None, '[]', '{"new": null, "old": null, "cur": {"nova_object.version": "1.1", "nova_object.name": "Flavor", "nova_object.data": {"disabled": false, "root_gb": 0, "name": "m1.nano", "flavorid": "42", "deleted": false, "created_at": "2015-07-31T01:50:53Z", "ephemeral_gb": 0, "updated_at": null, "memory_mb": 64, "vcpus": 1, "extra_specs": {}, "swap": 0, "rxtx_factor": 1.0, "is_public": true, "deleted_at": null, "vcpu_weight": 0, "id": 6}, "nova_object.namespace": "nova"}}', None)]
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack Traceback (most recent call last):
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/opt/stack/new/nova/nova/api/openstack/__init__.py", line 128, in __call__
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     return req.get_response(self.application)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/webob/request.py", line 1317, in send
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     application, catch_exc_info=False)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/webob/request.py", line 1281, in call_application
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     app_iter = application(self.environ, start_response)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     return resp(environ, start_response)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 130, in __call__
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     resp = self.call_func(req, *args, **self.kwargs)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 195, in call_func
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     return self.func(req, *args, **kwargs)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py", line 434, in __call__
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     response = req.get_response(self._app)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/webob/request.py", line 1317, in send
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     application, catch_exc_info=False)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/webob/request.py", line 1281, in call_application
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     app_iter = application(self.environ, start_response)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     return resp(environ, start_response)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     return resp(environ, start_response)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/routes/middleware.py", line 136, in __call__
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     response = self.app(environ, start_response)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     return resp(environ, start_response)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 130, in __call__
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     resp = self.call_func(req, *args, **self.kwargs)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 195, in call_func
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     return self.func(req, *args, **kwargs)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/opt/stack/new/nova/nova/api/openstack/wsgi.py", line 756, in __call__
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     content_type, body, accept)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/opt/stack/new/nova/nova/api/openstack/wsgi.py", line 821, in _process_stack
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     action_result = self.dispatch(meth, request, action_args)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/opt/stack/new/nova/nova/api/openstack/wsgi.py", line 911, in dispatch
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     return method(req=request, **action_args)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/opt/stack/new/nova/nova/api/openstack/compute/servers.py", line 643, in create
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     self._handle_create_exception(*sys.exc_info())
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/opt/stack/new/nova/nova/api/openstack/compute/servers.py", line 472, in _handle_create_exception
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     six.reraise(*exc_info)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/opt/stack/new/nova/nova/api/openstack/compute/servers.py", line 628, in create
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     check_server_group_quota=check_server_group_quota)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/opt/stack/new/nova/nova/hooks.py", line 149, in inner
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     rv = f(*args, **kwargs)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/opt/stack/new/nova/nova/compute/api.py", line 1488, in create
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     check_server_group_quota=check_server_group_quota)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/opt/stack/new/nova/nova/compute/api.py", line 1121, in _create_instance
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     instance_group, check_server_group_quota)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/opt/stack/new/nova/nova/compute/api.py", line 976, in _provision_instances
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     quotas.rollback()
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 119, in __exit__
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     six.reraise(self.type_, self.value, self.tb)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/opt/stack/new/nova/nova/compute/api.py", line 939, in _provision_instances
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     num_instances, i, shutdown_terminate)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/opt/stack/new/nova/nova/compute/api.py", line 1388, in create_db_entry_for_new_instance
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     instance.create()
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/opt/stack/new/nova/nova/objects/base.py", line 116, in wrapper
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     return fn(self, *args, **kwargs)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/opt/stack/new/nova/nova/objects/instance.py", line 609, in create
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     db_inst = db.instance_create(self._context, updates)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/opt/stack/new/nova/nova/db/api.py", line 633, in instance_create
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     return IMPL.instance_create(context, values)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 229, in wrapper
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     return f(*args, **kwargs)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 1652, in instance_create
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     session.add(instance_ref)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 490, in __exit__
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     self.rollback()
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     compat.reraise(exc_type, exc_value, exc_tb)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 487, in __exit__
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     self.commit()
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 392, in commit
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     self._prepare_impl()
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 372, in _prepare_impl
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     self.session.flush()
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2004, in flush
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     self._flush(objects)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2122, in _flush
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     transaction.rollback(_capture_exception=True)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     compat.reraise(exc_type, exc_value, exc_tb)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2086, in _flush
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     flush_context.execute()
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 373, in execute
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     rec.execute(self)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 532, in execute
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     uow
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 174, in save_obj
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     mapper, table, insert)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 781, in _emit_insert_statements
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     execute(statement, params)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 914, in execute
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     return meth(self, multiparams, params)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/sql/elements.py", line 323, in _execute_on_connection
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     return connection._execute_clauseelement(self, multiparams, params)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1010, in _execute_clauseelement
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     compiled_sql, distilled_params
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1146, in _execute_context
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     context)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1337, in _handle_dbapi_exception
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     util.raise_from_cause(newraise, exc_info)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     reraise(type(exception), exception, tb=exc_tb)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1139, in _execute_context
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     context)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 450, in do_execute
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     cursor.execute(statement, parameters)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 134, in execute
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     result = self._query(query)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 282, in _query
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     conn.query(q)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 768, in query
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 929, in _read_query_result
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     result.read()
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 1125, in read
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     first_packet = self.connection._read_packet()
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 893, in _read_packet
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     packet.check_error()
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 369, in check_error
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     err.raise_mysql_exception(self._data)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/pymysql/err.py", line 120, in raise_mysql_exception
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     _check_mysql_exception(errinfo)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/pymysql/err.py", line 115, in _check_mysql_exception
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack     raise InternalError(errno, errorvalue)
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack DBDeadlock: (pymysql.err.InternalError) (1213, u'Deadlock found when trying to get lock; try restarting transaction') [SQL: u'INSERT INTO instance_extra (created_at, updated_at, deleted_at, deleted, instance_uuid, numa_topology, pci_requests, flavor, vcpu_model) VALUES (%s, %s, %s, %s, %s, %s, %s, %s, %s)'] [parameters: (datetime.datetime(2015, 7, 31, 1, 52, 20, 772556), None, None, 0, '645dcef8-0852-40b5-ac1f-e422b7909e90', None, '[]', '{"new": null, "old": null, "cur": {"nova_object.version": "1.1", "nova_object.name": "Flavor", "nova_object.data": {"disabled": false, "root_gb": 0, "name": "m1.nano", "flavorid": "42", "deleted": false, "created_at": "2015-07-31T01:50:53Z", "ephemeral_gb": 0, "updated_at": null, "memory_mb": 64, "vcpus": 1, "extra_specs": {}, "swap": 0, "rxtx_factor": 1.0, "is_public": true, "deleted_at": null, "vcpu_weight": 0, "id": 6}, "nova_object.namespace": "nova"}}', None)]
  2015-07-31 01:52:20.792 18304 ERROR nova.api.openstack 

  5 hits in 7 days, check and gate, all failures:

  http://logstash.openstack.org/#eyJzZWFyY2giOiJtZXNzYWdlOlwiY3JlYXRlX2RiX2VudHJ5X2Zvcl9uZXdfaW5zdGFuY2VcIiBBTkQgbWVzc2FnZTpcIkRlYWRsb2NrIGZvdW5kIHdoZW4gdHJ5aW5nIHRvIGdldCBsb2NrOyB0cnkgcmVzdGFydGluZyB0cmFuc2FjdGlvbicpIFtTUUw6IHUnSU5TRVJUIElOVE8gaW5zdGFuY2VfZXh0cmFcIiBBTkQgdGFnczpcInNjcmVlbi1uLWFwaS50eHRcIiIsImZpZWxkcyI6W10sIm9mZnNldCI6MCwidGltZWZyYW1lIjoiNjA0ODAwIiwiZ3JhcGhtb2RlIjoiY291bnQiLCJ0aW1lIjp7InVzZXJfaW50ZXJ2YWwiOjB9LCJzdGFtcCI6MTQzODM0OTYzNTY4OX0=

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1480305/+subscriptions
References

[Bug 1480305] [NEW] FloatingIPsTestJSON fails with DBDeadlock inserting into instance_extra
From: Matt Riedemann, 2015-07-31