tidb的sql查询不稳定

lxzkenney · 2023 年1 月 12 日 04:13

tidb 5.0.3
SQL:
desc SELECT
→ summary_create_time AS summary_create_time,
→ encrypt_mobile AS encrypt_mobile,
→ first_class_content AS first_class_content,
→ second_class_content AS second_class_content,
→ third_class_content AS third_class_content,
→ forth_class_content AS forth_class_content
→ FROM shuidi_data_warehouse.dwb_risk_cs_service_summary_full_d
→ WHERE 1 = 1
→ AND encrypt_mobile = ‘xxxxxxxxxxx’
→ ORDER BY summary_create_time DESC
→ LIMIT 0, 150;
SQL查询执行计划，统计信息的健康度 100。

SQL查询属于简单查询，有索引，过滤后数据个位数。慢查询里面没有这个SQL的慢查记录，业务上确实每天都有 60多条的大概 2秒左右的查询响应，告警。程序的链路上暂时也没发现什么异常。从数据库这边排查，不知道是否有锁等待，锁冲突的情况。这个应该咋排查，看哪些指标。确定是否有读的锁等待问题。
从数据库这边来说，访问量不大，没有压力。就是这个表dwb_risk_cs_service_summary_full_d 的读写比较频繁，量级是1千万。
日志上确实有一些写写冲突，不知道影不影响读操作。

最近两天的CPU使用率很低，访问量不大。

这个图是ERROR KEYS ：指标好像没那么细，看不出是读写有没有冲突

我是咖啡哥 · 2023 年1 月 12 日 04:20

DML频繁，会影响读的效率。可以在sql详情里面看到版本数会很多。

xingzhenxiang · 2023 年1 月 12 日 05:07

索引换成encrypt_mobile+summary_create_time 试试

裤衩儿飞上天 · 2023 年1 月 12 日 05:31

explain analyze 结果贴上来看看

lxzkenney · 2023 年1 月 12 日 06:05

explain_analyze.txt (5.5 KB)

mysql> mysql> explain analyze SELECT summary_create_time AS summary_create_time, encrypt_mobile AS encrypt_mobile, first_class_content AS first_class_content, second_class_content AS second_class_content, third_class_content AS thss_content, forth_class_content AS forth_class_content FROM shuidi_data_warehouse.dwb_risk_cs_service_summary_full_d WHERE 1 = 1 AND encrypt_mobile = ‘QbZD73YfQvq22tytWDo4Cw==’ ORDER BY summary_create_time DESC LIMIT 0, 150;
±---------------------------------±--------±--------±----------±-------------------------------------------------------------------------------------±------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±-------------------------------------------------------------------------------------------------------±----------±-----+
| id | estRows | actRows | task | access object | execution info | operator info | memory | disk |
±---------------------------------±--------±--------±----------±-------------------------------------------------------------------------------------±------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±-------------------------------------------------------------------------------------------------------±----------±-----+
| TopN_10 | 2.00 | 0 | root | | time:517.9µs, loops:1 | shuidi_data_warehouse.dwb_risk_cs_service_summary_full_d.summary_create_time:desc, offset:0, count:150 | 0 Bytes | N/A |
| └─IndexLookUp_28 | 2.00 | 0 | root | | time:509.6µs, loops:2, table_task: {total_time: 7.61ms, num: 0, concurrency: 16} | | 207 Bytes | N/A |
| ├─IndexRangeScan_26(Build) | 2.00 | 0 | cop[tikv] | table:dwb_risk_cs_service_summary_full_d, index:index_encrypt_mobile(encrypt_mobile) | time:456.1µs, loops:1, cop_task: {num: 1, max: 434.8µs, proc_keys: 0, rpc_num: 1, rpc_time: 420µs, copr_cache_hit_ratio: 0.00}, tikv_task:{time:0s, loops:1}, scan_detail: {total_process_keys: 0, total_keys: 1, rocksdb: {delete_skipped_count: 0, key_skipped_count: 0, block: {cache_hit_count: 11, read_count: 0, read_byte: 0 Bytes}}} | range:[“QbZD73YfQvq22tytWDo4Cw==”,“QbZD73YfQvq22tytWDo4Cw==”], keep order:false | N/A | N/A |
| └─TableRowIDScan_27(Probe) | 2.00 | 0 | cop[tikv] | table:dwb_risk_cs_service_summary_full_d | | keep order:false | N/A | N/A |
±---------------------------------±--------±--------±----------±-------------------------------------------------------------------------------------±------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±-------------------------------------------------------------------------------------------------------±----------±-----+
4 rows in set (0.00 sec)

裤衩儿飞上天 · 2023 年1 月 12 日 06:36

等sql执行慢的时候，你可以查一下 DATA_LOCK_WAITS 表，里面会有当前时刻等锁信息
可参考： TiDB 锁冲突问题处理 | PingCAP Docs
具体你这个感觉应该从业务逻辑层面入手，看看冲突在哪儿了

tidb菜鸟一只 · 2023 年1 月 12 日 06:52

你这个sql明显执行时间和encrypt_mobile的值有关啊，你找encrypt_mobile对应数据特别多的值，查一下这个sql的执行时间。

xingzhenxiang · 2023 年1 月 12 日 08:55

建个联合索引很难吗，我觉得建个联合索引就解决了

胡杨树旁 · 2023 年1 月 12 日 09:00

是不是数据分布不均匀？

lxzkenney · 2023 年1 月 12 日 09:12

explain_analyze.txt (15.3 KB)

加完后的执行计划，感觉耗时稍微高了点。多了一步。
±-----------------------------------±--------±--------±----------±--------------------------------------------------------------------------------------------------------±------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±----------±-----+
| id | estRows | actRows | task | access object | execution info | operator info | memory | disk |
±-----------------------------------±--------±--------±----------±--------------------------------------------------------------------------------------------------------±------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±----------±-----+
| Limit_13 | 2.00 | 0 | root | | time:497.9µs, loops:1 | offset:0, count:150 | N/A | N/A |
| └─Projection_38 | 2.50 | 0 | root | | time:497.1µs, loops:1, Concurrency:OFF | shuidi_data_warehouse.dwb_risk_cs_service_summary_full_d.summary_create_time, shuidi_data_warehouse.dwb_risk_cs_service_summary_full_d.encrypt_mobile, shuidi_data_warehouse.dwb_risk_cs_service_summary_full_d.first_class_content, shuidi_data_warehouse.dwb_risk_cs_service_summary_full_d.second_class_content, shuidi_data_warehouse.dwb_risk_cs_service_summary_full_d.third_class_content, shuidi_data_warehouse.dwb_risk_cs_service_summary_full_d.forth_class_content | 3.79 KB | N/A |
| └─IndexLookUp_37 | 2.50 | 0 | root | | time:496.3µs, loops:1, table_task: {total_time: 7.43ms, num: 0, concurrency: 16} | | 216 Bytes | N/A |
| ├─Limit_36(Build) | 2.50 | 0 | cop[tikv] | | time:445.2µs, loops:1, cop_task: {num: 1, max: 405µs, proc_keys: 0, rpc_num: 1, rpc_time: 387.6µs, copr_cache_hit_ratio: 0.00}, tikv_task:{time:0s, loops:1}, scan_detail: {total_process_keys: 0, total_keys: 1, rocksdb: {delete_skipped_count: 0, key_skipped_count: 0, block: {cache_hit_count: 16, read_count: 0, read_byte: 0 Bytes}}} | offset:0, count:150 | N/A | N/A |
| │ └─IndexRangeScan_34 | 2.50 | 0 | cop[tikv] | table:dwb_risk_cs_service_summary_full_d, index:index_encrypt_time(encrypt_mobile, summary_create_time) | tikv_task:{time:0s, loops:1}, scan_detail: {total_process_keys: 0, total_keys: 0, rocksdb: {delete_skipped_count: 0, key_skipped_count: 0, block: {cache_hit_count: 0, read_count: 0, read_byte: 0 Bytes}}} | range:[“QbZD73YfQvq22tytWDo4Cw==”,“QbZD73YfQvq22tytWDo4Cw==”], keep order:true, desc | N/A | N/A |
| └─TableRowIDScan_35(Probe) | 2.50 | 0 | cop[tikv] | table:dwb_risk_cs_service_summary_full_d | | keep order:false, stats:pseudo | N/A | N/A |
±-----------------------------------±--------±--------±----------±--------------------------------------------------------------------------------------------------------±------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±----------±-----+
6 rows in set (0.00 sec)

xingzhenxiang · 2023 年1 月 12 日 09:23

这…………,，理论上筛选和排序都在索引上完成了，应该更快啊

army · 2023 年1 月 12 日 10:06

你看下查询慢的时候，是否正好有写入在更新相同的行，感觉像是读写冲突，可以看下慢的时候的执行计划，rosolvelock是不是等待时间比较久

lxzkenney · 2023 年1 月 12 日 10:43

看了下对应时间点的监控，这个算读写冲突吗