MySQL slow query log (SlowQueryLog) _ MySQL

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 can help us locate the internal issue of mysqld

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. MySQL log file system Composition 2. slow query log 3. slow query log demonstration long_query_time: set the threshold for slow query, the SQL statement that exceeds the set value is recorded in the slow query log. the default value is 10sslow_query_log: whether to enable the slow query log log_slow_queries: whether to enable the slow query log (this parameter should be replaced by slow_query_log, slow_query_log_file: specifies the location where the slow log file is stored. it can be empty and 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: http://blog.csdn.net/leshamiroot@localhost [Tempdb]> 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 ..... for ease of demonstration, we insert some data, and the repeated process in the middle omitting root @ localhost [tempdb]> insert into tb_slow select * from tb_slow; Query OK, 265 28 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 Ro Ws_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_tim E: 0.000183 Rows_sent: 83 Rows_examined: 424614 SET timestamp = 1412431847; select table_schema, table_name, count (*) from tb_slow -- this SQL statement has been 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 '; + ----------------------------- + ------- + | Variable_name | Value | + ------------------------------- + ------- + | log_queries_no T_using_indexes | OFF | + rows + ------- + root @ localhost [tempdb]> set global log_queries_not_using_indexes = 1; Query OK, 0 rows affected (0.00 sec) -- view the index information of table tb_slow, 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) r Oot @ localhost [tempdb] & gt; 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. the reason for the record is that the index is not taken, because the table itself does not have an index 4. formatting the slow query log structured slow query log is to extract important information in the slow query log according to 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