MySQL log-slow query log (slow-query-log) _ MySQL

Slow query log: all SQL statements that run longer than long_query_time in MySQL slow query log records help you find slow SQL statements, so that we can optimize these SQL statements. Slow query log configuration: by default, mysql does not enable slow query logs. [Root @ rh64 slow query log:

The MySQL slow query log records all SQL statements that have been executed for more than long_query_time. this helps you find slow SQL statements and optimize these SQL statements.

Configuration of slow query logs:

By default, mysql does not enable slow query logs.

[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,201 5, 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. you can configure the my. cnf file, which is automatically configured when the service is started.

[Root @ rh64 ~] # Cat/etc/my. cnf

[Mysqld]

Datadir =/var/lib/mysql

Socket =/var/lib/mysql. sock

User = mysql

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

Symbolic-links = 0

Innodb_data_file_path = ibdata1: 12 M; ibdata2: 10 M: 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. pid

Explicit_defaults_for_timestamp = true

Innodb_buffer_pool_size = 128 M

Join_buffer_size = 128 M

Sort_buffer_size = 2 M

Read_rnd_buffer_size = 2 M

After the server is restarted, view:

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)

2. configure slow-query-log in the system

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)

3. View slow query log information

[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: 58SET 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: 58SET 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: 59SET 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: 59SET timestamp=1449476806;insert into emp1 select * from emp1;

The record does not use the index statement:

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_pe_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)

Test:

Mysql> select count (*) from emp1 where empno = 7788;

+ ---------- +

| Count (*) |

+ ---------- +

| 1, 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: 58SET 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: 59SET 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: 59SET 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: 68SET timestamp=1449477044;select count(*) from emp1 where empno=7788;

4. use mysqldumpslow to view slow query logs

[root@rh64 mysql]# mysqldumpslowCan'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

Sort by average lock time and search for the top 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.00 s (0 s) Lock = 0.00 s (0 s) 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.00 s (0 s) Lock = 0.00 s (0 s) 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.00 s (0 s) Lock = 0.00 s (0 s) 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