Home > Database > Mysql Tutorial > body text

MySQL 日志之--慢查询日志(slow-query-log)_MySQL

WBOY
Release: 2016-05-27 13:46:31
Original
1268 people have browsed it

慢查询日志:

 

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 1

Server version: 5.6.25-73.1 Percona Server (GPL), Release 73.1, Revision 07b797f

Copyright (c) 2009-2015 Percona LLC and/or its affiliates

Copyright (c) 2000, 2015, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its

affiliates. Other names may be trademarks of their respective

owners。

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> show variables like '%slow%';

+------------------------------------+------------------------------+
| Variable_name                      | Value                        |
+------------------------------------+------------------------------+
| log_slow_admin_statements          | OFF                          |
| log_slow_filter                    |                              |
| log_slow_rate_limit                | 1                            |
| log_slow_rate_type                 | session                      |
| log_slow_slave_statements          | OFF                          |
| log_slow_sp_statements             | ON                           |
| log_slow_verbosity                 |                              |
| max_slowlog_files                  | 0                            |
| max_slowlog_size                   | 0                            |
| slow_launch_time                   | 2                            |
| slow_query_log                     | OFF                          |
| slow_query_log_always_write_time   | 10.000000                    |
| slow_query_log_file                | /var/lib/mysql/rh64-slow.log |
| slow_query_log_timestamp_always    | OFF                          |
| slow_query_log_timestamp_precision | second                       |
| slow_query_log_use_global_control  |                              |
+------------------------------------+------------------------------+
16 rows in set (0.01 sec)
Copy after login

1、可以配置my.cnf文件,服务启动时自动配置

[root@rh64 ~]# cat /etc/my.cnf

[mysqld]

datadir=/var/lib/mysql

socket=/var/lib/mysql/mysql.sock

user=mysql

# Disabling symbolic-links is recommended to prevent assorted security risks

symbolic-links=0

innodb_data_file_path=ibdata1:12M;ibdata2:10M:autoextend

sql_mode=STRICT_TRANS_TABLES ,NO_ENGINE_SUBSTITUTION

slow_query_log=true

slow_query_log_file = "/var/lib/mysql/rh64-slow.log"

long_query_time=1

log-queries-not-using-indexes=true

[mysqld_safe]

log-error=/var/log/mysqld.log

pid-file=/var/run/mysqld/mysqld.pid

explicit_defaults_for_timestamp=true

innodb_buffer_pool_size = 128M

join_buffer_size = 128M

sort_buffer_size = 2M

read_rnd_buffer_size = 2M

重启server后,查看:

mysql> show variables like '%slow%';

+------------------------------------+------------------------------+
| Variable_name                      | Value                        |
+------------------------------------+------------------------------+
| log_slow_admin_statements          | OFF                          |
| log_slow_filter                    |                              |
| log_slow_rate_limit                | 1                            |
| log_slow_rate_type                 | session                      |
| log_slow_slave_statements          | OFF                          |
| log_slow_sp_statements             | ON                           |
| log_slow_verbosity                 |                              |
| max_slowlog_files                  | 0                            |
| max_slowlog_size                   | 0                            |
|
 slow_launch_time                   | 2                            |
| slow_query_log                     | ON                           |
| slow_query_log_always_write_time   | 10.000000                    |
| slow_query_log_file                | /var/lib/mysql/rh64-slow.log |
| slow_query_log_timestamp_always    | OFF                          |
| slow_query_log_timestamp_precision | second                       |
| slow_query_log_use_global_control  |                              |
+------------------------------------+------------------------------+
16 rows in set (0.00 sec)
Copy after login

2、在系统中配置slow-query-log

mysql> set @@global.slow_query_log = on;

mysql> show variables like '%slow%';

+------------------------------------+------------------------------+
| Variable_name                      | Value                        |
+------------------------------------+------------------------------+
| log_slow_admin_statements          | OFF                          |
| log_slow_filter                    |                              |
| log_slow_rate_limit                | 1                            |
| log_slow_rate_type                 | session                      |
| log_slow_slave_statements          | OFF                          |
| log_slow_sp_statements             | ON                           |
| log_slow_verbosity                 |                              |
| max_slowlog_files                  | 0                            |
| max_slowlog_size                   | 0                            |
| slow_launch_time                   | 2                            |
| slow_query_log                     | ON                           |
| slow_query_log_always_write_time   | 10.000000                    |
| slow_query_log_file                | /var/lib/mysql/rh64-slow.log |
| slow_query_log_timestamp_always    | OFF                          |
| slow_query_log_timestamp_precision | second                       |
| slow_query_log_use_global_control  |                              |
+------------------------------------+------------------------------+
16 rows in set (0.00 sec)
Copy after login

3、查看慢查询日志信息

[root@rh64 mysql]# tail 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;
[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;
Copy after login

记录没有使用索引的语句:

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)
Copy after login

测试:

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;
Copy after login

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
Copy after login

[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
Copy after login

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

Reading mysql slow query log from rh64-slow.log
Count: 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 emp1
Count: 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 emp1
Count: 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
Copy after login

 

按照平均锁定时间进行排序,查找前10名:

  [root@rh64 mysql]# mysqldumpslow -s al -n 10 rh64-slow.log 

Reading mysql slow query log from rh64-slow.log

 

Count: 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 emp1

 

Count: 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 emp1

 

Count: 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

Related labels:
log
source:php.cn
Statement of this Website
The content of this article is voluntarily contributed by netizens, and the copyright belongs to the original author. This site does not assume corresponding legal responsibility. If you find any content suspected of plagiarism or infringement, please contact admin@php.cn
Popular Tutorials
More>
Latest Downloads
More>
Web Effects
Website Source Code
Website Materials
Front End Template