MySQL 日志之--慢查询日志（slow-query-log）

来源：互联网发布：乐高机器人ev3编程软件编辑：程序博客网时间：2024/05/29 17:08

MySQL 日志之--慢查询日志（slow-query-log）

慢查询日志：

MySQL慢查询日志记录下所有执行超过long_query_time时间的SQL语句，帮你找到执行慢的SQL，方便我们对这些SQL进行优化。

慢查询日志的配置：

默认情况下，mysql没有启用慢查询日志。

[root@rh64 ~]# mysql -u root -p
Enter password:

Welcome to the MySQL monitor.  Commands end with ; or \g.Your MySQL connection id is 1Server version: 5.6.25-73.1 Percona Server (GPL), Release 73.1, Revision 07b797fCopyright (c) 2009-2015 Percona LLC and/or its affiliatesCopyright (c) 2000, 2015, Oracle and/or its affiliates. All rights reserved.Oracle is a registered trademark of Oracle Corporation and/or itsaffiliates. Other names may be trademarks of their respectiveowners。Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

[mysqld]datadir=/var/lib/mysqlsocket=/var/lib/mysql/mysql.sockuser=mysql# Disabling symbolic-links is recommended to prevent assorted security riskssymbolic-links=0innodb_data_file_path=ibdata1:12M;ibdata2:10M:autoextendsql_mode=STRICT_TRANS_TABLES ,NO_ENGINE_SUBSTITUTIONslow_query_log=trueslow_query_log_file = "/var/lib/mysql/rh64-slow.log"long_query_time=1log-queries-not-using-indexes=true[mysqld_safe]log-error=/var/log/mysqld.logpid-file=/var/run/mysqld/mysqld.pidexplicit_defaults_for_timestamp=trueinnodb_buffer_pool_size = 128Mjoin_buffer_size = 128Msort_buffer_size = 2Mread_rnd_buffer_size = 2M

use prod;SET timestamp=1449476453;insert into emp1 select * from emp1;# Time: 151207 16:21:11# User@Host: root[root] @ localhost []  Id:     2# Schema: prod  Last_errno: 0  Killed: 0# Query_time: 16.748949  Lock_time: 0.000137  Rows_sent: 0  Rows_examined: 1236992  Rows_affected: 618496# Bytes_sent: 58

SET timestamp=1449476471;insert into emp1 select * from emp1;[root@rh64 mysql]# tail -f rh64-slow.log use prod;

SET timestamp=1449476453;insert into emp1 select * from emp1;# Time: 151207 16:21:11# User@Host: root[root] @ localhost []  Id:     2# Schema: prod  Last_errno: 0  Killed: 0# Query_time: 16.748949  Lock_time: 0.000137  Rows_sent: 0  Rows_examined: 1236992  Rows_affected: 618496# Bytes_sent: 58

SET timestamp=1449476471;insert into emp1 select * from emp1;# Time: 151207 16:22:54# User@Host: root[root] @ localhost []  Id:     2# Schema: prod  Last_errno: 0  Killed: 0# Query_time: 44.036039  Lock_time: 0.000083  Rows_sent: 0  Rows_examined: 2473984  Rows_affected: 1236992# Bytes_sent: 59

SET timestamp=1449476574;insert into emp1 select * from emp1;# Time: 151207 16:26:46# User@Host: root[root] @ localhost []  Id:     2# Schema: prod  Last_errno: 0  Killed: 0# Query_time: 106.674422  Lock_time: 0.000148  Rows_sent: 0  Rows_examined: 4947968  Rows_affected: 2473984# Bytes_sent: 59

SET timestamp=1449476806;insert into emp1 select * from emp1;

记录没有使用索引的语句：
mysql> set @@global.log_queries_not_using_indexes=on;
Query OK, 0 rows affected (0.00 sec)

mysql> show variables like '%index%';
+----------------------------------------+-------+
| Variable_name | Value |
+----------------------------------------+-------+
| eq_range_index_dive_limit | 10 |
| expand_fast_index_creation | OFF |
| innodb_adaptive_hash_index | ON |
| innodb_adaptive_hash_index_partitions | 1 |
| innodb_cmp_per_index_enabled | OFF |
| log_bin_index | |
| log_queries_not_using_indexes | ON |
| log_throttle_queries_not_using_indexes | 0 |
| relay_log_index | |
+----------------------------------------+-------+
9 rows in set (0.00 sec)

测试：
mysql> select count(*) from emp1 where empno=7788;
+----------+
| count(*) |
+----------+
| 688128 |
+----------+
1 row in set (4.03 sec)

[root@rh64 mysql]# tail rh64-slow.log

SET timestamp=1449476453;insert into emp1 select * from emp1;# Time: 151207 16:21:11# User@Host: root[root] @ localhost []  Id:     2# Schema: prod  Last_errno: 0  Killed: 0# Query_time: 16.748949  Lock_time: 0.000137  Rows_sent: 0  Rows_examined: 1236992  Rows_affected: 618496# Bytes_sent: 58

SET timestamp=1449476471;insert into emp1 select * from emp1;# Time: 151207 16:22:54# User@Host: root[root] @ localhost []  Id:     2# Schema: prod  Last_errno: 0  Killed: 0# Query_time: 44.036039  Lock_time: 0.000083  Rows_sent: 0  Rows_examined: 2473984  Rows_affected: 1236992# Bytes_sent: 59

SET timestamp=1449476574;insert into emp1 select * from emp1;# Time: 151207 16:26:46# User@Host: root[root] @ localhost []  Id:     2# Schema: prod  Last_errno: 0  Killed: 0# Query_time: 106.674422  Lock_time: 0.000148  Rows_sent: 0  Rows_examined: 4947968  Rows_affected: 2473984# Bytes_sent: 59

SET timestamp=1449476806;insert into emp1 select * from emp1;# Time: 151207 16:30:44# User@Host: root[root] @ localhost []  Id:     2# Schema: prod  Last_errno: 0  Killed: 0# Query_time: 4.025612  Lock_time: 0.000098  Rows_sent: 1  Rows_examined: 4947968  Rows_affected: 0# Bytes_sent: 68

SET timestamp=1449477044;select count(*) from emp1 where empno=7788;

4、通过mysqldumpslow工具查看慢查询日志
[root@rh64 mysql]# mysqldumpslow

Can't determine basedir from 'my_print_defaults mysqld' output: --datadir=/var/lib/mysql--socket=/var/lib/mysql/mysql.sock--user=mysql--symbolic-links=0--innodb_data_file_path=ibdata1:12M;ibdata2:10M:autoextend--sql_mode=STRICT_TRANS_TABLES ,NO_ENGINE_SUBSTITUTION

[root@rh64 mysql]# mysqldumpslow --help

Usage: mysqldumpslow [ OPTS... ] [ LOGS... ]Parse and summarize the MySQL slow query log. Options are  --verbose    verbose  --debug      debug  --help       write this text to standard output  -v           verbose  -d           debug  -s ORDER     what to sort by (al, at, ar, c, l, r, t), 'at' is default                al: average lock time                ar: average rows sent                at: average query time                 c: count                 l: lock time                 r: rows sent                 t: query time    -r           reverse the sort order (largest last instead of first)  -t NUM       just show the top n queries  -a           don't abstract all numbers to N and strings to 'S'  -n NUM       abstract numbers with at least n digits within names  -g PATTERN   grep: only consider stmts that include this string  -h HOSTNAME  hostname of db server for *-slow.log filename (can be wildcard),               default is '*', i.e. match all  -i NAME      name of server instance (if using mysql.server startup script)  -l           don't subtract lock time from total time

[root@rh64 mysql]# mysqldumpslow rh64-slow.log

Reading mysql slow query log from rh64-slow.logCount: 3  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), root[root]@localhost  # Schema: prod  Last_errno: N  Killed: N  # Query_time: N.N  Lock_time: N.N  Rows_sent: N  Rows_examined: N  Rows_affected: N  # Bytes_sent: N  SET timestamp=N;  insert into emp1 select * from emp1Count: 1  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), root[root]@localhost  # Schema: prod  Last_errno: N  Killed: N  # Query_time: N.N  Lock_time: N.N  Rows_sent: N  Rows_examined: N  Rows_affected: N  # Bytes_sent: N  use prod;  SET timestamp=N;  insert into emp1 select * from emp1Count: 1  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), root[root]@localhost  # Schema: prod  Last_errno: N  Killed: N  # Query_time: N.N  Lock_time: N.N  Rows_sent: N  Rows_examined: N  Rows_affected: N  # Bytes_sent: N  SET timestamp=N;  select count(*) from emp1 where empno=N    按照平均锁定时间进行排序，查找前10名：  [root@rh64 mysql]# mysqldumpslow -s al -n 10 rh64-slow.log Reading mysql slow query log from rh64-slow.logCount: 3  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), root[root]@localhost  # Schema: prod  Last_errno: N  Killed: N  # Query_time: N.N  Lock_time: N.N  Rows_sent: N  Rows_examined: N  Rows_affected: N  # Bytes_sent: N  SET timestamp=N;  insert into emp1 select * from emp1Count: 1  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), root[root]@localhost  # Schema: prod  Last_errno: N  Killed: N  # Query_time: N.N  Lock_time: N.N  Rows_sent: N  Rows_examined: N  Rows_affected: N  # Bytes_sent: N  use prod;  SET timestamp=N;  insert into emp1 select * from emp1Count: 1  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), root[root]@localhost  # Schema: prod  Last_errno: N  Killed: N  # Query_time: N.N  Lock_time: N.N  Rows_sent: N  Rows_examined: N  Rows_affected: N  # Bytes_sent: N  SET timestamp=N;  select count(*) from emp1 where empno=N

0 0