When does InnoDB time out instead of reporting deadlock?

Question

I have a "Lock wait timeout exceeded" error from MySQL that I can't reproduce or diagnose. I'm sure it's deadlock (as opposed to a transaction grabbing a lock then twiddling its thumbs), because my logs show that another process started at the same time, also hung, then continued when the first timed out. But normally, InnoDB detects deadlocks without timing out. So I am trying to understand why this deadlock was not detected.

Both transactions are using isolation level serializable. (I have a fair understanding of InnoDB locking in this isolation level.) There is one non-InnoDB (MyISAM) table used in the transaction, which I insert into and update. However, I don't understand how it could be involved in the deadlock, because I believe MyISAM just takes a table lock during the inserts and updates (then immediately releases it since MyISAM is not transactional), so no other lock is taken while this table lock is held.

So I'm convinced that the deadlock involves only InnoDB tables, which brings me back to the question of why it was not detected. The MySQL documentation (http://dev.mysql.com/doc/refman/5.1/en/innodb-deadlock-detection.html) implies that deadlock detection pretty much always works. The problem cases I found while searching involve things like explicit "lock table", "alter table", and "insert delayed". I'm not doing any of these things, just inserts, updates, and selects (some of my selects are "for update").

I tried to reproduce by creating one MyISAM table and a couple InnoDB tables and doing various sequences of insert and update into MyISAM, and "select for update"s in InnoDB. But every time I produced a deadlock, InnoDB reported it immediately. I could not reproduce a timeout.

Any other tips for diagnosing this? I am using mysql 5.1.49.

Answer 1

One tip is that you can use SHOW INNODB STATUS to, you guessed it, show the status of the InnoDB engine.

The information it returns (a big hunk of text) includes info on current table locks, and the last detected deadlock (under the heading "LATEST DETECTED DEADLOCK"), so this trick isn't that useful well after the fact, but it can help you track down a hung query while it's happening.

mysqladmin debug can also print useful lock-debugging information.

A third trick is to create a magically-named table called innodb_lock_monitor as described at http://dev.mysql.com/doc/refman/5.1/en/innodb-monitors.html which gives more detailed lock debugging.

HTH!

UPDATE:

It may not be detecting a deadlock becuase it isn't actually a deadlock, but more likely that one process is waiting for a row lock on a row that is locked by another process. From the manual for the innodb_lock_wait_timeout variable:

The timeout in seconds an InnoDB transaction may wait for a row lock before giving up. The default value is 50 seconds. A transaction that tries to access a row that is locked by another InnoDB transaction will hang for at most this many seconds before issuing the following error:

ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction When a lock wait timeout occurs, the current statement is not executed. The current transaction is not rolled back. (Until MySQL 5.0.13 InnoDB rolled back the entire transaction if a lock wait timeout happened.

A deadlock occurs, for example, when two processes each need to lock rows that are locked by the other process, and no amount of waiting will resolve the conflict.

Answer 2

I managed to reproduce and diagnose the problem. It is a deadlock involving MyISAM and InnoDB. It appears to be an interaction between transactional InnoDB row locking and non-transactional MyISAM table locking. I've filed a bug: http://bugs.mysql.com/bug.php?id=57118. At any rate, I believe the answer to my original question is, InnoDB should always detect deadlocks, unless there is a bug in MySQL. ;-)