Mysql – Lock wait time out exceed restart transaction

innodbMySQLtransaction

I had got error on the lock wait time out so below I got 3 samples taken. One I took before the increase innodb_lock_wait_timeout to 120. So is there anything else I must tweak based on the logs below.

Before increasing

1280
MySQL thread id 183, query id 465855 192.168.100.11 vscs1
---TRANSACTION 0 2491326, not started, process no 6622, OS thread id 140388595255040
MySQL thread id 185, query id 479140 192.168.100.11 vscs1
---TRANSACTION 0 2491044, not started, process no 6622, OS thread id 140388594988800
MySQL thread id 186, query id 463354 192.168.100.11 vscs1
---TRANSACTION 0 2491324, not started, process no 6622, OS thread id 140388599514880
MySQL thread id 147, query id 479132 192.168.100.11 vscs1
---TRANSACTION 0 2491100, not started, process no 6622, OS thread id 140388724803328
MySQL thread id 133, query id 477373 192.168.100.11 vscs1
---TRANSACTION 0 2491278, not started, process no 6622, OS thread id 140388596586240
MySQL thread id 168, query id 476621 192.168.100.11 vscs1
---TRANSACTION 0 2490727, not started, process no 6622, OS thread id 140388596852480
MySQL thread id 167, query id 463538 192.168.100.11 vscs1
---TRANSACTION 0 2491140, not started, process no 6622, OS thread id 140388597651200
MySQL thread id 163, query id 463529 192.168.100.11 vscs1
---TRANSACTION 0 2491312, not started, process no 6622, OS thread id 140388598183680
MySQL thread id 157, query id 479053 192.168.100.11 vscs1
---TRANSACTION 0 2491294, not started, process no 6622, OS thread id 140388599781120
MySQL thread id 146, query id 478179 192.168.100.11 vscs1
---TRANSACTION 0 2491225, not started, process no 6622, OS thread id 140388600579840
MySQL thread id 143, query id 465144 192.168.100.11 vscs1
---TRANSACTION 0 2491305, not started, process no 6622, OS thread id 140388601112320
MySQL thread id 141, query id 478993 192.168.100.11 vscs1
---TRANSACTION 0 2491290, not started, process no 6622, OS thread id 140388601378560
MySQL thread id 139, query id 477383 192.168.100.11 vscs1
---TRANSACTION 0 2490874, not started, process no 6622, OS thread id 140388724270848
MySQL thread id 135, query id 463385 192.168.100.11 vscs1
---TRANSACTION 0 2491277, not started, process no 6622, OS thread id 140388601911040
MySQL thread id 137, query id 479062 192.168.100.11 vscs1
---TRANSACTION 0 2491135, not started, process no 6622, OS thread id 140388725069568
MySQL thread id 131, query id 463384 192.168.100.11 vscs1
---TRANSACTION 0 2491310, ACTIVE 29 sec, process no 6622, OS thread id 140388597384960 starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 368, 1 row lock(s)
MySQL thread id 165, query id 479034 192.168.100.11 vscs1 Updating
Update tblID Set lastValue=4372  Where tableName='tblUnAst'
Trx read view will not see trx with id >= 0 2491311, sees < 0 2490366
------- TRX HAS BEEN WAITING 29 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 19 page no 3 n bits 72 index `GEN_CLUST_INDEX` of table `scs`.`tblID` trx id 0 2491310 lock_mode X waiting
Record lock, heap no 2
------------------
---TRANSACTION 0 2491307, ACTIVE 38 sec, process no 6622, OS thread id 140388597917440 starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 368, 1 row lock(s)
MySQL thread id 162, query id 479004 192.168.100.11 vscs1 Updating
Update tblID Set lastValue=4372  Where tableName='tblUnAst'
Trx read view will not see trx with id >= 0 2491308, sees < 0 2490366
------- TRX HAS BEEN WAITING 38 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 19 page no 3 n bits 72 index `GEN_CLUST_INDEX` of table `scs`.`tblID` trx id 0 2491307 lock_mode X waiting
Record lock, heap no 2
------------------
---TRANSACTION 0 2491299, ACTIVE 46 sec, process no 6622, OS thread id 140388388042496 starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 368, 1 row lock(s)
MySQL thread id 132, query id 478208 192.168.100.11 vscs1 Updating
Update tblID Set lastValue=4372  Where tableName='tblUnAst'
Trx read view will not see trx with id >= 0 2491300, sees < 0 2490366
------- TRX HAS BEEN WAITING 46 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 19 page no 3 n bits 72 index `GEN_CLUST_INDEX` of table `scs`.`tblID` trx id 0 2491299 lock_mode X waiting
Record lock, heap no 2
------------------
---TRANSACTION 0 2491281, ACTIVE 64 sec, process no 6622, OS thread id 140388724004608
1 lock struct(s), heap size 368, 0 row lock(s), undo log entries 1
MySQL thread id 136, query id 477325 192.168.100.11 vscs1
Trx read view will not see trx with id >= 0 2491282, sees < 0 2490366
---TRANSACTION 0 2491256, ACTIVE 108 sec, process no 6622, OS thread id 140388598449920
1 lock struct(s), heap size 368, 0 row lock(s), undo log entries 1
MySQL thread id 158, query id 467973 192.168.100.11 vscs1
Trx read view will not see trx with id >= 0 2491257, sees < 0 2490366
---TRANSACTION 0 2491199, ACTIVE 153 sec, process no 6622, OS thread id 140388600846080
1 lock struct(s), heap size 368, 0 row lock(s), undo log entries 1
MySQL thread id 142, query id 464318 192.168.100.11 vscs1
Trx read view will not see trx with id >= 0 2491200, sees < 0 2490366
---TRANSACTION 0 2491086, ACTIVE 265 sec, process no 6622, OS thread id 140388724537088
2 lock struct(s), heap size 368, 0 row lock(s), undo log entries 2
MySQL thread id 134, query id 453252 192.168.100.11 vscs1
Trx read view will not see trx with id >= 0 2491087, sees < 0 2490366
---TRANSACTION 0 2490842, ACTIVE 587 sec, process no 6622, OS thread id 140388600313600
2 lock struct(s), heap size 368, 0 row lock(s), undo log entries 2
MySQL thread id 144, query id 404624 192.168.100.11 vscs1
Trx read view will not see trx with id >= 0 2490843, sees < 0 2490366
---TRANSACTION 0 2490708, ACTIVE 716 sec, process no 6622, OS thread id 140388593923840
5 lock struct(s), heap size 1216, 1 row lock(s), undo log entries 5
MySQL thread id 199, query id 370321 192.168.100.11 vscs1
Trx read view will not see trx with id >= 0 2490709, sees < 0 2490366
---TRANSACTION 0 2490648, ACTIVE 744 sec, process no 6622, OS thread id 140388601644800
2 lock struct(s), heap size 368, 0 row lock(s), undo log entries 2
MySQL thread id 138, query id 369508 192.168.100.11 vscs1
Trx read view will not see trx with id >= 0 2490649, sees < 0 2490366
---TRANSACTION 0 2490642, ACTIVE 750 sec, process no 6622, OS thread id 140388594190080
1 lock struct(s), heap size 368, 0 row lock(s), undo log entries 1
MySQL thread id 192, query id 367922 192.168.100.11 vscs1
Trx read view will not see trx with id >= 0 2490643, sees < 0 2490366
---TRANSACTION 0 2490555, ACTIVE 840 sec, process no 6622, OS thread id 140388595787520
4 lock struct(s), heap size 1216, 1 row lock(s), undo log entries 4
MySQL thread id 182, query id 349533 192.168.100.11 vscs1
Trx read view will not see trx with id >= 0 2490556, sees < 0 2490366
---TRANSACTION 0 2490533, ACTIVE 852 sec, process no 6622, OS thread id 140388596053760
1 lock struct(s), heap size 368, 0 row lock(s), undo log entries 1
MySQL thread id 177, query id 345850 192.168.100.11 vscs1
Trx read view will not see trx with id >= 0 2490534, sees < 0 2490366
---TRANSACTION 0 2490381, ACTIVE 987 sec, process no 6622, OS thread id 140388600047360
2 lock struct(s), heap size 368, 0 row lock(s), undo log entries 2
MySQL thread id 145, query id 84142 192.168.100.11 vscs1
Trx read view will not see trx with id >= 0 2490382, sees < 0 2490366
---TRANSACTION 0 2490376, ACTIVE 993 sec, process no 6622, OS thread id 140388598716160
1 lock struct(s), heap size 368, 0 row lock(s), undo log entries 1
MySQL thread id 150, query id 67292 192.168.100.11 vscs1
Trx read view will not see trx with id >= 0 2490377, sees < 0 2490366
---TRANSACTION 0 2490371, ACTIVE 995 sec, process no 6622, OS thread id 140388598982400
7 lock struct(s), heap size 1216, 7 row lock(s), undo log entries 5
MySQL thread id 149, query id 58852 192.168.100.11 vscs1
Trx read view will not see trx with id >= 0 2490372, sees < 0 2490366
---TRANSACTION 0 2490366, ACTIVE 998 sec, process no 6622, OS thread id 140388599248640
1 lock struct(s), heap size 368, 0 row lock(s), undo log entries 1
MySQL thread id 148, query id 50401 192.168.100.11 vscs1
Trx read view will not see trx with id >= 0 2490367, sees < 0 2490367
--------
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
23934 OS file reads, 2622 OS file writes, 1521 OS fsyncs
4.00 reads/s, 19894 avg bytes/read, 1.14 writes/s, 1.14 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2,
641 inserts, 641 merged recs, 513 merges
Hash table size 17393, node heap has 7 buffer(s)
110.27 hash searches/s, 64.42 non-hash searches/s
---
LOG
---
Log sequence number 0 1454407131
Log flushed up to   0 1454407131
Last checkpoint at  0 1454403687
0 pending log writes, 0 pending chkp writes
856 log i/o's done, 1.14 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 21296456; in additional pool allocated 1048576
Dictionary memory allocated 390168
Buffer pool size   512
Free buffers       0
Database pages     505
Modified db pages  15
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages read 128135, created 12, written 1874
4.86 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 992 / 1000
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
18 read views open inside InnoDB
Main thread process no. 6622, id 140388612400896, state: sleeping
Number of rows inserted 332, updated 353, deleted 0, read 10910686
0.29 inserts/s, 0.43 updates/s, 0.00 deletes/s, 473.93 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

1 row in set (0.00 sec)

ERROR:
No query specified

1st sample after increase

show engine innodb status\G
*************************** 1. row ***************************
  Type: InnoDB
  Name:
Status:
=====================================
130507  5:13:33 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 51 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 20519, signal count 20505
Mutex spin waits 0, rounds 4183, OS waits 15
RW-shared spins 45944, OS waits 20490; RW-excl spins 19, OS waits 12
------------
TRANSACTIONS
------------
Trx id counter 0 2493509
Purge done for trx's n:o < 0 2493504 undo n:o < 0 0
History list length 37
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 2493455, not started, process no 7268, OS thread id 140471080023808
MySQL thread id 90, query id 114373 192.168.100.11 websvs1
---TRANSACTION 0 2493402, not started, process no 7268, OS thread id 140471202846464
MySQL thread id 25, query id 105647 192.168.100.11 vscs1
---TRANSACTION 0 2493389, not started, process no 7268, OS thread id 140471203112704
MySQL thread id 24, query id 105583 192.168.100.11 vscs1
---TRANSACTION 0 2493100, not started, process no 7268, OS thread id 140471203645184
MySQL thread id 22, query id 92664 192.168.100.11 vscs1
---TRANSACTION 0 2493277, not started, process no 7268, OS thread id 140471210927872
MySQL thread id 8, query id 103502 192.168.100.11 vscs1
---TRANSACTION 0 2492963, not started, process no 7268, OS thread id 140471080556288
MySQL thread id 38, query id 91212 192.168.100.11 vscs1
---TRANSACTION 0 0, not started, process no 7268, OS thread id 140471080290048
MySQL thread id 43, query id 114612 localhost root
show engine innodb status
---TRANSACTION 0 2493507, not started, process no 7268, OS thread id 140471200716544
MySQL thread id 34, query id 114611 192.168.100.11 vscs1
---TRANSACTION 0 2493506, not started, process no 7268, OS thread id 140471200982784
MySQL thread id 33, query id 114601 192.168.100.11 vscs1
---TRANSACTION 0 2492547, not started, process no 7268, OS thread id 140471201781504
MySQL thread id 30, query id 76507 192.168.100.11 vscs1
---TRANSACTION 0 2493058, not started, process no 7268, OS thread id 140471202047744
MySQL thread id 29, query id 91747 192.168.100.11 vscs1
---TRANSACTION 0 2493421, not started, process no 7268, OS thread id 140471211992832
MySQL thread id 4, query id 114177 192.168.100.11 vscs1
---TRANSACTION 0 2493484, not started, process no 7268, OS thread id 140471202313984
MySQL thread id 27, query id 114564 192.168.100.11 vscs1
---TRANSACTION 0 2493411, not started, process no 7268, OS thread id 140471202580224
MySQL thread id 26, query id 105708 192.168.100.11 vscs1
---TRANSACTION 0 2493292, not started, process no 7268, OS thread id 140471203378944
MySQL thread id 23, query id 105067 192.168.100.11 vscs1
---TRANSACTION 0 2493166, not started, process no 7268, OS thread id 140471203911424
MySQL thread id 21, query id 101445 192.168.100.11 vscs1
---TRANSACTION 0 2492826, not started, process no 7268, OS thread id 140471204177664
MySQL thread id 20, query id 90551 192.168.100.11 vscs1
---TRANSACTION 0 2492515, not started, process no 7268, OS thread id 140471204443904
MySQL thread id 19, query id 76331 192.168.100.11 vscs1
---TRANSACTION 0 2492452, not started, process no 7268, OS thread id 140470193747712
MySQL thread id 18, query id 71237 192.168.100.11 vscs1
---TRANSACTION 0 2492272, not started, process no 7268, OS thread id 140471204710144
MySQL thread id 15, query id 91426 192.168.100.11 vscs1
---TRANSACTION 0 2492269, not started, process no 7268, OS thread id 140471204976384
MySQL thread id 14, query id 92982 192.168.100.11 vscs1
---TRANSACTION 0 2492304, not started, process no 7268, OS thread id 140471205508864
MySQL thread id 12, query id 105224 192.168.100.11 vscs1
---TRANSACTION 0 2492687, not started, process no 7268, OS thread id 140471210129152
MySQL thread id 11, query id 81763 192.168.100.11 vscs1
---TRANSACTION 0 2492665, not started, process no 7268, OS thread id 140471210395392
MySQL thread id 10, query id 80152 192.168.100.11 vscs1
---TRANSACTION 0 2492476, not started, process no 7268, OS thread id 140471210661632
MySQL thread id 9, query id 73007 192.168.100.11 vscs1
---TRANSACTION 0 2493048, not started, process no 7268, OS thread id 140471211194112
MySQL thread id 7, query id 91693 192.168.100.11 vscs1
---TRANSACTION 0 2492481, not started, process no 7268, OS thread id 140471211460352
MySQL thread id 6, query id 73035 192.168.100.11 vscs1
---TRANSACTION 0 2492600, not started, process no 7268, OS thread id 140471211726592
MySQL thread id 5, query id 77571 192.168.100.11 vscs1
--------
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
11811 OS file reads, 2692 OS file writes, 1778 OS fsyncs
4.80 reads/s, 117496 avg bytes/read, 3.47 writes/s, 2.14 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2,
713 inserts, 713 merged recs, 288 merges
Hash table size 17393, node heap has 4 buffer(s)
140.62 hash searches/s, 73.39 non-hash searches/s
---
LOG
---
Log sequence number 0 1455084521
Log flushed up to   0 1455084521
Last checkpoint at  0 1455083429
0 pending log writes, 0 pending chkp writes
1301 log i/o's done, 1.57 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 21501264; in additional pool allocated 1048576
Dictionary memory allocated 390168
Buffer pool size   512
Free buffers       0
Database pages     508
Modified db pages  4
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages read 55114, created 19, written 1524
34.45 reads/s, 0.00 creates/s, 1.90 writes/s
Buffer pool hit rate 976 / 1000
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
1 read views open inside InnoDB
Main thread process no. 7268, id 140471091312384, state: sleeping
Number of rows inserted 350, updated 616, deleted 0, read 4394330
0.22 inserts/s, 0.69 updates/s, 0.00 deletes/s, 6064.16 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

2nd sample after increase

mysql> show engine innodb status\G
*************************** 1. row ***************************
  Type: InnoDB
  Name:
Status:
=====================================
130507 12:26:51 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 11 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 474709, signal count 474267
Mutex spin waits 0, rounds 83167, OS waits 190
RW-shared spins 1055681, OS waits 474391; RW-excl spins 171, OS waits 84
------------
TRANSACTIONS
------------
Trx id counter 0 2507435
Purge done for trx's n:o < 0 2507433 undo n:o < 0 0
History list length 24
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 0, not started, process no 7268, OS thread id 140471205242624
MySQL thread id 2342, query id 2258106 localhost root
show engine innodb status
---TRANSACTION 0 2507431, not started, process no 7268, OS thread id 140471201515264
MySQL thread id 31, query id 2249681 192.168.100.11 vscs1
---TRANSACTION 0 2507286, not started, process no 7268, OS thread id 140471080822528
MySQL thread id 37, query id 2237933 192.168.100.11 vscs1
---TRANSACTION 0 2506767, not started, process no 7268, OS thread id 140471201249024
MySQL thread id 32, query id 2068631 192.168.100.11 vscs1
---TRANSACTION 0 2507181, not started, process no 7268, OS thread id 140471202846464
MySQL thread id 25, query id 2217691 192.168.100.11 vscs1
---TRANSACTION 0 2507426, not started, process no 7268, OS thread id 140471203112704
MySQL thread id 24, query id 2249653 192.168.100.11 vscs1
---TRANSACTION 0 2507057, not started, process no 7268, OS thread id 140471203645184
MySQL thread id 22, query id 2241042 192.168.100.11 vscs1
---TRANSACTION 0 2507239, not started, process no 7268, OS thread id 140471210927872
MySQL thread id 8, query id 2248183 192.168.100.11 vscs1
---TRANSACTION 0 2507073, not started, process no 7268, OS thread id 140471080556288
MySQL thread id 38, query id 2195237 192.168.100.11 vscs1
---TRANSACTION 0 2506947, not started, process no 7268, OS thread id 140471200716544
MySQL thread id 34, query id 2110790 192.168.100.11 vscs1
---TRANSACTION 0 2507401, not started, process no 7268, OS thread id 140471200982784
MySQL thread id 33, query id 2247238 192.168.100.11 vscs1
---TRANSACTION 0 2507364, not started, process no 7268, OS thread id 140471201781504
MySQL thread id 30, query id 2244145 192.168.100.11 vscs1
---TRANSACTION 0 2507147, not started, process no 7268, OS thread id 140471202047744
MySQL thread id 29, query id 2237934 192.168.100.11 vscs1
---TRANSACTION 0 2506850, not started, process no 7268, OS thread id 140471211992832
MySQL thread id 4, query id 2081660 192.168.100.11 vscs1
---TRANSACTION 0 2507429, not started, process no 7268, OS thread id 140471202313984
MySQL thread id 27, query id 2249669 192.168.100.11 vscs1
---TRANSACTION 0 2507433, not started, process no 7268, OS thread id 140471202580224
MySQL thread id 26, query id 2258105 192.168.100.11 vscs1
---TRANSACTION 0 2507376, not started, process no 7268, OS thread id 140471203378944
MySQL thread id 23, query id 2244897 192.168.100.11 vscs1
---TRANSACTION 0 2507264, not started, process no 7268, OS thread id 140471203911424
MySQL thread id 21, query id 2228700 192.168.100.11 vscs1
---TRANSACTION 0 2507407, not started, process no 7268, OS thread id 140471204177664
MySQL thread id 20, query id 2247950 192.168.100.11 vscs1
---TRANSACTION 0 2507418, not started, process no 7268, OS thread id 140471204443904
MySQL thread id 19, query id 2249083 192.168.100.11 vscs1
---TRANSACTION 0 2506774, not started, process no 7268, OS thread id 140470193747712
MySQL thread id 18, query id 2228732 192.168.100.11 vscs1
---TRANSACTION 0 2507290, not started, process no 7268, OS thread id 140471204710144
MySQL thread id 15, query id 2237960 192.168.100.11 vscs1
---TRANSACTION 0 2507224, not started, process no 7268, OS thread id 140471204976384
MySQL thread id 14, query id 2244173 192.168.100.11 vscs1
---TRANSACTION 0 2506999, not started, process no 7268, OS thread id 140471205508864
MySQL thread id 12, query id 2131568 192.168.100.11 vscs1
---TRANSACTION 0 2507275, not started, process no 7268, OS thread id 140471210129152
MySQL thread id 11, query id 2237180 192.168.100.11 vscs1
---TRANSACTION 0 2507414, not started, process no 7268, OS thread id 140471210395392
MySQL thread id 10, query id 2248290 192.168.100.11 vscs1
---TRANSACTION 0 2506827, not started, process no 7268, OS thread id 140471210661632
MySQL thread id 9, query id 2071734 192.168.100.11 vscs1
---TRANSACTION 0 2507368, not started, process no 7268, OS thread id 140471211194112
MySQL thread id 7, query id 2244168 192.168.100.11 vscs1
---TRANSACTION 0 2507279, not started, process no 7268, OS thread id 140471211460352
MySQL thread id 6, query id 2249682 192.168.100.11 vscs1
---TRANSACTION 0 2507300, not started, process no 7268, OS thread id 140471211726592
MySQL thread id 5, query id 2241023 192.168.100.11 vscs1
--------
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
251091 OS file reads, 45023 OS file writes, 25818 OS fsyncs
3.64 reads/s, 16384 avg bytes/read, 0.36 writes/s, 0.36 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2,
9852 inserts, 9852 merged recs, 8373 merges
Hash table size 17393, node heap has 4 buffer(s)
5.36 hash searches/s, 23.27 non-hash searches/s
---
LOG
---
Log sequence number 0 1460632209
Log flushed up to   0 1460632209
Last checkpoint at  0 1460630034
0 pending log writes, 0 pending chkp writes
15288 log i/o's done, 0.36 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 21342016; in additional pool allocated 1045248
Dictionary memory allocated 390168
Buffer pool size   512
Free buffers       0
Database pages     508
Modified db pages  22
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages read 1554136, created 189, written 31373
3.64 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 977 / 1000
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
1 read views open inside InnoDB
Main thread process no. 7268, id 140471091312384, state: sleeping
Number of rows inserted 4574, updated 5967, deleted 0, read 154891781
0.18 inserts/s, 0.18 updates/s, 0.00 deletes/s, 250.16 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

1 row in set (0.00 sec)

select version();

+------------+
| version()  |
+------------+
| 5.1.69-log |
+------------+
1 row in set (0.00 sec)

show global variables like 'innodb%';

+-----------------------------------------+------------------------+
| Variable_name                           | Value                  |
+-----------------------------------------+------------------------+
| innodb_adaptive_hash_index              | ON                     |
| innodb_additional_mem_pool_size         | 1048576                |
| innodb_autoextend_increment             | 8                      |
| innodb_autoinc_lock_mode                | 1                      |
| innodb_buffer_pool_size                 | 8388608                |
| innodb_checksums                        | ON                     |
| innodb_commit_concurrency               | 0                      |
| innodb_concurrency_tickets              | 500                    |
| innodb_data_file_path                   | ibdata1:10M:autoextend |
| innodb_data_home_dir                    |                        |
| innodb_doublewrite                      | ON                     |
| innodb_fast_shutdown                    | 1                      |
| innodb_file_io_threads                  | 4                      |
| innodb_file_per_table                   | ON                     |
| innodb_flush_log_at_trx_commit          | 1                      |
| innodb_flush_method                     |                        |
| innodb_force_recovery                   | 0                      |
| innodb_lock_wait_timeout                | 120                    |
| innodb_locks_unsafe_for_binlog          | OFF                    |
| innodb_log_buffer_size                  | 1048576                |
| innodb_log_file_size                    | 5242880                |
| innodb_log_files_in_group               | 2                      |
| innodb_log_group_home_dir               | ./                     |
| innodb_max_dirty_pages_pct              | 90                     |
| innodb_max_purge_lag                    | 0                      |
| innodb_mirrored_log_groups              | 1                      |
| innodb_open_files                       | 300                    |
| innodb_rollback_on_timeout              | OFF                    |
| innodb_stats_method                     | nulls_equal            |
| innodb_stats_on_metadata                | ON                     |
| innodb_support_xa                       | ON                     |
| innodb_sync_spin_loops                  | 20                     |
| innodb_table_locks                      | ON                     |
| innodb_thread_concurrency               | 8                      |
| innodb_thread_sleep_delay               | 10000                  |
| innodb_use_legacy_cardinality_algorithm | ON                     |
+-----------------------------------------+------------------------+
36 rows in set (0.00 sec)

Best Answer

Please look carefully at the queries that are locking

The SHOW ENGINE INNODB STATUS\G is incomplete

I cannot fully tell you anything more because you gave me three transactions that

  • execute the exact same query
  • lock the same page in the GEN_CLUST_INDEX

as shown from your display

---TRANSACTION 0 2491310, ACTIVE 29 sec, process no 6622, OS thread id 140388597384960 starting index read
Update tblID Set lastValue=4372  Where tableName='tblUnAst'

---TRANSACTION 0 2491307, ACTIVE 38 sec, process no 6622, OS thread id 140388597917440 starting index read
Update tblID Set lastValue=4372  Where tableName='tblUnAst'

---TRANSACTION 0 2491299, ACTIVE 46 sec, process no 6622, OS thread id 140388388042496 starting index read
Update tblID Set lastValue=4372  Where tableName='tblUnAst'

Notwithstanding, there are undo log entries coming from several transactions.

This situation is so reminiscent of three question from one person (RedBlueThing) that I helped troubleshoot. Here were those posts:

RedBlueThing solved it by changing his code, not his configuration.

In light of this, look back at the SHOW ENGINE INNODB STATUS\G output. From what you provided, I see many transactions and many undo log entries from multiple transactions. Apparently, this came from multiple transactions trying to run the exact same query.

RECOMMENDATION

You are using a very old version of the InnoDB Storage Engine. You should upgrade to the latest MySQL as you can set a higher number of read and write I/O threads The new InnoDB can also access up to 48 cores. If you do not upgrade, the very least you should do is set innodb_thread_concurrency to 0.

As @altmannmarcelo mentioned in the comment below, you can install the InnoDB Plugin. See my post MySQL - Installing InnoDB Plugin