关于MySQL的慢日志分析工具

cheng029

今天我们看看关于MySQL慢日志的阅读。
我们知道，如果我们的语句不够优化，那么首先MySQL的慢日志是进一步优化的离线证据，虽然里面有好 多“伪慢语句”！
先不说怎么优化，如果你的日志有一条语句赌住了，那么会有不计其数的慢语句填充到MySQL的满日志里面。那么首先提炼出这些语 句就非常头疼。
今天主要介绍两种工具：
1,mysqldumpslow。（咱们 MySQL自带的简单而又实用的工具）

我们先来看下mysqldumpslow的结果。
[iyunv@localhost ~]# mysqldumpslow -r  localhost-slow.log

Reading  mysql slow query log from localhost-slow.log             Count: 2  Time=7.00s (14s)  Lock=0.00s (0s)  Rows=0.0 (0),  root[root]@localhost               select * from t_page_sample order by id desc limit N,N             Count: 1  Time=11.00s (11s)  Lock=0.00s (0s)  Rows=1.0 (1),  root[root]@localhost               select count(*) from t_page_sample             Count: 1  Time=1418.00s (1418s)  Lock=0.00s (0s)  Rows=0.0 (0),  root[root]@localhost               insert ignore into t_page_sample select ceil(rand()*N),  ceil(rand()*N), date_sub(now(),interval floor(rand()*N) day), now() from  t_page_sample

比如要查找排序的慢语句：
[iyunv@localhost ~]# mysqldumpslow -r -g "order by " localhost-slow.log

Reading mysql slow query log from  localhost-slow.log             Count: 2   Time=7.00s (14s)  Lock=0.00s (0s)  Rows=0.0 (0), root[root]@localhost                select * from t_page_sample order by id desc limit N,N

自带的mysqldumpslow简单 实用，作为我个人的首选。关于具体的参数含义，可以参见它自身的HELP。

2,mk-query-digest。(网上著名的开源脚本家族Maatkit中一员)
手 册地址：http://www.maatkit.org/doc/mk-query-digest.html
下载方法：wget  http://www.maatkit.org/get/mk-query-digest
完了赋给它可执行权限就OK。
mk-query-digest  功能太多，我今天只是试了下它对MySQL慢日志的分析功能。
以下是我觉得比较实用的功能。

1）分析慢日志并且把找出来的语句写到规定的 表里。
[iyunv@localhost ~]#  ./mk-query-digest --limit 2 --select  Query_time,Lock_time,Rows_sent,Rows_examined,ts --create-review-table  --review D=t_girl,t=query_review localhost-slow.log

# 280ms user time, 80ms system  time, 11.56M rss, 16.65M vsz             # Current  date: Sat May  8 02:47:39 2010             # Files: localhost-slow.log             #  Overall: 4 total, 3 unique, 0.01 QPS, 1.96x concurrency ________________             #                      total     min     max     avg     95%  stddev  median             # Exec  time          1443s      5s   1418s    361s   1357s    584s    684s             #  Lock time              0       0       0       0       0       0       0             #  Rows sent              1       0       1    0.25    0.99    0.43       0             #  Rows exam          6.98M   1.69M   1.89M   1.74M   1.86M  76.62k    1.69M             # Time range        2010-05-08 00:28:42 to 2010-05-08 00:40:58             #  Profile             # Rank Query ID           Response time    Calls R/Call     Item             # ==== ================== ================ ===== =========  ===============             #    1 0x2A94F91D8C3B4B26  1418.0000 99.0%     1  1418.0000 INSERT SELECT t_page_sample             #    2 0x06754F1BD3C8D697     14.0000  1.0%     2    7.0000 SELECT t_page_sample             # Query 1: 0  QPS, 0x concurrency, ID 0x2A94F91D8C3B4B26 at byte 0 ________             # This  item is included in the report because it matches --limit.             #                pct   total     min     max     avg     95%  stddev  median             #  Count         25       1             # Exec time     98   1418s   1418s   1418s    1418s   1418s       0   1418s             # Lock time      0       0        0       0       0       0       0       0             # Rows sent      0        0       0       0       0       0       0       0             # Rows exam      27   1.89M   1.89M   1.89M   1.89M   1.89M       0   1.89M             # Time  range 2010-05-08 00:28:42 to 2010-05-08 00:28:42             # Query_time  distribution             #   1us             #  10us             # 100us             #   1ms             #  10ms             #  100ms             #    1s             #  10s+   ################################################################             #  Review information             #    first_seen: 2010-05-08 00:28:42             #      last_seen: 2010-05-08 00:28:42             #   reviewed_by:             #   reviewed_on:             #        comments:             # Tables             #    SHOW TABLE STATUS FROM `t_girl` LIKE  't_page_sample'\G             #    SHOW CREATE TABLE `t_girl`.`t_page_sample`\G             insert   ignore into t_page_sample select ceil(rand()*10000000), ceil(rand()*9),  date_sub(now(),interval floor(rand()*20) day), now() from  t_page_sample\G             # Query 2: 0.07 QPS, 0.47x concurrency, ID  0x06754F1BD3C8D697 at byte 1499             # This item is included in the report  because it matches --limit.             #              pct   total     min      max     avg     95%  stddev  median             # Count         50       2             #  Exec time      0     14s      5s      9s      7s      9s      3s      7s             #  Lock time      0       0       0       0       0       0       0       0             #  Rows sent      0       0       0       0       0       0       0       0             #  Rows exam     48   3.39M   1.69M   1.69M   1.69M   1.69M       0    1.69M             # Time range 2010-05-08 00:40:28 to 2010-05-08 00:40:58             #  Query_time distribution             #   1us             #  10us             # 100us             #   1ms             #    10ms             # 100ms             #    1s   ################################################################             #   10s+             # Review information             #    first_seen: 2010-05-08 00:40:28             #       last_seen: 2010-05-08 00:40:58             #   reviewed_by:             #   reviewed_on:               #      comments:             # Tables             #    SHOW TABLE STATUS FROM  `t_girl` LIKE 't_page_sample'\G             #    SHOW CREATE TABLE  `t_girl`.`t_page_sample`\G             # EXPLAIN             select * from t_page_sample  order by id desc limit 4400000,2\G

[iyunv@localhost  ~]#

因为慢日志里面会有写和读语句，所以当以后想要分析某类语句时，只需要简单的SELECT即可出来。

mysql> select * from query_review  where fingerprint like 'select%'\G

*************************** 1. row  ***************************                 checksum: 465365117438580375             fingerprint: select * from t_page_sample  order by id desc limit ?                  sample: select * from t_page_sample  order by id desc limit 4400000,2              first_seen: 2010-05-08 00:40:28                last_seen: 2010-05-08 00:40:58             reviewed_by: NULL             reviewed_on:  NULL                comments: NULL             1 rows in set (0.00 sec)

2. 分析当前运行的SQL语句。
以 前我都是自己写脚本，配合CRONTAB来定时抓取信息到固定的文件里以备分析。不过现在可以用它来打印出比较详细的报告来。

[iyunv@localhost ~]# ./mk-query-digest  --select Query_time,Lock_time,Rows_sent,Rows_examined  --processlist  h=localhost,u=root

#  Caught SIGINT.             # 690ms user time, 2.4s system time, 11.27M rss,  16.41M vsz             # Current date: Sat May  8 03:17:39 2010             # Files:  STDIN             # Overall: 1 total, 1 unique, 0 QPS, 0x concurrency  ______________________             #                    total     min     max      avg     95%  stddev  median             # Exec time        1273313855s  1273313855s 1273313855s 1273313855s 1273313855s       0 1273313855s             #  Lock time              0       0       0       0       0       0       0             #  Profile             # Rank Query ID           Response time          Calls  R/Call          Ite             # ==== ================== ======================  ===== =============== ===             #    1 0xB52E1970DE36E57F 1273313854.8595  100.0%     1 1273313854.8595 SELECT t_page_sample             # Query 1: 0  QPS, 0x concurrency, ID 0xB52E1970DE36E57F at byte 0 ________             # This  item is included in the report because it matches --limit.             #                pct   total     min     max     avg     95%  stddev  median             #  Count        100       1             # Exec time    100 1273313855s 1273313855s  1273313855s 1273313855s 1273313855s       0 1273313855s             # Lock  time      0       0       0       0       0       0       0       0             #  Query_time distribution             #   1us             #  10us             # 100us             #   1ms             #    10ms             # 100ms             #    1s             #  10s+   ################################################################             #  Tables             #    SHOW TABLE STATUS FROM `t_girl` LIKE 't_page_sample'\G             #      SHOW CREATE TABLE `t_girl`.`t_page_sample`\G             # EXPLAIN             select  count(*) from t_page_sample\G             [iyunv@localhost ~]#

当 想停止截取当前语句时，按住CTRL+C就OK。

不过我还是喜欢我自己的那个小脚本。哈哈。

2168575

谢谢楼主，共同发展

wuliuwang

找到好贴不容易，我顶你了，谢了

火冰狐

找不到恐龙，就用蜥蜴顶

liwya

美女未抱身先走,常使色狼泪满襟。。。。。。

gaojinguan

路过，学习下

wsjz_01

美女未抱身先走,常使色狼泪满襟。。。。。。

zhangxiajun

给力