A complete record of a Mysql deadlock troubleshooting process

Preface

The database deadlocks I encountered before were all caused by inconsistent locking order during batch updates, but last week I encountered a deadlock that was very difficult to understand. I took this opportunity to relearn MySQL deadlock knowledge and common deadlock scenarios. After much research and discussions with colleagues, I finally discovered the cause of the deadlock problem and gained a lot. Although we are backend programmers, we do not need to analyze the lock-related source code as deeply as DBAs, but if we can master the basic deadlock troubleshooting methods, it will be of great benefit to our daily development.

PS: This article will not introduce the basic knowledge of deadlock. For the locking principle of MySQL, please refer to the link provided in the reference materials of this article.

Deadlock Causes

Let me first introduce the database and table situation. Because it involves real data within the company, the following is simulated and will not affect the specific analysis.

We use the MySQL database version 5.5, the transaction isolation level is the default RR (Repeatable-Read), and the InnoDB engine is used. Assume that there is a test table:

CREATE TABLE `test` (
 `id` int(11) unsigned NOT NULL AUTO_INCREMENT,
 `a` int(11) unsigned DEFAULT NULL,
 PRIMARY KEY (`id`),
 UNIQUE KEY `a` (`a`)
) ENGINE=InnoDB AUTO_INCREMENT=100 DEFAULT CHARSET=utf8;

The structure of the table is very simple, with a primary key id and another unique index a. The data in the table are as follows:

mysql> select * from test;
+----+------+
| id | a |
+----+------+
| 1 | 1 |
| 2 | 2 |
| 4 | 4 |
+----+------+
3 rows in set (0.00 sec)

The operations that cause deadlock are as follows:

Then we can view the deadlock log through SHOW ENGINE INNODB STATUS; ;:

------------------------
LATEST DETECTED DEADLOCK
------------------------
170219 13:31:31
*** (1) TRANSACTION:
TRANSACTION 2A8BD, ACTIVE 11 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 376, 1 row lock(s)
MySQL thread id 448218, OS thread handle 0x2abe5fb5d700, query id 18923238 renjun.fangcloud.net 121.41.41.92 root updating
delete from test where a = 2
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 923 n bits 80 index `a` of table `oauthdemo`.`test` trx id 2A8BD lock_mode X waiting
Record lock, heap no 3 PHYSICAL RECORD: n_fields 2; compact format; info bits 32
 0: len 4; hex 00000002; asc ;;
 1: len 4; hex 00000002; asc ;;
*** (2) TRANSACTION:
TRANSACTION 2A8BC, ACTIVE 18 sec inserting
mysql tables in use 1, locked 1
4 lock struct(s), heap size 1248, 3 row lock(s), undo log entries 2
MySQL thread id 448217, OS thread handle 0x2abe5fd65700, query id 18923239 renjun.fangcloud.net 121.41.41.92 root update
insert into test (id,a) values ​​(10,2)
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 0 page no 923 n bits 80 index `a` of table `oauthdemo`.`test` trx id 2A8BC lock_mode X locks rec but not gap
Record lock, heap no 3 PHYSICAL RECORD: n_fields 2; compact format; info bits 32
 0: len 4; hex 00000002; asc ;;
 1: len 4; hex 00000002; asc ;;
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 923 n bits 80 index `a` of table `oauthdemo`.`test` trx id 2A8BC lock mode S waiting
Record lock, heap no 3 PHYSICAL RECORD: n_fields 2; compact format; info bits 32
 0: len 4; hex 00000002; asc ;;
 1: len 4; hex 00000002; asc ;;
*** WE ROLL BACK TRANSACTION (1)

analyze

Reading the deadlock log

When encountering a deadlock, the first step is to read the deadlock log. The deadlock log is usually divided into two parts. The first part shows what lock transaction 1 is waiting for:

170219 13:31:31
*** (1) TRANSACTION:
TRANSACTION 2A8BD, ACTIVE 11 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 376, 1 row lock(s)
MySQL thread id 448218, OS thread handle 0x2abe5fb5d700, query id 18923238 renjun.fangcloud.net 121.41.41.92 root updating
delete from test where a = 2
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 923 n bits 80 index `a` of table `oauthdemo`.`test` trx id 2A8BD lock_mode X waiting
Record lock, heap no 3 PHYSICAL RECORD: n_fields 2; compact format; info bits 32
 0: len 4; hex 00000002; asc ;;
 1: len 4; hex 00000002; asc ;;

From the log, we can see that transaction 1 is currently executing delete from test where a = 2 This statement is applying for an X lock on index a, so lock_mode X waiting is displayed.

The bottom half of the log then shows the locks that transaction 2 currently holds and is waiting for:

*** (2) TRANSACTION:
TRANSACTION 2A8BC, ACTIVE 18 sec inserting
mysql tables in use 1, locked 1
4 lock struct(s), heap size 1248, 3 row lock(s), undo log entries 2
MySQL thread id 448217, OS thread handle 0x2abe5fd65700, query id 18923239 renjun.fangcloud.net 121.41.41.92 root update
insert into test (id,a) values ​​(10,2)
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 0 page no 923 n bits 80 index `a` of table `oauthdemo`.`test` trx id 2A8BC lock_mode X locks rec but not gap
Record lock, heap no 3 PHYSICAL RECORD: n_fields 2; compact format; info bits 32
 0: len 4; hex 00000002; asc ;;
 1: len 4; hex 00000002; asc ;;
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 923 n bits 80 index `a` of table `oauthdemo`.`test` trx id 2A8BC lock mode S waiting
Record lock, heap no 3 PHYSICAL RECORD: n_fields 2; compact format; info bits 32
 0: len 4; hex 00000002; asc ;;
 1: len 4; hex 00000002; asc ;;

From HOLDS THE LOCKS(S) block in the log, we can see that transaction 2 holds an X lock on index a, and it is a record lock. The lock is acquired by the delete statement executed by transaction 2 in step 2. Because this is an equality query based on a unique index in RR isolation mode (Where a = 2), a record lock is requested instead of a next-key lock.

From WAITING FOR THIS LOCK TO BE GRANTED , which is a shared lock. The lock is applied by the statement insert into test (id,a) values ​​(10,2). Under normal circumstances, the insert statement will apply for an exclusive lock, that is, an X lock, but an S lock appears here. This is because field a is a unique index, so the insert statement will perform a duplicate key check before inserting. In order for this check to succeed, it is necessary to apply for an S lock to prevent other transactions from modifying field a.

So why does the S lock fail? This means that applications for locks on the same field need to queue. There is an unsuccessful X lock before the S lock, so the S lock must wait, thus forming a circular waiting and a deadlock occurs.

By reading the deadlock log, we can clearly know what kind of circular wait is formed by the two transactions. After further analysis, we can reversely infer the cause of the circular wait, that is, the cause of the deadlock.

Deadlock formation flow chart

In order to help you better understand the causes of deadlock, we will explain the process of deadlock formation in the form of a table:

expand

During the deadlock troubleshooting process, a colleague discovered that the above scenario would produce another deadlock, which could not be reproduced manually and could only be reproduced in a high-concurrency scenario.

The log corresponding to this deadlock is not posted here. lock_mode X locks gap before rec insert intention waiting gap before rec insert intention waiting.

We still use a table to explain in detail the process of deadlock generation:

Summarize

When troubleshooting deadlocks, you first need to analyze the circular wait scenario based on the deadlock log, then analyze the lock type and sequence based on the SQL executed by each current transaction, and reversely infer how the circular wait is formed. In this way, you can find the cause of the deadlock.

Well, that’s all for this article. I hope that the content of this article can be of some help to your study or work. The above analysis is based on experience. I hope that other friends can point out the errors and deficiencies. Thank you for your support for 123WORDPRESS.COM.