背景介绍
某一天早上来到公司，接到业务同学反馈，线上某个SQL之前查问速度很快，从某个工夫点开始查问速度忽然变慢了，心愿DBA帮忙查看下。业务同学反馈的原话如下：
看到这个问题，我第一工夫询问了业务对这个表的基本操作，失去的反馈如下：
- 这个表的SQL语法没有产生过变动
- 这个表的表构造近期未产生变更
- 这个表是个日志表，近期只有写入insert，没有大量delete、update操作
剖析过程
1、SQL剖析
首先，咱们来看下这条SQL（脱敏之后）：
SELECT
xxx, xxx, xxx, xxx, ....
FROM log\_xxxx\_2022\_4
WHERE 1=1
AND \`l\_mid\` = 'xxxxxxx-E527B8CD-84B-960'
AND \`l\_opertime\` < '2022-04-20 10:56:37'
AND \`l\_opertime\` >= '2022-03-20 10:56:37'
ORDER BY \`l\_opertime\` DESC LIMIT 0,20;
SQL的语义自身比较简单，是一个单表查问，不波及简单查问：
从某一张表外面，利用l\_mid和l\_opertime这两个字段作为过滤条件，输出表外面的其余字段，并依照l\_opertime排序。
2、表构造剖析
这样一条简略的SQL，如果有索引的话，应该不会呈现问题才对，咱们看下表构造：
show index from log_xxxx_2022_4;+-----------------+------------+---------------------+--------------+---------------+-----------+-------------+----------+--------+------+------------+---------+---------------+---------+------------+-----------+| Table | Non_unique | Key_name | Seq_in_index | Column_name | Collation | Cardinality | Sub_part | Packed | Null | Index_type | Comment | Index_comment | Visible | Expression | Clustered |+-----------------+------------+---------------------+--------------+---------------+-----------+-------------+----------+--------+------+------------+---------+---------------+---------+------------+-----------+| log_xxxx_2022_4 | 0 | PRIMARY | 1 | l_id | A | 0 | NULL | NULL | | BTREE | | | YES | NULL | YES || log_xxxx_2022_4 | 1 | l_oper | 1 | l_oper | A | 0 | NULL | NULL | | BTREE | | | YES | NULL | NO || log_xxxx_2022_4 | 1 | l_channel | 1 | l_channel | A | 0 | NULL | NULL | | BTREE | | | YES | NULL | NO || log_xxxx_2022_4 | 1 | l_xxxxid | 1 | l_xxxxid | A | 0 | NULL | NULL | | BTREE | | | YES | NULL | NO || log_xxxx_2022_4 | 1 | l_mid | 1 | l_mid | A | 0 | NULL | NULL | | BTREE | | | YES | NULL | NO || log_xxxx_2022_4 | 1 | l_user | 1 | l_user | A | 0 | NULL | NULL | | BTREE | | | YES | NULL | NO || log_xxxx_2022_4 | 1 | l_opertime | 1 | l_opertime | A | 0 | NULL | NULL | | BTREE | | | YES | NULL | NO || log_xxxx_2022_4 | 1 | l_xxxstatus | 1 | l_xxxstatus | A | 0 | NULL | NULL | | BTREE | | | YES | NULL | NO || log_xxxx_2022_4 | 1 | index_l_submit_time | 1 | l_submit_time | A | 0 | NULL | NULL | | BTREE | | | YES | NULL | NO |+-----------------+------------+---------------------+--------------+---------------+-----------+-------------+----------+--------+------+------------+---------+---------------+---------+------------+-----------+9 rows in set (0.00 sec)从上述索引构造，能够看进去，咱们的l\_mid字段和l\_opertime字段，都有索引。
从索引原理上看，这个SQL的执行打算至多应该是一个IndexRangeScan（索引范畴扫描）。
3、执行打算剖析
传统的MySQL中，应用Explain语句来剖析MySQL的执行打算。在TiDB中，咱们能够应用2种办法查看TiDB的执行打算：
a、Explain + SQL ：这种办法不会真正执行语句，会间接返回执行打算
b、Explain Analyze + SQL ： 这种办法会执行SQL语句，并返回SQL的执行打算
咱们应用上述办法b来查看执行打算（起因是这种办法能够看到SQL的执行工夫），上述SQL的执行打算如下：
+----------------------------------+----------+----------+-----------+-----------------------------------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------------------------------------------------------------------------+----------+------+| id | estRows | actRows | task | access object | execution info | operator info | memory | disk |+----------------------------------+----------+----------+-----------+-----------------------------------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------------------------------------------------------------------------+----------+------+| Limit_12 | 20.00 | 0 | root | | time:26.2s, loops:1 | offset:0, count:20 | N/A | N/A || └─IndexLookUp_28 | 20.00 | 0 | root | | time:26.2s, loops:1, index_task: {total_time: 26.1s, fetch_handle: 1.95s, build: 3.39s, wait: 20.7s}, table_task: {total_time: 2m6.3s, num: 1043, concurrency: 5} | | 167.2 MB | N/A || ├─IndexRangeScan_25(Build) | 20000.00 | 21180838 | cop[tikv] | table:log_xxxx_2022_4, index:l_opertime(l_opertime) | time:848.9ms, loops:20703, cop_task: {num: 23, max: 1.42s, min: 2.14ms, avg: 712.3ms, p95: 1.15s, max_proc_keys: 969873, p95_proc_keys: 960000, tot_proc: 15.1s, tot_wait: 41ms, rpc_num: 23, rpc_time: 16.4s, copr_cache_hit_ratio: 0.04}, tikv_task:{proc max:763ms, min:31ms, p80:729ms, p95:747ms, iters:20788, tasks:23}, scan_detail: {total_process_keys: 20220838, total_process_keys_size: 930158548, total_keys: 20220861, rocksdb: {delete_skipped_count: 0, key_skipped_count: 20220839, block: {cache_hit_count: 12975, read_count: 28, read_byte: 1.35 MB}}} | range:[2022-03-20 10:56:37,2022-04-20 10:56:37), keep order:true, desc, stats:pseudo | N/A | N/A || └─Selection_27(Probe) | 20.00 | 0 | cop[tikv] | | time:1m57.9s, loops:1043, cop_task: {num: 1441, max: 891.8ms, min: 848.6µs, avg: 91.2ms, p95: 286.5ms, max_proc_keys: 20992, p95_proc_keys: 20480, tot_proc: 1m51.3s, tot_wait: 17.1s, rpc_num: 1441, rpc_time: 2m11.3s, copr_cache_hit_ratio: 0.00}, tikv_task:{proc max:235ms, min:0s, p80:78ms, p95:98ms, iters:27477, tasks:1441}, scan_detail: {total_process_keys: 21180838, total_process_keys_size: 7841770073, total_keys: 21184733, rocksdb: {delete_skipped_count: 0, key_skipped_count: 55260873, block: {cache_hit_count: 239289, read_count: 83, read_byte: 622.7 KB}}} | eq(comment5_log.log_xxxx_2022_4.l_mid, "625F70C0-ABD4F004-E527B8CD-84B-960") | N/A | N/A || └─TableRowIDScan_26 | 20000.00 | 21180838 | cop[tikv] | table:log_xxxx_2022_4 | tikv_task:{proc max:231ms, min:0s, p80:76ms, p95:95ms, iters:27477, tasks:1441} | keep order:false, stats:pseudo | N/A | N/A |+----------------------------------+----------+----------+-----------+-----------------------------------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------------------------------------------------------------------------+----------+------+5 rows in set (26.15 sec)上述SQL的执行工夫是：26.15 sec
咱们对TiDB的执行打算进行剖析：
id 列：算子名称.
从图中能够看出，咱们以后的SQL算子蕴含：
IndexLookUp：先汇总 Build 端 TiKV 扫描上来的 RowID，再去 Probe 端上依据这些 RowID 准确地读取 TiKV 上的数据。
IndexFullScan：另一种“全表扫描”，扫的是索引数据，不是表数据。
TableRowIDScan：依据下层传递下来的 RowID 扫描表数据。时常在索引读操作后检索符合条件的行。
estRows 列：显示TiDB预计会解决的行数
actRows 列：显示TiDB算子理论输入的数据条数
预估扫描行数最多是2w行，然而理论的输入条数是2000w行。
task 列：显示算子在执行语句时的所在位置，root代表tidb，cop代表tikv
access object 列：代表被拜访的表对象和索引
execution info 列：算子的理论执行信息，蕴含执行工夫等
这部分内容能够看到每个步骤的执行工夫，然而不是特地直观，前面咱们会通过Dashboard页面去剖析执行工夫。
operator info 列：显示拜访表、分区、索引的其余信息
range: [2022-03-20 10:56:37,2022-04-20 10:56:37] 示意查问的 WHERE 字句 (l\_opertime = 2022-04-20 10:56:37) 被下推到了 TiKV，对应的 task 为 cop[tikv]
keep order:true 示意这个查问须要TiKV依照程序返回后果
stats：pseudo 它示意estRows显示的预估行数可能不准，TiDB定期在后盾更新统计信息，也能够通过Analyze table 来手动更新信息。
memory 列：算子占用的内存空间大小
disk 列：算子占用磁盘空间的大小
4、TiDB DashBoard剖析
上述Explain Analyze剖析的执行打算内容，execution info列不够直观。咱们看下TiDB 的Dashboard，其实也能发现一些端倪。
进入TiDB 的 Dashboard页面--->点击左侧的慢查问--->依照SQL语句（或者提炼的SQL指纹）进行搜寻--->查看SQL执行耗时状况，看到相似的SQL执行耗时状况如下：
能够看到，大部分执行耗时都在Coprocessor执行耗时阶段，其余阶段占用的工夫非常少。
值得注意的是，Coprocessor累计执行耗时看起来大于SQL执行工夫，这个是因为TiKV 会并行处理工作，因而累计执行耗时不是天然流逝工夫
咱们再看看SQL的根本信息：
从SQL根本信息上，也能够看到，以后SQL应用的统计信息是pseudo，而pseudo代表统计信息不精确，就有可能导致TiDB基于老本的执行打算抉择谬误。
解决办法
有了上述的实践根底，问题的解决就变得简略了。
依据官网文档形容，咱们应用Analyze table log\_xxxx\_2022\_4 来从新收集下这个表的统计信息，而后从新执行查问：
analyze table log_cmnt_2022_4;Query OK, 0 rows affected, 1 warning (51.11 sec)再次利用Explain Analyze查看SQL执行打算： +----------------------------------+---------+---------+-----------+-------------------------------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------------------------------------------------------------------------------------------------------------------------------------+-----------+------+| id | estRows | actRows | task | access object | execution info | operator info | memory | disk |+----------------------------------+---------+---------+-----------+-------------------------------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------------------------------------------------------------------------------------------------------------------------------------+-----------+------+| TopN_9 | 2.15 | 0 | root | | time:977µs, loops:1 | coxxxx5_log.log_xxxx_2022_4.l_opertime:desc, offset:0, count:20 | 0 Bytes | N/A || └─IndexLookUp_24 | 2.15 | 0 | root | | time:939.3µs, loops:2, | | 236 Bytes | N/A || ├─IndexRangeScan_17(Build) | 2.15 | 0 | cop[tikv] | table:log_xxxx_2022_4, index:l_mid(l_mid) | time:822.3µs, loops:1, cop_task: {num: 1, max: 749.8µs, proc_keys: 0, tot_proc: 1ms, rpc_num: 1, rpc_time: 734.8µs, copr_cache_hit_ratio: 0.00}, tikv_task:{time:1ms, loops:1}, scan_detail: {total_process_keys: 0, total_process_keys_size: 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:["625F70C0-ABD4F004-E527B8CD-84B-960","625F70C0-ABD4F004-E527B8CD-84B-960"], keep order:false | N/A | N/A || └─TopN_23(Probe) | 2.15 | 0 | cop[tikv] | | | comment5_log.log_xxxx_2022_4.l_opertime:desc, offset:0, count:20 | N/A | N/A || └─Selection_19 | 2.15 | 0 | cop[tikv] | | | ge(comxxxx5_log.log_xxxx_2022_4.l_opertime, 2022-03-20 10:56:37.000000), lt(coxxxxx5_log.log_xxxx_2022_4.l_opertime, 2022-04-20 10:56:37.000000) | N/A | N/A || └─TableRowIDScan_18 | 2.15 | 0 | cop[tikv] | table:log_xxxx_2022_4 | | keep order:false | N/A | N/A |+----------------------------------+---------+---------+-----------+-------------------------------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------------------------------------------------------------------------------------------------------------------------------------+-----------+------+6 rows in set (0.00 sec)从最新的SQL执行打算中，咱们不难发现：
1、执行打算中，预估的行数estRows，从一开始的2w行到当初的2.15行，理论执行行数actRows，从一开始的2000w行，到当初的0行，有了很大的一个改善。
2、SQL的执行工夫变成了0.00s，意味着执行工夫在10ms之内。
当初咱们比照下执行工夫：
统计信息收集之前：SQL执行26s
统计信息收集之后：SQL执行0.00s
一个Analyze操作，让整个SQL执行工夫，足足翻了1000倍还多！！！
批改之后，业务同学反馈查问速度晋升显著，监控肉眼可见：
Pseudo状态的SQL如何被动排查？如何解决？
从咱们上述案例中能够发现，如果一个表的统计信息采纳了pseudo，很可能造成查问慢的状况。因而，在理论利用中，咱们须要对应用了pseudo统计信息的SQL进行摸排，能够应用上面的办法来进行摸排：
计划1、SQL排查并手动analyze
select query, query_time, statsfrom information_schema.slow_querywhere is_internal = falseand stats like '%pseudo%';应用上述SQL查找到所有的应用了pseudo统计信息的SQL，并对它们拜访的表，手动做一次analyze table操作。
上述SQL的输入样例如下：
+-----------------------------+-------------+---------------------------------+| query | query_time | stats |+-----------------------------+-------------+---------------------------------+| select * from t1 where a=1; | 0.302558006 | t1:pseudo || select * from t1 where a=2; | 0.401313532 | t1:pseudo || select * from t1 where a>2; | 0.602011247 | t1:pseudo || select * from t1 where a>3; | 0.50077719 | t1:pseudo || select * from t1 join t2; | 0.931260518 | t1:407872303825682445,t2:pseudo |+-----------------------------+-------------+---------------------------------+计划2、批改参数：pseudo-estimate-ratio
这个参数代表批改的行数/表的总行数的比值，超过该值的时候，零碎会认为统计信息曾经过期，就会应用pseudo，这个值的默认值是0.8，最小值是0，最大值是1。它是统计信息是否生效的判断规范。
能够将这个参数调整成1，从而让TiKV执行SQL的时候不抉择pseudo统计信息。
计划3、批改参数：tidb_enable_pseudo_for_outdated_stats
这个变量用来管制TiDB优化器在某一张表上的统计信息过期之后的行为，默认值是On。
如果应用默认值On，在某张表的统计信息过期之后，代表优化器认为以后表除了总行数之外，其余的统计信息曾经生效，所以会采纳pseudo统计信息；
如果应用Off，即便一张表上的统计信息生效，也会应用以后表的统计信息，不会应用pseudo。如果你的表更新频繁，又没有即便对表进行analyze table，那么倡议应用off选项。
计划4、TiDB Dashboard排查
登录TiDB的Dashboard，点击TiDB--->statistics--->pseudo estimation OPS面板即可。
如果监控中应用Pseudo统计信息的SQL过多，那么阐明咱们的统计信息存在大量生效的状况，须要对这类SQL拜访的表从新进行信息统计。
总结
到这里，下面的问题算是解决了，咱们也晓得了如何对应用了Pseudo统计信息的SQL进行排查了。
咱们先尝试写一些总结：
1、遇到慢查问，咱们个别须要进行一系列剖析，包含SQL历史运行状态理解、SQL语义剖析、SQL拜访的表对应的表构造剖析、执行打算剖析等等
2、TiDB的Dashboard中的慢日志模块曾经帮用户整顿了相干信息，要学会借助已有的性能去排查问题。
3、问题解决后，还应该想方法从源头上杜绝问题再次发生。
其实如果更近一步去思考，既然TiDB自身会进行统计信息收集，那么它的收集策略又是怎么的呢？？？为什么它有收集统计信息的性能，咱们的表还会应用到pseudo统计信息呢？？？这些，其实都是值得思考的问题。这里我给出一点官网文档的提醒：
对于统计信息的更多细节，期待大家在实践中去摸索，去发现。:)
原作者：Asiaye 发表工夫：2022/4/26 原文链接：https://tidb.net/blog/df697598