慢查询日志：
MySQL慢查询日志记录下所有执行超过long_query_time时间的SQL语句，帮你找到执行慢的SQL，方便我们对这些SQL进行优化。
慢查询日志的配置：
默认情况下，mysql没有启用慢查询日志。
[root@rh64 ~]# mysql -u root -p
|
1
2
3
4
5
6
7
8
9
10
|
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)
1、可以配置my.cnf文件，服务启动时自动配置
[root@rh64 ~]# cat /etc/my.cnf
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
|
[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%';
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
|
+------------------------------------+------------------------------+
| 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)
|
2、在系统中配置slow-query-log
mysql> set @@global.slow_query_log = on;
mysql> show variables like '%slow%';
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
|
+------------------------------------+------------------------------+
| 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)
|
3、查看慢查询日志信息
[root@rh64 mysql]# tail rh64-slow.log
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
|
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)
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
|
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
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
|
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
|
1
2
3
4
5
6
|
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
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
|
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
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
|
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
|
按照平均锁定时间进行排序，查找前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
