How can I troubleshoot MySQL Lock Timeout Errors with Rails?

Question

All of a sudden (without any changes to related code) we are getting lock errors through active record such as:

ActiveRecord::StatementInvalid: Mysql2::Error: Lock wait timeout exceeded; 
try restarting transaction: UPDATE `items` SET `state` = 'reserved', `updated_at` = '2012-09-15 17:58:21' WHERE `items`.`id` = 248220

and

ActiveRecord::StatementInvalid: Mysql2::Error: Lock wait timeout exceeded; 
try restarting transaction: DELETE FROM `sessions` WHERE `sessions`.`id` = 41997883

We aren't doing our own transactions in either of these models, so the only transactions are the built in rails ones. There has not been a surge in traffic or request volume.

These errors appear to be when a "new" query tries to run on a locked table and has to wait, how do we see what it's waiting for? How do we figure out which part of our code is issuing queries that lock the tables for extended periods of time?

Any ideas on where we can look or how to investigate the cause of this?

Answer 1

Take a look at pt-deadlock-logger, while not directly related to rails, should give you a considerable amount of information about the deadlocks occurring.

http://www.percona.com/doc/percona-toolkit/2.1/pt-deadlock-logger.html

There is a nice writeup with some examples: http://www.mysqlperformanceblog.com/2012/09/19/logging-deadlocks-errors/

The tool is very simple and useful. It monitors the output of SHOW ENGINE INNODB STATUS and log the new deadlocks to a file or to a table that we can later review. Let’s see how it works with an example.

The article goes on to explain that this can log information about the deadlock such as queries involved, which hosts, thread ids, etc.

I've also found it helpful to prefix queries with comments to allow tracking, such as the file or module, function, even which user. The query comments usually get passed down all the way to diagnostic tools like this, and could help track down which parts of code and in which circumstances are causing deadlocks.