mysql慢查詢(xún)功能詳細介紹

這篇文章主要講解了“慢查詢(xún)功能詳細介紹”，文中的講解內容簡(jiǎn)單清晰，易于學(xué)習與理解，下面請大家跟著(zhù)小編的思路慢慢深入，一起來(lái)研究和學(xué)習“mysql慢查詢(xún)功能詳細介紹”吧！

開(kāi)啟mysql慢查詢(xún)日志
1.查看當前慢查詢(xún)設置情況

#查看慢查詢(xún)時(shí)間，默認10s，建議降到1s或以下，
mysql> show variables like "long_query_time";
+-----------------+----------+
| Variable_name   | Value    |
+-----------------+----------+
| long_query_time | 1.000000 |
+-----------------+----------+
1 row in set (0.00 sec)
#查看慢查詢(xún)配置情況
mysql> show variables like "%slow%";
+-----------------------------------+----------------------+
| Variable_name                     | Value                |
+-----------------------------------+----------------------+
| log_slow_admin_statements         | OFF                  |
| log_slow_filter                   |                      |
| log_slow_rate_limit               | 1                    |
| log_slow_rate_type                | session              |
| log_slow_slave_statements         | OFF                  |
| log_slow_sp_statements            | ON                   |
| log_slow_verbosity                |                      |
| max_slowlog_files                 | 0                    |
| max_slowlog_size                  | 0                    |
| slow_launch_time                  | 2                    |
| slow_query_log                    | ON                   |
| slow_query_log_always_write_time  | 10.000000            |
| slow_query_log_file               | /tmp/slow_querys.log |
| slow_query_log_use_global_control |                      |
+-----------------------------------+----------------------+
14 rows in set (0.01 sec)

其中，slow_query_log的值是on就是已開(kāi)啟功能了。

2.如何開(kāi)啟慢查詢(xún)功能
方法一：在上找到mysql的配置文件my.cnf , 然后再mysqld模塊里追加一下內容，這樣的好處是會(huì )一直生效，不好就是需要重啟mysql進(jìn)程。

vim my.cnf
[mysqld]
slow_query_log = ON
#定義慢查詢(xún)日志的路徑
slow_query_log_file = /tmp/slow_querys.log
#定義查過(guò)多少秒的查詢(xún)算是慢查詢(xún)，我這里定義的是1秒，5.6之后允許設置少于1秒，例如0.1秒
long_query_time = 1
#用來(lái)設置是否記錄沒(méi)有使用索引的查詢(xún)到慢查詢(xún)記錄,默認關(guān)閉,看需求開(kāi)啟,會(huì )產(chǎn)生很多日志,可動(dòng)態(tài)修改
#log-queries-not-using-indexes
管理指令也會(huì )被記錄到慢查詢(xún)。比如OPTIMEZE TABLE, ALTER TABLE,默認關(guān)閉,看需求開(kāi)啟,會(huì )產(chǎn)生很多日志,可動(dòng)態(tài)修改
#log-slow-admin-statements

然后重啟mysql服務(wù)器即可，這是通過(guò)一下命令看一下慢查詢(xún)日志的情況：

tail -f /tmp/slow_querys.log

方法二：通過(guò)修改mysql的全局變量來(lái)處理，這樣做的好處是，不用重啟mysql服務(wù)器，登陸到mysql上執行一下sql腳本即可，不過(guò)重啟后就失效了。

#開(kāi)啟慢查詢(xún)功能，1是開(kāi)啟，0是關(guān)閉
mysql> set global slow_query_log=1;
#定義查過(guò)多少秒的查詢(xún)算是慢查詢(xún)，我這里定義的是1秒，5.6之后允許設置少于1秒，例如0.1秒
mysql> set global long_query_time=1;
#定義慢查詢(xún)日志的路徑
mysql> set global slow_query_log_file='/tmp/slow_querys.log';
#關(guān)閉功能：set global slow_query_log=0;
然后通過(guò)一下命令查看是否成功
mysql> show variables like 'long%'; 
mysql> show variables like 'slow%';
#設置慢查詢(xún)記錄到表中
#set global log_output='TABLE';

當然了，你也可以?xún)烧吆弦?，一方面不用重啟mysql進(jìn)程就能生效，另一方面也不用怕重啟后參數失效，效果也是一致的。

特別要注意的是long_query_time的設置，5.6之后支持設置低于0.1秒，所以記錄的詳細程度，就看你自己的需求，數據庫容量比較大的，超過(guò)0.1秒還是比較多，所以就變得有點(diǎn)不合理了。

慢查詢(xún)日志的記錄定義

直接查看mysql的慢查詢(xún)日志分析，比如我們可以tail -f  slow_query.log查看里面的內容

tail -f  slow_query.log
# Time: 110107 16:22:11
# User@Host: root[root] @ localhost []
# Query_time: 9.869362 Lock_time: 0.000035 Rows_sent: 1 Rows_examined: 6261774
SET timestamp=1294388531;
select count(*) from ep_friends;

字段意義解析：

第一行,SQL查詢(xún)執行的時(shí)間
第二行,執行SQL查詢(xún)的連接信息，用戶(hù)和連接IP
第三行,記錄了一些我們比較有用的信息，如下解析
    Query_time,這條SQL執行的時(shí)間,越長(cháng)則越慢
    Lock_time,在MySQL服務(wù)器階段(不是在存儲引擎階段)等待表鎖時(shí)間
    Rows_sent,查詢(xún)返回的行數
    Rows_examined,查詢(xún)檢查的行數，越長(cháng)就當然越費時(shí)間

第四行,設置時(shí)間戳，沒(méi)有實(shí)際意義，只是和第一行對應執行時(shí)間。

第五行及后面所有行（第二個(gè)# Time:之前）,執行的sql語(yǔ)句記錄信息，因為sql可能會(huì )很長(cháng)。

分析慢查詢(xún)的軟件

雖然慢查詢(xún)日志已經(jīng)夠清晰，但是往往我們的日志記錄到的不是只有一條sql，可能有很多很多條，如果不加以統計，估計要看到猴年馬月，這個(gè)時(shí)候就需要做統計分析了。

方法一：使用mysql程序自帶的mysqldumpslow命令分析，例如：
mysqldumpslow -s c -t 10 /tmp/slow-log
這會(huì )輸出記錄次數最多的10條SQL語(yǔ)句，得出的結果和上面一般慢查詢(xún)記錄的格式?jīng)]什么太大差別，這里就不展開(kāi)來(lái)詳細解析了。

參數解析：
-s：是表示按照何種方式排序，子參數如下：

    c、t、l、r：分別是按照記錄次數、時(shí)間、查詢(xún)時(shí)間、返回的記錄數來(lái)排序，

    ac、at、al、ar：表示相應的倒敘；

-t：返回前面多少條的數據，這里意思就是返回10條數據了（也可以說(shuō)是前十）

-g：后邊可以寫(xiě)一個(gè)正則匹配模式，大小寫(xiě)不敏感的，比如：
    /path/mysqldumpslow -s r -t 10 /tmp/slow-log，得到返回記錄集最多的10個(gè)查詢(xún)。
    /path/mysqldumpslow -s t -t 10 -g “l(fā)eft join” /tmp/slow-log，得到按照時(shí)間排序的前10條里面含有左連接的查詢(xún)語(yǔ)句。

方法二：使用pt(Percona Toolkit)工具的pt-query-digest進(jìn)行統計分析。這個(gè)是由Percona公司出品的一個(gè)用perl編寫(xiě)的腳本，只有安裝上pt工具集才會(huì )存在，有興趣的朋友就要先安裝pt工具了。直接分析慢查詢(xún)文件，執行如下：

pt-query-digest slow_querys.log >t.txt

因為記錄里還是可能有很多sql在，看起來(lái)還是費勁，所以建議輸出到文件來(lái)看了。輸出的信息會(huì )分成三部分，

第一部分：總體統計結果

# 580ms user time, 0 system time, 35.46M rss, 100.01M vsz
# Current date: Wed Jul 19 14:32:40 2017
# Hostname: yztserver1
# Files: slow_querys.log
# Overall: 2.63k total, 36 unique, 0.03 QPS, 0.03x concurrency ___________
# Time range: 2017-07-18T03:17:17 to 2017-07-19T06:30:18
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time          3145s      1s      5s      1s      2s   258ms      1s
# Lock time          677ms       0    64ms   257us   260us     2ms   144us
# Rows sent          8.44k       0   5.50k    3.29    0.99  108.92    0.99
# Rows examine       1.06G       0   2.12M 421.02k 619.64k 155.33k 419.40k
# Rows affecte           0       0       0       0       0       0       0
# Bytes sent         9.00M      11   6.24M   3.51k  13.78k 119.76k   65.89
# Query size       735.85k       6   2.19k  286.72  463.90  128.05  246.02

記錄這個(gè)慢日志文件里面的所有慢查詢(xún)統計信息，通常粗略看看就好了:

Overall: 這個(gè)文件里總共有多少條查詢(xún)，上例為總共2.63k個(gè)查詢(xún)，也就是2.63k條慢查詢(xún)。
Time range: 查詢(xún)執行的時(shí)間范圍。
unique: 唯一查詢(xún)數量，即對查詢(xún)條件進(jìn)行參數化以后，統計的總共有多少個(gè)不同的查詢(xún)，該例為36。也就是說(shuō)這2.63K條慢查詢(xún)，實(shí)際歸類(lèi)為36條。

Attribute：屬性解析，其他子項：

    total: 總計，min:最小，max: 最大，avg:平均，

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

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

其他就字面意思，去翻譯一下就好。

第二部分：查詢(xún)分組統計結果

# Profile
# Rank Query ID           Response time   Calls R/Call V/M   Item
# ==== ================== =============== ===== ====== ===== =============
#    1 0x8965CC929FB1C7B2 2080.0546 66.1%  1816 1.1454  0.03 SELECT 1 
#    2 0x9C57D04CEA1970B4  228.4754  7.3%   131 1.7441  0.10 SELECT 2 
#    3 0x94B4D7AA44982464  138.5964  4.4%   112 1.2375  0.05 SELECT 3
#    4 0x6BD09392D1D0B5D7   84.1681  2.7%    70 1.2024  0.03 SELECT 4 
#    5 0x1E9926677DBA3657   81.2260  2.6%    68 1.1945  0.03 SELECT 5 
#    6 0xBBCE31227D8C6A93   69.6594  2.2%    56 1.2439  0.05 SELECT 6
#    7 0x9A691CB1A14640F4   60.4517  1.9%    51 1.1853  0.04 SELECT 7 
#    8 0xDA99A20C8BE81B9C   55.7751  1.8%    46 1.2125  0.05 SELECT 8 
#    9 0x1F53AC684A365326   55.6378  1.8%    45 1.2364  0.03 SELECT 9_ 
#   10 0x664E0C18531443A5   38.6894  1.2%    31 1.2480  0.05 SELECT way_bill_main 
#   11 0xF591153EC390D8CA   32.5370  1.0%    28 1.1620  0.01 SELECT way_bill_main 
#   12 0xA3A82D5207F1BC2E   24.6582  0.8%    20 1.2329  0.06 SELECT way_bill_main 
#   13 0xFCED276145371CE4   22.2543  0.7%    18 1.2363  0.05 SELECT way_bill_main 
#   14 0x4895DF4252D5A600   21.3184  0.7%    17 1.2540  0.07 SELECT way_bill_main 
#   16 0xA4DD833DF8C96D04   14.6107  0.5%    13 1.1239  0.01 SELECT way_bill_main 
#   17 0x0426A3C3538CBBA8   13.9799  0.4%    13 1.0754  0.00 SELECT way_bill_main 
#   18 0x2C52F334EF3D8D2D   12.5960  0.4%    10 1.2596  0.03 SELECT way_bill_main 
# MISC 0xMISC              110.2030  3.5%    83 1.3277   0.0 <19 ITEMS>

這部分對查詢(xún)進(jìn)行參數化并分組，然后對各類(lèi)查詢(xún)的執行情況進(jìn)行分析，結果按總執行時(shí)長(cháng)，從大到小排序，恕我改了些顯示。
Response: 總的響應時(shí)間。
time: 該查詢(xún)在本次分析中總的時(shí)間占比。
calls: 執行次數，即本次分析總共有多少條這種類(lèi)型的查詢(xún)語(yǔ)句。
R/Call: 平均每次執行的響應時(shí)間。
Item : 查詢(xún)對象

第三部分：每一種查詢(xún)的詳細統計結果，這是其中一個(gè)

# Query 1: 0.02 QPS, 0.02x concurrency, ID 0x8965CC929FB1C7B2 at byte 868609
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.03
# Time range: 2017-07-18T03:17:56 to 2017-07-19T06:30:18
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         69    1816
# Exec time     66   2080s      1s      4s      1s      1s   189ms      1s
# Lock time     51   349ms    67us    19ms   192us   194us   760us   144us
# Rows sent     21   1.77k       1       1       1       1       0       1
# Rows examine  71 771.37M 262.54k 440.03k 434.96k 419.40k  24.34k 419.40k
# Rows affecte   0       0       0       0       0       0       0       0
# Bytes sent     1 120.49k      65      68   67.94   65.89    0.35   65.89
# Query size    60 443.31k     248     250  249.97  246.02    0.00  246.02
# String:
# Databases    ytttt
# Hosts        10.25.28.2
# Last errno   0
# Users        gztttttt
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s  ################################################################
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `ytttt` LIKE 'way_bill_main'\G
#    SHOW CREATE TABLE `ytttt`.`way_bill_main`\G
#    SHOW TABLE STATUS FROM `ytttt` LIKE 'scheduler_task'\G
#    SHOW CREATE TABLE `ytttt`.`scheduler_task`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT COUNT(1) FROM 1 as w inner join  .....此處省略。。。

這部分的上面一部分和第一部分信息類(lèi)似，統計該記錄sql的總運行效率信息，下面一部分的解析如下：

Databases: 庫名
Users: 各個(gè)用戶(hù)執行的次數（占比），現在只有一個(gè)用戶(hù)，因為我授權的就是一個(gè)庫一個(gè)獨立用戶(hù)。
Query_time distribution : 查詢(xún)時(shí)間分布, 長(cháng)短體現區間占比，本例中基本上都是1s。
Tables: 查詢(xún)中涉及到的表
Explain: 示例，也就是這條sql本身的信息。

后面其他信息也大體和這個(gè)類(lèi)似，只是顯示不同的sql信息而已，都屬于這個(gè)第三部分。

------------------------------------------------------------------------------------------

pt-query-digest參數說(shuō)明：

--create-review-table  當使用--review參數把分析結果輸出到表中時(shí)，如果沒(méi)有表就自動(dòng)創(chuàng )建。
--create-history-table  當使用--history參數把分析結果輸出到表中時(shí)，如果沒(méi)有表就自動(dòng)創(chuàng )建。
--filter  對輸入的慢查詢(xún)按指定的字符串進(jìn)行匹配過(guò)濾后再進(jìn)行分析
--limit限制輸出結果百分比或數量，默認值是20,即將最慢的20條語(yǔ)句輸出，如果是50%則按總響應時(shí)間占比從大到小排序，輸出到總和達到50%位置截止。
--host  MySQL服務(wù)器地址
--user  mysql用戶(hù)名
--password  mysql用戶(hù)密碼
--history 將分析結果保存到表中，分析結果比較詳細，下次再使用--history時(shí)，如果存在相同的語(yǔ)句，且查詢(xún)所在的時(shí)間區間和歷史表中的不同，則會(huì )記錄到數據表中，可以通過(guò)查詢(xún)同一CHECKSUM來(lái)比較某類(lèi)型查詢(xún)的歷史變化。
--review 將分析結果保存到表中，這個(gè)分析只是對查詢(xún)條件進(jìn)行參數化，一個(gè)類(lèi)型的查詢(xún)一條記錄，比較簡(jiǎn)單。當下次使用--review時(shí)，如果存在相同的語(yǔ)句分析，就不會(huì )記錄到數據表中。
--output 分析結果輸出類(lèi)型，值可以是report(標準分析報告)、slowlog(Mysql slow log)、json、json-anon，一般使用report，以便于閱讀。
--since 從什么時(shí)間開(kāi)始分析，值為字符串，可以是指定的某個(gè)”yyyy-mm-dd [hh:mm:ss]”格式的時(shí)間點(diǎn)，也可以是簡(jiǎn)單的一個(gè)時(shí)間值：s(秒)、h(小時(shí))、m(分鐘)、d(天)，如12h就表示從12小時(shí)前開(kāi)始統計。
--until 截止時(shí)間，配合—since可以分析一段時(shí)間內的慢查詢(xún)。

其他命令示例：

1.分析最近12小時(shí)內的查詢(xún)：
pt-query-digest  --since=12h  slow.log > slow_report2.log
2.分析指定時(shí)間范圍內的查詢(xún)：
pt-query-digest slow.log --since '2014-04-17 09:30:00' --until '2014-04-17  10:00:00'>>slow_report3.log
3.分析指含有select語(yǔ)句的慢查詢(xún)
pt-query-digest--filter '$event->{fingerprint} =~ m/^select/i' slow.log> slow_report4.log
4.針對某個(gè)用戶(hù)的慢查詢(xún)
pt-query-digest--filter '($event->{user} || "") =~ m/^root/i' slow.log> slow_report5.log
5.查詢(xún)所有所有的全表掃描或full join的慢查詢(xún)
pt-query-digest--filter '(($event->{Full_scan} || "") eq "yes") ||(($event->{Full_join} || "") eq "yes")' slow.log> slow_report6.log
6.把查詢(xún)保存到query_review表
pt-query-digest  --user=root –password=abc123 --review  h=localhost,D=test,t=query_review--create-review-table  slow.log
7.把查詢(xún)保存到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
8.通過(guò)tcpdump抓取mysql的tcp協(xié)議數據，然后再分析
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
9.分析binlog
mysqlbinlog mysql-bin.000093 > mysql-bin000093.sql
pt-query-digest  --type=binlog  mysql-bin000093.sql > slow_report10.log
10.分析general log
pt-query-digest  --type=genlog  localhost.log > slow_report11.log

--------------------------------------------------------------------------------------------

個(gè)人觀(guān)點(diǎn):

其實(shí)pt-query-digest雖然信息很多，但是輸出的有用信息不見(jiàn)得就比mysqldumpslow好很多，反而眼花繚亂的，而且還要裝多個(gè)工具才能用。不過(guò)可以甩問(wèn)題給開(kāi)發(fā)看到效率有多差也算是一個(gè)好事，可以說(shuō)清楚那個(gè)sql執行了多少次慢查詢(xún)，所以實(shí)際使用上還是見(jiàn)仁見(jiàn)智，自己看著(zhù)辦。

額外說(shuō)明:

1.個(gè)別情況下,mysql慢查詢(xún)記錄可能達不到目的.

那是因為mysql的慢查詢(xún)記錄機制導致,因為mysql只是把在引擎階段的慢查詢(xún)記錄到慢日志,其他例如網(wǎng)絡(luò )延遲(如:跨機房),IO傳輸延時(shí)(如:讀寫(xiě)頻繁),客戶(hù)端延遲(如:jdbc高負載),還有個(gè)別內部資源鎖等待,可能導致增加的查詢(xún)延時(shí),但又不一定記錄在慢日志的.

所以很可能就出現一種詭異的情況,明明查詢(xún)確實(shí)很慢,但是mysql的慢日志就是沒(méi)有記錄下來(lái).這個(gè)時(shí)候就要我們的思路更廣闊一些才行了.

2.如果慢查詢(xún)日志還是解決不了問(wèn)題的話(huà)，就建議開(kāi)查詢(xún)日志general-log來(lái)跟蹤sql了.
大體和上面操作差不多，先查看當前狀態(tài)
show variables like 'general%';
可以在my.cnf里添加
general-log = 1開(kāi)啟（0關(guān)閉）
log = /log/mysql_query.log路徑
也可以設置變量那樣更改
set global general_log=1開(kāi)啟（0關(guān)閉）