yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1342086] Re: DBDeadlock in delete_instance

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Russell Bryant <1342086@xxxxxxxxxxxxxxxxxx>
Date: Wed, 23 Jul 2014 15:00:54 -0000
Reply-to: Bug 1342086 <1342086@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
** Changed in: nova
       Status: Fix Committed => Fix Released

** Changed in: nova
    Milestone: None => juno-2

-- 
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/1342086

Title:
  DBDeadlock in delete_instance

Status in OpenStack Compute (Nova):
  Fix Released

Bug description:
  2014-07-15 11:11:59.993 ERROR nova.api.openstack [req-cc826bd5-7d9a-491d-bdde-c64a70a0a630 TelemetryNotificationAPITestXML-21795205 TelemetryNotificationAPITestXML-1445201375] Caught error: (OperationalError) (1213, 'Deadlock found when trying to get lock; try restarting transaction') 'UPDATE instances SET updated_at=updated_at, deleted_at=%s, deleted=id WHERE instances.deleted = %s AND instances.uuid = %s AND instances.host IS NULL' (datetime.datetime(2014, 7, 15, 11, 11, 59, 979427), 0, 'bbb916b2-9854-4c5e-9687-515352f3e4df')
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack Traceback (most recent call last):
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/api/openstack/__init__.py", line 125, in __call__
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     return req.get_response(self.application)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1320, in send
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     application, catch_exc_info=False)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1284, in call_application
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     app_iter = application(self.environ, start_response)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     return resp(environ, start_response)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token.py", line 661, in __call__
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     return self._app(env, start_response)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     return resp(environ, start_response)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     return resp(environ, start_response)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/routes/middleware.py", line 131, in __call__
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     response = self.app(environ, start_response)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     return resp(environ, start_response)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 130, in __call__
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     resp = self.call_func(req, *args, **self.kwargs)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 195, in call_func
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     return self.func(req, *args, **kwargs)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/api/openstack/wsgi.py", line 906, in __call__
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     content_type, body, accept)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/api/openstack/wsgi.py", line 972, in _process_stack
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     action_result = self.dispatch(meth, request, action_args)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/api/openstack/wsgi.py", line 1056, in dispatch
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     return method(req=request, **action_args)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/api/openstack/compute/servers.py", line 1201, in delete
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     self._delete(req.environ['nova.context'], req, id)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/api/openstack/compute/servers.py", line 1030, in _delete
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     self.compute_api.delete(context, instance)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/compute/api.py", line 192, in wrapped
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     return func(self, context, target, *args, **kwargs)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/compute/api.py", line 182, in inner
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     return function(self, context, instance, *args, **kwargs)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/compute/api.py", line 209, in _wrapped
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     return fn(self, context, instance, *args, **kwargs)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/compute/api.py", line 163, in inner
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     return f(self, context, instance, *args, **kw)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/compute/api.py", line 1719, in delete
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     self._delete_instance(context, instance)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/compute/api.py", line 1709, in _delete_instance
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     task_state=task_states.DELETING)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/compute/api.py", line 1543, in _delete
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     user_id=user_id)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/openstack/common/excutils.py", line 82, in __exit__
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     six.reraise(self.type_, self.value, self.tb)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/compute/api.py", line 1480, in _delete
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     instance.destroy()
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/objects/base.py", line 196, in wrapper
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     return fn(self, ctxt, *args, **kwargs)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/objects/instance.py", line 358, in destroy
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     constraint=constraint)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/db/api.py", line 664, in instance_destroy
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     rv = IMPL.instance_destroy(context, instance_uuid, constraint)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 164, in wrapper
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     return f(*args, **kwargs)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 1688, in instance_destroy
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     count = query.soft_delete()
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/openstack/common/db/sqlalchemy/session.py", line 694, in soft_delete
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     synchronize_session=synchronize_session)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2690, in update
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     update_op.exec_()
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 816, in exec_
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     self._do_exec()
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 913, in _do_exec
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     update_stmt, params=self.query._params)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/openstack/common/db/sqlalchemy/session.py", line 444, in _wrap
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     _raise_if_deadlock_error(e, self.bind.dialect.name)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/openstack/common/db/sqlalchemy/session.py", line 427, in _raise_if_deadlock_error
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack     raise exception.DBDeadlock(operational_error)
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack DBDeadlock: (OperationalError) (1213, 'Deadlock found when trying to get lock; try restarting transaction') 'UPDATE instances SET updated_at=updated_at, deleted_at=%s, deleted=id WHERE instances.deleted = %s AND instances.uuid = %s AND instances.host IS NULL' (datetime.datetime(2014, 7, 15, 11, 11, 59, 979427), 0, 'bbb916b2-9854-4c5e-9687-515352f3e4df')
  2014-07-15 11:11:59.993 20784 TRACE nova.api.openstack 

  
  http://logs.openstack.org/62/100162/3/check/check-tempest-dsvm-full/77badd4/logs/screen-n-api.txt.gz?level=INFO#_2014-07-15_11_11_59_993

  
  Discovered in the check queue.

  query: message:"Deadlock found when trying to get lock" AND
  message:"UPDATE instances SET" AND NOT tags:"console.html"

  9 hits in last 10 days.

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

[Bug 1342086] [NEW] DBDeadlock in delete_instance
From: Joe Gordon, 2014-07-15