【工具】慢日志查看 pt-query-digest.md

pt-query-digest工具可以通過慢查詢?nèi)罩句套堋⑵胀ú樵內(nèi)罩尽inlog對MySQL中的查 詢語句進行分析凫乖,也可以通過SHOW PROCESSLIST語句輸出信息峻仇,以及tcpdump 抓取的 MySQL協(xié)議數(shù)據(jù)對MySQL中的查詢語句進行分析俄讹。

官方文檔: https://www.percona.com/doc/percona-toolkit/LATEST/pt-query-digest.html

ps:個人來說還是傾向于將慢日志記錄到 slow_log表中去的

解析慢查詢?nèi)罩?/h1>
pt-query-digest /var/lib/mysql/VM_0_9_centos-slow.log > slow_report.log

輸出結(jié)果分為3部分

第一部分

匯總信息

[root@VM_0_9_centos ~]# more slow_report.log 

# 230ms user time, 20ms system time, 26.35M rss, 220.76M vsz      # CPU和內(nèi)存使用信息
# Current date: Wed Aug 26 15:44:46 2020                          # 當前時間
# Hostname: VM_0_9_centos                                          # 主機名
# Files: /var/lib/mysql/VM_0_9_centos-slow.log                      # 輸入的慢日志路徑

## 整個分析結(jié)果的匯總信息
# Overall: 258 total, 37 unique, 0.02 QPS, 0.00x concurrency _____________
# Time range: 2020-08-26T11:20:16 to 2020-08-26T15:44:11
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time             7s   249us      5s    26ms     4ms   311ms   657us
# Lock time          349ms       0   152ms     1ms   348us    12ms   194us
# Rows sent         33.01k       0   9.77k  131.03  755.64  742.92    0.99
# Rows examine      93.32k       0   9.77k  370.38  874.75  775.00   54.21
# Query size        51.71k      15   7.23k  205.23  223.14  615.30  143.84
  • Overall:總共有多少個查詢哆致,該例總共有2.58k(2580)個查詢。
  • Time range:查詢執(zhí)行的時間范圍患膛。注意摊阀,MySQL5.7版本中的時間格式不同于之 前的版本。
  • Unique:唯一查詢數(shù)量踪蹬,即對查詢條件進行參數(shù)化以后胞此,總共有多少個不同的查 詢。該例為10個跃捣。
  • Attribute:如上述代碼段所示漱牵,表示Attribute列描述的Exec time、Lock time等屬性 名稱疚漆。
* total:表示Attribute列描述的Exec time酣胀、Lock time等屬性的統(tǒng)計數(shù)值。 
* min:表示Attribute列描述的Exec time娶聘、Lock time等屬性的最小值闻镶。 
* max:表示Attribute列描述的Exec time、Lock time等屬性的最大值丸升。 
* avg:表示Attribute列描述的Exec time铆农、Lock time等屬性的平均值。 
* 95%:表示Attribute列描述的Exec time狡耻、Lock time等屬性的所有值從小到大排 列墩剖,然后取位于95%位置的那個數(shù)值(需要重點關(guān)注這個值)。 
* stddev:標準偏差夷狰,用于數(shù)值的分布統(tǒng)計岭皂。 
* median:表示Attribute列描述的Exec time、Lock time等屬性的中位數(shù)孵淘,即把所有 值從小到大排列蒲障,取位于中間的那個數(shù)值

第二部分

對查詢進行參數(shù)化并分組,然后對各類查詢的執(zhí)行情況進行分析,結(jié)果按總執(zhí)行時間從大到小排列

# Profile
# Rank Query ID                        Response time Calls R/Call V/M   It
# ==== =============================== ============= ===== ====== ===== ==
#    1 0x59A74D08D407B5EDF9A57DD5A4...  5.0003 73.7%     1 5.0003  0.00 SELECT
#    2 0x64EF0EA126730002088884A136...  0.9650 14.2%     2 0.4825  0.01 
#    3 0x5E1B3DE19F673369DCF52FE6A5...  0.3174  4.7%     2 0.1587  0.00 INSERT data_million_a
#    4 0x3992A499999D8F9E3ACC220E0F...  0.1334  2.0%     1 0.1334  0.00 ALTER TABLE dtb_table_size `dtb_table_size`
#    5 0x66CAA645BA3ED5433EADC39CCA...  0.0991  1.5%     2 0.0495  0.08 SELECT data_million_a
# MISC 0xMISC                           0.2735  4.0%   250 0.0011   0.0 <32 ITEMS>
  • Rank:為查詢生成的數(shù)字編號揉阎,表示該分類語句在整個分析結(jié)果集中的排名庄撮。
  • Query ID:為查詢生成的隨機字符串ID(根據(jù)指紋語句生成的checksum隨機字符串)。
  • Response time:該查詢的總的響應(yīng)時間和占所有查詢的總的響應(yīng)時間的百分比毙籽。
  • Calls:該查詢的執(zhí)行次數(shù)洞斯,即本次分析總共有多少條這種類型的查詢語句。
  • R/Call:該查詢平均每次執(zhí)行的響應(yīng)時間坑赡。
  • V/M:響應(yīng)時間的方差與均值的比值烙如。
  • Item:具體的查詢語句對象(標準化格式轉(zhuǎn)換的語句形式:去掉了具體的select字段和表名、where條件等)

第三部分

按照語句執(zhí)行的總時間毅否,從大到小依次打印每條語句的相關(guān)統(tǒng)計信息

# Query 1: 0 QPS, 0x concurrency, ID 0x59A74D08D407B5EDF9A57DD5A41825CA at byte 0
# Scores: V/M = 0.00
# Time range: all events occurred at 2020-08-26T11:20:16
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0       1
# Exec time     73      5s      5s      5s      5s      5s       0      5s
# Lock time      0       0       0       0       0       0       0       0
# Rows sent      0       1       1       1       1       1       0       1
# Rows examine   0       0       0       0       0       0       0       0
# Query size     0      15      15      15      15      15       0      15
# String:
# Hosts        localhost
# Users        root
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s  ################################################################
#  10s+
# EXPLAIN /*!50100 PARTITIONS*/
select sleep(5)\G
  • Time range:查詢執(zhí)行的時間范圍亚铁。注意,MySQL5.7版本中的時間格式不同于之 前的版本螟加。
  • Attribute:如上述代碼段所示徘溢,表示Attribute列描述的Count、Exec time捆探、Lock time等屬性名稱然爆。
  • pct:表示該分組語句(這里指上述代碼段中“Query 1”代表的分組語句,具體的語 句樣本在EXPLAIN ...關(guān)鍵字下面有輸出黍图。另外曾雕,在上述代碼段中,如total助被、min等計算值
    都是針對該語句分組的剖张,下文中不再贅述)的total值(該分組語句的統(tǒng)計值)與統(tǒng)計樣本 中總的所有語句統(tǒng)計值的占比。
  • total:表示Attribute列描述的Count恰起、Exec time修械、Lock time等屬性的統(tǒng)計值。
  • min:表示Attribute列描述的Exec time检盼、Lock time等屬性的最小值肯污。
  • max:表示Attribute列描述的Exec time、Lock time等屬性的最大值吨枉。
  • avg:表示Attribute列描述的Exec time蹦渣、Lock time等屬性的平均值。
  • 95%:表示語句對應(yīng)的Exec time貌亭、Lock time等屬性值從大到小排序之后柬唯,位于 95%位置的那個數(shù)值(需要重點關(guān)注這個值)。
  • stddev:標準偏差圃庭,用于數(shù)值的分布統(tǒng)計锄奢。
  • median:代表對應(yīng)屬性值的中位數(shù)失晴,將所有值從小到大排列,取位于中間的那個 數(shù)值拘央。
  • Databases:庫名涂屁。
  • Users:各個用戶執(zhí)行的次數(shù)(占比)。
  • Query_time distribution:查詢時間分布灰伟,由“#”字符表示的長短體現(xiàn)了語句執(zhí)行時 間的占比區(qū)間拆又。從上述代碼段中可以看到,執(zhí)行時間在1s左右的查詢數(shù)量占絕大多數(shù)栏账。
  • Tables:使用查詢語句中涉及的表生成的用于查詢表統(tǒng)計信息和表結(jié)構(gòu)的SQL語 句文本帖族。
  • EXPLAIN:表示查詢語句的樣本(方便復(fù)制出來查看執(zhí)行計劃。注意挡爵,該語句不 是隨機生成的竖般,而是分組語句中最差的查詢SQL語句)

使用示例

最近12小時的查詢

pt-query-digest /var/lib/mysql/VM_0_9_centos-slow.log --since=12h > slow_report_12h.log

指定時間范圍內(nèi)的查詢

pt-query-digest /var/lib/mysql/VM_0_9_centos-slow.log --since '2020-08-26 11:30:00' --until '2020-08-26 12:00:00'> slow_report_range.log

分析只是select的慢查詢

pt-query-digest /var/lib/mysql/VM_0_9_centos-slow.log --filter '$event->{fingerprint} =~ m/^select/i' > slow_report_select.log

針對某個用戶的慢查詢

pt-query-digest /var/lib/mysql/VM_0_9_centos-slow.log --filter '($event->{user} || "") =~ m/^root/i' > slow_report_db.log

查詢所有的全表掃描或FULL JOIN的慢查詢

pt-query-digest /var/lib/mysql/VM_0_9_centos-slow.log --filter '(($event->{Full_scan} || "") eq "yes") || (($event->{Full_join} || "") eq "yes")' > slow_report_full.log

將查詢分析結(jié)果保存到query_review表中

會在指定的test庫下生成 query_review 表

pt-query-digest  --user=root --password=1122333 --review h=localhost,D=yqtest,t=query_review --create-review-table --no-report /var/lib/mysql/VM_0_9_centos-slow.log

將查詢分析結(jié)果保存到query_history表中

pt-query-digest --user=root --password=1122333 --history h=localhost,D=yqtest,t=query_history --create-history-table --no-report /var/lib/mysql/VM_0_9_centos-slow.log
最后編輯于
?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請聯(lián)系作者
  • 序言:七十年代末,一起剝皮案震驚了整個濱河市了讨,隨后出現(xiàn)的幾起案子捻激,更是在濱河造成了極大的恐慌,老刑警劉巖前计,帶你破解...
    沈念sama閱讀 212,816評論 6 492
  • 序言:濱河連續(xù)發(fā)生了三起死亡事件,死亡現(xiàn)場離奇詭異垃杖,居然都是意外死亡男杈,警方通過查閱死者的電腦和手機,發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 90,729評論 3 385
  • 文/潘曉璐 我一進店門调俘,熙熙樓的掌柜王于貴愁眉苦臉地迎上來伶棒,“玉大人,你說我怎么就攤上這事彩库》粑蓿” “怎么了?”我有些...
    開封第一講書人閱讀 158,300評論 0 348
  • 文/不壞的土叔 我叫張陵骇钦,是天一觀的道長宛渐。 經(jīng)常有香客問我,道長眯搭,這世上最難降的妖魔是什么秩伞? 我笑而不...
    開封第一講書人閱讀 56,780評論 1 285
  • 正文 為了忘掉前任道媚,我火速辦了婚禮,結(jié)果婚禮上,老公的妹妹穿的比我還像新娘空入。我一直安慰自己,他們只是感情好斤寂,可當我...
    茶點故事閱讀 65,890評論 6 385
  • 文/花漫 我一把揭開白布。 她就那樣靜靜地躺著允耿,像睡著了一般。 火紅的嫁衣襯著肌膚如雪扒怖。 梳的紋絲不亂的頭發(fā)上右犹,一...
    開封第一講書人閱讀 50,084評論 1 291
  • 那天,我揣著相機與錄音姚垃,去河邊找鬼念链。 笑死,一個胖子當著我的面吹牛积糯,可吹牛的內(nèi)容都是我干的掂墓。 我是一名探鬼主播,決...
    沈念sama閱讀 39,151評論 3 410
  • 文/蒼蘭香墨 我猛地睜開眼看成,長吁一口氣:“原來是場噩夢啊……” “哼君编!你這毒婦竟也來了?” 一聲冷哼從身側(cè)響起川慌,我...
    開封第一講書人閱讀 37,912評論 0 268
  • 序言:老撾萬榮一對情侶失蹤吃嘿,失蹤者是張志新(化名)和其女友劉穎,沒想到半個月后梦重,有當?shù)厝嗽跇淞掷锇l(fā)現(xiàn)了一具尸體兑燥,經(jīng)...
    沈念sama閱讀 44,355評論 1 303
  • 正文 獨居荒郊野嶺守林人離奇死亡,尸身上長有42處帶血的膿包…… 初始之章·張勛 以下內(nèi)容為張勛視角 年9月15日...
    茶點故事閱讀 36,666評論 2 327
  • 正文 我和宋清朗相戀三年琴拧,在試婚紗的時候發(fā)現(xiàn)自己被綠了降瞳。 大學時的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片。...
    茶點故事閱讀 38,809評論 1 341
  • 序言:一個原本活蹦亂跳的男人離奇死亡蚓胸,死狀恐怖挣饥,靈堂內(nèi)的尸體忽然破棺而出,到底是詐尸還是另有隱情沛膳,我是刑警寧澤扔枫,帶...
    沈念sama閱讀 34,504評論 4 334
  • 正文 年R本政府宣布,位于F島的核電站锹安,受9級特大地震影響短荐,放射性物質(zhì)發(fā)生泄漏。R本人自食惡果不足惜八毯,卻給世界環(huán)境...
    茶點故事閱讀 40,150評論 3 317
  • 文/蒙蒙 一搓侄、第九天 我趴在偏房一處隱蔽的房頂上張望。 院中可真熱鬧话速,春花似錦讶踪、人聲如沸。這莊子的主人今日做“春日...
    開封第一講書人閱讀 30,882評論 0 21
  • 文/蒼蘭香墨 我抬頭看了看天上的太陽柱查。三九已至,卻和暖如春云石,著一層夾襖步出監(jiān)牢的瞬間唉工,已是汗流浹背。 一陣腳步聲響...
    開封第一講書人閱讀 32,121評論 1 267
  • 我被黑心中介騙來泰國打工汹忠, 沒想到剛下飛機就差點兒被人妖公主榨干…… 1. 我叫王不留淋硝,地道東北人。 一個月前我還...
    沈念sama閱讀 46,628評論 2 362
  • 正文 我出身青樓宽菜,卻偏偏與公主長得像谣膳,于是被迫代替她去往敵國和親。 傳聞我的和親對象是個殘疾皇子铅乡,可洞房花燭夜當晚...
    茶點故事閱讀 43,724評論 2 351

推薦閱讀更多精彩內(nèi)容