tidb 6.1.7版本第一次执行limit 10很慢,后面再执行就很快

tidb 版本6.1.7

目标表1.1亿左右,取表的前几行记录这种操作第一次执行很慢,但是第二次(第二次以后)执行的时候就很快,感觉有点不及预期,理论上是应该匹配到了sql查询就结束,不知道是什么原因。

PS:这类sql是业务的需求,需要取前面几行数据。

下面是样例,第一次执行基本在8秒以上,然后再次执行就在100ms左右,慢的时候耗时主要是在tot_proc,不知道这个是具体做啥的。

mysql> desc SELECT   id,   create_time,   update_time,   key_business,   topic,   tags,   msg_id,   ext_spropertie,   send_time,   send_status FROM   record_logistics_message;
+-----------------------+--------------+-----------+--------------------------------+----------------------+
| id                    | estRows      | task      | access object                  | operator info        |
+-----------------------+--------------+-----------+--------------------------------+----------------------+
| TableReader_5         | 118683969.00 | root      |                                | data:TableFullScan_4 |
| └─TableFullScan_4     | 118683969.00 | cop[tikv] | table:record_logistics_message | keep order:false     |
+-----------------------+--------------+-----------+--------------------------------+----------------------+
2 rows in set (0.00 sec)

mysql> 
mysql>  explain analyze SELECT   id,   create_time,   update_time,   key_business,   topic,   tags,   msg_id,   ext_spropertie,   send_time,   send_status FROM   record_logistics_message limit 10;
+---------------------------+---------+---------+-----------+--------------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------+---------+------+
| id                        | estRows | actRows | task      | access object                  | execution info                                                                                                                                                                                                                                                                                                       | operator info      | memory  | disk |
+---------------------------+---------+---------+-----------+--------------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------+---------+------+
| Limit_7                   | 10.00   | 10      | root      |                                | time:8.11s, loops:2                                                                                                                                                                                                                                                                                                  | offset:0, count:10 | N/A     | N/A  |
| └─TableReader_11          | 10.00   | 10      | root      |                                | time:8.11s, loops:1, cop_task: {num: 253, max: 222.3ms, min: 456.3µs, avg: 32ms, p95: 100.5ms, max_proc_keys: 10, p95_proc_keys: 0, tot_proc: 7.91s, tot_wait: 90ms, rpc_num: 253, rpc_time: 8.09s, copr_cache_hit_ratio: 0.26}                                                                                      | data:Limit_10      | 13.1 KB | N/A  |
|   └─Limit_10              | 10.00   | 10      | cop[tikv] |                                | tikv_task:{proc max:258ms, min:0s, p80:61ms, p95:128ms, iters:253, tasks:253}, scan_detail: {total_process_keys: 10, total_process_keys_size: 13092, total_keys: 26272492, rocksdb: {delete_skipped_count: 320075, key_skipped_count: 26763920, block: {cache_hit_count: 53874, read_count: 3, read_byte: 76.7 KB}}} | offset:0, count:10 | N/A     | N/A  |
|     └─TableFullScan_9     | 10.00   | 10      | cop[tikv] | table:record_logistics_message | tikv_task:{proc max:258ms, min:0s, p80:61ms, p95:128ms, iters:253, tasks:253}                                                                                                                                                                                                                                        | keep order:false   | N/A     | N/A  |
+---------------------------+---------+---------+-----------+--------------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------+---------+------+
4 rows in set (8.18 sec)

mysql>  explain analyze SELECT   id,   create_time,   update_time,   key_business,   topic,   tags,   msg_id,   ext_spropertie,   send_time,   send_status FROM   record_logistics_message limit 10;
+---------------------------+---------+---------+-----------+--------------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------+---------+------+
| id                        | estRows | actRows | task      | access object                  | execution info                                                                                                                                                                                                                                                                              | operator info      | memory  | disk |
+---------------------------+---------+---------+-----------+--------------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------+---------+------+
| Limit_7                   | 10.00   | 10      | root      |                                | time:114.4ms, loops:2                                                                                                                                                                                                                                                                       | offset:0, count:10 | N/A     | N/A  |
| └─TableReader_11          | 10.00   | 10      | root      |                                | time:114.4ms, loops:1, cop_task: {num: 253, max: 4.71ms, min: 209.9µs, avg: 423.4µs, p95: 660.1µs, tot_proc: 2ms, tot_wait: 42ms, rpc_num: 253, rpc_time: 105.1ms, copr_cache_hit_ratio: 0.89}                                                                                              | data:Limit_10      | 13.1 KB | N/A  |
|   └─Limit_10              | 10.00   | 10      | cop[tikv] |                                | tikv_task:{proc max:258ms, min:0s, p80:61ms, p95:128ms, iters:253, tasks:253}, scan_detail: {total_process_keys: 0, total_process_keys_size: 0, total_keys: 29, rocksdb: {delete_skipped_count: 0, key_skipped_count: 0, block: {cache_hit_count: 312, read_count: 1, read_byte: 64.0 KB}}} | offset:0, count:10 | N/A     | N/A  |
|     └─TableFullScan_9     | 10.00   | 10      | cop[tikv] | table:record_logistics_message | tikv_task:{proc max:258ms, min:0s, p80:61ms, p95:128ms, iters:253, tasks:253}                                                                                                                                                                                                               | keep order:false   | N/A     | N/A  |
+---------------------------+---------+---------+-----------+--------------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------+---------+------+
4 rows in set (0.12 sec)

mysql>  explain analyze SELECT   id,   create_time,   update_time,   key_business,   topic,   tags,   msg_id,   ext_spropertie,   send_time,   send_status FROM   record_logistics_message limit 11;
+---------------------------+---------+---------+-----------+--------------------------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------+---------+------+
| id                        | estRows | actRows | task      | access object                  | execution info                                                                                                                                                                                                                                                                                                          | operator info      | memory  | disk |
+---------------------------+---------+---------+-----------+--------------------------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------+---------+------+
| Limit_7                   | 11.00   | 11      | root      |                                | time:11.8s, loops:2                                                                                                                                                                                                                                                                                                     | offset:0, count:11 | N/A     | N/A  |
| └─TableReader_11          | 11.00   | 11      | root      |                                | time:11.8s, loops:1, cop_task: {num: 253, max: 264.3ms, min: 515.2µs, avg: 46.7ms, p95: 135.4ms, max_proc_keys: 11, p95_proc_keys: 0, tot_proc: 11.4s, tot_wait: 226ms, rpc_num: 253, rpc_time: 11.8s, copr_cache_hit_ratio: 0.00}                                                                                      | data:Limit_10      | 13.4 KB | N/A  |
|   └─Limit_10              | 11.00   | 11      | cop[tikv] |                                | tikv_task:{proc max:264ms, min:0s, p80:66ms, p95:129ms, iters:253, tasks:253}, scan_detail: {total_process_keys: 11, total_process_keys_size: 13361, total_keys: 35717822, rocksdb: {delete_skipped_count: 2834812, key_skipped_count: 38806755, block: {cache_hit_count: 70260, read_count: 250, read_byte: 13.7 MB}}} | offset:0, count:11 | N/A     | N/A  |
|     └─TableFullScan_9     | 11.00   | 11      | cop[tikv] | table:record_logistics_message | tikv_task:{proc max:264ms, min:0s, p80:66ms, p95:129ms, iters:253, tasks:253}                                                                                                                                                                                                                                           | keep order:false   | N/A     | N/A  |
+---------------------------+---------+---------+-----------+--------------------------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------+---------+------+
4 rows in set (11.84 sec)

mysql>  explain analyze SELECT   id,   create_time,   update_time,   key_business,   topic,   tags,   msg_id,   ext_spropertie,   send_time,   send_status FROM   record_logistics_message limit 11;
+---------------------------+---------+---------+-----------+--------------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------+---------+------+
| id                        | estRows | actRows | task      | access object                  | execution info                                                                                                                                                                                                                                                                              | operator info      | memory  | disk |
+---------------------------+---------+---------+-----------+--------------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------+---------+------+
| Limit_7                   | 11.00   | 11      | root      |                                | time:87.5ms, loops:2                                                                                                                                                                                                                                                                        | offset:0, count:11 | N/A     | N/A  |
| └─TableReader_11          | 11.00   | 11      | root      |                                | time:87.5ms, loops:1, cop_task: {num: 253, max: 705.6µs, min: 224.5µs, avg: 316.2µs, p95: 455.3µs, tot_proc: 4ms, tot_wait: 11ms, rpc_num: 253, rpc_time: 78ms, copr_cache_hit_ratio: 0.89}                                                                                                 | data:Limit_10      | 13.3 KB | N/A  |
|   └─Limit_10              | 11.00   | 11      | cop[tikv] |                                | tikv_task:{proc max:264ms, min:0s, p80:66ms, p95:129ms, iters:253, tasks:253}, scan_detail: {total_process_keys: 0, total_process_keys_size: 0, total_keys: 29, rocksdb: {delete_skipped_count: 0, key_skipped_count: 0, block: {cache_hit_count: 286, read_count: 0, read_byte: 0 Bytes}}} | offset:0, count:11 | N/A     | N/A  |
|     └─TableFullScan_9     | 11.00   | 11      | cop[tikv] | table:record_logistics_message | tikv_task:{proc max:264ms, min:0s, p80:66ms, p95:129ms, iters:253, tasks:253}                                                                                                                                                                                                               | keep order:false   | N/A     | N/A  |
+---------------------------+---------+---------+-----------+--------------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------+---------+------+
4 rows in set (0.10 sec)

mysql>  explain analyze SELECT   id,   create_time,   update_time,   key_business,   topic,   tags,   msg_id,   ext_spropertie,   send_time,   send_status FROM   record_logistics_message limit 12;
+---------------------------+---------+---------+-----------+--------------------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------+---------+------+
| id                        | estRows | actRows | task      | access object                  | execution info                                                                                                                                                                                                                                                                                                        | operator info      | memory  | disk |
+---------------------------+---------+---------+-----------+--------------------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------+---------+------+
| Limit_7                   | 12.00   | 12      | root      |                                | time:11.6s, loops:2                                                                                                                                                                                                                                                                                                   | offset:0, count:12 | N/A     | N/A  |
| └─TableReader_11          | 12.00   | 12      | root      |                                | time:11.6s, loops:1, cop_task: {num: 253, max: 271.3ms, min: 332.5µs, avg: 45.7ms, p95: 130.5ms, max_proc_keys: 12, p95_proc_keys: 0, tot_proc: 11.4s, tot_wait: 20ms, rpc_num: 253, rpc_time: 11.6s, copr_cache_hit_ratio: 0.00}                                                                                     | data:Limit_10      | 13.6 KB | N/A  |
|   └─Limit_10              | 12.00   | 12      | cop[tikv] |                                | tikv_task:{proc max:271ms, min:0s, p80:63ms, p95:129ms, iters:253, tasks:253}, scan_detail: {total_process_keys: 12, total_process_keys_size: 13621, total_keys: 35717823, rocksdb: {delete_skipped_count: 2834812, key_skipped_count: 38806756, block: {cache_hit_count: 70497, read_count: 1, read_byte: 64.0 KB}}} | offset:0, count:12 | N/A     | N/A  |
|     └─TableFullScan_9     | 12.00   | 12      | cop[tikv] | table:record_logistics_message | tikv_task:{proc max:271ms, min:0s, p80:63ms, p95:129ms, iters:253, tasks:253}                                                                                                                                                                                                                                         | keep order:false   | N/A     | N/A  |
+---------------------------+---------+---------+-----------+--------------------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------+---------+------+
4 rows in set (11.59 sec)

mysql>  explain analyze SELECT   id,   create_time,   update_time,   key_business,   topic,   tags,   msg_id,   ext_spropertie,   send_time,   send_status FROM   record_logistics_message limit 12;
+---------------------------+---------+---------+-----------+--------------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------+---------+------+
| id                        | estRows | actRows | task      | access object                  | execution info                                                                                                                                                                                                                                                                              | operator info      | memory  | disk |
+---------------------------+---------+---------+-----------+--------------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------+---------+------+
| Limit_7                   | 12.00   | 12      | root      |                                | time:149.8ms, loops:2                                                                                                                                                                                                                                                                       | offset:0, count:12 | N/A     | N/A  |
| └─TableReader_11          | 12.00   | 12      | root      |                                | time:149.8ms, loops:1, cop_task: {num: 253, max: 17ms, min: 202.3µs, avg: 566.4µs, p95: 683.4µs, tot_proc: 4ms, tot_wait: 76ms, rpc_num: 253, rpc_time: 141.5ms, copr_cache_hit_ratio: 0.89}                                                                                                | data:Limit_10      | 13.6 KB | N/A  |
|   └─Limit_10              | 12.00   | 12      | cop[tikv] |                                | tikv_task:{proc max:271ms, min:0s, p80:63ms, p95:129ms, iters:253, tasks:253}, scan_detail: {total_process_keys: 0, total_process_keys_size: 0, total_keys: 29, rocksdb: {delete_skipped_count: 0, key_skipped_count: 0, block: {cache_hit_count: 286, read_count: 0, read_byte: 0 Bytes}}} | offset:0, count:12 | N/A     | N/A  |
|     └─TableFullScan_9     | 12.00   | 12      | cop[tikv] | table:record_logistics_message | tikv_task:{proc max:271ms, min:0s, p80:63ms, p95:129ms, iters:253, tasks:253}                                                                                                                                                                                                               | keep order:false   | N/A     | N/A  |
+---------------------------+---------+---------+-----------+--------------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------+---------+------+
4 rows in set (0.16 sec)

mysql> 
  1. 快应该是 copr_cache_hit_ratio 原因,cache 优化。
  2. 慢的话直观不预期,要么 mvcc compact 不及时,要么感觉是不是调整过一些算子大小,我看 cop task 有直接分253 个 task。或者是 tikv 很忙?

从监控看不忙的,集群平均耗时也很低

delete_skipped_count: 2834812, key_skipped_count: 38806756

:thinking: 要不试试这个表手动收一下 compact:专栏 - TiDB MVCC 问题处理 | TiDB 社区

1 个赞

mvcc 版本过多问题,看下 gc 配置以及 gc 是否正常,检查业务逻辑,是否有突然的大量数据删除还未到 gc 时间

另外 6.1 版本的 gc compaction filter 机制问题也会导致 mvcc 版本过多问题,关闭这个 gc compaction filter 或者升级到 v6.5.11 以上,参考:https://docs.pingcap.com/zh/tidb/stable/release-6.5.11#改进提升

2 个赞

此话题已在最后回复的 7 天后被自动关闭。不再允许新回复。