Shulou(Shulou.com)06/01 Report--

Preface

If our business is in a very primary stage and the degree of concurrency is relatively low, then we will not encounter a deadlock problem once in several years. On the contrary, our business has a very high degree of concurrency. Then the deadlock problem that breaks out from time to time must make us scratch our heads very much. However, when the deadlock problem occurs, the first reaction of many inexperienced students is to become an ostrich: this thing is very advanced, I do not understand, resigned to fate, it does not always happen. In fact, if you carefully read our previous three articles on sentence locking analysis in MySQL, plus this analysis on deadlock logs, then solving the deadlock problem should not be so baffling.

Preparatory work

In order for the story to develop smoothly, we need to build a table:

CREATE TABLE hero (id INT, name VARCHAR, country varchar, PRIMARY KEY (id), KEY idx_name (name)) Engine=InnoDB CHARSET=utf8

We created a clustered index for the id column of the hero table and a secondary index for the name column. This hero table is mainly used to store some heroes from the three Kingdoms. We insert some records into the table:

INSERT INTO hero VALUES (1,'l Liu Bei', 'Shu'), (3,'z Zhuge Liang', 'Shu'), (8,'c Cao Cao', 'Wei'), (15,'x Xun Xun', 'Wei'), (20, 'Sun Quan','Wu')

Now the data in the table looks like this:

Mysql > SELECT * FROM hero +-+ | id | name | country | +-- + | 1 | l Liu Bei | Shu | 3 | z Zhuge Liang | Shu | 8 | c Cao Cao | Wei | 15 | x Xun Xun | Wei | 20 | s Sun Quan | Wu | +-+-- -+-+ 5 rows in set (0.00 sec)

The preparatory work is done.

Create a deadlock scenario

Let's first create a scenario where a deadlock occurs and execute two transactions in Session An and Session B, respectively, as follows:

Let's analyze:

As you can see from step ③, the transaction in Session A first adds an X-type formal record lock to the record with an id value of 1 in the clustering index of the hero table. As you can see from step ④, the transaction in Session B adds an X-type formal record lock to the record with an id value of 3 in the clustering index of the hero table. As you can see from step ⑤, the transaction in Session A then wants to add an X-type formal record lock to the record with an id value of 3 in the clustering index of the hero table, but conflicts with the lock added by the transaction in step ④ B, so Session An enters a blocking state, waiting for the lock to be acquired. As can be seen from step ⑥, the transaction in Session B wants to add an X-type formal record lock to the record with the id value of 1 in the clustering index of the hero table, but conflicts with the lock added by the transaction in step ③, while the transaction loop in Session An and Session B waits for the lock held by the other party, and the deadlock occurs, which is detected by the deadlock detection mechanism of the MySQL server, so a transaction is selected to roll back. And send a message to the client:

ERROR 1213 (40001): Deadlock found when trying to get lock; try restarting transaction

The above is from the point of view of what locks are added to the statements to analyze the deadlock situation, but in practical application, we may not know which statements produce deadlocks at all. We need to reverse locate what statements produce deadlocks according to the deadlock log generated by MySQL when deadlocks occur, so as to optimize our business.

View deadlock log

The uncle who designed InnoDB provided us with the SHOW ENGINE INNODB STATUS command to view some status information about the InnoDB storage engine, including the locking situation during the last deadlock in the system. When the deadlock in the above example occurs, let's run this command:

Mysql > SHOW ENGINE INNODB STATUS\ G. A lot of other information was omitted-LATEST DETECTED DEADLOCK----2019-06-20 13:39:19 0x70000697e000information * (1) TRANSACTION:TRANSACTION 30477, ACTIVE 10 sec starting index readmysql tables in use 1, locked 1LOCK WAIT 3 lock struct (s), heap size 1160, 2 row lock (s) MySQL thread id 2, OS thread handle 123145412648960 Query id 46 localhost 127.0.0.1 root statisticsselect * from hero where id = 3 for update*** (1) WAITING FOR THIS LOCK TO BE GRANTED:RECORD LOCKS space id 171n bits 72 index PRIMARY of table `dahaizi`.`room`trx id 30477 lock_mode X locks rec but not gap waitingRecord lock, heap no 3 PHYSICAL RECORD: n_fields 5 Compact format; info bits 00: len 4; hex 80000003; asc; 1: len 6; hex 0000007517; asc u; 2: len 7; hex 80000001d0011d; asc; 3: len 10; hex 7ae8afb8e8919be4baae; asc z; 4: len 3; hex e89c80; asc * (2) TRANSACTION:TRANSACTION 30478, ACTIVE 8 sec starting index readmysql tables in use 1, locked 13 lock struct (s), heap size 1160, 2 row lock (s) MySQL thread id 3, OS thread handle 123145412927488, query id 47 localhost 127.0.0.1 root statisticsselect * from hero where id = 1 for update*** (2) HOLDS THE LOCK (S): RECORD LOCKS space id 171page no 3n bits 72 index PRIMARY of table `dahaizi`` trx id 30478 lock_mode X locks rec but not gapRecord lock, heap no 3 PHYSICAL RECORD: n_fields 5 Compact format; info bits 00: len 4; hex 80000003; asc; 1: len 6; hex 0000007517; asc u; 2: len 7; hex 80000001d0011d; asc; 3: len 10; hex 7ae8afb8e8919be4baae; asc z; 4: len 3; hex e89c80; asc; * * (2) WAITING FOR THIS LOCK TO BE GRANTED:RECORD LOCKS space id 171 page no 3n bits 72 index PRIMARY of table `dahaizi`.`room`trx id 30478 lock_mode X locks rec but not gap waitingRecord lock, heap no 2 PHYSICAL RECORD: n_fields 5; compact format Info bits 00: len 4; hex 80000001; asc; 1: len 6; hex 0000007517; asc u; 2: len 7; hex 80000001d00110; asc; 3: len 7; hex 6ce58898e5a487; asc l; 4: len 3; hex e89c80; asc; * * WE ROLL BACK TRANSACTION (2) -. Omitted a lot of other information.

We are only concerned with the recent deadlock information, so we will put forward the LATEST DETECTED DEADLOCK section separately for analysis. Let's take a look at the deadlock log of this output line by line:

First of all, look at the first sentence:

2019-06-20 13:39:19 0x70000697e000

The deadlock occurred at 13:39:19 on 2019-06-20, followed by a string of hexadecimal 0x70000697e000 indicating the thread id of the thread assigned by the operating system to the current session.

Then there is information about the first transaction when the deadlock occurs:

* * (1) TRANSACTION:# assigns an id of 30477 to the transaction, and the transaction has been in the ACTIVE state for 10 seconds. What the transaction is doing now is: "starting index read" TRANSACTION 30477, ACTIVE 10 sec starting index read#. This transaction uses a table and locks a table. (this is not to say that a table lock is added to the table. As long as it is not a consistent read table, it needs to be locked. For more information on how to lock, please see locking statement analysis or booklet section) mysql tables in use 1, locked transaction is in LOCK WAIT state, with 3 lock structures (2 row lock structure, 1 table-level X-type intention lock structure, lock structure is highlighted in the booklet), heap size is the memory size applied for storing lock structure (we can ignore it) There are 2 row locks in the structure LOCK WAIT 3 lock struct (s), heap size 1160, 2 row lock (s) # the id of the thread is 2 (the thread id named by MySQL itself), the id of the thread at the operating system level is that long string of numbers, and the id of the current query is 46 (internal use of MySQL, can be ignored) There are also username host information MySQL thread id 2, OS thread handle 123145412648960, query id 46 localhost 127.0.0.1 root statistics# statement blocking this transaction select * from hero where id = 3 for update# the lock that this transaction is currently waiting to acquire: * * (1) WAITING FOR THIS LOCK TO BE GRANTED:# is waiting to acquire the tablespace ID is 151and the page number is 3 That is, the lock of a record in the PRIMAY index of table hero (n_bits is a string of memory allocated to store the lock information of this page, which is described in detail in the booklet). The type of lock is X-type formal record lock (rec but not gap) RECORD LOCKS space id 171page no 3 n bits 72 index PRIMARY of table `dahaizi`.`room` trx id 30477 lock_mode X locks rec but not gap waiting# the heap_no recorded on the page is 2. The specific recording information is as follows: Record lock, heap no 3 PHYSICAL RECORD: n_fields 5 Compact format; info bits keys this is the primary key value 0: len 4; hex 80000003; asc;; # this is trx_id hidden column 1: len 6; hex 0000007517; asc u;; # this is roll_pointer hidden column 2: len 7; hex 80000001d0011d; asc;; # this is name column 3: len 10; hex 7ae8afb8e8919be4baae; asc z; # this is country column 4: len 3; hex e89c80; asc

As you can see from this information, the transaction in Session A generated a lock structure for two records, but the X-type formal record lock (rec but not gap) on one of the records was not acquired, and the location of the record that did not acquire the lock was: the tablespace ID is 151and the page number is 3. Of course, the uncle who designed InnoDB also gave the details of this record, its primary key value is 80000003, which is actually the format used by InnoDB internal storage, which actually represents the number 3, that is, the transaction is waiting to obtain the X-type formal record lock of the record whose hero table cluster index primary key value is 3.

Then there is information about the second transaction when the deadlock occurs:

We have already introduced most of the information, so we pick the important ones and say:

* * (2) TRANSACTION:TRANSACTION 30478, ACTIVE 8 sec starting index readmysql tables in use 1, locked 13 lock struct (s), heap size 1160, 2 row lock (s) MySQL thread id 3, OS thread handle 123145412927488 Query id 47 localhost 127.0.0.1 root statisticsselect * from hero where id = 1 for update# indicates the lock information acquired by the transaction * * (2) HOLDS THE LOCK (S): RECORD LOCKS space id 171page no 3n bits 72 index PRIMARY of table `dahaizi`.`room`trx id 30478 lock_mode X locks rec but not gapRecord lock, heap no 3 PHYSICAL RECORD: n_fields 5 The primary key value of compact format; info bits keys is 30: len 4; hex 80000003; asc;; 1: len 6; hex 0000007517; asc u; 2: len 7; hex 80000001d0011d; asc;; 3: len 10; hex 7ae8afb8e8919be4baae; asc z; 4: len 3; hex e89c80; asc # indicates the lock information that the transaction is waiting to acquire * (2) WAITING FOR THIS LOCK TO BE GRANTED:RECORD LOCKS space id 171st page no 3 n bits 72 index PRIMARY of table `dahaizi`.`room` trx id 30478 lock_mode X locks rec but not gap waitingRecord lock, heap no 2 PHYSICAL RECORD: n_fields 5; compact format; info bits key value is 10: len 4; hex 80000001; asc;; 1: len 6; hex 0000007517; asc u; 2: len 7; hex 80000001d00110; asc; 3: len 7; hex 6ce58898e5a487 Asc l;; 4: len 3; hex e89c80; asc

As can be seen from the above output, the transaction in Session B acquires the type X normal record lock of the record with the hero table clustering index primary key value 3, and waits for the type X normal record lock of the record with the hero table cluster index primary key value 1 (the implication is that the type X normal record lock of the record with the hero table clustering index primary key value 1 has been acquired by the transaction in SESSION A).

Look at the last part:

* WE ROLL BACK TRANSACTION (2)

In the end, the InnoDB storage engine decided to roll back the second transaction, the transaction in Session B.

The thought of deadlock Analysis

1. When viewing the deadlock log, first take a look at the deadlock transaction waiting for the lock to be acquired.

In this example, the statement that SESSION An is found to be blocked is:

Select * from hero where id = 3 for update

The statements blocked by SESSION B are:

Select * from hero where id = 1 for update

Then remember: go to your business code to find out the other statements of the transaction in which these two statements are located.

2. After finding all the statements in the transaction in which the deadlock occurred, the deadlock occurrence process is analyzed against the information of the lock acquired by the transaction and the lock that is waiting.

As you can see from the deadlock log, SESSION An acquires the type X normal record lock of the record whose hero clustering index id value is 1 (this is actually acquired from the lock that SESSION B is waiting for), looks at the statement in SESSION A, and finds that it is caused by the following statement (analyzing the three articles against the statement locking):

Select * from hero where id = 1 for update

And SESSION B acquires the X-type normal record lock of the record whose hero clustering index id value is 3, looks at the statement in SESSION B, and finds that it is caused by the following statement (analyzing the three articles against the statement locking):

Select * from hero where id = 3 for update

Then look at SESSION A waiting for an X-type normal record lock for a record with a clustered index id value of 3 in the hero table, which is caused by the following statement:

Select * from hero where id = 3 for update

Then look at SESSION B waiting for an X-type normal record lock for a record with a clustered index id of 1 in the hero table, which is caused by the following statement:

Select * from hero where id = 1 for update

Then the whole deadlock formation process is restored according to the deadlock log.

Summary

The above is the whole content of this article. I hope the content of this article has a certain reference and learning value for everyone's study or work. Thank you for your support.

Welcome to subscribe "Shulou Technology Information " to get latest news, interesting things and hot topics in the IT industry, and controls the hottest and latest Internet news, technology news and IT industry trends.