TiDB 會(huì)將執(zhí)行時(shí)間超過(guò)slow-threshold（默認(rèn)值為300 毫秒）的語(yǔ)句輸出到slow-query-file（默認(rèn)值：”tidb-slow.log”）日志文件中，用于幫助用戶定位慢查詢語(yǔ)句，分析和解決SQL 執(zhí)行的性能問(wèn)題。

慢查詢?nèi)罩疚恢?/span>

通過(guò)命令showvariables like ‘%slow%’; 查看當(dāng)前slowlog位置

慢查詢?nèi)罩靖袷浇馕?/span>

Slow Query 基礎(chǔ)信息：

Time：表示日志打印時(shí)間。

Query_time：表示執(zhí)行這個(gè)語(yǔ)句花費(fèi)的時(shí)間。

Query：表示SQL 語(yǔ)句。慢日志里面不會(huì)打印Query，但映射到內(nèi)存表后，對(duì)應(yīng)的字段叫Query。

Digest：表示SQL 語(yǔ)句的指紋。

Txn_start_ts：表示事務(wù)的開始時(shí)間戳，也是事務(wù)的唯一ID，可以用這個(gè)值在TiDB 日志中查找事務(wù)相關(guān)的其他日志。

Is_internal：表示是否為TiDB 內(nèi)部的SQL 語(yǔ)句。true表示 TiDB系統(tǒng)內(nèi)部執(zhí)行的 SQL語(yǔ)句，false表示用戶執(zhí)行的 SQL語(yǔ)句。

Index_ids：表示語(yǔ)句涉及到的索引的ID。

Succ：表示語(yǔ)句是否執(zhí)行成功。

Backoff_time：表示語(yǔ)句遇到需要重試的錯(cuò)誤時(shí)在重試前等待的時(shí)間，常見(jiàn)的需要重試的錯(cuò)誤有以下幾種：遇到了lock、Region分裂、tikvserver is busy。

和內(nèi)存使用相關(guān)的字段

Memory_max：表示執(zhí)行期間TiDB 使用的最大內(nèi)存空間，單位為byte。

和SQL 執(zhí)行的用戶相關(guān)的字段：

User：表示執(zhí)行語(yǔ)句的用戶名。

Conn_ID：表示用戶的鏈接ID，可以用類似con:3 的關(guān)鍵字在TiDB 日志中查找該鏈接相關(guān)的其他日志。

DB：表示執(zhí)行語(yǔ)句時(shí)使用的database。

和TiKV Coprocessor Task 相關(guān)的字段：

Request_count：表示這個(gè)語(yǔ)句發(fā)送的Coprocessor 請(qǐng)求的數(shù)量。

Total_keys：表示Coprocessor 掃過(guò)的key 的數(shù)量。

Process_time：執(zhí)行SQL 在 TiKV的處理時(shí)間之和，因?yàn)閿?shù)據(jù)會(huì)并行的發(fā)到TiKV 執(zhí)行，這個(gè)值可能會(huì)超過(guò)Query_time。

Wait_time：表示這個(gè)語(yǔ)句在TiKV 的等待時(shí)間之和，因?yàn)門iKV 的Coprocessor 線程數(shù)是有限的，當(dāng)所有的Coprocessor線程都在工作的時(shí)候，請(qǐng)求會(huì)排隊(duì)；當(dāng)隊(duì)列中有某些請(qǐng)求耗時(shí)很長(zhǎng)的時(shí)候，后面的請(qǐng)求的等待時(shí)間都會(huì)增加。

Process_keys：表示Coprocessor 處理的key 的數(shù)量。相比total_keys，processed_keys不包含 MVCC的舊版本。如果processed_keys 和total_keys 相差很大，說(shuō)明舊版本比較多。

Cop_proc_avg：cop-task的平均執(zhí)行時(shí)間。

Cop_proc_p90：cop-task的 P90 分位執(zhí)行時(shí)間。

Cop_proc_max：cop-task的最大執(zhí)行時(shí)間。

Cop_proc_addr：執(zhí)行時(shí)間最長(zhǎng)的cop-task 所在地址。

Cop_wait_avg：cop-task的平均等待時(shí)間。

Cop_wait_p90：cop-task的 P90 分位等待時(shí)間。

Cop_wait_max：cop-task的最大等待時(shí)間。

Cop_wait_addr：等待時(shí)間最長(zhǎng)的cop-task 所在地址。

通過(guò)在sql命令窗口查看慢查詢語(yǔ)句

搜索Top N 的慢查詢

select query_time,query

frominformation_schema.slow_query

where is_internal =false  -- 排除 TiDB內(nèi)部的慢查詢 SQL

order by query_timedesc

limit 2;

時(shí)間單位為秒

這是之前測(cè)試數(shù)據(jù)時(shí)，執(zhí)行的插入語(yǔ)句，被tidb判斷為慢查詢，因?yàn)闆](méi)有索引

搜索某個(gè)用戶的Top N 慢查詢

select query_time,query, user

frominformation_schema.slow_query

where is_internal =false  -- 排除 TiDB內(nèi)部的慢查詢 SQL

and user = "test"       -- 查找的用戶名

order by query_timedesc

limit 2;

根據(jù)SQL 指紋搜索同類慢查詢

先根據(jù)topn查詢到digest值，再查詢指紋值

select query_time,query, digest

frominformation_schema.slow_query

where is_internal =false

order by query_timedesc

limit 1;

select query,query_time

frominformation_schema.slow_query

where digest ="31a61be6ba3e5a51b26372ba82e6cdc7b517e73630af5937ad7b607500375aac";

搜索統(tǒng)計(jì)信息為pseudo 的慢查詢SQL 語(yǔ)句

select query,query_time, stats

frominformation_schema.slow_query

where is_internal =false

and stats like%pseudo%;

跟MySQL一樣，使用pt-query-digest查看tidb的慢日志同樣可以分析慢查詢

pt-query-digest/data/deploy/log/tidb_slow_query.log

pt-query-digest輸出結(jié)果分析

第一部分：總體統(tǒng)計(jì)結(jié)果

Overall：總共有多少條查詢

Time range：查詢執(zhí)行的時(shí)間范圍

unique：唯一查詢數(shù)量，即對(duì)查詢條件進(jìn)行參數(shù)化以后，總共有多少個(gè)不同的查詢

total：總計(jì)  min：最小  max：最大 avg：平均

95%：把所有值從小到大排列，位置位于95%的那個(gè)數(shù)，這個(gè)數(shù)一般最具有參考價(jià)值

median：中位數(shù)，把所有值從小到大排列，位置位于中間那個(gè)數(shù)

第二部分：查詢分組統(tǒng)計(jì)結(jié)果

Rank：所有語(yǔ)句的排名，默認(rèn)按查詢時(shí)間降序排列，通過(guò)--order-by指定

QueryID：語(yǔ)句的ID，（去掉多余空格和文本字符，計(jì)算hash值）

Response：總的響應(yīng)時(shí)間

time：該查詢?cè)诒敬畏治鲋锌偟臅r(shí)間占比

calls：執(zhí)行次數(shù)，即本次分析總共有多少條這種類型的查詢語(yǔ)句

R/Call：平均每次執(zhí)行的響應(yīng)時(shí)間

V/M：響應(yīng)時(shí)間Variance-to-mean的比率

Item：查詢對(duì)象

第三部分：每一種查詢的詳細(xì)統(tǒng)計(jì)結(jié)果

由下面查詢的詳細(xì)統(tǒng)計(jì)結(jié)果，最上面的表格列出了執(zhí)行次數(shù)、最大、最小、平均、95%等各項(xiàng)目的統(tǒng)計(jì)。

ID：查詢的ID號(hào)，和上圖的QueryID對(duì)應(yīng)

Databases：數(shù)據(jù)庫(kù)名

Users：各個(gè)用戶執(zhí)行的次數(shù)（占比）

Query_timedistribution ：查詢時(shí)間分布,長(zhǎng)短體現(xiàn)區(qū)間占比，本例中1s-10s之間查詢數(shù)量是10s以上的兩倍。

Tables：查詢中涉及到的表

Explain：SQL語(yǔ)句

PT-QUERY-DIGEST用法示例：

1.直接分析慢查詢文件:

pt-query-digest slow.log > slow_report.log

2.分析最近12小時(shí)內(nèi)的查詢：

pt-query-digest --since=12h  slow.log > slow_report2.log

3.分析指定時(shí)間范圍內(nèi)的查詢：

pt-query-digestslow.log --since 2017-01-07 09:30:00 --until 2017-01-07 10:00:00>> slow_report3.log

4.分析指含有select語(yǔ)句的慢查詢

pt-query-digest--filter $event->{fingerprint} =~ m/^select/i slow.log>slow_report4.log

5.針對(duì)某個(gè)用戶的慢查詢

pt-query-digest--filter ($event->{user} || "") =~ m/^root/i slow.log>slow_report5.log

6.查詢所有所有的全表掃描或fulljoin的慢查詢

pt-query-digest--filter (($event->{Full_scan} || "") eq "yes")||(($event->{Full_join} || "") eq "yes")slow.log> slow_report6.log

7.把查詢保存到query_review表

pt-query-digest--user=root –password=abc123 --review h=localhost,D=test,t=query_review--create-review-table  slow.log

8.把查詢保存到query_history表

pt-query-digest --user=root –password=abc123 --review h=localhost,D=test,t=query_history--create-review-table slow.log_0001

pt-query-digest --user=root –password=abc123 --review h=localhost,D=test,t=query_history--create-review-table slow.log_0002

9.通過(guò)tcpdump抓取mysql的tcp協(xié)議數(shù)據(jù)，然后再分析

tcpdump -s 65535 -x-nn -q -tttt -i any -c 1000 port 3306 > mysql.tcp.txt

pt-query-digest--type tcpdump mysql.tcp.txt> slow_report9.log

10.分析binlog

mysqlbinlogmysql-bin.000093 > mysql-bin000093.sql

pt-query-digest --type=binlog  mysql-bin000093.sql > slow_report10.log

11.分析generallog

pt-query-digest --type=genlog  localhost.log > slow_report11.log

在tidb中并不是所有SLOW_QUERY 的語(yǔ)句都是有問(wèn)題的。真正會(huì)造成集群整體壓力增大的，是那些process_time 很大的語(yǔ)句。wait_time很大，但 process_time很小的語(yǔ)句通常不是問(wèn)題語(yǔ)句，是因?yàn)楸粏?wèn)題語(yǔ)句阻塞，在執(zhí)行隊(duì)列等待造成的響應(yīng)時(shí)間過(guò)長(zhǎng)。所以我們可以使用adminshow slow 命令直接定位慢查詢語(yǔ)句。通過(guò)查找到問(wèn)題語(yǔ)句后,通過(guò)對(duì)應(yīng)的優(yōu)化手段進(jìn)行優(yōu)化,如索引分析,統(tǒng)計(jì)信息收集等.

admin show slowrecent N;

admin show slow top[internal | all] N;

例如：

admin show slow top3;

admin show slow topinternal 3;

admin show slow topall 5;

由于內(nèi)存限制，保留的慢查詢記錄的條數(shù)是有限的。當(dāng)命令查詢的 N 大于記錄條數(shù)時(shí)，返回的結(jié)果記錄條數(shù)會(huì)小于 N。

輸出內(nèi)容詳細(xì)說(shuō)明，如下：