1, the MySQL log file system composition
2. Slow query log
3. Slow Query Log Demo
Long_query_time: Set the threshold of the slow query, the SQL that exceeds the sub-set value is logged to the slow query log, the default value is 10s
Slow_query_log: Specifies whether to turn on the slow query log
Log_slow_queries: Specifies whether to turn on the slow query log (this parameter should be replaced by Slow_query_log for compatibility retention)
Slow_query_log_file: Specifies the slow log file location, can be empty, the system will give a default file Host_name-slow.log
Min_examined_row_limit: Query check returns less than the specified row for SQL is not logged to the slow query log
Log_queries_not_using_indexes: Slow query logs that do not use indexes are logged to the index
--Current version
[Email protected] [(None)]> show variables like ' version ';
+---------------+------------+
| variable_name | Value |
+---------------+------------+
| Version | 5.5.39-log |
+---------------+------------+
[Email protected] [(None)]> show variables like '%slow% ';
+---------------------+---------------------------------+
| variable_name | Value |
+---------------------+---------------------------------+
| log_slow_queries | OFF |
| Slow_launch_time | 2 |
| Slow_query_log | OFF |
| Slow_query_log_file | /var/lib/mysql/suse11b-slow.log |
+---------------------+---------------------------------+
[Email protected] [tempdb]> set global Log_slow_queries=1;
Query OK, 0 rows affected, 1 Warning (0.00 sec)
[Email protected] [(none)]> show warnings;
+---------+------+--------------------------------------------------------------------------------------------- ----------------------+
| Level | Code | Message |
+---------+------+--------------------------------------------------------------------------------------------- ----------------------+
| Warning | 1287 | ' @ @log_slow_queries ' is deprecated and would be removed in a future release. Use ' @ @slow_query_log ' instead |
+---------+------+--------------------------------------------------------------------------------------------- ----------------------+
--From the following query, 2 system variable Log_slow_queries,slow_query_log are simultaneously set to ON
Root[email protected][(none)]> show variables like '%slow% ';
+---------------------+---------------------------------+
| variable_name | Value |
+---------------------+---------------------------------+
| log_slow_queries | On |
| Slow_launch_time | 2 |
| Slow_query_log | On |
| Slow_query_log_file | /var/lib/mysql/suse11b-slow.log |
+---------------------+---------------------------------+
[Email protected] [tempdb]> Show variables like '%long_query_time% ';
+-----------------+-----------+
| variable_name | Value |
+-----------------+-----------+
| Long_query_time | 10.000000 |
+-----------------+-----------+
-For demonstration purposes, we set the global and session level long_query_time to 1
[Email protected] [tempdb]> set global long_query_time=1;
Query OK, 0 rows Affected (0.00 sec)
[Email protected] [tempdb]> set session long_query_time=1;
Query OK, 0 rows Affected (0.00 sec)
--author:leshami
--blog:http://blog.csdn.net/leshami
[Email protected] [tempdb]> CREATE TABLE Tb_slow as SELECT * from Information_schema.columns;
Query OK, 829 rows Affected (0.10 sec)
records:829 duplicates:0 warnings:0
[Email protected] [tempdb]> INSERT INTO Tb_slow select * from Tb_slow;
Query OK, 829 rows affected (0.05 sec)
records:829 duplicates:0 warnings:0
..... For illustrative purposes, we insert some data, and the intermediate repetition process omits
[Email protected] [tempdb]> INSERT INTO Tb_slow select * from Tb_slow;
Query OK, 26528 rows Affected (4.40 sec)
records:26528 duplicates:0 warnings:0
[Email protected] [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/mysql.sock
Time Id Command Argument
# time:2881064151 22:05:48
# [email protected]: root[root] @ localhost []
# query_time:4.396858 lock_time:0.000140 rows_sent:0 rows_examined:53056
Use tempdb;
SET timestamp=1412431548;
INSERT INTO Tb_slow select * from Tb_slow;
.... Insert some records again ....
[Email protected] [tempdb]> INSERT INTO Tb_slow select * from Tb_slow;
Query OK, 212224 rows Affected (37.51 sec)
records:212224 duplicates:0 warnings:0
[Email protected] [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 (*) |
+--------------------+----------------------------------------------+----------+
| Information_schema | collation_character_set_applicability | 1024 |
| Performance_schema | cond_instances | 1024 | ...........
| MySQL | user | 21504 |
+--------------------+----------------------------------------------+----------+
In Set (1.58 sec)
[Email protected] [tempdb]> system Tail/var/lib/mysql/suse11b-slow.log
# [email protected]: 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
# [email protected]: 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 is recorded with a query time of 1.573293s
Group BY Table_schema,table_name ORDER by 3, 2;
[Email protected] [tempdb]> Show variables like '%log_queries_not_using_indexes ';
+-------------------------------+-------+
| variable_name | Value |
+-------------------------------+-------+
| log_queries_not_using_indexes | OFF |
+-------------------------------+-------+
[Email protected] [tempdb]> set global Log_queries_not_using_indexes=1;
Query OK, 0 rows Affected (0.00 sec)
--View Table Tb_slow index information, table Tb_slow No index
[Email protected] [tempdb]> Show index from Tb_slow;
Empty Set (0.00 sec)
[Email protected]lhost[tempdb]> Select COUNT (*) from Tb_slow;
+----------+
| COUNT (*) |
+----------+
| 424448 |
+----------+
1 row in Set (0.20 sec)
[Email protected] [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 is not indexed
4. Format slow query log
A structured slow query log is a way to extract important information from a slow query log as easy to read and to sort by a specific sorting method.
This approach is somewhat similar to having a tkprof in Oracle to format the trace file of Oracle.
For the previous slow query log we use Mysqldumpslow to extract the following:
suse11b:~ # mysqldumpslow-s At,al/var/lib/mysql/suse11b-slow.log
Reading mysql slow query log from/var/lib/mysql/suse11b-slow.log
Count:4 time=16.87s (67s) lock=0.00s (0s) rows=0.0 (0), Root[root] @localhost
INSERT INTO Tb_slow select * from Tb_slow
count:1 time=0.20s (0s) lock=0.00s (0s) rows=1.0 (1), Root[root] @localhost
Select COUNT (*) from Tb_slow
count:1 time=1.57s (1s) lock=0.00s (0s) rows=83.0 (in), Root[root] @localhost
Select Table_schema,table_name,count (*) from Tb_slow
Group BY Table_schema,table_name ORDER by N,n
#以下是按照最大耗用时间排最后, only 2 ways to format the log file
suse11b:~ # mysqldumpslow-r-T 2/var/lib/mysql/suse11b-slow.log
Reading mysql slow query log from/var/lib/mysql/suse11b-slow.log
count:1 time=1.57s (1s) lock=0.00s (0s) rows=83.0 (in), Root[root] @localhost
Select Table_schema,table_name,count (*) from Tb_slow
Group BY Table_schema,table_name ORDER by N,n
Count:4 time=16.87s (67s) lock=0.00s (0s) rows=0.0 (0), Root[root] @localhost
INSERT INTO Tb_slow select * from Tb_slow
#获取mysqldumpslow的帮助信息
suse11b:~ # 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, in, AR, C, L, R, T), ' at ' is default Al:average lock time ar:average rows sent At:average Query time C:count #query的次数 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-N and strings to ' S '
-N NUM abstract numbers with at least n digits within names
-G PATTERN Grep:only Consider stmts that include the This string
-H HOSTNAME HOSTNAME of DB Server for *-slow.log filename (can being 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
There is a tkprof in Oracle to format the trace files of Oracle