慢查詢日志分析


慢查詢日志

一篇好文章,學習保存。。。。

打開慢查詢日志

慢查詢日志,顧名思義就是記錄執行比較慢查詢的日志。

查看是否開啟慢查詢日志:

show variables like '%slow%';

打開慢查詢日志。修改MySQL的配置文件my.cn一般是在/etc目錄下面,加上下面三行配置后重啟MySQL。

slow_query_log = ON
slow_launch_time = 2
slow_query_log_file = /usr/local/mysql/data/slow_query.log

slow_launch_time只能精確到秒,如果需要更精確可以使用一些第三方的工具比如后面介紹的pt-query-digest。

注意:我這里用的MySQL版本是5.6,不同版本的MySQL開啟慢查詢的配置是不同的,比如5.6之前的某些版本是ong_query_time, long_query_time和log-slow-queries。可以先在終端執行show variables like '%slow%';查看下當前版本具體配置是什么。

也可以在終端通過設置全局變量來打開慢查詢日志:

set  @@global.slow_query_log = ON;

保存慢查詢日志到表中

MySQL支持將慢查詢日志保存到mysql.slow_log這張表中。通過@@global.log_output可以設置默認為TABLE,FILE和TABLE只能同時使用一個。

set @@global.log_output='TABLE';

我們可以使用下面的語句來模擬慢查詢:

select sleep(10);

慢查詢日志分析

1、可以使用MySQL自帶的mysqldumpslow工具。使用很簡單,可以跟-help來查看具體的用法。

# -s:排序方式。c , t , l , r 表示記錄次數、時間、查詢時間的多少、返回的記錄數排序;
#                             ac , at , al , ar 表示相應的倒敘;
# -t:返回前面多少條的數據;
# -g:包含什么,大小寫不敏感的;
mysqldumpslow -s r -t 10  /slowquery.log     #slow記錄最多的10個語句
mysqldumpslow -s t -t 10 -g "left join"  /slowquery.log     #按照時間排序前10中含有"left join"

2、可以導到mysql.slow_query表中,然后通過sql語句進行分析。

3、使用第三方工具,下面會有介紹。

 

Percona Toolkit介紹

percona-toolkit是一組高級命令行工具的集合,用來執行各種通過手工執行非常復雜和麻煩的mysql和系統任務。這些任務包括:

  • 檢查master和slave數據的一致性
  • 有效地對記錄進行歸檔
  • 查找重復的索引
  • 對服務器信息進行匯總
  • 分析來自日志和tcpdump的查詢
  • 當系統出問題的時候收集重要的系統信息

安裝

安裝percona-toolkit非常簡單,到官網下載.tar.gz包:

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

然后依次執行下面的命令:

perl Makefile.PL
make
make test
make install

默認的會被安裝在/usr/local/bin目錄下。執行man percona-toolkit可以查看安裝了哪些工具。

運行工具可能會遇到下面的錯誤:

這是因為缺少相應包,.pm包實際上perl的包,運行下面的命令安裝即可:

yum install -y perl-Time-HiRes

如果安裝過程中出現” Error Downloading Packages”錯誤,嘗試yum clean all后再安裝。使用其Percona Toolkit中其他工具也可能會遇到類似的問題,按照提示安裝相應的perl包就可以了。

Percona Toolkit整個工具箱提供了非常多實用的工具,具體的使用方法可以參看官方文檔

下面有選擇的給大家介紹幾個有用的工具。

pt-query-digest

pt-query-digest可以從普通MySQL日志,慢查詢日志以及二進制日志中分析查詢,甚至可以從SHOW PROCESSLIST和MySQL協議的tcpdump中進行分析,如果沒有指定文件,它從標准輸入流(STDIN)中讀取數據。

最簡單的用法如下:

pt-query-digest slow.logs

輸出信息大致如下:

整個輸出分為三大部分:

1、整體概要(Overall)

這個部分是一個大致的概要信息(類似loadrunner給出的概要信息),通過它可以對當前MySQL的查詢性能做一個初步的評估,比如各個指標的最大值(max),平均值(min),95%分布值,中位數(median),標准偏差(stddev)。這些指標有查詢的執行時間(Exec time),鎖占用的時間(Lock time),MySQL執行器需要檢查的行數(Rows examine),最后返回給客戶端的行數(Rows sent),查詢的大小。

2、查詢的匯總信息(Profile)

這個部分對所有”重要”的查詢(通常是比較慢的查詢)做了個一覽表:

每個查詢都有一個Query ID,這個ID通過Hash計算出來的。pt-query-digest是根據這個所謂的Fingerprint來group by的。舉例下面兩個查詢的Fingerprint是一樣的都是select * from table1 where column1 = ?,工具箱中也有一個與之相關的工具pt-fingerprint。

select * from table1 where column1 = 2
select * from table1 where column1 = 3
  • Rank整個分析中該“語句”的排名,一般也就是性能最常的。
  • Response time  “語句”的響應時間以及整體占比情況。
  • Calls 該“語句”的執行次數。
  • R/Call 每次執行的平均響應時間。
  • V/M 響應時間的差異平均對比率。

在尾部有一行輸出,顯示了其他2個占比較低而不值得單獨顯示的查詢的統計數據。

3、詳細信息

這個部分會列出Profile表中每個查詢的詳細信息:

包括Overall中有的信息、查詢響應時間的分布情況以及該查詢”入榜”的理由。

pt-query-digest還有很多復雜的操作,這里就不一一介紹了。比如:從PROCESSLIST中查詢某個MySQL中最慢的查詢:

pt-query-digest –processlist h=host1

從tcpdump中分析:

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 log保存到另外一台機器上待稍后詳細分析:

pt-query-digest --review h=host2 --no-report slow.log

還可以跟一些過濾條件。詳見官方文檔:http://www.percona.com/doc/percona-toolkit/2.2/pt-query-digest.html

另外結合一些第三方工具還能生成相應的報表,可以參考這里:http://biancheng.dnbcw.info/mysql/433514.html

建議:當slow log很大的時候最好還是將日志文件移到其他機器上進行分析。

 

pt-index-usage

這個工具主要是用來分析查詢的索引使用情況。

pt-index-usage slow_query.log --h localhost --password 123456

詳細的用法 –help查看再對照官網就差不再贅述。

注意使用這個工具需要MySQL必須要有密碼,另外運行時可能報找不到/var/lib/mysql/mysql.sock的錯,簡單的從/tmp/mysql.sock鏈接一個就行了。

重點要說明的是pt-index-usage只能分析慢查詢日志,所以如果想全面分析所有查詢的索引使用情況就得將slow_launch_time設置為0,因此請謹慎使用該工具,線上使用的話最好在凌晨進行分析,尤其分析大量日志的時候是很耗CPU的。

整體來說這個工具是不推薦使用的,要想實現類似的分析可以考慮一些其他第三方的工具,比如:mysqlidxchx, userstat和check-unused-keys。網上比較推薦的是userstat,一個Google貢獻的patch。

Oracle是可以將執行計划保存到性能視圖中的,這樣分析起來可能更靈活,但是目前我還沒找到MySQL中類似的做法。

 

pt-upgrade

這個工具用來檢查在新版本中運行的SQL是否與老版本一樣,返回相同的結果,最好的應用場景就是數據遷移的時候。

pt-upgrade h=host1 h=host2 slow.log

 

pt-query-advisor 

靜態查詢分析工具。能夠解析查詢日志、分析查詢模式,然后給出所有可能存在潛在問題的查詢,並給出足夠詳細的建議。這個工具好像2.2的版本給去掉了,有可能是因為對性能影響比較大新版本直接去掉了。

總結:上面這些工具最好不要直接在線上使用,應該作為上線輔助或故障后離線分析的工具,也可以做性能測試的時候配合着使用。

 

SHOW PROFILE

SHOW PROFILE是Google高級架構師Jeremy Cole貢獻給MySQL社區的,它可以用來MySQL執行語句時候所使用的資源。默認是關閉的,需要打開執行下面的語句:

set profiling = 1;#這個命令只在本會話內起作用。

執行簡單的SHOW PROFILES可以看到打開profiling之后所有查詢的執行時間。

執行SHOW PROFILE [TYPE] FOR QUERY Query_ID可以看到MySQL執行某個查詢各個步驟的各項性能指標的詳細信息:

如果沒有指定FOR QUERY則顯示最近一條查詢的詳細信息。TYPE是可選的,有以下幾個選項:

  • ALL 顯示所有性能信息
  • BLOCK IO 顯示塊IO操作的次數
  • CONTEXT SWITCHES 顯示上下文切換次數,不管是主動還是被動
  • CPU 顯示用戶CPU時間、系統CPU時間
  • IPC 顯示發送和接收的消息數量
  • MEMORY [暫未實現]
  • PAGE FAULTS 顯示頁錯誤數量
  • SOURCE 顯示源碼中的函數名稱與位置
  • SWAPS 顯示SWAP的次數

MySQL在執行查詢語句的時候會有很多步驟,這里就不一一贅述了,用到的時候網上搜下就行。需要特別說明的是Sending data這個步驟,給人感覺是MySQL把數據發送給客戶端的耗時,其實不然,這個步驟包括了MySQL內部各個存儲之間復制數據的過程,比如硬盤的尋道。

總結:前面的慢查詢日志分析更像是對整個MySQL查詢情況做一個全面的檢查,而SHOW PROFILE則是對單個查詢語句的剖析,通常當現網出現問題時應該結合二者。使用慢查詢分析定位到具體的查詢,使用SHOW PROFILE定位到具體的問題,是Sending data比較耗時還是System lock比較耗時...

 

performance_schema

這兩個庫保存了MySQL的一些性能和元數據相關的信息,其中performance_schema是MySQL5.5才新增的,上面提到的很多工具其實利用了這個庫的信息。比如SHOW PROFILE ALL FOR QUERY 2:的信息還可以通過下面的查詢獲取:

SELECT * FROM information_schema.profiling WHERE query_id = 2 ORDER BY seq;

利用performance_schema還可以做一些更靈活的統計:

復制代碼
SET @query_id = 1;
SELECT STATE,SUM(DURATION) AS Total_R,
    ROUND(100*SUM(DURATION)/(SELECT SUM(DURATION) FROM INFORMATION_SCHEMA.PROFILING
    WHERE QUERY_ID = @query_id),2) AS Pct_R,
    COUNT(*) AS Calls,
    SUM(DURATION)/COUNT(*) AS "R/Call"
FROM INFORMATION_SCHEMA.PROFILING
WHERE QUERY_ID = @query_id
GROUP BY STATE
ORDER BY Total_R DESC;
復制代碼

這個簡單的查詢可以在《高性能MySQL第三版》中找到,可它能統計SHOW PROFILE各個步驟的耗時、耗時占比、調用API次數以及每次的平均耗時。在《高性能MySQL第三版》中還提到了很多有用的工具(SHOW STATUS,SHOW PROCESSLIST...)包括使用方法,強烈推薦這本書。


注意!

本站转载的文章为个人学习借鉴使用,本站对版权不负任何法律责任。如果侵犯了您的隐私权益,请联系我们删除。



 
粤ICP备14056181号  © 2014-2021 ITdaan.com