select max(DateTIme) from tablename 速度慢

不输土豆 · 2024 年5 月 20 日 10:52

【 TiDB 使用环境】生产环境
【 TiDB 版本】V6.5.9
【复现路径】
1.查询慢的信息
1.1, 首次连接后，第一使用 select max(datetime) from tablename 时，延迟到达4.0秒左右
mysql>

mysql> explain analyze select max(DateTime) from TRESmartSumPer_PIT;
±-----------------------------±--------±--------±----------±---------------------------------------------------±-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±-----------------------------------------------------------±----------±-----+
| id | estRows | actRows | task | access object | execution info | operator info | memory | disk |
±-----------------------------±--------±--------±----------±---------------------------------------------------±-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±-----------------------------------------------------------±----------±-----+
| StreamAgg_10 | 1.00 | 1 | root | | time:954.7µs, loops:2 | funcs:max(data_pit.tresmartsumper_pit.datetime)->Column#31 | 220 Bytes | N/A |
| └─Limit_14 | 1.00 | 1 | root | | time:947.9µs, loops:2 | offset:0, count:1 | N/A | N/A |
| └─IndexReader_21 | 1.00 | 1 | root | | time:945.3µs, loops:1, cop_task: {num: 1, max: 1.53ms, proc_keys: 1, rpc_num: 1, rpc_time: 1.5ms, copr_cache_hit_ratio: 0.00, distsql_concurrency: 1} | index:Limit_20 | 331 Bytes | N/A |
| └─Limit_20 | 1.00 | 1 | cop[tikv] | | tikv_task:{time:0s, loops:1}, scan_detail: {total_process_keys: 1, total_process_keys_size: 117, total_keys: 2, get_snapshot_time: 33.4µs, rocksdb: {key_skipped_count: 2, block: {cache_hit_count: 15}}} | offset:0, count:1 | N/A | N/A |
| └─IndexFullScan_19 | 1.00 | 1 | cop[tikv] | table:TRESmartSumPer_PIT, index:DateTime(DateTime) | tikv_task:{time:0s, loops:1} | keep order:true, desc | N/A | N/A |
±-----------------------------±--------±--------±----------±---------------------------------------------------±-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±-----------------------------------------------------------±----------±-----+
5 rows in set (3.52 sec)

1.2 SLOW log
Time: 2024-05-20T17:00:12.783209569+08:00
Txn_start_ts: 449890381783630477
User@Host: wmh[wmh] @ 192.168.202.9 [192.168.202.9]
Conn_ID: 1520453057400460761
Query_time: 3.517811043
Parse_time: 0.000059137
Compile_time: 0.000489663
Rewrite_time: 0.000393289
Optimize_time: 0.000274297
Wait_TS: 0.000011669
Cop_time: 0.000653512 Request_count: 1 Process_keys: 1 Total_keys: 2 Get_snapshot_time: 0.000 Rocksdb_key_skipped_count: 2 Rocksdb_block_cache_hit_co unt: 13 # DB: data_pit # Index_names: [TRESmartSumPer_PIT:DateTime]
Is_internal: false
Digest: 4274f68c3a414ba4dd783291f864a76f3ca99e415acc1fcc66acd8586bf4d232
Stats: TRESmartSumPer_PIT:449479787995725863
Num_cop_tasks: 1
Cop_proc_avg: 0 Cop_proc_addr: 10.0.3.93:20160
Cop_wait_avg: 0 Cop_wait_addr: 10.0.3.93:20160
Mem_max: 500 # Prepared: false
Plan_from_cache: false
Plan_from_binding: false
Has_more_results: false
KV_total: 0.000811246
PD_total: 3.338144114
Backoff_total: 0
Write_sql_response_total: 0.000021161
Result_rows: 0
Succ: true
IsExplicitTxn: false
IsSyncStatsFailed: false
Plan: tidb_decode_plan(‘5wWwMAk1XzEwCTAJMQlmdW5jczptYXgoZGF0YV9waXQudHJlc21hcnRzdW1wZXJfARNYZGF0ZXRpbWUpLT5Db2x1bW4jMzEJMQkBE6A6Njc3LjnCtXMsIGxvb3BzOjIJMjIwIEJ5dGVzCU4vQQoxCTE2XzE0CQFuPG9mZnNldDowLCBjb3VudDodRQgzLjIyRQAITi9BAQQgCjIJMzJfMjEJAT8waW5kZXg6TGltaXRfMgERDYEIMS4zHTwAMQFeaHBfdGFzazoge251bTogMSwgbWF4OiA4MzMuMQUrIHByb2Nfa2V5cwUdDHJwY18RKQEMBVgUIDgwMC42BS7YY29wcl9jYWNoZV9oaXRfcmF0aW86IDAuMDAsIGRpc3RzcWxfY29uY3VycmVuY3k6IDF9CTMzMT0GDDMJMTYFtAxfMAkxWggBBGt2CbUYe3RpbWU6MDVSXDF9LCBzY2FuX2RldGFpbDoge3RvdGFsXwHECGVzcxnHRhcAKF9zaXplOiAxMTcsDR4J9DwyLCBnZXRfc25hcHNob3RfBXIQIDM1LjUF8FRyb2Nrc2RiOiB7a2V5X3NraXBwZWRfKbQBPAxibG9jIV05Ew0cFDEzfX19CTG8HDQJNDZfMTkJCfVkdGFibGU6VFJFU21hcnRTdW1QZXJfUElULCAp2CBEYXRlVGltZSgRCWwpLCBrZWVwIG9yZGVyOnRydWUsIGRlc2MJMQl0ai0BIAlOL0EJTi9BCg==’)
Plan_digest: 03bb305ea548b39ba9831bbf4ff07b5c243b972a3eac7e3b835fe178efd92681
Binary_plan: tidb_decode_binary_plan(‘pQfQCqAHCgxTdHJlYW1BZ2dfMTASlQYKCExpbWl0XzE0Eq8FCg5JbmRleFJlYWRlcl8yMRLIAwoNIBgyMBKtAQoQBSBURnVsbFNjYW5fMTkh39EB6SS/ckApAAUB2PA/MAE4AkACSjYKNAoIZGF0YV9waXQSElRSRVNtYXJ0U3VtUGVyX1BJVBoUCghEYXRlVGltZRIVCuBSFWtlZXAgb3JkZXI6dHJ1ZSwgZGVzY2ocdGlrdl90YXNrOnt0aW1lOjBzLCBsb29wczoxfXD///8JAgQBeAkIDP///wFemwBUUhFvZmZzZXQ6MCwgY291bnQ6MWrKAW5gAJgsIHNjYW5fZGV0YWlsOiB7dG90YWxfcHJvY2Vzc19rZXlzOiAxLCBGFwAkX3NpemU6IDExNxEeCS1AMiwgZ2V0X3NuYXBzaG90X3QB0nwgMzUuNcK1cywgcm9ja3NkYjoge2tleV9za2lwcGVkXwmsATxAYmxvY2s6IHtjYWNoZV9oaXQRHBAxM319fVoOARg3ttv3B9I+MqkBKAFAAVIOaW5kZXg6SQYMMjBaFgWNEDY3MS4zBY0tZRRigwFjb3ApghQge251bToB8yRtYXg6IDgzMy4xBSwhEw3jGDEsIHJwY18RKQEMBVkUIDgwMC42BS4QY29wcl8ZxJhyYXRpbzogMC4wMCwgZGlzdHNxbF9jb25jdXJyZW5jeTogMX1wywIu4gFe1ABG4gEV1wgzLjIFfQnXADJaLQEYJ4eQlxsuVEItASg6ZnVuY3M6bWF4KFHcEC50cmVzQdsUc3VtcGVyQe9MLmRhdGV0aW1lKS0+Q29sdW1uIzMZggg3LjkyggA43AF4////////////ARgB’)
use data_pit;
explain analyze select max(DateTime) from TRESmartSumPer_PIT;

2.再次执行时，速度就快了
2.1 执行计划
mysql>
mysql> explain analyze select max(DateTime) from TRESmartSumPer_PIT;
±-----------------------------±--------±--------±----------±---------------------------------------------------±------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±-----------------------------------------------------------±----------±-----+
| id | estRows | actRows | task | access object | execution info | operator info | memory | disk |
±-----------------------------±--------±--------±----------±---------------------------------------------------±------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±-----------------------------------------------------------±----------±-----+
| StreamAgg_10 | 1.00 | 1 | root | | time:1.25ms, loops:2 | funcs:max(data_pit.tresmartsumper_pit.datetime)->Column#31 | 668 Bytes | N/A |
| └─Limit_14 | 1.00 | 1 | root | | time:1.24ms, loops:2 | offset:0, count:1 | N/A | N/A |
| └─IndexReader_21 | 1.00 | 1 | root | | time:1.24ms, loops:1, cop_task: {num: 1, max: 1.19ms, proc_keys: 1, rpc_num: 1, rpc_time: 1.14ms, copr_cache_hit_ratio: 0.00, distsql_concurrency: 1} | index:Limit_20 | 338 Bytes | N/A |
| └─Limit_20 | 1.00 | 1 | cop[tikv] | | tikv_task:{time:0s, loops:1}, scan_detail: {total_process_keys: 1, total_process_keys_size: 117, total_keys: 2, get_snapshot_time: 329.4µs, rocksdb: {key_skipped_count: 2, block: {cache_hit_count: 13}}} | offset:0, count:1 | N/A | N/A |
| └─IndexFullScan_19 | 1.00 | 1 | cop[tikv] | table:TRESmartSumPer_PIT, index:DateTime(DateTime) | tikv_task:{time:0s, loops:1} | keep order:true, desc | N/A | N/A |
±-----------------------------±--------±--------±----------±---------------------------------------------------±------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±-----------------------------------------------------------±----------±-----+
5 rows in set (0.05 sec)

2.2 对应的慢SQL
Time: 2024-05-20T17:07:33.29944025+08:00
Txn_start_ts: 449890498175565982
User@Host: wmh[wmh] @ 192.168.202.9 [192.168.202.9]
Conn_ID: 1520453057400460761
Query_time: 0.044330099
Parse_time: 0.000025138
Compile_time: 0.000299687
Rewrite_time: 0.000249411
Optimize_time: 0.000163697
Wait_TS: 0.000005949
Cop_time: 0.000934951 Request_count: 1 Process_keys: 1 Total_keys: 2 Get_snapshot_time: 0.000 Rocksdb_key_skipped_count: 2 Rocksdb_block_cache_hit_co unt: 14 Rocksdb_block_read_count: 1 Rocksdb_block_read_byte: 8595 Rocksdb_block_read_time: 0.000
DB: data_pit # Index_names: [TRESmartSumPer_PIT:DateTime]
Is_internal: false
Digest: 4274f68c3a414ba4dd783291f864a76f3ca99e415acc1fcc66acd8586bf4d232
Stats: TRESmartSumPer_PIT:449479787995725863
Num_cop_tasks: 1
Cop_proc_avg: 0 Cop_proc_addr: 10.0.3.93:20160
Cop_wait_avg: 0 Cop_wait_addr: 10.0.3.93:20160
Mem_max: 1014 # Prepared: false # Plan_from_cache: false
Plan_from_binding: false # Has_more_results: false
KV_total: 0.000918619 # PD_total: 0.000004261
Backoff_total: 0
Write_sql_response_total: 0.000015934
Result_rows: 0
Succ: true
IsExplicitTxn: false
IsSyncStatsFailed: false
Plan: tidb_decode_plan(‘nQawMAk1XzEwCTAJMQlmdW5jczptYXgoZGF0YV9waXQudHJlc21hcnRzdW1wZXJfARNYZGF0ZXRpbWUpLT5Db2x1bW4jMzEJMQkBE6A6OTUzLjHCtXMsIGxvb3BzO jIJNjY4IEJ5dGVzCU4vQQoxCTE2XzE0CQFuPG9mZnNldDowLCBjb3VudDoZRQQ0OTJDAAhOL0EBBCAKMgkzMl8yMQkBPTBpbmRleDpMaW1pdF8yAREJfww0Ny41HTwAMQFcaHBfdGFzazoge251bTog MSwgbWF4OiA4NzYuNAUrIHByb2Nfa2V5cwUdDHJwY18RKQEMBVgUIDg1Ni44BS7YY29wcl9jYWNoZV9oaXRfcmF0aW86IDAuMDAsIGRpc3RzcWxfY29uY3VycmVuY3k6IDF9CTM0Nj0EDDMJMTYFtAx fMAkxWgYBBGt2CbUYe3RpbWU6MDVQXDF9LCBzY2FuX2RldGFpbDoge3RvdGFsXwHECGVzcxnHRhcAKF9zaXplOiAxMTcsDR4J9DwyLCBnZXRfc25hcHNob3RfBXIQIDMwOS4J8VRyb2Nrc2RiOiB7a2 V5X3NraXBwZWRfKbMBPQxibG9jIV45FA0cGDE0LCByZWEVLAAxDQ8wYnl0ZTogOC4zOSBLQg0UCXUoMTIuMcK1c319fQkx9Bw0CTQ2XzE5CSktZHRhYmxlOlRSRVNtYXJ0U3VtUGVyX1BJVCwgSRAgRGF0ZVRpbWUoEQlsKSwga2VlcCBvcmRlcjp0cnVlLCBkZXNjCTEJdGplASAJTi9BCU4vQQo=’)
Plan_digest: 03bb305ea548b39ba9831bbf4ff07b5c243b972a3eac7e3b835fe178efd92681
Binary_plan: tidb_decode_binary_plan(‘2wfQCtYHCgxTdHJlYW1BZ2dfMTASywYKCExpbWl0XzE0EucFCg5JbmRleFJlYWRlcl8yMRKABAoNIBgyMBKtAQoQBSBURnVsbFNjYW5fMTkh39EB6SS/ckApAAUB2PA/MAE4AkACSjYKNAoIZGF0YV9waXQSElRSRVNtYXJ0U3VtUGVyX1BJVBoUCghEYXRlVGltZRIVCuBSFWtlZXAgb3JkZXI6dHJ1ZSwgZGVzY2ocdGlrdl90YXNrOnt0aW1lOjBzLCBsb29wczoxfXD///8JAgQBeAkIDP///wFemwBUUhFvZmZzZXQ6MCwgY291bnQ6MWqCAm5gAAgsIHMB7nxkZXRhaWw6IHt0b3RhbF9wcm9jZXNzX2tleXM6IDEsIEYXACRfc2l6ZTogMTE3ER4JLUAyLCBnZXRfc25hcHNob3RfdAHSgCAzMDkuOMK1cywgcm9ja3NkYjoge2tleV9za2lwcGVkXwmtAT1AYmxvY2s6IHtjYWNoZV9oaXQRHBgxNCwgcmVhFSwAMQ0PMGJ5dGU6IDguMzkgS0INFAl1JDEyLjHCtXN9fX1aRgEYN7bb9wfSPjLhASgBQAFSDmluZGV4Okk+DDIwWhYFUBA5NDcuNQXELZ0UYoMBY29wKboUIHtudW06AZUkbWF4OiA4NzYuNAUsIUstGwGyCHBjXxEpAQwFWRAgODU2LikeEGNvcHJfGfuYcmF0aW86IDAuMDAsIGRpc3RzcWxfY29uY3VycmVuY3k6IDF9cNoCLhoCXtQARhoCJFoUdGltZTo5NDkFqQnVADJaKwEYJ4eQlxsuVEIrASg6ZnVuY3M6bWF4KHESEC50cmVzYREUc3VtcGVyYSUQLmRhdGUBbiwpLT5Db2x1bW4jMzExVwQ1MyWnUfRAMnCcBXj///////////8BGAE=’)
explain analyze select max(DateTime) from TRESmartSumPer_PIT;

【遇到的问题：问题现象及影响】连接TIDB后，第一次执行 select max(DateTime) from tablename 时，速度会出乎意料的慢。
【资源配置】进入到 TiDB Dashboard -集群信息 (Cluster Info) -主机(Hosts) 截图此页面
【附件：截图/日志/监控】
1，表结构

zhanggame1 · 2024 年5 月 20 日 12:12

看执行计划没看出来问题

像风一样的男子 · 2024 年5 月 21 日 00:36

你改成这个试试
select max(DateTime) from (select DateTime from TRESmartSumPer_PIT) t;

DBAER · 2024 年5 月 21 日 00:46

可以trace sql 试一下，看慢在哪里

zhaokede · 2024 年5 月 21 日 00:59

看起来也用到了索引的

yiduoyunQ · 2024 年5 月 21 日 01:54

PD_total: 3.338144114
PD_total：表示这个语句在 PD 上所有 RPC 请求花费的时间。

帅的掉渣 · 2024 年5 月 21 日 02:09

tidb执行计划一致，没问题。 pd耗时长，检查pd服务是否繁忙，网络通信是否流畅，pd机器某指标是否瓶颈

tidb菜鸟一只 · 2024 年5 月 21 日 06:54

pd节点资源监控看下

TiDBer_HUfcQIJx · 2024 年5 月 21 日 08:00

pd节点为什么这么慢

TIDB-Learner · 2024 年5 月 21 日 09:50

hughzm · 2024 年5 月 21 日 10:00

执行计划没有问题，考虑优先排除和Tidb的网络连接问题，或者在另外时间点执行来排除服务器负载问题

TiDBer_H5NdJb5Q · 2024 年5 月 21 日 10:13

PD_total这么大，是pd负载太高还是在调度region

Kongdom · 2024 年5 月 21 日 12:07

现在看到max这种聚合函数慢，就想推荐TiFlash组件提速

不输土豆 · 2024 年5 月 27 日 06:26

问题现象是一样的。

不输土豆 · 2024 年5 月 27 日 07:05

每次建立connection 之后，第一次执行这个sql 耗时会长；后面再执行相同SQL耗时就很正常了。感觉像是client段，需要缓存某种信息。
我再15:00 左右，重新建立connection 之后，执行sql 触发了一个慢的查询。这是慢时，pd 负载信息。

不输土豆 · 2024 年5 月 27 日 07:12

刚刚又发现，重新建立connection, 指定同一个tidb 服务，就不会出现查询慢的情况。所以应该是tidb服务需要缓存否写信息。是不是tidb server从pd server 拉取region info 时，这一步 pd-server 耗时长了。
（客户端就是pymyql, 所以不考虑客户端缓存 region 信息）

+--------------------+      +--------------------+      +--------------------+
|       Client       |      |        TiDB        |      |        PD          |
+--------------------+      +--------------------+      +--------------------+
          |                          |                         |
          | 1. Send SQL Query        |                         |
          +------------------------->|                         |
          |                          |                         |
          |                          | 2. Parse and Optimize   |
          |                          +------------------------>|
          |                          |                         |
          |                          | 3. Fetch Region Info    |
          |                          +------------------------>|
          |                          |                         |
          |                          | 4. Cache Region Info    |
          |                          |<------------------------+
          |                          |                         |
          |                          | 5. Execute Query        |
          |                          | (using cached Region    |
          |                          |  info to access TiKV)   |
          |                          |                         |
          |                          | 6. Merge Results        |
          |                          |                         |
          | 7. Return Results        |                         |
          +<-------------------------+-------------------------+

不输土豆 · 2024 年5 月 27 日 09:26

第一次连接时，执行trace sql：

第二次连接时，执行trace sql:

健康的腰间盘 · 2024 年5 月 27 日 09:53

PD节点升配

不输土豆 · 2024 年5 月 28 日 02:39

请问下，最有可能是pd-server 的什么资源到了瓶颈呢

WinterLiu · 2024 年5 月 28 日 03:21

看到日志中 PD节点花了很多的时间