Login/Register
How do I debug this mysql deadlock?
Asked Answered
mysqldatabase-deadlocks
R

1

7

I'm getting deadlocks in my MySQL InnoDB tables. InnoDB log pinpoints two queries that resulted in deadlock (it's two exact same queries, both parts of exact same transactions, resulting from almost-simultaneous duplicate requests to API). But I can't understand what is the problem - query just updates some fields in a row, why should it deadlock?

Here's example of the query:

update `some_table` set `some_field` = 123 where `some_table`.`id` = 530;

Below I pasted the deadlock log from InnoDB show engine innodb status;. What puzzles me is that for (2) TRANSACTION rows in HOLDS THE LOCK and WAITING FOR THIS LOCK TO BE GRANTED are the same - as if it was both holding the lock and waiting for it.

I am new to deadlock handling in InnoDB, so probably I am missing something. What is wrong here?

LATEST DETECTED DEADLOCK
------------------------
2017-10-28 11:50:42 0x7f9d586d2700
*** (1) TRANSACTION:
TRANSACTION 14425003, ACTIVE 1 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 5 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1
MySQL thread id 4662, OS thread handle 140313765725952, query id 6441114 localhost 127.0.0.1 app updating
update `some_table` set `some_field` = 123 where `some_table`.`id` = 530
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 148 page no 15 n bits 96 index PRIMARY of table `some_schema`.`some_table` trx id 14425003 lock_mode X locks rec but not gap waiting
Record lock, heap no 14 PHYSICAL RECORD: n_fields 30; compact format; info bits 0
 0: len 8; hex 8000000000000212; asc         ;;
 1: len 6; hex 000000dc1b3a; asc      :;;
 2: len 7; hex 350000013227b6; asc 5   2' ;;
 3: len 8; hex 8000000000000006; asc         ;;
 4: SQL NULL;
 5: len 4; hex 80000000; asc     ;;
 6: len 28; hex d09ed0bad181d0bad0b8d0b520d181d0b0d0b4d18b20283530333029; asc                       (5030);;
 7: len 30; hex d09fd0bed181d0b5d0bbd0bed0ba2022d09ed0bad181d0bad0b8d0b520d1; asc                "              ; (total 38 bytes);
 8: len 12; hex d0add092d0a0d098d09ad090; asc             ;;
 9: len 4; hex 312e3732; asc 1.72;;
 10: len 8; hex 8000000000000023; asc        #;;
 11: SQL NULL;
 12: len 30; hex 30820122300d06092a864886f70d01010105000382010f003082010a0282; asc 0  "0   * H             0     ; (total 294 bytes);
 13: SQL NULL;
 14: len 1; hex 9d; asc  ;;
 15: len 30; hex 353030303a333b3530303a333b313030303a33313b35303a353b3130303a; asc 5000:3;500:3;1000:31;50:5;100:; (total 32 bytes);
 16: len 4; hex 800001f4; asc     ;;
 17: len 8; hex 8000015f622b7acf; asc    _b+z ;;
 18: SQL NULL;
 19: SQL NULL;
 20: len 1; hex 80; asc  ;;
 21: len 1; hex 81; asc  ;;
 22: len 1; hex 81; asc  ;;
 23: len 1; hex 81; asc  ;;
 24: len 4; hex 77696669; asc wifi;;
 25: len 7; hex 6d656761666f6e; asc megafon;;
 26: len 8; hex 8000015f5d43771a; asc    _]Cw ;;
 27: len 30; hex 4a1a42c600000230000007d700000772000007b3000007e1000007e20000; asc J B    0       r              ; (total 48 bytes);
 28: len 8; hex 5cbdd55bbd55e93f; asc \  [ U ?;;
 29: len 4; hex 80000000; asc     ;;

*** (2) TRANSACTION:
TRANSACTION 14425004, ACTIVE 1 sec starting index read
mysql tables in use 1, locked 1
5 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1
MySQL thread id 4663, OS thread handle 140313770141440, query id 6441120 localhost 127.0.0.1 app updating
update `some_table` set `some_field` = 123 where `some_table`.`id` = 530
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 148 page no 15 n bits 96 index PRIMARY of table `some_schema`.`some_table` trx id 14425004 lock mode S locks rec but not gap
Record lock, heap no 14 PHYSICAL RECORD: n_fields 30; compact format; info bits 0
 0: len 8; hex 8000000000000212; asc         ;;
 1: len 6; hex 000000dc1b3a; asc      :;;
 2: len 7; hex 350000013227b6; asc 5   2' ;;
 3: len 8; hex 8000000000000006; asc         ;;
 4: SQL NULL;
 5: len 4; hex 80000000; asc     ;;
 6: len 28; hex d09ed0bad181d0bad0b8d0b520d181d0b0d0b4d18b20283530333029; asc                       (5030);;
 7: len 30; hex d09fd0bed181d0b5d0bbd0bed0ba2022d09ed0bad181d0bad0b8d0b520d1; asc                "              ; (total 38 bytes);
 8: len 12; hex d0add092d0a0d098d09ad090; asc             ;;
 9: len 4; hex 312e3732; asc 1.72;;
 10: len 8; hex 8000000000000023; asc        #;;
 11: SQL NULL;
 12: len 30; hex 30820122300d06092a864886f70d01010105000382010f003082010a0282; asc 0  "0   * H             0     ; (total 294 bytes);
 13: SQL NULL;
 14: len 1; hex 9d; asc  ;;
 15: len 30; hex 353030303a333b3530303a333b313030303a33313b35303a353b3130303a; asc 5000:3;500:3;1000:31;50:5;100:; (total 32 bytes);
 16: len 4; hex 800001f4; asc     ;;
 17: len 8; hex 8000015f622b7acf; asc    _b+z ;;
 18: SQL NULL;
 19: SQL NULL;
 20: len 1; hex 80; asc  ;;
 21: len 1; hex 81; asc  ;;
 22: len 1; hex 81; asc  ;;
 23: len 1; hex 81; asc  ;;
 24: len 4; hex 77696669; asc wifi;;
 25: len 7; hex 6d656761666f6e; asc megafon;;
 26: len 8; hex 8000015f5d43771a; asc    _]Cw ;;
 27: len 30; hex 4a1a42c600000230000007d700000772000007b3000007e1000007e20000; asc J B    0       r              ; (total 48 bytes);
 28: len 8; hex 5cbdd55bbd55e93f; asc \  [ U ?;;
 29: len 4; hex 80000000; asc     ;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 148 page no 15 n bits 96 index PRIMARY of table `some_schema`.`some_table` trx id 14425004 lock_mode X locks rec but not gap waiting
Record lock, heap no 14 PHYSICAL RECORD: n_fields 30; compact format; info bits 0
 0: len 8; hex 8000000000000212; asc         ;;
 1: len 6; hex 000000dc1b3a; asc      :;;
 2: len 7; hex 350000013227b6; asc 5   2' ;;
 3: len 8; hex 8000000000000006; asc         ;;
 4: SQL NULL;
 5: len 4; hex 80000000; asc     ;;
 6: len 28; hex d09ed0bad181d0bad0b8d0b520d181d0b0d0b4d18b20283530333029; asc                       (5030);;
 7: len 30; hex d09fd0bed181d0b5d0bbd0bed0ba2022d09ed0bad181d0bad0b8d0b520d1; asc                "              ; (total 38 bytes);
 8: len 12; hex d0add092d0a0d098d09ad090; asc             ;;
 9: len 4; hex 312e3732; asc 1.72;;
 10: len 8; hex 8000000000000023; asc        #;;
 11: SQL NULL;
 12: len 30; hex 30820122300d06092a864886f70d01010105000382010f003082010a0282; asc 0  "0   * H             0     ; (total 294 bytes);
 13: SQL NULL;
 14: len 1; hex 9d; asc  ;;
 15: len 30; hex 353030303a333b3530303a333b313030303a33313b35303a353b3130303a; asc 5000:3;500:3;1000:31;50:5;100:; (total 32 bytes);
 16: len 4; hex 800001f4; asc     ;;
 17: len 8; hex 8000015f622b7acf; asc    _b+z ;;
 18: SQL NULL;
 19: SQL NULL;
 20: len 1; hex 80; asc  ;;
 21: len 1; hex 81; asc  ;;
 22: len 1; hex 81; asc  ;;
 23: len 1; hex 81; asc  ;;
 24: len 4; hex 77696669; asc wifi;;
 25: len 7; hex 6d656761666f6e; asc megafon;;
 26: len 8; hex 8000015f5d43771a; asc    _]Cw ;;
 27: len 30; hex 4a1a42c600000230000007d700000772000007b3000007e1000007e20000; asc J B    0       r              ; (total 48 bytes);
 28: len 8; hex 5cbdd55bbd55e93f; asc \  [ U ?;;
 29: len 4; hex 80000000; asc     ;;

*** WE ROLL BACK TRANSACTION (2)
Ruyle answered 28/10, 2017 at 9:2 Comment(1)
I am getting same exact problem but with 2 same insert queries. – Magi
P
1

I guess this deadlock is caused by share lock on your primary key. Here is a link to offical document, how deadlock occurs.

Then I look into your issue, and do some investigation to try to reproduce this deadlock. First, let analysis your deadlock log:

  1. 2 transactions related to this deadlock.
  2. Transaction (1) id = 14425003
  3. Transaction (2) id = 14425004
  4. Transaction (2) roll back finnaly after deadlock was detected.
  5. Transaction (2) hold lock mode S locks rec but not gap
  6. Transaction (2) wait lock_mode X locks rec but not gap
  7. Transaction (1) wait lock_mode X locks rec but not gap

To sum up, Transaction (2) hold RECORD LOCK S and want to get RECORD LOCK X, at the same time Transaction (1) want to get RECORD LOCK X. They blocked each other, and then a deadlock occur.

Use select * where id = 530 lock in share mode to grant RECORD LOCK S is very simple, however, I think you may not use this query in your application.

Then we need to know when RECORD LOCK S will be add to a primary index. The following are from msyql offical document

If a duplicate-key error occurs, a shared lock on the duplicate index record is set. This use of a shared lock can result in deadlock should there be multiple sessions trying to insert the same row if another session already has an exclusive lock. This can occur if another session deletes the row. Suppose that an InnoDB table t1 has the following structure:

With that said, there must be some query do insert or update and duplicate-key error occurs.

The following are how to reproduce this kind of deadlock:

1. Create table:

CREATE TABLE `t` (
  `id` bigint(20) NOT NULL AUTO_INCREMENT,
  `name` varchar(32) NOT NULL,
  PRIMARY KEY (`id`),
  unique key `p_name` (`name`)
) ENGINE=InnoDB CHARSET=utf8;

2. Prepare data:

insert into t (name) value ('A'), ('C'), ('D');

3. Reproduce Steps

+-------------------------------------------+--------------------------------------+
|                 Session A                 |              Session B               |
+-------------------------------------------+--------------------------------------+
| begin;                                    |                                      |
|                                           | begin;                               |
| insert into t (id, name) values (4, 'E'); |                                      |
| update t set name = 'C' where id = 4;     |                                      |
|                                           | update t set name = 'C' where id = 2;|
|                                           | BLOCKED                              |
| update t set name = 'C' where id = 2;     |                                      |
| DEADLOCK OCCUR                            |                                      |
+-------------------------------------------+--------------------------------------+

4. The final deadlock log is as following:

------------------------
LATEST DETECTED DEADLOCK
------------------------
2020-07-23 07:19:39 0x7f8cc819e700
*** (1) TRANSACTION:
TRANSACTION 2774, ACTIVE 4 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 140242628749056, query id 9719 192.168.48.1 root updating
/* ApplicationName=PyCharm 2019.1.1 */ update t set name = 'C' where id = 2
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 64 page no 3 n bits 72 index PRIMARY of table `test`.`t` trx id 2774 lock_mode X locks rec but not gap waiting
Record lock, heap no 3 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 8; hex 8000000000000002; asc         ;;
 1: len 6; hex 000000000ad0; asc       ;;
 2: len 7; hex a90000011d0120; asc        ;;
 3: len 1; hex 43; asc C;;

*** (2) TRANSACTION:
TRANSACTION 2773, ACTIVE 424 sec starting index read
mysql tables in use 1, locked 1
5 lock struct(s), heap size 1136, 4 row lock(s), undo log entries 1
MySQL thread id 8, OS thread handle 140242629289728, query id 9729 192.168.48.1 root updating
/* ApplicationName=PyCharm 2019.1.1 */ update t set name = 'C' where id = 2
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 64 page no 3 n bits 72 index PRIMARY of table `test`.`t` trx id 2773 lock mode S locks rec but not gap
Record lock, heap no 3 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 8; hex 8000000000000002; asc         ;;
 1: len 6; hex 000000000ad0; asc       ;;
 2: len 7; hex a90000011d0120; asc        ;;
 3: len 1; hex 43; asc C;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 64 page no 3 n bits 72 index PRIMARY of table `test`.`t` trx id 2773 lock_mode X locks rec but not gap waiting
Record lock, heap no 3 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 8; hex 8000000000000002; asc         ;;
 1: len 6; hex 000000000ad0; asc       ;;
 2: len 7; hex a90000011d0120; asc        ;;
 3: len 1; hex 43; asc C;;

*** WE ROLL BACK TRANSACTION (1)

5. How to prevent

  • Avoid or reduce duplicated value insert or update
  • Don't use unique index and let application to ensure value is unique
  • Reduce concurrent queries.
Provincial answered 23/7, 2020 at 7:24 Comment(0)

© 2022 - 2024 — McMap. All rights reserved.