TiDB slow log字段含义

TiDB slow log字段含义 

Slow Query 基础信息：

• Time：表示日志打印时间。
• Query_time：表示执行这个语句花费的时间。
• Parse_time：表示这个语句在语法解析阶段花费的时间。
• Compile_time：表示这个语句在查询优化阶段花费的时间。
• Optimize_time：表示这个语句在优化查询计划阶段花费的时间。
• Wait_TS：表示这个语句在等待获取事务 TS 阶段花费的时间。
• Query：表示 SQL 语句。慢日志里面不会打印 Query，但映射到内存表后，对应的字段叫 Query。
• Digest：表示 SQL 语句的指纹。
• Txn_start_ts：表示事务的开始时间戳，也是事务的唯一 ID，可以用这个值在 TiDB 日志中查找事务相关的其他日志。
• Is_internal：表示是否为 TiDB 内部的 SQL 语句。true 表示 TiDB 系统内部执行的 SQL 语句，false 表示用户执行的 SQL 语句。
• Index_names：表示这个语句执行用到的索引。
• Stats：表示这个语句使用到的统计信息的健康状态、内部版本号、总行数、修改行数以及加载状态。pseudo 状态表示统计信息不健康。如果有尝试使用但没有完全加载的统计信息，会在之后输出其内部状态。例如，t1:439478225786634241[105000;5000][col1:allEvicted][idx1:allEvicted] 的含义如下：
  • t1：本次查询优化过程中使用了 t1 表上的统计信息
  • 439478225786634241：其内部版本号
  • 105000：统计信息中维护的总行数
  • 5000：自上次收集统计信息以来记录的修改的行数
  • col1:allEvicted：col1 列对应的统计信息没有完全加载
  • idx1:allEvicted：idx1 索引对应的统计信息没有完全加载
• Succ：表示语句是否执行成功。
• Backoff_time：表示语句遇到需要重试的错误时在重试前等待的时间。常见的需要重试的错误有以下几种：遇到了 lock、Region 分裂、tikv server is busy。
• Plan：表示语句的执行计划，用 select tidb_decode_plan('xxx...') SQL 语句可以解析出具体的执行计划。
• Binary_plan：表示以二进制格式编码后的语句的执行计划，用 select tidb_decode_binary_plan('xxx...') SQL 语句可以解析出具体的执行计划。传递的信息和 Plan 字段基本相同，但是解析出的执行计划的格式会和 Plan 字段不同。
• Prepared：表示这个语句是否是 Prepare 或 Execute 的请求。
• Plan_from_cache：表示这个语句是否命中了执行计划缓存。
• Plan_from_binding：表示这个语句是否用的绑定的执行计划。
• Has_more_results：表示这个语句的查询结果是否还有更多的数据待用户发起 fetch 命令获取。
• 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 则为最后一次执行时间。
• KV_total：表示这个语句在 TiKV/TiFlash 上所有 RPC 请求花费的时间。
• PD_total：表示这个语句在 PD 上所有 RPC 请求花费的时间。
• Backoff_total：表示这个语句在执行过程中所有 backoff 花费的时间。
• Write_sql_response_total：表示这个语句把结果发送回客户端花费的时间。
• Result_rows：表示这个语句查询结果的行数。
• Warnings：表示这个语句执行过程中产生的警告，采用 JSON 格式。通常和 SHOW WARNINGS 语句的输出结果一致，但是可能会包含 SHOW WARNINGS 中没有的警告，因而可以提供更多诊断信息。这类警告将被标记为 IsExtra: true。
• IsExplicitTxn：表示这个语句是否在一个明确声明的事务中。如果是 false，表示这个语句的事务是 autocommit=1，即语句执行完成后就自动提交的事务。

和事务执行相关的字段：

• 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 会触发一次远程过程调用。
• Wait_prewrite_binlog_time：表示事务提交时用于写 binlog 的时间。
• Resolve_lock_time：表示事务提交时遇到锁后，清理锁或者等待锁过期的时间。

和内存使用相关的字段：

• Mem_max：表示执行期间 TiDB 使用的最大内存空间，单位为 byte。

和硬盘使用相关的字段：

• Disk_max：表示执行期间 TiDB 使用的最大硬盘空间，单位为 byte。

和 SQL 执行的用户相关的字段：

• User：表示执行语句的用户名。
• Host：表示执行语句的用户地址。
• Conn_ID：表示用户的链接 ID，可以用类似 con:3 的关键字在 TiDB 日志中查找该链接相关的其他日志。
• DB：表示执行语句时使用的 database。

和 TiKV Coprocessor Task 相关的字段：

• Request_count：表示这个语句发送的 Coprocessor 请求的数量。
• Total_keys：表示 Coprocessor 扫过的 key 的数量。
• Process_time：执行 SQL 在 TiKV 的处理时间之和，因为数据会并行的发到 TiKV 执行，这个值可能会超过 Query_time。
• Wait_time：表示这个语句在 TiKV 的等待时间之和，因为 TiKV 的 Coprocessor 线程数是有限的，当所有的 Coprocessor 线程都在工作的时候，请求会排队；当队列中有某些请求耗时很长的时候，后面的请求的等待时间都会增加。
• Process_keys：表示 Coprocessor 处理的 key 的数量。相比 total_keys，processed_keys 不包含 MVCC 的旧版本。如果 processed_keys 和 total_keys 相差很大，说明旧版本比较多。
• Num_cop_tasks：表示这个语句发送的 Coprocessor 请求的数量。
• Cop_proc_avg：cop-task 的平均执行时间，包括一些无法统计的等待时间，如 RocksDB 内的 mutex。
• Cop_proc_p90：cop-task 的 P90 分位执行时间。
• Cop_proc_max：cop-task 的最大执行时间。
• Cop_proc_addr：执行时间最长的 cop-task 所在地址。
• Cop_wait_avg：cop-task 的平均等待时间，包括请求排队和获取 snapshot 时间。
• Cop_wait_p90：cop-task 的 P90 分位等待时间。
• Cop_wait_max：cop-task 的最大等待时间。
• Cop_wait_addr：等待时间最长的 cop-task 所在地址。
• Rocksdb_delete_skipped_count：RocksDB 读数据过程中已删除 Key 的扫描数。
• Rocksdb_key_skipped_count：RocksDB 扫数据时遇到的已删除 (tombstone) Key 数量。
• Rocksdb_block_cache_hit_count：RocksDB 从 Block Cache 缓存中读数据的次数。
• Rocksdb_block_read_count：RocksDB 从文件系统中读数据的次数。
• Rocksdb_block_read_byte：RocksDB 从文件系统中读数据的数据量。
• Rocksdb_block_read_time：RocksDB 从文件系统中读数据的时间。
• Cop_backoff_{backoff-type}_total_times：因某种错误造成的 backoff 总次数。
• Cop_backoff_{backoff-type}_total_time：因某种错误造成的 backoff 总时间。
• Cop_backoff_{backoff-type}_max_time：因某种错误造成的最大 backoff 时间。
• Cop_backoff_{backoff-type}_max_addr：因某种错误造成的最大 backoff 时间的 cop-task 地址。
• Cop_backoff_{backoff-type}_avg_time：因某种错误造成的平均 backoff 时间。
• Cop_backoff_{backoff-type}_p90_time：因某种错误造成的 P90 分位 backoff 时间。

backoff-type 一般有以下几种：

• tikvRPC：给 TiKV 发送 RPC 请求失败而产生的 backoff。
• tiflashRPC：给 TiFlash 发送 RPC 请求失败而产生的 backoff。
• pdRPC：给 PD 发送 RPC 请求失败而产生的 backoff。
• txnLock：遇到锁冲突后产生的 backoff。
• regionMiss：Region 发生分裂或者合并后，TiDB 的 Region 缓存信息过期导致请求失败而产生的 backoff。
• regionScheduling：Region 还在调度中，尚未选出 Leader 导致无法处理请求而产生的 backoff。
• tikvServerBusy：因为 TiKV 负载太高无法处理新请求而产生的 backoff。
• tiflashServerBusy：因为 TiFlash 负载太高无法处理新请求而产生的 backoff。
• tikvDiskFull：因为 TiKV 的磁盘满了而产生的 backoff。
• txnLockFast：因为读数据时遇到了锁而产生的 backoff。