Re: Lock wait timeout exceeded; try restarting transaction
Hello Rick,
we again faced outage and this time I have innodb logs.
=====================================
120312 4:45:01 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 46 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 4650, signal count 4637
Mutex spin waits 0, rounds 184781, OS waits 736
RW-shared spins 7592, OS waits 3315; RW-excl spins 2681, OS waits 543
------------------------
LATEST DETECTED DEADLOCK
------------------------
120312 4:36:14
*** (1) TRANSACTION:
TRANSACTION 0 955569846, ACTIVE 362 sec, process no 532, OS thread id 140630574614272 fetching rows
mysql tables in use 1, locked 1
LOCK WAIT 38 lock struct(s), heap size 6752, 2962 row lock(s), undo log entries 9
MySQL thread id 114, query id 9649837 localhost saas updating
DELETE FROM fdreason WHERE tranunkid = NAME_CONST('v_tranunkid',NULL)
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 73880 n bits 112 index `PRIMARY` of table `saas_20110806`.`fdreason` trx id 0 955569846 lock_mode X waiting
Record lock, heap no 40 PHYSICAL RECORD: n_fields 12; compact format; info bits 0
0: len 8; hex 801e32b4789742af; asc 2 x B ;; 1: len 6; hex 000038f4d57c; asc 8 |;; 2: len 7; hex 800000ed130110; asc ;; 3: SQL NULL; 4: len 8; hex 8000000000000000; asc ;; 5: len 8; hex 80000000000003be; asc ;; 6: len 8; hex 8000124ca00d561d; asc L V ;; 7: len 4; hex 80000055; asc U;; 8: len 4; hex 80000000; asc ;; 9: len 10; hex 4e6f20536d6f6b696e67; asc No Smoking;; 10: len 6; hex 524553455256; asc RESERV;; 11: len 1; hex 80; asc ;;
*** (2) TRANSACTION:
TRANSACTION 0 955569851, ACTIVE 357 sec, process no 532, OS thread id 140630518855424 starting index read, thread declared inside InnoDB 500
mysql tables in use 1, locked 1
9 lock struct(s), heap size 3024, 5 row lock(s), undo log entries 1
MySQL thread id 206, query id 9701482 localhost saas updating
DELETE FROM fdinclusion WHERE tranunkid = NAME_CONST('v_tranunkid',NULL)
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 0 page no 73880 n bits 112 index `PRIMARY` of table `saas_20110806`.`fdreason` trx id 0 955569851 lock mode S locks rec but not gap
Record lock, heap no 40 PHYSICAL RECORD: n_fields 12; compact format; info bits 0
0: len 8; hex 801e32b4789742af; asc 2 x B ;; 1: len 6; hex 000038f4d57c; asc 8 |;; 2: len 7; hex 800000ed130110; asc ;; 3: SQL NULL; 4: len 8; hex 8000000000000000; asc ;; 5: len 8; hex 80000000000003be; asc ;; 6: len 8; hex 8000124ca00d561d; asc L V ;; 7: len 4; hex 80000055; asc U;; 8: len 4; hex 80000000; asc ;; 9: len 10; hex 4e6f20536d6f6b696e67; asc No Smoking;; 10: len 6; hex 524553455256; asc RESERV;; 11: len 1; hex 80; asc ;;
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 3408 n bits 80 index `PRIMARY` of table `saas_20110806`.`fdinclusion` trx id 0 955569851 lock_mode X waiting
Record lock, heap no 8 PHYSICAL RECORD: n_fields 14; compact format; info bits 0
0: len 8; hex 801b5b1bf4c54001; asc [ @ ;; 1: len 6; hex 00002da2945b; asc - [;; 2: len 7; hex 800000461b0165; asc F e;; 3: len 4; hex 8000004d; asc M;; 4: len 8; hex 801b5b1bf4c5418b; asc [ A ;; 5: len 8; hex 801b5b1bf4c542a2; asc [ B ;; 6: len 8; hex 801b5b1bf4c54004; asc [ @ ;; 7: len 8; hex 4556455259444159; asc EVERYDAY;; 8: len 11; hex 504552494e5354414e4345; asc PERINSTANCE;; 9: len 9; hex 800000000000810000; asc ;; 10: len 4; hex 80000001; asc ;; 11: len 8; hex 8000000000000586; asc ;; 12: len 8; hex 8000124c94239954; asc L # T;; 13: len 8; hex 801b5b1bf4c54001; asc [ @ ;;
*** WE ROLL BACK TRANSACTION (2)
------------
TRANSACTIONS
------------
Trx id counter 0 955572815
Purge done for trx's n:o < 0 955567127 undo n:o < 0 0
History list length 331
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 0, not started, process no 532, OS thread id 140630574413568
MySQL thread id 348, query id 15176005 localhost saas
SHOW ENGINE INNODB STATUS
---TRANSACTION 0 0, not started, process no 532, OS thread id 140630521865984
MySQL thread id 335, query id 13578599 localhost saas
---TRANSACTION 0 955572801, not started, process no 532, OS thread id 140630518654720
MySQL thread id 321, query id 13978421 localhost saas
---TRANSACTION 0 955572649, not started, process no 532, OS thread id 140630523471616
MySQL thread id 320, query id 13039579 localhost saas
---TRANSACTION 0 955572808, not started, process no 532, OS thread id 140630519658240
MySQL thread id 316, query id 14375299 localhost saas
---TRANSACTION 0 955572528, not started, process no 532, OS thread id 140630518052608
MySQL thread id 303, query id 12640032 localhost saas
---TRANSACTION 0 955572426, not started, process no 532, OS thread id 140630573008640
MySQL thread id 302, query id 12690042 localhost saas
---TRANSACTION 0 955572561, not started, process no 532, OS thread id 140630517049088
MySQL thread id 301, query id 12787458 localhost saas
---TRANSACTION 0 0, not started, process no 532, OS thread id 140630524876544
MySQL thread id 298, query id 15175489 localhost 127.0.0.1 saas
---TRANSACTION 0 955572653, not started, process no 532, OS thread id 140630517249792
MySQL thread id 295, query id 13100101 localhost saas
---TRANSACTION 0 955572344, not started, process no 532, OS thread id 140630524073728
MySQL thread id 294, query id 12079117 localhost saas
---TRANSACTION 0 955572407, not started, process no 532, OS thread id 140630528288512
MySQL thread id 289, query id 12305687 localhost saas
---TRANSACTION 0 955572800, not started, process no 532, OS thread id 140630525880064
MySQL thread id 286, query id 13931726 localhost saas
---TRANSACTION 0 955572698, not started, process no 532, OS thread id 140630525077248
MySQL thread id 285, query id 13263197 localhost saas
---TRANSACTION 0 955572748, not started, process no 532, OS thread id 140630523873024
MySQL thread id 279, query id 13599532 localhost saas
---TRANSACTION 0 0, not started, process no 532, OS thread id 140630522668800
MySQL thread id 267, query id 15174613 localhost 127.0.0.1 root
---TRANSACTION 0 955567476, not started, process no 532, OS thread id 140630528087808
MySQL thread id 89, query id 15134838 localhost 127.0.0.1 root
---TRANSACTION 0 955567125, ACTIVE 1458 sec, process no 532, OS thread id 140630528489216 fetching rows, thread declared inside InnoDB 414
mysql tables in use 8, locked 8
20 lock struct(s), heap size 3024, 2015 row lock(s), undo log entries 1592574
MySQL thread id 84, query id 15176002 localhost saas Sending data
select keyvalue into v_timediff from cfparameter where keyname='DisTimeZone' and hotel_code= NAME_CONST('photel_code',_utf8'85' COLLATE 'utf8_general_ci')
Trx read view will not see trx with id >= 0 955567126, sees < 0 955567126
--------
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
71306 OS file reads, 7752 OS file writes, 4447 OS fsyncs
27.50 reads/s, 20178 avg bytes/read, 3.89 writes/s, 2.78 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 5, seg size 7,
75 inserts, 75 merged recs, 55 merges
Hash table size 17393, node heap has 19 buffer(s)
3048.09 hash searches/s, 3866.16 non-hash searches/s
---
LOG
---
Log sequence number 1 1845502360
Log flushed up to 1 1845390649
Last checkpoint at 1 1844141511
0 pending log writes, 0 pending chkp writes
3812 log i/o's done, 2.46 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 26782528; in additional pool allocated 1048320
Dictionary memory allocated 4713032
Buffer pool size 512
Free buffers 0
Database pages 493
Modified db pages 62
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages read 128941, created 6877, written 10566
33.87 reads/s, 4.67 creates/s, 5.46 writes/s
Buffer pool hit rate 1000 / 1000
--------------
ROW OPERATIONS
--------------
1 queries inside InnoDB, 0 queries in queue
2 read views open inside InnoDB
Main thread process no. 532, id 140630536881920, state: sleeping
Number of rows inserted 796408, updated 796703, deleted 45, read 1620077281
542.36 inserts/s, 542.36 updates/s, 0.00 deletes/s, 1082918.31 reads/s