yahoo-eng-team team mailing list archive

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

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: OpenStack Infra <1480305@xxxxxxxxxxxxxxxxxx>
Date: Thu, 08 Sep 2016 18:25:53 -0000
Reply-to: Bug 1480305 <1480305@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Reviewed:  https://review.openstack.org/292800
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=df15e467b61fee781e78b07bf910d6b411bafd44
Submitter: Jenkins
Branch:    master

commit df15e467b61fee781e78b07bf910d6b411bafd44
Author: John Garbutt <john.garbutt@xxxxxxxxxxxxx>
Date:   Tue Mar 15 10:21:47 2016 +0000

    db: retry on deadlocks while adding an instance
    
    We are hitting deadlocks in the gate when we are inserting the new
    instance_extra row into the DB.
    
    We should follow up this fix and look at way to avoid the deadlock
    happening rather than retrying it. It currently doesn't happen too
    often, so this should be enough to stop the problem while we work on a
    better fix.
    
    Closes-Bug: #1480305
    
    Change-Id: Iba218bf28c7d1e6040c551fe836d6fa5e5e45f4d


** Changed in: nova
       Status: Triaged => Fix Released

-- 
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):
  Fix Released
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