CDC should not send changes of un-captured key ranges

[overvenus]

Bug Report

CDC sends changes of un-captured key ranges. It has overheads for both TiCDC and TiKV, especially for TiKV when a changefeed enables old value. For example, when we start to load data by INSERT SQL, TiKV caches old value by region, so it may cache both row data and index data (which is not unnecessary to captured). In pessimistic txn, TiKV may not cache all indexes, it may lead to old value cache miss.

In the red box, the cache hit rate should be 100%.

This issue is found during the development of #10072

mysql> trace insert into `sbtest1` (`k` , `c` , `pad`, `id` ) values (2992017 , "31451373586-15688153734-79729593694-96509299839-83724898275-86711833539-78981337422-35049690573-51724173961-87474696253", "98996621624-36689827414-04092488557-09587706818-65008859162", 1000019);
+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------$--------+-------------+
| operation                                                                                                                                                                                 | startTS        | duration    |
+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------$--------+-------------+
| trace                                                                                                                                                                                     | 01:05:5$.204092 | 13.883489ms |
|   └─session.ExecuteStmt                                                                                                                                                                   | 01:05:5$.204098 | 13.86887ms  |
|     ├─executor.Compile                                                                                                                                                                    | 01:05:5$.204115 | 110.188µs   |
|     └─session.runStmt                                                                                                                                                                     | 01:05:5$.204260 | 13.663742ms |
|       ├─executor.handleNoDelayExecutor                                                                                                                                                    | 01:05:5$.204288 | 10.387744ms |
|       │ └─*executor.InsertExec.Next                                                                                                                                                       | 01:05:5$.204291 | 10.369615ms |
|       │   ├─table.AddRecord                                                                                                                                                               | 01:05:5$.214577 | 60.16µs     |
|       │   └─index.Create                                                                                                                                                                  | 01:05:5$.214616 | 2.527µs     |
|       ├─loadRegion                                                                                                                                                                        | 01:05:5$.214698 | 476.335µs   |
|       ├─loadRegion                                                                                                                                                                        | 01:05:52.215229 | 239.766µs   |
|       └─regionRequest.SendReqCtx # TiKV cache old values here                                                                                                                             | 01:05:52.215520 | 1.078863ms  |
|         ├─rpcClient.SendRequest, region ID: 126, type: PessimisticLock, mutations [PessimisticLock], key [7480000000000000335f6980000000000000010380000000000f42530380000000002da791]     | 01:05:52.215580 | 981.217µs   |
|         └─regionRequest.SendReqCtx # TiKV cache old values here                                                                                                                           | 01:05:52.216645 | 1.013009ms  |
|           └─rpcClient.SendRequest, region ID: 2, type: PessimisticLock, mutations [PessimisticLock], key [7480000000000000335f72800000000181b336]                                         | 01:05:52.216686 | 950.6µs     |
+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-----------------+-------------+
14 rows in set (0.02 sec)

mysql> trace commit;
+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+----------------+------------+
| operation                                                                                                                                                                           | startTS        | duration   |
+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+----------------+------------+
| trace                                                                                                                                                                               | 01:06:05.2746$6 | 3.602457ms |
|   └─session.ExecuteStmt                                                                                                                                                             | 01:06:05.2746$1 | 3.588645ms |
|     ├─executor.Compile                                                                                                                                                              | 01:06:05.2746$0 | 8.986µs    |
|     └─session.runStmt                                                                                                                                                               | 01:06:05.2746$5 | 3.493035ms |
|       ├─executor.handleNoDelayExecutor                                                                                                                                              | 01:06:05.2746$6 | 21.58µs    |
|       │ └─*executor.SimpleExec.Next                                                                                                                                                 | 01:06:05.274687 | 1.605µs    |
|       └─session.CommitTxn                                                                                                                                                           | 01:06:05.274712 | 3.39318ms  |
|         └─session.doCommitWitRetry                                                                                                                                                  | 01:06:05.274716 | 3.381367ms |
|           └─tikvTxn.Commit                                                                                                                                                          | 01:06:05.274723 | 3.349106ms |
|             └─twoPhaseCommitter.prewriteMutations                                                                                                                                   | 01:06:05.275236 | 2.80608ms  |
|               ├─loadRegion                                                                                                                                                          | 01:06:05.275246 | 386.527µs  |
|               ├─regionRequest.SendReqCtx                                                                                                                                            | 01:06:05.275746 | 2.274309ms |
|               │ └─rpcClient.SendRequest, region ID: 2, type: Prewrite, mutations [Put], key [7480000000000000335f72800000000181b336]                                                | 01:06:05.275800 | 2.195865ms |
|               ├─regionRequest.SendReqCtx                                                                                                                                            | 01:06:05.275747 | 2.141951ms |
|               │ └─rpcClient.SendRequest, region ID: 126, type: Prewrite, mutations [Insert], key [7480000000000000335f6980000000000000010380000000000f42530380000000002da791]       | 01:06:05.275801 | 2.063306ms |
|               └─regionRequest.SendReqCtx                                                                                                                                            | 01:06:05.275783 | 2.164292ms |
|                 └─rpcClient.SendRequest, region ID: 178, type: Prewrite, mutations [Put], key [7480000000000000335f6980000000000000020380000000002da79103800000000181b336]          | 01:06:05.275840 | 2.084568ms |
+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-----------------+------------+
17 rows in set (0.01 sec)

mysql> show create table sbtest1;
+---------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Table   | Create Table                                                                                                                                                                                                                                                                                                                                          |
+---------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| sbtest1 | CREATE TABLE `sbtest1` (
  `id` int(11) NOT NULL AUTO_INCREMENT,
  `k` int(11) NOT NULL DEFAULT '0',
  `c` char(120) NOT NULL DEFAULT '',
  `pad` char(60) NOT NULL DEFAULT '',
  PRIMARY KEY (`id`,`k`) /*T![clustered_index] NONCLUSTERED */,
  KEY `k_1` (`k`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_bin AUTO_INCREMENT=25307238 |
+---------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.01 sec)

What version of TiKV are you using?

TiKV 5.0.0

Steps to reproduce

# create a changefeed with old value enabled.
sysbench --db-driver=mysql --mysql-host=172.16.5.33 --mysql-port=47904 --mysql-user=root --time=15000 --report-interval=10 --threads=64 --mysql-db=test --tables=1 --table-size=6000000 oltp_write_only prepare && \
sleep 60 && sysbench --db-driver=mysql --mysql-host=172.16.5.33 --mysql-port=47904 --mysql-user=root --time=15000 --report-interval=10 --threads=64 --mysql-db=test --tables=1 --table-size=6000000 oltp_write_only run

What did you expect?

100% cache hit.

What did happened?

90% cache hit.

[overvenus]

@ben1009 Could you take a look?

[ben1009]

@ben1009 Could you take a look?

sure

[hi-rustin]

/unassign @hicqu

/assign