截取mysql 慢语句

by liangjz

最近和开发、DBA一起对MYSQL作性能调优，发现几个点对抓取MYSQL慢语句很有帮助

在/etc/my.cnf 文件加入

log_slow_queries
log-queries-not-using-indexes
log_long_format
long_query_time=1

  将在mysql数据目录下( datadir = /home/mysql ) 生成一个如test-slow.log的文件,内容有：

# Time: 080430 20:06:53
#User@Host: match_account[match_account] @  [10.0.4.114]
# Query_time: 0  Lock_time: 0  Rows_sent: 9  Rows_examined: 18
SELECT * FROM `tree_menus`   WHERE (parentid = 0)  ORDER BY sequence desc, id desc;
# Time: 080430 20:09:04

查询用了0秒，返回9行，一共查了18行

如何利用呢，有2 种方法：

1） [root@test mysql]# grep Rows_examined   test-slow.log  | sort -g -k9 -r|uniq -u |head -100
# Query_time: 0  Lock_time: 0  Rows_sent: 30  Rows_examined: 24460
# Query_time: 0  Lock_time: 0  Rows_sent: 10  Rows_examined: 24440
# Query_time: 0  Lock_time: 0  Rows_sent: 9  Rows_examined: 24439
# Query_time: 0  Lock_time: 0  Rows_sent: 2  Rows_examined: 24432
# Query_time: 0  Lock_time: 0  Rows_sent: 1  Rows_examined: 24430
# Query_time: 0  Lock_time: 0  Rows_sent: 0  Rows_examined: 12043
# Query_time: 0  Lock_time: 0  Rows_sent: 34  Rows_examined: 2441
# Query_time: 0  Lock_time: 0  Rows_sent: 12  Rows_examined: 1449
# Query_time: 0  Lock_time: 0  Rows_sent: 15  Rows_examined: 30
# Query_time: 0  Lock_time: 0  Rows_sent: 5  Rows_examined: 23
# Query_time: 0  Lock_time: 0  Rows_sent: 6  Rows_examined: 22
# Query_time: 0  Lock_time: 0  Rows_sent: 9  Rows_examined: 18
# Query_time: 0  Lock_time: 0  Rows_sent: 1  Rows_examined: 6
# Query_time: 0  Lock_time: 0  Rows_sent: 1  Rows_examined: 5
# Query_time: 0  Lock_time: 0  Rows_sent: 2  Rows_examined: 2
[root@test mysql]# grep -A 1 -B 2  "Rows_examined: 24460"  test-slow.lo
grep: test-slow.lo: No such file or directory
[root@test mysql]# grep -A 1 -B 2  "Rows_examined: 24460"  test-slow.log
# Time: 080430 20:02:29
#User@Host: match_account[match_account] @  [10.0.4.114]
# Query_time: 0  Lock_time: 0  Rows_sent: 30  Rows_examined: 24460
SELECT * FROM `profiles`    ORDER BY position, created_at DESC LIMIT 0, 30;

2）方法2：

[root@test mysql]# mysqldumpslow   -s  t   -t  20

Reading mysql slow query log from /home/mysql/test-slow.log
Count: 1  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=6.0 (6), match_account[match_account]@[10.0.4.114]
  SELECT * FROM `reports`    ORDER BY sequence desc LIMIT N

Count: 1  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=15.0 (15), match_account[match_account]@[10.0.4.114]
  SELECT * FROM `experts`   WHERE (email IS NULL)  ORDER BY sequence desc LIMIT N

一般我们关注的3类，参见

http://blog.dreamhosters.com/kbase/index.cgi?area=2868

A) "Rows_examined" is more than 2000
B) "Rows_examined" is less than 2000 but that query is being run 20 times a second.
C) "Rows_examined" is three times bigger than "Rows_sent"