本章节介绍如何利用 TiDB 提供的系统监控诊断工具，对运行负载中的查问进行排查和诊断。除了上一章节介绍的通过 EXPLAIN 语句来查看诊断查问打算问题外，本章节次要会介绍通过 TiDB Slow Query 慢查问内存表，以及 TiDB Dashboard 的可视化 Statements 性能来监控和诊断慢查问。
Slow Query 慢查问内存表
TiDB 默认会启用慢查问日志，并将执行工夫超过规定阈值的 SQL 保留到日志文件。慢查问日志罕用于定位慢查问语句，剖析和解决 SQL 的性能问题。通过零碎表 information_schema.slow_query 也能够查看以后 TiDB 节点的慢查问日志，其字段与慢查问日志文件内容统一。TiDB 从 4.0 版本开始又新增了零碎表 information_schema.cluster_slow_query，能够用于查看全副 TiDB 节点的慢查问。
本节将首先简要介绍慢查问日志的格局和字段含意，而后针对上述两种慢查问零碎表给出一些常见的查问示例。
慢查问日志示例及字段阐明
上面是一段典型的慢查问日志：
# Time: 2019-08-14T09:26:59.487776265+08:00
# Txn_start_ts: 410450924122144769
# User: root@127.0.0.1
# Conn_ID: 3086
# Query_time: 1.527627037
# Parse_time: 0.000054933
# Compile_time: 0.000129729
# Process_time: 0.07 Wait_time: 0.002 Backoff_time: 0.002 Request_count: 1 Total_keys: 131073 Process_keys: 131072 Prewrite_time: 0.335415029 Commit_time: 0.032175429 Get_commit_ts_time: 0.000177098 Local_latch_wait_time: 0.106869448 Write_keys: 131072 Write_size: 3538944 Prewrite_region: 1
# DB: test
# Is_internal: false
# Digest: 50a2e32d2abbd6c1764b1b7f2058d428ef2712b029282b776beb9506a365c0f1
# Stats: t:414652072816803841
# Num_cop_tasks: 1
# Cop_proc_avg: 0.07 Cop_proc_p90: 0.07 Cop_proc_max: 0.07 Cop_proc_addr: 172.16.5.87:20171
# Cop_wait_avg: 0 Cop_wait_p90: 0 Cop_wait_max: 0 Cop_wait_addr: 172.16.5.87:20171
# Mem_max: 525211
# Succ: true
# Plan_digest: e5f9d9746c756438a13c75ba3eedf601eecf555cdb7ad327d7092bdd041a83e7
# Plan: tidb_decode_plan('ZJAwCTMyXzcJMAkyMAlkYXRhOlRhYmxlU2Nhbl82CjEJMTBfNgkxAR0AdAEY1Dp0LCByYW5nZTpbLWluZiwraW5mXSwga2VlcCBvcmRlcjpmYWxzZSwgc3RhdHM6cHNldWRvCg==')
insert into t select * from t;以下逐个介绍慢查问日志中各个字段的含意。
留神：慢查问日志中所有工夫相干字段的单位都是秒。
(1) 慢查问根底信息：
Time：示意日志打印工夫。Query_time：示意执行该语句破费的工夫。Parse_time：示意该语句在语法解析阶段破费的工夫。Compile_time：示意该语句在查问优化阶段破费的工夫。Digest：示意该语句的 SQL 指纹。Stats：示意 table 应用的统计信息版本工夫戳。如果工夫戳显示为pseudo，示意用默认假如的统计信息。Txn_start_ts：示意事务的开始工夫戳，也就是事务的惟一 ID，能够用该值在 TiDB 日志中查找事务相干的其余日志。Is_internal：示意是否为 TiDB 外部的 SQL 语句。true示意是 TiDB 零碎外部执行的 SQL 语句，false示意是由用户执行的 SQL 语句。Index_ids：示意该语句应用的索引 ID。Succ：示意该语句是否执行胜利。Backoff_time：示意遇到须要重试的谬误时该语句在重试前期待的工夫。常见的须要重试的谬误有以下几种：遇到了 lock、Region 决裂、tikv server is busy。Plan_digest：示意 plan 的指纹。Plan：示意该语句的执行打算，运行select tidb_decode_plan('...')能够解析出具体的执行打算。Query：示意该 SQL 语句。慢日志里不会打印字段名 Query，但映射到内存表后对应的字段叫Query。
(2) 和事务执行相干的字段：
Prewrite_time：示意事务两阶段提交中第一阶段（prewrite阶段）的耗时。Commit_time：示意事务两阶段提交中第二阶段（commit阶段）的耗时。Get_commit_ts_time：示意事务两阶段提交中第二阶段（commit阶段）获取commit工夫戳的耗时。Local_latch_wait_time：示意事务两阶段提交中第二阶段（commit阶段）发动前在 TiDB 侧等锁的耗时。Write_keys：示意该事务向 TiKV 的 Write CF 写入 Key 的数量。Write_size：示意事务提交时写 key 和 value 的总大小。Prewrite_region：示意事务两阶段提交中第一阶段（prewrite阶段）波及的 TiKV Region 数量。每个 Region 会触发一次近程过程调用。
(3) 和内存应用相干的字段：
Memory_max：示意执行期间 TiDB 应用的最大内存空间，单位为byte。
(4) 和用户相干的字段：
User：示意执行语句的用户名。Conn_ID：示意用户的连贯 ID，能够用相似con:3的关键字在 TiDB 日志中查找该链接相干的其余日志。DB：示意执行语句时应用的 database。
(5) 和 TiKV Coprocessor Task 相干的字段：
Process_time：该 SQL 在 TiKV 上的解决工夫之和。因为数据会并行发到 TiKV 执行，该值可能会超过Query_time。Wait_time：示意该语句在 TiKV 上的等待时间之和。因为 TiKV 的 Coprocessor 线程数是无限的，当所有的 Coprocessor 线程都在工作的时候，申请会排队；若队列中局部申请耗时很长，前面的申请的等待时间会减少。Request_count：示意该语句发送的 Coprocessor 申请的数量。Total_keys：示意 Coprocessor 扫过的 key 的数量。Process_keys：示意 Coprocessor 解决的 key 的数量。相较于total_keys，processed_keys 不蕴含 MVCC 的旧版本。如果processed_keys和total_keys相差很大，阐明旧版本比拟多。Cop_proc_avg：cop-task 的均匀执行工夫。Cop_proc_p90：cop-task 的 P90 分位执行工夫。Cop_proc_max：cop-task 的最大执行工夫。Cop_proc_addr：执行工夫最长的 cop-task 所在地址。Cop_wait_avg：cop-task 的均匀等待时间。Cop_wait_p90：cop-task 的 P90 分位等待时间。Cop_wait_max：cop-task 的最大等待时间。Cop_wait_addr：等待时间最长的 cop-task 所在地址。
Slow Query 内存表应用排查
上面通过一些示例展现如何通过 SQL 查看 TiDB 的慢查问。
检索以后节点 Top N 慢查问
以下 SQL 用于检索以后 TiDB 节点的 Top 2 慢查问：
> select query_time, query
from information_schema.slow_query -- 检索以后 TiDB 节点的慢查问
where is_internal = false -- 排除 TiDB 外部的慢查问
order by query_time desc
limit 2;
+--------------+------------------------------------------------------------------+
| query_time | query |
+--------------+------------------------------------------------------------------+
| 12.77583857 | select * from t_slim, t_wide where t_slim.c0=t_wide.c0; |
| 0.734982725 | select t0.c0, t1.c1 from t_slim t0, t_wide t1 where t0.c0=t1.c0; |
+--------------+------------------------------------------------------------------+检索全副节点上指定用户的 Top N 慢查问
以下 SQL 会检索全副 TiDB 节点上指定用户 test 的 Top 2 慢查问：
> select query_time, query, user
from information_schema.cluster_slow_query -- 检索全副 TiDB 节点的慢查问
where is_internal = false
and user = "test"
order by query_time desc
limit 2;
+-------------+------------------------------------------------------------------+----------------+
| Query_time | query | user |
+-------------+------------------------------------------------------------------+----------------+
| 0.676408014 | select t0.c0, t1.c1 from t_slim t0, t_wide t1 where t0.c0=t1.c1; | test |
+-------------+------------------------------------------------------------------+----------------+检索同类慢查问
在失去 Top N 慢查问后，可通过 SQL 指纹持续检索同类慢查问。
-- 先获取 Top N 的慢查问和对应的 SQL 指纹
> select query_time, query, digest
from information_schema.cluster_slow_query
where is_internal = false
order by query_time desc
limit 1;
+-------------+-----------------------------+------------------------------------------------------------------+
| query_time | query | digest |
+-------------+-----------------------------+------------------------------------------------------------------+
| 0.302558006 | select * from t1 where a=1; | 4751cb6008fda383e22dacb601fde85425dc8f8cf669338d55d944bafb46a6fa |
+-------------+-----------------------------+------------------------------------------------------------------+
-- 再依据 SQL 指纹检索同类慢查问
> select query, query_time
from information_schema.cluster_slow_query
where digest = "4751cb6008fda383e22dacb601fde85425dc8f8cf669338d55d944bafb46a6fa";
+-----------------------------+-------------+
| query | query_time |
+-----------------------------+-------------+
| select * from t1 where a=1; | 0.302558006 |
| select * from t1 where a=2; | 0.401313532 |
+-----------------------------+-------------+ 检索统计信息为 pseudo 的慢查问
如果慢查问日志中的统计信息被标记为 pseudo，往往阐明 TiDB 表的统计信息更新不及时，须要运行 analyze table 手动收集统计信息。以下 SQL 能够找到这一类慢查问：
如果慢查问日志中的统计信息被标记为 pseudo，往往阐明 TiDB 表的统计信息更新不及时，须要运行 analyze table 手动收集统计信息。以下 SQL 能够找到这一类慢查问：> select query, query_time, stats
from information_schema.cluster_slow_query
where is_internal = false
and stats like '%pseudo%';
+-----------------------------+-------------+---------------------------------+
| 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 |
+-----------------------------+-------------+---------------------------------+查问执行打算发生变化的慢查问
因为统计信息不准，可能导致同类型 SQL 的执行打算产生意料之外的扭转。用以下 SQL 能够检索到哪些慢查问具备多种不同的执行打算：
> select count(distinct plan_digest) as count, digest,min(query)
from information_schema.cluster_slow_query
group by digest
having count>1
limit 3\G
***************************[1. row]***************************
count | 2
digest | 17b4518fde82e32021877878bec2bb309619d384fca944106fcaf9c93b536e94
min(query) | SELECT DISTINCT c FROM sbtest25 WHERE id BETWEEN ? AND ? ORDER BY c [arguments: (291638, 291737)];
***************************[2. row]***************************
count | 2
digest | 9337865f3e2ee71c1c2e740e773b6dd85f23ad00f8fa1f11a795e62e15fc9b23
min(query) | SELECT DISTINCT c FROM sbtest22 WHERE id BETWEEN ? AND ? ORDER BY c [arguments: (215420, 215519)];
***************************[3. row]***************************
count | 2
digest | db705c89ca2dfc1d39d10e0f30f285cbbadec7e24da4f15af461b148d8ffb020
min(query) | SELECT DISTINCT c FROM sbtest11 WHERE id BETWEEN ? AND ? ORDER BY c [arguments: (303359, 303458)];-- 借助 SQL 指纹进一步查问执行打算的详细信息
> select min(plan),plan_digest
from information_schema.cluster_slow_query
where digest='17b4518fde82e32021877878bec2bb309619d384fca944106fcaf9c93b536e94'
group by plan_digest\G
*************************** 1. row ***************************
min(plan): Sort_6 root 100.00131380758702 sbtest.sbtest25.c:asc
└─HashAgg_10 root 100.00131380758702 group by:sbtest.sbtest25.c, funcs:firstrow(sbtest.sbtest25.c)->sbtest.sbtest25.c
└─TableReader_15 root 100.00131380758702 data:TableRangeScan_14
└─TableScan_14 cop 100.00131380758702 table:sbtest25, range:[502791,502890], keep order:false
plan_digest: 6afbbd21f60ca6c6fdf3d3cd94f7c7a49dd93c00fcf8774646da492e50e204ee
*************************** 2. row ***************************
min(plan): Sort_6 root 1 sbtest.sbtest25.c:asc
└─HashAgg_12 root 1 group by:sbtest.sbtest25.c, funcs:firstrow(sbtest.sbtest25.c)->sbtest.sbtest25.c
└─TableReader_13 root 1 data:HashAgg_8
└─HashAgg_8 cop 1 group by:sbtest.sbtest25.c,
└─TableScan_11 cop 1.2440069558121831 table:sbtest25, range:[472745,472844], keep order:false统计各个节点的慢查问数量
以下 SQL 统计指定时段内各个 TiDB 节点上呈现过的慢查问数量：
> select instance, count(*)
from information_schema.cluster_slow_query
where time >= "2020-03-06 00:00:00"
and time < now()
group by instance;
+---------------+----------+
| instance | count(*) |
+---------------+----------+
| 0.0.0.0:10081 | 124 |
| 0.0.0.0:10080 | 119771 |
+---------------+----------+检索异样时段的慢查问
假设 2020-03-10 13:24:00 至 2020-03-10 13:27:00 期间发现 QPS 升高和查问响应工夫升高等问题，能够用以下 SQL 过滤出仅仅呈现在异样时段的慢查问：
> select * from
(select /*+ AGG_TO_COP(), HASH_AGG() */ count(*),
min(time),
sum(query_time) AS sum_query_time,
sum(Process_time) AS sum_process_time,
sum(Wait_time) AS sum_wait_time,
sum(Commit_time),
sum(Request_count),
sum(process_keys),
sum(Write_keys),
max(Cop_proc_max),
min(query),min(prev_stmt),
digest
from information_schema.cluster_slow_query
where time >= '2020-03-10 13:24:00'
and time < '2020-03-10 13:27:00'
adn Is_internal = false
group by digest) AS t1
where t1.digest not in
(select /*+ AGG_TO_COP(), HASH_AGG() */ digest
from information_schema.cluster_slow_query
where time >= '2020-03-10 13:20:00' -- 排除失常时段 `2020-03-10 13:20:00` ~ `2020-03-10 13:23:00` 期间的慢查问
and time < '2020-03-10 13:23:00'
group by digest)
order by t1.sum_query_time desc
limit 10\G
***************************[1. row]***************************
count(*) | 200
min(time) | 2020-03-10 13:24:27.216186
sum_query_time | 50.114126194
sum_process_time | 268.351
sum_wait_time | 8.476
sum(Commit_time) | 1.044304306
sum(Request_count) | 6077
sum(process_keys) | 202871950
sum(Write_keys) | 319500
max(Cop_proc_max) | 0.263
min(query) | delete from test.tcs2 limit 5000;
min(prev_stmt) |
digest | 24bd6d8a9b238086c9b8c3d240ad4ef32f79ce94cf5a468c0b8fe1eb5f8d03dfTiDB Dashboard 可视化 Statements
上一节介绍了利用 Slow Query 内存表来排查慢查问，但 Slow Query 只会记录超过慢日志阈值的 SQL 而短少对全副运行负载的诊断排查。本节会介绍通过应用 TiDB Dashboard 来排查定位问题查问。TiDB Dashboard 提供了 Statements 用来监控和统计 SQL，例如页面上提供了丰盛的列表信息，包含提早、执行次数、扫描行数、全表扫描次数等，用来剖析哪些类别的 SQL 语句耗时过长、耗费内存过多等状况，帮忙用户定位性能问题。
TiDB 已反对多种性能排查工具。但在多种利用场景需要下，仍有有余，例如：
1.Grafana 不能排查单条 SQL 的性能问题
2.Slow log 只记录超过慢日志阀值的 SQL
3.General log 自身对性能有肯定影响
4.Explain analyze 只能查看能够复现的问题
5.Profile 只能查看整个实例的瓶颈
因而推出可视化 Statements，能够间接在页面察看 SQL 执行状况，不须要查问零碎表，便于用户定位性能问题。
应用 TiDB Dashboard
从 4.0 版本开始，TiDB 提供了一个新的 Dashboard 运维管理工具，集成在 PD 组件上，默认地址为 http://pd-url:pd_port/dashboard。不同于 Grafana 监控是从数据库的监控视角登程，TiDB Dashboard 从 DBA 管理员角度登程，最大限度的简化管理员对 TiDB 数据库的运维，可在一个界面查看到整个分布式数据库集群的运行状况，包含数据热点、SQL 运行状况、集群信息、日志搜寻、实时性能剖析等。
查看 Statements 整体状况
登录后，在左侧点击「SQL 语句剖析」即可进入此性能页面。
在工夫区间选项框中抉择要剖析的时间段，即可失去该时段所有数据库的 SQL 语句执行统计状况。
如果只关怀某些数据库，则能够在第二个选项框中抉择相应的数据库对后果进行过滤，反对多选。
后果以表格的模式展现，并反对按不同的列对后果进行排序，如下图所示。
1. 抉择须要剖析的时间段
2. 反对按数据库过滤
3. 反对按不同的指标排序
留神：这里所指的 SQL 语句理论指的是某一类 SQL 语句。语法统一的 SQL 语句会规一化为一类雷同的 SQL 语句。
例如：
SELECT * FROM employee WHERE id IN (1, 2, 3);
select * from EMPLOYEE where ID in (4, 5);规一化为
select * from employee where id in (...);
在 SQL 类别列，点击某类 SQL 语句，能够进入该 SQL 语句的详情页查看更具体的信息，以及该 SQL 语句在不同节点上执行的统计状况。
单个 Statements 详情页要害信息如下图所示。
1.SQL 执行总时长
2. 均匀影响行数（个别是写入）
3. 均匀扫描行数（个别是读）
4. 各个节点执行指标（能够疾速定位出某个节点性能瓶颈）
Statements 参数配置
tidb_enable_stmt_summary
Statements 性能默认开启，也能够通过设置零碎变量关上，例如：
set global tidb_enable_stmt_summary = true;tidb_stmt_summary_refresh_interval
设置 performance_schema.events_statements_summary_by_digest 表的的清空周期，单位是秒 (s)，默认值是 1800，例如：
set global tidb_stmt_summary_refresh_interval = 1800;tidb_stmt_summary_history_size
设置performance_schema.events_statements_summary_by_digest_history表保留每种 SQL 的历史的数量，默认值是 24，例如：
set global tidb_stmt_summary_history_size = 24; 因为 Statements 信息是存储在内存表中，为了避免内存溢出等问题，须要限度保留的 SQL 条数和 SQL 的最大显示长度。这两个参数须要在 config.toml 的 [stmt-summary] 类别下配置：
- 通过
max-stmt-count更改保留的 SQL 品种数量，默认 200 条。当 SQL 品种超过max-stmt-count时，会移除最近没有应用的 SQL - 通过
max-sql-length更改DIGEST_TEXT和QUERY_SAMPLE_TEXT的最大显示长度，默认是 4096
留神：tidb_stmt_summary_history_size、max-stmt-count、max-sql-length 几项配置影响内存占用，倡议依据理论状况调整，不宜设置得过大。
综上所述，可视化 Statements 能够疾速定位某个 SQL 性能问题。
本文为「TiDB 查问优化及调优」系列文章的第三篇，前文咱们别离介绍了优化器的基本概念 和 TiDB 的查问打算，后续将持续对 TiDB 调整及优化查问执行打算、其余优化器开发或布局中的诊断调优性能等进行介绍。
如果您对 TiDB 的产品有任何倡议，欢送来到 internals.tidb.io 与咱们交换。
点击查看更多 TiDB 查问优化及调优文章