Bug #101371 | The transaction does not unlock the record lock on the unmatched record | ||
---|---|---|---|
Submitted: | 29 Oct 2020 9:33 | Modified: | 2 Nov 2020 13:12 |
Reporter: | Cheng Zhou | Email Updates: | |
Status: | Not a Bug | Impact on me: | |
Category: | MySQL Server: InnoDB storage engine | Severity: | S3 (Non-critical) |
Version: | 8.0 | OS: | Any |
Assigned to: | CPU Architecture: | Any |
[29 Oct 2020 9:33]
Cheng Zhou
[29 Oct 2020 11:34]
Cheng Zhou
Correction for [How to repeat]: Step 4: session1: start transaction; select * from t1 where a=2 for update; session2: select * from t1 where b='xxxx' for update; while session2 is hung, commit or rollback the transaction in session1 immediately.
[29 Oct 2020 12:08]
MySQL Verification Team
Hi Mr. Zhou, Thank you for your bug report. However, we need more info on the problem that you report. We need to see exactly which record is locked. It could be supermum or infimum. This info is available through InnoDB status output. We are waiting on your feedback.
[29 Oct 2020 12:52]
Cheng Zhou
The file for the whole output of 'show engine innodb status' is uploaded. ===================================== 2020-10-29 20:40:56 0x7f710f8ba700 INNODB MONITOR OUTPUT ===================================== Per second averages calculated from the last 60 seconds ----------------- BACKGROUND THREAD ----------------- srv_master_thread loops: 21558 srv_active, 0 srv_shutdown, 280863 srv_idle srv_master_thread log flush and writes: 0 ---------- SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 4408300 OS WAIT ARRAY INFO: signal count 4255442 RW-shared spins 2972038, rounds 4955432, OS waits 2006597 RW-excl spins 8392, rounds 2605179, OS waits 2297226 RW-sx spins 542, rounds 15861, OS waits 517 Spin rounds per wait: 1.67 RW-shared, 310.44 RW-excl, 29.26 RW-sx ------------ TRANSACTIONS ------------ Trx id counter 8390 Purge done for trx's n:o < 8388 undo n:o < 0 state: running but idle History list length 0 LIST OF TRANSACTIONS FOR EACH SESSION: ---TRANSACTION 421598689108208, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421598689106496, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421598689105640, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 8389, ACTIVE 35 sec 3 lock struct(s), heap size 1136, 1 row lock(s) MySQL thread id 26, OS thread handle 140123243734784, query id 608548883 localhost root
[29 Oct 2020 13:07]
MySQL Verification Team
Hi Mr. Zhou, Thank you for your feedback. However, we can not analyse what you report. First, you have to include locks in your innodb status, for which you can configure the server. Second, you have not uploaded anything into the "Files" tab. Can't repeat.
[29 Oct 2020 13:49]
Cheng Zhou
I mean, in this case I report, the result set of the query is empty: mysql> select * from t1 where b='xxxx' for update; Empty set (1.98 sec) But this transaction holds the record lock where a=2 and doesn't unlock it until the transaction is committed or rollbacked. This record lock should be unlocked once the transaction checks out the record is unmatched.
[29 Oct 2020 13:50]
Cheng Zhou
mysql> show engine innodb status\G *************************** 1. row *************************** Type: InnoDB Name: Status: ===================================== 2020-10-29 20:17:33 0x7f70fc2ae700 INNODB MONITOR OUTPUT ===================================== Per second averages calculated from the last 31 seconds ----------------- BACKGROUND THREAD ----------------- srv_master_thread loops: 21558 srv_active, 0 srv_shutdown, 279460 srv_idle srv_master_thread log flush and writes: 0 ---------- SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 4408300 OS WAIT ARRAY INFO: signal count 4255442 RW-shared spins 2972038, rounds 4955432, OS waits 2006597 RW-excl spins 8392, rounds 2605179, OS waits 2297226 RW-sx spins 542, rounds 15861, OS waits 517 Spin rounds per wait: 1.67 RW-shared, 310.44 RW-excl, 29.26 RW-sx ------------ TRANSACTIONS ------------ Trx id counter 8388 Purge done for trx's n:o < 8388 undo n:o < 0 state: running but idle History list length 0 LIST OF TRANSACTIONS FOR EACH SESSION: ---TRANSACTION 421598689108208, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421598689106496, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421598689105640, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 8362, ACTIVE 10835 sec 3 lock struct(s), heap size 1136, 1 row lock(s) MySQL thread id 26, OS thread handle 140123243734784, query id 608548877 localhost root starting show engine innodb status -------- FILE I/O -------- I/O thread 0 state: waiting for completed aio requests (insert buffer thread) I/O thread 1 state: waiting for completed aio requests (log thread) I/O thread 2 state: waiting for completed aio requests (read thread) I/O thread 3 state: waiting for completed aio requests (read thread) I/O thread 4 state: waiting for completed aio requests (read thread) I/O thread 5 state: waiting for completed aio requests (read thread) I/O thread 6 state: waiting for completed aio requests (read thread) I/O thread 7 state: waiting for completed aio requests (read thread) I/O thread 8 state: waiting for completed aio requests (read thread) I/O thread 9 state: waiting for completed aio requests (read thread) I/O thread 10 state: waiting for completed aio requests (read thread) I/O thread 11 state: waiting for completed aio requests (read thread) I/O thread 12 state: waiting for completed aio requests (read thread) I/O thread 13 state: waiting for completed aio requests (read thread) I/O thread 14 state: waiting for completed aio requests (read thread) I/O thread 15 state: waiting for completed aio requests (read thread) I/O thread 16 state: waiting for completed aio requests (read thread) I/O thread 17 state: waiting for completed aio requests (read thread) I/O thread 18 state: waiting for completed aio requests (write thread) I/O thread 19 state: waiting for completed aio requests (write thread) I/O thread 20 state: waiting for completed aio requests (write thread) I/O thread 21 state: waiting for completed aio requests (write thread) I/O thread 22 state: waiting for completed aio requests (write thread) I/O thread 23 state: waiting for completed aio requests (write thread) I/O thread 24 state: waiting for completed aio requests (write thread) I/O thread 25 state: waiting for completed aio requests (write thread) I/O thread 26 state: waiting for completed aio requests (write thread) I/O thread 27 state: waiting for completed aio requests (write thread) I/O thread 28 state: waiting for completed aio requests (write thread) I/O thread 29 state: waiting for completed aio requests (write thread) I/O thread 30 state: waiting for completed aio requests (write thread) I/O thread 31 state: waiting for completed aio requests (write thread) I/O thread 32 state: waiting for completed aio requests (write thread) I/O thread 33 state: waiting for completed aio requests (write thread) Pending normal aio reads: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] , aio writes: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] , ibuf aio reads:, log i/o's:, sync i/o's: Pending flushes (fsync) log: 0; buffer pool: 143 1343872 OS file reads, 77108448 OS file writes, 31906572 OS fsyncs 0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
[29 Oct 2020 13:50]
Cheng Zhou
------------------------------------- INSERT BUFFER AND ADAPTIVE HASH INDEX ------------------------------------- Ibuf: size 1, free list len 3195, seg size 3197, 0 merges merged operations: insert 0, delete mark 0, delete 0 discarded operations: insert 0, delete mark 0, delete 0 Hash table size 1106407, node heap has 0 buffer(s) Hash table size 1106407, node heap has 0 buffer(s) Hash table size 1106407, node heap has 0 buffer(s) Hash table size 1106407, node heap has 0 buffer(s) Hash table size 1106407, node heap has 0 buffer(s) Hash table size 1106407, node heap has 0 buffer(s) Hash table size 1106407, node heap has 0 buffer(s) Hash table size 1106407, node heap has 0 buffer(s) 0.00 hash searches/s, 0.00 non-hash searches/s --- LOG --- Log sequence number 173397305846 Log buffer assigned up to 173397305846 Log buffer completed up to 173397305846 Log written up to 173397305846 Log flushed up to 173397305846 Added dirty pages up to 173397305846 Pages flushed up to 173397305846 Last checkpoint at 173397305846 68377784 log i/o's done, 0.00 log i/o's/second ---------------------- BUFFER POOL AND MEMORY ---------------------- Total large memory allocated 4395630592 Dictionary memory allocated 468067 Buffer pool size 262139 Free buffers 8796 Database pages 253343 Old database pages 93385 Modified db pages 0 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages made young 1155906, not young 343651562 0.00 youngs/s, 0.00 non-youngs/s Pages read 1343845, created 636793, written 8135433 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: 253343, unzip_LRU len: 0 I/O sum[0]:cur[0], unzip sum[0]:cur[0] ---------------------- INDIVIDUAL BUFFER POOL INFO ---------------------- ---BUFFER POOL 0 Buffer pool size 32767 Free buffers 1113 Database pages 31654 Old database pages 11667 Modified db pages 0 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages made young 142170, not young 43436054 0.00 youngs/s, 0.00 non-youngs/s Pages read 168358, created 81724, written 1017379 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: 31654, unzip_LRU len: 0 I/O sum[0]:cur[0], unzip sum[0]:cur[0] ---BUFFER POOL 1 Buffer pool size 32768 Free buffers 1092 Database pages 31676 Old database pages 11682 Modified db pages 0 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages made young 142445, not young 43174557 0.00 youngs/s, 0.00 non-youngs/s Pages read 167446, created 80730, written 1009295 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: 31676, unzip_LRU len: 0 I/O sum[0]:cur[0], unzip sum[0]:cur[0] ---BUFFER POOL 2 Buffer pool size 32767 Free buffers 1083 Database pages 31684 Old database pages 11685 Modified db pages 0 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages made young 143112, not young 42942409 0.00 youngs/s, 0.00 non-youngs/s Pages read 167453, created 78525, written 1005821 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: 31684, unzip_LRU len: 0 I/O sum[0]:cur[0], unzip sum[0]:cur[0] ---BUFFER POOL 3 Buffer pool size 32767 Free buffers 1116 Database pages 31651 Old database pages 11663 Modified db pages 0 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages made young 144038, not young 43007645 0.00 youngs/s, 0.00 non-youngs/s Pages read 167645, created 78280, written 1060845 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: 31651, unzip_LRU len: 0 I/O sum[0]:cur[0], unzip sum[0]:cur[0] ---BUFFER POOL 4 Buffer pool size 32767 Free buffers 1110 Database pages 31657 Old database pages 11670 Modified db pages 0 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages made young 140961, not young 42653500 0.00 youngs/s, 0.00 non-youngs/s Pages read 166912, created 77796, written 1023609 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: 31657, unzip_LRU len: 0 I/O sum[0]:cur[0], unzip sum[0]:cur[0] ---BUFFER POOL 5 Buffer pool size 32767 Free buffers 1122 Database pages 31645 Old database pages 11662 Modified db pages 0 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages made young 139837, not young 42730134 0.00 youngs/s, 0.00 non-youngs/s Pages read 168494, created 80354, written 1018246 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: 31645, unzip_LRU len: 0 I/O sum[0]:cur[0], unzip sum[0]:cur[0] ---BUFFER POOL 6 Buffer pool size 32768 Free buffers 1083 Database pages 31685 Old database pages 11678 Modified db pages 0 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages made young 147428, not young 43391323 0.00 youngs/s, 0.00 non-youngs/s Pages read 170514, created 80602, written 997223 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: 31685, unzip_LRU len: 0 I/O sum[0]:cur[0], unzip sum[0]:cur[0] ---BUFFER POOL 7 Buffer pool size 32768 Free buffers 1077 Database pages 31691 Old database pages 11678 Modified db pages 0 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages made young 155915, not young 42315940 0.00 youngs/s, 0.00 non-youngs/s Pages read 167023, created 78782, written 1003015 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: 31691, 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=100260, Main thread ID=140115035645696 , state=sleeping Number of rows inserted 350002824, updated 0, deleted 0, read 350002840 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s Number of system rows inserted 90, updated 356, deleted 20, read 5033 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s ---------------------------- END OF INNODB MONITOR OUTPUT ============================ 1 row in set (0.12 sec)
[29 Oct 2020 13:51]
MySQL Verification Team
Hi Mr. Zhou, We were not able to repeat your report. Also, you did not provide us with info that we have already asked for.
[29 Oct 2020 13:53]
MySQL Verification Team
Hi Mr. Zhou, As you can see from your own output, no records are locked.
[31 Oct 2020 2:30]
Cheng Zhou
Sorry, I misunderstood what you asked for. But, in the output given above, there is ONE row lock. Here is the innodb status output: ------------ TRANSACTIONS ------------ Trx id counter 8422 Purge done for trx's n:o < 8414 undo n:o < 0 state: running but idle History list length 0 LIST OF TRANSACTIONS FOR EACH SESSION: ---TRANSACTION 421598689107352, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421598689106496, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421598689105640, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 8421, ACTIVE 806 sec 3 lock struct(s), heap size 1136, 1 row lock(s) MySQL thread id 30, OS thread handle 140123245479680, query id 608548955 localhost root TABLE LOCK table `zcdb`.`t1` trx id 8421 lock mode IX RECORD LOCKS space id 8 page no 4 n bits 72 index PRIMARY of table `zcdb`.`t1` trx id 8421 lock_mode X locks rec but not gap RECORD LOCKS space id 8 page no 4 n bits 72 index PRIMARY of table `zcdb`.`t1` trx id 8421 lock_mode X locks rec but not gap Record lock, heap no 3 PHYSICAL RECORD: n_fields 4; compact format; info bits 0 0: len 4; hex 80000002; asc ;; 1: len 6; hex 000000002090; asc ;; 2: len 7; hex 81000000f10110; asc ;; 3: len 10; hex 61616161322020202020; asc aaaa2 ;; --------
[2 Nov 2020 12:39]
MySQL Verification Team
Hi Mr. Zhou, Thank you for the output. It shows clearly that only a row with a value of column 'a' being 2 has been locked, which is expected behaviour. Not a bug.
[2 Nov 2020 13:12]
Cheng Zhou
Would you please be more specific? I don't quite understand why it is expected behaviour. The transaction in session1 has already been committed. The SQL in the transaction in session2 is "select * from t2 where b='xxxx' for update;", whose result set is empty. But it locks the row with a value of column 'a' being 2, which does not match the condition "b='xxxx'" in the where clause. The row lock does not been unlocked until the whole transaction is committed or rollbacked.