Issue #227: Lock wait timeout exceeded; try restarting transaction
| Reported by: | misisko1 |
| State: | new |
| Created on: | 2016-06-21 05:49 |
| Updated on: | 2016-06-21 17:14 |
Description
Hi,
i got some use cases which end with mysterious transaction error. I use mysql and INNODB.
- login with local account ends with timeout, but LDAP works fine
- comment and review changeset ends with timeout
All those errors lead to timeout in 'UPDATE users' SQL statements. A attach some logs.
Error (for example from login as admin local account - LDAP works fine):
OperationalError: (OperationalError) (1205, 'Lock wait timeout exceeded; try restarting transaction') 'UPDATE users SET last_login=%s WHERE users.user_id = %s' (datetime.datetime(2016, 6, 21, 7, 39, 23, 736317), 2L) URL: http://mercurial.######.##/_admin/login?came_from=%2F File '/opt/kallithea/venv/local/lib/python2.7/site-packages/weberror/errormiddleware.py', line 171 in __call__ app_iter = self.application(environ, sr_checker) File '/opt/kallithea/venv/local/lib/python2.7/site-packages/kallithea/lib/middleware/sessionmiddleware.py', line 62 in __call__ return self.wrap_app(environ, session_start_response) File '/opt/kallithea/venv/local/lib/python2.7/site-packages/routes/middleware.py', line 131 in __call__ response = self.app(environ, start_response) File '/opt/kallithea/venv/local/lib/python2.7/site-packages/pylons/wsgiapp.py', line 103 in __call__ response = self.dispatch(controller, environ, start_response) File '/opt/kallithea/venv/local/lib/python2.7/site-packages/pylons/wsgiapp.py', line 313 in dispatch return controller(environ, start_response) File '/opt/kallithea/venv/local/lib/python2.7/site-packages/kallithea/lib/base.py', line 446 in __call__ return WSGIController.__call__(self, environ, start_response) File '/opt/kallithea/venv/local/lib/python2.7/site-packages/pylons/controllers/core.py', line 214 in __call__ response = self._dispatch_call() File '/opt/kallithea/venv/local/lib/python2.7/site-packages/pylons/controllers/core.py', line 164 in _dispatch_call response = self._inspect_call(func) File '/opt/kallithea/venv/local/lib/python2.7/site-packages/pylons/controllers/core.py', line 107 in _inspect_call result = self._perform_call(func, args) File '/opt/kallithea/venv/local/lib/python2.7/site-packages/pylons/controllers/core.py', line 57 in _perform_call return func(**args) File '/opt/kallithea/venv/local/lib/python2.7/site-packages/kallithea/controllers/login.py', line 116 in index is_external_auth=False) File '/opt/kallithea/venv/local/lib/python2.7/site-packages/kallithea/lib/base.py', line 116 in log_in_user meta.Session().commit() File '/opt/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/orm/session.py', line 710 in commit self.transaction.commit() File '/opt/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/orm/session.py', line 368 in commit self._prepare_impl() File '/opt/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/orm/session.py', line 347 in _prepare_impl self.session.flush() File '/opt/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/orm/session.py', line 1734 in flush self._flush(objects) File '/opt/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/orm/session.py', line 1805 in _flush flush_context.execute() File '/opt/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/orm/unitofwork.py', line 331 in execute rec.execute(self) File '/opt/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/orm/unitofwork.py', line 475 in execute uow File '/opt/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/orm/persistence.py', line 59 in save_obj mapper, table, update) File '/opt/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/orm/persistence.py', line 485 in _emit_update_statements execute(statement, params) File '/opt/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py', line 1449 in execute params) File '/opt/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py', line 1584 in _execute_clauseelement compiled_sql, distilled_params File '/opt/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py', line 1698 in _execute_context context) File '/opt/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py', line 1691 in _execute_context context) File '/opt/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/engine/default.py', line 331 in do_execute cursor.execute(statement, parameters) File '/opt/kallithea/venv/local/lib/python2.7/site-packages/MySQLdb/cursors.py', line 205 in execute self.errorhandler(self, exc, value) File '/opt/kallithea/venv/local/lib/python2.7/site-packages/MySQLdb/connections.py', line 36 in defaulterrorhandler raise errorclass, errorvalue OperationalError: (OperationalError) (1205, 'Lock wait timeout exceeded; try restarting transaction') 'UPDATE users SET last_login=%s WHERE users.user_id = %s' (datetime.datetime(2016, 6, 21, 7, 39, 23, 736317), 2L)
In MySQL a type 'show processlist;'
I got
Attachments
Comments
Comment by Mads Kiilerich, on 2016-06-21 13:09
That seems like a database issue more than a Kallithea issue.
Comment by misisko1, on 2016-06-21 14:27
I need to do more tests,but it concern only rows in users table with admin flag. When admin is set to 0 lock disapper.
Comment by Mads Kiilerich, on 2016-06-21 15:28
I don't know what that means ;-)
Kallithea doesn't have any database specific code - sqlalchemy generally makes it work on postgresql and sqlite (which I both test) and according to other testers also on mysql.
Comment by Konstantin Veretennicov, on 2016-06-21 17:14
I know little of MySQL, but this looks like some transactions deadlocked and db engine "resolved" it by aborting one of them. This can be due to high transaction isolation level + high load; or not enough indexes.
It would help to find out what are those deadlocking transactions, because exception only shows one of them, "the victim".
Or even better if you can make this reproducible for us.