How to log all the MySQL queries that waited for a table lock?

Question

We are trying to diagnose a deadlock problem MySQL 5.0. Currently all the tables are MyISAM tables and so all the locks are table locks. We have a good table_locks_waited to table_locks_immediate ratio (lower than 1:1000), but within a couple of minutes we get a couple of deadlocks. This only happens on Amazon EC2 but not any of our other servers.

Is there a way to log all the queries that could not obtain a table lock immediately? We want to see all the queries that contributed to the table_locks_waited number.

Solution 1

In the slow log, one of the fields displayed is the Lock Time

Here is a sample with two queries that were logged

# Time: 110726  1:00:09
# User@Host: mysql[mysql] @  [10.64.100.208]
# Query_time: 8  Lock_time: 0  Rows_sent: 0  Rows_examined: 852669
insert into rates_old select * from rates;
# Time: 110726  1:30:56
# User@Host: mysql[mysql] @  [10.64.100.208]
# Query_time: 50  Lock_time: 0  Rows_sent: 0  Rows_examined: 11015414
SET timestamp=1311661856;
delete a.*,  b.* from zillowDump a, zillowHistory b where a.loanRequestId=b.loanRequestId and a.addDate < date_sub(now(), INTERVAL 2 week);

Please note the Lock_time: field.

CAVEAT

In MySQL 5.1+ the field appears in the default mysql.slow_log table

mysql> show create table mysql.slow_log\G
*************************** 1. row ***************************
       Table: slow_log
Create Table: CREATE TABLE `slow_log` (
  `start_time` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,
  `user_host` mediumtext NOT NULL,
  `query_time` time NOT NULL,
  `lock_time` time NOT NULL,
  `rows_sent` int(11) NOT NULL,
  `rows_examined` int(11) NOT NULL,
  `db` varchar(512) NOT NULL,
  `last_insert_id` int(11) NOT NULL,
  `insert_id` int(11) NOT NULL,
  `server_id` int(10) unsigned NOT NULL,
  `sql_text` mediumtext NOT NULL
) ENGINE=CSV DEFAULT CHARSET=utf8 COMMENT='Slow log'
1 row in set (0.00 sec)

Either way, you can get a hold of the lock time of any query

Solution 2

Try watching the queries and locks in real time using this command:

watch -n 0.5 'mysqladmin -u root -ppassword "processlist"'

If the locking happens for any length of time, you should get a good idea of what is going on.

Comments

[Greg Petersen]

Did you check the SHOW FULL PROCESSLIST output? Also take a look at Table Locking Issues on the MySQL's site.

[Sudip Bhandari]

quite helpful.. thanks