MYSQL

MySQL的慢日志分析工具详解

作者:本站 2017-08-08 浏览:1355 标签: mysql    日志    工具    

  我们知道,如果我们的语句不够优化,那么首先MySQL的慢日志是进一步优化的离线证据,虽然里面有好 多“伪慢语句”!  先不说怎么优化,如果你的日志有一条语句赌住了,那么会有不计其数的慢语句填充到MySQL的满日志里面。那么首先提炼出这些

  我们知道,如果我们的语句不够优化,那么首先MySQL的慢日志是进一步优化的离线证据,虽然里面有好 多“伪慢语句”!

  先不说怎么优化,如果你的日志有一条语句赌住了,那么会有不计其数的慢语句填充到MySQL的满日志里面。那么首先提炼出这些语 句就非常头疼。

  今天主要介绍两种工具:

  1,mysqldumpslow。(咱们 MySQL自带的简单而又实用的工具)

  我们先来看下mysqldumpslow的结果。

  [root@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

  比如要查找排序的慢语句:

  [root@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)分析慢日志并且把找出来的语句写到规定的 表里。

  [root@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

  [root@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来定时抓取信息到固定的文件里以备分析。不过现在可以用它来打印出比较详细的报告来。

  [root@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
[root@localhost ~]#

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


  • 0

  • 0

  • 1.本站遵循行业规范,任何转载的稿件都会明确标注作者和来源;2.本站的原创文章,请转载时务必注明文章作者和来源,不尊重原创的行为我们将追究责任;3.如有文章有版权争议,请给我们留言或者邮件告知我们,邮箱地址:028mw@126.com。