Galera deadlock on SELECT FOR UPDATE is not handled

[Roman Podoliaka]

Galera has a known limitation on not being able to handle concurrent SELECT FOR UPDATE queries. If a multiple transactions with SELECT FOR UPDATE statements selecting the same set of rows are executed concurrently, one of them will succeed, while other ones will fail with a deadlock. In order to be able to restart the transaction, we should detect deadlocks properly.

Running nova-api in the wild shows, that at least one additional exception is not currently handled properly:

2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/nova/db/api.py", line 1128, in quota_reserve
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack project_id=project_id, user_id=user_id)
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.py", line 143, in wrapper
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack return f(*args, **kwargs)
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.py", line 181, in wrapped
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack return f(*args, **kwargs)
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.py", line 3185, in quota_reserve
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack context, session, project_id, user_id)
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.py", line 3153, in _get_project_user_quota_usages
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack with_lockmode('update').\
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2300, in all
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack return list(self)
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2412, in __iter__
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack return self._execute_and_instances(context)
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2427, in _execute_and_instances
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack result = conn.execute(querycontext.statement, self._params)
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 729, in execute
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack return meth(self, multiparams, params)
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/sqlalchemy/sql/elements.py", line 321, in _execute_on_connection
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack return connection._execute_clauseelement(self, multiparams, params)
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 826, in _execute_clauseelement
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack compiled_sql, distilled_params
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 958, in _execute_context
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack context)
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1156, in _handle_dbapi_exception
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack util.raise_from_cause(newraise, exc_info)
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack reraise(type(exception), exception, tb=exc_tb)
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 951, in _execute_context
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack context)
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 436, in do_execute
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack cursor.execute(statement, parameters)
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/MySQLdb/cursors.py", line 205, in execute
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack self.errorhandler(self, exc, value)
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack raise errorclass, errorvalue
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack OperationalError: (OperationalError) (1205, 'Lock wait timeout exceeded; try restarting transaction') 'SELECT quota_usages.deleted_at AS quota_usages_deleted_at, quota_usages.deleted AS quota_usages_deleted, quota_usages.created_at AS quota_usages_created_at, quota_usages.updated_at AS quota_usages_updated_at, quota_usages.id AS quota_usages_id, quota_usages.project_id AS quota_usages_project_id, quota_usages.user_id AS quota_usages_user_id, quota_usages.resource AS quota_usages_resource, quota_usages.in_use AS quota_usages_in_use, quota_usages.reserved AS quota_usages_reserved, quota_usages.until_refresh AS quota_usages_until_refresh \nFROM quota_usages \nWHERE quota_usages.deleted = %s AND quota_usages.project_id = %s FOR UPDATE' (0, '638d3d20992046e0a963e33ebd61c48d')
2014-11-19 03:08:52.393 20181 TRACE nova.api.openstack

[Viktor Serhieiev (vsergeyev)]

Fixed in oslo.db by https://review.openstack.org/#/c/135674/