MySQL Slow Query Log (Slow Query Log), mysqlslow

MySQL Slow Query Log (Slow Query Log), mysqlslow

Like most relational databases, log files are an important part of MySQL databases. MySQL has several different log files, such as error log files, binary logs, common logs, and slow query logs. These logs help us locate the internal events of mysqld, database performance faults, record the change history of data, and recover the database. This document describes general query logs.

 

1. Composition of the MySQL Log File System
A. Error Log: records the problems that occur when mysqld is started, running, or stopped.
B. General logs: records established client connections and executed statements.
C. Update logs: statements used to record and change data. This log is no longer used in MySQL 5.1.
D. binary log: records all statements for changing data. It is also used for replication.
E. Slow query log: records all queries whose execution time exceeds long_query_time seconds or where no index is used.
F. Innodb log: innodb redo log

By default, all logs are created in the mysqld data directory.
You can force mysqld to close and reopen the log file by refreshing the log (or switch to a new log in some cases ).
When you execute a flush logs statement or mysqladmin flush-logs or mysqladmin refresh, the log is aging.
In the case of MySQL replication, the slave replication server maintains more log files, which are called replacement logs.

 

2. Slow query logs
Slow query logs record SQL statements that affect the database performance on the mysql server to log files. By analyzing these special SQL statements, you can improve the database performance.
Use the -- slow_query_log [= {0 | 1}] Option to enable slow query logs. All SQL statements whose execution time exceeds long_query_time are recorded in slow query logs.
By default, the hostname-slow.log is the name of the slow query log file, which is stored in the data directory. By default, the slow query log is not enabled.
By default, managed SQL statements (such as OPTIMIZE TABLE, ANALYZE TABLE, and ALTER TABLE) related to the database are not logged.
For management SQL statements, you can use -- log-slow-admin-statements to enable slow SQL statements for record management.
After the statement is executed and all the locks are released, the mysqld logs are recorded as slow query logs. The record sequence may be different from the execution sequence. Obtaining the initial lock time is not counted as the execution time.

You can use the mysqldumpslow command to obtain the query summary displayed in the log to process slow query logs.
Queries processed using the query cache are not added to the slow query log. queries with zero rows or one row in the table that cannot benefit from the index are not written into the slow query log.
The MySQL server records whether SQL statements are written to slow query logs in the following order.
A. The query must either not be an administrative statement, or -- log-slow-adminstatements must have been specified.
B. The query must have taken at least long_query_time seconds, or log_queries_not_using_indexes must be enabled and the query used no indexes for row lookups.
C. The query must have examined at least min_examined_row_limit rows.
D. The query must not be suppressed according to the log_throttle_queries_not_using_indexes setting.

 

3. Slow query log demonstration

Long_query_time: set the threshold for slow queries. The SQL statements that exceed the threshold are recorded in slow query logs. The default value is 10sslow_query_log: whether to enable log_slow_queries: specify whether to enable the slow query log (this parameter is to be replaced by slow_query_log for compatibility retention) slow_query_log_file: Specifies the location where the slow log file is stored, can be empty, the system will give a default file host_name-slow.logmin_examined_row_limit: the query check returns SQL statements that are less than the specified row of this parameter and are not recorded in the slow query log log_queries_not_using_indexes: whether the index is recorded in slow query logs without indexes -- the current version root @ localhost [(none)]> show variables like 'version '; + --------------- + ------------ + | Variable_name | Value | + --------------- + ------------ + | version | 5.5.39-log | + --------------- + ------------ + root @ localhost [(none)]> show variables like '% slow % '; + dimensions + | Variable_name | Value | + dimensions + | log_slow_queries | OFF | slow_launch_time | 2 | slow_query_log | OFF | slow_query_log_file |/var/lib/mysql/ suse11b-slow.log | + ----------------------- + ------------------------------- + root @ localhost [tempdb]> set global log_slow_queries = 1; query OK, 0 rows affected, 1 warning (0.00 sec) root @ localhost [(none)]> show warnings; + --------- + ------ + threshold + | Level | Code | Message | + --------- + ------ + threshold + | Warning | 1287 | '@ log_slow_queries' is deprecated and will be removed in a future release. please use '@ slow_query_log' instead | + --------- + ------ + rows + -- The following query shows the two system variables log_slow_queries, slow_query_log is also set to onroot @ localhost [(none)]> show variables like '% slow % '; + dimensions + | Variable_name | Value | + dimensions + | log_slow_queries | ON | slow_launch_time | 2 | slow_query_log | ON | slow_query_log_file |/var/lib/mysql/ suse11b-slow.log | + --------------------- + ------------------------------- + root @ localhost [tempdb]> show variables like '% long_query_time % '; + ----------------- + --------- + | Variable_name | Value | + ----------------- + ----------- + | long_query_time | 10.000000 | + ----------------- + ----------- + -- for ease of demonstration, we set global and session level long_query_time to 1root @ localhost [tempdb]> set global long_query_time = 1; Query OK, 0 rows affected (0.00 sec) root @ localhost [tempdb]> set session long_query_time = 1; Query OK, 0 rows affected (0.00 sec) -- Author: Leshami -- Blog: tables> create table tb_slow as select * from information_schema.columns; Query OK, 829 rows affected (0.10 sec) Records: 829 Duplicates: 0 Warnings: 0root @ localhost [tempdb]> insert into tb_slow select * from tb_slow; Query OK, 829 rows affected (0.05 sec) Records: 829 Duplicates: 0 Warnings: 0 ..... to facilitate the demonstration, we inserted some data. The repeated process in the middle omitted root @ localhost [tempdb]> insert into tb_slow select * from tb_slow; Query OK, 26528 rows affected (4.40 sec) Records: 26528 Duplicates: 0 Warnings: 0root @ localhost [tempdb]> system tail/var/lib/mysql/suse11b-slow.log/usr/sbin/mysqld, Version: 5.5.39-log (MySQL Community Server (GPL )). started with: Tcp port: 3306 Unix socket:/var/lib/mysql. sockTime Id Command Argument # Time: 141004 22:05:48 # User @ Host: root [root] @ localhost [] # Query_time: 4.396858 Lock_time: 0.000140 Rows_sent: 0 Rows_examined: 53056use tempdb; SET timestamp = 1412431548; insert into tb_slow select * from tb_slow ;.... insert some records again .... root @ localhost [tempdb]> insert into tb_slow select * from tb_slow; Query OK, 212224 rows affected (37.51 sec) Records: 212224 Duplicates: 0 Warnings: 0root @ localhost [tempdb]> select table_schema, table_name, count (*) from tb_slow-> group by table_schema, table_name order by 3, 2; + -------------------- + ---------------------------------------------- + ---------- + | table_schema | table_name | count (*) | + ------------------ + region + ---------- + | information_schema | COLLATION_CHARACTER_SET_APPLICABILITY | 1024 | performance_schema | cond_instances | 1024 | ........... | mysql | user | 21504 | + -------------------- + ---------------------------------------------- + ---------- + 83 rows in set (1.58 sec) root @ localhost [tempdb]> system tail/var/lib/mysql/suse11b-slow.log # User @ Host: root [root] @ localhost [] # Query_time: 37.514172 Lock_time: 0.000123 Rows_sent: 0 Rows_examined: 424448 SET timestamp = 1412431806; insert into tb_slow select * from tb_slow; # Time: 141004 22:10:47 # User @ Host: root [root] @ localhost [] # Query_time: 1.573293 Lock_time: 0.000183 Rows_sent: 83 Rows_examined: 424614 SET timestamp = 1412431847; select table_schema, table_name, count (*) from tb_slow -- This SQL statement is recorded, the query time is 1.573293 sgroup by table_schema, table_name order by; root @ localhost [tempdb]> show variables like '% log_queries_not_using_indexes '; + region + ------- + | Variable_name | Value | + region + ------- + | log_queries_not_using_indexes | OFF | + region + ------- + root @ localhost [tempdb]> set global log_queries_not_using_indexes = 1; query OK, 0 rows affected (0.00 sec) -- view the table tb_slow index information. The table tb_slow does not have any index. root @ localhost [tempdb]> show index from tb_slow; Empty set (0.00 sec) root @ localhost [tempdb]> select count (*) from tb_slow; + ---------- + | count (*) | + ---------- + | 424448 | + ---------- + 1 row in set (0.20 sec) root @ localhost [tempdb]> system tail-n3/var/lib/mysql/suse11b-slow.log # Query_time: 0.199840 Lock_time: 0.000152 Rows_sent: 1 Rows_examined: 424448 SET timestamp = 1412432188; select count (*) from tb_slow; -- the query time is 0.199840, because the index is not taken, because the table itself has no index

4. Format slow query logs

Structured slow query logs extract important information in slow query logs based on ease of reading and specific sorting methods. This method is similar to formatting the trace file of Oracle using tkprof in oracle. For the previous slow query log, we use mysqldumpslow to extract the following: suse11b :~ # Mysqldumpslow-s at, al/var/lib/mysql/suse11b-slow.logReading mysql slow query log from/var/lib/mysql/suse11b-slow.logCount: 4 Time = 16.87 s (67 s) lock = 0.00 s (0 s) Rows = 0.0 (0), root [root] @ localhost insert into tb_slow select * from tb_slowCount: 1 Time = 0.20 s (0 s) lock = 0.00 s (0 s) Rows = 1.0 (1), root [root] @ localhost select count (*) from tb_slowCount: 1 Time = 1.57 s (1 s) lock = 0.00 s (0 s) Rows = 83.0 (83 ), Root [root] @ localhost select table_schema, table_name, count (*) from tb_slow group by table_schema, table_name order by N, N # The following is the last line according to the maximum consumption time, only two logs are displayed. format the log file suse11b :~ # Mysqldumpslow-r-t 2/var/lib/mysql/suse11b-slow.logReading mysql slow query log from/var/lib/mysql/suse11b-slow.logCount: 1 Time = 1.57 s (1 s) lock = 0.00 s (0 s) Rows = 83.0 (83), root [root] @ localhost select table_schema, table_name, count (*) from tb_slow group by table_schema, table_name order by N, NCount: 4 Time = 16.87 s (67 s) Lock = 0.00 s (0 s) Rows = 0.0 (0 ), root [root] @ localhost insert into tb_slow select * From tb_slow # obtain the help information of mysqldumpslow suse11b :~ # Mysqldumpslow -- helpUsage: mysqldumpslow [OPTS...] [LOGS...] parse and summarize the MySQL slow query log. options are -- verbose -- 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 # query times l: lock time r: rows sent # number of returned records 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 cmdts 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

How to Set slow query logs? By default, mysql does not record slow query logs. How can I set it to record slow queries?

Linux:

Add

Log-slow-queries =/var/lib/mysql/slowquery. log (specify the location where the log file is stored, which can be empty and the system will give a default file host_name-slow.log)
Long_query_time = 2 (the time when the record exceeds, the default value is 10 s)
Log-queries-not-using-indexes)
Log-long-format (if it is set, all queries without indexes will be recorded)

Windows:

Add the following statement in [mysqld] Of my. ini:
Log-slow-queries = E: \ web \ mysql \ log \ mysqlslowquery. log
Long_query_time = 2 (other parameters above)

Mysql slow Query

Let's take a look at the value of your long_query_time configuration. This is the slow query time. Only queries that exceed this time will be recorded in the slow query log.
Instead of logging all queries.