Comment 0 for bug 1026709

Revision history for this message
Johannes Erdfelt (johannes.erdfelt) wrote :

The quota reservations code acquires SQL locks inconsistently which can result in a deadlock.

Because of a bug in SQLAlchemy (http://www.sqlalchemy.org/trac/ticket/2536) it can result in this exception:

[...]
2012-07-16 22:16:03 TRACE nova.api.openstack File "/usr/lib/python2.6/dist-packages/nova/api/openstack/compute/servers.py", line 707, in create
2012-07-16 22:16:03 TRACE nova.api.openstack scheduler_hints=scheduler_hints)
2012-07-16 22:16:03 TRACE nova.api.openstack File "/usr/lib/python2.6/dist-packages/nova/compute/api.py", line 780, in create
2012-07-16 22:16:03 TRACE nova.api.openstack scheduler_hints=scheduler_hints)
2012-07-16 22:16:03 TRACE nova.api.openstack File "/usr/lib/python2.6/dist-packages/nova/compute/api.py", line 372, in _create_instance
2012-07-16 22:16:03 TRACE nova.api.openstack context, instance_type, min_count, max_count)
2012-07-16 22:16:03 TRACE nova.api.openstack File "/usr/lib/python2.6/dist-packages/nova/compute/api.py", line 178, in _check_num_instances_quota
2012-07-16 22:16:03 TRACE nova.api.openstack cores=req_cores, ram=req_ram)
2012-07-16 22:16:03 TRACE nova.api.openstack File "/usr/lib/python2.6/dist-packages/nova/quota.py", line 695, in reserve
2012-07-16 22:16:03 TRACE nova.api.openstack expire=expire)
2012-07-16 22:16:03 TRACE nova.api.openstack File "/usr/lib/python2.6/dist-packages/nova/quota.py", line 338, in reserve
2012-07-16 22:16:03 TRACE nova.api.openstack FLAGS.until_refresh, FLAGS.max_age)
2012-07-16 22:16:03 TRACE nova.api.openstack File "/usr/lib/python2.6/dist-packages/nova/db/api.py", line 1050, in quota_reserve
2012-07-16 22:16:03 TRACE nova.api.openstack until_refresh, max_age)
2012-07-16 22:16:03 TRACE nova.api.openstack File "/usr/lib/python2.6/dist-packages/nova/db/sqlalchemy/api.py", line 132, in wrapper
2012-07-16 22:16:03 TRACE nova.api.openstack return f(*args, **kwargs)
2012-07-16 22:16:03 TRACE nova.api.openstack File "/usr/lib/python2.6/dist-packages/nova/db/sqlalchemy/api.py", line 2584, in quota_reserve
2012-07-16 22:16:03 TRACE nova.api.openstack usages = _get_quota_usages(context, session, deltas.keys())
2012-07-16 22:16:03 TRACE nova.api.openstack File "/usr/lib/python2.6/dist-packages/nova/db/sqlalchemy/api.py", line 2572, in _get_quota_usages
2012-07-16 22:16:03 TRACE nova.api.openstack with_lockmode('update').\
2012-07-16 22:16:03 TRACE nova.api.openstack File "/usr/lib/python2.6/dist-packages/sqlalchemy/orm/query.py", line 1729, in all
2012-07-16 22:16:03 TRACE nova.api.openstack return list(self)
2012-07-16 22:16:03 TRACE nova.api.openstack File "/usr/lib/python2.6/dist-packages/sqlalchemy/orm/query.py", line 1953, in instances
2012-07-16 22:16:03 TRACE nova.api.openstack fetch = cursor.fetchall()
2012-07-16 22:16:03 TRACE nova.api.openstack File "/usr/lib/python2.6/dist-packages/sqlalchemy/engine/base.py", line 2979, in fetchall
2012-07-16 22:16:03 TRACE nova.api.openstack l = self.process_rows(self._fetchall_impl())
2012-07-16 22:16:03 TRACE nova.api.openstack File "/usr/lib/python2.6/dist-packages/sqlalchemy/engine/base.py", line 2948, in _fetchall_impl
2012-07-16 22:16:03 TRACE nova.api.openstack self._non_result()
2012-07-16 22:16:03 TRACE nova.api.openstack File "/usr/lib/python2.6/dist-packages/sqlalchemy/engine/base.py", line 2953, in _non_result
2012-07-16 22:16:03 TRACE nova.api.openstack "This result object does not return rows. "
2012-07-16 22:16:03 TRACE nova.api.openstack ResourceClosedError: This result object does not return rows. It has been closed automatically.

However, the real bug is a deadlock (hidden by the aforementioned SQLAlchemy bug), which should show as an OperationError similar to this:

"Deadlock found when trying to get lock; try restarting transaction"

The problem is a result of the quota_reserve code acquiring the quota_usages lock before the reservations lock, whereas quota_commit and quota_rollback acquire the locks in reverse order.