Mysql日志管理

Mysql日志

一、Mysql日志类型

Mysql日志主要分为四类，这四类日志分别是:

错误日志: 记录Mysql服务的启动、运行和停止Mysql服务时出现的问题
查询日志: 记录建立的客户端连接和执行的语句
二进制日志: 记录所有更改数据的语句，可以用于数据复制
慢查询日志: 记录所有执行时间超过Long_query_time的所有查询或不使用索引的查询

默认情况下，所有日志创建于Mysql数据目录中，通过刷新日志，可以强制Mysql关闭和重新打开日志文件(或者在某些情况下切换到一个新的日志)。当执行一个flush logs语句或执行mysqladmin flush-logs或mysqladmin refresh时，将刷新日志。

二、二进制日志

1. 启动和设置二进制日志

修改配置文件my.ini/my.cnf中[mysqld]组下面设置二进制日志参数，需重启Mysql服务生效:

[mysqld]

log-bin=mysql-bin

server_id=1

expire_logs_days=10

max_binlog_size=100M

binlog_format=row

参数	描述
log-bin	定义开启二进制日志，可以指定path路径及文件名，如log-bin=/var/log/binlog，如果不指定，则日志文件以主机名为文件名
expire_logs_days	定义了Mysql清除过期日志的时间，即二进制日志自动删除的天数
max_binlog_size	定义了单个文件的大小限制，不能将该变量设置为大于1G或者小于4096字节。默认值是1G

Mysql二进制日志存储了所有的变更信息，Mysql二进制日志是经常用到的。当Mysql创建二进制日志文件时，首先创建一个以'filename'为名称，以'.index'为后缀的文件，再创建一个以'filename'为名称，以'.000001'为后缀的文件。当Mysql服务重新启动一次，以'.000001'为后缀的文件会增加一个，并且后缀名为1递增，如果日志长度超过了max_binlog_size的上限(默认是1G)也会创建一个新的日志文件。默认存储路径为data目录C:\ProgramData\MySQL\MySQL Server 5.5\data

暂时停止记录二进制日志:
set sql_log_bin=0
恢复记录日志:
set sql_log_bin=1

2. 查看Mysql日志

root@localhost |★(none)★| 17:30:33-> show variables like 'log_%';
+----------------------------------------+----------------------------------+
| Variable_name                          | Value                            |
+----------------------------------------+----------------------------------+
| log_bin                                | ON                               |
| log_bin_basename                       | /data/mysql/data/mysql-bin       |
| log_bin_index                          | /data/mysql/data/mysql-bin.index |
| log_bin_trust_function_creators        | OFF                              |
| log_bin_use_v1_row_events              | OFF                              |
| log_builtin_as_identified_by_password  | OFF                              |
| log_error                              | ./db01.err                       |
| log_error_verbosity                    | 3                                |
| log_output                             | FILE                             |
| log_queries_not_using_indexes          | OFF                              |
| log_slave_updates                      | OFF                              |
| log_slow_admin_statements              | OFF                              |
| log_slow_slave_statements              | OFF                              |
| log_statements_unsafe_for_binlog       | ON                               |
| log_syslog                             | OFF                              |
| log_syslog_facility                    | daemon                           |
| log_syslog_include_pid                 | ON                               |
| log_syslog_tag                         |                                  |
| log_throttle_queries_not_using_indexes | 0                                |
| log_timestamps                         | UTC                              |
| log_warnings                           | 2                                |
+----------------------------------------+----------------------------------+
21 rows in set (0.00 sec)

查看二进制日志:
root@localhost |★(none)★| 17:36:31-> show binary logs;
+----------------+-----------+
| Log_name       | File_size |
+----------------+-----------+
| VIP-bin.000001 |       107 |
+----------------+-----------+
1 row in set (0.00 sec)

查看当前正在使用的二进制日志:
root@localhost |★(none)★| 17:40:33-> show master status;
+------------------+----------+--------------+------------------+-------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+------------------+----------+--------------+------------------+-------------------+
| VIP-bin.000001 |      107 |              |                  |                   |
+------------------+----------+--------------+------------------+-------------------+
1 row in set (0.00 sec)

查看日志事件信息:
root@localhost |★(none)★| 17:45:33-> show binlog events in 'VIP-bin.000002' limit 5,6;
+------------------+-----+------------+-----------+-------------+---------------------------------+
| Log_name         | Pos | Event_type | Server_id | End_log_pos | Info                            |
+------------------+-----+------------+-----------+-------------+---------------------------------+
| mysql-bin.000005 | 383 | Query      |         6 |         455 | BEGIN                           |
| mysql-bin.000005 | 455 | Table_map  |         6 |         502 | table_id: 109 (mydb.test)       |
| mysql-bin.000005 | 502 | Write_rows |         6 |         542 | table_id: 109 flags: STMT_END_F |
| mysql-bin.000005 | 542 | Xid        |         6 |         573 | COMMIT /* xid=19 */             |
+------------------+-----+------------+-----------+-------------+---------------------------------+
4 rows in set (0.00 sec)

查看二进制内容:
[root@db01 data]# mysqlbinlog mysql-bin.000004

[root@db01 data]# mysqlbinlog --base64-output=decode-rows -vvv mysql-bin.000005

[root@db01 data]# mysqlbinlog --start-position=383 --stop-position=573 mysql-bin.000005

[root@db01 data]# mysqlbinlog -v --base64-output=DECODE-ROWS  --start-datetime="2021-05-16 17:30:29" --stop-datetime="2021-05-16 17:40:31" --database=test mysql-bin.000015 >/tmp/test.sql

[root@db01 data]# mysqlbinlog -d mydb mysql-bin.000004    ---只显示mydb数据库相关的内容

3. 切换日志

root@localhost |★(none)★| 20:23:24-> flush logs;
[root@db01 ~]# mysqladmin -uroot -proot flush-logs
[root@db01 ~]# mysqladmin -uroot -proot refresh

4. 删除二进制日志

Reset Master删除所有二进制日志文件

root@localhost |★(none)★| 20:31:05-> reset master
执行完后，所有二进制日志将被删除，Mysql会重新创建二进制日志，新的日志文件扩展名将重新从000001开始编号。

Purge Master Logs删除指定日志文件

purge master|binary logs to 'log_name';
purge master|binary logs before 'date';
第一种方法指定文件名，该命令删除文件名编号比指定文件名编号小的所有日志文件
第二种方法指定日期，该命令删除指定日期以前的所有日志文件

root@localhost |★(none)★| 20:38:34-> show master logs;
+----------------+-----------+
| Log_name       | File_size |
+----------------+-----------+
| VIP-bin.000001 |       148 |
| VIP-bin.000002 |       148 |
| VIP-bin.000003 |       148 |
| VIP-bin.000004 |       148 |
| VIP-bin.000005 |       148 |
| VIP-bin.000006 |       148 |
| VIP-bin.000007 |       107 |
+----------------+-----------+
7 rows in set (0.00 sec)

root@localhost |★(none)★| 20:39:47-> purge master logs to 'VIP-bin.000004';
Query OK, 0 rows affected (0.01 sec)

root@localhost |★(none)★| 20:39:53-> show binary logs;
+----------------+-----------+
| Log_name       | File_size |
+----------------+-----------+
| VIP-bin.000004 |       148 |
| VIP-bin.000005 |       148 |
| VIP-bin.000006 |       148 |
| VIP-bin.000007 |       107 |
+----------------+-----------+
4 rows in set (0.00 sec)

root@localhost |★(none)★| 20:46:41-> show binary logs;
+----------------+-----------+
| Log_name       | File_size |
+----------------+-----------+
| VIP-bin.000004 |       148 |
| VIP-bin.000005 |       148 |
| VIP-bin.000006 |       148 |
| VIP-bin.000007 |       148 |
| VIP-bin.000008 |       107 |
+----------------+-----------+
5 rows in set (0.00 sec)

C:\ProgramData\MySQL\MySQL Server 5.5\data>mysqlbinlog VIP-bin.000008
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#171211 20:46:41 server id 1  end_log_pos 107   Start: binlog v 4, server v 5.5.53-log created 171211 20:46:41
# Warning: this binlog is either in use or was not closed properly.
BINLOG '
MX4uWg8BAAAAZwAAAGsAAAABAAQANS41LjUzLWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAVAAEGggAAAAICAgCAA==
'/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

root@localhost |★(none)★| 21:08:09-> purge master logs before '2017-12-11 20:46:41';
Query OK, 0 rows affected (0.01 sec)

root@localhost |★(none)★| 21:13:44-> show master logs;
+----------------+-----------+
| Log_name       | File_size |
+----------------+-----------+
| VIP-bin.000007 |       148 |
| VIP-bin.000008 |       107 |
+----------------+-----------+

5.GITD恢复数据

在5.6版本开启GTID时必须开启log-slave-updates，因为GTID相关信息是存放在内存的，重启以后就丢失了，必须要从binlog里找到最新应用到的GTID；
在5.7版本由于引入了mysql.gtid_executed表，GTID信息存放在这个数据表里，那么重启之后就不再需要去读取binlog来获取GTID相关信息了。同时通过gtid_executed_compression_period参数控制执行了多少个事务以后，对mysql.gtid_executed表进行压缩，以免大量的GTID信息占用过多存储空间。

配置文件添加GITD参数

[root@db01 ~]# vi /etc/my.cnf

[mysqld]

gtid-mode=on

enforce-gtid-consistency=1

log-slave-updates=1

重启DB

[root@db01 ~]# mysqladmin -uroot -p shutdown
[root@db01 ~]# mysqld_safe --user=mysql &

查看GTID

mysql> show master status;
+------------------+----------+--------------+------------------+-------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+------------------+----------+--------------+------------------+-------------------+
| mysql-bin.000006 |      154 |              |                  |                   |
+------------------+----------+--------------+------------------+-------------------+
1 row in set (0.00 sec)

mysql> create database gtid;
Query OK, 1 row affected (0.01 sec)

mysql> show master status;
+------------------+----------+--------------+------------------+----------------------------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set                      |
+------------------+----------+--------------+------------------+----------------------------------------+
| mysql-bin.000006 |      313 |              |                  | d5d29a37-ace6-11eb-9949-000c29bdd3e5:1 |
+------------------+----------+--------------+------------------+----------------------------------------+
1 row in set (0.00 sec)

mysql> use gtid
Database changed

mysql> create table t(id int);
Query OK, 0 rows affected (0.01 sec)

mysql> show master status;
+------------------+----------+--------------+------------------+------------------------------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set                        |
+------------------+----------+--------------+------------------+------------------------------------------+
| mysql-bin.000006 |      474 |              |                  | d5d29a37-ace6-11eb-9949-000c29bdd3e5:1-2 |
+------------------+----------+--------------+------------------+------------------------------------------+
1 row in set (0.00 sec)

mysql> insert into t values (1);
Query OK, 1 row affected (0.00 sec)

mysql> show master status;
+------------------+----------+--------------+------------------+------------------------------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set                        |
+------------------+----------+--------------+------------------+------------------------------------------+
| mysql-bin.000006 |      726 |              |                  | d5d29a37-ace6-11eb-9949-000c29bdd3e5:1-3 |
+------------------+----------+--------------+------------------+------------------------------------------+
1 row in set (0.00 sec)

使用GTID恢复数据

mysql> drop table t;
Query OK, 0 rows affected (0.01 sec)

mysql> show master status;
+------------------+----------+--------------+------------------+------------------------------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set                        |
+------------------+----------+--------------+------------------+------------------------------------------+
| mysql-bin.000006 |      905 |              |                  | d5d29a37-ace6-11eb-9949-000c29bdd3e5:1-4 |
+------------------+----------+--------------+------------------+------------------------------------------+
1 row in set (0.00 sec)

mysql> show binlog events in 'mysql-bin.000006';
+------------------+-----+----------------+-----------+-------------+-------------------------------------------------------------------+
| Log_name         | Pos | Event_type     | Server_id | End_log_pos | Info                                                              |
+------------------+-----+----------------+-----------+-------------+-------------------------------------------------------------------+
| mysql-bin.000006 |   4 | Format_desc    |         6 |         123 | Server ver: 5.7.26-log, Binlog ver: 4                             |
| mysql-bin.000006 | 123 | Previous_gtids |         6 |         154 |                                                                   |
| mysql-bin.000006 | 154 | Gtid           |         6 |         219 | SET @@SESSION.GTID_NEXT= 'd5d29a37-ace6-11eb-9949-000c29bdd3e5:1' |
| mysql-bin.000006 | 219 | Query          |         6 |         313 | create database gtid                                              |
| mysql-bin.000006 | 313 | Gtid           |         6 |         378 | SET @@SESSION.GTID_NEXT= 'd5d29a37-ace6-11eb-9949-000c29bdd3e5:2' |
| mysql-bin.000006 | 378 | Query          |         6 |         474 | use gtid; create table t(id int)                                |
| mysql-bin.000006 | 474 | Gtid           |         6 |         539 | SET @@SESSION.GTID_NEXT= 'd5d29a37-ace6-11eb-9949-000c29bdd3e5:3' |
| mysql-bin.000006 | 539 | Query          |         6 |         611 | BEGIN                                                             |
| mysql-bin.000006 | 611 | Table_map      |         6 |         655 | table_id: 108 (gtid.t)                                            |
| mysql-bin.000006 | 655 | Write_rows     |         6 |         695 | table_id: 108 flags: STMT_END_F                                   |
| mysql-bin.000006 | 695 | Xid            |         6 |         726 | COMMIT /* xid=17 */                                               |
| mysql-bin.000006 | 726 | Gtid           |         6 |         791 | SET @@SESSION.GTID_NEXT= 'd5d29a37-ace6-11eb-9949-000c29bdd3e5:4' |
| mysql-bin.000006 | 791 | Query          |         6 |         905 | use gtid; DROP TABLE t /* generated by server */              |
+------------------+-----+----------------+-----------+-------------+-------------------------------------------------------------------+
13 rows in set (0.00 sec)

由上可知只需恢复mysql-bin.000006中GTID:2-3，即可以恢复t表
d5d29a37-ace6-11eb-9949-000c29bdd3e5:2
d5d29a37-ace6-11eb-9949-000c29bdd3e5:3

[root@db01 data]# mysqlbinlog --skip-gtids --include-gtids=d5d29a37-ace6-11eb-9949-000c29bdd3e5:2-3 mysql-bin.000006 > /tmp/gtid.sql

mysql> set sql_log_bin=0;

mysql> source /tmp/gtid.sql

mysql> use gtid
Database changed

mysql> select * from t;
+------+
| id   |
+------+
|    1 |
+------+
1 row in set (0.00 sec)

mysql> set sql_log_bin=1;

GTID相关参数:
--skip-gtids
--include-gtids
--exclude-gtids:'d5d29a37-ace6-11eb-9949-000c29bdd3e5:5','d5d29a37-ace6-11eb-9949-000c29bdd3e5:8'

--skip-gtids参数必须加入，否则导入的时候gtid会冲突。

三、慢查询日志

慢查询相关参数:
slow_query_log
slow_query_log_file
long_query_time
log_queries_not_using_indexes

MySQL的慢查询日志是MySQL提供的一种日志记录，用来记录在MySQL中响应时间超过阈值的语句，具体指运行时间超过long_query_time值的SQL，则会被记录到慢查询日志中（日志可以写入文件或者数据库表，如果对性能要求高的话，建议写文件）。默认情况下，MySQL数据库是不开启慢查询日志的，long_query_time的默认值为10（即10秒，通常设置为1秒），即运行10秒以上的语句是慢查询语句。

一般来说，慢查询发生在大表（比如：一个表的数据量有几百万），且查询条件的字段没有建立索引，此时要匹配查询条件的字段会进行全表扫描，耗时超过long_query_time，则为慢查询语句。

1.查看慢查询是否开启

mysql> show variables like 'slow_query%';
+---------------------+------------------------------------+
| Variable_name       | Value                              |
+---------------------+------------------------------------+
| slow_query_log      | OFF                                |
| slow_query_log_file | /usr/local/mysql/data/vip-slow.log |
+---------------------+------------------------------------+
2 rows in set (0.00 sec)

2.开启慢查询

在配置文件中添加参数(重启生效)

[root@vip ~]# vim /etc/my.cnf

[mysqld]
slow_query_log = 1
slow_query_log_file = /usr/local/mysql/data/admin-slow.log
long_query_time = 0.5
log_queries_not_using_indexes = 1

[root@vip ~]# /etc/init.d/mysql restart
Shutting down MySQL.. SUCCESS!
Starting MySQL. SUCCESS!

mysql> show variables like 'slow_query%';
+---------------------+--------------------------------------+
| Variable_name       | Value                                |
+---------------------+--------------------------------------+
| slow_query_log      | ON                                   |
| slow_query_log_file | /usr/local/mysql/data/admin-slow.log |
+---------------------+--------------------------------------+
2 rows in set (0.00 sec)

在全局会话中设置(立刻生效，重启失效)

mysql> set global slow_query_log = 1;
Query OK, 0 rows affected (0.27 sec)

mysql> set global slow_query_log_file = '/usr/local/mysql/data/admin-slow.log';
Query OK, 0 rows affected (0.00 sec)

或者:
mysql> set global slow_query_log = 1,slow_query_log_file = '/usr/local/mysql/data/admin-slow.log';
Query OK, 0 rows affected (0.00 sec)

mysql> show variables like 'slow_query%';
+---------------------+--------------------------------------+
| Variable_name       | Value                                |
+---------------------+--------------------------------------+
| slow_query_log      | ON                                   |
| slow_query_log_file | /usr/local/mysql/data/admin-slow.log |
+---------------------+--------------------------------------+
2 rows in set (0.00 sec)

3.慢查询相关参数

参数	描述	备注
slow_query_log	慢查询日志开启标识, 1表示开启，0表示关闭
slow_query_log_file	慢查询日志文件路径
long_query_time	指定慢查询阈值，当查询时间大于或等于设定的阈值时，记录进慢查询日志，默认10秒	5.5版本毫秒支持
min_examined_row_limit	查询结果返回记录数少于该参数值的SQL不被记录到慢查询日志
log_queries_not_using_indexes	将没有使用索引的SQL记录到慢查询日志
log_throttle_queries_not_using_indexes	限制每分钟记录没有使用索引SQL语句的次数	5.6版本
log_slow_admin_statement	记录操作语句，如alter/analyze table
log_output	慢查询日志的输出样式，file\|table\|none	5.5版本
log_slow_slave_statements	在从服务器上开启慢查询日志
log_timestamps	写入时区信息	5.7版本

4.格式化慢查询日志

[root@vip ~]# mysqldumpslow /usr/local/mysql/data/admin-slow.log

Reading mysql slow query log from /usr/local/mysql/data/admin-slow.log
Count: 2  Time=5.50s (11s)  Lock=0.00s (0s)  Rows=1.0 (2), root[root]@localhost
  select sleep(N)

或者

[root@db01 data]# mysqldumpslow -s c -t 10 /data/mysql/data/slow.log

5.示例-long_query_time

(1)开启慢查询日志
mysql> set global slow_query_log = 1,slow_query_log_file = '/usr/local/mysql/data/admin-slow.log';
Query OK, 0 rows affected (0.00 sec)

mysql> show variables like 'slow_query%';
+---------------------+--------------------------------------+
| Variable_name       | Value                                |
+---------------------+--------------------------------------+
| slow_query_log      | ON                                   |
| slow_query_log_file | /usr/local/mysql/data/admin-slow.log |
+---------------------+--------------------------------------+
2 rows in set (0.00 sec)

(2)设置log_query_time参数
mysql> set global long_query_time = 5;
Query OK, 0 rows affected (0.00 sec)

(3)查看慢查询日志
[root@vip ~]# tail -f -n 50 /usr/local/mysql/data/admin-slow.log

/usr/local/mysql/bin/mysqld, Version: 5.6.39 (MySQL Community Server (GPL)). started with:
Tcp port: 3306  Unix socket: /tmp/mysql.sock
Time                 Id Command    Argument

(4)执行慢查询语句(set global需要退出当前会话重新登录才生效，否则不会记录当前会话执行的语句)
mysql> select sleep(4);
+----------+
| sleep(4) |
+----------+
|        0 |
+----------+
1 row in set (4.00 sec)

mysql> select sleep(5);
+----------+
| sleep(5) |
+----------+
|        0 |
+----------+
1 row in set (5.00 sec)

mysql> select sleep(6);
+----------+
| sleep(6) |
+----------+
|        0 |
+----------+
1 row in set (6.00 sec)

(5)再次查看慢查询日志
[root@vip ~]# tail -f -n 50 /usr/local/mysql/data/admin-slow.log

/usr/local/mysql/bin/mysqld, Version: 5.6.39 (MySQL Community Server (GPL)). started with:
Tcp port: 3306  Unix socket: /tmp/mysql.sock
Time                 Id Command    Argument
# Time: 180702 14:53:55
# User@Host: root[root] @ localhost []  Id:     2
# Query_time: 5.001012  Lock_time: 0.000000 Rows_sent: 1  Rows_examined: 0
SET timestamp=1530514435;
select sleep(5);
# Time: 180702 14:54:23
# User@Host: root[root] @ localhost []  Id:     2
# Query_time: 6.000133  Lock_time: 0.000000 Rows_sent: 1  Rows_examined: 0
SET timestamp=1530514463;
select sleep(6);

(6)格式化语句
[root@vip ~]# mysqldumpslow /usr/local/mysql/data/admin-slow.log

Reading mysql slow query log from /usr/local/mysql/data/admin-slow.log
Count: 2  Time=5.50s (11s)  Lock=0.00s (0s)  Rows=1.0 (2), root[root]@localhost
  select sleep(N)

6.示例-log_output

(1)查看慢查询日志
mysql> show variables like 'slow_query%';
+---------------------+------------------------------------+
| Variable_name       | Value                              |
+---------------------+------------------------------------+
| slow_query_log      | OFF                                |
| slow_query_log_file | /usr/local/mysql/data/vip-slow.log |
+---------------------+------------------------------------+
2 rows in set (0.00 sec)

mysql> show variables like 'log_output';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| log_output    | FILE  |
+---------------+-------+
1 row in set (0.00 sec)

(2)配置慢查询日志
mysql> set global slow_query_log = 1;
Query OK, 0 rows affected (0.00 sec)

mysql> set global log_output = 'table';
Query OK, 0 rows affected (0.00 sec)

(3)查看慢查询日志
mysql> show variables like 'slow_query%';
+---------------------+------------------------------------+
| Variable_name       | Value                              |
+---------------------+------------------------------------+
| slow_query_log      | ON                                 |
| slow_query_log_file | /usr/local/mysql/data/vip-slow.log |
+---------------------+------------------------------------+
2 rows in set (0.00 sec)

mysql> show variables like 'log_output';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| log_output    | TABLE |
+---------------+-------+
1 row in set (0.00 sec)

mysql> show variables like 'long%';
+-----------------+-----------+
| Variable_name   | Value     |
+-----------------+-----------+
| long_query_time | 10.000000 |
+-----------------+-----------+
1 row in set (0.00 sec)

mysql> select * from mysql.slow_log;
Empty set (0.00 sec)

(3)执行慢查询操作
mysql> select sleep(9);
+----------+
| sleep(9) |
+----------+
|        0 |
+----------+
1 row in set (9.00 sec)

mysql> select sleep(10);
+-----------+
| sleep(10) |
+-----------+
|         0 |
+-----------+
1 row in set (10.00 sec)

(4)再次查看慢查询日志记录
mysql> select * from mysql.slow_log;
+---------------------+---------------------------+------------+-----------+-----------+---------------+----+----------------+-----------+-----------+------------------+-----------+
| start_time          | user_host                 | query_time | lock_time | rows_sent | rows_examined | db | last_insert_id | insert_id | server_id | sql_text         | thread_id |
+---------------------+---------------------------+------------+-----------+-----------+---------------+----+----------------+-----------+-----------+------------------+-----------+
| 2018-07-02 16:54:34 | root[root] @ localhost [] | 00:00:10   | 00:00:00  |         1 |             0 |    |              0 |         0 |         0 | select sleep(10) |         4 |
+---------------------+---------------------------+------------+-----------+-----------+---------------+----+----------------+-----------+-----------+------------------+-----------+
1 row in set (0.00 sec)

(5)优化slow_log表，修改表的存储引擎为Myisam
mysql> show create table mysql.slow_log;

CREATE TABLE slow_log (
  start_time timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,
  user_host mediumtext NOT NULL,
  query_time time NOT NULL,
  lock_time time NOT NULL,
  rows_sent int(11) NOT NULL,
  rows_examined int(11) NOT NULL,
  db varchar(512) NOT NULL,
  last_insert_id int(11) NOT NULL,
  insert_id int(11) NOT NULL,
  server_id int(10) unsigned NOT NULL,
  sql_text mediumtext NOT NULL,
  thread_id bigint(21) unsigned NOT NULL
) ENGINE=CSV DEFAULT CHARSET=utf8 COMMENT='Slow log'

mysql> use mysql
Database changed
mysql> alter table slow_log engine=myisam;
ERROR 1580 (HY000): You cannot 'ALTER' a log table if logging is enabled

mysql> set global slow_query_log = 0;
Query OK, 0 rows affected (0.00 sec)

mysql> alter table slow_log engine=myisam;
Query OK, 2 rows affected (0.00 sec)
Records: 2  Duplicates: 0  Warnings: 0

mysql> set global slow_query_log = 1;
Query OK, 0 rows affected (0.00 sec)

mysql> show table status from mysql where name = 'slow_log'\G
*************************** 1. row ***************************
           Name: slow_log
         Engine: MyISAM
        Version: 10
     Row_format: Dynamic
           Rows: 2
 Avg_row_length: 76
    Data_length: 152
Max_data_length: 281474976710655
   Index_length: 1024
      Data_free: 0
 Auto_increment: NULL
    Create_time: 2018-07-02 17:06:46
    Update_time: 2018-07-02 17:06:46
     Check_time: NULL
      Collation: utf8_general_ci
       Checksum: NULL
 Create_options:
        Comment: Slow log
1 row in set (0.00 sec)

四、日志分析工具

Pt-Query-Digest analyzes MySQL queries from slow, general, and binary log files. It can also analyze queries from SHOW PROCESSLIST and MySQL protocol data from tcpdump. By default, queries are grouped by fingerprint and reported in descending order of query time (i.e. the slowest queries first). If no FILES are given, the tool reads STDIN. The optional DSN is used for certain options like --since and --until.

https://www.zhangdong.me/mysql/pt-query-digest.html