mysql慢查詢分析工具比較與實戰


00 前言

在進行mysql性能優化的時候,第一個想到的便是查看慢sql。

但是對於慢sql有沒有什么好的工具進行分析呢?

推薦兩個工具mysqldumpslow及pt-query-digest。

mysqlslowdump較為簡單,常用命令:

#得到返回記錄最多的20個sql
mysqldumpslow -s r -t 20 slowSQl.log

# 得到平均訪問次數最多的20條sql
mysqldumpslow -s ar -t 20 slowSQl.log

如果linux上沒有安裝mysqldumpslow,yum install安裝下就行了。

本文主要說下pt-query-digest。

pt-query-digest可以非常清晰地將slowSQL分析出來,類似oracle的AWR報告。

    # Rank Query ID                        Response time   Calls R/Call V/M   
# ==== =============================== =============== ===== ====== ===== 
#    1 0xABD1DCCCCD5AA5128E10C27B34... 1246.6948 41.7%   283 4.4053  0.04 UPDATE ziweidashi_deviceinfo
#    2 0x6914B81AAD1785E50708ABD113...  877.6900 29.3%   339 2.5891  0.09 SELECT birthDay_notify
#    3 0x44D9474C6D5C58DD07B5FEEA0D...  299.4193 10.0%    71 4.2172  0.05 SELECT tmall_product_orders
#    4 0xA9BE84CBE3DAA9B1CDD9B5A9EC...  127.0137  4.2%    46 2.7612  0.04 SELECT daily_user_action_log
#    5 0xCF0E12117C971C3013142E3717...  118.3138  4.0%    49 2.4146  0.05 SELECT tmall_user_take_coupon_record
#    6 0x94263184D24186330B13193534...   97.0805  3.2%    35 2.7737  0.56 SELECT tgg_users
#    7 0xC51165F1287A2ECDA221AC1F54...   52.5870  1.8%    22 2.3903  0.04 SELECT util_user_task_log
#    8 0xB8004D6D8A7A7967E04CD81E26...   43.7895  1.5%    16 2.7368  0.08 SELECT daily_user_action_log
#    9 0x910E19224F33DAA6391927B8E8...   41.3720  1.4%    15 2.7581  1.17 SELECT qifugong_tianbi_record
# MISC 0xMISC                            86.7871  2.9%    30 2.8929   0.0 <12 ITEMS>

並且不只可以分析慢SQL日志,還可以分析binlog、general log。

此外,pt-query-digest是percona-toolkit工具包的其中一個工具。
這個工具包下還有很多實用的性能分析輔助工具。

01 安裝排坑

1、下載

# 進入安裝目錄
cd /usr/local/src

# 下載percona-toolkit 工具包
wget percona.com/get/percona-toolkit.tar.gz

# 解壓
tar zxf percona-toolkit.tar.gz

# 進入解壓文件夾
cd /usr/local/src/percona-toolkit-3.1.0

# 安裝perl模塊,制定依賴路徑
perl Makefile.PL PREFIX=/usr/local/percona-toolkit

2、報錯 prerequisite DBD::mysql 3 not found

報錯如下,找不到DBD包

[root@iZ2zebthf35ejlps5v87ksZ percona-toolkit-3.1.0]# perl Makefile.PL PREFIX=/usr/local/percona-toolkit
Checking if your kit is complete...
Looks good
Warning: prerequisite DBD::mysql 3 not found.
Warning: prerequisite DBI 1.46 not found.
Writing Makefile for percona-toolkit

百度問題,找到鏈接,https://blog.csdn.net/heizistudio/article/details/45724707?locationNum=8&fps=1

安裝依賴包

yum install perl-DBD-MySQL

然后重新執行命令

[root@iZ2zebthf35ejlps5v87ksZ percona-toolkit-3.1.0]# perl Makefile.PL PREFIX=/usr/local/percona-toolkit
Writing Makefile for percona-toolkit

3、安裝

make && make install

安裝后內容如下

……
Installing /usr/local/percona-toolkit/bin/pt-summary
Installing /usr/local/percona-toolkit/bin/pt-table-sync
Appending installation info to /usr/local/percona-toolkit/lib64/perl5/perllocal.pod

4、使用

[root@iZ2zebthf35ejlps5v87ksZ bin]# pt-query-digest /usr/local/mysql/data/slow.log
-bash: pt-query-digest: command not found

發現沒找到pt-query-digest命令,是因為bash命令默認是從/usr/bin下找的;

如果rpm安裝,會默認添加到/usr/bin下;

而我們現在是編譯二進制安裝到,並且默認是裝到了/usr/local/percona-toolkit下,發現本文件夾下有個bin目錄,pt工具都在其下。

-rwxrwxr-x 1 hc hc   41747 Sep 16  2019 pt-align
-rwxrwxr-x 1 hc hc  270675 Sep 16  2019 pt-archiver
-rwxrwxr-x 1 hc hc  170783 Sep 16  2019 pt-config-diff
-rwxrwxr-x 1 hc hc  167978 Sep 16  2019 pt-deadlock-logger
-rwxrwxr-x 1 hc hc  166450 Sep 16  2019 pt-diskstats
-rwxrwxr-x 1 hc hc  171099 Sep 16  2019 pt-duplicate-key-checker
-rwxrwxr-x 1 hc hc   50157 Sep 16  2019 pt-fifo-split
-rwxrwxr-x 1 hc hc  151809 Sep 16  2019 pt-find
-rwxrwxr-x 1 hc hc   67304 Sep 16  2019 pt-fingerprint
-rwxrwxr-x 1 hc hc  134955 Sep 16  2019 pt-fk-error-logger
-rwxrwxr-x 1 hc hc  223887 Sep 16  2019 pt-heartbeat
-rwxrwxr-x 1 hc hc  228213 Sep 16  2019 pt-index-usage
-rwxrwxr-x 1 hc hc   32405 Sep 16  2019 pt-ioprofile
-rwxrwxr-x 1 hc hc  256092 Sep 16  2019 pt-kill
-rwxrwxr-x 1 hc hc   21913 Sep 16  2019 pt-mext
-rwxrwxr-x 1 hc hc 8196032 Sep 16  2019 pt-mongodb-query-digest
-rwxrwxr-x 1 hc hc 8522944 Sep 16  2019 pt-mongodb-summary
-rwxrwxr-x 1 hc hc  108113 Sep 16  2019 pt-mysql-summary
-rwxrwxr-x 1 hc hc  426996 Sep 16  2019 pt-online-schema-change
-rwxrwxr-x 1 hc hc 4794784 Sep 16  2019 pt-pg-summary
-rwxrwxr-x 1 hc hc   24598 Sep 16  2019 pt-pmp
-rwxrwxr-x 1 hc hc  527607 Sep 16  2019 pt-query-digest
-rwxrwxr-x 1 hc hc 3624992 Sep 16  2019 pt-secure-collect
-rwxrwxr-x 1 hc hc   78242 Sep 16  2019 pt-show-grants
-rwxrwxr-x 1 hc hc   37784 Sep 16  2019 pt-sift
-rwxrwxr-x 1 hc hc  146952 Sep 16  2019 pt-slave-delay
-rwxrwxr-x 1 hc hc  131404 Sep 16  2019 pt-slave-find
-rwxrwxr-x 1 hc hc  184944 Sep 16  2019 pt-slave-restart
-rwxrwxr-x 1 hc hc   76226 Sep 16  2019 pt-stalk
-rwxrwxr-x 1 hc hc   90816 Sep 16  2019 pt-summary
-rwxrwxr-x 1 hc hc  459729 Sep 16  2019 pt-table-checksum
-rwxrwxr-x 1 hc hc  405119 Sep 16  2019 pt-table-sync
-rwxrwxr-x 1 hc hc  247743 Sep 16  2019 pt-table-usage
-rwxrwxr-x 1 hc hc  333011 Sep 16  2019 pt-upgrade
-rwxrwxr-x 1 hc hc  178415 Sep 16  2019 pt-variable-advisor
-rwxrwxr-x 1 hc hc  102545 Sep 16  2019 pt-visual-explain

本次使用到主力工具,pt-query-digest,執行命令,進行慢日志分析

./pt-query-digest /usr/local/mysql/data/slow.log

5、又報錯 Can't locate Digest/MD5.pm in @INC

[root@iZ2zebthf35ejlps5v87ksZ bin]# ./pt-query-digest /usr/local/mysql/data/slow.log
Can't locate Digest/MD5.pm in @INC (@INC contains: /usr/local/lib64/perl5 /usr/local/share/perl5 /usr/lib64/perl5/vendor_perl /usr/share/perl5/vendor_perl /usr/lib64/perl5 /usr/share/perl5 .) at ./pt-query-digest line 2470.
BEGIN failed--compilation aborted at ./pt-query-digest line 2470.

安裝perl-Digest-MD5工具

yum -y install perl-Digest-MD5

終於可以運行了

./pt-query-digest /usr/local/mysql/data/slow.log

6、無腦命令如下

yum -y install perl-DBD-MySQL
yum -y install perl-Digest-MD5

cd /usr/local/src
wget percona.com/get/percona-toolkit.tar.gz
tar zxf percona-toolkit.tar.gz
cd /usr/local/src/percona-toolkit-3.1.0
perl Makefile.PL PREFIX=/usr/local/percona-toolkit
make && make install

二、分析實戰

1、執行工具pt-query-digest

./pt-query-digest /usr/local/src/slowsqlExample/slow0312.log 

2、結果分析

找了一個慢sql,分析結果如下

[root@iZ2zebthf35ejlps5v87ksZ bin]# ./pt-query-digest /usr/local/src/slowsqlExample/slow0312.log 

第一部分
該工具執行日志分析的用戶時間,系統時間,物理內存占用大小,虛擬內存占用大小
# 360ms user time, 10ms system time, 22.56M rss, 187.09M vsz
工具執行時間
# Current date: Fri Mar 20 22:54:14 2020
運行分析工具的主機名    
# Hostname: iZ2zebthf35ejlps5v87ksZ
被分析的文件名
# Files: /usr/local/src/slowsqlExample/slow0312.log
語句總數量,唯一的語句數量,QPS,並發數
# Overall: 906 total, 21 unique, 0.02 QPS, 0.07x concurrency _____________
日志記錄的時間范圍
# Time range: 2020-03-11 12:22:13 to 2020-03-12 00:16:57
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
語句執行時間
# Exec time          2991s      2s     10s      3s      5s      1s      3s
鎖占用時間
# Lock time          552ms    24us   371ms   609us   103us    12ms    57us
發送到客戶端的行數
# Rows sent        167.53k       0  17.99k  189.35  487.09   1.22k       0
select語句掃描行數
# Rows examine     980.73M     238   1.96M   1.08M   1.95M 757.80k 753.18k
查詢的字符數
# Query size       258.71k      17   1.77k  292.41  463.90  202.02  329.68


第二部分
# Profile
Rank:所有語句的排名,默認按查詢時間降序排列,通過--order-by指定
Query ID:語句的ID,(去掉多余空格和文本字符,計算hash值)
Response:總的響應時間
time:該查詢在本次分析中總的時間占比
calls:執行次數,即本次分析總共有多少條這種類型的查詢語句
R/Call:平均每次執行的響應時間
V/M:響應時間Variance-to-mean的比率
Item:查詢對象
# Rank Query ID                        Response time   Calls R/Call V/M   
# ==== =============================== =============== ===== ====== ===== 
#    1 0xABD1DCCCCD5AA5128E10C27B34... 1246.6948 41.7%   283 4.4053  0.04 UPDATE ziweidashi_deviceinfo
#    2 0x6914B81AAD1785E50708ABD113...  877.6900 29.3%   339 2.5891  0.09 SELECT birthDay_notify
#    3 0x44D9474C6D5C58DD07B5FEEA0D...  299.4193 10.0%    71 4.2172  0.05 SELECT tmall_product_orders
#    4 0xA9BE84CBE3DAA9B1CDD9B5A9EC...  127.0137  4.2%    46 2.7612  0.04 SELECT daily_user_action_log
#    5 0xCF0E12117C971C3013142E3717...  118.3138  4.0%    49 2.4146  0.05 SELECT tmall_user_take_coupon_record
#    6 0x94263184D24186330B13193534...   97.0805  3.2%    35 2.7737  0.56 SELECT tgg_users
#    7 0xC51165F1287A2ECDA221AC1F54...   52.5870  1.8%    22 2.3903  0.04 SELECT util_user_task_log
#    8 0xB8004D6D8A7A7967E04CD81E26...   43.7895  1.5%    16 2.7368  0.08 SELECT daily_user_action_log
#    9 0x910E19224F33DAA6391927B8E8...   41.3720  1.4%    15 2.7581  1.17 SELECT qifugong_tianbi_record
# MISC 0xMISC                            86.7871  2.9%    30 2.8929   0.0 <12 ITEMS>


第三及后續部分,第一條查詢語句 query id:0xABD1DCCCCD5AA5128E10C27B34BC04E7
# Query 1: 0.01 QPS, 0.03x concurrency, ID 0xABD1DCCCCD5AA5128E10C27B34BC04E7 at byte 355748
# Scores: V/M = 0.04
# Time range: 2020-03-11 12:24:03 to 2020-03-12 00:16:13
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         31     283
# Exec time     41   1247s      4s      8s      4s      5s   437ms      4s
# Lock time     69   386ms    24us   371ms     1ms    93us    21ms    44us
# Rows sent      0       0       0       0       0       0       0       0
# Rows examine  18 180.00M 651.14k 651.45k 651.29k 650.62k       0 650.62k
# Query size    10  27.64k     100     100     100     100       0     100
# String:
數據庫名
# Databases    taxen_ziweidashi
執行主機
# Hosts        118.190.93.166
執行用戶
# Users        devAccount
查詢時間占比
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s  ################################################################
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `taxen_ziweidashi` LIKE 'ziweidashi_deviceinfo'\G
#    SHOW CREATE TABLE `taxen_ziweidashi`.`ziweidashi_deviceinfo`\G
UPDATE ziweidashi_deviceinfo
         SET expired = 1 
        WHERE createTime   <=   1583942580685\G
# Converted for EXPLAIN
# EXPLAIN /*!50100 PARTITIONS*/
select  expired = 1 from ziweidashi_deviceinfo where  createTime   <=   1583942580685\G

# Query 2: 0.03 QPS, 0.07x concurrency, ID 0x6914B81AAD1785E50708ABD11319E02E at byte 13829
# Scores: V/M = 0.09
# Time range: 2020-03-11 12:22:13 to 16:05:47
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         37     339
# Exec time     29    878s      2s      4s      3s      4s   472ms      2s
# Lock time      5    29ms    31us     4ms    86us    98us   229us    66us
# Rows sent      0      24       0       2    0.07       0    0.32       0
# Rows examine  67 665.20M   1.96M   1.96M   1.96M   1.96M       0   1.96M
# Query size    59 154.47k     462     467  466.60  463.90    2.07  463.90
# String:
# Hosts        10.66.186.115
# Users        root
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s  ################################################################
#  10s+
# Tables
#    SHOW TABLE STATUS LIKE 'birthDay_notify'\G
#    SHOW CREATE TABLE `birthDay_notify`\G
# EXPLAIN /*!50100 PARTITIONS*/
select birthdayno0_.id as id1_1_, birthdayno0_.index_card_show_date as index_ca2_1_, birthdayno0_.userId as userId3_1_, birthdayno0_.push_content as push_con4_1_, birthdayno0_.card_content as card_con5_1_, birthdayno0_.birthday_userId as birthday6_1_, birthdayno0_.birthday_contactId as birthday7_1_, birthdayno0_.need_push as need_pus8_1_ from birthDay_notify birthdayno0_ where birthdayno0_.userId=1304747 and birthdayno0_.index_card_show_date='2020-03-11 00:00:00'\G

……省略

3、實例優化

找出這幾條語句,對症下葯,進行寫法的修改、索引的設計,基本可以解決慢SQL問題。

例如query1的語句

    UPDATE ziweidashi_deviceinfo
         SET expired = 1 
        WHERE createTime   <=   1583942580685

分析后發現,這張表大部分數據的expired字段都是1,每次update都相當於全表查詢、鎖定了一次。

從邏輯上分析,是expired不等於1才修改的。

可以修改為

UPDATE ziweidashi_deviceinfo
         SET expired = 1 
        WHERE createTime   <=   1583942580685
        and expired != 1

直接從平均的5秒執行時間降低到了0.04秒。

其他語句類似。

三、常用命令

1.分析慢查詢文件

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

2.分析最近12小時內的查詢

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

3.分析指定時間范圍內的查詢

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

4、通過tcpdump抓取mysql的tcp協議數據,然后再分析

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

5、分析binlog

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

6、分析general log

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

四、參考資料

1、高性能mysql(第三版)

2、MySQL慢查詢分析工具pt-query-digest詳解 作者:楓葉工作室。

3、Warning: prerequisite DBD::mysql 3 not found 作者:ora600

4、使用lcov時遇到錯誤can't locate Digest/MD5.pm in @INC (@INC contains: /usr/local/lib64/perl5 ...的錯誤 作者:迷茫的葉

5、percona官網


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM