Record a troubleshooting of RR and RC deadlock

Keywords: MySQL

Record the deadlock problems and solutions encountered in the development process

The first is the isolation level. mysql has four isolation levels, from loose to strict

  • Read uncommitted         Read Uncommitted
  • Read commit             Read Committed     (isolation level used in online environment)
  • Repeatable reading         Repeatable Read   (Mysql default isolation level)
  • Serialization             Serializable

 

First deadlock

Background: when there is no record in db, concurrent insertion will cause deadlock

The first is the deadlock problem encountered for the first time,   By command

show engine innodb status

View the deadlock log as follows:

 

=====================================
2021-11-15 14:45:15 0x70000908f000 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 53 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 436 srv_active, 0 srv_shutdown, 136216 srv_idle
srv_master_thread log flush and writes: 0
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 14531
OS WAIT ARRAY INFO: signal count 12688
RW-shared spins 0, rounds 0, OS waits 0
RW-excl spins 0, rounds 0, OS waits 0
RW-sx spins 0, rounds 0, OS waits 0
Spin rounds per wait: 0.00 RW-shared, 0.00 RW-excl, 0.00 RW-sx
------------------------
LATEST DETECTED DEADLOCK
------------------------
2021-11-15 14:37:11 0x700004455000
*** (1) TRANSACTION:
TRANSACTION 47513, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1128, 1 row lock(s), undo log entries 1
MySQL thread id 26344, OS thread handle 123145497554944, query id 441640 localhost 127.0.0.1 root update
INSERT IGNORE INTO `wms_product` (`app_id`,`wms_warehouse_id`,`sku_id`,`amount`,`period_amount`,`trans_amount`,`version`,`update_time`,`create_time`) VALUES (2,1,'C-allocation',1,0,0,1,'2021-11-15 14:37:11.698119','2021-11-15 14:37:11.698119')

*** (1) HOLDS THE LOCK(S):
RECORD LOCKS space id 179 page no 5 n bits 72 index uk_skuid_wmsid_appid of table `wms`.`wms_product` trx id 47513 lock mode S waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 8; hex 432de8b083e68ba8; asc C-      ;;
 1: len 8; hex 8000000000000001; asc         ;;
 2: len 4; hex 80000002; asc     ;;
 3: len 8; hex 8000000000000056; asc        V;;


*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 179 page no 5 n bits 72 index uk_skuid_wmsid_appid of table `wms`.`wms_product` trx id 47513 lock mode S waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 8; hex 432de8b083e68ba8; asc C-      ;;
 1: len 8; hex 8000000000000001; asc         ;;
 2: len 4; hex 80000002; asc     ;;
 3: len 8; hex 8000000000000056; asc        V;;


*** (2) TRANSACTION:
TRANSACTION 47503, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 24 lock struct(s), heap size 3488, 21 row lock(s), undo log entries 4
MySQL thread id 26392, OS thread handle 123145430462464, query id 441871 localhost 127.0.0.1 root update
INSERT IGNORE INTO `wms_product` (`app_id`,`wms_warehouse_id`,`sku_id`,`amount`,`period_amount`,`trans_amount`,`version`,`update_time`,`create_time`) VALUES (2,1,'B Concurrent warehousing',1,0,0,1,'2021-11-15 14:37:11.682939','2021-11-15 14:37:11.682939')

*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 179 page no 5 n bits 72 index uk_skuid_wmsid_appid of table `wms`.`wms_product` trx id 47503 lock_mode X locks rec but not gap
Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 8; hex 432de8b083e68ba8; asc C-      ;;
 1: len 8; hex 8000000000000001; asc         ;;
 2: len 4; hex 80000002; asc     ;;
 3: len 8; hex 8000000000000056; asc        V;;


*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 179 page no 5 n bits 72 index uk_skuid_wmsid_appid of table `wms`.`wms_product` trx id 47503 lock_mode X locks gap before rec insert intention waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 8; hex 432de8b083e68ba8; asc C-      ;;
 1: len 8; hex 8000000000000001; asc         ;;
 2: len 4; hex 80000002; asc     ;;
 3: len 8; hex 8000000000000056; asc        V;;

*** WE ROLL BACK TRANSACTION (1)
------------
TRANSACTIONS
------------
Trx id counter 47828
Purge done for trx's n:o < 47828 undo n:o < 0 state: running but idle
History list length 0
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 281479673057184, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 281479673056392, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 281479673055600, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 281479673054808, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: waiting for i/o request (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (read thread)
I/O thread 4 state: waiting for i/o request (read thread)
I/O thread 5 state: waiting for i/o request (read thread)
I/O thread 6 state: waiting for i/o request (write thread)
I/O thread 7 state: waiting for i/o request (write thread)
I/O thread 8 state: waiting for i/o request (write thread)
I/O thread 9 state: waiting for i/o request (write thread)
Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
 ibuf aio reads:, log i/o's:, sync i/o's:
Pending flushes (fsync) log: 0; buffer pool: 2
1644 OS file reads, 161796 OS file writes, 113308 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 5.41 writes/s, 2.28 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2, 0 merges
merged operations:
 insert 0, delete mark 0, delete 0
discarded operations:
 insert 0, delete mark 0, delete 0
Hash table size 34679, node heap has 1 buffer(s)
Hash table size 34679, node heap has 1 buffer(s)
Hash table size 34679, node heap has 1 buffer(s)
Hash table size 34679, node heap has 2 buffer(s)
Hash table size 34679, node heap has 2 buffer(s)
Hash table size 34679, node heap has 2 buffer(s)
Hash table size 34679, node heap has 2 buffer(s)
Hash table size 34679, node heap has 5 buffer(s)
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number          56679186
Log buffer assigned up to    56679186
Log buffer completed up to   56679186
Log written up to            56679186
Log flushed up to            56679186
Added dirty pages up to      56679186
Pages flushed up to          56679186
Last checkpoint at           56679186
86480 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 0
Dictionary memory allocated 504140
Buffer pool size   8191
Free buffers       5147
Database pages     3028
Old database pages 1097
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 668, not young 149
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1086, created 1943, written 58798
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 3028, unzip_LRU len: 0
I/O sum[229]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
Process ID=555, Main thread ID=0x7000048f0000 , state=sleeping
Number of rows inserted 21319, updated 39868, deleted 3791, read 180746
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
Number of system rows inserted 837, updated 3436, deleted 524, read 39358
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

 

 

You can see that it is for only one table ` WMS'. ` WMS_ Product ` deadlocks generated during insertion.

 

About in code   Table ` WMS'. ` WMS_ The operation diagram of product ` is

  1. Select * from wms_product for update     –- Try locking
  2. Insert xxx   (insert a record without query)

 

reason:   In the local environment, the isolation level is the default RR   (special reminder: modifying the isolation level directly through mysql command will not take effect / it only takes effect for the current session. You need to modify the configuration file and restart)

At the RR level, mysql is the solution   Unreal reading   Gap lock is introduced   The gap lock locks not one row of records, but the gap between rows (the so-called phantom reading means that when the same range is queried twice in a transaction, the latter query sees records that were not seen in the previous query   The reason is that the S or X lock can only lock existing rows and cannot prevent others from inserting)

The gap lock and the gap lock are not mutually exclusive, and the gap lock is only mutually exclusive with the insertion operation

After understanding the above gap lock, it is easy to understand the cause of deadlock. Simply draw the following sequence diagram:

time
Session1
Session2
remarks
T1 Get Gap lock Get Gap lock Obtain the gap lock at the same time, not mutually exclusive
T2 Insert xxx (wait for gap lock of Session2) Insert xxx (wait for gap lock of Session1) Wait for each other
T3     deadlock

 

remarks:   After discussion with Raytheon boss here, it should not be added to the next for update simply for this situation without considering the business, because the subsequent Insert or Update will have an X lock

 

 

Second deadlock

Background: when there is no record in db, concurrent insertion will cause deadlock

By modifying the configuration file and restarting, the local isolation level is successfully updated to RC, and there is no gap lock problem. However, there are also some changes in business. Product is introduced_ Batch no batch table. The two tables need to be updated at the same time

The deadlock log is as follows:

 

=====================================
2021-11-30 10:24:59 0x70000e150000 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 42 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 45 srv_active, 0 srv_shutdown, 129307 srv_idle
srv_master_thread log flush and writes: 0
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 592
OS WAIT ARRAY INFO: signal count 478
RW-shared spins 0, rounds 0, OS waits 0
RW-excl spins 0, rounds 0, OS waits 0
RW-sx spins 0, rounds 0, OS waits 0
Spin rounds per wait: 0.00 RW-shared, 0.00 RW-excl, 0.00 RW-sx
------------------------
LATEST DETECTED DEADLOCK
------------------------
2021-11-30 10:24:32 0x70000cdf6000
*** (1) TRANSACTION:
TRANSACTION 59401, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 5 lock struct(s), heap size 1128, 3 row lock(s), undo log entries 2
MySQL thread id 328, OS thread handle 123145563062272, query id 8008 localhost 127.0.0.1 root update
INSERT INTO `wms_product_batchno` (`app_id`,`wms_warehouse_id`,`sku_id`,`batch_no`,`amount`,`period_amount`,`expire_time`,`update_time`,`create_time`) VALUES (2,1,'C-allocation','C11234124124129999999',1,0,'2021-12-10 10:24:32','2021-11-30 10:24:32.471672','2021-11-30 10:24:32.471672')

*** (1) HOLDS THE LOCK(S):
RECORD LOCKS space id 307 page no 5 n bits 72 index uk_skuid_wmsid_appid of table `wms`.`wms_product` trx id 59401 lock_mode X locks rec but not gap
Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 8; hex 432de8b083e68ba8; asc C-      ;;
 1: len 8; hex 8000000000000001; asc         ;;
 2: len 4; hex 80000002; asc     ;;
 3: len 8; hex 8000000000000001; asc         ;;


*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 305 page no 5 n bits 72 index uk_skuid_wmsid_app_id_batchno of table `wms`.`wms_product_batchno` trx id 59401 lock mode S waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
 0: len 8; hex 432de8b083e68ba8; asc C-      ;;
 1: len 8; hex 8000000000000001; asc         ;;
 2: len 4; hex 80000002; asc     ;;
 3: len 21; hex 433131323334313234313234313239393939393939; asc C11234124124129999999;;
 4: len 8; hex 8000000000000001; asc         ;;


*** (2) TRANSACTION:
TRANSACTION 59467, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 5 lock struct(s), heap size 1128, 3 row lock(s)
MySQL thread id 390, OS thread handle 123145633349632, query id 8233 localhost 127.0.0.1 root statistics
SELECT * FROM `wms_product` WHERE app_id = 2 and sku_id = 'C-allocation' and wms_warehouse_id = 1 FOR UPDATE

*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 305 page no 5 n bits 72 index uk_skuid_wmsid_app_id_batchno of table `wms`.`wms_product_batchno` trx id 59467 lock_mode X locks rec but not gap
Record lock, heap no 2 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
 0: len 8; hex 432de8b083e68ba8; asc C-      ;;
 1: len 8; hex 8000000000000001; asc         ;;
 2: len 4; hex 80000002; asc     ;;
 3: len 21; hex 433131323334313234313234313239393939393939; asc C11234124124129999999;;
 4: len 8; hex 8000000000000001; asc         ;;


*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 307 page no 5 n bits 72 index uk_skuid_wmsid_appid of table `wms`.`wms_product` trx id 59467 lock_mode X locks rec but not gap waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 8; hex 432de8b083e68ba8; asc C-      ;;
 1: len 8; hex 8000000000000001; asc         ;;
 2: len 4; hex 80000002; asc     ;;
 3: len 8; hex 8000000000000001; asc         ;;

*** WE ROLL BACK TRANSACTION (2)
------------
TRANSACTIONS
------------
Trx id counter 59502
Purge done for trx's n:o < 59502 undo n:o < 0 state: running but idle
History list length 15
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 281479685464760, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 281479685463968, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 281479685463176, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 281479685462384, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 281479685461592, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: waiting for i/o request (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (read thread)
I/O thread 4 state: waiting for i/o request (read thread)
I/O thread 5 state: waiting for i/o request (read thread)
I/O thread 6 state: waiting for i/o request (write thread)
I/O thread 7 state: waiting for i/o request (write thread)
I/O thread 8 state: waiting for i/o request (write thread)
I/O thread 9 state: waiting for i/o request (write thread)
Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
 ibuf aio reads:, log i/o's:, sync i/o's:
Pending flushes (fsync) log: 0; buffer pool: 0
2294 OS file reads, 6630 OS file writes, 4541 OS fsyncs
0.02 reads/s, 16384 avg bytes/read, 12.31 writes/s, 6.83 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2, 0 merges
merged operations:
 insert 0, delete mark 0, delete 0
discarded operations:
 insert 0, delete mark 0, delete 0
Hash table size 34679, node heap has 1 buffer(s)
Hash table size 34679, node heap has 1 buffer(s)
Hash table size 34679, node heap has 1 buffer(s)
Hash table size 34679, node heap has 1 buffer(s)
Hash table size 34679, node heap has 1 buffer(s)
Hash table size 34679, node heap has 1 buffer(s)
Hash table size 34679, node heap has 2 buffer(s)
Hash table size 34679, node heap has 4 buffer(s)
4.60 hash searches/s, 31.50 non-hash searches/s
---
LOG
---
Log sequence number          66935527
Log buffer assigned up to    66935527
Log buffer completed up to   66935527
Log written up to            66935527
Log flushed up to            66935527
Added dirty pages up to      66935527
Pages flushed up to          66935527
Last checkpoint at           66935527
2437 log i/o's done, 3.10 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 0
Dictionary memory allocated 451775
Buffer pool size   8192
Free buffers       6001
Database pages     2179
Old database pages 785
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1728, created 451, written 3091
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 2179, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
Process ID=581, Main thread ID=0x70000d291000 , state=sleeping
Number of rows inserted 267, updated 445, deleted 0, read 1668
0.17 inserts/s, 0.69 updates/s, 0.00 deletes/s, 4.90 reads/s
Number of system rows inserted 152, updated 1836, deleted 76, read 14284
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 7.69 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

 

 

 

The operation sequence for the two tables in the code is as follows

  1. Select * from productBatchNo   for update             // Also try locking
  2. Select * from product for update                            // Also try locking
  3. Update productBatchNo and product
  4. Commit

 

The details are as follows:

Note that all operations in the following table occur at time t1

operation
Session1
Session2
Session3
remarks
Query ProdcutBatchNo and lock it   Completed, but not locked because there is no record in db Completed,   However, because there is no record in db, it is not locked Not started For Session2, because Session1 is not submitted, Session2 cannot see the data at the RC level because it is not locked
Query the Product and lock it   Completed, but not locked because there is no record in db Ready to execute    
Update logic (BatchNo and Product) Completed      
Commit transaction commit Not submitted      

 

After entering t2 time:

operation
Session1
Session2
Session3
remarks
operation
Session1
Session2
Session3
remarks
Query ProdcutBatchNo and lock it   Completed, but not locked because there is no record in db Completed,   However, because there is no record in db, it is not locked There are records in db, and the X lock is applied to the Product  
Query the Product and lock it   Completed, but not locked because there is no record in db There are records in db, and the X lock is applied to the product Ready to execute  
Update logic (BatchNo and Product) Completed Ready to execute    
Commit transaction commit Successfully submitted      

 

After entering t3 time

operation
Session1
Session2
Session3
remarks
Query ProdcutBatchNo and lock it   Completed, but not locked because there is no record in db Completed,   However, because there is no record in db, it is not locked There are records in db, and the X lock is applied to the Product  
Query the Product and lock it   Completed, but not locked because there is no record in db There are records in db, and the X lock is applied to the product Since Prodct is X locked by Session2, it is waiting to be released  
Update logic (BatchNo and Product) Completed Ready to execute. Because the BatchNo is locked by Session3, it is waiting to be released    
Commit transaction commit Successfully submitted     Session2 and Session3 wait for each other and deadlock

The root cause is that records that do not exist cannot be locked

Solution:

After querying ProductBatchNo or Product, judge whether there are records in the DB. If there are no records in the DB, directly end the transaction. And insert the corresponding empty record into the DB. (key information such as Sku_ID, BatchNo, etc. has value, and the commodity quantity is 0)

In this way, the influence of nonexistent rows is eliminated, so that in subsequent update operations, once a Session gets the lock, it will directly block other sessions

 

reference material:

https://www.cnblogs.com/paul8339/p/6877729.html

Posted by Remote4ever on Sun, 05 Dec 2021 05:22:04 -0800