您好,欢迎来到三六零分类信息网!老站,搜索引擎当天收录,欢迎发信息

MySQL 之 slow log

2025/11/4 21:10:17发布10次查看
慢查询有什么用? 它能记录下所有执行超过long_query_time时间的sql语句,帮你找到执行慢的sql,方便我们对这些sql进行优化。 测试用 mysql 版本。 server version: 5.6.10-log source distribution 未做任何慢日志设置时。 mysql show variables like %que
慢查询有什么用?
它能记录下所有执行超过long_query_time时间的sql语句,帮你找到执行慢的sql,方便我们对这些sql进行优化。
测试用 mysql 版本。
server version: 5.6.10-log source distribution
未做任何慢日志设置时。
mysql> show variables like %query%; +------------------------------+--------------------------------------+ | variable_name | value | +------------------------------+--------------------------------------+ | binlog_rows_query_log_events | off | | ft_query_expansion_limit | 20 | | have_query_cache | yes | | long_query_time | 10.000000 | | query_alloc_block_size | 8192 | | query_cache_limit | 1048576 | | query_cache_min_res_unit | 4096 | | query_cache_size | 1048576 | | query_cache_type | off | | query_cache_wlock_invalidate | off | | query_prealloc_size | 8192 | | slow_query_log | off | | slow_query_log_file | /usr/local/mysql/data/betty-slow.log | +------------------------------+--------------------------------------+ 13 rows in set (0.01 sec) mysql>
修改配置文件,开启 slow log 。
[root@betty data]# vi /etc/my.cnf # for advice on how to change settings please see # http://dev.mysql.com/doc/refman/5.6/en/server-configuration-defaults.html # *** do not edit this file. it's a template which will be copied to the # *** default location during install, and will be replaced if you # *** upgrade to a newer version of mysql. [mysqld] # remove leading # and set to the amount of ram for the most important data # cache in mysql. start at 70% of total ram for dedicated server, else 10%. # innodb_buffer_pool_size = 128m # remove leading # to turn on a very important data integrity option: logging # changes to the binary log between backups. log_bin=mysql-bin slow_query_log=on slow_query_log_file=mysql-slow long_query_time=2 # these are commonly set, remove the # and set as required. # basedir = ..... # datadir = ..... # port = ..... # server_id = ..... # socket = ..... # remove leading # to set options mainly useful for reporting servers. # the server defaults are faster for transactions and fast selects. # adjust sizes as needed, experiment to find the optimal values. # join_buffer_size = 128m # sort_buffer_size = 2m # read_rnd_buffer_size = 2m sql_mode=no_engine_substitution,strict_trans_tables [mysql] socket = /tmp/mysql.sock
重启 mysql 。
[root@betty data]# /etc/init.d/mysql restart shutting down mysql.. [ ok ] starting mysql. [ ok ] [root@betty data]#
查看 slow log 。
[root@betty data]# ll mysql-slow -rw-rw---- 1 mysql mysql 719 sep 6 12:43 mysql-slow
重新查看系统变量值。
mysql> mysql> show variables like %query%; +------------------------------+------------+ | variable_name | value | +------------------------------+------------+ | binlog_rows_query_log_events | off | | ft_query_expansion_limit | 20 | | have_query_cache | yes | | long_query_time | 2.000000 | | query_alloc_block_size | 8192 | | query_cache_limit | 1048576 | | query_cache_min_res_unit | 4096 | | query_cache_size | 1048576 | | query_cache_type | off | | query_cache_wlock_invalidate | off | | query_prealloc_size | 8192 | | slow_query_log | on | | slow_query_log_file | mysql-slow | +------------------------------+------------+ 13 rows in set (0.00 sec) mysql>
查看新生成的 slow log 的内容。
[root@betty data]# cat mysql-slow /usr/local/mysql/bin/mysqld, version: 5.6.10-log (source distribution). started with: tcp port: 0 unix socket: (null) time id command argument [root@betty data]#
测试 slow log 。
mysql> mysql> select 1; +---+ | 1 | +---+ | 1 | +---+ 1 row in set (0.00 sec) mysql> mysql> select sleep(1); +----------+ | sleep(1) | +----------+ | 0 | +----------+ 1 row in set (1.00 sec) mysql> mysql> mysql> select sleep(3); +----------+ | sleep(3) | +----------+ | 0 | +----------+ 1 row in set (3.00 sec) mysql> mysql> select sleep(4); +----------+ | sleep(4) | +----------+ | 0 | +----------+ 1 row in set (4.01 sec) mysql> mysql> mysql> select sleep(5); +----------+ | sleep(5) | +----------+ | 0 | +----------+ 1 row in set (5.00 sec) mysql> select sleep(2); +----------+ | sleep(2) | +----------+ | 0 | +----------+ 1 row in set (2.01 sec) mysql> mysql> select sleep(1); +----------+ | sleep(1) | +----------+ | 0 | +----------+ 1 row in set (1.00 sec) mysql> select 2; +---+ | 2 | +---+ | 2 | +---+ 1 row in set (0.00 sec) mysql>
查看此时 slow log 的内容。
[root@betty data]# cat mysql-slow /usr/local/mysql/bin/mysqld, version: 5.6.10-log (source distribution). started with: tcp port: 0 unix socket: (null) time id command argument # time: 130906 12:52:51 # user@host: root[root] @ localhost [] id: 1 # query_time: 3.002864 lock_time: 0.000000 rows_sent: 1 rows_examined: 0 set timestamp=1378443171; select sleep(3); # time: 130906 12:53:01 # user@host: root[root] @ localhost [] id: 1 # query_time: 4.001943 lock_time: 0.000000 rows_sent: 1 rows_examined: 0 set timestamp=1378443181; select sleep(4); # time: 130906 12:53:09 # user@host: root[root] @ localhost [] id: 1 # query_time: 5.002093 lock_time: 0.000000 rows_sent: 1 rows_examined: 0 set timestamp=1378443189; select sleep(5); # time: 130906 12:53:15 # user@host: root[root] @ localhost [] id: 1 # query_time: 2.002984 lock_time: 0.000000 rows_sent: 1 rows_examined: 0 set timestamp=1378443195; select sleep(2); [root@betty data]#
实验:
a. 使用 mysql 自带慢查询日志分析工具 mysqldumpslow 。
[root@betty data]# mysqldumpslow mysql-slow reading mysql slow query log from mysql-slow count: 4 time=3.50s (14s) lock=0.00s (0s) rows=1.0 (4), root[root]@localhost select sleep(n) [root@betty data]#
b. 使用 hackmysql.com 推出的一款日志分析工具 mysqlsla 。
[root@betty data]# mysqlsla -lt slow mysql-slow report for slow logs: mysql-slow 4 queries total, 1 unique sorted by 't_sum' grand totals: time 14 s, lock 0 s, rows sent 4, rows examined 0 ______________________________________________________________________ 001 ___ count : 4 (100.00%) time : 14.009884 s total, 3.502471 s avg, 2.002984 s to 5.002093 s max (100.00%) lock time (s) : 0 total, 0 avg, 0 to 0 max (0.00%) rows sent : 1 avg, 1 to 1 max (100.00%) rows examined : 0 avg, 0 to 0 max (0.00%) database : users : root@localhost : 100.00% (4) of query, 100.00% (4) of all users query abstract: set timestamp=n; select sleep(n); query sample: set timestamp=1378443171; select sleep(3); [root@betty data]#
c. 使用德国人写的 mysql_explain_slow_log 。(不知道为什么未统计出信息)
[root@betty wget_dir]# ./mysql_explain_slow_log --user=root --password= --socket=/tmp/mysql.sock d.
google code 上的一个分析工具 mysql_filter_slow_log (最后更新日期为2007年),提供了 python 和 php 两种可执行的脚本。
[root@betty wget_dir]# python mysql_filter_slow_log.py /usr/local/mysql/data/mysql-slow --no-duplicates --sort-execution-count --top=10# execution count: 1 time on 2013-09-06 16:07:23.# column : avg | max | sum# query time : 5 | 5 | 5# lock time : 0 | 0 | 0# rows examined: 0 | 0 | 0# rows sent : 1 | 1 | 1# user@host: root[root] @ localhost [] id: 1set timestamp=1378454843;select sleep(5);# execution count: 1 time on 2013-09-06 16:07:15.# column : avg | max | sum# query time : 4 | 4 | 4# lock time : 0 | 0 | 0# rows examined: 0 | 0 | 0# rows sent : 1 | 1 | 1# user@host: root[root] @ localhost [] id: 1set timestamp=1378454835;select sleep(4);# execution count: 1 time on 2013-09-06 16:07:01.# column : avg | max | sum# query time : 3 | 3 | 3# lock time : 0 | 0 | 0# rows examined: 0 | 0 | 0# rows sent : 1 | 1 | 1# user@host: root[root] @ localhost [] id: 1set timestamp=1378454821;select sleep(3);# execution count: 1 time on 2013-09-06 16:07:28.# column : avg | max | sum# query time : 2 | 2 | 2# lock time : 0 | 0 | 0# rows examined: 0 | 0 | 0# rows sent : 1 | 1 | 1# user@host: root[root] @ localhost [] id: 1set timestamp=1378454848;select sleep(2);[root@betty wget_dir]#
e. 使用 percona-toolkit 中的 pt-query-digest (在《高性能mysql》中多次提出,值得使用的工具)。
[root@betty data]# pt-query-digest --user=root mysql-slow # 120ms user time, 10ms system time, 20.21m rss, 68.70m vsz# current date: mon sep 9 13:21:38 2013# hostname: betty# files: mysql-slow# overall: 4 total, 1 unique, 0.15 qps, 0.52x concurrency ________________# time range: 2013-09-06 16:07:01 to 16:07:28# attribute total min max avg 95% stddev median# ============ ======= ======= ======= ======= ======= ======= =======# exec time 14s 2s 5s 4s 5s 1s 4s# lock time 0 0 0 0 0 0 0# rows sent 4 1 1 1 1 0 1# rows examine 0 0 0 0 0 0 0# query size 60 15 15 15 15 0 15# profile# rank query id response time calls r/call v/m item# ==== ================== ============== ===== ====== ===== ======# 1 0xf9a57dd5a41825ca 14.0097 100.0% 4 3.5024 0.36 select# query 1: 0.15 qps, 0.52x concurrency, id 0xf9a57dd5a41825ca at byte 548# this item is included in the report because it matches --limit.# scores: v/m = 0.36# time range: 2013-09-06 16:07:01 to 16:07:28# attribute pct total min max avg 95% stddev median# ============ === ======= ======= ======= ======= ======= ======= =======# count 100 4# exec time 100 14s 2s 5s 4s 5s 1s 4s# lock time 0 0 0 0 0 0 0 0# rows sent 100 4 1 1 1 1 0 1# rows examine 0 0 0 0 0 0 0 0# query size 100 60 15 15 15 15 0 15# string:# hosts localhost# users root# query_time distribution# 1us# 10us# 100us# 1ms# 10ms# 100ms# 1s ################################################################# 10s+# explain /*!50100 partitions*/select sleep(5)\g[root@betty data]#
慢查询配置项
# i.e. you could add the following lines under the [mysqld] section of your my.ini or my.cnf configuration file:# log all queries taking more than 3 secondslong_query_time=3 # minimum: 1, default: 10# mysql >= 5.1.21 (or patched): 3 seconds = 3000000 microseconds# long_query_time=3.000000 # minimum: 0.000001 (1 microsecond)# activate the slow query logslow_query_log # >= 5.1.29# log-slow-queries # deprecated since 5.1.29# write to a custom file name (>= 5.1.29)# slow_query_log_file=file_name # default: /data_dir/host_name-slow.log# log all queries without indexes# log-queries-not-using-indexes# log only queries which examine at least n rows (>= 5.1.21)# min_examined_row_limit=1000 # default: 0# log slow optimize table, analyze table, and alter table statements# log-slow-admin-statements# log slow queries executed by replication slaves (>= 5.1.21)# log-slow-slave-statements# mysql 5.1.6 through 5.1.20 had a default value of log-output=table, so you should force# attention: logging to table only includes whole seconds informationlog-output=file## admin query for online activation is possible since mysql 5.1 (without server restart)## set @@global.slow_query_log=1## set @@global.long_query_time=1## show current variables related to the slow query log## show global variables where variable_name regexp 'admin|min_examined|log_output|log_queries|log_slave|long|slow_quer'
========= 我是分割线 =========
下面给出网上一篇流传已久的博客文章,供参考(做了部分修正)。
参考:《五款常用mysql slow log分析工具的比较》,原文写于2008年。
mysql slow log 分析工具的比较
mysql 中的 slow log 是用来记录执行时间较长(超过 long_query_time 秒)的 sql 的一种日志工具。
启用 slow log
在 my.cnf 中设置
[mysqld]slow_query_log=onslow_query_log_file=mysql-slow
重启 mysql 服务。
五款常用工具
mysqldumpslow mysqlsla myprofi mysql-explain-slow-log mysql-log-filter mysqldumpslow mysql官方提供的慢查询日志分析工具。输出图表如下:
主要功能包括统计不同慢 sql 的
出现次数(count) 执行耗费的平均时间和累计总耗费时间(time) 等待锁耗费的时间(lock) 发送给客户端的行总数(rows) 扫描的行总数(rows) 用户以及sql语句本身(抽象了一下格式,比如 limit 1, 20 用 limit n,n 表示) mysqlsla hackmysql.com 推出的一款日志分析工具(该网站还维护了 mysqlreport,mysqlidxchk 等比较实用的mysql 工具)。
整体来说,功能非常强大。输出的数据报表非常有利于分析慢查询的原因,包括执行频率、数据量、查询消耗等。
格式说明如下:
总查询次数 (queries total),去重后的 sql 数量 (unique) 输出报表的内容排序(sorted by) 最重大的慢 sql 统计信息,包括平均执行时间、等待锁时间、结果行的总数、扫描的行总数。 count --sql 的执行次数及占总的 slow log 数量的百分比。 time -- 执行时间,包括总时间、平均时间、最小、最大时间、时间占到总慢 sql 时间的百分比。 95% of time -- 去除最快和最慢的 sql,覆盖率占 95% 的 sql 的执行时间。 lock time -- 等待锁的时间。 95% of lock -- 95% 的慢 sql 等待锁时间。 rows sent -- 结果行统计数量,包括平均、最小、最大数量。 rows examined -- 扫描的行数量。 database -- 属于哪个数据库。 users -- 哪个用户、ip、占到所有用户执行的 sql 百分比。 query abstract -- 抽象后的 sql 语句。 query sample -- sql 语句。 除了以上的输出,官方还提供了很多定制化参数,是一款不可多得的好工具。
mysql-explain-slow-log 德国人写的一个 perl 脚本。
http://www.willamowius.de/mysql-tools.html
http://www.bt285.cn/content.php?id=1196863
功能上有点瑕疵。不仅把所有的 slow log 打印到屏幕上,而且统计也只有数量而已,不推荐使用。
mysql-log-filter google code 上找到的一个分析工具,提供了 python 和 php 两种可执行的脚本。
http://code.google.com/p/mysql-log-filter/
功能上比官方的 mysqldumpslow 多了查询时间的统计信息(平均、最大、累计),其他功能都与 mysqldumpslow 类似。
特色功能除了统计信息外,还针对输出内容做了排版和格式化,保证整体输出的简洁。喜欢简洁报表的朋友,推荐使用一下。
myprofi 纯 php 写的一个开源分析工具.项目在 sourceforge 上。
http://myprofi.sourceforge.net/ ==> 已变为http://sourceforge.net/projects/myprofi/
功能上,列出了总的慢查询次数和类型、去重后的 sql 语句、执行次数及其占总的 slow log 数量的百分比。
从整体输出样式来看,比 mysql-log-filter 还要简洁,省去了很多不必要的内容。对于只想看 sql 语句及执行次数的用户来说,比较推荐。
总结:
工具/功能 一般统计信息 高级统计信息 脚本 优势
mysqldumpslow 支持 不支持 perl mysql官方自带
mysqlsla 支持 支持 perl 功能强大,数据报表齐全,定制化能力强
mysql-explain-slow-log 支持 不支持 perl 无
mysql-log-filter 支持 部分支持 python or php 不失功能的前提下,保持输出简洁
myprofi 支持 不支持 php 非常精简
原文地址:mysql 之 slow log, 感谢原作者分享。
该用户其它信息

VIP推荐

免费发布信息,免费发布B2B信息网站平台 - 三六零分类信息网 沪ICP备09012988号-2
企业名录 Product