Extremely slow update via primary key

I have an update that is taking a huge amount of time, and I can not see the reason why.

From the slow query log I see :

User@Host: root[root] @ xx-xx-xx-xxx

Thread_id: 41664 Schema: palio_demo Last_errno: 1205 Killed: 0

Query_time: 51.302989 Lock_time: 0.000082 Rows_sent: 0 Rows_examined: 0 Rows_affected: 0 Rows_read: 1

Bytes_sent: 67 Tmp_tables: 0 Tmp_disk_tables: 0 Tmp_table_sizes: 0

InnoDB_trx_id: DA7EF817

SET timestamp=1346437934;
UPDATE ad_network_ad_groups SET ad_network_task = NULL WHERE id = 544632;

The table itself is not overly large 480K rows (not that it should matter on a primary key update)

The table looks like :

mysql> show create table ad_network_ad_groups \G
*************************** 1. row ***************************
Table: ad_network_ad_groups
Create Table: CREATE TABLE ad_network_ad_groups (

… About 20 columns


(a couple other indexes here, but the updated column is not indexed)

1 row in set (0.00 sec)

There is an update trigger on the table, and I can post the code if need be, but it checks for the change to a couple columns, and if it finds it will insert a journal record, but the column being updated is not one of the 3 the trigger is trapping.

This is running on AWS, and I’ve taken a snapshot of the disks and created a test environment to test as to why this might be happening, but can’t reproduce it in test, runs in .01 seconds there (which is what I would expect in prod).

Any idea what I could check next ?


From your slow log entry it seems that your update didn’t happen due to 1205 error, which is “(ER_LOCK_WAIT_TIMEOUT): Lock wait timeout exceeded; try restarting transaction”. The query took >50s because the default value for innodb_lock_wait_timeout is 50s, and after that period your query attempt timeout was reached.
So it seems that other transaction was holding lock on this row for that long.

btw you can enable more innodb stats in slow log by setting log_slow_verbosity described here:
http://www.percona.com/doc/percona-server/5.1/diagnostics/sl ow_extended.html?id=percona-server:features:slow_extended_51 &redirect=2#log_slow_verbosity