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:
None 
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
Description:
transaction_isolation is READ-COMMITTED,the query using a full table scan does not unlock the lock on the unmatched record which was held after a lock conflict.

How to repeat:
1.transaction_isolation is READ-COMMITTED;
2.create table t1(a int primary key, b char(10));
3.insert into t1 values(1,'aaaa1'),(2,'aaaa2'),(3,'aaaa3'),(4,'aaaa4');
4.
session1:
start transaction;
select * from t1 where a=2 for update;

session2:
select * from t2 where b='xxxx' for update;

while session2 is hung, commit or rollback the transaction in session1 immediately.

5.The transaction in session2 holds the X-lock on the primary key where a=2 and does not unlock it until the transaction is committed or rollbacked.

 mysql> select * from performance_schema.data_locks\G
*************************** 1. row ***************************
               ENGINE: INNODB
       ENGINE_LOCK_ID: 140123712396696:1067:140123643654944
ENGINE_TRANSACTION_ID: 8362
            THREAD_ID: 397807
             EVENT_ID: 42
        OBJECT_SCHEMA: zcdb
          OBJECT_NAME: t1
       PARTITION_NAME: NULL
    SUBPARTITION_NAME: NULL
           INDEX_NAME: NULL
OBJECT_INSTANCE_BEGIN: 140123643654944
            LOCK_TYPE: TABLE
            LOCK_MODE: IX
          LOCK_STATUS: GRANTED
            LOCK_DATA: NULL
*************************** 2. row ***************************
               ENGINE: INNODB
       ENGINE_LOCK_ID: 140123712396696:8:4:3:140123643652376
ENGINE_TRANSACTION_ID: 8362
            THREAD_ID: 397807
             EVENT_ID: 42
        OBJECT_SCHEMA: zcdb
          OBJECT_NAME: t1
       PARTITION_NAME: NULL
    SUBPARTITION_NAME: NULL
           INDEX_NAME: PRIMARY
OBJECT_INSTANCE_BEGIN: 140123643652376
            LOCK_TYPE: RECORD
            LOCK_MODE: X,REC_NOT_GAP
          LOCK_STATUS: GRANTED
            LOCK_DATA: 2
2 rows in set (0.00 sec)
[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.