Mysql – When and why can this kind of deadlock occur

deadlockinnodbMySQL

------------------------
LATEST DETECTED DEADLOCK
------------------------
130409  0:40:58
*** (1) TRANSACTION:
TRANSACTION 3D61D41F, ACTIVE 3 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 43 lock struct(s), heap size 6960, 358 row lock(s), undo log entries 43
MySQL thread id 17241690, OS thread handle 0x7ffd3469a700, query id 860259163 localhost root update
INSERT INTO `notification` (`other_grouped_notifications_count`, `user_id`, `notifiable_type`, `action_item`, `action_id`, `created_at`, `status`, `updated_at`) VALUES (0, 4442, 'MATCH', 'MATCH', 224716, 1365448255, 1, 1365448255)
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 272207 n bits 1272 index `user_id` of table `notification` trx id 3D61D41F lock_mode X locks gap before rec insert intention waiting
Record lock, heap no 69 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 4; hex 8000115b; asc    [;;
 1: len 4; hex 0005e0bb; asc     ;;

*** (2) TRANSACTION:
TRANSACTION 3D61C472, ACTIVE 15 sec starting index read
mysql tables in use 1, locked 1
3 lock struct(s), heap size 1248, 2 row lock(s)
MySQL thread id 17266704, OS thread handle 0x7ffd34b01700, query id 860250374 localhost root Updating
UPDATE `notification` SET `status`=0 WHERE user_id = 4443 and status=1
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 0 page no 272207 n bits 1272 index `user_id` of table `notification` trx id 3D61C472 lock_mode X
Record lock, heap no 69 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 4; hex 8000115b; asc    [;;
 1: len 4; hex 0005e0bb; asc     ;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 261029 n bits 248 index `PRIMARY` of table `notification` trx id 3D61C472 lock_mode X locks rec but not gap waiting
Record lock, heap no 161 PHYSICAL RECORD: n_fields 16; compact format; info bits 0
 0: len 4; hex 0005e0bb; asc     ;;
 1: len 6; hex 00000c75178f; asc    u  ;;
 2: len 7; hex 480007c00c1d10; asc H      ;;
 3: len 4; hex 8000115b; asc    [;;
 4: len 8; hex 5245474953544552; asc REGISTER;;
 5: SQL NULL;
 6: SQL NULL;
 7: SQL NULL;
 8: len 4; hex d117dd91; asc     ;;
 9: len 4; hex d117dd91; asc     ;;
 10: len 1; hex 80; asc  ;;
 11: SQL NULL;
 12: SQL NULL;
 13: SQL NULL;
 14: SQL NULL;
 15: len 4; hex 80000000; asc     ;;

*** WE ROLL BACK TRANSACTION (2)
------------
TRANSACTIONS
------------
Trx id counter 3DBAB14A
Purge done for trx's n:o < 3DBAAF69 undo n:o < 0
History list length 1911
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0, not started
MySQL thread id 17555159, OS thread handle 0x7ffd342f7700, query id 874625123 localhost root
show engine innodb status
---TRANSACTION 3DBAB148, not started
MySQL thread id 17557253, OS thread handle 0x7ffd34a9f700, query id 874625122 localhost root
---TRANSACTION 3DBAB0F0, not started
MySQL thread id 17557249, OS thread handle 0x7ffd34948700, query id 874624797 localhost root
---TRANSACTION 3DBAB0FF, not started
MySQL thread id 17546322, OS thread handle 0x7ffd343bb700, query id 874624821 localhost root
---TRANSACTION 3DBAB0FE, not started
MySQL thread id 17546288, OS thread handle 0x7ffd3441d700, query id 874624819 localhost root
---TRANSACTION 3DBAB0FB, not started
MySQL thread id 17546267, OS thread handle 0x7ffd34543700, query id 874624818 localhost root
---TRANSACTION 3DBAB0FA, not started
MySQL thread id 17546259, OS thread handle 0x7ffd34638700, query id 874624817 localhost root
---TRANSACTION 3DBAB01D, not started
MySQL thread id 17546253, OS thread handle 0x7ffbfce8f700, query id 874624182 localhost root
---TRANSACTION 3DBAB00A, not started
MySQL thread id 17546252, OS thread handle 0x7ffd34d4d700, query id 874624151 localhost root
---TRANSACTION 3DBAB101, not started
MySQL thread id 17546251, OS thread handle 0x7ffd34359700, query id 874624824 localhost root
---TRANSACTION 3DBAB100, not started
MySQL thread id 17546249, OS thread handle 0x7ffd34853700, query id 874624823 localhost root
---TRANSACTION 3DBAB102, not started
MySQL thread id 17546245, OS thread handle 0x7ffbfd079700, query id 874624825 localhost root
---TRANSACTION 0, not started
MySQL thread id 17509427, OS thread handle 0x7ffbfc0a8700, query id 872618032 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 (read thread)
I/O thread 4 state: waiting for i/o request (read thread)
I/O thread 5 state: waiting for i/o request (read thread)
I/O thread 6 state: waiting for i/o request (write thread)
I/O thread 7 state: waiting for i/o request (write thread)
I/O thread 8 state: waiting for i/o request (write thread)
I/O thread 9 state: waiting for i/o request (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
1251611 OS file reads, 59363166 OS file writes, 43388223 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 37.85 writes/s, 35.43 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 6378, seg size 6380, 45209 merges
merged operations:
 insert 467359, delete mark 13737931, delete 888610
discarded operations:
 insert 0, delete mark 0, delete 0
Hash table size 8850487, node heap has 15036 buffer(s)
296481.25 hash searches/s, 4879.87 non-hash searches/s
---
LOG
---
Log sequence number 174590808256
Log flushed up to   174590808256
Last checkpoint at  174589633376
0 pending log writes, 0 pending chkp writes
42519161 log i/o's done, 35.28 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 4395630592; in additional pool allocated 0
Dictionary memory allocated 829252
Buffer pool size   262144
Free buffers       16
Database pages     247092
Old database pages 91191
Modified db pages  755
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 4120399, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 2422849, created 679606, written 29056740
0.00 reads/s, 0.00 creates/s, 2.86 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: 247092, unzip_LRU len: 0
I/O sum[705]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
1 read views open inside InnoDB
Main thread process no. 30911, id 140720292824832, state: sleeping
Number of rows inserted 30042313, updated 60944284, deleted 28858062, read 2514515901102
11.36 inserts/s, 28.57 updates/s, 4.00 deletes/s, 436602.24 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

Indexes in notification table are –

id - Primary key  
user_id - non-unique index

Best Answer

Let's look at the queries that are deadlocking:

Under TRANSACTION 3D61D41F, you have this query:

INSERT INTO `notification` (`other_grouped_notifications_count`, `user_id`,
`notifiable_type`, `action_item`, `action_id`, `created_at`, `status`, `updated_at`)
VALUES (0, 4442, 'MATCH', 'MATCH', 224716, 1365448255, 1, 1365448255)

Under TRANSACTION 3D61C472, you have this query:

UPDATE `notification` SET `status`=0 WHERE user_id = 4443 and status=1

How in thw world could these queries deadlock?

To answer this, you must understand how the InnoDB Storage Engine handles indexes. For starters, click here to see the pictorial representation of InnoDB's Infrastructure.

Here is something to also start with: the gen_clust_index, better known as the Clustered Index. It is the home of the PRIMARY KEY. As the MySQL Documentation says:

All indexes other than the clustered index are known as secondary indexes. In InnoDB, each record in a secondary index contains the primary key columns for the row, as well as the columns specified for the secondary index. InnoDB uses this primary key value to search for the row in the clustered index.

If the primary key is long, the secondary indexes use more space, so it is advantageous to have a short primary key.

Since entries in a Secondary Index contain the key back to the Clustered Index, there would be some processing done to align secondary keys with corresponding PRIMARY KEY entries. This is performed in the Insert Buffer contained within ibdata1 (the system tablespace).

Now, look back at the queries.

FIRST QUERY : The INSERT query from TRANSACTION 3D61D41F has to lock a newly generated entry in the gen_clust_index. It also has to create an entry in the Secondary Index for user_id 4442 and must carry the newly created gen_clust_index key and process them together in the Insert Buffer.

SECOND QUERY : The UPDATE query in TRANSACTION 3D61C472 has to get a lock on an already existing row whose user_id is 4443. Consequently, a lock on the corresponding gen_clust_index entry is required.

LOCKS IN COMMON

`TRANSACTION 3D61D41F`

RECORD LOCKS space id 0 page no 272207 n bits 1272 index `user_id`
0: len 4; hex 8000115b; asc    [;;
1: len 4; hex 0005e0bb; asc     ;;
Record lock, heap no 69 PHYSICAL RECORD: n_fields 2; compact format; info bits 0

`TRANSACTION 3D61C472`

RECORD LOCKS space id 0 page no 272207 n bits 1272 index `user_id`
0: len 4; hex 8000115b; asc    [;;
1: len 4; hex 0005e0bb; asc     ;;
Record lock, heap no 69 PHYSICAL RECORD: n_fields 2; compact format; info bits 0

Both Transactions Need the Same Part of the gen_clust_index

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 261029 n bits 248 index `PRIMARY` of table `notification` trx id 3D61C472 lock_mode X locks rec but not gap waiting
Record lock, heap no 161 PHYSICAL RECORD: n_fields 16; compact format; info bits 0

According to this, the UPDATE query has attempted to lock first. Unfortunately, that's fair because UPDATE works with an already existing row. The INSERT is attempting to create a new row. It had to auto generate a PRIMARY KEY entry in the same location needed by the UPDATE.

This solves the mystery as to why the deadlock occurs in this particular instance.

SUGGESTION

Instead of doing

INSERT INTO ROLE (PERMISSION_ID, ROLE_NAME, DOMAIN_ID) VALUES (4188, 'everyone',
(SELECT DOMAIN_ID FROM DOMAIN WHERE TENANT_ID=1 AND DOMAIN_NAME='INTERNAL'));

you should retrieve the DOMAIN_ID separately into a variable and then use it in the INSERT

SELECT DOMAIN_ID INTO @domain_id FROM DOMAIN
WHERE TENANT_ID=1 AND DOMAIN_NAME='INTERNAL';
INSERT INTO ROLE (PERMISSION_ID, ROLE_NAME, DOMAIN_ID) VALUES (4188,'everyone',@domain_id);

This might reduce the need to pile up locks

Best Answer

TRANSACTION 3D61D41F

TRANSACTION 3D61C472

Related Solutions

Mysql – How to find who holds the lock based on the hex-dumped

Mysql – Clarification on thesql deadlock situation

SUGGESTION

Related Question

`TRANSACTION 3D61D41F`

`TRANSACTION 3D61C472`