共計 10237 個字符,預計需要花費 26 分鐘才能閱讀完成。
這篇文章主要講解了“mysql 慢查詢功能詳細介紹”,文中的講解內容簡單清晰,易于學習與理解,下面請大家跟著丸趣 TV 小編的思路慢慢深入,一起來研究和學習“mysql 慢查詢功能詳細介紹”吧!
開啟 mysql 慢查詢日志
1. 查看當前慢查詢設置情況
# 查看慢查詢時間,默認 10s,建議降到 1s 或以下,mysql show variables like long_query_time
+-----------------+----------+
| Variable_name | Value |
+-----------------+----------+
| long_query_time | 1.000000 |
+-----------------+----------+
1 row in set (0.00 sec)
#查看慢查詢配置情況
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 就是已開啟功能了。
2. 如何開啟慢查詢功能
方法一:在服務器上找到 mysql 的配置文件 my.cnf , 然后再 mysqld 模塊里追加一下內容,這樣的好處是會一直生效,不好就是需要重啟 mysql 進程。
vim my.cnf
[mysqld]
slow_query_log = ON
#定義慢查詢日志的路徑
slow_query_log_file = /tmp/slow_querys.log
#定義查過多少秒的查詢算是慢查詢,我這里定義的是 1 秒,5.6 之后允許設置少于 1 秒,例如 0.1 秒
long_query_time = 1
#用來設置是否記錄沒有使用索引的查詢到慢查詢記錄, 默認關閉, 看需求開啟, 會產生很多日志, 可動態修改
#log-queries-not-using-indexes
管理指令也會被記錄到慢查詢。比如 OPTIMEZE TABLE, ALTER TABLE, 默認關閉, 看需求開啟, 會產生很多日志, 可動態修改
#log-slow-admin-statements
然后重啟 mysql 服務器即可,這是通過一下命令看一下慢查詢日志的情況:
tail -f /tmp/slow_querys.log
方法二:通過修改 mysql 的全局變量來處理,這樣做的好處是,不用重啟 mysql 服務器,登陸到 mysql 上執行一下 sql 腳本即可,不過重啟后就失效了。
# 開啟慢查詢功能,1 是開啟,0 是關閉
mysql set global slow_query_log=1;
#定義查過多少秒的查詢算是慢查詢,我這里定義的是 1 秒,5.6 之后允許設置少于 1 秒,例如 0.1 秒
mysql set global long_query_time=1;
#定義慢查詢日志的路徑
mysql set global slow_query_log_file= /tmp/slow_querys.log
#關閉功能:set global slow_query_log=0;
然后通過一下命令查看是否成功
mysql show variables like long%
mysql show variables like slow%
#設置慢查詢記錄到表中
#set global log_output= TABLE
當然了,你也可以兩者合一,一方面不用重啟 mysql 進程就能生效,另一方面也不用怕重啟后參數失效,效果也是一致的。
特別要注意的是 long_query_time 的設置,5.6 之后支持設置低于 0.1 秒,所以記錄的詳細程度,就看你自己的需求,數據庫容量比較大的,超過 0.1 秒還是比較多,所以就變得有點不合理了。
慢查詢日志的記錄定義
直接查看 mysql 的慢查詢日志分析,比如我們可以 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 查詢執行的時間
第二行, 執行 SQL 查詢的連接信息,用戶和連接 IP
第三行, 記錄了一些我們比較有用的信息,如下解析
Query_time, 這條 SQL 執行的時間, 越長則越慢
Lock_time, 在 MySQL 服務器階段(不是在存儲引擎階段) 等待表鎖時間
Rows_sent, 查詢返回的行數
Rows_examined, 查詢檢查的行數,越長就當然越費時間
第四行, 設置時間戳,沒有實際意義,只是和第一行對應執行時間。
第五行及后面所有行(第二個# Time: 之前), 執行的 sql 語句記錄信息,因為 sql 可能會很長。
分析慢查詢的軟件
雖然慢查詢日志已經夠清晰,但是往往我們的日志記錄到的不是只有一條 sql,可能有很多很多條,如果不加以統計,估計要看到猴年馬月,這個時候就需要做統計分析了。
方法一:使用 mysql 程序自帶的 mysqldumpslow 命令分析,例如:
mysqldumpslow -s c -t 10 /tmp/slow-log
這會輸出記錄次數最多的 10 條 SQL 語句,得出的結果和上面一般慢查詢記錄的格式沒什么太大差別,這里就不展開來詳細解析了。
參數解析:
-s:是表示按照何種方式排序,子參數如下:
c、t、l、r:分別是按照記錄次數、時間、查詢時間、返回的記錄數來排序,
ac、at、al、ar:表示相應的倒敘;
-t:返回前面多少條的數據,這里意思就是返回 10 條數據了(也可以說是前十)
-g:后邊可以寫一個正則匹配模式,大小寫不敏感的,比如:
/path/mysqldumpslow -s r -t 10 /tmp/slow-log,得到返回記錄集最多的 10 個查詢。
/path/mysqldumpslow -s t -t 10 -g“left join”/tmp/slow-log,得到按照時間排序的前 10 條里面含有左連接的查詢語句。
方法二:使用 pt(Percona Toolkit)工具的 pt-query-digest 進行統計分析。這個是由 Percona 公司出品的一個用 perl 編寫的腳本,只有安裝上 pt 工具集才會存在,有興趣的朋友就要先安裝 pt 工具了。直接分析慢查詢文件,執行如下:
pt-query-digest slow_querys.log t.txt
因為記錄里還是可能有很多 sql 在,看起來還是費勁,所以建議輸出到文件來看了。輸出的信息會分成三部分,
第一部分:總體統計結果
# 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
記錄這個慢日志文件里面的所有慢查詢統計信息,通常粗略看看就好了:
Overall: 這個文件里總共有多少條查詢,上例為總共 2.63k 個查詢,也就是 2.63k 條慢查詢。
Time range: 查詢執行的時間范圍。
unique: 唯一查詢數量,即對查詢條件進行參數化以后,統計的總共有多少個不同的查詢,該例為 36。也就是說這 2.63K 條慢查詢,實際歸類為 36 條。
Attribute:屬性解析,其他子項:
total: 總計,min: 最小,max: 最大,avg: 平均,
95%: 把所有值從小到大排列,位置位于 95% 的那個數,這個數一般最具有參考價值,
median: 中位數,把所有值從小到大排列,位置位于中間那個數。
其他就字面意思,去翻譯一下就好。
第二部分:查詢分組統計結果
# 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
這部分對查詢進行參數化并分組,然后對各類查詢的執行情況進行分析,結果按總執行時長,從大到小排序,恕我改了些顯示。
Response: 總的響應時間。
time: 該查詢在本次分析中總的時間占比。
calls: 執行次數,即本次分析總共有多少條這種類型的查詢語句。
R/Call: 平均每次執行的響應時間。
Item : 查詢對象
第三部分:每一種查詢的詳細統計結果,這是其中一個
# 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 ..... 此處省略。。。
這部分的上面一部分和第一部分信息類似,統計該記錄 sql 的總運行效率信息,下面一部分的解析如下:
Databases: 庫名
Users: 各個用戶執行的次數(占比),現在只有一個用戶,因為我授權的就是一個庫一個獨立用戶。
Query_time distribution : 查詢時間分布, 長短體現區間占比,本例中基本上都是 1s。
Tables: 查詢中涉及到的表
Explain: 示例,也就是這條 sql 本身的信息。
后面其他信息也大體和這個類似,只是顯示不同的 sql 信息而已,都屬于這個第三部分。
——————————————————————————————
pt-query-digest 參數說明:
–create-review-table 當使用 –review 參數把分析結果輸出到表中時,如果沒有表就自動創建。
–create-history-table 當使用 –history 參數把分析結果輸出到表中時,如果沒有表就自動創建。
–filter 對輸入的慢查詢按指定的字符串進行匹配過濾后再進行分析
–limit 限制輸出結果百分比或數量,默認值是 20, 即將最慢的 20 條語句輸出,如果是 50% 則按總響應時間占比從大到小排序,輸出到總和達到 50% 位置截止。
–host MySQL 服務器地址
–user mysql 用戶名
–password mysql 用戶密碼
–history 將分析結果保存到表中,分析結果比較詳細,下次再使用 –history 時,如果存在相同的語句,且查詢所在的時間區間和歷史表中的不同,則會記錄到數據表中,可以通過查詢同一 CHECKSUM 來比較某類型查詢的歷史變化。
–review 將分析結果保存到表中,這個分析只是對查詢條件進行參數化,一個類型的查詢一條記錄,比較簡單。當下次使用 –review 時,如果存在相同的語句分析,就不會記錄到數據表中。
–output 分析結果輸出類型,值可以是 report(標準分析報告)、slowlog(Mysql slow log)、json、json-anon,一般使用 report,以便于閱讀。
–since 從什么時間開始分析,值為字符串,可以是指定的某個”yyyy-mm-dd [hh:mm:ss]”格式的時間點,也可以是簡單的一個時間值:s(秒)、h(小時)、m(分鐘)、d(天),如 12h 就表示從 12 小時前開始統計。
–until 截止時間,配合—since 可以分析一段時間內的慢查詢。
其他命令示例:
1. 分析最近 12 小時內的查詢:
pt-query-digest –since=12h slow.log slow_report2.log
2. 分析指定時間范圍內的查詢:
pt-query-digest slow.log –since 2014-04-17 09:30:00 –until 2014-04-17 10:00:00 slow_report3.log
3. 分析指含有 select 語句的慢查詢
pt-query-digest–filter $event- {fingerprint} =~ m/^select/i slow.log slow_report4.log
4. 針對某個用戶的慢查詢
pt-query-digest–filter ($event- {user} || ) =~ m/^root/i slow.log slow_report5.log
5. 查詢所有所有的全表掃描或 full join 的慢查詢
pt-query-digest–filter (($event- {Full_scan} || ) eq yes ) ||(($event- {Full_join} || ) eq yes ) slow.log slow_report6.log
6. 把查詢保存到 query_review 表
pt-query-digest –user=root –password=abc123 –review h=localhost,D=test,t=query_review–create-review-table slow.log
7. 把查詢保存到 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. 通過 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
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
——————————————————————————————–
個人觀點:
其實 pt-query-digest 雖然信息很多,但是輸出的有用信息不見得就比 mysqldumpslow 好很多,反而眼花繚亂的,而且還要裝多個工具才能用。不過可以甩問題給開發看到效率有多差也算是一個好事,可以說清楚那個 sql 執行了多少次慢查詢,所以實際使用上還是見仁見智,自己看著辦。
額外說明:
1. 個別情況下,mysql 慢查詢記錄可能達不到目的.
那是因為 mysql 的慢查詢記錄機制導致, 因為 mysql 只是把在引擎階段的慢查詢記錄到慢日志, 其他例如網絡延遲(如: 跨機房),IO 傳輸延時(如: 讀寫頻繁), 客戶端延遲(如:jdbc 高負載), 還有個別內部資源鎖等待, 可能導致增加的查詢延時, 但又不一定記錄在慢日志的.
所以很可能就出現一種詭異的情況, 明明查詢確實很慢, 但是 mysql 的慢日志就是沒有記錄下來. 這個時候就要我們的思路更廣闊一些才行了.
2. 如果慢查詢日志還是解決不了問題的話,就建議開查詢日志 general-log 來跟蹤 sql 了.
大體和上面操作差不多,先查看當前狀態
show variables like general%
可以在 my.cnf 里添加
general-log = 1 開啟(0 關閉)
log = /log/mysql_query.log 路徑
也可以設置變量那樣更改
set global general_log= 1 開啟(0 關閉)
感謝各位的閱讀,以上就是“mysql 慢查詢功能詳細介紹”的內容了,經過本文的學習后,相信大家對 mysql 慢查詢功能詳細介紹這一問題有了更深刻的體會,具體使用情況還需要大家實踐驗證。這里是丸趣 TV,丸趣 TV 小編將為大家推送更多相關知識點的文章,歡迎關注!