From eda906af7dc58738eef5b6d50ed5da174448b722 Mon Sep 17 00:00:00 2001 From: Yuanjia Zhang Date: Mon, 2 Nov 2020 13:59:20 +0800 Subject: [PATCH] cherry pick #4575 to release-4.0 Signed-off-by: ti-srebot --- identify-slow-queries.md | 12 ++++++++++-- 1 file changed, 10 insertions(+), 2 deletions(-) diff --git a/identify-slow-queries.md b/identify-slow-queries.md index bbf42b4d62ad..a904918b6d12 100644 --- a/identify-slow-queries.md +++ b/identify-slow-queries.md @@ -14,11 +14,13 @@ TiDB 默认启用慢查询日志，可以修改配置 [`enable-slow-log`](/tidb- ```sql # Time: 2019-08-14T09:26:59.487776265+08:00 # Txn_start_ts: 410450924122144769 -# User: root@127.0.0.1 +# User@Host: root[root] @ localhost [127.0.0.1] # Conn_ID: 3086 +# Exec_retry_time: 5.1 Exec_retry_count: 3 # Query_time: 1.527627037 # Parse_time: 0.000054933 # Compile_time: 0.000129729 +# Rewrite_time: 0.000000003 Preproc_subqueries: 2 Preproc_subqueries_time: 0.000000002 # Process_time: 0.07 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 @@ -36,6 +38,7 @@ TiDB 默认启用慢查询日志，可以修改配置 [`enable-slow-log`](/tidb- # Plan_from_cache: false # Succ: true # Plan: tidb_decode_plan('ZJAwCTMyXzcJMAkyMAlkYXRhOlRhYmxlU2Nhbl82CjEJMTBfNgkxAR0AdAEY1Dp0LCByYW5nZTpbLWluZiwraW5mXSwga2VlcCBvcmRlcjpmYWxzZSwgc3RhdHM6cHNldWRvCg==') +use test; insert into t select * from t; ``` @@ -61,6 +64,11 @@ Slow Query 基础信息： * `Plan`：表示语句的执行计划，用 `select tidb_decode_plan('xxx...')` SQL 语句可以解析出具体的执行计划。 * `Prepared`：表示这个语句是否是 `Prepare` 或 `Execute` 的请求。 * `Plan_from_cache`：表示这个语句是否命中了执行计划缓存。 +* `Rewrite_time`：表示这个语句在查询改写阶段花费的时间。 +* `Preproc_subqueries`：表示这个语句中被提前执行的子查询个数，如 `where id in (select if from t)` 这个子查询就可能被提前执行。 +* `Preproc_subqueries_time`：表示这个语句中被提前执行的子查询耗时。 +* `Exec_retry_count`：表示这个语句执行的重试次数。一般出现在悲观事务中，上锁失败时重试执行该语句。 +* `Exec_retry_time`：表示这个语句的重试执行时间。例如某个查询一共执行了三次（前两次失败），则 `Exec_retry_time` 表示前两次的执行时间之和，`Query_time` 减去 `Exec_retry_time` 则为最后一次执行时间。 和事务执行相关的字段： @@ -113,7 +121,7 @@ Slow Query 基础信息： * [tidb_slow_log_threshold](/system-variables.md#tidb_slow_log_threshold)：设置慢日志的阈值，执行时间超过阈值的 SQL 语句将被记录到慢日志中。默认值是 300 ms。 * [tidb_query_log_max_len](/system-variables.md#tidb_query_log_max_len)：设置慢日志记录 SQL 语句的最大长度。默认值是 4096 byte。 * [tidb_log_desensitization](/system-variables.md#tidb_log_desensitization)：设置慢日志记录 SQL 时是否将用户数据脱敏用 `?` 代替。默认值是 0 ，即关闭该功能。 -* [tidb_enable_collect_execution_info](/system-variables.md#tidb_enable_collect_execution_info)：设置是否记录执行计划中各个算子的执行信息，默认值是 1。该功能对性能的影响约为 3%。开启该项后查看 `Plan` 的示例如下： +* [tidb_enable_collect_execution_info](/system-variables.md#tidb_enable_collect_execution_info)：设置是否记录执行计划中各个算子的物理执行信息，默认值是 `1`。该功能对性能的影响约为 3%。开启该项后查看 `Plan` 的示例如下： ```sql > select tidb_decode_plan('jAOIMAk1XzE3CTAJMQlmdW5jczpjb3VudChDb2x1bW4jNyktPkMJC/BMNQkxCXRpbWU6MTAuOTMxNTA1bXMsIGxvb3BzOjIJMzcyIEJ5dGVzCU4vQQoxCTMyXzE4CTAJMQlpbmRleDpTdHJlYW1BZ2dfOQkxCXQRSAwyNzY4LkgALCwgcnBjIG51bTogMQkMEXMQODg0MzUFK0hwcm9jIGtleXM6MjUwMDcJMjA2HXsIMgk1BWM2zwAAMRnIADcVyAAxHcEQNQlOL0EBBPBbCjMJMTNfMTYJMQkzMTI4MS44NTc4MTk5MDUyMTcJdGFibGU6dCwgaW5kZXg6aWR4KGEpLCByYW5nZTpbLWluZiw1MDAwMCksIGtlZXAgb3JkZXI6ZmFsc2UJMjUBrgnQVnsA');