I have a sporadic deadlocking issue with MySQL 5.6. This server is configured as a read only slave, which is why it is extremely odd there is a deadlock issue.
I have innodb_lock_wait_timeout set to 120.
A subset (due to character limits on serverfault) of the output of SHOW ENGINE INNODB STATUS; is below.
I am hoping someone can point me in the right direction. What is the cause of this problem and how do I go about resolving it?
Update 4/12: I noticed the particularly peculiar issue is thread # 140123720021760 seems to be blocking itself.
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 29739376
--Thread 140123720021760 has waited at btr0sea.cc line 658 for 442.00 seconds the semaphore:
X-lock (wait_ex) on RW-latch at 0x46a65388 created in file btr0sea.cc line 173
a writer (thread id 140123720021760) has reserved it in mode wait exclusive
number of readers 1, waiters flag 1, lock_word: ffffffffffffffff
Last time read locked in file btr0sea.cc line 907
Last time write locked in file /export/home/pb2/build/sb_0-24964924-1505319557.6/rpm/BUILD/mysql-5.6.38/mysql-5.6.38/storage/innobase/btr/btr0sea.cc line 658
--Thread 140124318373632 has waited at btr0cur.cc line 2045 for 440.00 seconds the semaphore:
X-lock on RW-latch at 0x46a65388 created in file btr0sea.cc line 173
a writer (thread id 140123720021760) has reserved it in mode wait exclusive
number of readers 1, waiters flag 1, lock_word: ffffffffffffffff
Last time read locked in file btr0sea.cc line 907
Last time write locked in file /export/home/pb2/build/sb_0-24964924-1505319557.6/rpm/BUILD/mysql-5.6.38/mysql-5.6.38/storage/innobase/btr/btr0sea.cc line 658
--Thread 140121070274304 has waited at row0sel.cc line 4074 for 439.00 seconds the semaphore:
S-lock on RW-latch at 0x46a65388 created in file btr0sea.cc line 173
a writer (thread id 140123720021760) has reserved it in mode wait exclusive
number of readers 1, waiters flag 1, lock_word: ffffffffffffffff
Last time read locked in file btr0sea.cc line 907
Last time write locked in file /export/home/pb2/build/sb_0-24964924-1505319557.6/rpm/BUILD/mysql-5.6.38/mysql-5.6.38/storage/innobase/btr/btr0sea.cc line 658
------------
TRANSACTIONS
------------
Trx id counter 2444027091
Purge done for trx's n:o < 2444026968 undo n:o < 0 state: running but idle
History list length 1589
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0, not started
MySQL thread id 148840, OS thread handle 0x7f712cd85700, query id 215116859 192.168.100.50 play init
SHOW ENGINE INNODB STATUS
---TRANSACTION 0, not started
MySQL thread id 148839, OS thread handle 0x7f7078db9700, query id 215116452 192.168.100.50 play
---TRANSACTION 2444027012, ACTIVE 440 sec updating or deleting
mysql tables in use 1, locked 1
2 lock struct(s), heap size 360, 1 row lock(s), undo log entries 1
MySQL thread id 2, OS thread handle 0x7f713c389700, query id 215115280 System lock
---TRANSACTION 2444027088, ACTIVE 3 sec starting index read
mysql tables in use 10, locked 0
MySQL thread id 148862, OS thread handle 0x7f7109108700, query id 215116832 10.10.10.80 play_readonly statistics
select client0_.client_id as client_i1_33_0_, client0_.active as active2_33_0_, client0_.address_city as address_3_33_0_, client0_.address_country as address_4_33_0_, client0_.address_line1 as address_5_33_0_, client0_.address_line2 as address_6_33_0_, client0_.address_state as address_7_33_0_, client0_.address_zipcode as address_8_33_0_, client0_.bank_info as bank_inf9_33_0_, client0_.calendar_type as calenda10_33_0_, client0_.card_type_enabled_set as card_ty11_33_0_, client0_.catch_all_receipt_text as catch_a12_33_0_, client0_.city_of_incorporation as city_of13_33_0_, client0_.client_display
Trx read view will not see trx with id >= 2444027089, sees < 2444027012
--------
FILE I/O
--------
I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
I/O thread 1 state: waiting for completed aio requests (log thread)
I/O thread 2 state: waiting for completed aio requests (read thread)
I/O thread 3 state: waiting for completed aio requests (read thread)
I/O thread 4 state: waiting for completed aio requests (read thread)
I/O thread 5 state: waiting for completed aio requests (read thread)
I/O thread 6 state: waiting for completed aio requests (write thread)
I/O thread 7 state: waiting for completed aio requests (write thread)
I/O thread 8 state: waiting for completed aio requests (write thread)
I/O thread 9 state: waiting for completed aio requests (write thread)
Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0] ,
ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
36630825 OS file reads, 231356872 OS file writes, 108178779 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 70724, seg size 70726, 4826685 merges
merged operations:
insert 6743692, delete mark 49985569, delete 2426777
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 84999163, node heap has 341459 buffer(s)
0.00 hash searches/s, 4.50 non-hash searches/s
---
LOG
---
Log sequence number 2131849036943
Log flushed up to 2131849036943
Pages flushed up to 2131849036943
Last checkpoint at 2131849036943
0 pending log writes, 0 pending chkp writes
37238698 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 43956305920; in additional pool allocated 0
Dictionary memory allocated 2406027
Buffer pool size 2621440
Free buffers 8193
Database pages 2271787
Old database pages 838446
Modified db pages 0
Pending reads 0
Pending writes: LRU 1, flush list 0, single page 0
Pages made young 288176007, not young 1989790258
0.10 youngs/s, 0.00 non-youngs/s
Pages read 36629170, created 1207472, written 164204069
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 11 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 2271787, unzip_LRU len: 0
I/O sum[24]:cur[0], unzip sum[0]:cur[0]
----------------------
INDIVIDUAL BUFFER POOL INFO
----------------------
---BUFFER POOL 0
Buffer pool size 327680
Free buffers 1025
Database pages 283983
Old database pages 104809
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 40220727, not young 283474530
0.00 youngs/s, 0.00 non-youngs/s
Pages read 5186114, created 152096, written 35871221
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 283983, unzip_LRU len: 0
I/O sum[3]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 1
Buffer pool size 327680
Free buffers 1026
Database pages 283990
Old database pages 104812
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 36212975, not young 249869675
0.00 youngs/s, 0.00 non-youngs/s
Pages read 4641916, created 151079, written 14821449
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 283990, unzip_LRU len: 0
I/O sum[3]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 2
Buffer pool size 327680
Free buffers 1025
Database pages 283923
Old database pages 104787
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 31148941, not young 207780893
0.10 youngs/s, 0.00 non-youngs/s
Pages read 3912247, created 147944, written 19145924
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 58 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 283923, unzip_LRU len: 0
I/O sum[3]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 3
Buffer pool size 327680
Free buffers 1025
Database pages 283971
Old database pages 104805
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 36726178, not young 253275164
0.00 youngs/s, 0.00 non-youngs/s
Pages read 4671182, created 151023, written 25773402
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 283971, unzip_LRU len: 0
I/O sum[3]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 4
Buffer pool size 327680
Free buffers 1022
Database pages 283999
Old database pages 104815
Modified db pages 0
Pending reads 0
Pending writes: LRU 1, flush list 0, single page 0
Pages made young 36790229, not young 268599143
0.00 youngs/s, 0.00 non-youngs/s
Pages read 4620148, created 151929, written 20173631
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 283999, unzip_LRU len: 0
I/O sum[3]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 5
Buffer pool size 327680
Free buffers 1025
Database pages 284004
Old database pages 104817
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 33417599, not young 219971495
0.00 youngs/s, 0.00 non-youngs/s
Pages read 4074681, created 146202, written 17018304
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 284004, unzip_LRU len: 0
I/O sum[3]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 6
Buffer pool size 327680
Free buffers 1021
Database pages 283942
Old database pages 104795
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 36990403, not young 256117529
0.00 youngs/s, 0.00 non-youngs/s
Pages read 4774761, created 152747, written 16831520
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 283942, unzip_LRU len: 0
I/O sum[3]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 7
Buffer pool size 327680
Free buffers 1024
Database pages 283975
Old database pages 104806
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 36668955, not young 250701829
0.00 youngs/s, 0.00 non-youngs/s
Pages read 4748121, created 154452, written 14568618
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 283975, unzip_LRU len: 0
I/O sum[3]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
78 read views open inside InnoDB
Main thread process no. 2221, id 140124339353344, state: sleeping
Number of rows inserted 126495327, updated 53443514, deleted 99690029, read 137185949856
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 2.30 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
