Lock wait timeout exceeded; try restarting transaction

Issue #227 new
misisko1 created an issue

Hi,

i got some use cases which end with mysterious transaction error. I use mysql and INNODB.

  1. login with local account ends with timeout, but LDAP works fine
  2. 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

2016-06-21 07_42_55-mysql.exprit.sk_KALLITHEA_kallithea_users_ - HeidiSQL Portable 8.3.0.4694.png

Comments (4)

  1. misisko1 reporter

    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.

  2. Mads Kiilerich

    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.

  3. Konstantin Veretennicov

    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.

  4. Log in to comment