Deadlock with 3 concurrent DELETEs by unique key and triggers reading the same row

[Valerii Kravchuk]

I have reasons to think that this bug is repeatable on upstream MySQL starting from 5.5.24 at least, but as I can not reproduce it on Oracle's MySQL 5.7.11 and can easily reproduce on Percona Server 5.7.12, I decided to report it here first and then let you work on details.

Here it is:

mysql> drop database test;
Query OK, 18 rows affected (36.06 sec)

mysql> create database test;
Query OK, 1 row affected (0.04 sec)

mysql> use test
Database changed
mysql> CREATE TABLE `tu`(`id` int(11), `a` int(11) DEFAULT NULL, `b` varchar(10) DEFAULT NULL, `c` varchar(10) DEFAULT NULL, PRIMARY KEY(`id`), UNIQUE KEY `u`(`a`,`b`)) ENGINE=InnoDB DEFAULT CHARSET=latin1 STATS_PERSISTENT=0;
Query OK, 0 rows affected (0.24 sec)

mysql> insert into tu values(1,1,'a','a'),(2,9999,'xxxx','x'),(3,10000,'b','b'),(4,4,'c','c');
Query OK, 4 rows affected (0.03 sec)
Records: 4 Duplicates: 0 Warnings: 0

mysql> select * from tu;
+----+-------+------+------+
| id | a | b | c |
+----+-------+------+------+
| 1 | 1 | a | a |
| 2 | 9999 | xxxx | x |
| 3 | 10000 | b | b |
| 4 | 4 | c | c |
+----+-------+------+------+
4 rows in set (0.01 sec)

mysql> create trigger tr1 before delete on tu for each row select c into @a from tu where a=9999 and b='xxxx';
Query OK, 0 rows affected (0.06 sec)

mysql> create trigger tr2 after delete on tu for each row select c into @b from tu where a=9999 and b='xxxx';
Query OK, 0 rows affected (0.07 sec)

mysql> exit
Bye

Now let's run 3 concurrent DELETEs of the row referenced in triggers using mysqlslap:

[openxs@centos 5.7]$ mysqlslap -uroot --concurrency=3 --create-schema=test --no-drop --number-of-queries=1000 --query="delete from tu where a = 9999 and b = 'xxxx'"
mysqlslap: Cannot run query delete from tu where a = 9999 and b = 'xxxx' ERROR : Deadlock found when trying to get lock; try restarting transaction

Let's check deadlock details:

[openxs@centos 5.7]$ mysql -uroot
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 10
Server version: 5.7.12-5-log Percona Server (GPL), Release 5, Revision a2f663a

Copyright (c) 2009-2016 Percona LLC and/or its affiliates
Copyright (c) 2000, 2016, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> show engine innodb status\G
*************************** 1. row ***************************
  Type: InnoDB
  Name:
Status:
=====================================
2016-07-04 15:00:25 0x7f2df3f10700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 56 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 44 srv_active, 0 srv_shutdown, 429 srv_idle
srv_master_thread log flush and writes: 473
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 1424
OS WAIT ARRAY INFO: signal count 1186
RW-shared spins 0, rounds 610, OS waits 269
RW-excl spins 0, rounds 10925, OS waits 290
RW-sx spins 223, rounds 6668, OS waits 167
Spin rounds per wait: 610.00 RW-shared, 10925.00 RW-excl, 29.90 RW-sx
------------------------
LATEST DETECTED DEADLOCK
------------------------
2016-07-04 15:00:07 0x7f2df3e8e700
*** (1) TRANSACTION:
TRANSACTION 358015, ACTIVE 0 sec starting index read
mysql tables in use 3, locked 3
LOCK WAIT 2 lock struct(s), heap size 1136, 1 row lock(s)
MySQL thread id 7, OS thread handle 139835342915328, query id 348 localhost root updating
delete from tu where a = 9999 and b = 'xxxx'
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 622 page no 4 n bits 72 index u of table `test`.`tu` trx id 358015 lock_mode X locks rec but not gap waiting
*** (2) TRANSACTION:
TRANSACTION 358014, ACTIVE 0 sec starting index read
mysql tables in use 3, locked 3
3 lock struct(s), heap size 1136, 2 row lock(s)
MySQL thread id 9, OS thread handle 139835342382848, query id 349 localhost root updating
delete from tu where a = 9999 and b = 'xxxx'
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 622 page no 4 n bits 72 index u of table `test`.`tu` trx id 358014 lock_mode X locks rec but not gap
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 622 page no 4 n bits 72 index u of table `test`.`tu` trx id 358014 lock_mode X waiting
*** WE ROLL BACK TRANSACTION (1)

Now, go on and explain this deadlock. Why transaction that holds the record lock on unique secondary index may need the next-key lock on the same index and so on. Have fun!

I'll add more details about versions affected as soon as I get this bug reproduced on them.

[Valerii Kravchuk (valerii-kravchuk)]

See upstream http://bugs.mysql.com/bug.php?id=82127. Triggers are NOT strictly needed when I use 2 cores on a real hardware (instead of single core VM).

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-3479