MySQL Forums
Forum List  »  InnoDB

InnoDB lock timeout on UPDATE
Posted by: Andy Smith
Date: March 27, 2008 08:41PM

I have the following table:

mysql> show columns from workouts;
+---------------+--------------+------+-----+---------+----------------+
| Field | Type | Null | Key | Default | Extra |
+---------------+--------------+------+-----+---------+----------------+
| id | int(11) | NO | PRI | NULL | auto_increment |
| name | varchar(255) | YES | | NULL | |
| private | tinyint(1) | YES | | NULL | |
| description | text | YES | | NULL | |
| active | tinyint(1) | YES | | NULL | |
| program_id | int(11) | YES | MUL | NULL | |
| workout_order | int(11) | YES | | 0 | |
+---------------+--------------+------+-----+---------+----------------+
7 rows in set (0.01 sec)

I also have an index on program_id.

Whenever I run an update on this table, it goes very slow. I used innotop and watched the database when the query was running, and it is waiting on a record lock, but it doesn't seem like another transaction has it locked.

Here is an example of a query that makes is hang:

UPDATE `workouts` SET `workout_order` = 0, `private` = NULL, `active` = 1, `description` = '', `program_id` = 22047, `name` = 'Upper Chest and Tricepts' WHERE `id` = 12420

Here is the output of SHOW INNODB STATUS when it is waiting on a lock:

mysql> show innodb status\G
*************************** 1. row ***************************
Status:
=====================================
080327 19:42:13 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 41 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 34610, signal count 34596
Mutex spin waits 0, rounds 133446, OS waits 656
RW-shared spins 70824, OS waits 32244; RW-excl spins 4123, OS waits 1484
------------
TRANSACTIONS
------------
Trx id counter 0 26553679
Purge done for trx's n:o < 0 26553613 undo n:o < 0 0
History list length 21
Total number of lock structs in row lock hash table 2
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 0, not started, process no 326, OS thread id 1141827920
MySQL thread id 47, query id 400379 localhost root
show innodb status
---TRANSACTION 0 26553666, not started, process no 326, OS thread id 1141963088
MySQL thread id 44, query id 400304 localhost root
---TRANSACTION 0 26553678, not started, process no 326, OS thread id 1141152080
MySQL thread id 43, query id 400318 localhost root
---TRANSACTION 0 26543021, not started, process no 326, OS thread id 1141422416
MySQL thread id 31, query id 400379 localhost root
---TRANSACTION 0 26553494, not started, process no 326, OS thread id 1141287248
MySQL thread id 12, query id 399889 localhost root
---TRANSACTION 0 26553613, ACTIVE 25 sec, process no 326, OS thread id 1141692752 starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 368
MySQL thread id 45, query id 400236 localhost root Updating
UPDATE `workouts` SET `workout_order` = 0, `private` = NULL, `active` = 1, `description` = '', `program_id` = 19090, `name` = 'Upper Body' WHERE `id` = 12384
------- TRX HAS BEEN WAITING 25 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 9068 n bits 184 index `PRIMARY` of table `gyminee_production/workouts` trx id 0 26553613 lock_mode X locks rec but not gap waiting
Record lock, heap no 114 PHYSICAL RECORD: n_fields 9; compact format; info bits 0
0: len 4; hex 80003060; asc 0`;; 1: len 6; hex 000001952a70; asc *p;; 2: len 7; hex 8000000b6b0110; asc k ;; 3: len 10; hex 557070657220426f6479; asc Upper Body;; 4: SQL NULL; 5: len 0; hex ; asc ;; 6: len 1; hex 81; asc ;; 7: len 4; hex 80004a92; asc J ;; 8: len 4; hex 80000000; asc ;;

------------------
---TRANSACTION 0 26553488, ACTIVE 84 sec, process no 326, OS thread id 1141557584
2 lock struct(s), heap size 368
MySQL thread id 46, query id 399870 localhost root
--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: waiting for i/o request (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (write thread)
Pending normal aio reads: 0, aio writes: 0,
ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
463105 OS file reads, 54178 OS file writes, 29194 OS fsyncs
4.90 reads/s, 29507 avg bytes/read, 2.98 writes/s, 2.41 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 5, seg size 7,
11700 inserts, 11700 merged recs, 5693 merges
Hash table size 17393, used cells 868, node heap has 3 buffer(s)
3.37 hash searches/s, 34.73 non-hash searches/s
---
LOG
---
Log sequence number 0 2551850699
Log flushed up to 0 2551850699
Last checkpoint at 0 2551850699
0 pending log writes, 0 pending chkp writes
22286 log i/o's done, 2.27 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 22018032; in additional pool allocated 1044224
Buffer pool size 512
Free buffers 0
Database pages 509
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages read 743838, created 319, written 32793
8.83 reads/s, 0.00 creates/s, 0.90 writes/s
Buffer pool hit rate 997 / 1000
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
1 read views open inside InnoDB
Main thread process no. 326, id 1140881744, state: waiting for server activity
Number of rows inserted 9619, updated 2133, deleted 2375, read 557610996
0.68 inserts/s, 0.66 updates/s, 0.59 deletes/s, 18950.25 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

1 row in set, 1 warning (0.21 sec)




I would very much appreciate help on this, as I have been stuck on this bug for a few days. I am happy to provide more information to help get to the bottom of this problem. I have a web app, and performance tanks when this happens.

Options: ReplyQuote


Subject
Views
Written By
Posted
InnoDB lock timeout on UPDATE
4398
March 27, 2008 08:41PM
2087
April 02, 2008 01:53AM


Sorry, you can't reply to this topic. It has been closed.

Content reproduced on this site is the property of the respective copyright holders. It is not reviewed in advance by Oracle and does not necessarily represent the opinion of Oracle or any other party.