MySQL 慢查詢日誌分析 pt-query-digest

打開查詢日誌,會記錄全部查詢

general_log=ON

general_log_file=/home/logs/mysql.log

下載安裝    官方文檔  https://www.percona.com/doc/percona-toolkit/2.2/pt-query-digest.html

wget http://www.percona.com/get/pt-query-digest

yum -y install perl-Time-HiRes

chmod +x pt-query-digest

cp pt-query-digest /usr/bin/

或者下載整套工具

wget percona.com/get/percona-toolkit.rpm

rpm -ivh percona-toolkit-2.2.13-1.noarch.rpm

wget percona.com/get/percona-toolkit.tar.gz

tar -zxvf percona-toolkit-2.2.13.tar.gz 

cd percona-toolkit-2.2.13

perl Makefile.PL

make && make install

percona-toolkit工具包的使用教程之介紹和安裝
http://blog.chinaunix.net/uid-20639775-id-3206802.html
percona-toolkit工具包的使用教程之開發工具類使用
http://blog.chinaunix.net/uid-20639775-id-3207926.html
percona-toolkit工具包的使用教程之性能類工具
http://blog.chinaunix.net/uid-20639775-id-3210834.html
percona-toolkit工具包的使用教程之配置類工具
http://blog.chinaunix.net/uid-20639775-id-3210843.html
percona-toolkit工具包的使用教程之監控類工具使用
http://blog.chinaunix.net/uid-20639775-id-3215742.html
percona-toolkit工具包的使用教程之複製類工具
http://blog.chinaunix.net/uid-20639775-id-3229211.html
percona-toolkit工具包的使用教程之系統類工具
http://blog.chinaunix.net/uid-20639775-id-3236839.html
percona-toolkit工具包的使用教程之實用類工具
http://blog.chinaunix.net/uid-20639775-id-3236864.html

MySQL 慢查詢日誌分析及可視化結果

http://www.ttlsa.com/mysql/mysql-slow-query-log-analysis-and-visualization-of-results/

用法示例

(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 '2014-04-17 09:30:00' --until '2014-04-17 10:00:00'> > slow_report3.log

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

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

(5) 針對某個用戶的慢查詢

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

(6) 查詢全部全部的全表掃描或full join的慢查詢

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_20140401

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

(9)經過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

(10)分析binlog

mysqlbinlog mysql-bin.000093 > mysql-bin000093.sql

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

(11)分析general log

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

tcpdump抓取mysql sql語句腳本

#!/bin/bash
#this script used montor mysql network traffic.echo sql

tcpdump -i eth0 -s 0 -l -w - dst port 3306 | strings | perl -e '
while(<>) { chomp; next if /^[^ ]+[ ]*$/;
    if(/^(SELECT|UPDATE|DELETE|INSERT|SET|COMMIT|ROLLBACK|CREATE|DROP|ALTER|CALL)/i)
    {
        if (defined $q) { print "$q\n"; }
        $q=$_;
    } else {
        $_ =~ s/^[ \t]+//; $q.=" $_";
    }
}

例  pt-query-digest slowquery.log

# 15s user time, 40ms system time, 28.67M rss, 180.19M vsz
# Current date: Tue Dec 29 17:17:10 2015
# Hostname: owl1
# Files: slowquery.log
# Overall: 41.77k total, 282 unique, 0.12 QPS, 0.72x concurrency _________

# Time range: 2015-12-25 18:20:35 to 2015-12-29 17:17:01
# Attribute          total     min     max     avg     95%  stddev  median
     屬性             總計     最小    最大    平均          標準    中等
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time        244824s    76us   9300s      6s   490us    189s   204us
  語句執行時間
# Lock time            15s       0      1s   351us   214us     9ms    89us
# Rows sent          9.59M       0 728.56k  240.74    0.99  10.85k    0.99
  發送到客戶端行數
# Rows examine      35.91M       0   1.42M  901.56   51.63  23.34k    2.90
  掃描行數
# Query size        11.09M       6   1.03k  278.45  621.67  170.03  192.76

# Profile
# Rank Query ID           Response time     Calls R/Call     V/M =>響應時間Variance-to-mean的比率
  排名 語句ID             響應時間          次數 平均響應時間       Item =>查詢語句一部分
# ==== ================== ================= ===== ========= ===== ========
#    1 0x813031B8BBC3B329 244241.8160 99.8%   188 1299.1586 49... COMMIT
#    2 0x9C487FF1619D928A    145.4454  0.1%    83    1.7524  0.25 SELECT t_media
#    3 0xA2C6AEC11CD4CE59    119.4845  0.0%    72    1.6595  0.21 SELECT t_activity_live
#    4 0x2AF153117E450C55     91.8681  0.0%    66    1.3919  0.20 SELECT t_relation
#    5 0x03096D125987A35D     78.8235  0.0%    58    1.3590  0.18 SELECT t_activity_record
#    8 0xB7E1D1E378B827B7     14.2656  0.0%    12    1.1888  0.15 SELECT t_user_record
# MISC 0xMISC                132.7931  0.1% 41291    0.0032   0.0 <276 ITEMS>

每條查詢語句分析 pct指的是該項佔概要報告中的百分比
# Query 1: 0.01 QPS, 0.01x concurrency, ID 0x9C487FF1619D928A at byte 272548
# Scores: V/M = 0.25
# Time range: 2015-12-25 18:20:35 to 22:40:37
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0      83
# Exec time      0    145s   541ms      3s      2s      3s   662ms      2s
# Lock time      0    14ms    79us   502us   163us   273us    71us   144us
# Rows sent      0      83       1       1       1       1       0       1
# Rows examine   0      83       1       1       1       1       0       1
# Query size     0  85.27k   1.03k   1.03k   1.03k   1.03k       0   1.03k
# String:
# Hosts        owl-test
# Users        owluser
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms  ########
#    1s  ################################################################
#  10s+
# Tables
#    SHOW TABLE STATUS LIKE 't_media'\G
#    SHOW CREATE TABLE `t_media`\G
# EXPLAIN /*!50100 PARTITIONS*/
select mediaasset0_.id as id1_16_0_, mediaasset0_.begin_time as begin_ti2_16_0_, mediaasset0_.channel_id as channel_3_16_0_, mediaasset0_.chat_url as chat_url4_16_0_,
 mediaasset0_.create_time as create_t5_16_0_, mediaasset0_.owl_id as owl_id6_16_0_, mediaasset0_.duration as duration7_16_0_, mediaasset0_.end_time as end_time8_16_0_,
  mediaasset0_.locat_desc as locat_de9_16_0_, mediaasset0_.location as locatio10_16_0_, mediaasset0_.media_type as media_t11_16_0_, mediaasset0_.origin_type as origi
  n_12_16_0_, mediaasset0_.play_state as play_st13_16_0_, mediaasset0_.player as player14_16_0_, mediaasset0_.large_poster as large_p15_16_0_, mediaasset0_.medium_po
  ster as medium_16_16_0_, mediaasset0_.small_poster as small_p17_16_0_, mediaasset0_.price as price18_16_0_, mediaasset0_.rank as rank19_16_0_, mediaasset0_.real_ti
  me as real_ti20_16_0_, mediaasset0_.short_url as short_u21_16_0_, mediaasset0_.status as status22_16_0_, mediaasset0_.tags as tags23_16_0_, mediaasset0_.title as t
  itle24_16_0_ from t_media mediaasset0_ where mediaasset0_.id=82154\G