Bug #82127 Deadlock with 3 concurrent DELETEs by UNIQUE key
Submitted: 6 Jul 2016 13:55 Modified: 17 Aug 2018 17:32
Reporter: Valeriy Kravchuk Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S3 (Non-critical)
Version:5.7.13 OS:Any
Assigned to: CPU Architecture:Any
Tags: deadlock, innodb, missing manual

[6 Jul 2016 13:55] Valeriy Kravchuk
Description:
Basically, https://bugs.launchpad.net/percona-server/+bug/1598822 is also repeatable with MySQL 5.7.13, even without triggers defined. See more details below.

How to repeat:
On the fresh 5.7.13 instance started with --no-defaults:

openxs@ao756:~/dbs/5.7$ bin/mysql -uroot
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 4
Server version: 5.7.13 MySQL Community Server (GPL)

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> create database test;
Query OK, 1 row affected (0,00 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,30 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,04 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,00 sec)

-- This part below is optional

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,10 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,10 sec)

mysql> exit
Bye
openxs@ao756:~/dbs/5.7$ bin/mysqlslap -uroot --concurrency=3 --create-schema=test --no-drop --number-of-queries=1000 --query="delete from tu where a = 9999 and b = 'xxxx'"
bin/mysqlslap: Cannot run query delete from tu where a = 9999 and b = 'xxxx' ERROR : Deadlock found when trying to get lock; try restarting transaction

Now, let's check deadlock details:

openxs@ao756:~/dbs/5.7$ bin/mysql -uroot
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 9
Server version: 5.7.13 MySQL Community Server (GPL)

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-06 16:44:26 0x7efd6b827700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 0 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 6 srv_active, 0 srv_shutdown, 115 srv_idle
srv_master_thread log flush and writes: 121
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 16
OS WAIT ARRAY INFO: signal count 15
RW-shared spins 0, rounds 18, OS waits 9
RW-excl spins 0, rounds 0, OS waits 0
RW-sx spins 0, rounds 0, OS waits 0
Spin rounds per wait: 18.00 RW-shared, 0.00 RW-excl, 0.00 RW-sx
------------------------
LATEST DETECTED DEADLOCK
------------------------
2016-07-06 16:44:13 0x7efd6b868700
*** (1) TRANSACTION:
TRANSACTION 1287, 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 139626895537920, query id 15 localhost root updating
delete from tu where a = 9999 and b = 'xxxx'
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 23 page no 4 n bits 72 index u of table `test`.`tu` trx id 1287 lock_mode X locks rec but not gap waiting
Record lock, heap no 3 PHYSICAL RECORD: n_fields 3; compact format; info bits 32
 0: len 4; hex 8000270f; asc   ' ;;
 1: len 4; hex 78787878; asc xxxx;;
 2: len 4; hex 80000002; asc     ;;

*** (2) TRANSACTION:
TRANSACTION 1285, 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 8, OS thread handle 139626895804160, query id 16 localhost root updating
delete from tu where a = 9999 and b = 'xxxx'
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 23 page no 4 n bits 72 index u of table `test`.`tu` trx id 1285 lock_mode X locks rec but not gap
Record lock, heap no 3 PHYSICAL RECORD: n_fields 3; compact format; info bits 32
 0: len 4; hex 8000270f; asc   ' ;;
 1: len 4; hex 78787878; asc xxxx;;
 2: len 4; hex 80000002; asc     ;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 23 page no 4 n bits 72 index u of table `test`.`tu` trx id 1285 lock_mode X waiting
Record lock, heap no 3 PHYSICAL RECORD: n_fields 3; compact format; info bits 32
 0: len 4; hex 8000270f; asc   ' ;;
 1: len 4; hex 78787878; asc xxxx;;
 2: len 4; hex 80000002; asc     ;;

*** WE ROLL BACK TRANSACTION (1)
...

Now, try to find explanation for this deadlock (or the need to ever get a next-key lock on the same secondary index record that is already locked) in the manual.

Same happens without triggers as well:

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,00 sec)

mysql> show triggers;
Empty set (0,01 sec)

mysql> exit
Bye
openxs@ao756:~/dbs/5.7$ bin/mysqlslap -uroot --concurrency=3 --create-schema=test --no-drop --number-of-queries=1000 --query="delete from tu where a = 9999 and b = 'xxxx'"
bin/mysqlslap: Cannot run query delete from tu where a = 9999 and b = 'xxxx' ERROR : Deadlock found when trying to get lock; try restarting transaction
openxs@ao756:~/dbs/5.7$ bin/mysql -uroot
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 14
Server version: 5.7.13 MySQL Community Server (GPL)

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-06 16:51:37 0x7efd6b8a9700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 4 seconds

...

------------------------
LATEST DETECTED DEADLOCK
------------------------
2016-07-06 16:50:15 0x7efd6b827700
*** (1) TRANSACTION:
TRANSACTION 1519, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 1136, 1 row lock(s)
MySQL thread id 12, OS thread handle 139626896070400, query id 266 localhost root updating
delete from tu where a = 9999 and b = 'xxxx'
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 23 page no 4 n bits 72 index u of table `test`.`tu` trx id 1519 lock_mode X waiting
Record lock, heap no 3
*** (2) TRANSACTION:
TRANSACTION 1517, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
3 lock struct(s), heap size 1136, 2 row lock(s)
MySQL thread id 13, OS thread handle 139626895537920, query id 265 localhost root updating
delete from tu where a = 9999 and b = 'xxxx'
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 23 page no 4 n bits 72 index u of table `test`.`tu` trx id 1517 lock_mode X locks rec but not gap
Record lock, heap no 3
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 23 page no 4 n bits 72 index u of table `test`.`tu` trx id 1517 lock_mode X waiting
Record lock, heap no 3
*** WE ROLL BACK TRANSACTION (1)

Suggested fix:
Explain locking for DELETE statement properly in the manual, for the case with secondary UNIQUE index as well.

Consider fixing locking in InnoDB so that deadlock does NOT happen in such a typical use case of concurrent load (originally was reported by customer on a bit more complicated table).
[6 Jul 2016 17:42] Sinisa Milivojevic
Hi Valeriy,

Thank you so much for your bug report.

However, I am wandering why do you think that this is a bug ???

What we have is a deadlock that occurs during lock upgrading and not during lock acquiring. Deadlocks are to be expected in the transactional engines, and are not consider bugs.

If you remember, I have filed for the feature request, where priority would go to the transaction that just wants to upgrade a lock. It was even justified by Heikki. I can try to provide for it a much higher priority. Would that be good enough for you ????

Thanks for the reminder, though ...
[6 Jul 2016 21:45] Valeriy Kravchuk
Please, send me URLs and quotes from that manual pages that explain the case when DELETE may request a record lock on secondary index and then request a next-key lock on the same record of the same secondary index. I'll easily agree it's not a bug if the manual explains the locks requests we see in this case and why they are needed at the REPEATABLE READ (default) isolation level.
[6 Jul 2016 21:48] Valeriy Kravchuk
If you mean this old request, https://bugs.mysql.com/bug.php?id=21356, Sinisa, then I have to say that this case is different.
[7 Jul 2016 14:01] Sinisa Milivojevic
Valeriy,

To tell you the truth I do not see anything unknown in your report.

With triggers,  both the 'before delete' and 'after delete' triggers are trying to delete the same record. That sounds like a natural deadlock to me. 

Without triggers, you are trying to delete the same row(s) from three separate connections.

That leads to the natural deadlock, due to the lock upgrading, about which I have submitted a feature request.
[7 Jul 2016 16:35] Valeriy Kravchuk
Sinisa, please, give me URL or present a quote from the current manual of MySQL 5.7 (or any version) that explains when "lock upgrading" happens. Alternatively, show me the code that does this.

Deadlocks in concurrent environment are surely expected and not new, and manual explains many of typical scenarios, but not the one I reproduced here. Nothing in the manual (from my knowledge) explains why (or in what cases) DELETE, at REPEATABLE READ isolation level, may get a secondary index record lock and then request a next-key lock on the SAME record.

So, I see a documentation issue here at least.
[7 Jul 2016 17:25] Sinisa Milivojevic
This is a fair request.

Verified.
[12 Jun 2018 14:23] Daniel Price
Posted by developer:
 
The locking that occurs in this scenario has been determined to be suboptimal. Reclassifying as an InnoDB code bug.
[17 Aug 2018 17:32] Valeriy Kravchuk
Changed category.