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

MySQL log-slow query log (slow-query-log)
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 ~] # 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 07b797fCopyright (c) 2009-2015 Percona LLC and/or its affiliatesCopyright (c) 2000,201 5, Oracle and/or its affiliates. all rights reserved. oracle is a registered trademark of Oracle Corporation and/or itsaff Iliates. Other names may be trademarks of their respectiveowners. 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 during service startup [root @ rh64 ~] # Cat/etc/my. cnf [mysqld] datadir =/var/lib/mysqlsocket =/var/lib/mysql. sockuser = mysql # Disabling symbolic-links is recommended to prevent assorted security riskssymbolic-links = encrypted = ibdata1: 12 M; ibdata2: 10 M: autoextendsql_mode = STRICT_TRANS_TABLES, NO_ENGINE_SUBSTITUTION slow_query_log = trueslow_query_log_file = "/var/lib/mysql/rh64-slow.log" long_query_time = Success = true [mysqld_safe] log-error =/var/log/mysqld. logpid-file =/var/run/mysqld. restart = trueinnodb_buffer_pool_size = 128Mjoin_buffer_size = 128Msort_buffer_size = 2Mread_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-logmysql> set @ global. slow_query_log = on in the system; 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_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)

 

Test: 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: 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, find 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