runtime stats of index lookup reader is not accurate

[crazycs520]

Bug Report

Please answer these questions before submitting your issue. Thanks!

1. Minimal reproduce step (Required)

> explain analyze select sum(a*b) from stress_test.t_index_lookup use index (idx0) where a < 1000000;
+------------------------------+-----------+---------+-----------+-------------------------------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------------------------------------------------------------------------+---------+------+
| id                           | estRows   | actRows | task      | access object                       | execution info                                                                                                                                                                                                                                                                                                                                                                                                                                                                                        | operator info                                                                        | memory  | disk |
+------------------------------+-----------+---------+-----------+-------------------------------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------------------------------------------------------------------------+---------+------+
| HashAgg_13                   | 1.00      | 1       | root      |                                     | time:1.31s, loops:2, partial_worker:{wall_time:1.313125151s, concurrency:5, task_num:1, tot_wait:6.565353615s, tot_exec:34.39µs, tot_time:6.565399555s, max:1.313100081s, p95:1.313100081s}, final_worker:{wall_time:1.313181351s, concurrency:5, task_num:1, tot_wait:6.565548185s, tot_exec:54.09µs, tot_time:6.565610725s, max:1.313165621s, p95:1.313165621s}                                                                                                                                     | funcs:sum(Column#8)->Column#6                                                        | N/A     | N/A  |
| └─IndexLookUp_14             | 1.00      | 36      | root      |                                     | time:1.31s, loops:2, index_task: 258.6ms, table_task: {num: 28, concurrency: 5, time: 6.29s}                                                                                                                                                                                                                                                                                                                                                                                                          |                                                                                      | 6.61 MB | N/A  |
|   ├─IndexRangeScan_11(Build) | 500000.00 | 500000  | cop[tikv] | table:t_index_lookup, index:idx0(a) | time:1.14s, loops:28, cop_task: {num: 1, max: 238.6ms, proc_keys: 500000, tot_proc: 234ms, rpc_num: 1, rpc_time: 238.6ms, copr_cache: disabled}, tikv_task:{time:224ms, loops:493}, total_keys: 500001, processed_keys: 500000, rocksdb: {delete_skipped_count: 68190, key_skipped_count: 568190, block_cache_hit_count: 382, block_read_count: 0, block_read: 0 Bytes}                                                                                                                               | range:[-inf,1000000), keep order:false                                               | N/A     | N/A  |
|   └─HashAgg_7(Probe)         | 1.00      | 36      | cop[tikv] |                                     | time:4.9s, loops:56, cop_task: {num: 36, max: 239.5ms, min: 7.93ms, avg: 143.1ms, p95: 235.6ms, max_proc_keys: 20480, p95_proc_keys: 20480, tot_proc: 4.79s, tot_wait: 2ms, rpc_num: 36, rpc_time: 5.15s, copr_cache: disabled}, tikv_task:{proc max:227ms, min:6ms, p80:215ms, p95:223ms, iters:516, tasks:36}, total_keys: 501993, processed_keys: 500000, rocksdb: {delete_skipped_count: 2614, key_skipped_count: 11295, block_cache_hit_count: 959752, block_read_count: 0, block_read: 0 Bytes} | funcs:sum(mul(stress_test.t_index_lookup.a, stress_test.t_index_lookup.b))->Column#8 | N/A     | N/A  |
|     └─TableRowIDScan_12      | 500000.00 | 500000  | cop[tikv] | table:t_index_lookup                | tikv_task:{proc max:227ms, min:6ms, p80:212ms, p95:221ms, iters:516, tasks:36}                                                                                                                                                                                                                                                                                                                                                                                                                        | keep order:false                                                                     | N/A     | N/A  |
+------------------------------+-----------+---------+-----------+-------------------------------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------------------------------------------------------------------------+---------+------+

the runtime stats of IndexRangeScan_11 is:

time:1.14s, loops:28, cop_task: {num: 1, max: 238.6ms, proc_keys: 500000, tot_proc: 234ms, rpc_num: 1, rpc_time: 238.6ms ...

The total time is 1.14s, and there is only 1 cop-task that cost 238.6ms, so where is the rest time?

4. What is your TiDB version? (Required)

> select tidb_version();
+-------------------------------------------------------------------+
| tidb_version()                                                    |
+-------------------------------------------------------------------+
| Release Version: v4.0.0-beta.2-1890-g0370fbf6a                    |
| Edition: Community                                                |
| Git Commit Hash: 0370fbf6a3890fc658c1cccc42b28f33c2656872         |
| Git Branch: master                                                |
| UTC Build Time: 2020-12-23 08:31:45                               |
| GoVersion: go1.14.4                                               |
| Race Enabled: false                                               |
| TiKV Min Version: v3.0.0-60965b006877ca7234adaced7890d7b029ed1306 |
| Check Table Before Drop: false                                    |
+-------------------------------------------------------------------+

[ti-srebot]

Please edit this comment or add a new comment to complete the following information

Not a bug

1. Remove the 'type/bug' label
2. Add notes to indicate why it is not a bug

Duplicate bug

1. Add the 'type/duplicate' label
2. Add the link to the original bug

Bug

Note: Make Sure that 'component', and 'severity' labels are added
Example for how to fill out the template: #20100

1. Root Cause Analysis (RCA) (optional)

2. Symptom (optional)

3. All Trigger Conditions (optional)

4. Workaround (optional)

5. Affected versions

6. Fixed versions