MySQL Forums
Forum List  »  InnoDB

innodb deadlock on UPDATE
Posted by: Michael Leitch
Date: July 06, 2015 09:37AM

I have a situation that is in a deadlock with two client threads trying to do an update on the same table but different rows. This shouldn't be happening, and I can't figure out why. Below I've included information on my setup and the problem.

I have increased innodb_lock_wait_timeout to 300 seconds. Neither of the commands were performed and they timed out.


Setup:
-----------------------------------------------------------------------------------
MySQL
-----

Community Version

innodb_version, 5.6.25
protocol_version, 10
slave_type_conversions,
version, 5.6.25
version_comment, MySQL Community Server (GPL)
version_compile_machine, x86_64
version_compile_os, Linux

SHOW VARIABLES LIKE 'tx_isolation'; --> REPEATABLE-READ
innodb_lock_wait_timeout=300;

OS:
----

[root@EMP0-LINUX mysql]# uname -a
Linux EMP0-LINUX 2.6.32-504.23.4.el6.x86_64 #1 SMP Tue Jun 9 20:57:37 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux
[root@EMP0-LINUX mysql]# cat /etc/centos-release
CentOS release 6.6 (Final)

Queries
-----------------------------------------------------------------------------------

UPDATE UNIT_COUNTS SET T_EARLIEST = '2004-01-04 12:03:42', T_LATEST = '2004-01-17 08:44:26', N_PTS = 4, AVG_DUR = 62.232100 WHERE ID = 8317
UPDATE UNIT_COUNTS SET T_EARLIEST = '2004-02-17 00:03:58', T_LATEST = '2004-02-18 23:56:06', N_PTS = 2, AVG_DUR = 15.490300 WHERE ID = 15788

SELECT * FROM information_schema.innodb_locks
---------------------------------------------------------------------------------
# lock_id, lock_trx_id, lock_mode, lock_type, lock_table, lock_index, lock_space, lock_page, lock_rec, lock_data
'13874529:43492:791:171', '13874529', 'X', 'RECORD', '`AG100$$BURNABY`.`UNIT_COUNTS`', 'PRIMARY', '43492', '791', '171', '15788'
'13869066:43492:791:171', '13869066', 'X', 'RECORD', '`AG100$$BURNABY`.`UNIT_COUNTS`', 'PRIMARY', '43492', '791', '171', '15788'
'13874496:43492:388:221', '13874496', 'X', 'RECORD', '`AG100$$BURNABY`.`UNIT_COUNTS`', 'PRIMARY', '43492', '388', '221', '8317'
'13869066:43492:388:221', '13869066', 'X', 'RECORD', '`AG100$$BURNABY`.`UNIT_COUNTS`', 'PRIMARY', '43492', '388', '221', '8317'


InnoDB Status
---------------------------------------------------------------------------------
=====================================
2015-07-06 08:03:57 7fe70cfd4700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 4 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 1176 srv_active, 0 srv_shutdown, 37710 srv_idle
srv_master_thread log flush and writes: 38886
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 5776
OS WAIT ARRAY INFO: signal count 6327
Mutex spin waits 25574, rounds 167660, OS waits 5154
RW-shared spins 923, rounds 20643, OS waits 576
RW-excl spins 28, rounds 2785, OS waits 41
Spin rounds per wait: 6.56 mutex, 22.37 RW-shared, 99.46 RW-excl
------------
TRANSACTIONS
------------
Trx id counter 13874549
Purge done for trx's n:o < 13872143 undo n:o < 0 state: running but idle
History list length 944
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 13874548, not started
MySQL thread id 74, OS thread handle 0x7fe70a5b4700, query id 1767153 localhost 127.0.0.1 mike cleaning up
---TRANSACTION 13874532, not started
MySQL thread id 72, OS thread handle 0x7fe70cf52700, query id 1766457 localhost 127.0.0.1 mike cleaning up
---TRANSACTION 13874533, not started
MySQL thread id 71, OS thread handle 0x7fe70a4f1700, query id 1766458 localhost 127.0.0.1 mike cleaning up
---TRANSACTION 13874519, not started
MySQL thread id 70, OS thread handle 0x7fe70a46f700, query id 1765599 localhost 127.0.0.1 mike cleaning up
---TRANSACTION 13874499, not started
MySQL thread id 68, OS thread handle 0x7fe70cf11700, query id 1765362 localhost 127.0.0.1 mike cleaning up
---TRANSACTION 13874500, not started
MySQL thread id 67, OS thread handle 0x7fe6e3fff700, query id 1765363 localhost 127.0.0.1 mike cleaning up
---TRANSACTION 13869058, not started
MySQL thread id 25, OS thread handle 0x7fe70ce4e700, query id 1784598 localhost 127.0.0.1 mike cleaning up
---TRANSACTION 0, not started
MySQL thread id 3, OS thread handle 0x7fe70cf93700, query id 1784620 localhost 127.0.0.1 root cleaning up
---TRANSACTION 13874356, not started
MySQL thread id 2, OS thread handle 0x7fe70cfd4700, query id 1784621 localhost 127.0.0.1 root init
SHOW ENGINE INNODB STATUS
---TRANSACTION 13869065, not started
MySQL thread id 11, OS thread handle 0x7fe70a5f5700, query id 1784599 localhost 127.0.0.1 mike cleaning up
---TRANSACTION 13791677, not started
MySQL thread id 8, OS thread handle 0x7fe70ce8f700, query id 1784597 localhost 127.0.0.1 mike cleaning up
---TRANSACTION 13874529, ACTIVE 72 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 137 lock struct(s), heap size 13864, 4908 row lock(s), undo log entries 2421
MySQL thread id 73, OS thread handle 0x7fe70a4b0700, query id 1779685 localhost 127.0.0.1 mike updating
UPDATE UNIT_COUNTS SET T_EARLIEST = '2004-02-17 00:03:58', T_LATEST = '2004-02-18 23:56:06', N_PTS = 2, AVG_DUR = 15.490300 WHERE ID = 15788
Trx read view will not see trx with id >= 13874530, sees < 13869066
------- TRX HAS BEEN WAITING 70 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 43492 page no 791 n bits 360 index `PRIMARY` of table `AG100$$BURNABY`.`UNIT_COUNTS` trx id 13874529 lock_mode X locks rec but not gap waiting
Record lock, heap no 171 PHYSICAL RECORD: n_fields 17; compact format; info bits 0
0: len 4; hex 00003dac; asc = ;;
1: len 6; hex 000000d39aec; asc ;;
2: len 7; hex 64000021600a62; asc d !` b;;
3: len 1; hex 05; asc ;;
4: len 2; hex 0004; asc ;;
5: len 1; hex 01; asc ;;
6: len 2; hex 0005; asc ;;
7: len 1; hex 80; asc ;;
8: len 1; hex 03; asc ;;
9: len 3; hex 8f9a21; asc !;;
10: len 1; hex 03; asc ;;
11: len 2; hex 0001; asc ;;
12: len 1; hex 80; asc ;;
13: len 5; hex 9971a200fa; asc q ;;
14: len 5; hex 9971a57e06; asc q ~ ;;
15: len 4; hex 00000002; asc ;;
16: len 4; hex 6ad87741; asc j wA;;

------------------
---TRANSACTION 13874496, ACTIVE 73 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 173 lock struct(s), heap size 30248, 9999 row lock(s), undo log entries 4958
MySQL thread id 69, OS thread handle 0x7fe70ced0700, query id 1784494 localhost 127.0.0.1 mike updating
UPDATE UNIT_COUNTS SET T_EARLIEST = '2004-01-04 12:03:42', T_LATEST = '2004-01-17 08:44:26', N_PTS = 4, AVG_DUR = 62.232100 WHERE ID = 8317
Trx read view will not see trx with id >= 13874497, sees < 13869066
------- TRX HAS BEEN WAITING 68 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 43492 page no 388 n bits 360 index `PRIMARY` of table `AG100$$BURNABY`.`UNIT_COUNTS` trx id 13874496 lock_mode X locks rec but not gap waiting
Record lock, heap no 221 PHYSICAL RECORD: n_fields 17; compact format; info bits 0
0: len 4; hex 0000207d; asc };;
1: len 6; hex 000000d382fd; asc ;;
2: len 7; hex 0f00001fb61df1; asc ;;
3: len 1; hex 03; asc ;;
4: len 2; hex 0001; asc ;;
5: len 1; hex 01; asc ;;
6: len 2; hex 0005; asc ;;
7: len 1; hex 80; asc ;;
8: len 1; hex 03; asc ;;
9: len 3; hex 8f9a21; asc !;;
10: len 1; hex 03; asc ;;
11: len 2; hex 0001; asc ;;
12: len 1; hex 80; asc ;;
13: len 5; hex 997148c0ea; asc qH ;;
14: len 5; hex 9971628b1a; asc qb ;;
15: len 4; hex 00000004; asc ;;
16: len 4; hex aced7842; asc xB;;

------------------
---TRANSACTION 13869066, ACTIVE 37131 sec
976 lock struct(s), heap size 95784, 46639 row lock(s)
MySQL thread id 10, OS thread handle 0x7fe70ce0d700, query id 1784600 localhost 127.0.0.1 mike cleaning up
Trx read view will not see trx with id >= 13872142, sees < 13870292
--------
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
26437 OS file reads, 62188 OS file writes, 5481 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 107, seg size 109, 0 merges
merged operations:
insert 0, delete mark 0, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 9239359, node heap has 4346 buffer(s)
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number 28969919119
Log flushed up to 28969919119
Pages flushed up to 28969919119
Last checkpoint at 28969919119
0 pending log writes, 0 pending chkp writes
37753 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 4292608000; in additional pool allocated 0
Dictionary memory allocated 3102798
Buffer pool size 255984
Free buffers 222101
Database pages 29531
Old database pages 10608
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 1, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 26333, created 3198, written 22237
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: 29531, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
----------------------
INDIVIDUAL BUFFER POOL INFO
----------------------
---BUFFER POOL 0
Buffer pool size 15999
Free buffers 13863
Database pages 1860
Old database pages 666
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1650, created 210, written 1273
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: 1860, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 1
Buffer pool size 15999
Free buffers 13777
Database pages 1947
Old database pages 698
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1675, created 272, written 1164
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1947, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 2
Buffer pool size 15999
Free buffers 14005
Database pages 1721
Old database pages 615
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1471, created 250, written 696
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1721, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 3
Buffer pool size 15999
Free buffers 14051
Database pages 1676
Old database pages 604
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1553, created 123, written 2152
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1676, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 4
Buffer pool size 15999
Free buffers 13850
Database pages 1874
Old database pages 671
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 1, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1690, created 184, written 2776
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1874, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 5
Buffer pool size 15999
Free buffers 13788
Database pages 1941
Old database pages 696
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1667, created 274, written 1984
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1941, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 6
Buffer pool size 15999
Free buffers 13828
Database pages 1901
Old database pages 681
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1715, created 186, written 1439
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1901, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 7
Buffer pool size 15999
Free buffers 13988
Database pages 1738
Old database pages 621
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1552, created 186, written 773
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1738, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 8
Buffer pool size 15999
Free buffers 13876
Database pages 1852
Old database pages 663
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1703, created 149, written 721
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1852, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 9
Buffer pool size 15999
Free buffers 13761
Database pages 1967
Old database pages 706
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1715, created 252, written 2037
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1967, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 10
Buffer pool size 15999
Free buffers 13892
Database pages 1834
Old database pages 664
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1626, created 208, written 1399
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: 1834, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 11
Buffer pool size 15999
Free buffers 13904
Database pages 1826
Old database pages 654
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1607, created 219, written 1536
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1826, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 12
Buffer pool size 15999
Free buffers 13727
Database pages 1999
Old database pages 717
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1819, created 180, written 862
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1999, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 13
Buffer pool size 15999
Free buffers 13714
Database pages 2018
Old database pages 737
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1912, created 106, written 953
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 2018, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 14
Buffer pool size 15999
Free buffers 13991
Database pages 1736
Old database pages 620
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1532, created 204, written 1476
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1736, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 15
Buffer pool size 15999
Free buffers 14086
Database pages 1641
Old database pages 595
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1446, created 195, written 996
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1641, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
3 read views open inside InnoDB
Main thread process no. 3539, id 140630405793536, state: sleeping
Number of rows inserted 33750, updated 708974, deleted 2193, read 8405879420
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

Options: ReplyQuote


Subject
Views
Written By
Posted
innodb deadlock on UPDATE
2051
July 06, 2015 09:37AM
928
July 08, 2015 07:24PM
1334
July 08, 2015 09:52PM
1009
July 09, 2015 11:52PM
945
July 15, 2015 12:00PM
879
July 17, 2015 03:43PM
843
July 17, 2015 04:42PM
839
July 24, 2015 03:00PM


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.