# Extremely slow update via primary key

**URL:** <https://forums.percona.com/t/extremely-slow-update-via-primary-key/1883>\
**Category:** Other MySQL® Questions\
**Created:** [August 31, 2012, 1:31pm UTC](https://forums.percona.com/t/extremely-slow-update-via-primary-key/1883 "2012-08-31T13:31:27Z")\
**Posts on this page:** 2\
**Page:** 1

<div class="post-metadata">

**Author:** ![dandummer](https://avatars.discourse-cdn.com/v4/letter/d/b5e925/32.png) [@dandummer](https://forums.percona.com/u/dandummer)\
**Post date:** [August 31, 2012, 1:31pm UTC](https://forums.percona.com/t/extremely-slow-update-via-primary-key/1883/1 "2012-08-31T13:31:27Z")

</div>

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` (  
`id` bigint(20) NOT NULL AUTO\_INCREMENT,  
..  
.. About 20 columns  
..

PRIMARY KEY (`id`),

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

) ENGINE=InnoDB AUTO\_INCREMENT=565287 DEFAULT CHARSET=latin1  
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 ?

---

<div class="post-metadata">

**Author:** ![przemek](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/przemek/32/3_2.png) [@przemek](https://forums.percona.com/u/przemek)\
**Post date:** [September 4, 2012, 6:36am UTC](https://forums.percona.com/t/extremely-slow-update-via-primary-key/1883/2 "2012-09-04T06:36:40Z")

</div>

Dan,

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](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
