Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

IndexLookUp cost mismatches actual execution time compared with TableScan by clustered index #49901

Open
pcqz opened this issue Dec 29, 2023 · 9 comments
Labels
affects-8.1 found/gs found by gs report/customer Customers have encountered this bug. sig/planner SIG: Planner type/enhancement The issue or PR belongs to an enhancement. type/performance type/regression

Comments

@pcqz
Copy link

pcqz commented Dec 29, 2023

Bug Report

Please answer these questions before submitting your issue. Thanks!

1. Minimal reproduce step (Required)

(1) Create a sysbench table like this:

CREATE TABLE `sbtest1` (
  `id` int(10) unsigned NOT NULL AUTO_INCREMENT,
  `k` int(10) unsigned NOT NULL DEFAULT '0',
  `c` char(120) NOT NULL DEFAULT '',
  `pad` char(60) NOT NULL DEFAULT '',
  PRIMARY KEY (`id`, `k`) /*T![clustered_index] CLUSTERED */
);

(2) Run insert.sh to insert some rows.
(3) Execute the following sqls:

alter table sbtest1 add column id_1 int;
alter table sbtest1 add key(id_1);
update sbtest1 set id_1=id;
analyze table sbtest1;

(4) Compare the following plans:

explain analyze select * from sbtest1 where id=1 and id_1=1;
explain analyze select * from sbtest1 where id=1 and id_1=0;
explain analyze select * from sbtest1 use index(primary) where id=1 and id_1=1;
explain analyze select * from sbtest1 use index(primary) where id=1 and id_1=0;

2. What did you expect to see? (Required)

Execution plan uses clustered index.

mysql> explain format='verbose' select * from sbtest1 use index(primary) where id=1 and id_1=1;
+--------------------------+---------+---------+-----------+---------------+-------------------------------+
| id                       | estRows | estCost | task      | access object | operator info                 |
+--------------------------+---------+---------+-----------+---------------+-------------------------------+
| TableReader_7            | 0.00    | 24.95   | root      |               | data:Selection_6              |
| └─Selection_6            | 0.00    | 374.21  | cop[tikv] |               | eq(sbtest.sbtest1.id_1, 1)    |
|   └─TableRangeScan_5     | 1.01    | 323.71  | cop[tikv] | table:sbtest1 | range:[1,1], keep order:false |
+--------------------------+---------+---------+-----------+---------------+-------------------------------+
3 rows in set (0.00 sec)
mysql> explain analyze select * from sbtest1 use index(primary) where id=1 and id_1=1;
+--------------------------+---------+---------+-----------+---------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------+-----------+------+
| id                       | estRows | actRows | task      | access object | execution info                                                                                                                                                                                                                                    | operator info                 | memory    | disk |
+--------------------------+---------+---------+-----------+---------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------+-----------+------+
| TableReader_7            | 0.00    | 1       | root      |               | time:751.6µs, loops:2, RU:0.302888, cop_task: {num: 1, max: 651.8µs, proc_keys: 1, tot_proc: 148.1µs, tot_wait: 65.2µs, rpc_num: 1, rpc_time: 625.7µs, copr_cache_hit_ratio: 0.00, build_task_duration: 11.3µs, max_distsql_concurrency: 1}       | data:Selection_6              | 519 Bytes | N/A  |
| └─Selection_6            | 0.00    | 1       | cop[tikv] |               | tikv_task:{time:0s, loops:1}, scan_detail: {total_process_keys: 1, total_process_keys_size: 230, total_keys: 3, get_snapshot_time: 27.1µs, rocksdb: {key_skipped_count: 2, block: {cache_hit_count: 6}}}                                          | eq(sbtest.sbtest1.id_1, 1)    | N/A       | N/A  |
|   └─TableRangeScan_5     | 1.01    | 1       | cop[tikv] | table:sbtest1 | tikv_task:{time:0s, loops:1}                                                                                                                                                                                                                      | range:[1,1], keep order:false | N/A       | N/A  |
+--------------------------+---------+---------+-----------+---------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------+-----------+------+
3 rows in set (0.00 sec)
mysql> explain analyze select * from sbtest1 use index(primary) where id=1 and id_1=0;
+--------------------------+---------+---------+-----------+---------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------+-----------+------+
| id                       | estRows | actRows | task      | access object | execution info                                                                                                                                                                                                                                    | operator info                 | memory    | disk |
+--------------------------+---------+---------+-----------+---------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------+-----------+------+
| TableReader_7            | 0.00    | 0       | root      |               | time:742.4µs, loops:1, RU:0.301466, cop_task: {num: 1, max: 668.4µs, proc_keys: 1, tot_proc: 143.9µs, tot_wait: 68.9µs, rpc_num: 1, rpc_time: 642.6µs, copr_cache_hit_ratio: 0.00, build_task_duration: 9.59µs, max_distsql_concurrency: 1}       | data:Selection_6              | 238 Bytes | N/A  |
| └─Selection_6            | 0.00    | 0       | cop[tikv] |               | tikv_task:{time:0s, loops:1}, scan_detail: {total_process_keys: 1, total_process_keys_size: 230, total_keys: 3, get_snapshot_time: 27.7µs, rocksdb: {key_skipped_count: 2, block: {cache_hit_count: 6}}}                                          | eq(sbtest.sbtest1.id_1, 0)    | N/A       | N/A  |
|   └─TableRangeScan_5     | 1.01    | 1       | cop[tikv] | table:sbtest1 | tikv_task:{time:0s, loops:1}                                                                                                                                                                                                                      | range:[1,1], keep order:false | N/A       | N/A  |
+--------------------------+---------+---------+-----------+---------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------+-----------+------+
3 rows in set (0.00 sec)

3. What did you see instead (Required)

The plan uses IndexRangeScan and IndexLookUp.

mysql> explain format='verbose' select * from sbtest1 where id=1 and id_1=1;
+-------------------------------+---------+---------+-----------+---------------------------------+-------------------------------+
| id                            | estRows | estCost | task      | access object                   | operator info                 |
+-------------------------------+---------+---------+-----------+---------------------------------+-------------------------------+
| IndexLookUp_11                | 0.00    | 18.48   | root      |                                 |                               |
| ├─Selection_10(Build)         | 0.00    | 277.21  | cop[tikv] |                                 | eq(sbtest.sbtest1.id, 1)      |
| │ └─IndexRangeScan_8          | 1.00    | 227.31  | cop[tikv] | table:sbtest1, index:id_1(id_1) | range:[1,1], keep order:false |
| └─TableRowIDScan_9(Probe)     | 0.00    | 0.00    | cop[tikv] | table:sbtest1                   | keep order:false              |
+-------------------------------+---------+---------+-----------+---------------------------------+-------------------------------+
4 rows in set (0.00 sec)
mysql> explain analyze select * from sbtest where id=1 and id_1=1;
+-------------------------------+---------+---------+-----------+--------------------------------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------+---------+------+
| id                            | estRows | actRows | task      | access object                  | execution info                                                                                                                                                                                                                                                                                                                                                                                                                                                           | operator info                 | memory  | disk |
+-------------------------------+---------+---------+-----------+--------------------------------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------+---------+------+
| IndexLookUp_11                | 0.00    | 1       | root      |                                | time:1.5ms, loops:2, RU:0.657320, index_task: {total_time: 660.2µs, fetch_handle: 656.5µs, build: 882ns, wait: 2.86µs}, table_task: {total_time: 734.5µs, num: 1, concurrency: 5}, next: {wait_index: 741.1µs, wait_table_lookup_build: 59.3µs, wait_table_lookup_resp: 667.5µs}                                                                                                                                                                                         |                               | 63.0 KB | N/A  |
| ├─Selection_10(Build)         | 0.00    | 1       | cop[tikv] |                                | time:646.8µs, loops:3, cop_task: {num: 1, max: 574.6µs, proc_keys: 1, tot_proc: 117.9µs, tot_wait: 63.7µs, rpc_num: 1, rpc_time: 552.9µs, copr_cache_hit_ratio: 0.00, build_task_duration: 20.6µs, max_distsql_concurrency: 1}, tikv_task:{time:0s, loops:1}, scan_detail: {total_process_keys: 1, total_process_keys_size: 57, total_keys: 2, get_snapshot_time: 25.7µs, rocksdb: {key_skipped_count: 1, block: {cache_hit_count: 7}}}                                  | eq(sbtest.sbtest.id, 1)       | N/A     | N/A  |
| │ └─IndexRangeScan_8          | 1.01    | 1       | cop[tikv] | table:sbtest, index:id_1(id_1) | tikv_task:{time:0s, loops:1}                                                                                                                                                                                                                                                                                                                                                                                                                                             | range:[1,1], keep order:false | N/A     | N/A  |
| └─TableRowIDScan_9(Probe)     | 0.00    | 1       | cop[tikv] | table:sbtest                   | time:646.1µs, loops:2, cop_task: {num: 1, max: 569.6µs, proc_keys: 1, tot_proc: 172.5µs, tot_wait: 44.2µs, rpc_num: 1, rpc_time: 555.1µs, copr_cache_hit_ratio: 0.00, build_task_duration: 14µs, max_distsql_concurrency: 1, max_extra_concurrency: 1}, tikv_task:{time:0s, loops:1}, scan_detail: {total_process_keys: 1, total_process_keys_size: 3910, total_keys: 2, get_snapshot_time: 19.8µs, rocksdb: {key_skipped_count: 1, block: {cache_hit_count: 9}}}        | keep order:false              | N/A     | N/A  |
+-------------------------------+---------+---------+-----------+--------------------------------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------+---------+------+
4 rows in set (0.00 sec)

mysql> explain analyze select * from sbtest where id=1 and id_1=0;
+-------------------------------+---------+---------+-----------+--------------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------+-----------+------+
| id                            | estRows | actRows | task      | access object                  | execution info                                                                                                                                                                                                                                                                                                                                                       | operator info                 | memory    | disk |
+-------------------------------+---------+---------+-----------+--------------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------+-----------+------+
| IndexLookUp_11                | 0.00    | 0       | root      |                                | time:643µs, loops:1, RU:0.286461                                                                                                                                                                                                                                                                                                                                     |                               | 236 Bytes | N/A  |
| ├─Selection_10(Build)         | 0.00    | 0       | cop[tikv] |                                | time:558.2µs, loops:1, cop_task: {num: 1, max: 506.3µs, proc_keys: 0, tot_proc: 109.4µs, tot_wait: 59.7µs, rpc_num: 1, rpc_time: 491.3µs, copr_cache_hit_ratio: 0.00, build_task_duration: 11.8µs, max_distsql_concurrency: 1}, tikv_task:{time:0s, loops:1}, scan_detail: {total_keys: 1, get_snapshot_time: 23.9µs, rocksdb: {block: {cache_hit_count: 7}}}        | eq(sbtest.sbtest.id, 1)       | N/A       | N/A  |
| │ └─IndexRangeScan_8          | 1.01    | 0       | cop[tikv] | table:sbtest, index:id_1(id_1) | tikv_task:{time:0s, loops:1}                                                                                                                                                                                                                                                                                                                                         | range:[0,0], keep order:false | N/A       | N/A  |
| └─TableRowIDScan_9(Probe)     | 0.00    | 0       | cop[tikv] | table:sbtest                   |                                                                                                                                                                                                                                                                                                                                                                      | keep order:false              | N/A       | N/A  |
+-------------------------------+---------+---------+-----------+--------------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------+-----------+------+
4 rows in set (0.00 sec)

4. What is your TiDB version? (Required)

v7.1.2

@pcqz pcqz added the type/bug The issue is confirmed as a bug. label Dec 29, 2023
@jackysp jackysp added the found/gs found by gs label Jan 4, 2024
@kennedy8312
Copy link

/type regression

@kennedy8312
Copy link

/type performance

@kennedy8312
Copy link

Regression Analysis
PR caused this regression: #35240

@kennedy8312
Copy link

explain analyze select * from sbtest1 where id=1 and id_1=1;
explain analyze select * from sbtest1 where id=1 and id_1=0;
explain analyze select * from sbtest1 use index(primary) where id=1 and id_1=1;
explain analyze select * from sbtest1 use index(primary) where id=1 and id_1=0;

@kennedy8312
Copy link

kennedy8312 commented Jan 27, 2024

8b06ef2 seems to be the first commit causing the plan change.


mysql> select tidb_version();
+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| tidb_version() |
+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Release Version: v6.5.0-alpha-204-g8b06ef2727
Edition: Community
Git Commit Hash: 8b06ef2
Git Branch: HEAD
UTC Build Time: 2024-01-27 13:11:51
GoVersion: go1.21.4
Race Enabled: false
TiKV Min Version: 6.2.0-alpha
Check Table Before Drop: false
Store: unistore |

id estRows actRows task access object execution info operator info memory disk
IndexLookUp_11 0.00 1 root time:247.3µs, loops:2, index_task: {total_time: 104.3µs, fetch_handle: 103.9µs, build: 167ns, wait: 250ns}, table_task: {total_time: 114.9µs, num: 1, concurrency: 5} 19.5 KB N/A
├─Selection_10(Build) 0.00 1 cop[tikv] time:102.6µs, loops:3, cop_task: {num: 1, max: 82.5µs, proc_keys: 0, rpc_num: 1, rpc_time: 78.7µs, copr_cache_hit_ratio: 0.00, distsql_concurrency: 15}, tikv_task:{time:75.9µs, loops:0} eq(test.sbtest1.id, 1) N/A N/A
│ └─IndexRangeScan_8 1.00 1 cop[tikv] table:sbtest1, index:id_1(id_1) tikv_task:{time:75.9µs, loops:0} range:[1,1], keep order:false N/A N/A
└─TableRowIDScan_9(Probe) 0.00 1 cop[tikv] table:sbtest1 time:94.7µs, loops:2, cop_task: {num: 1, max: 65.5µs, proc_keys: 0, rpc_num: 1, rpc_time: 61.2µs, copr_cache_hit_ratio: 0.00, distsql_concurrency: 15}, tikv_task:{time:58.6µs, loops:0} keep order:false N/A N/A
id estRows actRows task access object execution info operator info memory disk
IndexLookUp_11 0.00 0 root time:130.2µs, loops:1 184 Bytes N/A
├─Selection_10(Build) 0.00 0 cop[tikv] time:104.5µs, loops:1, cop_task: {num: 1, max: 73.3µs, proc_keys: 0, rpc_num: 1, rpc_time: 69.3µs, copr_cache_hit_ratio: 0.00, distsql_concurrency: 15}, tikv_task:{time:66.8µs, loops:0} eq(test.sbtest1.id, 1) N/A N/A
│ └─IndexRangeScan_8 1.00 0 cop[tikv] table:sbtest1, index:id_1(id_1) tikv_task:{time:66.8µs, loops:0} range:[0,0], keep order:false N/A N/A
└─TableRowIDScan_9(Probe) 0.00 0 cop[tikv] table:sbtest1 keep order:false N/A N/A
id estRows actRows task access object execution info operator info memory disk
TableReader_7 0.00 1 root time:85.9µs, loops:2, cop_task: {num: 1, max: 71µs, proc_keys: 0, rpc_num: 1, rpc_time: 67.2µs, copr_cache_hit_ratio: 0.00, distsql_concurrency: 15} data:Selection_6 452 Bytes N/A
└─Selection_6 0.00 1 cop[tikv] tikv_task:{time:64µs, loops:0} eq(test.sbtest1.id_1, 1) N/A N/A
└─TableRangeScan_5 1.00 1 cop[tikv] table:sbtest1 tikv_task:{time:64µs, loops:0} range:[1,1], keep order:false N/A N/A
id estRows actRows task access object execution info operator info memory disk
TableReader_7 0.00 0 root time:91.2µs, loops:1, cop_task: {num: 1, max: 80.8µs, proc_keys: 0, rpc_num: 1, rpc_time: 76.3µs, copr_cache_hit_ratio: 0.00, distsql_concurrency: 15} data:Selection_6 176 Bytes N/A
└─Selection_6 0.00 0 cop[tikv] tikv_task:{time:73.4µs, loops:0} eq(test.sbtest1.id_1, 0) N/A N/A
└─TableRangeScan_5 1.00 1 cop[tikv] table:sbtest1 tikv_task:{time:73.4µs, loops:0} range:[1,1], keep order:false N/A N/A

@kennedy8312
Copy link

The -1 commit seems to be fine.


mysql> select tidb_version();
+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| tidb_version() |
+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Release Version: v6.5.0-alpha-203-gadcacd8d89
Edition: Community
Git Commit Hash: adcacd8
Git Branch: HEAD
UTC Build Time: 2024-01-27 13:26:53
GoVersion: go1.21.4
Race Enabled: false
TiKV Min Version: 6.2.0-alpha
Check Table Before Drop: false
Store: unistore |

id estRows actRows task access object execution info operator info memory disk
TableReader_7 0.00 1 root time:109.8µs, loops:2, cop_task: {num: 1, max: 95.9µs, proc_keys: 0, rpc_num: 1, rpc_time: 91.4µs, copr_cache_hit_ratio: 0.00, distsql_concurrency: 15} data:Selection_6 452 Bytes N/A
└─Selection_6 0.00 1 cop[tikv] tikv_task:{time:88.5µs, loops:0} eq(test.sbtest1.id_1, 1) N/A N/A
└─TableRangeScan_5 1.00 1 cop[tikv] table:sbtest1 tikv_task:{time:88.5µs, loops:0} range:[1,1], keep order:false N/A N/A
id estRows actRows task access object execution info operator info memory disk
TableReader_7 0.00 0 root time:90.2µs, loops:1, cop_task: {num: 1, max: 66.5µs, proc_keys: 0, rpc_num: 1, rpc_time: 62.6µs, copr_cache_hit_ratio: 0.00, distsql_concurrency: 15} data:Selection_6 176 Bytes N/A
└─Selection_6 0.00 0 cop[tikv] tikv_task:{time:60.4µs, loops:0} eq(test.sbtest1.id_1, 0) N/A N/A
└─TableRangeScan_5 1.00 1 cop[tikv] table:sbtest1 tikv_task:{time:60.4µs, loops:0} range:[1,1], keep order:false N/A N/A
id estRows actRows task access object execution info operator info memory disk
TableReader_7 0.00 1 root time:68.7µs, loops:2, cop_task: {num: 1, max: 58.3µs, proc_keys: 0, rpc_num: 1, rpc_time: 54.7µs, copr_cache_hit_ratio: 0.00, distsql_concurrency: 15} data:Selection_6 452 Bytes N/A
└─Selection_6 0.00 1 cop[tikv] tikv_task:{time:52.5µs, loops:0} eq(test.sbtest1.id_1, 1) N/A N/A
└─TableRangeScan_5 1.00 1 cop[tikv] table:sbtest1 tikv_task:{time:52.5µs, loops:0} range:[1,1], keep order:false N/A N/A
id estRows actRows task access object execution info operator info memory disk
TableReader_7 0.00 0 root time:84.3µs, loops:1, cop_task: {num: 1, max: 71.5µs, proc_keys: 0, rpc_num: 1, rpc_time: 67.4µs, copr_cache_hit_ratio: 0.00, distsql_concurrency: 15} data:Selection_6 176 Bytes N/A
└─Selection_6 0.00 0 cop[tikv] tikv_task:{time:64.7µs, loops:0} eq(test.sbtest1.id_1, 0) N/A N/A
└─TableRangeScan_5 1.00 1 cop[tikv] table:sbtest1 tikv_task:{time:64.7µs, loops:0} range:[1,1], keep order:false N/A N/A

@kennedy8312
Copy link

/affect 6.5

@kennedy8312
Copy link

/label affects-6.5

@qw4990 qw4990 removed type/bug The issue is confirmed as a bug. severity/major may-affects-5.4 This bug maybe affects 5.4.x versions. may-affects-6.1 affects-6.5 affects-7.1 affects-7.5 labels Apr 2, 2024
@qw4990 qw4990 added the type/enhancement The issue or PR belongs to an enhancement. label Apr 2, 2024
@seiya-annie
Copy link

/found customer

@ti-chi-bot ti-chi-bot bot added the report/customer Customers have encountered this bug. label Jun 4, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
affects-8.1 found/gs found by gs report/customer Customers have encountered this bug. sig/planner SIG: Planner type/enhancement The issue or PR belongs to an enhancement. type/performance type/regression
Projects
None yet
Development

No branches or pull requests

7 participants