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

Bug #1598822 reported by Valerii Kravchuk on 2016-07-04
10
This bug affects 1 person
Affects Status Importance Assigned to Milestone
MySQL Server
Unknown
Unknown
Percona Server moved to https://jira.percona.com/projects/PS
Status tracked in 5.7
5.5
New
Undecided
Unassigned
5.6
New
Undecided
Unassigned
5.7
New
Undecided
Unassigned

Bug Description

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.

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).

tags: added: upstream
tags: added: i135960

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

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.